Opened 4 years ago

Last modified 3 years ago

#22160 closed defect

[PATCH] Retry on `SocketException: Unexpected end of file from server` — at Version 27

Reported by: MichaelFS Owned by: team
Priority: normal Milestone: 22.08
Component: Core Version: latest
Keywords: Api 0.6, Upload Cc:

Description (last modified by taylor.smock)

What steps will reproduce the problem?

  1. Open JOSM and create one or more changes, no matter whether on ode, way or relation
  2. Click UPload

What is the expected result?

UPload should be accepted, a "SUCCESS"-message should be displayed.

What happens instead?

Message: Connection with Remote-Server
https://api.openstreetmap.org/api/0.6/failed.
Please check your Internet-connection.

Of course, the Internet-connection is stable and ONline. Nevertheless, I experienced such failures up to five times for one changeset.

The issue has been reported multiple times since January 2022 from several users in the German Forum [ ​https://forum.openstreetmap.org/viewtopic.php?id=74624]

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

Relative:URL: ^/trunk
Repository:UUID: 0c6e7542-c601-0410-84e7-c038aed88b3b
Last:Changed Date: 2022-04-04 22:26:00 +0200 (Mon, 04 Apr 2022)
Revision:18427
Build-Date:2022-04-05 01:30:55
URL:https://josm.openstreetmap.de/svn/trunk

Identification: JOSM/1.5 (18427 de) Linux Manjaro Linux
Memory Usage: 292 MB / 7832 MB (143 MB allocated, but free)
Java version: 18.0.1.1+2, N/A, OpenJDK 64-Bit Server VM
Look and Feel: javax.swing.plaf.nimbus.NimbusLookAndFeel
Screen: :0.0 1920×1080 (scaling 1.00×1.00)
Maximum Screen Size: 1920×1080
Best cursor sizes: 16×16→16×16, 32×32→32×32
Environment variable LANG: de_DE.UTF-8
System property file.encoding: UTF-8
System property sun.jnu.encoding: UTF-8
Locale info: de_DE
Numbers with default locale: 1234567890 -> 1234567890
Desktop environment: KDE
VM arguments: [--add-opens=java.desktop/javax.swing.text.html=ALL-UNNAMED, -Djosm.restart=true, -Dawt.useSystemAAFontSettings=gasp]

Plugins:
+ buildings_tools (35978)
+ continuosDownload (99)
+ fieldpapers (v0.5.0)
+ reverter (35980)
+ terracer (35893)
+ undelete (35893)
+ utilsplugin2 (35978)

Map paint styles:
+ https://josm.openstreetmap.de/josmfile?page=Styles/AddressValidator&zip=1

Note: The below stack traces may not be related to the above issue (was closed as othersoftware, see comment:1 )
From comment:12/comment:24

2022-06-23 21:48:55.554 INFO: PUT https://api.openstreetmap.org/api/0.6/changeset/create (229 B) ...
2022-06-23 21:48:55.558 INFO: PUT https://api.openstreetmap.org/api/0.6/changeset/create -> !!! (1 ms)
2022-06-23 21:48:55.559 WARNING: java.net.SocketException: Unexpected end of file from server. Cause: 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.openChangeset(OsmApi.java:463)
	at org.openstreetmap.josm.io.OsmServerWriter.uploadOsm(OsmServerWriter.java:202)
	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-06-23 21:48:55.560 INFO: PUT https://api.openstreetmap.org/api/0.6/changeset/create (229 B) ...
2022-06-23 21:48:55.684 INFO: PUT https://api.openstreetmap.org/api/0.6/changeset/create -> HTTP/1.1 200 (74 ms; 9 B)
2022-06-23 21:48:55.684 INFO: OK

Change History (28)

comment:1 by taylor.smock, 4 years ago

Resolution: → othersoftware
Status: new → closed

It looks like the OSM servers were down again. See ​https://prometheus.openstreetmap.org/d/ST-7bi5Gz/api-database?orgId=1&from=1655847307102&to=1655891753255 (specifically, I suspect you were trying to upload during the outage at around 06:00 UTC).

comment:2 by mmd, 4 years ago

No, there are repeated reports from different users all saying that they need multiple attempts to upload data. So that's unrelated to the single event you've mentioned here.

Kindly request to reopen this ticket, and continue investigating the issue, and find some mitigation. We don't see none of these reports with others editing apps, and we're suspecting the issue to be related to some Java issue. Thanks.

comment:3 by stoecker, 4 years ago

We cannot investigate anything without additional data about the issue. As should be pretty obvious it does not happen on our systems.

comment:4 by mmd, 4 years ago

I also checked minutely diffs here ​https://planet.openstreetmap.org/replication/minute/005/112/ , starting with file

488.osc.gz 2022-06-22 06:00 90K
489.osc.gz 2022-06-22 06:01 71K

...

502.osc.gz 2022-06-22 06:15 67K

Based on these minutely diffs, I cannot follow your argument, that the changeset upload was unavailable at 06:00 UTC today.

comment:5 by mmd, 4 years ago

As should be pretty obvious it does not happen on our systems.

As I've mentioned earlier on, the one thing I don't understand is, why we're only seeing these reports from JOSM users. Is JOSM doing anything special here? Are other apps more resilient to temporary network hickups? Are there some strange JDK issues with some versions, that are impacting maybe some parts of your users?

in reply to:  2 comment:6 by taylor.smock, 4 years ago

Replying to mmd:

No, there are repeated reports from different users all saying that they need multiple attempts to upload data. So that's unrelated to the single event you've mentioned here.

That is, however, most likely what caused the issue for this specific user.

Kindly request to reopen this ticket, and continue investigating the issue, and find some mitigation. We don't see none of these reports with others editing apps, and we're suspecting the issue to be related to some Java issue. Thanks.

I've seen the same problem as well. The problem is tracking it down. I have yet to find a way to reliably reproduce it, and it usually doesn't happen. Which has implications for fixing it. Since I have no reliable way to reproduce, I cannot step through the code to find the problematic section, and fix it in our code or file a ticket in upstream Java. For all we know, it might be an implementation specific bug (aka Azul Java). If you want to try and track it down, you can try running the jar files using ​Liberica Java, ​Temurin Java, etc. You can also try different versions of Java (starting with Java 8) and see if it starts occurring with a specific Java version. But then we come back to the fact it doesn't happen consistently, which means that you might use Java 8 for a week, see nothing, and move to Java 11, when the next upload may have caused the issue.

If someone can come up with a way to reliably reproduce the problem, then I will be able to fix it in fairly short order if it is in JOSM, or report it upstream otherwise.

Regardless, I do not believe that this ticket is the appropriate place for the unrelated (probably java) bug (given the time that the bug was reported).

I am working on a ticket which will give better feedback when the OSM api is down (see #22138, which you've already commented on), which will at least let us know if the api was up or down.

Replying to mmd:

Based on these minutely diffs, I cannot follow your argument, that the changeset upload was unavailable at 06:00 UTC today.

All I can say is that the OSM monitoring service said that it was down. Maybe it was still processing changesets during that period, but something was happening on the OSM server end.

in reply to:  5 comment:7 by stoecker, 4 years ago

Replying to mmd:

As should be pretty obvious it does not happen on our systems.

As I've mentioned earlier on, the one thing I don't understand is, why we're only seeing these reports from JOSM users. Is JOSM doing anything special here? Are other apps more resilient to temporary network hickups?

Network I/O is a rather complicated thing and there are big differences between different implementations. E.G. the browser based system rely on browser network I/O and this is designed to try more connections in case of issues instead of waiting and reporting to the user. JOSM tries a connect usually only once and reports back to the user.

Best example is when e.g. IPv6 of a server is down. JOSM will report an error in this case. Most browsers will silently switch to IPv4 access (which is disturbing sometimes when you yourself are responsible for server setup and you simply don't see the error :-).

So yes - in case of network trouble JOSM is more likely to report this to the users than other systems.

There are lots of possible mitigation methods and when there are important issues we'll try to workaround them, but most often a more stable network or simply "retry" is the proper solution.

comment:8 by mmd, 4 years ago

Thanks to both for your insights, much appreciated.

All I can say is that the OSM monitoring service said that it was down. Maybe it was still processing changesets during that period, but something was happening on the OSM server end.

Just wanted to quickly comment on this one. Since I've also noticed that prometheus lacks some data specifically at 06:00 UTC, I started looking into minutely diffs a bit. Typically, a changeset upload would take a few seconds, a really, really large changeset with a huge relations maybe about 1 minute in exceptional cases. That's like the 0.005% case. In case you're interested, I did a more in-depth analysis on this topic last year: ​https://lists.openstreetmap.org/pipermail/dev/2021-March/031139.html

Looking into the minutely diff files and checking the timestamps in there, changeset uploads were happening pretty much all the time without much obvious interruption. My assumption is that data collection by prometheus / grafana might have had some temporary issue. Yes, even collecting stats can be a fun exercise. :)

but most often a more stable network or simply "retry" is the proper solution.

I generally agree that retrying will help in a lot of cases, and I would also assume that this is exactly what browsers are doing under the hood.

Unfortunately, we still have this gap in the API that the upload is not idempotent: in case a user uploads a changeset with only new buildings in there, and the upload is retried for whatever reason, we might end up creating duplicate buildings on the database.

Maybe you still recall the discussion we've had in ​https://github.com/openstreetmap/openstreetmap-website/issues/2201 . It would make a retry basically a "zero risk" activity. As we couldn't agree on implementation specifics, this feature is not available as of today.

comment:9 by chris66, 4 years ago

I'm also having this problem. After changing the Java Version from V8-32 bit to V11-64 bit the upload is failing less often.
Today I had this error two or three times. One Retry was successfull in every case.

With java8 I sometimes needed 4 retries until the upload succeeded.

OS=Win 10

in reply to:  8 ; comment:10 by stoecker, 4 years ago

Maybe you still recall the discussion we've had in ​https://github.com/openstreetmap/openstreetmap-website/issues/2201 . It would make a retry basically a "zero risk" activity.

I don't think I've even seen this discussion before. Interesting how easy the participants blame JOSM for doing something wrong when they either didn't understand the problem or have not solution. "Asking the user" is the ultimate bullshit answer to any problem.

Reading the discussion I think we could further mitigate upload duplications when we download and merge the changeset in case of retry attemps.

in reply to:  10 ; comment:11 by skyper, 4 years ago

Is there a problem with checking for open changesets (#21570) or creating changesets (#21976)?

Replying to stoecker:

Reading the discussion I think we could further mitigate upload duplications when we download and merge the changeset in case of retry attemps.

How does this help with new objects? I would be happy about some magic as it is a real pain to recheck all of them if the connection is cut in the middle or end of a bigger upload.

comment:12 by anonymous, 4 years ago

It seems that the server closes the TCP connection (FIN, ACK), after that JOSM tries to PUT and fails?

Wireshark log:

|Time     | OSM mapper PC                         |
|         |                   | api.openstreetmap.org                 
|10:58:37,800577477|         SYN       |                   |Seq = 0
|         |(37866)  ------------------>  (443)    |
|10:58:37,815469006|         SYN, ACK  |                   |Seq = 0 Ack = 1
|         |(37866)  <------------------  (443)    |
|10:58:37,815491939|         ACK       |                   |Seq = 1 Ack = 1
|         |(37866)  ------------------>  (443)    |
|10:58:37,817174486|         PSH, ACK - Len: 1037          |Seq = 1 Ack = 1
|         |(37866)  ------------------>  (443)    |
|10:58:37,832314372|         ACK       |                   |Seq = 1 Ack = 1038
|         |(37866)  <------------------  (443)    |
|10:58:37,833799716|         ACK - Len: 1440               |Seq = 1 Ack = 1038
|         |(37866)  <------------------  (443)    |
|10:58:37,833804130|         ACK       |                   |Seq = 1038 Ack = 1441
|         |(37866)  ------------------>  (443)    |
|10:58:37,833921115|         PSH, ACK - Len: 1440          |Seq = 1441 Ack = 1038
|         |(37866)  <------------------  (443)    |
|10:58:37,833928327|         ACK       |                   |Seq = 1038 Ack = 2881
|         |(37866)  ------------------>  (443)    |
|10:58:37,834923146|         PSH, ACK - Len: 1216          |Seq = 2881 Ack = 1038
|         |(37866)  <------------------  (443)    |
|10:58:37,834927572|         ACK       |                   |Seq = 1038 Ack = 4097
|         |(37866)  ------------------>  (443)    |
|10:58:37,835034867|         PSH, ACK - Len: 1126          |Seq = 4097 Ack = 1038
|         |(37866)  <------------------  (443)    |
|10:58:37,835036577|         ACK       |                   |Seq = 1038 Ack = 5223
|         |(37866)  ------------------>  (443)    |
|10:58:37,836016930|         PSH, ACK - Len: 90            |Seq = 1038 Ack = 5223
|         |(37866)  ------------------>  (443)    |
|10:58:37,836319917|         PSH, ACK - Len: 655           |Seq = 1128 Ack = 5223
|         |(37866)  ------------------>  (443)    |
|10:58:37,851186883|         ACK       |                   |Seq = 5223 Ack = 1128
|         |(37866)  <------------------  (443)    |
|10:58:37,851663210|         PSH, ACK - Len: 303           |Seq = 5223 Ack = 1128
|         |(37866)  <------------------  (443)    |
|10:58:37,851672051|         ACK       |                   |Seq = 1783 Ack = 5526
|         |(37866)  ------------------>  (443)    |
|10:58:37,852645587|         PSH, ACK - Len: 303           |Seq = 5526 Ack = 1128
|         |(37866)  <------------------  (443)    |
|10:58:37,852646908|         ACK       |                   |Seq = 1783 Ack = 5829
|         |(37866)  ------------------>  (443)    |
|10:58:37,852723662|         ACK       |                   |Seq = 5829 Ack = 1783
|         |(37866)  <------------------  (443)    |
|10:58:37,902396083|         ACK - Len: 1440               |Seq = 5829 Ack = 1783
|         |(37866)  <------------------  (443)    |
|10:58:37,902410055|         ACK       |                   |Seq = 1783 Ack = 7269
|         |(37866)  ------------------>  (443)    |
|10:58:37,902818810|         PSH, ACK - Len: 578           |Seq = 7269 Ack = 1783
|         |(37866)  <------------------  (443)    |
|10:58:37,902823230|         ACK       |                   |Seq = 1783 Ack = 7847
|         |(37866)  ------------------>  (443)    |
|10:58:38,082921856|         PSH, ACK - Len: 24            |Seq = 7847 Ack = 1783
|         |(37866)  <------------------  (443)    |
|10:58:38,082934024|         ACK       |                   |Seq = 1783 Ack = 7871
|         |(37866)  ------------------>  (443)    |
|10:58:38,082946251|         FIN, ACK  |                   |Seq = 7871 Ack = 1783
|         |(37866)  <------------------  (443)    |
|10:58:38,123034242|         ACK       |                   |Seq = 1783 Ack = 7872
|         |(37866)  ------------------>  (443)    |
|10:58:38,875773751|         PSH, ACK - Len: 682           |Seq = 1783 Ack = 7872
|         |(37866)  ------------------>  (443)    |
|10:58:38,875859865|         PSH, ACK - Len: 530           |Seq = 2465 Ack = 7872
|         |(37866)  ------------------>  (443)    |
|10:58:38,876049086|         PSH, ACK - Len: 40            |Seq = 2995 Ack = 7872
|         |(37866)  ------------------>  (443)    |
|10:58:38,876077289|         FIN, PSH, ACK - Len:          |Seq = 3035 Ack = 7872
|         |(37866)  ------------------>  (443)    |
|10:58:38,890965810|         ACK       |                   |Seq = 7872 Ack = 2465
|         |(37866)  <------------------  (443)    |
|10:58:38,891001069|         ACK       |                   |Seq = 7872 Ack = 2995
|         |(37866)  <------------------  (443)    |
|10:58:38,891460628|         ACK       |                   |Seq = 7872 Ack = 3035
|         |(37866)  <------------------  (443)    |
|10:58:38,891880357|         ACK       |                   |Seq = 7872 Ack = 3076
|         |(37866)  <------------------  (443)    |

JOSM log:

10:58:37.785 FEIN: Änderungssätze einlesen …
10:58:37.785 FEIN: Verbinde mit Server ...
10:58:37.785 FEIN: REQUEST HEADERS: {Accept=application/xml, */*;q=0.8, Accept-Encoding=gzip, deflate, Authorization=OAuth oauth_consumer_key=...}
10:58:37.903 INFORMATION: GET https://api.openstreetmap.org/api/0.6/changesets?user=77777&open=true -> HTTP/1.1 200 (117 ms; 459 B)
10:58:37.903 FEIN: RESPONSE HEADERS: {null=[HTTP/1.1 200 OK], Server=[Apache/2.4.41 (Ubuntu)], ...}
10:58:37.903 FEIN: Daten werden heruntergeladen …
10:58:37.903 FEIN: Änderungssätze werden heruntergeladen …
10:58:37.903 FEIN: 
10:58:37.903 FEIN: Liste der Änderungssätze einlesen …
10:58:37.903 FEIN: Starting SAX parsing of org.xml.sax.InputSource@4a73ceed using org.openstreetmap.josm.io.OsmChangesetParser$Parser@3accd9c1
10:58:37.904 FEIN: 'SAX parsing' in 0 ms beendet
10:58:37.904 INFORMATION: 1 open changesets on server
10:58:38.858 INFORMATION: Starting upload with tags {comment=...}
10:58:38.858 INFORMATION: Strategy: CHUNKED_DATASET_STRATEGY, ChunkSize: 10, Policy: none, Close after: false
10:58:38.858 INFORMATION: Änderungssatz 55555: ...
10:58:38.874 FEIN: Exiting map mode: Auswählen
10:58:38.875 INFORMATION: Message notifier inactive
10:58:38.875 FEIN: Verbinde mit Server ...
10:58:38.875 INFORMATION: PUT https://api.openstreetmap.org/api/0.6/changeset/55555 (492 B) ...
10:58:38.875 FEIN: Daten werden hochgeladen …
10:58:38.875 FEIN: REQUEST HEADERS: {Accept=application/xml, */*;q=0.8, Accept-Encoding=gzip, deflate, Authorization=OAuth oauth_consumer_key=...}
10:58:38.876 INFORMATION: PUT https://api.openstreetmap.org/api/0.6/changeset/55555 -> !!! (0 ms)
10:58:38.876 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:77)
        at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
        at java.base/java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:499)
        at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:480)
        at java.base/sun.net.www.protocol.http.HttpURLConnection$10.run(HttpURLConnection.java:2048)
        at java.base/sun.net.www.protocol.http.HttpURLConnection$10.run(HttpURLConnection.java:2043)
        at java.base/java.security.AccessController.doPrivileged(AccessController.java:569)
        at java.base/sun.net.www.protocol.http.HttpURLConnection.getChainedException(HttpURLConnection.java:2042)
        at java.base/sun.net.www.protocol.http.HttpURLConnection.getInputStream0(HttpURLConnection.java:1609)
        at java.base/sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1589)
        at java.base/java.net.HttpURLConnection.getResponseCode(HttpURLConnection.java:529)
        at java.base/sun.net.www.protocol.https.HttpsURLConnectionImpl.getResponseCode(HttpsURLConnectionImpl.java:308)
        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:1136)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
        at java.base/java.lang.Thread.run(Thread.java:833)
Caused by: java.net.SocketException: Unexpected end of file from server
        at java.base/sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:903)
        at java.base/sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:726)
        at java.base/sun.net.www.protocol.http.HttpURLConnection.getInputStream0(HttpURLConnection.java:1688)
        at java.base/sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1589)
        at java.base/sun.net.www.protocol.http.HttpURLConnection.getHeaderField(HttpURLConnection.java:3257)
        at java.base/sun.net.www.protocol.https.HttpsURLConnectionImpl.getHeaderField(HttpsURLConnectionImpl.java:269)
        at org.openstreetmap.josm.tools.Http1Client$1.getResponseVersion(Http1Client.java:85)
        ... 15 more

10:58:38.876 WARNUNG: Already here java.net.SocketException: Unexpected end of file from server
10:58:38.876 INFORMATION: Message notifier active (checks every 5 minutes)
10:58:38.960 SCHWERWIEGEND: org.openstreetmap.josm.io.OsmTransferException: java.net.SocketException: Unexpected end of file from server. Ursache: java.net.SocketException: Unexpected end of file from server. Ursache: java.net.SocketException: Unexpected end of file from server
org.openstreetmap.josm.io.OsmTransferException: java.net.SocketException: Unexpected end of file from server
        at org.openstreetmap.josm.io.OsmApi.sendRequest(OsmApi.java:777)
        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:1136)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
        at java.base/java.lang.Thread.run(Thread.java:833)
Caused by: 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:77)
        at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
        at java.base/java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:499)
        at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:480)
        at java.base/sun.net.www.protocol.http.HttpURLConnection$10.run(HttpURLConnection.java:2048)
        at java.base/sun.net.www.protocol.http.HttpURLConnection$10.run(HttpURLConnection.java:2043)
        at java.base/java.security.AccessController.doPrivileged(AccessController.java:569)
        at java.base/sun.net.www.protocol.http.HttpURLConnection.getChainedException(HttpURLConnection.java:2042)
        at java.base/sun.net.www.protocol.http.HttpURLConnection.getInputStream0(HttpURLConnection.java:1609)
        at java.base/sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1589)
        at java.base/java.net.HttpURLConnection.getResponseCode(HttpURLConnection.java:529)
        at java.base/sun.net.www.protocol.https.HttpsURLConnectionImpl.getResponseCode(HttpsURLConnectionImpl.java:308)
        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)
        ... 12 more
Caused by: java.net.SocketException: Unexpected end of file from server
        at java.base/sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:903)
        at java.base/sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:726)
        at java.base/sun.net.www.protocol.http.HttpURLConnection.getInputStream0(HttpURLConnection.java:1688)
        at java.base/sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1589)
        at java.base/sun.net.www.protocol.http.HttpURLConnection.getHeaderField(HttpURLConnection.java:3257)
        at java.base/sun.net.www.protocol.https.HttpsURLConnectionImpl.getHeaderField(HttpsURLConnectionImpl.java:269)
        at org.openstreetmap.josm.tools.Http1Client$1.getResponseVersion(Http1Client.java:85)
        ... 15 more

10:58:38.962 SCHWERWIEGEND: Netzwerkausnahme - <html>Verbindungsaufbau zum Remote-Server<br>'https://api.openstreetmap.org/api/0.6/' gescheitert.<br>Bitte überprüfen Sie Ihre Internetverbindung.</html>

comment:13 by anonymous, 4 years ago

Another log:

Wireshark log:

|Time     | OSM mapper PC                         |
|         |                   | api.openstreetmap.org                 
|10:52:25,583208863|         SYN       |                   |Seq = 0
|         |(41328)  ------------------>  (443)    |
|10:52:25,599131123|         SYN, ACK  |                   |Seq = 0 Ack = 1
|         |(41328)  <------------------  (443)    |
|10:52:25,599145423|         ACK       |                   |Seq = 1 Ack = 1
|         |(41328)  ------------------>  (443)    |
|10:52:25,601589257|         PSH, ACK - Len: 1037          |Seq = 1 Ack = 1
|         |(41328)  ------------------>  (443)    |
|10:52:25,617990948|         ACK       |                   |Seq = 1 Ack = 1038
|         |(41328)  <------------------  (443)    |
|10:52:25,618665094|         PSH, ACK - Len: 213           |Seq = 1 Ack = 1038
|         |(41328)  <------------------  (443)    |
|10:52:25,618668955|         ACK       |                   |Seq = 1038 Ack = 214
|         |(41328)  ------------------>  (443)    |
|10:52:25,619384663|         PSH, ACK - Len: 90            |Seq = 1038 Ack = 214
|         |(41328)  ------------------>  (443)    |
|10:52:25,619757135|         PSH, ACK - Len: 651           |Seq = 1128 Ack = 214
|         |(41328)  ------------------>  (443)    |
|10:52:25,635072864|         ACK       |                   |Seq = 214 Ack = 1128
|         |(41328)  <------------------  (443)    |
|10:52:25,635519014|         PSH, ACK - Len: 303           |Seq = 214 Ack = 1128
|         |(41328)  <------------------  (443)    |
|10:52:25,635522835|         ACK       |                   |Seq = 1779 Ack = 517
|         |(41328)  ------------------>  (443)    |
|10:52:25,635720357|         ACK       |                   |Seq = 517 Ack = 1779
|         |(41328)  <------------------  (443)    |
|10:52:25,685575618|         ACK - Len: 1440               |Seq = 517 Ack = 1779
|         |(41328)  <------------------  (443)    |
|10:52:25,685579832|         ACK       |                   |Seq = 1779 Ack = 1957
|         |(41328)  ------------------>  (443)    |
|10:52:25,685725267|         PSH, ACK - Len: 578           |Seq = 1957 Ack = 1779
|         |(41328)  <------------------  (443)    |
|10:52:25,685728991|         ACK       |                   |Seq = 1779 Ack = 2535
|         |(41328)  ------------------>  (443)    |
|10:52:26,076125389|         PSH, ACK - Len: 24            |Seq = 2535 Ack = 1779
|         |(41328)  <------------------  (443)    |
|10:52:26,076139312|         ACK       |                   |Seq = 1779 Ack = 2559
|         |(41328)  ------------------>  (443)    |
|10:52:26,076153580|         FIN, ACK  |                   |Seq = 2559 Ack = 1779
|         |(41328)  <------------------  (443)    |
|10:52:26,119030039|         ACK       |                   |Seq = 1779 Ack = 2560
|         |(41328)  ------------------>  (443)    |
|10:52:27,719480133|         PSH, ACK - Len: 680           |Seq = 1779 Ack = 2560
|         |(41328)  ------------------>  (443)    |
|10:52:27,719542640|         PSH, ACK - Len: 530           |Seq = 2459 Ack = 2560
|         |(41328)  ------------------>  (443)    |
|10:52:27,719716543|         PSH, ACK - Len: 40            |Seq = 2989 Ack = 2560
|         |(41328)  ------------------>  (443)    |
|10:52:27,719742207|         FIN, PSH, ACK - Len:          |Seq = 3029 Ack = 2560
|         |(41328)  ------------------>  (443)    |
|10:52:27,735426430|         ACK       |                   |Seq = 2560 Ack = 2459
|         |(41328)  <------------------  (443)    |
|10:52:27,735894331|         ACK       |                   |Seq = 2560 Ack = 2989
|         |(41328)  <------------------  (443)    |
|10:52:27,735945469|         ACK       |                   |Seq = 2560 Ack = 3029
|         |(41328)  <------------------  (443)    |
|10:52:27,736116706|         ACK       |                   |Seq = 2560 Ack = 3070
|         |(41328)  <------------------  (443)    |

JOSM log:

10:52:25.582 FEIN: Änderungssätze einlesen …
10:52:25.582 FEIN: Verbinde mit Server ...
10:52:25.582 FEIN: REQUEST HEADERS: {Accept=application/xml, */*;q=0.8, Accept-Encoding=gzip, deflate, Authorization=OAuth oauth_consumer_key=...}
10:52:25.686 INFORMATION: GET https://api.openstreetmap.org/api/0.6/changesets?user=77777&open=true -> HTTP/1.1 200 (103 ms; 459 B)
10:52:25.686 FEIN: RESPONSE HEADERS: {null=[HTTP/1.1 200 OK], Server=[Apache/2.4.41 (Ubuntu)], ...}
10:52:25.686 FEIN: Daten werden heruntergeladen …
10:52:25.686 FEIN: Änderungssätze werden heruntergeladen …
10:52:25.686 FEIN: 
10:52:25.686 FEIN: Liste der Änderungssätze einlesen …
10:52:25.686 FEIN: Starting SAX parsing of org.xml.sax.InputSource@72a06a75 using org.openstreetmap.josm.io.OsmChangesetParser$Parser@3e36cda1
10:52:25.687 FEIN: 'SAX parsing' in 0 ms beendet
10:52:25.687 INFORMATION: 1 open changesets on server
10:52:27.702 INFORMATION: Starting upload with tags {comment=...}
10:52:27.702 INFORMATION: Strategy: CHUNKED_DATASET_STRATEGY, ChunkSize: 10, Policy: none, Close after: false
10:52:27.702 INFORMATION: Änderungssatz 55555: ...
10:52:27.718 FEIN: Exiting map mode: Auswählen
10:52:27.718 INFORMATION: Message notifier inactive
10:52:27.719 FEIN: Verbinde mit Server ...
10:52:27.719 INFORMATION: PUT https://api.openstreetmap.org/api/0.6/changeset/55555 (492 B) ...
10:52:27.719 FEIN: Daten werden hochgeladen …
10:52:27.719 FEIN: REQUEST HEADERS: {Accept=application/xml, */*;q=0.8, Accept-Encoding=gzip, deflate, Authorization=OAuth oauth_consumer_key=...}
10:52:27.719 INFORMATION: PUT https://api.openstreetmap.org/api/0.6/changeset/55555 -> !!! (0 ms)
10:52:27.720 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:77)
        at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
        at java.base/java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:499)
        at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:480)
        at java.base/sun.net.www.protocol.http.HttpURLConnection$10.run(HttpURLConnection.java:2048)
        at java.base/sun.net.www.protocol.http.HttpURLConnection$10.run(HttpURLConnection.java:2043)
        at java.base/java.security.AccessController.doPrivileged(AccessController.java:569)
        at java.base/sun.net.www.protocol.http.HttpURLConnection.getChainedException(HttpURLConnection.java:2042)
        at java.base/sun.net.www.protocol.http.HttpURLConnection.getInputStream0(HttpURLConnection.java:1609)
        at java.base/sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1589)
        at java.base/java.net.HttpURLConnection.getResponseCode(HttpURLConnection.java:529)
        at java.base/sun.net.www.protocol.https.HttpsURLConnectionImpl.getResponseCode(HttpsURLConnectionImpl.java:308)
        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:1136)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
        at java.base/java.lang.Thread.run(Thread.java:833)
Caused by: java.net.SocketException: Unexpected end of file from server
        at java.base/sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:903)
        at java.base/sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:726)
        at java.base/sun.net.www.protocol.http.HttpURLConnection.getInputStream0(HttpURLConnection.java:1688)
        at java.base/sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1589)
        at java.base/sun.net.www.protocol.http.HttpURLConnection.getHeaderField(HttpURLConnection.java:3257)
        at java.base/sun.net.www.protocol.https.HttpsURLConnectionImpl.getHeaderField(HttpsURLConnectionImpl.java:269)
        at org.openstreetmap.josm.tools.Http1Client$1.getResponseVersion(Http1Client.java:85)
        ... 15 more

10:52:27.720 WARNUNG: Already here java.net.SocketException: Unexpected end of file from server
10:52:27.720 INFORMATION: Message notifier active (checks every 5 minutes)
10:52:27.793 SCHWERWIEGEND: org.openstreetmap.josm.io.OsmTransferException: java.net.SocketException: Unexpected end of file from server. Ursache: java.net.SocketException: Unexpected end of file from server. Ursache: java.net.SocketException: Unexpected end of file from server
org.openstreetmap.josm.io.OsmTransferException: java.net.SocketException: Unexpected end of file from server
        at org.openstreetmap.josm.io.OsmApi.sendRequest(OsmApi.java:777)
        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:1136)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
        at java.base/java.lang.Thread.run(Thread.java:833)
Caused by: 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:77)
        at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
        at java.base/java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:499)
        at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:480)
        at java.base/sun.net.www.protocol.http.HttpURLConnection$10.run(HttpURLConnection.java:2048)
        at java.base/sun.net.www.protocol.http.HttpURLConnection$10.run(HttpURLConnection.java:2043)
        at java.base/java.security.AccessController.doPrivileged(AccessController.java:569)
        at java.base/sun.net.www.protocol.http.HttpURLConnection.getChainedException(HttpURLConnection.java:2042)
        at java.base/sun.net.www.protocol.http.HttpURLConnection.getInputStream0(HttpURLConnection.java:1609)
        at java.base/sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1589)
        at java.base/java.net.HttpURLConnection.getResponseCode(HttpURLConnection.java:529)
        at java.base/sun.net.www.protocol.https.HttpsURLConnectionImpl.getResponseCode(HttpsURLConnectionImpl.java:308)
        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)
        ... 12 more
Caused by: java.net.SocketException: Unexpected end of file from server
        at java.base/sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:903)
        at java.base/sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:726)
        at java.base/sun.net.www.protocol.http.HttpURLConnection.getInputStream0(HttpURLConnection.java:1688)
        at java.base/sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1589)
        at java.base/sun.net.www.protocol.http.HttpURLConnection.getHeaderField(HttpURLConnection.java:3257)
        at java.base/sun.net.www.protocol.https.HttpsURLConnectionImpl.getHeaderField(HttpsURLConnectionImpl.java:269)
        at org.openstreetmap.josm.tools.Http1Client$1.getResponseVersion(Http1Client.java:85)
        ... 15 more

10:52:27.794 SCHWERWIEGEND: Netzwerkausnahme - <html>Verbindungsaufbau zum Remote-Server<br>'https://api.openstreetmap.org/api/0.6/' gescheitert.<br>Bitte überprüfen Sie Ihre Internetverbindung.</html>

in reply to:  11 ; comment:15 by stoecker, 4 years ago

Replying to skyper:

Is there a problem with checking for open changesets (#21570) or creating changesets (#21976)?

Replying to stoecker:

Reading the discussion I think we could further mitigate upload duplications when we download and merge the changeset in case of retry attemps.

How does this help with new objects? I would be happy about some magic as it is a real pain to recheck all of them if the connection is cut in the middle or end of a bigger upload.

When an upload process fails we don't know the state. It either could have failed before the server accepted the data (retry is fine) or afterwards (new objects will be duplicated on retry).

When downloading the changeset we can merge the server state and thus replace the new objects in JOSM with the server state and prevent duplicates on retry. Merge code already exists (i.e. manual redownload of area does the same).

comment:16 by mmd, 4 years ago

When downloading the changeset we can merge the server state and thus replace the new objects in JOSM with the server state and prevent duplicates on retry

I think this brings up an interesting question, at what time such a changeset download should ideally happen. Let's assume we have a really large changeset, and the network breaks down in the middle of an upload. It might still take around 30-60s in these extreme cases for the changeset upload to be committed on the database. Until then, the changeset download would not return those "in flight" transactions yet. If you fetch the changeset during that timeframe, you would end up creating some duplicates later on.

As a side note, the overall "idempotency" discussion was also trying find find an answer to the "in flight" transactions issue.

in reply to:  15 comment:17 by skyper, 4 years ago

Replying to stoecker:

When downloading the changeset we can merge the server state and thus replace the new objects in JOSM with the server state and prevent duplicates on retry. Merge code already exists (i.e. manual redownload of area does the same).

Are you sure this works? I always ended up with duplicate objects, version=1 vs id=0. The already uploaded objects (version=1) did not merge/replace the new objects (id=0). Especially if members of relations were successfully uploaded but not the relations themself you had to be really careful.

comment:18 by stoecker, 4 years ago

I'm not sure. But I believe we have this :-)

in reply to:  description comment:19 by MKnight, 4 years ago

Replying to MichaelFS:

The issue has been reported multiple times since January 2022 from several users in the German Forum [ ​https://forum.openstreetmap.org/viewtopic.php?id=74624]

i got this error(s) earlier little bit before November 22th (see ​https://forum.openstreetmap.org/viewtopic.php?pid=851970#p851970).
That was the day i got feedback from other user in IRC who has the same problem too for a while.

comment:20 by flohoff, 4 years ago

I am having the same issues since early 2022 i think - I also reported it to the Github issue before.
Running Linux openjdk 11, most of the time dual stacked.

I once got it in wireshark and IIRC its an early SSL abort. So no wonder we cant see the request in RAILs or on the server at all. I try capturing a tcpdump again. It used to be pretty annoying e.g. 3 out of 4 connection attempts failed (For me it initially looked like an API load balancing issue or something) and is now much better like 1 in 8 which fail.

Flo

comment:21 by flohoff, 4 years ago

There is a packet capture.

​https://silicon-verl.de/home/flo/tmp/20220623/20220623-flo-pcap-josm-failed-connect2.pcap

So what i can see is that the TCP connection was kept open from the JOSM side (the connection started in 20:41:45 for checking open changesets) and josm tries to reuse that connection for the upload at 20:41:47 which then fails.

Corresponding josm output:

2022-06-23 20:41:45.772 INFO: GET https://api.openstreetmap.org/api/0.6/changesets?user=34927&open=true -> HTTP/1.1 200 (141 ms; 189 B)
2022-06-23 20:41:45.774 INFO: 0 open changesets on server
2022-06-23 20:41:47.394 INFO: Starting upload with tags {created_by=JOSM/1.5 (18382 en), comment=Add landuse}
2022-06-23 20:41:47.394 INFO: Strategy: SINGLE_REQUEST_STRATEGY, ChunkSize: -1, Policy: none, Close after: true
2022-06-23 20:41:47.394 INFO: Changeset 0: Add landuse
2022-06-23 20:41:47.469 INFO: Message notifier inactive
2022-06-23 20:41:47.470 INFO: PUT https://api.openstreetmap.org/api/0.6/changeset/create (223 B) ...
2022-06-23 20:41:47.513 INFO: PUT https://api.openstreetmap.org/api/0.6/changeset/create -> !!! (39 ms)
2022-06-23 20:41:47.515 WARNING: java.net.SocketException: Unexpected end of file from server. Cause: 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:152)
	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.openChangeset(OsmApi.java:463)
	at org.openstreetmap.josm.io.OsmServerWriter.uploadOsm(OsmServerWriter.java:202)
	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-06-23 20:41:47.516 INFO: Message notifier active (checks every 60 minutes)
2022-06-23 20:41:47.733 SEVERE: org.openstreetmap.josm.io.OsmTransferException: java.net.SocketException: Unexpected end of file from server. Cause: java.net.SocketException: Unexpected end of file from server. Cause: java.net.SocketException: Unexpected end of file from server
org.openstreetmap.josm.io.OsmTransferException: java.net.SocketException: Unexpected end of file from server
	at org.openstreetmap.josm.io.OsmApi.sendRequest(OsmApi.java:777)
	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.openChangeset(OsmApi.java:463)
	at org.openstreetmap.josm.io.OsmServerWriter.uploadOsm(OsmServerWriter.java:202)
	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/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:152)
	at org.openstreetmap.josm.tools.HttpClient.connect(HttpClient.java:124)
	at org.openstreetmap.josm.io.OsmApi.sendRequest(OsmApi.java:729)
	... 12 more
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-06-23 20:41:47.750 SEVERE: Network exception - <html>Failed to open a connection to the remote server<br>'https://api.openstreetmap.org/api/0.6/'.<br>Please check your internet connection.</html>
Last edited 4 years ago by taylor.smock (previous) (diff)

comment:22 by mmd, 4 years ago

NB: I added a link back to this ticket on the operations issue: ​https://github.com/openstreetmap/operations/issues/597

It's quite interesting that everyone reports issues with the two changeset endpoints which are handled by the Rails port.

by taylor.smock, 4 years ago

Attachment: 22160.patch​ added

Instead of catching ConnectException, catch its super class SocketException, and retry

comment:23 by taylor.smock, 4 years ago

To whoever provided comment:12, and comment:21 (flohoff): thank you. The logged stack traces were helpful.

Please try attachment:josm-custom.jar and see if that fixes the problem.

Note that I have not yet committed it, as I want to go through the history and see if there was a reason for us to use ConnectException over SocketException. Like uploading the same thing twice. So please check for duplicate uploads on a frequent basis if you do test out the attachment:josm-custom.jar file.

EDIT: ConnectException was first introduced in r874.

Last edited 4 years ago by taylor.smock (previous) (diff)

comment:24 by flohoff, 4 years ago

With the josm-custom.jar from comment:23

Okay - so after 2 uploads i got this. I did not get a popup - Everything went through smooth.

But it feels like we are painting over something here. Something in the SSL/TLS handling seems to go boom and we are now just reconnecting in any case something fails.

2022-06-23 21:48:55.554 INFO: PUT https://api.openstreetmap.org/api/0.6/changeset/create (229 B) ...
2022-06-23 21:48:55.558 INFO: PUT https://api.openstreetmap.org/api/0.6/changeset/create -> !!! (1 ms)
2022-06-23 21:48:55.559 WARNING: java.net.SocketException: Unexpected end of file from server. Cause: 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.openChangeset(OsmApi.java:463)
	at org.openstreetmap.josm.io.OsmServerWriter.uploadOsm(OsmServerWriter.java:202)
	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-06-23 21:48:55.560 INFO: PUT https://api.openstreetmap.org/api/0.6/changeset/create (229 B) ...
2022-06-23 21:48:55.684 INFO: PUT https://api.openstreetmap.org/api/0.6/changeset/create -> HTTP/1.1 200 (74 ms; 9 B)
2022-06-23 21:48:55.684 INFO: OK
Last edited 4 years ago by taylor.smock (previous) (diff)

comment:25 by flohoff, 4 years ago

While staring at it again - Are these times accurate?

2022-06-23 21:48:55.558 INFO: PUT ​https://api.openstreetmap.org/api/0.6/changeset/create -> !!! (1 ms)

1ms is well below the RTT to the api.openstreetmap.org - so something in the local API knows the connection is gone.

in reply to:  24 comment:26 by taylor.smock, 4 years ago

Replying to flohoff:

With the josm-custom.jar from comment:23

Okay - so after 2 uploads i got this. I did not get a popup - Everything went through smooth.

But it feels like we are painting over something here. Something in the SSL/TLS handling seems to go boom and we are now just reconnecting in any case something fails.

That is literally what we are doing. Something is causing a failure, so we are just retrying. Originally, we were just retrying in case of a timeout. With attachment:22160.patch​, we are retrying in any case where there is a socket exception.

Known subclasses for SocketException ("Thrown to indicate that there is an error creating or accessing a Socket")

  • BindException -- shouldn't be thrown, "Signals that an error occurred while attempting to bind a socket to a local address and port. Typically, the port is in use, or the requested local address could not be assigned."
  • ConnectException-- replacing that here, "Signals that an error occurred while attempting to connect a socket to a remote address and port. Typically, the connection was refused remotely (e.g., no process is listening on the remote address/port)."
  • ConnectionResetException -- "Thrown to indicate a connection reset"
  • NoRouteToHostException -- "Signals that an error occurred while attempting to connect a socket to a remote address and port. Typically, the remote host cannot be reached because of an intervening firewall, or if an intermediate router is down."
  • PortUnreachableException -- "Signals that an ICMP Port Unreachable message has been received on a connected datagram."
  • Various subclasses from httpclient, shouldn't be thrown in our code.

All of the ones that we should see indicate we should probably retry.

So I think applying attachment:22160.patch​ is safe, but considering the age of the code, and the criticality thereof, I don't think we should apply it until next Wednesday (assuming we do a release this weekend).

Of note, all the reported logs show that the calling issue is at org.openstreetmap.josm.tools.Http1Client$1.getResponseVersion(Http1Client.java:85). We are getting the header field (specifically, the HTTP version), which fails. This sets the rememberedException variable in HttpUrlConnection, which throws it when getInputStream is called again.

You can alternatively try the HTTP2 plugin, and see if that helps.

comment:27 by taylor.smock, 4 years ago

Description: modified (diff)
Milestone: → 22.07
Resolution: othersoftware
Status: closed → reopened
Summary: Upload of changes works only after several attempts → [PATCH] Retry on `SocketException: Unexpected end of file from server`

Even though I still feel like the original report by MichaelFS was due to a possibly flaky OSM server, I'm going to reopen this since a good chunk of discussion for a separate issue has occurred here.

Note: See TracTickets for help on using tickets.