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, 0x488, COMPUTER1$
2011-06-22 11:46:52, 4656, D:\Temp\Test.xls, 0x3e7, 0x520, 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, 0x830, Michael
2011-06-22 11:46:51, 4656, D:\Temp\Test.xls, 0x3e7, 0x520, COMPUTER1$
2011-06-22 11:46:51, 4656, D:\Temp\Test.xls, 0x3e7, 0x484, COMPUTER1$
2011-06-22 11:46:51, 4656, D:\Temp\Test.xls, 0x38e5a, 0x830, Michael
2011-06-22 11:46:51, 4656, D:\Temp\Test.xls, 0x3e7, 0x3fc, COMPUTER1$
2011-06-22 11:46:47, 4656, PlugPlaySecurityObject, 0x3e7, 0x0, COMPUTER1$
2011-06-22 11:45:08, 4656, D:\Temp\Test.xls, 0x38e5a, 0x128, 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 0x128) and the HandleID 0x830 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, 0x520, COMPUTER1$
2011-06-22 11:46:52, 4658, 0x3e7, 0x488, COMPUTER1$
2011-06-22 11:46:52, 4658, 0x3e7, 0x520, COMPUTER1$
2011-06-22 11:46:51, 4658, 0x38e5a, 0x830, Michael
2011-06-22 11:46:51, 4658, 0x3e7, 0x484, COMPUTER1$
2011-06-22 11:46:51, 4658, 0x3e7, 0x520, COMPUTER1$
2011-06-22 11:46:51, 4658, 0x3e7, 0x520, COMPUTER1$
2011-06-22 11:46:51, 4658, 0x38e5a, 0x830, Michael
2011-06-22 11:46:51, 4658, 0x3e7, 0x3fc, COMPUTER1$
2011-06-22 11:46:51, 4658, 0x38e5a, 0x128, 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, 0x128 or 0x830) with the latest possible FileCloseTime. As we can see HandleIDs 0x830 and 0x128 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.

Advertisements

2 responses

  1. Hello everyone, it’s my first pay a visit at this site, and post is genuinely fruitful designed for me, keep up posting these types of posts.

    1. Thank you very much for the pleasent comment! I’m happy my posts may help someone!

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: