diff libfdproto/messages.c @ 804:c5b7d4a2cc77

Log message dumps in one call to the dump function to avoid fragmentation in the log files, as per Zack comment
author Sebastien Decugis <sdecugis@nict.go.jp>
date Wed, 22 Aug 2012 00:22:46 +0200
parents 0f566e550813
children c0a88c1bcc1e
line wrap: on
line diff
--- a/libfdproto/messages.c	Wed Aug 22 00:18:15 2012 +0200
+++ b/libfdproto/messages.c	Wed Aug 22 00:22:46 2012 +0200
@@ -661,21 +661,23 @@
 #define INOBJHDR 	"%*s   "
 #define INOBJHDRVAL 	indent<0 ? 1 : indent, indent<0 ? "-" : "|"
 
+/* Write some debug data in a buffer */
+
 /* Dump a msg_t object */
-static void obj_dump_msg (struct msg * msg, int indent, FILE * fstr )
+static int obj_dump_msg (struct msg * msg, int indent, char **outstr, size_t *offset, size_t *outlen )
 {
 	int ret = 0;
 	
-	fd_log_debug_fstr(fstr, "%*sMSG: %p\n", INOBJHDRVAL, msg);
+	CHECK_FCT( dump_add_str(outstr, offset, outlen, "%*sMSG: %p\n", INOBJHDRVAL, msg) );
 	
 	if (!CHECK_MSG(msg)) {
-		fd_log_debug_fstr(fstr, INOBJHDR "INVALID!\n", INOBJHDRVAL);
-		return;
+		CHECK_FCT( dump_add_str(outstr, offset, outlen, INOBJHDR "INVALID!\n", INOBJHDRVAL) );
+		return 0;
 	}
 	
 	if (!msg->msg_model) {
 		
-		fd_log_debug_fstr(fstr, INOBJHDR "(no model)\n", INOBJHDRVAL);
+		CHECK_FCT( dump_add_str(outstr, offset, outlen, INOBJHDR "(no model)\n", INOBJHDRVAL) );
 		
 	} else {
 		
@@ -683,19 +685,19 @@
 		struct dict_cmd_data  dictdata;
 		ret = fd_dict_gettype(msg->msg_model, &dicttype);
 		if (ret || (dicttype != DICT_COMMAND)) {
-			fd_log_debug_fstr(fstr, INOBJHDR "(invalid model: %d %d)\n", INOBJHDRVAL, ret, dicttype);
+			CHECK_FCT( dump_add_str(outstr, offset, outlen, INOBJHDR "(invalid model: %d %d)\n", INOBJHDRVAL, ret, dicttype) );
 			goto public;
 		}
 		ret = fd_dict_getval(msg->msg_model, &dictdata);
 		if (ret != 0) {
-			fd_log_debug_fstr(fstr, INOBJHDR "(error getting model data: %s)\n", INOBJHDRVAL, strerror(ret));
+			CHECK_FCT( dump_add_str(outstr, offset, outlen, INOBJHDR "(error getting model data: %s)\n", INOBJHDRVAL, strerror(ret)) );
 			goto public;
 		}
-		fd_log_debug_fstr(fstr, INOBJHDR "model : v/m:" DUMP_CMDFL_str "/" DUMP_CMDFL_str ", %u \"%s\"\n", INOBJHDRVAL, 
-			DUMP_CMDFL_val(dictdata.cmd_flag_val), DUMP_CMDFL_val(dictdata.cmd_flag_mask), dictdata.cmd_code, dictdata.cmd_name);
+		CHECK_FCT( dump_add_str(outstr, offset, outlen, INOBJHDR "model : v/m:" DUMP_CMDFL_str "/" DUMP_CMDFL_str ", %u \"%s\"\n", INOBJHDRVAL, 
+			DUMP_CMDFL_val(dictdata.cmd_flag_val), DUMP_CMDFL_val(dictdata.cmd_flag_mask), dictdata.cmd_code, dictdata.cmd_name) );
 	}
 public:	
-	fd_log_debug_fstr(fstr, INOBJHDR "public: V:%d L:%d fl:" DUMP_CMDFL_str " CC:%u A:%d hi:%x ei:%x\n", INOBJHDRVAL, 
+	CHECK_FCT( dump_add_str(outstr, offset, outlen, INOBJHDR "public: V:%d L:%d fl:" DUMP_CMDFL_str " CC:%u A:%d hi:%x ei:%x\n", INOBJHDRVAL, 
 		msg->msg_public.msg_version,
 		msg->msg_public.msg_length,
 		DUMP_CMDFL_val(msg->msg_public.msg_flags),
@@ -703,24 +705,25 @@
 		msg->msg_public.msg_appl,
 		msg->msg_public.msg_hbhid,
 		msg->msg_public.msg_eteid
-		);
-	fd_log_debug_fstr(fstr, INOBJHDR "intern: rwb:%p rt:%d cb:%p(%p) qry:%p asso:%d sess:%p src:%s(%zd)\n", 
-			INOBJHDRVAL, msg->msg_rawbuffer, msg->msg_routable, msg->msg_cb.fct, msg->msg_cb.data, msg->msg_query, msg->msg_associated, msg->msg_sess, msg->msg_src_id?:"(nil)", msg->msg_src_id_len);
+		) );
+	CHECK_FCT( dump_add_str(outstr, offset, outlen, INOBJHDR "intern: rwb:%p rt:%d cb:%p(%p) qry:%p asso:%d sess:%p src:%s(%zd)\n", 
+			INOBJHDRVAL, msg->msg_rawbuffer, msg->msg_routable, msg->msg_cb.fct, msg->msg_cb.data, msg->msg_query, msg->msg_associated, msg->msg_sess, msg->msg_src_id?:"(nil)", msg->msg_src_id_len) );
+	return 0;
 }
 
 /* Dump an avp object */
-static void obj_dump_avp ( struct avp * avp, int indent, FILE * fstr )
+static int obj_dump_avp ( struct avp * avp, int indent, char **outstr, size_t *offset, size_t *outlen )
 {
 	int ret = 0;
 	
 	if (!CHECK_AVP(avp)) {
-		fd_log_debug_fstr(fstr, INOBJHDR "INVALID!\n", INOBJHDRVAL);
-		return;
+		CHECK_FCT( dump_add_str(outstr, offset, outlen, INOBJHDR "INVALID!\n", INOBJHDRVAL) );
+		return 0;
 	}
 	
 	if (!avp->avp_model) {
 		
-		fd_log_debug_fstr(fstr, INOBJHDR "(no model)\n", INOBJHDRVAL);
+		CHECK_FCT( dump_add_str(outstr, offset, outlen, INOBJHDR "(no model)\n", INOBJHDRVAL) );
 		
 	} else {
 		
@@ -728,67 +731,69 @@
 		struct dict_avp_data dictdata;
 		ret = fd_dict_gettype(avp->avp_model, &dicttype);
 		if (ret || (dicttype != DICT_AVP)) {
-			fd_log_debug_fstr(fstr, INOBJHDR "(invalid model: %d %d)\n", INOBJHDRVAL, ret, dicttype);
+			CHECK_FCT( dump_add_str(outstr, offset, outlen, INOBJHDR "(invalid model: %d %d)\n", INOBJHDRVAL, ret, dicttype) );
 			goto public;
 		}
 		ret = fd_dict_getval(avp->avp_model, &dictdata);
 		if (ret != 0) {
-			fd_log_debug_fstr(fstr, INOBJHDR "(error getting model data: %s)\n", INOBJHDRVAL, strerror(ret));
+			CHECK_FCT( dump_add_str(outstr, offset, outlen, INOBJHDR "(error getting model data: %s)\n", INOBJHDRVAL, strerror(ret)) );
 			goto public;
 		}
-		fd_log_debug_fstr(fstr, INOBJHDR "model : v/m:" DUMP_AVPFL_str "/" DUMP_AVPFL_str ", %12s, %u \"%s\"\n", INOBJHDRVAL, 
+		CHECK_FCT( dump_add_str(outstr, offset, outlen, INOBJHDR "model : v/m:" DUMP_AVPFL_str "/" DUMP_AVPFL_str ", %12s, %u \"%s\"\n", INOBJHDRVAL, 
 			DUMP_AVPFL_val(dictdata.avp_flag_val), 
 			DUMP_AVPFL_val(dictdata.avp_flag_mask), 
 			type_base_name[dictdata.avp_basetype], 
 			dictdata.avp_code, 
-			dictdata.avp_name );
+			dictdata.avp_name ) );
 	}
 public:	
-	fd_log_debug_fstr(fstr, INOBJHDR "public: C:%u fl:" DUMP_AVPFL_str " L:%d V:%u  data:@%p\n", INOBJHDRVAL, 
+	CHECK_FCT( dump_add_str(outstr, offset, outlen, INOBJHDR "public: C:%u fl:" DUMP_AVPFL_str " L:%d V:%u  data:@%p\n", INOBJHDRVAL, 
 		avp->avp_public.avp_code,
 		DUMP_AVPFL_val(avp->avp_public.avp_flags),
 		avp->avp_public.avp_len,
 		avp->avp_public.avp_vendor,
 		avp->avp_public.avp_value
-		);
+		) );
 	/* Dump the value if set */
 	if (avp->avp_public.avp_value) {
 		if (!avp->avp_model) {
-			fd_log_debug_fstr(fstr, INOBJHDR "(data set but no model: ERROR)\n", INOBJHDRVAL);
+			CHECK_FCT( dump_add_str(outstr, offset, outlen, INOBJHDR "(data set but no model: ERROR)\n", INOBJHDRVAL) );
 		} else {
-			fd_dict_dump_avp_value(avp->avp_public.avp_value, avp->avp_model, indent, fstr);
+			CHECK_FCT( fd_dict_dump_avp_value(avp->avp_public.avp_value, avp->avp_model, indent, outstr, offset, outlen) );
 		}
 	}
 
-	fd_log_debug_fstr(fstr, INOBJHDR "intern: src:%p mf:%d raw:%p(%d)\n", INOBJHDRVAL, avp->avp_source, avp->avp_mustfreeos, avp->avp_rawdata, avp->avp_rawlen);
+	CHECK_FCT( dump_add_str(outstr, offset, outlen, INOBJHDR "intern: src:%p mf:%d raw:%p(%d)\n", INOBJHDRVAL, avp->avp_source, avp->avp_mustfreeos, avp->avp_rawdata, avp->avp_rawlen) );
+	return 0;
 }
 
-/* Dump a single object content */
-static void msg_dump_intern ( int level, msg_or_avp * obj, int indent, FILE * fstr )
+/* Dump a single object content into out string, realloc if needed */
+static int msg_dump_intern ( int level, msg_or_avp * obj, int indent, char **outstr, size_t *offset, size_t *outlen )
 {
 	/* Log only if we are at least at level */
 	if ( ! TRACE_BOOL(level) )
-		return;
+		return 0;
 	
 	/* Check the object */
 	if (!VALIDATE_OBJ(obj)) {
-		fd_log_debug_fstr(fstr, ">>> invalid object (%p)!.\n", obj);
-		return;
+		CHECK_FCT( dump_add_str(outstr, offset, outlen, ">>> invalid object (%p)!.\n", obj) );
+		return 0;
 	}
 	
 	/* Dump the object */
 	switch (_C(obj)->type) {
 		case MSG_AVP:
-			obj_dump_avp ( _A(obj), indent, fstr );
+			CHECK_FCT( obj_dump_avp ( _A(obj), indent, outstr, offset, outlen ));
 			break;
 		
 		case MSG_MSG:
-			obj_dump_msg ( _M(obj), indent, fstr );
+			CHECK_FCT( obj_dump_msg ( _M(obj), indent, outstr, offset, outlen ) );
 			break;
 		
 		default:
 			ASSERT(0);
 	}
+	return 0;
 }
 
 /* Dump a message to a specified file stream */
@@ -796,18 +801,35 @@
 {
 	msg_or_avp * ref = msg;
 	int indent = 2;
+	char *outstr;
+	size_t offset, outlen;
+	CHECK_FCT_DO( dump_init_str(&outstr, &offset, &outlen), { fd_log_debug_fstr(fstr, "Error initializing string for dumping %p\n", msg); return; } );
 	do {
-		msg_dump_intern ( NONE, ref, indent, fstr );
+		CHECK_FCT_DO(  msg_dump_intern ( NONE, ref, indent, &outstr, &offset, &outlen ),
+				fd_log_debug_fstr(fstr, "Error while dumping %p\n", ref) );
 		
 		/* Now find the next object */
 		CHECK_FCT_DO(  fd_msg_browse ( ref, MSG_BRW_WALK, &ref, &indent ), break  );
 		
 		/* dump next object */
 	} while (ref);
+	
+	/* now really output this in one shot, so it is not interrupted */
+	fd_log_debug_fstr(fstr, "%s", outstr);
+	
+	free(outstr);
 }
 void fd_msg_dump_fstr_one ( struct msg * msg, FILE * fstr ) /* just the header */
 {
-	msg_dump_intern ( NONE, msg, 2, fstr );
+	char *outstr;
+	size_t offset, outlen;
+	CHECK_FCT_DO( dump_init_str(&outstr, &offset, &outlen), { fd_log_debug_fstr(fstr, "Error initializing string for dumping %p\n", msg); return; } );
+	CHECK_FCT_DO(  msg_dump_intern ( NONE, msg, 2, &outstr, &offset, &outlen ),
+				fd_log_debug_fstr(fstr, "Error while dumping %p\n", msg) );
+	/* now really output this in one shot, so it is not interrupted */
+	fd_log_debug_fstr(fstr, "%s", outstr);
+	
+	free(outstr);
 }
 
 /* Dump a message content -- for debug mostly */
@@ -815,10 +837,14 @@
 {
 	msg_or_avp * ref = obj;
 	int indent = 1;
-	
-	TRACE_DEBUG(level, "------ Dumping object %p (w)-------", obj);
+	char *outstr;
+	size_t offset, outlen;
+	CHECK_FCT_DO( dump_init_str(&outstr, &offset, &outlen), 
+			{ fd_log_debug_fstr(fd_g_debug_fstr, "Error initializing string for dumping %p\n", obj); return; } );
+
 	do {
-		msg_dump_intern ( level, ref, indent, fd_g_debug_fstr );
+		CHECK_FCT_DO(  msg_dump_intern ( level, ref, indent, &outstr, &offset, &outlen ),
+				fd_log_debug_fstr(fd_g_debug_fstr, "Error while dumping %p\n", ref) );
 		
 		/* Now find the next object */
 		CHECK_FCT_DO(  fd_msg_browse ( ref, MSG_BRW_WALK, &ref, &indent ), break  );
@@ -826,15 +852,27 @@
 		/* dump next object */
 	} while (ref);
 	
+	/* now really output this in one shot, so it is not interrupted */
+	TRACE_DEBUG(level, "------ Dumping object %p (w)-------", obj);
+	fd_log_debug_fstr(fd_g_debug_fstr, "%s", outstr);
 	TRACE_DEBUG(level, "------ /end of object %p -------", obj);
+	
+	free(outstr);
 }
 
 /* Dump a single object content -- for debug mostly */
 void fd_msg_dump_one ( int level, msg_or_avp * obj )
 {
+	char *outstr;
+	size_t offset, outlen;
+	CHECK_FCT_DO( dump_init_str(&outstr, &offset, &outlen), 
+			{ fd_log_debug_fstr(fd_g_debug_fstr, "Error initializing string for dumping %p\n", obj); return; } );
+	CHECK_FCT_DO(  msg_dump_intern ( level, obj, 1, &outstr, &offset, &outlen ),
+			fd_log_debug_fstr(fd_g_debug_fstr, "Error while dumping %p\n", obj) );
 	TRACE_DEBUG(level, "------ Dumping object %p (s)-------", obj);
-	msg_dump_intern ( level, obj, 1, fd_g_debug_fstr );
+	fd_log_debug_fstr(fd_g_debug_fstr, "%s", outstr);
 	TRACE_DEBUG(level, "------ /end of object %p -------", obj);
+	free(outstr);
 }
 
 
@@ -1687,7 +1725,7 @@
 		
 		if (mandatory && (avp->avp_public.avp_flags & AVP_FLAG_MANDATORY)) {
 			TRACE_DEBUG(INFO, "Unsupported mandatory AVP found:");
-			msg_dump_intern(INFO, avp, 2, fd_g_debug_fstr);
+			fd_msg_dump_one(INFO, avp);
 			if (error_info) {
 				error_info->pei_errcode = "DIAMETER_AVP_UNSUPPORTED";
 				error_info->pei_avp = avp;
"Welcome to our mercurial repository"