changeset 89:e15ba31853ef

Cleanup in debug messages: INFO = errors, FULL = tracing execution path
author Sebastien Decugis <sdecugis@nict.go.jp>
date Tue, 15 Jul 2008 16:55:41 +0900
parents 2f46f6491c04
children c2f0ff9a5774
files configure.ac waaad/conf.c waaad/dict-base.c waaad/dictionary.c waaad/dispatch.c waaad/extensions.c waaad/log.h waaad/main.c waaad/message.c waaad/peer.c waaad/queues.c waaad/queues.h waaad/routing.c waaad/security.c waaad/session.c
diffstat 15 files changed, 473 insertions(+), 179 deletions(-) [+]
line wrap: on
line diff
--- a/configure.ac	Tue Jul 15 13:56:30 2008 +0900
+++ b/configure.ac	Tue Jul 15 16:55:41 2008 +0900
@@ -176,7 +176,7 @@
             [AS_HELP_STRING([--disable-debug],
                [Remove all debug messages.])],
             [AC_SUBST([WAAAD_DEBUG], [-DTRACE_LEVEL=NONE])],
-            [AC_SUBST([WAAAD_DEBUG], [-DTRACE_LEVEL=FULL])])
+            [AC_SUBST([WAAAD_DEBUG], [-DTRACE_LEVEL=INFO])])
 
 AC_ARG_WITH([conf],
             [AS_HELP_STRING([--with-conf=<file>],
--- a/waaad/conf.c	Tue Jul 15 13:56:30 2008 +0900
+++ b/waaad/conf.c	Tue Jul 15 16:55:41 2008 +0900
@@ -102,17 +102,17 @@
 	int ret;
 	
 	if (!g_conf) {
-		TRACE_DEBUG (FULL, "Configuration is not initialized...");
+		TRACE_DEBUG (INFO, "Configuration is not initialized...");
 		return EINVAL;
 	}
 
-	TRACE_DEBUG (INFO, "Parsing configuration file: %s...", g_conf->filepath);
+	TRACE_DEBUG (FULL, "Parsing configuration file: %s...", g_conf->filepath);
 	
 	yyin = fopen(g_conf->filepath, "r");
 	if (yyin == NULL) {
 		ret = errno;
 		log_error("Unable to open configuration file %s for reading: %s\n", g_conf->filepath, strerror(ret));
-		TRACE_DEBUG (FULL, "Error occurred, message logged -- configuration file.");
+		TRACE_DEBUG (INFO, "Error occurred, message logged -- configuration file.");
 		return ret;
 	}
 
--- a/waaad/dict-base.c	Tue Jul 15 13:56:30 2008 +0900
+++ b/waaad/dict-base.c	Tue Jul 15 16:55:41 2008 +0900
@@ -89,6 +89,8 @@
 
 int dict_base_protocol(void)
 {
+	TRACE_ENTRY("");
+	
 	/* Vendors section */
 	{
 		/* The base RFC has no vendor information */
--- a/waaad/dictionary.c	Tue Jul 15 13:56:30 2008 +0900
+++ b/waaad/dictionary.c	Tue Jul 15 16:55:41 2008 +0900
@@ -246,6 +246,8 @@
 /* Initialize a list */
 static void init_list ( _dict_list_t * list, _dict_object_t * o )
 {
+	TRACE_ENTRY("%p %p", list, o);
+	
 	list->next = list;
 	list->prev = list;
 	list->o = o;
@@ -261,6 +263,8 @@
 	_dict_list_t * li = sentinel;
 	int cmp;
 	
+	TRACE_ENTRY("%p %p %p %p", obj_l, sentinel, cmp_fct, ref_duplicate);
+	
 	/* Some debug sanity checks */
 	assert(obj_l->o != NULL);
 	assert(obj_l->next == obj_l);
@@ -297,6 +301,8 @@
 /* Remove an object from a list. The write-lock must already have been acquired */
 static void remove_from_list ( _dict_list_t * obj_l )
 {
+	TRACE_ENTRY("%p", obj_l);
+	
 	/* Some debug sanity checks */
 	assert(obj_l->o != NULL);
 	assert(obj_l->next != obj_l);
@@ -317,6 +323,8 @@
 {
 	_dict_list_t * li;
 	
+	TRACE_ENTRY("%p", sentinel);
+	
 	/* Some debug sanity checks */
 	assert(sentinel->o == NULL);
 	
@@ -345,6 +353,9 @@
 static void init_object( _dict_object_t * obj, dict_object_type_t type )
 {
 	int i;
+	
+	TRACE_ENTRY("%p %d", obj, type);
+	
 	/* Clean the object first */
 	memset ( obj, 0, sizeof(_dict_object_t));
 	
@@ -382,6 +393,8 @@
 {
 	int ret = 0;
 
+	TRACE_ENTRY("%p %p %d", dest, source, type);
+	
 	/* Generic: copy the full data structure */	
 	memcpy( dest, source, dict_obj_info[type].datasize );
 	
@@ -402,7 +415,6 @@
 			
 		case DICT_TYPE_ENUM:
 			DUP_string( ((dict_type_enum_data_t *)dest)->enum_name );
-			/* Do we have to copy the value in case of octetstring constants? ... */
 			break;
 
 		case DICT_AVP:
@@ -423,16 +435,19 @@
 {
 	int ret = 0;
 	
+	TRACE_ENTRY("%p", obj);
+	
 	if (  (!obj) 
 	   || (obj->objeyec != OBJECT_EYECATCHER)
 	   || (!CHECK_TYPE(obj->type))
 	   || (obj->typeyec != dict_obj_info[obj->type].eyecatcher)
 	   ) {
 		if (obj) {
-			TRACE_DEBUG(FULL, "obj->objeyec : %x - %x\n", obj->objeyec, OBJECT_EYECATCHER);
-			TRACE_DEBUG(FULL, "obj->type    : %d\n", obj->type);
-			TRACE_DEBUG(FULL, "obj->objeyec : %x - %x\n", obj->objeyec, OBJECT_EYECATCHER);
-			TRACE_DEBUG(FULL, "obj->typeyec : %x - %x\n", obj->typeyec, _OBINFO(obj).eyecatcher);
+			TRACE_DEBUG(INFO, "Invalid object : %p\n", obj);
+			TRACE_DEBUG(INFO, "obj->objeyec : %x - %x\n", obj->objeyec, OBJECT_EYECATCHER);
+			TRACE_DEBUG(INFO, "obj->type    : %d\n", obj->type);
+			TRACE_DEBUG(INFO, "obj->objeyec : %x - %x\n", obj->objeyec, OBJECT_EYECATCHER);
+			TRACE_DEBUG(INFO, "obj->typeyec : %x - %x\n", obj->typeyec, _OBINFO(obj).eyecatcher);
 		}
 		return EINVAL;
 	}
@@ -444,6 +459,8 @@
 /* Free the data associated to an object */
 static void destroy_object_data(_dict_object_t * obj)
 {
+	TRACE_ENTRY("%p", obj);
+	
 	switch (obj->type) {
 		case DICT_VENDOR:
 			free( obj->data.vendor.vendor_name );
@@ -459,7 +476,6 @@
 			
 		case DICT_TYPE_ENUM:
 			free( obj->data.type_enum.enum_name );
-			/* Do we have to free the value in case of octetstring constants? ... */
 			break;
 
 		case DICT_AVP:
@@ -477,6 +493,8 @@
 {
 	int i;
 	
+	TRACE_ENTRY("%p", obj);
+	
 	/* Update global count */
 	_OBINFO(obj).count--;
 	
@@ -518,24 +536,32 @@
 /* Compare two vendor objects by their id (checks already performed) */
 static int order_vendor_by_id ( _dict_object_t *o1, _dict_object_t *o2 )
 {
+	TRACE_ENTRY("%p %p", o1, o2);
+	
 	return order_scalar( o1->data.vendor.vendor_id, o2->data.vendor.vendor_id );
 }
 
 /* Compare two application objects by their id (checks already performed) */
 static int order_appli_by_id  ( _dict_object_t *o1, _dict_object_t *o2 )
 {
+	TRACE_ENTRY("%p %p", o1, o2);
+	
 	return order_scalar( o1->data.application.application_id, o2->data.application.application_id );
 }
 
 /* Compare two type objects by their name (checks already performed) */
 static int order_type_by_name ( _dict_object_t *o1, _dict_object_t *o2 )
 {
+	TRACE_ENTRY("%p %p", o1, o2);
+	
 	return strcmp( o1->data.type.type_name, o2->data.type.type_name );
 }
 
 /* Compare two type_enum objects by their names (checks already performed) */
 static int order_enum_by_name ( _dict_object_t *o1, _dict_object_t *o2 )
 {
+	TRACE_ENTRY("%p %p", o1, o2);
+	
 	return strcmp( o1->data.type_enum.enum_name, o2->data.type_enum.enum_name );
 }
 
@@ -545,6 +571,8 @@
 	size_t oslen;
 	int cmp = 0;
 	
+	TRACE_ENTRY("%p %p", o1, o2);
+	
 	/* The comparison function depends on the type of data */
 	switch ( o1->parent->data.type.type_base ) {
 		case AVP_TYPE_OCTETSTRING:
@@ -582,18 +610,24 @@
 /* Compare two avp objects by their codes (checks already performed) */
 static int order_avp_by_code  ( _dict_object_t *o1, _dict_object_t *o2 )
 {
+	TRACE_ENTRY("%p %p", o1, o2);
+	
 	return order_scalar( o1->data.avp.avp_code, o2->data.avp.avp_code );
 }
 
 /* Compare two avp objects by their names (checks already performed) */
 static int order_avp_by_name  ( _dict_object_t *o1, _dict_object_t *o2 )
 {
+	TRACE_ENTRY("%p %p", o1, o2);
+	
 	return strcmp( o1->data.avp.avp_name, o2->data.avp.avp_name );
 }
 
 /* Compare two command objects by their names (checks already performed) */
 static int order_cmd_by_name  ( _dict_object_t *o1, _dict_object_t *o2 )
 {
+	TRACE_ENTRY("%p %p", o1, o2);
+	
 	return strcmp( o1->data.cmd.cmd_name, o2->data.cmd.cmd_name );
 }
 
@@ -601,7 +635,11 @@
 static int order_cmd_by_codefl( _dict_object_t *o1, _dict_object_t *o2 )
 {
 	uint8_t fl1, fl2;
-	int ret = order_scalar( o1->data.cmd.cmd_code, o2->data.cmd.cmd_code );
+	int ret = 0;
+	
+	TRACE_ENTRY("%p %p", o1, o2);
+	
+	ret = order_scalar( o1->data.cmd.cmd_code, o2->data.cmd.cmd_code );
 	if (ret) 
 		return ret;
 	/* Same code, must compare the value of the 'R' flag */
@@ -616,6 +654,8 @@
 /* Compare two rule object by the AVP name that they refer (checks already performed) */
 static int order_rule_by_avpn ( _dict_object_t *o1, _dict_object_t *o2 )
 {
+	TRACE_ENTRY("%p %p", o1, o2);
+	
 	return strcmp( _O(o1->data.rule.rule_avp)->data.avp.avp_name, _O(o2->data.rule.rule_avp)->data.avp.avp_name );
 }
 
@@ -769,6 +809,8 @@
 	int ret = 0;
 	vendor_id_t id;
 	
+	TRACE_ENTRY("%d %p %p", criteria, what, result);
+	
 	switch (criteria) {
 		case VENDOR_BY_ID_REF:
 		case VENDOR_BY_ID_VAL:
@@ -806,6 +848,8 @@
 	int ret = 0;
 	application_id_t id;
 	
+	TRACE_ENTRY("%d %p %p", criteria, what, result);
+	
 	switch (criteria) {
 		case APPLICATION_BY_ID_REF:
 		case APPLICATION_BY_ID_VAL:
@@ -847,6 +891,8 @@
 {
 	int ret = 0;
 	
+	TRACE_ENTRY("%d %p %p", criteria, what, result);
+	
 	switch (criteria) {
 		case TYPE_BY_NAME:
 			/* "what" is a type name */
@@ -877,6 +923,8 @@
 {
 	int ret = 0;
 	
+	TRACE_ENTRY("%d %p %p", criteria, what, result);
+	
 	switch (criteria) {
 		case ENUM_BY_STRUCT:
 			{
@@ -995,6 +1043,8 @@
 {
 	int ret = 0;
 	
+	TRACE_ENTRY("%d %p %p", criteria, what, result);
+	
 	switch (criteria) {
 		case AVP_BY_CODE_REF:
 		case AVP_BY_CODE_VAL:
@@ -1059,6 +1109,8 @@
 {
 	int ret = 0;
 	
+	TRACE_ENTRY("%d %p %p", criteria, what, result);
+	
 	switch (criteria) {
 		case CMD_BY_NAME:
 			/* "what" is a command name */
@@ -1142,6 +1194,8 @@
 {
 	int ret = 0;
 	
+	TRACE_ENTRY("%d %p %p", criteria, what, result);
+	
 	switch (criteria) {
 		case RULE_BY_AVP_AND_PARENT:
 			{
@@ -1401,8 +1455,10 @@
 /* Get the type of an object */
 int dict_gettype ( dict_object_t * object, dict_object_type_t * type)
 {
+	TRACE_ENTRY("%p %p", object, type);
+	
 	if (!type || verify_object(_O(object))) {
-		TRACE_DEBUG (FULL, "EINVAL." );
+		TRACE_DEBUG (INFO, "EINVAL." );
 		return EINVAL;
 	}
 	
@@ -1414,8 +1470,10 @@
 /* Get the data associated to an object */
 int dict_getval ( dict_object_t * object, void * val)
 {
+	TRACE_ENTRY("%p %p", object, val);
+	
 	if (!val || verify_object(_O(object))) {
-		TRACE_DEBUG (FULL, "EINVAL." );
+		TRACE_DEBUG (INFO, "EINVAL." );
 		return EINVAL;
 	}
 	
@@ -1431,12 +1489,12 @@
 	_dict_object_t * new = NULL;
 	_dict_object_t * vendor = NULL;
 	
-	TRACE_DEBUG (FULL, "dict_new (%s, %p, %p, %p).", dict_obj_info[CHECK_TYPE(type) ? type : 0].name, data, parent, ref );
+	TRACE_ENTRY("%d(%s) %p %p %p", type, dict_obj_info[CHECK_TYPE(type) ? type : 0].name, data, parent, ref);
 	
 	/* Check parameters */
 	if (   !CHECK_TYPE(type) 
 	    || !data) {
-		TRACE_DEBUG (FULL, "EINVAL." );
+		TRACE_DEBUG (INFO, "EINVAL." );
 		return EINVAL;
 	}
 	
@@ -1444,7 +1502,7 @@
 	switch (dict_obj_info[type].parent) {
 		case 0:	/* parent is forbidden */
 			if (parent != NULL) {
-				TRACE_DEBUG (FULL, "Parent is forbidden, EINVAL." );
+				TRACE_DEBUG (INFO, "Parent is forbidden, EINVAL." );
 				return EINVAL;
 			}
 		
@@ -1454,7 +1512,7 @@
 		
 		case 2: /* parent is mandatory */
 			if (verify_object(parent)) {
-				TRACE_DEBUG (FULL, "Parent is invalid, EINVAL." );
+				TRACE_DEBUG (INFO, "Parent is invalid, EINVAL." );
 				return EINVAL;
 			}
 			
@@ -1468,7 +1526,7 @@
 					ret = EINVAL;
 			}
 			if (ret != 0) {
-				TRACE_DEBUG (FULL, "Parent is wrong type, EINVAL." );
+				TRACE_DEBUG (INFO, "Parent is wrong type, EINVAL." );
 				return EINVAL;
 			}
 	}
@@ -1630,9 +1688,11 @@
 {
 	int ret = 0;
 	
+	TRACE_ENTRY("%d(%s) %d %p %p", type, dict_obj_info[CHECK_TYPE(type) ? type : 0].name, criteria, what, result);
+	
 	/* Check param */
 	if (!CHECK_TYPE(type)) {
-		TRACE_DEBUG (FULL, "EINVAL." );
+		TRACE_DEBUG (INFO, "EINVAL." );
 		return EINVAL;
 	}
 	
@@ -1668,6 +1728,8 @@
 {
 	int ret = 0;
 	
+	TRACE_ENTRY("");
+	
 	/* Sanity checks */
 	assert( (sizeof(type_base_name) / sizeof(type_base_name[0])) == (AVP_TYPE_MAX + 1) );
 	assert( (sizeof(dict_obj_info)  / sizeof(dict_obj_info[0]))  == (DICT_TYPE_MAX + 1) );
@@ -1714,7 +1776,6 @@
 	}
 		
 	/* Done */
-	TRACE_DEBUG (INFO, "Dictionary module initialized");
 	return 0;
 }
 
@@ -1723,7 +1784,7 @@
 {
 	int ret = 0, i;
 	
-	TRACE_DEBUG (FULL, "Unloading dictionary...");
+	TRACE_ENTRY("");
 	
 	/* Acquire the write lock to make sure no other operation is ongoing */
 	ret = pthread_rwlock_wrlock(&dict_lock);
@@ -1764,14 +1825,16 @@
 	int ret = 0;
 	_dict_list_t * li;
 	
+	TRACE_ENTRY("%p %p %p", parent, data, cb);
+	
 	/* Check parameters */
 	if (!parent || verify_object(_O(parent))) {
-		TRACE_DEBUG (FULL, "invalid parent object EINVAL." );
+		TRACE_DEBUG (INFO, "invalid parent object EINVAL." );
 		return EINVAL;
 	}
 	if (  (_O(parent)->type != DICT_COMMAND) 
 	   && ((_O(parent)->type != DICT_AVP) || (_O(parent)->data.avp.avp_basetype != AVP_TYPE_GROUPED) ) ) {
-		TRACE_DEBUG (FULL, "wrong parent EINVAL." );
+		TRACE_DEBUG (INFO, "wrong parent EINVAL." );
 		return EINVAL;
 	}
 	TRACE_DEBUG (FULL, "Iterating on rules of %s: '%s'.", 
--- a/waaad/dispatch.c	Tue Jul 15 13:56:30 2008 +0900
+++ b/waaad/dispatch.c	Tue Jul 15 16:55:41 2008 +0900
@@ -45,30 +45,36 @@
 /* Initialize the module */
 int disp_init ( void )
 {
-	TRACE_DEBUG (INFO, "Dispatch module initialized");
-	TRACE_DEBUG (FULL, "@@@ Not implemented yet." );
+	TRACE_ENTRY("");
+	
+	TRACE_DEBUG (INFO, "@@@ Not implemented yet." );
 	return 0;
 }
 
 /* End of the module */
 int disp_fini ( void )
 {
-	TRACE_DEBUG (FULL, "Unloading dispatch module...");
-	TRACE_DEBUG (FULL, "@@@ Not implemented yet." );
+	TRACE_ENTRY("");
+	
+	TRACE_DEBUG (INFO, "@@@ Not implemented yet." );
 	return 0;
 }
 
 /* Register a new callback. */
 int disp_register ( disp_cb_t cb, disp_reg_t how, void * when, disp_cb_hdl_t ** handle )
 {
-	TRACE_DEBUG (FULL, "@@@ %s: not implemented yet.", __FUNCTION__ );
+	TRACE_ENTRY("%p %d %p %p", cb, how, when, handle);
+	
+	TRACE_DEBUG (INFO, "@@@ Not implemented yet." );
 	return ENOTSUP;
 }
 
 /* Remove a registered callback. */
 int disp_unregister ( disp_cb_hdl_t * handle )
 {
-	TRACE_DEBUG (FULL, "@@@ %s: not implemented yet.", __FUNCTION__ );
+	TRACE_ENTRY("%p", handle);
+	
+	TRACE_DEBUG (INFO, "@@@ Not implemented yet." );
 	return ENOTSUP;
 }
 
--- a/waaad/extensions.c	Tue Jul 15 13:56:30 2008 +0900
+++ b/waaad/extensions.c	Tue Jul 15 16:55:41 2008 +0900
@@ -70,6 +70,7 @@
 /* Initialize the API that is passed to extensions */
 static void api_init(void)
 {
+	TRACE_ENTRY("");
 	exported_api.version = WAAAD_API_VER;
 	API_INIT_LOG        ( exported_api.log        );
 	API_INIT_DICTIONARY ( exported_api.dictionary );
@@ -85,17 +86,18 @@
 /* Initialize the extensions module */
 int ext_init( void ) 
 {
+	TRACE_ENTRY("");
 	memset(&ext_head, 0, sizeof(ext_t));
 	ext_tail = &ext_head;
 	api_init();
-	TRACE_DEBUG (INFO, "Extension module initialized");
 	return 0;
 }
 	
 /* Add a new extension in the list, for loading later */
 int ext_register( char * filename, char * conffile )
 {
-	TRACE_DEBUG (FULL, "Adding %s", filename);
+	TRACE_ENTRY("%p(%s) %p(%s)", filename, filename?filename:"", conffile, conffile?conffile:"");
+	
 	/* Check the filename is valid */
 	if (filename == NULL) {
 		TRACE_DEBUG (INFO, "Empty extension filename");
@@ -134,7 +136,7 @@
 		
 	/* we are done */
 	ext_tail = ext_tail->next;
-	TRACE_DEBUG (INFO, "%s added.", filename);
+	TRACE_DEBUG (FULL, "%s added.", filename);
 	return 0;
 }
 
@@ -143,12 +145,12 @@
 {
 	int ret, (*waaad_ext_init)(waaad_api_t *, char *) = NULL;
 	
-	TRACE_DEBUG (FULL, "Loading extensions...");
+	TRACE_ENTRY("");
 	
 	/* Loop on all extensions, in FIFO order */
 	for (ext_tail = ext_head.next; ext_tail != NULL; ext_tail = ext_tail->next)
 	{
-		TRACE_DEBUG (INFO, "Loading %s", ext_tail->filename);
+		TRACE_DEBUG (FULL, "Loading %s", ext_tail->filename);
 		
 		/* Load the extension */
 		ext_tail->handler = dlopen(ext_tail->filename, RTLD_LAZY | RTLD_LOCAL);
@@ -156,7 +158,7 @@
 		if (ext_tail->handler == NULL) {
 			/* An error occured */
 			log_error("Loading of extension %s failed:\n %s\n", ext_tail->filename, dlerror());
-			TRACE_DEBUG (FULL, "Error occurred, message logged -- dlopen.");
+			TRACE_DEBUG (INFO, "Error occurred, message logged -- dlopen.");
 			return EINVAL;
 		}
 		
@@ -166,7 +168,7 @@
 		if (waaad_ext_init == NULL) {
 			/* An error occured */
 			log_error("Invalid extension %s:\n %s\n", ext_tail->filename, dlerror());
-			TRACE_DEBUG (FULL, "Error occurred, message logged -- dlsym.");
+			TRACE_DEBUG (INFO, "Error occurred, message logged -- dlsym.");
 			return EINVAL;
 		}
 		
@@ -187,7 +189,7 @@
 		if (ret != 0) {
 			/* The extension was unable to load cleanly */
 			log_error("Extension %s could not be initialized, aborting.\n", ext_tail->filename);
-			TRACE_DEBUG (FULL, "Error occurred, message logged -- waaad_ext_init.");
+			TRACE_DEBUG (INFO, "Error occurred, message logged -- waaad_ext_init.");
 			return ret;
 		}
 		
@@ -204,8 +206,8 @@
 {
 	int ret=0;
 	
-	TRACE_DEBUG (FULL, "Unloading extensions...");
-
+	TRACE_ENTRY("");
+	
 	/* Loop on all objects */
 	for (ext_tail = ext_head.next; ext_tail != NULL; ext_tail = ext_head.next)
 	{
--- a/waaad/log.h	Tue Jul 15 13:56:30 2008 +0900
+++ b/waaad/log.h	Tue Jul 15 16:55:41 2008 +0900
@@ -110,22 +110,25 @@
 /* The remaining of the file is dedicated to debug facility */
 
 /* levels definitions */
-#define NONE 0
-#define INFO 1
-#define FULL 2
+#define NONE 0	/* Display no debug message */
+#define INFO 1	/* Display errors only */
+#define FULL 2  /* Display lot of information to follow code execution */
 
 /* Default level is INFO */
 #ifndef TRACE_LEVEL 
 #define TRACE_LEVEL INFO
-#endif /* TRACE_##TRACE_MODULE##_LEVEL */
+#endif /* TRACE_LEVEL */
 
 /* The level of the module being compiled */
 static int debug_level = TRACE_LEVEL;
-/* We use an run-time variable to be able to change the level with a debugger on-the-fly */
+/* We use an run-time variable to be able to change the level on-the-fly with a debugger */
 
 /* Macro to log debug */
 #define TRACE_DEBUG(level,format,args... ) \
 	{ if ( level <= debug_level + g_conf->log_verbose ) \
 		log_debug("%-12s:%-4d( %-15s): " format "\n", __FILE__, __LINE__, __FUNCTION__, ## args); }
+		
+#define TRACE_ENTRY(_format,_args... ) \
+	TRACE_DEBUG(FULL, "Entering function (parms: " _format ")", ##_args )
 
 #endif /* _LOG_H_ */
--- a/waaad/main.c	Tue Jul 15 13:56:30 2008 +0900
+++ b/waaad/main.c	Tue Jul 15 16:55:41 2008 +0900
@@ -97,6 +97,8 @@
 		{ NULL,	0, NULL, 0 }
 	};
 	
+	TRACE_ENTRY("%d %p", argc, argv);
+	
 	/* Loop on arguments */
 	while (1) {
 		c = getopt_long (argc, argv, "hVc:dq", long_options, &option_index);
@@ -131,11 +133,11 @@
 
 			case '?':	/* Invalid option.  */
 				/* `getopt_long' already printed an error message.  */
-				TRACE_DEBUG(FULL, "getopt_long found an invalid character\n");
+				TRACE_DEBUG(INFO, "getopt_long found an invalid character\n");
 				return 1;
 
 			default:	/* bug: option not considered.  */
-				TRACE_DEBUG(FULL, "A command-line option is missing in parser: %c\n", c);
+				TRACE_DEBUG(INFO, "A command-line option is missing in parser: %c\n", c);
 				return 1;
 		}
 	}
@@ -245,7 +247,7 @@
 	
 	/* Terminate */
 end:
-	TRACE_DEBUG(INFO, "Entering 'end' section of main function.");
+	TRACE_DEBUG(FULL, "Entering 'end' section of main function.");
 	
 	(void)sec_fini();
 	
--- a/waaad/message.c	Tue Jul 15 13:56:30 2008 +0900
+++ b/waaad/message.c	Tue Jul 15 16:55:41 2008 +0900
@@ -215,6 +215,8 @@
 /* Initialize a _msg_list_t structure */
 static void init_list(_msg_list_t * list, _msg_avp_chain_t * top)
 {
+	TRACE_ENTRY("%p %p", list, top);
+	
 	list->next = list;
 	list->prev = list;
 	list->head = list;
@@ -224,6 +226,8 @@
 /* Initialize a _msg_avp_chain_t structure */
 static void init_chain(_msg_avp_chain_t * chain, int type)
 {
+	TRACE_ENTRY("%p %d", chain, type);
+	
 	init_list( &chain->chaining, chain);
 	init_list( &chain->children, chain);
 	chain->type = type;
@@ -232,6 +236,8 @@
 /* Initialize a new AVP object */
 static void init_avp ( _msg_avp_t * avp )
 {
+	TRACE_ENTRY("%p", avp);
+	
 	memset(avp, 0, sizeof(_msg_avp_t));
 	init_chain( &avp->avp_chain, _MSG_AVP);
 	avp->avp_eyec = _MSG_AVP_EYEC;
@@ -240,6 +246,8 @@
 /* Initialize a new MSG object */
 static void init_msg ( _msg_t * msg )
 {
+	TRACE_ENTRY("%p", msg);
+	
 	memset(msg, 0, sizeof(_msg_t));
 	init_chain( &msg->msg_chain, _MSG_MSG);
 	msg->msg_eyec = _MSG_MSG_EYEC;
@@ -248,15 +256,17 @@
 /* Destroy and free an AVP or message */
 static int destroy_obj (_msg_avp_chain_t * obj )
 {
+	TRACE_ENTRY("%p", obj);
+	
 	/* Check the parameter is a valid object */
 	if (!VALIDATE_OBJ(obj)) {
-		TRACE_DEBUG(FULL, "Received an invalid msg or avp. EINVAL");
+		TRACE_DEBUG(INFO, "Received an invalid msg or avp. EINVAL");
 		return EINVAL;
 	}
 
 	/* Only accept objects with no linked children */
 	if (!IS_LIST_EMPTY( &obj->children )) {
-		TRACE_DEBUG(FULL, "Received an AVP or command with children. EINVAL");
+		TRACE_DEBUG(INFO, "Received an AVP or command with children. EINVAL");
 		return EINVAL;
 	}
 	
@@ -285,6 +295,8 @@
 {
 	_msg_list_t *li;
 	
+	TRACE_ENTRY("%p %p", sentinel, item);
+	
 	/* In case the item has no "position", assign the optional placement. This should never happen actually. */
 	if (!item->pos)
 		item->pos = RULE_OPTIONAL;
@@ -323,6 +335,8 @@
 /* Unlink an item from a list */
 static void item_unlink(_msg_list_t * item)
 {
+	TRACE_ENTRY("%p", item);
+	
 	/* Check first that this item is linked and not a sentinel */
 	if (item->head == item)
 		return;
@@ -343,6 +357,8 @@
 {
 	_msg_list_t *sub;
 	
+	TRACE_ENTRY("%p", obj);
+	
 	/* Destroy any subtree */
 	while ( (sub = obj->children.next) != &obj->children)
 		destroy_tree(sub->top);
@@ -366,7 +382,7 @@
 	int ret = 0, i;
 	cb_data_t *_data = (cb_data_t *)data;
 
-	TRACE_DEBUG(FULL, "enter (%p, %p)", _data, rule);
+	TRACE_ENTRY("%p %p", data, rule);
 	
 	/* Create as many children as the template says */
 	for (i=0; i<rule->rule_template; i++) {
@@ -375,7 +391,7 @@
 		/* Create the child AVP -- eventually a tree of AVPs */
 		ret = msg_avp_new(rule->rule_avp, _data->flags, &child);
 		if (ret != 0) {
-			TRACE_DEBUG(FULL, "Creation of child AVP failed: %d (%s)", ret, strerror(ret));
+			TRACE_DEBUG(INFO, "Creation of child AVP failed: %d (%s)", ret, strerror(ret));
 			return ret;
 		}
 
@@ -655,6 +671,8 @@
 /* Write a message header in the buffer */
 static int _msg_buf_msg(unsigned char * buffer, size_t buflen, size_t * offset, _msg_t * msg)
 {
+	TRACE_ENTRY("%p %d %p %p", buffer, buflen, offset, msg);
+	
 	if ((buflen - *offset) < GETMSGHDRSZ())
 		return ENOSPC;
 	
@@ -689,6 +707,8 @@
 	dict_avp_data_t dictdata;
 	int ret = 0;
 	
+	TRACE_ENTRY("%p %d %p %p", buffer, buflen, offset, avp);
+	
 	if ((buflen - *offset) < avp->avp_public.avp_len)
 		return ENOSPC;
 	
@@ -762,6 +782,9 @@
 {
 	int ret = 0;
 	_msg_list_t * avpch;
+	
+	TRACE_ENTRY("%p %d %p %p", buffer, buflen, offset, list);
+	
 	for (avpch = list->next; avpch != list; avpch = avpch->next) {
 		/* Re-align the offset if needed */
 		*offset = PAD4(*offset);
@@ -769,7 +792,7 @@
 		/* Bufferize the AVP */
 		ret = _msg_buf_avp(buffer, buflen, offset, _A(avpch->top));
 		if (ret != 0) {
-			TRACE_DEBUG(INFO, "_msg_buf_avp returned: %s", strerror(ret));
+			TRACE_DEBUG(INFO, "_msg_buf_avp failed: %s", strerror(ret));
 			return ret;
 		}
 	}
@@ -786,6 +809,8 @@
 {
 	size_t offset = 0;
 	
+	TRACE_ENTRY("%p %d %p", buf, buflen, list);
+	
 	while (offset < buflen) {
 		_msg_avp_t * avp;
 		
@@ -798,7 +823,7 @@
 		avp = (_msg_avp_t *) malloc (sizeof(_msg_avp_t));
 		if (!avp) {
 			log_error("Unable to allocate enough memory: %s\n", strerror(errno));
-			TRACE_DEBUG (FULL, "malloc failed.");
+			TRACE_DEBUG (INFO, "malloc failed.");
 			return ENOMEM;
 		}
 		
@@ -866,15 +891,17 @@
 	int ret = 0;
 	dict_avp_data_t dictdata;
 	
+	TRACE_ENTRY("%p %d %d", avp, recheck, mandatory);
+	
 	/* First check we received an AVP as input */
 	if (!CHECK_AVP(avp)) {
-		TRACE_DEBUG(FULL, "The parameter is not an AVP");
+		TRACE_DEBUG(INFO, "The parameter is not an AVP");
 		return EINVAL;
 	}
 	
 	if (avp->avp_model != NULL) {
 		if (recheck == 0) {
-			TRACE_DEBUG(FULL, "The AVP model is already set.");
+			TRACE_DEBUG(INFO, "The AVP model is already set.");
 			return EINVAL;
 		} else {
 			/* the model has already been resolved. we do check it is still valid */
@@ -910,28 +937,28 @@
 	if (ret == ENOENT) {
 		
 		if (mandatory && (avp->avp_public.avp_flags & AVP_FLAG_MANDATORY)) {
-			TRACE_DEBUG(FULL, "Unsupported mandatory AVP found.");
+			TRACE_DEBUG(INFO, "Unsupported mandatory AVP found.");
 			return ENOTSUP;
 		}
 		
 		if (recheck) {
 			/* In this case, the data is supposed to be in the raw internal buffer */
 			if (avp->avp_rawdata == NULL) {
-				TRACE_DEBUG(FULL, "Invalid buffer state in the AVP object.");
+				TRACE_DEBUG(INFO, "Invalid buffer state in the AVP object.");
 				return EINVAL;
 			}
 			TRACE_DEBUG(FULL, "Unsupported optional AVP found, source data already in avp_rawdata.");
 		} else {
 			/* we must copy the data from the source to the internal buffer area */
 			if ((avp->avp_source == NULL) || (avp->avp_rawdata != NULL)) {
-				TRACE_DEBUG(FULL, "Invalid buffers states in the AVP object.");
+				TRACE_DEBUG(INFO, "Invalid buffers states in the AVP object.");
 				return EINVAL;
 			}
 			
 			avp->avp_rawdata = malloc(avp->avp_public.avp_len - GETAVPHDRSZ( avp->avp_public.avp_flags ));
 			if (!avp->avp_rawdata) {
 				log_error("Memory allocation failed. %s", strerror(errno));
-				TRACE_DEBUG(FULL, "Malloc failed.");
+				TRACE_DEBUG(INFO, "Malloc failed.");
 				return ENOMEM;
 			}
 			
@@ -946,7 +973,7 @@
 	
 	/* Handle other errors */
 	if (ret != 0) {
-		TRACE_DEBUG(FULL, "Unexpected error in dict_search: %s", strerror(ret));
+		TRACE_DEBUG(INFO, "Unexpected error in dict_search: %s", strerror(ret));
 		return ret;
 	}
 	
@@ -989,7 +1016,7 @@
 			avp->avp_storage.os.data = malloc(avp->avp_storage.os.len);
 			if (!avp->avp_storage.os.data) {
 				log_error("Memory allocation failed. %s", strerror(errno));
-				TRACE_DEBUG(FULL, "Malloc failed.");
+				TRACE_DEBUG(INFO, "Malloc failed.");
 				return ENOMEM;
 			}
 			avp->avp_mustfreeos = 1;
@@ -1033,6 +1060,8 @@
 	int ret;
 	_msg_list_t * avpch;
 	
+	TRACE_ENTRY("%p %d %d", head, recheck, mandatory);
+	
 	/* Sanity check */
 	assert ( head == head->head );
 	
@@ -1040,7 +1069,7 @@
 	for (avpch=head->next; avpch != head; avpch = avpch->next) {
 		ret = _mpd_do_avp(_A(avpch->top), recheck, mandatory);
 		if (ret != 0) {
-			TRACE_DEBUG(FULL, "_mpd for child %p failed: %s", avpch->top, strerror(ret));
+			TRACE_DEBUG(INFO, "_mpd for child %p failed: %s", avpch->top, strerror(ret));
 			return ret;
 		}
 	}
@@ -1054,8 +1083,10 @@
 {
 	int ret = 0;
 	
+	TRACE_ENTRY("%p %d", msg, recheck);
+	
 	if (! CHECK_MSG(msg) ) {
-		TRACE_DEBUG (FULL, "Invalid message received.");
+		TRACE_DEBUG (INFO, "Invalid message received.");
 		return EINVAL;
 	}
 	
@@ -1063,7 +1094,7 @@
 		msg->msg_model = NULL;
 	
 	if ( msg->msg_model != NULL) {
-		TRACE_DEBUG (FULL, "MSG already parsed, we do not process again.");
+		TRACE_DEBUG (INFO, "MSG already parsed, we do not process again.");
 		return EINVAL;
 	}
 	
@@ -1073,7 +1104,7 @@
 			&msg->msg_public.msg_code,
 			&msg->msg_model);
 	if (ret != 0) {
-		TRACE_DEBUG (FULL, "Looking for command object in the dictionary failed: %s.", strerror(ret));
+		TRACE_DEBUG (INFO, "Looking for command object in the dictionary failed: %s.", strerror(ret));
 		if (ret == ENOENT)
 			ret = ENOTSUP;
 		return ret;
@@ -1087,8 +1118,10 @@
 {
 	int ret = 0;
 	
+	TRACE_ENTRY("%p %d", obj, recheck);
+	
 	if (!VALIDATE_OBJ(obj)) {
-		TRACE_DEBUG(FULL, "Received an invalid object. EINVAL");
+		TRACE_DEBUG(INFO, "Received an invalid object. EINVAL");
 		return EINVAL;
 	}
 	
@@ -1122,6 +1155,8 @@
 	_msg_list_t * li;
 	int curpos = 0; /* The current position in the list */
 	
+	TRACE_ENTRY("%p %p %p %p %p", model_avp, list, count, firstpos, lastpos);
+	
 	*count = 0;	/* number of instances found */
 	*firstpos = 0;	/* position of the first instance */
 	*lastpos = 0;	/* position of the last instance, starting from the end */
@@ -1156,8 +1191,11 @@
 	int ret = 0, count, first, last, min;
 	_mpr_t * _data = (_mpr_t *) data;
 	
+	TRACE_ENTRY("%p %p", data, rule);
+	
 	/* Get statistics of the AVP concerned by this rule in the message instance */
 	_mpr_stat_avps( rule->rule_avp, _data->sentinel, &count, &first, &last);
+	
 	{
 		dict_avp_data_t avpdata;
 		ret = dict_getval(rule->rule_avp, &avpdata);
@@ -1186,14 +1224,14 @@
 			min = 1;
 	}
 	if (count < min) {
-		TRACE_DEBUG(FULL, "Conflicting rule: the number of occurences (%d) is < the rule min (%d).", count, min);
+		TRACE_DEBUG(INFO, "Conflicting rule: the number of occurences (%d) is < the rule min (%d).", count, min);
 		ret = EBADMSG;
 		goto end;
 	}
 	
 	/* Check the "max" value */
 	if ((rule->rule_max != -1) && (count > rule->rule_max)) {
-		TRACE_DEBUG(FULL, "Conflicting rule: the number of occurences (%d) is > the rule max (%d).", count, rule->rule_max);
+		TRACE_DEBUG(INFO, "Conflicting rule: the number of occurences (%d) is > the rule max (%d).", count, rule->rule_max);
 		ret = EBADMSG;
 		goto end;
 	}
@@ -1208,7 +1246,7 @@
 		case RULE_FIXED_HEAD:
 			/* Since "0*1<fixed>" is a valid rule specifier, we only reject cases where the AVP appears *after* its fixed position */
 			if (first > rule->rule_order) {
-				TRACE_DEBUG(FULL, "Conflicting rule: the FIXED_HEAD AVP appears first in (%d) position, the rule requires (%d).", first, rule->rule_order);
+				TRACE_DEBUG(INFO, "Conflicting rule: the FIXED_HEAD AVP appears first in (%d) position, the rule requires (%d).", first, rule->rule_order);
 				ret = EBADMSG;
 				goto end;
 			}
@@ -1217,7 +1255,7 @@
 		case RULE_FIXED_TAIL:
 			/* Since "0*1<fixed>" is a valid rule specifier, we only reject cases where the AVP appears *before* its fixed position */
 			if (last > rule->rule_order) {	/* We have a ">" here because we count in reverse order (i.e. from the end) */
-				TRACE_DEBUG(FULL, "Conflicting rule: the FIXED_TAIL AVP appears last in (%d) position, the rule requires (%d).", last, rule->rule_order);
+				TRACE_DEBUG(INFO, "Conflicting rule: the FIXED_TAIL AVP appears last in (%d) position, the rule requires (%d).", last, rule->rule_order);
 				ret = EBADMSG;
 				goto end;
 			}
@@ -1245,13 +1283,15 @@
 	_mpr_t data;
 	dict_object_t * model;
 	
+	TRACE_ENTRY("%p %p %d", object, rule, mandatory);
+	
 	/* object has already been checked and dict-parsed when we are called. */
 	
 	/* First, handle the cases where there is no model */
 	{
 		/* Commands MUST be supported in the dictionary */
 		if (CHECK_MSG(object) && ((model = _M(object)->msg_model) == NULL)) {
-			TRACE_DEBUG(FULL, "Message with no dictionary model. EINVAL");
+			TRACE_DEBUG(INFO, "Message with no dictionary model. EINVAL");
 			return EINVAL;
 		}
 
@@ -1259,7 +1299,7 @@
 		if (CHECK_AVP(object) && ((model = _A(object)->avp_model) == NULL)) {
 			if ( mandatory && (_A(object)->avp_public.avp_flags & AVP_FLAG_MANDATORY)) {
 				/* Return an error in this case */
-				TRACE_DEBUG(FULL, "Mandatory AVP with no dictionary model. EBADMSG");
+				TRACE_DEBUG(INFO, "Mandatory AVP with no dictionary model. EBADMSG");
 				return EBADMSG;
 			} else {
 				/* We don't know any rule for this object, so assume OK */
@@ -1295,7 +1335,7 @@
 		for (ch = _C(object)->children.next; ch != &_C(object)->children; ch = ch->next) {
 			ret = _mpr_do ( ch->top, rule, is_child_mand );
 			if (ret != 0) {
-				TRACE_DEBUG(FULL, "_msg_parse_rules failed in child %p", ch->top);
+				TRACE_DEBUG(INFO, "_msg_parse_rules failed in child %p", ch->top);
 				return ret;
 			}
 		}
@@ -1317,7 +1357,7 @@
 		if (_ret == 0) {
 			*rule = conflictrule;
 		} else {
-			TRACE_DEBUG(FULL, "dict_search failed to find the rule: %s", strerror(_ret));
+			TRACE_DEBUG(INFO, "dict_search failed to find the rule: %s", strerror(_ret));
 		}
 	}
 	
@@ -1363,22 +1403,26 @@
 /* Initialize the module */
 int msg_init ( void )
 {
+	TRACE_ENTRY("");
+	
 	/* There are no globals to initialize in this module... */
-	TRACE_DEBUG (INFO, "Message module initialized");
 	return 0;
 }
 
 /* End of the module */
 int msg_fini ( void )
 {
+	TRACE_ENTRY("");
+	
 	/* Nothing to do here */
-	TRACE_DEBUG (FULL, "Unloading message module...");
 	return 0;
 }
 
 /* Resolve dictionary objects of message instances. See _mpd_* functions in this file. */
 int msg_parse_dict ( msg_t * msg )
 {
+	TRACE_ENTRY("%p", msg);
+	
 	return _mpd_do(_C(msg), 0);
 }
 
@@ -1395,23 +1439,23 @@
 	dict_object_type_t dicttype;
 	dict_cmd_data_t    dictdata;
 	
-	TRACE_DEBUG (FULL, "Creating a message instance (%p, %x, %p)", model, flags, msg );
+	TRACE_ENTRY("%p %x %p", model, flags, msg);
 	
 	/* Check the parameters */
 	if ((!model) || (!msg) || (!CHECK_MSGFL(flags))) {
-		TRACE_DEBUG (FULL, "EINVAL." );
+		TRACE_DEBUG (INFO, "EINVAL." );
 		return EINVAL;
 	}
 	
 	ret = dict_gettype(model, &dicttype);
 	if (ret || (dicttype != DICT_COMMAND)) {
-		TRACE_DEBUG (FULL, "(%d, %d) -> EINVAL.", ret, dicttype );
+		TRACE_DEBUG (INFO, "(%d, %d) -> EINVAL.", ret, dicttype );
 		return EINVAL;
 	}
 	
 	ret = dict_getval(model, &dictdata);
 	if (ret != 0) {
-		TRACE_DEBUG (FULL, "Error occurred in dict_getval: %d (%s).", ret, strerror(ret) );
+		TRACE_DEBUG (INFO, "Error occurred in dict_getval: %d (%s).", ret, strerror(ret) );
 		return ret;
 	}
 	
@@ -1419,7 +1463,7 @@
 	new = (_msg_t *) malloc (sizeof(_msg_t));
 	if (!new) {
 		log_error("Unable to allocate enough memory: %s\n", strerror(errno));
-		TRACE_DEBUG (FULL, "malloc failed.");
+		TRACE_DEBUG (INFO, "malloc failed.");
 		return ENOMEM;
 	}
 	
@@ -1437,7 +1481,7 @@
 		cb_data_t data = { _C(new), flags};
 		ret = dict_iterate_rules ( model, &data, create_child_avp );
 		if (ret != 0) {
-			TRACE_DEBUG (FULL, "dict_iterate_rules failed (%s).", strerror(ret) );
+			TRACE_DEBUG (INFO, "dict_iterate_rules failed (%s).", strerror(ret) );
 			destroy_tree(_C(new));
 			return ret;
 		}
@@ -1456,23 +1500,23 @@
 	dict_object_type_t dicttype;
 	dict_avp_data_t    dictavpdata;
 	
-	TRACE_DEBUG (FULL, "Creating an AVP instance (%p, %x, %p)", model, flags, avp );
+	TRACE_ENTRY("%p %x %p", model, flags, avp);
 	
 	/* Check the parameters */
 	if ((!model) || (!avp) || (!CHECK_MSGFL(flags))) {
-		TRACE_DEBUG (FULL, "EINVAL." );
+		TRACE_DEBUG (INFO, "EINVAL." );
 		return EINVAL;
 	}
 	
 	ret = dict_gettype(model, &dicttype);
 	if (ret || (dicttype != DICT_AVP)) {
-		TRACE_DEBUG (FULL, "(%d, %d) -> EINVAL.", ret, dicttype );
+		TRACE_DEBUG (INFO, "(%d, %d) -> EINVAL.", ret, dicttype );
 		return EINVAL;
 	}
 	
 	ret = dict_getval(model, &dictavpdata);
 	if (ret != 0) {
-		TRACE_DEBUG (FULL, "Error occurred in dict_getval: %d (%s).", ret, strerror(ret) );
+		TRACE_DEBUG (INFO, "Error occurred in dict_getval: %d (%s).", ret, strerror(ret) );
 		return ret;
 	}
 	
@@ -1480,7 +1524,7 @@
 	new = (_msg_avp_t *) malloc (sizeof(_msg_avp_t));
 	if (!new) {
 		log_error("Unable to allocate enough memory: %s\n", strerror(errno));
-		TRACE_DEBUG (FULL, "malloc failed.");
+		TRACE_DEBUG (INFO, "malloc failed.");
 		return ENOMEM;
 	}
 	
@@ -1498,7 +1542,7 @@
 		cb_data_t data = { _C(new), flags};
 		ret = dict_iterate_rules ( model, &data, create_child_avp );
 		if (ret != 0) {
-			TRACE_DEBUG (FULL, "dict_iterate_rules failed (%s).", strerror(ret) );
+			TRACE_DEBUG (INFO, "dict_iterate_rules failed (%s).", strerror(ret) );
 			destroy_tree(_C(new));
 			return ret;
 		}
@@ -1512,18 +1556,20 @@
 /* Add an AVP into a tree */
 int msg_avp_add ( void * reference, msg_dir_t dir, msg_avp_t *avp)
 {
+	TRACE_ENTRY("%p %d %p", reference, dir, avp);
+	
 	/* Check the parameters */
 	if (!VALIDATE_OBJ(reference)) {
-		TRACE_DEBUG(FULL, "Received an invalid msg or avp. EINVAL");
+		TRACE_DEBUG(INFO, "Received an invalid msg or avp. EINVAL");
 		return EINVAL;
 	}
 	if (!CHECK_AVP(avp)) {
-		TRACE_DEBUG(FULL, "Received an invalid avp. EINVAL");
+		TRACE_DEBUG(INFO, "Received an invalid avp. EINVAL");
 		return EINVAL;
 	}
 	/* Check the avp to add is not chained */
 	if (!IS_LIST_EMPTY(&_C(avp)->chaining)) {
-		TRACE_DEBUG(FULL, "Received an avp already chained. EINVAL");
+		TRACE_DEBUG(INFO, "Received an avp already chained. EINVAL");
 		return EINVAL;
 	}
 	
@@ -1532,7 +1578,7 @@
 		case MSG_BRW_NEXT:
 			/* Check the reference is an AVP -- we do not chain AVPs at same level as msgs. */
 			if (_C(reference)->type != _MSG_AVP) {
-				TRACE_DEBUG(FULL, "Received an invalid reference type. EINVAL");
+				TRACE_DEBUG(INFO, "Received an invalid reference type. EINVAL");
 				return EINVAL;
 			}
 			/* Insert the new avp after the reference */
@@ -1542,7 +1588,7 @@
 		case MSG_BRW_PREV:
 			/* Check the reference is an AVP */
 			if (_C(reference)->type != _MSG_AVP) {
-				TRACE_DEBUG(FULL, "Received an invalid reference type. EINVAL");
+				TRACE_DEBUG(INFO, "Received an invalid reference type. EINVAL");
 				return EINVAL;
 			}
 			/* Insert the new avp before the reference */
@@ -1561,7 +1607,7 @@
 
 		default:
 			/* Other directions are invalid */
-			TRACE_DEBUG(FULL, "Received an invalid direction. EINVAL");
+			TRACE_DEBUG(INFO, "Received an invalid direction. EINVAL");
 			return EINVAL;
 	}
 			
@@ -1571,6 +1617,8 @@
 /* Free an object and its tree */
 int msg_free ( void * object, int subtree )
 {
+	TRACE_ENTRY("%p %d", object, subtree);
+	
 	if (!subtree)
 		return destroy_obj ( _C(object) );
 	
@@ -1586,13 +1634,15 @@
 	int diff = 0;
 	_msg_list_t      *li = NULL;
 	
+	TRACE_ENTRY("%p %d %p %p", reference, dir, found, depth);
+	
 	/* Initialize the "found" result if any */
 	if (found)
 		*found = NULL;
 	
 	/* Check the parameters */
 	if (!VALIDATE_OBJ(reference)) {
-		TRACE_DEBUG(FULL, "Received an invalid reference object. EINVAL");
+		TRACE_DEBUG(INFO, "Received an invalid reference object. EINVAL");
 		return EINVAL;
 	}
 	
@@ -1616,7 +1666,7 @@
 		case MSG_BRW_NEXT:
 			/* Check the reference is an AVP */
 			if (_C(reference)->type != _MSG_AVP) {
-				TRACE_DEBUG(FULL, "Received an invalid reference type. EINVAL");
+				TRACE_DEBUG(INFO, "Received an invalid reference type. EINVAL");
 				return EINVAL;
 			}
 
@@ -1632,7 +1682,7 @@
 		case MSG_BRW_PREV:
 			/* Check the reference is an AVP */
 			if (_C(reference)->type != _MSG_AVP) {
-				TRACE_DEBUG(FULL, "Received an invalid reference type. EINVAL");
+				TRACE_DEBUG(INFO, "Received an invalid reference type. EINVAL");
 				return EINVAL;
 			}
 
@@ -1711,7 +1761,7 @@
 			
 		default:
 			/* Other directions are invalid */
-			TRACE_DEBUG(FULL, "Received an invalid direction. EINVAL");
+			TRACE_DEBUG(INFO, "Received an invalid direction. EINVAL");
 			return EINVAL;
 	}
 	
@@ -1729,9 +1779,11 @@
 /* Retrieve the model of an object */
 int msg_model ( void * reference, dict_object_t ** model )
 {
+	TRACE_ENTRY("%p %p", reference, model);
+	
 	/* Check the parameters */
 	if ((!model) || (!VALIDATE_OBJ(reference))) {
-		TRACE_DEBUG(FULL, "Received an invalid reference object. EINVAL");
+		TRACE_DEBUG(INFO, "Received an invalid reference object. EINVAL");
 		return EINVAL;
 	}
 	
@@ -1757,9 +1809,11 @@
 {
 	dict_base_type_t type = -1;
 	
+	TRACE_ENTRY("%p %p", avp, value);
+	
 	/* Check parameter */
 	if ((!CHECK_AVP(avp)) || (!_A(avp)->avp_model)) {
-		TRACE_DEBUG(FULL, "Received an invalid reference object. EINVAL");
+		TRACE_DEBUG(INFO, "Received an invalid reference object. EINVAL");
 		return EINVAL;
 	}
 	
@@ -1770,17 +1824,17 @@
 		int ret = 0;
 		ret = dict_gettype(_A(avp)->avp_model, &dicttype);
 		if (ret || (dicttype != DICT_AVP)) {
-			TRACE_DEBUG(FULL, "Received an invalid reference object. EINVAL");
+			TRACE_DEBUG(INFO, "Received an invalid reference object. EINVAL");
 			return EINVAL;
 		}
 		ret = dict_getval(_A(avp)->avp_model, &dictdata);
 		if (ret != 0) {
-			TRACE_DEBUG(FULL, "Error getting avp model data");
+			TRACE_DEBUG(INFO, "Error getting avp model data");
 			return ret;
 		}
 		type = dictdata.avp_basetype;
 		if (type == AVP_TYPE_GROUPED) {
-			TRACE_DEBUG(FULL, "Cannot set a value to a grouped AVP. EINVAL");
+			TRACE_DEBUG(INFO, "Cannot set a value to a grouped AVP. EINVAL");
 			return EINVAL;
 		}
 	}
@@ -1807,7 +1861,7 @@
 		_A(avp)->avp_storage.os.data = malloc(value->os.len);
 		if (!_A(avp)->avp_storage.os.data) {
 			log_error("Unable to allocate enough memory: %s\n", strerror(errno));
-			TRACE_DEBUG (FULL, "malloc failed.");
+			TRACE_DEBUG (INFO, "malloc failed.");
 			return ENOMEM;
 		}
 		_A(avp)->avp_mustfreeos = 1;
@@ -1823,8 +1877,10 @@
 /* Retrieve the address of the msg_public field of a message */
 int msg_data ( msg_t *msg, msg_data_t **pdata )
 {
+	TRACE_ENTRY("%p %p", msg, pdata);
+	
 	if ((!CHECK_MSG(msg)) || (!pdata)) {
-		TRACE_DEBUG(FULL, "Received an invalid reference object. EINVAL");
+		TRACE_DEBUG(INFO, "Received an invalid reference object. EINVAL");
 		return EINVAL;
 	}
 	*pdata = & _M(msg)->msg_public;
@@ -1834,8 +1890,10 @@
 /* Retrieve the address of the avp_public field of an avp */
 int msg_avp_data ( msg_avp_t *avp, msg_avp_data_t **pdata )
 {
+	TRACE_ENTRY("%p %p", avp, pdata);
+	
 	if ((!CHECK_AVP(avp)) || (!pdata)) {
-		TRACE_DEBUG(FULL, "Received an invalid reference object. EINVAL");
+		TRACE_DEBUG(INFO, "Received an invalid reference object. EINVAL");
 		return EINVAL;
 	}
 	*pdata = & _A(avp)->avp_public;
@@ -1845,8 +1903,10 @@
 /* Retrieve the raw data of an AVP for which the model was not resolved. */
 int msg_avp_getrawdata ( msg_avp_t *avp, unsigned char **data )
 {
+	TRACE_ENTRY("%p %p", avp, data);
+	
 	if ((!CHECK_AVP(avp)) || (!data)) {
-		TRACE_DEBUG(FULL, "Received an invalid reference object. EINVAL");
+		TRACE_DEBUG(INFO, "Received an invalid reference object. EINVAL");
 		return EINVAL;
 	}
 	*data = _A(avp)->avp_rawdata;
@@ -1865,18 +1925,20 @@
 		dict_avp_data_t avpdata;
 	} dictdata;
 	
+	TRACE_ENTRY("%p", object);
+	
 	/* Get the model of the object. This also validates the object */
 	ret = msg_model ( object, &model );
 	/* Check the object is valid */
 	if ((ret != 0) || (model == NULL)) {
-		TRACE_DEBUG(FULL, "Received an invalid object, or object without model. EINVAL");
+		TRACE_DEBUG(INFO, "Received an invalid object, or object without model. EINVAL");
 		return EINVAL;
 	}
 	
 	/* Get the information of the model */
 	ret = dict_getval(model, &dictdata);
 	if (ret != 0) {
-		TRACE_DEBUG(FULL, "Error in dict_getdata: %s", strerror(ret));
+		TRACE_DEBUG(INFO, "Error in dict_getdata: %s", strerror(ret));
 		return ret;
 	}
 	
@@ -1887,7 +1949,7 @@
 		
 		/* Now check that the data is set in the AVP */
 		if (_A(object)->avp_public.avp_data == NULL) {
-			TRACE_DEBUG(FULL, "The avp_data is not set.");
+			TRACE_DEBUG(INFO, "The avp_data is not set.");
 			return EINVAL;
 		}
 		
@@ -1926,7 +1988,7 @@
 		for (ch = _C(object)->children.next; ch != &_C(object)->children; ch = ch->next) {
 			ret = msg_update_length ( ch->top );
 			if (ret != 0) {
-				TRACE_DEBUG(FULL, "msg_update_length failed in child %p", ch->top);
+				TRACE_DEBUG(INFO, "msg_update_length failed in child %p", ch->top);
 				return ret;
 			}
 			
@@ -1949,10 +2011,12 @@
 {
 	int ret = 0;
 	
+	TRACE_ENTRY("%p %p", object, rule);
+	
 	/* Resolve the dictionary objects when missing. This also validates the object. */
 	ret = _mpd_do( _C(object), 1 );
 	if (ret != 0) {
-		TRACE_DEBUG(FULL, "msg_parse_dict failed.");
+		TRACE_DEBUG(INFO, "msg_parse_dict failed.");
 		return ret;
 	}
 	
@@ -1974,16 +2038,18 @@
 	unsigned char * buf = NULL;
 	size_t offset = 0;
 	
+	TRACE_ENTRY("%p %p %p", msg, buffer, is_routable);
+	
 	/* Check the parameters */
 	if ( (buffer == NULL) || (! CHECK_MSG(msg) ) ) {
-		TRACE_DEBUG(FULL, "Invalid parameter. EINVAL");
+		TRACE_DEBUG(INFO, "Invalid parameter. EINVAL");
 		return EINVAL;
 	}
 	
 	/* Update the length. This also checks that all AVP have their values set */
 	ret = msg_update_length(msg);
 	if (ret != 0) {
-		TRACE_DEBUG(FULL, "Error updating lengths: %s", strerror(ret));
+		TRACE_DEBUG(INFO, "Error updating lengths: %s", strerror(ret));
 		return ret;
 	}
 	
@@ -1991,14 +2057,14 @@
 	buf = malloc(_M(msg)->msg_public.msg_length);
 	if (!buf) {
 		log_error("Memory allocation failed: %s\n", strerror(errno));
-		TRACE_DEBUG(FULL, "malloc failed");
+		TRACE_DEBUG(INFO, "malloc failed");
 		return ENOMEM;
 	}
 	
 	/* Write the message header in the buffer */
 	ret = _msg_buf_msg(buf, _M(msg)->msg_public.msg_length, &offset, _M(msg));
 	if (ret != 0) {
-		TRACE_DEBUG(FULL, "Error bufferizing the header: %s", strerror(ret));
+		TRACE_DEBUG(INFO, "Error bufferizing the header: %s", strerror(ret));
 		free(buf);
 		return ret;
 	}
@@ -2006,7 +2072,7 @@
 	/* Write the list of AVPs */
 	ret = _msg_buf_chain(buf, _M(msg)->msg_public.msg_length, &offset, &_C(msg)->children);
 	if (ret != 0) {
-		TRACE_DEBUG(FULL, "Error bufferizing the header: %s", strerror(ret));
+		TRACE_DEBUG(INFO, "Error bufferizing the AVPs: %s", strerror(ret));
 		free(buf);
 		return ret;
 	}
@@ -2022,11 +2088,14 @@
 	return 0;
 }
 
+/* Create a message object from a buffer. Dictionary objects are not resolved, AVP contents are not interpreted */
 int msg_parse_buffer ( unsigned char * buffer, size_t buflen, msg_t ** msg )
 {
 	_msg_t * new = NULL;
 	int ret = 0;
 	
+	TRACE_ENTRY("%p %d %p", buffer, buflen, msg);
+	
 	if ((!buffer) || (!msg) || (buflen < GETMSGHDRSZ())) {
 		TRACE_DEBUG(INFO, "Invalid parameter (%p, %d, %p)", buffer, buflen, msg);
 		return EINVAL;
@@ -2044,7 +2113,7 @@
 	new = (_msg_t *) malloc (sizeof(_msg_t));
 	if (!new) {
 		log_error("Unable to allocate enough memory: %s\n", strerror(errno));
-		TRACE_DEBUG (FULL, "malloc failed.");
+		TRACE_DEBUG (INFO, "malloc failed.");
 		return ENOMEM;
 	}
 	
@@ -2074,9 +2143,3 @@
 	return 0;
 }
 
-
-
-
-
-
-
--- a/waaad/peer.c	Tue Jul 15 13:56:30 2008 +0900
+++ b/waaad/peer.c	Tue Jul 15 16:55:41 2008 +0900
@@ -113,44 +113,47 @@
 /* Initialize the module */
 int peer_init ( void )
 {
-	TRACE_DEBUG (INFO, "Peer module initialized");
-	TRACE_DEBUG (FULL, "@@@ Not implemented yet." );
+	TRACE_ENTRY( "" );
+	TRACE_DEBUG (INFO, "@@@ Not implemented yet." );
 	return 0;
 }
 
 /* End of the module */
 int peer_fini ( void )
 {
-	TRACE_DEBUG (FULL, "Unloading peer module...");
-	TRACE_DEBUG (FULL, "@@@ Not implemented yet." );
+	TRACE_ENTRY( "" );
+	TRACE_DEBUG (INFO, "@@@ Not implemented yet." );
 	return 0;
 }
 
 /* Add a new peer */
 int peer_add ( peer_add_t * data )
 {
-	TRACE_DEBUG (FULL, "Adding the peer '%s'...", data->peer_id);
-	TRACE_DEBUG (FULL, "@@@ Not implemented yet." );
+	TRACE_ENTRY( "%p", data );
+	TRACE_DEBUG (INFO, "@@@ Not implemented yet." );
 	return 0;
 }
 
 /* Allow the peers to start connexions */
 int peer_start ( void )
 {
-	TRACE_DEBUG (FULL, "@@@ %s: not implemented yet.", __FUNCTION__ );
+	TRACE_ENTRY( "" );
+	TRACE_DEBUG (INFO, "@@@ %s: not implemented yet.", __FUNCTION__ );
 	return ENOTSUP;
 }
 
 /* Get some information from a peer_t opaque object */
 int peer_get ( peer_t * peer, peer_info_t what, void **result )
 {
-	TRACE_DEBUG (FULL, "@@@ %s: not implemented yet.", __FUNCTION__ );
+	TRACE_ENTRY( "%p %d %p", peer, what, result );
+	TRACE_DEBUG (INFO, "@@@ %s: not implemented yet.", __FUNCTION__ );
 	return ENOTSUP;
 }
 
 /* Queue a message in the given peer */
 int peer_send ( peer_t * peer, msg_t * msg )
 {
-	TRACE_DEBUG (FULL, "@@@ %s: not implemented yet.", __FUNCTION__ );
+	TRACE_ENTRY( "%p %p", peer, msg );
+	TRACE_DEBUG (INFO, "@@@ %s: not implemented yet.", __FUNCTION__ );
 	return ENOTSUP;
 }
--- a/waaad/queues.c	Tue Jul 15 13:56:30 2008 +0900
+++ b/waaad/queues.c	Tue Jul 15 16:55:41 2008 +0900
@@ -39,82 +39,215 @@
  * See queues.h for more information.
  */
 
+#include <pthread.h>
 #include <errno.h>
+#include <string.h>
+#include <stdlib.h>
 
 #include "waaad-internal.h"
 
+/********************************************************************************************************/
+
+/* A list item */
+typedef struct _li_t_ {
+	struct _li_t_ 	* next;
+	struct _li_t_ 	* prev;
+	msg_t		* msg;
+} _li_t;
+
+#define LI_init( _li, _msg ) {	\
+	(_li)->next = (_li);	\
+	(_li)->prev = (_li);	\
+	(_li)->msg  = (_msg);	\
+}
+
+#define LI_isempty( _li ) ((_li)->next == (_li))
+	
+
+/* Internal representation of a queue */
+typedef struct {
+	int		eyec;	/* An eye catcher, also used to check a queue is valid. _MEQ_EYEC */
+	int		count;	/* number of objects in the list if >0, number of waiters if <0 */
+	_li_t		list;	/* sentinel for the list */
+	pthread_mutex_t	mtx;	/* Mutex protecting this queue */
+	pthread_cond_t	cond;	/* condition variable of the list */
+} _meq_t;
+
+/* The eye catcher value */
+#define _MEQ_EYEC	0xe7ec1130
+
+/* Macro to cast */
+#define _Q( _ptr ) ((_meq_t *)(_ptr))
+
+/* Macro to check a pointer */
+#define CHECK_QUEUE( _queue ) (( (_queue) != NULL) && ( _Q(_queue)->eyec == _MEQ_EYEC) )
+
+
 /* The global queues pointers are actually declared here */
 meq_t * g_meq_incoming = NULL;	/* Received messages */
 meq_t * g_meq_outgoing = NULL;	/* Messages to send */
 meq_t * g_meq_local = NULL;	/* Messages for local handling */
 
+/********************************************************************************************************/
+
 /* Initialize the module */
 int meq_init ( void )
 {
-	/* Initialize the module */
+	int ret = 0;
+	
+	TRACE_ENTRY( "" );
 	
 	/* Initialize the global queues */
-	
+	ret = meq_new(&g_meq_incoming);
+	if (ret != 0) {
+		TRACE_DEBUG(INFO, "Failed to initialize a queue: %s", strerror(ret));
+		return ret;
+	}
+	ret = meq_new(&g_meq_outgoing);
+	if (ret != 0) {
+		TRACE_DEBUG(INFO, "Failed to initialize a queue: %s", strerror(ret));
+		return ret;
+	}
+	ret = meq_new(&g_meq_local);
+	if (ret != 0) {
+		TRACE_DEBUG(INFO, "Failed to initialize a queue: %s", strerror(ret));
+		return ret;
+	}
 	
-	TRACE_DEBUG (INFO, "Queues module initialized");
-	TRACE_DEBUG (FULL, "@@@ Not implemented yet." );
 	return 0;
 }
 
 /* End of the module */
 int meq_fini ( void )
 {
-	TRACE_DEBUG (FULL, "Unloading queues module...");
-	TRACE_DEBUG (FULL, "@@@ Not implemented yet." );
+	int ret = 0;
+	
+	TRACE_ENTRY( "" );
+	
+	ret = meq_del(&g_meq_incoming);
+	if (ret != 0) {
+		TRACE_DEBUG(INFO, "Failed to initialize a queue: %s", strerror(ret));
+		return ret;
+	}
+	ret = meq_del(&g_meq_outgoing);
+	if (ret != 0) {
+		TRACE_DEBUG(INFO, "Failed to initialize a queue: %s", strerror(ret));
+		return ret;
+	}
+	ret = meq_del(&g_meq_local);
+	if (ret != 0) {
+		TRACE_DEBUG(INFO, "Failed to initialize a queue: %s", strerror(ret));
+		return ret;
+	}
 	return 0;
 }
 
-
+/* Create a new queue */
 int meq_new ( meq_t ** queue )
 {
-	TRACE_DEBUG (FULL, "@@@ %s: not implemented yet.", __FUNCTION__ );
-	return ENOTSUP;
+	int ret = 0;
+	_meq_t * new;
+	
+	TRACE_ENTRY( "%p", queue );
+	if (!queue) {
+		TRACE_DEBUG(INFO, "Received NULL. EINVAL");
+		return EINVAL;
+	}
+	
+	/* Create a new object */
+	new = (_meq_t *) malloc (sizeof (_meq_t) );
+	if (new == NULL) {
+		log_error("Memory allocation failed: %s\n", strerror(errno));
+		TRACE_DEBUG(INFO, "Malloc failed");
+		return ENOMEM;
+	}
+	
+	/* Initialize the content */
+	memset(new, 0, sizeof(_meq_t));
+	
+	new->eyec = _MEQ_EYEC;
+	LI_init(&new->list, NULL);
+	
+	ret = pthread_mutex_init(&new->mtx, NULL);
+	if (ret != 0) {
+		log_error("Mutex initialization failed: %s\n", strerror(ret));
+		TRACE_DEBUG(INFO, "pthread_mutex_init failed");
+		free(new);
+		return ret;
+	}
+		
+	ret = pthread_cond_init(&new->cond, NULL);
+	if (ret != 0) {
+		log_error("Condition variable initialization failed: %s\n", strerror(ret));
+		TRACE_DEBUG(INFO, "pthread_cond_init failed");
+		free(new);
+		return ret;
+	}
+	
+	/* We're done */
+	*queue = (meq_t *) new;
+	return 0;
 }
 
-
+/* Delete a queue */
 int meq_del ( meq_t ** queue )
 {
-	TRACE_DEBUG (FULL, "@@@ %s: not implemented yet.", __FUNCTION__ );
-	return ENOTSUP;
+	int ret = 0;
+	
+	TRACE_ENTRY( "%p", queue );
+
+	if ( ! CHECK_QUEUE( queue ) ) {
+		TRACE_DEBUG(INFO, "Invalid parameter");
+		return EINVAL;
+	}
+	
+	ret = pthread_mutex_lock( &_Q(queue)->mtx );
+	if (ret != 0) {
+		TRACE_DEBUG(INFO, "pthread_mutex_lock failed: %s", strerror(ret));
+		return ret;
+	}
+	
+	
+	return 0;
 }
 
 
 int meq_length ( meq_t * queue, int * length )
 {
-	TRACE_DEBUG (FULL, "@@@ %s: not implemented yet.", __FUNCTION__ );
+	TRACE_ENTRY( "%p %p", queue, length );
+	TRACE_DEBUG (INFO, "@@@ %s: not implemented yet.", __FUNCTION__ );
 	return ENOTSUP;
 }
 
 
 int meq_post ( meq_t * queue, msg_t * msg )
 {
-	TRACE_DEBUG (FULL, "@@@ %s: not implemented yet.", __FUNCTION__ );
+	TRACE_ENTRY( "%p %p", queue, msg );
+	TRACE_DEBUG (INFO, "@@@ %s: not implemented yet.", __FUNCTION__ );
 	return ENOTSUP;
 }
 
 
 int meq_get ( meq_t * queue, msg_t ** msg )
 {
-	TRACE_DEBUG (FULL, "@@@ %s: not implemented yet.", __FUNCTION__ );
+	TRACE_ENTRY( "%p %p", queue, msg );
+	TRACE_DEBUG (INFO, "@@@ %s: not implemented yet.", __FUNCTION__ );
 	return ENOTSUP;
 }
 
 
 int meq_tryget ( meq_t * queue, msg_t ** msg )
 {
-	TRACE_DEBUG (FULL, "@@@ %s: not implemented yet.", __FUNCTION__ );
+	TRACE_ENTRY( "%p %p", queue, msg );
+	TRACE_DEBUG (INFO, "@@@ %s: not implemented yet.", __FUNCTION__ );
 	return ENOTSUP;
 }
 
 
 int meq_timedget ( meq_t * queue, msg_t ** msg, const struct timespec *abstime )
 {
-	TRACE_DEBUG (FULL, "@@@ %s: not implemented yet.", __FUNCTION__ );
+	TRACE_ENTRY( "%p %p %p", queue, msg, abstime );
+	TRACE_DEBUG (INFO, "@@@ %s: not implemented yet.", __FUNCTION__ );
 	return ENOTSUP;
 }
 
--- a/waaad/queues.h	Tue Jul 15 13:56:30 2008 +0900
+++ b/waaad/queues.h	Tue Jul 15 16:55:41 2008 +0900
@@ -106,7 +106,8 @@
  *  queue	: Pointer to an empty message queue to delete.
  *
  * DESCRIPTION: 
- *  Destroys a message queue. This is only possible if no thread is wainting for a message.
+ *  Destroys a message queue. This is only possible if no thread is waiting for a message,
+ * and the queue is empty.
  *
  * RETURN VALUE:
  *  0		: The message queue has been destroyed successfully.
--- a/waaad/routing.c	Tue Jul 15 13:56:30 2008 +0900
+++ b/waaad/routing.c	Tue Jul 15 16:55:41 2008 +0900
@@ -45,44 +45,48 @@
 /* Initialize the module */
 int rt_init ( void )
 {
-	TRACE_DEBUG (INFO, "Routing module initialized");
-	TRACE_DEBUG (FULL, "@@@ Not implemented yet." );
+	TRACE_ENTRY( "" );
+	TRACE_DEBUG (INFO, "@@@ Not implemented yet." );
 	return 0;
 }
 
 /* End of the module */
 int rt_fini ( void )
 {
-	TRACE_DEBUG (FULL, "Unloading routing module...");
-	TRACE_DEBUG (FULL, "@@@ Not implemented yet." );
+	TRACE_ENTRY( "" );
+	TRACE_DEBUG (INFO, "@@@ Not implemented yet." );
 	return 0;
 }
 
 /* Register a callback for routing-out. */
 int rt_out_register ( rt_out_cb_t cb, void * data, rt_out_pos_t pos, rt_out_hdl_t ** handler )
 {
-	TRACE_DEBUG (FULL, "@@@ %s: not implemented yet.", __FUNCTION__ );
+	TRACE_ENTRY( "%p %p %d %p", cb, data, pos, handler );
+	TRACE_DEBUG (INFO, "@@@ %s: not implemented yet.", __FUNCTION__ );
 	return ENOTSUP;
 }
 
 /* Remove a routing-out callback */
 int rt_out_unregister ( rt_out_hdl_t * handler )
 {
-	TRACE_DEBUG (FULL, "@@@ %s: not implemented yet.", __FUNCTION__ );
+	TRACE_ENTRY( "%p", handler );
+	TRACE_DEBUG (INFO, "@@@ %s: not implemented yet.", __FUNCTION__ );
 	return ENOTSUP;
 }
 
 /* Register a callback for routing-fwd. */
 int rt_fwd_register ( rt_fwd_cb_t cb, void * data, rt_fwd_pos_t pos, rt_fwd_hdl_t ** handler )
 {
-	TRACE_DEBUG (FULL, "@@@ %s: not implemented yet.", __FUNCTION__ );
+	TRACE_ENTRY( "%p %p %d %p", cb, data, pos, handler );
+	TRACE_DEBUG (INFO, "@@@ %s: not implemented yet.", __FUNCTION__ );
 	return ENOTSUP;
 }
 
 /* Remove a routing-fwd callback */
 int rt_fwd_unregister ( rt_fwd_hdl_t * handler )
 {
-	TRACE_DEBUG (FULL, "@@@ %s: not implemented yet.", __FUNCTION__ );
+	TRACE_ENTRY( "%p", handler );
+	TRACE_DEBUG (INFO, "@@@ %s: not implemented yet.", __FUNCTION__ );
 	return ENOTSUP;
 }
 
--- a/waaad/security.c	Tue Jul 15 13:56:30 2008 +0900
+++ b/waaad/security.c	Tue Jul 15 16:55:41 2008 +0900
@@ -45,30 +45,32 @@
 /* Initialize the module */
 int sec_init ( void )
 {
-	TRACE_DEBUG (INFO, "Security module initialized");
-	TRACE_DEBUG (FULL, "@@@ Not implemented yet." );
+	TRACE_ENTRY( "" );
+	TRACE_DEBUG (INFO, "@@@ Not implemented yet." );
 	return 0;
 }
 
 /* End of the module */
 int sec_fini ( void )
 {
-	TRACE_DEBUG (FULL, "Unloading security module...");
-	TRACE_DEBUG (FULL, "@@@ Not implemented yet." );
+	TRACE_ENTRY( "" );
+	TRACE_DEBUG (INFO, "@@@ Not implemented yet." );
 	return 0;
 }
 
 /* Register a new module. */
 int sec_register ( sec_module_t * module, sec_mod_hdl_t ** handler )
 {
-	TRACE_DEBUG (FULL, "@@@ %s: not implemented yet.", __FUNCTION__ );
+	TRACE_ENTRY( "%p %p", module, handler );
+	TRACE_DEBUG (INFO, "@@@ %s: not implemented yet.", __FUNCTION__ );
 	return ENOTSUP;
 }
 
 /* Remove a registered module. */
 int sec_unregister ( sec_mod_hdl_t * handle )
 {
-	TRACE_DEBUG (FULL, "@@@ %s: not implemented yet.", __FUNCTION__ );
+	TRACE_ENTRY( "%p", handle );
+	TRACE_DEBUG (INFO, "@@@ %s: not implemented yet.", __FUNCTION__ );
 	return ENOTSUP;
 }
 
--- a/waaad/session.c	Tue Jul 15 13:56:30 2008 +0900
+++ b/waaad/session.c	Tue Jul 15 16:55:41 2008 +0900
@@ -45,86 +45,96 @@
 /* Initialize the module */
 int sess_init ( void )
 {
-	TRACE_DEBUG (INFO, "Session module initialized");
-	TRACE_DEBUG (FULL, "@@@ Not implemented yet." );
+	TRACE_ENTRY( "" );
+	TRACE_DEBUG (INFO, "@@@ Not implemented yet." );
 	return 0;
 }
 
 /* End of the module */
 int sess_fini ( void )
 {
-	TRACE_DEBUG (FULL, "Unloading session module...");
-	TRACE_DEBUG (FULL, "@@@ Not implemented yet." );
+	TRACE_ENTRY( "" );
+	TRACE_DEBUG (INFO, "@@@ Not implemented yet." );
 	return 0;
 }
 
 /* Create a new session (identifier and object). */
 int sess_new ( sess_id_t ** session, sess_flags_t flags, char * opt )
 {
-	TRACE_DEBUG (FULL, "@@@ %s: not implemented yet.", __FUNCTION__ );
+	TRACE_ENTRY( "%p %d %p", session, flags, opt );
+	TRACE_DEBUG (INFO, "@@@ %s: not implemented yet.", __FUNCTION__ );
 	return ENOTSUP;
 }
 
 /* Find a session object corresponding to a given session-id */
 int sess_fromsid ( char * sid, size_t len, sess_id_t ** session)
 {
-	TRACE_DEBUG (FULL, "@@@ %s: not implemented yet.", __FUNCTION__ );
+	TRACE_ENTRY( "%p %d %p", sid, len, session );
+	TRACE_DEBUG (INFO, "@@@ %s: not implemented yet.", __FUNCTION__ );
 	return ENOTSUP;
 }
 
 /* Get the session-id string of a session */
 int sess_getsid ( sess_id_t * session, char ** sid )
 {
-	TRACE_DEBUG (FULL, "@@@ %s: not implemented yet.", __FUNCTION__ );
+	TRACE_ENTRY( "%p %p", session, sid );
+	TRACE_DEBUG (INFO, "@@@ %s: not implemented yet.", __FUNCTION__ );
 	return ENOTSUP;
 }
 
 /* Increase refcount of a session */
 int sess_link ( sess_id_t * session )
 {
-	TRACE_DEBUG (FULL, "@@@ %s: not implemented yet.", __FUNCTION__ );
+	TRACE_ENTRY( "%p", session );
+	TRACE_DEBUG (INFO, "@@@ %s: not implemented yet.", __FUNCTION__ );
 	return ENOTSUP;
 }
 
 /* Decrease refcount of a session, eventually free it. */
 int sess_unlink ( sess_id_t ** session )
 {
-	TRACE_DEBUG (FULL, "@@@ %s: not implemented yet.", __FUNCTION__ );
+	TRACE_ENTRY( "%p", session );
+	TRACE_DEBUG (INFO, "@@@ %s: not implemented yet.", __FUNCTION__ );
 	return ENOTSUP;
 }
 
 /* Create a new client of the module. */
 int sess_regext ( sess_reg_t ** client )
 {
-	TRACE_DEBUG (FULL, "@@@ %s: not implemented yet.", __FUNCTION__ );
+	TRACE_ENTRY( "%p", client );
+	TRACE_DEBUG (INFO, "@@@ %s: not implemented yet.", __FUNCTION__ );
 	return ENOTSUP;
 }
 
 /* Destroy a client of the module. */
 int sess_deregext ( sess_reg_t * client )
 {
-	TRACE_DEBUG (FULL, "@@@ %s: not implemented yet.", __FUNCTION__ );
+	TRACE_ENTRY( "%p", client );
+	TRACE_DEBUG (INFO, "@@@ %s: not implemented yet.", __FUNCTION__ );
 	return ENOTSUP;
 }
 
 /* Register data in a session. */
 int sess_data_reg ( sess_id_t * session, sess_reg_t * client, void * data, void (*cleanup)(void *) )
 {
-	TRACE_DEBUG (FULL, "@@@ %s: not implemented yet.", __FUNCTION__ );
+	TRACE_ENTRY( "%p %p %p %p", session, client, data, cleanup );
+	TRACE_DEBUG (INFO, "@@@ %s: not implemented yet.", __FUNCTION__ );
 	return ENOTSUP;
 }
 
 /* Retrieve registered data. */
 int sess_data_get ( sess_id_t * session, sess_reg_t * client, void ** data )
 {
-	TRACE_DEBUG (FULL, "@@@ %s: not implemented yet.", __FUNCTION__ );
+	TRACE_ENTRY( "%p %p %p", session, client, data );
+	TRACE_DEBUG (INFO, "@@@ %s: not implemented yet.", __FUNCTION__ );
 	return ENOTSUP;
 }
 
 /* Remove registered data from a session. */
 int sess_data_dereg ( sess_id_t * session, sess_reg_t * client, void ** data )
 {
-	TRACE_DEBUG (FULL, "@@@ %s: not implemented yet.", __FUNCTION__ );
+	TRACE_ENTRY( "%p %p %p", session, client, data );
+	TRACE_DEBUG (INFO, "@@@ %s: not implemented yet.", __FUNCTION__ );
 	return ENOTSUP;
 }
 
"Welcome to our mercurial repository"