[Gluster-users] fstat() sometimes sets ctime nanoseconds, sometimes not

[Alexander Kruppa]

Hello,

I noticed strange behaviour with running tar on files stored on glusterfs. I did not set up the glusterfs, so I can't answer questions about details of its configuration, but I can easily contact the guy who can. The parameters printed by "mount" are:

catrel-s1-ib:/catrel on /glusterfs type fuse.glusterfs (rw,relatime,user_id=0,group_id=0,default_permissions,allow_other,max_read=131072)

As an example to demonstrate the problem, let's create a tar archive to contain the directory /glusterfs/test/, which contains a single file "foo":

$ ls -l /glusterfs/test/
total 216
-rw-r--r-- 1 akruppa users 218658 Jan 13 13:29 foo


Running tar results in the error message "file changed as we read it":

$ tar cvf test.tar /glusterfs/test/
tar: Removing leading `/' from member names
/glusterfs/test/
/glusterfs/test/foo
tar: /glusterfs/test/foo: file changed as we read it


Running tar 10 times on the directory, looking for the "file changed as we read it" error message, and waiting 1 second between each run:

$ for I in `seq 10` ; do echo -n "$I: "; tar cvf test.tar /glusterfs/test/ 2>&1 | grep "file changed as we read it" || echo; sleep 1; done
1: tar: /glusterfs/kruppaal/test/foo: file changed as we read it
2: tar: /glusterfs/kruppaal/test/foo: file changed as we read it
3: tar: /glusterfs/kruppaal/test/foo: file changed as we read it
4: tar: /glusterfs/kruppaal/test/foo: file changed as we read it
5: tar: /glusterfs/kruppaal/test/foo: file changed as we read it
6: tar: /glusterfs/kruppaal/test/foo: file changed as we read it
7: tar: /glusterfs/kruppaal/test/foo: file changed as we read it
8: tar: /glusterfs/kruppaal/test/foo: file changed as we read it
9: tar: /glusterfs/kruppaal/test/foo: file changed as we read it
10: tar: /glusterfs/kruppaal/test/foo: file changed as we read it


The same thing, but without waiting 1 second:

$ for I in `seq 10` ; do echo -n "$I: "; tar cvf test.tar /glusterfs/test/ 2>&1 | grep "file changed as we read it" || echo; done
1: tar: /glusterfs/kruppaal/test/foo: file changed as we read it
2:
3:
4:
5:
6:
7:
8:
9:
10:

So without the sleep 1, the tar runs except the first one seem to work. When specifying the file directly to tar, rather than the directory:

$ for I in `seq 10` ; do echo -n "$I: "; tar cvf test.tar /glusterfs/test/foo 2>&1 | grep "file changed as we read it" || echo; sleep 1; done
1:
2:
3:
4:
5:
6:
7:
8:
9:
10:

Now always seems to work. With a sleep time of 0.5 seconds instead of 1 second:

$ for I in `seq 100` ; do echo -n "$I: "; tar cvf test.tar /glusterfs/test/ 2>&1 | grep "file changed as we read it" || echo; sleep 0.5; done
1: tar: /glusterfs/test/foo: file changed as we read it
2:
3: tar: /glusterfs/test/foo: file changed as we read it
4:
5: tar: /glusterfs/test/foo: file changed as we read it
6:
7: tar: /glusterfs/test/foo: file changed as we read it
8: ...

It goes on like this, every other run fails. With a sleep time of 0.1, about every 10-th run fails.

I modified tar to print the ctime it got from fstat() when the "file changed as we read it" occurs. The patch is below. With the modified tar, we find:

$ ~/build/tar-1.26.my/src/tar cvf test.tar /glusterfs/test/
/home/akruppa/build/tar-1.26.my/src/tar: Removing leading `/' from member names
/glusterfs/test/
/glusterfs/test/foo
/home/akruppa/build/tar-1.26.my/src/tar: /glusterfs/test/foo: file changed as we read it
original_ctime = (1389616142, 406799549), new_ctime = (1389616142, 0)


It seems that fstat() sometimes fills in the nanosecond part of ctime, and sometimes not. The fact that the problem seems to depend on recent file accesses may hint at a metadata caching problem?

Best regards,
Alex Kruppa


Patch against the GNU tar 1.26 sources (http://ftp.gnu.org/gnu/tar/):

$ diff tar-1.26/src/create.c tar-1.26.my/src/create.c 
1788c1788,1789
< 	  if ((timespec_cmp (get_stat_ctime (&final_stat), original_ctime) != 0
---
>           struct timespec new_ctime = get_stat_ctime (&final_stat);
> 	  if ((timespec_cmp (new_ctime, original_ctime) != 0
1796a1798,1800
>               fprintf (stderr, "original_ctime = (%ld, %ld), new_ctime = (%ld, %ld)\n", 
>                        (long) original_ctime.tv_sec, (long) original_ctime.tv_nsec, 
>                        (long) new_ctime.tv_sec, (long) new_ctime.tv_nsec);