alexsilva / supervisor

Supervisor process control system for Windows
http://supervisord.org
Other
118 stars 26 forks source link

Subprocess log file setting issue #52

Open wssf812 opened 1 year ago

wssf812 commented 1 year ago

This is my configuration file [program:xxxx] command=cmd.exe xxxxx autostart=true autorestart=true startretries=3 stdout_logfile=NONE stderr_logfile=xx/xxx.log

I set the standard output log to empty and prevent it from entering relevant logs. But how can there be [info] level logs in the error log file? My loglevel=error

By the way, if the sub process frequently outputs logs, will it affect the performance of superviosr and cause blocking? This question is very important. Please answer it. Thank you

luolingchun commented 12 months ago

Same problem +1

use redirect_stderr=true, but no error logs in stdout_logfile.

alexsilva commented 10 months ago

@luolingchun

Same problem +1

use redirect_stderr=true, but no error logs in stdout_logfile.

What version of Python were you using when you did this test? I have noticed that version 3.10.11-amd64 is experiencing several instability issues.

luolingchun commented 10 months ago

@alexsilva

Python 3.8.5-amd64

OS: Windows 11

luolingchun commented 10 months ago

I did a more detailed test, and when Flask Debug mode is started, the print log will be output the next time the service is restarted (Debug mode).

  1. First step:
@app.route("/")
def index():
    print(111111111)
    print("test中文test")
    return "ok"

if __name__ == "__main__":
    app.run("0.0.0.0", 5001, debug=True)

Log out after sending two requests:

* Serving Flask app 'app'
 * Debug mode: on
WARNING: This is a development server. Do not use it in a production deployment. Use a production WSGI server instead.
 * Running on all addresses (0.0.0.0)
 * Running on http://127.0.0.1:5001
 * Running on http://10.0.7.217:5001
Press CTRL+C to quit
 * Restarting with stat
 * Debugger is active!
 * Debugger PIN: 283-907-158
127.0.0.1 - - [06/Nov/2023 10:58:40] "GET / HTTP/1.1" 200 -
127.0.0.1 - - [06/Nov/2023 10:58:45] "GET / HTTP/1.1" 200 -
  1. Second step: Add print(222222222)
    @app.route("/")
    def index():
    print(111111111)
    print("test中文test")
    print(222222222)
    return "ok"

    Log out:

You can see that the log has been refreshed.

But I have same issue with #49 (log missed 中文) and it is correct for me to go back to version 4.5.0.

...
127.0.0.1 - - [06/Nov/2023 11:07:02] "GET / HTTP/1.1" 200 -
127.0.0.1 - - [06/Nov/2023 11:07:04] "GET / HTTP/1.1" 200 -
 * Detected change in 'D:\\workspace\\xxx\\xxx-server\\src\\wsgi.py', reloading
111111111
testtest
111111111
testtest
 * Restarting with stat
 * Debugger is active!
 * Debugger PIN: 283-907-158

Complete configuration file:

[supervisord]
nodaemon=false

[inet_http_server]
port=*:9001

[supervisorctl]

[program:app-win1]
command=D:\\workspace\\xxx\\xxx-server\\venv\\Scripts\\python.exe D:\\workspace\\xxx\\xxx-server\\src\\wsgi.py
autostart=true
autorestart=true
# 将stderr的日志写入stdout日志文件中
redirect_stderr=true
stdout_logfile=D:\workspace\xxx\xxx-server\logs\app1.log
stdout_logfile_maxbytes=10MB
stdout_logfile_backups=5
# 杀死进程组包括子进程
stopasgroup=true
killasgroup=true
alexsilva commented 10 months ago

I did a more detailed test, and when Flask Debug mode is started, the print log will be output the next time the service is restarted (Debug mode).

  1. First step:
@app.route("/")
def index():
    print(111111111)
    print("test中文test")
    return "ok"

if __name__ == "__main__":
    app.run("0.0.0.0", 5001, debug=True)

Log out after sending two requests:

* Serving Flask app 'app'
 * Debug mode: on
WARNING: This is a development server. Do not use it in a production deployment. Use a production WSGI server instead.
 * Running on all addresses (0.0.0.0)
 * Running on http://127.0.0.1:5001
 * Running on http://10.0.7.217:5001
Press CTRL+C to quit
 * Restarting with stat
 * Debugger is active!
 * Debugger PIN: 283-907-158
127.0.0.1 - - [06/Nov/2023 10:58:40] "GET / HTTP/1.1" 200 -
127.0.0.1 - - [06/Nov/2023 10:58:45] "GET / HTTP/1.1" 200 -
  1. Second step: Add print(222222222)
@app.route("/")
def index():
    print(111111111)
    print("test中文test")
    print(222222222)
    return "ok"

Log out:

You can see that the log has been refreshed.

But I have same issue with #49 (log missed 中文) and it is correct for me to go back to version 4.5.0.

...
127.0.0.1 - - [06/Nov/2023 11:07:02] "GET / HTTP/1.1" 200 -
127.0.0.1 - - [06/Nov/2023 11:07:04] "GET / HTTP/1.1" 200 -
 * Detected change in 'D:\\workspace\\xxx\\xxx-server\\src\\wsgi.py', reloading
111111111
testtest
111111111
testtest
 * Restarting with stat
 * Debugger is active!
 * Debugger PIN: 283-907-158

Complete configuration file:

[supervisord]
nodaemon=false

[inet_http_server]
port=*:9001

[supervisorctl]

[program:app-win1]
command=D:\\workspace\\xxx\\xxx-server\\venv\\Scripts\\python.exe D:\\workspace\\xxx\\xxx-server\\src\\wsgi.py
autostart=true
autorestart=true
# 将stderr的日志写入stdout日志文件中
redirect_stderr=true
stdout_logfile=D:\workspace\xxx\xxx-server\logs\app1.log
stdout_logfile_maxbytes=10MB
stdout_logfile_backups=5
# 杀死进程组包括子进程
stopasgroup=true
killasgroup=true

What encoding is used in the script to print "test中文test"?

Does configuring python encoding before initializing it solve the problem?

set PYTHONIOENCODING=utf8

luolingchun commented 10 months ago

@alexsilva Thanks, it's worked.

[supervisord]
nodaemon=false
environment=PYTHONIOENCODING="utf8"

...

Is there a solution to the problem of delayed printing of logs?

luolingchun commented 10 months ago

I got it.

PYTHONIOENCODING=utf8 for correct encoding and PYTHONUNBUFFERED=1 for correct logs.

[supervisord]
nodaemon=false
environment=PYTHONIOENCODING=utf8,PYTHONUNBUFFERED=1

...
alexsilva commented 10 months ago

Recently I introduced a new concept and it serves to control the time that the process is idle. The more processing there is, the more the sleep time tends to zero. This will help with log processing as well.

@wssf812 @luolingchun time machine