I was trawling through some logs today and came across a strange error.
Here's how it appears in the log:
2014/09/11 15:23:52.801 [CC3A5FDD16035540B87F1B8C5E806588:<removed>] WARN a.b.c.Ddd - Main failure
java.lang.NullPointerException: null
2014/09/11 15:23:52.801 [CC3A5FDD16035540B87F1B8C5E806588:<removed>] ...
and here's what the code looks like:
} catch (Exception e) {
Ddd.log.warn("Main failure ", e);
throw e;
}
The code is in a jsp if that is important. The same exception is repeated once more in the log (as you'd expect from the throw e
).
I have no record of what the cause was - the previous line in the log shows execution of a query. This occurred just twice over a 4-day period and seems not to have caused any harm to the system.
Environment: Fairly busy web service running under Tomcat with Java 5.
I am not asking for tips on debugging the system - these errors are long-gone and may even never happen again. I was just stumped as to how any exception (especially an NPE) could be created without a stack trace?
Added
The logger being used is an slf4j
driven Logback
instance. I believe the warn
method is here. Not sure what Logback
method that resolves to but I am confident the Throwable
parameter is treated specially and if there was an stack trace attached to the Throwable
it would appear in the log.
LogBack.xml - as requested:
<?xml version="1.0" encoding="UTF-8"?>
<configuration>
<property name="log.package" value="Package" />
<property name="log.pattern" value="%date{yyyy/MM/dd HH:mm:ss.SSS} [%X{session}:%X{device}] %level %logger{25} - %msg%n"/>
<property name="log.consolePattern" value="%highlight(%-5level) %white(%logger{25}) - %msg%n"/>
<if condition='isDefined("catalina.home")'>
<then>
<property name="log.dir" value="${catalina.home}/logs" />
</then>
<else>
<property name="log.dir" value="." />
</else>
</if>
<appender name="console" class="ch.qos.logback.core.ConsoleAppender">
<filter class="ch.qos.logback.classic.filter.ThresholdFilter">
<level>DEBUG</level>
</filter>
<encoder>
<Pattern>${log.consolePattern}</Pattern>
</encoder>
</appender>
<appender name="rolling" class="ch.qos.logback.core.rolling.RollingFileAppender">
<file>${log.dir}/${log.package}.log</file>
<encoder>
<Pattern>${log.pattern}</Pattern>
</encoder>
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<fileNamePattern>${log.dir}/${log.package}.%d{yyyy-MM-dd}.%i.log.zip</fileNamePattern>
<timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
<!-- or whenever the file size reaches 16MB. -->
<maxFileSize>16MB</maxFileSize>
</timeBasedFileNamingAndTriggeringPolicy>
<!-- Keep no more than 3 months data. -->
<maxHistory>90</maxHistory>
<cleanHistoryOnStart>true</cleanHistoryOnStart>
</rollingPolicy>
</appender>
<!-- Default logging levels. -->
<root level="INFO">
<appender-ref ref="console"/>
<appender-ref ref="rolling"/>
</root>
<!-- Specific logging levels. -->
<!-- Generally set to INFO or ERROR but if you need more details, set to DEBUG. -->
<logger name="org.apache" level="INFO"/>
<logger name="net.sf.ehcache" level="ERROR"/>
<logger name="com.zaxxer" level="ERROR"/>
<logger name="ch.qos" level="ERROR"/>
</configuration>
I hand-edited out the values after the session ID in the log to remove customer data.
Sometimes, especially when it comes to NullPointers (in my experience), the jvm can optimize the creation and casting of exceptions, and the stack trace is lost (or more correctly, never created). I suspect that your issue is not related to certain java libs, but rather the jvm itself.
If you add this argument when starting your jvm-process you will get your stack traces back, if my suspicion is correct.
-XX:-OmitStackTraceInFastThrow
This has been asked before, look here for more details:
Note, that this applies sun/oracle jvm
Collected from the Internet
Please contact [email protected] to delete if infringement.
Comments