Unable to re-deploy rails app (java.lang.RuntimeException: BUG: could not initialize constructor handle) #4442
Comments
|
Weird. |
|
Ok, I've had a look at the code. This is failing inside ManyVarsDynamicScope where we attempt to create a MethodHandle for constructing instances of said scope. The handle is acquired in a static code block at boot and should only fail if security settings prevent acquisition of the needed constructor handle. I would expect this to fail every time if it fails at all. If it's failing only in the n+1 deployments, I'd suspect some classloading problem. Unfortunately I can't see what the original error was because we didn't log it (my mistake). I've pushed 9aad929 to remedy that. Are you able to try deploying with a jruby-head build so we can get a better error report? |
|
Thanks @headius, I have installed jruby-head + jruby-jars gem from latest GIT, and here is the detailed log: Seems to be a classloader problem… It happens when I deploy a second rails WAR, too. |
|
yay - yay - yay ... too much generated content for a re-boot :) ! |
|
Ok, so this looks like something wrong with classloading in your setup. You're getting two visible definitions of the StaticScope class, so when we try to capture a handle for ManyVarsDynamicScope's constructor it blows up. This may be a bug in JBoss or the JVM. I'll have a look at the code. @kares This is actually just trying to get a MethodHandle to ManyVarsDynamicScope's constructor, so it can be constructed programmatically along with all the generated ones. This isn't a failure in our code generation. |
|
@aldrinmartoq It seems like this could only be failing if you had JRuby (or some version of it) also in the app server classpath, rather than only in the war file. Can you investigate if that's the case? The error message claims that Object's classloader (the bootstrap classloader) sees a different version of the class than the webapp classloader, which should only be possible if JRuby is also being loaded at the bootstrap level. If you do not have JRuby in the app server's classpath, this may be a bug in method handle logic. |
|
I have the same problem. With jruby 9.1.5.0 I don't have this problem. Environment: jruby 9.1.7.0 (2.3.1) 2017-01-11 68056ae Java HotSpot(TM) 64-Bit Server VM 25.112-b15 on 1.8.0_112-b15 +jit [linux-x86_64] jboss/wildfly |
|
@headius I have checked, and there is no other JRuby jar in the classpath. Don't know how JBoss load that class with a bootstrap classloader. Here is my log: When I undeploy the war, there are no Unload entries in the log, and the server keep some JRuby jars open, for ex: But none of those jars has the StaticScope class. I'm still trying to debug what's wrong with JBoss with no luck. @thomasoberle I will check later if JRuby 9.1.5.0 works for me, thanks. |
|
@headius @thomasoberle I confirm I can re-deploy using JRuby 9.1.5.0 🤔 |
|
Hmm, I wonder if our recently-failing j2ee test suite is caused by the same problem. Any thoughts, @mkristian? |
|
@headius thoughts: it first sounds more like some regression between 9.1.5.0 and 9.1.7.0. secondly it is high time to make some time and get these j2ee test green again as they might have caught this problem. |
|
@mkristian I agree. |
|
@headius I have run
|
|
@aldrinmartoq believe its pretty much solid what is the cause ... whats not clear is why its happening |
|
@kares the last time I wanted to have a look why it is red I saw that even green tests produces stacktraces so at this time I decided to put it under 'allow-failures'. anyways it is on my TODO for this week ;) |
|
Same problem here. Except we have two tomcat instances, and it only does it on one of them...? |
|
@aldrinmartoq Interesting! I'll have a look and see if I can come up with a theory. |
|
@aldrinmartoq Yeah, the commits around that one don't seem likely to have caused this...so I find that bisect very confusing. Neither of the two commits you point out made any substantive changes to the code. The It still seems like there has to be another JRuby sneaking into some lower classloader, or one deployed application is leaking into the next. Perhaps you can run something like this against your JBoss instance and see what you find?
|
|
Is there any information I can provide that would help? Would it be better if I raised a seperate issue for my problem? The error message is basically the same, but under Tomcat, not JBoss. (Still trying to work out why we get the problem on one server but not the other here, but I'm not very hopeful...) |
|
News: On Tomcat, the problem only occurs if multiple war files on the Tomcat server are using jRuby. If you have only one, everything is fine. This is why we had one instance that worked and one that did not. Our .war files here are being built with Warbler and there is no mucking about with shared jars. So something is leaking? For the record, this is the error message I see (in /var/log/tomcat/localhost.yyyy.mm.dd.txt). It's almost identical to the one raised by the OP: |
|
By way of confirmation: I had the same error in wildfly 10.1.0 and jruby-jars 9.1.7.0. Reverting to jruby-jars 9.1.5.0 fixed the issue. Thanks for all your hard work |
|
@headius I've tried your suggestion and it seems the jars are not left over between deploys. Here is my reporte, please note that this same sequence works in jruby-9.1.5.0. # 1. Start server
$ ./standalone.sh
# 2. Check for existing jruby jars (nothing)
$ find . -name '*.jar' -exec jar tf {} \; | grep StaticScope
# 3. Install app (it works fine)
$ cp app.war /jboss-eap-7.0/standalone/deployments/
# 4. Check for existing jruby jars
$ find . -name '*.jar' -exec jar tf {} \; | grep StaticScope
./standalone/tmp/vfs/deployment/deployment5f68b1284b65427e/jruby-core-9.1.8.0-SNAPSHOT-complete.jar-55128f7dd075c566/jruby-core-9.1.8.0-SNAPSHOT-complete.jar
org/jruby/parser/StaticScope$Type.class
org/jruby/parser/StaticScope.class
org/jruby/parser/StaticScopeFactory.class
./standalone/tmp/vfs/temp/tempcdf486b6cf96f53b/content-89d4787060a19efb/WEB-INF/gems/gems/jruby-jars-9.1.8.0.SNAPSHOT/lib/jruby-core-9.1.8.0-SNAPSHOT-complete.jar
org/jruby/parser/StaticScope$Type.class
org/jruby/parser/StaticScope.class
org/jruby/parser/StaticScopeFactory.class
./standalone/tmp/vfs/temp/tempcdf486b6cf96f53b/content-89d4787060a19efb/WEB-INF/lib/jruby-core-9.1.8.0-SNAPSHOT-complete.jar
org/jruby/parser/StaticScope$Type.class
org/jruby/parser/StaticScope.class
org/jruby/parser/StaticScopeFactory.class
# 5. Remove app
$ rm -f /jboss-eap-7.0/standalone/deployments/app.war
# 6. Check for existing jruby jars (none)
$ find . -name '*.jar' -exec jar tf {} \; | grep StaticScope
# 7. Install app again (it will fail)
$ cp app.war /jboss-eap-7.0/standalone/deployments/
$ tail server.log
16:28:17,742 ERROR [org.jboss.msc.service.fail] (ServerService Thread Pool -- 85) MSC000001: Failed to start service jboss.undertow.deployment.default-server.default-host./gcu: org.jboss.msc.service.StartException in service jboss.undertow.deployment.default-server.default-host./gcu: java.lang.ExceptionInInitializerError
at org.wildfly.extension.undertow.deployment.UndertowDeploymentService$1.run(UndertowDeploymentService.java:85)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
at org.jboss.threads.JBossThread.run(JBossThread.java:320)
Caused by: java.lang.ExceptionInInitializerError
at org.jruby.runtime.ThreadContext.<init>(ThreadContext.java:214)
at org.jruby.runtime.ThreadContext.newContext(ThreadContext.java:85)
at org.jruby.internal.runtime.ThreadService.initMainThread(ThreadService.java:166)
at org.jruby.Ruby.init(Ruby.java:1164)
at org.jruby.Ruby.newInstance(Ruby.java:338)
at org.jruby.rack.DefaultRackApplicationFactory.newRuntime(DefaultRackApplicationFactory.java:337)
at org.jruby.rack.DefaultRackApplicationFactory$RackApplicationImpl.<init>(DefaultRackApplicationFactory.java:438)
at org.jruby.rack.DefaultRackApplicationFactory.createApplication(DefaultRackApplicationFactory.java:426)
at org.jruby.rack.DefaultRackApplicationFactory.newApplication(DefaultRackApplicationFactory.java:99)
at org.jruby.rack.DefaultRackApplicationFactory.getApplication(DefaultRackApplicationFactory.java:113)
at org.jruby.rack.SharedRackApplicationFactory.doInit(SharedRackApplicationFactory.java:34)
at org.jruby.rack.RackApplicationFactoryDecorator.init(RackApplicationFactoryDecorator.java:100)
at org.jruby.rack.RackServletContextListener.contextInitialized(RackServletContextListener.java:50)
at io.undertow.servlet.core.ApplicationListeners.contextInitialized(ApplicationListeners.java:187)
at io.undertow.servlet.core.DeploymentManagerImpl.deploy(DeploymentManagerImpl.java:198)
at org.wildfly.extension.undertow.deployment.UndertowDeploymentService.startContext(UndertowDeploymentService.java:100)
at org.wildfly.extension.undertow.deployment.UndertowDeploymentService$1.run(UndertowDeploymentService.java:82)
... 6 more
Caused by: java.lang.RuntimeException: BUG: could not initialize constructor handle
at org.jruby.runtime.scope.ManyVarsDynamicScope.<clinit>(ManyVarsDynamicScope.java:39)
... 23 more
Caused by: java.lang.IllegalAccessException: no such constructor: org.jruby.runtime.scope.ManyVarsDynamicScope.<init>(StaticScope,DynamicScope)void/newInvokeSpecial
at java.lang.invoke.MemberName.makeAccessException(MemberName.java:867)
at java.lang.invoke.MemberName$Factory.resolveOrFail(MemberName.java:1003)
at java.lang.invoke.MethodHandles$Lookup.resolveOrFail(MethodHandles.java:1386)
at java.lang.invoke.MethodHandles$Lookup.findConstructor(MethodHandles.java:924)
at org.jruby.runtime.scope.ManyVarsDynamicScope.<clinit>(ManyVarsDynamicScope.java:36)
... 23 more
Caused by: java.lang.LinkageError: loader constraint violation: when resolving method "org.jruby.runtime.scope.ManyVarsDynamicScope.<init>(Lorg/jruby/parser/StaticScope;Lorg/jruby/runtime/DynamicScope;)V" the class loader (instance of <bootloader>) of the current class, java/lang/Object, and the class loader (instance of org/jboss/modules/ModuleClassLoader) for the method's defining class, org/jruby/runtime/scope/ManyVarsDynamicScope, have different Class objects for the type org/jruby/parser/StaticScope used in the signature
at java.lang.invoke.MethodHandleNatives.resolve(Native Method)
at java.lang.invoke.MemberName$Factory.resolve(MemberName.java:975)
at java.lang.invoke.MemberName$Factory.resolveOrFail(MemberName.java:1000)
... 26 more
# 8. Check for existing jruby jars (please note the path is different)
$ find . -name '*.jar' -exec jar tf {} \; | grep StaticScope
./standalone/tmp/vfs/deployment/deployment5f68b1284b65427e/jruby-core-9.1.8.0-SNAPSHOT-complete.jar-9c14eaa135c5bf59/jruby-core-9.1.8.0-SNAPSHOT-complete.jar
org/jruby/parser/StaticScope$Type.class
org/jruby/parser/StaticScope.class
org/jruby/parser/StaticScopeFactory.class
./standalone/tmp/vfs/temp/tempcdf486b6cf96f53b/content-eb3c8b4bdb93aaa/WEB-INF/gems/gems/jruby-jars-9.1.8.0.SNAPSHOT/lib/jruby-core-9.1.8.0-SNAPSHOT-complete.jar
org/jruby/parser/StaticScope$Type.class
org/jruby/parser/StaticScope.class
org/jruby/parser/StaticScopeFactory.class
./standalone/tmp/vfs/temp/tempcdf486b6cf96f53b/content-eb3c8b4bdb93aaa/WEB-INF/lib/jruby-core-9.1.8.0-SNAPSHOT-complete.jar
org/jruby/parser/StaticScope$Type.class
org/jruby/parser/StaticScope.class
org/jruby/parser/StaticScopeFactory.class |
|
Get into the similar problem with JRuby [9.0.5.0, 9.1.5.0, 9.1.7.0] and Weblogic 12.
<Feb 21, 2017, 2:51:20,921 AM UTC> <Error> <Deployer> <BEA-149202> <Encountered an exception while attempting to commit the 9 task for the application "my_war" on [partition-name: DOMAIN].>
<Feb 21, 2017, 2:51:20,928 AM UTC> <Warning> <Deployer> <BEA-149004> <Failures were detected while initiating redeploy task for application "my_war".>
<Feb 21, 2017, 2:51:20,928 AM UTC> <Warning> <Deployer> <BEA-149078> <Stack trace for message 149004
weblogic.application.ModuleException: java.lang.RuntimeException: BUG: could not initialize constructor handle
at weblogic.application.internal.ExtensibleModuleWrapper.start(ExtensibleModuleWrapper.java:140)
at weblogic.application.internal.flow.ModuleListenerInvoker.start(ModuleListenerInvoker.java:124)
at weblogic.application.internal.flow.ModuleStateDriver$3.next(ModuleStateDriver.java:233)
at weblogic.application.internal.flow.ModuleStateDriver$3.next(ModuleStateDriver.java:228)
at weblogic.application.utils.StateMachineDriver.nextState(StateMachineDriver.java:45)
Truncated. see log file for complete stacktrace
Caused By: java.lang.RuntimeException: BUG: could not initialize constructor handle
at org.jruby.runtime.scope.ManyVarsDynamicScope.<clinit>(ManyVarsDynamicScope.java:39)
at org.jruby.runtime.ThreadContext.<init>(ThreadContext.java:214)
at org.jruby.runtime.ThreadContext.newContext(ThreadContext.java:85)
at org.jruby.internal.runtime.ThreadService.initMainThread(ThreadService.java:166)
at org.jruby.Ruby.init(Ruby.java:1161)
Truncated. see log file for complete stacktrace |
|
@mskutin You are seeing this happen with 9.0.5.0 and 9.1.5.0 as well as later releases? That doesn't seem to fit other folks saying that 9.1.5.0 works ok. @mwarnock @aldrinmartoq Ok. We need a way to reproduce this. I'm very confused where the duplicate class is coming from. So a few suggestions:
Given that it doesn't look like there's a duplicate coming in from the filesystem or system-level classloader, my current theory is something unusual happening with JBoss classloading. Another possibility is that a thread context classloader is getting shared across deploys and causing the same classes to conflict with each other. @bbrowning This isn't Torquebox, but do you have any ideas here? You've worked at this level of JBoss/WildFly more than me. |
|
@headius Hey, I forgot to write that |
|
Is this related to #4312 ? The same exception appears in both cases. |
|
Rails dummy app to reproduce Instruction in README.md create the war file: install a wildfly 10.1 / startup parameters JBOSS_HOME="{path}/wildfly" JBOSS_LOG_FILE="${JBOSS_HOME}/standalone/log/jboss_startup.log" SHORT_DATE=$(date +"%Y%m%d%H%M") to Reproduce the error: Unable to re-deploy rails app (java.lang.RuntimeException: BUG: could not initialize constructor handle) #4442 Deploy the app and replace or remove the app and deploy again |
|
I believe @k77ch7 is right that this is fixed by #4312, and I have merged that for JRuby 9.1.8.0. In #4312, @shirosaki discovered (and I have reproduced) a separate issue with jnr-ffi segfaulting in its finalizer. I will investigate that now. |
|
Thanks guys! Sorry to be entirely unhelpful, I've been sick the last 4 days. |
|
Thank you guys a bunch! For the record: This fixed our issue described in this SO post. |
Environment
Expected Behavior
We need to reinstall a rails application without restarting the JBoss application server.
Actual Behavior
We are trying to redeploy our rails app into a JBoss Server (
rm -f jboss-eap-7.0/standalone/deployments/prueba.war; cp -f prueba.war jboss-eap-7.0/standalone/deployments/), but it fails with an exception. If we restart JBoss, the application runs fine.We can reproduce the error with the following:
Here is the error log:
The text was updated successfully, but these errors were encountered: