Windows11 VMs failing to boot
-
[10:38 hst100 xen]# tail -f /var/log/xensource.log Jul 11 10:41:22 hst100 xapi: [ info||17967 |sm_exec D:1f5adec885fc|xapi_session] Session.destroy trackid=d57ddf3b827b76a764382bb034f6df00 Jul 11 10:41:22 hst100 xapi: [debug||17967 |OpaqueRef:2f7768a0-46af-7e7a-f61a-75b641fe160d|dummytaskhelper] task SR.stat D:2e250443803d created by task R:2f7768a046af Jul 11 10:41:22 hst100 xapi: [debug||17967 |SR.stat D:2e250443803d|sm] SM nfs sr_update sr=OpaqueRef:cab6d499-a2af-f407-b5d7-cc5106101c59 Jul 11 10:41:22 hst100 xapi: [ info||17967 |sm_exec D:43e19d131b64|xapi_session] Session.create trackid=51e6c3231dd12ea7d711ef4cfef8a392 pool=false uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Jul 11 10:41:22 hst100 xapi: [debug||17981 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:pool.get_all D:ee0f82c1e793 created by task D:43e19d131b64 Jul 11 10:41:22 hst100 xapi: [ info||17982 /var/lib/xcp/xapi|session.login_with_password D:ea7449fe408a|xapi_session] Session.create trackid=35cd066b3e308a3c646cac5035147382 pool=false uname=root originator=SM is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Jul 11 10:41:22 hst100 xapi: [debug||17983 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:pool.get_all D:8998fc7453cf created by task D:ea7449fe408a Jul 11 10:41:22 hst100 xapi: [ info||17982 /var/lib/xcp/xapi|session.logout D:802a90760a73|xapi_session] Session.destroy trackid=35cd066b3e308a3c646cac5035147382 Jul 11 10:41:22 hst100 xapi: [ info||17984 /var/lib/xcp/xapi|session.login_with_password D:bb6735f8c01e|xapi_session] Session.create trackid=01bb9a84f1ed735542a4cbdcb22dc3e4 pool=false uname=root originator=SM is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Jul 11 10:41:22 hst100 xapi: [debug||17985 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:pool.get_all D:a641844de76c created by task D:bb6735f8c01e Jul 11 10:41:24 hst100 xapi: [ info||17967 |sm_exec D:43e19d131b64|xapi_session] Session.destroy trackid=51e6c3231dd12ea7d711ef4cfef8a392 Jul 11 10:41:24 hst100 xapi: [debug||17965 /var/lib/xcp/xapi|SR.scan R:2f7768a046af|xapi_sr] Xapi_sr.scan.(fun).scan_rec no change detected, updating VDIs Jul 11 10:41:24 hst100 xapi: [debug||17965 /var/lib/xcp/xapi|SR.scan R:2f7768a046af|message_forwarding] Unmarking SR after SR.scan (task=OpaqueRef:2f7768a0-46af-7e7a-f61a-75b641fe160d) Jul 11 10:41:24 hst100 xapi: [debug||17987 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:session.logout D:d6d32a67415f created by task D:101b45c58ffc Jul 11 10:41:24 hst100 xapi: [ info||17987 /var/lib/xcp/xapi|session.logout D:ae943942b564|xapi_session] Session.destroy trackid=f6fa2f161f0320e76f9eaa32793303e0 Jul 11 10:41:24 hst100 xapi: [debug||17959 |scan one D:101b45c58ffc|xapi_sr] Scan of SR d4b22411-592f-7ada-0597-68dbcb56ee4d complete. Jul 11 10:41:27 hst100 xcp-rrdd: [ info||9 ||rrdd_main] memfree has changed to 1080120 in domain 4 Jul 11 10:41:27 hst100 xenopsd-xc: [debug||6 |events|xenops_server] Received an event on managed VM 4b27ed77-6a0e-cb7f-ccaa-1f852861d190 Jul 11 10:41:27 hst100 xenopsd-xc: [debug||6 |queue|xenops_server] Queue.push ["VM_check_state","4b27ed77-6a0e-cb7f-ccaa-1f852861d190"] onto 4b27ed77-6a0e-cb7f-ccaa-1f852861d190:[ ] Jul 11 10:41:27 hst100 squeezed: [debug||4 ||squeeze_xen] watch /data/updated <- Fri Jul 11 10:41:27 2025 Jul 11 10:41:27 hst100 xenopsd-xc: [debug||26 ||xenops_server] Queue.pop returned ["VM_check_state","4b27ed77-6a0e-cb7f-ccaa-1f852861d190"] Jul 11 10:41:27 hst100 xenopsd-xc: [debug||26 |events|xenops_server] Task 1417 reference events: ["VM_check_state","4b27ed77-6a0e-cb7f-ccaa-1f852861d190"] Jul 11 10:41:27 hst100 xenopsd-xc: [debug||26 |events|xenops_server] VM 4b27ed77-6a0e-cb7f-ccaa-1f852861d190 is not requesting any attention Jul 11 10:41:27 hst100 xenopsd-xc: [debug||26 |events|xenops_server] VM_DB.signal 4b27ed77-6a0e-cb7f-ccaa-1f852861d190 Jul 11 10:41:27 hst100 xenopsd-xc: [debug||26 |events|task_server] Task 1417 completed; duration = 0 Jul 11 10:41:27 hst100 xenopsd-xc: [debug||26 ||xenops_server] TASK.signal 1417 (object deleted) Jul 11 10:41:27 hst100 xapi: [debug||148 |org.xen.xapi.xenops.classic events D:14adfb57e17b|xenops] Processing event: ["Vm","4b27ed77-6a0e-cb7f-ccaa-1f852861d190"] Jul 11 10:41:27 hst100 xapi: [debug||148 |org.xen.xapi.xenops.classic events D:14adfb57e17b|xenops] xenops event on VM 4b27ed77-6a0e-cb7f-ccaa-1f852861d190 Jul 11 10:41:27 hst100 xenopsd-xc: [debug||2932 |org.xen.xapi.xenops.classic events D:14adfb57e17b|xenops_server] VM.stat 4b27ed77-6a0e-cb7f-ccaa-1f852861d190 Jul 11 10:41:27 hst100 xapi: [debug||148 |org.xen.xapi.xenops.classic events D:14adfb57e17b|xenops] xenopsd event: processing event for VM 4b27ed77-6a0e-cb7f-ccaa-1f852861d190 Jul 11 10:41:27 hst100 xapi: [debug||148 |org.xen.xapi.xenops.classic events D:14adfb57e17b|xenops] Supressing VM.allowed_operations update because guest_agent data is largely the same Jul 11 10:41:27 hst100 xapi: [debug||148 |org.xen.xapi.xenops.classic events D:14adfb57e17b|xenops] xenopsd event: Updating VM 4b27ed77-6a0e-cb7f-ccaa-1f852861d190 domid 4 guest_agent Jul 11 10:41:29 hst100 xapi: [ info||17988 /var/lib/xcp/xapi|session.login_with_password D:241021bd77e1|xapi_session] Session.create trackid=92f90e5f1c41bf1f25a7e8decad1be50 pool=false uname=root originator=SM is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Jul 11 10:41:29 hst100 xapi: [debug||17989 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:pool.get_all D:4faa903a387e created by task D:241021bd77e1 Jul 11 10:41:29 hst100 xapi: [ info||17984 /var/lib/xcp/xapi|session.logout D:b78e5175096e|xapi_session] Session.destroy trackid=01bb9a84f1ed735542a4cbdcb22dc3e4 Jul 11 10:41:35 hst100 xcp-rrdd: [ info||9 ||rrdd_main] memfree has changed to 6554228 in domain 5 Jul 11 10:41:36 hst100 xapi: [debug||16966 ||sparse_dd_wrapper] sparse_dd: Progress: 19 Jul 11 10:41:36 hst100 xapi: [debug||16966 ||storage] TASK.signal 19 = ["Pending",0.22100000000000003] Jul 11 10:41:36 hst100 xapi: [debug||23 |sm_events D:a7cbe4356632|storage_access] sm event on Task 19 Jul 11 10:41:36 hst100 xapi: [debug||12554 HTTPS 51.161.213.26->|Async.VM.migrate_send R:78b4661066db|storage_access] Received update: ["Task","19"] Jul 11 10:41:36 hst100 xapi: [debug||12554 HTTPS 51.161.213.26->|Async.VM.migrate_send R:78b4661066db|storage_access] Calling UPDATES.get Async.VM.migrate_send R:78b4661066db 1749 30 Jul 11 10:41:47 hst100 xapi: [debug||177 scanning_thread|SR scanner D:97b30c7439bc|xapi_sr] Automatically scanning SRs = [ OpaqueRef:cab6d499-a2af-f407-b5d7-cc5106101c59;OpaqueRef:3e473288-a1f8-f0bb-80d7-3baa0ee0628b ] Jul 11 10:41:47 hst100 xapi: [debug||17990 ||dummytaskhelper] task scan one D:f280daf4394a created by task D:97b30c7439bc Jul 11 10:41:47 hst100 xapi: [debug||17991 ||dummytaskhelper] task scan one D:7d4bfe2b75fa created by task D:97b30c7439bc Jul 11 10:41:47 hst100 xapi: [debug||17992 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:session.slave_login D:0908878b4b6b created by task D:f280daf4394a Jul 11 10:41:47 hst100 xapi: [ info||17992 /var/lib/xcp/xapi|session.slave_login D:8b0c6872d88c|xapi_session] Session.create trackid=aeaa0692cf6b9ee21b44fba5b9a33cc6 pool=true uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Jul 11 10:41:47 hst100 xapi: [debug||17993 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:session.slave_login D:09334d9f54d0 created by task D:7d4bfe2b75fa Jul 11 10:41:47 hst100 xapi: [ info||17993 /var/lib/xcp/xapi|session.slave_login D:96939f2b4390|xapi_session] Session.create trackid=2f7776a5c3a2cce90ffe012a98075090 pool=true uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Jul 11 10:41:47 hst100 xapi: [debug||17995 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:pool.get_all D:e9fd3b387f46 created by task D:96939f2b4390 Jul 11 10:41:47 hst100 xapi: [debug||17994 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:pool.get_all D:5b55216f450c created by task D:8b0c6872d88c Jul 11 10:41:47 hst100 xapi: [debug||17996 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:SR.scan D:1d51f520afa5 created by task D:f280daf4394a Jul 11 10:41:47 hst100 xapi: [debug||17997 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:SR.scan D:36c909da8770 created by task D:7d4bfe2b75fa Jul 11 10:41:47 hst100 xapi: [ info||17996 /var/lib/xcp/xapi|dispatch:SR.scan D:1d51f520afa5|taskhelper] task SR.scan R:06b4b7bb8db2 (uuid:ddd5c80f-327e-91ce-d11f-35655171a772) created (trackid=aeaa0692cf6b9ee21b44fba5b9a33cc6) by task D:f280daf4394a Jul 11 10:41:47 hst100 xapi: [debug||17996 /var/lib/xcp/xapi|SR.scan R:06b4b7bb8db2|message_forwarding] SR.scan: SR = 'd4b22411-592f-7ada-0597-68dbcb56ee4d (HST100 Backup)' Jul 11 10:41:47 hst100 xapi: [ info||17997 /var/lib/xcp/xapi|dispatch:SR.scan D:36c909da8770|taskhelper] task SR.scan R:08bcdeea9fb1 (uuid:0f824f57-8c33-2062-bf66-d9b72fb56f3b) created (trackid=2f7776a5c3a2cce90ffe012a98075090) by task D:7d4bfe2b75fa Jul 11 10:41:47 hst100 xapi: [debug||17997 /var/lib/xcp/xapi|SR.scan R:08bcdeea9fb1|message_forwarding] SR.scan: SR = 'd0140e93-71fe-9b11-4e5a-d80ce8102870 (ISOs)' Jul 11 10:41:47 hst100 xapi: [debug||17996 /var/lib/xcp/xapi|SR.scan R:06b4b7bb8db2|message_forwarding] Marking SR for SR.scan (task=OpaqueRef:06b4b7bb-8db2-67e6-ce2b-fc190d089f17) Jul 11 10:41:47 hst100 xapi: [ info||17996 /var/lib/xcp/xapi|OpaqueRef:06b4b7bb-8db2-67e6-ce2b-fc190d089f17|mux] SR.scan2 dbg:OpaqueRef:06b4b7bb-8db2-67e6-ce2b-fc190d089f17 sr:d4b22411-592f-7ada-0597-68dbcb56ee4d Jul 11 10:41:47 hst100 xapi: [debug||17997 /var/lib/xcp/xapi|SR.scan R:08bcdeea9fb1|message_forwarding] Marking SR for SR.scan (task=OpaqueRef:08bcdeea-9fb1-3d0b-4d96-335db5a0c2a4) Jul 11 10:41:47 hst100 xapi: [ info||17997 /var/lib/xcp/xapi|OpaqueRef:08bcdeea-9fb1-3d0b-4d96-335db5a0c2a4|mux] SR.scan2 dbg:OpaqueRef:08bcdeea-9fb1-3d0b-4d96-335db5a0c2a4 sr:d0140e93-71fe-9b11-4e5a-d80ce8102870 Jul 11 10:41:47 hst100 xapi: [ info||17998 |OpaqueRef:06b4b7bb-8db2-67e6-ce2b-fc190d089f17|Storage_smapiv1_wrapper] SR.scan2 dbg:OpaqueRef:06b4b7bb-8db2-67e6-ce2b-fc190d089f17 sr:d4b22411-592f-7ada-0597-68dbcb56ee4d Jul 11 10:41:47 hst100 xapi: [debug||17998 |OpaqueRef:06b4b7bb-8db2-67e6-ce2b-fc190d089f17|dummytaskhelper] task SR.scan D:91a013d358e8 created by task R:06b4b7bb8db2 Jul 11 10:41:47 hst100 xapi: [debug||17998 |SR.scan D:91a013d358e8|sm] SM nfs sr_scan sr=OpaqueRef:cab6d499-a2af-f407-b5d7-cc5106101c59 Jul 11 10:41:47 hst100 xapi: [ info||17998 |sm_exec D:70bcac641a6a|xapi_session] Session.create trackid=c04e3737f472c63e8250fab8a79f53ff pool=false uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Jul 11 10:41:47 hst100 xapi: [ info||18000 |OpaqueRef:08bcdeea-9fb1-3d0b-4d96-335db5a0c2a4|Storage_smapiv1_wrapper] SR.scan2 dbg:OpaqueRef:08bcdeea-9fb1-3d0b-4d96-335db5a0c2a4 sr:d0140e93-71fe-9b11-4e5a-d80ce8102870 Jul 11 10:41:47 hst100 xapi: [debug||18000 |OpaqueRef:08bcdeea-9fb1-3d0b-4d96-335db5a0c2a4|dummytaskhelper] task SR.scan D:699f208e1dc1 created by task R:08bcdeea9fb1 Jul 11 10:41:47 hst100 xapi: [debug||18000 |SR.scan D:699f208e1dc1|sm] SM iso sr_scan sr=OpaqueRef:3e473288-a1f8-f0bb-80d7-3baa0ee0628b Jul 11 10:41:47 hst100 xapi: [ info||18000 |sm_exec D:fab90060eebd|xapi_session] Session.create trackid=e0bfbc800696ff3374cdf776a5151a63 pool=false uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Jul 11 10:41:47 hst100 xapi: [debug||17999 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:pool.get_all D:5fa86e462ac9 created by task D:70bcac641a6a Jul 11 10:41:47 hst100 xapi: [debug||18001 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:pool.get_all D:2f47ed86fffe created by task D:fab90060eebd Jul 11 10:41:48 hst100 xapi: [ info||18000 |sm_exec D:fab90060eebd|xapi_session] Session.destroy trackid=e0bfbc800696ff3374cdf776a5151a63 Jul 11 10:41:48 hst100 xapi: [debug||18000 |OpaqueRef:08bcdeea-9fb1-3d0b-4d96-335db5a0c2a4|dummytaskhelper] task SR.stat D:a0f54d83143c created by task R:08bcdeea9fb1 Jul 11 10:41:48 hst100 xapi: [debug||18000 |SR.stat D:a0f54d83143c|sm] SM iso sr_update sr=OpaqueRef:3e473288-a1f8-f0bb-80d7-3baa0ee0628b Jul 11 10:41:48 hst100 xapi: [ info||18000 |sm_exec D:c353bb85679c|xapi_session] Session.create trackid=b469a692ddbdb291cc6937d3eee4e2a9 pool=false uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Jul 11 10:41:48 hst100 xapi: [debug||18004 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:pool.get_all D:f84a14cc6b90 created by task D:c353bb85679c Jul 11 10:41:48 hst100 xapi: [ info||18000 |sm_exec D:c353bb85679c|xapi_session] Session.destroy trackid=b469a692ddbdb291cc6937d3eee4e2a9 Jul 11 10:41:48 hst100 xapi: [debug||17997 /var/lib/xcp/xapi|SR.scan R:08bcdeea9fb1|xapi_sr] Xapi_sr.scan.(fun).scan_rec no change detected, updating VDIs Jul 11 10:41:48 hst100 xapi: [debug||17997 /var/lib/xcp/xapi|SR.scan R:08bcdeea9fb1|message_forwarding] Unmarking SR after SR.scan (task=OpaqueRef:08bcdeea-9fb1-3d0b-4d96-335db5a0c2a4) Jul 11 10:41:48 hst100 xapi: [debug||18006 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:session.logout D:ca51b0c3f90e created by task D:7d4bfe2b75fa Jul 11 10:41:48 hst100 xapi: [ info||18006 /var/lib/xcp/xapi|session.logout D:fa1f5fa07905|xapi_session] Session.destroy trackid=2f7776a5c3a2cce90ffe012a98075090 Jul 11 10:41:48 hst100 xapi: [debug||17991 |scan one D:7d4bfe2b75fa|xapi_sr] Scan of SR d0140e93-71fe-9b11-4e5a-d80ce8102870 complete. Jul 11 10:41:48 hst100 xcp-rrdd: [ info||9 ||rrdd_main] memfree has changed to 572992 in domain 7 Jul 11 10:41:48 hst100 xenopsd-xc: [debug||6 |events|xenops_server] Received an event on managed VM dcb7847c-e7c3-01a2-67a4-35d0d875e6e2 Jul 11 10:41:48 hst100 xenopsd-xc: [debug||6 |queue|xenops_server] Queue.push ["VM_check_state","dcb7847c-e7c3-01a2-67a4-35d0d875e6e2"] onto dcb7847c-e7c3-01a2-67a4-35d0d875e6e2:[ ] Jul 11 10:41:48 hst100 squeezed: [debug||4 ||squeeze_xen] watch /data/updated <- Fri Jul 11 10:42:27 2025 Jul 11 10:41:48 hst100 xenopsd-xc: [debug||40 ||xenops_server] Queue.pop returned ["VM_check_state","dcb7847c-e7c3-01a2-67a4-35d0d875e6e2"] Jul 11 10:41:48 hst100 xenopsd-xc: [debug||40 |events|xenops_server] Task 1418 reference events: ["VM_check_state","dcb7847c-e7c3-01a2-67a4-35d0d875e6e2"] Jul 11 10:41:48 hst100 xenopsd-xc: [debug||40 |events|xenops_server] VM dcb7847c-e7c3-01a2-67a4-35d0d875e6e2 is not requesting any attention Jul 11 10:41:48 hst100 xenopsd-xc: [debug||40 |events|xenops_server] VM_DB.signal dcb7847c-e7c3-01a2-67a4-35d0d875e6e2 Jul 11 10:41:48 hst100 xenopsd-xc: [debug||40 |events|task_server] Task 1418 completed; duration = 0 Jul 11 10:41:48 hst100 xenopsd-xc: [debug||40 ||xenops_server] TASK.signal 1418 (object deleted) Jul 11 10:41:48 hst100 xapi: [debug||148 |org.xen.xapi.xenops.classic events D:14adfb57e17b|xenops] Processing event: ["Vm","dcb7847c-e7c3-01a2-67a4-35d0d875e6e2"] Jul 11 10:41:48 hst100 xapi: [debug||148 |org.xen.xapi.xenops.classic events D:14adfb57e17b|xenops] xenops event on VM dcb7847c-e7c3-01a2-67a4-35d0d875e6e2 Jul 11 10:41:48 hst100 xenopsd-xc: [debug||2935 |org.xen.xapi.xenops.classic events D:14adfb57e17b|xenops_server] VM.stat dcb7847c-e7c3-01a2-67a4-35d0d875e6e2 Jul 11 10:41:48 hst100 xapi: [debug||148 |org.xen.xapi.xenops.classic events D:14adfb57e17b|xenops] xenopsd event: processing event for VM dcb7847c-e7c3-01a2-67a4-35d0d875e6e2 Jul 11 10:41:48 hst100 xapi: [debug||148 |org.xen.xapi.xenops.classic events D:14adfb57e17b|xenops] Supressing VM.allowed_operations update because guest_agent data is largely the same Jul 11 10:41:48 hst100 xapi: [debug||148 |org.xen.xapi.xenops.classic events D:14adfb57e17b|xenops] xenopsd event: Updating VM dcb7847c-e7c3-01a2-67a4-35d0d875e6e2 domid 7 guest_agent Jul 11 10:41:50 hst100 xapi: [debug||18007 HTTPS 51.161.213.26->:::80|host.call_plugin R:257d771f7575|audit] Host.call_plugin host = 'cb2ae4d4-6ed4-4790-8739-3cf0c2940c99 (hst100)'; plugin = 'updater.py'; fn = 'check_update' args = [ 'hidden' ] Jul 11 10:41:51 hst100 xapi: [debug||3138 HTTPS 67.219.99.188->:::80|event.from D:98aa8880a8c9|xapi_event] suppressing empty event.from Jul 11 10:41:52 hst100 xapi: [debug||175 |xapi events D:520281ee7232|dummytaskhelper] task timeboxed_rpc D:41df3c81c2c6 created by task D:520281ee7232 Jul 11 10:41:52 hst100 xapi: [debug||18008 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:event.from D:608fbb40b816 created by task D:520281ee7232 Jul 11 10:41:52 hst100 xapi: [debug||18009 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:session.logout D:a31c91185b23 created by task D:52b88ea71bd5 Jul 11 10:41:52 hst100 xapi: [ info||18009 /var/lib/xcp/xapi|session.logout D:1aee21f5a80d|xapi_session] Session.destroy trackid=50452fd8d8f3a62f62cad67fa30b24f1 Jul 11 10:41:52 hst100 xapi: [debug||18010 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:session.slave_login D:1de1795837e0 created by task D:52b88ea71bd5 Jul 11 10:41:52 hst100 xapi: [ info||18010 /var/lib/xcp/xapi|session.slave_login D:19fcc3b48c90|xapi_session] Session.create trackid=a13373689bd852f3693510a9856128f2 pool=true uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Jul 11 10:41:52 hst100 xapi: [debug||18011 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:pool.get_all D:e6855e017e42 created by task D:19fcc3b48c90 Jul 11 10:41:52 hst100 xapi: [debug||18012 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:event.from D:25ad6ad641aa created by task D:52b88ea71bd5 Jul 11 10:41:52 hst100 xapi: [ info||17998 |sm_exec D:70bcac641a6a|xapi_session] Session.destroy trackid=c04e3737f472c63e8250fab8a79f53ff Jul 11 10:41:52 hst100 xapi: [debug||17998 |OpaqueRef:06b4b7bb-8db2-67e6-ce2b-fc190d089f17|dummytaskhelper] task SR.stat D:591a6d7dfd4c created by task R:06b4b7bb8db2 Jul 11 10:41:52 hst100 xapi: [debug||17998 |SR.stat D:591a6d7dfd4c|sm] SM nfs sr_update sr=OpaqueRef:cab6d499-a2af-f407-b5d7-cc5106101c59 Jul 11 10:41:52 hst100 xapi: [ info||17998 |sm_exec D:90c6faeac33e|xapi_session] Session.create trackid=a5f3768a01c1a5591ff28ae0c084c1e6 pool=false uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Jul 11 10:41:52 hst100 xapi: [debug||18013 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:pool.get_all D:43b797d7e11e created by task D:90c6faeac33e Jul 11 10:41:52 hst100 xapi: [ info||18014 /var/lib/xcp/xapi|session.login_with_password D:66f31b75e9ba|xapi_session] Session.create trackid=e89374827e41fe370399494057e73e05 pool=false uname=root originator=SM is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Jul 11 10:41:52 hst100 xapi: [debug||18015 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:pool.get_all D:dcfefe59018c created by task D:66f31b75e9ba Jul 11 10:41:52 hst100 xapi: [ info||18014 /var/lib/xcp/xapi|session.logout D:1229724ea671|xapi_session] Session.destroy trackid=e89374827e41fe370399494057e73e05 Jul 11 10:41:52 hst100 xapi: [ info||18017 /var/lib/xcp/xapi|session.login_with_password D:93780a0651d7|xapi_session] Session.create trackid=0be0df15d648322d6b569474255ed645 pool=false uname=root originator=SM is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49 Jul 11 10:41:52 hst100 xapi: [debug||18018 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:pool.get_all D:b6549a355f02 created by task D:93780a0651d7 Jul 11 10:41:54 hst100 xapi: [ info||17998 |sm_exec D:90c6faeac33e|xapi_session] Session.destroy trackid=a5f3768a01c1a5591ff28ae0c084c1e6 Jul 11 10:41:54 hst100 xapi: [debug||17996 /var/lib/xcp/xapi|SR.scan R:06b4b7bb8db2|xapi_sr] Xapi_sr.scan.(fun).scan_rec no change detected, updating VDIs Jul 11 10:41:54 hst100 xapi: [debug||17996 /var/lib/xcp/xapi|SR.scan R:06b4b7bb8db2|message_forwarding] Unmarking SR after SR.scan (task=OpaqueRef:06b4b7bb-8db2-67e6-ce2b-fc190d089f17) Jul 11 10:41:54 hst100 xapi: [debug||18019 /var/lib/xcp/xapi|post_root|dummytaskhelper] task dispatch:session.logout D:dd3305158779 created by task D:f280daf4394a Jul 11 10:41:54 hst100 xapi: [ info||18019 /var/lib/xcp/xapi|session.logout D:4dd639657798|xapi_session] Session.destroy trackid=aeaa0692cf6b9ee21b44fba5b9a33cc6 Jul 11 10:41:54 hst100 xapi: [debug||17990 |scan one D:f280daf4394a|xapi_sr] Scan of SR d4b22411-592f-7ada-0597-68dbcb56ee4d complete. -
Jul 11 10:33:59 hst100 cleanup.py[132827]: All output goes to log Jul 11 10:33:59 hst100 systemd[1]: Started Garbage Collector for SR d4b22411-592f-7ada-0597-68dbcb56ee4d. Jul 11 10:34:12 hst100 forkexecd: [error||0 ||forkexecd] 133009 (/opt/xensource/libexec/mail-alarm <?xml version="1.0" encoding="UTF-8"?>\x0A<message><ref>OpaqueRef:80e8cac6-789a-8d76-70b6-afe1551f8de2</ref><name>ALARM</name><priority>3</priority><cls>VM</cls><obj_uuid>1b298dd8-5921-4090-8ac9-f26efbaf88b3</obj_uuid><timestamp>20250711T00:34:12Z</timestamp><uuid>d2844e9b-f88c-bf7e-5456-610060fcb05b</uuid><body>value: 1.000000\x0Aconfig:\x0A<variable>\x0A\x09<name value="fs_usage"/>\x0A\x09<alarm_trigger_level value="0.9"/>\x0A\x09<alarm_trigger_period value="60"/>\x0A\x09<alarm_auto_inhibit_period value="3600"/>\x0A</variable>\x0A</body></message>) exited with code 1 Jul 11 10:34:22 hst100 systemd[1]: Starting Garbage Collector for SR d4b22411-592f-7ada-0597-68dbcb56ee4d... Jul 11 10:34:28 hst100 cleanup.py[133122]: All output goes to log Jul 11 10:34:28 hst100 systemd[1]: Started Garbage Collector for SR d4b22411-592f-7ada-0597-68dbcb56ee4d. Jul 11 10:34:38 hst100 sparse_dd: [debug||0 ||sparse_dd] progress 10% Jul 11 10:34:44 hst100 qemu-dm-5[22780]: 22780@1752194084.964567:xen_platform_log xen platform: xeniface|IoctlLog: USER: OnSessionChange(SessionLock, 2) Jul 11 10:34:47 hst100 qemu-dm-5[22780]: 22780@1752194087.641201:xen_platform_log xen platform: xen|ModuleAdd: FFFFF80333BF0000 - FFFFF80333C00FFF [mskssrv.sys] Jul 11 10:34:47 hst100 qemu-dm-5[22780]: 22780@1752194087.642844:xen_platform_log xen platform: xen|ModuleAdd: FFFFF80333C10000 - FFFFF80333C20FFF [ksthunk.sys] Jul 11 10:34:52 hst100 systemd[1]: Starting Garbage Collector for SR d4b22411-592f-7ada-0597-68dbcb56ee4d... Jul 11 10:34:59 hst100 cleanup.py[133367]: All output goes to log Jul 11 10:34:59 hst100 systemd[1]: Started Garbage Collector for SR d4b22411-592f-7ada-0597-68dbcb56ee4d. Jul 11 10:35:23 hst100 systemd[1]: Starting Garbage Collector for SR d4b22411-592f-7ada-0597-68dbcb56ee4d... Jul 11 10:35:29 hst100 cleanup.py[133646]: All output goes to log Jul 11 10:35:29 hst100 systemd[1]: Started Garbage Collector for SR d4b22411-592f-7ada-0597-68dbcb56ee4d. Jul 11 10:35:52 hst100 systemd[1]: Starting Garbage Collector for SR d4b22411-592f-7ada-0597-68dbcb56ee4d... Jul 11 10:35:59 hst100 cleanup.py[133908]: All output goes to log Jul 11 10:35:59 hst100 systemd[1]: Started Garbage Collector for SR d4b22411-592f-7ada-0597-68dbcb56ee4d. Jul 11 10:36:22 hst100 systemd[1]: Starting Garbage Collector for SR d4b22411-592f-7ada-0597-68dbcb56ee4d... Jul 11 10:36:29 hst100 cleanup.py[134206]: All output goes to log Jul 11 10:36:29 hst100 systemd[1]: Started Garbage Collector for SR d4b22411-592f-7ada-0597-68dbcb56ee4d. Jul 11 10:36:52 hst100 systemd[1]: Starting Garbage Collector for SR d4b22411-592f-7ada-0597-68dbcb56ee4d... Jul 11 10:36:59 hst100 cleanup.py[134483]: All output goes to log Jul 11 10:36:59 hst100 systemd[1]: Started Garbage Collector for SR d4b22411-592f-7ada-0597-68dbcb56ee4d. Jul 11 10:37:23 hst100 systemd[1]: Starting Garbage Collector for SR d4b22411-592f-7ada-0597-68dbcb56ee4d... Jul 11 10:37:29 hst100 cleanup.py[134766]: All output goes to log Jul 11 10:37:29 hst100 systemd[1]: Started Garbage Collector for SR d4b22411-592f-7ada-0597-68dbcb56ee4d. Jul 11 10:37:52 hst100 systemd[1]: Starting Garbage Collector for SR d4b22411-592f-7ada-0597-68dbcb56ee4d... Jul 11 10:37:59 hst100 cleanup.py[135061]: All output goes to log Jul 11 10:37:59 hst100 systemd[1]: Started Garbage Collector for SR d4b22411-592f-7ada-0597-68dbcb56ee4d. Jul 11 10:38:22 hst100 systemd[1]: Starting Garbage Collector for SR d4b22411-592f-7ada-0597-68dbcb56ee4d... Jul 11 10:38:29 hst100 cleanup.py[135334]: All output goes to log Jul 11 10:38:29 hst100 systemd[1]: Started Garbage Collector for SR d4b22411-592f-7ada-0597-68dbcb56ee4d. Jul 11 10:38:52 hst100 systemd[1]: Starting Garbage Collector for SR d4b22411-592f-7ada-0597-68dbcb56ee4d... Jul 11 10:38:58 hst100 cleanup.py[135655]: All output goes to log Jul 11 10:38:58 hst100 systemd[1]: Started Garbage Collector for SR d4b22411-592f-7ada-0597-68dbcb56ee4d. Jul 11 10:39:22 hst100 systemd[1]: Starting Garbage Collector for SR d4b22411-592f-7ada-0597-68dbcb56ee4d... Jul 11 10:39:29 hst100 cleanup.py[135953]: All output goes to log Jul 11 10:39:29 hst100 systemd[1]: Started Garbage Collector for SR d4b22411-592f-7ada-0597-68dbcb56ee4d. Jul 11 10:39:52 hst100 systemd[1]: Starting Garbage Collector for SR d4b22411-592f-7ada-0597-68dbcb56ee4d... Jul 11 10:39:59 hst100 cleanup.py[136246]: All output goes to log Jul 11 10:39:59 hst100 systemd[1]: Started Garbage Collector for SR d4b22411-592f-7ada-0597-68dbcb56ee4d. Jul 11 10:40:01 hst100 systemd[1]: Started Session c43 of user root. Jul 11 10:40:01 hst100 systemd[1]: Starting Session c43 of user root. Jul 11 10:40:22 hst100 tapdisk[33072]: received 'close' message (uuid = 10) Jul 11 10:40:22 hst100 tapdisk[33072]: nbd: NBD server pause(0x16b09f0) Jul 11 10:40:22 hst100 tapdisk[33072]: nbd: NBD server pause(0x16c8810) Jul 11 10:40:22 hst100 tapdisk[33072]: nbd: NBD server free(0x16b09f0) Jul 11 10:40:22 hst100 tapdisk[33072]: nbd: NBD server free(0x16c8810) Jul 11 10:40:22 hst100 tapdisk[33072]: gaps written/skipped: 0/0 Jul 11 10:40:22 hst100 tapdisk[33072]: /var/run/sr-mount/ff9dc099-c34f-d3ac-3ac4-19ed74480a4b/310dc526-765c-455c-848d-610bb7ae6cd1.vhd: b: 102400, a: 102279, f: 102279, n: 419753840 Jul 11 10:40:22 hst100 tapdisk[33072]: closed image /var/run/sr-mount/ff9dc099-c34f-d3ac-3ac4-19ed74480a4b/310dc526-765c-455c-848d-610bb7ae6cd1.vhd (0 users, state: 0x00000000, type: 4) Jul 11 10:40:22 hst100 tapdisk[33072]: sending 'close response' message (uuid = 10) Jul 11 10:40:22 hst100 tapdisk[33072]: received 'detach' message (uuid = 10) Jul 11 10:40:22 hst100 tapdisk[33072]: sending 'detach response' message (uuid = 10) Jul 11 10:40:22 hst100 tapdisk[33072]: tapdisk-log: closing after 0 errors Jul 11 10:40:22 hst100 tapdisk[33072]: tapdisk-syslog: 22 messages, 1932 bytes, xmits: 23, failed: 0, dropped: 0 Jul 11 10:40:22 hst100 tapdisk[33072]: tapdisk-control: draining 1 connections Jul 11 10:40:22 hst100 tapdisk[33072]: tapdisk-control: done Jul 11 10:40:22 hst100 systemd[1]: Starting Garbage Collector for SR d4b22411-592f-7ada-0597-68dbcb56ee4d... Jul 11 10:40:29 hst100 cleanup.py[136554]: All output goes to log Jul 11 10:40:29 hst100 systemd[1]: Started Garbage Collector for SR d4b22411-592f-7ada-0597-68dbcb56ee4d. Jul 11 10:40:52 hst100 xenguest-13-build[136890]: Command line: -controloutfd 8 -controlinfd 9 -mode hvm_build -image /usr/libexec/xen/boot/hvmloader -domid 13 -store_port 5 -store_domid 0 -console_port 6 -console_domid 0 -mem_max_mib 8184 -mem_start_mib 8184 Jul 11 10:40:52 hst100 xenguest-13-build[136890]: Domain Properties: Type HVM, hap 1 Jul 11 10:40:52 hst100 xenguest-13-build[136890]: Determined the following parameters from xenstore: Jul 11 10:40:52 hst100 xenguest-13-build[136890]: vcpu/number:4 vcpu/weight:256 vcpu/cap:0 Jul 11 10:40:52 hst100 xenguest-13-build[136890]: nx: 1, pae 1, cores-per-socket 4, x86-fip-width 0, nested 0 Jul 11 10:40:52 hst100 xenguest-13-build[136890]: apic: 1 acpi: 1 acpi_s4: 0 acpi_s3: 0 tsc_mode: 0 hpet: 1 Jul 11 10:40:52 hst100 xenguest-13-build[136890]: nomigrate 0, timeoffset 36000 mmio_hole_size 0 Jul 11 10:40:52 hst100 xenguest-13-build[136890]: viridian: 1, time_ref_count: 1, reference_tsc: 1 hcall_remote_tlb_flush: 0 apic_assist: 1 crash_ctl: 1 stimer: 1 hcall_ipi: 0 Jul 11 10:40:52 hst100 xenguest-13-build[136890]: vcpu/0/affinity:111111111111 Jul 11 10:40:52 hst100 xenguest-13-build[136890]: vcpu/1/affinity:111111111111 Jul 11 10:40:52 hst100 xenguest-13-build[136890]: vcpu/2/affinity:111111111111 Jul 11 10:40:52 hst100 xenguest-13-build[136890]: vcpu/3/affinity:111111111111 Jul 11 10:40:52 hst100 xenguest-13-build[136890]: domainbuilder: detail: xc_dom_allocate: cmdline="", features="" Jul 11 10:40:52 hst100 xenguest-13-build[136890]: domainbuilder: detail: xc_dom_kernel_file: filename="/usr/libexec/xen/boot/hvmloader" Jul 11 10:40:52 hst100 xenguest-13-build[136890]: domainbuilder: detail: xc_dom_malloc_filemap : 629 kB Jul 11 10:40:52 hst100 xenguest-13-build[136890]: domainbuilder: detail: xc_dom_module_file: filename="/usr/share/ipxe/ipxe.bin" Jul 11 10:40:52 hst100 xenguest-13-build[136890]: domainbuilder: detail: xc_dom_malloc_filemap : 132 kB Jul 11 10:40:52 hst100 xenguest-13-build[136890]: domainbuilder: detail: xc_dom_boot_xen_init: ver 4.17, caps xen-3.0-x86_64 hvm-3.0-x86_32 hvm-3.0-x86_32p hvm-3.0-x86_64 Jul 11 10:40:52 hst100 xenguest-13-build[136890]: domainbuilder: detail: xc_dom_parse_image: called Jul 11 10:40:52 hst100 xenguest-13-build[136890]: domainbuilder: detail: xc_dom_find_loader: trying multiboot-binary loader ... Jul 11 10:40:52 hst100 xenguest-13-build[136890]: domainbuilder: detail: loader probe failed Jul 11 10:40:52 hst100 xenguest-13-build[136890]: domainbuilder: detail: xc_dom_find_loader: trying HVM-generic loader ... Jul 11 10:40:52 hst100 xenguest-13-build[136890]: domainbuilder: detail: loader probe OK Jul 11 10:40:52 hst100 xenguest-13-build[136890]: xc: detail: ELF: phdr: paddr=0x100000 memsz=0x57ac4 Jul 11 10:40:52 hst100 xenguest-13-build[136890]: xc: detail: ELF: memory: 0x100000 -> 0x157ac4 Jul 11 10:40:52 hst100 xenguest-13-build[136890]: domainbuilder: detail: xc_dom_compat_check: supported guest type: xen-3.0-x86_64 Jul 11 10:40:52 hst100 xenguest-13-build[136890]: domainbuilder: detail: xc_dom_compat_check: supported guest type: hvm-3.0-x86_32 <= matches Jul 11 10:40:52 hst100 xenguest-13-build[136890]: domainbuilder: detail: xc_dom_compat_check: supported guest type: hvm-3.0-x86_32p Jul 11 10:40:52 hst100 xenguest-13-build[136890]: domainbuilder: detail: xc_dom_compat_check: supported guest type: hvm-3.0-x86_64 Jul 11 10:40:52 hst100 xenguest-13-build[136890]: Calculated provisional MMIO hole size as 0x10000000 Jul 11 10:40:52 hst100 xenguest-13-build[136890]: Loaded OVMF from /usr/share/edk2/OVMF-release.fd Jul 11 10:40:52 hst100 xenguest-13-build[136890]: domainbuilder: detail: xc_dom_mem_init: mem 8184 MB, pages 0x1ff800 pages, 4k each Jul 11 10:40:52 hst100 xenguest-13-build[136890]: domainbuilder: detail: xc_dom_mem_init: 0x1ff800 pages Jul 11 10:40:52 hst100 xenguest-13-build[136890]: domainbuilder: detail: xc_dom_boot_mem_init: called Jul 11 10:40:52 hst100 xenguest-13-build[136890]: domainbuilder: detail: range: start=0x0 end=0xf0000000 Jul 11 10:40:52 hst100 xenguest-13-build[136890]: domainbuilder: detail: range: start=0x100000000 end=0x20f800000 Jul 11 10:40:52 hst100 xenguest-13-build[136890]: xc: detail: PHYSICAL MEMORY ALLOCATION: Jul 11 10:40:52 hst100 xenguest-13-build[136890]: xc: detail: 4KB PAGES: 0x0000000000000200 Jul 11 10:40:52 hst100 xenguest-13-build[136890]: xc: detail: 2MB PAGES: 0x00000000000003fb Jul 11 10:40:52 hst100 xenguest-13-build[136890]: xc: detail: 1GB PAGES: 0x0000000000000006 Jul 11 10:40:52 hst100 xenguest-13-build[136890]: Final lower MMIO hole size is 0x10000000 Jul 11 10:40:52 hst100 xenguest-13-build[136890]: domainbuilder: detail: xc_dom_build_image: called Jul 11 10:40:52 hst100 xenguest-13-build[136890]: domainbuilder: detail: xc_dom_pfn_to_ptr_retcount: domU mapping: pfn 0x100+0x58 at 0x7f47fc88a000 Jul 11 10:40:52 hst100 xenguest-13-build[136890]: domainbuilder: detail: xc_dom_alloc_segment: kernel : 0x100000 -> 0x157ac4 (pfn 0x100 + 0x58 pages) Jul 11 10:40:52 hst100 xenguest-13-build[136890]: xc: detail: ELF: phdr 0 at 0x7f47fac98000 -> 0x7f47face8ea0 Jul 11 10:40:52 hst100 xenguest-13-build[136890]: domainbuilder: detail: xc_dom_pfn_to_ptr_retcount: domU mapping: pfn 0x158+0x200 at 0x7f47faaf0000 Jul 11 10:40:52 hst100 xenguest-13-build[136890]: domainbuilder: detail: xc_dom_alloc_segment: System Firmware module : 0x158000 -> 0x358000 (pfn 0x158 + 0x200 pages) Jul 11 10:40:52 hst100 xenguest-13-build[136890]: domainbuilder: detail: xc_dom_pfn_to_ptr_retcount: domU mapping: pfn 0x358+0x22 at 0x7f47fc868000 Jul 11 10:40:52 hst100 xenguest-13-build[136890]: domainbuilder: detail: xc_dom_alloc_segment: module0 : 0x358000 -> 0x379200 (pfn 0x358 + 0x22 pages) Jul 11 10:40:52 hst100 xenguest-13-build[136890]: domainbuilder: detail: xc_dom_pfn_to_ptr_retcount: domU mapping: pfn 0x37a+0x1 at 0x7f47fca47000 Jul 11 10:40:52 hst100 xenguest-13-build[136890]: domainbuilder: detail: xc_dom_alloc_segment: HVM start info : 0x37a000 -> 0x37a878 (pfn 0x37a + 0x1 pages) Jul 11 10:40:52 hst100 xenguest-13-build[136890]: domainbuilder: detail: xc_dom_build_image : virt_alloc_end : 0x37b000 Jul 11 10:40:52 hst100 xenguest-13-build[136890]: domainbuilder: detail: xc_dom_build_image : virt_pgtab_end : 0x0 Jul 11 10:40:52 hst100 xenguest-13-build[136890]: domainbuilder: detail: xc_dom_boot_image: called Jul 11 10:40:52 hst100 xenguest-13-build[136890]: domainbuilder: detail: domain builder memory footprint Jul 11 10:40:52 hst100 xenguest-13-build[136890]: domainbuilder: detail: allocated Jul 11 10:40:52 hst100 xenguest-13-build[136890]: domainbuilder: detail: malloc : 18525 bytes Jul 11 10:40:52 hst100 xenguest-13-build[136890]: domainbuilder: detail: anon mmap : 0 bytes Jul 11 10:40:52 hst100 xenguest-13-build[136890]: domainbuilder: detail: mapped Jul 11 10:40:52 hst100 xenguest-13-build[136890]: domainbuilder: detail: file mmap : 762 kB Jul 11 10:40:52 hst100 xenguest-13-build[136890]: domainbuilder: detail: domU mmap : 2540 kB Jul 11 10:40:52 hst100 xenguest-13-build[136890]: domainbuilder: detail: Adding module 0 guest_addr 358000 len 135680 Jul 11 10:40:52 hst100 xenguest-13-build[136890]: domainbuilder: detail: vcpu_hvm: called Jul 11 10:40:52 hst100 xenguest-13-build[136890]: domainbuilder: detail: xc_dom_set_gnttab_entry: d13 gnt[0] -> d0 0xfefff Jul 11 10:40:52 hst100 xenguest-13-build[136890]: domainbuilder: detail: xc_dom_set_gnttab_entry: d13 gnt[1] -> d0 0xfeffc Jul 11 10:40:52 hst100 xenguest-13-build[136890]: viridian base Jul 11 10:40:52 hst100 xenguest-13-build[136890]: + time_ref_count Jul 11 10:40:52 hst100 xenguest-13-build[136890]: + reference_tsc Jul 11 10:40:52 hst100 xenguest-13-build[136890]: + apic_assist Jul 11 10:40:52 hst100 xenguest-13-build[136890]: + crash_ctl Jul 11 10:40:52 hst100 xenguest-13-build[136890]: + stimer Jul 11 10:40:52 hst100 xenguest-13-build[136890]: Parsing '178bfbff-f6f83203-2e500800-040001f3-0000000f-f1bf07a9-00405f4e-00000000-711ed005-10000010-00000020-18000144-00000000-00000000-00000000-00000000-00000000-00000000-00000000-00000000-00000000-00000000' as featureset Jul 11 10:40:52 hst100 xenguest-13-build[136890]: domainbuilder: detail: xc_dom_release: called Jul 11 10:40:52 hst100 xenguest-13-build[136890]: Writing to control: 'result:1044476 1044479#012' Jul 11 10:40:52 hst100 xenguest-13-build[136890]: All done Jul 11 10:40:52 hst100 ovs-vsctl: ovs|00001|db_ctl_base|ERR|no row "vif13.0" in table Interface Jul 11 10:40:52 hst100 ovs-vsctl: ovs|00001|vsctl|INFO|Called as ovs-vsctl --timeout=30 -- --if-exists del-port vif13.0 Jul 11 10:40:52 hst100 ovs-vsctl: ovs|00001|vsctl|INFO|Called as ovs-vsctl --timeout=30 add-port xapi2 vif13.0 -- set interface vif13.0 "external-ids:\"xs-vm-uuid\"=\"16a5f8be-781c-46fe-df43-83744df32826\"" -- set interface vif13.0 "external-ids:\"xs-vif-uuid\"=\"a48873c0-17c9-8905-712e-72579245a342\"" -- set interface vif13.0 "external-ids:\"xs-network-uuid\"=\"1bfba311-a261-d329-d01d-ab2713d0dc78\"" -- set interface vif13.0 "external-ids:\"attached-mac\"=\"da:ff:e4:1f:38:61\"" Jul 11 10:40:53 hst100 systemd[1]: Starting Garbage Collector for SR d4b22411-592f-7ada-0597-68dbcb56ee4d... Jul 11 10:40:53 hst100 tapdisk[137103]: tapdisk-control: init, 10 x 4k buffers Jul 11 10:40:53 hst100 tapdisk[137103]: I/O queue driver: lio Jul 11 10:40:53 hst100 tapdisk[137103]: I/O queue driver: lio Jul 11 10:40:53 hst100 tapdisk[137103]: tapdisk-log: started, level 0 Jul 11 10:40:53 hst100 tapdisk[137103]: Tapdisk running, control on /var/run/blktap-control/ctl137103 Jul 11 10:40:53 hst100 tapdisk[137103]: nbd: Set up local unix domain socket on path '/var/run/blktap-control/nbdclient137103' Jul 11 10:40:53 hst100 tapdisk[137103]: received 'attach' message (uuid = 10) Jul 11 10:40:53 hst100 tapdisk[137103]: sending 'attach response' message (uuid = 10) Jul 11 10:40:53 hst100 tapdisk[137103]: received 'open' message (uuid = 10) Jul 11 10:40:53 hst100 tapdisk[137103]: /var/run/sr-mount/ff9dc099-c34f-d3ac-3ac4-19ed74480a4b/0d16619f-bcb7-47ea-9ecc-46159e4ff4ad.vhd version: tap 0x00010003, b: 51200, a: 21320, f: 21320, n: 87497696 Jul 11 10:40:53 hst100 tapdisk[137103]: opened image /var/run/sr-mount/ff9dc099-c34f-d3ac-3ac4-19ed74480a4b/0d16619f-bcb7-47ea-9ecc-46159e4ff4ad.vhd (1 users, state: 0x00000001, type: 4, rw) Jul 11 10:40:53 hst100 tapdisk[137103]: VBD CHAIN: Jul 11 10:40:53 hst100 tapdisk[137103]: /var/run/sr-mount/ff9dc099-c34f-d3ac-3ac4-19ed74480a4b/0d16619f-bcb7-47ea-9ecc-46159e4ff4ad.vhd: type:vhd(4) storage:ext(2) Jul 11 10:40:53 hst100 tapdisk[137103]: bdev: capacity=209715200 sector_size=512/512 flags=0 Jul 11 10:40:53 hst100 tapdisk[137103]: nbd: Set up local unix domain socket on path '/var/run/blktap-control/nbdserver137103.10' Jul 11 10:40:53 hst100 tapdisk[137103]: nbd: registering for unix_listening_fd Jul 11 10:40:53 hst100 tapdisk[137103]: nbd: Successfully started NBD server on /var/run/blktap-control/nbd-old137103.10 Jul 11 10:40:53 hst100 tapdisk[137103]: nbd: Set up local unix domain socket on path '/var/run/blktap-control/nbdserver-new137103.10' Jul 11 10:40:53 hst100 tapdisk[137103]: nbd: registering for unix_listening_fd Jul 11 10:40:53 hst100 tapdisk[137103]: nbd: Successfully started NBD server on /var/run/blktap-control/nbd137103.10 Jul 11 10:40:53 hst100 tapdisk[137103]: sending 'open response' message (uuid = 10) Jul 11 10:40:53 hst100 tapdisk[137114]: tapdisk-control: init, 10 x 4k buffers Jul 11 10:40:53 hst100 tapdisk[137114]: I/O queue driver: lio Jul 11 10:40:53 hst100 tapdisk[137114]: I/O queue driver: lio Jul 11 10:40:53 hst100 tapdisk[137114]: tapdisk-log: started, level 0 Jul 11 10:40:53 hst100 tapdisk[137114]: Tapdisk running, control on /var/run/blktap-control/ctl137114 Jul 11 10:40:53 hst100 tapdisk[137114]: nbd: Set up local unix domain socket on path '/var/run/blktap-control/nbdclient137114' Jul 11 10:40:53 hst100 tapdisk[137114]: received 'attach' message (uuid = 12) Jul 11 10:40:53 hst100 tapdisk[137114]: sending 'attach response' message (uuid = 12) Jul 11 10:40:53 hst100 tapdisk[137114]: received 'open' message (uuid = 12) Jul 11 10:40:53 hst100 tapdisk[137114]: /var/run/sr-mount/ff9dc099-c34f-d3ac-3ac4-19ed74480a4b/310dc526-765c-455c-848d-610bb7ae6cd1.vhd version: tap 0x00010003, b: 102400, a: 102279, f: 102279, n: 419753840 Jul 11 10:40:53 hst100 tapdisk[137114]: opened image /var/run/sr-mount/ff9dc099-c34f-d3ac-3ac4-19ed74480a4b/310dc526-765c-455c-848d-610bb7ae6cd1.vhd (1 users, state: 0x00000001, type: 4, rw) Jul 11 10:40:53 hst100 tapdisk[137114]: VBD CHAIN: Jul 11 10:40:53 hst100 tapdisk[137114]: /var/run/sr-mount/ff9dc099-c34f-d3ac-3ac4-19ed74480a4b/310dc526-765c-455c-848d-610bb7ae6cd1.vhd: type:vhd(4) storage:ext(2) Jul 11 10:40:53 hst100 tapdisk[137114]: bdev: capacity=419430400 sector_size=512/512 flags=0 Jul 11 10:40:53 hst100 tapdisk[137114]: nbd: Set up local unix domain socket on path '/var/run/blktap-control/nbdserver137114.12' Jul 11 10:40:53 hst100 tapdisk[137114]: nbd: registering for unix_listening_fd Jul 11 10:40:53 hst100 tapdisk[137114]: nbd: Successfully started NBD server on /var/run/blktap-control/nbd-old137114.12 Jul 11 10:40:53 hst100 tapdisk[137114]: nbd: Set up local unix domain socket on path '/var/run/blktap-control/nbdserver-new137114.12' Jul 11 10:40:53 hst100 tapdisk[137114]: nbd: registering for unix_listening_fd Jul 11 10:40:53 hst100 tapdisk[137114]: nbd: Successfully started NBD server on /var/run/blktap-control/nbd137114.12 Jul 11 10:40:53 hst100 tapdisk[137114]: sending 'open response' message (uuid = 12) Jul 11 10:40:53 hst100 tapback[137128]: tapback.c:445 slave tapback daemon started, only serving domain 13 Jul 11 10:40:53 hst100 tapback[137128]: backend.c:406 832 physical_device_changed Jul 11 10:40:53 hst100 tapback[137128]: backend.c:406 768 physical_device_changed Jul 11 10:40:53 hst100 tapback[137128]: backend.c:406 832 physical_device_changed Jul 11 10:40:53 hst100 tapback[137128]: backend.c:492 832 found tapdisk[137114], for 254:12 Jul 11 10:40:53 hst100 tapdisk[137114]: received 'disk info' message (uuid = 12) Jul 11 10:40:53 hst100 tapdisk[137114]: VBD 12 got disk info: sectors=419430400 sector size=512, info=0 Jul 11 10:40:53 hst100 tapdisk[137114]: sending 'disk info rsp' message (uuid = 12) Jul 11 10:40:53 hst100 tapback[137128]: backend.c:406 768 physical_device_changed Jul 11 10:40:53 hst100 tapback[137128]: backend.c:492 768 found tapdisk[137103], for 254:10 Jul 11 10:40:53 hst100 tapdisk[137103]: received 'disk info' message (uuid = 10) Jul 11 10:40:53 hst100 tapdisk[137103]: VBD 10 got disk info: sectors=209715200 sector size=512, info=0 Jul 11 10:40:53 hst100 tapdisk[137103]: sending 'disk info rsp' message (uuid = 10) Jul 11 10:40:53 hst100 systemd[1]: Started transient unit for varstored-13. Jul 11 10:40:53 hst100 systemd[1]: Starting transient unit for varstored-13... Jul 11 10:40:53 hst100 varstored-13[137207]: main: --domain = '13' Jul 11 10:40:53 hst100 varstored-13[137207]: main: --chroot = '/var/run/xen/varstored-root-13' Jul 11 10:40:53 hst100 varstored-13[137207]: main: --depriv = '(null)' Jul 11 10:40:53 hst100 varstored-13[137207]: main: --uid = '65548' Jul 11 10:40:53 hst100 varstored-13[137207]: main: --gid = '1004' Jul 11 10:40:53 hst100 varstored-13[137207]: main: --backend = 'xapidb' Jul 11 10:40:53 hst100 varstored-13[137207]: main: --arg = 'socket:/xapi-depriv-socket' Jul 11 10:40:53 hst100 varstored-13[137207]: main: --pidfile = '/var/run/xen/varstored-13.pid' Jul 11 10:40:53 hst100 varstored-13[137207]: main: --arg = 'uuid:16a5f8be-781c-46fe-df43-83744df32826' Jul 11 10:40:53 hst100 varstored-13[137207]: main: --arg = 'save:/efi-vars-save.dat' Jul 11 10:40:53 hst100 varstored-13[137207]: varstored_initialize: 4 vCPU(s) Jul 11 10:40:53 hst100 varstored-13[137207]: varstored_initialize: ioservid = 0 Jul 11 10:40:53 hst100 varstored-13[137207]: varstored_initialize: iopage = 0x7fe157ec9000 Jul 11 10:40:53 hst100 varstored-13[137207]: varstored_initialize: VCPU0: 7 -> 308 Jul 11 10:40:53 hst100 varstored-13[137207]: varstored_initialize: VCPU1: 8 -> 309 Jul 11 10:40:53 hst100 varstored-13[137207]: varstored_initialize: VCPU2: 9 -> 310 Jul 11 10:40:53 hst100 varstored-13[137207]: varstored_initialize: VCPU3: 10 -> 311 Jul 11 10:40:53 hst100 varstored-13[137207]: load_one_auth_data: Auth file '/var/lib/varstored/dbx.auth' is missing! Jul 11 10:40:53 hst100 varstored-13[137207]: load_one_auth_data: Auth file '/var/lib/varstored/db.auth' is missing! Jul 11 10:40:53 hst100 varstored-13[137207]: load_one_auth_data: Auth file '/var/lib/varstored/KEK.auth' is missing! Jul 11 10:40:53 hst100 varstored-13[137207]: initialize_settings: Secure boot enable: false Jul 11 10:40:53 hst100 varstored-13[137207]: initialize_settings: Authenticated variables: enforcing Jul 11 10:40:53 hst100 varstored-13[137207]: IO request not ready Jul 11 10:40:53 hst100 varstored-13[137207]: message repeated 3 times: [ IO request not ready] Jul 11 10:40:53 hst100 systemd[1]: Started transient unit for swtpm-13. Jul 11 10:40:53 hst100 systemd[1]: Starting transient unit for swtpm-13... Jul 11 10:40:53 hst100 swtpm-13[137230]: Arguments: 13 /var/lib/xcp/run/swtpm-root-13// unix+http://xapi-depriv-socket false Jul 11 10:40:53 hst100 swtpm-13[137230]: Binding socket to /var/lib/xcp/run/swtpm-root-13//swtpm-sock Jul 11 10:40:53 hst100 swtpm-13[137230]: Exec: /usr/bin/swtpm swtpm-13 socket --tpm2 --tpmstate backend-uri=unix+http://xapi-depriv-socket --ctrl type=unixio,fd=3 --log level=1 --pid file=/swtpm-13.pid -t --chroot /var/lib/xcp/run/swtpm-root-13// --runas 196621 Jul 11 10:40:53 hst100 swtpm-13[137230]: core dump limit: 67108864 Jul 11 10:40:53 hst100 swtpm-13[137230]: Could not write to pidfile : No space left on device Jul 11 10:40:53 hst100 ovs-vsctl: ovs|00001|db_ctl_base|ERR|no row "tap13.0" in table Interface Jul 11 10:40:53 hst100 ovs-vsctl: ovs|00001|vsctl|INFO|Called as ovs-vsctl --timeout=30 -- --if-exists del-port tap13.0 Jul 11 10:40:53 hst100 ovs-vsctl: ovs|00001|vsctl|INFO|Called as ovs-vsctl --timeout=30 add-port xapi2 tap13.0 -- set interface tap13.0 "external-ids:\"xs-vm-uuid\"=\"16a5f8be-781c-46fe-df43-83744df32826\"" -- set interface tap13.0 "external-ids:\"xs-vif-uuid\"=\"a48873c0-17c9-8905-712e-72579245a342\"" -- set interface tap13.0 "external-ids:\"xs-network-uuid\"=\"1bfba311-a261-d329-d01d-ab2713d0dc78\"" -- set interface tap13.0 "external-ids:\"attached-mac\"=\"da:ff:e4:1f:38:61\"" Jul 11 10:40:53 hst100 systemd[1]: swtpm-13.service: main process exited, code=exited, status=1/FAILURE Jul 11 10:40:53 hst100 systemd[1]: Unit swtpm-13.service entered failed state. Jul 11 10:40:53 hst100 systemd[1]: swtpm-13.service failed. Jul 11 10:40:53 hst100 forkexecd: [ info||0 ||forkexecd] qemu-dm-13[137252]: Arguments: 13 --syslog -chardev socket,id=chrtpm,path=/var/lib/xcp/run/swtpm-root-13/swtpm-sock -tpmdev emulator,id=tpm0,chardev=chrtpm -device tpm-crb,tpmdev=tpm0 -std-vga -videoram 8 -vnc unix:/var/run/xen/vnc-13,lock-key-sync=off -acpi -monitor null -pidfile /var/run/xen/qemu-dm-13.pid -xen-domid 13 -m size=8184 -boot order=dc -usb -device usb-tablet,port=2 -smp 4,maxcpus=4 -serial pty -display none -nodefaults -trace enable=xen_platform_log -sandbox on,obsolete=deny,elevateprivileges=allow,spawn=deny,resourcecontrol=deny -S -parallel null -qmp unix:/var/run/xen/qmp-libxl-13,server,nowait -qmp unix:/var/run/xen/qmp-event-13,server,nowait -device xen-platform,addr=3,device-id=0x0002 -device nvme,serial=nvme0,id=nvme0,addr=7 -drive id=disk0,if=none,file=/dev/sm/backend/ff9dc099-c34f-d3ac-3ac4-19ed74480a4b/0d16619f-bcb7-47ea-9ecc-46159e4ff4ad,media=disk,auto-read-only=off,format=raw -device nvme-ns,drive=disk0,bus=nvme0,nsid=1 -drive id=disk1,if=none,file=/dev/sm/backend/ff9dc099-c34f-d3ac-3ac4-19ed74480a4b/310dc526-765c-455c-848d-610bb7ae6cd1,media=disk,auto-read-only=off,format=raw -device nvme-ns,drive=disk1,bus=nvme0,nsid=2 -device e1000,netdev=tapnet0,mac=da:ff:e4:1f:38:61,addr=4,rombar=0 -netdev tap,id=tapnet0,fd=8 Jul 11 10:40:53 hst100 forkexecd: [ info||0 ||forkexecd] qemu-dm-13[137252]: Exec: /usr/lib64/xen/bin/qemu-system-i386 qemu-dm-13 -machine pc-i440fx-2.10,accel=xen,max-ram-below-4g=4026531840,suppress-vmdesc=on,allow-unassigned=true,trad_compat=False -chardev socket,id=chrtpm,path=/var/lib/xcp/run/swtpm-root-13/swtpm-sock -tpmdev emulator,id=tpm0,chardev=chrtpm -device tpm-crb,tpmdev=tpm0 -vnc unix:/var/run/xen/vnc-13,lock-key-sync=off -monitor null -pidfile /var/run/xen/qemu-dm-13.pid -xen-domid 13 -m size=8184 -boot order=dc -usb -device usb-tablet,port=2 -smp 4,maxcpus=4 -serial pty -display none -nodefaults -trace enable=xen_platform_log -sandbox on,obsolete=deny,elevateprivileges=allow,spawn=deny,resourcecontrol=deny -S -parallel null -qmp unix:/var/run/xen/qmp-libxl-13,server,nowait -qmp unix:/var/run/xen/qmp-event-13,server,nowait -device xen-platform,addr=3,device-id=0x0002 -device nvme,serial=nvme0,id=nvme0,addr=7 -drive id=disk0,if=none,file=/dev/sm/backend/ff9dc099-c34f-d3ac-3ac4-19ed74480a4b/0d16619f-bcb7-47ea-9ecc-46159e4ff4ad,media=disk,auto-read-only=off,format=raw -device nvme-ns,drive=disk0,bus=nvme0,nsid=1 -drive id=disk1,if=none,file=/dev/sm/backend/ff9dc099-c34f-d3ac-3ac4-19ed74480a4b/310dc526-765c-455c-848d-610bb7ae6cd1,media=disk,auto-read-only=off,format=raw -device nvme-ns,drive=disk1,bus=nvme0,nsid=2 -device e1000,netdev=tapnet0,mac=da:ff:e4:1f:38:61,addr=4,rombar=0 -netdev tap,id=tapnet0,fd=8 -device VGA,vgamem_mb=8,addr=2,romfile= -vnc-clipboard-socket-fd 4 -chardev stdio,id=ovmf -device isa-debugcon,chardev=ovmf,iobase=0x402 -xen-domid-restrict -chroot /var/xen/qemu/root-13 -runas 65548:1004 Jul 11 10:40:53 hst100 qemu-dm-13[137268]: Moving to cgroup slice 'vm.slice' Jul 11 10:40:53 hst100 qemu-dm-13[137268]: core dump limit: 67108864 Jul 11 10:40:53 hst100 qemu-dm-13[137268]: qemu-dm-13: -chardev socket,id=chrtpm,path=/var/lib/xcp/run/swtpm-root-13/swtpm-sock: Failed to connect socket /var/lib/xcp/run/swtpm-root-13/swtpm-sock: Connection refused Jul 11 10:40:53 hst100 /opt/xensource/libexec/xcp-clipboardd[137266]: poll failed because revents=0x11 (qemu socket) Jul 11 10:40:59 hst100 cleanup.py[137060]: All output goes to log Jul 11 10:40:59 hst100 systemd[1]: Started Garbage Collector for SR d4b22411-592f-7ada-0597-68dbcb56ee4d. Jul 11 10:41:22 hst100 systemd[1]: Starting Garbage Collector for SR d4b22411-592f-7ada-0597-68dbcb56ee4d... Jul 11 10:41:29 hst100 cleanup.py[137582]: All output goes to log Jul 11 10:41:29 hst100 systemd[1]: Started Garbage Collector for SR d4b22411-592f-7ada-0597-68dbcb56ee4d. Jul 11 10:41:52 hst100 systemd[1]: Starting Garbage Collector for SR d4b22411-592f-7ada-0597-68dbcb56ee4d... Jul 11 10:41:59 hst100 cleanup.py[137875]: All output goes to log Jul 11 10:41:59 hst100 systemd[1]: Started Garbage Collector for SR d4b22411-592f-7ada-0597-68dbcb56ee4d. Jul 11 10:42:22 hst100 systemd[1]: Starting Garbage Collector for SR d4b22411-592f-7ada-0597-68dbcb56ee4d... Jul 11 10:42:23 hst100 sparse_dd: [debug||0 ||sparse_dd] progress 20% Jul 11 10:42:29 hst100 cleanup.py[138151]: All output goes to log Jul 11 10:42:29 hst100 systemd[1]: Started Garbage Collector for SR d4b22411-592f-7ada-0597-68dbcb56ee4d. Jul 11 10:42:52 hst100 systemd[1]: Starting Garbage Collector for SR d4b22411-592f-7ada-0597-68dbcb56ee4d... -
@McHenry
Do they work if you turn off Secure Boot? There's a procedure to enable Secure Boot, see https://docs.xcp-ng.org/guides/guest-UEFI-Secure-Boot/ .Do you have space left on your Dom0 disk?
-
-
@McHenry
/dev/md127p1(the root partition) looks pretty full. Do you store anything big in there (ISOs...)? -
-
Safe to delete these *.gz files?
-
@McHenry That's your Dom0 partition, which stores the XCP-ng operating system. Don't store the ISOs there (which your local ISO SR is doing), you should mount an ISO SR using NFS instead.
/var/log shouldn't be an issue as it's in a separate partition. (I misread the df output)
-
Wow, it worked!
-
I deleted a few ISOs and the VM now boots.
So the issue was I was storing ISOs in the root partition and it was full?
-
@McHenry Yes, that's the cause of your issue.
-
Thank you so much. If you want me I'll be at the pub.
-
O olivierlambert marked this topic as a question on
-
O olivierlambert has marked this topic as solved on
Hello! It looks like you're interested in this conversation, but you don't have an account yet.
Getting fed up of having to scroll through the same posts each visit? When you register for an account, you'll always come back to exactly where you were before, and choose to be notified of new replies (either via email, or push notification). You'll also be able to save bookmarks and upvote posts to show your appreciation to other community members.
With your input, this post could be even better 💗
Register Login