Replace non-ASCII µs suffix in telemetry metric names (#4776)

## Summary
- Renames the microsecond-unit suffix used by several telemetry metric
and span-attribute names from the non-ASCII `µs`/`μs` characters to
plain-ASCII `us`, since backends such as Mimir/Prometheus reject metric
names containing non-ASCII characters and were dropping these metrics on
ingestion.
- Covers the shape DB connection pool checkout queue-time metric named
directly in the issue, plus several interval/span-duration attribute
names elsewhere in the sync-service that used the same non-ASCII suffix,
for consistency.
- Adds coverage confirming the renamed metric is exported with a
plain-ASCII name.

Fixes #4732

Author: alco

.changeset/ascii-telemetry-names.md

@@ -0,0 +1,6 @@
+---
+"@core/sync-service": minor
+"@core/electric-telemetry": minor
+---
+
+**Breaking change**: renamed several telemetry metric and span attribute names, replacing their non-ASCII `µs`/`μs` microsecond suffix with the plain-ASCII `us`. Some metrics backends (e.g. Mimir/Prometheus) reject metric names containing non-ASCII characters, which previously caused ingestion of the affected metrics to fail. Any dashboards, alerts, or queries referencing the old attribute names (e.g. `shape_db.pool.checkout.queue_time_μs`) need to be updated to the new ASCII names (e.g. `shape_db.pool.checkout.queue_time_us`).

integration-tests/tests/otel-export.lux

@@ -120,6 +120,7 @@
   [invoke grep_otel_collector_output "Metric electric\.storage\.snapshot_stored\.operations .*stack_id=single_stack"]
   [invoke grep_otel_collector_output "Metric electric\.storage\.transaction_stored\.bytes .*stack_id=single_stack"]
   [invoke grep_otel_collector_output "Metric electric\.storage\.transaction_stored\.operations .*stack_id=single_stack"]
+  [invoke grep_otel_collector_output "Metric electric\.shape_db\.pool\.checkout\.queue_time_us .*stack_id=single_stack"]
 
   # The initial snapshot query span is exported from the Snapshotter path."]
   [invoke grep_otel_collector_output "Span shape_snapshot\.execute_for_shape .*shape\.query_reason=initial_snapshot"]

packages/electric-telemetry/lib/electric/telemetry/stack_telemetry.ex

@@ -120,7 +120,7 @@ defmodule ElectricTelemetry.StackTelemetry do
       sum("electric.subqueries.subset_result.count"),
       sum("electric.subqueries.move_in_triggered.count"),
       last_value("electric.postgres.info_looked_up.pg_version"),
-      distribution("electric.shape_db.pool.checkout.queue_time_μs", unit: :microsecond),
+      distribution("electric.shape_db.pool.checkout.queue_time_us", unit: :microsecond),
       last_value("electric.connection.consumers_ready.duration",
         unit: {:native, :millisecond}
       ),

packages/sync-service/lib/electric/postgres/snapshot_query.ex

@@ -51,12 +51,12 @@ defmodule Electric.Postgres.SnapshotQuery do
       span_attrs,
       stack_id,
       fn ->
-        OpenTelemetry.start_interval(:"shape_snapshot.checkout_wait.duration_µs")
+        OpenTelemetry.start_interval(:"shape_snapshot.checkout_wait.duration_us")
 
         Postgrex.transaction(
           pool,
           fn conn ->
-            OpenTelemetry.start_interval(:"shape_snapshot.setup.duration_µs")
+            OpenTelemetry.start_interval(:"shape_snapshot.setup.duration_us")
 
             ctx = %{
               conn: conn,
@@ -79,7 +79,7 @@ defmodule Electric.Postgres.SnapshotQuery do
               span_name: "shape_snapshot.set_display_settings"
             )
 
-            OpenTelemetry.start_interval(:"shape_snapshot.query.duration_µs")
+            OpenTelemetry.start_interval(:"shape_snapshot.query.duration_us")
 
             result =
               OpenTelemetry.with_child_span(
@@ -90,7 +90,7 @@ defmodule Electric.Postgres.SnapshotQuery do
               )
 
             OpenTelemetry.stop_and_save_intervals(
-              total_attribute: :"shape_snapshot.total.duration_µs"
+              total_attribute: :"shape_snapshot.total.duration_us"
             )
 
             result

packages/sync-service/lib/electric/replication/shape_log_collector.ex

@@ -750,7 +750,7 @@ defmodule Electric.Replication.ShapeLogCollector do
       ],
       state.stack_id,
       fn ->
-        OpenTelemetry.start_interval(:"shape_log_collector.logging.duration_µs")
+        OpenTelemetry.start_interval(:"shape_log_collector.logging.duration_us")
 
         Logger.debug(
           fn ->
@@ -768,7 +768,7 @@ defmodule Electric.Replication.ShapeLogCollector do
         result = handle_txn_fragment(state, txn_fragment)
 
         OpenTelemetry.stop_and_save_intervals(
-          total_attribute: :"shape_log_collector.transaction.total_duration_µs"
+          total_attribute: :"shape_log_collector.transaction.total_duration_us"
         )
 
         put_wall_clock_duration_if_commit(txn_fragment)
@@ -832,11 +832,11 @@ defmodule Electric.Replication.ShapeLogCollector do
   defp handle_txn_fragment(state, txn_fragment) do
     OpenTelemetry.add_span_attributes("txn.is_dropped": false)
 
-    OpenTelemetry.start_interval(:"shape_log_collector.fill_keys_in_txn.duration_µs")
+    OpenTelemetry.start_interval(:"shape_log_collector.fill_keys_in_txn.duration_us")
 
     case fill_keys(txn_fragment, state) do
       {:ok, txn_fragment} ->
-        OpenTelemetry.start_interval(:"partitions.handle_transaction.duration_µs")
+        OpenTelemetry.start_interval(:"partitions.handle_transaction.duration_us")
 
         {partitions, txn_fragment} =
           Partitions.handle_txn_fragment(state.partitions, txn_fragment)
@@ -859,7 +859,7 @@ defmodule Electric.Replication.ShapeLogCollector do
   end
 
   defp publish(state, event) do
-    OpenTelemetry.start_interval(:"shape_log_collector.event_routing.duration_µs")
+    OpenTelemetry.start_interval(:"shape_log_collector.event_routing.duration_us")
 
     {events_by_handle, event_router} =
       EventRouter.event_by_shape_handle(state.event_router, event)
@@ -879,7 +879,7 @@ defmodule Electric.Replication.ShapeLogCollector do
       %{stack_id: state.stack_id}
     )
 
-    OpenTelemetry.start_interval(:"shape_log_collector.publish.duration_µs")
+    OpenTelemetry.start_interval(:"shape_log_collector.publish.duration_us")
     context = OpenTelemetry.get_current_context()
 
     {undeliverable, delivered_pids} =
@@ -920,7 +920,7 @@ defmodule Electric.Replication.ShapeLogCollector do
 
     case event do
       %TransactionFragment{commit: commit} when not is_nil(commit) ->
-        OpenTelemetry.start_interval(:"shape_log_collector.set_last_processed_lsn.duration_µs")
+        OpenTelemetry.start_interval(:"shape_log_collector.set_last_processed_lsn.duration_us")
 
         lsn = Lsn.from_integer(state.last_processed_offset.tx_offset)
         LsnTracker.set_last_processed_lsn(state.stack_id, lsn)
@@ -1033,22 +1033,22 @@ defmodule Electric.Replication.ShapeLogCollector do
         if EventRouter.has_shape?(state.event_router, shape_handle) do
           Logger.debug("Deleting shape #{shape_handle}")
 
-          OpenTelemetry.start_interval(:"unsubscribe_shape.remove_subscription.duration_µs")
+          OpenTelemetry.start_interval(:"unsubscribe_shape.remove_subscription.duration_us")
 
-          OpenTelemetry.start_interval(:"unsubscribe_shape.remove_from_event_router.duration_µs")
+          OpenTelemetry.start_interval(:"unsubscribe_shape.remove_from_event_router.duration_us")
           event_router = EventRouter.remove_shape(state.event_router, shape_handle)
 
-          OpenTelemetry.start_interval(:"unsubscribe_shape.remove_from_partitions.duration_µs")
+          OpenTelemetry.start_interval(:"unsubscribe_shape.remove_from_partitions.duration_us")
           partitions = Partitions.remove_shape(state.partitions, shape_handle)
 
-          OpenTelemetry.start_interval(:"unsubscribe_shape.demonitor_writer.duration_µs")
+          OpenTelemetry.start_interval(:"unsubscribe_shape.demonitor_writer.duration_us")
           state = demonitor_writer(state, shape_handle)
 
-          OpenTelemetry.start_interval(:"unsubscribe_shape.remove_from_flush_tracker.duration_µs")
+          OpenTelemetry.start_interval(:"unsubscribe_shape.remove_from_flush_tracker.duration_us")
           flush_tracker = FlushTracker.handle_shape_removed(state.flush_tracker, shape_handle)
 
           OpenTelemetry.start_interval(
-            :"unsubscribe_shape.remove_from_dependency_layers.duration_µs"
+            :"unsubscribe_shape.remove_from_dependency_layers.duration_us"
           )
 
           dependency_layers =
@@ -1057,7 +1057,7 @@ defmodule Electric.Replication.ShapeLogCollector do
           Electric.Shapes.ConsumerRegistry.remove_consumer(shape_handle, state.registry_state)
 
           OpenTelemetry.stop_and_save_intervals(
-            total_attribute: "unsubscribe_shape.total_duration_µs"
+            total_attribute: "unsubscribe_shape.total_duration_us"
           )
 
           {:ok,

packages/sync-service/lib/electric/shape_cache/shape_cleaner.ex

@@ -31,7 +31,7 @@ defmodule Electric.ShapeCache.ShapeCleaner do
       fn ->
         valid_handles = remove_shapes_immediate(stack_id, shape_handles, reason)
         remove_shapes_deferred(stack_id, valid_handles)
-        OpenTelemetry.stop_and_save_intervals(total_attribute: "remove_shape.total_duration_µs")
+        OpenTelemetry.stop_and_save_intervals(total_attribute: "remove_shape.total_duration_us")
         :ok
       end
     )
@@ -155,18 +155,18 @@ defmodule Electric.ShapeCache.ShapeCleaner do
   end
 
   defp remove_shape_immediate(stack_id, shape_handle, reason) do
-    OpenTelemetry.start_interval(:"remove_shape.shape_status_remove.duration_µs")
+    OpenTelemetry.start_interval(:"remove_shape.shape_status_remove.duration_us")
 
     case Electric.ShapeCache.ShapeStatus.remove_shape(stack_id, shape_handle) do
       :ok ->
-        OpenTelemetry.start_interval(:"remove_shape.shape_consumer_stop.duration_µs")
+        OpenTelemetry.start_interval(:"remove_shape.shape_consumer_stop.duration_us")
 
         stack_storage = Storage.for_stack(stack_id)
 
         with :ok <- Consumer.stop(stack_id, shape_handle, reason),
-             OpenTelemetry.start_interval(:"remove_shape.storage_cleanup.duration_µs"),
+             OpenTelemetry.start_interval(:"remove_shape.storage_cleanup.duration_us"),
              :ok <- Storage.cleanup!(stack_storage, shape_handle),
-             OpenTelemetry.start_interval(:"remove_shape.shape_log_collector_remove.duration_µs"),
+             OpenTelemetry.start_interval(:"remove_shape.shape_log_collector_remove.duration_us"),
              :ok <-
                Electric.Replication.ShapeLogCollector.remove_shape(stack_id, shape_handle) do
           :ok
@@ -183,7 +183,7 @@ defmodule Electric.ShapeCache.ShapeCleaner do
   end
 
   defp remove_shapes_deferred(stack_id, shape_handles) when is_list(shape_handles) do
-    OpenTelemetry.start_interval(:"remove_shape.remove_shapes_deferred.duration_µs")
+    OpenTelemetry.start_interval(:"remove_shape.remove_shapes_deferred.duration_us")
     :ok = CleanupTaskSupervisor.cleanup_async(stack_id, shape_handles)
   end
 

packages/sync-service/lib/electric/shape_cache/shape_status/shape_db/connection.ex

@@ -204,7 +204,7 @@ defmodule Electric.ShapeCache.ShapeStatus.ShapeDb.Connection do
 
     OpenTelemetry.execute(
       [:electric, :shape_db, :pool, :checkout],
-      %{queue_time_μs: enqueued_duration_us},
+      %{queue_time_us: enqueued_duration_us},
       %{label: label, stack_id: Keyword.get(pool_state, :stack_id)}
     )
 

packages/sync-service/lib/electric/shapes/filter.ex

@@ -178,7 +178,7 @@ defmodule Electric.Shapes.Filter do
   @spec affected_shapes(Filter.t(), Changes.change() | Relation.t()) ::
           MapSet.t(shape_id())
   def affected_shapes(%Filter{} = filter, change) do
-    OpenTelemetry.timed_fun("filter.affected_shapes.duration_µs", fn ->
+    OpenTelemetry.timed_fun("filter.affected_shapes.duration_us", fn ->
       try do
         shapes_affected_by_change(filter, change)
       catch

packages/sync-service/lib/electric/telemetry/open_telemetry.ex

@@ -302,16 +302,16 @@ defmodule Electric.Telemetry.OpenTelemetry do
   e.g.
 
   ```elixir
-  OpenTelemetry.start_interval(:quick_sleep.duration_µs)
+  OpenTelemetry.start_interval(:quick_sleep.duration_us)
   Process.sleep(1)
-  OpenTelemetry.start_interval(:longer_sleep.duration_µs)
+  OpenTelemetry.start_interval(:longer_sleep.duration_us)
   Process.sleep(2)
-  OpenTelemetry.stop_and_save_intervals(total_attribute: "total_sleep_µs")
+  OpenTelemetry.stop_and_save_intervals(total_attribute: "total_sleep_us")
   ```
   will add the following attributes to the current span:
-    quick_sleep.duration_µs: 1000
-    longer_sleep.duration_µs: 2000
-    total_sleep_µs: 3000
+    quick_sleep.duration_us: 1000
+    longer_sleep.duration_us: 2000
+    total_sleep_us: 3000
   """
   @spec start_interval(atom()) :: :ok
   def start_interval(interval_name) when is_atom(interval_name) do