登录不打印方法或行号 [英] logback doesn't print method or line number

问题描述

这在Gradle项目中，使用Groovy作为应用程序代码和测试代码.但是我正在使用logback.xml文件进行配置.

这里可能很重要的一个因素是我正在使用Groovy @ Slf4j 注释以提供记录器.

%method和%line转换词通常分别打印为"invoke"和"-1"(尽管有时"invoke0"和"-2").

有趣的是，有时它确实会打印方法和编号:例如，当它是带有Exception参数的ERROR级别日志时:

log.error( 'indexSearcher.indexReader.close() threw Exception', e )

...我想这与e对象有关，该对象随身携带了位置"数据，然后logback可以利用该数据.但是只是偶尔会在INFO级消息中打印出方法和行号:这很令人困惑.

我已经看到人们在使用异步追加程序时遇到问题，但是我的追加程序是ROLLING_FILE(此处):我已将以下几行添加到我的附加程序中:

<includeCallerData>true</includeCallerData>
<param name="locationInfo" value="true" />

...没有解决问题.

某人说必须确保在某些时候打开调试数据.在Groovy上下文中，我不确定如何尝试该想法.

解决方案

logback.groovy

appender("STDOUT", ConsoleAppender) {
  encoder(PatternLayoutEncoder) {
    pattern = "%d{HH:mm:ss.SSS} [%thread] %-5level {%logger} - %class.%method:%line - %msg%n"
  }
}
root(DEBUG, ["STDOUT"])

X.groovy

@GrabConfig(systemClassLoader=true)
@GrabResolver(name='maven2',root='http://repo1.maven.org/maven2/')
@Grab(group='ch.qos.logback', module='logback-classic', version='1.2.3')
@Grab(group='org.slf4j', module='slf4j-api', version='1.7.30')

import groovy.util.logging.Slf4j

@Slf4j
class A {
    def f() {
        log.info 'msg-info-2'       //line 11
        log.with{
            info  'msg-info-1'      //line 13
            //new Exception("test").printStackTrace(System.out)
        }
    }
}

def a = new A()
a.f()

命令groovy X.groovy打印:

12:24:43.134 [main] INFO  {A} - A.f:11 - msg-info-1
12:24:43.139 [main] INFO  {A} - sun.reflect.NativeMethodAccessorImpl.invoke0:-2 - msg-info-2

---

为什么

在logback中有一个类

行

您将看到如下所示的堆栈跟踪:

java.lang.Exception: test
    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
    ... + 11 elements
    at A$_f_closure1.doCall(X.groovy:14)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    ... + 15 elements
    at A.f(X.groovy:12)
    ... + 20 elements

CallerData试图从堆栈跟踪中跳过技术常规元素，但未能检测到正确的元素.

---

解决方案

可以修改 用于登录上下文.

我不知道如何从logback.xml开始执行此操作，但是我发现了如何使用logback.groovy

执行此操作

logback.groovy (已修改)

也许对于您的情况，您必须添加另一个框架(忽略的)程序包...

context.getFrameworkPackages().addAll([
    "sun.reflect", 
    "java.lang.reflect", 
    "org.codehaus.groovy", 
    "groovy.lang.MetaMethod",
    "jdk.internal.reflect"
    ])

appender("STDOUT", ConsoleAppender) {
  encoder(PatternLayoutEncoder) {
    pattern = "%d{HH:mm:ss.SSS} [%thread] %-5level {%logger} - %class.%method:%line - %msg%n"
  }
}
root(DEBUG, ["STDOUT"])

使用此配置，上面的代码可以正确打印行:

13:12:14.410 [main] INFO  {A} - A.f:11 - msg-info-2
13:12:14.416 [main] INFO  {A} - A$_f_closure1.doCall:13 - msg-info-1

This is in a Gradle project using Groovy for the app code as well as test code. But I'm using a logback.xml file for configuration.

One factor here that may be significant is that I am using the Groovy @Slf4j annotation to provide a logger.

The %method and %line conversion words usually get printed out as "invoke" and "-1" respectively (although sometimes "invoke0" with "-2").

Interestingly, it does sometimes print the method and number: for example when it's an ERROR level log with an Exception parameter:

log.error( 'indexSearcher.indexReader.close() threw Exception', e )

... I presume that's something to do with the e object carrying with it "location" data which logback can then exploit. But just occasionally an INFO level message gets printed with the method and line number: it's quite puzzling.

I've seen people having problems with an async appender, but my appender is ROLLING_FILE (RollingFileAppender). This is not an extension of an async appender.

I've tried other remedies documented in other SO questions (e.g. here): I've added these lines to my appender:

<includeCallerData>true</includeCallerData>
<param name="locationInfo" value="true" />

... did not solve the problem.

Someone somewhere said that it was necessary to ensure debug data was switched on at some point. In a Groovy context I'm not sure how I might try that idea.

解决方案

logback.groovy

appender("STDOUT", ConsoleAppender) {
  encoder(PatternLayoutEncoder) {
    pattern = "%d{HH:mm:ss.SSS} [%thread] %-5level {%logger} - %class.%method:%line - %msg%n"
  }
}
root(DEBUG, ["STDOUT"])

X.groovy

@GrabConfig(systemClassLoader=true)
@GrabResolver(name='maven2',root='http://repo1.maven.org/maven2/')
@Grab(group='ch.qos.logback', module='logback-classic', version='1.2.3')
@Grab(group='org.slf4j', module='slf4j-api', version='1.7.30')

import groovy.util.logging.Slf4j

@Slf4j
class A {
    def f() {
        log.info 'msg-info-2'       //line 11
        log.with{
            info  'msg-info-1'      //line 13
            //new Exception("test").printStackTrace(System.out)
        }
    }
}

def a = new A()
a.f()

The command groovy X.groovy prints:

12:24:43.134 [main] INFO  {A} - A.f:11 - msg-info-1
12:24:43.139 [main] INFO  {A} - sun.reflect.NativeMethodAccessorImpl.invoke0:-2 - msg-info-2

---

why

in logback there is a class CallerData with method extract that extracts caller data information as an array based on a Throwable parameter and returns an array of StackTraceElement. It tries to cleenup the stacktrace, however for groovy it could be really complex.

For example if you uncomment the line new Exception("test").printStackTrace(System.out)

You'll see stacktrace like this:

java.lang.Exception: test
    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
    ... + 11 elements
    at A$_f_closure1.doCall(X.groovy:14)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    ... + 15 elements
    at A.f(X.groovy:12)
    ... + 20 elements

CallerData tries to skip the technical groovy elements from stacktrace but fails to detect the right one.

---

solution

It's possible to modify the Framework Packages for the logback context.

I don't know how to do that from logback.xml, but I found how to do it using logback.groovy

logback.groovy (modified)

maybe for your case you have to add another framework (ignored) packages...

context.getFrameworkPackages().addAll([
    "sun.reflect", 
    "java.lang.reflect", 
    "org.codehaus.groovy", 
    "groovy.lang.MetaMethod",
    "jdk.internal.reflect"
    ])

appender("STDOUT", ConsoleAppender) {
  encoder(PatternLayoutEncoder) {
    pattern = "%d{HH:mm:ss.SSS} [%thread] %-5level {%logger} - %class.%method:%line - %msg%n"
  }
}
root(DEBUG, ["STDOUT"])

with this configuration the code above prints lines correctly:

13:12:14.410 [main] INFO  {A} - A.f:11 - msg-info-2
13:12:14.416 [main] INFO  {A} - A$_f_closure1.doCall:13 - msg-info-1

这篇关于登录不打印方法或行号的文章就介绍到这了，希望我们推荐的答案对大家有所帮助，也希望大家多多支持IT屋！