Audit log screen - very slow page load

koki · September 21, 2021, 9:41am

Is there any possibility to speed up the Audit log screen load? It takes really long time to load several records.

tvavrda · September 22, 2021, 5:32am

The reason it is slow is because of a too complex query that loads related changes.

I propose splitting the audit view into two sections - master with the current entity changes and a detail with related entities changes. And make it lazy loaded. This way it would not need to load all the changes in one complex query that is forced to do a table fullscan.

washi · November 2, 2021, 2:27pm

washi · January 12, 2022, 1:43pm

@koki Could you test it?

koki · January 12, 2022, 2:05pm

Actually I got following error on Master 2021.2.0.2369

tvavrda · January 13, 2022, 4:29pm

Have you updated the “Audit” package?

koki · January 14, 2022, 9:02am

Yes, the Audit package is updated from Master 2021.2.0.2369 model.

koki · January 14, 2022, 9:07am

The error appeared, when I tried Audit on screen form with 50 000 rows. When I tried it on form with 20 000 rows, the Audit screen is shown but it takes loooong time. So there is no speed up with updated Audit package.

washi · April 5, 2022, 11:17am

I’ve analyzed the underlying SQL commands. At the moment audit uses this:

DECLARE @OrigamDataAuditLog_parRefParentRecordId AS UniqueIdentifier;

SET @OrigamDataAuditLog_parRefParentRecordId = NULL


-----------------------------------------------------------------
-- OrigamDataAuditLog
-----------------------------------------------------------------
SELECT
	[OrigamDataAuditLog].[OldValue] AS [OldValue],
	[OrigamDataAuditLog].[refColumnId] AS [refColumnId],
	[OrigamDataAuditLog].[NewValueId] AS [NewValueId],
	[OrigamDataAuditLog].[NewValue] AS [NewValue],
	[OrigamDataAuditLog].[OldValueId] AS [OldValueId],
	[OrigamDataAuditLog].[ActionType] AS [ActionType],
	[OrigamDataAuditLog].[SecondReferenceKey] AS [SecondReferenceKey],
	[OrigamDataAuditLog].[refParentRecordEntityId] AS [refParentRecordEntityId],
	[OrigamDataAuditLog].[refParentRecordId] AS [refParentRecordId],
	[OrigamDataAuditLog].[RecordUpdated] AS [RecordUpdated],
	[OrigamDataAuditLog].[RecordCreatedServer] AS [RecordCreatedServer],
	[OrigamDataAuditLog].[Id] AS [Id],
	[OrigamDataAuditLog].[RecordUpdatedServer] AS [RecordUpdatedServer],
	[OrigamDataAuditLog].[RecordCreatedBy] AS [RecordCreatedBy],
	[OrigamDataAuditLog].[RecordCreated] AS [RecordCreated],
	[OrigamDataAuditLog].[RecordUpdatedBy] AS [RecordUpdatedBy]
FROM
	[OrigamDataAuditLog] AS [OrigamDataAuditLog]
WHERE  (
	 (( ([OrigamDataAuditLog].[refParentRecordId] = @OrigamDataAuditLog_parRefParentRecordId) OR  ([OrigamDataAuditLog].[SecondReferenceKey] = @OrigamDataAuditLog_parRefParentRecordId))));

OrigamDataAuditLog_parRefParentRecordId is the id of the record we’re auditing. Despite having indexes in place, they’re ignored and SQL server runs table scan.

After slight adjustment of the query, the indices start being used:

DECLARE @OrigamDataAuditLog_parRefParentRecordId AS UniqueIdentifier;

SET @OrigamDataAuditLog_parRefParentRecordId = '2462eecb-5191-4059-b71f-da784ed1ce8e'


-----------------------------------------------------------------
-- OrigamDataAuditLog
-----------------------------------------------------------------
SELECT
	[OrigamDataAuditLog].[OldValue] AS [OldValue],
	[OrigamDataAuditLog].[refColumnId] AS [refColumnId],
	[OrigamDataAuditLog].[NewValueId] AS [NewValueId],
	[OrigamDataAuditLog].[NewValue] AS [NewValue],
	[OrigamDataAuditLog].[OldValueId] AS [OldValueId],
	[OrigamDataAuditLog].[ActionType] AS [ActionType],
	[OrigamDataAuditLog].[SecondReferenceKey] AS [SecondReferenceKey],
	[OrigamDataAuditLog].[refParentRecordEntityId] AS [refParentRecordEntityId],
	[OrigamDataAuditLog].[refParentRecordId] AS [refParentRecordId],
	[OrigamDataAuditLog].[RecordUpdated] AS [RecordUpdated],
	[OrigamDataAuditLog].[RecordCreatedServer] AS [RecordCreatedServer],
	[OrigamDataAuditLog].[Id] AS [Id],
	[OrigamDataAuditLog].[RecordUpdatedServer] AS [RecordUpdatedServer],
	[OrigamDataAuditLog].[RecordCreatedBy] AS [RecordCreatedBy],
	[OrigamDataAuditLog].[RecordCreated] AS [RecordCreated],
	[OrigamDataAuditLog].[RecordUpdatedBy] AS [RecordUpdatedBy]
FROM
	[OrigamDataAuditLog] AS [OrigamDataAuditLog]
WHERE 
[OrigamDataAuditLog].[refParentRecordId] = @OrigamDataAuditLog_parRefParentRecordId 
OR  (([OrigamDataAuditLog].[SecondReferenceKey] = @OrigamDataAuditLog_parRefParentRecordId)
	 and (OrigamDataAuditLog.ActionType = 8))

@koki Can you confirm performance gain?

koki · April 5, 2022, 9:39pm

@washi There is really performance gain for the second query. The first query run time for specific refParentRecordId was 3:53. The second query run time was 22 seconds. Great!
Please, could you implement it into the Audit package?
Thank you!

tvavrda · April 6, 2022, 4:46am

22 seconds seems still very high to me. Are there many records being returned?

koki · April 6, 2022, 6:21am

There are over 82 million rows in DataAuditLog and the query returned 96 rows.

tvavrda · April 6, 2022, 6:22am

Then I would not accept 22 seconds as good. Returning 96 records must be in milliseconds. Can you please post your actual query plan?

koki · April 6, 2022, 6:46am

When I try it today for the same or different refParentRecordId the query times are: 5 sec current query, 2 sec new query. The query execution plan is:

tvavrda · April 6, 2022, 12:18pm

That is also very strange as the old query was using a table scan, which in your case should take ages. 2 seconds would be acceptable, of course.

washi · April 6, 2022, 4:26pm

I think that an old query (before including the deleted items) should be used as a point of reference for the performance comparison.

DECLARE @OrigamDataAuditLog_parRefParentRecordId AS UniqueIdentifier;

SET @OrigamDataAuditLog_parRefParentRecordId = '2462eecb-5191-4059-b71f-da784ed1ce8e'


-----------------------------------------------------------------
-- OrigamDataAuditLog
-----------------------------------------------------------------
SELECT
	[OrigamDataAuditLog].[OldValue] AS [OldValue],
	[OrigamDataAuditLog].[refColumnId] AS [refColumnId],
	[OrigamDataAuditLog].[NewValueId] AS [NewValueId],
	[OrigamDataAuditLog].[NewValue] AS [NewValue],
	[OrigamDataAuditLog].[OldValueId] AS [OldValueId],
	[OrigamDataAuditLog].[ActionType] AS [ActionType],
	[OrigamDataAuditLog].[SecondReferenceKey] AS [SecondReferenceKey],
	[OrigamDataAuditLog].[refParentRecordEntityId] AS [refParentRecordEntityId],
	[OrigamDataAuditLog].[refParentRecordId] AS [refParentRecordId],
	[OrigamDataAuditLog].[RecordUpdated] AS [RecordUpdated],
	[OrigamDataAuditLog].[RecordCreatedServer] AS [RecordCreatedServer],
	[OrigamDataAuditLog].[Id] AS [Id],
	[OrigamDataAuditLog].[RecordUpdatedServer] AS [RecordUpdatedServer],
	[OrigamDataAuditLog].[RecordCreatedBy] AS [RecordCreatedBy],
	[OrigamDataAuditLog].[RecordCreated] AS [RecordCreated],
	[OrigamDataAuditLog].[RecordUpdatedBy] AS [RecordUpdatedBy]
FROM
	[OrigamDataAuditLog] AS [OrigamDataAuditLog]
WHERE 
[OrigamDataAuditLog].[refParentRecordId] = @OrigamDataAuditLog_parRefParentRecordId

washi · May 2, 2022, 9:25am

washi · May 2, 2022, 9:45am

washi · May 2, 2022, 2:41pm

washi · May 2, 2022, 2:46pm

@koki The adjustments are available in model.