Attachment 302567 Details for Bug 442685 – anaconda.log

anaconda.log

anaconda.log (text/plain), 13.32 KB, created by Mark McLoughlin on 2008-04-16 09:30:20 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Mark McLoughlin

Created: 2008-04-16 09:30:20 UTC

Size: 13.32 KB

patch

obsolete

>07:54:13 INFO    : kernel command line: ks=http://172.31.0.3/x86-64-xen-guest-ks.cfg 
>
>07:54:13 INFO    : anaconda version 11.4.0.71 on x86_64 starting
>07:54:13 INFO    : 509728 kB are available
>07:54:13 DEBUG   : probing buses
>07:54:13 DEBUG   : waiting for hardware to initialize
>07:54:14 INFO    : getting kickstart file
>07:54:14 INFO    : only have one network device: eth0
>07:54:14 INFO    : sending dhcp request through device eth0
>07:54:14 DEBUG   : waiting for link eth0...
>07:54:14 DEBUG   :    0 seconds.
>07:54:14 DEBUG   : sleep (nicdelay) for 0 secs first
>07:54:14 DEBUG   : continuing...
>07:54:14 DEBUG   : sending anaconda-Linux 2.6.25-0.24.rc9.fc9.x86_64.xen x86_64 as dhcp vendor-class
>requesting dhcp timeout 45
>07:54:14 INFO    : Listening on LPF/eth0/00:16:3e:6c:05:01
>07:54:14 INFO    : Sending on   LPF/eth0/00:16:3e:6c:05:01
>07:54:14 INFO    : Sending on   Socket/fallback
>07:54:16 INFO    : DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 5
>07:54:16 INFO    : DHCPOFFER from 172.31.0.1
>07:54:16 INFO    : DHCPREQUEST on eth0 to 255.255.255.255 port 67
>07:54:16 INFO    : DHCPACK from 172.31.0.1
>07:54:16 INFO    : bound to 172.31.0.101 -- renewal in 98705 seconds.
>07:54:16 INFO    : doing kickstart... setting it up
>07:54:16 DEBUG   : waiting for link eth0...
>07:54:16 DEBUG   :    0 seconds.
>07:54:16 DEBUG   : sleep (nicdelay) for 0 secs first
>07:54:16 DEBUG   : continuing...
>07:54:17 WARNING : reverse name lookup of 172.31.0.101 failed
>07:54:17 DEBUG   : getHostandPath host: |172.31.0.3|
>07:54:17 DEBUG   : getHostandPath file(1): |/x86-64-xen-guest-ks.cfg|
>07:54:17 INFO    : file location: http://172.31.0.3/x86-64-xen-guest-ks.cfg
>07:54:17 INFO    : transferring http://172.31.0.3/x86-64-xen-guest-ks.cfg to a fd
>07:54:17 INFO    : setting up kickstart
>07:54:17 INFO    : kickstartFromUrl
>07:54:17 INFO    : results of url ks, url http://ftp.heanet.ie/pub/fedora/linux/development/x86_64/os/
>07:54:17 DEBUG   : going to set language to en_US.UTF-8
>07:54:17 INFO    : setting language to en_US.UTF-8
>07:54:17 INFO    : need to set up networking
>07:54:17 INFO    : going to pick interface
>07:54:17 INFO    : going to do getNetConfig
>07:54:17 INFO    : setting specified hostname of test64
>07:54:17 INFO    : eth0 is not a wireless adapter
>07:54:17 DEBUG   : waiting for link eth0...
>07:54:17 DEBUG   :    0 seconds.
>07:54:17 DEBUG   : sleep (nicdelay) for 0 secs first
>07:54:17 DEBUG   : continuing...
>07:54:17 DEBUG   : sending anaconda-Linux 2.6.25-0.24.rc9.fc9.x86_64.xen x86_64 as dhcp vendor-class
>requesting dhcp timeout 45
>07:54:20 INFO    : DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 8
>07:54:20 INFO    : DHCPOFFER from 172.31.0.1
>07:54:20 INFO    : DHCPREQUEST on eth0 to 255.255.255.255 port 67
>07:54:20 INFO    : DHCPACK from 172.31.0.1
>07:54:20 INFO    : bound to 172.31.0.101 -- renewal in 115160 seconds.
>07:54:20 DEBUG   : device = eth0
>07:54:20 DEBUG   : broadcast = 172.31.0.255
>07:54:20 DEBUG   : netmask = 255.255.255.0
>07:54:20 DEBUG   : network = 172.31.0.0
>07:54:20 DEBUG   : gateway = 172.31.0.1
>07:54:20 DEBUG   : dns[0] = 172.31.0.1
>07:54:20 ERROR   : add: failed - 17: Netlink Error (errno = File exists)
>07:54:20 DEBUG   : waiting for link eth0...
>07:54:20 DEBUG   :    0 seconds.
>07:54:20 DEBUG   : sleep (nicdelay) for 0 secs first
>07:54:20 DEBUG   : continuing...
>07:54:20 WARNING : reverse name lookup of 172.31.0.101 failed
>07:54:20 INFO    : starting to STEP_URL
>07:54:20 INFO    : URL_STAGE_MAIN - url is http://ftp.heanet.ie/pub/fedora/linux/development/x86_64/os/
>07:54:20 DEBUG   : url address ftp.heanet.ie
>07:54:20 DEBUG   : url prefix /pub/fedora/linux/development/x86_64/os/
>07:54:20 ERROR   : got to setupCdrom without a CD device
>07:54:20 INFO    : transferring http://ftp.heanet.ie/pub/fedora/linux/development/x86_64/os//images/updates.img to a fd
>07:54:23 INFO    : transferring http://ftp.heanet.ie/pub/fedora/linux/development/x86_64/os//images/product.img to a fd
>07:54:25 INFO    : 509728 kB are available
>07:54:25 INFO    : transferring http://ftp.heanet.ie/pub/fedora/linux/development/x86_64/os//images/stage2.img to a fd
>08:01:26 DEBUG   : copied 109707264 bytes to /tmp/stage2.img (complete)
>08:01:26 INFO    : mounted loopback device /mnt/runtime on /dev/loop0 as /tmp/stage2.img
>08:01:26 INFO    : got url http://ftp.heanet.ie/pub/fedora/linux/development/x86_64/os/
>08:01:26 INFO    : Loading SELinux policy
>08:01:26 INFO    : getting ready to spawn shell now
>08:01:27 INFO    : Running anaconda script /usr/bin/anaconda
>08:01:28 INFO    : using only installclass _Fedora
>08:01:28 INFO    : Starting message bus...
>08:01:33 INFO    : Starting HAL daemon...
>08:01:38 WARNING : /usr/lib/python2.5/site-packages/pykickstart/parser.py:594: DeprecationWarning: %packages does not end with %end.  This syntax has been deprecated.  It may be removed from future releases, which will result in a fatal error from kickstart.  Please modify your kickstart file to use this updated syntax.
>  warnings.warn(_("%s does not end with %%end.  This syntax has been deprecated.  It may be removed from future releases, which will result in a fatal error from kickstart.  Please modify your kickstart file to use this updated syntax.") % "%packages", DeprecationWarning)
>
>08:01:38 INFO    : anaconda called with cmdline = ['/usr/bin/anaconda', '-m', 'http://ftp.heanet.ie/pub/fedora/linux/development/x86_64/os/', '--graphical', '--selinux', '--kickstart', '/tmp/ks.cfg', '--lang', 'en_US.UTF-8', '--keymap', 'uk']
>08:01:38 INFO    : Display mode = g
>08:01:38 INFO    : Method = http://ftp.heanet.ie/pub/fedora/linux/development/x86_64/os/
>08:01:46 INFO    : Started mini-wm
>08:01:46 INFO    : Starting graphical installation...
>08:01:47 DEBUG   : starting mpaths
>08:01:47 DEBUG   : self.driveList(): [u'xvda']
>08:01:47 DEBUG   : DiskSet.skippedDisks: []
>08:01:47 DEBUG   : DiskSet.skippedDisks: []
>08:01:47 DEBUG   : starting all mpaths on drives [u'xvda']
>08:01:47 DEBUG   : scanning for multipath on drives [u'xvda']
>08:01:47 DEBUG   : loading bdevid modules from: '/tmp/updates/bdevid/:/mnt/source/RHupdates/bdevid/:/lib64/bdevid/:/usr/lib64/bdevid/'
>08:01:47 DEBUG   : mpaths: []
>08:01:47 DEBUG   : done starting mpaths.  Drivelist: [u'xvda']
>08:01:47 DEBUG   : starting dmraids
>08:01:47 DEBUG   : self.driveList(): [u'xvda']
>08:01:47 DEBUG   : DiskSet.skippedDisks: []
>08:01:47 DEBUG   : DiskSet.skippedDisks: []
>08:01:47 DEBUG   : starting all dmraids on drives [u'xvda']
>08:01:47 DEBUG   : scanning for dmraid on drives [u'xvda']
>08:01:47 DEBUG   : done starting dmraids.  Drivelist: [u'xvda']
>08:01:47 WARNING : step installtype does not exist
>08:01:47 WARNING : step confirminstall does not exist
>08:01:47 WARNING : step complete does not exist
>08:01:47 WARNING : step complete does not exist
>08:01:47 WARNING : step complete does not exist
>08:01:47 WARNING : step complete does not exist
>08:01:47 WARNING : step complete does not exist
>08:01:47 WARNING : step complete does not exist
>08:01:47 WARNING : step complete does not exist
>08:01:47 WARNING : step complete does not exist
>08:01:47 WARNING : step complete does not exist
>08:01:47 INFO    : moving (1) to step networkdevicecheck
>08:01:47 INFO    : moving (1) to step partitionobjinit
>08:01:47 INFO    : no initiator set
>08:01:47 INFO    : no /tmp/fcpconfig; not configuring zfcp
>08:01:48 INFO    : Reinitializing label for drive xvda
>08:01:48 DEBUG   : adding drive xvda to disk list
>08:01:48 INFO    : moving (1) to step autopartitionexecute
>08:01:48 DEBUG   : adding drive xvda to disk list
>08:01:48 DEBUG   : used space is 1552
>08:01:48 DEBUG   : actual space is 9984
>08:01:48 DEBUG   : used space is 2080
>08:01:48 DEBUG   : actual space is 9984
>08:01:48 DEBUG   : used space is 9984
>08:01:48 DEBUG   : actual space is 9984
>08:01:48 DEBUG   : used space is 9984
>08:01:48 DEBUG   : actual space is 9984
>08:01:48 INFO    : moving (1) to step partitiondone
>08:01:48 INFO    : moving (1) to step migratefilesystems
>08:01:48 INFO    : moving (1) to step enablefilesystems
>08:01:48 INFO    : disk.commit() for /dev/xvda
>08:01:48 DEBUG   : adding drive xvda to disk list
>08:01:50 INFO    : formatting swap as swap
>08:01:50 INFO    : formatting / as ext3
>08:01:50 INFO    : Format command:  ['mke2fs', '/dev/VolGroup00/LogVol00', '-j']
>
>08:02:31 INFO    : formatting /boot as ext3
>08:02:31 INFO    : Format command:  ['mke2fs', '/dev/xvda1', '-j']
>
>08:02:34 DEBUG   : adding drive xvda to disk list
>08:02:34 INFO    : lv VolGroup00/LogVol00, attr is -wi-a-
>08:02:34 INFO    : lv is VolGroup00/LogVol00, size of 8928
>08:02:34 INFO    : lv is VolGroup00/LogVol01, size of 1056
>08:02:34 INFO    : trying to mount /dev/VolGroup00/LogVol00 on /
>08:02:34 INFO    : set SELinux context for mountpoint / to False
>08:02:34 DEBUG   : mounting /dev/VolGroup00/LogVol00 on /mnt/sysimage// as ext3
>08:02:34 DEBUG   : isys.py:mount()- going to mount /dev/VolGroup00/LogVol00 on /mnt/sysimage with options defaults
>08:02:34 INFO    : set SELinux context for newly mounted filesystem root at / to False
>08:02:34 INFO    : trying to mount /dev/xvda1 on /boot
>08:02:34 INFO    : set SELinux context for mountpoint /boot to False
>08:02:34 DEBUG   : mounting /dev/xvda1 on /mnt/sysimage//boot as ext3
>08:02:34 DEBUG   : isys.py:mount()- going to mount /dev/xvda1 on /mnt/sysimage/boot with options defaults
>08:02:34 INFO    : set SELinux context for newly mounted filesystem root at /boot to False
>08:02:34 INFO    : trying to mount sys on /sys
>08:02:34 INFO    : set SELinux context for mountpoint /sys to False
>08:02:34 DEBUG   : mounting sys on /mnt/sysimage//sys as sysfs
>08:02:34 DEBUG   : isys.py:mount()- going to mount sys on /mnt/sysimage/sys with options defaults
>08:02:34 INFO    : set SELinux context for newly mounted filesystem root at /sys to False
>08:02:34 INFO    : trying to mount proc on /proc
>08:02:34 INFO    : set SELinux context for mountpoint /proc to False
>08:02:34 DEBUG   : mounting proc on /mnt/sysimage//proc as proc
>08:02:34 DEBUG   : isys.py:mount()- going to mount proc on /mnt/sysimage/proc with options defaults
>08:02:34 INFO    : set SELinux context for newly mounted filesystem root at /proc to False
>08:02:34 INFO    : moving (1) to step bootloadersetup
>08:02:34 INFO    : moving (1) to step reposetup
>08:02:34 INFO    : added repository Additional Fedora Software with URL http://mirrors.fedoraproject.org/mirrorlist?repo=rawhide&arch=x86_64
>08:02:34 INFO    : Using /tmp/stage2.img as stage2 image
>08:03:14 WARNING : /usr/lib/python2.5/site-packages/yum/repos.py:64: RuntimeWarning: YumProgress.progressbar called when popped
>  self.callback.progressbar(num, len(repos), repo.id)
>
>08:03:20 INFO    : no groups missing
>08:03:20 INFO    : moving (1) to step basepkgsel
>08:03:21 INFO    : moving (1) to step postselection
>08:03:21 INFO    : selecting kernel-xen package for kernel
>08:03:43 WARNING : Try 1/10 for http://ftp.heanet.ie/pub/fedora/linux/development/x86_64/os/repodata/filelists.sqlite.bz2 failed
>08:04:00 WARNING : Try 2/10 for http://ftp.heanet.ie/pub/fedora/linux/development/x86_64/os/repodata/filelists.sqlite.bz2 failed
>08:04:49 INFO    : moving (1) to step install
>08:04:49 INFO    : moving (1) to step setuptime
>08:04:49 ERROR   : unable to set timezone
>08:04:52 INFO    : moving (1) to step preinstallconfig
>08:04:53 DEBUG   : isys.py:mount()- going to mount /selinux on /mnt/sysimage/selinux with options defaults
>08:04:53 WARNING : no dev package, going to bind mount /dev
>08:04:53 DEBUG   : isys.py:mount()- going to mount /dev on /mnt/sysimage/dev with options defaults,bind
>08:04:53 INFO    : self.hostname = test64
>08:04:54 INFO    : moving (1) to step installpackages
>08:04:54 INFO    : Preparing to install packages
>08:34:23 WARNING : /usr/lib/anaconda/iw/progress_gui.py:56: GtkWarning: gtk_progress_set_percentage: assertion `percentage >= 0 && percentage <= 1.0' failed
>  self.progress.set_fraction(pct)
>
>08:34:24 INFO    : moving (1) to step postinstallconfig
>08:34:24 INFO    : moving (1) to step writeconfig
>08:34:24 INFO    : Writing main configuration
>08:34:25 INFO    : self.hostname = test64
>08:34:27 INFO    : moving (1) to step firstboot
>08:34:27 INFO    : moving (1) to step instbootloader
>08:34:27 INFO    : vg VolGroup00, size is 10016, pesize is 32768
>08:34:27 INFO    : vg VolGroup00, size is 10016, pesize is 32768
>08:34:27 INFO    : vg VolGroup00, size is 10016, pesize is 32768
>08:34:27 INFO    : vg VolGroup00, size is 10016, pesize is 32768
>08:34:28 INFO    : Running kickstart %%traceback script(s)
>08:34:28 INFO    : All kickstart %%traceback script(s) have been run
>08:34:28 CRITICAL: anaconda 11.4.0.71 exception report
>Traceback (most recent call first):
>  File "/usr/lib64/python2.5/site-packages/rhpl/executil.py", line 81, in execWithRedirect
>    os.execv(command, argv)
>  File "/usr/lib/booty/bootloaderInfo.py", line 666, in runGrubInstall
>  File "/usr/lib/booty/bootloaderInfo.py", line 690, in installGrub
>  File "/usr/lib/booty/bootloaderInfo.py", line 1229, in installGrub
>  File "/usr/lib/booty/bootloaderInfo.py", line 925, in writeGrub
>  File "/usr/lib/booty/bootloaderInfo.py", line 1108, in write
>  File "/usr/lib/booty/bootloaderInfo.py", line 1216, in write
>  File "/usr/lib/anaconda/bootloader.py", line 229, in writeBootloader
>  File "/usr/lib/anaconda/dispatch.py", line 208, in moveStep
>  File "/usr/lib/anaconda/dispatch.py", line 131, in gotoNext
>  File "/usr/lib/anaconda/gui.py", line 1259, in nextClicked
>  File "/usr/lib/anaconda/iw/progress_gui.py", line 80, in renderCallback
>  File "/usr/lib/anaconda/gui.py", line 1280, in handleRenderCallback
>OSError: [Errno 8] Exec format error
>

Actions: View

Attachments on bug 442685: 302567 | 303163