How are object access events generated?

I wrote this as an answer for Tom, who emailed me, but I thought I'd share it with everyone.

 

There are 7 events associated with object access auditing in Windows:

560 is the "open handle" event. It is logged when an app asks for access to an object (via a call like CreateFile). An access check is performed against the DACL (discretionary access control list == permissions) and an audit check is performed against the SACL (system access control list == audit settings). If the result of the access check matches the result of the audit check, an audit is generated- for successful accesses, the audit records the accesses that were granted, and for failures, the audit records the accesses that were requested. If the access check was successful, then a handle is returned to the calling program.

There is no event 561. I don't know why, maybe we'll use it in the future for something cool we haven't thought of yet.

562 is the "close handle" event. It is logged when an app disposes of an existing handle (how it got the handle is described above).

563 is the "open handle for delete" event. It works EXACTLY like event 560, and is logged only for files and only when the CreateFile API is called with a special flag that says "This is going to be a temporary file, delete it when I close the handle".

564 is the "delete" event. It works EXACTLY like event 562, but it is logged in conjunction with event 563 rather than event 560. Note that depending on how the object was deleted, you might get a 560-562 pair or a 563-564 pair. The former are much more common.

565 and 566 are application and AD access audit events. They record the actual accesses that were performed on the application-specific object or on the AD object. There are no handle semantics for these events.

567 is the "operation audit" event. It first exists on Windows XP. Once a handle to an object is opened (event 560 or 563), 567 is generated the first time an audited access is performed on an object.

Now let's put this together.

Scenario 1: Notepad is used to open an existing text file.

Notepad calls createfile("filename.txt"). Access check is performed, not opening for delete--> generate event 560 and list the accesses notepad was given (== what it asked for). Notepad is a well-behaved app and only asks for what it intends to use: GENERIC_READ (==read_control + read_data + read_attributes). Notepad reads the file (event 567 for "read_data") and closes the handle (event 562).

Scenario 2: Word is used to open an existing Word document.

Word has funny file i/o semantics. You've probably noticed that it generates files with silly names like "~ocument1.doc" and "~wrdf7.tmp". If you were to watch it very carefully with a program like FileMon from SysInternals, you'd notice that what Word does is:

1) Copy the file with a new name

2) Creates one or more temporary files for doing some operations (I don't know exactly what for)

3) Update the metadata in the original file to indicate it's locked for editing

4) Operate on the copy

And at save it:

5) Deletes the original file

6) Renames the working copy with the original name

7) Deletes the temporary working file(s)

The audit trail looks much more unusual:

You'll see 560 for the original file (open handle with all accesses), 560 for the copy (if there's an object-inherit SACL on the directory), 560 for the temp file, 567 (read data + write data) for the original file (reading the contents to write to the temporary file, writing metadata to the original file), 567 for the copy (write data), 567 for the temp file (???), and possibly more 567 events as it accesses the files. At the end when you save you see a similar mess as it cleans up. It can vary a little depending on what you do in Word.

You might ask, “Well, Eric, why don’t you just get rid of all that junk and just log an event that says what Word did?”.

Good question. As I mentioned in my post on “Trustworthiness in Audit Records”, the only practical way to do that would be to instrument Word for audit, and then the audit trail would be exactly as reliable as the user using Word, because if Word can write to the audit trail, and Word is running in the user’s context, then the user can write to the audit trail.

Now, we CAN improve things. In fact we did for Vista. Most people other than developers and Common Criteria evaluators don’t care about handle open/close audit events. So we made those harder to turn on in Vista, and we improved the “operation” audit event (was id 567, now it’s 4663 in Vista) so that it can stand alone. So by default when you turn on object auditing, you don’t see who requested access to objects, you see who performed access on objects. This is a huge step in the right direction, IMO.

There's a good technical discussion of access check & audit here. It’s a little dated- it pre-dates event 567 in XP- but it is still accurate.

I suggest that you read the whole "access control" section, but at the very least, read the 2 pages in this section on "access check" and "audit generation".

Eric

 

[2008-09-04 Updated link]

Comments

  • Anonymous
    October 31, 2006
    "now it’s 4663 in Vista" Do you guys plan to publish a full list of Vista events and what they all mean?

  • Anonymous
    November 01, 2006
    Yes, we do plan to publish such a list, however the content is not ready.  As I posted earlier, except for events that are new in Vista, you can generally "translate" a pre-Vista event into a Vista event by adding 4096 to the pre-Vista event ID.

  • Anonymous
    September 04, 2008
    I've written before on noise reduction in the Windows security event log. I've also written to describe

  • Anonymous
    November 13, 2010
    I did some testing and found that on a 2k3 Server, if I use notepad from Windows 7 to open a file in a share on the server, I get event id 560 and 562.  If I connect to the 2k3 server from another 2k3 server and open the file I get event id 560, 567 and 562.  Is this by design due to the noise reduction?  I am looking at the event log of the 2k3 server for these events.

  • Anonymous
    March 13, 2011
    Interesting article. But I have one more question: Is it possible to exclude records with ID 560, 562, 567 from Security Log when Object Access Audit is enabled in group policy under Windows 2003 Server ?

  • Anonymous
    March 22, 2011
    Hi Flibustier, In Windows Server 2003, there is no way to exclude only those specific event IDs by ID, if Object Access audit policy is enabled for either success or failure. You can exclude those events for particular combinations of objects and accesses by adjusting the SACLs on the underlying objects. Eric