Backend usage metrics (offline entities) for 2024.2 #1198

ktuite · 2024-09-24T23:04:36Z

Example of new metrics:

    num_offline_entity_branches: 1,
    num_offline_entity_interrupted_branches: 1,
    num_offline_entity_submissions_reprocessed: 1,
    max_entity_submission_delay: 0.022,
    avg_entity_submission_delay: 0.015

This covers these metrics:

1. Number of offline branches involving more than one update
2. How many branches were interrupted in the middle of being processed?
3. How many submissions were put in the backlog just long enough for updates to be processed in the correct order? In other words, how many submission.reprocess events have there been?
6. How long does it take for an entity change to be processed? What is the max amount of time between when the submission was created and the entity version was created?
- Matt: "What I'm personally interested in is some sense of how often there are long delays in entity processing due to a large number of unprocessed events in the audit log. How often are the workers working through the audit log overworked?"

It doesn't include

4. How many offline updates have been force-processed?
- This requires changing entity audit logging a bit to be able to track this (Log when a create/update entity submission is force applied central#720)

TODO:

~~tackle this one~~: (planning to leave til after Log when a create/update entity submission is force applied central#720)
5. How long does it take for an entire branch to be processed? Specifically: what is the max amount of time between when the first submission for a branch is received and when the last submission is processed?
Hook up the rest of the analytics (send output to odk form, update analytics form, etc.)

What has been done to verify that this works as intended?

Why is this the best possible solution? Were any other approaches considered?

How does this change affect users? Describe intentional changes to behavior and behavior that could have accidentally been affected by code changes. In other words, what are the regression risks?

Does this change require updates to the API documentation? If so, please update docs/api.yaml as part of this PR.

Before submitting this PR, please make sure you have:

run make test and confirmed all checks still pass OR confirm CircleCI build passes
verified that any code from external sources are properly credited in comments or that everything is internally sourced

matthew-white

Looking good so far, just leaving some initial thoughts!

lib/model/query/analytics.js

matthew-white · 2024-09-25T00:40:55Z

lib/model/query/analytics.js

+// submission create loggedAt timestamp (when sub was created) to when
+// the event was processed, which will be after the entity version was
+// created.
+const measureEntityProcessingTime = () => ({ one }) => one(sql`


Could this exclude offline updates that are force-processed from the backlog? I think those would skew the metrics.

Maybe this is another place where getodk/central#720 would be helpful.

Based on the discussion below, I think this isn't an issue after all. Even if an offline update ends up in the backlog, that's different from how quickly the submission.create event is processed.

matthew-white · 2024-09-25T00:46:36Z

lib/model/query/analytics.js

+// submission create loggedAt timestamp (when sub was created) to when
+// the event was processed, which will be after the entity version was
+// created.
+const measureEntityProcessingTime = () => ({ one }) => one(sql`


For the same reason, it'd be great if we could exclude submission.create events that were processed when the approvalRequired flag was toggled, as we expect a delay in that case. I'm not really sure how to identify that though. 🤔 If it helped, I think it'd be OK to exclude entity creations (entity defs whose version number is 1), since those are the only entity defs that the approvalRequired flag will affect.

This query is kinda indirect in a way that I think is convenient for the metric we are getting at.

It's looking at the timestamps on the submission.create audit event which only gets updated by the jobs worker, the one that runs the first time the event comes in. The other things that process submission events to make entities (like the batch processing when toggling the approvalRequired flag and batch-processing the backlog) use the event to look up information, but they don't update anything about the underlying event.

So I think it's safe to to look at this time difference like this. It's not every submission create event, it's only the ones that ultimately turn into entity versions. It doesn't capture how long it takes overall for a submission to become an entity (potentially factoring in these other sources of delay), but it does capture how long a submission would be sitting around waiting for any initial entity processing (even if the result of that was it getting skipped to be reexamined later).

Maybe what you were expecting was a more explicit (entity def creation date - source submission def creation date). I could add a query for that, too, that could include these other ways in which entity processing can get delayed. Then we could see if there's a noticeable difference... which would mean these delay-related mechanism are activated.

It's looking at the timestamps on the submission.create audit event which only gets updated by the jobs worker, the one that runs the first time the event comes in.

Ah that's interesting, I hadn't put that together. This sounds like a good way to approach the metric then. 👍 I don't feel like we need anything more explicit: it makes sense to me to start with this.

matthew-white · 2024-09-25T13:25:26Z

I think metric 5 is also one that would benefit from getodk/central#720.

ktuite · 2024-09-25T21:04:18Z

lib/model/query/analytics.js

+WHERE action = 'submission.create'
+`);
+
+const measureElapsedEntityTime = () => ({ one }) => one(sql`


I added this query for fun but decided not to include it in the actual report. Partly because it feels slower than some of the other queries and the overall set of queries is already sooo slow.

Yeah, and I think as we discussed above, we would expect these metrics to be larger than those from measureEntityProcessingTime(), as these metrics will include the 5-day entity backlog wait and also the time between submission creation and submission approval (if submission approval is required).

matthew-white · 2024-09-25T22:47:33Z

test/integration/other/analytics-queries.js

+
+      // Create form, set dataset people to approvalRequired = true
+      await createTestForm(service, container, testData.forms.simpleEntity, 1);
+      await approvalRequired(service, 1, 'people');


Ah sorry, I just removed this function in #1196, as it wasn't used anymore and the linter was complaining. I think merging now would break the master branch, but you could merge master into this PR, then add approvalRequired() back. Or if it's not used elsewhere, you could just send the request to toggle the flag without using approvalRequired(). Sorry about that!

ktuite requested a review from matthew-white September 24, 2024 23:58

matthew-white reviewed Sep 25, 2024

View reviewed changes

ktuite commented Sep 25, 2024

View reviewed changes

ktuite marked this pull request as ready for review September 25, 2024 21:05

ktuite changed the title ~~Offline entity usage metrics for 2024.2~~ Backend usage metrics (offline entities) for 2024.2 Sep 25, 2024

ktuite mentioned this pull request Sep 25, 2024

Frontend usage metrics strings (offline entities) for 2024.2 getodk/central-frontend#1029

Merged

2 tasks

matthew-white approved these changes Sep 25, 2024

View reviewed changes

ktuite added 8 commits September 25, 2024 16:04

Start of offline entity analytics queries

7e8a2e8

Counting submission.reprocess events

f7af3e2

Submission/entity wait time

df96ea4

Updating interrupted branch count query

cb543d6

Tests trying to show submission processing delays

2f3b1c9

New overall entity time query

fa25ada

Add new values to output and update form version

0215b7b

replace approval required request

16e33b5

ktuite force-pushed the ktuite/usage_metrics branch from ebeb0ba to 16e33b5 Compare September 25, 2024 23:06

ktuite merged commit 3e190d5 into master Sep 25, 2024
6 checks passed

ktuite deleted the ktuite/usage_metrics branch September 25, 2024 23:27

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Backend usage metrics (offline entities) for 2024.2 #1198

Backend usage metrics (offline entities) for 2024.2 #1198

ktuite commented Sep 24, 2024 •

edited

Loading

matthew-white left a comment

matthew-white Sep 25, 2024

matthew-white Sep 25, 2024

matthew-white Sep 25, 2024

matthew-white Sep 25, 2024

ktuite Sep 25, 2024

ktuite Sep 25, 2024

matthew-white Sep 25, 2024

matthew-white commented Sep 25, 2024

ktuite Sep 25, 2024

matthew-white Sep 25, 2024

matthew-white Sep 25, 2024

Backend usage metrics (offline entities) for 2024.2 #1198

Backend usage metrics (offline entities) for 2024.2 #1198

Conversation

ktuite commented Sep 24, 2024 • edited Loading

What has been done to verify that this works as intended?

Why is this the best possible solution? Were any other approaches considered?

How does this change affect users? Describe intentional changes to behavior and behavior that could have accidentally been affected by code changes. In other words, what are the regression risks?

Does this change require updates to the API documentation? If so, please update docs/api.yaml as part of this PR.

Before submitting this PR, please make sure you have:

matthew-white left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

matthew-white commented Sep 25, 2024

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

ktuite commented Sep 24, 2024 •

edited

Loading