[22:04 XCP25 ~]# grep "Oct 14 20:08" /var/log/xensource.log Oct 14 20:08:04 XCP25 xapi: [debug||1206 scanning_thread|SR scanner D:3b6b5f2d8cde|xapi_sr] Automatically scanning SRs = [ OpaqueRef:88574456-65df-41a3-8d3e-8a77ba64c325 ] Oct 14 20:08:04 XCP25 xapi: [debug||5937029 ||dummytaskhelper] task scan one D:cc88361e60c7 created by task D:3b6b5f2d8cde Oct 14 20:08:04 XCP25 xapi: [debug||5937030 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:session.slave_login D:c0c31acf917e created by task D:cc88361e60c7 Oct 14 20:08:04 XCP25 xapi: [ info||5937030 /var/lib/xcp/xapi|session.slave_login D:f78cff496770|xapi_session] Session.create trackid=e8b1321cc9a5156ad7cf4d00bbb818d4 pool=true uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:08:04 XCP25 xapi: [debug||5937031 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:0365843ebb6b created by task D:f78cff496770 Oct 14 20:08:04 XCP25 xapi: [debug||5937032 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.scan D:3d013ab4c3a7 created by task D:cc88361e60c7 Oct 14 20:08:04 XCP25 xapi: [ info||5937032 /var/lib/xcp/xapi||taskhelper] task SR.scan R:4049a509c54b (uuid:9699e313-7fa6-5f96-6072-0076d673d8bb) created (trackid=e8b1321cc9a5156ad7cf4d00bbb818d4) by task D:cc88361e60c7 Oct 14 20:08:04 XCP25 xapi: [debug||5937032 /var/lib/xcp/xapi|SR.scan R:4049a509c54b|message_forwarding] SR.scan: SR = 'ef3c3e29-6bb9-64f2-1174-1f0295bdd4f1 (NFS ISO)' Oct 14 20:08:04 XCP25 xapi: [debug||5937032 /var/lib/xcp/xapi|SR.scan R:4049a509c54b|message_forwarding] Marking SR for SR.scan (task=OpaqueRef:4049a509-c54b-4c9c-93f6-680e367635a0) Oct 14 20:08:04 XCP25 xapi: [ info||5937032 /var/lib/xcp/xapi|SR.scan R:4049a509c54b|storage_impl] SR.scan dbg:OpaqueRef:4049a509-c54b-4c9c-93f6-680e367635a0 sr:ef3c3e29-6bb9-64f2-1174-1f0295bdd4f1 Oct 14 20:08:04 XCP25 xapi: [debug||5937033 ||dummytaskhelper] task SR.scan D:1e227a3d66ec created by task R:4049a509c54b Oct 14 20:08:04 XCP25 xapi: [debug||5937033 |SR.scan D:1e227a3d66ec|sm] SM iso sr_scan sr=OpaqueRef:88574456-65df-41a3-8d3e-8a77ba64c325 Oct 14 20:08:04 XCP25 xapi: [ info||5937033 |sm_exec D:876c63a89441|xapi_session] Session.create trackid=8f482465cc925a1598a24e098c721ac7 pool=false uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:08:04 XCP25 xapi: [debug||5937034 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:9a21c16c213f created by task D:876c63a89441 Oct 14 20:08:04 XCP25 xapi: [debug||5937035 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:host.get_other_config D:5e81a7504013 created by task D:1e227a3d66ec Oct 14 20:08:04 XCP25 xapi: [debug||5937036 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_by_uuid D:e12022761452 created by task D:1e227a3d66ec Oct 14 20:08:04 XCP25 xapi: [debug||5937037 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_all_records_where D:3cb072280955 created by task D:1e227a3d66ec Oct 14 20:08:04 XCP25 xapi: [debug||5937038 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_other_config D:df2ce3557308 created by task D:1e227a3d66ec Oct 14 20:08:04 XCP25 xapi: [debug||5937039 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_by_uuid D:b3fc4198e483 created by task D:1e227a3d66ec Oct 14 20:08:04 XCP25 xapi: [debug||5937040 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.set_virtual_allocation D:e952835a4684 created by task D:1e227a3d66ec Oct 14 20:08:04 XCP25 xapi: [debug||5937041 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.set_physical_size D:36c284eaeb08 created by task D:1e227a3d66ec Oct 14 20:08:04 XCP25 xapi: [debug||5937042 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.set_physical_utilisation D:15ee051a4741 created by task D:1e227a3d66ec Oct 14 20:08:04 XCP25 xapi: [debug||5937043 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_by_uuid D:6f804ae45e16 created by task D:1e227a3d66ec Oct 14 20:08:04 XCP25 xapi: [debug||5937044 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_all_records_where D:60dbb3b6d0d7 created by task D:1e227a3d66ec Oct 14 20:08:05 XCP25 xapi: [ info||5937033 |sm_exec D:876c63a89441|xapi_session] Session.destroy trackid=8f482465cc925a1598a24e098c721ac7 Oct 14 20:08:05 XCP25 xapi: [ info||5937032 /var/lib/xcp/xapi|SR.scan R:4049a509c54b|storage_impl] SR.stat dbg:OpaqueRef:4049a509-c54b-4c9c-93f6-680e367635a0 sr:ef3c3e29-6bb9-64f2-1174-1f0295bdd4f1 Oct 14 20:08:05 XCP25 xapi: [debug||5937045 ||dummytaskhelper] task SR.stat D:1e0616b5c69a created by task R:4049a509c54b Oct 14 20:08:05 XCP25 xapi: [debug||5937045 |SR.stat D:1e0616b5c69a|sm] SM iso sr_update sr=OpaqueRef:88574456-65df-41a3-8d3e-8a77ba64c325 Oct 14 20:08:05 XCP25 xapi: [ info||5937045 |sm_exec D:49f5e05522ed|xapi_session] Session.create trackid=a19edc99c8a91edfef989037734e0fb0 pool=false uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:08:05 XCP25 xapi: [debug||5937046 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:63a9f1ddea86 created by task D:49f5e05522ed Oct 14 20:08:05 XCP25 xapi: [debug||5937047 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:host.get_other_config D:fb810a65b221 created by task D:1e0616b5c69a Oct 14 20:08:05 XCP25 xapi: [ info||5937045 |sm_exec D:49f5e05522ed|xapi_session] Session.destroy trackid=a19edc99c8a91edfef989037734e0fb0 Oct 14 20:08:05 XCP25 xapi: [debug||5937032 /var/lib/xcp/xapi|SR.scan R:4049a509c54b|message_forwarding] Unmarking SR after SR.scan (task=OpaqueRef:4049a509-c54b-4c9c-93f6-680e367635a0) Oct 14 20:08:05 XCP25 xapi: [debug||5937048 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:session.logout D:02d00e525bfe created by task D:cc88361e60c7 Oct 14 20:08:05 XCP25 xapi: [ info||5937048 /var/lib/xcp/xapi|session.logout D:c149cb4e8288|xapi_session] Session.destroy trackid=e8b1321cc9a5156ad7cf4d00bbb818d4 Oct 14 20:08:05 XCP25 xapi: [debug||5937029 |scan one D:cc88361e60c7|xapi_sr] Scan of SR ef3c3e29-6bb9-64f2-1174-1f0295bdd4f1 complete. Oct 14 20:08:10 XCP25 xapi: [debug||5937049 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:session.logout D:aa44d08fd7b9 created by task D:6f7ddf1004ca Oct 14 20:08:10 XCP25 xapi: [ info||5937049 /var/lib/xcp/xapi|session.logout D:fa0fdaf35867|xapi_session] Session.destroy trackid=c9208296c751113c9482a82a759901b0 Oct 14 20:08:10 XCP25 xapi: [debug||5937050 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:session.slave_login D:bf95b3644fcf created by task D:6f7ddf1004ca Oct 14 20:08:10 XCP25 xapi: [ info||5937050 /var/lib/xcp/xapi|session.slave_login D:a5ddc3bfd71a|xapi_session] Session.create trackid=838ee567e924112759cea98634caba99 pool=true uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:08:10 XCP25 xapi: [debug||5937051 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:8764d28b0bf7 created by task D:a5ddc3bfd71a Oct 14 20:08:10 XCP25 xapi: [debug||5937052 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:event.from D:6065e89fe628 created by task D:6f7ddf1004ca Oct 14 20:08:21 XCP25 xapi: [debug||5863012 ||storage_access] Calling UPDATES.get Async.VM.migrate_send R:326d34bf7507 1513 30 Oct 14 20:08:28 XCP25 xapi: [debug||5937053 HTTPS 10.10.10.95->:::80|host.call_plugin R:87e6fbe888db|audit] Host.call_plugin host = '8d6e2b03-54c1-4523-b45b-d572a268f2cc (XCP25)'; plugin = 'updater.py'; fn = 'check_update' args = [ 'hidden' ] Oct 14 20:08:34 XCP25 xapi: [debug||1206 scanning_thread|SR scanner D:3b6b5f2d8cde|xapi_sr] Automatically scanning SRs = [ OpaqueRef:88574456-65df-41a3-8d3e-8a77ba64c325 ] Oct 14 20:08:34 XCP25 xapi: [debug||5937054 ||dummytaskhelper] task scan one D:d8f66c365df0 created by task D:3b6b5f2d8cde Oct 14 20:08:34 XCP25 xapi: [debug||5937055 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:session.slave_login D:f5e7ad04b586 created by task D:d8f66c365df0 Oct 14 20:08:34 XCP25 xapi: [ info||5937055 /var/lib/xcp/xapi|session.slave_login D:ce7268ef0614|xapi_session] Session.create trackid=ff51937fbb6d791a6782e500ea141ebd pool=true uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:08:34 XCP25 xapi: [debug||5937056 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:3879140491b4 created by task D:ce7268ef0614 Oct 14 20:08:34 XCP25 xapi: [debug||5937057 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.scan D:dbecb7ccd19e created by task D:d8f66c365df0 Oct 14 20:08:34 XCP25 xapi: [ info||5937057 /var/lib/xcp/xapi||taskhelper] task SR.scan R:a5f1f462d604 (uuid:b452ba4f-7f32-05ee-fbfb-1ef693e3cc45) created (trackid=ff51937fbb6d791a6782e500ea141ebd) by task D:d8f66c365df0 Oct 14 20:08:34 XCP25 xapi: [debug||5937057 /var/lib/xcp/xapi|SR.scan R:a5f1f462d604|message_forwarding] SR.scan: SR = 'ef3c3e29-6bb9-64f2-1174-1f0295bdd4f1 (NFS ISO)' Oct 14 20:08:34 XCP25 xapi: [debug||5937057 /var/lib/xcp/xapi|SR.scan R:a5f1f462d604|message_forwarding] Marking SR for SR.scan (task=OpaqueRef:a5f1f462-d604-4b6d-975a-8b9de6adbeea) Oct 14 20:08:34 XCP25 xapi: [ info||5937057 /var/lib/xcp/xapi|SR.scan R:a5f1f462d604|storage_impl] SR.scan dbg:OpaqueRef:a5f1f462-d604-4b6d-975a-8b9de6adbeea sr:ef3c3e29-6bb9-64f2-1174-1f0295bdd4f1 Oct 14 20:08:34 XCP25 xapi: [debug||5937058 ||dummytaskhelper] task SR.scan D:313b7a27e7da created by task R:a5f1f462d604 Oct 14 20:08:34 XCP25 xapi: [debug||5937058 |SR.scan D:313b7a27e7da|sm] SM iso sr_scan sr=OpaqueRef:88574456-65df-41a3-8d3e-8a77ba64c325 Oct 14 20:08:34 XCP25 xapi: [ info||5937058 |sm_exec D:845dd7865b9f|xapi_session] Session.create trackid=66834ddc5e5285536c15f1ac50df5cdc pool=false uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:08:34 XCP25 xapi: [debug||5937059 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:8063ba7a7d41 created by task D:845dd7865b9f Oct 14 20:08:34 XCP25 xapi: [debug||5937060 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:host.get_other_config D:4556bd137229 created by task D:313b7a27e7da Oct 14 20:08:34 XCP25 xapi: [debug||5937061 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_by_uuid D:6ca840d7afda created by task D:313b7a27e7da Oct 14 20:08:34 XCP25 xapi: [debug||5937062 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_all_records_where D:1b6a5b7021fd created by task D:313b7a27e7da Oct 14 20:08:34 XCP25 xapi: [debug||5937063 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_other_config D:b5e2e99ffbbe created by task D:313b7a27e7da Oct 14 20:08:34 XCP25 xapi: [debug||5937064 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_by_uuid D:3cb46f48f2ef created by task D:313b7a27e7da Oct 14 20:08:34 XCP25 xapi: [debug||5937065 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.set_virtual_allocation D:1e2b57972ba3 created by task D:313b7a27e7da Oct 14 20:08:34 XCP25 xapi: [debug||5937066 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.set_physical_size D:dffedd141359 created by task D:313b7a27e7da Oct 14 20:08:34 XCP25 xapi: [debug||5937067 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.set_physical_utilisation D:f88432fcc1a3 created by task D:313b7a27e7da Oct 14 20:08:34 XCP25 xapi: [debug||5937068 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_by_uuid D:787ad0a3944b created by task D:313b7a27e7da Oct 14 20:08:34 XCP25 xapi: [debug||5937069 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_all_records_where D:2e8142c3c0e4 created by task D:313b7a27e7da Oct 14 20:08:34 XCP25 xapi: [ info||5937058 |sm_exec D:845dd7865b9f|xapi_session] Session.destroy trackid=66834ddc5e5285536c15f1ac50df5cdc Oct 14 20:08:34 XCP25 xapi: [ info||5937057 /var/lib/xcp/xapi|SR.scan R:a5f1f462d604|storage_impl] SR.stat dbg:OpaqueRef:a5f1f462-d604-4b6d-975a-8b9de6adbeea sr:ef3c3e29-6bb9-64f2-1174-1f0295bdd4f1 Oct 14 20:08:34 XCP25 xapi: [debug||5937070 ||dummytaskhelper] task SR.stat D:dd9054caa0fb created by task R:a5f1f462d604 Oct 14 20:08:34 XCP25 xapi: [debug||5937070 |SR.stat D:dd9054caa0fb|sm] SM iso sr_update sr=OpaqueRef:88574456-65df-41a3-8d3e-8a77ba64c325 Oct 14 20:08:34 XCP25 xapi: [ info||5937070 |sm_exec D:bb09160d22de|xapi_session] Session.create trackid=fc0a3f32aece7629f00365776454ed30 pool=false uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:08:34 XCP25 xapi: [debug||5937071 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:e5afddd407de created by task D:bb09160d22de Oct 14 20:08:35 XCP25 xapi: [debug||5937072 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:host.get_other_config D:4b18f41c6525 created by task D:dd9054caa0fb Oct 14 20:08:35 XCP25 xapi: [ info||5937070 |sm_exec D:bb09160d22de|xapi_session] Session.destroy trackid=fc0a3f32aece7629f00365776454ed30 Oct 14 20:08:35 XCP25 xapi: [debug||5937057 /var/lib/xcp/xapi|SR.scan R:a5f1f462d604|message_forwarding] Unmarking SR after SR.scan (task=OpaqueRef:a5f1f462-d604-4b6d-975a-8b9de6adbeea) Oct 14 20:08:35 XCP25 xapi: [debug||5937073 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:session.logout D:a0e0d854d184 created by task D:d8f66c365df0 Oct 14 20:08:35 XCP25 xapi: [ info||5937073 /var/lib/xcp/xapi|session.logout D:9136bbc420aa|xapi_session] Session.destroy trackid=ff51937fbb6d791a6782e500ea141ebd Oct 14 20:08:35 XCP25 xapi: [debug||5937054 |scan one D:d8f66c365df0|xapi_sr] Scan of SR ef3c3e29-6bb9-64f2-1174-1f0295bdd4f1 complete. Oct 14 20:08:40 XCP25 xcp-rrdd: [ info||7 ||rrdd_main] GC live_words = 611650 Oct 14 20:08:40 XCP25 xcp-rrdd: [ info||7 ||rrdd_main] GC heap_words = 1104896 Oct 14 20:08:40 XCP25 xcp-rrdd: [ info||7 ||rrdd_main] GC free_words = 493219 Oct 14 20:08:40 XCP25 xapi: [debug||1202 ||dummytaskhelper] task timeboxed_rpc D:6bd464e2960d created by task D:54124fdb6d24 Oct 14 20:08:40 XCP25 xapi: [debug||5937074 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:session.logout D:5f879d2b7fe3 created by task D:6f7ddf1004ca Oct 14 20:08:40 XCP25 xapi: [ info||5937074 /var/lib/xcp/xapi|session.logout D:a2a8582f331c|xapi_session] Session.destroy trackid=838ee567e924112759cea98634caba99 Oct 14 20:08:40 XCP25 xapi: [debug||5937075 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:event.from D:6723dbe03ce8 created by task D:54124fdb6d24 Oct 14 20:08:40 XCP25 xapi: [debug||5937076 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:session.slave_login D:618b7d1076cf created by task D:6f7ddf1004ca Oct 14 20:08:40 XCP25 xapi: [ info||5937076 /var/lib/xcp/xapi|session.slave_login D:e4d27518870c|xapi_session] Session.create trackid=95c8554c09045cf729a67ce6b25d2f28 pool=true uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:08:40 XCP25 xapi: [debug||5937077 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:94db5982a3f0 created by task D:e4d27518870c Oct 14 20:08:40 XCP25 xapi: [debug||5937078 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:event.from D:d4becbd10f5e created by task D:6f7ddf1004ca Oct 14 20:08:43 XCP25 xenopsd-xc: [debug||5 ||xenops_server] Received an event on managed VM 3797df5e-695a-00be-86bd-318a7c48860f Oct 14 20:08:43 XCP25 xcp-rrdd: [ info||9 ||rrdd_main] memfree has changed to 11903788 in domain 23 Oct 14 20:08:43 XCP25 xenopsd-xc: [debug||5 |queue|xenops_server] Queue.push ["VM_check_state","3797df5e-695a-00be-86bd-318a7c48860f"] onto 3797df5e-695a-00be-86bd-318a7c48860f:[ ] Oct 14 20:08:43 XCP25 xenopsd-xc: [debug||27 ||xenops_server] Queue.pop returned ["VM_check_state","3797df5e-695a-00be-86bd-318a7c48860f"] Oct 14 20:08:43 XCP25 xenopsd-xc: [debug||27 |events|xenops_server] Task 324528 reference events: ["VM_check_state","3797df5e-695a-00be-86bd-318a7c48860f"] Oct 14 20:08:43 XCP25 xenopsd-xc: [debug||27 |events|xenops_server] VM 3797df5e-695a-00be-86bd-318a7c48860f is not requesting any attention Oct 14 20:08:43 XCP25 xenopsd-xc: [debug||27 |events|xenops_server] VM_DB.signal 3797df5e-695a-00be-86bd-318a7c48860f Oct 14 20:08:43 XCP25 xenopsd-xc: [debug||27 |events|task_server] Task 324528 completed; duration = 0 Oct 14 20:08:43 XCP25 xenopsd-xc: [debug||27 ||xenops_server] TASK.signal 324528 (object deleted) Oct 14 20:08:43 XCP25 xapi: [debug||1197 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops] Processing event: ["Vm","3797df5e-695a-00be-86bd-318a7c48860f"] Oct 14 20:08:43 XCP25 xapi: [debug||1197 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops] xenops event on VM 3797df5e-695a-00be-86bd-318a7c48860f Oct 14 20:08:43 XCP25 xenopsd-xc: [debug||655128 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops_server] VM.stat 3797df5e-695a-00be-86bd-318a7c48860f Oct 14 20:08:43 XCP25 xapi: [debug||1197 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops] xenopsd event: processing event for VM 3797df5e-695a-00be-86bd-318a7c48860f Oct 14 20:08:43 XCP25 xapi: [debug||1197 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops] Supressing VM.allowed_operations update because guest_agent data is largely the same Oct 14 20:08:43 XCP25 xapi: [debug||1197 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops] xenopsd event: Updating VM 3797df5e-695a-00be-86bd-318a7c48860f domid 23 guest_agent Oct 14 20:08:51 XCP25 xapi: [debug||5863012 ||storage_access] Calling UPDATES.get Async.VM.migrate_send R:326d34bf7507 1513 30 [22:04 XCP25 ~]# grep "Oct 14 20:09" /var/log/xensource.log Oct 14 20:09:02 XCP25 xapi: [debug||47 dbflush [/var/lib/xcp/state.db]||sql] XML backend [/var/lib/xcp/state.db] -- Write buffer flushed. Time: 0.046842 Oct 14 20:09:04 XCP25 xapi: [debug||1206 scanning_thread|SR scanner D:3b6b5f2d8cde|xapi_sr] Automatically scanning SRs = [ OpaqueRef:88574456-65df-41a3-8d3e-8a77ba64c325 ] Oct 14 20:09:04 XCP25 xapi: [debug||5937079 ||dummytaskhelper] task scan one D:cca6e7e1fdfa created by task D:3b6b5f2d8cde Oct 14 20:09:04 XCP25 xapi: [debug||5937080 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:session.slave_login D:9cb9fc3525c2 created by task D:cca6e7e1fdfa Oct 14 20:09:04 XCP25 xapi: [ info||5937080 /var/lib/xcp/xapi|session.slave_login D:665bc79bb73a|xapi_session] Session.create trackid=796184b622de3b19d491b9015949ed1c pool=true uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:04 XCP25 xapi: [debug||5937081 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:0409990bbe4d created by task D:665bc79bb73a Oct 14 20:09:04 XCP25 xapi: [debug||5937082 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.scan D:0d2a928a3b51 created by task D:cca6e7e1fdfa Oct 14 20:09:04 XCP25 xapi: [ info||5937082 /var/lib/xcp/xapi||taskhelper] task SR.scan R:ad9b33000794 (uuid:80c6f07f-8a6c-4b01-1b6d-ce091e82459d) created (trackid=796184b622de3b19d491b9015949ed1c) by task D:cca6e7e1fdfa Oct 14 20:09:04 XCP25 xapi: [debug||5937082 /var/lib/xcp/xapi|SR.scan R:ad9b33000794|message_forwarding] SR.scan: SR = 'ef3c3e29-6bb9-64f2-1174-1f0295bdd4f1 (NFS ISO)' Oct 14 20:09:04 XCP25 xapi: [debug||5937082 /var/lib/xcp/xapi|SR.scan R:ad9b33000794|message_forwarding] Marking SR for SR.scan (task=OpaqueRef:ad9b3300-0794-41b3-aa33-43dec98ec430) Oct 14 20:09:04 XCP25 xapi: [ info||5937082 /var/lib/xcp/xapi|SR.scan R:ad9b33000794|storage_impl] SR.scan dbg:OpaqueRef:ad9b3300-0794-41b3-aa33-43dec98ec430 sr:ef3c3e29-6bb9-64f2-1174-1f0295bdd4f1 Oct 14 20:09:04 XCP25 xapi: [debug||5937083 ||dummytaskhelper] task SR.scan D:c727c176e6e6 created by task R:ad9b33000794 Oct 14 20:09:04 XCP25 xapi: [debug||5937083 |SR.scan D:c727c176e6e6|sm] SM iso sr_scan sr=OpaqueRef:88574456-65df-41a3-8d3e-8a77ba64c325 Oct 14 20:09:04 XCP25 xapi: [ info||5937083 |sm_exec D:506a4248a409|xapi_session] Session.create trackid=3eef1aef114e3834f456594fad37a04e pool=false uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:04 XCP25 xapi: [debug||5937084 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:cedae5c26ed4 created by task D:506a4248a409 Oct 14 20:09:04 XCP25 xapi: [debug||5937085 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:host.get_other_config D:7728ca1cce55 created by task D:c727c176e6e6 Oct 14 20:09:05 XCP25 xapi: [debug||5937086 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_by_uuid D:46914eeb4a69 created by task D:c727c176e6e6 Oct 14 20:09:05 XCP25 xapi: [debug||5937087 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_all_records_where D:06a1ac367945 created by task D:c727c176e6e6 Oct 14 20:09:05 XCP25 xapi: [debug||5937088 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_other_config D:de77be09846e created by task D:c727c176e6e6 Oct 14 20:09:05 XCP25 xapi: [debug||5937089 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_by_uuid D:81e51065b685 created by task D:c727c176e6e6 Oct 14 20:09:05 XCP25 xapi: [debug||5937090 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.set_virtual_allocation D:07928874555b created by task D:c727c176e6e6 Oct 14 20:09:05 XCP25 xapi: [debug||5937091 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.set_physical_size D:e728877df525 created by task D:c727c176e6e6 Oct 14 20:09:05 XCP25 xapi: [debug||5937092 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.set_physical_utilisation D:75e2db47036a created by task D:c727c176e6e6 Oct 14 20:09:05 XCP25 xapi: [debug||5937093 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_by_uuid D:c73ad21f2885 created by task D:c727c176e6e6 Oct 14 20:09:05 XCP25 xapi: [debug||5937094 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_all_records_where D:6bac6b3e25a8 created by task D:c727c176e6e6 Oct 14 20:09:05 XCP25 xapi: [ info||5937083 |sm_exec D:506a4248a409|xapi_session] Session.destroy trackid=3eef1aef114e3834f456594fad37a04e Oct 14 20:09:05 XCP25 xapi: [ info||5937082 /var/lib/xcp/xapi|SR.scan R:ad9b33000794|storage_impl] SR.stat dbg:OpaqueRef:ad9b3300-0794-41b3-aa33-43dec98ec430 sr:ef3c3e29-6bb9-64f2-1174-1f0295bdd4f1 Oct 14 20:09:05 XCP25 xapi: [debug||5937095 ||dummytaskhelper] task SR.stat D:2a9e62cf6c84 created by task R:ad9b33000794 Oct 14 20:09:05 XCP25 xapi: [debug||5937095 |SR.stat D:2a9e62cf6c84|sm] SM iso sr_update sr=OpaqueRef:88574456-65df-41a3-8d3e-8a77ba64c325 Oct 14 20:09:05 XCP25 xapi: [ info||5937095 |sm_exec D:00498f82eb7b|xapi_session] Session.create trackid=32845980187fc335fce27dd27d78073e pool=false uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:05 XCP25 xapi: [debug||5937096 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:7934eb0e160b created by task D:00498f82eb7b Oct 14 20:09:05 XCP25 xapi: [debug||5937097 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:host.get_other_config D:b85aba1d4d6b created by task D:2a9e62cf6c84 Oct 14 20:09:05 XCP25 xapi: [ info||5937095 |sm_exec D:00498f82eb7b|xapi_session] Session.destroy trackid=32845980187fc335fce27dd27d78073e Oct 14 20:09:05 XCP25 xapi: [debug||5937082 /var/lib/xcp/xapi|SR.scan R:ad9b33000794|message_forwarding] Unmarking SR after SR.scan (task=OpaqueRef:ad9b3300-0794-41b3-aa33-43dec98ec430) Oct 14 20:09:05 XCP25 xapi: [debug||5937098 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:session.logout D:e2d4b82d815a created by task D:cca6e7e1fdfa Oct 14 20:09:05 XCP25 xapi: [ info||5937098 /var/lib/xcp/xapi|session.logout D:a4e535b1280c|xapi_session] Session.destroy trackid=796184b622de3b19d491b9015949ed1c Oct 14 20:09:05 XCP25 xapi: [debug||5937079 |scan one D:cca6e7e1fdfa|xapi_sr] Scan of SR ef3c3e29-6bb9-64f2-1174-1f0295bdd4f1 complete. Oct 14 20:09:06 XCP25 xapi: [error||3 ||storage_migrate] Tapdisk mirroring has failed Oct 14 20:09:06 XCP25 xapi: [debug||24 |sm_events D:3f117f94a984|storage_access] sm event on mirror: bb502d0d-3f9b-7ecd-723b-6363f5de9b96/b607eebc-49ad-4fc0-ad4a-b605fedfc51e Oct 14 20:09:06 XCP25 xapi: [ info||24 |sm_events D:3f117f94a984|storage_impl] DATA.MIRROR.stat dbg:sm_events D:3f117f94a984 id:bb502d0d-3f9b-7ecd-723b-6363f5de9b96/b607eebc-49ad-4fc0-ad4a-b605fedfc51e Oct 14 20:09:06 XCP25 xapi: [debug||5863012 ||storage_access] Received update: ["Mirror","bb502d0d-3f9b-7ecd-723b-6363f5de9b96/b607eebc-49ad-4fc0-ad4a-b605fedfc51e"] Oct 14 20:09:06 XCP25 xapi: [debug||5863012 ||storage_access] Calling UPDATES.get Async.VM.migrate_send R:326d34bf7507 1514 30 Oct 14 20:09:06 XCP25 xapi: [debug||24 |sm_events D:3f117f94a984|storage_access] Mirror bb502d0d-3f9b-7ecd-723b-6363f5de9b96/b607eebc-49ad-4fc0-ad4a-b605fedfc51e has failed Oct 14 20:09:06 XCP25 xapi: [debug||24 |sm_events D:3f117f94a984|storage_access] Mirror associated with task: OpaqueRef:326d34bf-7507-44dc-ab19-47bf16e4d787 Oct 14 20:09:06 XCP25 xapi: [debug||5937099 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:session.slave_login D:58224db21529 created by task D:3f117f94a984 Oct 14 20:09:06 XCP25 xapi: [ info||5937099 /var/lib/xcp/xapi|session.slave_login D:4cf0fa1c0d0a|xapi_session] Session.create trackid=8758982519d00d68c95e92b4a3cdb4e8 pool=true uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:06 XCP25 xapi: [debug||5937100 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:171fbc439ee3 created by task D:4cf0fa1c0d0a Oct 14 20:09:06 XCP25 xapi: [debug||5937101 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:task.cancel D:22f4029981d2 created by task D:3f117f94a984 Oct 14 20:09:06 XCP25 xapi: [ info||5937101 /var/lib/xcp/xapi|task.cancel D:8afce7b28c5e|storage_access] storage_access: TASK.cancel 14 Oct 14 20:09:06 XCP25 xapi: [debug||5937102 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:session.logout D:a118851b69db created by task D:3f117f94a984 Oct 14 20:09:06 XCP25 xapi: [ info||5937102 /var/lib/xcp/xapi|session.logout D:286cd3445e2e|xapi_session] Session.destroy trackid=8758982519d00d68c95e92b4a3cdb4e8 Oct 14 20:09:06 XCP25 xapi: [error||5909120 ||sparse_dd_wrapper] Failure from sparse_dd: Using protocol: nbd\x0A raising End_of_file Oct 14 20:09:06 XCP25 xapi: [ info||5908951 |Async.VM.migrate_send R:326d34bf7507|task_server] Task 14 has been cancelled: raising Cancelled exception Oct 14 20:09:06 XCP25 xapi: [ info||5937104 HTTP 127.0.0.1->:::80|session.slave_login D:26379d005460|xapi_session] Session.create trackid=9ff13714ac1adf328ae6bd7cceeef139 pool=true uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:06 XCP25 xapi: [debug||5937105 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:4e887cd4d552 created by task D:26379d005460 Oct 14 20:09:06 XCP25 xapi: [ info||5937103 HTTP 127.0.0.1->:::80|Querying services D:f75c5e7c95cb|storage_impl] VDI.deactivate dbg:Async.VM.migrate_send R:326d34bf7507 dp:b09a2759-a0ee-8d15-8fbb-7dd8f72af079 sr:bb502d0d-3f9b-7ecd-723b-6363f5de9b96 vdi:6622ac6f-ae32-4a2a-b081-ad3444af3d24 vm:0 Oct 14 20:09:06 XCP25 xapi: [debug||5937106 ||dummytaskhelper] task VDI.deactivate D:fbe9de6e53c3 created by task O:Async.VM.mig Oct 14 20:09:06 XCP25 xapi: [debug||5937106 |VDI.deactivate D:fbe9de6e53c3|dummytaskhelper] task VDI.deactivate D:771649730bc9 created by task O:Async.VM.mig Oct 14 20:09:06 XCP25 xapi: [debug||5937106 ||sm] SM nfs vdi_deactivate sr=OpaqueRef:a909a187-63e5-48d3-9de2-7bacfc43caf6 vdi=OpaqueRef:e9d2854d-3d93-41c1-880d-4ff04cb7c694 Oct 14 20:09:06 XCP25 xapi: [ info||5937106 |sm_exec D:506ddcb11850|xapi_session] Session.create trackid=2f65f6755f85aecd9ec7a35a3bbf93c4 pool=false uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:06 XCP25 xapi: [debug||5937107 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:5114583aee0b created by task D:506ddcb11850 Oct 14 20:09:06 XCP25 xapi: [debug||5937108 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:host.get_other_config D:ac2289813f6d created by task D:fbe9de6e53c3 Oct 14 20:09:06 XCP25 xapi: [debug||5937109 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_sm_config D:fce260b4b252 created by task D:fbe9de6e53c3 Oct 14 20:09:06 XCP25 xapi: [debug||5937110 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_other_config D:574bb48742aa created by task D:fbe9de6e53c3 Oct 14 20:09:06 XCP25 xapi: [debug||5937111 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_other_config D:2aa7fe2d5991 created by task D:fbe9de6e53c3 Oct 14 20:09:06 XCP25 xapi: [debug||5937112 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_by_uuid D:de59d4155ab1 created by task D:fbe9de6e53c3 Oct 14 20:09:06 XCP25 xapi: [debug||5937113 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_sm_config D:9aabdb3b7b30 created by task D:fbe9de6e53c3 Oct 14 20:09:07 XCP25 xapi: [debug||5937114 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_by_uuid D:d8ab8ba54597 created by task D:fbe9de6e53c3 Oct 14 20:09:07 XCP25 xapi: [debug||5937115 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.remove_from_sm_config D:092f2e9640f1 created by task D:fbe9de6e53c3 Oct 14 20:09:07 XCP25 xapi: [debug||5937115 /var/lib/xcp/xapi||api_effect] VDI.remove_from_sm_config Oct 14 20:09:07 XCP25 xapi: [debug||5937116 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.remove_from_sm_config D:d76beb8ba65d created by task D:fbe9de6e53c3 Oct 14 20:09:07 XCP25 xapi: [debug||5937116 /var/lib/xcp/xapi||api_effect] VDI.remove_from_sm_config Oct 14 20:09:07 XCP25 xapi: [debug||5937117 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_by_uuid D:0a2d2b04614a created by task D:fbe9de6e53c3 Oct 14 20:09:07 XCP25 xapi: [debug||5937118 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_SR D:6d001ab1a2e6 created by task D:fbe9de6e53c3 Oct 14 20:09:07 XCP25 xapi: [debug||5937119 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_uuid D:f2121a093ad2 created by task D:fbe9de6e53c3 Oct 14 20:09:07 XCP25 xapi: [debug||5937120 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_by_uuid D:577d3c0ed038 created by task D:fbe9de6e53c3 Oct 14 20:09:07 XCP25 xapi: [debug||5937121 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_type D:bef5633a8e1e created by task D:fbe9de6e53c3 Oct 14 20:09:07 XCP25 xapi: [debug||5937122 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SM.get_all_records_where D:042f53d1fc88 created by task D:fbe9de6e53c3 Oct 14 20:09:07 XCP25 xapi: [debug||5937123 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SM.get_driver_filename D:80981537ad1f created by task D:fbe9de6e53c3 Oct 14 20:09:07 XCP25 xapi: [debug||5937124 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VM.get_all_records_where D:9c2e29deda0c created by task D:fbe9de6e53c3 Oct 14 20:09:07 XCP25 xapi: [debug||5937125 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:PBD.get_all_records_where D:2708374ba975 created by task D:fbe9de6e53c3 Oct 14 20:09:07 XCP25 xapi: [debug||5937126 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:PBD.get_device_config D:0769e9ee420a created by task D:fbe9de6e53c3 Oct 14 20:09:07 XCP25 xapi: [ info||5937131 /var/lib/xcp/xapi|session.login_with_password D:29a359dfb209|xapi_session] Session.create trackid=d2d574e07bc09aad54eb9f57e56420bb pool=false uname=root originator=SM is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:07 XCP25 xapi: [debug||5937132 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:7451a35e45a1 created by task D:29a359dfb209 Oct 14 20:09:07 XCP25 xapi: [ info||5937140 /var/lib/xcp/xapi|session.logout D:16e43afe60e2|xapi_session] Session.destroy trackid=d2d574e07bc09aad54eb9f57e56420bb Oct 14 20:09:07 XCP25 xapi: [debug||5937141 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_by_uuid D:d1dcf57bce9b created by task D:fbe9de6e53c3 Oct 14 20:09:07 XCP25 xapi: [debug||5937142 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:host.get_by_uuid D:3abf92e5883d created by task D:fbe9de6e53c3 Oct 14 20:09:07 XCP25 xapi: [debug||5937143 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_sm_config D:b2fc4307b5a2 created by task D:fbe9de6e53c3 Oct 14 20:09:07 XCP25 xapi: [debug||5937144 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.remove_from_sm_config D:bf176728a522 created by task D:fbe9de6e53c3 Oct 14 20:09:07 XCP25 xapi: [debug||5937144 /var/lib/xcp/xapi||api_effect] VDI.remove_from_sm_config Oct 14 20:09:07 XCP25 xapi: [ info||5937106 |sm_exec D:506ddcb11850|xapi_session] Session.destroy trackid=2f65f6755f85aecd9ec7a35a3bbf93c4 Oct 14 20:09:07 XCP25 xapi: [debug||5937103 HTTP 127.0.0.1->:::80|Querying services D:f75c5e7c95cb|storage_impl] dbg:Async.VM.migrate_send R:326d34bf7507 dp:b09a2759-a0ee-8d15-8fbb-7dd8f72af079 sr:bb502d0d-3f9b-7ecd-723b-6363f5de9b96 vdi:6622ac6f-ae32-4a2a-b081-ad3444af3d24 superstate:attached RO Oct 14 20:09:07 XCP25 xapi: [ info||5937145 HTTP 127.0.0.1->:::80|session.logout D:cda745737b2b|xapi_session] Session.destroy trackid=9ff13714ac1adf328ae6bd7cceeef139 Oct 14 20:09:07 XCP25 xapi: [ info||5937147 HTTP 127.0.0.1->:::80|session.slave_login D:0450e4269307|xapi_session] Session.create trackid=47565cc9ce24794c891e1cda654a941d pool=true uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:07 XCP25 xapi: [debug||5937148 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:2089d468e3c5 created by task D:0450e4269307 Oct 14 20:09:07 XCP25 xapi: [ info||5937146 HTTP 127.0.0.1->:::80|Querying services D:05e51a78cb0f|storage_impl] VDI.detach dbg:Async.VM.migrate_send R:326d34bf7507 dp:b09a2759-a0ee-8d15-8fbb-7dd8f72af079 sr:bb502d0d-3f9b-7ecd-723b-6363f5de9b96 vdi:6622ac6f-ae32-4a2a-b081-ad3444af3d24 vm:0 Oct 14 20:09:07 XCP25 xapi: [debug||5937149 ||dummytaskhelper] task VDI.detach D:45f13c7db580 created by task O:Async.VM.mig Oct 14 20:09:07 XCP25 xapi: [debug||5937149 |VDI.detach D:45f13c7db580|sm] SM nfs vdi_detach sr=OpaqueRef:a909a187-63e5-48d3-9de2-7bacfc43caf6 vdi=OpaqueRef:e9d2854d-3d93-41c1-880d-4ff04cb7c694 Oct 14 20:09:07 XCP25 xapi: [ info||5937149 |sm_exec D:5ddef7ba6acd|xapi_session] Session.create trackid=bc4f7b3ccd84f6e48dc8356fa4a9daa5 pool=false uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:07 XCP25 xapi: [debug||5937150 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:82475d931e3d created by task D:5ddef7ba6acd Oct 14 20:09:07 XCP25 xapi: [debug||5937151 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:host.get_other_config D:e787ea0a55f7 created by task D:45f13c7db580 Oct 14 20:09:07 XCP25 xapi: [debug||5937152 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_sm_config D:3dcdb3d56075 created by task D:45f13c7db580 Oct 14 20:09:07 XCP25 xapi: [debug||5937153 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_other_config D:8b8d1c0e71e6 created by task D:45f13c7db580 Oct 14 20:09:07 XCP25 xapi: [debug||5937154 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_other_config D:5751542c661a created by task D:45f13c7db580 Oct 14 20:09:07 XCP25 xapi: [ info||5937149 |sm_exec D:5ddef7ba6acd|xapi_session] Session.destroy trackid=bc4f7b3ccd84f6e48dc8356fa4a9daa5 Oct 14 20:09:07 XCP25 xapi: [debug||5937149 ||dummytaskhelper] task VDI.detach D:275eaf01ec86 created by task O:Async.VM.mig Oct 14 20:09:07 XCP25 xapi: [debug||5937146 HTTP 127.0.0.1->:::80|Querying services D:05e51a78cb0f|storage_impl] dbg:Async.VM.migrate_send R:326d34bf7507 dp:b09a2759-a0ee-8d15-8fbb-7dd8f72af079 sr:bb502d0d-3f9b-7ecd-723b-6363f5de9b96 vdi:6622ac6f-ae32-4a2a-b081-ad3444af3d24 superstate:detached Oct 14 20:09:07 XCP25 xapi: [ info||5937155 HTTP 127.0.0.1->:::80|session.logout D:6fb690d3a4f3|xapi_session] Session.destroy trackid=47565cc9ce24794c891e1cda654a941d Oct 14 20:09:07 XCP25 xapi: [debug||5908951 |Async.VM.migrate_send R:326d34bf7507|stunnel] stunnel start Oct 14 20:09:07 XCP25 xapi: [debug||5908951 |Async.VM.migrate_send R:326d34bf7507|xmlrpc_client] stunnel pid: 27427 (cached = false) connected to 10.10.1.11:443 Oct 14 20:09:07 XCP25 xapi: [debug||5908951 |Async.VM.migrate_send R:326d34bf7507|xmlrpc_client] with_recorded_stunnelpid task_opt=None s_pid=27427 Oct 14 20:09:08 XCP25 xapi: [error||5908951 |Async.VM.migrate_send R:326d34bf7507|storage_migrate] Caught Storage_error ([S(Cancelled);S(14)]): performing cleanup actions Oct 14 20:09:08 XCP25 xapi: [error||5908951 |Async.VM.migrate_send R:326d34bf7507|storage_migrate] Caught Storage_error ([S(Cancelled);S(14)]): copying snapshots vdi Oct 14 20:09:08 XCP25 xapi: [error||5908951 |Async.VM.migrate_send R:326d34bf7507|task_server] Task 14 failed; Storage_error ([S(Internal_error);S(Storage_error ([S(Internal_error);S(Storage_error ([S(Internal_error);S(Storage_error ([S(Cancelled);S(14)]))]))]))]) Oct 14 20:09:08 XCP25 xapi: [debug||5908951 |Async.VM.migrate_send R:326d34bf7507|storage] TASK.signal 14 = ["Failed",["Internal_error","Storage_error ([S(Internal_error);S(Storage_error ([S(Internal_error);S(Storage_error ([S(Cancelled);S(14)]))]))])"]] Oct 14 20:09:08 XCP25 xapi: [debug||5863012 ||storage_access] Received update: ["Task","14"] Oct 14 20:09:08 XCP25 xapi: [debug||24 |sm_events D:3f117f94a984|storage_access] sm event on Task 14 Oct 14 20:09:08 XCP25 xapi: [ info||5937157 HTTP 127.0.0.1->:::80|session.slave_login D:49bc7661d01d|xapi_session] Session.create trackid=ee8243df58bc8495e5d34f0b56b07c5e pool=true uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:08 XCP25 xapi: [debug||5937158 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:939af7a0a8b1 created by task D:49bc7661d01d Oct 14 20:09:08 XCP25 xapi: [ info||5937156 HTTP 127.0.0.1->:::80|Querying services D:5f79cff03daf|storage_impl] DP.destroy dbg:Async.VM.migrate_send R:326d34bf7507 dp:copy_vbd/b28f7ad9-597d-2608-409b-516f44cd9b14/6622ac6f-ae32-4a2a-b081-ad3444af3d24 allow_leak:false Oct 14 20:09:08 XCP25 xapi: [debug||5937156 HTTP 127.0.0.1->:::80|Querying services D:5f79cff03daf|storage_impl] [destroy_sr] Filtered VDI count:0 Oct 14 20:09:08 XCP25 xapi: message repeated 6 times: [ [debug||5937156 HTTP 127.0.0.1->:::80|Querying services D:5f79cff03daf|storage_impl] [destroy_sr] Filtered VDI count:0] Oct 14 20:09:08 XCP25 xapi: [ info||5937159 HTTP 127.0.0.1->:::80|session.logout D:8d56932cdb54|xapi_session] Session.destroy trackid=ee8243df58bc8495e5d34f0b56b07c5e Oct 14 20:09:08 XCP25 xapi: [ info||5937161 HTTP 127.0.0.1->:::80|session.slave_login D:5534afe0e5a0|xapi_session] Session.create trackid=369e4f8269530f954bb7d6fab400a7b3 pool=true uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:08 XCP25 xapi: [debug||5937162 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:c9991aab157f created by task D:5534afe0e5a0 Oct 14 20:09:08 XCP25 xapi: [ info||5937160 HTTP 127.0.0.1->:::80|Querying services D:7036307e0f04|storage_impl] DATA.MIRROR.stat dbg:Async.VM.migrate_send R:326d34bf7507 id:bb502d0d-3f9b-7ecd-723b-6363f5de9b96/d7db37b2-a897-469b-a352-33898ba24e2a Oct 14 20:09:08 XCP25 xapi: [ info||5937163 HTTP 127.0.0.1->:::80|session.logout D:95bcaa624209|xapi_session] Session.destroy trackid=369e4f8269530f954bb7d6fab400a7b3 Oct 14 20:09:08 XCP25 xapi: [ info||5937165 HTTP 127.0.0.1->:::80|session.slave_login D:7432bfe0352a|xapi_session] Session.create trackid=5afc9d4325b1c2cc51ae0e55911349e3 pool=true uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:08 XCP25 xapi: [debug||5937166 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:31bf98fb8eaf created by task D:7432bfe0352a Oct 14 20:09:08 XCP25 xapi: [ info||5937164 HTTP 127.0.0.1->:::80|Querying services D:9cffa2e474c8|storage_impl] DATA.MIRROR.stop dbg:Async.VM.migrate_send R:326d34bf7507 id:bb502d0d-3f9b-7ecd-723b-6363f5de9b96/d7db37b2-a897-469b-a352-33898ba24e2a Oct 14 20:09:08 XCP25 xapi: [ info||5937168 HTTP 127.0.0.1->:::80|session.slave_login D:941662f3af7b|xapi_session] Session.create trackid=d87234caf38ca7b33ac2a295efb61226 pool=true uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:08 XCP25 xapi: [debug||5937169 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:d6e6fa54ee77 created by task D:941662f3af7b Oct 14 20:09:08 XCP25 xapi: [ info||5937167 HTTP 127.0.0.1->:::80|Querying services D:58a92f0f32e0|storage_impl] SR.scan dbg:Async.VM.migrate_send R:326d34bf7507 sr:bb502d0d-3f9b-7ecd-723b-6363f5de9b96 Oct 14 20:09:08 XCP25 xapi: [debug||5937170 ||dummytaskhelper] task SR.scan D:6065f5e4365a created by task O:Async.VM.mig Oct 14 20:09:08 XCP25 xapi: [debug||5937170 |SR.scan D:6065f5e4365a|sm] SM nfs sr_scan sr=OpaqueRef:a909a187-63e5-48d3-9de2-7bacfc43caf6 Oct 14 20:09:08 XCP25 xapi: [ info||5937170 |sm_exec D:61ca0c813f3d|xapi_session] Session.create trackid=96e632fbf268d9b94787594c534f1502 pool=false uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:08 XCP25 xapi: [debug||5937171 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:3ddf0c705e98 created by task D:61ca0c813f3d Oct 14 20:09:08 XCP25 xapi: [debug||5937172 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:host.get_other_config D:899fb960dd39 created by task D:6065f5e4365a Oct 14 20:09:08 XCP25 xapi: [debug||5937173 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_sm_config D:827462934c40 created by task D:6065f5e4365a Oct 14 20:09:08 XCP25 xapi: [debug||5937174 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_other_config D:7c442d959c2f created by task D:6065f5e4365a Oct 14 20:09:08 XCP25 xapi: [debug||5937175 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_other_config D:2330d7c6a968 created by task D:6065f5e4365a Oct 14 20:09:09 XCP25 xapi: [debug||5937176 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_by_uuid D:a7ff19f9a0b0 created by task D:6065f5e4365a Oct 14 20:09:09 XCP25 xapi: [ info||5937177 /var/lib/xcp/xapi|session.login_with_password D:b5b2e179403b|xapi_session] Session.create trackid=a43a59f8fa88f6b0452e7e5dc908535f pool=false uname=root originator=SM is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:09 XCP25 xapi: [debug||5937178 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:5f6792df26f3 created by task D:b5b2e179403b Oct 14 20:09:09 XCP25 xapi: [debug||5937179 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.set_virtual_allocation D:e9296f4fd605 created by task D:6065f5e4365a Oct 14 20:09:09 XCP25 xapi: [debug||5937180 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.set_physical_size D:57963d09e9b2 created by task D:6065f5e4365a Oct 14 20:09:09 XCP25 xapi: [debug||5937182 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.set_physical_utilisation D:4747ecfa90d7 created by task D:6065f5e4365a Oct 14 20:09:09 XCP25 xapi: [debug||5937185 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_by_uuid D:9d56e8efd371 created by task D:6065f5e4365a Oct 14 20:09:09 XCP25 xapi: [debug||5937187 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_all_records_where D:726cb2fef0ad created by task D:6065f5e4365a Oct 14 20:09:09 XCP25 xapi: [ info||5937190 /var/lib/xcp/xapi|session.logout D:5f89a548fc7f|xapi_session] Session.destroy trackid=a43a59f8fa88f6b0452e7e5dc908535f Oct 14 20:09:09 XCP25 xapi: [ info||5937191 /var/lib/xcp/xapi|session.login_with_password D:7eb17d2dbf65|xapi_session] Session.create trackid=40aaa5f277be34cea21905b6804aefae pool=false uname=root originator=SM is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:09 XCP25 xapi: [debug||5937192 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:9dea91362d46 created by task D:7eb17d2dbf65 Oct 14 20:09:09 XCP25 xapi: [debug||5937196 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_by_uuid D:b40362389d29 created by task D:6065f5e4365a Oct 14 20:09:09 XCP25 xapi: [debug||5937199 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.set_virtual_size D:458693ac2365 created by task D:6065f5e4365a Oct 14 20:09:09 XCP25 xapi: [debug||5937201 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.set_physical_utilisation D:e0514e39bdb2 created by task D:6065f5e4365a Oct 14 20:09:09 XCP25 xapi: [debug||5937203 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.set_read_only D:5182a14b8dfc created by task D:6065f5e4365a Oct 14 20:09:09 XCP25 xapi: [debug||5937205 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_sm_config D:c64913a19da1 created by task D:6065f5e4365a Oct 14 20:09:09 XCP25 xapi: [debug||5937206 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.remove_from_sm_config D:f1471e8fb8ec created by task D:6065f5e4365a Oct 14 20:09:09 XCP25 xapi: [debug||5937206 /var/lib/xcp/xapi||api_effect] VDI.remove_from_sm_config Oct 14 20:09:09 XCP25 xapi: [debug||5937207 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.add_to_sm_config D:ba75b3317ab4 created by task D:6065f5e4365a Oct 14 20:09:09 XCP25 xapi: [debug||5937207 /var/lib/xcp/xapi||api_effect] VDI.add_to_sm_config Oct 14 20:09:09 XCP25 xapi: [ info||5937209 /var/lib/xcp/xapi|session.login_with_password D:78ae38c5ac0e|xapi_session] Session.create trackid=24b4a078ec08818d2b5f9d0bb7453929 pool=false uname=root originator=SM is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:09 XCP25 xapi: [debug||5937210 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:39ce18d07206 created by task D:78ae38c5ac0e Oct 14 20:09:09 XCP25 xapi: [ info||5937218 /var/lib/xcp/xapi|session.logout D:a01ec981fba6|xapi_session] Session.destroy trackid=24b4a078ec08818d2b5f9d0bb7453929 Oct 14 20:09:09 XCP25 xapi: [debug||5937219 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.set_cbt_enabled D:28cd803457d1 created by task D:6065f5e4365a Oct 14 20:09:09 XCP25 xapi: [ info||5937219 /var/lib/xcp/xapi||taskhelper] task VDI.set_cbt_enabled R:e5b66a3eaade (uuid:e80e78ff-3eb8-a1da-19e2-8ea48294b99a) created (trackid=96e632fbf268d9b94787594c534f1502) by task D:6065f5e4365a Oct 14 20:09:09 XCP25 xapi: [debug||5937219 /var/lib/xcp/xapi|VDI.set_cbt_enabled R:e5b66a3eaade|audit] VDI.set_cbt_enabled: VDI = 'd7db37b2-a897-469b-a352-33898ba24e2a'; value = 'false' Oct 14 20:09:09 XCP25 xapi: [debug||5937219 /var/lib/xcp/xapi|VDI.set_cbt_enabled R:e5b66a3eaade|xapi_vdi] VDI.set_cbt_enabled: Not doing anything, CBT is already disabled Oct 14 20:09:09 XCP25 xapi: [ info||5937170 |sm_exec D:61ca0c813f3d|xapi_session] Session.destroy trackid=96e632fbf268d9b94787594c534f1502 Oct 14 20:09:09 XCP25 xapi: [ info||5937220 HTTP 127.0.0.1->:::80|session.logout D:cc515ec8b90b|xapi_session] Session.destroy trackid=d87234caf38ca7b33ac2a295efb61226 Oct 14 20:09:09 XCP25 xapi: [ info||5937222 HTTP 127.0.0.1->:::80|session.slave_login D:46bffaa02729|xapi_session] Session.create trackid=d01f9532677d05b70cc4036fea009e98 pool=true uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:09 XCP25 xapi: [debug||5937223 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:cee203c90c22 created by task D:46bffaa02729 Oct 14 20:09:09 XCP25 xapi: [ info||5937221 HTTP 127.0.0.1->:::80|Querying services D:bba75d127906|storage_impl] VDI.snapshot dbg:Async.VM.migrate_send R:326d34bf7507 sr:bb502d0d-3f9b-7ecd-723b-6363f5de9b96 vdi_info:{"sm_config":{"mirror":"null","vhd-parent":"96d8c44d-154c-466a-a013-ce6755ee55dc","read-caching-enabled-on-8d6e2b03-54c1-4523-b45b-d572a268f2cc":"true","host_OpaqueRef:d3f118d9-3aef-4d16-94d5-6d6fa22f84b9":"RW"},"sharable":false,"persistent":true,"physical_utilisation":23147257856,"virtual_size":1649267441664,"cbt_enabled":false,"read_only":false,"snapshot_of":"","snapshot_time":"19700101T00:00:00Z","is_a_snapshot":false,"metadata_of_pool":"","ty":"user","name_description":"Created by XO","name_label":"Server420_root","content_id":"d7db37b2-a897-469b-a352-33898ba24e2a","uuid":"d7db37b2-a897-469b-a352-33898ba24e2a","vdi":"d7db37b2-a897-469b-a352-33898ba24e2a"} Oct 14 20:09:09 XCP25 xapi: [debug||5937224 ||dummytaskhelper] task VDI.snapshot D:555e26333af4 created by task O:Async.VM.mig Oct 14 20:09:09 XCP25 xapi: [debug||5937224 |VDI.snapshot D:555e26333af4|dummytaskhelper] task VDI.snapshot D:4d58fd27448f created by task O:Async.VM.mig Oct 14 20:09:09 XCP25 xapi: [debug||5937224 |VDI.snapshot D:4d58fd27448f|sm] SM nfs vdi_snapshot sr=OpaqueRef:a909a187-63e5-48d3-9de2-7bacfc43caf6 vdi=OpaqueRef:60aa3203-4ac6-4be1-ad73-8dca3ff8a20e driver_params=[mirror=null; vhd-parent=96d8c44d-154c-466a-a013-ce6755ee55dc; read-caching-enabled-on-8d6e2b03-54c1-4523-b45b-d572a268f2cc=true; host_OpaqueRef:d3f118d9-3aef-4d16-94d5-6d6fa22f84b9=RW] Oct 14 20:09:09 XCP25 xapi: [ info||5937224 |sm_exec D:468697029e9c|xapi_session] Session.create trackid=0f77a9fb443000af5544ca7cf6d6bd2f pool=false uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:09 XCP25 xapi: [debug||5937225 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:ba16dd463e78 created by task D:468697029e9c Oct 14 20:09:09 XCP25 xapi: [debug||5937226 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:host.get_other_config D:006f4944ecff created by task D:4d58fd27448f Oct 14 20:09:09 XCP25 xapi: [debug||5937227 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_sm_config D:87626239fae8 created by task D:4d58fd27448f Oct 14 20:09:09 XCP25 xapi: [debug||5937228 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_other_config D:6a137ae4c9b5 created by task D:4d58fd27448f Oct 14 20:09:09 XCP25 xapi: [debug||5937229 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_other_config D:8c3b33941e1a created by task D:4d58fd27448f Oct 14 20:09:09 XCP25 xapi: [ info||5937230 /var/lib/xcp/xapi|session.login_with_password D:bc3a3000e251|xapi_session] Session.create trackid=297527afb585519f4a7bca38a67d2c1a pool=false uname=root originator=SM is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:09 XCP25 xapi: [debug||5937231 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:21b0e9a760a0 created by task D:bc3a3000e251 Oct 14 20:09:09 XCP25 xapi: [ info||5937239 /var/lib/xcp/xapi|session.logout D:297ddaf4c901|xapi_session] Session.destroy trackid=297527afb585519f4a7bca38a67d2c1a Oct 14 20:09:09 XCP25 xapi: [debug||5937240 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_by_uuid D:6b1e1927894b created by task D:4d58fd27448f Oct 14 20:09:09 XCP25 xapi: [debug||5937241 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.add_to_sm_config D:684f69fbe88a created by task D:4d58fd27448f Oct 14 20:09:09 XCP25 xapi: [debug||5937241 /var/lib/xcp/xapi||api_effect] VDI.add_to_sm_config Oct 14 20:09:09 XCP25 xapi: [debug||5937242 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_sm_config D:ca76f568e2ae created by task D:4d58fd27448f Oct 14 20:09:09 XCP25 xapi: [debug||5937243 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:host.call_plugin D:95551fa7a602 created by task D:4d58fd27448f Oct 14 20:09:09 XCP25 xapi: [ info||5937243 /var/lib/xcp/xapi||taskhelper] task host.call_plugin R:0fc857f522e9 (uuid:aa2b07db-aabc-2918-405c-6674afb875b5) created (trackid=0f77a9fb443000af5544ca7cf6d6bd2f) by task D:4d58fd27448f Oct 14 20:09:09 XCP25 xapi: [debug||5937243 /var/lib/xcp/xapi|host.call_plugin R:0fc857f522e9|audit] Host.call_plugin host = '8d6e2b03-54c1-4523-b45b-d572a268f2cc (XCP25)'; plugin = 'tapdisk-pause'; fn = 'pause' args = [ 'hidden' ] Oct 14 20:09:10 XCP25 xapi: [debug||5937244 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:session.logout D:e15458c710e7 created by task D:6f7ddf1004ca Oct 14 20:09:10 XCP25 xapi: [ info||5937244 /var/lib/xcp/xapi|session.logout D:de87799b8cda|xapi_session] Session.destroy trackid=95c8554c09045cf729a67ce6b25d2f28 Oct 14 20:09:10 XCP25 xapi: [debug||5937245 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:session.slave_login D:99b015cd22e0 created by task D:6f7ddf1004ca Oct 14 20:09:10 XCP25 xapi: [ info||5937245 /var/lib/xcp/xapi|session.slave_login D:fbd2a2b2d4ce|xapi_session] Session.create trackid=76a4fa6d9601ba72d7c78e152c90fdb8 pool=true uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:10 XCP25 xapi: [debug||5937246 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:29f10a24bd63 created by task D:fbd2a2b2d4ce Oct 14 20:09:10 XCP25 xapi: [debug||5937247 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:event.from D:7cd901fe0e16 created by task D:6f7ddf1004ca Oct 14 20:09:10 XCP25 xapi: [debug||5937248 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_sm_config D:bf2a35689fad created by task D:4d58fd27448f Oct 14 20:09:11 XCP25 xapi: [debug||5937249 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.db_introduce D:1c5ca35e9f4c created by task D:4d58fd27448f Oct 14 20:09:11 XCP25 xapi: [ info||5937249 /var/lib/xcp/xapi||taskhelper] task VDI.db_introduce R:5c35db68f5f5 (uuid:62ce79cc-74c1-2ef1-aedd-e6fdb03b8d4d) created (trackid=0f77a9fb443000af5544ca7cf6d6bd2f) by task D:4d58fd27448f Oct 14 20:09:11 XCP25 xapi: [debug||5937249 /var/lib/xcp/xapi|VDI.db_introduce R:5c35db68f5f5|xapi_vdi] {pool,db}_introduce uuid=e98540e7-7dd1-493e-b9e1-07159d71bc24 name_label= Oct 14 20:09:11 XCP25 xapi: [debug||5937249 /var/lib/xcp/xapi|VDI.db_introduce R:5c35db68f5f5|xapi_vdi] VDI.introduce read_only = false Oct 14 20:09:11 XCP25 xapi: [debug||5937250 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.db_introduce D:854fc5f07e43 created by task D:4d58fd27448f Oct 14 20:09:11 XCP25 xapi: [ info||5937250 /var/lib/xcp/xapi||taskhelper] task VDI.db_introduce R:60f5186d4aa7 (uuid:64c3f3d9-5157-6ed8-b8da-b47848af7a1f) created (trackid=0f77a9fb443000af5544ca7cf6d6bd2f) by task D:4d58fd27448f Oct 14 20:09:11 XCP25 xapi: [debug||5937250 /var/lib/xcp/xapi|VDI.db_introduce R:60f5186d4aa7|xapi_vdi] {pool,db}_introduce uuid=dfbcf219-95c8-49e9-a363-eb3e2c288aaa name_label=base copy Oct 14 20:09:11 XCP25 xapi: [debug||5937250 /var/lib/xcp/xapi|VDI.db_introduce R:60f5186d4aa7|xapi_vdi] VDI.introduce read_only = true Oct 14 20:09:11 XCP25 xapi: [debug||5937251 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.set_managed D:20cdfac20893 created by task D:4d58fd27448f Oct 14 20:09:11 XCP25 xapi: [debug||5937252 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_sm_config D:3d89212a1423 created by task D:4d58fd27448f Oct 14 20:09:11 XCP25 xapi: [debug||5937253 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.set_sm_config D:abff3912dec2 created by task D:4d58fd27448f Oct 14 20:09:11 XCP25 xapi: [debug||5937253 /var/lib/xcp/xapi||api_effect] VDI.set_sm_config Oct 14 20:09:11 XCP25 xapi: [debug||5937254 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_virtual_allocation D:cbee6813edea created by task D:4d58fd27448f Oct 14 20:09:11 XCP25 xapi: [debug||5937255 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_by_uuid D:bbef0d70f6ec created by task D:4d58fd27448f Oct 14 20:09:11 XCP25 xapi: [debug||5937256 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.set_virtual_allocation D:c5c7c5652546 created by task D:4d58fd27448f Oct 14 20:09:11 XCP25 xapi: [debug||5937257 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.set_physical_size D:a9963469327c created by task D:4d58fd27448f Oct 14 20:09:11 XCP25 xapi: [debug||5937258 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.set_physical_utilisation D:4c2c0bd339d3 created by task D:4d58fd27448f Oct 14 20:09:11 XCP25 xapi: [debug||5937259 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_by_uuid D:880ad61e4fac created by task D:4d58fd27448f Oct 14 20:09:11 XCP25 xapi: [debug||5937260 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_sm_config D:6835827c5fd7 created by task D:4d58fd27448f Oct 14 20:09:11 XCP25 xapi: [debug||5937261 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:host.call_plugin D:7753b79f5bbb created by task D:4d58fd27448f Oct 14 20:09:11 XCP25 xapi: [ info||5937261 /var/lib/xcp/xapi||taskhelper] task host.call_plugin R:9c52022d6001 (uuid:e55d4bbd-2bb0-c40a-5bd2-e84084cd361e) created (trackid=0f77a9fb443000af5544ca7cf6d6bd2f) by task D:4d58fd27448f Oct 14 20:09:11 XCP25 xapi: [debug||5937261 /var/lib/xcp/xapi|host.call_plugin R:9c52022d6001|audit] Host.call_plugin host = '8d6e2b03-54c1-4523-b45b-d572a268f2cc (XCP25)'; plugin = 'tapdisk-pause'; fn = 'unpause' args = [ 'hidden' ] Oct 14 20:09:11 XCP25 xapi: [error||3 ||storage_migrate] Tapdisk mirroring has failed Oct 14 20:09:11 XCP25 xapi: [debug||24 |sm_events D:3f117f94a984|storage_access] sm event on mirror: bb502d0d-3f9b-7ecd-723b-6363f5de9b96/b607eebc-49ad-4fc0-ad4a-b605fedfc51e Oct 14 20:09:11 XCP25 xapi: [ info||24 |sm_events D:3f117f94a984|storage_impl] DATA.MIRROR.stat dbg:sm_events D:3f117f94a984 id:bb502d0d-3f9b-7ecd-723b-6363f5de9b96/b607eebc-49ad-4fc0-ad4a-b605fedfc51e Oct 14 20:09:11 XCP25 xapi: [ info||5937276 /var/lib/xcp/xapi|session.login_with_password D:e7a692f68b85|xapi_session] Session.create trackid=d91975d9613b2db10f124647a177f458 pool=false uname=root originator=SM is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:11 XCP25 xapi: [debug||5937277 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:d5798c46e139 created by task D:e7a692f68b85 Oct 14 20:09:11 XCP25 xapi: [ info||5937285 /var/lib/xcp/xapi|session.logout D:68f95df8b394|xapi_session] Session.destroy trackid=d91975d9613b2db10f124647a177f458 Oct 14 20:09:11 XCP25 xapi: [debug||24 |sm_events D:3f117f94a984|storage_access] Mirror bb502d0d-3f9b-7ecd-723b-6363f5de9b96/b607eebc-49ad-4fc0-ad4a-b605fedfc51e has failed Oct 14 20:09:11 XCP25 xapi: [debug||24 |sm_events D:3f117f94a984|storage_access] Mirror associated with task: OpaqueRef:326d34bf-7507-44dc-ab19-47bf16e4d787 Oct 14 20:09:11 XCP25 xapi: [debug||5937286 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:session.slave_login D:819ed38f0749 created by task D:3f117f94a984 Oct 14 20:09:11 XCP25 xapi: [ info||5937286 /var/lib/xcp/xapi|session.slave_login D:cb537da12e83|xapi_session] Session.create trackid=34aeafdc3ae8fd56f5c4751432cd8171 pool=true uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:11 XCP25 xapi: [debug||5937287 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:e834b24e62cf created by task D:cb537da12e83 Oct 14 20:09:11 XCP25 xapi: [debug||5937288 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:task.cancel D:fc76fe973da7 created by task D:3f117f94a984 Oct 14 20:09:11 XCP25 xapi: [ info||5937288 /var/lib/xcp/xapi|task.cancel D:5f2c76dc0003|xapi_task] Task.cancel is falling back to polling Oct 14 20:09:11 XCP25 xapi: [debug||5937289 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:session.logout D:8a00733f21a6 created by task D:3f117f94a984 Oct 14 20:09:11 XCP25 xapi: [ info||5937289 /var/lib/xcp/xapi|session.logout D:d81bca63bf04|xapi_session] Session.destroy trackid=34aeafdc3ae8fd56f5c4751432cd8171 Oct 14 20:09:11 XCP25 xapi: [debug||5937290 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.remove_from_sm_config D:cdea2c501203 created by task D:4d58fd27448f Oct 14 20:09:11 XCP25 xapi: [debug||5937290 /var/lib/xcp/xapi||api_effect] VDI.remove_from_sm_config Oct 14 20:09:11 XCP25 xapi: [ info||5937224 |sm_exec D:468697029e9c|xapi_session] Session.destroy trackid=0f77a9fb443000af5544ca7cf6d6bd2f Oct 14 20:09:11 XCP25 xapi: [debug||5937224 ||storage_access] copying sm-config Oct 14 20:09:11 XCP25 xapi: [debug||5937224 ||dummytaskhelper] task VDI.update D:df1d8f23ee58 created by task O:Async.VM.mig Oct 14 20:09:11 XCP25 xapi: [debug||5937224 |VDI.update D:df1d8f23ee58|sm] SM nfs vdi_update sr=OpaqueRef:a909a187-63e5-48d3-9de2-7bacfc43caf6 vdi=OpaqueRef:50a9a479-bd10-4d8f-998d-6aa9d435a9c5 Oct 14 20:09:11 XCP25 xapi: [ info||5937224 |sm_exec D:4eae674c4ff7|xapi_session] Session.create trackid=5dabfc46fb0496de30f4a9d46c5bd6cc pool=false uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:11 XCP25 xapi: [debug||5937291 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:f13b7b0b11af created by task D:4eae674c4ff7 Oct 14 20:09:11 XCP25 xapi: [debug||5937292 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:host.get_other_config D:40389a9eca0a created by task D:df1d8f23ee58 Oct 14 20:09:11 XCP25 xapi: [debug||5937293 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_sm_config D:6be6cd10966a created by task D:df1d8f23ee58 Oct 14 20:09:11 XCP25 xapi: [debug||5937294 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_other_config D:1ecc3d367080 created by task D:df1d8f23ee58 Oct 14 20:09:11 XCP25 xapi: [debug||5937295 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_other_config D:9baea9e0a46e created by task D:df1d8f23ee58 Oct 14 20:09:11 XCP25 xapi: [debug||5937296 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_by_uuid D:bed4e3ce8a96 created by task D:df1d8f23ee58 Oct 14 20:09:11 XCP25 xapi: [debug||5937297 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_name_label D:c997dfdd14c3 created by task D:df1d8f23ee58 Oct 14 20:09:11 XCP25 xapi: [debug||5937298 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_name_description D:aaf6ae025361 created by task D:df1d8f23ee58 Oct 14 20:09:11 XCP25 xapi: [debug||5937299 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_sm_config D:0567327ff7a2 created by task D:df1d8f23ee58 Oct 14 20:09:11 XCP25 xapi: [debug||5937300 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_by_uuid D:2a2a3ba6bdf9 created by task D:df1d8f23ee58 Oct 14 20:09:11 XCP25 xapi: [debug||5937301 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.set_virtual_size D:c0ebe6aeb876 created by task D:df1d8f23ee58 Oct 14 20:09:11 XCP25 xapi: [debug||5937302 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.set_physical_utilisation D:cf0dcba2feca created by task D:df1d8f23ee58 Oct 14 20:09:11 XCP25 xapi: [debug||5937303 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.set_read_only D:20b380c49a55 created by task D:df1d8f23ee58 Oct 14 20:09:11 XCP25 xapi: [debug||5937304 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_sm_config D:519cf8bbedc8 created by task D:df1d8f23ee58 Oct 14 20:09:11 XCP25 xapi: [ info||5937305 /var/lib/xcp/xapi|session.login_with_password D:d3824e40e284|xapi_session] Session.create trackid=f2d74449b00fa4683307acc287305b6e pool=false uname=root originator=SM is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:11 XCP25 xapi: [debug||5937306 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:fbc4a7938fe6 created by task D:d3824e40e284 Oct 14 20:09:11 XCP25 xapi: [ info||5937314 /var/lib/xcp/xapi|session.logout D:8e8417cf002c|xapi_session] Session.destroy trackid=f2d74449b00fa4683307acc287305b6e Oct 14 20:09:11 XCP25 xapi: [debug||5937315 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.set_cbt_enabled D:b8577e1a0d19 created by task D:df1d8f23ee58 Oct 14 20:09:11 XCP25 xapi: [ info||5937315 /var/lib/xcp/xapi||taskhelper] task VDI.set_cbt_enabled R:3a4dbb01976d (uuid:96309f3c-c0e1-3d46-f5fd-d58b54924372) created (trackid=5dabfc46fb0496de30f4a9d46c5bd6cc) by task D:df1d8f23ee58 Oct 14 20:09:11 XCP25 xapi: [debug||5937315 /var/lib/xcp/xapi|VDI.set_cbt_enabled R:3a4dbb01976d|audit] VDI.set_cbt_enabled: VDI = 'e98540e7-7dd1-493e-b9e1-07159d71bc24'; value = 'false' Oct 14 20:09:11 XCP25 xapi: [debug||5937315 /var/lib/xcp/xapi|VDI.set_cbt_enabled R:3a4dbb01976d|xapi_vdi] VDI.set_cbt_enabled: Not doing anything, CBT is already disabled Oct 14 20:09:12 XCP25 xapi: [ info||5937224 |sm_exec D:4eae674c4ff7|xapi_session] Session.destroy trackid=5dabfc46fb0496de30f4a9d46c5bd6cc Oct 14 20:09:12 XCP25 xapi: [debug||5937224 ||storage_access] vdi = {"sm_config":{"vhd-parent":"dfbcf219-95c8-49e9-a363-eb3e2c288aaa"},"sharable":false,"persistent":true,"physical_utilisation":3248128,"virtual_size":1649267441664,"cbt_enabled":false,"read_only":false,"snapshot_of":"","snapshot_time":"20241015T00:09:11Z","is_a_snapshot":true,"metadata_of_pool":"OpaqueRef:NULL","ty":"user","name_description":"Created by XO","name_label":"Server420_root","content_id":"e2d13546-25a7-4650-8c5a-caacb67078e4","uuid":"e98540e7-7dd1-493e-b9e1-07159d71bc24","vdi":"e98540e7-7dd1-493e-b9e1-07159d71bc24"} Oct 14 20:09:12 XCP25 xapi: [ info||5937316 HTTP 127.0.0.1->:::80|session.logout D:2481d16e86cd|xapi_session] Session.destroy trackid=d01f9532677d05b70cc4036fea009e98 Oct 14 20:09:12 XCP25 xapi: [ info||5937318 HTTP 127.0.0.1->:::80|session.slave_login D:d19f671705fa|xapi_session] Session.create trackid=0613331218223f57a2abc5cf511645dd pool=true uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:12 XCP25 xapi: [debug||5937319 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:cb54b47df02e created by task D:d19f671705fa Oct 14 20:09:12 XCP25 xapi: [ info||5937317 HTTP 127.0.0.1->:::80|Querying services D:7730fd412635|storage_impl] VDI.destroy dbg:Async.VM.migrate_send R:326d34bf7507 sr:bb502d0d-3f9b-7ecd-723b-6363f5de9b96 vdi:e98540e7-7dd1-493e-b9e1-07159d71bc24 Oct 14 20:09:12 XCP25 xapi: [debug||5937320 ||dummytaskhelper] task VDI.destroy D:26e711b82136 created by task O:Async.VM.mig Oct 14 20:09:12 XCP25 xapi: [debug||5937320 |VDI.destroy D:26e711b82136|sm] SM nfs vdi_delete sr=OpaqueRef:a909a187-63e5-48d3-9de2-7bacfc43caf6 vdi=OpaqueRef:50a9a479-bd10-4d8f-998d-6aa9d435a9c5 Oct 14 20:09:12 XCP25 xapi: [ info||5937320 |sm_exec D:c35eb8df0dc0|xapi_session] Session.create trackid=d7c52a07faca96509ab45c10468597a6 pool=false uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:12 XCP25 xapi: [debug||5937321 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:11e80a3909b5 created by task D:c35eb8df0dc0 Oct 14 20:09:12 XCP25 xapi: [debug||5937322 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:host.get_other_config D:e73d5feb7c6c created by task D:26e711b82136 Oct 14 20:09:12 XCP25 xapi: [debug||5937323 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_sm_config D:a6530a7a94f8 created by task D:26e711b82136 Oct 14 20:09:12 XCP25 xapi: [debug||5937324 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_other_config D:1deb73b1b51e created by task D:26e711b82136 Oct 14 20:09:12 XCP25 xapi: [debug||5937325 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_other_config D:d1cf1a402a99 created by task D:26e711b82136 Oct 14 20:09:12 XCP25 xapi: [ info||5937326 /var/lib/xcp/xapi|session.login_with_password D:c3e991ff64b1|xapi_session] Session.create trackid=757b31e56472acc6661f961575a90675 pool=false uname=root originator=SM is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:12 XCP25 xapi: [debug||5937327 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:be8b3a30df66 created by task D:c3e991ff64b1 Oct 14 20:09:12 XCP25 xapi: [ info||5937335 /var/lib/xcp/xapi|session.logout D:3ed1380e1cf0|xapi_session] Session.destroy trackid=757b31e56472acc6661f961575a90675 Oct 14 20:09:12 XCP25 xapi: [debug||5937336 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_by_uuid D:6634147ee19c created by task D:26e711b82136 Oct 14 20:09:12 XCP25 xapi: [debug||5937337 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.db_forget D:e26f7cea753b created by task D:26e711b82136 Oct 14 20:09:12 XCP25 xapi: [ info||5937337 /var/lib/xcp/xapi||taskhelper] task VDI.db_forget R:b1ad9fb25545 (uuid:06a79d25-35a8-4dd0-a382-003518e5c5db) created (trackid=d7c52a07faca96509ab45c10468597a6) by task D:26e711b82136 Oct 14 20:09:12 XCP25 xapi: [debug||5937337 /var/lib/xcp/xapi|VDI.db_forget R:b1ad9fb25545|xapi_vdi] db_forget uuid=e98540e7-7dd1-493e-b9e1-07159d71bc24 Oct 14 20:09:12 XCP25 xapi: [debug||5937338 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_virtual_allocation D:e6ed82aa8246 created by task D:26e711b82136 Oct 14 20:09:12 XCP25 xapi: [debug||5937339 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_by_uuid D:0e485d793176 created by task D:26e711b82136 Oct 14 20:09:12 XCP25 xapi: [debug||5937340 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.set_virtual_allocation D:217ddb3adf48 created by task D:26e711b82136 Oct 14 20:09:12 XCP25 xapi: [debug||5937341 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.set_physical_size D:5fc362d5e1ae created by task D:26e711b82136 Oct 14 20:09:12 XCP25 xapi: [debug||5937342 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.set_physical_utilisation D:660f9371c87a created by task D:26e711b82136 Oct 14 20:09:12 XCP25 xapi: [ info||5937343 /var/lib/xcp/xapi|session.login_with_password D:45d242c49449|xapi_session] Session.create trackid=d9e3ac42382dadf60cb41ad641e5801e pool=false uname=root originator=SM is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:12 XCP25 xapi: [debug||5937344 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:c5fed5bf1912 created by task D:45d242c49449 Oct 14 20:09:12 XCP25 xapi: [ info||5937345 /var/lib/xcp/xapi|session.login_with_password D:1d41481a2483|xapi_session] Session.create trackid=d9d0ccff4be447d289482fc93eb6123c pool=false uname=root originator=SM is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:12 XCP25 xapi: [debug||5937346 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:6e119d4d097f created by task D:1d41481a2483 Oct 14 20:09:12 XCP25 xapi: [ info||5937360 /var/lib/xcp/xapi|session.logout D:349beea0a25c|xapi_session] Session.destroy trackid=d9e3ac42382dadf60cb41ad641e5801e Oct 14 20:09:12 XCP25 xapi: [ info||5937361 /var/lib/xcp/xapi|session.logout D:e8bdaedacb1c|xapi_session] Session.destroy trackid=d9d0ccff4be447d289482fc93eb6123c Oct 14 20:09:12 XCP25 xapi: [ info||5937362 /var/lib/xcp/xapi|session.login_with_password D:eccf41cc0034|xapi_session] Session.create trackid=305aa60dba266d807d4e84d04c8d9bfe pool=false uname=root originator=SM is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:12 XCP25 xapi: [debug||5937363 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:72e87449bcb3 created by task D:eccf41cc0034 Oct 14 20:09:12 XCP25 xapi: [ info||5937320 |sm_exec D:c35eb8df0dc0|xapi_session] Session.destroy trackid=d7c52a07faca96509ab45c10468597a6 Oct 14 20:09:12 XCP25 xapi: [ info||5937373 HTTP 127.0.0.1->:::80|session.logout D:768b5cf2a919|xapi_session] Session.destroy trackid=0613331218223f57a2abc5cf511645dd Oct 14 20:09:12 XCP25 xapi: [ info||5937374 /var/lib/xcp/xapi|session.logout D:21893960c8e7|xapi_session] Session.destroy trackid=305aa60dba266d807d4e84d04c8d9bfe Oct 14 20:09:12 XCP25 xapi: [debug||5937164 HTTP 127.0.0.1->:::80|Querying services D:9cffa2e474c8|storage_migrate] Snapshot VDI already cleaned up Oct 14 20:09:12 XCP25 xapi: [debug||5937164 HTTP 127.0.0.1->:::80|Querying services D:9cffa2e474c8|stunnel] stunnel start Oct 14 20:09:12 XCP25 xapi: [debug||5937164 HTTP 127.0.0.1->:::80|Querying services D:9cffa2e474c8|xmlrpc_client] stunnel pid: 27774 (cached = false) connected to 10.10.1.11:443 Oct 14 20:09:12 XCP25 xapi: [debug||5937164 HTTP 127.0.0.1->:::80|Querying services D:9cffa2e474c8|xmlrpc_client] with_recorded_stunnelpid task_opt=None s_pid=27774 Oct 14 20:09:12 XCP25 xapi: [debug||5937379 /var/lib/xcp/xapi||api_effect] VDI.remove_from_sm_config Oct 14 20:09:12 XCP25 xapi: [debug||5937380 /var/lib/xcp/xapi||api_effect] VDI.remove_from_sm_config Oct 14 20:09:12 XCP25 xapi: [debug||5937381 /var/lib/xcp/xapi||api_effect] VDI.add_to_sm_config Oct 14 20:09:12 XCP25 xapi: [debug||5937383 /var/lib/xcp/xapi||api_effect] VDI.remove_from_sm_config Oct 14 20:09:12 XCP25 xapi: [debug||5937384 /var/lib/xcp/xapi||api_effect] VDI.add_to_sm_config Oct 14 20:09:16 XCP25 xapi: [error||3 ||storage_migrate] Tapdisk mirroring has failed Oct 14 20:09:16 XCP25 xapi: [debug||24 |sm_events D:3f117f94a984|storage_access] sm event on mirror: bb502d0d-3f9b-7ecd-723b-6363f5de9b96/b607eebc-49ad-4fc0-ad4a-b605fedfc51e Oct 14 20:09:16 XCP25 xapi: [ info||24 |sm_events D:3f117f94a984|storage_impl] DATA.MIRROR.stat dbg:sm_events D:3f117f94a984 id:bb502d0d-3f9b-7ecd-723b-6363f5de9b96/b607eebc-49ad-4fc0-ad4a-b605fedfc51e Oct 14 20:09:16 XCP25 xapi: [debug||24 |sm_events D:3f117f94a984|storage_access] Mirror bb502d0d-3f9b-7ecd-723b-6363f5de9b96/b607eebc-49ad-4fc0-ad4a-b605fedfc51e has failed Oct 14 20:09:16 XCP25 xapi: [debug||24 |sm_events D:3f117f94a984|storage_access] Mirror associated with task: OpaqueRef:326d34bf-7507-44dc-ab19-47bf16e4d787 Oct 14 20:09:16 XCP25 xapi: [debug||5937387 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:session.slave_login D:8d2c6ec34714 created by task D:3f117f94a984 Oct 14 20:09:16 XCP25 xapi: [ info||5937387 /var/lib/xcp/xapi|session.slave_login D:5e94ab9e6f12|xapi_session] Session.create trackid=b5818809631a51b7841519cfce6b1408 pool=true uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:16 XCP25 xapi: [debug||5937388 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:a49763db33f7 created by task D:5e94ab9e6f12 Oct 14 20:09:16 XCP25 xapi: [debug||5937389 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:task.cancel D:139e33d14c50 created by task D:3f117f94a984 Oct 14 20:09:16 XCP25 xapi: [ info||5937389 /var/lib/xcp/xapi|task.cancel D:e8163dcb8c54|xapi_task] Task.cancel is falling back to polling Oct 14 20:09:16 XCP25 xapi: [debug||5937390 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:session.logout D:6eb0c7bac17e created by task D:3f117f94a984 Oct 14 20:09:16 XCP25 xapi: [ info||5937390 /var/lib/xcp/xapi|session.logout D:7f5f5da034b9|xapi_session] Session.destroy trackid=b5818809631a51b7841519cfce6b1408 Oct 14 20:09:20 XCP25 xapi: [ info||5937391 HTTP 127.0.0.1->:::80|session.logout D:bc60a953d973|xapi_session] Session.destroy trackid=5afc9d4325b1c2cc51ae0e55911349e3 Oct 14 20:09:20 XCP25 xapi: [debug||5863012 ||stunnel] stunnel start Oct 14 20:09:20 XCP25 xapi: [debug||5863012 ||xmlrpc_client] stunnel pid: 27898 (cached = false) connected to 10.10.10.5:443 Oct 14 20:09:20 XCP25 xapi: [debug||5863012 ||xmlrpc_client] with_recorded_stunnelpid task_opt=None s_pid=27898 Oct 14 20:09:20 XCP25 xapi: [error||5863012 ||xapi_vm_migrate] Failed to destroy remote VDI Oct 14 20:09:20 XCP25 xapi: [ info||5937393 HTTP 127.0.0.1->:::80|session.slave_login D:f2ba689e34fc|xapi_session] Session.create trackid=8ea69e14bb438d7f530eafa4d7075913 pool=true uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:20 XCP25 xapi: [debug||5937394 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:a4f8d3bee044 created by task D:f2ba689e34fc Oct 14 20:09:20 XCP25 xapi: [ info||5937392 HTTP 127.0.0.1->:::80|Querying services D:ff46c5029871|storage_impl] DP.destroy dbg:Async.VM.migrate_send R:326d34bf7507 dp:mirror_vbd/23/xvda allow_leak:false Oct 14 20:09:20 XCP25 xapi: [debug||5937392 HTTP 127.0.0.1->:::80|Querying services D:ff46c5029871|storage_impl] [destroy_sr] Filtered VDI count:0 Oct 14 20:09:20 XCP25 xapi: message repeated 3 times: [ [debug||5937392 HTTP 127.0.0.1->:::80|Querying services D:ff46c5029871|storage_impl] [destroy_sr] Filtered VDI count:0] Oct 14 20:09:20 XCP25 xapi: [debug||5937392 HTTP 127.0.0.1->:::80|Querying services D:ff46c5029871|storage_impl] [destroy_sr] Filtered VDI count:1 Oct 14 20:09:20 XCP25 xapi: [debug||5937392 HTTP 127.0.0.1->:::80|Querying services D:ff46c5029871|storage_impl] [destroy_sr] VDI found with the dp is d7db37b2-a897-469b-a352-33898ba24e2a Oct 14 20:09:20 XCP25 xapi: [debug||5937392 HTTP 127.0.0.1->:::80|Querying services D:ff46c5029871|storage_impl] dbg:Async.VM.migrate_send R:326d34bf7507 dp:mirror_vbd/23/xvda sr:bb502d0d-3f9b-7ecd-723b-6363f5de9b96 vdi:d7db37b2-a897-469b-a352-33898ba24e2a superstate:activated RW Oct 14 20:09:20 XCP25 xapi: [debug||5937392 HTTP 127.0.0.1->:::80|Querying services D:ff46c5029871|storage_impl] dbg:Async.VM.migrate_send R:326d34bf7507 dp:mirror_vbd/23/xvda sr:bb502d0d-3f9b-7ecd-723b-6363f5de9b96 vdi:d7db37b2-a897-469b-a352-33898ba24e2a superstate:activated RW Oct 14 20:09:20 XCP25 xapi: [debug||5937392 HTTP 127.0.0.1->:::80|Querying services D:ff46c5029871|storage_impl] [destroy_sr] Filtered VDI count:0 Oct 14 20:09:20 XCP25 xapi: [debug||5937392 HTTP 127.0.0.1->:::80|Querying services D:ff46c5029871|storage_impl] [destroy_sr] Filtered VDI count:0 Oct 14 20:09:20 XCP25 xapi: [ info||5937395 HTTP 127.0.0.1->:::80|session.logout D:e18ce44a1ba4|xapi_session] Session.destroy trackid=8ea69e14bb438d7f530eafa4d7075913 Oct 14 20:09:20 XCP25 xapi: [debug||5863012 ||stunnel] stunnel start Oct 14 20:09:20 XCP25 xapi: [debug||5863012 ||xmlrpc_client] stunnel pid: 27906 (cached = false) connected to 10.10.10.5:443 Oct 14 20:09:20 XCP25 xapi: [debug||5863012 ||xmlrpc_client] with_recorded_stunnelpid task_opt=None s_pid=27906 Oct 14 20:09:21 XCP25 xapi: [ info||5937397 HTTP 127.0.0.1->:::80|session.slave_login D:687ed486add8|xapi_session] Session.create trackid=0b2e087045867245c2eaea968e21fa22 pool=true uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:21 XCP25 xapi: [debug||5937398 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:b52569cb956c created by task D:687ed486add8 Oct 14 20:09:21 XCP25 xapi: [ info||5937396 HTTP 127.0.0.1->:::80|Querying services D:bc670f628a09|storage_impl] DP.destroy dbg:Async.VM.migrate_send R:326d34bf7507 dp:copy_vbd/b0d8e0a4-005f-1f6c-6104-91911aad4278/2156735d-17a1-479b-bcd7-09c53fb6f2d4 allow_leak:false Oct 14 20:09:21 XCP25 xapi: [debug||5937396 HTTP 127.0.0.1->:::80|Querying services D:bc670f628a09|storage_impl] [destroy_sr] Filtered VDI count:0 Oct 14 20:09:21 XCP25 xapi: message repeated 6 times: [ [debug||5937396 HTTP 127.0.0.1->:::80|Querying services D:bc670f628a09|storage_impl] [destroy_sr] Filtered VDI count:0] Oct 14 20:09:21 XCP25 xapi: [ info||5937399 HTTP 127.0.0.1->:::80|session.logout D:72c4e0a7dc32|xapi_session] Session.destroy trackid=0b2e087045867245c2eaea968e21fa22 Oct 14 20:09:21 XCP25 xapi: [ info||5937401 HTTP 127.0.0.1->:::80|session.slave_login D:24b6f0a03b44|xapi_session] Session.create trackid=c9d7182c6c1235b1569a4308d95605f5 pool=true uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:21 XCP25 xapi: [debug||5937402 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:8b74e3362c86 created by task D:24b6f0a03b44 Oct 14 20:09:21 XCP25 xapi: [ info||5937400 HTTP 127.0.0.1->:::80|Querying services D:9b1eb3cf9223|storage_impl] DATA.MIRROR.stat dbg:Async.VM.migrate_send R:326d34bf7507 id:bb502d0d-3f9b-7ecd-723b-6363f5de9b96/b607eebc-49ad-4fc0-ad4a-b605fedfc51e Oct 14 20:09:21 XCP25 xapi: [ info||5937403 HTTP 127.0.0.1->:::80|session.logout D:82ac10e346d8|xapi_session] Session.destroy trackid=c9d7182c6c1235b1569a4308d95605f5 Oct 14 20:09:21 XCP25 xapi: [ info||5937405 HTTP 127.0.0.1->:::80|session.slave_login D:5422795ee346|xapi_session] Session.create trackid=c3a061e3f28e80093b4ffe0f9729698d pool=true uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:21 XCP25 xapi: [debug||5937406 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:13dc68e523e3 created by task D:5422795ee346 Oct 14 20:09:21 XCP25 xapi: [ info||5937404 HTTP 127.0.0.1->:::80|Querying services D:1c0c674f6951|storage_impl] DATA.MIRROR.stop dbg:Async.VM.migrate_send R:326d34bf7507 id:bb502d0d-3f9b-7ecd-723b-6363f5de9b96/b607eebc-49ad-4fc0-ad4a-b605fedfc51e Oct 14 20:09:21 XCP25 xapi: [ info||5937408 HTTP 127.0.0.1->:::80|session.slave_login D:151055e74d1a|xapi_session] Session.create trackid=2a6acc0c7794bac390f56309c5f3247b pool=true uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:21 XCP25 xapi: [debug||5937409 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:38441d8e355e created by task D:151055e74d1a Oct 14 20:09:21 XCP25 xapi: [ info||5937407 HTTP 127.0.0.1->:::80|Querying services D:7c3e4ab64428|storage_impl] SR.scan dbg:Async.VM.migrate_send R:326d34bf7507 sr:bb502d0d-3f9b-7ecd-723b-6363f5de9b96 Oct 14 20:09:21 XCP25 xapi: [debug||5937410 ||dummytaskhelper] task SR.scan D:ed039dfd7cf3 created by task O:Async.VM.mig Oct 14 20:09:21 XCP25 xapi: [debug||5937410 |SR.scan D:ed039dfd7cf3|sm] SM nfs sr_scan sr=OpaqueRef:a909a187-63e5-48d3-9de2-7bacfc43caf6 Oct 14 20:09:21 XCP25 xapi: [ info||5937410 |sm_exec D:4e6098066520|xapi_session] Session.create trackid=0934a324f860a7e46efff3a3e1d4adf6 pool=false uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:21 XCP25 xapi: [debug||5937411 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:4d86ede82cab created by task D:4e6098066520 Oct 14 20:09:21 XCP25 xapi: [error||3 ||storage_migrate] Tapdisk mirroring has failed Oct 14 20:09:21 XCP25 xapi: [debug||24 |sm_events D:3f117f94a984|storage_access] sm event on mirror: bb502d0d-3f9b-7ecd-723b-6363f5de9b96/b607eebc-49ad-4fc0-ad4a-b605fedfc51e Oct 14 20:09:21 XCP25 xapi: [ info||24 |sm_events D:3f117f94a984|storage_impl] DATA.MIRROR.stat dbg:sm_events D:3f117f94a984 id:bb502d0d-3f9b-7ecd-723b-6363f5de9b96/b607eebc-49ad-4fc0-ad4a-b605fedfc51e Oct 14 20:09:21 XCP25 xapi: [debug||24 |sm_events D:3f117f94a984|storage_access] Mirror bb502d0d-3f9b-7ecd-723b-6363f5de9b96/b607eebc-49ad-4fc0-ad4a-b605fedfc51e has failed Oct 14 20:09:21 XCP25 xapi: [debug||24 |sm_events D:3f117f94a984|storage_access] Couldn't find mirror id: bb502d0d-3f9b-7ecd-723b-6363f5de9b96/b607eebc-49ad-4fc0-ad4a-b605fedfc51e Oct 14 20:09:21 XCP25 xapi: [debug||5937412 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:host.get_other_config D:1207a272ba6d created by task D:ed039dfd7cf3 Oct 14 20:09:21 XCP25 xapi: [debug||5937413 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_sm_config D:2b7d13a7730f created by task D:ed039dfd7cf3 Oct 14 20:09:21 XCP25 xapi: [debug||5937414 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_other_config D:6227b4d89a14 created by task D:ed039dfd7cf3 Oct 14 20:09:21 XCP25 xapi: [debug||5937415 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_other_config D:d19b1d8ca0cb created by task D:ed039dfd7cf3 Oct 14 20:09:22 XCP25 xapi: [debug||5937416 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_by_uuid D:773eaf985c68 created by task D:ed039dfd7cf3 Oct 14 20:09:22 XCP25 xapi: [ info||5937417 /var/lib/xcp/xapi|session.login_with_password D:787d8f80afda|xapi_session] Session.create trackid=6f48c51a04c741955728d1057045c60a pool=false uname=root originator=SM is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:22 XCP25 xapi: [debug||5937418 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:a9e802ecec6d created by task D:787d8f80afda Oct 14 20:09:22 XCP25 xapi: [debug||5937419 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.set_virtual_allocation D:8cfa0f0edaf7 created by task D:ed039dfd7cf3 Oct 14 20:09:22 XCP25 xapi: [debug||5937420 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.set_physical_size D:50fbfd81c972 created by task D:ed039dfd7cf3 Oct 14 20:09:22 XCP25 xapi: [debug||5937421 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.set_physical_utilisation D:270af5dbd865 created by task D:ed039dfd7cf3 Oct 14 20:09:22 XCP25 xapi: [debug||5937424 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_by_uuid D:2cadf29c03d5 created by task D:ed039dfd7cf3 Oct 14 20:09:22 XCP25 xapi: [debug||5937426 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_all_records_where D:9576c72da29f created by task D:ed039dfd7cf3 Oct 14 20:09:22 XCP25 xapi: [ info||5937430 /var/lib/xcp/xapi|session.logout D:366f70cc95b9|xapi_session] Session.destroy trackid=6f48c51a04c741955728d1057045c60a Oct 14 20:09:22 XCP25 xapi: [ info||5937431 /var/lib/xcp/xapi|session.login_with_password D:34c7532d6b6d|xapi_session] Session.create trackid=3485917a93232e61177190c10bad8183 pool=false uname=root originator=SM is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:22 XCP25 xapi: [debug||5937432 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:b5dd0dc35157 created by task D:34c7532d6b6d Oct 14 20:09:22 XCP25 xapi: [debug||5937434 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_by_uuid D:deba5665564a created by task D:ed039dfd7cf3 Oct 14 20:09:22 XCP25 xapi: [debug||5937437 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.set_virtual_size D:d7cba9d504fa created by task D:ed039dfd7cf3 Oct 14 20:09:22 XCP25 xapi: [debug||5937439 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.set_physical_utilisation D:2589cda96891 created by task D:ed039dfd7cf3 Oct 14 20:09:22 XCP25 xapi: [debug||5937441 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.set_read_only D:ceeef4076869 created by task D:ed039dfd7cf3 Oct 14 20:09:22 XCP25 xapi: [debug||5937443 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_sm_config D:e95fd9ad3716 created by task D:ed039dfd7cf3 Oct 14 20:09:22 XCP25 xapi: [ info||5937446 /var/lib/xcp/xapi|session.login_with_password D:51a8d80d9f68|xapi_session] Session.create trackid=0064cd2cde0c4dc9f2f89e6118d424d4 pool=false uname=root originator=SM is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:22 XCP25 xapi: [debug||5937447 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:08e7e25bbe49 created by task D:51a8d80d9f68 Oct 14 20:09:22 XCP25 xapi: [ info||5937455 /var/lib/xcp/xapi|session.logout D:ff631a1d306a|xapi_session] Session.destroy trackid=3485917a93232e61177190c10bad8183 Oct 14 20:09:22 XCP25 xapi: [ info||5937457 /var/lib/xcp/xapi|session.logout D:248bf04f9a04|xapi_session] Session.destroy trackid=0064cd2cde0c4dc9f2f89e6118d424d4 Oct 14 20:09:22 XCP25 xapi: [debug||5937458 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.set_cbt_enabled D:665439ac2f63 created by task D:ed039dfd7cf3 Oct 14 20:09:22 XCP25 xapi: [ info||5937458 /var/lib/xcp/xapi||taskhelper] task VDI.set_cbt_enabled R:a9dddc36583a (uuid:f057d4c6-d2c6-d77b-4b8c-a03bcce462c0) created (trackid=0934a324f860a7e46efff3a3e1d4adf6) by task D:ed039dfd7cf3 Oct 14 20:09:22 XCP25 xapi: [debug||5937458 /var/lib/xcp/xapi|VDI.set_cbt_enabled R:a9dddc36583a|audit] VDI.set_cbt_enabled: VDI = 'd7db37b2-a897-469b-a352-33898ba24e2a'; value = 'false' Oct 14 20:09:22 XCP25 xapi: [debug||5937458 /var/lib/xcp/xapi|VDI.set_cbt_enabled R:a9dddc36583a|xapi_vdi] VDI.set_cbt_enabled: Not doing anything, CBT is already disabled Oct 14 20:09:22 XCP25 xapi: [debug||5937459 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_by_uuid D:5145908b069b created by task D:ed039dfd7cf3 Oct 14 20:09:22 XCP25 xapi: [debug||5937460 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.set_virtual_size D:2e4552cfb26c created by task D:ed039dfd7cf3 Oct 14 20:09:22 XCP25 xapi: [debug||5937461 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.set_physical_utilisation D:ac01759d694b created by task D:ed039dfd7cf3 Oct 14 20:09:22 XCP25 xapi: [debug||5937462 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.set_read_only D:0fb1d9fa003c created by task D:ed039dfd7cf3 Oct 14 20:09:22 XCP25 xapi: [debug||5937463 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_sm_config D:596d8a0366ac created by task D:ed039dfd7cf3 Oct 14 20:09:22 XCP25 xapi: [ info||5937464 /var/lib/xcp/xapi|session.login_with_password D:3790c192ee14|xapi_session] Session.create trackid=cac48c020124abe8024bab055ff2710a pool=false uname=root originator=SM is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:22 XCP25 xapi: [debug||5937465 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:bb691542a391 created by task D:3790c192ee14 Oct 14 20:09:22 XCP25 xapi: [ info||5937473 /var/lib/xcp/xapi|session.logout D:215f7389601f|xapi_session] Session.destroy trackid=cac48c020124abe8024bab055ff2710a Oct 14 20:09:22 XCP25 xapi: [debug||5937474 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.set_cbt_enabled D:82dda58e02cb created by task D:ed039dfd7cf3 Oct 14 20:09:22 XCP25 xapi: [ info||5937474 /var/lib/xcp/xapi||taskhelper] task VDI.set_cbt_enabled R:b4aac1ff0aba (uuid:48f8f018-6780-56b8-a101-f0fa39c56d95) created (trackid=0934a324f860a7e46efff3a3e1d4adf6) by task D:ed039dfd7cf3 Oct 14 20:09:22 XCP25 xapi: [debug||5937474 /var/lib/xcp/xapi|VDI.set_cbt_enabled R:b4aac1ff0aba|audit] VDI.set_cbt_enabled: VDI = 'dfbcf219-95c8-49e9-a363-eb3e2c288aaa'; value = 'false' Oct 14 20:09:22 XCP25 xapi: [debug||5937474 /var/lib/xcp/xapi|VDI.set_cbt_enabled R:b4aac1ff0aba|xapi_vdi] VDI.set_cbt_enabled: Not doing anything, CBT is already disabled Oct 14 20:09:22 XCP25 xapi: [ info||5937410 |sm_exec D:4e6098066520|xapi_session] Session.destroy trackid=0934a324f860a7e46efff3a3e1d4adf6 Oct 14 20:09:22 XCP25 xapi: [ info||5937475 HTTP 127.0.0.1->:::80|session.logout D:798482a72814|xapi_session] Session.destroy trackid=2a6acc0c7794bac390f56309c5f3247b Oct 14 20:09:22 XCP25 xapi: [ info||5937477 HTTP 127.0.0.1->:::80|session.slave_login D:5b62ced99f07|xapi_session] Session.create trackid=a76912933b081ef71d8bf87be2eeda6b pool=true uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:22 XCP25 xapi: [debug||5937478 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:8bef2793e331 created by task D:5b62ced99f07 Oct 14 20:09:22 XCP25 xapi: [ info||5937476 HTTP 127.0.0.1->:::80|Querying services D:4422f0168be2|storage_impl] VDI.snapshot dbg:Async.VM.migrate_send R:326d34bf7507 sr:bb502d0d-3f9b-7ecd-723b-6363f5de9b96 vdi_info:{"sm_config":{"mirror":"null","vhd-parent":"548c77e5-fe27-4484-b5f4-53fae19a3a2e","read-caching-enabled-on-8d6e2b03-54c1-4523-b45b-d572a268f2cc":"false","read-caching-reason-8d6e2b03-54c1-4523-b45b-d572a268f2cc":"NO_RO_IMAGE","host_OpaqueRef:d3f118d9-3aef-4d16-94d5-6d6fa22f84b9":"RW"},"sharable":false,"persistent":true,"physical_utilisation":710435328,"virtual_size":107374182400,"cbt_enabled":false,"read_only":false,"snapshot_of":"","snapshot_time":"19700101T00:00:00Z","is_a_snapshot":false,"metadata_of_pool":"","ty":"user","name_description":"","name_label":"[NOBAK]Server420_backups","content_id":"b607eebc-49ad-4fc0-ad4a-b605fedfc51e","uuid":"b607eebc-49ad-4fc0-ad4a-b605fedfc51e","vdi":"b607eebc-49ad-4fc0-ad4a-b605fedfc51e"} Oct 14 20:09:22 XCP25 xapi: [debug||5937479 ||dummytaskhelper] task VDI.snapshot D:0b945f14afa8 created by task O:Async.VM.mig Oct 14 20:09:22 XCP25 xapi: [debug||5937479 |VDI.snapshot D:0b945f14afa8|dummytaskhelper] task VDI.snapshot D:fded595da4ba created by task O:Async.VM.mig Oct 14 20:09:22 XCP25 xapi: [debug||5937479 |VDI.snapshot D:fded595da4ba|sm] SM nfs vdi_snapshot sr=OpaqueRef:a909a187-63e5-48d3-9de2-7bacfc43caf6 vdi=OpaqueRef:7069c225-0bf2-433c-a255-0fab035ea70b driver_params=[mirror=null; vhd-parent=548c77e5-fe27-4484-b5f4-53fae19a3a2e; read-caching-enabled-on-8d6e2b03-54c1-4523-b45b-d572a268f2cc=false; read-caching-reason-8d6e2b03-54c1-4523-b45b-d572a268f2cc=NO_RO_IMAGE; host_OpaqueRef:d3f118d9-3aef-4d16-94d5-6d6fa22f84b9=RW] Oct 14 20:09:22 XCP25 xapi: [ info||5937479 |sm_exec D:801af1dba505|xapi_session] Session.create trackid=cf3363a83fa6d8fc2628218d67418a3f pool=false uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:22 XCP25 xapi: [debug||5937480 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:0e446879152d created by task D:801af1dba505 Oct 14 20:09:22 XCP25 xapi: [debug||5937481 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:host.get_other_config D:1ad9a125bde7 created by task D:fded595da4ba Oct 14 20:09:22 XCP25 xapi: [debug||5937482 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_sm_config D:8f188502c8a3 created by task D:fded595da4ba Oct 14 20:09:22 XCP25 xapi: [debug||5937483 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_other_config D:37bbf20c934a created by task D:fded595da4ba Oct 14 20:09:22 XCP25 xapi: [debug||5937484 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_other_config D:40307015de7a created by task D:fded595da4ba Oct 14 20:09:22 XCP25 xapi: [ info||5937485 /var/lib/xcp/xapi|session.login_with_password D:0a9c68bf03f3|xapi_session] Session.create trackid=b0a8f6301334fd3c84ef750081821933 pool=false uname=root originator=SM is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:22 XCP25 xapi: [debug||5937486 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:03bf8e8c4a10 created by task D:0a9c68bf03f3 Oct 14 20:09:22 XCP25 xapi: [ info||5937494 /var/lib/xcp/xapi|session.logout D:a3423e990c98|xapi_session] Session.destroy trackid=b0a8f6301334fd3c84ef750081821933 Oct 14 20:09:22 XCP25 xapi: [debug||5937495 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_by_uuid D:2e75b8119892 created by task D:fded595da4ba Oct 14 20:09:22 XCP25 xapi: [debug||5937496 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.add_to_sm_config D:3a9798e793ac created by task D:fded595da4ba Oct 14 20:09:22 XCP25 xapi: [debug||5937496 /var/lib/xcp/xapi||api_effect] VDI.add_to_sm_config Oct 14 20:09:22 XCP25 xapi: [debug||5937497 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_sm_config D:229ea5a87e2b created by task D:fded595da4ba Oct 14 20:09:22 XCP25 xapi: [debug||5937498 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:host.call_plugin D:8977a0143b73 created by task D:fded595da4ba Oct 14 20:09:22 XCP25 xapi: [ info||5937498 /var/lib/xcp/xapi||taskhelper] task host.call_plugin R:fd7809467593 (uuid:9afd1b8f-5e26-c33a-9fc1-7ab633420e5d) created (trackid=cf3363a83fa6d8fc2628218d67418a3f) by task D:fded595da4ba Oct 14 20:09:22 XCP25 xapi: [debug||5937498 /var/lib/xcp/xapi|host.call_plugin R:fd7809467593|audit] Host.call_plugin host = '8d6e2b03-54c1-4523-b45b-d572a268f2cc (XCP25)'; plugin = 'tapdisk-pause'; fn = 'pause' args = [ 'hidden' ] Oct 14 20:09:23 XCP25 xapi: [debug||5937499 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_sm_config D:c7e7adc46107 created by task D:fded595da4ba Oct 14 20:09:23 XCP25 xapi: [debug||5937500 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.db_introduce D:69b27a751787 created by task D:fded595da4ba Oct 14 20:09:23 XCP25 xapi: [ info||5937500 /var/lib/xcp/xapi||taskhelper] task VDI.db_introduce R:804f21365415 (uuid:41a77438-de9d-eff9-5b63-d9f9da42286b) created (trackid=cf3363a83fa6d8fc2628218d67418a3f) by task D:fded595da4ba Oct 14 20:09:23 XCP25 xapi: [debug||5937500 /var/lib/xcp/xapi|VDI.db_introduce R:804f21365415|xapi_vdi] {pool,db}_introduce uuid=a155aa1c-26c2-4065-ab6b-bb1459c2cc07 name_label= Oct 14 20:09:23 XCP25 xapi: [debug||5937500 /var/lib/xcp/xapi|VDI.db_introduce R:804f21365415|xapi_vdi] VDI.introduce read_only = false Oct 14 20:09:23 XCP25 xapi: [debug||5937501 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.db_introduce D:8702c2bc0595 created by task D:fded595da4ba Oct 14 20:09:23 XCP25 xapi: [ info||5937501 /var/lib/xcp/xapi||taskhelper] task VDI.db_introduce R:a325501c65b6 (uuid:5cc5c406-ab08-cb80-7237-b6e9be559820) created (trackid=cf3363a83fa6d8fc2628218d67418a3f) by task D:fded595da4ba Oct 14 20:09:23 XCP25 xapi: [debug||5937501 /var/lib/xcp/xapi|VDI.db_introduce R:a325501c65b6|xapi_vdi] {pool,db}_introduce uuid=8cd80a56-d2a4-4e60-b39e-3b9586a53fbf name_label=base copy Oct 14 20:09:23 XCP25 xapi: [debug||5937501 /var/lib/xcp/xapi|VDI.db_introduce R:a325501c65b6|xapi_vdi] VDI.introduce read_only = true Oct 14 20:09:23 XCP25 xapi: [debug||5937502 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.set_managed D:2929e8623e93 created by task D:fded595da4ba Oct 14 20:09:23 XCP25 xapi: [debug||5937503 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_sm_config D:1895b4e6fe18 created by task D:fded595da4ba Oct 14 20:09:23 XCP25 xapi: [debug||5937504 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.set_sm_config D:bff5ac984ae4 created by task D:fded595da4ba Oct 14 20:09:23 XCP25 xapi: [debug||5937504 /var/lib/xcp/xapi||api_effect] VDI.set_sm_config Oct 14 20:09:23 XCP25 xapi: [debug||5937505 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_virtual_allocation D:cecf9b85d31a created by task D:fded595da4ba Oct 14 20:09:23 XCP25 xapi: [debug||5937506 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_by_uuid D:75dbd783e338 created by task D:fded595da4ba Oct 14 20:09:23 XCP25 xapi: [debug||5937507 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.set_virtual_allocation D:bbe39d2b5260 created by task D:fded595da4ba Oct 14 20:09:23 XCP25 xapi: [debug||5937508 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.set_physical_size D:c0cb2b343eea created by task D:fded595da4ba Oct 14 20:09:23 XCP25 xapi: [debug||5937509 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.set_physical_utilisation D:b80c45b9b276 created by task D:fded595da4ba Oct 14 20:09:23 XCP25 xapi: [debug||5937510 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_by_uuid D:1537e7982b98 created by task D:fded595da4ba Oct 14 20:09:23 XCP25 xapi: [debug||5937511 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_sm_config D:a62f7e808c27 created by task D:fded595da4ba Oct 14 20:09:23 XCP25 xapi: [debug||5937512 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:host.call_plugin D:dd6f442c2a90 created by task D:fded595da4ba Oct 14 20:09:23 XCP25 xapi: [ info||5937512 /var/lib/xcp/xapi||taskhelper] task host.call_plugin R:6286aada21d3 (uuid:333f1eb4-7a19-0294-98a0-f436ff984c4c) created (trackid=cf3363a83fa6d8fc2628218d67418a3f) by task D:fded595da4ba Oct 14 20:09:23 XCP25 xapi: [debug||5937512 /var/lib/xcp/xapi|host.call_plugin R:6286aada21d3|audit] Host.call_plugin host = '8d6e2b03-54c1-4523-b45b-d572a268f2cc (XCP25)'; plugin = 'tapdisk-pause'; fn = 'unpause' args = [ 'hidden' ] Oct 14 20:09:23 XCP25 xapi: [ info||5937527 /var/lib/xcp/xapi|session.login_with_password D:fff964040fd9|xapi_session] Session.create trackid=dd445de3bd68dfa19e39e5f6d45bdb19 pool=false uname=root originator=SM is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:23 XCP25 xapi: [debug||5937528 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:e4c4a0403e9d created by task D:fff964040fd9 Oct 14 20:09:23 XCP25 xapi: [ info||5937536 /var/lib/xcp/xapi|session.logout D:f27591efa04d|xapi_session] Session.destroy trackid=dd445de3bd68dfa19e39e5f6d45bdb19 Oct 14 20:09:24 XCP25 xapi: [debug||5937537 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.remove_from_sm_config D:2e8892022ce9 created by task D:fded595da4ba Oct 14 20:09:24 XCP25 xapi: [debug||5937537 /var/lib/xcp/xapi||api_effect] VDI.remove_from_sm_config Oct 14 20:09:24 XCP25 xapi: [ info||5937479 |sm_exec D:801af1dba505|xapi_session] Session.destroy trackid=cf3363a83fa6d8fc2628218d67418a3f Oct 14 20:09:24 XCP25 xapi: [debug||5937479 ||storage_access] copying sm-config Oct 14 20:09:24 XCP25 xapi: [debug||5937479 ||dummytaskhelper] task VDI.update D:895959f16137 created by task O:Async.VM.mig Oct 14 20:09:24 XCP25 xapi: [debug||5937479 |VDI.update D:895959f16137|sm] SM nfs vdi_update sr=OpaqueRef:a909a187-63e5-48d3-9de2-7bacfc43caf6 vdi=OpaqueRef:47da7ba6-e4a5-424d-8c85-e4db0257c1c3 Oct 14 20:09:24 XCP25 xapi: [ info||5937479 |sm_exec D:f0a791e2c76a|xapi_session] Session.create trackid=00e1a81ac048047e848283254349601e pool=false uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:24 XCP25 xapi: [debug||5937538 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:706b58a28e75 created by task D:f0a791e2c76a Oct 14 20:09:24 XCP25 xapi: [debug||5937539 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:host.get_other_config D:2e3e99a3161a created by task D:895959f16137 Oct 14 20:09:24 XCP25 xapi: [debug||5937540 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_sm_config D:79b3141874c6 created by task D:895959f16137 Oct 14 20:09:24 XCP25 xapi: [debug||5937541 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_other_config D:82a3d382f934 created by task D:895959f16137 Oct 14 20:09:24 XCP25 xapi: [debug||5937542 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_other_config D:741fcb001670 created by task D:895959f16137 Oct 14 20:09:24 XCP25 xapi: [debug||5937543 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_by_uuid D:0ed3d540e939 created by task D:895959f16137 Oct 14 20:09:24 XCP25 xapi: [debug||5937544 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_name_label D:8a2c04fb209f created by task D:895959f16137 Oct 14 20:09:24 XCP25 xapi: [debug||5937545 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_name_description D:8ae8bffeee38 created by task D:895959f16137 Oct 14 20:09:24 XCP25 xapi: [debug||5937546 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_sm_config D:4920b3a85f53 created by task D:895959f16137 Oct 14 20:09:24 XCP25 xapi: [debug||5937547 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_by_uuid D:2e8a6647d79a created by task D:895959f16137 Oct 14 20:09:24 XCP25 xapi: [debug||5937548 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.set_virtual_size D:71832da30906 created by task D:895959f16137 Oct 14 20:09:24 XCP25 xapi: [debug||5937549 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.set_physical_utilisation D:5624e6e378e1 created by task D:895959f16137 Oct 14 20:09:24 XCP25 xapi: [debug||5937550 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.set_read_only D:5c8a280a59fe created by task D:895959f16137 Oct 14 20:09:24 XCP25 xapi: [debug||5937551 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_sm_config D:9eb26b87f276 created by task D:895959f16137 Oct 14 20:09:24 XCP25 xapi: [ info||5937552 /var/lib/xcp/xapi|session.login_with_password D:ded3dfcdb1f4|xapi_session] Session.create trackid=9b521d14b129129cbaeb9338f0944922 pool=false uname=root originator=SM is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:24 XCP25 xapi: [debug||5937553 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:3d5b78e4fbde created by task D:ded3dfcdb1f4 Oct 14 20:09:24 XCP25 xapi: [ info||5937561 /var/lib/xcp/xapi|session.logout D:76c8a0f41230|xapi_session] Session.destroy trackid=9b521d14b129129cbaeb9338f0944922 Oct 14 20:09:24 XCP25 xapi: [debug||5937562 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.set_cbt_enabled D:47ae04c2b258 created by task D:895959f16137 Oct 14 20:09:24 XCP25 xapi: [ info||5937562 /var/lib/xcp/xapi||taskhelper] task VDI.set_cbt_enabled R:f86efecbeffb (uuid:db29e72d-e1df-b16b-008b-26a52d5bacea) created (trackid=00e1a81ac048047e848283254349601e) by task D:895959f16137 Oct 14 20:09:24 XCP25 xapi: [debug||5937562 /var/lib/xcp/xapi|VDI.set_cbt_enabled R:f86efecbeffb|audit] VDI.set_cbt_enabled: VDI = 'a155aa1c-26c2-4065-ab6b-bb1459c2cc07'; value = 'false' Oct 14 20:09:24 XCP25 xapi: [debug||5937562 /var/lib/xcp/xapi|VDI.set_cbt_enabled R:f86efecbeffb|xapi_vdi] VDI.set_cbt_enabled: Not doing anything, CBT is already disabled Oct 14 20:09:24 XCP25 xapi: [ info||5937479 |sm_exec D:f0a791e2c76a|xapi_session] Session.destroy trackid=00e1a81ac048047e848283254349601e Oct 14 20:09:24 XCP25 xapi: [debug||5937479 ||storage_access] vdi = {"sm_config":{"vhd-parent":"8cd80a56-d2a4-4e60-b39e-3b9586a53fbf"},"sharable":false,"persistent":true,"physical_utilisation":215552,"virtual_size":107374182400,"cbt_enabled":false,"read_only":false,"snapshot_of":"","snapshot_time":"20241015T00:09:24Z","is_a_snapshot":true,"metadata_of_pool":"OpaqueRef:NULL","ty":"user","name_description":"","name_label":"[NOBAK]Server420_backups","content_id":"a0b44192-bf65-95fe-2989-f8afa087d5da","uuid":"a155aa1c-26c2-4065-ab6b-bb1459c2cc07","vdi":"a155aa1c-26c2-4065-ab6b-bb1459c2cc07"} Oct 14 20:09:24 XCP25 xapi: [ info||5937563 HTTP 127.0.0.1->:::80|session.logout D:6b9f16e70c00|xapi_session] Session.destroy trackid=a76912933b081ef71d8bf87be2eeda6b Oct 14 20:09:24 XCP25 xapi: [ info||5937565 HTTP 127.0.0.1->:::80|session.slave_login D:3157cf31889c|xapi_session] Session.create trackid=b96fee66f1ed725bae9a886610130c96 pool=true uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:24 XCP25 xapi: [debug||5937566 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:57ebaec40c1f created by task D:3157cf31889c Oct 14 20:09:24 XCP25 xapi: [ info||5937564 HTTP 127.0.0.1->:::80|Querying services D:15ad0b2b64cf|storage_impl] VDI.destroy dbg:Async.VM.migrate_send R:326d34bf7507 sr:bb502d0d-3f9b-7ecd-723b-6363f5de9b96 vdi:a155aa1c-26c2-4065-ab6b-bb1459c2cc07 Oct 14 20:09:24 XCP25 xapi: [debug||5937567 ||dummytaskhelper] task VDI.destroy D:a04bea6e8cb5 created by task O:Async.VM.mig Oct 14 20:09:24 XCP25 xapi: [debug||5937567 |VDI.destroy D:a04bea6e8cb5|sm] SM nfs vdi_delete sr=OpaqueRef:a909a187-63e5-48d3-9de2-7bacfc43caf6 vdi=OpaqueRef:47da7ba6-e4a5-424d-8c85-e4db0257c1c3 Oct 14 20:09:24 XCP25 xapi: [ info||5937567 |sm_exec D:448dc22ac31b|xapi_session] Session.create trackid=af796c9bfba7f3963f789938ff181167 pool=false uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:24 XCP25 xapi: [debug||5937568 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:ec7df9e1d4c1 created by task D:448dc22ac31b Oct 14 20:09:24 XCP25 xapi: [debug||5937569 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:host.get_other_config D:359c0dd50935 created by task D:a04bea6e8cb5 Oct 14 20:09:24 XCP25 xapi: [debug||5937570 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_sm_config D:0a56873cf068 created by task D:a04bea6e8cb5 Oct 14 20:09:24 XCP25 xapi: [debug||5937571 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_other_config D:72b030ecc1a8 created by task D:a04bea6e8cb5 Oct 14 20:09:24 XCP25 xapi: [debug||5937572 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_other_config D:2f9f1d162205 created by task D:a04bea6e8cb5 Oct 14 20:09:24 XCP25 xapi: [ info||5937573 /var/lib/xcp/xapi|session.login_with_password D:c20d1d550708|xapi_session] Session.create trackid=2fb041086556d70ec7c64cb706c8f023 pool=false uname=root originator=SM is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:24 XCP25 xapi: [debug||5937574 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:4aef32e12c4d created by task D:c20d1d550708 Oct 14 20:09:24 XCP25 xapi: [ info||5937582 /var/lib/xcp/xapi|session.logout D:411a1a269433|xapi_session] Session.destroy trackid=2fb041086556d70ec7c64cb706c8f023 Oct 14 20:09:24 XCP25 xapi: [debug||5937583 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_by_uuid D:e174b5932b1a created by task D:a04bea6e8cb5 Oct 14 20:09:24 XCP25 xapi: [debug||5937584 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.db_forget D:516e64470589 created by task D:a04bea6e8cb5 Oct 14 20:09:24 XCP25 xapi: [ info||5937584 /var/lib/xcp/xapi||taskhelper] task VDI.db_forget R:abd40ff4268b (uuid:7f550ad6-d236-aafd-a4e1-17bdd5b98048) created (trackid=af796c9bfba7f3963f789938ff181167) by task D:a04bea6e8cb5 Oct 14 20:09:24 XCP25 xapi: [debug||5937584 /var/lib/xcp/xapi|VDI.db_forget R:abd40ff4268b|xapi_vdi] db_forget uuid=a155aa1c-26c2-4065-ab6b-bb1459c2cc07 Oct 14 20:09:24 XCP25 xapi: [debug||5937585 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_virtual_allocation D:601eb0ba4ebf created by task D:a04bea6e8cb5 Oct 14 20:09:24 XCP25 xapi: [debug||5937586 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_by_uuid D:87815a080d2a created by task D:a04bea6e8cb5 Oct 14 20:09:24 XCP25 xapi: [debug||5937587 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.set_virtual_allocation D:283fb4931948 created by task D:a04bea6e8cb5 Oct 14 20:09:24 XCP25 xapi: [debug||5937588 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.set_physical_size D:3c8d99625dc9 created by task D:a04bea6e8cb5 Oct 14 20:09:24 XCP25 xapi: [debug||5937589 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.set_physical_utilisation D:8333eb729fff created by task D:a04bea6e8cb5 Oct 14 20:09:24 XCP25 xapi: [ info||5937590 /var/lib/xcp/xapi|session.login_with_password D:ed654748bb5a|xapi_session] Session.create trackid=495966dc5bb20e8295ee1cdaf3453f32 pool=false uname=root originator=SM is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:24 XCP25 xapi: [ info||5937591 /var/lib/xcp/xapi|session.login_with_password D:bdf34660a54b|xapi_session] Session.create trackid=988ca60a4b044011357d4655f5c1a9b6 pool=false uname=root originator=SM is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:24 XCP25 xapi: [debug||5937592 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:24a656d3bf9e created by task D:ed654748bb5a Oct 14 20:09:24 XCP25 xapi: [debug||5937593 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:4ba77839e9ff created by task D:bdf34660a54b Oct 14 20:09:24 XCP25 xapi: [ info||5937607 /var/lib/xcp/xapi|session.logout D:a47cd9df16d9|xapi_session] Session.destroy trackid=495966dc5bb20e8295ee1cdaf3453f32 Oct 14 20:09:24 XCP25 xapi: [ info||5937608 /var/lib/xcp/xapi|session.logout D:3b6df020dbe9|xapi_session] Session.destroy trackid=988ca60a4b044011357d4655f5c1a9b6 Oct 14 20:09:24 XCP25 xapi: [ info||5937609 /var/lib/xcp/xapi|session.login_with_password D:28e1119e24c7|xapi_session] Session.create trackid=e1769ad9d59235b529a49dfc1560f0f2 pool=false uname=root originator=SM is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:24 XCP25 xapi: [debug||5937610 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:33e9641dab6a created by task D:28e1119e24c7 Oct 14 20:09:24 XCP25 xapi: [ info||5937567 |sm_exec D:448dc22ac31b|xapi_session] Session.destroy trackid=af796c9bfba7f3963f789938ff181167 Oct 14 20:09:24 XCP25 xapi: [ info||5937621 HTTP 127.0.0.1->:::80|session.logout D:d929528c98e8|xapi_session] Session.destroy trackid=b96fee66f1ed725bae9a886610130c96 Oct 14 20:09:24 XCP25 xapi: [ info||5937620 /var/lib/xcp/xapi|session.logout D:a5b5b6d0ba7b|xapi_session] Session.destroy trackid=e1769ad9d59235b529a49dfc1560f0f2 Oct 14 20:09:24 XCP25 xapi: [debug||5937404 HTTP 127.0.0.1->:::80|Querying services D:1c0c674f6951|storage_migrate] Snapshot VDI already cleaned up Oct 14 20:09:24 XCP25 xapi: [debug||5937404 HTTP 127.0.0.1->:::80|Querying services D:1c0c674f6951|stunnel] stunnel start Oct 14 20:09:24 XCP25 xapi: [debug||5937404 HTTP 127.0.0.1->:::80|Querying services D:1c0c674f6951|xmlrpc_client] stunnel pid: 28288 (cached = false) connected to 10.10.1.11:443 Oct 14 20:09:24 XCP25 xapi: [debug||5937404 HTTP 127.0.0.1->:::80|Querying services D:1c0c674f6951|xmlrpc_client] with_recorded_stunnelpid task_opt=None s_pid=28288 Oct 14 20:09:27 XCP25 xapi: [ info||5937622 HTTP 127.0.0.1->:::80|session.logout D:771e220c9ba3|xapi_session] Session.destroy trackid=c3a061e3f28e80093b4ffe0f9729698d Oct 14 20:09:27 XCP25 xapi: [debug||5863012 ||stunnel] stunnel start Oct 14 20:09:27 XCP25 xapi: [debug||5863012 ||xmlrpc_client] stunnel pid: 28296 (cached = false) connected to 10.10.10.5:443 Oct 14 20:09:27 XCP25 xapi: [debug||5863012 ||xmlrpc_client] with_recorded_stunnelpid task_opt=None s_pid=28296 Oct 14 20:09:27 XCP25 xapi: [error||5863012 ||xapi_vm_migrate] Failed to destroy remote VDI Oct 14 20:09:27 XCP25 xapi: [ info||5937624 HTTP 127.0.0.1->:::80|session.slave_login D:7bb096650cbe|xapi_session] Session.create trackid=6124f1c640f9899c7aae19b3c2db52c3 pool=true uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:27 XCP25 xapi: [debug||5937625 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:641bc539c68d created by task D:7bb096650cbe Oct 14 20:09:27 XCP25 xapi: [ info||5937623 HTTP 127.0.0.1->:::80|Querying services D:4312a6c3a697|storage_impl] DP.destroy dbg:Async.VM.migrate_send R:326d34bf7507 dp:mirror_vbd/23/xvdb allow_leak:false Oct 14 20:09:27 XCP25 xapi: [debug||5937623 HTTP 127.0.0.1->:::80|Querying services D:4312a6c3a697|storage_impl] [destroy_sr] Filtered VDI count:0 Oct 14 20:09:27 XCP25 xapi: message repeated 3 times: [ [debug||5937623 HTTP 127.0.0.1->:::80|Querying services D:4312a6c3a697|storage_impl] [destroy_sr] Filtered VDI count:0] Oct 14 20:09:27 XCP25 xapi: [debug||5937623 HTTP 127.0.0.1->:::80|Querying services D:4312a6c3a697|storage_impl] [destroy_sr] Filtered VDI count:1 Oct 14 20:09:27 XCP25 xapi: [debug||5937623 HTTP 127.0.0.1->:::80|Querying services D:4312a6c3a697|storage_impl] [destroy_sr] VDI found with the dp is b607eebc-49ad-4fc0-ad4a-b605fedfc51e Oct 14 20:09:27 XCP25 xapi: [debug||5937623 HTTP 127.0.0.1->:::80|Querying services D:4312a6c3a697|storage_impl] dbg:Async.VM.migrate_send R:326d34bf7507 dp:mirror_vbd/23/xvdb sr:bb502d0d-3f9b-7ecd-723b-6363f5de9b96 vdi:b607eebc-49ad-4fc0-ad4a-b605fedfc51e superstate:activated RW Oct 14 20:09:27 XCP25 xapi: [debug||5937623 HTTP 127.0.0.1->:::80|Querying services D:4312a6c3a697|storage_impl] dbg:Async.VM.migrate_send R:326d34bf7507 dp:mirror_vbd/23/xvdb sr:bb502d0d-3f9b-7ecd-723b-6363f5de9b96 vdi:b607eebc-49ad-4fc0-ad4a-b605fedfc51e superstate:activated RW Oct 14 20:09:27 XCP25 xapi: [debug||5937623 HTTP 127.0.0.1->:::80|Querying services D:4312a6c3a697|storage_impl] [destroy_sr] Filtered VDI count:0 Oct 14 20:09:27 XCP25 xapi: [debug||5937623 HTTP 127.0.0.1->:::80|Querying services D:4312a6c3a697|storage_impl] [destroy_sr] Filtered VDI count:0 Oct 14 20:09:27 XCP25 xapi: [ info||5937626 HTTP 127.0.0.1->:::80|session.logout D:93323aed7bcc|xapi_session] Session.destroy trackid=6124f1c640f9899c7aae19b3c2db52c3 Oct 14 20:09:27 XCP25 xapi: [error||5863012 ||xapi_vm_migrate] Caught Server_error(MIRROR_FAILED, [ OpaqueRef:7069c225-0bf2-433c-a255-0fab035ea70b ]): cleaning up Oct 14 20:09:27 XCP25 xapi: [debug||5863012 ||xenops] suppressing xenops events on VM: 3797df5e-695a-00be-86bd-318a7c48860f Oct 14 20:09:27 XCP25 xenopsd-xc: [debug||655130 |Async.VM.migrate_send R:326d34bf7507|xenops_server] VM.stat 3797df5e-695a-00be-86bd-318a7c48860f Oct 14 20:09:27 XCP25 xapi: [debug||5863012 ||xenops] re-enabled xenops events on VM: 3797df5e-695a-00be-86bd-318a7c48860f; refreshing VM Oct 14 20:09:27 XCP25 xenopsd-xc: [debug||655131 |Async.VM.migrate_send R:326d34bf7507|xenops_server] UPDATES.refresh_vm 3797df5e-695a-00be-86bd-318a7c48860f Oct 14 20:09:27 XCP25 xenopsd-xc: [debug||655131 |Async.VM.migrate_send R:326d34bf7507|xenops_server] VM_DB.signal 3797df5e-695a-00be-86bd-318a7c48860f Oct 14 20:09:27 XCP25 xenopsd-xc: [debug||655131 |Async.VM.migrate_send R:326d34bf7507|xenops_server] VBD_DB.signal 3797df5e-695a-00be-86bd-318a7c48860f.xvdd Oct 14 20:09:27 XCP25 xenopsd-xc: [debug||655131 |Async.VM.migrate_send R:326d34bf7507|xenops_server] VBD_DB.signal 3797df5e-695a-00be-86bd-318a7c48860f.xvda Oct 14 20:09:27 XCP25 xenopsd-xc: [debug||655131 |Async.VM.migrate_send R:326d34bf7507|xenops_server] VBD_DB.signal 3797df5e-695a-00be-86bd-318a7c48860f.xvdb Oct 14 20:09:27 XCP25 xenopsd-xc: [debug||655131 |Async.VM.migrate_send R:326d34bf7507|xenops_server] VIF_DB.signal 3797df5e-695a-00be-86bd-318a7c48860f.1 Oct 14 20:09:27 XCP25 xenopsd-xc: [debug||655131 |Async.VM.migrate_send R:326d34bf7507|xenops_server] VIF_DB.signal 3797df5e-695a-00be-86bd-318a7c48860f.0 Oct 14 20:09:27 XCP25 xapi: [debug||1197 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops] Processing event: ["Vm","3797df5e-695a-00be-86bd-318a7c48860f"] Oct 14 20:09:27 XCP25 xapi: [debug||1197 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops] xenops event on VM 3797df5e-695a-00be-86bd-318a7c48860f Oct 14 20:09:27 XCP25 xenopsd-xc: [debug||655132 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops_server] VM.stat 3797df5e-695a-00be-86bd-318a7c48860f Oct 14 20:09:27 XCP25 xapi: [debug||5863012 ||xenops] Client.UPDATES.inject_barrier 38 Oct 14 20:09:27 XCP25 xenopsd-xc: [debug||655133 |Async.VM.migrate_send R:326d34bf7507|xenops_server] UPDATES.inject_barrier 3797df5e-695a-00be-86bd-318a7c48860f 38 Oct 14 20:09:27 XCP25 xapi: [debug||1197 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops] xenopsd event: ignoring event for VM 3797df5e-695a-00be-86bd-318a7c48860f: metadata has not changed Oct 14 20:09:27 XCP25 xapi: [debug||1197 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops] Processing barrier 38 Oct 14 20:09:27 XCP25 xapi: [debug||1197 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops] Processing event: ["Vbd",["3797df5e-695a-00be-86bd-318a7c48860f","xvdd"]] Oct 14 20:09:27 XCP25 xapi: [debug||1197 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops] xenops event on VBD 3797df5e-695a-00be-86bd-318a7c48860f.xvdd Oct 14 20:09:27 XCP25 xenopsd-xc: [debug||655135 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops_server] VBD.stat 3797df5e-695a-00be-86bd-318a7c48860f.xvdd Oct 14 20:09:27 XCP25 xapi: [debug||1197 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops] xenopsd event: ignoring event for VBD 3797df5e-695a-00be-86bd-318a7c48860f.xvdd: metadata has not changed Oct 14 20:09:27 XCP25 xapi: [debug||1197 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops] Processing event: ["Vbd",["3797df5e-695a-00be-86bd-318a7c48860f","xvda"]] Oct 14 20:09:27 XCP25 xapi: [debug||1197 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops] xenops event on VBD 3797df5e-695a-00be-86bd-318a7c48860f.xvda Oct 14 20:09:27 XCP25 xenopsd-xc: [debug||655136 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops_server] VBD.stat 3797df5e-695a-00be-86bd-318a7c48860f.xvda Oct 14 20:09:27 XCP25 xenopsd-xc: [debug||655136 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops] /usr/bin/ionice -p24186 Oct 14 20:09:27 XCP25 xapi: [debug||1197 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops] xenopsd event: ignoring event for VBD 3797df5e-695a-00be-86bd-318a7c48860f.xvda: metadata has not changed Oct 14 20:09:27 XCP25 xapi: [debug||1197 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops] Processing event: ["Vbd",["3797df5e-695a-00be-86bd-318a7c48860f","xvdb"]] Oct 14 20:09:27 XCP25 xapi: [debug||1197 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops] xenops event on VBD 3797df5e-695a-00be-86bd-318a7c48860f.xvdb Oct 14 20:09:27 XCP25 xenopsd-xc: [debug||655137 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops_server] VBD.stat 3797df5e-695a-00be-86bd-318a7c48860f.xvdb Oct 14 20:09:27 XCP25 xenopsd-xc: [debug||655137 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops] /usr/bin/ionice -p24134 Oct 14 20:09:27 XCP25 xapi: [debug||1197 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops] xenopsd event: ignoring event for VBD 3797df5e-695a-00be-86bd-318a7c48860f.xvdb: metadata has not changed Oct 14 20:09:27 XCP25 xapi: [debug||1197 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops] Processing event: ["Vif",["3797df5e-695a-00be-86bd-318a7c48860f","1"]] Oct 14 20:09:27 XCP25 xapi: [debug||1197 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops] xenops event on VIF 3797df5e-695a-00be-86bd-318a7c48860f.1 Oct 14 20:09:27 XCP25 xenopsd-xc: [debug||655138 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops_server] VIF.stat 3797df5e-695a-00be-86bd-318a7c48860f.1 Oct 14 20:09:27 XCP25 xapi: [debug||1197 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops] xenopsd event: ignoring event for VIF 3797df5e-695a-00be-86bd-318a7c48860f.1: metadata has not changed Oct 14 20:09:27 XCP25 xapi: [debug||1197 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops] Processing event: ["Vif",["3797df5e-695a-00be-86bd-318a7c48860f","0"]] Oct 14 20:09:27 XCP25 xapi: [debug||1197 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops] xenops event on VIF 3797df5e-695a-00be-86bd-318a7c48860f.0 Oct 14 20:09:27 XCP25 xenopsd-xc: [debug||655139 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops_server] VIF.stat 3797df5e-695a-00be-86bd-318a7c48860f.0 Oct 14 20:09:27 XCP25 xapi: [debug||1197 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops] xenopsd event: ignoring event for VIF 3797df5e-695a-00be-86bd-318a7c48860f.0: metadata has not changed Oct 14 20:09:27 XCP25 xenopsd-xc: [debug||655140 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops_server] UPDATES.remove_barrier 38 Oct 14 20:09:27 XCP25 xapi: [debug||1197 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops] Processing event: ["Vbd",["3797df5e-695a-00be-86bd-318a7c48860f","xvdd"]] Oct 14 20:09:27 XCP25 xapi: [debug||1197 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops] Skipping (already processed this round) Oct 14 20:09:27 XCP25 xapi: [debug||1197 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops] Processing event: ["Vbd",["3797df5e-695a-00be-86bd-318a7c48860f","xvda"]] Oct 14 20:09:27 XCP25 xapi: [debug||1197 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops] Skipping (already processed this round) Oct 14 20:09:27 XCP25 xapi: [debug||1197 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops] Processing event: ["Vbd",["3797df5e-695a-00be-86bd-318a7c48860f","xvdb"]] Oct 14 20:09:27 XCP25 xapi: [debug||1197 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops] Skipping (already processed this round) Oct 14 20:09:27 XCP25 xapi: [debug||1197 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops] Processing event: ["Vif",["3797df5e-695a-00be-86bd-318a7c48860f","1"]] Oct 14 20:09:27 XCP25 xapi: [debug||1197 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops] Skipping (already processed this round) Oct 14 20:09:27 XCP25 xapi: [debug||1197 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops] Processing event: ["Vif",["3797df5e-695a-00be-86bd-318a7c48860f","0"]] Oct 14 20:09:27 XCP25 xapi: [debug||1197 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops] Skipping (already processed this round) Oct 14 20:09:27 XCP25 xapi: [debug||5863012 ||stunnel] stunnel start Oct 14 20:09:27 XCP25 xapi: [debug||5863012 ||xmlrpc_client] stunnel pid: 28322 (cached = false) connected to 10.10.10.5:443 Oct 14 20:09:27 XCP25 xapi: [debug||5863012 ||xmlrpc_client] with_recorded_stunnelpid task_opt=None s_pid=28322 Oct 14 20:09:27 XCP25 xapi: [error||5863012 ||xapi_vm_migrate] Caught Server_error(UUID_INVALID, [ VM; 3797df5e-695a-00be-86bd-318a7c48860f ]) while destroying VM uuid=3797df5e-695a-00be-86bd-318a7c48860f on destination host Oct 14 20:09:27 XCP25 xapi: [debug||5863012 ||stunnel] stunnel start Oct 14 20:09:27 XCP25 xapi: [debug||5863012 ||xmlrpc_client] stunnel pid: 28326 (cached = false) connected to 10.10.10.5:443 Oct 14 20:09:27 XCP25 xapi: [debug||5863012 ||xmlrpc_client] with_recorded_stunnelpid task_opt=None s_pid=28326 Oct 14 20:09:27 XCP25 xapi: [error||5863012 ||xapi_vm_migrate] Caught Server_error(UUID_INVALID, [ VM; b0d8e0a4-005f-1f6c-6104-91911aad4278 ]) while destroying VM uuid=b0d8e0a4-005f-1f6c-6104-91911aad4278 on destination host Oct 14 20:09:27 XCP25 xapi: [debug||5863012 ||stunnel] stunnel start Oct 14 20:09:27 XCP25 xapi: [debug||5863012 ||xmlrpc_client] stunnel pid: 28330 (cached = false) connected to 10.10.10.5:443 Oct 14 20:09:27 XCP25 xapi: [debug||5863012 ||xmlrpc_client] with_recorded_stunnelpid task_opt=None s_pid=28330 Oct 14 20:09:27 XCP25 xapi: [error||5863012 ||xapi_vm_migrate] Caught Server_error(UUID_INVALID, [ VM; b28f7ad9-597d-2608-409b-516f44cd9b14 ]) while destroying VM uuid=b28f7ad9-597d-2608-409b-516f44cd9b14 on destination host Oct 14 20:09:27 XCP25 xapi: [debug||5863012 ||xapi_vm_migrate] Mirror failed for VDI: b607eebc-49ad-4fc0-ad4a-b605fedfc51e Oct 14 20:09:27 XCP25 xapi: [error||5863012 ||backtrace] Async.VM.migrate_send R:326d34bf7507 failed with exception Server_error(MIRROR_FAILED, [ OpaqueRef:7069c225-0bf2-433c-a255-0fab035ea70b ]) Oct 14 20:09:27 XCP25 xapi: [error||5863012 ||backtrace] Raised Server_error(MIRROR_FAILED, [ OpaqueRef:7069c225-0bf2-433c-a255-0fab035ea70b ]) Oct 14 20:09:27 XCP25 xapi: [error||5863012 ||backtrace] 1/1 xapi Raised at file (Thread 5863012 has no backtrace table. Was with_backtraces called?, line 0 Oct 14 20:09:27 XCP25 xapi: [error||5863012 ||backtrace] Oct 14 20:09:27 XCP25 xapi: [debug||1202 ||xenops] Event on VM 3797df5e-695a-00be-86bd-318a7c48860f; resident_here = true Oct 14 20:09:27 XCP25 xapi: [debug||1202 ||xenops] xapi_cache: updating cache for 3797df5e-695a-00be-86bd-318a7c48860f Oct 14 20:09:27 XCP25 xapi: [debug||1202 ||xenops] VM 3797df5e-695a-00be-86bd-318a7c48860f metadata has changed: updating xenopsd Oct 14 20:09:27 XCP25 xapi: [ info||1202 ||xenops] xenops: VM.import_metadata {"vusbs":[],"vgpus":[],"pcis":[],"vifs":[{"ipv6_configuration":"Unspecified6","ipv4_configuration":"Unspecified4","extra_private_keys":{"vif-uuid":"de9a4140-0b67-314b-6fed-0bbd00d4cf74","network-uuid":"19edb159-d210-7c75-abb3-b8c63dacd7f4"},"locking_mode":"Unlocked","other_config":{},"backend":["Local","xenbr7"],"mtu":1500,"carrier":true,"mac":"be:d5:3b:82:2b:45","position":0,"id":["3797df5e-695a-00be-86bd-318a7c48860f","0"]},{"ipv6_configuration":"Unspecified6","ipv4_configuration":"Unspecified4","extra_private_keys":{"vif-uuid":"cbea6ad6-cb84-5536-e021-d2bdabda6348","network-uuid":"5051222c-d05b-acb5-cdff-c0e48c000ae9"},"locking_mode":"Unlocked","other_config":{},"backend":["Local","xapi0"],"mtu":1500,"carrier":true,"mac":"12:f3:fa:06:fc:42","position":1,"id":["3797df5e-695a-00be-86bd-318a7c48860f","1"]}],"vbds":[{"persistent":true,"extra_private_keys":{},"extra_backend_keys":{"polling-duration":"1000","polling-idle-threshold":"50"},"unpluggable":false,"ty":"Disk","backend":["VDI","bb502d0d-3f9b-7ecd-723b-6363f5de9b96/b607eebc-49ad-4fc0-ad4a-b605fedfc51e"],"mode":"ReadWrite","position":["Ide",1,0],"id":["3797df5e-695a-00be-86bd-318a7c48860f","xvdb"]},{"persistent":true,"extra_private_keys":{},"extra_backend_keys":{"polling-duration":"1000","polling-idle-threshold":"50"},"unpluggable":false,"ty":"Disk","backend":["VDI","bb502d0d-3f9b-7ecd-723b-6363f5de9b96/d7db37b2-a897-469b-a352-33898ba24e2a"],"mode":"ReadWrite","position":["Ide",0,0],"id":["3797df5e-695a-00be-86bd-318a7c48860f","xvda"]},{"persistent":true,"extra_private_keys":{},"extra_backend_keys":{"polling-duration":"1000","polling-idle-threshold":"50"},"unpluggable":false,"ty":"CDROM","mode":"ReadOnly","position":["Ide",3,0],"id":["3797df5e-695a-00be-86bd-318a7c48860f","xvdd"]}],"vm":{"generation_id":"","has_vendor_device":false,"pci_power_mgmt":false,"pci_msitranslate":true,"on_reboot":["Start"],"on_shutdown":["Shutdown"],"on_crash":["Start"],"scheduler_params":{"affinity":[],"priority":[256,0]},"vcpus":4,"vcpu_max":4,"memory_dynamic_min":2147483648,"memory_dynamic_max":17179869184,"memory_static_max":17179869184,"suppress_spurious_page_faults":false,"ty":["HVM",{"firmware":"Bios","qemu_stubdom":false,"qemu_disk_cmdline":false,"boot_order":"dcn","pci_passthrough":false,"pci_emulations":[],"serial":"pty","acpi":true,"video":"Standard_VGA","video_mib":8,"timeoffset":"0","shadow_multiplier":1.0,"hap":true}],"bios_strings":{"bios-vendor":"Xen","bios-version":"","system-manufacturer":"Xen","system-product-name":"HVM domU","system-version":"","system-serial-number":"","baseboard-manufacturer":"","baseboard-product-name":"","baseboard-version":"","baseboard-serial-number":"","baseboard-asset-tag":"","baseboard-location-in-chassis":"","enclosure-asset-tag":"","hp-rombios":"","oem-1":"Xen","oem-2":"MS_VM_CERT/SHA1/bdbeb6e0a816d43fa6d3fe8aaef04c2bad9d3e3d"},"platformdata":{"featureset":"1fcbfbff-f7fa3223-2c100800-00000121-0000000f-009c0fab-00000008-00000000-00001000-bc000400-00000000-00000000-00000000-00000000-00000000-00000000-0c000004-00000000-00000000-00000000-00000000-00000000","timeoffset":"0","usb":"true","usb_tablet":"true","secureboot":"false","device-model":"qemu-upstream-compat","videoram":"8","hpet":"true","apic":"true","device_id":"0001","vga":"std","nx":"true","pae":"true","viridian":"false","acpi":"1"},"xsdata":{"vm-data/mmio-hole-size":"268435456","vm-data":""},"ssidref":0,"name":"Server420","id":"3797df5e-695a-00be-86bd-318a7c48860f"}} Oct 14 20:09:27 XCP25 xenopsd-xc: [debug||655143 |queue|xenops_server] Queue.push ["Atomic",["VM_import_metadata",["3797df5e-695a-00be-86bd-318a7c48860f",{"vusbs":[],"vgpus":[],"pcis":[],"vifs":[{"ipv6_configuration":"Unspecified6","ipv4_configuration":"Unspecified4","extra_private_keys":{"vif-uuid":"de9a4140-0b67-314b-6fed-0bbd00d4cf74","network-uuid":"19edb159-d210-7c75-abb3-b8c63dacd7f4"},"locking_mode":"Unlocked","other_config":{},"backend":["Local","xenbr7"],"mtu":1500,"carrier":true,"mac":"be:d5:3b:82:2b:45","position":0,"id":["3797df5e-695a-00be-86bd-318a7c48860f","0"]},{"ipv6_configuration":"Unspecified6","ipv4_configuration":"Unspecified4","extra_private_keys":{"vif-uuid":"cbea6ad6-cb84-5536-e021-d2bdabda6348","network-uuid":"5051222c-d05b-acb5-cdff-c0e48c000ae9"},"locking_mode":"Unlocked","other_config":{},"backend":["Local","xapi0"],"mtu":1500,"carrier":true,"mac":"12:f3:fa:06:fc:42","position":1,"id":["3797df5e-695a-00be-86bd-318a7c48860f","1"]}],"vbds":[{"persistent":true,"extra_private_keys":{},"extra_backend_keys":{"polling-duration":"1000","polling-idle-threshold":"50"},"unpluggable":false,"ty":"Disk","backend":["VDI","bb502d0d-3f9b-7ecd-723b-6363f5de9b96/b607eebc-49ad-4fc0-ad4a-b605fedfc51e"],"mode":"ReadWrite","position":["Ide",1,0],"id":["3797df5e-695a-00be-86bd-318a7c48860f","xvdb"]},{"persistent":true,"extra_private_keys":{},"extra_backend_keys":{"polling-duration":"1000","polling-idle-threshold":"50"},"unpluggable":false,"ty":"Disk","backend":["VDI","bb502d0d-3f9b-7ecd-723b-6363f5de9b96/d7db37b2-a897-469b-a352-33898ba24e2a"],"mode":"ReadWrite","position":["Ide",0,0],"id":["3797df5e-695a-00be-86bd-318a7c48860f","xvda"]},{"persistent":true,"extra_private_keys":{},"extra_backend_keys":{"polling-duration":"1000","polling-idle-threshold":"50"},"unpluggable":false,"ty":"CDROM","mode":"ReadOnly","position":["Ide",3,0],"id":["3797df5e-695a-00be-86bd-318a7c48860f","xvdd"]}],"vm":{"generation_id":"","has_vendor_device":false,"pci_power_mgmt":false,"pci_msitranslate":true,"on_reboot":["Start"],"on_shutdown":["Shutdown"],"on_crash":["Start"],"scheduler_params":{"affinity":[],"priority":[256,0]},"vcpus":4,"vcpu_max":4,"memory_dynamic_min":2147483648,"memory_dynamic_max":17179869184,"memory_static_max":17179869184,"suppress_spurious_page_faults":false,"ty":["HVM",{"firmware":"Bios","qemu_stubdom":false,"qemu_disk_cmdline":false,"boot_order":"dcn","pci_passthrough":false,"pci_emulations":[],"serial":"pty","acpi":true,"video":"Standard_VGA","video_mib":8,"timeoffset":"0","shadow_multiplier":1.0,"hap":true}],"bios_strings":{"bios-vendor":"Xen","bios-version":"","system-manufacturer":"Xen","system-product-name":"HVM domU","system-version":"","system-serial-number":"","baseboard-manufacturer":"","baseboard-product-name":"","baseboard-version":"","baseboard-serial-number":"","baseboard-asset-tag":"","baseboard-location-in-chassis":"","enclosure-asset-tag":"","hp-rombios":"","oem-1":"Xen","oem-2":"MS_VM_CERT/SHA1/bdbeb6e0a816d43fa6d3fe8aaef04c2bad9d3e3d"},"platformdata":{"featureset":"1fcbfbff-f7fa3223-2c100800-00000121-0000000f-009c0fab-00000008-00000000-00001000-bc000400-00000000-00000000-00000000-00000000-00000000-00000000-0c000004-00000000-00000000-00000000-00000000-00000000","timeoffset":"0","usb":"true","usb_tablet":"true","secureboot":"false","device-model":"qemu-upstream-compat","videoram":"8","hpet":"true","apic":"true","device_id":"0001","vga":"std","nx":"true","pae":"true","viridian":"false","acpi":"1"},"xsdata":{"vm-data/mmio-hole-size":"268435456","vm-data":""},"ssidref":0,"name":"Server420","id":"3797df5e-695a-00be-86bd-318a7c48860f"}}]]] onto 3797df5e-695a-00be-86bd-318a7c48860f:[ ] Oct 14 20:09:27 XCP25 xenopsd-xc: [debug||17 ||xenops_server] Queue.pop returned ["Atomic",["VM_import_metadata",["3797df5e-695a-00be-86bd-318a7c48860f",{"vusbs":[],"vgpus":[],"pcis":[],"vifs":[{"ipv6_configuration":"Unspecified6","ipv4_configuration":"Unspecified4","extra_private_keys":{"vif-uuid":"de9a4140-0b67-314b-6fed-0bbd00d4cf74","network-uuid":"19edb159-d210-7c75-abb3-b8c63dacd7f4"},"locking_mode":"Unlocked","other_config":{},"backend":["Local","xenbr7"],"mtu":1500,"carrier":true,"mac":"be:d5:3b:82:2b:45","position":0,"id":["3797df5e-695a-00be-86bd-318a7c48860f","0"]},{"ipv6_configuration":"Unspecified6","ipv4_configuration":"Unspecified4","extra_private_keys":{"vif-uuid":"cbea6ad6-cb84-5536-e021-d2bdabda6348","network-uuid":"5051222c-d05b-acb5-cdff-c0e48c000ae9"},"locking_mode":"Unlocked","other_config":{},"backend":["Local","xapi0"],"mtu":1500,"carrier":true,"mac":"12:f3:fa:06:fc:42","position":1,"id":["3797df5e-695a-00be-86bd-318a7c48860f","1"]}],"vbds":[{"persistent":true,"extra_private_keys":{},"extra_backend_keys":{"polling-duration":"1000","polling-idle-threshold":"50"},"unpluggable":false,"ty":"Disk","backend":["VDI","bb502d0d-3f9b-7ecd-723b-6363f5de9b96/b607eebc-49ad-4fc0-ad4a-b605fedfc51e"],"mode":"ReadWrite","position":["Ide",1,0],"id":["3797df5e-695a-00be-86bd-318a7c48860f","xvdb"]},{"persistent":true,"extra_private_keys":{},"extra_backend_keys":{"polling-duration":"1000","polling-idle-threshold":"50"},"unpluggable":false,"ty":"Disk","backend":["VDI","bb502d0d-3f9b-7ecd-723b-6363f5de9b96/d7db37b2-a897-469b-a352-33898ba24e2a"],"mode":"ReadWrite","position":["Ide",0,0],"id":["3797df5e-695a-00be-86bd-318a7c48860f","xvda"]},{"persistent":true,"extra_private_keys":{},"extra_backend_keys":{"polling-duration":"1000","polling-idle-threshold":"50"},"unpluggable":false,"ty":"CDROM","mode":"ReadOnly","position":["Ide",3,0],"id":["3797df5e-695a-00be-86bd-318a7c48860f","xvdd"]}],"vm":{"generation_id":"","has_vendor_device":false,"pci_power_mgmt":false,"pci_msitranslate":true,"on_reboot":["Start"],"on_shutdown":["Shutdown"],"on_crash":["Start"],"scheduler_params":{"affinity":[],"priority":[256,0]},"vcpus":4,"vcpu_max":4,"memory_dynamic_min":2147483648,"memory_dynamic_max":17179869184,"memory_static_max":17179869184,"suppress_spurious_page_faults":false,"ty":["HVM",{"firmware":"Bios","qemu_stubdom":false,"qemu_disk_cmdline":false,"boot_order":"dcn","pci_passthrough":false,"pci_emulations":[],"serial":"pty","acpi":true,"video":"Standard_VGA","video_mib":8,"timeoffset":"0","shadow_multiplier":1.0,"hap":true}],"bios_strings":{"bios-vendor":"Xen","bios-version":"","system-manufacturer":"Xen","system-product-name":"HVM domU","system-version":"","system-serial-number":"","baseboard-manufacturer":"","baseboard-product-name":"","baseboard-version":"","baseboard-serial-number":"","baseboard-asset-tag":"","baseboard-location-in-chassis":"","enclosure-asset-tag":"","hp-rombios":"","oem-1":"Xen","oem-2":"MS_VM_CERT/SHA1/bdbeb6e0a816d43fa6d3fe8aaef04c2bad9d3e3d"},"platformdata":{"featureset":"1fcbfbff-f7fa3223-2c100800-00000121-0000000f-009c0fab-00000008-00000000-00001000-bc000400-00000000-00000000-00000000-00000000-00000000-00000000-0c000004-00000000-00000000-00000000-00000000-00000000","timeoffset":"0","usb":"true","usb_tablet":"true","secureboot":"false","device-model":"qemu-upstream-compat","videoram":"8","hpet":"true","apic":"true","device_id":"0001","vga":"std","nx":"true","pae":"true","viridian":"false","acpi":"1"},"xsdata":{"vm-data/mmio-hole-size":"268435456","vm-data":""},"ssidref":0,"name":"Server420","id":"3797df5e-695a-00be-86bd-318a7c48860f"}}]]] Oct 14 20:09:27 XCP25 xenopsd-xc: [debug||17 |xapi events D:54124fdb6d24|xenops_server] Task 324529 reference xapi events D:54124fdb6d24: ["Atomic",["VM_import_metadata",["3797df5e-695a-00be-86bd-318a7c48860f",{"vusbs":[],"vgpus":[],"pcis":[],"vifs":[{"ipv6_configuration":"Unspecified6","ipv4_configuration":"Unspecified4","extra_private_keys":{"vif-uuid":"de9a4140-0b67-314b-6fed-0bbd00d4cf74","network-uuid":"19edb159-d210-7c75-abb3-b8c63dacd7f4"},"locking_mode":"Unlocked","other_config":{},"backend":["Local","xenbr7"],"mtu":1500,"carrier":true,"mac":"be:d5:3b:82:2b:45","position":0,"id":["3797df5e-695a-00be-86bd-318a7c48860f","0"]},{"ipv6_configuration":"Unspecified6","ipv4_configuration":"Unspecified4","extra_private_keys":{"vif-uuid":"cbea6ad6-cb84-5536-e021-d2bdabda6348","network-uuid":"5051222c-d05b-acb5-cdff-c0e48c000ae9"},"locking_mode":"Unlocked","other_config":{},"backend":["Local","xapi0"],"mtu":1500,"carrier":true,"mac":"12:f3:fa:06:fc:42","position":1,"id":["3797df5e-695a-00be-86bd-318a7c48860f","1"]}],"vbds":[{"persistent":true,"extra_private_keys":{},"extra_backend_keys":{"polling-duration":"1000","polling-idle-threshold":"50"},"unpluggable":false,"ty":"Disk","backend":["VDI","bb502d0d-3f9b-7ecd-723b-6363f5de9b96/b607eebc-49ad-4fc0-ad4a-b605fedfc51e"],"mode":"ReadWrite","position":["Ide",1,0],"id":["3797df5e-695a-00be-86bd-318a7c48860f","xvdb"]},{"persistent":true,"extra_private_keys":{},"extra_backend_keys":{"polling-duration":"1000","polling-idle-threshold":"50"},"unpluggable":false,"ty":"Disk","backend":["VDI","bb502d0d-3f9b-7ecd-723b-6363f5de9b96/d7db37b2-a897-469b-a352-33898ba24e2a"],"mode":"ReadWrite","position":["Ide",0,0],"id":["3797df5e-695a-00be-86bd-318a7c48860f","xvda"]},{"persistent":true,"extra_private_keys":{},"extra_backend_keys":{"polling-duration":"1000","polling-idle-threshold":"50"},"unpluggable":false,"ty":"CDROM","mode":"ReadOnly","position":["Ide",3,0],"id":["3797df5e-695a-00be-86bd-318a7c48860f","xvdd"]}],"vm":{"generation_id":"","has_vendor_device":false,"pci_power_mgmt":false,"pci_msitranslate":true,"on_reboot":["Start"],"on_shutdown":["Shutdown"],"on_crash":["Start"],"scheduler_params":{"affinity":[],"priority":[256,0]},"vcpus":4,"vcpu_max":4,"memory_dynamic_min":2147483648,"memory_dynamic_max":17179869184,"memory_static_max":17179869184,"suppress_spurious_page_faults":false,"ty":["HVM",{"firmware":"Bios","qemu_stubdom":false,"qemu_disk_cmdline":false,"boot_order":"dcn","pci_passthrough":false,"pci_emulations":[],"serial":"pty","acpi":true,"video":"Standard_VGA","video_mib":8,"timeoffset":"0","shadow_multiplier":1.0,"hap":true}],"bios_strings":{"bios-vendor":"Xen","bios-version":"","system-manufacturer":"Xen","system-product-name":"HVM domU","system-version":"","system-serial-number":"","baseboard-manufacturer":"","baseboard-product-name":"","baseboard-version":"","baseboard-serial-number":"","baseboard-asset-tag":"","baseboard-location-in-chassis":"","enclosure-asset-tag":"","hp-rombios":"","oem-1":"Xen","oem-2":"MS_VM_CERT/SHA1/bdbeb6e0a816d43fa6d3fe8aaef04c2bad9d3e3d"},"platformdata":{"featureset":"1fcbfbff-f7fa3223-2c100800-00000121-0000000f-009c0fab-00000008-00000000-00001000-bc000400-00000000-00000000-00000000-00000000-00000000-00000000-0c000004-00000000-00000000-00000000-00000000-00000000","timeoffset":"0","usb":"true","usb_tablet":"true","secureboot":"false","device-model":"qemu-upstream-compat","videoram":"8","hpet":"true","apic":"true","device_id":"0001","vga":"std","nx":"true","pae":"true","viridian":"false","acpi":"1"},"xsdata":{"vm-data/mmio-hole-size":"268435456","vm-data":""},"ssidref":0,"name":"Server420","id":"3797df5e-695a-00be-86bd-318a7c48860f"}}]]] Oct 14 20:09:27 XCP25 xenopsd-xc: [debug||17 |xapi events D:54124fdb6d24|xenops_server] VM.import_metadata: overwriting VM metadata for VM: 3797df5e-695a-00be-86bd-318a7c48860f Oct 14 20:09:27 XCP25 xenopsd-xc: [debug||17 |xapi events D:54124fdb6d24|xenops_server] Platformdata:featureset=1fcbfbff-f7fa3223-2c100800-00000121-0000000f-009c0fab-00000008-00000000-00001000-bc000400-00000000-00000000-00000000-00000000-00000000-00000000-0c000004-00000000-00000000-00000000-00000000-00000000 Oct 14 20:09:27 XCP25 xenopsd-xc: [debug||17 |xapi events D:54124fdb6d24|xenops_server] VM.add {"generation_id":"","has_vendor_device":false,"pci_power_mgmt":false,"pci_msitranslate":true,"on_reboot":["Start"],"on_shutdown":["Shutdown"],"on_crash":["Start"],"scheduler_params":{"affinity":[],"priority":[256,0]},"vcpus":4,"vcpu_max":4,"memory_dynamic_min":2147483648,"memory_dynamic_max":17179869184,"memory_static_max":17179869184,"suppress_spurious_page_faults":false,"ty":["HVM",{"firmware":"Bios","qemu_stubdom":false,"qemu_disk_cmdline":false,"boot_order":"dcn","pci_passthrough":false,"pci_emulations":[],"serial":"pty","acpi":true,"video":"Standard_VGA","video_mib":8,"timeoffset":"0","shadow_multiplier":1.0,"hap":true}],"bios_strings":{"bios-vendor":"Xen","bios-version":"","system-manufacturer":"Xen","system-product-name":"HVM domU","system-version":"","system-serial-number":"","baseboard-manufacturer":"","baseboard-product-name":"","baseboard-version":"","baseboard-serial-number":"","baseboard-asset-tag":"","baseboard-location-in-chassis":"","enclosure-asset-tag":"","hp-rombios":"","oem-1":"Xen","oem-2":"MS_VM_CERT/SHA1/bdbeb6e0a816d43fa6d3fe8aaef04c2bad9d3e3d"},"platformdata":{"featureset":"1fcbfbff-f7fa3223-2c100800-00000121-0000000f-009c0fab-00000008-00000000-00001000-bc000400-00000000-00000000-00000000-00000000-00000000-00000000-0c000004-00000000-00000000-00000000-00000000-00000000","timeoffset":"0","usb":"true","usb_tablet":"true","secureboot":"false","device-model":"qemu-upstream-compat","videoram":"8","hpet":"true","apic":"true","device_id":"0001","vga":"std","nx":"true","pae":"true","viridian":"false","acpi":"1"},"xsdata":{"vm-data/mmio-hole-size":"268435456","vm-data":""},"ssidref":0,"name":"Server420","id":"3797df5e-695a-00be-86bd-318a7c48860f"} Oct 14 20:09:27 XCP25 xenopsd-xc: [debug||17 |xapi events D:54124fdb6d24|xenops_utils] TypedTable: Writing VM/3797df5e-695a-00be-86bd-318a7c48860f/config Oct 14 20:09:27 XCP25 xapi: [debug||1202 ||dummytaskhelper] task timeboxed_rpc D:335768689fb6 created by task D:54124fdb6d24 Oct 14 20:09:27 XCP25 xenopsd-xc: [debug||17 |xapi events D:54124fdb6d24|xenops] VM 3797df5e-695a-00be-86bd-318a7c48860f exists with domid=23; checking whether xenstore is intact Oct 14 20:09:27 XCP25 xapi: [debug||5937627 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:event.from D:581c4e7f1fbd created by task D:54124fdb6d24 Oct 14 20:09:27 XCP25 xenopsd-xc: [debug||17 |xapi events D:54124fdb6d24|xenops_server] VBD.add 3797df5e-695a-00be-86bd-318a7c48860f.xvdb {"persistent":true,"extra_private_keys":{},"extra_backend_keys":{"polling-duration":"1000","polling-idle-threshold":"50"},"unpluggable":false,"ty":"Disk","backend":["VDI","bb502d0d-3f9b-7ecd-723b-6363f5de9b96/b607eebc-49ad-4fc0-ad4a-b605fedfc51e"],"mode":"ReadWrite","position":["Ide",1,0],"id":["3797df5e-695a-00be-86bd-318a7c48860f","xvdb"]} Oct 14 20:09:27 XCP25 xenopsd-xc: [debug||17 |xapi events D:54124fdb6d24|xenops_utils] TypedTable: Writing VM/3797df5e-695a-00be-86bd-318a7c48860f/vbd.xvdb Oct 14 20:09:27 XCP25 xenopsd-xc: [debug||17 |xapi events D:54124fdb6d24|xenops_server] VBD.add 3797df5e-695a-00be-86bd-318a7c48860f.xvda {"persistent":true,"extra_private_keys":{},"extra_backend_keys":{"polling-duration":"1000","polling-idle-threshold":"50"},"unpluggable":false,"ty":"Disk","backend":["VDI","bb502d0d-3f9b-7ecd-723b-6363f5de9b96/d7db37b2-a897-469b-a352-33898ba24e2a"],"mode":"ReadWrite","position":["Ide",0,0],"id":["3797df5e-695a-00be-86bd-318a7c48860f","xvda"]} Oct 14 20:09:27 XCP25 xenopsd-xc: [debug||17 |xapi events D:54124fdb6d24|xenops_utils] TypedTable: Writing VM/3797df5e-695a-00be-86bd-318a7c48860f/vbd.xvda Oct 14 20:09:27 XCP25 xenopsd-xc: [debug||17 |xapi events D:54124fdb6d24|xenops_server] VBD.add 3797df5e-695a-00be-86bd-318a7c48860f.xvdd {"persistent":true,"extra_private_keys":{},"extra_backend_keys":{"polling-duration":"1000","polling-idle-threshold":"50"},"unpluggable":false,"ty":"CDROM","mode":"ReadOnly","position":["Ide",3,0],"id":["3797df5e-695a-00be-86bd-318a7c48860f","xvdd"]} Oct 14 20:09:27 XCP25 xenopsd-xc: [debug||17 |xapi events D:54124fdb6d24|xenops_utils] TypedTable: Writing VM/3797df5e-695a-00be-86bd-318a7c48860f/vbd.xvdd Oct 14 20:09:27 XCP25 xenopsd-xc: [debug||17 |xapi events D:54124fdb6d24|xenops_server] VIF.add {"ipv6_configuration":"Unspecified6","ipv4_configuration":"Unspecified4","extra_private_keys":{"vif-uuid":"de9a4140-0b67-314b-6fed-0bbd00d4cf74","network-uuid":"19edb159-d210-7c75-abb3-b8c63dacd7f4"},"locking_mode":"Unlocked","other_config":{},"backend":["Local","xenbr7"],"mtu":1500,"carrier":true,"mac":"be:d5:3b:82:2b:45","position":0,"id":["3797df5e-695a-00be-86bd-318a7c48860f","0"]} Oct 14 20:09:27 XCP25 xenopsd-xc: [debug||17 |xapi events D:54124fdb6d24|xenops_utils] TypedTable: Writing VM/3797df5e-695a-00be-86bd-318a7c48860f/vif.0 Oct 14 20:09:27 XCP25 xenopsd-xc: [debug||17 |xapi events D:54124fdb6d24|xenops_server] VIF.add {"ipv6_configuration":"Unspecified6","ipv4_configuration":"Unspecified4","extra_private_keys":{"vif-uuid":"cbea6ad6-cb84-5536-e021-d2bdabda6348","network-uuid":"5051222c-d05b-acb5-cdff-c0e48c000ae9"},"locking_mode":"Unlocked","other_config":{},"backend":["Local","xapi0"],"mtu":1500,"carrier":true,"mac":"12:f3:fa:06:fc:42","position":1,"id":["3797df5e-695a-00be-86bd-318a7c48860f","1"]} Oct 14 20:09:27 XCP25 xenopsd-xc: [debug||17 |xapi events D:54124fdb6d24|xenops_utils] TypedTable: Writing VM/3797df5e-695a-00be-86bd-318a7c48860f/vif.1 Oct 14 20:09:27 XCP25 xenopsd-xc: [debug||17 |xapi events D:54124fdb6d24|task_server] Task 324529 completed; duration = 0 Oct 14 20:09:27 XCP25 xenopsd-xc: [debug||17 |xapi events D:54124fdb6d24|task_server] Auto-destroying task 324529 Oct 14 20:09:27 XCP25 xenopsd-xc: [debug||17 ||xenops_server] TASK.signal 324529 (object deleted) Oct 14 20:09:31 XCP25 xapi: [debug||5937628 HTTPS 10.10.10.95->:::80|host.call_plugin R:2b5070b1f4df|audit] Host.call_plugin host = '8d6e2b03-54c1-4523-b45b-d572a268f2cc (XCP25)'; plugin = 'updater.py'; fn = 'check_update' args = [ 'hidden' ] Oct 14 20:09:34 XCP25 xapi: [debug||1206 scanning_thread|SR scanner D:3b6b5f2d8cde|xapi_sr] Automatically scanning SRs = [ OpaqueRef:88574456-65df-41a3-8d3e-8a77ba64c325 ] Oct 14 20:09:34 XCP25 xapi: [debug||5937629 ||dummytaskhelper] task scan one D:8025297650f4 created by task D:3b6b5f2d8cde Oct 14 20:09:34 XCP25 xapi: [debug||5937630 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:session.slave_login D:ee8b23333307 created by task D:8025297650f4 Oct 14 20:09:34 XCP25 xapi: [ info||5937630 /var/lib/xcp/xapi|session.slave_login D:c295f7835901|xapi_session] Session.create trackid=b44e2a72ceb110432588921bac0d3887 pool=true uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:34 XCP25 xapi: [debug||5937631 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:a167d3d839dc created by task D:c295f7835901 Oct 14 20:09:34 XCP25 xapi: [debug||5937632 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.scan D:e885ccdc0a44 created by task D:8025297650f4 Oct 14 20:09:34 XCP25 xapi: [ info||5937632 /var/lib/xcp/xapi||taskhelper] task SR.scan R:df6cec10b8c7 (uuid:4af14d35-8b1a-29ef-42e0-95c6219b7f53) created (trackid=b44e2a72ceb110432588921bac0d3887) by task D:8025297650f4 Oct 14 20:09:34 XCP25 xapi: [debug||5937632 /var/lib/xcp/xapi|SR.scan R:df6cec10b8c7|message_forwarding] SR.scan: SR = 'ef3c3e29-6bb9-64f2-1174-1f0295bdd4f1 (NFS ISO)' Oct 14 20:09:34 XCP25 xapi: [debug||5937632 /var/lib/xcp/xapi|SR.scan R:df6cec10b8c7|message_forwarding] Marking SR for SR.scan (task=OpaqueRef:df6cec10-b8c7-4988-9008-cacafcde3a09) Oct 14 20:09:34 XCP25 xapi: [ info||5937632 /var/lib/xcp/xapi|SR.scan R:df6cec10b8c7|storage_impl] SR.scan dbg:OpaqueRef:df6cec10-b8c7-4988-9008-cacafcde3a09 sr:ef3c3e29-6bb9-64f2-1174-1f0295bdd4f1 Oct 14 20:09:34 XCP25 xapi: [debug||5937633 ||dummytaskhelper] task SR.scan D:cd03c6fa749c created by task R:df6cec10b8c7 Oct 14 20:09:34 XCP25 xapi: [debug||5937633 |SR.scan D:cd03c6fa749c|sm] SM iso sr_scan sr=OpaqueRef:88574456-65df-41a3-8d3e-8a77ba64c325 Oct 14 20:09:34 XCP25 xapi: [ info||5937633 |sm_exec D:13410fd14303|xapi_session] Session.create trackid=e6cbc0364238b5420571a69e0ba58685 pool=false uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:34 XCP25 xapi: [debug||5937634 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:b3719bfa513b created by task D:13410fd14303 Oct 14 20:09:34 XCP25 xapi: [debug||5937635 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:host.get_other_config D:74c82548c2ae created by task D:cd03c6fa749c Oct 14 20:09:34 XCP25 xapi: [debug||5937636 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_by_uuid D:f87f20503f48 created by task D:cd03c6fa749c Oct 14 20:09:34 XCP25 xapi: [debug||5937637 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_all_records_where D:e0c8e87d24bc created by task D:cd03c6fa749c Oct 14 20:09:34 XCP25 xapi: [debug||5937638 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_other_config D:dcaee2d018a8 created by task D:cd03c6fa749c Oct 14 20:09:34 XCP25 xapi: [debug||5937639 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_by_uuid D:78b871e0bd06 created by task D:cd03c6fa749c Oct 14 20:09:34 XCP25 xapi: [debug||5937640 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.set_virtual_allocation D:ec73896082e4 created by task D:cd03c6fa749c Oct 14 20:09:34 XCP25 xapi: [debug||5937641 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.set_physical_size D:d718f54c4832 created by task D:cd03c6fa749c Oct 14 20:09:34 XCP25 xapi: [debug||5937642 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.set_physical_utilisation D:28a3278df35a created by task D:cd03c6fa749c Oct 14 20:09:34 XCP25 xapi: [debug||5937643 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_by_uuid D:c0b7a34d7f43 created by task D:cd03c6fa749c Oct 14 20:09:34 XCP25 xapi: [debug||5937644 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VDI.get_all_records_where D:2ae40effd42b created by task D:cd03c6fa749c Oct 14 20:09:34 XCP25 xapi: [ info||5937633 |sm_exec D:13410fd14303|xapi_session] Session.destroy trackid=e6cbc0364238b5420571a69e0ba58685 Oct 14 20:09:34 XCP25 xapi: [ info||5937632 /var/lib/xcp/xapi|SR.scan R:df6cec10b8c7|storage_impl] SR.stat dbg:OpaqueRef:df6cec10-b8c7-4988-9008-cacafcde3a09 sr:ef3c3e29-6bb9-64f2-1174-1f0295bdd4f1 Oct 14 20:09:34 XCP25 xapi: [debug||5937645 ||dummytaskhelper] task SR.stat D:41599fc4242f created by task R:df6cec10b8c7 Oct 14 20:09:34 XCP25 xapi: [debug||5937645 |SR.stat D:41599fc4242f|sm] SM iso sr_update sr=OpaqueRef:88574456-65df-41a3-8d3e-8a77ba64c325 Oct 14 20:09:34 XCP25 xapi: [ info||5937645 |sm_exec D:f52dcca02879|xapi_session] Session.create trackid=76abcfdd1760ba02b5a4d361f288bcf1 pool=false uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:34 XCP25 xapi: [debug||5937646 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:5752e373901e created by task D:f52dcca02879 Oct 14 20:09:35 XCP25 xapi: [debug||5937647 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:host.get_other_config D:83585b1c91cd created by task D:41599fc4242f Oct 14 20:09:35 XCP25 xapi: [ info||5937645 |sm_exec D:f52dcca02879|xapi_session] Session.destroy trackid=76abcfdd1760ba02b5a4d361f288bcf1 Oct 14 20:09:35 XCP25 xapi: [debug||5937632 /var/lib/xcp/xapi|SR.scan R:df6cec10b8c7|message_forwarding] Unmarking SR after SR.scan (task=OpaqueRef:df6cec10-b8c7-4988-9008-cacafcde3a09) Oct 14 20:09:35 XCP25 xapi: [debug||5937648 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:session.logout D:5dbe2c9dd93c created by task D:8025297650f4 Oct 14 20:09:35 XCP25 xapi: [ info||5937648 /var/lib/xcp/xapi|session.logout D:ef755eebaa71|xapi_session] Session.destroy trackid=b44e2a72ceb110432588921bac0d3887 Oct 14 20:09:35 XCP25 xapi: [debug||5937629 |scan one D:8025297650f4|xapi_sr] Scan of SR ef3c3e29-6bb9-64f2-1174-1f0295bdd4f1 complete. Oct 14 20:09:40 XCP25 xapi: [debug||5937649 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:session.logout D:533ac8ffe9cf created by task D:6f7ddf1004ca Oct 14 20:09:40 XCP25 xapi: [ info||5937649 /var/lib/xcp/xapi|session.logout D:dac925850bd8|xapi_session] Session.destroy trackid=76a4fa6d9601ba72d7c78e152c90fdb8 Oct 14 20:09:40 XCP25 xapi: [debug||5937650 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:session.slave_login D:7294c168ec90 created by task D:6f7ddf1004ca Oct 14 20:09:40 XCP25 xapi: [ info||5937650 /var/lib/xcp/xapi|session.slave_login D:c05e7d727adf|xapi_session] Session.create trackid=e395f340a3b51c152e8f080a8656cdfc pool=true uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Oct 14 20:09:40 XCP25 xapi: [debug||5937651 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:0f2dbc16dee3 created by task D:c05e7d727adf Oct 14 20:09:40 XCP25 xapi: [debug||5937652 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:event.from D:0253de3f5e01 created by task D:6f7ddf1004ca Oct 14 20:09:44 XCP25 xenopsd-xc: [debug||5 ||xenops_server] Received an event on managed VM 3797df5e-695a-00be-86bd-318a7c48860f Oct 14 20:09:44 XCP25 xenopsd-xc: [debug||5 |queue|xenops_server] Queue.push ["VM_check_state","3797df5e-695a-00be-86bd-318a7c48860f"] onto 3797df5e-695a-00be-86bd-318a7c48860f:[ ] Oct 14 20:09:44 XCP25 xenopsd-xc: [debug||32 ||xenops_server] Queue.pop returned ["VM_check_state","3797df5e-695a-00be-86bd-318a7c48860f"] Oct 14 20:09:44 XCP25 xenopsd-xc: [debug||32 |events|xenops_server] Task 324530 reference events: ["VM_check_state","3797df5e-695a-00be-86bd-318a7c48860f"] Oct 14 20:09:44 XCP25 xenopsd-xc: [debug||32 |events|xenops_server] VM 3797df5e-695a-00be-86bd-318a7c48860f is not requesting any attention Oct 14 20:09:44 XCP25 xenopsd-xc: [debug||32 |events|xenops_server] VM_DB.signal 3797df5e-695a-00be-86bd-318a7c48860f Oct 14 20:09:44 XCP25 xenopsd-xc: [debug||32 |events|task_server] Task 324530 completed; duration = 0 Oct 14 20:09:44 XCP25 xenopsd-xc: [debug||32 ||xenops_server] TASK.signal 324530 (object deleted) Oct 14 20:09:44 XCP25 xapi: [debug||1197 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops] Processing event: ["Vm","3797df5e-695a-00be-86bd-318a7c48860f"] Oct 14 20:09:44 XCP25 xapi: [debug||1197 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops] xenops event on VM 3797df5e-695a-00be-86bd-318a7c48860f Oct 14 20:09:44 XCP25 xenopsd-xc: [debug||655145 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops_server] VM.stat 3797df5e-695a-00be-86bd-318a7c48860f Oct 14 20:09:44 XCP25 xapi: [debug||1197 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops] xenopsd event: processing event for VM 3797df5e-695a-00be-86bd-318a7c48860f Oct 14 20:09:44 XCP25 xapi: [debug||1197 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops] Supressing VM.allowed_operations update because guest_agent data is largely the same Oct 14 20:09:44 XCP25 xapi: [debug||1197 |org.xen.xapi.xenops.classic events D:32df2765d6ea|xenops] xenopsd event: Updating VM 3797df5e-695a-00be-86bd-318a7c48860f domid 23 guest_agent