JOSM unresponsive after using WMS

[nkamapper]

What steps will reproduce the problem?

1. Open WMS "Norway orthophoto (more recent, more zoom)"
2. Edit for a while (normal size file)

Tile size was set to 1024

What is the expected result?

Normal editing

What happens instead?

CPU usage increases to very high level
"Out of memory" message (8192 MB available to JOSM)

Possibly related to #20443 and #20207

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

Revision:17428
Is-Local-Build:true
Build-Date:2020-12-30 15:56:02

Identification: JOSM/1.5 (17428 SVN en_GB) Mac OS X 10.15.7
OS Build number: Mac OS X 10.15.7 (19H2)
Memory Usage: 8192 MB / 8192 MB (4183 MB allocated, but free)
Java version: 15.0.1+9, Azul Systems, Inc., OpenJDK 64-Bit Server VM
Look and Feel: com.apple.laf.AquaLookAndFeel
Screen: Display 69733568 1440×900 (scaling 2.00×2.00)
Maximum Screen Size: 1440×900
Best cursor sizes: 16×16→16×16, 32×32→32×32
VM arguments: [--module-path=/Applications/JOSM.app/Contents/app/mods]
Dataset consistency test: No problems found

Plugins:
+ PicLayer (2a9aa7a)
+ apache-commons (35524)
+ apache-http (35589)
+ changeset-viewer (25)
+ conflation (0.6.6)
+ ejml (35458)
+ ext_tools (35640)
+ geotools (35458)
+ imagery-xml-bounds (35640)
+ jaxb (35543)
+ jna (35662)
+ jts (35458)
+ opendata (35640)
+ pdfimport (35640)
+ reverter (35688)
+ todo (30306)
+ utilsplugin2 (35691)

Tagging presets:
+ https://josm.openstreetmap.de/josmfile?page=Presets/LaneAttributes&zip=1
+ https://raw.githubusercontent.com/OpenNauticalChart/josm/master/INT-1-preset.xml

Map paint styles:
+ https://josm.openstreetmap.de/josmfile?page=Styles/Lane_and_Road_Attributes&zip=1
- https://raw.githubusercontent.com/OpenSeaMap/josm/master/CEVNI_MapCSS.mapcss
- https://raw.githubusercontent.com/OpenSeaMap/josm/master/INT1_Seamark.mapcss

Last errors/warnings:
- 02268.708 W: Not downloading all tiles because there is more than 18 tiles on an axis!
- 02268.861 W: Not downloading all tiles because there is more than 18 tiles on an axis!
- 02269.018 W: Not downloading all tiles because there is more than 18 tiles on an axis!
- 02269.181 W: Not downloading all tiles because there is more than 18 tiles on an axis!
- 02269.337 W: Not downloading all tiles because there is more than 18 tiles on an axis!
- 02269.486 W: Not downloading all tiles because there is more than 18 tiles on an axis!
- 02394.269 E: Failed to locate image 'https://www.kartverket.no/Content/Images/logo-graphic-512.png'
- 02409.297 W: java.net.SocketTimeoutException: Connect timed out
- 02409.298 W: Already here java.net.SocketTimeoutException: Connect timed out
- 02409.401 E: Failed to locate image 'http://openptmap.de/favicon_pt.png'

[GerdP]

Do you think the memory problems are caused by the WMS downloads?

[GerdP]

Right after asking this I got the memory problem without any editing, just downloading a bit of data and panning+ zooming in / out.

[nkamapper]

Replying to GerdP:

Do you think the memory problems are caused by the WMS downloads?

Yes, using WMS imagery is the only thing I do differently when this problem is occurring.

[GerdP]

So far I only found out that the large tile size also means more bytes for data that is downloaded but not visible. With 1024 instead of 512 the value is four times higher and thus it is more likely to hit the limit. The number of tiles in memory seems also to depend on the amount of view port changes (panning, zoom in/out) within a time period.
My assumption is that we have a situation where many tiles are downloaded for the first time and "waiting to be written to the disk cache" while more new tiles are downloaded. This alone seems to work well but maybe something goes wrong when network problems or other timeouts are involved. I wasn't able to reproduce the hang again so far, but I am still trying...

[GerdP]

@nkamapper
Another thing that is different to my machine:
Your report shows

Screen: Display 69733568 1440×900 (scaling 2.00×2.00)

Mine shows

Screen: \Display0 1920×1080 (scaling 1.00×1.00)

I don't know how to influence the "scaling", it might be important.

[nkamapper]

Replying to GerdP:

I don't know how to influence the "scaling", it might be important.

I could test, if I had known how to adjust "scaling"...

In daily work, however, #20443 is the biggest problem because it makes WMS unusable. Tile size 1024 was just an attempt to get around that problem.

[GerdP]

The "scaling" text is produced with this code:

            for (GraphicsDevice gd : GraphicsEnvironment.getLocalGraphicsEnvironment().getScreenDevices()) {
                text.append(" ").append(gd.getIDstring());
                DisplayMode dm = gd.getDisplayMode();
                if (dm != null) {
                    AffineTransform transform = gd.getDefaultConfiguration().getDefaultTransform();
                    // Java 11: use DisplayMode#toString
                    text.format(" %d\u00D7%d (scaling %.2f\u00D7%.2f)",
                            dm.getWidth(), dm.getHeight(), transform.getScaleX(), transform.getScaleY());
                }
            }

I assume that means that the setting is in the configuration for the video driver or the screen driver.

I think #20014 is also relevant.

[GerdP]

See #13173 reg. scaling.

[wiktorn]

In 17494/josm:

Remove unneeded WMS download threads.

Once the WMS layer is destroyed, remove threadpool, as it will never be GC as the
threads are alive.

Refactor fetching tiles from different zoom levels for easier debugging.

See: #20443, #20497

[wiktorn]

In 17495/josm:

Extend the size of MemoryTileCache

Include in the computations:

• all zoomOffsets that might be visited during paint
• overloadTiles() method that adds new tiles to be fetched

Merge tooLarge() and insane() method, as only tileCache size limit is sensible and resign from any
artificial limits.

See: #20014, #20497

[GerdP]

I still don't understand the idea behind overloadTiles(). My understanding is that it adds a big extra work, eg. if the normal code would download 4 x 3 = 12 tiles, the overload changes that to 6 x 5 = 30 tiles.

[wiktorn]

Replying to GerdP:

I still don't understand the idea behind overloadTiles(). My understanding is that it adds a big extra work, eg. if the normal code would download 4 x 3 = 12 tiles, the overload changes that to 6 x 5 = 30 tiles.

The idea behind overloadTiles() is that is loads the tile from the server that are around your viewpoint. So if you move, the tiles will be already there. Yes - it's generating more requests, but I'd say, that it gives far better user experience, as the tiles are already there.

[GerdP]

It might improve user experience for the case that you edit many details in a small area and stay in that area. I consider this a rare case. During the last weeks I've modified landuse areas. That means I zoom in and out often, I use Validator to find overlapping areas and other errors. I've configured JOSM to zoom to the coresponding objects when I select an error. So, my typical use pattern is to jump around within the downloaded data. I think it's rather unpredictable.

[GerdP]

I've just started to edit with r17496 and it behaves worse with TMS Bing layer. large delays after a rather short usage time. I see these messages:

2021-02-20 10:26:25.406 FINE: zoomChanged(): 18
2021-02-20 10:26:25.448 INFO: AbstractTileSourceLayer: estimated visible tiles: 88, estimated cache size: 704
2021-02-20 10:26:25.450 INFO: AbstractTileSourceLayer: estimated visible tiles: 88, estimated cache size: 704
2021-02-20 10:26:25.450 INFO: Allocate for tile source layer: 176 MB of memory. Available: 7,232 MB.
...
2021-02-20 10:44:53.555 FINE: TMS - Skipping job https://ecn.t1.tiles.virtualearth.net/tiles/a12020132022012.jpeg?g=10042 because host limit reached
2021-02-20 10:44:53.555 FINE: TMS - Skipping job https://ecn.t1.tiles.virtualearth.net/tiles/a1202013202023.jpeg?g=10042 because host limit reached
2021-02-20 10:44:53.555 FINE: TMS - Skipping job https://ecn.t1.tiles.virtualearth.net/tiles/a1202013202200.jpeg?g=10042 because host limit reached

I normally don't use -Xmx8G so I'll try again with my defaults.

[wiktorn]

@GerdP:

And can you say, what kind of the usage you've did? I've tried browsing with Bing quite a lot and it works good.

From my status report:

Memory Usage: 888 MB / 8178 MB (457 MB allocated, but free)
Java version: 11.0.1+13, Oracle Corporation, OpenJDK 64-Bit Server VM

Though I've started it with simple java -jar josm-custom.jar. Maybe I should consider checking with newer Java versions, as I was testing only with 8 and 11.

Tried with Java 15:

Memory Usage: 3408 MB / 8180 MB (860 MB allocated, but free)
Java version: 15.0.2+7, AdoptOpenJDK, OpenJDK 64-Bit Server VM

Also no problems. Looks like on my machine, JRE defaults to -XMx8G

[wiktorn]

I've chosen -Xmx1G, and it also worked, though I see, that there is no error message shown, when layer is not added due to the fact, that there is no memory available. It's listed in Layers, but it's not showing...

Anyway - with -Xmx2G, I can have Bing and Vertikalniva2 WMS layer open, and both works well.

[GerdP]

And can you say, what kind of the usage you've did? I've tried browsing with Bing quite a lot and it works good.

I loaded a gpx track from yesterdays bicycle ride and Bing layer and started to look at those points that I marked as fixmes. I guess this means a rather random access pattern. My machine only has 8 G physical memory so using -Xmx8G is not a good idea, it was a left over from yesterdays testing. It might still be a good idea to reproduce my problem. With -Xmx2G I don't see it. These are my status values with -Xmx2G (it's a local build with some patches, no relevant changes in the imagery area):

Is-Local-Build:true

Identification: JOSM/1.5 (17496 SVN en) Windows 10 64-Bit
OS Build number: Windows 10 Home 2004 (19041)
Memory Usage: 524 MB / 1820 MB (112 MB allocated, but free)
Java version: 1.8.0_272-b10, AdoptOpenJDK, OpenJDK 64-Bit Server VM
Look and Feel: com.sun.java.swing.plaf.windows.WindowsLookAndFeel

While writing this I noticed that I see again lots of the "because host limit reached" messages.

2021-02-20 11:39:46.640 FINE: TMS - Skipping job https://ecn.t1.tiles.virtualearth.net/tiles/a1202012313133332.jpeg?g=10042 because host limit reached
2021-02-20 11:39:46.657 FINE: TMS - Skipping job https://ecn.t3.tiles.virtualearth.net/tiles/a1202012313132321.jpeg?g=10042 because host limit reached
2021-02-20 11:39:46.657 FINE: TMS - Skipping job https://ecn.t1.tiles.virtualearth.net/tiles/a120201231331110.jpeg?g=10042 because host limit reached
2021-02-20 11:39:46.657 FINE: TMS - Skipping job https://ecn.t3.tiles.virtualearth.net/tiles/a120201231331130.jpeg?g=10042 because host limit reached
2021-02-20 11:39:46.657 FINE: TMS - Skipping job https://ecn.t2.tiles.virtualearth.net/tiles/a120201231313322.jpeg?g=10042 because host limit reached
2021-02-20 11:39:46.657 FINE: TMS - Skipping job https://ecn.t1.tiles.virtualearth.net/tiles/a120201231313233.jpeg?g=10042 because host limit reached
2021-02-20 11:39:46.657 FINE: TMS - Skipping job https://ecn.t2.tiles.virtualearth.net/tiles/a120201231331011.jpeg?g=10042 because host limit reached
2021-02-20 11:39:46.657 FINE: TMS - Skipping job https://ecn.t1.tiles.virtualearth.net/tiles/a12020123133111.jpeg?g=10042 because host limit reached
2021-02-20 11:39:46.657 FINE: TMS - Skipping job https://ecn.t2.tiles.virtualearth.net/tiles/a12020123133113.jpeg?g=10042 because host limit reached
2021-02-20 11:39:46.657 FINE: TMS - Skipping job https://ecn.t3.tiles.virtualearth.net/tiles/a12020123131332.jpeg?g=10042 because host limit reached
2021-02-20 11:39:46.657 FINE: TMS - Skipping job https://ecn.t2.tiles.virtualearth.net/tiles/a12020123131323.jpeg?g=10042 because host limit reached
2021-02-20 11:39:46.658 FINE: TMS - Skipping job https://ecn.t3.tiles.virtualearth.net/tiles/a12020123133101.jpeg?g=10042 because host limit reached
2021-02-20 11:39:46.658 FINE: TMS - Skipping job https://ecn.t3.tiles.virtualearth.net/tiles/a1202012313133.jpeg?g=10042 because host limit reached
2021-02-20 11:39:46.658 FINE: TMS - Skipping job https://ecn.t0.tiles.virtualearth.net/tiles/a1202012313311.jpeg?g=10042 because host limit reached
2021-02-20 11:39:46.658 FINE: TMS - Skipping job https://ecn.t2.tiles.virtualearth.net/tiles/a1202012313132.jpeg?g=10042 because host limit reached
2021-02-20 11:39:46.658 FINE: TMS - Skipping job https://ecn.t3.tiles.virtualearth.net/tiles/a1202012313310.jpeg?g=10042 because host limit reached
2021-02-20 11:39:46.658 FINE: TMS - Skipping job https://ecn.t0.tiles.virtualearth.net/tiles/a120201231313.jpeg?g=10042 because host limit reached
2021-02-20 11:39:46.658 FINE: TMS - Skipping job https://ecn.t1.tiles.virtualearth.net/tiles/a120201231331.jpeg?g=10042 because host limit reached
2021-02-20 11:39:46.658 FINE: TMS - Skipping job https://ecn.t0.tiles.virtualearth.net/tiles/a12020123131.jpeg?g=10042 because host limit reached

So, JOSM was in the background for a while and I switched to it to get the status report.

[skyper]

On Linux, by default, -Xmx is set to a percentage of the physical memory. Think it was 25 or 30%.

I`ve noticed long lags if there is no more physical memory available and therefore the system is using the swap.

[wiktorn]

Replying to GerdP:

While writing this I noticed that I see again lots of the "because host limit reached" messages.

2021-02-20 11:39:46.640 FINE: TMS - Skipping job https://ecn.t1.tiles.virtualearth.net/tiles/a1202012313133332.jpeg?g=10042 because host limit reached
2021-02-20 11:39:46.657 FINE: TMS - Skipping job https://ecn.t1.tiles.virtualearth.net/tiles/a12020123133111.jpeg?g=10042 because host limit reached

So, JOSM was in the background for a while and I switched to it to get the status report.

I'd worry about these messages. These are natural, when the number of requests that mapview tries to execute is larger than the limit. These tiles will get eventually loaded. And I'd avoid running with -Xmx set to same value as physical memory.

Replying to skyper:

On Linux, by default, -Xmx is set to a percentage of the physical memory. Think it was 25 or 30%.

It looks like. I've just tested on Linux with 4, 8 and 12GB, and Java default max memory was 1, 2, and 3GB. Looks pretty sane default. As far as I'm seeing on my Windows machine, I've also see there JVM allocating 25% of physical memory

I`ve noticed long lags if there is no more physical memory available and therefore the system is using the swap.

If heap spreads into swap then sluggishness in inevitable.

[GerdP]

@wiktorn
One small detail: The text in this log message

 AbstractTileSourceLayer: estimated visible tiles: 42, estimated cache size: 336

should be improved. It shows the number of "overloaded tiles" as "visible" tiles.

Reg. the debug info on the screen: My understanding is that the "Memory Cache" is always disabled with the current code as the size is 0. Why do we still calculate and display the debug info?

[GerdP]

FYI: I've edited now for nearly two hours with r17503 and haven't noticed any issues with the Bing TMS layer.

[wiktorn]

In 17504/josm:

Correct memory information

Correct message sent to logging when estimating cache size. Add rendering of the
message when memory allocation failed for drawing the layer.

See: #20497

[wiktorn]

Good to hear. The only drawback is, that we will require 4x more memory per imagery layer, just to cover most pessimistic scenario.

[GerdP]

With most pessimistic scenario you mean the activated "Viewport Following"?

[wiktorn]

Replying to GerdP:

With most pessimistic scenario you mean the activated "Viewport Following"?

Most pessimistic scenario, is that paint algorithm will need to visit all tiles from zoom levels -5 to +2 (relative to current zoom level) to paint the map view. Meaning, that at current zoom level there were no loaded tiles to paint, as well as zoomLevel +1 etc.

[wiktorn]

In 17507/josm:

Add documentation for changes from [17495]

Reverse links in code, so when changes will be applied in zoomOffsets or
overloadTiles comments will direct developer to estimateTileCacheSize to update
the computation there.

See: #20014, #20497

[wiktorn]

In 17516/josm:

Fine tune cache sizing

Reduce the cache size, by not counting the tiles that are overloaded for other
zoom levels. Overloaded tiles are only counted for current zoom level.

This reduces memory requirements for a layer, depending on the number of the
tiles shown by 20%-50%. Reduction is high for low number of tiles (when large
tiles or small screen is in use) and low for high number of tiles (when
small tiles or large screen is in use)

See: #20014, #20497

[wiktorn]

Can we consider this one closed?

[nkamapper]

Tested 17538, and I am not able to reproduce out-of-momory anymore.

[wiktorn]

Thank you, closing this ticket then.