[Fedora-xen] Restore Failed

Wed Nov 7 14:56:27 UTC 2007

In my previous post, I was asking questions about how to get guest VMs 
to cleanly shutdown and start back up when the host shuts down and 
starts back up.

> Newbie Virt Questions and comments on	wiki/Docs/Fedora8VirtQuickStart

I have made some progress on this issue by complete accident.
Previously I had a Fedora7 guest stored in an LVM partition.
I just tried a Fedora8-RC3 guest stored in a regular file.

Now the behavior is that if the guest is running when the host is shut 
down, it appears to try to start it back up after the host boots back 
up.  BUT, the guest restore fails with the following:

I would greatly appreciate any tips on how to stabilize this environment 
to get clean guest shutdowns and start ups when the host shuts down and 
starts up.  Thanks in advance.

> [2007-11-07 09:45:40 2414] INFO (SrvDaemon:338) Xend Daemon started
> [2007-11-07 09:45:40 2414] INFO (SrvDaemon:342) Xend changeset: unavailable.
> [2007-11-07 09:45:40 2414] INFO (SrvDaemon:349) Xend version: Unknown.
> [2007-11-07 09:45:40 2414] DEBUG (XendDomainInfo:126) XendDomainInfo.recreate({'max_vcpu_id': 3, 'cpu_time': 12024165224L, 'ssidref': 0, 'hvm': 0, 'shutdown_reason': 0, 'dying': 0, 'online_vcpus': 4, 'domid': 0, 'paused': 0, 'crashed': 0, 'running': 1, 'maxmem_kb': 17179869180L, 'shutdown': 0, 'mem_kb': 8124200L, 'handle': [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], 'blocked': 0, 'name': 'Domain-0'})
> [2007-11-07 09:45:40 2414] INFO (XendDomainInfo:143) Recreating domain 0, UUID 00000000-0000-0000-0000-000000000000. at /local/domain/0
> [2007-11-07 09:45:40 2414] DEBUG (XendDomainInfo:2026) Storing VM details: {'on_xend_stop': 'ignore', 'shadow_memory': '0', 'uuid': '00000000-0000-0000-0000-000000000000', 'on_reboot': 'restart', 'image': '(linux (kernel ))', 'on_poweroff': 'destroy', 'on_xend_start': 'ignore', 'on_crash': 'restart', 'xend/restart_count': '0', 'vcpus': '4', 'vcpu_avail': '15', 'name': 'Domain-0'}
> [2007-11-07 09:45:40 2414] DEBUG (XendDomainInfo:875) Storing domain details: {'cpu/3/availability': 'online', 'name': 'Domain-0', 'console/limit': '1048576', 'memory/target': '8124200', 'cpu/2/availability': 'online', 'vm': '/vm/00000000-0000-0000-0000-000000000000', 'domid': '0', 'cpu/0/availability': 'online', 'cpu/1/availability': 'online', 'control/platform-feature-multiprocessor-suspend': '1'}
> [2007-11-07 09:45:40 2414] DEBUG (XendDomain:443) Adding Domain: 0
> [2007-11-07 09:45:40 2414] DEBUG (XendDomain:379) number of vcpus to use is 0
> [2007-11-07 09:45:40 2414] DEBUG (XendDomainInfo:875) Storing domain details: {'cpu/3/availability': 'online', 'name': 'Domain-0', 'console/limit': '1048576', 'memory/target': '8124200', 'cpu/2/availability': 'online', 'vm': '/vm/00000000-0000-0000-0000-000000000000', 'domid': '0', 'cpu/0/availability': 'online', 'cpu/1/availability': 'online', 'control/platform-feature-multiprocessor-suspend': '1'}
> [2007-11-07 09:45:40 2414] DEBUG (XendDomainInfo:959) XendDomainInfo.handleShutdownWatch
> [2007-11-07 09:45:40 2414] DEBUG (XendDomainInfo:233) XendDomainInfo.createDormant({'vcpus_params': {}, 'PV_args': '', 'features': '', 'cpus': [], 'devices': {'9138bd07-7b37-af28-37ce-e9303b5c6f8d': ('vfb', {'vncunused': '1', 'other_config': {'vncunused': '1', 'type': 'vnc'}, 'type': 'vnc', 'uuid': '9138bd07-7b37-af28-37ce-e9303b5c6f8d'}), '2f1154f7-b1fc-e94f-3ebc-a7ec9b8e2977': ('vkbd', {'uuid': '2f1154f7-b1fc-e94f-3ebc-a7ec9b8e2977', 'backend': '0'}), '91c7caa0-3dfa-fc65-a81e-b76c88fe321f': ('vbd', {'uuid': '91c7caa0-3dfa-fc65-a81e-b76c88fe321f', 'bootable': 1, 'driver': 'paravirtualised', 'dev': 'xvda:disk', 'uname': 'file:/root/subversion.vm', 'mode': 'w', 'backend': '0'}), '2a06c796-f2a2-c96b-bd33-383ccf9a731a': ('vif', {'bridge': 'eth0', 'mac': '00:16:3e:1f:a4:ec', 'script': 'vif-bridge', 'uuid': '2a06c796-f2a2-c96b-bd33-383ccf9a731a', 'backend': '0'})}, 'vcpu_avail': 1L, 'VCPUs_live': 1, 'PV_bootloader': '/usr/bin/pygrub', 'actions_after_crash': 'restart', 'vbd_refs'
: ['91c7caa0-3dfa-fc65-a81e-b76c88fe321f'], 'PV_ramdisk': '', 'is_control_domain': False, 'name_label': 'subversion', 'VCPUs_at_startup': 1, 'HVM_boot_params': {}, 'platform': {'rtc_timeoffset': '0'}, 'cpu_weight': 256, 'console_refs': ['9138bd07-7b37-af28-37ce-e9303b5c6f8d'], 'cpu_cap': 0, 'vif_refs': ['2a06c796-f2a2-c96b-bd33-383ccf9a731a'], 'on_xend_stop': 'ignore', 'memory_static_min': 0, 'HVM_boot_policy': '', 'VCPUs_max': 1, 'start_time': 1194445904.5699999, 'memory_static_max': 1073741824, 'actions_after_shutdown': 'destroy', 'on_xend_start': 'ignore', 'memory_dynamic_max': 1073741824, 'actions_after_suspend': '', 'is_a_template': False, 'memory_dynamic_min': 1073741824, 'uuid': '7b6bbe1a-6669-7e7e-b17a-c5d0562b4e59', 'PV_kernel': '', 'cpu_time': 39.113985640999999, 'shadow_memory': 0, 'PV_bootloader_args': '', 'notes': {'HV_START_LOW': '4118806528', 'FEATURES': 'writable_page_tables|writable_descriptor_tables|auto_translated_physmap|pae_pgdir_above_4gb|supervisor_mode
_kernel', 'VIRT_BASE': '3221225472', 'GUEST_VERSION': '2.6', 'PADDR_OFFSET': '3221225472', 'GUEST_OS': 'linux', 'HYPERCALL_PAGE': '3238006784', 'LOADER': 'generic', 'SUSPEND_CANCEL': '1', 'PAE_MODE': 'yes', 'ENTRY': '3238002688', 'XEN_VERSION': 'xen-3.0'}, 'other_config': {}, 'actions_after_reboot': 'restart', 'status': '1', 'vtpm_refs': [], 'security': None})
> [2007-11-07 09:45:40 2414] ERROR (XendDomainInfo:2332) bridge_to_network
> Traceback (most recent call last):
>   File "/usr/lib64/python2.5/site-packages/xen/xend/XendDomainInfo.py", line 2330, in get_dev_xenapi_config
>     config.get('bridge')).get_uuid()
>   File "/usr/lib64/python2.5/site-packages/xen/xend/XendNode.py", line 510, in bridge_to_network
>     raise Exception('Cannot find network for bridge %s' % bridge)
> Exception: Cannot find network for bridge eth0
> [2007-11-07 09:45:40 2414] INFO (SrvServer:180) unix path=/var/lib/xend/xend-socket
> [2007-11-07 09:45:40 2414] WARNING (XendAPI:672) API call: VBD.set_device not found
> [2007-11-07 09:45:40 2414] WARNING (XendAPI:672) API call: VBD.set_mode not found
> [2007-11-07 09:45:40 2414] WARNING (XendAPI:672) API call: VBD.set_type not found
> [2007-11-07 09:45:40 2414] WARNING (XendAPI:672) API call: VM.get_auto_power_on not found
> [2007-11-07 09:45:40 2414] WARNING (XendAPI:672) API call: VM.set_auto_power_on not found
> [2007-11-07 09:45:40 2414] WARNING (XendAPI:672) API call: VM.set_VCPUs_max not found
> [2007-11-07 09:45:40 2414] WARNING (XendAPI:672) API call: VM.set_VCPUs_at_startup not found
> [2007-11-07 09:45:40 2414] WARNING (XendAPI:672) API call: debug.get_all not found
> [2007-11-07 09:45:40 2414] WARNING (XendAPI:672) API call: console.get_other_config not found
> [2007-11-07 09:45:40 2414] WARNING (XendAPI:672) API call: console.set_other_config not found
> [2007-11-07 09:45:40 2414] WARNING (XendAPI:672) API call: VIF.get_network not found
> [2007-11-07 09:45:40 2414] WARNING (XendAPI:672) API call: VIF.set_device not found
> [2007-11-07 09:45:40 2414] WARNING (XendAPI:672) API call: VIF.set_MAC not found
> [2007-11-07 09:45:40 2414] WARNING (XendAPI:672) API call: VIF.set_MTU not found
> [2007-11-07 09:45:40 2414] WARNING (XendAPI:672) API call: session.get_all_records not found
> [2007-11-07 09:45:40 2414] WARNING (XendAPI:672) API call: event.get_record not found
> [2007-11-07 09:45:40 2414] WARNING (XendAPI:672) API call: event.get_all not found
> [2007-11-07 09:45:43 2414] INFO (XMLRPCServer:149) Opening Unix domain socket XML-RPC server on /var/run/xend/xen-api.sock; authentication has been disabled for this server.
> [2007-11-07 09:45:43 2414] INFO (XMLRPCServer:149) Opening Unix domain socket XML-RPC server on /var/run/xend/xmlrpc.sock.
> [2007-11-07 09:45:44 2414] DEBUG (XendDomainInfo:210) XendDomainInfo.restore(['domain', ['domid', '4'], ['on_crash', 'restart'], ['uuid', '7b6bbe1a-6669-7e7e-b17a-c5d0562b4e59'], ['bootloader_args'], ['vcpus', '1'], ['name', 'subversion'], ['on_poweroff', 'destroy'], ['on_reboot', 'restart'], ['bootloader', '/usr/bin/pygrub'], ['maxmem', '1024'], ['memory', '1024'], ['shadow_memory', '0'], ['vcpu_avail', '1'], ['cpu_weight', '256'], ['cpu_cap', '0'], ['features'], ['on_xend_start', 'ignore'], ['on_xend_stop', 'ignore'], ['start_time', '1194445904.57'], ['cpu_time', '19.492313782'], ['online_vcpus', '1'], ['image', ['linux', ['kernel'], ['rtc_timeoffset', '0'], ['notes', ['HV_START_LOW', '4118806528'], ['FEATURES', 'writable_page_tables|writable_descriptor_tables|auto_translated_physmap|pae_pgdir_above_4gb|supervisor_mode_kernel'], ['VIRT_BASE', '3221225472'], ['GUEST_VERSION', '2.6'], ['PADDR_OFFSET', '3221225472'], ['GUEST_OS', 'linux'], ['HYPERCALL_PAGE', '3238006784'], [
'LOADER', 'generic'], ['SUSPEND_CANCEL', '1'], ['PAE_MODE', 'yes'], ['ENTRY', '3238002688'], ['XEN_VERSION', 'xen-3.0']]]], ['status', '2'], ['state', '-b----'], ['store_mfn', '2154297'], ['console_mfn', '2154296'], ['device', ['vif', ['bridge', 'eth0'], ['mac', '00:16:3e:1f:a4:ec'], ['script', 'vif-bridge'], ['uuid', '2a06c796-f2a2-c96b-bd33-383ccf9a731a'], ['backend', '0']]], ['device', ['vbd', ['uname', 'file:/root/subversion.vm'], ['uuid', '91c7caa0-3dfa-fc65-a81e-b76c88fe321f'], ['mode', 'w'], ['dev', 'xvda:disk'], ['backend', '0'], ['bootable', '1']]], ['device', ['vkbd', ['backend', '0']]], ['device', ['vfb', ['vncunused', '1'], ['type', 'vnc'], ['uuid', '9138bd07-7b37-af28-37ce-e9303b5c6f8d']]]])
> [2007-11-07 09:45:44 2414] DEBUG (XendDomainInfo:1465) XendDomainInfo.constructDomain
> [2007-11-07 09:45:44 2414] DEBUG (balloon:113) Balloon: 131072 KiB free; need 2048; done.
> [2007-11-07 09:45:44 2414] DEBUG (XendDomain:443) Adding Domain: 1
> [2007-11-07 09:45:44 2414] DEBUG (XendDomainInfo:2026) Storing VM details: {'on_xend_stop': 'ignore', 'shadow_memory': '0', 'uuid': '7b6bbe1a-6669-7e7e-b17a-c5d0562b4e59', 'on_reboot': 'restart', 'start_time': '1194445904.57', 'on_poweroff': 'destroy', 'on_xend_start': 'ignore', 'on_crash': 'restart', 'xend/restart_count': '0', 'vcpus': '1', 'vcpu_avail': '1', 'image': "(linux (kernel ) (rtc_timeoffset 0) (notes (HV_START_LOW 4118806528) (FEATURES 'writable_page_tables|writable_descriptor_tables|auto_translated_physmap|pae_pgdir_above_4gb|supervisor_mode_kernel') (VIRT_BASE 3221225472) (GUEST_VERSION 2.6) (PADDR_OFFSET 3221225472) (GUEST_OS linux) (HYPERCALL_PAGE 3238006784) (LOADER generic) (SUSPEND_CANCEL 1) (PAE_MODE yes) (ENTRY 3238002688) (XEN_VERSION xen-3.0)))", 'name': 'subversion'}
> [2007-11-07 09:45:44 2414] INFO (XendDomainInfo:1367) createDevice: vkbd : {'uuid': '417e4cd7-3e82-a982-ff62-53a0b89fb649', 'backend': '0'}
> [2007-11-07 09:45:44 2414] DEBUG (DevController:115) DevController: writing {'state': '1', 'backend-id': '0', 'backend': '/local/domain/0/backend/vkbd/1/0'} to /local/domain/1/device/vkbd/0.
> [2007-11-07 09:45:44 2414] DEBUG (DevController:117) DevController: writing {'frontend-id': '1', 'domain': 'subversion', 'frontend': '/local/domain/1/device/vkbd/0', 'state': '1', 'online': '1'} to /local/domain/0/backend/vkbd/1/0.
> [2007-11-07 09:45:44 2414] INFO (XendDomainInfo:1367) createDevice: vfb : {'vncunused': '1', 'other_config': {'vncunused': '1', 'type': 'vnc'}, 'type': 'vnc', 'uuid': '9138bd07-7b37-af28-37ce-e9303b5c6f8d'}
> [2007-11-07 09:45:44 2414] DEBUG (DevController:115) DevController: writing {'state': '1', 'backend-id': '0', 'backend': '/local/domain/0/backend/vfb/1/0'} to /local/domain/1/device/vfb/0.
> [2007-11-07 09:45:44 2414] DEBUG (DevController:117) DevController: writing {'vncunused': '1', 'domain': 'subversion', 'frontend': '/local/domain/1/device/vfb/0', 'uuid': '9138bd07-7b37-af28-37ce-e9303b5c6f8d', 'state': '1', 'online': '1', 'frontend-id': '1', 'type': 'vnc'} to /local/domain/0/backend/vfb/1/0.
> [2007-11-07 09:45:44 2414] DEBUG (vfbif:78) No VNC passwd configured for vfb access
> [2007-11-07 09:45:44 2414] DEBUG (vfbif:9) Spawn: ['/usr/lib64/xen/bin/qemu-dm', '-M', 'xenpv', '-d', '1', '-domain-name', 'subversion', '-vnc', '127.0.0.1:0', '-vncunused']
> [2007-11-07 09:45:44 2414] INFO (XendDomainInfo:1367) createDevice: vbd : {'uuid': '91c7caa0-3dfa-fc65-a81e-b76c88fe321f', 'bootable': 1, 'driver': 'paravirtualised', 'dev': 'xvda:disk', 'uname': 'file:/root/subversion.vm', 'mode': 'w', 'backend': '0'}
> [2007-11-07 09:45:44 2414] DEBUG (DevController:115) DevController: writing {'backend-id': '0', 'virtual-device': '51712', 'device-type': 'disk', 'state': '1', 'backend': '/local/domain/0/backend/vbd/1/51712'} to /local/domain/1/device/vbd/51712.
> [2007-11-07 09:45:44 2414] DEBUG (DevController:117) DevController: writing {'domain': 'subversion', 'frontend': '/local/domain/1/device/vbd/51712', 'uuid': '91c7caa0-3dfa-fc65-a81e-b76c88fe321f', 'dev': 'xvda', 'state': '1', 'params': '/root/subversion.vm', 'mode': 'w', 'online': '1', 'frontend-id': '1', 'type': 'file'} to /local/domain/0/backend/vbd/1/51712.
> [2007-11-07 09:45:44 2414] INFO (XendDomainInfo:1367) createDevice: vif : {'bridge': 'eth0', 'mac': '00:16:3e:1f:a4:ec', 'script': 'vif-bridge', 'uuid': '2a06c796-f2a2-c96b-bd33-383ccf9a731a', 'backend': '0'}
> [2007-11-07 09:45:44 2414] DEBUG (DevController:115) DevController: writing {'backend-id': '0', 'mac': '00:16:3e:1f:a4:ec', 'handle': '0', 'state': '1', 'backend': '/local/domain/0/backend/vif/1/0'} to /local/domain/1/device/vif/0.
> [2007-11-07 09:45:44 2414] DEBUG (DevController:117) DevController: writing {'bridge': 'eth0', 'domain': 'subversion', 'handle': '0', 'uuid': '2a06c796-f2a2-c96b-bd33-383ccf9a731a', 'script': '/etc/xen/scripts/vif-bridge', 'state': '1', 'frontend': '/local/domain/1/device/vif/0', 'mac': '00:16:3e:1f:a4:ec', 'online': '1', 'frontend-id': '1'} to /local/domain/0/backend/vif/1/0.
> [2007-11-07 09:45:44 2414] DEBUG (XendDomainInfo:875) Storing domain details: {'image/entry': '3238002688', 'console/port': '2', 'image/loader': 'generic', 'vm': '/vm/7b6bbe1a-6669-7e7e-b17a-c5d0562b4e59', 'control/platform-feature-multiprocessor-suspend': '1', 'image/hv-start-low': '4118806528', 'image/guest-os': 'linux', 'image/features/writable-descriptor-tables': '1', 'image/virt-base': '3221225472', 'memory/target': '1048576', 'image/guest-version': '2.6', 'image/features/supervisor-mode-kernel': '1', 'image/pae-mode': 'yes', 'console/limit': '1048576', 'image/paddr-offset': '3221225472', 'image/hypercall-page': '3238006784', 'image/suspend-cancel': '1', 'cpu/0/availability': 'online', 'image/features/pae-pgdir-above-4gb': '1', 'image/features/writable-page-tables': '1', 'image/features/auto-translated-physmap': '1', 'name': 'subversion', 'domid': '1', 'image/xen-version': 'xen-3.0', 'store/port': '1'}
> [2007-11-07 09:45:44 2414] DEBUG (XendCheckpoint:202) restore:shadow=0x0, _static_max=0x40000000, _static_min=0x0, 
> [2007-11-07 09:45:44 2414] DEBUG (balloon:119) Balloon: 131064 KiB free; 0 to scrub; need 1048576; retries: 20.
> [2007-11-07 09:45:44 2414] DEBUG (balloon:134) Balloon: setting dom0 target to 7037 MiB.
> [2007-11-07 09:45:44 2414] DEBUG (XendDomainInfo:583) Setting memory target of domain Domain-0 (0) to 7037 MiB.
> [2007-11-07 09:45:44 2414] DEBUG (XendDomainInfo:875) Storing domain details: {'cpu/3/availability': 'online', 'name': 'Domain-0', 'console/limit': '1048576', 'memory/target': '7205888', 'cpu/2/availability': 'online', 'vm': '/vm/00000000-0000-0000-0000-000000000000', 'domid': '0', 'cpu/0/availability': 'online', 'cpu/1/availability': 'online', 'control/platform-feature-multiprocessor-suspend': '1'}
> [2007-11-07 09:45:45 2414] DEBUG (balloon:113) Balloon: 1049376 KiB free; need 1048576; done.
> [2007-11-07 09:45:45 2414] DEBUG (XendCheckpoint:214) [xc_restore]: /usr/lib64/xen/bin/xc_restore 4 1 1 2 0 0 0
> [2007-11-07 09:45:45 2414] INFO (XendCheckpoint:350) xc_domain_restore start: p2m_size = 40800
> [2007-11-07 09:45:45 2414] INFO (XendCheckpoint:350) ERROR Internal error: read extended-info signature failed
> [2007-11-07 09:45:45 2414] INFO (XendCheckpoint:350) Restore exit with rc=1
> [2007-11-07 09:45:45 2414] DEBUG (XendDomainInfo:1713) XendDomainInfo.destroy: domid=1
> [2007-11-07 09:45:45 2414] DEBUG (XendDomainInfo:1730) XendDomainInfo.destroyDomain(1)
> [2007-11-07 09:45:45 2414] ERROR (XendDomainInfo:1742) XendDomainInfo.destroy: xc.domain_destroy failed.
> Traceback (most recent call last):
>   File "/usr/lib64/python2.5/site-packages/xen/xend/XendDomainInfo.py", line 1736, in destroyDomain
>     xc.domain_destroy(self.domid)
> Error: (3, 'No such process')
> [2007-11-07 09:45:45 2414] ERROR (XendDomain:1104) Restore failed
> Traceback (most recent call last):
>   File "/usr/lib64/python2.5/site-packages/xen/xend/XendDomain.py", line 1099, in domain_restore_fd
>     return XendCheckpoint.restore(self, fd, paused=paused)
>   File "/usr/lib64/python2.5/site-packages/xen/xend/XendCheckpoint.py", line 218, in restore
>     forkHelper(cmd, fd, handler.handler, True)
>   File "/usr/lib64/python2.5/site-packages/xen/xend/XendCheckpoint.py", line 338, in forkHelper
>     raise XendError("%s failed" % string.join(cmd))
> XendError: /usr/lib64/xen/bin/xc_restore 4 1 1 2 0 0 0 failed