[patch 49/56] Protocol debug support

Subject: [patch @num@/@total@] Protocol debug support

This patch adds the debug output for the protocol itself
(printing out packets ... )

(BTW, continuing to clean out printk( KERN_ERR =>OMBUG, and 
fixing kcom_task_send )

Index: linux/include/hpc/debug.h
===================================================================
--- linux.orig/include/hpc/debug.h	2006-11-02 22:52:47.000000000 +0100
+++ linux/include/hpc/debug.h	2006-11-02 22:52:57.000000000 +0100
@@ -24,6 +24,7 @@
 #include <hpc/protocol.h>
 #include <hpc/comm.h>
 #include <hpc/hpc.h>
+#include <hpc/kcom.h>
 
 int proc_debug_get_loadinfo(char *value, size_t size);
 int proc_debug_get_admin(char *value, size_t size);
@@ -35,6 +36,12 @@
 
 
 /* for packets */
+void om_dump_packet(struct kcom_pkt* pkt);
+void om_dump_packet_hdr(struct kcom_pkt* pkt);
+void om_dump_packet_data(struct kcom_pkt* pkt);
+extern int om_debug_do_switch;
+
+
 void om_debug_regs(struct pt_regs *);
 void debug_mlink(struct socket *);
 
@@ -46,8 +53,15 @@
 #define OMDEBUG(var, lim, fmt...)	{ if (var >= lim) \
 						printk(KERN_DEBUG "[OMDBG] %s:%d ", __FUNCTION__,  __LINE__); \
 						printk(fmt); }
+#define OMDEBUG_DO(var, lim, action)	do { \
+					    if (var >= lim) { \
+						om_debug_do_switch = var;  \
+						action; \
+					    } \
+					} while (0)
 #else
-#define OMDEBUG(var, lim, fmt...)	do {} while (0)
+#define OMDEBUG(var, lim, fmt...)
+#define OMDEBUG_DO(var, lim, action)
 #endif
 
 #define OMDEBUG_MIG(lim, fmt...)	OMDEBUG(om_opts.debug_mig, lim, fmt)
@@ -55,5 +69,9 @@
 #define OMDEBUG_RINO(lim, fmt...)	OMDEBUG(om_opts.debug_rino, lim, fmt)
 #define OMDEBUG_CPYUSER(lim, fmt...)	OMDEBUG(om_opts.debug_copyuser, lim, fmt)
 #define OMDEBUG_KCOMD(lim, fmt...)	OMDEBUG(om_opts.debug_kcomd, lim, fmt)
+#define OMDEBUG_PROTOCOL(lim, fmt...)	OMDEBUG(om_opts.debug_protocol, lim, fmt)
+
+#define OMDEBUG_PROTOCOL_DO(lim, action) OMDEBUG_DO(om_opts.debug_protocol, lim, action)
+#define OMDEBUG_KCOMD_DO(lim, action)    OMDEBUG_DO(om_opts.debug_kcomd, lim, action)
 
 #endif /* _HPC_DEBUG_H */
Index: linux/include/hpc/hpc.h
===================================================================
--- linux.orig/include/hpc/hpc.h	2006-11-02 22:52:47.000000000 +0100
+++ linux/include/hpc/hpc.h	2006-11-02 22:52:57.000000000 +0100
@@ -57,6 +57,7 @@
 	int debug_rino;
 	int debug_copyuser;
 	int debug_kcomd;
+	int debug_protocol;
 #endif
 };
 
Index: linux/hpc/kcomd.c
===================================================================
--- linux.orig/hpc/kcomd.c	2006-11-02 22:52:55.000000000 +0100
+++ linux/hpc/kcomd.c	2006-11-02 22:52:57.000000000 +0100
@@ -332,6 +332,7 @@
 	int i=0;
 
 
+	OMDEBUG_PROTOCOL(2, "KCOMD: Receiving packet \n");
 	// read in hdr
 	recv_kcom_pkt = pkt_hdr_read(node);
 
@@ -357,17 +358,17 @@
 	if ((recv_kcom_pkt->type & MSG_MASK) == PKT_NEW_MSG) {
 		switch (recv_kcom_pkt->type & MIG_MASK) {
 			case MIG_INIT:
-				OMDEBUG_KCOMD(2, "KCOMD: it's a MIG_INIT packet ... \n");
+				OMDEBUG_PROTOCOL(2, "KCOMD: it's a MIG_INIT packet ... \n");
 				mig_do_receive_init(node, recv_kcom_pkt);
 				break;
 			case MIG_GO_HOME:
-				OMDEBUG_KCOMD(2, "KCOMD: it's a MIG_GO_HOME packet ... \n");
+				OMDEBUG_PROTOCOL(2, "KCOMD: it's a MIG_GO_HOME packet ... \n");
 				mig_do_receive_home(node, recv_kcom_pkt);
 				break;
 			case MIG_COME_HOME:
 			{
 				task_t *sltsk;
-				OMDEBUG_KCOMD(2, "KCOMD: it's a MIG_COME_HOME packet ... \n");
+				OMDEBUG_PROTOCOL(2, "KCOMD: it's a MIG_COME_HOME packet ... \n");
 				sltsk = find_task_by_pid(recv_kcom_pkt->rpid);
 				if (!sltsk) {
  				    OMBUG("openMosix: Unable to find the task %d\n", recv_kcom_pkt->rpid);
@@ -420,6 +421,11 @@
 
 		write_lock(&task->out_packs_lock);
 		list_for_each_entry_safe(pkt, pkt_next, &task->out_packs, list) {
+
+			OMDEBUG_KCOMD(3, "KCOMD: send packet type=%d len=%d\n"
+				     ,pkt->type, pkt->len);
+
+			OMDEBUG_KCOMD_DO(4, om_dump_packet(pkt));
 			data_send(node->sock, (void *)pkt, pkt->len);
 
 			list_del(&pkt->list);
Index: linux/hpc/kcom.c
===================================================================
--- linux.orig/hpc/kcom.c	2006-11-02 22:52:53.000000000 +0100
+++ linux/hpc/kcom.c	2006-11-02 22:52:57.000000000 +0100
@@ -26,8 +26,208 @@
 #include <hpc/prototype.h>
 
 #include <hpc/debug.h>
+#include <linux/ctype.h>
 
 
+#ifdef CONFIG_OPENMOSIX_DEBUG
+
+
+/*
+ * Protocol debug, used to dump a packet
+ */
+
+
+int om_debug_do_switch = 0;
+/**
+ *
+ * om_format_type
+ *
+ * Description:
+ * format the type of a packet in a human readable
+ * format
+ * @buffer the buffer to write to (need at least 44 chars)
+ **/
+
+void om_format_type(int type, char* buffer)
+{
+    char *msg_mask_names[] = {
+			       "new "
+			     , "ack "
+			     , "resp"
+			     , "nack"
+			     };
+    char *mig_mask_names[] = {
+			       "ping     "
+			     , "init     "
+			     , "mm       "
+			     , "vma      "
+			     , "page     "
+			     , "fp       "
+			     , "arch     "
+			     , "task     "
+			     , "go_home  "
+			     , "come_home"
+			     , "abort    "
+			     , "syscall  "
+			     };
+    char *sys_mask_names[] = {
+			       "copy_from_user   "
+			     , "copy_to_user     "
+			     , "strncpy_from_user"
+			     , "strnlen_user     "
+			     , "get_user         "
+			     , "put_user         "
+			     , "signal           "
+			     , "coming_home      "
+			     , "syscall_done     "
+			     };
+    char *dep_flg[] = { "dep", "DEP" };
+    char *mig_flg[] = { "mig", "MIG" };
+    char *rem_flg[] = { "rem", "REM" };
+
+    sprintf(buffer, "%s%s%s %s %s %s"
+	   , rem_flg[ (type & REM_FLG) >> 14 ]
+	   , mig_flg[ (type & MIG_FLG) >> 13 ]
+	   , dep_flg[ (type & DEP_FLG) >> 12 ]
+	   , sys_mask_names[ (type & SYSCALL_MASK) >> 8 ]
+	   , mig_mask_names[ (type & MIG_MASK)     >> 4 ]
+	   , msg_mask_names[ (type & MSG_MASK)     >> 0 ]
+	   );
+}
+
+
+/**
+ * hexdump
+ * Description
+ * Produces a hexdump of the given buffer
+ * @buff : raw data
+ * @len : length to display
+ **/
+
+void hexdump(const unsigned char* const buff, int len)
+{
+    int i, dumped = 0;
+    int h = 0, a = 0;
+    int inc = 0;
+
+    char hexbuf[64];
+    char asciibuf[64];
+
+    if (!buff || len <= 0) return;
+
+    for (i = 0; i < len; i++) {
+	dumped = 0;
+
+	h += sprintf(hexbuf + h, "%02X", buff[i]);
+
+
+
+	if (isprint(buff[i])) asciibuf[a] = buff[i];
+	else asciibuf[a] = '.';
+
+	a++;
+
+	if (0 != i && 0 == (i%16)) {
+	    hexbuf[h] = 0;
+	    asciibuf[a] = 0;
+	    printk(KERN_DEBUG"[OM] pktdump |%35.35s| |%16.16s|\n", hexbuf, asciibuf);
+	    dumped = 1;
+	    a = 0;
+	    h = 0;
+	    inc = 0;
+
+	} else if (0 == ((h - inc)% 8) && h != 2) {
+	    hexbuf[h++] = ' ';
+	    inc++ ;
+	}
+
+
+    }
+
+    if (!dumped) {
+	hexbuf[h] = 0;
+	asciibuf[a] = 0;
+	printk(KERN_DEBUG"[OM] pktdump |%-35.35s| |%-16.16s|\n", hexbuf, asciibuf);
+    }
+
+}
+
+/**
+ * om_dump_packet_hdr
+ *
+ * Description
+ * dump the packet to the console in a readable way
+ *
+ * @param pkt : the packet to dump
+ **/
+
+void om_dump_packet_hdr(struct kcom_pkt* pkt)
+{
+    char buffer[64];
+
+    if (!pkt) {
+	OMBUG("packet is null, can't dump header\n");
+	return;
+    }
+
+    om_format_type(pkt->type, buffer);
+
+    printk(KERN_DEBUG"[OM] pktdump hpid: %5d rpid: %5d len: %d\n"
+	  , pkt->hpid, pkt->rpid, pkt->len);
+
+    printk(KERN_DEBUG"[OM] pktdump %s\n", buffer);
+    printk(KERN_DEBUG"[OM] pktdump addr: 0x%p msgid: %d\n"
+	  , (void *) pkt->addr, pkt->msgid);
+
+    printk(KERN_DEBUG"[OM] pktdump RAW header dump ----------------------------------------\n");
+    hexdump((char*)pkt, (int) &(((struct kcom_pkt*) 0)->data));
+    printk(KERN_DEBUG"[OM] pktdump RAW header dump ----------------------------------------\n");
+
+}
+
+void om_dump_packet_data(struct kcom_pkt* pkt)
+{
+    if (!pkt) {
+	OMBUG(KERN_DEBUG"packet is null, can't dump header\n");
+	return;
+    }
+
+    if (!pkt->data) {
+	OMBUG(KERN_DEBUG"packet data is NULL\n");
+	return;
+    }
+
+    printk(KERN_DEBUG"[OM] pktdump data RAW dump ------------------------------------------\n");
+    hexdump(pkt->data, pkt->len);
+    printk(KERN_DEBUG"[OM] pktdump data RAW dump ------------------------------------------\n");
+}
+
+/**
+ * om_dump_packet
+ * Description:
+ *
+ * dump the packet content if the used om_debug_do_switch is >= 4 dump data too
+ * @pkt: the packet to dump
+ */
+
+void om_dump_packet(struct kcom_pkt* pkt)
+{
+
+    if (!pkt) {
+	OMBUG("packet is NULL ... can't dump it \n");
+	return;
+    }
+
+    om_dump_packet_hdr(pkt);
+
+    if (om_debug_do_switch >= 4) {
+	om_dump_packet_data(pkt);
+    }
+
+}
+
+
+#endif
 /**
  * pkt_data_read
  *
@@ -49,7 +249,7 @@
 	iov.iov_base = data;
 	iov.iov_len = len;
 
-	OMDEBUG_KCOMD(3, "KCOMD: reading data (%dB)... \n", len);
+	OMDEBUG_PROTOCOL(2, "KCOMD: reading data (%dB)... \n", len);
 	// Too small of a packet gets delayed before being sent. Even with TCP_NODELAY
 	if (len < 32) {
 		iov.iov_base = &buf;
@@ -66,7 +266,7 @@
 
 			/* Prevent infinite loop 60s */
 			if (60000 > nb_retries) {
-				printk(KERN_ERR "openMosix %s too many retries\n", __FUNCTION__);
+				OMBUG("too many retries\n");
 				len = -1;
 				goto read_exit;
 			}
@@ -76,7 +276,7 @@
 		}
 
 		if (i < 0) {
-			printk(KERN_ERR "openMosix %s: %d receiving data.\n", __FUNCTION__, i);
+			OMBUG("error %d receiving data.\n", i);
 			len = -1;
 			goto read_exit;
 		}
@@ -96,6 +296,9 @@
 }
 EXPORT_SYMBOL_GPL(pkt_data_read);
 
+
+
+
 /**
  * pkt_hdr_read
  *
@@ -118,7 +321,7 @@
 	iov.iov_base = recv_kcom_pkt;
  	iov.iov_len = sizeof(struct kcom_pkt);
 
- 	OMDEBUG_KCOMD(3, "KCOMD: reading headers ... \n");
+ 	OMDEBUG_PROTOCOL(2, "KCOMD: reading headers ... \n");
 	oldfs = get_fs();
 	set_fs(KERNEL_DS);
 
@@ -135,7 +338,7 @@
  	}
 
  	if (i < 0) {
- 		printk(KERN_ERR "openMosix: %s %d receiving header.\n", __FUNCTION__, i);
+		OMBUG("error %d receiving header.\n", i);
  		goto receive_error;
  	}
  	iov.iov_base += i;
@@ -153,16 +356,15 @@
 
 
 receive_timeout:
- 	printk(KERN_ERR "openMosix %s Can't receive header %d fragment, too many (%d)\n"
- 			 " retries)", __FUNCTION__, i, retry);
+	OMBUG("Can't receive header %d fragment, too many (%d) retries\n", i, retry);
  	goto exit_error;
 
 receive_error:
- 	printk(KERN_ERR "openMosix %s, %d receiving header.\n", __FUNCTION__,  i);
+	OMBUG("%d receiving header.\n", i);
  	goto exit_error;
 
 receive_incomplete:
- 	printk(KERN_ERR "openMosix %s incomplete packet received\n", __FUNCTION__);
+	OMBUG("incomplete packet received\n");
 
 exit_error:
 
@@ -231,16 +433,15 @@
 {
 	struct kcom_pkt *pkt;
 
-	OMDEBUG_KCOMD(3, "KCOMD: creating packet (len %d type %d ack %d)... \n", len, type, ack);
+	OMDEBUG_PROTOCOL(3, "KCOMD: creating packet (len %d type %d ack %d)... \n", len, type, ack);
 	pkt=kmem_cache_alloc(kcom_pkt_cachep, SLAB_KERNEL);
 	if (pkt) {
 		pkt->len = len;
 		pkt->type = type;
 
-		if (len > 0)
-			pkt->data=data;
-		else
-			pkt->data=NULL;
+		if (len > 0) pkt->data=data;
+		else pkt->data=NULL;
+
 
 		INIT_LIST_HEAD(&pkt->list);
 
@@ -324,7 +525,7 @@
 
 	node=kmem_cache_alloc(kcom_node_cachep, SLAB_KERNEL);
 	if (!node) {
-		printk(KERN_ERR "Unable to allocate node space.\n");
+		OMBUG("Unable to allocate node space.\n");
 		return NULL; //-ENOMEM;
 	}
 	INIT_LIST_HEAD(&node->list);
@@ -350,7 +551,7 @@
 	if (kcomd_task)
 		send_sig(SIGHUP,kcomd_task,0);
 	else {
-		printk(KERN_ERR "Unable to find kcomd daemon.\n");
+		OMBUG("Unable to find kcomd daemon.\n");
 		return NULL;
 	}
 	return node;
@@ -410,7 +611,7 @@
 	ret = sock_setsockopt(sock, SOL_SOCKET, SO_KEEPALIVE,
 		pval, sizeof(val));
 	if (ret) {
-		printk(KERN_ERR "unable to setsock SO_KEEPALIVE ERROR %d\n", ret);
+		OMBUG("unable to setsock SO_KEEPALIVE ERROR %d\n", ret);
 		return -1;
 	}
 
@@ -419,7 +620,7 @@
 	ret = sock->ops->setsockopt(sock, IPPROTO_TCP, TCP_KEEPINTVL,
 		pval, sizeof(val));
 	if (ret) {
-		printk(KERN_ERR "Unable to setsock TCP_KEEPINTVL ERROR %d\n", ret);
+		OMBUG("Unable to setsock TCP_KEEPINTVL ERROR %d\n", ret);
 		return -1;
 	}
 
@@ -427,7 +628,7 @@
 	ret = sock->ops->setsockopt(sock, IPPROTO_TCP, TCP_KEEPCNT,
 		pval, sizeof(val));
 	if (ret) {
-		printk(KERN_ERR "unable to setsock TCP_KEEPCNT ERROR %d\n", ret);
+		OMBUG("unable to setsock TCP_KEEPCNT ERROR %d\n", ret);
 		return -1;
 	}
 
@@ -435,14 +636,14 @@
 	ret = sock->ops->setsockopt(sock, IPPROTO_TCP, TCP_KEEPIDLE,
 		pval, sizeof(val));
 	if (ret) {
-		printk(KERN_ERR "unable to setsock TCP_KEEPIDLE ERROR %d\n", ret);
+		OMBUG("unable to setsock TCP_KEEPIDLE ERROR %d\n", ret);
 		return -1;
 	}
 
 	val=1;
 	ret = sock->ops->setsockopt(sock, IPPROTO_TCP, TCP_NODELAY, pval, sizeof(val));
 	if (ret < 0) {
-		printk(KERN_ERR "Unable to setsockopt ERROR: %d\n", ret);
+		OMBUG("Unable to setsockopt ERROR: %d\n", ret);
 		return -1;
 	}
 	set_fs(oldfs);
@@ -470,9 +671,12 @@
 
 	struct kcom_node *node;
 
+
+	OMDEBUG_PROTOCOL(1, "Creating new connection\n");
+
 	ret = sock_create(saddr->sa_family, SOCK_STREAM, IPPROTO_TCP, &sock);
 	if (ret < 0) {
-		printk(KERN_ERR "Unable to sock_create. ret=%d\n", ret);
+		OMBUG("Unable to sock_create. ret=%d\n", ret);
 		return NULL;
 	}
 
@@ -493,7 +697,7 @@
 	set_current_state(TASK_RUNNING);
 
 	if (error < 0) {
-		printk(KERN_ERR "Unable to create connection. Err %d\n", error);
+		OMBUG("Unable to create connection. Err %d\n", error);
 		return NULL;
 	}
 
@@ -501,13 +705,13 @@
 	if (!node) {
 		node = kcom_node_add(sock);
 		if (!node) {
-			printk(KERN_ERR "Unable to add node\n");
+			OMBUG("Unable to add node\n");
 			return NULL;
 		}
 		memcpy(&node->addr, saddr, sizeof(*saddr));
 		ret=set_sockopts(node->sock);
 		if (ret) {
-			printk(KERN_ERR "Unable to set socket options.\n");
+			OMBUG("Unable to set socket options.\n");
 			return NULL;
 		}
 	} else
@@ -551,7 +755,7 @@
 					kctask->rpid = 0;
 				}
 			} else {
-				printk(KERN_ERR "ERROR creating kcom task.\n");
+				OMBUG("ERROR creating kcom task.\n");
 				return NULL;
 			}
 		}
@@ -643,7 +847,7 @@
 	p = find_task_by_pid(pid);
 	 read_unlock(&tasklist_lock);
 	if (!p) {
-		printk(KERN_ERR "Unable to find pid %u\n", pid);
+		OMBUG("Unable to find pid %u\n", pid);
 		return NULL;
 	}
 
@@ -769,14 +973,14 @@
  **/
 int kcom_task_send(struct kcom_task *tsk, int type, int datasize, char *data, char *resp, unsigned long addr)
 {
-	// struct kcom_task *tsk;
 	struct kcom_pkt *pkt;
 
-	// printk("kcom_task_send:\n");
-	// tsk = kcom_task_find(pid);
 	if (!tsk)
 		return -ENODEV;
 
+	OMDEBUG_PROTOCOL(2, "sending task packet (type=%d, datasize=%d)"
+			,type, datasize);
+
 	/* put pkt in kcom_task */
 	pkt = kcom_pkt_create(datasize, type, PKT_NEW_MSG, data);
 	if (!pkt)
@@ -791,6 +995,9 @@
 	pkt->rpid=tsk->rpid;
 	pkt->addr=addr; // used by vma_pages
 
+	OMDEBUG_PROTOCOL(3, "Adding packet to out_packs\n");
+	OMDEBUG_PROTOCOL_DO(3, om_dump_packet(pkt));
+
 	write_lock(&tsk->out_packs_lock);
 	list_add_tail(&pkt->list, &tsk->out_packs);
 	write_unlock(&tsk->out_packs_lock);
@@ -816,9 +1023,12 @@
 	task_t *p = current;
 	unsigned int msgid;
 
+	OMDEBUG_PROTOCOL(1, "protocol: send packet (type=%d datasize=%d)\n"
+			,type, datasize);
+
 	node=kcom_node_find((struct sockaddr *)saddr);
 	if (node==NULL) {
-		printk(KERN_ERR "node not found, creating new connection.\n");
+		OMBUG("node not found, creating new connection.\n");
 		node=create_connection((struct sockaddr *)saddr);
 		if (node==NULL)
 			return -1;
@@ -826,7 +1036,7 @@
 
 	tsk=kcom_task_find(p->pid);
 	if (tsk==NULL) {
-		printk(KERN_ERR "Task not found. creating new.\n");
+		OMBUG("Task not found. creating new.\n");
 		tsk=kcom_task_create(node, p->pid);
 		if (tsk==NULL)
 			return -1;
@@ -854,34 +1064,57 @@
 	struct kcom_pkt *send_pkt;
 	struct kcom_task *send_tsk;
 
+	OMDEBUG_PROTOCOL(1, "protocol: sending NACK packet\n");
+
+	if (!p) {
+	    OMBUG("null task!");
+	    return -ENODEV;
+	}
+
 	mig_flag=recv_pkt->type & MIG_MASK;
 	syscall_flag=recv_pkt->type & SYSCALL_MASK;
 
-	send_tsk=kcom_task_find(p->pid);
+	send_tsk = kcom_task_find(p->pid);
+
+	if (!send_tsk) {
+	    OMBUG("can't find kcomd task for pid %d\n", p->pid);
+	    return -ENODEV;
+	}
 
 	if (task_test_dflags(p, DREMOTE))
 		node_flag = REM_FLG;
 	else
 		node_flag = DEP_FLG;
+
 	send_pkt=kcom_pkt_create(0, mig_flag | syscall_flag | PKT_NACK | node_flag, PKT_NACK, NULL);
 
-	send_pkt->msgid=recv_pkt->msgid; /* responses have same msg id as pkt they are responding to. */
+	if (!send_pkt) {
+	    OMBUG("Can't create packet\n");
+	    return -ENODEV;
+	}
+
+	/* responses have same msg id as pkt they are responding to. */
+	send_pkt->msgid=recv_pkt->msgid;
 	send_pkt->hpid=recv_pkt->hpid;
 	send_pkt->rpid=recv_pkt->rpid;
 	send_pkt->resp=recv_pkt->resp;
 
-	// spin_lock(&send_tsk->spinlock); /* done outside this function */
+	OMDEBUG_PROTOCOL(3, "Adding packet to out_packs\n");
+	OMDEBUG_PROTOCOL_DO(3, om_dump_packet(send_pkt));
+
+	write_lock(&send_tsk->out_packs_lock);
 	list_add_tail(&send_pkt->list, &send_tsk->out_packs);
-	// spin_unlock(&send_tsk->spinlock);
+	write_unlock(&send_tsk->out_packs_lock);
 
 	if (kcomd_task)
 		send_sig(SIGHUP,kcomd_task,0);
 	else {
-		printk(KERN_ERR "Unable to signal kcomd\n");
+		OMBUG("Unable to signal kcomd\n");
 		return -1;
 	}
 
 	return 0;
+
 }
 EXPORT_SYMBOL(kcom_send_nack);
 
@@ -901,30 +1134,49 @@
 	struct kcom_pkt *send_pkt;
 	struct kcom_task *send_tsk;
 
+	OMDEBUG_PROTOCOL(1, "protocol: sending ACK packet\n");
+
+	if (!p) {
+	    OMBUG("null task!");
+	    return -ENODEV;
+	}
+
 	mig_flag=recv_pkt->type & MIG_MASK;
 	syscall_flag=recv_pkt->type & SYSCALL_MASK;
 
 	send_tsk=kcom_task_find(p->pid);
 
+	if (!send_tsk) {
+	    OMBUG("can't find kcomd task for pid %d\n", p->pid);
+	    return -ENODEV;
+	}
 	if (task_test_dflags(p, DREMOTE))
 		node_flag = REM_FLG;
 	else
 		node_flag = DEP_FLG;
 	send_pkt=kcom_pkt_create(0, mig_flag | syscall_flag | PKT_ACK | node_flag, PKT_ACK, NULL);
 
+	if (!send_pkt) {
+	    OMBUG("Can't create packet\n");
+	    return -ENODEV;
+	}
+
 	send_pkt->msgid=recv_pkt->msgid; // responses have same msg id as pkt they are responding to.
 	send_pkt->hpid=recv_pkt->hpid;
 	send_pkt->rpid=recv_pkt->rpid;
 	send_pkt->resp=recv_pkt->resp;
 
-	// spin_lock(&send_tsk->spinlock); // done outside this function
+	OMDEBUG_PROTOCOL(3, "Adding packet to out_packs\n");
+	OMDEBUG_PROTOCOL_DO(3, om_dump_packet(send_pkt));
+
+	write_lock(&send_tsk->out_packs_lock);
 	list_add_tail(&send_pkt->list, &send_tsk->out_packs);
-	// spin_unlock(&send_tsk->spinlock);
+	write_unlock(&send_tsk->out_packs_lock);
 
 	if (kcomd_task)
 		send_sig(SIGHUP,kcomd_task,0);
 	else {
-		printk(KERN_ERR "Unable to signal kcomd\n");
+		OMBUG("Unable to signal kcomd\n");
 		return -1;
 	}
 
@@ -937,7 +1189,7 @@
  *
  * Description:
  *    Send an response to the other node.  This is the matching function for kcom_send_with_response.
- *    An response is both the acknowledgement that the kcom pkt was received correctly (or not) and
+ *    A response is both the acknowledgement that the kcom pkt was received correctly (or not) and
  *    the expected response data.
  **/
 int kcom_send_resp(task_t *p, int len, char *buf, struct kcom_pkt *recv_pkt)
@@ -948,11 +1200,24 @@
 	struct kcom_pkt *send_pkt;
 	struct kcom_task *send_tsk;
 
+	OMDEBUG_PROTOCOL(1, "protocol: send response (len=%d)\n"
+			, len);
+
+	if(!p) {
+	    OMBUG("Null task!\n");
+	    return -ENODEV;
+	}
+
 	mig_flag=recv_pkt->type & MIG_MASK;
 	syscall_flag=recv_pkt->type & SYSCALL_MASK;
 
 	send_tsk=kcom_task_find(p->pid);
 
+	if (!send_tsk) {
+	    OMBUG("Can't locate task for %d\n", p->pid);
+	    return -ENODEV;
+	}
+
 	if (task_test_dflags(p, DREMOTE))
 		node_flag = REM_FLG;
 	else
@@ -960,16 +1225,27 @@
 
 	send_pkt=kcom_pkt_create(len, mig_flag | syscall_flag | PKT_ACK | node_flag, PKT_ACK, buf);
 
+	if (!send_pkt) {
+	    OMBUG("Can't create packet\n");
+	    return -ENODEV;
+	}
+
 	send_pkt->msgid=recv_pkt->msgid;
 	send_pkt->hpid=send_tsk->hpid;
 	send_pkt->rpid=send_tsk->rpid;
 	send_pkt->resp=recv_pkt->resp;
 
+	OMDEBUG_PROTOCOL(3, "Adding packet to out_packs\n");
+	OMDEBUG_PROTOCOL_DO(3, om_dump_packet(send_pkt));
+
+	write_lock(&send_tsk->out_packs_lock);
 	list_add_tail(&send_pkt->list, &send_tsk->out_packs);
+	write_unlock(&send_tsk->out_packs_lock);
+
 	if (kcomd_task) {
 		send_sig(SIGHUP, kcomd_task, 0);
 	} else {
-		printk(KERN_ERR "Unable to signal kcomd\n");
+		OMBUG("Unable to signal kcomd\n");
 		return -1;
 	}
 	return 0;
@@ -1084,13 +1360,16 @@
 	unsigned int msgid;
 	int ack;
 
+	OMDEBUG_PROTOCOL(2, "sending packet with ack (type=%d, datasize=%d)\n"
+			,type, datasize);
+
 	node=kcom_node_find((struct sockaddr *)saddr);
 
 	if (node==NULL) {
 
 		node=create_connection((struct sockaddr *)saddr);
 		if (!node) {
-			printk(KERN_ERR "ERROR: Unable to create new connection.\n");
+			OMBUG("ERROR: Unable to create new connection.\n");
 			goto return_error;
 		}
 	}
@@ -1099,7 +1378,7 @@
 	if (tsk==NULL) {
 		tsk=kcom_task_create(node, p->pid);
 		if (!tsk) {
-			printk(KERN_ERR "ERROR: Unable to create task.\n");
+			OMBUG("ERROR: Unable to create task.\n");
 			goto return_error;
 		}
 	}
@@ -1110,7 +1389,7 @@
 	if (kcomd_task)
 		send_sig(SIGHUP, kcomd_task, 0);
 	else {
-		printk(KERN_ERR "Unable to find kcomd daemon.\n");
+		OMBUG("Unable to find kcomd daemon.\n");
 		goto return_error;
 	}
 
@@ -1123,8 +1402,10 @@
 
 	set_current_state(TASK_RUNNING);
 
-	if (ack == -2) goto return_error;
-
+	if (ack == -2) {
+	    OMBUG("Got NACK !! \n");
+	    goto return_error;
+	}
 	return 0;
 
 return_error:
@@ -1145,6 +1426,9 @@
 	unsigned int msgid;
 	int i=-1;
 
+	OMDEBUG_PROTOCOL(1, "Sending packet with response (type=%d, datasize=%d)"
+			,type, datasize);
+
 	node=kcom_node_find((struct sockaddr *)saddr);
 	if (node==NULL) {
 		node=create_connection((struct sockaddr *)saddr);
@@ -1157,7 +1441,7 @@
 	if (!tsk) {
 		tsk=kcom_task_create(node, p->pid);
 		if (!tsk) {
-			printk(KERN_ERR "Unable to create task\n");
+			OMBUG("Unable to create task\n");
 			return -1;
 		}
 	}
@@ -1167,7 +1451,7 @@
 	if (kcomd_task)
 		send_sig(SIGHUP,kcomd_task,0);
 	else {
-		printk(KERN_ERR "Unable to find kcomd daemon.\n");
+		OMBUG("Unable to find kcomd daemon.\n");
 		return -1;
 	}
 
Index: linux/hpc/debugfs.c
===================================================================
--- linux.orig/hpc/debugfs.c	2006-11-02 22:52:47.000000000 +0100
+++ linux/hpc/debugfs.c	2006-11-02 22:52:57.000000000 +0100
@@ -28,6 +28,7 @@
 	{ "rinode", 0644, &om_opts.debug_rino },
 	{ "copyuser", 0644, &om_opts.debug_copyuser },
 	{ "kcomd", 0644, &om_opts.debug_kcomd },
+	{ "protocol", 0644, &om_opts.debug_protocol },
 };
 
 static struct dentry * dfs_dentries[ARRAY_SIZE(file_entries)];
Index: linux/hpc/proc.c
===================================================================
--- linux.orig/hpc/proc.c	2006-11-02 22:52:49.000000000 +0100
+++ linux/hpc/proc.c	2006-11-02 22:52:57.000000000 +0100
@@ -51,7 +51,7 @@
 
 	OMDEBUG_MIG(2, "asking process %d migration ?\n", p->pid);
 	if (!dest_ptr) {
-	    printk(KERN_ERR "openmosix: openmosix internal structure is not initialized for pid %d\n", p->pid);
+	    OMBUG("internal structure is not initialized for pid %d\n", p->pid);
 	    return -EFAULT;
 	}
 
@@ -77,7 +77,7 @@
 			if (kcomd_task != NULL) send_sig(SIGHUP,kcomd_task,0);
 		} else {
 
-			OMDEBUG_MIG(3, "asking process %d to migrate home (not a DDEPUTY)?\n", p->pid);
+			OMDEBUG_MIG(3, "asking process %d to migrate home (from remote)\n",  p->pid);
 			task_register_migration(p);
 		}
 	} else {
@@ -91,6 +91,7 @@
 				if (in_aton(buf) == cur_addr->sin_addr.s_addr) { /* home -> remote - redundant migration;*/
 					return size;
 				} /* FIXME:  remote to remote migration*/
+			OMBUG("remote to remote migration is not yet implemented :(\n");
 			}
 		} else {
 
Index: linux/hpc/migctrl.c
===================================================================
--- linux.orig/hpc/migctrl.c	2006-11-02 22:52:38.000000000 +0100
+++ linux/hpc/migctrl.c	2006-11-02 22:52:57.000000000 +0100
@@ -184,7 +184,7 @@
 {
 	OMDEBUG_MIG(3, "pid %d Moving task?\n", p->pid);
 	if (task_test_stay(p, DSTAY)) {
-		printk(KERN_DEBUG "oM: Task can't move. check stay reason\n");
+		OMDEBUG_MIG(2, "Task can't move. check stay reason\n");
 		return -1;
 	}
 	__task_move_to_node(p, whereto, reason);