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.

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

Cleanup logging #255

Closed
wants to merge 3 commits into from
Closed

Cleanup logging #255

wants to merge 3 commits into from

Conversation

vlovich
Copy link

@vlovich vlovich commented May 14, 2015

This ensures, particularly with executables living in long paths, that we don't have uninteresting log context spamming the log lines. Printing a truncated version of the command & the call args on every log-line is just spam. Also, it makes sure that the INFO message that gets printed contains the full command that was executed & with whitespace escaped properly so that you can copy directly from the log-line & paste.

Vitali Lovich added 2 commits May 13, 2015 22:27
None in particular would cause an exception through on creation of a
sub-context.
Remove context from the 'command' logger to reduce verbosity & duplication.
Have the child process logger include just the pid as context.

Have the parent print the full command that was executed.

This reduces the length of the log-line (& thus noise) signficantly &
ensures that the entire command is logged (which makes it useful for
debugging).
@vlovich vlovich force-pushed the cleanup-logging branch from 97b2182 to c4bbaba Compare May 14, 2015 05:48
@vlovich
Copy link
Author

vlovich commented May 14, 2015

Sample output:

INFO:sh.command.process:84960: started /opt/homebrew/opt/coreutils/libexec/gnubin/ls -la 'abc def'
DEBUG:sh.command:starting process 84960: "['/opt/homebrew/opt/coreutils/libexec/gnubin/ls', '-la', 'abc def']"
DEBUG:sh.command.process.streamwriter:84960.stdin: parsed stdin as a queue
DEBUG:sh.command.process:84960: <sh.StreamWriter object at 0x102330c50> ready for more input
DEBUG:sh.command.process:84960: acquiring wait lock to wait for completion
DEBUG:sh.command.process:84960: got wait lock
DEBUG:sh.command.process:84960: exit code not set, waiting on pid
DEBUG:sh.command.process.streamwriter:84960.stdin: received no data
...

This lets you copy-paste the output which is convenient when debugging
these sorts of programs.
@vlovich vlovich force-pushed the cleanup-logging branch from c4bbaba to a9e19fa Compare May 22, 2015 18:15
@marascio
Copy link

I was just about to go implement this as the current INFO level logging is uninteresting in almost all cases because of the truncation, for example:

sh.command I <Command '/var/lib/condor/exec...(81 more)' call_args {'bg': False, 'timeo...(485 more)>: starting process

What I want is simply a full synopsis of the command being executed, just as is implemented in this pull request.

What needs to happen to get this merged?

@virtuald
Copy link

+1 on this functionality

@amoffat
Copy link
Owner

amoffat commented Oct 6, 2016

I made some very similar changes for #323. They're in the release-1.2 branch and will go out with it

@amoffat amoffat closed this Oct 6, 2016
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

4 participants