Attachment 1472097 Details for Bug 1598528 – automate.log

automate.log

retry.log (text/plain), 16.09 KB, created by Yadnyawalk Tale on 2018-08-01 14:04:49 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Yadnyawalk Tale

Created: 2018-08-01 14:04:49 UTC

Size: 16.09 KB

patch

obsolete

>[----] I, [2018-08-01T09:47:49.167175 #28155:1908d2c]  INFO -- : Instantiating [/SYSTEM/PROCESS/Request?MiqServer%3A%3Amiq_server=1&User%3A%3Auser=1&class=StateMachine&instance=sm_instance&message=create&namespace=ytale_domain%2FtestNS&object_name=Request&request=Call_Instance#create]
>[----] I, [2018-08-01T09:47:49.196369 #28155:1908d2c]  INFO -- : Updated namespace [/SYSTEM/PROCESS/Request?MiqServer%3A%3Amiq_server=1&User%3A%3Auser=1&class=StateMachine&instance=sm_instance&message=create&namespace=ytale_domain%2FtestNS&object_name=Request&request=Call_Instance#create  ManageIQ/SYSTEM]
>[----] I, [2018-08-01T09:47:49.275978 #28155:1908d2c]  INFO -- : Updated namespace [SYSTEM/PROCESS/parse_provider_category  ManageIQ/SYSTEM]
>[----] I, [2018-08-01T09:47:49.282648 #28155:1908d2c]  INFO -- : Invoking [builtin] method [/ManageIQ/System/Process/parse_provider_category] with inputs [{}]
>[----] I, [2018-08-01T09:47:49.283312 #28155:1908d2c]  INFO -- : Setting provider_category to: 
>[----] I, [2018-08-01T09:47:49.283909 #28155:1908d2c]  INFO -- : Following Relationship [miqaedb:/System/Request/Call_Instance#create]
>[----] I, [2018-08-01T09:47:49.302575 #28155:1908d2c]  INFO -- : Updated namespace [miqaedb:/System/Request/Call_Instance#create  ManageIQ/System]
>[----] I, [2018-08-01T09:47:49.318635 #28155:1908d2c]  INFO -- : Following Relationship [miqaedb:/ytale_domain/testNS/StateMachine/sm_instance#create]
>[----] I, [2018-08-01T09:47:49.338533 #28155:1908d2c]  INFO -- : Processing State=[state1]
>[----] I, [2018-08-01T09:47:49.338787 #28155:1908d2c]  INFO -- : Following Relationship [miqaedb:/ytale_domain/testNS/ytale_Class/meth1_instance#create]
>[----] I, [2018-08-01T09:47:49.350086 #28155:1908d2c]  INFO -- : Updated namespace [testNS/ytale_Class/meth1  ytale_domain/testNS]
>[----] I, [2018-08-01T09:47:49.356748 #28155:1908d2c]  INFO -- : Invoking [inline] method [/ytale_domain/testNS/ytale_Class/meth1] with inputs [{}]
>[----] I, [2018-08-01T09:47:49.357979 #28155:1908d2c]  INFO -- : <AEMethod [/ytale_domain/testNS/ytale_Class/meth1]> Starting 
>[----] I, [2018-08-01T09:47:49.822982 #28155:5dbcfb8]  INFO -- : <AEMethod meth1> method started
>[----] I, [2018-08-01T09:47:49.824755 #28155:5dbcfb8]  INFO -- : <AEMethod meth1> Retry Count Value : 0
>[----] I, [2018-08-01T09:47:49.851310 #28155:1908d2c]  INFO -- : <AEMethod [/ytale_domain/testNS/ytale_Class/meth1]> Ending
>[----] I, [2018-08-01T09:47:49.851501 #28155:1908d2c]  INFO -- : Method exited with rc=MIQ_OK
>[----] I, [2018-08-01T09:47:49.851845 #28155:1908d2c]  INFO -- : Followed  Relationship [miqaedb:/ytale_domain/testNS/ytale_Class/meth1_instance#create]
>[----] I, [2018-08-01T09:47:49.851972 #28155:1908d2c]  INFO -- : Processed State=[state1] with Result=[retry]
>[----] I, [2018-08-01T09:47:49.852378 #28155:1908d2c]  INFO -- : Followed  Relationship [miqaedb:/ytale_domain/testNS/StateMachine/sm_instance#create]
>[----] I, [2018-08-01T09:47:49.853045 #28155:1908d2c]  INFO -- : Followed  Relationship [miqaedb:/System/Request/Call_Instance#create]
>[----] I, [2018-08-01T09:47:53.053909 #28155:190f80c]  INFO -- : Instantiating [/SYSTEM/PROCESS/Request?MiqServer%3A%3Amiq_server=1&User%3A%3Auser=1&ae_state=state1&ae_state_previous=---%0A%22%2Fytale_domain%2FtestNS%2FStateMachine%2Fsm_instance%22%3A%0A%20%20ae_state%3A%20state1%0A%20%20ae_state_retries%3A%201%0A%20%20ae_state_started%3A%202018-08-01%2013%3A47%3A49%20UTC%0A%20%20ae_state_max_retries%3A%203%0A&ae_state_retries=1&class=StateMachine&instance=sm_instance&message=create&namespace=ytale_domain%2FtestNS&object_name=Request&request=Call_Instance#create]
>[----] I, [2018-08-01T09:47:53.082323 #28155:190f80c]  INFO -- : Updated namespace [/SYSTEM/PROCESS/Request?MiqServer%3A%3Amiq_server=1&User%3A%3Auser=1&ae_state=state1&ae_state_previous=---%0A%22%2Fytale_domain%2FtestNS%2FStateMachine%2Fsm_instance%22%3A%0A%20%20ae_state%3A%20state1%0A%20%20ae_state_retries%3A%201%0A%20%20ae_state_started%3A%202018-08-01%2013%3A47%3A49%20UTC%0A%20%20ae_state_max_retries%3A%203%0A&ae_state_retries=1&class=StateMachine&instance=sm_instance&message=create&namespace=ytale_domain%2FtestNS&object_name=Request&request=Call_Instance#create  ManageIQ/SYSTEM]
>[----] I, [2018-08-01T09:47:53.158672 #28155:190f80c]  INFO -- : Updated namespace [SYSTEM/PROCESS/parse_provider_category  ManageIQ/SYSTEM]
>[----] I, [2018-08-01T09:47:53.165467 #28155:190f80c]  INFO -- : Invoking [builtin] method [/ManageIQ/System/Process/parse_provider_category] with inputs [{}]
>[----] I, [2018-08-01T09:47:53.166116 #28155:190f80c]  INFO -- : Setting provider_category to: 
>[----] I, [2018-08-01T09:47:53.166688 #28155:190f80c]  INFO -- : Following Relationship [miqaedb:/System/Request/Call_Instance#create]
>[----] I, [2018-08-01T09:47:53.184798 #28155:190f80c]  INFO -- : Updated namespace [miqaedb:/System/Request/Call_Instance#create  ManageIQ/System]
>[----] I, [2018-08-01T09:47:53.199293 #28155:190f80c]  INFO -- : Following Relationship [miqaedb:/ytale_domain/testNS/StateMachine/sm_instance#create]
>[----] I, [2018-08-01T09:47:53.218036 #28155:190f80c]  INFO -- : Processing State=[state1]
>[----] I, [2018-08-01T09:47:53.218303 #28155:190f80c]  INFO -- : Following Relationship [miqaedb:/ytale_domain/testNS/ytale_Class/meth1_instance#create]
>[----] I, [2018-08-01T09:47:53.229902 #28155:190f80c]  INFO -- : Updated namespace [testNS/ytale_Class/meth1  ytale_domain/testNS]
>[----] I, [2018-08-01T09:47:53.236452 #28155:190f80c]  INFO -- : Invoking [inline] method [/ytale_domain/testNS/ytale_Class/meth1] with inputs [{}]
>[----] I, [2018-08-01T09:47:53.237813 #28155:190f80c]  INFO -- : <AEMethod [/ytale_domain/testNS/ytale_Class/meth1]> Starting 
>[----] I, [2018-08-01T09:47:53.790632 #28155:127873c]  INFO -- : <AEMethod meth1> method started
>[----] I, [2018-08-01T09:47:53.792966 #28155:127873c]  INFO -- : <AEMethod meth1> Retry Count Value : 1
>[----] I, [2018-08-01T09:47:53.823511 #28155:190f80c]  INFO -- : <AEMethod [/ytale_domain/testNS/ytale_Class/meth1]> Ending
>[----] I, [2018-08-01T09:47:53.823700 #28155:190f80c]  INFO -- : Method exited with rc=MIQ_OK
>[----] I, [2018-08-01T09:47:53.824003 #28155:190f80c]  INFO -- : Followed  Relationship [miqaedb:/ytale_domain/testNS/ytale_Class/meth1_instance#create]
>[----] I, [2018-08-01T09:47:53.824107 #28155:190f80c]  INFO -- : Processed State=[state1] with Result=[retry]
>[----] I, [2018-08-01T09:47:53.824463 #28155:190f80c]  INFO -- : Followed  Relationship [miqaedb:/ytale_domain/testNS/StateMachine/sm_instance#create]
>[----] I, [2018-08-01T09:47:53.825104 #28155:190f80c]  INFO -- : Followed  Relationship [miqaedb:/System/Request/Call_Instance#create]
>[----] I, [2018-08-01T09:47:55.236905 #28155:190f4b0]  INFO -- : Instantiating [/SYSTEM/PROCESS/Request?MiqServer%3A%3Amiq_server=1&User%3A%3Auser=1&ae_state=state1&ae_state_previous=---%0A%22%2Fytale_domain%2FtestNS%2FStateMachine%2Fsm_instance%22%3A%0A%20%20ae_state%3A%20state1%0A%20%20ae_state_retries%3A%202%0A%20%20ae_state_started%3A%202018-08-01%2013%3A47%3A49%20UTC%0A%20%20ae_state_max_retries%3A%203%0A&ae_state_retries=2&class=StateMachine&instance=sm_instance&message=create&namespace=ytale_domain%2FtestNS&object_name=Request&request=Call_Instance#create]
>[----] I, [2018-08-01T09:47:55.264570 #28155:190f4b0]  INFO -- : Updated namespace [/SYSTEM/PROCESS/Request?MiqServer%3A%3Amiq_server=1&User%3A%3Auser=1&ae_state=state1&ae_state_previous=---%0A%22%2Fytale_domain%2FtestNS%2FStateMachine%2Fsm_instance%22%3A%0A%20%20ae_state%3A%20state1%0A%20%20ae_state_retries%3A%202%0A%20%20ae_state_started%3A%202018-08-01%2013%3A47%3A49%20UTC%0A%20%20ae_state_max_retries%3A%203%0A&ae_state_retries=2&class=StateMachine&instance=sm_instance&message=create&namespace=ytale_domain%2FtestNS&object_name=Request&request=Call_Instance#create  ManageIQ/SYSTEM]
>[----] I, [2018-08-01T09:47:55.336420 #28155:190f4b0]  INFO -- : Updated namespace [SYSTEM/PROCESS/parse_provider_category  ManageIQ/SYSTEM]
>[----] I, [2018-08-01T09:47:55.343363 #28155:190f4b0]  INFO -- : Invoking [builtin] method [/ManageIQ/System/Process/parse_provider_category] with inputs [{}]
>[----] I, [2018-08-01T09:47:55.344034 #28155:190f4b0]  INFO -- : Setting provider_category to: 
>[----] I, [2018-08-01T09:47:55.344567 #28155:190f4b0]  INFO -- : Following Relationship [miqaedb:/System/Request/Call_Instance#create]
>[----] I, [2018-08-01T09:47:55.365800 #28155:190f4b0]  INFO -- : Updated namespace [miqaedb:/System/Request/Call_Instance#create  ManageIQ/System]
>[----] I, [2018-08-01T09:47:55.380863 #28155:190f4b0]  INFO -- : Following Relationship [miqaedb:/ytale_domain/testNS/StateMachine/sm_instance#create]
>[----] I, [2018-08-01T09:47:55.401947 #28155:190f4b0]  INFO -- : Processing State=[state1]
>[----] I, [2018-08-01T09:47:55.402206 #28155:190f4b0]  INFO -- : Following Relationship [miqaedb:/ytale_domain/testNS/ytale_Class/meth1_instance#create]
>[----] I, [2018-08-01T09:47:55.414993 #28155:190f4b0]  INFO -- : Updated namespace [testNS/ytale_Class/meth1  ytale_domain/testNS]
>[----] I, [2018-08-01T09:47:55.422534 #28155:190f4b0]  INFO -- : Invoking [inline] method [/ytale_domain/testNS/ytale_Class/meth1] with inputs [{}]
>[----] I, [2018-08-01T09:47:55.423792 #28155:190f4b0]  INFO -- : <AEMethod [/ytale_domain/testNS/ytale_Class/meth1]> Starting 
>[----] I, [2018-08-01T09:47:56.000789 #28155:5df2e24]  INFO -- : <AEMethod meth1> method started
>[----] I, [2018-08-01T09:47:56.002976 #28155:5df2e24]  INFO -- : <AEMethod meth1> Retry Count Value : 2
>[----] I, [2018-08-01T09:47:56.027412 #28155:190f4b0]  INFO -- : <AEMethod [/ytale_domain/testNS/ytale_Class/meth1]> Ending
>[----] I, [2018-08-01T09:47:56.027615 #28155:190f4b0]  INFO -- : Method exited with rc=MIQ_OK
>[----] I, [2018-08-01T09:47:56.027957 #28155:190f4b0]  INFO -- : Followed  Relationship [miqaedb:/ytale_domain/testNS/ytale_Class/meth1_instance#create]
>[----] I, [2018-08-01T09:47:56.028102 #28155:190f4b0]  INFO -- : Processed State=[state1] with Result=[retry]
>[----] I, [2018-08-01T09:47:56.028546 #28155:190f4b0]  INFO -- : Followed  Relationship [miqaedb:/ytale_domain/testNS/StateMachine/sm_instance#create]
>[----] I, [2018-08-01T09:47:56.029450 #28155:190f4b0]  INFO -- : Followed  Relationship [miqaedb:/System/Request/Call_Instance#create]
>[----] I, [2018-08-01T09:47:57.182803 #28155:190fd0c]  INFO -- : Instantiating [/SYSTEM/PROCESS/Request?MiqServer%3A%3Amiq_server=1&User%3A%3Auser=1&ae_state=state1&ae_state_previous=---%0A%22%2Fytale_domain%2FtestNS%2FStateMachine%2Fsm_instance%22%3A%0A%20%20ae_state%3A%20state1%0A%20%20ae_state_retries%3A%203%0A%20%20ae_state_started%3A%202018-08-01%2013%3A47%3A49%20UTC%0A%20%20ae_state_max_retries%3A%203%0A&ae_state_retries=3&class=StateMachine&instance=sm_instance&message=create&namespace=ytale_domain%2FtestNS&object_name=Request&request=Call_Instance#create]
>[----] I, [2018-08-01T09:47:57.218751 #28155:190fd0c]  INFO -- : Updated namespace [/SYSTEM/PROCESS/Request?MiqServer%3A%3Amiq_server=1&User%3A%3Auser=1&ae_state=state1&ae_state_previous=---%0A%22%2Fytale_domain%2FtestNS%2FStateMachine%2Fsm_instance%22%3A%0A%20%20ae_state%3A%20state1%0A%20%20ae_state_retries%3A%203%0A%20%20ae_state_started%3A%202018-08-01%2013%3A47%3A49%20UTC%0A%20%20ae_state_max_retries%3A%203%0A&ae_state_retries=3&class=StateMachine&instance=sm_instance&message=create&namespace=ytale_domain%2FtestNS&object_name=Request&request=Call_Instance#create  ManageIQ/SYSTEM]
>[----] I, [2018-08-01T09:47:57.298290 #28155:190fd0c]  INFO -- : Updated namespace [SYSTEM/PROCESS/parse_provider_category  ManageIQ/SYSTEM]
>[----] I, [2018-08-01T09:47:57.304807 #28155:190fd0c]  INFO -- : Invoking [builtin] method [/ManageIQ/System/Process/parse_provider_category] with inputs [{}]
>[----] I, [2018-08-01T09:47:57.305471 #28155:190fd0c]  INFO -- : Setting provider_category to: 
>[----] I, [2018-08-01T09:47:57.305996 #28155:190fd0c]  INFO -- : Following Relationship [miqaedb:/System/Request/Call_Instance#create]
>[----] I, [2018-08-01T09:47:57.324543 #28155:190fd0c]  INFO -- : Updated namespace [miqaedb:/System/Request/Call_Instance#create  ManageIQ/System]
>[----] I, [2018-08-01T09:47:57.338288 #28155:190fd0c]  INFO -- : Following Relationship [miqaedb:/ytale_domain/testNS/StateMachine/sm_instance#create]
>[----] I, [2018-08-01T09:47:57.356451 #28155:190fd0c]  INFO -- : Processing State=[state1]
>[----] I, [2018-08-01T09:47:57.356684 #28155:190fd0c]  INFO -- : Following Relationship [miqaedb:/ytale_domain/testNS/ytale_Class/meth1_instance#create]
>[----] I, [2018-08-01T09:47:57.368145 #28155:190fd0c]  INFO -- : Updated namespace [testNS/ytale_Class/meth1  ytale_domain/testNS]
>[----] I, [2018-08-01T09:47:57.377738 #28155:190fd0c]  INFO -- : Invoking [inline] method [/ytale_domain/testNS/ytale_Class/meth1] with inputs [{}]
>[----] I, [2018-08-01T09:47:57.378903 #28155:190fd0c]  INFO -- : <AEMethod [/ytale_domain/testNS/ytale_Class/meth1]> Starting 
>[----] I, [2018-08-01T09:47:57.990112 #28155:1278b60]  INFO -- : <AEMethod meth1> method started
>[----] I, [2018-08-01T09:47:57.991755 #28155:1278b60]  INFO -- : <AEMethod meth1> Retry Count Value : 3
>[----] I, [2018-08-01T09:47:58.014989 #28155:190fd0c]  INFO -- : <AEMethod [/ytale_domain/testNS/ytale_Class/meth1]> Ending
>[----] I, [2018-08-01T09:47:58.015165 #28155:190fd0c]  INFO -- : Method exited with rc=MIQ_OK
>[----] I, [2018-08-01T09:47:58.015444 #28155:190fd0c]  INFO -- : Followed  Relationship [miqaedb:/ytale_domain/testNS/ytale_Class/meth1_instance#create]
>[----] I, [2018-08-01T09:47:58.015540 #28155:190fd0c]  INFO -- : Processed State=[state1] with Result=[retry]
>[----] I, [2018-08-01T09:47:58.015890 #28155:190fd0c]  INFO -- : Followed  Relationship [miqaedb:/ytale_domain/testNS/StateMachine/sm_instance#create]
>[----] I, [2018-08-01T09:47:58.016567 #28155:190fd0c]  INFO -- : Followed  Relationship [miqaedb:/System/Request/Call_Instance#create]
>[----] I, [2018-08-01T09:48:01.179174 #28155:19086ec]  INFO -- : Instantiating [/SYSTEM/PROCESS/Request?MiqServer%3A%3Amiq_server=1&User%3A%3Auser=1&ae_state=state1&ae_state_previous=---%0A%22%2Fytale_domain%2FtestNS%2FStateMachine%2Fsm_instance%22%3A%0A%20%20ae_state%3A%20state1%0A%20%20ae_state_retries%3A%204%0A%20%20ae_state_started%3A%202018-08-01%2013%3A47%3A49%20UTC%0A%20%20ae_state_max_retries%3A%203%0A&ae_state_retries=4&class=StateMachine&instance=sm_instance&message=create&namespace=ytale_domain%2FtestNS&object_name=Request&request=Call_Instance#create]
>[----] I, [2018-08-01T09:48:01.204212 #28155:19086ec]  INFO -- : Updated namespace [/SYSTEM/PROCESS/Request?MiqServer%3A%3Amiq_server=1&User%3A%3Auser=1&ae_state=state1&ae_state_previous=---%0A%22%2Fytale_domain%2FtestNS%2FStateMachine%2Fsm_instance%22%3A%0A%20%20ae_state%3A%20state1%0A%20%20ae_state_retries%3A%204%0A%20%20ae_state_started%3A%202018-08-01%2013%3A47%3A49%20UTC%0A%20%20ae_state_max_retries%3A%203%0A&ae_state_retries=4&class=StateMachine&instance=sm_instance&message=create&namespace=ytale_domain%2FtestNS&object_name=Request&request=Call_Instance#create  ManageIQ/SYSTEM]
>[----] I, [2018-08-01T09:48:01.271497 #28155:19086ec]  INFO -- : Updated namespace [SYSTEM/PROCESS/parse_provider_category  ManageIQ/SYSTEM]
>[----] I, [2018-08-01T09:48:01.278035 #28155:19086ec]  INFO -- : Invoking [builtin] method [/ManageIQ/System/Process/parse_provider_category] with inputs [{}]
>[----] I, [2018-08-01T09:48:01.278584 #28155:19086ec]  INFO -- : Setting provider_category to: 
>[----] I, [2018-08-01T09:48:01.279087 #28155:19086ec]  INFO -- : Following Relationship [miqaedb:/System/Request/Call_Instance#create]
>[----] I, [2018-08-01T09:48:01.294684 #28155:19086ec]  INFO -- : Updated namespace [miqaedb:/System/Request/Call_Instance#create  ManageIQ/System]
>[----] I, [2018-08-01T09:48:01.308227 #28155:19086ec]  INFO -- : Following Relationship [miqaedb:/ytale_domain/testNS/StateMachine/sm_instance#create]
>[----] I, [2018-08-01T09:48:01.327430 #28155:19086ec]  INFO -- : Processing State=[state1]
>[----] E, [2018-08-01T09:48:01.328022 #28155:19086ec] ERROR -- : State=<state1> running  raised exception: <number of retries <4> exceeded maximum of <3>>
>[----] W, [2018-08-01T09:48:01.328124 #28155:19086ec]  WARN -- : Error in State=[state1]
>[----] I, [2018-08-01T09:48:01.328281 #28155:19086ec]  INFO -- : Followed  Relationship [miqaedb:/ytale_domain/testNS/StateMachine/sm_instance#create]
>[----] I, [2018-08-01T09:48:01.328936 #28155:19086ec]  INFO -- : Followed  Relationship [miqaedb:/System/Request/Call_Instance#create]
>

Actions: View

Attachments on bug 1598528: 1472097