| Message ID | 20220330082046.3512424-3-asavkov@redhat.com (mailing list archive) |
|---|---|
| State | Superseded |
| Delegated to: | Netdev Maintainers |
| Headers | show |
| Series | Upper bound kernel timers | expand |
Greeting,
FYI, we noticed the following commit (built with gcc-9):
commit: 6ef3f95797546781829db3bb6228c9990ba1d49f ("[PATCH v3 2/2] net: make tcp keepalive timer upper bound")
url: https://github.com/intel-lab-lkp/linux/commits/Artem-Savkov/timer-add-a-function-to-adjust-timeouts-to-be-upper-bound/20220330-172140
base: https://git.kernel.org/cgit/linux/kernel/git/tip/tip.git b166e52541f2357ce126a92ce1d9a580fdca719d
patch link: https://lore.kernel.org/netdev/20220330082046.3512424-3-asavkov@redhat.com
in testcase: kernel-selftests
version: kernel-selftests-x86_64-a17aac1b-1_20220328
with following parameters:
group: tc-testing
ucode: 0xec
test-description: The kernel contains a set of "self tests" under the tools/testing/selftests/ directory. These are intended to be small unit tests to exercise individual code paths in the kernel.
test-url: https://www.kernel.org/doc/Documentation/kselftest.txt
on test machine: 8 threads Intel(R) Core(TM) i7-6700 CPU @ 3.40GHz with 16G memory
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
If you fix the issue, kindly add following tag
Reported-by: kernel test robot <oliver.sang@intel.com>
[ 158.913672][ C1] UBSAN: shift-out-of-bounds in kernel/time/timer.c:584:32
[ 158.922603][ C1] shift exponent -3 is negative
[ 158.927346][ C1] CPU: 1 PID: 0 Comm: swapper/1 Not tainted 5.17.0-rc6-00028-g6ef3f9579754 #1
[ 158.936050][ C1] Hardware name: HP HP Z240 SFF Workstation/802E, BIOS N51 Ver. 01.63 10/05/2017
[ 158.945011][ C1] Call Trace:
[ 158.948161][ C1] <IRQ>
[ 158.950872][ C1] dump_stack_lvl (lib/dump_stack.c:107)
[ 158.955242][ C1] ubsan_epilogue (lib/ubsan.c:152)
[ 158.959517][ C1] __ubsan_handle_shift_out_of_bounds.cold (lib/ubsan.c:330)
[ 158.966138][ C1] ? generic_powersave_bias_target (drivers/cpufreq/cpufreq_ondemand.c:68)
[ 158.972155][ C1] ? lockdep_hardirqs_on_prepare (kernel/locking/lockdep.c:4224 kernel/locking/lockdep.c:4292 kernel/locking/lockdep.c:4244)
[ 158.977994][ C1] ? ktime_get (arch/x86/include/asm/irqflags.h:45 arch/x86/include/asm/irqflags.h:80 arch/x86/include/asm/irqflags.h:138 include/linux/seqlock.h:105 kernel/time/timekeeping.c:827)
[ 158.982275][ C1] ? trace_hardirqs_on (kernel/trace/trace_preemptirq.c:50 (discriminator 22))
[ 158.987164][ C1] upper_bound_timeout.cold (kernel/time/timer.c:584)
[ 158.992402][ C1] inet_csk_reset_keepalive_timer (net/ipv4/inet_connection_sock.c:592)
[ 158.998153][ C1] tcp_keepalive_timer (net/ipv4/tcp_timer.c:750)
[ 159.003132][ C1] ? tcp_compressed_ack_kick (net/ipv4/tcp_timer.c:674)
[ 159.008623][ C1] call_timer_fn (arch/x86/include/asm/jump_label.h:27 include/linux/jump_label.h:212 include/trace/events/timer.h:125 kernel/time/timer.c:1488)
[ 159.013077][ C1] ? lock_release (kernel/locking/lockdep.c:5315 kernel/locking/lockdep.c:5659)
[ 159.017617][ C1] ? add_timer (kernel/time/timer.c:1464)
[ 159.021891][ C1] ? lock_downgrade (kernel/locking/lockdep.c:5647)
[ 159.026607][ C1] ? tcp_compressed_ack_kick (net/ipv4/tcp_timer.c:674)
[ 159.032095][ C1] ? lockdep_hardirqs_on_prepare (kernel/locking/lockdep.c:4224 kernel/locking/lockdep.c:4292 kernel/locking/lockdep.c:4244)
[ 159.034064][ T433] HDRINST usr/include/linux/arcfb.h
[ 159.037937][ C1] ? tcp_compressed_ack_kick (net/ipv4/tcp_timer.c:674)
[ 159.043186][ T433]
[ 159.048657][ C1] run_timer_softirq (kernel/time/timer.c:1533 kernel/time/timer.c:1800 kernel/time/timer.c:1776 kernel/time/timer.c:1813)
[ 159.048676][ C1] ? call_timer_fn (kernel/time/timer.c:1810)
[ 159.048681][ C1] ? __next_base (kernel/time/hrtimer.c:506)
[ 159.051777][ T433] HDRINST usr/include/linux/am437x-vpfe.h
[ 159.055760][ C1] ? rcu_read_lock_sched_held (include/linux/lockdep.h:283 kernel/rcu/update.c:125)
[ 159.060401][ T433]
[ 159.064827][ C1] ? rcu_read_lock_bh_held (kernel/rcu/update.c:120)
[ 159.064842][ C1] __do_softirq (arch/x86/include/asm/jump_label.h:27 include/linux/jump_label.h:212 include/trace/events/irq.h:142 kernel/softirq.c:559)
[ 159.064864][ C1] irq_exit_rcu (kernel/softirq.c:432 kernel/softirq.c:637 kernel/softirq.c:649)
[ 159.071477][ T433] HDRINST usr/include/linux/perf_event.h
[ 159.076075][ C1] sysvec_apic_timer_interrupt (arch/x86/kernel/apic/apic.c:1097 (discriminator 14))
[ 159.076082][ C1] </IRQ>
[ 159.078286][ T433]
[ 159.083411][ C1] <TASK>
[ 159.083414][ C1] asm_sysvec_apic_timer_interrupt (arch/x86/include/asm/idtentry.h:638)
[ 159.083421][ C1] RIP: 0010:cpuidle_enter_state (drivers/cpuidle/cpuidle.c:259)
[ 159.083428][ C1] Code: 00 00 31 ff e8 47 3f 43 fe 80 3c 24 00 74 12 9c 58 f6 c4 02 0f 85 1f 08 00 00 31 ff e8 af c1 5b fe e8 ea 43 71 fe fb 45 85 f6 <0f> 88 90 03 00 00 49 63 ee 48 83 fd 09 0f 87 62 09 00 00 48 8d 44
All code
========
0: 00 00 add %al,(%rax)
2: 31 ff xor %edi,%edi
4: e8 47 3f 43 fe callq 0xfffffffffe433f50
9: 80 3c 24 00 cmpb $0x0,(%rsp)
d: 74 12 je 0x21
f: 9c pushfq
10: 58 pop %rax
11: f6 c4 02 test $0x2,%ah
14: 0f 85 1f 08 00 00 jne 0x839
1a: 31 ff xor %edi,%edi
1c: e8 af c1 5b fe callq 0xfffffffffe5bc1d0
21: e8 ea 43 71 fe callq 0xfffffffffe714410
26: fb sti
27: 45 85 f6 test %r14d,%r14d
2a:* 0f 88 90 03 00 00 js 0x3c0 <-- trapping instruction
30: 49 63 ee movslq %r14d,%rbp
33: 48 83 fd 09 cmp $0x9,%rbp
37: 0f 87 62 09 00 00 ja 0x99f
3d: 48 rex.W
3e: 8d .byte 0x8d
3f: 44 rex.R
Code starting with the faulting instruction
===========================================
0: 0f 88 90 03 00 00 js 0x396
6: 49 63 ee movslq %r14d,%rbp
9: 48 83 fd 09 cmp $0x9,%rbp
d: 0f 87 62 09 00 00 ja 0x975
13: 48 rex.W
14: 8d .byte 0x8d
15: 44 rex.R
[ 159.088738][ T433] HDRINST usr/include/linux/netfilter_arp.h
[ 159.092147][ C1] RSP: 0018:ffffc9000014fd80 EFLAGS: 00000202
[ 159.092151][ C1] RAX: 000000000039d49f RBX: ffffe8ffffa82330 RCX: 1ffffffff0bf9cc1
[ 159.092154][ C1] RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffffffff830167d6
[ 159.097833][ T433]
[ 159.103298][ C1] RBP: 0000000000000004 R08: 0000000000000001 R09: 0000000000000001
[ 159.103301][ C1] R10: ffffffff85fd3c67 R11: fffffbfff0bfa78c R12: ffffffff85a74a40
[ 159.103303][ C1] R13: 00000024ff70d012 R14: 0000000000000004 R15: 0000000000000001
[ 159.103319][ C1] ? cpuidle_enter_state (arch/x86/include/asm/irqflags.h:45 arch/x86/include/asm/irqflags.h:80 drivers/cpuidle/cpuidle.c:257)
[ 159.107090][ T433] HDRINST usr/include/linux/virtio_console.h
[ 159.108317][ C1] ? menu_reflect (drivers/cpuidle/governors/menu.c:441)
[ 159.111135][ T433]
[ 159.116958][ C1] cpuidle_enter (drivers/cpuidle/cpuidle.c:353)
[ 159.116969][ C1] do_idle (kernel/sched/idle.c:158 kernel/sched/idle.c:239 kernel/sched/idle.c:306)
[ 159.116985][ C1] ? arch_cpu_idle_exit+0xc0/0xc0
[ 159.151856][ T433] HDRINST usr/include/linux/hdlcdrv.h
[ 159.153998][ C1] cpu_startup_entry (kernel/sched/idle.c:402 (discriminator 1))
[ 159.161840][ T433]
[ 159.169651][ C1] start_secondary (arch/x86/kernel/smpboot.c:224)
[ 159.169658][ C1] ? set_cpu_sibling_map (arch/x86/kernel/smpboot.c:224)
[ 159.169673][ C1] secondary_startup_64_no_verify (arch/x86/kernel/head_64.S:300)
[ 159.169703][ C1] </TASK>
[ 159.197643][ T433] HDRINST usr/include/linux/posix_acl_xattr.h
[ 159.200540][ C1] ================================================================================
[ 159.206541][ T433]
[ 159.210985][ C1] ================================================================================
To reproduce:
git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
sudo bin/lkp install job.yaml # job file is attached in this email
bin/lkp split-job --compatible job.yaml # generate the yaml file for lkp run
sudo bin/lkp run generated-yaml-file
# if come across any failure that blocks the test,
# please remove ~/.lkp and /lkp dir to run from a clean state.
On Sat, Apr 02, 2022 at 11:09:40AM +0800, kernel test robot wrote: > > > Greeting, > > FYI, we noticed the following commit (built with gcc-9): > > commit: 6ef3f95797546781829db3bb6228c9990ba1d49f ("[PATCH v3 2/2] net: make tcp keepalive timer upper bound") > url: https://github.com/intel-lab-lkp/linux/commits/Artem-Savkov/timer-add-a-function-to-adjust-timeouts-to-be-upper-bound/20220330-172140 > base: https://git.kernel.org/cgit/linux/kernel/git/tip/tip.git b166e52541f2357ce126a92ce1d9a580fdca719d > patch link: https://lore.kernel.org/netdev/20220330082046.3512424-3-asavkov@redhat.com > > in testcase: kernel-selftests > version: kernel-selftests-x86_64-a17aac1b-1_20220328 > with following parameters: > > group: tc-testing > ucode: 0xec > > test-description: The kernel contains a set of "self tests" under the tools/testing/selftests/ directory. These are intended to be small unit tests to exercise individual code paths in the kernel. > test-url: https://www.kernel.org/doc/Documentation/kselftest.txt > > > on test machine: 8 threads Intel(R) Core(TM) i7-6700 CPU @ 3.40GHz with 16G memory > > caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace): > > > > If you fix the issue, kindly add following tag > Reported-by: kernel test robot <oliver.sang@intel.com> > > > [ 158.913672][ C1] UBSAN: shift-out-of-bounds in kernel/time/timer.c:584:32 > [ 158.922603][ C1] shift exponent -3 is negative This is caused by LVL_START(0). Levels 0 and 1 need to be handled separately to insure we don't end up with negative values.
diff --git a/net/ipv4/inet_connection_sock.c b/net/ipv4/inet_connection_sock.c index 1e5b53c2bb267..bb2dbfb6f5b50 100644 --- a/net/ipv4/inet_connection_sock.c +++ b/net/ipv4/inet_connection_sock.c @@ -589,7 +589,7 @@ EXPORT_SYMBOL(inet_csk_delete_keepalive_timer); void inet_csk_reset_keepalive_timer(struct sock *sk, unsigned long len) { - sk_reset_timer(sk, &sk->sk_timer, jiffies + len); + sk_reset_timer(sk, &sk->sk_timer, jiffies + upper_bound_timeout(len)); } EXPORT_SYMBOL(inet_csk_reset_keepalive_timer);
Make sure TCP keepalive timer does not expire late. Switching to upper bound timers means it can fire off early but in case of keepalive tcp_keepalive_timer() handler checks elapsed time and resets the timer if it was triggered early. This results in timer "cascading" to a higher precision and being just a couple of milliseconds off it's original mark. Signed-off-by: Artem Savkov <asavkov@redhat.com> --- net/ipv4/inet_connection_sock.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-)