Skip to content

Remove log duplication with ap_log_error() and friends#941

Open
michael-o wants to merge 1 commit intoGrahamDumpleton:developfrom
michael-o:remove-log-duplication
Open

Remove log duplication with ap_log_error() and friends#941
michael-o wants to merge 1 commit intoGrahamDumpleton:developfrom
michael-o:remove-log-duplication

Conversation

@michael-o
Copy link
Contributor

@michael-o michael-o commented Feb 14, 2026 •
edited
Loading

Previously, every log line contained the string 'mod_wsgi' along with the current pid. Both duplicate error log format parameters %P (current pid) and %m (the module logging). Hence, remove the duplication.

Moreover, I have fixed a few messages for position for args or consistent style.

Log sample after change:
httpd-error.log:

2026-02-14 22:24:13.492295 [pid: 90361, tid: 35041079296] [wsgi:debug] src/server/mod_wsgi.c(8545): Socket for 'kona' is '/var/run/wsgi.90361.0.1.sock'.
2026-02-14 22:24:13.492347 [pid: 90361, tid: 35041079296] [wsgi:debug] src/server/mod_wsgi.c(8614): Listen backlog for socket '/var/run/wsgi.90361.0.1.sock' is 100.
2026-02-14 22:24:13.493053 [pid: 90364, tid: 35041079296] [wsgi:info] Starting process 'kona' with uid=1001, gid=1001 and threads=5.
2026-02-14 22:24:13.493508 [pid: 90364, tid: 35041079296] [wsgi:info] Python home /usr/local/kona/app/.venv.
2026-02-14 22:24:13.493810 [pid: 90364, tid: 35041079296] [wsgi:info] Initializing Python.
2026-02-14 22:24:13.495049 [pid: 90365, tid: 35041079296] [wsgi:info] Initializing Python.
2026-02-14 22:24:13.495418 [pid: 90366, tid: 35041079296] [wsgi:info] Initializing Python.
2026-02-14 22:24:13.495687 [pid: 90367, tid: 35041079296] [wsgi:info] Initializing Python.
2026-02-14 22:24:13.529998 [pid: 90366, tid: 35041079296] [wsgi:info] Attach interpreter ''.
2026-02-14 22:24:13.530169 [pid: 90365, tid: 35041079296] [wsgi:info] Attach interpreter ''.
2026-02-14 22:24:13.530196 [pid: 90367, tid: 35041079296] [wsgi:info] Attach interpreter ''.
2026-02-14 22:24:14.504023 [pid: 90373, tid: 35041079296] [wsgi:info] Initializing Python.
2026-02-14 22:24:14.518709 [pid: 90373, tid: 35041079296] [wsgi:info] Attach interpreter ''.
2026-02-14 22:29:57.879876 [pid: 90361, tid: 35041079296] [wsgi:info] Process 'kona' (pid=90364) has died, deregister and restart it.
2026-02-14 22:29:57.879957 [pid: 90361, tid: 35041079296] [wsgi:info] Process 'kona' (pid=90364) terminated normally, exit code 0
2026-02-14 22:29:57.879985 [pid: 90361, tid: 35041079296] [wsgi:info] Process 'kona' (pid=90364) has been deregistered and will no longer be monitored.
2026-02-14 22:29:57.880955 [pid: 91649, tid: 35041079296] [wsgi:info] Starting process 'kona' with uid=1001, gid=1001 and threads=5.
2026-02-14 22:29:57.881471 [pid: 91649, tid: 35041079296] [wsgi:info] Python home /usr/local/kona/app/.venv.
2026-02-14 22:29:57.881799 [pid: 91649, tid: 35041079296] [wsgi:info] Initializing Python.
2026-02-14 22:30:57.496932 [pid: 90361, tid: 35041079296] [wsgi:info] Process 'kona' (pid=91649) has died, deregister and restart it.
2026-02-14 22:30:57.496994 [pid: 90361, tid: 35041079296] [wsgi:info] Process 'kona' (pid=91649) terminated normally, exit code 0
2026-02-14 22:30:57.497004 [pid: 90361, tid: 35041079296] [wsgi:info] Process 'kona' (pid=91649) has been deregistered and will no longer be monitored.
2026-02-14 22:30:57.498151 [pid: 91902, tid: 35041079296] [wsgi:info] Starting process 'kona' with uid=1001, gid=1001 and threads=5.
2026-02-14 22:30:57.498665 [pid: 91902, tid: 35041079296] [wsgi:info] Python home /usr/local/kona/app/.venv.
2026-02-14 22:30:57.498976 [pid: 91902, tid: 35041079296] [wsgi:info] Initializing Python.
2026-02-14 22:32:00.122037 [pid: 90361, tid: 35041079296] [wsgi:info] Process 'kona' (pid=91902) has died, deregister and restart it.
2026-02-14 22:32:00.122103 [pid: 90361, tid: 35041079296] [wsgi:info] Process 'kona' (pid=91902) terminated by signal 9
2026-02-14 22:32:00.122130 [pid: 90361, tid: 35041079296] [wsgi:info] Process 'kona' (pid=91902) has been deregistered and will no longer be monitored.
2026-02-14 22:32:00.123113 [pid: 92143, tid: 35041079296] [wsgi:info] Starting process 'kona' with uid=1001, gid=1001 and threads=5.
2026-02-14 22:32:00.123620 [pid: 92143, tid: 35041079296] [wsgi:info] Python home /usr/local/kona/app/.venv.
2026-02-14 22:32:00.123933 [pid: 92143, tid: 35041079296] [wsgi:info] Initializing Python.

vhost-error.log:

2026-02-14 22:24:13.510299 [pid: 90364, tid: 35041079296] [wsgi:info] Attach interpreter ''.
2026-02-14 22:24:13.519895 [pid: 90364, tid: 35041079296] [wsgi:info] Adding '/usr/local/kona/app' to path.
2026-02-14 22:24:13.533654 [pid: 90364, tid: 35041079296] [wsgi:info] Create interpreter 'kona'.
2026-02-14 22:24:13.542629 [pid: 90364, tid: 35041079296] [wsgi:info] Adding '/usr/local/kona/app' to path.
2026-02-14 22:24:13.543102 [pid: 90364, tid: 35041079296] [wsgi:info] Loading Python script '/usr/local/kona/wsgi/kona.wsgi' for process 'kona' and application 'kona'.
2026-02-14 22:24:15.337069 [pid: 90364, tid: 36794413312] [wsgi:debug] src/server/mod_wsgi.c(9175): Started thread 0 in daemon process 'kona'.
2026-02-14 22:24:15.337121 [pid: 90364, tid: 36794415104] [wsgi:debug] src/server/mod_wsgi.c(9175): Started thread 1 in daemon process 'kona'.
2026-02-14 22:24:15.337149 [pid: 90364, tid: 36794416896] [wsgi:debug] src/server/mod_wsgi.c(9175): Started thread 2 in daemon process 'kona'.
2026-02-14 22:24:15.337192 [pid: 90364, tid: 36794418688] [wsgi:debug] src/server/mod_wsgi.c(9175): Started thread 3 in daemon process 'kona'.
2026-02-14 22:24:15.337244 [pid: 90364, tid: 36794420480] [wsgi:debug] src/server/mod_wsgi.c(9175): Started thread 4 in daemon process 'kona'.
2026-02-14 22:29:56.672170 [pid: 90364, tid: 36794418688] [wsgi:info] [client: 10.64.3.54:36062] [cid: rnrkV4+E0Sk, rid: aZDpVIzb7kryvze0UJXqZwAAWBM] Force restart of process 'kona'.
2026-02-14 22:29:56.672232 [pid: 90364, tid: 35041079296] [wsgi:info] Shutdown requested 'kona'.
2026-02-14 22:29:56.672254 [pid: 90366, tid: 35696445440] [wsgi:info] [client: 10.64.3.54:36062] [cid: rnrkV4+E0Sk, rid: aZDpVIzb7kryvze0UJXqZwAAWBM] Connect after WSGI daemon process restart, attempt #1.
2026-02-14 22:29:56.672263 [pid: 90364, tid: 36794418688] [wsgi:debug] src/server/mod_wsgi.c(9156): Exiting thread 3 in daemon process 'kona'.
2026-02-14 22:29:56.672297 [pid: 90364, tid: 36794413312] [wsgi:debug] src/server/mod_wsgi.c(9156): Exiting thread 0 in daemon process 'kona'.
2026-02-14 22:29:56.672301 [pid: 90364, tid: 36794420480] [wsgi:debug] src/server/mod_wsgi.c(9156): Exiting thread 4 in daemon process 'kona'.
2026-02-14 22:29:56.672411 [pid: 90364, tid: 35041079296] [wsgi:info] Stopping process 'kona'.
2026-02-14 22:29:56.672431 [pid: 90364, tid: 35041079296] [wsgi:info] Destroying interpreters.
2026-02-14 22:29:56.672442 [pid: 90364, tid: 35041079296] [wsgi:info] Destroy interpreter 'kona'.
2026-02-14 22:29:56.672471 [pid: 90364, tid: 35041079296] [wsgi:info] End interpreter 'kona'.
2026-02-14 22:29:56.672414 [pid: 90364, tid: 36794416896] [wsgi:debug] src/server/mod_wsgi.c(9156): Exiting thread 2 in daemon process 'kona'.
2026-02-14 22:29:56.672418 [pid: 90364, tid: 36794415104] [wsgi:debug] src/server/mod_wsgi.c(9156): Exiting thread 1 in daemon process 'kona'.
2026-02-14 22:29:57.133738 [pid: 90364, tid: 35041079296] [wsgi:info] Cleanup interpreter ''.
2026-02-14 22:29:57.133872 [pid: 90364, tid: 35041079296] [wsgi:info] Terminating Python.
2026-02-14 22:29:57.141310 [pid: 90364, tid: 35041079296] [wsgi:info] Python has shutdown.
2026-02-14 22:29:57.141379 [pid: 90364, tid: 35041079296] [wsgi:info] Exiting process 'kona'.
2026-02-14 22:29:57.897903 [pid: 91649, tid: 35041079296] [wsgi:info] Attach interpreter ''.
2026-02-14 22:29:57.907305 [pid: 91649, tid: 35041079296] [wsgi:info] Adding '/usr/local/kona/app' to path.
2026-02-14 22:29:57.920778 [pid: 91649, tid: 35041079296] [wsgi:info] Create interpreter 'kona'.
2026-02-14 22:29:57.929432 [pid: 91649, tid: 35041079296] [wsgi:info] Adding '/usr/local/kona/app' to path.
2026-02-14 22:29:57.929883 [pid: 91649, tid: 35041079296] [wsgi:info] Loading Python script '/usr/local/kona/wsgi/kona.wsgi' for process 'kona' and application 'kona'.
2026-02-14 22:29:59.708672 [pid: 91649, tid: 36889547008] [wsgi:debug] src/server/mod_wsgi.c(9175): Started thread 0 in daemon process 'kona'.
2026-02-14 22:29:59.708816 [pid: 91649, tid: 36889548800] [wsgi:debug] src/server/mod_wsgi.c(9175): Started thread 1 in daemon process 'kona'.
2026-02-14 22:29:59.708854 [pid: 91649, tid: 36889550592] [wsgi:debug] src/server/mod_wsgi.c(9175): Started thread 2 in daemon process 'kona'.
2026-02-14 22:29:59.708890 [pid: 91649, tid: 36889552384] [wsgi:debug] src/server/mod_wsgi.c(9175): Started thread 3 in daemon process 'kona'.
2026-02-14 22:29:59.708930 [pid: 91649, tid: 36889554176] [wsgi:debug] src/server/mod_wsgi.c(9175): Started thread 4 in daemon process 'kona'.
2026-02-14 22:30:56.730069 [pid: 91649, tid: 35041079296] [wsgi:info] Shutdown requested 'kona'.
2026-02-14 22:30:56.730300 [pid: 91649, tid: 35041079296] [wsgi:info] Stopping process 'kona'.
2026-02-14 22:30:56.730300 [pid: 91649, tid: 36889554176] [wsgi:debug] src/server/mod_wsgi.c(9156): Exiting thread 4 in daemon process 'kona'.
2026-02-14 22:30:56.730304 [pid: 91649, tid: 36889550592] [wsgi:debug] src/server/mod_wsgi.c(9156): Exiting thread 2 in daemon process 'kona'.
2026-02-14 22:30:56.730301 [pid: 91649, tid: 36889552384] [wsgi:debug] src/server/mod_wsgi.c(9156): Exiting thread 3 in daemon process 'kona'.
2026-02-14 22:30:56.730306 [pid: 91649, tid: 36889548800] [wsgi:debug] src/server/mod_wsgi.c(9156): Exiting thread 1 in daemon process 'kona'.
2026-02-14 22:30:56.730322 [pid: 91649, tid: 35041079296] [wsgi:info] Destroying interpreters.
2026-02-14 22:30:56.730424 [pid: 91649, tid: 35041079296] [wsgi:info] Destroy interpreter 'kona'.
2026-02-14 22:30:56.730460 [pid: 91649, tid: 35041079296] [wsgi:info] End interpreter 'kona'.
2026-02-14 22:30:57.214328 [pid: 91649, tid: 35041079296] [wsgi:info] Cleanup interpreter ''.
2026-02-14 22:30:57.214486 [pid: 91649, tid: 35041079296] [wsgi:info] Terminating Python.
2026-02-14 22:30:57.221727 [pid: 91649, tid: 35041079296] [wsgi:info] Python has shutdown.
2026-02-14 22:30:57.221790 [pid: 91649, tid: 35041079296] [wsgi:info] Exiting process 'kona'.
2026-02-14 22:30:57.515110 [pid: 91902, tid: 35041079296] [wsgi:info] Attach interpreter ''.
2026-02-14 22:30:57.524637 [pid: 91902, tid: 35041079296] [wsgi:info] Adding '/usr/local/kona/app' to path.
2026-02-14 22:30:57.538273 [pid: 91902, tid: 35041079296] [wsgi:info] Create interpreter 'kona'.
2026-02-14 22:30:57.547050 [pid: 91902, tid: 35041079296] [wsgi:info] Adding '/usr/local/kona/app' to path.
2026-02-14 22:30:57.547507 [pid: 91902, tid: 35041079296] [wsgi:info] Loading Python script '/usr/local/kona/wsgi/kona.wsgi' for process 'kona' and application 'kona'.
2026-02-14 22:30:59.334109 [pid: 91902, tid: 36861343744] [wsgi:debug] src/server/mod_wsgi.c(9175): Started thread 1 in daemon process 'kona'.
2026-02-14 22:30:59.334084 [pid: 91902, tid: 36861341952] [wsgi:debug] src/server/mod_wsgi.c(9175): Started thread 0 in daemon process 'kona'.
2026-02-14 22:30:59.334146 [pid: 91902, tid: 36861345536] [wsgi:debug] src/server/mod_wsgi.c(9175): Started thread 2 in daemon process 'kona'.
2026-02-14 22:30:59.334166 [pid: 91902, tid: 36861347328] [wsgi:debug] src/server/mod_wsgi.c(9175): Started thread 3 in daemon process 'kona'.
2026-02-14 22:30:59.334193 [pid: 91902, tid: 36861349120] [wsgi:debug] src/server/mod_wsgi.c(9175): Started thread 4 in daemon process 'kona'.
2026-02-14 22:32:00.140119 [pid: 92143, tid: 35041079296] [wsgi:info] Attach interpreter ''.
2026-02-14 22:32:00.149611 [pid: 92143, tid: 35041079296] [wsgi:info] Adding '/usr/local/kona/app' to path.
2026-02-14 22:32:00.163227 [pid: 92143, tid: 35041079296] [wsgi:info] Create interpreter 'kona'.
2026-02-14 22:32:00.171995 [pid: 92143, tid: 35041079296] [wsgi:info] Adding '/usr/local/kona/app' to path.
2026-02-14 22:32:00.172455 [pid: 92143, tid: 35041079296] [wsgi:info] Loading Python script '/usr/local/kona/wsgi/kona.wsgi' for process 'kona' and application 'kona'.
2026-02-14 22:32:01.968997 [pid: 92143, tid: 36214612224] [wsgi:debug] src/server/mod_wsgi.c(9175): Started thread 0 in daemon process 'kona'.
2026-02-14 22:32:01.969024 [pid: 92143, tid: 36214614016] [wsgi:debug] src/server/mod_wsgi.c(9175): Started thread 1 in daemon process 'kona'.
2026-02-14 22:32:01.969055 [pid: 92143, tid: 36214615808] [wsgi:debug] src/server/mod_wsgi.c(9175): Started thread 2 in daemon process 'kona'.
2026-02-14 22:32:01.969079 [pid: 92143, tid: 36214617600] [wsgi:debug] src/server/mod_wsgi.c(9175): Started thread 3 in daemon process 'kona'.
2026-02-14 22:32:01.969115 [pid: 92143, tid: 36214619392] [wsgi:debug] src/server/mod_wsgi.c(9175): Started thread 4 in daemon process 'kona'.

All information is retained through ErrorLogFormat:

"%{cu}t [pid: %P, tid: %T] [%-m:%l] [client:\ %a] [cid:\ %{c}L,\ rid:\ %-L] %7F: %E: %M"

@michael-o
Remove log duplication with ap_log_error() and friends
eeb468d 
Previously, every log line contained the string 'mod_wsgi' along with the
current pid. Both duplicate error log format parameters '%P' (current pid) and
'%m' (the module logging). Hence, remove the duplication.
@michael-o
Copy link
Contributor Author

michael-o commented Feb 14, 2026

If necessary, I can move the message fixes into a separate PR.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Reviewers

No reviews

Assignees

No one assigned

Labels

None yet

Projects

None yet

Milestone

No milestone

Development

Successfully merging this pull request may close these issues.

1 participant

@michael-o