Modify

Opened 3 years ago

Closed 3 years ago

Last modified 3 years ago

#20207 closed defect (fixed)

[Patch] JOSM unresponsive, tries to load tiles for zoom level that is not supported

Reported by: nkamapper Owned by: team
Priority: critical Milestone: 20.12
Component: Core Version:
Keywords: template_report, jcs, regression Cc: Don-vip, wiktorn, stoecker

Description

What steps will reproduce the problem?

I have not been able to discover specifically what causes the problem.
First seen on v17329, now also on 17084.
Same problem on iMac and MacBook.

What is the expected result?

Normal operation.

What happens instead?

JOSM eventually becomes unresponsive after an hour or so of editing. Must force termination.
Activity monitor on Mac reporting >300% CPU for JOSM.

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

URL:https://josm.openstreetmap.de/svn/trunk
Repository:UUID: 0c6e7542-c601-0410-84e7-c038aed88b3b
Last:Changed Date: 2020-10-03 13:42:38 +0200 (Sat, 03 Oct 2020)
Build-Date:2020-10-04 01:30:47
Revision:17084
Relative:URL: ^/trunk

Identification: JOSM/1.5 (17084 en_GB) Mac OS X 10.15.7
OS Build number: Mac OS X 10.15.7 (19H2)
Memory Usage: 3870 MB / 3870 MB (977 MB allocated, but free)
Java version: 1.8.0_271-b09, Oracle Corporation, Java HotSpot(TM) 64-Bit Server VM
Look and Feel: com.apple.laf.AquaLookAndFeel
Screen: Display 69733568 1440x900 (scaling 1.0x1.0)
Maximum Screen Size: 1440x900
Best cursor sizes: 16x16 -> 16x16, 32x32 -> 32x32
Dataset consistency test: No problems found

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

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:
- 14987.301 E: [99][Interceptor]
- 14987.302 E: [99][Interceptor]
- 14987.303 E: [99][Interceptor]
- 14987.303 E: [99][Interceptor]
- 14987.304 E: [99][Interceptor]
- 14987.305 E: [99][Interceptor]
- 14987.305 E: [99][Interceptor]
- 14987.306 E: [99][Interceptor]
- 14987.307 E: [99][Interceptor]
- 14987.307 E: [99][Interceptor]

Attachments (2)

small-part-of-norway.osm (151.5 KB ) - added by GerdP 3 years ago.
20207.patch (1.7 KB ) - added by GerdP 3 years ago.
revert changes from #18193

Download all attachments as: .zip

Change History (29)

comment:1 by nkamapper, 3 years ago

It could be related to validation, but I have too few observations to be certain.

comment:2 by GerdP, 3 years ago

My guess is a combination of memory leaks and validation.
You can try to use VisualVm to get more details. It allows to look "into" the java program while its running and shows where CPU is used: http://visualvm.github.io/
Quick guide: after installation, start JOSM and Visual VM. In VisualVM, select the JOSM program so that it tracks the activities. Next, do your normal work with JOSM and once it starts to be unresponsive, use VisualVM , click on the Sampler tab and then on CPU button. Wait a few secs and press stop. Now you can click through the trees to find out which routines are doing most of the work.

comment:3 by nkamapper, 3 years ago

I think I have been able to reproduce the problem:

1) Open a background imagery, for example Carto
2) Zoom in to Norway and open the "Kartverket Address overlay" WMS
3) Pan and zoom actively for 1-2 minutes
4) JOSM freezes

The "Kartverket Place Names overlay" WMS seems to create the same problem, while for example the "Kartverket Cadastral overlay" does not (at least not alone).

comment:4 by GerdP, 3 years ago

OK, I can reproduce this. When I open that background image while a large part of Norway is visible JOSM stops to respond, CPU cores are very busy in org.openstreetmap.josm.tools.Http1Client$1.getResponseVersion() which calls
sun.net.www.protocol.https.HttpsURLConnectionImpl.getHeaderField(). Console shows

D:\portable_prgs\josm>java.exe  -Xmx2G -Xms128M  -jar "d:\portable_prgs\JOSM\josm-tested.jar"
2020-12-08 22:05:53.938 INFORMATION: Protokollierungsgrad ist bei INFORMATION (INFO, 800)
2020-12-08 22:05:58.455 INFO: loading plugin 'jaxb' (version 35543)
2020-12-08 22:06:01.257 INFO: GET https://api.openstreetmap.org/api/0.6/user/details -> HTTP/1.1 200 (401 ms; 844 B)
2020-12-08 22:06:03.595 INFO: Obtained 80 Tag2Link rules from resource://META-INF/resources/webjars/tag2link/2020.10.18/index.json
2020-12-08 22:06:09.967 WARNING: Warning - <html>Plugin pbf requires JOSM version 17334. The current JOSM version is 17329.<br>You have to update JOSM in order to use this plugin.</html>
2020-12-08 22:06:12.754 INFO: loading plugin 'reverter' (version 35640)
2020-12-08 22:06:12.845 INFO: RemoteControl: adding command "revert_changeset" (handled by RevertChangesetHandler)
2020-12-08 22:06:12.847 INFO: loading plugin 'apache-commons' (version 35524)
2020-12-08 22:06:12.851 INFO: loading plugin 'jts' (version 35458)
2020-12-08 22:06:12.873 INFO: loading plugin 'jna' (version 35662)
2020-12-08 22:06:13.041 INFO: loading plugin 'ejml' (version 35458)
2020-12-08 22:06:13.048 INFO: loading plugin 'geotools' (version 35458)
2020-12-08 22:06:13.677 INFO: Warp/affine reduction enabled: true
2020-12-08 22:06:15.110 INFO: loading plugin 'utilsplugin2' (version 35671)
2020-12-08 22:06:15.389 INFO: loading plugin 'o5m' (version 35640)
2020-12-08 22:06:15.409 INFO: loading plugin 'opendata' (version 35640)
2020-12-08 22:06:15.488 INFO: loading plugin 'measurement' (version 35640)
2020-12-08 22:06:15.496 INFO: loading plugin 'continuosDownload' (version 91)
2020-12-08 22:06:15.529 INFO: Reassigning shortcut 'continuosdownload:activate' from null to 640 because of conflict with Alt+Shift+D
2020-12-08 22:06:15.532 INFO: Silent shortcut conflict: 'continuosdownload:activate' moved by 'file:download_along' to 'Ctrl+Alt+F1'.
2020-12-08 22:06:15.552 INFO: loading plugin 'poly' (version 35640)
2020-12-08 22:06:15.571 INFO: loading plugin 'undelete' (version 35640)
2020-12-08 22:06:15.683 INFO: loading plugin 'buildings_tools' (version 35669)
2020-12-08 22:06:16.241 INFO: RemoteControl::Accepting remote connections on /0:0:0:0:0:0:0:1:8111
2020-12-08 22:06:16.244 INFO: RemoteControl::Accepting remote connections on /127.0.0.1:8111
2020-12-08 22:06:16.244 INFO: Message notifier active (checks every 5 minutes)
2020-12-08 22:06:16.286 INFO: Changeset updater active (checks every 60 minutes if open changesets have been closed)
2020-12-08 22:06:16.461 INFO: GET https://api.openstreetmap.org/api/0.6/user/details (get number of unread messages) -> HTTP/1.1 200 (212 ms; 844 B)
2020-12-08 22:06:28.238 INFO: AbstractTileSourceLayer: estimated visible tiles: 54, estimated cache size: 216
2020-12-08 22:06:28.344 INFO: AbstractTileSourceLayer: estimated visible tiles: 54, estimated cache size: 216
2020-12-08 22:06:28.345 INFO: AbstractTileSourceLayer: estimated visible tiles: 54, estimated cache size: 216
2020-12-08 22:06:28.346 INFO: Allocate for tile source layer: 54 MB of memory. Available: 1,770 MB.
2020-12-08 22:06:28.796 INFO: GET https://b.tile.openstreetmap.org/14/8576/5346.png -> HTTP/1.1 200 (361 ms; 12.3 kB)
....
2020-12-08 22:08:59.568 INFO: GET https://wms.geonorge.no/skwms1/wms.matrikkel.seeiendom2?SERVICE=WMS&VERSION=1.1.1&REQUEST=GetMap&FORMAT=image/png&TRANSPARENT=true&LAYERS=matrikkel:MATRIKKELADRESSEWFS,matrikkel:VEGADRESSEWFS&STYLES=&SRS=EPSG:27391&WIDTH=512&HEIGHT=512&BBOX=-64359.0363596,590559.4622936,-64206.1623031,590712.3363502 -> HTTP/1.1 200 (10.3 s; 6.57 kB)
2020-12-08 22:09:04.852 INFO: GET https://wms.geonorge.no/skwms1/wms.matrikkel.seeiendom2?SERVICE=WMS&VERSION=1.1.1&REQUEST=GetMap&FORMAT=image/png&TRANSPARENT=true&LAYERS=matrikkel:MATRIKKELADRESSEWFS,matrikkel:VEGADRESSEWFS&STYLES=&SRS=EPSG:27391&WIDTH=512&HEIGHT=512&BBOX=-64359.0363596,590100.8401239,-64206.1623031,590253.7141804 -> HTTP/1.1 200 (7.6 s; 6.57 kB)
2020-12-08 22:09:04.853 INFO: GET https://wms.geonorge.no/skwms1/wms.matrikkel.seeiendom2?SERVICE=WMS&VERSION=1.1.1&REQUEST=GetMap&FORMAT=image/png&TRANSPARENT=true&LAYERS=matrikkel:MATRIKKELADRESSEWFS,matrikkel:VEGADRESSEWFS&STYLES=&SRS=EPSG:27391&WIDTH=512&HEIGHT=512&BBOX=-64359.0363596,589947.9660673,-64206.1623031,590100.8401239 -> HTTP/1.1 200 (2.7 s; 6.57 kB)
2020-12-08 22:09:08.699 INFO: GET https://wms.geonorge.no/skwms1/wms.matrikkel.seeiendom2?SERVICE=WMS&VERSION=1.1.1&REQUEST=GetMap&FORMAT=image/png&TRANSPARENT=true&LAYERS=matrikkel:MATRIKKELADRESSEWFS,matrikkel:VEGADRESSEWFS&STYLES=&SRS=EPSG:27391&WIDTH=512&HEIGHT=512&BBOX=-64359.0363596,589795.0920107,-64206.1623031,589947.9660673 -> HTTP/1.1 200 (2.5 s; 6.57 kB)
2020-12-08 22:09:11.960 INFO: GET https://wms.geonorge.no/skwms1/wms.matrikkel.seeiendom2?SERVICE=WMS&VERSION=1.1.1&REQUEST=GetMap&FORMAT=image/png&TRANSPARENT=true&LAYERS=matrikkel:MATRIKKELADRESSEWFS,matrikkel:VEGADRESSEWFS&STYLES=&SRS=EPSG:27391&WIDTH=512&HEIGHT=512&BBOX=-64359.0363596,589642.2179542,-64206.1623031,589795.0920107 -> HTTP/1.1 200 (1.6 s; 6.57 kB)
2020-12-08 22:09:18.859 INFO: GET https://wms.geonorge.no/skwms1/wms.matrikkel.seeiendom2?SERVICE=WMS&VERSION=1.1.1&REQUEST=GetMap&FORMAT=image/png&TRANSPARENT=true&LAYERS=matrikkel:MATRIKKELADRESSEWFS,matrikkel:VEGADRESSEWFS&STYLES=&SRS=EPSG:27391&WIDTH=512&HEIGHT=512&BBOX=-64359.0363596,589489.3438976,-64206.1623031,589642.2179542 -> HTTP/1.1 200 (1.1 s; 6.57 kB)
2020-12-08 22:09:23.027 INFO: GET https://wms.geonorge.no/skwms1/wms.matrikkel.seeiendom2?SERVICE=WMS&VERSION=1.1.1&REQUEST=GetMap&FORMAT=image/png&TRANSPARENT=true&LAYERS=matrikkel:MATRIKKELADRESSEWFS,matrikkel:VEGADRESSEWFS&STYLES=&SRS=EPSG:27391&WIDTH=512&HEIGHT=512&BBOX=-64359.0363596,589336.4698410,-64206.1623031,589489.3438976 -> HTTP/1.1 200 (5.3 s; 6.57 kB)
2020-12-08 22:09:29.491 INFO: GET https://wms.geonorge.no/skwms1/wms.matrikkel.seeiendom2?SERVICE=WMS&VERSION=1.1.1&REQUEST=GetMap&FORMAT=image/png&TRANSPARENT=true&LAYERS=matrikkel:MATRIKKELADRESSEWFS,matrikkel:VEGADRESSEWFS&STYLES=&SRS=EPSG:27391&WIDTH=512&HEIGHT=512&BBOX=-64359.0363596,589183.5957845,-64206.1623031,589336.4698410 -> HTTP/1.1 200 (10.6 s; 6.57 kB)
2020-12-08 22:09:31.489 INFO: GET https://wms.geonorge.no/skwms1/wms.matrikkel.seeiendom2?SERVICE=WMS&VERSION=1.1.1&REQUEST=GetMap&FORMAT=image/png&TRANSPARENT=true&LAYERS=matrikkel:MATRIKKELADRESSEWFS,matrikkel:VEGADRESSEWFS&STYLES=&SRS=EPSG:27391&WIDTH=512&HEIGHT=512&BBOX=-64359.0363596,589030.7217279,-64206.1623031,589183.5957845 -> HTTP/1.1 200 (4.2 s; 6.57 kB)
2020-12-08 22:09:53.452 INFO: GET https://wms.geonorge.no/skwms1/wms.matrikkel.seeiendom2?SERVICE=WMS&VERSION=1.1.1&REQUEST=GetMap&FORMAT=image/png&TRANSPARENT=true&LAYERS=matrikkel:MATRIKKELADRESSEWFS,matrikkel:VEGADRESSEWFS&STYLES=&SRS=EPSG:27391&WIDTH=512&HEIGHT=512&BBOX=-64359.0363596,588877.8476713,-64206.1623031,589030.7217279 -> HTTP/1.1 200 (15.5 s; 6.57 kB)
2020-12-08 22:09:55.288 INFO: GET https://wms.geonorge.no/skwms1/wms.matrikkel.seeiendom2?SERVICE=WMS&VERSION=1.1.1&REQUEST=GetMap&FORMAT=image/png&TRANSPARENT=true&LAYERS=matrikkel:MATRIKKELADRESSEWFS,matrikkel:VEGADRESSEWFS&STYLES=&SRS=EPSG:27391&WIDTH=512&HEIGHT=512&BBOX=-64359.0363596,588724.9736147,-64206.1623031,588877.8476713 -> HTTP/1.1 200 (8.4 s; 6.57 kB)
2020-12-08 22:09:57.144 INFO: GET https://wms.geonorge.no/skwms1/wms.matrikkel.seeiendom2?SERVICE=WMS&VERSION=1.1.1&REQUEST=GetMap&FORMAT=image/png&TRANSPARENT=true&LAYERS=matrikkel:MATRIKKELADRESSEWFS,matrikkel:VEGADRESSEWFS&STYLES=&SRS=EPSG:27391&WIDTH=512&HEIGHT=512&BBOX=-64359.0363596,588572.0995582,-64206.1623031,588724.9736147 -> HTTP/1.1 200 (10.3 s; 6.57 kB)
2020-12-08 22:10:06.458 INFO: GET https://wms.geonorge.no/skwms1/wms.matrikkel.seeiendom2?SERVICE=WMS&VERSION=1.1.1&REQUEST=GetMap&FORMAT=image/png&TRANSPARENT=true&LAYERS=matrikkel:MATRIKKELADRESSEWFS,matrikkel:VEGADRESSEWFS&STYLES=&SRS=EPSG:27391&WIDTH=512&HEIGHT=512&BBOX=-64359.0363596,588419.2255016,-64206.1623031,588572.0995582 -> HTTP/1.1 200 (3.5 s; 6.57 kB)
2020-12-08 22:10:09.459 INFO: GET https://wms.geonorge.no/skwms1/wms.matrikkel.seeiendom2?SERVICE=WMS&VERSION=1.1.1&REQUEST=GetMap&FORMAT=image/png&TRANSPARENT=true&LAYERS=matrikkel:MATRIKKELADRESSEWFS,matrikkel:VEGADRESSEWFS&STYLES=&SRS=EPSG:27391&WIDTH=512&HEIGHT=512&BBOX=-64359.0363596,588266.3514450,-64206.1623031,588419.2255016 -> HTTP/1.1 200 (5.1 s; 6.57 kB)
2020-12-08 22:10:17.137 INFO: GET https://wms.geonorge.no/skwms1/wms.matrikkel.seeiendom2?SERVICE=WMS&VERSION=1.1.1&REQUEST=GetMap&FORMAT=image/png&TRANSPARENT=true&LAYERS=matrikkel:MATRIKKELADRESSEWFS,matrikkel:VEGADRESSEWFS&STYLES=&SRS=EPSG:27391&WIDTH=512&HEIGHT=512&BBOX=-64359.0363596,588113.4773885,-64206.1623031,588266.3514450 -> HTTP/1.1 200 (10.7 s; 6.57 kB)

Exception: java.lang.OutOfMemoryError thrown from the UncaughtExceptionHandler in thread "WMS-downloader-0"
2020-12-08 22:11:28.011 INFO: GET https://wms.geonorge.no/skwms1/wms.matrikkel.seeiendom2?SERVICE=WMS&VERSION=1.1.1&REQUEST=GetMap&FORMAT=image/png&TRANSPARENT=true&LAYERS=matrikkel:MATRIKKELADRESSEWFS,matrikkel:VEGADRESSEWFS&STYLES=&SRS=EPSG:27391&WIDTH=512&HEIGHT=512&BBOX=-64359.0363596,587654.8552188,-64206.1623031,587807.7292753 -> !!! (43.3 s)
2020-12-08 22:11:30.496 WARNING: javax.net.ssl.SSLException: Server key. Cause: java.security.InvalidKeyException: No installed provider supports this key: sun.security.rsa.RSAPublicKeyImpl. Cause: java.security.NoSuchAlgorithmException: Error constructing implementation (algorithm: SHA512withRSA, provider: SunRsaSign, class: sun.security.rsa.RSASignature$SHA512withRSA). Cause: java.lang.OutOfMemoryError: GC overhead limit exceeded
javax.net.ssl.SSLException: Server key
        at sun.security.ssl.Handshaker.throwSSLException(Unknown Source)
        at sun.security.ssl.ClientHandshaker.processMessage(Unknown Source)
        at sun.security.ssl.Handshaker.processLoop(Unknown Source)
        at sun.security.ssl.Handshaker.process_record(Unknown Source)
        at sun.security.ssl.SSLSocketImpl.readRecord(Unknown Source)
        at sun.security.ssl.SSLSocketImpl.performInitialHandshake(Unknown Source)
        at sun.security.ssl.SSLSocketImpl.startHandshake(Unknown Source)
        at sun.security.ssl.SSLSocketImpl.startHandshake(Unknown Source)
        at sun.net.www.protocol.https.HttpsClient.afterConnect(Unknown Source)
        at sun.net.www.protocol.https.AbstractDelegateHttpsURLConnection.connect(Unknown Source)
        at sun.net.www.protocol.https.HttpsURLConnectionImpl.connect(Unknown Source)
        at org.openstreetmap.josm.tools.Http1Client.performConnection(Http1Client.java:78)
        at org.openstreetmap.josm.tools.HttpClient.connect(HttpClient.java:148)
        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(Unknown Source)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
        at java.lang.Thread.run(Unknown Source)
Caused by: java.security.InvalidKeyException: No installed provider supports this key: sun.security.rsa.RSAPublicKeyImpl
        at java.security.Signature$Delegate.chooseProvider(Unknown Source)
        at java.security.Signature$Delegate.engineInitVerify(Unknown Source)
        at java.security.Signature.initVerify(Unknown Source)
        at sun.security.ssl.HandshakeMessage$ECDH_ServerKeyExchange.<init>(Unknown Source)
        ... 18 more
Caused by: java.security.NoSuchAlgorithmException: Error constructing implementation (algorithm: SHA512withRSA, provider: SunRsaSign, class: sun.security.rsa.RSASignature$SHA512withRSA)
        at java.security.Provider$Service.newInstance(Unknown Source)
        at java.security.Signature$Delegate.newInstance(Unknown Source)
        ... 22 more
Caused by: java.lang.OutOfMemoryError: GC overhead limit exceeded


Exception: java.lang.OutOfMemoryError thrown from the UncaughtExceptionHandler in thread "WMS-downloader-1"
2020-12-08 22:11:53.042 INFO: GET https://wms.geonorge.no/skwms1/wms.matrikkel.seeiendom2?SERVICE=WMS&VERSION=1.1.1&REQUEST=GetMap&FORMAT=image/png&TRANSPARENT=true&LAYERS=matrikkel:MATRIKKELADRESSEWFS,matrikkel:VEGADRESSEWFS&STYLES=&SRS=EPSG:27391&WIDTH=512&HEIGHT=512&BBOX=-64359.0363596,587807.7292753,-64206.1623031,587960.6033319 -> HTTP/1.1 200 (1 min 12 s; 6.57 kB)
2020-12-08 22:11:57.147 INFO: GET https://wms.geonorge.no/skwms1/wms.matrikkel.seeiendom2?SERVICE=WMS&VERSION=1.1.1&REQUEST=GetMap&FORMAT=image/png&TRANSPARENT=true&LAYERS=matrikkel:MATRIKKELADRESSEWFS,matrikkel:VEGADRESSEWFS&STYLES=&SRS=EPSG:27391&WIDTH=512&HEIGHT=512&BBOX=-64359.0363596,587501.9811622,-64206.1623031,587654.8552188 -> HTTP/1.1 200 (18.7 s; 6.57 kB)
2020-12-08 22:11:59.798 INFO: GET https://wms.geonorge.no/skwms1/wms.matrikkel.seeiendom2?SERVICE=WMS&VERSION=1.1.1&REQUEST=GetMap&FORMAT=image/png&TRANSPARENT=true&LAYERS=matrikkel:MATRIKKELADRESSEWFS,matrikkel:VEGADRESSEWFS&STYLES=&SRS=EPSG:27391&WIDTH=512&HEIGHT=512&BBOX=-64359.0363596,587349.1071056,-64206.1623031,587501.9811622 -> HTTP/1.1 200 (6.7 s; 6.57 kB)

Exception: java.lang.OutOfMemoryError thrown from the UncaughtExceptionHandler in thread "RMI TCP Connection(idle)"
Last edited 3 years ago by GerdP (previous) (diff)

comment:5 by GerdP, 3 years ago

Cc: Don-vip added

comment:6 by GerdP, 3 years ago

Cc: wiktorn added
Keywords: jcs added

by GerdP, 3 years ago

Attachment: small-part-of-norway.osm added

comment:7 by GerdP, 3 years ago

OK, I can reproduce strange behaviour like this:

  1. Start JOSM r17239 with clean home
  2. load small-part-of-norway.osm
  3. Imagary -> ? Imagery not matching any other catagory -> Kartverket Address overlay

I would expect that all download activity stops after a few seconds but I three very busy threads "JCS downloading" for many seconds, using lots of memory.
This activity only seems to stop when I close the layer "Kartverket Address overlay"

comment:8 by smootheFiets, 3 years ago

I ran into what looks like the same issue on my MacBook. For me, the offending WTMS layer appears to be "PDOK aerial imagery latest" (Netherlands). After start-up, JOSM works smoothly for a while (like it always did before version 17329), then starts using up huge amounts of CPU for no obvious reason. High CPU usage is associated with a "flickering" behavior: imagery tiles appear and disappear over the course of a few seconds, before they converge on showing (or not). Zooming in seems to help temporarily against the flickering, as does disabling other imagery layers. Closing JOSM and restarting it helps for a while, but the issue keeps reappearing. Flushing the tile cache didn't help.

I hope this helps!

comment:9 by GerdP, 3 years ago

I see the problem with the "Kartverket Address overlay" also in older versions, just tried older tested version r16812.

comment:10 by GerdP, 3 years ago

The server seems to have problems with overload and JOSM seems to have problems with the information that is send by the server. I have no idea how to fix that.

comment:11 by nkamapper, 3 years ago

I could provide feedback to the provider (Kartverket), but I would need a technical description of the problem + what to ask for.

comment:12 by wiktorn, 3 years ago

I guess the culprit is somewhere around this part of the definition of imagery:

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

Looks like few bugs here:

  1. It looks like even though the tile zoom level is too low to show the tiles, for some reason jobs are submitted to load the tiles, though in this situation, they shouldn't
  2. Even though, the jobs are submitted to load the data and they succeed, some of the tiles are fetched from the cache, but some are not.

I think that 1st is the one, that makes most impact here.

comment:13 by GerdP, 3 years ago

I think this part of the code in JCSCachedTileLoaderJob looks suspicious because multiple threads may execute the syncronized block for the same key before one actually adds an element to the map. I tried e.g. to move the lower line into the sync block but that didn't fix the problem.

        synchronized (this) {
            first = !inProgress.containsKey(deduplicationKey);
        }
        inProgress.computeIfAbsent(deduplicationKey, k -> ConcurrentHashMap.newKeySet()).add(listener);
Last edited 3 years ago by GerdP (previous) (diff)

comment:14 by wiktorn, 3 years ago

This shouldn't be a problem.

The one that has first == true should execute the HTTP request. All the others should just add themselves as listeners once the job is finished.

This might indeed lead to high memory usage in situation as here, but it's not main problem. The question is, why at all we are submitting anything to load, when the zoom level prevents displaying any tiles anyway.

comment:15 by GerdP, 3 years ago

I looked at this code because I noticed that the listener list for a single job contained hundrets of listeners. My assumption is that listeners are not removed. With the well working "Kartverket Cadastral overlay" the lists contains one element. This might also explain why sometimes, even when I close all layers, the "JCS Downloading" jobs stay busy for a long time. In this case org.openstreetmap.gui.jmapviewer.Tile.loadImage() is very busy.

  • Another routine that seems to consume lots of CPU time is org.openstreetmap.josm.tools.ImageWarp$GridTransform.transform() maybe that only happens with the transformation EPSG:27391 which is listed first in Kartverket Address overlay.

comment:16 by GerdP, 3 years ago

I tried some older snapshots. I think r16666 works OK, r16677 doesn't.
Seems r16669 introduced the problem, this small patch seems to help:

  • src/org/openstreetmap/josm/gui/layer/AbstractTileSourceLayer.java

     
    15701570
    15711571        List<Tile> missedTiles = this.paintTileImages(g, ts);
    15721572        if (getDisplaySettings().isAutoLoad()) {
    1573             ts.overloadTiles();
     1573//            ts.overloadTiles();
    15741574        }
    15751575        int[] otherZooms = {1, 2, -1, -2, -3, -4, -5};
    15761576        for (int zoomOffset : otherZooms) {}}}

comment:17 by GerdP, 3 years ago

Keywords: regression added

by GerdP, 3 years ago

Attachment: 20207.patch added

revert changes from #18193

comment:18 by GerdP, 3 years ago

Summary: JOSM unresponsive[Patch] JOSM unresponsive, tries to loads tiles for zoom level that is not supported

I don't see any negative effect when I revert the changes with 20207.patch, but that might depend on the background image. For sure the code is not correct as it ignores min/max setting for zoom levels.

comment:19 by GerdP, 3 years ago

Summary: [Patch] JOSM unresponsive, tries to loads tiles for zoom level that is not supported[Patch] JOSM unresponsive, tries to load tiles for zoom level that is not supported

comment:20 by GerdP, 3 years ago

Cc: stoecker added

@Dirk: Do you have an example for a background image which will suffer from this revert?

comment:21 by wiktorn, 3 years ago

I'd rather go with following approach:

  • src/org/openstreetmap/josm/gui/layer/AbstractTileSourceLayer.java

    diff --git src/org/openstreetmap/josm/gui/layer/AbstractTileSourceLayer.java src/org/openstreetmap/josm/gui/layer/AbstractTileSourceLayer.java
    index 73280574e0..b623a0cca7 100644
    implements ImageObserver, TileLoaderListener, ZoomChangeListener, FilterChangeLi  
    13041304         */
    13051305        private void overloadTiles() {
    13061306            int overload = 1;
    13071307            int minXo = Utils.clamp(minX-overload, tileSource.getTileXMin(zoom), tileSource.getTileXMax(zoom));
    13081308            int maxXo = Utils.clamp(maxX+overload, tileSource.getTileXMin(zoom), tileSource.getTileXMax(zoom));
    13091309            int minYo = Utils.clamp(minY-overload, tileSource.getTileYMin(zoom), tileSource.getTileYMax(zoom));
    13101310            int maxYo = Utils.clamp(maxY+overload, tileSource.getTileYMin(zoom), tileSource.getTileYMax(zoom));
    1311             for (int x = minXo; x < maxXo; ++x) {
    1312                 for (int y = minYo; y < maxYo; ++y) {
    1313                     loadTile(getOrCreateTile(x, y, zoom), false);
    1314                 }
     1311
     1312            TileSet ts = new TileSet(new TileXY(minXo, minYo), new TileXY(maxXo, maxYo), zoom);
     1313            if (!ts.tooLarge()) {
     1314                ts.loadAllTiles(false);
    13151315            }
    13161316        }
    13171317

Or, if this is too conservative, change tooLarge to insane. It would keep the current logic, but provide a safeguard for cases where there is a lot of tiles on screen (when in other places, we refuse to load the tiles anyway).

comment:22 by GerdP, 3 years ago

OK, will try that. Regarding the code in JCSCachedTileLoaderJob.submit():
I do not yet understand why we allow multiple listeners for a single tile loader job, esp. when all those listeners are of the same kind, e.g. WMSCachedTileLoaderJob. Isn't that a clear signal that something has gone wrong before?

in reply to:  22 comment:23 by wiktorn, 3 years ago

Replying to GerdP:

OK, will try that. Regarding the code in JCSCachedTileLoaderJob.submit():
I do not yet understand why we allow multiple listeners for a single tile loader job, esp. when all those listeners are of the same kind, e.g. WMSCachedTileLoaderJob. Isn't that a clear signal that something has gone wrong before?

We could try to just keep most recent job instead of all. But I'm pretty sure, that this would mess up in situations, where someone has the same layer open multiple times (e.g. with different transparency, gamma settings etc.). I'm pretty sure, that we allow that right now.

The only case, where this jobs are running out of control, is when we try to load more tiles, that fit into cache (see insane) - then listener is the only reference that holds this object in memory.

What we can do here, is try to use WeakRef / SoftRef to listeners to allow GC to get rid of them in such cases as this one.

Nevertheless approach from comment above is necessary to reduce CPU usage in such case, WeakRef's would only prevent OOM.

comment:24 by GerdP, 3 years ago

Ah, yes, did not think of same layer open multiple times. I do that sometimes unintented when searching for the best background imagery. I always wondered if that really means that the same data is downloaded or rendered twice, esp. when the topmost layer isn't transparent.

Anyway, you patch also seems to prevent the problem without removing the wanted logic for #18193, so please commit it.

comment:25 by wiktorn, 3 years ago

Resolution: fixed
Status: newclosed

In 17402/josm:

Refuse to download tiles if the tileset is too large

Use TileSet in overloadTiles and move decision whether to load the tileset or not to loadAllTiles.

Closes: #20207

comment:26 by stoecker, 3 years ago

I have to check the effect on my application, but theoretically this patch looks good. In my use case there shouldn't be anywhere near 18 tiles per row, but have normal amount instead.

The effect of #18193 comes for any layer where there are visible changes between zoom levels (i.e. most maps) together with auto-follow function.

comment:27 by Klumbumbus, 3 years ago

Milestone: 20.12

Modify Ticket

Change Properties
Set your email in Preferences
Action
as closed The owner will remain team.
as The resolution will be set.
The resolution will be deleted. Next status will be 'reopened'.

Add Comment


E-mail address and name can be saved in the Preferences .
 
Note: See TracTickets for help on using tickets.