Community
Participate
Working Groups
I occasionally(!) get a strange NullPointerException in java.util.zip.Inflator.ensureOpen when i try to open a stream to a bundleentry. I retrieve the URLs via bundle.findEntries(...). Currently the exception is only reproduceable if the bundle is exported as jar. Here comes the method which produces the exception: The exception-line is: InputStream entryIS = entry.openStream(); ------- private void writeBundle(NodeDesc nd, OutputStream outputStream, BundleContext context) { ZipOutputStream zos = new ZipOutputStream(outputStream); Enumeration bundleEntries = context.getBundle().findEntries("/jarcontent", "*", true); try { byte[] copyBuf = new byte[512]; while(bundleEntries.hasMoreElements()) { java.net.URL entry = (java.net.URL)bundleEntries.nextElement(); InputStream entryIS = entry.openStream(); //THIS LINE PRODUCE THE EXCEPTION [... the method copy the entries from entryIS to the zipoutputstream- but this code is not reached if the exceptionoccurs ...] } catch (IOException e) { e.printStackTrace(); } } ------- (The method searches all files in /jarcontent which contain template files for a dynamically created bundle. Then it iterates the entries, modifys them if needed, and copy them into the new jar.) The interesting part is that the exception only occours occasionally. But after the start of the osgi framework i can (nearly) always reproduce it for 1 time. If i trigger the method again, no execption occurs. I also get this exception in 2 other bundles which contain war files for a webapp container. Tested with JDKs: + 1.5.0_10-b03 + 1.6.0-b105 Here the Exception: java.lang.NullPointerException at java.util.zip.Inflater.ensureOpen(Inflater.java:325) at java.util.zip.Inflater.reset(Inflater.java:294) at java.util.zip.ZipFile.getInflater(ZipFile.java:372) at java.util.zip.ZipFile.getInputStream(ZipFile.java:320) at java.util.zip.ZipFile.getInputStream(ZipFile.java:286) at org.eclipse.osgi.baseadaptor.bundlefile.ZipBundleEntry.getInputStream(ZipBundleEntry.java:51) at org.eclipse.osgi.framework.internal.core.BundleURLConnection.connect(BundleURLConnection.java:53) at org.eclipse.osgi.framework.internal.core.BundleURLConnection.getInputStream(BundleURLConnection.java:99) at java.net.URL.openStream(URL.java:1007) at com.v8tech.mmc.adminsupport.newwizard.AdminPluginGeneratorServlet.writeBundle(AdminPluginGeneratorServlet.java:79) at com.v8tech.mmc.adminsupport.newwizard.AdminPluginGeneratorServlet.process(AdminPluginGeneratorServlet.java:55)
Is the configuration setting osgi.bundlefile.limit set? I think this can happen if the zipfile is closed while you are reading from it. That may happen if the osgi.bundlefile.limit is set to low and we are thrashing the zip open/close operations. Or are is the bundle being uninstalled while you are reading from it? That would close the zipfile also.
No, osgi.bundlefile.limit is not set. I´ve set it to 1000 to test, but there is no difference (I set it with -Dosgi... - hope this is correct). The bundle is also not being uninstalled. Currently my test procedure is the following: + Export my project as feature of my server + Start the osgi framework + Make the first request in the browser => Exception + Make the second request in the browser => No exception + ... all following invokations return the correct result. If i make the first request with the browser, the exception occurs. On the second request the data is created correctly. (In reply to comment #1) > Is the configuration setting osgi.bundlefile.limit set? I think this can > happen if the zipfile is closed while you are reading from it. That may happen > if the osgi.bundlefile.limit is set to low and we are thrashing the zip > open/close operations. > > Or are is the bundle being uninstalled while you are reading from it? That > would close the zipfile also. >
How many bundles do you have in your target? Do you reproduce when launching from PDE or only when launching externally as a built product. Can you attach a test bundle with a set of steps to reproduce. If osgi.bundlefile.limit is not set then I do not know what is going on. It appears that someone is closing the zipfile but nothing should do that unless a bundle is uninstalled or a refresh packages is occurring. Do you see anything in your log file when this occurs? Please attach the log if so. Thanks.
I´ve only tested after i exported the application. I´ve never launched the app within the PDE. After a few other tests i was also able to reproduce the problem within the knopflerfish framework. Maybe my code causes the bug but as you can see, its very trivial. Currently it looks like that the exception does only occur if: + The bundle is exported as jar + The URL to a bundleentry must be retrieved via Bundle.findEntries(...) or Bundle.getEntry(...). + The thread invoking url.openConnection is NOT the osgi-thread which invokes the life-cycle methods start() or stop() of the BundleActivator. In my case, its a thread from the webserver. If i try to access the data within this thread, it works in all cases. (And no - my bundle is not stopped before the other thread tries to access the data :-)) Another interesting point is that the exception only occurs on the first request of url.openConnection(). On the second request, the entry is returned correctly. I´ll do further investigations and I´ll try to create a setup with which you can reproduce the bug.
You mention multiple threads. Is one of the threads installing the bundles for the first time? or does this happen from a cached install when accessing the bundle data for the first time in an instance of the framework?
The exception occurs regardless of weather it´s a cached launch or not. (Deleting all in datadir except config.ini). The thread accessing the bundle content has nothing to do with the deployment of the bundle. The bundle is deployed via the osgi.bundles property in config.ini. After the full framework launch I use a browser to do a request on the servlet which uses Activator.getInstance().getBundleContext() and tries to retrieve bundledata. Then the exception occurs (The first time). The second request (hitting F5 to the browser) is ok. Also the time between the startup of the framework and the request with the browser has no effect on the bug.
Any chance you could attach an example we can use to reproduce? Also is this only reproduced on Linux or does it happen on other OS's
I have seen the same exception under similar circumstances. A web server thread is trying to load a resource through Bundle.getResource(). In my case it occurs on Linux and Windows. I have not yet been able to produce a small test case.
I can reproduce this exception 100% of the time on Windows using Java 6 JDK (update 3). I am trying to integrate OSGi, Jetty 6.1.6, and Glassfish JSP compiler as an embedded web server in a desktop application. I am trying to package the web resources in an OSGi bundle. Jetty is able to serve static content from the bundle just fine, but when I try to access a JSP file, one or more of the resources will result in this NullPointerException. This is obviously not a small test case, as it requires more than a dozen bundles. I have instrumented org.eclipse.osgi.baseadaptor.bundlefile.ZipBundleFile and org.eclipse.osgi.baseadaptor.bundlefile.ZipBundleEntry in a local version of the OSGi core. I am catching the NPE in ZipBundleEntry and dumping the state of the MRU Zip Bundle File cache: Caught Exeption: java.lang.NullPointerException ZIP Entry: web/WEB-INF/lib/jstl-1.1.1.jar Bundle File: ZipBundleFile [H:\...\milo.web_1.0.0.jar ] 103 MRU Bundle File List: 14 open files out of 100 INDEX MRU BUNDLE ----- ----- ----------------------------------------------------- 0: 675 - ZipBundleFile [H:\...\org.eclipse.osgi_3.4.0.milo.jar ] 551 1: 694 - ZipBundleFile [H:\...\milo.shell_1.0.0.jar ] 159 2: 1857 - ZipBundleFile [H:\...\milo.web_1.0.0.jar ] 103 3: 1053 - ZipBundleFile [H:\...\milo.net_1.0.0.jar ] 182 4: 1651 - ZipBundleFile [H:\...\org.getahead.dwr_2.0.1.jar ] 362 5: 1767 - ZipBundleFile [H:\...\org.mortbay.jetty_6.1.6.jar ] 246 6: 1765 - ZipBundleFile [H:\...\org.mortbay.jetty.util_6.1.6.jar ] 97 7: 1695 - ZipBundleFile [H:\...\javax.servlet_2.5.0.jar ] 78 8: 950 - ZipBundleFile [H:\...\milo.platform_1.0.0.jar ] 29 9: 677 - ZipBundleFile [H:\...\milo.parser_1.0.0.jar ] 24 10: 1849 - ZipBundleFile [H:\...\org.mortbay.jetty.jsp_6.1.6.jar ] 2759 11: 684 - ZipBundleFile [H:\...\org.apache.commons_1.0.0.jar ] 585 12: 792 - ZipBundleFile [H:\...\org.apache.log4j_1.0.0.jar ] 274 13: 686 - ZipBundleFile [H:\...\org.apache.xerces_2.8.0.jar ] 1323 java.lang.NullPointerException at java.util.zip.Inflater.ensureOpen(Unknown Source) at java.util.zip.Inflater.reset(Unknown Source) at java.util.zip.ZipFile.getInflater(Unknown Source) at java.util.zip.ZipFile.getInputStream(Unknown Source) at java.util.zip.ZipFile.getInputStream(Unknown Source) (etc.) In the above printout, the number at the end of each line indicates the number of entries in the zip file associated with the ZipBundleFile. The fact that I can print those out after the exception has occurred suggests that the ZIP file has NOT been closed. The Inflater must have been invalidated by some other means, which admittedly sounds impossible. I've been trying to find a way to "see inside" the java.util.ZipFile and its private vector of Inflaters, but no luck so far.
Followup: I used reflection to hack into the ZipFile object, and found that several of its Inflaters had been returned to the cache in an invalid state. Still no idea how they are being closed, but there it is. Is there any way to debug an Equinox application in Eclipse such that the code is loaded from the bundle jars? Whenever I try to debug my app, Eclipse seems to unpack everything and use DirBundles instead of ZipBundles. It kind of defeats the purpose in this case. Workaround (i.e. Grotesque hack that gets around the bug): public class ZipBundleFile { protected synchronized ZipFile getZipFile() throws IOException { if (closed) { mruList.add(this); zipFile = basicOpen(); closed = false; } else { mruList.use(this); cleanZipInflaterPool(); // <== NEW LINE } return zipFile; } // SERIOUSLY MAJOR HACK! synchronized void cleanZipInflaterPool() { try { Class zipClass = java.util.zip.ZipFile.class; Class infClass = java.util.zip.Inflater.class; Field fieldInflaters = zipClass.getDeclaredField("inflaters"); fieldInflaters.setAccessible(true); Field fieldStrm = infClass.getDeclaredField("strm"); fieldStrm.setAccessible(true); Vector inflaters = (Vector) fieldInflaters.get(zipFile); synchronized (inflaters) { for (int i = inflaters.size() - 1; i >= 0; i--) { Object inf = inflaters.elementAt(i); if (fieldStrm.getLong(inf) == 0L) { // this inflater is invalid, // remove it from the list! inflaters.remove(i); } } } } catch (Exception ignored) { } }
I'm encountering this bug as well. Configuration info: 64-bit Sun Java 1.6.0_03-b05 VM Linux 2.6.22 (Ubuntu 7.10 distribution) Equinox 3.3.2.R33x_v20080105 The bundles that are giving me problems are being deployed dynamically by the dirdeployer bundle from Knopflerfish. When I unzip the bundles (and give the resulting directories .jar extensions to trick dirdeployer into deploying them) they work fine.
please check the very simmilar issue in the Apache Felix 1.6.1: https://issues.apache.org/jira/browse/FELIX-1032
Richard Hall from felix discussed this issue more with me in great detail. It appears someone is wrapping the input stream from a bundle resource which ends up being a stream from ZipFile.getInputStream. This wrapper object then has a finalize method that ends up closing the wrappered stream. This appears to also cause finalize to be called transitively on all objects referenced by the wrapper object. This ends up including the Inflater object. What appears to happen is that the close() operation on the input stream makes the Inflater available for reuse but then the Inflator has its finalize method called by the GC which invalidates it. In the case Richard saw the class org.mortbay.resource.URLResource wrapped the input stream and called close on it during URLResource.finalize(). It appears somewhere there is a potential bug where a resource is not properly closed and it they is depending on GC to clean up the and close the stream. Unfortunately this practice seems to expose this issue.
Here are some more details from Richard: I investigated this bug rather thoroughly and have come to the conclusion that it is a JRE bug. This is what is happening: ZipFile.getInputStream() returns an instance of an anonymous subclass of InflaterInputStream. InflaterInputStream is constructed with an Inflater instance coming from a pool of inflaters in ZipFile. The InflaterInputStream subclass inserts the Inflater back into the ZipFile inflater pool on close(); note that InflaterInputStream subclass instance is does not call close() on itself in its finalizer. So, if this InflaterInputStream is wrapped in another InputStream and/or object that does call close() on it from the wrapper's finalizer(), then we run into a potential issue. What I am seeing is there is no reference to the wrapper, then the garbage collector is trying to finalize the wrapper, the InflaterInputStream subclass, and the Inflater inside it. In this case, the wrapper's finalizer() calls close() on the InflaterInputStream subclass which inserts a reference of its Inflater back into the ZipFile's inflater pool. Then the garbage collector continues to call finalize() on the other objects. In particular, Inflater.finalize() calls end() on itself, which invalidates the Inflater for future use. This the crux of the issue, since we now have an invalid Inflater in the ZipFile's inflater pool. Since it is not uncommon for people to close() in finalizers, I think the JRE should not have side effects like this in close. The JRE should be modified such that ZipFile does not simply remove Inflater instances from its "unused" pool when creating InflaterInputStreams, it should also insert them into another "used" pool to keep a hard reference to them. That way it won't get GC'd in the above scenario and end() won't be called on it to invalidate it. Until that happens, the work around it to explicitly call close() on all input streams rather than doing it in the finalizer. In this particular cases, it looks like mortbay was not explicitly closing a resource input stream, since I saw this stack trace snippet: !!! Thread[Finalizer,8,system] RELEASING INFLATER java.util.zip.Inflater@f96093 !!! Thread[Finalizer,8,system] java.lang.Thread.getStackTrace(Thread.java:1436) !!! Thread[Finalizer,8,system] java.util.zip.ZipFile.releaseInflater(ZipFile.java:280) !!! Thread[Finalizer,8,system] java.util.zip.ZipFile.access$000(ZipFile.java:29) !!! Thread[Finalizer,8,system] java.util.zip.ZipFile$1.close(ZipFile.java:217) !!! Thread[Finalizer,8,system] org.mortbay.resource.URLResource.release(URLResource.java:82)
This bug hasn't had any activity in quite some time. Maybe the problem got resolved, was a duplicate of something else, or became less pressing for some reason - or maybe it's still relevant but just hasn't been looked at yet. If you have further information on the current state of the bug, please add it. The information can be, for example, that the problem still occurs, that you still want the feature, that more information is needed, or that the bug is (for whatever reason) no longer relevant.
I think with modern versions of the JVM this is no longer an issue.
