[Ocfs2-commits] zab commits r2555 - trunk/fs/ocfs2/cluster

[svn-commits at oss.oracle.com]

Author: zab
Signed-off-by: mfasheh
Date: 2005-08-29 19:07:04 -0500 (Mon, 29 Aug 2005)
New Revision: 2555

Modified:
   trunk/fs/ocfs2/cluster/tcp.c
   trunk/fs/ocfs2/cluster/tcp_internal.h
Log:
o include informative timestamps in idle net timeout message

Signed-off-by: mfasheh


Modified: trunk/fs/ocfs2/cluster/tcp.c
===================================================================
--- trunk/fs/ocfs2/cluster/tcp.c	2005-08-27 00:05:12 UTC (rev 2554)
+++ trunk/fs/ocfs2/cluster/tcp.c	2005-08-30 00:07:04 UTC (rev 2555)
@@ -461,6 +461,7 @@
 	if (sk->sk_user_data) {
 		struct o2net_sock_container *sc = sk->sk_user_data;
 		sclog(sc, "data_ready hit\n");
+		do_gettimeofday(&sc->sc_tv_data_ready);
 		o2net_sc_queue_work(sc, &sc->sc_rx_work);
 		ready = sc->sc_data_ready;
 	} else {
@@ -1083,9 +1084,13 @@
 	if (syserr != O2NET_ERR_NONE)
 		goto out_respond;
 
+	do_gettimeofday(&sc->sc_tv_func_start);
+	sc->sc_msg_key = be32_to_cpu(hdr->key);
+	sc->sc_msg_type = be16_to_cpu(hdr->msg_type);
 	handler_status = (nmh->nh_func)(hdr, sizeof(o2net_msg) +
 					     be16_to_cpu(hdr->data_len),
 					nmh->nh_func_data);
+	do_gettimeofday(&sc->sc_tv_func_stop);
 
 out_respond:
 	/* this destroys the hdr, so don't use it after this */
@@ -1148,6 +1153,7 @@
 	size_t datalen;
 
 	sclog(sc, "receiving\n");
+	do_gettimeofday(&sc->sc_tv_advance_start);
 
 	/* do we need more header? */
 	if (sc->sc_page_off < sizeof(o2net_msg)) {
@@ -1214,6 +1220,7 @@
 
 out:
 	sclog(sc, "ret = %d\n", ret);
+	do_gettimeofday(&sc->sc_tv_advance_stop);
 	return ret;
 }
 
@@ -1295,9 +1302,23 @@
 static void o2net_idle_timer(unsigned long data)
 {
 	struct o2net_sock_container *sc = (struct o2net_sock_container *)data;
+	struct timeval now;
 
+	do_gettimeofday(&now);
+
 	mlog(ML_NOTICE, "connection to " SC_NODEF_FMT " has been idle for 10 "
 	     "seconds, shutting it down.\n", SC_NODEF_ARGS(sc));
+	mlog(ML_NOTICE, "here are some times that might help debug the "
+	     "situation: (tmr %ld.%ld now %ld.%ld dr %ld.%ld adv "
+	     "%ld.%ld:%ld.%ld func (%08x:%u) %ld.%ld:%ld.%ld)\n",
+	     sc->sc_tv_timer.tv_sec, sc->sc_tv_timer.tv_usec, 
+	     now.tv_sec, now.tv_usec,
+	     sc->sc_tv_data_ready.tv_sec, sc->sc_tv_data_ready.tv_usec, 
+	     sc->sc_tv_advance_start.tv_sec, sc->sc_tv_advance_start.tv_usec, 
+	     sc->sc_tv_advance_stop.tv_sec, sc->sc_tv_advance_stop.tv_usec, 
+	     sc->sc_msg_key, sc->sc_msg_type,
+	     sc->sc_tv_func_start.tv_sec, sc->sc_tv_func_start.tv_usec,
+	     sc->sc_tv_func_stop.tv_sec, sc->sc_tv_func_stop.tv_usec);
 
 	o2net_sc_queue_work(sc, &sc->sc_shutdown_work);
 }
@@ -1307,6 +1328,7 @@
 	o2net_sc_cancel_delayed_work(sc, &sc->sc_keepalive_work);
 	o2net_sc_queue_delayed_work(sc, &sc->sc_keepalive_work,
 				    O2NET_KEEPALIVE_DELAY_SECS * HZ);
+	do_gettimeofday(&sc->sc_tv_timer);
 	mod_timer(&sc->sc_idle_timeout,
 		  jiffies + (O2NET_IDLE_TIMEOUT_SECS * HZ));
 }

Modified: trunk/fs/ocfs2/cluster/tcp_internal.h
===================================================================
--- trunk/fs/ocfs2/cluster/tcp_internal.h	2005-08-27 00:05:12 UTC (rev 2554)
+++ trunk/fs/ocfs2/cluster/tcp_internal.h	2005-08-30 00:07:04 UTC (rev 2555)
@@ -127,6 +127,15 @@
 	void			(*sc_data_ready)(struct sock *sk, int bytes);
 
 	struct list_head	sc_net_proc_item;
+
+	struct timeval 		sc_tv_timer;
+	struct timeval 		sc_tv_data_ready;
+	struct timeval 		sc_tv_advance_start;
+	struct timeval 		sc_tv_advance_stop;
+	struct timeval 		sc_tv_func_start;
+	struct timeval 		sc_tv_func_stop;
+	u32			sc_msg_key;
+	u16			sc_msg_type;
 };
 
 struct o2net_msg_handler {