delayed updates to file-access time
D P Schreber
behavior of hfs+ requires special configuration options to be used when
building mutt in osx. The oddity is this: read-only operations on files
don't update the access time immediately. Instead, the access time is
updated a few (up to 5?) minutes later.
As a simple example, consider the following. I have a file that hasn't
been accessed since since 17-Dec. If I cat it to /dev/null today
(20-Dec, 13:54) the access time doesn't change:
> ls -lu mail ; cat mail > /dev/null ; ls -lu mail
-rw-r--r-- 1 xxxxxxx yyyyyy 10836 17 Dec 20:49 mail
-rw-r--r-- 1 xxxxxxx yyyyyy 10836 17 Dec 20:49 mail
The access time will stay this way for some minutes, and then suddenly
switch to the current time (not to the time of the 'cat', but the time
when the status update finally occurs).
Any read-only file operation behaves the same -- there's nothing special
about cat'ing to /dev/null. Otoh operations like 'touch' set the access
time is immediately.
This odd behavior occurs whether or not journaling is enabled.
Is this a known quirk of hfs+? I didn't find any descriptions of it
outside the context of mutt.
Heath Raftery
That is an odd quirk. Unfortunately, I'm going to complicate the matter a bit
by saying that I cannot reproduce this behaviour on my system!
$ ls -lu unison.log; cat unison.log > /dev/null; ls -lu unison.log
-rw------- 1 liteyear liteyear 264308 28 Nov 19:05 unison.log
-rw------- 1 liteyear liteyear 264308 21 Dec 09:03 unison.log
Mac OS X 10.3.6 on a G4 iMac logged in via SSH using bash.
$ ls -lu cvsqrc.pdf; cat cvsqrc.pdf > /dev/null; ls -lu cvsqrc.pdf
-rw-r--r-- 1 liteyear liteyear 81544 4 Aug 18:32 cvsqrc.pdf
-rw-r--r-- 1 liteyear liteyear 81544 21 Dec 09:08 cvsqrc.pdf
Mac OS X 10.3.5 on a G4 Powerbook logged in locally using bash.
HTH in some way! Let us know what you find.
Heath
--
*--------------------------------------------------------*
| ^Nothing is foolproof to a sufficiently talented fool^ |
| Heath Raftery, HRSoftWorks _\|/_ |
*______________________________________m_('.')_m_________*
D P Schreber
> That is an odd quirk. Unfortunately, I'm going to complicate the matter a bit
> by saying that I cannot reproduce this behaviour on my system!
Hmm, very interesting. This is an hfs+ file system, correct? Is
journaling enabled? If not, has it ever been?
> Mac OS X 10.3.6 on a G4 iMac logged in via SSH using bash.
I should have listed version numbers: I've done this test in 10.3.6 and
10.3.7 but not in earlier systems. I use tcsh, but running the same
test in bash has the same results.
> HTH in some way!
It's definitely useful to know that it's not a universal problem. All
the osx users in the mutt newsgroup had the same results I did. Can you
think of anything in any way unusual about your system configuration?
Heath Raftery
>> That is an odd quirk. Unfortunately, I'm going to complicate the matter a bit
>> by saying that I cannot reproduce this behaviour on my system!
> Hmm, very interesting. This is an hfs+ file system, correct? Is
> journaling enabled? If not, has it ever been?
Yes and yes. Both since birth I believe.
>> HTH in some way!
> It's definitely useful to know that it's not a universal problem. All
> the osx users in the mutt newsgroup had the same results I did. Can you
> think of anything in any way unusual about your system configuration?
How very odd. I wish I could think of something special about my system, but I
really can't. They are both pretty standard setups.
Gregory Weston
D P Schreber <schre...@rayban.net> wrote:
> > HTH in some way!
>
> It's definitely useful to know that it's not a universal problem. All
> the osx users in the mutt newsgroup had the same results I did. Can you
> think of anything in any way unusual about your system configuration?
FWIW: I'm running a dual g5 with 10.3.7 and I'm seeing a consistent lag
of several seconds. Several being less than 10. Journalling is on.
--
Change account to gw when responding by mail.
D P Schreber
> by saying that I cannot reproduce this behaviour on my system!
>
> $ ls -lu unison.log; cat unison.log > /dev/null; ls -lu unison.log
> -rw------- 1 liteyear liteyear 264308 28 Nov 19:05 unison.log
> -rw------- 1 liteyear liteyear 264308 21 Dec 09:03 unison.log
>
> Mac OS X 10.3.6 on a G4 iMac logged in via SSH using bash.
>
> $ ls -lu cvsqrc.pdf; cat cvsqrc.pdf > /dev/null; ls -lu cvsqrc.pdf
> -rw-r--r-- 1 liteyear liteyear 81544 4 Aug 18:32 cvsqrc.pdf
> -rw-r--r-- 1 liteyear liteyear 81544 21 Dec 09:08 cvsqrc.pdf
I think I'm seeing a pattern. In these two cases, the access time on
the files was some time ago, whereas the files I tested all started out
with an access time at most a few days in the past. So I ran the test
on a file with an access time of 3-Dec and the time updated immediately!
Then I ran it again a minute later on the same file and the test failed
in the way I reported earlier. Of course by the time of the second
test, the access time was only minutes old.
I've since replicated this pattern repeatedly and consistently: older
files show an updated access time immediately, fairly new files don't
(exactly how new they have to be, I don't know yet).
So here's the key question: if you rerun the test on the same two files
above, does it work properly or not?
Heath Raftery
Well done!
$ ls -lu unison.log; cat unison.log > /dev/null; ls -lu unison.log
-rw------- 1 liteyear liteyear 264308 21 Dec 09:08 unison.log
-rw------- 1 liteyear liteyear 264308 21 Dec 09:08 unison.log
$ ls -lu unison.log
-rw------- 1 liteyear liteyear 264308 21 Dec 13:31 unison.log
I executed the second ls -lu less than a minute later (maybe 20-30
seconds I think). I'd be very interested to know the cause of this very
unusual behaviour, as I'm sure you would. I wonder if it is documented
anywhere...
Barry Margolin
D P Schreber <schre...@rayban.net> wrote:
The system may be doing some caching -- when you read the file the
second time, its contents are still in a memory buffer from the first
time. Since it doesn't actually read the file, it may also be skipping
the step of updating the access time.
This is common when accessing files on servers. Perhaps OS X treats
HFS+ volumes internally as virtual servers, and ends up with similar
behavior.
I think POSIX allows some latitude in when access times are updated, to
allow for this type of behavior.
--
Barry Margolin, bar...@alum.mit.edu
Arlington, MA
*** PLEASE post questions in newsgroups, not directly to me ***
D P Schreber
>> I've since replicated this pattern repeatedly and consistently: older
>> files show an updated access time immediately, fairly new files don't
>> (exactly how new they have to be, I don't know yet).
>
I'm relieved it's replicable.
> $ ls -lu unison.log; cat unison.log > /dev/null; ls -lu unison.log
> -rw------- 1 liteyear liteyear 264308 21 Dec 09:08 unison.log
> -rw------- 1 liteyear liteyear 264308 21 Dec 09:08 unison.log
> $ ls -lu unison.log
> -rw------- 1 liteyear liteyear 264308 21 Dec 13:31 unison.log
>
> I executed the second ls -lu less than a minute later (maybe 20-30
> seconds I think).
My guess is that if you did this (boring) test 50 times, the delay
before the change in the access-time attribute would vary from a few
seconds to 4+ minutes. If you don't have anything better to do.. :)
> I'd be very interested to know the cause of this very unusual
> behaviour, as I'm sure you would. I wonder if it is documented
> anywhere...
It doesn't seem to be very widely known, and it sure feels like a bug to
me: I can't think of any sense in which this would be considered
correct behavior. I also can't think of any reason why the relative age
of the file should matter one way or the other. Some efficiency hack
maybe that tries to batch updates when the time delta is short?
D P Schreber
> The system may be doing some caching -- when you read the file the
> second time, its contents are still in a memory buffer from the first
> time. Since it doesn't actually read the file, it may also be skipping
> the step of updating the access time.
The access time does update eventually, just not right away. And when
it finally does update, it gets the current time, not the actual access
time. So for a little while the access-time is too old, and then it
becomes too new.
But in general, it seems plausble that some kind of caching of this sort
is at the root of the odd behavior. One counter-argument is that I've
seen this on files whose last access-time was several days in the past,
which seems like a long time for a cache to stay around. I _think_ I've
also seen it on files whose previous access occurred in an earlier boot.
That would be a stronger counter but I need to verify that I can
replicate that scenario.
Are there any relevant mount parameters for hfs+ that might come into
play here?
Gregory Weston
D P Schreber <schre...@rayban.net> wrote:
> But in general, it seems plausble that some kind of caching of this sort
> is at the root of the odd behavior. One counter-argument is that I've
> seen this on files whose last access-time was several days in the past,
> which seems like a long time for a cache to stay around. I _think_ I've
> also seen it on files whose previous access occurred in an earlier boot.
> That would be a stronger counter but I need to verify that I can
> replicate that scenario.
Here's an amusing notion: Storing that information will take some time.
Not a lot, but some. Perhaps it's an optimization to only do the update
after some threshold amount of idle time that varies directly with the
amount of activity the file is seeing.