From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org X-Spam-Level: X-Spam-Status: No, score=-0.8 required=3.0 tests=DKIM_SIGNED,DKIM_VALID, DKIM_VALID_AU,FREEMAIL_FORGED_FROMDOMAIN,FREEMAIL_FROM, HEADER_FROM_DIFFERENT_DOMAINS,MAILING_LIST_MULTI,SPF_PASS autolearn=ham autolearn_force=no version=3.4.0 Received: from mail.kernel.org (mail.kernel.org [198.145.29.99]) by smtp.lore.kernel.org (Postfix) with ESMTP id B17E8C43381 for ; Tue, 12 Mar 2019 20:00:32 +0000 (UTC) Received: from vger.kernel.org (vger.kernel.org [209.132.180.67]) by mail.kernel.org (Postfix) with ESMTP id 5FFAD214D8 for ; Tue, 12 Mar 2019 20:00:32 +0000 (UTC) Authentication-Results: mail.kernel.org; dkim=pass (2048-bit key) header.d=gmail.com header.i=@gmail.com header.b="OW4EAJmU" Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1727203AbfCLUAb (ORCPT ); Tue, 12 Mar 2019 16:00:31 -0400 Received: from mail-wm1-f65.google.com ([209.85.128.65]:55951 "EHLO mail-wm1-f65.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1726775AbfCLUAb (ORCPT ); Tue, 12 Mar 2019 16:00:31 -0400 Received: by mail-wm1-f65.google.com with SMTP id 4so4002070wmf.5 for ; Tue, 12 Mar 2019 13:00:28 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20161025; h=mime-version:references:in-reply-to:from:date:message-id:subject:to :cc:content-transfer-encoding; bh=YgqRqg9AWRerL3/hv0qHGcf0QgwJPorqjXQToPIcXQA=; b=OW4EAJmUlhpxOEbwXw5VBH+gBNpIL4L93KDVbdYK4Q7rfX1uKhUhFmWoBR1tTcRrgG 1jtYEwreY6KrxCdOvQh/3DPhihciOjW8vEWDAq7vd06090aoapiIl6R5H1JcK8WjZS9A B0nfN+7qKSxVEyyOtfHxuGtajQ9zzOaFBigksGnMYiYtSR0iX2rlP/iYcl/5fZqQfY8X LLZubj7V6/5CAIeHYKHW+6MuOOXBp9Oo0Ad/0qUhXHlHkOIiYyzbCVDMeD8jS4s1MHls qUyUahTR33kmleJMTv4Ap2/73dEI3TV554dn8RzSM1M8bCQtBqn5ko4d/dJr0g1IizLd hN1g== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:mime-version:references:in-reply-to:from:date :message-id:subject:to:cc:content-transfer-encoding; bh=YgqRqg9AWRerL3/hv0qHGcf0QgwJPorqjXQToPIcXQA=; b=r2KjA2hhW+kCSyizOs2DT/H3thiBdOtDJ/38bz/7UBBi96+pPW2CEtKRmI6uV4Kyza caqfgflQdUy7jFUBy0mrOyhEtQA66O1hC5h+qaspXejvBJOo/8YEZO5RrgWit5rlHEPs Q7Tiz9+DOFjAIuCOD+wpKsv1jugcoIJyDAV2Au5cHu62CBUX0joP9tIe4I/c/yHhS6+b wd7niepyknyZSdOL9s1WIP0FN0P3fIHm1KOVpS5M5hYvI3OrqUlEnBAEyJnVGm0Tg14K INUCtT/6ci/J/Y91tDNxDM5COAaQVBVfpHYxlRi8j3U+AQ9uTEnhpyCqppdP6JLBHpeI 7NQw== X-Gm-Message-State: APjAAAUF4qPqsIrGn3yi7w++vw7Uupvr0Kj02mYD66MdiJUCe/r8+hEm +Oxhz68f2u01g7hIgR1FQUwZu9gizDg/qzkFmag= X-Google-Smtp-Source: APXvYqy+DKiafwzBBpzTqPd7F+K8ldJtGthGnkPD7u8uL03fVN7x7vxMoKYeWE0SARa1uvzhEedqgn3bqShMSVpeZFg= X-Received: by 2002:a1c:7306:: with SMTP id d6mr3236204wmb.40.1552420827857; Tue, 12 Mar 2019 13:00:27 -0700 (PDT) MIME-Version: 1.0 References: <20190228185758.6f37i2sfnr2mdrce@localhost> <02874ECE860811409154E81DA85FBB5892324F9C@ORSMSX121.amr.corp.intel.com> <02874ECE860811409154E81DA85FBB5892325034@ORSMSX121.amr.corp.intel.com> <02874ECE860811409154E81DA85FBB58923251BB@ORSMSX121.amr.corp.intel.com> In-Reply-To: <02874ECE860811409154E81DA85FBB58923251BB@ORSMSX121.amr.corp.intel.com> From: Paul Thomas Date: Tue, 12 Mar 2019 16:00:15 -0400 Message-ID: Subject: Re: [Linuxptp-devel] strangeness To: "Keller, Jacob E" , netdev@vger.kernel.org, Harini Katakam Cc: "linuxptp-devel@lists.sourceforge.net" Content-Type: text/plain; charset="UTF-8" Content-Transfer-Encoding: quoted-printable Sender: netdev-owner@vger.kernel.org Precedence: bulk List-ID: X-Mailing-List: netdev@vger.kernel.org On Tue, Mar 12, 2019 at 3:22 PM Keller, Jacob E wrote: > > > > > -----Original Message----- > > From: Paul Thomas [mailto:pthomas8589@gmail.com] > > Sent: Tuesday, March 12, 2019 10:50 AM > > To: Keller, Jacob E > > Cc: linuxptp-devel@lists.sourceforge.net > > Subject: Re: [Linuxptp-devel] strangeness > > > > On Tue, Mar 12, 2019 at 1:11 PM Keller, Jacob E > > wrote: > > > > > > > -----Original Message----- > > > > From: Paul Thomas [mailto:pthomas8589@gmail.com] > > > > Sent: Tuesday, March 12, 2019 10:00 AM > > > > To: Keller, Jacob E > > > > Subject: Re: [Linuxptp-devel] strangeness > > > > > > > > On Tue, Mar 12, 2019 at 12:26 PM Keller, Jacob E > > > > wrote: > > > > > > > > > > > -----Original Message----- > > > > > > From: netdev-owner@vger.kernel.org [mailto:netdev-owner@vger.ke= rnel.org] > > On > > > > > > Behalf Of Harini Katakam > > > > > > Sent: Tuesday, March 12, 2019 3:10 AM > > > > > > To: Paul Thomas > > > > > > Cc: linuxptp-devel@lists.sourceforge.net; netdev@vger.kernel.or= g > > > > > > Subject: Re: [Linuxptp-devel] strangeness > > > > > > > > > > > > Hi Paul, > > > > > > On Tue, Mar 12, 2019 at 8:26 AM Paul Thomas > > > > wrote: > > > > > > > > > > > > > > Hi All, > > > > > > > > > > > > > > Let me do a quick clean recap of this issue. > > > > > > > > > > > > > > On a Debian arm64 system with a 5.0rc8 kernel using the macb = driver on > > > > > > > zynqmp, enabling tx timestamping (1) breaks networking! The f= irst and > > > > > > > most noticeable way is that you can no longer connect with ss= h. This > > > > > > > is a serious bug somewhere and merits some attention. > > > > > > > > > > > > > > Trying to debug ssh is a possibility, but I was trying to deb= ug with > > > > > > > something easier and thus the netcat testing. The specific is= sue can > > > > > > > be seen in the following strace. In this setup nc just connec= ts to a > > > > > > > server and tries to send two packets (2). The first packet go= es > > > > > > > through fine, but the second doesn't because nc is stuck fore= ver > > > > > > > trying to read from the socket. > > > > > > > pselect6(4, [0 3], NULL, NULL, NULL, NULL) =3D 1 (in [0]) <--= waiting on > > > > > > > stdin and UDP sock > > > > > > > read(0, "c1\n", 8192) =3D 3 <-- read three chars from stdin > > > > > > > write(3, "c1\n", 3) =3D 3 <-- write those out on the UDP sock > > > > > > > pselect6(4, [0 3], NULL, NULL, NULL, NULL) =3D 1 (in [3]) <-= - waiting > > > > > > > on stdin and UDP sock > > > > > > > read(3, <-- waits forever here as there is no data to read > > > > > > > > > > > > > > I've been reading more, an old patch and the timestamping.txt= doc > > > > > > > helped me understand a little more of what's going on: > > > > > > > https://lore.kernel.org/netdev/20130328211925.7644.15781.stgi= t@jekeller- > > > > > > hub.jf.intel.com/ > > > > > > > https://www.kernel.org/doc/Documentation/networking/timestamp= ing.txt > > > > > > > > > > > > > > So it is clear that if the SO_SELECT_ERR_QUEUE flag is set th= en in > > > > > > > fact the select should return, but it is not set in this case= . I can > > > > > > > see everything that is going on in datagram_poll() in datagra= m.c. The > > > > > > > main difference being that in the broken case the mask is 0x3= 0c and in > > > > > > > the working case it is 0x304. The difference is EPOLLERR, whi= ch is > > > > > > > there clearly in the code if !skb_queue_empty(&sk->sk_error_q= ueue). > > > > > > > > > > > > > > Then in select.c POLLIN_SET includes EPOLLERR. It almost look= s as if > > > > > > > it's behaving as it should (except that things break). My fir= st > > > > > > > question is should the sk_error_queue be empty if there is a = tx > > > > > > > timestamp available (in datagram_poll() in datagram.c)? If it= 's not > > > > > > > empty I don't see what else SO_SELECT_ERR_QUEUE flag is doing= for the > > > > > > > select() and I don't see what would be different about the ma= cb/arm64 > > > > > > > setup? > > > > > > > > > > > > Thanks for the summary. > > > > > > I think sk_error_queue should be empty because packets are queu= ed to > > > > > > that via skb_complete_timestamp (sock_queue_err_skb) and this s= hould > > > > > > not be called in this flow. I'm sorry if I'm missing something = - I'll let others > > > > > > from netdev comment. > > > > > > I'm not sure why EPOLLERR in being set in this case. > > > > > > > > > > > > > > > > I believe at least historically that the Tx timestamps were notif= ied to the > > > > applications using the error queue. > > > > The documentation (Documentation/networking/timestamping.txt) says > > > > "recvmsg() with flag MSG_ERRQUEUE", so it's returned to userspace > > > > through the error queue, but at datagram_poll() in datagram.c: > > > > /* exceptional events? */ > > > > if (sk->sk_err || !skb_queue_empty(&sk->sk_error_queue)) > > > > > > > > Should this already be non-empty and EPOLLERR be returned as part o= f > > > > mask? Or should _only_ EPOLLPRI be returned when SOCK_SELECT_ERR_QU= EUE > > > > is true? Surly someone on this list knows what should be happening?= It > > > > will help direct where we are looking. Should we be looking at the > > > > queues? Or should be looking at do_select() in fs/select.c or > > > > somewhere else? > > > > > > > > > > > HI Jake, > > Thanks for looking at this. > > > > > It's been quite some time since I looked at this. Hmm. Can you reprod= uce this with > > another board? I haven't seen the issue before. > > > > > > I remember adding SO_SELECT_ERR_QUEUE as an option, and it made the s= ocket > > wake up when a Tx timestamp occurred. I believe this was eventually fix= ed in a more > > direct way, and now the socket option doesn't really do much. > > > > > > See Linux commit 7d4c04fc1700 ("net: add option to enable error queue= packets > > waking select", 2013-03-31) > > That looks like your netdev patch, and the text makes sense. > > > > > > Basically, the option now just adds POLLPRI along with POLLERR when t= he Tx > > timestamp is ready, and the socket will wake up when there is a Timesta= mp. > > > > > > This was eventually fixed so that you could select on just POLLERR, a= nd have it > > actually wake up on the error messages, and the option was no longer ne= cessary. > > Ah, so is selecting on POLLERR a seperate flag? > > > > > > > > That's what I recall about SO_SELECT_ERR_QUEUE at least. > > > > > > So.. to clarify the behavior you're seeing is that the socket wakes u= p on pselect, and > > then you go to read it, but it never returns because there's no data av= ailable? And the > > socket woke up because there was an error, but the error queue is also = empty? > > The tx timestams are enabled globally across the system with > > hwstamp_ctl, there is just one option on or off. The issue seems to be > > with applications that are not expecting select to return on POLLERR. > > This certainly the case with netcat, and I suspect it is a similar > > thing that breaks ssh. I haven't checked if there is actually a tx > > timestamp in the error queue for the nc case (probably is). But maybe > > this points us in the right direction for a specific socket if the > > SOF_TIMESTAMPING_TX_HARDWARE option hasn't been requested should the > > timestamps be pushed to the error queue in the first place? > > > > thanks, > > Paul > > Hmm. I haven't been able to reproduce this using other device drivers, so= I wonder if the specific device driver is doing something weird and indica= ting that it can Tx timestamp every packet, in its hard_xmit routine... But= it should only be doing that for packets which are requested to timestamp = from the socket. Yes! I think this could be it. I just submitted this patch so that we can talk about it: https://lore.kernel.org/netdev/20190312195053.21741-1-pthomas8589@gmail.com= / This fixes the issue I'm having with nc and ssh. -Paul > > Thanks, > Jake > > > > > > > > > Thanks, > > > Jake > > > > > > > thanks, > > > > Paul > > > > > > > > > Thanks, > > > > > Jake