Modify

Opened 4 years ago

Closed 4 years ago

Last modified 4 years ago

#14182 closed defect (fixed)

System log fills from errors: user.info syslog: missing module (null)

Reported by: hnyman <hannu.nyman@…> Owned by: developers
Priority: normal Milestone: Chaos Calmer 15.05
Component: base system Version: Trunk
Keywords: systemlog log Cc: hannu.nyman@…

Description

Brand new trunk 38038 build for ar71xx/wndr3700.

At the boot, the system log fills rapidly from dozens lines of errors:

user.info syslog: missing module (null)
daemon.info sysinit: kmod: missing module (null)

There are so many error lines that the beginning of the system log is not visible any more after the boot has completed.

The previous 38017 build does not produce similar errors.

I suspect either r38023 or r38024 to be the culprit.

Larger example of the error log below:

Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:00 2013 user.info syslog: missing module (null)
Wed Sep 18 20:08:01 2013 kern.info kernel: [   14.540000] u32 classifier
Wed Sep 18 20:08:01 2013 kern.info kernel: [   14.540000]     input device check on
Wed Sep 18 20:08:01 2013 kern.info kernel: [   14.540000]     Actions configured
Wed Sep 18 20:08:01 2013 kern.info kernel: [   14.570000] Mirror/redirect action on
Wed Sep 18 20:08:01 2013 kern.info kernel: [   14.590000] Loading modules backported from Linux version master-2013-06-27-0-gdcfa6d5
Wed Sep 18 20:08:01 2013 kern.info kernel: [   14.600000] Backport generated by backports.git backports-20130617-4-ge3220f5
...
Wed Sep 18 20:08:01 2013 kern.debug kernel: [   15.000000] ath: Regpair used: 0x3a
Wed Sep 18 20:08:01 2013 kern.debug kernel: [   15.000000] ieee80211 phy1: Selected rate control algorithm 'minstrel_ht'
Wed Sep 18 20:08:01 2013 kern.info kernel: [   15.010000] ieee80211 phy1: Atheros AR9280 Rev:2 mem=0xb0010000, irq=41
Wed Sep 18 20:08:01 2013 daemon.info sysinit: kmod: missing module (null)
Wed Sep 18 20:08:01 2013 daemon.info sysinit: kmod: missing module (null)
Wed Sep 18 20:08:01 2013 daemon.info sysinit: kmod: missing module (null)
Wed Sep 18 20:08:01 2013 daemon.info sysinit: kmod: missing module (null)
Wed Sep 18 20:08:01 2013 daemon.info sysinit: kmod: missing module (null)
Wed Sep 18 20:08:01 2013 daemon.info sysinit: kmod: missing module (null)
Wed Sep 18 20:08:01 2013 daemon.info sysinit: kmod: missing module (null)
Wed Sep 18 20:08:01 2013 daemon.info sysinit: kmod: missing module (null)
Wed Sep 18 20:08:01 2013 daemon.info sysinit: kmod: missing module (null)
Wed Sep 18 20:08:01 2013 daemon.info sysinit: kmod: missing module (null)
Wed Sep 18 20:08:01 2013 daemon.info sysinit: kmod: missing module (null)

Attachments (0)

Change History (8)

comment:1 Changed 4 years ago by katananja@…

I've the exact same problem, WDR4300 v1.6 r38044

comment:2 Changed 4 years ago by anonymous

This might also be related to r38021 etc. module autoload/autoprobe conversions.

comment:3 Changed 4 years ago by hnyman <hannu.nyman@…>

I noticed also that my USB is not working any more:

Thu Sep 19 19:44:16 2013 kern.err kernel: [83032.910000] FAT-fs (sda1): IO charset iso8859-1 not found

So, this is apparently related to #14189

Based on a recent check-in in ubox repository, I guess that the reason might be erroneous module name parsing regarding - or _ in the module name. Due to that bug, the 8859-1 language module does not get loaded and prevents USB key from working.

So, this might have been caused by http://nbd.name/gitweb.cgi?p=luci2/ubox.git;a=commitdiff;h=bf2483023b3f99c0a74f96fb3cdab5a0c0ef3081
And hopefully it will get fixed with http://nbd.name/gitweb.cgi?p=luci2/ubox.git;a=commitdiff;h=102b1ad4c5c4db2c5a62f8581ab098885d4295c8 , as soon as trunk gets changed to utilise that revision of ubox. Hopefully so.

comment:4 Changed 4 years ago by hnyman <hannu.nyman@…>

This is almost duplicate of #14189

Both are vaused by the new ubox kmodloader / insmod / lsmod failing to handle modules with both _ and - in the name. nls_8859-1.ko is one example fo such a module.

After some more debugging, it is rather complicated:

Looks like the function get_module_name already mangles (= tries to clean) the module name by replacing all dashes with underscore, thus the module name "nls_8859-1" gets simplified to "nls_8859_1".
http://nbd.name/gitweb.cgi?p=luci2/ubox.git;a=blob;f=kmodloader.c;hb=102b1ad4c5c4db2c5a62f8581ab098885d4295c8#l127

When that is then later used in get_module_path, both "all _" and "all -" file name versions are tested, but as the real module file has both of them, it is never found. My previous attempt on Monday to use the original module name failed, because the module name was not the original one, but mangled by get_module_name. nls_8859-1 was alrady nls_8859_1 :-(

Added logging shows that clearly:

root@OpenWrt:~# insmod nls_8859-1
kmod: get_module_name: nls_8859-1 --> nls_8859_1
kmod: get_module_path: nls_8859_1
kmod: get_module_path_dash: /lib/modules/3.10.12/nls_8859_1.ko
kmod: get_module_path_uscore: /lib/modules/3.10.12/nls-8859-1.ko
kmod: get_module_path_intact: /lib/modules/3.10.12/nls_8859_1.ko
kmod: get_module_path not found: nls_8859_1
kmod: missing module (null)
kmod: get_module_path: nls_8859_1
kmod: get_module_path_dash: /lib/modules/3.10.12/nls_8859_1.ko
kmod: get_module_path_uscore: /lib/modules/3.10.12/nls-8859-1.ko
kmod: get_module_path_intact: /lib/modules/3.10.12/nls_8859_1.ko
kmod: get_module_path not found: nls_8859_1
kmod: get_module_path: nls_8859_1
kmod: get_module_path_dash: /lib/modules/3.10.12/nls_8859_1.ko
kmod: get_module_path_uscore: /lib/modules/3.10.12/nls-8859-1.ko
kmod: get_module_path_intact: /lib/modules/3.10.12/nls_8859_1.ko
kmod: get_module_path not found: nls_8859_1
kmod: failed to insert (null)

The real path /lib/modules/3.10.12/nls_8859-1.ko is never tested.

I will next try removing the "replace - with _" logic from get_module_name and hope that it does not break anything.

comment:5 Changed 4 years ago by hnyman <hannu.nyman@…>

The previous log example had wrong filename, but that did not actually decrease the value of the path parsing logic example.

I compiled a version, where get_module_name does not mangle the module name. That enables insmod to work again:

root@OpenWrt:~# lsmod | grep 8859
root@OpenWrt:~# insmod nls_iso8859-1
kmod: get_module_name: nls_iso8859-1 --> nls_iso8859-1
kmod: get_module_path: nls_iso8859-1
kmod: get_module_path_intact: /lib/modules/3.10.12/nls_iso8859-1.ko
root@OpenWrt:~# lsmod | grep 8859
nls_base                4974 10 nls_iso8859_1
nls_iso8859_1           2880  0

The module did not get loaded automatically at the reboot or when inserting the USB stick, so this is not the full solution, yet.

comment:6 Changed 4 years ago by hnyman <hannu.nyman@…>

The previous solution of removing dash replacement from get_module_name caused three other modules not to load: leds-wndr3700-usb, ledtrig-netdev, ledtrig-usbdev

Apparently that replacement is still needed for those modules. So, removing it is not a good solution.

comment:7 Changed 4 years ago by hnyman <hannu.nyman@…>

I created a patch for ubox that works for me. And the nls_iso8859-1 module gets now properly loaded at the startup.

The original reason lies with Linux sources. Some of the nls code page module file name are strange, as they contain both _ and -. Link to Linux sources: https://git.kernel.org/cgit/linux/kernel/git/stable/linux-stable.git/tree/fs/nls

Modprobe implementations apparently try to convert most module names to underscores, but finding those mixed-name nls files will then be impossible.

There are 4 basic ways to solve:
1) Change filenames in Linux sources (and in module definitions). Or duplicate the files (nls_iso8859_1.ko). Or something like that.
2) Abandon ubox modprobe & insmod. Busybox insmod works ok. Not likely, as Openwrt has just introduced ubox based modprobe/insmod with r38019.
3) Handle nls codepage module names differently in modprobe = ubox. I tried that earlier this week, but apparently the modprobe uses various functions to handle the module name, so trying to preserve original mixed name for nls* did not quite succeed.
4) Handle file search for the nls module files differently in modprobe = ubox. If the module name starts with "nls", assume that it may contain later a dash "-", despite it being already standardized to underscore "_" in the module name. Note that there are no nls file names with a second _ after the original nls_ .

I created an ugly hack/patch that works for me. I applied it to ubox head, one check-in ahead of the ubox currently brought to Openwrt, but it should be applicable also to the current ubox version.

This requires creating a new patches directory for ubox in the Openwrt buildroot and creating the patch there.

After failing the normal file search, the patch checks if the module name starts with nls, and if yes, then it jumps over the initial "nls_" but replaces the later occurences of _ with -, making the filename once again like "nls_iso8859-1.ko".

The new check has been placed last, just before the failure and return with NULL. So, all normal modules are first handled with the normal logic and this is just a fallback for nls*. (I have not checked if there are other modules with mixed names.)

--- trunk/package/system/ubox/Makefile	(revision 38237)
+++ trunk/package/system/ubox/Makefile	(working copy)
@@ -1,13 +1,13 @@
 include $(TOPDIR)/rules.mk
 
 PKG_NAME:=ubox
-PKG_VERSION:=2013-09-17
+PKG_VERSION:=2013-09-27
 PKG_RELEASE=$(PKG_SOURCE_VERSION)
 
 PKG_SOURCE_PROTO:=git
 PKG_SOURCE_URL:=git://nbd.name/luci2/ubox.git
 PKG_SOURCE_SUBDIR:=$(PKG_NAME)-$(PKG_VERSION)
-PKG_SOURCE_VERSION:=cc07b0b7ac66d0e4a05470dd69a28305405cd7dd
+PKG_SOURCE_VERSION:=102b1ad4c5c4db2c5a62f8581ab098885d4295c8
 PKG_SOURCE:=$(PKG_NAME)-$(PKG_VERSION)-$(PKG_SOURCE_VERSION).tar.gz
 CMAKE_INSTALL:=1
 
--- trunk/package/system/ubox/patches/020-add-logging	(revision 0)
+++ trunk/package/system/ubox/patches/020-add-logging	(working copy)
@@ -0,0 +1,26 @@
+--- a/kmodloader.c
++++ b/kmodloader.c
+@@ -121,6 +121,23 @@
+ 	if (!stat(path, &s))
+ 		return path;
+ 
++	// Fix for nls module names like nls_iso8859-1.ko, revert the last underscore
++	char *t;
++	if (!strncmp("nls", name, 3)) {
++		snprintf(path, 256, "%s" DEF_MOD_PATH "%s.ko", prefix, ver.release, name);
++		t = basename(path);		
++		replace_dash(t);
++		t += 4;   // jump over "nls-" at the start
++        	while (t && *t) {
++			if (*t == '_')
++				*t = '-';
++			t++;
++		}
++		//LOG("get_module_path: %s\n", path);
++		if (!stat(path, &s))
++			return path;
++	}
++
+ 	return NULL;
+ }
+ 

#14189 is a duplicate of this bug.

comment:8 Changed 4 years ago by jow

  • Resolution set to fixed
  • Status changed from new to closed

Add Comment

Modify Ticket

Action
as closed .
The resolution will be deleted. Next status will be 'reopened'.
Author


E-mail address and user name can be saved in the Preferences.

 
Note: See TracTickets for help on using tickets.