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.

Sign up for GitHub

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

Jump to bottom

Quarkus 2.x has java.lang.NoClassDefFoundError: Could not initialize class javax.crypto.JceSecurity #19265

Closed
dhoffer opened this issue Aug 5, 2021 · 33 comments
Closed

Quarkus 2.x has java.lang.NoClassDefFoundError: Could not initialize class javax.crypto.JceSecurity #19265

dhoffer opened this issue Aug 5, 2021 · 33 comments
Labels
area/security kind/bug Something isn't working triage/needs-feedback We are waiting for feedback.

Comments

@dhoffer
Copy link

dhoffer commented Aug 5, 2021

Describe the bug

After upgrading from 1.13.7.Final to any of the 2.x versions we get this error at startup.

I retested with 2.1.1.Final and it has the same behavior.

We are using JDK 11.0.11+9. Code and JDK work fine with pre 2.x Quarkus.

This code is just trying to decrypt a password in the io.quarkus.credentials.CredentialsProvider implementation used to connect to the database.

2021-08-05 15:21:21,296 ERROR [io.qua.run.Application] (main) Failed to start application (with profile prod): java.lang.NoClassDefFoundError: Could not initialize class javax.crypto.JceSecurity
at java.base/javax.crypto.Cipher.getInstance(Cipher.java:540)
at com.bs.util.encryption.AESEncryptDecrypt.getInitializedCipher(AESEncryptDecrypt.java:151)
at com.bs.util.encryption.AESEncryptDecrypt.decrypt(AESEncryptDecrypt.java:127)
at com.bs.util.encryption.AESEncryptDecryptProxy.decrypt(AESEncryptDecryptProxy.java:44)
at com.bs.util.BSDataSourceCredentialsProvider.getCredentials(BSDataSourceCredentialsProvider.java:33)
at com.bs.util.BSDataSourceCredentialsProvider_ClientProxy.getCredentials(BSDataSourceCredentialsProvider_ClientProxy.zig:157)
at io.quarkus.agroal.runtime.AgroalVaultCredentialsProviderPassword.asProperties(AgroalVaultCredentialsProviderPassword.java:21)
at io.agroal.api.security.AgroalDefaultSecurityProvider.getSecurityProperties(AgroalDefaultSecurityProvider.java:23)
at io.agroal.pool.ConnectionFactory.securityProperties(ConnectionFactory.java:190)
at io.agroal.pool.ConnectionFactory.securityProperties(ConnectionFactory.java:179)
at io.agroal.pool.ConnectionFactory.jdbcProperties(ConnectionFactory.java:160)
at io.agroal.pool.ConnectionFactory.createConnection(ConnectionFactory.java:204)
at io.agroal.pool.ConnectionPool$CreateConnectionTask.call(ConnectionPool.java:470)
at io.agroal.pool.ConnectionPool$CreateConnectionTask.call(ConnectionPool.java:452)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at io.agroal.pool.util.PriorityScheduledExecutor.beforeExecute(PriorityScheduledExecutor.java:68)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1126)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at java.base/java.lang.Thread.run(Thread.java:829)

Expected behavior

Quarkus should be able to load the JDK class javax.crypto.JceSecurity.

Actual behavior

See stacktrace in description.

How to Reproduce?

No response

Output of uname -a or ver

No response

Output of java -version

openjdk 11.0.11 2021-04-20 OpenJDK Runtime Environment AdoptOpenJDK-11.0.11+9 (build 11.0.11+9) OpenJDK 64-Bit Server VM AdoptOpenJDK-11.0.11+9 (build 11.0.11+9, mixed mode)

GraalVM version (if different from Java)

No response

Quarkus version or git rev

2.1.1.Final

Build tool (ie. output of mvnw --version or gradlew --version)

No response

Additional information

No response
@dhoffer dhoffer added the kind/bug Something isn't working label Aug 5, 2021
@quarkus-bot
Copy link

quarkus-bot bot commented Aug 5, 2021

/cc @sberyozkin

@stuartwdouglas
Copy link
Member

How can I reproduce this? I can load the class fine using Class.forName().

That error is also an initializion error, which means the static init block in JceSecurity is throwing an exception. Attaching a debugger to see what is actually throwing the exception would also be really helpful if you can't provide a reproducer.

@dhoffer
Copy link
Author

dhoffer commented Aug 9, 2021 via email

@stuartwdouglas
Copy link
Member

The static block is in the JDK itself, not much we can do about it. I tried with pretty much the exact same code and it worked.

Looking through the source code of JceSecurity I don't see how anything Quarkus was doing could actually affect it, so I am really not sure what is going on. You are going to need to attach a debugger to see what is actually throwing the exception (Java makes it really hard to debug these kinds of errors, as the cause is lost and turned into NoClassDefFoundError instead).

@dhoffer
Copy link
Author

dhoffer commented Aug 9, 2021 via email

@dhoffer
Copy link
Author

dhoffer commented Aug 20, 2021 •
edited
Loading

I am having a hard time getting more details as I debug this. Here is the full stack trace.

2021-08-19 15:34:14,891 ERROR [io.qua.run.Application] (main) Failed to start application (with profile prod): java.lang.NoClassDefFoundError: Could not initialize class javax.crypto.JceSecurity
at java.base/javax.crypto.Cipher.getInstance(Cipher.java:540)
at com.bs.util.encryption.AESEncryptDecrypt.getInitializedCipher(AESEncryptDecrypt.java:151)
at com.bs.util.encryption.AESEncryptDecrypt.decrypt(AESEncryptDecrypt.java:127)
at com.bs.util.encryption.AESEncryptDecryptProxy.decrypt(AESEncryptDecryptProxy.java:50)
at com.bs.util.DataSourceCredentialsProvider.getCredentials(DataSourceCredentialsProvider.java:33)
at com.bs.util.DataSourceCredentialsProvider_ClientProxy.getCredentials(DataSourceCredentialsProvider_ClientProxy.zig:157)
at io.quarkus.agroal.runtime.AgroalVaultCredentialsProviderPassword.asProperties(AgroalVaultCredentialsProviderPassword.java:21)
at io.agroal.api.security.AgroalDefaultSecurityProvider.getSecurityProperties(AgroalDefaultSecurityProvider.java:23)
at io.agroal.pool.ConnectionFactory.securityProperties(ConnectionFactory.java:190)
at io.agroal.pool.ConnectionFactory.securityProperties(ConnectionFactory.java:179)
at io.agroal.pool.ConnectionFactory.jdbcProperties(ConnectionFactory.java:160)
at io.agroal.pool.ConnectionFactory.createConnection(ConnectionFactory.java:204)
at io.agroal.pool.ConnectionPool$CreateConnectionTask.call(ConnectionPool.java:470)
at io.agroal.pool.ConnectionPool$CreateConnectionTask.call(ConnectionPool.java:452)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at io.agroal.pool.util.PriorityScheduledExecutor.beforeExecute(PriorityScheduledExecutor.java:68)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1126)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at java.base/java.lang.Thread.run(Thread.java:829)

The line in java.base/javax.crypto.Cipher.getInstance where it is failing is on this line:
JceSecurity.canUseProvider(s.getProvider()) (line 540)

However my IDE will never go into that method it throws the NoClassDefFoundError exception.

The strange part is when I debug this the code lands on 540 about 20 times in a loop, giving an error each time. Then it just quits with the above stack trace.

Note our app has 3 data sources and two of them use the DataSourceCredentialsProvider. The third data source is not available in our DEV environment so that one just fails...but we expect that one to fail. With Quarkus 2.x all of them fail with this new NoClassDefFoundError error.

I have verified this fails with the new 2.1.3.Final version as well.

So in summary fails with all Quarkus 2.x
Works with all Quarkus 1.x
Same JDK 11
Same code base.

Here is my Java:
C:\projects\app>java --version
openjdk 11.0.11 2021-04-20
OpenJDK Runtime Environment AdoptOpenJDK-11.0.11+9 (build 11.0.11+9)
OpenJDK 64-Bit Server VM AdoptOpenJDK-11.0.11+9 (build 11.0.11+9, mixed mode)

Note this is very early code in application startup. Agroal is trying to get the password for our DB and to do that it has to use our AES decryption that is used in the CredentialsProvider implementation.

@stuartwdouglas
Copy link
Member

It looks like the static init block has the following:

        } catch (Exception e) {
            throw new SecurityException(
                    "Can not initialize cryptographic mechanism", e);
        }

Can you set a breakpoint for SecurityException, and try and figure out what the underlying exception is?

Also what mode is this, is it prod, dev or both? If it is prod using fast-jar is it still a problem with legacy-jar or uber-jar?

@dhoffer
Copy link
Author

dhoffer commented Aug 24, 2021

Its not throwing in the static block, all good there. We are running in prod using an uber-jar.

@stuartwdouglas
Copy link
Member

Can you make a reproducer? It seems like this is all in the database startup code so I am assuming a small project with the same config would have the same issue?

@dhoffer
Copy link
Author

dhoffer commented Aug 24, 2021

I doubt that will be possible. If no one else is having any troubles with their 2.x apps my new simple one will likely work as well. I'll keep investigating but not getting far on this.

@stuartwdouglas
Copy link
Member

Is there something specific in your datasource config that is triggering this code path?

It's really weird because I don't really see how Quarkus can affect a JDK class like this, especially given we don't do anything special with ClassLoading in an Uber Jar.

@dhoffer
Copy link
Author

dhoffer commented Aug 24, 2021

Nothing special. Just using quarkus.datasource.credentials-provider config so Quarkus uses CredentialsProvider to get DB credentials. Quarkus calls this very early as it needs the DB credentials early.

@jaikiran
Copy link
Member

So I tried something outside of Quarkus in a standalone trivial Java code. 2 classes Foo and Bar. Foo just keeps calling a static method on Bar in a loop and catches any exception, prints it and the continues calling that method on Bar for the next time. This it does for 5 times. Bar has a static (class) initialization block and intentionally throws an exception from that block everytime. Here's what these classes look like:

Foo.java

public class Foo {
	public static void main(final String[] args) throws Exception {
		for (int i = 0; i < 5; i++) {
			try {
				Bar.doSomething();
			} catch(Throwable t) {
				System.err.println("Got error " + i);
				t.printStackTrace();
			}

		}

	}
}

Bar.java

public class Bar {

	static {
		System.out.println("Hi");
		if (true) {
			throw new SecurityException("intentional");
		}
	}
	
	public static void doSomething() {
		System.err.println("Done");
	}
}

I then run this code with Java 11 and here's what I get as the output:

Hi
Got error 0
java.lang.ExceptionInInitializerError
	at Foo.main(Foo.java:5)
Caused by: java.lang.SecurityException: intentional
	at Bar.<clinit>(Bar.java:6)
	... 1 more
Got error 1
java.lang.NoClassDefFoundError: Could not initialize class Bar
	at Foo.main(Foo.java:5)
Got error 2
java.lang.NoClassDefFoundError: Could not initialize class Bar
	at Foo.main(Foo.java:5)
Got error 3
java.lang.NoClassDefFoundError: Could not initialize class Bar
	at Foo.main(Foo.java:5)
Got error 4
java.lang.NoClassDefFoundError: Could not initialize class Bar
	at Foo.main(Foo.java:5)

Notice that the first attempt that called the static method Bar.doSomething which triggered the static initializer of Bar class fails and contains the full details including the underlying root cause of why it failed in its exception stacktrace:

Hi
Got error 0
java.lang.ExceptionInInitializerError
	at Foo.main(Foo.java:5)
Caused by: java.lang.SecurityException: intentional
	at Bar.<clinit>(Bar.java:6)
	... 1 more

However, the subsequent attempts on Bar.doSomething() just throw a NoClassDefFoundError without any underlying cause, like this next attempt:

Got error 1
java.lang.NoClassDefFoundError: Could not initialize class Bar
	at Foo.main(Foo.java:5)

This detail is crucial, because in one of your comment you said:

The strange part is when I debug this the code lands on 540 about 20 times in a loop, giving an error each time. Then it just quits with the above stack trace.

So it looks like somewhere in your code in this flow you have a catch block which catches the exception (actually I think some part of your code is catching Throwable and not just Exception) but then does something else which again triggers the code which leads to this JceSecurity class. This it perhaps does in a loop maybe? Perhaps 20 times and then when all 20 attempts fail, it throws the last exception, which of course as seen in that above sample code will not contain the root cause.

So what you could do is, in the following flow/classes:

at java.base/javax.crypto.Cipher.getInstance(Cipher.java:540)
at com.bs.util.encryption.AESEncryptDecrypt.getInitializedCipher(AESEncryptDecrypt.java:151)
at com.bs.util.encryption.AESEncryptDecrypt.decrypt(AESEncryptDecrypt.java:127)
at com.bs.util.encryption.AESEncryptDecryptProxy.decrypt(AESEncryptDecryptProxy.java:50)
at com.bs.util.DataSourceCredentialsProvider.getCredentials(DataSourceCredentialsProvider.java:33)

Find out where such a loop or try/catch block exists. See what's it's doing and if needs to be fixed. Since you are able to debug this code, I think if you can add a breakpoint in this catch block and inspect the first thrown exception, then it's likely that it will have a cause hierarchy which shows what the root cause is. If you need help understanding that root cause you can paste that exception hierarchy here (you can get it while debugger is attached by executing a e.printStackTrace() against that exception that you are inspecting, the stacktrace will get printed in the console of Quarkus app). It's crucial that you inspect the first exception that is thrown out of those 20 exceptions in a loop.

@stuartwdouglas
Copy link
Member

I would also try adding a breakpoint for ExceptionInInitializerError and see if that helps

@dhoffer
Copy link
Author

dhoffer commented Aug 25, 2021

Thanks for the detailed reply and ideas, I will try to track this down.

I do have some initial feedback though. We no NOT have any retries or loops in our code regarding this issue. We make ONE call to Cipher.getInstance(cryptoModePadding) for every ONE call of Quarkus/Agroal to CredentialsProvider#getCredentials(String credentialsProviderName)

I believe the loop of 20 I mentioned is in the JDK here:

public static final Cipher getInstance(String transformation){
...
Iterator t = services.iterator();
Exception failure = null;
while (t.hasNext()) {
Service s = t.next();
if (JceSecurity.canUseProvider(s.getProvider()) == false) {
continue;
}
...

@jaikiran
Copy link
Member

I believe the loop of 20 I mentioned is in the JDK here:

public static final Cipher getInstance(String transformation){
...
Iterator t = services.iterator();
Exception failure = null;
while (t.hasNext()) {
Service s = t.next();
if (JceSecurity.canUseProvider(s.getProvider()) == false) {
continue;
}

That however doesn't explain why the thrown exception is not getting propagated out of the loop and method, the very first instance. I don't see any catch block around that call to JceSecurity.canUseProvider, unless I'm not looking at the right JDK version/implementation?

We are using JDK 11.0.11+9

Where did you download and install this from?

@dhoffer
Copy link
Author

dhoffer commented Aug 25, 2021 via email •
edited
Loading

@jaikiran
Copy link
Member

If the "easier" path of debugging doesn't solve this, then I think the last resort is the Byteman approach. In that case, please follow these steps:

RULE ExceptionInInitializerError no-arg
CLASS java.lang.ExceptionInInitializerError
METHOD <init>()
AT EXIT
IF TRUE
DO traceStack("*** ExceptionInInitializerError no-arg called")
ENDRULE

RULE ExceptionInInitializerError throwable-arg
CLASS java.lang.ExceptionInInitializerError
METHOD <init>(Throwable)
AT EXIT
IF TRUE
DO traceStack("*** ExceptionInInitializerError called with a cause");
   $1.printStackTrace();
ENDRULE


RULE ExceptionInInitializerError string-arg
CLASS java.lang.ExceptionInInitializerError
METHOD <init>(String)
AT EXIT
IF TRUE
DO traceStack("*** ExceptionInInitializerError with message called")
ENDRULE


RULE JceSecurity exception exit
CLASS javax.crypto.JceSecurity
METHOD <clinit>
AT EXCEPTION EXIT
IF TRUE
DO traceStack("*** JceSecurity failed with exception");
  $^.printStackTrace();
ENDRULE
  • Assuming that location you saved these files is "C:\projects\udl\byteman", the launch your Quarkus application using:
java -javaagent:"C:\projects\udl\byteman\byteman-4.0.16.jar=script:C:\projects\udl\byteman\byteman-rules.btm,boot:C:\projects\udl\byteman\byteman-4.0.16.jar,prop:org.jboss.byteman.verbose=true,prop:org.jboss.byteman.transform.all=true" -jar <the-quarkus-application-jar>

(you might have to fiddle with the java launch command. Essentially you just need to additionally add the javaagent option as noted above in addition to whatever you are currently using to launch your application)

This should generate (hopefully) enough exception stacktrace/output on the console when the JceSecurity class initialization errors out.

P.S: Long back, I had wondered whether Quarkus should have a much more seamless integration with Byteman to help with issues like these. I think it's time to experiment a bit and see how to make debugging Quarkus in cases like these easier with Byteman. I'll see if I can try a PoC to make this easier.

@jaikiran
Copy link
Member

jaikiran commented Aug 25, 2021 •
edited
Loading

@stuartwdouglas, @mkouba, any chance the dynamic bytecode that we generate[1] in this com.bs.util.BSDataSourceCredentialsProvider_ClientProxy.zig:

com.bs.util.BSDataSourceCredentialsProvider.getCredentials(BSDataSourceCredentialsProvider.java:33)
at com.bs.util.BSDataSourceCredentialsProvider_ClientProxy.getCredentials(BSDataSourceCredentialsProvider_ClientProxy.zig:157)
at io.quarkus.agroal.runtime.AgroalVaultCredentialsProviderPassword.asProperties(AgroalVaultCredentialsProviderPassword.java:21)

might have swallowed the exception/throwable from JceSecurity at some point in its usage and yet allowed the call on that proxy to move forward? That's the last thing I can think of, before I call it a day. The bytecode generation code isn't very intuitive to understand at a quick glance (for obvious reasons), so I can't confirm this myself right now.

[1] https://github.com/quarkusio/quarkus/blob/main/independent-projects/arc/processor/src/main/java/io/quarkus/arc/processor/ClientProxyGenerator.java#L45

@dhoffer
Copy link
Author

dhoffer commented Aug 25, 2021

Fyi...I tried 2.1.3.Final in 3 more Quarkus apps, all much smaller then the first one. Two did not have this error but one does so 2 in total have this error and 2 do not. And just as a reminder this is with 2.x only, 1.x is fine.

@stuartwdouglas
Copy link
Member

stuartwdouglas commented Aug 25, 2021 via email

@dhoffer
Copy link
Author

dhoffer commented Aug 26, 2021 •
edited
Loading

I finally have good news to report. The tips provided by @jaikiran were incredibly helpful.

I added Byteman just as described and the logs immediately reported:

java.util.ServiceConfigurationError: java.net.spi.URLStreamHandlerProvider: Provider org.infinispan.commons.jdkspecific.ClasspathURLStreamHandlerProvider not found
at java.base/java.util.ServiceLoader.fail(ServiceLoader.java:589)

So then a quick Google query brought me here:

infinispan/infinispan-quarkus#55

It turns out that in the two apps that fail we had a dependency on this component. But it turns out it's OBE as it builds/runs with out the infinispan-quarkus dependency.

So some observations/questions/suggestions.

  1. Why does Quarkus 2.x fail with this but 1.x was fine?
  2. Why does Quarkus hide the real error? IDK but suspect that what @jaikiran said regarding com.bs.util.BSDataSourceCredentialsProvider_ClientProxy.zig is likely the cause.
  3. I really like the suggestion that @jaikiran had about integrating Byteman with Quarkus. That tool brought the error from complete obscurity to front and center.

I am good on this issue but Quarkus might want to evaluate the above and see if there is a way to help others when they have strange issues like this one.

Many thanks to @jaikiran on this one!

-Dave

@stuartwdouglas
Copy link
Member

The client proxy should not be hiding anything.

What was the full stack trace? It should shed some light on what hid the exception.

There is an issue for a byteman extension, although it was mostly in reference to native: #2263

@jaikiran
Copy link
Member

Thank you for continuing to investigate this.

I added Byteman just as described and the logs immediately reported:

java.util.ServiceConfigurationError: java.net.spi.URLStreamHandlerProvider: Provider org.infinispan.commons.jdkspecific.ClasspathURLStreamHandlerProvider not found
at java.base/java.util.ServiceLoader.fail(ServiceLoader.java:589)

So I suspect, it's this[1] static block in JceSecurity which is triggering that URLStreamHandler lookup. So like Stuart says, if you can show us the entire exception stacktrace, that will help us understand where this exception is getting swallowed and we can provide a fix if relevant.

[1] https://github.com/openjdk/jdk11u-dev/blob/master/src/java.base/share/classes/javax/crypto/JceSecurity.java.template#L237

@dhoffer
Copy link
Author

dhoffer commented Aug 26, 2021 via email

@jaikiran
Copy link
Member

Do you mean you want to see all that Byteman reported? If so I can try to
do that test first thing tomorrow. I did not capture all of it.

Yes, please. That will be crucial for us (Quarkus) to solve this properly, if at all this turns out to be something that needs to be solved in Quarkus.

@dhoffer
Copy link
Author

dhoffer commented Aug 26, 2021

Here is the full log with Byteman. Please ignore the use of google cache in our part of the code that is new and has nothing to do with this issue, the cache just means we only have to get the user/password once per datasource.

org.jboss.byteman.agent.Transformer : possible trigger for rule JceSecurity exception exit in class javax.crypto.JceSecurity
RuleTriggerMethodAdapter.injectTriggerPoint : inserting trigger into javax.crypto.JceSecurity.() void for rule JceSecurity exception exit
org.jboss.byteman.agent.Transformer : inserted trigger for JceSecurity exception exit in class javax.crypto.JceSecurity
Rule.execute called for JceSecurity exception exit_3:0
HelperManager.install for helper class org.jboss.byteman.rule.helper.Helper
calling activated() for helper class org.jboss.byteman.rule.helper.Helper
Default helper activated
calling installed(JceSecurity exception exit) for helper classorg.jboss.byteman.rule.helper.Helper
Installed rule using default helper : JceSecurity exception exit
JceSecurity exception exit execute
*** JceSecurity failed with exceptionjavax.crypto.JceSecurity.(JceSecurity.java:246)
javax.crypto.Cipher.getInstance(Cipher.java:540)
com.bs.util.encryption.AESEncryptDecrypt.getInitializedCipher(AESEncryptDecrypt.java:151)
com.bs.util.encryption.AESEncryptDecrypt.decrypt(AESEncryptDecrypt.java:127)
com.bs.util.encryption.AESEncryptDecryptProxy.decrypt(AESEncryptDecryptProxy.java:44)
com.bs.util.DataSourceCredentialsProvider.getEmrCredentials(DataSourceCredentialsProvider.java:108)
com.bs.util.DataSourceCredentialsProvider$1.load(DataSourceCredentialsProvider.java:59)
com.bs.util.DataSourceCredentialsProvider$1.load(DataSourceCredentialsProvider.java:49)
com.google.common.cache.LocalCache$LoadingValueReference.loadFuture(LocalCache.java:3529)
com.google.common.cache.LocalCache$Segment.loadSync(LocalCache.java:2278)
com.google.common.cache.LocalCache$Segment.lockedGetOrLoad(LocalCache.java:2155)
com.google.common.cache.LocalCache$Segment.get(LocalCache.java:2045)
com.google.common.cache.LocalCache.get(LocalCache.java:3953)
com.google.common.cache.LocalCache.getOrLoad(LocalCache.java:3976)
com.google.common.cache.LocalCache$LocalLoadingCache.get(LocalCache.java:4960)
com.bs.util.DataSourceCredentialsProvider.getCredentials(DataSourceCredentialsProvider.java:82)
com.bs.util.DataSourceCredentialsProvider_ClientProxy.getCredentials(DataSourceCredentialsProvider_ClientProxy.zig:186)
io.quarkus.agroal.runtime.AgroalVaultCredentialsProviderPassword.asProperties(AgroalVaultCredentialsProviderPassword.java:21)
io.agroal.api.security.AgroalDefaultSecurityProvider.getSecurityProperties(AgroalDefaultSecurityProvider.java:23)
io.agroal.pool.ConnectionFactory.securityProperties(ConnectionFactory.java:190)
io.agroal.pool.ConnectionFactory.securityProperties(ConnectionFactory.java:179)
io.agroal.pool.ConnectionFactory.jdbcProperties(ConnectionFactory.java:160)
io.agroal.pool.ConnectionFactory.createConnection(ConnectionFactory.java:204)
io.agroal.pool.ConnectionPool$CreateConnectionTask.call(ConnectionPool.java:470)
io.agroal.pool.ConnectionPool$CreateConnectionTask.call(ConnectionPool.java:452)
java.util.concurrent.FutureTask.run(FutureTask.java:264)
io.agroal.pool.util.PriorityScheduledExecutor.beforeExecute(PriorityScheduledExecutor.java:68)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1126)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
java.lang.Thread.run(Thread.java:829)
java.util.ServiceConfigurationError: java.net.spi.URLStreamHandlerProvider: Provider org.infinispan.commons.jdkspecific.ClasspathURLStreamHandlerProvider not found
at java.base/java.util.ServiceLoader.fail(ServiceLoader.java:589)
at java.base/java.util.ServiceLoader$LazyClassPathLookupIterator.nextProviderClass(ServiceLoader.java:1212)
at java.base/java.util.ServiceLoader$LazyClassPathLookupIterator.hasNextService(ServiceLoader.java:1221)
at java.base/java.util.ServiceLoader$LazyClassPathLookupIterator.hasNext(ServiceLoader.java:1265)
at java.base/java.util.ServiceLoader$2.hasNext(ServiceLoader.java:1300)
at java.base/java.util.ServiceLoader$3.hasNext(ServiceLoader.java:1385)
at java.base/java.net.URL$1.getNext(URL.java:1314)
at java.base/java.net.URL$1.hasNext(URL.java:1329)
at java.base/java.net.URL$2.run(URL.java:1355)
at java.base/java.net.URL$2.run(URL.java:1352)
at java.base/java.security.AccessController.doPrivileged(Native Method)
at java.base/java.net.URL.lookupViaProviders(URL.java:1351)
at java.base/java.net.URL.getURLStreamHandler(URL.java:1437)
at java.base/java.net.URL.(URL.java:651)
at java.base/java.net.URL.(URL.java:541)
at java.base/java.net.URL.(URL.java:488)
at java.base/javax.crypto.JceSecurity.(JceSecurity.java:239)
at java.base/javax.crypto.Cipher.getInstance(Cipher.java:540)
at com.bs.util.encryption.AESEncryptDecrypt.getInitializedCipher(AESEncryptDecrypt.java:151)
at com.bs.util.encryption.AESEncryptDecrypt.decrypt(AESEncryptDecrypt.java:127)
at com.bs.util.encryption.AESEncryptDecryptProxy.decrypt(AESEncryptDecryptProxy.java:44)
at com.bs.util.DataSourceCredentialsProvider.getEmrCredentials(DataSourceCredentialsProvider.java:108)
at com.bs.util.DataSourceCredentialsProvider$1.load(DataSourceCredentialsProvider.java:59)
at com.bs.util.DataSourceCredentialsProvider$1.load(DataSourceCredentialsProvider.java:49)
at com.google.common.cache.LocalCache$LoadingValueReference.loadFuture(LocalCache.java:3529)
at com.google.common.cache.LocalCache$Segment.loadSync(LocalCache.java:2278)
at com.google.common.cache.LocalCache$Segment.lockedGetOrLoad(LocalCache.java:2155)
at com.google.common.cache.LocalCache$Segment.get(LocalCache.java:2045)
at com.google.common.cache.LocalCache.get(LocalCache.java:3953)
at com.google.common.cache.LocalCache.getOrLoad(LocalCache.java:3976)
at com.google.common.cache.LocalCache$LocalLoadingCache.get(LocalCache.java:4960)
at com.bs.util.DataSourceCredentialsProvider.getCredentials(DataSourceCredentialsProvider.java:82)
at com.bs.util.DataSourceCredentialsProvider_ClientProxy.getCredentials(DataSourceCredentialsProvider_ClientProxy.zig:186)
at io.quarkus.agroal.runtime.AgroalVaultCredentialsProviderPassword.asProperties(AgroalVaultCredentialsProviderPassword.java:21)
at io.agroal.api.security.AgroalDefaultSecurityProvider.getSecurityProperties(AgroalDefaultSecurityProvider.java:23)
at io.agroal.pool.ConnectionFactory.securityProperties(ConnectionFactory.java:190)
at io.agroal.pool.ConnectionFactory.securityProperties(ConnectionFactory.java:179)
at io.agroal.pool.ConnectionFactory.jdbcProperties(ConnectionFactory.java:160)
at io.agroal.pool.ConnectionFactory.createConnection(ConnectionFactory.java:204)
at io.agroal.pool.ConnectionPool$CreateConnectionTask.call(ConnectionPool.java:470)
at io.agroal.pool.ConnectionPool$CreateConnectionTask.call(ConnectionPool.java:452)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at io.agroal.pool.util.PriorityScheduledExecutor.beforeExecute(PriorityScheduledExecutor.java:68)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1126)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at java.base/java.lang.Thread.run(Thread.java:829)

And here is the log w/o Byteman.

2021-08-26 08:38:41,374 ERROR [io.qua.run.Application] (main) Failed to start application (with profile prod): java.lang.NoClassDefFoundError: Could not initialize class javax.crypto.JceSecurity
at java.base/javax.crypto.Cipher.getInstance(Cipher.java:540)
at com.bs.util.encryption.AESEncryptDecrypt.getInitializedCipher(AESEncryptDecrypt.java:151)
at com.bs.util.encryption.AESEncryptDecrypt.decrypt(AESEncryptDecrypt.java:127)
at com.bs.util.encryption.AESEncryptDecryptProxy.decrypt(AESEncryptDecryptProxy.java:44)
at com.bs.util.DataSourceCredentialsProvider.getEmrCredentials(DataSourceCredentialsProvider.java:108)
at com.bs.util.DataSourceCredentialsProvider$1.load(DataSourceCredentialsProvider.java:59)
at com.bs.util.DataSourceCredentialsProvider$1.load(DataSourceCredentialsProvider.java:49)
at com.google.common.cache.LocalCache$LoadingValueReference.loadFuture(LocalCache.java:3529)
at com.google.common.cache.LocalCache$Segment.loadSync(LocalCache.java:2278)
at com.google.common.cache.LocalCache$Segment.lockedGetOrLoad(LocalCache.java:2155)
at com.google.common.cache.LocalCache$Segment.get(LocalCache.java:2045)
at com.google.common.cache.LocalCache.get(LocalCache.java:3953)
at com.google.common.cache.LocalCache.getOrLoad(LocalCache.java:3976)
at com.google.common.cache.LocalCache$LocalLoadingCache.get(LocalCache.java:4960)
at com.bs.util.DataSourceCredentialsProvider.getCredentials(DataSourceCredentialsProvider.java:82)
at com.bs.util.DataSourceCredentialsProvider_ClientProxy.getCredentials(DataSourceCredentialsProvider_ClientProxy.zig:186)
at io.quarkus.agroal.runtime.AgroalVaultCredentialsProviderPassword.asProperties(AgroalVaultCredentialsProviderPassword.java:21)
at io.agroal.api.security.AgroalDefaultSecurityProvider.getSecurityProperties(AgroalDefaultSecurityProvider.java:23)
at io.agroal.pool.ConnectionFactory.securityProperties(ConnectionFactory.java:190)
at io.agroal.pool.ConnectionFactory.securityProperties(ConnectionFactory.java:179)
at io.agroal.pool.ConnectionFactory.jdbcProperties(ConnectionFactory.java:160)
at io.agroal.pool.ConnectionFactory.createConnection(ConnectionFactory.java:204)
at io.agroal.pool.ConnectionPool$CreateConnectionTask.call(ConnectionPool.java:470)
at io.agroal.pool.ConnectionPool$CreateConnectionTask.call(ConnectionPool.java:452)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at io.agroal.pool.util.PriorityScheduledExecutor.beforeExecute(PriorityScheduledExecutor.java:68)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1126)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at java.base/java.lang.Thread.run(Thread.java:829)

Notice that w/o Byteman everything that happens inside of Cipher.getInstance(Cipher.java:540) is lost.

@jaikiran
Copy link
Member

Thank you very much for that stacktrace. That's very useful. So here's the relevant one from your post:

org.jboss.byteman.agent.Transformer : possible trigger for rule JceSecurity exception exit in class javax.crypto.JceSecurity
RuleTriggerMethodAdapter.injectTriggerPoint : inserting trigger into javax.crypto.JceSecurity.() void for rule JceSecurity exception exit
org.jboss.byteman.agent.Transformer : inserted trigger for JceSecurity exception exit in class javax.crypto.JceSecurity
Rule.execute called for JceSecurity exception exit_3:0
HelperManager.install for helper class org.jboss.byteman.rule.helper.Helper
calling activated() for helper class org.jboss.byteman.rule.helper.Helper
Default helper activated
calling installed(JceSecurity exception exit) for helper classorg.jboss.byteman.rule.helper.Helper
Installed rule using default helper : JceSecurity exception exit
JceSecurity exception exit execute
*** JceSecurity failed with exceptionjavax.crypto.JceSecurity.(JceSecurity.java:246)
javax.crypto.Cipher.getInstance(Cipher.java:540)
com.bs.util.encryption.AESEncryptDecrypt.getInitializedCipher(AESEncryptDecrypt.java:151)
com.bs.util.encryption.AESEncryptDecrypt.decrypt(AESEncryptDecrypt.java:127)
com.bs.util.encryption.AESEncryptDecryptProxy.decrypt(AESEncryptDecryptProxy.java:44)
com.bs.util.DataSourceCredentialsProvider.getEmrCredentials(DataSourceCredentialsProvider.java:108)
com.bs.util.DataSourceCredentialsProvider$1.load(DataSourceCredentialsProvider.java:59)
com.bs.util.DataSourceCredentialsProvider$1.load(DataSourceCredentialsProvider.java:49)
com.google.common.cache.LocalCache$LoadingValueReference.loadFuture(LocalCache.java:3529)
com.google.common.cache.LocalCache$Segment.loadSync(LocalCache.java:2278)
com.google.common.cache.LocalCache$Segment.lockedGetOrLoad(LocalCache.java:2155)
com.google.common.cache.LocalCache$Segment.get(LocalCache.java:2045)
com.google.common.cache.LocalCache.get(LocalCache.java:3953)
com.google.common.cache.LocalCache.getOrLoad(LocalCache.java:3976)
com.google.common.cache.LocalCache$LocalLoadingCache.get(LocalCache.java:4960)
com.bs.util.DataSourceCredentialsProvider.getCredentials(DataSourceCredentialsProvider.java:82)
com.bs.util.DataSourceCredentialsProvider_ClientProxy.getCredentials(DataSourceCredentialsProvider_ClientProxy.zig:186)
io.quarkus.agroal.runtime.AgroalVaultCredentialsProviderPassword.asProperties(AgroalVaultCredentialsProviderPassword.java:21)
io.agroal.api.security.AgroalDefaultSecurityProvider.getSecurityProperties(AgroalDefaultSecurityProvider.java:23)
io.agroal.pool.ConnectionFactory.securityProperties(ConnectionFactory.java:190)
io.agroal.pool.ConnectionFactory.securityProperties(ConnectionFactory.java:179)
io.agroal.pool.ConnectionFactory.jdbcProperties(ConnectionFactory.java:160)
io.agroal.pool.ConnectionFactory.createConnection(ConnectionFactory.java:204)
io.agroal.pool.ConnectionPool$CreateConnectionTask.call(ConnectionPool.java:470)
io.agroal.pool.ConnectionPool$CreateConnectionTask.call(ConnectionPool.java:452)
java.util.concurrent.FutureTask.run(FutureTask.java:264)
io.agroal.pool.util.PriorityScheduledExecutor.beforeExecute(PriorityScheduledExecutor.java:68)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1126)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
java.lang.Thread.run(Thread.java:829)
java.util.ServiceConfigurationError: java.net.spi.URLStreamHandlerProvider: Provider org.infinispan.commons.jdkspecific.ClasspathURLStreamHandlerProvider not found
at java.base/java.util.ServiceLoader.fail(ServiceLoader.java:589)
at java.base/java.util.ServiceLoader$LazyClassPathLookupIterator.nextProviderClass(ServiceLoader.java:1212)
at java.base/java.util.ServiceLoader$LazyClassPathLookupIterator.hasNextService(ServiceLoader.java:1221)
at java.base/java.util.ServiceLoader$LazyClassPathLookupIterator.hasNext(ServiceLoader.java:1265)
at java.base/java.util.ServiceLoader$2.hasNext(ServiceLoader.java:1300)
at java.base/java.util.ServiceLoader$3.hasNext(ServiceLoader.java:1385)
at java.base/java.net.URL$1.getNext(URL.java:1314)
at java.base/java.net.URL$1.hasNext(URL.java:1329)
at java.base/java.net.URL$2.run(URL.java:1355)
at java.base/java.net.URL$2.run(URL.java:1352)
at java.base/java.security.AccessController.doPrivileged(Native Method)
at java.base/java.net.URL.lookupViaProviders(URL.java:1351)
at java.base/java.net.URL.getURLStreamHandler(URL.java:1437)
at java.base/java.net.URL.(URL.java:651)
at java.base/java.net.URL.(URL.java:541)
at java.base/java.net.URL.(URL.java:488)
at java.base/javax.crypto.JceSecurity.(JceSecurity.java:239)
at java.base/javax.crypto.Cipher.getInstance(Cipher.java:540)
at com.bs.util.encryption.AESEncryptDecrypt.getInitializedCipher(AESEncryptDecrypt.java:151)
at com.bs.util.encryption.AESEncryptDecrypt.decrypt(AESEncryptDecrypt.java:127)
at com.bs.util.encryption.AESEncryptDecryptProxy.decrypt(AESEncryptDecryptProxy.java:44)
at com.bs.util.DataSourceCredentialsProvider.getEmrCredentials(DataSourceCredentialsProvider.java:108)
at com.bs.util.DataSourceCredentialsProvider$1.load(DataSourceCredentialsProvider.java:59)
at com.bs.util.DataSourceCredentialsProvider$1.load(DataSourceCredentialsProvider.java:49)
at com.google.common.cache.LocalCache$LoadingValueReference.loadFuture(LocalCache.java:3529)
at com.google.common.cache.LocalCache$Segment.loadSync(LocalCache.java:2278)
at com.google.common.cache.LocalCache$Segment.lockedGetOrLoad(LocalCache.java:2155)
at com.google.common.cache.LocalCache$Segment.get(LocalCache.java:2045)
at com.google.common.cache.LocalCache.get(LocalCache.java:3953)
at com.google.common.cache.LocalCache.getOrLoad(LocalCache.java:3976)
at com.google.common.cache.LocalCache$LocalLoadingCache.get(LocalCache.java:4960)
at com.bs.util.DataSourceCredentialsProvider.getCredentials(DataSourceCredentialsProvider.java:82)
at com.bs.util.DataSourceCredentialsProvider_ClientProxy.getCredentials(DataSourceCredentialsProvider_ClientProxy.zig:186)
at io.quarkus.agroal.runtime.AgroalVaultCredentialsProviderPassword.asProperties(AgroalVaultCredentialsProviderPassword.java:21)
at io.agroal.api.security.AgroalDefaultSecurityProvider.getSecurityProperties(AgroalDefaultSecurityProvider.java:23)
at io.agroal.pool.ConnectionFactory.securityProperties(ConnectionFactory.java:190)
at io.agroal.pool.ConnectionFactory.securityProperties(ConnectionFactory.java:179)
at io.agroal.pool.ConnectionFactory.jdbcProperties(ConnectionFactory.java:160)
at io.agroal.pool.ConnectionFactory.createConnection(ConnectionFactory.java:204)
at io.agroal.pool.ConnectionPool$CreateConnectionTask.call(ConnectionPool.java:470)
at io.agroal.pool.ConnectionPool$CreateConnectionTask.call(ConnectionPool.java:452)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at io.agroal.pool.util.PriorityScheduledExecutor.beforeExecute(PriorityScheduledExecutor.java:68)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1126)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at java.base/java.lang.Thread.run(Thread.java:829)

There are at least 3 or 4 interesting points here:

  1. The call to a URL constructor is resulting into a java.lang.Error instead of an java.lang.Exception type. The javadoc of that constructor makes no mention of that. So this probably needs to be raised and discussed with the JDK team.

  2. A java.lang.Error that gets thrown from a static initialization block of a class doesn't seem to raise a ExceptionInInitializerError. Instead it just throws back the Error. This is unlike the case where an java.lang.Exception gets thrown from a static initialization block, where such exceptions are wrapped into ExceptionInInitializerError. I actually tried this again in that trivial Java code I pasted previously and threw an Error from Bar instead of an Exception and running it I see that it just throws the original Error and doesn't wrap it into a ExceptionInInitializerError. So that explains why the ExceptionInInitializerError byteman rule didn't get triggered in this flow. The javadoc of ExceptionInInitializerError makes no distinction between these 2 cases, so again this needs some inputs from the JDK team.

  3. Finally, the mysterious part that we have been trying to understand - who is eating this exception. From that stacktrace, it looks to me that the the Error, just "falls off" the thread. What I mean is, this looks like an "uncaught exception/error" that happens in a thread created by the io.agroal.pool.util.PriorityScheduledExecutor$PriorityExecutorThreadFactory and run by the io.agroal.pool.util.PriorityScheduledExecutor. This Error goes uncaught and the thread dies (as expected) and this error/exception never gets reported. Then certain other thread tries to use that JceSecurity class which has already failed in its class definition and thus runs into the NoClassDefFoundError. @stuartwdouglas, do you think we should add a UncaughtExceptionHandler to the Thread created in PriorityExecutorThreadFactory[1] and log any uncaught errors?

  4. The new mystery - Now if the previous Error isn't being reported/logged, then how come the NoClassDefFoundError which too is a Error type gets logged, from the exact same flow like this:

2021-08-26 08:38:41,374 ERROR [io.qua.run.Application] (main) Failed to start application (with profile prod): java.lang.NoClassDefFoundError: Could not initialize class javax.crypto.JceSecurity
at java.base/javax.crypto.Cipher.getInstance(Cipher.java:540)
at com.bs.util.encryption.AESEncryptDecrypt.getInitializedCipher(AESEncryptDecrypt.java:151)
...
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at io.agroal.pool.util.PriorityScheduledExecutor.beforeExecute(PriorityScheduledExecutor.java:68)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1126)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at java.base/java.lang.Thread.run(Thread.java:829)

Looking at the place where that log message is coming from, it's this catch block[2] in io.quarkus.runtime.ApplicationLifecycleManager. However that catch block is catching Exception type and not Error type. So it appears like there's some code somewhere which is catching, not all, but very specific Error types and wrapping them into an Exception and throwing it, in that flow. I'm not 100% certain about this. I don't remember seeing code which only deals with certain Error types and wraps them into Exception, in Quarkus. Unfortunately, that context is lost in that stacktrace, because we in that same catch block only log the rootCause[3] instead of the whole contextual stacktrace. @stuartwdouglas, do you think, in this else block (where we are done checking for specific root causes) we should log the whole exception stacktrace instead of just the root cause, to help in issues like these?

[1] https://github.com/agroal/agroal/blob/master/agroal-pool/src/main/java/io/agroal/pool/util/PriorityScheduledExecutor.java#L109
[2] https://github.com/quarkusio/quarkus/blob/main/core/runtime/src/main/java/io/quarkus/runtime/ApplicationLifecycleManager.java#L149
[3] https://github.com/quarkusio/quarkus/blob/main/core/runtime/src/main/java/io/quarkus/runtime/ApplicationLifecycleManager.java#L206

@stuartwdouglas
Copy link
Member

I have opened agroal/agroal#39

@jaikiran
Copy link
Member

The call to a URL constructor is resulting into a java.lang.Error instead of an java.lang.Exception type. The javadoc of that constructor makes no mention of that. So this probably needs to be raised and discussed with the JDK team.

I read up the docs in detail today and as per[2]:

If no URLStreamHandlerFactory has yet been set up, or if the factory's createURLStreamHandler method returns null, then the ServiceLoader mechanism is used to locate URLStreamHandlerProvider implementations using the system class loader. The order that providers are located is implementation specific, and an implementation is free to cache the located providers. A ServiceConfigurationError, Error or RuntimeException thrown from the createURLStreamHandler, if encountered, will be propagated to the calling thread

So that API is behaving fine as per what it states in its javadocs.

[2] https://docs.oracle.com/en/java/javase/11/docs/api/java.base/java/net/URL.html#%3Cinit%3E(java.lang.String,java.lang.String,int,java.lang.String)

@jaikiran
Copy link
Member

A java.lang.Error that gets thrown from a static initialization block of a class doesn't seem to raise a ExceptionInInitializerError. Instead it just throws back the Error. This is unlike the case where an java.lang.Exception gets thrown from a static initialization block, where such exceptions are wrapped into ExceptionInInitializerError. I actually tried this again in that trivial Java code I pasted previously and threw an Error from Bar instead of an Exception and running it I see that it just throws the original Error and doesn't wrap it into a ExceptionInInitializerError. So that explains why the ExceptionInInitializerError byteman rule didn't get triggered in this flow. The javadoc of ExceptionInInitializerError makes no distinction between these 2 cases, so again this needs some inputs from the JDK team.

I read up the JLS and section 12.4.2[1] states:

Otherwise, the initializers must have completed abruptly by throwing some exception E. If the class of E is not Error or one of its subclasses, then create a new instance of the class ExceptionInInitializerError, with E as the argument, and use this object in place of E in the following step

So the current behaviour is as per the spec, so there's no issue in this area.

I see that Stuart has opened a PR to fix agroal to log these exceptions that fall off the thread execution. So that should sort out the major part of this issue. The only final question is, should we improve the ApplicationLifeCycleManager to log the whole exception stacktrace instead of just the rootCause.

[1] https://docs.oracle.com/javase/specs/jls/se16/html/jls-12.html#jls-12.4.2

@geoand
Copy link
Contributor

geoand commented Sep 20, 2024

Is this still an issue?

@geoand geoand added the triage/needs-feedback We are waiting for feedback. label Sep 20, 2024
@geoand
Copy link
Contributor

geoand commented Oct 2, 2024

Closing for lack of feedback

@geoand geoand closed this as not planned Won't fix, can't repro, duplicate, stale Oct 2, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
area/security kind/bug Something isn't working triage/needs-feedback We are waiting for feedback.
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@jaikiran @stuartwdouglas @dhoffer @geoand