Jira (PUP-6254) Windows Service start reports failures instead of success under some states

[Glenn Sarti (JIRA)]

Title: Message Title

Glenn Sarti created an issue   Puppet / PUP-6254 Windows Service start reports failures instead of success under some states Issue Type: Bug Assignee: Unassigned Created: 2016/05/02 9:28 AM Priority: Normal Reporter: Glenn Sarti 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. Add Comment   This message was sent by Atlassian JIRA (v6.4.13#64028-sha1:b7939e9) -- You received this message because you are subscribed to the Google Groups "Puppet Bugs" group. To unsubscribe from this group and stop receiving emails from it, send an email to puppet-bugs+unsubscr...@googlegroups.com. To post to this group, send email to puppet-bugs@googlegroups.com. Visit this group at https://groups.google.com/group/puppet-bugs. For more options, visit https://groups.google.com/d/optout.