Kernel panic in Docker 1.7.1, Ubuntu 14.04 kernel 3.16/Ubuntu 15.04 kernel 3.19

[aidanhs]

A bit like #13940 (in that they're both panics, the stack traces are very different), but present on 3.19.

Trace from 15.04:

Jul 20 16:58:14 vcr005 kernel: [ 2686.115923] ------------[ cut here ]------------
Jul 20 16:58:14 vcr005 kernel: [ 2686.115934] WARNING: CPU: 2 PID: 15380 at /build/buildd/linux-3.19.0/security/apparmor/file.c:607 aa_file_perm+0x1c1/0x430()
Jul 20 16:58:14 vcr005 kernel: [ 2686.115935] AppArmor WARN aa_file_perm: ((!flabel)): 
Jul 20 16:58:14 vcr005 kernel: [ 2686.115937] Modules linked in: xt_nat xt_tcpudp veth xt_conntrack ipt_MASQUERADE nf_nat_masquerade_ipv4 iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 xt_addrtype iptable_filter ip_tables x_tables br_netfilter nf_nat nf_conntrack bridge stp llc aufs binfmt_misc rfcomm bnep uvcvideo videobuf2_vmalloc videobuf2_memops videobuf2_core v4l2_common videodev arc4 media btusb iwldvm mac80211 bluetooth snd_usb_audio snd_usbmidi_lib intel_rapl snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_codec_generic snd_hda_intel snd_hda_controller iosf_mbi snd_hda_codec x86_pkg_temp_thermal snd_hwdep intel_powerclamp iwlwifi thinkpad_acpi snd_pcm coretemp nvram kvm_intel snd_seq_midi snd_seq_midi_event snd_rawmidi kvm snd_seq cfg80211 snd_seq_device mei_me snd_timer snd mei joydev serio_raw soundcore shpchp lpc_ich mac_hid parport_pc ppdev lp parport autofs4 dm_crypt hid_generic usbhid hid crct10dif_pclmul crc32_pclmul ghash_clmulni_intel aesni_intel aes_x86_64 lrw gf128mul glue_helper ablk_helper cryptd i915 psmouse ahci sdhci_pci libahci i2c_algo_bit sdhci drm_kms_helper e1000e drm ptp pps_core wmi video
Jul 20 16:58:14 vcr005 kernel: [ 2686.116003] CPU: 2 PID: 15380 Comm: oninit Not tainted 3.19.0-22-generic #22-Ubuntu
Jul 20 16:58:14 vcr005 kernel: [ 2686.116005] Hardware name: LENOVO 23444TG/23444TG, BIOS G1ET41WW (1.16 ) 05/25/2012
Jul 20 16:58:14 vcr005 kernel: [ 2686.116006]  ffffffff81ad2428 ffff8800a9833ae8 ffffffff817c4188 0000000000000007
Jul 20 16:58:14 vcr005 kernel: [ 2686.116008]  ffff8800a9833b38 ffff8800a9833b28 ffffffff810769aa ffff880211110000
Jul 20 16:58:14 vcr005 kernel: [ 2686.116010]  ffff8800ca9ac430 ffff8801f63d2500 ffff8801e102a1c0 0000000000000002
Jul 20 16:58:14 vcr005 kernel: [ 2686.116013] Call Trace:
Jul 20 16:58:14 vcr005 kernel: [ 2686.116019]  [<ffffffff817c4188>] dump_stack+0x45/0x57
Jul 20 16:58:14 vcr005 kernel: [ 2686.116023]  [<ffffffff810769aa>] warn_slowpath_common+0x8a/0xc0
Jul 20 16:58:14 vcr005 kernel: [ 2686.116026]  [<ffffffff81076a26>] warn_slowpath_fmt+0x46/0x50
Jul 20 16:58:14 vcr005 kernel: [ 2686.116030]  [<ffffffff81359101>] aa_file_perm+0x1c1/0x430
Jul 20 16:58:14 vcr005 kernel: [ 2686.116034]  [<ffffffff810ada5d>] ? check_preempt_wakeup+0x1ad/0x240
Jul 20 16:58:14 vcr005 kernel: [ 2686.116038]  [<ffffffff817c9206>] ? down_read+0x16/0x30
Jul 20 16:58:14 vcr005 kernel: [ 2686.116047]  [<ffffffffc09230d6>] ? au_pin_hdir_lock+0x56/0x70 [aufs]
Jul 20 16:58:14 vcr005 kernel: [ 2686.116054]  [<ffffffffc09233bd>] ? au_do_pin+0xed/0x250 [aufs]
Jul 20 16:58:14 vcr005 kernel: [ 2686.116058]  [<ffffffff81356262>] common_file_perm+0x42/0xf0
Jul 20 16:58:14 vcr005 kernel: [ 2686.116065]  [<ffffffffc091cec8>] ? au_ready_to_write+0x1d8/0x330 [aufs]
Jul 20 16:58:14 vcr005 kernel: [ 2686.116067]  [<ffffffff81356468>] apparmor_file_permission+0x18/0x20
Jul 20 16:58:14 vcr005 kernel: [ 2686.116070]  [<ffffffff813141a3>] security_file_permission+0x23/0xa0
Jul 20 16:58:14 vcr005 kernel: [ 2686.116075]  [<ffffffffc091d815>] au_do_iter+0x25/0xf0 [aufs]
Jul 20 16:58:14 vcr005 kernel: [ 2686.116081]  [<ffffffffc091e949>] aufs_write_iter+0xe9/0x1e0 [aufs]
Jul 20 16:58:14 vcr005 kernel: [ 2686.116085]  [<ffffffffc091e860>] ? aufs_fallocate+0x1e0/0x1e0 [aufs]
Jul 20 16:58:14 vcr005 kernel: [ 2686.116091]  [<ffffffffc091e860>] ? aufs_fallocate+0x1e0/0x1e0 [aufs]
Jul 20 16:58:14 vcr005 kernel: [ 2686.116095]  [<ffffffff812412e9>] aio_run_iocb+0x1f9/0x3d0
Jul 20 16:58:14 vcr005 kernel: [ 2686.116098]  [<ffffffff810a72a8>] ? __enqueue_entity+0x78/0x80
Jul 20 16:58:14 vcr005 kernel: [ 2686.116101]  [<ffffffff8124234e>] ? do_io_submit+0x1ce/0x4d0
Jul 20 16:58:14 vcr005 kernel: [ 2686.116105]  [<ffffffff811d6fde>] ? kmem_cache_alloc+0x1ce/0x200
Jul 20 16:58:14 vcr005 kernel: [ 2686.116108]  [<ffffffff8124234e>] ? do_io_submit+0x1ce/0x4d0
Jul 20 16:58:14 vcr005 kernel: [ 2686.116110]  [<ffffffff812423d6>] do_io_submit+0x256/0x4d0
Jul 20 16:58:14 vcr005 kernel: [ 2686.116114]  [<ffffffff81242660>] SyS_io_submit+0x10/0x20
Jul 20 16:58:14 vcr005 kernel: [ 2686.116117]  [<ffffffff817cb24d>] system_call_fastpath+0x16/0x1b
Jul 20 16:58:14 vcr005 kernel: [ 2686.116119] ---[ end trace 6364c3c0294763f6 ]---
Jul 20 16:58:14 vcr005 kernel: [ 2686.116127] BUG: unable to handle kernel NULL pointer dereference at 0000000000000040
Jul 20 16:58:14 vcr005 kernel: [ 2686.116167] IP: [<ffffffff81358f93>] aa_file_perm+0x53/0x430
Jul 20 16:58:14 vcr005 kernel: [ 2686.116194] PGD b84d5067 PUD b161a067 PMD 0 
Jul 20 16:58:14 vcr005 kernel: [ 2686.116215] Oops: 0000 [#1] SMP 
Jul 20 16:58:14 vcr005 kernel: [ 2686.116232] Modules linked in: xt_nat xt_tcpudp veth xt_conntrack ipt_MASQUERADE nf_nat_masquerade_ipv4 iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 xt_addrtype iptable_filter ip_tables x_tables br_netfilter nf_nat nf_conntrack bridge stp llc aufs binfmt_misc rfcomm bnep uvcvideo videobuf2_vmalloc videobuf2_memops videobuf2_core v4l2_common videodev arc4 media btusb iwldvm mac80211 bluetooth snd_usb_audio snd_usbmidi_lib intel_rapl snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_codec_generic snd_hda_intel snd_hda_controller iosf_mbi snd_hda_codec x86_pkg_temp_thermal snd_hwdep intel_powerclamp iwlwifi thinkpad_acpi snd_pcm coretemp nvram kvm_intel snd_seq_midi snd_seq_midi_event snd_rawmidi kvm snd_seq cfg80211 snd_seq_device mei_me snd_timer snd mei joydev serio_raw soundcore shpchp lpc_ich mac_hid parport_pc ppdev lp parport autofs4 dm_crypt hid_generic usbhid hid crct10dif_pclmul crc32_pclmul ghash_clmulni_intel aesni_intel aes_x86_64 lrw gf128mul glue_helper ablk_helper cryptd i915 psmouse ahci sdhci_pci libahci i2c_algo_bit sdhci drm_kms_helper e1000e drm ptp pps_core wmi video
Jul 20 16:58:14 vcr005 kernel: [ 2686.116755] CPU: 2 PID: 15380 Comm: oninit Tainted: G        W      3.19.0-22-generic #22-Ubuntu
Jul 20 16:58:14 vcr005 kernel: [ 2686.116792] Hardware name: LENOVO 23444TG/23444TG, BIOS G1ET41WW (1.16 ) 05/25/2012
Jul 20 16:58:14 vcr005 kernel: [ 2686.116826] task: ffff8801df1f6bf0 ti: ffff8800a9830000 task.ti: ffff8800a9830000
Jul 20 16:58:14 vcr005 kernel: [ 2686.116859] RIP: 0010:[<ffffffff81358f93>]  [<ffffffff81358f93>] aa_file_perm+0x53/0x430
Jul 20 16:58:14 vcr005 kernel: [ 2686.116897] RSP: 0018:ffff8800a9833b98  EFLAGS: 00010246
Jul 20 16:58:14 vcr005 kernel: [ 2686.116921] RAX: 0000000000000024 RBX: ffff8800ca9ac430 RCX: 0000000000000024
Jul 20 16:58:14 vcr005 kernel: [ 2686.116953] RDX: 0000000000000007 RSI: 0000000000000000 RDI: 0000000000000009
Jul 20 16:58:14 vcr005 kernel: [ 2686.116985] RBP: ffff8800a9833c38 R08: 0000000000020378 R09: 00000000000005ea
Jul 20 16:58:14 vcr005 kernel: [ 2686.117014] R10: 0000000000000096 R11: 00000000000005ea R12: ffff8801f63d2500
Jul 20 16:58:14 vcr005 kernel: [ 2686.117044] R13: 0000000000000000 R14: 0000000000000002 R15: 0000000000000000
Jul 20 16:58:14 vcr005 kernel: [ 2686.117069] FS:  00007f15d4ca4720(0000) GS:ffff88021e280000(0000) knlGS:0000000000000000
Jul 20 16:58:14 vcr005 kernel: [ 2686.117096] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Jul 20 16:58:14 vcr005 kernel: [ 2686.117111] CR2: 0000000000000040 CR3: 00000000cbcdb000 CR4: 00000000001407e0
Jul 20 16:58:14 vcr005 kernel: [ 2686.117129] Stack:
Jul 20 16:58:14 vcr005 kernel: [ 2686.117135]  ffff8800a9833be8 ffffffff810ada5d ffff88001f7aae40 ffffffff817c9206
Jul 20 16:58:14 vcr005 kernel: [ 2686.117158]  ffff8800a9833bf8 ffff8800a9833d20 ffff8801fb9873d8 000000111f7aae40
Jul 20 16:58:14 vcr005 kernel: [ 2686.117189]  ffff8800a9833bf8 ffffffffc09230d6 ffff8800a9833d20 ffff8800a9833d20
Jul 20 16:58:14 vcr005 kernel: [ 2686.117220] Call Trace:
Jul 20 16:58:14 vcr005 kernel: [ 2686.117235]  [<ffffffff810ada5d>] ? check_preempt_wakeup+0x1ad/0x240
Jul 20 16:58:14 vcr005 kernel: [ 2686.117265]  [<ffffffff817c9206>] ? down_read+0x16/0x30
Jul 20 16:58:14 vcr005 kernel: [ 2686.117295]  [<ffffffffc09230d6>] ? au_pin_hdir_lock+0x56/0x70 [aufs]
Jul 20 16:58:14 vcr005 kernel: [ 2686.117316]  [<ffffffffc09233bd>] ? au_do_pin+0xed/0x250 [aufs]
Jul 20 16:58:14 vcr005 kernel: [ 2686.117333]  [<ffffffff81356262>] common_file_perm+0x42/0xf0
Jul 20 16:58:14 vcr005 kernel: [ 2686.117351]  [<ffffffffc091cec8>] ? au_ready_to_write+0x1d8/0x330 [aufs]
Jul 20 16:58:14 vcr005 kernel: [ 2686.117375]  [<ffffffff81356468>] apparmor_file_permission+0x18/0x20
Jul 20 16:58:14 vcr005 kernel: [ 2686.117402]  [<ffffffff813141a3>] security_file_permission+0x23/0xa0
Jul 20 16:58:14 vcr005 kernel: [ 2686.117434]  [<ffffffffc091d815>] au_do_iter+0x25/0xf0 [aufs]
Jul 20 16:58:14 vcr005 kernel: [ 2686.117462]  [<ffffffffc091e949>] aufs_write_iter+0xe9/0x1e0 [aufs]
Jul 20 16:58:14 vcr005 kernel: [ 2686.117492]  [<ffffffffc091e860>] ? aufs_fallocate+0x1e0/0x1e0 [aufs]
Jul 20 16:58:14 vcr005 kernel: [ 2686.117512]  [<ffffffffc091e860>] ? aufs_fallocate+0x1e0/0x1e0 [aufs]
Jul 20 16:58:14 vcr005 kernel: [ 2686.117530]  [<ffffffff812412e9>] aio_run_iocb+0x1f9/0x3d0
Jul 20 16:58:14 vcr005 kernel: [ 2686.118504]  [<ffffffff810a72a8>] ? __enqueue_entity+0x78/0x80
Jul 20 16:58:14 vcr005 kernel: [ 2686.119470]  [<ffffffff8124234e>] ? do_io_submit+0x1ce/0x4d0
Jul 20 16:58:14 vcr005 kernel: [ 2686.120474]  [<ffffffff811d6fde>] ? kmem_cache_alloc+0x1ce/0x200
Jul 20 16:58:14 vcr005 kernel: [ 2686.121521]  [<ffffffff8124234e>] ? do_io_submit+0x1ce/0x4d0
Jul 20 16:58:14 vcr005 kernel: [ 2686.122602]  [<ffffffff812423d6>] do_io_submit+0x256/0x4d0
Jul 20 16:58:14 vcr005 kernel: [ 2686.123662]  [<ffffffff81242660>] SyS_io_submit+0x10/0x20
Jul 20 16:58:14 vcr005 kernel: [ 2686.124666]  [<ffffffff817cb24d>] system_call_fastpath+0x16/0x1b
Jul 20 16:58:14 vcr005 kernel: [ 2686.125588] Code: 01 00 00 4d 85 e4 0f 84 3c 01 00 00 4d 8b ac 24 c8 00 00 00 4d 8b 7d 08 4d 85 ff 0f 84 57 01 00 00 f6 43 40 02 45 8b 6d 10 75 47 <41> f6 47 40 02 75 40 41 f7 d5 45 21 f5 44 89 6d 90 0f 84 b6 00 
Jul 20 16:58:14 vcr005 kernel: [ 2686.127617] RIP  [<ffffffff81358f93>] aa_file_perm+0x53/0x430
Jul 20 16:58:14 vcr005 kernel: [ 2686.128610]  RSP <ffff8800a9833b98>
Jul 20 16:58:14 vcr005 kernel: [ 2686.129696] CR2: 0000000000000040
Jul 20 16:58:14 vcr005 kernel: [ 2686.137404] ---[ end trace 6364c3c0294763f7 ]---

The 14.04 trace is pretty similar, including mentions of aufs and apparmor. These lines are exactly the same for 14.04 (excluding offsets of course):

apparmor_file_permission+0x18/0x20
security_file_permission+0x23/0xa0
au_do_iter+0x25/0xf0 [aufs]
aufs_write_iter+0xe9/0x1e0 [aufs]

---

BUG REPORT INFORMATION

$ docker version
Client version: 1.7.1
Client API version: 1.19
Go version (client): go1.4.2
Git commit (client): 786b29d
OS/Arch (client): linux/amd64
Server version: 1.7.1
Server API version: 1.19
Go version (server): go1.4.2
Git commit (server): 786b29d
OS/Arch (server): linux/amd64

$ docker info   
Containers: 0
Images: 191
Storage Driver: aufs
 Root Dir: /var/lib/docker/aufs
 Backing Filesystem: extfs
 Dirs: 191
 Dirperm1 Supported: true
Execution Driver: native-0.2
Logging Driver: json-file
Kernel Version: 3.19.0-22-generic
Operating System: Ubuntu 15.04
CPUs: 4
Total Memory: 7.529 GiB
Name: vcr005
ID: 2IDI:AT5B:LFKI:K3IQ:QYUH:NIEA:MKPM:TCT7:L7VQ:QNFM:O37Y:HF3J
WARNING: No swap limit support

$: uname -a
Linux vcr005 3.19.0-22-generic #22-Ubuntu SMP Tue Jun 16 17:15:15 UTC 2015 x86_64 x86_64 x86_64 GNU/Linux

Machines: Lenovo T430 and Lenovo T420

Result expected: the kernel does not panic.

----------END REPORT ---------

[phemmer]

Have you reported this on the kernel bug tracker? While docker might be able to put in a workaround for the issue, the issue itself lies in the kernel, and the kernel team is the one that ultimately needs to fix it.

[unclejack]

These kernels are custom patched by Canonical with aufs and I'm seeing aufs in the call traces. It would be a really good idea to report these issues to Canonical to see if they can help out, especially if you have a good way to reproduce this.

[aidanhs]

A good repro is always the problem, unfortunately it seems to be intermittent. I'm currently working on getting it in a VM.

[LK4D4]

@aidanhs For kernel guys trace might be enough. Definitely makes sense to report to Canonical.

[aidanhs]

Commented on https://bugs.launchpad.net/apparmor/+bug/1448912 which seems suspiciously similar. I'll see whether they agree.

[justincormack]

This was resolved in the upstream report.