Re: [PATCH v14 net-next 08/23] net/tcp: Add AO sign to RST packets

From: Dmitry Safonov
Date: Tue Oct 17 2023 - 19:20:06 EST


On 10/17/23 09:37, kernel test robot wrote:
>
>
> Hello,
>
> kernel test robot noticed "BUG:sleeping_function_called_from_invalid_context_at_net/core/sock.c" on:
>
> commit: df13d11e6a2a3cc5f973aca36f68f880fa42d55f ("[PATCH v14 net-next 08/23] net/tcp: Add AO sign to RST packets")
> url: https://github.com/intel-lab-lkp/linux/commits/Dmitry-Safonov/net-tcp-Prepare-tcp_md5sig_pool-for-TCP-AO/20231010-071412
> patch link: https://lore.kernel.org/all/20231009230722.76268-9-dima@xxxxxxxxxx/
> patch subject: [PATCH v14 net-next 08/23] net/tcp: Add AO sign to RST packets
>
> in testcase: trinity
> version: trinity-i386-abe9de86-1_20230429
> with following parameters:
>
> runtime: 300s
> group: group-02
> nr_groups: 5
>
> test-description: Trinity is a linux system call fuzz tester.
> test-url: http://codemonkey.org.uk/projects/trinity/
>
>
> compiler: gcc-12
> test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 16G
>
> (please refer to attached dmesg/kmsg for entire log/backtrace)
>
>
>
> If you fix the issue in a separate patch/commit (i.e. not just a new version of
> the same patch/commit), kindly add following tags
> | Reported-by: kernel test robot <oliver.sang@xxxxxxxxx>
> | Closes: https://lore.kernel.org/oe-lkp/202310171606.30e15ebe-oliver.sang@xxxxxxxxx
>
>
> [ 221.348247][ T7133] BUG: sleeping function called from invalid context at net/core/sock.c:2978
> [ 221.349875][ T7133] in_atomic(): 0, irqs_disabled(): 0, non_block: 0, pid: 7133, name: trinity-c4
> [ 221.351666][ T7133] preempt_count: 0, expected: 0
> [ 221.352614][ T7133] RCU nest depth: 1, expected: 0
> [ 221.353518][ T7133] 2 locks held by trinity-c4/7133:
> [ 221.354530][ T7133] #0: ed8b5660 (sk_lock-AF_INET6){+.+.}-{0:0}, at: tcp_sendmsg (net/ipv4/tcp.c:1336)
> [ 221.374314][ T7133] #1: c27dbb18 (rcu_read_lock){....}-{1:2}, at: inet6_csk_xmit (include/linux/rcupdate.h:747 net/ipv6/inet6_connection_sock.c:129)
> [ 221.375906][ T7133] CPU: 1 PID: 7133 Comm: trinity-c4 Tainted: G W TN 6.6.0-rc4-01105-gdf13d11e6a2a #1

Quite puzzling. It doesn't seem that it can happen to inet6_csk_xmit():

: rcu_read_lock();
: skb_dst_set_noref(skb, dst);
:
: /* Restore final destination back after routing done */
: fl6.daddr = sk->sk_v6_daddr;
:
: res = ip6_xmit(sk, skb, &fl6, sk->sk_mark, rcu_dereference(np->opt),
: np->tclass, sk->sk_priority);
: rcu_read_unlock();

So, I presumed the calltrace was for nested rcu_read_lock() case.
Then I've looked at all return/goto cases, I couldn't find any
unbalanced rcu_read_{,un}lock().

Is this reproducible by any chance?


> [ 221.377820][ T7133] Call Trace:
> [ 221.378447][ T7133] dump_stack_lvl (lib/dump_stack.c:107)
> [ 221.379373][ T7133] dump_stack (lib/dump_stack.c:114)
> [ 221.380186][ T7133] __might_resched (kernel/sched/core.c:10188)
> [ 221.381100][ T7133] __release_sock (include/linux/sched.h:2097 net/core/sock.c:2978)
> [ 221.381960][ T7133] release_sock (net/core/sock.c:3520)
> [ 221.382784][ T7133] inet_wait_for_connect (net/ipv4/af_inet.c:609)
> [ 221.383763][ T7133] ? autoremove_wake_function (kernel/sched/wait.c:479)
> [ 221.384757][ T7133] __inet_stream_connect (net/ipv4/af_inet.c:701 (discriminator 1))
> [ 221.385741][ T7133] ? kmalloc_node_trace (mm/slab_common.c:1133)
> [ 221.386702][ T7133] tcp_sendmsg_fastopen (net/ipv4/tcp.c:1026)
> [ 221.387685][ T7133] tcp_sendmsg_locked (net/ipv4/tcp.c:1073)
> [ 221.388642][ T7133] ? find_held_lock (kernel/locking/lockdep.c:5243)
> [ 221.389536][ T7133] ? mark_held_locks (kernel/locking/lockdep.c:4273)
> [ 221.390437][ T7133] ? lock_sock_nested (net/core/sock.c:3511)
> [ 221.391359][ T7133] ? lock_sock_nested (net/core/sock.c:3511)
> [ 221.392335][ T7133] tcp_sendmsg (net/ipv4/tcp.c:1336)
> [ 221.393153][ T7133] inet6_sendmsg (net/ipv6/af_inet6.c:658 (discriminator 2))
> [ 221.394010][ T7133] ____sys_sendmsg (net/socket.c:730 net/socket.c:745 net/socket.c:2558)
> [ 221.394927][ T7133] ___sys_sendmsg (net/socket.c:2612)
> [ 221.395844][ T7133] __sys_sendmsg (net/socket.c:2641)
> [ 221.396671][ T7133] __ia32_sys_sendmsg (net/socket.c:2648)
> [ 221.397562][ T7133] __do_fast_syscall_32 (arch/x86/entry/common.c:112 arch/x86/entry/common.c:178)
> [ 221.398485][ T7133] do_fast_syscall_32 (arch/x86/entry/common.c:203)
> [ 221.399401][ T7133] do_SYSENTER_32 (arch/x86/entry/common.c:247)
> [ 221.404363][ T7133] entry_SYSENTER_32 (arch/x86/entry/entry_32.S:840)
> [ 221.405255][ T7133] EIP: 0xb7f59579
> [ 221.405931][ T7133] Code: b8 01 10 06 03 74 b4 01 10 07 03 74 b0 01 10 08 03 74 d8 01 00 00 00 00 00 00 00 00 00 00 00 00 00 51 52 55 89 e5 0f 34 cd 80 <5d> 5a 59 c3 90 90 90 90 8d 76 00 58 b8 77 00 00 00 cd 80 90 8d 76
> All code
> ========
> 0: b8 01 10 06 03 mov $0x3061001,%eax
> 5: 74 b4 je 0xffffffffffffffbb
> 7: 01 10 add %edx,(%rax)
> 9: 07 (bad)
> a: 03 74 b0 01 add 0x1(%rax,%rsi,4),%esi
> e: 10 08 adc %cl,(%rax)
> 10: 03 74 d8 01 add 0x1(%rax,%rbx,8),%esi
> ...
> 20: 00 51 52 add %dl,0x52(%rcx)
> 23: 55 push %rbp
> 24:* 89 e5 mov %esp,%ebp <-- trapping instruction
> 26: 0f 34 sysenter
> 28: cd 80 int $0x80
> 2a: 5d pop %rbp
> 2b: 5a pop %rdx
> 2c: 59 pop %rcx
> 2d: c3 ret
> 2e: 90 nop
> 2f: 90 nop
> 30: 90 nop
> 31: 90 nop
> 32: 8d 76 00 lea 0x0(%rsi),%esi
> 35: 58 pop %rax
> 36: b8 77 00 00 00 mov $0x77,%eax
> 3b: cd 80 int $0x80
> 3d: 90 nop
> 3e: 8d .byte 0x8d
> 3f: 76 .byte 0x76
>
> Code starting with the faulting instruction
> ===========================================
> 0: 5d pop %rbp
> 1: 5a pop %rdx
> 2: 59 pop %rcx
> 3: c3 ret
> 4: 90 nop
> 5: 90 nop
> 6: 90 nop
> 7: 90 nop
> 8: 8d 76 00 lea 0x0(%rsi),%esi
> b: 58 pop %rax
> c: b8 77 00 00 00 mov $0x77,%eax
> 11: cd 80 int $0x80
> 13: 90 nop
> 14: 8d .byte 0x8d
> 15: 76 .byte 0x76
> [ 221.409527][ T7133] EAX: ffffffda EBX: 00000137 ECX: 01ce1580 EDX: 240449b4
> [ 221.410805][ T7133] ESI: 000000b1 EDI: 8b8b8b8b EBP: 08080808 ESP: bfc205fc
> [ 221.412147][ T7133] DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 007b EFLAGS: 00000296
> [ 221.481648][ T7133]
> [ 221.482194][ T7133] ================================================
> [ 221.483377][ T7133] WARNING: lock held when returning to user space!
> [ 221.484574][ T7133] 6.6.0-rc4-01105-gdf13d11e6a2a #1 Tainted: G W TN
> [ 221.485904][ T7133] ------------------------------------------------
> [ 221.487044][ T7133] trinity-c4/7133 is leaving the kernel with locks still held!
> [ 221.488448][ T7133] 1 lock held by trinity-c4/7133:
> [ 221.489401][ T7133] #0: c27dbb18 (rcu_read_lock){....}-{1:2}, at: inet6_csk_xmit (include/linux/rcupdate.h:747 net/ipv6/inet6_connection_sock.c:129)
> [ 221.491125][ T7133] ------------[ cut here ]------------
> [ 221.501170][ T7133] Voluntary context switch within RCU read-side critical section!
> [ 221.501214][ T7133] WARNING: CPU: 1 PID: 7133 at kernel/rcu/tree_plugin.h:320 rcu_note_context_switch (kernel/rcu/tree_plugin.h:320 (discriminator 11))
> [ 221.504458][ T7133] Modules linked in: ipmi_msghandler uio_pdrv_genirq uio rtc_cmos processor fuse drm drm_panel_orientation_quirks configfs
> [ 221.506701][ T7133] CPU: 1 PID: 7133 Comm: trinity-c4 Tainted: G W TN 6.6.0-rc4-01105-gdf13d11e6a2a #1
> [ 221.508634][ T7133] EIP: rcu_note_context_switch (kernel/rcu/tree_plugin.h:320 (discriminator 11))
> [ 221.509684][ T7133] Code: e9 87 fe ff ff 8d 74 26 00 8b 41 2c 89 45 ec e9 16 ff ff ff 8d 74 26 00 90 c6 05 09 88 94 c2 01 68 04 84 32 c2 e8 47 14 f5 ff <0f> 0b 5a e9 b0 fd ff ff 8d b4 26 00 00 00 00 81 e2 ff ff ff 7f 0f
> All code
> ========
> 0: e9 87 fe ff ff jmp 0xfffffffffffffe8c
> 5: 8d 74 26 00 lea 0x0(%rsi,%riz,1),%esi
> 9: 8b 41 2c mov 0x2c(%rcx),%eax
> c: 89 45 ec mov %eax,-0x14(%rbp)
> f: e9 16 ff ff ff jmp 0xffffffffffffff2a
> 14: 8d 74 26 00 lea 0x0(%rsi,%riz,1),%esi
> 18: 90 nop
> 19: c6 05 09 88 94 c2 01 movb $0x1,-0x3d6b77f7(%rip) # 0xffffffffc2948829
> 20: 68 04 84 32 c2 push $0xffffffffc2328404
> 25: e8 47 14 f5 ff call 0xfffffffffff51471
> 2a:* 0f 0b ud2 <-- trapping instruction
> 2c: 5a pop %rdx
> 2d: e9 b0 fd ff ff jmp 0xfffffffffffffde2
> 32: 8d b4 26 00 00 00 00 lea 0x0(%rsi,%riz,1),%esi
> 39: 81 e2 ff ff ff 7f and $0x7fffffff,%edx
> 3f: 0f .byte 0xf
>
> Code starting with the faulting instruction
> ===========================================
> 0: 0f 0b ud2
> 2: 5a pop %rdx
> 3: e9 b0 fd ff ff jmp 0xfffffffffffffdb8
> 8: 8d b4 26 00 00 00 00 lea 0x0(%rsi,%riz,1),%esi
> f: 81 e2 ff ff ff 7f and $0x7fffffff,%edx
> 15: 0f .byte 0xf
> [ 221.513148][ T7133] EAX: 00000000 EBX: e52d7c40 ECX: 00000000 EDX: 00000000
> [ 221.514443][ T7133] ESI: 00000000 EDI: eadb5640 EBP: ead7df28 ESP: ead7df10
> [ 221.515747][ T7133] DS: 007b ES: 007b FS: 00d8 GS: 0033 SS: 0068 EFLAGS: 00010046
> [ 221.517184][ T7133] CR0: 80050033 CR2: 01ce68cc CR3: 2ae6f000 CR4: 00000690
> [ 221.518449][ T7133] Call Trace:
> [ 221.519074][ T7133] ? show_regs (arch/x86/kernel/dumpstack.c:478)
> [ 221.519826][ T7133] ? rcu_note_context_switch (kernel/rcu/tree_plugin.h:320 (discriminator 11))
> [ 221.520887][ T7133] ? __warn (kernel/panic.c:673)
> [ 221.521663][ T7133] ? rcu_note_context_switch (kernel/rcu/tree_plugin.h:320 (discriminator 11))
> [ 221.522722][ T7133] ? report_bug (lib/bug.c:201 lib/bug.c:219)
> [ 221.523615][ T7133] ? exc_overflow (arch/x86/kernel/traps.c:250)
> [ 221.524517][ T7133] ? handle_bug (arch/x86/kernel/traps.c:216)
> [ 221.525240][ T7133] ? exc_invalid_op (arch/x86/kernel/traps.c:258 (discriminator 1))
> [ 221.526115][ T7133] ? handle_exception (arch/x86/entry/entry_32.S:1056)
> [ 221.527035][ T7133] ? exc_overflow (arch/x86/kernel/traps.c:250)
> [ 221.527882][ T7133] ? rcu_note_context_switch (kernel/rcu/tree_plugin.h:320 (discriminator 11))
> [ 221.528945][ T7133] ? exc_overflow (arch/x86/kernel/traps.c:250)
> [ 221.529743][ T7133] ? rcu_note_context_switch (kernel/rcu/tree_plugin.h:320 (discriminator 11))
> [ 221.530784][ T7133] __schedule (arch/x86/include/asm/preempt.h:80 (discriminator 3) kernel/sched/core.c:556 (discriminator 3) kernel/sched/sched.h:1372 (discriminator 3) kernel/sched/sched.h:1681 (discriminator 3) kernel/sched/core.c:6612 (discriminator 3))
> [ 221.531573][ T7133] ? exit_to_user_mode_prepare (kernel/entry/common.c:158 kernel/entry/common.c:204)
> [ 221.532627][ T7133] schedule (arch/x86/include/asm/preempt.h:85 (discriminator 1) kernel/sched/core.c:6772 (discriminator 1))
> [ 221.533358][ T7133] exit_to_user_mode_prepare (kernel/entry/common.c:161 kernel/entry/common.c:204)
> [ 221.534382][ T7133] ? sysvec_reboot (arch/x86/kernel/smp.c:269)
> [ 221.535255][ T7133] irqentry_exit_to_user_mode (kernel/entry/common.c:130 kernel/entry/common.c:311)
> [ 221.536302][ T7133] irqentry_exit (kernel/entry/common.c:445)
> [ 221.537101][ T7133] sysvec_reschedule_ipi (arch/x86/kernel/smp.c:269)
> [ 221.538079][ T7133] handle_exception (arch/x86/entry/entry_32.S:1056)
> [ 221.538990][ T7133] EIP: 0xb7f59579
> [ 221.539674][ T7133] Code: b8 01 10 06 03 74 b4 01 10 07 03 74 b0 01 10 08 03 74 d8 01 00 00 00 00 00 00 00 00 00 00 00 00 00 51 52 55 89 e5 0f 34 cd 80 <5d> 5a 59 c3 90 90 90 90 8d 76 00 58 b8 77 00 00 00 cd 80 90 8d 76
> All code
> ========
> 0: b8 01 10 06 03 mov $0x3061001,%eax
> 5: 74 b4 je 0xffffffffffffffbb
> 7: 01 10 add %edx,(%rax)
> 9: 07 (bad)
> a: 03 74 b0 01 add 0x1(%rax,%rsi,4),%esi
> e: 10 08 adc %cl,(%rax)
> 10: 03 74 d8 01 add 0x1(%rax,%rbx,8),%esi
> ...
> 20: 00 51 52 add %dl,0x52(%rcx)
> 23: 55 push %rbp
> 24:* 89 e5 mov %esp,%ebp <-- trapping instruction
> 26: 0f 34 sysenter
> 28: cd 80 int $0x80
> 2a: 5d pop %rbp
> 2b: 5a pop %rdx
> 2c: 59 pop %rcx
> 2d: c3 ret
> 2e: 90 nop
> 2f: 90 nop
> 30: 90 nop
> 31: 90 nop
> 32: 8d 76 00 lea 0x0(%rsi),%esi
> 35: 58 pop %rax
> 36: b8 77 00 00 00 mov $0x77,%eax
> 3b: cd 80 int $0x80
> 3d: 90 nop
> 3e: 8d .byte 0x8d
> 3f: 76 .byte 0x76
>
> Code starting with the faulting instruction
> ===========================================
> 0: 5d pop %rbp
> 1: 5a pop %rdx
> 2: 59 pop %rcx
> 3: c3 ret
> 4: 90 nop
> 5: 90 nop
> 6: 90 nop
> 7: 90 nop
> 8: 8d 76 00 lea 0x0(%rsi),%esi
> b: 58 pop %rax
> c: b8 77 00 00 00 mov $0x77,%eax
> 11: cd 80 int $0x80
> 13: 90 nop
> 14: 8d .byte 0x8d
> 15: 76 .byte 0x76
> [ 221.543249][ T7133] EAX: ffffff91 EBX: 00000137 ECX: bfc205fc EDX: b7f59579
> [ 221.544585][ T7133] ESI: 000000b1 EDI: 8b8b8b8b EBP: 08080808 ESP: bfc205fc
> [ 221.545872][ T7133] DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 007b EFLAGS: 00000296
> [ 221.547230][ T7133] ? sysvec_reboot (arch/x86/kernel/smp.c:269)
> [ 221.548133][ T7133] irq event stamp: 10576
> [ 221.548909][ T7133] hardirqs last enabled at (10575): _raw_spin_unlock_irq (arch/x86/include/asm/irqflags.h:42 arch/x86/include/asm/irqflags.h:77 include/linux/spinlock_api_smp.h:159 kernel/locking/spinlock.c:202)
> [ 221.550576][ T7133] hardirqs last disabled at (10576): exit_to_user_mode_prepare (include/linux/entry-common.h:191 kernel/entry/common.c:181 kernel/entry/common.c:204)
> [ 221.552434][ T7133] softirqs last enabled at (10570): release_sock (net/core/sock.c:3528)
> [ 221.553958][ T7133] softirqs last disabled at (10568): release_sock (net/core/sock.c:3517)
> [ 221.555538][ T7133] ---[ end trace 0000000000000000 ]---
>
>
> The kernel config and materials to reproduce are available at:
> https://download.01.org/0day-ci/archive/20231017/202310171606.30e15ebe-oliver.sang@xxxxxxxxx
>
>
>

Thanks,
Dmitry