[LU-6492] less +F doesn't work

• Type: Bug
• Resolution: Cannot Reproduce
• Priority: Minor
• Affects Version/s: Lustre 2.5.3
• Environment: CentOS 6.4 x86_64

Epic/Theme

lustre-2.5.3

• Severity: 3
• Assignee: WC Triage
• Reporter: Nick Tan (Inactive)

Description

node 1 streams data into an ever-growing file (e.g. a log file).

node 2 can see the file changing with stat:

$ stat logs/*.3
File: `debug.o12716414.3'
Size: 33472307 Blocks: 65360 IO Block: 4194304 regular file
Device: 4a737072h/1249079410d Inode: 144115224750877831 Links: 1
Access: (0664/rw-rw-r-) Uid: ( 1087/ tzuyenw) Gid: ( 2117/teamcott)
Access: 2015-04-24 13:33:09.000000000 +0800
Modify: 2015-04-24 13:33:13.000000000 +0800
Change: 2015-04-24 13:33:13.000000000 +0800

$ stat logs/*.3
File: `debug.o12716414.3'
Size: 33485617 Blocks: 65360 IO Block: 4194304 regular file
Device: 4a737072h/1249079410d Inode: 144115224750877831 Links: 1
Access: (0664/rw-rw-r-) Uid: ( 1087/ tzuyenw) Gid: ( 2117/teamcott)
Access: 2015-04-24 13:33:09.000000000 +0800
Modify: 2015-04-24 13:33:18.000000000 +0800
Change: 2015-04-24 13:33:18.000000000 +0800

On node 2, a tail -f (which calls fstat() to determine if the file has changed) works:

13:34:45.548212 read(3, ""..., 8192) = 5118 <0.005387>
13:34:45.547101 write(1, ""..., 5118) = 5118 <0.001003>
13:34:45.555175 read(3, "", 8192) = 0 <0.000124>
13:34:45.555367 fstat(3,

{st_mode=S_IFREG|0664, st_size=33712023, ...}) = 0 <0.000100>
13:34:45.555566 nanosleep({1, 0}, NULL) = 0 <1.000124>
13:34:46.555811 fstat(3, {st_mode=S_IFREG|0664, st_size=33712023, ...}

) = 0 <0.000185>
13:34:46.556136 nanosleep(

{1, 0}, NULL) = 0 <1.000118>
13:34:47.556374 fstat(3, {st_mode=S_IFREG|0664, st_size=33712023, ...}) = 0 <0.000175>
13:34:47.556684 nanosleep({1, 0}

, NULL) = 0 <1.000134>
13:34:48.556948 fstat(3,

{st_mode=S_IFREG|0664, st_size=33712023, ...}) = 0 <0.000156>
13:34:48.557234 nanosleep({1, 0}, NULL) = 0 <1.000110>
13:34:49.557444 fstat(3, {st_mode=S_IFREG|0664, st_size=33712023, ...}

) = 0 <0.037993>
13:34:49.595556 read(3, ""..., 8192) = 8192 <0.333306>
...
13:34:49.937886 read(3, "", 8192) = 0 <0.000126>
13:34:49.938080 fstat(3,

{st_mode=S_IFREG|0664, st_size=33725333, ...}

) = 0 <0.000105>

Interestingly, even though the file size didn't change (we can see the st_size there), it evidently indicated some kind of change (perhaps mtime?) because tail knew to try the read() again, and the read() succeeded. After the successful read, it did another read/fstat, and at that point the st_size was updated.

However "less" in Follow mode (which doesn't do fstat() before read()) doesn't work:

13:33:11.949002 nanosleep(

{1, 0}, 0x7fff832a7c30) = 0 <1.000156>
13:33:12.949280 read(4, "", 5324) = 0 <0.000028>
13:33:12.949752 nanosleep({1, 0}

, 0x7fff832a7c30) = 0 <1.000155>
13:33:13.950040 read(4, "", 5324) = 0 <0.000031>
13:33:13.950496 nanosleep(

{1, 0}, 0x7fff832a7c30) = 0 <1.000148>
13:33:14.950767 read(4, "", 5324) = 0 <0.000029>
13:33:14.951249 nanosleep({1, 0}

, 0x7fff832a7c30) = 0 <1.000150>
13:33:15.951520 read(4, "", 5324) = 0 <0.000026>
13:33:15.952015 nanosleep(

{1, 0}, 0x7fff832a7c30) = 0 <1.000147>
13:33:16.952287 read(4, "", 5324) = 0 <0.000029>
13:33:16.952738 nanosleep({1, 0}

, 0x7fff832a7c30) = 0 <1.000148>
13:33:17.953009 read(4, "", 5324) = 0 <0.000026>
etc.

Despite the fact that the file is growing (as seen by stat in another terminal), the read() acts like the file descriptor is still at the end of the file. The logfile grows every 10 seconds, but you can leave that less running for hours and hours, it'll never see it.