RE: Can anyone boot a system using btrfs root with linux 3.14 or newer?

Пламен Петров
2014-04-24T18:51:55Z

[-- Attachment #1: Type: text/plain, Size: 15557 bytes --]

> -----Original Message-----
> From: Пламен Петров [mailto:plamen@petrovi.no-ip.info]
> Sent: Thursday, April 24, 2014 8:44 PM
> To: 'Marc MERLIN'
> Cc: 'linux-btrfs@vger.kernel.org'
> Subject: RE: Can anyone boot a system using btrfs root with linux 3.14 or
> newer?
>
> > -----Original Message-----
> > From: Marc MERLIN [mailto:marc@merlins.org]
> > Sent: Thursday, April 24, 2014 8:33 PM
> > To: Пламен Петров
> > Cc: linux-btrfs@vger.kernel.org
> > Subject: Re: Can anyone boot a system using btrfs root with linux 3.14
> > or newer?
> >
> > On Thu, Apr 24, 2014 at 08:19:21PM +0300, Пламен Петров wrote:
> > > I just realized that the l gave no way for identifying the
> > > particular bugzilla
> > entry. Here it is:
> > > https://bugzilla.kernel.org/show_bug.cgi?id=74261
> >
> > Thanks.
> >
> > But to save us a lot more speculation, can you please try booting a
> > linux system (either initrd, or another one with a non btrfs root),
> > and then trying to mount that filesystem from the command line?
>
> Using 3.14.1 perhaps?
>
> I will try to do that now, but if I can't manage to do it today - expect the
> results tomorrow.
>
> One more detail I managed to rule out today is that my problematic
> filesystems used subvol-other-than-root as default, made like so:
>
> $ mount /dev/sda2 /sda2 -o relatime,compress=zlib,subvol=system-main-fs
> $ btrfs subvolume set-default system-main-fs /sda2
>
> Only using different name for the subvolume.
> Anyway - its irrelevant.
> I formatted a fresh root as BTRFS, skipped the above, and tried booting
> 3.14.1 - result was kernel panic. So different default subvolume or not - its
> not the problem.

So, here is what I did:
My debug VM had:
sda
sda1 200 MB /boot - ext2
sda2 5 GB / - BTRFS
sda3 5 GB / - XFS
sda4 One extra partition used for mangling (XFS).

sda2 and sda3 were mostly the same, except /etc/fstab, for obvious reasons.

I booted 3.14.1 using sda3 as root, and then tried mounting sda2. It went OK, here is what dmesg said:
[ 12.412465] Btrfs loaded
[ 12.418259] rtc_cmos 00:03: setting system clock to 2014-04-24 21:24:49 UTC (1398374689)
[ 12.589585] input: ImPS/2 Generic Wheel Mouse as /devices/platform/i8042/serio1/input/input3
[ 12.593662] md: Skipping autodetection of RAID arrays. (raid=autodetect will force)
[ 12.622697] XFS (sda3): Mounting Filesystem
[ 12.859854] XFS (sda3): Ending clean mount
[ 12.860716] VFS: Mounted root (xfs filesystem) on device 8:3.
[ 12.877671] devtmpfs: mounted
[ 12.878878] Freeing unused kernel memory: 928K (ffffffff81c80000 - ffffffff81d68000)
[ 12.879074] Write protecting the kernel read-only data: 12288k
[ 12.880894] Freeing unused kernel memory: 280K (ffff8800017ba000 - ffff880001800000)
[ 12.885059] Freeing unused kernel memory: 1480K (ffff880001a8e000 - ffff880001c00000)
[ 13.260033] mount (1508) used greatest stack depth: 4600 bytes left
[ 13.487836] udevd[1517]: starting version 182
[ 13.701783] cdrom_id (1577) used greatest stack depth: 4416 bytes left
[ 14.413107] BTRFS: device fsid 2ba08fbc-4b95-46cc-b638-299f16462620 devid 1 transid 22 /dev/sda2
[ 14.579120] EXT4-fs (sda1): mounted filesystem without journal. Opts: (null)
[ 15.297292] hpet1: lost 2 rtc interrupts
[ 15.942679] ip (1620) used greatest stack depth: 4352 bytes left
[ 15.957207] e1000: eth0 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: None
[ 16.052274] random: nonblocking pool is initialized
[ 86.490078] BTRFS: device fsid 2ba08fbc-4b95-46cc-b638-299f16462620 devid 1 transid 22 /dev/sda2
[ 86.492947] BTRFS info (device sda2): disk space caching is enabled
[ 86.579155] BTRFS: creating UUID tree
[ 86.748681] mount (1899) used greatest stack depth: 2560 bytes left

At this point I rebooted the VM with 3.13.11 just to verify everything works on the BTRFS sda2, and it did. Here is its dmesg:

[ 8.292487] Btrfs loaded
[ 8.292663] msgmni has been set to 1978
[ 8.302800] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 251)
[ 8.302991] io scheduler noop registered (default)
[ 8.303101] io scheduler deadline registered
[ 8.303475] crc32: CRC_LE_BITS = 64, CRC_BE BITS = 64
[ 8.303668] crc32: self tests passed, processed 225944 bytes in 130881 nsec
[ 8.303945] crc32c: CRC_LE_BITS = 64
[ 8.304037] crc32c: self tests passed, processed 225944 bytes in 65371 nsec
[ 8.519327] crc32_combine: 8373 self tests passed
[ 8.736143] crc32c_combine: 8373 self tests passed
[ 8.737102] pcieport 0000:00:15.0: irq 40 for MSI/MSI-X
[ 8.738366] pcieport 0000:00:15.1: irq 41 for MSI/MSI-X
[ 8.739587] pcieport 0000:00:15.2: irq 42 for MSI/MSI-X
[ 8.740822] pcieport 0000:00:15.3: irq 43 for MSI/MSI-X
[ 8.742007] pcieport 0000:00:15.4: irq 44 for MSI/MSI-X
[ 8.743221] pcieport 0000:00:15.5: irq 45 for MSI/MSI-X
[ 8.744555] pcieport 0000:00:15.6: irq 46 for MSI/MSI-X
[ 8.745774] pcieport 0000:00:15.7: irq 47 for MSI/MSI-X
[ 8.747230] pcieport 0000:00:16.0: irq 48 for MSI/MSI-X
[ 8.748712] pcieport 0000:00:16.1: irq 49 for MSI/MSI-X
[ 8.749967] pcieport 0000:00:16.2: irq 50 for MSI/MSI-X
[ 8.751182] pcieport 0000:00:16.3: irq 51 for MSI/MSI-X
[ 8.752366] pcieport 0000:00:16.4: irq 52 for MSI/MSI-X
[ 8.753599] pcieport 0000:00:16.5: irq 53 for MSI/MSI-X
[ 8.754821] pcieport 0000:00:16.6: irq 54 for MSI/MSI-X
[ 8.756053] pcieport 0000:00:16.7: irq 55 for MSI/MSI-X
[ 8.757243] pcieport 0000:00:17.0: irq 56 for MSI/MSI-X
[ 8.758456] pcieport 0000:00:17.1: irq 57 for MSI/MSI-X
[ 8.759656] pcieport 0000:00:17.2: irq 58 for MSI/MSI-X
[ 8.760871] pcieport 0000:00:17.3: irq 59 for MSI/MSI-X
[ 8.762232] pcieport 0000:00:17.4: irq 60 for MSI/MSI-X
[ 8.763522] pcieport 0000:00:17.5: irq 61 for MSI/MSI-X
[ 8.764798] pcieport 0000:00:17.6: irq 62 for MSI/MSI-X
[ 8.765996] pcieport 0000:00:17.7: irq 63 for MSI/MSI-X
[ 8.767202] pcieport 0000:00:18.0: irq 64 for MSI/MSI-X
[ 8.768443] pcieport 0000:00:18.1: irq 65 for MSI/MSI-X
[ 8.769624] pcieport 0000:00:18.2: irq 66 for MSI/MSI-X
[ 8.770844] pcieport 0000:00:18.3: irq 67 for MSI/MSI-X
[ 8.772031] pcieport 0000:00:18.4: irq 68 for MSI/MSI-X
[ 8.773320] pcieport 0000:00:18.5: irq 69 for MSI/MSI-X
[ 8.774596] pcieport 0000:00:18.6: irq 70 for MSI/MSI-X
[ 8.775810] pcieport 0000:00:18.7: irq 71 for MSI/MSI-X
[ 8.778754] ACPI: AC Adapter [ACAD] (on-line)
[ 8.779467] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0
[ 8.779663] ACPI: Power Button [PWRF]
[ 8.783957] xenfs: not registering filesystem on non-xen platform
[ 8.787231] Non-volatile memory driver v1.3
[ 8.787428] Linux agpgart interface v0.103
[ 8.788612] agpgart-intel 0000:00:00.0: Intel 440BX Chipset
[ 8.790580] agpgart-intel 0000:00:00.0: AGP aperture is 256M @ 0x0
[ 8.791666] [drm] Initialized drm 1.1.0 20060810
[ 8.809538] brd: module loaded
[ 8.819642] loop: module loaded
[ 8.819780] HP CISS Driver (v 3.6.26)
[ 8.821732] vmw_vmci 0000:00:07.7: Found VMCI PCI device at 0x11080, irq 16
[ 8.821987] vmw_vmci 0000:00:07.7: Using capabilities 0xc
[ 8.822319] vmw_vmci 0000:00:07.7: irq 72 for MSI/MSI-X
[ 8.822377] vmw_vmci 0000:00:07.7: irq 73 for MSI/MSI-X
[ 8.823258] Guest personality initialized and is active
[ 8.824045] VMCI host device registered (name=vmci, major=10, minor=62)
[ 8.824202] Initialized host personality
[ 8.830316] mpt2sas version 16.100.00.00 loaded
[ 8.831550] VMware PVSCSI driver - version 1.0.2.0-k
[ 8.835267] ata_piix 0000:00:07.1: version 2.13
[ 8.839894] scsi0 : ata_piix
[ 8.841344] scsi1 : ata_piix
[ 8.842426] ata1: PATA max UDMA/33 cmd 0x1f0 ctl 0x3f6 bmdma 0x1060 irq 14
[ 8.842587] ata2: PATA max UDMA/33 cmd 0x170 ctl 0x376 bmdma 0x1068 irq 15
[ 8.845619] bonding: Ethernet Channel Bonding Driver: v3.7.1 (April 27, 2011)
[ 8.862876] pcnet32: pcnet32.c:v1.35 21.Apr.2008 tsbogend@alpha.franken.de
[ 8.863649] e1000: Intel(R) PRO/1000 Network Driver - version 7.3.21-k8-NAPI
[ 8.863799] e1000: Copyright (c) 1999-2006 Intel Corporation.
[ 9.025659] ata2.00: ATAPI: VMware Virtual IDE CDROM Drive, 00000001, max UDMA/33
[ 9.065490] ata2.00: configured for UDMA/33
[ 9.066207] scsi 1:0:0:0: CD-ROM NECVMWar VMware IDE CDR10 1.00 PQ: 0 ANSI: 5
[ 9.067759] sr0: scsi3-mmc drive: 1x/1x writer dvd-ram cd/rw xa/form2 cdda tray
[ 9.067978] cdrom: Uniform CD-ROM driver Revision: 3.20
[ 9.073651] sr 1:0:0:0: Attached scsi CD-ROM sr0
[ 9.074388] sr 1:0:0:0: Attached scsi generic sg0 type 5
[ 9.305312] e1000 0000:02:00.0 eth0: (PCI:66MHz:32-bit) 00:0c:29:55:5f:81
[ 9.305558] e1000 0000:02:00.0 eth0: Intel(R) PRO/1000 Network Connection
[ 9.306253] e1000e: Intel(R) PRO/1000 Network Driver - 2.3.2-k
[ 9.306474] e1000e: Copyright(c) 1999 - 2013 Intel Corporation.
[ 9.307179] igb: Intel(R) Gigabit Ethernet Network Driver - version 5.0.5-k
[ 9.307424] igb: Copyright (c) 2007-2013 Intel Corporation.
[ 9.309118] VMware vmxnet3 virtual NIC driver - version 1.2.0.0-k-NAPI
[ 9.309857] Fusion MPT base driver 3.04.20
[ 9.310048] Copyright (c) 1999-2008 LSI Corporation
[ 9.310274] Fusion MPT SPI Host driver 3.04.20
[ 9.311661] mptbase: ioc0: Initiating bringup
[ 9.486032] ioc0: LSI53C1030 B0: Capabilities={Initiator}
[ 9.888306] scsi2 : ioc0: LSI53C1030 B0, FwRev=01032920h, Ports=1, MaxQ=128, IRQ=17
[ 10.165079] scsi 2:0:0:0: Direct-Access VMware, VMware Virtual S 1.0 PQ: 0 ANSI: 2
[ 10.165726] scsi target2:0:0: Beginning Domain Validation
[ 10.168562] scsi target2:0:0: Domain Validation skipping write tests
[ 10.169019] scsi target2:0:0: Ending Domain Validation
[ 10.169571] scsi target2:0:0: FAST-40 WIDE SCSI 80.0 MB/s ST (25 ns, offset 127)
[ 10.172712] sd 2:0:0:0: [sda] 25165824 512-byte logical blocks: (12.8 GB/12.0 GiB)
[ 10.173562] sd 2:0:0:0: [sda] Write Protect is off
[ 10.173957] sd 2:0:0:0: [sda] Mode Sense: 61 00 00 00
[ 10.174196] sd 2:0:0:0: [sda] Cache data unavailable
[ 10.174645] sd 2:0:0:0: [sda] Assuming drive cache: write through
[ 10.176514] sd 2:0:0:0: Attached scsi generic sg1 type 0
[ 10.177047] sd 2:0:0:0: [sda] Cache data unavailable
[ 10.177052] sd 2:0:0:0: [sda] Assuming drive cache: write through
[ 10.184581] Fusion MPT FC Host driver 3.04.20
[ 10.185965] Fusion MPT SAS Host driver 3.04.20
[ 10.187431] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[ 10.187921] ehci-pci: EHCI PCI platform driver
[ 10.189278] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[ 10.189759] ohci-pci: OHCI PCI platform driver
[ 10.191061] uhci_hcd: USB Universal Host Controller Interface driver
[ 10.194583] i8042: PNP: PS/2 Controller [PNP0303:KBC,PNP0f13:MOUS] at 0x60,0x64 irq 1,12
[ 10.197335] serio: i8042 KBD port at 0x60,0x64 irq 1
[ 10.197572] serio: i8042 AUX port at 0x60,0x64 irq 12
[ 10.198744] sda: sda1 sda2 sda3 sda4
[ 10.199255] mousedev: PS/2 mouse device common for all mice
[ 10.215071] sd 2:0:0:0: [sda] Cache data unavailable
[ 10.215284] sd 2:0:0:0: [sda] Assuming drive cache: write through
[ 10.215608] sd 2:0:0:0: [sda] Attached SCSI disk
[ 10.223044] rtc_cmos 00:03: rtc core: registered rtc_cmos as rtc0
[ 10.223530] rtc_cmos 00:03: alarms up to one month, y3k, 114 bytes nvram, hpet irqs
[ 10.225055] md: linear personality registered for level -1
[ 10.225498] md: raid0 personality registered for level 0
[ 10.225619] md: raid1 personality registered for level 1
[ 10.225740] md: raid10 personality registered for level 10
[ 10.225960] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1
[ 10.226287] md: raid6 personality registered for level 6
[ 10.226427] md: raid5 personality registered for level 5
[ 10.226560] md: raid4 personality registered for level 4
[ 10.229500] device-mapper: ioctl: 4.27.0-ioctl (2013-10-30) initialised: dm-devel@redhat.com
[ 10.229788] device-mapper: raid: Loading target version 1.5.2
[ 10.236443] usbcore: registered new interface driver usbhid
[ 10.236590] usbhid: USB HID core driver
[ 10.236776] Netfilter messages via NETLINK v0.30.
[ 10.236901] nf_conntrack version 0.5.0 (7913 buckets, 31652 max)
[ 10.237587] ctnetlink v0.93: registering with nfnetlink.
[ 10.237883] ip_tables: (C) 2000-2006 Netfilter Core Team
[ 10.238052] TCP: cubic registered
[ 10.238142] TCP: vegas registered
[ 10.238236] TCP: veno registered
[ 10.238324] TCP: yeah registered
[ 10.238410] Initializing XFRM netlink socket
[ 10.238517] NET: Registered protocol family 17
[ 10.238632] Key type dns_resolver registered
[ 10.250310] rtc_cmos 00:03: setting system clock to 2014-04-24 21:32:28 UTC (1398375148)
[ 10.434122] input: ImPS/2 Generic Wheel Mouse as /devices/platform/i8042/serio1/input/input3
[ 10.437178] md: Skipping autodetection of RAID arrays. (raid=autodetect will force)
[ 10.469491] btrfs: device fsid 2ba08fbc-4b95-46cc-b638-299f16462620 devid 1 transid 25 /dev/root
[ 10.472644] btrfs: disk space caching is enabled
[ 10.629425] VFS: Mounted root (btrfs filesystem) on device 0:14.
[ 10.630271] devtmpfs: mounted
[ 10.634102] Freeing unused kernel memory: 916K (ffffffff81c7e000 - ffffffff81d63000)
[ 10.634723] Write protecting the kernel read-only data: 12288k
[ 10.639516] Freeing unused kernel memory: 376K (ffff8800017a2000 - ffff880001800000)
[ 10.648068] Freeing unused kernel memory: 1504K (ffff880001a88000 - ffff880001c00000)
[ 10.990350] mount (1131) used greatest stack depth: 4416 bytes left
[ 11.082048] udevd[1139]: starting version 182
[ 11.082112] udevd (1138) used greatest stack depth: 4408 bytes left
[ 11.866053] btrfs: device fsid 2ba08fbc-4b95-46cc-b638-299f16462620 devid 1 transid 25 /dev/sda2
[ 11.867495] btrfs (1196) used greatest stack depth: 4320 bytes left
[ 12.307431] btrfs: use zlib compression
[ 12.307549] btrfs: disk space caching is enabled
[ 12.406078] mount (1197) used greatest stack depth: 3200 bytes left
[ 12.522659] btrfs: use zlib compression
[ 12.523038] btrfs: disk space caching is enabled
[ 12.601811] EXT4-fs (sda1): mounted filesystem without journal. Opts: (null)
[ 15.629161] hpet1: lost 1 rtc interrupts
[ 16.483149] random: nonblocking pool is initialized
[ 17.126828] e1000: eth0 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: None
[ 18.470646] cc1 (1271) used greatest stack depth: 3032 bytes left

>From the above - the first obvious thing is that with 3.13.11 BTRFS gets loaded much earlier in the boot process - that is why the second dmesg dump is much larger, and both start at " Btrfs loaded" - mind you.

Next was booting the BTRFS sda2 with 3.14.1.
Sadly, it panicked again. So, no dmesg dump - just a screenshot. See the attached file.
So, what got changed during the 3.14 merge window, that messed up booting for BTRFS partitions?
Should I try building an "allyesconfig" kernel, in case something is messed up with my kernel .configs?
What do you think guys and galls?
Anything you want me try - this is entirely disposable VM now, so I'll gladly try everything you ask...
---------------------------------
Plamen Petrov

[-- Attachment #2: debug-vm-panic.png --]
[-- Type: image/png, Size: 46408 bytes --]