Report each ID generator's current position as a metric

[erikjohnston]

When a stream advances in the database but stops being replicated to a process, that process's view of the stream freezes. Requests that wait for it to catch up to a token issued by another worker then time out and return empty responses indefinitely (see #20080), and nothing exported said so.

Report get_current_token from every ID generator, on every process. The value is comparable between processes, so a stream that has stopped reaching one of them shows up as divergence with no client traffic needed. It is also the position that wait_for_stream_token waits on, so its divergence is the failure itself rather than a proxy for it.

Being a watermark over gapless runs of persisted IDs, it also catches a single writer of a sharded stream going quiet, which a maximum across writers would hide behind the writers still being replicated.

[erikjohnston]

The oldest prometheus_client we support doesn't have this type.

[MadLittleMods]

We should say something about "this may be expected but get_prometheus_metric_current_value(...) requires being specific enough with labels taht only one sample matches".

[erikjohnston]

This now prints e.g.:

builtins.AssertionError: Multiple metrics found for 'gauge:synapse_storage_stream_current_position' with labels {'instance_name': 'master', 'server_name': 'test'}

Differences in labels:
 {'stream_name': 'e2e_cross_signing_keys'}
 {'stream_name': 'events'}
 {'stream_name': 'backfill'}
 {'stream_name': 'un_partial_stated_event_stream'}
 {'stream_name': 'to_device'}
 {'stream_name': 'receipts'}
 {'stream_name': 'pushers'}
 {'stream_name': 'push_rules_stream'}
 {'stream_name': 'sticky_events'}
 {'stream_name': 'thread_subscriptions'}
 {'stream_name': 'account_data'}
 {'stream_name': 'presence_stream'}
 {'stream_name': 'profile_updates'}
 {'stream_name': 'un_partial_stated_room_stream'}
 {'stream_name': 'quarantined_media'}
 {'stream_name': 'device_lists_stream'}
 {'stream_name': 'test_stream'}

tests.storage.test_id_generators.MultiWriterIdGeneratorTestCase.test_current_position_metric

[MadLittleMods]

My first reaction: I don't understand what this is trying to say.

It would be more clear to just print the actual full metrics (related to #20097 (comment))

[erikjohnston]

What about:

The labels of the metrics that matched are (excluding common labels that are in all metrics):

As what the author needs is to be more explicit with the given labels, and so needs to include one of the printed labels.

What you get from the full list (for a simple ish metric) is e.g.:

 {'stream_name': 'e2e_cross_signing_keys', 'instance_name': 'master', 'server_name': 'test'}
 {'stream_name': 'events', 'instance_name': 'master', 'server_name': 'test'}
 {'stream_name': 'backfill', 'instance_name': 'master', 'server_name': 'test'}
 {'stream_name': 'un_partial_stated_event_stream', 'instance_name': 'master', 'server_name': 'test'}
 {'stream_name': 'to_device', 'instance_name': 'master', 'server_name': 'test'}
 {'stream_name': 'receipts', 'instance_name': 'master', 'server_name': 'test'}
 {'stream_name': 'pushers', 'instance_name': 'master', 'server_name': 'test'}
 {'stream_name': 'push_rules_stream', 'instance_name': 'master', 'server_name': 'test'}
 {'stream_name': 'sticky_events', 'instance_name': 'master', 'server_name': 'test'}
 {'stream_name': 'thread_subscriptions', 'instance_name': 'master', 'server_name': 'test'}
 {'stream_name': 'account_data', 'instance_name': 'master', 'server_name': 'test'}
 {'stream_name': 'presence_stream', 'instance_name': 'master', 'server_name': 'test'}
 {'stream_name': 'profile_updates', 'instance_name': 'master', 'server_name': 'test'}
 {'stream_name': 'un_partial_stated_room_stream', 'instance_name': 'master', 'server_name': 'test'}
 {'stream_name': 'quarantined_media', 'instance_name': 'master', 'server_name': 'test'}
 {'stream_name': 'device_lists_stream', 'instance_name': 'master', 'server_name': 'test'}
 {'stream_name': 'test_stream', 'instance_name': 'master', 'server_name': 'test'}

[MadLittleMods]

I would just simplify and say Matching metrics: <raw splat of all labels>

Ideally using the recognizable Prometheus sample format like synapse_event_processing_positions{name="delayed_events",server_name="my.synapse.linux.server"} 2255.0

And then a hint about needing to be more specific about the labels so it only selects one.

[erikjohnston]

I mean, we could though there is no convenient function for formatting a sample into such lines. I also don't see what repeatedly logging the metric name and the values buy us?

And then a hint about needing to be more specific about the labels so it only selects one.

Isn't that what the current wording already does?

No metric found for gauge:synapse_storage_stream_current_position with labels {'stream_name': 'test_stream', 'server_name': 'test'}

and

Multiple metrics found for 'gauge:synapse_storage_stream_current_position' with labels {'server_name': 'test'} The labels of the metrics that matched are (excluding common labels that are in all metrics): ...

[MadLittleMods]

I also don't see what repeatedly logging the metric name and the values buy us?

It's way more clear than trying to understand what the fancy diff is trying to convey.

Isn't that what the current wording already does?

Barely. It says multiple metrics were found but it doesn't say that you need to be more specific to only select one (or why).

[erikjohnston]

How blocking is this for you, given this is an error that should only fire if someone misuses the function in a test?

I've explicitly called out that if the labels match multiple metrics they should be more specific...

I also don't see what repeatedly logging the metric name and the values buy us?

It's way more clear than trying to understand what the fancy diff is trying to convey.

I disagree really, especially if we have metrics with many labels. Not to mention there is no easy way to format as the standard metric format as far as I can find.

The comparison:

builtins.AssertionError: Multiple metrics found for 'gauge:synapse_storage_stream_current_position' with labels {'server_name': 'test'}

Specify extra labels to match the specific metric under test. The extra labels on the matching metrics are: 
 {'stream_name': 'e2e_cross_signing_keys'}
 {'stream_name': 'events'}
 {'stream_name': 'backfill'}

versus:

builtins.AssertionError: Multiple metrics found for 'gauge:synapse_storage_stream_current_position' with labels {'server_name': 'test'}

Specify extra labels to match the specific metric under test.

The matching metrics:
 synapse_storage_stream_current_position{server_name='test', stream_name='e2e_cross_signing_keys'}
 synapse_storage_stream_current_position{server_name='test', stream_name='events'}
 synapse_storage_stream_current_position{server_name='test', stream_name='backfill'}

[MadLittleMods]

(review pass)