Bug 438249 - vgsplit causes 'cluster request' failure
Summary: vgsplit causes 'cluster request' failure
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Enterprise Linux 5
Classification: Red Hat
Component: lvm2
Version: 5.2
Hardware: All
OS: Linux
medium
medium
Target Milestone: rc
: ---
Assignee: Dave Wysochanski
QA Contact: Corey Marthaler
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2008-03-19 21:12 UTC by Corey Marthaler
Modified: 2010-01-12 03:53 UTC (History)
9 users (show)

Fixed In Version: RHBA-2008-0378
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2008-05-21 15:40:03 UTC
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Red Hat Product Errata RHBA-2008:0378 0 normal SHIPPED_LIVE lvm2 bug fix and enhancement update 2008-05-20 19:32:48 UTC

Description Corey Marthaler 2008-03-19 21:12:04 UTC
Description of problem:
PV /dev/etherd/e1.1p1    VG vg           lvm2 [605.48 GB / 605.48 GB free]
PV /dev/etherd/e1.1p2    VG vg           lvm2 [605.48 GB / 605.48 GB free]
PV /dev/etherd/e1.1p3    VG vg           lvm2 [605.48 GB / 605.48 GB free]

[root@hayes-02 tmp]# vgsplit vg new /dev/etherd/e1.1p[123]
  Volume group "new" not found
  cluster request failed: Invalid argument
  New volume group "new" successfully split from "vg"

Version-Release number of selected component (if applicable):
2.6.18-85.el5
lvm2-2.02.32-2.el5
lvm2-cluster-2.02.32-2.el5

Comment 1 Corey Marthaler 2008-03-19 21:13:30 UTC
Same thing happens when you just split a subset like you're supposed to:

[root@hayes-02 tmp]# vgsplit new vg  /dev/etherd/e1.1p[2]
  Volume group "vg" not found
  cluster request failed: Invalid argument
  New volume group "vg" successfully split from "new"


Comment 2 Dave Wysochanski 2008-03-19 21:45:44 UTC
I will check this out since I think I'm the last one that changed this code.

Comment 3 Dave Wysochanski 2008-03-20 03:43:57 UTC
I don't think my recent changes have introduced an issue in the vgsplit into a
new vg.

The error message "cluster request failed: Invalid argument" came up before and
apparentely we related to locking
(https://bugzilla.redhat.com/show_bug.cgi?id=364081).  That issue was apparently
fixed with changes that went in 11/15/2007 (RHEL4 build
lvm2-2.02.27-4.el4/lvm2-cluster-2.02.27-4.el4).  I don't really have a great
understanding of the specifics, but it is clear vgsplit does not have the same
code paths as in that bug.  There may be similarities but at this point I really
don't understand it well enough to say.

Comment 4 Corey Marthaler 2008-03-25 16:23:35 UTC
I don't remember seeing these messages before (wrt vgsplit), so I'm going to
mark this as a regression.

Comment 5 Dave Wysochanski 2008-04-01 17:25:32 UTC
Is it only the message or can you verify the volume group is split correctly.  I
do not have a rhel5 cluster setup and running I can easily repro/debug this at
the moment.

Not sure how to prioritize something with 'low' priority / severity but
"Regression" keyword.  At this point would you say it is or _is not_ something
that needs to be fixed before 5.2 goes out?  (is this a blocker)

Comment 6 Corey Marthaler 2008-04-01 18:23:01 UTC
Dave,

It appears that that vg did split correctly. What is with the "Volume group
"vg2" not found" message? I saw that in bz 246115 as well. It appears that
message just showed up in the recent builds, so there's still something fishy
with vgsplits.

[root@hayes-03 tmp]# vgcreate vg1 /dev/etherd/e1.1p1 /dev/etherd/e1.1p2
/dev/etherd/e1.1p3
  Volume group "vg1" successfully created
[root@hayes-03 tmp]# vgsplit vg1 vg2 /dev/etherd/e1.1p[123]
  Volume group "vg2" not found
  cluster request failed: Invalid argument
  New volume group "vg2" successfully split from "vg1"
[root@hayes-03 tmp]# vgs
  VG         #PV #LV #SN Attr   VSize  VFree
  VolGroup00   1   2   0 wz--n- 74.38G    0
  vg2          3   0   0 wz--nc  3.80T 3.80T


I'll bump the priority as we don't want to release with these messages, not
knowing if there's more to this issue.

Comment 7 Corey Marthaler 2008-04-01 19:12:55 UTC
I verified that this message is in fact a regression from rhel5.1.

2.6.18-53.el5
lvm2-2.02.26-3.el5
lvm2-cluster-2.02.26-1.el5

[root@grant-03 ~]# vgsplit vg1 vg2 /dev/sdb[123]
  Cannot split: Nowhere to store metadata for new Volume Group
[root@grant-03 ~]# vgsplit vg1 vg2 /dev/sdb1
  Volume group "vg2" successfully split from "vg1"

To the untrained eye, it appears that this would have been introduced by the fix
for bz 246115.

Comment 8 Dave Wysochanski 2008-04-01 19:38:10 UTC
Ok, let me go back further in the history.  I think I know where the 'Volume
group "vg2" not found' message is coming from - suspect the vg_lock_and_read()
call to see if the new vg exists.

I will try a simple patch to see if the error message goes away.

Comment 9 Dave Wysochanski 2008-04-01 19:46:48 UTC
Thank you for the clues corey, it is starting to make sense.

I think this was introduced by a change I made last july, convert to
vg_lock_and_read():
commit 23c2625984a908980bfafd95ac25f4de2ad630ce
Author: Dave Wysochanski <dwysocha>
Date:   Mon Jul 23 17:27:54 2007 +0000

    Add vg_lock_and_read() external library function.

By doing that I consolidated some code and cleaned things up but may have
introduced some unnecessary error messages.  There are times when you try a
vg_read() for example, and it might fail, but you don't necessarily want to see
the message.  A vgsplit to a new destination is one such case.

The timeframe of the change matches up with the data you provided - it was after
2.02.26 and before 2.02.32.

Still not sure about the cluster request failed message.

Comment 10 Dave Wysochanski 2008-04-01 20:49:06 UTC
I think I see some other problems when you split into a new vg.  I originally
thought a simple log_suppress() around vg_lock_and_read() on the new vg would
suffice.  However, a deeper look at the code and examining the history I think
is showing some other problems I introduced when I made that change and then
later added the split into existing volume group code.

Comment 11 Dave Wysochanski 2008-04-02 13:03:03 UTC
I'm guesing the "cluster request failed" message is the result of the lock_vol()
(inside vg_lock_and_read) on the new VG which does not yet exist.  I believe the
message is coming from clvmd (daemons/clvmd/clvmd_refresh.c:_send_request), in
which case the order of the messages in question could be inverted (lock_vol()
comes before vg_read(), but the "cluster request failed" message is the second
message printed):
	/* Read the returned values */
	off = 1;		/* we've already read the first byte */
	while (off <= outheader->arglen && len > 0) {
		len = read(_clvmd_sock, outheader->args + off,
			   buflen - off - offsetof(struct clvm_header, args));
		if (len > 0)
			off += len;
	}

	/* Was it an error ? */
	if (outheader->status != 0) {
		errno = outheader->status;

		/* Only return an error here if there are no node-specific
		   errors present in the message that might have more detail */
		if (!(outheader->flags & CLVMD_FLAG_NODEERRS)) {
			fprintf(stderr, "cluster request failed: %s\n", strerror(errno));
			return 0;
		}

	}




The only other place this message occurs is cluster_locking.c:send_request(),
the result of a failed read of a response from clvmd socket:
	/* Read the returned values */
	off = 1;		/* we've already read the first byte */
	while (off <= outheader->arglen && len > 0) {
		len = read(_clvmd_sock, outheader->args + off,
			   buflen - off - offsetof(struct clvm_header, args));
		if (len > 0)
			off += len;
	}

	/* Was it an error ? */
	if (outheader->status != 0) {
		errno = outheader->status;

		/* Only return an error here if there are no node-specific
		   errors present in the message that might have more detail */
		if (!(outheader->flags & CLVMD_FLAG_NODEERRS)) {
			log_error("cluster request failed: %s", strerror(errno));
			return 0;
		}

	}


Comment 12 Dave Wysochanski 2008-04-02 13:51:48 UTC
Could also be the result of the "unlock_vg()" call right after the failed
vg_read().  That would explain the message sequence.

Comment 13 Dave Wysochanski 2008-04-02 14:03:29 UTC
Looks like both messages are benign, and both are from vg_lock_and_read()
failing on the new vg.  The "Volume group not found" is from the "vg_read()",
and the "cluster request failed" is from the unlock_vg() call.

No blocker needed in this case, but we certainly want to silence these messages.
 Will work on that now.

The snippit of code is:
    if (lock_cmd == LCK_UNLOCK) {

	lkid = (int)(long)dm_hash_lookup(lock_hash, lockname);
	if (lkid == 0)
	    return EINVAL;

Snip from IRC confirming the source of the second message.  

<deepthot> chrissie: hi - I'm trying to confirm a theory
<deepthot> I'm working on bz https://bugzilla.redhat.com/show_bug.cgi?id=438249
<deepthot> it's "cluster request failed" message when you do a vgsplit and the
new vg you are splitting into does not exist
<deepthot> I'm not that familar with cluster locking
<deepthot> Is it possible I could see this message if I try to lock or unlock a
vg that does not yet exist?
<deepthot> the error code is EINVAL
<deepthot> I'm leaning towards the unlock at this point
<chrissie> possibly...I'll check
<deepthot> I'm mainly trying to determine if the message is benign or warrants a
blocker bug for 5.2
* kennepede (~pkennedy.redhat.com) has joined #cluster
<deepthot> e.g. a deeper problem than just the message
<chrissie> yes, if you try to unlock an VG that's not locked, you WILl be EINVAL
<chrissie> clvmd-command.c:193
<chrissie> sorry :207
<chrissie> (stupid cursor)
<deepthot> ok great, that is exactly where I was looking!
<deepthot> thanks for the confirmation!
<deepthot> so benign error message, no blocker needed.
<deepthot> thanks.
<chrissie> any time :)

Comment 14 Dave Wysochanski 2008-04-02 14:46:25 UTC
The previous message doesn't really explain it.  We should be able to do a lock,
unlock of a vg that does not yet exist without error.

In any case, vgsplit to a new vg does not look correct and I'm looking at it now.

Comment 15 Dave Wysochanski 2008-04-02 17:29:17 UTC
In vgsplit, the first vg_lock_and_read(...vg_from...) looks correct (based on a
comparison with the code before vg_lock_and_read was introduced).  The other two
are clearly incorrect though.

The problem is vgsplit calls vg_read() multiple times for destination vg (vg_to)
- not sure why at this point.  So we need to obtain the vg lock for vg_to early
in the code.  If we cannot, we need to fail, regardless of whether the
destination vg exists.

Comment 16 Dave Wysochanski 2008-04-02 17:43:08 UTC
Not clear to me why we're writing out the new vg as exported towards the bottom
of vgsplit (then reading it back and writing it out again):
	/* Write out new VG as EXPORTED */
	vg_to->status |= EXPORTED_VG;

	if (!archive(vg_to))
		goto error;

	if (!vg_write(vg_to) || !vg_commit(vg_to))
		goto error;

	backup(vg_to);


Also unclear whether we're actually doing this correctly - code looks different
than actual vgexport code (why are we not setting the EXPORTED_VG flag on each
pv, as in vgexport_single):
	if (!archive(vg))
		goto error;

	vg->status |= EXPORTED_VG;

	list_iterate_items(pvl, &vg->pvs) {
		pv = pvl->pv;
		pv->status |= EXPORTED_VG;
	}

	if (!vg_write(vg) || !vg_commit(vg))
		goto error;

	backup(vg);



Comment 17 Dave Wysochanski 2008-04-02 19:44:11 UTC
Fixed checked in upstream.  In addition to fixing the error messages, fixes a
larger problem where a vg lock was not obtained when a new vg was the
destination, which could result in metadata corruption.

Comment 20 Dave Wysochanski 2008-04-03 14:03:24 UTC
Risk analysis:
This is a regression.  Problem would only be seen when a vgsplit was done into a
new VG.  A lock was not properly obtained on the new VG before creation.  Thus,
if another command was run which somehow created this new VG with the same name,
corruption would occur.

Scope:
Fix involved vgsplit.c only, and reverted a previous change where
vg_lock_and_read() was used incorrectly in the place of vg_read() to determine
whether a new VG would exist. 

Comment 21 Suzanne Logcher 2008-04-03 16:15:22 UTC
From Apr 3 RHEL meeting:

REPORTER: rkenna
STATUS:   Regression fixed upstream.
DECISION: Approved blocker-rc for Snapshot 5.


Comment 24 Corey Marthaler 2008-04-04 19:38:03 UTC
fix verified in lvm2-2.02.32-4.el5.

[root@hayes-02 tmp]# pvcreate /dev/etherd/e1.1p*
  Physical volume "/dev/etherd/e1.1p1" successfully created
  Physical volume "/dev/etherd/e1.1p2" successfully created
  Physical volume "/dev/etherd/e1.1p3" successfully created
  Physical volume "/dev/etherd/e1.1p4" successfully created
  Physical volume "/dev/etherd/e1.1p5" successfully created
[root@hayes-02 tmp]# vgcreate vg1 /dev/etherd/e1.1p*
  Volume group "vg1" successfully created
[root@hayes-02 tmp]# vgsplit vg1 vg2 /dev/etherd/e1.1p*
  New volume group "vg2" successfully split from "vg1"


Comment 26 errata-xmlrpc 2008-05-21 15:40:03 UTC
An advisory has been issued which should help the problem
described in this bug report. This report is therefore being
closed with a resolution of ERRATA. For more information
on the solution and/or where to find the updated files,
please follow the link below. You may reopen this bug report
if the solution does not work for you.

http://rhn.redhat.com/errata/RHBA-2008-0378.html



Note You need to log in before you can comment on or make changes to this bug.