Ned here again. There comes a day in nearly every administrator’s life where they will need to boot a domain controller into DS Restore Mode. Whether it’s to perform an authoritative restore or fix database issues, you will need the local administrator password. Too often, we work with customers that have not been maintaining this password and do not have a way to get in to their DC’s. Sometimes it’s because the password was set by another admin who is not available or no longer works at the company. Other times it’s because the password was set at DC promotion years ago and no one remembers it anymore. Since the password can only be set when the DC is running in normal mode, you get a nasty chicken and the egg situation if the DC cannot start Directory Services correctly. Today we’ll talk about some methods to get this password under control.

The old fashioned way

All domain controllers have a hard-coded local Administrator account stored in their SAM database. This account and local database are not used or generally available when the DC is running normally. You probably remember setting this password during DCPROMO:

In addition, the password can be reset later while the DC is running by using the NTDSUTIL tool:

If you know the password, you can restart the domain controller into DS Restore mode using F8 or via the boot options exposed in MSCONFIG and away you go.

But what are the options to maintain this password, especially when your environment is in the hundreds or thousands of DC’s? Let’s dig in.

NTDSUTIL Password Pull

Beginning with hotfix KB961320 on Windows Server 2008, you now have the option to synchronize the DSRM password on a DC with a specific domain account. You must do every time the password is changed; it does not create an automatic sync partnership.

1. Create a standard domain user account and set it with a complex password. It does not need to be a member of any special groups or the Domain Admins group.

2. Install the hotfix on your DC and restart.

3. Logon to the DC normally.

4. In an elevated CMD prompt where you have logged on as a Domain Admin, run:

NTDSUTIL
SET DSRM PASSWORD
SYNC FROM DOMAIN ACCOUNT <your user here>
Q
Q

So for example (using NTDSUTIL’s ability to pass in all parameters on a single command-line):

Note how there is no need to provide the actual password being used, or provide the old password. This feature will also be included in Service Pack 2 for Win2008.

Group Policy Preference Automation of NTDSUTIL

So what if we want to automate this NTDSUTIL command so that is run via a scheduled task? This is easily done using Group Policy Preferences.

Note: Before you get too excited that I’ve missed something – no, GPP Local User password does not work with the DSRM passwords on domain controllers. You cannot use it to push a new password to the local administrator on DC’s; it only works only on member computers. Trust me, I’ve tried.

The beauty of this solution is that there is no password stored anywhere except in Active Directory itself and the system effectively self maintains – the only administrator intervention needed is to periodically change the special user’s password, and to make sure the scheduled task is working on the DC’s. The same way you should be checking to make sure those backups will actually function for a restore if you ever need to use this password.

So let’s set this up:

1. Start GPMC on a Windows Server 2008 or Windows Vista computer running RSAT.

2. Create and link a new policy on the Domain Controllers OU (you are doing all this in a test domain first, right?).

3. Create the GPP Scheduled task settings.

Note here that I have set:

A) Action of ‘Update’ (this will create the task if it does not exist).

B) Run command of the built-in GPP variable for %SystemDir% to specify the System32 directory, along with the ntdsutil.exe to be called.

C) The command line exactly as it would be done by hand with ntdsutil, including the quotation marks:

“SET DSRM PASSWORD” “SYNC FROM DOMAIN ACCOUNT DsrmUser” Q Q

D) The task is Enabled with a checkbox so that it will run, not just be created.

E) Then I have set this to run as a daily task at 9AM (it’s fairly likely that the DC will be running at that point). I could also run this hourly, weekly, etc – whatever I want.

4. After having created the policy and letting it apply to DC’s, I now see it is working by examining the scheduled tasks on one of my domain controllers. There it is (as well as another one I added to run every night too – can’t be too careful):

5. Once the right time has come and gone, I boot a DC into DS Repair mode and check – sure enough, my new password has taken affect automagically.

And there you go.

- Ned ‘That’s the same combination I have on my luggage!’ Pyle

Reviewer’s note: We made Ned change his smart card PIN to something other than ‘12345’ after he let it slip in this blog post.

Ned here again. Today begins a 21-part series on using the DFSR debug logs to further your understanding of Distributed File System Replication. While there are specific troubleshooting scenarios that will be covered, the most important part of understanding any products logging is making sure you are comfortable with it before you have errors. That way you have some point of reference if things go wrong.

As you can probably guess, these posts were a long time in development. They are based on an internal DFSR whitepaper I have worked on for six months, and which went through review by a number of excellent folks here in Support, Field Engineering, and the Product Group itself. Except for the removal of all private source code references, this series is otherwise unchanged.

I'll start with a couple posts on the logs themselves, how they are formatted, how they can be controlled, etc. Then I'll dig into scenarios in detail, for both Windows Server 2003 R2 and Windows Server 2008. Don't feel like you have to read and memorize everything – this series is a reference guide as well.

And yes, there will be a complete downloadable copy of this series in a few common file formats when the series is done.

Logging levels

DFSR writes circular log files in %systemroot%\debug that automatically compress with the GZ archive format. The debug logs can have varying levels of detail verbosity, to control how much or how little data you want written. It is also possible to control how many logs to maintain before overwriting the oldest ones, how many entries to store in each log, where the logs are stored, and whether or not logging should run. Under default log settings they should never occupy more than ~50MB of space on Windows Server 2003 R2 servers.

The following controls the log settings and describes the defaults:

SETTING: Debug Log Severity
Default: 4
Range: 1-5
WMIC syntax:

wmic /namespace:\\root\microsoftdfs path dfsrmachineconfig set debuglogseverity=5

SETTING: Debug Log Messages
Default: 200000
Range: 1000 to 4294967295 (FFFFFFFF)
WMIC syntax:

wmic /namespace:\\root\microsoftdfs path dfsrmachineconfig set maxdebuglogmessages=500000

SETTING: Debug Log Files
Default: 100
Range: 1 to 10000
WMIC syntax:

wmic /namespace:\\root\microsoftdfs path dfsrmachineconfig set maxdebuglogfiles=200

SETTING: Debug Log File Path
Default: %windir%\debug
WMIC syntax:

wmic /namespace:\\root\microsoftdfs path dfsrmachineconfig set debuglogfilepath="d:\dfsrlogs"

NOTE: The path must be created manually; if not, at service restart, the default value %windir%\debug will be used.

SETTING: Enable Debug Logging (NOTE: Debug logging is enabled by default)
Default: TRUE
Range: TRUE or FALSE
WMIC syntax:

wmic /namespace:\\root\microsoftdfs path dfsrmachineconfig set enabledebuglog=true

The WMIC.EXE commands above are actually modifying the DfsrMachineConfig.XML file that is stored in the %systemdrive%\system volume information\dfsr\config. It will populate the DfsrDebug tags. If running with defaults, these would not be populated – in the example below debug log severity is now at 5:

- <DfsrDebug>
<EnableDebugLog>true</EnableDebugLog>
<DebugLogFilePath>C:\WINDOWS\debug</DebugLogFilePath>
<MaxDebugLogFiles>100</MaxDebugLogFiles>
<DebugLogSeverity>5</DebugLogSeverity>
<MaxDebugLogMessages>200000</MaxDebugLogMessages>
</DfsrDebug>

When setting Debug Log Severity you are influencing how verbose the logs are – i.e. what do we consider important enough to write. Here is a brief table:

Since the default is 4, DFSR will log everything that occurs except for tracing details. Tracing details are called out further in this guide, and are only necessary to activate under very specific troubleshooting scenarios.

The debug log format

The DFSR debug logs use a consistent, predictable format that consists of:

Header – written at the top of each log file and contains (for example):

* FRS Log Sequence:1 Index:1 Computer:2003MEM20 TimeZone:Eastern Standard Time (GMT-05:00) Build:[Feb 16 2007 20:14:20 built by: srv03_sp2_rtm] Enterprise=1
* Configuration logLevel:4 maxEntryCount:200000 maxFileCount:100 logPath:\\.\C:\WINDOWS\debug\

Header lines always start with an asterisk (*). The header information is always written and cannot be turned off without disabling logging altogether.

Single-line messages – written throughout the logs and always map back to one discrete operation in DFSR. So for example:

20080111 15:12:30.996 3876 JOIN 1171 Join::SubmitUpdate Sent: uid:{AC759213-00AF-4578-9C6E-EA0764FDC9AC}-v33846 gvsn:{AC759213-00AF-4578-9C6E-EA0764FDC9AC}-v33846 name:USRSTAT.EXE connId:{CC694D38-7E97-467C-A963-B3D9B6E308B9} csId:{1697E5EB-BBD0-45B7-AC2F-11EBE7B3FD47} csName:dfsrprestaged

Single-line messages always start with a date-time stamp entry. The above sample line is wrapped for readability.

Nested messages – written throughout the logs and always map back to one discrete operation in DFSR that generates a multi-line response for better readability. So for example:

20080111 11:44:28.873 1640 INCO 4378 InConnection::UpdateProcessed Received Update. updatesLeft:237 processed:1171 sessionId:1 open:1 updateType:0 processStatus:0 connId:{D0BF5598-9457-4C32-8C50-7558BCD76610} csId:{1697E5EB-BBD0-45B7-AC2F-11EBE7B3FD47} csName:dfsrprestaged update:
+    present 1
+    nameConflict 0
+    attributes 0x10
+    gvsn {AC759213-00AF-4578-9C6E-EA0764FDC9AC}-v29102
+    uid {AC759213-00AF-4578-9C6E-EA0764FDC9AC}-v29102
+    parent {AC759213-00AF-4578-9C6E-EA0764FDC9AC}-v28024
+    fence 16010101 00:00:00.000
+    clock 20080110 19:05:43.167
+    createTime 20080110 19:05:43.157 GMT
+    csId {1697E5EB-BBD0-45B7-AC2F-11EBE7B3FD47}
+    hash 37123A73-30C1AFF0-B4EE5252-46212327
+    similarity 00000000-00000000-00000000-00000000
+    name acctsid

Nested messages follow single line messages that are ended with a colon. The nested messages always start with a plus sign (+). The nested lines can change depending on the class and method/function being executed so they are described in their own section below for 'File and Folder Field Information'.

The common GUID fields

Globally Unique Identifiers (GUID's) are used throughout the DFSR system to map the friendly names of the topology to unique entries used by the DFSR service. This can make reading the DFSR debug logs very challenging, as not all GUID's in the environment are defined in the logs. When examining the DFSR debug logs it is important to understand how to map GUID's to real objects for troubleshooting purposes. Sample log entry:

20080403 11:19:54.349 1660 SRTR 329 SERVER_EstablishConnection Succeeded on connId:{097BFFAA-99FB-4A4D-9590-C102985A55C6} replicaSetId:{D3558FFB-1E46-483F-AE89-E840E4A6A97B} partnerAddress:2003MEM21.contoso.com
20080403 11:19:55.710 3360 JOIN 1171 Join::SubmitUpdate Sent: uid:{AC759213-00AF-4578-9C6E-EA0764FDC9AC}-v137449 gvsn:{AC759213-00AF-4578-9C6E-EA0764FDC9AC}-v137449 name:samplefile.txt connId:{097BFFAA-99FB-4A4D-9590-C102985A55C6} csId:{B269F903-539D-42F2-9D33-935590097578} csName:ihaterobocopy
20080403 11:19:55.891 572 OUTC 588 OutConnection::OpenFile Received request for update:
+    present 1
+    nameConflict 0
+    attributes 0x20
+    gvsn {AC759213-00AF-4578-9C6E-EA0764FDC9AC}-v137449
+    uid {AC759213-00AF-4578-9C6E-EA0764FDC9AC}-v137449
+    parent {B269F903-539D-42F2-9D33-935590097578}-v1
+    fence 16010101 00:00:00.000
+    clock 20080403 15:17:17.233
+    createTime 20080403 15:17:17.193 GMT
+    csId {B269F903-539D-42F2-9D33-935590097578}
+    hash 00000000-00000000-00000000-00000000
+    similarity 00000000-00000000-00000000-00000000
+    name samplefile.txt

There are a few tools that can be used to map the GUID's:

DFSRADMIN.EXE and DFSRDIAG.EXE - You can use the DFSRADMIN and DFSRDIAG tools included with DFSR to enumerate the topology and determine the GUID's. Below is a sample of doing this through a CMD prompt with the data provided by the above logs:

Dfsradmin.exe rg list /attr:rgname,rgguid

RgName RgGuid
SteveLovesFRS d3558ffb-1e46-483f-ae89-e840e4a6a97b

The above command is used to return the Replication Group name, which you will see below is necessary to complete a number of further lookups. This maps to REPLICASETID.

Dfsradmin.exe rf list /rgname:SteveLovesFRS /attr:rfname,rfguid

RfName RfGuid
ihaterobocopy b269f903-539d-42f2-9d33-935590097578

The above command is used to get the GUID of the Replicated Folder so that CSID is known.

Dfsradmin.exe conn list /rgname:SteveLovesFRS /attr:sendmem,recvmem,connguid

SendMem RecvMem ConnGuid
2003MEM20 2003MEM21 097bffaa-99fb-4a4d-9590-c102985a55c6
2003MEM21 2003MEM20 d2e396a5-837b-4103-b8a2-b8fc2c71d388

The above command is used to return the Connection GUID's that can be mapped to CONNID.

Dfsrdiag.exe guid2name /guid:AC759213-00AF-4578-9C6E-EA0764FDC9AC /rgname:stevelovesfrs

Object Type : DfsrVolumeInfo
Computer : 2003MEM20.contoso.com
Volume Guid : B8B42506-BF98-11DC-B176-0003FF3813C5
Volume Path : E:
Volume SN : 108172604
DB Guid : AC759213-00AF-4578-9C6E-EA0764FDC9AC

Finally, the above command is used to retrieve the GUID of the actual DFSR database and therefore the server it is running on. When files and folders are created or modified, the originating server is used to form the GUID portion of the name, and then the current version vector from that server is appended to complete the unique file mapping in the database. These are used for UID and GVSN.

So having retrieved all the GUID's, we can now see that our debug log entry actually means:

20080403 11:19:54.349 1660 SRTR 329 SERVER_EstablishConnection Succeeded on connId: 2003MEM20 replicaSetId:SteveLovesFRS partnerAddress:2003MEM21.contoso.com
20080403 11:19:55.710 3360 JOIN 1171 Join::SubmitUpdate Sent: uid: 2003MEM20-v137449 gvsn: 2003MEM20-v137449 name:samplefile.txt connId: 2003MEM20 csId: ihaterobocopy csName:ihaterobocopy
20080403 11:19:55.891 572 OUTC 588 OutConnection::OpenFile Received request for update:
+    present 1
+    nameConflict 0
+    attributes 0x20
+    gvsn 2003MEM20-v137449
+    uid 2003MEM20-v137449
+    parent 2003MEM20-v1
+    fence 16010101 00:00:00.000
+    clock 20080403 15:17:17.233
+    createTime 20080403 15:17:17.193 GMT
+    csId {B269F903-539D-42F2-9D33-935590097578}
+    hash 00000000-00000000-00000000-00000000
+    similarity 00000000-00000000-00000000-00000000
+    name samplefile.txt

Next up – nested debug log fields and module ID's.

Understanding DFSR debug logging (Part 1: Logging Levels, Log Format, GUID’s)
Understanding DFSR debug logging (Part 2: Nested Fields, Module ID's)
Understanding DFSR debug logging (Part 3: The Log Scenario Format, File Added to Replicated Folder on Windows Server 2008)
Understanding DFSR debug logging (Part 4: A Very Small File Added to Replicated Folder on Windows Server 2008)
Understanding DFSR debug logging (Part 5: File Modified on Windows Server 2003 R2)
Understanding DFSR debug logging (Part 6: Microsoft Office Word 97-2003 File Modified on Windows Server 2008)
Understanding DFSR debug logging (Part 7: Microsoft Office Word 2007 File Modified on Windows Server 2008)
Understanding DFSR debug logging (Part 8: File Deleted from Windows Server 2003 R2)
Understanding DFSR debug logging (Part 9: File is Renamed on Windows Server 2003 R2)
Understanding DFSR debug logging (Part 10: File Conflicted between two Windows Server 2008)
Understanding DFSR debug logging (Part 11: Directory created on Windows Server 2003 R2)
Understanding DFSR debug logging (Part 12: Domain Controller Bind and Config Polling on Windows Server 2008)
Understanding DFSR debug logging (part 13: A New Replication Group and Replicated Folder between two Windows Server 2008 members)
Understanding DFSR debug logging (Part 14: A sharing violation due to a file locked upstream between two Windows Server 2008)
Understanding DFSR debug logging (Part 15: Pre-Seeded Data Usage during Initial Sync)
Understanding DFSR debug logging (Part 16: File modification with RDC in very granular detail (uses debug severity 5))
Understanding DFSR debug logging (Part 17: Replication failing because of blocked RPC ports (uses debug severity 5))
Understanding DFSR debug logging (Part 18: LDAP queries failing due to network (uses debug severity 5))
Understanding DFSR debug logging (Part 19: File Blocked Inbound by a File Screen Filter Driver (uses debug severity 5))
Understanding DFSR debug logging (Part 20: Skipped temporary and filtered files (uses debug severity 5))
Understanding DFSR debug logging (Part 21: File replication performance from throttling (uses debug severity 5))

- Ned 'Cure for Insomnia' Pyle

Herbert here. Here are some common questions asked by AD Administrators:

- Why has my AD database size increased by 500MB in the last three weeks?
- I see lots of AD replication in Domain Controller monitoring. What are all these changes?

Both symptoms can be severe enough to impair the operations of your AD forest. Here are examples of past occurrences that we tracked down:

312403  Distributed Link Tracking on Windows-based domain controllers
http://support.microsoft.com/default.aspx?scid=kb;EN-US;312403

318774  Removing duplicate and unwanted proxy addresses in Exchange
http://support.microsoft.com/default.aspx?scid=kb;EN-US;318774

940262  The Active Directory database size increases unexpectedly because a Windows Server 2003-based DNS server inappropriately creates several SerialNo objects
http://support.microsoft.com/default.aspx?scid=kb;EN-US;940262

In order to find the cause for the problems, you should find what has changed in the AD database recently. Now Active Directory assigns an "Update Sequence Number" (USN) to each change. These USNs are 64 Bit Integers and are specific to a Domain Controller. The DC GUID and USN together uniquely identify a database change. A USN is both assigned to originating changes and replicated changes. So even for read-only GC content, you see local USNs getting written.

You can use these USNs to identify recent changes in the database of each DC. Each AD Server (includes AD/AM and LDS) has an attribute named “highestCommittedUSN” on its RootDSE object. Here’s an example output from LDP:

...
12> supportedLDAPPolicies: MaxPoolThreads; MaxDatagramRecv; MaxReceiveBuffer; InitRecvTimeout; MaxConnections; MaxConnIdleTime; MaxPageSize; MaxQueryDuration; MaxTempTableSize; MaxResultSetSize; MaxNotificationPerConn; MaxValRange;
1> highestCommittedUSN: 175389104;
4> supportedSASLMechanisms: GSSAPI; GSS-SPNEGO; EXTERNAL; DIGEST-MD5;
...

Based on this number, you can query for the most recently changed Objects using an LDAP query. As an example, I’m using LDIFDE and I’m subtracting 10000 from the “highestCommittedUSN” value seen on RootDSE:

Ldifde /d dc=contoso,dc=com /s contoso-DC1 /r "(usnchanged>=175379104)" /f domain-NC-last-10000-080919.txt

This file now contains the names of the objects that were changed or created recently. The object names give you a hint as to what area of AD you need to look at, but it may not be enough of a clue yet. For users, you can use attributes that tell you about recent changes:

Pwdlastset
Lastlogontimestamp

e.g. pwdLastSet: 129333360374989750

The attributes have a 64 bit time format. You can convert them to readable timestamps using:

C:\> w32tm /ntte 129333360374989750
149691 09:20:37.4989750 - 04.11.2010 10:20:37

You can then grep the LDIF export based on this knowledge about this time stamp, e.g.:

C:\>w32tm /ntte 129333000000000000
149690 23:20:00.0000000 - 04.11.2010 00:20:00

Command would be something like:

Ldifde /c:" pwdlastset: 129333" domain-NC-last-10000-080919.txt | wc

This would print the list of users and computers who changed their password in the last ten hours. In most cases, these should all considered false positives.

If they are not all new objects (very recent whenCreated attribute), you may want to look at what attributes have been changed. Also, you want to know from which DC the object change is originating.

Maybe the DC that writes all the changes is the primary DC your provisioning system is working against, or it’s a DC you don’t expect to see. To get this information, retrieve the object meta-data using:

repadmin /showobjmeta <DC name> <Object-DN>

The output looks like this:

Loc.USN         Originating DC   Org.USN  Org.Time/Date        Ver Attribute
=======     =============== ========= =============       
...
175389437     HQ\contoso-DC1   175389437 2008-09-16 18:12:46    2 name
...

The leftmost column is the local USN; the more interesting fields are to the right, where you see the originating DC information and change time-stamp, attribute version and name. If the version is really high, it could mean excessive updates to this attribute which deserves more investigation.

You should also look out for changes seen for linked attributes (Windows Server 2003 Forest Mode and higher):

Type    Attribute     Last Mod Time                    Originating DC  Loc.USN   Org.USN        Ver   Distinguished Name
============================================================================
ABSENT  member 2008-09-19 15:14:01       HQ\contoso-DC1 175384020 175384020   2    CN=test-user1,OU=Test-OU,DC=contoso,DC=com
PRESENT member 2008-09-16 18:22:29       HQ\contoso-DC1 175379684 175379684   1   CN=test-user2,OU=Test-OU,DC=contoso,DC=com

Note: High values for USNs will distort the table view.

Many “ABSENT” and high version numbers indicate high activity with linked values. “ABSENT” indicates a deleted link, so you can think of it as a value tombstone. It’s treated just like an object tombstone in the database. During replication it means that the value is deleted from the attribute, in this case a group membership.

Attributes that can contain lots of data deserve special attention. This often applies to attributes containing binary values, including the security descriptor for AD or Exchange, or attributes containing certificates. Note that by default, LDIFDE does not dump “ntSecurityDescriptor”. If any of these attributes show high version numbers or a recent update time stamp on many objects, you should investigate further. It will depend on the attribute on how you investigate the changes, for example for “ntSecurityDescriptor” you can dump it using DSACLS and check out any excess Access Control Entries.

Excessive changes to “ntSecurityDescriptor” are not so much a problem regarding database size because there is single instance storage for these since Windows Server 2003. But they can take lots of replication bandwidth.

The information on objects, attributes and originating DC you collected so far should give you good hints regarding the originator of the changes. If it’s not clear yet, you can enable auditing on successful changes to these attributes to find out the process that is making these changes. It may be necessary to make the attribute viewable in ACL Editor so you can define auditing for it. See the guide in:

296490  How to modify the filtered properties of an object
http://support.microsoft.com/default.aspx?scid=kb;EN-US;296490

But what if there is no pattern evolving while you get the data?

One approach is to repeat the LDIFDE export and reduce the window until you see a pattern. Maybe the problematic changes only happen at certain times of the day, so it would also play a role when you create the export. Or the changes happen on a branch office that only replicates at a certain time of day.

But there are also more naming contexts that may have excessive changes, such as Configuration or the DNS partitions ForestDnsZones and DomainDnsZones, and on GCs. Hopefully, the admins of the other domains are already aware of the excessive changes. This is how you search the whole of the GC data:

Ldifde /d "" /s contoso-DC1 /t 3268 /r "(usnchanged>=175379104)" /f GC-last-10000-080919.txt

Hint: Keep in mind that this query only shows changes for attributes that are present in the GC.

And finally, the problem may not be with existing objects that are changed, but with objects that are deleted and re-created all the time. Deleted objects still take database space for the tombstone, and the new objects cause replication traffic. LDIFDE can include deleted objects in the query when you pass the “/x” option:

Ldifde /d dc=contoso,dc=com /s contoso-DC1 /x /r "(usnchanged>=175379104)" /f domain-NC-last-10000-deleted-080919.txt

If the combined size of the tombstones is a problem, you have to wait until the garbage collection is done before you can reduce the size of the database file using an offline defragmentation. We advise against shortening Tombstone Lifetime for the sole purpose of kicking out these objects earlier. When you have strict replication enabled and replication quarantine is enforced, this shortening TSL to a few days can have a drastic impact on the availability of your Active Directory.

I hope you’re having fun investigating all your ongoing AD changes. I think you’re up to a few interesting findings.

- Herbert Mauerer

Oxymoron - a figure of speech by which a locution produces an incongruous, seemingly self-contradictory effect, as in “cruel kindness” or “succeeded with errors.”

Hi, Ken here. Recently I encountered an issue where the customer was trying to install certificate services on Windows Server 2008. They installed the Active Directory Certificate Services role using Server Manager. When the install completed they received the error “Installation succeeded with errors.” Sometimes “completed with errors” isn’t a big deal, but in this case it was really just “failed.”

So first off, let’s take a look in the Event Log to see if anything more informative than “Succeeded with Errors” has been recorded. In the event log I saw the following events:

Log Name: Application
Source: Microsoft-Windows-CertificationAuthority
Date: 6/25/2008 11:06:09 AM
Event ID: 5
Task Category: None
Level: Error
Keywords: Classic
User: SYSTEM
Computer: con-root-ca.contoso.com

Description:
Active Directory Certificate Services could not find required registry information.
The Active Directory Certificate Services may need to be reinstalled.
Log Name: System
Source: Service Control Manager
Date: 6/25/2008 11:50:57 AM
Event ID: 7023
Task Category: None
Level: Error
Keywords: Classic
User: N/A
Computer: con-root-ca.contoso.com
Description:
The Active Directory Certificate Services service terminated with the following
error:
Cannot complete this function.
Log Name: System
Source: Microsoft-Windows-DistributedCOM
Date: 6/25/2008 11:41:13 AM
Event ID: 10016
Task Category: None
Level: Error
Keywords: Classic
User: CONTOSO\testuser
Computer: con-root-ca.contoso.com
Description:
The application-specific permission settings do not grant Local Launch permission
for the COM Server application with CLSID
{D99E6E73-FC88-11D0-B498-00A0C90312F3}
to the user DOMAIN\username SID (SID Value) from address LocalHost (Using LRPC).
This security permission can be modified using the Component Services
administrative tool.

So, from the event logs, we see some pretty serious issues. Certificate Services cannot find required registry information, and is causing the service to not start. When we try to start the service manually, we get the following error:

Cannot complete this function 0x3eb (win32:1003)

That’s a nice error, but it doesn’t tell us anything new. The other event referenced the registry, so, let’s go take a look in there. The keys for the Certificate Authority are located in the following location:

HKLM\SYSTEM\CurrentControlSet\Services\CertSvc\Configuration\<CA Name>

In the registry we see that the “Setupstatus” value is set to “0xc-“. This is not correct, if the installation was really successful, it should be set to “1”. We also see that the “Security” value is missing completely. The security value is a default binary value that is stamped in the registry during the Certificate Authority installation.

Setupstatus = 0xc –
Security=?? – This value was missing completely

So now we know that the installation not only had errors, but actually did not complete. So, I then moved over to the Server Manager log, to see what it had to say. The Server Manager log contains details about operations performed by the Server Manager. The log can be found in %SystemRoot%\logs\ServerManager.log.

In the ServerManager.log, I saw the following:

2124: 2008-07-01 14:05:50.494 [Provider] Error (Id=0) System.UnauthorizedAccessException: Access is denied. (Exception from HRESULT: 0x80070005 (E_ACCESSDENIED)) at Microsoft.CertificateServices.Setup.Interop.CCertSrvSetupClass.Install()
at Microsoft.Windows.ServerManager.CertificateServer.CertificateServerRoleProvider.Configure(Object clientContext, String hostComputerName, XDocument guest, String guestIdentity)

So, in the Servermanager.log, we see a great big “Access is Denied”. That’s something I can understand, but it doesn’t tell us what it is trying to access. Well, we were installing Certificate Services, so I then moved over to the Certificate Services setup log. The setup log is helpful for troubleshooting in the event of errors. The setup log is located in %Systemroot%\CertOCM.log.

In the CertOCM.log, I saw the following:

109.2552.443: Install Server: Access is denied. 0x80070005 (WIN32: 5)0.0.965: Message Box: EmergencyMessageBox: Fatal: 0x80004003 MsgId: 0x : Access is denied. 0x80070005 (WIN32: 5)
114.5848.949: End: CCertSrvSetup::Install: Access is denied. 0x80070005 (WIN32: 5)

So in the CertOCM.log, I see another “Access is Denied”. This is still not specific enough to determine the issue. I know that during the installation, we look in the Active Directory to load the templates. So I then moved over to the CertEnroll.log to see what we have in there. When an enrollment attempt is made, the information is recorded in the %Systemroot%\CertEnroll.log.

In the CertEnroll.log, I saw the following error for all of the templates. Here is one of the entries I see, this one for the SmartcardLogon template:

808.4098.0: 0x32 (WIN32: 50)
808.4131.0: 0x32 (WIN32: 50)
429.2157.0: 0x32 (WIN32: 50): 00002098: SecErr: DSID-03150E8A, problem 4003
(INSUFF_ACCESS_RIGHTS), data 0
808.4138.0: 0x32 (WIN32: 50)
808.7585.0: 0x80072098 (WIN32: 8344): SmartcardLogon

I also saw the following error in the Certenroll.log:

202.5252.0: 0x80090016 (-214689380): Exception at
d:\rtm\ds\security\services\ca\fs\crypto\capicryptofactory.cpp(501):
CryptAcquireContext( &hProv, pszContainer, pszProvider, nProviderType, fAcquire)
HRESULT = 0x80090016

So this is something good. I was already sure that there is a permissions issue, but now we are seeing specifically, “INSUFF_ACCESS_RIGHTS”, when accessing the Certificate Templates in the Active Directory. So I then moved over to the AD, to see what kind of permissions we had on the templates. I did the following to check the permissions:

1. Using Adsiedit, I looked at the permissions on the templates under cn=public key services,cn=services,cn=configuration,dc=< Forest Root Domain>. The Enterprise Administrators group should have had Full Control on all of the certificate templates.

2. I also checked permissions for all the sub containers underneath Public Key Services. The account installing the CA should have had permissions. For example, Certificate Templates, OID, KRA containers.

Note: By default only the Enterprise Admins and the Domain Admins groups in the Forest Root Domain have enough permission to install and configure an Enterprise Certification Authority. If you have modified permissions, you may not have given yourself enough permission to do the install.

In this case, the permissions for Enterprise Administrators were set to Read-Only, or had been removed completely on some of the objects. Once we restored the Enterprise Admins back to the correct permissions, we were able to successfully install the Certificate Authority using the Microsoft CSP…and all was right in the World. :-)

Finally, here are a couple of links to some great information. The first is a Step by Step, complete with requirements and a lab setup to play with. The second is the Active Directory Certificate Services Portal site, loads of PKI goodness.

Windows Server Active Directory Certificate Services Step-by-Step Guide http://technet.microsoft.com/en-us/library/cc772393.aspx
Active Directory Certificate Services
http://technet.microsoft.com/en-us/library/cc534992.aspx

- Ken “The Beard” McMahan

Ned here again. Despite the title, today’s post is not about Australopithecus. I recently spent a few days in Redmond teaching part of the Microsoft Certified Master course. During the class… eh wait…

You’ve never heard of MCM? You should definitely check it out if you’re looking to take your career to the next level, and if you like really, really hard final exams.

Ok, back on track. During the class breaks one of the students asked an interesting question: “Why does the DFS client not return a complete list of DFS links in a referral request?”

If you’ve never looked at a very large DFS Namespace link referral list before, you might not have noticed this either. For most companies, there’s only one really big list – SYSVOL. As you know, the Domain System Volume (SYSVOL) share is actually a special-cased DFS link that only runs on domain controllers and doesn’t require any special set up other than DCPROMO to configure. So let’s consider the following:

Here I run DSQUERY on a Vista SP1 client with RSAT installed to list out all the DC’s in the domain:

For those that don’t feel like counting, that’s 45 DC’s in this domain. So then I run the DFSUTIL command to list out the link targets in this SYSVOL link:

So I have 45 DC’s, but I only see 29 DC link targets here. That’s weird. Maybe it’s just DFSUTIL. Let’s get a third opinion from a network trace like a good engineer always does:

Here’s the referral request packet from the client:

And here’s the response packet from the DC (i.e. the DFS root namespace server):

Note how the DC has returned 29 servers as well, so there was nothing wrong with DFSUTIL. The network trace shows how the referral indexes match up perfectly with what DFSUTIL shows, and the Index:1 value matches the position 0 in the DFS referral list we saw earlier. 29 is too weird of a number to be hard coded; developers like binary multiples. So what gives?

After source code review and a confirmation chat with the (awesome) lead developer for DFSN, I had my answer: This is expected, by design behavior. A Windows client will only request a 4 kilobyte buffer of links from the Namespace Root server. The 29 link list is not a hard-coded limit, but just happens to be how many links here in this domain will fit in a 4K referral request buffer used by the client. If the link paths were shorter then more would fit (and mine are pretty long here compared to most domains).

This buffer is used for performance reasons - not memory performance, but failover time performance. Since DFS lists are serialized and each server must be tried if the preceding server is unavailable, it was decided many years ago that only 4K would be allocated. Assuming a failover time of ~20 seconds (including retries) per link target, having an extremely long list of links would make the user experience very poor if the client had to fall through 500 servers and fail just because there was a temporary network issue on the client. If this many links are unavailable, it's highly likely that the network for this client is having catastrophic issues and even if a complete referral list was provided it is unlikely the link target requests would be fulfilled. And since until now this was never even documented, it seems like the decision worked out fine. :-)

For the curious:

1) No, this 4K buffer is not configurable.

2) The SPC referral buffer is 56K, so it's unlikely that it will ever be filled in all but the most gigantic forests. We’ve never heard of it happening in 10 years of AD, at least.

And to that student and his excellent question – Viele Grüße!

- Ned ‘N+1’ Pyle

New KB articles related to Directory Services for the week of 3/1-3/7.

Hi, it's Adam Conkle again from the Directory Services team. Today's posting covers how to correctly disable Offline Files in Windows Vista. I recently had a case where the customer was experiencing undesirable behavior with a file share only when the file server was accessed from their Windows Vista machines.

The symptoms were:

1. Files saved to the file share from the Vista machines will not update the file on the file server, yet the changes appear when accessed on the Vista machine.

2. Files and folders that have been deleted from the file server continue to appear when the file share is accessed from the Vista machines. The files and folders cannot be deleted from the Vista machines because the files do not exist.

The customer advised that they had chosen to disable Offline Files on all of their Vista machines. I looked at Control Panel and Offline Files was set to Disabled. I then looked at Services.msc and the Offline Files service was disabled. Looks good, right?

Next, I decided it would be a good idea to get a Process Monitor capture while we reproduce the above symptoms. Analysis of the capture showed me that Explorer.exe was not accessing the UNC path as expected, but rather was accessing C:\Windows\CSC\<namespace_path_for_share>. That's odd. You're probably thinking: "Why is Explorer.exe trying to access the Client Side Caching database when Offline Files has been disabled?"

That is a great question, and here is the answer:

Client Side Caching has a kernel driver that is loaded at startup when Offline Files is enabled. You can check the status of the driver by opening System Information (Start > Run > msinfo32 > System Summary > Software Environment > System Drivers). In the name column you will find "csc" with a description of "Offline Files Driver". When Offline Files is truly disabled, the Start Mode column should be set to "Disabled"; otherwise it will be set to "System" which means it is loaded at system startup.

In my case, the customer's driver was set to "System" even though the Offline Files GUI and the Offline Files service were both disabled. Offline Files on her Vista machines was in a halfway enabled state. No synchronization with the file server was taking place, but Explorer.exe was still directed to look at the CSC database because the kernel driver was loaded.

When the customer disabled Offline Files on the Vista machines, she manually disabled the Offline Files service on each machine, and she never made any change to the Offline Files GUI in Control Panel. I found that when you only disable the service, the Offline Files GUI does get updated and shows "Disabled", but it leaves the kernel driver startup mode set to "System". If you disable Offline Files via the Control Panel GUI, the service is disabled and the kernel driver is disabled as well. When Offline Files is disabled via the Control Panel GUI, you will be prompted to reboot the machine for this to take effect (so that the kernel driver can be unloaded).

The supported way to disable Offline Files is to use the Offline Files GUI in Control Panel, Group Policy, or WMIC.

To enable/disable Offline Files via Group Policy:

This is a Computer Configuration setting under Administrative Templates\Network\Offline Files named "Allow of Disallow use of the Offline Files feature". Once the GPO applies, a reboot is required for the setting to take effect.

To enable/disable Offline Files via WMIC:

We use the Enable method of Win32_OfflineFilesCache to enable or disable offline files. Simply pass the Enable method a Boolean value.

Example command:

As noted in the output, a reboot is required for the new setting to take effect.

If you have gotten your Vista machines into the state described above, enable Offline Files via one of the supported methods described above, reboot, disable Offline Files using a supported method, and then reboot once again.

Thanks,

Adam ‘Axe Body Wash’ Conkle

New KB articles related to Directory Services for the week of 3/7-3/14.