https://issues.apache.org/bugzilla/show_bug.cgi?id=57021
Bug ID: 57021
Summary: Improve logging in AprLifecycleListener and
jni.Library when Tomcat-Native DLL fails to load
Product: Tomcat 8
Version: 8.0.14
Hardware: PC
Status: NEW
Severity: enhancement
Priority: P2
Component: Connectors
Assignee: dev@tomcat.apache.org
Reporter: knst.koli...@gmail.com
I occasionally used a version of Tomcat-Native DLL that JVM failed to
initialize. The error was logged to stderr, but to none of our log files.
Steps to reproduce with 8.0.14 on Windows with JDK 7u67:
1. Get a wrong version of tcnative-1.dll and put it into %CATALINA_HOME%/bin
directory. I erroneously used a x64 DLL with a x86 JDK.
2. Start Tomcat and log output into a file:
cd bin
catalina.bat run >catalina.out 2>&1
3. Stop Tomcat
Ctrl+C or catalina.bat stop
4. Actual: An error (cited below) was logged onto console (catalina.out) but it
is not present in catalina.2014-09-25.log file. The only relevant message in
catalina.2014-09-25.log was "The APR based Apache Tomcat Native library <...>
was not found on the java.library.path: <...>.
Expected: A properly logged error.
Looking in the source code,
1) In AprLifecycleListener.init() the Throwable is caught but not logged.
2) The exception is printed by org.apache.tomcat.jni.Library.Library()
constructor. The code looks like the following:
[[[
String name = System.mapLibraryName(NAMES[i]);
String path = System.getProperty("java.library.path");
String sep = System.getProperty("path.separator");
String [] paths = path.split(sep);
for (int j=0; j<paths.length; j++) {
java.io.File fd = new java.io.File(paths[j] , name);
if (fd.exists()) {
t.printStackTrace();
}
}
if ( i > 0)
err.append(", ");
err.append(t.getMessage());
<...>
if (!loaded) {
err.append('(');
err.append(System.getProperty("java.library.path"));
err.append(')');
throw new UnsatisfiedLinkError(err.toString());
}
]]]
The loop with "fd.exists()" does essentially the same thing that JRE itself is
doing in loadLibrary() to locate the library file before actually trying to
load it.
Thoughts on possible improvement:
===================================
A. Treat the case when "fd.exists()" as fatal and rethrow original exception.
This will change behaviour in case when both "tcnative-1" and "libtcnative-1"
libraries are present in "java.library.path" directories and the first library
fails to load while the second one succeeds.
With the current code it will print an error for the first library and may
silently successfully load the second one. With the change that I am proposing
it will fail with the first library without trying the second one.
I say that configuration with both libraries being present is unlikely, and as
it was printing an error for the first library I say that such configuration is
a broken one.
Rethrowing original exception will provide better diagnostics (if
AprLifecycleListener is modified to log it) and will remove printing to
System.err.
B. Replace "throw new UnsatisfiedLinkError(err.toString());" with a custom
Error class e.g. LibraryNotFoundError extends UnsatisfiedLinkError.
- Include original exceptions and library names into LibraryNotFoundError.
- Use this class in AprLifecycleListener to discern between
UnsatisfiedLinkError from failed attempt to load a library versus the common
"library does not exist" scenario.
In the former case, log it as a warning. In the latter case print original
exceptions if debug logging is enabled. The usual informational message
follows.
C. Simplify AprLifecycleListener class and call Library.initialize(null)
directly without relying on reflection.
There are already references to the fields such as Library.APR_MAJOR_VERSION
further in the code. There is no point in using reflection is this case.
In the unlikely case that tomcat-jni.jar is not on classpath,
AprLifecycleListener should not be present in server.xml as well. In this case
Connector.<init> will call AprLifecycleListener.isAprAvailable() but the call
to init() will not be performed. It should succeed even if Library class is not
on classpath.
For reference, the error message with 8.0.14 (with some path censoring) was:
========================
[[[
java.lang.UnsatisfiedLinkError: <CATALINA_HOME>\bin\tcnative-1.dll: Can't load
AMD 64-bit .dll on a IA 32-bit platform
at java.lang.ClassLoader$NativeLibrary.load(Native Method)
at java.lang.ClassLoader.loadLibrary1(ClassLoader.java:1965)
at java.lang.ClassLoader.loadLibrary0(ClassLoader.java:1890)
at java.lang.ClassLoader.loadLibrary(ClassLoader.java:1880)
at java.lang.Runtime.loadLibrary0(Runtime.java:849)
at java.lang.System.loadLibrary(System.java:1088)
at org.apache.tomcat.jni.Library.<init>(Library.java:40)
at org.apache.tomcat.jni.Library.initialize(Library.java:172)
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
org.apache.catalina.core.AprLifecycleListener.init(AprLifecycleListener.java:203)
at
org.apache.catalina.core.AprLifecycleListener.isAprAvailable(AprLifecycleListener.java:105)
at org.apache.catalina.connector.Connector.setProtocol(Connector.java:564)
at org.apache.catalina.connector.Connector.<init>(Connector.java:66)
at
org.apache.catalina.startup.ConnectorCreateRule.begin(ConnectorCreateRule.java:62)
...
]]]
--
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@tomcat.apache.org
For additional commands, e-mail: dev-h...@tomcat.apache.org
