Regular ext4 error warning with HD in USB dock

Regular ext4 error warning with HD in USB dock

[Con Kolivas]

Hi all

Since I moved my internal HD into a USB dock externally and mount the ext4 
filesystem on it, I regularly get the following errors after it has been 
mounted for a while (see timecode). It doesn't seem to matter which recent 
kernel I use. 


[1048401.773270] EXT4-fs (sde8): mounted filesystem with writeback data mode. 
Opts: (null)
[1048702.736011] EXT4-fs (sde8): error count: 3
[1048702.736016] EXT4-fs (sde8): initial error at 1289053677: 
ext4_journal_start_sb:251
[1048702.736018] EXT4-fs (sde8): last error at 1289080948: ext4_put_super:719

I've forced an fs check numerous times but nothing comes up. There was only 
one occasion where the filesystem mounted RO but that was months ago and has 
since been fine.

This does not appear to cause any actual problems and happens it seems at 
_precisely_ the moment the hard drive decides to go into sleep mode as I hear 
it spin down. hdparm is unable to extract details from the hard drive when it 
is plugged into the usb dock.



The options used on this are as follows:
tune2fs 1.41.12 (17-May-2010)
Filesystem volume name:   backup
Last mounted on:          /media/backup
Filesystem UUID:          4eff5eb7-89fb-4db1-8cfd-f09db598a00b
Filesystem magic number:  0xEF53
Filesystem revision #:    1 (dynamic)
Filesystem features:      has_journal ext_attr resize_inode dir_index filetype 
needs_recovery extent flex_bg sparse_super large_file huge_file uninit_bg 
dir_nlink extra_isize
Filesystem flags:         signed_directory_hash 
Default mount options:    journal_data_writeback
Filesystem state:         clean
Errors behavior:          Continue
Filesystem OS type:       Linux
Inode count:              22593536
Block count:              90355576
Reserved block count:     0
Free blocks:              30330219
Free inodes:              21828725
First block:              0
Block size:               4096
Fragment size:            4096
Reserved GDT blocks:      1002
Blocks per group:         32768
Fragments per group:      32768
Inodes per group:         8192
Inode blocks per group:   512
Flex block group size:    16
Filesystem created:       Fri Jun 19 22:38:36 2009
Last mount time:          Tue Dec 28 09:36:34 2010
Last write time:          Tue Dec 28 09:36:34 2010
Mount count:              8
Maximum mount count:      -1
Last checked:             Sun Dec 19 21:50:05 2010
Check interval:           0 (<none>)
Lifetime writes:          1992 GB
Reserved blocks uid:      0 (user root)
Reserved blocks gid:      0 (group root)
First inode:              11
Inode size:               256
Required extra isize:     28
Desired extra isize:      28
Journal inode:            8
Default directory hash:   half_md4
Directory Hash Seed:      5cdfe619-0de5-4bcd-85d2-5fa5f4f13da7
Journal backup:           inode blocks


lsusb 
Bus 003 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 005 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 007 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 004 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 006 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 002 Device 008: ID 046d:c70a Logitech, Inc. MX5000 Cordless Desktop
Bus 002 Device 007: ID 046d:c70e Logitech, Inc. MX1000 Bluetooth Laser Mouse
Bus 002 Device 006: ID 0424:2228 Standard Microsystems Corp. 9-in-2 Card 
Reader
Bus 002 Device 005: ID 046d:0b02 Logitech, Inc. BT Mini-Receiver (HID proxy 
mode)
Bus 002 Device 004: ID 04b8:012c Seiko Epson Corp. Perfection V350 (GT-F700)
Bus 002 Device 003: ID 0424:2602 Standard Microsystems Corp. USB 2.0 Hub
Bus 002 Device 002: ID 0424:2514 Standard Microsystems Corp. USB 2.0 Hub
Bus 002 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 001 Device 003: ID 1759:5000 LucidPort Technology, Inc. 
Bus 001 Device 002: ID 1058:1100 Western Digital Technologies, Inc. 
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub

lspci 
00:00.0 Host bridge: Intel Corporation 82P965/G965 Memory Controller Hub (rev 
02)
00:01.0 PCI bridge: Intel Corporation 82P965/G965 PCI Express Root Port (rev 
02)
00:1a.0 USB Controller: Intel Corporation 82801H (ICH8 Family) USB UHCI 
Controller #4 (rev 02)
00:1a.1 USB Controller: Intel Corporation 82801H (ICH8 Family) USB UHCI 
Controller #5 (rev 02)
00:1a.7 USB Controller: Intel Corporation 82801H (ICH8 Family) USB2 EHCI 
Controller #2 (rev 02)
00:1b.0 Audio device: Intel Corporation 82801H (ICH8 Family) HD Audio 
Controller (rev 02)
00:1c.0 PCI bridge: Intel Corporation 82801H (ICH8 Family) PCI Express Port 1 
(rev 02)
00:1c.3 PCI bridge: Intel Corporation 82801H (ICH8 Family) PCI Express Port 4 
(rev 02)
00:1c.4 PCI bridge: Intel Corporation 82801H (ICH8 Family) PCI Express Port 5 
(rev 02)
00:1d.0 USB Controller: Intel Corporation 82801H (ICH8 Family) USB UHCI 
Controller #1 (rev 02)
00:1d.1 USB Controller: Intel Corporation 82801H (ICH8 Family) USB UHCI 
Controller #2 (rev 02)
00:1d.2 USB Controller: Intel Corporation 82801H (ICH8 Family) USB UHCI 
Controller #3 (rev 02)
00:1d.7 USB Controller: Intel Corporation 82801H (ICH8 Family) USB2 EHCI 
Controller #1 (rev 02)
00:1e.0 PCI bridge: Intel Corporation 82801 PCI Bridge (rev f2)
00:1f.0 ISA bridge: Intel Corporation 82801HB/HR (ICH8/R) LPC Interface 
Controller (rev 02)
00:1f.2 SATA controller: Intel Corporation 82801HB (ICH8) 4 port SATA AHCI 
Controller (rev 02)
00:1f.3 SMBus: Intel Corporation 82801H (ICH8 Family) SMBus Controller (rev 
02)
01:00.0 VGA compatible controller: nVidia Corporation G96 [GeForce 9400 GT] 
(rev a1)
02:00.0 SATA controller: JMicron Technology Corp. JMB362/JMB363 Serial ATA 
Controller (rev 02)
02:00.1 IDE interface: JMicron Technology Corp. JMB362/JMB363 Serial ATA 
Controller (rev 02)
03:00.0 Ethernet controller: Realtek Semiconductor Co., Ltd. RTL8111/8168B PCI 
Express Gigabit Ethernet controller (rev 01)
05:02.0 Multimedia video controller: Brooktree Corporation Bt878 Video Capture 
(rev 11)
05:02.1 Multimedia controller: Brooktree Corporation Bt878 Audio Capture (rev 
11)


Pointers would be appreciated, even if it's just "it's harmless, ignore it".

Thanks,
Con
-- 
-ck

Re: Regular ext4 error warning with HD in USB dock

[Ted Ts'o]

On Tue, Dec 28, 2010 at 09:53:45AM +1100, Con Kolivas wrote:
> 
> Since I moved my internal HD into a USB dock externally and mount the ext4 
> filesystem on it, I regularly get the following errors after it has been 
> mounted for a while (see timecode). It doesn't seem to matter which recent 
> kernel I use. 
> 
> [1048401.773270] EXT4-fs (sde8): mounted filesystem with writeback data mode. 
> Opts: (null)
> [1048702.736011] EXT4-fs (sde8): error count: 3
> [1048702.736016] EXT4-fs (sde8): initial error at 1289053677: 
> ext4_journal_start_sb:251
> [1048702.736018] EXT4-fs (sde8): last error at 1289080948: ext4_put_super:719

That's actually not an error.  It's a report which is generated every
24 hours, indicating that there has been 3 errors since the last time
the error count has been cleared, with the first error taking place at
Sat Nov 6 10:27:57 2010 (US/Eastern) in the function
ext4_journal_start_sb(), at line 251, and the most recent error taking
place at Sat Nov 6 18:02:28 2010 (US/Eastern), in the function
ext4_put_super() at line 719.  This is a new feature which was added
in 2.6.36.

This information (which is stored in the ext4 superblock) gets cleared
by e2fsck version 1.41.13 or newer (1.41.14 is the most recently
released version).  If you are using an older version of e2fsck, this
information won't get cleared, which is not a disaster, although it
could potentially get annoying.  The solution is to simply to upgrade
to the newest version of e2fsprogs if you are using the 2.6.36 or
newer kernel.

The idea behind this feature is to make sure that if there was a file
system corruption detected, it wouldn't be lost due to log files
getting overflowed.  It's also helpful when users report problems to
distribution support lines, since it makes it more likely support
personnel will be able to determine that there has been some file
system corrutpion issues, perhaps caused by hardware problems, or some
other cause, including kernel bugs.

Hope this helps explain what you're seeing!

						- Ted

Re: Regular ext4 error warning with HD in USB dock

[Rogier Wolff]

On Mon, Dec 27, 2010 at 09:53:43PM -0500, Ted Ts'o wrote:
> On Tue, Dec 28, 2010 at 09:53:45AM +1100, Con Kolivas wrote:
> > [1048401.773270] EXT4-fs (sde8): mounted filesystem with writeback data mode. 
> > Opts: (null)
> > [1048702.736011] EXT4-fs (sde8): error count: 3
> > [1048702.736016] EXT4-fs (sde8): initial error at 1289053677: 
> > ext4_journal_start_sb:251
> > [1048702.736018] EXT4-fs (sde8): last error at 1289080948: ext4_put_super:719
> 
> That's actually not an error.  It's a report which is generated every
> 24 hours, indicating that there has been 3 errors since the last time
> the error count has been cleared, with the first error taking place at
> Sat Nov 6 10:27:57 2010 (US/Eastern) in the function
> ext4_journal_start_sb(), at line 251, and the most recent error taking
> place at Sat Nov 6 18:02:28 2010 (US/Eastern), in the function
> ext4_put_super() at line 719.  This is a new feature which was added
> in 2.6.36.

Nice. But the issue you're not mentioning is: What errors could have 
happened on the 6th of november? Should Con worry about those errors?

OK, the chances are that he has rebooted since november, and that an
older fsck fixed the errors, but not cleared the "fs errror log". Would
these errors have triggered a "remount-readonly" if the fs was mounted 
like that?

I don't reboot that often: 

obelix:~> uptime
 09:16:19 up 175 days, 19:04, 19 users,  load average: 110.10, 110.61, 111.22

(and yes, the load is quite high on that machine. I won't polute this
thread about that....)

	Roger. 

-- 
** R.E.Wolff@BitWizard.nl ** http://www.BitWizard.nl/ ** +31-15-2600998 **
**    Delftechpark 26 2628 XH  Delft, The Netherlands. KVK: 27239233    **
*-- BitWizard writes Linux device drivers for any device you may have! --*
Q: It doesn't work. A: Look buddy, doesn't work is an ambiguous statement. 
Does it sit on the couch all day? Is it unemployed? Please be specific! 
Define 'it' and what it isn't doing. --------- Adapted from lxrbot FAQ

Re: Regular ext4 error warning with HD in USB dock

[Con Kolivas]

On Tue, 28 Dec 2010 19:19:17 Rogier Wolff wrote:
> On Mon, Dec 27, 2010 at 09:53:43PM -0500, Ted Ts'o wrote:
> > On Tue, Dec 28, 2010 at 09:53:45AM +1100, Con Kolivas wrote:
> > > [1048401.773270] EXT4-fs (sde8): mounted filesystem with writeback data
> > > mode. Opts: (null)
> > > [1048702.736011] EXT4-fs (sde8): error count: 3
> > > [1048702.736016] EXT4-fs (sde8): initial error at 1289053677:
> > > ext4_journal_start_sb:251
> > > [1048702.736018] EXT4-fs (sde8): last error at 1289080948:
> > > ext4_put_super:719
> > 
> > That's actually not an error.  It's a report which is generated every
> > 24 hours, indicating that there has been 3 errors since the last time
> > the error count has been cleared, with the first error taking place at
> > Sat Nov 6 10:27:57 2010 (US/Eastern) in the function
> > ext4_journal_start_sb(), at line 251, and the most recent error taking
> > place at Sat Nov 6 18:02:28 2010 (US/Eastern), in the function
> > ext4_put_super() at line 719.  This is a new feature which was added
> > in 2.6.36.
> 
> Nice. But the issue you're not mentioning is: What errors could have
> happened on the 6th of november? Should Con worry about those errors?
> 
> OK, the chances are that he has rebooted since november, and that an
> older fsck fixed the errors, but not cleared the "fs errror log". Would
> these errors have triggered a "remount-readonly" if the fs was mounted
> like that?

Indeed the FS was remounted as RO at the time. I had to power down the USB 
device and power it up again after umounting the FS and then doing an FSCK 
before it was usable again, and the machine had about a month of uptime when 
it happened. It has not caused a problem since.

Thanks,
Con
-- 
-ck

Re: Regular ext4 error warning with HD in USB dock

[Amir Goldstein]

On Tue, Dec 28, 2010 at 10:19 AM, Rogier Wolff <R.E.Wolff@bitwizard.nl> wrote:
> On Mon, Dec 27, 2010 at 09:53:43PM -0500, Ted Ts'o wrote:
>> On Tue, Dec 28, 2010 at 09:53:45AM +1100, Con Kolivas wrote:
>> > [1048401.773270] EXT4-fs (sde8): mounted filesystem with writeback data mode.
>> > Opts: (null)
>> > [1048702.736011] EXT4-fs (sde8): error count: 3
>> > [1048702.736016] EXT4-fs (sde8): initial error at 1289053677:
>> > ext4_journal_start_sb:251
>> > [1048702.736018] EXT4-fs (sde8): last error at 1289080948: ext4_put_super:719
>>
>> That's actually not an error.  It's a report which is generated every
>> 24 hours, indicating that there has been 3 errors since the last time
>> the error count has been cleared, with the first error taking place at
>> Sat Nov 6 10:27:57 2010 (US/Eastern) in the function
>> ext4_journal_start_sb(), at line 251, and the most recent error taking
>> place at Sat Nov 6 18:02:28 2010 (US/Eastern), in the function
>> ext4_put_super() at line 719.  This is a new feature which was added
>> in 2.6.36.
>
> Nice. But the issue you're not mentioning is: What errors could have
> happened on the 6th of november? Should Con worry about those errors?
>

Ted,

I would like to use this opportunity to remind you about my
record_journal_errstr()
implementation, see:
https://github.com/amir73il/ext4-snapshots/blob/next3-stable/fs/next3/super.c#L157

It records the initial errors messages (which I found to be the most
interesting),
in a message buffer on the unused space after the journal super block
(3K on a 4K block fs).

fsck prints out those messages and clears the buffer.
In under a year of Next3 fs in beta and production, it has helped me many times
to analyse bugs post-mortem and find the problem.

If there is demand, I can post the patch for Ext4.

Amir.

> OK, the chances are that he has rebooted since november, and that an
> older fsck fixed the errors, but not cleared the "fs errror log". Would
> these errors have triggered a "remount-readonly" if the fs was mounted
> like that?
>
> I don't reboot that often:
>
> obelix:~> uptime
>  09:16:19 up 175 days, 19:04, 19 users,  load average: 110.10, 110.61, 111.22
>
> (and yes, the load is quite high on that machine. I won't polute this
> thread about that....)
>
>        Roger.
>
> --
> ** R.E.Wolff@BitWizard.nl ** http://www.BitWizard.nl/ ** +31-15-2600998 **
> **    Delftechpark 26 2628 XH  Delft, The Netherlands. KVK: 27239233    **
> *-- BitWizard writes Linux device drivers for any device you may have! --*
> Q: It doesn't work. A: Look buddy, doesn't work is an ambiguous statement.
> Does it sit on the couch all day? Is it unemployed? Please be specific!
> Define 'it' and what it isn't doing. --------- Adapted from lxrbot FAQ
> --
> To unsubscribe from this list: send the line "unsubscribe linux-ext4" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html
>

Re: Regular ext4 error warning with HD in USB dock

[Ric Wheeler]

On 12/28/2010 05:30 AM, Amir Goldstein wrote:
> On Tue, Dec 28, 2010 at 10:19 AM, Rogier Wolff<R.E.Wolff@bitwizard.nl>  wrote:
>> On Mon, Dec 27, 2010 at 09:53:43PM -0500, Ted Ts'o wrote:
>>> On Tue, Dec 28, 2010 at 09:53:45AM +1100, Con Kolivas wrote:
>>>> [1048401.773270] EXT4-fs (sde8): mounted filesystem with writeback data mode.
>>>> Opts: (null)
>>>> [1048702.736011] EXT4-fs (sde8): error count: 3
>>>> [1048702.736016] EXT4-fs (sde8): initial error at 1289053677:
>>>> ext4_journal_start_sb:251
>>>> [1048702.736018] EXT4-fs (sde8): last error at 1289080948: ext4_put_super:719
>>> That's actually not an error.  It's a report which is generated every
>>> 24 hours, indicating that there has been 3 errors since the last time
>>> the error count has been cleared, with the first error taking place at
>>> Sat Nov 6 10:27:57 2010 (US/Eastern) in the function
>>> ext4_journal_start_sb(), at line 251, and the most recent error taking
>>> place at Sat Nov 6 18:02:28 2010 (US/Eastern), in the function
>>> ext4_put_super() at line 719.  This is a new feature which was added
>>> in 2.6.36.
>> Nice. But the issue you're not mentioning is: What errors could have
>> happened on the 6th of november? Should Con worry about those errors?
>>
> Ted,
>
> I would like to use this opportunity to remind you about my
> record_journal_errstr()
> implementation, see:
> https://github.com/amir73il/ext4-snapshots/blob/next3-stable/fs/next3/super.c#L157
>
> It records the initial errors messages (which I found to be the most
> interesting),
> in a message buffer on the unused space after the journal super block
> (3K on a 4K block fs).
>
> fsck prints out those messages and clears the buffer.
> In under a year of Next3 fs in beta and production, it has helped me many times
> to analyse bugs post-mortem and find the problem.
>
> If there is demand, I can post the patch for Ext4.
>
> Amir.

I do think that this sounds like a useful addition - should be very useful in 
doing post mortem analysis...

Thanks!

Ric

Re: Regular ext4 error warning with HD in USB dock

[Ted Ts'o]

On Tue, Dec 28, 2010 at 09:19:17AM +0100, Rogier Wolff wrote:
> > That's actually not an error.  It's a report which is generated every
> > 24 hours, indicating that there has been 3 errors since the last time
> > the error count has been cleared, with the first error taking place at
> > Sat Nov 6 10:27:57 2010 (US/Eastern) in the function
> > ext4_journal_start_sb(), at line 251, and the most recent error taking
> > place at Sat Nov 6 18:02:28 2010 (US/Eastern), in the function
> > ext4_put_super() at line 719.  This is a new feature which was added
> > in 2.6.36.
> 
> Nice. But the issue you're not mentioning is: What errors could have 
> happened on the 6th of november? Should Con worry about those errors?

It looks like those errors were probably caused by I/O errors while
writing to the journal.  Maybe due to a flakey USB connection,
perhaps?  It would be useful to look at the /var/log/messagfes around
that date to get a more detailed look.

> OK, the chances are that he has rebooted since november, and that an
> older fsck fixed the errors, but not cleared the "fs errror log". Would
> these errors have triggered a "remount-readonly" if the fs was mounted 
> like that?

Yes, errors that get recorded into the superblock are also errors that
would cause a read-only remount if the file system is set that way.

      	      			       	    - Ted

Re: Regular ext4 error warning with HD in USB dock

[torn5]

On 12/28/2010 03:53 AM, Ted Ts'o wrote:
> On Tue, Dec 28, 2010 at 09:53:45AM +1100, Con Kolivas wrote:
>    
>> Since I moved my internal HD into a USB dock externally and mount the ext4
>> filesystem on it, I regularly get the following errors after it has been
>> mounted for a while (see timecode). It doesn't seem to matter which recent
>> kernel I use.
>>
>> [1048401.773270] EXT4-fs (sde8): mounted filesystem with writeback data mode.
>> Opts: (null)
>> [1048702.736011] EXT4-fs (sde8): error count: 3
>> [1048702.736016] EXT4-fs (sde8): initial error at 1289053677:
>> ext4_journal_start_sb:251
>> [1048702.736018] EXT4-fs (sde8): last error at 1289080948: ext4_put_super:719
>>      
> That's actually not an error.  It's a report which is generated every
> 24 hours, indicating that there has been 3 errors since the last time
> the error count has been cleared, with the first error taking place at
> Sat Nov 6 10:27:57 2010 (US/Eastern) in the function
> ext4_journal_start_sb(), at line 251, and the most recent error taking
> place at Sat Nov 6 18:02:28 2010 (US/Eastern), in the function
> ext4_put_super() at line 719.  This is a new feature which was added
> in 2.6.36.
>    


This is going to be a faq...
I suppose the datetime is encoded (what format is that?) in that long 
number after "at".
May I suggest the datetime gets decoded in the printing?
Also may I suggest that the error happens immediately after mount and 
not after 300 seconds from mount?

I just subscribed to this list exactly to report the same kind of error.

Last week I was doing reliability tests for open-iscsi and this error 
drove me crazy. I spent days in tests where I thought I could reproduce 
an error in open-iscsi by disconnecting and reconnecting the network; I 
even reported this to the open-iscsi mailing list, but in fact it was an 
old error of the filesystem and it was not getting cleared by my older 
e2fsck 1.41.11 .

If that happened immediately after mount or if it spitted the datetime 
in human readable format, I would have immediately guessed it was due to 
an existing "filesystem problem" (even though I was running fsck.ext4 -f 
prior to each mount) but instead I thought it was due to my 5 minutes of 
"networks disconnection tests" I was doing after each mount. DOH!

Anyway thanks for your work: excellent filesystem.

PS: I have a question for you regarding ext4 behaviour with SCSI 
commands resubmissions... ok I am opening another thread for that.

Re: Regular ext4 error warning with HD in USB dock

[Ted Ts'o]

On Tue, Dec 28, 2010 at 11:41:53AM +0100, torn5 wrote:
> 
> This is going to be a faq...
> I suppose the datetime is encoded (what format is that?) in that
> long number after "at".

Number of seconds since January 1st, 1970 midnight GMT.  (Standard
Unix-time format).  It's hard for the kernel to decode it since it
doesn't know what time-zone you are in, or what your local legislature
has done vis-a-vis arbitrary and cabritious adjustments to the
start/stop date of daylight savings time, etc.

It's easy enough to decode it using perl:

   perl -e '$t = localtime(1289053677); print "$t\n"'

> May I suggest the datetime gets decoded in the printing?
> Also may I suggest that the error happens immediately after mount
> and not after 300 seconds from mount?

Hmmm.... maybe.  The idea behind the 300 second delay was for the root
file system, to let e2fsck have a chance to fix the file system before
reporting the errors at mount time.

						- Ted


     	     	       

Re: Regular ext4 error warning with HD in USB dock

[Ben Pfaff]

Ted Ts'o <tytso@mit.edu> writes:

> On Tue, Dec 28, 2010 at 11:41:53AM +0100, torn5 wrote:
>> 
>> This is going to be a faq...
>> I suppose the datetime is encoded (what format is that?) in that
>> long number after "at".
>
> Number of seconds since January 1st, 1970 midnight GMT.  (Standard
> Unix-time format).  It's hard for the kernel to decode it since it
> doesn't know what time-zone you are in, or what your local legislature
> has done vis-a-vis arbitrary and cabritious adjustments to the
> start/stop date of daylight savings time, etc.
>
> It's easy enough to decode it using perl:
>
>    perl -e '$t = localtime(1289053677); print "$t\n"'

The "date" program can decode these values too:
        date -d @1289053677
-- 
Ben Pfaff 
http://benpfaff.org

Re: Regular ext4 error warning with HD in USB dock

[torn5]

On 12/28/2010 03:32 PM, Ted Ts'o wrote:
> On Tue, Dec 28, 2010 at 11:41:53AM +0100, torn5 wrote:
>    
>> This is going to be a faq...
>> I suppose the datetime is encoded (what format is that?) in that
>> long number after "at".
>>      
> Number of seconds since January 1st, 1970 midnight GMT.  (Standard
> Unix-time format).  It's hard for the kernel to decode it since it
> doesn't know what time-zone you are in, or what your local legislature
> has done vis-a-vis arbitrary and cabritious adjustments to the
> start/stop date of daylight savings time, etc.
>    

I suggest to decode it in GMT then.
Like this it's not possible to guess it's a "time" value, and hence that 
it's an *old* error. I thought it was a pointer to something, and so I 
thought the error was happening now, or more likely (since it was 
triggered after 300 seconds) that it was some inconsistency in the 
filesystem being detected now, in some kind of lazy check.