Jira (PUP-10885) Race-condition in service resource

[David Schmitt (Jira)]

Title: Message Title

David Schmitt created an issue   Puppet / PUP-10885 Race-condition in service resource Issue Type: Bug Assignee: Unassigned Attachments: wsusclient-service-errors.json Components: Types and Providers Created: 2021/02/03 2:21 AM Priority: Normal Reporter: David Schmitt Puppet Version: latest puppet5; puppet6 nightlies Puppet Server Version: n/a OS Name/Version: windows during wsus_client acceptance testing, approximately 10% of all tries to manage the wuauserv service fail with the service resource being confused about the state transitions of the service: Error: /Stage[main]/Wsus_client/Service[wuauserv]: Failed to call refresh: Failed to transition the wuauserv service to the SERVICE_STOPPED state. Detail: Unexpected transition to the SERVICE_RUNNING state while waiting for the pending transition from SERVICE_STOP_PENDING to SERVICE_STOPPED to finish. Error: /Stage[main]/Wsus_client/Service[wuauserv]: Failed to transition the wuauserv service to the SERVICE_STOPPED state. Detail: Unexpected transition to the SERVICE_RUNNING state while waiting for the pending transition from SERVICE_STOP_PENDING to SERVICE_STOPPED to finish. C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util/windows/service.rb:940:in `block (2 levels) in wait_on_pending_state' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util/windows/service.rb:735:in `block (2 levels) in query_status' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util/windows/service.rb:723:in `initialize' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util/windows/service.rb:723:in `new' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util/windows/service.rb:723:in `block in query_status' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util/windows/service.rb:712:in `initialize' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util/windows/service.rb:712:in `new' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util/windows/service.rb:712:in `query_status' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util/windows/service.rb:931:in `block in wait_on_pending_state' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util/windows/service.rb:930:in `loop' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util/windows/service.rb:930:in `wait_on_pending_state' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util/windows/service.rb:898:in `block in wait_on_state_transition' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util/windows/service.rb:735:in `block (2 levels) in query_status' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util/windows/service.rb:723:in `initialize' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util/windows/service.rb:723:in `new' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util/windows/service.rb:723:in `block in query_status' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util/windows/service.rb:712:in `initialize' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util/windows/service.rb:712:in `new' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util/windows/service.rb:712:in `query_status' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util/windows/service.rb:893:in `wait_on_state_transition' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util/windows/service.rb:690:in `block (2 levels) in transition_service_state' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util/windows/service.rb:735:in `block (2 levels) in query_status' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util/windows/service.rb:723:in `initialize' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util/windows/service.rb:723:in `new' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util/windows/service.rb:723:in `block in query_status' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util/windows/service.rb:712:in `initialize' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util/windows/service.rb:712:in `new' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util/windows/service.rb:712:in `query_status' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util/windows/service.rb:636:in `block in transition_service_state' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util/windows/service.rb:602:in `block in open_service' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util/windows/service.rb:619:in `open_scm' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util/windows/service.rb:599:in `open_service' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util/windows/service.rb:635:in `transition_service_state' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util/windows/service.rb:365:in `stop' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/provider/service/windows.rb:90:in `stop' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/provider/service/service.rb:13:in `restart' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/type/service.rb:314:in `refresh' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/transaction/event_manager.rb:149:in `process_callback' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/transaction/event_manager.rb:34:in `block in process_events' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/transaction/event_manager.rb:121:in `block in queued_events' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/transaction/event_manager.rb:120:in `each' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/transaction/event_manager.rb:120:in `queued_events' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/transaction/event_manager.rb:33:in `process_events' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/transaction.rb:288:in `eval_resource' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/transaction.rb:191:in `call' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/transaction.rb:191:in `block (2 levels) in evaluate' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util.rb:546:in `block in thinmark' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/2.5.0/benchmark.rb:308:in `realtime' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util.rb:545:in `thinmark' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/transaction.rb:191:in `block in evaluate' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/graph/relationship_graph.rb:122:in `traverse' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/transaction.rb:178:in `evaluate' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/resource/catalog.rb:240:in `block (2 levels) in apply' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util.rb:546:in `block in thinmark' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/2.5.0/benchmark.rb:308:in `realtime' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util.rb:545:in `thinmark' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/resource/catalog.rb:239:in `block in apply' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util/log.rb:161:in `with_destination' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/transaction/report.rb:148:in `as_logging_destination' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/resource/catalog.rb:238:in `apply' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/configurer.rb:193:in `block (2 levels) in apply_catalog' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util.rb:546:in `block in thinmark' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/2.5.0/benchmark.rb:308:in `realtime' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util.rb:545:in `thinmark' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/configurer.rb:192:in `block in apply_catalog' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util.rb:233:in `block in benchmark' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/2.5.0/benchmark.rb:308:in `realtime' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util.rb:232:in `benchmark' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/configurer.rb:191:in `apply_catalog' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/configurer.rb:433:in `run_internal' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/configurer.rb:248:in `block in run' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/context.rb:62:in `override' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet.rb:314:in `override' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/configurer.rb:218:in `run' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/application/apply.rb:342:in `apply_catalog' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/application/apply.rb:254:in `block in main' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/context.rb:62:in `override' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet.rb:314:in `override' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/application/apply.rb:208:in `main' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/application/apply.rb:178:in `run_command' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/application.rb:382:in `block in run' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util.rb:735:in `exit_on_fail' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/application.rb:382:in `run' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util/command_line.rb:143:in `run' C:/Program Files/Puppet Labs/Puppet/puppet/lib/ruby/vendor_ruby/puppet/util/command_line.rb:77:in `execute' C:/Program Files/Puppet Labs/Puppet/puppet/bin/puppet:4:in `<main>' This happens sometimes on the first test in the sequence (maybe because of interference with bootup sequence) and sometimes on a later test group (maybe because of service still starting from previous test). Desired Behavior: service resource on windows successfully manages service state in all situations. Actual Behavior: service resource on windows is interrupted by unexpected state changes and causes transient errors. attached a log of all test failures over the last two months. Check this query for full details (request access) Add Comment   This message was sent by Atlassian Jira (v8.5.2#805002-sha1:a66f935) -- 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 view this discussion on the web visit https://groups.google.com/d/msgid/puppet-bugs/JIRA.385969.1612347692000.131709.1612347720054%40Atlassian.JIRA.