Docker build hangs on XFS with kernel 4.10

Bug #1679768 reported by Doki
42
This bug affects 8 people
Affects Status Importance Assigned to Milestone
docker.io (Ubuntu)
Invalid
Undecided
Unassigned
linux (Ubuntu)
Invalid
Undecided
Unassigned

Bug Description

I have my docker partition on XFS, and recently upgraded to Zesty Beta.
Most of my `docker build.` processes hangs with a similar message in syslog:

```
Apr 4 09:19:04 epuspdxn0004 kernel: [ 1330.171267] INFO: task kworker/1:3:5589 blocked for more than 120 seconds.
Apr 4 09:19:04 epuspdxn0004 kernel: [ 1330.171275] Tainted: P O 4.10.0-15-generic #17-Ubuntu
Apr 4 09:19:04 epuspdxn0004 kernel: [ 1330.171278] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Apr 4 09:19:04 epuspdxn0004 kernel: [ 1330.171282] kworker/1:3 D 0 5589 2 0x00000000
Apr 4 09:19:04 epuspdxn0004 kernel: [ 1330.171310] Workqueue: aufsd wkq_func [aufs]
Apr 4 09:19:04 epuspdxn0004 kernel: [ 1330.171313] Call Trace:
Apr 4 09:19:04 epuspdxn0004 kernel: [ 1330.171323] __schedule+0x233/0x6f0
Apr 4 09:19:04 epuspdxn0004 kernel: [ 1330.171415] ? kmem_zone_alloc+0x81/0x120 [xfs]
Apr 4 09:19:04 epuspdxn0004 kernel: [ 1330.171419] schedule+0x36/0x80
Apr 4 09:19:04 epuspdxn0004 kernel: [ 1330.171423] rwsem_down_read_failed+0xfa/0x150
Apr 4 09:19:04 epuspdxn0004 kernel: [ 1330.171491] ? xfs_file_buffered_aio_read+0x3d/0xc0 [xfs]
Apr 4 09:19:04 epuspdxn0004 kernel: [ 1330.171496] call_rwsem_down_read_failed+0x18/0x30
Apr 4 09:19:04 epuspdxn0004 kernel: [ 1330.171500] down_read+0x20/0x40
Apr 4 09:19:04 epuspdxn0004 kernel: [ 1330.171567] xfs_ilock+0xf5/0x110 [xfs]
Apr 4 09:19:04 epuspdxn0004 kernel: [ 1330.171628] xfs_file_buffered_aio_read+0x3d/0xc0 [xfs]
Apr 4 09:19:04 epuspdxn0004 kernel: [ 1330.171686] xfs_file_read_iter+0x68/0xc0 [xfs]
Apr 4 09:19:04 epuspdxn0004 kernel: [ 1330.171692] new_sync_read+0xd2/0x120
Apr 4 09:19:04 epuspdxn0004 kernel: [ 1330.171695] __vfs_read+0x26/0x40
Apr 4 09:19:04 epuspdxn0004 kernel: [ 1330.171697] vfs_read+0x96/0x130
Apr 4 09:19:04 epuspdxn0004 kernel: [ 1330.171715] vfsub_read_u+0x14/0x30 [aufs]
Apr 4 09:19:04 epuspdxn0004 kernel: [ 1330.171729] vfsub_read_k+0x2c/0x40 [aufs]
Apr 4 09:19:04 epuspdxn0004 kernel: [ 1330.171743] au_copy_file+0x10c/0x370 [aufs]
Apr 4 09:19:04 epuspdxn0004 kernel: [ 1330.171756] au_cp_regular+0x11a/0x200 [aufs]
Apr 4 09:19:04 epuspdxn0004 kernel: [ 1330.171767] ? au_cp_regular+0x1ef/0x200 [aufs]
Apr 4 09:19:04 epuspdxn0004 kernel: [ 1330.171777] ? au_cp_regular+0x188/0x200 [aufs]
Apr 4 09:19:04 epuspdxn0004 kernel: [ 1330.171788] cpup_entry+0x538/0x5f0 [aufs]
Apr 4 09:19:04 epuspdxn0004 kernel: [ 1330.171802] ? vfsub_lookup_one_len+0x31/0x70 [aufs]
Apr 4 09:19:04 epuspdxn0004 kernel: [ 1330.171814] au_cpup_single.constprop.18+0x145/0x6a0 [aufs]
Apr 4 09:19:04 epuspdxn0004 kernel: [ 1330.171820] ? dput+0x40/0x270
Apr 4 09:19:04 epuspdxn0004 kernel: [ 1330.171831] au_cpup_simple+0x4d/0x80 [aufs]
Apr 4 09:19:04 epuspdxn0004 kernel: [ 1330.171842] au_call_cpup_simple+0x28/0x40 [aufs]
Apr 4 09:19:04 epuspdxn0004 kernel: [ 1330.171855] wkq_func+0x14/0x80 [aufs]
Apr 4 09:19:04 epuspdxn0004 kernel: [ 1330.171861] process_one_work+0x1fc/0x4b0
Apr 4 09:19:04 epuspdxn0004 kernel: [ 1330.171864] worker_thread+0x4b/0x500
Apr 4 09:19:04 epuspdxn0004 kernel: [ 1330.171870] kthread+0x101/0x140
Apr 4 09:19:04 epuspdxn0004 kernel: [ 1330.171873] ? process_one_work+0x4b0/0x4b0
Apr 4 09:19:04 epuspdxn0004 kernel: [ 1330.171878] ? kthread_create_on_node+0x60/0x60
Apr 4 09:19:04 epuspdxn0004 kernel: [ 1330.171883] ? SyS_exit_group+0x14/0x20
Apr 4 09:19:04 epuspdxn0004 kernel: [ 1330.171887] ret_from_fork+0x2c/0x40
Apr 4 09:19:04 epuspdxn0004 kernel: [ 1330.171895] INFO: task useradd:5758 blocked for more than 120 seconds.
Apr 4 09:19:04 epuspdxn0004 kernel: [ 1330.171899] Tainted: P O 4.10.0-15-generic #17-Ubuntu
```

Revision history for this message
Doki (lkishalmi) wrote :

I just booted up with my yakkety kernel 4.8 and this bug has gone. I guess it is due to the recent changes in the XFS.

Revision history for this message
Joshua Powers (powersj) wrote :

@lkishalmi, can you collect some more details for us by running:

apport-collect -p linux 1679768

Changed in docker.io (Ubuntu):
status: New → Incomplete
Revision history for this message
Gaylord Holder (gaylord.holder) wrote :

Same problem from here. upgrade from 16.10 to 17.04 and the docker cache on and xfs files system hangs with lots of xfs errors. Submitting apport-collect.

Revision history for this message
Chris West (faux) wrote :
Download full text (4.2 KiB)

Ditto.

I can trigger it with:

$ docker run debian:sid ln /usr/lib/os-release /usr/lib/os-release.dpkg-tmp

This will output nothing and just hang forever. That command is what apt-get update tries to do while installing the base-files update for debian:sid.

Here's the sysrq+w output, it seems to be angry about aufs_link.

Workqueue: aufsd wkq_func [aufs]
Call Trace:
 __schedule+0x233/0x6f0
 ? kmem_zone_alloc+0x81/0x120 [xfs]
 schedule+0x36/0x80
 rwsem_down_read_failed+0xfa/0x150
 ? xfs_file_buffered_aio_read+0x3d/0xc0 [xfs]
 call_rwsem_down_read_failed+0x18/0x30
 down_read+0x20/0x40
 xfs_ilock+0xf5/0x110 [xfs]
 xfs_file_buffered_aio_read+0x3d/0xc0 [xfs]
 xfs_file_read_iter+0x68/0xc0 [xfs]
 new_sync_read+0xd2/0x120
 __vfs_read+0x26/0x40
 vfs_read+0x96/0x130
 vfsub_read_u+0x14/0x30 [aufs]
 vfsub_read_k+0x2c/0x40 [aufs]
 au_copy_file+0x10c/0x370 [aufs]
 au_cp_regular+0x11a/0x200 [aufs]
 ? au_cp_regular+0x1ef/0x200 [aufs]
 ? au_cp_regular+0x188/0x200 [aufs]
 cpup_entry+0x538/0x5f0 [aufs]
 ? vfsub_lookup_one_len+0x31/0x70 [aufs]
 ? kmem_cache_alloc_trace+0xd7/0x190
 au_cpup_single.constprop.18+0x145/0x6a0 [aufs]
 ? dput+0x40/0x270
 au_cpup_simple+0x4d/0x80 [aufs]
 au_call_cpup_simple+0x28/0x40 [aufs]
 wkq_func+0x14/0x80 [aufs]
 process_one_work+0x1fc/0x4b0
 worker_thread+0x4b/0x500
 kthread+0x109/0x140
 ? process_one_work+0x4b0/0x4b0
 ? kthread_create_on_node+0x60/0x60
 ret_from_fork+0x2c/0x40
kworker/4:2 D 0 150 2 0x00000000
Workqueue: aufsd wkq_func [aufs]
Call Trace:
 __schedule+0x233/0x6f0
 schedule+0x36/0x80
 rwsem_down_write_failed+0x21d/0x3a0
 call_rwsem_down_write_failed+0x17/0x30
 down_write+0x2d/0x40
 cpup_entry+0x49e/0x5f0 [aufs]
 ? vfsub_lookup_one_len+0x31/0x70 [aufs]
 ? au_sio_lkup_one+0x93/0xa0 [aufs]
 ? kmem_cache_alloc_trace+0xd7/0x190
 au_cpup_single.constprop.18+0x145/0x6a0 [aufs]
 ? dput+0x40/0x270
 au_cpup_simple+0x4d/0x80 [aufs]
 au_call_cpup_simple+0x28/0x40 [aufs]
 wkq_func+0x14/0x80 [aufs]
 process_one_work+0x1fc/0x4b0
 worker_thread+0x4b/0x500
 kthread+0x109/0x140
 ? process_one_work+0x4b0/0x4b0
 ? kthread_create_on_node+0x60/0x60
 ret_from_fork+0x2c/0x40
dpkg D 0 7061 7052 0x00000007
Call Trace:
 __schedule+0x233/0x6f0
 ? set_next_entity+0xc3/0x1b0
 schedule+0x36/0x80
 schedule_timeout+0x22a/0x3f0
 ? __schedule+0x23b/0x6f0
 ? insert_work+0x7c/0xc0
 wait_for_completion+0xb4/0x140
 ? wake_up_q+0x80/0x80
 au_wkq_do_wait+0x91/0xf0 [aufs]
 ? au_wkq_run+0x60/0x60 [aufs]
 ? au_do_sio_cpup_simple+0x110/0x110 [aufs]
 au_do_sio_cpup_simple+0x99/0x110 [aufs]
 au_sio_cpup_simple+0x21/0x70 [aufs]
 au_cpup_or_link+0x123/0x360 [aufs]
 aufs_link+0x476/0x6a0 [aufs]
 ? h_permission+0x128/0x170 [aufs]
 vfs_link+0x241/0x330
 SyS_link+0x1f8/0x210
 do_syscall_64+0x5b/0xc0
 entry_SYSCALL64_slow_path+0x25/0x25
RIP: 0033:0x7f5ef07e8db7
RSP: 002b:00007ffd8f75b9d8 EFLAGS: 00000202 ORIG_RAX: 0000000000000056
RAX: ffffffffffffffda RBX: 00007ffd8f75beb0 RCX: 00007f5ef07e8db7
RDX: 00000000000081a4 RSI: 00005636d984a560 RDI: 00005636d984a510
RBP: 00005636d9848b70 R08: 00005636d984a910 R09: 0000000000000100
R10: 0000000000000002 R11: 0000000000000202 R12: 00005636d984a5b0
R13: 0000000000000000 R14: 00005636d97eb830 R15...

Read more...

Revision history for this message
Chris West (faux) wrote : apport information

AlsaDevices:
 total 0
 crw-rw---- 1 root audio 116, 1 Jul 7 22:59 seq
 crw-rw---- 1 root audio 116, 33 Jul 7 22:59 timer
AplayDevices: Error: [Errno 2] No such file or directory
ApportVersion: 2.20.4-0ubuntu4.1
Architecture: amd64
ArecordDevices: Error: [Errno 2] No such file or directory
AudioDevicesInUse: Error: command ['fuser', '-v', '/dev/snd/seq', '/dev/snd/timer'] failed with exit code 1:
DistroRelease: Ubuntu 17.04
HibernationDevice: RESUME=UUID=6388d9a1-4cc2-4946-a427-3126a1a153f5
InstallationDate: Installed on 2017-03-15 (114 days ago)
InstallationMedia: Ubuntu-Server 16.04.2 LTS "Xenial Xerus" - Release amd64 (20170215.8)
IwConfig: Error: [Errno 2] No such file or directory
Package: linux (not installed)
PciMultimedia:

ProcEnviron:
 LANG=en_US.utf8
 SHELL=/bin/bash
 TERM=xterm-256color
 PATH=(custom, no user)
ProcFB: 0 inteldrmfb
ProcKernelCmdLine: BOOT_IMAGE=/boot/vmlinuz-4.10.0-26-generic root=UUID=e0f7b691-d355-409f-8591-3d94db7e7984 ro noquiet nosplash net.ifnames=0 biosdevname=0
ProcVersionSignature: Ubuntu 4.10.0-26.30-generic 4.10.17
RelatedPackageVersions:
 linux-restricted-modules-4.10.0-26-generic N/A
 linux-backports-modules-4.10.0-26-generic N/A
 linux-firmware 1.164.1
RfKill: Error: [Errno 2] No such file or directory
Tags: zesty
Uname: Linux 4.10.0-26-generic x86_64
UpgradeStatus: Upgraded to zesty on 2017-07-03 (4 days ago)
UserGroups:

_MarkForUpload: True
dmi.bios.date: 12/04/2012
dmi.bios.vendor: Intel Corp.
dmi.bios.version: BLH6710H.86A.0160.2012.1204.1156
dmi.board.asset.tag: To be filled by O.E.M.
dmi.board.name: DH67BL
dmi.board.vendor: Intel Corporation
dmi.board.version: AAG10189-209
dmi.chassis.type: 3
dmi.modalias: dmi:bvnIntelCorp.:bvrBLH6710H.86A.0160.2012.1204.1156:bd12/04/2012:svn:pn:pvr:rvnIntelCorporation:rnDH67BL:rvrAAG10189-209:cvn:ct3:cvr:

tags: added: apport-collected zesty
Revision history for this message
Chris West (faux) wrote : CRDA.txt

apport information

Revision history for this message
Chris West (faux) wrote : CurrentDmesg.txt

apport information

Revision history for this message
Chris West (faux) wrote : JournalErrors.txt

apport information

Revision history for this message
Chris West (faux) wrote : Lspci.txt

apport information

Revision history for this message
Chris West (faux) wrote : Lsusb.txt

apport information

Revision history for this message
Chris West (faux) wrote : ProcCpuinfo.txt

apport information

Revision history for this message
Chris West (faux) wrote : ProcCpuinfoMinimal.txt

apport information

Revision history for this message
Chris West (faux) wrote : ProcInterrupts.txt

apport information

Revision history for this message
Chris West (faux) wrote : ProcModules.txt

apport information

Revision history for this message
Chris West (faux) wrote : UdevDb.txt

apport information

Revision history for this message
Chris West (faux) wrote : WifiSyslog.txt

apport information

Revision history for this message
Brian Moyles (bmoyles) wrote :

Seeing the same on Xenial when using linux-hwe-edge

Revision history for this message
Ubuntu Kernel Bot (ubuntu-kernel-bot) wrote : Missing required logs.

This bug is missing log files that will aid in diagnosing the problem. While running an Ubuntu kernel (not a mainline or third-party kernel) please enter the following command in a terminal window:

apport-collect 1679768

and then change the status of the bug to 'Confirmed'.

If, due to the nature of the issue you have encountered, you are unable to run this command, please add a comment stating that fact and change the bug status to 'Confirmed'.

This change has been made by an automated script, maintained by the Ubuntu Kernel Team.

Changed in linux (Ubuntu):
status: New → Incomplete
Revision history for this message
Dawei wang (daweiwang.gatekeeper) wrote :

Got the same issue, when using rpm/yum in docker container with aufs and xfs.

Switched docker to overlay2 and it worked.

Revision history for this message
Scott Emmons (lscotte) wrote :
Download full text (4.2 KiB)

We are seeing the same issue here with 4.10.0-24-generic, and will see if we can reproduce with a newer hwe backport (4.11.0-13-generic).

Jul 20 14:32:47 ubuntu kernel: INFO: task kworker/5:2:574 blocked for more than 120 seconds.
Jul 20 14:32:47 ubuntu kernel: Tainted: P O 4.10.0-24-generic #28~16.04.1-Ubuntu
Jul 20 14:32:47 ubuntu kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this messa
Jul 20 14:32:47 ubuntu kernel: kworker/5:2 D 0 574 2 0x00000000
Jul 20 14:32:47 ubuntu kernel: Workqueue: aufsd wkq_func [aufs]
Jul 20 14:32:47 ubuntu kernel: Call Trace:
Jul 20 14:32:47 ubuntu kernel: __schedule+0x232/0x700
Jul 20 14:32:47 ubuntu kernel: ? kmem_cache_alloc+0xd7/0x1b0
Jul 20 14:32:47 ubuntu kernel: ? kmem_zone_alloc+0x81/0x120 [xfs]
Jul 20 14:32:47 ubuntu kernel: schedule+0x36/0x80
Jul 20 14:32:47 ubuntu kernel: rwsem_down_read_failed+0xf9/0x150
Jul 20 14:32:47 ubuntu kernel: ? xfs_trans_free_item_desc+0x33/0x40 [xfs]
Jul 20 14:32:47 ubuntu kernel: ? xfs_trans_free_items+0x80/0xb0 [xfs]
Jul 20 14:32:47 ubuntu kernel: ? xfs_file_buffered_aio_read+0x3d/0xc0 [xfs]
Jul 20 14:32:47 ubuntu kernel: call_rwsem_down_read_failed+0x18/0x30
Jul 20 14:32:47 ubuntu kernel: down_read+0x20/0x40
Jul 20 14:32:47 ubuntu kernel: xfs_ilock+0xfa/0x110 [xfs]
Jul 20 14:32:47 ubuntu kernel: xfs_file_buffered_aio_read+0x3d/0xc0 [xfs]
Jul 20 14:32:47 ubuntu kernel: xfs_file_read_iter+0x68/0xc0 [xfs]
Jul 20 14:32:47 ubuntu kernel: new_sync_read+0xd0/0x120
Jul 20 14:32:47 ubuntu kernel: __vfs_read+0x26/0x40
Jul 20 14:32:47 ubuntu kernel: vfs_read+0x93/0x130
Jul 20 14:32:47 ubuntu kernel: vfsub_read_u+0x14/0x30 [aufs]
Jul 20 14:32:47 ubuntu kernel: vfsub_read_k+0x2c/0x40 [aufs]
Jul 20 14:32:47 ubuntu kernel: au_copy_file+0x10f/0x370 [aufs]
Jul 20 14:32:47 ubuntu kernel: au_cp_regular+0x10f/0x200 [aufs]
Jul 20 14:32:47 ubuntu kernel: ? au_cp_regular+0x1ad/0x200 [aufs]
Jul 20 14:32:47 ubuntu kernel: ? au_cp_regular+0x177/0x200 [aufs]
Jul 20 14:32:47 ubuntu kernel: cpup_entry+0x552/0x610 [aufs]
Jul 20 14:32:47 ubuntu kernel: au_cpup_single.constprop.18+0x145/0x6a0 [aufs]
Jul 20 14:32:47 ubuntu kernel: ? dput+0x34/0x250
Jul 20 14:32:47 ubuntu kernel: au_cpup_simple+0x53/0x90 [aufs]
Jul 20 14:32:47 ubuntu kernel: au_call_cpup_simple+0x28/0x40 [aufs]
Jul 20 14:32:47 ubuntu kernel: wkq_func+0x14/0x80 [aufs]
Jul 20 14:32:47 ubuntu kernel: process_one_work+0x16b/0x4a0
Jul 20 14:32:47 ubuntu kernel: worker_thread+0x4b/0x500
Jul 20 14:32:47 ubuntu kernel: kthread+0x109/0x140
Jul 20 14:32:47 ubuntu kernel: ? process_one_work+0x4a0/0x4a0
Jul 20 14:32:47 ubuntu kernel: ? kthread_create_on_node+0x60/0x60
Jul 20 14:32:47 ubuntu kernel: ret_from_fork+0x2c/0x40
Jul 20 14:32:47 ubuntu kernel: INFO: task s6-chown:5548 blocked for more than 120 seconds.
Jul 20 14:32:47 ubuntu kernel: Tainted: P O 4.10.0-24-generic #28~16.04.1-Ubuntu
Jul 20 14:32:47 ubuntu kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this messa
Jul 20 14:32:47 ubuntu kernel: s6-chown D 0 5548 5546 0x00000100
Jul 20 14:32:47 ubuntu kernel: Call Trace:
Jul 20 14:32:47 ubuntu kernel: _...

Read more...

Revision history for this message
Scott Emmons (lscotte) wrote :
Revision history for this message
dino99 (9d9) wrote :
Changed in linux (Ubuntu):
status: Incomplete → Invalid
Changed in docker.io (Ubuntu):
status: Incomplete → Invalid
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.