bionic/linux: hung task triggered by ubuntu_vfat_stress stress-ng testcase

[Kleber Sacilotto de Souza]

When running the ubuntu_vfat_stress on a powerpc64el system with kernel 4.15.0-36-generic it triggers the following hung task:

================================================================================
10:39:09 DEBUG| [stdout] Mounted tmpfs /mnt/vfat-test-56562
10:39:09 DEBUG| [stdout] Created loop image /mnt/vfat-test-56562/vfat-loop-data
10:39:09 DEBUG| [stdout] mkfs.fat 4.1 (2017-01-24)
10:39:09 DEBUG| [stdout]
10:39:09 DEBUG| [stdout] --------------------------------------------------------------------------------
10:39:09 DEBUG| [stdout] VFAT options: dmask=777
10:39:09 DEBUG| [stdout] Stress test: /home/ubuntu/autotest/client/tmp/ubuntu_vfat_stress/src/stress-ng/stress-ng --verify --times --metrics-brief --syslog --keep-name -t 10s --hdd 2 --hdd-opts sync,wr-rnd,rd-rnd,fadv-willneed,fadv-rnd --lockf 2 --seek 2 --aio 2 --aio-requests 32 --dentry 2 --dir 2 --dentry-order stride --fallocate 2 --fstat 2 --dentries 100 --lease 2 --open 2 --rename 2 --hdd-bytes 4M --fallocate-bytes 4M --chdir 2 --rename 2 --hdd-write-size 512
10:39:09 DEBUG| [stdout] VFAT_IMAGE path: /mnt/vfat-test-56562
10:39:09 DEBUG| [stdout] Mount point: /mnt/vfat-test-56562
10:39:09 DEBUG| [stdout] Date: Thu Oct 18 10:39:09 UTC 2018
10:39:09 DEBUG| [stdout] Host: baltar
10:39:09 DEBUG| [stdout] Kernel: 4.15.0-36-generic #39-Ubuntu SMP Mon Sep 24 16:18:48 UTC 2018
10:39:09 DEBUG| [stdout] Machine: baltar ppc64le ppc64le
10:39:09 DEBUG| [stdout] CPUs online: 160
10:39:09 DEBUG| [stdout] CPUs total: 160
10:39:09 DEBUG| [stdout] Page size: 65536
10:39:09 DEBUG| [stdout] Pages avail: 1907765
10:39:09 DEBUG| [stdout] Pages total: 2089666
10:39:09 DEBUG| [stdout] --------------------------------------------------------------------------------
10:39:09 DEBUG| [stdout]
10:39:09 DEBUG| [stdout]
10:39:09 DEBUG| [stdout] stress-ng: info: [146983] dispatching hogs: 2 hdd, 2 lockf, 2 seek, 2 aio, 2 dentry, 2 dir, 2 fallocate, 2 fstat, 2 lease, 2 open, 2 rename, 2 chdir, 2 rename
10:39:09 DEBUG| [stdout] stress-ng: info: [146983] cache allocate: using built-in defaults as unable to determine cache details
10:39:11 DEBUG| [stdout] stress-ng: fail: [147027] stress-ng-chdir: mkdir failed, errno=28 (No space left on device)
10:39:11 DEBUG| [stdout] stress-ng: fail: [147007] stress-ng-hdd: read failed, errno=28 (No space left on device)
10:39:11 DEBUG| [stdout] stress-ng: fail: [146993] stress-ng-hdd: read failed, errno=28 (No space left on device)
10:39:11 DEBUG| [stdout] stress-ng: fail: [147005] stress-ng-chdir: mkdir failed, errno=28 (No space left on device)
10:39:12 DEBUG| [stdout] stress-ng: error: [146983] process 146993 (stress-ng-hdd) terminated with an error, exit status=1 (stress-ng core failure)
10:39:12 DEBUG| [stdout] stress-ng: error: [146983] process 147007 (stress-ng-hdd) terminated with an error, exit status=1 (stress-ng core failure)
10:42:05 DEBUG| [stdout] Found kernel warning and/or call trace:
10:42:05 DEBUG| [stdout]
10:42:05 DEBUG| [stdout] [ 5869.838856] TESTING: --verify --times --metrics-brief --syslog --keep-name -t 10s --hdd 2 --hdd-opts sync,wr-rnd,rd-rnd,fadv-willneed,fadv-rnd --lockf 2 --seek 2 --aio 2 --aio-requests 32 --dentry 2 --dir 2 --dentry-order stride --fallocate 2 --fstat 2 --dentries 100 --lease 2 --open 2 --rename 2 --hdd-bytes 4M --fallocate-bytes 4M --chdir 2 --rename 2 --hdd-write-size 512
10:42:05 DEBUG| [stdout] [ 5870.027499] ubuntu_vfat_str (56562): drop_caches: 1
10:42:05 DEBUG| [stdout] [ 5870.037987] ubuntu_vfat_str (56562): drop_caches: 2
10:42:05 DEBUG| [stdout] [ 5870.041591] ubuntu_vfat_str (56562): drop_caches: 3
10:42:05 DEBUG| [stdout] [ 5870.441211] VFAT options: dmask=777
10:42:05 DEBUG| [stdout] [ 5870.441271] Stress test: /home/ubuntu/autotest/client/tmp/ubuntu_vfat_stress/src/stress-ng/stress-ng --verify --times --metrics-brief --syslog --keep-name -t 10s --hdd 2 --hdd-opts sync,wr-rnd,rd-rnd,fadv-willneed,fadv-rnd --lockf 2 --seek 2 --aio 2 --aio-requests 32 --dentry 2 --dir 2 --dentry-order stride --fallocate 2 --fstat 2 --dentries 100 --lease 2 --open 2 --rename 2 --hdd-bytes 4M --fallocate-bytes 4M --chdir 2 --rename 2 --hdd-write-size 512
10:42:05 DEBUG| [stdout] [ 5870.441296] Mount point: /mnt/vfat-test-56562
10:42:05 DEBUG| [stdout] [ 6044.945208] INFO: task kworker/u322:0:46400 blocked for more than 120 seconds.
10:42:05 DEBUG| [stdout] [ 6044.945277] Not tainted 4.15.0-36-generic #39-Ubuntu
10:42:05 DEBUG| [stdout] [ 6044.945313] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
10:42:05 DEBUG| [stdout] [ 6044.945366] kworker/u322:0 D 0 46400 2 0x00000800
10:42:05 DEBUG| [stdout] [ 6044.945378] Workqueue: writeback wb_workfn (flush-7:0)
10:42:05 DEBUG| [stdout] [ 6044.945380] Call Trace:
10:42:05 DEBUG| [stdout] [ 6044.945385] [c000200db8b22af0] [c000200db8b22b20] 0xc000200db8b22b20 (unreliable)
10:42:05 DEBUG| [stdout] [ 6044.945391] [c000200db8b22cc0] [c00000000001c1d0] __switch_to+0x2a0/0x4d0
10:42:05 DEBUG| [stdout] [ 6044.945397] [c000200db8b22d20] [c000000000cfcae4] __schedule+0x2a4/0xaf0
10:42:05 DEBUG| [stdout] [ 6044.945400] [c000200db8b22df0] [c000000000cfd370] schedule+0x40/0xc0
10:42:05 DEBUG| [stdout] [ 6044.945404] [c000200db8b22e10] [c000000000152d9c] io_schedule+0x2c/0x50
10:42:05 DEBUG| [stdout] [ 6044.945408] [c000200db8b22e40] [c0000000006d1804] wbt_wait+0x484/0x4e0
10:42:05 DEBUG| [stdout] [ 6044.945412] [c000200db8b22ee0] [c000000000698924] blk_mq_make_request+0x104/0x6e0
10:42:05 DEBUG| [stdout] [ 6044.945417] [c000200db8b22f80] [c000000000686594] generic_make_request+0x124/0x380
10:42:05 DEBUG| [stdout] [ 6044.945420] [c000200db8b22ff0] [c0000000006868ac] submit_bio+0xbc/0x1d0
10:42:05 DEBUG| [stdout] [ 6044.945424] [c000200db8b230a0] [c00000000042dd0c] submit_bh_wbc+0x1dc/0x240
10:42:05 DEBUG| [stdout] [ 6044.945428] [c000200db8b230f0] [c00000000042dfe8] __block_write_full_page+0x278/0x570
10:42:05 DEBUG| [stdout] [ 6044.945431] [c000200db8b23190] [c00000000054aa2c] fat_writepage+0x2c/0x40
10:42:05 DEBUG| [stdout] [ 6044.945434] [c000200db8b231b0] [c00000000043bcd0] __mpage_writepage+0x170/0x7b0
10:42:05 DEBUG| [stdout] [ 6044.945438] [c000200db8b236e0] [c0000000002f2c5c] write_cache_pages+0x25c/0x590
10:42:05 DEBUG| [stdout] [ 6044.945441] [c000200db8b23820] [c00000000043b9a8] mpage_writepages+0x78/0x150
10:42:05 DEBUG| [stdout] [ 6044.945443] [c000200db8b238b0] [c00000000054a9a8] fat_writepages+0x28/0x40
10:42:05 DEBUG| [stdout] [ 6044.945446] [c000200db8b238d0] [c0000000002f5ddc] do_writepages+0x4c/0x130
10:42:05 DEBUG| [stdout] [ 6044.945449] [c000200db8b23940] [c00000000041eed0] __writeback_single_inode+0x70/0x570
10:42:05 DEBUG| [stdout] [ 6044.945451] [c000200db8b239a0] [c00000000041fa6c] writeback_sb_inodes+0x26c/0x5d0
10:42:05 DEBUG| [stdout] [ 6044.945453] [c000200db8b23ab0] [c00000000042012c] wb_writeback+0x13c/0x460
10:42:05 DEBUG| [stdout] [ 6044.945456] [c000200db8b23b80] [c000000000420e00] wb_workfn+0x100/0x5e0
10:42:05 DEBUG| [stdout] [ 6044.945459] [c000200db8b23c90] [c000000000134a98] process_one_work+0x298/0x5a0
10:42:05 DEBUG| [stdout] [ 6044.945462] [c000200db8b23d20] [c000000000134e38] worker_thread+0x98/0x630
10:42:05 DEBUG| [stdout] [ 6044.945465] [c000200db8b23dc0] [c00000000013da68] kthread+0x1a8/0x1b0
10:42:05 DEBUG| [stdout] [ 6044.945470] [c000200db8b23e30] [c00000000000b658] ret_from_kernel_thread+0x5c/0x84
10:42:05 DEBUG| [stdout] [ 6044.945474] INFO: task stress-ng:146997 blocked for more than 120 seconds.
10:42:05 DEBUG| [stdout] [ 6044.945532] Not tainted 4.15.0-36-generic #39-Ubuntu
10:42:05 DEBUG| [stdout] [ 6044.945567] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
10:42:05 DEBUG| [stdout] [ 6044.945619] stress-ng D 0 146997 146983 0x00040002
10:42:05 DEBUG| [stdout] [ 6044.945622] Call Trace:
10:42:05 DEBUG| [stdout] [ 6044.945624] [c000200daa85b910] [0000006f0000006a] 0x6f0000006a (unreliable)
10:42:05 DEBUG| [stdout] [ 6044.945628] [c000200daa85bae0] [c00000000001c1d0] __switch_to+0x2a0/0x4d0
10:42:05 DEBUG| [stdout] [ 6044.945631] [c000200daa85bb40] [c000000000cfcae4] __schedule+0x2a4/0xaf0
10:42:05 DEBUG| [stdout] [ 6044.945634] [c000200daa85bc10] [c000000000cfd370] schedule+0x40/0xc0
10:42:05 DEBUG| [stdout] [ 6044.945636] [c000200daa85bc30] [c00000000041cc04] wb_wait_for_completion+0x94/0xe0
10:42:05 DEBUG| [stdout] [ 6044.945639] [c000200daa85bc90] [c00000000041e2f8] sync_inodes_sb+0xd8/0x310
10:42:05 DEBUG| [stdout] [ 6044.945642] [c000200daa85bd60] [c000000000425fdc] sync_inodes_one_sb+0x2c/0x40
10:42:05 DEBUG| [stdout] [ 6044.945645] [c000200daa85bd80] [c0000000003daa4c] iterate_supers+0xec/0x200
10:42:05 DEBUG| [stdout] [ 6044.945648] [c000200daa85bdf0] [c0000000004265d4] sys_sync+0x54/0xf0
10:42:05 DEBUG| [stdout] [ 6044.945651] [c000200daa85be30] [c00000000000b284] system_call+0x58/0x6c
10:42:05 DEBUG| [stdout] [ 6044.945653] INFO: task stress-ng:146999 blocked for more than 120 seconds.
10:42:05 DEBUG| [stdout] [ 6044.945698] Not tainted 4.15.0-36-generic #39-Ubuntu
10:42:05 DEBUG| [stdout] [ 6044.945733] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
10:42:05 DEBUG| [stdout] [ 6044.945784] stress-ng D 0 146999 146983 0x00040002
10:42:05 DEBUG| [stdout] [ 6044.945787] Call Trace:
10:42:05 DEBUG| [stdout] [ 6044.945789] [c000200daa826d90] [c000200daa826de0] 0xc000200daa826de0 (unreliable)
10:42:05 DEBUG| [stdout] [ 6044.945792] [c000200daa826f60] [c00000000001c1d0] __switch_to+0x2a0/0x4d0
10:42:05 DEBUG| [stdout] [ 6044.945795] [c000200daa826fc0] [c000000000cfcae4] __schedule+0x2a4/0xaf0
10:42:05 DEBUG| [stdout] [ 6044.945798] [c000200daa827090] [c000000000cfd370] schedule+0x40/0xc0
10:42:05 DEBUG| [stdout] [ 6044.945801] [c000200daa8270b0] [c000000000152d9c] io_schedule+0x2c/0x50
10:42:05 DEBUG| [stdout] [ 6044.945804] [c000200daa8270e0] [c0000000006d1804] wbt_wait+0x484/0x4e0
10:42:05 DEBUG| [stdout] [ 6044.945807] [c000200daa827180] [c000000000698924] blk_mq_make_request+0x104/0x6e0
10:42:05 DEBUG| [stdout] [ 6044.945810] [c000200daa827220] [c000000000686594] generic_make_request+0x124/0x380
10:42:05 DEBUG| [stdout] [ 6044.945813] [c000200daa827290] [c0000000006868ac] submit_bio+0xbc/0x1d0
10:42:05 DEBUG| [stdout] [ 6044.945816] [c000200daa827340] [c00000000042dd0c] submit_bh_wbc+0x1dc/0x240
10:42:05 DEBUG| [stdout] [ 6044.945819] [c000200daa827390] [c00000000042dfe8] __block_write_full_page+0x278/0x570
10:42:05 DEBUG| [stdout] [ 6044.945821] [c000200daa827430] [c00000000054aa2c] fat_writepage+0x2c/0x40
10:42:05 DEBUG| [stdout] [ 6044.945824] [c000200daa827450] [c00000000043bcd0] __mpage_writepage+0x170/0x7b0
10:42:05 DEBUG| [stdout] [ 6044.945827] [c000200daa827980] [c0000000002f2c5c] write_cache_pages+0x25c/0x590
10:42:05 DEBUG| [stdout] [ 6044.945829] [c000200daa827ac0] [c00000000043b9a8] mpage_writepages+0x78/0x150
10:42:05 DEBUG| [stdout] [ 6044.945832] [c000200daa827b50] [c00000000054a9a8] fat_writepages+0x28/0x40
10:42:05 DEBUG| [stdout] [ 6044.945835] [c000200daa827b70] [c0000000002f5ddc] do_writepages+0x4c/0x130
10:42:05 DEBUG| [stdout] [ 6044.945839] [c000200daa827be0] [c0000000002e06e8] __filemap_fdatawrite_range+0x108/0x180
10:42:05 DEBUG| [stdout] [ 6044.945842] [c000200daa827c80] [c0000000002e0a18] file_write_and_wait_range+0x88/0x100
10:42:05 DEBUG| [stdout] [ 6044.945846] [c000200daa827cd0] [c000000000416b10] __generic_file_fsync+0x40/0x170
10:42:05 DEBUG| [stdout] [ 6044.945849] [c000200daa827d20] [c000000000416c6c] generic_file_fsync+0x2c/0x70
10:42:05 DEBUG| [stdout] [ 6044.945854] [c000200daa827d50] [c000000000548eb0] fat_file_fsync+0x30/0x80
10:42:05 DEBUG| [stdout] [ 6044.945856] [c000200daa827d80] [c000000000426288] vfs_fsync_range+0x78/0x170
10:42:05 DEBUG| [stdout] [ 6044.945859] [c000200daa827dd0] [c000000000426408] do_fsync+0x58/0xd0
10:42:05 DEBUG| [stdout] [ 6044.945861] [c000200daa827e10] [c0000000004267f8] SyS_fsync+0x28/0x40
10:42:05 DEBUG| [stdout] [ 6044.945865] [c000200daa827e30] [c00000000000b284] system_call+0x58/0x6c
10:42:05 DEBUG| [stdout] [ 6044.945867] INFO: task stress-ng:147003 blocked for more than 120 seconds.
10:42:05 DEBUG| [stdout] [ 6044.945911] Not tainted 4.15.0-36-generic #39-Ubuntu
10:42:05 DEBUG| [stdout] [ 6044.945946] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
10:42:05 DEBUG| [stdout] [ 6044.945998] stress-ng D 0 147003 146983 0x00040002
10:42:05 DEBUG| [stdout] [ 6044.946000] Call Trace:
10:42:05 DEBUG| [stdout] [ 6044.946002] [c000200daa8636e0] [c000200daa863730] 0xc000200daa863730 (unreliable)
10:42:05 DEBUG| [stdout] [ 6044.946006] [c000200daa8638b0] [c00000000001c1d0] __switch_to+0x2a0/0x4d0
10:42:05 DEBUG| [stdout] [ 6044.946009] [c000200daa863910] [c000000000cfcae4] __schedule+0x2a4/0xaf0
10:42:05 DEBUG| [stdout] [ 6044.946012] [c000200daa8639e0] [c000000000cfd370] schedule+0x40/0xc0
10:42:05 DEBUG| [stdout] [ 6044.946015] [c000200daa863a00] [c000000000152d9c] io_schedule+0x2c/0x50
10:42:05 DEBUG| [stdout] [ 6044.946017] [c000200daa863a30] [c0000000006d1804] wbt_wait+0x484/0x4e0
10:42:05 DEBUG| [stdout] [ 6044.946020] [c000200daa863ad0] [c000000000698924] blk_mq_make_request+0x104/0x6e0
10:42:05 DEBUG| [stdout] [ 6044.946023] [c000200daa863b70] [c000000000686594] generic_make_request+0x124/0x380
10:42:05 DEBUG| [stdout] [ 6044.946026] [c000200daa863be0] [c0000000006868ac] submit_bio+0xbc/0x1d0
10:42:05 DEBUG| [stdout] [ 6044.946030] [c000200daa863c90] [c000000000676ad4] submit_bio_wait+0x64/0xa0
10:42:05 DEBUG| [stdout] [ 6044.946033] [c000200daa863ce0] [c00000000068bed4] blkdev_issue_flush+0xb4/0x110
10:42:05 DEBUG| [stdout] [ 6044.946036] [c000200daa863d20] [c000000000416c8c] generic_file_fsync+0x4c/0x70
10:42:05 DEBUG| [stdout] [ 6044.946039] [c000200daa863d50] [c000000000548eb0] fat_file_fsync+0x30/0x80
10:42:05 DEBUG| [stdout] [ 6044.946041] [c000200daa863d80] [c000000000426288] vfs_fsync_range+0x78/0x170
10:42:05 DEBUG| [stdout] [ 6044.946044] [c000200daa863dd0] [c000000000426408] do_fsync+0x58/0xd0
10:42:05 DEBUG| [stdout] [ 6044.946046] [c000200daa863e10] [c0000000004267f8] SyS_fsync+0x28/0x40
10:42:05 DEBUG| [stdout] [ 6044.946049] [c000200daa863e30] [c00000000000b284] system_call+0x58/0x6c
10:42:05 DEBUG| [stdout] [ 6044.946052] INFO: task stress-ng:147006 blocked for more than 120 seconds.
10:42:05 DEBUG| [stdout] [ 6044.946096] Not tainted 4.15.0-36-generic #39-Ubuntu
10:42:05 DEBUG| [stdout] [ 6044.946131] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
10:42:05 DEBUG| [stdout] [ 6044.946184] stress-ng D 0 147006 146983 0x00040002
10:42:05 DEBUG| [stdout] [ 6044.946187] Call Trace:
10:42:05 DEBUG| [stdout] [ 6044.946188] [c000200daa8236e0] [c000200daa823730] 0xc000200daa823730 (unreliable)
10:42:05 DEBUG| [stdout] [ 6044.946192] [c000200daa8238b0] [c00000000001c1d0] __switch_to+0x2a0/0x4d0
10:42:05 DEBUG| [stdout] [ 6044.946195] [c000200daa823910] [c000000000cfcae4] __schedule+0x2a4/0xaf0
10:42:05 DEBUG| [stdout] [ 6044.946198] [c000200daa8239e0] [c000000000cfd370] schedule+0x40/0xc0
10:42:05 DEBUG| [stdout] [ 6044.946201] [c000200daa823a00] [c000000000152d9c] io_schedule+0x2c/0x50
10:42:05 DEBUG| [stdout] [ 6044.946203] [c000200daa823a30] [c0000000006d1804] wbt_wait+0x484/0x4e0
10:42:05 DEBUG| [stdout] [ 6044.946206] [c000200daa823ad0] [c000000000698924] blk_mq_make_request+0x104/0x6e0
10:42:05 DEBUG| [stdout] [ 6044.946209] [c000200daa823b70] [c000000000686594] generic_make_request+0x124/0x380
10:42:05 DEBUG| [stdout] [ 6044.946212] [c000200daa823be0] [c0000000006868ac] submit_bio+0xbc/0x1d0
10:42:05 DEBUG| [stdout] [ 6044.946215] [c000200daa823c90] [c000000000676ad4] submit_bio_wait+0x64/0xa0
10:42:05 DEBUG| [stdout] [ 6044.946217] [c000200daa823ce0] [c00000000068bed4] blkdev_issue_flush+0xb4/0x110
10:42:05 DEBUG| [stdout] [ 6044.946220] [c000200daa823d20] [c000000000416c8c] generic_file_fsync+0x4c/0x70
10:42:05 DEBUG| [stdout] [ 6044.946223] [c000200daa823d50] [c000000000548eb0] fat_file_fsync+0x30/0x80
10:42:05 DEBUG| [stdout] [ 6044.946226] [c000200daa823d80] [c000000000426288] vfs_fsync_range+0x78/0x170
10:42:05 DEBUG| [stdout] [ 6044.946228] [c000200daa823dd0] [c000000000426408] do_fsync+0x58/0xd0
10:42:05 DEBUG| [stdout] [ 6044.946231] [c000200daa823e10] [c0000000004267f8] SyS_fsync+0x28/0x40
10:42:05 DEBUG| [stdout] [ 6044.946234] [c000200daa823e30] [c00000000000b284] system_call+0x58/0x6c
10:42:05 DEBUG| [stdout] [ 6044.946236] INFO: task stress-ng:147010 blocked for more than 120 seconds.
10:42:05 DEBUG| [stdout] [ 6044.946279] Not tainted 4.15.0-36-generic #39-Ubuntu
10:42:05 DEBUG| [stdout] [ 6044.946315] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
10:42:05 DEBUG| [stdout] [ 6044.946367] stress-ng D 0 147010 146983 0x00040002
10:42:05 DEBUG| [stdout] [ 6044.946369] Call Trace:
10:42:05 DEBUG| [stdout] [ 6044.946371] [c000200daa86b5b0] [c000200daa86b600] 0xc000200daa86b600 (unreliable)
10:42:05 DEBUG| [stdout] [ 6044.946375] [c000200daa86b780] [c00000000001c1d0] __switch_to+0x2a0/0x4d0
10:42:05 DEBUG| [stdout] [ 6044.946377] [c000200daa86b7e0] [c000000000cfcae4] __schedule+0x2a4/0xaf0
10:42:05 DEBUG| [stdout] [ 6044.946380] [c000200daa86b8b0] [c000000000cfd370] schedule+0x40/0xc0
10:42:05 DEBUG| [stdout] [ 6044.946383] [c000200daa86b8d0] [c000000000152d9c] io_schedule+0x2c/0x50
10:42:05 DEBUG| [stdout] [ 6044.946386] [c000200daa86b900] [c0000000002dc52c] __lock_page+0x14c/0x1c0
10:42:05 DEBUG| [stdout] [ 6044.946389] [c000200daa86b9a0] [c0000000002de5fc] pagecache_get_page+0x2ac/0x450
10:42:05 DEBUG| [stdout] [ 6044.946392] [c000200daa86ba00] [c0000000002de7d4] grab_cache_page_write_begin+0x34/0x70
10:42:05 DEBUG| [stdout] [ 6044.946395] [c000200daa86ba30] [c00000000042f53c] block_write_begin+0x4c/0x170
10:42:05 DEBUG| [stdout] [ 6044.946397] [c000200daa86ba80] [c00000000042f8ec] cont_write_begin+0x28c/0x3a0
10:42:05 DEBUG| [stdout] [ 6044.946399] [c000200daa86bb40] [c00000000054a8c8] fat_write_begin+0x58/0xc0
10:42:05 DEBUG| [stdout] [ 6044.946402] [c000200daa86bbd0] [c0000000002ddc5c] generic_perform_write+0xec/0x270
10:42:05 DEBUG| [stdout] [ 6044.946405] [c000200daa86bc60] [c0000000002e2290] __generic_file_write_iter+0x250/0x2a0
10:42:05 DEBUG| [stdout] [ 6044.946409] [c000200daa86bcc0] [c0000000002e24ec] generic_file_write_iter+0x20c/0x2e0
10:42:05 DEBUG| [stdout] [ 6044.946413] [c000200daa86bd00] [c0000000003d2554] new_sync_write+0x104/0x160
10:42:05 DEBUG| [stdout] [ 6044.946415] [c000200daa86bd90] [c0000000003d5c98] vfs_write+0xd8/0x220
10:42:05 DEBUG| [stdout] [ 6044.946417] [c000200daa86bde0] [c0000000003d5fb8] SyS_write+0x68/0x110
10:42:05 DEBUG| [stdout] [ 6044.946420] [c000200daa86be30] [c00000000000b284] system_call+0x58/0x6c
10:42:05 DEBUG| [stdout] [ 6044.946422] INFO: task stress-ng:147013 blocked for more than 120 seconds.
10:42:05 DEBUG| [stdout] [ 6044.946466] Not tainted 4.15.0-36-generic #39-Ubuntu
10:42:05 DEBUG| [stdout] [ 6044.946502] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
10:42:05 DEBUG| [stdout] [ 6044.946553] stress-ng D 0 147013 146983 0x00040002
10:42:05 DEBUG| [stdout] [ 6044.946556] Call Trace:
10:42:05 DEBUG| [stdout] [ 6044.946558] [c000200daa817910] [0000009400000028] 0x9400000028 (unreliable)
10:42:05 DEBUG| [stdout] [ 6044.946561] [c000200daa817ae0] [c00000000001c1d0] __switch_to+0x2a0/0x4d0
10:42:05 DEBUG| [stdout] [ 6044.946564] [c000200daa817b40] [c000000000cfcae4] __schedule+0x2a4/0xaf0
10:42:05 DEBUG| [stdout] [ 6044.946567] [c000200daa817c10] [c000000000cfd370] schedule+0x40/0xc0
10:42:05 DEBUG| [stdout] [ 6044.946569] [c000200daa817c30] [c00000000041cc04] wb_wait_for_completion+0x94/0xe0
10:42:05 DEBUG| [stdout] [ 6044.946572] [c000200daa817c90] [c00000000041e2f8] sync_inodes_sb+0xd8/0x310
10:42:05 DEBUG| [stdout] [ 6044.946574] [c000200daa817d60] [c000000000425fdc] sync_inodes_one_sb+0x2c/0x40
10:42:05 DEBUG| [stdout] [ 6044.946577] [c000200daa817d80] [c0000000003daa4c] iterate_supers+0xec/0x200
10:42:05 DEBUG| [stdout] [ 6044.946579] [c000200daa817df0] [c0000000004265d4] sys_sync+0x54/0xf0
10:42:05 DEBUG| [stdout] [ 6044.946582] [c000200daa817e30] [c00000000000b284] system_call+0x58/0x6c
10:42:05 DEBUG| [stdout] [ 6044.946584] INFO: task stress-ng:147016 blocked for more than 120 seconds.
10:42:05 DEBUG| [stdout] [ 6044.946628] Not tainted 4.15.0-36-generic #39-Ubuntu
10:42:05 DEBUG| [stdout] [ 6044.946663] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
10:42:05 DEBUG| [stdout] [ 6044.946715] stress-ng D 0 147016 146983 0x00040002
10:42:05 DEBUG| [stdout] [ 6044.946717] Call Trace:
10:42:05 DEBUG| [stdout] [ 6044.946719] [c000200daa852d90] [c000200daa852de0] 0xc000200daa852de0 (unreliable)
10:42:05 DEBUG| [stdout] [ 6044.946722] [c000200daa852f60] [c00000000001c1d0] __switch_to+0x2a0/0x4d0
10:42:05 DEBUG| [stdout] [ 6044.946725] [c000200daa852fc0] [c000000000cfcae4] __schedule+0x2a4/0xaf0
10:42:05 DEBUG| [stdout] [ 6044.946728] [c000200daa853090] [c000000000cfd370] schedule+0x40/0xc0
10:42:05 DEBUG| [stdout] [ 6044.946731] [c000200daa8530b0] [c000000000152d9c] io_schedule+0x2c/0x50
10:42:05 DEBUG| [stdout] [ 6044.946733] [c000200daa8530e0] [c0000000006d1804] wbt_wait+0x484/0x4e0
10:42:05 DEBUG| [stdout] [ 6044.946736] [c000200daa853180] [c000000000698924] blk_mq_make_request+0x104/0x6e0
10:42:05 DEBUG| [stdout] [ 6044.946739] [c000200daa853220] [c000000000686594] generic_make_request+0x124/0x380
10:42:05 DEBUG| [stdout] [ 6044.946742] [c000200daa853290] [c0000000006868ac] submit_bio+0xbc/0x1d0
10:42:05 DEBUG| [stdout] [ 6044.946745] [c000200daa853340] [c00000000042dd0c] submit_bh_wbc+0x1dc/0x240
10:42:05 DEBUG| [stdout] [ 6044.946748] [c000200daa853390] [c00000000042dfe8] __block_write_full_page+0x278/0x570
10:42:05 DEBUG| [stdout] [ 6044.946751] [c000200daa853430] [c00000000054aa2c] fat_writepage+0x2c/0x40
10:42:05 DEBUG| [stdout] [ 6044.946753] [c000200daa853450] [c00000000043bcd0] __mpage_writepage+0x170/0x7b0
10:42:05 DEBUG| [stdout] [ 6044.946756] [c000200daa853980] [c0000000002f2c5c] write_cache_pages+0x25c/0x590
10:42:05 DEBUG| [stdout] [ 6044.946759] [c000200daa853ac0] [c00000000043b9a8] mpage_writepages+0x78/0x150
10:42:05 DEBUG| [stdout] [ 6044.946761] [c000200daa853b50] [c00000000054a9a8] fat_writepages+0x28/0x40
10:42:05 DEBUG| [stdout] [ 6044.946764] [c000200daa853b70] [c0000000002f5ddc] do_writepages+0x4c/0x130
10:42:05 DEBUG| [stdout] [ 6044.946767] [c000200daa853be0] [c0000000002e06e8] __filemap_fdatawrite_range+0x108/0x180
10:42:05 DEBUG| [stdout] [ 6044.946770] [c000200daa853c80] [c0000000002e0a18] file_write_and_wait_range+0x88/0x100
10:42:05 DEBUG| [stdout] [ 6044.946773] [c000200daa853cd0] [c000000000416b10] __generic_file_fsync+0x40/0x170
10:42:05 DEBUG| [stdout] [ 6044.946776] [c000200daa853d20] [c000000000416c6c] generic_file_fsync+0x2c/0x70
10:42:05 DEBUG| [stdout] [ 6044.946779] [c000200daa853d50] [c000000000548eb0] fat_file_fsync+0x30/0x80
10:42:05 DEBUG| [stdout] [ 6044.946782] [c000200daa853d80] [c000000000426288] vfs_fsync_range+0x78/0x170
10:42:05 DEBUG| [stdout] [ 6044.946784] [c000200daa853dd0] [c000000000426408] do_fsync+0x58/0xd0
10:42:05 DEBUG| [stdout] [ 6044.946787] [c000200daa853e10] [c0000000004267f8] SyS_fsync+0x28/0x40
10:42:05 DEBUG| [stdout] [ 6044.946790] [c000200daa853e30] [c00000000000b284] system_call+0x58/0x6c
10:42:05 DEBUG| [stdout] [ 6044.946792] INFO: task stress-ng:147023 blocked for more than 120 seconds.
10:42:05 DEBUG| [stdout] [ 6044.946836] Not tainted 4.15.0-36-generic #39-Ubuntu
10:42:05 DEBUG| [stdout] [ 6044.946885] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
10:42:05 DEBUG| [stdout] [ 6044.946937] stress-ng D 0 147023 146983 0x00040002
10:42:05 DEBUG| [stdout] [ 6044.946939] Call Trace:
10:42:05 DEBUG| [stdout] [ 6044.946941] [c000200daa8436e0] [c000200daa843730] 0xc000200daa843730 (unreliable)
10:42:05 DEBUG| [stdout] [ 6044.946945] [c000200daa8438b0] [c00000000001c1d0] __switch_to+0x2a0/0x4d0
10:42:05 DEBUG| [stdout] [ 6044.946948] [c000200daa843910] [c000000000cfcae4] __schedule+0x2a4/0xaf0
10:42:05 DEBUG| [stdout] [ 6044.946951] [c000200daa8439e0] [c000000000cfd370] schedule+0x40/0xc0
10:42:05 DEBUG| [stdout] [ 6044.946954] [c000200daa843a00] [c000000000152d9c] io_schedule+0x2c/0x50
10:42:05 DEBUG| [stdout] [ 6044.946956] [c000200daa843a30] [c0000000006d1804] wbt_wait+0x484/0x4e0
10:42:05 DEBUG| [stdout] [ 6044.946959] [c000200daa843ad0] [c000000000698924] blk_mq_make_request+0x104/0x6e0
10:42:05 DEBUG| [stdout] [ 6044.946962] [c000200daa843b70] [c000000000686594] generic_make_request+0x124/0x380
10:42:05 DEBUG| [stdout] [ 6044.946964] [c000200daa843be0] [c0000000006868ac] submit_bio+0xbc/0x1d0
10:42:05 DEBUG| [stdout] [ 6044.946968] [c000200daa843c90] [c000000000676ad4] submit_bio_wait+0x64/0xa0
10:42:05 DEBUG| [stdout] [ 6044.946970] [c000200daa843ce0] [c00000000068bed4] blkdev_issue_flush+0xb4/0x110
10:42:05 DEBUG| [stdout] [ 6044.946973] [c000200daa843d20] [c000000000416c8c] generic_file_fsync+0x4c/0x70
10:42:05 DEBUG| [stdout] [ 6044.946976] [c000200daa843d50] [c000000000548eb0] fat_file_fsync+0x30/0x80
10:42:05 DEBUG| [stdout] [ 6044.946978] [c000200daa843d80] [c000000000426288] vfs_fsync_range+0x78/0x170
10:42:05 DEBUG| [stdout] [ 6044.946981] [c000200daa843dd0] [c000000000426408] do_fsync+0x58/0xd0
10:42:05 DEBUG| [stdout] [ 6044.946983] [c000200daa843e10] [c0000000004267f8] SyS_fsync+0x28/0x40
10:42:05 DEBUG| [stdout] [ 6044.946986] [c000200daa843e30] [c00000000000b284] system_call+0x58/0x6c
10:42:05 DEBUG| [stdout] [ 6044.946989] INFO: task stress-ng:147028 blocked for more than 120 seconds.
10:42:05 DEBUG| [stdout] [ 6044.947033] Not tainted 4.15.0-36-generic #39-Ubuntu
10:42:05 DEBUG| [stdout] [ 6044.947068] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
10:42:05 DEBUG| [stdout] [ 6044.947120] stress-ng D 0 147028 146983 0x00040002
10:42:05 DEBUG| [stdout] [ 6044.947122] Call Trace:
10:42:05 DEBUG| [stdout] [ 6044.947124] [c000200daa87f6e0] [c000200daa87f730] 0xc000200daa87f730 (unreliable)
10:42:05 DEBUG| [stdout] [ 6044.947127] [c000200daa87f8b0] [c00000000001c1d0] __switch_to+0x2a0/0x4d0
10:42:05 DEBUG| [stdout] [ 6044.947130] [c000200daa87f910] [c000000000cfcae4] __schedule+0x2a4/0xaf0
10:42:05 DEBUG| [stdout] [ 6044.947133] [c000200daa87f9e0] [c000000000cfd370] schedule+0x40/0xc0
10:42:05 DEBUG| [stdout] [ 6044.947136] [c000200daa87fa00] [c000000000152d9c] io_schedule+0x2c/0x50
10:42:05 DEBUG| [stdout] [ 6044.947138] [c000200daa87fa30] [c0000000006d1804] wbt_wait+0x484/0x4e0
10:42:05 DEBUG| [stdout] [ 6044.947141] [c000200daa87fad0] [c000000000698924] blk_mq_make_request+0x104/0x6e0
10:42:05 DEBUG| [stdout] [ 6044.947144] [c000200daa87fb70] [c000000000686594] generic_make_request+0x124/0x380
10:42:05 DEBUG| [stdout] [ 6044.947147] [c000200daa87fbe0] [c0000000006868ac] submit_bio+0xbc/0x1d0
10:42:05 DEBUG| [stdout] [ 6044.947150] [c000200daa87fc90] [c000000000676ad4] submit_bio_wait+0x64/0xa0
10:42:05 DEBUG| [stdout] [ 6044.947152] [c000200daa87fce0] [c00000000068bed4] blkdev_issue_flush+0xb4/0x110
10:42:05 DEBUG| [stdout] [ 6044.947155] [c000200daa87fd20] [c000000000416c8c] generic_file_fsync+0x4c/0x70
10:42:05 DEBUG| [stdout] [ 6044.947158] [c000200daa87fd50] [c000000000548eb0] fat_file_fsync+0x30/0x80
10:42:05 DEBUG| [stdout] [ 6044.947161] [c000200daa87fd80] [c000000000426288] vfs_fsync_range+0x78/0x170
10:42:05 DEBUG| [stdout] [ 6044.947163] [c000200daa87fdd0] [c000000000426408] do_fsync+0x58/0xd0
10:42:05 DEBUG| [stdout] [ 6044.947166] [c000200daa87fe10] [c0000000004267f8] SyS_fsync+0x28/0x40
10:42:05 DEBUG| [stdout] [ 6044.947169] [c000200daa87fe30] [c00000000000b284] system_call+0x58/0x6c
================================================================================

It was also triggered on ADT with kernel 4.15.0-38-generic (but not with 4.15.0-36)
https://objectstorage.prodstack4-5.canonical.com/v1/AUTH_77e2ada1e7a84929a74ba3b87153c0ac/autopkgtest-bionic/bionic/ppc64el/l/linux/20181017_151749_d42a8@/log.gz

This has not yet been observed in other architectures.

How to reproduce:
Clone autotest and autotest-client-tests repos and run:
$ AUTOTEST_PATH=/home/ubuntu/autotest sudo -E autotest/client/autotest-local --verbose autotest/client/tests/ubuntu_vfat_stress/control

[Ubuntu Kernel Bot (ubuntu-kernel-bot)]

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 1798574

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.

[Po-Hsu Lin (cypressyew)]

For the record, as we don't have this test enlisted for bare-metal testing (lp:1798575), the only way to catch this for other kernels will be the ADT testing for ppc.

[Kleber Sacilotto de Souza (kleber-souza)]

It didn't fail with older kernels on ADT, only with 4.15.0-38. So there might be a environment variable to it as well (e.g. number of cpus). And since we ran this test on baremetal only with ppc64el, it might affect other arches as well.

[Colin Ian King (colin-king)]

I can reproduce this on 4.15.0-38 but not on a more recent kernel, e.g. 4.15.0-64, so I think this has been fixed. I'll close this for now as fixed released, but feel free to re-open it if we see the same issue again.