Use Process Monitor to Find Event 4625

A Server 2012 R2 Essentials machine recently started generating logon error 4625 four times every five minutes. I realized that the times matched the times that my monitoring software checks in, but exactly which component is causing the error?

Here is the error:

Log Name:      Security
Source:        Microsoft-Windows-Security-Auditing
Date:          10/24/2014 2:47:13 PM
Event ID:      4625
Task Category: Logon
Level:         Information
Keywords:      Audit Failure
User:          N/A
Computer:      SVR01.mydomain.local
Description:
An account failed to log on.

Subject:
	Security ID:		NULL SID
	Account Name:		-
	Account Domain:		-
	Logon ID:		0x0

Logon Type:			3

Account For Which Logon Failed:
	Security ID:		NULL SID
	Account Name:		SVR01$
	Account Domain:		mydomain

Failure Information:
	Failure Reason:		An Error occured during Logon.
	Status:			0xC000006D
	Sub Status:		0x0

Process Information:
	Caller Process ID:	0x0
	Caller Process Name:	-

Network Information:
	Workstation Name:	SVR01
	Source Network Address:	fe80::9105:194f:4de7:e277
	Source Port:		53036

Detailed Authentication Information:
	Logon Process:		
	Authentication Package:	NTLM
	Transited Services:	-
	Package Name (NTLM only):	-
	Key Length:		0

Event Xml:
<Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
  <System>
    <Provider Name="Microsoft-Windows-Security-Auditing" Guid="{54849625-5478-4994-A5BA-3E3B0328C30D}" />
    <EventID>4625</EventID>
    <Version>0</Version>
    <Level>0</Level>
    <Task>12544</Task>
    <Opcode>0</Opcode>
    <Keywords>0x8010000000000000</Keywords>
    <TimeCreated SystemTime="2014-10-24T21:47:13.009094300Z" />
    <EventRecordID>3518338</EventRecordID>
    <Correlation />
    <Execution ProcessID="644" ThreadID="6344" />
    <Channel>Security</Channel>
    <Computer>SVR01.mydomain.local</Computer>
    <Security />
  </System>
  <EventData>
    ...removed...
  </EventData>
</Event>

It’s interesting that the Source Network Address is the Link-local IPv6 address. IPv6 is installed on the machine and it is set to obtain an address automatically but there is no IPv6 DHCP server on the network.

Sysinternals Process Monitor generates thousands of lines per second. How do we know which line triggered the above event? The trick is to get the exact time (timestamp) from the error’s Details tab, or from the Event Xml above.

T21:47:13.009094300Z indicates that the  error occurred at 9:47:13pm GMT or 2:47:13pm PST. Assuming Process Monitor was running when the event was generated, we can look for events occurring just before “2:47:13.009094300” in Process Monitor:

Now that we know that the event has a Result of LOGON FAILURE, we can add that as a Process Monitor filter and find the failures even faster:

And here are the four failed logon attempts:

Now What?

So what is going on here? I’m using the monitoring tool to run PsLoggeon.exe, one of the Sysinternals Pstools, to see who (if anyone) is logged on locally to the server. For some reason, PsLoggedon is trying to create a pipe on an IPv6 Link-local address. My options at this point:

• Stop the PsLoggedon user monitoring on the server.
• The error is coming from a legitimate program, so ignore 4 errors x 12 times/hour x 24 hours/day = 1152 errors per day.
• Delve deep into IPv6, pipes, Sysinternals, etc. and try to figure out how to make the tool stop this access or how to grant it permission to do the access.

I think I’ll go with the second option and ignore 1152 errors per day.