Bug 232782 - Autoloading module 8 times.
Summary: Autoloading module 8 times.
Status: Closed FIXED
Alias: None
Product: Base System
Classification: Unclassified
Component: bin (show other bugs)
Version: CURRENT
Hardware: Any Any
: --- Affects Only Me
Assignee: Warner Losh
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2018-10-29 15:04 UTC by Bjoern A. Zeeb
Modified: 2021-07-16 18:31 UTC (History)
1 user (show)

See Also:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Bjoern A. Zeeb freebsd_committer freebsd_triage 2018-10-29 15:04:42 UTC
On a HEAD machine from 3 days ago on a fresh boot -v I see 8 attempts to "Autoloading module: ioat.ko".
As you can see below, the first attempt actually loads the module, attaches ioat[0-7].
Afterwards another 7 attempts to load the module (again) are logged.  Maybe it doesn't even try to log the module, just still prints it?

# dmesg -a | grep ioat
Autoloading module: ioat.ko
ioat0: <IVB IOAT Ch0> mem 0xfac1c000-0xfac1ffff irq 31 at device 4.0 on pci0
ioat0: Capabilities: 2f7<PQ,Extended_APIC_ID,Block_Fill,Move_CRC,DCA,Marker_Skipping,CRC,Page_Break>
ioat0: attempting to allocate 1 MSI-X vectors (1 supported)
ioat0: using IRQ 291 for MSI-X
ioat1: <IVB IOAT Ch1> mem 0xfac18000-0xfac1bfff irq 39 at device 4.1 on pci0
ioat1: Capabilities: 2f7<PQ,Extended_APIC_ID,Block_Fill,Move_CRC,DCA,Marker_Skipping,CRC,Page_Break>
ioat1: attempting to allocate 1 MSI-X vectors (1 supported)
ioat1: using IRQ 292 for MSI-X
ioat2: <IVB IOAT Ch2> mem 0xfac14000-0xfac17fff irq 31 at device 4.2 on pci0
ioat2: Capabilities: f7<Extended_APIC_ID,Block_Fill,Move_CRC,DCA,Marker_Skipping,CRC,Page_Break>
ioat2: attempting to allocate 1 MSI-X vectors (1 supported)
ioat2: using IRQ 293 for MSI-X
ioat3: <IVB IOAT Ch3> mem 0xfac10000-0xfac13fff irq 39 at device 4.3 on pci0
ioat3: Capabilities: f7<Extended_APIC_ID,Block_Fill,Move_CRC,DCA,Marker_Skipping,CRC,Page_Break>
ioat3: attempting to allocate 1 MSI-X vectors (1 supported)
ioat3: using IRQ 294 for MSI-X
ioat4: <IVB IOAT Ch4> mem 0xfac0c000-0xfac0ffff irq 31 at device 4.4 on pci0
ioat4: Capabilities: f7<Extended_APIC_ID,Block_Fill,Move_CRC,DCA,Marker_Skipping,CRC,Page_Break>
ioat4: attempting to allocate 1 MSI-X vectors (1 supported)
ioat4: using IRQ 295 for MSI-X
ioat5: <IVB IOAT Ch5> mem 0xfac08000-0xfac0bfff irq 39 at device 4.5 on pci0
ioat5: Capabilities: f7<Extended_APIC_ID,Block_Fill,Move_CRC,DCA,Marker_Skipping,CRC,Page_Break>
ioat5: attempting to allocate 1 MSI-X vectors (1 supported)
ioat5: using IRQ 296 for MSI-X
ioat6: <IVB IOAT Ch6> mem 0xfac04000-0xfac07fff irq 31 at device 4.6 on pci0
ioat6: Capabilities: f7<Extended_APIC_ID,Block_Fill,Move_CRC,DCA,Marker_Skipping,CRC,Page_Break>
ioat6: attempting to allocate 1 MSI-X vectors (1 supported)
ioat6: using IRQ 297 for MSI-X
ioat7: <IVB IOAT Ch7> mem 0xfac00000-0xfac03fff irq 39 at device 4.7 on pci0
ioat7: Capabilities: f7<Extended_APIC_ID,Block_Fill,Move_CRC,DCA,Marker_Skipping,CRC,Page_Break>
ioat7: attempting to allocate 1 MSI-X vectors (1 supported)
ioat7: using IRQ 298 for MSI-X
Autoloading module: ioat.ko
Autoloading module: ioat.ko
Autoloading module: ioat.ko
Autoloading module: ioat.ko
Autoloading module: ioat.ko
Autoloading module: ioat.ko
Autoloading module: ioat.ko
#
Comment 1 ota 2021-06-04 03:35:45 UTC
I happen to look into this case as I also noticed multiple attempts to load.

It uses kldload -n option so that it doesn't reload what's been loaded.
https://cgit.freebsd.org/src/blame/libexec/rc/rc.d/devmatch#n70

"Autoloading module:" is printed for each try and a bit excessive but no harm.
Comment 2 commit-hook freebsd_committer freebsd_triage 2021-07-08 21:27:41 UTC
A commit in branch main references this bug:

URL: https://cgit.FreeBSD.org/src/commit/?id=5549c6a62f0f4fc5d7e80973b28ebcf7f556edf8

commit 5549c6a62f0f4fc5d7e80973b28ebcf7f556edf8
Author:     Warner Losh <imp@FreeBSD.org>
AuthorDate: 2021-07-08 19:53:18 +0000
Commit:     Warner Losh <imp@FreeBSD.org>
CommitDate: 2021-07-08 21:22:22 +0000

    devmatch: don't announce autoloading so much

    devmatch rc script would announce it was loading a module multiple
    times. It used kldload -n so it really wasn't loading it that many
    times, but the message is confusing. Use kldstat to see if we need to
    load the module before saying we do. This fixes the vast majority of the
    problems. It may be possible to race devmatch with a user invocation and
    devd, though quite hard. In that case we'll announce things twice, but
    still only load it once. No attempt is made to fix this.

    PR:                     232782
    MFC After:              2 weeks
    Sponsored by:           Netflix

 libexec/rc/rc.d/devmatch | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)
Comment 3 commit-hook freebsd_committer freebsd_triage 2021-07-16 17:47:44 UTC
A commit in branch stable/12 references this bug:

URL: https://cgit.FreeBSD.org/src/commit/?id=66c5e65030ca055ada3eae1c18cbbafe8131fa86

commit 66c5e65030ca055ada3eae1c18cbbafe8131fa86
Author:     Warner Losh <imp@FreeBSD.org>
AuthorDate: 2021-07-08 19:53:18 +0000
Commit:     Warner Losh <imp@FreeBSD.org>
CommitDate: 2021-07-16 17:45:11 +0000

    devmatch: don't announce autoloading so much

    devmatch rc script would announce it was loading a module multiple
    times. It used kldload -n so it really wasn't loading it that many
    times, but the message is confusing. Use kldstat to see if we need to
    load the module before saying we do. This fixes the vast majority of the
    problems. It may be possible to race devmatch with a user invocation and
    devd, though quite hard. In that case we'll announce things twice, but
    still only load it once. No attempt is made to fix this.

    PR:                     232782
    MFC After:              2 weeks
    Sponsored by:           Netflix

 libexec/rc/rc.d/devmatch | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)
Comment 4 commit-hook freebsd_committer freebsd_triage 2021-07-16 18:31:00 UTC
A commit in branch stable/13 references this bug:

URL: https://cgit.FreeBSD.org/src/commit/?id=00ed9aa54bec137327e37c25fcd5d59347bbf4e6

commit 00ed9aa54bec137327e37c25fcd5d59347bbf4e6
Author:     Warner Losh <imp@FreeBSD.org>
AuthorDate: 2021-07-08 19:53:18 +0000
Commit:     Warner Losh <imp@FreeBSD.org>
CommitDate: 2021-07-16 18:28:44 +0000

    devmatch: don't announce autoloading so much

    devmatch rc script would announce it was loading a module multiple
    times. It used kldload -n so it really wasn't loading it that many
    times, but the message is confusing. Use kldstat to see if we need to
    load the module before saying we do. This fixes the vast majority of the
    problems. It may be possible to race devmatch with a user invocation and
    devd, though quite hard. In that case we'll announce things twice, but
    still only load it once. No attempt is made to fix this.

    PR:                     232782
    MFC After:              2 weeks
    Sponsored by:           Netflix

    (cherry picked from commit 5549c6a62f0f4fc5d7e80973b28ebcf7f556edf8)

 libexec/rc/rc.d/devmatch | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)