Supervisor / supervisor

Supervisor process control system for Unix (supervisord)
http://supervisord.org
Other
8.44k stars 1.24k forks source link

Add ability to specify log format #553

Open mminer opened 9 years ago

mminer commented 9 years ago

It would be helpful to have control over the format of the log output. For inspiration, other tools that allow you to customize the log format include Celery (CELERYD_LOG_FORMAT) and Gunicorn (access_log_format).

oponcea-dn commented 1 year ago

+1

sscarduzio commented 1 year ago

This should be added as a core feature in supervisord, it's not a job for weird wrapper scripts.

j0wns commented 1 year ago

For ones who are looking for some workaround. Here is how I ended with prefixing output with process name:

supervisor.conf

[program:process-1]
command=/path-to/prefix-output.sh executable1

[program:process-2]
command=/path-to/prefix-output.sh executable2

prefix-output.sh

#!/bin/bash

# Get prefix from SUPERVISOR_PROCESS_NAME environment variable
printf -v PREFIX "%-10.10s" "${SUPERVISOR_PROCESS_NAME}"

# Prefix stdout and stderr
exec 1> >( perl -ne '$| = 1; print "'"${PREFIX}"' | $_"' >&1)
exec 2> >( perl -ne '$| = 1; print "'"${PREFIX}"' | $_"' >&2)

exec "$@"

Example output

process-1  | Some process output
process-2  | Very important message
...

Inspired and mostly copy-pasted from: https://serverfault.com/a/946271

This was an excellent starting point for adding a static name to subprocess output.

I wanted improve the consistency for readability and parsing by adding per-line time stamps that matched supervisord's format: '2023-06-09 17:25:36,778 INFO Included extra file "/etc/supervisor/conf.d/example.conf" during parsing'

This perl in the following heredoc will calculate a timestamp at run time for each line that is sent to stdout and stderr

# https://github.com/Supervisor/supervisor/issues/553
# Refer: https://stackoverflow.com/questions/26032541/how-to-get-system-time-in-nano-seconds-in-perl
cat << 'EOF' > /opt/supervisord/prefix-output.sh
#!/bin/bash

# Prefix outputs with Time Stamp and Process Name
exec 1> >( perl -ne 'use Time::HiRes qw(time); use POSIX qw( strftime ); $time=time; $microsecs = ($time - int($time)) * 1e3; $| = 1; printf( "%s,%03.0f '"${SUPERVISOR_PROCESS_NAME}"' %s", strftime("%Y-%m-%d %H:%M:%S", gmtime($time)), $microsecs, $_);' >&1)
exec 2> >( perl -ne 'use Time::HiRes qw(time); use POSIX qw( strftime ); $time=time; $microsecs = ($time - int($time)) * 1e3; $| = 1; printf( "%s,%03.0f '"${SUPERVISOR_PROCESS_NAME}"' %s", strftime("%Y-%m-%d %H:%M:%S", gmtime($time)), $microsecs, $_);' >&2)

exec "$@"
EOF

Example Output running within a docker container

container  | 2023-06-09 17:39:30,474 INFO spawned: 'env' with pid 61
container  | 2023-06-09 17:39:30,474 INFO success: env entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
container  | 2023-06-09 17:39:30,507 env SUPERVISOR_GROUP_NAME=init
container  | 2023-06-09 17:39:30,507 env SUPERVISOR_SERVER_URL=unix:///var/run/supervisor.sock
kadirgun commented 4 months ago

+1

mrtzgh commented 3 months ago

+1

CRCinAU commented 3 months ago

+1

Pre-Z commented 1 month ago

+1

RDonii commented 1 week ago

+1