Superblock last write time is in the future

[rg003]

Hello everyone!

I'm new to Fedora and this is my first post. About a month ago I installed Fedora 21 in my computer. I chose a minimal installation with a few additions. Everything was fine until March 5th, when I started to notice the system booted a bit slower than usual (it normally takes less than 3 seconds, so adding 2 extra seconds is noticeable).

I fired systemd-analyze critical-chain and it blamed systemd-fsck-root.service as the problem. I examined the history log for that service and funnily enough, I had started to get the following messages while booting and the service is now taking 2.6 seconds alone to run:

-- Reboot --
Mar 05 07:17:33 localhost.localdomain systemd-fsck[280]: ROOTFS: clean, 362548/7331840 files, 12428807/29304945 blocks
-- Reboot --
Mar 05 07:20:10 localhost.localdomain systemd-fsck[278]: ROOTFS: Superblock last write time is in the future.
Mar 05 07:20:10 localhost.localdomain systemd-fsck[278]: (by less than a day, probably due to the hardware clock being incorrectly set).  FIXED.
Mar 05 07:20:12 localhost.localdomain systemd-fsck[278]: ROOTFS: 362572/7331840 files (0.2% non-contiguous), 12431446/29304945 blocks

The workaround for that problem as suggested by a web search is to simply put "broken_system_clock = 1" in /etc/e2fsck.conf. That works, but I want to know why it's complaining, because I don't know what's wrong and I'm unable to get rid of the problem.

• The system dualboots Fedora and Windows 7.
• On installation Fedora configured the hardware clock as using local time (confirmed from /etc/adjtime).
• The BIOS shows the correct local time.
• Using date on the command line shows the correct local time.
• hwclock displays the correct local time too.
• This is a desktop computer permanently on AC power, not an embedded system, laptop or whatever.
• dumpe2fs on the root filesystem (the only Linux filesystem, by the way) displays an apparently correct local time in the last write field.

Is anyone having this same problem? I'm suspecting a bug in e2fsprogs for a simple reason. If you check the journal output above, you see I got a clean check at 7:17 and a problematic check at 7:20. I reviewed the history with yum and at 7:18 I installed a bunch of updates for that day, including e2fsprogs and e2fsprogs-libs, and presumably rebooted after the update.

Thanks in advance for any advice and information.

[jpollard]

There are two possibilities:

1. you have a bad clock (actually, it could be slow, and the system doesn't get to update the hardware clock on shutdown).

2. You don't shut the system down such that the current time is recorded in the filesystem and in the hardware clock.

#2 sometimes happens if the system is configured for time based on UTC, but the hardware is actually on local time. This normally would show up with the time suddenly offset by an hour or more. This could get hidden if the system resyncs itself to an external time source (which likely happens after the disks are mounted) as the time checks made then would look normal.

[rg003]

How would I go about checking #1? After rebooting, I check the clock on the BIOS and it seems to have the proper local time, accurate to less than one second. Also, hwclock --systohc (with or without --localtime) just before rebooting doesn't seem to fix anything.

About #2, normally I shut the system down using "sudo /sbin/shutdown -r now" or "sudo /sbin/shutdown -h now" (I have a couple of aliases because of the length of those commands). If there's a better way to do it in Fedora, please do tell. I know /sbin/shutdown is linked to systemctl but not much more.

[jpollard]

I'm not sure on #1 as it may depend on the motherboard and how it does things. On my system "hwclock --show" shows the hardware clock being a second behind actual time - and repeated queries show it is REALLY variable (the smallest was -0.031590 seconds, largest -1.000320 seconds, and it jumps nearly the entire range in a second. Not very accurate).

Does the system actually halt (as in actually go to bios/ufi/halt)?

Normally, I'm just rebooting - and that has been working with f21.

BTW, In my looking around I found:
https://bugs.debian.org/cgi-bin/bugr...cgi?bug=755722

Which refers to an earlier:
http://lists.freedesktop.org/archive...ay/002526.html

This is Pottering saying systemd will not update the hardware clock on shutdown.

So what you are seeing isn't unknown.

[PabloTwo]

You can use the command timedatectl status to check if your clock settings are as you think they are.

[zimon]

Same thing here. This started after fedup from F20 to F21.

It now in every reboot complains, and fscks lvm filesystems:

Mar 05 15:27:27 myhost systemd-fsck[868]: /dev/mapper/vg_myhost-lv_root: Superblock last write time is in the future.
Mar 05 15:27:27 myhost systemd-fsck[868]: (by less than a day, probably due to the hardware clock being incorrectly set).  FIXED.
Mar 05 15:28:17 myhost systemd-fsck[868]: /dev/mapper/vg_myhost-lv_root: 585938/3276800 files (1.5% non-contiguous), 9247946/13107200 blocks

# journalctl -t systemd-fsck|grep future
Feb 20 17:05:38 myhost systemd-fsck[1167]: /dev/mapper/vg_myhost-lv_root: Superblock last write time is in the future.
Feb 21 15:22:05 myhost systemd-fsck[1001]: /dev/mapper/vg_myhost-lv_root: Superblock last write time is in the future.
Feb 21 17:37:59 myhost systemd-fsck[855]: /dev/mapper/vg_myhost-lv_root: Superblock last write time is in the future.
Feb 23 19:17:07 myhost systemd-fsck[1179]: /dev/mapper/vg_myhost-lv_root: Superblock last write time is in the future.
Feb 25 17:50:58 myhost systemd-fsck[970]: /dev/mapper/vg_myhost-lv_root: Superblock last write time is in the future.
Feb 25 19:26:51 myhost systemd-fsck[897]: /dev/mapper/vg_myhost-lv_root: Superblock last write time is in the future.
Feb 25 19:49:36 myhost systemd-fsck[4335]: /dev/mapper/vg_myhost-lv_root: Superblock last write time is in the future.
Feb 25 20:24:05 myhost systemd-fsck[855]: /dev/mapper/vg_myhost-lv_root: Superblock last write time is in the future.
Feb 26 16:11:26 myhost systemd-fsck[1239]: /dev/mapper/vg_myhost-lv_root: Superblock last write time is in the future.
....
Several lines omitted.
IN EVERY REBOOT
NO CRASHES THERE HAVE BEEN.
.....
Mar 04 20:58:32 myhost systemd-fsck[767]: /dev/mapper/vg_myhost-lv_root: Superblock last write time is in the future.
Mar 05 13:26:40 myhost systemd-fsck[788]: /dev/mapper/vg_myhost-lv_root: Superblock last write time is in the future.
Mar 05 13:39:16 myhost systemd-fsck[778]: /dev/mapper/vg_myhost-lv_root: Superblock last write time is in the future.
Mar 05 14:40:36 myhost systemd-fsck[760]: /dev/mapper/vg_myhost-lv_root: Superblock last write time is in the future.
Mar 05 15:12:37 myhost systemd-fsck[768]: /dev/mapper/vg_myhost-lv_root: Superblock last write time is in the future.
Mar 05 15:27:27 myhost systemd-fsck[868]: /dev/mapper/vg_myhost-lv_root: Superblock last write time is in the future.

I have "GRUB_GFXPAYLOAD_LINUX=text" in /etc/sysconfig/grub, so I have seen this happening every time since fedup from F20 to F21.
Due to other problems with F21, I didn't before ask about this nor filed a bug.

HWclock is in local time also. In Fedora 20 this was not a problem.

"clock -r" and "date" commands show the same time, "-0.301770 seconds".

[rg003]

@jpollard Yes, I halt the system normally after use, and when I reboot it goes to the BIOS. I forgot to mention I sometimes reboot from the console, outside of X11, by using the classic Ctrl+Alt+Del. I believe this triggers the same thing as shutdown -r now. The Debian thread you mention is interesting, but all affected users seem to have different problems with the hardware clock being off, which does not appear to be my case.

@PabloTwo Thanks for the tip. Indeed, the config appears to be right as I mentioned. It ends with a warning about keeping the clock in local time and the problem when DST kicks in, but nothing more. Note DST will not kick in in my timezone until the end of March. It was not active before or after the problem showed up.

# timedatectl status
      Local time: Tue 2015-03-10 00:50:06 CET
  Universal time: Mon 2015-03-09 23:50:06 UTC
        RTC time: Tue 2015-03-10 00:50:07
       Time zone: Europe/Madrid (CET, +0100)
     NTP enabled: yes
NTP synchronized: yes
 RTC in local TZ: yes
      DST active: no
 Last DST change: DST ended at
                  Sun 2014-10-26 02:59:59 CEST
                  Sun 2014-10-26 02:00:00 CET
 Next DST change: DST begins (the clock jumps one hour forward) at
                  Sun 2015-03-29 01:59:59 CET
                  Sun 2015-03-29 03:00:00 CEST

Warning: The system is configured to read the RTC time in the local time zone. This
         mode can not be fully supported. It will create various problems with time
         zone changes and daylight saving time adjustments. The RTC time is never updated,
         it relies on external facilities to maintain it. If at all possible, use
         RTC in UTC by calling 'timedatectl set-local-rtc 0'.

[jpollard]

@jpollard Yes, I halt the system normally after use, and when I reboot it goes to the BIOS. I forgot to mention I sometimes reboot from the console, outside of X11, by using the classic Ctrl+Alt+Del. I believe this triggers the same thing as shutdown -r now. The Debian thread you mention is interesting, but all affected users seem to have different problems with the hardware clock being off, which does not appear to be my case.

All shutdown methods that used to work don't exist with systemd - so all of the former commands use systemd to shutdown.

All the hardware clock has to be is in the past - and one second would be enough to trigger this.

Does it also happen if you wait a minute or more before rebooting?

[lsatenstein]

There are two possibilities:

1. you have a bad clock (actually, it could be slow, and the system doesn't get to update the hardware clock on shutdown).

2. You don't shut the system down such that the current time is recorded in the filesystem and in the hardware clock.

#2 sometimes happens if the system is configured for time based on UTC, but the hardware is actually on local time. This normally would show up with the time suddenly offset by an hour or more. This could get hidden if the system resyncs itself to an external time source (which likely happens after the disks are mounted) as the time checks made then would look normal.

Please include

#3 Switch to daylight savings time for North America. I too had this problem. In my case it eventually it corrected itself.

[lsatenstein]

@jpollard Yes, I halt the system normally after use, and when I reboot it goes to the BIOS. I forgot to mention I sometimes reboot from the console, outside of X11, by using the classic Ctrl+Alt+Del. I believe this triggers the same thing as shutdown -r now. The Debian thread you mention is interesting, but all affected users seem to have different problems with the hardware clock being off, which does not appear to be my case.

@PabloTwo Thanks for the tip. Indeed, the config appears to be right as I mentioned. It ends with a warning about keeping the clock in local time and the problem when DST kicks in, but nothing more. Note DST will not kick in in my timezone until the end of March. It was not active before or after the problem showed up.

# timedatectl status
      Local time: Tue 2015-03-10 00:50:06 CET
  Universal time: Mon 2015-03-09 23:50:06 UTC
        RTC time: Tue 2015-03-10 00:50:07
       Time zone: Europe/Madrid (CET, +0100)
     NTP enabled: yes
NTP synchronized: yes
 RTC in local TZ: yes
      DST active: no
 Last DST change: DST ended at
                  Sun 2014-10-26 02:59:59 CEST
                  Sun 2014-10-26 02:00:00 CET
 Next DST change: DST begins (the clock jumps one hour forward) at
                  Sun 2015-03-29 01:59:59 CET
                  Sun 2015-03-29 03:00:00 CEST

Warning: The system is configured to read the RTC time in the local time zone. This
         mode can not be fully supported. It will create various problems with time
         zone changes and daylight saving time adjustments. The RTC time is never updated,
         it relies on external facilities to maintain it. If at all possible, use
         RTC in UTC by calling 'timedatectl set-local-rtc 0'.

Hi jpollard

My experimenting with ctl-alt-delete, or with popping the power on button on my desktop (it does the equivalent), invokes shutdown. But I also discovered that it does not perform a "sync" command beforehand. If your data is in the cache, and if there are open file(s), the filesystem will not be clean. On a the next boot, you will often see the recovering from journal message.

So, rathen than do ctl-alt-delete, from terminal mode, issue sync ; sync ; poweroff
as a reminder, review poweroff and"shutdown now" from the man pages.

This note not directed at you JP.
New to Linux? enter terminal mode and type man shutdown

[jpollard]

Hi jpollard

My experimenting with ctl-alt-delete, or with popping the power on button on my desktop (it does the equivalent), invokes shutdown. But I also discovered that it does not perform a "sync" command beforehand. If your data is in the cache, and if there are open file(s), the filesystem will not be clean. On a the next boot, you will often see the recovering from journal message.

So, rathen than do ctl-alt-delete, from terminal mode, issue sync ; sync ; poweroff
as a reminder, review poweroff and"shutdown now" from the man pages.

This note not directed at you JP.
New to Linux? enter terminal mode and type man shutdown

New to Fedora?
systemd interprets ALL of the shutdown methods.

Check: http://www.freedesktop.org/software/...d.special.html

$ ls -l /usr/sbin/shutdown /usr/sbin/halt /usr/sbin/poweroff
lrwxrwxrwx. 1 root root 16 Feb  5 14:51 /usr/sbin/halt -> ../bin/systemctl
lrwxrwxrwx. 1 root root 16 Feb  5 14:51 /usr/sbin/shutdown -> ../bin/systemctl
lrwxrwxrwx. 1 root root 16 Feb  5 14:51 /usr/sbin/poweroff -> ../bin/systemctl

And whether or not popping the power button calls one of the earlier methods - if the filesystems are not synched you actually crashed the system.

Been there done that.

It is also one of the reasons I moved to ext4 - better recovery. I may move to btrfs soon.

[rg003]

@jpollard Yes, it happens even if I wait 1 minute in the BIOS or at the GRUB prompt. It also happens even if I run hwclock --localtime --systohc just before rebooting.

[zimon]

And I kept machine shut off for 10 minutes, but it did not affect the issue. The machine was shutdown from GNOME panel menu.

I now changed "timedatectl set-local-rtc 0" and hwclock is now in UTC time. Let's see next time if it still complains and does the fsck'ing. I rather would keep hwclock in UTC anyway, but Windows 7 had problems with it. But my Windows 7 installation has been broken anyway now for months, so I have no problem now to keep hwclock in UTC.

[rg003]

I had meant to reply to this thread a few days ago but it was impossible due to lack of time. Basically, I think it's simply a bug either in the kernel, initial RAM disk or some startup unit, but I don't know how to investigate a bit more or who to report the bug to. Let me tell you what I did.

I downloaded e2fsprogs from sources, and compiled e2fsck myself. Superblock times are checked here, and you can see the mount time is checked first, followed by the last write time, but the problem seems to happen with the superblock write time and not mount time. Before those checks take place, I made the program print the current time (ctx->now), the superblock last write time (fs->super->s_wtime) and the superblock last mount time (fs->super->s_mtime). I replaced e2fsck, fsck.ext{2,3,4,4dev} with my custom version temporarily.

Then I booted Fedora, and immediately rebooted (last mount and write time should be similar). I booted from a live USB then, without mounting the filesystem, and ran dumpe2fs -h on it. From the live USB, I could see both times were almost the same (a few seconds apart) and appropriately matched the current wall clock time, more or less. Then I finally booted Fedora, running then with my modified tools. Same error as always, but I could see the last write time was 3599 seconds in the future (about the local offset from UTC for Europe/Madrid, by the way) thanks to the print statements, while the last mount time was fine as it was from the live USB. Knowing both times were similar from the live USB, I conclude something breaks the superblock last write time while booting.

I've now gone the same path as zimon above, simply setting the hardware clock to UTC and telling Windows to be in UTC. In Windows you can add more clocks or use a desktop widget in a different time zone, so it's not really a problem (and I use Windows only for gaming, so I don't mind). I prefer this solution to covering up the bug by telling e2fsck that the system clock is broken, which I don't think it is.

Any ideas about who to report the bug to, or how to continue investigating?

[jpollard]

Post it to bugzilla under Fedora.

Your evidence makes it seem the ramfs is setting a local time even when it isn't, and always using UTC.