Mac OS X 10.6.6 Active Directory Login issues

A while after updating all the Apple Suites to 10.6.6 I started getting a few Apple Macs which would not let anybody log in. I had a look at the system log and found this:


07/03/2012 15:44:22    kernel    Ethernet [AppleBCM5701Ethernet]: Link up on en0, 100-Megabit, Full-duplex, No flow-control, Debug [796d,0300,0de1,0300,41e1,0000]
07/03/2012 15:44:25    configd[13]    setting hostname to "n240-11904.local"
07/03/2012 15:44:25    configd[13]    network configuration changed.
07/03/2012 15:44:26    configd[13]    network configuration changed.
07/03/2012 15:44:26    configd[13]    setting hostname to "n240-11904.ictservicestest.somewhere.ac.uk"
07/03/2012 15:44:27    com.apple.DirectoryServices[15]    Enter machine password:
07/03/2012 15:44:28    com.apple.DirectoryServices[15]    [2012/03/07 15:44:28, 0, pid=466] /SourceCache/samba/samba-235.5/samba/source/libads/kerberos.c:ads_kinit_password(228)
07/03/2012 15:44:28    com.apple.DirectoryServices[15]      kerberos_kinit_password N240-11904$@STUDENTS.somewhere.AC.UK failed: Preauthentication failed
07/03/2012 15:44:28    com.apple.DirectoryServices[15]    [2012/03/07 15:44:28, 0, pid=466] /SourceCache/samba/samba-235.5/samba/source/libads/kerberos.c:ads_kinit_password(228)
07/03/2012 15:44:28    com.apple.DirectoryServices[15]      kerberos_kinit_password N240-11904$@STUDENTS.somewhere.AC.UK failed: Preauthentication failed
07/03/2012 15:44:29    mDNSResponder[31]    RegisterInterface: Frequent transitions for interface en0 (FE80:0000:0000:0000:CA2A:14FF:FE0B:B63D)
07/03/2012 15:44:33    com.apple.DirectoryServices[15]    Enter machine password:
07/03/2012 15:44:33    com.apple.DirectoryServices[15]    [2012/03/07 15:44:33, 0, pid=474] /SourceCache/samba/samba-235.5/samba/source/libads/kerberos.c:ads_kinit_password(228)
07/03/2012 15:44:33    com.apple.DirectoryServices[15]      kerberos_kinit_password N240-11904$@STUDENTS.somewhere.AC.UK failed: Preauthentication failed
07/03/2012 15:44:33    com.apple.DirectoryServices[15]    [2012/03/07 15:44:33, 0, pid=474] /SourceCache/samba/samba-235.5/samba/source/libads/kerberos.c:ads_kinit_password(228)
07/03/2012 15:44:33    com.apple.DirectoryServices[15]      kerberos_kinit_password N240-11904$@STUDENTS.somewhere.AC.UK failed: Preauthentication failed
07/03/2012 15:44:33    com.apple.DirectoryServices[15]    Enter machine password:
07/03/2012 15:44:33    DirectoryService[15]    Failed to changed computer password in Active Directory domain students.somewhere.ac.uk
07/03/2012 15:44:33    com.apple.DirectoryServices[15]    [2012/03/07 15:44:33, 0, pid=479] /SourceCache/samba/samba-235.5/samba/source/libads/kerberos.c:ads_kinit_password(228)
07/03/2012 15:44:33    com.apple.DirectoryServices[15]      kerberos_kinit_password N240-11904$@STUDENTS.somewhere.AC.UK failed: Preauthentication failed
07/03/2012 15:44:34    com.apple.DirectoryServices[15]    [2012/03/07 15:44:34, 0, pid=479] /SourceCache/samba/samba-235.5/samba/source/libads/kerberos.c:ads_kinit_password(228)
07/03/2012 15:44:34    com.apple.DirectoryServices[15]      kerberos_kinit_password N240-11904$@STUDENTS.somewhere.AC.UK failed: Preauthentication failed
07/03/2012 15:44:34    com.apple.DirectoryServices[15]    Enter machine password:
07/03/2012 15:44:34    com.apple.DirectoryServices[15]    [2012/03/07 15:44:34, 0, pid=484] /SourceCache/samba/samba-235.5/samba/source/libads/kerberos.c:ads_kinit_password(228)
07/03/2012 15:44:34    com.apple.DirectoryServices[15]      kerberos_kinit_password N240-11904$@STUDENTS.somewhere.AC.UK failed: Preauthentication failed
07/03/2012 15:44:34    com.apple.DirectoryServices[15]    [2012/03/07 15:44:34, 0, pid=484] /SourceCache/samba/samba-235.5/samba/source/libads/kerberos.c:ads_kinit_password(228)
07/03/2012 15:44:34    com.apple.DirectoryServices[15]      kerberos_kinit_password N240-11904$@STUDENTS.somewhere.AC.UK failed: Preauthentication failed
07/03/2012 15:44:36    ntpd[20]    time reset +0.717779 s
07/03/2012 15:45:01    /System/Library/CoreServices/RemoteManagement/AppleVNCServer.bundle/Contents/MacOS/AppleVNCServer[91]    CGSKeyTranslateInitialize: KLGetCurrentKeyboardLayout or KLGetKeyboardLayoutProperty is not available, fall back to USA keymap
07/03/2012 15:45:09    SecurityAgent[96]    Could not get the user record for '_mac_bind' from Directory Services
07/03/2012 15:45:09    SecurityAgent[96]    User info context values set for _mac_bind
07/03/2012 15:45:09    SecurityAgent[96]    unknown-user (_mac_bind) login attempt PASSED for auditing
07/03/2012 15:45:13    SecurityAgent[96]    Could not get the user record for '_mac_bind' from Directory Services
07/03/2012 15:45:13    SecurityAgent[96]    User info context values set for _mac_bind
07/03/2012 15:45:13    SecurityAgent[96]    unknown-user (_mac_bind) login attempt PASSED for auditing


This is what happened after I woke the machine up and then tried to log in as a user called "_mac_bind". It happens with any Active Directory user.

After trying all the standard things:

1. reset PR-RAM
2. /sbin/fsck -yf
3. unbind and bind again

I finally resorted to re-imaging, which actually fixed the problem, although I am not sure why.

I came back to the problem after finding it happen quite a few times and tried binding it to Active Directory with a different name (although I had my doubts). This fixed the problem.

I conclude to say that there must have been a problem on the server side. Perhaps the mac had been placed in the wrong list. My next thing to try would be to delete any instance of it on the servers and try binding it under it's old name.

After this, I would either assume someone had done something to the instance on the server, or the server had not liked the machine at one point and disallowed it.

.......

Well, I've come back to this some time later. It appears one of the Staff iMacs is now exhibiting the same behavour, but changing its Active Directory bound name does not fix it this time. So, before I re-image hopefully the Network Administrator can have a look. Here's the log for the one exhibiting this behavour:

13/03/2012 09:36:28 SecurityAgent[95] Showing Login Window

13/03/2012 09:36:28 kernel Ethernet [AppleBCM5701Ethernet]: Link up on en0, 100-Megabit, Full-duplex, No flow-control, Debug [796d,2300,0de1,0300,41e1,0000]

13/03/2012 09:36:34 configd[13] network configuration changed.

13/03/2012 09:36:36 configd[13] setting hostname to "n214a-11905.ictservicestest.somewhere.ac.uk"

13/03/2012 09:36:50 com.apple.DirectoryServices[15] Enter machine password: 

13/03/2012 09:36:52 com.apple.DirectoryServices[15] DNS update failed!

13/03/2012 09:36:56 DirectoryService[15] GSSAPI Error: Unspecified GSS failure.  Minor code may provide more information (Cannot find KDC for requested realm)

13/03/2012 09:36:56 DirectoryService[15] GSSAPI Error: Unspecified GSS failure.  Minor code may provide more information (Cannot find KDC for requested realm)

13/03/2012 09:36:57 DirectoryService[15] GSSAPI Error: Unspecified GSS failure.  Minor code may provide more information (Cannot find KDC for requested realm)

13/03/2012 09:36:57 com.apple.DirectoryServices[15] Enter machine password: 

13/03/2012 09:36:58 com.apple.DirectoryServices[15] DNS update failed!

13/03/2012 09:36:58 SecurityAgent[95] Could not get the user record for _mac_bind from DirectoryServices.

13/03/2012 09:36:58 SecurityAgent[95] Will sleep 1 seconds and try again (retryCount = 4)

13/03/2012 09:36:59 SecurityAgent[95] Could not get the user record for _mac_bind from DirectoryServices.

13/03/2012 09:36:59 SecurityAgent[95] Will sleep 2 seconds and try again (retryCount = 3)

13/03/2012 09:37:01 SecurityAgent[95] Could not get the user record for _mac_bind from DirectoryServices.

13/03/2012 09:37:01 SecurityAgent[95] Will sleep 4 seconds and try again (retryCount = 2)

13/03/2012 09:37:05 SecurityAgent[95] Could not get the user record for _mac_bind from DirectoryServices.

13/03/2012 09:37:05 SecurityAgent[95] Will sleep 8 seconds and try again (retryCount = 1)

13/03/2012 09:37:13 SecurityAgent[95] User info context values set for _mac_bind

13/03/2012 09:37:13 SecurityAgent[95] unknown-user (_mac_bind) login attempt PASSED for auditing

13/03/2012 09:37:17 SecurityAgent[95] Could not get the user record for _mac_bind from DirectoryServices.

13/03/2012 09:37:17 SecurityAgent[95] Will sleep 1 seconds and try again (retryCount = 4)

13/03/2012 09:37:18 SecurityAgent[95] Could not get the user record for _mac_bind from DirectoryServices.

13/03/2012 09:37:18 SecurityAgent[95] Will sleep 2 seconds and try again (retryCount = 3)

13/03/2012 09:37:20 SecurityAgent[95] Could not get the user record for _mac_bind from DirectoryServices.

13/03/2012 09:37:20 SecurityAgent[95] Will sleep 4 seconds and try again (retryCount = 2)

13/03/2012 09:37:24 SecurityAgent[95] User info context values set for _mac_bind

13/03/2012 09:37:26 authorizationhost[94] k5_store_ticket_in_cache(): got -1765328243 (Matching credential not found) on /SourceCache/SecurityAgent/SecurityAgent-39574/plugins/krb5/krb5_operations.c:115

13/03/2012 09:37:26 SecurityAgent[95] Login Window Showing Progress

13/03/2012 09:37:26 authorizationhost[94] ERROR | -[HomeDirMounter mountNetworkHomeWithURL:attributes:dirPath:username:] | PremountHomeDirectoryWithAuthentication( url=smb://faraday.students.somewhere.ac.uk/FaradayStudents, homedir=/Network/Servers/faraday.students.somewhere.ac.uk/FaradayStudents/_mac_bind, name=_mac_bind ) returned 45

13/03/2012 09:37:53 DirectoryService[15] GSSAPI Error: Unspecified GSS failure.  Minor code may provide more information (Cannot find KDC for requested realm)

13/03/2012 09:37:53 SecurityAgent[95] Could not get the user record for '_mac_bind' from Directory Services

13/03/2012 09:37:53 SecurityAgent[95] User info context values set for _mac_bind

13/03/2012 09:37:53 SecurityAgent[95] unknown-user (_mac_bind) login attempt PASSED for auditing

13/03/2012 09:38:04 SecurityAgent[95] Could not get the user record for _mac_bind from DirectoryServices.

13/03/2012 09:38:04 SecurityAgent[95] Will sleep 1 seconds and try again (retryCount = 4)

13/03/2012 09:38:05 SecurityAgent[95] Could not get the user record for _mac_bind from DirectoryServices.

13/03/2012 09:38:05 SecurityAgent[95] Will sleep 2 seconds and try again (retryCount = 3)

13/03/2012 09:38:07 SecurityAgent[95] Could not get the user record for _mac_bind from DirectoryServices.

13/03/2012 09:38:07 SecurityAgent[95] Will sleep 4 seconds and try again (retryCount = 2)

13/03/2012 09:38:11 SecurityAgent[95] Could not get the user record for _mac_bind from DirectoryServices.

13/03/2012 09:38:11 SecurityAgent[95] Will sleep 8 seconds and try again (retryCount = 1)

13/03/2012 09:38:19 SecurityAgent[95] User info context values set for _mac_bind

13/03/2012 09:38:19 SecurityAgent[95] unknown-user (_mac_bind) login attempt PASSED for auditing

13/03/2012 09:38:24 SecurityAgent[95] User info context values set for cove

13/03/2012 09:38:25 SecurityAgent[95] Login Window Showing Progress

13/03/2012 09:38:26 SecurityAgent[95] Login Window done

13/03/2012 09:38:26 loginwindow[31] Login Window - Returned from Security Agent

Just for comparison, here is a log for a 'normal' machine:

13/03/2012 08:30:40 configd[13] network configuration changed.

13/03/2012 08:30:40 configd[13] setting hostname to "n219-002225"

13/03/2012 08:30:41 blued[17] writeExtendedInquiryResponse returned 105

13/03/2012 08:30:41 com.apple.SystemStarter[22] Starting Qmaster services

13/03/2012 08:30:43 com.apple.DirectoryServices[15] Enter machine password: 

13/03/2012 08:30:43 com.apple.SecurityServer[25] Session 0x30a460 created

13/03/2012 08:30:43 com.apple.SecurityServer[25] Session 0x30a460 attributes 0x30

13/03/2012 08:30:44 loginwindow[31] Login Window Started Security Agent

13/03/2012 08:30:45 WindowServer[68] kCGErrorFailure: Set a breakpoint @ CGErrorBreakpoint() to catch errors as they are logged.

13/03/2012 08:30:45 com.apple.WindowServer[68] Tue Mar 13 08:30:45 n219-002225 WindowServer[68] : kCGErrorFailure: Set a breakpoint @ CGErrorBreakpoint() to catch errors as they are logged.

13/03/2012 08:30:45 TabletDriver[99] Finish launching /Library/Application Support/Tablet/PenTabletDriver.app/Contents/Resources/ConsumerTouchDriver.app

13/03/2012 08:30:45 com.wacom.pentablet[99] TabletDriver[99]: Finish launching /Library/Application Support/Tablet/PenTabletDriver.app/Contents/Resources/ConsumerTouchDriver.app

13/03/2012 08:30:45 SecurityAgent[105] Showing Login Window

13/03/2012 08:30:45 TabletDriver[99] Finish launching /Library/Application Support/Tablet/PenTabletDriver.app/Contents/Resources/TabletDriver.app

13/03/2012 08:30:45 com.wacom.pentablet[99] TabletDriver[99]: Finish launching /Library/Application Support/Tablet/PenTabletDriver.app/Contents/Resources/TabletDriver.app

13/03/2012 08:30:45 com.apple.DirectoryServices[15] DNS update failed!

13/03/2012 08:30:47 com.apple.DirectoryServices[15] Enter machine password: 

13/03/2012 08:30:48 com.apple.DirectoryServices[15] DNS update failed!

13/03/2012 08:30:55 root[125] sntp options: a=2 v=1 e=0.100 E=5.000 P=2147483647.000

13/03/2012 08:30:55 root[125]    d=15 c=5 x=0 op=1 l=/var/run/sntp.pid f= time.euro.apple.com

13/03/2012 08:30:55 root[125] sntp: not enough valid responses received in time

13/03/2012 09:46:27 /System/Library/CoreServices/RemoteManagement/AppleVNCServer.bundle/Contents/MacOS/AppleVNCServer[106] Authentication: SUCCEEDED :: User Name: cove :: Viewer Address: 172.25.3.128 :: Type: DH

13/03/2012 09:46:42 SecurityAgent[105] User info context values set for _mac_bind

13/03/2012 09:46:43 authorizationhost[104] k5_store_ticket_in_cache(): got -1765328243 (Matching credential not found) on /SourceCache/SecurityAgent/SecurityAgent-39574/plugins/krb5/krb5_operations.c:115

13/03/2012 09:46:43 edu.mit.Kerberos.CCacheServer[148] launchctl start error: No such process

13/03/2012 09:46:44 SecurityAgent[105] Login Window Showing Progress

13/03/2012 09:46:49 gssd-agent[153] Could not canonicalize our host name in kerberos_init

13/03/2012 09:46:55 mcxalr_agent[165] Listener client (pid: 165) entering listen mode for uid: 2069522553

13/03/2012 09:46:55 SecurityAgent[105] Login Window done

13/03/2012 09:46:55 loginwindow[31] Login Window - Returned from Security Agent

13/03/2012 09:46:55 com.apple.loginwindow[31] LoginHook: Executing /etc/hooks/LIclean.hook...

13/03/2012 09:46:55 root[173] LoginHook: Starting for _mac_bind

13/03/2012 09:46:56 kernel mcxalr{0} 32-bit  Build date: Feb  3 2010 19:02:48

13/03/2012 09:46:56 kernel mcxalr{1} Started

13/03/2012 09:46:56 kernel mcxalr{2} Management ENABLED for uid: 2069522553

13/03/2012 09:46:56 kernel calling mpo_policy_init for mcxalr

13/03/2012 09:46:56 kernel Security policy loaded: MCX App Launch (mcxalr)

13/03/2012 09:46:56 kernel mcxalr{3} Auth provider registered.  connection: 1  uid: 2069522553  version: 1

13/03/2012 09:46:56 com.apple.loginwindow[31] ls: /Network/Servers/faraday.students.somewhere.ac.uk/FaradayStudents/_mac_bind/Library/Caches: No such file or directory

13/03/2012 09:46:56 com.apple.loginwindow[31] usage: chmod [-fhv] [-R [-H | -L | -P]] [-a | +a | =a  [i][# [ n]]] mode|entry file ...

13/03/2012 09:46:56 com.apple.loginwindow[31] chmod [-fhv] [-R [-H | -L | -P]] [-E | -C | -N | -i | -I] file ...

13/03/2012 09:46:56 com.apple.loginwindow[31] ls: /Network/Servers/faraday.students.somewhere.ac.uk/FaradayStudents/_mac_bind/Library/Fonts: No such file or directory

13/03/2012 09:46:56 com.apple.loginwindow[31] usage: chmod [-fhv] [-R [-H | -L | -P]] [-a | +a | =a  [i][# [ n]]] mode|entry file ...

13/03/2012 09:46:56 com.apple.loginwindow[31] chmod [-fhv] [-R [-H | -L | -P]] [-E | -C | -N | -i | -I] file ...

13/03/2012 09:46:56 com.apple.loginwindow[31] ls: /Network/Servers/faraday.students.somewhere.ac.uk/FaradayStudents/_mac_bind/Library/Application Support/SMART Technologies Inc/Gallery: No such file or directory

13/03/2012 09:46:56 com.apple.loginwindow[31] usage: chmod [-fhv] [-R [-H | -L | -P]] [-a | +a | =a  [i][# [ n]]] mode|entry file ...

13/03/2012 09:46:56 com.apple.loginwindow[31] chmod [-fhv] [-R [-H | -L | -P]] [-E | -C | -N | -i | -I] file ...

13/03/2012 09:46:56 com.apple.loginwindow[31] cp: /Users/cove/Library/Application Support/Microsoft/Office: No such file or directory

13/03/2012 09:46:57 com.apple.loginwindow[31] mkdir: /Network/Servers/faraday.students.somewhere.ac.uk/FaradayStudents/_mac_bind/Movies/iMovie Events: File exists

13/03/2012 09:46:57 com.apple.loginwindow[31] mkdir: /Network/Servers/faraday.students.somewhere.ac.uk/FaradayStudents/_mac_bind/Movies/iMovie Projects: File exists

13/03/2012 09:46:57 com.apple.loginwindow[31] mkdir: /Network/Servers/faraday.students.somewhere.ac.uk/FaradayStudents/_mac_bind/Library/Application Support/Microsoft: File exists

13/03/2012 09:46:57 com.apple.loginwindow[31] ln: /Network/Servers/faraday.students.somewhere.ac.uk/FaradayStudents/_mac_bind/Library/Application Support/SMART Technologies Inc/Gallery

13/03/2012 09:46:57 com.apple.loginwindow[31] : No such file or directory

13/03/2012 09:46:57 root[242] - LoginHook:  Finished for _mac_bind

13/03/2012 09:46:57 loginwindow[31] USER_PROCESS: 31 console

13/03/2012 09:46:57 com.apple.UserEventAgent-LoginWindow[95] ALF error: cannot find useragent 1102

13/03/2012 09:46:57 com.apple.UserEventAgent-LoginWindow[95] plugin.UserEventAgentFactory: called with typeID=FC86416D-6164-2070-726F-70735C216EC0

13/03/2012 09:46:57 com.apple.launchd[1] ([0x0-0x5005].com.wacom.Consumer_TouchDriver[112]) Exited with exit code: 255

13/03/2012 09:46:57 com.apple.launchd.peruser.2069522553[146] (com.apple.ReportCrash) Falling back to default Mach exception handler. Could not find: com.apple.ReportCrash.Self

13/03/2012 09:46:57 com.apple.launchd[1] (com.wacom.pentablet[99]) Exited with exit code: 255

13/03/2012 09:46:59 mds[29] (Normal) DiskStore: Rebuilding index for /Network/Servers/faraday.students.somewhere.ac.uk/FaradayStudents/_mac_bind

13/03/2012 09:47:00 mds[29] (Normal) DiskStore: Creating index for /Network/Servers/faraday.students.somewhere.ac.uk/FaradayStudents/_mac_bind

13/03/2012 09:47:04 com.apple.launchd.peruser.2069522553[146] (com.apple.Kerberos.renew.plist[261]) Exited with exit code: 1

13/03/2012 09:47:05 ServerScanner[257] Not scanning because node /LDAPv3/xserve.somewhere.ac.uk is in searchPath

13/03/2012 09:47:07 MacClient[272] Starting UniFLOWMacClient

13/03/2012 09:47:08 Adobe Acrobat Updater Helper[267] Adobe Acrobat Updater encountered errorCode 1504

13/03/2012 09:47:09 MacClient[272] ID: 2 Request url 'http://gutenberg.students.somewhere.ac.uk/pwclient/logon/logonmacuser.asp?MachineName=_mac_bind&ClientType=1' with timeout 90.000000

13/03/2012 09:47:10 MacClient[272] ID: 2 Request url 'http://gutenberg.students.somewhere.ac.uk/pwclient/isapi/momntfy.dll?RunEventLoop?Handle=250' with timeout 90.000000

The only differences between these two machines are the fact that they are on different VLANs. The mac with the problem is on a special MAC VLAN, and the other is not.

Coincidentaly, I've only seen the problem on Mac's on this specific VLAN? Might be a coincidence as half of them are on the VLAN, soon to be all.

I shall update this. If anybody has any ideas please reply.




Update:


So, still no luck but lots more logs. Not sure if I'm going to post them all as it seems like a lot of data. Anyway, I ran out of time and had to re-image. It's working now. I shall update this when I find another machine with the same issues.