Crash when printing to console with special characters.

[TimotheeJeannin]

I'm experiencing crashes when Honcho tries to print to console with special characters:

Traceback (most recent call last):
File "/app/.heroku/python/bin/honcho", line 9, in <module>
    load_entry_point('honcho==0.4.2', 'console_scripts', 'honcho')()
File "/app/.heroku/python/lib/python2.7/site-packages/honcho/command.py", line 292, in main
    app.parse()
File "/app/.heroku/python/lib/python2.7/site-packages/honcho/command.py", line 129, in parse
    options.func(self, options)
File "/app/.heroku/python/lib/python2.7/site-packages/honcho/command.py", line 190, in start
    sys.exit(process_manager.loop())
File "/app/.heroku/python/lib/python2.7/site-packages/honcho/process.py", line 114, in loop
File "/app/.heroku/python/lib/python2.7/site-packages/honcho/printer.py", line 22, in write

Here is a Stackoverflow question with more details:

http://stackoverflow.com/questions/19100116/looks-like-logs-are-crashing-my-django-app

[TimotheeJeannin]

logger.warning(u'Start our little encoding test')
logger.warning(u"Let's print some accented characters: è é ï ")

one = u"é"
two = "e"
logger.warning(u"The concatenation of a %s and a %s is %s " % (type(one), type(two), type(one + two)))

test = "é"
logger.warning(u"I can log a %s if I use decode. See: %s" % (type(test), test.decode('utf-8')))

user = User.objects.get(username='timojeajea')
logger.warning(u"When getting strings from the database, they are encoded as %s." % type(user.first_name))
logger.warning(u"So I should be able to print them: %s" % user.get_full_name())

Without Honcho:

Start our little encoding test
Let's print some accented characters: è é ï 
The concatenation of a <type 'unicode'> and a <type 'str'> is <type 'unicode'>
I can log a <type 'str'> if I use decode. See: é
When getting strings from the database, they are encoded as <type 'unicode'>.
So I should be able to print them: Timothée Jeannin

With Honcho:

Start our little encoding test
Traceback (most recent call last):
  File "/app/.heroku/python/bin/honcho", line 9, in <module>
    load_entry_point('honcho==0.4.2', 'console_scripts', 'honcho')()
  File "/app/.heroku/python/lib/python2.7/site-packages/honcho/command.py", line 292, in main
    app.parse()
  File "/app/.heroku/python/lib/python2.7/site-packages/honcho/command.py", line 129, in parse
    options.func(self, options)
  File "/app/.heroku/python/lib/python2.7/site-packages/honcho/command.py", line 190, in start
    sys.exit(process_manager.loop())
  File "/app/.heroku/python/lib/python2.7/site-packages/honcho/process.py", line 114, in loop
    print(line, end='', file=proc.printer)
  File "/app/.heroku/python/lib/python2.7/site-packages/honcho/printer.py", line 22, in write
    self.output.write(*new_args, **kwargs)
UnicodeEncodeError: 'ascii' codec can't encode character u'\xe8' in position 109: ordinal not in range(128)

[nickstenning]

Oh dear. That's not very good. Shouldn't be too hard to fix, I don't think. I'll take a look at the weekend.

[TimotheeJeannin]

Great, thank you ! :)

Another precision, running Honcho locally works fine for me.

Honcho locally - > Fine
Heroku without Honcho - > Fine
Heroku with Honcho - > Problem

Among others, I have those environment variables on Heroku:

USER=heroku
LANG=en_US.UTF-8

[jice-lavocat]

Hi Nick,

I also ran into the problem with some accentuated characters. Did you have time to look into that? Can we help somehow?

[nickstenning]

Hi guys. Sorry I haven't had a chance to look at this yet.

What would be really useful is a failing test case. If you feel up to it, a pull request with a test that demonstrates the failure consistently would be really useful. I imagine this will take the form of a script in tests/ that spits out Unicode characters and a corresponding test which attempts to run Honcho with that script in a Procfile.

[TimotheeJeannin]

I'm trying to write a test case that demonstrates the failure but it's not easy to do since it depends on the console encoding.

From my local environement:

>>> import sys
>>> sys.stdout.encoding
'UTF-8'

On Heroku, sys.stdout.encoding is None.

I just looked over the logging python package to how they are doing things and I found this:
https://bitbucket.org/pypy/pypy/src/9d88b4875d6e12570a635848524bb7f5283ee558/lib-python/2.7/logging/__init__.py?at=translation-cleanup

def emit(self, record):
    """
    Emit a record.

    If a formatter is specified, it is used to format the record.
    The record is then written to the stream with a trailing newline.  If
    exception information is present, it is formatted using
    traceback.print_exception and appended to the stream.  If the stream
    has an 'encoding' attribute, it is used to determine how to do the
    output to the stream.
    """
    try:
        msg = self.format(record)
        stream = self.stream
        fs = "%s\n"
        if not _unicode: #if no unicode support...
            stream.write(fs % msg)
        else:
            try:
                if (isinstance(msg, unicode) and
                    getattr(stream, 'encoding', None)):
                    ufs = fs.decode(stream.encoding)
                    try:
                        stream.write(ufs % msg)
                    except UnicodeEncodeError:
                        #Printing to terminals sometimes fails. For example,
                        #with an encoding of 'cp1251', the above write will
                        #work if written to a stream opened or wrapped by
                        #the codecs module, but fail when writing to a
                        #terminal even when the codepage is set to cp1251.
                        #An extra encoding step seems to be needed.
                        stream.write((ufs % msg).encode(stream.encoding))
                else:
                    stream.write(fs % msg)
            except UnicodeError:
                stream.write(fs % msg.encode("UTF-8"))
        self.flush()
    except (KeyboardInterrupt, SystemExit):
        raise
    except:
        self.handleError(record)

It looks a lot different in the actual source of python though : http://hg.python.org/cpython/file/ab05e7dd2788/Lib/logging

Maybe we can get some inspiration from this.

[malthe]

Any movement on this?

[nickstenning]

I don't think Honcho is doing anything wrong here. The purpose of the LANG environment variable is to tell programs what they can reasonably print. Honcho is accepting UTF-8 encoded characters and then refusing to print them to a terminal that can't accept them (i.e. one with LANG="").

If you want to fix this on Heroku, just set the LANG environment variable to something sensible, i.e.

heroku config:set LANG=en_US.UTF-8

[nickstenning]

To be clear, if you run Honcho in a terminal with an appropriate LANG, Honcho will work just fine. This issue only crops up when the terminal cannot accept UTF-8.

[fgrosse]

Just in case anybody else runs into this: I had to export PYTHONIOENCODING=utf-8 to solve the problem. Setting LANG=en_US.UTF-8 didnt solve the problem on my zsh.