NPE when com.sun.identity.util.debug.provider is Invalid

[Kortanul]

Affected Versions

• 13.5.x (sustaining/13.5.x, at 772b7a7)

Summary

If you specify a custom class name for com.sun.identity.util.debug.provider when running Tomcat, and that class name is invalid, AM fails to start with an NPE instead of recovering gracefully.

Steps to Reproduce

1. Modify CATALINA_OPTS for AM to include the following:

   -Dcom.sun.identity.util.debug.provider=com.sun.identity.shared.debug.impl.StdOutDebugProvider

2. Ensure the AM WAR file is in the Tomcat webapps folder.
3. Attempt to launch Tomcat.

Expected Results

• The following error should appear in the Tomcat log:

  Failed to create debug service provider instance. Using the default provider.
  java.lang.ClassNotFoundException: com.sun.identity.shared.debug.impl.StdOutDebugProvider
        at org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1364)
        at org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1185)
        at java.lang.Class.forName0(Native Method)
        at java.lang.Class.forName(Class.java:264)

• AM deploys and launches successfully.

Actual Results

• The following error appears:

  SEVERE [localhost-startStop-1] org.apache.catalina.core.StandardContext.startInternal One or more listeners failed to start. Full details will be found in the appropriate container log file
  SEVERE [localhost-startStop-1] org.apache.catalina.core.StandardContext.startInternal Context [/wrenam] startup failed due to previous errors
  INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/usr/local/tomcat/webapps/wrenam] has finished in [30,695] ms

• The following NPE appears in the Catalina logs:

  SEVERE [localhost-startStop-1] org.apache.catalina.core.StandardContext.listenerStart Exception sending context initialized event to listener instance of class [org.forgerock.guice.core.GuiceInitialisationFilter]
   org.forgerock.guava.common.util.concurrent.ExecutionError: java.lang.ExceptionInInitializerError
          at org.forgerock.guava.common.cache.LocalCache$Segment.get(LocalCache.java:2201)
          at org.forgerock.guava.common.cache.LocalCache.get(LocalCache.java:3937)
  Caused by: java.lang.ExceptionInInitializerError
          at com.sun.identity.shared.debug.Debug.initialize(Debug.java:292)
          at com.sun.identity.shared.debug.Debug.<clinit>(Debug.java:762)
          at org.forgerock.openam.slf4j.AMLoggerFactory$1.load(AMLoggerFactory.java:33)
          at org.forgerock.openam.slf4j.AMLoggerFactory$1.load(AMLoggerFactory.java:30)
  Caused by: java.lang.NullPointerException
          at com.sun.identity.shared.debug.Debug.getInstance(Debug.java:206)
          at com.sun.identity.shared.locale.Locale.<clinit>(Locale.java:84)

• AM fails to deploy and start.

[Kortanul]

This is really dumb... ROFL. The reason for the NPE is that the initialization of the Locale class fails while AM is in the process of initializing logging... so it tries to use the thing it just failed to initialize to log the error.

In short, the debug provider is null, so it tries to log an error using the Locale, which depends on the provider not being null for logging...