Logback SMTPAppender mixes up mails

293 views Asked by At

I do issue 10 error messages using this code:

final Logger log = LoggerFactory.getLogger("myLogger");
for(int i = 0; i<10; i++)
   log.error("myMessage" + i);

I configured logback.xml (see bottom) to write to console and to send emails. Console says:

17:56:21.172 [http-bio-8443-exec-1] ERROR myLogger - myMessage0
17:56:21.174 [http-bio-8443-exec-1] ERROR myLogger - myMessage1
17:56:21.174 [http-bio-8443-exec-1] ERROR myLogger - myMessage2
17:56:21.174 [http-bio-8443-exec-1] ERROR myLogger - myMessage3
17:56:21.174 [http-bio-8443-exec-1] ERROR myLogger - myMessage4
17:56:21.174 [http-bio-8443-exec-1] ERROR myLogger - myMessage5
17:56:21.174 [http-bio-8443-exec-1] ERROR myLogger - myMessage6
17:56:21.174 [http-bio-8443-exec-1] ERROR myLogger - myMessage7
17:56:21.175 [http-bio-8443-exec-1] ERROR myLogger - myMessage8
17:56:21.175 [http-bio-8443-exec-1] ERROR myLogger - myMessage9

which is perfect. Also ch.qos.logback.classic.ViewStatusMessagesServlet shows my emails with 10 rows saying

INFO | SMTPAppender | About to send out SMTP message "ERROR myLogger myMessageNNN" to [[email protected]]

with N in 0 to 9, but the order of emails is shuffled to 7-0-9-2-8-1-4-3-5-6, which is still ok.

But unfortunatly, in my email account I find 10 equal emails, all with subject "ERROR myLogger myMessage8" and body

ERROR myLogger

myMessage6

So instead of sending 10 emails, one of them is sent 10 times. Even worse, subject and body of that email do not correspond to each other.

All 10 emails do have exactly the same Message-ID.

I tried this with logback 1.1.2, 1.1.1, and 1.1.0 (fetched from mvnrepository) and it always shows the same behaviour.

I tried it with two different smtp servers of my employer, and I did access both via Thunderbird and SquirrelMail, but this makes no difference.

If I do a "Thread.sleep(1000)" before each log.error, everything works as expected and the emails are perfectly fine.

<configuration scan="true" scanPeriod="1 minute">
  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <encoder>
      <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
    </encoder>
  </appender>
  <appender name="EMAIL" class="ch.qos.logback.classic.net.SMTPAppender">
    <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
      <level>ERROR</level>
    </filter>
    <smtpHost>xxx.yyy.com</smtpHost>
    <to>[email protected]</to>
    <from>[email protected]</from>
    <subject>%-5level %logger{26} %m{50}</subject>
    <layout class="ch.qos.logback.classic.PatternLayout">
      <pattern>%level %logger%n%n%m%n%n%ex</pattern>
    </layout>
  </appender>
  <root level="INFO">
    <appender-ref ref="STDOUT"/>
    <appender-ref ref="EMAIL"/>
  </root>
</configuration>

I created an jira issue for that: http://jira.qos.ch/browse/LOGBACK-1032 but the jira looks a bit orphaned.

0

There are 0 answers