Uploaded image for project: 'SLF4J'
  1. SLF4J
  2. SLF4J-15

bogus jcl-over-slf4j impl - %F, %L etc. off by one

    Details

    • Type: Bug
    • Status: Resolved
    • Resolution: Fixed
    • Affects Version/s: None
    • Fix Version/s: None
    • Component/s: Implementations
    • Labels:
      None
    • Environment:

      Operating System: All
      Platform: All

      Description

      Since jcl-over-slf4j implementation uses wrt. log4j internally
      org.apache.log4j.Logger, this leads to an off by one situation wrt.
      determination of the source line and thus always reports the SLF4JLog as source
      of the event
      because LoggingEvent#FQCN is set to org.apache.log4j.Category and not to
      org.apache.commons.logging.impl.SLF4JLog.

      E.g.:
      private static final Log log = LogFactory.getLog(JCLTest.class);

      executed like:

      org.apache.commons.logging.LogFactory#getLog(clazz)
      -->org.apache.commons.logging.impl.SLF4FLogFactory#getInstance(clazz)
      -->org.slf4j.LoggerFactory.getLogger(clazzName)
      -->org.slf4j.impl.NLOG4JLoggerFactory#getLogger(clazzName)
      -->org.apache.log4j.LogManager#getLogger(clazzName)
      -->org.apache.log4j.Hierarchy#getLogger(clazzName)

      -->org.apache.log4.DefaultCategoryFactory#makeNewLoggerInstance(clazzName)
      <--------------org.apache.log4j.Logger(clazzName)
      <--org.apache.commons.logging.impl.SLF4JLog(logger)

      logger.FCQN == org.apache.log4j.Category

      log.info("test");
      -->org.apache.commons.logging.impl.SLF4JLog.logger#info(String)
      -->org.apache.log4j.Category#info(String)
      -->org.apache.log4j.Category#forcedLog(FQCN, Level.INFO, message, null);
      -->event = new LoggingEvent(FQCN, this, level, message, t);
      -->#callAppenders(event);
      ...-->event.LocationInfo(new Throwable(), FQCN);
      ...-->s="stackTraceOfThrowableAsString(t)"
      #ibegin = s.lastIndexOf(FQCN);
      #ibegin += "charsTilnextLine()"
      #return "lineFrom(ibegin, tilEOL)

      So obviously, this is an error aka off by one situation, since SLF4JLog
      is actually the FQCN which should be used and not Category ...

      A stacktrace used to determine %F:%L, which makes the problem better visible:

      java.lang.Throwable
      at
      org.apache.log4j.spi.LoggingEvent.getLocationInformation(LoggingEvent.java:182)
      at
      org.apache.log4j.helpers.PatternParser$LocationPatternConverter.convert(PatternParser.java:475)
      at org.apache.log4j.helpers.PatternConverter.format(PatternConverter.java:56)
      at org.apache.log4j.PatternLayout.format(PatternLayout.java:495)
      at org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:292)
      at org.apache.log4j.WriterAppender.append(WriterAppender.java:150)
      at org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:221)
      at
      org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:57)
      at org.apache.log4j.Category.callAppenders(Category.java:198)
      at org.apache.log4j.Category.forcedLog(Category.java:510)
      at org.apache.log4j.Category.info(Category.java:738)
      at org.apache.commons.logging.impl.SLF4JLog.info(SLF4JLog.java:120)
      at JCLTest.<init>(JCLTest.java:21)
      at JCLTest.main(JCLTest.java:25)

      Thus the result:

      04:30:46,334 [main] INFO (SLF4JLog.java:120) - test

      But should be:
      04:30:46,334 [main] INFO (JCLTest.java:21) - test

      So, at least if one wanna use e.g. nlog4j as its slf4j impl., logging is almost
      completely unusable wrt. debugging, which makes it hard to troubleshoot AS like
      jboss etc. ...

        Attachments

          Activity

            People

            • Assignee:
              slf4j-dev SLF4J developers list
              Reporter:
              elkner Jens Elkner
            • Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: