Skip to content

Commit

Permalink
Change metrics duration units to seconds. Fixes #1396
Browse files Browse the repository at this point in the history
  • Loading branch information
bgrainger committed Nov 16, 2023
1 parent 8d56d85 commit c5ca41c
Show file tree
Hide file tree
Showing 8 changed files with 39 additions and 39 deletions.
6 changes: 3 additions & 3 deletions docs/content/diagnostics/metrics.md
Original file line number Diff line number Diff line change
Expand Up @@ -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.
6 changes: 3 additions & 3 deletions src/MySqlConnector/Core/ConnectionPool.cs
Original file line number Diff line number Diff line change
Expand Up @@ -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);
}
Expand Down Expand Up @@ -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;
}
}
Expand All @@ -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)
Expand Down
18 changes: 9 additions & 9 deletions src/MySqlConnector/Core/MetricsReporter.cs
Original file line number Diff line number Diff line change
Expand Up @@ -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)
{
Expand Down Expand Up @@ -48,10 +48,10 @@ static MetricsReporter()
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.");
}
6 changes: 3 additions & 3 deletions src/MySqlConnector/Core/ServerSession.cs
Original file line number Diff line number Diff line change
Expand Up @@ -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);
}
Expand Down Expand Up @@ -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);
Expand Down Expand Up @@ -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))
Expand Down
2 changes: 1 addition & 1 deletion src/MySqlConnector/MySqlConnection.cs
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down
14 changes: 7 additions & 7 deletions src/MySqlConnector/Utilities/Utility.cs
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down
12 changes: 6 additions & 6 deletions tests/MySqlConnector.Tests/Metrics/ConnectionTimeTests.cs
Original file line number Diff line number Diff line change
Expand Up @@ -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)]
Expand All @@ -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)]
Expand All @@ -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)]
Expand All @@ -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)]
Expand All @@ -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)]
Expand All @@ -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);
}
}
14 changes: 7 additions & 7 deletions tests/MySqlConnector.Tests/Metrics/MetricsTestsBase.cs
Original file line number Diff line number Diff line change
Expand Up @@ -23,7 +23,7 @@ public MetricsTestsBase()
}
};
m_meterListener.SetMeasurementEventCallback<int>(OnMeasurementRecorded);
m_meterListener.SetMeasurementEventCallback<float>(OnMeasurementRecorded);
m_meterListener.SetMeasurementEventCallback<double>(OnMeasurementRecorded);
m_meterListener.Start();
}

Expand Down Expand Up @@ -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;
}

Expand All @@ -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)
Expand All @@ -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);
}
}
Expand All @@ -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;
}

0 comments on commit c5ca41c

Please sign in to comment.