Merge lp:~raharper/curtin/trunk.debug-mdadm into lp:~curtin-dev/curtin/trunk

[Ryan Harper]

Add clear_holders checks to disk and partition handlers

In some cases disks may contain block device metadata outside of the
current partition table. Due to Linux udev rules and behaviors;
creating or modifying a disks partition table may trigger udev rules
which may start up mdadm, bcache or lvm services which will obtain
exclusive access to the disk preventing installation from completing.

This branch addresses this issue with the following

- block.wipe_volume now uses os.O_EXCL flag to obtain exclusive access
  to a device; this fails when something else (like mdadm) obtains
  a file handle on the device with O_EXCL flag

- Upon failure to obtain exclusive access, we dump information about
  a devices block holders

- During disk handling, after creating a partition table we check for
  holders and then clear them if present.

- During partition handling, after creating a new partition we check
  for holders and then clear them if present.

Add clear_holders checks to disk and partition handlers

In some cases disks may contain block device metadata outside of the
current partition table. Due to Linux udev rules and behaviors;
creating or modifying a disks partition table may trigger udev rules
which may start up mdadm, bcache or lvm services which will obtain
exclusive access to the disk preventing installation from completing.

This branch addresses this issue with the following

- block.wipe_volume now uses os.O_EXCL flag to obtain exclusive access
  to a device; this fails when something else (like mdadm) obtains
  a file handle on the device with O_EXCL flag

- Upon failure to obtain exclusive access, we dump information about
  a devices block holders

- During disk handling, after creating a partition table we check for
  holders and then clear them if present.

- During partition handling, after creating a new partition we check
  for holders and then clear them if present.

[Server Team CI bot (server-team-bot)]

PASSED: Continuous integration, rev:443
https://jenkins.ubuntu.com/server/job/curtin-ci/299/
Executed test runs:
    SUCCESS: https://jenkins.ubuntu.com/server/job/curtin-ci/nodes=vm-amd64/299
    SUCCESS: https://jenkins.ubuntu.com/server/job/curtin-ci/nodes=vm-i386/299
    SUCCESS: https://jenkins.ubuntu.com/server/job/curtin-ci/nodes=vm-ppc64el/299
    SUCCESS: https://jenkins.ubuntu.com/server/job/curtin-ci/nodes=vm-s390x/299

Click here to trigger a rebuild:
https://jenkins.ubuntu.com/server/job/curtin-ci/299/rebuild

review: Approve (continuous-integration)

[Scott Moser (smoser)]

I think this looks good.
there are some small requests for enhancement inline.

[Ryan Harper (raharper)]

Thanks for the review. Comments inline, but mostly ACKs for me to fix.

On Mon, Jan 30, 2017 at 12:32 PM, Scott Moser <email address hidden> wrote:

> I think this looks good.
> there are some small requests for enhancement inline.
>
> Diff comments:
>
> > === modified file 'curtin/block/__init__.py'
> > --- curtin/block/__init__.py 2016-11-18 15:12:19 +0000
> > +++ curtin/block/__init__.py 2017-01-27 17:22:00 +0000
> > @@ -742,7 +754,17 @@
> > LOG.debug("%s is %s bytes. wiping with buflen=%s",
> > path, size, buflen)
> >
> > - with open(path, "rb+") as fp:
> > + try:
> > + fd = os.open(path, os.O_RDWR | os.O_EXCL)
> > + except OSError:
> > + LOG.exception("Failed to exclusively open device")
>
> which device ? I dont think we even print the path to the device at all
> here.
>

It ends up in the exception stacktrace, however, we should be explicit in
the message.
ACK

>
> > + holders = get_holders(path)
> > + LOG.error('Device holders with exclusive access: %s', holders)
> > + mount_points = util.device_is_mounted(path)
> > + LOG.error('Device mounts: %s', mount_points)
> > + raise
> > +
> > + with os.fdopen(fd, "rb+") as fp:
> > while True:
> > pbuf = readfunc(buflen)
> > pos = fp.tell()
>
> i think this is sane, and gets 'fd' above closed except in the case where
> this open fails.
> i think if os.fdopen(fd) fails, then fd will not ever get a close() on it.
> Not that it should fail, but
> " If fdopen() raises an exception, it leaves fd untouched (unclosed)"
>

Lemme look at this.

>
> > @@ -772,11 +794,18 @@
> > if not (is_block or os.path.isfile(path)):
> > raise ValueError("%s: not an existing file or block device",
> path)
> >
> > + pt_names = []
> > if partitions and is_block:
> > ptdata = sysfs_partition_data(path)
> > for kname, ptnum, start, size in ptdata:
> > - offsets.append(start)
> > - offsets.append(start + size - zero_size)
> > + pt_names.append(dev_path(kname))
> > + # offsets.append(start)
> > + # offsets.append(start + size - zero_size)
> > + pt_names.reverse()
> > +
> > + for pt in pt_names:
> > + LOG.debug('Wiping partition: %s', pt)
>
> give the device path to be cleaar:
> Wiping partitition %s on %s, pt, path
>

I think that's implicit in the pt name since it's comprised of
dev_path(kname)
Ie, it's going to be items like '/dev/sda3', '/dev/nvme0n1p1'

>
> > + quick_zero(pt, partitions=False)
> >
> > LOG.debug("wiping 1M on %s at offsets %s", path, offsets)
> > return zero_file_at_offsets(path, offsets, buflen=buflen,
> count=count)
> > @@ -796,7 +825,19 @@
> > buf = b'\0' * buflen
> > tot = buflen * count
> > msg_vals = {'path': path, 'tot': buflen * count}
> > - with open(path, "rb+") as fp:
> > +
> > + # ensure we're the only open fd on the device
> > + try:
> > + fd = os.open(path, os.O_RDWR | os.O_EXCL)
> > + except OSError:
> > + LOG.exception("Failed to exclusively open device")
>
> which device ? perhaps this fail path could...

[Ryan Harper (raharper)]

On Mon, Jan 30, 2017 at 12:32 PM, Scott Moser <email address hidden> wrote:

> I think this looks good.
> there are some small requests for enhancement inline.
>
> Diff comments:
>
> > + holders = get_holders(path)
> > + LOG.error('Device holders with exclusive access: %s', holders)
> > + mount_points = util.device_is_mounted(path)
> > + LOG.error('Device mounts: %s', mount_points)
> > + raise
> > +
> > + with os.fdopen(fd, "rb+") as fp:
> > while True:
> > pbuf = readfunc(buflen)
> > pos = fp.tell()
>
> i think this is sane, and gets 'fd' above closed except in the case where
> this open fails.
> i think if os.fdopen(fd) fails, then fd will not ever get a close() on it.
> Not that it should fail, but
> " If fdopen() raises an exception, it leaves fd untouched (unclosed)"
>

In the case the os.fdopen fails; I don't think fd is still valid for
closing. Even if it were, we cannot tell
as fd is *just* an int, which may or maynot point to a real file-descriptor
anymore.
If we blindly call os.close(fd), we may encounter an OSError ("Bad file
descriptor") if the fd is already
closed.

Lastly, as we exit wipe_file, the fd will leave scope and Python will reap
the fd.

If you can find a counter-example where we are leaking an fd, please let me
know.

Ryan

[Scott Moser (smoser)]

Heres an example on the case where hte os level file handle does not get closed.
Whether its worth handling, I'll not comment. But it is a real possibility that you
get an open file handle but the os.fdopen() fails, and thus the close never happens
that would happen on the exit from the 'with'.

#!/usr/bin/python3
import os, sys
path = sys.argv[1]
with open(path, "w") as owritefp:
    owritefp.write("hello world\n")

# fd is an open file handle here.
fd = os.open(path, os.O_RDONLY | os.O_EXCL)

# this fails beacuse rb+ is not compatible with O_RDONLY above.
# resulting in no 'close' being called on the "file object" fp.
with os.fdopen(fd, "rb+") as fp:
    fp.write("bye bye\n")

os.close(fd)

[Scott Moser (smoser)]

>
> I think that's implicit in the pt name since it's comprised of
> dev_path(kname)
> Ie, it's going to be items like '/dev/sda3', '/dev/nvme0n1p1'

Yeah, you're right. unless somehow the partition name is wrong, and that is why it failed... ie, /dev/foo!/css1
or some oddity that left us guessing what went wrong.

sm

[Ryan Harper (raharper)]

On Mon, Jan 30, 2017 at 6:56 PM, Scott Moser <email address hidden> wrote:

> Heres an example on the case where hte os level file handle does not get
> closed.
> Whether its worth handling, I'll not comment. But it is a real
> possibility that you
> get an open file handle but the os.fdopen() fails, and thus the close
> never happens
> that would happen on the exit from the 'with'.
>
>
> #!/usr/bin/python3
> import os, sys
> path = sys.argv[1]
> with open(path, "w") as owritefp:
> owritefp.write("hello world\n")\
>

Not sure what this is doing here.

> # fd is an open file handle here.
> fd = os.open(path, os.O_RDONLY | os.O_EXCL)
>
> # this fails beacuse rb+ is not compatible with O_RDONLY above.
> # resulting in no 'close' being called on the "file object" fp.
> with os.fdopen(fd, "rb+") as fp:
> fp.write("bye bye\n")
>

> os.close(fd)
>

That's not what's happening;

 #!/usr/bin/python3
import os, sys, errno

path = sys.argv[1]

# fd is an open file handle here.
fd = os.open(path, os.O_RDONLY | os.O_EXCL)

# this fails beacuse rb+ is not compatible with O_RDONLY above.
# resulting in no 'close' being called on the "file object" fp.
print("fd=%s" % fd)
try:
    with os.fdopen(fd, "rb+") as fp:
        msg = "bye bye\n".encode("utf-8")
        fp.write(msg)
except Exception as e:
    print("Failed to write to fd: %s" % e)

print("closing fd:%s" % fd)
try:
    os.close(fd)
    print("close OK")
except OSError as err:
    if err.args[0] == errno.EBADF:
        print("fd isn't a valid file descriptor (man 2 close)")
    else:
        print("some other error")

This outputs:

% python3 fd.py /tmp/foo
fd=3
Failed to write to fd: [Errno 9] Bad file descriptor
closing fd:3
fd isn't a valid file descriptor (man 2 close)

I believe what happens is that the context manager constructs a FileObject
passing in the fd,
The FileObject exit hook handles closing the fd so that when we return from
it, the fd is
already closed.

In fact, that's _exactly_ what happens. If I drop the with and just use
assignments:

try:
    fp = os.fdopen(fd, "rb+")
    msg = "bye bye\n".encode("utf-8")
    fp.write(msg)
except Exception as e:
    print("Failed to write to fd: %s" % e)

And now the output looks like this:

 % python3 fd.py /tmp/foo
fd=3
closing fd:3
close OK

> --
> https://code.launchpad.net/~raharper/curtin/trunk.debug-
> mdadm/+merge/315805
> You are the owner of lp:~raharper/curtin/trunk.debug-mdadm.
>

[Ryan Harper (raharper)]

On Mon, Jan 30, 2017 at 6:59 PM, Scott Moser <email address hidden> wrote:

> >
> > I think that's implicit in the pt name since it's comprised of
> > dev_path(kname)
> > Ie, it's going to be items like '/dev/sda3', '/dev/nvme0n1p1'
>
> Yeah, you're right. unless somehow the partition name is wrong, and that
> is why it failed... ie, /dev/foo!/css1
> or some oddity that left us guessing what went wrong.
>

I'll double check; kname comes from lsblk output, and we're just prefixing
that with /dev/ in dev_path
Not sure how that's going to be wrong. But I can print all three (kname,
partnumber, and combined)

>
> sm
>
> --
> https://code.launchpad.net/~raharper/curtin/trunk.debug-
> mdadm/+merge/315805
> You are the owner of lp:~raharper/curtin/trunk.debug-mdadm.
>

[lp:~raharper/curtin/trunk.debug-mdadm]

444. By Ryan Harper on 2017-01-31

Address MP feedback

- use err instead of _err when consuming
- Use device == entry[0] to match device mounted
- Rename device_is_mounted to list_device_mounts
- Refactor exclusive open into a contextmanager
- Be more verbose when recursively wiping partitions

[Server Team CI bot (server-team-bot)]

PASSED: Continuous integration, rev:444
https://jenkins.ubuntu.com/server/job/curtin-ci/304/
Executed test runs:
    SUCCESS: https://jenkins.ubuntu.com/server/job/curtin-ci/nodes=vm-amd64/304
    SUCCESS: https://jenkins.ubuntu.com/server/job/curtin-ci/nodes=vm-i386/304
    SUCCESS: https://jenkins.ubuntu.com/server/job/curtin-ci/nodes=vm-ppc64el/304
    SUCCESS: https://jenkins.ubuntu.com/server/job/curtin-ci/nodes=vm-s390x/304

Click here to trigger a rebuild:
https://jenkins.ubuntu.com/server/job/curtin-ci/304/rebuild

review: Approve (continuous-integration)

[Scott Moser (smoser)]

close.

[Ryan Harper (raharper)]

On Tue, Jan 31, 2017 at 3:19 PM, Scott Moser <email address hidden> wrote:

> close.
>
>
> Diff comments:
>
> >
> > === modified file 'curtin/block/clear_holders.py'
> > --- curtin/block/clear_holders.py 2016-08-30 21:56:13 +0000
> > +++ curtin/block/clear_holders.py 2017-01-31 20:57:11 +0000
> > @@ -62,6 +63,25 @@
> > return os.path.realpath(os.path.join(sysfs_path, 'bcache',
> 'cache'))
> >
> >
> > +def umount_device(device):
> > + """
> > + Attempt to unmount a device and any other devices which may be
> > + mounted on top of the devices mountpoint
> > + """
> > + proc_mounts = block.get_proc_mounts()
> > + mount_entries = [entry for entry in proc_mounts if device ==
> entry[0]]
> > + if len(mount_entries) > 0:
> > + for me in mount_entries:
> > + LOG.debug('Device is mounted: %s', me)
> > + mount_point = me[1]
> > + submounts = [entry for entry in proc_mounts
> > + if mount_point in entry[1]]
>
> need to do if mount_point + "/" in entry[1]
> if you had:
> /opt
> /opt2
> that would go awry, causing you to attempt to unmount /opt2. and probably
> should do startswith also.
>

I'll add unittests to get it right.

>
> submounts = [entry for entry in proc_mounts if entry[1].startswith(mount_point
> + "/")]
>
> > + umount_list = sorted(submounts, key=lambda x: x[1],
> reverse=True)
>
> i'm pretty sure this is still wrong.
> you dont want to sort submounts on the second field in /proc/mounts. that
> could go awry. You want to walk /proc/mounts in reverse. Not the somewhat
> arbitrary order that C locale sorting by the second field will give you.
>

I'll add unittests, what I really need to sort by the number of submounts,
walk to the leaf and umount on the way back.
You mentioned we have this in mount-image-callback; I'll see about bringing
that logic over to python and have a unittest.

I may drop it from this MR as this isn't needed but it's useful for
restarting control-c'd curtin installs which leave devices mounted.

I also need to add a unittest for that exclusive_open to ensure we take the
right paths, and additional unittest to test that
we invoke clear_holders in the case that we find new holders after
partitioning.

>
> > + for mp in [m[1] for m in umount_list]:
> > + LOG.debug('Umounting submounts at: %s', mp)
> > + util.do_umount(mp)
> > +
> > +
> > def shutdown_bcache(device):
> > """
> > Shut down bcache for specified bcache device
>
>
> --
> https://code.launchpad.net/~raharper/curtin/trunk.debug-
> mdadm/+merge/315805
> You are the owner of lp:~raharper/curtin/trunk.debug-mdadm.
>

[lp:~raharper/curtin/trunk.debug-mdadm]

445. By Ryan Harper on 2017-01-31

Remove incomplete unmount_device

446. By Ryan Harper on 2017-02-01

add unittest for block.exclusive_open

447. By Ryan Harper on 2017-02-01

add block_meta unittests to validate clear_holders called as needed

448. By Ryan Harper on 2017-02-01

merge from trunk

[Server Team CI bot (server-team-bot)]

PASSED: Continuous integration, rev:448
https://jenkins.ubuntu.com/server/job/curtin-ci/305/
Executed test runs:
    SUCCESS: https://jenkins.ubuntu.com/server/job/curtin-ci/nodes=vm-amd64/305
    SUCCESS: https://jenkins.ubuntu.com/server/job/curtin-ci/nodes=vm-i386/305
    SUCCESS: https://jenkins.ubuntu.com/server/job/curtin-ci/nodes=vm-ppc64el/305
    SUCCESS: https://jenkins.ubuntu.com/server/job/curtin-ci/nodes=vm-s390x/305

Click here to trigger a rebuild:
https://jenkins.ubuntu.com/server/job/curtin-ci/305/rebuild

review: Approve (continuous-integration)

[lp:~raharper/curtin/trunk.debug-mdadm]

449. By Ryan Harper on 2017-02-01

remove debugging prints in block.wipe_file

[Ryan Harper (raharper)]

Re-ran vmtests on diglett:

Ran 1015 tests in 7099.384s

OK (SKIP=1)

The skip is the apt-proxy test which is disabled on diglett.

[Server Team CI bot (server-team-bot)]

PASSED: Continuous integration, rev:449
https://jenkins.ubuntu.com/server/job/curtin-ci/306/
Executed test runs:
    SUCCESS: https://jenkins.ubuntu.com/server/job/curtin-ci/nodes=vm-amd64/306
    SUCCESS: https://jenkins.ubuntu.com/server/job/curtin-ci/nodes=vm-i386/306
    SUCCESS: https://jenkins.ubuntu.com/server/job/curtin-ci/nodes=vm-ppc64el/306
    SUCCESS: https://jenkins.ubuntu.com/server/job/curtin-ci/nodes=vm-s390x/306

Click here to trigger a rebuild:
https://jenkins.ubuntu.com/server/job/curtin-ci/306/rebuild

review: Approve (continuous-integration)

[Scott Moser (smoser)]

looks good to me. Approve.
I didn't take time to read, but please re-read your commit message to make sure it is still relevant (since we've' been through many iterations here).

[Ryan Harper (raharper)]

ACK

On Wed, Feb 1, 2017 at 9:46 AM, Scott Moser <email address hidden> wrote:

> looks good to me. Approve.
> I didn't take time to read, but please re-read your commit message to make
> sure it is still relevant (since we've' been through many iterations here).
>
> --
> https://code.launchpad.net/~raharper/curtin/trunk.debug-
> mdadm/+merge/315805
> You are the owner of lp:~raharper/curtin/trunk.debug-mdadm.
>

=== modified file 'curtin/block/__init__.py'
--- curtin/block/__init__.py	2016-11-18 15:12:19 +0000
+++ curtin/block/__init__.py	2017-02-01 15:10:46 +0000
@@ -15,12 +15,14 @@
 #   You should have received a copy of the GNU Affero General Public License
 #   along with Curtin.  If not, see <http://www.gnu.org/licenses/>.
 
+from contextlib import contextmanager
 import errno
+import itertools
 import os
+import shlex
 import stat
-import shlex
+import sys
 import tempfile
-import itertools
 
 from curtin import util
 from curtin.block import lvm
@@ -165,6 +167,18 @@
     return os.path.normpath(path)
 
 
+def get_holders(device):
+    """
+    Look up any block device holders, return list of knames
+    """
+    # block.sys_block_path works when given a /sys or /dev path
+    sysfs_path = sys_block_path(device)
+    # get holders
+    holders = os.listdir(os.path.join(sysfs_path, 'holders'))
+    LOG.debug("devname '%s' had holders: %s", device, holders)
+    return holders
+
+
 def _lsblock_pairs_to_dict(lines):
     """
     parse lsblock output and convert to dict
@@ -723,6 +737,40 @@
             check_dos_signature(device))
 
 
+@contextmanager
+def exclusive_open(path):
+    """
+    Obtain an exclusive file-handle to the file/device specified
+    """
+    print('exclusive_open running')
+    mode = 'rb+'
+    fd = None
+    if not os.path.exists(path):
+        raise ValueError("No such file at path: %s" % path)
+
+    try:
+        fd = os.open(path, os.O_RDWR | os.O_EXCL)
+        try:
+            fd_needs_closing = True
+            with os.fdopen(fd, mode) as fo:
+                yield fo
+            fd_needs_closing = False
+        except OSError:
+            LOG.exception("Failed to create file-object from fd")
+            raise
+        finally:
+            # python2 leaves fd open if there os.fdopen fails
+            if fd_needs_closing and sys.version_info.major == 2:
+                os.close(fd)
+    except OSError:
+        LOG.exception("Failed to exclusively open path: %s", path)
+        holders = get_holders(path)
+        LOG.error('Device holders with exclusive access: %s', holders)
+        mount_points = util.list_device_mounts(path)
+        LOG.error('Device mounts: %s', mount_points)
+        raise
+
+
 def wipe_file(path, reader=None, buflen=4 * 1024 * 1024):
     """
     wipe the existing file at path.
@@ -742,7 +790,7 @@
     LOG.debug("%s is %s bytes. wiping with buflen=%s",
               path, size, buflen)
 
-    with open(path, "rb+") as fp:
+    with exclusive_open(path) as fp:
         while True:
             pbuf = readfunc(buflen)
             pos = fp.tell()
@@ -772,11 +820,17 @@
     if not (is_block or os.path.isfile(path)):
         raise ValueError("%s: not an existing file or block device", path)
 
+    pt_names = []
     if partitions and is_block:
         ptdata = sysfs_partition_data(path)
         for kname, ptnum, start, size in ptdata:
-            offsets.append(start)
-            offsets.append(start + size - zero_size)
+            pt_names.append((dev_path(kname), kname, ptnum))
+        pt_names.reverse()
+
+    for (pt, kname, ptnum) in pt_names:
+        LOG.debug('Wiping path: dev:%s kname:%s partnum:%s',
+                  pt, kname, ptnum)
+        quick_zero(pt, partitions=False)
 
     LOG.debug("wiping 1M on %s at offsets %s", path, offsets)
     return zero_file_at_offsets(path, offsets, buflen=buflen, count=count)
@@ -796,7 +850,8 @@
     buf = b'\0' * buflen
     tot = buflen * count
     msg_vals = {'path': path, 'tot': buflen * count}
-    with open(path, "rb+") as fp:
+
+    with exclusive_open(path) as fp:
         # get the size by seeking to end.
         fp.seek(0, 2)
         size = fp.tell()

=== modified file 'curtin/block/clear_holders.py'
--- curtin/block/clear_holders.py	2016-08-30 21:56:13 +0000
+++ curtin/block/clear_holders.py	2017-02-01 15:10:46 +0000
@@ -25,6 +25,7 @@
 
 from curtin import (block, udev, util)
 from curtin.block import lvm
+from curtin.block import mdadm
 from curtin.log import LOG
 
 
@@ -118,8 +119,8 @@
     """
     blockdev = block.sysfs_to_devpath(device)
     LOG.debug('using mdadm.mdadm_stop on dev: %s', blockdev)
-    block.mdadm.mdadm_stop(blockdev)
-    block.mdadm.mdadm_remove(blockdev)
+    mdadm.mdadm_stop(blockdev)
+    mdadm.mdadm_remove(blockdev)
 
 
 def wipe_superblock(device):
@@ -369,7 +370,7 @@
     # but there was not enough to start the array, the call to wipe_volume on
     # all disks and partitions should be sufficient to remove the mdadm
     # metadata
-    block.mdadm.mdadm_assemble(scan=True, ignore_errors=True)
+    mdadm.mdadm_assemble(scan=True, ignore_errors=True)
     # the bcache module needs to be present to properly detect bcache devs
     # on some systems (precise without hwe kernel) it may not be possible to
     # lad the bcache module bcause it is not present in the kernel. if this

=== modified file 'curtin/block/mdadm.py'
--- curtin/block/mdadm.py	2016-08-30 21:56:13 +0000
+++ curtin/block/mdadm.py	2017-02-01 15:10:46 +0000
@@ -28,6 +28,7 @@
 from subprocess import CalledProcessError
 
 from curtin.block import (dev_short, dev_path, is_valid_device, sys_block_path)
+from curtin.block import get_holders
 from curtin import (util, udev)
 from curtin.log import LOG
 
@@ -138,7 +139,12 @@
         # mdadm assemble returns 2 when called on an array that is already
         # assembled. this is not an error, so accept return code of 2
         # all other return codes can be accepted with ignore_error set to true
-        util.subp(cmd, capture=True, rcs=[0, 1, 2])
+        scan, err = util.subp(cmd, capture=True, rcs=[0, 1, 2])
+        LOG.debug('mdadm assemble scan results:\n%s\n%s', scan, err)
+        scan, err = util.subp(['mdadm', '--detail', '--scan', '-v'],
+                              capture=True, rcs=[0, 1])
+        LOG.debug('mdadm detail scan after assemble:\n%s\n%s',
+                  scan, err)
     except util.ProcessExecutionError:
         LOG.warning("mdadm_assemble had unexpected return code")
         if not ignore_errors:
@@ -177,6 +183,11 @@
         cmd.append("--name=%s" % md_name)
 
     for device in devices:
+        # mdadm can be sticky, double check
+        holders = get_holders(device)
+        if len(holders) > 0:
+            LOG.warning('Detected holders during mdadm creation: %s', holders)
+            raise OSError('Failed to remove holders from %s', device)
         # Zero out device superblock just in case device has been used for raid
         # before, as this will cause many issues
         util.subp(["mdadm", "--zero-superblock", device], capture=True)
@@ -206,7 +217,12 @@
             LOG.debug('available md modules: \n%s' % out)
         else:
             LOG.debug('no available md modules found')
+
+        for dev in devices + spares:
+            h = get_holders(dev)
+            LOG.debug('Device %s has holders: %s', dev, h)
         raise
+
     util.subp(["udevadm", "control", "--start-exec-queue"])
     util.subp(["udevadm", "settle",
                "--exit-if-exists=%s" % md_devname])
@@ -241,14 +257,17 @@
     assert_valid_devpath(devpath)
 
     LOG.info("mdadm stopping: %s" % devpath)
-    util.subp(["mdadm", "--stop", devpath], rcs=[0, 1], capture=True)
+    out, err = util.subp(["mdadm", "--stop", devpath], capture=True)
+    LOG.debug("mdadm stop:\n%s\n%s", out, err)
 
 
 def mdadm_remove(devpath):
     assert_valid_devpath(devpath)
 
     LOG.info("mdadm removing: %s" % devpath)
-    util.subp(["mdadm", "--remove", devpath], rcs=[0, 1], capture=True)
+    out, err = util.subp(["mdadm", "--remove", devpath],
+                         rcs=[0], capture=True)
+    LOG.debug("mdadm remove:\n%s\n%s", out, err)
 
 
 def mdadm_query_detail(md_devname, export=MDADM_USE_EXPORT):

=== modified file 'curtin/commands/block_meta.py'
--- curtin/commands/block_meta.py	2016-12-02 02:01:20 +0000
+++ curtin/commands/block_meta.py	2017-02-01 15:10:46 +0000
@@ -367,6 +367,11 @@
                 util.subp(["parted", disk, "--script", "mklabel", "msdos"])
             else:
                 raise ValueError('invalid partition table type: %s', ptable)
+        holders = clear_holders.get_holders(disk)
+        if len(holders) > 0:
+            LOG.info('Detected block holders on disk %s: %s', disk, holders)
+            clear_holders.clear_holders(disk)
+            clear_holders.assert_clear(disk)
 
     # Make the name if needed
     if info.get('name'):
@@ -538,6 +543,15 @@
     else:
         raise ValueError("parent partition has invalid partition table")
 
+    # check if we've triggered hidden metadata like md, lvm or bcache
+    part_kname = get_path_to_storage_volume(info.get('id'), storage_config)
+    holders = clear_holders.get_holders(part_kname)
+    if len(holders) > 0:
+        LOG.debug('Detected block holders on partition %s: %s', part_kname,
+                  holders)
+        clear_holders.clear_holders(part_kname)
+        clear_holders.assert_clear(part_kname)
+
     # Wipe the partition if told to do so, do not wipe dos extended partitions
     # as this may damage the extended partition table
     if config.value_as_boolean(info.get('wipe')):

=== modified file 'curtin/util.py'
--- curtin/util.py	2017-01-27 19:44:39 +0000
+++ curtin/util.py	2017-02-01 15:10:46 +0000
@@ -274,6 +274,19 @@
     return False
 
 
+def list_device_mounts(device):
+    # return mount entry if device is in /proc/mounts
+    mounts = ""
+    with open("/proc/mounts", "r") as fp:
+        mounts = fp.read()
+
+    dev_mounts = []
+    for line in mounts.splitlines():
+        if line.split()[0] == device:
+            dev_mounts.append(line)
+    return dev_mounts
+
+
 def do_mount(src, target, opts=None):
     # mount src at target with opts and return True
     # if already mounted, return False

=== modified file 'tests/unittests/test_block.py'
--- tests/unittests/test_block.py	2016-11-18 15:12:19 +0000
+++ tests/unittests/test_block.py	2017-02-01 15:10:46 +0000
@@ -4,6 +4,7 @@
 import mock
 import tempfile
 import shutil
+import sys
 
 from collections import OrderedDict
 
@@ -252,6 +253,77 @@
         found = util.load_file(trgfile)
         self.assertEqual(data, found)
 
+    def test_exclusive_open_raise_missing(self):
+        myfile = self.tfile("no-such-file")
+
+        with self.assertRaises(ValueError):
+            with block.exclusive_open(myfile) as fp:
+                fp.close()
+
+    @mock.patch('os.close')
+    @mock.patch('os.fdopen')
+    @mock.patch('os.open')
+    def test_exclusive_open(self, mock_os_open, mock_os_fdopen, mock_os_close):
+        flen = 1024
+        myfile = self.tfile("my_exclusive_file")
+        util.write_file(myfile, flen * b'\1', omode="wb")
+        mock_fd = 3
+        mock_os_open.return_value = mock_fd
+
+        with block.exclusive_open(myfile) as fp:
+            fp.close()
+
+        mock_os_open.assert_called_with(myfile, os.O_RDWR | os.O_EXCL)
+        mock_os_fdopen.assert_called_with(mock_fd, 'rb+')
+        self.assertEqual([], mock_os_close.call_args_list)
+
+    @mock.patch('os.close')
+    @mock.patch('curtin.util.list_device_mounts')
+    @mock.patch('curtin.block.get_holders')
+    @mock.patch('os.open')
+    def test_exclusive_open_non_exclusive_exception(self, mock_os_open,
+                                                    mock_holders,
+                                                    mock_list_mounts,
+                                                    mock_os_close):
+        flen = 1024
+        myfile = self.tfile("my_exclusive_file")
+        util.write_file(myfile, flen * b'\1', omode="wb")
+        mock_os_open.side_effect = OSError("NO_O_EXCL")
+        mock_holders.return_value = ['md1']
+        mock_list_mounts.return_value = []
+
+        with self.assertRaises(OSError):
+            with block.exclusive_open(myfile) as fp:
+                fp.close()
+
+        mock_os_open.assert_called_with(myfile, os.O_RDWR | os.O_EXCL)
+        mock_holders.assert_called_with(myfile)
+        mock_list_mounts.assert_called_with(myfile)
+        self.assertEqual([], mock_os_close.call_args_list)
+
+    @mock.patch('os.close')
+    @mock.patch('os.fdopen')
+    @mock.patch('os.open')
+    def test_exclusive_open_fdopen_failure(self, mock_os_open,
+                                           mock_os_fdopen, mock_os_close):
+        flen = 1024
+        myfile = self.tfile("my_exclusive_file")
+        util.write_file(myfile, flen * b'\1', omode="wb")
+        mock_fd = 3
+        mock_os_open.return_value = mock_fd
+        mock_os_fdopen.side_effect = OSError("EBADF")
+
+        with self.assertRaises(OSError):
+            with block.exclusive_open(myfile) as fp:
+                fp.close()
+
+        mock_os_open.assert_called_with(myfile, os.O_RDWR | os.O_EXCL)
+        mock_os_fdopen.assert_called_with(mock_fd, 'rb+')
+        if sys.version_info.major == 2:
+            mock_os_close.assert_called_with(mock_fd)
+        else:
+            self.assertEqual([], mock_os_close.call_args_list)
+
 
 class TestWipeVolume(TestCase):
     dev = '/dev/null'

=== modified file 'tests/unittests/test_block_mdadm.py'
--- tests/unittests/test_block_mdadm.py	2016-09-14 19:52:06 +0000
+++ tests/unittests/test_block_mdadm.py	2017-02-01 15:10:46 +0000
@@ -34,17 +34,26 @@
 
     def test_mdadm_assemble_scan(self):
         mdadm.mdadm_assemble(scan=True)
-        self.mock_util.subp.assert_called_with(
-            ["mdadm", "--assemble", "--scan", "-v"], capture=True,
-            rcs=[0, 1, 2])
+        assemble_calls = [
+            call(["mdadm", "--assemble", "--scan", "-v"], capture=True,
+                 rcs=[0, 1, 2]),
+            call(["mdadm", "--detail", "--scan", "-v"], capture=True,
+                 rcs=[0, 1]),
+        ]
+        self.mock_util.subp.assert_has_calls(assemble_calls)
         self.assertTrue(self.mock_udev.udevadm_settle.called)
 
     def test_mdadm_assemble_md_devname(self):
         md_devname = "/dev/md0"
         mdadm.mdadm_assemble(md_devname=md_devname)
-        self.mock_util.subp.assert_called_with(
-            ["mdadm", "--assemble", md_devname, "--run"], capture=True,
-            rcs=[0, 1, 2])
+
+        assemble_calls = [
+            call(["mdadm", "--assemble", md_devname, "--run"],
+                 capture=True, rcs=[0, 1, 2]),
+            call(["mdadm", "--detail", "--scan", "-v"], capture=True,
+                 rcs=[0, 1]),
+        ]
+        self.mock_util.subp.assert_has_calls(assemble_calls)
         self.assertTrue(self.mock_udev.udevadm_settle.called)
 
     def test_mdadm_assemble_md_devname_short(self):
@@ -61,9 +70,13 @@
         md_devname = "/dev/md0"
         devices = ["/dev/vdc1", "/dev/vdd1"]
         mdadm.mdadm_assemble(md_devname=md_devname, devices=devices)
-        self.mock_util.subp.assert_called_with(
-            ["mdadm", "--assemble", md_devname, "--run"] + devices,
-            capture=True, rcs=[0, 1, 2])
+        assemble_calls = [
+            call(["mdadm", "--assemble", md_devname, "--run"] + devices,
+                 capture=True, rcs=[0, 1, 2]),
+            call(["mdadm", "--detail", "--scan", "-v"], capture=True,
+                 rcs=[0, 1]),
+        ]
+        self.mock_util.subp.assert_has_calls(assemble_calls)
         self.assertTrue(self.mock_udev.udevadm_settle.called)
 
     def test_mdadm_assemble_exec_error(self):
@@ -85,10 +98,12 @@
         super(TestBlockMdadmCreate, self).setUp()
         self.add_patch('curtin.block.mdadm.util', 'mock_util')
         self.add_patch('curtin.block.mdadm.is_valid_device', 'mock_valid')
+        self.add_patch('curtin.block.mdadm.get_holders', 'mock_holders')
 
         # Common mock settings
         self.mock_valid.return_value = True
         self.mock_util.lsb_release.return_value = {'codename': 'precise'}
+        self.mock_holders.return_value = []
 
     def prepare_mock(self, md_devname, raidlevel, devices, spares):
         side_effects = []
@@ -333,7 +348,7 @@
         device = "/dev/vdc"
         mdadm.mdadm_stop(device)
         expected_calls = [
-            call(["mdadm", "--stop", device], rcs=[0, 1], capture=True),
+            call(["mdadm", "--stop", device], capture=True),
         ]
         self.mock_util.subp.assert_has_calls(expected_calls)
 
@@ -359,7 +374,7 @@
         device = "/dev/vdc"
         mdadm.mdadm_remove(device)
         expected_calls = [
-            call(["mdadm", "--remove", device], rcs=[0, 1], capture=True),
+            call(["mdadm", "--remove", device], rcs=[0], capture=True),
         ]
         self.mock_util.subp.assert_has_calls(expected_calls)
 

=== modified file 'tests/unittests/test_clear_holders.py'
--- tests/unittests/test_clear_holders.py	2016-09-14 19:38:32 +0000
+++ tests/unittests/test_clear_holders.py	2017-02-01 15:10:46 +0000
@@ -172,13 +172,14 @@
             ['cryptsetup', 'remove', self.test_blockdev], capture=True)
 
     @mock.patch('curtin.block.clear_holders.LOG')
+    @mock.patch('curtin.block.clear_holders.mdadm')
     @mock.patch('curtin.block.clear_holders.block')
-    def test_shutdown_mdadm(self, mock_block, mock_log):
+    def test_shutdown_mdadm(self, mock_block, mock_mdadm, mock_log):
         """test clear_holders.shutdown_mdadm"""
         mock_block.sysfs_to_devpath.return_value = self.test_blockdev
         clear_holders.shutdown_mdadm(self.test_syspath)
-        mock_block.mdadm.mdadm_stop.assert_called_with(self.test_blockdev)
-        mock_block.mdadm.mdadm_remove.assert_called_with(self.test_blockdev)
+        mock_mdadm.mdadm_stop.assert_called_with(self.test_blockdev)
+        mock_mdadm.mdadm_remove.assert_called_with(self.test_blockdev)
         self.assertTrue(mock_log.debug.called)
 
     @mock.patch('curtin.block.clear_holders.LOG')
@@ -320,7 +321,7 @@
         mock_gen_holders_tree.return_value = self.example_holders_trees[1][1]
         clear_holders.assert_clear(device)
 
-    @mock.patch('curtin.block.clear_holders.block.mdadm')
+    @mock.patch('curtin.block.clear_holders.mdadm')
     @mock.patch('curtin.block.clear_holders.util')
     def test_start_clear_holders_deps(self, mock_util, mock_mdadm):
         clear_holders.start_clear_holders_deps()

=== added file 'tests/unittests/test_commands_block_meta.py'
--- tests/unittests/test_commands_block_meta.py	1970-01-01 00:00:00 +0000
+++ tests/unittests/test_commands_block_meta.py	2017-02-01 15:10:46 +0000
@@ -0,0 +1,118 @@
+from unittest import TestCase
+from mock import patch
+
+from curtin.commands import block_meta
+
+
+class BlockMetaTestBase(TestCase):
+    def setUp(self):
+        super(BlockMetaTestBase, self).setUp()
+
+    def add_patch(self, target, attr):
+        """Patches specified target object and sets it as attr on test
+        instance also schedules cleanup"""
+        m = patch(target, autospec=True)
+        p = m.start()
+        self.addCleanup(m.stop)
+        setattr(self, attr, p)
+
+
+class TestBlockMeta(BlockMetaTestBase):
+    def setUp(self):
+        super(TestBlockMeta, self).setUp()
+        # self.target = tempfile.mkdtemp()
+
+        basepath = 'curtin.commands.block_meta.'
+        self.add_patch(basepath + 'get_path_to_storage_volume', 'mock_getpath')
+        self.add_patch(basepath + 'make_dname', 'mock_make_dname')
+        self.add_patch('curtin.util.subp', 'mock_subp')
+        self.add_patch('curtin.block.get_part_table_type',
+                       'mock_block_get_part_table_type')
+        self.add_patch('curtin.block.wipe_volume',
+                       'mock_block_wipe_volume')
+        self.add_patch('curtin.block.path_to_kname',
+                       'mock_block_path_to_kname')
+        self.add_patch('curtin.block.sys_block_path',
+                       'mock_block_sys_block_path')
+        self.add_patch('curtin.block.clear_holders.get_holders',
+                       'mock_get_holders')
+        self.add_patch('curtin.block.clear_holders.clear_holders',
+                       'mock_clear_holders')
+        self.add_patch('curtin.block.clear_holders.assert_clear',
+                       'mock_assert_clear')
+
+        self.target = "my_target"
+        self.config = {
+            'storage': {
+                'version': 1,
+                'config': [
+                    {'grub_device': True,
+                     'id': 'sda',
+                     'name': 'sda',
+                     'path': '/wark/xxx',
+                     'ptable': 'msdos',
+                     'type': 'disk',
+                     'wipe': 'superblock'},
+                    {'device': 'sda',
+                     'flag': 'boot',
+                     'id': 'sda-part1',
+                     'name': 'sda-part1',
+                     'number': 1,
+                     'offset': '4194304B',
+                     'size': '511705088B',
+                     'type': 'partition',
+                     'uuid': 'fc7ab24c-b6bf-460f-8446-d3ac362c0625',
+                     'wipe': 'superblock'}
+                ],
+            }
+        }
+        self.storage_config = (
+            block_meta.extract_storage_ordered_dict(self.config))
+
+    def test_disk_handler_calls_clear_holder(self):
+        info = self.storage_config.get('sda')
+        disk = info.get('path')
+        self.mock_getpath.return_value = disk
+        self.mock_block_get_part_table_type.return_value = 'dos'
+        self.mock_subp.side_effect = iter([
+            (0, 0),  # parted mklabel
+        ])
+        holders = ['md1']
+        self.mock_get_holders.return_value = holders
+
+        block_meta.disk_handler(info, self.storage_config)
+
+        print("clear_holders: %s" % self.mock_clear_holders.call_args_list)
+        print("assert_clear: %s" % self.mock_assert_clear.call_args_list)
+        self.mock_clear_holders.assert_called_with(disk)
+        self.mock_assert_clear.assert_called_with(disk)
+
+    def test_partition_handler_calls_clear_holder(self):
+        disk_info = self.storage_config.get('sda')
+        part_info = self.storage_config.get('sda-part1')
+        disk_kname = disk_info.get('path')
+        part_kname = disk_kname + '1'
+        self.mock_getpath.side_effect = iter([
+            disk_info.get('id'),
+            part_kname,
+            part_kname,
+            part_kname,
+        ])
+
+        self.mock_block_get_part_table_type.return_value = 'dos'
+        kname = 'xxx'
+        self.mock_block_path_to_kname.return_value = kname
+        self.mock_block_sys_block_path.return_value = '/sys/class/block/xxx'
+        self.mock_subp.side_effect = iter([
+            ("", 0),  # parted mkpart
+            ("", 0),  # ??
+        ])
+        holders = ['md1']
+        self.mock_get_holders.return_value = holders
+
+        block_meta.partition_handler(part_info, self.storage_config)
+
+        print("clear_holders: %s" % self.mock_clear_holders.call_args_list)
+        print("assert_clear: %s" % self.mock_assert_clear.call_args_list)
+        self.mock_clear_holders.assert_called_with(part_kname)
+        self.mock_assert_clear.assert_called_with(part_kname)