Frequent kernel panics when doing heavy I/O in LXC containers on Btrfs

[Lenz Grimmer]

I initially reported this as a bug in LXC (https://github.com/lxc/lxc/issues/424), but I was (rightfully) advised to report this as a kernel issue instead:

I'm running Ubuntu 14.04.1 LTS (x86_64) on my Laptop. Current Kernel version is "3.13.0-44-generic". The LXC version is "1.0.7-0ubuntu0.1", installed from the "ubuntu-lxc" PPA on Launchpad.

I have a dedicated Btrfs file system mounted on /container/, which I use for storing all LXC containers.

The file system is created on top of a logical volume:

lenz@lenz-ThinkPad-T440 ~ % mount | grep container
/dev/mapper/ubuntu--vg-container on /container type btrfs (rw)
lenz@lenz-ThinkPad-T440 ~ % sudo lvdisplay /dev/mapper/ubuntu--vg-container
  --- Logical volume ---
  LV Path /dev/ubuntu-vg/container
  LV Name container
  VG Name ubuntu-vg
  LV UUID JUq21P-SSoS-UeU5-rdDS-k6V4-d30e-gJM1FA
  LV Write Access read/write
  LV Creation host, time lenz-ThinkPad-T440, 2014-09-15 13:42:27 +0200
  LV Status available
  # open 1
  LV Size 65,00 GiB
  Current LE 16640
  Segments 1
  Allocation inherit
  Read ahead sectors auto
  - currently set to 256
  Block device 252:5

The hard disk drive is a Samsung SSD ("Samsung SSD 840 EVO 500GB, EXT0BB0Q, max UDMA/133", according to dmesg).

I have a number containers based on CentOS 6, these were created by cloning a base image using lxc-clone -s.

Quite frequently, when I create heavy disk I/O in one or several of these containers (e.g. by running yum update concurrently, or by transferring large files e.g. via a HTTP upload to one of the container instances), my host system freezes. This only happens when container activity is involved, the system runs stable otherwise. Most of the time the X desktop freezes, sometimes a Kernel panic can be observed on the console. Unfortunately I'm unable to capture it other than by taking a picture. The only solution is to perform a cold reboot using the power button.

This occurred to me before. I then re-created the /container/ file system from scratch and started again. But now it's happening again, so I would like to report it for investigation.

ProblemType: Bug
DistroRelease: Ubuntu 14.04
Package: linux-image-generic 3.13.0.44.51
ProcVersionSignature: Ubuntu 3.13.0-44.73-generic 3.13.11-ckt12
Uname: Linux 3.13.0-44-generic x86_64
ApportVersion: 2.14.1-0ubuntu3.6
Architecture: amd64
AudioDevicesInUse:
 USER PID ACCESS COMMAND
 /dev/snd/controlC1: lenz 2782 F.... pulseaudio
 /dev/snd/controlC0: lenz 2782 F.... pulseaudio
CurrentDesktop: Unity
Date: Wed Jan 28 16:16:20 2015
HibernationDevice: RESUME=UUID=a60307c3-e53f-473e-ba9e-90cbfe484bb8
InstallationDate: Installed on 2014-09-15 (135 days ago)
InstallationMedia: Ubuntu 14.04.1 LTS "Trusty Tahr" - Release amd64 (20140722.2)
MachineType: LENOVO 20B6005YGE
ProcFB: 0 inteldrmfb
ProcKernelCmdLine: BOOT_IMAGE=/vmlinuz-3.13.0-44-generic root=/dev/mapper/ubuntu--vg-root ro softlockup_panic=1 elevator=noop quiet splash nomdmonddf nomdmonisw vt.handoff=7
RelatedPackageVersions:
 linux-restricted-modules-3.13.0-44-generic N/A
 linux-backports-modules-3.13.0-44-generic N/A
 linux-firmware 1.127.11
SourcePackage: linux
UpgradeStatus: No upgrade log present (probably fresh install)
dmi.bios.date: 09/03/2014
dmi.bios.vendor: LENOVO
dmi.bios.version: GJET79WW (2.29 )
dmi.board.asset.tag: Not Available
dmi.board.name: 20B6005YGE
dmi.board.vendor: LENOVO
dmi.board.version: 0B98401 PRO
dmi.chassis.asset.tag: No Asset Information
dmi.chassis.type: 10
dmi.chassis.vendor: LENOVO
dmi.chassis.version: Not Available
dmi.modalias: dmi:bvnLENOVO:bvrGJET79WW(2.29):bd09/03/2014:svnLENOVO:pn20B6005YGE:pvrThinkPadT440:rvnLENOVO:rn20B6005YGE:rvr0B98401PRO:cvnLENOVO:ct10:cvrNotAvailable:
dmi.product.name: 20B6005YGE
dmi.product.version: ThinkPad T440
dmi.sys.vendor: LENOVO

[Lenz Grimmer (lenzgr)]

Attaching a second screen shot with a slightly different stack trace

[Brad Figg (brad-figg)]

This change was made by a bot.

[Joseph Salisbury (jsalisbury)]

Did this issue start happening after an update/upgrade? Was there a prior kernel version where you were not having this particular problem?

Would it be possible for you to test the latest upstream kernel? Refer to https://wiki.ubuntu.com/KernelMainlineBuilds . Please test the latest v3.19 kernel[0].

If this bug is fixed in the mainline kernel, please add the following tag 'kernel-fixed-upstream'.

If the mainline kernel does not fix this bug, please add the tag: 'kernel-bug-exists-upstream'.

If you are unable to test the mainline kernel, for example it will not boot, please add the tag: 'kernel-unable-to-test-upstream'.
Once testing of the upstream kernel is complete, please mark this bug as "Confirmed".

Thanks in advance.

[0] http://kernel.ubuntu.com/~kernel-ppa/mainline/v3.19-rc6-vivid/

[Lenz Grimmer (lenzgr)]

Hi Joseph, thanks for your quick reply. The problems began some time after I started using LXC with Btrfs on Trusty, but I'm not sure if a particular kernel update introduced a regression. I've been using Btrfs on my home directory previously as well, but did not experience similar I/O-related crashes.

I'll try using the latest upstream kernel and report back. The problem is that these crashes happen randomly, I have not yet been able to reproduce them reliably (and since this always brings down my entire work environment, I'm not too excited about these crashes, as you can probably imagine).

[Lenz Grimmer (lenzgr)]

FYI, I'm now running Kernel version 3.19.0-031900rc6-generic from the URL you mentioned in #4. Let's see if the issue persists.

The file system mounts fine, but I'm concerned about the output of btrfsck:

Checking filesystem on /dev/mapper/ubuntu--vg-container
UUID: b95b58fb-d0b2-4735-a4ed-2033537eb89a
checking extents
checking free space cache
free space inode generation (0) did not match free space cache generation (135494)
free space inode generation (0) did not match free space cache generation (135494)
There is no free space entry for 11902451712-11904450560
There is no free space entry for 11902451712-12914262016
cache appears valid but isnt 11840520192
There is no free space entry for 14083878912-14084898816
There is no free space entry for 14083878912-15061745664
cache appears valid but isnt 13988003840
There is no free space entry for 15305744384-15306821632
There is no free space entry for 15305744384-16135487488
cache appears valid but isnt 15061745664
There is no free space entry for 16377102336-16378097664
There is no free space entry for 16377102336-17209229312
cache appears valid but isnt 16135487488
Wanted bytes 1957888, found 393216 for off 17210597376
Wanted bytes 1072373760, found 393216 for off 17210597376
cache appears valid but isnt 17209229312
There is no free space entry for 22839361536-22840332288
There is no free space entry for 22839361536-23651680256
cache appears valid but isnt 22577938432
There is no free space entry for 27126554624-27128291328
There is no free space entry for 27126554624-27946647552
cache appears valid but isnt 26872905728
There is no free space entry for 27985326080-27987566592
There is no free space entry for 27985326080-29020389376
cache appears valid but isnt 27946647552
There is no free space entry for 30126866432-30127960064
There is no free space entry for 30126866432-31167873024
cache appears valid but isnt 30094131200
Wanted bytes 2195456, found 12288 for off 64471998464
Wanted bytes 1055612928, found 12288 for off 64471998464
cache appears valid but isnt 64453869568
There is no free space entry for 65631424512-65632366592
There is no free space entry for 65631424512-66601353216
cache appears valid but isnt 65527611392
free space inode generation (0) did not match free space cache generation (135494)
found 15376998613 bytes used err is -22
total csum bytes: 44021104
total tree bytes: 601505792
total fs tree bytes: 419954688
total extent tree bytes: 103333888
btree space waste bytes: 129058353
file data blocks allocated: 126222901248
 referenced 43301400576
Btrfs v3.12

I'm not sure if the corruption is the cause or the consequence of the kernel panics, which require a hard reboot.

[Lenz Grimmer (lenzgr)]

Looks like the repair was successful:

% sudo btrfsck --repair /dev/mapper/ubuntu--vg-container
enabling repair mode
Checking filesystem on /dev/mapper/ubuntu--vg-container
UUID: b95b58fb-d0b2-4735-a4ed-2033537eb89a
checking extents
checking free space cache
cache and super generation don't match, space cache will be invalidated
checking fs roots
checking csums
checking root refs
found 37972963086 bytes used err is 0
total csum bytes: 44021104
total tree bytes: 651902976
total fs tree bytes: 470499328
total extent tree bytes: 103186432
btree space waste bytes: 136847949
file data blocks allocated: 126929125376
 referenced 44007616512
Btrfs v3.12

I'll now proceed with testing this against the upstream kernel.

[Lenz Grimmer (lenzgr)]

NB: Trying to "dd" an image of the Btrfs file system to an external USB3 disk using the mainline kernel revealed a different issue, which I reported as bug#1415859.

[Lenz Grimmer (lenzgr)]

Update: using the mainline kernel, I observe a slightly different pattern. When running multiple heavy I/O operations in parallel (e.g. rsyncing a large ISO image to a container, performing an http upload into another one and running "yum update" on all containers), the large uploads start to stall and come to a crawling halt at some point.

"dmesg" reveals some different btrfs related issues:

[ 6838.005920] INFO: task kworker/u16:0:5815 blocked for more than 120 seconds.
[ 6838.005924] Not tainted 3.19.0-031900rc6-generic #201501261152
[ 6838.005925] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 6838.005926] kworker/u16:0 D ffff88024422bb18 0 5815 2 0x00000000
[ 6838.005953] Workqueue: events_unbound btrfs_async_reclaim_metadata_space [btrfs]
[ 6838.005954] ffff88024422bb18 ffff88024422bad8 ffff88024422bfd8 00000000000141c0
[ 6838.005956] ffff88030c1b0700 ffff88021a1e13a0 ffff8802c78a75c0 ffff88024422bb08
[ 6838.005958] ffff88024422bc88 7fffffffffffffff 7fffffffffffffff ffff8802c78a75c0
[ 6838.005959] Call Trace:
[ 6838.005965] [<ffffffff817cd6b9>] schedule+0x29/0x70
[ 6838.005968] [<ffffffff817d0445>] schedule_timeout+0x1b5/0x210
[ 6838.005972] [<ffffffff8108e01a>] ? __queue_delayed_work+0xaa/0x1a0
[ 6838.005974] [<ffffffff8108e5db>] ? try_to_grab_pending+0x4b/0x80
[ 6838.005976] [<ffffffff817cebc7>] wait_for_completion+0xa7/0x160
[ 6838.005979] [<ffffffff810a3fa0>] ? try_to_wake_up+0x2a0/0x2a0
[ 6838.005983] [<ffffffff8121d6c6>] writeback_inodes_sb_nr+0x86/0xb0
[ 6838.005997] [<ffffffffc0630b9d>] shrink_delalloc+0x10d/0x300 [btrfs]
[ 6838.006011] [<ffffffffc0630e68>] flush_space+0xd8/0x150 [btrfs]
[ 6838.006022] [<ffffffffc063175b>] btrfs_async_reclaim_metadata_space+0x14b/0x1d0 [btrfs]
[ 6838.006024] [<ffffffff8108f6dd>] process_one_work+0x14d/0x460
[ 6838.006026] [<ffffffff810900bb>] worker_thread+0x11b/0x3f0
[ 6838.006029] [<ffffffff8108ffa0>] ? create_worker+0x1e0/0x1e0
[ 6838.006031] [<ffffffff81095cc9>] kthread+0xc9/0xe0
[ 6838.006032] [<ffffffff81095c00>] ? flush_kthread_worker+0x90/0x90
[ 6838.006035] [<ffffffff817d17fc>] ret_from_fork+0x7c/0xb0
[ 6838.006037] [<ffffffff81095c00>] ? flush_kthread_worker+0x90/0x90
[ 6957.962660] INFO: task kworker/u16:0:5815 blocked for more than 120 seconds.
[ 6957.962667] Not tainted 3.19.0-031900rc6-generic #201501261152
[ 6957.962668] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 6957.962671] kworker/u16:0 D ffff88024422bb18 0 5815 2 0x00000000
[ 6957.962706] Workqueue: events_unbound btrfs_async_reclaim_metadata_space [btrfs]
[ 6957.962709] ffff88024422bb18 ffff88024422bad8 ffff88024422bfd8 00000000000141c0
[ 6957.962713] ffff88030c1b0700 ffff88021a1e13a0 ffff8802c78a75c0 ffff88024422bb08
[ 6957.962716] ffff88024422bc88 7fffffffffffffff 7fffffffffffffff ffff8802c78a75c0
[ 6957.962720] Call Trace:
[ 6957.962741] [<ffffffff817cd6b9>] schedule+0x29/0x70
[ 6957.962746] [<ffffffff817d0445>] schedule_timeout+0x1b5/0x210
[ 6957.962752] [<ffffffff8108e01a>] ? __queue_delayed_work+0xaa/0x1a0
[ 6957.962756] [<ffffffff8108e5db>] ? try_to_grab_pending+0x4b/0x80
[ 6957.962760] [<ffff...