Hide Forgot
Created attachment 573675 [details] Brick Log File Description of problem: 1) The following messages are repeatedly logged in brick log file. 2) These messages can also be improvised for making it more meaningful and for better understanding. The Message1 was printed 3022 times. Message1:- --------- [2012-03-28 17:57:12.280526] I [server3_1-fops.c:1522:server_open_cbk] 0-dstore-server: 289: OPEN (null) (--) ==> -1 (No such file or directory) Message2:- --------- [2012-03-28 17:57:12.286314] I [server3_1-fops.c:1319:server_flush_cbk] 0-dstore-server: 290: FLUSH -2 (--) ==> -1 (No such file or directory) Message3:- ---------- [2012-03-28 17:57:12.292465] I [server3_1-fops.c:343:server_entrylk_cbk] 0-dstore-server: 294: ENTRYLK (null) (--) ==> -1 (No such file or directory) Message4:- ----------- [2012-03-28 17:57:30.830970] I [server3_1-fops.c:295:server_finodelk_cbk] 0-dstore-server: 81: FINODELK -2 (--) ==> -1 (No such file or directory) Version-Release number of selected component (if applicable): mainline How reproducible: often script1:- -------- #!/bin/bash mountpoint=`pwd` for i in {1..5} do level1_dir=$mountpoint/fuse1.$i mkdir $level1_dir cd $level1_dir for j in {1..5} do level2_dir=dir.$j mkdir $level2_dir cd $level2_dir for k in {1..5} do dd if=/dev/zero of=file.$k bs="$k"M count=1024 done cd $level1_dir done cd $mountpoint done script2:- ------- #!/bin/bash mountpoint=`pwd` for i in {1..5} do level1_dir=$mountpoint/nfs1.$i mkdir $level1_dir cd $level1_dir for j in {1..5} do level2_dir=dir.$j mkdir $level2_dir cd $level2_dir for k in {1..5} do dd if=/dev/zero of=file.$k bs="$k"M count=1024 done cd $level1_dir done cd $mountpoint done Steps to Reproduce: 1.Create a distribute-replicate volume.start the volume 2.create fuse,nfs mounts. 3.run script1 on fuse mount. run script2 on nfs mount 4.add-brick to the volume while the script1, script2 are still in progress.
Created attachment 573676 [details] Brick Log File1
Noticed that there are many places where we print/log 'path' of the fop when it fails (in client3-1-fops.c), Now, with gfid based changes, we may not have 'path' in a call which causes this behavior. Taking it out of beta milestone as the fix involves some work (as in number of lines to be edited), and not a blocker itself for beta2 release.
Kaushal, Most of the patch is about fixing the log, and some task is understanding if we need all those log. As you are already handling log cleanup in client/server protocol, assigning to you.
The logs look like they have already been changed for gfid. The "(null)" in the log is for path and the following "(--)" is for a missing gfid.
REVIEW: http://review.gluster.org/6241 (server/rpc: Numerous entries of error - "No such file or directory" in bricks log) posted (#1) for review on master by Vikhyat Umrao (vikhyat.umrao)
REVIEW: http://review.gluster.org/6241 (server/rpc: Numerous entries of error - "No such file or directory" in bricks log) posted (#2) for review on master by Vikhyat Umrao (vumrao)
COMMIT: http://review.gluster.org/6241 committed in master by Vijay Bellur (vbellur) ------ commit cfbc7ddbadfc7d01124aa713c4769c45e0522db5 Author: Vikhyat Umrao <vumrao> Date: Mon Nov 11 14:52:54 2013 +0530 server/rpc: Numerous entries of error - "No such file or directory" in bricks log Problem: Messages were getting logged very frequently at log level INFO. One of the log file snippet - [2013-10-27 00:05:01.501355] I [server3_1-fops.c:1707:server_stat_cbk] 0-vol-server: 24846575: STAT (null) (--) ==> -1 (No such file or directory) [2013-10-27 00:05:01.505101] I [server3_1-fops.c:1707:server_stat_cbk] 0-vol-server: 24846577: STAT (null) (--) ==> -1 (No such file or directory) [2013-10-27 00:05:01.507299] I [server3_1-fops.c:1707:server_stat_cbk] 0-vol-server: 24846578: STAT (null) (--) ==> -1 (No such file or directory) [2013-10-20 19:50:35.554563] I [server3_1-fops.c:1538:server_open_cbk] 0-vol-server: 18714687: OPEN <gfid:01c70ca0-1952-4e82-abee-a07205757d8e> (01c70ca0-1952-4e82-abee-a07205757d8e) ==> -1 (No such file or directory) [2013-10-20 19:50:35.555520] I [server3_1-fops.c:1538:server_open_cbk] 0-vol-server: 18714697: OPEN <gfid:01c70ca0-1952-4e82-abee-a07205757d8e> (01c70ca0-1952-4e82-abee-a07205757d8e) ==> -1 (No such file or directory) [2013-10-20 19:50:35.558292] I [server3_1-fops.c:1538:server_open_cbk] 0-vol-server: 18714712: OPEN (null) (--) ==> -1 (No such file or directory) Solution: Moved them to DEBUG log level if error number equlas to ENOENT else to ERROR log level. It will help in decreasing the size of log files at INFO log level. Change-Id: I23d74320c9c21bbce4805c20295556cc2cc0a8d8 BUG: 808073 Signed-off-by: Vikhyat Umrao <vumrao> Reviewed-on: http://review.gluster.org/6241 Reviewed-by: Niels de Vos <ndevos> Tested-by: Gluster Build System <jenkins.com> Reviewed-by: Vijay Bellur <vbellur>
The patch merged with comment #7 reduces the logging when the FOP returns ENOENT. This is a change that prevents users from being confused about the messages, and prevents filling disks with near to useless messages. The ENOENT messages are passed back to the client, which will handle (and log) the error. The actual issue seems to be caused by calling the server_*_cbk() functions, when there is neither a filename or gfid passed. Therefore, keeping this Bug as NEW, waiting for someone to have a closer look at the root cause.
This bug is getting closed because a release has been made available that should address the reported issue. In case the problem is still not fixed with glusterfs-3.5.0, please reopen this bug report. glusterfs-3.5.0 has been announced on the Gluster Developers mailinglist [1], packages for several distributions should become available in the near future. Keep an eye on the Gluster Users mailinglist [2] and the update infrastructure for your distribution. [1] http://thread.gmane.org/gmane.comp.file-systems.gluster.devel/6137 [2] http://thread.gmane.org/gmane.comp.file-systems.gluster.user