Api Probleme

Bei mir ist der erste Radiobutton “Lade alle Objekte in einer Anfrage hoch” gesetzt:

Nachdem ich mir jetzt auch das HTTP2-Plugin für JOSM installiert habe und ausgiebig getestet habe:

Auch beim Herunterladen von Notes (https://api.openstreetmap.org/api/0.6/notes…) bekomme ich manchmal “GOAWAY” und aber immer nur dann, wenn zwischen zwei Abfragen ca. 4-6 Sekunden liegen. Frage ich deutlich schneller oder langsamer ab, bekomme ich kein GOAWAY.
Nach Auswertung von Wireshark und JOSM-Logs läuft das immer nach folgendem Schema ab:

  1. Verbindungsaufbau
  2. Up- oder Download von der OSM-API
  3. OSM-Server beendet die Verbindung mit GOAWAY, gefolgt von einem TCP-FIN.
  4. Gleichzeitig bzw. weniger als eine Millisekunde davor (die Zeitnahme ist vermutlich auch nicht 100%-ig genau) oder danach versucht JOSM über die inzwischen geschlossene Verbindung Daten zu senden, was dann fehlschlägt.
  5. JOSM behandelt diesen Fall dann nicht korrekt.

Genau da scheint also das Problem zu sein.
Bei erstmaligen Verbindungen zur API tritt der Fehler nie auf, erst wenn JOSM versucht eine bestehende Verbindung nochmal zu verwenden, nachdem sie kurz davor geschlossen wurde. Also so etwas wie ein Time-of-Check-to-Time-of-Use-Problem: https://de.wikipedia.org/wiki/Time-of-Check-to-Time-of-Use-Problem
JOSM bzw. Java sehen nach, ob die Verbindung zur API noch besteht, falls das der Fall ist, versucht JOSM diese wiederzuverwenden, bis dann aber JOSM die Verbindung verwendet, wurde diese zwischenzeitlich geschlossen. Diesen Fall behandelt dann JOSM nicht korrekt.

Das ist sehr interessant, der Wert liegt verdächtig nahe am Keep-Alive timeout von 5 Sekunden, den ich in den Traces von MichaelFS im Ticket gesehen habe (das war allerdings noch mit HTTP/1.1)

15:00:34.813 FEIN: RESPONSE HEADERS: {null=[HTTP/1.1 200 OK], Server=[Apache/2.4.41 (Ubuntu)], …, Keep-Alive=[timeout=5, max=100], Status=[200 OK]

Es wäre prima, wenn du deine Findings auch im JOSM Ticket posten könntest, es ist sehr relevant für unser Problem.

Wenn das doch bloß 'ne simple race condition sein sollte, dann wundert mich, daß es bisher noch keine Probleme gab. Auf jeden Fall sollte der Code JOSM doch eine Callback-Funktion registrieren (oder wie man Vergleichbares in Java auch immer macht), damit es mitbekommt, wenn ihm zwischenzeitlich die Verbindung wegfliegt.

Heute superschnell und ohne Errors. Wurde schon was gebastelt am Server? :sunglasses:

Nein und es gibt auch keinen Grund dafür.

Heute trat es erstmals nicht beim Hochladen auf, sondern direkt beim Neustart nach dem Aktualisieren der Plugins:

Leider habe ich kein Wireshark-Log, weil ich in dieser Phase nicht damit rechnete. Zwei weitere Neustarts mit Wireshark waren dann ohne Fehler.
Bei mir ist “kein Proxy” eingestellt.

JOSM-tested 18463 mit http2 Plugin
openjdk version “11.0.15” 2022-04-19
opensuse 15.3

Ich denke, das http2 Plugin-Experiment hat uns nicht wirklich weitergebracht, einfach weil es mit Fehlern auch nicht sauber umgeht und neue Probleme macht.

Im Ticket habe ich vorgeschlagen, das ganze zu beenden. Mal schauen, was die Maintainer dazu sagen.

/api/0.6/user/details wird übrigens auch von Ruby on Rails versorgt…

Taylor Smock hat m.E. einen anderen Vorschlag. Kannst Du das testen oder erklären, wie man das macht? Mit oder ohne http2?

Teste ich gerade. Hier mal ein Auszug aus der Ausgabe:

2022-07-05 20:51:03.773 INFORMATION: GET https://api.openstreetmap.org/api/0.6/map?bbox=7.67851,52.3145656,7.6827371,52.3172743 -> HTTP/1.1 200 (934 ms)
2022-07-05 20:51:40.077 INFORMATION: GET https://api.openstreetmap.org/api/0.6/changesets?user=43972&open=true -> HTTP/1.1 200 (235 ms; 411 B)
2022-07-05 20:51:40.079 INFORMATION: 1 open changesets on server
2022-07-05 20:51:41.831 INFORMATION: Starting upload with tags {comment=https://maproulette.org/browse/challenges/27780, source=sat, created_by=JOSM/1.5 (18499 SVN de)}
2022-07-05 20:51:41.831 INFORMATION: Strategy: SINGLE_REQUEST_STRATEGY, ChunkSize: -1, Policy: none, Close after: false
2022-07-05 20:51:41.833 INFORMATION: Änderungssatz 123246442: https://maproulette.org/browse/challenges/27780
2022-07-05 20:51:41.886 INFORMATION: Message notifier inactive
2022-07-05 20:51:41.887 INFORMATION: PUT https://api.openstreetmap.org/api/0.6/changeset/123246442 (452 B) ...
2022-07-05 20:51:41.890 INFORMATION: PUT https://api.openstreetmap.org/api/0.6/changeset/123246442 -> !!! (1 ms)
2022-07-05 20:51:41.891 WARNUNG: java.net.SocketException: Unexpected end of file from server. Ursache: java.net.SocketException: Unexpected end of file from server
java.net.SocketException: Unexpected end of file from server
        at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
        at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
        at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
        at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:490)
        at java.base/sun.net.www.protocol.http.HttpURLConnection$10.run(HttpURLConnection.java:1974)
        at java.base/sun.net.www.protocol.http.HttpURLConnection$10.run(HttpURLConnection.java:1969)
        at java.base/java.security.AccessController.doPrivileged(Native Method)
        at java.base/sun.net.www.protocol.http.HttpURLConnection.getChainedException(HttpURLConnection.java:1968)
        at java.base/sun.net.www.protocol.http.HttpURLConnection.getInputStream0(HttpURLConnection.java:1536)
        at java.base/sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1520)
        at java.base/java.net.HttpURLConnection.getResponseCode(HttpURLConnection.java:527)
        at java.base/sun.net.www.protocol.https.HttpsURLConnectionImpl.getResponseCode(HttpsURLConnectionImpl.java:334)
        at org.openstreetmap.josm.tools.Http1Client$1.getResponseCode(Http1Client.java:94)
        at org.openstreetmap.josm.tools.HttpClient.connect(HttpClient.java:161)
        at org.openstreetmap.josm.tools.HttpClient.connect(HttpClient.java:124)
        at org.openstreetmap.josm.io.OsmApi.sendRequest(OsmApi.java:729)
        at org.openstreetmap.josm.io.OsmApi.sendRequest(OsmApi.java:673)
        at org.openstreetmap.josm.io.OsmApi.sendRequest(OsmApi.java:668)
        at org.openstreetmap.josm.io.OsmApi.sendPutRequest(OsmApi.java:663)
        at org.openstreetmap.josm.io.OsmApi.updateChangeset(OsmApi.java:498)
        at org.openstreetmap.josm.io.OsmServerWriter.uploadOsm(OsmServerWriter.java:206)
        at org.openstreetmap.josm.gui.io.UploadPrimitivesTask.realRun(UploadPrimitivesTask.java:266)
        at org.openstreetmap.josm.gui.io.AsynchronousUploadPrimitivesTask.realRun(AsynchronousUploadPrimitivesTask.java:129)
        at org.openstreetmap.josm.gui.PleaseWaitRunnable.doRealRun(PleaseWaitRunnable.java:94)
        at org.openstreetmap.josm.gui.PleaseWaitRunnable.run(PleaseWaitRunnable.java:142)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at java.base/java.lang.Thread.run(Thread.java:829)
Caused by: java.net.SocketException: Unexpected end of file from server
        at java.base/sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:866)
        at java.base/sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:689)
        at java.base/sun.net.www.protocol.http.HttpURLConnection.getInputStream0(HttpURLConnection.java:1615)
        at java.base/sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1520)
        at java.base/sun.net.www.protocol.http.HttpURLConnection.getHeaderField(HttpURLConnection.java:3135)
        at java.base/sun.net.www.protocol.https.HttpsURLConnectionImpl.getHeaderField(HttpsURLConnectionImpl.java:295)
        at org.openstreetmap.josm.tools.Http1Client$1.getResponseVersion(Http1Client.java:85)
        ... 15 more

2022-07-05 20:51:41.891 WARNUNG: Already here java.net.SocketException: Unexpected end of file from server
2022-07-05 20:51:41.892 INFORMATION: PUT https://api.openstreetmap.org/api/0.6/changeset/123246442 (452 B) ...
2022-07-05 20:51:42.144 INFORMATION: PUT https://api.openstreetmap.org/api/0.6/changeset/123246442 -> HTTP/1.1 200 (157 ms; 413 B)
2022-07-05 20:51:42.144 INFORMATION: OK
2022-07-05 20:51:42.264 INFORMATION: POST https://api.openstreetmap.org/api/0.6/changeset/123246442/upload (244 kB) ...
2022-07-05 20:51:45.980 INFORMATION: POST https://api.openstreetmap.org/api/0.6/changeset/123246442/upload -> HTTP/1.1 200 (3,0 s)
2022-07-05 20:51:45.980 INFORMATION: OK
2022-07-05 20:51:46.100 INFORMATION: Message notifier active (checks every 60 minutes)

Es wird mit dem Patch also ein automatischer Neuversuch im Fehlerfall gestartet.

Danke!

**Mit oder ohne http2?
**Magst Du das auch im Ticket hinterlegen? Ich glaube nicht, dass dei Maintainer hier im DE-Forum mitlesen.

Was muss ich (nutze bisher kein WireGuard (falls es das ist), kann es aber installieren) tun, um auch solch eine Ausgabe zu generieren?

Habe http2 wie empfohlen wieder deinstalliert.
Die Ausgabe ist einfach die Terminalausgabe von java.

JOSM mit Option --debug starten

Für diejenigen, die aus dem Ticket nicht direkt Nachrichten erhalten:

und die gepatchte Version nutzen: Der Autor bittet um Rückmeldung, insbesondere zum Problem “duplicate upload”.

Für den hier diskutierten Fehler SocketException: Unexpected end of file from server wurde eine Code-Änderung für eine neue JOSM-Version vorgenommen. Großer Dank an den Autor.

Schön, die gepatchte Version läuft bei mir weiterhin problemlos.

Hi,
ich hoffe der Patch (automatisches Retry) funktioniert auch noch mit der jüngsten API Änderung (Bandwidth-Limitierung zur Vandalismus-Abwehr) ?

Möglicherweise nicht. Es gibt ein neues Ticket dazu: #23448 (JOSM uploaded thousands of duplicate ways and relations) – JOSM


Ohjeee… :see_no_evil: