Removing the %d mitigates the issue without solving the problem. The lame syslogd on OS X doesn't give me millisecond precision and, sometimes, that matters to my app. I'm really just trying to figure out who dropped the ball here. Did the SyslogAppender send a message that was already dorked or was the SyslogAppender message fine and the syslog server itself screwed things up.
Thanks for the suggestion, though. On Thu, Jun 6, 2013 at 6:38 PM, Chris Pratt <[email protected]> wrote: > How about just removing the %d parameter (since syslogd already timestamps > each entry) and seeing if the problem moves or goes away. > (*Chris*) > > > On Thu, Jun 6, 2013 at 5:13 PM, Robert Kuhar <[email protected]>wrote: > >> I too am suspicious of the OS X syslogd, but I really don't know how to >> trouble shoot it. Maybe I sniff the wire to see what the UDP packets look >> like? That seems rather primitive. I just wondered if anyone else has >> ever seen this apparent message corruption when using a SyslogAppender. >> >> THanks, >> Bob >> >> >> On Thu, Jun 6, 2013 at 4:03 PM, Chris Pratt <[email protected]>wrote: >> >>> It looks to me like the first timestamp and the bobk-mbp.local are being >>> output by the SysLog daemon, but I have no idea what would be inserting the >>> <Info> in the center of the timestamp from Logback. Could your SysLog >>> daemon be automatically inserting the log level at the first colon in the >>> message? >>> (*Chris*) >>> >>> >>> On Thu, Jun 6, 2013 at 3:24 PM, Robert Kuhar <[email protected]>wrote: >>> >>>> My SyslogAppender succeeds in sending messages to the syslogd on my >>>> MacBook, but the messages themselves are "corrupt" the syslogd logs them. >>>> For example, a RollingFileAppender >>>> >>>> <appender name="DAILY_ROLLING" >>>> class="ch.qos.logback.core.rolling.RollingFileAppender"> >>>> <File>logs/dm.log</File> >>>> <rollingPolicy >>>> class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy"> >>>> <FileNamePattern>logs/dm.%d{yyyyMMdd}.log</FileNamePattern> >>>> </rollingPolicy> >>>> <encoder> >>>> <pattern>%d{yyyy-MM-dd'T'HH:mm:ss.SSS} [%p] %c{2} >>>> DSN:%X{X-HTC-DEVICE-SN} APV:%X{X-HTC-APP-VERSION} RID:%X{X-HTC-REQUEST-ID} >>>> - %m%n</pattern> >>>> </encoder> >>>> </appender> >>>> >>>> logs a message like... >>>> >>>> 2013-06-06T15:02:17.129 [INFO] Global$ DSN: APV: RID: - dm2-server >>>> starting >>>> >>>> But the SysLog appender dorks the message corrupting the %d timestamp >>>> and duplicating the level. My SyslogAppender is configured like... >>>> >>>> <appender name="SYSLOG" >>>> class="ch.qos.logback.classic.net.SyslogAppender"> >>>> <syslogHost>localhost</syslogHost> >>>> <facility>local4</facility> >>>> <suffixPattern>%d{yyyy-MM-dd'T'HH:mm:ss.SSS} %p %c{2} >>>> DSN:%X{X-HTC-DEVICE-SN} APV:%X{X-HTC-APP-VERSION} RID:%X{X-HTC-REQUEST-ID} >>>> - %m</suffixPattern> >>>> </appender> >>>> >>>> With the same log message appearing like... >>>> >>>> Jun 6 15:02:17 bobk-mbp.local 2013-06-06T15 <Info>: 02:17.129 INFO >>>> Global$ DSN: APV: RID: - dm2-server starting >>>> >>>> Where did the <Info> come from and what is it doing in the middle of >>>> logback's %d timestamp? Is this logback messing up or syslogd? Any >>>> recommendations on how to troubleshoot this? >>>> >>>> Bob >>>> >>>> >>>> >>>> _______________________________________________ >>>> Logback-user mailing list >>>> [email protected] >>>> http://mailman.qos.ch/mailman/listinfo/logback-user >>>> >>> >>> >>> _______________________________________________ >>> Logback-user mailing list >>> [email protected] >>> http://mailman.qos.ch/mailman/listinfo/logback-user >>> >> >> >> _______________________________________________ >> Logback-user mailing list >> [email protected] >> http://mailman.qos.ch/mailman/listinfo/logback-user >> > > > _______________________________________________ > Logback-user mailing list > [email protected] > http://mailman.qos.ch/mailman/listinfo/logback-user >
_______________________________________________ Logback-user mailing list [email protected] http://mailman.qos.ch/mailman/listinfo/logback-user
