rapid undo failed

[matkoniecz]

During testing #1432 I made a test edit in a live OSM database that I immediately reverted[1]. To my surprise revert was not actually applied - see history of https://www.openstreetmap.org/way/22766359/history

For example https://www.openstreetmap.org/changeset/71430814 contains test edit adding access tag, revert edit was not applied. Selecting "undo" again was showing toast that nothing more can be undone.

It may be caused by competing edits and undos applied to the same some object in a short time, I am not considering likely that #1432 code is buggy.

[1] not the optimal way of testing but I have no idea how to do it better and fully test it, usually I solve quests on a real survey - in this case the nearest quest was quite far away from me

[westnordost]

Could you try to reproduce it, looking at the log? Iirc it is logged if a change is not applied due to a conflict

…

On June 20, 2019 9:46:31 AM GMT+02:00, Mateusz Konieczny ***@***.***> wrote: During testing #1432 I made a test edit in a live OSM database that I immediately reverted[1]. To my surprise revert was not actually applied - see history of https://www.openstreetmap.org/way/22766359/history For example https://www.openstreetmap.org/changeset/71430814 contains test edit adding access tag, revert edit was not applied. Selecting "undo" again was showing toast that nothing more can be undone. It may be caused by competing edits and undos applied to the same some object in a short time, I am not considering likely that #1432 code is buggy. [1] not the optimal way of testing but I have no idea how to do it better and fully test it, usually I solve quests on a real survey)

[mmd-osm]

Does SC fetch some data from the API via /map right after the first upload and before triggering the revert?

In case of a db fail over, there's typically a very small replication delay, which could cause some object (versions) to not being part of the /map call, if you send the /map query too quickly after the upload.

JOSM handles this by processing the diffResult, iD has a delay of a few seconds right after the upload and before loading new data.

If the data is coming from Overpass API, the replication delay will be at least 1 minute, if not longer.

[westnordost]

@mmd-osm
After successful upload of each change*, SC gets the new version of the uploaded element from the diffResult and saves the updated version of the element to local storage, yes.
If there is a conflict while uploading an element (server version is higher than local version), only then SC does a GET /[node|way|relation]/$id (etc.) to update the local version of the element and tries again.

Are you saying that one cannot rely on that this GET call will return always the current version of the element?

* a revert is the same mechanism

[mmd-osm]

CGImap can point to different databases for read/write and read-only operations. During normal operations, both point to the same primary database server karm in Amsterdam, in which case there's obviously no replication delay.

It might happen during a fail over, that a read-only mirror katla is used for /map and other GET operations, i.e. you might experience a few seconds delay (see https://munin.openstreetmap.org/openstreetmap.org/katla.openstreetmap.org/postgres_replication_9_5_main.html).

As you're already updating your local data from the diffresult, you're not immediately affected by a potential replication delay in a similar way as iD, which is using a /map call to reload all local data.

Nevertheless, you could still cross check the object/object versions you received in the diffResult with what a subsequent GET call returns. If the diffResult announced a newer version compared to the GET call, there might be some replication delay/issue.

Here's the respective iD issue: openstreetmap/iD#1646 with has some further pointers. Some of the discussion may not be relevant anymore, I don't recall exactly, how the replication was set up before the move to AMS.

For the problem at hand, it would be good to see the actual error in the log files... just wanted to raise a bit of awareness, that replication delays could potentially happen.

[matkoniecz]

Could you try to reproduce it, looking at the log?

I can do this, though I wonder is it feasible to use test editing API to avoid nonsense edit-revert cycle in main database.

It may be tricky, as I would need to somehow match what overpass server returns with content on https://master.apis.dev.openstreetmap.org - probably by populating master.apis.dev.openstreetmap.org with suitable data and running my private overpass loaded with selection of test api data.

[westnordost]

Nevertheless, you could still cross check the object/object versions you received in the diffResult with what a subsequent GET call returns. If the diffResult announced a newer version compared to the GET call, there might be some replication delay/issue.

@mmd-osm Actually, I do not even update the element via a GET call. Knowing that the app was the last one who did a change on the element (otherwise there would have been a conflict), I simply take the (local) version of the element - the one I had been uploading - and give it the new version returned from the diffResult before saving it back to local storage. Is this assumption wrong?
Or do you mean the GET followed by a subsequent possible conflict?

@matkoniecz Well to test generally new quests, the easiest way would be to

1. turn off auto-sync, optionally, log out just to be sure no actual changes are made
2. connect the smartphone you are testing with so that you see the logs
3. solve the quest in question
4. look at the log. What has been changed in answer of a quest is logged.

Using the test editing API is inconvenient because as you note yourself, there is no actual "normal" data on it.

However, the matter at hand is more important right now - if this really is reproducable, this is a bug of potentially highest criticality.

[mmd-osm]

and give it the new version returned from the diffResult before saving it back to local storage. Is this assumption wrong?

No, that looks ok. JOSM does it the same way.

[matkoniecz]

I finally started testing it a bit - one of things that would be nice is to log undoes, like quest solvings are logged (it may allow to distinguish "undo edit failed to edit OSM database" and "there was no undo edit at all")

[westnordost]

Doesn't it already? The log tag should be different.

[matkoniecz]

No sign in logs (I solved quest and undid it and solved again, without uploading).

07-08 10:33:49.656 11703-11703/de.westnordost.streetcomplete.debug D/QuestController: Solved a AddMaxHeight quest: ADD "maxheight"="9999"
07-08 10:33:49.775 11703-11767/de.westnordost.streetcomplete.debug D/Tangram: TANGRAM map.cpp:382: resize: 720 x 1123
07-08 10:33:55.577 11703-11703/de.westnordost.streetcomplete.debug V/BoostFramework: BoostFramework() : mPerf = com.qualcomm.qti.Performance@3a6d1fe
07-08 10:33:55.577 11703-11703/de.westnordost.streetcomplete.debug V/BoostFramework: BoostFramework() : mPerf = com.qualcomm.qti.Performance@a76fd5f
07-08 10:33:55.582 11703-11703/de.westnordost.streetcomplete.debug V/BoostFramework: BoostFramework() : mPerf = com.qualcomm.qti.Performance@7332875
07-08 10:33:55.582 11703-11703/de.westnordost.streetcomplete.debug V/BoostFramework: BoostFramework() : mPerf = com.qualcomm.qti.Performance@69a100a
07-08 10:33:58.987 11703-11703/de.westnordost.streetcomplete.debug V/BoostFramework: BoostFramework() : mPerf = com.qualcomm.qti.Performance@41c44
07-08 10:33:58.988 11703-11703/de.westnordost.streetcomplete.debug V/BoostFramework: BoostFramework() : mPerf = com.qualcomm.qti.Performance@2f4f12d
07-08 10:33:59.059 11703-11703/de.westnordost.streetcomplete.debug V/BoostFramework: BoostFramework() : mPerf = com.qualcomm.qti.Performance@b4cc16e
07-08 10:33:59.059 11703-11703/de.westnordost.streetcomplete.debug V/BoostFramework: BoostFramework() : mPerf = com.qualcomm.qti.Performance@bb2100f
07-08 10:34:00.077 11703-11767/de.westnordost.streetcomplete.debug D/Tangram: TANGRAM map.cpp:382: resize: 720 x 713
07-08 10:34:01.858 11703-11703/de.westnordost.streetcomplete.debug V/BoostFramework: BoostFramework() : mPerf = com.qualcomm.qti.Performance@58b29b6
07-08 10:34:01.860 11703-11703/de.westnordost.streetcomplete.debug V/BoostFramework: BoostFramework() : mPerf = com.qualcomm.qti.Performance@bba66b7
07-08 10:34:01.867 11703-11703/de.westnordost.streetcomplete.debug V/BoostFramework: BoostFramework() : mPerf = com.qualcomm.qti.Performance@2e84d8d
07-08 10:34:01.867 11703-11703/de.westnordost.streetcomplete.debug V/BoostFramework: BoostFramework() : mPerf = com.qualcomm.qti.Performance@c982b42
07-08 10:34:02.647 11703-11703/de.westnordost.streetcomplete.debug V/BoostFramework: BoostFramework() : mPerf = com.qualcomm.qti.Performance@974667c
07-08 10:34:02.647 11703-11703/de.westnordost.streetcomplete.debug V/BoostFramework: BoostFramework() : mPerf = com.qualcomm.qti.Performance@db19b05
07-08 10:34:02.650 11703-11703/de.westnordost.streetcomplete.debug V/BoostFramework: BoostFramework() : mPerf = com.qualcomm.qti.Performance@c1fad8b
07-08 10:34:02.650 11703-11703/de.westnordost.streetcomplete.debug V/BoostFramework: BoostFramework() : mPerf = com.qualcomm.qti.Performance@4df6e68
07-08 10:34:03.579 11703-11703/de.westnordost.streetcomplete.debug D/QuestController: Solved a AddMaxHeight quest: ADD "maxheight"="9999"

[westnordost]

I mean these logs here: https://github.com/westnordost/StreetComplete/blob/master/app/src/main/java/de/westnordost/streetcomplete/data/osm/upload/AOsmQuestChangesetsUpload.java#L133

The LOG-tag is different OsmQuestChangesetsUpload and UndoOsmQuestChangesetsUpload.

[westnordost]

I think I understand the problem now. While the change is uploading, so after the getAll of the table has been made but before the quest status is changed to closed, you press the undo button. Then, the system still thinks that you didn't upload it yet, so it undoes it the normal/offline way instead of (scheduling to) revert it.