INFO: rcu detected stall in readlink

3 views
Skip to first unread message

syzbot

unread,
Apr 14, 2019, 5:28:21 AM4/14/19
to syzkaller-a...@googlegroups.com
Hello,

syzbot found the following crash on:

HEAD commit: 8fe42840 Merge 4.9.141 into android-4.9
git tree: android-4.9
console output: https://syzkaller.appspot.com/x/log.txt?x=13ab7e17400000
kernel config: https://syzkaller.appspot.com/x/.config?x=22a5ba9f73b6da1d
dashboard link: https://syzkaller.appspot.com/bug?extid=3ca0d8618e8d5a422613
compiler: gcc (GCC) 8.0.1 20180413 (experimental)
userspace arch: i386
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=13512df7400000

IMPORTANT: if you fix the bug, please add the following tag to the commit:
Reported-by: syzbot+3ca0d8...@syzkaller.appspotmail.com

Free memory is -10008kB above reserved
lowmemorykiller: Killing 'syz-executor3' (12360) (tgid 12359), adj 1000,
to free 8888kB on behalf of 'init' (1) because
cache 2680kB is below limit 6144kB for oom_score_adj 0
Free memory is -9908kB above reserved
INFO: rcu_preempt detected stalls on CPUs/tasks:
Tasks blocked on level-0 rcu_node (CPUs 0-1): P470
(detected by 0, t=10504 jiffies, g=3089, c=3088, q=86042)
udevd R running task 25064 470 1 0x00000008
ffff8801db607c60 ffffffff813fa6fd ffffffff813fa504 ffff8801d3bb4740
ffffffff830cd6c0 0000000000000096 ffff8801d3bb4b20 dffffc0000000000
ffff8801db607c98 ffffffff81404e39 0000000000000c10 000000000001501a
Call Trace:
<IRQ>
[<ffffffff813fa6fd>] sched_show_task.cold.35+0x279/0x31f
kernel/sched/core.c:5317
[<ffffffff81404e39>] rcu_print_detail_task_stall_rnp+0xc2/0xfe
kernel/rcu/tree_plugin.h:530
[<ffffffff81405f5f>] rcu_print_detail_task_stall
kernel/rcu/tree_plugin.h:543 [inline]
[<ffffffff81405f5f>] print_other_cpu_stall kernel/rcu/tree.c:1408 [inline]
[<ffffffff81405f5f>] check_cpu_stall kernel/rcu/tree.c:1520 [inline]
[<ffffffff81405f5f>] __rcu_pending kernel/rcu/tree.c:3487 [inline]
[<ffffffff81405f5f>] rcu_pending kernel/rcu/tree.c:3551 [inline]
[<ffffffff81405f5f>] rcu_check_callbacks.cold.69+0x757/0xd27
kernel/rcu/tree.c:2880
[<ffffffff81267470>] update_process_times+0x30/0x70
kernel/time/timer.c:1629
[<ffffffff8129641a>] tick_sched_handle.isra.5+0x4a/0xf0
kernel/time/tick-sched.c:151
[<ffffffff81296536>] tick_sched_timer+0x76/0x130
kernel/time/tick-sched.c:1190
[<ffffffff8126a197>] __run_hrtimer kernel/time/hrtimer.c:1255 [inline]
[<ffffffff8126a197>] __hrtimer_run_queues+0x357/0xe30
kernel/time/hrtimer.c:1319
[<ffffffff8126c681>] hrtimer_interrupt+0x1b1/0x430
kernel/time/hrtimer.c:1353
[<ffffffff810912d4>] local_apic_timer_interrupt+0x74/0xa0
arch/x86/kernel/apic/apic.c:937
[<ffffffff8281b76c>] smp_apic_timer_interrupt+0x7c/0xb0
arch/x86/kernel/apic/apic.c:961
[<ffffffff8281902d>] apic_timer_interrupt+0x9d/0xb0
arch/x86/entry/entry_64.S:648
<EOI>
[<ffffffff812270c8>] vprintk_emit+0x448/0x790 kernel/printk/printk.c:1908
[<ffffffff81227438>] vprintk+0x28/0x30 kernel/printk/printk.c:1918
[<ffffffff8122745d>] vprintk_default+0x1d/0x30 kernel/printk/printk.c:1919
[<ffffffff81402f9f>] vprintk_func kernel/printk/internal.h:36 [inline]
[<ffffffff81402f9f>] printk+0xaf/0xd7 kernel/printk/printk.c:1980
[<ffffffff8222d9e8>] lowmem_scan.cold.1+0x1f9/0x35b
drivers/staging/android/lowmemorykiller.c:177
[<ffffffff81449cc6>] do_shrink_slab mm/vmscan.c:398 [inline]
[<ffffffff81449cc6>] shrink_slab.part.8+0x3c6/0xa00 mm/vmscan.c:501
[<ffffffff814557fd>] shrink_slab mm/vmscan.c:465 [inline]
[<ffffffff814557fd>] shrink_node+0x1ed/0x740 mm/vmscan.c:2602
[<ffffffff814560c7>] shrink_zones mm/vmscan.c:2749 [inline]
[<ffffffff814560c7>] do_try_to_free_pages mm/vmscan.c:2791 [inline]
[<ffffffff814560c7>] try_to_free_pages+0x377/0xb80 mm/vmscan.c:3002
[<ffffffff81428a01>] __perform_reclaim mm/page_alloc.c:3324 [inline]
[<ffffffff81428a01>] __alloc_pages_direct_reclaim mm/page_alloc.c:3345
[inline]
[<ffffffff81428a01>] __alloc_pages_slowpath mm/page_alloc.c:3697 [inline]
[<ffffffff81428a01>] __alloc_pages_nodemask+0x981/0x1bd0
mm/page_alloc.c:3862
[<ffffffff814eb7e7>] __alloc_pages include/linux/gfp.h:433 [inline]
[<ffffffff814eb7e7>] __alloc_pages_node include/linux/gfp.h:446 [inline]
[<ffffffff814eb7e7>] alloc_slab_page mm/slub.c:1408 [inline]
[<ffffffff814eb7e7>] allocate_slab mm/slub.c:1557 [inline]
[<ffffffff814eb7e7>] new_slab+0x367/0x3d0 mm/slub.c:1635
[<ffffffff814ed97d>] new_slab_objects mm/slub.c:2419 [inline]
[<ffffffff814ed97d>] ___slab_alloc.constprop.33+0x2ed/0x470 mm/slub.c:2576
[<ffffffff814edb50>] __slab_alloc.isra.25.constprop.32+0x50/0xa0
mm/slub.c:2618
[<ffffffff814eddb2>] slab_alloc_node mm/slub.c:2681 [inline]
[<ffffffff814eddb2>] slab_alloc mm/slub.c:2723 [inline]
[<ffffffff814eddb2>] kmem_cache_alloc+0x212/0x2b0 mm/slub.c:2728
[<ffffffff8153eca8>] getname_flags+0xc8/0x550 fs/namei.c:137
[<ffffffff8153fa2f>] user_path_at_empty+0x2f/0x70 fs/namei.c:2578
[<ffffffff8151a5e1>] SYSC_readlinkat fs/stat.c:327 [inline]
[<ffffffff8151a5e1>] SyS_readlinkat+0xf1/0x350 fs/stat.c:315
[<ffffffff8151a86a>] SYSC_readlink fs/stat.c:352 [inline]
[<ffffffff8151a86a>] SyS_readlink+0x2a/0x40 fs/stat.c:349
[<ffffffff810056ef>] do_syscall_64+0x19f/0x550 arch/x86/entry/common.c:285
[<ffffffff82817893>] entry_SYSCALL_64_after_swapgs+0x5d/0xdb
udevd R running task 25064 470 1 0x80000008
ffff8801db607c60 ffffffff813fa6fd ffffffff813fa504 ffff8801d3bb4740
ffffffff830cd6c0 0000000000000096 ffff8801d3bb4b20 dffffc0000000000
ffff8801db607c98 ffffffff81404e39 ffffffff830cda40 000000000001501a
Call Trace:
<IRQ>
[<ffffffff813fa6fd>] sched_show_task.cold.35+0x279/0x31f
kernel/sched/core.c:5317
[<ffffffff81404e39>] rcu_print_detail_task_stall_rnp+0xc2/0xfe
kernel/rcu/tree_plugin.h:530
[<ffffffff81405fb7>] rcu_print_detail_task_stall
kernel/rcu/tree_plugin.h:545 [inline]
[<ffffffff81405fb7>] print_other_cpu_stall kernel/rcu/tree.c:1408 [inline]
[<ffffffff81405fb7>] check_cpu_stall kernel/rcu/tree.c:1520 [inline]
[<ffffffff81405fb7>] __rcu_pending kernel/rcu/tree.c:3487 [inline]
[<ffffffff81405fb7>] rcu_pending kernel/rcu/tree.c:3551 [inline]
[<ffffffff81405fb7>] rcu_check_callbacks.cold.69+0x7af/0xd27
kernel/rcu/tree.c:2880
[<ffffffff81267470>] update_process_times+0x30/0x70
kernel/time/timer.c:1629
[<ffffffff8129641a>] tick_sched_handle.isra.5+0x4a/0xf0
kernel/time/tick-sched.c:151
[<ffffffff81296536>] tick_sched_timer+0x76/0x130
kernel/time/tick-sched.c:1190
[<ffffffff8126a197>] __run_hrtimer kernel/time/hrtimer.c:1255 [inline]
[<ffffffff8126a197>] __hrtimer_run_queues+0x357/0xe30
kernel/time/hrtimer.c:1319
[<ffffffff8126c681>] hrtimer_interrupt+0x1b1/0x430
kernel/time/hrtimer.c:1353
[<ffffffff810912d4>] local_apic_timer_interrupt+0x74/0xa0
arch/x86/kernel/apic/apic.c:937
[<ffffffff8281b76c>] smp_apic_timer_interrupt+0x7c/0xb0
arch/x86/kernel/apic/apic.c:961
[<ffffffff8281902d>] apic_timer_interrupt+0x9d/0xb0
arch/x86/entry/entry_64.S:648
<EOI>
[<ffffffff812270c8>] vprintk_emit+0x448/0x790 kernel/printk/printk.c:1908
[<ffffffff81227438>] vprintk+0x28/0x30 kernel/printk/printk.c:1918
[<ffffffff8122745d>] vprintk_default+0x1d/0x30 kernel/printk/printk.c:1919
[<ffffffff81402f9f>] vprintk_func kernel/printk/internal.h:36 [inline]
[<ffffffff81402f9f>] printk+0xaf/0xd7 kernel/printk/printk.c:1980
[<ffffffff8222d9e8>] lowmem_scan.cold.1+0x1f9/0x35b
drivers/staging/android/lowmemorykiller.c:177
[<ffffffff81449cc6>] do_shrink_slab mm/vmscan.c:398 [inline]
[<ffffffff81449cc6>] shrink_slab.part.8+0x3c6/0xa00 mm/vmscan.c:501
[<ffffffff814557fd>] shrink_slab mm/vmscan.c:465 [inline]
[<ffffffff814557fd>] shrink_node+0x1ed/0x740 mm/vmscan.c:2602
[<ffffffff814560c7>] shrink_zones mm/vmscan.c:2749 [inline]
[<ffffffff814560c7>] do_try_to_free_pages mm/vmscan.c:2791 [inline]
[<ffffffff814560c7>] try_to_free_pages+0x377/0xb80 mm/vmscan.c:3002
[<ffffffff81428a01>] __perform_reclaim mm/page_alloc.c:3324 [inline]
[<ffffffff81428a01>] __alloc_pages_direct_reclaim mm/page_alloc.c:3345
[inline]
[<ffffffff81428a01>] __alloc_pages_slowpath mm/page_alloc.c:3697 [inline]
[<ffffffff81428a01>] __alloc_pages_nodemask+0x981/0x1bd0
mm/page_alloc.c:3862
[<ffffffff814eb7e7>] __alloc_pages include/linux/gfp.h:433 [inline]
[<ffffffff814eb7e7>] __alloc_pages_node include/linux/gfp.h:446 [inline]
[<ffffffff814eb7e7>] alloc_slab_page mm/slub.c:1408 [inline]
[<ffffffff814eb7e7>] allocate_slab mm/slub.c:1557 [inline]
[<ffffffff814eb7e7>] new_slab+0x367/0x3d0 mm/slub.c:1635
[<ffffffff814ed97d>] new_slab_objects mm/slub.c:2419 [inline]
[<ffffffff814ed97d>] ___slab_alloc.constprop.33+0x2ed/0x470 mm/slub.c:2576
[<ffffffff814edb50>] __slab_alloc.isra.25.constprop.32+0x50/0xa0
mm/slub.c:2618
[<ffffffff814eddb2>] slab_alloc_node mm/slub.c:2681 [inline]
[<ffffffff814eddb2>] slab_alloc mm/slub.c:2723 [inline]
[<ffffffff814eddb2>] kmem_cache_alloc+0x212/0x2b0 mm/slub.c:2728
[<ffffffff8153eca8>] getname_flags+0xc8/0x550 fs/namei.c:137
[<ffffffff8153fa2f>] user_path_at_empty+0x2f/0x70 fs/namei.c:2578
[<ffffffff8151a5e1>] SYSC_readlinkat fs/stat.c:327 [inline]
[<ffffffff8151a5e1>] SyS_readlinkat+0xf1/0x350 fs/stat.c:315
[<ffffffff8151a86a>] SYSC_readlink fs/stat.c:352 [inline]
[<ffffffff8151a86a>] SyS_readlink+0x2a/0x40 fs/stat.c:349
[<ffffffff810056ef>] do_syscall_64+0x19f/0x550 arch/x86/entry/common.c:285
[<ffffffff82817893>] entry_SYSCALL_64_after_swapgs+0x5d/0xdb
lowmemorykiller: Killing 'syz-executor3' (12360) (tgid 12359), adj 1000,
to free 8888kB on behalf of 'syz-executor5' (12357) because
cache 2592kB is below limit 6144kB for oom_score_adj 0
Free memory is -13376kB above reserved
lowmemorykiller: Killing 'syz-executor3' (12360) (tgid 12359), adj 1000,
to free 8888kB on behalf of 'syz-executor4' (12368) because
cache 2592kB is below limit 6144kB for oom_score_adj 0
Free memory is -13376kB above reserved
lowmemorykiller: Killing 'syz-executor3' (12360) (tgid 12359), adj 1000,
to free 8888kB on behalf of 'syz-executor0' (12363) because
cache 2236kB is below limit 6144kB for oom_score_adj 0
Free memory is -13156kB above reserved
lowmemorykiller: Killing 'syz-executor3' (12360) (tgid 12359), adj 1000,
to free 8888kB on behalf of 'kswapd0' (33) because
cache 2220kB is below limit 6144kB for oom_score_adj 0
Free memory is -13136kB above reserved
lowmemorykiller: Killing 'syz-executor3' (12360) (tgid 12359), adj 1000,
to free 8828kB on behalf of 'syz-executor0' (2113) because
cache 2580kB is below limit 6144kB for oom_score_adj 0
Free memory is -9436kB above reserved
lowmemorykiller: Killing 'syz-executor3' (12360) (tgid 12359), adj 1000,
to free 8828kB on behalf of 'kswapd0' (33) because
cache 2728kB is below limit 6144kB for oom_score_adj 0
Free memory is -9756kB above reserved
lowmemorykiller: Killing 'syz-executor3' (12360) (tgid 12359), adj 1000,
to free 8808kB on behalf of 'syz-executor2' (12369) because
cache 4076kB is below limit 6144kB for oom_score_adj 0
Free memory is -13448kB above reserved
lowmemorykiller: Killing 'syz-executor5' (12357) (tgid 12354), adj 1000,
to free 6436kB on behalf of 'syz-executor2' (12370) because
cache 3776kB is below limit 6144kB for oom_score_adj 0
Free memory is -13448kB above reserved
lowmemorykiller: Killing 'syz-executor4' (12375) (tgid 12375), adj 1000,
to free 4832kB on behalf of 'syz-executor2' (12369) because
cache 3868kB is below limit 6144kB for oom_score_adj 0
Free memory is -7868kB above reserved
lowmemorykiller: Killing 'syz-executor1' (12371) (tgid 12371), adj 1000,
to free 4564kB on behalf of 'kswapd0' (33) because
cache 3868kB is below limit 6144kB for oom_score_adj 0
Free memory is -9868kB above reserved
lowmemorykiller: Killing 'syz-executor1' (12371) (tgid 12371), adj 1000,
to free 5176kB on behalf of 'syz-executor4' (2121) because
cache 4112kB is below limit 6144kB for oom_score_adj 0
Free memory is -13304kB above reserved
lowmemorykiller: Killing 'syz-executor1' (12371) (tgid 12371), adj 1000,
to free 5176kB on behalf of 'syz-executor4' (2121) because
cache 3048kB is below limit 6144kB for oom_score_adj 0
Free memory is -13232kB above reserved
lowmemorykiller: Killing 'syz-executor1' (12372) (tgid 12371), adj 1000,
to free 5176kB on behalf of 'syz-executor2' (12386) because
cache 2748kB is below limit 6144kB for oom_score_adj 0
Free memory is -13232kB above reserved
lowmemorykiller: Killing 'syz-executor0' (12281) (tgid 12281), adj 1000,
to free 3928kB on behalf of 'syz-executor2' (12386) because
cache 2748kB is below limit 6144kB for oom_score_adj 0
Free memory is -13232kB above reserved
lowmemorykiller: Killing 'syz-executor2' (12286) (tgid 12286), adj 1000,
to free 3996kB on behalf of 'syz-executor5' (12389) because
cache 2748kB is below limit 6144kB for oom_score_adj 0
Free memory is -13232kB above reserved
lowmemorykiller: Killing 'syz-executor4' (12316) (tgid 12316), adj 1000,
to free 3928kB on behalf of 'kswapd0' (33) because
cache 2748kB is below limit 6144kB for oom_score_adj 0
Free memory is -13232kB above reserved
lowmemorykiller: Killing 'syz-executor1' (12289) (tgid 12289), adj 1000,
to free 3924kB on behalf of 'syz-executor5' (12389) because
cache 2548kB is below limit 6144kB for oom_score_adj 0
Free memory is 660kB above reserved
lowmemorykiller: Killing 'syz-executor1' (12309) (tgid 12309), adj 1000,
to free 3924kB on behalf of 'kswapd0' (33) because
cache 2648kB is below limit 8192kB for oom_score_adj 1
Free memory is 8160kB above reserved
lowmemorykiller: Killing 'syz-executor3' (12310) (tgid 12310), adj 1000,
to free 3924kB on behalf of 'syz-executor2' (12386) because
cache 2548kB is below limit 6144kB for oom_score_adj 0
Free memory is -1140kB above reserved
lowmemorykiller: Killing 'syz-executor1' (12324) (tgid 12324), adj 1000,
to free 3924kB on behalf of 'syz-executor2' (12386) because
cache 2548kB is below limit 65536kB for oom_score_adj 12
Free memory is 18140kB above reserved
lowmemorykiller: Killing 'syz-executor3' (12325) (tgid 12325), adj 1000,
to free 3924kB on behalf of 'syz-executor4' (2121) because
cache 2748kB is below limit 6144kB for oom_score_adj 0
Free memory is -13232kB above reserved
lowmemorykiller: Killing 'syz-executor4' (12292) (tgid 12292), adj 1000,
to free 3928kB on behalf of 'syz-executor3' (12379) because
cache 2748kB is below limit 6144kB for oom_score_adj 0
Free memory is -13232kB above reserved
lowmemorykiller: Killing 'syz-executor0' (2652) (tgid 2652), adj 1000,
to free 3444kB on behalf of 'syz-executor3' (12379) because
cache 2648kB is below limit 65536kB for oom_score_adj 12
Free memory is 34736kB above reserved
lowmemorykiller: Killing 'syz-executor1' (2664) (tgid 2664), adj 1000,
to free 3444kB on behalf of 'syz-executor3' (12379) because
cache 2748kB is below limit 65536kB for oom_score_adj 12
Free memory is 35336kB above reserved
lowmemorykiller: Killing 'syz-executor0' (2652) (tgid 2652), adj 1000,
to free 3444kB on behalf of 'kswapd0' (33) because
cache 2648kB is below limit 8192kB for oom_score_adj 1
Free memory is 8160kB above reserved
lowmemorykiller: Killing 'syz-executor0' (2652) (tgid 2652), adj 1000,
to free 3444kB on behalf of 'kworker/u4:5' (2141) because
cache 2748kB is below limit 6144kB for oom_score_adj 0
Free memory is -13232kB above reserved
lowmemorykiller: Killing 'syz-executor3' (2695) (tgid 2695), adj 1000,
to free 3444kB on behalf of 'kworker/u4:5' (2141) because
cache 2748kB is below limit 65536kB for oom_score_adj 12
Free memory is 59428kB above reserved
lowmemorykiller: Killing 'syz-executor3' (2695) (tgid 2695), adj 1000,
to free 3444kB on behalf of 'kswapd0' (33) because
cache 2748kB is below limit 65536kB for oom_score_adj 12
Free memory is 59428kB above reserved
lowmemorykiller: Killing 'syz-executor1' (12271) (tgid 12271), adj 1000,
to free 3920kB on behalf of 'syz-executor4' (2121) because
cache 2548kB is below limit 65536kB for oom_score_adj 12
Free memory is 21036kB above reserved
lowmemorykiller: Killing 'syz-executor2' (12286) (tgid 12286), adj 1000,
to free 3996kB on behalf of 'syz-executor0' (12382) because
cache 2748kB is below limit 6144kB for oom_score_adj 0
Free memory is -13232kB above reserved
lowmemorykiller: Killing 'syz-executor0' (2652) (tgid 2652), adj 1000,
to free 3444kB on behalf of 'syz-executor2' (12386) because
cache 2548kB is below limit 65536kB for oom_score_adj 12
Free memory is 18936kB above reserved
lowmemorykiller: Killing 'syz-executor1' (12309) (tgid 12309), adj 1000,
to free 3924kB on behalf of 'syz-executor5' (12389) because
cache 2648kB is below limit 8192kB for oom_score_adj 1
Free memory is 8160kB above reserved
lowmemorykiller: Killing 'syz-executor1' (2696) (tgid 2696), adj 1000,
to free 3444kB on behalf of 'kworker/u4:5' (2141) because
cache 2748kB is below limit 65536kB for oom_score_adj 12
Free memory is 59428kB above reserved
lowmemorykiller: Killing 'syz-executor0' (2673) (tgid 2673), adj 1000,
to free 3444kB on behalf of 'syz-executor3' (12379) because
cache 2648kB is below limit 65536kB for oom_score_adj 12
Free memory is 49628kB above reserved
lowmemorykiller: Killing 'syz-executor1' (12464) (tgid 12464), adj 1000,
to free 11432kB on behalf of 'kswapd0' (33) because
cache 5088kB is below limit 6144kB for oom_score_adj 0
Free memory is -5336kB above reserved


---
This bug is generated by a bot. It may contain errors.
See https://goo.gl/tpsmEJ for more information about syzbot.
syzbot engineers can be reached at syzk...@googlegroups.com.

syzbot will keep track of this bug report. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.
syzbot can test patches for this bug, for details see:
https://goo.gl/tpsmEJ#testing-patches
Reply all
Reply to author
Forward
0 new messages