[logback-user] erratic smtpAppender behavior

[Palmer, Eric]

I'm trying to get 5 emails sent and am getting 1 random one sent.


        log = LoggerFactory.getLogger("applogger");
        //TODO Get emails sending
        logErr = LoggerFactory.getLogger("Error");
        log.info("test logger");
        logErr.error("test error message1");
        logErr.error("test error message2");
        logErr.error("test error message3");
        logErr.error("test error message4");
        logErr.error("test error message5");
        log.error("from applogger");
        try {
            Thread.sleep(5000);
        } catch(InterruptedException ex) {
            Thread.currentThread().interrupt();
        }
        System.exit(0);

Sends one email out of the 5 error messages and the one sent is not predictable.

Config file
<configuration debug="true">
    <timestamp key="bySecond" datePattern="yyyyMMdd'T'HHmmss"/>

    <appender name="ERROREMAIL" class="ch.qos.logback.classic.net.SMTPAppender">
        <cyclicBufferTracker class="ch.qos.logback.core.spi.CyclicBufferTracker">
            <!-- send just one log entry per email -->
            <bufferSize>1</bufferSize>
        </cyclicBufferTracker>
        <smtpHost>mysmtp.host.edu</smtpHost>
        <to>epalmer at richmond.edu<mailto:epalmer at richmond.edu></to>
        <from>epalmer at richmond.edu<mailto:epalmer at richmond.edu></from>
        <subject>Error in DirPeople2Xml: %logger{20} - %m</subject>
        <layout class="ch.qos.logback.classic.PatternLayout">
            <pattern>%date %-30(%d{HH:mm:ss.SSS} [%M]) %-5level %-33(%C{32}) - %msg%n</pattern>
        </layout>
    </appender>

    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <!-- encoders are assigned the type
     ch.qos.logback.classic.encoder.PatternLayoutEncoder by default -->
        <encoder>
            <pattern>%-30(%d{HH:mm:ss.SSS} [%M]) %-5level %-33(%C{32}) - %msg%n</pattern>
        </encoder>
    </appender>

    <appender name="FILE" class="ch.qos.logback.core.FileAppender">
        <file>/Volumes/HD2/IDEAProjects/DirPeople2Xml/local/logs/log-${bySecond}.log</file>
        <append>true</append>
        <!-- encoders are assigned the type
             ch.qos.logback.classic.encoder.PatternLayoutEncoder by default -->
        <encoder>
            <pattern>%-30(%d{HH:mm:ss.SSS} [%M]) %-5level %-33(%C{32}) - %msg%n</pattern>
        </encoder>
    </appender>

    <logger name="Error" level="error">
        <appender-ref ref="ERROREMAIL" />
    </logger>
    <root level="info">
        <appender-ref ref="FILE" />
        <appender-ref ref="STDOUT" />
    </root>
</configuration>


Stdout messages
07:42:08,457 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.groovy]
07:42:08,457 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback-test.xml] at [file:/Volumes/HD2/IDEAProjects/DirPeople2Xml/target/classes/logback-test.xml]
07:42:08,573 |-INFO in ch.qos.logback.core.joran.action.TimestampAction - Using current interpretation time, i.e. now, as time reference.
07:42:08,575 |-INFO in ch.qos.logback.core.joran.action.TimestampAction - Adding property to the context with key="bySecond" and value="20130621T074208" to the LOCAL scope
07:42:08,575 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.classic.net.SMTPAppender]
07:42:08,592 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [ERROREMAIL]
07:42:08,690 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
07:42:08,693 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [STDOUT]
07:42:08,697 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
07:42:08,703 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.FileAppender]
07:42:08,705 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [FILE]
07:42:08,708 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
07:42:08,708 |-INFO in ch.qos.logback.core.FileAppender[FILE] - File property is set to [/Volumes/HD2/IDEAProjects/DirPeople2Xml/local/logs/log-20130621T074208.log]
07:42:08,711 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [Error] to ERROR
07:42:08,711 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [ERROREMAIL] to Logger[Error]
07:42:08,712 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to INFO
07:42:08,712 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [FILE] to Logger[ROOT]
07:42:08,712 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [STDOUT] to Logger[ROOT]
07:42:08,712 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration.
07:42:08,713 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator at 5e0feb48 - Registering current configuration as safe fallback point
07:42:08.717 [main]            INFO  e.r.i.w.D.PeopleXmlMain           - some log message
07:42:08.721 [startApp]        INFO  e.r.i.w.DirPeople2Xml.AppInfo     - test logger
07:42:08,728 |-INFO in ch.qos.logback.classic.net.SMTPAppender[ERROREMAIL] - SMTPAppender [ERROREMAIL] is tracking [1] buffers
07:42:08.721 [startApp]        ERROR e.r.i.w.DirPeople2Xml.AppInfo     - test error message1
07:42:08.728 [startApp]        ERROR e.r.i.w.DirPeople2Xml.AppInfo     - test error message2
07:42:08.728 [startApp]        ERROR e.r.i.w.DirPeople2Xml.AppInfo     - test error message3
07:42:08.729 [startApp]        ERROR e.r.i.w.DirPeople2Xml.AppInfo     - test error message4
07:42:08.729 [startApp]        ERROR e.r.i.w.DirPeople2Xml.AppInfo     - test error message5
07:42:08.730 [startApp]        ERROR e.r.i.w.DirPeople2Xml.AppInfo     - from applogger
07:42:08,754 |-INFO in ch.qos.logback.classic.net.SMTPAppender[ERROREMAIL] - About to send out SMTP message "Error in DirPeople2Xml: Error - test error message2" to [epalmer at richmond.edu<mailto:epalmer at richmond.edu>]
07:42:08,754 |-INFO in ch.qos.logback.classic.net.SMTPAppender[ERROREMAIL] - About to send out SMTP message "Error in DirPeople2Xml: Error - test error message5" to [epalmer at richmond.edu<mailto:epalmer at richmond.edu>]
07:42:08,755 |-INFO in ch.qos.logback.classic.net.SMTPAppender[ERROREMAIL] - About to send out SMTP message "Error in DirPeople2Xml: Error - test error message4" to [epalmer at richmond.edu<mailto:epalmer at richmond.edu>]
07:42:08,755 |-INFO in ch.qos.logback.classic.net.SMTPAppender[ERROREMAIL] - About to send out SMTP message "Error in DirPeople2Xml: Error - test error message1" to [epalmer at richmond.edu<mailto:epalmer at richmond.edu>]
07:42:08,755 |-INFO in ch.qos.logback.classic.net.SMTPAppender[ERROREMAIL] - About to send out SMTP message "Error in DirPeople2Xml: Error - test error message3" to [epalmer at richmond.edu<mailto:epalmer at richmond.edu>]


Thanks in advance for help

--
Eric Palmer
Web Services
U of Richmond

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mailman.qos.ch/pipermail/logback-user/attachments/20130626/cedefe2c/attachment.html>