[patch 15/21] 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-10-27 22:08:16.000000000 +0200
+++ linux/include/hpc/debug.h	2006-10-27 22:08:51.000000000 +0200
@@ -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 *);
 
@@ -45,14 +52,26 @@
 #ifdef CONFIG_OPENMOSIX_DEBUG
 #define OMDEBUG(var, lim, fmt...)	{ if (var >= lim) \
 					printk(KERN_DEBUG "[OMDBG] " 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)
-#define OMDEBUG_SYS(lim, fmt...)	OMDEBUG(om_opts.debug_sys, lim, fmt)
-#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_MIG(lim, fmt...)	  OMDEBUG(om_opts.debug_mig, lim, fmt)
+#define OMDEBUG_SYS(lim, fmt...)	  OMDEBUG(om_opts.debug_sys, lim, fmt)
+#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-10-27 22:08:16.000000000 +0200
+++ linux/include/hpc/hpc.h	2006-10-27 22:08:51.000000000 +0200
@@ -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-10-27 22:08:16.000000000 +0200
+++ linux/hpc/kcomd.c	2006-10-27 22:10:03.000000000 +0200
@@ -345,7 +345,7 @@
 	struct kcom_pkt *recv_kcom_pkt;
 	int i=0;
 
-	OMDEBUG_KCOMD( 2, "KCOMD: %s:%d Receiving packet \n", __FUNCTION__, __LINE__);
+	OMDEBUG_PROTOCOL( 2, "protocol: %s:%d Receiving packet \n", __FUNCTION__, __LINE__);
 
 	// read in hdr
 	recv_kcom_pkt = pkt_hdr_read(node);
@@ -372,17 +372,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: %s:%d it's a MIG_INIT packet ... \n", __FUNCTION__, __LINE__ );
+				OMDEBUG_PROTOCOL(2, "protocol: %s:%d it's a MIG_INIT packet ... \n", __FUNCTION__, __LINE__ );
 				mig_do_receive_init(node, recv_kcom_pkt);
 				break;
 			case MIG_GO_HOME:
-				OMDEBUG_KCOMD(2, "KCOMD: %s:%d it's a MIG_GO_HOME packet ... \n", __FUNCTION__, __LINE__ );
+				OMDEBUG_PROTOCOL(2, "protocol: %s:%d it's a MIG_GO_HOME packet ... \n", __FUNCTION__, __LINE__ );
 				mig_do_receive_home(node, recv_kcom_pkt);
 				break;
 			case MIG_COME_HOME:
 			{
 				task_t *sltsk;
-				OMDEBUG_KCOMD(2, "KCOMD: %s:%d it's a MIG_COME_HOME packet ... \n", __FUNCTION__, __LINE__ );
+				OMDEBUG_PROTOCOL(2, "protocol: %s:%d it's a MIG_COME_HOME packet ... \n", __FUNCTION__, __LINE__ );
 				sltsk = find_task_by_pid(recv_kcom_pkt->rpid);
 				if ( !sltsk ) {
 				    OMBUG("openMosix: %s Unable to find the task %d\n", __FUNCTION__, recv_kcom_pkt->rpid );
@@ -435,6 +435,11 @@
 
 		write_lock( &task->out_packs_lock );
 		list_for_each_entry_safe(pkt, pkt_next, &task->out_packs, list) {
+
+			OMDEBUG_KCOMD(3, "KCOMD: %s send packet type=%d len=%d\n"
+				     , __FUNCTION__, 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-10-27 22:08:16.000000000 +0200
+++ linux/hpc/kcom.c	2006-10-27 22:09:51.000000000 +0200
@@ -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
+ * @param 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
+ * @param buff : raw data
+ * @param 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: %s:%d reading data (%dB)... \n", __FUNCTION__, __LINE__, len );
+	OMDEBUG_PROTOCOL(2, "protocol: %s:%d reading data (%dB)... \n", __FUNCTION__, __LINE__, 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: %s:%d reading headers ... \n", __FUNCTION__, __LINE__ );
+	OMDEBUG_PROTOCOL(2, "KCOMD: %s:%d reading headers ... \n", __FUNCTION__, __LINE__ );
 	oldfs = get_fs();
 	set_fs(KERNEL_DS);
 
@@ -134,7 +337,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;
@@ -151,16 +354,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:
 
@@ -229,16 +431,14 @@
 {
 	struct kcom_pkt *pkt;
 
-	OMDEBUG_KCOMD(3, "KCOMD: %s:%d creating packet (len %d type %d ack %d)... \n", __FUNCTION__, __LINE__, len, type, ack );
+	OMDEBUG_PROTOCOL(3, "protocol: %s:%d creating packet (len %d type %d ack %d)... \n", __FUNCTION__, __LINE__, 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 );
 
@@ -322,7 +522,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);
@@ -348,7 +548,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;
@@ -408,7 +608,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;
 	}
 
@@ -417,7 +617,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;
 	}
 
@@ -425,7 +625,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;
 	}
 
@@ -433,14 +633,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);
@@ -468,9 +668,12 @@
 
 	struct kcom_node *node;
 
+
+	OMDEBUG_PROTOCOL(1, "%s Creating new connection\n", __FUNCTION__ );
+
 	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;
 	}
 
@@ -491,7 +694,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;
 	}
 
@@ -499,13 +702,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
@@ -549,7 +752,7 @@
 					kctask->rpid = 0;
 				}
 			} else {
-				printk(KERN_ERR "ERROR creating kcom task.\n");
+				OMBUG("ERROR creating kcom task.\n");
 				return NULL;
 			}
 		}
@@ -641,7 +844,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;
 	}
 
@@ -767,14 +970,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, "%s sending task packet (type=%d, datasize=%d)"
+			, __FUNCTION__, type, datasize );
+
 	/* put pkt in kcom_task */
 	pkt = kcom_pkt_create(datasize, type, PKT_NEW_MSG, data);
 	if (!pkt)
@@ -789,6 +992,9 @@
 	pkt->rpid=tsk->rpid;
 	pkt->addr=addr; // used by vma_pages
 
+	OMDEBUG_PROTOCOL( 3, "%s Adding packet to out_packs\n", __FUNCTION__ );
+	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 );
@@ -814,9 +1020,12 @@
 	task_t *p = current;
 	unsigned int msgid;
 
+	OMDEBUG_PROTOCOL(1, "protocol: %s:%d send packet (type=%d datasize=%d)\n"
+			, __FUNCTION__, __LINE__, 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;
@@ -824,7 +1033,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;
@@ -852,34 +1061,57 @@
 	struct kcom_pkt *send_pkt;
 	struct kcom_task *send_tsk;
 
+	OMDEBUG_PROTOCOL(1, "protocol: %s:%d sending NACK packet\n" , __FUNCTION__, __LINE__ );
+
+	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, "%s Adding packet to out_packs\n", __FUNCTION__ );
+	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);
 
@@ -899,30 +1131,49 @@
 	struct kcom_pkt *send_pkt;
 	struct kcom_task *send_tsk;
 
+	OMDEBUG_PROTOCOL(1, "protocol: %s:%d sending ACK packet\n" , __FUNCTION__, __LINE__ );
+
+	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, "%s Adding packet to out_packs\n", __FUNCTION__ );
+	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;
 	}
 
@@ -935,7 +1186,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)
@@ -946,11 +1197,24 @@
 	struct kcom_pkt *send_pkt;
 	struct kcom_task *send_tsk;
 
+	OMDEBUG_PROTOCOL(1, "protocol: %s:%d send response (len=%d)\n"
+			, __FUNCTION__, __LINE__, 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
@@ -958,16 +1222,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, "%s Adding packet to out_packs\n", __FUNCTION__ );
+	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;
@@ -1082,13 +1357,16 @@
 	unsigned int msgid;
 	int ack;
 
+	OMDEBUG_PROTOCOL(2, "%s sending packet with ack (type=%d, datasize=%d)\n"
+			, __FUNCTION__, 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;
 		}
 	}
@@ -1097,7 +1375,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;
 		}
 	}
@@ -1108,7 +1386,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;
 	}
 
@@ -1121,7 +1399,10 @@
 
 	set_current_state(TASK_RUNNING);
 
-	if ( ack == -2 ) goto return_error;
+	if ( ack == -2 ) {
+	    OMBUG("Got NACK !! \n");
+	    goto return_error;
+	}
 
 	return 0;
 
@@ -1143,6 +1424,9 @@
 	unsigned int msgid;
 	int i=-1;
 
+	OMDEBUG_PROTOCOL( 1, "%s Sending packet with response (type=%d, datasize=%d)"
+			, __FUNCTION__, type, datasize );
+
 	node=kcom_node_find((struct sockaddr *)saddr);
 	if (node==NULL) {
 		node=create_connection((struct sockaddr *)saddr);
@@ -1155,7 +1439,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;
 		}
 	}
@@ -1165,7 +1449,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-10-27 22:08:16.000000000 +0200
+++ linux/hpc/debugfs.c	2006-10-27 22:08:51.000000000 +0200
@@ -29,6 +29,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-10-27 22:08:16.000000000 +0200
+++ linux/hpc/proc.c	2006-10-27 22:08:51.000000000 +0200
@@ -51,7 +51,7 @@
 
 	OMDEBUG_MIG( 2, "%s asking process %d migration ?\n", __FUNCTION__, 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, "%s:%d asking process %d to migrate home (not a DDEPUTY)?\n", __FUNCTION__, __LINE__,  p->pid );
+			OMDEBUG_MIG( 3, "%s:%d asking process %d to migrate home (from remote)\n", __FUNCTION__, __LINE__,  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-10-27 22:08:16.000000000 +0200
+++ linux/hpc/migctrl.c	2006-10-27 22:08:51.000000000 +0200
@@ -202,7 +202,7 @@
 {
 	OMDEBUG_MIG( 3, "%s:%d pid %d Moving task?\n", __FUNCTION__, __LINE__,  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);