"honcho start" gives no output

[jlirochon]

     $ honcho start
     (...stalled here...)
    ^C
    22:00:48 system | web.1 started (pid=20863)
    22:01:24 system | SIGINT received
    22:01:24 system | sending SIGTERM to web.1 (pid 20863)
    22:01:24 system | web.1 stopped (rc=-15)

But, if I user PYTHONUNBUFFERED it works

    $ PYTHONUNBUFFERED=1 honcho start
    22:02:10 system | web.1 started (pid=20877)
    22:02:10 web.1  | serving on http://0.0.0.0:8080

Sys info :

    $ uname -a
    Darwin Juliens-MacBook-Pro.local 14.1.0 Darwin Kernel Version 14.1.0: Mon Dec 22 23:10:38 PST 2014; root:xnu-2782.10.72~2/RELEASE_X86_64 x86_64
    $ python --version
    Python 3.4.2

[msabramo]

Ditto here.

[marca@marca-mac2 honcho]$ python -V
Python 3.4.2
[marca@marca-mac2 honcho]$ cat Procfile
web: cat

Without PYTHONUNBUFFERED, I get no output until I hit Ctrl-C:

[marca@marca-mac2 honcho]$ honcho start
^C13:43:22 system | web.1 started (pid=85574)
13:43:26 system | SIGINT received
13:43:26 system | sending SIGTERM to web.1 (pid 85574)
13:43:26 system | web.1 stopped (rc=-15)

With PYTHONUNBUFFERED=1, I do see it output web.1 started right away:

[marca@marca-mac2 honcho]$ PYTHONUNBUFFERED=1 honcho start
13:43:30 system | web.1 started (pid=85578)
^C13:43:32 system | SIGINT received
13:43:32 system | sending SIGTERM to web.1 (pid 85578)
13:43:32 system | web.1 stopped (rc=-15)

[msabramo]

This seems to only happen on Python 3; it does not happen for me with Python 2.7.9.

[msabramo]

Same behavior on Python 3.2 and 3.3.

[derbroti]

Just a minor remark: The issue was introduced in the 0.6.x series. 0.5.0 works fine, every newer version has this issue. Tested with python 3.4.x.

[gregmuellegger]

I also have this issue when using 0.7.1, even with Python 2.7. In the example below you can see that the Django startup message is swallowed if PYTHONUNBUFFERED is not set:

$ honcho start
09:46:58 system    | webpack.1 started (pid=7112)
09:46:58 system    | web.1 started (pid=7113)
09:46:58 webpack.1 | Live Reload listening on port 35729
09:46:58 webpack.1 | 
09:46:58 webpack.1 | webpack building...
09:47:04 webpack.1 | webpack built 515a36861413ce8243ac in 6445ms
^C09:47:08 system    | SIGINT received
09:47:08 system    | sending SIGTERM to webpack.1 (pid 7112)
09:47:08 system    | sending SIGTERM to web.1 (pid 7113)
09:47:08 system    | web.1 stopped (rc=-15)
09:47:08 system    | webpack.1 stopped (rc=-15)

$ PYTHONUNBUFFERED=1 honcho start
09:47:17 system    | web.1 started (pid=7234)
09:47:17 system    | webpack.1 started (pid=7233)
09:47:17 webpack.1 | Live Reload listening on port 35729
09:47:17 webpack.1 | 
09:47:17 webpack.1 | webpack building...
09:47:17 web.1     | Performing system checks...
09:47:17 web.1     | 
09:47:17 web.1     | System check identified no issues (0 silenced).
09:47:17 web.1     | April 15, 2016 - 07:47:17
09:47:17 web.1     | Django version 1.9.5, using settings 'website.settings'
09:47:17 web.1     | Starting development server at http://127.0.0.1:8000/
09:47:17 web.1     | Quit the server with CONTROL-C.
09:47:23 webpack.1 | webpack built 515a36861413ce8243ac in 6406ms
09:47:25 web.1     | [15/Apr/2016 07:47:25] "GET / HTTP/1.1" 200 38
09:47:27 web.1     | [15/Apr/2016 07:47:27] "GET / HTTP/1.1" 200 38
^C09:47:45 system    | SIGINT received
09:47:45 system    | sending SIGTERM to webpack.1 (pid 7233)
09:47:45 system    | sending SIGTERM to web.1 (pid 7234)
09:47:45 system    | web.1 stopped (rc=-15)
09:47:45 system    | webpack.1 stopped (rc=-15)

$ honcho version
honcho 0.7.1

$ python --version
Python 2.7.11

[nickstenning]

If Django's runserver buffers its output, there's nothing Honcho can do about that. You can verify that this is not a Honcho issue by setting PYTHONUNBUFFERED=1 in the Procfile just for the Django process.

[gregmuellegger]

That... makes absolutely sense. Thanks for getting me on the right track!