Performance problems for WMS

[nkamapper]

Consider the WMS ​https://wms.geonorge.no/skwms1/wms.reguleringsplaner (for example "Vertikalniva2" layer), or any other of the Kartverket WMS services (Norway) in JOSM.

The result in JOSM is very frustrating. Lots of empty tiles and error messages (the error "Overforbruk på kort tid" means "Too many requests during short period").

The performance for the same imagery in QGIS is better. Could there be ways of improving the performance i JOSM?

[Gazer75]

There should be a setting to limit the number of calls made to a server for each imagery layer.
Kartverket (The Norwegian Mapping Authority) have set a pretty low limit to avoid servers getting hammered.

Some of this issue is a cache bug where JOSM ignore already cached tiles.

[Gazer75]

There should be a setting to limit the number of calls made to a server for each imagery layer.
Kartverket (The Norwegian Mapping Authority) have set a pretty low limit to avoid servers getting hammered.

Some of this issue is a cache bug where JOSM ignore already cached tiles.

[GerdP]

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.

[Gazer75]

That report will not give anything useful for this issue anyway. It's been happening for months if not years.
It is also OS independent and regardless of plugins used or whatever.

The problem is JOSM is hammering the WMS server with to many requests and that triggers the warning tiles instead of the actual image.

[GerdP]

We recently fixed such a problem, see #20207.

[Gazer75]

I also think part of the problem is #19004 but there really should be an option in settings to limit queries per second.

[nkamapper]

Here is the bug report.

What steps will reproduce the problem?

1. Go to Norway, in JOSM.
2. Open the WMS ​​https://wms.geonorge.no/skwms1/wms.reguleringsplaner (for example "Vertikalniva2" layer), or any other of the Kartverket WMS services) in JOSM.
3. Pan and zoom for a little while..

What is the expected result?

A proper rendering av the WMS content.

What happens instead?

Several problems:
i) Missing tiles.
ii) Flashing tiles (on and off) in disco fashion.
iii) Sometimes no rendering at all, needs a flush.
iv) After a while, for example when zooming in and out: error messages from the server "Overforbruk på kort tid" (eng: "Too many requests during short period"). May depend on the WMS selected.

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

Error messages below are for the "reguleringsplaner" WMS.

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 (5198 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:
- 00311.067 W: Not downloading all tiles because there is more than 18 tiles on an axis!
- 00311.081 W: Not downloading all tiles because there is more than 18 tiles on an axis!
- 00311.137 E: [99][Interceptor]
- 00311.151 W: Not downloading all tiles because there is more than 18 tiles on an axis!
- 00311.164 W: Not downloading all tiles because there is more than 18 tiles on an axis!
- 00311.307 W: Not downloading all tiles because there is more than 18 tiles on an axis!
- 00311.360 W: Not downloading all tiles because there is more than 18 tiles on an axis!
- 00311.375 W: Not downloading all tiles because there is more than 18 tiles on an axis!
- 00311.451 W: Not downloading all tiles because there is more than 18 tiles on an axis!
- 00311.463 W: Not downloading all tiles because there is more than 18 tiles on an axis!

[nkamapper]

By the way, this problem is not related to Kartverket/Norway only. The tiles are also flashing disco style for example when viewing the standard orthophotos in JOSM for Gothenburg, Sweden.

[GerdP]

Do you also see that with a clean installation?

[nkamapper]

Replying to GerdP:

Do you also see that with a clean installation?

Hm, what is the best way to get a clean installation?

[GerdP]

Either use an option to tell JOSM were it should create its (new) home directory like this:
java -Djosm.home=/home/user/.josm_dev -jar josm-tested.jar
or stop JOSM, rename the existing preferences.xml and start JOSM (later reverse that)

[nkamapper]

I tested with a clean installation. Performance is better initially, then seems to become worse after prolonged usage.

[Gazer75]

I've noticed extremely sluggish performance after a while in JOSM as well. The more layers you have used the faster the performance drops I feel.
Panning around or placing nodes to form a way becomes really laggy. At the same time CPU load has dropped a lot as well.

My i5 3570K is pretty old at this point, but at the start of a session panning can easily use 25-50% (1-2 cores), but when it starts getting laggy the same panning around is down to like 10-15%.

Not sure if this info helps at all...

[GerdP]

Seems none of the expert is working on this so I'll try to find something. I can reproduce strange behaviour like JCSCachedTileLoaderJob still producing timeout error messages after removing all image layers:

2021-02-10 10:53:59.827 WARNING: java.net.SocketTimeoutException: Read timed out. Cause: java.net.SocketTimeoutException: Read timed out
java.net.SocketTimeoutException: Read timed out
	at sun.reflect.GeneratedConstructorAccessor77.newInstance(Unknown Source)
	at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
	at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
	at sun.net.www.protocol.http.HttpURLConnection$10.run(HttpURLConnection.java:1950)
	at sun.net.www.protocol.http.HttpURLConnection$10.run(HttpURLConnection.java:1945)
	at java.security.AccessController.doPrivileged(Native Method)
	at sun.net.www.protocol.http.HttpURLConnection.getChainedException(HttpURLConnection.java:1944)
	at sun.net.www.protocol.http.HttpURLConnection.getInputStream0(HttpURLConnection.java:1514)
	at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1498)
	at java.net.HttpURLConnection.getResponseCode(HttpURLConnection.java:480)
	at sun.net.www.protocol.https.HttpsURLConnectionImpl.getResponseCode(HttpsURLConnectionImpl.java:352)
	at org.openstreetmap.josm.tools.Http1Client$1.getResponseCode(Http1Client.java:94)
	at org.openstreetmap.josm.tools.HttpClient.connect(HttpClient.java:152)
	at org.openstreetmap.josm.tools.HttpClient.connect(HttpClient.java:124)
	at org.openstreetmap.josm.data.cache.JCSCachedTileLoaderJob.loadObject(JCSCachedTileLoaderJob.java:315)
	at org.openstreetmap.josm.data.cache.JCSCachedTileLoaderJob.run(JCSCachedTileLoaderJob.java:226)
	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.net.SocketTimeoutException: Read timed out
	at java.net.SocketInputStream.socketRead0(Native Method)
	at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
	at java.net.SocketInputStream.read(SocketInputStream.java:171)
	at java.net.SocketInputStream.read(SocketInputStream.java:141)
	at sun.security.ssl.SSLSocketInputRecord.read(SSLSocketInputRecord.java:457)
	at sun.security.ssl.SSLSocketInputRecord.bytesInCompletePacket(SSLSocketInputRecord.java:68)
	at sun.security.ssl.SSLSocketImpl.readApplicationRecord(SSLSocketImpl.java:1095)
	at sun.security.ssl.SSLSocketImpl.access$200(SSLSocketImpl.java:72)
	at sun.security.ssl.SSLSocketImpl$AppInputStream.read(SSLSocketImpl.java:815)
	at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
	at java.io.BufferedInputStream.read1(BufferedInputStream.java:286)
	at java.io.BufferedInputStream.read(BufferedInputStream.java:345)
	at sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:735)
	at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:678)
	at sun.net.www.protocol.http.HttpURLConnection.getInputStream0(HttpURLConnection.java:1593)
	at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1498)
	at sun.net.www.protocol.http.HttpURLConnection.getHeaderField(HttpURLConnection.java:3097)
	at sun.net.www.protocol.https.HttpsURLConnectionImpl.getHeaderField(HttpsURLConnectionImpl.java:313)
	at org.openstreetmap.josm.tools.Http1Client$1.getResponseVersion(Http1Client.java:85)
	... 7 more

2021-02-10 10:53:59.827 FINE: JCS - IOException during communication with server for: https://mapy.geoportal.gov.pl/wss/service/img/guest/ORTO/MapServer/WMSServer?LAYERS=Raster&STYLES=default&FORMAT=image/jpeg&CRS=EPSG:3857&WIDTH=512&HEIGHT=512&BBOX=2269873.9919566,6809621.9758698,2348145.5089206,6887893.4928338&VERSION=1.3.0&SERVICE=WMS&REQUEST=GetMap
2021-02-10 10:53:59.827 FINE: tileLoadingFinished() tile: Tile 10/285/168@Geoportal 2: Orthophotomap (aerial image) WMS [ERROR] success: false

Up to now I don't see that the disk cache works, it seems it always returns a miss.

[GerdP]

Hmm, something strange happened. The disk cache didn't work as expected for me as for each new session all images were downloaded again. To verify this I changed the location of the cache and from that point on this problem was gone. I changed back to the original directory but the problem is still not reproducable.

[nkamapper]

Thank you for looking into this problem. Currently, WMS in JOSM is unusable.

[wiktorn]

@nkmapper:

can you please elaborate how can I reproduce this issue? Maybe - try running JOSM with --debug option, like:

java -jar josm-test.jar --debug

This will show some debug information on the map regarding cache.

Please observe:

• third line starting with "Cache stats" - "HitCountAux" - this is the number of tiles fetched from the disk
• under --- Block disk cache section, Key Map Size - number of objects in the cache

I did some testing and I can't confirm any performance issues. After going through ~2500 tiles, no significant changes in speed, nor in memory usage. Though I did observe:

• endless loops of displaying the tiles (which may result in "disco mode")
• some tiles that didn't load (though right-click + load did load it without problem)
• some tiles rendered with "Overforbruk på kort tid" message, but I don't consider that a JOSM error, and for me - it occured quite rarely.

My WMS settings are:

• max 3 simultaneus connections
• tile size: 1024
• tile offset: 0

If there is some sluggish performance as well after panning, please:

• clear WMS cache
• add necesary number of layers to reproduce the issue
• report Key Map Size for Block Disk Cache when the problem is apparent

Then I'll know, how long I need to pan to notice the problem ;-)

And as for the last comment, I see that on restart, there were some HTTP calls executed, although all tiles were returned from cache and displayed correctly. This may indicate that there are some extraneous request made. I'll investigate that while waiting for the answers.

EDIT: And can you provide information, how much physical memory you have? 8GB is allocated to JOSM out of how many?

[GerdP]

@wiktorn: Thanks for looking into this. I've also seen strange results, but as wrote before I wasn't able to reproduce.
Found one minor leak so far: If you close a WMS layer the correspondings WMS threads are not "killed". If you open a new layer new additional threads are started. No idea if this is part of the problem.
In VisualVM I can see that the "used memory" can jump up by 1GB within a second if I press +and - frequently. With tile size 1024 this memory is allocated for 3MB byte arrays tile size 1024x1024x3), but the objects are normally freed within a few seconds.

[wiktorn]

Accidentally I did some bisecting and compared how [17401] works compared to [17491], and I see difference in how many attempts there are to download tiles (though all tiles are served from cache).

My test scenario was:

1. to download the area (I choose Gvarv, Coordinates: 59.387985, 9.174528)
2. "zoom to data"
3. Add Vertikalniva2 imagery layer

I first primed the cache, and all results are from subsequent runs, on each I started JOSM freshly. All tests were made with tile size = 1024.

I noted how many tiles were downloaded on each tile zoom. Display tile zoom in my case was 13:

zoom	[17401]	[17491]
8	1	1
9	1	1
10	2	2
11	3	4
12	3	6
13	14	53

Just for context, my screen was showing 4 tiles horizontally, 2 vertically. I have 2560x1440 screen.

The slight increase in number of tiles download on zoom levels 8-12 might be explained by some other changes that I'm not familiar with, but this looks OK'ish. Though what happens on level 13 is worrying:

• for 18 tiles download is executed twice
• for 17 tiles download is executed only once

This it self shouldn't generate extra requests towards the imagery provider as requests for same tile should be handled by one request. Though this may impact the performance of application.

I've also checked, how it looks regarding downloading the tiles (only on [17491]) and it looks like during download, only 32 HTTP requests were invoked, though - only 30 tiles requests (2 tiles were downloaded twice!)

@GerdP - are you aware of any changes, that could result in such change?

[GerdP]

are you aware of any changes, that could result in such change?

The only obvious candidate is r17402 : Refuse to download tiles if the tileset is too large
See also ticket:20014#comment:22

[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]

@nkmapper:

Can you please check, if [17496] helps you with issues you're experiencing? At least it should help for:

• endless loops of displaying the tiles (which may result in "disco mode")

And also, hopefully also for (I haven't noticed that as I was testing):

• some tiles that didn't load (though right-click + load did load it without problem)

[nkamapper]

Replying to wiktorn:

Can you please check, if [17496] helps you with issues you're experiencing?

I will. 17494 seems to be the latest I can download, so may have to wait a bit.

[skyper]

Replying to wiktorn:

And also, hopefully also for (I haven't noticed that as I was testing):

• some tiles that didn't load (though right-click + load did load it without problem)

Oh, I have notice this issue, too.

Replying to nkamapper:

Replying to wiktorn:

Can you please check, if [17496] helps you with issues you're experiencing?

I will. 17494 seems to be the latest I can download, so may have to wait a bit.

Have a look at jenkins.

[nkamapper]

Replying to wiktorn:

@nkmapper:
can you please elaborate how can I reproduce this issue? Maybe - try running JOSM with --debug option

I do not have JDK so was not able to log. However the problems appear already after a few seconds and does not improve after clearing tile cache and restart. Testing with 17428 (Mac bundle), 1024 tiles, 3 connections and imagery "N50 topo" + "Norway orthophotos (more recent, more zoom)". Panning and zooming over various parts of Norway, no editing. With "problems" I mean:

• Sluggish tile loading (2-10 seconds)
• Disco mode
• Missing tiles
• "Overforbruk på kort tid" error message (fewer than usual today, but more than in QGIS).
• High CPU utilization, busy fan

When adding two more WMS (the "Reguleringsplaner" WMS mentioned earlier + "Address overlay"), JOSM is out of memory after about 15 minutes (8GB).

[wiktorn]

I gave a try macOS package and it looks like it always allocates 8GB heap. It might be not the best approach, especially in memory constrained stations.

@nkmapper how much physical memory your system has?

[nkamapper]

Replying to wiktorn:

@nkmapper how much physical memory your system has?

16GB

[wiktorn]

Replying to nkamapper:

When adding two more WMS (the "Reguleringsplaner" WMS mentioned earlier + "Address overlay"), JOSM is out of memory after about 15 minutes (8GB).

I was browsing on macOS Reguleringsplaner for 15 minutes, ~3150 tiles were downloaded and haven't noticed any memory issues.

Status report show 1200MB/8192MB used.

I tried to play also with address overlay (Kartverket Address overlay) and there is some way and one thing I've noticed, is that in the definition there is this section:

        <min-zoom>19</min-zoom>
        <max-zoom>24</max-zoom>

It means, that if browsing at zoom level of 19, it already has quite a lot of tiles on the screen, and even at zoom level 18, there is much to many to download.

The tile info shows, that after reprojection from EPSG:27391 to EPSG:3857 their size is only 226x225. The Regulersingsplanner on the other hand works in native resolution of EPSG:3857.

Both of the tiles, show the errors of "too many requests" and I fear, that they may share the counters. Browsing Kartveket Address overlay will generate a lot of requests.

@nkamapper:
Which projection do you use and if you use EPSG:3857, can you change to one also supported by address overlay? Like UTM zone 32 or any other listed here (you can select them by code):

<projections>
            <code>EPSG:27391</code><code>EPSG:27392</code><code>EPSG:27393</code><code>EPSG:27394</code><code>EPSG:27395</code><code>EPSG:27396</code><code>EPSG:27397</code><code>EPSG:27398</code>
            <code>EPSG:32632</code><code>EPSG:32633</code><code>EPSG:32634</code><code>EPSG:32635</code><code>EPSG:32636</code>
        </projections>

And check if this helps you with the problem of errors during loading of the tiles (it will not solve the problem, but may make it less inconvenient).

The best would be, if you could test already the version [17496], together with other fixes. This should be available tomorrow, if you want to avoid installing Java.

[nkamapper]

I tested 17500 this morning. Tested the Ortho WMS, DTM and Address overlay with 512 og 1024 tile size. Big improvement! Disco is gone. Quicker loading. Was not able to run out of memory.

Heavy CPU load and busy fan with a lot of continuoues zooming/panning of DTM but no crash.

The Address overlay WMS is now showing text (earlier was often empty), but it is producing more "Overforbruk" error messages than I have every seen before. No difference between UTM and 3857. I get crazy many error messages at zoom 15 and 16. Why is JOSM loading tiles at those zoom levels when they are only available from zoom 19?

The orthos tends to get stuck at certain tiles/zoom levels (with high pixelation) and require manual reloading. Is there a way JOSM could discover this and reload automatically when that tile is revisited? Would be a lot more convenient when zooming in/out frequently at a location, which is a typical use case.

[wiktorn]

Replying to nkamapper:

The Address overlay WMS is now showing text (earlier was often empty), but it is producing more "Overforbruk" error messages than I have every seen before. No difference between UTM and 3857. I get crazy many error messages at zoom 15 and 16. Why is JOSM loading tiles at those zoom levels when they are only available from zoom 19?

This is to properly support situations, where there a mi-nzoom between 1-5, and to use tiles from first available zoom when showing the world. In such case as this, I'd think about disabling the download at all if the current zoom level is not matching min-zoom of the layer as the result is a lot of queries and poor performance.

The orthos tends to get stuck at certain tiles/zoom levels (with high pixelation) and require manual reloading. Is there a way JOSM could discover this and reload automatically when that tile is revisited? Would be a lot more convenient when zooming in/out frequently at a location, which is a typical use case.

What I can do here, is to not cache on disk such tiles and when the user returns to the place, there will be another try to download.

What I do not want to do here is to do condition-less retry, as it would hammer the servers with requests. And in case of these servers, it would probably result in endless errors returned. If I understand correctly, the failing requests are also counted against the quota.

[wiktorn]

In 17505/josm:

Do not cache responses, that are not images.

When server returns content type and it's not an image, then do not put it into
cache and try to extract error message from response.

That way, errors will not be stored in on-disk cache and hopefully they will be
retried when user browses again to the same area (modulo MemoryTileCache).

See: #20443

[wiktorn]

Can we consider this one closed?

[nkamapper]

I have tested 17538 with the Orthophoto, Address, Cadastral and Building services. The only problem left now is a large number of "Overforbruk" error messages outside of the min-zoom/max-zoom intervals, indicating that too many requests are sent to the server.

[wiktorn]

Thank you, closing this ticket.

For failures when loading the tiles, solution for #20014 might improve the situation

[skyper]

Replying to nkamapper:

I have tested 17538 with the Orthophoto, Address, Cadastral and Building services. The only problem left now is a large number of "Overforbruk" error messages outside of the min-zoom/max-zoom intervals, indicating that too many requests are sent to the server.

Indeed, much better now, thanks. Me too are noticing problems when beyond max-zoom.