Skip to main content

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....

Comments

Popular posts from this blog

DFSR - eventid 4312 - replication just won't work

This warning isn't documented that well on the googles, so here's some google fodder:


You are trying to set up replication for a DFS folder (no existing replication)Source server is 2008R2, 'branch office' server is 2012R2 (I'm moving all our infra to 2012R2)You have no issues getting replication configuredYou see the DFSR folders get created on the other end, but nothing stagesFinally you get EventID 4312:
The DFS Replication service failed to get folder information when walking the file system on a journal wrap or loss recovery due to repeated sharing violations encountered on a folder. The service cannot replicate the folder and files in that folder until the sharing violation is resolved.  Additional Information:  Folder: F:\Users$\user.name\Desktop\Random Folder Name\  Replicated Folder Root: F:\Users$  File ID: {00000000-0000-0000-0000-000000000000}-v0  Replicated Folder Name: Users  Replicated Folder ID: 33F0449D-5E67-4DA1-99AC-681B5BACC7E5  Replication Group…

Fixing duplicate SPNs (service principal name)

This is a pretty handy thing to know:

SPNs are used when a specific service/daemon uses Kerberos to authenticate against AD. They map a specific service, port, and object together with this convention: class/host:port/name

If you use a computer object to auth (such as local service):
MSSQLSVC/tor-sql-01.domain.local:1433

If you use a user object to auth (such as a service account, or admin account):
MSSQLSVC/username:1433

Why do we care about duplicate SPNs? If you have two entries trying to auth using the same Kerberos ticket (I think that's right...), they will conflict, and cause errors and service failures.

To check for duplicate SPNs:
The command "setspn.exe -X

C:\Windows\system32>setspn -X
Processing entry 7
MSSQLSvc/server1.company.local:1433 is registered on these accounts:
CN=SERVER1,OU=servers,OU=resources,DC=company,DC=local
CN=SQL Admin,OU=service accounts,OU=resources,DC=company,DC=local

found 1 groups of duplicate SPNs. (truncated/sanitized)

Note that y…

Logstash to Nagios - alerting based on Windows Event ID

This took way longer than it should have to get going...so here's a config and brain dump...

Why?
You want to have a central place to analyze Windows Event/IIS/local application logs, alert off specific events, alert off specific situations.  You don't have the budget for a boxed solution.  You want pretty graphs.  You don't particularly care about individual server states.  (see rationale below - although you certainly have all the tools here to care, I haven't provided that configuration)

How?
ELK stack, OMD, NXlog agent, and Rsyslog.  The premise here is as follows:

Event generated on server into EventLogNXlog ships to Logstash inputLogstash filter adds fields and tags to specified eventsLogstash output sends to a passive Nagios service via the Nagios NSCA outputThe passive service on Nagios (Check_MK c/o OMD) does its thing w. alerting
OMD
Open Monitoring Distribution, but the real point here is Check_MK (IIRC Icinga uses this...).  It makes Nagios easy to use and main…