Skip to content

Commit 884b113

Browse files
DavoudEshtehariDavoud Eshteharikarinazhouwinseros
authored
Supporting Event counter in .Net core (#719)
* Add event counters * Add support netstandard 2.1 & fix the conflict in event source * Support new event source types & add the test unit * Remove supporting obsolete types * fix unit test * Add snippet sample code * Address comments * Fix minor typo (#3) * Reformatting counter methods * Fix minor typo * Removed IsEnabled condition and reformatted counter methods * Unit tests for Microsoft.Data.SqlClient.SqlClientEventSource (#2) * Implemented tests for Microsoft.Data.SqlClient.SqlClientEventSource * Updated the EventCounter test to reflect the recent changes in the code * Working on EventCounter tests access event counters through reflection * Updated the EventCounterTest to use reflection * Fixing dangling SqlConnection's left in tests * EventCountersTest now checks hard/soft connects/disconnects counters * Reverted the DataTestUtility changes * Reverted using statements to the old-style in tests * Reverted the ConnectionPoolTest.ReclaimEmancipatedOnOpenTest() * Reverted using statements to the old-style in tests * Reverted using statements to the old-style in tests * Rewrite the EventCounterTest assertions not to conflict with other tests * Code review cleanup * Add more tests (#5) Added EventCounter_ReclaimedConnectionsCounter_Functional & EventCounter_ConnectionPoolGroupsCounter_Functional tests. * Address comments Co-authored-by: Davoud Eshtehari <David.esh@gmail.com> Co-authored-by: Davoud Eshtehari <v-daesht@microsoft.com> Co-authored-by: Karina Zhou <v-jizho2@microsoft.com> Co-authored-by: Nikita Kobzev <win.accuracy@gmail.com>
1 parent 0005645 commit 884b113

File tree

20 files changed

+1097
-137
lines changed

20 files changed

+1097
-137
lines changed

‎doc/samples/SqlClientDiagnosticCounter.cs‎

Lines changed: 62 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,62 @@
1+
// <Snippet1>
2+
using System;
3+
using System.Collections.Generic;
4+
using System.Diagnostics.Tracing;
5+
using System.Linq;
6+
7+
// This listener class will listen for events from the SqlClientEventSource class.
8+
// SqlClientEventSource is an implementation of the EventSource class which gives
9+
// it the ability to create events.
10+
public class EventCounterListener : EventListener
11+
{
12+
protected override void OnEventSourceCreated(EventSource eventSource)
13+
{
14+
// Only enable events from SqlClientEventSource.
15+
if (eventSource.Name.Equals("Microsoft.Data.SqlClient.EventSource"))
16+
{
17+
var options = new Dictionary<string, string>();
18+
// define time interval 1 second
19+
// without defining this parameter event counters will not enabled
20+
options.Add("EventCounterIntervalSec", "1");
21+
// enable for the None keyword
22+
EnableEvents(eventSource, EventLevel.Informational, EventKeywords.None, options);
23+
}
24+
}
25+
26+
// This callback runs whenever an event is written by SqlClientEventSource.
27+
// Event data is accessed through the EventWrittenEventArgs parameter.
28+
protected override void OnEventWritten(EventWrittenEventArgs eventData)
29+
{
30+
if (eventData.Payload.FirstOrDefault(p => p is IDictionary<string, object> x && x.ContainsKey("Name")) is IDictionary<string, object> counters)
31+
{
32+
if (counters.TryGetValue("DisplayName", out object name) && name is string cntName
33+
&& counters.TryGetValue("Mean", out object value) && value is double cntValue)
34+
{
35+
// print event counter's name and mean value
36+
Console.WriteLine($"{cntName}\t\t{cntValue}");
37+
}
38+
}
39+
}
40+
}
41+
42+
class Program
43+
{
44+
static void Main(string[] args)
45+
{
46+
// Create a new event listener
47+
using (var listener = new EventCounterListener())
48+
{
49+
string connectionString = "Data Source=localhost; Integrated Security=true";
50+
51+
for (int i = 0; i < 50; i++)
52+
{
53+
// Open a connection
54+
SqlConnection cnn = new SqlConnection(connectionString);
55+
cnn.Open();
56+
// wait for sampling interval happens
57+
System.Threading.Thread.Sleep(500);
58+
}
59+
}
60+
}
61+
}
62+
// </Snippet1>

‎src/Microsoft.Data.SqlClient/netcore/src/Common/src/Microsoft/Data/ProviderBase/DbConnectionFactory.cs‎

Lines changed: 13 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -25,7 +25,7 @@ internal abstract partial class DbConnectionFactory
2525
private static int _objectTypeCount; // EventSource counter
2626
internal int ObjectID { get; } = Interlocked.Increment(ref _objectTypeCount);
2727

28-
// s_pendingOpenNonPooled is an array of tasks used to throttle creation of non-pooled connections to
28+
// s_pendingOpenNonPooled is an array of tasks used to throttle creation of non-pooled connections to
2929
// a maximum of Environment.ProcessorCount at a time.
3030
private static uint s_pendingOpenNonPooledNext = 0;
3131
private static Task<DbConnectionInternal>[] s_pendingOpenNonPooled = new Task<DbConnectionInternal>[Environment.ProcessorCount];
@@ -124,6 +124,7 @@ internal DbConnectionInternal CreateNonPooledConnection(DbConnection owningConne
124124
DbConnectionInternal newConnection = CreateConnection(connectionOptions, poolKey, poolGroupProviderInfo, null, owningConnection, userOptions);
125125
if (null != newConnection)
126126
{
127+
SqlClientEventSource.Log.HardConnectRequest();
127128
newConnection.MakeNonPooledObject(owningConnection);
128129
}
129130
SqlClientEventSource.Log.TryTraceEvent("<prov.DbConnectionFactory.CreateNonPooledConnection|RES|CPOOL> {0}, Non-pooled database connection created.", ObjectID);
@@ -138,6 +139,7 @@ internal DbConnectionInternal CreatePooledConnection(DbConnectionPool pool, DbCo
138139
DbConnectionInternal newConnection = CreateConnection(options, poolKey, poolGroupProviderInfo, pool, owningObject, userOptions);
139140
if (null != newConnection)
140141
{
142+
SqlClientEventSource.Log.HardConnectRequest();
141143
newConnection.MakePooledConnection(pool);
142144
}
143145
SqlClientEventSource.Log.TryTraceEvent("<prov.DbConnectionFactory.CreatePooledConnection|RES|CPOOL> {0}, Pooled database connection created.", ObjectID);
@@ -281,6 +283,7 @@ internal DbConnectionPoolGroup GetConnectionPoolGroup(DbConnectionPoolKey key, D
281283

282284
// lock prevents race condition with PruneConnectionPoolGroups
283285
newConnectionPoolGroups.Add(key, newConnectionPoolGroup);
286+
SqlClientEventSource.Log.EnterActiveConnectionPoolGroup();
284287
connectionPoolGroup = newConnectionPoolGroup;
285288
_connectionPoolGroups = newConnectionPoolGroups;
286289
}
@@ -304,7 +307,7 @@ private void PruneConnectionPoolGroups(object state)
304307
{
305308
// when debugging this method, expect multiple threads at the same time
306309
SqlClientEventSource.Log.TryAdvancedTraceEvent("<prov.DbConnectionFactory.PruneConnectionPoolGroups|RES|INFO|CPOOL> {0}", ObjectID);
307-
310+
308311
// First, walk the pool release list and attempt to clear each
309312
// pool, when the pool is finally empty, we dispose of it. If the
310313
// pool isn't empty, it's because there are active connections or
@@ -324,6 +327,7 @@ private void PruneConnectionPoolGroups(object state)
324327
{
325328
_poolsToRelease.Remove(pool);
326329
SqlClientEventSource.Log.TryAdvancedTraceEvent("<prov.DbConnectionFactory.PruneConnectionPoolGroups|RES|INFO|CPOOL> {0}, ReleasePool={1}", ObjectID, pool.ObjectID);
330+
SqlClientEventSource.Log.ExitInactiveConnectionPool();
327331
}
328332
}
329333
}
@@ -348,6 +352,7 @@ private void PruneConnectionPoolGroups(object state)
348352
{
349353
_poolGroupsToRelease.Remove(poolGroup);
350354
SqlClientEventSource.Log.TryAdvancedTraceEvent("<prov.DbConnectionFactory.PruneConnectionPoolGroups|RES|INFO|CPOOL> {0}, ReleasePoolGroup={1}", ObjectID, poolGroup.ObjectID);
355+
SqlClientEventSource.Log.ExitInactiveConnectionPoolGroup();
351356
}
352357
}
353358
}
@@ -372,7 +377,8 @@ private void PruneConnectionPoolGroups(object state)
372377
// move idle entries from last prune pass to a queue for pending release
373378
// otherwise process entry which may move it from active to idle
374379
if (entry.Value.Prune())
375-
{ // may add entries to _poolsToRelease
380+
{
381+
// may add entries to _poolsToRelease
376382
QueuePoolGroupForRelease(entry.Value);
377383
}
378384
else
@@ -405,6 +411,8 @@ internal void QueuePoolForRelease(DbConnectionPool pool, bool clearing)
405411
}
406412
_poolsToRelease.Add(pool);
407413
}
414+
SqlClientEventSource.Log.EnterInactiveConnectionPool();
415+
SqlClientEventSource.Log.ExitActiveConnectionPool();
408416
}
409417

410418
internal void QueuePoolGroupForRelease(DbConnectionPoolGroup poolGroup)
@@ -416,6 +424,8 @@ internal void QueuePoolGroupForRelease(DbConnectionPoolGroup poolGroup)
416424
{
417425
_poolGroupsToRelease.Add(poolGroup);
418426
}
427+
SqlClientEventSource.Log.EnterInactiveConnectionPoolGroup();
428+
SqlClientEventSource.Log.ExitActiveConnectionPoolGroup();
419429
}
420430

421431
virtual protected DbConnectionInternal CreateConnection(DbConnectionOptions options, DbConnectionPoolKey poolKey, object poolGroupProviderInfo, DbConnectionPool pool, DbConnection owningConnection, DbConnectionOptions userOptions)

‎src/Microsoft.Data.SqlClient/netcore/src/Common/src/Microsoft/Data/ProviderBase/DbConnectionInternal.cs‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -231,6 +231,7 @@ internal void DeactivateConnection()
231231
int activateCount = Interlocked.Decrement(ref _activateCount);
232232
#endif // DEBUG
233233

234+
SqlClientEventSource.Log.ExitActiveConnection();
234235

235236
if (!_connectionIsDoomed && Pool.UseLoadBalancing)
236237
{

‎src/Microsoft.Data.SqlClient/netcore/src/Common/src/Microsoft/Data/ProviderBase/DbConnectionPoolGroup.cs‎

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -187,15 +187,16 @@ internal DbConnectionPool GetConnectionPool(DbConnectionFactory connectionFactor
187187
newPool.Startup(); // must start pool before usage
188188
bool addResult = _poolCollection.TryAdd(currentIdentity, newPool);
189189
Debug.Assert(addResult, "No other pool with current identity should exist at this point");
190+
SqlClientEventSource.Log.EnterActiveConnectionPool();
190191
pool = newPool;
191192
}
192193
else
193194
{
194195
// else pool entry has been disabled so don't create new pools
195196
Debug.Assert(PoolGroupStateDisabled == _state, "state should be disabled");
196197

197-
// don't need to call connectionFactory.QueuePoolForRelease(newPool) because
198-
// pool callbacks were delayed and no risk of connections being created
198+
// don't need to call connectionFactory.QueuePoolForRelease(newPool) because
199+
// pool callbacks were delayed and no risk of connections being created
199200
newPool.Shutdown();
200201
}
201202
}
@@ -262,7 +263,6 @@ internal bool Prune()
262263
// pool into a list of pools to be released when they
263264
// are completely empty.
264265
DbConnectionFactory connectionFactory = pool.ConnectionFactory;
265-
266266
connectionFactory.QueuePoolForRelease(pool, false);
267267
}
268268
else

‎src/Microsoft.Data.SqlClient/netcore/src/Microsoft.Data.SqlClient.csproj‎

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -327,6 +327,10 @@
327327
<Compile Include="Microsoft\Data\SqlClient\VirtualSecureModeEnclaveProviderBase.cs" />
328328
<Compile Include="Microsoft\Data\SqlClient\AlwaysEncryptedEnclaveProviderUtils.cs" />
329329
</ItemGroup>
330+
<!-- netcoreapp 3.1 & netstandard 2.1 and above -->
331+
<ItemGroup Condition="'$(OSGroup)' != 'AnyOS' AND '$(TargetFramework)' != 'netcoreapp2.1' AND '$(TargetFramework)' != 'netstandard2.0'">
332+
<Compile Include="Microsoft\Data\SqlClient\SqlClientEventSource.NetCoreApp.cs" />
333+
</ItemGroup>
330334
<ItemGroup Condition="'$(OSGroup)' != 'AnyOS' AND '$(TargetGroup)' == 'netcoreapp'">
331335
<Compile Include="Microsoft\Data\Common\DbConnectionStringCommon.NetCoreApp.cs" />
332336
<Compile Include="Microsoft\Data\ProviderBase\DbConnectionPool.NetCoreApp.cs" />

‎src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/ProviderBase/DbConnectionFactory.cs‎

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -108,6 +108,7 @@ internal bool TryGetConnection(DbConnection owningConnection, TaskCompletionSour
108108
}
109109

110110
connection = CreateNonPooledConnection(owningConnection, poolGroup, userOptions);
111+
SqlClientEventSource.Log.EnterNonPooledConnection();
111112
}
112113
else
113114
{
@@ -209,6 +210,10 @@ private static void TryGetConnectionCompletedContinuation(Task<DbConnectionInter
209210
task.Result.DoomThisConnection();
210211
task.Result.Dispose();
211212
}
213+
else
214+
{
215+
SqlClientEventSource.Log.EnterNonPooledConnection();
216+
}
212217
}
213218
}
214219
}

‎src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/ProviderBase/DbConnectionInternal.cs‎

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -219,6 +219,7 @@ internal void ActivateConnection(Transaction transaction)
219219
#endif // DEBUG
220220

221221
Activate(transaction);
222+
SqlClientEventSource.Log.EnterActiveConnection();
222223
}
223224

224225
internal virtual void CloseConnection(DbConnection owningObject, DbConnectionFactory connectionFactory)
@@ -296,6 +297,7 @@ internal virtual void CloseConnection(DbConnection owningObject, DbConnectionFac
296297
else
297298
{
298299
Deactivate(); // ensure we de-activate non-pooled connections, or the data readers and transactions may not get cleaned up...
300+
SqlClientEventSource.Log.HardDisconnectRequest();
299301

300302
// To prevent an endless recursion, we need to clear
301303
// the owning object before we call dispose so that
@@ -312,6 +314,7 @@ internal virtual void CloseConnection(DbConnection owningObject, DbConnectionFac
312314
}
313315
else
314316
{
317+
SqlClientEventSource.Log.ExitNonPooledConnection();
315318
Dispose();
316319
}
317320
}
@@ -370,6 +373,7 @@ virtual internal void DelegatedTransactionEnded()
370373
// once and for all, or the server will have fits about us
371374
// leaving connections open until the client-side GC kicks
372375
// in.
376+
SqlClientEventSource.Log.ExitNonPooledConnection();
373377
Dispose();
374378
}
375379
// When _pooledCount is 0, the connection is a pooled connection
@@ -482,6 +486,7 @@ internal void SetInStasis()
482486
{
483487
_isInStasis = true;
484488
SqlClientEventSource.Log.TryPoolerTraceEvent("<prov.DbConnectionInternal.SetInStasis|RES|CPOOL> {0}, Non-Pooled Connection has Delegated Transaction, waiting to Dispose.", ObjectID);
489+
SqlClientEventSource.Log.EnterStasisConnection();
485490
}
486491

487492
private void TerminateStasis(bool returningToPool)
@@ -494,6 +499,7 @@ private void TerminateStasis(bool returningToPool)
494499
{
495500
SqlClientEventSource.Log.TryPoolerTraceEvent("<prov.DbConnectionInternal.TerminateStasis|RES|CPOOL> {0}, Delegated Transaction has ended, connection is closed/leaked. Disposing.", ObjectID);
496501
}
502+
SqlClientEventSource.Log.ExitStasisConnection();
497503
_isInStasis = false;
498504
}
499505
}

‎src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/ProviderBase/DbConnectionPool.cs‎

Lines changed: 16 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -231,6 +231,7 @@ internal void PutTransactedObject(Transaction transaction, DbConnectionInternal
231231
}
232232
SqlClientEventSource.Log.TryPoolerTraceEvent("<prov.DbConnectionPool.TransactedConnectionPool.PutTransactedObject|RES|CPOOL> {0}, Transaction {1}, Connection {2}, Added.", ObjectID, transaction.GetHashCode(), transactedObject.ObjectID);
233233
}
234+
SqlClientEventSource.Log.EnterFreeConnection();
234235
}
235236

236237
internal void TransactionEnded(Transaction transaction, DbConnectionInternal transactedObject)
@@ -293,6 +294,7 @@ internal void TransactionEnded(Transaction transaction, DbConnectionInternal tra
293294
// connections, we'll put it back...
294295
if (0 <= entry)
295296
{
297+
SqlClientEventSource.Log.ExitFreeConnection();
296298
Pool.PutObjectFromTransactedPool(transactedObject);
297299
}
298300
}
@@ -600,6 +602,7 @@ private void CleanupCallback(object state)
600602
{
601603
Debug.Assert(obj != null, "null connection is not expected");
602604
// If we obtained one from the old stack, destroy it.
605+
SqlClientEventSource.Log.ExitFreeConnection();
603606

604607
// Transaction roots must survive even aging out (TxEnd event will clean them up).
605608
bool shouldDestroy = true;
@@ -696,11 +699,13 @@ internal void Clear()
696699
while (_stackNew.TryPop(out obj))
697700
{
698701
Debug.Assert(obj != null, "null connection is not expected");
702+
SqlClientEventSource.Log.ExitFreeConnection();
699703
DestroyObject(obj);
700704
}
701705
while (_stackOld.TryPop(out obj))
702706
{
703707
Debug.Assert(obj != null, "null connection is not expected");
708+
SqlClientEventSource.Log.ExitFreeConnection();
704709
DestroyObject(obj);
705710
}
706711

@@ -742,6 +747,7 @@ private DbConnectionInternal CreateObject(DbConnection owningObject, DbConnectio
742747
}
743748
_objectList.Add(newObj);
744749
_totalObjects = _objectList.Count;
750+
SqlClientEventSource.Log.EnterPooledConnection();
745751
}
746752

747753
// If the old connection belonged to another pool, we need to remove it from that
@@ -967,9 +973,11 @@ internal void DestroyObject(DbConnectionInternal obj)
967973
if (removed)
968974
{
969975
SqlClientEventSource.Log.TryPoolerTraceEvent("<prov.DbConnectionPool.DestroyObject|RES|CPOOL> {0}, Connection {1}, Removed from pool.", ObjectID, obj.ObjectID);
976+
SqlClientEventSource.Log.ExitPooledConnection();
970977
}
971978
obj.Dispose();
972979
SqlClientEventSource.Log.TryPoolerTraceEvent("<prov.DbConnectionPool.DestroyObject|RES|CPOOL> {0}, Connection {1}, Disposed.", ObjectID, obj.ObjectID);
980+
SqlClientEventSource.Log.HardDisconnectRequest();
973981
}
974982
}
975983

@@ -1301,6 +1309,7 @@ private bool TryGetConnection(DbConnection owningObject, uint waitForMultipleObj
13011309
}
13021310

13031311
connection = obj;
1312+
SqlClientEventSource.Log.SoftConnectRequest();
13041313
return true;
13051314
}
13061315

@@ -1337,6 +1346,7 @@ internal DbConnectionInternal ReplaceConnection(DbConnection owningObject, DbCon
13371346

13381347
if (newConnection != null)
13391348
{
1349+
SqlClientEventSource.Log.SoftConnectRequest();
13401350
PrepareConnection(owningObject, newConnection, oldConnection.EnlistedTransaction);
13411351
oldConnection.PrepareForReplaceConnection();
13421352
oldConnection.DeactivateConnection();
@@ -1374,6 +1384,7 @@ private DbConnectionInternal GetFromGeneralPool()
13741384
if (null != obj)
13751385
{
13761386
SqlClientEventSource.Log.TryPoolerTraceEvent("<prov.DbConnectionPool.GetFromGeneralPool|RES|CPOOL> {0}, Connection {1}, Popped from general pool.", ObjectID, obj.ObjectID);
1387+
SqlClientEventSource.Log.ExitFreeConnection();
13771388
}
13781389
return (obj);
13791390
}
@@ -1390,6 +1401,7 @@ private DbConnectionInternal GetFromTransactedPool(out Transaction transaction)
13901401
if (null != obj)
13911402
{
13921403
SqlClientEventSource.Log.TryPoolerTraceEvent("<prov.DbConnectionPool.GetFromTransactedPool|RES|CPOOL> {0}, Connection {1}, Popped from transacted pool.", ObjectID, obj.ObjectID);
1404+
SqlClientEventSource.Log.ExitFreeConnection();
13931405

13941406
if (obj.IsTransactionRoot)
13951407
{
@@ -1544,12 +1556,13 @@ internal void PutNewObject(DbConnectionInternal obj)
15441556

15451557
_stackNew.Push(obj);
15461558
_waitHandles.PoolSemaphore.Release(1);
1559+
SqlClientEventSource.Log.EnterFreeConnection();
15471560
}
15481561

15491562
internal void PutObject(DbConnectionInternal obj, object owningObject)
15501563
{
15511564
Debug.Assert(null != obj, "null obj?");
1552-
1565+
SqlClientEventSource.Log.SoftDisconnectRequest();
15531566

15541567
// Once a connection is closing (which is the state that we're in at
15551568
// this point in time) you cannot delegate a transaction to or enlist
@@ -1662,6 +1675,8 @@ private bool ReclaimEmancipatedObjects()
16621675
{
16631676
DbConnectionInternal obj = reclaimedObjects[i];
16641677
SqlClientEventSource.Log.TryPoolerTraceEvent("<prov.DbConnectionPool.ReclaimEmancipatedObjects|RES|CPOOL> {0}, Connection {1}, Reclaiming.", ObjectID, obj.ObjectID);
1678+
SqlClientEventSource.Log.ReclaimedConnectionRequest();
1679+
16651680
emancipatedObjectFound = true;
16661681

16671682
obj.DetachCurrentTransactionIfEnded();

0 commit comments

Comments
 (0)