Event Log Message Files (The description for Event ID … cannot be found)

Anybody who has used the built-in event viewer that comes with Windows more than once, has probably seen the message “The description for Event ID ( 50 ) in Source ( SomeService ) cannot be found. The local computer may not have the necessary registry information or message DLL files to display messages from a remote computer.” when viewing certain events. This message occurs more often when viewing events on a remote event log, but it appears often enough on the local machine as well.

event_message_id_cannot_be_found.pngI will explain this dubious error message here, but before I do I will explain how messages are in fact logged to the event log. After reading this you should have a much clearer picture about how applications log to the event log and how you go about troubleshooting this “error”.

The framework that Microsoft created for the event log, back in the NT 3.51 days, was actually quite sophisticated in many ways – especially when compared with the more simplistic Syslog capabilities (though Syslog still has some unique features).

A key feature of event logging in Windows is the fact that an application, at least when using the event log framework in the way it was intended to be used, will never actually directly write the actual message to the event log – instead it will log only the event source and event id, along with some properties such as category and insertion strings. The framework also supports multiple languages, so if you open an event on a French Windows, then the event will display in French (of course assuming that the message file from the vendor supports that) instead of English.

Let’s look at an example – using EventSentry – to understand this better. When EventSentry detects a service status change, it will log the event 11000 to the event log that reads something like this:

The service Print Spooler (Spooler) changed its status from RUNNING to STOPPED.

When EventSentry logs this event to the event log, you would expect that the application does (in a simplified manner) something like this:

LogToEventLog(“EventSentry”,
101000, “The service Print Spooler (Spooler) changed its status from RUNNING to
STOPPED.”);

However, this is NOT the case. The application logging to the event log never actually logs the message to the event log, instead the application would log something similar to this:

LogToEventLog(“EventSentry”,
101000, “RUNNING”, “STOPPED”);

(Note that the above example is for illustration purposes only, the actual code is somewhat more complicated)

So, our actual string from the event message is nowhere to be found, and that’s because the string is embedded in what is referred to as the “Event Message File”. The event message file contains a list of all events that an application could potentially log to the event log. Here is what an event message file looks like before it is compiled:

MessageId=10100
SymbolicName=EVENTSENTRY_SVC_STATUSCHANGE
Language=English
The status for service %1 (%2) changed from %3 to %4.
.
Language=German
Der Dienststatus von Dienst %1 (%2) aenderte sich von %3 auf %4.
.

Notice the numbers contained in the string that start with the percentage sign. These are placeholders for so-called insertion strings, and they make it possible to make the event log message dynamic, since an application developer can’t possible account for all imaginable error message or information that might be accumulated during the runtime of the application. For example, an application might log the name of a file that is being monitored to the event log, clearly this can’t be embedded into the event message file.

Instead, the application can insert strings (hence, insertion strings) into the event message during run time. Those strings are then stored in the actual event log, along with all the other static properties of event, such as the event id and the event source.

Event message files are usually DLL files, but event resources can also be embedded in executables – as is the case in EventSentry, where all events are contained in the eventsentry_svc.exe file. This is generally a good idea, since it reduces the number of files that have to be shipped with the software and it also prevents you from “losing” the message DLL.

You can browse through all embedded events in a message file by using the event message browser that is included in the free EventSentry SysAdmin Tools which you can download here. Simply launch the application, select an event log (e.g. Application), select an event source (e.g. EventSentry), and browse through all the registered event messages, sorted by the ID.

So now that we know how Windows handles event messages internally, we can go back to the original problem: “The description for Event ID ( 50 ) in Source ( SomeService ) cannot be found.”. The Windows Event Viewer logs this message for one of the following reasons:

* No message file is registered for the source (e.g. SomeService)
* The registered message file does not exist or cannot be accessed
* The specified event id is not included in the message file

If the message file is not registered, then this is probably because the application wasn’t installed correctly, or because it has already been uninstalled by the time you are trying to view the event message. For example, if the event message was logged before the application was uninstalled, but you are viewing the event after the application was uninstalled, then you will see this message.

If the event you are trying to view is important, then you can try to fix the problem yourself by either fixing the registry entry or locating the missing event message file.

The registry location depends on only two factors: The event log [EVENTLOG] the event was logged to as well as the event source [EVENTSOURCE].

HKLM\System\CurrentControlSet\Services\Eventlog\[EVENTLOG]\[EVENTSOURCE]

(Replace [EVENTLOG] and [EVENTSOURCE] with the respective values, and view/add/edit the value EventMessageFile. This is the value that points to the message file)

If this value doesn’t exist, then you can add it as either a REG_SZ or a REG_EXPAND_SZ value. You can specify multiple message files with a semicolon.

regedit_eventmessagefile.pngIf the message file specified in the value doesn’t exist, then you can simply copy it into the appropriate location – assuming you can get a hold of it that is :-). Oracle is notorious for not including the message file, in particular with the Express Edition.

A final note on message files for those of you haven’t had enough yet: You can use message files not only to translate event messages, but also for categories, GUIDs and more. Some of the values you might find (mostly in the security event log) are CategoryMessageFile, GuidMessageFile and ParameterMessageFile.

Well, this article turned out a lot longer than I had anticipated, but hopefully you will have a better understanding as to why this message is logged and what you can do about it.

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.

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.

Vista Event Log Changes

As you may already know, Microsoft significantly changed the Windows event log in Windows Vista. I always found the Windows event log to be a very well designed logging infrastructure, at least compared to the logging facilities that are available in other major network operating systems. The Windows event log however hasn’t changed much since it was originally included in Windows NT. It has actually been 13 1/2 years since the core event log service and event viewer underwent a major improvement – other than updating security event ids to accommodate new events related to various security components – Windows NT 3.1 was first released in 1993. I have never actually seen the event viewer in Windows NT 3.1, but Windows NT 3.51’s event viewer for example was not too much different than Windows 2003’s.

So it appears that Microsoft finally realized that a good system can be improved (especially with compliance becoming more and more important over the last years), and so the event log subsystem, including the event viewer, appear to have been rewritten completely in Windows Vista and of course the upcoming Windows Server 2008.

As we are continuing to improve Vista support in EventSentry,  I will cover the changes that I believe are relevant to IT professionals that need to manage their event logs. Just as a side note, EventSentry already monitors the Vista event log since the end of 2006, however ES 2.81 currently accesses the Vista event log through the legacy API that Vista (fortunately) still provides to pre-Vista event log software.

Before I dig into the technical details about the new event log, I need to point out that Microsoft made a large amount of changes to the event log, and didn’t leave a stone unturned. While the overall logic is the same (you have event logs and events 🙂 ), a lot has changed under the hood.

While this will affect IT professionals that need to manage event logs (since they need to make sure that their software works with Vista & Windows 2008), it will affect software developers even more. While I like a lot of the changes that were introduced, and we all know improvements were overdue for a long time, I personally feel that the new event log has been over-engineered. A lot of the features that were added are a bit of overkill and accessing, especially writing to, the event log is significantly more involved with the new version (at least if you take advantage of the new XML functionality). I think it would have been better to gradually introduce improvements over the last 10 years, rather than ignoring the event log for a long time and then introduce a myriad of new functionality to it – some of which has yet to make sense (I will prove my point below with future posts).

In any case, I will get off my soapbox now and focus on the relevant changes that were introduced.

Keywords
One of the new fields added to the properties of an event is called “Keywords”. I find the most interesting thing about this field that security events now have their severity stored in the Keywords field instead of the Type field (Type was renamed to Level in Vista and later). As you know, events in Windows Server 2003 and earlier used to have their severity stored in the Type property of an event (Information, Warning, Error, Audit Success, Audit Failure), but in Vista and later the severity of security events (Audit Success, Audit Failure) have been moved to the new Keywords field.

This of course leaves the question what the Level is set to for audit events. Well, the answer is Information. All Audit Success and Audit Failure events have their main severity stored in the Keywords field, whereas the Level field is always set to Information. An Audit Failure event that is informational, yeah – that makes a lot of sense!

So in theory it would be possible to have an Audit Failure event logged with a level of Information/Warning/Error, but I am not sure how useful this would be. After all, an Audit Failure is an Audit Failure.

Why was this changed? I am not sure. After asking the head of the Windows Auditing Team at Microsoft I received an explanation that, unfortunately, failed to eliminate my confusion. The original Type field could obviously accommodate the two attributes (since had always been there), and there would have been room for even more. There was some consensus between the two of us that the keywords field, at least in combination with the security events, was maybe not implemented in the best way.

In EventSentry we currently ignore the Keywords field and merge it with the original Type field, so that you can search across Pre-Vista machines and Vista machines using the same field name.

So this is it for now, we will cover a lot more about the new Windows Event Log here in the future. As always, let us know if you have any questions or feedback.