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
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"
I will check this out since I think I'm the last one that changed this code.
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.
I don't remember seeing these messages before (wrt vgsplit), so I'm going to mark this as a regression.
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)
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.
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.
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.
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.
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.
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; } }
Could also be the result of the "unlock_vg()" call right after the failed vg_read(). That would explain the message sequence.
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 :)
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.
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.
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);
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.
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.
From Apr 3 RHEL meeting: REPORTER: rkenna STATUS: Regression fixed upstream. DECISION: Approved blocker-rc for Snapshot 5.
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"
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