[Date Prev][Date Next] [Thread Prev][Thread Next] [Date Index] [Thread Index]

Bug#714959: linux-image-3.2.0-4-kirkwood mdraid array fails to assemble b/c drives are not yet ready (sata_mv)



I tried stable wheezy with kernel 3.2.0-4-kirkwood on my QNAP TS-412 (logs attached) and unstable as of 13.03.2014 (sorry, didn’t remember kernel version) with same result.
The «delayroot» boot argument set to 20 sec helped me.
In a few days will try latest kernel and report then.


         __  __                      _ _
        |  \/  | __ _ _ ____   _____| | |
        | |\/| |/ _` | '__\ \ / / _ \ | |
        | |  | | (_| | |   \ V /  __/ | |
        |_|  |_|\__,_|_|    \_/ \___|_|_|
 _   _     ____              _
| | | |   | __ )  ___   ___ | |_ 
| | | |___|  _ \ / _ \ / _ \| __| 
| |_| |___| |_) | (_) | (_) | |_ 
 \___/    |____/ \___/ \___/ \__|  ** LOADER **
 ** MARVELL BOARD: DB-88F6281A-BP LE 

U-Boot 1.1.4 (Oct 27 2010 - 16:50:30) Marvell version: 3.4.4

U-Boot code: 00600000 -> 0067FFF0  BSS: -> 00690DCC

Soc: MV88F6281 Rev 3 (DDR2)
CPU running @ 1200Mhz L2 running @ 400Mhz
SysClock = 400Mhz , TClock = 200Mhz 

DRAM CAS Latency = 5 tRP = 6 tRAS = 18 tRCD=6
DRAM CS[0] base 0x00000000   size 256MB 
DRAM Total size 256MB  16bit width
[16384kB@f8000000] Flash: 16 MB
Addresses 8M - 0M are saved for the U-Boot usage.
Mem malloc Initialization (8M - 7M): Done

CPU : Marvell Feroceon (Rev 1)


USB 0: host mode
PCI 0: PCI Express Root Complex Interface
PEX interface detected Link X1
Net:   egiga0 [PRIME], egiga1
Hit any key to stop autoboot:  0 
Unknown command 'uart1' - try 'help'
## Booting image at 00800000 ...
   Image Name:   kernel 3.2.0-4-kirkwood
   Created:      2014-03-13  15:07:08 UTC
   Image Type:   ARM Linux Kernel Image (uncompressed)
   Data Size:    1610768 Bytes =  1.5 MB
   Load Address: 00008000
   Entry Point:  00008000
   Verifying Checksum ... OK
OK

Starting kernel ...

Uncompressing Linux... done, booting the kernel.
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpu
[    0.000000] Linux version 3.2.0-4-kirkwood (debian-kernel@lists.debian.org) (gcc version 4.6.3 (Debian 4.6.3-14) ) #1 Debian 3.2.54-2
[    0.000000] CPU: Feroceon 88FR131 [56251311] revision 1 (ARMv5TE), cr=00053977
[    0.000000] CPU: VIVT data cache, VIVT instruction cache
[    0.000000] Machine: QNAP TS-41x
[    0.000000] Ignoring unrecognised tag 0x41000403
[    0.000000] Memory policy: ECC disabled, Data cache writeback
[    0.000000] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 65024
[    0.000000] Kernel command line: console=ttyS0,115200 root=/dev/ram initrd=0xa00000,0x900000 ramdisk=34816
[    0.000000] PID hash table entries: 1024 (order: 0, 4096 bytes)
[    0.000000] Dentry cache hash table entries: 32768 (order: 5, 131072 bytes)
[    0.000000] Inode-cache hash table entries: 16384 (order: 4, 65536 bytes)
[    0.000000] Memory: 256MB = 256MB total
[    0.000000] Memory: 245868k/245868k available, 16276k reserved, 0K highmem
[    0.000000] Virtual kernel memory layout:
[    0.000000]     vector  : 0xffff0000 - 0xffff1000   (   4 kB)
[    0.000000]     fixmap  : 0xfff00000 - 0xfffe0000   ( 896 kB)
[    0.000000]     vmalloc : 0xd0800000 - 0xfe800000   ( 736 MB)
[    0.000000]     lowmem  : 0xc0000000 - 0xd0000000   ( 256 MB)
[    0.000000]     modules : 0xbf000000 - 0xc0000000   (  16 MB)
[    0.000000]       .text : 0xc0008000 - 0xc03e757c   (3966 kB)
[    0.000000]       .init : 0xc03e8000 - 0xc040c000   ( 144 kB)
[    0.000000]       .data : 0xc040c000 - 0xc0446820   ( 235 kB)
[    0.000000]        .bss : 0xc0446844 - 0xc04a9ed8   ( 398 kB)
[    0.000000] NR_IRQS:114
[    0.000000] sched_clock: 32 bits at 200MHz, resolution 5ns, wraps every 21474ms
[    0.000000] Console: colour dummy device 80x30
[    7.625187] Calibrating delay loop... 1196.85 BogoMIPS (lpj=5984256)
[    7.715078] pid_max: default: 32768 minimum: 301
[    7.715199] Security Framework initialized
[    7.715271] Mount-cache hash table entries: 512
[    7.715597] Initializing cgroup subsys cpuacct
[    7.715620] Initializing cgroup subsys memory
[    7.715643] Initializing cgroup subsys devices
[    7.715653] Initializing cgroup subsys freezer
[    7.715662] Initializing cgroup subsys net_cls
[    7.715671] Initializing cgroup subsys blkio
[    7.715691] Initializing cgroup subsys perf_event
[    7.715778] CPU: Testing write buffer coherency: ok
[    7.716961] devtmpfs: initialized
[    7.718758] print_constraints: dummy: 
[    7.718992] NET: Registered protocol family 16
[    7.719756] Kirkwood: MV88F6281-A1, TCLK=200000000.
[    7.719770] Feroceon L2: Enabling L2
[    7.719803] Feroceon L2: Cache support initialised.
[    7.761244] Kirkwood PCIe port 0: 
[    7.761251] link up
[    7.761275] PCI: bus0 uses PCIe port 0
[    7.761678] PCI: bus0: Fast back to back transfers disabled
[    7.761928] pci 0000:00:01.0: BAR 0: assigned [mem 0xe0000000-0xe00fffff 64bit]
[    7.761947] pci 0000:00:01.0: BAR 2: assigned [io  0x1000-0x10ff]
[    7.763610] bio: create slab <bio-0> at 0
[    7.763992] vgaarb: loaded
[    7.764540] Switching to clocksource orion_clocksource
[    7.778790] NET: Registered protocol family 2
[    7.778995] IP route cache hash table entries: 2048 (order: 1, 8192 bytes)
[    7.779605] TCP established hash table entries: 8192 (order: 4, 65536 bytes)
[    7.779788] TCP bind hash table entries: 8192 (order: 3, 32768 bytes)
[    7.779883] TCP: Hash tables configured (established 8192 bind 8192)
[    7.779892] TCP reno registered
[    7.779901] UDP hash table entries: 256 (order: 0, 4096 bytes)
[    7.779923] UDP-Lite hash table entries: 256 (order: 0, 4096 bytes)
[    7.780131] NET: Registered protocol family 1
[    7.780331] Unpacking initramfs...
[    8.198822] Freeing initrd memory: 9216K
[    8.198839] NetWinder Floating Point Emulator V0.97 (double precision)
[    8.199438] audit: initializing netlink socket (disabled)
[    8.199483] type=2000 audit(0.560:1): initialized
[    8.200677] VFS: Disk quotas dquot_6.5.2
[    8.200760] Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[    8.200863] JFFS2 version 2.2. (NAND) (SUMMARY)  © 2001-2006 Red Hat, Inc.
[    8.201200] msgmni has been set to 498
[    8.202673] alg: No test for stdrng (krng)
[    8.202785] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 253)
[    8.202798] io scheduler noop registered
[    8.202805] io scheduler deadline registered
[    8.202857] io scheduler cfq registered (default)
[    8.202953] mv_xor_shared mv_xor_shared.0: Marvell shared XOR driver
[    8.202984] mv_xor_shared mv_xor_shared.1: Marvell shared XOR driver
[    8.234604] mv_xor mv_xor.0: Marvell XOR: ( xor cpy )
[    8.274601] mv_xor mv_xor.1: Marvell XOR: ( xor fill cpy )
[    8.314601] mv_xor mv_xor.2: Marvell XOR: ( xor cpy )
[    8.354599] mv_xor mv_xor.3: Marvell XOR: ( xor fill cpy )
[    8.354945] Serial: 8250/16550 driver, 2 ports, IRQ sharing disabled
[    8.375477] serial8250.0: ttyS0 at MMIO 0xf1012000 (irq = 33) is a 16550A
[    8.828930] console [ttyS0] enabled
[    8.852701] serial8250.1: ttyS1 at MMIO 0xf1012100 (irq = 34) is a 16550A
[    8.861019] m25p80 spi0.0: m25p128 (16384 Kbytes)
[    8.865785] Creating 6 MTD partitions on "spi_flash":
[    8.870862] 0x000000000000-0x000000080000 : "U-Boot"
[    8.876713] 0x000000200000-0x000000400000 : "Kernel"
[    8.882526] 0x000000400000-0x000000d00000 : "RootFS1"
[    8.888469] 0x000000d00000-0x000001000000 : "RootFS2"
[    8.894391] 0x000000080000-0x0000000c0000 : "U-Boot Config"
[    8.900882] 0x0000000c0000-0x000000200000 : "NAS Config"
[    8.907334] mousedev: PS/2 mouse device common for all mice
[    9.914647] rtc-mv rtc-mv: internal RTC not ticking
[    9.919651] i2c /dev entries driver
[    9.927012] rtc-s35390a 0-0030: rtc core: registered rtc-s35390a as rtc0
[    9.933841] cpuidle: using governor ladder
[    9.938051] cpuidle: using governor menu
[    9.942750] TCP cubic registered
[    9.946010] NET: Registered protocol family 17
[    9.950485] Registering the dns_resolver key type
[    9.955697] registered taskstats version 1
[    9.960832] rtc-s35390a 0-0030: setting system clock to 2014-03-13 15:15:08 UTC (1394723708)
[    9.969370] Initializing network drop monitor service
[    9.975087] Freeing init memory: 144K
Loading, please wait...
[   10.045148] udevd[51]: starting version 175
[   10.200968] SCSI subsystem initialized
[   10.316105] PCI: enabling device 0000:00:01.0 (0140 -> 0143)
[   10.321932] sata_mv 0000:00:01.0: Gen-IIE 32 slots 4 ports SCSI mode IRQ via INTx
[   10.400982] scsi0 : sata_mv
[   10.408413] scsi1 : sata_mv
[   10.416175] scsi2 : sata_mv
[   10.421699] scsi3 : sata_mv
[   10.424780] ata1: SATA max UDMA/133 mmio m1048576@0xe0000000 port 0xe0022000 irq 9
[   10.432387] ata2: SATA max UDMA/133 mmio m1048576@0xe0000000 port 0xe0024000 irq 9
[   10.440008] ata3: SATA max UDMA/133 mmio m1048576@0xe0000000 port 0xe0026000 irq 9
[   10.447623] ata4: SATA max UDMA/133 mmio m1048576@0xe0000000 port 0xe0028000 irq 9
[   10.457179] sata_mv sata_mv.0: slots 32 ports 2
[   10.469228] scsi4 : sata_mv
[   10.473973] scsi5 : sata_mv
[   10.478714] ata5: SATA max UDMA/133 irq 21
[   10.482829] ata6: SATA max UDMA/133 irq 21
[   10.834587] ata5: SATA link down (SStatus 0 SControl F300)
[   10.964609] ata1: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
[   10.985003] ata1.00: ATA-9: WDC WD20EFRX-68EUZN0, 80.00A80, max UDMA/133
[   10.991738] ata1.00: 3907029168 sectors, multi 0: LBA48 NCQ (depth 31/32)
[   11.014996] ata1.00: configured for UDMA/133
[   11.019610] scsi 0:0:0:0: Direct-Access     ATA      WDC WD20EFRX-68E 80.0 PQ: 0 ANSI: 5
[   11.534614] ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
[   11.554999] ata2.00: ATA-9: WDC WD20EFRX-68EUZN0, 80.00A80, max UDMA/133
[   11.561731] ata2.00: 3907029168 sectors, multi 0: LBA48 NCQ (depth 31/32)
[   11.584994] ata2.00: configured for UDMA/133
[   11.589581] scsi 1:0:0:0: Direct-Access     ATA      WDC WD20EFRX-68E 80.0 PQ: 0 ANSI: 5
[   12.104608] ata3: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
[   12.124995] ata3.00: ATA-9: WDC WD20EFRX-68EUZN0, 80.00A80, max UDMA/133
[   12.131731] ata3.00: 3907029168 sectors, multi 0: LBA48 NCQ (depth 31/32)
[   12.154994] ata3.00: configured for UDMA/133
[   12.159570] scsi 2:0:0:0: Direct-Access     ATA      WDC WD20EFRX-68E 80.0 PQ: 0 ANSI: 5
[   12.514604] ata4: SATA link down (SStatus 0 SControl 300)
[   12.864583] ata6: SATA link down (SStatus 0 SControl F300)
[   12.922332] sd 0:0:0:0: [sda] 3907029168 512-byte logical blocks: (2.00 TB/1.81 TiB)
[   12.930149] sd 0:0:0:0: [sda] 4096-byte physical blocks
[   12.943997] sd 1:0:0:0: [sdb] 3907029168 512-byte logical blocks: (2.00 TB/1.81 TiB)
[   12.951809] sd 1:0:0:0: [sdb] 4096-byte physical blocks
[   12.957579] sd 2:0:0:0: [sdc] 3907029168 512-byte logical blocks: (2.00 TB/1.81 TiB)
[   12.965383] sd 2:0:0:0: [sdc] 4096-byte physical blocks
[   12.979831] sd 0:0:0:0: [sda] Write Protect is off
[   12.984916] sd 1:0:0:0: [sdb] Write Protect is off
[   12.989985] sd 2:0:0:0: [sdc] Write Protect is off
[   12.994924] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[   13.005146] sd 1:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[   13.015327] sd 2:0:0:0: [sdc] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[   13.056908]  sdc: unknown partition table
[   13.061891] sd 2:0:0:0: [sdc] Attached SCSI disk
[   13.245945] ata4: exception Emask 0x10 SAct 0x0 SErr 0x4010000 action 0xe frozen
[   13.253374] ata4: edma_err_cause=00000010 pp_flags=00000000, dev connect
[   13.260128] ata4: SError: { PHYRdyChg DevExch }
[   13.264705] ata4: hard resetting link
[   13.630674]  sdb: unknown partition table
[   13.637521] sd 1:0:0:0: [sdb] Attached SCSI disk
[   13.655431]  sda: unknown partition table
[   13.662099] sd 0:0:0:0: [sda] Attached SCSI disk
Begin: Loading essential drivers ... done.
Begin: Running /scripts/init-premount ... done.
Begin: Mounting root file system ... Begin: Running /scripts/local-top ... Begin: Assembling all MD arrays ... [   13.909616] md: md0 stopped.
[   13.924251] md: bind<sdb>
[   13.938670] md: bind<sdc>
[   13.960331] md: bind<sda>
[   14.164673] raid6: int32x1     80 MB/s
[   14.335054] raid6: int32x2    123 MB/s
[   14.505022] raid6: int32x4    125 MB/s
[   14.674915] raid6: int32x8    156 MB/s
[   14.678674] raid6: using algorithm int32x8 (156 MB/s)
[   14.715395] async_tx: api initialized (async)
[   14.721293] xor: measuring software checksum speed
[   14.774565]    arm4regs  :  1091.600 MB/sec
[   14.824563]    8regs     :   654.800 MB/sec
[   14.874566]    32regs    :   906.400 MB/sec
[   14.878765] xor: using function: arm4regs (1091.600 MB/sec)
[   14.893593] md: raid6 personality registered for level 6
[   14.898966] md: raid5 personality registered for level 5
[   14.904295] md: raid4 personality registered for level 4
[   14.910513] bio: create slab <bio-1> at 1
[   14.914584] md/raid:md0: not clean -- starting background reconstruction
[   14.921348] md/raid:md0: device sda operational as raid disk 0
[   14.927219] md/raid:md0: device sdc operational as raid disk 2
[   14.933081] md/raid:md0: device sdb operational as raid disk 1
[   14.940037] md/raid:md0: allocated 4218kB
[   14.944152] md/raid:md0: cannot start dirty degraded array.
[   14.950622] md/raid:md0: failed to run raid set.
[   14.955277] md: pers->run() failed ...
mdadm: failed to RUN_ARRAY /dev/md/0: Input/output error
mdadm: Not enough devices to start the array while not clean - consider --force.
Failure: failed to assemble all arrays.
done.
[   14.977180] device-mapper: uevent: version 1.0.3
[   14.983440] device-mapper: ioctl: 4.22.0-ioctl (2011-10-19) initialised: dm-devel@redhat.com
  Volume group "vg00" not found
  Skipping volume group vg00
Unable to find LVM volume vg00/system
  Volume group "vg00" not found
  Skipping volume group vg00
Unable to find LVM volume vg00/swap
done.
Begin: Waiting for root file system ... [   20.054585] ata4: link is slow to respond, please be patient (ready=0)
[   21.254635] ata4: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
[   21.474646] ata4.00: ATA-9: WDC WD20EFRX-68EUZN0, 80.00A80, max UDMA/133
[   21.481384] ata4.00: 3907029168 sectors, multi 0: LBA48 NCQ (depth 31/32)
[   21.505002] ata4.00: configured for UDMA/133
[   21.509300] ata4: EH complete
[   21.513302] scsi 3:0:0:0: Direct-Access     ATA      WDC WD20EFRX-68E 80.0 PQ: 0 ANSI: 5
[   21.526075] sd 3:0:0:0: [sdd] 3907029168 512-byte logical blocks: (2.00 TB/1.81 TiB)
[   21.533860] sd 3:0:0:0: [sdd] 4096-byte physical blocks
[   21.553033] sd 3:0:0:0: [sdd] Write Protect is off
[   21.560033] sd 3:0:0:0: [sdd] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[   21.598504]  sdd: unknown partition table
[   21.605292] sd 3:0:0:0: [sdd] Attached SCSI disk

done.
Gave up waiting for root device.  Common problems:
 - Boot args (cat /proc/cmdline)
   - Check rootdelay= (did the system wait long enough?)
   - Check root= (did the system wait for the right device?)
 - Missing modules (cat /proc/modules; ls /dev)
ALERT!  /dev/mapper/vg00-system does not exist.  Dropping to a shell!
modprobe: module i8042 not found in modules.dep
modprobe: module ehci-hcd not found in modules.dep
modprobe: module uhci-hcd not found in modules.dep
modprobe: module ohci-hcd not found in modules.dep
modprobe: module usbhid not found in modules.dep


BusyBox v1.20.2 (Debian 1:1.20.0-7) built-in shell (ash)
Enter 'help' for a list of built-in commands.

/bin/sh: can't access tty; job control turned off
(initramfs) 
(initramfs) 
25 марта 2014 г., в 23:45, Martin Michlmayr <tbm@cyrius.com> написал(а):

> * Martin Waschbuesch <martin@waschbuesch.de> [2013-07-04 19:12]:
>> Package: src:linux
>> Version: 3.2.46-1
> 
> Alexander Rumyantsev just reported the same issue to me.  Alexander,
> which kernel version are you using?
> 
> If this is still present in the kernel in Debian unstable, I'll email
> the upstream kernel folks.
> 
> -- 
> Martin Michlmayr
> http://www.cyrius.com/


Reply to: