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

["Пламен Петров" <plamen@petrovi.no-ip.info>]

[-- 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 --]