Branch b1_6

b=15501
i=eric.mei
i=rread

Nathan's early margin debug patch.

diff --git a/lustre/include/lustre_net.h b/lustre/include/lustre_net.h
index 1bd2eab..ce3a7a7 100644 (file)
--- a/lustre/include/lustre_net.h
+++ b/lustre/include/lustre_net.h
@@ -530,6 +530,7 @@ struct ptlrpc_service {
         int              srv_watchdog_factor;   /* soft watchdog timeout mutiplier */
         unsigned         srv_cpu_affinity:1;    /* bind threads to CPUs */
         unsigned         srv_at_check:1;        /* check early replies */
+        cfs_time_t       srv_at_checktime;      /* debug */
 
         __u32            srv_req_portal;
         __u32            srv_rep_portal;

diff --git a/lustre/ptlrpc/service.c b/lustre/ptlrpc/service.c
index 9d8c811..2915102 100644 (file)
--- a/lustre/ptlrpc/service.c
+++ b/lustre/ptlrpc/service.c
@@ -283,6 +283,7 @@ static void ptlrpc_at_timer(unsigned long castmeharder)
                svc->srv_name, cfs_time_current_sec(), 
                list_empty(&svc->srv_at_list) ? ", empty" : ""); 
         svc->srv_at_check = 1;
+        svc->srv_at_checktime = cfs_time_current();
         cfs_waitq_signal(&svc->srv_waitq);
 }
 
@@ -583,7 +584,7 @@ static int ptlrpc_check_req(struct ptlrpc_request *req)
 static void ptlrpc_at_set_timer(struct ptlrpc_service *svc)
 {
         struct ptlrpc_request *rq;
-        time_t next;
+        __s32 next;
 
         spin_lock(&svc->srv_at_lock);
         if (list_empty(&svc->srv_at_list)) {
@@ -595,7 +596,8 @@ static void ptlrpc_at_set_timer(struct ptlrpc_service *svc)
         /* Set timer for closest deadline */
         rq = list_entry(svc->srv_at_list.next, struct ptlrpc_request, 
                         rq_timed_list);
-        next = rq->rq_deadline - cfs_time_current_sec() - at_early_margin;
+        next = (__s32)(rq->rq_deadline - cfs_time_current_sec() -
+                       at_early_margin);
         if (next <= 0) 
                 ptlrpc_at_timer((unsigned long)svc);
         else
@@ -774,6 +776,7 @@ static int ptlrpc_at_check_timed(struct ptlrpc_service *svc)
         struct ptlrpc_request *rq, *n;
         struct list_head work_list;
         time_t now = cfs_time_current_sec();
+        cfs_duration_t delay;
         int first, counter = 0;
         ENTRY;
 
@@ -782,6 +785,7 @@ static int ptlrpc_at_check_timed(struct ptlrpc_service *svc)
                 spin_unlock(&svc->srv_at_lock);
                 RETURN(0);
         }
+        delay = cfs_time_sub(cfs_time_current(), svc->srv_at_checktime);
         svc->srv_at_check = 0;
         
         if (list_empty(&svc->srv_at_list)) {
@@ -819,11 +823,17 @@ static int ptlrpc_at_check_timed(struct ptlrpc_service *svc)
 
         CDEBUG(D_ADAPTTO, "timeout in %+ds, asking for %d secs on %d early "
                "replies\n", first, at_extra, counter);
-        if (first < 0)
+        
+        if (first < 0) {
                 /* We're already past request deadlines before we even get a 
                    chance to send early replies */
                 LCONSOLE_WARN("%s: This server is not able to keep up with "
-                              "request traffic (cpu-bound).\n", svc->srv_name);
+                              "request traffic (cpu-bound).\n",  svc->srv_name);
+                CWARN("earlyQ=%d reqQ=%d recA=%d, svcEst=%d, "
+                      "delay="CFS_DURATION_T"(jiff)\n",
+                      counter, svc->srv_n_queued_reqs, svc->srv_n_active_reqs,
+                      at_get(&svc->srv_at_estimate), delay);
+        }
 
         /* ptlrpc_server_free_request may delete an entry out of the work
            list */