Skip to content

Add additional trigger debug logging #1103

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 4 commits into from
Jul 24, 2024
Merged

Conversation

Charles-Gagnon
Copy link
Contributor

@Charles-Gagnon Charles-Gagnon commented Jul 23, 2024

This will help us and users diagnose issues with the trigger function - especially for being able to track when the change version we're looking at changes so we can see what change version the function is looking at for a given point in time.

New messages:

  • PreInvocation updated LastSyncVersion
    [PreInvocation] Updated LastSyncVersion from 0 to 121
  • PostInvocation updated LastSyncVersion
    [PostInvocation] Updated LastSyncVersion from 153 to 155 MaxAttemptRowsToBeDeleted=1
  • When leases are renewed for lease locked rows
    Renewed leases for 1 rows
  • When the internal state is cleared (usually due to a previous error)
    Clearing internal state for 1 rows

Updated messages:

  • Added max attempts reached count to the lease locked row count check
    Executed GetChangesCommand in GetTableChangesAsync. 0 available changed rows. (0 found with lease locks and 1 ignored because they've reached the max attempt limit)

@@ -394,7 +394,6 @@ public enum TelemetryMeasureName
GetColumnDefinitionsDurationMs,
GetPrimaryKeysDurationMs,
GetUnprocessedChangesDurationMs,
GetLockedRowCountDurationMs,
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The duration wasn't being calculated correctly so I just removed to keep things simpler. We haven't really used these durations for anything useful so far anyways - we can always add it back in if needed.

{AppLockStatements}

DECLARE @last_sync_version bigint;
SELECT @last_sync_version = LastSyncVersion
FROM {GlobalStateTableName}
WHERE UserFunctionID = '{this._userFunctionId}' AND UserTableID = {this._userTableId};

SELECT COUNT(*)
DECLARE @lease_locked_count int;
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Refactored this to just create the message in the query itself. I could have returned a table with the numeric values, but having to read the data table and do all that extra stuff didn't seem worth it when we can just do it directly in the T-SQL.

{
var commandSw = Stopwatch.StartNew();
leaseLockedRowsCount = (int)await getLeaseLockedRowCountCommand.ExecuteScalarAsyncWithLogging(this._logger, CancellationToken.None);
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Note I fixed an issue here with not passing in the cancellation token. We should be doing that for all queries we execute so that if the function execution is cancelled we'll properly cancel the queries we're running right away.

@Charles-Gagnon Charles-Gagnon merged commit 0be9d0e into main Jul 24, 2024
2 checks passed
@Charles-Gagnon Charles-Gagnon deleted the chgagnon/additionalLogging branch July 24, 2024 20:43
PBBlox pushed a commit to PBBlox/azure-functions-sql-extension that referenced this pull request Apr 6, 2025
* Add additional debug logging

* Add max attempts to lease locked check

* log when match condition is null

---------

Co-authored-by: MaddyDev <[email protected]>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants