some python3 fixes

This fixes the last set of WARN messages in my testing.
 * open /dev/console in text mode
 * move final message to be jinja template by default to avoid
   a warning about lack of cheetah.
 * write and read pickle'd contents in binary
 * some logging tests

Also:
 * add tool tox-venv for simple things like:
   tox-venv py34 /bin/bash

9 files changed, 146 insertions, 16 deletions

diff --git a/ChangeLog b/ChangeLog
index bafeea3d..127bc361 100644
--- a/ChangeLog
+++ b/ChangeLog
@@ -21,7 +21,7 @@
  - hostname: on first boot apply hostname to be same as is written for
    persistent hostname.  (LP: #1246485)
  - remove usage of dmidecode on linux in favor of /sys interface [Ben Howard]
- - python3 support [Barry Warsaw] (LP: #1247132)
+ - python3 support [Barry Warsaw, Daniel Watson, Josh Harlow] (LP: #1247132)
 0.7.6:
  - open 0.7.6
  - Enable vendordata on CloudSigma datasource (LP: #1303986)
diff --git a/cloudinit/config/cc_final_message.py b/cloudinit/config/cc_final_message.py
index b24294e4..ad957e12 100644
--- a/cloudinit/config/cc_final_message.py
+++ b/cloudinit/config/cc_final_message.py
@@ -26,9 +26,12 @@ from cloudinit.settings import PER_ALWAYS
 
 frequency = PER_ALWAYS
 
-# Cheetah formated default message
-FINAL_MESSAGE_DEF = ("Cloud-init v. ${version} finished at ${timestamp}."
-                     " Datasource ${datasource}.  Up ${uptime} seconds")
+# Jinja formated default message
+FINAL_MESSAGE_DEF = (
+  "## template: jinja\n"
+  "Cloud-init v. {{version}} finished at {{timestamp}}."
+  " Datasource {{datasource}}.  Up {{uptime}} seconds"
+)
 
 
 def handle(_name, cfg, cloud, log, args):
diff --git a/cloudinit/stages.py b/cloudinit/stages.py
index f4f4591d..c5b1ded0 100644
--- a/cloudinit/stages.py
+++ b/cloudinit/stages.py
@@ -180,9 +180,12 @@ class Init(object):
         pickled_fn = self.paths.get_ipath_cur('obj_pkl')
         pickle_contents = None
         try:
-            pickle_contents = util.load_file(pickled_fn)
-        except Exception:
+            pickle_contents = util.load_file(pickled_fn, decode=False)
+        except Exception as e:
+            if os.path.isfile(pickled_fn):
+                LOG.warn("failed loading pickle in %s: %s" % (pickled_fn, e))
             pass
+
         # This is expected so just return nothing
         # successfully loaded...
         if not pickle_contents:
@@ -203,7 +206,7 @@ class Init(object):
             util.logexc(LOG, "Failed pickling datasource %s", self.datasource)
             return False
         try:
-            util.write_file(pickled_fn, pk_contents, mode=0o400)
+            util.write_file(pickled_fn, pk_contents, omode="wb", mode=0o400)
         except Exception:
             util.logexc(LOG, "Failed pickling datasource to %s", pickled_fn)
             return False
diff --git a/cloudinit/util.py b/cloudinit/util.py
index b845adfd..67ea5553 100644
--- a/cloudinit/util.py
+++ b/cloudinit/util.py
@@ -404,7 +404,7 @@ def multi_log(text, console=True, stderr=True,
     if console:
         conpath = "/dev/console"
         if os.path.exists(conpath):
-            with open(conpath, 'wb') as wfh:
+            with open(conpath, 'w') as wfh:
                 wfh.write(text)
                 wfh.flush()
         else:
diff --git a/doc/examples/cloud-config.txt b/doc/examples/cloud-config.txt
index ed4eb7fc..1c59c2cf 100644
--- a/doc/examples/cloud-config.txt
+++ b/doc/examples/cloud-config.txt
@@ -484,7 +484,9 @@ resize_rootfs: True
 # final_message
 # default: cloud-init boot finished at $TIMESTAMP. Up $UPTIME seconds
 # this message is written by cloud-final when the system is finished
-# its first boot
+# its first boot.
+# This message is rendered as if it were a template.  If you
+# want jinja, you have to start the line with '## template:jinja\n'
 final_message: "The system is finally up, after $UPTIME seconds"
 
 # configure where output will go
diff --git a/tests/unittests/helpers.py b/tests/unittests/helpers.py
index 6b9394b3..ce77af93 100644
--- a/tests/unittests/helpers.py
+++ b/tests/unittests/helpers.py
@@ -254,6 +254,19 @@ class FilesystemMockingTestCase(ResourceUsingTestCase):
                 self.patched_funcs.enter_context(
                     mock.patch.object(mod, f, trap_func))
 
+    def patchOpen(self, new_root):
+        trap_func = retarget_many_wrapper(new_root, 1, open)
+        name = 'builtins.open' if PY3 else '__builtin__.open'
+        self.patched_funcs.enter_context(mock.patch(name, trap_func))
+
+    def patchStdoutAndStderr(self, stdout=None, stderr=None):
+        if stdout is not None:
+            self.patched_funcs.enter_context(
+                mock.patch.object(sys, 'stdout', stdout))
+        if stderr is not None:
+            self.patched_funcs.enter_context(
+                mock.patch.object(sys, 'stderr', stderr))
+
 
 class HttprettyTestCase(TestCase):
     # necessary as http_proxy gets in the way of httpretty
diff --git a/tests/unittests/test_util.py b/tests/unittests/test_util.py
index a1bd2c46..b96da663 100644
--- a/tests/unittests/test_util.py
+++ b/tests/unittests/test_util.py
@@ -1,21 +1,22 @@
 from __future__ import print_function
 
+import logging
 import os
-import stat
-import yaml
 import shutil
+import stat
 import tempfile
 
-from . import helpers
 import six
+import yaml
+
+from cloudinit import importer, util
+from . import helpers
 
 try:
     from unittest import mock
 except ImportError:
     import mock
 
-from cloudinit import importer
-from cloudinit import util
 
 
 class FakeSelinux(object):
@@ -377,4 +378,70 @@ class TestReadDMIData(helpers.FilesystemMockingTestCase):
         self.assertFalse(None, util.read_dmi_data("key"))
 
 
+class TestMultiLog(helpers.FilesystemMockingTestCase):
+
+    def _createConsole(self, root):
+        os.mkdir(os.path.join(root, 'dev'))
+        open(os.path.join(root, 'dev', 'console'), 'a').close()
+
+    def setUp(self):
+        super(TestMultiLog, self).setUp()
+        self.root = tempfile.mkdtemp()
+        self.addCleanup(shutil.rmtree, self.root)
+        self.patchOS(self.root)
+        self.patchUtils(self.root)
+        self.patchOpen(self.root)
+        self.stdout = six.StringIO()
+        self.stderr = six.StringIO()
+        self.patchStdoutAndStderr(self.stdout, self.stderr)
+
+    def test_stderr_used_by_default(self):
+        logged_string = 'test stderr output'
+        util.multi_log(logged_string)
+        self.assertEqual(logged_string, self.stderr.getvalue())
+
+    def test_stderr_not_used_if_false(self):
+        util.multi_log('should not see this', stderr=False)
+        self.assertEqual('', self.stderr.getvalue())
+
+    def test_logs_go_to_console_by_default(self):
+        self._createConsole(self.root)
+        logged_string = 'something very important'
+        util.multi_log(logged_string)
+        self.assertEqual(logged_string, open('/dev/console').read())
+
+    def test_logs_dont_go_to_stdout_if_console_exists(self):
+        self._createConsole(self.root)
+        util.multi_log('something')
+        self.assertEqual('', self.stdout.getvalue())
+
+    def test_logs_go_to_stdout_if_console_does_not_exist(self):
+        logged_string = 'something very important'
+        util.multi_log(logged_string)
+        self.assertEqual(logged_string, self.stdout.getvalue())
+
+    def test_logs_go_to_log_if_given(self):
+        log = mock.MagicMock()
+        logged_string = 'something very important'
+        util.multi_log(logged_string, log=log)
+        self.assertEqual([((mock.ANY, logged_string), {})],
+                         log.log.call_args_list)
+
+    def test_newlines_stripped_from_log_call(self):
+        log = mock.MagicMock()
+        expected_string = 'something very important'
+        util.multi_log('{0}\n'.format(expected_string), log=log)
+        self.assertEqual((mock.ANY, expected_string), log.log.call_args[0])
+
+    def test_log_level_defaults_to_debug(self):
+        log = mock.MagicMock()
+        util.multi_log('message', log=log)
+        self.assertEqual((logging.DEBUG, mock.ANY), log.log.call_args[0])
+
+    def test_given_log_level_used(self):
+        log = mock.MagicMock()
+        log_level = mock.Mock()
+        util.multi_log('message', log=log, log_level=log_level)
+        self.assertEqual((log_level, mock.ANY), log.log.call_args[0])
+
 # vi: ts=4 expandtab
diff --git a/tools/tox-venv b/tools/tox-venv
new file mode 100755
index 00000000..76ed5076
--- /dev/null
+++ b/tools/tox-venv
@@ -0,0 +1,42 @@
+#!/bin/sh
+
+error() { echo "$@" 1>&2; }
+fail() { [ $# -eq 0 ] || error "$@"; exit 1; }
+Usage() {
+   cat <<EOF
+Usage: ${0##*/} tox-environment [command [args]]
+   run command with provided arguments in the provided tox environment
+   command defaults to \${SHELL:-/bin/sh}.
+
+   invoke with '--list' to show available environments
+EOF
+}
+list_toxes() {
+   local td="$1" pre="$2" d=""
+   ( cd "$tox_d" &&
+     for d in *; do [ -f "$d/bin/activate" ] && echo "${pre}$d"; done)
+}
+
+[ $# -eq 0 ] && { Usage 1>&2; exit 1; }
+[ "$1" = "-h" -o "$1" = "--help" ] && { Usage; exit 0; }
+
+env="$1"
+shift
+tox_d="${0%/*}/../.tox"
+activate="$tox_d/$env/bin/activate"
+
+
+[ -d "$tox_d" ] || fail "$tox_d: not a dir. maybe run 'tox'?"
+
+[ "$env" = "-l" -o "$env" = "--list" ] && { list_toxes ; exit ; }
+
+if [ ! -f "$activate" ]; then
+   error "$env: not a valid tox environment?"
+   error "try one of:"
+   list_toxes "$tox_d" "  "
+   fail
+fi
+. "$activate"
+
+[ "$#" -gt 0 ] || set -- ${SHELL:-/bin/bash}
+debian_chroot="tox:$env" exec "$@"
diff --git a/tox.ini b/tox.ini
index d04cd47c..686a1e7a 100644
--- a/tox.ini
+++ b/tox.ini
@@ -3,7 +3,7 @@ envlist = py26,py27,py34
 recreate = True
 
 [testenv]
-commands = python -m nose tests
+commands = python -m nose {posargs:tests}
 deps =
      contextlib2
      httpretty>=0.7.1
@@ -13,7 +13,7 @@ deps =
      pyflakes
 
 [testenv:py26]
-commands = nosetests tests
+commands = nosetests {posargs:tests}
 deps =
      contextlib2
      httpretty>=0.7.1