We are starting to get new Mac systems in for desktop replacements at work. In the past these were treated as completely standalone systems. Users had local home directories, and we weren’t even really backing them up due to the complications FileValut presented. I really hope Lion solves this with full disk encryption, but I’ve not even looked into this yet. We need to join the Mac systems to Active Directory to enforce password policies. I also want to have users mount their home directories from our EMC NAS storage.
I quickly ran into an interesting problem joining new Snow Leopard and legacy Leopard Mac systems to our Active Directory. I kept getting an error that indicated the account username and password I used could not join the machine to the AD. Of course, I know that was not the case. I was able to turn on the DirectoryService.debug.log file by sending a USR1 to the DirectoryService process. Sending a USR1 will toggle debug logging, so you can send another USR1 to turn it off again:
sudo killall -USR1 DirectoryService
See the manual page for more, like using USR2 to toggle API logging. There are hexadecimal identifiers for actions in the debug log. Once you find what you are looking for, you can grep on that ID value. This is what I saw happening:
2011-04-25 16:50:08 EDT - T[0xB0185000] - Active Directory: Attempting Add Record......
2011-04-25 16:50:08 EDT - T[0xB0185000] - Active Directory: Adding in OU = CN=Computers,DC=cse,DC=ohio-state,DC=edu
2011-04-25 16:50:08 EDT - T[0xB0185000] - Active Directory: Added record CN=rowland-mac,CN=Computers,DC=cse,DC=ohio-state,DC=edu
2011-04-25 16:50:08 EDT - T[0xB0185000] - Active Directory: Setting Computer Password......
2011-04-25 16:50:08 EDT - T[0xB0185000] - Active Directory: Deleting Record CN=rowland-mac,CN=Computers,DC=cse,DC=ohio-state,DC=edu...
2011-04-25 16:50:08 EDT - T[0xB0185000] - Active Directory: Setting Computer Password FAILED Deleted Record......
Clearly Mac OS X was able to do everything except change the password on the computer account once it had added it to the AD. I fired up Wireshark on my Mac and saw the following packets. The first is the request to change the computer account password using the kpasswd protocol:
No. Time Source Destination Protocol Info
691 3.521763 164.107.120.107 164.107.114.11 KPASSWD Request
Frame 691 (234 bytes on wire, 234 bytes captured)
Arrival Time: Apr 25, 2011 19:38:35.971888000
[Time delta from previous captured frame: 0.000116000 seconds]
[Time delta from previous displayed frame: 0.000116000 seconds]
[Time since reference or first frame: 3.521763000 seconds]
Frame Number: 691
Frame Length: 234 bytes
Capture Length: 234 bytes
[Frame is marked: False]
[Protocols in frame: eth:ip:udp:kpasswd]
[Coloring Rule Name: UDP]
[Coloring Rule String: udp]
Ethernet II, Src: Apple_b3:4d:49 (00:1b:63:b3:4d:49), Dst: 00:23:9c:46:f2:00 (00:23:9c:46:f2:00)
Destination: 00:23:9c:46:f2:00 (00:23:9c:46:f2:00)
Address: 00:23:9c:46:f2:00 (00:23:9c:46:f2:00)
.... ...0 .... .... .... .... = IG bit: Individual address (unicast)
.... ..0. .... .... .... .... = LG bit: Globally unique address (factory default)
Source: Apple_b3:4d:49 (00:1b:63:b3:4d:49)
Address: Apple_b3:4d:49 (00:1b:63:b3:4d:49)
.... ...0 .... .... .... .... = IG bit: Individual address (unicast)
.... ..0. .... .... .... .... = LG bit: Globally unique address (factory default)
Type: IP (0x0800)
Internet Protocol, Src: 164.107.120.107 (164.107.120.107), Dst: 164.107.114.11 (164.107.114.11)
Version: 4
Header length: 20 bytes
Differentiated Services Field: 0x00 (DSCP 0x00: Default; ECN: 0x00)
0000 00.. = Differentiated Services Codepoint: Default (0x00)
.... ..0. = ECN-Capable Transport (ECT): 0
.... ...0 = ECN-CE: 0
Total Length: 220
Identification: 0x340e (13326)
Flags: 0x00
0... = Reserved bit: Not set
.0.. = Don't fragment: Not set
..0. = More fragments: Not set
Fragment offset: 1480
Time to live: 64
Protocol: UDP (0x11)
Header checksum: 0x11fd [correct]
[Good: True]
[Bad : False]
Source: 164.107.120.107 (164.107.120.107)
Destination: 164.107.114.11 (164.107.114.11)
[IP Fragments (1680 bytes): #690(1480), #691(200)]
[Frame: 690, payload: 0-1479 (1480 bytes)]
[Frame: 691, payload: 1480-1679 (200 bytes)]
User Datagram Protocol, Src Port: 50406 (50406), Dst Port: kpasswd (464)
Source port: 50406 (50406)
Destination port: kpasswd (464)
Length: 1680
Checksum: 0xdfa0 [correct]
[Good Checksum: True]
[Bad Checksum: False]
MS Kpasswd
Message Length: 1672
Version: Request (0xff80)
AP_REQ Length: 1513
AP_REQ
Kerberos AP-REQ
Pvno: 5
MSG Type: AP-REQ (14)
Padding: 0
APOptions: 00000000
.0.. .... .... .... .... .... .... .... = Use Session Key: Do NOT use the session key to encrypt the ticket
..0. .... .... .... .... .... .... .... = Mutual required: Mutual authentication is NOT required
Ticket
Tkt-vno: 5
Realm: CSE.OHIO-STATE.EDU
Server Name (Unknown): kadmin/changepw
Name-type: Unknown (0)
Name: kadmin
Name: changepw
enc-part aes256-cts-hmac-sha1-96
Encryption type: aes256-cts-hmac-sha1-96 (18)
Kvno: 100003
enc-part: AFF4597D76A9DED1446C2E9B1672DD931C8F3DFA2D33F1BE...
Authenticator aes256-cts-hmac-sha1-96
Encryption type: aes256-cts-hmac-sha1-96 (18)
Authenticator data: 215C9C1108143CB84F138E2B522599B6F2AC87B6BBBEA6CA...
KRB-PRIV
Kerberos
PRIV_BODY KRB-PRIV
Pvno: 5
MSG Type: KRB-PRIV (21)
enc PRIV: 308183A003020112A27C047A88FB8B24C0A5901A14681E86... aes256-cts-hmac-sha1-96
Encryption type: aes256-cts-hmac-sha1-96 (18)
Encrypted PRIV
The very next frame contains a KRB5KDC_ERR_S_PRINCIPAL_UNKNOWN error response:
No. Time Source Destination Protocol Info
692 3.522243 164.107.114.11 164.107.120.107 KPASSWD KRB Error: KRB5KDC_ERR_S_PRINCIPAL_UNKNOWN
Frame 692 (146 bytes on wire, 146 bytes captured)
Arrival Time: Apr 25, 2011 19:38:35.972368000
[Time delta from previous captured frame: 0.000480000 seconds]
[Time delta from previous displayed frame: 0.000480000 seconds]
[Time since reference or first frame: 3.522243000 seconds]
Frame Number: 692
Frame Length: 146 bytes
Capture Length: 146 bytes
[Frame is marked: False]
[Protocols in frame: eth:ip:udp:kpasswd]
[Coloring Rule Name: UDP]
[Coloring Rule String: udp]
Ethernet II, Src: 00:23:9c:46:f2:00 (00:23:9c:46:f2:00), Dst: Apple_b3:4d:49 (00:1b:63:b3:4d:49)
Destination: Apple_b3:4d:49 (00:1b:63:b3:4d:49)
Address: Apple_b3:4d:49 (00:1b:63:b3:4d:49)
.... ...0 .... .... .... .... = IG bit: Individual address (unicast)
.... ..0. .... .... .... .... = LG bit: Globally unique address (factory default)
Source: 00:23:9c:46:f2:00 (00:23:9c:46:f2:00)
Address: 00:23:9c:46:f2:00 (00:23:9c:46:f2:00)
.... ...0 .... .... .... .... = IG bit: Individual address (unicast)
.... ..0. .... .... .... .... = LG bit: Globally unique address (factory default)
Type: IP (0x0800)
Internet Protocol, Src: 164.107.114.11 (164.107.114.11), Dst: 164.107.120.107 (164.107.120.107)
Version: 4
Header length: 20 bytes
Differentiated Services Field: 0x00 (DSCP 0x00: Default; ECN: 0x00)
0000 00.. = Differentiated Services Codepoint: Default (0x00)
.... ..0. = ECN-Capable Transport (ECT): 0
.... ...0 = ECN-CE: 0
Total Length: 132
Identification: 0x3a83 (14979)
Flags: 0x04 (Don't Fragment)
0... = Reserved bit: Not set
.1.. = Don't fragment: Set
..0. = More fragments: Not set
Fragment offset: 0
Time to live: 127
Protocol: UDP (0x11)
Header checksum: 0x8d98 [correct]
[Good: True]
[Bad : False]
Source: 164.107.114.11 (164.107.114.11)
Destination: 164.107.120.107 (164.107.120.107)
User Datagram Protocol, Src Port: kpasswd (464), Dst Port: 50406 (50406)
Source port: kpasswd (464)
Destination port: 50406 (50406)
Length: 112
Checksum: 0xce60 [correct]
[Good Checksum: True]
[Bad Checksum: False]
Kerberos KRB-ERROR
Pvno: 5
MSG Type: KRB-ERROR (30)
stime: 2011-04-25 23:38:35 (UTC)
susec: 798969
error_code: KRB5KDC_ERR_S_PRINCIPAL_UNKNOWN (7)
Realm: CSE.OHIO-STATE.EDU
Server Name (Service and Instance): kadmin/changepw
Name-type: Service and Instance (2)
Name: kadmin
Name: changepw
e-data
This got me thinking. I did some searching and found a post outlining a similar issue and another one from NetApp on TechNet outlining the same type of problem. Both reference this hotfix to solve the problem. I checked using repadmin.exe to see if we had done an authoritative restore that affected the krbtgt user, and sure enough the version numbers were higher than 100,000. The version numbers were much lower on our research domain controller, and I was able to join there.
I duplicated this in a Windows Server 2008 VM I have at home. The version numbers on the krbtgt user AD attributes matched our research domain controller before doing the authoritative restore:
C:\Users\Administrator>repadmin.exe /showobjmeta vmware-win2008 cn=krbtgt,cn=users,dc=vmware,dc=local
35 entries.
Loc.USN Originating DSA Org.USN Org.Time/Date
Ver Attribute
======= =============== ========= =============
=== =========
12321 Default-First-Site-Name\VMWARE-WIN2008 12321 2009-02-01 23:09:06
1 objectClass
12321 Default-First-Site-Name\VMWARE-WIN2008 12321 2009-02-01 23:09:06
1 cn
12326 Default-First-Site-Name\VMWARE-WIN2008 12326 2009-02-01 23:09:06
2 description
12321 Default-First-Site-Name\VMWARE-WIN2008 12321 2009-02-01 23:09:06
1 instanceType
12321 Default-First-Site-Name\VMWARE-WIN2008 12321 2009-02-01 23:09:06
1 whenCreated
12322 Default-First-Site-Name\VMWARE-WIN2008 12322 2009-02-01 23:09:06
1 displayName
12321 Default-First-Site-Name\VMWARE-WIN2008 12321 2009-02-01 23:09:06
1 showInAdvancedViewOnly
16680 Default-First-Site-Name\VMWARE-WIN2008 16680 2009-02-01 23:30:09
2 nTSecurityDescriptor
12321 Default-First-Site-Name\VMWARE-WIN2008 12321 2009-02-01 23:09:06
1 name
12323 Default-First-Site-Name\VMWARE-WIN2008 12323 2009-02-01 23:09:06
3 userAccountControl
12322 Default-First-Site-Name\VMWARE-WIN2008 12322 2009-02-01 23:09:06
1 codePage
12322 Default-First-Site-Name\VMWARE-WIN2008 12322 2009-02-01 23:09:06
1 countryCode
12322 Default-First-Site-Name\VMWARE-WIN2008 12322 2009-02-01 23:09:06
1 homeDirectory
12322 Default-First-Site-Name\VMWARE-WIN2008 12322 2009-02-01 23:09:06
1 homeDrive
12324 Default-First-Site-Name\VMWARE-WIN2008 12324 2009-02-01 23:09:06
2 dBCSPwd
12322 Default-First-Site-Name\VMWARE-WIN2008 12322 2009-02-01 23:09:06
1 scriptPath
12322 Default-First-Site-Name\VMWARE-WIN2008 12322 2009-02-01 23:09:06
1 logonHours
12322 Default-First-Site-Name\VMWARE-WIN2008 12322 2009-02-01 23:09:06
1 userWorkstations
12324 Default-First-Site-Name\VMWARE-WIN2008 12324 2009-02-01 23:09:06
2 unicodePwd
12324 Default-First-Site-Name\VMWARE-WIN2008 12324 2009-02-01 23:09:06
2 ntPwdHistory
12324 Default-First-Site-Name\VMWARE-WIN2008 12324 2009-02-01 23:09:06
2 pwdLastSet
12322 Default-First-Site-Name\VMWARE-WIN2008 12322 2009-02-01 23:09:06
1 primaryGroupID
12325 Default-First-Site-Name\VMWARE-WIN2008 12325 2009-02-01 23:09:06
1 supplementalCredentials
12322 Default-First-Site-Name\VMWARE-WIN2008 12322 2009-02-01 23:09:06
1 userParameters
12322 Default-First-Site-Name\VMWARE-WIN2008 12322 2009-02-01 23:09:06
1 profilePath
12321 Default-First-Site-Name\VMWARE-WIN2008 12321 2009-02-01 23:09:06
1 objectSid
16680 Default-First-Site-Name\VMWARE-WIN2008 16680 2009-02-01 23:30:09
1 adminCount
12322 Default-First-Site-Name\VMWARE-WIN2008 12322 2009-02-01 23:09:06
1 comment
12322 Default-First-Site-Name\VMWARE-WIN2008 12322 2009-02-01 23:09:06
1 accountExpires
12324 Default-First-Site-Name\VMWARE-WIN2008 12324 2009-02-01 23:09:06
2 lmPwdHistory
12321 Default-First-Site-Name\VMWARE-WIN2008 12321 2009-02-01 23:09:06
1 sAMAccountName
12321 Default-First-Site-Name\VMWARE-WIN2008 12321 2009-02-01 23:09:06
1 sAMAccountType
12446 Default-First-Site-Name\VMWARE-WIN2008 12446 2009-02-01 23:09:21
1 servicePrincipalName
12321 Default-First-Site-Name\VMWARE-WIN2008 12321 2009-02-01 23:09:06
1 objectCategory
12321 Default-First-Site-Name\VMWARE-WIN2008 12321 2009-02-01 23:09:06
1 isCriticalSystemObject
0 entries.
Type Attribute Last Mod Time Originating DSA
Loc.USN Org.USN Ver
======= ============ ============= =================
======= ======= ===
Distinguished Name
=============================
Next I did an authoritative restore:
C:\Users\Administrator>net stop ntds
<snip>
C:\Users\Administrator>ntdsutil
ntdsutil: activate instance NTDS
Active instance set to "NTDS".
ntdsutil: authoritative restore
authoritative restore: restore subtree cn=Users,dc=vmware,dc=local
Opening DIT database... Done.
The current time is 04-26-11 00:10.12.
Most recent database update occured at 04-26-11 00:07.10.
Increasing attribute version numbers by 100000.
Counting records that need updating...
Records found: 0000000051
Done.
Found 51 records to update.
Updating records...
Records remaining: 0000000000
Done.
Successfully updated 51 records.
The following text file with a list of authoritatively restored objects has been
created in the current working directory:
ar_20110426-001012_objects.txt
One or more specified objects have back-links in this domain. The following LDIF
files with link restore operations have been created in the current working dir
ectory:
ar_20110426-001012_links_vmware.local.ldf
Authoritative Restore completed successfully.
authoritative restore: quit
ntdsutil: quit
C:\Users\Administrator>net start ntds
<snip>
I checked the version numbers again, and now they matched our production AD at work:
C:\Users\Administrator>repadmin.exe /showobjmeta vmware-win2008 cn=krbtgt,cn=users,dc=vmware,dc=local
36 entries.
Loc.USN Originating DSA Org.USN Org.Time/Date
Ver Attribute
======= =============== ========= =============
=== =========
819244 Default-First-Site-Name\VMWARE-WIN2008 819244 2011-04-26 00:10:121
00001 objectClass
819244 Default-First-Site-Name\VMWARE-WIN2008 819244 2011-04-26 00:10:121
00001 cn
819244 Default-First-Site-Name\VMWARE-WIN2008 819244 2011-04-26 00:10:121
00002 description
819244 Default-First-Site-Name\VMWARE-WIN2008 819244 2011-04-26 00:10:121
00001 instanceType
12321 e470cfbf-a782-40ab-badb-314e2760696d 12321 2009-02-01 23:09:06
1 whenCreated
819244 Default-First-Site-Name\VMWARE-WIN2008 819244 2011-04-26 00:10:121
00001 displayName
819244 Default-First-Site-Name\VMWARE-WIN2008 819244 2011-04-26 00:10:121
00000 isDeleted
819244 Default-First-Site-Name\VMWARE-WIN2008 819244 2011-04-26 00:10:121
00001 showInAdvancedViewOnly
819244 Default-First-Site-Name\VMWARE-WIN2008 819244 2011-04-26 00:10:121
00002 nTSecurityDescriptor
819244 Default-First-Site-Name\VMWARE-WIN2008 819244 2011-04-26 00:10:121
00001 name
819244 Default-First-Site-Name\VMWARE-WIN2008 819244 2011-04-26 00:10:121
00003 userAccountControl
819244 Default-First-Site-Name\VMWARE-WIN2008 819244 2011-04-26 00:10:121
00001 codePage
819244 Default-First-Site-Name\VMWARE-WIN2008 819244 2011-04-26 00:10:121
00001 countryCode
819244 Default-First-Site-Name\VMWARE-WIN2008 819244 2011-04-26 00:10:121
00001 homeDirectory
819244 Default-First-Site-Name\VMWARE-WIN2008 819244 2011-04-26 00:10:121
00001 homeDrive
819244 Default-First-Site-Name\VMWARE-WIN2008 819244 2011-04-26 00:10:121
00002 dBCSPwd
819244 Default-First-Site-Name\VMWARE-WIN2008 819244 2011-04-26 00:10:121
00001 scriptPath
819244 Default-First-Site-Name\VMWARE-WIN2008 819244 2011-04-26 00:10:121
00001 logonHours
819244 Default-First-Site-Name\VMWARE-WIN2008 819244 2011-04-26 00:10:121
00001 userWorkstations
819244 Default-First-Site-Name\VMWARE-WIN2008 819244 2011-04-26 00:10:121
00002 unicodePwd
819244 Default-First-Site-Name\VMWARE-WIN2008 819244 2011-04-26 00:10:121
00002 ntPwdHistory
819244 Default-First-Site-Name\VMWARE-WIN2008 819244 2011-04-26 00:10:121
00002 pwdLastSet
819244 Default-First-Site-Name\VMWARE-WIN2008 819244 2011-04-26 00:10:121
00001 primaryGroupID
819244 Default-First-Site-Name\VMWARE-WIN2008 819244 2011-04-26 00:10:121
00001 supplementalCredentials
819244 Default-First-Site-Name\VMWARE-WIN2008 819244 2011-04-26 00:10:121
00001 userParameters
819244 Default-First-Site-Name\VMWARE-WIN2008 819244 2011-04-26 00:10:121
00001 profilePath
819244 Default-First-Site-Name\VMWARE-WIN2008 819244 2011-04-26 00:10:121
00001 objectSid
819244 Default-First-Site-Name\VMWARE-WIN2008 819244 2011-04-26 00:10:121
00001 adminCount
819244 Default-First-Site-Name\VMWARE-WIN2008 819244 2011-04-26 00:10:121
00001 comment
819244 Default-First-Site-Name\VMWARE-WIN2008 819244 2011-04-26 00:10:121
00001 accountExpires
819244 Default-First-Site-Name\VMWARE-WIN2008 819244 2011-04-26 00:10:121
00002 lmPwdHistory
819244 Default-First-Site-Name\VMWARE-WIN2008 819244 2011-04-26 00:10:121
00001 sAMAccountName
819244 Default-First-Site-Name\VMWARE-WIN2008 819244 2011-04-26 00:10:121
00001 sAMAccountType
819244 Default-First-Site-Name\VMWARE-WIN2008 819244 2011-04-26 00:10:121
00001 servicePrincipalName
819244 Default-First-Site-Name\VMWARE-WIN2008 819244 2011-04-26 00:10:121
00001 objectCategory
819244 Default-First-Site-Name\VMWARE-WIN2008 819244 2011-04-26 00:10:121
00001 isCriticalSystemObject
0 entries.
Type Attribute Last Mod Time Originating DSA
Loc.USN Org.USN Ver
======= ============ ============= =================
======= ======= ===
Distinguished Name
=============================
It is hard to tell due to the wrapping, but the first digit is right up against the end of the date (the final digit on each line is the first of the version number in most cases). I was able to hack up the DNS on my Mac OS X Server VM enough so that it could attempt to join my test AD VM (at the expense of it not working when running Server Manager though). I was able to join before the authoritative restore, but not after. I installed the hotfix, and it was all working again. I did a snapshot before starting in both cases.
This was a weird problem that was hard to figure out. Searching online reveals a lot of problems that have to do with standard “using the wrong account” or “DNS is not configured properly” issues. It was only after having dug deeper and finding the specific sequence of events from the DirectoryService debug log and Wireshark packet inspection that I was able to narrow down the search to find the hotfix. So, if you can’t join your Mac to your AD, it’s possible this is the issue. Even though this was a big problem for about a day, it was an interesting problem to solve.