More netlogon.log digging
We have been having GP (on the mentioned SQL4 box) heck over the last week or so, probably caused by all the network changes all at once, but who knows, so I'm digging! Clients are fed up with massive lag, errors, and general unusability. Up until a week ago or so, things were just peachy.
While troubleshooting SQL connection issues, I've come across about 1000 entries in the netlogon.log from the past three days like this:
06/23 23:30:02 [LOGON] ORTHOTIC: SamLogon: Transitive Network logon of orthotic\sqlsvc from EXCHANGE (via EXCHANGE) Returns 0xC000006A
6A, recall, being bad password, and the account shows as locked out in the adlockout tool.
So a service is trying to access something on Exchange from Exchange...weird.
I took a look at one of the SQL boxes, and it uses this sqlsvc account for its SQL services. The security log in SQL shows no failed logon attempts. The event log is showing W32time warnings however - might not be that important - the clock is only off by 30 seconds or so compared to my workstation.
Interestingly enough, there is a database mail section in the log viewer, and there are 'DatabaseMail process is started' and 'DatabaseMail process is shutting down' entries every two hours or so, with varying times between. Does this correlate to the netlogon.log events?
At 14:21:01 there is this:
06/26 14:21:01 [LOGON] ORTHOTIC: SamLogon: Transitive Network logon of (null)\orthotic\sqlsvc from SQL4 (via EXCHANGE) Returns 0xC0000064
At 14:20:02 there is a 'DatabaseMail process is started' event on SQL4 using sqlsvc.
Oooh! Very interesting!
At 13:51:05 in netlogon.log I see this over the space of 1.5 seconds for about a page's worth (at 1600x1200):
06/26 13:21:08 [LOGON] ORTHOTIC: SamLogon: Transitive Network logon of orthotic\sqlsvc from EXCHANGE (via YYZ-DC-2) Returns 0xC0000234
06/26 13:51:05 [LOGON] ORTHOTIC: SamLogon: Transitive Network logon of (null)\orthotic\sqlsvc from SQL4 (via EXCHANGE) Entered
06/26 13:51:05 [LOGON] ORTHOTIC: NlPickDomainWithAccount: orthotic\sqlsvc: Algorithm entered. UPN:0 Sam:0 Exp:0 Cross: 0 Root:1 DC:0
06/26 13:51:05 [CRITICAL] ORTHOTIC: NlPickDomainWithAccount: orthotic\sqlsvc: Must be either UPN or SAM account. UPN:0 Sam:0
06/26 13:51:05 [LOGON] ORTHOTIC: SamLogon: Transitive Network logon of (null)\orthotic\sqlsvc from SQL4 (via EXCHANGE) Returns 0xC0000064
06/26 13:51:05 [LOGON] ORTHOTIC: SamLogon: Transitive Network logon of (null)\orthotic\sqlsvc from SQL4 (via EXCHANGE) Entered
06/26 13:51:05 [LOGON] ORTHOTIC: NlPickDomainWithAccount: orthotic\sqlsvc: Algorithm entered. UPN:0 Sam:0 Exp:0 Cross: 0 Root:1 DC:0
06/26 13:51:05 [CRITICAL] ORTHOTIC: NlPickDomainWithAccount: orthotic\sqlsvc: Must be either UPN or SAM account. UPN:0 Sam:0
06/26 13:51:05 [LOGON] ORTHOTIC: SamLogon: Transitive Network logon of (null)\orthotic\sqlsvc from SQL4 (via EXCHANGE) Returns 0xC0000064
06/26 13:51:05 [LOGON] ORTHOTIC: SamLogon: Transitive Network logon of orthotic\sqlsvc from EXCHANGE (via EXCHANGE) Entered
06/26 13:51:05 [LOGON] ORTHOTIC: SamLogon: Transitive Network logon of orthotic\sqlsvc from EXCHANGE (via EXCHANGE) Returns 0xC000006A
Horrific. An interesting line:
06/26 13:51:05 [CRITICAL] ORTHOTIC: NlPickDomainWithAccount: orthotic\sqlsvc: Must be either UPN or SAM account. UPN:0 Sam:0
Hmm. At 13:50:04 there is a 'DatabaseMail Process is started' event on SQL4.
13:59:25, hmm...less entries, but from the other SQL server this time...I wonder what runs on SQL3 at this time...
06/26 13:59:25 [LOGON] ORTHOTIC: SamLogon: Transitive Network logon of (null)\orthotic\sqlsvc from SQL3 (via EXCHANGE) Entered
06/26 13:59:25 [LOGON] ORTHOTIC: NlPickDomainWithAccount: orthotic\sqlsvc: Algorithm entered. UPN:0 Sam:0 Exp:0 Cross: 0 Root:1 DC:0
06/26 13:59:25 [CRITICAL] ORTHOTIC: NlPickDomainWithAccount: orthotic\sqlsvc: Must be either UPN or SAM account. UPN:0 Sam:0
06/26 13:59:25 [LOGON] ORTHOTIC: SamLogon: Transitive Network logon of (null)\orthotic\sqlsvc from SQL3 (via EXCHANGE) Returns 0xC0000064
06/26 13:59:25 [LOGON] ORTHOTIC: SamLogon: Transitive Network logon of orthotic\sqlsvc from EXCHANGE (via EXCHANGE) Entered
06/26 13:59:25 [LOGON] ORTHOTIC: SamLogon: Transitive Network logon of orthotic\sqlsvc from EXCHANGE (via EXCHANGE) Returns 0xC0000234
At 14:00:20, more SQL4:
0 [LOGON] ORTHOTIC: SamLogon: Transitive Network logon of (null)\orthotic\sqlsvc from SQL4 (via EXCHANGE) Entered
06/26 14:00:20 [LOGON] ORTHOTIC: NlPickDomainWithAccount: orthotic\sqlsvc: Algorithm entered. UPN:0 Sam:0 Exp:0 Cross: 0 Root:1 DC:0
06/26 14:00:20 [CRITICAL] ORTHOTIC: NlPickDomainWithAccount: orthotic\sqlsvc: Must be either UPN or SAM account. UPN:0 Sam:0
06/26 14:00:20 [LOGON] ORTHOTIC: SamLogon: Transitive Network logon of (null)\orthotic\sqlsvc from SQL4 (via EXCHANGE) Returns 0xC0000064
06/26 14:00:20 [LOGON] ORTHOTIC: SamLogon: Transitive Network logon of orthotic\sqlsvc from EXCHANGE (via EXCHANGE) Entered
06/26 14:00:20 [LOGON] ORTHOTIC: SamLogon: Transitive Network logon of orthotic\sqlsvc from EXCHANGE (via EXCHANGE) Returns 0xC0000234
14:21:01, a whole rash in netlogon, and lookee...14:20:02 has DatabaseMail process is started. 59 seconds off again, explaining the w32time warnings I've been seeing.
Probably safe to say at this point that the rest of them are caused by the DatabaseMail process starting. So!! What jobs run at those times? Somewhat frustratingly, there are no records of failed jobs at all of those times, and since every job is run by that user...doesn't make sense that some would work, and others not....unless only some jobs use the DatabaseMail process...
I checked the setup of the DatabaseMail under SQL4\Management, and updated the password. I unlocked the account using the adlockout tool on all DCs, so we'll see how long it takes to start erroring. I'm going to check other features to see if the sqlsvc password is out of date.
Doesn't seem to be set anywhere else...I'll try the services. They look correct - I don't want to change them yet, as they seem to be working fine. 30 minutes and no more lockouts, but I'll probably have to wait until tomorrow to see more.
Signing off for now....
While troubleshooting SQL connection issues, I've come across about 1000 entries in the netlogon.log from the past three days like this:
06/23 23:30:02 [LOGON] ORTHOTIC: SamLogon: Transitive Network logon of orthotic\sqlsvc from EXCHANGE (via EXCHANGE) Returns 0xC000006A
6A, recall, being bad password, and the account shows as locked out in the adlockout tool.
So a service is trying to access something on Exchange from Exchange...weird.
I took a look at one of the SQL boxes, and it uses this sqlsvc account for its SQL services. The security log in SQL shows no failed logon attempts. The event log is showing W32time warnings however - might not be that important - the clock is only off by 30 seconds or so compared to my workstation.
Interestingly enough, there is a database mail section in the log viewer, and there are 'DatabaseMail process is started' and 'DatabaseMail process is shutting down' entries every two hours or so, with varying times between. Does this correlate to the netlogon.log events?
At 14:21:01 there is this:
06/26 14:21:01 [LOGON] ORTHOTIC: SamLogon: Transitive Network logon of (null)\orthotic\sqlsvc from SQL4 (via EXCHANGE) Returns 0xC0000064
At 14:20:02 there is a 'DatabaseMail process is started' event on SQL4 using sqlsvc.
Oooh! Very interesting!
At 13:51:05 in netlogon.log I see this over the space of 1.5 seconds for about a page's worth (at 1600x1200):
06/26 13:21:08 [LOGON] ORTHOTIC: SamLogon: Transitive Network logon of orthotic\sqlsvc from EXCHANGE (via YYZ-DC-2) Returns 0xC0000234
06/26 13:51:05 [LOGON] ORTHOTIC: SamLogon: Transitive Network logon of (null)\orthotic\sqlsvc from SQL4 (via EXCHANGE) Entered
06/26 13:51:05 [LOGON] ORTHOTIC: NlPickDomainWithAccount: orthotic\sqlsvc: Algorithm entered. UPN:0 Sam:0 Exp:0 Cross: 0 Root:1 DC:0
06/26 13:51:05 [CRITICAL] ORTHOTIC: NlPickDomainWithAccount: orthotic\sqlsvc: Must be either UPN or SAM account. UPN:0 Sam:0
06/26 13:51:05 [LOGON] ORTHOTIC: SamLogon: Transitive Network logon of (null)\orthotic\sqlsvc from SQL4 (via EXCHANGE) Returns 0xC0000064
06/26 13:51:05 [LOGON] ORTHOTIC: SamLogon: Transitive Network logon of (null)\orthotic\sqlsvc from SQL4 (via EXCHANGE) Entered
06/26 13:51:05 [LOGON] ORTHOTIC: NlPickDomainWithAccount: orthotic\sqlsvc: Algorithm entered. UPN:0 Sam:0 Exp:0 Cross: 0 Root:1 DC:0
06/26 13:51:05 [CRITICAL] ORTHOTIC: NlPickDomainWithAccount: orthotic\sqlsvc: Must be either UPN or SAM account. UPN:0 Sam:0
06/26 13:51:05 [LOGON] ORTHOTIC: SamLogon: Transitive Network logon of (null)\orthotic\sqlsvc from SQL4 (via EXCHANGE) Returns 0xC0000064
06/26 13:51:05 [LOGON] ORTHOTIC: SamLogon: Transitive Network logon of orthotic\sqlsvc from EXCHANGE (via EXCHANGE) Entered
06/26 13:51:05 [LOGON] ORTHOTIC: SamLogon: Transitive Network logon of orthotic\sqlsvc from EXCHANGE (via EXCHANGE) Returns 0xC000006A
Horrific. An interesting line:
06/26 13:51:05 [CRITICAL] ORTHOTIC: NlPickDomainWithAccount: orthotic\sqlsvc: Must be either UPN or SAM account. UPN:0 Sam:0
Hmm. At 13:50:04 there is a 'DatabaseMail Process is started' event on SQL4.
13:59:25, hmm...less entries, but from the other SQL server this time...I wonder what runs on SQL3 at this time...
06/26 13:59:25 [LOGON] ORTHOTIC: SamLogon: Transitive Network logon of (null)\orthotic\sqlsvc from SQL3 (via EXCHANGE) Entered
06/26 13:59:25 [LOGON] ORTHOTIC: NlPickDomainWithAccount: orthotic\sqlsvc: Algorithm entered. UPN:0 Sam:0 Exp:0 Cross: 0 Root:1 DC:0
06/26 13:59:25 [CRITICAL] ORTHOTIC: NlPickDomainWithAccount: orthotic\sqlsvc: Must be either UPN or SAM account. UPN:0 Sam:0
06/26 13:59:25 [LOGON] ORTHOTIC: SamLogon: Transitive Network logon of (null)\orthotic\sqlsvc from SQL3 (via EXCHANGE) Returns 0xC0000064
06/26 13:59:25 [LOGON] ORTHOTIC: SamLogon: Transitive Network logon of orthotic\sqlsvc from EXCHANGE (via EXCHANGE) Entered
06/26 13:59:25 [LOGON] ORTHOTIC: SamLogon: Transitive Network logon of orthotic\sqlsvc from EXCHANGE (via EXCHANGE) Returns 0xC0000234
At 14:00:20, more SQL4:
0 [LOGON] ORTHOTIC: SamLogon: Transitive Network logon of (null)\orthotic\sqlsvc from SQL4 (via EXCHANGE) Entered
06/26 14:00:20 [LOGON] ORTHOTIC: NlPickDomainWithAccount: orthotic\sqlsvc: Algorithm entered. UPN:0 Sam:0 Exp:0 Cross: 0 Root:1 DC:0
06/26 14:00:20 [CRITICAL] ORTHOTIC: NlPickDomainWithAccount: orthotic\sqlsvc: Must be either UPN or SAM account. UPN:0 Sam:0
06/26 14:00:20 [LOGON] ORTHOTIC: SamLogon: Transitive Network logon of (null)\orthotic\sqlsvc from SQL4 (via EXCHANGE) Returns 0xC0000064
06/26 14:00:20 [LOGON] ORTHOTIC: SamLogon: Transitive Network logon of orthotic\sqlsvc from EXCHANGE (via EXCHANGE) Entered
06/26 14:00:20 [LOGON] ORTHOTIC: SamLogon: Transitive Network logon of orthotic\sqlsvc from EXCHANGE (via EXCHANGE) Returns 0xC0000234
14:21:01, a whole rash in netlogon, and lookee...14:20:02 has DatabaseMail process is started. 59 seconds off again, explaining the w32time warnings I've been seeing.
Probably safe to say at this point that the rest of them are caused by the DatabaseMail process starting. So!! What jobs run at those times? Somewhat frustratingly, there are no records of failed jobs at all of those times, and since every job is run by that user...doesn't make sense that some would work, and others not....unless only some jobs use the DatabaseMail process...
I checked the setup of the DatabaseMail under SQL4\Management, and updated the password. I unlocked the account using the adlockout tool on all DCs, so we'll see how long it takes to start erroring. I'm going to check other features to see if the sqlsvc password is out of date.
Doesn't seem to be set anywhere else...I'll try the services. They look correct - I don't want to change them yet, as they seem to be working fine. 30 minutes and no more lockouts, but I'll probably have to wait until tomorrow to see more.
Signing off for now....
Comments
Post a Comment