<div dir="ltr"><div style>The root cause of my issue appears to be the syslogd implementations. Somehow the first colon of the message is significant. Our syslog guru guy describes it as "program" and says its just a string followed by a colon and a space. Adding a static text program field terminated with a colon ("dm-service: ") to the front of the suffixPattern appears to fix the problem. You've got to give the syslog what it wants.</div>
<div style><br></div><div style><span style="font-family:arial,sans-serif;font-size:13px">My SyslogAppender is configured like...</span><br></div><div><br></div><div><div> <appender name="SYSLOG" class="ch.qos.logback.classic.net.SyslogAppender"></div>
<div> <syslogHost>localhost</syslogHost></div><div> <facility>local4</facility></div><div> <suffixPattern>dm-service: %d{yyyy-MM-dd'T'HH:mm:ss.SSS'Z'} [%p] %c{2} DSN:%X{X-HTC-DEVICE-SN} APV:%X{X-HTC-APP-VERSION} RID:%X{X-HTC-REQUEST-ID} - %m</suffixPattern></div>
<div> </appender></div><div><br></div><div style>produces the syslog message...</div><div><br></div></div><div>Jun 13 14:35:50 bobk-mbp.local dm-service <Info>: 2013-06-13T14:35:50.064Z [INFO] Global$ DSN: APV: RID: - dm2-server starting<br>
</div><div><br></div><div class="gmail_extra">The "level" remains duplicated but I've observed that they don't appear to map each other 1:1 (I'm sure this is documented somewhere but am not motivated enough to go in search of it). Syslog <Info> is indeed slf4j INFO, but Syslog <Debug> somehow ends up with both my DEBUG and TRACE slf4j messages. I've come to the conclusion that this isn't duplication as much as mapping and because the mapping isn't 1:1 I need to keep it around.</div>
<div class="gmail_extra"><br></div><div class="gmail_extra" style>In any event. Thanks to all for their insights.</div><div class="gmail_extra" style><br></div><div class="gmail_extra" style>Bob</div><div class="gmail_extra">
<br><div class="gmail_quote">On Thu, Jun 6, 2013 at 11:51 PM, Robert Kuhar <span dir="ltr"><<a href="mailto:robertkuhar@gmail.com" target="_blank">robertkuhar@gmail.com</a>></span> wrote:<br><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left-width:1px;border-left-color:rgb(204,204,204);border-left-style:solid;padding-left:1ex">
<div dir="ltr">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.<div>
<br></div><div>Thanks for the suggestion, though.</div></div><div class=""><div class="h5"><div class="gmail_extra"><br><br><div class="gmail_quote">On Thu, Jun 6, 2013 at 6:38 PM, Chris Pratt <span dir="ltr"><<a href="mailto:thechrispratt@gmail.com" target="_blank">thechrispratt@gmail.com</a>></span> wrote:<br>
<blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left-width:1px;border-left-color:rgb(204,204,204);border-left-style:solid;padding-left:1ex"><div dir="ltr">How about just removing the %d parameter (since syslogd already timestamps each entry) and seeing if the problem moves or goes away.<span><font color="#888888"><div>
(*Chris*)</div></font></span></div><div><div><div class="gmail_extra"><br><br><div class="gmail_quote">
On Thu, Jun 6, 2013 at 5:13 PM, Robert Kuhar <span dir="ltr"><<a href="mailto:robertkuhar@gmail.com" target="_blank">robertkuhar@gmail.com</a>></span> wrote:<br><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left-width:1px;border-left-color:rgb(204,204,204);border-left-style:solid;padding-left:1ex">
<div dir="ltr">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.<div>
<br></div><div>THanks,</div><div>Bob</div></div><div><div><div class="gmail_extra"><br><br><div class="gmail_quote">On Thu, Jun 6, 2013 at 4:03 PM, Chris Pratt <span dir="ltr"><<a href="mailto:thechrispratt@gmail.com" target="_blank">thechrispratt@gmail.com</a>></span> wrote:<br>
<blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left-width:1px;border-left-color:rgb(204,204,204);border-left-style:solid;padding-left:1ex"><div dir="ltr">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?<div>
(*Chris*)</div></div><div class="gmail_extra"><br><br><div class="gmail_quote"><div><div>On Thu, Jun 6, 2013 at 3:24 PM, Robert Kuhar <span dir="ltr"><<a href="mailto:robertkuhar@gmail.com" target="_blank">robertkuhar@gmail.com</a>></span> wrote:<br>
</div></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left-width:1px;border-left-color:rgb(204,204,204);border-left-style:solid;padding-left:1ex"><div><div><div dir="ltr">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 <div>
<br></div><div>
<div> <appender name="DAILY_ROLLING" class="ch.qos.logback.core.rolling.RollingFileAppender"></div><div> <File>logs/dm.log</File></div><div> <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy"></div>
<div> <FileNamePattern>logs/dm.%d{yyyyMMdd}.log</FileNamePattern></div><div> </rollingPolicy></div><div> <encoder></div><div> <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></div>
<div> </encoder></div><div> </appender></div></div><div><br></div><div>logs a message like...<br></div><div><br></div><div>2013-06-06T15:02:17.129 [INFO] Global$ DSN: APV: RID: - dm2-server starting<br>
</div><div><br></div><div>But the SysLog appender dorks the message corrupting the %d timestamp and duplicating the level. My SyslogAppender is configured like...</div><div><br></div><div><div> <appender name="SYSLOG" class="ch.qos.logback.classic.net.SyslogAppender"></div>
<div> <syslogHost>localhost</syslogHost></div><div> <facility>local4</facility></div><div> <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></div>
<div> </appender></div><div><br></div><div>With the same log message appearing like...</div><div><br></div><div>Jun 6 15:02:17 bobk-mbp.local 2013-06-06T15 <Info>: 02:17.129 INFO Global$ DSN: APV: RID: - dm2-server starting<br>
</div><div><br></div><div>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?</div>
<div><br></div><div>Bob</div></div><div><div><br></div><div><br></div></div></div>
<br></div></div>_______________________________________________<br>
Logback-user mailing list<br>
<a href="mailto:Logback-user@qos.ch" target="_blank">Logback-user@qos.ch</a><br>
<a href="http://mailman.qos.ch/mailman/listinfo/logback-user" target="_blank">http://mailman.qos.ch/mailman/listinfo/logback-user</a><br></blockquote></div><br></div>
<br>_______________________________________________<br>
Logback-user mailing list<br>
<a href="mailto:Logback-user@qos.ch" target="_blank">Logback-user@qos.ch</a><br>
<a href="http://mailman.qos.ch/mailman/listinfo/logback-user" target="_blank">http://mailman.qos.ch/mailman/listinfo/logback-user</a><br></blockquote></div><br></div>
</div></div><br>_______________________________________________<br>
Logback-user mailing list<br>
<a href="mailto:Logback-user@qos.ch" target="_blank">Logback-user@qos.ch</a><br>
<a href="http://mailman.qos.ch/mailman/listinfo/logback-user" target="_blank">http://mailman.qos.ch/mailman/listinfo/logback-user</a><br></blockquote></div><br></div>
</div></div><br>_______________________________________________<br>
Logback-user mailing list<br>
<a href="mailto:Logback-user@qos.ch" target="_blank">Logback-user@qos.ch</a><br>
<a href="http://mailman.qos.ch/mailman/listinfo/logback-user" target="_blank">http://mailman.qos.ch/mailman/listinfo/logback-user</a><br></blockquote></div><br></div>
</div></div></blockquote></div><br></div></div>