Bug 577196 - Freeze when installing bootloader
Summary: Freeze when installing bootloader
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Fedora
Classification: Fedora
Component: anaconda
Version: 13
Hardware: All
OS: Linux
low
medium
Target Milestone: ---
Assignee: Anaconda Maintenance Team
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks: F13Beta, F13BetaBlocker
TreeView+ depends on / blocked
 
Reported: 2010-03-26 12:37 UTC by Kamil Páral
Modified: 2013-01-10 05:48 UTC (History)
9 users (show)

Fixed In Version: anaconda-13.37.2-1.fc13
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2010-03-31 13:50:37 UTC


Attachments (Terms of Use)
screen when freezing occurs (102.10 KB, image/png)
2010-03-26 12:37 UTC, Kamil Páral
no flags Details
anaconda-logs.tgz (56.29 KB, application/x-gzip)
2010-03-26 14:56 UTC, James Laska
no flags Details
anaconda-logs.tgz (62.41 KB, application/x-gzip)
2010-03-26 15:28 UTC, James Laska
no flags Details

Description Kamil Páral 2010-03-26 12:37:49 UTC
Created attachment 402834 [details]
screen when freezing occurs

Description of problem:
Installing Fedora 13 Beta RC1 x86_64 from DVD:
http://serverbeach1.fedoraproject.org/pub/alt/stage/13-Beta.RC1/
Standard default install next-next-next in KVM, tried both Graphical and Minimal package set.

The installation always freezes with dialog "Installing bootloader" (see screenshot). The system is hard frozen, nothing helps.

Once I have seen getting black screen instead, mouse cursor worked. After an attempt to switch to VT1 the system froze.

I attached serial console to the virtual machine, but nothing is printed out before or during the freeze.

Any ideas how to gather more information?

Version-Release number of selected component (if applicable):
Fedora 13 Beta RC1 x86_64
anaconda 13.37

How reproducible:
3 attempts froze, 1 attempt got black screen and then froze

Comment 1 James Laska 2010-03-26 13:10:19 UTC
If I setup utelnetd to access the system and watch the logs before the hang occurs, I see the following information...


13:04:57,084 ERR kernel:end_request: I/O error, dev sr0, sector 181068
13:04:57,086 INFO kernel:sr 1:0:0:0: [sr0] Device not ready
13:04:57,086 INFO kernel:sr 1:0:0:0: [sr0] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
13:04:57,086 INFO kernel:sr 1:0:0:0: [sr0] Sense Key : Not Ready [current] 
13:04:57,086 WARN kernel:Info fld=0x0
13:04:57,086 INFO kernel:sr 1:0:0:0: [sr0] Add. Sense: Medium not present
13:04:57,086 INFO kernel:sr 1:0:0:0: [sr0] CDB: Read(10): 28 00 00 00 b0 d5 00 00 02 00
13:04:57,086 ERR kernel:end_request: I/O error, dev sr0, sector 181076
13:04:57,089 INFO kernel:sr 1:0:0:0: [sr0] Device not ready
13:04:57,089 INFO kernel:sr 1:0:0:0: [sr0] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
13:04:57,089 INFO kernel:sr 1:0:0:0: [sr0] Sense Key : Not Ready [current] 
13:04:57,089 WARN kernel:Info fld=0x0
13:04:57,089 INFO kernel:sr 1:0:0:0: [sr0] Add. Sense: Medium not present
13:04:57,089 INFO kernel:sr 1:0:0:0: [sr0] CDB: Read(10): 28 00 00 00 b0 d5 00 00 02 00
13:04:57,089 ERR kernel:end_request: I/O error, dev sr0, sector 181076
13:04:57,091 INFO kernel:sr 1:0:0:0: [sr0] Device not ready
13:04:57,091 INFO kernel:sr 1:0:0:0: [sr0] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
13:04:57,091 INFO kernel:sr 1:0:0:0: [sr0] Sense Key : Not Ready [current] 
13:04:57,091 WARN kernel:Info fld=0x0
13:04:57,091 INFO kernel:sr 1:0:0:0: [sr0] Add. Sense: Medium not present
13:04:57,091 INFO kernel:sr 1:0:0:0: [sr0] CDB: Read(10): 28 00 00 00 b0 d5 00 00 02 00
13:04:57,091 ERR kernel:end_request: I/O error, dev sr0, sector 181076
13:04:57,094 INFO kernel:sr 1:0:0:0: [sr0] Device not ready
13:04:57,094 INFO kernel:sr 1:0:0:0: [sr0] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
13:04:57,094 INFO kernel:sr 1:0:0:0: [sr0] Sense Key : Not Ready [current] 
13:04:57,094 WARN kernel:Info fld=0x0
13:04:57,094 INFO kernel:sr 1:0:0:0: [sr0] Add. Sense: Medium not present
13:04:57,094 INFO kernel:sr 1:0:0:0: [sr0] CDB: Read(10): 28 00 00 00 b0 d5 00 00 02 00
13:04:57,094 ERR kernel:end_request: I/O error, dev sr0, sector 181076
13:04:57,098 INFO kernel:sr 1:0:0:0: [sr0] Device not ready
13:04:57,098 INFO kernel:sr 1:0:0:0: [sr0] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
13:04:57,098 INFO kernel:sr 1:0:0:0: [sr0] Sense Key : Not Ready [current] 
13:04:57,098 WARN kernel:Info fld=0x0
13:04:57,098 INFO kernel:sr 1:0:0:0: [sr0] Add. Sense: Medium not present
13:04:57,098 INFO kernel:sr 1:0:0:0: [sr0] CDB: Read(10): 28 00 00 00 b0 a5 00 00 02 00
13:04:57,098 ERR kernel:end_request: I/O error, dev sr0, sector 180884
13:04:57,098 ERR kernel:SQUASHFS error: squashfs_read_data failed to read block 0x35a53b8
13:04:57,098 ERR kernel:SQUASHFS error: Unable to read data cache entry [35a53b8]
13:04:57,098 ERR kernel:SQUASHFS error: Unable to read page, block 35a53b8, size a9b3

Could this be a problem introduced by the fix for bug#569377?

Comment 2 Kamil Páral 2010-03-26 13:15:25 UTC
When I install from netinst.iso from HTTP or NFS repo, no freezes occur.

Comment 3 Chris Lumens 2010-03-26 14:23:12 UTC
Well, the netinst.iso is a completely different image, with much less data, on a completely different piece of physical media.  Did you run media check on the original DVD before installation?

Comment 4 James Laska 2010-03-26 14:34:21 UTC
(In reply to comment #3)
> Well, the netinst.iso is a completely different image, with much less data, on
> a completely different piece of physical media.  Did you run media check on the
> original DVD before installation?    

Yeah, the DVD passed media check.

Comment 5 James Laska 2010-03-26 14:56:46 UTC
Created attachment 402862 [details]
anaconda-logs.tgz

-rw-rw-r-- jlaska/jlaska 27721 2010-03-26 09:21 tmp/minimon/anaconda.log
-rw-rw-r-- jlaska/jlaska  7903 2010-03-26 09:21 tmp/minimon/install.log
-rw-rw-r-- jlaska/jlaska 39675 2010-03-26 09:21 tmp/minimon/program.log
-rw-rw-r-- jlaska/jlaska 180088 2010-03-26 09:21 tmp/minimon/storage.log
-rw-rw-r-- jlaska/jlaska 134937 2010-03-26 09:25 tmp/minimon/syslog
-rw-rw-r-- jlaska/jlaska  26577 2010-03-26 09:21 tmp/minimon/X.log
-rw-rw-r-- jlaska/jlaska  25341 2010-03-26 09:17 tmp/minimon/yum.log

Comment 6 James Laska 2010-03-26 15:28:01 UTC
Created attachment 402867 [details]
anaconda-logs.tgz

Comment 7 Peter Jones 2010-03-26 15:34:07 UTC
in storage.log:
11:20:29,077 DEBUG storage: looking for device 'sr0'...
11:20:29,082 DEBUG storage:                 OpticalDevice.mediaPresent: sr0 ; status: True ;
11:20:29,089 DEBUG storage:                 Iso9660FS.supported: supported: True ;
11:20:29,089 DEBUG storage: found OpticalDevice instance (0x7ffb548544d0) --
  name = sr0  status = True  parents = []
  kids = 0
  id = 2 
  uuid = None  format = <storage.formats.fs.Iso9660FS object at 0x7ffb54854390>  size = 3606.58203125
  major = 11  minor = 0  exists = True
  sysfs path = /devices/pci0000:00/0000:00:01.1/host1/target1:0:0/1:0:0:0/block/sr0  partedDevice = <parted.device.Device object at 0x7ffb3e682250>
  target size = 0  path = /dev/sr0 
  format args = []  originalFormat = Iso9660FS instance (0x7ffb54854390) --
  type = iso9660  name = iso9660  status = True
  device = /dev/sr0  uuid = None  exists = True
  options = ro  supported = True  formattable = False  resizable = False
  mountpoint = None  mountopts = None
  label = Fedora_13-Beta_x86_64_DVD  size = 0  targetSize = 0
  
11:20:29,092 DEBUG storage:            OpticalDevice.eject: sr0 ; status: True ;
11:20:29,094 DEBUG storage:             OpticalDevice.teardown: sr0 ; status: True ;

And at the same time (GMT though) in syslog:
15:20:29,282 ERR kernel:ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 
15:20:29,282 ERR kernel:ata2.00: BMDMA stat 0x5 
15:20:29,282 INFO kernel:sr 1:0:0:0: [sr0] CDB: Read(10): 28 00 00 00 eb 75 00 00 02 00
15:20:29,283 ERR kernel:ata2.00: cmd a0/01:00:00:00:10/00:00:00:00:00/a0 tag 0 dma 4096 in
15:20:29,283 ERR kernel:         res 01/60:00:00:00:10/00:00:00:00:00/a0 Emask 0x3 (HSM violation)
15:20:29,283 ERR kernel:ata2.00: status: { ERR }
15:20:29,283 INFO kernel:ata2: soft resetting link
15:20:29,435 DEBUG kernel:ata2.01: NODEV after polling detection
15:20:29,436 INFO kernel:ata2.00: configured for MWDMA2
15:20:29,439 INFO kernel:ata2: EH complete
15:20:29,439 INFO kernel:sr 1:0:0:0: [sr0] Device not ready
15:20:29,440 INFO kernel:sr 1:0:0:0: [sr0] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
15:20:29,440 INFO kernel:sr 1:0:0:0: [sr0] Sense Key : Not Ready [current]

Comment 8 Peter Jones 2010-03-26 15:34:55 UTC
So, that definitely looks like we wouldn't see it without the eject fix, but it doesn't look like the eject fix is the actual /cause/ of the problem. It merely enables the real bug to show through.

Comment 9 David Lehman 2010-03-26 17:11:58 UTC
This was reported from a virt install (disks in storage.log are vda, vdb). The original eject bug (bug 569377) did not even manifest in virt. We should find out if this happens on real hardware.

Comment 10 Adam Williamson 2010-03-26 21:57:56 UTC
So we've been doing some real hardware tests. Seems sometimes we can reproduce, sometimes not.

Here's my result:

I tested installing to a 4GB USB stick, to save messing up my real disk at all. So at the disk selection stage, I picked only the USB drive. I then picked 'use entire disk', but also 'review and modify layout'. The layout it chose was a 500MB /boot, with the rest of the disk as an LVM, with a 2GB swap partition and the rest - 1.5GB -as / . I changed this to be just a 400GB /boot partition and the rest of the disk as a / partition: no LVM, no swap partition.

I chose the minimal package set, to make sure it'd fit on the stick and to make the install process quicker.

This test succeeded: it didn't hit the bug. The install process completed, ejected the DVD, and displayed the 'yay we're done' screen. The installed system on the USB stick boots fine. I can provide anaconda logs from the stick if desired.

Jesse's been testing also, if he could add his results on this thread it'd be great.



-- 
Fedora Bugzappers volunteer triage team
https://fedoraproject.org/wiki/BugZappers

Comment 11 Jesse Keating 2010-03-26 23:06:26 UTC
I've discovered a pattern.

If the install either involves installing to LVM or the disks were part of a pre-existing LVM I get the hang at the end.

If the disks were not involved in a previous LVM, and if the install is to a non-LVM setup, there is no hang at the end.

My conclusion is that the existence of LVM is what's causing this to fall over.

Comment 12 Jesse Keating 2010-03-26 23:06:47 UTC
Further data, I've been doing all this testing with bios raid, so it's not device-mapper.

Comment 13 Adam Williamson 2010-03-26 23:39:17 UTC
as discussed on IRC, I just tested - again installing to my 4GB USB key - using auto-partitioning. I zero'ed the key before doing the install. Auto-partitioning definitely set up an LVM, I checked that at the console. Again the install completed successfully, no bug. I was using the minimal package set again. I'll try doing an install over the now-LVM'ed stick and see what happens with that.



-- 
Fedora Bugzappers volunteer triage team
https://fedoraproject.org/wiki/BugZappers

Comment 14 He Rui 2010-03-30 11:09:36 UTC
I did some tests on this issue using F13-beta-rc1-x86_64-DVD.iso.

1. In virt-install, it hanged at installing bootloader and was 100% reproducible no matter it's minimal or graphical, lvm or no lvm...

2. On bare metal, the screen hanged after it ejected the DVD and the screen(tty6) hanged with black screen. As far as I tested, it didn't happen in minimal install. Then I used the same ext4 partitions(/ and /boot) to install it only with package differences:

a. Minimal install - pass.
b. gnome + office + base + xwindow - pass
c. graphical default - fail
 
The failure info on tty3:
...
INFO anaconda: leaving (1) step dopostaction
INFO anaconda: moving (1) to step complete
WARNING anaconda: /usr/lib/anaconda/gui.py:1533: GTKWarning: Error loading theme icon 'gtk-quit' for stock: Error reading from file: Input/output error 
_

Info on tty5 :
...
GNU GRUB version 0.97 (640K lower / 3072K upper memory)

[ Minimal BASH-like line editing is supported. For the first word, TAB lists possible command completions. Anywhere else TAB lists the possible completions of a device/filename.]

grub> root (hd0,4)
Filesystem type is ext2fs, partition type 0x83
grub> install --stage2=/boot/grub/stage2 /grub/stage1 d (hd0) /grub/stage2 p (hd0,4)/grub/grub.conf
grub>
Backtrace:

Comment 15 Fedora Update System 2010-03-31 03:13:57 UTC
anaconda-13.37.1-1.fc13 has been submitted as an update for Fedora 13.
http://admin.fedoraproject.org/updates/anaconda-13.37.1-1.fc13

Comment 16 Liam Li 2010-03-31 10:08:06 UTC
I tested on anaconda 13.37.1, it has been fixed.

Comment 17 James Laska 2010-03-31 13:50:14 UTC
Closing this issue based on feedback from Liam (comment#16) and additional F-13-Beta-RC2 test results

Comment 18 Fedora Update System 2010-04-01 00:46:47 UTC
anaconda-13.37.2-1.fc13 has been submitted as an update for Fedora 13.
http://admin.fedoraproject.org/updates/anaconda-13.37.2-1.fc13

Comment 19 Fedora Update System 2010-04-01 04:59:51 UTC
anaconda-13.37.2-1.fc13 has been pushed to the Fedora 13 stable repository.  If problems still persist, please make note of it in this bug report.


Note You need to log in before you can comment on or make changes to this bug.