Audit performance

[mark.myers]

Is anyone having performace issues with the Audit View?
I've had auditing turned on - in Build 815 using DBMS - for about a week now have noticed some problems. Normal operations are OK but when I try to clear the log I get timeout errors. I captured the command it was using to clear the log and ran it manually - it took over 5 minutes. There are no indexes on the table (t_Snapshot) and so I was thinking of adding indexes to these fields: SeriesID, ElementID, SnapshotName, Position; I am concerned that there may be a performance hit on updating the indexes for each operation done in the UI. Also the recovery mode for the DB (SQL Server) is set to Full so I could try setting it to Simple - but there's a risk of loss of work then. Any thoughts?

BTW, there were 12095 records in the table but taking up over 350M and this was just a few days worth!!!

The command to clear the logs was...
DELETE FROM t_snapshot WHERE (SeriesID = 'LOG' OR SeriesID = 'LOG Search Terms') AND SnapshotName NOT LIKE 't_snapshot'

Mark.

[bmioch]

Hi Mark,

Thanks for the feedback regarding Auditing. Hopefully someone else can answer your SQL Server specific questions.

I'm glad to hear that normal operations are OK. If you don't mind telling me, how many people over how many days created that many entries (roughly)?

[mark.myers]

Just me - over about 3 days.
I suspect it has to do with locking. I set a group lock on two root models (in preparation for when I hand the repository over to the client) and that seems to place a LOT of stuff in the BinContent1 and/or BinContent2 fields.

[bmioch]

Thanks Mark. I've corrected the issue that was causing the excessive size of log items. It should be in Build 816.

If you were locking often, this might help your timeout problem too, since there won't be so much in there.

Bill

[mark.myers]

Thanks, Bill.
I'll hold off doing the indexes and see how 816 goes (but I think some indexes on the table would probably help the performance of the audit view, just a thought)

[«Midnight»]

Mark,

Once you've tried this with build 816, please post your results to this thread. I (for one) would like to see how much of a difference the change makes.

Thanks much,
David

[mark.myers]

David,
I've done a little more investigating and am somewhat concerned with what I have found. I still need to do more (longer) checks but this is what I have so far. Using Audit View in Advanced Mode or Raw Mode seems to be fine but I get timeouts when using Standard Mode (ie synced to project browser)

In raw mode the query is:
SELECT SnapshotID,SnapshotName,Style,BinContent2 FROM t_snapshot WHERE SeriesID = 'LOG'

In Advanced Mode the query is:
SELECT SnapshotID,SnapshotName,Style,BinContent2 FROM t_snapshot WHERE SeriesID = 'LOG' AND ElementID<>'0'

but a sample of a query from Standard Mode (depends on the element selected in the browser, of course) is:
SELECT SnapshotID FROM t_snapshot WHERE (SeriesID = 'LOG' OR SeriesID = 'LOG Search Terms') AND ElementID<>'0' AND (Notes LIKE '%{62CB2246-A966-4bd9-8B9D-C2A118A650F7}%' OR Notes
LIKE '%{F481CDAF-7AF3-4dce-97D9-1D2EC18555F9}%' OR Notes LIKE '%{E93E3178-D0EE-4d4d-911B-8C04FC7F4557}%' OR Notes LIKE '%{B7F0ADE4-4C8B-4e18-B002-E51833A6139F}%' OR Notes LIKE
'%{7BB9D697-E709-4eae-8D4D-98C2AF432F84}%' OR Notes LIKE '%{EC04F3F8-3315-4a6f-B073-C565507425B5}%' OR Notes LIKE '%{D12B13FE-DDA4-4fe7-855E-620A412A8E52}%' OR Notes LIKE
'%{A66A32E7-0497-4278-BCDF-4EB2280B1C19}%' OR Notes LIKE '%{EE0AEAE0-2AB5-453a-A15B-135DCA597757}%') ORDER BY Position DESC

The problem is using a LIKE expression of the form '%xxx%' so the DBEngine has no choice but to do a row by row table scan. the bigger the snapshot table gets the slower the query will be. Indexes cannot help this situation.

Bill, any chance of having this improved? May just have to avoid using the Standard Mode.

I have placed indexes on SeriesID and ElementID and will run the Profiler and Tuning Advisor to see what else I find over a longer timespan.

Regards,
Mark.

[bmioch]

Yes Mark, there is. We're aware of this issue.

The Search which sits behind those statements currently checks how many search terms there are. If they are below a certain threshold, it does the search in the SQL statement (as you have shown). If it is over, it pulls down the necessary data and does the search in code. Currently that threshold is too high.

The reasoning behind the idea it is that offsite users on a slow connection want to do as much processing on the server as possible, so that only the data they need is sent to them.

I will be investigating further to see what action should be taken. At the moment I'm thinking the threshold idea may either be dropped entirely (if it doesn't improve the experience for slow users noticibly), or it may be exposed as an option.

[mark.myers]

OK.
Thanks, Bill.

Mark.

[«Midnight»]

...the threshold idea may either be dropped entirely (if it doesn't improve the experience for slow users noticibly [sic]) , or it may be exposed as an option.

Bill,

Please consider exposing this option to the API as well.

Thanks much,
David

[mark.myers]

Bill,

I think the idea of pushing the processing onto the server is a good idea and, as much as possible, should be the standard practice. I would be more concerned that the underlying data structures may not be sufficient to quickly find the records required - hence the criteria Notes LIKE '%guid%' which is not good. Perhaps the better (ideal) solution would be for another table to also be populated at time of audit which would contain a column for GUID (indexed) and the auditID - at audit time you could use regular expressions to quickly find the GUID's and strip them out. I realise these are fundamental changes and may impact performance at time of audit or have other implications I don't know of but I'm just throwing up ideas.

Regards,
Mark.