Hi,
some weeks ago I installed OS 12.1 on an SSD. I am pretty happy with the system and especially with its responsiveness. But I recognized a strange thing:
If I boot the system and log in immediately my desktop comes up quickly. But then the system is stuck for 20-30seconds. Nothing gets loaded. Once I can open a terminal I type “dmesg” and the last line that is dumped is:
103.650963] EXT4-fs (sdb1): re-mounted. Opts: acl,user_xattr,commit=0
It seems my root disk is being re-mounted. That would explain why the system gets stuck. But why is it re-mounted? And who does this?
> It seems my root disk is being re-mounted. That would explain why the
> system gets stuck. But why is it re-mounted? And who does this?
One of the features of systemd is the early login. You can in fact log into
the machine before it has finished booting, there are processes going on.
On of them could do that remount.
Don’t ask me why/what is doing that, I’m no expert on systemd. Few people
know much about it.
I do remember that the disk is initially mounted read only, as early as
possible from initrd, so that it can be checked and boot proceed loading
things. Later on it is remounted with full features, and login should be
allowed after this. It must be a variation of this process.
–
Cheers / Saludos,
Carlos E. R.
(from 11.4 x86_64 “Celadon” at Telcontar)
It seems I have to revise my speculation that there is a connection between the hang and the re-mount. I rebooted without a hang but still found the remount (this time after 12sec). I rebooted again and got a hang but the remount was after 13sec, i.e. before the hang. Nevertheless, below is an excerpt of /var/log/messages around the remount that I mentioned originally. And to be frank, most of this looks strange to me
Cheers
Frank
Jan 20 18:35:56 pc2009 dbus-daemon[1037]: **** ADDING /sys/devices/pci0000:00/0000:00:0b.0/host3/target3:0:0/3:0:0:0/block/sdb
Jan 20 18:35:56 pc2009 dbus-daemon[1037]: **** UPDATING /sys/devices/pci0000:00/0000:00:0b.0/host3/target3:0:0/3:0:0:0/block/sdb
Jan 20 18:35:56 pc2009 dbus-daemon[1037]: helper(pid 3700): launched job udisks-helper-ata-smart-collect on /dev/sdb
Jan 20 18:35:56 pc2009 dbus-daemon[1037]: **** ADDED /sys/devices/pci0000:00/0000:00:0b.0/host3/target3:0:0/3:0:0:0/block/sdb
Jan 20 18:35:56 pc2009 dbus-daemon[1037]: **** ADDING /sys/devices/pci0000:00/0000:00:0b.0/host3/target3:0:0/3:0:0:0/block/sdb/sdb1
Jan 20 18:35:56 pc2009 dbus-daemon[1037]: **** UPDATING /sys/devices/pci0000:00/0000:00:0b.0/host3/target3:0:0/3:0:0:0/block/sdb/sdb1
Jan 20 18:35:56 pc2009 dbus-daemon[1037]: **** ADDED /sys/devices/pci0000:00/0000:00:0b.0/host3/target3:0:0/3:0:0:0/block/sdb/sdb1
Jan 20 18:35:56 pc2009 dbus-daemon[1037]: **** ADDING /sys/devices/pci0000:00/0000:00:0b.0/host3/target3:0:0/3:0:0:0/block/sdb/sdb2
Jan 20 18:35:56 pc2009 dbus-daemon[1037]: **** UPDATING /sys/devices/pci0000:00/0000:00:0b.0/host3/target3:0:0/3:0:0:0/block/sdb/sdb2
Jan 20 18:35:56 pc2009 dbus-daemon[1037]: **** ADDED /sys/devices/pci0000:00/0000:00:0b.0/host3/target3:0:0/3:0:0:0/block/sdb/sdb2
Jan 20 18:35:56 pc2009 dbus-daemon[1037]: **** CHANGING /sys/devices/pci0000:00/0000:00:0b.0/host0/target0:0:0/0:0:0:0/block/sda/sda4
Jan 20 18:35:56 pc2009 dbus-daemon[1037]: **** UPDATING /sys/devices/pci0000:00/0000:00:0b.0/host0/target0:0:0/0:0:0:0/block/sda/sda4
Jan 20 18:35:56 pc2009 dbus-daemon[1037]: **** CHANGED /sys/devices/pci0000:00/0000:00:0b.0/host0/target0:0:0/0:0:0:0/block/sda/sda4
Jan 20 18:35:56 pc2009 dbus-daemon[1037]: **** CHANGING /sys/devices/pci0000:00/0000:00:0b.0/host3/target3:0:0/3:0:0:0/block/sdb/sdb2
Jan 20 18:35:56 pc2009 dbus-daemon[1037]: **** UPDATING /sys/devices/pci0000:00/0000:00:0b.0/host3/target3:0:0/3:0:0:0/block/sdb/sdb2
Jan 20 18:35:56 pc2009 dbus-daemon[1037]: **** CHANGED /sys/devices/pci0000:00/0000:00:0b.0/host3/target3:0:0/3:0:0:0/block/sdb/sdb2
Jan 20 18:35:56 pc2009 dbus-daemon[1037]: **** CHANGING /sys/devices/pci0000:00/0000:00:0b.0/host0/target0:0:0/0:0:0:0/block/sda
Jan 20 18:35:56 pc2009 dbus-daemon[1037]: **** UPDATING /sys/devices/pci0000:00/0000:00:0b.0/host0/target0:0:0/0:0:0:0/block/sda
Jan 20 18:35:56 pc2009 dbus-daemon[1037]: **** CHANGED /sys/devices/pci0000:00/0000:00:0b.0/host0/target0:0:0/0:0:0:0/block/sda
Jan 20 18:35:56 pc2009 dbus-daemon[1037]: **** CHANGING /sys/devices/pci0000:00/0000:00:0b.0/host3/target3:0:0/3:0:0:0/block/sdb
Jan 20 18:35:56 pc2009 dbus-daemon[1037]: **** UPDATING /sys/devices/pci0000:00/0000:00:0b.0/host3/target3:0:0/3:0:0:0/block/sdb
Jan 20 18:35:56 pc2009 dbus-daemon[1037]: **** CHANGED /sys/devices/pci0000:00/0000:00:0b.0/host3/target3:0:0/3:0:0:0/block/sdb
Jan 20 18:35:56 pc2009 dbus-daemon[1037]: **** CHANGING /sys/devices/pci0000:00/0000:00:0b.0/host2/target2:0:0/2:0:0:0/block/sr0
Jan 20 18:35:56 pc2009 dbus-daemon[1037]: **** UPDATING /sys/devices/pci0000:00/0000:00:0b.0/host2/target2:0:0/2:0:0:0/block/sr0
Jan 20 18:35:56 pc2009 dbus-daemon[1037]: **** CHANGED /sys/devices/pci0000:00/0000:00:0b.0/host2/target2:0:0/2:0:0:0/block/sr0
Jan 20 18:35:56 pc2009 dbus-daemon[1037]: **** CHANGING /sys/devices/pci0000:00/0000:00:0b.0/host0/target0:0:0/0:0:0:0/block/sda/sda1
Jan 20 18:35:56 pc2009 dbus-daemon[1037]: **** UPDATING /sys/devices/pci0000:00/0000:00:0b.0/host0/target0:0:0/0:0:0:0/block/sda/sda1
Jan 20 18:35:56 pc2009 dbus-daemon[1037]: **** CHANGED /sys/devices/pci0000:00/0000:00:0b.0/host0/target0:0:0/0:0:0:0/block/sda/sda1
Jan 20 18:35:56 pc2009 dbus-daemon[1037]: **** CHANGING /sys/devices/pci0000:00/0000:00:0b.0/host0/target0:0:0/0:0:0:0/block/sda/sda2
Jan 20 18:35:56 pc2009 dbus-daemon[1037]: **** UPDATING /sys/devices/pci0000:00/0000:00:0b.0/host0/target0:0:0/0:0:0:0/block/sda/sda2
Jan 20 18:35:56 pc2009 dbus-daemon[1037]: **** CHANGED /sys/devices/pci0000:00/0000:00:0b.0/host0/target0:0:0/0:0:0:0/block/sda/sda2
Jan 20 18:35:56 pc2009 dbus-daemon[1037]: **** CHANGING /sys/devices/pci0000:00/0000:00:0b.0/host3/target3:0:0/3:0:0:0/block/sdb/sdb1
Jan 20 18:35:56 pc2009 dbus-daemon[1037]: **** UPDATING /sys/devices/pci0000:00/0000:00:0b.0/host3/target3:0:0/3:0:0:0/block/sdb/sdb1
Jan 20 18:35:56 pc2009 dbus-daemon[1037]: **** CHANGED /sys/devices/pci0000:00/0000:00:0b.0/host3/target3:0:0/3:0:0:0/block/sdb/sdb1
Jan 20 18:35:56 pc2009 dbus-daemon[1037]: **** CHANGING /sys/devices/pci0000:00/0000:00:0b.0/host0/target0:0:0/0:0:0:0/block/sda/sda3
Jan 20 18:35:56 pc2009 dbus-daemon[1037]: **** UPDATING /sys/devices/pci0000:00/0000:00:0b.0/host0/target0:0:0/0:0:0:0/block/sda/sda3
Jan 20 18:35:56 pc2009 dbus-daemon[1037]: **** CHANGED /sys/devices/pci0000:00/0000:00:0b.0/host0/target0:0:0/0:0:0:0/block/sda/sda3
Jan 20 18:35:56 pc2009 dbus-daemon[1037]: helper(pid 3700): completed with exit code 0
Jan 20 18:35:56 pc2009 kernel: 103.650963] EXT4-fs (sdb1): re-mounted. Opts: acl,user_xattr,commit=0
Jan 20 18:35:56 pc2009 dbus-daemon[1037]: **** EMITTING CHANGED for /sys/devices/pci0000:00/0000:00:0b.0/host3/target3:0:0/3:0:0:0/block/sdb
Jan 20 18:35:56 pc2009 dbus-daemon[1037]: **** /proc/self/mountinfo changed
Jan 20 18:35:56 pc2009 dbus[1037]: [system] Activating service name=‘org.kde.powerdevil.backlighthelper’ (using servicehelper)
Jan 20 18:35:56 pc2009 dbus-daemon[1037]: dbus[1037]: [system] Activating service name=‘org.kde.powerdevil.backlighthelper’ (using servicehelper)
Jan 20 18:35:56 pc2009 dbus-daemon[1037]: no kernel backlight interface found
Jan 20 18:35:56 pc2009 dbus-daemon[1037]: dbus[1037]: [system] Successfully activated service ‘org.kde.powerdevil.backlighthelper’
Jan 20 18:35:56 pc2009 rsyslogd-2177: imuxsock begins to drop messages from pid 1037 due to rate-limiting
Jan 20 18:36:01 pc2009 rsyslogd-2177: imuxsock lost 7 messages from pid 1037 due to rate-limiting
Jan 20 18:36:01 pc2009 dbus[1037]: [system] Activating service name=‘org.freedesktop.RealtimeKit1’ (using servicehelper)
Jan 20 18:36:01 pc2009 dbus-daemon[1037]: dbus[1037]: [system] Activating service name=‘org.freedesktop.RealtimeKit1’ (using servicehelper)
Jan 20 18:36:01 pc2009 dbus-daemon[1037]: dbus[1037]: [system] Successfully activated service ‘org.freedesktop.RealtimeKit1’
Jan 20 18:36:01 pc2009 dbus[1037]: [system] Successfully activated service ‘org.freedesktop.RealtimeKit1’
Jan 20 17:36:01 pc2009 rtkit-daemon[3887]: Sucessfully called chroot.
Jan 20 17:36:01 pc2009 rtkit-daemon[3887]: Sucessfully dropped privileges.
Jan 20 17:36:01 pc2009 rtkit-daemon[3887]: Sucessfully limited resources.
Jan 20 17:36:01 pc2009 rtkit-daemon[3887]: Running.
Jan 20 17:36:01 pc2009 rtkit-daemon[3887]: Canary thread running.
Jan 20 17:36:01 pc2009 rtkit-daemon[3887]: Failed to make ourselves RT: Operation not permitted
Jan 20 17:36:01 pc2009 rtkit-daemon[3887]: Watchdog thread running.
Jan 20 18:36:01 pc2009 pulseaudio[3910]: [pulseaudio] pid.c: Daemon already running.
Jan 20 18:36:01 pc2009 pulseaudio[3915]: [pulseaudio] pid.c: Daemon already running.
Jan 20 18:36:01 pc2009 pulseaudio[3917]: [pulseaudio] pid.c: Daemon already running.
Jan 20 18:36:26 pc2009 polkitd(authority=local): Registered Authentication Agent for unix-session:/org/freedesktop/ConsoleKit/Session1 (system bus name :1.41 [/usr/lib64/kde4/libexec/polkit-kde-authentication-agent-1], object path /org/kde/PolicyKit1/AuthenticationAgent, locale de_DE.UTF-8)
Jan 20 18:37:11 pc2009 kernel: 178.846434] fuse init (API version 7.17)
Jan 20 18:37:11 pc2009 dbus-daemon[1037]: **** /proc/self/mountinfo changed
Jan 20 18:37:11 pc2009 dbus-daemon[1037]: **** /proc/self/mountinfo changed
Now that you say this, Carlos, I remember that in older installations there was this re-mount too, which explicitly said re-mounting read-write. May be I am still a little confused by systemd and the new boot process… I went through the messages a little more carefully and saw the re-mount a couple of times. It just seems to be normal.
It has allways been the case (even before the existence of Linux) that the root file system is mounted read only early in the boot process. This so that programs can be loaded early in the boot process (the first one I can think of is* init*). It is done from data (sort of fstab, or even a copy of it)) in initrd.
(Off topic: there was a problem on the forums not long ago where somebody changed the file system type of his root partition. He changed everything he could think about, but the system could not boot. The error being that it tried that first read-omly mount with the old fs type and the superblock was wrong. He had to recreate initrd to cure this).
Then after the boot process being complete, the root partition is re-mounted rw for it’s further normal use. The message about this is allways in dmesg.
In sysvinit nobody cared about this (in normal cases), but systemd seems to have a sync problem here.
O.k. I understand that the re-mount is normal. But that it happens several times puzzles me. See at the excerpt of todays log. Just a couple of seconds after system start my disk is re-mounted twice in a row. And after my log in, which was almost an hour later, I get another one. The options have changed, is that the reason?
Cheers
Frank
Jan 21 09:36:05 pc2009 kernel: 1.870182] EXT4-fs (sdb1): mounted filesystem with ordered data mode. Opts: acl,user_xattr
Jan 21 09:36:05 pc2009 kernel: 1.879680] EXT4-fs (sdb1): re-mounted. Opts: acl,user_xattr
Jan 21 09:36:05 pc2009 kernel: 2.417509] EXT4-fs (sdb1): re-mounted. Opts: acl,user_xattr
…
(some lines of the following block have been deleted by me because they do not deal obviously with my disk sdb)
…
Jan 21 10:33:36 pc2009 dbus-daemon[1007]: helper(pid 3346): launched job udisks-helper-ata-smart-collect on /dev/sdb
Jan 21 10:33:36 pc2009 dbus-daemon[1007]: **** ADDED /sys/devices/pci0000:00/0000:00:0b.0/host3/target3:0:0/3:0:0:0/block/sdb
Jan 21 10:33:36 pc2009 dbus-daemon[1007]: **** ADDING /sys/devices/pci0000:00/0000:00:0b.0/host3/target3:0:0/3:0:0:0/block/sdb/sdb1
Jan 21 10:33:36 pc2009 dbus-daemon[1007]: **** UPDATING /sys/devices/pci0000:00/0000:00:0b.0/host3/target3:0:0/3:0:0:0/block/sdb/sdb1
Jan 21 10:33:36 pc2009 dbus-daemon[1007]: **** ADDED /sys/devices/pci0000:00/0000:00:0b.0/host3/target3:0:0/3:0:0:0/block/sdb/sdb1
Jan 21 10:33:36 pc2009 dbus-daemon[1007]: **** ADDING /sys/devices/pci0000:00/0000:00:0b.0/host3/target3:0:0/3:0:0:0/block/sdb/sdb2
Jan 21 10:33:36 pc2009 dbus-daemon[1007]: **** UPDATING /sys/devices/pci0000:00/0000:00:0b.0/host3/target3:0:0/3:0:0:0/block/sdb/sdb2
Jan 21 10:33:36 pc2009 dbus-daemon[1007]: **** ADDED /sys/devices/pci0000:00/0000:00:0b.0/host3/target3:0:0/3:0:0:0/block/sdb/sdb2
Jan 21 10:33:36 pc2009 dbus-daemon[1007]: **** CHANGING /sys/devices/pci0000:00/0000:00:0b.0/host3/target3:0:0/3:0:0:0/block/sdb/sdb2
Jan 21 10:33:36 pc2009 dbus-daemon[1007]: **** UPDATING /sys/devices/pci0000:00/0000:00:0b.0/host3/target3:0:0/3:0:0:0/block/sdb/sdb2
Jan 21 10:33:36 pc2009 dbus-daemon[1007]: **** CHANGED /sys/devices/pci0000:00/0000:00:0b.0/host3/target3:0:0/3:0:0:0/block/sdb/sdb2
Jan 21 10:33:36 pc2009 dbus-daemon[1007]: **** CHANGING /sys/devices/pci0000:00/0000:00:0b.0/host3/target3:0:0/3:0:0:0/block/sdb
Jan 21 10:33:36 pc2009 dbus-daemon[1007]: **** UPDATING /sys/devices/pci0000:00/0000:00:0b.0/host3/target3:0:0/3:0:0:0/block/sdb
Jan 21 10:33:36 pc2009 dbus-daemon[1007]: **** CHANGED /sys/devices/pci0000:00/0000:00:0b.0/host3/target3:0:0/3:0:0:0/block/sdb
Jan 21 10:33:36 pc2009 dbus-daemon[1007]: **** CHANGING /sys/devices/pci0000:00/0000:00:0b.0/host3/target3:0:0/3:0:0:0/block/sdb/sdb1
Jan 21 10:33:36 pc2009 dbus-daemon[1007]: **** UPDATING /sys/devices/pci0000:00/0000:00:0b.0/host3/target3:0:0/3:0:0:0/block/sdb/sdb1
Jan 21 10:33:36 pc2009 dbus-daemon[1007]: **** CHANGED /sys/devices/pci0000:00/0000:00:0b.0/host3/target3:0:0/3:0:0:0/block/sdb/sdb1
Jan 21 10:33:36 pc2009 dbus-daemon[1007]: helper(pid 3346): completed with exit code 0
Jan 21 10:33:36 pc2009 kernel: 3417.659148] EXT4-fs (sdb1): re-mounted. Opts: acl,user_xattr,commit=0
Jan 21 10:33:36 pc2009 dbus-daemon[1007]: **** EMITTING CHANGED for /sys/devices/pci0000:00/0000:00:0b.0/host3/target3:0:0/3:0:0:0/block/sdb
Jan 21 10:33:36 pc2009 dbus-daemon[1007]: **** /proc/self/mountinfo changed
