Windows Audit Part 2: Getting the time iterval in which the file was open

In this article we’ll try to find out how long the file has been open. We can say that a user closes a file (or an object) by searching for the 562 (“Handle Closed”)/4658 (“The handle to an object was closed”) events for Win2003 and Win2008 respectively.
Consider the following test: the file D:\Temp\Test.xls has the audit set up for List Folder/Read Data only (see items 2-1/2-2, Windows Audit Part 1) and we open it by double-clicking and close it a few minutes later. Our task is to know when it was open and when it was closed.
Let’s use the code from Windows Audit Part 1 and see when the file was open:

For Windows 2008:

logparser -i:EVT -o:csv -tabs:ON -resolveSIDs:ON “SELECT TimeGenerated AS FileOpenTime, EventID, EXTRACT_TOKEN(STRINGS,6,’|’) AS FileOpened, 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”

FileOpenTime, EventID,FileOpened, LogonID, HandleID, USERNAME
2011-06-22 11:46:52, 4656, D:\Temp\Test.xls, 0x3e7, 0×488, COMPUTER1$
2011-06-22 11:46:52, 4656, D:\Temp\Test.xls, 0x3e7, 0×520, COMPUTER1$
2011-06-22 11:46:52, 4656, D:\Temp\Test.xls, 0x3e7, 0x3f8, COMPUTER1$
2011-06-22 11:46:51, 4656, D:\Temp\Test.xls, 0x38e5a, 0×830, Michael
2011-06-22 11:46:51, 4656, D:\Temp\Test.xls, 0x3e7, 0×520, COMPUTER1$
2011-06-22 11:46:51, 4656, D:\Temp\Test.xls, 0x3e7, 0×484, COMPUTER1$
2011-06-22 11:46:51, 4656, D:\Temp\Test.xls, 0x38e5a, 0×830, Michael
2011-06-22 11:46:51, 4656, D:\Temp\Test.xls, 0x3e7, 0x3fc, COMPUTER1$
2011-06-22 11:46:47, 4656, PlugPlaySecurityObject, 0x3e7, 0×0, COMPUTER1$
2011-06-22 11:45:08, 4656, D:\Temp\Test.xls, 0x38e5a, 0×128, Michael
2011-06-22 11:45:08, 4656, D:\Temp\Test.xls, 0x38e5a, 0x2cc, Michael
2011-06-22 11:45:08, 4656, D:\Temp\Test.xls, 0x38e5a, 0x2cc, Michael

Here we can see several HandleIDs that were created for the D:\Temp\Test.xls at 11:45:08 (0x2cc and 0×128) and the HandleID 0×830 created at 11:46:51 for the username “Michael”. Hence we can say that the file was first accessed at 11:45:08. Let’s find out when it was closed!

Here is the code for handle close operations:

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

FileCloseTime, EventID, LogonID, HandleID, USERNAME
2011-06-22 11:46:52, 4658, 0x3e7, 0x3f8, COMPUTER1$
2011-06-22 11:46:52, 4658, 0x3e7, 0×520, COMPUTER1$
2011-06-22 11:46:52, 4658, 0x3e7, 0×488, COMPUTER1$
2011-06-22 11:46:52, 4658, 0x3e7, 0×520, COMPUTER1$
2011-06-22 11:46:51, 4658, 0x38e5a, 0×830, Michael
2011-06-22 11:46:51, 4658, 0x3e7, 0×484, COMPUTER1$
2011-06-22 11:46:51, 4658, 0x3e7, 0×520, COMPUTER1$
2011-06-22 11:46:51, 4658, 0x3e7, 0×520, COMPUTER1$
2011-06-22 11:46:51, 4658, 0x38e5a, 0×830, Michael
2011-06-22 11:46:51, 4658, 0x3e7, 0x3fc, COMPUTER1$
2011-06-22 11:46:51, 4658, 0x38e5a, 0×128, Michael
2011-06-22 11:45:08, 4658, 0x38e5a, 0x2cc, Michael
2011-06-22 11:45:08, 4658, 0x38e5a, 0x2cc, Michael

In this output we must find one of the preceding HandleIDs (0x2cc, 0×128 or 0×830) with the latest possible FileCloseTime. As we can see HandleIDs 0×830 and 0×128 was registered at 11:46:51 and IDs 0x2cc at 11:45:08 (in fact, at the time the file was open). So we can conclude that the file was open from 11:45:08 till 11:46:51.

For Windows 2003:

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

FileOpenTime, EventID, FileOpened, HandleID, USERNAME
2011-06-23 11:55:06, 560, C:\Test\Test.xls, 1064, DOMAIN\Michael
2011-06-23 11:55:06, 560, C:\Test\Test.xls, 460, DOMAIN\Michael
2011-06-23 11:55:06, 560, C:\Test\Test.xls, 2200, DOMAIN\Michael
2011-06-23 11:55:06, 560, C:\Test\Test.xls, 532, DOMAIN\Michael
2011-06-23 11:55:06, 560, C:\Test\Test.xls, 2268, DOMAIN\Michael
2011-06-23 11:55:06, 560, C:\Test\Test.xls, 2244, DOMAIN\Michael
2011-06-23 11:55:06, 560, C:\Test\Test.xls, 784, DOMAIN\Michael
2011-06-23 11:55:06, 560, C:\Test\Test.xls, 1744, DOMAIN\Michael
2011-06-23 11:55:06, 560, C:\Test\Test.xls, 532, DOMAIN\Michael
2011-06-23 11:49:20, 560, C:\Test\Test.xls, 2268, DOMAIN\Michael
2011-06-23 11:49:20, 560, C:\Test\Test.xls, 2292, DOMAIN\Michael
2011-06-23 11:49:18, 560, C:\Test\Test.xls, 596, DOMAIN\Michael
2011-06-23 11:49:18, 560, C:\Test\Test.xls, 512, DOMAIN\Michael
2011-06-23 11:49:18, 560, C:\Test\Test.xls, 512, DOMAIN\Michael
2011-06-23 11:49:17, 560, C:\Test\Test.xls, 1820, DOMAIN\Michael
2011-06-23 11:49:17, 560, C:\Test\Test.xls, 2348, DOMAIN\Michael
2011-06-23 11:49:17, 560, C:\Test\Test.xls, 2332, DOMAIN\Michael

So the file was open at 11:49:17 (IDs 2332, 2348, 1820) …

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

FileClosingTime, EventID, HandleID, USERNAME
2011-06-23 11:55:06, 562, 2200, DOMAIN\Michael
2011-06-23 11:55:06, 562, 1064, DOMAIN\Michael
2011-06-23 11:55:06, 562, 460, DOMAIN\Michael
2011-06-23 11:55:06, 562, 2244, DOMAIN\Michael
2011-06-23 11:55:06, 562, 532, DOMAIN\Michael
2011-06-23 11:55:06, 562, 2268, DOMAIN\Michael
2011-06-23 11:55:06, 562, 532, DOMAIN\Michael
2011-06-23 11:55:06, 562, 784, DOMAIN\Michael
2011-06-23 11:55:06, 562, 1744, DOMAIN\Michael
2011-06-23 11:55:06, 562, 596, DOMAIN\Michael
2011-06-23 11:49:20, 562, 2268, DOMAIN\Michael
2011-06-23 11:49:20, 562, 2292, DOMAIN\Michael
2011-06-23 11:49:18, 562, 512, DOMAIN\Michael
2011-06-23 11:49:18, 562, 512, DOMAIN\Michael
2011-06-23 11:49:17, 562, 2332, DOMAIN\Michael
2011-06-23 11:49:17, 562, 1820, DOMAIN\Michael
2011-06-23 11:49:17, 562, 2348, DOMAIN\Michael

and closed at …???!!! Look! All HandleIDs (2260, 1840) that were created at the moment of the first file access attempt (at 11:49:17) was closed at the same time! I think we must consider the next FileOpenTime, 11:49:18. First, let’s write down all HandleIDs for 11:49:18, here they are: 512 and 596. Now we should link them to the latest 562 events for the same HandleIDs: ID 512 was closed at 11:49:18 and ID 596 at 11:55:06. It is event 562 for HandleID 596 which indicates the file closing time, at least it can be verified in practice.

Windows Audit Part1

Windows Audit Part3

Advertisements

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: