Bug with py3.6 _out function

[retr0h]

I'm having an issue on 3.6 when executing an _out function. I have a CustomLogger and Formatter which work perfectly find under 2.7. They also work fine under 3.6 when not using sh.

A sample module can be used to reproduce the issue. It simply calls a script which sleeps and prints to stdout.

It looks as though sh is providing a queue.Queue object to the logger as an argument which is causing the formatting to fail.

Working under 2.7

$ pyenv virtualenv 2.7.12 sh-venv-test
$ pyenv activate 2.7.12/envs/sh-venv-test
$ pip install sh colorama
$ python --version
Python 2.7.12
$ python foo.py
  hi
  hi
  hi

Not working under 3.6

$ pyenv virtualenv 3.6.0 sh-venv-test-bad
$ pyenv activate 3.6.0/envs/sh-venv-test-bad
$ pip install sh colorama
$ python --version
Python 3.6.0

$ python foo.py                                                                                                     [17/900]
in py
(<queue.Queue object at 0x106fa5ac8>,)
--- Logging error ---
Traceback (most recent call last):
  File "/Users/jodewey/.pyenv/versions/3.6.0/lib/python3.6/logging/__init__.py", line 995, in emit
    msg = self.format(record)
  File "/Users/jodewey/.pyenv/versions/3.6.0/lib/python3.6/logging/__init__.py", line 841, in format
    return fmt.format(record)
  File "foo.py", line 76, in format
    return super(TrailingNewlineFormatter, self).format(record)
  File "/Users/jodewey/.pyenv/versions/3.6.0/lib/python3.6/logging/__init__.py", line 578, in format
    record.message = record.getMessage()
  File "/Users/jodewey/.pyenv/versions/3.6.0/lib/python3.6/logging/__init__.py", line 341, in getMessage
    msg = msg % self.args
TypeError: not all arguments converted during string formatting
Call stack:
  File "/Users/jodewey/.pyenv/versions/3.6.0/lib/python3.6/threading.py", line 884, in _bootstrap
    self._bootstrap_inner()
  File "/Users/jodewey/.pyenv/versions/3.6.0/lib/python3.6/threading.py", line 916, in _bootstrap_inner
    self.run()
  File "/Users/jodewey/.pyenv/versions/3.6.0/lib/python3.6/threading.py", line 864, in run
    self._target(*self._args, **self._kwargs)
  File "/Users/jodewey/.pyenv/versions/3.6.0/envs/sh-venv-test-bad/lib/python3.6/site-packages/sh.py", line 1540, in wrap
    fn(*args, **kwargs)
  File "/Users/jodewey/.pyenv/versions/3.6.0/envs/sh-venv-test-bad/lib/python3.6/site-packages/sh.py", line 2480, in output_thread
    done = f.read()
  File "/Users/jodewey/.pyenv/versions/3.6.0/envs/sh-venv-test-bad/lib/python3.6/site-packages/sh.py", line 2930, in read
    self.write_chunk(chunk)
  File "/Users/jodewey/.pyenv/versions/3.6.0/envs/sh-venv-test-bad/lib/python3.6/site-packages/sh.py", line 2905, in write_chunk
    self.should_quit = self.process_chunk(chunk)
  File "/Users/jodewey/.pyenv/versions/3.6.0/envs/sh-venv-test-bad/lib/python3.6/site-packages/sh.py", line 2826, in process
    return handler(chunk)
  File "/Users/jodewey/.pyenv/versions/3.6.0/envs/sh-venv-test-bad/lib/python3.6/site-packages/sh.py", line 1624, in fn
    return handler(chunk, *args)
  File "foo.py", line 65, in out
    self._log(OUT, msg, args, **kwargs)
 Message: 'hi'
Arguments: (<queue.Queue object at 0x106fa5ac8>,)
^CTraceback (most recent call last):
  File "foo.py", line 169, in <module>
    command()
  File "/Users/jodewey/.pyenv/versions/3.6.0/envs/sh-venv-test-bad/lib/python3.6/site-packages/sh.py", line 1427, in __call__
    return RunningCommand(cmd, call_args, stdin, stdout, stderr)
  File "/Users/jodewey/.pyenv/versions/3.6.0/envs/sh-venv-test-bad/lib/python3.6/site-packages/sh.py", line 774, in __init__
    self.wait()
  File "/Users/jodewey/.pyenv/versions/3.6.0/envs/sh-venv-test-bad/lib/python3.6/site-packages/sh.py", line 784, in wait
    exit_code = self.process.wait()
  File "/Users/jodewey/.pyenv/versions/3.6.0/envs/sh-venv-test-bad/lib/python3.6/site-packages/sh.py", line 2354, in wait
    pid, exit_code = no_interrupt(os.waitpid, self.pid, 0) # blocks
  File "/Users/jodewey/.pyenv/versions/3.6.0/envs/sh-venv-test-bad/lib/python3.6/site-packages/sh.py", line 1666, in no_interrupt
    ret = syscall(*args, **kwargs)
KeyboardInterrupt   

[retr0h]

Any ideas?

[amoffat]

Sorry @retr0h, this one slipped through the cracks. I'll take a look at it today.

[amoffat]

There's a fix on the release-1.12.14 branch and a new test to cover this case. It won't ship until I finish #378 but you're welcome to test it out in the mean time.

[amoffat]

Fixed on master, version 1.12.14