Potential bug with Windows VM backup: "Body Timeout Error"
-
the log @ 04:35:11 to 04:35:57 is + 300kb
Is there anything I can sort out -
04:35:11
Jul 3 04:35:11 saruman xapi: [debug||253 scanning_thread|SR scanner D:326d57d887b1|xapi_sr] Automatically scanning SRs = [ OpaqueRef:16725e54-2f51-9bcc-0a1b-31847b9d2bfb ] Jul 3 04:35:11 saruman xapi: [debug||29568 ||dummytaskhelper] task scan one D:732f75985406 created by task D:326d57d887b1 Jul 3 04:35:11 saruman xapi: [debug||29569 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:session.slave_login D:eccbbe50488c created by task D:732f75985406 Jul 3 04:35:11 saruman xapi: [ info||29569 /var/lib/xcp/xapi|session.slave_login D:cc07678de121|xapi_session] Session.create trackid=3bd666ff307e18fa86ce028a05437c1b pool=true uname= originator=xapi is_loca$ Jul 3 04:35:11 saruman xapi: [debug||29570 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:pool.get_all D:0fd564ae5c24 created by task D:cc07678de121 Jul 3 04:35:11 saruman xapi: [debug||29571 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:SR.scan D:9dd57167ef24 created by task D:732f75985406 Jul 3 04:35:11 saruman xapi: [ info||29571 /var/lib/xcp/xapi|dispatch:SR.scan D:9dd57167ef24|taskhelper] task SR.scan R:30711df16968 (uuid:2a8220fc-6843-ae13-7934-af2faad9d716) created (trackid=3bd666ff307e$ Jul 3 04:35:11 saruman xapi: [debug||29571 /var/lib/xcp/xapi|SR.scan R:30711df16968|message_forwarding] SR.scan: SR = 'fd8042bf-61a9-e2cb-09e8-b6ea67086b15 (T1_ISO_test)' Jul 3 04:35:11 saruman xapi: [debug||29571 /var/lib/xcp/xapi|SR.scan R:30711df16968|message_forwarding] Marking SR for SR.scan (task=OpaqueRef:30711df1-6968-d3f8-5c29-47cc108f58a5) Jul 3 04:35:11 saruman xapi: [ info||29571 /var/lib/xcp/xapi|OpaqueRef:30711df1-6968-d3f8-5c29-47cc108f58a5|mux] SR.scan2 dbg:OpaqueRef:30711df1-6968-d3f8-5c29-47cc108f58a5 sr:fd8042bf-61a9-e2cb-09e8-b6ea67$ Jul 3 04:35:11 saruman xapi: [ info||29572 |OpaqueRef:30711df1-6968-d3f8-5c29-47cc108f58a5|Storage_smapiv1_wrapper] SR.scan2 dbg:OpaqueRef:30711df1-6968-d3f8-5c29-47cc108f58a5 sr:fd8042bf-61a9-e2cb-09e8-b6e$ Jul 3 04:35:11 saruman xapi: [debug||29572 |OpaqueRef:30711df1-6968-d3f8-5c29-47cc108f58a5|dummytaskhelper] task SR.scan D:5930d0b18dda created by task R:30711df16968 Jul 3 04:35:11 saruman xapi: [debug||29572 |SR.scan D:5930d0b18dda|sm] SM iso sr_scan sr=OpaqueRef:16725e54-2f51-9bcc-0a1b-31847b9d2bfb Jul 3 04:35:11 saruman xapi: [ info||29572 |sm_exec D:cdde671c2793|xapi_session] Session.create trackid=603446d3a4f6757a43d68053f52d381d pool=false uname= originator=xapi is_local_superuser=true auth_user_s$ Jul 3 04:35:11 saruman xapi: [debug||29573 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:pool.get_all D:f3490996e6d0 created by task D:cdde671c2793 Jul 3 04:35:11 saruman xapi: [debug||29574 /var/lib/xcp/xapi|SR.set_virtual_allocation D:1eeb803b2ec7|redo_debug] Write was successful Jul 3 04:35:11 saruman xapi: [debug||29574 /var/lib/xcp/xapi|SR.set_virtual_allocation D:1eeb803b2ec7|redo_debug] Xapi_database__Redo_log.healthy Jul 3 04:35:11 saruman xapi: [debug||29574 /var/lib/xcp/xapi|SR.set_virtual_allocation D:1eeb803b2ec7|redo_debug] Xapi_database__Redo_log.can_connect_fn Jul 3 04:35:11 saruman xapi: [ info||29572 |sm_exec D:cdde671c2793|xapi_session] Session.destroy trackid=603446d3a4f6757a43d68053f52d381d Jul 3 04:35:11 saruman xapi: [debug||29572 |OpaqueRef:30711df1-6968-d3f8-5c29-47cc108f58a5|dummytaskhelper] task SR.stat D:a6701a0ec320 created by task R:30711df16968 Jul 3 04:35:11 saruman xapi: [debug||29572 |SR.stat D:a6701a0ec320|sm] SM iso sr_update sr=OpaqueRef:16725e54-2f51-9bcc-0a1b-31847b9d2bfb Jul 3 04:35:11 saruman xapi: [ info||29572 |sm_exec D:ceb705d62eae|xapi_session] Session.create trackid=e3c583021d6b31a31247294476f0db00 pool=false uname= originator=xapi is_local_superuser=true auth_user_s$ Jul 3 04:35:11 saruman xapi: [debug||29575 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:pool.get_all D:59518d9a8e14 created by task D:ceb705d62eae Jul 3 04:35:11 saruman xapi: [debug||29522 HTTPS 192.168.11.80->:::80|post_root|dummytaskhelper] task dispatch:event.from D:01634ea2dc87 created by task D:2339f3bbdbf5 Jul 3 04:35:11 saruman xapi: [ info||29572 |sm_exec D:ceb705d62eae|xapi_session] Session.destroy trackid=e3c583021d6b31a31247294476f0db00 Jul 3 04:35:11 saruman xapi: [debug||29571 /var/lib/xcp/xapi|SR.scan R:30711df16968|xapi_sr] Xapi_sr.scan.(fun).scan_rec no change detected, updating VDIs Jul 3 04:35:11 saruman xapi: [debug||29571 /var/lib/xcp/xapi|SR.scan R:30711df16968|redo_debug] Write was successful Jul 3 04:35:11 saruman xapi: [debug||29571 /var/lib/xcp/xapi|SR.scan R:30711df16968|redo_debug] Xapi_database__Redo_log.healthy Jul 3 04:35:11 saruman xapi: [debug||29571 /var/lib/xcp/xapi|SR.scan R:30711df16968|redo_debug] Xapi_database__Redo_log.can_connect_fn Jul 3 04:35:11 saruman xapi: [debug||29571 /var/lib/xcp/xapi|SR.scan R:30711df16968|message_forwarding] Unmarking SR after SR.scan (task=OpaqueRef:30711df1-6968-d3f8-5c29-47cc108f58a5) Jul 3 04:35:11 saruman xapi: [debug||29578 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:session.logout D:a2c2abbfb834 created by task D:732f75985406 Jul 3 04:35:11 saruman xapi: [ info||29578 /var/lib/xcp/xapi|session.logout D:a86923f19a9e|xapi_session] Session.destroy trackid=3bd666ff307e18fa86ce028a05437c1b Jul 3 04:35:11 saruman xapi: [debug||29568 |scan one D:732f75985406|xapi_sr] Scan of SR fd8042bf-61a9-e2cb-09e8-b6ea67086b15 complete. -
04:35:12
Jul 3 04:35:12 saruman xapi: [debug||29579 HTTPS 192.168.11.104->:::80|session.login_with_password D:078b8e80c48d|xapi_session] Success: local auth, user root from HTTP request from Internet with User-Agent$ Jul 3 04:35:12 saruman xapi: [ info||29579 HTTPS 192.168.11.104->:::80|session.login_with_password D:078b8e80c48d|xapi_session] Session.create trackid=312991ac2a491678ffbd03d423ed0141 pool=false uname=root $ Jul 3 04:35:12 saruman xapi: [debug||29580 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:pool.get_all D:bc2edf3c8615 created by task D:078b8e80c48d Jul 3 04:35:12 saruman xapi: [debug||29582 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:session.logout D:69563c555812 created by task D:823ea5ff66e2 Jul 3 04:35:12 saruman xapi: [ info||29582 /var/lib/xcp/xapi|session.logout D:3070e3db5da9|xapi_session] Session.destroy trackid=48e113dd5c7a1d45458e1d2b92601693 Jul 3 04:35:12 saruman xapi: [debug||29583 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:session.slave_login D:f633debe7850 created by task D:823ea5ff66e2 Jul 3 04:35:12 saruman xapi: [ info||29583 /var/lib/xcp/xapi|session.slave_login D:e9b0235f0e4a|xapi_session] Session.create trackid=ca2803ef4e7083f4747a48db63c177e6 pool=true uname= originator=xapi is_loca$ Jul 3 04:35:12 saruman xapi: [debug||29584 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:pool.get_all D:26e00eb4d36e created by task D:e9b0235f0e4a Jul 3 04:35:12 saruman xapi: [debug||29585 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:event.from D:78809790a29d created by task D:823ea5ff66e2 Jul 3 04:35:12 saruman xapi: [debug||29579 HTTPS 192.168.11.104->:::80|VM.remove_from_blocked_operations R:cbfa771b26b7|audit] VM.remove_from_blocked_operations: self = '9568a891-c547-964e-5efb-9f793ac7fb42$ Jul 3 04:35:12 saruman xapi: [debug||29579 HTTPS 192.168.11.104->:::80|VM.remove_from_blocked_operations R:cbfa771b26b7|xapi_vm] Xapi_vm.remove_from_blocked_operations Jul 3 04:35:12 saruman xapi: [debug||29581 HTTPS 192.168.11.104->:::80|VM.remove_from_blocked_operations R:59870af6f27b|audit] VM.remove_from_blocked_operations: self = '9568a891-c547-964e-5efb-9f793ac7fb42$ Jul 3 04:35:12 saruman xapi: [debug||29581 HTTPS 192.168.11.104->:::80|VM.remove_from_blocked_operations R:59870af6f27b|xapi_vm] Xapi_vm.remove_from_blocked_operations Jul 3 04:35:12 saruman xapi: [debug||29586 HTTPS 192.168.11.104->:::80|VM.add_to_blocked_operations R:120f9900abf1|audit] VM.add_to_blocked_operations: self = '9568a891-c547-964e-5efb-9f793ac7fb42 (XO-Sauro$ Jul 3 04:35:12 saruman xapi: [debug||29586 HTTPS 192.168.11.104->:::80|VM.add_to_blocked_operations R:120f9900abf1|xapi_vm] Xapi_vm.add_to_blocked_operations Jul 3 04:35:12 saruman xapi: [debug||29586 HTTPS 192.168.11.104->:::80|VM.add_to_blocked_operations R:120f9900abf1|redo_debug] Write was successful Jul 3 04:35:12 saruman xapi: [debug||29586 HTTPS 192.168.11.104->:::80|VM.add_to_blocked_operations R:120f9900abf1|redo_debug] Xapi_database__Redo_log.healthy Jul 3 04:35:12 saruman xapi: [debug||29586 HTTPS 192.168.11.104->:::80|VM.add_to_blocked_operations R:120f9900abf1|redo_debug] Xapi_database__Redo_log.can_connect_fn Jul 3 04:35:12 saruman xapi: [debug||29579 HTTPS 192.168.11.104->:::80|VM.add_to_blocked_operations R:c0c78557699e|audit] VM.add_to_blocked_operations: self = '9568a891-c547-964e-5efb-9f793ac7fb42 (XO-Sauro$ Jul 3 04:35:12 saruman xapi: [debug||29579 HTTPS 192.168.11.104->:::80|VM.add_to_blocked_operations R:c0c78557699e|xapi_vm] Xapi_vm.add_to_blocked_operations Jul 3 04:35:12 saruman xapi: [debug||251 |xapi events D:bc2806bdd685|xenops] Event on VM 9568a891-c547-964e-5efb-9f793ac7fb42; resident_here = true Jul 3 04:35:12 saruman xapi: [debug||29579 HTTPS 192.168.11.104->:::80|VM.add_to_blocked_operations R:c0c78557699e|redo_debug] Write was successful Jul 3 04:35:12 saruman xapi: [debug||29579 HTTPS 192.168.11.104->:::80|VM.add_to_blocked_operations R:c0c78557699e|redo_debug] Xapi_database__Redo_log.healthy Jul 3 04:35:12 saruman xapi: [debug||29579 HTTPS 192.168.11.104->:::80|VM.add_to_blocked_operations R:c0c78557699e|redo_debug] Xapi_database__Redo_log.can_connect_fn Jul 3 04:35:12 saruman xapi: [debug||29581 HTTPS 192.168.11.104->:::80|VM.remove_from_blocked_operations R:a1c90fe4b993|audit] VM.remove_from_blocked_operations: self = '8353b44b-86cb-475b-e730-97f7fa7bacc6$ Jul 3 04:35:12 saruman xapi: [debug||29587 HTTPS 192.168.11.104->:::80|VM.remove_from_blocked_operations R:864e0196124f|audit] VM.remove_from_blocked_operations: self = '8353b44b-86cb-475b-e730-97f7fa7bacc6$ Jul 3 04:35:12 saruman xapi: [debug||29581 HTTPS 192.168.11.104->:::80|VM.remove_from_blocked_operations R:a1c90fe4b993|xapi_vm] Xapi_vm.remove_from_blocked_operations Jul 3 04:35:12 saruman xapi: [debug||29587 HTTPS 192.168.11.104->:::80|VM.remove_from_blocked_operations R:864e0196124f|xapi_vm] Xapi_vm.remove_from_blocked_operations Jul 3 04:35:12 saruman xapi: [debug||251 |xapi events D:bc2806bdd685|xenops] xapi_cache: not updating cache for 9568a891-c547-964e-5efb-9f793ac7fb42 Jul 3 04:35:12 saruman xapi: [debug||251 |xapi events D:bc2806bdd685|dummytaskhelper] task timeboxed_rpc D:49d7209c4cec created by task D:bc2806bdd685 Jul 3 04:35:12 saruman xapi: [debug||29586 HTTPS 192.168.11.104->:::80|VM.add_to_blocked_operations R:b8c16837eac3|audit] VM.add_to_blocked_operations: self = '8353b44b-86cb-475b-e730-97f7fa7bacc6 (2-LMDE7)$ Jul 3 04:35:12 saruman xapi: [debug||29586 HTTPS 192.168.11.104->:::80|VM.add_to_blocked_operations R:b8c16837eac3|xapi_vm] Xapi_vm.add_to_blocked_operations Jul 3 04:35:12 saruman xapi: [debug||29616 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:event.from D:41bf54393b78 created by task D:bc2806bdd685 Jul 3 04:35:12 saruman xapi: [debug||29586 HTTPS 192.168.11.104->:::80|VM.add_to_blocked_operations R:b8c16837eac3|redo_debug] Write was successful Jul 3 04:35:12 saruman xapi: [debug||29586 HTTPS 192.168.11.104->:::80|VM.add_to_blocked_operations R:b8c16837eac3|redo_debug] Xapi_database__Redo_log.healthy Jul 3 04:35:12 saruman xapi: [debug||29586 HTTPS 192.168.11.104->:::80|VM.add_to_blocked_operations R:b8c16837eac3|redo_debug] Xapi_database__Redo_log.can_connect_fn Jul 3 04:35:12 saruman xapi: [debug||29581 HTTPS 192.168.11.104->:::80|VM.add_to_blocked_operations R:4f271f2de8d1|audit] VM.add_to_blocked_operations: self = '8353b44b-86cb-475b-e730-97f7fa7bacc6 (2-LMDE7)$ Jul 3 04:35:12 saruman xapi: [debug||29581 HTTPS 192.168.11.104->:::80|VM.add_to_blocked_operations R:4f271f2de8d1|xapi_vm] Xapi_vm.add_to_blocked_operations Jul 3 04:35:12 saruman xapi: [debug||251 |xapi events D:bc2806bdd685|xenops] Event on VM 9568a891-c547-964e-5efb-9f793ac7fb42; resident_here = true Jul 3 04:35:12 saruman xapi: [debug||29581 HTTPS 192.168.11.104->:::80|VM.add_to_blocked_operations R:4f271f2de8d1|redo_debug] Write was successful Jul 3 04:35:12 saruman xapi: [debug||29581 HTTPS 192.168.11.104->:::80|VM.add_to_blocked_operations R:4f271f2de8d1|redo_debug] Xapi_database__Redo_log.healthy Jul 3 04:35:12 saruman xapi: [debug||29581 HTTPS 192.168.11.104->:::80|VM.add_to_blocked_operations R:4f271f2de8d1|redo_debug] Xapi_database__Redo_log.can_connect_fn Jul 3 04:35:12 saruman xapi: [debug||251 |xapi events D:bc2806bdd685|xenops] xapi_cache: not updating cache for 9568a891-c547-964e-5efb-9f793ac7fb42 Jul 3 04:35:12 saruman xapi: [debug||251 |xapi events D:bc2806bdd685|dummytaskhelper] task timeboxed_rpc D:606238890c31 created by task D:bc2806bdd685 Jul 3 04:35:12 saruman xapi: [debug||29617 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:event.from D:aa12a2dc6e7f created by task D:bc2806bdd685 Jul 3 04:35:12 saruman xapi: [debug||29579 HTTPS 192.168.11.104->:::80|VM.remove_from_other_config D:09c0ab21bf75|audit] VM.remove_from_other_config: self = '9568a891-c547-964e-5efb-9f793ac7fb42 (XO-Sauron)$ Jul 3 04:35:12 saruman xapi: [debug||29581 HTTPS 192.168.11.104->:::80|VM.remove_from_other_config D:21199f16e114|audit] VM.remove_from_other_config: self = '9568a891-c547-964e-5efb-9f793ac7fb42 (XO-Sauron)$ Jul 3 04:35:12 saruman xapi: [debug||29588 HTTPS 192.168.11.104->:::80|VM.remove_from_other_config D:a4bd602cbe8e|audit] VM.remove_from_other_config: self = '9568a891-c547-964e-5efb-9f793ac7fb42 (XO-Sauron)$ Jul 3 04:35:12 saruman xapi: [debug||29587 HTTPS 192.168.11.104->:::80|VM.remove_from_other_config D:d1c1276459e6|audit] VM.remove_from_other_config: self = '9568a891-c547-964e-5efb-9f793ac7fb42 (XO-Sauron)$ Jul 3 04:35:12 saruman xapi: [debug||29589 HTTPS 192.168.11.104->:::80|VM.remove_from_other_config D:c0de975ab044|audit] VM.remove_from_other_config: self = '9568a891-c547-964e-5efb-9f793ac7fb42 (XO-Sauron)$ Jul 3 04:35:12 saruman xapi: [debug||29594 :::80|dispatch:VDI.remove_from_other_config D:055791cdfc68|api_effect] VDI.remove_from_other_config Jul 3 04:35:12 saruman xapi: [debug||29591 HTTPS 192.168.11.104->:::80|VM.remove_from_other_config D:f790effaa602|audit] VM.remove_from_other_config: self = '9568a891-c547-964e-5efb-9f793ac7fb42 (XO-Sauron)$ Jul 3 04:35:12 saruman xapi: [debug||29593 :::80|dispatch:VDI.remove_from_other_config D:2bfdc6504ebb|api_effect] VDI.remove_from_other_config Jul 3 04:35:12 saruman xapi: [debug||29590 HTTPS 192.168.11.104->:::80|VM.remove_from_other_config D:d79e6e4a5136|audit] VM.remove_from_other_config: self = '9568a891-c547-964e-5efb-9f793ac7fb42 (XO-Sauron)$ Jul 3 04:35:12 saruman xapi: [debug||29592 HTTPS 192.168.11.104->:::80|VM.remove_from_other_config D:8ee15c17ea09|audit] VM.remove_from_other_config: self = '9568a891-c547-964e-5efb-9f793ac7fb42 (XO-Sauron)$ Jul 3 04:35:12 saruman xapi: [debug||29598 :::80|dispatch:VDI.remove_from_other_config D:e3b2d69ca32b|api_effect] VDI.remove_from_other_config Jul 3 04:35:12 saruman xapi: [debug||29597 :::80|dispatch:VDI.remove_from_other_config D:06d05c0b1461|api_effect] VDI.remove_from_other_config Jul 3 04:35:12 saruman xapi: [debug||29595 :::80|dispatch:VDI.remove_from_other_config D:db62dc7de8f4|api_effect] VDI.remove_from_other_config Jul 3 04:35:12 saruman xapi: [debug||29600 :::80|dispatch:VDI.remove_from_other_config D:d03eeab97ea6|api_effect] VDI.remove_from_other_config Jul 3 04:35:12 saruman xapi: [debug||29599 :::80|dispatch:VDI.remove_from_other_config D:3893de8bae36|api_effect] VDI.remove_from_other_config Jul 3 04:35:12 saruman xapi: [debug||29596 :::80|dispatch:VDI.remove_from_other_config D:a5bf3ce348ca|api_effect] VDI.remove_from_other_config Jul 3 04:35:12 saruman xapi: [debug||29579 :::80|dispatch:pool.add_to_other_config D:bdfc9a522f7a|api_effect] pool.add_to_other_config Jul 3 04:35:12 saruman xapi: [debug||29579 HTTPS 192.168.11.104->:::80|pool.add_to_other_config D:0a47778fa26d|redo_debug] Write was successful Jul 3 04:35:12 saruman xapi: [debug||29579 HTTPS 192.168.11.104->:::80|pool.add_to_other_config D:0a47778fa26d|redo_debug] Xapi_database__Redo_log.healthy Jul 3 04:35:12 saruman xapi: [debug||29579 HTTPS 192.168.11.104->:::80|pool.add_to_other_config D:0a47778fa26d|redo_debug] Xapi_database__Redo_log.can_connect_fn Jul 3 04:35:12 saruman xapi: [debug||29591 HTTPS 192.168.11.104->:::80|VM.remove_from_other_config D:c4766abc27f9|audit] VM.remove_from_other_config: self = '8353b44b-86cb-475b-e730-97f7fa7bacc6 (2-LMDE7)',$ Jul 3 04:35:12 saruman xapi: [debug||29589 HTTPS 192.168.11.104->:::80|VM.remove_from_other_config D:063aa097b84d|audit] VM.remove_from_other_config: self = '8353b44b-86cb-475b-e730-97f7fa7bacc6 (2-LMDE7)',$ Jul 3 04:35:12 saruman xapi: [debug||29593 :::80|dispatch:VDI.remove_from_other_config D:f8726461e0a6|api_effect] VDI.remove_from_other_config Jul 3 04:35:12 saruman xapi: [debug||29590 HTTPS 192.168.11.104->:::80|VM.remove_from_other_config D:56a1ee681aa1|audit] VM.remove_from_other_config: self = '8353b44b-86cb-475b-e730-97f7fa7bacc6 (2-LMDE7)',$ Jul 3 04:35:12 saruman xapi: [debug||29588 HTTPS 192.168.11.104->:::80|VM.remove_from_other_config D:d0c436e970e0|audit] VM.remove_from_other_config: self = '8353b44b-86cb-475b-e730-97f7fa7bacc6 (2-LMDE7)',$ Jul 3 04:35:12 saruman xapi: [debug||29594 :::80|dispatch:VDI.remove_from_other_config D:b5d6bc3ef534|api_effect] VDI.remove_from_other_config Jul 3 04:35:12 saruman xapi: [debug||29599 :::80|dispatch:VDI.remove_from_other_config D:03ba46b0e8ef|api_effect] VDI.remove_from_other_config Jul 3 04:35:12 saruman xapi: [debug||29618 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:session.logout D:d5f8624586ad created by task D:823ea5ff66e2 Jul 3 04:35:12 saruman xapi: [ info||29618 /var/lib/xcp/xapi|session.logout D:7e639832bcac|xapi_session] Session.destroy trackid=ca2803ef4e7083f4747a48db63c177e6 Jul 3 04:35:12 saruman xapi: [debug||29598 :::80|dispatch:VDI.remove_from_other_config D:96529103281e|api_effect] VDI.remove_from_other_config Jul 3 04:35:12 saruman xapi: [debug||29595 :::80|dispatch:VDI.remove_from_other_config D:e85d4b89ad38|api_effect] VDI.remove_from_other_config Jul 3 04:35:12 saruman xapi: [debug||29587 HTTPS 192.168.11.104->:::80|event.from D:be3f60eca8bb|xapi_message] Xapi_message.get_since_for_events.(fun): cache (6778) might not contain all messages since the $ Jul 3 04:35:12 saruman xapi: [debug||29597 :::80|dispatch:VDI.remove_from_other_config D:88fc89495212|api_effect] VDI.remove_from_other_config Jul 3 04:35:12 saruman xapi: [debug||29600 :::80|dispatch:VDI.remove_from_other_config D:6a674f0efe15|api_effect] VDI.remove_from_other_config Jul 3 04:35:12 saruman xapi: [debug||29586 HTTPS 192.168.11.104->:::80|VM.remove_from_other_config D:833cf106f19c|audit] VM.remove_from_other_config: self = '8353b44b-86cb-475b-e730-97f7fa7bacc6 (2-LMDE7)',$ Jul 3 04:35:12 saruman xapi: [debug||29596 :::80|dispatch:VDI.remove_from_other_config D:9254480263a9|api_effect] VDI.remove_from_other_config Jul 3 04:35:12 saruman xapi: [debug||29581 HTTPS 192.168.11.104->:::80|VM.remove_from_other_config D:8c2599ed7ef2|audit] VM.remove_from_other_config: self = '8353b44b-86cb-475b-e730-97f7fa7bacc6 (2-LMDE7)',$ Jul 3 04:35:12 saruman xapi: [debug||29592 HTTPS 192.168.11.104->:::80|VM.remove_from_other_config D:ca1700a7e280|audit] VM.remove_from_other_config: self = '8353b44b-86cb-475b-e730-97f7fa7bacc6 (2-LMDE7)',$ Jul 3 04:35:12 saruman xapi: [debug||29579 HTTPS 192.168.11.104->:::80|VM.remove_from_other_config D:aafbe991c105|audit] VM.remove_from_other_config: self = '8353b44b-86cb-475b-e730-97f7fa7bacc6 (2-LMDE7)',$ Jul 3 04:35:12 saruman xapi: [debug||29619 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:session.slave_login D:89df7c940b75 created by task D:823ea5ff66e2 Jul 3 04:35:12 saruman xapi: [ info||29619 /var/lib/xcp/xapi|session.slave_login D:59ec45a4596a|xapi_session] Session.create trackid=dc8fda850a7364496d500cdb347f5e29 pool=true uname= originator=xapi is_loca$ Jul 3 04:35:12 saruman xapi: [debug||29620 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:pool.get_all D:a750749f3208 created by task D:59ec45a4596a Jul 3 04:35:12 saruman xapi: [debug||29522 HTTPS 192.168.11.80->:::80|post_root|dummytaskhelper] task dispatch:event.from D:40c21b705d99 created by task D:2339f3bbdbf5 Jul 3 04:35:12 saruman xapi: [debug||29621 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:event.from D:bd4ae306d733 created by task D:823ea5ff66e2 Jul 3 04:35:12 saruman xapi: [debug||29588 :::80|dispatch:pool.remove_from_other_config D:09bc5706ae58|api_effect] pool.remove_from_other_config Jul 3 04:35:12 saruman xapi: [debug||29588 HTTPS 192.168.11.104->:::80|pool.remove_from_other_config D:b878052f8693|redo_debug] Write was successful Jul 3 04:35:12 saruman xapi: [debug||29588 HTTPS 192.168.11.104->:::80|pool.remove_from_other_config D:b878052f8693|redo_debug] Xapi_database__Redo_log.healthy Jul 3 04:35:12 saruman xapi: [debug||29588 HTTPS 192.168.11.104->:::80|pool.remove_from_other_config D:b878052f8693|redo_debug] Xapi_database__Redo_log.can_connect_fn Jul 3 04:35:12 saruman xapi: [debug||29590 :::80|dispatch:pool.add_to_other_config D:606a7dcff861|api_effect] pool.add_to_other_config Jul 3 04:35:12 saruman xapi: [debug||29622 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:session.logout D:40aaae606f44 created by task D:823ea5ff66e2 Jul 3 04:35:12 saruman xapi: [ info||29622 /var/lib/xcp/xapi|session.logout D:015fd09352fd|xapi_session] Session.destroy trackid=dc8fda850a7364496d500cdb347f5e29 Jul 3 04:35:12 saruman xapi: [debug||29590 HTTPS 192.168.11.104->:::80|pool.add_to_other_config D:d8968e8ce182|redo_debug] Write was successful Jul 3 04:35:12 saruman xapi: [debug||29590 HTTPS 192.168.11.104->:::80|pool.add_to_other_config D:d8968e8ce182|redo_debug] Xapi_database__Redo_log.healthy Jul 3 04:35:12 saruman xapi: [debug||29590 HTTPS 192.168.11.104->:::80|pool.add_to_other_config D:d8968e8ce182|redo_debug] Xapi_database__Redo_log.can_connect_fn -
04:35:13
Jul 3 04:35:13 saruman xapi: [debug||29623 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:session.slave_login D:d12a36aec5c5 created by task D:823ea5ff66e2 Jul 3 04:35:13 saruman xapi: [ info||29623 /var/lib/xcp/xapi|session.slave_login D:db731796bbe1|xapi_session] Session.create trackid=6d3639a6c690af83677109c2e81b9a61 pool=true uname= originator=xapi is_loca$ Jul 3 04:35:13 saruman xapi: [debug||29624 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:pool.get_all D:5c79f55ea570 created by task D:db731796bbe1 Jul 3 04:35:13 saruman xapi: [debug||29625 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:event.from D:bae99b900b1f created by task D:823ea5ff66e2 Jul 3 04:35:13 saruman xapi: [debug||29626 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:session.logout D:6f544c69ebbe created by task D:823ea5ff66e2 Jul 3 04:35:13 saruman xapi: [ info||29626 /var/lib/xcp/xapi|session.logout D:a524f2308dd2|xapi_session] Session.destroy trackid=6d3639a6c690af83677109c2e81b9a61 Jul 3 04:35:13 saruman xapi: [debug||29627 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:session.slave_login D:113819379339 created by task D:823ea5ff66e2 Jul 3 04:35:13 saruman xapi: [ info||29627 /var/lib/xcp/xapi|session.slave_login D:da0f565ff5e4|xapi_session] Session.create trackid=fc2ae746311712adae8891823c565fcc pool=true uname= originator=xapi is_loca$ Jul 3 04:35:13 saruman xapi: [debug||29628 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:pool.get_all D:a50ca0951811 created by task D:da0f565ff5e4 Jul 3 04:35:13 saruman xapi: [ info||29581 :::80|dispatch:VM.snapshot D:059f47467b66|dispatcher] spawning a new thread to handle the current task (trackid=312991ac2a491678ffbd03d423ed0141) Jul 3 04:35:13 saruman xapi: [debug||29629 HTTPS 192.168.11.104->|Async.VM.snapshot R:23c458eea2f3|audit] VM.snapshot: VM = '9568a891-c547-964e-5efb-9f793ac7fb42 (XO-Sauron)'; new_name = 'xo-backup-temp-sna$ Jul 3 04:35:13 saruman xapi: [ warn||29629 HTTPS 192.168.11.104->|Async.VM.snapshot R:23c458eea2f3|xapi_vm_helpers] VM XO-Sauron could run on any of these hosts: [ saruman; gandalf ] Jul 3 04:35:13 saruman xapi: [ info||29629 HTTPS 192.168.11.104->|Async.VM.snapshot R:23c458eea2f3|xapi_session] Session.create trackid=fc0856cd8590ab3a2927037d7a81aad7 pool=true uname= originator=xapi is_l$ Jul 3 04:35:13 saruman xapi: [debug||29630 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:pool.get_all D:948b01cd27d8 created by task R:23c458eea2f3 Jul 3 04:35:13 saruman xapi: [debug||251 |xapi events D:bc2806bdd685|xenops] Event on VM 9568a891-c547-964e-5efb-9f793ac7fb42; resident_here = true Jul 3 04:35:13 saruman xapi: [debug||29631 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:event.from D:348ac052a98b created by task D:823ea5ff66e2 Jul 3 04:35:13 saruman xapi: [debug||251 |xapi events D:bc2806bdd685|xenops] xapi_cache: not updating cache for 9568a891-c547-964e-5efb-9f793ac7fb42 Jul 3 04:35:13 saruman xapi: [debug||251 |xapi events D:bc2806bdd685|dummytaskhelper] task timeboxed_rpc D:9ecbd9a624cd created by task D:bc2806bdd685 Jul 3 04:35:13 saruman xapi: [debug||29632 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:event.from D:c6c1a6c44a42 created by task D:bc2806bdd685 Jul 3 04:35:13 saruman xapi: [debug||29629 HTTPS 192.168.11.104->|Async.VM.snapshot R:23c458eea2f3|xmlrpc_client] stunnel pid: 311291 (cached) connected to 192.168.11.80:443 Jul 3 04:35:13 saruman xapi: [debug||29522 HTTPS 192.168.11.80->:::80|post_root|dummytaskhelper] task dispatch:event.from D:6b6812c25bed created by task D:2339f3bbdbf5 Jul 3 04:35:13 saruman xapi: [debug||29633 HTTPS 192.168.11.80->:::80|post_root|dummytaskhelper] task dispatch:VBD.get_record D:01f767c0ddc0 created by task R:23c458eea2f3 Jul 3 04:35:13 saruman xapi: [debug||29633 HTTPS 192.168.11.80->:::80|post_root|dummytaskhelper] task dispatch:VBD.get_record D:9ffbba29f97f created by task R:23c458eea2f3 Jul 3 04:35:13 saruman xapi: [debug||29633 HTTPS 192.168.11.80->:::80|post_root|dummytaskhelper] task dispatch:VDI.snapshot D:12db600c3fa5 created by task R:23c458eea2f3 Jul 3 04:35:13 saruman xapi: [ info||29633 :::80|dispatch:VDI.snapshot D:12db600c3fa5|taskhelper] task Async.VDI.snapshot R:f18b93d1b960 (uuid:f34cc941-d83b-c870-c5b4-c81f0cb3da85) created (trackid=fc0856cd$ Jul 3 04:35:13 saruman xapi: [ info||29633 :::80|dispatch:VDI.snapshot D:12db600c3fa5|dispatcher] spawning a new thread to handle the current task (trackid=fc0856cd8590ab3a2927037d7a81aad7) Jul 3 04:35:13 saruman xapi: [debug||29634 HTTPS 192.168.11.80->|Async.VDI.snapshot R:f18b93d1b960|audit] VDI.snapshot: VDI = 'bd106c3a-b734-4daf-9399-d33d49fed36a' Jul 3 04:35:13 saruman xapi: [debug||29634 HTTPS 192.168.11.80->|Async.VDI.snapshot R:f18b93d1b960|message_forwarding] Marking SR for VDI.snapshot (task=OpaqueRef:f18b93d1-b960-5450-316a-02a3bc69bc46) Jul 3 04:35:13 saruman xapi: [ info||29634 |OpaqueRef:f18b93d1-b960-5450-316a-02a3bc69bc46|mux] VDI.snapshot dbg:OpaqueRef:f18b93d1-b960-5450-316a-02a3bc69bc46 sr:3a5f09a2-7799-3c91-f85c-beafb7ebaae3 vdi_in$ Jul 3 04:35:13 saruman xapi: [ info||29635 |OpaqueRef:f18b93d1-b960-5450-316a-02a3bc69bc46|Storage_smapiv1_wrapper] VDI.snapshot dbg:OpaqueRef:f18b93d1-b960-5450-316a-02a3bc69bc46 sr:3a5f09a2-7799-3c91-f85c$ Jul 3 04:35:13 saruman xapi: [debug||29635 |OpaqueRef:f18b93d1-b960-5450-316a-02a3bc69bc46|dummytaskhelper] task VDI.snapshot D:13069db1b6de created by task R:f18b93d1b960 Jul 3 04:35:13 saruman xapi: [debug||29635 |VDI.snapshot D:13069db1b6de|dummytaskhelper] task VDI.snapshot D:e03e23e135b6 created by task R:f18b93d1b960 Jul 3 04:35:13 saruman xapi: [debug||29635 |VDI.snapshot D:e03e23e135b6|sm] SM lvmoiscsi vdi_snapshot sr=OpaqueRef:c7e918d2-2b0a-dd0e-2551-1c24c38682bc vdi=OpaqueRef:3e0af3d4-d5fa-7df6-81bb-ed8dd1a022b7 dri$ Jul 3 04:35:13 saruman xapi: [ info||29635 |sm_exec D:23136a3929df|xapi_session] Session.create trackid=d898f150be4e5f82d2ba1092f17d313b pool=false uname= originator=xapi is_local_superuser=true auth_user_s$ Jul 3 04:35:13 saruman xapi: [debug||29633 HTTPS 192.168.11.80->:::80|post_root|dummytaskhelper] task dispatch:task.get_record D:814ed1b104b4 created by task R:23c458eea2f3 Jul 3 04:35:13 saruman xapi: [debug||29636 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:pool.get_all D:410f573394ff created by task D:23136a3929df Jul 3 04:35:13 saruman xapi: [debug||29633 HTTPS 192.168.11.80->:::80|post_root|dummytaskhelper] task dispatch:task.get_record D:b07a70dc7e77 created by task R:23c458eea2f3 Jul 3 04:35:13 saruman xapi: [debug||29633 HTTPS 192.168.11.80->:::80|post_root|dummytaskhelper] task dispatch:event.from D:d77f1ed4b011 created by task R:23c458eea2f3 Jul 3 04:35:13 saruman xapi: [debug||29633 HTTPS 192.168.11.80->:::80|post_root|dummytaskhelper] task dispatch:event.from D:23ae4cda51cd created by task R:23c458eea2f3 Jul 3 04:35:13 saruman xapi: [debug||29581 :::80|dispatch:pool.remove_from_other_config D:5c246069b24d|api_effect] pool.remove_from_other_config Jul 3 04:35:13 saruman xapi: [debug||29581 HTTPS 192.168.11.104->:::80|pool.remove_from_other_config D:7fa1dd1b610d|redo_debug] Write was successful Jul 3 04:35:13 saruman xapi: [debug||29581 HTTPS 192.168.11.104->:::80|pool.remove_from_other_config D:7fa1dd1b610d|redo_debug] Xapi_database__Redo_log.healthy Jul 3 04:35:13 saruman xapi: [debug||29581 HTTPS 192.168.11.104->:::80|pool.remove_from_other_config D:7fa1dd1b610d|redo_debug] Xapi_database__Redo_log.can_connect_fn Jul 3 04:35:13 saruman xapi: [debug||29637 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:session.logout D:c65ec447c291 created by task D:823ea5ff66e2 Jul 3 04:35:13 saruman xapi: [ info||29637 /var/lib/xcp/xapi|session.logout D:2d8f671dcb46|xapi_session] Session.destroy trackid=fc2ae746311712adae8891823c565fcc Jul 3 04:35:13 saruman xapi: [debug||29638 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:session.slave_login D:af04be83537e created by task D:823ea5ff66e2 Jul 3 04:35:13 saruman xapi: [ info||29638 /var/lib/xcp/xapi|session.slave_login D:497d43b949e1|xapi_session] Session.create trackid=ae54891c93c09fd7e250231eed50c45e pool=true uname= originator=xapi is_loca$ Jul 3 04:35:13 saruman xapi: [debug||29639 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:pool.get_all D:17b025805107 created by task D:497d43b949e1 Jul 3 04:35:13 saruman xapi: [debug||29640 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:event.from D:1165e4dbb01b created by task D:823ea5ff66e2 Jul 3 04:35:13 saruman xapi: [ info||29581 :::80|dispatch:VM.snapshot D:237ca78655d5|dispatcher] spawning a new thread to handle the current task (trackid=312991ac2a491678ffbd03d423ed0141) Jul 3 04:35:13 saruman xapi: [debug||29641 HTTPS 192.168.11.104->|Async.VM.snapshot R:c609ded5338f|audit] VM.snapshot: VM = '8353b44b-86cb-475b-e730-97f7fa7bacc6 (2-LMDE7)'; new_name = 'xo-backup-temp-snaps$ Jul 3 04:35:13 saruman xapi: [ warn||29641 HTTPS 192.168.11.104->|Async.VM.snapshot R:c609ded5338f|xapi_vm_helpers] VM 2-LMDE7 could run on any of these hosts: [ saruman; gandalf ] Jul 3 04:35:13 saruman xapi: [debug||29641 HTTPS 192.168.11.104->|Async.VM.snapshot R:c609ded5338f|xapi_vm_snapshot] Snapshot: begin Jul 3 04:35:13 saruman xapi: [debug||29642 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:session.slave_login D:0531ebceddde created by task R:c609ded5338f Jul 3 04:35:13 saruman xapi: [ info||29642 /var/lib/xcp/xapi|session.slave_login D:d9f6475804cb|xapi_session] Session.create trackid=f0fcb7daa81b6648a27b679090415989 pool=true uname= originator=xapi is_loca$ Jul 3 04:35:13 saruman xapi: [debug||29643 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:pool.get_all D:8971f156b3c7 created by task D:d9f6475804cb Jul 3 04:35:13 saruman xapi: [debug||29644 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:VBD.get_record D:bb6e7e98aae7 created by task R:c609ded5338f Jul 3 04:35:13 saruman xapi: [debug||29645 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:VDI.snapshot D:2d335c8f7d98 created by task R:c609ded5338f Jul 3 04:35:13 saruman xapi: [ info||29645 /var/lib/xcp/xapi|dispatch:VDI.snapshot D:2d335c8f7d98|taskhelper] task Async.VDI.snapshot R:96e11de516db (uuid:9bc12c58-57d1-6b03-3459-1fb7485455e7) created (trac$ Jul 3 04:35:13 saruman xapi: [ info||29645 /var/lib/xcp/xapi|dispatch:VDI.snapshot D:2d335c8f7d98|dispatcher] spawning a new thread to handle the current task (trackid=f0fcb7daa81b6648a27b679090415989) Jul 3 04:35:13 saruman xapi: [debug||29646 |Async.VDI.snapshot R:96e11de516db|audit] VDI.snapshot: VDI = '35e5b2fd-1999-4705-9523-17ae3d4aeafc' Jul 3 04:35:13 saruman xapi: [debug||29646 |Async.VDI.snapshot R:96e11de516db|message_forwarding] Marking SR for VDI.snapshot (task=OpaqueRef:96e11de5-16db-4246-a4e7-7f7820adfb7f) Jul 3 04:35:13 saruman xapi: [debug||29646 |Async.VDI.snapshot R:96e11de516db|message_forwarding] Caught exception while marking SR for VDI.snapshot in message forwarder: OTHER_OPERATION_IN_PROGRESS: [ SR; $ Jul 3 04:35:13 saruman xapi: [debug||29646 |Async.VDI.snapshot R:96e11de516db|helpers] VDI.snapshot locking failed: caught transient failure OTHER_OPERATION_IN_PROGRESS: [ SR; OpaqueRef:c7e918d2-2b0a-dd0e-2$ Jul 3 04:35:13 saruman xapi: [debug||29646 |Async.VDI.snapshot R:96e11de516db|helpers] Waiting for up to 13.900298 seconds before retrying... Jul 3 04:35:13 saruman xapi: [debug||29647 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:session.slave_login D:ad14e5bd8c30 created by task R:c609ded5338f Jul 3 04:35:13 saruman xapi: [ info||29647 /var/lib/xcp/xapi|session.slave_login D:e67c9ff57be0|xapi_session] Session.create trackid=0ee691a0ea54ef4f1d942860027acb03 pool=true uname= originator=xapi is_loca$ Jul 3 04:35:13 saruman xapi: [debug||29648 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:pool.get_all D:689649238183 created by task D:e67c9ff57be0 Jul 3 04:35:13 saruman xapi: [debug||29649 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:task.get_record D:f273bee54ab3 created by task R:c609ded5338f Jul 3 04:35:13 saruman xapi: [debug||29650 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:task.get_record D:edc7a54cb199 created by task R:c609ded5338f Jul 3 04:35:13 saruman xapi: [debug||29651 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:event.from D:3b124fca1598 created by task R:c609ded5338f Jul 3 04:35:13 saruman xapi: [debug||29652 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:event.from D:360b9489801a created by task R:c609ded5338f Jul 3 04:35:13 saruman xapi: [debug||29522 HTTPS 192.168.11.80->:::80|post_root|dummytaskhelper] task dispatch:event.from D:771fb90505ed created by task D:2339f3bbdbf5 Jul 3 04:35:13 saruman xapi: [debug||29653 /var/lib/xcp/xapi|dispatch:VDI.add_to_sm_config D:45c544ac19b4|api_effect] VDI.add_to_sm_config Jul 3 04:35:13 saruman xapi: [debug||29653 /var/lib/xcp/xapi|VDI.add_to_sm_config D:d290305cac66|redo_debug] Write was successful Jul 3 04:35:13 saruman xapi: [debug||29653 /var/lib/xcp/xapi|VDI.add_to_sm_config D:d290305cac66|redo_debug] Xapi_database__Redo_log.healthy Jul 3 04:35:13 saruman xapi: [debug||29653 /var/lib/xcp/xapi|VDI.add_to_sm_config D:d290305cac66|redo_debug] Xapi_database__Redo_log.can_connect_fn Jul 3 04:35:13 saruman xapi: [debug||29653 /var/lib/xcp/xapi|host.call_plugin R:27058d1c6a7c|audit] Host.call_plugin host = 'aae1f2ab-1f2f-4a38-af90-97d850a2caaf (saruman)'; plugin = 'tapdisk-pause'; fn = '$ Jul 3 04:35:13 saruman xapi: [debug||1420 ha_monitor|HA monitor D:4f75c83bbba0|helpers] about to call script without a timeout: /usr/libexec/xapi/cluster-stack/xhad/ha_query_liveset Jul 3 04:35:13 saruman xapi: [debug||1420 ha_monitor|HA monitor D:4f75c83bbba0|xapi_ha] Liveset: online 8c67881d-e100-4a02-9e8d-98aac410e6b0 [ L A ]; aae1f2ab-1f2f-4a38-af90-97d850a2caaf [*LM A ]; Jul 3 04:35:13 saruman xapi: [debug||1420 ha_monitor|HA monitor D:4f75c83bbba0|xapi_ha] Processing warnings Jul 3 04:35:13 saruman xapi: [debug||1420 ha_monitor|HA monitor D:4f75c83bbba0|xapi_ha] Done with warnings Jul 3 04:35:13 saruman xapi: [debug||1420 ha_monitor|HA monitor D:4f75c83bbba0|xapi_ha_vm_failover] restart_auto_run_vms called Jul 3 04:35:13 saruman xapi: [debug||1420 ha_monitor|HA monitor D:4f75c83bbba0|xapi_ha_vm_failover] Setting all VMs running or paused to Halted Jul 3 04:35:13 saruman xapi: [debug||1420 ha_monitor|HA monitor D:4f75c83bbba0|xapi_ha_vm_failover] Protected VMs: [ ] Jul 3 04:35:13 saruman xapi: [debug||1420 ha_monitor|HA monitor D:4f75c83bbba0|xapi_ha_vm_failover] Restart plan for non-agile offline VMs: [ ] Jul 3 04:35:13 saruman xapi: [debug||1420 ha_monitor|HA monitor D:4f75c83bbba0|xapi_ha_vm_failover] Planning configuration for offline agile VMs = { total_hosts = 2; num_failures = 1; hosts = [ 4c084741 (ga$ Jul 3 04:35:13 saruman xapi: [debug||1420 ha_monitor|HA monitor D:4f75c83bbba0|xapi_ha_vm_failover] Computing a specific plan for the failure of VMs: [ ] Jul 3 04:35:13 saruman xapi: [debug||1420 ha_monitor|HA monitor D:4f75c83bbba0|xapi_ha_vm_failover] Restart plan for agile offline VMs: [ ] Jul 3 04:35:13 saruman xapi: [debug||1420 ha_monitor|HA monitor D:4f75c83bbba0|xapi_ha_vm_failover] Planning configuration for future failures = { total_hosts = 2; num_failures = 1; hosts = [ 4c084741 (gand$ Jul 3 04:35:13 saruman xapi: [debug||29655 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:session.slave_login D:56526d9b00fb created by task D:4f75c83bbba0 Jul 3 04:35:13 saruman xapi: [ info||29655 /var/lib/xcp/xapi|session.slave_login D:ebe7eb7e5755|xapi_session] Session.create trackid=19d8ad5280db4cad07e3ce5eefc93c41 pool=true uname= originator=xapi is_loca$ Jul 3 04:35:13 saruman xapi: [debug||29656 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:pool.get_all D:87450437dafe created by task D:ebe7eb7e5755 Jul 3 04:35:13 saruman xapi: [debug||1420 ha_monitor|HA monitor D:4f75c83bbba0|xapi_ha_vm_failover] Processing 0 parallel groups Jul 3 04:35:13 saruman xapi: message repeated 2 times: [ [debug||1420 ha_monitor|HA monitor D:4f75c83bbba0|xapi_ha_vm_failover] Processing 0 parallel groups] Jul 3 04:35:13 saruman xapi: [debug||29657 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:session.logout D:8c4fce474a86 created by task D:4f75c83bbba0 Jul 3 04:35:13 saruman xapi: [ info||29657 /var/lib/xcp/xapi|session.logout D:3fedf5ebefc4|xapi_session] Session.destroy trackid=19d8ad5280db4cad07e3ce5eefc93c41 Jul 3 04:35:13 saruman xapi: [debug||1420 ha_monitor|HA monitor D:4f75c83bbba0|xapi_ha] Network peers = [8c67881d-e100-4a02-9e8d-98aac410e6b0;aae1f2ab-1f2f-4a38-af90-97d850a2caaf] Jul 3 04:35:13 saruman xapi: [debug||1420 ha_monitor|HA monitor D:4f75c83bbba0|xapi_ha] Network peers = [8c67881d-e100-4a02-9e8d-98aac410e6b0;aae1f2ab-1f2f-4a38-af90-97d850a2caaf] -
On your backup remote, look at the file left behind by the failed run
It's empty
I increased the schedule to every 30 min.
All 3 of them are OK
-
This post is deleted! -
aaaand it happens again.
-
Sorry it's back.
Just to line things up for whoever picks this up: the original full-backup Body Timeout was tracked in https://github.com/xapi-project/xen-api/pull/6786 and shipped with the March 2026 8.3 updates, so what you're seeing on metadata backups might be a cousin rather than the same bug.
From Olivier's earlier note the error just means XO got nothing from the pool master for 5 minutes mid-transfer, so the useful question is what the master was doing during that silence.
The fact that a toolstack restart clears it for a while and then it returns is probably itself a clue.
Could you grab the complete logs from one failed metadata run (the ask pierrebrunet made earlier), plus a rough note of whether it lines up with the master being busy or briefly unreachable?
I'm out of my depth on the internals, but that's the piece the team will want.
-
Due to the fact that this is the second XO release in a row that broke backups I do wonder: are all backup job types being tested via automated unit tests? Are those tests being run multiple times in order to catch issues that do not occur during every single test run? There must be a reason for QA not catching these kind of issues…
-
@MajorP93 I am currently working on this issue but to answer you quickly, yes we have automatic tests, unit and integration tests (you can see them in *.integ.mjs and *.test.mjs files, and @xen-orchestra/qatest folder), a long QA to validate at each release. We add a regression test at every bug we encounter.
The issue is we could not reproduce your exact issue yet.
Hello! It looks like you're interested in this conversation, but you don't have an account yet.
Getting fed up of having to scroll through the same posts each visit? When you register for an account, you'll always come back to exactly where you were before, and choose to be notified of new replies (either via email, or push notification). You'll also be able to save bookmarks and upvote posts to show your appreciation to other community members.
With your input, this post could be even better 💗
Register Login