1505455 - time sync is failing on windows 7 workers

Status: RESOLVED FIXED

(Infrastructure & Operations :: RelOps: OpenCloudConfig, task)

Description

[Rob Thijssen [:grenade (EET/UTC+0300)]]

the time service fails to start after the tyme sync commands are issued. pt logs look like this:

- https://papertrailapp.com/systems/i-0eccb07d9b1f2ce4c.gecko-t-win7-32.usw2.mozilla.com/events
- https://papertrailapp.com/systems/i-095f4bc4ca7cadd68.gecko-t-win7-32-gpu.usw2.mozilla.com/events

Nov 07 17:41:36 i-095f4bc4ca7cadd68.gecko-t-win7-32-gpu.usw2.mozilla.com Microsoft-Windows-WMI: Event filter with query "SELECT * FROM __InstanceModificationEvent WITHIN 60 WHERE TargetInstance ISA "Win32_Processor" AND TargetInstance.LoadPercentage > 99" could not be reactivated in namespace "//./root/CIMV2" because of error 0x80041003. Events cannot be delivered through this filter until the problem is corrected. 
Nov 07 17:41:40 i-095f4bc4ca7cadd68.gecko-t-win7-32-gpu.usw2.mozilla.com Microsoft-Windows-CAPI2: Failed extract of third-party root list from auto update cab at: <http://www.download.windowsupdate.com/msdownload/update/v3/static/trustedr/en/authrootstl.cab> with error: A required certificate is not within its validity period when verifying against the current system clock or the timestamp in the signed file.  . 
Nov 07 17:42:05 i-095f4bc4ca7cadd68.gecko-t-win7-32-gpu.usw2.mozilla.com OpenCloudConfig: Run-OpenCloudConfig :: begin - 2018-11-07T15:42:03.8643000Z 
Nov 07 17:42:05 i-095f4bc4ca7cadd68.gecko-t-win7-32-gpu.usw2.mozilla.com OpenCloudConfig: Set-DefaultStrongCryptography :: begin - 2018-11-07T15:42:03.9891000Z 
Nov 07 17:42:05 i-095f4bc4ca7cadd68.gecko-t-win7-32-gpu.usw2.mozilla.com OpenCloudConfig: Set-DefaultStrongCryptography :: CLRVersion: 4.0.30319.34209, PSVersion: 5.0.10586.117 
Nov 07 17:42:05 i-095f4bc4ca7cadd68.gecko-t-win7-32-gpu.usw2.mozilla.com OpenCloudConfig: Set-DefaultStrongCryptography :: SecurityProtocol: Tls, Tls11, Tls12 
Nov 07 17:42:05 i-095f4bc4ca7cadd68.gecko-t-win7-32-gpu.usw2.mozilla.com OpenCloudConfig: Set-DefaultStrongCryptography :: Detected TLS v1.2 in security protocol support list 
Nov 07 17:42:05 i-095f4bc4ca7cadd68.gecko-t-win7-32-gpu.usw2.mozilla.com OpenCloudConfig: Set-DefaultStrongCryptography :: Detected registry setting to use strong cryptography on 32 bit .Net Framework 
Nov 07 17:42:05 i-095f4bc4ca7cadd68.gecko-t-win7-32-gpu.usw2.mozilla.com OpenCloudConfig: Set-DefaultStrongCryptography :: SecurityProtocol: Tls, Tls11, Tls12 
Nov 07 17:42:05 i-095f4bc4ca7cadd68.gecko-t-win7-32-gpu.usw2.mozilla.com OpenCloudConfig: Set-DefaultStrongCryptography :: end - 2018-11-07T15:42:04.0671000Z 
Nov 07 17:42:05 i-095f4bc4ca7cadd68.gecko-t-win7-32-gpu.usw2.mozilla.com OpenCloudConfig: Set-NetworkRoutes :: begin - 2018-11-07T15:42:04.0827000Z 
Nov 07 17:42:06 i-095f4bc4ca7cadd68.gecko-t-win7-32-gpu.usw2.mozilla.com OpenCloudConfig: Set-NetworkRoutes :: skipping network route correction (not configured for OS: Microsoft Windows 7 Enterprise N ). 
Nov 07 17:42:06 i-095f4bc4ca7cadd68.gecko-t-win7-32-gpu.usw2.mozilla.com OpenCloudConfig: Set-NetworkRoutes :: end - 2018-11-07T15:42:04.1139000Z 
Nov 07 17:42:06 i-095f4bc4ca7cadd68.gecko-t-win7-32-gpu.usw2.mozilla.com OpenCloudConfig: Set-ServiceState :: begin - 2018-11-07T15:42:04.1139000Z 
Nov 07 17:42:06 i-095f4bc4ca7cadd68.gecko-t-win7-32-gpu.usw2.mozilla.com OpenCloudConfig: Set-ServiceState :: wuauserv service state: Stopped. 
Nov 07 17:42:06 i-095f4bc4ca7cadd68.gecko-t-win7-32-gpu.usw2.mozilla.com OpenCloudConfig: Set-ServiceState :: wuauserv service state: Running. 
Nov 07 17:42:06 i-095f4bc4ca7cadd68.gecko-t-win7-32-gpu.usw2.mozilla.com OpenCloudConfig: Set-ServiceState :: end - 2018-11-07T15:42:04.4103000Z 
Nov 07 17:42:06 i-095f4bc4ca7cadd68.gecko-t-win7-32-gpu.usw2.mozilla.com OpenCloudConfig: Run-OpenCloudConfig :: userdata run starting. 
Nov 07 17:42:06 i-095f4bc4ca7cadd68.gecko-t-win7-32-gpu.usw2.mozilla.com OpenCloudConfig: Set-SystemClock :: begin - 2018-11-07T15:42:04.5039000Z 
Nov 07 17:42:06 i-095f4bc4ca7cadd68.gecko-t-win7-32-gpu.usw2.mozilla.com OpenCloudConfig: Set-SystemClock :: w32time service status: Stopped 
Nov 07 17:42:06 i-095f4bc4ca7cadd68.gecko-t-win7-32-gpu.usw2.mozilla.com OpenCloudConfig: Set-SystemClock :: system timezone set to UTC. 
Nov 07 17:42:06 i-095f4bc4ca7cadd68.gecko-t-win7-32-gpu.usw2.mozilla.com OpenCloudConfig: Set-SystemClock :: time service unregistered. 
Nov 07 17:42:07 i-095f4bc4ca7cadd68.gecko-t-win7-32-gpu.usw2.mozilla.com OpenCloudConfig: Set-SystemClock :: time service registered. 
Nov 07 17:42:07 i-095f4bc4ca7cadd68.gecko-t-win7-32-gpu.usw2.mozilla.com OpenCloudConfig: Set-SystemClock :: time service configured with peerlist: 0.pool.ntp.org 1.pool.ntp.org 2.pool.ntp.org 3.pool.ntp.org 
Nov 07 17:42:07 i-095f4bc4ca7cadd68.gecko-t-win7-32-gpu.usw2.mozilla.com OpenCloudConfig: Set-ServiceState :: begin - 2018-11-07T15:42:05.6583000Z 
Nov 07 17:42:07 i-095f4bc4ca7cadd68.gecko-t-win7-32-gpu.usw2.mozilla.com OpenCloudConfig: Set-ServiceState :: w32time service state: Stopped. 
Nov 07 17:42:07 i-095f4bc4ca7cadd68.gecko-t-win7-32-gpu.usw2.mozilla.com Microsoft-Windows-Time-Service: The time service encountered an error while reading its configuration from the registry and cannot start. The error was: Dzhe system cannot find the file specified. (0x80070002) 
Nov 07 17:42:07 i-095f4bc4ca7cadd68.gecko-t-win7-32-gpu.usw2.mozilla.com Microsoft-Windows-Time-Service: <11>1 2018-11-07T15:42:05.658300+00:00 i-095f4bc4ca7cadd68.gecko-t-win7-32-gpu.usw2.mozilla.com Microsoft-Windows-Time-Service 1232 - [NXLOG@14506 Keywords="-9223372036854775808" EventType="ERROR" EventID="46" ProviderGuid="{06EDCFEB-0FD0-4E53-ACCA-A6F8BBF81BCB}" Version="0" Task="0" OpcodeValue="0" RecordNumber="4178" ThreadID="3120" Channel="System" Domain="NT AUTHORITY" AccountName="LOCAL SERVICE" UserID="S-1-5-19" AccountType="Well Known Group" Opcode="Info" ErrorMessage="0x80070002: The system cannot find the file specified. 
Nov 07 17:42:07 i-095f4bc4ca7cadd68.gecko-t-win7-32-gpu.usw2.mozilla.com Microsoft-Windows-Time-Service: " EventReceivedTime="2018-11-07 15:42:06" SourceModuleName="eventlog" SourceModuleType="im_msvistalog"] The time service encountered an error and was forced to shut down. The error was: 0x80070002: The system cannot find the file specified.   
Nov 07 17:42:07 i-095f4bc4ca7cadd68.gecko-t-win7-32-gpu.usw2.mozilla.com Service_Control_Manager: The Windows Time service terminated with the following error:   The system cannot find the file specified. 
Nov 07 17:46:43 i-095f4bc4ca7cadd68.gecko-t-win7-32-gpu.usw2.mozilla.com Microsoft-Windows-Security-SPP: Failed to schedule Software Protection service for re-start at 2018-12-07T15:29:41Z. Error Code: 0x80070005.

Comment 1

[Rob Thijssen [:grenade (EET/UTC+0300)]]

fixed by retrying after running:
`sc config w32time type= own`
https://github.com/mozilla-releng/OpenCloudConfig/commit/a260579306e7a4ae50ee64e9cf33863d94d56d74