Sam, can this be retested, I think we were getting into dirty page write amplification because of using vfat on a tmpfs backing store file. I've reworked the test now to use bog standard vfat on a loopbacked file.
Fix committed: http://kernel.ubuntu.com/git/ubuntu/autotest-client- tests.git/commit/?id=e39a7d03a6dbda3039514096737d72150877017b ** No longer affects: stress-ng ** Changed in: linux (Ubuntu) Status: Confirmed => Fix Committed ** Changed in: linux (Ubuntu) Status: Fix Committed => Triaged ** Changed in: ubuntu-kernel-tests Assignee: (unassigned) => Colin Ian King (colin-king) ** Changed in: ubuntu-kernel-tests Importance: Undecided => High ** Changed in: ubuntu-kernel-tests Status: New => Fix Committed -- You received this bug notification because you are a member of Kernel Packages, which is subscribed to linux in Ubuntu. https://bugs.launchpad.net/bugs/1805778 Title: ubuntu_vfat_stress failed again with P8/P9 Bionic Status in ubuntu-kernel-tests: Fix Committed Status in linux package in Ubuntu: Triaged Bug description: This issue just like bug 1801907, but this time it's passed with P8 "modoc", failed with P8 "entei" and P9 "baltar" I haven't run them directly, this is the result when testing with the whole test suite. 06:21:04 INFO | START ubuntu_vfat_stress.vfat-stress ubuntu_vfat_stress.vfat-stress timestamp=1543472464 timeout=18000 localtime=Nov 29 06:21:04 06:21:04 DEBUG| Persistent state client._record_indent now set to 2 06:21:04 DEBUG| Persistent state client.unexpected_reboot now set to ('ubuntu_vfat_stress.vfat-stress', 'ubuntu_vfat_stress.vfat-stress') 06:21:04 DEBUG| Waiting for pid 56149 for 18000 seconds 06:21:04 DEBUG| Running 'LOG=/tmp/vfat-falure.log STRESS_NG=/home/ubuntu/autotest/client/tmp/ubuntu_vfat_stress/src/stress-ng/stress-ng DURATION=10s bash -c /home/ubuntu/autotest/client/tests/ubuntu_vfat_stress/ubuntu_vfat_stress.sh /home/ubuntu/autotest/client/tmp/ubuntu_vfat_stress/src 2>&1' 06:21:04 DEBUG| [stdout] 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 06:21:04 DEBUG| [stdout] Mounting tmpfs /mnt/vfat-test-56154 06:21:05 DEBUG| [stdout] Created loop image /mnt/vfat-test-56154/vfat-loop-data 06:21:05 DEBUG| [stdout] mkfs.fat 4.1 (2017-01-24) 06:21:06 DEBUG| [stdout] 06:21:06 DEBUG| [stdout] -------------------------------------------------------------------------------- 06:21:06 DEBUG| [stdout] VFAT options: allow_utime=20 06:21:06 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 06:21:06 DEBUG| [stdout] VFAT_IMAGE path: /mnt/vfat-test-56154 06:21:06 DEBUG| [stdout] Mount point: /mnt/vfat-test-56154 06:21:06 DEBUG| [stdout] Date: Thu Nov 29 06:21:06 UTC 2018 06:21:06 DEBUG| [stdout] Host: baltar 06:21:06 DEBUG| [stdout] Kernel: 4.15.0-42-generic #45-Ubuntu SMP Thu Nov 15 19:29:37 UTC 2018 06:21:06 DEBUG| [stdout] Machine: baltar ppc64le ppc64le 06:21:06 DEBUG| [stdout] CPUs online: 40 06:21:06 DEBUG| [stdout] CPUs total: 160 06:21:06 DEBUG| [stdout] Page size: 65536 06:21:06 DEBUG| [stdout] Pages avail: 1935143 06:21:06 DEBUG| [stdout] Pages total: 2089666 06:21:06 DEBUG| [stdout] -------------------------------------------------------------------------------- 06:21:06 DEBUG| [stdout] 06:21:06 DEBUG| [stdout] 06:21:06 DEBUG| [stdout] Started, PID 56225 06:23:13 DEBUG| [stdout] Timed out waiting for stress-ng to finish 06:23:13 DEBUG| [stdout] Forcefully killing, PID 56225 (after 121 seconds) 06:23:23 DEBUG| [stdout] Found kernel warning and/or call trace: 06:23:23 DEBUG| [stdout] 06:23:23 DEBUG| [stdout] [ 4940.791800] 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 06:23:23 DEBUG| [stdout] [ 4941.855398] Created loop image /mnt/vfat-test-56154/vfat-loop-data 06:23:23 DEBUG| [stdout] [ 4942.232934] ubuntu_vfat_str (56154): drop_caches: 1 06:23:23 DEBUG| [stdout] [ 4942.593708] ubuntu_vfat_str (56154): drop_caches: 2 06:23:23 DEBUG| [stdout] [ 4942.597717] ubuntu_vfat_str (56154): drop_caches: 3 06:23:23 DEBUG| [stdout] [ 4943.125332] VFAT options: allow_utime=20 06:23:23 DEBUG| [stdout] [ 4943.125392] 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 06:23:23 DEBUG| [stdout] [ 4943.125420] Mount point: /mnt/vfat-test-56154 06:23:23 DEBUG| [stdout] [ 4943.125979] Started, PID 56225 06:23:23 DEBUG| [stdout] [ 5069.761998] Timed out waiting for stress-ng to finish 06:23:23 DEBUG| [stdout] [ 5069.762077] Forcefully killing, PID 56225 (after 121 seconds) 06:23:23 DEBUG| [stdout] [ 5078.885169] INFO: task kworker/u322:2:56189 blocked for more than 120 seconds. 06:23:23 DEBUG| [stdout] [ 5078.885238] Not tainted 4.15.0-42-generic #45-Ubuntu 06:23:23 DEBUG| [stdout] [ 5078.885274] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. 06:23:23 DEBUG| [stdout] [ 5078.885327] kworker/u322:2 D 0 56189 2 0x00000800 06:23:23 DEBUG| [stdout] [ 5078.885338] Workqueue: writeback wb_workfn (flush-7:0) 06:23:23 DEBUG| [stdout] [ 5078.885340] Call Trace: 06:23:23 DEBUG| [stdout] [ 5078.885347] [c000200e38f7aaf0] [c000000000044c70] doorbell_exception+0xb0/0xe0 (unreliable) 06:23:23 DEBUG| [stdout] [ 5078.885352] [c000200e38f7acc0] [c00000000001c1d0] __switch_to+0x2a0/0x4d0 06:23:23 DEBUG| [stdout] [ 5078.885356] [c000200e38f7ad20] [c000000000cfdb84] __schedule+0x2a4/0xaf0 06:23:23 DEBUG| [stdout] [ 5078.885359] [c000200e38f7adf0] [c000000000cfe410] schedule+0x40/0xc0 06:23:23 DEBUG| [stdout] [ 5078.885362] [c000200e38f7ae10] [c000000000152e7c] io_schedule+0x2c/0x50 06:23:23 DEBUG| [stdout] [ 5078.885366] [c000200e38f7ae40] [c0000000006d20c4] wbt_wait+0x484/0x4e0 06:23:23 DEBUG| [stdout] [ 5078.885369] [c000200e38f7aee0] [c000000000699134] blk_mq_make_request+0x104/0x6e0 06:23:23 DEBUG| [stdout] [ 5078.885373] [c000200e38f7af80] [c000000000686cf4] generic_make_request+0x124/0x380 06:23:23 DEBUG| [stdout] [ 5078.885376] [c000200e38f7aff0] [c00000000068700c] submit_bio+0xbc/0x1d0 06:23:23 DEBUG| [stdout] [ 5078.885380] [c000200e38f7b0a0] [c00000000042de2c] submit_bh_wbc+0x1dc/0x240 06:23:23 DEBUG| [stdout] [ 5078.885383] [c000200e38f7b0f0] [c00000000042e108] __block_write_full_page+0x278/0x570 06:23:23 DEBUG| [stdout] [ 5078.885386] [c000200e38f7b190] [c00000000054af2c] fat_writepage+0x2c/0x40 06:23:23 DEBUG| [stdout] [ 5078.885389] [c000200e38f7b1b0] [c00000000043bdf0] __mpage_writepage+0x170/0x7b0 06:23:23 DEBUG| [stdout] [ 5078.885392] [c000200e38f7b6e0] [c0000000002f2d9c] write_cache_pages+0x25c/0x590 06:23:23 DEBUG| [stdout] [ 5078.885395] [c000200e38f7b820] [c00000000043bac8] mpage_writepages+0x78/0x150 06:23:23 DEBUG| [stdout] [ 5078.885397] [c000200e38f7b8b0] [c00000000054aea8] fat_writepages+0x28/0x40 06:23:23 DEBUG| [stdout] [ 5078.885400] [c000200e38f7b8d0] [c0000000002f5f1c] do_writepages+0x4c/0x130 06:23:23 DEBUG| [stdout] [ 5078.885403] [c000200e38f7b940] [c00000000041eff0] __writeback_single_inode+0x70/0x570 06:23:23 DEBUG| [stdout] [ 5078.885405] [c000200e38f7b9a0] [c00000000041fb8c] writeback_sb_inodes+0x26c/0x5d0 06:23:23 DEBUG| [stdout] [ 5078.885407] [c000200e38f7bab0] [c00000000042024c] wb_writeback+0x13c/0x460 06:23:23 DEBUG| [stdout] [ 5078.885410] [c000200e38f7bb80] [c000000000420f20] wb_workfn+0x100/0x5e0 06:23:23 DEBUG| [stdout] [ 5078.885414] [c000200e38f7bc90] [c000000000134bd8] process_one_work+0x298/0x5a0 06:23:23 DEBUG| [stdout] [ 5078.885416] [c000200e38f7bd20] [c000000000134f78] worker_thread+0x98/0x630 06:23:23 DEBUG| [stdout] [ 5078.885419] [c000200e38f7bdc0] [c00000000013db48] kthread+0x1a8/0x1b0 06:23:23 DEBUG| [stdout] [ 5078.885423] [c000200e38f7be30] [c00000000000b658] ret_from_kernel_thread+0x5c/0x84 06:23:23 DEBUG| [stdout] [ 5078.885426] INFO: task stress-ng:56241 blocked for more than 120 seconds. 06:23:23 DEBUG| [stdout] [ 5078.885470] Not tainted 4.15.0-42-generic #45-Ubuntu 06:23:23 DEBUG| [stdout] [ 5078.885505] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. 06:23:23 DEBUG| [stdout] [ 5078.885558] stress-ng D 0 56241 1 0x00040002 06:23:23 DEBUG| [stdout] [ 5078.885560] Call Trace: 06:23:23 DEBUG| [stdout] [ 5078.885564] [c000000d4743f5b0] [c000000d4743f600] 0xc000000d4743f600 (unreliable) 06:23:23 DEBUG| [stdout] [ 5078.885568] [c000000d4743f780] [c00000000001c1d0] __switch_to+0x2a0/0x4d0 06:23:23 DEBUG| [stdout] [ 5078.885571] [c000000d4743f7e0] [c000000000cfdb84] __schedule+0x2a4/0xaf0 06:23:23 DEBUG| [stdout] [ 5078.885574] [c000000d4743f8b0] [c000000000cfe410] schedule+0x40/0xc0 06:23:23 DEBUG| [stdout] [ 5078.885577] [c000000d4743f8d0] [c000000000152e7c] io_schedule+0x2c/0x50 06:23:23 DEBUG| [stdout] [ 5078.885581] [c000000d4743f900] [c0000000002dc6ec] __lock_page+0x14c/0x1c0 06:23:23 DEBUG| [stdout] [ 5078.885584] [c000000d4743f9a0] [c0000000002de7bc] pagecache_get_page+0x2ac/0x450 06:23:23 DEBUG| [stdout] [ 5078.885587] [c000000d4743fa00] [c0000000002de994] grab_cache_page_write_begin+0x34/0x70 06:23:23 DEBUG| [stdout] [ 5078.885589] [c000000d4743fa30] [c00000000042f65c] block_write_begin+0x4c/0x170 06:23:23 DEBUG| [stdout] [ 5078.885592] [c000000d4743fa80] [c00000000042fa0c] cont_write_begin+0x28c/0x3a0 06:23:23 DEBUG| [stdout] [ 5078.885594] [c000000d4743fb40] [c00000000054adc8] fat_write_begin+0x58/0xc0 06:23:23 DEBUG| [stdout] [ 5078.885597] [c000000d4743fbd0] [c0000000002dde1c] generic_perform_write+0xec/0x270 06:23:23 DEBUG| [stdout] [ 5078.885601] [c000000d4743fc60] [c0000000002e2450] __generic_file_write_iter+0x250/0x2a0 06:23:23 DEBUG| [stdout] [ 5078.885604] [c000000d4743fcc0] [c0000000002e26ac] generic_file_write_iter+0x20c/0x2e0 06:23:23 DEBUG| [stdout] [ 5078.885608] [c000000d4743fd00] [c0000000003d2674] new_sync_write+0x104/0x160 06:23:23 DEBUG| [stdout] [ 5078.885610] [c000000d4743fd90] [c0000000003d5db8] vfs_write+0xd8/0x220 06:23:23 DEBUG| [stdout] [ 5078.885613] [c000000d4743fde0] [c0000000003d60d8] SyS_write+0x68/0x110 06:23:23 DEBUG| [stdout] [ 5078.885616] [c000000d4743fe30] [c00000000000b284] system_call+0x58/0x6c 06:23:23 DEBUG| [stdout] [ 5078.885618] INFO: task stress-ng:56243 blocked for more than 120 seconds. 06:23:23 DEBUG| [stdout] [ 5078.885677] Not tainted 4.15.0-42-generic #45-Ubuntu 06:23:23 DEBUG| [stdout] [ 5078.885713] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. 06:23:23 DEBUG| [stdout] [ 5078.885765] stress-ng D 0 56243 1 0x00040002 ProblemType: Bug DistroRelease: Ubuntu 18.04 Package: linux-image-4.15.0-42-generic 4.15.0-42.45 ProcVersionSignature: Ubuntu 4.15.0-42.45-generic 4.15.18 Uname: Linux 4.15.0-42-generic ppc64le AlsaDevices: total 0 crw-rw---- 1 root audio 116, 1 Nov 29 04:58 seq crw-rw---- 1 root audio 116, 33 Nov 29 04:58 timer AplayDevices: Error: [Errno 2] No such file or directory: 'aplay': 'aplay' ApportVersion: 2.20.9-0ubuntu7.5 Architecture: ppc64el ArecordDevices: Error: [Errno 2] No such file or directory: 'arecord': 'arecord' AudioDevicesInUse: Error: command ['fuser', '-v', '/dev/snd/seq', '/dev/snd/timer'] failed with exit code 1: Date: Thu Nov 29 05:05:38 2018 IwConfig: Error: [Errno 2] No such file or directory: 'iwconfig': 'iwconfig' Lsusb: Bus 002 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub Bus 001 Device 003: ID 0451:80ff Texas Instruments, Inc. Bus 001 Device 004: ID 0557:2419 ATEN International Co., Ltd Bus 001 Device 002: ID 0557:7000 ATEN International Co., Ltd Hub Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub PciMultimedia: ProcFB: 0 astdrmfb ProcKernelCmdLine: root=UUID=acd1a0d7-f6fc-4130-928c-c8b11ad6e4be ro console=hvc0 ProcLoadAvg: 2.45 1.59 0.69 3/1426 14448 ProcLocks: 1: FLOCK ADVISORY WRITE 4143 00:17:593 0 EOF 2: FLOCK ADVISORY WRITE 3627 00:17:525 0 EOF 3: POSIX ADVISORY WRITE 1799 00:17:368 0 EOF 4: POSIX ADVISORY WRITE 4090 00:17:592 0 EOF 5: POSIX ADVISORY WRITE 4089 00:17:582 0 EOF ProcSwaps: Filename Type Size Used Priority /swap.img file 8388544 0 -2 ProcVersion: Linux version 4.15.0-42-generic (buildd@bos02-ppc64el-001) (gcc version 7.3.0 (Ubuntu 7.3.0-16ubuntu3)) #45-Ubuntu SMP Thu Nov 15 19:29:37 UTC 2018 RelatedPackageVersions: linux-restricted-modules-4.15.0-42-generic N/A linux-backports-modules-4.15.0-42-generic N/A linux-firmware 1.173.2 RfKill: Error: [Errno 2] No such file or directory: 'rfkill': 'rfkill' SourcePackage: linux UpgradeStatus: No upgrade log present (probably fresh install) VarLogDump_list: total 0 cpu_cores: Number of cores present = 40 cpu_coreson: Number of cores online = 40 cpu_dscr: DSCR is 16 cpu_freq: min: 2.262 GHz (cpu 40) max: 2.927 GHz (cpu 4) avg: 2.896 GHz cpu_runmode: Could not retrieve current diagnostics mode, No kernel interface to firmware cpu_smt: SMT is off To manage notifications about this bug go to: https://bugs.launchpad.net/ubuntu-kernel-tests/+bug/1805778/+subscriptions -- Mailing list: https://launchpad.net/~kernel-packages Post to : kernel-packages@lists.launchpad.net Unsubscribe : https://launchpad.net/~kernel-packages More help : https://help.launchpad.net/ListHelp
