Add telemetry event for timed out response

lib/xandra/connection.ex

@@ -22,8 +22,6 @@ defmodule Xandra.Connection do
   @max_cassandra_stream_id 32_768
   @restore_timed_out_stream_id_timeout 30 * 60 * 60 * 1000
 
-  require Logger
-
   # This record is used internally when we check out a "view" of the state of
   # the connection. This holds all the necessary info to encode queries and more.
   # It's a record just so that we don't have to create yet another module for a struct.
@@ -738,7 +736,11 @@ defmodule Xandra.Connection do
     case pop_in(data.in_flight_requests[stream_id]) do
       {nil, data} ->
         if MapSet.member?(data.timed_out_ids, stream_id) do
-          Logger.warning("Received message with stream id #{stream_id}, but it had timed out")
+          :telemetry.execute(
+            [:xandra, :timed_out_response],
+            telemetry_meta(data, %{stream_id: stream_id})
+          )
+
           update_in(data.timed_out_ids, &MapSet.delete(&1, stream_id))
         else
           raise """

lib/xandra/telemetry.ex

@@ -68,6 +68,7 @@ defmodule Xandra.Telemetry do
       [:xandra, :prepared_cache, :miss],
       [:xandra, :prepare_query, :stop],
       [:xandra, :execute_query, :stop],
+      [:xandra, :timed_out_response],
       [:xandra, :server_warnings],
       [:xandra, :cluster, :change_event],
       [:xandra, :cluster, :control_connection, :connected],
@@ -170,6 +171,12 @@ defmodule Xandra.Telemetry do
       [:server_warnings] ->
         Logger.warning("Received warnings: #{inspect(measurements.warnings)}", logger_meta)
 
+      [:timed_out_response] ->
+        Logger.warning(
+          "Received response for stream id #{metadata.stream_id}, but request had already timed out",
+          logger_meta
+        )
+
       [:prepared_cache, status] when status in [:hit, :miss] ->
         query = inspect(metadata.query)
         Logger.debug("Prepared cache #{status} for query: #{query}", logger_meta)