JOSM crashes during large uploads

[jmarchon]

What steps will reproduce the problem?

Unsure, sometimes happens during the upload of a large (~40,000+ edits) session. Sometimes it also works just fine.

What is the expected result?

The upload is performed as normal

What happens instead?

Partway through the upload, it stops and JOSM no longer reacts to any input. I've waited for 30+ minutes and it does not appear to ever recover. I then have to force kill JOSM via the system monitor, revert all the edits already uploaded, and start over again. It does ask to recover the data layer, but it is then locked and I cannot continue the upload.

Please provide any additional information below. Attach a screenshot if possible.

I will attach the requested thread dump as a text file.

Relative:URL: ^/trunk
Repository:UUID: 0c6e7542-c601-0410-84e7-c038aed88b3b
Last:Changed Date: 2023-12-07 13:35:12 +0100 (Thu, 07 Dec 2023)
Revision:18907
Build-Date:2023-12-07 16:38:49
URL:https://josm.openstreetmap.de/svn/trunk

Identification: JOSM/1.5 (18907 en) Linux Ubuntu 22.04.3 LTS
Memory Usage: 1057 MB / 1954 MB (480 MB allocated, but free)
Java version: 17.0.7+7-LTS, Azul Systems, Inc., OpenJDK 64-Bit Server VM
Look and Feel: com.formdev.flatlaf.FlatDarculaLaf
Screen: :0.0 1800×1200 (scaling 1.00×1.00)
Maximum Screen Size: 1800×1200
Best cursor sizes: 16×16→16×16, 32×32→32×32
Environment variable LANG: en_US.UTF-8
System property file.encoding: UTF-8
System property sun.jnu.encoding: UTF-8
Locale info: en_US
Numbers with default locale: 1234567890 -> 1234567890
Desktop environment: ubuntu:GNOME
fonts-noto: fonts-noto:-
VM arguments: [-Dicedtea-web.bin.location=/opt/OpenWebStart/javaws, -Djava.util.Arrays.useLegacyMergeSort=true, --add-exports=jdk.deploy/com.sun.deploy.config=ALL-UNNAMED, --add-opens=java.desktop/javax.swing.text.html=ALL-UNNAMED, --add-reads=java.naming=ALL-UNNAMED,java.desktop, --add-exports=java.base/sun.security.action=ALL-UNNAMED,java.desktop, --add-reads=java.base=ALL-UNNAMED,java.desktop, --add-exports=java.naming/com.sun.jndi.toolkit.url=ALL-UNNAMED,java.desktop, --add-opens=java.base/jdk.internal.loader=ALL-UNNAMED, --add-exports=java.desktop/com.apple.eawt=ALL-UNNAMED, --add-exports=java.desktop/sun.awt=ALL-UNNAMED,java.desktop, --add-opens=java.base/jdk.internal.ref=ALL-UNNAMED, --add-exports=java.base/sun.security.validator=ALL-UNNAMED,java.desktop, --add-exports=java.desktop/com.sun.imageio.plugins.jpeg=ALL-UNNAMED, --add-exports=java.base/sun.net.www.protocol.jar=ALL-UNNAMED,java.desktop, --add-exports=java.base/jdk.internal.util.jar=ALL-UNNAMED,java.desktop, --add-opens=java.prefs/java.util.prefs=ALL-UNNAMED, --add-exports=java.base/com.sun.net.ssl.internal.ssl=ALL-UNNAMED,java.desktop, --add-exports=javafx.graphics/com.sun.javafx.application=ALL-UNNAMED, --add-modules=java.scripting,java.sql,javafx.controls,javafx.media,javafx.swing,javafx.web, --add-exports=java.desktop/sun.awt.X11=ALL-UNNAMED,java.desktop, --add-exports=java.desktop/sun.applet=ALL-UNNAMED,java.desktop,jdk.jsobject, --add-exports=java.base/sun.net.www.protocol.http=ALL-UNNAMED,java.desktop, --add-opens=java.base/java.lang=ALL-UNNAMED, --add-exports=java.base/sun.security.util=ALL-UNNAMED,java.desktop, --add-exports=java.desktop/com.sun.imageio.spi=ALL-UNNAMED, --add-reads=java.desktop=ALL-UNNAMED,java.naming, --add-opens=java.base/java.nio=ALL-UNNAMED, --add-exports=java.base/sun.security.x509=ALL-UNNAMED,java.desktop, --add-opens=java.desktop/javax.imageio.spi=ALL-UNNAMED, --add-exports=java.desktop/javax.jnlp=ALL-UNNAMED,java.desktop, --add-exports=java.base/sun.security.provider=ALL-UNNAMED,java.desktop]

Plugins:
+ FastDraw (36126)
+ FixAddresses (36126)
+ PicLayer (1.0.3)
+ apache-commons (36176)
+ apache-http (36176)
+ buildings_tools (36178)
+ contourmerge (v0.2.0)
+ damn (0.13.1)
+ flatlaf (36176)
+ gridify (1606242219)
+ jna (36176)
+ josm-batch-downloader (1.0.4)
+ mapwithai (819)
+ markseen (14)
+ pmtiles (36156)
+ reltoolbox (36178)
+ reverter (36126)
+ shrinkwrap (v1.0.4)
+ todo (133)
+ undelete (36126)
+ utilsplugin2 (36178)

Tagging presets:
+ https://josm.openstreetmap.de/josmfile?page=Presets/TurnLanes&zip=1
+ https://josm.openstreetmap.de/josmfile?page=Presets/LaneAttributes&zip=1

Map paint styles:
- https://josm.openstreetmap.de/josmfile?page=Styles/Lane_and_Road_Attributes&zip=1
- https://josm.openstreetmap.de/josmfile?page=Styles/Coloured_Streets&zip=1
+ https://josm.openstreetmap.de/josmfile?page=Styles/MapWithAI&zip=1

Validator rules:
+ ${HOME}/Documents/OSM/JOSM validator rules/ALLCAPS-to-TitleCase.validator.mapcss
+ ${HOME}/Documents/OSM/JOSM validator rules/USStreetNameExpander.validator.mapcss
+ ${HOME}/Documents/OSM/JOSM validator rules/USStreetNameExpander-PostfixDirectional.validator.mapcss
+ ${HOME}/Documents/OSM/JOSM validator rules/USStreetNameExpander-PrefixDirectional.validator.mapcss

[jmarchon]

The thread dump text file

[stoecker]

You've allocated less than 2GB for JOSM. That's not much for your large screen size and large uploads (probably also with background imagery?). I'd suggest to increase the memory allocated to JOSM to at least twice the size.

Depending on how you start josm, see wiki:Help/CommandLineOptions

[taylor.smock]

From the thread dump:

"AWT-EventQueue-1" #51 prio=6 os_prio=0 cpu=192796.73ms elapsed=2557.93s allocated=15960M defined_classes=2775 tid=0x000055c1945e1030 nid=0x174f waiting on condition  [0x00007f9a99af1000]
   java.lang.Thread.State: WAITING (parking)
	at jdk.internal.misc.Unsafe.park(java.base@17.0.7/Native Method)
	- parking to wait for  <0x00000000b6100020> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
        [...snip...]
	at sun.net.www.http.ChunkedInputStream.close(java.base@17.0.7/ChunkedInputStream.java:764)
	at java.io.FilterInputStream.close(java.base@17.0.7/FilterInputStream.java:179)
	at sun.net.www.protocol.http.HttpURLConnection$HttpInputStream.close(java.base@17.0.7/HttpURLConnection.java:3771)
	at sun.net.www.protocol.http.HttpURLConnection.disconnect(java.base@17.0.7/HttpURLConnection.java:3125)
	at sun.net.www.protocol.https.HttpsURLConnectionImpl.disconnect(java.base@17.0.7/HttpsURLConnectionImpl.java:235)
	at org.openstreetmap.josm.tools.Http1Client.disconnect(Http1Client.java:225)
	at org.openstreetmap.josm.tools.Http1Client.disconnect(Http1Client.java:211)
	at org.openstreetmap.josm.io.OsmConnection.cancel(OsmConnection.java:90)
	- locked <0x00000000885491a8> (a org.openstreetmap.josm.io.OsmApi)
	at org.openstreetmap.josm.io.OsmServerWriter.cancel(OsmServerWriter.java:244)
	at org.openstreetmap.josm.gui.io.UploadPrimitivesTask.cancel(UploadPrimitivesTask.java:421)
	- locked <0x00000000b6100388> (a org.openstreetmap.josm.gui.io.AsynchronousUploadPrimitivesTask)
	at org.openstreetmap.josm.gui.io.AsynchronousUploadPrimitivesTask.cancel(AsynchronousUploadPrimitivesTask.java:134)
	at org.openstreetmap.josm.gui.PleaseWaitRunnable.operationCanceled(PleaseWaitRunnable.java:148)
	at org.openstreetmap.josm.gui.progress.CancelHandler.cancel(CancelHandler.java:24)
	- locked <0x00000000b61004b0> (a org.openstreetmap.josm.gui.progress.CancelHandler)
	at org.openstreetmap.josm.gui.progress.AbstractProgressMonitor.cancel(AbstractProgressMonitor.java:214)
        [...snip...]
   Locked ownable synchronizers:
	- None

"main-worker-0" #50 prio=5 os_prio=0 cpu=155320.32ms elapsed=2558.59s allocated=6479M defined_classes=343 tid=0x00007f9ab029ac40 nid=0x174d runnable  [0x00007f9a99bf0000]
   java.lang.Thread.State: RUNNABLE
	at sun.nio.ch.SocketDispatcher.read0(java.base@17.0.7/Native Method)
        [...snip...]
	- locked <0x00000000b6184248> (a java.io.BufferedInputStream)
	at sun.net.www.http.ChunkedInputStream.readAheadBlocking(java.base@17.0.7/ChunkedInputStream.java:554)
	at sun.net.www.http.ChunkedInputStream.readAhead(java.base@17.0.7/ChunkedInputStream.java:611)
	at sun.net.www.http.ChunkedInputStream.read(java.base@17.0.7/ChunkedInputStream.java:705)
	at java.io.FilterInputStream.read(java.base@17.0.7/FilterInputStream.java:132)
	at sun.net.www.protocol.http.HttpURLConnection$HttpInputStream.read(java.base@17.0.7/HttpURLConnection.java:3698)
	at org.openstreetmap.josm.io.ProgressInputStream.read(ProgressInputStream.java:49)
        [...snip...]
	- locked <0x00000000b6186578> (a org.openstreetmap.josm.io.UTFInputStreamReader)
        [...snip...]
	- locked <0x00000000b6186578> (a org.openstreetmap.josm.io.UTFInputStreamReader)
	at java.io.Reader.read(java.base@17.0.7/Reader.java:197)
	at java.util.Scanner.readInput(java.base@17.0.7/Scanner.java:882)
	at java.util.Scanner.next(java.base@17.0.7/Scanner.java:1476)
	at org.openstreetmap.josm.tools.HttpClient$Response.fetchContent(HttpClient.java:440)
	- locked <0x00000000b6186688> (a org.openstreetmap.josm.tools.Http1Client$Http1Response)
	at org.openstreetmap.josm.io.OsmApi.sendRequest(OsmApi.java:804)
        [...snip...]
   Locked ownable synchronizers:
	- <0x00000000870ce0a0> (a java.util.concurrent.ThreadPoolExecutor$Worker)
	- <0x00000000b5f99e60> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
	- <0x00000000b5fa5140> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
	- <0x00000000b6100020> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)

The second AWT-EventQueue-1 thread (yes, there are two) is waiting on 0x00000000b6100020 which is owned by the main-worker-0 thread. The main worker thread may be stuck in a native method with the ChunkedInputStream locked, which prevents the connection from being closed, since the worker thread is holding the lock.

I'm thinking this is probably a javabug. The lock is acquired by ChunkedInputStream#read in the worker thread, and then the UI thread tries to disconnect in ChunkedInputStream#close.

We could probably work around this by interrupting the worker thread, but we probably don't want to do that. I'll do a bit of research to see if there is a better way for us to disconnect.

[taylor.smock]

Upstream JavaBug: ​https://bugs.openjdk.org/browse/JDK-8081395 .
It looks like they expect URLConnection.setReadTimeout to be set.

[taylor.smock]

Well, this is fun. It should be set (see source:trunk/src/org/openstreetmap/josm/tools/Http1Client.java@18925#L218​ ).

@jmarchon: What are the advanced preferences socket.timeout.read and socket.timeout.connect set to? The defaults are 30 and 15 respectively.

[stoecker]

Question is if setting the timeout works after the fact... I would doubt that. With the unlimited number of possibilities to create a connection in Java there's probably one (or more) not properly handled ;-)

[taylor.smock]

We call setReadTimeout elsewhere (in setupConnection), and I'm kind of wondering if the timeouts @jmarchon set were 0. Which would be "infinite" per documentation.

[jmarchon]

socket.timeout.read and socket.timeout.connect are set to their defaults (30 & 15).