Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Tomcat doesn't run on openjdk8-fedora #880

Closed
nyh opened this issue Jun 8, 2017 · 9 comments
Closed

Tomcat doesn't run on openjdk8-fedora #880

nyh opened this issue Jun 8, 2017 · 9 comments

Comments

@nyh
Copy link
Contributor

nyh commented Jun 8, 2017

After fixing issues #601 and #878, tomcat still doesn't run with openjdk8-fedora. If I run

scripts/build image=openjdk8-fedora,tomcat
scripts/run.py

The result looks something like that (abridged):

OSv v0.24-366-ga70cbd0
eth0: 192.168.122.15
java.so: Starting JVM app using: io/osv/isolated/RunIsolatedJvmApp
java.so: Setting Java system classloader to IsolatingOsvSystemClassLoader and logging manager to IsolatingLogManager
...
Exception was caught while running -cp /usr/tomcat/bin/bootstrap.jar:/usr/tomcat/bin/tomcat-juli.jar -Djava.util.logging.config.file=/usr/tomcat/conf/logging.properties -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager -Dcatalina.base=/usr/tomcat -Dcatalina.home=/usr/tomcat -Djava.io.tmpdir=/usr/tomcat/temp org.apache.catalina.startup.Bootstrap start exception: io.osv.isolated.ContextFailedException: java.lang.InternalError
io.osv.isolated.ContextFailedException: java.lang.InternalError
	at io.osv.isolated.Context.join(Context.java:63)
	at io.osv.isolated.IsolatedJvm.runSync(IsolatedJvm.java:159)
	at io.osv.isolated.MultiJarLoader$RunOnThread.run(MultiJarLoader.java:130)
Caused by: java.lang.InternalError
	at sun.security.ec.SunEC.initialize(Native Method)
	at sun.security.ec.SunEC.access$000(SunEC.java:49)
	at sun.security.ec.SunEC$1.run(SunEC.java:61)
	at sun.security.ec.SunEC$1.run(SunEC.java:58)
	at java.security.AccessController.doPrivileged(Native Method)
	at sun.security.ec.SunEC.<clinit>(SunEC.java:58)
	at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
	at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
	at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
	at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
	at java.lang.Class.newInstance(Class.java:442)
	at sun.security.jca.ProviderConfig$2.run(ProviderConfig.java:221)
	at sun.security.jca.ProviderConfig$2.run(ProviderConfig.java:206)
	at java.security.AccessController.doPrivileged(Native Method)
	at sun.security.jca.ProviderConfig.doLoadProvider(ProviderConfig.java:206)
	at sun.security.jca.ProviderConfig.getProvider(ProviderConfig.java:187)
	at sun.security.jca.ProviderList.loadAll(ProviderList.java:282)
	at sun.security.jca.ProviderList.removeInvalid(ProviderList.java:299)
	at sun.security.jca.Providers.getFullProviderList(Providers.java:173)
	at java.security.Security.getProviders(Security.java:485)
	at org.apache.catalina.core.JreMemoryLeakPreventionListener.lifecycleEvent(JreMemoryLeakPreventionListener.java:393)
	at org.apache.catalina.util.LifecycleSupport.fireLifecycleEvent(LifecycleSupport.java:117)
	at org.apache.catalina.util.LifecycleBase.fireLifecycleEvent(LifecycleBase.java:90)
	at org.apache.catalina.util.LifecycleBase.setStateInternal(LifecycleBase.java:402)
	at org.apache.catalina.util.LifecycleBase.init(LifecycleBase.java:99)
	at org.apache.catalina.startup.Catalina.load(Catalina.java:576)
	at org.apache.catalina.startup.Catalina.load(Catalina.java:599)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.apache.catalina.startup.Bootstrap.load(Bootstrap.java:310)
	at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:484)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at io.osv.Jvm.runMain(Jvm.java:119)
	at io.osv.isolated.IsolatedJvm.access$400(IsolatedJvm.java:30)
	at io.osv.isolated.IsolatedJvm$3.run(IsolatedJvm.java:116)

It seems to me that the relevant part of this trace is:

	at sun.security.ec.SunEC.initialize(Native Method)
	at sun.security.ec.SunEC.access$000(SunEC.java:49)
	at sun.security.ec.SunEC$1.run(SunEC.java:61)
	at sun.security.ec.SunEC$1.run(SunEC.java:58)
	at java.security.AccessController.doPrivileged(Native Method)
	at sun.security.ec.SunEC.<clinit>(SunEC.java:58)

Which would mean there is a problem in this internal Java method (so I'll need to look at its code next)... However, there are many lines above implying this might have something to do with the "isolation" stuff. @wkozaczuk have you ever seen something like this?

@wkozaczuk
Copy link
Collaborator

wkozaczuk commented Jun 8, 2017 via email

@wkozaczuk
Copy link
Collaborator

wkozaczuk commented Jun 8, 2017 via email

@nyh
Copy link
Contributor Author

nyh commented Jun 9, 2017

That commit was about adding some of the prerequisites of libsunsec.so - when I saw that libsunsec.so was being loaded, and calling non-existant functions because ts prerequisite libraries weren't found. But maybe my commit to clean up the directory link ruined things?
Anyway, I'm surprised at your finding, because the trace:

	at sun.security.ec.SunEC.initialize(Native Method)
	at sun.security.ec.SunEC.access$000(SunEC.java:49)

suggested to me that what failed was the native method - i.e., libsunec.so was successfully loaded but then its initialization function failed. But I probably misunderstood this. Anyway, need to look at the OpenJDK 8 code, not OpenJDK 7.

@nyh
Copy link
Contributor Author

nyh commented Jun 9, 2017

Turns out the faulting initialize() code comes from a Fedora-specific patch, it's not in the original openjdk code. The library itself loads well, it's just the initialize() call which is failing:

--- openjdk/jdk/src/share/classes/sun/security/ec/SunEC.java    Wed Jan 27 03:45
:06 2016 +0000
+++ openjdk/jdk/src/share/classes/sun/security/ec/SunEC.java    Wed Jan 27 04:02
:27 2016 +0000
@@ -58,6 +58,7 @@
             AccessController.doPrivileged(new PrivilegedAction<Void>() {
                 public Void run() {
                     System.loadLibrary("sunec"); // check for native library
+                    initialize();
                     return null;
                 }
             });

I'm continuing to investigate.

@nyh
Copy link
Contributor Author

nyh commented Jun 9, 2017

The initialize() function (see Fedora's pr2815.patch) does

+JNIEXPORT void
+JNICALL Java_sun_security_ec_SunEC_initialize
+  (JNIEnv *env, jclass UNUSED(clazz))
+{
+#ifdef SYSTEM_NSS
+    if (SECOID_Init() != SECSuccess) {
+       ThrowException(env, INTERNAL_ERROR);
+    }
+#endif
+}

This SECOID_Init() is libnss stuff. I have no idea what it's supposed to do. Continuing to investigate :-)

@nyh
Copy link
Contributor Author

nyh commented Jun 9, 2017

Wow, this bug is really frustrating.
I ran SECOID_Init() myself in the same image, and it works (returns 0, i.e., SECSuccess).
When I print out the functions being resolved, I notice that when Java calls this initialize() function, somehow (I'm not sure exactly how), NSS_Init() gets called as well. It seems to me now that it is that function that fails (and somehow causes SECOID_Init() to fail). I also notice this failure happens right after a dladdr() which fails to find the requested symbol, I am guessing maybe one of the modules /usr/lib64/libnss* are not installed - although I can't explain why I don't see any error messages.
I also suspected that NSS_Init() might be failing because we installed antique version of ca-certificates, but updating it to the latest ca-certificates package did not help, unfortunately.
I also can't explain why my own call of SECOID_Init() succeeded, but Java's ended up calling NSS_Init() and failing...
What a mess...

@wkozaczuk
Copy link
Collaborator

wkozaczuk commented Jun 10, 2017 via email

@nyh
Copy link
Contributor Author

nyh commented Jan 17, 2018

Same problem when trying to run apache-derby with openjdk8-fedora:

scripts/build image=openjdk8-fedora,apache-derby

wkozaczuk added a commit to cloudius-systems/osv-apps that referenced this issue Jan 19, 2020
This patch fixes a crash reported by issue #880. The crash
actually happens due to a missing library libfreeblpriv3.so
provided by nss-softokn-freebl package. The root cause
was discovered by tracing vfs* operation where libsunec
would try and fail to dlopen() that library.

It turns out that newer versions of the package java-1.8.0-openjdk-headless
(for fedora 32 for example) come with libsunec that is NOT dependant
on nss* libraries (at least not dynamically) and would work
without this patch.

This patch also fixes cpio related issue that would happen
when trying to build this app on Ubuntu (see cloudius-systems/osv#880 (comment)
for details).

Fixes #880

Signed-off-by: Waldemar Kozaczuk <[email protected]>
@wkozaczuk
Copy link
Collaborator

wkozaczuk commented Jan 19, 2020

Fixed by cloudius-systems/osv-apps@682f9da

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants