nickstenning / honcho

Honcho: a python clone of Foreman. For managing Procfile-based applications.
http://pypi.python.org/pypi/honcho
MIT License
1.6k stars 146 forks source link

Stdout/stderr redirection #191

Closed ChillarAnand closed 7 years ago

ChillarAnand commented 7 years ago

When a process, say celery is started directly, it shows output like this.

/home/chillaranand/.virtualenvs/sherlock/lib/python3.5/site-packages/celery/backends/amqp.py:68: CPendingDeprecationWarning: 
    The AMQP result backend is scheduled for deprecation in     version 4.0 and removal in version v5.0.     Please use RPC backend or a persistent backend.

  alternative='Please use RPC backend or a persistent backend.')

 -------------- celery@pavilion v4.0.2 (latentcall)
---- **** ----- 
--- * ***  * -- Linux-4.4.0-75-generic-x86_64-with-Ubuntu-16.04-xenial 2017-05-04 16:32:19
-- * - **** --- 
- ** ---------- [config]
- ** ---------- .> app:         __main__:0x7f9d58040dd8
- ** ---------- .> transport:   amqp://guest:**@localhost:5672//
- ** ---------- .> results:     amqp://
- *** --- * --- .> concurrency: 4 (prefork)
-- ******* ---- .> task events: OFF (enable -E to monitor tasks in this worker)
--- ***** ----- 
 -------------- [queues]
                .> celery           exchange=celery(direct) key=celery

[tasks]
  . t.add
  . t.bar
  . t.baz
  . t.dummy
  . t.foo
  . t.mul
  . t.sub
  . t.wait

[2017-05-04 16:32:20,052: INFO/MainProcess] Connected to amqp://guest:**@127.0.0.1:5672//
[2017-05-04 16:32:20,062: INFO/MainProcess] mingle: searching for neighbors
[2017-05-04 16:32:21,082: INFO/MainProcess] mingle: all alone
[2017-05-04 16:32:21,106: INFO/MainProcess] celery@pavilion ready.

On the other hand, the same process gives this output with honcho.

16:31:55 celery.1 | [2017-05-04 11:01:55,306: INFO/MainProcess] Connected to amqp://guest:**@127.0.0.1:5672//
16:31:55 celery.1 | [2017-05-04 11:01:55,321: INFO/MainProcess] mingle: searching for neighbors
16:31:56 celery.1 | [2017-05-04 11:01:56,349: INFO/MainProcess] mingle: all alone
16:31:56 celery.1 | [2017-05-04 11:01:56,388: WARNING/MainProcess] /home/chillaranand/.virtualenvs/sherlock/lib/python3.5/site-packages/celery/fixups/
django.py:202: UserWarning: Using settings.DEBUG leads to a memory leak, never use this setting in production environments!
16:31:56 celery.1 |   warnings.warn('Using settings.DEBUG leads to a memory leak, never '
16:31:56 celery.1 | [2017-05-04 11:01:56,388: INFO/MainProcess] celery@pavilion ready.

After the process is stopped, it show stderr

^C16:32:06 system   | SIGINT received
16:32:06 system   | sending SIGTERM to celery.1 (pid 6727)
16:38:52 celery.1 | 
16:38:52 celery.1 | worker: Warm shutdown (MainProcess)
16:38:52 celery.1 |  
16:38:52 celery.1 |  -------------- celery@pavilion v4.0.2 (latentcall)
16:38:52 celery.1 | ---- **** ----- 
16:38:52 celery.1 | --- * ***  * -- Linux-4.4.0-75-generic-x86_64-with-Ubuntu-16.04-xenial 2017-05-04 11:08:45
16:38:52 celery.1 | -- * - **** --- 
16:38:52 celery.1 | - ** ---------- [config]
16:38:52 celery.1 | - ** ---------- .> app:         sherlock:0x7f3f35481208
16:38:52 celery.1 | - ** ---------- .> transport:   amqp://guest:**@localhost:5672//
16:38:52 celery.1 | - ** ---------- .> results:     disabled://
16:38:52 celery.1 | - *** --- * --- .> concurrency: 4 (prefork)
16:38:52 celery.1 | -- ******* ---- .> task events: OFF (enable -E to monitor tasks in this worker)
16:38:52 celery.1 | --- ***** ----- 
16:38:52 celery.1 |  -------------- [queues]
16:38:52 celery.1 |                 .> celery           exchange=celery(direct) key=celery
16:38:52 celery.1 |                 
16:38:52 celery.1 | 
16:38:52 celery.1 | [tasks]
16:38:52 celery.1 |   . mycroft.core.tasks.dummy
aisbaa commented 7 years ago
PYTHONUNBUFFERED=1 honcho start
ChillarAnand commented 7 years ago

Excellent. Thank you.

edmorley commented 7 years ago

Is disabling output buffering something that Honcho should be doing automatically?

For example some of the tricks in: https://stackoverflow.com/questions/107705/disable-output-buffering

ChillarAnand commented 7 years ago

Unfortunately, it didn't fix the issue. Only after honcho is stopped, stdout is getting flushed.

^C12:28:15 system   | SIGINT received
12:28:15 system   | sending SIGTERM to celery.1 (pid 19893)
12:28:15 system   | sending SIGTERM to minio.1 (pid 19894)
12:28:15 system   | sending SIGTERM to web.1 (pid 19895)
12:28:15 system   | minio.1 stopped (rc=-15)
12:28:15 system   | web.1 stopped (rc=-15)
12:28:16 celery.1 | 
12:28:16 celery.1 | worker: Warm shutdown (MainProcess)
12:28:16 celery.1 | [2017-07-06 06:58:16,867: INFO/MainProcess] beat: Shutting down...
12:28:17 celery.1 | aaaaaaaa