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 …).
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.
Michael Firsov 