Add trace log in new low/high logic to help dignose issues.

Signed-off-by: Shaohua Li <s...@fb.com>
---
 block/blk-throttle.c | 43 +++++++++++++++++++++++++++++++++++++++++--
 1 file changed, 41 insertions(+), 2 deletions(-)

diff --git a/block/blk-throttle.c b/block/blk-throttle.c
index a5f3435..d35bbf1 100644
--- a/block/blk-throttle.c
+++ b/block/blk-throttle.c
@@ -2,6 +2,7 @@
  * Interface for controlling IO bandwidth on a request queue
  *
  * Copyright (C) 2010 Vivek Goyal <vgo...@redhat.com>
+ * Shaohua Li <s...@fb.com> adds low/high limit
  */
 
 #include <linux/module.h>
@@ -92,6 +93,12 @@ enum {
        LIMIT_CNT = 3,
 };
 
+static char *limit_name[LIMIT_CNT] = {
+       [LIMIT_LOW] = "low",
+       [LIMIT_HIGH] = "high",
+       [LIMIT_MAX] = "max",
+};
+
 struct throtl_grp {
        /* must be the first member */
        struct blkg_policy_data pd;
@@ -1565,6 +1572,8 @@ static ssize_t tg_set_limit(struct kernfs_open_file *of,
        if (index == LIMIT_MAX && tg->td->limit_index == LIMIT_MAX &&
            tg->td->limit_valid[LIMIT_HIGH])
                tg->td->limit_index = LIMIT_HIGH;
+       throtl_log(&tg->td->service_queue, "switch state to %s",
+               limit_name[tg->td->limit_index]);
        tg_conf_updated(tg);
        ret = 0;
 out_finish:
@@ -1710,6 +1719,9 @@ static void throtl_calculate_low_interval(struct 
throtl_data *td)
                td->low_upgrade_interval = cg_check_time;
                td->low_downgrade_interval = dbits / ubits * cg_check_time;
        }
+       throtl_log(&td->service_queue,
+               "low upgrade interval=%u, downgrade interval=%u",
+               td->low_upgrade_interval, td->low_downgrade_interval);
 }
 
 static void throtl_calculate_high_interval(struct throtl_data *td)
@@ -1729,6 +1741,9 @@ static void throtl_calculate_high_interval(struct 
throtl_data *td)
                td->high_upgrade_interval = cg_check_time;
                td->high_downgrade_interval = dbits / ubits * cg_check_time;
        }
+       throtl_log(&td->service_queue,
+               "high upgrade interval=%u, downgrade interval=%u",
+               td->high_upgrade_interval, td->high_downgrade_interval);
 }
 
 static bool throtl_upgrade_check_one(struct throtl_grp *tg, bool *idle)
@@ -1745,6 +1760,8 @@ static bool throtl_upgrade_check_one(struct throtl_grp 
*tg, bool *idle)
        /* if cgroup is below low limit for a long time, consider it idle */
        if (time_after(jiffies,
            tg_last_low_overflow_time(tg) + tg->td->low_upgrade_interval)) {
+               throtl_log(&tg->service_queue, "idle upgrade, hit low time=%lu 
jiffies=%lu",
+                       tg_last_low_overflow_time(tg), jiffies);
                *idle = true;
                return true;
        }
@@ -1757,18 +1774,23 @@ static bool throtl_upgrade_check_one(struct throtl_grp 
*tg, bool *idle)
                return false;
        if (tg->iops[WRITE][LIMIT_LOW] != 0 && !sq->nr_queued[WRITE])
                return false;
+       throtl_log(&tg->service_queue, "reach low limit upgrade");
        return true;
 check_high:
        /* if cgroup is below high limit for a long time, consider it idle */
        if (time_after(jiffies,
            tg_last_high_overflow_time(tg) + tg->td->high_upgrade_interval)) {
+               throtl_log(&tg->service_queue, "idle upgrade, hit high time=%lu 
jiffies=%lu",
+                       tg_last_high_overflow_time(tg), jiffies);
                *idle = true;
                return true;
        }
 
        /* if cgroup reaches high/max limit, it's ok to next limit */
-       if (sq->nr_queued[READ] || sq->nr_queued[WRITE])
+       if (sq->nr_queued[READ] || sq->nr_queued[WRITE]) {
+               throtl_log(&tg->service_queue, "reach high/max limit upgrade");
                return true;
+       }
        return false;
 }
 
@@ -1838,6 +1860,8 @@ static void throtl_upgrade_state(struct throtl_data *td)
        td->limit_index++;
        while (!td->limit_valid[td->limit_index])
                td->limit_index++;
+       throtl_log(&td->service_queue, "upgrade state to %s",
+               limit_name[td->limit_index]);
        td->low_upgrade_time = jiffies;
        if (td->limit_index == LIMIT_HIGH)
                td->high_downgrade_time = jiffies;
@@ -1886,6 +1910,8 @@ static void throtl_downgrade_state(struct throtl_data 
*td, int new)
        int old = td->limit_index;
 
        td->limit_index = new;
+       throtl_log(&td->service_queue, "downgrade state to %s",
+               limit_name[td->limit_index]);
        /* max crosses high to low */
        if (new == LIMIT_LOW && old == LIMIT_MAX && 
td->limit_valid[LIMIT_HIGH]) {
                td->low_downgrade_time = jiffies;
@@ -1926,8 +1952,17 @@ static bool throtl_downgrade_check_one(struct throtl_grp 
*tg, bool check_low)
             time_after(now,
              td->high_upgrade_time + td->high_downgrade_interval) &&
             time_after(now,
-             tg_last_high_overflow_time(tg) + td->high_downgrade_interval)))
+             tg_last_high_overflow_time(tg) + td->high_downgrade_interval))) {
+               throtl_log(&tg->service_queue,
+                       "%s idle downgrade, last hit limit time=%lu upgrade 
time=%lu jiffies=%lu",
+                       check_low ? "low" : "high",
+                       check_low ? tg_last_low_overflow_time(tg) :
+                               tg_last_high_overflow_time(tg),
+                       check_low ? td->low_upgrade_time :
+                               td->high_upgrade_time,
+                       jiffies);
                return true;
+       }
        return false;
 }
 
@@ -1986,6 +2021,7 @@ static void throtl_downgrade_check(struct throtl_grp *tg)
 
        bps = tg->last_bytes_disp[READ] * HZ;
        do_div(bps, elapsed_time);
+       throtl_log(&tg->service_queue, "rbps=%llu", bps);
        if (tg->bps[READ][LIMIT_LOW] != 0 &&
            bps >= tg->bps[READ][LIMIT_LOW])
                tg->last_low_overflow_time[READ] = now;
@@ -1996,6 +2032,7 @@ static void throtl_downgrade_check(struct throtl_grp *tg)
 
        bps = tg->last_bytes_disp[WRITE] * HZ;
        do_div(bps, elapsed_time);
+       throtl_log(&tg->service_queue, "wbps=%llu", bps);
        if (tg->bps[WRITE][LIMIT_LOW] != 0 &&
            bps >= tg->bps[WRITE][LIMIT_LOW])
                tg->last_low_overflow_time[WRITE] = now;
@@ -2005,6 +2042,7 @@ static void throtl_downgrade_check(struct throtl_grp *tg)
                tg->last_high_overflow_time[WRITE] = now;
 
        iops = tg->last_io_disp[READ] * HZ / elapsed_time;
+       throtl_log(&tg->service_queue, "riops=%u", iops);
        if (tg->iops[READ][LIMIT_LOW] != 0 &&
            iops >= tg->iops[READ][LIMIT_LOW])
                tg->last_low_overflow_time[READ] = now;
@@ -2014,6 +2052,7 @@ static void throtl_downgrade_check(struct throtl_grp *tg)
                tg->last_high_overflow_time[READ] = now;
 
        iops = tg->last_io_disp[WRITE] * HZ / elapsed_time;
+       throtl_log(&tg->service_queue, "wiops=%u", iops);
        if (tg->iops[WRITE][LIMIT_LOW] != 0 &&
            iops >= tg->iops[WRITE][LIMIT_LOW])
                tg->last_low_overflow_time[WRITE] = now;
-- 
2.8.0.rc2

Reply via email to