[Lustre-cvs] b_devel: lustre/ldlm ldlm_lockd.c

[Mike S. <sh...@us...>]

Update of /cvsroot/lustre/lustre/ldlm
In directory sc8-pr-cvs1:/tmp/cvs-serv32044/ldlm

Modified Files:
      Tag: b_devel
	ldlm_lockd.c 
Log Message:
Whine to console if we take > obd_timeout to service a request, or grant a lock.


Index: ldlm_lockd.c
===================================================================
RCS file: /cvsroot/lustre/lustre/ldlm/ldlm_lockd.c,v
retrieving revision 1.131.2.46
retrieving revision 1.131.2.47
diff -u -w -b -B -p -r1.131.2.46 -r1.131.2.47
--- ldlm_lockd.c	5 Jul 2003 22:46:20 -0000	1.131.2.46
+++ ldlm_lockd.c	13 Jul 2003 09:33:10 -0000	1.131.2.47
@@ -347,10 +347,19 @@ int ldlm_server_blocking_ast(struct ldlm
         RETURN(rc);
 }
 
+/* XXX copied from ptlrpc/service.c */
+static long timeval_sub(struct timeval *large, struct timeval *small)
+{
+        return (large->tv_sec - small->tv_sec) * 1000000 +
+                (large->tv_usec - small->tv_usec);
+}
+
 int ldlm_server_completion_ast(struct ldlm_lock *lock, int flags, void *data)
 {
         struct ldlm_request *body;
         struct ptlrpc_request *req;
+        struct timeval granted_time;
+        long total_enqueue_wait;
         int rc = 0, size = sizeof(*body);
         ENTRY;
 
@@ -359,6 +368,12 @@ int ldlm_server_completion_ast(struct ld
                 RETURN(-EINVAL);
         }
 
+        do_gettimeofday(&granted_time);
+        total_enqueue_wait = timeval_sub(&granted_time, &lock->l_enqueued_time);
+
+        if (total_enqueue_wait / 1000000 > obd_timeout)
+                LDLM_ERROR(lock, "enqueue wait took %ldus", total_enqueue_wait);
+
         req = ptlrpc_prep_req(lock->l_export->exp_ldlm_data.led_import,
                               LDLM_CP_CALLBACK, 1, &size, NULL);
         if (!req)
@@ -370,7 +385,8 @@ int ldlm_server_completion_ast(struct ld
         body->lock_flags = flags;
         ldlm_lock2desc(lock, &body->lock_desc);
 
-        LDLM_DEBUG(lock, "server preparing completion AST");
+        LDLM_DEBUG(lock, "server preparing completion AST (after %ldus wait)",
+                   total_enqueue_wait);
         req->rq_replen = lustre_msg_size(0, NULL);
 
         req->rq_level = LUSTRE_CONN_RECOVER;
@@ -447,6 +463,7 @@ int ldlm_handle_enqueue(struct ptlrpc_re
         if (!lock)
                 GOTO(out, err = -ENOMEM);
 
+        do_gettimeofday(&lock->l_enqueued_time);
         memcpy(&lock->l_remote_handle, &dlm_req->lock_handle1,
                sizeof(lock->l_remote_handle));
         LDLM_DEBUG(lock, "server-side enqueue handler, new lock created");