[PUP-6254] Windows Service start reports failures instead of success under some states Created: 2016/05/02  Updated: 2018/09/06  Resolved: 2018/09/06

Status: Closed
Project: Puppet
Component/s: None
Affects Version/s: None
Fix Version/s: None

Type: Bug Priority: Normal
Reporter: Glenn Sarti Assignee: Unassigned
Resolution: Duplicate Votes: 0
Labels: service, transitional-service-states, type_and_provider, windows
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Blocks
is blocked by PUP-5475 Windows Service provider should use s... Closed
Relates
relates to MODULES-7696 Problem with wsus_client trying to re... Open
relates to PUP-5475 Windows Service provider should use s... Closed
Template:
Epic Link: WINning
Team: Platform OS

 Description   

During FM-5175, the WSUS_Client module failed acceptance tests intermittently due to a service start failure;

16:23:14 Failures:
16:23:14 
16:23:14   1) wsus_client auto_update_option => notifyonly 
16:23:14      Failure/Error: apply_manifest_on(default, pp, :catch_failures => true)
16:23:14      Beaker::Host::CommandFailure:
16:23:14        Host 't2jesxgwkw2uecz.delivery.puppetlabs.net' exited with 6 running:
16:23:14         cmd.exe /c puppet apply --verbose --detailed-exitcodes C:/cygwin64/tmp/apply_manifest.pp.kuNup0
16:23:14        Last 10 lines of output were:
16:23:14        	Notice: /Stage[main]/Wsus_client/Registry_key[HKLM\Software\Policies\Microsoft\Windows\WindowsUpdate\AU]/ensure: created
16:23:14        	Notice: /Stage[main]/Wsus_client/Wsus_client::Setting[HKLM\Software\Policies\Microsoft\Windows\WindowsUpdate\AU\AUOptions]/Registry_value[HKLM\Software\Policies\Microsoft\Windows\WindowsUpdate\AU\AUOptions]/ensure: created
16:23:14        	Info: /Stage[main]/Wsus_client/Wsus_client::Setting[HKLM\Software\Policies\Microsoft\Windows\WindowsUpdate\AU\AUOptions]/Registry_value[HKLM\Software\Policies\Microsoft\Windows\WindowsUpdate\AU\AUOptions]: Scheduling refresh of Service[wuauserv]
16:23:14        	Notice: /Stage[main]/Wsus_client/Service[wuauserv]: Triggered 'refresh' from 1 events
16:23:14        	Info: Class[Wsus_client]: Unscheduling all events on Class[Wsus_client]
16:23:14        	Error: Cannot start wuauserv, error was: Execution of 'C:/Windows/system32/net.exe start wuauserv' returned 2: The service is starting or stopping.  Please try again later.
16:23:14        	Wrapped exception:
16:23:14        	Execution of 'C:/Windows/system32/net.exe start wuauserv' returned 2: The service is starting or stopping.  Please try again later.
16:23:14        	Error: /Stage[main]/Wsus_client/Service[wuauserv]/ensure: change from stopped to running failed: Cannot start wuauserv, error was: Execution of 'C:/Windows/system32/net.exe start wuauserv' returned 2: The service is starting or stopping.  Please try again later.
16:23:14        	Notice: Applied catalog in 4.96 seconds
16:23:14        
16:23:14      # ./vendor/gems/gems/beaker-2.40.0/lib/beaker/host.rb:331:in `exec'
16:23:14      # ./vendor/gems/gems/beaker-2.40.0/lib/beaker/dsl/helpers/host_helpers.rb:78:in `block in on'
16:23:14      # ./vendor/gems/gems/beaker-2.40.0/lib/beaker/shared/host_manager.rb:115:in `run_block_on'
16:23:14      # ./vendor/gems/gems/beaker-2.40.0/lib/beaker/dsl/patterns.rb:35:in `block_on'
16:23:14      # ./vendor/gems/gems/beaker-2.40.0/lib/beaker/dsl/helpers/host_helpers.rb:63:in `on'
16:23:14      # ./vendor/gems/gems/beaker-2.40.0/lib/beaker/dsl/helpers/puppet_helpers.rb:469:in `block in apply_manifest_on'
16:23:14      # ./vendor/gems/gems/beaker-2.40.0/lib/beaker/shared/host_manager.rb:115:in `run_block_on'
16:23:14      # ./vendor/gems/gems/beaker-2.40.0/lib/beaker/dsl/patterns.rb:35:in `block_on'
16:23:14      # ./vendor/gems/gems/beaker-2.40.0/lib/beaker/dsl/helpers/puppet_helpers.rb:398:in `apply_manifest_on'
16:23:14      # ./spec/acceptance/wsus_client_spec.rb:36:in `create_apply_manifest'
16:23:14      # ./spec/acceptance/wsus_client_spec.rb:140:in `block (5 levels) in <top (required)>'
16:23:14 
16:23:14   2) wsus_client auto_update_option => 3 
16:23:14      Failure/Error: apply_manifest_on(default, pp, :catch_failures => true)
16:23:14      Beaker::Host::CommandFailure:
16:23:14        Host 't2jesxgwkw2uecz.delivery.puppetlabs.net' exited with 6 running:
16:23:14         cmd.exe /c puppet apply --verbose --detailed-exitcodes C:/cygwin64/tmp/apply_manifest.pp.p8MUsq
16:23:14        Last 10 lines of output were:
16:23:14        	Notice: /Stage[main]/Wsus_client/Registry_key[HKLM\Software\Policies\Microsoft\Windows\WindowsUpdate\AU]/ensure: created
16:23:14        	Notice: /Stage[main]/Wsus_client/Wsus_client::Setting[HKLM\Software\Policies\Microsoft\Windows\WindowsUpdate\AU\AUOptions]/Registry_value[HKLM\Software\Policies\Microsoft\Windows\WindowsUpdate\AU\AUOptions]/ensure: created
16:23:14        	Info: /Stage[main]/Wsus_client/Wsus_client::Setting[HKLM\Software\Policies\Microsoft\Windows\WindowsUpdate\AU\AUOptions]/Registry_value[HKLM\Software\Policies\Microsoft\Windows\WindowsUpdate\AU\AUOptions]: Scheduling refresh of Service[wuauserv]
16:23:14        	Notice: /Stage[main]/Wsus_client/Service[wuauserv]: Triggered 'refresh' from 1 events
16:23:14        	Info: Class[Wsus_client]: Unscheduling all events on Class[Wsus_client]
16:23:14        	Error: Cannot start wuauserv, error was: Execution of 'C:/Windows/system32/net.exe start wuauserv' returned 2: The service is starting or stopping.  Please try again later.
16:23:14        	Wrapped exception:
16:23:14        	Execution of 'C:/Windows/system32/net.exe start wuauserv' returned 2: The service is starting or stopping.  Please try again later.
16:23:14        	Error: /Stage[main]/Wsus_client/Service[wuauserv]/ensure: change from stopped to running failed: Cannot start wuauserv, error was: Execution of 'C:/Windows/system32/net.exe start wuauserv' returned 2: The service is starting or stopping.  Please try again later.
16:23:14        	Notice: Applied catalog in 1.11 seconds
16:23:14        
16:23:14      # ./vendor/gems/gems/beaker-2.40.0/lib/beaker/host.rb:331:in `exec'
16:23:14      # ./vendor/gems/gems/beaker-2.40.0/lib/beaker/dsl/helpers/host_helpers.rb:78:in `block in on'
16:23:14      # ./vendor/gems/gems/beaker-2.40.0/lib/beaker/shared/host_manager.rb:115:in `run_block_on'
16:23:14      # ./vendor/gems/gems/beaker-2.40.0/lib/beaker/dsl/patterns.rb:35:in `block_on'
16:23:14      # ./vendor/gems/gems/beaker-2.40.0/lib/beaker/dsl/helpers/host_helpers.rb:63:in `on'
16:23:14      # ./vendor/gems/gems/beaker-2.40.0/lib/beaker/dsl/helpers/puppet_helpers.rb:469:in `block in apply_manifest_on'
16:23:14      # ./vendor/gems/gems/beaker-2.40.0/lib/beaker/shared/host_manager.rb:115:in `run_block_on'
16:23:14      # ./vendor/gems/gems/beaker-2.40.0/lib/beaker/dsl/patterns.rb:35:in `block_on'
16:23:14      # ./vendor/gems/gems/beaker-2.40.0/lib/beaker/dsl/helpers/puppet_helpers.rb:398:in `apply_manifest_on'
16:23:14      # ./spec/acceptance/wsus_client_spec.rb:36:in `create_apply_manifest'
16:23:14      # ./spec/acceptance/wsus_client_spec.rb:134:in `block (5 levels) in <top (required)>'
16:23:14 
16:23:14 Finished in 31 minutes 29 seconds (files took 16 minutes 36 seconds to load)
16:23:14 163 examples, 2 failures

This seems to come from the way puppet starts windows service. The status method converts the various windows service states into the puppet representation;
https://github.com/puppetlabs/puppet/blob/master/lib/puppet/provider/service/windows.rb#L90-L95

However during a start operation, the current status of the service is not queried before a start operation e.g. Issuing a Start to a service that is in the Start_pending state will error when using net.exe

Also. Due to the way the SCM works, a puppet stop operation may still leave a service in a Stop_Pending state. So a subsequent, puppet start operation will fail as it will not wait for the Stop_pending to complete prior to issuing a start command.

It appears that the start and stop operations require more state handling so as to not give false failures.



 Comments   
Comment by Sean McDonald [ 2018/08/21 ]

Blocked by PUP-5475

Comment by Sean McDonald [ 2018/09/06 ]

This should be resolved with the resolution of PUP-5475, tests have been added like https://github.com/puppetlabs/puppet/pull/7017/files#diff-3605a66d10a7037dc84d525509509608R102 that should determine that ensure => running should not fail when the service enters a pending state.

 

For now I'm going to close this issue as a duplicate, and we can re-open this ticket if this behavior appears again after the resolution of PUP-5475

Generated at Thu Nov 14 10:48:28 PST 2019 using JIRA 7.7.1#77002-sha1:e75ca93d5574d9409c0630b81c894d9065296414.