[e1000] a23171eb76: WARNING: CPU: 1 PID: 0 at net/sched/sch_generic.c:316 dev_watchdog+0x181/0x1dc
by kernel test robot
FYI, we noticed the following commit:
https://git.kernel.org/pub/scm/linux/kernel/git/jkirsher/next-queue.git dev-queue
commit a23171eb76f4316455e288732b1c66f1651d99d4 ("e1000: track BQL bytes regardless of skb or not")
in testcase: boot
on test machine: qemu-system-x86_64 -enable-kvm -cpu host -smp 2 -m 1G
caused below changes:
+--------------------------------------------------+------------+------------+
| | db846ea612 | a23171eb76 |
+--------------------------------------------------+------------+------------+
| boot_successes | 4 | 2 |
| boot_failures | 0 | 4 |
| WARNING:at_net/sched/sch_generic.c:#dev_watchdog | 0 | 4 |
+--------------------------------------------------+------------+------------+
[ 15.801867] <address>Apache/2.4.12 (Debian) Server at inn Port 80</address>
[ 15.803063] </body></html>
[ 22.201376] ------------[ cut here ]------------
[ 22.202127] WARNING: CPU: 1 PID: 0 at net/sched/sch_generic.c:316 dev_watchdog+0x181/0x1dc
[ 22.203603] NETDEV WATCHDOG: eth0 (e1000): transmit queue 0 timed out
[ 22.204563] CPU: 1 PID: 0 Comm: swapper/1 Not tainted 4.8.0-rc6-01530-ga23171e #15
[ 22.205687] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
[ 22.206978] 0000000000000000 ffff88003be03d28 ffffffff81405db4 ffff88003be03d78
[ 22.208141] ffffffff8235a1fb ffff88003be03d68 ffffffff81079c75 0000013c3be03de0
[ 22.209302] ffff8800317da000 ffff8800324d4e00 ffff8800317da420 0000000000000001
[ 22.210466] Call Trace:
[ 22.210843] <IRQ> [<ffffffff81405db4>] dump_stack+0x61/0x7e
[ 22.211657] [<ffffffff81079c75>] __warn+0xb3/0xce
[ 22.212314] [<ffffffff81079cd6>] warn_slowpath_fmt+0x46/0x4e
[ 22.213103] [<ffffffff81bcf825>] dev_watchdog+0x181/0x1dc
[ 22.213857] [<ffffffff81bcf6a4>] ? qdisc_rcu_free+0x3f/0x3f
[ 22.214636] [<ffffffff810c6438>] call_timer_fn+0x63/0xcd
[ 22.215378] [<ffffffff810c63d5>] ? process_timeout+0xb/0xb
[ 22.216171] [<ffffffff810c65f0>] run_timer_softirq+0x14e/0x177
[ 22.216982] [<ffffffff81bcf6a4>] ? qdisc_rcu_free+0x3f/0x3f
[ 22.217760] [<ffffffff8103a6f4>] ? kvm_clock_get_cycles+0x9/0xb
[ 22.218582] [<ffffffff810cb7c0>] ? ktime_get+0x9e/0xfb
[ 22.219300] [<ffffffff81034478>] ? lapic_next_deadline+0x21/0x27
[ 22.220142] [<ffffffff8107d7c4>] __do_softirq+0xc9/0x1c8
[ 22.220884] [<ffffffff8107da62>] irq_exit+0x3d/0x4b
[ 22.221564] [<ffffffff81034d2d>] smp_trace_apic_timer_interrupt+0x7b/0x88
[ 22.222473] [<ffffffff81034d43>] smp_apic_timer_interrupt+0x9/0xb
[ 22.223267] [<ffffffff81cb22ef>] apic_timer_interrupt+0x7f/0x90
[ 22.224041] <EOI> [<ffffffff8103a99e>] ? native_safe_halt+0x6/0x8
[ 22.224867] [<ffffffff81025e9e>] default_idle+0x9/0xd
[ 22.225532] [<ffffffff81026365>] arch_cpu_idle+0xa/0xc
[ 22.226215] [<ffffffff810aa510>] default_idle_call+0x2e/0x30
[ 22.226956] [<ffffffff810aa637>] cpu_startup_entry+0x125/0x1dc
[ 22.227717] [<ffffffff81033541>] start_secondary+0xf5/0xf8
[ 22.228457] ---[ end trace 06d1fc98b62498d9 ]---
[ 22.229151] e1000 0000:00:03.0 eth0: Reset adapter
Thanks,
Kernel Test Robot
5 years, 7 months
[e1000] 9c35926970: WARNING: CPU: 1 PID: 889 at net/sched/sch_generic.c:316 dev_watchdog+0x186/0x1e1
by kernel test robot
FYI, we noticed the following commit:
https://git.kernel.org/pub/scm/linux/kernel/git/jkirsher/next-queue.git dev-queue
commit 9c3592697073deabf9213eced286603301b53b66 ("e1000: track BQL bytes regardless of skb or not")
in testcase: boot
on test machine: qemu-system-x86_64 -enable-kvm -cpu host -smp 2 -m 1G
caused below changes:
+--------------------------------------------------+------------+------------+
| | 64b9488ec2 | 9c35926970 |
+--------------------------------------------------+------------+------------+
| boot_successes | 3 | 4 |
| boot_failures | 2 | 4 |
| invoked_oom-killer:gfp_mask=0x | 2 | |
| Mem-Info | 2 | |
| WARNING:at_net/sched/sch_generic.c:#dev_watchdog | 0 | 4 |
| calltrace:rcu_torture_writer | 0 | 1 |
| calltrace:rcu_torture_cbflood | 0 | 1 |
+--------------------------------------------------+------------+------------+
[ 24.237992] kill 3615 dmesg --follow --decode
[ 24.274410] wait for background monitors: 3616 3618 oom-killer nfs-hang
[ 38.126455] ------------[ cut here ]------------
[ 38.128379] WARNING: CPU: 1 PID: 889 at net/sched/sch_generic.c:316 dev_watchdog+0x186/0x1e1
[ 38.130934] NETDEV WATCHDOG: eth0 (e1000): transmit queue 0 timed out
[ 38.132450] Modules linked in: snd_pcsp
[ 38.133762] CPU: 1 PID: 889 Comm: rcu_torture_wri Not tainted 4.8.0-rc6-01587-g9c35926 #1
[ 38.136029] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
[ 38.138421] 0000000000000000 ffff88003be03d18 ffffffff8156f76e ffff88003be03d68
[ 38.140922] 0000000000000000 ffff88003be03d58 ffffffff810a33cd 0000013c3be03dd0
[ 38.143353] ffff88002e06a160 ffff88002f0fd738 ffff88002e06a600 0000000000000001
[ 38.145779] Call Trace:
[ 38.146690] <IRQ> [<ffffffff8156f76e>] dump_stack+0x86/0xc0
[ 38.148241] [<ffffffff810a33cd>] __warn+0xc2/0xdd
[ 38.149480] [<ffffffff810a3433>] warn_slowpath_fmt+0x4b/0x53
[ 38.150853] [<ffffffff81ba4165>] dev_watchdog+0x186/0x1e1
[ 38.152180] [<ffffffff81ba3fdf>] ? qdisc_rcu_free+0x44/0x44
[ 38.153531] [<ffffffff8111be33>] call_timer_fn+0x169/0x382
[ 38.154907] [<ffffffff81ba3fdf>] ? qdisc_rcu_free+0x44/0x44
[ 38.156269] [<ffffffff8111c20a>] expire_timers+0x1be/0x22f
[ 38.157643] [<ffffffff8111c57e>] run_timer_softirq+0x6e/0x94
[ 38.159053] [<ffffffff81cf183b>] __do_softirq+0x20b/0x4d0
[ 38.160394] [<ffffffff810a933f>] irq_exit+0x47/0x9b
[ 38.161647] [<ffffffff81cf1334>] smp_apic_timer_interrupt+0x42/0x4d
[ 38.163076] [<ffffffff81cf060c>] apic_timer_interrupt+0x8c/0xa0
[ 38.164479] <EOI> [<ffffffff810c9a98>] ? finish_task_switch+0x126/0x1e6
[ 38.166086] [<ffffffff810eb561>] ? lock_is_held+0x4f/0x5b
[ 38.167431] [<ffffffff810c9bce>] ___might_sleep+0x76/0x202
[ 38.168889] [<ffffffff81197361>] stutter_wait+0x89/0xc5
[ 38.170220] [<ffffffff8110d7d6>] rcu_torture_writer+0x540/0x5bb
[ 38.171684] [<ffffffff8110d296>] ? rcu_torture_pipe_update+0x7a/0x7a
[ 38.173219] [<ffffffff810c2f26>] kthread+0xfb/0x103
[ 38.174503] [<ffffffff81ceedaf>] ret_from_fork+0x1f/0x40
[ 38.175940] [<ffffffff810c2e2b>] ? kthread_create_on_node+0x1ca/0x1ca
[ 38.177533] ---[ end trace c37dbd949bf88060 ]---
[ 38.180288] e1000 0000:00:03.0 eth0: Reset adapter
Thanks,
Kernel Test Robot
5 years, 7 months
Tips to append base tree info by git-format-patch
by Ye Xiaolong
Hi,
Here's a tip for people who've been bothered by messages sent by kbuild bot like
below:
[auto build test ERROR on net/master]
[also build test ERROR on v4.8-rc3 next-20160825]
[if your patch is applied to the wrong git tree, please drop us a note
to help improve the system]
It means that 0day bot applied the patch to net/master which is obtained based
on heuristic (0day bot does a guess job based on the MAINTAINERS file in linux
src to get the tree/branch ). It can't guarantee 100% accuracy.
To avoid false reports which is caused by 0day apply your patches to a wrong
tree, we suggest to use the new option --base which is introduced since git
2.9.0 to append the base tree info, here is a example of it:
Imagine that on top of the public commit P, you applied well-known
(on-flight) patches X, Y and Z from somebody else or yourself, and then built
your three-patch series A, B, C, the history would be like:
................................................
---P---X---Y---Z---A---B---C
................................................
With `git format-patch --base=P -3 C`,
where P could be the exact commit sha, or variants e.g. HEAD~6, you can also use
--base=auto for convenience, the base tree information block is shown at the
end of the first message the command outputs (either the first patch, or the
cover letter), like this:
------------
base-commit: P
prerequisite-patch-id: X
prerequisite-patch-id: Y
prerequisite-patch-id: Z
------------
For more information, please refer to: https://git-scm.com/docs/git-format-patch
We'll be appreciated if you could use this option if you'd like your patch
series to be verified by 0day on a solid base as yours.
Feedbacks are welcome! Please drop us a mail if you have any suggestions.
Thanks,
Xiaolong
5 years, 7 months
[blk-mq] 65d5291eee: BUG: unable to handle kernel NULL pointer dereference at 0000000000000010
by kernel test robot
Greetings,
0day kernel testing robot got the below dmesg and the first bad commit is
https://git.kernel.org/pub/scm/linux/kernel/git/axboe/linux-block.git for-4.9/block-smp
commit 65d5291eee667b9b310123991234f2fb18e51548
Author: Sebastian Andrzej Siewior <bigeasy(a)linutronix.de>
AuthorDate: Thu Sep 22 08:05:19 2016 -0600
Commit: Jens Axboe <axboe(a)fb.com>
CommitDate: Thu Sep 22 08:05:19 2016 -0600
blk-mq: Convert to new hotplug state machine
Install the callbacks via the state machine so we can phase out the cpu
hotplug notifiers mess.
Signed-off-by: Sebastian Andrzej Siewior <bigeasy(a)linutronix.de>
Signed-off-by: Thomas Gleixner <tglx(a)linutronix.de>
Cc: Peter Zijlstra <peterz(a)infradead.org>
Cc: linux-block(a)vger.kernel.org
Cc: rt(a)linutronix.de
Cc: Christoph Hellwing <hch(a)lst.de>
Link: http://lkml.kernel.org/r/20160919212601.180033814@linutronix.de
Signed-off-by: Thomas Gleixner <tglx(a)linutronix.de>
Signed-off-by: Jens Axboe <axboe(a)fb.com>
+-------------------------------------------------+------------+------------+------------+
| | 9467f85960 | 65d5291eee | ac2a66c299 |
+-------------------------------------------------+------------+------------+------------+
| boot_successes | 65 | 19 | 25 |
| boot_failures | 0 | 7 | 14 |
| BUG:unable_to_handle_kernel | 0 | 7 | 9 |
| Oops | 0 | 7 | 9 |
| RIP:__sbitmap_queue_get | 0 | 7 | 9 |
| calltrace:SyS_read | 0 | 7 | |
| Kernel_panic-not_syncing:Fatal_exception | 0 | 7 | |
| RIP:show_stack_log_lvl | 0 | 0 | 9 |
| BUG:kernel_reboot-without-warning_in_test_stage | 0 | 0 | 5 |
+-------------------------------------------------+------------+------------+------------+
udevd[271]: failed to execute '/sbin/modprobe' '/sbin/modprobe -bv acpi:PNP0F13:': No such file or directory
[ 5.089894] init: Failed to create pty - disabling logging for job
[ 5.091053] init: Temporary process spawn error: No such file or directory
[ 5.108938] BUG: unable to handle kernel NULL pointer dereference at 0000000000000010
[ 5.110243] IP: [<ffffffff8156b2b3>] __sbitmap_queue_get+0x13/0xd0
[ 5.111264] PGD 1f6cd067 PUD 1f789067 PMD 0
[ 5.111989] Oops: 0000 [#1] PREEMPT SMP
[ 5.112599] Modules linked in:
[ 5.113095] CPU: 1 PID: 273 Comm: blkid Not tainted 4.8.0-rc4-00047-g65d5291 #1
[ 5.114232] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
[ 5.115578] task: ffff88001ef7a000 task.stack: ffff88001f76c000
[ 5.116493] RIP: 0010:[<ffffffff8156b2b3>] [<ffffffff8156b2b3>] __sbitmap_queue_get+0x13/0xd0
[ 5.117875] RSP: 0018:ffff88001f76f800 EFLAGS: 00010297
[ 5.118692] RAX: ffff88001ef7a000 RBX: 0000000000000010 RCX: 0000000000000001
[ 5.119777] RDX: 0000000000000000 RSI: 0000000000000010 RDI: 0000000000000010
[ 5.120904] RBP: ffff88001f76f820 R08: 00000000ffffffff R09: ffa8340d00000000
[ 5.121986] R10: 0000000000000001 R11: 0000000000000001 R12: 0000000000000010
[ 5.123071] R13: ffff88001f76f950 R14: ffff88001ed2fe00 R15: 0000000000000010
[ 5.124174] FS: 00007f34d2eba740(0000) GS:ffff88001d600000(0000) knlGS:0000000000000000
[ 5.125414] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 5.126273] CR2: 0000000000000010 CR3: 000000001f783000 CR4: 00000000000006e0
[ 5.127396] Stack:
[ 5.127722] ffff880017697000 0000000000000010 ffff88001f76f950 ffff88001ed2fe00
[ 5.128945] ffff88001f76f850 ffffffff8150c888 ffff88001d7e2500 ffff880017697000
[ 5.130193] ffff88001f76f950 ffff88001ed2fe00 ffff88001f76f8b8 ffffffff8150cb27
[ 5.131408] Call Trace:
[ 5.131832] [<ffffffff8150c888>] __bt_get+0x28/0xb0
[ 5.132611] [<ffffffff8150cb27>] bt_get+0x57/0x240
[ 5.133496] [<ffffffff81044a29>] ? sched_clock+0x9/0x10
[ 5.134303] [<ffffffff81124000>] ? abort_exclusive_wait+0xb0/0xb0
[ 5.135262] [<ffffffff8150cffe>] blk_mq_get_tag+0x9e/0xd0
[ 5.136100] [<ffffffff81506777>] __blk_mq_alloc_request+0x27/0x240
[ 5.137093] [<ffffffff81509ced>] blk_mq_map_request+0x3cd/0x6c0
[ 5.138026] [<ffffffff81509920>] ? blk_mq_alloc_request+0x1d0/0x1d0
[ 5.139019] [<ffffffff8150b8f8>] blk_sq_make_request+0x6e8/0x790
[ 5.139970] [<ffffffff814eb7e1>] ? bio_add_page+0x101/0x120
[ 5.140862] [<ffffffff814f83a9>] generic_make_request+0xf9/0x200
[ 5.141807] [<ffffffff812cee29>] ? do_mpage_readpage+0x939/0x950
[ 5.142742] [<ffffffff814f85f3>] submit_bio+0x143/0x160
[ 5.143612] [<ffffffff812c233e>] ? guard_bio_eod+0x1ae/0x1c0
[ 5.144498] [<ffffffff81209695>] ? lru_cache_add+0x15/0x20
[ 5.145363] [<ffffffff812ce4e7>] mpage_bio_submit+0xb7/0xc0
[ 5.146237] [<ffffffff812cefd2>] mpage_readpages+0x192/0x1e0
[ 5.147131] [<ffffffff812c5980>] ? I_BDEV+0x20/0x20
[ 5.147905] [<ffffffff812c5980>] ? I_BDEV+0x20/0x20
[ 5.148671] [<ffffffff812c679c>] blkdev_readpages+0x2c/0x40
[ 5.149548] [<ffffffff812c6770>] ? blkdev_write_begin+0x50/0x50
[ 5.150494] [<ffffffff812062d3>] __do_page_cache_readahead+0x2b3/0x3d0
[ 5.151514] [<ffffffff812060ff>] ? __do_page_cache_readahead+0xdf/0x3d0
[ 5.152540] [<ffffffff8120688a>] ondemand_readahead+0x49a/0x4e0
[ 5.153498] [<ffffffff8120661e>] ? ondemand_readahead+0x22e/0x4e0
[ 5.154458] [<ffffffff81206bb5>] page_cache_sync_readahead+0x75/0x90
[ 5.155432] [<ffffffff811f5259>] generic_file_read_iter+0x229/0xba0
[ 5.156425] [<ffffffff81071439>] ? kvm_sched_clock_read+0x9/0x20
[ 5.157425] [<ffffffff811bcf2a>] ? trace_preempt_on+0x11a/0x160
[ 5.158377] [<ffffffff812c806e>] blkdev_read_iter+0x5e/0x80
[ 5.159257] [<ffffffff812760af>] __vfs_read+0x15f/0x1a0
[ 5.160097] [<ffffffff81276e92>] vfs_read+0xc2/0x170
[ 5.160881] [<ffffffff812785e3>] SyS_read+0x53/0xc0
[ 5.161663] [<ffffffff81a83440>] entry_SYSCALL_64_fastpath+0x23/0xc1
[ 5.162656] Code: 44 89 e0 41 5c 41 5d 5d c3 0f 1f 44 00 00 66 2e 0f 1f 84 00 00 00 00 00 55 48 89 e5 41 56 41 55 41 54 53 48 89 fb e8 bd 57 c3 ff <44> 8b 33 4c 8b 6b 18 65 45 8b 65 00 45 39 f4 72 2d e8 a7 57 c3
[ 5.167027] RIP [<ffffffff8156b2b3>] __sbitmap_queue_get+0x13/0xd0
[ 5.168024] RSP <ffff88001f76f800>
[ 5.168603] CR2: 0000000000000010
[ 5.169134] ---[ end trace 27e57ef0b9dd28e0 ]---
[ 5.169860] Kernel panic - not syncing: Fatal exception
git bisect start ac2a66c299f24ec3552ba837d07cee67994449bc 3be7988674ab33565700a37b210f502563d932e6 --
git bisect bad 03f2d63751931d26ec21b4edf440dc3404be9b56 # 06:41 0- 2 Merge 'peterz-queue/locking/core' into devel-spot-201609230307
git bisect good 7c84168685ed7d4bd2611d81a5379da3cb80d4b4 # 07:07 20+ 0 Merge 'linux-review/Vaishali-Thakkar/fs-9p-Drop-memory-allocation-cast/20160923-010928' into devel-spot-201609230307
git bisect good cc936bf9ab9717a93af552ec52cd98dcac2c058b # 07:32 22+ 0 Merge 'percpu/for-next' into devel-spot-201609230307
git bisect bad ba6c76dfb30e1bfa39b53b1a0ada247b85553ff2 # 07:58 0- 4 Merge 'block/for-next' into devel-spot-201609230307
git bisect good 7c8e5a885e1bd9b8f9b2f625eb74706555a56a7e # 08:17 22+ 0 Merge 'tj-libata/for-4.9' into devel-spot-201609230307
git bisect good 4c72fd3335e0d1ef1cc73a84cc933cd9ca806314 # 08:43 22+ 1 Merge 'tj-libata/for-next' into devel-spot-201609230307
git bisect good 0806f1f60f0db03675ca82fd4dba9f27d015fe05 # 08:59 21+ 0 Merge 'linux-review/Arnd-Bergmann/PCI-rockchip-fix-uninitialized-variable-use/20160922-234617' into devel-spot-201609230307
git bisect good 818aa8ec6ef3a51e8666c4b084cacb3812740b76 # 09:16 21+ 0 Merge branch 'for-4.9/block' into for-next
git bisect bad 65d5291eee667b9b310123991234f2fb18e51548 # 09:38 0- 4 blk-mq: Convert to new hotplug state machine
git bisect good cf392d10b69e6e6c57ceea48b347a2ab1a4b75b2 # 09:52 22+ 0 cpu/hotplug: Add multi instance support
git bisect good 5dfcfb02e18dec9a2f56765011817706e1ab1daf # 10:18 22+ 0 Merge branch 'smp/for-block' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip into for-4.9/block-smp
git bisect good 9467f85960a31d56f95371516e55e210e1e3d51c # 10:39 22+ 0 blk-mq/cpu-notif: Convert to new hotplug state machine
# first bad commit: [65d5291eee667b9b310123991234f2fb18e51548] blk-mq: Convert to new hotplug state machine
git bisect good 9467f85960a31d56f95371516e55e210e1e3d51c # 10:45 60+ 0 blk-mq/cpu-notif: Convert to new hotplug state machine
# extra tests on HEAD of linux-devel/devel-spot-201609230307
git bisect bad ac2a66c299f24ec3552ba837d07cee67994449bc # 10:45 0- 14 0day head guard for 'devel-spot-201609230307'
# extra tests on tree/branch block/for-4.9/block-smp
git bisect bad 65d5291eee667b9b310123991234f2fb18e51548 # 10:51 0- 7 blk-mq: Convert to new hotplug state machine
# extra tests with first bad commit reverted
git bisect good ee89e16094fa6f4c3a693724fced3029c9955462 # 11:35 61+ 1 Revert "blk-mq: Convert to new hotplug state machine"
# extra tests on tree/branch linus/master
git bisect good b1f2beb87bb034bb209773807994279f90cace78 # 12:04 61+ 0 Merge tag 'media/v4.8-7' of git://git.kernel.org/pub/scm/linux/kernel/git/mchehab/linux-media
# extra tests on tree/branch linux-next/master
git bisect good 6b9db9bb533a770d0df771d9c91482de13328e9f # 12:28 60+ 1 Add linux-next specific files for 20160922
---
0-DAY kernel test infrastructure Open Source Technology Center
https://lists.01.org/pipermail/lkp Intel Corporation
5 years, 7 months
[e1000] 095ca5cabf: WARNING: CPU: 1 PID: 64 at net/sched/sch_generic.c:316 dev_watchdog+0x1fa/0x29a
by kernel test robot
FYI, we noticed the following commit:
https://git.kernel.org/pub/scm/linux/kernel/git/jkirsher/next-queue.git dev-queue
commit 095ca5cabf9c0aed3f0d2ca2ff6d76da2b33c54e ("e1000: track BQL bytes regardless of skb or not")
in testcase: boot
on test machine: qemu-system-x86_64 -enable-kvm -cpu host -smp 2 -m 4G
caused below changes:
+--------------------------------------------------+------------+------------+
| | 1e27cdc62f | 095ca5cabf |
+--------------------------------------------------+------------+------------+
| boot_successes | 8 | 2 |
| boot_failures | 0 | 4 |
| WARNING:at_net/sched/sch_generic.c:#dev_watchdog | 0 | 4 |
| calltrace:ring_buffer_producer_thread | 0 | 1 |
| calltrace:ring_buffer_consumer_thread | 0 | 1 |
+--------------------------------------------------+------------+------------+
[ 46.951717] <address>Apache/2.4.12 (Debian) Server at inn Port 80</address>
[ 46.953118] </body></html>
[ 53.729030] ------------[ cut here ]------------
[ 53.730245] WARNING: CPU: 1 PID: 64 at net/sched/sch_generic.c:316 dev_watchdog+0x1fa/0x29a
[ 53.731599] NETDEV WATCHDOG: eth0 (e1000): transmit queue 0 timed out
[ 53.732461] CPU: 1 PID: 64 Comm: rb_consumer Not tainted 4.8.0-rc6-01066-g095ca5c #1
[ 53.733449] 0000000000000000 ffff88013f503ce0 ffffffffac14921b 0000000000000000
[ 53.733449] ffffffffacb569db ffff88013f503d20 ffffffffabab5ef9 000000093f503d98
[ 53.733449] ffff880130732000 ffff880130732460 0000000000000000 0000000000000001
[ 53.733449] Call Trace:
[ 53.733449] <IRQ> [<ffffffffac14921b>] dump_stack+0xc9/0x130
[ 53.733449] [<ffffffffacb569db>] ? dev_watchdog+0x1fa/0x29a
[ 53.733449] [<ffffffffabab5ef9>] __warn+0x10d/0x128
[ 53.733449] [<ffffffffabab5f5f>] warn_slowpath_fmt+0x4b/0x53
[ 53.733449] [<ffffffffacb569db>] dev_watchdog+0x1fa/0x29a
[ 53.733449] [<ffffffffacb567e1>] ? qdisc_rcu_free+0x59/0x59
[ 53.733449] [<ffffffffabb77d66>] call_timer_fn+0x2d0/0x5e9
[ 53.733449] [<ffffffffacb567e1>] ? qdisc_rcu_free+0x59/0x59
[ 53.733449] [<ffffffffabb783bd>] expire_timers+0x33e/0x358
[ 53.733449] [<ffffffffabb7845b>] run_timer_softirq+0x84/0x139
[ 53.733449] [<ffffffffacef5761>] __do_softirq+0x381/0x7cb
[ 53.733449] [<ffffffffababf222>] irq_exit+0x79/0x1ea
[ 53.733449] [<ffffffffacef4ecb>] smp_apic_timer_interrupt+0x42/0x4d
[ 53.733449] [<ffffffffacef43d6>] apic_timer_interrupt+0x96/0xa0
[ 53.733449] <EOI> [<ffffffffabbd1b78>] ? ring_buffer_consume+0x227/0x270
[ 53.733449] [<ffffffffabbd3d13>] ring_buffer_consumer_thread+0x1a9/0x643
[ 53.733449] [<ffffffffabbd3b6a>] ? ring_buffer_producer_thread+0x6b1/0x6b1
[ 53.733449] [<ffffffffabae54b5>] kthread+0x124/0x12c
[ 53.733449] [<ffffffffacef2d8f>] ret_from_fork+0x1f/0x40
[ 53.733449] [<ffffffffabae5391>] ? __kthread_parkme+0x9a/0x9a
[ 53.761774] ---[ end trace 5091b95f0bf83ccf ]---
[ 61.270884] e1000 0000:00:03.0 eth0: Reset adapter
Thanks,
Kernel Test Robot
5 years, 7 months
[lkp] [e1000] 531c8b7edc: WARNING: CPU: 1 PID: 0 at net/sched/sch_generic.c:316 dev_watchdog+0x182/0x1dd
by kernel test robot
FYI, we noticed the following commit:
https://git.kernel.org/pub/scm/linux/kernel/git/jkirsher/next-queue.git dev-queue
commit 531c8b7edc41cd032b308c6c690bf8c41f838c7c ("e1000: track BQL bytes regardless of skb or not")
in testcase: boot
on test machine: qemu-system-x86_64 -enable-kvm -cpu IvyBridge -smp 2 -m 1G
caused below changes:
+------------------------------------------------------------------+------------+------------+
| | 118f98b838 | 531c8b7edc |
+------------------------------------------------------------------+------------+------------+
| boot_successes | 3 | 2 |
| boot_failures | 3 | 5 |
| BUG:kernel_reboot-without-warning_in_test_stage | 1 | 1 |
| invoked_oom-killer:gfp_mask=0x | 2 | |
| Mem-Info | 2 | |
| Kernel_panic-not_syncing:Out_of_memory_and_no_killable_processes | 2 | |
| WARNING:at_net/sched/sch_generic.c:#dev_watchdog | 0 | 4 |
+------------------------------------------------------------------+------------+------------+
[ 12.161712] kill 2226 dmesg --follow --decode
[ 12.181105] wait for background monitors: 2227 2229 oom-killer nfs-hang
[ 25.437514] ------------[ cut here ]------------
[ 25.438452] WARNING: CPU: 1 PID: 0 at net/sched/sch_generic.c:316 dev_watchdog+0x182/0x1dd
[ 25.440191] NETDEV WATCHDOG: eth0 (e1000): transmit queue 0 timed out
[ 25.441393] Modules linked in: acpi_cpufreq
[ 25.442413] CPU: 1 PID: 0 Comm: swapper/1 Not tainted 4.8.0-rc6-01433-g531c8b7 #1
[ 25.444092] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
[ 25.445923] 0000000000000000 ffff88003d503d48 ffffffff814fbd53 ffff88003d503d98
[ 25.447875] 0000000000000000 ffff88003d503d88 ffffffff811045b2 0000013c3d503e00
[ 25.449820] ffff88002481a000 ffff880026f95600 0000000000000001 0000000000000001
[ 25.452148] Call Trace:
[ 25.452887] <IRQ> [<ffffffff814fbd53>] dump_stack+0x86/0xc0
[ 25.454057] [<ffffffff811045b2>] __warn+0xc2/0xdd
[ 25.455038] [<ffffffff81104618>] warn_slowpath_fmt+0x4b/0x53
[ 25.456126] [<ffffffff819948f6>] dev_watchdog+0x182/0x1dd
[ 25.457189] [<ffffffff81994774>] ? qdisc_rcu_free+0x3e/0x3e
[ 25.458273] [<ffffffff8115c088>] call_timer_fn+0x6b/0x122
[ 25.459334] [<ffffffff8115c230>] expire_timers+0xf1/0x125
[ 25.460390] [<ffffffff81994774>] ? qdisc_rcu_free+0x3e/0x3e
[ 25.461473] [<ffffffff8115c2d2>] run_timer_softirq+0x6e/0x11b
[ 25.462572] [<ffffffff8107aa6f>] ? lapic_next_deadline+0x26/0x2c
[ 25.463700] [<ffffffff81167d11>] ? clockevents_program_event+0xd7/0xef
[ 25.464896] [<ffffffff81aba2ed>] __do_softirq+0x13d/0x2c8
[ 25.465956] [<ffffffff811092dc>] irq_exit+0x47/0x9b
[ 25.466958] [<ffffffff81aba0ba>] smp_apic_timer_interrupt+0x42/0x4d
[ 25.468115] [<ffffffff81ab93cc>] apic_timer_interrupt+0x8c/0xa0
[ 25.469229] <EOI> [<ffffffff8108631c>] ? native_safe_halt+0x6/0x8
[ 25.470450] [<ffffffff81065c72>] default_idle+0x5b/0xdd
[ 25.471496] [<ffffffff810662da>] arch_cpu_idle+0xf/0x11
[ 25.472533] [<ffffffff8113b7a2>] default_idle_call+0x3d/0x44
[ 25.473626] [<ffffffff8113b986>] cpu_startup_entry+0x1dd/0x2ea
[ 25.474730] [<ffffffff81079814>] start_secondary+0x121/0x123
[ 25.475834] ---[ end trace c8154ee51af38008 ]---
[ 25.477191] e1000 0000:00:03.0 eth0: Reset adapter
Thanks,
Xiaolong
5 years, 7 months
[lkp] [f2fs] b873b798af: fsmark.files_per_sec 73.0% improvement
by kernel test robot
FYI, we noticed a 73.0% improvement of fsmark.files_per_sec due to commit:
commit b873b798af6386f3c7ca1636d4989e9b8f9d1794 ("Revert "f2fs: use percpu_rw_semaphore"")
https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git master
in testcase: fsmark
on test machine: 72 threads Intel(R) Xeon(R) CPU E5-2699 v3 @ 2.30GHz with 128G memory
with following parameters:
iterations: 8
disk: 1SSD
nr_threads: 4
fs: f2fs
filesize: 9B
test_size: 40G
sync_method: fsyncBeforeClose
nr_directories: 16d
nr_files_per_directory: 256fpd
cpufreq_governor: performance
The fsmark is a file system benchmark to test synchronous write workloads, for example, mail servers workload.
Disclaimer:
Results have been estimated based on internal Intel analysis and are provided
for informational purposes only. Any difference in system hardware or software
design or configuration may affect actual performance.
Details are as below:
-------------------------------------------------------------------------------------------------->
To reproduce:
git clone git://git.kernel.org/pub/scm/linux/kernel/git/wfg/lkp-tests.git
cd lkp-tests
bin/lkp install job.yaml # job file is attached in this email
bin/lkp run job.yaml
=========================================================================================
compiler/cpufreq_governor/disk/filesize/fs/iterations/kconfig/nr_directories/nr_files_per_directory/nr_threads/rootfs/sync_method/tbox_group/test_size/testcase:
gcc-6/performance/1SSD/9B/f2fs/8/x86_64-rhel-7.2/16d/256fpd/4/debian-x86_64-2016-08-31.cgz/fsyncBeforeClose/lkp-hsw-ep4/40G/fsmark
commit:
3408fef744 ("Merge branch 'x86-urgent-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip")
b873b798af ("Revert "f2fs: use percpu_rw_semaphore"")
3408fef7448ce7d3 b873b798af6386f3c7ca1636d4
---------------- --------------------------
fail:runs %reproduction fail:runs
| | |
%stddev %change %stddev
\ | \
22427 ± 2% +73.0% 38798 ± 1% fsmark.files_per_sec
469.31 ± 2% -41.7% 273.52 ± 1% fsmark.time.elapsed_time
469.31 ± 2% -41.7% 273.52 ± 1% fsmark.time.elapsed_time.max
2e+08 ± 0% +16.5% 2.33e+08 ± 0% fsmark.time.file_system_outputs
324.25 ± 0% +4.3% 338.25 ± 0% fsmark.time.percent_of_cpu_this_job_got
1472 ± 1% -40.2% 879.79 ± 1% fsmark.time.system_time
52.26 ± 0% -11.3% 46.36 ± 3% fsmark.time.user_time
37520477 ± 2% -64.8% 13224338 ± 0% fsmark.time.voluntary_context_switches
345437 ± 2% -39.4% 209409 ± 1% interrupts.CAL:Function_call_interrupts
4201472 ± 10% +19.1% 5002240 ± 0% meminfo.DirectMap2M
93747 ± 1% -78.2% 20431 ± 3% meminfo.Dirty
538708 ± 13% +17.3% 631889 ± 3% numa-meminfo.node0.SUnreclaim
48936 ± 66% -85.8% 6931 ± 47% numa-meminfo.node1.Dirty
301268 ± 2% -42.0% 174711 ± 5% softirqs.RCU
726268 ± 0% -31.2% 499340 ± 1% softirqs.SCHED
1247621 ± 0% -25.8% 925631 ± 0% softirqs.TIMER
8.64 ± 1% +2.3% 8.83 ± 1% turbostat.%Busy
244.00 ± 1% +3.4% 252.25 ± 1% turbostat.Avg_MHz
0.80 ± 3% +29.1% 1.03 ± 5% turbostat.CPU%c3
0.01 ± 0% -100.0% 0.00 ± -1% turbostat.Pkg%pc3
194.75 ± 2% +71.4% 333.75 ± 1% vmstat.io.bi
122798 ± 2% +120.2% 270434 ± 1% vmstat.io.bo
162637 ± 0% -39.0% 99205 ± 1% vmstat.system.cs
94048 ± 0% +20.1% 112911 ± 0% vmstat.system.in
7078528 ± 24% +45.5% 10295956 ± 1% numa-vmstat.node0.nr_dirtied
134688 ± 13% +17.3% 157981 ± 3% numa-vmstat.node0.nr_slab_unreclaimable
3932913 ± 27% +64.7% 6477432 ± 2% numa-vmstat.node0.nr_written
12243 ± 66% -86.0% 1708 ± 45% numa-vmstat.node1.nr_dirty
12372 ± 66% -85.7% 1772 ± 43% numa-vmstat.node1.nr_zone_write_pending
356019 ± 45% +54.0% 548372 ± 21% numa-vmstat.node1.numa_miss
24986528 ± 0% +16.4% 29089616 ± 0% proc-vmstat.nr_dirtied
23466 ± 1% -78.2% 5104 ± 3% proc-vmstat.nr_dirty
14460939 ± 0% +28.7% 18611323 ± 0% proc-vmstat.nr_written
23740 ± 1% -77.8% 5265 ± 3% proc-vmstat.nr_zone_write_pending
2852 ± 4% -21.8% 2230 ± 6% proc-vmstat.numa_hint_faults
2325 ± 9% -24.6% 1752 ± 5% proc-vmstat.numa_hint_faults_local
943958 ± 3% -37.8% 587185 ± 1% proc-vmstat.pgfault
1651946 ± 1% -18.4% 1347438 ± 0% proc-vmstat.pgfree
57844058 ± 0% +28.7% 74445459 ± 0% proc-vmstat.pgpgout
4.069e+08 ± 5% -73.0% 1.098e+08 ± 2% cpuidle.C1-HSW.time
37792253 ± 3% -65.8% 12910843 ± 0% cpuidle.C1-HSW.usage
2.018e+08 ± 9% -90.7% 18847626 ± 4% cpuidle.C1E-HSW.time
1985790 ± 9% -94.3% 112882 ± 1% cpuidle.C1E-HSW.usage
4.711e+08 ± 3% -50.7% 2.324e+08 ± 8% cpuidle.C3-HSW.time
2312993 ± 5% -74.6% 587232 ± 9% cpuidle.C3-HSW.usage
2.995e+10 ± 2% -40.9% 1.771e+10 ± 1% cpuidle.C6-HSW.time
31182059 ± 2% -40.6% 18519022 ± 1% cpuidle.C6-HSW.usage
5.744e+08 ± 6% -50.5% 2.844e+08 ± 9% cpuidle.POLL.time
386829 ± 2% -30.6% 268320 ± 0% cpuidle.POLL.usage
1.189e+12 ± 4% -38.3% 7.335e+11 ± 13% perf-stat.branch-instructions
8.976e+09 ± 3% -38.8% 5.491e+09 ± 13% perf-stat.branch-misses
2.67 ± 1% +20.1% 3.20 ± 6% perf-stat.cache-miss-rate%
3.896e+09 ± 5% -16.4% 3.257e+09 ± 9% perf-stat.cache-misses
1.461e+11 ± 5% -29.7% 1.028e+11 ± 16% perf-stat.cache-references
76682921 ± 2% -64.3% 27344845 ± 0% perf-stat.context-switches
1.008e+13 ± 2% -37.7% 6.275e+12 ± 13% perf-stat.cpu-cycles
340726 ± 4% -50.3% 169411 ± 2% perf-stat.cpu-migrations
2.17 ± 2% +4.2% 2.26 ± 0% perf-stat.dTLB-load-miss-rate%
1.902e+10 ± 2% -28.3% 1.363e+10 ± 5% perf-stat.dTLB-load-misses
8.576e+11 ± 2% -31.3% 5.888e+11 ± 5% perf-stat.dTLB-loads
0.19 ± 4% -51.3% 0.09 ± 2% perf-stat.dTLB-store-miss-rate%
9.342e+08 ± 4% -66.5% 3.132e+08 ± 9% perf-stat.dTLB-store-misses
4.95e+11 ± 5% -31.1% 3.409e+11 ± 10% perf-stat.dTLB-stores
1.662e+09 ± 1% -34.0% 1.097e+09 ± 3% perf-stat.iTLB-loads
5.754e+12 ± 4% -36.1% 3.679e+12 ± 12% perf-stat.instructions
0.57 ± 1% +2.8% 0.59 ± 0% perf-stat.ipc
911944 ± 3% -38.1% 564696 ± 2% perf-stat.minor-faults
1.254e+09 ± 1% -24.3% 9.495e+08 ± 14% perf-stat.node-load-misses
1.039e+09 ± 4% -15.5% 8.778e+08 ± 10% perf-stat.node-loads
3.43e+08 ± 7% -15.3% 2.905e+08 ± 3% perf-stat.node-stores
911944 ± 3% -38.1% 564694 ± 2% perf-stat.page-faults
5256 ± 0% -100.0% 0.00 ± -1% slabinfo.Acpi-Parse.active_objs
5256 ± 0% -100.0% 0.00 ± -1% slabinfo.Acpi-Parse.num_objs
11523 ± 2% -8.6% 10532 ± 4% slabinfo.anon_vma.active_objs
11523 ± 2% -8.6% 10532 ± 4% slabinfo.anon_vma.num_objs
703.50 ± 6% -100.0% 0.00 ± -1% slabinfo.blkdev_ioc.active_objs
703.50 ± 6% -100.0% 0.00 ± -1% slabinfo.blkdev_ioc.num_objs
24860 ± 0% -74.8% 6261 ± 8% slabinfo.cred_jar.active_objs
591.25 ± 0% -74.9% 148.25 ± 8% slabinfo.cred_jar.active_slabs
24860 ± 0% -74.8% 6261 ± 8% slabinfo.cred_jar.num_objs
591.25 ± 0% -74.9% 148.25 ± 8% slabinfo.cred_jar.num_slabs
3378 ± 1% +25.2% 4228 ± 0% slabinfo.ftrace_event_field.active_objs
3378 ± 1% +25.2% 4228 ± 0% slabinfo.ftrace_event_field.num_objs
59330 ± 0% +14.8% 68136 ± 0% slabinfo.kernfs_node_cache.active_objs
872.50 ± 0% +14.8% 1002 ± 0% slabinfo.kernfs_node_cache.active_slabs
59330 ± 0% +14.8% 68136 ± 0% slabinfo.kernfs_node_cache.num_objs
872.50 ± 0% +14.8% 1002 ± 0% slabinfo.kernfs_node_cache.num_slabs
6676 ± 1% +16.2% 7754 ± 3% slabinfo.kmalloc-1024.active_objs
7034 ± 1% +13.8% 8005 ± 3% slabinfo.kmalloc-1024.num_objs
7888 ± 2% -16.9% 6554 ± 1% slabinfo.kmalloc-128.num_objs
140664 ± 1% -100.0% 0.00 ± -1% slabinfo.nat_entry.active_objs
1105 ± 1% -100.0% 0.00 ± -1% slabinfo.nat_entry.active_slabs
141508 ± 1% -100.0% 0.00 ± -1% slabinfo.nat_entry.num_objs
1105 ± 1% -100.0% 0.00 ± -1% slabinfo.nat_entry.num_slabs
6617 ± 1% -100.0% 0.00 ± -1% slabinfo.nat_entry_set.active_objs
6617 ± 1% -100.0% 0.00 ± -1% slabinfo.nat_entry_set.num_objs
2058 ± 1% +21.8% 2507 ± 3% slabinfo.trace_event_file.active_objs
2058 ± 1% +21.8% 2507 ± 3% slabinfo.trace_event_file.num_objs
10569 ± 6% -43.8% 5944 ± 0% sched_debug.cfs_rq:/.exec_clock.avg
41631 ± 12% -34.6% 27235 ± 1% sched_debug.cfs_rq:/.exec_clock.max
31.35 ± 3% -38.3% 19.36 ± 7% sched_debug.cfs_rq:/.exec_clock.min
11878 ± 11% -38.1% 7355 ± 3% sched_debug.cfs_rq:/.exec_clock.stddev
176.51 ± 7% +64.9% 291.01 ± 5% sched_debug.cfs_rq:/.load_avg.avg
423.29 ± 14% +64.1% 694.45 ± 27% sched_debug.cfs_rq:/.load_avg.max
154.03 ± 9% +58.1% 243.55 ± 3% sched_debug.cfs_rq:/.load_avg.min
56938 ± 3% -39.7% 34341 ± 8% sched_debug.cfs_rq:/.min_vruntime.avg
203752 ± 14% -36.3% 129884 ± 4% sched_debug.cfs_rq:/.min_vruntime.max
53503 ± 11% -39.0% 32655 ± 3% sched_debug.cfs_rq:/.min_vruntime.stddev
1.18 ± 9% -23.2% 0.91 ± 3% sched_debug.cfs_rq:/.nr_spread_over.avg
5.35 ± 57% -46.7% 2.85 ± 22% sched_debug.cfs_rq:/.nr_spread_over.max
0.88 ± 0% -9.3% 0.80 ± 0% sched_debug.cfs_rq:/.nr_spread_over.min
0.74 ± 45% -46.3% 0.40 ± 29% sched_debug.cfs_rq:/.nr_spread_over.stddev
-133253 ±-27% -30.0% -93231 ± -9% sched_debug.cfs_rq:/.spread0.avg
-185913 ±-19% -33.2% -124114 ± -7% sched_debug.cfs_rq:/.spread0.min
53510 ± 11% -39.0% 32659 ± 3% sched_debug.cfs_rq:/.spread0.stddev
121.15 ± 5% +37.4% 166.47 ± 3% sched_debug.cfs_rq:/.util_avg.avg
60.38 ± 7% +64.8% 99.50 ± 5% sched_debug.cfs_rq:/.util_avg.min
268435 ± 5% -37.7% 167150 ± 6% sched_debug.cpu.clock.avg
268443 ± 5% -37.7% 167155 ± 6% sched_debug.cpu.clock.max
268426 ± 5% -37.7% 167141 ± 6% sched_debug.cpu.clock.min
268435 ± 5% -37.7% 167150 ± 6% sched_debug.cpu.clock_task.avg
268443 ± 5% -37.7% 167155 ± 6% sched_debug.cpu.clock_task.max
268426 ± 5% -37.7% 167141 ± 6% sched_debug.cpu.clock_task.min
427.52 ± 4% -39.5% 258.79 ± 18% sched_debug.cpu.curr->pid.avg
7133 ± 5% -38.5% 4388 ± 2% sched_debug.cpu.curr->pid.max
1597 ± 3% -39.4% 968.49 ± 10% sched_debug.cpu.curr->pid.stddev
69143 ± 5% -43.4% 39168 ± 0% sched_debug.cpu.nr_load_updates.avg
104414 ± 7% -41.2% 61358 ± 0% sched_debug.cpu.nr_load_updates.max
40699 ± 12% -35.7% 26180 ± 13% sched_debug.cpu.nr_load_updates.min
16173 ± 11% -45.1% 8874 ± 2% sched_debug.cpu.nr_load_updates.stddev
572452 ± 6% -68.8% 178351 ± 0% sched_debug.cpu.nr_switches.avg
2286232 ± 16% -62.2% 863098 ± 1% sched_debug.cpu.nr_switches.max
1022 ± 9% -31.2% 703.45 ± 7% sched_debug.cpu.nr_switches.min
670927 ± 13% -66.2% 226751 ± 2% sched_debug.cpu.nr_switches.stddev
27.81 ± 8% -30.2% 19.40 ± 22% sched_debug.cpu.nr_uninterruptible.max
-84.97 ±-15% -60.2% -33.80 ± -8% sched_debug.cpu.nr_uninterruptible.min
18.80 ± 9% -57.2% 8.06 ± 6% sched_debug.cpu.nr_uninterruptible.stddev
572289 ± 6% -68.9% 178115 ± 0% sched_debug.cpu.sched_count.avg
2287959 ± 16% -62.3% 861574 ± 1% sched_debug.cpu.sched_count.max
683.79 ± 11% -38.5% 420.60 ± 9% sched_debug.cpu.sched_count.min
671226 ± 13% -66.2% 226646 ± 2% sched_debug.cpu.sched_count.stddev
285499 ± 6% -69.0% 88575 ± 0% sched_debug.cpu.sched_goidle.avg
1139461 ± 16% -62.3% 429764 ± 1% sched_debug.cpu.sched_goidle.max
277.76 ± 13% -37.3% 174.25 ± 10% sched_debug.cpu.sched_goidle.min
334870 ± 13% -66.3% 112944 ± 2% sched_debug.cpu.sched_goidle.stddev
286808 ± 6% -68.9% 89323 ± 0% sched_debug.cpu.ttwu_count.avg
1292490 ± 15% -55.4% 576405 ± 0% sched_debug.cpu.ttwu_count.max
300.28 ± 5% -45.5% 163.75 ± 4% sched_debug.cpu.ttwu_count.min
348803 ± 13% -62.2% 131973 ± 1% sched_debug.cpu.ttwu_count.stddev
255200 ± 11% +21.7% 310625 ± 0% sched_debug.cpu.ttwu_local.max
162.35 ± 5% -50.8% 79.90 ± 3% sched_debug.cpu.ttwu_local.min
268435 ± 5% -37.7% 167147 ± 6% sched_debug.cpu_clk
267057 ± 5% -37.9% 165797 ± 6% sched_debug.ktime
268435 ± 5% -37.7% 167147 ± 6% sched_debug.sched_clk
204.00 ± 27% -100.0% 0.00 ± -1% sched_debug.tailf2fs_flush-259
1.80 ± 21% -49.3% 0.91 ± 3% perf-profile.calltrace.cycles-pp.__account_scheduler_latency.enqueue_entity.enqueue_task_fair.activate_task.ttwu_do_activate
2.37 ± 5% +43.4% 3.40 ± 6% perf-profile.calltrace.cycles-pp.__alloc_percpu_gfp.__percpu_counter_init.f2fs_alloc_inode.alloc_inode.new_inode_pseudo
1.14 ± 4% +43.6% 1.63 ± 2% perf-profile.calltrace.cycles-pp.__blk_mq_complete_request.blk_mq_complete_request.__nvme_process_cq.nvme_irq.__handle_irq_event_percpu
7.85 ± 7% -36.7% 4.97 ± 12% perf-profile.calltrace.cycles-pp.__f2fs_add_link.f2fs_create.path_openat.do_filp_open.do_sys_open
0.62 ± 3% +39.8% 0.87 ± 12% perf-profile.calltrace.cycles-pp.__f2fs_submit_merged_bio.f2fs_submit_merged_bio_cond.f2fs_wait_on_page_writeback.wait_on_node_pages_writeback.f2fs_do_sync_file
1.99 ± 7% +51.6% 3.02 ± 9% perf-profile.calltrace.cycles-pp.__filemap_fdatawrite_range.filemap_write_and_wait_range.f2fs_do_sync_file.f2fs_sync_file.vfs_fsync_range
0.97 ± 3% +42.3% 1.39 ± 6% perf-profile.calltrace.cycles-pp.__generic_file_write_iter.f2fs_file_write_iter.__vfs_write.vfs_write.sys_write
1.19 ± 4% +45.1% 1.72 ± 1% perf-profile.calltrace.cycles-pp.__handle_irq_event_percpu.handle_irq_event_percpu.handle_irq_event.handle_edge_irq.handle_irq
1.17 ± 4% +43.8% 1.67 ± 1% perf-profile.calltrace.cycles-pp.__nvme_process_cq.nvme_irq.__handle_irq_event_percpu.handle_irq_event_percpu.handle_irq_event
2.42 ± 5% +44.2% 3.49 ± 6% perf-profile.calltrace.cycles-pp.__percpu_counter_init.f2fs_alloc_inode.alloc_inode.new_inode_pseudo.new_inode
1.16 ± 7% +37.9% 1.59 ± 8% perf-profile.calltrace.cycles-pp.__percpu_counter_sum.f2fs_balance_fs.f2fs_create.path_openat.do_filp_open
0.93 ± 9% +29.6% 1.21 ± 10% perf-profile.calltrace.cycles-pp.__percpu_counter_sum.f2fs_balance_fs.f2fs_write_data_page.f2fs_write_cache_pages.f2fs_write_data_pages
0.40 ± 57% +332.7% 1.72 ± 33% perf-profile.calltrace.cycles-pp.__percpu_counter_sum.f2fs_write_data_pages.do_writepages.__writeback_single_inode.writeback_sb_inodes
1.08 ± 2% +38.9% 1.51 ± 5% perf-profile.calltrace.cycles-pp.__vfs_write.vfs_write.sys_write.entry_SYSCALL_64_fastpath
0.79 ± 4% +47.9% 1.17 ± 3% perf-profile.calltrace.cycles-pp.__wake_up.__wake_up_bit.end_page_writeback.f2fs_write_end_io.bio_endio
0.79 ± 4% +48.6% 1.18 ± 3% perf-profile.calltrace.cycles-pp.__wake_up_bit.end_page_writeback.f2fs_write_end_io.bio_endio.blk_update_request
0.78 ± 4% +48.9% 1.17 ± 3% perf-profile.calltrace.cycles-pp.__wake_up_common.__wake_up.__wake_up_bit.end_page_writeback.f2fs_write_end_io
0.87 ± 8% +248.6% 3.05 ± 31% perf-profile.calltrace.cycles-pp.__writeback_inodes_wb.wb_writeback.wb_workfn.process_one_work.worker_thread
0.59 ± 5% +259.9% 2.13 ± 32% perf-profile.calltrace.cycles-pp.__writeback_single_inode.writeback_sb_inodes.__writeback_inodes_wb.wb_writeback.wb_workfn
0.71 ± 4% +44.4% 1.02 ± 2% perf-profile.calltrace.cycles-pp.activate_task.ttwu_do_activate.try_to_wake_up.default_wake_function.wake_bit_function
1.72 ± 27% -100.0% 0.00 ± -1% perf-profile.calltrace.cycles-pp.activate_task.ttwu_do_activate.try_to_wake_up.wake_up_q.rwsem_wake
2.69 ± 4% +42.8% 3.84 ± 7% perf-profile.calltrace.cycles-pp.alloc_inode.new_inode_pseudo.new_inode.f2fs_new_inode.f2fs_create
0.99 ± 3% +45.3% 1.43 ± 2% perf-profile.calltrace.cycles-pp.bio_endio.blk_update_request.blk_mq_end_request.nvme_complete_rq.__blk_mq_complete_request
1.14 ± 4% +44.1% 1.64 ± 2% perf-profile.calltrace.cycles-pp.blk_mq_complete_request.__nvme_process_cq.nvme_irq.__handle_irq_event_percpu.handle_irq_event_percpu
1.09 ± 4% +45.5% 1.58 ± 2% perf-profile.calltrace.cycles-pp.blk_mq_end_request.nvme_complete_rq.__blk_mq_complete_request.blk_mq_complete_request.__nvme_process_cq
1.02 ± 3% +46.1% 1.49 ± 2% perf-profile.calltrace.cycles-pp.blk_update_request.blk_mq_end_request.nvme_complete_rq.__blk_mq_complete_request.blk_mq_complete_request
1.00 ± 14% -100.0% 0.00 ± -1% perf-profile.calltrace.cycles-pp.call_rwsem_wake.up_write.percpu_up_write.set_node_addr.new_node_page
0.78 ± 4% +47.9% 1.15 ± 3% perf-profile.calltrace.cycles-pp.default_wake_function.wake_bit_function.__wake_up_common.__wake_up.__wake_up_bit
1.40 ± 4% +42.1% 1.98 ± 1% perf-profile.calltrace.cycles-pp.do_IRQ.ret_from_intr.cpuidle_enter.call_cpuidle.cpu_startup_entry
16.62 ± 5% -24.3% 12.58 ± 10% perf-profile.calltrace.cycles-pp.do_fsync.sys_fsync.entry_SYSCALL_64_fastpath
1.98 ± 7% +51.4% 3.00 ± 8% perf-profile.calltrace.cycles-pp.do_writepages.__filemap_fdatawrite_range.filemap_write_and_wait_range.f2fs_do_sync_file.f2fs_sync_file
0.55 ± 4% +233.8% 1.85 ± 33% perf-profile.calltrace.cycles-pp.do_writepages.__writeback_single_inode.writeback_sb_inodes.__writeback_inodes_wb.wb_writeback
0.91 ± 4% +48.8% 1.36 ± 3% perf-profile.calltrace.cycles-pp.end_page_writeback.f2fs_write_end_io.bio_endio.blk_update_request.blk_mq_end_request
2.23 ± 16% -55.4% 1.00 ± 3% perf-profile.calltrace.cycles-pp.enqueue_entity.enqueue_task_fair.activate_task.ttwu_do_activate.try_to_wake_up
0.70 ± 4% +43.8% 1.01 ± 2% perf-profile.calltrace.cycles-pp.enqueue_task_fair.activate_task.ttwu_do_activate.try_to_wake_up.default_wake_function
1.56 ± 23% -100.0% 0.00 ± -1% perf-profile.calltrace.cycles-pp.enqueue_task_fair.activate_task.ttwu_do_activate.try_to_wake_up.wake_up_q
7.83 ± 7% -36.9% 4.94 ± 12% perf-profile.calltrace.cycles-pp.f2fs_add_regular_entry.__f2fs_add_link.f2fs_create.path_openat.do_filp_open
2.58 ± 5% +43.4% 3.71 ± 6% perf-profile.calltrace.cycles-pp.f2fs_alloc_inode.alloc_inode.new_inode_pseudo.new_inode.f2fs_new_inode
1.33 ± 8% +50.5% 2.00 ± 7% perf-profile.calltrace.cycles-pp.f2fs_balance_fs.f2fs_create.path_openat.do_filp_open.do_sys_open
1.15 ± 8% +59.0% 1.83 ± 9% perf-profile.calltrace.cycles-pp.f2fs_balance_fs.f2fs_write_data_page.f2fs_write_cache_pages.f2fs_write_data_pages.do_writepages
0.77 ± 2% +52.9% 1.17 ± 8% perf-profile.calltrace.cycles-pp.f2fs_dentry_hash.find_in_level.f2fs_find_entry.f2fs_lookup.path_openat
16.57 ± 5% -24.4% 12.52 ± 10% perf-profile.calltrace.cycles-pp.f2fs_do_sync_file.f2fs_sync_file.vfs_fsync_range.do_fsync.sys_fsync
1.02 ± 3% +42.2% 1.45 ± 6% perf-profile.calltrace.cycles-pp.f2fs_file_write_iter.__vfs_write.vfs_write.sys_write.entry_SYSCALL_64_fastpath
4.88 ± 7% +59.7% 7.79 ± 6% perf-profile.calltrace.cycles-pp.f2fs_find_entry.f2fs_lookup.path_openat.do_filp_open.do_sys_open
4.96 ± 7% +58.6% 7.87 ± 6% perf-profile.calltrace.cycles-pp.f2fs_lookup.path_openat.do_filp_open.do_sys_open.sys_open
3.11 ± 4% +41.6% 4.40 ± 6% perf-profile.calltrace.cycles-pp.f2fs_new_inode.f2fs_create.path_openat.do_filp_open.do_sys_open
0.68 ± 3% +41.1% 0.95 ± 13% perf-profile.calltrace.cycles-pp.f2fs_submit_merged_bio_cond.f2fs_wait_on_page_writeback.wait_on_node_pages_writeback.f2fs_do_sync_file.f2fs_sync_file
16.59 ± 5% -24.4% 12.55 ± 10% perf-profile.calltrace.cycles-pp.f2fs_sync_file.vfs_fsync_range.do_fsync.sys_fsync.entry_SYSCALL_64_fastpath
1.03 ± 4% +59.1% 1.64 ± 13% perf-profile.calltrace.cycles-pp.f2fs_wait_on_page_writeback.wait_on_node_pages_writeback.f2fs_do_sync_file.f2fs_sync_file.vfs_fsync_range
0.67 ± 2% +35.6% 0.91 ± 7% perf-profile.calltrace.cycles-pp.f2fs_write_begin.generic_perform_write.__generic_file_write_iter.f2fs_file_write_iter.__vfs_write
1.65 ± 7% +43.8% 2.37 ± 10% perf-profile.calltrace.cycles-pp.f2fs_write_cache_pages.f2fs_write_data_pages.do_writepages.__filemap_fdatawrite_range.filemap_write_and_wait_range
1.32 ± 7% +45.0% 1.92 ± 9% perf-profile.calltrace.cycles-pp.f2fs_write_data_page.f2fs_write_cache_pages.f2fs_write_data_pages.do_writepages.__filemap_fdatawrite_range
1.98 ± 7% +51.1% 2.98 ± 8% perf-profile.calltrace.cycles-pp.f2fs_write_data_pages.do_writepages.__filemap_fdatawrite_range.filemap_write_and_wait_range.f2fs_do_sync_file
0.55 ± 4% +232.9% 1.85 ± 33% perf-profile.calltrace.cycles-pp.f2fs_write_data_pages.do_writepages.__writeback_single_inode.writeback_sb_inodes.__writeback_inodes_wb
0.98 ± 3% +45.8% 1.43 ± 2% perf-profile.calltrace.cycles-pp.f2fs_write_end_io.bio_endio.blk_update_request.blk_mq_end_request.nvme_complete_rq
3.10 ± 4% -65.8% 1.06 ± 13% perf-profile.calltrace.cycles-pp.f2fs_write_node_page.fsync_node_pages.f2fs_do_sync_file.f2fs_sync_file.vfs_fsync_range
2.08 ± 6% +63.2% 3.40 ± 9% perf-profile.calltrace.cycles-pp.filemap_write_and_wait_range.f2fs_do_sync_file.f2fs_sync_file.vfs_fsync_range.do_fsync
6.71 ± 14% -46.1% 3.62 ± 18% perf-profile.calltrace.cycles-pp.find_get_pages_tag.pagevec_lookup_tag.fsync_node_pages.f2fs_do_sync_file.f2fs_sync_file
4.83 ± 7% +59.5% 7.71 ± 6% perf-profile.calltrace.cycles-pp.find_in_level.f2fs_find_entry.f2fs_lookup.path_openat.do_filp_open
2.81 ± 8% +76.4% 4.95 ± 5% perf-profile.calltrace.cycles-pp.find_target_dentry.find_in_level.f2fs_find_entry.f2fs_lookup.path_openat
11.21 ± 7% -52.2% 5.37 ± 15% perf-profile.calltrace.cycles-pp.fsync_node_pages.f2fs_do_sync_file.f2fs_sync_file.vfs_fsync_range.do_fsync
0.85 ± 3% +38.6% 1.18 ± 6% perf-profile.calltrace.cycles-pp.generic_perform_write.__generic_file_write_iter.f2fs_file_write_iter.__vfs_write.vfs_write
3.32 ± 9% -78.2% 0.72 ± 12% perf-profile.calltrace.cycles-pp.get_node_info.new_node_page.new_inode_page.init_inode_metadata.f2fs_add_regular_entry
1.27 ± 4% +41.7% 1.80 ± 1% perf-profile.calltrace.cycles-pp.handle_edge_irq.handle_irq.do_IRQ.ret_from_intr.cpuidle_enter
1.29 ± 4% +42.5% 1.85 ± 1% perf-profile.calltrace.cycles-pp.handle_irq.do_IRQ.ret_from_intr.cpuidle_enter.call_cpuidle
1.22 ± 4% +43.6% 1.75 ± 1% perf-profile.calltrace.cycles-pp.handle_irq_event.handle_edge_irq.handle_irq.do_IRQ.ret_from_intr
1.21 ± 3% +44.6% 1.74 ± 1% perf-profile.calltrace.cycles-pp.handle_irq_event_percpu.handle_irq_event.handle_edge_irq.handle_irq.do_IRQ
7.20 ± 8% -46.5% 3.85 ± 15% perf-profile.calltrace.cycles-pp.init_inode_metadata.f2fs_add_regular_entry.__f2fs_add_link.f2fs_create.path_openat
1.28 ± 8% +187.7% 3.68 ± 26% perf-profile.calltrace.cycles-pp.kthread.ret_from_fork
1.27 ± 5% +45.4% 1.85 ± 10% perf-profile.calltrace.cycles-pp.memset_erms.__alloc_percpu_gfp.__percpu_counter_init.f2fs_alloc_inode.alloc_inode
2.75 ± 4% +42.4% 3.91 ± 6% perf-profile.calltrace.cycles-pp.new_inode.f2fs_new_inode.f2fs_create.path_openat.do_filp_open
6.96 ± 8% -48.7% 3.57 ± 14% perf-profile.calltrace.cycles-pp.new_inode_page.init_inode_metadata.f2fs_add_regular_entry.__f2fs_add_link.f2fs_create
2.70 ± 4% +42.9% 3.85 ± 7% perf-profile.calltrace.cycles-pp.new_inode_pseudo.new_inode.f2fs_new_inode.f2fs_create.path_openat
6.95 ± 8% -49.0% 3.55 ± 15% perf-profile.calltrace.cycles-pp.new_node_page.new_inode_page.init_inode_metadata.f2fs_add_regular_entry.__f2fs_add_link
1.12 ± 4% +44.3% 1.61 ± 2% perf-profile.calltrace.cycles-pp.nvme_complete_rq.__blk_mq_complete_request.blk_mq_complete_request.__nvme_process_cq.nvme_irq
1.17 ± 4% +44.5% 1.70 ± 1% perf-profile.calltrace.cycles-pp.nvme_irq.__handle_irq_event_percpu.handle_irq_event_percpu.handle_irq_event.handle_edge_irq
6.83 ± 14% -45.8% 3.70 ± 18% perf-profile.calltrace.cycles-pp.pagevec_lookup_tag.fsync_node_pages.f2fs_do_sync_file.f2fs_sync_file.vfs_fsync_range
1.00 ± 6% +37.6% 1.38 ± 7% perf-profile.calltrace.cycles-pp.pcpu_alloc.__alloc_percpu_gfp.__percpu_counter_init.f2fs_alloc_inode.alloc_inode
1.56 ± 10% -100.0% 0.00 ± -1% perf-profile.calltrace.cycles-pp.percpu_down_write.get_node_info.new_node_page.new_inode_page.init_inode_metadata
1.58 ± 5% -100.0% 0.00 ± -1% perf-profile.calltrace.cycles-pp.percpu_down_write.set_node_addr.f2fs_write_node_page.fsync_node_pages.f2fs_do_sync_file
1.15 ± 8% -100.0% 0.00 ± -1% perf-profile.calltrace.cycles-pp.percpu_down_write.set_node_addr.new_node_page.new_inode_page.init_inode_metadata
0.87 ± 11% -100.0% 0.00 ± -1% perf-profile.calltrace.cycles-pp.percpu_up_write.get_node_info.new_node_page.new_inode_page.init_inode_metadata
1.03 ± 14% -100.0% 0.00 ± -1% perf-profile.calltrace.cycles-pp.percpu_up_write.set_node_addr.new_node_page.new_inode_page.init_inode_metadata
1.12 ± 8% +213.3% 3.53 ± 27% perf-profile.calltrace.cycles-pp.process_one_work.worker_thread.kthread.ret_from_fork
3.52 ± 17% -41.6% 2.05 ± 17% perf-profile.calltrace.cycles-pp.radix_tree_next_chunk.find_get_pages_tag.pagevec_lookup_tag.fsync_node_pages.f2fs_do_sync_file
1.28 ± 8% +187.7% 3.68 ± 26% perf-profile.calltrace.cycles-pp.ret_from_fork
1.43 ± 3% +41.6% 2.02 ± 1% perf-profile.calltrace.cycles-pp.ret_from_intr.cpuidle_enter.call_cpuidle.cpu_startup_entry.start_secondary
1.63 ± 13% -100.0% 0.00 ± -1% perf-profile.calltrace.cycles-pp.rwsem_wake.call_rwsem_wake.up_write.percpu_up_write.set_node_addr
2.35 ± 6% -100.0% 0.00 ± -1% perf-profile.calltrace.cycles-pp.set_node_addr.f2fs_write_node_page.fsync_node_pages.f2fs_do_sync_file.f2fs_sync_file
2.33 ± 11% -100.0% 0.00 ± -1% perf-profile.calltrace.cycles-pp.set_node_addr.new_node_page.new_inode_page.init_inode_metadata.f2fs_add_regular_entry
16.63 ± 5% -24.3% 12.59 ± 10% perf-profile.calltrace.cycles-pp.sys_fsync.entry_SYSCALL_64_fastpath
1.16 ± 1% +41.0% 1.64 ± 5% perf-profile.calltrace.cycles-pp.sys_write.entry_SYSCALL_64_fastpath
0.77 ± 4% +47.6% 1.14 ± 3% perf-profile.calltrace.cycles-pp.try_to_wake_up.default_wake_function.wake_bit_function.__wake_up_common.__wake_up
2.31 ± 12% -100.0% 0.00 ± -1% perf-profile.calltrace.cycles-pp.try_to_wake_up.wake_up_q.rwsem_wake.call_rwsem_wake.up_write
0.73 ± 3% +45.2% 1.05 ± 2% perf-profile.calltrace.cycles-pp.ttwu_do_activate.try_to_wake_up.default_wake_function.wake_bit_function.__wake_up_common
1.81 ± 26% -100.0% 0.00 ± -1% perf-profile.calltrace.cycles-pp.ttwu_do_activate.try_to_wake_up.wake_up_q.rwsem_wake.call_rwsem_wake
1.02 ± 14% -100.0% 0.00 ± -1% perf-profile.calltrace.cycles-pp.up_write.percpu_up_write.set_node_addr.new_node_page.new_inode_page
16.60 ± 5% -24.4% 12.56 ± 10% perf-profile.calltrace.cycles-pp.vfs_fsync_range.do_fsync.sys_fsync.entry_SYSCALL_64_fastpath
1.14 ± 2% +41.3% 1.61 ± 5% perf-profile.calltrace.cycles-pp.vfs_write.sys_write.entry_SYSCALL_64_fastpath
1.21 ± 5% +59.6% 1.94 ± 12% perf-profile.calltrace.cycles-pp.wait_on_node_pages_writeback.f2fs_do_sync_file.f2fs_sync_file.vfs_fsync_range.do_fsync
0.78 ± 4% +48.7% 1.16 ± 3% perf-profile.calltrace.cycles-pp.wake_bit_function.__wake_up_common.__wake_up.__wake_up_bit.end_page_writeback
2.37 ± 12% -100.0% 0.00 ± -1% perf-profile.calltrace.cycles-pp.wake_up_q.rwsem_wake.call_rwsem_wake.up_write.percpu_up_write
0.96 ± 9% +253.0% 3.38 ± 28% perf-profile.calltrace.cycles-pp.wb_workfn.process_one_work.worker_thread.kthread.ret_from_fork
0.96 ± 9% +253.0% 3.38 ± 28% perf-profile.calltrace.cycles-pp.wb_writeback.wb_workfn.process_one_work.worker_thread.kthread
1.12 ± 8% +213.6% 3.53 ± 27% perf-profile.calltrace.cycles-pp.worker_thread.kthread.ret_from_fork
0.85 ± 8% +249.6% 2.96 ± 31% perf-profile.calltrace.cycles-pp.writeback_sb_inodes.__writeback_inodes_wb.wb_writeback.wb_workfn.process_one_work
3.22 ± 9% -50.4% 1.59 ± 6% perf-profile.children.cycles-pp.__account_scheduler_latency
2.38 ± 5% +43.0% 3.40 ± 6% perf-profile.children.cycles-pp.__alloc_percpu_gfp
1.38 ± 6% +57.5% 2.17 ± 8% perf-profile.children.cycles-pp.__blk_mq_complete_request
7.85 ± 7% -36.7% 4.97 ± 12% perf-profile.children.cycles-pp.__f2fs_add_link
0.67 ± 4% +46.8% 0.98 ± 8% perf-profile.children.cycles-pp.__f2fs_submit_merged_bio
2.08 ± 7% +69.9% 3.53 ± 8% perf-profile.children.cycles-pp.__filemap_fdatawrite_range
0.97 ± 3% +43.6% 1.40 ± 6% perf-profile.children.cycles-pp.__generic_file_write_iter
1.43 ± 6% +58.8% 2.28 ± 7% perf-profile.children.cycles-pp.__handle_irq_event_percpu
1.82 ± 10% -47.3% 0.96 ± 6% perf-profile.children.cycles-pp.__kernel_text_address
1.41 ± 6% +58.7% 2.24 ± 7% perf-profile.children.cycles-pp.__nvme_process_cq
2.42 ± 5% +44.5% 3.50 ± 6% perf-profile.children.cycles-pp.__percpu_counter_init
3.59 ± 6% +64.2% 5.89 ± 15% perf-profile.children.cycles-pp.__percpu_counter_sum
0.86 ± 7% +53.4% 1.31 ± 10% perf-profile.children.cycles-pp.__radix_tree_lookup
1.46 ± 6% -32.9% 0.98 ± 9% perf-profile.children.cycles-pp.__schedule
1.34 ± 3% -11.0% 1.20 ± 5% perf-profile.children.cycles-pp.__tick_nohz_idle_enter
1.09 ± 1% +40.1% 1.53 ± 5% perf-profile.children.cycles-pp.__vfs_write
1.04 ± 3% +49.4% 1.56 ± 8% perf-profile.children.cycles-pp.__wake_up
1.08 ± 5% +59.9% 1.72 ± 9% perf-profile.children.cycles-pp.__wake_up_bit
1.01 ± 4% +54.8% 1.56 ± 8% perf-profile.children.cycles-pp.__wake_up_common
0.87 ± 8% +248.6% 3.05 ± 31% perf-profile.children.cycles-pp.__writeback_inodes_wb
0.59 ± 5% +259.9% 2.13 ± 32% perf-profile.children.cycles-pp.__writeback_single_inode
1.10 ± 7% +81.0% 2.00 ± 15% perf-profile.children.cycles-pp._raw_spin_lock
3.67 ± 8% -50.3% 1.82 ± 7% perf-profile.children.cycles-pp.activate_task
2.69 ± 4% +42.6% 3.84 ± 6% perf-profile.children.cycles-pp.alloc_inode
1.23 ± 5% +58.8% 1.95 ± 8% perf-profile.children.cycles-pp.bio_endio
1.39 ± 6% +58.2% 2.19 ± 8% perf-profile.children.cycles-pp.blk_mq_complete_request
1.32 ± 5% +59.1% 2.10 ± 8% perf-profile.children.cycles-pp.blk_mq_end_request
1.24 ± 5% +59.6% 1.98 ± 8% perf-profile.children.cycles-pp.blk_update_request
3.44 ± 10% -82.2% 0.61 ± 14% perf-profile.children.cycles-pp.call_rwsem_wake
0.99 ± 4% +55.9% 1.54 ± 8% perf-profile.children.cycles-pp.default_wake_function
1.67 ± 6% +56.1% 2.61 ± 7% perf-profile.children.cycles-pp.do_IRQ
16.62 ± 5% -24.3% 12.58 ± 10% perf-profile.children.cycles-pp.do_fsync
2.68 ± 6% +106.4% 5.53 ± 16% perf-profile.children.cycles-pp.do_writepages
2.90 ± 9% -49.2% 1.47 ± 6% perf-profile.children.cycles-pp.dump_trace
1.11 ± 5% +61.1% 1.79 ± 9% perf-profile.children.cycles-pp.end_page_writeback
3.56 ± 8% -50.4% 1.77 ± 7% perf-profile.children.cycles-pp.enqueue_entity
3.60 ± 8% -50.3% 1.79 ± 7% perf-profile.children.cycles-pp.enqueue_task_fair
7.83 ± 7% -36.9% 4.94 ± 12% perf-profile.children.cycles-pp.f2fs_add_regular_entry
2.59 ± 5% +43.7% 3.72 ± 6% perf-profile.children.cycles-pp.f2fs_alloc_inode
2.49 ± 8% +54.4% 3.84 ± 8% perf-profile.children.cycles-pp.f2fs_balance_fs
0.86 ± 2% +49.1% 1.28 ± 9% perf-profile.children.cycles-pp.f2fs_dentry_hash
16.57 ± 5% -24.4% 12.53 ± 10% perf-profile.children.cycles-pp.f2fs_do_sync_file
1.02 ± 3% +42.8% 1.46 ± 6% perf-profile.children.cycles-pp.f2fs_file_write_iter
4.88 ± 7% +59.8% 7.80 ± 6% perf-profile.children.cycles-pp.f2fs_find_entry
4.97 ± 7% +58.5% 7.88 ± 6% perf-profile.children.cycles-pp.f2fs_lookup
3.11 ± 4% +41.6% 4.41 ± 6% perf-profile.children.cycles-pp.f2fs_new_inode
0.68 ± 4% +40.7% 0.96 ± 13% perf-profile.children.cycles-pp.f2fs_submit_merged_bio_cond
16.60 ± 5% -24.4% 12.55 ± 10% perf-profile.children.cycles-pp.f2fs_sync_file
1.04 ± 4% +58.6% 1.65 ± 13% perf-profile.children.cycles-pp.f2fs_wait_on_page_writeback
0.67 ± 2% +35.6% 0.91 ± 7% perf-profile.children.cycles-pp.f2fs_write_begin
1.73 ± 7% +65.8% 2.87 ± 9% perf-profile.children.cycles-pp.f2fs_write_cache_pages
1.39 ± 7% +68.6% 2.33 ± 9% perf-profile.children.cycles-pp.f2fs_write_data_page
2.62 ± 6% +104.0% 5.35 ± 16% perf-profile.children.cycles-pp.f2fs_write_data_pages
1.20 ± 5% +58.7% 1.91 ± 8% perf-profile.children.cycles-pp.f2fs_write_end_io
3.11 ± 4% -65.5% 1.07 ± 13% perf-profile.children.cycles-pp.f2fs_write_node_page
2.08 ± 6% +63.1% 3.40 ± 9% perf-profile.children.cycles-pp.filemap_write_and_wait_range
0.95 ± 11% +47.9% 1.40 ± 8% perf-profile.children.cycles-pp.find_get_entry
6.83 ± 13% -43.6% 3.85 ± 17% perf-profile.children.cycles-pp.find_get_pages_tag
4.84 ± 7% +59.4% 7.71 ± 6% perf-profile.children.cycles-pp.find_in_level
2.82 ± 8% +76.0% 4.96 ± 5% perf-profile.children.cycles-pp.find_target_dentry
11.21 ± 7% -52.2% 5.37 ± 15% perf-profile.children.cycles-pp.fsync_node_pages
0.85 ± 2% +39.0% 1.18 ± 7% perf-profile.children.cycles-pp.generic_perform_write
3.51 ± 8% -75.7% 0.85 ± 10% perf-profile.children.cycles-pp.get_node_info
0.69 ± 10% +52.7% 1.05 ± 7% perf-profile.children.cycles-pp.get_node_page
1.54 ± 6% +55.7% 2.39 ± 8% perf-profile.children.cycles-pp.handle_edge_irq
1.56 ± 5% +56.2% 2.44 ± 8% perf-profile.children.cycles-pp.handle_irq
1.47 ± 5% +57.7% 2.32 ± 7% perf-profile.children.cycles-pp.handle_irq_event
1.46 ± 5% +58.0% 2.30 ± 7% perf-profile.children.cycles-pp.handle_irq_event_percpu
7.20 ± 8% -46.4% 3.86 ± 15% perf-profile.children.cycles-pp.init_inode_metadata
1.28 ± 8% +187.7% 3.68 ± 26% perf-profile.children.cycles-pp.kthread
1.35 ± 5% +44.7% 1.96 ± 10% perf-profile.children.cycles-pp.memset_erms
0.65 ± 14% +107.7% 1.35 ± 20% perf-profile.children.cycles-pp.native_queued_spin_lock_slowpath
2.75 ± 4% +42.3% 3.91 ± 6% perf-profile.children.cycles-pp.new_inode
6.97 ± 8% -48.8% 3.57 ± 14% perf-profile.children.cycles-pp.new_inode_page
2.70 ± 4% +42.8% 3.86 ± 7% perf-profile.children.cycles-pp.new_inode_pseudo
6.96 ± 8% -48.9% 3.55 ± 15% perf-profile.children.cycles-pp.new_node_page
1.35 ± 6% +58.9% 2.15 ± 8% perf-profile.children.cycles-pp.nvme_complete_rq
1.42 ± 6% +58.2% 2.24 ± 7% perf-profile.children.cycles-pp.nvme_irq
1.88 ± 6% +44.5% 2.72 ± 8% perf-profile.children.cycles-pp.pagecache_get_page
6.98 ± 13% -43.3% 3.96 ± 17% perf-profile.children.cycles-pp.pagevec_lookup_tag
1.01 ± 6% +38.5% 1.40 ± 7% perf-profile.children.cycles-pp.pcpu_alloc
1.91 ± 4% -100.0% 0.00 ± -1% perf-profile.children.cycles-pp.percpu_down_read
4.30 ± 8% -100.0% 0.00 ± -1% perf-profile.children.cycles-pp.percpu_down_write
2.56 ± 12% -100.0% 0.00 ± -1% perf-profile.children.cycles-pp.percpu_up_write
2.42 ± 10% -48.6% 1.24 ± 6% perf-profile.children.cycles-pp.print_context_stack
1.12 ± 8% +213.3% 3.53 ± 27% perf-profile.children.cycles-pp.process_one_work
3.68 ± 16% -38.9% 2.25 ± 16% perf-profile.children.cycles-pp.radix_tree_next_chunk
1.28 ± 8% +186.5% 3.68 ± 26% perf-profile.children.cycles-pp.ret_from_fork
1.70 ± 5% +55.6% 2.65 ± 7% perf-profile.children.cycles-pp.ret_from_intr
3.42 ± 10% -82.1% 0.61 ± 13% perf-profile.children.cycles-pp.rwsem_wake
2.90 ± 9% -49.1% 1.48 ± 6% perf-profile.children.cycles-pp.save_stack_trace_tsk
1.50 ± 6% -31.7% 1.03 ± 9% perf-profile.children.cycles-pp.schedule
4.69 ± 8% -88.3% 0.55 ± 9% perf-profile.children.cycles-pp.set_node_addr
16.64 ± 5% -24.3% 12.60 ± 10% perf-profile.children.cycles-pp.sys_fsync
1.17 ± 2% +40.7% 1.65 ± 5% perf-profile.children.cycles-pp.sys_write
1.16 ± 2% -13.2% 1.00 ± 6% perf-profile.children.cycles-pp.tick_nohz_stop_sched_tick
4.48 ± 9% -50.9% 2.20 ± 9% perf-profile.children.cycles-pp.try_to_wake_up
3.82 ± 8% -50.5% 1.89 ± 7% perf-profile.children.cycles-pp.ttwu_do_activate
2.73 ± 11% -75.1% 0.68 ± 6% perf-profile.children.cycles-pp.up_write
16.61 ± 5% -24.3% 12.56 ± 10% perf-profile.children.cycles-pp.vfs_fsync_range
1.14 ± 2% +41.8% 1.62 ± 5% perf-profile.children.cycles-pp.vfs_write
1.21 ± 5% +59.8% 1.94 ± 12% perf-profile.children.cycles-pp.wait_on_node_pages_writeback
0.94 ± 5% +61.3% 1.51 ± 8% perf-profile.children.cycles-pp.wake_bit_function
3.57 ± 10% -81.4% 0.66 ± 10% perf-profile.children.cycles-pp.wake_up_q
0.96 ± 9% +253.0% 3.38 ± 28% perf-profile.children.cycles-pp.wb_workfn
0.96 ± 9% +253.0% 3.38 ± 28% perf-profile.children.cycles-pp.wb_writeback
1.12 ± 8% +213.6% 3.53 ± 27% perf-profile.children.cycles-pp.worker_thread
0.85 ± 8% +249.6% 2.96 ± 31% perf-profile.children.cycles-pp.writeback_sb_inodes
2.58 ± 7% +59.9% 4.12 ± 14% perf-profile.self.cycles-pp.__percpu_counter_sum
0.86 ± 7% +53.4% 1.31 ± 10% perf-profile.self.cycles-pp.__radix_tree_lookup
0.86 ± 2% +49.1% 1.28 ± 9% perf-profile.self.cycles-pp.f2fs_dentry_hash
3.19 ± 10% -48.2% 1.65 ± 18% perf-profile.self.cycles-pp.find_get_pages_tag
2.82 ± 8% +76.0% 4.96 ± 5% perf-profile.self.cycles-pp.find_target_dentry
1.35 ± 5% +44.7% 1.96 ± 10% perf-profile.self.cycles-pp.memset_erms
0.65 ± 14% +107.7% 1.35 ± 20% perf-profile.self.cycles-pp.native_queued_spin_lock_slowpath
0.74 ± 8% +37.9% 1.03 ± 9% perf-profile.self.cycles-pp.pcpu_alloc
3.20 ± 8% -100.0% 0.00 ± -1% perf-profile.self.cycles-pp.percpu_down_write
3.68 ± 16% -38.9% 2.25 ± 16% perf-profile.self.cycles-pp.radix_tree_next_chunk
perf-stat.dTLB-loads
9.5e+11 *+---------------------------*------------------------------------+
| . ..*... .. + |
9e+11 ++ *. *....*...*...* + ..*...*....*... |
8.5e+11 ++ + ..*. *...*...*...|
| *. *
8e+11 ++ |
| |
7.5e+11 ++ |
| |
7e+11 ++ |
6.5e+11 ++ |
O |
6e+11 ++ |
| O O |
5.5e+11 ++------O---------------------------------------------------------+
perf-stat.dTLB-load-misses
2.2e+10 ++----------------------------------------------------------------+
2.1e+10 *+ * |
| .. .*...*....*...*.. .. + |
2e+10 ++ .. . . + .*... ..*....*... .*.. |
1.9e+10 ++ * * + .. *. *... .. .|
| * * *
1.8e+10 ++ |
1.7e+10 ++ |
1.6e+10 ++ |
| |
1.5e+10 O+ |
1.4e+10 ++ |
| O O |
1.3e+10 ++ O |
1.2e+10 ++----------------------------------------------------------------+
perf-stat.dTLB-store-misses
1.2e+09 ++----------------------------------------------------------------+
1.1e+09 *+ |
| .. ..*... |
1e+09 ++ ..*.. *...*... .*....*... ..*...|
9e+08 ++ *...*. *...*...*... .. *...*. *
| * |
8e+08 ++ |
7e+08 ++ |
6e+08 ++ |
| |
5e+08 ++ |
4e+08 ++ |
| O |
3e+08 O+ O O |
2e+08 ++----------------------------------------------------------------+
perf-stat.iTLB-loads
1.8e+09 ++----------------------------------------------------------------+
*.. .*... ..*...*... *.. |
1.7e+09 ++ . ..*...*.... .. *. *...*. . . ..*...*...|
1.6e+09 ++ *. * .. .. *. *
| . |
1.5e+09 ++ * |
| |
1.4e+09 ++ |
| |
1.3e+09 ++ |
1.2e+09 ++ |
O |
1.1e+09 ++ O |
| O O |
1e+09 ++----------------------------------------------------------------+
perf-stat.page-faults
1.05e+06 ++---------------------------------------------------------------+
1e+06 ++ .*. |
| .. .. ..*.. |
950000 *+ ..*....* .*. . |
900000 ++.. .*... ..*... ..*. *... .. *... |
| .. *. *. * *...*
850000 ++ * |
800000 ++ |
750000 ++ |
| |
700000 ++ |
650000 ++ |
| |
600000 O+ O |
550000 ++------O---O----------------------------------------------------+
perf-stat.context-switches
8e+07 *+-------*---*---*---*----*---*---*---*----*-------*---*----*-------+
| *.. *. *...*
7e+07 ++ |
| |
| |
6e+07 ++ |
| |
5e+07 ++ |
| |
4e+07 ++ |
| |
| |
3e+07 O+ O O O |
| |
2e+07 ++------------------------------------------------------------------+
perf-stat.cpu-migrations
400000 ++-----------------------------------------------------------------+
| ..*... |
*.. ..*....*. *.. ..*... |
350000 ++ . .*...*... ..*. . ..*. . ..*
| *... .. *. *. *...*. |
| *. |
300000 ++ |
| |
250000 ++ |
| |
| |
200000 ++ |
| |
O O O O |
150000 ++-----------------------------------------------------------------+
perf-stat.minor-faults
1.05e+06 ++---------------------------------------------------------------+
1e+06 ++ .*. |
| .. .. ..*.. |
950000 *+ ..*....* .*. . |
900000 ++.. .*... ..*... ..*. *... .. *... |
| .. *. *. * *...*
850000 ++ * |
800000 ++ |
750000 ++ |
| |
700000 ++ |
650000 ++ |
| |
600000 O+ O |
550000 ++------O---O----------------------------------------------------+
perf-stat.dTLB-store-miss-rate_
0.22 ++-------------------------------------------------------------------+
| |
0.2 *+. ..*
| . *... ..*....*. |
0.18 ++ *....*...*...*.. .. . ..*. |
| .. .*...*....*... . *. |
0.16 ++ .. *...* |
| * |
0.14 ++ |
| |
0.12 ++ |
| |
0.1 ++ |
O O O O |
0.08 ++-------------------------------------------------------------------+
fsmark.time.system_time
1600 ++-------------------------------------------------------------------+
| |
1500 *+.. ..*...*...*....*...*...*....*...*...*... ..*...*...*.... |
1400 ++ *.. *.. *...*
| |
1300 ++ |
| |
1200 ++ |
| |
1100 ++ |
1000 ++ |
| |
900 O+ |
| O O O |
800 ++-------------------------------------------------------------------+
fsmark.time.percent_of_cpu_this_job_got
340 ++--O-----------------------------------------------------------------+
O |
| O O |
335 ++ |
| |
| |
| |
330 ++ |
| |
| |
325 ++ *.. *.. .*...*
| .. .. + .. .. |
|. .*.. + ..*. |
* *...*....*...*...*.... .. . + *...*. |
320 ++-----------------------------*-------*----*-------------------------+
fsmark.time.elapsed_time
500 ++--------------------------------------------------------------------+
*.. ..*... ..*....*...*...*....*... ..*...*...*.... |
| . ..*...*.. *. *.. *...*
450 ++ *.. |
| |
| |
400 ++ |
| |
350 ++ |
| |
| |
300 ++ |
O |
| O O O |
250 ++--------------------------------------------------------------------+
fsmark.time.elapsed_time.max
500 ++--------------------------------------------------------------------+
*.. ..*... ..*....*...*...*....*... ..*...*...*.... |
| . ..*...*.. *. *.. *...*
450 ++ *.. |
| |
| |
400 ++ |
| |
350 ++ |
| |
| |
300 ++ |
O |
| O O O |
250 ++--------------------------------------------------------------------+
fsmark.time.voluntary_context_switches
4e+07 ++-----------------------*---*------------------------------------+
*... ..*...*....*...*. *...*...*... ..*...*...*... |
3.5e+07 ++ *. *.. *...*
| |
| |
3e+07 ++ |
| |
2.5e+07 ++ |
| |
2e+07 ++ |
| |
| |
1.5e+07 O+ O O |
| O |
1e+07 ++----------------------------------------------------------------+
fsmark.time.file_system_outputs
2.35e+08 ++---------------------------------------------------------------+
O O O O |
2.3e+08 ++ |
2.25e+08 ++ |
| |
2.2e+08 ++ |
| |
2.15e+08 ++ |
| |
2.1e+08 ++ |
2.05e+08 ++ |
| |
2e+08 *+..*...*...*...*...*...*...*....*...*...*...*...*...*...*...*...*
| |
1.95e+08 ++---------------------------------------------------------------+
fsmark.files_per_sec
40000 ++-----------O------------------------------------------------------+
38000 O+ O O |
| |
36000 ++ |
34000 ++ |
| |
32000 ++ |
30000 ++ |
28000 ++ |
| |
26000 ++ |
24000 ++ |
*...*....*...*... ..*.... ..*... ..*...*
22000 ++ *. *...*...*...*....*. *...*....*. |
20000 ++------------------------------------------------------------------+
interrupts.CAL:Function_call_interrupts
380000 ++-----------------------------------------------------------------+
| .*... |
360000 *+. ..*...*...*...*....*...*...*... .. *....*.. |
340000 ++ . ..*....*. * . ..*
| *. *. |
320000 ++ |
300000 ++ |
| |
280000 ++ |
260000 ++ |
| |
240000 ++ |
220000 ++ |
O O O |
200000 ++-----------O-----------------------------------------------------+
vmstat.io.bi
340 ++--O--------O--------------------------------------------------------+
O O |
320 ++ |
300 ++ |
| |
280 ++ |
| |
260 ++ |
| |
240 ++ |
220 ++ |
| |
200 ++..*.... ..*.... ..*...*
*. *...*....*...*...*....*...*...*....*. *...*...*.. |
180 ++--------------------------------------------------------------------+
vmstat.io.bo
280000 ++-----------O-----------------------------------------------------+
O O O |
260000 ++ |
240000 ++ |
| |
220000 ++ |
200000 ++ |
| |
180000 ++ |
160000 ++ |
| |
140000 ++ |
120000 *+..*...*....*...*...*...*...*....*...*...*...*... ..*....*...*...*
| *. |
100000 ++-----------------------------------------------------------------+
vmstat.system.in
115000 ++-----------------------------------------------------------------+
| O O O |
O |
110000 ++ |
| |
| |
105000 ++ |
| |
100000 ++ |
| |
| |
95000 ++..*... ..*... ..*...*
*. *....*...*...*...*...*....*...*...*. *...*....*. |
| |
90000 ++-----------------------------------------------------------------+
vmstat.system.cs
170000 ++-----------------------------------------------------------------+
*...*...*....*...*...*...*...*....*...*...*...*...*...*....*...*...*
160000 ++ |
150000 ++ |
| |
140000 ++ |
| |
130000 ++ |
| |
120000 ++ |
110000 ++ |
| |
100000 ++ O O O |
O |
90000 ++-----------------------------------------------------------------+
[*] bisect-good sample
[O] bisect-bad sample
Thanks,
Xiaolong
5 years, 7 months
[lkp] [mm, page_alloc] 20bc70770f: INFO: possible recursive locking detected ]
by kernel test robot
FYI, we noticed the following commit:
git://bee.sh.intel.com/git/yhuang/linux.git percpug
commit 20bc70770f5e890a958a9ddc5a33aafe18cf9e10 ("mm, page_alloc: Use per CPU group page set")
in testcase: boot
on test machine: qemu-system-x86_64 -enable-kvm -smp 2 -m 512M
caused below changes:
+-----------------------------------------------------------------+------------+------------+
| | 4dfbb3e9a0 | 20bc70770f |
+-----------------------------------------------------------------+------------+------------+
| boot_successes | 1 | 2 |
| boot_failures | 91 | 60 |
| BUG:kernel_reboot-without-warning_in_test_stage | 27 | 37 |
| invoked_oom-killer:gfp_mask=0x | 7 | 2 |
| Mem-Info | 7 | 2 |
| BUG:spinlock_bad_magic_on_CPU | 1 | |
| BUG:KASAN:slab-out-of-bounds | 1 | |
| calltrace:fd_timer_workfn | 1 | |
| calltrace:SyS_mprotect | 1 | |
| Kernel_panic-not_syncing:Attempted_to_kill_init!exitcode= | 56 | |
| Out_of_memory:Kill_process | 5 | |
| INFO:possible_recursive_locking_detected | 0 | 20 |
| calltrace:kswapd | 0 | 6 |
| BUG:sleeping_function_called_from_invalid_context_at_fs/inode.c | 0 | 20 |
| INFO:lockdep_is_turned_off | 0 | 20 |
| calltrace:SyS_clone | 0 | 1 |
| BUG:kernel_hang_in_test_stage | 0 | 1 |
| calltrace:SyS_sendfile64 | 0 | 1 |
| calltrace:compat_SyS_pwritev2 | 0 | 1 |
| calltrace:compat_SyS_execve | 0 | 1 |
| calltrace:compat_SyS_open | 0 | 1 |
| calltrace:SyS_getdents | 0 | 1 |
| calltrace:SyS_newfstatat | 0 | 2 |
| calltrace:SyS_execve | 0 | 1 |
+-----------------------------------------------------------------+------------+------------+
[ 68.322800] /lkp/lkp/src/bin/run-lkp
[ 70.060553]
[ 70.060894] =============================================
[ 70.061805] [ INFO: possible recursive locking detected ]
[ 70.062729] 4.8.0-rc5-00007-g20bc707 #1 Not tainted
[ 70.063555] ---------------------------------------------
[ 70.064468] run-lkp/543 is trying to acquire lock:
[ 70.065278] (&(&p->lock)->rlock){..-.-.}, at: [<ffffffffb6c34f72>] get_page_from_freelist+0x7c6/0x104c
[ 70.067007]
[ 70.067007] but task is already holding lock:
[ 70.067992] (&(&p->lock)->rlock){..-.-.}, at: [<ffffffffb6c34f72>] get_page_from_freelist+0x7c6/0x104c
[ 70.069714]
[ 70.069714] other info that might help us debug this:
[ 70.070815] Possible unsafe locking scenario:
[ 70.070815]
[ 70.075349] CPU0
[ 70.079124] ----
[ 70.082844] lock(&(&p->lock)->rlock);
[ 70.086805] lock(&(&p->lock)->rlock);
[ 70.093742]
[ 70.093742] *** DEADLOCK ***
[ 70.093742]
[ 70.112892] May be due to missing lock nesting notation
[ 70.112892]
[ 70.128150] 4 locks held by run-lkp/543:
[ 70.134934] #0: (&sig->cred_guard_mutex){+.+.+.}, at: [<ffffffffb6cda1ba>] prepare_bprm_creds+0x43/0xbc
[ 70.143849] #1: (shrinker_rwsem){++++..}, at: [<ffffffffb6c49ca1>] shrink_slab+0x88/0x6b9
[ 70.153181] #2: (&type->s_umount_key#16){++++..}, at: [<ffffffffb6cd3a10>] trylock_super+0x1b/0x74
[ 70.162599] #3: (&(&p->lock)->rlock){..-.-.}, at: [<ffffffffb6c34f72>] get_page_from_freelist+0x7c6/0x104c
[ 70.172049]
[ 70.172049] stack backtrace:
[ 70.185464] CPU: 0 PID: 543 Comm: run-lkp Not tainted 4.8.0-rc5-00007-g20bc707 #1
[ 70.194844] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
[ 70.202648] ffff880009740818 ffff88000811f0c0 ffffffffb72ff639 ffff88000811f1c8
[ 70.211307] ffffffffb6b4e17d ffff880009740790 ffff880009740860 0000000409740860
[ 70.220988] ffff880009740840 0000000000000000 ffff880009740790 ffff880009740858
[ 70.229224] Call Trace:
[ 70.236764] [<ffffffffb72ff639>] dump_stack+0x19/0x1b
[ 70.244867] [<ffffffffb6b4e17d>] __lock_acquire+0x1c4a/0x1ce1
[ 70.252365] [<ffffffffb6b479fc>] ? match_held_lock+0x1c/0x260
[ 70.260976] [<ffffffffb6b4e96e>] lock_acquire+0xe2/0x216
[ 70.268801] [<ffffffffb6c34f72>] ? get_page_from_freelist+0x7c6/0x104c
[ 70.276351] [<ffffffffb80ad96d>] _raw_spin_lock+0x3b/0x4a
[ 70.284664] [<ffffffffb6c34f72>] ? get_page_from_freelist+0x7c6/0x104c
[ 70.292946] [<ffffffffb6c34f72>] get_page_from_freelist+0x7c6/0x104c
[ 70.300346] [<ffffffffb6c365ca>] __alloc_pages_nodemask+0x7ee/0x1536
[ 70.306669] [<ffffffffb6ca15b3>] ? save_stack+0xb2/0xc4
[ 70.315095] [<ffffffffb6c9b79e>] new_slab+0xb4/0x5ae
[ 70.322726] [<ffffffffb6c49ebd>] ? shrink_slab+0x2a4/0x6b9
[ 70.330139] [<ffffffffb6c9cc93>] ___slab_alloc+0x3c0/0x65e
[ 70.337070] [<ffffffffb7333cf9>] ? __debug_object_init+0x100/0x56d
[ 70.344850] [<ffffffffb6b49f8e>] ? mark_lock+0xc5/0x965
[ 70.349766] [<ffffffffb6b4ac48>] ? trace_hardirqs_off_caller+0xd1/0x121
[ 70.353554] [<ffffffffb7333cf9>] ? __debug_object_init+0x100/0x56d
[ 70.357321] [<ffffffffb6c9cf72>] __slab_alloc+0x41/0x7f
[ 70.363531] [<ffffffffb6c9d69d>] kmem_cache_alloc+0xaa/0x355
[ 70.370307] [<ffffffffb6be3407>] ? ftrace_likely_update+0xf6/0x25c
[ 70.378331] [<ffffffffb7333cf9>] ? __debug_object_init+0x100/0x56d
[ 70.385537] [<ffffffffb7333cf9>] __debug_object_init+0x100/0x56d
[ 70.391682] [<ffffffffb7334349>] debug_object_activate+0x1b0/0x1ff
[ 70.395735] [<ffffffffb6d87059>] ? proc_destroy_inode+0x1e/0x1e
[ 70.399804] [<ffffffffb6b729d2>] __call_rcu+0x87/0x5b4
[ 70.403588] [<ffffffffb6d5b079>] ? locks_free_lock_context+0x48/0x17f
[ 70.407397] [<ffffffffb6b72f16>] call_rcu+0x17/0x19
[ 70.411009] [<ffffffffb6d87057>] proc_destroy_inode+0x1c/0x1e
[ 70.414843] [<ffffffffb6cfd43a>] destroy_inode+0x82/0x9c
[ 70.418588] [<ffffffffb6cfe015>] evict+0x210/0x2ca
[ 70.422247] [<ffffffffb6cff56c>] iput+0x3ba/0x4a9
[ 70.425968] [<ffffffffb6cf36ae>] dentry_unlink_inode+0x1c5/0x1fc
[ 70.430648] [<ffffffffb6cf55c3>] __dentry_kill+0xe9/0x29e
[ 70.435818] [<ffffffffb6cf5a53>] shrink_dentry_list+0x2db/0x746
[ 70.442601] [<ffffffffb6cf3924>] ? d_lru_shrink_move+0xb4/0xb4
[ 70.449116] [<ffffffffb6cf6e38>] prune_dcache_sb+0x67/0x77
[ 70.456123] [<ffffffffb6cd3bf0>] super_cache_scan+0x187/0x22e
[ 70.463337] [<ffffffffb6c49ebd>] shrink_slab+0x2a4/0x6b9
[ 70.470260] [<ffffffffb6c4f1a7>] shrink_node+0x4f5/0x4fa
[ 70.474503] [<ffffffffb6c4f3a6>] do_try_to_free_pages+0x1fa/0x653
[ 70.478046] [<ffffffffb6c4f960>] try_to_free_pages+0x161/0x40c
[ 70.483739] [<ffffffffb6c367a5>] __alloc_pages_nodemask+0x9c9/0x1536
[ 70.489729] [<ffffffffb6c99b25>] ? init_object+0x6c/0x99
[ 70.492930] [<ffffffffb6b49f8e>] ? mark_lock+0xc5/0x965
[ 70.497300] [<ffffffffb6b51566>] ? __raw_spin_lock_init+0x21/0x78
[ 70.502646] [<ffffffffb6c3732a>] __get_free_pages+0x18/0x51
[ 70.508273] [<ffffffffb6a66ec3>] pgd_alloc+0x25/0x241
[ 70.513701] [<ffffffffb6ae8fec>] mm_init+0x2bd/0x34a
[ 70.517537] [<ffffffffb6ae9501>] mm_alloc+0x4d/0x54
[ 70.521414] [<ffffffffb6cdafbe>] do_execveat_common+0x50e/0xd6f
[ 70.527301] [<ffffffffb6cdacb0>] ? do_execveat_common+0x200/0xd6f
[ 70.532425] [<ffffffffb6cdbd00>] SyS_execve+0x3a/0x45
[ 70.535757] [<ffffffffb80ae7e0>] ? ptregs_sys_vfork+0x10/0x10
[ 70.540249] [<ffffffffb6a03704>] do_syscall_64+0x13d/0x6c5
[ 70.545041] [<ffffffffb80ae6bc>] entry_SYSCALL64_slow_path+0x25/0x25
[ 70.549194] BUG: sleeping function called from invalid context at fs/inode.c:498
[ 70.554278] in_atomic(): 1, irqs_disabled(): 0, pid: 543, name: run-lkp
[ 70.558933] INFO: lockdep is turned off.
[ 70.562331] Preemption disabled at:[<ffffffffb6c34f72>] get_page_from_freelist+0x7c6/0x104c
[ 70.566522]
[ 70.569955] CPU: 0 PID: 543 Comm: run-lkp Not tainted 4.8.0-rc5-00007-g20bc707 #1
[ 70.573881] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
[ 70.579650] 00000000000001f2 ffff88000811f690 ffffffffb72ff639 ffff88000811f6c8
[ 70.585781] ffffffffb6b31c1c 0000000000000000 ffffffffb8785058 00000000000001f2
[ 70.591350] 0000000000000000 ffffffffb823f400 ffff88000811f708 ffffffffb6b31d9e
[ 70.595748] Call Trace:
[ 70.599043] [<ffffffffb72ff639>] dump_stack+0x19/0x1b
[ 70.602896] [<ffffffffb6b31c1c>] ___might_sleep+0x1d8/0x2da
[ 70.607921] [<ffffffffb6b31d9e>] __might_sleep+0x80/0x114
[ 70.613824] [<ffffffffb6cfdc8f>] clear_inode+0x24/0x19a
[ 70.619084] [<ffffffffb6d86fdd>] proc_evict_inode+0x23/0x81
[ 70.623470] [<ffffffffb6cfdf67>] evict+0x162/0x2ca
[ 70.628918] [<ffffffffb6cff56c>] iput+0x3ba/0x4a9
[ 70.632925] [<ffffffffb6cf36ae>] dentry_unlink_inode+0x1c5/0x1fc
[ 70.638958] [<ffffffffb6cf55c3>] __dentry_kill+0xe9/0x29e
[ 70.644654] [<ffffffffb6cf5b7d>] shrink_dentry_list+0x405/0x746
[ 70.648513] [<ffffffffb6cf3924>] ? d_lru_shrink_move+0xb4/0xb4
[ 70.652532] [<ffffffffb6cf6e38>] prune_dcache_sb+0x67/0x77
[ 70.656731] [<ffffffffb6cd3bf0>] super_cache_scan+0x187/0x22e
[ 70.662475] [<ffffffffb6c49ebd>] shrink_slab+0x2a4/0x6b9
[ 70.668070] [<ffffffffb6c4f1a7>] shrink_node+0x4f5/0x4fa
[ 70.672808] [<ffffffffb6c4f3a6>] do_try_to_free_pages+0x1fa/0x653
[ 70.676670] [<ffffffffb6c4f960>] try_to_free_pages+0x161/0x40c
[ 70.680678] [<ffffffffb6c367a5>] __alloc_pages_nodemask+0x9c9/0x1536
[ 70.684524] [<ffffffffb6c99b25>] ? init_object+0x6c/0x99
[ 70.688286] [<ffffffffb6b49f8e>] ? mark_lock+0xc5/0x965
[ 70.692245] [<ffffffffb6b51566>] ? __raw_spin_lock_init+0x21/0x78
[ 70.696375] [<ffffffffb6c3732a>] __get_free_pages+0x18/0x51
[ 70.701702] [<ffffffffb6a66ec3>] pgd_alloc+0x25/0x241
[ 70.706939] [<ffffffffb6ae8fec>] mm_init+0x2bd/0x34a
[ 70.712790] [<ffffffffb6ae9501>] mm_alloc+0x4d/0x54
[ 70.720913] [<ffffffffb6cdafbe>] do_execveat_common+0x50e/0xd6f
[ 70.727826] [<ffffffffb6cdacb0>] ? do_execveat_common+0x200/0xd6f
[ 70.733837] [<ffffffffb6cdbd00>] SyS_execve+0x3a/0x45
[ 70.739330] [<ffffffffb80ae7e0>] ? ptregs_sys_vfork+0x10/0x10
[ 70.745090] [<ffffffffb6a03704>] do_syscall_64+0x13d/0x6c5
[ 70.750778] [<ffffffffb80ae6bc>] entry_SYSCALL64_slow_path+0x25/0x25
Elapsed time: 80
Thanks,
Xiaolong
5 years, 7 months
[lkp] [mm, page_alloc] 91727d2eac: WARNING: CPU: 0 PID: 65 at mm/memcontrol.c:998 mem_cgroup_update_lru_size+0xf0/0x106
by kernel test robot
FYI, we noticed the following commit:
https://git.kernel.org/pub/scm/linux/kernel/git/andrea/aa.git master
commit 91727d2eac2b5800bda8d12c3007548c9e1196c8 ("Revert "mm, page_alloc: remove fair zone allocation policy"")
in testcase: trinity
with following parameters:
runtime: 300s
Trinity is a linux system call fuzz tester.
on test machine: qemu-system-x86_64 -enable-kvm -cpu Westmere -m 512M
caused below changes:
+--------------------------------------------------------+------------+------------+
| | 88e7143071 | 91727d2eac |
+--------------------------------------------------------+------------+------------+
| boot_successes | 125 | 109 |
| boot_failures | 49 | 57 |
| invoked_oom-killer:gfp_mask=0x | 41 | 24 |
| Mem-Info | 41 | 24 |
| BUG:kernel_reboot-without-warning_in_test_stage | 8 | 10 |
| WARNING:at_mm/memcontrol.c:#mem_cgroup_update_lru_size | 0 | 23 |
| calltrace:SyS_clone | 0 | 7 |
| kernel_BUG_at_mm/memcontrol.c | 0 | 23 |
| invalid_opcode:#[##]PREEMPT | 0 | 23 |
| RIP:mem_cgroup_update_lru_size | 0 | 23 |
| Kernel_panic-not_syncing:Fatal_exception | 0 | 23 |
| calltrace:kswapd | 0 | 9 |
| calltrace:compat_SyS_pwritev2 | 0 | 1 |
| calltrace:SyS_fallocate | 0 | 3 |
| warn_alloc_failed+0x | 0 | 1 |
| calltrace:compat_SyS_ioctl | 0 | 1 |
| calltrace:compat_SyS_writev | 0 | 1 |
| calltrace:compat_SyS_pwritev | 0 | 1 |
+--------------------------------------------------------+------------+------------+
[ 53.663593] VFS: Warning: trinity-c3 using old stat() call. Recompile your binary.
[ 61.319090] warning: process `trinity-c3' used the deprecated sysctl system call with
[ 62.618335] ------------[ cut here ]------------
[ 62.619085] WARNING: CPU: 0 PID: 65 at mm/memcontrol.c:998 mem_cgroup_update_lru_size+0xf0/0x106
[ 62.620689] mem_cgroup_update_lru_size(ffff88001e813800, 3, -1): lru_size 6 but empty
[ 62.621912] CPU: 0 PID: 65 Comm: kswapd0 Not tainted 4.8.0-rc5-00086-g91727d2 #1
[ 62.623074] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
[ 62.624429] 0000000000000000 ffff88001b6afa18 ffffffff814b6895 ffff88001b6afa58
[ 62.625641] ffffffff810bb069 000003e600000000 0000000000000000 ffff88001e813830
[ 62.626850] 0000000000000007 0000000000000007 ffff88001e813800 ffff88001b6afab8
[ 62.628058] Call Trace:
[ 62.628457] [<ffffffff814b6895>] dump_stack+0x19/0x1b
[ 62.629281] [<ffffffff810bb069>] __warn+0xb9/0xd4
[ 62.630047] [<ffffffff810bb0ce>] warn_slowpath_fmt+0x4a/0x4c
[ 62.630961] [<ffffffff8118d61d>] mem_cgroup_update_lru_size+0xf0/0x106
[ 62.631994] [<ffffffff81145c0a>] isolate_lru_pages+0x20e/0x229
[ 62.632988] [<ffffffff81147384>] shrink_active_list+0xc3/0x325
[ 62.633880] [<ffffffff81147a36>] shrink_node_memcg+0x450/0x5d8
[ 62.634772] [<ffffffff810e5300>] ? match_held_lock+0x121/0x16e
[ 62.635667] [<ffffffff81147c81>] shrink_node+0xc3/0x281
[ 62.636517] [<ffffffff811486bd>] kswapd+0x468/0x5a6
[ 62.637305] [<ffffffff81148255>] ? mem_cgroup_shrink_node+0x86/0x86
[ 62.638309] [<ffffffff810d3f8e>] kthread+0xf2/0xfa
[ 62.639092] [<ffffffff81db146f>] ret_from_fork+0x1f/0x40
[ 62.639941] [<ffffffff810d3e9c>] ? __kthread_parkme+0x7a/0x7a
[ 62.640839] ---[ end trace 8b431ea8d68b698f ]---
[ 62.641558] ------------[ cut here ]------------
To reproduce:
git clone git://git.kernel.org/pub/scm/linux/kernel/git/wfg/lkp-tests.git
cd lkp-tests
bin/lkp install job.yaml # job file is attached in this email
bin/lkp run job.yaml
Thanks,
Xiaolong
5 years, 7 months
[e1000] 4a4636bbe8: WARNING: CPU: 0 PID: 0 at net/sched/sch_generic.c:316 dev_watchdog+0x182/0x1dd
by kernel test robot
FYI, we noticed the following commit:
https://git.kernel.org/pub/scm/linux/kernel/git/jkirsher/next-queue.git dev-queue
commit 4a4636bbe856b8acb0c0fd681a7684aad8500b5e ("e1000: track BQL bytes regardless of skb or not")
in testcase: boot
on test machine: qemu-system-x86_64 -enable-kvm -cpu Nehalem -smp 2 -m 1G
caused below changes:
+------------------------------------------------------------------+------------+------------+
| | a40bf86e91 | 4a4636bbe8 |
+------------------------------------------------------------------+------------+------------+
| boot_successes | 2 | 2 |
| boot_failures | 2 | 6 |
| BUG:kernel_reboot-without-warning_in_test_stage | 2 | |
| invoked_oom-killer:gfp_mask=0x | 0 | 2 |
| Mem-Info | 0 | 2 |
| Kernel_panic-not_syncing:Out_of_memory_and_no_killable_processes | 0 | 2 |
| WARNING:at_net/sched/sch_generic.c:#dev_watchdog | 0 | 4 |
+------------------------------------------------------------------+------------+------------+
[ 14.626516]
[ 14.629010] Dload Upload Total Spent Left Speed
[ 21.411164] ------------[ cut here ]------------
[ 21.412780] WARNING: CPU: 0 PID: 0 at net/sched/sch_generic.c:316 dev_watchdog+0x182/0x1dd
[ 21.415906] NETDEV WATCHDOG: eth0 (e1000): transmit queue 0 timed out
[ 21.417740] Modules linked in: acpi_cpufreq
[ 21.419411] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.8.0-rc6-01395-g4a4636b #1
[ 21.422067] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
[ 21.424943] 0000000000000000 ffff88003d403d48 ffffffff814fbd53 ffff88003d403d98
[ 21.427375] 0000000000000000 ffff88003d403d88 ffffffff811045b2 0000013c3d403e00
[ 21.429251] ffff880024916000 ffff88002f209600 0000000000000001 0000000000000000
[ 21.431124] Call Trace:
[ 21.431830] <IRQ> [<ffffffff814fbd53>] dump_stack+0x86/0xc0
[ 21.432967] [<ffffffff811045b2>] __warn+0xc2/0xdd
[ 21.433932] [<ffffffff81104618>] warn_slowpath_fmt+0x4b/0x53
[ 21.434996] [<ffffffff8199483f>] dev_watchdog+0x182/0x1dd
[ 21.436033] [<ffffffff819946bd>] ? qdisc_rcu_free+0x3e/0x3e
[ 21.437089] [<ffffffff8115c088>] call_timer_fn+0x6b/0x122
[ 21.438126] [<ffffffff8115c230>] expire_timers+0xf1/0x125
[ 21.439160] [<ffffffff819946bd>] ? qdisc_rcu_free+0x3e/0x3e
[ 21.440222] [<ffffffff8115c2d2>] run_timer_softirq+0x6e/0x11b
[ 21.441301] [<ffffffff8107aa45>] ? lapic_next_event+0x1d/0x21
[ 21.442378] [<ffffffff81167d11>] ? clockevents_program_event+0xd7/0xef
[ 21.443543] [<ffffffff81aba2ad>] __do_softirq+0x13d/0x2c8
[ 21.444584] [<ffffffff811092dc>] irq_exit+0x47/0x9b
[ 21.445568] [<ffffffff81aba07a>] smp_apic_timer_interrupt+0x42/0x4d
[ 21.446701] [<ffffffff81ab938c>] apic_timer_interrupt+0x8c/0xa0
[ 21.447799] <EOI> [<ffffffff8108631c>] ? native_safe_halt+0x6/0x8
[ 21.448986] [<ffffffff81065c72>] default_idle+0x5b/0xdd
[ 21.450007] [<ffffffff810662da>] arch_cpu_idle+0xf/0x11
[ 21.451023] [<ffffffff8113b7a2>] default_idle_call+0x3d/0x44
[ 21.452088] [<ffffffff8113b986>] cpu_startup_entry+0x1dd/0x2ea
[ 21.453172] [<ffffffff81aacade>] rest_init+0x85/0x87
[ 21.454163] [<ffffffff823d0efa>] start_kernel+0x3f7/0x404
[ 21.455200] [<ffffffff823d0120>] ? early_idt_handler_array+0x120/0x120
[ 21.456360] [<ffffffff823d0299>] x86_64_start_reservations+0x2a/0x2c
[ 21.457506] [<ffffffff823d03d9>] x86_64_start_kernel+0x13e/0x14d
[ 21.458612] ---[ end trace 3228b8a8c22efeee ]---
[ 21.460056] e1000 0000:00:03.0 eth0: Reset adapter
Thanks,
Kernel Test Robot
5 years, 7 months