Merge lp:~raharper/curtin/trunk.fix-bcache-sysfs-write-failures-on-remove into lp:~curtin-dev/curtin/trunk

[Ryan Harper]

bcache: accept sysfs write failure in shutdown handler if path missing

Bcache device shutdown is asynchronus. The kernel may remove the
device after we've tested to see if the device needs to be stopped but
before we issue a 'stop' command to the bcache sysfs file.

When that happens, curtin throws an exception; this patch catches
those and tests if the target path is missing; and if so, ignores the
error as it's expected due to device removal.

All other write failures where the path is still present are still
valid and reported.

LP: #1700564

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

PASSED: Continuous integration, rev:526
https://jenkins.ubuntu.com/server/job/curtin-ci/622/
Executed test runs:
    SUCCESS: https://jenkins.ubuntu.com/server/job/curtin-ci/nodes=metal-amd64/622
    SUCCESS: https://jenkins.ubuntu.com/server/job/curtin-ci/nodes=metal-arm64/622
    SUCCESS: https://jenkins.ubuntu.com/server/job/curtin-ci/nodes=metal-ppc64el/622
    SUCCESS: https://jenkins.ubuntu.com/server/job/curtin-ci/nodes=metal-s390x/622

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

review: Approve (continuous-integration)

[Ryan Harper (raharper)]

vmtest subset run:

+ ./tools/jenkins-runner -p 4 tests/vmtests/test_bcache_basic.py tests/vmtests/test_mdadm_bcache.py tests/vmtests/test_raid5_bcache.py
...
Ran 395 tests in 2160.668s

OK
Thu, 14 Sep 2017 16:42:19 +0000: vmtest end [0] in 2162s

Going to start up a full run; expect to see ArtfulNetwork failures, but otherwise should pass all other tests.

[lp:~raharper/curtin/trunk.fix-bcache-sysfs-write-failures-on-remove]

527. By Ryan Harper on 2017-09-14

merge from trunk

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

PASSED: Continuous integration, rev:527
https://jenkins.ubuntu.com/server/job/curtin-ci/623/
Executed test runs:
    SUCCESS: https://jenkins.ubuntu.com/server/job/curtin-ci/nodes=metal-amd64/623
    SUCCESS: https://jenkins.ubuntu.com/server/job/curtin-ci/nodes=metal-arm64/623
    SUCCESS: https://jenkins.ubuntu.com/server/job/curtin-ci/nodes=metal-ppc64el/623
    SUCCESS: https://jenkins.ubuntu.com/server/job/curtin-ci/nodes=metal-s390x/623

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

review: Approve (continuous-integration)

[Scott Moser (smoser)]

My only comments are that I really think it doesn't hurt to see the value of the error at a debug level.

I know you've had dis-interest in doing that before. but I just think its useful information.

except (IOError, OSError) as e:
    LOG.debug('bcache stop file %s not present, device removed: %s', bcache_stop, e)

review: Approve

[lp:~raharper/curtin/trunk.fix-bcache-sysfs-write-failures-on-remove]

528. By Ryan Harper on 2017-09-29

merge from trunk

529. By Ryan Harper on 2017-09-29

Add exception for logging

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

PASSED: Continuous integration, rev:529
https://jenkins.ubuntu.com/server/job/curtin-ci/636/
Executed test runs:
    SUCCESS: https://jenkins.ubuntu.com/server/job/curtin-ci/nodes=metal-amd64/636
    SUCCESS: https://jenkins.ubuntu.com/server/job/curtin-ci/nodes=metal-arm64/636
    SUCCESS: https://jenkins.ubuntu.com/server/job/curtin-ci/nodes=metal-ppc64el/636
    SUCCESS: https://jenkins.ubuntu.com/server/job/curtin-ci/nodes=metal-s390x/636

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

review: Approve (continuous-integration)

[lp:~raharper/curtin/trunk.fix-bcache-sysfs-write-failures-on-remove]

530. By Ryan Harper on 2017-09-29

Use errno.ENOENT to check for missing bcache stop file

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

FAILED: Continuous integration, rev:530
https://jenkins.ubuntu.com/server/job/curtin-ci/638/
Executed test runs:
    FAILURE: https://jenkins.ubuntu.com/server/job/curtin-ci/nodes=metal-amd64/638/console
    FAILURE: https://jenkins.ubuntu.com/server/job/curtin-ci/nodes=metal-arm64/638/console
    FAILURE: https://jenkins.ubuntu.com/server/job/curtin-ci/nodes=metal-ppc64el/638/console
    FAILURE: https://jenkins.ubuntu.com/server/job/curtin-ci/nodes=metal-s390x/638/console

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

review: Needs Fixing (continuous-integration)

[lp:~raharper/curtin/trunk.fix-bcache-sysfs-write-failures-on-remove]

531. By Ryan Harper on 2017-10-05

Update unittest, using errno means we skip the os.path.exists check (which can race)

532. By Ryan Harper on 2017-10-12

merge from trunk

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

PASSED: Continuous integration, rev:532
https://jenkins.ubuntu.com/server/job/curtin-ci/655/
Executed test runs:
    SUCCESS: https://jenkins.ubuntu.com/server/job/curtin-ci/nodes=metal-amd64/655
    SUCCESS: https://jenkins.ubuntu.com/server/job/curtin-ci/nodes=metal-arm64/655
    SUCCESS: https://jenkins.ubuntu.com/server/job/curtin-ci/nodes=metal-ppc64el/655
    SUCCESS: https://jenkins.ubuntu.com/server/job/curtin-ci/nodes=metal-s390x/655

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

review: Approve (continuous-integration)

[Scott Moser (smoser)]

review: Needs Information

[Ryan Harper (raharper)]

On Thu, Oct 12, 2017 at 2:56 PM, Scott Moser <email address hidden> wrote:

> Review: Needs Information
>
>
>
> Diff comments:
>
> > === modified file 'curtin/block/clear_holders.py'
> > --- curtin/block/clear_holders.py 2017-05-24 18:42:40 +0000
> > +++ curtin/block/clear_holders.py 2017-10-12 16:29:11 +0000
> > @@ -132,8 +132,13 @@
> > os.path.basename(bcache_cache_sysfs))
> > else:
> > LOG.info('stopping bcache cacheset at: %s', bcache_cache_sysfs)
> > - util.write_file(os.path.join(bcache_cache_sysfs, 'stop'),
> > - '1', mode=None)
> > + bcache_stop = os.path.join(bcache_cache_sysfs, 'stop')
> > + try:
> > + util.write_file(bcache_stop, '1', mode=None)
> > + except (IOError, OSError) as e:
> > + if e.errno == errno.ENOENT:
> > + LOG.debug('bcache stop file %s missing, device removed:
> %s',
> > + bcache_stop, e)
>
> dont you want:
> else:
> raise e
> ?
> or did you intend to be completely silent on failure except in the ENOENT
> case.
>

This is the only case where we want to eat the exception; the write to the
file
failed due to bcache kernel bits stopping. I'll add a comment to make it
more clear.

>
> > try:
> > util.wait_for_removal(bcache_cache_sysfs,
> retries=removal_retries)
> > except OSError:
>
>
> --
> https://code.launchpad.net/~raharper/curtin/trunk.fix-
> bcache-sysfs-write-failures-on-remove/+merge/330758
> You are the owner of lp:~raharper/curtin/trunk.fix-
> bcache-sysfs-write-failures-on-remove.
>

[lp:~raharper/curtin/trunk.fix-bcache-sysfs-write-failures-on-remove]

533. By Ryan Harper on 2017-10-12

Ensure we don't swallow all exceptions, only ENOENT

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

PASSED: Continuous integration, rev:533
https://jenkins.ubuntu.com/server/job/curtin-ci/656/
Executed test runs:
    SUCCESS: https://jenkins.ubuntu.com/server/job/curtin-ci/nodes=metal-amd64/656
    SUCCESS: https://jenkins.ubuntu.com/server/job/curtin-ci/nodes=metal-arm64/656
    SUCCESS: https://jenkins.ubuntu.com/server/job/curtin-ci/nodes=metal-ppc64el/656
    SUCCESS: https://jenkins.ubuntu.com/server/job/curtin-ci/nodes=metal-s390x/656

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

review: Approve (continuous-integration)

[Chad Smith (chad.smith)]

I like the fact that you've added unit tests here, but the depth of mocking on this makes for unit tests that know too much about the internal implementation of the shutdown_bcache function. which means unittests will break more frequently if we change the operations performed by shutdown_bcache. Since the try/except handling is boilerplate for both cases, let's just pull it into a helper function which can be easily tested. Here's a patch for that and the simple unit tests addditions. I believe you can also drop your two unit tests as it feels like the mock depth will make it harder to maintain.

patch: http://paste.ubuntu.com/25733308/

review: Approve

[lp:~raharper/curtin/trunk.fix-bcache-sysfs-write-failures-on-remove]

534. By Ryan Harper on 2017-10-13

Use common bcache_maybe_remove handler for simpler unittests

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

PASSED: Continuous integration, rev:534
https://jenkins.ubuntu.com/server/job/curtin-ci/657/
Executed test runs:
    SUCCESS: https://jenkins.ubuntu.com/server/job/curtin-ci/nodes=metal-amd64/657
    SUCCESS: https://jenkins.ubuntu.com/server/job/curtin-ci/nodes=metal-arm64/657
    SUCCESS: https://jenkins.ubuntu.com/server/job/curtin-ci/nodes=metal-ppc64el/657
    SUCCESS: https://jenkins.ubuntu.com/server/job/curtin-ci/nodes=metal-s390x/657

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

review: Approve (continuous-integration)

=== modified file 'curtin/block/clear_holders.py'
--- curtin/block/clear_holders.py	2017-05-24 18:42:40 +0000
+++ curtin/block/clear_holders.py	2017-10-13 17:48:44 +0000
@@ -93,6 +93,22 @@
     return path
 
 
+def maybe_stop_bcache_device(device):
+    """Attempt to stop the provided device_path or raise unexpected errors."""
+    bcache_stop = os.path.join(device, 'stop')
+    try:
+        util.write_file(bcache_stop, '1', mode=None)
+    except (IOError, OSError) as e:
+        # Note: if we get a write failure and the exception is that the
+        # file is not found; we log this expected behavior; any other
+        # exception is raised
+        if e.errno == errno.ENOENT:
+            LOG.debug('bcache stop file %s missing, device removed: %s',
+                      bcache_stop, e)
+        else:
+            raise e
+
+
 def shutdown_bcache(device):
     """
     Shut down bcache for specified bcache device
@@ -132,8 +148,7 @@
                  os.path.basename(bcache_cache_sysfs))
     else:
         LOG.info('stopping bcache cacheset at: %s', bcache_cache_sysfs)
-        util.write_file(os.path.join(bcache_cache_sysfs, 'stop'),
-                        '1', mode=None)
+        maybe_stop_bcache_device(bcache_cache_sysfs)
         try:
             util.wait_for_removal(bcache_cache_sysfs, retries=removal_retries)
         except OSError:
@@ -162,8 +177,7 @@
         return
     else:
         LOG.info('stopping bcache backing device at: %s', bcache_block_sysfs)
-        util.write_file(os.path.join(bcache_block_sysfs, 'stop'),
-                        '1', mode=None)
+        maybe_stop_bcache_device(bcache_block_sysfs)
         try:
             # wait for them all to go away
             for dev in [device, bcache_block_sysfs] + slave_paths:

=== modified file 'tests/unittests/test_clear_holders.py'
--- tests/unittests/test_clear_holders.py	2017-08-02 20:55:03 +0000
+++ tests/unittests/test_clear_holders.py	2017-10-13 17:48:44 +0000
@@ -1,3 +1,4 @@
+import errno
 import mock
 import os
 import textwrap
@@ -329,6 +330,52 @@
             mock.call(cset, retries=self.remove_retries)
         ])
 
+    # test bcache shutdown with 'stop' sysfs write failure
+    @mock.patch('curtin.block.clear_holders.udev.udevadm_settle')
+    @mock.patch('curtin.block.clear_holders.get_bcache_sys_path')
+    @mock.patch('curtin.block.clear_holders.util')
+    @mock.patch('curtin.block.clear_holders.os')
+    @mock.patch('curtin.block.clear_holders.LOG')
+    @mock.patch('curtin.block.clear_holders.get_bcache_using_dev')
+    def test_shutdown_bcache_stop_sysfs_write_fails(self, mock_get_bcache,
+                                                    mock_log, mock_os,
+                                                    mock_util,
+                                                    mock_get_bcache_block,
+                                                    mock_udevadm_settle):
+        """Test writes sysfs write failures pass if file not present"""
+        device = "/sys/class/block/null"
+        mock_os.path.exists.side_effect = iter([
+                True,   # backing device exists
+                True,   # cset device not present (already removed)
+                False,  # backing device is removed with cset
+                False,  # bcache/stop sysfs is missing (already removed)
+        ])
+        cset = '/sys/fs/bcache/fake'
+        mock_get_bcache.return_value = cset
+        mock_get_bcache_block.return_value = device + '/bcache'
+        mock_os.path.join.side_effect = os.path.join
+
+        # make writes to sysfs fail
+        mock_util.write_file.side_effect = IOError(errno.ENOENT,
+                                                   "File not found")
+
+        clear_holders.shutdown_bcache(device)
+
+        self.assertEqual(2, len(mock_log.info.call_args_list))
+        self.assertEqual(3, len(mock_os.path.exists.call_args_list))
+        self.assertEqual(1, len(mock_get_bcache.call_args_list))
+        self.assertEqual(1, len(mock_get_bcache_block.call_args_list))
+        self.assertEqual(1, len(mock_util.write_file.call_args_list))
+        self.assertEqual(1, len(mock_util.wait_for_removal.call_args_list))
+
+        mock_get_bcache.assert_called_with(device, strict=False)
+        mock_util.write_file.assert_has_calls([
+            mock.call(cset + '/stop', '1', mode=None),
+        ])
+        mock_util.wait_for_removal.assert_has_calls([
+            mock.call(cset, retries=self.remove_retries)
+        ])
+
     @mock.patch('curtin.block.clear_holders.LOG')
     @mock.patch('curtin.block.clear_holders.block.sys_block_path')
     @mock.patch('curtin.block.clear_holders.lvm')
@@ -531,6 +578,41 @@
         for tree, result in test_trees_and_results:
             self.assertEqual(clear_holders.format_holders_tree(tree), result)
 
+    @mock.patch('curtin.block.clear_holders.util.write_file')
+    def test_maybe_stop_bcache_device_raises_errors(self, m_write_file):
+        """Unexpected exceptions are raised by maybe_stop_bcache_device."""
+        m_write_file.side_effect = OSError(errno.EAGAIN, 'Unexpected errno')
+        with self.assertRaises(OSError) as cm:
+            clear_holders.maybe_stop_bcache_device('does/not/matter')
+        self.assertEqual('[Errno 11] Unexpected errno', str(cm.exception))
+        self.assertEqual(
+            mock.call('does/not/matter/stop', '1', mode=None),
+            m_write_file.call_args)
+
+    @mock.patch('curtin.block.clear_holders.LOG')
+    @mock.patch('curtin.block.clear_holders.util.write_file')
+    def test_maybe_stop_bcache_device_handles_oserror(self, m_write_file,
+                                                      m_log):
+        """When OSError.NOENT is raised, log the condition and move on."""
+        m_write_file.side_effect = OSError(errno.ENOENT, 'Expected oserror')
+        clear_holders.maybe_stop_bcache_device('does/not/matter')
+        self.assertEqual(
+            'bcache stop file %s missing, device removed: %s',
+            m_log.debug.call_args[0][0])
+        self.assertEqual('does/not/matter/stop', m_log.debug.call_args[0][1])
+
+    @mock.patch('curtin.block.clear_holders.LOG')
+    @mock.patch('curtin.block.clear_holders.util.write_file')
+    def test_maybe_stop_bcache_device_handles_ioerror(self, m_write_file,
+                                                      m_log):
+        """When IOError.NOENT is raised, log the condition and move on."""
+        m_write_file.side_effect = IOError(errno.ENOENT, 'Expected ioerror')
+        clear_holders.maybe_stop_bcache_device('does/not/matter')
+        self.assertEqual(
+            'bcache stop file %s missing, device removed: %s',
+            m_log.debug.call_args[0][0])
+        self.assertEqual('does/not/matter/stop', m_log.debug.call_args[0][1])
+
     def test_get_holder_types(self):
         """test clear_holders.get_holder_types"""
         test_trees_and_results = [