Skip to content

Commit 1cba30a

Browse files
Charles-GagnonCharles-Gagnon
authored
Remove extra events (#573)
* Remove extra events * more * fixes * Remove more extras
1 parent ca7a3e1 commit 1cba30a

File tree

4 files changed

+50
-63
lines changed

4 files changed

+50
-63
lines changed

‎src/SqlAsyncCollector.cs‎

Lines changed: 1 addition & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -528,7 +528,6 @@ WHEN NOT MATCHED THEN
528528
public static async Task<TableInformation> RetrieveTableInformationAsync(SqlConnection sqlConnection, string fullName, ILogger logger, IEnumerable<string> objectColumnNames)
529529
{
530530
Dictionary<TelemetryPropertyName, string> sqlConnProps = sqlConnection.AsConnectionProps();
531-
TelemetryInstance.TrackEvent(TelemetryEventName.GetTableInfoStart, sqlConnProps);
532531
logger.LogDebugWithThreadId("BEGIN RetrieveTableInformationAsync");
533532
var table = new SqlObject(fullName);
534533

@@ -641,7 +640,7 @@ public static async Task<TableInformation> RetrieveTableInformationAsync(SqlConn
641640
};
642641
sqlConnProps.Add(TelemetryPropertyName.QueryType, usingInsertQuery ? "insert" : "merge");
643642
sqlConnProps.Add(TelemetryPropertyName.HasIdentityColumn, hasIdentityColumnPrimaryKeys.ToString());
644-
TelemetryInstance.TrackDuration(TelemetryEventName.GetTableInfoEnd, tableInfoSw.ElapsedMilliseconds, sqlConnProps, durations);
643+
TelemetryInstance.TrackDuration(TelemetryEventName.GetTableInfo, tableInfoSw.ElapsedMilliseconds, sqlConnProps, durations);
645644
logger.LogDebugWithThreadId($"END RetrieveTableInformationAsync Duration={tableInfoSw.ElapsedMilliseconds}ms DB and Table: {sqlConnection.Database}.{fullName}. Primary keys: [{string.Join(",", primaryKeys.Select(pk => pk.Name))}]. SQL Column and Definitions: [{string.Join(",", columnDefinitionsFromSQL)}] Object columns: [{string.Join(",", objectColumnNames)}]");
646645
return new TableInformation(primaryKeyProperties, columnDefinitionsFromSQL, query, hasIdentityColumnPrimaryKeys);
647646
}

‎src/Telemetry/Telemetry.cs‎

Lines changed: 7 additions & 18 deletions
Original file line numberDiff line numberDiff line change
@@ -323,32 +323,22 @@ public enum ConvertType
323323
/// </summary>
324324
public enum TelemetryEventName
325325
{
326-
AcquireLeaseEnd,
327-
AcquireLeaseStart,
328326
AddAsync,
329327
Convert,
330328
Create,
331-
Error,
332329
FlushAsync,
333-
GetChangesEnd,
334-
GetChangesStart,
330+
GetChanges,
335331
GetColumnDefinitions,
336332
GetPrimaryKeys,
337333
GetScaleStatus,
338-
GetTableInfoEnd,
339-
GetTableInfoStart,
340-
ReleaseLeasesEnd,
341-
ReleaseLeasesStart,
342-
RenewLeasesEnd,
343-
RenewLeasesStart,
344-
StartListenerEnd,
345-
StartListenerStart,
346-
StopListenerEnd,
347-
StopListenerStart,
334+
GetTableInfo,
335+
ReleaseLeases,
336+
RenewLeases,
337+
StartListener,
338+
StopListener,
348339
TableInfoCacheHit,
349340
TableInfoCacheMiss,
350-
TriggerFunctionEnd,
351-
TriggerFunctionStart,
341+
TriggerFunction,
352342
TriggerMonitorStart,
353343
UpsertEnd,
354344
UpsertStart,
@@ -361,7 +351,6 @@ public enum TelemetryPropertyName
361351
{
362352
ErrorCode,
363353
ErrorName,
364-
ExceptionType,
365354
HasIdentityColumn,
366355
HasConfiguredBatchSize,
367356
HasConfiguredMaxChangesPerWorker,

‎src/TriggerBinding/SqlTableChangeMonitor.cs‎

Lines changed: 26 additions & 23 deletions
Original file line numberDiff line numberDiff line change
@@ -338,7 +338,6 @@ private async Task RunChangeConsumptionLoopAsync()
338338
/// </summary>
339339
private async Task GetTableChangesAsync(SqlConnection connection, CancellationToken token)
340340
{
341-
TelemetryInstance.TrackEvent(TelemetryEventName.GetChangesStart, this._telemetryProps);
342341
this._logger.LogDebugWithThreadId("BEGIN GetTableChanges");
343342
try
344343
{
@@ -390,23 +389,25 @@ private async Task GetTableChangesAsync(SqlConnection connection, CancellationTo
390389
acquireLeasesDurationMs = commandSw.ElapsedMilliseconds;
391390
}
392391
this._logger.LogDebugWithThreadId($"END AcquireLeases Duration={acquireLeasesDurationMs}ms");
392+
393+
// Only send event if we got changes to reduce the overall number of events sent since we generally
394+
// only care about the times that we had to actually retrieve and process rows
395+
var measures = new Dictionary<TelemetryMeasureName, double>
396+
{
397+
[TelemetryMeasureName.SetLastSyncVersionDurationMs] = setLastSyncVersionDurationMs,
398+
[TelemetryMeasureName.GetChangesDurationMs] = getChangesDurationMs,
399+
[TelemetryMeasureName.AcquireLeasesDurationMs] = acquireLeasesDurationMs,
400+
[TelemetryMeasureName.TransactionDurationMs] = transactionSw.ElapsedMilliseconds,
401+
[TelemetryMeasureName.BatchCount] = this._rowsToProcess.Count,
402+
};
403+
TelemetryInstance.TrackEvent(TelemetryEventName.GetChanges, this._telemetryProps, measures);
393404
}
394405

395406
transaction.Commit();
396407

397408
// Set the rows for processing, now since the leases are acquired.
398409
this._rowsToProcess = rows;
399410
this._state = State.ProcessingChanges;
400-
var measures = new Dictionary<TelemetryMeasureName, double>
401-
{
402-
[TelemetryMeasureName.SetLastSyncVersionDurationMs] = setLastSyncVersionDurationMs,
403-
[TelemetryMeasureName.GetChangesDurationMs] = getChangesDurationMs,
404-
[TelemetryMeasureName.AcquireLeasesDurationMs] = acquireLeasesDurationMs,
405-
[TelemetryMeasureName.TransactionDurationMs] = transactionSw.ElapsedMilliseconds,
406-
[TelemetryMeasureName.BatchCount] = this._rowsToProcess.Count,
407-
};
408-
409-
TelemetryInstance.TrackEvent(TelemetryEventName.GetChangesEnd, this._telemetryProps, measures);
410411
}
411412
catch (Exception)
412413
{
@@ -468,7 +469,6 @@ private async Task ProcessTableChangesAsync()
468469
{
469470
var input = new TriggeredFunctionData() { TriggerValue = changes };
470471

471-
TelemetryInstance.TrackEvent(TelemetryEventName.TriggerFunctionStart, this._telemetryProps);
472472
this._logger.LogDebugWithThreadId("Executing triggered function");
473473
var stopwatch = Stopwatch.StartNew();
474474

@@ -482,7 +482,7 @@ private async Task ProcessTableChangesAsync()
482482
if (result.Succeeded)
483483
{
484484
this._logger.LogDebugWithThreadId($"Successfully triggered function. Duration={durationMs}ms");
485-
TelemetryInstance.TrackEvent(TelemetryEventName.TriggerFunctionEnd, this._telemetryProps, measures);
485+
TelemetryInstance.TrackEvent(TelemetryEventName.TriggerFunction, this._telemetryProps, measures);
486486
// We've successfully fully processed these so set them to be released in the cleanup phase
487487
this._rowsToRelease = this._rowsToProcess;
488488
this._rowsToProcess = new List<IReadOnlyDictionary<string, object>>();
@@ -582,20 +582,25 @@ private async Task RenewLeasesAsync(SqlConnection connection, CancellationToken
582582
{
583583
using (SqlCommand renewLeasesCommand = this.BuildRenewLeasesCommand(connection, transaction))
584584
{
585-
TelemetryInstance.TrackEvent(TelemetryEventName.RenewLeasesStart, this._telemetryProps);
586585
this._logger.LogDebugWithThreadId($"BEGIN RenewLeases Query={renewLeasesCommand.CommandText}");
587586
var stopwatch = Stopwatch.StartNew();
588587

589-
await renewLeasesCommand.ExecuteNonQueryAsync(token);
588+
int rowsAffected = await renewLeasesCommand.ExecuteNonQueryAsync(token);
590589

591590
long durationMs = stopwatch.ElapsedMilliseconds;
592-
this._logger.LogDebugWithThreadId($"END RenewLeases Duration={durationMs}ms");
593-
var measures = new Dictionary<TelemetryMeasureName, double>
591+
this._logger.LogDebugWithThreadId($"END RenewLeases Duration={durationMs}ms RowsAffected={rowsAffected}");
592+
593+
if (rowsAffected > 0)
594594
{
595-
[TelemetryMeasureName.DurationMs] = durationMs,
596-
};
595+
// Only send an event if we actually updated rows to reduce the overall number of events we send
596+
var measures = new Dictionary<TelemetryMeasureName, double>
597+
{
598+
[TelemetryMeasureName.DurationMs] = durationMs,
599+
};
600+
601+
TelemetryInstance.TrackEvent(TelemetryEventName.RenewLeases, this._telemetryProps, measures);
602+
}
597603

598-
TelemetryInstance.TrackEvent(TelemetryEventName.RenewLeasesEnd, this._telemetryProps, measures);
599604

600605
transaction.Commit();
601606
}
@@ -672,7 +677,6 @@ private async Task ReleaseLeasesAsync(SqlConnection connection, CancellationToke
672677
{
673678
if (this._rowsToRelease.Count > 0)
674679
{
675-
TelemetryInstance.TrackEvent(TelemetryEventName.ReleaseLeasesStart, this._telemetryProps);
676680
long newLastSyncVersion = this.RecomputeLastSyncVersion();
677681
bool retrySucceeded = false;
678682

@@ -705,7 +709,6 @@ private async Task ReleaseLeasesAsync(SqlConnection connection, CancellationToke
705709
updateLastSyncVersionDurationMs = commandSw.ElapsedMilliseconds;
706710
this._logger.LogDebugWithThreadId($"END UpdateTablesPostInvocation Duration={updateLastSyncVersionDurationMs}ms");
707711
}
708-
709712
transaction.Commit();
710713

711714
var measures = new Dictionary<TelemetryMeasureName, double>
@@ -715,7 +718,7 @@ private async Task ReleaseLeasesAsync(SqlConnection connection, CancellationToke
715718
[TelemetryMeasureName.TransactionDurationMs] = transactionSw.ElapsedMilliseconds,
716719
};
717720

718-
TelemetryInstance.TrackEvent(TelemetryEventName.ReleaseLeasesEnd, this._telemetryProps, measures);
721+
TelemetryInstance.TrackEvent(TelemetryEventName.ReleaseLeases, this._telemetryProps, measures);
719722
retrySucceeded = true;
720723
this._rowsToRelease = new List<IReadOnlyDictionary<string, object>>();
721724
}

‎src/TriggerBinding/SqlTriggerListener.cs‎

Lines changed: 16 additions & 20 deletions
Original file line numberDiff line numberDiff line change
@@ -107,15 +107,6 @@ public async Task StartAsync(CancellationToken cancellationToken)
107107
}
108108

109109
this.InitializeTelemetryProps();
110-
TelemetryInstance.TrackEvent(
111-
TelemetryEventName.StartListenerStart,
112-
new Dictionary<TelemetryPropertyName, string>(this._telemetryProps) {
113-
{ TelemetryPropertyName.HasConfiguredMaxChangesPerWorker, this._hasConfiguredMaxChangesPerWorker.ToString() }
114-
},
115-
new Dictionary<TelemetryMeasureName, double>() {
116-
{ TelemetryMeasureName.MaxChangesPerWorker, this._maxChangesPerWorker }
117-
}
118-
);
119110

120111
try
121112
{
@@ -172,9 +163,15 @@ public async Task StartAsync(CancellationToken cancellationToken)
172163
[TelemetryMeasureName.InsertGlobalStateTableRowDurationMs] = insertGlobalStateTableRowDurationMs,
173164
[TelemetryMeasureName.CreateLeasesTableDurationMs] = createLeasesTableDurationMs,
174165
[TelemetryMeasureName.TransactionDurationMs] = transactionSw.ElapsedMilliseconds,
166+
[TelemetryMeasureName.MaxChangesPerWorker] = this._maxChangesPerWorker
175167
};
176168

177-
TelemetryInstance.TrackEvent(TelemetryEventName.StartListenerEnd, this._telemetryProps, measures);
169+
TelemetryInstance.TrackEvent(
170+
TelemetryEventName.StartListener,
171+
new Dictionary<TelemetryPropertyName, string>(this._telemetryProps) {
172+
{ TelemetryPropertyName.HasConfiguredMaxChangesPerWorker, this._hasConfiguredMaxChangesPerWorker.ToString() }
173+
},
174+
measures);
178175
}
179176
}
180177
catch (Exception ex)
@@ -189,7 +186,6 @@ public async Task StartAsync(CancellationToken cancellationToken)
189186

190187
public Task StopAsync(CancellationToken cancellationToken)
191188
{
192-
TelemetryInstance.TrackEvent(TelemetryEventName.StopListenerStart, this._telemetryProps);
193189
var stopwatch = Stopwatch.StartNew();
194190

195191
int previousState = Interlocked.CompareExchange(ref this._listenerState, ListenerStopping, ListenerStarted);
@@ -206,7 +202,7 @@ public Task StopAsync(CancellationToken cancellationToken)
206202
[TelemetryMeasureName.DurationMs] = stopwatch.ElapsedMilliseconds,
207203
};
208204

209-
TelemetryInstance.TrackEvent(TelemetryEventName.StopListenerEnd, this._telemetryProps, measures);
205+
TelemetryInstance.TrackEvent(TelemetryEventName.StopListener, this._telemetryProps, measures);
210206
return Task.CompletedTask;
211207
}
212208

@@ -248,11 +244,11 @@ private async Task<int> GetUserTableIdAsync(SqlConnection connection, Cancellati
248244
{
249245
const int NameIndex = 0, TypeIndex = 1, LengthIndex = 2, PrecisionIndex = 3, ScaleIndex = 4;
250246
string getPrimaryKeyColumnsQuery = $@"
251-
SELECT
252-
c.name,
253-
t.name,
254-
c.max_length,
255-
c.precision,
247+
SELECT
248+
c.name,
249+
t.name,
250+
c.max_length,
251+
c.precision,
256252
c.scale
257253
FROM sys.indexes AS i
258254
INNER JOIN sys.index_columns AS ic ON i.object_id = ic.object_id AND i.index_id = ic.index_id
@@ -308,9 +304,9 @@ private async Task<IReadOnlyList<string>> GetUserTableColumnsAsync(SqlConnection
308304
{
309305
const int NameIndex = 0, TypeIndex = 1, IsAssemblyTypeIndex = 2;
310306
string getUserTableColumnsQuery = $@"
311-
SELECT
312-
c.name,
313-
t.name,
307+
SELECT
308+
c.name,
309+
t.name,
314310
t.is_assembly_type
315311
FROM sys.columns AS c
316312
INNER JOIN sys.types AS t ON c.user_type_id = t.user_type_id

0 commit comments

Comments
 (0)