locked
SQL Server 2008 Audit_Amazing_Expecting Comments RRS feed

  • Question

  • We enabled SQL Server external audit feature in our production server. We enabled only DML(Insert,Update,Delete) single audit event instead of group event on database level.Later, we reviewed the audit log file and everything looks good because all DML(Insert,Update,Delete)event was audit from all databases.

    We amazing after seeing one thing, SELECT query was also audited on the file. We checked the action id column through select * from fn_get_audit_file(file_pattern,default,default) and it was showing as UP (it means that update event occurred against SELECT query).

    Below is the query,

    select tbl.name, schema_name(tbl.schema_id), tbl.type, cast(case when tbl.is_ms_shipped = 1 then 1when (select major_id from sys.extended_properties where major_id = tbl.object_id and minor_id = 0 and class = 1 and name = N'microsoft_database_tools_support')is not null then 1 else 0 end as bit)from sys.all_objects AS tbl where tbl.type in (N'U', N'S') and permissions(tbl.object_id) & 4096 <> 0

    Question is : Why SELECT query was audited as UPDATE event?. Any idea? Post your valuable findings. Thanks

    DINESH.D

    Monday, April 29, 2013 6:20 PM

All replies

  • A guess: The select kicked off auto-update of statistics and it is that update that you are seeing in the audit.

    Tibor Karaszi, SQL Server MVP | web | blog

    Monday, April 29, 2013 7:09 PM
  • Tibork,

    Thanks for your reply.

    I reviewed my audit file again.

    If ur guess is correct, UPDATE STATISTICS should be audited against that table before or after this SELECT statement audited.

    But, we couldn't find UPDATE STATISTICS command on overall audit file.

    Anyother guess from your end?

    Tuesday, April 30, 2013 12:11 AM
  • I wasn't thinking about the UPDATE STATISTICS command. I was thinking about to auto-update of statistics that a SELECT (for instance) can trigger. Can you repro this? Does it happen by the same SELECT twice after each other? If it happens from the first SELECT but not the following, then it might be statistics, since the statistics would be updated by the second SELECT.

    Tibor Karaszi, SQL Server MVP | web | blog

    Tuesday, April 30, 2013 2:54 PM
  • Tibork,

    Your effort is helping me here. I am juz posting below result snippet.

    Query:

    select event_time,action_id,statement from sys.fn_get_audit_file('C:\Audit_logs\Server_audit_*.sqlaudit',default,default) where statement like 'select%'

    Note : A set of (more than 20) SELECT event occured at same time.

    Result :

    event_time          action_id              statement

    =======          ======             ======= 

    2013-04-30 10:11:08.0032383 UP   select tbl.name, schema_name(tbl.schema_id), tbl.type, cast(case when tbl.is_ms_shipped = 1 then 1when (select major_id from sys.extended_properties where major_id = tbl.object_id and minor_id = 0 and class = 1 and name = N'microsoft_database_tools_support')is not null then 1 else 0 end as bit)from sys.all_objects AS tbl where tbl.type in (N'U', N'S') and permissions(tbl.object_id) & 4096 <> 0

    2013-04-30 10:11:08.0032383 UP   select tbl.name, schema_name(tbl.schema_id), tbl.type, cast(case when tbl.is_ms_shipped = 1 then 1when (select major_id from sys.extended_properties where major_id = tbl.object_id and minor_id = 0 and class = 1 and name = N'microsoft_database_tools_support')is not null then 1 else 0 end as bit)from sys.all_objects AS tbl where tbl.type in (N'U', N'S') and permissions(tbl.object_id) & 4096 <> 0

    2013-04-30 10:11:08.0032383 UP   select tbl.name, schema_name(tbl.schema_id), tbl.type, cast(case when tbl.is_ms_shipped = 1 then 1when (select major_id from sys.extended_properties where major_id = tbl.object_id and minor_id = 0 and class = 1 and name = N'microsoft_database_tools_support')is not null then 1 else 0 end as bit)from sys.all_objects AS tbl where tbl.type in (N'U', N'S') and permissions(tbl.object_id) & 4096 <> 0

    2013-04-30 10:11:08.0032383 UP   select tbl.name, schema_name(tbl.schema_id), tbl.type, cast(case when tbl.is_ms_shipped = 1 then 1when (select major_id from sys.extended_properties where major_id = tbl.object_id and minor_id = 0 and class = 1 and name = N'microsoft_database_tools_support')is not null then 1 else 0 end as bit)from sys.all_objects AS tbl where tbl.type in (N'U', N'S') and permissions(tbl.object_id) & 4096 <> 0

    2013-04-30 10:11:08.0032383 UP   select tbl.name, schema_name(tbl.schema_id), tbl.type, cast(case when tbl.is_ms_shipped = 1 then 1when (select major_id from sys.extended_properties where major_id = tbl.object_id and minor_id = 0 and class = 1 and name = N'microsoft_database_tools_support')is not null then 1 else 0 end as bit)from sys.all_objects AS tbl where tbl.type in (N'U', N'S') and permissions(tbl.object_id) & 4096 <> 0

    2013-04-30 10:11:08.0032383 UP   select tbl.name, schema_name(tbl.schema_id), tbl.type, cast(case when tbl.is_ms_shipped = 1 then 1when (select major_id from sys.extended_properties where major_id = tbl.object_id and minor_id = 0 and class = 1 and name = N'microsoft_database_tools_support')is not null then 1 else 0 end as bit)from sys.all_objects AS tbl where tbl.type in (N'U', N'S') and permissions(tbl.object_id) & 4096 <> 0

    2013-04-30 10:11:08.0032383 UP   select tbl.name, schema_name(tbl.schema_id), tbl.type, cast(case when tbl.is_ms_shipped = 1 then 1when (select major_id from sys.extended_properties where major_id = tbl.object_id and minor_id = 0 and class = 1 and name = N'microsoft_database_tools_support')is not null then 1 else 0 end as bit)from sys.all_objects AS tbl where tbl.type in (N'U', N'S') and permissions(tbl.object_id) & 4096 <> 0

    2013-04-30 10:11:08.0032383 UP   select tbl.name, schema_name(tbl.schema_id), tbl.type, cast(case when tbl.is_ms_shipped = 1 then 1when (select major_id from sys.extended_properties where major_id = tbl.object_id and minor_id = 0 and class = 1 and name = N'microsoft_database_tools_support')is not null then 1 else 0 end as bit)from sys.all_objects AS tbl where tbl.type in (N'U', N'S') and permissions(tbl.object_id) & 4096 <> 0

    2013-04-30 10:11:08.0032383 UP   select tbl.name, schema_name(tbl.schema_id), tbl.type, cast(case when tbl.is_ms_shipped = 1 then 1when (select major_id from sys.extended_properties where major_id = tbl.object_id and minor_id = 0 and class = 1 and name = N'microsoft_database_tools_support')is not null then 1 else 0 end as bit)from sys.all_objects AS tbl where tbl.type in (N'U', N'S') and permissions(tbl.object_id) & 4096 <> 0

    2013-04-30 10:11:08.0032383 UP   select tbl.name, schema_name(tbl.schema_id), tbl.type, cast(case when tbl.is_ms_shipped = 1 then 1when (select major_id from sys.extended_properties where major_id = tbl.object_id and minor_id = 0 and class = 1 and name = N'microsoft_database_tools_support')is not null then 1 else 0 end as bit)from sys.all_objects AS tbl where tbl.type in (N'U', N'S') and permissions(tbl.object_id) & 4096 <> 0

    2013-04-30 11:16:46.5292383 UP   select tbl.name, schema_name(tbl.schema_id), tbl.type, cast(case when tbl.is_ms_shipped = 1 then 1when (select major_id from sys.extended_properties where major_id = tbl.object_id and minor_id = 0 and class = 1 and name = N'microsoft_database_tools_support')is not null then 1 else 0 end as bit)from sys.all_objects AS tbl where tbl.type in (N'U', N'S') and permissions(tbl.object_id) & 4096 <> 0


    2013-04-30 11:16:46.5292383 UP   select tbl.name, schema_name(tbl.schema_id), tbl.type, cast(case when tbl.is_ms_shipped = 1 then 1when (select major_id from sys.extended_properties where major_id = tbl.object_id and minor_id = 0 and class = 1 and name = N'microsoft_database_tools_support')is not null then 1 else 0 end as bit)from sys.all_objects AS tbl where tbl.type in (N'U', N'S') and permissions(tbl.object_id) & 4096 <> 0
     
    2013-04-30 11:16:46.5292383 UP   select tbl.name, schema_name(tbl.schema_id), tbl.type, cast(case when tbl.is_ms_shipped = 1 then 1when (select major_id from sys.extended_properties where major_id = tbl.object_id and minor_id = 0 and class = 1 and name = N'microsoft_database_tools_support')is not null then 1 else 0 end as bit)from sys.all_objects AS tbl where tbl.type in (N'U', N'S') and permissions(tbl.object_id) & 4096 <> 0

    2013-04-30 11:16:46.5292383 UP   select tbl.name, schema_name(tbl.schema_id), tbl.type, cast(case when tbl.is_ms_shipped = 1 then 1when (select major_id from sys.extended_properties where major_id = tbl.object_id and minor_id = 0 and class = 1 and name = N'microsoft_database_tools_support')is not null then 1 else 0 end as bit)from sys.all_objects AS tbl where tbl.type in (N'U', N'S') and permissions(tbl.object_id) & 4096 <> 0

     
    2013-04-30 11:16:46.5292383 UP   select tbl.name, schema_name(tbl.schema_id), tbl.type, cast(case when tbl.is_ms_shipped = 1 then 1when (select major_id from sys.extended_properties where major_id = tbl.object_id and minor_id = 0 and class = 1 and name = N'microsoft_database_tools_support')is not null then 1 else 0 end as bit)from sys.all_objects AS tbl where tbl.type in (N'U', N'S') and permissions(tbl.object_id) & 4096 <> 0

    2013-04-30 11:16:46.5292383 UP   select tbl.name, schema_name(tbl.schema_id), tbl.type, cast(case when tbl.is_ms_shipped = 1 then 1when (select major_id from sys.extended_properties where major_id = tbl.object_id and minor_id = 0 and class = 1 and name = N'microsoft_database_tools_support')is not null then 1 else 0 end as bit)from sys.all_objects AS tbl where tbl.type in (N'U', N'S') and permissions(tbl.object_id) & 4096 <> 0

    2013-04-30 11:16:46.5292383 UP   select tbl.name, schema_name(tbl.schema_id), tbl.type, cast(case when tbl.is_ms_shipped = 1 then 1when (select major_id from sys.extended_properties where major_id = tbl.object_id and minor_id = 0 and class = 1 and name = N'microsoft_database_tools_support')is not null then 1 else 0 end as bit)from sys.all_objects AS tbl where tbl.type in (N'U', N'S') and permissions(tbl.object_id) & 4096 <> 0

    2013-04-30 11:16:46.5292383 UP   select tbl.name, schema_name(tbl.schema_id), tbl.type, cast(case when tbl.is_ms_shipped = 1 then 1when (select major_id from sys.extended_properties where major_id = tbl.object_id and minor_id = 0 and class = 1 and name = N'microsoft_database_tools_support')is not null then 1 else 0 end as bit)from sys.all_objects AS tbl where tbl.type in (N'U', N'S') and permissions(tbl.object_id) & 4096 <> 0
     
    2013-04-30 11:16:46.5292383 UP   select tbl.name, schema_name(tbl.schema_id), tbl.type, cast(case when tbl.is_ms_shipped = 1 then 1when (select major_id from sys.extended_properties where major_id = tbl.object_id and minor_id = 0 and class = 1 and name = N'microsoft_database_tools_support')is not null then 1 else 0 end as bit)from sys.all_objects AS tbl where tbl.type in (N'U', N'S') and permissions(tbl.object_id) & 4096 <> 0

    Tuesday, April 30, 2013 5:41 PM
  • Hmm, that doesn't seem to be auto-update of statistics, but I can't teel for sure. Sorry, but I'm out of ideas from here...

    Tibor Karaszi, SQL Server MVP | web | blog

    Wednesday, May 1, 2013 9:06 AM
  • Could you share the statements you used to set up the audit? (It should be possible to bring up the audit in SSMS and use the Script button.)


    Erland Sommarskog, SQL Server MVP, esquel@sommarskog.se
    Wednesday, May 1, 2013 10:29 AM
  • :-) Even we too and struggle a lot,, Anyway,,, Thanks for your extend support tibork.
    Wednesday, May 1, 2013 5:53 PM
  • Ernald,

    I am posting here as you expected through Script button in SSMS.

    SERVER LEVEL AUDIT FILE CREATION
    ================================

    USE [master]
    GO

    /****** Object:  Audit [Server_audit]    Script Date: 05/01/2013 15:13:53 ******/
    CREATE SERVER AUDIT [Server_audit]
    TO FILE
    ( FILEPATH = N'F:\AuditFiles\'
     ,MAXSIZE = 200 MB
     ,MAX_ROLLOVER_FILES = 5
     ,RESERVE_DISK_SPACE = OFF
    )
    WITH
    ( QUEUE_DELAY = 1000
     ,ON_FAILURE = CONTINUE
     ,AUDIT_GUID = 'a12345-0896-4112-b8f7-492d688a6ed3'
    )
    GO

    DATABASE LEVEL DML AUDIT FILE ENABLING
    =======================================

    USE [XXXXX]
    GO

    CREATE DATABASE AUDIT SPECIFICATION [DML_Audit]
    FOR SERVER AUDIT [Server_audit]
    ADD (DELETE ON DATABASE::[XXXXX] BY [public]),
    ADD (INSERT ON DATABASE::[XXXXX] BY [public]),
    ADD (UPDATE ON DATABASE::[XXXXX] BY [public])
    WITH (STATE = ON)
    GO

    Wednesday, May 1, 2013 7:22 PM
  • I installed the audit according to your script, and then I played around a little in Object Explorer, but the audit file did not include anything interesting.

    Then I ran that exact query you had, and, boy! A single execution logs something like 19000 rows! Exactly why and what is going on, I haven't figured out yet.


    Erland Sommarskog, SQL Server MVP, esquel@sommarskog.se
    Thursday, May 2, 2013 9:37 PM
  • I was able to track it down to the use of the permissions() function. Why this function generate UP events I don't know. Maybe it is a bug, but I note in Books Online that this function is deprecated. So it is little intresting to know where this query is coming from...


    Erland Sommarskog, SQL Server MVP, esquel@sommarskog.se
    Thursday, May 2, 2013 10:04 PM