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

lvs-devel.vger.kernel.org archive mirror
 help / color / mirror / Atom feed

* Re: Fw: [Bug 209427] New: Incorrect timestamp cause packet to be dropped
       [not found] <20200929103532.0ecbc3b3@hermes.local>
@ 2020-09-30  7:29 ` Eric Dumazet
  2020-09-30 17:17   ` Julian Anastasov
  0 siblings, 1 reply; 3+ messages in thread
From: Eric Dumazet @ 2020-09-30  7:29 UTC (permalink / raw)
  To: Stephen Hemminger, netdev, Julian Anastasov,
	lvs-devel@vger.kernel.org, abt-admin



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@bugzilla.kernel.org
> To: stephen@networkplumber.org
> 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@networkplumber.org
>           Reporter: abt-admin@mail.ru
>         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)


^ permalink raw reply related	[flat|nested] 3+ messages in thread

* Re: Fw: [Bug 209427] New: Incorrect timestamp cause packet to be dropped
  2020-09-30  7:29 ` Fw: [Bug 209427] New: Incorrect timestamp cause packet to be dropped Eric Dumazet
@ 2020-09-30 17:17   ` Julian Anastasov
  2020-10-09 10:22     ` Evgeny B
  0 siblings, 1 reply; 3+ messages in thread
From: Julian Anastasov @ 2020-09-30 17:17 UTC (permalink / raw)
  To: Eric Dumazet
  Cc: Stephen Hemminger, netdev, lvs-devel@vger.kernel.org, abt-admin


	Hello,

On Wed, 30 Sep 2020, Eric Dumazet wrote:

> On 9/29/20 7:35 PM, Stephen Hemminger wrote:
> > 
> > 
> > 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?
> > 
> 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;
> +

	Should be after all skb_forward_csum() calls in ip_vs_xmit.c

>         if (skb_headroom(skb) < max_headroom || skb_cloned(skb)) {
>                 new_skb = skb_realloc_headroom(skb, max_headroom);
>                 if (!new_skb)

Regards

--
Julian Anastasov <ja@ssi.bg>


^ permalink raw reply	[flat|nested] 3+ messages in thread

* Re: Fw: [Bug 209427] New: Incorrect timestamp cause packet to be dropped
  2020-09-30 17:17   ` Julian Anastasov
@ 2020-10-09 10:22     ` Evgeny B
  0 siblings, 0 replies; 3+ messages in thread
From: Evgeny B @ 2020-10-09 10:22 UTC (permalink / raw)
  Cc: Stephen Hemminger, netdev, lvs-devel@vger.kernel.org

I just realized all my messages were bounced by mail server, this is 
last try


This fix works, however they should be applied for each of ipvs_xmit 
functions (e.g. ip_vs_nat_xmit(), ip_vs_dr_xmit(), etc.)

I look forward to seeing the patch in ml-5.x

Thank you!


On 9/30/2020 8:17 PM, Julian Anastasov wrote:
> 	Hello,
>
> On Wed, 30 Sep 2020, Eric Dumazet wrote:
>
>> On 9/29/20 7:35 PM, Stephen Hemminger wrote:
>>>
>>> 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?
>>>
>> 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;
>> +
> 	Should be after all skb_forward_csum() calls in ip_vs_xmit.c
>
>>          if (skb_headroom(skb) < max_headroom || skb_cloned(skb)) {
>>                  new_skb = skb_realloc_headroom(skb, max_headroom);
>>                  if (!new_skb)
> Regards
>
> --
> Julian Anastasov <ja@ssi.bg>
>

^ permalink raw reply	[flat|nested] 3+ messages in thread

end of thread, other threads:[~2020-10-09 10:22 UTC | newest]

Thread overview: 3+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
     [not found] <20200929103532.0ecbc3b3@hermes.local>
2020-09-30  7:29 ` Fw: [Bug 209427] New: Incorrect timestamp cause packet to be dropped Eric Dumazet
2020-09-30 17:17   ` Julian Anastasov
2020-10-09 10:22     ` Evgeny B

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).