Repository navigation
feat(outbox): report outbox messages that stay undispatched - #4598
guilhermeappel wants to merge 167 commits into
Conversation
Add spec 0038 for the telemetry part of issue BrighterCommand#4489: report how many outbox messages have stayed undispatched for longer than a set age, so an operator can see a message that was never sent, including in an application that runs without the outbox sweeper. The channel for failed clears, the other part of the issue, is not in this spec. Part of issue BrighterCommand#4489
A hosted service in Outbox.Hosting counts the undispatched messages older than the set age on a fixed schedule, one bounded call at a time, through the outbox's existing count. It runs on its own, so it keeps measuring when the sweeper or the posting path is stuck. A sealed meter in core, created by AddBrighterInstrumentation, publishes the last count as a gauge and how each scheduled measurement ended, skips included, as a counter. The mediator, the sweeper and the existing meter roles do not change. The ADR stays Proposed until it is agreed on the pull request. Regenerating docs/adr/index.md also adds the missing row for ADR 0082-isolate-azure-service-bus-subscription-retries. Part of issue BrighterCommand#4489
Because we can circuit break a topic, we should have an age per publication, otherwise we won't see that clearly |
| ## Proposed Solution | ||
|
|
||
| 1. The app turns the feature on with one explicit configuration step that names a **stale age**. It may also set a **ceiling**, a **measurement interval** and a **measurement timeout**. Each has a documented default. | ||
| 2. While measurement runs, Brighter counts the outbox's undispatched messages older than the stale age once per interval, up to the ceiling. |
There was a problem hiding this comment.
We might choose to support both this "overall outstanding count" and a "per topic outstanding count" to allow for topic circuit breakers to show up
|
Makes sense. While a topic's circuit is open, the sweeper skips that topic, so its messages stay in the outbox. One count over the whole outbox can't show which topic they belong to. I'll keep the overall count, as you suggest, and add a count per topic on an instrument of its own, tagged with |
A topic whose circuit breaker is open keeps its messages in the outbox, and one count over the whole outbox cannot show which topic they are on. Ask for a count per topic beside the overall count, with an age per publication that falls back to the overall stale age, and the smallest age winning when publications share a topic. The count per topic needs a new optional capability on the outbox, since no outbox can count several topics, each at its own age, and the outbox interfaces cannot gain a member. An outbox without it reports the overall count only. Part of issue BrighterCommand#4489
Revise ADR 0085-outbox-stale-message-telemetry for the two counts: the monitor makes the overall count and the count per topic at each due time, one cannot delay the other, and a second gauge reports one series per topic. A publication can set its own stale age. ADR 0086-outbox-per-topic-stale-count decides the optional outbox interface the count per topic goes through: one call for every topic, each topic at its own age and up to the ceiling, by the message header topic. Only InMemoryOutbox will implement it in this PR, and a follow-up issue will track each of the other outbox families. Part of issue BrighterCommand#4489
|
@iancooper I've pushed the revised requirements and ADRs for the age per publication and the count per topic. ADR 0085-outbox-stale-message-telemetry now covers both counts. The count per topic got an ADR of its own, ADR 0086-outbox-per-topic-stale-count, because the optional interface it adds to the outbox is a separate decision that each outbox family can then implement on its own. On the points I said the ADRs would cover: the ceiling applies to each topic on its own, so a busy topic can't hide a quiet one, and a topic shared by two publications uses the smaller age. In this PR only InMemoryOutbox will implement the interface. The database outboxes, MongoDb included, will report the overall count until their follow-ups land, with one issue per family. If you'd rather have one of them in this PR, tell me which and I'll add it. Running the two counts side by side touches most of the mechanism in ADR 0085-outbox-stale-message-telemetry. The new sections there are the ones on the smallest age, the age on |
|
|
@guilhermeappel BTW, don't forget that the "box" tests are generated from liquid templates. Typically, add in memory, then add a generic test, then fill it out for all of the actual boxes |
Revise ADR 0085-outbox-stale-message-telemetry so that the age, ceiling and cancellation tests of the overall count are generic tests in Paramore.Brighter.Base.Test. Its scope now names these tests as a second decision that serves the first. The test generator renders them for every outbox it configures, through a new suite. A hand-written test class for InMemoryOutbox derives the age and ceiling tests. What differs for each store, such as holding it for the cancellation test, goes in each outbox's provider class, through an interface the suite renders. Once step 13 records a result as a gap, the outbox's test configuration holds the number of the issue that tracks it. The generated test is then skipped, naming that issue. The ADR also plans a change to the Skip audits. The scan they share will cover only the messaging-gateway folders, so an outbox Skip needs no row in the gateway ledger. Revise ADR 0086-outbox-per-topic-stale-count so that the first family's follow-up adds a topic-counting suite to the generator, behind a SupportsTopicCounting setting that is false by default. It no longer leaves the overall count's cancellation test to the follow-ups, since ADR 0085-outbox-stale-message-telemetry keeps that test in its step 13. This follows the reminder on PR BrighterCommand#4598 that the box tests are generated from Liquid templates. Both ADRs stay Proposed. ADR 0085-outbox-stale-message-telemetry readability (before -> after): blocks: 363 -> 398 over150: 0 -> 0 over200: 0 -> 0 bold_prose: 14 -> 14 bold_leads: 119 -> 124 diagrams: 2 -> 2 h4: 15 -> 16 list_share: 137/175 -> 146/185 prose_bold_leads: 0 -> 0 run: 5 -> 5 span: 91 -> 91 units40: 0 -> 0 units50: 0 -> 0 units60: 0 -> 0 worst: 25 -> 25 emdash2: 0 -> 0 ADR 0086-outbox-per-topic-stale-count readability (before -> after): blocks: 164 -> 166 over150: 0 -> 0 over200: 0 -> 0 bold_prose: 7 -> 7 bold_leads: 63 -> 63 diagrams: 2 -> 2 h4: 8 -> 8 list_share: 50/71 -> 50/72 prose_bold_leads: 0 -> 0 run: 3 -> 3 span: 21 -> 21 units40: 0 -> 0 units50: 0 -> 0 units60: 0 -> 0 worst: 25 -> 25 emdash2: 0 -> 0 Length targets: zero oversized blocks and zero units over 25 words; both stay zero. In ADR 0085-outbox-stale-message-telemetry the new blocks come from the conformance subsection, the new Negative bullets and alternatives 30 to 34. The new references and the paragraph under the new h4 heading add the rest. The five new bullet leads are those alternatives, in that section's fixed form. The h4 count rises by one, for the heading that holds the reason for the generated tests. In ADR 0086-outbox-per-topic-stale-count one paragraph on the suite's setting and two references are new, and one bullet is gone. No diagram changes. Identifier load is unchanged at 71 distinct IDs in ADR 0085-outbox-stale-message-telemetry and 24 in ADR 0086-outbox-per-topic-stale-count. Part of issue BrighterCommand#4489
Revise ADR 0085-outbox-stale-message-telemetry so that step 13 runs the Firestore facts against the Firestore emulator, as it already runs the Spanner facts against the Spanner emulator. The ADR said the Firestore results come from a run with a Google Cloud project's credentials. The gcp-ci job does not run for a pull request from a fork, so that run would need a Google Cloud project outside CI. FirestoreClientBuilder has no public EmulatorDetection setting, so the ADR now says how the Firestore test provider reaches the emulator. When FIRESTORE_EMULATOR_HOST is set, the provider sets a Configure action on the FirestoreConfiguration it builds for each case. The action clears the builder's Credential, because the builder takes only one source of credentials. The action then points the builder at the host in FIRESTORE_EMULATOR_HOST, with insecure channel credentials. With the variable unset, as in gcp-ci, the Firestore facts still connect to a Google Cloud project. FirestoreConfiguration already offers Configure, so production code does not change. The ADR also says why the emulator is enough for Firestore: the Firestore gaps in columns (a) to (c) of FR-14 come from the outbox's code, not from the store. A new sentence in the Negative consequences says that FR-14 records no result from Google Cloud for Spanner or Firestore. The gap marks do not change. Step 13 still sets a mark only after it has run the column's facts with no mark. The ADR stays Proposed. The design review in review-design.md records pass 14 over this change. ADR 0085-outbox-stale-message-telemetry readability (before -> after): blocks: 398 -> 399 over150: 0 -> 0 over200: 0 -> 0 bold_prose: 14 -> 14 bold_leads: 124 -> 124 diagrams: 2 -> 2 h4: 16 -> 16 list_share: 146/185 -> 146/185 prose_bold_leads: 0 -> 0 run: 5 -> 5 span: 91 -> 91 units40: 0 -> 0 units50: 0 -> 0 units60: 0 -> 0 worst: 25 -> 25 emdash2: 0 -> 0 Length targets: zero oversized blocks and zero units over 25 words; both stay zero. The new block is the paragraph split off from the one on the gcp-ci job. Joined, the two would have 170 words, over the 150-word limit. The new block sits before Technology Choices, and the Negative bullet gains only a sentence, so the structure columns do not move. Identifier load is unchanged at 71 distinct IDs. Part of issue BrighterCommand#4489
|
I've pushed 18edca4 and 55ecf5f. 18edca4 revises ADR 0085-outbox-stale-message-telemetry and ADR 0086-outbox-per-topic-stale-count to use the test generator for the stale count tests of the outboxes. 55ecf5f revises ADR 0085-outbox-stale-message-telemetry to run the Firestore stale count tests against the Firestore emulator. In ADR 0085-outbox-stale-message-telemetry, the age, ceiling and cancellation tests of the overall count are generic tests in The cancellation test is generated too. It needs a store that is kept from answering, and how to hold one differs for each database. Each outbox's provider class prepares the store through an interface the suite renders. For MsSql, PostgreSql, MySql and Sqlite, a second connection holds a lock on the store. For DynamoDB, MongoDb, Spanner and Firestore, the store isn't held, so the test cancels the token before the call, as AC-17 allows. Step 13 then records whether each of those outboxes passes the token to its client. The FR-14 table already records gaps for Firestore's age, ceiling and cancellation, and for DynamoDB's ceiling. Step 13 runs every generated test and records the results in that table. Each gap then gets an issue of its own. The outbox's entry in The Before the first mark, step 13 narrows the scan of the ADR 0067-conformance-rollout-and-deferral-governance Skip audits to the messaging-gateway folders, test first, because the rule in In ADR 0086-outbox-per-topic-stale-count, the in-memory implementation and the generic test stay in this PR. Whichever family's follow-up lands first adds a topic-counting suite to the generator. It sits behind a The details are in the "Conformance tests for the overall count" section of ADR 0085-outbox-stale-message-telemetry. If both ADRs look right, I'll mark them Accepted and start on the code here. If not, let me know what to change. |
|
Worth noting #4627 which gives us monitoring of the Sweeper via our Health Checks. Once that lands, we may want to pick up these Outbox metrics too, and update a status from them in a health check |
|
Thanks, that makes sense. In ADR 0085-outbox-stale-message-telemetry, Spec 0038-outbox-stale-message-telemetry keeps a health check for stale messages out of scope (OOS-6), so I'd leave it for a separate PR once PR #4627 is merged. That separate PR would work out which readings the check uses and which remedy kind it reports, following the convention from ADR 0086-sweeper-remedy-health-checks. Before I start on the code here, are ADR 0085-outbox-stale-message-telemetry and ADR 0086-outbox-per-topic-stale-count OK to mark Accepted? |
Before I start on the code here, are ADR 0085-outbox-stale-message-telemetry and ADR 0086-outbox-per-topic-stale-count OK to mark Accepted? |
@iancooper I think your answer didn't come through. I only see my question in your comment. Are ADR 0085-outbox-stale-message-telemetry and ADR 0086-outbox-per-topic-stale-count OK to mark Accepted, or would you like changes first? |
… monitor's stale age - Test: When_a_publication_has_no_stale_age_should_measure_its_topic_at_the_stale_age - Characterisation: RED observed via: falling back to the measurement interval instead of the stale age, and orders was counted at 1 minute instead of 5; mutation reverted, re-run green - Task: T8.12 (spec 0038-outbox-stale-message-telemetry) Part of issue BrighterCommand#4489
…r a measured topic - Test: When_the_per_topic_count_is_left_out_should_run_only_the_overall_count - Characterisation: RED observed via: measuring topics without checking the outbox can count by topic, and the start failed for the outbox with no per-topic count; and via measuring topics without checking there is a topic to measure, and the "no registry", "empty registry" and "empty topic only" cases recorded per-topic series; each mutation reverted, re-run green - Task: T8.13 (spec 0038-outbox-stale-message-telemetry) Part of issue BrighterCommand#4489
- Test: When_five_due_times_complete_should_make_one_bounded_call_per_count_each - Characterisation: RED observed via: making an extra outstanding-messages call before the count, and the double's OutstandingMessagesAsync threw, so none of the five count calls was made; mutation reverted, re-run green - Task: T8.14 (spec 0038-outbox-stale-message-telemetry) Part of issue BrighterCommand#4489
…e ages - Test: When_topics_hold_stale_messages_at_their_own_ages_should_report_both_gauges - Characterisation: RED observed via: recording the overall count as the sum of the per-topic counts, and the overall gauge read 3 instead of 2; mutation reverted, re-run green - Task: T8.15 (spec 0038-outbox-stale-message-telemetry) Part of issue BrighterCommand#4489
…rall gauge - Test: When_a_topic_has_no_publication_should_count_it_in_the_overall_gauge_only - Characterisation: RED observed via: recording the overall count as the sum of the per-topic counts, and the overall gauge read 1 instead of 2; mutation reverted, re-run green - Task: T8.16 (spec 0038-outbox-stale-message-telemetry) Part of issue BrighterCommand#4489
- Test: When_a_topic_exceeds_the_ceiling_should_cap_each_topic_on_its_own - Characterisation: RED observed via: dividing the ceiling by the number of topics on the per-topic call, and the topic values came out orders 1, payments 1, refunds 0 instead of 3, 2, 0; mutation reverted, re-run green - Task: T8.17 (spec 0038-outbox-stale-message-telemetry) Part of issue BrighterCommand#4489
- Test: When_a_message_header_topic_differs_from_its_publication_should_count_it_toward_the_header_topic - Characterisation: RED observed via: making the in-memory outbox count a message by the producer topic in its bag instead of its header topic, and both cases failed, the second with orders 2 and orders.v2 0 instead of 1 and 1; mutation reverted, re-run green - Task: T8.18 (spec 0038-outbox-stale-message-telemetry) Part of issue BrighterCommand#4489
- Test: When_a_topic_is_tripped_should_still_count_it, When_a_topic_is_tripped_should_still_ask_the_outbox_for_it - Characterisation: RED observed via: making the monitor drop the topics tripped on the outbox circuit breaker from the topics it counts, and both tests failed with only payments where orders and payments were expected; mutation reverted, re-run green - Task: T8.19 (spec 0038-outbox-stale-message-telemetry) Part of issue BrighterCommand#4489
- Test: When_measurements_complete_should_tag_the_gauges_with_fixed_attributes - Characterisation: RED observed via: tagging the overall gauge with an orders destination, and the test failed with messaging.destination.name on the overall series in all ten collections, where only the outbox implementation was expected; mutation reverted, re-run green - Task: T8.20 (spec 0038-outbox-stale-message-telemetry) Part of issue BrighterCommand#4489
…ings - Test: When_settings_are_at_their_bounds_should_start_and_measure - Characterisation: RED observed via: passing TimeSpan.MaxValue as the overall count's age, and both cases timed out waiting for the first completed overall count, since InMemoryOutbox cannot subtract that age from now; mutation reverted, re-run green - Task: T8.23 (spec 0038-outbox-stale-message-telemetry) Part of issue BrighterCommand#4489
…ient state into counts - Test: When_the_monitor_is_started_from_a_flow_with_ambient_state_should_not_carry_it_into_counts - Characterisation: RED observed via: starting the loop without ExecutionContext.SuppressFlow, and the outbox saw the starting caller's AsyncLocal value instead of null; mutation reverted, re-run green - Task: T8.24 (spec 0038-outbox-stale-message-telemetry) Part of issue BrighterCommand#4489
…urns more - Test: When_an_outbox_returns_more_than_the_ceiling_should_record_the_ceiling - Implementation: the loop records min(count, CountCeiling) for the overall count and caps each topic's value on its own before it completes the per-topic count and logs it - Task: T8.21 (spec 0038-outbox-stale-message-telemetry) Part of issue BrighterCommand#4489
- Test: When_the_per_topic_result_has_an_unrequested_topic_should_drop_it - Implementation: the per-topic count keeps only the topics the monitor resolved at start, so a topic the outbox adds on its own never reaches the gauge or the log - Task: T8.22 (spec 0038-outbox-stale-message-telemetry) Part of issue BrighterCommand#4489
- Implementation: the loop records a skip and logs its Warning through one method that takes the count, so the per-topic count can use the same path; only the overall count calls it, as before - Task: T8.25 (spec 0038-outbox-stale-message-telemetry) Part of issue BrighterCommand#4489
- Test: When_time_advances_three_intervals_at_once_should_skip_two_due_times_for_each_count - Implementation: when the loop wakes after more than one due time has passed, it records the skip and logs one Warning for each count it measures, not only the overall count. Until now only the overall count was skipped, and the test failed on Assert.Equal for the per-topic Skipped total, expected 2 and got 0 - Task: T8.25 (spec 0038-outbox-stale-message-telemetry) Part of issue BrighterCommand#4489
Description
This is the telemetry part of issue #4489. As I said on the issue, I'm starting it as a draft. It has the requirements, spec 0038-outbox-stale-message-telemetry, and two ADRs, ADR 0085-outbox-stale-message-telemetry and ADR 0086-outbox-per-topic-stale-count, which you've accepted. Since then I've updated ADR 0085-outbox-stale-message-telemetry and the requirements for the relational count timeout from PR #4613, without changing any decision (commit 72c5306), and added the task breakdown in tasks.md.
I'm working through tasks.md in order. It has 15 phases, and the first five are in. Phase 1 adds
Publication.StaleMessageAgeand the six new names inBrighterSemanticConventions. In phase 2,IAmATopicCountingOutboxarrives with itsInMemoryOutboximplementation and the contract tests inTopicCountingOutboxBaseTestsso the generated tests of each outbox that implements it later can derive from them. Phase 3 adds the readings type and the sealed meter. TheStartrow of the readings table in ADR 0085-outbox-stale-message-telemetry says neither count has a latest value afterStart. No task covered aStartafter both counts already had one, so I added the test and the clearing in commit 4fa0beb instead of changing tasks.md. In phase 4,AddBrighterInstrumentationcreates the meter, and the meter only creates its instruments when the readings are registered. Phase 5 addsTimedOutboxStaleMessageMonitorOptionsandUseOutboxStaleMessageMonitor, which rejects invalid settings withConfigurationExceptionand registers the options and the readings. The hosted monitor itself comes in phase 6. The PR stays a draft until the rest is in.The feature reports how many outbox messages have stayed undispatched for longer than an age you set, so an operator can alert on a message that was never sent, even in an app that runs without the sweeper. A new hosted service in
Outbox.Hosting, registered withUseOutboxStaleMessageMonitorin the same way asUseOutboxArchiver, counts on a fixed interval, with a timeout. It makes two counts at each interval, and one never waits for the other. The overall count goes through the outbox's existing async count. The count per topic goes through a new optional outbox interface, which ADR 0086-outbox-per-topic-stale-count decides, so a topic whose circuit breaker is open shows up on its own. Each publication can set its own stale age, falling back to the monitor's, and a topic shared by several publications uses the smallest. A sealed meter in core, created byAddBrighterInstrumentationlikePublishConfirmationMeterfrom PR #4562, publishes each count as an observable gauge, one series per topic for the second, and a counter of how each scheduled measurement ended, so "no recent reading" looks different from zero. The mediator, the sweeper and the existing meter roles don't change.These are the answers I went with for the three questions in my last comment on the issue:
OutboxMeterfrom PR Add outbox metrics #4484. They come fromIMeterFactorylikePublishConfirmationMeter, so they don't depend on when the mediator is built, andOutboxMeterand its role stay as they are. Alternative 12 in ADR 0085-outbox-stale-message-telemetry has the details. If you'd rather the outbox had one meter, I'll move them. The new meter has no role interface, so moving it later breaks no implementer.After your review I added an age per publication and the count per topic, as described above. The count per topic only works on an outbox that implements the new interface. Only
InMemoryOutboxdoes in this PR, and each of the other outbox families gets a follow-up issue, so until then they report the overall count only. The gauges don't tell instances apart: each process measures its own outbox, the series carries the outbox type in a newparamore.brighter.outbox.implementationattribute, and the docs will say to combine instances that share a database with max rather than sum (alternative 17 in ADR 0085-outbox-stale-message-telemetry).I read "telemetry on the call that warns" as a metric you can alert on, counted on a schedule rather than on each Post or Clear, because a quiet app with no posts would never report a message that failed once. There's no Warning log for each count above zero either. Alternative 13 in ADR 0085-outbox-stale-message-telemetry has why, and alternative 23 there says why I didn't rely on added minus cleared from ADR 0084-outbox-metrics. The requirements still list my questions as Q-1 to Q-16, and the ADRs answer each of them. Q-7, Q-14 and Q-15 are the ones your review reopened.
Related Issues
Part of issue #4489. The channel for failed clears, the other part of the issue, isn't in this PR.
Type of Change
Checklist
Additional Notes
UseOutboxStaleMessageMonitor,TimedOutboxStaleMessageMonitorand its options inOutbox.Hosting, and in core the meter, a small readings type that the monitor writes and the meter reads, two enums that the readings type's methods take, six names inBrighterSemanticConventions, the optionalIAmATopicCountingOutboxinterface and a nullableStaleMessageAgeproperty onPublication. The readings type and its enums are public only becauseOutbox.Hostingis a separate assembly, the same reasonAmbientScopeSuppressionis public.GetOutstandingMessageCountsByTopicAsyncrejects a null or empty topic. A test covers the empty one. The null one has no test, because aDictionarykey can't be null, as ADR 0086-outbox-per-topic-stale-count says.review-requirements.md,review-design.mdandreview-tasks.mdin the spec folder.