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

[Ryan Harper]

content decoding in load_file, apply_net raise exception on errors

This patch series fixes two issues. First, subcommands of the apply_net
command were exiting non-zero but we failed to raise and exception
which let curtin hide an error. We've modified apply_net to re-raise
the exception when it occurs. Additionally update vmtest to look for
stack-traces in the installation log and mark a test failed if it
detects one; this should prevent future cases from re-occurring.

The second error is when loading a file with and encoding, load_file
did not handle this case. Merge in a version of load_file from
cloud-init which already handles this case. Introduce new
unittests to validate the function as it touches some block related
code where we read partition data directly.

Finally, the mock_open feature of unittest.mock only supports
binary data in version 2.0.0 or newer, so skip this unittest on
systems without a new-enough mock; note this does not affect
the function of the code on the same release, only the unittest.

content decoding in load_file, apply_net raise exception on errors

This patch series fixes two issues. First, subcommands of the apply_net
command were exiting non-zero but we failed to raise and exception
which let curtin hide an error. We've modified apply_net to re-raise
the exception when it occurs. Additionally update vmtest to look for
stack-traces in the installation log and mark a test failed if it
detects one; this should prevent future cases from re-occurring.

The second error is when loading a file with and encoding, load_file
did not handle this case. Merge in a version of load_file from
cloud-init which already handles this case. Introduce new
unittests to validate the function as it touches some block related
code where we read partition data directly.

Finally, the mock_open feature of unittest.mock only supports
binary data in version 2.0.0 or newer, so skip this unittest on
systems without a new-enough mock; note this does not affect
the function of the code on the same release, only the unittest.

[lp:~raharper/curtin/trunk.lp1635560]

435. By Ryan Harper on 2017-01-12

merge from trunk

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

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

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

review: Approve (continuous-integration)

[lp:~raharper/curtin/trunk.lp1635560]

436. By Ryan Harper on 2017-01-19

merge from trunk

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

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

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

review: Approve (continuous-integration)

[Scott Moser (smoser)]

I'm kind of worreid about a behavior change in default usage of load_file.
Previously load_file without a mode argument would open in 'r' mode. It would would always return a string, and would raise exception if the read in non-binary mode failed.

Now we're changing that to
 open in rb mode
 raise exception if decode() fails.

I'm afraid their might be subtle differences between what we had:
  open(file, "r").read()
and the new:
  open(file, "rb").read().decode("utf-8", "replace")

I don't have an example, but I'm afraid there might be differences.

[Ryan Harper (raharper)]

On Fri, Jan 20, 2017 at 12:37 PM, Scott Moser <email address hidden> wrote:

> I'm kind of worreid about a behavior change in default usage of load_file.
> Previously load_file without a mode argument would open in 'r' mode. It
> would would always return a string, and would raise exception if the read
> in non-binary mode failed.
>
> Now we're changing that to
> open in rb mode
> raise exception if decode() fails.
>
> I'm afraid their might be subtle differences between what we had:
> open(file, "r").read()
> and the new:
> open(file, "rb").read().decode("utf-8", "replace")
>
> I don't have an example, but I'm afraid there might be differences.
>

Agreed, though this is how we do this in cloud-init.
I've found places in code where we do use load_file with the expected
non-decoding case
and have run vmtests to verify that all that still works.

>
> Diff comments:
>
> >
> > === modified file 'curtin/util.py'
> > --- curtin/util.py 2016-11-30 16:00:39 +0000
> > +++ curtin/util.py 2017-01-19 17:21:37 +0000
> > @@ -321,11 +321,23 @@
> > os.chmod(filename, mode)
> >
> >
> > -def load_file(path, mode="r", read_len=None, offset=0):
> > +def load_file(path, mode="rb", read_len=None, offset=0, decode=True):
> > with open(path, mode) as fp:
> > if offset:
> > fp.seek(offset)
> > - return fp.read(read_len) if read_len else fp.read()
> > + contents = fp.read(read_len) if read_len else fp.read()
> > +
> > + if decode:
>
> maybe:
> if decode and 'b' in mode
>

OK.

>
> > + return decode_binary(contents)
> > + else:
> > + return contents
> > +
> > +
>
> the decode_binary in cloud-init is someewhat of a hack, and i'd much
> rather not have it there.
> Instead, I'd rather have the caller know what they have and decode if they
> need it rather than the 'isinstance' test.
>

Well, the instance check is the workaround of not using six for byte vs.
string between python 2 and 3.
I think it makes as-is; the point of util is handle some of these
complexities to simplify the code elsewhere.

> I'm ok with decode_binary, but i'd prefer it not to do the isinstance
> chec,.
>

Hrm, I not sure this works without the check across py2 and py3 .

>
> > +def decode_binary(blob, encoding='utf-8', errors='replace'):
> > + # Converts a binary type into a text type using given encoding.
> > + if isinstance(blob, string_types):
> > + return blob
> > + return blob.decode(encoding, errors=errors)
> >
> >
> > def file_size(path):
>
>
> --
> https://code.launchpad.net/~raharper/curtin/trunk.lp1635560/+merge/314645
> You are the owner of lp:~raharper/curtin/trunk.lp1635560.
>

[lp:~raharper/curtin/trunk.lp1635560]

437. By Ryan Harper on 2017-01-19

vmtest: make install-log error checking more obvious

438. By Ryan Harper on 2017-01-24

Modify known error message to not trip install failure detection

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

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

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

review: Approve (continuous-integration)

[lp:~raharper/curtin/trunk.lp1635560]

439. By Ryan Harper on 2017-01-25

util: only call decode_binary when needed, decode_binary only decodes binary

440. By Ryan Harper on 2017-01-25

merge from trunk

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

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

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

review: Approve (continuous-integration)

[lp:~raharper/curtin/trunk.lp1635560]

441. By Ryan Harper on 2017-01-27

merge from trunk

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

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

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

review: Approve (continuous-integration)

[Scott Moser (smoser)]

I guess I approve, with the one question inline.
I do think our load_file is kind of wierd still though..
cloud-init takes a 'decode' parameter, but does not take a open param.
Here, though, we take both mode and decode.

They seem to do mostly the same thing (and if they dont, i'd rather handle that specifically).

Ie, best case scenario is that:
  load_file("file", mode="rb", decode=True) == load_file("file", mode="r", decode=False).
The worse cases is if that is subtly different.

Can we just drop the mode parameter and alway suse 'rb' ?

Then the caller gets a string if they pass decode=True, and gets bytes otherwise.

[Ryan Harper (raharper)]

On Mon, Jan 30, 2017 at 10:26 AM, Scott Moser <email address hidden> wrote:

> I guess I approve, with the one question inline.
> I do think our load_file is kind of wierd still though..
> cloud-init takes a 'decode' parameter, but does not take a open param.
>

mode

> Here, though, we take both mode and decode.
>
> They seem to do mostly the same thing (and if they dont, i'd rather handle
> that specifically).
>
> Ie, best case scenario is that:
> load_file("file", mode="rb", decode=True) == load_file("file", mode="r",
> decode=False).
> The worse cases is if that is subtly different.
>

These are worth unittests to confirm; I'll add those;

>
> Can we just drop the mode parameter and alway suse 'rb' ?
>
> Then the caller gets a string if they pass decode=True, and gets bytes
> otherwise.
>

The one case, (for which we don't have a user at the moment) is if someone
wants to do
something with decoding differently than what the default is then they'll
need mode='rb'
and decode=False;

In general, what decision can we make when we get mode='r' and decode=True ?
Was that default or did the caller really specify that?

If we don't care about that specifically; and I don't know that we need to,
then it
does seem like we can use decode boolean and drop mode.

>
>
>
> 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 21:00:47 +0000
> > @@ -375,10 +375,10 @@
> > cmd = ['blockdev', '--rereadpt'] + devices
> > try:
> > util.subp(cmd, capture=True)
> > - except util.ProcessExecutionError as e:
> > + except util.ProcessExecutionError:
> > # FIXME: its less than ideal to swallow this error, but until
> > # we fix LP: #1489521 we kind of need to.
> > - LOG.warn("rescanning devices failed: %s", e)
> > + LOG.warn("Error rescanning devices, possibly known issue LP:
> #1489521")
>
> is there a reason not to log the error ?
>

Currently we have a comment that indicated that we don't care about the
error at this time
The message getting logged tripped the vmtest check_install_log regex which
indicated the
deployment failed. If we don't care about this error, then I think we can
skip the logging here.

> if you dont log the error, then the exit code and stderr and stdout get
> completely lost.
>

If we want to log the exit-code and stderr,stdout we can; it was the
python stacktrace
that got dumped via printing the exception that triggered the failure of a
test.

> >
> > udevadm_settle()
> >
>
>
> --
> https://code.launchpad.net/~raharper/curtin/trunk.lp1635560/+merge/314645
> You are the owner of lp:~raharper/curtin/trunk.lp1635560.
>

[lp:~raharper/curtin/trunk.lp1635560]

442. By Ryan Harper on 2017-01-30

util.load_file: set mode based on decode parameter

443. By Ryan Harper on 2017-01-30

util.load_file: drop mode parameter, always use 'rb'

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

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

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

review: Approve (continuous-integration)

[Ryan Harper (raharper)]

Re-run vmtest on diglett after revno 443:

----------------------------------------------------------------------
Ran 1015 tests in 8278.084s

OK (SKIP=1)
Mon, 30 Jan 2017 14:18:28 -0600: vmtest end [0] in 8280s

[lp:~raharper/curtin/trunk.lp1635560]

444. By Ryan Harper on 2017-02-01

merge from trunk

445. By Ryan Harper on 2017-02-06

Add comment when logging expected error; don't pass decode=False in block_info

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

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

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

review: Needs Fixing (continuous-integration)

=== modified file 'curtin/block/__init__.py'
--- curtin/block/__init__.py	2017-02-01 15:10:13 +0000
+++ curtin/block/__init__.py	2017-02-06 19:55:25 +0000
@@ -392,7 +392,11 @@
     except util.ProcessExecutionError as e:
         # FIXME: its less than ideal to swallow this error, but until
         # we fix LP: #1489521 we kind of need to.
-        LOG.warn("rescanning devices failed: %s", e)
+        LOG.warn("Error rescanning devices, possibly known issue LP: #1489521")
+        # Reformatting the execption output so as to not trigger
+        # vmtest scanning for Unexepected errors in install logfile
+        LOG.warn("cmd: %s\nstdout:%s\nstderr:%s\nexit_code:%s", e.cmd,
+                 e.stdout, e.stderr, e.exit_code)
 
     udevadm_settle()
 
@@ -702,7 +706,7 @@
     # this signature must be at 0x1fe
     # https://en.wikipedia.org/wiki/Master_boot_record#Sector_layout
     return (is_block_device(device) and util.file_size(device) >= 0x200 and
-            (util.load_file(device, mode='rb', read_len=2, offset=0x1fe) ==
+            (util.load_file(device, decode=False, read_len=2, offset=0x1fe) ==
              b'\x55\xAA'))
 
 
@@ -720,7 +724,7 @@
     sector_size = get_blockdev_sector_size(device)[0]
     return (is_block_device(device) and
             util.file_size(device) >= 2 * sector_size and
-            (util.load_file(device, mode='rb', read_len=8,
+            (util.load_file(device, decode=False, read_len=8,
                             offset=sector_size) == b'EFI PART'))
 
 

=== modified file 'curtin/commands/apply_net.py'
--- curtin/commands/apply_net.py	2016-08-29 18:27:32 +0000
+++ curtin/commands/apply_net.py	2017-02-06 19:55:25 +0000
@@ -160,7 +160,7 @@
     except:
         msg = bmsg + " %s exists, but could not be read." % cfg
         LOG.exception(msg)
-        return
+        raise
 
 
 def _maybe_remove_legacy_eth0(target,
@@ -194,7 +194,7 @@
     except:
         msg = bmsg + " %s exists, but could not be read." % cfg
         LOG.exception(msg)
-        return
+        raise
 
     LOG.warn(msg)
 

=== modified file 'curtin/util.py'
--- curtin/util.py	2017-02-02 22:52:01 +0000
+++ curtin/util.py	2017-02-06 19:55:25 +0000
@@ -337,11 +337,21 @@
         os.chmod(filename, mode)
 
 
-def load_file(path, mode="r", read_len=None, offset=0):
-    with open(path, mode) as fp:
+def load_file(path, read_len=None, offset=0, decode=True):
+    with open(path, "rb") as fp:
         if offset:
             fp.seek(offset)
-        return fp.read(read_len) if read_len else fp.read()
+        contents = fp.read(read_len) if read_len else fp.read()
+
+    if decode:
+        return decode_binary(contents)
+    else:
+        return contents
+
+
+def decode_binary(blob, encoding='utf-8', errors='replace'):
+    # Converts a binary type into a text type using given encoding.
+    return blob.decode(encoding, errors=errors)
 
 
 def file_size(path):

=== modified file 'tests/unittests/helpers.py'
--- tests/unittests/helpers.py	2016-09-16 18:54:28 +0000
+++ tests/unittests/helpers.py	2017-02-06 19:55:25 +0000
@@ -14,28 +14,32 @@
 #
 #   You should have received a copy of the GNU Affero General Public License
 #   along with Curtin.  If not, see <http://www.gnu.org/licenses/>.
+
+import contextlib
+import imp
+import importlib
 import mock
 
 
-class mocked_open(object):
-    # older versions of mock can't really mock the builtin 'open' easily.
-    def __init__(self):
-        self.mocked = None
-
-    def __enter__(self):
-        if self.mocked:
-            return self.mocked.start()
-
-        py2_p = '__builtin__.open'
-        py3_p = 'builtins.open'
+def builtin_module_name():
+    options = ('builtins', '__builtin__')
+    for name in options:
         try:
-            self.mocked = mock.patch(py2_p, new_callable=mock.mock_open())
-            return self.mocked.start()
+            imp.find_module(name)
         except ImportError:
-            self.mocked = mock.patch(py3_p, new_callable=mock.mock_open())
-            return self.mocked.start()
-
-    def __exit__(self, etype, value, trace):
-        if self.mocked:
-            self.mocked.stop()
-        self.mocked = None
+            continue
+        else:
+            print('importing and returning: %s' % name)
+            importlib.import_module(name)
+            return name
+
+
[e-mail]
+def simple_mocked_open(content=None):
+    if not content:
+        content = ''
+    m_open = mock.mock_open(read_data=content)
+    mod_name = builtin_module_name()
+    m_patch = '{}.open'.format(mod_name)
+    with mock.patch(m_patch, m_open, create=True):
+        yield m_open

=== modified file 'tests/unittests/test_apt_source.py'
--- tests/unittests/test_apt_source.py	2017-02-02 22:52:01 +0000
+++ tests/unittests/test_apt_source.py	2017-02-06 19:55:25 +0000
@@ -42,7 +42,7 @@
     load file and return content after decoding
     """
     try:
-        content = util.load_file(filename, mode="r")
+        content = util.load_file(filename, decode=True)
     except Exception as error:
         print('failed to load file content for test: %s' % error)
         raise

=== modified file 'tests/unittests/test_block.py'
--- tests/unittests/test_block.py	2017-02-01 00:37:15 +0000
+++ tests/unittests/test_block.py	2017-02-06 19:55:25 +0000
@@ -8,7 +8,7 @@
 
 from collections import OrderedDict
 
-from .helpers import mocked_open
+from .helpers import simple_mocked_open
 from curtin import util
 from curtin import block
 
@@ -210,7 +210,8 @@
         myfile = self.tfile("def_zero")
         util.write_file(myfile, flen * b'\1', omode="wb")
         block.wipe_file(myfile)
-        found = util.load_file(myfile, mode="rb")
+        with open(myfile, mode="rb") as fh:
+            found = fh.read()
         self.assertEqual(found, flen * b'\0')
 
     def test_reader_used(self):
@@ -223,7 +224,8 @@
         # populate with nulls
         util.write_file(myfile, flen * b'\0', omode="wb")
         block.wipe_file(myfile, reader=reader, buflen=flen)
-        found = util.load_file(myfile, mode="rb")
+        with open(myfile, mode="rb") as fh:
+            found = fh.read()
         self.assertEqual(found, flen * b'\1')
 
     def test_reader_twice(self):
@@ -239,7 +241,8 @@
         myfile = self.tfile("reader_twice")
         util.write_file(myfile, flen * b'\xff', omode="wb")
         block.wipe_file(myfile, reader=reader, buflen=20)
-        found = util.load_file(myfile, mode="rb")
+        with open(myfile, mode="rb") as fh:
+            found = fh.read()
         self.assertEqual(found, expected)
 
     def test_reader_fhandle(self):
@@ -346,15 +349,13 @@
 
     @mock.patch('curtin.block.wipe_file')
     def test_wipe_zero(self, mock_wipe_file):
-        with mocked_open() as mock_open:
+        with simple_mocked_open():
             block.wipe_volume(self.dev, mode='zero')
             mock_wipe_file.assert_called_with(self.dev)
-            mock_open.return_value = mock.MagicMock()
 
     @mock.patch('curtin.block.wipe_file')
     def test_wipe_random(self, mock_wipe_file):
-        with mocked_open() as mock_open:
-            mock_open.return_value = mock.MagicMock()
+        with simple_mocked_open() as mock_open:
             block.wipe_volume(self.dev, mode='random')
             mock_open.assert_called_with('/dev/urandom', 'rb')
             mock_wipe_file.assert_called_with(
@@ -436,8 +437,8 @@
     gpt_content_4k = b'\x00' * 0x800 + b'EFI PART' + b'\x00' * (0x800 - 8)
     null_content = b'\x00' * 0xf00
 
-    def _test_util_load_file(self, content, device, mode, read_len, offset):
-        return (bytes if 'b' in mode else str)(content[offset:offset+read_len])
+    def _test_util_load_file(self, content, device, read_len, offset, decode):
+        return (bytes if not decode else str)(content[offset:offset+read_len])
 
     @mock.patch('curtin.block.check_dos_signature')
     @mock.patch('curtin.block.check_efi_signature')

=== modified file 'tests/unittests/test_util.py'
--- tests/unittests/test_util.py	2016-08-29 21:32:21 +0000
+++ tests/unittests/test_util.py	2017-02-06 19:55:25 +0000
@@ -1,4 +1,4 @@
-from unittest import TestCase
+from unittest import TestCase, skipIf
 import mock
 import os
 import stat
@@ -6,6 +6,7 @@
 import tempfile
 
 from curtin import util
+from .helpers import simple_mocked_open
 
 
 class TestLogTimer(TestCase):
@@ -460,4 +461,34 @@
         m_subp.assert_called_with(cmd, target=target)
 
 
+class TestLoadFile(TestCase):
+    """Test utility 'load_file'"""
+
+    def test_load_file_simple(self):
+        fname = 'test.cfg'
+        contents = "#curtin-config"
+        with simple_mocked_open(content=contents) as m_open:
+            loaded_contents = util.load_file(fname, decode=False)
+            self.assertEqual(contents, loaded_contents)
+            m_open.assert_called_with(fname, 'rb')
+
+    @skipIf(mock.__version__ < '2.0.0', "mock version < 2.0.0")
+    def test_load_file_handles_utf8(self):
+        fname = 'test.cfg'
+        contents = b'd\xc3\xa9j\xc8\xa7'
+        with simple_mocked_open(content=contents) as m_open:
+            with open(fname, 'rb') as f:
+                self.assertEqual(f.read(), contents)
+            m_open.assert_called_with(fname, 'rb')
+
+    @skipIf(mock.__version__ < '2.0.0', "mock version < 2.0.0")
+    @mock.patch('curtin.util.decode_binary')
+    def test_load_file_respects_decode_false(self, mock_decode):
+        fname = 'test.cfg'
+        contents = b'start \xc3\xa9 end'
+        with simple_mocked_open(contents):
+            loaded_contents = util.load_file(fname, decode=False)
+            self.assertEqual(type(loaded_contents), bytes)
+            self.assertEqual(loaded_contents, contents)
+
 # vi: ts=4 expandtab syntax=python

=== modified file 'tests/vmtests/__init__.py'
--- tests/vmtests/__init__.py	2017-01-27 16:13:17 +0000
+++ tests/vmtests/__init__.py	2017-02-06 19:55:25 +0000
@@ -546,10 +546,11 @@
                     install_log = lfh.read().decode('utf-8', errors='replace')
                 errmsg, errors = check_install_log(install_log)
                 if errmsg:
+                    logger.error('Found error: ' + errmsg)
                     for e in errors:
-                        logger.error(e)
-                    logger.error(errmsg)
-                    raise Exception(cls.__name__ + ":" + errmsg)
+                        logger.error('Context:\n' + e)
+                    raise Exception(cls.__name__ + ":" + errmsg +
+                                    '\n'.join(errors))
                 else:
                     logger.info('Install OK')
             else:
@@ -912,6 +913,14 @@
             raise exc
 
 
+def find_error_context(err_match, contents, nrchars=200):
+    context_start = err_match.start() - nrchars
+    context_end = err_match.end() + nrchars
+    # extract contents, split into lines, drop the first and last partials
+    # recombine and return
+    return "\n".join(contents[context_start:context_end].splitlines()[1:-1])
+
+
 def check_install_log(install_log):
     # look if install is OK via curtin 'Installation ok"
     # if we dont find that, scan for known error messages and report
@@ -925,17 +934,18 @@
                    'Installation\ failed',
                    'ImportError: No module named.*',
                    'Unexpected error while running command',
-                   'E: Unable to locate package.*']))
+                   'E: Unable to locate package.*',
+                   'Traceback.*most recent call last.*:']))
 
     install_is_ok = re.findall(install_pass, install_log)
+    # always scan for errors
+    found_errors = re.finditer(install_fail, install_log)
     if len(install_is_ok) == 0:
-        errors = re.findall(install_fail, install_log)
-        if len(errors) > 0:
-            for e in errors:
-                logger.error(e)
-            errmsg = ('Errors during curtin installer')
-        else:
-            errmsg = ('Failed to verify Installation is OK')
+        errmsg = ('Failed to verify Installation is OK')
+
+    for e in found_errors:
+        errors.append(find_error_context(e, install_log))
+        errmsg = ('Errors during curtin installer')
 
     return errmsg, errors
 
@@ -1011,6 +1021,7 @@
             { shutdown -P now "Shutting down on centos"; }
         [ "$(lsb_release -sc)" = "precise" ] &&
             { shutdown -P now "Shutting down on precise"; }
+        exit 0;
         """)
 
     scripts = ([collect_prep] + collect_scripts + [collect_post] +