Re: [PATCH] module: add debugging auto-load duplicate module support

[Lucas De Marchi]

On Fri, Apr 21, 2023 at 10:38:49AM -0700, Luis Chamberlain wrote:
> On Fri, Apr 21, 2023 at 09:42:39AM -0700, Lucas De Marchi wrote:
> > On Fri, Apr 21, 2023 at 05:12:51PM +0200, Greg KH wrote:
> > > On Thu, Apr 20, 2023 at 02:03:32PM -0700, Luis Chamberlain wrote:
> > > udev is just the transport to kmod here, it's not in the job of
> > > filtering duplicate messages.
> >
> > udev nowadays use *lib*kmod. It's udev who has the
> > context it can operate on.
> >
> > Also, those module loads will not use the path this patch is changing
> > call_modprobe is not the path that triggers udev to load modules.
> > /me confused
>
> This patch prooves that module auto-loading (request_modue() calls) and
> so the /sbin/modprobe calls are *not* the issue. That is why udev was
> the next candidate consideration.

that makes more sense.

> > What can be done from userspace in the udev path
> >
> > 1) udev to do the ratelimit'ing. Define a time window,
> > filter out uevents in systemd/src/udev/udev-builtin-kmod.c
> >
> > 2) libkmod to do the ratelimit'ing with a similar approach, but udev
> > needs to tell libkmod what is the window it wants to use
> >
> > 3) libkmod to act on the context it has from the *kernel*. It used
> > to be cheap with the call simply blocking early on the syscall in
> > a mutex... or we didn't have that many calls. So libkmod
> > simply calls [f]init_module() again regardless of the module's
> > state being in a "coming" state.  Is this the case here?
>
> I only got so far as to also confirm libkmod is used, so if libkmod
> does that check then this is already done, but the issue I think is
> that I think that the races are so much that you still get duplicates.
> So even if the check is done there are so many parallel calls that
> the check doesn't help as the module won't be loaded for a while.
>
> > I haven't seen this data.
>
> Just build a modules-next [0] kernel with the new CONFIG_MODULE_STATS
> and after boot cat /sys/kernel/debug/modules/stats. Then increase
> the number of CPUs on the system by 2 and try again. Then enable
> the new MODULE_DEBUG_AUTOLOAD_DUPS which I just pushed to modules-next
> and see how many duplicates you see. If you don't see many then that
> means the other source for duplicates should be udev.
>
> [0] https://git.kernel.org/pub/scm/linux/kernel/git/mcgrof/linux.git/log/?h=modules-next
>
> > This is done to avoid a) the toctou implied and b) to
> > provide the correct return for that call - libkmod can't know if the
> > previous call will succeed or fail.
>
> Just as with the kludge-of-concept I posted for kread [0], userspace
> also should have similar issues in mapping module name to arbitrary
> file names given:
>
>  o a module can be in different paths and libkmod could for
>     example at one point load a module in one path, then userspace
>     removes it, and the next path is used.

no, it can't. Unless you are doing out of tree modules and loading them
manually by path. There can only be one module with the same name in kmod's
database. If you have duplicate modules, depmod will use the dir
priority configured by the distro (see depmod.d(5)).

Since we are talking about *udev* it's not a real possibility as
1) the udev requests are serialized
2) there is only 1 kmod ctx, so they use the same configuration, no
funky kmod_new("/another-rootfs", ...) type of thing.

>  o module names may differ from the filename slightly (in the kernel
>    we replace dash with "_", refer to KBUILD_MODNAME

this is taken care by depmod/libkmod too. All the aliases are mapped to
module names and then normalized. See modname_normalize() in kmod.

> So the only thing it could do is use the full path of the module used to
> deter duplicates. Then, it could actually converge duplicate requests and
> share the results just as my kludge-of-concept did.

this is assuming you are loading modules by path from random places.
It's not what udev does.

> [1] https://lore.kernel.org/all/ZDmAvwi+KNvie+OI@xxxxxxxxxxxxxxxxxxxxxx/T/#md172510af8fdf7e0f76f6caafee9c99f7a8b6de7
>
> > libkmod only skips the call if the module is already in
> > the live state.
>
> It can do better, it can converge requests to avoid a kernel_read*()
> from using vmalloc space. Note that this was not well known before,
> but now it is clear.

in userspace, if using the same context and using init_module() rather
than finit_module(), I **guess** we would have a similar thing due to
the memory pool for modules: we don't read the module again. That is not
true for finit_module() though as we just open and pass the fd.

> I realize though that this could mean sharing a context between all
> loads thoughs in udev, and such a change could take significant time
> and review to complete.

But there is only one context. There aren't multiple paralell requests
from multiple sources. Probably need to Cc someone still changing
udev's builtin...  but from a quick look, from what I remember about
that the last time I touched it and without data to prove me wrong,
it seems we are not looking at the right problem space to come up with a
solution.

> If we *wanted* to do this in kernel instead, I have already shown it's
> not hard.
>
> > It seems systemd-udev also duplicates the check
> > in src/shared/module-util.c:module_load_and_warn()
>
> Evidence is showing that does not suffice for the races which are
> currently possible.

can you raise the udev verbosity and share? All the kmod-builtin
calls will already be logged there. See
src/udev/udev-event.c:udev_event_execute_run() leading to

	log_device_debug(event->dev, "Running built-in command \"%s\"", command);
	r = udev_builtin_run(event->dev, &event->rtnl, builtin_cmd, command, false);

if you are rather seeing "Running command", ohh... then your udev was
built without libkmod and it will just fork/exec. Not what we want.

> > Note that libkmod already spares loading the module multiple times from
> > disk as it uses a memory pool for the modules. It reuses one iff it
> > comes from the same context (i.e. it's only udev involved and not a
> > bunch of parallel calls to modprobe).
>
> If a different context is used its not shared.

see above.

> > 4) If all the calls are coming from the same context and it is udev...
> > I'm not sure this is actually the problem - the udev's kmod builtin
> > handler is single-threaded and will handle one request at a time.
> > I don't see any data to confirm it's coming from a single source or
> > multiple sources. Could you get a trace containing [f]init_module and
> > the trace_module_request(), together with a verbose udev log?
> >
> > If this is all coming from a synthetic use case with thousands of
> > modprobe execs, I'm not sure there is much to do on the userspace side.
>
> It's not synthetic, I rested simply increasing the number of CPUs on a
> system, you can use kdevops for that if you want to try.
>
> > > > > Why not
> > > > > just rate-limit it in userspace if your system can't handle 10's of
> > > > > thousands of kmod calls all at once? I think many s390 systems did this
> > > > > decades ago when they were controlling 10's of thousands of scsi devices
> > > > > and were hit with "device detection storms" at boot like this.
> > > >
> > > > Boot is a special context and in this particular case I agree userspace
> > > > kmod could/should be extended to avoid duplicate module requests in that
> >
> > see above
> >
> > > > context. But likewise the kernel should only have to try to issue a
> > > > request for a single module once, if it could easily do that.
> > >
> > > Are you sure that this is happening at boot in a way that userspace
> > > didn't just trigger it on its own after init started up?  That happens
> > > as a "coldboot" walk of the device tree and all uevent are regenerated.
> > > That is userspace asking for this, so there's nothing that the kernel
> > > can do.
> > >
> > > > This does beg the question, why force userspace to rate limit if we
> > > > can do better in the kernel? Specially if *we're the ones*, as you say,
> > > > that are hinting to userspace to shoot back loading modules for us and we
> > > > know we're just going to drop duplicates?
> > >
> > > Maybe error out of duplicate module loading earlier?  I don't know,
> > > sorry.
> >
> > I still don't see what's the source of the problem from the data
> > available. Is the kernel issuing multiple request_module()?
>
> For the cases I saw it only accounted for *one* of the many duplicates.
> So that's not it.
>
> > Or is the
> > kernel sending multiple udev event for userspace to map the alias to the
> > module and load it?
>
> That's what I suspect. Each CPU triggers tons of module loads.

so it seems the easiest thing to do is collect the udev log.

> > The mapping alias -> module currently belongs in
> > userspace so if you are de-duplicating, it can't be only on the module
> > name.
>
> That's one way, but it can also do it on the path used too.

path should be irrelevant for the problem we are looking at.

> > > > > What specific devices and bus types are the problem here for these systems?
> > > >
> > > > My best assessment of the situation is that each CPU in udev ends up triggering
> > > > a load of duplicate set of modules, not just one, but *a lot*. Not sure
> > > > what heuristics udev uses to load a set of modules per CPU.
> > >
> > > Again, finding which device and bus is causing the problem is going to
> > > be key here to try to solve the issue.  Are you logging duplicate module
> >
> > agreed.
> >
> > If the info I requested above is available on other threads, could you
> > point me to those?
> >
> > thanks
> > Lucas De Marchi
> >
> > > loads by name as well?
>
> The above instructions on using modules-next will let you both see
> what's going on.

hopefully you don't have CONFIG_UEVENT_HELPER_PATH set or anything
mucking /sys/kernel/uevent_helper. Right?

Lucas De Marchi

>  Luis