ceph-volume: fix stderr failure to decode/encode when redirected

src/ceph-volume/ceph_volume/log.py

@@ -31,3 +31,18 @@ def setup(name='ceph-volume.log', log_path=None):
     fh.setFormatter(logging.Formatter(FILE_FORMAT))
 
     root_logger.addHandler(fh)
+
+
+def setup_console():
+    # TODO: At some point ceph-volume should stop using the custom logger
+    # interface that exists in terminal.py and use the logging module to
+    # produce output for the terminal
+    # Console Logger
+    sh = logging.StreamHandler()
+    sh.setFormatter(logging.Formatter('[terminal] %(message)s'))
+    sh.setLevel(logging.DEBUG)
+
+    terminal_logger = logging.getLogger('terminal')
+
+    # allow all levels at root_logger, handlers control individual levels
+    terminal_logger.addHandler(sh)

src/ceph-volume/ceph_volume/main.py

@@ -131,6 +131,7 @@ def main(self, argv):
         if os.path.isdir(conf.log_path):
             conf.log_path = os.path.join(args.log_path, 'ceph-volume.log')
         log.setup()
+        log.setup_console()
         logger = logging.getLogger(__name__)
         logger.info("Running command: ceph-volume %s %s", " ".join(main_args), " ".join(subcommand_args))
         # set all variables from args and load everything needed according to

src/ceph-volume/ceph_volume/terminal.py

@@ -1,8 +1,10 @@
-import codecs
 import logging
 import sys
 
 
+terminal_logger = logging.getLogger('terminal')
+
+
 class colorize(str):
     """
     Pretty simple to use::
@@ -80,34 +82,13 @@ def make(cls, string):
 class _Write(object):
 
     def __init__(self, _writer=None, prefix='', suffix='', flush=False):
-        # we can't set sys.stderr as the default for _writer. Otherwise
+        # we can't set sys.stderr as the default for _writer. otherwise
         # pytest's capturing gets confused
-        if not _writer:
-            _writer = sys.stderr
-        self._writer = _Write._unicode_output_stream(_writer)
-        sys.stderr = self._writer
+        self._writer = _writer or sys.stderr
         self.suffix = suffix
         self.prefix = prefix
         self.flush = flush
 
-    @staticmethod
-    def _unicode_output_stream(stream):
-        # wrapper for given stream, so it can write unicode without throwing
-        # exception
-        # sys.stderr.encoding is None if !isatty
-        encoding = stream.encoding or ''
-        if encoding.upper() in ('UTF-8', 'UTF8'):
-            # already using unicode encoding, nothing to do
-            return stream
-        encoding = encoding or 'UTF-8'
-        if sys.version_info >= (3, 0):
-            # try to use whatever writer class the stream was
-            return stream.__class__(stream.buffer, encoding, 'replace',
-                                    stream.newlines, stream.line_buffering)
-        else:
-            # in python2, stderr is but a "file"
-            return codecs.getwriter(encoding)(stream, 'replace')
-
     def bold(self, string):
         self.write(bold(string))
 
@@ -117,9 +98,17 @@ def raw(self, string):
         self.write(string)
 
     def write(self, line):
-        self._writer.write(self.prefix + line + self.suffix)
-        if self.flush:
-            self._writer.flush()
+        entry = self.prefix + line + self.suffix
+
+        try:
+            self._writer.write(entry)
+            if self.flush:
+                self._writer.flush()
+        except (UnicodeDecodeError, UnicodeEncodeError):
+            try:
+                terminal_logger.info(entry.strip('\n'))
+            except (AttributeError, TypeError):
+                terminal_logger.info(entry)
 
 
 def stdout(msg):

src/ceph-volume/ceph_volume/tests/functional/scripts/output.py

@@ -0,0 +1,5 @@
+import os
+from ceph_volume import terminal
+
+char = os.environ.get('INVALID')
+terminal.stdout(char)

src/ceph-volume/ceph_volume/tests/functional/scripts/test_unicode.sh

@@ -0,0 +1,35 @@
+#!/bin/bash
+
+# Not entirely sure why these executables don't seem to be available in the
+# $PATH when running from tox. Calling out to `which` seems to fix it, at the
+# expense of making the script a bit obtuse
+
+mktemp=$(which mktemp)
+cat=$(which cat)
+grep=$(which grep)
+PYTHON_EXECUTABLE=`which python`
+STDERR_FILE=$($mktemp)
+INVALID="→"
+
+echo "stderr file created: $STDERR_FILE"
+
+INVALID="$INVALID" $PYTHON_EXECUTABLE $1 2> ${STDERR_FILE}
+
+retVal=$?
+
+if [ $retVal -ne 0 ]; then
+    echo "Failed test: Unexpected failure from running Python script"
+    echo "Below is output of stderr captured:"
+    $cat "${STDERR_FILE}"
+    exit $retVal
+fi
+
+$grep --quiet "$INVALID" ${STDERR_FILE}
+
+retVal=$?
+if [ $retVal -ne 0 ]; then
+    echo "Failed test: expected to find \"${INVALID}\" character in tmpfile: \"${STDERR_FILE}\""
+    echo "Below is output of stderr captured:"
+    $cat "${STDERR_FILE}"
+fi
+exit $retVal

src/ceph-volume/ceph_volume/tests/test_terminal.py

@@ -2,9 +2,14 @@
 
 import codecs
 import io
+try:
+    from io import StringIO
+except ImportError:
+    from StringIO import StringIO
 import pytest
 import sys
 from ceph_volume import terminal
+from ceph_volume.log import setup_console
 
 
 class SubCommand(object):
@@ -97,27 +102,42 @@ class TestWriteUnicode(object):
 
     def setup(self):
         self.octpus_and_squid_en = u'octpus and squid'
-        octpus_and_squid_zh = u'章鱼和鱿鱼'
-        self.message = self.octpus_and_squid_en + octpus_and_squid_zh
+        self.octpus_and_squid_zh = u'章鱼和鱿鱼'
+        self.message = self.octpus_and_squid_en + self.octpus_and_squid_zh
+        setup_console()
 
     def test_stdout_writer(self, capsys):
         # should work with whatever stdout is
         terminal.stdout(self.message)
         _, err = capsys.readouterr()
         assert self.octpus_and_squid_en in err
+        assert self.octpus_and_squid_zh in err
 
     @pytest.mark.parametrize('encoding', ['ascii', 'utf8'])
-    def test_writer(self, encoding, stream, monkeypatch, capsys):
-        if encoding == 'ascii' and sys.version_info > (3,):
+    def test_writer_log(self, stream, encoding, monkeypatch, caplog):
+        writer = StringIO()
+        terminal._Write(_writer=writer).raw(self.message)
+        writer.flush()
+        writer.seek(0)
+        output = writer.readlines()[0]
+        assert self.octpus_and_squid_en in output
+
+    @pytest.mark.parametrize('encoding', ['utf8'])
+    def test_writer(self, encoding, stream, monkeypatch, capsys, caplog):
+        buffer = io.BytesIO()
+        writer = stream(buffer, encoding)
+        terminal._Write(_writer=writer).raw(self.message)
+        writer.flush()
+        writer.seek(0)
+        val = buffer.getvalue()
+        assert self.octpus_and_squid_en.encode(encoding) in val
+
+    def test_writer_uses_log_on_unicodeerror(self, stream, monkeypatch, capture):
+
+        if sys.version_info > (3,):
             pytest.skip("Something breaks inside of pytest's capsys")
-        # should keep writer alive
-        with capsys.disabled():
-            buffer = io.BytesIO()
-            # we want to have access to the sys.stdout's attributes in
-            # make_stream(), not the ones of pytest.capture.EncodedFile
-            writer = stream(buffer, encoding)
-            monkeypatch.setattr(sys, 'stderr', writer)
-            terminal.stdout(self.message)
-            writer.flush()
-            val = buffer.getvalue()
-            assert self.octpus_and_squid_en.encode(encoding) in val
+        monkeypatch.setattr(terminal.terminal_logger, 'info', capture)
+        buffer = io.BytesIO()
+        writer = stream(buffer, 'ascii')
+        terminal._Write(_writer=writer).raw(self.message)
+        assert self.octpus_and_squid_en in capture.calls[0]['args'][0]

src/ceph-volume/shell_tox.ini

@@ -0,0 +1,11 @@
+[tox]
+envlist = py27, py35, py36
+skip_missing_interpreters = true
+
+[testenv]
+passenv=*
+whitelist_externals=
+  bash
+  grep
+  mktemp
+commands=bash {posargs:ceph_volume/tests/functional/scripts/test_unicode.sh} {posargs:ceph_volume/tests/functional/scripts/output.py}