Message-ID: <20171104134021.qwlkall6ck7urt76@codemonkey.org.uk>
Date:   Sat, 4 Nov 2017 09:40:21 -0400
From:   Dave Jones <davej@...emonkey.org.uk>
To:     netdev@...r.kernel.org
Subject: ipset related DEBUG_VIRTUAL crash.

I have a script that hourly replaces an ipset list. This has been in
place for a year or so, but last night it triggered this on 4.14-rc7

[455951.731181] kernel BUG at arch/x86/mm/physaddr.c:26!
[455951.737016] invalid opcode: 0000 [#1] PREEMPT SMP DEBUG_PAGEALLOC KASAN
[455951.742525] CPU: 0 PID: 3850 Comm: ipset Not tainted 4.14.0-rc7-firewall+ #1 
[455951.753293] task: ffff88013033cfc0 task.stack: ffff8801c3d48000
[455951.758567] RIP: 0010:__phys_addr+0x5b/0x80
[455951.763742] RSP: 0018:ffff8801c3d4f528 EFLAGS: 00010287
[455951.768838] RAX: 00007800849b62b6 RBX: 00000000849b62b6 RCX: ffffffff9f072a5d
[455951.773881] RDX: dffffc0000000000 RSI: dffffc0000000000 RDI: ffffffffa06917e0
[455951.778844] RBP: 00007800049b62b6 R08: 0000000000000002 R09: 0000000000000000
[455951.783729] R10: 0000000000000000 R11: 0000000000000000 R12: ffffffff9fca8b05
[455951.788524] R13: ffff8801ce844268 R14: 00000000049b62b6 R15: ffff8801ce8442ea
[455951.793239] FS:  00007fb44e656c80(0000) GS:ffff8801d3200000(0000) knlGS:0000000000000000
[455951.797904] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[455951.802479] CR2: 00007ffeeafd70a8 CR3: 00000001b6cd2001 CR4: 00000000000606f0
[455951.806998] Call Trace:
[455951.811404]  kfree+0x4c/0x310
[455951.815714]  hash_ip4_ahash_destroy+0x85/0xd0
[455951.819944]  hash_ip4_destroy+0x64/0x90
[455951.824069]  ip_set_destroy+0x4f0/0x500
[455951.828098]  ? ip_set_destroy+0x5/0x500
[455951.832029]  ? __rcu_read_unlock+0xd3/0x190
[455951.835867]  ? ip_set_utest+0x560/0x560
[455951.839610]  ? ip_set_utest+0x560/0x560
[455951.843239]  nfnetlink_rcv_msg+0x73e/0x770
[455951.846780]  ? nfnetlink_rcv_msg+0x352/0x770
[455951.850229]  ? nfnetlink_rcv+0xe90/0xe90
[455951.853571]  ? native_sched_clock+0xe8/0x190
[455951.856822]  ? lock_release+0x5d3/0x7d0
[455951.859976]  netlink_rcv_skb+0x121/0x230
[455951.863037]  ? nfnetlink_rcv+0xe90/0xe90
[455951.865999]  ? netlink_ack+0x4c0/0x4c0
[455951.868866]  ? ns_capable_common+0x68/0xc0
[455951.871638]  nfnetlink_rcv+0x1ad/0xe90
[455951.874312]  ? lock_acquire+0x380/0x380
[455951.876891]  ? __rcu_read_unlock+0xd3/0x190
[455951.879378]  ? __rcu_read_lock+0x30/0x30
[455951.881764]  ? rcu_is_watching+0xa4/0xf0
[455951.884048]  ? netlink_connect+0x1e0/0x1e0
[455951.886236]  ? nfnl_err_reset+0x180/0x180
[455951.888329]  ? netlink_deliver_tap+0x128/0x560
[455951.890333]  ? netlink_deliver_tap+0x5/0x560
[455951.892229]  ? iov_iter_advance+0x172/0x7f0
[455951.894029]  ? netlink_getname+0x150/0x150
[455951.895736]  ? can_nice.part.77+0x20/0x20
[455951.897342]  ? iov_iter_copy_from_user_atomic+0x7d0/0x7d0
[455951.898877]  ? netlink_trim+0x111/0x1b0
[455951.900394]  ? netlink_skb_destructor+0xf0/0xf0
[455951.901908]  netlink_unicast+0x2b1/0x340
[455951.903397]  ? netlink_detachskb+0x30/0x30
[455951.904862]  ? lock_acquire+0x380/0x380
[455951.906299]  ? lockdep_rcu_suspicious+0x100/0x100
[455951.907729]  netlink_sendmsg+0x4f2/0x650
[455951.909141]  ? netlink_broadcast_filtered+0x9e0/0x9e0
[455951.910565]  ? _copy_from_user+0x86/0xc0
[455951.911964]  ? netlink_broadcast_filtered+0x9e0/0x9e0
[455951.913364]  SYSC_sendto+0x2f0/0x3c0
[455951.914741]  ? SYSC_connect+0x210/0x210
[455951.916111]  ? bad_area_access_error+0x230/0x230
[455951.917479]  ? ___sys_recvmsg+0x320/0x320
[455951.918811]  ? sock_wake_async+0xc0/0xc0
[455951.920112]  ? SyS_brk+0x3ae/0x3d0
[455951.921381]  ? prepare_exit_to_usermode+0xde/0x230
[455951.922642]  ? enter_from_user_mode+0x30/0x30
[455951.923913]  ? mark_held_locks+0x1b/0xa0
[455951.925179]  ? entry_SYSCALL_64_fastpath+0x5/0xad
[455951.926459]  ? trace_hardirqs_on_caller+0x185/0x260
[455951.927747]  ? trace_hardirqs_on_thunk+0x1a/0x1c
[455951.929031]  entry_SYSCALL_64_fastpath+0x18/0xad
[455951.930314] RIP: 0033:0x7fb44df4ac53
[455951.931592] RSP: 002b:00007ffeeafb6a08 EFLAGS: 00000246
[455951.932914]  ORIG_RAX: 000000000000002c
[455951.934231] RAX: ffffffffffffffda RBX: 000055b8f35d26d0 RCX: 00007fb44df4ac53
[455951.935603] RDX: 000000000000002c RSI: 000055b8f35d14b8 RDI: 0000000000000003
[455951.936991] RBP: 000055b8f35cf010 R08: 00007fb44dc5dbe0 R09: 000000000000000c
[455951.938387] R10: 0000000000000000 R11: 0000000000000246 R12: 00007fb44e43b020
[455951.939795] R13: 00007ffeeafb6acc R14: 0000000000000000 R15: 000055b8f1ca68e0
[455951.941208] Code: 80 48 39 eb 72 25 48 c7 c7 09 d6 a4 a0 e8 3e 28 2c 00 0f b6 0d 80 ab 9d 01 48 8d 45 00 48 d3 e8 48 85 c0 75 06 5b 48 89 e8 5d c3 <0f> 0b 48 c7 c7 10 c0 62 a0 e8 a7 2a 2c 00 48 8b 2d 60 95 5b 01 
[455951.993251] RIP: __phys_addr+0x5b/0x80 RSP: ffff8801c3d4f528
[455982.040898] ---[ end trace dfb8a0f07b7c5316 ]---
[459428.674105] ==================================================================
[459428.679829] BUG: KASAN: use-after-free in __mutex_lock+0x26c/0xf30
[459428.685463] Read of size 4 at addr ffff88013033d020 by task ipset/4611
[459428.696474] CPU: 0 PID: 4611 Comm: ipset Tainted: G      D         4.14.0-rc7-firewall+ #1 
[459428.707271] Call Trace:
[459428.712489]  dump_stack+0xb4/0x124
[459428.717615]  ? _atomic_dec_and_lock+0xec/0xec
[459428.722657]  ? __mutex_lock+0x26c/0xf30
[459428.727612]  print_address_description+0x91/0x260
[459428.732494]  ? __mutex_lock+0x26c/0xf30
[459428.737275]  kasan_report+0x264/0x350
[459428.741935]  __mutex_lock+0x26c/0xf30
[459428.746486]  ? __mutex_lock+0x1d5/0xf30
[459428.750990]  ? __zone_watermark_ok+0x200/0x200
[459428.755410]  ? nfnetlink_rcv_msg+0x58d/0x770
[459428.759731]  ? __ww_mutex_wakeup_for_backoff+0x100/0x100
[459428.763970]  ? __lock_acquire+0x15a/0x2000
[459428.768052]  ? __lock_acquire+0x15a/0x2000
[459428.772013]  ? radix_tree_next_chunk+0x5b6/0x700
[459428.775887]  ? debug_show_all_locks+0x2e0/0x2e0
[459428.779670]  ? debug_show_all_locks+0x2e0/0x2e0
[459428.783342]  ? __lock_acquire+0x15a/0x2000
[459428.786916]  ? lockdep_rcu_suspicious+0x100/0x100
[459428.790432]  ? __lock_acquire+0x15a/0x2000
[459428.794076]  ? do_raw_spin_trylock+0xb3/0x100
[459428.797615]  ? __lock_acquire+0x15a/0x2000
[459428.801052]  ? do_raw_spin_lock+0x120/0x120
[459428.804402]  ? stack_access_ok+0x41/0xb0
[459428.807656]  ? debug_show_all_locks+0x2e0/0x2e0
[459428.810811]  ? stop_critical_timings+0x220/0x220
[459428.813871]  ? trace_preempt_on+0x220/0x220
[459428.816833]  ? stop_critical_timings+0x220/0x220
[459428.819695]  ? __lock_acquire+0x15a/0x2000
[459428.822447]  ? unwind_next_frame+0x53b/0xae0
[459428.825127]  ? debug_lockdep_rcu_enabled+0x22/0x40
[459428.827719]  ? nfnetlink_rcv_msg+0x562/0x770
[459428.830194]  ? lock_acquire+0x380/0x380
[459428.832567]  ? __read_once_size_nocheck.constprop.6+0x10/0x10
[459428.834869]  ? __rcu_read_unlock+0xd3/0x190
[459428.837064]  ? __rcu_read_lock+0x30/0x30
[459428.839158]  ? nla_parse+0xba/0x1f0
[459428.841135]  ? nla_policy_len+0x80/0x80
[459428.843004]  ? lockdep_rcu_suspicious+0x100/0x100
[459428.844789]  ? ftrace_profile_pages_init+0x140/0x140
[459428.846475]  nfnetlink_rcv_msg+0x58d/0x770
[459428.848061]  ? nfnetlink_rcv_msg+0x352/0x770
[459428.849614]  ? nfnetlink_rcv+0xe90/0xe90
[459428.851132]  ? save_stack+0x8b/0xb0
[459428.852623]  netlink_rcv_skb+0x121/0x230
[459428.854094]  ? nfnetlink_rcv+0xe90/0xe90
[459428.855549]  ? netlink_ack+0x4c0/0x4c0
[459428.856956]  ? ns_capable_common+0x68/0xc0
[459428.858356]  nfnetlink_rcv+0x1ad/0xe90
[459428.859754]  ? lock_acquire+0x380/0x380
[459428.861149]  ? __rcu_read_unlock+0xd3/0x190
[459428.862547]  ? __rcu_read_lock+0x30/0x30
[459428.863925]  ? netlink_lookup+0x41d/0x750
[459428.865297]  ? netlink_connect+0x1e0/0x1e0
[459428.866665]  ? nfnl_err_reset+0x180/0x180
[459428.868043]  ? netlink_deliver_tap+0x128/0x560
[459428.869423]  ? netlink_deliver_tap+0x5/0x560
[459428.870786]  ? iov_iter_advance+0x172/0x7f0
[459428.872146]  ? netlink_getname+0x150/0x150
[459428.873495]  ? __phys_addr_symbol+0x23/0x40
[459428.874838]  ? iov_iter_copy_from_user_atomic+0x7d0/0x7d0
[459428.876221]  ? netlink_trim+0x111/0x1b0
[459428.877598]  ? netlink_skb_destructor+0xf0/0xf0
[459428.878973]  netlink_unicast+0x2b1/0x340
[459428.880366]  ? netlink_detachskb+0x30/0x30
[459428.881764]  ? lock_acquire+0x380/0x380
[459428.883153]  ? lockdep_rcu_suspicious+0x100/0x100
[459428.884550]  ? debug_lockdep_rcu_enabled+0x22/0x40
[459428.885950]  netlink_sendmsg+0x4f2/0x650
[459428.887344]  ? netlink_broadcast_filtered+0x9e0/0x9e0
[459428.888755]  ? _copy_from_user+0x86/0xc0
[459428.890162]  ? netlink_broadcast_filtered+0x9e0/0x9e0
[459428.891587]  SYSC_sendto+0x2f0/0x3c0
[459428.893002]  ? SYSC_connect+0x210/0x210
[459428.894410]  ? bad_area_access_error+0x230/0x230
[459428.895824]  ? ___sys_recvmsg+0x320/0x320
[459428.897233]  ? sock_wake_async+0xc0/0xc0
[459428.898637]  ? SyS_brk+0x3ae/0x3d0
[459428.900026]  ? prepare_exit_to_usermode+0xde/0x230
[459428.901433]  ? enter_from_user_mode+0x30/0x30
[459428.902838]  ? SyS_socket+0xd9/0x130
[459428.904227]  ? trace_hardirqs_off_caller+0x1a/0x100
[459428.905626]  ? trace_hardirqs_on_caller+0x11/0x260
[459428.907031]  ? trace_hardirqs_on_thunk+0x1a/0x1c
[459428.908424]  entry_SYSCALL_64_fastpath+0x18/0xad
[459428.909821] RIP: 0033:0x7ff9e38b2c53
[459428.911211] RSP: 002b:00007ffcca4a8408 EFLAGS: 00000246
[459428.912618]  ORIG_RAX: 000000000000002c
[459428.914070] RAX: ffffffffffffffda RBX: 0000000000000008 RCX: 00007ff9e38b2c53
[459428.915527] RDX: 000000000000001c RSI: 00007ffcca4a8440 RDI: 0000000000000003
[459428.917007] RBP: 00007ffcca4a8440 R08: 00007ff9e35c5be0 R09: 000000000000000c
[459428.918484] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000001
[459428.919968] R13: 00007ffcca4a841c R14: 0000000000000001 R15: 0000000000000000

[459428.922917] Allocated by task 4557:
[459428.924403]  save_stack+0x33/0xb0
[459428.925880]  kasan_kmalloc+0xb3/0xe0
[459428.927259]  kmem_cache_alloc+0xfc/0x300
[459428.928639]  getname_flags+0x41/0x210
[459428.930026]  user_path_at_empty+0x1d/0x40
[459428.931416]  vfs_statx+0xb6/0x130
[459428.932801]  SYSC_newstat+0x6d/0xc0
[459428.934186]  entry_SYSCALL_64_fastpath+0x18/0xad

[459428.936968] Freed by task 4557:
[459428.938362]  save_stack+0x33/0xb0
[459428.939753]  kasan_slab_free+0x74/0xc0
[459428.941147]  kmem_cache_free+0x8d/0x2c0
[459428.942525]  filename_lookup+0x18d/0x250
[459428.943893]  vfs_statx+0xb6/0x130
[459428.945255]  SYSC_newstat+0x6d/0xc0
[459428.946612]  entry_SYSCALL_64_fastpath+0x18/0xad

[459428.949333] The buggy address belongs to the object at ffff88013033c740
                 which belongs to the cache names_cache of size 4096
[459428.952145] The buggy address is located 2272 bytes inside of
                 4096-byte region [ffff88013033c740, ffff88013033d740)
[459428.955044] The buggy address belongs to the page:
[459428.956588] page:ffffea0004c0ce00 count:1 mapcount:0 mapping:          (null) index:0x0
[459428.958184]  compound_mapcount: 0
[459428.959752] flags: 0x8000000000008100(slab|head)
[459428.961346] raw: 8000000000008100 0000000000000000 0000000000000000 0000000100070007
[459428.962998] raw: ffffea0006890020 ffffea0006e32420 ffff8801d12c90c0 0000000000000000
[459428.964660] page dumped because: kasan: bad access detected

[459428.967979] Memory state around the buggy address:
[459428.969660]  ffff88013033cf00: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
[459428.971385]  ffff88013033cf80: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
[459428.973091] >ffff88013033d000: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
[459428.974774]                                ^
[459428.976458]  ffff88013033d080: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
[459428.978209]  ffff88013033d100: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
[459428.979938] ==================================================================

Powered by blists - more mailing lists