Operational Event 567? Maybe sometimes.

In my previous post I explained when and why 560 events are logged, and roughly explained why they are only of limited usefulness since they only log what a user could have done, not what they actually did.

Starting with Windows XP and Windows Server 2003, Microsoft introduced the so-called operational event 567. This event is supposed to enhance the auditing experience by not only logging what a user could do, but instead what he actually did! Does this sound too good to be true? Well, I guess that’s because it almost is.

According to Eric Fitzgerald’s Object Access Auditing Overview (Eric is the former head of the Windows Auditing Team), the 567 event should be logged in between the 560 (open handle) and 562 (close handle) events.

As such, the idea behind the 567 is simple:

1. User opens text file backup.cmd with a text editor. Event 560 is logged which includes all the rights the user will have to the document backup.cmd.

2. The user hits the save button, and Windows logs event 567, most likely including the WRITE_DATA access mask which indicates that data was written to the file. Note that the 567 event will not, unlike the 560 event, include the file name in the message text, but instead just the value of the handle that was included in the previously logged 560 event. As such, to make use of that event, you will have to go back to the 560 event to figure out which file was affected by the subsequently logged 567 event.

3. When the user closes the file, event 562 is logged. This event also only includes the value of the handle which was returned by the previously logged 560 event.

Well, you can imagine that I got pretty excited after doing all the research and was ready to see that 567 event in action on our production and test network. So I enabled auditing on a folder and started creating files, modifying files and so forth. Events 560 and 562 were logged just fine and as expected, but I had difficulties seeing a 567 event – it just wasn’t there. Since there is no option to turn event 567 on or off, I wasn’t exactly sure what I was doing wrong. I was ready to give up – after all I was quite tired that night, but after playing around more, trying different operating systems, different auditing options, logging on locally etc. I finally saw the 567 event. Hooray!

All seemed well until the next morning, when I tried to continue last night’s work and got stuck again. No 567 event. I then remember Eric’s blog entry, where he pointed out that event 567, due to a bug, wasn’t logged when files were accessed through a file share unless you had WinXP SP2 or Win2k3 SP1. Surely this couldn’t be a problem in my network, since I was running SP2 on XP and Windows Server 2003. Well, it was the best hint I had to work with, and so I compared local and remote file access auditing to see if it would make a difference.

Bingo!

As it turned out, event 567 was only logged when I accessed files locally, that is if the file that was audited resided on the same machine that I had logged on to. As soon as I accessed a file through a file share (as most people do), event 567 was not logged.

I was still confused though, after all I had read about the 567 event not only in Microsoft’s documentation and blog, but also at other trustworthy sources and still thought that maybe something was off in my environment. Maybe I was missing a hotfix or some other secret ingredient that would prevent my server from generating the highly desired 567 event.

So expanded my tests to another test network, another production network, a SBS 2003 network and so on and so on. The results were always the same, event 567 was not logged when I accessed the audited file through a file share.

Since I ran out of options and the existence vs. non-existence of the 567 affected development of a new EventSentry feature, I opened up a support call with Microsoft’s Enterprise Support. After an hour of mostly hold time and an actually helpful engineer, it turns out that event 567 is indeed only logged sometimes. The engineer didn’t want to be too specific, but the bottom line was that one should not except the 567 event to always be logged when a 560/562 event pair was logged. Asking why that was the case, I was told that implementing event 567 “correctly” would have required a kernel change which was not an option. So there you have it.

I stick to my “research” however – event 567 is indeed logged as long as you are accessing the audited files locally, and not through a network share. Otherwise you will have make do with the 560/562 events.

Of course you can also upgrade to Vista or Windows Server 2008, which log event 4663 (= 567 + 4096) regardless of whether you access the file locally or remotely. This event also includes the full filename and path, so collecting the related 4656 and 4658 events is not necessary. I have verified it with both, and it works very well indeed.

Thankfully, EventSentry 2.90 (when released) will take most of that burden of you and perform some additional  work for you to give a crisp idea of who is modifying/creating/deleting which file at what time.

Enjoy!

Tracking Objects with 560 and 562 Object Access events

One of the upcoming features in the 2.90 release of EventSentry is file object tracking, which will – as the name implies – track file access!

EventSentry already tracks process activity by intercepting and analyzing the 592 and 593 security events that are generated when a process starts or exits respectively; we also track logons and logoffs by intercepting and analyzing the various logon (e.g. 528) and logoff events. Tracking object access turns out to be a bit more involved as process and logon tracking, since Windows 2003 and earlier don’t actually log when an object is modified, but instead log when an object handle is being returned to the caller. I would like to mention here that object auditing has been drastically improved in Vista and later, but more on that next week.

But before I explain the 560, 562 and the problematic 567 events, let’s make sure we have everything setup for auditing to work.

1. Make sure that “Audit Object Access” is active on the machine where the files will be accessed. In most cases this will be your file server, and you will probably want to configure this with a group policy object and apply this setting to all machines from which you plan on collecting object audit events.

2. Once auditing is enabled on the machine, you will have to tell Windows which files you effectively want to audit, since generating an audit event for every single file by default would fill up your security event log quicker than you could get a cup of coffee. To audit a folder, bring up the security properties of the folder, click advanced and select the “Auditing” tab. Here you will specify which accesses and users will be audited, and I recommend that you always use Everyone when adding an audit entry to ensure that all object access is audited. I also recommend only auditing the access type you really care about. since 560 events can quickly fill up your event log (and consequently any consolidated database you might have) and there is no reason to monitor accesses you’re not concerned with (e.g. ReadAttributes).

Now to get back to the 560 and 562 events, this is better explained with an example. In Windows, when you need to read or write to a file, you usually call the CreateFile() API function which will return a handle to the object (=file in this case) you are about to access. When calling CreateFile(), you tell Windows which access to the file you need. For example, when you simply need to read from a file then you can pass GENERIC_READ (or the more specific FILE_READ_DATA) for the dwDesiredAccess parameter.

Assuming that you are allowed READ access to the file, Windows will return a handle to the requested file (that you can now use in subsequent ReadFile() operations). And this is exactly where Windows logs the 560 Audit Success event (assuming of course the access type and user match the auditing enries), essentially documenting that an object handle was returned. While this all sounds nice and dandy, the problem with the 560 event is that it doesn’t actually tell you what the caller ended up doing with that handle. Even if the caller where to close the handle right away with CloseHandle(), the 560 event would have still been logged – even if the caller never actually accessed the file.

The same holds true for potential write access to a file. If I access a file with the GENERIC_WRITE access right, then Windows will log a 560 event that looks similar to this:

Object Open:
Object Server: Security
Object Type: File
Object Name: E:\Folder\Customers\Sheet.xls
Handle ID: 20084
Operation ID: {0,93244500}
Process ID: 4
Image File Name:
Primary User Name: DC1$
Primary Domain: ESDOMAIN
Primary Logon ID: (0x0,0x3E7)
Client User Name: support.engineer
Client Domain: ESDOMAIN
Client Logon ID: (0x0,0x58C5419)
Accesses: READ_CONTROL
ReadData (or ListDirectory)
WriteData (or AddFile)
AppendData (or AddSubdirectory or CreatePipeInstance)
ReadEA
WriteEA
ReadAttributes
WriteAttributes

At first glance, one would assume that support.engineer wrote to the file, after all WriteData is included in the listed Accesses. This is far from accurate however, since the user could have closed the file right-away again (without ever reading or writing data from/to it) and the event would have still been logged in exactly the same manner.

This means that unless you manually verify some properties of the file, for example the access stamps, size or checksum, the 560 events only tell you what a user could have done, not what they actually did.

When the calling process is done working with the file, it will call CloseHandle() to close the handle it had previously opened. As such, a 560 event is always followed by a 562 event that includes the same handle ID as the original 560 event.

At some point during the Windows XP development, Microsoft seems to have realized that the 560 events are limited in their usefulness (at least for authorized access), and introduced the 567 event, also called an “operational event”. The purpose of the 567 event is not to log when a handle is returned, but instead when a file is actually being accessed – much more useful – at least in theory. So even though the 567 event was created to solve the problems of the 560 event, it does so only under limited circumstances.

But since I already wrote more on this subject than most people probably want to read, I will explain the 567 event in all detail in my next post this weekend.

Server Virtualization: Physical to Virtual Migration

Despite being around for quite some time now (VMWare released its first version of VMWare Workstation in 2001), server virtualization seems to be all the rage these days. It seems that not a day goes by without seeing virtualization mentioned in a newsletter, magazine or web site.

The first virtualization software product I used was indeed VMWare Workstation, some time around 2002. I used it mainly for testing and development, and the fact that it supported most major operating systems (e.g. Linux) was very helpful. A couple of years later we got our first dedicated server where we ran the VMWare GSX Server (now called VMWare Server). At that time I also evaluated Microsoft Virtual Server, but found it to be inferior from both a management and performance aspect, and it also didn’t support Non-Microsoft Operating Systems. Microsoft Virtual Server has improved since then however and is a viable alternative today.

As virtualization has become more and more important for our business, we have since migrated to the VMWare ESX Server, which supplies its own Linux-based operating system and thus offers a slightly better performance among other benefits. I know this is starting to sound a lot like a VMWare advertisement, so I’ll try to get to the point. Don’t get me wrong, we’ve definitely found problems in VMWare’s products over the years, but its proven to be a stable and reliable platform overall. For example, installing and upgrading ESX Server has thus far not caused us any problems or difficulties. Read Michael’s review of VMWare Server 2 however, he doesn’t appear to have liked the latest release of VMWare Server too much.

One thing that is often overlooked in my opinion however is the ability to migrate physical machines to virtual machines using the free VMWare Converter. Using the converter, you can migrate a physical into a virtual machine, which can run on any of VMWare’s products. How many IT departments are running servers that are barely used anymore, yet cannot be turned off because a handful of users are occasionally accessing the server to access old data? Those machines usually don’t require fast hardware and might even be running on systems that are no longer supported by the manufacturer. Systems like these are ideal candidates for virtualization.

Here are just some of the benefits you get by moving a legacy or underutilized machine to a virtual server:

  1. If you retire (=recycle) the original hardware, you save money on power by requiring less A/C and power consumption in your data center.
  2. You can cancel any maintenance agreements on the hardware if it is retired.
  3. You might speed up the application if the server hosting the virtual machines is more powerful than the original box the software was running on.
  4. If the migration fails or causes unexpected problems, then you have nothing to fear since the original server won’t be modified.
  5. The migration is done remotely, so you don’t even have to physically log on to the computer being migrated.
  6. Virtual machines can be suspended, thus saving RAM on the host machine while suspended.

We performed a similar migration a couple of months ago when we switched to a new support ticketing system. Since we didn’t migrate any data from the previous system to our new system, we wanted to have the ability to login and search tickets periodically – so shutting of and formatting the server was not an option. Of course, keeping the server running 24/7 seemed like waste as well – especially when we wouldn’t need to access the machine more than once a week. Hence, a migration to a virtual machines seemed like the best option and the server lives on ESX Server since. The physical server was initially just turned off for a few weeks, but has since found new use for a different project.

So if you’re planning to move to virtualization or have already begun, don’t just think about new machines but also consider “virtualizing” existing physical machines.

And remember that machines running inside VMWare or Microsoft Virtual Server can be monitored by EventSentry just like a physical machine can. 🙂

1983: Coleco Adam

If you’re past 30 then you’ve probably heard about the Commodore C64, the Amiga, the IBM XT and so forth. Well, another lesser known computer that was released around the same time IBM released their “IBM Personal Computer XT” was the Coleco Adam.

Why is this funny?

To find out why this is beyond funny, you will have to read the Wikipedia article about the Coleco Adam, in particular the “Problems” section. We found the 1st and 3rd problem most amusing.

Vista/Win2k8 Event Log Changes #2: .evtx Format

In my previous post I already mentioned that Vista and Windows Server 2008 introduced many changes to the Windows Event Log, and the event log backup files with the familiar .evt extension are no exception. If you backup event logs in the .evt format and plan on moving to Vista and/or Windows 2008 then you should make yourself familiar with the basic changes and the “new” EVTX format.

The new event viewer on Vista and Win2k8 supports exporting an event log in either the EVTX, XML, TXT or CSV format. If you select the EVTX format then you will not be able to import/load this file on a Pre-Vista/Win2k8 machine, the old event viewer does not understand the new EVTX format.

So far so good, this is to be expected. Like I mentioned in my previous post, Vista and later also still provide the legacy event log APIs so that applications that were developed for Windows 2003 and earlier are still able to access and backup the event log. The next paragraphs get a bit confusing, so only read on if you are interested in more details ;-).

Windows 2003 and earlier provide two API calls to backup and/or clear the event log: ClearEventLog() and BackupEventLog(). If you use any of these functions to backup an event log on Vista and later, then you are still able to create a .evt file. I would expect that this file could be opened on any computer that understands the EVT format, however this is not the case. Even when you export an event log using the aforementioned legacy API calls, the resulting file can still only be opened with the new event viewer on Vista or later. I will refer to event log backup files that were created on Vista and later with the legacy API calls as the new EVT format from now on.

This becomes more clear when you compare the contents of the new EVT format with the EVTX format. While the two files are different for the exact same event log backup – the overall structure are quite similar. You can also rename a file with the new EVT format to the EVTX extension and the new event viewer will open this file correctly. The format of an EVT file on the other hand is very different to that of an EVTX file.

So the bottom line is that you can, in theory, create three types of event log backup files:

1. EVT Format
These files are created on Windows Server 2003 and earlier. Vista and later refer to these files as “Classic Event Log Files”, and you can open and read EVT files on any NT-based OS including Vista and later.

2. EVT Format (when created on Vista and later)
These files can only be created on Vista and later by using the legacy API calls ClearEventLog() and BackupEventLog(). It is important to point out that even though these files have the .evt extension, they unfortunately cannot be read on Windows Server 2003 or earlier and the format of this file is similar to the new EVTX format.

3. EVTX Format
These files can only be created and viewed on Vista and later.

Note on EventSentry: If you are backing up event logs with EventSentry v2.72, v2.80 or v2.81 on Vista or Windows 2008, then EventSentry will create EVT files (#2) that can only be viewed on Vista or later. We are switching to the native EVTX format for event log backups with the upcoming v2.90 release of EventSentry.