diff --git a/lib/xandra/connection.ex b/lib/xandra/connection.ex index cbd4d2d7..7887f00e 100644 --- a/lib/xandra/connection.ex +++ b/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 """ diff --git a/lib/xandra/telemetry.ex b/lib/xandra/telemetry.ex index 75a8285f..4527944b 100644 --- a/lib/xandra/telemetry.ex +++ b/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)