Re: Systemd debugging
On Thu, Nov 27, 2014 at 12:06:20AM +0200, Andrei POPESCU wrote:
> On Mi, 26 nov 14, 12:27:00, Haines Brown wrote:
> > I intalled Jessie and ran into troubles. One of them was an error mesage
> > during boot: Failed to Start Load Kernel Modules. Neverthess, I could
> > boot successfully. I do have /lib/modules/3.16.0-4-686-pae.
> >
> > In pursuing this issue, the first thing I found out was that bootlogd is
> > not used with systemd.
>
> You can use this instead
>
> journalctl -alb
Andrei, I did as you suggested, but I'm not sure if the result really
adds anything substantive.
I start the command:
-- Logs begin at Wed 2014-11-26 17:15:15 EST, end at Thu 2014-11-27
07:37:20 EST. --
Nov 26 17:15:15 engels systemd-journal[202]: Runtime journal is using
8.0M (max allowed 322.3M, trying to leave 483.5M free of 3.1G
available current limit 322.3M).
Then the failed to insert module problem. I find that in fact I do have
/lib/modules/3.12.0-4-686-pae/kernel/drivers/hwmon/it87.ko on this box.
When it87 not inserted, were all further module insertions terminated?
If .../kernel/drivers/block/loop.ko was loaded, why not it87.ko?
Nov 26 17:15:16 engels systemd-fsck[195]: /dev/sda1: clean,
15827/61056 files, 120381/243968 blocks
Nov 26 17:15:16 engels systemd-modules-load[201]: Inserted module 'loop'
Nov 26 17:15:16 engels kernel: loop: module loaded
Nov 26 17:15:16 engels systemd-modules-load[201]: Inserted module
'coretemp'
Nov 26 17:15:16 engels systemd-modules-load[201]: Failed to insert
'it87': No such device
Nov 26 17:15:16 engels systemd[1]: systemd-modules-load.service: main
process exited, code=exited, status=1/FAILURE
Nov 26 17:15:16 engels systemd[1]: Failed to start Load Kernel Modules.
Nov 26 17:15:16 engels systemd[1]: Unit systemd-modules-load.service
entered failed state.
Then there's the report about not being able to mount /usb although in
fact it is mounted and accessible. Was it initially seen as ro? Does
this mean that the remount command succeeded to mount /usr on second
try without ro?
Nov 26 17:15:17 engels hdparm[357]: Setting parameters of disc: (none).
Nov 26 17:15:17 engels systemd-fsck[350]: /dev/sda5: recovering journal
Nov 26 17:15:17 engels systemd-remount-fs[356]: mount: /usr not
mounted or bad option
Nov 26 17:15:17 engels systemd-remount-fs[356]: In some cases useful
info is found in syslog - try
Nov 26 17:15:17 engels systemd-remount-fs[356]: dmesg | tail or so.
Nov 26 17:15:17 engels systemd-remount-fs[356]: /bin/mount for /usr
exited with exit status 32.
Nov 26 17:15:17 engels systemd[1]: systemd-remount-fs.service: main
process exited, code=exited, status=1/FAILURE
Nov 26 17:15:17 engels systemd[1]: Failed to start Remount Root and
Kernel File Systems.
Nov 26 17:15:17 engels systemd[1]: Unit systemd-remount-fs.service
entered failed state.
Nov 26 17:15:17 engels kernel: EXT4-fs (sda1): re-mounted. Opts:
errors=remount-ro
Then there's something wrong when Console Kit and Policy Kit loaded.
Both were ultimately activated, but something about page size failed:
Nov 26 17:17:36 engels dbus[723]: [system] Activating via systemd:
service name='org.freedesktop.ConsoleKit'
unit='console-kit-daemon.service'
Nov 26 17:17:36 engels console-kit-daemon[1310]: (process:1373):
GLib-CRITICAL **: g_slice_set_config: assertion
'sys_page_size == 0' failed
Nov 26 17:17:36 engels console-kit-daemon[1310]: missing action
Nov 26 17:17:36 engels dbus[723]: [system] Activating via systemd:
service name='org.freedesktop.PolicyKit1' unit='polkitd.service'
Nov 26 17:17:36 engels polkitd[1376]: started daemon version 0.105
using authority implementation `local' version `0.105'
Nov 26 17:17:36 engels dbus[723]: [system] Successfully activated
service 'org.freedesktop.PolicyKit1'
Nov 26 17:17:36 engels dbus[723]: [system] Successfully activated
service 'org.freedesktop.ConsoleKit'
Nov 26 17:17:36 engels console-kit-daemon[1310]: (process:1386):
GLib-CRITICAL **: g_slice_set_config: assertion
'sys_page_size == 0' failed
Nov 26 17:17:51 engels console-kit-daemon[1310]: (process:1499):
GLib-CRITICAL **: g_slice_set_config: assertion
'sys_page_size == 0' failed
This immediately followed by a problem getting IP address from my
router's DHCP. The box has wifi card, but no ethernet cable. Before
Jessie, wlan0 was assigned an address automatically, but with Jessie
there's no assress and wlan-avahi instead gets a bogus address. I can
do ifdown/ifup and get an IP address, but should not have to. Is DBus
blocking the connection? Why ping 192.168.1.254? That's non-existent.
The router is 192.168.1.255.
Nov 26 17:17:52 engels ntpd[896]: Deferring DNS for
1.debian.pool.ntp.org 1
Nov 26 17:17:53 engels console-kit-daemon[1310]: (process:1540):
GLib-CRITICAL **: g_slice_set_config: assertion
'sys_page_size == 0' failed
Nov 26 17:17:55 engels dhclient[585]: DHCPDISCOVER on
eth0 to 255.255.255.255 port 67 interval 15
Nov 26 17:17:55 engels ifup[573]: DHCPDISCOVER on
eth0 to 255.255.255.255 port 67 interval 15
Nov 26 17:18:06 engels org.gtk.vfs.Daemon[1545]: A connection to
the bus can't be made
Nov 26 17:18:06 engels org.gtk.vfs.Daemon[1545]:
g_dbus_connection_real_closed: Remote peer vanished with error:
Underlying GIOStream returned 0 bytes on an async read
(g-io-error-quark, 0). Exiting.
Nov 26 17:18:06 engels console-kit-daemon[1310]: (process:1597):
GLib-CRITICAL **: g_slice_set_config: assertion
'sys_page_size == 0' failed
Nov 26 17:18:07 engels console-kit-daemon[1310]: (process:1599):
GLib-CRITICAL **: g_slice_set_config: assertion
'sys_page_size == 0' failed
Nov 26 17:18:10 engels dhclient[585]: No DHCPOFFERS received.
...
Nov 26 17:15:19 engels kernel: ieee80211 phy0:
rt2x00lib_request_firmware: Info - Firmware detected -
version: 0.34
Nov 26 17:15:19 engels kernel: IPv6: ADDRCONF(NETDEV_UP):
wlan0: link is not ready
Nov 26 17:15:19 engels dhclient[492]: Listening on
LPF/wlan0/68:1c:a2:04:21:74
Nov 26 17:15:19 engels dhclient[492]: Sending on
LPF/wlan0/68:1c:a2:04:21:74
Nov 26 17:15:19 engels dhclient[492]: Sending on Socket/fallback
Nov 26 17:15:19 engels dhclient[492]: DHCPREQUEST on wlan0
to 255.255.255.255 port 67
Nov 26 17:15:19 engels networking[429]: Listening on
LPF/wlan0/68:1c:a2:04:21:74
Nov 26 17:15:19 engels networking[429]: Sending on
LPF/wlan0/68:1c:a2:04:21:74
Nov 26 17:15:19 engels networking[429]: Sending on Socket/fallback
Nov 26 17:15:19 engels networking[429]: DHCPREQUEST on wlan0
to 255.255.255.255 port 67
...
Nov 26 17:16:46 engels dhclient[492]: No DHCPOFFERS received.
Nov 26 17:16:46 engels dhclient[492]: Trying recorded lease
192.168.1.133
Nov 26 17:16:46 engels networking[429]: No DHCPOFFERS received.
Nov 26 17:16:46 engels networking[429]: Trying recorded lease
192.168.1.133
Nov 26 17:16:49 engels networking[429]: PING 192.168.1.254
(192.168.1.254) 56(84) bytes of data.
Nov 26 17:16:49 engels networking[429]: --- 192.168.1.254 ping
statistics ---
Nov 26 17:16:49 engels networking[429]: 1 packets transmitted,
0 received, +1 errors, 100% packet loss, time 0ms
Nov 26 17:16:49 engels avahi-autoipd(wlan0)[506]: Found user
'avahi-autoipd' (UID 101) and group 'avahi-autoipd' (GID 103).
Nov 26 17:16:49 engels avahi-autoipd(wlan0)[506]: Successfully
called chroot().
Nov 26 17:16:49 engels avahi-autoipd(wlan0)[506]: Successfully
dropped root privileges.
Nov 26 17:16:49 engels avahi-autoipd(wlan0)[506]: Starting with
address 169.254.5.53
Nov 26 17:16:55 engels avahi-autoipd(wlan0)[506]: Callout BIND,
address 169.254.5.53 on interface wlan0
Nov 26 17:16:59 engels avahi-autoipd(wlan0)[506]: Successfully
claimed IP address 169.254.5.53
Nov 26 17:16:59 engels systemd-journal[202]: Forwarding to syslog
missed 16 messages.
And this material seems to reiterate issues that already came up:
Nov 26 17:17:36 engels systemd[1306]: Startup finished in 41ms.
Nov 26 17:17:36 engels dbus[723]: [system] Activating via systemd:
service name='org.freedesktop.ConsoleKit'
unit='console-kit-daemon.service'
Nov 26 17:17:36 engels console-kit-daemon[1310]: (process:1373):
GLib-CRITICAL **: g_slice_set_config: assertion
'sys_page_size == 0' failed
Nov 26 17:17:36 engels console-kit-daemon[1310]: missing action
Nov 26 17:17:36 engels dbus[723]: [system] Activating via systemd:
service name='org.freedesktop.PolicyKit1' unit='polkitd.service'
Nov 26 17:17:36 engels polkitd[1376]: started daemon version 0.105
using authority implementation `local' version `0.105'
Nov 26 17:17:36 engels dbus[723]: [system] Successfully activated
service 'org.freedesktop.PolicyKit1'
Nov 26 17:17:36 engels dbus[723]: [system] Successfully activated
service 'org.freedesktop.ConsoleKit'
Nov 26 17:17:36 engels console-kit-daemon[1310]: (process:1386):
GLib-CRITICAL **: g_slice_set_config: assertion
'sys_page_size == 0' failed
Nov 26 17:17:51 engels console-kit-daemon[1310]: (process:1499):
GLib-CRITICAL **: g_slice_set_config: assertion
'sys_page_size == 0' failed
Nov 26 17:17:52 engels ntpd[896]: Deferring DNS for
1.debian.pool.ntp.org 1
Nov 26 17:17:53 engels console-kit-daemon[1310]: (process:1540):
GLib-CRITICAL **: g_slice_set_config: assertion
'sys_page_size == 0' failed
...
Nov 26 17:38:48 engels ntpd[896]: peers refreshed
Nov 26 17:38:50 engels avahi-autoipd(wlan0)[506]: Successfully
claimed IP address 169.254.5.53
Nov 26 17:39:01 engels ntpd_intres[1723]: host name not found:
0.debian.pool.ntp.org
So am I right to characterize the problems as:
a) it87 module present, but its directory not searched.
b) The remount of /usr initially failed because it was tried ro,
and so had to be done again without the ro option?.
c) While Console Kit and Policy Kit load, it is only with a
page size error. Is it serious?
d) DBus seems to block assignment of IP address by router's DHCP.
Haines Brown
Reply to: