Why do I get a spurious ']' character in syslog messages with Python's SysLogHandler on OS X?

Question

With Python 3.5 on OS X 10.10.4, I get spurious ] characters in the output syslog messages. This can be seen with the following sample program:

#!/usr/bin/env python3

import logging
import logging.handlers

logger = logging.getLogger('test')

syslog_handler = logging.handlers.SysLogHandler(address='/var/run/syslog')
syslog_formatter = logging.Formatter('[{process}] {message}', style='{')
syslog_handler.setFormatter(syslog_formatter)

logger.addHandler(syslog_handler)
logger.error("Test : ABC")

If I run this, I see syslog output like this:

Dec 16 12:38:33 mymachinename [76399] Test]: ABC

(Note the spurious ] character after Test).

If I change the formatter string slightly to remove the initial [ character, the additional ] disappears. However, I wish this literal character to appear in the formatted string (and I have the same problem even if it's not at the beginning of the formatting string).

Why does this spurious ] appear, and how can I avoid it?

OS X's asl.conf, which is where logging is configured, looks like this. I have not modified it from the defaults:

##
# configuration file for syslogd and aslmanager
##

# authpriv messages are root/admin readable
? [= Facility authpriv] access 0 80

# remoteauth critical, alert, and emergency messages are root/admin readable
? [= Facility remoteauth] [<= Level critical] access 0 80

# broadcast emergency messages
? [= Level emergency] broadcast

# save kernel [PID 0] and launchd [PID 1] messages
? [<= PID 1] store

# ignore "internal" facility
? [= Facility internal] ignore

# save everything from emergency to notice
? [<= Level notice] store

# Rules for /var/log/system.log
> system.log mode=0640 format=bsd rotate=seq compress file_max=5M all_max=50M
? [= Sender kernel] file system.log
? [<= Level notice] file system.log
? [= Facility auth] [<= Level info] file system.log
? [= Facility authpriv] [<= Level info] file system.log
? [= Facility user] [<= Level debug] file system.log

# Facility com.apple.alf.logging gets saved in appfirewall.log
? [= Facility com.apple.alf.logging] file appfirewall.log file_max=5M all_max=

I do not see the same problem on Ubuntu 10.04, so it appears to be OS X-specific.

Answer 1

UPDATE:

Got it. Fix your formatting string to adhere to BSD syslog formatting:

syslog_formatter = logging.Formatter('[{process}]: {message}', style='{')
...
logger.error("Test : ABC")

and you get:

Aug 23 21:38:02 mymachine [65057]: Test : ABC

BACKGROUND/ORIGINAL POST

I reproduced your error on OS X 10.11.6

Aug 23 21:10:15 machine-name [64643] Test]: ABC

The colon is definitely the culprit. I changed the message to:

logger.error("Test  ABC")

And then the log entry is normal:

Aug 23 21:15:03 machine Unknown: [64701] Test  ABC

I think the colon is being interpreted as a formatting character because you are using the BSD formatting option. From the BSD syslog rfc:

the first character of the CONTENT field that signifies the conclusion of 
the TAG field has been seen to be the left square bracket character ("["), 
a colon character (":"), or a space character.  This is explained in more 
detail in Section 5.3.

So maybe the OS X syslog is trying to adhere to the BSD Syslog RFC and getting confused?