[Bugs] [Bug 1393743] New: the return size of fstat sometime is not correct while write-behind feature enabled

[bugzilla at redhat.com]

https://bugzilla.redhat.com/show_bug.cgi?id=1393743

            Bug ID: 1393743
           Summary: the return size of fstat sometime is not correct while
                    write-behind feature enabled
           Product: GlusterFS
           Version: 3.6.9
         Component: write-behind
          Severity: urgent
          Assignee: bugs at gluster.org
          Reporter: george.lian at nokia.com
                CC: bugs at gluster.org



Description of problem:

sometimes the size of fstat is incorrect, it could be test by tail application
Version-Release number of selected component (if applicable):


How reproducible:


Steps to Reproduce:
1.make 2 SN with replicated.
2.make a CLI host mounted to the SN, let's say /mnt/log
3. on CLI host start the rsyslog servie and let the output store in /mnt/log,
let's say /mnt/log/syslog
4. tail -f /mnt/log/syslog >/devnull on CLI host
5. on CLI host lanuch 4 process 
  a) logger 51 bytes every 101 ms
  b) logger 101 bytes every 111 ms
  c) logger 301 bytes every 121 ms
  d) logger 501 bytes every 131 ms

Actual results:
"syslog: file truncated" printer on terminal about ten minutes

Expected results:
tail -f should be no error information printed on terminal

Additional info:

has set trace log and add some private log in glusterfs, some userful log ,
also include some of my private comments with begin of [George/C].

[2016-11-10 03:11:31.686813] T [fuse-bridge.c:2304:fuse_write_resume]
0-glusterfs-fuse: 93101: WRITE (0xa4757c, size=50, offset=39739375)

[George/C] the size should be 39739375+50 now

[2016-11-10 03:11:31.679749] T [fuse-bridge.c:832:fuse_getattr_resume]
0-glusterfs-fuse: 93099: FGETATTR 139805905838312 (/messages/0xa47654)
[2016-11-10 03:11:31.687328] W [md-cache.c:937:mdc_fstat_cbk] (-->
/lib64/libglusterfs.so.0(_gf_log_callingfn+0x15c)[0x7f272c86bebc] (-->
/usr/lib64/glusterfs/3.6.9/xlator/performance/md-cache.so(mdc_fstat_cbk+0x7b)[0x7f271a8b28bb]
(--> /lib64/libglusterfs.so.0(default_fstat_cbk+0xac)[0x7f272c872c5c] (-->
/usr/lib64/glusterfs/3.6.9/xlator/performance/read-ahead.so(ra_attr_cbk+0xac)[0x7f271b0e08ac]
(--> /lib64/libglusterfs.so.0(default_fstat_cbk+0xac)[0x7f272c872c5c] )))))
0-mdc-cache: mdc_fstat from storage server stat size[39739375]
[George/C] the size of fstat is still 39739375, 50 bytes not included, why?

[2016-11-10 03:11:31.687694] T [fuse-bridge.c:832:fuse_getattr_resume]
0-glusterfs-fuse: 93102: FGETATTR 139805905838312 (/messages/0xa47654)
[2016-11-10 03:11:31.687893] W [md-cache.c:961:mdc_fstat] (-->
/lib64/libglusterfs.so.0(_gf_log_callingfn+0x15c)[0x7f272c86bebc] (-->
/usr/lib64/glusterfs/3.6.9/xlator/performance/md-cache.so(mdc_fstat+0x1b7)[0x7f271a8b3977]
(-->
/usr/lib64/glusterfs/3.6.9/xlator/debug/io-stats.so(io_stats_fstat+0x149)[0x7f271a6977c9]
(--> /lib64/libglusterfs.so.0(default_fstat+0x5c)[0x7f272c87015c] (-->
/usr/lib64/glusterfs/3.6.9/xlator/meta.so(meta_fstat+0x2e)[0x7f271a4811ce]
))))) 0-mdc-cache: mdc_fstat from cache stat size[39739375]

[2016-11-10 03:11:31.696637] T [fuse-bridge.c:832:fuse_getattr_resume]
0-glusterfs-fuse: 93105: FGETATTR 139805905838312 (/messages/0xa47654)
[2016-11-10 03:11:31.696780] W [md-cache.c:961:mdc_fstat] (-->
/lib64/libglusterfs.so.0(_gf_log_callingfn+0x15c)[0x7f272c86bebc] (-->
/usr/lib64/glusterfs/3.6.9/xlator/performance/md-cache.so(mdc_fstat+0x1b7)[0x7f271a8b3977]
(-->
/usr/lib64/glusterfs/3.6.9/xlator/debug/io-stats.so(io_stats_fstat+0x149)[0x7f271a6977c9]
(--> /lib64/libglusterfs.so.0(default_fstat+0x5c)[0x7f272c87015c] (-->
/usr/lib64/glusterfs/3.6.9/xlator/meta.so(meta_fstat+0x2e)[0x7f271a4811ce]
))))) 0-mdc-cache: mdc_fstat from cache stat size[39739375]

[2016-11-10 03:11:31.696818] T [fuse-bridge.c:755:fuse_attr_cbk]
0-glusterfs-fuse: 93105: FSTAT() /messages => 12997464502055181759

[2016-11-10 03:11:31.697940] T [fuse-bridge.c:2174:fuse_readv_cbk]
0-glusterfs-fuse: 93106: READ => 33/4096,39739392/0

[George/C] the read from 39739392 and read 33bytes, 

[2016-11-10 03:11:31.698039] T [fuse-bridge.c:832:fuse_getattr_resume]
0-glusterfs-fuse: 93107: FGETATTR 139805905838312 (/messages/0xa47654)
[2016-11-10 03:11:31.698170] W [md-cache.c:961:mdc_fstat] (-->
/lib64/libglusterfs.so.0(_gf_log_callingfn+0x15c)[0x7f272c86bebc] (-->
/usr/lib64/glusterfs/3.6.9/xlator/performance/md-cache.so(mdc_fstat+0x1b7)[0x7f271a8b3977]
(-->
/usr/lib64/glusterfs/3.6.9/xlator/debug/io-stats.so(io_stats_fstat+0x149)[0x7f271a6977c9]
(--> /lib64/libglusterfs.so.0(default_fstat+0x5c)[0x7f272c87015c] (-->
/usr/lib64/glusterfs/3.6.9/xlator/meta.so(meta_fstat+0x2e)[0x7f271a4811ce]
))))) 0-mdc-cache: mdc_fstat from cache stat size[39739375]
[George/C] the fstat still return 39739375, still 50 bytes less, Why?

[2016-11-10 03:11:31.698188] T [fuse-bridge.c:755:fuse_attr_cbk]
0-glusterfs-fuse: 93107: FSTAT() /messages => 12997464502055181759

-- 
You are receiving this mail because:
You are on the CC list for the bug.
You are the assignee for the bug.