You are viewing a plain text version of this content. The canonical link for it is here.
Posted to log4j-dev@logging.apache.org by "Stefan Leonhartsberger (JIRA)" <ji...@apache.org> on 2015/06/10 10:00:12 UTC

[jira] [Updated] (LOG4J2-1028) Incorrect Line Number in location information

     [ https://issues.apache.org/jira/browse/LOG4J2-1028?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Stefan Leonhartsberger updated LOG4J2-1028:
-------------------------------------------
    Description: 
When enabling location information in Log4j2
The line numbers of the log records are incorrect 
as they are only taking into account the first time in the stacktrace where the 
class in question (FQCN) was called

This however may not be accurate as the class may call methods within itself  adding to the stacktrace - these are not considered when gathering location information within Log4jLogEvent.

An example stacktrace:
{code}
stackTrace = {java.lang.StackTraceElement[18]@4612} 
 0 = {java.lang.StackTraceElement@4617} "java.lang.Thread.getStackTrace(Thread.java:1552)"
 1 = {java.lang.StackTraceElement@4618} "org.apache.logging.log4j.core.impl.Log4jLogEvent.calcLocation(Log4jLogEvent.java:386)"
 2 = {java.lang.StackTraceElement@4619} "org.apache.logging.log4j.core.async.AsyncLogger.location(AsyncLogger.java:293)"
 3 = {java.lang.StackTraceElement@4620} "org.apache.logging.log4j.core.async.AsyncLogger.logMessage(AsyncLogger.java:252)"
 4 = {java.lang.StackTraceElement@4621} "org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:738)"
 5 = {java.lang.StackTraceElement@4622} "org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:708)"
 6 = {java.lang.StackTraceElement@4623} "com.test.logging.factory.Log4j2Factory$Log4J2CatsLogger.log(Log4j2Factory.java:106)"
 7 = {java.lang.StackTraceElement@4624} "com.test.agent.configuration.Configuration.setPttId(Configuration.java:1079)"
 8 = {java.lang.StackTraceElement@4625} "com.test.agent.configuration.Configuration.loadDefaultConfiguration(Configuration.java:323)"
 9 = {java.lang.StackTraceElement@4614} "com.test.agent.configuration.Configuration.<init>(Configuration.java:302)"
 10 = {java.lang.StackTraceElement@4613} "com.test.agent.configuration.ConfigurationParser.createConfig(ConfigurationParser.java:51)"
 11 = {java.lang.StackTraceElement@4626} "com.test.agent.AgentMain.initConfig(AgentMain.java:231)"
 12 = {java.lang.StackTraceElement@4627} "com.test.agent.AgentMain.init(AgentMain.java:204)"
 13 = {java.lang.StackTraceElement@4628} "com.c4i.test.agent.AgentBase.init(AgentBase.java:456)"
 14 = {java.lang.StackTraceElement@4629} "com.test.agent.AgentBase.createAgent(AgentBase.java:194)"
 15 = {java.lang.StackTraceElement@4630} "com.test.agent.AgentBase.agentmain(AgentBase.java:141)"
 16 = {java.lang.StackTraceElement@4631} "com.test.agent.AgentMain.main(AgentMain.java:109)"
 17 = {java.lang.StackTraceElement@4632} "com.test.agent.AgentMain.main(AgentMain.java:86)"
{code} 

Expected Line Number: 1079
Received Line Number: 302

Reason is that the stack is iterated from the wrong direction - i=17. (starting with i=0 would result in the correct behaviour.


  was:
When enabling location information in Log4j2
The line numbers of the log records are incorrect 
as they are only taking into account the first time in the stacktrace where the 
class in question (FQCN) was called

This however may not be accurate as the class may call methods within itself  adding to the stacktrace - these are not considered when gathering location information within Log4jLogEvent.

An example stacktrace:
{code}
stackTrace = {java.lang.StackTraceElement[18]@4612} 
 0 = {java.lang.StackTraceElement@4617} "java.lang.Thread.getStackTrace(Thread.java:1552)"
 1 = {java.lang.StackTraceElement@4618} "org.apache.logging.log4j.core.impl.Log4jLogEvent.calcLocation(Log4jLogEvent.java:386)"
 2 = {java.lang.StackTraceElement@4619} "org.apache.logging.log4j.core.async.AsyncLogger.location(AsyncLogger.java:293)"
 3 = {java.lang.StackTraceElement@4620} "org.apache.logging.log4j.core.async.AsyncLogger.logMessage(AsyncLogger.java:252)"
 4 = {java.lang.StackTraceElement@4621} "org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:738)"
 5 = {java.lang.StackTraceElement@4622} "org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:708)"
 6 = {java.lang.StackTraceElement@4623} "com.test.logging.factory.Log4j2Factory$Log4J2CatsLogger.log(Log4j2Factory.java:106)"
 7 = {java.lang.StackTraceElement@4624} "com.test.agent.configuration.Configuration.setPttId(Configuration.java:1079)"
 8 = {java.lang.StackTraceElement@4625} "com.test.agent.configuration.Configuration.loadDefaultConfiguration(Configuration.java:323)"
 9 = {java.lang.StackTraceElement@4614} "com.test.agent.configuration.Configuration.<init>(Configuration.java:302)"
 10 = {java.lang.StackTraceElement@4613} "com.test.agent.configuration.ConfigurationParser.createConfig(ConfigurationParser.java:51)"
 11 = {java.lang.StackTraceElement@4626} "com.test.agent.AgentMain.initConfig(AgentMain.java:231)"
 12 = {java.lang.StackTraceElement@4627} "com.test.agent.AgentMain.init(AgentMain.java:204)"
 13 = {java.lang.StackTraceElement@4628} "com.c4i.test.agent.AgentBase.init(AgentBase.java:456)"
 14 = {java.lang.StackTraceElement@4629} "com.test.agent.AgentBase.createAgent(AgentBase.java:194)"
 15 = {java.lang.StackTraceElement@4630} "com.test.agent.AgentBase.agentmain(AgentBase.java:141)"
 16 = {java.lang.StackTraceElement@4631} "com.test.agent.AgentMain.main(AgentMain.java:109)"
 17 = {java.lang.StackTraceElement@4632} "com.test.agent.AgentMain.main(AgentMain.java:86)"
{code} 

Expected Line Number: 1079
Received Line Number: 301

Reason is that the stack is iterated from the wrong direction - i=17. (starting with i=0 would result in the correct behaviour.



> Incorrect Line Number in location information
> ---------------------------------------------
>
>                 Key: LOG4J2-1028
>                 URL: https://issues.apache.org/jira/browse/LOG4J2-1028
>             Project: Log4j 2
>          Issue Type: Bug
>          Components: Core
>    Affects Versions: 2.3
>         Environment: Java 1.8.0_45 64-bit
> Maven 3.3.1
> Windows 7
> basically any...
>            Reporter: Stefan Leonhartsberger
>
> When enabling location information in Log4j2
> The line numbers of the log records are incorrect 
> as they are only taking into account the first time in the stacktrace where the 
> class in question (FQCN) was called
> This however may not be accurate as the class may call methods within itself  adding to the stacktrace - these are not considered when gathering location information within Log4jLogEvent.
> An example stacktrace:
> {code}
> stackTrace = {java.lang.StackTraceElement[18]@4612} 
>  0 = {java.lang.StackTraceElement@4617} "java.lang.Thread.getStackTrace(Thread.java:1552)"
>  1 = {java.lang.StackTraceElement@4618} "org.apache.logging.log4j.core.impl.Log4jLogEvent.calcLocation(Log4jLogEvent.java:386)"
>  2 = {java.lang.StackTraceElement@4619} "org.apache.logging.log4j.core.async.AsyncLogger.location(AsyncLogger.java:293)"
>  3 = {java.lang.StackTraceElement@4620} "org.apache.logging.log4j.core.async.AsyncLogger.logMessage(AsyncLogger.java:252)"
>  4 = {java.lang.StackTraceElement@4621} "org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:738)"
>  5 = {java.lang.StackTraceElement@4622} "org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:708)"
>  6 = {java.lang.StackTraceElement@4623} "com.test.logging.factory.Log4j2Factory$Log4J2CatsLogger.log(Log4j2Factory.java:106)"
>  7 = {java.lang.StackTraceElement@4624} "com.test.agent.configuration.Configuration.setPttId(Configuration.java:1079)"
>  8 = {java.lang.StackTraceElement@4625} "com.test.agent.configuration.Configuration.loadDefaultConfiguration(Configuration.java:323)"
>  9 = {java.lang.StackTraceElement@4614} "com.test.agent.configuration.Configuration.<init>(Configuration.java:302)"
>  10 = {java.lang.StackTraceElement@4613} "com.test.agent.configuration.ConfigurationParser.createConfig(ConfigurationParser.java:51)"
>  11 = {java.lang.StackTraceElement@4626} "com.test.agent.AgentMain.initConfig(AgentMain.java:231)"
>  12 = {java.lang.StackTraceElement@4627} "com.test.agent.AgentMain.init(AgentMain.java:204)"
>  13 = {java.lang.StackTraceElement@4628} "com.c4i.test.agent.AgentBase.init(AgentBase.java:456)"
>  14 = {java.lang.StackTraceElement@4629} "com.test.agent.AgentBase.createAgent(AgentBase.java:194)"
>  15 = {java.lang.StackTraceElement@4630} "com.test.agent.AgentBase.agentmain(AgentBase.java:141)"
>  16 = {java.lang.StackTraceElement@4631} "com.test.agent.AgentMain.main(AgentMain.java:109)"
>  17 = {java.lang.StackTraceElement@4632} "com.test.agent.AgentMain.main(AgentMain.java:86)"
> {code} 
> Expected Line Number: 1079
> Received Line Number: 302
> Reason is that the stack is iterated from the wrong direction - i=17. (starting with i=0 would result in the correct behaviour.



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org