trust_pw_change causes 4625 Event on Windows Domain Controller

Pmantis

Dabbler
Joined
Mar 11, 2015
Messages
19
I have a customer with a 2008 server as the DC and FreeNAS-11.2-U5. I'm getting Automate (formerly Labtech) tickets for failed logins occasionally. I checked the event log details (below) and the FreeNAS log (below) and it seems to be related to an automatic password change for the trust relationship. Is there something I can do to prevent these log events?

Thank you very much!

The XML event data:
Code:
Log Name:      Security
Source:        Microsoft-Windows-Security-Auditing
Date:          10/8/2019 1:30:43 PM
Event ID:      4625
Task Category: Logon
Level:         Information
Keywords:      Audit Failure
User:          N/A
Computer:      98Server1.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:        98NAS1$
    Account Domain:        MYDOMAIN.LOCAL

Failure Information:
    Failure Reason:        Unknown user name or bad password.
    Status:            0xC000006D
    Sub Status:        0xC000006A

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

Network Information:
    Workstation Name:    98NAS1
    Source Network Address:    192.168.86.240
    Source Port:        18859

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

This event is generated when a logon request fails. It is generated on the computer where access was attempted.

The Subject fields indicate the account on the local system which requested the logon. This is most commonly a service such as the Server service, or a local process such as Winlogon.exe or Services.exe.

The Logon Type field indicates the kind of logon that was requested. The most common types are 2 (interactive) and 3 (network).

The Process Information fields indicate which account and process on the system requested the logon.

The Network Information fields indicate where a remote logon request originated. Workstation name is not always available and may be left blank in some cases.

The authentication information fields provide detailed information about this specific logon request.
    - Transited services indicate which intermediate services have participated in this logon request.
    - Package name indicates which sub-protocol was used among the NTLM protocols.
    - Key length indicates the length of the generated session key. This will be 0 if no session key was requested.
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="2019-10-08T17:30:43.992579000Z" />
    <EventRecordID>22978102</EventRecordID>
    <Correlation />
    <Execution ProcessID="544" ThreadID="1580" />
    <Channel>Security</Channel>
    <Computer>98Server1.mydomain.local</Computer>
    <Security />
  </System>
  <EventData>
    <Data Name="SubjectUserSid">S-1-0-0</Data>
    <Data Name="SubjectUserName">-</Data>
    <Data Name="SubjectDomainName">-</Data>
    <Data Name="SubjectLogonId">0x0</Data>
    <Data Name="TargetUserSid">S-1-0-0</Data>
    <Data Name="TargetUserName">98NAS1$</Data>
    <Data Name="TargetDomainName">MYDOMAIN.LOCAL</Data>
    <Data Name="Status">0xc000006d</Data>
    <Data Name="FailureReason">%%2313</Data>
    <Data Name="SubStatus">0xc000006a</Data>
    <Data Name="LogonType">3</Data>
    <Data Name="LogonProcessName">NtLmSsp </Data>
    <Data Name="AuthenticationPackageName">NTLM</Data>
    <Data Name="WorkstationName">98NAS1</Data>
    <Data Name="TransmittedServices">-</Data>
    <Data Name="LmPackageName">-</Data>
    <Data Name="KeyLength">0</Data>
    <Data Name="ProcessId">0x0</Data>
    <Data Name="ProcessName">-</Data>
    <Data Name="IpAddress">192.168.86.240</Data>
    <Data Name="IpPort">18859</Data>
  </EventData>
</Event>


Code:
Oct  8 13:14:10 98NAS1 winbindd[31260]: [2019/10/08 13:14:10.135596,  1] ../librpc/ndr/ndr.c:422(ndr_print_debug)
Oct  8 13:14:10 98NAS1 winbindd[31260]:        prepare_change: struct secrets_domain_infoB
Oct  8 13:14:10 98NAS1 winbindd[31260]:           version                  : SECRETS_DOMAIN_INFO_VERSION_1 (1)
Oct  8 13:14:10 98NAS1 winbindd[31260]:           reserved                 : 0x00000000 (0)
Oct  8 13:14:10 98NAS1 winbindd[31260]:           info                     : union secrets_domain_infoU(case 1)
Oct  8 13:14:10 98NAS1 winbindd[31260]:           info1                    : *
Oct  8 13:14:10 98NAS1 winbindd[31260]:               info1: struct secrets_domain_info1
Oct  8 13:14:10 98NAS1 winbindd[31260]:                   reserved_flags           : 0x0000000000000000 (0)
Oct  8 13:14:10 98NAS1 winbindd[31260]:                   join_time                : NTTIME(0)
Oct  8 13:14:10 98NAS1 winbindd[31260]:                   computer_name            : '98NAS1'
Oct  8 13:14:10 98NAS1 winbindd[31260]:                   account_name             : '98NAS1$'
Oct  8 13:14:10 98NAS1 winbindd[31260]:                   secure_channel_type      : SEC_CHAN_WKSTA (2)
Oct  8 13:14:10 98NAS1 winbindd[31260]:                   domain_info: struct lsa_DnsDomainInfo
Oct  8 13:14:10 98NAS1 winbindd[31260]:                       name: struct lsa_StringLarge
Oct  8 13:14:10 98NAS1 winbindd[31260]:                           length                   : 0x000e (14)
Oct  8 13:14:10 98NAS1 winbindd[31260]:                           size                     : 0x0010 (16)
Oct  8 13:14:10 98NAS1 winbindd[31260]:                           string                   : *
Oct  8 13:14:10 98NAS1 winbindd[31260]:                               string                   : 'MYDOMAIN'
Oct  8 13:14:10 98NAS1 winbindd[31260]:                       dns_domain: struct lsa_StringLarge
Oct  8 13:14:10 98NAS1 winbindd[31260]:                           length                   : 0x001a (26)
Oct  8 13:14:10 98NAS1 winbindd[31260]:                           size                     : 0x001c (28)
Oct  8 13:14:10 98NAS1 winbindd[31260]:                           string                   : *
Oct  8 13:14:10 98NAS1 winbindd[31260]:                               string                   : 'mydomain.local'
Oct  8 13:14:10 98NAS1 winbindd[31260]:                   trust_flags              : 0x0000001a (26)
Oct  8 13:14:10 98NAS1 winbindd[31260]:                          1: NETR_TRUST_FLAG_OUTBOUND
Oct  8 13:14:10 98NAS1 winbindd[31260]:                          0: NETR_TRUST_FLAG_TREEROOT
Oct  8 13:14:10 98NAS1 winbindd[31260]:                          1: NETR_TRUST_FLAG_PRIMARY 
Oct  8 13:14:10 98NAS1 winbindd[31260]:                          1: NETR_TRUST_FLAG_NATIVE   
Oct  8 13:14:10 98NAS1 winbindd[31260]:                          0: NETR_TRUST_FLAG_INBOUND 
Oct  8 13:14:10 98NAS1 winbindd[31260]:                          0: NETR_TRUST_FLAG_MIT_KRB5
Oct  8 13:14:10 98NAS1 winbindd[31260]:                          0: NETR_TRUST_FLAG_AES     
Oct  8 13:14:10 98NAS1 winbindd[31260]:                   trust_type               : LSA_TRUST_TYPE_UPLEVEL (2)
Oct  8 13:14:10 98NAS1 winbindd[31260]:                   trust_attributes         : 0x00000040 (64)
Oct  8 13:14:10 98NAS1 winbindd[31260]:                                   salt_data                : *
Oct  8 13:14:10 98NAS1 winbindd[31260]:                                   num_keys                 : 0x0004 (4)
Oct  8 13:14:10 98NAS1 winbindd[31260]:                                   keys: ARRAY(4)
Oct  8 13:14:10 98NAS1 winbindd[31260]:                                       keys: struct secrets_domain_info1_kerberos_key
Oct  8 13:14:10 98NAS1 winbindd[31260]:                                           iteration_count          : 0x00001000 (4096)
Oct  8 13:14:10 98NAS1 winbindd[31260]:                                           value                    : DATA_BLOB length=32
Oct  8 13:14:10 98NAS1 winbindd[31260]:                                       keys: struct secrets_domain_info1_kerberos_key
Oct  8 13:14:10 98NAS1 winbindd[31260]:                                   value                    : DATA_BLOB length=16
Oct  8 13:14:10 98NAS1 winbindd[31260]:                                   keytype                  : 0x00000017 (23)
Oct  8 13:14:10 98NAS1 winbindd[31260]:                                   iteration_count          : 0x00001000 (4096)
Oct  8 13:14:10 98NAS1 winbindd[31260]:                                   value                    : DATA_BLOB length=16
Oct  8 13:14:10 98NAS1 winbindd[31260]:                       old_password: struct secrets_domain_info1_password
Oct  8 13:14:10 98NAS1 winbindd[31260]:                               salt_data                : 'MYDOMAIN.LOCALhost98nas1.mydomain.local'
Oct  8 13:14:10 98NAS1 winbindd[31260]:                           default_iteration_count  : 0x00001000 (4096)
Oct  8 13:14:10 98NAS1 winbindd[31260]:                           num_keys                 : 0x0004 (4)
Oct  8 13:14:10 98NAS1 winbindd[31260]:                               keys: struct secrets_domain_info1_kerberos_key
Oct  8 13:14:10 98NAS1 winbindd[31260]:                                   iteration_count          : 0x00001000 (4096)
Oct  8 13:14:10 98NAS1 winbindd[31260]:                                   value                    : DATA_BLOB length=32
Oct  8 13:14:10 98NAS1 winbindd[31260]:                               keys: struct secrets_domain_info1_kerberos_key
Oct  8 13:14:10 98NAS1 winbindd[31260]:                                   iteration_count          : 0x00001000 (4096)
Oct  8 13:14:10 98NAS1 winbindd[31260]: [2019/10/08 13:14:10.168240,  0] ../source3/libsmb/trusts_util.c:381(trust_pw_change)
Oct  8 13:14:10 98NAS1 winbindd[31260]:   2019/10/08 13:14:10 : trust_pw_change(MYDOMAIN): Verifying passwords remotely netlogon_creds_cli:CLI[98NAS1/98NAS1$]/SRV[98SERVER1/MYDOMAIN].
Oct  8 13:14:10 98NAS1 winbindd[31260]: [2019/10/08 13:14:10.170266,  0] ../source3/libsmb/trusts_util.c:453(trust_pw_change)
Oct  8 13:14:10 98NAS1 winbindd[31260]:   2019/10/08 13:14:10 : trust_pw_change(MYDOMAIN): Verified old password remotely using netlogon_creds_cli:CLI[98NAS1/98NAS1$]/SRV[98SERVER1/MYDOMAIN]
Oct  8 13:14:10 98NAS1 winbindd[31260]: [2019/10/08 13:14:10.170321,  0] ../source3/libsmb/trusts_util.c:492(trust_pw_change)
Oct  8 13:14:10 98NAS1 winbindd[31260]:   2019/10/08 13:14:10 : trust_pw_change(MYDOMAIN): Changed password locally
Oct  8 13:14:10 98NAS1 winbindd[31260]: [2019/10/08 13:14:10.286863,  0] ../source3/libsmb/trusts_util.c:546(trust_pw_change)
Oct  8 13:14:10 98NAS1 winbindd[31260]:   2019/10/08 13:14:10 : trust_pw_change(MYDOMAIN): Changed password remotely using netlogon_creds_cli:CLI[98NAS1/98NAS1$]/SRV[98SERVER1/MYDOMAIN]
Oct  8 13:14:10 98NAS1 winbindd[31260]: [2019/10/08 13:14:10.287040,  1] ../librpc/ndr/ndr.c:422(ndr_print_debug)
Oct  8 13:14:10 98NAS1 winbindd[31260]:        finish_change: struct secrets_domain_infoB
Oct  8 13:14:10 98NAS1 winbindd[31260]:           version                  : SECRETS_DOMAIN_INFO_VERSION_1 (1)
Oct  8 13:14:10 98NAS1 winbindd[31260]:           reserved                 : 0x00000000 (0)
Oct  8 13:14:10 98NAS1 winbindd[31260]:           info                     : union secrets_domain_infoU(case 1)
Oct  8 13:14:10 98NAS1 winbindd[31260]:           info1                    : *
Oct  8 13:14:10 98NAS1 winbindd[31260]:               info1: struct secrets_domain_info1
Oct  8 13:14:10 98NAS1 winbindd[31260]:                   reserved_flags           : 0x0000000000000000 (0)
Oct  8 13:14:10 98NAS1 winbindd[31260]:                   join_time                : NTTIME(0)
Oct  8 13:14:10 98NAS1 winbindd[31260]:                   computer_name            : '98NAS1'
Oct  8 13:14:10 98NAS1 winbindd[31260]:                   account_name             : '98NAS1$'
Oct  8 13:14:10 98NAS1 winbindd[31260]:                   secure_channel_type      : SEC_CHAN_WKSTA (2)
Oct  8 13:14:10 98NAS1 winbindd[31260]:                   domain_info: struct lsa_DnsDomainInfo
Oct  8 13:14:10 98NAS1 winbindd[31260]:                       name: struct lsa_StringLarge
Oct  8 13:14:10 98NAS1 winbindd[31260]:                           length                   : 0x000e (14)
Oct  8 13:14:10 98NAS1 winbindd[31260]:                           size                     : 0x0010 (16)
Oct  8 13:14:10 98NAS1 winbindd[31260]:                           string                   : *
Oct  8 13:14:10 98NAS1 winbindd[31260]:                               string                   : 'MYDOMAIN'
Oct  8 13:14:10 98NAS1 winbindd[31260]:                       dns_domain: struct lsa_StringLarge
Oct  8 13:14:10 98NAS1 winbindd[31260]:                           length                   : 0x001a (26)
Oct  8 13:14:10 98NAS1 winbindd[31260]:                           size                     : 0x001c (28)
Oct  8 13:14:10 98NAS1 winbindd[31260]:                           string                   : *
Oct  8 13:14:10 98NAS1 winbindd[31260]:                               string                   : 'mydomain.local'
Oct  8 13:14:10 98NAS1 winbindd[31260]:                       dns_forest: struct lsa_StringLarge
Oct  8 13:14:10 98NAS1 winbindd[31260]:                           length                   : 0x001a (26)
Oct  8 13:14:10 98NAS1 winbindd[31260]:                           size                     : 0x001c (28)
Oct  8 13:14:10 98NAS1 winbindd[31260]:                           string                   : *
Oct  8 13:14:10 98NAS1 winbindd[31260]:                               string                   : 'mydomain.local'
Oct  8 13:14:10 98NAS1 winbindd[31260]:                          0: KERB_ENCTYPE_AES128_CTS_HMAC_SHA1_96
Oct  8 13:14:10 98NAS1 winbindd[31260]:                          0: KERB_ENCTYPE_COMPOUND_IDENTITY_SUPPORTED
Oct  8 13:14:10 98NAS1 winbindd[31260]:                          0: KERB_ENCTYPE_CLAIMS_SUPPORTED
Oct  8 13:14:10 98NAS1 winbindd[31260]:                          0: KERB_ENCTYPE_RESOURCE_SID_COMPRESSION_DISABLED
Oct  8 13:14:10 98NAS1 winbindd[31260]:                   password_last_change     : Tue Oct  8 13:14:10 2019 EDT
Oct  8 13:14:10 98NAS1 winbindd[31260]:                               keys: struct secrets_domain_info1_kerberos_key
Oct  8 13:14:10 98NAS1 winbindd[31260]:                                   iteration_count          : 0x00001000 (4096)
Oct  8 13:14:10 98NAS1 winbindd[31260]:                                   value                    : DATA_BLOB length=16
Oct  8 13:14:10 98NAS1 winbindd[31260]:                                   iteration_count          : 0x00001000 (4096)
Oct  8 13:14:10 98NAS1 winbindd[31260]:                                   value                    : DATA_BLOB length=8
Oct  8 13:14:10 98NAS1 winbindd[31260]:                   old_password             : *
Oct  8 13:14:10 98NAS1 winbindd[31260]:                       old_password: struct secrets_domain_info1_password
Oct  8 13:14:10 98NAS1 winbindd[31260]:                           change_time              : Tue Oct  1 13:14:10 2019 EDT
Oct  8 13:14:10 98NAS1 winbindd[31260]:                           cleartext_blob           : DATA_BLOB length=400
Oct  8 13:14:10 98NAS1 winbindd[31260]:                               salt_data                : 'MYDOMAIN.LOCALhost98nas1.mydomain.local'
Oct  8 13:14:10 98NAS1 winbindd[31260]:                           num_keys                 : 0x0004 (4)
Oct  8 13:14:10 98NAS1 winbindd[31260]:                           keys: ARRAY(4)
Oct  8 13:14:10 98NAS1 winbindd[31260]:                               keys: struct secrets_domain_info1_kerberos_key
Oct  8 13:14:10 98NAS1 winbindd[31260]:                                   keytype                  : 0x00000012 (18)
Oct  8 13:14:10 98NAS1 winbindd[31260]:                                   iteration_count          : 0x00001000 (4096)
Oct  8 13:14:10 98NAS1 winbindd[31260]:                                   value                    : DATA_BLOB length=32
Oct  8 13:14:10 98NAS1 winbindd[31260]:                               keys: struct secrets_domain_info1_kerberos_key
Oct  8 13:14:10 98NAS1 winbindd[31260]:                                   keytype                  : 0x00000011 (17)
Oct  8 13:14:10 98NAS1 winbindd[31260]:                                   iteration_count          : 0x00001000 (4096)
Oct  8 13:14:10 98NAS1 winbindd[31260]:                                   value                    : DATA_BLOB length=16
Oct  8 13:14:10 98NAS1 winbindd[31260]: [2019/10/08 13:14:10.290808,  0] ../source3/libsmb/trusts_util.c:565(trust_pw_change)
Oct  8 13:14:10 98NAS1 winbindd[31260]:   2019/10/08 13:14:10 : trust_pw_change(MYDOMAIN): Finished password change.
Oct  8 13:14:10 98NAS1 winbindd[31260]: [2019/10/08 13:14:10.292223,  0] ../source3/libsmb/trusts_util.c:618(trust_pw_change)
Oct  8 13:14:10 98NAS1 winbindd[31260]:   2019/10/08 13:14:10 : trust_pw_change(MYDOMAIN): Verified new password remotely using netlogon_creds_cli:CLI[98NAS1/98NAS1$]/SRV[98SERVER1/MYDOMAIN]
Oct  8 13:20:48 98NAS1 smbd[3612]: [2019/10/08 13:20:48.408401,  2] ../source3/smbd/server.c:807(remove_child_pid)
Oct  8 13:20:48 98NAS1 smbd[3612]:   Could not find child 70060 -- ignoring
Oct  8 13:30:43 98NAS1 winbindd[31260]: [2019/10/08 13:30:43.979388,  0] ../source3/libads/kerberos_util.c:74(ads_kinit_password)
Oct  8 13:30:43 98NAS1 winbindd[31260]:   kerberos_kinit_password 98NAS1$@MYDOMAIN.LOCAL failed: Preauthentication failed
Oct  8 13:30:43 98NAS1 winbindd[31260]: [2019/10/08 13:30:43.979453,  1] ../source3/libads/sasl.c:781(ads_sasl_spnego_bind)
Oct  8 13:30:43 98NAS1 winbindd[31260]:   ads_sasl_spnego_gensec_bind(KRB5) failed for ldap/98server1.mydomain.local with user[98NAS1$] realm[MYDOMAIN.LOCAL]: Preauthentication failed, fallback to NTLMSSP
Oct  8 13:30:43 98NAS1 winbindd[31260]: [2019/10/08 13:30:43.981656,  1] ../source3/libads/sasl.c:800(ads_sasl_spnego_bind)
Oct  8 13:30:43 98NAS1 winbindd[31260]:   ads_sasl_spnego_gensec_bind(NTLMSSP) failed for ldap/98server1.mydomain.local with user[98NAS1$] realm=[MYDOMAIN.LOCAL]: Invalid credentials
Oct  8 13:30:43 98NAS1 winbindd[31260]: [2019/10/08 13:30:43.981736,  1] ../source3/libads/ldap_utils.c:111(ads_do_search_retry_internal)
Oct  8 13:30:43 98NAS1 winbindd[31260]:   ads_search_retry: failed to reconnect (Invalid credentials)
 

Pmantis

Dabbler
Joined
Mar 11, 2015
Messages
19
I should probably mention that wbinfo -g properly returns group information, so I don't think there's an issue with the connectivity or syncing. Seems to be just a temporary issue.
 

anodos

Sambassador
iXsystems
Joined
Mar 6, 2014
Messages
9,554
Is this an RODC? How many DCs do you have? It looks like at 1310 FreeNAS updated its trust credentials, but then at 1330 the DC rejected the new credentials. If you don't feel like debugging the issue or aren't concerned about security implications, you can adjust "machine account password timeout" https://www.samba.org/samba/docs/current/man-html/smb.conf.5.html#MACHINEPASSWORDTIMEOUT. This parameter can be added as an auxiliary parameter under Services->SMB.
 

Pmantis

Dabbler
Joined
Mar 11, 2015
Messages
19
Only one domain controller for this customer. As a matter of fact, it's the only Windows server! There's 2 FreeNAS boxes serving files. I'm thinking of adding a second DC just for redundancy.
I'll look at the link you shared. Thank you!
 
Top