United StatesChange Country, Oracle Worldwide Web Sites Communities I am a... I want to...
JDK-8025512 : NPE with logging while launching webstart on jre7u40 if logging is disabled

Details
Type:
Bug
Submit Date:
2013-09-26
Status:
Closed
Updated Date:
2014-02-17
Project Name:
JDK
Resolved Date:
2013-12-10
Component:
core-libs
OS:
windows_xp
Sub-Component:
java.util.logging
CPU:
Priority:
P3
Resolution:
Fixed
Affected Versions:
7u40
Fixed Versions:
7u60 (b02)

Related Reports
Backport:
Duplicate:
Relates:
Relates:

Sub Tasks

Description
FULL PRODUCT VERSION :
Java Web Start 10.40.2.43
Using JRE version 1.7.0_40-b43 Java HotSpot(TM) Client VM

ADDITIONAL OS VERSION INFORMATION :
Microsoft Windows XP [Version 5.1.2600]

A DESCRIPTION OF THE PROBLEM :
My application was running fine until i upgraded my jre to 7u40. When my application is initializing its doing Logger.getLogger("ClassName"), i am getting following exception.

java.lang.ExceptionInInitializerError
    at java.util.logging.Logger.demandLogger(Unknown Source)
    at java.util.logging.Logger.getLogger(Unknown Source)
    at com.company.Application.Applet.<clinit>(Unknown Source)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
    at java.lang.reflect.Method.invoke(Unknown Source)
    at com.sun.javaws.Launcher.executeApplication(Unknown Source)
    at com.sun.javaws.Launcher.executeMainClass(Unknown Source)
    at com.sun.javaws.Launcher.doLaunchApp(Unknown Source)
    at com.sun.javaws.Launcher.run(Unknown Source)
    at java.lang.Thread.run(Unknown Source)

Caused by: java.lang.NullPointerException
    at java.util.logging.Logger.setParent(Unknown Source)
    at java.util.logging.LogManager$6.run(Unknown Source)
    at java.security.AccessController.doPrivileged(Native Method)
    at java.util.logging.LogManager.doSetParent(Unknown Source)
    at java.util.logging.LogManager.access$1100(Unknown Source)
    at java.util.logging.LogManager$LogNode.walkAndSetParent(Unknown Source)
    at java.util.logging.LogManager$LoggerContext.addLocalLogger(Unknown Source)
    at java.util.logging.LogManager$LoggerContext.addLocalLogger(Unknown Source)
    at java.util.logging.LogManager.addLogger(Unknown Source)
    at java.util.logging.LogManager$1.run(Unknown Source)
    at java.security.AccessController.doPrivileged(Native Method)
    at java.util.logging.LogManager.<clinit>(Unknown Source)

The exception is coming from this line

private static Logger logger = Logger.getLogger(Applet.class.getName());

Could it be because of any sideeffects with fix http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=8017174 ?

Workaround is to open java control center and enable logging. This is a concern since by default "Enable Logging" is unchecked. If i select "Enable Logging", application starts fine

REGRESSION.  Last worked in version 7u25

STEPS TO FOLLOW TO REPRODUCE THE PROBLEM :
1) Launch java control center and unselect "Enable Logging" from advanced tab
2) Create a sample westart application which initialize logging
private static Logger logger = Logger.getLogger(Applet.class.getName());
3) Application is not launching
4) If you enable "Enable Logging", application launches

EXPECTED VERSUS ACTUAL BEHAVIOR :
EXPECTED -
Should launch always irrespective of the "Enable Logging" checkbox.
ACTUAL -
Application fails with a nullpointer exception.

ERROR MESSAGES/STACK TRACES THAT OCCUR :
java.lang.ExceptionInInitializerError
    at java.util.logging.Logger.demandLogger(Unknown Source)
    at java.util.logging.Logger.getLogger(Unknown Source)
    at com.company.Application.Applet.<clinit>(Unknown Source)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
    at java.lang.reflect.Method.invoke(Unknown Source)
    at com.sun.javaws.Launcher.executeApplication(Unknown Source)
    at com.sun.javaws.Launcher.executeMainClass(Unknown Source)
    at com.sun.javaws.Launcher.doLaunchApp(Unknown Source)
    at com.sun.javaws.Launcher.run(Unknown Source)
    at java.lang.Thread.run(Unknown Source)

Caused by: java.lang.NullPointerException
    at java.util.logging.Logger.setParent(Unknown Source)
    at java.util.logging.LogManager$6.run(Unknown Source)
    at java.security.AccessController.doPrivileged(Native Method)
    at java.util.logging.LogManager.doSetParent(Unknown Source)
    at java.util.logging.LogManager.access$1100(Unknown Source)
    at java.util.logging.LogManager$LogNode.walkAndSetParent(Unknown Source)
    at java.util.logging.LogManager$LoggerContext.addLocalLogger(Unknown Source)
    at java.util.logging.LogManager$LoggerContext.addLocalLogger(Unknown Source)
    at java.util.logging.LogManager.addLogger(Unknown Source)
    at java.util.logging.LogManager$1.run(Unknown Source)
    at java.security.AccessController.doPrivileged(Native Method)
    at java.util.logging.LogManager.<clinit>(Unknown Source)

REPRODUCIBILITY :
This bug can be reproduced always.

---------- BEGIN SOURCE ----------
a simple logging enabled applet
---------- END SOURCE ----------

CUSTOMER SUBMITTED WORKAROUND :
Select "Enable Logging"
                                    

Comments
Verified using provided regtest: failed with 7u60b01, passed with 7u60b02. Closed as verified
                                     
2014-02-17
URL:   http://hg.openjdk.java.net/jdk7u/jdk7u/jdk/rev/3ba8d15adade
User:  lana
Date:  2013-12-16 18:05:21 +0000

                                     
2013-12-16
URL:   http://hg.openjdk.java.net/jdk7u/jdk7u-dev/jdk/rev/3ba8d15adade
User:  dfuchs
Date:  2013-12-10 09:41:37 +0000

                                     
2013-12-10
Public review link: http://cr.openjdk.java.net/~dfuchs/webrev_8025512/webrev.00/
                                     
2013-12-09
SQE is ok to take the fix in 7u60.
                                     
2013-11-15
Reopened since we now have a report containing traces which make it possible to figure out what is wrong and how to fix:

Log started: Mon, 11 Nov 2013 14:01:51 -0800
Java Plug-in 10.45.2.18
Using JRE version
 1.7.0_45-b18 Java HotSpot(TM) 64-Bit Server VM
cache: Initialize resource manager: com.sun.deploy.cache.ResourceProviderImpl@1f427975
Exception in thread "Thread-7" java.lang.ExceptionInInitializerError
	at java.util.logging.Logger.demandLogger(Logger.java:336)
	at java.util.logging.Logger.getLogger(Logger.java:390)
	at com.sun.deploy.trace.LoggerTraceListener.<init>(Unknown Source)
	at com.sun.deploy.trace.LoggerTraceListener.getOrCreateSharedInstance(Unknown Source)
	at sun.plugin.JavaRunTime.initTraceEnvironment(Unknown Source)
	at sun.plugin2.applet.Applet2Environment$2.run(Unknown Source)
	at java.lang.Thread.run(Thread.java:744)
Caused by: java.lang.NullPointerException
	at java.util.logging.Logger.setParent(Logger.java:1560)
	at java.util.logging.LogManager$6.run(LogManager.java:990)
	at java.security.AccessController.doPrivileged(Native Method)
	at java.util.logging.LogManager.doSetParent(LogManager.java:988)
	at java.util.logging.LogManager.access$1100(LogManager.java:148)
	at java.util.logging.LogManager$LogNode.walkAndSetParent(LogManager.java:1401)
	at java.util.logging.LogManager$LoggerContext.addLocalLogger(LogManager.java:654)
	at java.util.logging.LogManager$LoggerContext.addLocalLogger(LogManager.java:584)
	at java.util.logging.LogManager.addLogger(LogManager.java:949)
	at java.util.logging.LogManager$1.run(LogManager.java:201)
	at java.security.AccessController.doPrivileged(Native Method)
	at java.util.logging.LogManager.<clinit>(LogManager.java:173)
	... 7 more

                                     
2013-11-14
SQE can not accept this fix at the moment because it is incomplete. There is no link to delta or review request, no 7u60 justification or risk assessment. 

Please also provide testing recommendations.
                                     
2013-11-14
I cannot reproduce the issue described.

Below is the small test case that I use.
I artificially throw an ExceptionInInitializerError after the logger as been initialized - so that the test will always show an exception. 
1. If the Logger.getLogger() failed in NPE - we should see a NPE wrapped in an ExceptionInInitializerError.
2. If the call to Logger.getLogger() doesn't fail - we should see a print (System.err.println) in the console, as well as an
INFO log trace printed by the logger, and we should get a RuntimeException wrapped in  ExceptionInInitializerError.

As shown by the results below, I always see 2. I could not reproduce the NPE with 7u40 b43

---------- JNLP --------------

<jnlp codebase="file:<userhome>/test/TestAppletLoggerNPE/dist/" href="launch.jnlp" spec="1.0+">
  <information>
    <title>TestAppletLoggerNPE</title>
    <vendor>danielfuchs</vendor>
    <homepage href=""/>
    <description>TestAppletLoggerNPE</description>
    <description kind="short">TestAppletLoggerNPE</description>
  </information>
  <update check="always"/>
  <resources>
    <j2se version="1.7+"/>
    <jar href="TestAppletLoggerNPE.jar" main="true"/>
  </resources>
  <application-desc main-class="testappletloggernpe.TestAppletLoggerNPE"/>
</jnlp>


--------- MAIN -----------

package testappletloggernpe;

import java.util.logging.Logger;

public class TestAppletLoggerNPE extends java.applet.Applet {
    private static Logger logger = Logger.getLogger(java.applet.Applet.class.getName());
    static {
        System.err.println("Logger is: " + logger);
        logger.info("No NPE was raised");

        // If we reach here the NPE was not thrown. Throw RuntimeException
        // instead to get some kind of feedback...
        if (true) 
           throw new ExceptionInInitializerError(new RuntimeException("logger is: " + logger));
    }

    /**
    * Initialization method that will be called after the applet is loaded into
    * the browser.
    */
    public void init() {
        logger.severe("Started");
        System.err.println("OK");

    }

    public static void main(String... args) {
        new TestAppletLoggerNPE().init();
    }
}

--------- RESULT ---------

Logger is: java.util.logging.Logger@36c51c9c
Sep 26, 2013 5:04:46 PM testappletloggernpe.TestAppletLoggerNPE <clinit>
INFO: No NPE was raised
#### Java Web Start Error:
#### java.lang.ExceptionInInitializerError: null

java.lang.ExceptionInInitializerError
	at testappletloggernpe.TestAppletLoggerNPE.<clinit>(TestAppletLoggerNPE.java:18)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at com.sun.javaws.Launcher.executeApplication(Unknown Source)
	at com.sun.javaws.Launcher.executeMainClass(Unknown Source)
	at com.sun.javaws.Launcher.doLaunchApp(Unknown Source)
	at com.sun.javaws.Launcher.run(Unknown Source)
	at java.lang.Thread.run(Thread.java:724)
Caused by: java.lang.RuntimeException: logger is: java.util.logging.Logger@36c51c9c
	... 10 more

The RuntimeException above indicate that the call to Logger.getLogger() didn't throw any NPE or we wouldn't have reached this point.

                                     
2013-09-26
Note: I have tried this with various setting of the Java console - including 'do not start the console' - and never got the NPE.

                                     
2013-09-26
Could the original creator of the bug please provide a complete reproducer - and try out the test case I have added in comments above?
                                     
2013-09-26



Hardware and Software, Engineered to Work Together