JDK-4987037 : Unable to create Logger during JVM shutdown
  • Type: Bug
  • Component: core-libs
  • Sub-Component: java.util
  • Affected Version: 1.4.2
  • Priority: P4
  • Status: Closed
  • Resolution: Fixed
  • OS: linux
  • CPU: x86
  • Submitted: 2004-02-02
  • Updated: 2004-07-22
  • Resolved: 2004-06-10
The Version table provides details related to the release that this issue/RFE will be addressed.

Unresolved : Release in which this issue/RFE will be addressed.
Resolved: Release in which this issue/RFE has been resolved.
Fixed : Release in which this issue/RFE has been fixed. The release containing this fix may be available for download as an Early Access Release or a General Availability Release.

To download the current JDK release, click here.
Other
1.4.2_06 06Fixed
Description
Name: dk106046			Date: 02/02/2004

Synopsis:
The Logger object used in FileSystemPreferences.java is not created until a message must be passed to it. In this testcase, this occurs when the JVM is shutting down. Part of the creating of a Logger is to register a shutdown hook, which cant be done as we are already shutting down. 

OS:
Linux - all architectures, all flavours

Full JDK Version:
java version "1.4.2_03"
Java(TM) 2 Runtime Environment, Standard Edition (build 1.4.2_03-b02)
Java HotSpot(TM) Client VM (build 1.4.2_03-b02, mixed mode)

Problem:
The latest version of FileSystemPreferences.java has replaced the declaration:

     private static final Logger logger = Logger.getLogger("java.util.prefs");

with the function:

    private static Logger getLogger() {
        return Logger.getLogger("java.util.prefs");
    }

and all calls to the logger now use the static function getLogger().info (for example) rather than the local variable logger.info.

This means that the Logger object is not created until it is first used to print warnings. In the case detailed below, where the dir /etc/.java/.systemPref exists but is not writable, the Logger is not used until the JVM is shutting down. The Logger is therefore created at this point, which in turn creates a LogManager, which in turn attempts to create a Shutdown hook, which cant be done, as we are already shutting down, hence the "Shutdown in Progress" error.

This problem occurs in JDK 1.4.2_03 but not occur in 1.4.1_07.

Reproduction of Error:
Create the file /etc/.java/.systemPrefs as root.
Ensure that both the .java and the .systemPrefs directories are owned by root, and have permission 755, preventing normal users writing to them.

Run the following Java testcase, as a non-root standard user:

___________________
import java.lang.*;
import java.util.prefs.*;
import java.io.*;

public class vPref {

    public static void main(String argv[]) {
        vPref test = new vPref();
        test.SimplePreferencetest006();
        System.exit(0);
    }

    public void SimplePreferencetest006() {
        Preferences prefs = Preferences.systemNodeForPackage(getClass());
        Preferences prefs1 = prefs.node("/com/acme/widget");
        boolean passed = true;
        try {
            prefs1.removeNode();
        } catch (Exception e) {
        }
        return;
    }
}
__________________________

Error Message:
java.lang.ExceptionInInitializerError
        at java.util.logging.Logger.getLogger(Logger.java:227)
        at java.util.logging.Logger.<clinit>(Logger.java:181)
        at java.util.prefs.FileSystemPreferences.getLogger(FileSystemPreferences.java:52)
        at java.util.prefs.FileSystemPreferences.checkLockFile0ErrorCode(FileSystemPreferences.java:923)
        at java.util.prefs.FileSystemPreferences.lockFile(FileSystemPreferences.java:908)
        at java.util.prefs.FileSystemPreferences.sync(FileSystemPreferences.java:714)
        at java.util.prefs.FileSystemPreferences.flush(FileSystemPreferences.java:807)
        at java.util.prefs.FileSystemPreferences.syncWorld(FileSystemPreferences.java:458)
        at java.util.prefs.FileSystemPreferences.access$1200(FileSystemPreferences.java:33)
        at java.util.prefs.FileSystemPreferences$6.run(FileSystemPreferences.java:429)
Caused by: java.lang.IllegalStateException: Shutdown in progress
        at java.lang.Shutdown.add(Shutdown.java:110)
        at java.lang.Runtime.addShutdownHook(Runtime.java:222)
        at java.util.logging.LogManager.<init>(LogManager.java:197)
        at java.util.logging.LogManager$1.run(LogManager.java:155)
        at java.security.AccessController.doPrivileged1(Native Method)
        at java.security.AccessController.doPrivileged(AccessController.java:286)
        at java.util.logging.LogManager.<clinit>(LogManager.java:141)
        ... 10 more

Fix:
Replacing the function getLogger() in FileSystemPreferences.java with a static final Logger object, and replacing the calls to getLogger with the local object logger, as was done in 1.4.1 will stop this problem occuring, by ensuring that the Logger object is created when the FileSystemPreferences class is used, regardless of whether the Logger itself is used.

======================================================================

Comments
CONVERTED DATA BugTraq+ Release Management Values COMMIT TO FIX: 1.4.2_06 generic tiger-rc FIXED IN: 1.4.2_06 tiger-rc INTEGRATED IN: 1.4.2_06 tiger-b56 tiger-rc VERIFIED IN: 1.4.2_06
23-07-2004

SUGGESTED FIX *** /src/share/classes/java/util/logging/LogManager.java- Tue Jun 1 14:21:09 2004 --- LogManager.java Tue Jun 1 14:18:29 2004 *** 203,214 **** --- 203,219 ---- * it is intended that there only be one LogManager object, whose value is * retrieved by calling Logmanager.getLogManager. */ protected LogManager() { // Add a shutdown hook to close the global handlers. + try { Runtime.getRuntime().addShutdownHook(new Cleaner()); + } catch(IllegalStateException e) { + // If the VM is already shutting down, + // We do not need to register shutdownHook. } + } /** * Return the global LogManager object. */ public static LogManager getLogManager() {
23-07-2004

EVALUATION The current lazy initialization strategy was instituted to reduce footprint and startup time. While the problem could be fixed by going back to eacher initialization of the logger, this might have undesirable performance consequences. Another possibility is cope more gracefully with the failure to create a logger while the JVM is shutting down. It is not clear whether this problem should be fixed in the logger or in preferences. ###@###.### 2004-02-08
08-02-2004