Logsys flight recorder.

git-svn-id: http://svn.fedorahosted.org/svn/corosync/trunk@1681 fd59a12c-fef9-0310-b244-a6a79926bd2f

exec/main.c

@@ -83,9 +83,11 @@
 #include "version.h"
 
 LOGSYS_DECLARE_SYSTEM ("corosync",
-	LOG_MODE_OUTPUT_STDERR | LOG_MODE_OUTPUT_SYSLOG_THREADED | LOG_MODE_BUFFER_BEFORE_CONFIG,
+	LOG_MODE_OUTPUT_STDERR | LOG_MODE_THREADED | LOG_MODE_FORK,
 	NULL,
-	LOG_DAEMON);
+	LOG_DAEMON,
+	"[%5s] %b",
+	1000000);
 
 LOGSYS_DECLARE_SUBSYS ("MAIN", LOG_INFO);
 
@@ -145,7 +147,6 @@ static void *aisexec_exit (void *arg)
 #endif
 
 	totempg_finalize ();
-	logsys_flush ();
 
 	corosync_exit_error (AIS_DONE_EXIT);
 
@@ -171,14 +172,16 @@ static void sigquit_handler (int num)
 static void sigsegv_handler (int num)
 {
 	signal (SIGSEGV, SIG_DFL);
-	logsys_flush ();
+	logsys_atsegv();
+	logsys_log_rec_store ("/var/lib/corosync/fdata");
 	raise (SIGSEGV);
 }
 
 static void sigabrt_handler (int num)
 {
 	signal (SIGABRT, SIG_DFL);
-	logsys_flush ();
+	logsys_atsegv();
+	logsys_log_rec_store ("/var/lib/corosync/fdata");
 	raise (SIGABRT);
 }
 
@@ -494,7 +497,6 @@ int main (int argc, char **argv)
 	char *iface;
 	int res, ch;
 	int background, setprio;
- 	int totem_log_service;
 
  	/* default configuration
 	 */
@@ -506,7 +508,7 @@ int main (int argc, char **argv)
 		switch (ch) {
 			case 'f':
 				background = 0;
-				logsys_config_mode_set (LOG_MODE_OUTPUT_STDERR|LOG_MODE_FLUSH_AFTER_CONFIG);
+				logsys_config_mode_set (LOG_MODE_OUTPUT_STDERR|LOG_MODE_THREADED|LOG_MODE_FORK);
 				break;
 			case 'p':
 				setprio = 0;
@@ -639,6 +641,8 @@ int main (int argc, char **argv)
 	logsys_config_mode_set (main_config.logmode);
 	logsys_config_file_set (&error_string, main_config.logfile);
 
+	logsys_fork_completed ();
+
 	aisexec_uid_determine (&main_config);
 
 	aisexec_gid_determine (&main_config);
@@ -654,13 +658,14 @@ int main (int argc, char **argv)
 	aisexec_mlockall ();
 
 	totem_config.totem_logging_configuration = totem_logging_configuration;
-	totem_log_service = _logsys_subsys_create ("TOTEM", LOG_INFO);
-  	totem_config.totem_logging_configuration.log_level_security = logsys_mkpri (LOG_LEVEL_SECURITY, totem_log_service);
-	totem_config.totem_logging_configuration.log_level_error = logsys_mkpri (LOG_LEVEL_ERROR, totem_log_service);
-	totem_config.totem_logging_configuration.log_level_warning = logsys_mkpri (LOG_LEVEL_WARNING, totem_log_service);
-	totem_config.totem_logging_configuration.log_level_notice = logsys_mkpri (LOG_LEVEL_NOTICE, totem_log_service);
-	totem_config.totem_logging_configuration.log_level_debug = logsys_mkpri (LOG_LEVEL_DEBUG, totem_log_service);
-	totem_config.totem_logging_configuration.log_printf = logsys_log_printf;
+	totem_config.totem_logging_configuration.log_subsys_id =
+		_logsys_subsys_create ("TOTEM", LOG_INFO);
+  	totem_config.totem_logging_configuration.log_level_security = LOG_LEVEL_SECURITY;
+	totem_config.totem_logging_configuration.log_level_error = LOG_LEVEL_ERROR;
+	totem_config.totem_logging_configuration.log_level_warning = LOG_LEVEL_WARNING;
+	totem_config.totem_logging_configuration.log_level_notice = LOG_LEVEL_NOTICE;
+	totem_config.totem_logging_configuration.log_level_debug = LOG_LEVEL_DEBUG;
+	totem_config.totem_logging_configuration.log_printf = _logsys_log_printf;
 
 	/*
 	 * Sleep for a while to let other nodes in the cluster

exec/mainconfig.c

@@ -109,8 +109,6 @@ int corosync_main_config_read (
 	char *error_reason = error_string_response;
 	unsigned int object_find_handle;
 	unsigned int object_find_logsys_handle;
-	int global_debug = 0;
-
 
 	memset (main_config, 0, sizeof (struct main_config));
 
@@ -120,7 +118,7 @@ int corosync_main_config_read (
 		strlen ("logging"),
 		&object_find_handle);
 
-	main_config->logmode = LOG_MODE_FLUSH_AFTER_CONFIG;
+	main_config->logmode = LOG_MODE_THREADED | LOG_MODE_FORK;
 	if (objdb->object_find_next (
 		object_find_handle,
 		&object_service_handle) == 0) {
@@ -135,10 +133,10 @@ int corosync_main_config_read (
 		}
 		if (!objdb_get_string (objdb,object_service_handle, "to_syslog", &value)) {
 			if (strcmp (value, "yes") == 0) {
-				main_config->logmode |= LOG_MODE_OUTPUT_SYSLOG_THREADED;
+				main_config->logmode |= LOG_MODE_OUTPUT_SYSLOG;
 			} else
 			if (strcmp (value, "no") == 0) {
-				main_config->logmode &= ~LOG_MODE_OUTPUT_SYSLOG_THREADED;
+				main_config->logmode &= ~LOG_MODE_OUTPUT_SYSLOG;
 			}
 		}
 		if (!objdb_get_string (objdb,object_service_handle, "to_stderr", &value)) {
@@ -149,18 +147,8 @@ int corosync_main_config_read (
 				main_config->logmode &= ~LOG_MODE_OUTPUT_STDERR;
 			}
 		}
-
-		if (!objdb_get_string (objdb,object_service_handle, "debug", &value)) {
-                        if (strcmp (value, "on") == 0) {
-                                global_debug = 1;
-                        } else
-                        if (strcmp (value, "off") == 0) {
-                                global_debug = 0;
-                        } else {
-                                goto parse_error;
-                        }
-                }
 		if (!objdb_get_string (objdb,object_service_handle, "timestamp", &value)) {
+/* todo change format string
 			if (strcmp (value, "on") == 0) {
 				main_config->logmode |= LOG_MODE_DISPLAY_TIMESTAMP;
 			} else
@@ -169,12 +157,14 @@ int corosync_main_config_read (
 			} else {
 				goto parse_error;
 			}
+*/
 		}
 		if (!objdb_get_string (objdb,object_service_handle, "logfile", &value)) {
 			main_config->logfile = strdup (value);
 		}
 
 		if (!objdb_get_string (objdb,object_service_handle, "fileline", &value)) {
+/* TODO
 			if (strcmp (value, "on") == 0) {
 				main_config->logmode |= LOG_MODE_DISPLAY_FILELINE;
 			} else
@@ -183,6 +173,7 @@ int corosync_main_config_read (
 			} else {
 				goto parse_error;
 			}
+*/
 		}
 
 		if (!objdb_get_string (objdb,object_service_handle, "syslog_facility", &value)) {

exec/sync.c

@@ -546,7 +546,7 @@ static int sync_request_send (
 	struct iovec iovec[2];
 	int name_len;
 
-	ENTER("'%s'", name);
+	ENTER();
 
 	name_len = strlen (name) + 1;
 	msg.header.size = sizeof (msg) + name_len;
@@ -608,7 +608,7 @@ int sync_request (char *name)
 {
 	assert (name != NULL);
 
-	ENTER("'%s'", name);
+	ENTER();
 
 	if (sync_processing) {
 		return -1;
@@ -618,7 +618,7 @@ int sync_request (char *name)
 		TOTEM_CALLBACK_TOKEN_SENT, 0, /* don't delete after callback */
 		sync_request_send, name);
 
-	LEAVE("");
+	LEAVE();
 
 	return 0;
 }

exec/totemnet.c

@@ -137,7 +137,11 @@ struct totemnet_instance {
 
 	int totemnet_log_level_debug;
 
-	void (*totemnet_log_printf) (char *file, int line, int level, char *format, ...) __attribute__((format(printf, 4, 5)));
+	int totemnet_subsys_id;
+
+	void (*totemnet_log_printf) (int subsys, char *function, char *file,
+		int line, unsigned int level, char *format,
+		...)__attribute__((format(printf, 6, 7)));
 
 	totemnet_handle handle;
 
@@ -226,8 +230,12 @@ static void totemnet_instance_initialize (struct totemnet_instance *instance)
 	instance->my_memb_entries = 1;
 }
 
-#define log_printf(level, format, args...) \
-    instance->totemnet_log_printf (__FILE__, __LINE__, level, format, ##args)
+#define log_printf(level, format, args...)				\
+do {									\
+        instance->totemnet_log_printf (instance->totemnet_subsys_id,	\
+                (char *)__FUNCTION__, __FILE__, __LINE__, level,	\
+                format, ##args);					\
+} while (0);
 
 static int authenticate_and_decrypt (
 	struct totemnet_instance *instance,
@@ -1192,6 +1200,7 @@ int totemnet_initialize (
 	instance->totemnet_log_level_warning = totem_config->totem_logging_configuration.log_level_warning;
 	instance->totemnet_log_level_notice = totem_config->totem_logging_configuration.log_level_notice;
 	instance->totemnet_log_level_debug = totem_config->totem_logging_configuration.log_level_debug;
+	instance->totemnet_subsys_id = totem_config->totem_logging_configuration.log_subsys_id;
 	instance->totemnet_log_printf = totem_config->totem_logging_configuration.log_printf;
 
 	/*

exec/totempg.c

@@ -153,7 +153,10 @@ static int totempg_log_level_error;
 static int totempg_log_level_warning;
 static int totempg_log_level_notice;
 static int totempg_log_level_debug;
-static void (*totempg_log_printf) (char *file, int line, int level, char *format, ...) __attribute__((format(printf, 4, 5))) = NULL;
+static int totempg_subsys_id;
+static void (*totempg_log_printf) (int subsys_id, char *function, char *file,
+        int line, unsigned int level, char *format,
+        ...) __attribute__((format(printf, 6, 7)));
 
 struct totem_config *totempg_totem_config;
 
@@ -225,8 +228,11 @@ static pthread_mutex_t callback_token_mutex = PTHREAD_MUTEX_INITIALIZER;
 
 static pthread_mutex_t mcast_msg_mutex = PTHREAD_MUTEX_INITIALIZER;
 
-#define log_printf(level, format, args...) \
-    totempg_log_printf (__FILE__, __LINE__, level, format, ##args)
+#define log_printf(level, format, args...)				\
+do {									\
+        totempg_log_printf (totempg_subsys_id, (char *)__FUNCTION__,	\
+		__FILE__, __LINE__, level, format, ##args);		\
+} while (0);
 
 static struct assembly *assembly_ref (unsigned int nodeid)
 {
@@ -686,6 +692,7 @@ int totempg_initialize (
 	totempg_log_level_notice = totem_config->totem_logging_configuration.log_level_notice;
 	totempg_log_level_debug = totem_config->totem_logging_configuration.log_level_debug;
 	totempg_log_printf = totem_config->totem_logging_configuration.log_printf;
+	totempg_subsys_id = totem_config->totem_logging_configuration.log_subsys_id;
 
 	fragmentation_data = malloc (TOTEMPG_PACKET_SIZE);
 	if (fragmentation_data == 0) {

exec/totemrrp.c

@@ -194,7 +194,11 @@ struct totemrrp_instance {
 
 	int totemrrp_log_level_debug;
 
-	void (*totemrrp_log_printf) (char *file, int line, int level, char *format, ...) __attribute__((format(printf, 4, 5)));
+	int totemrrp_subsys_id;
+
+	void (*totemrrp_log_printf) (int subsys, char *function, char *file,
+		int line, unsigned int level, char *format,
+		...)__attribute__((format(printf, 6, 7)));
 
 	totemrrp_handle handle;
 
@@ -459,8 +463,14 @@ static struct hdb_handle_database totemrrp_instance_database = {
 	.mutex		= PTHREAD_MUTEX_INITIALIZER
 };
 
-#define log_printf(level, format, args...) \
-    rrp_instance->totemrrp_log_printf (__FILE__, __LINE__, level, format, ##args)
+
+#define log_printf(level, format, args...)				\
+do {									\
+	rrp_instance->totemrrp_log_printf (				\
+		rrp_instance->totemrrp_subsys_id,			\
+		(char *)__FUNCTION__, __FILE__, __LINE__, level,	\
+		format, ##args);					\
+} while (0);
 
 /*
  * None Replication Implementation
@@ -1426,6 +1436,7 @@ int totemrrp_initialize (
 	instance->totemrrp_log_level_warning = totem_config->totem_logging_configuration.log_level_warning;
 	instance->totemrrp_log_level_notice = totem_config->totem_logging_configuration.log_level_notice;
 	instance->totemrrp_log_level_debug = totem_config->totem_logging_configuration.log_level_debug;
+	instance->totemrrp_subsys_id = totem_config->totem_logging_configuration.log_subsys_id;
 	instance->totemrrp_log_printf = totem_config->totem_logging_configuration.log_printf;
 
 	instance->interfaces = totem_config->interfaces;

exec/totemsrp.c

@@ -429,7 +429,11 @@ struct totemsrp_instance {
 
 	int totemsrp_log_level_debug;
 
-	void (*totemsrp_log_printf) (char *file, int line, int level, char *format, ...) __attribute__((format(printf, 4, 5)));
+	int totemsrp_subsys_id;
+
+	void (*totemsrp_log_printf) (int subsys, char *function, char *file,
+		int line, unsigned int level, char *format,
+		...)__attribute__((format(printf, 6, 7)));;
 
 	enum memb_state memb_state;
 
@@ -607,8 +611,12 @@ struct message_handlers totemsrp_message_handlers = {
 
 static char *rundir = NULL;
 
-#define log_printf(level, format, args...) \
-    instance->totemsrp_log_printf (__FILE__, __LINE__, level, format, ##args)
+#define log_printf(level, format, args...)				\
+do {									\
+	instance->totemsrp_log_printf (instance->totemsrp_subsys_id,	\
+		(char *)__FUNCTION__, __FILE__, __LINE__, level,	\
+		format, ##args);					\
+} while (0);
 
 void totemsrp_instance_initialize (struct totemsrp_instance *instance)
 {
@@ -709,6 +717,7 @@ int totemsrp_initialize (
 	instance->totemsrp_log_level_warning = totem_config->totem_logging_configuration.log_level_warning;
 	instance->totemsrp_log_level_notice = totem_config->totem_logging_configuration.log_level_notice;
 	instance->totemsrp_log_level_debug = totem_config->totem_logging_configuration.log_level_debug;
+	instance->totemsrp_subsys_id = totem_config->totem_logging_configuration.log_subsys_id;
 	instance->totemsrp_log_printf = totem_config->totem_logging_configuration.log_printf;
 
 	/*

exec/util.c

@@ -87,7 +87,6 @@ void _corosync_exit_error (
 {
 	log_printf (LOG_LEVEL_ERROR, "AIS Executive exiting "
 		"with status %d at %s:%u.\n", err, file, line);
-	logsys_flush();
 	exit (EXIT_FAILURE);
 }
 

include/corosync/engine/logsys.h

@@ -1,6 +1,6 @@
 /*
  * Copyright (c) 2002-2004 MontaVista Software, Inc.
- * Copyright (c) 2006-2007 Red Hat, Inc.
+ * Copyright (c) 2006-2008 Red Hat, Inc.
  *
  * Author: Steven Dake (sdake@redhat.com)
  * Author: Lon Hohberger (lhh@redhat.com)
@@ -41,21 +41,14 @@
 #include <assert.h>
 
 /*
- * MODE_OUTPUT_SYSLOG_* modes are mutually exclusive
+ * All of the LOG_MODE's can be ORed together for combined behavior
  */
 #define LOG_MODE_OUTPUT_FILE		(1<<0)
 #define LOG_MODE_OUTPUT_STDERR		(1<<1)
-#define LOG_MODE_OUTPUT_SYSLOG_THREADED	(1<<2)
-#define LOG_MODE_OUTPUT_SYSLOG_LOSSY	(1<<3)
-#define LOG_MODE_OUTPUT_SYSLOG_BLOCKING	(1<<4)
-#define LOG_MODE_DISPLAY_PRIORITY	(1<<5)
-#define LOG_MODE_DISPLAY_FILELINE	(1<<6)
-#define LOG_MODE_DISPLAY_TIMESTAMP	(1<<7)
-#define LOG_MODE_BUFFER_BEFORE_CONFIG	(1<<8)
-#define LOG_MODE_FLUSH_AFTER_CONFIG	(1<<9)
-#define LOG_MODE_SHORT_FILELINE		(1<<10)
-#define LOG_MODE_NOSUBSYS		(1<<11)
-#define LOG_MODE_FILTER_DEBUG_FROM_SYSLOG	(1<<12)
+#define LOG_MODE_OUTPUT_SYSLOG		(1<<3)
+#define LOG_MODE_NOSUBSYS		(1<<4)
+#define LOG_MODE_FORK			(1<<5)
+#define LOG_MODE_THREADED		(1<<6)
 
 /*
  * Log priorities, compliant with syslog and SA Forum Log spec.
@@ -71,37 +64,23 @@
 #define LOG_LEVEL_DEBUG			LOG_DEBUG
 
 /*
-** Log tags, used by _logsys_trace macros, uses 32 bits => 32 different tags
-*/	
-#define LOGSYS_TAG_LOG	    		(1<<0)
-#define LOGSYS_TAG_ENTER		(1<<1)
-#define LOGSYS_TAG_LEAVE		(1<<2)
-#define LOGSYS_TAG_TRACE1		(1<<3)
-#define LOGSYS_TAG_TRACE2		(1<<4)
-#define LOGSYS_TAG_TRACE3		(1<<5)
-#define LOGSYS_TAG_TRACE4		(1<<6)
-#define LOGSYS_TAG_TRACE5		(1<<7)
-#define LOGSYS_TAG_TRACE6		(1<<8)
-#define LOGSYS_TAG_TRACE7		(1<<9)
-#define LOGSYS_TAG_TRACE8		(1<<10)
+ * The tag masks are all mutually exclusive
+ */	
+#define LOGSYS_TAG_LOG			(0xff<<28)
+#define LOGSYS_TAG_ENTER		(1<<27)
+#define LOGSYS_TAG_LEAVE		(1<<26)
+#define LOGSYS_TAG_TRACE1		(1<<25)
+#define LOGSYS_TAG_TRACE2		(1<<24)
+#define LOGSYS_TAG_TRACE3		(1<<23)
+#define LOGSYS_TAG_TRACE4		(1<<22)
+#define LOGSYS_TAG_TRACE5		(1<<21)
+#define LOGSYS_TAG_TRACE6		(1<<20)
+#define LOGSYS_TAG_TRACE7		(1<<19)
+#define LOGSYS_TAG_TRACE8		(1<<18)
 
 /*
  * External API
  */
-
-struct logsys_logger {
-	char subsys[6];
-	unsigned int priority;
-	unsigned int tags;
-	unsigned int mode;
-};
-
-extern struct logsys_logger logsys_loggers[];
-
-extern int logsys_single_id;
-
-extern inline int logsys_mkpri (int priority, int id);
-
 extern void logsys_config_mode_set (
 	unsigned int mode);
 
@@ -115,6 +94,9 @@ extern void logsys_config_facility_set (
 	char *name,
 	unsigned int facility);
 
+extern void logsys_format_set (
+	char *format);
+
 extern unsigned int logsys_config_subsys_set (
 	const char *subsys,
 	unsigned int tags,
@@ -137,33 +119,54 @@ extern int logsys_priority_id_get (
 extern const char *logsys_priority_name_get (
 	unsigned int priority);
 
+extern void logsys_fork_completed (void);
+
 extern void logsys_flush (void);
 
 extern void logsys_atsegv (void);
 
+extern int logsys_log_rec_store (char *filename);
+
 /*
  * Internal APIs that must be globally exported
  */
-extern unsigned int _logsys_subsys_create (const char *ident,
+extern unsigned int _logsys_subsys_create (
+	const char *ident,
 	unsigned int priority);
 
 extern void _logsys_nosubsys_set (void);
 
-extern int _logsys_wthread_create (void);
-
-extern void logsys_log_printf (char *file, int line, int priority,
-	char *format, ...) __attribute__((format(printf, 4, 5)));
-
-extern void _logsys_log_printf2 (char *file, int line, int priority,
-	int id, char *format, ...) __attribute__((format(printf, 5, 6)));
+extern int _logsys_rec_init (unsigned int size);
+
+extern void _logsys_log_printf (
+	int subsys,
+	char *function_name,
+	char *file_name,
+	int file_line,
+	unsigned int level,
+	char *format,
+	...) __attribute__((format(printf, 6, 7)));
+
+extern void _logsys_log_rec (
+	int subsys,
+	char *function_name,
+	char *file_name,
+	int file_line,
+	unsigned int rec_ident,
+	...);
 
-extern void _logsys_trace (char *file, int line, int tag, int id,
-	char *format, ...) __attribute__((format(printf, 5, 6)));
+extern int _logsys_wthread_create (void);
 
+static unsigned int logsys_subsys_id __attribute__((unused)) = -1;
+									
 /*
  * External definitions
  */
-#define LOGSYS_DECLARE_SYSTEM(name,mode,file,facility)			\
+extern void *logsys_rec_end;
+
+#define LOG_REC_END (&logsys_rec_end)
+
+#define LOGSYS_DECLARE_SYSTEM(name,mode,file,facility,format,rec_size)	\
 __attribute__ ((constructor)) static void logsys_system_init (void)	\
 {									\
 	char *error_string;						\
@@ -171,13 +174,11 @@ __attribute__ ((constructor)) static void logsys_system_init (void)	\
 	logsys_config_mode_set (mode);					\
 	logsys_config_file_set (&error_string, (file));			\
 	logsys_config_facility_set (name, (facility));			\
-        if (((mode) & LOG_MODE_BUFFER_BEFORE_CONFIG) == 0) {		\
-		_logsys_wthread_create ();				\
-	}								\
+	logsys_format_set (format);					\
+	_logsys_rec_init (rec_size);					\
+	_logsys_wthread_create();					\
 }
 
-static unsigned int logsys_subsys_id __attribute__((unused)) = -1;	\
-
 #define LOGSYS_DECLARE_NOSUBSYS(priority)				\
 __attribute__ ((constructor)) static void logsys_nosubsys_init (void)	\
 {									\
@@ -206,161 +207,88 @@ __attribute__ ((constructor)) static void logsys_subsys_init (void)	\
 			_logsys_subsys_create ((subsys), (priority));	\
 }
 
-#define log_printf(lvl, format, args...) do {				\
-	if (logsys_single_id)						\
-		logsys_subsys_id = 0;					\
-	assert (logsys_subsys_id != -1);				\
-	if ((lvl) <= logsys_loggers[logsys_subsys_id].priority)	{	\
-		_logsys_log_printf2 (__FILE__, __LINE__, lvl,		\
-			logsys_subsys_id, (format), ##args);		\
-	}								\
+#define log_rec(rec_ident, args...)					\
+do {									\
+	_logsys_log_rec (logsys_subsys_id, (char *) __FUNCTION__,	\
+		__FILE__,  __LINE__, rec_ident, ##args);		\
 } while(0)
 
-#define dprintf(format, args...) do {					\
-	if (logsys_single_id)						\
-		logsys_subsys_id = 0;					\
-	assert (logsys_subsys_id != -1);				\
-	if (LOG_LEVEL_DEBUG <= logsys_loggers[logsys_subsys_id].priority) { \
-		_logsys_log_printf2 (__FILE__, __LINE__, LOG_DEBUG,	\
-			logsys_subsys_id, (format), ##args);		\
-	}								\
+#define log_printf(lvl, format, args...)				\
+ do {									\
+	_logsys_log_printf (logsys_subsys_id, (char *) __FUNCTION__,	\
+		__FILE__, __LINE__, lvl, format, ##args);		\
 } while(0)
 
-#define ENTER_VOID() do {						\
-	if (logsys_single_id)						\
-		logsys_subsys_id = 0;					\
-	assert (logsys_subsys_id != -1);				\
-	if (LOG_LEVEL_DEBUG <= logsys_loggers[logsys_subsys_id].priority) { \
-		_logsys_trace (__FILE__, __LINE__, LOGSYS_TAG_ENTER,	\
-			logsys_subsys_id, ">%s\n", __FUNCTION__);	\
-	}								\
+#define ENTER() do {							\
+	_logsys_log_rec (logsys_subsys_id, (char *) __FUNCTION__,	\
+		__FILE__,  __LINE__, LOGSYS_TAG_ENTER, LOG_REC_END);	\
 } while(0)
 
-#define ENTER(format, args...) do {					\
-	if (logsys_single_id)						\
-		logsys_subsys_id = 0;					\
-	assert (logsys_subsys_id != -1);				\
-	if (LOG_LEVEL_DEBUG <= logsys_loggers[logsys_subsys_id].priority) { \
-		_logsys_trace (__FILE__, __LINE__, LOGSYS_TAG_ENTER,	\
-			logsys_subsys_id, ">%s: " format, __FUNCTION__,	\
-			##args);					\
-	}								\
-} while(0)
-
-#define LEAVE_VOID() do {						\
-	if (logsys_single_id)						\
-		logsys_subsys_id = 0;					\
-	assert (logsys_subsys_id != -1);				\
-	if (LOG_LEVEL_DEBUG <= logsys_loggers[logsys_subsys_id].priority) { \
-		_logsys_trace (__FILE__, __LINE__, LOGSYS_TAG_LEAVE,	\
-			logsys_subsys_id, "<%s\n", __FUNCTION__);	\
-	}								\
-} while(0)
-
-#define LEAVE(format, args...) do {					\
-	if (logsys_single_id)						\
-		logsys_subsys_id = 0;					\
-	assert (logsys_subsys_id != -1);				\
-	if (LOG_LEVEL_DEBUG <= logsys_loggers[logsys_subsys_id].priority) { \
-		_logsys_trace (__FILE__, __LINE__, LOGSYS_TAG_LEAVE,	\
-			logsys_subsys_id, "<%s: " format,		\
-			__FUNCTION__, ##args);				\
-	}								\
+#define LEAVE() do {							\
+	_logsys_log_rec (logsys_subsys_id, (char *) __FUNCTION__,	\
+		__FILE__,  __LINE__, LOGSYS_TAG_LEAVE, LOG_REC_END);	\
 } while(0)
 
 #define TRACE1(format, args...) do {					\
-	if (logsys_single_id)						\
-		logsys_subsys_id = 0;					\
-	assert (logsys_subsys_id != -1);				\
-	if (LOG_LEVEL_DEBUG <= logsys_loggers[logsys_subsys_id].priority) { \
-		_logsys_trace (__FILE__, __LINE__, LOGSYS_TAG_TRACE1,	\
-			logsys_subsys_id, (format), ##args);		\
-	}								\
+	_logsys_log_printf (logsys_subsys_id, (char *) __FUNCTION__,	\
+		__FILE__,  __LINE__, LOGSYS_TAG_TRACE1, format, ##args);\
 } while(0)
 
 #define TRACE2(format, args...) do {					\
-	if (logsys_single_id)						\
-		logsys_subsys_id = 0;					\
-	assert (logsys_subsys_id != -1);				\
-	if (LOG_LEVEL_DEBUG <= logsys_loggers[logsys_subsys_id].priority) { \
-		_logsys_trace (__FILE__, __LINE__, LOGSYS_TAG_TRACE2,	\
-			logsys_subsys_id, (format), ##args);		\
-	}								\
+	_logsys_log_printf (logsys_subsys_id, (char *) __FUNCTION__,	\
+		__FILE__,  __LINE__, LOGSYS_TAG_TRACE2, format, ##args);\
 } while(0)
 
-#define TRACE3(format, args...) do { \
-	if (logsys_single_id)						\
-		logsys_subsys_id = 0;					\
-	assert (logsys_subsys_id != -1);				\
-	if (LOG_LEVEL_DEBUG <= logsys_loggers[logsys_subsys_id].priority) { \
-		_logsys_trace (__FILE__, __LINE__, LOGSYS_TAG_TRACE3,	\
-			logsys_subsys_id, (format), ##args);		\
-    }									\
+#define TRACE3(format, args...) do {					\
+	_logsys_log_printf (logsys_subsys_id, (char *) __FUNCTION__,	\
+		__FILE__,  __LINE__, LOGSYS_TAG_TRACE3, format, ##args);\
 } while(0)
 
-#define TRACE4(format, args...) do { \
-	if (logsys_single_id)						\
-		logsys_subsys_id = 0;					\
-	assert (logsys_subsys_id != -1);				\
-	if (LOG_LEVEL_DEBUG <= logsys_loggers[logsys_subsys_id].priority) { \
-		_logsys_trace (__FILE__, __LINE__, LOGSYS_TAG_TRACE4,	\
-			logsys_subsys_id, (format), ##args);		\
-	}								\
+#define TRACE4(format, args...) do {					\
+	_logsys_log_printf (logsys_subsys_id, (char *) __FUNCTION__,	\
+		__FILE__,  __LINE__, LOGSYS_TAG_TRACE4, format, ##args);\
 } while(0)
 
 #define TRACE5(format, args...) do {					\
-	if (logsys_single_id)						\
-		logsys_subsys_id = 0;					\
-	assert (logsys_subsys_id != -1);				\
-	if (LOG_LEVEL_DEBUG <= logsys_loggers[logsys_subsys_id].priority) { \
-		_logsys_trace (__FILE__, __LINE__, LOGSYS_TAG_TRACE5,	\
-		logsys_subsys_id, (format), ##args);			\
-	}								\
+	_logsys_log_printf (logsys_subsys_id, (char *) __FUNCTION__,	\
+		__FILE__,  __LINE__, LOGSYS_TAG_TRACE5, format, ##args);\
 } while(0)
 
 #define TRACE6(format, args...) do {					\
-	if (logsys_single_id)						\
-		logsys_subsys_id = 0;					\
-	assert (logsys_subsys_id != -1);				\
-	if (LOG_LEVEL_DEBUG <= logsys_loggers[logsys_subsys_id].priority) { \
-		_logsys_trace (__FILE__, __LINE__, LOGSYS_TAG_TRACE6,	\
-			logsys_subsys_id, (format), ##args);		\
-	}								\
+	_logsys_log_printf (logsys_subsys_id, (char *) __FUNCTION__,	\
+		__FILE__,  __LINE__, LOGSYS_TAG_TRACE6, format, ##args);\
 } while(0)
 
 #define TRACE7(format, args...) do {					\
-	if (logsys_single_id)						\
-		logsys_subsys_id = 0;					\
-	assert (logsys_subsys_id != -1);				\
-	if (LOG_LEVEL_DEBUG <= logsys_loggers[logsys_subsys_id].priority) { \
-		_logsys_trace (__FILE__, __LINE__, LOGSYS_TAG_TRACE7,	\
-			 logsys_subsys_id, (format), ##args);		\
-	}								\
+	_logsys_log_printf (logsys_subsys_id, (char *) __FUNCTION__,	\
+		__FILE__,  __LINE__, LOGSYS_TAG_TRACE7, format, ##args);\
 } while(0)
 
 #define TRACE8(format, args...) do {					\
-	if (logsys_single_id)						\
-		logsys_subsys_id = 0;					\
-	assert (logsys_subsys_id != -1);				\
-	if (LOG_LEVEL_DEBUG <= logsys_loggers[logsys_subsys_id].priority) { \
-	_logsys_trace (__FILE__, __LINE__, LOGSYS_TAG_TRACE8,		\
-	 logsys_subsys_id, (format), ##args);				\
-	}								\
-} while(0)
-
-extern void _logsys_config_priority_set (unsigned int id, unsigned int priority);
-
-#define logsys_config_priority_set(priority) do {		        \
-	if (logsys_single_id)						\
-		logsys_subsys_id = 0;					\
-	assert (logsys_subsys_id != -1);				\
-	_logsys_config_priority_set (logsys_subsys_id, priority);       \
+	_logsys_log_printf (logsys_subsys_id, (char *) __FUNCTION__,	\
+		__FILE__,  __LINE__, LOGSYS_TAG_TRACE8, format, ##args);\
 } while(0)
 
-/* simple, function-based api */
+/*
+ * For one-time programmatic initialization and configuration of logsys
+ * instead of using the DECLARE macros.  These APIs do not allow subsystems
+ */
+int logsys_init (
+	char *name,
+	int mode,
+	int facility,
+	int priority,
+	char *file,
+	char *format,
+	int rec_size);
+
+int logsys_conf (
+	char *name,
+	int mode,
+	int facility,
+	int priority,
+	char *file);
 
-int logsys_init (char *name, int mode, int facility, int priority, char *file);
-int logsys_conf (char *name, int mode, int facility, int priority, char *file);
 void logsys_exit (void);
 
 #endif /* LOGSYS_H_DEFINED */

include/corosync/totem/totem.h

@@ -58,12 +58,21 @@ struct totem_interface {
 };
 
 struct totem_logging_configuration {
-	void (*log_printf) (char *, int, int, char *, ...) __attribute__((format(printf, 4, 5)));
+        void (*log_printf) (
+                int subsys,
+                char *function_name,
+                char *file_name,
+                int file_line,
+                unsigned int level,
+                char *format,
+                ...) __attribute__((format(printf, 6, 7)));
+
 	int log_level_security;
 	int log_level_error;
 	int log_level_warning;
 	int log_level_notice;
 	int log_level_debug;
+	int log_subsys_id;
 };
 
 struct totem_config {

services/cfg.c

@@ -264,8 +264,8 @@ int cfg_lib_exit_fn (void *conn)
 static int cfg_lib_init_fn (void *conn)
 {
 	
-	ENTER("");
-	LEAVE("");
+	ENTER();
+	LEAVE();
 
         return (0);
 }
@@ -281,7 +281,7 @@ static void message_handler_req_exec_cfg_ringreenable (
 		(struct req_exec_cfg_ringreenable *)message;
 	struct res_lib_cfg_ringreenable res_lib_cfg_ringreenable;
 
-	ENTER("");
+	ENTER();
 	api->totem_ring_reenable ();
         if (api->ipc_source_is_local(&req_exec_cfg_ringreenable->source)) {
 		res_lib_cfg_ringreenable.header.id = MESSAGE_RES_CFG_RINGREENABLE;
@@ -292,7 +292,7 @@ static void message_handler_req_exec_cfg_ringreenable (
 			&res_lib_cfg_ringreenable,
 			sizeof (struct res_lib_cfg_ringreenable));
 	}
-	LEAVE("");
+	LEAVE();
 }
 
 
@@ -310,7 +310,7 @@ static void message_handler_req_lib_cfg_ringstatusget (
 	char *totem_ip_string;
 	unsigned int i;
 
-	ENTER("");
+	ENTER();
 
 	res_lib_cfg_ringstatusget.header.id = MESSAGE_RES_CFG_RINGSTATUSGET;
 	res_lib_cfg_ringstatusget.header.size = sizeof (struct res_lib_cfg_ringstatusget);
@@ -336,7 +336,7 @@ static void message_handler_req_lib_cfg_ringstatusget (
 		&res_lib_cfg_ringstatusget,
 		sizeof (struct res_lib_cfg_ringstatusget));
 
-	LEAVE("");
+	LEAVE();
 }
 
 static void message_handler_req_lib_cfg_ringreenable (
@@ -346,7 +346,7 @@ static void message_handler_req_lib_cfg_ringreenable (
 	struct req_exec_cfg_ringreenable req_exec_cfg_ringreenable;
 	struct iovec iovec;
 
-	ENTER("");
+	ENTER();
 	req_exec_cfg_ringreenable.header.size =
 		sizeof (struct req_exec_cfg_ringreenable);
 	req_exec_cfg_ringreenable.header.id = SERVICE_ID_MAKE (CFG_SERVICE,
@@ -358,7 +358,7 @@ static void message_handler_req_lib_cfg_ringreenable (
 
 	assert (api->totem_mcast (&iovec, 1, TOTEM_SAFE) == 0);
 
-	LEAVE("");
+	LEAVE();
 }
 
 static void message_handler_req_lib_cfg_statetrack (
@@ -367,8 +367,8 @@ static void message_handler_req_lib_cfg_statetrack (
 {
 //	struct req_lib_cfg_statetrack *req_lib_cfg_statetrack = (struct req_lib_cfg_statetrack *)message;
 
-	ENTER("");
-	LEAVE("");
+	ENTER();
+	LEAVE();
 }
 
 static void message_handler_req_lib_cfg_statetrackstop (
@@ -377,8 +377,8 @@ static void message_handler_req_lib_cfg_statetrackstop (
 {
 //	struct req_lib_cfg_statetrackstop *req_lib_cfg_statetrackstop = (struct req_lib_cfg_statetrackstop *)message;
 
-	ENTER("");
-	LEAVE("");
+	ENTER();
+	LEAVE();
 }
 
 static void message_handler_req_lib_cfg_administrativestateset (
@@ -386,16 +386,16 @@ static void message_handler_req_lib_cfg_administrativestateset (
 	void *msg)
 {
 //	struct req_lib_cfg_administrativestateset *req_lib_cfg_administrativestateset = (struct req_lib_cfg_administrativestateset *)message;
-	ENTER("");
-	LEAVE("");
+	ENTER();
+	LEAVE();
 }
 static void message_handler_req_lib_cfg_administrativestateget (
 	void *conn,
 	void *msg)
 {
 //	struct req_lib_cfg_administrativestateget *req_lib_cfg_administrativestateget = (struct req_lib_cfg_administrativestateget *)message;
-	ENTER("");
-	LEAVE("");
+	ENTER();
+	LEAVE();
 }
 
 static void message_handler_req_lib_cfg_serviceload (
@@ -406,7 +406,7 @@ static void message_handler_req_lib_cfg_serviceload (
 		(struct req_lib_cfg_serviceload *)msg;
 	struct res_lib_cfg_serviceload res_lib_cfg_serviceload;
 
-	ENTER("");
+	ENTER();
 	api->service_link_and_init (
 		api,
 		(char *)req_lib_cfg_serviceload->service_name,
@@ -419,7 +419,7 @@ static void message_handler_req_lib_cfg_serviceload (
 		conn,
 		&res_lib_cfg_serviceload,
 		sizeof (struct res_lib_cfg_serviceload));
-	LEAVE("");
+	LEAVE();
 }
 
 static void message_handler_req_lib_cfg_serviceunload (
@@ -430,7 +430,7 @@ static void message_handler_req_lib_cfg_serviceunload (
 		(struct req_lib_cfg_serviceunload *)msg;
 	struct res_lib_cfg_serviceunload res_lib_cfg_serviceunload;
 
-	ENTER("");
+	ENTER();
 	api->service_unlink_and_exit (
 		api,
 		(char *)req_lib_cfg_serviceunload->service_name,
@@ -442,5 +442,5 @@ static void message_handler_req_lib_cfg_serviceunload (
 		conn,
 		&res_lib_cfg_serviceunload,
 		sizeof (struct res_lib_cfg_serviceunload));
-	LEAVE("");
+	LEAVE();
 }

test/Makefile

@@ -44,7 +44,7 @@ endif
 
 LIBRARIES= ../lib/libevs.a ../lib/libcpg.a ../lib/libcfg.a ../lib/libconfdb.a ../lib/libquorum.a
 LIBS = $(LIBRARIES) 
-BINARIES= testevs evsbench evsverify testcpg testcpg2 cpgbench testconfdb testquorum
+BINARIES= testevs evsbench evsverify testcpg testcpg2 cpgbench testconfdb logsysbench logsysrec testquorum
 
 override CFLAGS += -I../include
 override LDFLAGS += -L../lib
@@ -84,6 +84,12 @@ cpgbench: cpgbench.o $(LIBRARIES)
 testconfdb: testconfdb.o $(LIBRARIES)
 	$(CC) $(LDFLAGS) -o testconfdb testconfdb.o $(LIBS) -rdynamic
 
+logsysbench: logsysbench.o ../exec/liblogsys.a
+	$(CC) -o logsysbench logsysbench.o ../exec/liblogsys.a $(LDFLAGS)
+
+logsysrec: logsysrec.o ../exec/liblogsys.a
+	$(CC) -o logsysrec logsysrec.o ../exec/liblogsys.a $(LDFLAGS)
+
 logsys_s: logsys_s.o logsys_s1.o logsys_s2.o ../exec/liblogsys.a
 	$(CC) -o logsys_s logsys_s.o logsys_s1.o logsys_s2.o ../exec/liblogsys.a $(LDFLAGS)
 

test/logsys_s.c

@@ -38,7 +38,9 @@
 LOGSYS_DECLARE_SYSTEM ("logsystestsubsystems",
 	LOG_MODE_OUTPUT_STDERR | LOG_MODE_OUTPUT_SYSLOG_THREADED, 
 	NULL,
-	LOG_DAEMON);
+	LOG_DAEMON,
+	"[%8s] %b",
+	100000);
 
 extern void logsys_s1_print (void);
 extern void logsys_s2_print (void);

test/logsys_t1.c

@@ -38,7 +38,9 @@
 LOGSYS_DECLARE_SYSTEM ("logsystestNOsubsystems",
 	LOG_MODE_OUTPUT_STDERR | LOG_MODE_OUTPUT_SYSLOG_THREADED, 
 	NULL,
-	LOG_DAEMON);
+	LOG_DAEMON,
+	"%6s %b",
+	100000);
 
 LOGSYS_DECLARE_NOSUBSYS(LOG_LEVEL_DEBUG);
 

test/logsys_t2.c

@@ -36,9 +36,11 @@
 #include "../exec/logsys.h"
 
 LOGSYS_DECLARE_SYSTEM ("logtest_t2",
-	LOG_MODE_OUTPUT_STDERR | LOG_MODE_OUTPUT_SYSLOG_THREADED | LOG_MODE_BUFFER_BEFORE_CONFIG,
+	LOG_MODE_OUTPUT_STDERR | LOG_MODE_THREADED,
 	NULL,
-	LOG_DAEMON);
+	LOG_DAEMON,
+	"[%6s] %b"
+	100000);
 
 LOGSYS_DECLARE_NOSUBSYS(LOG_LEVEL_INFO);
 
@@ -48,7 +50,7 @@ main(int argc, char **argv)
 	/*
 	 * fork could occur here and the file to output to could be set
 	 */
-	logsys_config_mode_set (LOG_MODE_OUTPUT_STDERR | LOG_MODE_OUTPUT_SYSLOG_THREADED | LOG_MODE_FLUSH_AFTER_CONFIG);
+	logsys_config_mode_set (LOG_MODE_OUTPUT_STDERR | LOG_MODE_THREADED);
 
 	log_printf(LOG_NOTICE, "Hello, world!\n");
 	log_printf(LOG_DEBUG, "If you see this, the logger's busted\n");

test/logsysbench.c

@@ -0,0 +1,171 @@
+/*
+ * Copyright (c) 2008 Red Hat, Inc.
+ *
+ * All rights reserved.
+ *
+ * Author: Steven Dake (sdake@redhat.com)
+ *
+ * This software licensed under BSD license, the text of which follows:
+ * 
+ * Redistribution and use in source and binary forms, with or without
+ * modification, are permitted provided that the following conditions are met:
+ *
+ * - Redistributions of source code must retain the above copyright notice,
+ *   this list of conditions and the following disclaimer.
+ * - Redistributions in binary form must reproduce the above copyright notice,
+ *   this list of conditions and the following disclaimer in the documentation
+ *   and/or other materials provided with the distribution.
+ * - Neither the name of the MontaVista Software, Inc. nor the names of its
+ *   contributors may be used to endorse or promote products derived from this
+ *   software without specific prior written permission.
+ *
+ * THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS "AS IS"
+ * AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
+ * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE
+ * ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT OWNER OR CONTRIBUTORS BE
+ * LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR
+ * CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF
+ * SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS
+ * INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN
+ * CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE)
+ * ARISING IN ANY WAY OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF
+ * THE POSSIBILITY OF SUCH DAMAGE.
+ */
+#include <stdio.h>
+#include <stdint.h>
+#include <string.h>
+#include <sys/time.h>
+#include <time.h>
+#include <corosync/engine/logsys.h>
+
+LOGSYS_DECLARE_SYSTEM ("logtest_rec",
+	LOG_MODE_OUTPUT_STDERR | LOG_MODE_THREADED,
+	NULL,
+	LOG_DAEMON,
+	"[%6s] %b",
+	100000);
+
+LOGSYS_DECLARE_NOSUBSYS(LOG_LEVEL_INFO);
+
+#define LOGREC_ID_CHECKPOINT_CREATE 2
+#define LOGREC_ARGS_CHECKPOINT_CREATE 2
+#define ITERATIONS 1000000
+
+struct timeval tv1, tv2, tv_elapsed;
+
+#define timersub(a, b, result)					\
+do {								\
+	(result)->tv_sec = (a)->tv_sec - (b)->tv_sec;		\
+	(result)->tv_usec = (a)->tv_usec - (b)->tv_usec;	\
+	if ((result)->tv_usec < 0) {				\
+		--(result)->tv_sec;				\
+		(result)->tv_usec += 1000000;			\
+	}							\
+} while (0)
+
+void bm_start (void)
+{
+        gettimeofday (&tv1, NULL);
+}
+void bm_finish (char *operation)
+{
+        gettimeofday (&tv2, NULL);
+        timersub (&tv2, &tv1, &tv_elapsed);
+
+	if (strlen (operation) > 22) {
+        	printf ("%s\t\t", operation);
+	} else {
+        	printf ("%s\t\t\t", operation);
+	}
+        printf ("%9.3f operations/sec\n",
+                ((float)ITERATIONS) /  (tv_elapsed.tv_sec + (tv_elapsed.tv_usec / 1000000.0)));
+}
+
+char buffer[256];
+int main (void)
+{
+	int i;
+	char buf[1024];
+
+
+	printf ("heating up cache with logrec functionality\n");
+	for (i = 0; i < ITERATIONS; i++) {
+	log_rec (LOGREC_ID_CHECKPOINT_CREATE,
+		"recordA", 8, "recordB", 8, LOG_REC_END);
+	}
+	bm_start();
+	for (i = 0; i < ITERATIONS; i++) {
+	log_rec (LOGREC_ID_CHECKPOINT_CREATE,
+		buffer, 7, LOG_REC_END);
+	}
+	bm_finish ("log_rec 1 arguments:");
+	bm_start();
+	for (i = 0; i < ITERATIONS; i++) {
+	log_rec (LOGREC_ID_CHECKPOINT_CREATE,
+		"recordA", 8, LOG_REC_END);
+	}
+	bm_finish ("log_rec 2 arguments:");
+	bm_start();
+	for (i = 0; i < 10; i++) {
+	log_rec (LOGREC_ID_CHECKPOINT_CREATE,
+		"recordA", 8, "recordB", 8, LOG_REC_END);
+	}
+	bm_start();
+	for (i = 0; i < ITERATIONS; i++) {
+	log_rec (LOGREC_ID_CHECKPOINT_CREATE,
+		"recordA", 8, "recordB", 8, "recordC", 8, LOG_REC_END);
+	}
+	bm_finish ("log_rec 3 arguments:");
+	bm_start();
+	for (i = 0; i < ITERATIONS; i++) {
+	log_rec (LOGREC_ID_CHECKPOINT_CREATE,
+		"recordA", 8, "recordB", 8, "recordC", 8, "recordD", 8, LOG_REC_END);
+	}
+	bm_finish ("log_rec 4 arguments:");
+
+	/*
+	 * sprintf testing
+	 */
+	printf ("heating up cache with sprintf functionality\n");
+	for (i = 0; i < ITERATIONS; i++) {
+		sprintf (buf, "Some logging information %s", "recordA");
+	}
+	bm_start();
+	for (i = 0; i < ITERATIONS; i++) {
+		sprintf (buf, "Some logging information %s", "recordA");
+	}
+	bm_finish ("sprintf 1 argument:");
+	bm_start();
+	for (i = 0; i < ITERATIONS; i++) {
+		sprintf (buf, "Some logging information %s %s", "recordA", "recordB");
+	}
+	bm_finish ("sprintf 2 arguments:");
+	bm_start();
+	for (i = 0; i < ITERATIONS; i++) {
+		sprintf (buf, "Some logging information %s %s %s", "recordA", "recordB", "recordC");
+	}
+	bm_finish ("sprintf 3 arguments:");
+	bm_start();
+	for (i = 0; i < ITERATIONS; i++) {
+		sprintf (buf, "Some logging information %s %s %s %s", "recordA", "recordB", "recordC", "recordD");
+	}
+	bm_finish ("sprintf 4 arguments:");
+	bm_start();
+	for (i = 0; i < ITERATIONS; i++) {
+		sprintf (buf, "Some logging information %s %s %s %d", "recordA", "recordB", "recordC", i);
+	}
+	bm_finish ("sprintf 4 arguments (1 int):");
+
+	logsys_log_rec_store ("fdata");
+/* TODO
+	currently fails under some circumstances
+
+	bm_start();
+	for (i = 0; i < ITERATIONS; i++) {
+	log_printf (LOG_LEVEL_NOTICE, "test %d", i);
+	}
+	bm_finish("log_printf");
+*/
+
+	return (0);
+}

test/logsysrec.c

@@ -0,0 +1,62 @@
+/*
+ * Copyright (c) 2008 Red Hat, Inc.
+ *
+ * All rights reserved.
+ *
+ * Author: Steven Dake (sdake@redhat.com)
+ *
+ * This software licensed under BSD license, the text of which follows:
+ * 
+ * Redistribution and use in source and binary forms, with or without
+ * modification, are permitted provided that the following conditions are met:
+ *
+ * - Redistributions of source code must retain the above copyright notice,
+ *   this list of conditions and the following disclaimer.
+ * - Redistributions in binary form must reproduce the above copyright notice,
+ *   this list of conditions and the following disclaimer in the documentation
+ *   and/or other materials provided with the distribution.
+ * - Neither the name of the MontaVista Software, Inc. nor the names of its
+ *   contributors may be used to endorse or promote products derived from this
+ *   software without specific prior written permission.
+ *
+ * THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS "AS IS"
+ * AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
+ * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE
+ * ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT OWNER OR CONTRIBUTORS BE
+ * LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR
+ * CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF
+ * SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS
+ * INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN
+ * CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE)
+ * ARISING IN ANY WAY OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF
+ * THE POSSIBILITY OF SUCH DAMAGE.
+ */
+#include <stdio.h>
+#include <stdint.h>
+#include <corosync/engine/logsys.h>
+
+LOGSYS_DECLARE_SYSTEM ("logtest_rec",
+	LOG_MODE_OUTPUT_STDERR | LOG_MODE_THREADED,
+	NULL,
+	LOG_DAEMON,
+	"[%6s] %b",
+	100000);
+
+LOGSYS_DECLARE_NOSUBSYS(LOG_LEVEL_INFO);
+
+#define LOGREC_ID_CHECKPOINT_CREATE 2
+#define LOGREC_ARGS_CHECKPOINT_CREATE 2
+
+int main(int argc, char **argv)
+{
+	int i;
+
+	for (i = 0; i < 10; i++) {
+		log_printf (LOG_LEVEL_NOTICE, "This is a test of %s\n", "stringparse");
+
+		log_rec (LOGREC_ID_CHECKPOINT_CREATE, "record1", 8, "record22", 9, "record333", 10, "record444", 11, LOG_REC_END);
+	}
+	logsys_log_rec_store ("fdata");
+
+	return 0;
+}

tools/Makefile

@@ -42,7 +42,7 @@ ifeq (${COROSYNC_COMPAT}, SOLARIS)
 endif
 
 LIBS = ../lib/libconfdb.a ../lib/libcfg.a
-BINARIES=corosync-objctl corosync-cfgtool corosync-keygen
+BINARIES=corosync-objctl corosync-cfgtool corosync-keygen corosync-fplay
 APPS_SRC=$(addsuffix .c,$(BINARIES))
 EXTRA_CFLAGS = -I$(srcdir)include
 
@@ -57,6 +57,9 @@ corosync-cfgtool: corosync-cfgtool.o $(LIBS)
 corosync-keygen: corosync-keygen.o
 	$(CC) $(LDFLAGS) -o $@ $<
 
+corosync-fplay: corosync-fplay.o
+	$(CC) $(LDFLAGS) -o $@ $<
+
 clean:
 	rm -f *.o $(BINARIES)
 

tools/corosync-fplay.c

@@ -0,0 +1,479 @@
+#include <sys/types.h>
+#include <sys/stat.h>
+#include <fcntl.h>
+#include <stdio.h>
+#include <unistd.h>
+#include <string.h>
+#include <stdlib.h>
+#include <assert.h>
+#include <stdint.h>
+
+#include <sys/socket.h>
+#include <netinet/in.h>
+#include <sys/types.h>
+#include <sys/socket.h>
+#include <arpa/inet.h>
+
+#include <corosync/engine/logsys.h>
+
+unsigned int flt_data_size = 1000000;
+
+unsigned int *flt_data;
+#define FDHEAD_INDEX		(flt_data_size)
+#define FDTAIL_INDEX		(flt_data_size + 1)
+
+#define TOTEMIP_ADDRLEN (sizeof(struct in6_addr))
+
+struct totem_ip_address {
+        unsigned int   nodeid;
+        unsigned short family;
+        unsigned char  addr[TOTEMIP_ADDRLEN];
+} __attribute__((packed));
+
+struct memb_ring_id {
+        struct totem_ip_address rep;
+        unsigned long long seq;
+} __attribute__((packed));
+
+const char *totemip_print(struct totem_ip_address *addr)
+{
+	static char buf[INET6_ADDRSTRLEN];
+
+	return inet_ntop(addr->family, addr->addr, buf, sizeof(buf));
+}
+
+char *print_string_len (unsigned char *str, unsigned int len)
+{
+	unsigned int i;
+	static char buf[1024];
+	memset (buf, 0, sizeof (buf));
+	for (i = 0; i < len; i++) {
+		buf[i] = str[i];
+	}
+	return (buf);
+}
+
+void sync_printer_confchg_set_sync (void **record)
+{
+	unsigned int *my_should_sync = record[0];
+	printf ("Setting my_should_sync to %d\n", *my_should_sync);
+}
+
+void sync_printer_set_sync_state (void **record)
+{
+	unsigned int *my_sync_state = record[0];
+	printf ("Setting my_sync_state to %d\n", *my_sync_state);
+}
+
+void sync_printer_process_currentstate (void **record)
+{
+	unsigned int *my_sync_state = record[0];
+	printf ("Retrieving my_sync_state %d\n", *my_sync_state);
+}
+
+void sync_printer_process_get_shouldsync (void **record)
+{
+	unsigned int *my_should_sync = record[0];
+	printf ("Getting my_should_sync %d\n", *my_should_sync);
+}
+
+void sync_printer_checkpoint_release (void **record)
+{
+	unsigned char *name = record[0];
+	uint16_t *name_len = record[1];
+	unsigned int *ckpt_id = record[2];
+	unsigned int *from = record[3];
+
+	printf ("Checkpoint release name=[%s] id=[%d] from=[%d] len=[%d]\n",
+		print_string_len (name, *name_len),
+		*ckpt_id,
+		*from,
+		*name_len);
+}
+
+void sync_printer_checkpoint_transmit (void **record)
+{
+	unsigned char *name = record[0];
+	uint16_t *name_len = record[1];
+	unsigned int *ckpt_id = record[2];
+	unsigned int *xmit_id = record[3];
+
+	printf ("xmit_id=[%d] Checkpoint transmit name=[%s] id=[%d]\n",
+		*xmit_id, print_string_len (name, *name_len),
+		*ckpt_id);
+}
+
+void sync_printer_section_transmit (void **record)
+{
+	unsigned char *ckpt_name = record[0];
+	uint16_t *name_len = record[1];
+	unsigned int *ckpt_id = record[2];
+	unsigned int *xmit_id = record[3];
+	unsigned char *section_name = record[4];
+	uint16_t *section_name_len = record[5];
+	
+	printf ("xmit_id=[%d] Section transmit checkpoint name=[%s] id=[%d] ",
+		*xmit_id, print_string_len (ckpt_name, *name_len),
+		*ckpt_id);
+	printf ("section=[%s]\n",
+		print_string_len (section_name, *section_name_len));
+}
+void sync_printer_checkpoint_receive (void **record)
+{
+	unsigned char *ckpt_name = record[0];
+	uint16_t *name_len = record[1];
+	unsigned int *ckpt_id = record[2];
+	unsigned int *xmit_id = record[3];
+	
+	printf ("xmit_id=[%d] Checkpoint receive checkpoint name=[%s] id=[%d]\n",
+		*xmit_id, print_string_len (ckpt_name, *name_len), *ckpt_id);
+}
+
+void sync_printer_section_receive (void **record)
+{
+	unsigned char *ckpt_name = record[0];
+	uint16_t *name_len = record[1];
+	unsigned int *ckpt_id = record[2];
+	unsigned int *xmit_id = record[3];
+	unsigned char *section_name = record[4];
+	unsigned int *section_name_len = record[5];
+
+	printf ("xmit_id=[%d] Section receive checkpoint name=[%s] id=[%d] ",
+		*xmit_id, print_string_len (ckpt_name, *name_len),
+		*ckpt_id);
+
+	printf ("section=[%s]\n",
+		print_string_len (section_name, *section_name_len));
+}
+
+void sync_printer_nada (void **record)
+{
+printf ("nada\n");
+}
+void sync_printer_confchg_fn (void **record)
+{
+	unsigned int i;
+
+	unsigned int *members = record[0];
+	unsigned int *member_count = record[1];
+	struct memb_ring_id *ring_id = record[2];
+	struct in_addr addr;
+
+	printf ("sync confchg fn ringid [ip=%s seq=%lld]\n",
+		totemip_print (&ring_id->rep),
+		ring_id->seq);
+	printf ("members [%d]:\n", *member_count);
+	for (i = 0; i < *member_count; i++) {
+		addr.s_addr = members[i];
+		printf ("\tmember [%s]\n", inet_ntoa (addr));
+	}
+}
+
+void printer_totemsrp_mcast (void **record)
+{
+	unsigned int *msgid = record[0];
+
+	printf ("totemsrp_mcast %d\n", *msgid);
+}
+
+void printer_totemsrp_delv (void **record)
+{
+	unsigned int *msgid = record[0];
+
+	printf ("totemsrp_delv %d\n", *msgid);
+}
+
+void printer_totempg_mcast_fits (void **record)
+{
+	unsigned int *index = record[0];
+	unsigned int *iov_len = record[1];
+	unsigned int *copy_len = record[2];
+	unsigned int *fragment_size = record[3];
+	unsigned int *max_packet_size = record[4];
+	unsigned int *copy_base = record[5];
+	unsigned char *next_fragment = record[6];
+
+	printf ("totempg_mcast index=[%d] iov_len=[%d] copy_len=[%d] fragment_size=[%d] max_packet_size=[%d] copy_base=[%d] next_fragment[%d]\n",
+	*index, *iov_len, *copy_len, *fragment_size, *max_packet_size, *copy_base, *next_fragment);
+}
+
+void sync_printer_service_process (void **record)
+{
+	struct memb_ring_id *ring_id = record[0];
+	struct memb_ring_id *sync_ring_id = record[1];
+
+	printf ("sync service process callback ringid [ip=%s seq=%lld] ",
+		totemip_print (&ring_id->rep),
+		ring_id->seq);
+	printf ("sync ringid [ip=%s seq=%lld]\n",
+		totemip_print (&sync_ring_id->rep),
+		sync_ring_id->seq);
+}
+
+struct printer_subsys_record_print {
+	int ident;
+	void (*print_fn)(void **record);
+	int record_length;
+};
+
+struct printer_subsys {
+	char *subsys;
+	struct printer_subsys_record_print *record_printers;
+	int record_printers_count;
+};
+
+#define LOGREC_ID_SYNC_CONFCHG_FN 0
+#define LOGREC_ID_SYNC_SERVICE_PROCESS 1
+
+/*
+ * CKPT subsystem
+ */
+#define LOGREC_ID_CONFCHG_SETSYNC 0
+#define LOGREC_ID_SETSYNCSTATE 1
+#define LOGREC_ID_SYNC_PROCESS_CURRENTSTATE 2
+#define LOGREC_ID_SYNC_PROCESS_GETSHOULDSYNC 3
+#define LOGREC_ID_SYNC_CHECKPOINT_TRANSMIT 4
+#define LOGREC_ID_SYNC_SECTION_TRANSMIT 5
+#define LOGREC_ID_SYNC_CHECKPOINT_RECEIVE 6
+#define LOGREC_ID_SYNC_SECTION_RECEIVE 7
+#define LOGREC_ID_SYNC_CHECKPOINT_RELEASE 8
+
+#define LOGREC_ID_TOTEMSRP_MCAST 0
+#define LOGREC_ID_TOTEMSRP_DELV 1
+#define LOGREC_ID_TOTEMPG_MCAST_FITS 2
+
+
+struct printer_subsys_record_print record_print_sync[] = {
+	{
+		.ident				= LOGREC_ID_SYNC_CONFCHG_FN,
+		.print_fn			= sync_printer_confchg_fn,
+		.record_length			= 28
+	},
+	{
+		.ident				= LOGREC_ID_SYNC_SERVICE_PROCESS,
+		.print_fn			= sync_printer_service_process,
+		.record_length			= 28
+	}
+};
+
+struct printer_subsys_record_print record_print_ckpt[] = {
+	{
+		.ident				= LOGREC_ID_CONFCHG_SETSYNC,
+		.print_fn			= sync_printer_confchg_set_sync,
+		.record_length			= 28
+	},
+	{
+		.ident				= LOGREC_ID_SETSYNCSTATE,
+		.print_fn			= sync_printer_set_sync_state,
+		.record_length			= 28
+	},
+	{
+		.ident				= LOGREC_ID_SYNC_PROCESS_CURRENTSTATE,
+		.print_fn			= sync_printer_process_currentstate,
+		.record_length			= 28
+	},
+	{
+		.ident				= LOGREC_ID_SYNC_PROCESS_GETSHOULDSYNC,
+		.print_fn			= sync_printer_process_get_shouldsync,
+		.record_length			= 28
+	},
+	{
+		.ident				= LOGREC_ID_SYNC_CHECKPOINT_TRANSMIT,
+		.print_fn			= sync_printer_checkpoint_transmit,
+		.record_length			= 28
+	},
+	{
+		.ident				= LOGREC_ID_SYNC_SECTION_TRANSMIT,
+		.print_fn			= sync_printer_section_transmit,
+		.record_length			= 28
+	},
+	{
+		.ident				= LOGREC_ID_SYNC_CHECKPOINT_RECEIVE,
+		.print_fn			= sync_printer_checkpoint_receive,
+		.record_length			= 28
+	},
+	{
+		.ident				= LOGREC_ID_SYNC_SECTION_RECEIVE,
+		.print_fn			= sync_printer_section_receive,
+		.record_length			= 28
+	},
+	{
+		.ident				= LOGREC_ID_SYNC_CHECKPOINT_RELEASE,
+		.print_fn			= sync_printer_checkpoint_release,
+		.record_length			= 28
+	}
+
+};
+struct printer_subsys_record_print record_print_totem[] = {
+	{
+		.ident				= LOGREC_ID_TOTEMSRP_MCAST,
+		.print_fn			= printer_totemsrp_mcast,
+		.record_length			= 28
+	},
+	{
+		.ident				= LOGREC_ID_TOTEMSRP_DELV,
+		.print_fn			= printer_totemsrp_delv,
+		.record_length			= 28
+	},
+	{
+		.ident				= LOGREC_ID_TOTEMPG_MCAST_FITS,
+		.print_fn			= printer_totempg_mcast_fits,
+		.record_length			= 28
+	}
+};
+
+struct printer_subsys printer_subsystems[] = {
+	{
+		.subsys =			"SYNC",
+		.record_printers = 		record_print_sync,
+		.record_printers_count = 	sizeof (record_print_sync) / sizeof (struct printer_subsys_record_print)
+	},
+	{
+		.subsys =			"CKPT",
+		.record_printers = 		record_print_ckpt,
+		.record_printers_count = 	sizeof (record_print_ckpt) / sizeof (struct printer_subsys_record_print)
+	},
+	{
+		.subsys =			"TOTEM",
+		.record_printers = 		record_print_totem,
+		.record_printers_count = 	sizeof (record_print_totem) / sizeof (struct printer_subsys_record_print)
+	}
+};
+
+unsigned int printer_subsys_count = sizeof (printer_subsystems) / sizeof (struct printer_subsys);
+	
+unsigned int records_printed = 1;
+
+unsigned int record[10000];
+
+/*
+ * Copy record, dealing with wrapping
+ */
+int logsys_rec_get (int rec_idx) {
+	unsigned int rec_size;
+	int firstcopy, secondcopy;
+
+	rec_size = flt_data[rec_idx];
+
+	firstcopy = rec_size;
+	secondcopy = 0;
+	if (firstcopy + rec_idx > flt_data_size) {
+		firstcopy = flt_data_size - rec_idx; 
+		secondcopy -= firstcopy - rec_size;
+	}
+	memcpy (&record[0], &flt_data[rec_idx], firstcopy<<2);
+	if (secondcopy) {
+		memcpy (&record[firstcopy], &flt_data[0], secondcopy<<2);
+	}
+	return ((rec_idx + rec_size) % flt_data_size);
+}
+
+void logsys_rec_print (void *record)
+{
+	unsigned int *buf_uint32t = (unsigned int *)record;
+	unsigned int rec_size;
+	unsigned int rec_ident;
+	unsigned int line;
+	unsigned int arg_size_idx;
+	unsigned int i;
+	unsigned int j;
+	unsigned int rec_idx = 0;
+	unsigned int record_number;
+	unsigned int words_processed;
+	unsigned int found;
+	void *arguments[64];
+	int arg_count = 0;
+
+	rec_size = buf_uint32t[rec_idx];
+	rec_ident = buf_uint32t[rec_idx+1];
+	line = buf_uint32t[rec_idx+2];
+	record_number = buf_uint32t[rec_idx+3];
+
+printf ("rec=[%d] ", record_number);
+	arg_size_idx = rec_idx + 4;
+	words_processed = 4;
+	for (i = 0; words_processed < rec_size; i++) {
+		arguments[arg_count++] = &buf_uint32t[arg_size_idx + 1];
+		words_processed += buf_uint32t[arg_size_idx] + 1;
+		arg_size_idx += buf_uint32t[arg_size_idx] + 1;
+		
+	}
+
+	found = 0;
+	for (i = 0; i < printer_subsys_count; i++) {
+		if (strcmp ((char *)arguments[0], printer_subsystems[i].subsys) == 0) {
+			for (j = 0; j < printer_subsystems[i].record_printers_count; j++) {
+				if (rec_ident == printer_subsystems[i].record_printers[j].ident) {
+					printer_subsystems[i].record_printers[j].print_fn (&arguments[3]);
+					found = 1;
+				}
+			}
+		}	
+	}
+	if (rec_ident & LOGSYS_TAG_LOG) {
+		printf ("Log Message=%s\n", (char *)arguments[3]);
+		found = 1;
+	}
+	if (rec_ident & LOGSYS_TAG_ENTER) {
+		printf ("ENTERING function [%s] line [%d]\n", (char *)arguments[2], line);
+		found = 1;
+	}
+	if (rec_ident & LOGSYS_TAG_LEAVE) {
+		printf ("LEAVING function [%s] line [%d]\n", (char *)arguments[2], line);
+		found = 1;
+	}
+	if (found == 0) {
+		printf ("Unknown record type found subsys=[%s] ident=[%d]\n",
+		(char *)arguments[0], rec_ident);
+	}
+
+
+	if (rec_ident == 999) {
+		printf ("ENTERING function [%s] line [%d]\n", (char *)arguments[2], line);
+		found = 1;
+	}
+	if (rec_ident == 1000) {
+		printf ("LEAVING function [%s] line [%d]\n", (char *)arguments[2], line);
+		found = 1;
+	}
+	if (found == 0) {
+		printf ("Unknown record type found subsys=[%s] ident=[%d]\n",
+			(char *)arguments[0], rec_ident);
+	}
+		
+
+#ifdef COMPILE_OUT
+printf ("\n");
+#endif
+}
+
+int main (void)
+{
+	unsigned int fd;
+	int rec_idx;
+	int end_rec;
+	int record_count = 1;
+
+	flt_data = malloc ((flt_data_size + 2) * sizeof (unsigned int));
+	fd = open ("/var/lib/corosync/fdata", O_RDONLY);
+	read (fd, flt_data, (flt_data_size + 2) * sizeof (unsigned int));
+
+	rec_idx = flt_data[FDTAIL_INDEX];
+	end_rec = flt_data[FDHEAD_INDEX];
+
+	printf ("Starting replay: head [%d] tail [%d]\n",
+		flt_data[FDHEAD_INDEX],
+		flt_data[FDTAIL_INDEX]);
+
+	for (;;) {
+		rec_idx = logsys_rec_get (rec_idx);
+		logsys_rec_print (record);
+		if (rec_idx == end_rec) {
+			break;
+		}
+		record_count += 1;
+	}
+
+	printf ("Finishing replay: records found [%d]\n", record_count);
+	return (0);
+}