Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

supervisor-stdout introduces some sort of buffer lag, delaying log lines up to ~10 minutes #25

Open
whereisaaron opened this issue Jun 7, 2024 · 2 comments · May be fixed by #26
Open

supervisor-stdout introduces some sort of buffer lag, delaying log lines up to ~10 minutes #25

whereisaaron opened this issue Jun 7, 2024 · 2 comments · May be fixed by #26

Comments

@whereisaaron
Copy link

whereisaaron commented Jun 7, 2024 •
edited
Loading

UPDATE: Fixed by #26 and this fork

I have a supervisor-stdout configuration working well, but the event forwarding is introducing considerable buffer lag into logs. Events collected by supervisor-stdout will often not be emitted by supervisord stdout until up to ~10 minutes later. The time is variable. It is usually worst when applications starts or has been dormant. Logs just don't flow. Then after ~10 minutes a whole bunch of old log messages will be output by supervisord. Once the application gets busy, the lag is usually small or only a few seconds.

You can see here that supervisord output many log lines (~100) in the same micro-second (left timestamp). But the log lines themselves span several minutes (~10 minutes, timestamps on right). This didn't happen until I introduced [supervisor + supervisor-stdout] into the application. Anyone else seen this? Is this a problem with output buffering in the supervisor-stdout handler?

image
@whereisaaron
Copy link
Author

So the problem stems from Python stdout which is automatically block-buffered when not interactive. This used to apply to stderr too, but that no doubt swallowed error messages, so they disabled that. Now the behaviour is inconsistent.

With python 3, there is an extra option to print to flush the buffer, print('foo', flush=True). I patched my branch to do that and it seems to have fixed the huge buffer lag I was seeing.

When interactive, the stdout stream is line-buffered. Otherwise, it is block-buffered like regular text files. The stderr stream is line-buffered in both cases. You can make both streams unbuffered by passing the -u command-line option or setting the PYTHONUNBUFFERED environment variable.

Changed in version 3.9: Non-interactive stderr is now line-buffered instead of fully buffered.

whereisaaron@93ecc0b
image

@whereisaaron whereisaaron linked a pull request Jun 7, 2024 that will close this issue
Open
@whereisaaron
Copy link
Author

I fixed this and made a PR #26.
This fork includes the fix and more formatting features.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

Fixes blank lines & buffer lag, add alternative formatting options whereisaaron/supervisor-stdout
1 participant
@whereisaaron