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

logback-access: %S macros is broken

    XMLWordPrintable

Details

    • Icon: Bug Bug
    • Resolution: Duplicate
    • Icon: Major Major
    • 1.3.0-alpha7
    • 1.2.2, 1.2.3
    • logback-access
    • None
    • Oracle Java 1.7.0_71

      Apache Tomcat 7.0.77

    Description

      I'm trying to set up logging using Logback similar to my existing JULI logging configuration where I used %S macro in pattern. Logback throws an error when it tries to append message to access log and request is not logged.

      Without %S macro everything seems to working fine.

      logback-access.xml

      <?xml version="1.0" encoding="UTF-8"?>
      
      <configuration>
      
          <appender name="ACCESS-LOG" class="ch.qos.logback.core.rolling.RollingFileAppender">
              <file>${catalina.base}/logs/access.log</file>
              <append>true</append>
              <encoder class="ch.qos.logback.access.PatternLayoutEncoder">
                  <charset>utf-8</charset>
                  <pattern>%t %I %i{X-Forwarded-For} %h "%r" %s %b %D %S "%i{User-Agent}"</pattern>
              </encoder>
              <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
                  <fileNamePattern>${catalina.base}/logs/access.log.%d{yyyyMMdd}.gz</fileNamePattern>
              </rollingPolicy>
          </appender>
      
          <appender-ref ref="ACCESS-LOG" />
      
      </configuration>
      

       

      Error message in catalina.out

      14:53:13,142 |-INFO in ch.qos.logback.access.tomcat.LogbackValve[null] - filename property not set. Assuming [conf/logback-access.xml]
      14:53:13,146 |-INFO in ch.qos.logback.access.tomcat.LogbackValve[null] - Found configuration file [/pub/site/exchg/conf/logback-access.xml] using property "catalina.base"
      14:53:13,181 |-INFO in ch.qos.logback.access.joran.action.ConfigurationAction - debug attribute not set
      14:53:13,181 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.rolling.RollingFileAppender]
      14:53:13,189 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [ACCESS-LOG]
      14:53:13,223 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@14729364 - Will use gz compression
      14:53:13,224 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@14729364 - Will use the pattern /pub/site/exchg/logs/access.log.%d{yyyyMMdd} for the active file
      14:53:13,227 |-INFO in c.q.l.core.rolling.DefaultTimeBasedFileNamingAndTriggeringPolicy - The date pattern is 'yyyyMMdd' from file name pattern '/pub/site/exchg/logs/access.log.%d{yyyyMMdd}.gz'.
      14:53:13,227 |-INFO in c.q.l.core.rolling.DefaultTimeBasedFileNamingAndTriggeringPolicy - Roll-over at midnight.
      14:53:13,228 |-INFO in c.q.l.core.rolling.DefaultTimeBasedFileNamingAndTriggeringPolicy - Setting initial period to Sun May 14 14:53:13 NOVT 2017
      14:53:13,230 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[ACCESS-LOG] - Active log file name: /pub/site/exchg/logs/access.log
      14:53:13,230 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[ACCESS-LOG] - File property is set to [/pub/site/exchg/logs/access.log]
      14:53:13,231 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [ACCESS-LOG] to ch.qos.logback.access.tomcat.LogbackValve[null]
      14:53:13,231 |-INFO in ch.qos.logback.access.joran.action.ConfigurationAction - End of configuration.
      14:53:13,231 |-INFO in ch.qos.logback.access.joran.JoranConfigurator@1836d6a - Registering current configuration as safe fallback point
      14:53:13,231 |-INFO in ch.qos.logback.access.tomcat.LogbackValve[null] - Done configuring
      14:53:14,496 |-ERROR in ch.qos.logback.core.rolling.RollingFileAppender[ACCESS-LOG] - Appender [ACCESS-LOG] failed to append. java.lang.IllegalStateException: Cannot create a session after the response has been committed
              at java.lang.IllegalStateException: Cannot create a session after the response has been committed
              at      at org.apache.catalina.connector.Request.doGetSession(Request.java:3069)
              at      at org.apache.catalina.connector.Request.getSession(Request.java:2424)
              at      at ch.qos.logback.access.spi.AccessEvent.getSessionID(AccessEvent.java:249)
              at      at ch.qos.logback.access.pattern.SessionIDConverter.convert(SessionIDConverter.java:21)
              at      at ch.qos.logback.access.pattern.SessionIDConverter.convert(SessionIDConverter.java:18)
              at      at ch.qos.logback.core.pattern.FormattingConverter.write(FormattingConverter.java:36)
              at      at ch.qos.logback.core.pattern.PatternLayoutBase.writeLoopOnConverters(PatternLayoutBase.java:115)
              at      at ch.qos.logback.access.PatternLayout.doLayout(PatternLayout.java:200)
              at      at ch.qos.logback.access.PatternLayout.doLayout(PatternLayout.java:69)
              at      at ch.qos.logback.core.encoder.LayoutWrappingEncoder.encode(LayoutWrappingEncoder.java:115)
              at      at ch.qos.logback.core.OutputStreamAppender.subAppend(OutputStreamAppender.java:230)
              at      at ch.qos.logback.core.rolling.RollingFileAppender.subAppend(RollingFileAppender.java:235)
              at      at ch.qos.logback.core.OutputStreamAppender.append(OutputStreamAppender.java:102)
              at      at ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(UnsynchronizedAppenderBase.java:84)
              at      at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:51)
              at      at ch.qos.logback.access.tomcat.LogbackValve.invoke(LogbackValve.java:268)
              at      at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:445)
              at      at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1115)
              at      at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:637)
              at      at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:316)
              at      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
              at      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
              at      at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
              at      at java.lang.Thread.run(Thread.java:745)
      14:53:14,498 |-ERROR in ch.qos.logback.core.rolling.RollingFileAppender[ACCESS-LOG] - Appender [ACCESS-LOG] failed to append. java.lang.IllegalStateException: Cannot create a session after the response has been committed
              at java.lang.IllegalStateException: Cannot create a session after the response has been committed
              at      at org.apache.catalina.connector.Request.doGetSession(Request.java:3069)
              at      at org.apache.catalina.connector.Request.getSession(Request.java:2424)
              at      at ch.qos.logback.access.spi.AccessEvent.getSessionID(AccessEvent.java:249)
              at      at ch.qos.logback.access.pattern.SessionIDConverter.convert(SessionIDConverter.java:21)
              at      at ch.qos.logback.access.pattern.SessionIDConverter.convert(SessionIDConverter.java:18)
              at      at ch.qos.logback.core.pattern.FormattingConverter.write(FormattingConverter.java:36)
              at      at ch.qos.logback.core.pattern.PatternLayoutBase.writeLoopOnConverters(PatternLayoutBase.java:115)
              at      at ch.qos.logback.access.PatternLayout.doLayout(PatternLayout.java:200)
              at      at ch.qos.logback.access.PatternLayout.doLayout(PatternLayout.java:69)
              at      at ch.qos.logback.core.encoder.LayoutWrappingEncoder.encode(LayoutWrappingEncoder.java:115)
              at      at ch.qos.logback.core.OutputStreamAppender.subAppend(OutputStreamAppender.java:230)
              at      at ch.qos.logback.core.rolling.RollingFileAppender.subAppend(RollingFileAppender.java:235)
              at      at ch.qos.logback.core.OutputStreamAppender.append(OutputStreamAppender.java:102)
              at      at ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(UnsynchronizedAppenderBase.java:84)
              at      at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:51)
              at      at ch.qos.logback.access.tomcat.LogbackValve.invoke(LogbackValve.java:268)
              at      at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:445)
              at      at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1115)
              at      at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:637)
              at      at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:318)
              at      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
              at      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
              at      at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
              at      at java.lang.Thread.run(Thread.java:745)
      14:53:14,502 |-ERROR in ch.qos.logback.core.rolling.RollingFileAppender[ACCESS-LOG] - Appender [ACCESS-LOG] failed to append. java.lang.IllegalStateException: Cannot create a session after the response has been committed
              at java.lang.IllegalStateException: Cannot create a session after the response has been committed
              at      at org.apache.catalina.connector.Request.doGetSession(Request.java:3069)
              at      at org.apache.catalina.connector.Request.getSession(Request.java:2424)
              at      at ch.qos.logback.access.spi.AccessEvent.getSessionID(AccessEvent.java:249)
              at      at ch.qos.logback.access.pattern.SessionIDConverter.convert(SessionIDConverter.java:21)
              at      at ch.qos.logback.access.pattern.SessionIDConverter.convert(SessionIDConverter.java:18)
              at      at ch.qos.logback.core.pattern.FormattingConverter.write(FormattingConverter.java:36)
              at      at ch.qos.logback.core.pattern.PatternLayoutBase.writeLoopOnConverters(PatternLayoutBase.java:115)
              at      at ch.qos.logback.access.PatternLayout.doLayout(PatternLayout.java:200)
              at      at ch.qos.logback.access.PatternLayout.doLayout(PatternLayout.java:69)
              at      at ch.qos.logback.core.encoder.LayoutWrappingEncoder.encode(LayoutWrappingEncoder.java:115)
              at      at ch.qos.logback.core.OutputStreamAppender.subAppend(OutputStreamAppender.java:230)
              at      at ch.qos.logback.core.rolling.RollingFileAppender.subAppend(RollingFileAppender.java:235)
              at      at ch.qos.logback.core.OutputStreamAppender.append(OutputStreamAppender.java:102)
              at      at ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(UnsynchronizedAppenderBase.java:84)
              at      at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:51)
              at      at ch.qos.logback.access.tomcat.LogbackValve.invoke(LogbackValve.java:268)
              at      at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:445)
              at      at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1115)
              at      at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:637)
              at      at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:318)
              at      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
              at      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
              at      at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
              at      at java.lang.Thread.run(Thread.java:745)
      

      Attachments

        Activity

          People

            ceki Ceki Gülcü
            akhnin Nikita Akhnin
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved: