I finally found the time to update my system due to the ZFS related init issues and ran into a strange problem. It seems that the kernel is unable to initialize my USB thumb drive boot device during the initramfs phase properly unless I yank it out and re-insert it while it's "Waiting for root filesystem". I have a SuperMicro X7QC3 motherboard with an AMI BIOS and my USB controller is set to boot at "HiSpeed" in the BIOS. It gets through Grub with no issues and loads the kernel image and the initrd into memory without issue. It then happily detects all of my hard disks used in my ZFS setup with no problem. If I do nothing it will wait for the root FS (on the USB drive) to show up until something times out at which point it will drop me to an initramfs busybox prompt. Looking for the device shows that nothing has been detected. Sometimes I will get errors about a USB device not being able to be enumerated.
If I, instead, wait for "Waiting for root file system" to show up and pull out and re-insert the USB drive, it will properly detect it and boot up fine. So...what gives? Does anyone have any idea what's going on?
Woops, forgot to provide any useful information. The USB thumb drive is a "SanDisk Ultra Fit" with ID "0781:4483".
uname output: Linux ezra 3.2.0-4-amd64 #1 SMP Debian 3.2.68-1+deb7u5 x86_64 GNU/Linux
apt-show-versions: linux-image-amd64/wheezy uptodate 3.2+46
dmesg:
Code
[ 0.000000] Linux version 3.2.0-4-amd64 (debian-kernel@lists.debian.org) (gcc version 4.6.3 (Debian 4.6.3-14) ) #1 SMP Debian 3.2.68-1+deb7u5
... Omitted due to character limit ...
[ 1.762636] Unpacking initramfs...
... Omitted due to character limit ...
[ 2.564649] usbcore: registered new interface driver usbfs
[ 2.564785] usbcore: registered new interface driver hub
[ 2.564956] usbcore: registered new device driver usb
[ 2.565538] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[ 2.565700] ehci_hcd 0000:00:1d.7: setting latency timer to 64
[ 2.565704] ehci_hcd 0000:00:1d.7: EHCI Host Controller
[ 2.565834] ehci_hcd 0000:00:1d.7: new USB bus registered, assigned bus number 1
[ 2.565986] ehci_hcd 0000:00:1d.7: debug port 1
[ 2.568332] libata version 3.00 loaded.
[ 2.569961] ehci_hcd 0000:00:1d.7: cache line size of 64 is not supported
[ 2.569994] ehci_hcd 0000:00:1d.7: irq 23, io mem 0xfdfff800
[ 2.575979] FDC 0 is a post-1991 82077
[ 2.584047] ehci_hcd 0000:00:1d.7: USB 2.0 started, EHCI 1.00
[ 2.584150] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
[ 2.584228] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 2.584322] usb usb1: Product: EHCI Host Controller
[ 2.584395] usb usb1: Manufacturer: Linux 3.2.0-4-amd64 ehci_hcd
[ 2.584471] usb usb1: SerialNumber: 0000:00:1d.7
[ 2.584709] hub 1-0:1.0: USB hub found
[ 2.584783] hub 1-0:1.0: 6 ports detected
[ 2.584986] ahci 0000:00:1f.2: version 3.0
[ 2.585229] ahci 0000:00:1f.2: AHCI 0001.0100 32 slots 6 ports 3 Gbps 0x3f impl SATA mode
[ 2.585330] ahci 0000:00:1f.2: flags: 64bit ncq pm led slum part
[ 2.585410] ahci 0000:00:1f.2: setting latency timer to 64
... Omitted due to character limit (SATA disk init) ...
[ 2.600642] uhci_hcd: USB Universal Host Controller Interface driver
[ 2.600814] uhci_hcd 0000:00:1d.0: setting latency timer to 64
[ 2.600817] uhci_hcd 0000:00:1d.0: UHCI Host Controller
[ 2.600903] uhci_hcd 0000:00:1d.0: new USB bus registered, assigned bus number 2
[ 2.601022] uhci_hcd 0000:00:1d.0: irq 23, io base 0x0000e080
[ 2.601140] usb usb2: New USB device found, idVendor=1d6b, idProduct=0001
[ 2.601218] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 2.601311] usb usb2: Product: UHCI Host Controller
[ 2.601384] usb usb2: Manufacturer: Linux 3.2.0-4-amd64 uhci_hcd
[ 2.601460] usb usb2: SerialNumber: 0000:00:1d.0
[ 2.601679] hub 2-0:1.0: USB hub found
[ 2.601753] hub 2-0:1.0: 2 ports detected
[ 2.601923] uhci_hcd 0000:00:1d.1: setting latency timer to 64
[ 2.601926] uhci_hcd 0000:00:1d.1: UHCI Host Controller
[ 2.602008] uhci_hcd 0000:00:1d.1: new USB bus registered, assigned bus number 3
[ 2.602126] uhci_hcd 0000:00:1d.1: irq 19, io base 0x0000e000
[ 2.602241] usb usb3: New USB device found, idVendor=1d6b, idProduct=0001
[ 2.602319] usb usb3: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 2.602412] usb usb3: Product: UHCI Host Controller
[ 2.602486] usb usb3: Manufacturer: Linux 3.2.0-4-amd64 uhci_hcd
[ 2.602561] usb usb3: SerialNumber: 0000:00:1d.1
[ 2.602763] hub 3-0:1.0: USB hub found
[ 2.602837] hub 3-0:1.0: 2 ports detected
[ 2.602993] uhci_hcd 0000:00:1d.2: setting latency timer to 64
[ 2.602996] uhci_hcd 0000:00:1d.2: UHCI Host Controller
[ 2.603079] uhci_hcd 0000:00:1d.2: new USB bus registered, assigned bus number 4
[ 2.603207] uhci_hcd 0000:00:1d.2: irq 18, io base 0x0000dc00
[ 2.603322] usb usb4: New USB device found, idVendor=1d6b, idProduct=0001
[ 2.603400] usb usb4: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 2.603493] usb usb4: Product: UHCI Host Controller
[ 2.603566] usb usb4: Manufacturer: Linux 3.2.0-4-amd64 uhci_hcd
[ 2.603642] usb usb4: SerialNumber: 0000:00:1d.2
[ 2.603844] hub 4-0:1.0: USB hub found
[ 2.603919] hub 4-0:1.0: 2 ports detected
... Omitted due to character limit (more SATA and CDROM)...
[ 4.288794] device-mapper: uevent: version 1.0.3
[ 4.288992] device-mapper: ioctl: 4.22.0-ioctl (2011-10-19) initialised: dm-devel@redhat.com
[ 18.232033] usb 1-4: device descriptor read/64, error -110
[ 23.456021] usb 1-4: device descriptor read/64, error -71
[ 23.616253] hub 1-0:1.0: unable to enumerate USB device on port 4
[ 23.728019] usb 1-6: new high-speed USB device number 6 using ehci_hcd
[ 23.862628] usb 1-6: New USB device found, idVendor=14dd, idProduct=0002
[ 23.862707] usb 1-6: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 23.862785] usb 1-6: Product: Multidevice
[ 23.862856] usb 1-6: Manufacturer: Peppercon AG
[ 23.862929] usb 1-6: SerialNumber: 0562b201b2462fdf611C11C62A54F306
[ 23.870073] input: Peppercon AG Multidevice as /devices/pci0000:00/0000:00:1d.7/usb1/1-6/1-6:1.0/input/input1
[ 23.870306] generic-usb 0003:14DD:0002.0001: input,hidraw0: USB HID v1.01 Mouse [Peppercon AG Multidevice] on usb-0000:00:1d.7-6/input0
[ 23.871606] input: Peppercon AG Multidevice as /devices/pci0000:00/0000:00:1d.7/usb1/1-6/1-6:1.1/input/input2
[ 23.871815] generic-usb 0003:14DD:0002.0002: input,hidraw1: USB HID v1.01 Keyboard [Peppercon AG Multidevice] on usb-0000:00:1d.7-6/input1
[ 23.871936] usbcore: registered new interface driver usbhid
[ 23.872019] usbhid: USB HID core driver
[ 24.104016] usb 2-2: new full-speed USB device number 2 using uhci_hcd
[ 24.262148] usb 2-2: New USB device found, idVendor=067b, idProduct=2303
[ 24.262226] usb 2-2: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[ 24.262304] usb 2-2: Product: USB-Serial Controller D
[ 24.262378] usb 2-2: Manufacturer: Prolific Technology Inc.
[ 25.072018] usb 1-3: new high-speed USB device number 7 using ehci_hcd
[ 25.205130] usb 1-3: New USB device found, idVendor=0781, idProduct=5583
[ 25.205208] usb 1-3: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 25.205286] usb 1-3: Product: Ultra Fit
[ 25.205357] usb 1-3: Manufacturer: SanDisk
[ 25.205429] usb 1-3: SerialNumber: 4C530001020208115280
[ 25.208696] Initializing USB Mass Storage driver...
[ 25.208952] scsi10 : usb-storage 1-3:1.0
[ 25.216049] usbcore: registered new interface driver usb-storage
[ 25.216128] USB Mass Storage support registered.
[ 26.216802] scsi 10:0:0:0: Direct-Access SanDisk Ultra Fit 1.00 PQ: 0 ANSI: 6
[ 26.218045] sd 10:0:0:0: Attached scsi generic sg7 type 0
[ 26.218530] sd 10:0:0:0: [sdg] 60751872 512-byte logical blocks: (31.1 GB/28.9 GiB)
[ 26.219651] sd 10:0:0:0: [sdg] Write Protect is off
[ 26.219727] sd 10:0:0:0: [sdg] Mode Sense: 43 00 00 00
[ 26.220524] sd 10:0:0:0: [sdg] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
[ 26.250770] sdg: sdg1 sdg2
[ 26.253525] sd 10:0:0:0: [sdg] Attached SCSI removable disk
[ 26.607995] EXT4-fs (sdg2): mounted filesystem with ordered data mode. Opts: (null)
... Omitted due to character limit ...
[ 28.005496] usbcore: registered new interface driver usbserial
[ 28.005612] USB Serial support registered for generic
[ 28.005752] usbcore: registered new interface driver usbserial_generic
[ 28.005830] usbserial: USB Serial Driver core
[ 28.008805] USB Serial support registered for pl2303
[ 28.008900] pl2303 2-2:1.0: pl2303 converter detected
[ 28.020319] usb 2-2: pl2303 converter now attached to ttyUSB0
[ 28.020462] usbcore: registered new interface driver pl2303
[ 28.020541] pl2303: Prolific PL2303 USB to serial adaptor driver
... Omitted due to character limit ...
[ 28.238763] ata6.00: configured for UDMA/133
[ 28.238852] ata6: EH complete
[ 28.239067] sd 5:0:0:0: [sdf] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
... Omitted due to character limit ...
[ 28.762683] ZFS: Loaded module v0.6.5.2-2-wheezy, ZFS pool version 5000, ZFS filesystem version 5
[ 28.942021] irq 18: nobody cared (try booting with the "irqpoll" option)
[ 28.942027] Pid: 0, comm: swapper/0 Tainted: P O 3.2.0-4-amd64 #1 Debian 3.2.68-1+deb7u5
[ 28.942030] Call Trace:
[ 28.942032] <IRQ> [<ffffffff81092ec9>] ? __report_bad_irq+0x2c/0xb5
[ 28.942050] [<ffffffff810932ce>] ? note_interrupt+0x1b8/0x23a
[ 28.942054] [<ffffffff81091640>] ? handle_irq_event_percpu+0x15f/0x17d
[ 28.942059] [<ffffffff81013a5a>] ? read_tsc+0x5/0x14
[ 28.942064] [<ffffffff81066439>] ? timekeeping_get_ns+0xd/0x2a
[ 28.942067] [<ffffffff81091692>] ? handle_irq_event+0x34/0x52
[ 28.942071] [<ffffffff8106c3b1>] ? arch_local_irq_save+0x11/0x17
[ 28.942075] [<ffffffff81093a45>] ? handle_fasteoi_irq+0x7c/0xaf
[ 28.942080] [<ffffffff8100fa51>] ? handle_irq+0x1d/0x21
[ 28.942083] [<ffffffff8100f62a>] ? do_IRQ+0x42/0x98
[ 28.942090] [<ffffffff813514ee>] ? common_interrupt+0x6e/0x6e
[ 28.942092] <EOI> [<ffffffff8106c38a>] ? arch_local_irq_restore+0x2/0x8
[ 28.942098] [<ffffffff8100d20f>] ? cpu_idle+0x72/0xf2
[ 28.942105] [<ffffffff816aab3b>] ? start_kernel+0x3bd/0x3c8
[ 28.942108] [<ffffffff816aa140>] ? early_idt_handlers+0x140/0x140
[ 28.942111] [<ffffffff816aa3c4>] ? x86_64_start_kernel+0x104/0x111
[ 28.942113] handlers:
[ 28.942145] [<ffffffffa00a4216>] usb_hcd_irq
[ 28.942146] Disabling IRQ #18
... Omitted due to character limit ...
[ 30.215740] ata6.00: configured for UDMA/133
[ 30.220161] ata6: EH complete
[ 30.560611] Adding 7903976k swap on /dev/sdg1. Priority:-1 extents:1 across:7903976k
[ 30.572983] EXT4-fs (sdg2): re-mounted. Opts: (null)
[ 31.389926] EXT4-fs (sdg2): re-mounted. Opts: errors=remount-ro
... Omitted due to character limit ...In that log, I waited until I saw
Code
[ 18.232033] usb 1-4: device descriptor read/64, error -110
[ 23.456021] usb 1-4: device descriptor read/64, error -71
[ 23.616253] hub 1-0:1.0: unable to enumerate USB device on port 4before yanking and re-inserting the thumb drive.