Write a script to reset a snapshot to the state at a previous timestamp

[shankari]

This will help us finish testing https://github.com/e-mission/em-public-dashboard/issues/103 The current script https://github.com/e-mission/em-public-dashboard/commit/cc2d2a40964a673f793b8a9fc7fddfd57e70557f works without errors and does find matches and reset labels.

However, there are many other matches for which the confirmed trip does not have any labels. Let's investigate further by adding additional logs and seeing what is going on.

reset_logs_first_round.gz

[shankari]

Spot-checking the entries that did have a match, it looks like the start_ts for the trip and the user_input are an exact match. That explains how the start_ts based matching from https://github.com/e-mission/em-public-dashboard/issues/103#issuecomment-1885989491 ~worked~ appeared to work in the first place. That's good.

However, it looks like there are multiple other user inputs that have a matching confirmed trip but no user input in the trip. Need to understand why that is happening...

[shankari]

Verified https://github.com/e-mission/em-public-dashboard/pull/112#issuecomment-1891113685 by adding an assertion that the start_ts is the same when there is a match with a user input

        else:
            print(f"For input {t['data']['start_fmt_time']} of type {t['metadata']['key']}, labeled at {t['metadata']['write_fmt_time']}, found confirmed trip starting at {confirmed_trip['data']['start_fmt_time']} with user input {confirmed_trip['data']['user_input']}")
            # new assertion is here
            assert confirmed_trip["data"]["start_ts"] == t["data"]['start_ts'],\
                "MATCHING CONFIRMED TRIP WITH USER INPUT AND DIFFERENT TS"
            input_type = t["metadata"]["key"].split("/")[1]
            print(f"Resetting input of type {input_type}")
            update_results = edb.get_analysis_timeseries_db().update_one({"_id": confirmed_trip["_id"],
                "metadata.key": "analysis/confirmed_trip"}, { "$unset": { 'data.user_input.%s' % input_type: {} } })
            print(f"Update results = {update_results.raw_result}")

The assertion was not triggered. I can't check in the assertion because it will trigger in the case that the user labeled a draft trip, but it looks like none of these labeled draft trips.

For input 2023-12-20T20:02:07.148000+07:00 of type manual/purpose_confirm, labeled at 2023-12-20T20:16:02.741000+07:00, found confirmed trip starting at 2023-12-20T19:05:27.266615+07:00 with no user input
delete all entries after timestamp 1703042820.0
deleting all timeseries entries after 1703042820.0, {'n': 40502, 'ok': 1.0}
deleting all analysis timeseries entries after 1703042820.0, {'n': 6477, 'ok': 1.0}

I also printed out the pipeline states and most of them are fairly recent,

for c14376df-aa22-4532-8d7d-ee3d114fdd56, USER_INPUT_MATCH_INCOMING was last run at 2023-08-18T01:08:24.152672+00:00
for c14376df-aa22-4532-8d7d-ee3d114fdd56, CREATE_COFNIRMED_OBJECT was last run at 2023-08-18T01:08:29.002761+00:00
for 32af51aa-eb6d-4453-ae2b-994d7d8c1fec, USER_INPUT_MATCH_INCOMING was last run at 2023-12-20T12:11:32.301258+00:00
for 32af51aa-eb6d-4453-ae2b-994d7d8c1fec, CREATE_COFNIRMED_OBJECT was last run at 2023-12-20T12:15:02.253524+00:00
for 41bd169b-9956-480c-8227-afea68db59ba, USER_INPUT_MATCH_INCOMING was last run at 2023-09-05T12:10:08.042838+00:00
for 41bd169b-9956-480c-8227-afea68db59ba, CREATE_COFNIRMED_OBJECT was last run at 2023-09-05T12:10:13.724048+00:00
for e96caa4c-1adc-456c-88f1-f8909a10cc8a, USER_INPUT_MATCH_INCOMING was last run at 2023-11-29T01:09:58.317997+00:00
for e96caa4c-1adc-456c-88f1-f8909a10cc8a, CREATE_COFNIRMED_OBJECT was last run at 2023-11-29T01:10:18.541959+00:00
for a1ae9652-7476-4c17-a22f-f02396e7c620, USER_INPUT_MATCH_INCOMING was last run at 2023-12-20T15:11:58.982748+00:00
for a1ae9652-7476-4c17-a22f-f02396e7c620, CREATE_COFNIRMED_OBJECT was last run at 2023-12-20T15:12:14.241761+00:00

Maybe the other user inputs were just not processed. But they are in Pacific, so they should have been before the processed time.

For input 2023-12-20T15:49:36.486127+07:00 of type manual/purpose_confirm, labeled at 2023-12-20T19:04:06.452000+07:00, found confirmed trip starting at 2023-12-20T14:22:50.209000+07:00 with no user input
For input 2023-12-18T20:12:15.920000+07:00 of type manual/purpose_confirm, labeled at 2023-12-20T19:06:39.087000+07:00, found confirmed trip starting at 2023-12-18T20:12:15.920000+07:00 with no user input
For input 2023-12-18T18:23:57.119000+07:00 of type manual/purpose_confirm, labeled at 2023-12-20T19:07:21.524000+07:00, found confirmed trip starting at 2023-12-18T18:14:26.040760+07:00 with no user input

[shankari]

I bet that the problem is that we are matching across users, given that we use

    ts = esta.TimeSeries.get_aggregate_time_series()

[shankari]

confirmed that, at least for the oldest entries with no match, we have run the pipeline later for at least some users.

for a1ae9652-7476-4c17-a22f-f02396e7c620, USER_INPUT_MATCH_INCOMING was last run at 2023-12-20T15:11:58.982748+00:00
for a1ae9652-7476-4c17-a22f-f02396e7c620, CREATE_COFNIRMED_OBJECT was last run at 2023-12-20T15:12:14.241761+00:00

For input 2023-12-20T15:49:36.486127+07:00 of type manual/purpose_confirm, labeled at 2023-12-20T12:04:06.452000+00:00, found confirmed trip starting at 2023-12-20T14:22:50.209000+07:00 with no user input

Also confirmed, from the code, that in get_confirmed_obj_for_user_input_obj, we read all the confirmed trips for a time range from the timeseries. So using the aggregate timeseries is incorrect, we should really do this on a per-user basis.

    if ui_obj['metadata']['key'] in place_keys:
        # if place, we'll query the same time range, but with 'enter_ts'
        tq.timeType = "data.enter_ts"
        potential_candidates = ts.find_entries(["analysis/confirmed_place"], tq)
    else:
        potential_candidates = ts.find_entries(["analysis/confirmed_trip"], tq)

Switching to a per-user computation with an assertion...

[shankari]

This works a lot better, but I'm getting an assertion error

DEBUG:root:sorted candidates are [{'write_fmt_time': '2023-12-18T06:09:29.289379-08:00', 'detail': '2023-12-18T20:12:15.920000+07:00'}]
DEBUG:root:most recent entry is 2023-12-18T06:09:29.289379-08:00, 2023-12-18T20:12:15.920000+07:00
For input 2023-12-18T20:12:15.920000+07:00 of type manual/purpose_confirm, labeled at 2023-12-20T12:06:39.087000+00:00, found confirmed trip starting at 2023-12-18T20:12:15.920000+07:00 with no user input
Traceback (most recent call last):
  File "/usr/src/app/saved-notebooks/bin/reset_snapshot_to_ts.py", line 67, in <module>
    assert confirmed_trip["metadata"]["write_ts"] > mi_pipeline_state["last_ts_run"],\

Need to think through the assertions better.

Note also that this could be a corrected manual input; we reset it on the first input so it was empty when overridden. Let's print out the matching trip id as well...

[shankari]

Assertion now consistently failing for

DEBUG:root:finished querying values for ['analysis/confirmed_trip'], count = 11
DEBUG:root:orig_ts_db_matches = 0, analysis_ts_db_matches = 11
DEBUG:root:Comparing user input motorcycle: 2023-12-20T19:31:21.577000+07:00 -> 2023-12-20T19:35:11.821000+07:00, trip 2023-12-20T08:44:42.257000+07:00 -> 2023-12-20T09:11:33.911000+07:00, start checks are (True && False) and end checks are (False || False)
DEBUG:root:Comparing user input motorcycle: 2023-12-20T19:31:21.577000+07:00 -> 2023-12-20T19:35:11.821000+07:00, trip 2023-12-20T10:31:24.517380+07:00 -> 2023-12-20T10:37:33.420000+07:00, start checks are (True && False) and end checks are (False || False)
DEBUG:root:Comparing user input motorcycle: 2023-12-20T19:31:21.577000+07:00 -> 2023-12-20T19:35:11.821000+07:00, trip 2023-12-20T10:37:34.619128+07:00 -> 2023-12-20T10:44:37.947000+07:00, start checks are (True && False) and end checks are (False || False)
DEBUG:root:Comparing user input motorcycle: 2023-12-20T19:31:21.577000+07:00 -> 2023-12-20T19:35:11.821000+07:00, trip 2023-12-20T11:15:47.607593+07:00 -> 2023-12-20T11:19:56.572000+07:00, start checks are (True && False) and end checks are (False || False)
DEBUG:root:Comparing user input motorcycle: 2023-12-20T19:31:21.577000+07:00 -> 2023-12-20T19:35:11.821000+07:00, trip 2023-12-20T11:41:16.379077+07:00 -> 2023-12-20T11:45:17.912000+07:00, start checks are (True && False) and end checks are (False || False)
DEBUG:root:Comparing user input motorcycle: 2023-12-20T19:31:21.577000+07:00 -> 2023-12-20T19:35:11.821000+07:00, trip 2023-12-20T13:48:37.970016+07:00 -> 2023-12-20T13:53:45.573000+07:00, start checks are (True && False) and end checks are (False || False)
DEBUG:root:Comparing user input motorcycle: 2023-12-20T19:31:21.577000+07:00 -> 2023-12-20T19:35:11.821000+07:00, trip 2023-12-20T13:58:42.595384+07:00 -> 2023-12-20T14:25:22.328000+07:00, start checks are (True && False) and end checks are (False || False)
DEBUG:root:Comparing user input motorcycle: 2023-12-20T19:31:21.577000+07:00 -> 2023-12-20T19:35:11.821000+07:00, trip 2023-12-20T15:49:36.486127+07:00 -> 2023-12-20T16:09:36.557000+07:00, start checks are (True && False) and end checks are (False || False)
DEBUG:root:Comparing user input motorcycle: 2023-12-20T19:31:21.577000+07:00 -> 2023-12-20T19:35:11.821000+07:00, trip 2023-12-20T16:37:52.752541+07:00 -> 2023-12-20T16:49:51.540000+07:00, start checks are (True && False) and end checks are (False || False)
DEBUG:root:Comparing user input motorcycle: 2023-12-20T19:31:21.577000+07:00 -> 2023-12-20T19:35:11.821000+07:00, trip 2023-12-20T17:43:50.475334+07:00 -> 2023-12-20T17:52:37.414000+07:00, start checks are (True && False) and end checks are (False || False)
DEBUG:root:Comparing user input motorcycle: 2023-12-20T19:31:21.577000+07:00 -> 2023-12-20T19:35:11.821000+07:00, trip 2023-12-20T17:55:27.969786+07:00 -> 2023-12-20T18:01:52.739000+07:00, start checks are (True && False) and end checks are (False || False)
No matching confirmed trip for 2023-12-20T19:31:21.577000+07:00
Traceback (most recent call last):
  File "/usr/src/app/saved-notebooks/bin/reset_snapshot_to_ts.py", line 63, in <module>
    assert cc_pipeline_state["last_ts_run"] < ui["metadata"]["write_ts"],\
AssertionError: confirmed trip pipeline was last run at 2023-12-20T15:12:14.241761+00:00 after the user input submitted at 2023-12-20T13:14:19.392000+00:00, user labeled a draft trip, so there is should be a confirmed trip to match

It looks like we have run the pipeline after the user input came in, but haven't yet created the corresponding confirmed trip. Note that the last potentially matching entry starts at 2023-12-20T17:55:27.969786+07:00 We don't track when the user input was received on the server (we probably should), so there is no way to validate that directly. But we can check to see if the last confirmed trip was before this user input

[shankari]

After adding timezones, I get consistent values. Basically, the manual input could have come in after the confirmed trip was created, even though it was saved on the phone earlier.

DEBUG:root:Comparing user input motorcycle: 2023-12-20T19:31:21.577000+07:00 -> 2023-12-20T19:35:11.821000+07:00, trip 2023-12-20T17:55:27.969786+07:00 -> 2023-12-20T18:01:52.739000+07:00, start checks are (True && False) and end checks are (False || False)
No matching confirmed trip for 2023-12-20T19:31:21.577000+07:00
Traceback (most recent call last):
  File "/usr/src/app/saved-notebooks/bin/reset_snapshot_to_ts.py", line 64, in <module>
    assert cc_pipeline_state["last_ts_run"] < ui["metadata"]["write_ts"],\
AssertionError: confirmed trip pipeline was last run at 2023-12-20T22:12:14.241761+07:00 after the user input submitted at 2023-12-20T20:14:19.392000+07:00, user labeled a draft trip, so there is should be a confirmed trip to match

[shankari]

Changing to last_processed_ts is more correct because we can have run the pipeline at any time, but not actually processed anything. If we haven't processed upto time x, we will not find a confirmed trip to match time x.

                assert cc_pipeline_state["last_processed_ts"] < ui["metadata"]["write_ts"],\
                    f"last processed confirmed trip was at {arrow.get(cc_pipeline_state['last_processed_ts']).to(args.timezone)} after the user input submitted at {arrow.get(ui['metadata']['write_fmt_time'])}, user labeled a draft trip, so there is should be a confirmed trip to match"

[shankari]

After improving the assertions for the matching confirmed trip with no input case, the assertion triggers

For input 2023-12-18T20:12:15.920000+07:00 of type manual/purpose_confirm, labeled at 2023-12-20T19:05:28.385000+07:00, found confirmed trip 6580529963db011fd9339410 starting at 2023-12-18T20:12:15.920000+07:00 with user input {'purpose_confirm': 'ໄປວຽກ', 'mode_confirm': 'motorcycle'}
Resetting input of type purpose_confirm
Update results = {'n': 1, 'nModified': 1, 'ok': 1.0, 'updatedExisting': True}
For input 2023-12-18T20:12:15.920000+07:00 of type manual/mode_confirm, labeled at 2023-12-20T19:06:27.949000+07:00, found confirmed trip 6580529963db011fd9339410 starting at 2023-12-18T20:12:15.920000+07:00 with user input {'mode_confirm': 'motorcycle'}
Resetting input of type mode_confirm
Update results = {'n': 1, 'nModified': 1, 'ok': 1.0, 'updatedExisting': True}
For input 2023-12-18T20:12:15.920000+07:00 of type manual/purpose_confirm, labeled at 2023-12-20T19:06:39.087000+07:00, found confirmed trip 6580529963db011fd9339410 starting at 2023-12-18T20:12:15.920000+07:00 with no user input
Traceback (most recent call last):
  File "/usr/src/app/saved-notebooks/bin/reset_snapshot_to_ts.py", line 78, in <module>
    assert False,\
AssertionError: confirmed trip 6580529963db011fd9339410 was written 2023-12-18T21:09:29.289379+07:00 before the last matching pipeline run 2023-12-20T20:16:07.741000+07:00, or after user input was written 2023-12-20T19:06:39.087000+07:00, should have been filled in

But this is expected because there was an overridden input, likely a correction. We need to handle this in the checks

[shankari]

After handing that in the checks, we are able to run through without triggering any asserts.

There were only two users with additional

``` number of manual records after cutoff = direct: 0, timeseries: 0 number of manual records after cutoff = direct: 0, timeseries: 0 number of manual records after cutoff = direct: 0, timeseries: 0 number of manual records after cutoff = direct: 0, timeseries: 0 number of manual records after cutoff = direct: 0, timeseries: 0 number of manual records after cutoff = direct: 0, timeseries: 0 number of manual records after cutoff = direct: 0, timeseries: 0 number of manual records after cutoff = direct: 0, timeseries: 0 number of manual records after cutoff = direct: 0, timeseries: 0 number of manual records after cutoff = direct: 0, timeseries: 0 number of manual records after cutoff = direct: 0, timeseries: 0 number of manual records after cutoff = direct: 116, timeseries: 116 number of manual records after cutoff = direct: 0, timeseries: 0 number of manual records after cutoff = direct: 0, timeseries: 0 number of manual records after cutoff = direct: 0, timeseries: 0 number of manual records after cutoff = direct: 0, timeseries: 0 number of manual records after cutoff = direct: 0, timeseries: 0 number of manual records after cutoff = direct: 27, timeseries: 27 number of manual records after cutoff = direct: 0, timeseries: 0 number of manual records after cutoff = direct: 0, timeseries: 0 number of manual records after cutoff = direct: 0, timeseries: 0 number of manual records after cutoff = direct: 0, timeseries: 0 number of manual records after cutoff = direct: 0, timeseries: 0 number of manual records after cutoff = direct: 0, timeseries: 0 number of manual records after cutoff = direct: 0, timeseries: 0 number of manual records after cutoff = direct: 0, timeseries: 0 number of manual records after cutoff = direct: 0, timeseries: 0 number of manual records after cutoff = direct: 0, timeseries: 0 number of manual records after cutoff = direct: 0, timeseries: 0 number of manual records after cutoff = direct: 0, timeseries: 0 number of manual records after cutoff = direct: 0, timeseries: 0 number of manual records after cutoff = direct: 0, timeseries: 0 number of manual records after cutoff = direct: 0, timeseries: 0 number of manual records after cutoff = direct: 0, timeseries: 0 number of manual records after cutoff = direct: 0, timeseries: 0 number of manual records after cutoff = direct: 0, timeseries: 0 number of manual records after cutoff = direct: 0, timeseries: 0 number of manual records after cutoff = direct: 0, timeseries: 0 number of manual records after cutoff = direct: 0, timeseries: 0 number of manual records after cutoff = direct: 0, timeseries: 0 number of manual records after cutoff = direct: 0, timeseries: 0 number of manual records after cutoff = direct: 0, timeseries: 0 ```

All the entries with matching trips but no user input are due to overrides and have been fully reset earlier

``` $ grep --after-context=1 "no user input" /tmp/reset_logs For input 2023-12-18T20:12:15.920000+07:00 of type manual/purpose_confirm, labeled at 2023-12-20T19:06:39.087000+07:00, found confirmed trip 6580529963db011fd9339410 starting at 2023-12-18T20:12:15.920000+07:00 with no user input confirmed trip 6580529963db011fd9339410 used to have matching inputs but has been fully reset -- For input 2023-12-19T06:28:58.685000+07:00 of type manual/purpose_confirm, labeled at 2023-12-20T19:07:55.104000+07:00, found confirmed trip 6580ed9e0b87663db0d31974 starting at 2023-12-19T06:28:58.685000+07:00 with no user input confirmed trip 6580ed9e0b87663db0d31974 used to have matching inputs but has been fully reset For input 2023-12-19T05:33:56.424000+07:00 of type manual/purpose_confirm, labeled at 2023-12-20T19:08:57.934000+07:00, found confirmed trip 6580ed9e0b87663db0d31972 starting at 2023-12-19T05:33:56.424000+07:00 with no user input confirmed trip 6580ed9e0b87663db0d31972 used to have matching inputs but has been fully reset -- For input 2023-12-16T12:22:30.785000+07:00 of type manual/mode_confirm, labeled at 2023-12-20T19:11:54.631000+07:00, found confirmed trip 657d3f5fd0e548e39490746b starting at 2023-12-16T12:22:30.785000+07:00 with no user input confirmed trip 657d3f5fd0e548e39490746b used to have matching inputs but has been fully reset -- For input 2023-12-18T15:55:38.052859+07:00 of type manual/purpose_confirm, labeled at 2023-12-20T20:09:41.334000+07:00, found confirmed trip 65800c7aca7e2aed89921455 starting at 2023-12-18T15:55:38.052859+07:00 with no user input confirmed trip 65800c7aca7e2aed89921455 used to have matching inputs but has been fully reset -- For input 2023-12-20T10:37:34.619128+07:00 of type manual/purpose_confirm, labeled at 2023-12-20T20:12:06.848000+07:00, found confirmed trip 6582691c23621453ebe01a9b starting at 2023-12-20T10:37:34.619128+07:00 with no user input confirmed trip 6582691c23621453ebe01a9b used to have matching inputs but has been fully reset ```

And all the entries for which there were no matching confirmed trips were because the user labeled draft trips

``` $ grep --after-context=1 "No matching" /tmp/reset_logs No matching confirmed trip for 2023-12-20T19:31:21.577000+07:00 last processed confirmed trip was at 2023-12-20T18:01:57.739000+07:00 but the user labeled input submitted at 2023-12-20T20:14:19.392000+07:00 starting at 2023-12-20T19:31:21.577000+07:00, user labeled a draft trip, so will not be a confirmed trip to match No matching confirmed trip for 2023-12-20T19:31:21.577000+07:00 last processed confirmed trip was at 2023-12-20T18:01:57.739000+07:00 but the user labeled input submitted at 2023-12-20T20:14:24.290000+07:00 starting at 2023-12-20T19:31:21.577000+07:00, user labeled a draft trip, so will not be a confirmed trip to match No matching confirmed trip for 2023-12-20T19:31:21.577000+07:00 last processed confirmed trip was at 2023-12-20T18:01:57.739000+07:00 but the user labeled input submitted at 2023-12-20T20:14:33.454000+07:00 starting at 2023-12-20T19:31:21.577000+07:00, user labeled a draft trip, so will not be a confirmed trip to match No matching confirmed trip for 2023-12-20T20:02:07.148000+07:00 last processed confirmed trip was at 2023-12-20T18:01:57.739000+07:00 but the user labeled input submitted at 2023-12-20T20:15:57.305000+07:00 starting at 2023-12-20T20:02:07.148000+07:00, user labeled a draft trip, so will not be a confirmed trip to match No matching confirmed trip for 2023-12-20T20:02:07.148000+07:00 last processed confirmed trip was at 2023-12-20T18:01:57.739000+07:00 but the user labeled input submitted at 2023-12-20T20:16:02.741000+07:00 starting at 2023-12-20T20:02:07.148000+07:00, user labeled a draft trip, so will not be a confirmed trip to match ```

reset_logs_final_working_version.gz

[shankari]

Running the production container on the reset snapshot, the labeled metrics work

Labeled metrics	Sensed metrics

but not the sensed metrics

Investigating why... Duh! It's because I didn't run the sensed metrics notebook. That does make me wonder how this ever worked https://github.com/e-mission/em-public-dashboard/issues/103#issuecomment-1889542919

The steps outlined are only for the default metrics not for the default sensed metrics.

[shankari]

ok, everything works now.

$ docker exec -it em-public-dashboard-notebook-server-1 /bin/bash
root@1f1c9bd14267:/usr/src/app# source setup/activate.sh
(emission) root@1f1c9bd14267:/usr/src/app# cd saved-notebooks
(emission) root@1f1c9bd14267:/usr/src/app/saved-notebooks# PYTHONPATH=.. python bin/update_mappings.py mapping_dictionaries.ipynb
(emission) root@1f1c9bd14267:/usr/src/app/saved-notebooks# PYTHONPATH=.. python bin/generate_plots.py generic_metrics.ipynb default
...
# PYTHONPATH=.. python bin/generate_plots.py generic_metrics_sensed.ipynb default
/usr/src/app/saved-notebooks/bin/generate_plots.py:30: SyntaxWarning: "is not" with a literal. Did you mean "!="?
  if r.status_code is not 200:
...

No errors. Generated values are the same as previous production EXCEPT timeseries of all emissions, which is missing because I did not run the timeseries scripts. Original production values are from: https://github.com/e-mission/em-public-dashboard/issues/103#issuecomment-1889542919

Production Snapshot Dec 20th	Docker compose prod