svn build with ant on Ubuntu 18.04/20.04 crashes with "Could not initialize class org.openstreetmap.josm.data.cache.JCSCacheManager" at runtime

[mvogt]

Building a working josm in a Ubuntu 18.04 environment from svn recently stopped working for me. I did svn co https://josm.openstreetmap.de/svn/trunk/ and ran "ant" in there.

I did build r15937 (and a bunch of version before that) and worked normally. When building r16239 the generated jar file will start but trying to download anything will fail with a crash:

2020-04-30 18:38:19.285 INFO: Obtained 57 Tag2Link rules from https://josm.openstreetmap.de/remote/wikidata-sparql
2020-04-30 18:38:19.325 INFO: Obtained 11 Tag2Link rules from https://josm.openstreetmap.de/remote/sophox-sparql
Warning: Nashorn engine is planned to be removed from a future JDK release
2020-04-30 18:38:28.332 INFO: Changeset updater active (checks every 60 minutes if open changesets have been closed)
2020-04-30 18:38:28.332 INFO: Enabled EDT checker, wrongful access to gui from non EDT thread will be printed to console
2020-04-30 18:38:33.673 SEVERE: Handled by bug report queue: java.lang.NoClassDefFoundError: Could not initialize class org.openstreetmap.josm.data.cache.JCSCacheManager
java.lang.NoClassDefFoundError: Could not initialize class org.openstreetmap.josm.data.cache.JCSCacheManager
	at org.openstreetmap.josm.gui.layer.AbstractCachedTileSourceLayer.getCache(AbstractCachedTileSourceLayer.java:118)
	at org.openstreetmap.josm.gui.layer.AbstractCachedTileSourceLayer.getTileLoaderFactory(AbstractCachedTileSourceLayer.java:106)
	at org.openstreetmap.josm.gui.bbox.JosmMapViewer.<init>(JosmMapViewer.java:148)
	at org.openstreetmap.josm.gui.bbox.SlippyMapBBoxChooser.<init>(SlippyMapBBoxChooser.java:87)
	at org.openstreetmap.josm.gui.download.SlippyMapChooser.<init>(SlippyMapChooser.java:35)
	at org.openstreetmap.josm.gui.download.DownloadDialog.buildMainPanel(DownloadDialog.java:128)
	at org.openstreetmap.josm.gui.download.DownloadDialog.<init>(DownloadDialog.java:230)
	at org.openstreetmap.josm.gui.download.DownloadDialog.<init>(DownloadDialog.java:218)
	at org.openstreetmap.josm.gui.download.DownloadDialog.getInstance(DownloadDialog.java:84)
	at org.openstreetmap.josm.actions.DownloadAction.actionPerformed(DownloadAction.java:35)
	at java.desktop/javax.swing.AbstractButton.fireActionPerformed(AbstractButton.java:1967)
	at java.desktop/javax.swing.AbstractButton$Handler.actionPerformed(AbstractButton.java:2308)
	at java.desktop/javax.swing.DefaultButtonModel.fireActionPerformed(DefaultButtonModel.java:405)
	at java.desktop/javax.swing.DefaultButtonModel.setPressed(DefaultButtonModel.java:262)
	at java.desktop/javax.swing.plaf.basic.BasicButtonListener.mouseReleased(BasicButtonListener.java:279)
	at java.desktop/java.awt.AWTEventMulticaster.mouseReleased(AWTEventMulticaster.java:297)
	at java.desktop/java.awt.Component.processMouseEvent(Component.java:6631)
	at java.desktop/javax.swing.JComponent.processMouseEvent(JComponent.java:3342)
	at java.desktop/java.awt.Component.processEvent(Component.java:6396)
	at java.desktop/java.awt.Container.processEvent(Container.java:2263)
	at java.desktop/java.awt.Component.dispatchEventImpl(Component.java:5007)
	at java.desktop/java.awt.Container.dispatchEventImpl(Container.java:2321)
	at java.desktop/java.awt.Component.dispatchEvent(Component.java:4839)
	at java.desktop/java.awt.LightweightDispatcher.retargetMouseEvent(Container.java:4918)
	at java.desktop/java.awt.LightweightDispatcher.processMouseEvent(Container.java:4547)
	at java.desktop/java.awt.LightweightDispatcher.dispatchEvent(Container.java:4488)
	at java.desktop/java.awt.Container.dispatchEventImpl(Container.java:2307)
	at java.desktop/java.awt.Window.dispatchEventImpl(Window.java:2772)
	at java.desktop/java.awt.Component.dispatchEvent(Component.java:4839)
	at java.desktop/java.awt.EventQueue.dispatchEventImpl(EventQueue.java:772)
	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.base/java.security.ProtectionDomain$JavaSecurityAccessImpl.doIntersectionPrivilege(ProtectionDomain.java:95)
	at java.desktop/java.awt.EventQueue$5.run(EventQueue.java:745)
	at java.desktop/java.awt.EventQueue$5.run(EventQueue.java:743)
	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:742)
	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)

I tried this on two different machines (20.04 and 18.04) with the same result. With jdk 8/11/14. I also tried to checkout r15937 to bisect but this checkout fails with:

svn: warning: W170000: URL 'https://github.com/apache/commons-jcs/trunk/commons-jcs-core/src/main/java/org/apache/commons/jcs' at revision 3137 doesn't exist

Any hints what I can do to get to a working build would be greatly appreciated. Do I need to update anything on my side how I build josm?

Thanks,

Michael

[GerdP]

Did you try ant clean dist?

[GerdP]

If that doesn't help please attach the build log. CompositeCacheManager was removed in r16335, so maybe you did not check out r16239, but the latest version?

[mvogt]

Thanks @GertP - it looks like the missing CompositeCacheManager is a bit of a red-herring. I get this crash when trying to download a map in my svn build, adding debug prints shows that it fails in AbstractCachedTileSourceLayer.java:getCache() with "Could not initialize class org.openstreetmap.josm.data.cache.JCSCacheManager" but there is really no more info. This is build with openJDK 11.0.7, I wonder if that could be related, I will try with a more recent jdk maybe. Sorry for this unclear report, it's puzzling because the josm-tested.jar that I can download from here works fine it seems.

[mvogt]

I added some debug logs. The svn info output, the ant clean dist output and the log output when running. It crashes when I click on the download map data icon. However it works fine with the "josm-tested.jar" download from josm.org so I'm puzzled what my local build is doing wrong. I also added some debug prints in AbstractCachedTileSourceLayer.java:getCache() that shows that it tries to call JCSCacheManager.getCache(). I also add debug prints into JCSCacheManager itself which seems to be not printed at all (which is also puzzling).

[GerdP]

josm-tested is built with jdk 8. JOSM is also built with jdk 11, but I don't know if it is expected to work. Sometimes unit tests fail with jdk 11, but not with jdk 8.

[GerdP]

ant clean dist with JKD 8 on Windows

[GerdP]

I've attached my log from ant.

This looks suspicious in your log:

resolve:
[ivy:resolve] ivy.instance reference an ivy:settings defined in an other classloader.  An new default one will be used in this project.
[ivy:resolve] DEPRECATED: 'ivy.conf.file' is deprecated, use 'ivy.settings.file' instead
[ivy:resolve] :: Apache Ivy 2.5.0 - 20191020104435 :: https://ant.apache.org/ivy/ ::
[ivy:resolve] :: loading settings :: file = /tmp/3/trunk/ivysettings.xml 

See also output from automated builds for jdk8 and jdk11:
https://josm.openstreetmap.de/jenkins/job/JOSM/jdk=JDK8/6384/consoleFull
https://josm.openstreetmap.de/jenkins/job/JOSM/jdk=JDK11/6384/consoleFull

[GerdP]

Just to make sure: I assume you use a clean checkout without any patches?

[mvogt]

I updated the description, it appears to be some build issue on Ubuntu (or maybe linux in general?). I did a fresh svn checkout in a pristine 18.04 VM, build with ant and ran with "java -jar ./dist/josm-custom.jar". Same crash though.

[mvogt]

Also thanks to @GertP for all your help and hints, maybe I can dig a bit in the jenkins to see if there is anything done there that I miss.

[mvogt]

@GertP - sorry, did miss the earlier question. Yes, this was tested with a fresh checkout without any patches. I did add a bunch of System.out.println() to get a feel for what is wrong but I did not get further than the java.lang.NoClassDefFoundError: Could not initialize class org.openstreetmap.josm.data.cache.JCSCacheManager error.

[GerdP]

duplicate of #19153?

[mvogt]

@GerdP Could be, the error looks the same. But the other bug is a bit short on details. Also josm-testest.jar and josm-latest.jar works just fine for me, so the pre-build stuff is ok just building seems to be problematic.

[stoecker]

Hmm, if it is happening with a fresh checkout something is wrong. I'd assume the build is not as fresh as you think. Did you try with a fully fresh checkout, i.e. delete JOSM dir and recheckout?

[mvogt]

@stoecker Thanks for your feedback! I did a fresh checkout in a fresh VM ubuntu-18.04 VM, installed svn and all the build-dependencies (openjdk,ant,etc) and tested the generated jar - unfortunately it's the same error so I don't think this is an issue with a stable repo on the client. Happy to try more but both my java and my svn knowledge are a bit rusty and I ran out of ideas.

[GerdP]

r16335 was the last change on JCSCacheManager. My next step would be to compile r16334.

[GerdP]

I just found https://josm.openstreetmap.de/jenkins/job/JOSM-Integration/lastCompletedBuild/testReport/
and https://josm.openstreetmap.de/jenkins/job/JOSM-Integration/lastCompletedBuild/jdk=JDK8/testReport/org.openstreetmap.josm.tools/PlatformHookTestIT/testLatestUbuntuVersion/
Maybe this is related?
Can you try if r16192 still works for you? If yes, one of next releases probably introdced the problem.

[anonymous]

Thanks @GerdP - I tried to "svn co -r16192" and got the following error:
"""
svn: warning: W205011: Error handling externals definition for 'trunk/src/org/apache/commons/jcs':
svn: warning: W170000: URL '​https://github.com/apache/commons-jcs/trunk/commons-jcs-core/src/main/java/org/apache/commons/jcs' at revision 3137 doesn't exist
Checked out revision 16192.
svn: E205011: Failure occurred processing one or more externals definitions
"""
Any hints how I can fix this would be appreciated.

Next I tried -r16334 and it looks like the checkout of this revision works but r16334 crashes.

[GerdP]

I get the same warning and ant dist fails with various javac errors. See #16860.
I tried a clean checkout of r16195, get the same warning, but ant dist works and JOSM als seems to work.
I hope somebody else has an idea, I don't know any details about the changes reg. JCSCacheManager or ivy.

[simon04]

This ticket is lacking necessary information (in particular the used Java JDK/JRE)

---

Thanks for your report, however your ticket is incomplete and therefore not helpful in its current form.

Please add all needed information according to this list:

• The required parts of the Status Report from your JOSM.
  • Please, use Report Bug from Help menu and copy & paste.
• Describe what behaviour you expected.
• Describe what did happen instead.
• Describe if and how the issue is reproducible.
• Add any relevant information like error messages or screenshots.

To ensure that all technical relevant information is contained, create new tickets by clicking in JOSMs Main Menu on Help → Report Bug.

Remember: This is a generic notice so we don't need to write the same stuff again and again. It may only apply in parts to the specific case!

[GerdP]

Replying to simon04:

This ticket is lacking necessary information (in particular the used Java JDK/JRE)

See comment:3

[johsin18]

I experience the same problem (on Windows 10).
I tried with JDK 1.8.0_251 (and also JDK 11.0.1), and cleanly rebuilt many times.

The class file for JCSCacheManager.java is in fact contained by the JAR (at the correct location). I suspect that one of the many static initializers of JCSCacheManager throw an uncaught exception under certain circumstances (I skipped plugins), causing NoClassDefFoundError.

This is my Debug Information:

Build-Date:2020-05-05 07:36:34
Revision:16239
Is-Local-Build:true

Identification: JOSM/1.5 (16239 SVN en) Windows 10 64-Bit
OS Build number: Windows 10 Home 1909 (18363)
Memory Usage: 255 MB / 1803 MB (154 MB allocated, but free)
Java version: 1.8.0_251-b08, Oracle Corporation, Java HotSpot(TM) 64-Bit Server VM
Screen: \Display0 3200x1800, \Display1 1920x1200
Maximum Screen Size: 3200x1800
Program arguments: [--skip-plugins]

Plugins:
+ DxfImport
+ Mapillary
+ PicLayer
+ SimplifyArea
+ apache-commons
+ apache-http
+ areaselector
+ austriaaddresshelper
+ ejml
+ geotools
+ imagery_offset_db
+ javafx-windows
+ jaxb
+ jna
+ jogl
+ jts
+ log4j
+ opendata
+ reverter
+ terracer
+ utilsplugin2

Map paint styles:
- https://josm.openstreetmap.de/josmfile?page=Styles/PublicTransport&zip=1
- https://josm.openstreetmap.de/josmfile?page=Styles/PublicTransportV2&zip=1
- https://josm.openstreetmap.de/josmfile?page=Styles/Coloured_Streets&zip=1
- https://josm.openstreetmap.de/josmfile?page=Styles/Coloured_Suburb&zip=1
- https://www.dropbox.com/s/qo3ai47fpv241jf/Styles_Fixme_and_Notes.zip?raw=1
- https://josm.openstreetmap.de/josmfile?page=Styles/NoFeature&zip=1

Last errors/warnings:
- E: Handled by bug report queue: java.lang.NoClassDefFoundError: Could not initialize class org.openstreetmap.josm.data.cache.JCSCacheManager


=== REPORTED CRASH DATA ===
BugReportExceptionHandler#handleException:
No data collected.

Warning issued by: BugReportExceptionHandler#handleException

=== STACK TRACE ===
Thread: AWT-EventQueue-0 (17) of main
java.lang.NoClassDefFoundError: Could not initialize class org.openstreetmap.josm.data.cache.JCSCacheManager
	at org.openstreetmap.josm.gui.layer.AbstractCachedTileSourceLayer.getCache(AbstractCachedTileSourceLayer.java:118)
	at org.openstreetmap.josm.gui.layer.AbstractCachedTileSourceLayer.getTileLoaderFactory(AbstractCachedTileSourceLayer.java:106)
	at org.openstreetmap.josm.gui.bbox.JosmMapViewer.<init>(JosmMapViewer.java:148)
	at org.openstreetmap.josm.gui.bbox.SlippyMapBBoxChooser.<init>(SlippyMapBBoxChooser.java:87)
	at org.openstreetmap.josm.gui.download.SlippyMapChooser.<init>(SlippyMapChooser.java:35)
	at org.openstreetmap.josm.gui.download.DownloadDialog.buildMainPanel(DownloadDialog.java:128)
	at org.openstreetmap.josm.gui.download.DownloadDialog.<init>(DownloadDialog.java:230)
	at org.openstreetmap.josm.gui.download.DownloadDialog.<init>(DownloadDialog.java:218)
	at org.openstreetmap.josm.gui.download.DownloadDialog.getInstance(DownloadDialog.java:84)
	at org.openstreetmap.josm.actions.DownloadAction.actionPerformed(DownloadAction.java:35)
	at javax.swing.AbstractButton.fireActionPerformed(AbstractButton.java:2022)
	at javax.swing.AbstractButton$Handler.actionPerformed(AbstractButton.java:2348)
	at javax.swing.DefaultButtonModel.fireActionPerformed(DefaultButtonModel.java:402)
	at javax.swing.DefaultButtonModel.setPressed(DefaultButtonModel.java:259)
	at javax.swing.plaf.basic.BasicButtonListener.mouseReleased(BasicButtonListener.java:252)
	at java.awt.AWTEventMulticaster.mouseReleased(AWTEventMulticaster.java:290)
	at java.awt.Component.processMouseEvent(Component.java:6539)
	at javax.swing.JComponent.processMouseEvent(JComponent.java:3324)
	at java.awt.Component.processEvent(Component.java:6304)
	at java.awt.Container.processEvent(Container.java:2239)
	at java.awt.Component.dispatchEventImpl(Component.java:4889)
	at java.awt.Container.dispatchEventImpl(Container.java:2297)
	at java.awt.Component.dispatchEvent(Component.java:4711)
	at java.awt.LightweightDispatcher.retargetMouseEvent(Container.java:4904)
	at java.awt.LightweightDispatcher.processMouseEvent(Container.java:4535)
	at java.awt.LightweightDispatcher.dispatchEvent(Container.java:4476)
	at java.awt.Container.dispatchEventImpl(Container.java:2283)
	at java.awt.Window.dispatchEventImpl(Window.java:2746)
	at java.awt.Component.dispatchEvent(Component.java:4711)
	at java.awt.EventQueue.dispatchEventImpl(EventQueue.java:760)
	at java.awt.EventQueue.access$500(EventQueue.java:97)
	at java.awt.EventQueue$3.run(EventQueue.java:709)
	at java.awt.EventQueue$3.run(EventQueue.java:703)
	at java.security.AccessController.doPrivileged(Native Method)
	at java.security.ProtectionDomain$JavaSecurityAccessImpl.doIntersectionPrivilege(ProtectionDomain.java:74)
	at java.security.ProtectionDomain$JavaSecurityAccessImpl.doIntersectionPrivilege(ProtectionDomain.java:84)
	at java.awt.EventQueue$4.run(EventQueue.java:733)
	at java.awt.EventQueue$4.run(EventQueue.java:731)
	at java.security.AccessController.doPrivileged(Native Method)
	at java.security.ProtectionDomain$JavaSecurityAccessImpl.doIntersectionPrivilege(ProtectionDomain.java:74)
	at java.awt.EventQueue.dispatchEvent(EventQueue.java:730)
	at java.awt.EventDispatchThread.pumpOneEventForFilters(EventDispatchThread.java:205)
	at java.awt.EventDispatchThread.pumpEventsForFilter(EventDispatchThread.java:116)
	at java.awt.EventDispatchThread.pumpEventsForHierarchy(EventDispatchThread.java:105)
	at java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:101)
	at java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:93)
	at java.awt.EventDispatchThread.run(EventDispatchThread.java:82)

[simon04]

In 16392/josm:

see #19173, see #19113 - JCSCacheManager: log all initialization errors

[mvogt]

Build/run log from 16392

[mvogt]

I rebuild using r16392 but unfortunately nothing in the logs that looks new. The full log is attached (and also available in ​https://paste.ubuntu.com/p/nDnJymtsx5/)

[bhatchl]

I too get this error when running a locally built rev 16239 jar. Adding an additional try/catch for ExceptionInInitializerError

Index: src/org/openstreetmap/josm/gui/layer/AbstractCachedTileSourceLayer.java
===================================================================
--- src/org/openstreetmap/josm/gui/layer/AbstractCachedTileSourceLayer.java	(revision 16239)
+++ src/org/openstreetmap/josm/gui/layer/AbstractCachedTileSourceLayer.java	(working copy)
@@ -14,6 +14,7 @@
 import org.openstreetmap.josm.data.imagery.ImageryInfo;
 import org.openstreetmap.josm.data.imagery.TileLoaderFactory;
 import org.openstreetmap.josm.data.preferences.IntegerProperty;
+import org.openstreetmap.josm.tools.Logging;
 
 /**
  *
@@ -115,10 +116,15 @@
      * @return cache configured object for specified cache region
      */
     public static CacheAccess<String, BufferedImageCacheEntry> getCache(String name) {
+        try {
             return JCSCacheManager.getCache(name,
                     0,
                     MAX_DISK_CACHE_SIZE.get() * 1024, // MAX_DISK_CACHE_SIZE is in MB, needs to by in sync with getDiskCacheSize
                     CachedTileLoaderFactory.PROP_TILECACHE_DIR.get());
+        } catch (ExceptionInInitializerError error) {
+            Logging.error(error);
+            return null;
+        }
     }
 
     protected abstract Class<? extends TileLoader> getTileLoaderClass();

reveals this on startup:

2020-05-05 09:31:21.150 SEVERE: java.lang.ExceptionInInitializerError. Cause: java.lang.RuntimeException: Could not find factory implementation for log subsystem jul
java.lang.ExceptionInInitializerError
    at org.apache.commons.jcs.log.LogManager.getLogFactory(LogManager.java:83)
    at org.apache.commons.jcs.log.LogManager.getLog(LogManager.java:113)
    at org.apache.commons.jcs.auxiliary.disk.block.BlockDiskCacheFactory.<clinit>(BlockDiskCacheFactory.java:37)
    at org.openstreetmap.josm.data.cache.JCSCacheManager.<clinit>(JCSCacheManager.java:50)
    at org.openstreetmap.josm.gui.layer.AbstractCachedTileSourceLayer.getCache(AbstractCachedTileSourceLayer.java:120)
    at org.openstreetmap.josm.gui.layer.TMSLayer.getCache(TMSLayer.java:144)
    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:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.RuntimeException: Could not find factory implementation for log subsystem jul
    at org.apache.commons.jcs.log.LogManager$LogFactoryHolder.createLogFactory(LogManager.java:64)
    at org.apache.commons.jcs.log.LogManager$LogFactoryHolder.<clinit>(LogManager.java:40)
    ... 11 more

My guess is a bug was introduced in the commons-jcs-core 3.0-SNAPSHOT after the 16239 josm-tested jar was built and you maintainers had a good 3.0-SNAPSHOT in your ivy cache.

If I downgrade the version to 2.2.1 the error goes away, cached image layers can be added to the map, and the program exits cleanly. I'm not sure if any other JCS features are lost though.

Another interesting clue about the jcs 3.0-SNAPSHOT is that in the good josm-tested.jar there is no log package under /org/apache/commons/jcs/ but in my locally built jar there is.

[Klumbumbus]

Milestone renamed

[simon04]

In 16397/josm:

fix #19173 - JCS LogManager needs META-INF/services/org.apache.commons.jcs.log.LogFactory

org.apache.commons.jcs.log.JulLogFactory is loaded using ServiceLoader and needs to be registered in the META-INF/services file.

[johsin18]

The fix works for me, thanks.

Suggestion: Maybe add a "Kill"/"Terminate" button to the crash dialog, it's quite annoying if a crash (like this one) prevents quitting the application.

[simon04]

Ticket #19185 has been marked as a duplicate of this ticket.