Change metrics duration units to seconds. Fixes #1396

Author: bgrainger

docs/content/diagnostics/metrics.md

@@ -34,9 +34,9 @@ Name | Type | Unit | Description
 --- | --- | --- | ---
 `db.client.connections.usage` | UpDownCounter | `{connection}` | The number of connections that are currently in the state described by the state tag.
 `db.client.connections.pending_requests` | UpDownCounter | `{request}` | The number of pending requests for an open connection, cumulative for the entire pool.
-`db.client.connections.create_time` | Histogram | `ms` | The time it took to create a new connection.
-`db.client.connections.use_time` | Histogram | `ms` | The time between borrowing a connection and returning it to the pool.
-`db.client.connections.wait_time` | Histogram | `ms` | The time it took to obtain an open connection from the pool.
+`db.client.connections.create_time` | Histogram | `s` | The time it took to create a new connection.
+`db.client.connections.use_time` | Histogram | `s` | The time between borrowing a connection and returning it to the pool.
+`db.client.connections.wait_time` | Histogram | `s` | The time it took to obtain an open connection from the pool.
 `db.client.connections.idle.max` | UpDownCounter | `{connection}` | The maximum number of idle open connections allowed; this corresponds to `MaximumPoolSize` in the connection string.
 `db.client.connections.idle.min` | UpDownCounter | `{connection}` | The minimum number of idle open connections allowed; this corresponds to `MinimumPoolSize` in the connection string.
 `db.client.connections.max` | UpDownCounter | `{connection}` | The maximum number of open connections allowed; this corresponds to `MaximumPoolSize` in the connection string.

src/MySqlConnector/Core/ConnectionPool.cs

@@ -72,7 +72,7 @@ public async ValueTask<ServerSession> GetSessionAsync(MySqlConnection connection
 					if (ConnectionSettings.ConnectionReset || session.DatabaseOverride is not null)
 					{
 						if (timeoutMilliseconds != 0)
-							session.SetTimeout(Math.Max(1, timeoutMilliseconds - (int) Utility.GetElapsedMilliseconds(startingTimestamp)));
+							session.SetTimeout(Math.Max(1, timeoutMilliseconds - Utility.GetElapsedMilliseconds(startingTimestamp)));
 						reuseSession = await session.TryResetConnectionAsync(ConnectionSettings, connection, ioBehavior, cancellationToken).ConfigureAwait(false);
 						session.SetTimeout(Constants.InfiniteTimeout);
 					}
@@ -104,7 +104,7 @@ public async ValueTask<ServerSession> GetSessionAsync(MySqlConnection connection
 					Log.ReturningPooledSession(m_logger, Id, session.Id, leasedSessionsCountPooled);
 
 					session.LastLeasedTimestamp = Stopwatch.GetTimestamp();
-					MetricsReporter.RecordWaitTime(this, Utility.GetElapsedMilliseconds(startingTimestamp, session.LastLeasedTimestamp));
+					MetricsReporter.RecordWaitTime(this, Utility.GetElapsedSeconds(startingTimestamp, session.LastLeasedTimestamp));
 					return session;
 				}
 			}
@@ -123,7 +123,7 @@ public async ValueTask<ServerSession> GetSessionAsync(MySqlConnection connection
 			Log.ReturningNewSession(m_logger, Id, session.Id, leasedSessionsCountNew);
 
 			session.LastLeasedTimestamp = Stopwatch.GetTimestamp();
-			MetricsReporter.RecordCreateTime(this, Utility.GetElapsedMilliseconds(startingTimestamp, session.LastLeasedTimestamp));
+			MetricsReporter.RecordCreateTime(this, Utility.GetElapsedSeconds(startingTimestamp, session.LastLeasedTimestamp));
 			return session;
 		}
 		catch (Exception ex)

src/MySqlConnector/Core/MetricsReporter.cs

@@ -9,9 +9,9 @@ internal static class MetricsReporter
 	public static void RemoveIdle(ConnectionPool pool) => s_connectionsUsageCounter.Add(-1, pool.IdleStateTagList);
 	public static void AddUsed(ConnectionPool pool) => s_connectionsUsageCounter.Add(1, pool.UsedStateTagList);
 	public static void RemoveUsed(ConnectionPool pool) => s_connectionsUsageCounter.Add(-1, pool.UsedStateTagList);
-	public static void RecordCreateTime(ConnectionPool pool, float milliseconds) => s_createTimeHistory.Record(milliseconds, pool.PoolNameTagList);
-	public static void RecordUseTime(ConnectionPool pool, float milliseconds) => s_useTimeHistory.Record(milliseconds, pool.PoolNameTagList);
-	public static void RecordWaitTime(ConnectionPool pool, float milliseconds) => s_waitTimeHistory.Record(milliseconds, pool.PoolNameTagList);
+	public static void RecordCreateTime(ConnectionPool pool, double seconds) => s_createTimeHistory.Record(seconds, pool.PoolNameTagList);
+	public static void RecordUseTime(ConnectionPool pool, double seconds) => s_useTimeHistory.Record(seconds, pool.PoolNameTagList);
+	public static void RecordWaitTime(ConnectionPool pool, double seconds) => s_waitTimeHistory.Record(seconds, pool.PoolNameTagList);
 
 	public static void AddPendingRequest(ConnectionPool? pool)
 	{
@@ -48,10 +48,10 @@ static IEnumerable<Measurement<int>> GetMinimumConnections() =>
 			unit: "{connection}", description: "The number of connections that are currently in the state described by the state tag.");
 	private static readonly UpDownCounter<int> s_pendingRequestsCounter = ActivitySourceHelper.Meter.CreateUpDownCounter<int>("db.client.connections.pending_requests",
 			unit: "{request}", description: "The number of pending requests for an open connection, cumulative for the entire pool.");
-	private static readonly Histogram<float> s_createTimeHistory = ActivitySourceHelper.Meter.CreateHistogram<float>("db.client.connections.create_time",
-			unit: "ms", description: "The time it took to create a new connection.");
-	private static readonly Histogram<float> s_useTimeHistory = ActivitySourceHelper.Meter.CreateHistogram<float>("db.client.connections.use_time",
-		unit: "ms", description: "The time between borrowing a connection and returning it to the pool.");
-	private static readonly Histogram<float> s_waitTimeHistory = ActivitySourceHelper.Meter.CreateHistogram<float>("db.client.connections.wait_time",
-			unit: "ms", description: "The time it took to obtain an open connection from the pool.");
+	private static readonly Histogram<double> s_createTimeHistory = ActivitySourceHelper.Meter.CreateHistogram<double>("db.client.connections.create_time",
+			unit: "s", description: "The time it took to create a new connection.");
+	private static readonly Histogram<double> s_useTimeHistory = ActivitySourceHelper.Meter.CreateHistogram<double>("db.client.connections.use_time",
+		unit: "s", description: "The time between borrowing a connection and returning it to the pool.");
+	private static readonly Histogram<double> s_waitTimeHistory = ActivitySourceHelper.Meter.CreateHistogram<double>("db.client.connections.wait_time",
+			unit: "s", description: "The time it took to obtain an open connection from the pool.");
 }

src/MySqlConnector/Core/ServerSession.cs

@@ -78,7 +78,7 @@ public ValueTask ReturnToPoolAsync(IOBehavior ioBehavior, MySqlConnection? ownin
 		LastReturnedTimestamp = Stopwatch.GetTimestamp();
 		if (Pool is null)
 			return default;
-		MetricsReporter.RecordUseTime(Pool, Utility.GetElapsedMilliseconds(LastLeasedTimestamp, LastReturnedTimestamp));
+		MetricsReporter.RecordUseTime(Pool, Utility.GetElapsedSeconds(LastLeasedTimestamp, LastReturnedTimestamp));
 		LastLeasedTimestamp = 0;
 		return Pool.ReturnAsync(ioBehavior, this);
 	}
@@ -456,7 +456,7 @@ public async Task DisposeAsync(IOBehavior ioBehavior, CancellationToken cancella
 
 				var byteHandler = m_socket is null ? new StreamByteHandler(m_stream!) : (IByteHandler) new SocketByteHandler(m_socket);
 				if (cs.ConnectionTimeout != 0)
-					byteHandler.RemainingTimeout = Math.Max(1, cs.ConnectionTimeoutMilliseconds - (int) Utility.GetElapsedMilliseconds(startingTimestamp));
+					byteHandler.RemainingTimeout = Math.Max(1, cs.ConnectionTimeoutMilliseconds - Utility.GetElapsedMilliseconds(startingTimestamp));
 				m_payloadHandler = new StandardPayloadHandler(byteHandler);
 
 				payload = await ReceiveAsync(ioBehavior, cancellationToken).ConfigureAwait(false);
@@ -1218,7 +1218,7 @@ private async Task<bool> OpenNamedPipeAsync(ConnectionSettings cs, long starting
 		}
 
 		var namedPipeStream = new NamedPipeClientStream(cs.HostNames![0], cs.PipeName, PipeDirection.InOut, PipeOptions.Asynchronous);
-		var timeout = Math.Max(1, cs.ConnectionTimeoutMilliseconds - (int) Utility.GetElapsedMilliseconds(startingTimestamp));
+		var timeout = Math.Max(1, cs.ConnectionTimeoutMilliseconds - Utility.GetElapsedMilliseconds(startingTimestamp));
 		try
 		{
 			using (cancellationToken.Register(namedPipeStream.Dispose))

src/MySqlConnector/MySqlConnection.cs

@@ -907,7 +907,7 @@ private async ValueTask<ServerSession> CreateSessionAsync(ConnectionPool? pool,
 			// the cancellation token for connection is controlled by 'cancellationToken' (if it can be cancelled), ConnectionTimeout
 			// (from the connection string, if non-zero), or a combination of both
 			if (connectionSettings.ConnectionTimeout != 0)
-				timeoutSource = new CancellationTokenSource(TimeSpan.FromMilliseconds(Math.Max(1, connectionSettings.ConnectionTimeoutMilliseconds - (int) Utility.GetElapsedMilliseconds(startingTimestamp))));
+				timeoutSource = new CancellationTokenSource(TimeSpan.FromMilliseconds(Math.Max(1, connectionSettings.ConnectionTimeoutMilliseconds - Utility.GetElapsedMilliseconds(startingTimestamp))));
 			if (cancellationToken.CanBeCanceled && timeoutSource is not null)
 				linkedSource = CancellationTokenSource.CreateLinkedTokenSource(cancellationToken, timeoutSource.Token);
 			var connectToken = linkedSource?.Token ?? timeoutSource?.Token ?? cancellationToken;

src/MySqlConnector/Utilities/Utility.cs

@@ -568,21 +568,21 @@ public static void GetOSDetails(out string? os, out string osDescription, out st
 	/// <summary>
 	/// Gets the elapsed time (in milliseconds) since the specified <paramref name="startingTimestamp"/> (which must be a value returned from <see cref="Stopwatch.GetTimestamp"/>.
 	/// </summary>
-	public static float GetElapsedMilliseconds(long startingTimestamp) =>
+	public static int GetElapsedMilliseconds(long startingTimestamp) =>
 #if NET7_0_OR_GREATER
-		(float) Stopwatch.GetElapsedTime(startingTimestamp).TotalMilliseconds;
+		(int) Stopwatch.GetElapsedTime(startingTimestamp).TotalMilliseconds;
 #else
-		GetElapsedMilliseconds(startingTimestamp, Stopwatch.GetTimestamp());
+		(int) ((Stopwatch.GetTimestamp() - startingTimestamp) * 1000L / Stopwatch.Frequency);
 #endif
 
 	/// <summary>
-	/// Gets the elapsed time (in milliseconds) between the specified <paramref name="startingTimestamp"/> and <paramref name="endingTimestamp"/>. (These must be values returned from <see cref="Stopwatch.GetTimestamp"/>.)
+	/// Gets the elapsed time (in seconds) between the specified <paramref name="startingTimestamp"/> and <paramref name="endingTimestamp"/>. (These must be values returned from <see cref="Stopwatch.GetTimestamp"/>.)
 	/// </summary>
-	public static float GetElapsedMilliseconds(long startingTimestamp, long endingTimestamp) =>
+	public static double GetElapsedSeconds(long startingTimestamp, long endingTimestamp) =>
 #if NET7_0_OR_GREATER
-		(float) Stopwatch.GetElapsedTime(startingTimestamp, endingTimestamp).TotalMilliseconds;
+		Stopwatch.GetElapsedTime(startingTimestamp, endingTimestamp).TotalSeconds;
 #else
-		(endingTimestamp - startingTimestamp) * 1000.0f / Stopwatch.Frequency;
+		(endingTimestamp - startingTimestamp) / (double) Stopwatch.Frequency;
 #endif
 
 #if NET462

tests/MySqlConnector.Tests/Metrics/ConnectionTimeTests.cs

@@ -11,7 +11,7 @@ public async Task ConnectionTime()
 		await connection.OpenAsync();
 		var measurements = GetAndClearMeasurements("db.client.connections.create_time");
 		var time = Assert.Single(measurements);
-		Assert.InRange(time, 0, 300);
+		Assert.InRange(time, 0, 0.3);
 	}
 
 	[Fact(Skip = MetricsSkip)]
@@ -25,7 +25,7 @@ public async Task ConnectionTimeWithDelay()
 		await connection.OpenAsync();
 		var measurements = GetAndClearMeasurements("db.client.connections.create_time");
 		var time = Assert.Single(measurements);
-		Assert.InRange(time, 1000, 1300);
+		Assert.InRange(time, 1.0, 1.3);
 	}
 
 	[Fact(Skip = MetricsSkip)]
@@ -41,7 +41,7 @@ public async Task OpenFromPoolTime()
 		await connection.OpenAsync();
 		var measurements = GetAndClearMeasurements("db.client.connections.wait_time");
 		var time = Assert.Single(measurements);
-		Assert.InRange(time, 0, 200);
+		Assert.InRange(time, 0, 0.2);
 	}
 
 	[Fact(Skip = MetricsSkip)]
@@ -58,7 +58,7 @@ public async Task OpenFromPoolTimeWithDelay()
 		await connection.OpenAsync();
 		var measurements = GetAndClearMeasurements("db.client.connections.wait_time");
 		var time = Assert.Single(measurements);
-		Assert.InRange(time, 1000, 1200);
+		Assert.InRange(time, 1.0, 1.2);
 	}
 
 	[Fact(Skip = MetricsSkip)]
@@ -72,7 +72,7 @@ public async Task UseTime()
 		connection.Close();
 
 		var time = Assert.Single(GetAndClearMeasurements("db.client.connections.use_time"));
-		Assert.InRange(time, 0, 100);
+		Assert.InRange(time, 0, 0.1);
 	}
 
 	[Fact(Skip = MetricsSkip)]
@@ -87,6 +87,6 @@ public async Task UseTimeWithDelay()
 		connection.Close();
 
 		var time = Assert.Single(GetAndClearMeasurements("db.client.connections.use_time"));
-		Assert.InRange(time, 500, 600);
+		Assert.InRange(time, 0.5, 0.6);
 	}
 }

tests/MySqlConnector.Tests/Metrics/MetricsTestsBase.cs

@@ -23,7 +23,7 @@ public MetricsTestsBase()
 			}
 		};
 		m_meterListener.SetMeasurementEventCallback<int>(OnMeasurementRecorded);
-		m_meterListener.SetMeasurementEventCallback<float>(OnMeasurementRecorded);
+		m_meterListener.SetMeasurementEventCallback<double>(OnMeasurementRecorded);
 		m_meterListener.Start();
 	}
 
@@ -68,11 +68,11 @@ protected void AssertMeasurement(string name, int expected)
 			Assert.Equal(expected, m_measurements.GetValueOrDefault(name));
 	}
 
-	protected List<float> GetAndClearMeasurements(string name)
+	protected List<double> GetAndClearMeasurements(string name)
 	{
 		if (!m_timeMeasurements.TryGetValue(name, out var list))
-			list = new List<float>();
-		m_timeMeasurements[name] = new List<float>();
+			list = new();
+		m_timeMeasurements[name] = new List<double>();
 		return list;
 	}
 
@@ -96,7 +96,7 @@ private void OnMeasurementRecorded(Instrument instrument, int measurement, ReadO
 		}
 	}
 
-	private void OnMeasurementRecorded(Instrument instrument, float measurement, ReadOnlySpan<KeyValuePair<string, object?>> tags, object? state)
+	private void OnMeasurementRecorded(Instrument instrument, double measurement, ReadOnlySpan<KeyValuePair<string, object?>> tags, object? state)
 	{
 		var (poolName, stateTag) = GetTags(tags);
 		if (poolName != PoolName)
@@ -105,7 +105,7 @@ private void OnMeasurementRecorded(Instrument instrument, float measurement, Rea
 		lock (m_timeMeasurements)
 		{
 			if (!m_timeMeasurements.TryGetValue(instrument.Name, out var list))
-				list = m_timeMeasurements[instrument.Name] = new List<float>();
+				list = m_timeMeasurements[instrument.Name] = new List<double>();
 			list.Add(measurement);
 		}
 	}
@@ -126,6 +126,6 @@ private void OnMeasurementRecorded(Instrument instrument, float measurement, Rea
 
 
 	private readonly Dictionary<string, int> m_measurements;
-	private readonly Dictionary<string, List<float>> m_timeMeasurements;
+	private readonly Dictionary<string, List<double>> m_timeMeasurements;
 	private readonly MeterListener m_meterListener;
 }