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.
