Windows Audit Part 1: Tracing file openings

I’m sure any system administrator must be able to trace user activity on the network and be ready to answer at least a few simple questions such as “who accessed this file?”, “when and by whom this folder/file was deleted ?” and several others.

MS Windows operating systems offer a great graphic tool for tracing events – Event Viewer, but the more events are generated in the log the harder the way of finding needed information is getting. Moreover it is not enough just to know the meaning of the various event id-s because this information is useless without principles of log parsing. In other words an administrator should keep in mind the whole chain of consecutive events that can even be generated on various computers such as domain controllers and workstations befour getting started, for example, to audit file deletions.  With the release of Windows 2008, things became more complicated because of differences in generating audit entries in security log.

After spending many years working as a system administrator with Windows servers, I’d like to share with you my methods for tracing some common situations.

In this article I’d like to show you the differences between auditing in Windows 2003 and Windows 2008 regarding to file open operations.
To make our life easier we’ll make use of the free Microsoft Log Parser 2.2. Using these sample codes we’ll be able to find all necessary event IDs very quickly. So let’s get started!

I think one of the most important questions a system administrator should be able to answer is “Did someone open specific file?” I’m sure many of you are a bit puzzled by such a question: but wait a minute – it’s not as easy as it seems!

First, let’s have a look at “Auditing Entry for …” window, for example for the file D:\Temp\Test.xls (right click the file – Properties – Security – Advanced – Auditing – Edit – Auditing Entry for …).

1

There are twelve discrete NTFS permissions (and Full Control which is the cumulative of all 12) here but utilizing of what exactly NTFS permission will indicate that the file has really been accessed?! To find it out we’ll make some tests.
Prior to starting our tests I’d like to draw your attention to the interesting fact: although there’s the event ID 560 in Win2003 or event ID 4656 in Win2008 (“A handle to an object was requested “) registering the event of file (or object) access attempt it may be very confusing trying to understand in what circumstances these handle IDs are being generated. Even clicking on a file (not a double-clicking that leads to the file being opened in some application!) sometimes leads to a number of 560 or 4656 events (e.g. to a number of Handle IDs). So we can’t say that the file was opened just seeing the event 560 or 4656 for that file!!!

Now I offer to set the audit for the each of 12 discrete NTFS permissions and explore the outputs of this code after 1) clicking on the D:\Temp\Test.xls and 2) double-clicking on the D:\Temp\Test.xls:

For Win2003:

logparser -i:EVT -o:csv -tabs:ON -resolveSIDs:ON “SELECT TimeGenerated AS FileOpenTime, EventID, EXTRACT_TOKEN(STRINGS,2,’|’) AS FileOpen, EXTRACT_TOKEN(STRINGS,3,’|’) AS HandleID, SID AS USERNAME FROM security WHERE EventID = 560 ORDER BY FileOpenTime DESC”

For Win2008:

logparser -i:EVT -o:csv -tabs:ON -resolveSIDs:ON “SELECT TimeGenerated AS FileOpenTime, EventID, EXTRACT_TOKEN(STRINGS,6,’|’) AS FileOpen, EXTRACT_TOKEN(STRINGS,3,’|’) AS LogonID, EXTRACT_TOKEN(STRINGS,7,’|’) AS HandleID, EXTRACT_TOKEN(STRINGS,1,’|’) AS USERNAME FROM security WHERE EventID =4656 ORDER BY FileOpenTime DESC”

Both Win2003 and Win2008 have the Audit Policy “Object Access” enabled.

The goal of this is to find out how much auditing of each NTFS permission contributes to generating event IDs 560/4656.

1-1) Audit set only for “Traverse Folder/Execute File”, Win2003

a) Clicking on D:\Temp\Test.xls:
— no records—-

b) Double-clicking on D:\Temp\Test.xls:
— no records—-

1-2) Audit set only for “Traverse Folder/Execute File”, Win2008

a) Clicking on D:\Temp\Test.xls:
— no records—-

b) Double-clicking on D:\Temp\Test.xls:
— no records—-

2-1) Audit set only for “List Folder/Read Data”, Win2003

a) Clicking on D:\Temp\Test.xls:
— no records—-

b) Double-clicking on D:\Temp\Test.xls:

FileOpenTime, EventID, FileOpen, HandleID, USERNAME
2011-06-20 12:21:34, 560, C:\Test\Test.rtf, 384, DOMAIN\Michael
2011-06-20 12:21:34, 560, C:\Test\Test.rtf, 408, DOMAIN\Michael
2011-06-20 12:21:33, 560, C:\Test\Test.rtf, 136, DOMAIN\Michael
2011-06-20 12:21:33, 560, C:\Test\Test.rtf, -2147479332, DOMAIN\Michael

2-2) Audit set only for “List Folder/Read Data”, Win2008

a) Clicking on D:\Temp\Test.xls:
— no records—-

b) Double-clicking on D:\Temp\Test.xls:

FileOpenTime, EventID, FileOpen, LogonID, HandleID, USERNAME
2011-06-20 17:03:52, 4656, D:\Temp\Test.xls, 0x4075a, 0x11a4, Michael
2011-06-20 17:03:52, 4656, D:\Temp\Test.xls, 0x4075a, 0x420, Michael
2011-06-20 17:03:52, 4656, D:\Temp\Test.xls, 0x4075a, 0x420, Michael
2011-06-20 17:03:52, 4656, D:\Temp\Test.xls, 0x4075a, 0x420, Michael
2011-06-20 17:03:52, 4656, D:\Temp\Test.xls, 0x4075a, 0xb40, Michael
2011-06-20 17:03:52, 4656, D:\Temp\Test.xls, 0x4075a, 0x420, Michael
2011-06-20 17:03:52, 4656, D:\Temp\Test.xls, 0x4075a, 0x420, Michael
2011-06-20 17:03:51, 4656, D:\Temp\Test.xls, 0x4075a, 0x128, Michael
2011-06-20 17:03:51, 4656, D:\Temp\Test.xls, 0x4075a, 0x2c8, Michael
2011-06-20 17:03:51, 4656, D:\Temp\Test.xls, 0x4075a, 0x2c8, Michael
2011-06-20 17:03:51, 4656, D:\Temp\Test.xls, 0x4075a, 0x1084, Michael
2011-06-20 17:03:51, 4656, D:\Temp\Test.xls, 0x4075a, 0xee4, Michael

3-1) Audit set only for “Read Attributes”, Win2003

a) Clicking on D:\Temp\Test.xls:
— no records—-

b) Double-clicking on D:\Temp\Test.xls:

FileOpenTime, EventID, FileOpen, HandleID, USERNAME
2011-06-20 12:10:02, 560, C:\Test\Test.rtf, 1352, DOMAIN\Michael
2011-06-20 12:10:12, 560, C:\Test\Test.rtf, 5788, NT AUTHORITY\SYSTEM
2011-06-20 12:10:02, 560, C:\Test\Test.rtf, 408, DOMAIN\Michael
2011-06-20 12:10:02, 560, C:\Test\Test.rtf, -2147482584, DOMAIN\Michael
2011-06-20 12:10:02, 560, C:\Test\Test.rtf, 384, DOMAIN\Michael
2011-06-20 12:10:02, 560, C:\Test\Test.rtf, 132, DOMAIN\Michael

3-2) Audit set only for “Read Attributes”, Win2008

a) Clicking on D:\Temp\Test.xls:
— no records—-

b) Double-clicking on D:\Temp\Test.xls:

FileOpenTime, EventID, FileOpen, LogonID, HandleID, USERNAME
2011-06-21 13:38:15, 4656, D:\Temp\Test.xls, 0x45250, 0x2d4, Michael
2011-06-21 13:38:15, 4656, D:\Temp\Test.xls, 0x45250, 0x128, Michael
2011-06-21 13:38:15, 4656, D:\Temp\Test.xls, 0x45250, 0x3ac, Michael
2011-06-21 13:38:15, 4656, D:\Temp\Test.xls, 0x45250, 0x14c8, Michael
2011-06-21 13:38:15, 4656, D:\Temp\Test.xls, 0x45250, 0x2d4, Michael

4-1) Audit set only for “Read Extended Attributes”, Win2003

a) Clicking on D:\Temp\Test.xls:
— no records—-

b) Double-clicking on D:\Temp\Test.xls:

FileOpenTime, EventID, FileOpen, HandleID, USERNAME
2011-06-20 12:33:41, 560, C:\Test\Test.rtf, 388, DOMAIN\Michael
2011-06-20 12:33:41, 560, C:\Test\Test.rtf, 412, DOMAIN\Michael
2011-06-20 12:33:41, 560, C:\Test\Test.rtf, 136, DOMAIN\Michael

4-2) Audit set only for “Read Extended Attributes”, Win2008

a) Clicking on D:\Temp\Test.xls:

FileOpenTime, EventID, FileOpen, LogonID, HandleID, USERNAME
2011-06-20 17:05:28, 4656, D:\Temp\Test.xls, 0x4075a, 0x1750, Michael
2011-06-20 17:05:28, 4656, D:\Temp\Test.xls, 0x4075a, 0x314, Michael

b) Double-clicking on D:\Temp\Test.xls:

FileOpenTime, EventID, FileOpen, LogonID, HandleID, USERNAME
2011-06-20 17:06:12, 4656, D:\Temp\Test.xls, 0x4075a, 0x1664, Michael
2011-06-20 17:06:12, 4656, D:\Temp\Test.xls, 0x4075a, 0x5e4, Michael
2011-06-20 17:06:12, 4656, D:\Temp\Test.xls, 0x4075a, 0x5e4, Michael
2011-06-20 17:06:12, 4656, D:\Temp\Test.xls, 0x4075a, 0x5e4, Michael
2011-06-20 17:06:12, 4656, D:\Temp\Test.xls, 0x4075a, 0x1980, Michael
2011-06-20 17:06:12, 4656, D:\Temp\Test.xls, 0x4075a, 0x5e4, Michael
2011-06-20 17:06:12, 4656, D:\Temp\Test.xls, 0x4075a, 0x5e4, Michael
2011-06-20 17:06:11, 4656, D:\Temp\Test.xls, 0x4075a, 0x128, Michael
2011-06-20 17:06:11, 4656, D:\Temp\Test.xls, 0x4075a, 0x2c8, Michael
2011-06-20 17:06:11, 4656, D:\Temp\Test.xls, 0x4075a, 0x2c8, Michael
2011-06-20 17:06:11, 4656, D:\Temp\Test.xls, 0x4075a, 0x1750, Michael
2011-06-20 17:06:11, 4656, D:\Temp\Test.xls, 0x4075a, 0x123c, Michael
2011-06-20 17:06:10, 4656, D:\Temp\Test.xls, 0x4075a, 0x15f0, Michael
2011-06-20 17:06:10, 4656, D:\Temp\Test.xls, 0x4075a, 0x1750, Michael

5-1) Audit set only for “Create Files/Write Data”, Win2003

a) Clicking on D:\Temp\Test.xls:
— no records—-

b) Double-clicking on D:\Temp\Test.xls:
— no records—-

5-2) Audit set only for ” Create Files/Write Data “, Win2008

a) Clicking on D:\Temp\Test.xls:
— no records—-

b) Double-clicking on D:\Temp\Test.xls:

FileOpenTime, EventID, FileOpen, LogonID, HandleID, USERNAME
2011-06-20 17:00:46, 4656, D:\Temp\Test.xls, 0x4075a, 0x128, Michael

6-1) Audit set only for “Create Folders/Append Data “, Win2003

a) Clicking on D:\Temp\Test.xls:
— no records—-

b) Double-clicking on D:\Temp\Test.xls:
— no records—-

6-2) Audit set only for “Create Folders/Append Data “, Win2008

a) Clicking on D:\Temp\Test.xls:
— no records—-

b) Double-clicking on D:\Temp\Test.xls:

FileOpenTime, EventID, FileOpen, LogonID, HandleID, USERNAME
2011-06-20 17:02:32, 4656, D:\Temp\Test.xls, 0x4075a, 0x128, Michael

7-1) Audit set only for “Write Attributes “, Win2003

a) Clicking on D:\Temp\Test.xls:
— no records—-

b) Double-clicking on D:\Temp\Test.xls:
— no records—-

7-2) Audit set only for “Write Attributes “, Win2008

a) Clicking on D:\Temp\Test.xls:
— no records—-

b) Double-clicking on D:\Temp\Test.xls:

FileOpenTime, EventID, FileOpen, LogonID, HandleID, USERNAME
2011-06-20 16:44:20, 4656, D:\Temp\Test.xls, 0x4075a, 0x324, Michael

8-1) Audit set only for “Write Extended Attributes “, Win2003

a) Clicking on D:\Temp\Test.xls:
— no records—-

b) Double-clicking on D:\Temp\Test.xls:
— no records—-

8-2) Audit set only for “Write Extended Attributes “, Win2008

a) Clicking on D:\Temp\Test.xls:
— no records—-

b) Double-clicking on D:\Temp\Test.xls:

FileOpenTime, EventID, FileOpen, LogonID, HandleID, USERNAME
2011-06-20 15:50:26, 4656, D:\Temp\Test.xls, 0x4075a, 0x128, Michael

9-1) Audit set only for “Delete “, Win2003

a) Clicking on D:\Temp\Test.xls:
— no records—-

b) Double-clicking on D:\Temp\Test.xls:
— no records—-

9-2) Audit set only for “Delete “, Win2008

a) Clicking on D:\Temp\Test.xls:
— no records—-

b) Double-clicking on D:\Temp\Test.xls:
— no records—-

10-1) Audit set only for ” Read Permissions “, Win2003
a) Clicking on D:\Temp\Test.xls:
— no records—-

b) Double-clicking on D:\Temp\Test.xls:

FileOpenTime, EventID, FileOpen, HandleID, USERNAME
2011-06-20 12:44:34, 560, C:\Test\Test.rtf, 5456, NT AUTHORITY\SYSTEM

10-2) Audit set only for ” Read Permissions “, Win2008

a) Clicking on D:\Temp\Test.xls:

FileOpenTime, EventID, FileOpen, LogonID, HandleID, USERNAME
2011-06-20 14:19:50, 4656, D:\Temp\Test.xls, 0x4075a, 0x153c, Michael
2011-06-20 14:19:50, 4656, D:\Temp\Test.xls, 0x4075a, 0x153c, Michael
2011-06-20 14:19:50, 4656, D:\Temp\Test.xls, 0x4075a, 0x153c, Michael
2011-06-20 14:19:47, 4656, D:\Temp\Test.xls, 0x4075a, 0xd0c, Michael
2011-06-20 14:19:47, 4656, D:\Temp\Test.xls, 0x4075a, 0xd0c, Michael
2011-06-20 14:19:47, 4656, D:\Temp\Test.xls, 0x4075a, 0x17d4, Michael
2011-06-20 14:19:47, 4656, D:\Temp\Test.xls, 0x4075a, 0x17d4, Michael
2011-06-20 14:19:47, 4656, D:\Temp\Test.xls, 0x4075a, 0x17d4, Michael
2011-06-20 14:19:47, 4656, D:\Temp\Test.xls, 0x4075a, 0x1110, Michael
2011-06-20 14:19:47, 4656, D:\Temp\Test.xls, 0x4075a, 0x17d4, Michael
2011-06-20 14:19:47, 4656, D:\Temp\Test.xls, 0x4075a, 0x17d4, Michael
2011-06-20 14:19:47, 4656, D:\Temp\Test.xls, 0x4075a, 0x17d4, Michael
2011-06-20 14:19:47, 4656, D:\Temp\Test.xls, 0x4075a, 0x17d4, Michael
2011-06-20 14:19:47, 4656, D:\Temp\Test.xls, 0x4075a, 0x17d4, Michael
2011-06-20 14:19:47, 4656, D:\Temp\Test.xls, 0x4075a, 0x1208, Michael
2011-06-20 14:19:47, 4656, D:\Temp\Test.xls, 0x4075a, 0x17d4, Michael

b) Double-clicking on D:\Temp\Test.xls:

FileOpenTime, EventID, FileOpen, LogonID, HandleID, USERNAME

2011-06-20 14:20:44, 4656, D:\Temp\Test.xls, 0x4075a, 0xeec, Michael
2011-06-20 14:20:44, 4656, D:\Temp\Test.xls, 0x4075a, 0xeec, Michael
2011-06-20 14:20:44, 4656, D:\Temp\Test.xls, 0x4075a, 0xeec, Michael
2011-06-20 14:20:43, 4656, D:\Temp\Test.xls, 0x4075a, 0x11ec, Michael
2011-06-20 14:20:43, 4656, D:\Temp\Test.xls, 0x4075a, 0x1738, Michael
2011-06-20 14:20:43, 4656, D:\Temp\Test.xls, 0x4075a, 0x1738, Michael
2011-06-20 14:20:43, 4656, D:\Temp\Test.xls, 0x4075a, 0xcdc, Michael
2011-06-20 14:20:43, 4656, D:\Temp\Test.xls, 0x4075a, 0x13e0, Michael
2011-06-20 14:20:43, 4656, D:\Temp\Test.xls, 0x4075a, 0xd44, Michael
2011-06-20 14:20:43, 4656, D:\Temp\Test.xls, 0x4075a, 0xce8, Michael
2011-06-20 14:20:43, 4656, D:\Temp\Test.xls, 0x4075a, 0x121c, Michael
2011-06-20 14:20:43, 4656, D:\Temp\Test.xls, 0x4075a, 0xd44, Michael
2011-06-20 14:20:43, 4656, D:\Temp\Test.xls, 0x4075a, 0x121c, Michael
2011-06-20 14:20:43, 4656, D:\Temp\Test.xls, 0x4075a, 0x7a4, Michael
2011-06-20 14:20:43, 4656, D:\Temp\Test.xls, 0x4075a, 0x7a4, Michael
2011-06-20 14:20:43, 4656, D:\Temp\Test.xls, 0x4075a, 0x7a4, Michael
2011-06-20 14:20:43, 4656, D:\Temp\Test.xls, 0x4075a, 0x14b8, Michael
2011-06-20 14:20:43, 4656, D:\Temp\Test.xls, 0x4075a, 0x11ec, Michael
2011-06-20 14:20:43, 4656, D:\Temp\Test.xls, 0x4075a, 0x7f0, Michael
2011-06-20 14:20:43, 4656, D:\Temp\Test.xls, 0x4075a, 0x7a4, Michael
2011-06-20 14:20:43, 4656, D:\Temp\Test.xls, 0x4075a, 0x7a4, Michael
2011-06-20 14:20:42, 4656, D:\Temp\Test.xls, 0x4075a, 0xda8, Michael
2011-06-20 14:20:42, 4656, D:\Temp\Test.xls, 0x4075a, 0xda8, Michael
2011-06-20 14:20:42, 4656, D:\Temp\Test.xls, 0x4075a, 0xda8, Michael
2011-06-20 14:20:42, 4656, D:\Temp\Test.xls, 0x4075a, 0xda8, Michael
2011-06-20 14:20:42, 4656, D:\Temp\Test.xls, 0x4075a, 0xda8, Michael
2011-06-20 14:20:42, 4656, D:\Temp\Test.xls, 0x4075a, 0xdb0, Michael
2011-06-20 14:20:42, 4656, D:\Temp\Test.xls, 0x4075a, 0xda8, Michael
2011-06-20 14:20:42, 4656, D:\Temp\Test.xls, 0x4075a, 0xdc0, Michael
2011-06-20 14:20:42, 4656, D:\Temp\Test.xls, 0x4075a, 0xdc0, Michael
2011-06-20 14:20:42, 4656, D:\Temp\Test.xls, 0x4075a, 0xdc0, Michael
2011-06-20 14:20:42, 4656, D:\Temp\Test.xls, 0x4075a, 0x10d4, Michael
2011-06-20 14:20:42, 4656, D:\Temp\Test.xls, 0x4075a, 0x10d4, Michael
2011-06-20 14:20:42, 4656, D:\Temp\Test.xls, 0x4075a, 0x2c8, Michael
2011-06-20 14:20:42, 4656, D:\Temp\Test.xls, 0x4075a, 0x2c8, Michael
2011-06-20 14:20:42, 4656, D:\Temp\Test.xls, 0x4075a, 0x128, Michael
2011-06-20 14:20:42, 4656, D:\Temp\Test.xls, 0x4075a, 0x161c, Michael

11-1) Audit set only for ” Change Permissions “, Win2003

a) Clicking on D:\Temp\Test.xls:
— no records—-

b) Double-clicking on D:\Temp\Test.xls:
— no records—-

11-2) Audit set only for ” Change Permissions “, Win2008

a) Clicking on D:\Temp\Test.xls:
— no records—-

b) Double-clicking on D:\Temp\Test.xls:
— no records—-

12-1) Audit set only for “Take Ownership “, Win2003

a) Clicking on D:\Temp\Test.xls:
— no records—-

b) Double-clicking on D:\Temp\Test.xls:
— no records—-

12-2) Audit set only for “Take Ownership “, Win2008

a) Clicking on D:\Temp\Test.xls:
— no records—-

b) Double-clicking on D:\Temp\Test.xls:
— no records—-

As we can see in many cases windows 2008 generates events 4656 for some NTFS permissions that Windows 2003 does not (for instance, items 7-2, 8-2). So to audit file opening (e.g. double-clicking on a file) I would prefer to audit the permission that generates corresponding events equally in Win2003 and in Win2008, for example, items 2-1/2-2 (List Folder/Read Data) or 3-1/3-2/ (Read Attributes). It’s obvious that having auditing set up for more than one permission, we’ll have many more events in the log and it’d be hard to say what permission generates corresponding event 560/ 4656. That’s why we should choose as few permissions to audit as possible, just to narrow down the large amount of information we’re expecting to get from security logs.

Therefore, if we searched through a security log for the events 562/4658 we would find out how long the file was open, in other words, when the file was closed. We’ll talk about it in Windows Audit Part 2.

Advertisements

8 responses

  1. Hi! I’ve been reading your site for a long time now and finally got the bravery to go ahead and give you a shout out from Porter Tx! Just wanted to mention keep up the good job!

    1. Hi Anonse! I’m very pleased to know my articles may help someone in their job. Please feel free to comment on articles, – I’ll be happy to answer any questions should they arise.
      Thank you very much for your reply!

  2. Hi every one, here every one is sharing these knowledge, so
    it’s fastidious to read this website, and I used to go to see this weblog everyday.

  3. When someone writes an post he/she retains the idea of a user
    in his/her mind that how a user can be aware of it.
    Thus that’s why this article is perfect. Thanks!

    1. Sex randki, thank you very much!

      Regards,
      Michael Firsov

  4. I like what you guys are usually up too. Such clever work and exposure!
    Keep up the excellent works guys I’ve incorporated you guys
    to blogroll.

    1. Thank you so much for your words!
      I’m happy my work may help someone!

      Michael Firsov

  5. You have made some good points there. I looked on the net
    to learn more about the issue and found most individuals will go along with your views on this site.

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s

%d bloggers like this: