Bug 473188

Summary: F10 guest installation hangs at "installing kernel"
Product: [Fedora] Fedora Reporter: Russell Doty <rdoty>
Component: anacondaAssignee: Anaconda Maintenance Team <anaconda-maint-list>
Status: CLOSED RAWHIDE QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: high Docs Contact:
Priority: medium    
Version: 10CC: anaconda-maint-list, dcantrell, dhuff, greno, jgranado, madko, shap
Target Milestone: ---   
Target Release: ---   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2009-10-07 15:46:05 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
install.log from hanging install
none
anaconda-ks.cfg from the hanging install
none
floppy dirve img with ks.cfg none

Description Russell Doty 2008-11-27 00:09:18 UTC 
Description of problem:

Installation of a F10 guest on an F10 host proceeds normally until it gets to the final stage of installing kernel. It hangs at this point - not responding and no cpu usage, for several hours.

Version-Release number of selected component (if applicable):


How reproducible:

Every time I've tried.

Steps to Reproduce:
1. Install F10 with virtualization
2. Start Virtual Machine Manager
3. Create a F10 guest
4. Accept options and allow installation to run
  
Actual results:

Installation seems to proceed normally until it gets to the last step: package 1063 of 1063  Installing kernel-2.6.27.5-117.fc10.x86_64. Displays "installing bootloader". Guest hangs - mouse is frozen (with clock symbol), non responsive to inputs, less than 2% cpu usage. Allowed the system to continue like this for several hours with no progress.

Expected results:

Successful completion of guest installation.

Additional info:

After doing a shutdown with forced power off, I was able to successfully reboot the F10 guest. The guest functioned normally.
Comment 1 Jonathan S. Shapiro 2008-12-01 18:19:59 UTC 
I'm also seeing this, except that my VM host system is running F8. Also, in my cases I have added the Fedora Updates repository to the install, and it still hangs at this point.

I can also say that the bug occurs in both i386 guest on i386 host and x86_64 guest on x86_64 host configurations.

If the guest VM is forcibly shut down and allowed to reboot, it appears to come up okay, but I would sure feel more comfortable if somebody at RedHat could confirm that using this approach as a workaround isn't badly broken in some way.
Comment 2 Chris Lumens 2008-12-02 14:56:42 UTC 
Are there any error messages on tty1, tty4, or tty5?  Can you attach /tmp/anaconda.log and /tmp/syslog to this bug report?
Comment 3 Jonathan S. Shapiro 2008-12-02 19:56:20 UTC 
No joy on anything in /tmp, but I'm attaching the anaconda-ks.cfg, install.log from the guest /root. Nothing useful in either of them. The install.log.syslog file is empty (zero length). I've started a re-install to try to get you the tty state. That will take a while, but here is the exact install procedure so that you can replicate. Also note the post-install content of xend.log and traceback in xend-debug.log at bottom.

Host is running FC8-i386. Host kernel is 2.6.21.7-5.fc8xen. Host xen version is xen-3.1.2-5.fc8. Everything is up to date. virt-manager is install. No kickstart file is being used here. Host selinux is ENABLED.

I copied the F10 DVD iso image to /home/iso/. This is the i386 image

Using virt-manager, I create a new guest domain as follows:

  Fully Virtualized
  Installation media from the ISO image file.
  OS Type: Linux
  OS Variant: Fedora 8 (aside: that drop list needs an update!)
  Simple file (placed in /xen/), size 30720 Mbytes, allocate now
     [I have no reason to believe that the size matters.]
  Shared physical device peth0
     I have seen the freeze with both a fixed MAC and a non-fixed MAC address.
  Max memory 512M, Initial memory 256M
  Logical host CPUs: 4, VCPUs: 1

Creating the disk image file, predictably, takes a while. :-)

Select "install or upgrade", skip the media check

Anaconda Answers:

  English language, U.S. English kbd, Wipe all partitions
  Give a hostname (in my case f10-test)
  EST/New York, Sys clock uses UTC

  Whack all Linux partitons,  **review and modify**
    [To duplicate my previous error, I am altering the LVs as follows:
       LV name to f10_test
       delete /
       change swap size to 4096M, volname to swap00
       create /, all remaining space, ext3, volname root
     This is probably not necessary to reproduce.]
  Confirm write changes to disk: yes

  [File system format apparently proceeds successfully]
  [Accept boot sector defaults without modification]
  Package Selection:
    Check "software development"
    Check "Fedora 10 - i386"
    Check "Fedora 10 - i386 - updates"

    IP address was acquired successfully. Repo information was acquired
    successfully.

    BTW it is difficult to imagine that the "Enable IPv4" checkbox is not
    a typo in anaconda. Shouldn't that be "Enable IPv6"?

    [I have no reason to believe that these are related to the problem;
     I did this to duplicate my earlier conditions. In particular, checking
     Software Development is almost certainly NOT necessary.]

  Dependencies get checked successfully.
  MANY packages get installed. Thank God for coffee.

Okay. We get to the last package install (kernel), and things hang. At this point the mouse is live (so interrupts are being processed), and the installation is done (in the sense that if I power cycle the VM it comes up properly after an fsck).

At this point the "installing boot loader" dialog pops up and the system is well and truly hung. Mouse does not respond, and there no way to switch to any of the ttys.


Contents of HOST xend.log for this install:

[2008-12-02 13:17:41 3067] INFO (XendDomain:1054) Domain lv-f8 (1d25d8e0-af39-b634-f2ec-28716f2ca3e3) deleted.
[2008-12-02 13:18:17 3067] DEBUG (XendDomainInfo:451) XendDomainInfo.shutdown(halt)
[2008-12-02 13:18:17 3067] DEBUG (XendDomainInfo:1040) XendDomainInfo.handleShutdownWatch
[2008-12-02 13:18:17 3067] INFO (XendDomainInfo:469) HVM save:remote shutdown dom 12!
[2008-12-02 13:18:17 3067] INFO (XendDomainInfo:1228) Domain has shutdown: name=f10 id=12 reason=halt.
[2008-12-02 13:18:17 3067] DEBUG (XendDomainInfo:1802) XendDomainInfo.destroy: domid=12
[2008-12-02 13:18:17 3067] DEBUG (XendDomainInfo:1821) XendDomainInfo.destroyDomain(12)
[2008-12-02 13:18:17 3067] DEBUG (XendDomainInfo:1479) Removing vif/0
[2008-12-02 13:18:17 3067] DEBUG (XendDomainInfo:569) XendDomainInfo.destroyDevice: deviceClass = vif, device = vif/0
[2008-12-02 13:18:17 3067] DEBUG (XendDomainInfo:1479) Removing vbd/768
[2008-12-02 13:18:17 3067] DEBUG (XendDomainInfo:569) XendDomainInfo.destroyDevice: deviceClass = vbd, device = vbd/768
[2008-12-02 13:18:17 3067] DEBUG (XendDomainInfo:1479) Removing vbd/5632
[2008-12-02 13:18:17 3067] DEBUG (XendDomainInfo:569) XendDomainInfo.destroyDevice: deviceClass = vbd, device = vbd/5632
[2008-12-02 13:18:17 3067] DEBUG (XendDomainInfo:1479) Removing vkbd/0
[2008-12-02 13:18:17 3067] DEBUG (XendDomainInfo:569) XendDomainInfo.destroyDevice: deviceClass = vkbd, device = vkbd/0
[2008-12-02 13:18:17 3067] DEBUG (XendDomainInfo:1479) Removing vfb/0
[2008-12-02 13:18:17 3067] DEBUG (XendDomainInfo:569) XendDomainInfo.destroyDevice: deviceClass = vfb, device = vfb/0
[2008-12-02 13:18:17 3067] DEBUG (XendDomainInfo:1479) Removing console/0
[2008-12-02 13:18:17 3067] DEBUG (XendDomainInfo:569) XendDomainInfo.destroyDevice: deviceClass = console, device = console/0
[2008-12-02 13:18:17 3067] ERROR (XendConfig:934) dumping sxp from device controllers
Traceback (most recent call last):
  File "/usr/lib/python2.5/site-packages/xen/xend/XendConfig.py", line 920, in to_sxp
    configs = controller.configurations(txn)
  File "/usr/lib/python2.5/site-packages/xen/xend/server/DevController.py", line 243, in configurations
    return map(lambda x: self.configuration(x, transaction), self.deviceIDs(transaction))
  File "/usr/lib/python2.5/site-packages/xen/xend/server/DevController.py", line 243, in <lambda>
    return map(lambda x: self.configuration(x, transaction), self.deviceIDs(transaction))
  File "/usr/lib/python2.5/site-packages/xen/xend/server/DevController.py", line 250, in configuration
    configDict = self.getDeviceConfiguration(devid, transaction)
  File "/usr/lib/python2.5/site-packages/xen/xend/server/netif.py", line 153, in getDeviceConfiguration
    result = DevController.getDeviceConfiguration(self, devid, transaction)
  File "/usr/lib/python2.5/site-packages/xen/xend/server/DevController.py", line 287, in getDeviceConfiguration
    raise VmError("Device %s not connected" % devid)
VmError: Device 0 not connected
[2008-12-02 13:35:17 3067] DEBUG (XendDomainInfo:84) XendDomainInfo.create(['vm', ['name', 'f10-test'], ['memory', '256'], ['maxmem', '512'], ['vcpus', '1'], ['uuid', '98d26dc6-0147-b760-91b8-7d6f2f4a5102'], ['on_poweroff', 'destroy'], ['on_reboot', 'destroy'], ['on_crash', 'destroy'], ['image', ['hvm', ['kernel', '/usr/lib/xen/boot/hvmloader'], ['vcpus', '1'], ['boot', 'd'], ['acpi', '1'], ['apic', '1'], ['pae', '1'], ['usb', '1'], ['parallel', 'none'], ['serial', 'pty'], ['device_model', '/usr/lib/xen/bin/qemu-dm']]], ['device', ['vbd', ['dev', 'hda:disk'], ['uname', 'file:/xen/f10-test.img'], ['mode', 'w']]], ['device', ['vbd', ['dev', 'hdc:cdrom'], ['uname', 'file:/home/iso/Fedora-10-i386-DVD.iso'], ['mode', 'r']]], ['device', ['vif', ['mac', '00:16:3e:5f:b5:e2'], ['bridge', 'eth0']]], ['device', ['vkbd']], ['device', ['vfb', ['type', 'vnc'], ['vncunused', '1'], ['keymap', 'en-us']]]])
[2008-12-02 13:35:17 3067] DEBUG (XendDomainInfo:1555) XendDomainInfo.constructDomain
[2008-12-02 13:35:17 3067] DEBUG (balloon:116) Balloon: 1383040 KiB free; need 2048; done.
[2008-12-02 13:35:17 3067] DEBUG (XendDomain:443) Adding Domain: 13
[2008-12-02 13:35:17 3067] DEBUG (XendDomainInfo:1609) XendDomainInfo.initDomain: 13 256
[2008-12-02 13:35:17 3067] DEBUG (image:330) args: boot, val: d
[2008-12-02 13:35:17 3067] DEBUG (image:330) args: fda, val: None
[2008-12-02 13:35:17 3067] DEBUG (image:330) args: fdb, val: None
[2008-12-02 13:35:17 3067] DEBUG (image:330) args: soundhw, val: None
[2008-12-02 13:35:17 3067] DEBUG (image:330) args: localtime, val: None
[2008-12-02 13:35:17 3067] DEBUG (image:330) args: serial, val: pty
[2008-12-02 13:35:17 3067] DEBUG (image:330) args: std-vga, val: None
[2008-12-02 13:35:17 3067] DEBUG (image:330) args: isa, val: None
[2008-12-02 13:35:17 3067] DEBUG (image:330) args: acpi, val: 1
[2008-12-02 13:35:17 3067] DEBUG (image:330) args: usb, val: 1
[2008-12-02 13:35:17 3067] DEBUG (image:330) args: usbdevice, val: None
[2008-12-02 13:35:17 3067] DEBUG (image:330) args: k, val: None
[2008-12-02 13:35:17 3067] DEBUG (image:400) No VNC passwd configured for vfb access
[2008-12-02 13:35:17 3067] DEBUG (XendDomainInfo:1640) _initDomain:shadow_memory=0x0, memory_static_max=0x20000000, memory_static_min=0x0.
[2008-12-02 13:35:17 3067] DEBUG (balloon:116) Balloon: 1382012 KiB free; need 275456; done.
[2008-12-02 13:35:17 3067] INFO (image:129) buildDomain os=hvm dom=13 vcpus=1
[2008-12-02 13:35:17 3067] DEBUG (image:278) domid          = 13
[2008-12-02 13:35:17 3067] DEBUG (image:279) image          = /usr/lib/xen/boot/hvmloader
[2008-12-02 13:35:17 3067] DEBUG (image:280) store_evtchn   = 2
[2008-12-02 13:35:17 3067] DEBUG (image:281) memsize        = 256
[2008-12-02 13:35:17 3067] DEBUG (image:282) vcpus          = 1
[2008-12-02 13:35:17 3067] DEBUG (image:283) pae            = 1
[2008-12-02 13:35:17 3067] DEBUG (image:284) acpi           = 1
[2008-12-02 13:35:17 3067] DEBUG (image:285) apic           = 1
[2008-12-02 13:35:17 3067] INFO (XendDomainInfo:1458) createDevice: vkbd : {'uuid': '34af5a5f-2ddf-6488-7214-a822b74cb701'}
[2008-12-02 13:35:17 3067] DEBUG (DevController:117) DevController: writing {'state': '1', 'backend-id': '0', 'backend': '/local/domain/0/backend/vkbd/13/0'} to /local/domain/13/device/vkbd/0.
[2008-12-02 13:35:17 3067] DEBUG (DevController:119) DevController: writing {'frontend-id': '13', 'domain': 'f10-test', 'frontend': '/local/domain/13/device/vkbd/0', 'state': '1', 'online': '1'} to /local/domain/0/backend/vkbd/13/0.
[2008-12-02 13:35:17 3067] INFO (XendDomainInfo:1458) createDevice: vfb : {'vncunused': '1', 'keymap': 'en-us', 'type': 'vnc', 'uuid': '2fb0b6a7-e312-05e9-d808-c2b8eed7a5f7', 'other_config': {'vncunused': '1', 'keymap': 'en-us', 'type': 'vnc'}}
[2008-12-02 13:35:17 3067] DEBUG (DevController:117) DevController: writing {'state': '1', 'backend-id': '0', 'backend': '/local/domain/0/backend/vfb/13/0'} to /local/domain/13/device/vfb/0.
[2008-12-02 13:35:17 3067] DEBUG (DevController:119) DevController: writing {'vncunused': '1', 'domain': 'f10-test', 'frontend': '/local/domain/13/device/vfb/0', 'uuid': '2fb0b6a7-e312-05e9-d808-c2b8eed7a5f7', 'state': '1', 'keymap': 'en-us', 'online': '1', 'frontend-id': '13', 'type': 'vnc'} to /local/domain/0/backend/vfb/13/0.
[2008-12-02 13:35:17 3067] INFO (XendDomainInfo:1458) createDevice: vbd : {'uuid': '982343eb-b92a-e5ad-b5f4-aff67dd63ca7', 'bootable': 1, 'driver': 'paravirtualised', 'dev': 'hda:disk', 'uname': 'file:/xen/f10-test.img', 'mode': 'w'}
[2008-12-02 13:35:17 3067] DEBUG (DevController:117) DevController: writing {'backend-id': '0', 'virtual-device': '768', 'device-type': 'disk', 'state': '1', 'backend': '/local/domain/0/backend/vbd/13/768'} to /local/domain/13/device/vbd/768.
[2008-12-02 13:35:17 3067] DEBUG (DevController:119) DevController: writing {'domain': 'f10-test', 'frontend': '/local/domain/13/device/vbd/768', 'uuid': '982343eb-b92a-e5ad-b5f4-aff67dd63ca7', 'format': 'raw', 'dev': 'hda', 'state': '1', 'params': '/xen/f10-test.img', 'mode': 'w', 'online': '1', 'frontend-id': '13', 'type': 'file'} to /local/domain/0/backend/vbd/13/768.
[2008-12-02 13:35:17 3067] INFO (XendDomainInfo:1458) createDevice: vbd : {'uuid': '165e21ca-3f1c-d653-df70-92bed78f6738', 'bootable': 0, 'driver': 'paravirtualised', 'dev': 'hdc:cdrom', 'uname': 'file:/home/iso/Fedora-10-i386-DVD.iso', 'mode': 'r'}
[2008-12-02 13:35:17 3067] DEBUG (DevController:117) DevController: writing {'backend-id': '0', 'virtual-device': '5632', 'device-type': 'cdrom', 'state': '1', 'backend': '/local/domain/0/backend/vbd/13/5632'} to /local/domain/13/device/vbd/5632.
[2008-12-02 13:35:17 3067] DEBUG (DevController:119) DevController: writing {'domain': 'f10-test', 'frontend': '/local/domain/13/device/vbd/5632', 'uuid': '165e21ca-3f1c-d653-df70-92bed78f6738', 'format': 'raw', 'dev': 'hdc', 'state': '1', 'params': '/home/iso/Fedora-10-i386-DVD.iso', 'mode': 'r', 'online': '1', 'frontend-id': '13', 'type': 'file'} to /local/domain/0/backend/vbd/13/5632.
[2008-12-02 13:35:17 3067] INFO (XendDomainInfo:1458) createDevice: vif : {'bridge': 'eth0', 'mac': '00:16:3e:5f:b5:e2', 'uuid': '3af86fd8-9578-9032-90fe-9e763f8b603a'}
[2008-12-02 13:35:17 3067] DEBUG (DevController:117) DevController: writing {'backend-id': '0', 'mac': '00:16:3e:5f:b5:e2', 'handle': '0', 'state': '1', 'backend': '/local/domain/0/backend/vif/13/0'} to /local/domain/13/device/vif/0.
[2008-12-02 13:35:17 3067] DEBUG (DevController:119) DevController: writing {'bridge': 'eth0', 'domain': 'f10-test', 'handle': '0', 'uuid': '3af86fd8-9578-9032-90fe-9e763f8b603a', 'script': '/etc/xen/scripts/vif-bridge', 'state': '1', 'frontend': '/local/domain/13/device/vif/0', 'mac': '00:16:3e:5f:b5:e2', 'online': '1', 'frontend-id': '13'} to /local/domain/0/backend/vif/13/0.
[2008-12-02 13:35:17 3067] INFO (image:454) spawning device models: /usr/lib/xen/bin/qemu-dm ['/usr/lib/xen/bin/qemu-dm', '-d', '13', '-vcpus', '1', '-boot', 'd', '-serial', 'pty', '-acpi', '-usb', '-domain-name', 'f10-test', '-net', 'nic,vlan=1,macaddr=00:16:3e:5f:b5:e2,model=rtl8139', '-net', 'tap,vlan=1,bridge=eth0', '-vnc', '127.0.0.1:0', '-vncunused']
[2008-12-02 13:35:17 3067] INFO (image:458) device model pid: 29074
[2008-12-02 13:35:17 3067] DEBUG (XendDomainInfo:2116) Storing VM details: {'on_xend_stop': 'ignore', 'shadow_memory': '5', 'uuid': '98d26dc6-0147-b760-91b8-7d6f2f4a5102', 'on_reboot': 'destroy', 'start_time': '1228242917.6', 'on_poweroff': 'destroy', 'on_xend_start': 'ignore', 'on_crash': 'destroy', 'xend/restart_count': '0', 'vcpus': '1', 'vcpu_avail': '1', 'image': '(hvm (kernel /usr/lib/xen/boot/hvmloader) (acpi 1) (apic 1) (boot d) (device_model /usr/lib/xen/bin/qemu-dm) (pae 1) (serial pty) (usb 1) (notes (SUSPEND_CANCEL 1)))', 'name': 'f10-test'}
[2008-12-02 13:35:17 3067] DEBUG (XendDomainInfo:956) Storing domain details: {'console/port': '3', 'name': 'f10-test', 'console/limit': '1048576', 'vm': '/vm/98d26dc6-0147-b760-91b8-7d6f2f4a5102', 'domid': '13', 'image/suspend-cancel': '1', 'cpu/0/availability': 'online', 'memory/target': '262144', 'control/platform-feature-multiprocessor-suspend': '1', 'store/ring-ref': '65534', 'store/port': '2'}
[2008-12-02 13:35:17 3067] DEBUG (DevController:117) DevController: writing {'state': '1', 'backend-id': '0', 'backend': '/local/domain/0/backend/console/13/0'} to /local/domain/13/device/console/0.
[2008-12-02 13:35:17 3067] DEBUG (DevController:119) DevController: writing {'domain': 'f10-test', 'protocol': 'vt100', 'uuid': 'fbafc654-a59b-1237-803f-6229fa79acbb', 'frontend': '/local/domain/13/device/console/0', 'state': '1', 'location': '3', 'online': '1', 'frontend-id': '13'} to /local/domain/0/backend/console/13/0.
[2008-12-02 13:35:17 3067] DEBUG (XendDomainInfo:1040) XendDomainInfo.handleShutdownWatch
[2008-12-02 13:35:17 3067] DEBUG (DevController:150) Waiting for devices vif.
[2008-12-02 13:35:17 3067] DEBUG (DevController:155) Waiting for 0.
[2008-12-02 13:35:17 3067] DEBUG (DevController:594) hotplugStatusCallback /local/domain/0/backend/vif/13/0/hotplug-status.
[2008-12-02 13:35:18 3067] DEBUG (DevController:594) hotplugStatusCallback /local/domain/0/backend/vif/13/0/hotplug-status.
[2008-12-02 13:35:18 3067] DEBUG (DevController:608) hotplugStatusCallback 1.
[2008-12-02 13:35:18 3067] DEBUG (DevController:150) Waiting for devices usb.
[2008-12-02 13:35:18 3067] DEBUG (DevController:150) Waiting for devices vbd.
[2008-12-02 13:35:18 3067] DEBUG (DevController:155) Waiting for 768.
[2008-12-02 13:35:18 3067] DEBUG (DevController:594) hotplugStatusCallback /local/domain/0/backend/vbd/13/768/hotplug-status.
[2008-12-02 13:35:19 3067] DEBUG (DevController:594) hotplugStatusCallback /local/domain/0/backend/vbd/13/768/hotplug-status.
[2008-12-02 13:35:19 3067] DEBUG (DevController:608) hotplugStatusCallback 1.
[2008-12-02 13:35:19 3067] DEBUG (DevController:155) Waiting for 5632.
[2008-12-02 13:35:19 3067] DEBUG (DevController:594) hotplugStatusCallback /local/domain/0/backend/vbd/13/5632/hotplug-status.
[2008-12-02 13:35:19 3067] DEBUG (DevController:608) hotplugStatusCallback 1.
[2008-12-02 13:35:19 3067] DEBUG (DevController:150) Waiting for devices irq.
[2008-12-02 13:35:19 3067] DEBUG (DevController:150) Waiting for devices vkbd.
[2008-12-02 13:35:19 3067] DEBUG (DevController:150) Waiting for devices vfb.
[2008-12-02 13:35:19 3067] DEBUG (vfbif:109) skip waiting for HVM vfb
[2008-12-02 13:35:19 3067] DEBUG (DevController:150) Waiting for devices console.
[2008-12-02 13:35:19 3067] DEBUG (DevController:155) Waiting for 0.
[2008-12-02 13:35:19 3067] DEBUG (DevController:150) Waiting for devices pci.
[2008-12-02 13:35:19 3067] DEBUG (DevController:150) Waiting for devices ioports.
[2008-12-02 13:35:19 3067] DEBUG (DevController:150) Waiting for devices tap.
[2008-12-02 13:35:19 3067] DEBUG (DevController:150) Waiting for devices vtpm.
[2008-12-02 13:35:19 3067] INFO (XendDomain:1130) Domain f10-test (13) unpaused.
[2008-12-02 13:35:19 3067] DEBUG (XendDomainInfo:239) XendDomainInfo.createDormant({'vcpus_params': {}, 'PV_args': '', 'features': '', 'cpus': [], 'devices': {'ff08d6d9-45ca-0f96-4ac0-f05152e73289': ('vbd', {'bootable': 0, 'driver': 'paravirtualised', 'mode': 'r', 'dev': 'hdc:cdrom', 'uuid': 'ff08d6d9-45ca-0f96-4ac0-f05152e73289'}), '2566ddf3-95dd-b2a2-4715-d22954e52f64': ('vfb', {'vncunused': '1', 'keymap': 'en-us', 'type': 'vnc', 'uuid': '2566ddf3-95dd-b2a2-4715-d22954e52f64', 'other_config': {'vncunused': '1', 'keymap': 'en-us', 'type': 'vnc'}}), '2e7b09aa-e5c3-afb1-a3cf-773d48445abd': ('vkbd', {'uuid': '2e7b09aa-e5c3-afb1-a3cf-773d48445abd'}), 'ff1c2855-0e9e-88f5-a9e7-821d56b3bc35': ('vbd', {'uuid': 'ff1c2855-0e9e-88f5-a9e7-821d56b3bc35', 'bootable': 1, 'driver': 'paravirtualised', 'dev': 'hda:disk', 'uname': 'file:/xen/f10-test.img', 'mode': 'w'}), 'a8ae9cf7-c140-1ce7-ae07-cd511164da8f': ('vif', {'bridge': 'eth0', 'mac': '00:16:3e:5f:b5:e2', 'uuid': 'a8ae9cf7-c140-1ce7-ae07-cd511164da8f'})}, 'vcpu_avail': 1, 'VCPUs_live': 1, 'PV_bootloader': '', 'actions_after_crash': 'restart', 'vbd_refs': ['ff1c2855-0e9e-88f5-a9e7-821d56b3bc35', 'ff08d6d9-45ca-0f96-4ac0-f05152e73289'], 'PV_ramdisk': '', 'is_control_domain': False, 'name_label': 'f10-test', 'VCPUs_at_startup': 1, 'HVM_boot_params': {'order': 'c'}, 'platform': {'usb': '1', 'device_model': '/usr/lib/xen/bin/qemu-dm', 'boot': 'c', 'pae': '1', 'apic': '1', 'serial': 'pty', 'acpi': '1'}, 'cpu_weight': 256, 'console_refs': ['2566ddf3-95dd-b2a2-4715-d22954e52f64'], 'cpu_cap': 0, 'on_xend_stop': 'ignore', 'memory_static_min': 0, 'HVM_boot_policy': 'BIOS order', 'VCPUs_max': 1, 'memory_static_max': 536870912, 'actions_after_shutdown': 'destroy', 'on_xend_start': 'ignore', 'memory_dynamic_max': 268435456, 'actions_after_suspend': '', 'is_a_template': False, 'memory_dynamic_min': 268435456, 'uuid': '98d26dc6-0147-b760-91b8-7d6f2f4a5102', 'PV_kernel': '/usr/lib/xen/boot/hvmloader', 'shadow_memory': 0, 'PV_bootloader_args': '', 'other_config': {}, 'actions_after_reboot': 'restart', 'vif_refs': ['a8ae9cf7-c140-1ce7-ae07-cd511164da8f'], 'vtpm_refs': [], 'security': None})
[2008-12-02 13:35:19 3067] DEBUG (XendDomain:964) Creating new managed domain: f10-test


On the HOST, there is a traceback in xend-debug.log:

Traceback (most recent call last):
  File "/usr/lib/python2.5/site-packages/xen/web/httpserver.py", line 140, in process
    resource = self.getResource()
  File "/usr/lib/python2.5/site-packages/xen/web/httpserver.py", line 172, in getResource
    return self.getServer().getResource(self)
  File "/usr/lib/python2.5/site-packages/xen/web/httpserver.py", line 351, in getResource
    return self.root.getRequestResource(req)
  File "/usr/lib/python2.5/site-packages/xen/web/resource.py", line 39, in getRequestResource
    return findResource(self, req)
  File "/usr/lib/python2.5/site-packages/xen/web/resource.py", line 26, in findResource
    next = resource.getPathResource(pathElement, request)
  File "/usr/lib/python2.5/site-packages/xen/web/resource.py", line 49, in getPathResource
    val = self.getChild(path, request)
  File "/usr/lib/python2.5/site-packages/xen/web/SrvDir.py", line 71, in getChild
    val = self.get(x)
  File "/usr/lib/python2.5/site-packages/xen/xend/server/SrvDomainDir.py", line 52, in get
    return self.domain(x)
  File "/usr/lib/python2.5/site-packages/xen/xend/server/SrvDomainDir.py", line 44, in domain
    dom = self.xd.domain_lookup(x)
  File "/usr/lib/python2.5/site-packages/xen/xend/XendDomain.py", line 524, in domain_lookup
    raise XendInvalidDomain(str(domid))
XendInvalidDomain: <Fault 3: 'f10-test'>
Comment 4 Jonathan S. Shapiro 2008-12-02 19:57:54 UTC 
Oh. I should have added that all of the firstboot stuff proceeds normally if the machine is simply "hard booted" at the point of hang.
Comment 5 Jonathan S. Shapiro 2008-12-02 20:03:33 UTC 
Created attachment 325418 [details]
install.log from hanging install
Comment 6 Jonathan S. Shapiro 2008-12-02 20:04:34 UTC 
Created attachment 325420 [details]
anaconda-ks.cfg from the hanging install

rootpw line has been removed so as not to invite password cracking.
Comment 7 Jonathan S. Shapiro 2008-12-02 20:09:16 UTC 
Idle thought.

It actually looks to me like the install is completing successfully. No fsck is being run on reboot, and the boot block is clearly getting written correctly, or the guest system wouldn't reboot at all. I also don't see any selinux diagnostics that look even remotely relevant.

Could this be something as mundane as the "eject" call on the simulated DVD hanging for some reason?
Comment 8 Chris Lumens 2008-12-02 20:26:09 UTC 
I suppose that's possible.  I know we have a bug for F10 about not being able to eject the DVD.  I can't speak to the xen implications of this, however.
Comment 9 Jonathan S. Shapiro 2008-12-02 21:05:13 UTC 
Just finished re-running the VM setup with selinux in permissive mode. No change, so I don't think that is the culprit.

At least it's reproducible. :-)
Comment 10 Russell Doty 2008-12-03 01:53:59 UTC 
Interesting note - I filed the original bug report against kvm.

Jonathan seems to be using Xen.

Should we turn this into two separate bugs, one for kvm and one for xen? Or does the fact that we are seeing the same problem indicate that it might be hypervisor agnostic?
Comment 11 David Huff 2009-03-24 21:36:00 UTC 
Im also seeing the same thing on native KVM both 32 and 64 bit.... same thing, if you force shut-down image appears to come up fine and run through firstboot....
 
I am also seeing this in both graphical and text install...

reproducer: 

qemu-kvm -name 'testvm' -serial stdio -drive file=fc10-64.qcow2,if=ide,boot=on -net nic,vlan=0 -net user,vlan=0 -m 512 -cdrom isos/linux/Fedora-10-x86_64-DVD.iso -fda floppy.img -boot d -no-kvm-irqchip

boot with console=ttyS0,115022n8 ks=floppy
Comment 12 David Huff 2009-03-24 21:37:52 UTC 
Created attachment 336550 [details]
floppy dirve img with ks.cfg
Comment 13 David Huff 2009-03-24 22:23:33 UTC 
Ok, this looks to be a qcow2 issue not an anaconda issue, issue is not reproducible with a raw disk image....
Comment 14 Gerry Reno 2009-03-28 20:14:18 UTC 
We just encountered this issue this morning on a physical machine upgrade to F10 using the F10 DVD ISO.  The upgrade completes all the way to the point of installing the PAE kernel and then it just sits there with the little icon spinning.

After a good while we just rebooted the machine and it boots up but some of the services like nfs do not start.  And I see some selinux errors.  Ran /sbin/fixfiles relabel but it is complaining about permission denied to certain directories.

So it looks like the anaconda post-install scripts did not run and the bootloader was not modified because it still has the "Upgrade to F10(Cambridge)" entry.
Comment 15 Gerry Reno 2009-03-28 20:27:57 UTC 
P.S.  This was using the F10 i386 DVD ISO.
Comment 16 Gerry Reno 2009-03-28 21:31:49 UTC 
P.P.S.  And it was for a 32-bit install on 64-bit physical hardware.
Comment 17 Gerry Reno 2009-03-28 22:21:23 UTC 
Ok, in our case we did a 'yum update' which brought in a new selinux-policy-targeted and that fixed selinux.  Then we edited /boot/grub/grub.conf and fixed the boot entries.  We rebooted the machine and everything appears working normally now.

But the problem with the anaconda is still there and I"m sure will bother us again.
Comment 18 Chris Lumens 2009-08-21 15:35:03 UTC 
Can the original reporter still reproduce this problem with F11 or perhaps later?  I've never run into this problem before and therefore cannot reproduce, which makes it difficult to debug.
Comment 19 Joel Andres Granados 2009-09-09 09:15:36 UTC 
ping, is this still relevant for f12 alpha?
Comment 20 Russell Doty 2009-09-09 13:50:05 UTC 
I haven't run into this issue with F11 or with F12 Alpha.