feature/quota: Logging corrections

This patch solves the inconsistent quota usage logging when soft limit reached.

Change-Id: I47e7f1e65ed4b8306a999a20cc8f6b1772d47627
BUG: 1087198
Signed-off-by: Varun Shastry <vshastry@redhat.com>
Reviewed-on: http://review.gluster.org/7451
Tested-by: Gluster Build System <jenkins@build.gluster.com>
Reviewed-by: Vijay Bellur <vbellur@redhat.com>

2 files changed, 110 insertions, 21 deletions

diff --git a/tests/bugs/bug-1087198.t b/tests/bugs/bug-1087198.t
new file mode 100644
index 00000000000..b16a413f1d8
--- /dev/null
+++ b/tests/bugs/bug-1087198.t
@@ -0,0 +1,74 @@
+#!/bin/bash
+
+## The script tests the logging of the quota in the bricks after reaching soft
+## limit of the configured limit.
+##
+##  Steps:
+##  1. Create and mount the volume
+##  2. Enable quota and set the limit on 2 directories
+##  3. Write some data to cross the limit
+##  4. Grep the string expected in brick logs
+##  5. Wait for 10 seconds (alert timeout is set to 10s)
+##  6. Repeat 3 and 4.
+##  7. Cleanup
+
+. $(dirname $0)/../include.rc
+. $(dirname $0)/../fileio.rc
+
+cleanup;
+
+#1
+## Step 1
+TEST glusterd
+TEST pidof glusterd
+TEST $CLI volume info;
+
+TEST $CLI volume create $V0 $H0:$B0/brick{1..4};
+EXPECT 'Created' volinfo_field $V0 'Status';
+
+TEST $CLI volume start $V0;
+EXPECT 'Started' volinfo_field $V0 'Status';
+
+TEST mount -t nfs -o noac,soft,nolock,vers=3 $H0:/$V0 $N0
+
+
+QUOTA_LIMIT_DIR="quota_limit_dir"
+BRICK_LOG_DIR="`gluster --print-logdir`/bricks"
+
+#9
+TEST mkdir $N0/$QUOTA_LIMIT_DIR
+
+#10
+## Step 2
+TEST $CLI volume quota $V0 enable
+TEST $CLI volume quota $V0 alert-time 10
+TEST $CLI volume quota $V0 hard-timeout 0
+TEST $CLI volume quota $V0 soft-timeout 0
+TEST $CLI volume quota $V0 limit-usage / 200KB
+TEST $CLI volume quota $V0 limit-usage /$QUOTA_LIMIT_DIR 100KB
+
+#16
+## Step 3 and 4
+TEST dd if=/dev/urandom of=$N0/$QUOTA_LIMIT_DIR/95KB_file bs=1K count=95
+TEST grep -e "\"Usage crossed soft limit:.*used by /$QUOTA_LIMIT_DIR\"" -- $BRICK_LOG_DIR/*
+
+TEST dd if=/dev/urandom of=$N0/100KB_file bs=1K count=100
+TEST grep -e "\"Usage crossed soft limit:.*used by /\"" -- $BRICK_LOG_DIR/*
+
+#20
+## Step 5
+TEST sleep 10
+
+## Step 6
+TEST dd if=/dev/urandom of=$N0/$QUOTA_LIMIT_DIR/1KB_file bs=1K count=1
+TEST grep -e "\"Usage is above soft limit:.*used by /$QUOTA_LIMIT_DIR\"" -- $BRICK_LOG_DIR/*
+
+#23
+TEST dd if=/dev/urandom of=$N0/1KB_file bs=1K count=1
+TEST grep -e "\"Usage is above soft limit:.*used by /\"" -- $BRICK_LOG_DIR/*
+
+#25
+## Step 7
+TEST umount -f $N0
+
+cleanup;
diff --git a/xlators/features/quota/src/quota.c b/xlators/features/quota/src/quota.c
index 2ca4da0c15f..d93911dee08 100644
--- a/xlators/features/quota/src/quota.c
+++ b/xlators/features/quota/src/quota.c
@@ -4017,6 +4017,29 @@ off:
         return 0;
 }
 
+void
+quota_log_helper (char **usage_str, int64_t cur_size, inode_t *inode,
+                  char **path, struct timeval *cur_time)
+{
+        xlator_t        *this   = THIS;
+
+        if (!usage_str || !inode || !path || !cur_time) {
+                gf_log (this->name, GF_LOG_ERROR, "Received null argument");
+                return;
+        }
+
+        *usage_str = gf_uint64_2human_readable (cur_size);
+        if (!(*usage_str))
+                gf_log (this->name, GF_LOG_ERROR, "integer to string "
+                        "conversion failed Reason:\"Cannot allocate memory\"");
+
+        inode_path (inode, NULL, path);
+        if (!(*path))
+                *path = uuid_utoa (inode->gfid);
+
+        gettimeofday (cur_time, NULL);
+}
+
 /* Logs if
 *  i.   Usage crossed soft limit
 *  ii.  Usage above soft limit and alert-time elapsed
@@ -4027,47 +4050,39 @@ quota_log_usage (xlator_t *this, quota_inode_ctx_t *ctx, inode_t *inode,
 {
         struct timeval           cur_time       = {0,};
         char                    *usage_str      = NULL;
-        char                    size_str[32]    = {0};
         char                    *path           = NULL;
         int64_t                  cur_size       = 0;
         quota_priv_t            *priv           = NULL;
-        gf_boolean_t            dyn_mem         = _gf_true;
 
         priv = this->private;
-        if ((ctx->soft_lim <= 0) || (timerisset (&ctx->prev_log) &&
-                                     !quota_timeout (&ctx->prev_log,
-                                                     priv->log_timeout))) {
-                return;
-        }
-
-
         cur_size = ctx->size + delta;
-        usage_str = gf_uint64_2human_readable (cur_size);
-        if (!usage_str) {
-                snprintf (size_str, sizeof (size_str), "%"PRId64, cur_size);
-                usage_str = (char*) size_str;
-                dyn_mem = _gf_false;
-        }
-        inode_path (inode, NULL, &path);
-        if (!path)
-                path = uuid_utoa (inode->gfid);
 
-        gettimeofday (&cur_time, NULL);
+        if ((ctx->soft_lim <= 0) || cur_size < ctx->soft_lim)
+                return;
+
         /* Usage crossed/reached soft limit */
         if (DID_REACH_LIMIT (ctx->soft_lim, ctx->size, cur_size)) {
 
+                quota_log_helper (&usage_str, cur_size, inode,
+                                  &path, &cur_time);
+
                 gf_log (this->name, GF_LOG_ALERT, "Usage crossed "
                         "soft limit: %s used by %s", usage_str, path);
                 ctx->prev_log = cur_time;
         }
         /* Usage is above soft limit */
-        else if (cur_size > ctx->soft_lim){
+        else if (cur_size > ctx->soft_lim &&
+                           quota_timeout (&ctx->prev_log, priv->log_timeout)) {
+
+                quota_log_helper (&usage_str, cur_size, inode,
+                                  &path, &cur_time);
+
                 gf_log (this->name, GF_LOG_ALERT, "Usage is above "
                         "soft limit: %s used by %s", usage_str, path);
                 ctx->prev_log = cur_time;
         }
 
-        if (dyn_mem)
+        if (usage_str)
                 GF_FREE (usage_str);
 }