Apache Felix Framework class loading failures #3450

goatshriek · 2021-09-25T18:34:33Z

Describe the bug
A plugin built for Ghidra 10.0.3 is failing in some aspects of its functionality, raising exceptions that library classes cannot be found. This occurs under JDK 16, but not JDK 11. These classes are present in one of the jars included with the plugin, and this same plugin functions without issue when built for/installed in 10.0.2. Here is the error that appears:

NameError: cannot load Java class org.jruby.ext.readline.Readline
      load_ext at org/jruby/ext/jruby/JRubyUtilLibrary.java:201
        <main> at uri:classloader:/META-INF/jruby.home/lib/ruby/stdlib/readline.rb:9
       require at org/jruby/RubyKernel.java:974
       require at uri:classloader:/META-INF/jruby.home/lib/ruby/stdlib/rubygems/core_ext/kernel_require.rb:83
  <module:IRB> at uri:classloader:/META-INF/jruby.home/lib/ruby/stdlib/irb/input-method.rb:130
        <main> at uri:classloader:/META-INF/jruby.home/lib/ruby/stdlib/irb/input-method.rb:15
       require at org/jruby/RubyKernel.java:974
       require at uri:classloader:/META-INF/jruby.home/lib/ruby/stdlib/rubygems/core_ext/kernel_require.rb:83
        <main> at uri:classloader:/META-INF/jruby.home/lib/ruby/stdlib/irb.rb:19
       require at org/jruby/RubyKernel.java:974
       require at uri:classloader:/META-INF/jruby.home/lib/ruby/stdlib/rubygems/core_ext/kernel_require.rb:83
        <main> at <script>:1

I found that error mostly unhelpful, and after reverting to the 10.0.2 launch.properties (which fixes it) I captured this more relevant illegal access warning that reveals the culprit as the felix framework included within Ghidra:

WARNING: An illegal reflective access operation has occurred
WARNING: Illegal reflective access by org.apache.felix.framework.ext.ClassPathExtenderFactory$DefaultClassLoaderExtender (file:/C:/Users/reall/code/ghidra/ghidra_10.0.3_PUBLIC/Ghidra/Features/Base/lib/org.apache.felix.framework-6.0.3.jar) to method java.net.URLClassLoader.addURL(java.net.URL)
WARNING: Please consider reporting this to the maintainers of org.apache.felix.framework.ext.ClassPathExtenderFactory$DefaultClassLoaderExtender
WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
WARNING: All illegal access operations will be denied in a future release

This led me to the changes I submitted in a pull request which add --add-opens statements for each illegal access I ended up encountering. These line up nicely with those listed on the Apache Felix Jira project about this problem. Other Ghidra plugins might be affected by this as well, but I haven't been able to find any existing issues that mention it.

To Reproduce
I don't know of a way to trigger this without a plugin. That doesn't mean there isn't one, I just haven't looked very hard for it. To reproduce the specific instance of the issue that I see, you would need to download the plugin build for 10.0.3 and try to open an interactive Ruby scripting window.

Download and install the RubyDragon 1.0.0 build for Ghidra 10.0.3 from the project's release page.
Open Ghidra with a project.
Open a file from the project in the CodeBrowser tool.
Configure the CodeBrowser tool to enable the RubyDragon plugin. Whether or not ClojureDragon is enabled does not appear to make a difference.
Open the Ruby window via Window->Ruby.
You will be greeted with an error. The thread of execution for that window of course is gone at this point, rendering it unusable. The rest of Ghidra appears to be unaffected.

Expected behavior
I would expect Ghidra to be able to find classes that are in the lib jars, of course! Really though, I'm just looking for a resolution that doesn't involve manually modifying launch.properties every time someone wants to use this plugin in newer JDK environments. I briefly played with the classloaders used in my plugin, but I wasn't successful in resolving it with that technique.

Environment

OS: Windows 10.0.19043, Debian 11.0 (kernel 5.10.0-8)
Java Version: problem occurs with Adopt OpenJDK 16.0.1, problem does not occur with Adopt OpenJDK 11.0.11
Ghidra Version: 10.0.3
Ghidra Origin: Downloaded from the github releases page

Additional context
The Felix page linked above says that this is fixed in 7.0.0. I didn't try that out as a fix, but just wanted to mention it as an alternate path to my proposed patch.

I do realize that JDK 11 is the supported version of Ghidra and not 16 where the error happens. But I think this is still worth at least reporting and proposing a patch for, given that it was previously working until the recent "illegal reflective access" changes. Fixing this also seems inline with the changes from #3355 currently pinned on the issue list. At a minimum, perhaps it will at least help others with the same issue.

The text was updated successfully, but these errors were encountered:

ryanmkurtz · 2021-09-27T11:21:20Z

I am going to try to upgrade Felix the latest 7.x version which should address this issue.

mumbel · 2021-10-08T02:07:22Z

@ryanmkurtz looking like this broke my build, cannot open browser only front end. I removed my eclipse workspace and tried a fresh one along with redoing the gradle commands (init/prepDev/eclipse). Cannot say 100% its not some env issue on my end (20.04 / 11.0.11), but nothing looks different. Among the stack traces the only string I saw was felix (91f94b8 works)

2021-10-07 20:50:28 ERROR (GhidraScriptUtil) Failed to initialize BundleHost ghidra.app.plugin.core.osgi.OSGiException: initializing felix OSGi framework
        at ghidra.app.plugin.core.osgi.BundleHost.startFramework(BundleHost.java:471)
        at ghidra.app.script.GhidraScriptUtil.setBundleHost(GhidraScriptUtil.java:78)
        at ghidra.app.script.GhidraScriptUtil.initialize(GhidraScriptUtil.java:93)
        at ghidra.app.script.GhidraScriptUtil.acquireBundleHostReference(GhidraScriptUtil.java:411)
        at ghidra.app.plugin.core.script.GhidraScriptMgrPlugin.<init>(GhidraScriptMgrPlugin.java:65)
        at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
        at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
        at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
        at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:490)
        at ghidra.framework.plugintool.util.PluginUtils.instantiatePlugin(PluginUtils.java:184)
        at ghidra.framework.plugintool.PluginManager.addPlugins(PluginManager.java:100)
        at ghidra.framework.plugintool.PluginManager.restorePluginsFromXml(PluginManager.java:271)
        at ghidra.framework.plugintool.PluginTool.restoreFromXml(PluginTool.java:561)
        at ghidra.framework.plugintool.PluginTool.<init>(PluginTool.java:138)
        at ghidra.framework.project.tool.GhidraTool.<init>(GhidraTool.java:81)
        at ghidra.framework.project.tool.GhidraToolTemplate.createTool(GhidraToolTemplate.java:215)
        at ghidra.framework.project.tool.ToolManagerImpl.getTool(ToolManagerImpl.java:661)
        at ghidra.framework.project.tool.WorkspaceImpl.runTool(WorkspaceImpl.java:77)
        at ghidra.framework.main.ToolButton$2.end(ToolButton.java:624)
        at ghidra.framework.main.ZoomImageRunner$1.end(ZoomImageRunner.java:54)
        at org.jdesktop.animation.timing.Animator.end(Animator.java:755)
        at org.jdesktop.animation.timing.Animator.stop(Animator.java:660)
        at org.jdesktop.animation.timing.Animator.timingEvent(Animator.java:732)
        at org.jdesktop.animation.timing.Animator.access$200(Animator.java:75)
        at org.jdesktop.animation.timing.Animator$TimerTarget.actionPerformed(Animator.java:1041)
        at java.desktop/javax.swing.Timer.fireActionPerformed(Timer.java:317)
        at java.desktop/javax.swing.Timer$DoPostEvent.run(Timer.java:249)
        at java.desktop/java.awt.event.InvocationEvent.dispatch(InvocationEvent.java:313)
        at java.desktop/java.awt.EventQueue.dispatchEventImpl(EventQueue.java:770)
        at java.desktop/java.awt.EventQueue$4.run(EventQueue.java:721)
        at java.desktop/java.awt.EventQueue$4.run(EventQueue.java:715)
        at java.base/java.security.AccessController.doPrivileged(Native Method)
        at java.base/java.security.ProtectionDomain$JavaSecurityAccessImpl.doIntersectionPrivilege(ProtectionDomain.java:85)
        at java.desktop/java.awt.EventQueue.dispatchEvent(EventQueue.java:740)
        at java.desktop/java.awt.EventDispatchThread.pumpOneEventForFilters(EventDispatchThread.java:203)
        at java.desktop/java.awt.EventDispatchThread.pumpEventsForFilter(EventDispatchThread.java:124)
        at java.desktop/java.awt.EventDispatchThread.pumpEventsForHierarchy(EventDispatchThread.java:113)
        at java.desktop/java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:109)
        at java.desktop/java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:101)
        at java.desktop/java.awt.EventDispatchThread.run(EventDispatchThread.java:90)
Caused by: org.osgi.framework.BundleException: Activator stop error in bundle org.apache.felix.framework [0].
        at org.apache.felix.framework.Felix.stopBundle(Felix.java:2878)
        at org.apache.felix.framework.Felix.init(Felix.java:969)
        at org.apache.felix.framework.Felix.init(Felix.java:648)
        at ghidra.app.plugin.core.osgi.BundleHost.startFramework(BundleHost.java:468)
        ... 39 more
Caused by: java.lang.NullPointerException
        at org.apache.felix.framework.Felix$SystemBundleActivator.stop(Felix.java:5284)
        at org.apache.felix.framework.util.SecureAction.stopActivator(SecureAction.java:871)
        at org.apache.felix.framework.Felix.stopBundle(Felix.java:2822)
        ... 42 more

ryanmkurtz · 2021-10-08T11:22:56Z

This is the second report of this but I am having trouble reproducing it. I'll keep trying.

xiaoyinl · 2021-10-09T14:36:40Z

@ryanmkurtz I got a similar exception when I open CodeBrowser or Debugger. The stack trace is:

java.lang.NullPointerException
	at ghidra.app.plugin.core.osgi.BundleHost.getOSGiBundle(BundleHost.java:526)
	at ghidra.app.plugin.core.osgi.GhidraBundle.getOSGiBundle(GhidraBundle.java:172)
	at ghidra.app.plugin.core.osgi.GhidraBundle.isActive(GhidraBundle.java:179)
	at ghidra.app.plugin.core.osgi.BundleHost.saveManagedBundleState(BundleHost.java:887)
	at ghidra.app.plugin.core.script.GhidraScriptComponentProvider.writeConfigState(GhidraScriptComponentProvider.java:290)
	at ghidra.app.plugin.core.script.GhidraScriptMgrPlugin.writeConfigState(GhidraScriptMgrPlugin.java:87)
	at ghidra.framework.plugintool.PluginManager.saveToXml(PluginManager.java:252)
	at ghidra.framework.plugintool.PluginTool.saveToXml(PluginTool.java:580)
	at ghidra.framework.project.tool.GhidraTool.getToolTemplate(GhidraTool.java:118)
	at ghidra.framework.main.RunningToolsPanel.addTool(RunningToolsPanel.java:81)
	at ghidra.framework.main.WorkspacePanel.addTool(WorkspacePanel.java:255)
	at ghidra.framework.main.WorkspacePanel.toolAdded(WorkspacePanel.java:101)
	at ghidra.framework.project.tool.ToolManagerImpl.fireToolAddedEvent(ToolManagerImpl.java:719)
	at ghidra.framework.project.tool.WorkspaceImpl.runTool(WorkspaceImpl.java:89)
	at ghidra.framework.main.ToolButton$2.end(ToolButton.java:624)
	at ghidra.framework.main.ZoomImageRunner$1.end(ZoomImageRunner.java:54)
	at org.jdesktop.animation.timing.Animator.end(Animator.java:755)
	at org.jdesktop.animation.timing.Animator.stop(Animator.java:660)
	at org.jdesktop.animation.timing.Animator.timingEvent(Animator.java:732)
	at org.jdesktop.animation.timing.Animator.access$200(Animator.java:75)
	at org.jdesktop.animation.timing.Animator$TimerTarget.actionPerformed(Animator.java:1041)
	at java.desktop/javax.swing.Timer.fireActionPerformed(Timer.java:317)
	at java.desktop/javax.swing.Timer$DoPostEvent.run(Timer.java:249)
	at java.desktop/java.awt.event.InvocationEvent.dispatch(InvocationEvent.java:313)
	at java.desktop/java.awt.EventQueue.dispatchEventImpl(EventQueue.java:770)
	at java.desktop/java.awt.EventQueue$4.run(EventQueue.java:721)
	at java.desktop/java.awt.EventQueue$4.run(EventQueue.java:715)
	at java.base/java.security.AccessController.doPrivileged(Native Method)
	at java.base/java.security.ProtectionDomain$JavaSecurityAccessImpl.doIntersectionPrivilege(ProtectionDomain.java:85)
	at java.desktop/java.awt.EventQueue.dispatchEvent(EventQueue.java:740)
	at java.desktop/java.awt.EventDispatchThread.pumpOneEventForFilters(EventDispatchThread.java:203)
	at java.desktop/java.awt.EventDispatchThread.pumpEventsForFilter(EventDispatchThread.java:124)
	at java.desktop/java.awt.EventDispatchThread.pumpEventsForHierarchy(EventDispatchThread.java:113)
	at java.desktop/java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:109)
	at java.desktop/java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:101)
	at java.desktop/java.awt.EventDispatchThread.run(EventDispatchThread.java:90)

---------------------------------------------------
Build Date: 2021-Oct-08 0447 EDT
Ghidra Version: 10.1
Java Home: /usr/lib/jvm/java-11-openjdk-amd64
JVM Version: Debian 11.0.12
OS: Linux 5.10.0-kali9-amd64 amd64
Workstation: kali

Ghidra version: locally built (master, 0aff588)

ryanmkurtz · 2021-10-09T23:28:49Z

Thanks. I'll likely roll back to the older version on Monday until I can figure out what is going wrong.

ryanmkurtz · 2021-10-12T15:06:48Z

@mumbel @xiaoyinl, when you did your gradle commands, did you have any old eclipse projects layout around? Are you able to easily produce a build using gradle buildGhidra? If you do, and run your build against your same Ghidra project, does the error still happen?

xiaoyinl · 2021-10-12T16:05:05Z

@ryanmkurtz I don't have any eclipse projects. Yes, the error still happens. This is what I did:

build Ghidra with gradle buildGhidra (master 0aff588, gradle 7.2)
delete ~/.ghidra folder (This step doesn't matter. The same error occurs with or without my old .ghidra folder)
Run Ghidra. Create a new non-shared project (or use an existing project). Open CodeBrowser. An uncaught exception occurred.

Here is the log:
application.log

ryanmkurtz · 2021-10-12T17:14:19Z

It's looking like a classpath ordering issue with the jars. I've reverted the change locally, which will soon be mirrored up to GitHub. I'll re-close this issue when I have the proper solution in place.

ryanmkurtz · 2021-10-12T19:53:05Z

@jpleasu Did you run into issues with felix and bndlib both including the same org.osgi.framework package/classes? It seems there is an incompatibility if bndlib gets onto the classpath before felix does because of this.

jpleasu · 2021-10-12T20:58:59Z

Sorry, that doesn't sound familiar.

mumbel · 2021-10-13T01:38:58Z

dont know if this is a side effect of moving around so many things/red herring/bad setup... or if you saw similar @ryanmkurtz and this is what you were talking about

on felixFramework.init(); I get an exception

ERROR: Unable to start system bundle.
java.lang.NoSuchMethodError: 'java.util.Dictionary org.osgi.framework.FrameworkUtil.asDictionary(java.util.Map)'
	at org.apache.felix.framework.Felix$SystemBundleActivator.start(Felix.java:5166)

which gets caught, so this never happens

ghidra/Ghidra/Features/Base/src/main/java/ghidra/app/plugin/core/osgi/BundleHost.java

Line 473 in 95aa622

frameworkBundleContext = felixFramework.getBundleContext();

which mostly results in this getting spammed as exception popups in code browser (i think at least, get ~24 errors)

ghidra/Ghidra/Features/Base/src/main/java/ghidra/app/plugin/core/osgi/BundleHost.java

Line 526 in 95aa622

return frameworkBundleContext.getBundle(bundleLocation);

ryanmkurtz · 2021-10-13T11:04:40Z

I saw that behavior too. It happens when biz.aQute.bndlib-5.1.2.jar comes before org.apache.felix.framework-7.0.1.jar on the classpath. They both have org.osgi.framework.FrameworkUtil, and when felix goes to call into its version, it ends up calling into bndlib's, which is incompatible with felix 7.x. Upgrading bndlib to the latest didn't fix the compatibility, so I have to do some more research into how to get those 2 things to play nicely together.

Having to rely on a certain classpath ordering should be avoided at all costs. Having said that, I couldn't reproduce this at first because my classpath was ordered differently. We should put some more work into having a deterministic classpath to at least make problems like this more consistent.

ryanmkurtz · 2022-04-04T16:18:09Z

This classpath issue was fixed in biz.aQute.bndlib-6.1.0.jar (release notes). I am going to continue trying to get this upgrade working.

ryanmkurtz · 2022-04-05T16:05:30Z

@jpleasu, do you think it's feasible to drop the bndlib dependency from Ghidra? Is it simply creating a manifest file? If so, can that be done "by hand?" I ask because the latest version of bndlib has been made compatible with the latest version of felix by breaking out all of its OSGI jar dependencies, requiring Ghidra to depend on many new jars.

jpleasu · 2022-04-05T16:32:06Z

Yeah - bndLib is really making an OSGi bundle of a script directory - the manifest being the configuration file for a bundle.

You could probably cover most script directories with a simpler manifest generator? Fallback to an external call to bnd might work?

ryanmkurtz · 2022-04-05T17:51:12Z

Thanks for feedback. Yes, I'll experiment with a simpler manifest generator.

ryanmkurtz · 2022-04-07T14:46:28Z

Thanks for feedback. Yes, I'll experiment with a simpler manifest generator.

The experiment has failed. I just upgraded the minimal set of needed jars.

This was referenced Sep 25, 2021

allow reflective access by apache felix #3451

Closed

interactive Ruby interpreter broken in Ghidra 10.0.3 goatshriek/ruby-dragon#9

Closed

ryanmkurtz self-assigned this Sep 27, 2021

ryanmkurtz added this to the 10.1 milestone Oct 7, 2021

ryanmkurtz closed this as completed in fdd73e2 Oct 7, 2021

ryanmkurtz reopened this Oct 12, 2021

ryanmkurtz removed this from the 10.1 milestone Oct 12, 2021

ryanmkurtz added this to the 10.2 milestone Apr 7, 2022

ryanmkurtz closed this as completed in 18defd6 Apr 7, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Apache Felix Framework class loading failures #3450

Apache Felix Framework class loading failures #3450

goatshriek commented Sep 25, 2021

ryanmkurtz commented Sep 27, 2021 •

edited

mumbel commented Oct 8, 2021 •

edited

ryanmkurtz commented Oct 8, 2021

xiaoyinl commented Oct 9, 2021

ryanmkurtz commented Oct 9, 2021

ryanmkurtz commented Oct 12, 2021

xiaoyinl commented Oct 12, 2021

ryanmkurtz commented Oct 12, 2021 •

edited

ryanmkurtz commented Oct 12, 2021

jpleasu commented Oct 12, 2021

mumbel commented Oct 13, 2021

ryanmkurtz commented Oct 13, 2021 •

edited

ryanmkurtz commented Apr 4, 2022

ryanmkurtz commented Apr 5, 2022

jpleasu commented Apr 5, 2022

ryanmkurtz commented Apr 5, 2022

ryanmkurtz commented Apr 7, 2022

Apache Felix Framework class loading failures #3450

Apache Felix Framework class loading failures #3450

Comments

goatshriek commented Sep 25, 2021

ryanmkurtz commented Sep 27, 2021 • edited

mumbel commented Oct 8, 2021 • edited

ryanmkurtz commented Oct 8, 2021

xiaoyinl commented Oct 9, 2021

ryanmkurtz commented Oct 9, 2021

ryanmkurtz commented Oct 12, 2021

xiaoyinl commented Oct 12, 2021

ryanmkurtz commented Oct 12, 2021 • edited

ryanmkurtz commented Oct 12, 2021

jpleasu commented Oct 12, 2021

mumbel commented Oct 13, 2021

ryanmkurtz commented Oct 13, 2021 • edited

ryanmkurtz commented Apr 4, 2022

ryanmkurtz commented Apr 5, 2022

jpleasu commented Apr 5, 2022

ryanmkurtz commented Apr 5, 2022

ryanmkurtz commented Apr 7, 2022

ryanmkurtz commented Sep 27, 2021 •

edited

mumbel commented Oct 8, 2021 •

edited

ryanmkurtz commented Oct 12, 2021 •

edited

ryanmkurtz commented Oct 13, 2021 •

edited