Tiger broke Password Service

[Flash]

Since upgrading my OD master and replicas from 10.3.9 to 10.4.2, the Password Service pegs both processors on the OD master for 8-10 minutes whenever a password is changed. Doesn’t matter whether the password is changed from WGM, terminal, or managed client. No crashes occur, nothing written to System log, all else seems normal. The following consistent System log entries are also new since the update.

Upon Startup:

Jul 15 14:04:27 msusserver mDNSResponder: Update _kerberos._udp.MSUSSERVER.COLLEGIATE-VA.ORG. failed with rcode 4
Jul 15 14:04:27 msusserver mDNSResponder: Registration of record _kerberos._udp.MSUSSERVER.COLLEGIATE-VA.ORG. type 33 failed with error -65537
Jul 15 14:04:51 msusserver mDNSResponder: Update _kerberos._tcp.MSUSSERVER.COLLEGIATE-VA.ORG. failed with rcode 4
Jul 15 14:04:51 msusserver mDNSResponder: Registration of record _kerberos._tcp.MSUSSERVER.COLLEGIATE-VA.ORG. type 33 failed with error -65537

5-10 times per minute, all the time:

Jul 13 12:05:19 msusserver DirectoryService[39]: GSSAPI Error: Miscellaneous failure (Server not found in Kerberos database)

Other details:

-use “Standard” authentication, not Kerberos, no services Kerberized since upgrade
-all OD processes running as usual
-no dns or name changes made in the upgrade
-forward and reverse lookups come back normal
-appropriate server records exist when requesting “listprincs” from kadmin.local
-edu.mit.Kerberos file and kdc.conf look normal

[Flash]

Nothing of any consequence in the Password Service log. However, when I change a password, and the Password Service pegs the CPU’s for 10min, see below for what shows up in the Password Service Replication log during that 10 minutes. If I set replication interval to daily, then change a password, no spike whatsoever caused by Password Service. Clearly I have some issue with password replication. I’m thinking that one of the server records in the Kerberos Db is incorrect. What tool can I use to inspect these server records, search base, etc? I’m onto something here!

Password Service Replication Log:

Jul 20 2005 08:03:45 Synchronizing with “Replica1”
Jul 20 2005 08:04:14 Connecting to 10.1.1.15, synchronizing all records since 07/20/2005 12:41:24 AM
Jul 20 2005 08:04:14 The remote replica list has 1 parent and 1 replica.
Jul 20 2005 08:04:14 Updating the list of replicas. There is 1 parent and 1 replica in the list.
Jul 20 2005 08:04:16 syncfile: /var/db/authserver/apsSyncFi1121861056.358439
Jul 20 2005 08:04:16 sent 3 records, accepted 0, superceded 0
Jul 20 2005 08:04:16 No Kerberos records to update
Jul 20 2005 08:04:16 DoSync: the next replication will occur on 07/21/2005 at 12:00:00 AM
Jul 20 2005 08:04:21 updating replica list with on-disk changes
Jul 20 2005 08:04:32 Updated 1 Kerberos Records
Jul 20 2005 08:04:32 Updated 5 records, rejected 1367 from Replica1
Jul 20 2005 08:04:37 Synchronizing with “Replica1”
Jul 20 2005 08:04:43 SYNC PULL: providing data to 10.1.1.15 after 07/20/2005 08:02:45 AM
Jul 20 2005 08:05:06 Connecting to 10.1.1.15, synchronizing all records since 07/20/2005 08:03:45 AM
Jul 20 2005 08:05:06 The remote replica list has 1 parent and 1 replica.
Jul 20 2005 08:05:06 Updating the list of replicas. There is 1 parent and 1 replica in the list.
Jul 20 2005 08:05:06 merging conflicting replica lists
Jul 20 2005 08:05:06 SYNC PULL: updating 0 records
Jul 20 2005 08:05:13 syncfile: /var/db/authserver/apsSyncFi1121861113.568275
Jul 20 2005 08:05:13 sent 2 records, accepted 0, superceded 0
Jul 20 2005 08:05:13 No Kerberos records to update
Jul 20 2005 08:05:13 DoSync: the next replication will occur on 07/21/2005 at 12:00:00 AM
Jul 20 2005 08:05:18 updating replica list with on-disk changes
Jul 20 2005 08:05:18 Sending Kerberos data to “Replica1”
Jul 20 2005 08:05:47 Connecting to 10.1.1.15, synchronizing all records since 12/31/1969 07:00:00 PM
Jul 20 2005 08:05:47 The remote replica list has 1 parent and 1 replica.
Jul 20 2005 08:05:47 Updating the list of replicas. There is 1 parent and 1 replica in the list.
Jul 20 2005 08:05:50 sent 1382 records, accepted 0, superceded 0
Jul 20 2005 08:05:51 Updated 1 Kerberos Records
Jul 20 2005 08:05:51 Updated 5 records, rejected 1367 from Replica1
Jul 20 2005 08:05:51 updating replica list with on-disk changes
Jul 20 2005 08:06:11 SYNC PULL: providing data to 10.1.1.15 after 07/20/2005 08:03:45 AM
Jul 20 2005 08:06:39 SYNC PULL: updating 0 records
Jul 20 2005 08:06:41 Sending Kerberos data to “Replica1”
Jul 20 2005 08:07:11 Connecting to 10.1.1.15, synchronizing all records since 12/31/1969 07:00:00 PM
Jul 20 2005 08:07:11 The remote replica list has 1 parent and 1 replica.
Jul 20 2005 08:07:11 Updating the list of replicas. There is 1 parent and 1 replica in the list.
Jul 20 2005 08:07:13 sent 1382 records, accepted 0, superceded 0
Jul 20 2005 08:07:13 updating replica list with on-disk changes
Jul 20 2005 08:07:28 SYNC PULL: providing data to 10.1.1.15 after 07/20/2005 08:04:29 AM
Jul 20 2005 08:07:55 SYNC PULL: updating 1 records
Jul 20 2005 08:07:58 Sending Kerberos data to “Replica1”
Jul 20 2005 08:08:27 Connecting to 10.1.1.15, synchronizing all records since 12/31/1969 07:00:00 PM
Jul 20 2005 08:08:27 The remote replica list has 1 parent and 1 replica.
Jul 20 2005 08:08:27 Updating the list of replicas. There is 1 parent and 1 replica in the list.
Jul 20 2005 08:08:28 sent 1382 records, accepted 0, superceded 0
Jul 20 2005 08:08:28 updating replica list with on-disk changes
Jul 20 2005 08:08:42 SYNC PULL: providing data to 10.1.1.15 after 07/20/2005 08:05:49 AM
Jul 20 2005 08:09:10 SYNC PULL: updating 0 records
Jul 20 2005 08:09:13 Sending Kerberos data to “Replica1”
Jul 20 2005 08:09:42 Connecting to 10.1.1.15, synchronizing all records since 12/31/1969 07:00:00 PM
Jul 20 2005 08:09:42 The remote replica list has 1 parent and 1 replica.
Jul 20 2005 08:09:42 Updating the list of replicas. There is 1 parent and 1 replica in the list.
Jul 20 2005 08:09:45 sent 1382 records, accepted 0, superceded 0
Jul 20 2005 08:09:45 No Kerberos records to update
Jul 20 2005 08:09:45 Updated 1 records, rejected 0 from Replica1
Jul 20 2005 08:09:45 updating replica list with on-disk changes
Jul 20 2005 08:09:58 SYNC PULL: providing data to 10.1.1.15 after 07/20/2005 08:07:08 AM
Jul 20 2005 08:10:26 SYNC PULL: updating 2 records
Jul 20 2005 08:10:30 Sending Kerberos data to “Replica1”
Jul 20 2005 08:10:59 Connecting to 10.1.1.15, synchronizing all records since 12/31/1969 07:00:00 PM
Jul 20 2005 08:10:59 The remote replica list has 1 parent and 1 replica.
Jul 20 2005 08:10:59 Updating the list of replicas. There is 1 parent and 1 replica in the list.
Jul 20 2005 08:11:02 sent 1382 records, accepted 0, superceded 0
Jul 20 2005 08:11:02 No Kerberos records to update
Jul 20 2005 08:11:02 Updated 0 records, rejected 2 from Replica1
Jul 20 2005 08:11:02 updating replica list with on-disk changes
Jul 20 2005 08:11:20 SYNC PULL: providing data to 10.1.1.15 after 07/20/2005 08:08:23 AM
Jul 20 2005 08:11:47 SYNC PULL: updating 0 records
Jul 20 2005 08:11:52 Sending Kerberos data to “Replica1”
Jul 20 2005 08:12:21 Connecting to 10.1.1.15, synchronizing all records since 12/31/1969 07:00:00 PM
Jul 20 2005 08:12:21 The remote replica list has 1 parent and 1 replica.
Jul 20 2005 08:12:21 Updating the list of replicas. There is 1 parent and 1 replica in the list.
Jul 20 2005 08:12:22 sent 1382 records, accepted 0, superceded 0
Jul 20 2005 08:12:22 No Kerberos records to update
Jul 20 2005 08:12:22 Updated 2 records, rejected 0 from Replica1
Jul 20 2005 08:12:22 updating replica list with on-disk changes
Jul 20 2005 08:12:35 SYNC PULL: providing data to 10.1.1.15 after 07/20/2005 08:09:38 AM
Jul 20 2005 08:13:02 SYNC PULL: updating 0 records
Jul 20 2005 08:13:07 Sending Kerberos data to “Replica1”
Jul 20 2005 08:13:36 Connecting to 10.1.1.15, synchronizing all records since 12/31/1969 07:00:00 PM
Jul 20 2005 08:13:36 The remote replica list has 1 parent and 1 replica.
Jul 20 2005 08:13:36 Updating the list of replicas. There is 1 parent and 1 replica in the list.
Jul 20 2005 08:13:39 sent 1382 records, accepted 0, superceded 0
Jul 20 2005 08:13:39 updating replica list with on-disk changes
Jul 20 2005 08:14:00 SYNC PULL: providing data to 10.1.1.15 after 07/20/2005 08:11:01 AM
Jul 20 2005 08:14:28 SYNC PULL: updating 0 records
Jul 20 2005 08:14:29 Sending Kerberos data to “Replica1”
Jul 20 2005 08:14:58 Connecting to 10.1.1.15, synchronizing all records since 12/31/1969 07:00:00 PM
Jul 20 2005 08:14:58 The remote replica list has 1 parent and 1 replica.
Jul 20 2005 08:14:58 Updating the list of replicas. There is 1 parent and 1 replica in the list.
Jul 20 2005 08:14:59 sent 1382 records, accepted 0, superceded 0
Jul 20 2005 08:14:59 updating replica list with on-disk changes
Jul 20 2005 08:15:15 SYNC PULL: providing data to 10.1.1.15 after 07/20/2005 08:12:18 AM
Jul 20 2005 08:15:43 SYNC PULL: updating 1 records
Jul 20 2005 08:15:45 Sending Kerberos data to “Replica1”
Jul 20 2005 08:16:14 Connecting to 10.1.1.15, synchronizing all records since 12/31/1969 07:00:00 PM
Jul 20 2005 08:16:14 The remote replica list has 1 parent and 1 replica.
Jul 20 2005 08:16:14 Updating the list of replicas. There is 1 parent and 1 replica in the list.
Jul 20 2005 08:16:15 sent 1382 records, accepted 0, superceded 0
Jul 20 2005 08:16:15 updating replica list with on-disk changes
Jul 20 2005 08:16:29 SYNC PULL: providing data to 10.1.1.15 after 07/20/2005 08:13:41 AM
Jul 20 2005 08:16:57 SYNC PULL: updating 1 records
Jul 20 2005 08:17:00 Sending Kerberos data to “Replica1”
Jul 20 2005 08:17:29 Connecting to 10.1.1.15, synchronizing all records since 12/31/1969 07:00:00 PM
Jul 20 2005 08:17:29 The remote replica list has 1 parent and 1 replica.
Jul 20 2005 08:17:29 Updating the list of replicas. There is 1 parent and 1 replica in the list.
Jul 20 2005 08:17:32 sent 1382 records, accepted 0, superceded 0
Jul 20 2005 08:17:32 No Kerberos records to update
Jul 20 2005 08:17:32 Updated 1 records, rejected 0 from Replica1
Jul 20 2005 08:17:32 updating replica list with on-disk changes

[spiggott]

Anyone find an answer to this? I’m having the exact same issue.

[Author]

Posts