From 547510fb554bb77aa7f09efd46361306152b9d55 Mon Sep 17 00:00:00 2001 From: Neil Horman Date: Tue, 9 May 2017 13:41:12 -0400 Subject: [PATCH 1/3] Enhance error logging for failed UdevWait operations in devmapper If a wait event fails when preforming a devicemapper operation, it would be good to know, in addition to the cookie that its waiting on, we reported the error that was reported from the lvm2 library. Signed-off-by: Neil Horman --- pkg/devicemapper/devmapper.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/pkg/devicemapper/devmapper.go b/pkg/devicemapper/devmapper.go index 07161d43e8..e97d166e78 100644 --- a/pkg/devicemapper/devmapper.go +++ b/pkg/devicemapper/devmapper.go @@ -257,7 +257,7 @@ func (t *Task) getNextTarget(next unsafe.Pointer) (nextPtr unsafe.Pointer, start // UdevWait waits for any processes that are waiting for udev to complete the specified cookie. func UdevWait(cookie *uint) error { if res := DmUdevWait(*cookie); res != 1 { - logrus.Debugf("devicemapper: Failed to wait on udev cookie %d", *cookie) + logrus.Debugf("devicemapper: Failed to wait on udev cookie %d, %d", *cookie, res) return ErrUdevWait } return nil From edd1c9e3255ddd80c97313bd596812dbb3470a5b Mon Sep 17 00:00:00 2001 From: Neil Horman Date: Tue, 9 May 2017 13:42:01 -0400 Subject: [PATCH 2/3] Make cookies for devicemapper operations unique Currently, the devicemapper library sets cookies to correlate wait operations, which must be unique (as the lvm2 library doesn't detect duplicate cookies). The current method for cookie generation is to take the address of a cookie variable. However, because the variable is declared on the stack, execution patterns can lead to the cookie variable being declared at the same stack location, which results in a high likelyhood of duplicate cookie use, which in turn can lead to various odd lvm behaviors, which can be hard to track down (object use before create, duplicate completions, etc). Lets guarantee that the cookie we generate is unique by declaring it on the heap instead. This guarantees that the address of the variable won't be reused until such time as the UdevWait operation completes, and drops its reference to it, at which time the gc can reclaim it. Signed-off-by: Neil Horman --- pkg/devicemapper/devmapper.go | 30 +++++++++++++++--------------- 1 file changed, 15 insertions(+), 15 deletions(-) diff --git a/pkg/devicemapper/devmapper.go b/pkg/devicemapper/devmapper.go index e97d166e78..cc02562c16 100644 --- a/pkg/devicemapper/devmapper.go +++ b/pkg/devicemapper/devmapper.go @@ -328,11 +328,11 @@ func RemoveDevice(name string) error { return err } - var cookie uint - if err := task.setCookie(&cookie, 0); err != nil { + cookie := new(uint) + if err := task.setCookie(cookie, 0); err != nil { return fmt.Errorf("devicemapper: Can not set cookie: %s", err) } - defer UdevWait(&cookie) + defer UdevWait(cookie) dmSawBusy = false // reset before the task is run if err = task.run(); err != nil { @@ -361,10 +361,10 @@ func RemoveDeviceDeferred(name string) error { // set a task cookie and disable library fallback, or else libdevmapper will // disable udev dm rules and delete the symlink under /dev/mapper by itself, // even if the removal is deferred by the kernel. - var cookie uint + cookie := new(uint) var flags uint16 flags = DmUdevDisableLibraryFallback - if err := task.setCookie(&cookie, flags); err != nil { + if err := task.setCookie(cookie, flags); err != nil { return fmt.Errorf("devicemapper: Can not set cookie: %s", err) } @@ -377,7 +377,7 @@ func RemoveDeviceDeferred(name string) error { // this call will not wait for the deferred removal's final executing, since no // udev event will be generated, and the semaphore's value will not be incremented // by udev, what UdevWait is just cleaning up the semaphore. - defer UdevWait(&cookie) + defer UdevWait(cookie) if err = task.run(); err != nil { return fmt.Errorf("devicemapper: Error running RemoveDeviceDeferred %s", err) @@ -471,13 +471,13 @@ func CreatePool(poolName string, dataFile, metadataFile *os.File, poolBlockSize return fmt.Errorf("devicemapper: Can't add target %s", err) } - var cookie uint + cookie := new(uint) var flags uint16 flags = DmUdevDisableSubsystemRulesFlag | DmUdevDisableDiskRulesFlag | DmUdevDisableOtherRulesFlag - if err := task.setCookie(&cookie, flags); err != nil { + if err := task.setCookie(cookie, flags); err != nil { return fmt.Errorf("devicemapper: Can't set cookie %s", err) } - defer UdevWait(&cookie) + defer UdevWait(cookie) if err := task.run(); err != nil { return fmt.Errorf("devicemapper: Error running deviceCreate (CreatePool) %s", err) @@ -659,11 +659,11 @@ func ResumeDevice(name string) error { return err } - var cookie uint - if err := task.setCookie(&cookie, 0); err != nil { + cookie := new(uint) + if err := task.setCookie(cookie, 0); err != nil { return fmt.Errorf("devicemapper: Can't set cookie %s", err) } - defer UdevWait(&cookie) + defer UdevWait(cookie) if err := task.run(); err != nil { return fmt.Errorf("devicemapper: Error running deviceResume %s", err) @@ -757,12 +757,12 @@ func activateDevice(poolName string, name string, deviceID int, size uint64, ext return fmt.Errorf("devicemapper: Can't add node %s", err) } - var cookie uint - if err := task.setCookie(&cookie, 0); err != nil { + cookie := new(uint) + if err := task.setCookie(cookie, 0); err != nil { return fmt.Errorf("devicemapper: Can't set cookie %s", err) } - defer UdevWait(&cookie) + defer UdevWait(cookie) if err := task.run(); err != nil { return fmt.Errorf("devicemapper: Error running deviceCreate (ActivateDevice) %s", err) From 5206d45e70512f5fc06006047fb67b2f478b304d Mon Sep 17 00:00:00 2001 From: Neil Horman Date: Tue, 9 May 2017 13:30:10 -0400 Subject: [PATCH 3/3] Move UdevWait from defer to inline All LVM actions in the devicemapper library are asyncronous, involving a call to a task enqueue function (dm_run_task) and a wait on a resultant udev event (UdevWait). Currently devmapper.go defers all calls to UdevWait, which discards the return value. While it still generates an error message in the log (if debugging is enabled), the calling thread is still allowed to continue as if no error has occured, leading to subsequent errors, and significant confusion when debugging, due to those subsequent errors. Given that there is no risk of panic between the task submission and the wait operation, it seems more reasonable to preform the UdevWait inline at the end of any given lvm action so that errors can be caught and returned before docker can continue and create additional failures. Signed-off-by: Neil Horman --- pkg/devicemapper/devmapper.go | 24 +++++++++--------------- 1 file changed, 9 insertions(+), 15 deletions(-) diff --git a/pkg/devicemapper/devmapper.go b/pkg/devicemapper/devmapper.go index cc02562c16..f0a289e098 100644 --- a/pkg/devicemapper/devmapper.go +++ b/pkg/devicemapper/devmapper.go @@ -332,7 +332,6 @@ func RemoveDevice(name string) error { if err := task.setCookie(cookie, 0); err != nil { return fmt.Errorf("devicemapper: Can not set cookie: %s", err) } - defer UdevWait(cookie) dmSawBusy = false // reset before the task is run if err = task.run(); err != nil { @@ -342,7 +341,7 @@ func RemoveDevice(name string) error { return fmt.Errorf("devicemapper: Error running RemoveDevice %s", err) } - return nil + return UdevWait(cookie) } // RemoveDeviceDeferred is a useful helper for cleaning up a device, but deferred. @@ -368,6 +367,10 @@ func RemoveDeviceDeferred(name string) error { return fmt.Errorf("devicemapper: Can not set cookie: %s", err) } + if err = task.run(); err != nil { + return fmt.Errorf("devicemapper: Error running RemoveDeviceDeferred %s", err) + } + // libdevmapper and udev relies on System V semaphore for synchronization, // semaphores created in `task.setCookie` will be cleaned up in `UdevWait`. // So these two function call must come in pairs, otherwise semaphores will @@ -377,13 +380,8 @@ func RemoveDeviceDeferred(name string) error { // this call will not wait for the deferred removal's final executing, since no // udev event will be generated, and the semaphore's value will not be incremented // by udev, what UdevWait is just cleaning up the semaphore. - defer UdevWait(cookie) - if err = task.run(); err != nil { - return fmt.Errorf("devicemapper: Error running RemoveDeviceDeferred %s", err) - } - - return nil + return UdevWait(cookie) } // CancelDeferredRemove cancels a deferred remove for a device. @@ -477,13 +475,12 @@ func CreatePool(poolName string, dataFile, metadataFile *os.File, poolBlockSize if err := task.setCookie(cookie, flags); err != nil { return fmt.Errorf("devicemapper: Can't set cookie %s", err) } - defer UdevWait(cookie) if err := task.run(); err != nil { return fmt.Errorf("devicemapper: Error running deviceCreate (CreatePool) %s", err) } - return nil + return UdevWait(cookie) } // ReloadPool is the programmatic example of "dmsetup reload". @@ -663,13 +660,12 @@ func ResumeDevice(name string) error { if err := task.setCookie(cookie, 0); err != nil { return fmt.Errorf("devicemapper: Can't set cookie %s", err) } - defer UdevWait(cookie) if err := task.run(); err != nil { return fmt.Errorf("devicemapper: Error running deviceResume %s", err) } - return nil + return UdevWait(cookie) } // CreateDevice creates a device with the specified poolName with the specified device id. @@ -762,13 +758,11 @@ func activateDevice(poolName string, name string, deviceID int, size uint64, ext return fmt.Errorf("devicemapper: Can't set cookie %s", err) } - defer UdevWait(cookie) - if err := task.run(); err != nil { return fmt.Errorf("devicemapper: Error running deviceCreate (ActivateDevice) %s", err) } - return nil + return UdevWait(cookie) } // CreateSnapDeviceRaw creates a snapshot device. Caller needs to suspend and resume the origin device if it is active.