Bing (unsuccessfully) loads images before attribution data is ready

[bastiK]

After adding Bing layer, I get the following console output

failed loading 13/4246/2754 null
failed loading 13/4248/2755 null
failed loading 13/4247/2754 null
failed loading 13/4246/2756 null
failed loading 13/4248/2754 null
failed loading 13/4247/2756 null
failed loading 13/4246/2755 null
failed loading 13/4247/2755 null
failed loading 13/4249/2754 null
failed loading 13/4249/2755 null
failed loading 13/4250/2755 null
failed loading 13/4250/2756 null
failed loading 13/4250/2754 null
failed loading 13/4248/2756 null
failed loading 13/4249/2756 null
Successfully loaded Bing attribution data.

This indicates, that JOSM tries to load images for Bing before the attribution data is fetched.

[skyper]

One reason this was not reported ealier is that the attributions are loaded when opening the download dialog (#7284).

[bastiK]

Is this fixed? At the moment I get

Successfully loaded Bing attribution data.
Bing: attribution data is not yet loaded.
Bing: attribution data is not yet loaded.
Bing: attribution data is not yet loaded.
Bing: attribution data is not yet loaded.
Bing: attribution data is not yet loaded.
Bing: attribution data is not yet loaded.
Bing: attribution data is not yet loaded.
Bing: attribution data is not yet loaded.
Bing: attribution data is not yet loaded.

[simon04]

I thought this was fixed in ​[o27519].

This output makes no sense to me. Is this error reproducible with fresh settings?

[bastiK]

Yes. I added some debugging output, maybe this helps?

console:

#####paint
#####paint
#####paint
getAttribution() 0
start to get attribution
getAttribution() 1
getAttribution() 2
getAttribution() 3
getAttribution() 4
getAttribution() 5
call1
call2
getAttribution() 6
TMSLayer: Successfully loaded Bing attribution data.
call3
getAttribution()/TimeoutException 5
Bing: attribution data is not yet loaded.
failed loading 10/552/329 null
getAttribution()/TimeoutException 4
Bing: attribution data is not yet loaded.
failed loading 10/552/328 null
getAttribution()/TimeoutException 0
Bing: attribution data is not yet loaded.
failed loading 10/548/329 null
getAttribution()/TimeoutException 3
Bing: attribution data is not yet loaded.
failed loading 10/552/327 null
getAttribution()/TimeoutException 2
Bing: attribution data is not yet loaded.
failed loading 10/548/327 null
getAttribution()/TimeoutException 1
Bing: attribution data is not yet loaded.
failed loading 10/548/328 null
getAttribution()/TimeoutException 6
Bing: attribution data is not yet loaded.
getAttribution() 7
getAttribution()/TimeoutException 7
Bing: attribution data is not yet loaded.
getAttribution() 8
call4
getAttribution()/ret 8

src/org/openstreetmap/josm/gui/layer/TMSLayer.java

@@ -237 +237 @@
                 URL u = getAttributionUrl();
                 UTFInputStreamReader in = UTFInputStreamReader.create(u.openStream(), "utf-8");
                 String r = new Scanner(in).useDelimiter("\\A").next();
-                System.out.println("Successfully loaded Bing attribution data.");
+                System.out.println("TMSLayer: Successfully loaded Bing attribution data.");
                 return r.getBytes("utf-8");
             }
         }
@@ -248 +248 @@
 
                 @Override
                 public List<Attribution> call() throws Exception {
+                    System.err.println("call1");
+                
                     BingAttributionData attributionLoader = new BingAttributionData();
+                    System.err.println("call2");
                     int waitTimeSec = 1;
                     while (true) {
                         try {
                             String xml = attributionLoader.updateIfRequiredString();
-                            return parseAttributionText(new InputSource(new StringReader((xml))));
+                        System.err.println("call3");
+                        List<Attribution> ret = parseAttributionText(new InputSource(new StringReader((xml))));
+                        System.err.println("call4");
+                            return ret;
                         } catch (IOException ex) {
                             System.err.println("Could not connect to Bing API. Will retry in " + waitTimeSec + " seconds.");
                             Thread.sleep(waitTimeSec * 1000L);
@@ -1160 +1166 @@
      */
     @Override
     public void paint(Graphics2D g, MapView mv, Bounds bounds) {
+        System.err.println("### TMSLayer/paint");
         //long start = System.currentTimeMillis();
         EastNorth topLeft = mv.getEastNorth(0, 0);
         EastNorth botRight = mv.getEastNorth(mv.getWidth(), mv.getHeight());

src/org/openstreetmap/josm/gui/MapView.java

@@ -460 +460 @@
      * Draw the component.
      */
     @Override public void paint(Graphics g) {
+        System.err.println("#####paint");
         if (BugReportExceptionHandler.exceptionHandlingInProgress())
             return;

jmapviewer/tilesources/BingAerialTileSource.java

@@ -214 +214 @@
             }
         };
     }
-
+static int dd = 0;
     protected List<Attribution> getAttribution() {
+//        Thread.currentThread().dumpStack();
+    int d = dd++;
+System.err.println("getAttribution() "+d);
         if (attributions == null) {
             // see http://www.cs.umd.edu/~pugh/java/memoryModel/DoubleCheckedLocking.html
             synchronized (BingAerialTileSource.class) {
                 if (attributions == null) {
+                    System.err.println("start to get attribution");
                     attributions = Executors.newSingleThreadExecutor().submit(getAttributionLoaderCallable());
                 }
             }
         }
         try {
-            return attributions.get(1000, TimeUnit.MILLISECONDS);
+            List<Attribution> ret = attributions.get(1000, TimeUnit.MILLISECONDS);
+System.err.println("getAttribution()/ret "+d);
+            return ret;
         } catch (TimeoutException ex) {
+System.err.println("getAttribution()/TimeoutException "+d);
             System.err.println("Bing: attribution data is not yet loaded.");
         } catch (ExecutionException ex) {
             throw new RuntimeException(ex.getCause());

[bastiK]

It does seem to work however, just the console output looks strange.

[simon04]

Interestingly, the parsing takes a "long" time (call3 to call4).

To fix this, …:

• we could increase the timeout (from 1000 to e.g. 5000 milliseconds)
• change the console output:
  Successfully loaded Bing attribution data --> Successfully fetched Bing attribution data
  Bing: attribution data is not yet loaded --> Bing: attribution data is not yet ready

[Don-vip]

Replying to simon04:

I thought this was fixed in ​[o27519].

I can confirm this update fixed the problem on my config (I was seeing them almost every day but never took time to report the bug, as a zoom/unzoom was enough to reload missing tiles).

[simon04]

From #7284: skyper:

It seems to work but I get strange messages on the console:

Repository Root: http://josm.openstreetmap.de/svn
Build-Date: 2012-01-30 02:32:23
Last Changed Author: stoecker
Revision: 4878
Repository UUID: 0c6e7542-c601-0410-84e7-c038aed88b3b
URL: http://josm.openstreetmap.de/svn/trunk
Last Changed Date: 2012-01-30 00:02:54 +0100 (Mon, 30 Jan 2012)
Last Changed Rev: 4878

Warnung: Fehlende Einstellungsdatei "$HOME/.josm/preferences.xml". Datei mit Standardeinstellungen wird erstellt.
GET http://api.openstreetmap.org/api/capabilities... OK
Successfully loaded Bing attribution data.
Bing: attribution data is not yet loaded.
Bing: attribution data is not yet loaded.
Bing: attribution data is not yet loaded.
Bing: attribution data is not yet loaded.
Bing: attribution data is not yet loaded.
Bing: attribution data is not yet loaded.
Bing: attribution data is not yet loaded.
Bing: attribution data is not yet loaded.
Bing: attribution data is not yet loaded.
Bing: attribution data is not yet loaded.
Bing: attribution data is not yet loaded.
GET http://api.openstreetmap.org/api/0.6/map?bbox=....

[Don-vip]

I still have this problem in r5402:

1. Download some OSM data of a given area
2. Add Bing layer
3. All tiles fail to load, and I can see on the console:

Bing: attribution data is not yet loaded.
Bing: attribution data is not yet loaded.
Bing: attribution data is not yet loaded.
Bing: attribution data is not yet loaded.
Bing: attribution data is not yet loaded.
Bing: attribution data is not yet loaded.
Bing: attribution data is not yet loaded.
Bing: attribution data is not yet loaded.
Bing: attribution data is not yet loaded.
Bing: attribution data is not yet loaded.
Bing: attribution data is not yet loaded.
Bing: attribution data is not yet loaded.
Bing: attribution data is not yet loaded.
Failed loading http://ecn.t2.tiles.virtualearth.net/tiles/a1202220232311021121.jpeg?g=1008: null
Failed loading http://ecn.t1.tiles.virtualearth.net/tiles/a1202220232311021120.jpeg?g=1008: null
Failed loading http://ecn.t0.tiles.virtualearth.net/tiles/a1202220232311021031.jpeg?g=1008: null
Failed loading http://ecn.t1.tiles.virtualearth.net/tiles/a1202220232311021103.jpeg?g=1008: null
Failed loading http://ecn.t2.tiles.virtualearth.net/tiles/a1202220232311021011.jpeg?g=1008: null
Failed loading http://ecn.t0.tiles.virtualearth.net/tiles/a1202220232311021102.jpeg?g=1008: null
Failed loading http://ecn.t0.tiles.virtualearth.net/tiles/a1202220232311021101.jpeg?g=1008: null
Failed loading http://ecn.t3.tiles.virtualearth.net/tiles/a1202220232311021013.jpeg?g=1008: null
Failed loading http://ecn.t1.tiles.virtualearth.net/tiles/a1202220232311021010.jpeg?g=1008: null
Failed loading http://ecn.t2.tiles.virtualearth.net/tiles/a1202220232311021012.jpeg?g=1008: null
Failed loading http://ecn.t3.tiles.virtualearth.net/tiles/a1202220232311021100.jpeg?g=1008: null
Failed loading http://ecn.t3.tiles.virtualearth.net/tiles/a1202220232311021030.jpeg?g=1008: null

Restarting JOSM or refreshing the tiles solve the problem, I think it's maybe cache-related ?

[Don-vip]

In 5406/josm:

see #7280 - Change synchronization mechanism of MapView when being notified of paint preferences change.

The previous mechanism leads to a deadlock when the paint() method triggers itself a paint preference change, such as when a TMS layer wants to paint attribution.
This caused an HMI freeze of 1s and Bing layer to never display tiles at its first display without cached attribution.

[Don-vip]

Replying to simon04:

Interestingly, the parsing takes a "long" time (call3 to call4).

Indeed. The method org.openstreetmap.gui.jmapviewer.tilesources.parseAttributionText() takes more than 300ms to parse Bing attribution, this is way too long. Replacing all these Xpath expressions with a faster StaX parsing would reduce this time drastically.

[bastiK]

Replying to Don-vip:

In 5406/josm:

see #7280 - Change synchronization mechanism of MapView when being notified of paint preferences change.

The previous mechanism leads to a deadlock when the paint() method triggers itself a paint preference change, such as when a TMS layer wants to paint attribution.
This caused an HMI freeze of 1s and Bing layer to never display tiles at its first display without cached attribution.

Thanks for fixing this deadlock, didn't think of that... :)

[bastiK]

Replying to Don-vip:

Replying to simon04:

Interestingly, the parsing takes a "long" time (call3 to call4).

Indeed. The method org.openstreetmap.gui.jmapviewer.tilesources.parseAttributionText() takes more than 300ms to parse Bing attribution, this is way too long. Replacing all these Xpath expressions with a faster StaX parsing would reduce this time drastically.

Wow, that's is really slow for such a small document. Someone wrote a DOM parser in #6866, this might speed it up a little.

[Don-vip]

Replying to bastiK:

Someone wrote a DOM parser in #6866, this might speed it up a little.

Nice ! I'll try that tonight :)

[simon04]

Any update on this?