You are right with sleep method, today I noticed exception from different method then sleep
[----] I, [2020-02-26T14:32:27.194566 #32587:405aee8] INFO -- : Q-task_id([r745_service_template_provision_task_1712]) <AEMethod pre_terraform_openstack_k8s__1_0> Scheduled Job ID: 1832 Ansible Job ID: 4839
[----] I, [2020-02-26T14:32:27.195342 #32587:405aee8] INFO -- : Q-task_id([r745_service_template_provision_task_1712]) <AEMethod pre_terraform_openstack_k8s__1_0> [awx_run_adhoc_template] jobId: 1832 launched (retries 0)
[----] E, [2020-02-26T14:32:42.351973 #32587:a9af60] ERROR -- : Q-task_id([r745_service_template_provision_task_1712]) Terminating non responsive method with pid 22187
[----] E, [2020-02-26T14:32:42.353119 #32587:ea90048] ERROR -- : Q-task_id([r745_service_template_provision_task_1712]) <AEMethod pre_terraform_openstack_k8s__1_0> The following error occurred during method evaluation:
[----] E, [2020-02-26T14:32:42.353504 #32587:ea90048] ERROR -- : Q-task_id([r745_service_template_provision_task_1712]) <AEMethod pre_terraform_openstack_k8s__1_0> SignalException: SIGTERM
[----] E, [2020-02-26T14:32:42.356833 #32587:ea90048] ERROR -- : Q-task_id([r745_service_template_provision_task_1712]) <AEMethod pre_terraform_openstack_k8s__1_0> /usr/local/lib/ruby/2.4.0/drb/drb.rb:575:in `read'
/usr/local/lib/ruby/2.4.0/drb/drb.rb:575:in `load'
/usr/local/lib/ruby/2.4.0/drb/drb.rb:641:in `recv_reply'
/usr/local/lib/ruby/2.4.0/drb/drb.rb:941:in `recv_reply'
/usr/local/lib/ruby/2.4.0/drb/drb.rb:1254:in `send_message'
/usr/local/lib/ruby/2.4.0/drb/drb.rb:1142:in `block (2 levels) in method_missing'
/usr/local/lib/ruby/2.4.0/drb/drb.rb:1229:in `open'
/usr/local/lib/ruby/2.4.0/drb/drb.rb:1141:in `block in method_missing'
/usr/local/lib/ruby/2.4.0/drb/drb.rb:1160:in `with_friend'
/usr/local/lib/ruby/2.4.0/drb/drb.rb:1140:in `method_missing'
/KBCZ/Functions/Awx/utils:68:in `_awx_run_adhoc_check_status'
/KBCZ/Functions/Awx/utils:26:in `awx_run_adhoc_template'
/KBCZ/KbOrchestration/OrchestrationFlows/TemplatesMethods/Methods/util:27:in `block in unregister_hostnames_in_ipam_and_ldap'
/KBCZ/KbOrchestration/OrchestrationFlows/TemplatesMethods/Methods/util:24:in `each'
/KBCZ/KbOrchestration/OrchestrationFlows/TemplatesMethods/Methods/util:24:in `unregister_hostnames_in_ipam_and_ldap'
/KBCZ/KbOrchestration/OrchestrationFlows/TemplatesMethods/Methods/pre_terraform_openstack_k8s__1_0:94:in `rescue in <main>'
Unfortunatelly there is nothing in journalctl
around the time…
But I found perhaps related message in evm.log
:
[----] I, [2020-02-26T14:32:42.441132 #32587:a9af60] INFO – : Q-task_id([r745_service_template_provision_task_1712]) MIQ(ServiceTemplateProvisionTask#after_ae_delivery) ae_result=“error”
[----] I, [2020-02-26T14:32:42.747858 #32587:a9af60] INFO – : Q-task_id([r745_service_template_provision_task_1712]) MIQ(MiqQueue.put) Message id: [29060353], id: , Zone: [default], Role: [automate], Server: , MiqTask id: , Ident: [generic], Target id: , Instance id: , Task id: , Command: [MiqAeEngine.deliver], Timeout: [3600], Priority: [20], State: [ready], Deliver On: , Data: , Args: [{:object_type=>“ServiceAnsibleTower”, :object_id=>584, :attrs=>{:event_type=>:service_provisioned, “MiqEvent::miq_event”=>3481138, :miq_event_id=>3481138, “EventStream::event_stream”=>3481138, :event_stream_id=>3481138}, :instance_name=>“Event”, :user_id=>38, :miq_group_id=>146, :tenant_id=>22, :automate_message=>nil}]
[----] E, [2020-02-26T14:32:42.748163 #32587:a9af60] ERROR – : Q-task_id([r745_service_template_provision_task_1712]) MIQ(MiqQueue#deliver) Message id: [29059879], timed out after 600.397411021 seconds. Timeout threshold [600]
[----] I, [2020-02-26T14:32:42.748217 #32587:a9af60] INFO – : Q-task_id([r745_service_template_provision_task_1712]) MIQ(MiqGenericWorker::Runner#deliver_queue_message) MIQ(MiqGenericWorker::Runner) Reconnecting to DB after timeout error during queue deliver
[----] I, [2020-02-26T14:32:43.496484 #32587:a9af60] INFO – : Q-task_id([r745_service_template_provision_task_1712]) MIQ(MiqQueue#delivered) Message id: [29059879], State: [timeout], Delivered in [601.145701679] seconds
[----] I, [2020-02-26T14:32:43.562790 #32587:a9af60] INFO – : Q-task_id([r745_service_template_provision_task_1712]) MIQ(MiqGenericWorker#log_status) [Generic Worker] Worker ID [13238], PID [32587], GUID [365c0c67-33b2-4bd1-93a8-247782500f9a], Last Heartbeat [2020-02-26 13:22:42 UTC], Process Info: Memory Usage [691355648], Memory Size [1063780352], Proportional Set Size: [604480000], Unique Set Size: [601044000], Memory % [2.75], CPU Time [45220.0], CPU % [0.14], Priority [30]
[----] E, [2020-02-26T14:32:43.563226 #32587:a9af60] ERROR – : Q-task_id([r745_service_template_provision_task_1712]) MIQ(MiqGenericWorker::Runner) ID [13238] PID [32587] GUID [365c0c67-33b2-4bd1-93a8-247782500f9a] Exiting worker due to timeout error Worker exiting.
Could this be the issue?
Message id: [29059879], timed out after 600.397411021 seconds. Timeout threshold [600]