[PATCH] The Name Suggestion Index preset causes dramatic slowing in line drawing and following (tracing)

[SekeRob]

From a report in a related thread on the OSM Community forum ​https://community.openstreetmap.org/t/name-suggestion-index-in-josm/5263/14

The activation of the NSI preset effect does not get noticed until actual line drawing is started and causes very substantial mapping speed reduction which is what I do 95-98 percent of the time on OSM. When removing this preset in prefs I get the performance back immediately i.e. 100% reproducable. Drawing lines in a new / empty data layer does not show this noticeably, it's just not as fast, particularly following makes it visible, but load a dense farming area, data save size about 10MB and the effect is dramatic.

[SekeRob]

The system info that went MIA

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

Relative:URL: ^/trunk
Repository:UUID: 0c6e7542-c601-0410-84e7-c038aed88b3b
Last:Changed Date: 2023-06-02 17:23:29 +0200 (Fri, 02 Jun 2023)
Revision:18746
Build-Date:2023-06-03 01:31:02
URL:https://josm.openstreetmap.de/svn/trunk

Identification: JOSM/1.5 (18746 en_GB) Windows 10 64-Bit
OS Build number: Windows 10 Home 2009 (19045)
Memory Usage: 3144 MB / 4084 MB (672 MB allocated, but free)
Java version: 17.0.7+7-LTS, Azul Systems, Inc., OpenJDK 64-Bit Server VM
Look and Feel: javax.swing.plaf.metal.MetalLookAndFeel
Screen: \Display0 1920×1080 (scaling 1.00×1.00)
Maximum Screen Size: 1920×1080
Best cursor sizes: 16×16→32×32, 32×32→32×32
System property file.encoding: Cp1252
System property sun.jnu.encoding: Cp1252
Locale info: en_GB
Numbers with default locale: 1234567890 -> 1234567890
VM arguments: [-Dicedtea-web.bin.location=%UserProfile%\AppData\Local\Programs\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]
Dataset consistency test: No problems found

Plugins:
+ Mapillary (2.1.4)
+ RoadSigns (36066)
+ apache-commons (36034)
+ easypresets (1623509627)
+ editgpx (36079)
+ graphview (36079)
+ jaxb (35952)
+ jogl (1.2.3)
+ kendzi3d-resources (0.0.2)
+ log4j (36045)
+ notesolver (0.5.0)
+ pt_assistant (2.1.15-19-g9aeec3c-SNAPSHOT)
+ reltoolbox (36066)
+ reverter (36066)
+ routing (36066)
+ turnrestrictions (36079)
+ utilsplugin2 (36079)

Tagging presets:
+ https://raw.githubusercontent.com/yopaseopor/traffic_signs_preset_JOSM/master/IT.zip
+ https://github.com/kendzi/Simple3dBuildingsPreset/releases/download/0.9_2018-05-08/s3db-preset.zip
+ https://josm.openstreetmap.de/josmfile?page=Presets/LaneAttributes&zip=1
+ <josm.pref>/EasyPresets.xml
+ https://josm.openstreetmap.de/josmfile?page=Presets/AdvertisingPreset&zip=1

Map paint styles:
+ https://josm.openstreetmap.de/josmfile?page=Styles/PublicTransport&zip=1
+ https://josm.openstreetmap.de/josmfile?page=Styles/ColorWays&zip=1
+ https://josm.openstreetmap.de/josmfile?page=Rules/IncompleteObjectWarnings&zip=1
- https://josm.openstreetmap.de/josmfile?page=Styles/Lane_and_Road_Attributes&zip=1
+ https://josm.openstreetmap.de/josmfile?page=Styles/AdvertisingStyle&zip=1

Last errors/warnings:
- 05519.357 E: Failed to locate image '3d_simple_icon_blue_32.png'
- 05519.358 W:  null: Could not get presets icon 3d_simple_icon_blue_32.png
- 05519.359 E: Failed to locate image 'roof_icon_blue_32.png'
- 05519.360 W:  null: Could not get presets icon roof_icon_blue_32.png
- 05519.929 E: Failed to locate image 'traffic_signs_presets/unclassified.png'
- 05519.929 W:  null: Could not get presets icon traffic_signs_presets/unclassified.png
- 05519.931 E: Failed to locate image '3d_simple_icon_blue_32.png'
- 05519.932 W:  null: Could not get presets icon 3d_simple_icon_blue_32.png
- 05519.933 E: Failed to locate image 'roof_icon_blue_32.png'
- 05519.934 W:  null: Could not get presets icon roof_icon_blue_32.png

[taylor.smock]

I did a bit of profiling a few weeks back once I heard about this issue, and (IIRC), the primary problem is that we are iterating through all the presets every time the user creates a new node. I believe it was for the selection list (primarily).

I'll try to do a bit more profiling once I'm somewhere with a proper setup (AKA mouse + mechanical keyboard + multiple monitors).

[SekeRob]

This may be of interest: It appears this 'iterative checking' is not happening when loading a saved data set and NSI tagging preset in opposite order.

Also, something in drawing lag changed round about June 30 when Openwebstart downloaded a file during the startup, before the window appears which lists the start up script steps. In fact OPS has done one or several file downloads multiple times in past days including today July 5, 2023. Something afoot? Currently working in a 90 MB file, where slowing of tracing is actually appearing normal as if NSI is not attached.

You mention checking every new node. Does that have to be while drawing a line? I'd think that need not be as long as A is active, only when S is hit or esc or double click on the last node to indicate drawing has concluded.

Coincidence or not this topic and the related ticket v.v. the crashing of custom presets. As an edit session goes on, the appearance of a custom preset window takes longer and longer till eventually crashing, or until I edit-save a dummy custom preset I've created to reset this slowing after which things are normal again. Also, custom presets crash immediately after opening a second data layer and fetching some new area data in the zone already covered in the 1st data layer which is generally big (now 90 MB. On the first custom preset call the error happens, not always, but very frequent. Regular presets I've never seen causing the crash.

For what it's worth.

[taylor.smock]

Ticket retargeted after milestone closed

[SekeRob]

Another piece in the puzzle: Read in newsletter Nr.676 about the JOSM Theme plugin Flatlaf which has 9 themes. I was using JOSM's own metal before. Tried a few and though looking for the dark themes found Light to be serving my eyes best here for easiest reading of the field keys in the Preset panes. Restarted with NSI still attached and loaded a 93MB data set. No slowing at all as the session continued, no slowing of the custom presets, a sign that a crash of custom presets is imminent, in fact, the follow function in such a large data set has perceptually never been as fast. Exited the session and started with same setup and NSI still active and worked another half hour in the big data set and uploaded edits. Again, no slowing at all noticed, 'follow' remained swift on a newly added few hundred node farmland plot. Traced it, still fast. Calling custom presets showing and filling racing, looking for a couple of NSI entries, instant. gobsmacked.

I could detach Flatlaf and return to the JOSM metal theme and see if the slowing returns but not going to jinx my luck for now.

[taylor.smock]

JOSM metal theme

The Metal theme is actually built into Java; we don't control it. But it is a "good" default for most people.

Anyway, thanks for the update. I'll probably track down the problem and file a ticket with the OpenJDK folks.

[taylor.smock]

Ticket retargeted after milestone closed

[taylor.smock]

Java version: 17.0.8+7, Eclipse Adoptium, OpenJDK 64-Bit Server VM

I am now unable to reproduce with Metal LaF. Can you still reproduce if you update to Java 17.0.8?

EDIT: NVM. I needed a lot more data in the layer.

[taylor.smock]

OK. I've done a bit of debugging, and it appears to be related to the number of relations you have, nothing else. So I would expect it to be a problem in the same areas regardless of the LaF you are using.

[anonymous]

I've moved into a dense multipolygon area slowly converting them to SPs. NSI attached is virtual impossible to work so stepping thru

Attach NSI
Map encountered bus stop, get the brand tags etc
Detached NSi

The proposed tick box to switch the tagging preset plugins on and off would help, less downloading at that. Why NSI is activated every set node is something you'd better understand than I ever will. Huge pain in the posterior.

[taylor.smock]

I have a fix; I am going to wait for a few days since I just did a tested release.

Why NSI is activated every set node is something you'd better understand than I ever will.

It pretty much comes down to how we notify the relation list dialog of changes to the dataset. For whatever reason, we always re-initialize the dialog when a merged DataChangedEvent is called. That hasn't changed since at least 2010, so I wouldn't be surprised if there are other tickets here on Trac for it.

[anonymous]

Well goodos if this makes it a multiticket catch and kill with one stone. Smells almost like a little performance fanfare is coming up with 23.08 or maybe sooner.

[taylor.smock]

In 18792/josm:

Fix #23018: The Name Suggestion Index preset causes dramatic slowing in line drawing and following

The root cause is that every time the dataset fires a DataChangedEvent, we
rebuild the relation list. This causes a search in the presets, which can become
very expensive with the NSI. To fix this, we instead iterate through each
individual event in the DataChangedEvent, and perform the appropriate action.

[SekeRob]

After 24 hours on 18822: It works a treat and more deserving a diary entry and inclusion in the weekly OSM newsletter. Dataset 189Mb, relations 2262, tracing and drawing speed as if the first day on JOSM and mapping on blank canvas, no plugins, no styles, no custom to slow things down presets... awesome.

🤩 👍

[taylor.smock]

deserving a diary entry and inclusion in the weekly OSM newsletter

I don't usually do diary entries or submissions to Weekly OSM. If you feel like doing either, go for it.

With that said, I would draw attention to the fact that we didn't know it was a problem until someone (you) reported it. We cannot fix that which we do not know about.

In addition, you stuck around and tried to help us reproduce -- it is significantly harder to fix something that we cannot reproduce.

[SekeRob]

You mentioned suspecting other open tickets being related to this issue. One ticket I opened seemingly does so too which is the loop back while tracing at the 4th node set back to the starting node while holding the follow key. Think it was SteveA who eventually advised me to work with smaller data sets which did prevent this issue reoccurring, while keeping the large data set of same area in background. Well, I've been tracing a whole lot in the past 48 hours in big data sets and not once has this happened again. The racing follow forward and line drawing is continuing without a single moment of the line dragging behind. I'll see if I can trace back all my tickets and evaluate if deemed related and if still open close them with Xref to this ticket.

Other observation: Memory usage on my instance would usually climb fast to 4GB Ram use and slowing would come along with that. Nearing 4.5 it could happen that the system started with freezing behavious for minutes on end completely blocking the launching of the Windows task manager to see what's on. Unloading the data sets and let it sit would not release a bit of memory letting it sit. Right now after 5 hours up, just 3GB Status: Not meeting but exceeding expectations.

[taylor.smock]

Other observation: Memory usage on my instance would usually climb fast to 4GB Ram use and slowing would come along with that. Nearing 4.5 it could happen that the system started with freezing behavious for minutes on end completely blocking the launching of the Windows task manager to see what's on. Unloading the data sets and let it sit would not release a bit of memory letting it sit. Right now after 5 hours up, just 3GB Status: Not meeting but exceeding expectations.

This sounds like a bug. If it got fixed, it was accidentally fixed. If it happens again, please open a ticket with steps to reproduce.