This issue tracker has been migrated to GitHub, and is currently read-only.
For more information, see the GitHub FAQs in the Python's Developer Guide.

classification
Title: SysLogHandler does not seem to always expand %(loglevel)s properly
Type: Stage: resolved
Components: Versions: Python 2.7
process
Status: closed Resolution: not a bug
Dependencies: Superseder:
Assigned To: Nosy List: thread13, vinay.sajip
Priority: normal Keywords:

Created on 2017-02-28 10:42 by thread13, last changed 2022-04-11 14:58 by admin. This issue is now closed.

Files
File name Uploaded Description Edit
bad.py thread13, 2017-02-28 10:42 test file to reproduce the bug
good.py thread13, 2017-02-28 10:44
Messages (4)
msg288702 - (view) Author: Q (thread13) Date: 2017-02-28 10:42
On Ubuntu LTS 16.04, SysLogHandler with a custom formatter does not seem to expand loglevel/levelno fields properly, when there are square brackets ( see the attached examples ). Instead, it seems to replace '[%(loglevel)s]' with a '[pid]', and '%(loglevel)s' with 'LOGLEVEL[pid]' .

To test, run 'journalctl -f | grep test_test_test' on one console, and the attached files on another. The output for 'bad.py' looks as follows:
===
Feb 28 21:30:05 hostname <test_test_test>[7117]: logging was configured for process <7117>
===

And should have looked like:
===
Feb 28 21:30:05 hostname <test_test_test>[INFO]: logging was configured for process <7117>
===

For 'good.py', the output is as follows:
===
Feb 28 21:30:04 hostname <test_test_test>INFO[7114]: logging was configured for process <7114>
===

and should have probably been: 
===
Feb 28 21:30:04 hostname <test_test_test>INFO: logging was configured for process <7114>
===

Kind regards, /t13
msg288703 - (view) Author: Q (thread13) Date: 2017-02-28 10:44
Attaching the other file mentioned.
msg288704 - (view) Author: Q (thread13) Date: 2017-02-28 10:51
PS. I'm not sure if that is a systemd/journald issue, or indeed a Python bug.

However, it would be nice to clear one possibility. 

For a StreamHandler, it all works as it should.
msg288742 - (view) Author: Vinay Sajip (vinay.sajip) * (Python committer) Date: 2017-03-01 07:28
This is not a bug - logging is formatting the message as per the specified format string. It then prepends the priority and sends the result to the socket. What you are seeing is just how systemd/journald interpret the message that's sent.
History
Date User Action Args
2022-04-11 14:58:43adminsetgithub: 73861
2017-03-01 07:28:38vinay.sajipsetstatus: open -> closed
resolution: not a bug
messages: + msg288742

stage: resolved
2017-02-28 10:51:30thread13setmessages: + msg288704
2017-02-28 10:48:01serhiy.storchakasetnosy: + vinay.sajip
2017-02-28 10:44:20thread13setfiles: + good.py

messages: + msg288703
2017-02-28 10:42:29thread13create