Banking

SolutionBase: Using audit logs to monitor DHCP Server

Audit logs are not really practical for security auditing but can be invaluable in troubleshooting DHCP server-related issues. In this article, Brien Posey discusses the anatomy of a DHCP server audit log.

This article is also available as a TechRepublic download.

Most of the time, when a Windows related article talks about audit logs, those logs are security related. When it comes to the DHCP services though, the audit logs tend to be much more useful from a diagnostic standpoint than from a security standpoint. After all, a DHCP server's only job is to lease IP addresses to network clients, so there is little reason to perform a security audit of the DHCP server's activity (you do want to stay on top of the operating system's audit logs though).

Granted, some would argue that if the DHCP services give you auditing information that can be used to monitor network activity, then your security people should be going over those logs with a fine tooth comb. I disagree though. Unless you know exactly what you are looking for, going through the DHCP audit logs looking for potential security breaches is both tedious and generally non productive. After all, if there are hundreds of PCs on a network, then what are the chances that you would really be able to spot a single unauthorized MAC address among hundreds or thousands of legitimate log entries? In my opinion, your security staff's time is much better spent reviewing other types of audit logs.

That's not to say that the DHCP audit logs are useless though. Even though the DHCP audit logs are impractical for day to day security monitoring, they are an excellent diagnostic tool. The DHCP audit logs provide a wealth of information regarding your DHCP server's functionality. My goal in this article is to show you how to interpret these logs.

Configuring DHCP logging

Audit logging is enabled by default for the Windows Server 2003 version of DHCP. You can find the audit logs in the c:\windows\system32\dhcp folder. The log files use the name DhcpSrvLog-XXX.log, where XXX is a series of three letters that represents the day of the week that the log was created on. For example, a log namedDhcpSrvLog-Fri.log would be the log file that was created on Friday.

Although logging is enabled by default, there are some restrictions placed on the logs. These restrictions have to do with the log file sizes. A log file can grow to a maximum size of 1 MB. Furthermore, if the DHCP logs collectively grow to exceed 20 MB, then the logging function is shut down in an effort to conserve disk space.

For the most part, you can't really get around these limitations. There are a couple of things related to DHCP auditing that you can change though. To do so, open the DHCP console by selecting the DHCP command from the Administrative Tools menu. When the console opens, right-click on the listing for the current DHCP server, and select the Properties command from the resulting shortcut menu.

At this point Windows will open the DHCP server's properties sheet. If you look at the properties sheet's General tab, you'll see that there is a check box that you can use to enable or to disable DHCP logging. As I said before, DHCP logging is enabled by default. In most cases, it's probably a good idea to leave DHCP logging enabled. However, if your DHCP server is having performance problems, then disabling audit logging is one way that you can help the server to perform a little bit better.

Another DHCP audit logging related setting that you can change is the log file path. To do so, go to the Advanced tab. This tab contains a text box labeled Audit Log File Path. If for some reason you don't like the default logging path, you can use this text box to set the path to anything that you want.

Examining the DHCP logs

Now that I've shown you what few logging options exist, I want to show you how you can use the DHCP logs. The log files themselves are nothing more than text files. If you double-click on a log file, they will be opened again Notepad. Below is an excerpt from a fairly typical DHCP log:

Microsoft DHCP Service Activity Log

Event ID Meaning

00 The log was started.

01 The log was stopped.

02 The log was temporarily paused due to low disk space.

10 A new IP address was leased to a client.

11 A lease was renewed by a client.

12 A lease was released by a client.

13 An IP address was found to be in use on the network.

14 A lease request could not be satisfied because the scope's

address pool was exhausted.

15 A lease was denied.

16 A lease was deleted.

17 A lease was expired.

20 A BOOTP address was leased to a client.

21 A dynamic BOOTP address was leased to a client.

22 A BOOTP request could not be satisfied because the scope's

address pool for BOOTP was exhausted.

23 A BOOTP IP address was deleted after checking to see it was

not in use.

24 IP address cleanup operation has began.

25 IP address cleanup statistics.

30 DNS update request to the named DNS server

31 DNS update failed

32 DNS update successful

50+ Codes above 50 are used for Rogue Server Detection information.

ID,Date,Time,Description,IPAddress,HostName,MAC Address

00,07/21/06,19:42:47,Started,,,,

56,07/21/06,19:42:48,Authorization failure, stopped servicing,,production.com,,

55,07/21/06,19:50:52,Authorized(servicing),,production.com,,

24,07/21/06,20:42:48,Database Cleanup Begin,,,,

25,07/21/06,20:42:48,0 leases expired and 0 leases deleted,,,,

25,07/21/06,20:42:48,0 leases expired and 0 leases deleted,,,,

50,07/21/06,20:49:01,Unreachable Domain,,production.com,8250,

24,07/21/06,21:42:49,Database Cleanup Begin,,,,

25,07/21/06,21:42:49,0 leases expired and 0 leases deleted,,,,

25,07/21/06,21:42:49,0 leases expired and 0 leases deleted,,,,

If you look at the sample log file, you'll see that the first part of the log file contains a list of codes. I will come back to these codes in a little while. For now though, look just below the list of codes and you'll see a header row starting with ID, Date, Time, etc. The log entries themselves start below this header row.

The log portion of the file is actually presented in CSV format. As you probably know, CSV stands for Comma Separated Value. This means that each field is separated by a comma. CSV files can be difficult to read within a word processor. However they can be imported into Microsoft Excel for easier reading. The log entries below show a subset of the log entries from above, but presented in a format similar to the way that they would be displayed in Microsoft Excel, as shown in Table A.

In this particular set of log file entries, you can see an ID, date, time, and description for each event. Obviously the date and time are pretty self explanatory. However, at first glance the data in the ID and description fields may not make a lot of sense.

Earlier I showed you the list of the event IDs at the beginning of the log file. These event IDs correspond to the number shown in ID column. The description field simply contains elaboration of the information conveyed through the event ID.

For example, let's take a look at the very first entry in the log file excerpt shown above. As you can see, the event ID is 0 and the description is Started. If you look at the Event ID Meaning section at the top of the log file, you can see that the meaning of event ID 0 is that the log was started. In this particular case, the description really isn't necessary. I'm assuming that Microsoft probably just put it there to make your life a little bit easier.

If you look at the second entry in the log file, you can see that the event ID number is 56 and that the description is Authorization Failure. If you go back to the Event ID Meaning section at the top of the log file, you will see that there is no listing for event ID number 56. The Event ID Meaning section simply states that codes above 50 are used for rogue server detection information. Although log file does not tell you what code number 56 means specifically, I have done some research and found a listing of what code numbers above 50 mean. Below is a description:

50 - The DHCP server could not locate the necessary domain.

51 - Authorization was successful.

52 - The server was recently upgraded to Windows Server 2003 Standard Edition. During the upgrade process, the unauthorized DHCP server detection mechanism, which is used to determine whether or not the DHCP server has been authorized in the active directory, was disabled.

53 - The Active Directory was inaccessible at the time that the DHCP services started. Because of this, cached information was used to authorize the DHCP services to start.

54 - This is an authorization failure code. When this event occurs, it is because the DHCP server does not authorized within the active directory. An event code and 54 should be followed by an event ID showing that the DHCP services have stopped.

55 - The DHCP services were authorized to start.

56 - Event number 56 was the event that showed up in our sample log file. This event indicates that the DHCP service was not authorized to start, and was consequently shut down. As you probably know, you must authorize a DHCP server in active directory prior to starting the DHCP services.

57 - Another DHCP server already exist within the specified domain.

58 - The DHCP server was unable to locate the necessary domain.

59 - A network connectivity issue prevent the server for determining whether or not it has been authorized.

60 - This error code needs a bit of explaining. The event ID means that no domain controller is Directory Service enabled. This event ID this only encountered in mixed mode environments in which Windows NT domain controllers are present. Because a DHCP server can only be authorized through the Active Directory, the DHCP server must be able to communicate with the Active Directory in order to determine whether it has been authorized or not. Therefore, if the DHCP server is only able to communicate with Windows NT based domain controllers, the log file will reflect an event ID of 60.

61 - This event ID means that another DHCP server that belongs to the same domain was found on the network. This event ID is different from number 57 in that the detected DHCP server does not necessarily have to be authorized. For example, the DHCP services might be running on an old Windows NT server.

62 - Event ID number 62 means that another DHCP server was detected on the network. The difference between event ID number 62 and event ID numbers 61 and 57 is that event ID number 62 is not domain specific. In fact, the DHCP server that is detected does not even have to be a Windows server. This is simply a generic event ID that is produced anytime another DHCP server is detected.

63 - Event ID number 63 is produced when the DHCP server is having trouble with the rogue detection mechanism. This event is generated when the rogue detection mechanism is restarted. Restarting the rogue detection mechanism implies that the server is going to try one more time to determine whether or not it is authorized.

64 - This event ID indicates that there are no DHCP enabled network interfaces. What this means is that none of the server's network interfaces are configured in a way that is acceptable to the DHCP services. Typically this means one of three things. One possibility is that there may not be in network cable plugged into the network adapter in question. A second possibility is that all of the DHCP server's network interfaces might be configured to use dynamic IP addresses. A DHCP server requires at least one static IP address. Finally, the third possibility is that all of the network adapters bound to static IP addresses have been disabled.

The DHCP server database cleanup

The next thing that I want to show you is the database cleanup references in the log files. As I'm sure you know, IP address leases periodically expire. When a lease expires, the DHCP server must revoke the least.

To do so, the DHCP server relies on an internal database cleanup process that runs once an hour. In addition to cleaning up expired leases, the maintenance process performs a few minor housekeeping chores and creates a backup of the database. The database cleanup process and its results are included in the DHCP log file. The following excerpts from a log file show what you will typically see in regards to the database cleanup process:

24,07/22/06,00:00:34,Database Cleanup Begin,,,,

25,07/22/06,00:00:34,0 leases expired and 0 leases deleted,,,,

IP address leases

Of course the largest part of the typical DHCP server log are the log entries related to clients leasing, renewing, or releasing IP addresses. Below is an excerpt from a DHCP server log that shows this type of activity:

10,07/22/06,22:19:56,Assign,147.100.100.120,e2k7.,0013D30C227E,

31,07/22/06,22:19:56,DNS Update Failed,147.100.100.120,e2k7.,-1,

30,07/22/06,22:20:19,DNS Update Request,120.100.100.147,e2k7.,,

12,07/22/06,22:20:19,Release,147.100.100.120,e2k7.,0013D30C227E,

31,07/22/06,22:20:19,DNS Update Failed,147.100.100.120,e2k7.,-1,

30,07/22/06,22:20:25,DNS Update Request,120.100.100.147,e2k7.,,

10,07/22/06,22:20:25,Assign,147.100.100.120,e2k7.,0013D30C227E,

If you look at this log file excerpt, you will notice that it uses the very same status codes as the ones that I talked about earlier. These codes can be very helpful in diagnosing potential problems. For example, if you look at the second line of code in the excerpt above, you will notice a message stating that a DNS update failed. I generated this error by configuring my server with an incorrect DNS server address. In the real world though, this type of error could be hard to troubleshoot and less you look at the DHCP server logs.

Even though DHCP updates are failing IP addresses are still being leased. Therefore, the DHCP server gives the illusion that everything is working perfectly. Problems would only show up if a network client tried to communicate with another network client that got its IP address from this DNS server. Communications would likely fail because the DNS server would be unable to resolve the client's hostname to an IP address.

In a situation like this, it would be very easy to go on a wild goose chase. An inexperienced administrator would most likely be looking for a DNS server malfunction that doesn't exist. All the while, the clue to solving the problem lies in the DHCP server log. This is one reason why it is important to check your DHCP server logs periodically.

Editor's Picks

Free Newsletters, In your Inbox