Plugins » Foreman Remote Execution

When the connection gets interrupted we try to repeat several times, but we compare the current iteration number against a non-existent constant.

[2017-10-12 10:09:20.469 #18156] DEBUG -- dynflow: executing script: | sh <<WRAPPER | (/var/tmp/foreman-ssh-cmd-166c69fe-44a8-4563-a3a8-290960cb96f4/script < /dev/null; echo \$?>/var/tmp/foreman-ssh-cmd-166c69fe-44a8-4563-a3a8-290960cb96f4/exit_code) | /usr/bin/tee /var/tmp/foreman-ssh-cmd-166c69fe-44a8-4563-a3a8-290
960cb96f4/output | exit \$(cat /var/tmp/foreman-ssh-cmd-166c69fe-44a8-4563-a3a8-290960cb96f4/exit_code) | WRAPPER

[2017-10-12 10:09:20.471 #18156] DEBUG -- dynflow: refresh runner 166c69fe-44a8-4563-a3a8-290960cb96f4
[2017-10-12 10:09:20.471 #18156] DEBUG -- dynflow: refreshing runner
[2017-10-12 10:09:20.471 #18156] DEBUG -- dynflow: planning to refresh 166c69fe-44a8-4563-a3a8-290960cb96f4
[2017-10-12 10:09:21.472 #18156] DEBUG -- dynflow: Ticker ticking for 1 events
[2017-10-12 10:09:21.472 #18156] DEBUG -- dynflow: refresh runner 166c69fe-44a8-4563-a3a8-290960cb96f4
[2017-10-12 10:09:21.472 #18156] DEBUG -- dynflow: refreshing runner
[2017-10-12 10:09:21.472 #18156] DEBUG -- dynflow: planning to refresh 166c69fe-44a8-4563-a3a8-290960cb96f4
[2017-10-12 10:09:22.473 #18156] DEBUG -- dynflow: Ticker ticking for 1 events
[2017-10-12 10:09:22.473 #18156] DEBUG -- dynflow: refresh runner 166c69fe-44a8-4563-a3a8-290960cb96f4
[2017-10-12 10:09:22.474 #18156] DEBUG -- dynflow: refreshing runner
[2017-10-12 10:09:22.474 #18156] ERROR -- dynflow: Unexpected error: IOError closed stream
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/net-ssh-4.2.0/lib/net/ssh/ruby_compat.rb:20:in `select'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/net-ssh-4.2.0/lib/net/ssh/ruby_compat.rb:20:in `io_select'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/net-ssh-4.2.0/lib/net/ssh/transport/packet_stream.rb:75:in `available_for_read?'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/net-ssh-4.2.0/lib/net/ssh/transport/packet_stream.rb:90:in `next_packet'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/net-ssh-4.2.0/lib/net/ssh/transport/session.rb:193:in `block in poll_message'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/net-ssh-4.2.0/lib/net/ssh/transport/session.rb:188:in `loop'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/net-ssh-4.2.0/lib/net/ssh/transport/session.rb:188:in `poll_message'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/net-ssh-4.2.0/lib/net/ssh/connection/session.rb:544:in `dispatch_incoming_packets'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/net-ssh-4.2.0/lib/net/ssh/connection/session.rb:246:in `ev_preprocess'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/net-ssh-4.2.0/lib/net/ssh/connection/event_loop.rb:99:in `each'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/net-ssh-4.2.0/lib/net/ssh/connection/event_loop.rb:99:in `ev_preprocess'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/net-ssh-4.2.0/lib/net/ssh/connection/event_loop.rb:27:in `process'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/net-ssh-4.2.0/lib/net/ssh/connection/session.rb:225:in `process'
/home/aruzicka/git/foreman-remote-execution/lib/foreman_remote_execution_core/script_runner.rb:67:in `block (2 levels) in refresh'
/home/aruzicka/git/foreman-remote-execution/lib/foreman_remote_execution_core/script_runner.rb:110:in `with_disconnect_handling'
/home/aruzicka/git/foreman-remote-execution/lib/foreman_remote_execution_core/script_runner.rb:66:in `block in refresh'
/home/aruzicka/git/foreman-remote-execution/lib/foreman_remote_execution_core/script_runner.rb:96:in `with_retries'
/home/aruzicka/git/foreman-remote-execution/lib/foreman_remote_execution_core/script_runner.rb:65:in `refresh'
/home/aruzicka/git/foreman-tasks/lib/foreman_tasks_core/runner/base.rb:20:in `run_refresh'
/home/aruzicka/git/foreman-tasks/lib/foreman_tasks_core/runner/dispatcher.rb:40:in `refresh_runner'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/dynflow-0.8.31/lib/dynflow/actor.rb:6:in `on_message'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/context.rb:46:in `on_envelope'
/home/aruzicka/git/foreman-tasks/lib/foreman_tasks_core/runner/dispatcher.rb:24:in `on_envelope'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/executes_context.rb:7:in `on_envelope'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/dynflow-0.8.31/lib/dynflow/actor.rb:26:in `on_envelope'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/awaits.rb:15:in `on_envelope'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/sets_results.rb:14:in `on_envelope'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/buffer.rb:38:in `process_envelope'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/buffer.rb:31:in `process_envelopes?'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/buffer.rb:20:in `on_envelope'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/termination.rb:55:in `on_envelope'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/removes_child.rb:10:in `on_envelope'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/sets_results.rb:14:in `on_envelope'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/core.rb:161:in `process_envelope'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/core.rb:95:in `block in on_envelope'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/core.rb:118:in `block (2 levels) in schedule_execution'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-1.0.5/lib/concurrent/synchronization/mri_lockable_object.rb:38:in `block in synchronize' [8/629]
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-1.0.5/lib/concurrent/synchronization/mri_lockable_object.rb:38:in `synchronize'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-1.0.5/lib/concurrent/synchronization/mri_lockable_object.rb:38:in `synchronize'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/core.rb:115:in `block in schedule_execution'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/serialized_execution.rb:18:in `call'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/serialized_execution.rb:96:in `work'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/serialized_execution.rb:77:in `block in call_job'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/ruby_thread_pool_executor.rb:348:in `run_task'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/ruby_thread_pool_executor.rb:337:in `block (3 levels) in create_worker'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/ruby_thread_pool_executor.rb:320:in `loop'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/ruby_thread_pool_executor.rb:320:in `block (2 levels) in create_worker'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/ruby_thread_pool_executor.rb:319:in `catch'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/ruby_thread_pool_executor.rb:319:in `block in create_worker'
[2017-10-12 10:09:22.474 #18156] DEBUG -- dynflow: planning to refresh 166c69fe-44a8-4563-a3a8-290960cb96f4
[2017-10-12 10:09:22.476 #18156] ERROR -- dynflow: error while dispatching request to runner 166c69fe-44a8-4563-a3a8-290960cb96f4:NameError uninitialized constant ForemanRemoteExecutionCore::ScriptRunner::MAX_PROCESS_RETRIES:
/home/aruzicka/git/foreman-remote-execution/lib/foreman_remote_execution_core/script_runner.rb:100:in `rescue in with_retries'
/home/aruzicka/git/foreman-remote-execution/lib/foreman_remote_execution_core/script_runner.rb:95:in `with_retries'
/home/aruzicka/git/foreman-remote-execution/lib/foreman_remote_execution_core/script_runner.rb:65:in `refresh'
/home/aruzicka/git/foreman-tasks/lib/foreman_tasks_core/runner/base.rb:20:in `run_refresh'
/home/aruzicka/git/foreman-tasks/lib/foreman_tasks_core/runner/dispatcher.rb:40:in `refresh_runner'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/dynflow-0.8.31/lib/dynflow/actor.rb:6:in `on_message'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/context.rb:46:in `on_envelope'
/home/aruzicka/git/foreman-tasks/lib/foreman_tasks_core/runner/dispatcher.rb:24:in `on_envelope'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/executes_context.rb:7:in `on_envelope'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/dynflow-0.8.31/lib/dynflow/actor.rb:26:in `on_envelope'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/awaits.rb:15:in `on_envelope'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/sets_results.rb:14:in `on_envelope'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/buffer.rb:38:in `process_envelope'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/buffer.rb:31:in `process_envelopes?'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/buffer.rb:20:in `on_envelope'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/termination.rb:55:in `on_envelope'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/removes_child.rb:10:in `on_envelope'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/sets_results.rb:14:in `on_envelope'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/core.rb:161:in `process_envelope'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/core.rb:95:in `block in on_envelope'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/core.rb:118:in `block (2 levels) in schedule_execution'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-1.0.5/lib/concurrent/synchronization/mri_lockable_object.rb:38:in `block in synchronize'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-1.0.5/lib/concurrent/synchronization/mri_lockable_object.rb:38:in `synchronize'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-1.0.5/lib/concurrent/synchronization/mri_lockable_object.rb:38:in `synchronize'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/core.rb:115:in `block in schedule_execution'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/serialized_execution.rb:18:in `call'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/serialized_execution.rb:96:in `work'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/serialized_execution.rb:77:in `block in call_job'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/ruby_thread_pool_executor.rb:348:in `run_task'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/ruby_thread_pool_executor.rb:337:in `block (3 levels) in create_worker'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/ruby_thread_pool_executor.rb:320:in `loop'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/ruby_thread_pool_executor.rb:320:in `block (2 levels) in create_worker'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/ruby_thread_pool_executor.rb:319:in `catch'
/home/aruzicka/.rbenv/versions/2.4.1/lib/ruby/gems/2.4.0/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/ruby_thread_pool_executor.rb:319:in `block in create_worker'
[2017-10-12 10:09:22.477 #18156] DEBUG -- dynflow: closing session for command [166c69fe-44a8-4563-a3a8-290960cb96f4],0 actors left
[2017-10-12 10:09:22.478 #18156] DEBUG -- dynflow: terminate 166c69fe-44a8-4563-a3a8-290960cb96f4
[2017-10-12 10:09:22.480 #18156] DEBUG -- dynflow: Step f7e1952e-8700-4cf8-b755-ba283aece5ce: 2 got event #<ForemanTasksCore::Runner::Update:0x0000e524748a60>
[2017-10-12 10:09:22.480 #18156] DEBUG -- dynflow: Step f7e1952e-8700-4cf8-b755-ba283aece5ce: 2 suspended >> running in phase Run ForemanRemoteExecutionCore::Actions::RunScript
[2017-10-12 10:09:22.481 #18156] DEBUG -- dynflow: Step f7e1952e-8700-4cf8-b755-ba283aece5ce: 2 running >> success in phase Run ForemanRemoteExecutionCore::Actions::RunScript
[2017-10-12 10:09:22.483 #18156] DEBUG -- dynflow: Step f7e1952e-8700-4cf8-b755-ba283aece5ce: 5 pending >> running in phase Run SmartProxyDynflowCore::Callback::Action
[2017-10-12 10:09:22.519 #18156] ERROR -- action: Script execution failed
[2017-10-12 10:09:22.519 #18156] DEBUG -- dynflow: Step f7e1952e-8700-4cf8-b755-ba283aece5ce: 3 running >> error in phase Finalize ForemanRemoteExecutionCore::Actions::RunScript
[2017-10-12 10:09:22.521 #18156] DEBUG -- dynflow: ExecutionPlan f7e1952e-8700-4cf8-b755-ba283aece5ce running >> paused
[2017-10-12 10:09:22.522 #18156] DEBUG -- dynflow: ExecutionPlan f7e1952e-8700-4cf8-b755-ba283aece5ce paused >> stopped
[2017-10-12 10:09:23.477 #18156] DEBUG -- dynflow: Ticker ticking for 1 events