Received-SPF: pass (google.com: best guess record for domain of linux-kernel-owner@vger.kernel.org designates 209.132.180.67 as permitted sender) client-ip=209.132.180.67;
From:   Roman Gushchin <guro@fb.com>
To:     Bruce Ashfield <bruce.ashfield@gmail.com>
CC:     "linux-kernel@vger.kernel.org" <linux-kernel@vger.kernel.org>,
        "tj@kernel.org" <tj@kernel.org>,
        Richard Purdie <richard.purdie@linuxfoundation.org>,
        "oleg@redhat.com" <oleg@redhat.com>
Subject: Re: ptrace/strace and freezer oddities and v5.2+ kernels
Thread-Topic: ptrace/strace and freezer oddities and v5.2+ kernels
Thread-Index: AQHVeHNRdeEItaYf7UK2FXG2TrAmk6dGmZIAgAAmiACAAOrJAIAAPZIAgAG2jICABYy1AIAAehiAgAA2+wA=
Date:   Mon, 7 Oct 2019 23:27:58 +0000
Message-ID: <20191007232754.GB11171@tower.DHCP.thefacebook.com>
References: <CADkTA4PBT374CY+UNb85WjQEaNCDodMZu=MgpG8aMYbAu2eOGA@mail.gmail.com>
 <20191002020100.GA6436@castle.dhcp.thefacebook.com>
 <CADkTA4Mbai=Q5xgKH9-md_g73UsHiKnEauVgMWev+-sG8FVNSA@mail.gmail.com>
 <20191002181914.GA7617@castle.DHCP.thefacebook.com>
 <CADkTA4PmGBR7YdOXvi6sEDJ+uztuB7x2G95TCcW2u_iqjwhUNQ@mail.gmail.com>
 <20191004000913.GA5519@castle.DHCP.thefacebook.com>
 <CADkTA4OJok3cmYCcDKtxBXQ5xtK1EMujh7_AgLnVaeRr18TH9w@mail.gmail.com>
 <CADkTA4PKc6VEQYvXk4-EWMJPyOrzWQEsk4p6O_BMFo6kvT2jYg@mail.gmail.com>
In-Reply-To: <CADkTA4PKc6VEQYvXk4-EWMJPyOrzWQEsk4p6O_BMFo6kvT2jYg@mail.gmail.com>
Accept-Language: en-US
Content-Language: en-US
x-ms-exchange-messagesentrepresentingtype: 1
x-originating-ip: [2620:10d:c090:200::3:2a00]
x-ms-publictraffictype: Email
x-ms-office365-filtering-correlation-id: 3c726fd7-ef33-478c-fcae-08d74b7dfcda
x-ms-traffictypediagnostic: BN8PR15MB2531:
x-ms-exchange-purlcount: 2
x-microsoft-antispam-prvs: <BN8PR15MB253192B5009D7E139AB556A1BE9B0@BN8PR15MB2531.namprd15.prod.outlook.com>
x-ms-oob-tlc-oobclassifiers: OLM:10000;
x-forefront-prvs: 01834E39B7
x-forefront-antispam-report: SFV:NSPM;SFS:(10019020)(39860400002)(346002)(136003)(376002)(366004)(396003)(189003)(199004)(76274002)(51914003)(53754006)(6486002)(99286004)(6512007)(476003)(81156014)(8936002)(305945005)(86362001)(66946007)(8676002)(7736002)(66556008)(64756008)(66446008)(66476007)(6916009)(81166006)(2906002)(9686003)(6306002)(33656002)(5660300002)(6246003)(186003)(229853002)(446003)(11346002)(486006)(46003)(52116002)(102836004)(6506007)(6116002)(53546011)(1076003)(76176011)(386003)(6436002)(4326008)(14444005)(256004)(71190400001)(71200400001)(25786009)(966005)(54906003)(478600001)(14454004)(316002);DIR:OUT;SFP:1102;SCL:1;SRVR:BN8PR15MB2531;H:BN8PR15MB2626.namprd15.prod.outlook.com;FPR:;SPF:None;LANG:en;PTR:InfoNoRecords;MX:1;A:1;
received-spf: None (protection.outlook.com: fb.com does not designate
 permitted sender hosts)
x-ms-exchange-senderadcheck: 1
x-microsoft-antispam: BCL:0;
x-microsoft-antispam-message-info: Krj7aOidcaTEq+JtxqttMsgbJDaxmdOyAWNz0yNkp1YYx4qsyHAaYO2VZCZJ3l1YzmcDBnxUVMpkpaElpjOEEk5ij3e8uc3dOcK4T0x1JPH4e+J3K5hZBROjet0/WM51RSQnv1+9NOEapsHWVM4RDGtDa5BRWmGpL8VIrznA49Bh2tda9pb5MW7YCGWLx1urVW1Rb5JWFKghEEECJVIij5HUCVOLbj31uBf7jTqzhXOuoLoUdJ+PkGp9wdhvHm3ZKYBiKSDdwg35jmIGhzyF/pS9iKWR1uq11nRxGHJKyuP/c7I6VOeq3Di0vbmJfjRLwVF9rXXD7xZaWgtezvNv3tJSGncOdP26yArFQ3eeJCMJ5PSsVY8maDB45wFp6+Dl68yeNB9GBiypPh2TmKTQiV9+ew5xQ+jcjrg1D/fK/dG0HdUZPKyAGu4EIg0N1OlwD61mOKF73ba9/51qw+t9hg==
x-ms-exchange-transport-forked: True
Content-Type: text/plain; charset="us-ascii"
Content-ID: <80C4821D4B07BF419F438989734FD307@namprd15.prod.outlook.com>
Content-Transfer-Encoding: quoted-printable
MIME-Version: 1.0
X-MS-Exchange-CrossTenant-Network-Message-Id: 3c726fd7-ef33-478c-fcae-08d74b7dfcda
X-MS-Exchange-CrossTenant-originalarrivaltime: 07 Oct 2019 23:27:58.3878
 (UTC)
X-MS-Exchange-CrossTenant-fromentityheader: Hosted
X-MS-Exchange-CrossTenant-id: 8ae927fe-1255-47a7-a2af-5f3a069daaa2
X-MS-Exchange-CrossTenant-mailboxtype: HOSTED
X-MS-Exchange-CrossTenant-userprincipalname: XNy+RMLeinMGI3KTR0s+HcKa4E3rYqjIsU4s8Xjiyet50jUHmi6okqwzfBTapEFM
X-MS-Exchange-Transport-CrossTenantHeadersStamped: BN8PR15MB2531
X-OriginatorOrg: fb.com
X-Proofpoint-Virus-Version: vendor=fsecure engine=2.50.10434:6.0.95,1.0.8
 definitions=2019-10-07_04:2019-10-07,2019-10-07 signatures=0
X-Proofpoint-Spam-Details: rule=fb_default_notspam policy=fb_default score=0 phishscore=0
 mlxlogscore=999 suspectscore=0 clxscore=1015 lowpriorityscore=0
 priorityscore=1501 malwarescore=0 spamscore=0 mlxscore=0 adultscore=0
 bulkscore=0 impostorscore=0 classifier=spam adjust=0 reason=mlx
 scancount=1 engine=8.12.0-1908290000 definitions=main-1910070210
X-FB-Internal: deliver
Sender: linux-kernel-owner@vger.kernel.org
Precedence: bulk
List-ID: <linux-kernel.vger.kernel.org>
X-Mailing-List: linux-kernel@vger.kernel.org

On Mon, Oct 07, 2019 at 04:11:07PM -0400, Bruce Ashfield wrote:
> On Mon, Oct 7, 2019 at 8:54 AM Bruce Ashfield <bruce.ashfield@gmail.com> =
wrote:
> >
> > On Thu, Oct 3, 2019 at 8:09 PM Roman Gushchin <guro@fb.com> wrote:
> > >
> > > On Wed, Oct 02, 2019 at 05:59:36PM -0400, Bruce Ashfield wrote:
> > > > On Wed, Oct 2, 2019 at 2:19 PM Roman Gushchin <guro@fb.com> wrote:
> > > > >
> > > > > On Wed, Oct 02, 2019 at 12:18:54AM -0400, Bruce Ashfield wrote:
> > > > > > On Tue, Oct 1, 2019 at 10:01 PM Roman Gushchin <guro@fb.com> wr=
ote:
> > > > > > >
> > > > > > > On Tue, Oct 01, 2019 at 12:14:18PM -0400, Bruce Ashfield wrot=
e:
> > > > > > > > Hi all,
> > > > > > > >
> > > > > > >
> > > > > > > Hi Bruce!
> > > > > > >
> > > > > > > > The Yocto project has an upcoming release this fall, and I'=
ve been trying to
> > > > > > > > sort through some issues that are happening with kernel 5.2=
+ .. although
> > > > > > > > there is a specific yocto kernel, I'm testing and seeing th=
is with
> > > > > > > > normal / vanilla
> > > > > > > > mainline kernels as well.
> > > > > > > >
> > > > > > > > I'm running into an issue that is *very* similar to the one=
 discussed in the
> > > > > > > > [REGRESSION] ptrace broken from "cgroup: cgroup v2 freezer"=
 (76f969e)
> > > > > > > > thread from this past may: https://lkml.org/lkml/2019/5/12/=
272
> > > > > > > >
> > > > > > > > I can confirm that I have the proposed fix for the initial =
regression report in
> > > > > > > > my build (05b2892637 [signal: unconditionally leave the fro=
zen state
> > > > > > > > in ptrace_stop()]),
> > > > > > > > but yet I'm still seeing 3 or 4 minute runtimes on a test t=
hat used to take 3 or
> > > > > > > > 4 seconds.
> > > > > > >
> > > > > > > So, the problem is that you're experiencing a severe performa=
nce regression
> > > > > > > in some test, right?
> > > > > >
> > > > > > Hi Roman,
> > > > > >
> > > > > > Correct. In particular, running some of the tests that ship wit=
h strace itself.
> > > > > > The performance change is so drastic, that it definitely makes =
you wonder
> > > > > > "What have I done wrong? Since everyone must be seeing this" ..=
 and I
> > > > > > always blame myself first.
> > > > > >
> > > > > > >
> > > > > > > >
> > > > > > > > This isn't my normal area of kernel hacking, so I've so far=
 come up empty
> > > > > > > > at either fixing it myself, or figuring out a viable workar=
ound. (well, I can
> > > > > > > > "fix" it by remove the cgroup_enter_frozen() call in ptrace=
_stop ...
> > > > > > > > but obviously,
> > > > > > > > that is just me trying to figure out what could be causing =
the issue).
> > > > > > > >
> > > > > > > > As part of the release, we run tests that come with various=
 applications. The
> > > > > > > > ptrace test that is causing us issues can be boiled down to=
 this:
> > > > > > > >
> > > > > > > > $ cd /usr/lib/strace/ptest/tests
> > > > > > > > $ time ../strace -o log -qq -esignal=3Dnone -e/clock ./prin=
tpath-umovestr>ttt
> > > > > > > >
> > > > > > > > (I can provide as many details as needed, but I wanted to k=
eep this initial
> > > > > > > > email relatively short).
> > > > > > > >
> > > > > > > > I'll continue to debug and attempt to fix this myself, but =
I grabbed the
> > > > > > > > email list from the regression report in May to see if anyo=
ne has any ideas
> > > > > > > > or angles that I haven't covered in my search for a fix.
> > > > > > >
> > > > > > > I'm definitely happy to help, but it's a bit hard to say anyt=
hing from what
> > > > > > > you've provided. I'm not aware of any open issues with the fr=
eezer except
> > > > > > > some spurious cgroup frozen<->not frozen transitions which ca=
n happen in some
> > > > > > > cases. If you'll describe how can I reproduce the issue, and =
I'll try to take
> > > > > > > a look asap.
> > > > > >
> > > > > > That would be great.
> > > > > >
> > > > > > I'll attempt to remove all of the build system specifics out of=
 this
> > > > > > (and Richard Purdie
> > > > > > on the cc' of this can probably help provide more details / set=
up info as well).
> > > > > >
> > > > > > We are running the built-in tests of strace. So here's a cut an=
d paste of what I
> > > > > > did to get the tests available (ignore/skip what is common sens=
e or isn't needed
> > > > > > in your test rig).
> > > > > >
> > > > > > % git clone https://github.com/strace/strace.git
> > > > > > % cd strace
> > > > > > % ./bootstrap
> > > > > > # the --enable flag isn't strictly required, but may break on s=
ome
> > > > > > build machines
> > > > > > % ./configure --enable-mpers=3Dno
> > > > > > % make
> > > > > > % make check-TESTS
> > > > > >
> > > > > > That last step will not only build the tests, but run them all =
.. so
> > > > > > ^c the run once
> > > > > > it starts, since it is a lot of noise (we carry a patch to stra=
ce that
> > > > > > allows us to build
> > > > > > the tests without running them).
> > > > > >
> > > > > > % cd tests
> > > > > > % time strace -o log -qq -esignal=3Dnone -e/clock ./printpath-u=
movestr > fff
> > > > > > real    0m2.566s
> > > > > > user    0m0.284s
> > > > > > sys     0m2.519
> > > > > >
> > > > > > On pre-cgroup2 freezer kernels, you see a run time similar to w=
hat I have above.
> > > > > > On the newer kernels we are testing, it is taking 3 or 4 minute=
s to
> > > > > > run the test.
> > > > > >
> > > > > > I hope that is simple enough to setup and try. Since I've been =
seeing
> > > > > > this on both
> > > > > > mainline kernels and the yocto reference kernels, I don't think=
 it is
> > > > > > something that
> > > > > > I'm carrying in the distro/reference kernel that is causing thi=
s (but
> > > > > > again, I always
> > > > > > blame myself first). If you don't see that same run time, then =
that
> > > > > > does point the finger
> > > > > > back at what we are doing and I'll have to apologize for chewin=
g up some of your
> > > > > > time.
> > > > >
> > > > > Thank you for the detailed description!
> > > > > I'll try to reproduce the issue and will be back
> > > > > by the end of the week.
> > > >
> > > > Thanks again!
> > > >
> > > > While discussing the issue with a few yocto folks today, it came up=
 that
> > > > someone wasn't seeing the same behaviour on the opensuse v5.2 kerne=
l
> > > > (but I've yet to figure out exactly where to find that tree) .. but=
 when I do,
> > > > I'll try and confirm that and will look for patches or config diffe=
rences that
> > > > could explain the results.
> > > >
> > > > I did confirm that 5.3 shows the same thing today, and I'll do a 5.=
4-rc1 test
> > > > tomorrow.
> > > >
> > > > We are also primarily reproducing the issue on qemux86-64, so I'm a=
lso
> > > > going to try and rule out qemu (but the same version of qemu with j=
ust
> > > > the kernel changing shows the issue).
> > >
> > > Hi Bruce!
> > >
> > > I've tried to follow your steps, but unfortunately failed to reproduc=
e the issue.
> > > I've executed the test on my desktop running 5.2 and cgroup v1 (Fedor=
a 30),
> > > and also a qemu vm with vanilla 5.1 and 5.3 and cgroup v2 mounted by =
default.
> > > In all cases the test execution time was about 4.5 seconds.
> >
> > Hi Roman,
> >
> > Thanks for the time you spent on this. I had *thought* that I ruled out=
 my
> > config before posting .. but clearly, it is either not my config or som=
ething
> > else in the environment.
> >
> > >
> > > Looks like something makes your setup special. If you'll provide your
> > > build config, qemu arguments or any other configuration files, I can =
try
> > > to reproduce it on my side.
> >
> > Indeed. I'm going to dive back in and see what I can find. If I can
> > find something
> > that is reproducible in a completely different environment and easy to =
configure
> > components, I'll follow up with details.
> >
> > When I figure out what is going on with the config here, I'll follow up=
 as well,
> > so the solution can be captured in any archives.
>=20
> Actually, now that I think about it.
>=20
> Would it be possible to see the .config that you used for testing (and ev=
en how
> you launched the VM) ?.
>=20
> I just built a 5.2.17 kernel and the long runtimes persist here. I'm not =
seeing
> anything in my .config that is jumping out, and am now looking at how we =
are
> launching qemu .. but it would be helpful to have a known good baseline f=
or
> comparison.
>=20
> If you've already tossed that config, no worries, I'll muddle along
> and figure it
> out eventually.

Hi Bruce!

Can you, please, try to reproduce it on a fresh Fedora (or any other public
distro) installation? I've tried to reproduce it on my Fedora 30 running 5.=
2,
and wasn't successful.

Thanks!

PS I don't have that particular config by me now, will try to find and send
to you.