Author Archive: Michael Firsov

Exchange 2013 SP1: Testing DLP Part1

Exchange 2013 introduced, among other features, the feature known as DLP – Data Loss Prevention (http://technet.microsoft.com/en-us/library/jj150527%28v=exchg.150%29.aspx). I did some tests of this feature and would like to share with you the results I’ve got.

Document Fingerprinting  (http://technet.microsoft.com/library/dn635176%28v=exchg.150%29.aspx) added the ability to create user-based templates wich could help define sensitive types of documents used in an organization – that was what I was keen to test in my test lab. Here’s my first scenario: suppose there’s a highly sensitive document (or documents that are created based on it) that an organization would never permit to be sent as an attachment (.docx file). So my goal is to ensure a user can not send that sensitive docx file (and any docx files derived from it as well) while having the ability to send other docx files (the ones not containing sensitive information).

First of all please take a look at my sensitive document SensitiveDOC.docx

00

…and on the docx file that’s similar to the SensitiveDOC.docx but with completly different wording (NonSensitive.docx):

Non-Secret-DOC

Now we must “fingerprint” the SensitiveDOC.docx and create a DLP policy that prevents users from sending such information. Here I’d like to draw your attention to the following:

1) as this page (http://technet.microsoft.com/en-us/library/dn635176%28v=exchg.150%29.aspx) says  “The patent template contains the blank fields “Patent title,” “Inventors,” and “Description” and descriptions for each of those fields—that’s the word pattern. When you upload the original patent template, it’s in one of the supported file types and in plain text. The DLP agent uses an algorithm to convert this word pattern into a document fingerprint, …

– the words being used in a template DO MATTER !!! According to this explanation I’m expecting to have sending of  SensitiveDOC.docx prohibited while sending of NonSensitiveDOC.docx allowed.

2) http://technet.microsoft.com/en-us/library/jj150512%28v=exchg.150%29.aspx

The transport rule agent that enforces DLP policies does not differentiate between email message attachments, body text, or subject lines while evaluating messages and the conditions within your policies. ” – that’s why sensitive information contained in an attachment must be examined by the transport rule agent: it does not matter whether it is contained in a email body or in an attachment.

Let’s start Exchange ECP and go to the “data loss prevention” page:

02

02 03

40

04

05

…and add the Policy Tip (although in this configuration it won’t show up):

06

 

07-1

08

Now let’s create a custom DLP policy:

10

11

…create the rule:

12

13

14

We must choose “The message contains sensitive information” in the “Apply this rule if…” field:

15

16-1

Here’s the dialog that allows us to load our template:

17

19

 

21

22

23

We’ve completed adding the DLP policy and can proceed to testing this policy in Outlook 2013:

I compose a message to Administrator with the template itself as an attachment:

25

The result: delivery has failed as expected:

261
This time I’m sending a non-sensitive file – NonSensitive.docx:

27

The result: DLP policy has prevented this message from being sent too!

 

29

Despite the fact that NonSensitive.docx file has completely different wording it was subject to be processed by our DLP policy!!!

Now I’ll try to send a file (Test.docx) that has a different formatting, not just different wording:

0000

31

The result:

32– the file Test.docx has been successfully sent!

 

Conclusion: Document fingerprinting in Exchnage 2013 SP1 can be not as accurate as it should be and, as we can see, it may not take into consideration the words containing in the template, although Exchnage documentation states it should.

 

Why not Exchange Server 2013

Here should come the artcile titled Exchange Server 2013 Mailbox Auditing Part III, but for now I have serious doubts that I would ever venture to deploy Exchnage Server 2013 in my company, at least Exchage 2013 -2013/CU3. Why? Let me explain.
I’ve been using Exchange Server for about 15 years:  the first version I  deployed was Exchange Server 5 for Windows NT and this and all subsequent versions, of course,  had various bugs – that’s normal for any software, especially for a just released software (frankly speaking I can’t remember any bug in Exchange 5 – it worked just fine in my company – but I think it’s hardly possible for any software not to have them), but it’s normal only in case something doesn’t work as expected!  I mean when some feature is designed well but its implemention  has some issues – it’s normal.  But it’s not normal when a new feature itself starts producing issues on a server!  I’m talking about Managed Availability – a new feature that must continiously monitor a server and take appropriate actions should any failures occur.
First of all, the way the Managed Availability works is rather strange for me:
http://blogs.technet.com/b/exchange/archive/2012/09/21/lessons-from-the-datacenter-managed-availability.aspx
“When something is unhealthy its first action is to attempt to recover that component. Managed Availability provides multi-stage recovery actions – the first attempt might be to restart the application pool, the second attempt might be to restart service, the third attempt might be to restart the server, and the final attempt may be to offline the server so that it no longer accepts traffic. If these attempts fail, managed availability then escalates the issue to a human through event log notification.”

– please pay attention to the fact that even the third step in this procedure is not serious enough to notify an administrator of a server problem, so MS suppose Exchange Server  itself must decide whether to restart a server or not… What if there’s some other software working on the same machine that should not be restarted? Why not let an administrator know that something is going wrong on a server PRIOR TO rebooting???
But the things that suprised me the most in Managed Availability are 1) the lack of the official information (at least by the time Exchange Server 2013 was released) on the origin of the messages coming to/from the following address : inbound@inboundproxy .com 2) the problems that arise because of these messages.
When for some reason a message from inbound@inboundproxy .com (the address used by  the Exchange Server 2013 Health service) does not reach a monitoring mailbox Exchange Server generates an NDR message to inbound@inboundproxy .com that can not be delivered because this address does not exist. So these messages get piled up in the corresponding queue. Of course, we can circumvent this issue by adding
Add-ContentFilterPhrase –Influence BadWord –Phrase “Inboundproxy”.
ass written here http://social.technet.microsoft.com/Forums/en-US/171b518d-1503-4230-a844-531432c290f9/undeliverableinbound-proxy-probe?forum=exchangesvrgeneral
…but trying to get rid of messages that Exchange itself generates for monitoring purposes…  I don’t understand it… And I don’t understand why there was no any information on this “feature” on MSDN or technet by the release time: a lot of administrators were puzzled by the traffic from/to inbound@inboundproxy .com on their servers and were not able to find corresponding info, for example:
http://www.networksteve.com/exchange/topic.php/Exchange_2013:_inboundproxy@inboundproxy.com,_HealthMailbox_stuc/?TopicId=37709&Posts=1

One more “field of interest” in Exchange 2013 is its interactions with DNS service: as far as I see a lot of different issues may arise from unexpecting behaviour of Exchange Server when it uses dns:
http://social.technet.microsoft.com/Forums/en-US/01b7dfce-4084-4eb5-8d70-d5854f09de6c/outlook-2013-connectivity-issue?forum=exchangesvrgeneral
http://social.technet.microsoft.com/Forums/en-US/ae61d80c-58da-4f47-b83c-66b123b2faf4/exchange-2013-mailflow-and-the-hosts-file?forum=exchangesvrgeneral

http://social.technet.microsoft.com/Forums/en-US/fc26dac5-d4e2-49da-903d-361ea8b85388/451-470-temporary-server-error-please-try-again-later-prx5?forum=exchangesvrgeneral
In my case (the first two posts) all these weird errors in Event Viewer (ID 36874, …) are gone  as soon as I add Exchange Server machine to its Hosts file (please note that ID 36874 means there’s a TLS error, but Outlook by default uses HTTP connections internally so how there  could be SSL-related error?).
Yes, you can say “disable Health service, add Exchange server to Hosts file and enjoy Exchange 2013”, …but there appears to be an apprehension that there can be some other strange issues or even features in this version of Exchange.
Furthemore, I find it rather strange when MS first introduces separate roles in Exchange Server 2007, continues using the same roles in Exchange Server 2010  and suddenly rolls back in Exchange 2013 by reducing the number of roles just to CAS and Mailbox. And in spite of having just two roles Exchange 2013, for example,  still has “implicit” Hub role with its own log folders. It looks like MS doesn’t know in wich way their mail product should develop.
So I think the current release (even with CU3) is not stable enough to be deployed in production environment.  I very much hope  a new version (or SP) will be better.

The morning of a system administrator

A system administrator’s responsibilities typically include a number of tasks, such as performing backups of data, applying fixes/updates, monitoring software/hardware, troubleshooting problems and many others, that he/she must fulfill during a day. So I once asked myself how my working day should begin? What information regarding my network I’d like to have at hand right after having come to office?

I have formulated the following questions I want get answered every morning:

1) Were there any unexpected server reboots?

2) Is there any server that lacks of a disk space?

3) What are the sizes of my MS SQL Server databases?

4) Were there any connectivity problems with our Internet connection?

5) Were there any Active Directory modifications?

6) Were there any password resets?

Please pay attention to the fact that I need to have the aforementioned questions already answered by the time I enter the office. The answers to the questions 1-4 I get by means of the vbs-scripts that send me corresponding reports in the e-mail messages, while the answers to the two last questions are the text-file reports generated by the cmd-scripts containing MS Log Parsers commands, wich are executed by servers’ scheduled tasks (by cscript).

In this article I’d like to share with you these vbs and cmd scripts.

1) ServerReboots.vbs

2) FreeSpaceWatcher.vbs

3) SQLdbSpaceWatcher.vbs

4) InternetConnection.vbs

For unknown reason I can’t correctly attach the last two cmd-scripts, so I post them here: you can copy/paste the code into the txt-file and then change .txt extention to the .cmd

5) GroupModifications.cmd

———————–The  Begining of the script  —————————————–

rem #################################################################################

rem            Any modifications in the group membership.       ID 632/633/636/637/660/661

rem    LorParser.exe is executed once per a domain controller, so in my case there’re are two LogParser lines: for dc1 and for dc2.
rem    Please adjust the script according to your needs (e.g. to the number of your DCs).

rem    Default output folder – C:\CMD

rem    V2 18.05.2011    Author: Michael Firsov
rem #################################################################################

rd C:\cmd\Groups /s /q

md C:\cmd\Groups

rem Added to Global Group
“C:\Program Files\Log Parser 2.2\LogParser.exe”  -I:EVT -o:csv -tabs:ON “select  TimeGenerated AS ADDitionTime,  EventID, resolve_sid(replace_chr(EXTRACT_TOKEN(Strings,1,’|’),’%%{}’,”)) AS UserADDED,  resolve_sid(replace_chr(EXTRACT_TOKEN(Strings,2, ‘|’) ,’%%{}’,”)) AS  ToGROUP, resolve_sid(replace_chr(EXTRACT_TOKEN(Strings,5, ‘|’),’%%{}’,”)) AS   ADDED-BY-User FROM \\dc1\security WHERE eventid = 4728  ORDER BY ADDitionTime DESC ” > C:\cmd\Groups\DC1-AddedToGlobalGroup.txt
“C:\Program Files\Log Parser 2.2\LogParser.exe”  -I:EVT -o:csv -tabs:ON “select  TimeGenerated AS ADDitionTime,  EventID, resolve_sid(replace_chr(EXTRACT_TOKEN(Strings,1,’|’),’%%{}’,”)) AS UserADDED,  resolve_sid(replace_chr(EXTRACT_TOKEN(Strings,2, ‘|’) ,’%%{}’,”)) AS  ToGROUP, resolve_sid(replace_chr(EXTRACT_TOKEN(Strings,5, ‘|’),’%%{}’,”)) AS   ADDED-BY-User FROM \\dc2\security WHERE eventid = 4728  ORDER BY ADDitionTime DESC ” > C:\cmd\Groups\DC2-AddedToGlobalGroup.txt

rem Added to Local Group
“C:\Program Files\Log Parser 2.2\LogParser.exe”  -I:EVT -o:csv -tabs:ON “select  TimeGenerated AS ADDitionTime,  EventID, resolve_sid(replace_chr(EXTRACT_TOKEN(Strings,1,’|’),’%%{}’,”)) AS UserADDED,  resolve_sid(replace_chr(EXTRACT_TOKEN(Strings,2, ‘|’) ,’%%{}’,”)) AS  ToGROUP, resolve_sid(replace_chr(EXTRACT_TOKEN(Strings,5, ‘|’),’%%{}’,”)) AS   ADDED-BY-User FROM \\dc1\security WHERE eventid = 4732  ORDER BY ADDitionTime DESC ” > C:\cmd\Groups\DC1-AddedToLocalGroup.txt
“C:\Program Files\Log Parser 2.2\LogParser.exe”  -I:EVT -o:csv -tabs:ON “select  TimeGenerated AS ADDitionTime,  EventID, resolve_sid(replace_chr(EXTRACT_TOKEN(Strings,1,’|’),’%%{}’,”)) AS UserADDED,  resolve_sid(replace_chr(EXTRACT_TOKEN(Strings,2, ‘|’) ,’%%{}’,”)) AS  ToGROUP, resolve_sid(replace_chr(EXTRACT_TOKEN(Strings,5, ‘|’),’%%{}’,”)) AS   ADDED-BY-User FROM \\dc2\security WHERE eventid = 4732  ORDER BY ADDitionTime DESC ” > C:\cmd\Groups\DC2-AddedToLocalGroup.txt

rem Added to Universal Group
“C:\Program Files\Log Parser 2.2\LogParser.exe”  -I:EVT -o:csv -tabs:ON “select  TimeGenerated AS ADDitionTime,  EventID, resolve_sid(replace_chr(EXTRACT_TOKEN(Strings,1,’|’),’%%{}’,”)) AS UserADDED,  resolve_sid(replace_chr(EXTRACT_TOKEN(Strings,2, ‘|’) ,’%%{}’,”)) AS  ToGROUP, resolve_sid(replace_chr(EXTRACT_TOKEN(Strings,5, ‘|’),’%%{}’,”)) AS   ADDED-BY-User FROM \\dc1\security WHERE eventid = 4756  ORDER BY ADDitionTime DESC ” > C:\cmd\Groups\DC1-AddedToUniversallGroup.txt
“C:\Program Files\Log Parser 2.2\LogParser.exe”  -I:EVT -o:csv -tabs:ON “select  TimeGenerated AS ADDitionTime,  EventID, resolve_sid(replace_chr(EXTRACT_TOKEN(Strings,1,’|’),’%%{}’,”)) AS UserADDED,  resolve_sid(replace_chr(EXTRACT_TOKEN(Strings,2, ‘|’) ,’%%{}’,”)) AS  ToGROUP, resolve_sid(replace_chr(EXTRACT_TOKEN(Strings,5, ‘|’),’%%{}’,”)) AS   ADDED-BY-User FROM \\dc2\security WHERE eventid = 4756  ORDER BY ADDitionTime DESC ” > C:\cmd\Groups\DC2-AddedToUniversallGroup.txt

rem Removed from Global Group
“C:\Program Files\Log Parser 2.2\LogParser.exe”  -I:EVT -o:csv -tabs:ON “select  TimeGenerated AS ADDitionTime,  EventID, resolve_sid(replace_chr(EXTRACT_TOKEN(Strings,1,’|’),’%%{}’,”)) AS UserDELETED,  resolve_sid(replace_chr(EXTRACT_TOKEN(Strings,2, ‘|’) ,’%%{}’,”)) AS  FromGROUP, resolve_sid(replace_chr(EXTRACT_TOKEN(Strings,5, ‘|’),’%%{}’,”)) AS   DELETED-BY-User FROM \\dc1\security WHERE eventid = 4728  ORDER BY ADDitionTime DESC ” > C:\cmd\Groups\DC1-REMOVEDfromGlobalGroup.txt
“C:\Program Files\Log Parser 2.2\LogParser.exe”  -I:EVT -o:csv -tabs:ON “select  TimeGenerated AS ADDitionTime,  EventID, resolve_sid(replace_chr(EXTRACT_TOKEN(Strings,1,’|’),’%%{}’,”)) AS UserDELETED,  resolve_sid(replace_chr(EXTRACT_TOKEN(Strings,2, ‘|’) ,’%%{}’,”)) AS  FromGROUP, resolve_sid(replace_chr(EXTRACT_TOKEN(Strings,5, ‘|’),’%%{}’,”)) AS   DELETED-BY-User FROM \\dc2\security WHERE eventid = 4728  ORDER BY ADDitionTime DESC ” > C:\cmd\Groups\DC2-REMOVEDfromGlobalGroup.txt

rem Removed from Local Group
“C:\Program Files\Log Parser 2.2\LogParser.exe”  -I:EVT -o:csv -tabs:ON “select  TimeGenerated AS ADDitionTime,  EventID, resolve_sid(replace_chr(EXTRACT_TOKEN(Strings,1,’|’),’%%{}’,”)) AS UserDELETED,  resolve_sid(replace_chr(EXTRACT_TOKEN(Strings,2, ‘|’) ,’%%{}’,”)) AS  FromGROUP, resolve_sid(replace_chr(EXTRACT_TOKEN(Strings,5, ‘|’),’%%{}’,”)) AS   DELETED-BY-User FROM \\dc1\security WHERE eventid = 4733  ORDER BY ADDitionTime DESC ” > C:\cmd\Groups\DC1-REMOVEDfromLocalGroup.txt
“C:\Program Files\Log Parser 2.2\LogParser.exe”  -I:EVT -o:csv -tabs:ON “select  TimeGenerated AS ADDitionTime,  EventID, resolve_sid(replace_chr(EXTRACT_TOKEN(Strings,1,’|’),’%%{}’,”)) AS UserDELETED,  resolve_sid(replace_chr(EXTRACT_TOKEN(Strings,2, ‘|’) ,’%%{}’,”)) AS  FromGROUP, resolve_sid(replace_chr(EXTRACT_TOKEN(Strings,5, ‘|’),’%%{}’,”)) AS   DELETED-BY-User FROM \\dc2\security WHERE eventid = 4733  ORDER BY ADDitionTime DESC ” > C:\cmd\Groups\DC2-REMOVEDfromLocalGroup.txt

rem Removed from Universal Group
“C:\Program Files\Log Parser 2.2\LogParser.exe”  -I:EVT -o:csv -tabs:ON “select  TimeGenerated AS ADDitionTime,  EventID, resolve_sid(replace_chr(EXTRACT_TOKEN(Strings,1,’|’),’%%{}’,”)) AS UserDELETED,  resolve_sid(replace_chr(EXTRACT_TOKEN(Strings,2, ‘|’) ,’%%{}’,”)) AS  FromGROUP, resolve_sid(replace_chr(EXTRACT_TOKEN(Strings,5, ‘|’),’%%{}’,”)) AS   DELETED-BY-User FROM \\dc1\security WHERE eventid = 4757  ORDER BY ADDitionTime DESC ” > C:\cmd\Groups\DC1-REMOVEDfromUniversalGroup.txt
“C:\Program Files\Log Parser 2.2\LogParser.exe”  -I:EVT -o:csv -tabs:ON “select  TimeGenerated AS ADDitionTime,  EventID, resolve_sid(replace_chr(EXTRACT_TOKEN(Strings,1,’|’),’%%{}’,”)) AS UserDELETED,  resolve_sid(replace_chr(EXTRACT_TOKEN(Strings,2, ‘|’) ,’%%{}’,”)) AS  FromGROUP, resolve_sid(replace_chr(EXTRACT_TOKEN(Strings,5, ‘|’),’%%{}’,”)) AS   DELETED-BY-User FROM \\dc2\security WHERE eventid = 4757  ORDER BY ADDitionTime DESC ” > C:\cmd\Groups\DC2-REMOVEDfromUniversalGroup.txt

————————- The End  of the script  ———————————————

6) PassResets.cmd

———————–The  Begining of the script  —————————————–

rem #################################################################################

rem                        Password resets for MDC and MSE.
rem
rem                    ID 4723:     ’Win2000 – Both password changed AND password reset !!!
rem                    ID 4724:     ’Win2003 – Password reset ONLY !!!

rem    LorParser.exe is executed once per a domain controller, so in my case there’re are two LogParser lines: for dc1 and for dc2.
rem    Please adjust the script according to your needs (e.g. to the number of your DCs).

rem    Default output folder – C:\CMD

rem    V1    21.05.2010    Author: Michael Firsov
rem #################################################################################

rd C:\cmd\Passwords /s /q

md C:\cmd\Passwords

“C:\Program Files\Log Parser 2.2\LogParser.exe”  -I:EVT -o:csv -tabs:ON “select  TimeGenerated AS PasswordChangeTime,  EventID, EXTRACT_TOKEN(Strings,0,’|’) AS FOR-ACCOUNT,  RESOLVE_SID(EXTRACT_TOKEN(Strings,3, ‘|’)) AS  BY-USER FROM \\dc1\security WHERE eventid = 4723 OR eventid = 4724 ORDER BY PasswordChangeTime DESC” > C:\cmd\Passwords\DC1-passChanges.txt

“C:\Program Files\Log Parser 2.2\LogParser.exe”  -I:EVT -o:csv -tabs:ON “select  TimeGenerated AS PasswordChangeTime,  EventID, EXTRACT_TOKEN(Strings,0,’|’) AS FOR-ACCOUNT,  RESOLVE_SID(EXTRACT_TOKEN(Strings,3, ‘|’)) AS  BY-USER FROM \\dc2\security WHERE eventid = 4723  OR eventid = 4724 ORDER BY PasswordChangeTime  DESC” > C:\cmd\Passwords\DC2-passChanges.txt

————————- The End  of the script  ———————————————

Security Descriptor Reader

  Working with the highly sensitive information may require you to document ntfs permissions (including audit settings) a person has on a file or a folder. Creating a list of permissions once for a definite period of time may help track changes to a file or folder access mask and, in case of deliberate or undeliberate modifications, take appropriate actions. For this purpose I wrote the vbs script SecurityDescriptorReader.vbs (SecurityDescriptorReader – please copy/paste the content of the SecurityDescriptorReader.doc into SecurityDescriptorReader.VBS before use) that can read file security descriptor, including auditing settings and would like to offer it to you in this article.
    Let’s say we need to have a list of the ntfs permissions and the audit settings set on D:\Test\HR.txt.  All  we need to get a txt-file report (SDreport) with the ntfs permissions and the audit settings for that file is to run the script and supply a file/folder name. Now I will demonstrate the whole procedure in a step-by-step manner:
  
1) First let’s set the following set of permissions and the auditing mask:
(Administrators -Full Control, Users – Read and Execute)   1
1-1
1-3
2) Run the script:2Type the D:\Test\HR.txt and press OK
3)3
The warning message appears informing you the report will be saved in the C:\VBSreports folder (it will be created in case it does not already exist)
  
4) The report is created:
4
  
Let’s click “Yes” and see how the permission setting in 1) correlate with this report:
SDreport
  
a) “Owner of the D:\Test\HR.txt is TestDom\User1” – the owner of the file
b) “Object DACL is PRESENT” – ntfs permissions are present
c) “Object Audit is TURNED ON” – the audit has been set (SACL is present)
d) “SACL can be inherited” – means the “Include inheritable auditing entries from this object’s parent” option on the Auditing tab is checked:
  
1-4
  
e) DACL section:
   (“A discretionary access control list (DACL) identifies the trustees that are allowed or denied access to a securable object.”
http://msdn.microsoft.com/ru-ru/library/windows/desktop/aa374872%28v=vs.85%29.aspx)
In step 1 we set permissions for the two accounts: BUILTIN\Administrators and BUILTIN\Users. Here are the corresponding access masks:
  
AccessMask for Trustee BUILTIN\Administrators:
————————————————————————————————————-
Synchronize
Write ACL
Read security
Delete
Write attributes
Read attributes
Delete dir
Execute
Write extended attributes
Read extended attributes
Append
Write
Read
  
AccessMask for Trustee BUILTIN\Users:
————————————————————————————————————-
Synchronize
Read security
Read attributes
Execute
Read extended attributes
Read
————————————————————————————————————-
  
DACL Ace Type shows which type of access the current access mask describes: Allowed or Denied (in our case both BUILTIN\Administrators and BUILTIN\Users have
ACCESS_ALLOWED_ACE_TYPE DACL Ace Type. If we denied, for instance, Execute permission for BUILTIN\Users we would have an extra DACL Ace Type set to ACCESS_DENIED_ACE_TYPE with the AccessMask set to Execute.
If we had any inheritable permissions set on the D:\Test\HR.txt we would also see the following DACL flag:
DACL ACE FLAGS:
Permission have been inherited.
VALID_INHERIT_FLAGS
————————————————————————————————————-
  
f) SACL section:
(“A system access control list (SACL) enables administrators to log attempts to access a secured object.”
http://msdn.microsoft.com/ru-ru/library/windows/desktop/aa374872%28v=vs.85%29.aspx)
  
f-1) SACL TYPE:
Audit for trustee TestDom\Domain Users is TURNED ON – the account we added on the Audit tab
  
f-2) SACL FLAGS for trustee: TESTDOM\Domain Users
  
AUDIT_FAILED_ACCESS,
AUDIT Mask of the object D:\Test\HR.txt for Trustee TestDom\Domain Users is:
  
Delete
  
– means we want to audit the failed DELETE attemts for estDom\Domain Users
  
f-3) SACL FLAGS for trustee: TESTDOM\Domain Users
  
AUDIT_SUCCESSFUL_ACCESS,
AUDIT Mask of the object D:\Test\HR.txt for Trustee TestDom\Domain Users is:
  
Execute
Read
  
– means we want to audit successful Execute and Read access for TestDom\Domain Users also.
  
So after running this script for the D:\Test\HR.txt file we have a secuity descriptor report in C:\VBSreports\SDreport.txt. If we continue running the script for other files the corresponding reports will be appended to the C:\VBSreports\SDreport.txt file. Scheduling the script, for instance, on a monthly basis will allow you to track whether any of ntfs permissions on your most important files changed or not.
  
Attention!
  
For unknown reasons running the script for a LOCAL file on Windows Server 2008R2/Windows7 will ALWAYS result in  SACL TYPE: TURNED OFF, even when the auditing is enabled! It won’t occur if the file supplied to the script is located on a mapped drive, so you can run the script on Win2008R2/Win7 and supply the file name in the form X:\[folder]\file, where X: is a mapped drive. It’s rather interesting that the folder to wich the drive (for example, X) is mapped can be located on Windows Server2008R2/Windows7 and in this case SACL information will be read correctly!

Exchange 2010 SP1 Mailbox Access Auditing Part III

  In this article we’ll continue to study mailbox access auditing for delegate access. I’ll set up auditing for MovedToDeletedItems and SoftDelete actions and try to find the corresponding information in the audit logs.
For instance, I want to know when a message is deleted from User2’s mailbox while User2’s mailbox is open by User1. Let’s repeat all necessary steps described in Part I from the beginning:
1) In Exchange Management Console we give User1 Full Access permission on User2’s mailbox:
2) …then turn on mailbox access auditing for User2’s mailbox:
Set-Mailbox -Identity User2 -AuditEnabled $true
3) …and check whether mailbox access auditing is turned on:
Get-Mailbox User2 |FL *audit*

4)  As MoveToDeletedItems action is not audited by default for delegate access we should add it manually:

Set-Mailbox -Identity User2 -AuditDelegate Update,MoveToDeletedItems,SoftDelete,HardDelete,SendAs,Create -AuditEnabled $true

Get-Mailbox User2 |FL *audit*

5) Again, I log on to User2’s mailbox as User1 – User2’s mailbox will be added automatically. Then, I delete a message from User2’s Inbox folder:

6) As we can see the deleted message was moved to User1’s DeletedItems folder:

7) Let’s find the corresponding information in the audit log:

Search-MailboxAuditLog -Identity User2 –LogonTypes Delegate -StartDate 6/28/2012 -EndDate 6/28/2012 -ResultSize 2000

The only useful piece of information here is when User2’s mailbox was accessed last time, so let’s add –ShowDetails switch:

The same problem – the audit search output is empty.
Here is the first Exchange 2010 audit issue:
MS confirmed this to be a bug! It will be corrected in SP2 Rollup 4.
So MS released a feature that is not fully operational out of box because the auditing capabilities was first introduced in Exchange Server 2010 SP1.
Let’s generate the audit report in ECP:

Here we can see what (“Audit Test 2” item), from what mailbox (User2’s) and by whom (User1) was deleted. Pay attention to the operation which was registered in the log – ‘Soft-delete’.
Please note that 6/28/2012 1.28 PM has turned into 6/29/2012 12:28 AM because I changed the Time Zone between taking these screenshots.
8) Now I’ll move by the mouse the e-mail message titled “Audit Test1” into User2’s DeletedItems folder and generate the audit report in ECP:
9) … and check the audit log once again:

Search-MailboxAuditLog -Identity User2 –LogonTypes Delegate -StartDate 6/28/2012 -EndDate 6/28/2012 -ResultSize 2000

Mailbox accessed: User2

Time: 6/29/2012 3:53 AM
Performed by: User1
Signed in as: User with delegate access
Operation: Create
Subject: Audit Test1
Folder: Inbox
Status: Succeeded
  • This log record was generated because we enabled auditing of the “Create” operation.
Time: 6/29/2012 3:53 AM
Performed by: User1
Signed in as: User with delegate access
Operation: Soft-delete
Subject: Audit Test1
Source: Deleted Items
Status: Succeeded
Now pay attention to the operation being registered: it’s SoftDelete, although according to MS documentation (http://technet.microsoft.com/en-us/library/ff459237.aspx?ppud=4 : MoveToDeletedItems

An item is moved to the Deleted Items folder.) it should be MoveToDeletedItems!

This is probably the second bug in Exchange auditing.
10) While I was finishing my tests I wanted to repeat all necessary steps to reproduce the aforementioned bugs but discovered a brand-new one.
Here are my steps and the corresponding screenshots:
  1. While logged on to User2’s mailbox as User1 I MOVED (by the mouse) “Audit Test1” message from User2’ Inbox folder to the User2’s DeletedItems folder. At least “Create” and “MoveToDeletedItems” operations should be recorded in the User2’s audit log.
  2. Checked whether mailbox access audit is turned on
  3. Searched through the User2’s audit log

No record was logged! I’m completely lost for words…

The only thing I really know I won’t use such auditing in my production environment.

Exchange 2010 SP1 Mailbox Access Auditing Part II – Delegate Access Bug

In the previous article, we learned how to set mailbox access audit for delegate access and find corresponding information in the audit log.  In those tests we used EMC to grant some user account Full Mailbox permission on another person’s mailbox.
Let’s check now how we can revoke Full Access permission from a mailbox. To make this test more interesting I’ll grant Administrator user account the same Full Access mailbox permission on User2’s mailbox so there’re two user accounts – User1 and Administrator – with FA permission on User2’s mailbox:
  1. Let’s try to revoke FA permission on User2’ mailbox from User1 in EMC,
  2. …start Outlook as User1 and make sure there’s no additional (User2’s) mailbox in the left pane:

    As we can see User1 does not have access to User2’s mailbox any more – exactly what we expected!

  3. Now let’s revoke FA permission on User2’s mailbox from Administrator user account,
  4. …start Outlook as Administrator and check whether User2’s mailbox has disappeared or not:Look! Administrator user account does not have any permission on User2’s mailbox; nevertheless, it still can access it!
  5. Now let’s look at User2 attributes in ADSI Editor:Please don’t forget to click Filter and tick “Show only attributes that have values”.
  6. As we can see msExchDelegateListLinkvalue is still there – after removing it Administrator user account should stop having access to User2’s mailbox.
  7. Let’s once again start Outlook as Administrator and see there’s no User2’ mailbox in the left pane:
    In this article we found a way to circumvent the bug in EMC and remove Full Access permission from an administrative user account.

Exchange 2010 Mailbox Access Auditing Part I

  MS Exchange 2010 SP1 introduced, among other things, mailbox access audit feature that should help system administrators track users’ mailbox activity. While testing Exchange auditing capabilities I quite often bumped into some various issues and would like to present you with a series of articles about my mailbox access audit tests and their results. We can walk together through the steps of setting up a mailbox access auditing for the particular actions and compare the test results with the expected ones.
  From my point of view one of the most important user actions an administrator should be able to audit is Delegate mailbox access. For instance, if I give User1 Full Access permission to User2’s mailbox I’d like to know what actions (and when) will be accomplished by User1 in the Users2’s mailbox. In this article I want to focus on some practical approaches to mailbox access audit for delegate users.
  The first question I want answered is “who and when accessed a delegated mailbox”.
Consider this situation: User1 needs access to User2’s mailbox. Let’s walk through the steps necessary for granting the requested access and monitoring its usage.

1) In Exchange Management Console we give User1 Full Access permission to User2’s mailbox:

2) …then turn on mailbox access audit for User2’s mailbox:
Set-Mailbox -Identity User2 -AuditEnabled $true
3) …and check whether mailbox access auditing is turned on:
Get-Mailbox User2 |FL *audit*

4) Pay close attention to what actions are audited by default: as we’re going to use the delegate access Update, SoftDelete, HardDelete, SendAs and Create actions will be audited by default once mailbox access is enabled for a particular mailbox. So to be able to audit the access to User2’s mailbox we must add FolderBind action to the list of already audited actions

Set-Mailbox -Identity User2 -AuditDelegate Update,SoftDelete,HardDelete,SendAs,Create,FolderBind -AuditEnabled $true
and check they have been applied correctly:
Get-Mailbox User2 |FL *audit*

5) Now let’s start Outlook and log on to User1’s mailbox. Outlook will open the additional User2’s mailbox for User1 automatically:

5) Now let’s check if any log records was generated when Outlook was started:
Search-MailboxAuditLog -Identity User2 -LogonTypes Delegate -StartDate 6/14/2012 -EndDate 6/15/2012 -ResultSize 2000

  Yes, here we can see a brief description of the fact that someone accessed User2’s mailbox. As our goal is to get all availabale information about Delegate access to User2’s mailbox we should add -ShowDetails to the previuos command:

6) Search-MailboxAuditLog -Identity User2 -LogonTypes Delegate -StartDate 6/14/2012 -EndDate 6/15/2012 -ResultSize 2000 -ShowDetails

  What is it? Search-MailboxAuditLog cmdlet stops producing any output should I add -ShowDetails switch!

The output expected should contain the following fields: Operation, OperationResult, LogonType, …, ClientIPAddress and many others as described here: http://technet.microsoft.com/en-us/library/ff459237.aspx

 I know for sure that at least in some cases Search-MailboxAuditLog cmdlet with the swith -ShowDetails works correctly but I can’t explain why it does not work in this particular test.

 However, let’s try to use the other tool for reading mailbox access audit log – the Exchange Control Panel.

Log in to ECP under account that is a member of Exchange Organization Management group or Records Management group (for instance, Administrator account) and click “Run a non-owner mailbox access report”

 

  Here it is! This report contains a bit more information about the FolderBind action, at least we can see which user (User1) opened User2’s mailbox.

  Look! There are multiple occurrences of Delegate Access actions at 6:08Am. This is because FolderBind actions performed by delegates are consolidated. One log entry is generated for individual folder access within a time span of three hours.

Summary

This was the first test for Exchange Server 2010 SP1 mailbox auditing.  In the next article we’ll continue to work with the mailbox Delegate Access.
The new article on the Exchange Server 2013 describing the same test is now available here:  https://michaelfirsov.wordpress.com/exchange-2013-mailbox-auditing-part-i/

MS SQL Server 2008 Audit with MS Log Parser 2.2

As you may already know, MS SQL Server starting with version 2008 has the ability to audit server and database level events. Furthermore, SQL-server  audit-induced events can be sent to Windows application or security log, making them available  to a general log parsing.
In this article, I offer you the step-by-step guide that may help system administrators set sql-related audit and get all necessary information from windows security log.
Let’s consider the situation when we’ve been tasked to track all executions of some stored procedure, for example, “MonitorsSP” (on my test sql server computer it does nothing more than lists all information from “Monitors” table, but it doesn’t matter). Our goal to have an easy-readable report (in the form of a text file or a cmd window output) containing information regarding each MonitorsSP execution.

So let’s get started.

Step 1:

First of all, we must create an audit object in SQL Studio Management Studio:

Right-click Security\Audits and click “New Audit…”. It is the audit object which defines where triggered events should be sent to. Let’s name the audit object “AuditOBJECT1”, select “Security Log” and press OK:

Step 2:

Now when we have an audit object created we can set audit specification for server or database related actions. If we were to audit  sql server users’ logon/logoff we would create a new  server audit specification by right-clicking “Server Audit Specifications” and clicking “New Server Audit Specification…”. As far as our goal is to audit execution of a stored procedure we should create a database audit specification:

In the “Database Audit Specification Properties” window name the specification and assosiate it with the audit object “AuditOBJECT1”, then select Action Type = EXECUTE, Object Class = OBJECT, Object Schema = dbo, Object Name = MonitorsSP  (the name of the stored procedure) and Principal Name = SQL\DBuser2   (my sql server computer name is “SQL”, my test user name is “DBuser2” – of course, your server/user-name can be different).

By default, newly-created audit object and database audit specification are disabled, so we must activate ones: right-click the corresponding object and click “Enable…”.

To be able to write to Windows security log sql service account must be granted SeAuditPrivilege (also known as “Generate Security Audit”) privilege and sql server computer should be rebooted, although the latter is not mentioned in MS documentation!!! If you won’t reboot your server you’ll be getting the error 33204  “SQL Server Audit could not write to the security log” in Windows application log.

 Step 3:

Now it’s time to run “MonitorsSP” stored procedure as SQL\DBuser2 user and generate the report based on the corresponding event (33205) written to Windows security log. My SQL server uses windows authentication scheme so I log on to Windows as SQL\Dbusers, run MS SQL Server Management Studio and run “MonitorsSP” in a query window (sql login DBuser2 corresponds to Resourses database user ‘DBuser2’)

Once the execution has completed we can search through the security log for 33205 event:

The process of finding a single event is quite straightforward. But what if security log contained tens of thousands events? In that case, we can make use of Microsoft Log Parser, the free utility for log parsing (http://www.microsoft.com/download/en/details.aspx?displaylang=en&id=24659).

Here’s the code wich helps us produce a good-looking report irrespective of number of events containing in Windows security log:

LogParser -fullText:OFF -o:csv -tabs:ON “SELECT TimeGenerated, EventID, EXTRACT_TOKEN(EXTRACT_TOKEN(Strings, 16, ‘:’), 0, ‘\u000a’) AS SQL-Login, EXTRACT_TOKEN(EXTRACT_TOKEN(Strings, 19, ‘:’), 0, ‘\u000a’) AS DataBase-Login, EXTRACT_TOKEN(EXTRACT_TOKEN(Strings, 26, ‘:’), 0, ‘\u000a’) AS ObjectName, EXTRACT_TOKEN(EXTRACT_TOKEN(Strings, 27, ‘:’), 0, ‘\u000a’) AS SQL-Statement FROM SECURITY WHERE EventID = 33205 order by TimeGenerated DESC”

If you’d like to have a .txt report for future analysis you can add to the previous code the ‘INTO [file name]’ statement :

LogParser -fullText:OFF -o:csv -tabs:ON “SELECT TimeGenerated, EventID, EXTRACT_TOKEN(EXTRACT_TOKEN(Strings, 16, ‘:’), 0, ‘\u000a’) AS SQL-Login, EXTRACT_TOKEN(EXTRACT_TOKEN(Strings, 19, ‘:’), 0, ‘\u000a’) AS DataBase-Login, EXTRACT_TOKEN(EXTRACT_TOKEN(Strings, 26, ‘:’), 0, ‘\u000a’) AS ObjectName, EXTRACT_TOKEN(EXTRACT_TOKEN(Strings, 27, ‘:’), 0, ‘\u000a’) AS SQL-Statement INTO E:\SqlLogs\Log1.txt FROM SECURITY WHERE EventID = 33205 order by TimeGenerated DESC”

Note: for this code to work it should be typed or copied/pasted as a single line!

If you had already happended to use MS Log Parser for parsing Windows security log you might notice some changes in Extract_Token clause. First we use semicolon ‘:’ delimiter instead of  a pipe symbol ‘|’, second we should utilize Extract_Token clause once again to separate the resultant string lines using unicode line feed   character u000a.

Let’s remove the second EXTRACT_TOKEN clause and look at the resultant txt file:

LogParser -fullText:OFF -o:csv -tabs:ON “SELECT TimeGenerated, EventID, EXTRACT_TOKEN(Strings, 16, ‘:’) AS SQL-Login, EXTRACT_TOKEN(Strings, 19, ‘:’) AS DataBase-Login, EXTRACT_TOKEN(Strings, 26, ‘:’) AS ObjectName, EXTRACT_TOKEN(Strings, 27, ‘:’) AS SQL-Statement INTO E:\SqlLogs\Log1-1.txt FROM SECURITY WHERE EventID = 33205 order by TimeGenerated DESC”

If we open this file in any hex editor we’ll see th 0A character between (for example) ‘DBuser2’ and ‘server_principal_name’. So to present our report in an appropriate format we must once again use EXTRACT_TOKEN clause with ‘\u000a’ character as a delimiter.

You can see the differences between the formats of the ‘Strings’ field of 33205 event and (for example) 4624 event (An account was successfully logged on.) here:

LogParser -fullText:OFF -o:csv -tabs:ON “SELECT TimeGenerated, EventID, Strings INTO E:\SqlLogs\Strings33205.txt FROM SECURITY WHERE EventID = 33205 order by TimeGenerated DESC”

LogParser -fullText:OFF -o:csv -tabs:ON “SELECT TimeGenerated, EventID, Strings INTO E:\SqlLogs\Strings4624.txt FROM SECURITY WHERE EventID = 4624 order by TimeGenerated DESC”

I hope this article will help system administrators easily set an audit for variuos sql-related events and use MS Log Parser for analyzing them.

Windows Audit Part 3: Tracing file deletions

The new version of this article is available:
Windows Audit Part 4: Tracing file deletions in MS PowerShell

Now it’s time to answer the most important question: how we can trace file/folder deletions?

In this article I’d like to offer system administrators a pictorial guide with wich they could easily and quickly find all necessary information in Windows EventViewer security log.

The task:

To find out ‘what, by whom, when and at what location” was deleted.

(on the example of Windows Server 2008 R2)

Prerequisites:  First of all we should enable “Object Access” audit with “File System”,  “File Share” and “Handle Manipulation” subcategories (Win2008) or just  “File System” category for Win2003.

Let’s consider this scheme:
(upper event id-s are for Win2008-Win2012R2, lower ones are for Win2003)

Deletion2

I An object was deleted from the shared folder (“Network deletion”)

1-1)   Network Logon (pay attention to user name, workstation, Logon ID)

1-2)   Share Folder Access (only for Win2008)

2-1)   Open Handle ID  – e.g.  a file is open.
(pay attention to the list (*) of user permissions for the object and Logon ID.)

2-2)   Registration of the exercised “DELETE” permission** (0x10000)
(the empty “Process/Image File Name” field means “network deletion”)

2-3)   Object deletion
(the name of the deleted object might be  known from 2-2  or from 2-1 by its Handle ID).

2-4)  Handle ID Close – e.g. the file is closed.

3)    Network logoff (with the same Logon ID as in 1-1).

II An object was deleted locally  (“Local deletion”)

2-1)    Open Handle ID  – e.g.  a file is open.
(pay attention to the list (*) of user permisions for the object and Logon ID.)

2-2)    Registration of the exercised  “DELETE” permission** (0x10000)
(the “Process/Image File Name” field will show the application by wich the object was deleted. )

2-3)    Object deletion
(the name of the deleted object might be  known from 2-2
or from 2-1 by its Handle ID).

2-4)    Handle ID Close – e.g. the file is closed.

*: permissions mentioned here mean what user CAN do but not necessary WILL do!

**: this permission has been realy exercised.

 

Answer I

Note:    For future use I prefer to save the LogParser output to a text file,
for instance to H:\LogParser\.

a) We’ll get started by finding out if there was any file deletion:

LogParser  -o:csv -tabs:ON “SELECT  TimeGenerated, EventID, Extract_Token(Strings, 1, ‘|’) AS USER, Extract_Token(Strings, 3, ‘|’) AS LogonID, Extract_Token(Strings, 5, ‘|’) AS HandleID INTO H:\LogParser\Event4660.txt FROM Security WHERE EventID = 4660 ORDER BY TimeGenerated DESC”

The output:

TimeGenerated,          EventID,      USER,    LogonID,      HandleID

2010-01-20 13:09:58,      4660,             hdesk1,      0x138b8d8,     0xe4c

We can see that user hdesk1 deleted some  file on 20.01.2010 at 13:09:58.

b) Then we should find out what exactly was deleted, when and by whom:  (note that LogonID and HandleID should be the same as in the previous output)

LogParser  -o:csv -tabs:ON “SELECT  TimeGenerated, EventID, Extract_Token(Strings, 1, ‘|’) AS USER, Extract_Token(Strings, 3, ‘|’) AS LogonID, Extract_Token(Strings, 6, ‘|’) AS ObjectName, Extract_Token(Strings, 7, ‘|’) AS HandleID, Extract_Token(Strings, 11, ‘|’) AS ProcessName, Extract_Token(Strings, 9, ‘|’) AS AccessTYPE INTO H:\LogParser\Event4663.txt FROM Security WHERE EventID = 4663 AND AccessTYPE LIKE ‘%%0x10000%%’ ORDER BY TimeGenerated DESC”

The output:

TimeGd,  EventID,  USER,  LogonID,    ObjectName,      HandleID,        ProcessName,       AccessTYPE

13:09:58,    4663,    hdesk1,   0x138b8d8,     H:\Test\Doc1.txt,     0xe4c,     C:\Windows\explorer.exe,     0x10000

13:09:58,    4663,    hdesk1,   0x138b8d8,     H:\Test\Doc1.txt,      0xe4c,     C:\Windows\explorer.exe,     0x10000

Attention! In the output above there are two simultaneous events 4663 for the given LogonID and HandleID. Due to Microsoft’s documentation this event should be generated with the first permission utilization only. The reason for this is unknown to me so I prefer to count deletion events by ID 4660.

Judging by the field ProcessName = C:\Windows\explorer.exe , we know that the file was deleted locally .


The answer:

On 20.01.2010 at 13:09:58  user hdesk1 deleted the file H:\Test\Doc1.txt  locally  on server serv1  .

 

Answer II

 a) Once again we get started by finding out if there was any file deletion::

LogParser  -o:csv -tabs:ON “SELECT  TimeGenerated, EventID, Extract_Token(Strings, 1, ‘|’) AS USER, Extract_Token(Strings, 3, ‘|’) AS LogonID, Extract_Token(Strings, 5, ‘|’) AS HandleID INTO H:\LogParser\Event4660.txt FROM Security WHERE EventID = 4660 ORDER BY TimeGenerated DESC”

The output:

TimeGenerated,        EventID,     USER,    LogonID,       HandleID

2010-01-20 15:35:52,      4660,            jane,        0x1605225,      0x5414

We see that user  jane deleted some file/folder on 20.01.2010 at 15:35:52.

б) And again we find out what exactly was deleted, when and by whom:  (noting that LogonID and HandleID should be the same as in the previous output)

TimeGenerated,  EventID, USER,          LogonID,           ObjectName,        HandleID, ProcessName,   AccessTYPE

15:35:52,              4663,         jane,           0x1605225,         H:\Test\DocNet.txt,  0x5414,                   ,               0x10000

Here we see the name of deleted object (H:\Test\DocNet.txt) and how it was deleted.

As the field  ProcessName (or ImageName in Win2003) is empty we know there was what I call a “network deletion”.

Look! This time there’s no event 4663 dublication!

In both preceding examples we didn’t use the event 4656 (Handle Open) because we already know what exactly has been deleted from the event 4663.

The next step is to try to find out from what workstation the deletion has occurred.

At first we should search for the network logon event (4624) with the same LogonID (0x1605225) as in the events 4660 and 4663:

LogParser  -o:csv -tabs:ON “SELECT  TimeGenerated, EventID, Extract_Token(Strings, 3, ‘|’) AS LogonID, Extract_Token(Strings, 5, ‘|’) AS USER, Extract_Token(Strings, 8, ‘|’) AS LogonTYPE INTO H:\LogParser\Event4624-NetworkLogon.txt FROM Security WHERE EventID = 4624 ORDER BY TimeGenerated DESC”

The output:

TimeGenerated,                 EventID, LogonID,                USER,                     LogonTYPE,          ClientAddress

 

2010-01-20 15:45:18,            4624,           0x161475c,                SERV1$,                        3,                     127.0.0.1

2010-01-20 15:35:47,        4624,       0x1605225,            jane,                              3,                     10.1.2.102

2010-01-20 15:35:45,            4624,          0x16051d5,                jane,                               3,                     10.1.2.102

 

Note:  If we add [AND LogonID LIKE ‘%0x1605225%’]  expression to the code above
we’ll get the output with the single resulting  string:

LogParser  -o:csv -tabs:ON “SELECT  TimeGenerated, EventID, Extract_Token(Strings, 3, ‘|’) AS LogonID, Extract_Token(Strings, 5, ‘|’) AS USER, Extract_Token(Strings, 8, ‘|’) AS LogonTYPE INTO H:\LogParser\Event4624-NetworkLogon.txt FROM Security WHERE EventID = 4624 AND LogonID LIKE ‘%0x1605225%’ ORDER BY TimeGenerated DESC”

The output:

TimeGenerated,                 EventID, LogonID,                   USER,                     LogonTYPE,          ClientAddress

 2010-01-20 15:35:47,            4624,       0x1605225,            jane,                              3,                           10.1.2.102


So, the answer is: On 20.01.2010  at 15:35:52 user  “jane” deleted the file
H:\Test\DocNet.txt  on server SERV1 from the workstation
with ip = 10.1.2.102.

Moreover, we can make use of the new event in Win2008 – 5140 – to know from what shared folder this file was deleted:

LogParser -fullText:OFF -o:csv -tabs:ON “SELECT TimeGenerated, EventID, Extract_Token(Strings, 1, ‘|’) AS USER, Extract_Token(Strings, 2, ‘|’) AS DOMAIN, Extract_Token(Strings, 5, ‘|’) AS Source-IP, Extract_Token(Strings, 7, ‘|’) AS SHARE  INTO H:\LogParser\SERV1-FileShare-5140.txt FROM SECURITY WHERE EventID = 5140 AND SHARE NOT LIKE ‘%IPC%’ order by TimeGenerated desc”

The output:

TimeGenerated,      EventID,      USER,     Source-IP,    SHARE

2010-01-20 16:12:50,   5140,          secretary,     10.1.2.49,        \\*\DiskD

2010-01-20 15:35:47,   5140,    jane,            10.1.2.102,   \\*\Test

 …and to see when the given user logged off from the server Serv1 (e.g. at what time has the network session (with LogonID = 0x1605225 ) of the user “jane” from ip = 10.1.2.102 to Serv1 been ended ):

TimeGenerated,           EventID,     USER,      LogonID,  LogonTYPE

2010-01-20 16:32:12,      4634,      jane,             0x1605225,        3

2010-01-20 16:16:24,            4634,      Consuser1,     0x14d6257,            3

2010-01-20 16:16:00,            4634,     OLGA-SR$,    0x16708c3,            3

2010-01-20 16:14:25,            4634,     secretary,        0x166e3b3,            3

2010-01-20 16:13:01,            4634,     ELENA-LN$,  0x166e3a1,          3

2010-01-20 16:12:58,            4634,     jane,                   0x15d8694,         3

2010-01-20 15:45:18,            4634,   SERV1$,             0x161475c,          3

2010-01-20 15:44:47,            4634,   manager,            0x1469e11,          3

2010-01-20 15:35:46,            4634,     jane,                    0x16051d5,         3

So here it is the complete answer:

On 20.01.2010 at 15:35:47 user jane connected to the shared folder \\serv1\test from the workstation with ip = 10.1.2.102,  at 15:35:52 she deleted the file H:\Test\DocNet.txt  from \\serv1\test and closed the session at 16:32:12 (for example, closed the \\serv1\test shared folder’s window).

The new version of this article is available:
Windows Audit Part 4: Tracing file deletions in MS PowerShell

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.