the first introduction of dynamically loadable ipsec and tcpmd5 modules into STABLE branch. Since VIMAGE + 11-STABLE is officially unsupported I didn't report this issue before. Now I have a box running CURRNENT, so I could test this and confirm that CURRENT branch is also affected. Loading dynamically ipsec.ko module is broken for both STABLE and CURRENT. Quick steps for reproduction. KERNCONF: include GENERIC nooptions IPSEC # kldload ipsec kldload: an error occurred while loading module ipsec. Please check dmesg(8) for more details. # dmesg | tail -1 linker_load_file: /boot/kernel/ipsec.ko - unsupported file type Let me also mention, that presence of VIMAGE option is and always was irrelevant to loading tcpmd5.ko module.
(In reply to Marek Zarychta from comment #0) Please let me make a correction to the first sentence which was accidentally truncated: This problem is persistent from the first introduction of dynamically loadable ipsec and tcpmd5 modules into STABLE branch.
Make sure you rebuild kernel modules and not only kernel when you make changes to kernel configuration file. Some kernel options break compatibility of kernel with default kernel modules and VIMAGE is known to break it too. Rebuild of modules should solve the problem.
I am sorry for the false alert. It looks like the fresh version of CURRENT is error-free. Maybe it was connected with unclean obj dir and building option WITH_META_MODE. # cat /etc/src-env.conf WITH_META_MODE=yes STABLE anyway seems to be affected, KERNCONF to reproduce: include GENERIC ident VBSD options VIMAGE options IPSEC_SUPPORT nooptions IPSEC Is this configuration supported under STABLE branch?
(In reply to Marek Zarychta from comment #3) Yes, this is supported. So, did you rebuild kernel modules while building a kernel?
(In reply to Eugene Grosbein from comment #4) I suppose "make buildkernel" does so in correct manner. No issue for kernels built without "option VIMAGE". I am building "WITH_META_MODE=yes", but disabling this mode doesn't make any difference.
(In reply to Marek Zarychta from comment #5) make buildkernel does it correctly only if you have not MODULES_WITH_WORLD nor NO_MODULES, have you? It's easy to compare modification times of installed kernel file and ipsec.ko, anyway.
Kernel (In reply to Eugene Grosbein from comment #6) Kernel has been build and installed with modules, ipsec.ko and tcpmd5.ko are present among them. Aren't you able to reproduce this on 11-STABLE? KERNCONF to reproduce: include GENERIC ident VBSD options VIMAGE options IPSEC_SUPPORT nooptions IPSEC KERNCONF allowing to load ipsec module: include GENERIC ident VBSD #options VIMAGE options IPSEC_SUPPORT nooptions IPSEC
(In reply to Marek Zarychta from comment #0) > # kldload ipsec > kldload: an error occurred while loading module ipsec. Please check dmesg(8) > for more details. > > # dmesg | tail -1 > linker_load_file: /boot/kernel/ipsec.ko - unsupported file type Usually there is one additional message, something about unresolved symbols I think.
(In reply to Andrey V. Elsukov from comment #8) No additional information is provided, also when kldload is run in verbose mode.
(In reply to Andrey V. Elsukov from comment #8) I attempted to load ipsec module through ktrace. Maybe output from kdump will shed some light on it. 4988 ktrace RET ktrace 0 4988 ktrace CALL execve(0x7fffffffe570,0x7fffffffeb00,0x7fffffffeb20) 4988 ktrace NAMI "/sbin/kldload" 4988 ktrace NAMI "/libexec/ld-elf.so.1" 4988 kldload RET execve 0 4988 kldload CALL mmap(0,0x8000,0x3<PROT_READ|PROT_WRITE>,0x1002<MAP_PRIVATE|MAP_ANON>,0xffffffff,0) 4988 kldload RET mmap 34366160896/0x800620000 4988 kldload CALL issetugid 4988 kldload RET issetugid 0 4988 kldload CALL lstat(0x800624000,0x7fffffffd2a8) 4988 kldload NAMI "/etc" 4988 kldload STRU struct stat {dev=3966367049, ino=34, mode=040755, nlink=27, uid=0, gid=0, rdev=4294967295, atime=1488438738, mtime=1528894917.915542000, ctime=1528894917.915542000, birthtime=1488438738.121758000, size=124, blksize=8192, blocks=17, flags=0x800 } 4988 kldload RET lstat 0 4988 kldload CALL lstat(0x800624000,0x7fffffffd2a8) 4988 kldload NAMI "/etc/libmap.conf" 4988 kldload STRU struct stat {dev=3966367049, ino=129, mode=0100644, nlink=1, uid=0, gid=0, rdev=4294967295, atime=1488438738, mtime=1486757987, ctime=1488438738.133604000, birthtime=1488438738.133580000, size=107, blksize=4096, blocks=9, flags=0x800 } 4988 kldload RET lstat 0 4988 kldload CALL openat(AT_FDCWD,0x800624000,0x100000<O_RDONLY|O_CLOEXEC>) 4988 kldload NAMI "/etc/libmap.conf" 4988 kldload RET openat 3 4988 kldload CALL fstat(0x3,0x7fffffffdf68) 4988 kldload STRU struct stat {dev=3966367049, ino=129, mode=0100644, nlink=1, uid=0, gid=0, rdev=4294967295, atime=1488438738, mtime=1486757987, ctime=1488438738.133604000, birthtime=1488438738.133580000, size=107, blksize=4096, blocks=9, flags=0x800 } 4988 kldload RET fstat 0 4988 kldload CALL mmap(0,0x6b,0x1<PROT_READ>,0x2<MAP_PRIVATE>,0x3,0) 4988 kldload RET mmap 34366193664/0x800628000 4988 kldload CALL close(0x3) 4988 kldload RET close 0 4988 kldload CALL lstat(0x800624800,0x7fffffffc648) 4988 kldload NAMI "/usr" 4988 kldload STRU struct stat {dev=3966367049, ino=9, mode=040755, nlink=17, uid=0, gid=0, rdev=4294967295, atime=1488438765, mtime=1491851814.556537000, ctime=1491851814.556537000, birthtime=1488438727.012480000, size=17, blksize=4096, blocks=17, flags=0x800 } 4988 kldload RET lstat 0 4988 kldload CALL lstat(0x800624800,0x7fffffffc648) 4988 kldload NAMI "/usr/local" 4988 kldload STRU struct stat {dev=3966367049, ino=481, mode=040755, nlink=18, uid=0, gid=0, rdev=4294967295, atime=1488438738, mtime=1528385864.682621000, ctime=1528385864.682621000, birthtime=1488438738.192704000, size=18, blksize=4096, blocks=17, flags=0x800 } 4988 kldload RET lstat 0 4988 kldload CALL lstat(0x800624800,0x7fffffffc648) 4988 kldload NAMI "/usr/local/etc" 4988 kldload STRU struct stat {dev=3966367049, ino=32834, mode=040755, nlink=53, uid=0, gid=0, rdev=4294967295, atime=1488441079.899548000, mtime=1528385863.622125000, ctime=1528385863.622125000, birthtime=1488441079.899548000, size=90, blksize=6144, blocks=17, flags=0x800 } 4988 kldload RET lstat 0 4988 kldload CALL lstat(0x800624800,0x7fffffffc648) 4988 kldload NAMI "/usr/local/etc/libmap.d" 4988 kldload RET lstat -1 errno 2 No such file or directory 4988 kldload CALL munmap(0x800628000,0x6b) 4988 kldload RET munmap 0 4988 kldload CALL openat(AT_FDCWD,0x80061b429,0x100000<O_RDONLY|O_CLOEXEC>) 4988 kldload NAMI "/var/run/ld-elf.so.hints" 4988 kldload RET openat 3 4988 kldload CALL read(0x3,0x800821628,0x80) 4988 kldload GIO fd 3 read 128 bytes 0x0000 4568 6e74 0100 0000 8000 0000 4301 0000 0000 0000 4201 0000 0000 0000 0000 0000 0000 |Ehnt........C.......B.............| 0x0022 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 |..................................| 0x0044 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 |..................................| 0x0066 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 |..........................| 4988 kldload RET read 128/0x80 4988 kldload CALL fstat(0x3,0x7fffffffd7f0) 4988 kldload STRU struct stat {dev=3966367049, ino=721374, mode=0100444, nlink=1, uid=0, gid=0, rdev=4294967295, atime=1528903774.820245000, mtime=1528903774.820294000, ctime=1528903774.820317000, birthtime=1528903774.820245000, size=451, blksize=4096, blocks=9, flags=0x800 } 4988 kldload RET fstat 0 4988 kldload CALL lseek(0x3,0x80,SEEK_SET) 4988 kldload RET lseek 128/0x80 4988 kldload CALL read(0x3,0x800625000,0x143) 4988 kldload GIO fd 3 read 323 bytes "/lib:/usr/lib:/usr/lib/compat:/usr/local/lib:/usr/local/lib/R/lib:/usr/local/lib/compat:/usr/local/lib/gcc6:/usr/local/lib/graphvi\ z:/usr/local/lib/nss:/usr/local/lib/opencollada:/usr/local/lib/perl5/5.26/mach/CORE:/usr/local/lib/qt5:/usr/local/lib/samba4:/usr/\ local/lib/xrdp:/usr/local/llvm60/lib:/usr/local/share/chromium\0" 4988 kldload RET read 323/0x143 4988 kldload CALL close(0x3) 4988 kldload RET close 0 4988 kldload CALL access(0x800624800,0<F_OK>) 4988 kldload NAMI "/lib/libc.so.7" 4988 kldload RET access 0 4988 kldload CALL openat(AT_FDCWD,0x800621060,0x300000<O_RDONLY|O_CLOEXEC|O_VERIFY>) 4988 kldload NAMI "/lib/libc.so.7" 4988 kldload RET openat 3 4988 kldload CALL fstat(0x3,0x7fffffffdb28) 4988 kldload STRU struct stat {dev=3966367049, ino=655658, mode=0100444, nlink=1, uid=0, gid=0, rdev=4294967295, atime=1528875590.643985000, mtime=1528875590.644651000, ctime=1528875590.645044000, birthtime=1528875590.643985000, size=1769376, blksize=131072, blocks=2169, flags=0x20000 } 4988 kldload RET fstat 0 4988 kldload CALL mmap(0,0x1000,0x1<PROT_READ>,0x40002<MAP_PRIVATE|MAP_PREFAULT_READ>,0x3,0) 4988 kldload RET mmap 34366193664/0x800628000 4988 kldload CALL mmap(0,0x3ba000,0<PROT_NONE>,0x2000<MAP_GUARD>,0xffffffff,0) 4988 kldload RET mmap 34368266240/0x800822000 4988 kldload CALL mmap(0x800822000,0x195000,0x5<PROT_READ|PROT_EXEC>,0x60012<MAP_PRIVATE|MAP_FIXED|MAP_NOCORE|MAP_PREFAULT_READ>,0x3,0) 4988 kldload RET mmap 34368266240/0x800822000 4988 kldload CALL mmap(0x800bb6000,0xd000,0x3<PROT_READ|PROT_WRITE>,0x40012<MAP_PRIVATE|MAP_FIXED|MAP_PREFAULT_READ>,0x3,0x194000) 4988 kldload RET mmap 34372018176/0x800bb6000 4988 kldload CALL mmap(0x800bc3000,0x19000,0x3<PROT_READ|PROT_WRITE>,0x1012<MAP_PRIVATE|MAP_FIXED|MAP_ANON>,0xffffffff,0) 4988 kldload RET mmap 34372071424/0x800bc3000 4988 kldload CALL munmap(0x800628000,0x1000) 4988 kldload RET munmap 0 4988 kldload CALL close(0x3) 4988 kldload RET close 0 4988 kldload CALL mmap(0,0x19000,0x3<PROT_READ|PROT_WRITE>,0x1002<MAP_PRIVATE|MAP_ANON>,0xffffffff,0) 4988 kldload RET mmap 34366193664/0x800628000 4988 kldload CALL sigprocmask(SIG_BLOCK,0x800821738,0x7fffffffdfd0) 4988 kldload RET sigprocmask 0 4988 kldload CALL sigprocmask(SIG_SETMASK,0x80082174c,0) 4988 kldload RET sigprocmask 0 4988 kldload CALL readlink(0x800987a18,0x7fffffffd700,0x400) 4988 kldload NAMI "/etc/malloc.conf" 4988 kldload RET readlink -1 errno 2 No such file or directory 4988 kldload CALL issetugid 4988 kldload RET issetugid 0 4988 kldload CALL __sysctl(0x7fffffffd5a0,0x2,0x7fffffffd5f0,0x7fffffffd5e8,0x8009864ab,0xd) 4988 kldload SCTL "sysctl.name2oid" 4988 kldload RET __sysctl 0 4988 kldload CALL __sysctl(0x7fffffffd5f0,0x2,0x7fffffffd6b4,0x7fffffffd6a8,0,0) 4988 kldload SCTL "vm.overcommit" 4988 kldload RET __sysctl 0 4988 kldload CALL mmap(0,0x200000,0x3<PROT_READ|PROT_WRITE>,0x1002<MAP_PRIVATE|MAP_ANON>,0xffffffff,0) 4988 kldload RET mmap 34372173824/0x800bdc000 4988 kldload CALL munmap(0x800bdc000,0x200000) 4988 kldload RET munmap 0 4988 kldload CALL mmap(0,0x3ff000,0x3<PROT_READ|PROT_WRITE>,0x1002<MAP_PRIVATE|MAP_ANON>,0xffffffff,0) 4988 kldload RET mmap 34372173824/0x800bdc000 4988 kldload CALL munmap(0x800bdc000,0x24000) 4988 kldload RET munmap 0 4988 kldload CALL munmap(0x800e00000,0x1db000) 4988 kldload RET munmap 0 4988 kldload CALL sigprocmask(SIG_BLOCK,0x800821738,0x7fffffffdb50) 4988 kldload RET sigprocmask 0 4988 kldload CALL sigprocmask(SIG_SETMASK,0x80082174c,0) 4988 kldload RET sigprocmask 0 4988 kldload CALL sigprocmask(SIG_BLOCK,0x800821738,0x7fffffffdb50) 4988 kldload RET sigprocmask 0 4988 kldload CALL sigprocmask(SIG_SETMASK,0x80082174c,0) 4988 kldload RET sigprocmask 0 4988 kldload CALL kldload(0x7fffffffedab) 4988 kldload NAMI "/boot/kernel/linker.hints" 4988 kldload NAMI "/boot/kernel/ipsec.ko" 4988 kldload NAMI "/boot/kernel/ipsec.ko" 4988 kldload NAMI "/boot/kernel/ipsec.ko" 4988 kldload RET kldload -1 errno 8 Exec format error 4988 kldload CALL write(0x2,0x7fffffffdda0,0x9) 4988 kldload GIO fd 2 wrote 9 bytes "kldload: " 4988 kldload RET write 9 4988 kldload CALL write(0x2,0x7fffffffdea0,0x53) 4988 kldload GIO fd 2 wrote 83 bytes "an error occurred while loading the module. Please check dmesg(8) for more details." 4988 kldload RET write 83/0x53 4988 kldload CALL write(0x2,0x800bc1c67,0x1) 4988 kldload GIO fd 2 wrote 1 byte " " 4988 kldload RET write 1 4988 kldload CALL sigprocmask(SIG_BLOCK,0x800821738,0x7fffffffe910) 4988 kldload RET sigprocmask 0 4988 kldload CALL sigprocmask(SIG_SETMASK,0x80082174c,0) 4988 kldload RET sigprocmask 0 4988 kldload CALL sigprocmask(SIG_BLOCK,0x800821738,0x7fffffffe480) 4988 kldload RET sigprocmask 0 4988 kldload CALL sigprocmask(SIG_SETMASK,0x80082174c,0) 4988 kldload RET sigprocmask 0 4988 kldload CALL sigprocmask(SIG_BLOCK,0x800821738,0x7fffffffe480) 4988 kldload RET sigprocmask 0 4988 kldload CALL sigprocmask(SIG_SETMASK,0x80082174c,0) 4988 kldload RET sigprocmask 0 4988 kldload CALL exit(0x1)
Thanks to the mailing list freebsd-current it came out that the cause of failure is already loaded pf.ko module which also collides with ipfilter.ko so both can't be loaded at the same time. Both 11-STABLE and 12-STABLE seem to be affected.
Presumably out of vnet module space. See https://lists.freebsd.org/pipermail/freebsd-current/2018-October/071972.html thread as well.
A commit references this bug: Author: bz Date: Tue Oct 30 20:45:15 UTC 2018 New revision: 339930 URL: https://svnweb.freebsd.org/changeset/base/339930 Log: With more excessive use of modules, more kernel parts working with VIMAGE, and feature richness and global state increasing the 8k of vnet module space are no longer sufficient for people and loading multiple modules, e.g., pf(4) and ipl(4) or ipsec(4) will fail on the second module. Increase the module space to 8 * PAGE_SIZE which should be enough to hold multiple firewalls, ipsec, multicast (as in the old days was a problem), epair, carp, and any kind of other vnet enabled modules. Sadly this is a global byte array part of the vnet_set, so we cannot dynamically change its size; otherwise a TUNABLE would have been a better solution. PR: 228854 Reported by: Ernie Luzar, Marek Zarychta Discussed with: rgrimes on current MFC after: 3 days Changes: head/sys/net/vnet.c
A commit references this bug: Author: bz Date: Tue Oct 30 20:51:03 UTC 2018 New revision: 339931 URL: https://svnweb.freebsd.org/changeset/base/339931 Log: As a follow-up to r339930 and various reports implement logging in case we fail during module load because the pcpu or vnet module sections are full. We did return a proper error but not leaving any indication to the user as to what the actual problem was. Even worse, on 12/13 currently we are seeing an unrelated error (ENOSYS instead of ENOSPC, which gets skipped over in kern_linker.c) to be printed which made problem diagnostics even harder. PR: 228854 MFC after: 3 days Changes: head/sys/kern/link_elf.c head/sys/kern/link_elf_obj.c
Broke mips; follow-up commit to come; will try to MFC on Fri.
A commit references this bug: Author: bz Date: Tue Oct 30 21:35:57 UTC 2018 New revision: 339933 URL: https://svnweb.freebsd.org/changeset/base/339933 Log: Fix mips build after r339931. I erroneously thought that it was two 64bit platforms which use link_elf_obj.c. PR: 228854 Reported by: ci.f.o. MFC after: 3 days X-MFC with: r339931 Pointyhat to: bz Changes: head/sys/kern/link_elf_obj.c
A commit references this bug: Author: bz Date: Wed Oct 31 12:50:40 UTC 2018 New revision: 339951 URL: https://svnweb.freebsd.org/changeset/base/339951 Log: MFC r339930: With more excessive use of modules, more kernel parts working with VIMAGE, and feature richness and global state increasing the 8k of vnet module space are no longer sufficient for people and loading multiple modules, e.g., pf(4) and ipl(4) or ipsec(4) will fail on the second module. Increase the module space to 8 * PAGE_SIZE which should be enough to hold multiple firewalls, ipsec, multicast (as in the old days was a problem), epair, carp, and any kind of other vnet enabled modules. Sadly this is a global byte array part of the vnet_set, so we cannot dynamically change its size; otherwise a TUNABLE would have been a better solution. PR: 228854 Reported by: Ernie Luzar, Marek Zarychta Approved by: re (kib) Changes: _U stable/12/ stable/12/sys/net/vnet.c
A commit references this bug: Author: bz Date: Wed Oct 31 14:03:48 UTC 2018 New revision: 339953 URL: https://svnweb.freebsd.org/changeset/base/339953 Log: MFC r339931,r339933: As a follow-up to r339930 (r339951 in stable/12) and various reports implement logging in case we fail during module load because the pcpu or vnet module sections are full. We did return a proper error but not leaving any indication to the user as to what the actual problem was. Even worse, on 12/13 currently we are seeing an unrelated error (ENOSYS instead of ENOSPC, which gets skipped over in kern_linker.c) to be printed which made problem diagnostics even harder. PR: 228854 Approved by: re (kib) Changes: _U stable/12/ stable/12/sys/kern/link_elf.c stable/12/sys/kern/link_elf_obj.c
A commit references this bug: Author: bz Date: Fri Nov 2 14:07:07 UTC 2018 New revision: 340051 URL: https://svnweb.freebsd.org/changeset/base/340051 Log: MFC r339930: With more excessive use of modules, more kernel parts working with VIMAGE, and feature richness and global state increasing the 8k of vnet module space are no longer sufficient for people and loading multiple modules, e.g., pf(4) and ipl(4) or ipsec(4) will fail on the second module. Increase the module space to 8 * PAGE_SIZE which should be enough to hold multiple firewalls, ipsec, multicast (as in the old days was a problem), epair, carp, and any kind of other vnet enabled modules. Sadly this is a global byte array part of the vnet_set, so we cannot dynamically change its size; otherwise a TUNABLE would have been a better solution. PR: 228854 Changes: _U stable/11/ stable/11/sys/net/vnet.c
A commit references this bug: Author: bz Date: Fri Nov 2 14:15:52 UTC 2018 New revision: 340054 URL: https://svnweb.freebsd.org/changeset/base/340054 Log: MFC r339931,r339933 As a follow-up to r339930 and various reports implement logging in case we fail during module load because the pcpu or vnet module sections are full. We did return a proper error but not leaving any indication to the user as to what the actual problem was. PR: 228854 Changes: _U stable/11/ stable/11/sys/kern/link_elf.c stable/11/sys/kern/link_elf_obj.c
We think that for stable/11 and stable/12 and HEAD this should be fixed now. Thanks a lot for reporting!