nfs : logging improvements

NFS log-warning messages logged twice in cbk function. Though,
the logging messages are not exactly duplicate, instead of
logging twice, they can be merged to one log message and the
other log message is removed in cbk functions.

Example:
(1)
W [nfs3.c:2075:nfs3svc_write_cbk] 0-nfs: 16f4dce6:
        /f.195 => -1 (Disk quota exceeded)
(2)
W [nfs3-helpers.c:3443:nfs3_log_write_res] 0-nfs-nfsv3:
        XID: 16f4dce6, WRITE: NFS: 69(Resource (quota)
        hard limit exceeded), POSIX: 122
        (Disk quota exceeded), count: 0, UNSTABLE,
        wverf: 1381508849

Here, the second message is more elaborative, and is similar
to (1). Since file name is not present in (2), it is added to (2)
and then removing all mesages of type (1).

        Backport of http://review.gluster.org/#/c/11936/

Cherry picked from commit 0166dca4f268f07dcbf9db7ca971ed16e296e8b7
> Change-Id: I6028ab17b23948493a065dfad92fe4984548511f
> BUG: 1254146
> Signed-off-by: Manikandan Selvaganesh <mselvaga@redhat.com>
> Reviewed-on: http://review.gluster.org/11936
> Tested-by: NetBSD Build System <jenkins@build.gluster.org>
> Reviewed-by: jiffin tony Thottan <jthottan@redhat.com>
> Tested-by: Gluster Build System <jenkins@build.gluster.com>
> Reviewed-by: Niels de Vos <ndevos@redhat.com>

Change-Id: I6028ab17b23948493a065dfad92fe4984548511f
BUG: 1262344
Signed-off-by: Manikandan Selvaganesh <mselvaga@redhat.com>
Reviewed-on: http://review.gluster.org/12162
Tested-by: Gluster Build System <jenkins@build.gluster.com>
Reviewed-by: jiffin tony Thottan <jthottan@redhat.com>
Tested-by: NetBSD Build System <jenkins@build.gluster.org>
Reviewed-by: Niels de Vos <ndevos@redhat.com>

1 files changed, 58 insertions, 46 deletions

diff --git a/xlators/nfs/server/src/nfs3-helpers.c b/xlators/nfs/server/src/nfs3-helpers.c
index 5bb34c138cf..ca56404f127 100644
--- a/xlators/nfs/server/src/nfs3-helpers.c
+++ b/xlators/nfs/server/src/nfs3-helpers.c
@@ -3387,7 +3387,8 @@ nfs3_loglevel (int nfs_op, nfsstat3 stat) {
 }
 
 void
-nfs3_log_common_res (uint32_t xid, int op, nfsstat3 stat, int pstat)
+nfs3_log_common_res (uint32_t xid, int op, nfsstat3 stat, int pstat,
+                     const char *path)
 {
         char    errstr[1024];
         int     ll = nfs3_loglevel (op, stat);
@@ -3396,14 +3397,17 @@ nfs3_log_common_res (uint32_t xid, int op, nfsstat3 stat, int pstat)
                 return;
         nfs3_stat_to_errstr (xid, nfs3op_strings[op].str, stat, pstat, errstr, sizeof (errstr));
                 if (ll == GF_LOG_DEBUG)
-                        gf_msg_debug (GF_NFS3, 0, "%s", errstr);
+                        gf_msg_debug (GF_NFS3, 0, "%s => (%s)", path,
+                                      errstr);
                 else
-                        gf_msg (GF_NFS3, ll, errno, NFS_MSG_STAT_ERROR, "%s", errstr);
+                        gf_msg (GF_NFS3, ll, errno, NFS_MSG_STAT_ERROR,
+                                "%s => (%s)", path, errstr);
 
 }
 
 void
-nfs3_log_readlink_res (uint32_t xid, nfsstat3 stat, int pstat, char *linkpath)
+nfs3_log_readlink_res (uint32_t xid, nfsstat3 stat, int pstat, char *linkpath,
+                       const char *path)
 {
         char    errstr[1024];
         int     ll = nfs3_loglevel (NFS3_READLINK, stat);
@@ -3413,15 +3417,18 @@ nfs3_log_readlink_res (uint32_t xid, nfsstat3 stat, int pstat, char *linkpath)
 
         nfs3_stat_to_errstr (xid, "READLINK", stat, pstat, errstr, sizeof (errstr));
         if (ll == GF_LOG_DEBUG)
-                gf_msg_debug (GF_NFS3, 0, "%s, target: %s", errstr, linkpath);
+                gf_msg_debug (GF_NFS3, 0, "%s => (%s), target: %s", path,
+                              errstr, linkpath);
         else
-                gf_msg (GF_NFS3, ll, errno, NFS_MSG_STAT_ERROR, "%s, target: %s",
-                                errstr, linkpath);
+                gf_msg (GF_NFS3, ll, errno, NFS_MSG_STAT_ERROR,
+                        "%s => (%s) target: %s" , path,
+                        errstr, linkpath);
 }
 
 void
 nfs3_log_read_res (uint32_t xid, nfsstat3 stat, int pstat, count3 count,
-                   int is_eof, struct iovec *vec, int32_t veccount)
+                   int is_eof, struct iovec *vec,
+                   int32_t veccount, const char *path)
 {
         char    errstr[1024];
         int     ll = GF_LOG_DEBUG;
@@ -3432,30 +3439,31 @@ nfs3_log_read_res (uint32_t xid, nfsstat3 stat, int pstat, count3 count,
         nfs3_stat_to_errstr (xid, "READ", stat, pstat, errstr, sizeof (errstr));
         if (vec)
                 if (ll == GF_LOG_DEBUG)
-                        gf_msg (GF_NFS3, ll, errno, NFS_MSG_STAT_ERROR,
-                                        "%s, count: %"PRIu32", is_eof:"
-                                        " %d, vector: count: %d, len: %zd", errstr,
-                                        count, is_eof, veccount, vec->iov_len);
-                else
                         gf_msg_debug (GF_NFS3, 0,
-                                        "%s, count: %"PRIu32", is_eof:"
-                                        " %d, vector: count: %d, len: %zd", errstr,
-                                        count, is_eof, veccount, vec->iov_len);
+                                      "%s => (%s), count: %"PRIu32", is_eof:"
+                                      " %d, vector: count: %d, len: %zd", path,
+                                      errstr, count, is_eof, veccount,
+                                      vec->iov_len);
+                else
+                        gf_msg (GF_NFS3, ll, errno, NFS_MSG_STAT_ERROR,
+                                "%s => (%s), count: %"PRIu32", is_eof:"
+                                " %d, vector: count: %d, len: %zd", path,
+                                errstr, count, is_eof, veccount, vec->iov_len);
         else
                 if (ll == GF_LOG_DEBUG)
                         gf_msg_debug (GF_NFS3, 0,
-                                        "%s, count: %"PRIu32", is_eof:"
-                                        " %d", errstr, count, is_eof);
+                                      "%s => (%s), count: %"PRIu32", is_eof:"
+                                      " %d", path, errstr, count, is_eof);
                 else
                         gf_msg (GF_NFS3, ll, errno, NFS_MSG_STAT_ERROR,
-                                        "%s, count: %"PRIu32", is_eof:"
-                                        " %d", errstr, count, is_eof);
+                                "%s => (%s), count: %"PRIu32", is_eof:"
+                                " %d", path, errstr, count, is_eof);
 
 }
 
 void
 nfs3_log_write_res (uint32_t xid, nfsstat3 stat, int pstat, count3 count,
-                    int stable, uint64_t wverf)
+                    int stable, uint64_t wverf, const char *path)
 {
         char    errstr[1024];
         int     ll = nfs3_loglevel (NFS3_WRITE, stat);
@@ -3466,19 +3474,19 @@ nfs3_log_write_res (uint32_t xid, nfsstat3 stat, int pstat, count3 count,
         nfs3_stat_to_errstr (xid, "WRITE", stat, pstat, errstr, sizeof (errstr));
         if (ll == GF_LOG_DEBUG)
                 gf_msg_debug (GF_NFS3, 0,
-                                "%s, count: %"PRIu32", %s,wverf: %"PRIu64
-                                , errstr, count, (stable == UNSTABLE)?"UNSTABLE":"STABLE",
-                                wverf);
+                              "%s => (%s), count: %"PRIu32", %s,wverf: "
+                              "%"PRIu64, path, errstr, count,
+                              (stable == UNSTABLE)?"UNSTABLE":"STABLE", wverf);
         else
                 gf_msg (GF_NFS3, ll, errno, NFS_MSG_STAT_ERROR,
-                                "%s, count: %"PRIu32", %s,wverf: %"PRIu64
-                                , errstr, count, (stable == UNSTABLE)?"UNSTABLE":"STABLE",
-                                wverf);
+                        "%s => (%s), count: %"PRIu32", %s,wverf: %"PRIu64
+                        , path, errstr, count,
+                        (stable == UNSTABLE)?"UNSTABLE":"STABLE", wverf);
 }
 
 void
 nfs3_log_newfh_res (uint32_t xid, int op, nfsstat3 stat, int pstat,
-                    struct nfs3_fh *newfh)
+                    struct nfs3_fh *newfh, const char *path)
 {
         char    errstr[1024];
         char    fhstr[1024];
@@ -3490,15 +3498,16 @@ nfs3_log_newfh_res (uint32_t xid, int op, nfsstat3 stat, int pstat,
         nfs3_fh_to_str (newfh, fhstr, sizeof (fhstr));
 
         if (ll == GF_LOG_DEBUG)
-                gf_msg_debug (GF_NFS3, 0, "%s, %s", errstr, fhstr);
+                gf_msg_debug (GF_NFS3, 0, "%s => (%s), %s", path, errstr,
+                              fhstr);
         else
                 gf_msg (GF_NFS3, nfs3_loglevel (op, stat), errno, NFS_MSG_STAT_ERROR,
-                                "%s, %s", errstr, fhstr);
+                        "%s => (%s), %s", path, errstr, fhstr);
 }
 
 void
 nfs3_log_readdir_res (uint32_t xid, nfsstat3 stat, int pstat, uint64_t cverf,
-                      count3 count, int is_eof)
+                      count3 count, int is_eof, const char *path)
 {
         char    errstr[1024];
         int     ll = nfs3_loglevel (NFS3_READDIR, stat);
@@ -3508,17 +3517,19 @@ nfs3_log_readdir_res (uint32_t xid, nfsstat3 stat, int pstat, uint64_t cverf,
         nfs3_stat_to_errstr (xid, "READDIR", stat, pstat, errstr, sizeof (errstr));
         if (ll == GF_LOG_DEBUG)
                 gf_msg_debug (GF_NFS3, 0,
-                                "%s, count: %"PRIu32", cverf: %"PRIu64
-                                ", is_eof: %d", errstr, count, cverf, is_eof);
+                              "%s => (%s), count: %"PRIu32", cverf: %"PRIu64
+                              ", is_eof: %d", path, errstr, count, cverf,
+                              is_eof);
         else
                 gf_msg (GF_NFS3, ll, errno, NFS_MSG_STAT_ERROR,
-                                "%s, count: %"PRIu32", cverf: %"PRIu64
-                                ", is_eof: %d", errstr, count, cverf, is_eof);
+                        "%s => (%s), count: %"PRIu32", cverf: %"PRIu64
+                        ", is_eof: %d", path, errstr, count, cverf, is_eof);
 }
 
 void
 nfs3_log_readdirp_res (uint32_t xid, nfsstat3 stat, int pstat, uint64_t cverf,
-                       count3 dircount, count3 maxcount, int is_eof)
+                       count3 dircount, count3 maxcount, int is_eof,
+                       const char *path)
 {
         char    errstr[1024];
         int	ll = nfs3_loglevel (NFS3_READDIRP, stat);
@@ -3528,19 +3539,20 @@ nfs3_log_readdirp_res (uint32_t xid, nfsstat3 stat, int pstat, uint64_t cverf,
         nfs3_stat_to_errstr (xid, "READDIRPLUS", stat, pstat, errstr, sizeof (errstr));
         if (ll == GF_LOG_DEBUG)
                 gf_msg_debug (GF_NFS3, 0,
-                                "%s, dircount: %"PRIu32", maxcount: %"
-                                PRIu32", cverf: %"PRIu64", is_eof: %d", errstr, dircount,
-                                maxcount, cverf, is_eof);
+                              "%s => (%s), dircount: %"PRIu32", maxcount: %"
+                              PRIu32", cverf: %"PRIu64", is_eof: %d", path,
+                              errstr, dircount, maxcount, cverf, is_eof);
         else
                 gf_msg (GF_NFS3, ll, errno, NFS_MSG_STAT_ERROR,
-                                "%s, dircount: %"PRIu32", maxcount: %"
-                                PRIu32", cverf: %"PRIu64", is_eof: %d", errstr, dircount,
-                                maxcount, cverf, is_eof);
+                        "%s => (%s), dircount: %"PRIu32", maxcount: %"
+                        PRIu32", cverf: %"PRIu64", is_eof: %d", path, errstr,
+                        dircount, maxcount, cverf, is_eof);
 
 }
 
 void
-nfs3_log_commit_res (uint32_t xid, nfsstat3 stat, int pstat, uint64_t wverf)
+nfs3_log_commit_res (uint32_t xid, nfsstat3 stat, int pstat, uint64_t wverf,
+                     const char *path)
 {
         char    errstr[1024];
         int	ll = nfs3_loglevel (NFS3_COMMIT, stat);
@@ -3549,11 +3561,11 @@ nfs3_log_commit_res (uint32_t xid, nfsstat3 stat, int pstat, uint64_t wverf)
                 return;
         nfs3_stat_to_errstr (xid, "COMMIT", stat, pstat, errstr, sizeof (errstr));
         if (ll == GF_LOG_DEBUG)
-                gf_msg_debug (GF_NFS3, 0, "%s, wverf: %"PRIu64,
-                                errstr, wverf);
+                gf_msg_debug (GF_NFS3, 0, "%s => (%s), wverf: %"PRIu64,
+                              path, errstr, wverf);
         else
                 gf_msg (GF_NFS3, ll, errno, NFS_MSG_STAT_ERROR,
-                                "%s, wverf: %"PRIu64, errstr, wverf);
+                        "%s => (%s), wverf: %"PRIu64, path, errstr, wverf);
 
 }