Uploaded image for project: 'logback'
  1. logback
  2. LOGBACK-909

SMTPAppender synchronization problem in Asynchronous mode

    Details

    • Type: Bug
    • Status: Resolved
    • Priority: Major
    • Resolution: Fixed
    • Affects Version/s: 1.0.13
    • Fix Version/s: 1.1.3
    • Component/s: logback-classic
    • Labels:
      None

      Description

      Method SMTPAppender.sendBuffer using mimeMsg, but not synchronized

      App.java
      package com.mycompany.mavenproject4;
      
      import ch.qos.logback.classic.Logger;
      import ch.qos.logback.classic.LoggerContext;
      import ch.qos.logback.classic.PatternLayout;
      import ch.qos.logback.classic.net.SMTPAppender;
      import ch.qos.logback.classic.spi.ILoggingEvent;
      import ch.qos.logback.core.Layout;
      import ch.qos.logback.core.status.OnConsoleStatusListener;
      import com.icegreen.greenmail.util.GreenMail;
      import com.icegreen.greenmail.util.GreenMailUtil;
      import com.icegreen.greenmail.util.ServerSetup;
      import javax.mail.Multipart;
      import javax.mail.internet.MimeMessage;
      
      public class App {
      
      	private static final String DEFAULT_PATTERN = "%-4relative %mdc [%thread] %-5level %class - %msg%n";
      	private LoggerContext loggerContext = new LoggerContext();
      	private Logger logger = loggerContext.getLogger(this.getClass());
      	private GreenMail greenMail;
      
      	public static void main(String... args) throws Exception {
      
      		App app = new App();
      		app.test();
      	}
      
      	public void test() throws Exception {
      
      		OnConsoleStatusListener.addNewInstanceToContext(loggerContext);
      
      		startGreenMail();
      		try {
      			SMTPAppender smtpAppender = buildSMTPAppender();
      			smtpAppender.start();
      
      			logger.addAppender(smtpAppender);
      			logger.error("Message1");
      			logger.error("Message2");
      
      			greenMail.waitForIncomingEmail(5000, 2);
      			for (MimeMessage mimeMessage : greenMail.getReceivedMessages()) {
      
      				String subject = mimeMessage.getSubject();
      
      				Multipart multipart = (Multipart) mimeMessage.getContent();
      				String body = GreenMailUtil.getBody(multipart.getBodyPart(0));
      
      				System.out.println("subject=" + subject);
      				System.out.println("body=" + body);
      				System.out.println();
      			}
      
      		} finally {
      			stopGreenMail();
      		}
      	}
      
      	private void startGreenMail() throws InterruptedException {
      		greenMail = new GreenMail(new ServerSetup(25, "localhost", ServerSetup.PROTOCOL_SMTP));
      		greenMail.start();
      		Thread.currentThread().sleep(50);
      	}
      
      	private void stopGreenMail() {
      		greenMail.stop();
      	}
      
      	private SMTPAppender buildSMTPAppender() {
      		SMTPAppender smtpAppender = new SMTPAppender();
      		smtpAppender.setContext(loggerContext);
      		smtpAppender.setSubject("%msg");
      		smtpAppender.addTo("nospam@qos.ch");
      		smtpAppender.setAsynchronousSending(true);
      		smtpAppender.setLayout(buildPatternLayout());
      		return smtpAppender;
      	}
      
      	private Layout<ILoggingEvent> buildPatternLayout() {
      		PatternLayout layout = new PatternLayout();
      		layout.setContext(loggerContext);
      		layout.setPattern(DEFAULT_PATTERN);
      		layout.start();
      		return layout;
      	}
      }
      
      output1

      22:03:00,396 |-INFO in ch.qos.logback.classic.net.SMTPAppender[null] - SMTPAppender [null] is tracking [1] buffers
      22:03:00,412 |-INFO in ch.qos.logback.classic.net.SMTPAppender[null] - About to send out SMTP message "Message2" to [nospam@qos.ch]
      22:03:00,413 |-INFO in ch.qos.logback.classic.net.SMTPAppender[null] - About to send out SMTP message "Message1" to [nospam@qos.ch]
      subject=Message1
      body=225 [main] ERROR ? - Message1

      subject=Message1
      body=225 [main] ERROR ? - Message1

      output2

      22:03:29,514 |-INFO in ch.qos.logback.classic.net.SMTPAppender[null] - SMTPAppender [null] is tracking [1] buffers
      22:03:29,528 |-INFO in ch.qos.logback.classic.net.SMTPAppender[null] - About to send out SMTP message "Message1" to [nospam@qos.ch]
      22:03:29,528 |-INFO in ch.qos.logback.classic.net.SMTPAppender[null] - About to send out SMTP message "Message2" to [nospam@qos.ch]
      subject=Message2
      body=223 [main] ERROR ? - Message2

      subject=Message2
      body=223 [main] ERROR ? - Message2

        Attachments

          Issue Links

            Activity

              People

              • Assignee:
                tony19 Tony Trinh
                Reporter:
                alexlumpov Alex Lumpov
              • Votes:
                4 Vote for this issue
                Watchers:
                5 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: