Re: [PATCH] fs/exec.c: Add fast path for ENOENT on PATH search before allocating mm

[Mateusz Guzik]

On 11/8/23, Kees Cook <keescook@xxxxxxxxxxxx> wrote:
> On Wed, Nov 08, 2023 at 01:03:33AM +0100, Mateusz Guzik wrote:
>> On 11/8/23, Kees Cook <kees@xxxxxxxxxx> wrote:
>> >
>> >
>> > On November 7, 2023 3:08:47 PM PST, Mateusz Guzik <mjguzik@xxxxxxxxx>
>> > wrote:
>> >>On 11/7/23, Kees Cook <keescook@xxxxxxxxxxxx> wrote:
>> >>> On Tue, Nov 07, 2023 at 10:23:16PM +0100, Mateusz Guzik wrote:
>> >>>> If the patch which dodges second lookup still somehow appears slower
>> >>>> a
>> >>>> flamegraph or other profile would be nice. I can volunteer to take a
>> >>>> look at what's going on provided above measurements will be done and
>> >>>> show funkyness.
>> >>>
>> >>> When I looked at this last, it seemed like all the work done in
>> >>> do_filp_open() (my patch, which moved the lookup earlier) was heavier
>> >>> than the duplicate filename_lookup().
>> >>>
>> >>> What I didn't test was moving the sched_exec() before the mm
>> >>> creation,
>> >>> which Peter confirmed shouldn't be a problem, but I think that might
>> >>> be
>> >>> only a tiny benefit, if at all.
>> >>>
>> >>> If you can do some comparisons, that would be great; it always takes
>> >>> me
>> >>> a fair bit of time to get set up for flame graph generation, etc. :)
>> >>>
>> >>
>> >>So I spawned *one* process executing one statocally linked binary in a
>> >>loop, test case from http://apollo.backplane.com/DFlyMisc/doexec.c .
>> >>
>> >>The profile is definitely not what I expected:
>> >>   5.85%  [kernel]           [k] asm_exc_page_fault
>> >>   5.84%  [kernel]           [k] __pv_queued_spin_lock_slowpath
>> >>[snip]
>> >>
>> >>I'm going to have to recompile with lock profiling, meanwhile
>> >>according to bpftrace
>> >>(bpftrace -e 'kprobe:__pv_queued_spin_lock_slowpath { @[kstack()] =
>> >> count(); }')
>> >>top hits would be:
>> >>
>> >>@[
>> >>    __pv_queued_spin_lock_slowpath+1
>> >>    _raw_spin_lock+37
>> >>    __schedule+192
>> >>    schedule_idle+38
>> >>    do_idle+366
>> >>    cpu_startup_entry+38
>> >>    start_secondary+282
>> >>    secondary_startup_64_no_verify+381
>> >>]: 181
>> >>@[
>> >>    __pv_queued_spin_lock_slowpath+1
>> >>    _raw_spin_lock_irq+43
>> >>    wait_for_completion+141
>> >>    stop_one_cpu+127
>> >>    sched_exec+165
>> >
>> > There's the suspicious sched_exec() I was talking about! :)
>> >
>> > I think it needs to be moved, and perhaps _later_ instead of earlier?
>> > Hmm...
>> >
>>
>> I'm getting around 3.4k execs/s. However, if I "taskset -c 3
>> ./static-doexec 1" the number goes up to about 9.5k and lock
>> contention disappears from the profile. So off hand looks like the
>> task is walking around the box when it perhaps could be avoided -- it
>> is idle apart from running the test. Again this is going to require a
>> serious look instead of ad hoc pokes.
>
> Peter, is this something you can speak to? It seems like execve() forces
> a change in running CPU. Is this really something we want to be doing?
> Or is there some better way to keep it on the same CPU unless there is
> contention?
>

sched_exec causes migration only for only few % of execs in the bench,
but when it does happen there is tons of overhead elsewhere.

I expect real programs which get past execve will be prone to
migrating anyway, regardless of what sched_exec is doing.

That is to say, while sched_exec buggering off here would be nice, I
think for real-world wins the thing to investigate is the overhead
which comes from migration to begin with.

-- 
Mateusz Guzik <mjguzik gmail.com>