LVS
lvs-devel
Google
 
Web LinuxVirtualServer.org

Re: Fw: [Bug 209427] New: Incorrect timestamp cause packet to be dropped

To: Stephen Hemminger <stephen@xxxxxxxxxxxxxxxxxx>, netdev@xxxxxxxxxxxxxxx, Julian Anastasov <ja@xxxxxx>, "lvs-devel@xxxxxxxxxxxxxxx" <lvs-devel@xxxxxxxxxxxxxxx>, abt-admin@xxxxxxx
Subject: Re: Fw: [Bug 209427] New: Incorrect timestamp cause packet to be dropped
From: Eric Dumazet <eric.dumazet@xxxxxxxxx>
Date: Wed, 30 Sep 2020 09:29:22 +0200

On 9/29/20 7:35 PM, Stephen Hemminger wrote:
> 
> 
> Begin forwarded message:
> 
> Date: Tue, 29 Sep 2020 17:15:23 +0000
> From: bugzilla-daemon@xxxxxxxxxxxxxxxxxxx
> To: stephen@xxxxxxxxxxxxxxxxxx
> Subject: [Bug 209427] New: Incorrect timestamp cause packet to be dropped
> 
> 
> https://bugzilla.kernel.org/show_bug.cgi?id=209427
> 
>             Bug ID: 209427
>            Summary: Incorrect timestamp cause packet to be dropped
>            Product: Networking
>            Version: 2.5
>     Kernel Version: 5.8.10
>           Hardware: All
>                 OS: Linux
>               Tree: Mainline
>             Status: NEW
>           Severity: normal
>           Priority: P1
>          Component: Other
>           Assignee: stephen@xxxxxxxxxxxxxxxxxx
>           Reporter: abt-admin@xxxxxxx
>         Regression: No
> 
> After upgrading from my 3.10 to 5.8.10 I found out some of my packets are
> getting dropped by ipvlan interface (I'm using qdisk fq). Debugging session 
> led
> me to the place where this happens
> 
> net/sched/sch_fq.c:464
> ...
>         if (fq_packet_beyond_horizon(skb, q)) {
>                 if (q->horizon_drop) {
>                         q->stat_horizon_drops++;
>                         return qdisc_drop(skb, sch, to_free);
>                 }
>                 q->stat_horizon_caps++;
>                 skb->tstamp = q->ktime_cache + q->horizon;
>         }
> ...
> 
> then I noticed that in some cases skb->tstamp is equal to real ts whereas in
> the regular cases where a packet pass through it's time since kernel boot. 
> This
> doesn't make any sense for me as this condition is satisfied constantly
> 
> net/sched/sch_fq.c:439
> static bool fq_packet_beyond_horizon(const struct sk_buff *skb,
>                                     const struct fq_sched_data *q)
> {
>         return unlikely((s64)skb->tstamp > (s64)(q->ktime_cache + 
> q->horizon));
> }
> 
> Any ideas on what it can be?
> 
> some outputs:
>     [Tue Sep 29 14:59:06 2020] DBG: TIME: trid: -1081131982. all:
> q->ktime_cache 328453964122, skb->tstamp 1601391546982793177 <<
>     [Tue Sep 29 14:59:06 2020] DBG: TIME: trid: -1485308564. all:
> q->ktime_cache 334998110463, skb->tstamp 335012588783
>     ...
>     [Tue Sep 29 14:59:06 2020] DBG: TIME: trid: -1010372082. all:
> q->ktime_cache 335873778729, skb->tstamp 335741726080
>     [Tue Sep 29 14:59:06 2020] DBG: TIME: trid: 192888327. all: q->ktime_cache
> 335860696387, skb->tstamp 335870531339
>     [Tue Sep 29 14:59:07 2020] DBG: TIME: trid: -1463571809. all:
> q->ktime_cache 335305774517, skb->tstamp 1601391548109319017 <<
> 
>   perf trace: 
>     curl 32613 [014]  1546.957467: skb:kfree_skb: skbaddr=0xffff888f57159ae0
> protocol=2048 location=0xffffffff817bfdad
>                   9bfd56 kfree_skb (/lib/modules/5.8.10/build/vmlinux)
>                   9bfd56 kfree_skb (/lib/modules/5.8.10/build/vmlinux)
>                   9bfdad kfree_skb_list (/lib/modules/5.8.10/build/vmlinux)
>                   9da2b1 __dev_queue_xmit (/lib/modules/5.8.10/build/vmlinux)
>                   9da380 dev_queue_xmit (/lib/modules/5.8.10/build/vmlinux)
>                     1f39 vlan_dev_open ([8021q])
>                   9d9851 dev_hard_start_xmit
> (/lib/modules/5.8.10/build/vmlinux)
>                   9d9d05 __dev_queue_xmit (/lib/modules/5.8.10/build/vmlinux)
>                   9da380 dev_queue_xmit (/lib/modules/5.8.10/build/vmlinux)
>                   9d9d05 __dev_queue_xmit (/lib/modules/5.8.10/build/vmlinux)
>                   9da380 dev_queue_xmit (/lib/modules/5.8.10/build/vmlinux)
>                   9e32c3 neigh_connected_output
> (/lib/modules/5.8.10/build/vmlinux)
>                   a68cdb ip_finish_output2 (/lib/modules/5.8.10/build/vmlinux)
>                   a69b77 __ip_finish_output 
> (/lib/modules/5.8.10/build/vmlinux)
>                   a69cad ip_finish_output (/lib/modules/5.8.10/build/vmlinux)
>                   a6b65a ip_output (/lib/modules/5.8.10/build/vmlinux)
>                     f2e4 ip_vs_tunnel_xmit ([ip_vs])
>                     536a ip_vs_nat_icmp ([ip_vs])
>                     5913 ip_vs_out_icmp ([ip_vs])
>                     59c6 ip_vs_out_icmp ([ip_vs])
>                   a58255 nf_hook_slow (/lib/modules/5.8.10/build/vmlinux)
>                   a656f1 ip_local_deliver (/lib/modules/5.8.10/build/vmlinux)
>                   a64e07 ip_rcv_finish (/lib/modules/5.8.10/build/vmlinux)
>                   b717bb ip_sabotage_in (/lib/modules/5.8.10/build/vmlinux)
>                   a58255 nf_hook_slow (/lib/modules/5.8.10/build/vmlinux)
>                   a657a0 ip_rcv (/lib/modules/5.8.10/build/vmlinux)
>                   9db608 __netif_receive_skb_one_core
> (/lib/modules/5.8.10/build/vmlinux)
>                   9db658 __netif_receive_skb
> (/lib/modules/5.8.10/build/vmlinux)
>                   9db6e9 netif_receive_skb (/lib/modules/5.8.10/build/vmlinux)
>                   b5c5b6 br_netif_receive_skb
> (/lib/modules/5.8.10/build/vmlinux)
>                   b5c7d3 br_pass_frame_up (/lib/modules/5.8.10/build/vmlinux)
>                   b5c94d br_handle_frame_finish
> (/lib/modules/5.8.10/build/vmlinux)
>                   b7253b br_nf_hook_thresh (/lib/modules/5.8.10/build/vmlinux)
>                   b72fb0 br_nf_pre_routing_finish
> (/lib/modules/5.8.10/build/vmlinux)
>                   b733bc br_nf_pre_routing (/lib/modules/5.8.10/build/vmlinux)
>                   b5cdf1 br_handle_frame (/lib/modules/5.8.10/build/vmlinux)
>                   9da8c8 __netif_receive_skb_core
> (/lib/modules/5.8.10/build/vmlinux)
>                   9db5bf __netif_receive_skb_one_core
> (/lib/modules/5.8.10/build/vmlinux)
>                   9db658 __netif_receive_skb
> (/lib/modules/5.8.10/build/vmlinux)
>                   9db8a9 process_backlog (/lib/modules/5.8.10/build/vmlinux)
>                   9dd337 net_rx_action (/lib/modules/5.8.10/build/vmlinux)
>                   e000e1 __do_softirq (/lib/modules/5.8.10/build/vmlinux)
>                   c010c2 asm_call_on_stack (/lib/modules/5.8.10/build/vmlinux)
>                   235bef do_softirq_own_stack
> (/lib/modules/5.8.10/build/vmlinux)
>                   297f86 do_softirq.part.0 (/lib/modules/5.8.10/build/vmlinux)
>                   297fe0 __local_bh_enable_ip
> (/lib/modules/5.8.10/build/vmlinux)
>                   a68cef ip_finish_output2 (/lib/modules/5.8.10/build/vmlinux)
>                   a69b77 __ip_finish_output 
> (/lib/modules/5.8.10/build/vmlinux)
>                   a69cad ip_finish_output (/lib/modules/5.8.10/build/vmlinux)
>                   a6b65a ip_output (/lib/modules/5.8.10/build/vmlinux)
>                   a6ad4d ip_local_out (/lib/modules/5.8.10/build/vmlinux)
>                   a6b097 __ip_queue_xmit (/lib/modules/5.8.10/build/vmlinux)
>                   a8f740 ip_queue_xmit (/lib/modules/5.8.10/build/vmlinux)
>                   a89746 __tcp_transmit_skb 
> (/lib/modules/5.8.10/build/vmlinux)
>                   a8a5de tcp_connect (/lib/modules/5.8.10/build/vmlinux)
>                   a90f73 tcp_v4_connect (/lib/modules/5.8.10/build/vmlinux)
>                   aad59a __inet_stream_connect
> (/lib/modules/5.8.10/build/vmlinux)
>                   aad88b inet_stream_connect
> (/lib/modules/5.8.10/build/vmlinux)
>                   9b3e3f __sys_connect_file 
> (/lib/modules/5.8.10/build/vmlinux)
>                   9b3ef1 __sys_connect (/lib/modules/5.8.10/build/vmlinux)
>                   9b3f3a __x64_sys_connect (/lib/modules/5.8.10/build/vmlinux)
>                   b896b2 do_syscall_64 (/lib/modules/5.8.10/build/vmlinux)
>                   c0008c entry_SYSCALL_64 (/lib/modules/5.8.10/build/vmlinux)
>                    53878 [unknown] (/lib/ld-musl-x86_64.so.1)
>                        0 [unknown] ([unknown])
>                        0 [unknown] ([unknown])
> 

Thanks for the detailed report !

I suspect ipvs or bridge code needs something similar to the fixes done in 

https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/?id=de20900fbe1c4fd36de25a7a5a43223254ecf0d0

https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/?id=41d1c8839e5f8cb781cc635f12791decee8271b7

The reason for that is that skb->tstamp can get a timestamp in input path,
with a base which is not CLOCK_MONOTONIC, unfortunately.

Whenever a packet is forwarded, its tstamp must be cleared.

Can you try :

diff --git a/net/netfilter/ipvs/ip_vs_xmit.c b/net/netfilter/ipvs/ip_vs_xmit.c
index 
b00866d777fe0e9ed8018087ebc664c56f29b5c9..11e8ccdae358a89067046efa62ed40308b9e06f9
 100644
--- a/net/netfilter/ipvs/ip_vs_xmit.c
+++ b/net/netfilter/ipvs/ip_vs_xmit.c
@@ -952,6 +952,8 @@ ip_vs_prepare_tunneled_skb(struct sk_buff *skb, int skb_af,
 
        ip_vs_drop_early_demux_sk(skb);
 
+       skb->tstamp = 0;
+
        if (skb_headroom(skb) < max_headroom || skb_cloned(skb)) {
                new_skb = skb_realloc_headroom(skb, max_headroom);
                if (!new_skb)


<Prev in Thread] Current Thread [Next in Thread>