8

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.

Andrew Ferrier
  • 16,664
  • 13
  • 47
  • 76
  • Looks like `Test` is being interpreted as a tag. Could you please show your rsyslog configuration? Thanks. – alecxe Dec 15 '15 at 23:53
  • @alexce, good thought, but I don't think so, because the error is the same even if I replace Test with any other word. Removing the `:` does seem to remove the `]` also (which makes me think it is related), but I wanted a `:` as part of the message. – Andrew Ferrier Dec 16 '15 at 10:08
  • @alexce, OS X doesn't use rsyslog, but I've edited in my `asl.conf`, which is where logging is configured. – Andrew Ferrier Dec 16 '15 at 10:15

1 Answers1

4

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?

Liam Kelly
  • 3,524
  • 1
  • 17
  • 41
  • Perfect, thanks! I struggled with that for a while. This works. The only downside is that on Linux I now get an extra colon which doesn't match other syslog messages, but at least that looks neater. And I could be platform-specific Formatting code in if I cared too. Thanks! – Andrew Ferrier Aug 24 '16 at 11:14
  • No problem, I think this problem is really interesting because of all the growing NetOpts tools that parse Syslog messages. You would think that would drive even stricter formatting requirements. – Liam Kelly Aug 24 '16 at 14:09