* logging API updated (see doc/logging-api.txt for details)

  - LOG(LEVEL, FMT, ARGS...) and the short macro corresponding to
    LEVEL level made eqvivalent (eg. LOG(L_DBG, FMT, ARGS...) and
    DBG(FMT, ARGS...) prints always the same message)

  - changed the format of log messages produced by the macros
    to include the log level, module name, filename, line (if applicable)

  - added new, internal LOG_(LEVEL, PREFIX, FORMAT, ARGS...) macro

  - removed DPrint() and DEBUG() macros, L_DEFAULT log level and dprint()
    function

!!!
!!! IMPORTANT! READ ME!
!!!

These changes (mainly the first two) require reformating of the most log
messages in SER core and module source files.  This step can be done
automatically by running "scripts/logging/fix-logs-all" script BUT it
was NOT originally performed because it would have generated too many
changes in CVS which was discouraged by Andrei.  Instead, the developers
are expected to run it when ready.

Makefile.modules

@@ -29,6 +29,8 @@ override static_modules_path=
 # should be set in Makefile of apart module
 # INCLUDES += -I$(COREPATH)
 
+DEFS += -DMOD_NAME='"$(MOD_NAME)"'
+
 ifneq ($(makefile_defs_included),1)
 $(error "the local makefile does not include Makefile.defs!")
 endif

action.c

@@ -44,7 +44,7 @@
  *  2006-07-27  dns cache and dns based send address failover support (andrei)
  *  2006-12-06  on popular request last_retcode set also by module functions
  *              (andrei)
- *  2007-06-14  run_actions & do_action need a ctx or handle now, no more 
+ *  2007-06-14  run_actions & do_action need a ctx or handle now, no more
  *               static vars (andrei)
  *  2008-12-17  added UDP_MTU_TRY_PROTO_T (andrei)
  */
@@ -221,7 +221,7 @@ int do_action(struct run_act_ctx* h, struct action* a, struct sip_msg* msg)
 #endif
 				}
 
-#ifdef HONOR_MADDR				
+#ifdef HONOR_MADDR
 				if (u->maddr_val.s && u->maddr_val.len)
 					dst_host=&u->maddr_val;
 				else
@@ -303,7 +303,7 @@ int do_action(struct run_act_ctx* h, struct action* a, struct sip_msg* msg)
 				ret=E_BUG;
 				break;
 			}
-			LOG(a->val[0].u.number, "%s", a->val[1].u.string);
+			LOG_(a->val[0].u.number, "<script>: ", "%s", a->val[1].u.string);
 			ret=1;
 			break;
 
@@ -707,11 +707,11 @@ int do_action(struct run_act_ctx* h, struct action* a, struct sip_msg* msg)
 					ret=1;  /*default is continue */
 					if (v>0) {
 						if ((a->val[1].type==ACTIONS_ST)&&a->val[1].u.data){
-							ret=run_actions(h, 
+							ret=run_actions(h,
 										(struct action*)a->val[1].u.data, msg);
 						}
 					}else if ((a->val[2].type==ACTIONS_ST)&&a->val[2].u.data){
-							ret=run_actions(h, 
+							ret=run_actions(h,
 										(struct action*)a->val[2].u.data, msg);
 					}
 				}
@@ -794,8 +794,8 @@ int do_action(struct run_act_ctx* h, struct action* a, struct sip_msg* msg)
 			ret=1; /* continue processing */
 			break;
 
-	        case ADD_T:
-	        case ASSIGN_T:
+		case ADD_T:
+		case ASSIGN_T:
 
 			/* If the left attr was specified without indexing brackets delete
 			 * existing AVPs before adding new ones
@@ -992,6 +992,3 @@ error:
 	h->rec_lev--;
 	return ret;
 }
-
-
-

cfg_core.c

@@ -46,7 +46,7 @@
 #include "cfg_core.h"
 
 struct cfg_group_core default_core_cfg = {
-	L_DEFAULT, /*  print only msg. < L_WARN */
+	L_WARN, 	/*  print only msg. < L_WARN */
 	LOG_DAEMON,	/* log_facility -- see syslog(3) */
 #ifdef USE_DST_BLACKLIST
 	/* blacklist */

dns_cache.c

@@ -284,13 +284,13 @@ void fix_dns_flags(str *name)
 #ifdef DNS_SRV_LB
 		dns_flags|=DNS_SRV_RR_LB;
 #else
-		LOG(L_WARN, "WARING: fix_dns_flags: SRV loadbalaning is set, but"
+		LOG(L_WARN, "WARNING: fix_dns_flags: SRV loadbalaning is set, but"
 					" support for it is not compiled -- ignoring\n");
 #endif
 	}
 	if (cfg_get(core, core_cfg, dns_try_naptr)) {
 #ifndef USE_NAPTR
-	LOG(L_WARN, "WARING: fix_dns_flags: NAPTR support is enabled, but"
+	LOG(L_WARN, "WARNING: fix_dns_flags: NAPTR support is enabled, but"
 				" support for it is not compiled -- ignoring\n");
 #endif
 		dns_flags|=DNS_TRY_NAPTR;

doc/logging-api.txt

@@ -0,0 +1,134 @@
+  _                      _                  _    ____ ___ 
+ | |    ___   __ _  __ _(_)_ __   __ _     / \  |  _ \_ _|
+ | |   / _ \ / _` |/ _` | | '_ \ / _` |   / _ \ | |_) | | 
+ | |__| (_) | (_| | (_| | | | | | (_| |  / ___ \|  __/| | 
+ |_____\___/ \__, |\__, |_|_| |_|\__, | /_/   \_\_|  |___|
+            |___/ |___/         |___/                    
+                         Ondrej Martinek <[email protected]>
+                                              January 2009
+
+This document contains the short description of the logging API in SER
+for developers.
+
+Source files:
+    dprint.h
+    dprint.c
+
+ Compile-time control macros
+=============================
+
+    NO_LOG
+	If defined, logging is completely disabled in SER and no messages
+        are produced at all
+	       
+    NO_DEBUG
+	If defined, logging messages do not include the source filename and
+	line location info
+
+ Logging levels
+================
+
+    L_DBG   ... Debugging message (the lowest level)
+    L_INFO  ... Info message
+    L_WARN  ... Warning message
+    L_ERR   ... Error message
+    L_CRIT  ... Critical message
+    L_ALERT ... Alert message (the highest level)
+
+    The levels are implemented as integer macros.
+
+ Related variables
+===================
+
+    debug
+	The config.framework setting that contains the current logging level.
+	The initial value can be specified by "debug" parameter in ser.cfg or
+	by -d options on the command-line.  The default value is L_WARN.
+
+    log_stderror
+	The global variable which specifies whether the log messages should be
+	send to the standard error output or syslog (equals to zero).
+	Its value can be specified by "log_stderr" parameter in ser.cfg or
+	-E option on the command-line.
+	
+    log_facility
+	The config.framework setting that contains the current facility for
+	logging to syslog.
+	The initial value can be specified by "log_facility" parameter in
+	ser.cfg.  The default value is LOG_DAEMON.
+
+ Macro functions
+=================
+
+    * short macro aliases:
+	DBG(FMT, ARGS...)   alias for LOG(L_DBG, FMT, ARGS...)
+        INFO(FMT, ARGS...)  alias for LOG(L_INFO, FMT, ARGS...)
+        WARN(FMT, ARGS...)  alias for LOG(L_WARN, FMT, ARGS...)
+        ERR(FMT, ARGS...)   alias for LOG(L_ERR, FMT, ARGS...)
+        BUG(FMT, ARGS...)   alias for LOG(L_CRIT, FMT, ARGS...)
+        ALERT(FMT, ARGS...) alias for LOG(L_ALERT, FMT, ARGS...)
+
+    * LOG(LEVEL, FMT, ARGS...) macro
+	Prints the log message on stderr or syslog if the current debug level
+	is greater or equal to LEVEL.  The message has the following format:
+
+          - for messages by core:
+              PROC(PID) LEVEL: <core> [FILE:LINE]: MESSAGE
+
+          - for messages by modules:
+              PROC(PID) LEVEL: MODULE [FILE:LINE]: MESSAGE
+	      
+          - for messages by log(), xlog(), xdbg() script funcitons:
+              PROC(PID) LEVEL: <script>: MESSAGE
+
+	PROC is the SER process number and PID is the linux process ID.
+        LEVEL is one of "DEBUG", "INFO", "NOTICE", "WARNING", "ERROR",
+	"ALERT" and "BUG" strings.  MESSAGE is constructed from printf-like
+	arguments FMT and ARGS.
+
+        [FILE:LINE] location info is not present if NO_DEBUG macro is defined.
+  
+	Use of shorter aliases is preferred if LEVEL is a preprocess-time
+	constant.
+	
+    * LOG_(LEVEL, PREFIX, FMT, ARGS...) macro
+	Prints the log message on stderr or syslog if the current debug level
+	is greater or equal to LEVEL.  The message has the following format:
+	
+              PROC(PID) LEVEL: PREFIXMESSAGE
+
+	This is an internal macro try to avoid using it.
+
+
+--------------------------------------------------------------------------------
+
+ APPENDIX: Summary of the changes to the original API
+======================================================
+
+  - LOG(LEVEL, FMT, ARGS...) and the short macro corresponding to LEVEL level
+    made eqvivalent (eg. LOG(L_DBG, FMT, ARGS...) and DBG(FMT, ARGS...) prints
+    always the same message)
+
+  - changed the format of log messages produced by the macros to include
+    the log level, module name, filename, line (if applicable)
+     
+  - added new, internal LOG_(LEVEL, PREFIX, FORMAT, ARGS...) macro
+
+  - removed DPrint() and DEBUG() macros, L_DEFAULT log level and dprint()
+    function
+
+!!!
+!!! IMPORTANT! READ ME!
+!!!
+!!!  These changes (mainly the first two) require reformating of the most log
+!!!  messages in SER core and module source files.  This step can be done
+!!!  automatically by running "scripts/logging/fix-logs-all" script BUT it
+!!!  was NOT originally performed because it would have generated too many
+!!!  changes in CVS which was discouraged by Andrei.  Instead, the developers
+!!!  are expected to run it when ready.
+!!!
+!!! IMPORTANT! READ ME!
+!!!  
+
+--
+$Id$

dprint.c

@@ -29,48 +29,47 @@
  */
 
  
-#include "dprint.h"
 #include "globals.h"
-#include "pt.h"
+#include "dprint.h"
  
 #include <stdarg.h>
 #include <stdio.h>
 #include <strings.h>
 
-volatile int dprint_crit=0; /* signal protection: !=0 when dprint/LOG/DBG are
-								printing */
+#ifndef NO_SIG_DEBUG
+/* signal protection: !=0 when LOG/DBG/... are printing */
+volatile int dprint_crit = 0; 
+#endif
 
 static char* str_fac[]={"LOG_AUTH","LOG_CRON","LOG_DAEMON",
-					"LOG_KERN","LOG_LOCAL0","LOG_LOCAL1",
-					"LOG_LOCAL2","LOG_LOCAL3","LOG_LOCAL4","LOG_LOCAL5",
-					"LOG_LOCAL6","LOG_LOCAL7","LOG_LPR","LOG_MAIL",
-					"LOG_NEWS","LOG_USER","LOG_UUCP",
+			"LOG_KERN","LOG_LOCAL0","LOG_LOCAL1",
+			"LOG_LOCAL2","LOG_LOCAL3","LOG_LOCAL4","LOG_LOCAL5",
+			"LOG_LOCAL6","LOG_LOCAL7","LOG_LPR","LOG_MAIL",
+			"LOG_NEWS","LOG_USER","LOG_UUCP",
 #ifndef __OS_solaris
-					"LOG_AUTHPRIV","LOG_FTP","LOG_SYSLOG",
+			"LOG_AUTHPRIV","LOG_FTP","LOG_SYSLOG",
 #endif
-					0};
+			0};
+			
 static int int_fac[]={LOG_AUTH ,  LOG_CRON , LOG_DAEMON ,
-					LOG_KERN , LOG_LOCAL0 , LOG_LOCAL1 ,
-					LOG_LOCAL2 , LOG_LOCAL3 , LOG_LOCAL4 , LOG_LOCAL5 ,
-					LOG_LOCAL6 , LOG_LOCAL7 , LOG_LPR , LOG_MAIL ,
-					LOG_NEWS , LOG_USER , LOG_UUCP
+		      LOG_KERN , LOG_LOCAL0 , LOG_LOCAL1 ,
+		      LOG_LOCAL2 , LOG_LOCAL3 , LOG_LOCAL4 , LOG_LOCAL5 ,
+		      LOG_LOCAL6 , LOG_LOCAL7 , LOG_LPR , LOG_MAIL ,
+		      LOG_NEWS , LOG_USER , LOG_UUCP,
 #ifndef __OS_solaris
-					,LOG_AUTHPRIV,LOG_FTP,LOG_SYSLOG
+		      LOG_AUTHPRIV,LOG_FTP,LOG_SYSLOG,
 #endif
-					};
-
-
-void dprint(char * format, ...)
-{
-	va_list ap;
-
-	fprintf(stderr, "%2d(%d) ", process_no, my_pid());
-	va_start(ap, format);
-	vfprintf(stderr,format,ap);
-	fflush(stderr);
-	va_end(ap);
-}
+		      0};
 
+struct log_level_info log_level_info[] = {
+	{"ALERT", LOG_ALERT},	  /* L_ALERT */
+	{"BUG", LOG_CRIT},        /* L_CRIT */
+	{"ERROR", LOG_ERR},       /* L_ERR */
+	{"WARNING", LOG_WARNING}, /* L_WARN */
+	{"NOTICE", LOG_NOTICE},   /* L_NOTICE */
+	{"INFO", LOG_INFO},       /* L_INFO */
+	{"DEBUG", LOG_DEBUG}	  /* L_DBG */
+};
 
 int str2facility(char *s)
 {

dprint.h

@@ -25,232 +25,201 @@
  * Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA  02111-1307  USA
  */
 
-
-
 #ifndef dprint_h
 #define dprint_h
 
+#include <assert.h>
 #include <syslog.h>
-#include "cfg_core.h"
-
+#include <stdio.h> /* stderr, fprintf() */
 
-#define L_ALERT -3
-#define L_CRIT  -2
-#define L_ERR   -1
-#define L_DEFAULT 0
-#define L_WARN   1
-#define L_NOTICE 2
-#define L_INFO   3
-#define L_DBG    4
-
-/* vars:*/
+#include "cfg_core.h"
 
-extern int log_stderr;
-extern volatile int dprint_crit; /* protection against "simultaneous"
-									printing from signal handlers */
 
-#ifdef NO_SIG_DEBUG
-#define DPRINT_NON_CRIT		(1)
-#define DPRINT_CRIT_ENTER
-#define DPRINT_CRIT_EXIT
+/* C >= 99 has __func__, older gcc versions have __FUNCTION__ */
+#if __STDC_VERSION__ < 199901L
+#	if __GNUC__ >= 2
+#		define _FUNC_NAME_ __FUNCTION__
+#	else
+#		define _FUNC_NAME_ ""
+#	endif
 #else
-#define DPRINT_NON_CRIT		(dprint_crit==0)
-#define DPRINT_CRIT_ENTER	(dprint_crit++)
-#define DPRINT_CRIT_EXIT	(dprint_crit--)
+#	define _FUNC_NAME_ __func__
 #endif
 
-#define DPRINT_LEV	1
-/* priority at which we log */
-#define DPRINT_PRIO LOG_DEBUG
+#ifdef NO_DEBUG
+#	ifdef MOD_NAME
+#		define LOC_INFO		MOD_NAME ": "
+#	else
+#		define LOC_INFO		"<core>: "
+#	endif
+#else
+#	define XCT2STR(i) #i
+#	define CT2STR(l)  XCT2STR(l)
+#
+#	ifdef MOD_NAME
+#		define LOC_INFO		MOD_NAME " [" __FILE__ ":" CT2STR(__LINE__) "]: "
+#	else
+#		define LOC_INFO		"<core> [" __FILE__ ":" CT2STR(__LINE__) "]: "
+#	endif
+#
+#	ifdef NO_LOG
+#		undef NO_LOG
+#	endif
+#endif /* NO_DEBUG */
 
 
-void dprint (char* format, ...);
+/*
+ * Log levels
+ */
+#define L_ALERT		-3
+#define L_CRIT  	-2
+#define L_ERR   	-1
+#define L_WARN   	0
+#define L_NOTICE 	1
+#define L_INFO   	2
+#define L_DBG    	3
 
-int str2facility(char *s);
-int log_facility_fixup(void *handle, str *name, void **val);
+#define LOG_LEVEL2NAME(level)	(log_level_info[(level) - (L_ALERT)].name)
+#define LOG2SYSLOG_LEVEL(level)	(log_level_info[(level) - (L_ALERT)].syslog_level)
 
-/* C >= 99 has __func__, older gcc versions have __FUNCTION__ */
-#if __STDC_VERSION__ < 199901L
-# if __GNUC__ >= 2
-#  define _FUNC_NAME_ __FUNCTION__
-# else
-#  define _FUNC_NAME_ ""
-# endif
-#else
-# define _FUNC_NAME_ __func__
-#endif
 
+/* my_pid(), process_no are from pt.h but we cannot #include it here
+   because of circular dependencies */
+extern int process_no;
+extern int my_pid();
 
-#define XCT2STR(i) #i
-#define CT2STR(l) XCT2STR(l)
+/* non-zero if logging to stderr instead to the syslog */
+extern int log_stderr;
 
-#define LOC_INFO	__FILE__ ":" CT2STR(__LINE__) ": "
+/* maps log levels to their string name and corresponding syslog level */
 
+struct log_level_info {
+ 	char *name;
+	int syslog_level;
+};
 
+extern struct log_level_info log_level_info[];
 
-#ifdef NO_DEBUG
-	#ifdef __SUNPRO_C
-		#define DPrint(...)
-	#else
-		#define DPrint(fmt, args...)
-	#endif
-#else
-	#ifdef __SUNPRO_C
-		#define DPrint( ...) \
-			do{ \
-				if ((cfg_get(core, core_cfg, debug)>=DPRINT_LEV) && DPRINT_NON_CRIT){ \
-					DPRINT_CRIT_ENTER; \
-					if (log_stderr){ \
-						dprint (__VA_ARGS__); \
-					}else{ \
-						syslog(DPRINT_LEV|cfg_get(core, core_cfg, log_facility), \
-							__VA_ARGS__); \
-					}\
-					DPRINT_CRIT_EXIT; \
-				} \
-			}while(0)
-	#else
-			#define DPrint(fmt,args...) \
-			do{ \
-				if ((cfg_get(core, core_cfg, debug)>=DPRINT_LEV) && DPRINT_NON_CRIT){ \
-					DPRINT_CRIT_ENTER; \
-					if (log_stderr){ \
-						dprint (fmt, ## args); \
-					}else{ \
-						syslog(DPRINT_LEV|cfg_get(core, core_cfg, log_facility), \
-							fmt, ## args); \
-					}\
-					DPRINT_CRIT_EXIT; \
-				} \
-			}while(0)
-	#endif
-
+#ifndef NO_SIG_DEBUG
+/* protection against "simultaneous" printing from signal handlers */
+extern volatile int dprint_crit; 
 #endif
 
-#ifndef NO_DEBUG
-	#undef NO_LOG
-#endif
+int str2facility(char *s);
+int log_facility_fixup(void *handle, str *name, void **val);
+
 
+/*
+ * General logging macros
+ *
+ * LOG_(level, prefix, fmt, ...) prints "printf"-formatted log message to stderr (if
+ *	`log_stderr' is non-zero) to syslog.  Note that `fmt' must be constant.
+ *      `prefix' is added to the beginning of the message.
+ *
+ * LOG(level, fmt, ...) is same as LOG_() with LOC_INFO prefix.
+ */
 #ifdef NO_LOG
-	#ifdef __SUNPRO_C
-		#define LOG(lev, ...)
-	#else
-		#define LOG(lev, fmt, args...)
-	#endif
+
+#	ifdef __SUNPRO_C
+#		define LOG_(level, prefix, fmt, ...)
+#		define LOG(level, fmt, ...)
+#	else
+#		define LOG_(level, prefix, fmt, args...)
+#		define LOG(level, fmt, args...)
+#	endif
+
 #else
-	#ifdef __SUNPRO_C
-		#define LOG(lev, ...) \
+
+#	ifdef NO_SIG_DEBUG
+#		define DPRINT_NON_CRIT		(1)
+#		define DPRINT_CRIT_ENTER
+#		define DPRINT_CRIT_EXIT
+#	else
+#		define DPRINT_NON_CRIT		(dprint_crit==0)
+#		define DPRINT_CRIT_ENTER	(dprint_crit++)
+#		define DPRINT_CRIT_EXIT		(dprint_crit--)
+#	endif
+
+#	ifdef __SUNPRO_C
+#		define LOG_(level, prefix, fmt, ...) \
 			do { \
-				if ((cfg_get(core, core_cfg, debug)>=(lev)) && DPRINT_NON_CRIT){ \
+				if (cfg_get(core, core_cfg, debug) >= (level) && DPRINT_NON_CRIT) { \
 					DPRINT_CRIT_ENTER; \
-					if (log_stderr) dprint (__VA_ARGS__); \
-					else { \
-						switch(lev){ \
-							case L_CRIT: \
-								syslog(LOG_CRIT|cfg_get(core, core_cfg, log_facility), \
-									__VA_ARGS__); \
-								break; \
-							case L_ALERT: \
-								syslog(LOG_ALERT|cfg_get(core, core_cfg, log_facility), \
-									__VA_ARGS__); \
-								break; \
-							case L_ERR: \
-								syslog(LOG_ERR|cfg_get(core, core_cfg, log_facility), \
-									__VA_ARGS__); \
-								break; \
-							case L_WARN: \
-								syslog(LOG_WARNING|cfg_get(core, core_cfg, log_facility), \
-									__VA_ARGS__);\
-								break; \
-							case L_NOTICE: \
-								syslog(LOG_NOTICE|cfg_get(core, core_cfg, log_facility), \
-									__VA_ARGS__); \
-								break; \
-							case L_INFO: \
-								syslog(LOG_INFO|cfg_get(core, core_cfg, log_facility), \
-									__VA_ARGS__); \
-								break; \
-							case L_DBG: \
-								syslog(LOG_DEBUG|cfg_get(core, core_cfg, log_facility), \
-									__VA_ARGS__); \
-								break; \
-						} \
+					assert(((level) >= L_ALERT) && ((level) <= L_DBG)); \
+					if (log_stderr) { \
+						fprintf(stderr, "%2d(%d) %s: %s" fmt, \
+					            process_no, my_pid(), LOG_LEVEL2NAME(level), (prefix), __VA_ARGS__); \
+					} else { \
+						syslog(LOG2SYSLOG_LEVEL(level) | cfg_get(core, core_cfg, log_facility), \
+						       "%s: %s" fmt, log_level_info[(level)].name, (prefix), __VA_ARGS__); \
 					} \
 					DPRINT_CRIT_EXIT; \
 				} \
-			}while(0)
-	#else
-		#define LOG(lev, fmt, args...) \
+			} while(0)
+			
+#		define LOG(level, fmt, ...)  LOG_((level), LOC_INFO, fmt, __VA_ARGS__)
+
+#	else
+#		define LOG_(level, prefix, fmt, args...) \
 			do { \
-				if ((cfg_get(core, core_cfg, debug)>=(lev)) && DPRINT_NON_CRIT){ \
+				if (cfg_get(core, core_cfg, debug) >= (level) && DPRINT_NON_CRIT) { \
 					DPRINT_CRIT_ENTER; \
-					if (log_stderr) dprint (fmt, ## args); \
-					else { \
-						switch(lev){ \
-							case L_CRIT: \
-								syslog(LOG_CRIT|cfg_get(core, core_cfg, log_facility), \
-									fmt, ##args); \
-								break; \
-							case L_ALERT: \
-								syslog(LOG_ALERT|cfg_get(core, core_cfg, log_facility), \
-									fmt, ##args); \
-								break; \
-							case L_ERR: \
-								syslog(LOG_ERR|cfg_get(core, core_cfg, log_facility), \
-									fmt, ##args); \
-								break; \
-							case L_WARN: \
-								syslog(LOG_WARNING|cfg_get(core, core_cfg, log_facility), \
-									fmt, ##args);\
-								break; \
-							case L_NOTICE: \
-								syslog(LOG_NOTICE|cfg_get(core, core_cfg, log_facility), \
-									fmt, ##args); \
-								break; \
-							case L_INFO: \
-								syslog(LOG_INFO|cfg_get(core, core_cfg, log_facility), \
-									fmt, ##args); \
-								break; \
-							case L_DBG: \
-								syslog(LOG_DEBUG|cfg_get(core, core_cfg, log_facility), \
-									fmt, ##args); \
-								break; \
-						} \
+					assert(((level) >= L_ALERT) && ((level) <= L_DBG)); \
+					if (log_stderr) { \
+						fprintf(stderr, "%2d(%d) %s: %s" fmt, \
+					            process_no, my_pid(), LOG_LEVEL2NAME(level), (prefix), ## args); \
+					} else { \
+						syslog(LOG2SYSLOG_LEVEL(level) | cfg_get(core, core_cfg, log_facility), \
+						       "%s: %s" fmt, log_level_info[(level)].name, (prefix), ## args); \
 					} \
 					DPRINT_CRIT_EXIT; \
 				} \
-			}while(0)
-	#endif /*SUN_PRO_C*/
-#endif
+			} while(0)
+			
+#		define LOG(level, fmt, args...)  LOG_((level), LOC_INFO, fmt, ## args)
+		
+#	endif /* __SUNPRO_C */
+#endif /* NO_LOG */
 
 
-#ifdef NO_DEBUG
-	#ifdef __SUNPRO_C
-		#define DBG(...)
-	#else
-		#define DBG(fmt, args...)
-	#endif
-#else
-	#ifdef __SUNPRO_C
-		#define DBG(...) LOG(L_DBG, __VA_ARGS__)
-	#else
-		#define DBG(fmt, args...) LOG(L_DBG, fmt, ## args)
-	#endif
-#endif
-
+/*
+ * Simplier, prefered logging macros for constant log level
+ */
 #ifdef __SUNPRO_C
-		#define DEBUG(...) DBG("DEBUG: "          LOC_INFO __VA_ARGS__)
-		#define ERR(...)  LOG(L_ERR, "ERROR: "    LOC_INFO __VA_ARGS__)
-		#define WARN(...) LOG(L_WARN, "WARNING: " LOC_INFO __VA_ARGS__)
-		#define INFO(...) LOG(L_INFO, "INFO: "    LOC_INFO __VA_ARGS__)
-		#define BUG(...) LOG(L_CRIT, "BUG: "      LOC_INFO __VA_ARGS__)
+#	define ALERT(...)  LOG(L_ALERT,  __VA_ARGS__)
+#	define BUG(...)    LOG(L_CRIT,   __VA_ARGS__)
+#	define ERR(...)    LOG(L_ERR,    __VA_ARGS__)
+#	define WARN(...)   LOG(L_WARN,   __VA_ARGS__)
+#	define NOTICE(...) LOG(L_NOTICE, __VA_ARGS__)
+#	define INFO(...)   LOG(L_INFO,   __VA_ARGS__)
+
+#	ifdef NO_DEBUG
+#		define DBG(...)
+#	else
+#		define DBG(...)    LOG(L_DBG, __VA_ARGS__)
+#	endif		
+
+/* obsolete, do not use */
+#	define DEBUG(...) DBG(__VA_ARGS__)
+		
 #else
-		#define DEBUG(fmt, args...) DBG("DEBUG: "       LOC_INFO fmt, ## args)
-		#define ERR(fmt, args...) LOG(L_ERR, "ERROR: "  LOC_INFO fmt, ## args)
-		#define WARN(fmt, args...) LOG(L_WARN, "WARN: " LOC_INFO fmt, ## args)
-		#define INFO(fmt, args...) LOG(L_INFO, "INFO: " LOC_INFO fmt, ## args)
-		#define BUG(fmt, args...) LOG(L_CRIT, "BUG: "   LOC_INFO fmt, ## args)
-#endif
-
-
-#endif /* ifndef dprint_h */
+#	define ALERT(fmt, args...)  LOG(L_ALERT,  fmt, ## args)
+#	define BUG(fmt, args...)    LOG(L_CRIT,   fmt, ## args)
+#	define ERR(fmt, args...)    LOG(L_ERR,    fmt, ## args)
+#	define WARN(fmt, args...)   LOG(L_WARN,   fmt, ## args)
+#	define NOTICE(fmt, args...) LOG(L_NOTICE, fmt, ## args)
+#	define INFO(fmt, args...)   LOG(L_INFO,   fmt, ## args)
+
+#	ifdef NO_DEBUG
+#		define DBG(fmt, args...)
+#	else
+#		define DBG(fmt, args...)    LOG(L_DBG, fmt, ## args)
+#	endif		
+
+/* obsolete, do not use */
+#	define DEBUG(fmt, args...) DBG(fmt, ## args)
+		
+#endif /* __SUNPRO_C */
+
+
+#endif /* !dprint_h */

main.c

@@ -641,7 +641,7 @@ void handle_sigs()
 				DBG("SIGTERM received, program terminates\n");
 			/* shutdown/kill all the children */
 			shutdown_children(SIGTERM, 1);
-			dprint("Thank you for flying " NAME "\n");
+			LOG(L_NOTICE, "Thank you for flying " NAME "\n");
 			exit(0);
 			break;
 
@@ -767,32 +767,32 @@ int install_sigs()
 {
 	/* added by jku: add exit handler */
 	if (set_sig_h(SIGINT, sig_usr) == SIG_ERR ) {
-		DPrint("ERROR: no SIGINT signal handler can be installed\n");
+		ERR("no SIGINT signal handler can be installed\n");
 		goto error;
 	}
 	/* if we debug and write to a pipe, we want to exit nicely too */
 	if (set_sig_h(SIGPIPE, sig_usr) == SIG_ERR ) {
-		DPrint("ERROR: no SIGINT signal handler can be installed\n");
+		ERR("no SIGINT signal handler can be installed\n");
 		goto error;
 	}
 	if (set_sig_h(SIGUSR1, sig_usr)  == SIG_ERR ) {
-		DPrint("ERROR: no SIGUSR1 signal handler can be installed\n");
+		ERR("no SIGUSR1 signal handler can be installed\n");
 		goto error;
 	}
 	if (set_sig_h(SIGCHLD , sig_usr)  == SIG_ERR ) {
-		DPrint("ERROR: no SIGCHLD signal handler can be installed\n");
+		ERR("no SIGCHLD signal handler can be installed\n");
 		goto error;
 	}
 	if (set_sig_h(SIGTERM , sig_usr)  == SIG_ERR ) {
-		DPrint("ERROR: no SIGTERM signal handler can be installed\n");
+		ERR("no SIGTERM signal handler can be installed\n");
 		goto error;
 	}
 	if (set_sig_h(SIGHUP , sig_usr)  == SIG_ERR ) {
-		DPrint("ERROR: no SIGHUP signal handler can be installed\n");
+		ERR("no SIGHUP signal handler can be installed\n");
 		goto error;
 	}
 	if (set_sig_h(SIGUSR2 , sig_usr)  == SIG_ERR ) {
-		DPrint("ERROR: no SIGUSR2 signal handler can be installed\n");
+		ERR("no SIGUSR2 signal handler can be installed\n");
 		goto error;
 	}
 	return 0;

scripts/logging/fix-logs

@@ -0,0 +1,155 @@
+#!/usr/bin/perl -w
+#
+# Usage: fix-log [MODULE-NAME] < INFILE > OUTFILE
+#
+# Fixes logging macros and messages in the SER source file INFILE
+# to match the recent updates in the logging API.
+#
+# Specify MODULE_NAME if INFILE source file is a part of a SER module.
+#
+# See doc/logging-api.txt for details.
+#
+# $Id$
+
+#
+# What *exactly* does this script do?
+#
+#   - replaces LOG(L_*, ...) with the short macro corresponding to L_* level
+#
+#   - replaces DEBUG() with DBG() macro
+#
+#   - removes MODULE and the level string prefixes from FMT arguments of macros
+#     where FMT looks like "X:...", "X:Y:..." or "X:Y:Z:...", white spaces are
+#     ignored and preserved, string matching is case-insensitive
+#
+#     In addition, if the level string found in FMT argument doesn't match the actual
+#     level of the macro, the macro level is fixed.
+#
+#     Examples:
+#        ERR("ERROR:tm: blah\n")           becomes ERR("blah\n")
+#        DBG("Debug: blah\n")              becomes DBG("blah\n")
+#        LOG(L_ERR, "tm: INFO: blah\n")    becomes INFO("blah\n")
+#
+#   - removes 'MODULE_NAME ":' string from the beggining of FMT arguments of macros
+#     in module source files (a common special case)
+#
+#     Example:
+#        LOG(L_ERR, MODULE_NAME ": tm:Info:blah\n")   becomes INFO("blah\n")
+#
+
+# Map a text string to L_* log level macro
+my %text2level = (
+    "BUG"         => "L_CRIT",
+    "CRIT"        => "L_CRIT",
+    "CRITICAL"    => "L_CRIT",
+
+    "ALERT"       => "L_ALERT",
+
+    "ERR"         => "L_ERR",
+    "ERROR"       => "L_ERR",
+
+    "WARN"        => "L_WARN",
+    "WARNING"     => "L_WARN",
+
+    "NOTICE"      => "L_NOTICE",
+
+    "INFO"        => "L_INFO",
+
+    "DBG"         => "L_DBG",
+    "DEBUG"       => "L_DBG",
+);
+
+#
+short2level
+
+
+# Strip the leading and trailing whitespaces and upper-case a text
+sub norm {
+    my $text = ($_[0] || "");
+    $text =~ s/^\s*//;
+    $text =~ s/\s*$//;
+    uc($text);
+}
+
+my $module_name = norm($ARGV[0]);
+
+sub fix_log_prefix {
+    my ($prefix, $level) = ($_[0], $_[1]);
+
+    # delete prefix if it contains module name
+    if ($module_name) {
+        if (!$text || (norm($text) eq $module_name)) {
+            return ("", $level);
+        }
+    }
+
+    # delete prefix if it contains text level
+    my $prefix_level = $text2level{norm($prefix)};
+    if ($prefix_level) {
+	$prefix = "";
+	
+	# change level if does not match prefix level
+	if ($level =~ /^L_(DBG|INFO|NOTICE|WARN|ERR|CRIT|ALERT)$/ && 
+	    $level ne $prefix_level) {
+    	    return ("", $prefix_level);
+	}
+    }
+
+    return ($prefix . ":", $level);
+}
+
+sub fix_log {
+    my $level = $_[0];
+    my $prefix1 = $_[1];
+    my $prefix2 = $_[2];
+    my $prefix3 = $_[3];
+    my $space = $_[4];
+
+    ($prefix1, $level) = fix_log_prefix($prefix1, $level) if $prefix1;
+    ($prefix2, $level) = fix_log_prefix($prefix2, $level) if $prefix2;
+    ($prefix3, $level) = fix_log_prefix($prefix3, $level) if $prefix3;
+
+    my $prefix = $prefix1 . $prefix2 . $prefix3 . $space;
+    $prefix =~ s/^\s*//;
+    
+    "LOG($level, \"$prefix";
+}
+
+while (<STDIN>) {
+AGAIN:
+    # replace DEBUG() by DBG()
+    s/DEBUG\(/DBG\(/g;
+
+    # ...in case the statement spans more lines
+    if (/(DBG|INFO|NOTICE|WARN|ERR|BUG|ALERT)\(\s*$/ || /LOG\(([^,]*,)?\s*$/) {
+        $_ .= <STDIN>;
+        goto AGAIN;
+    }
+
+    # one common special case used in several modules
+    if ($module_name) {
+	s/LOG\(\s*([^,]+)\s*,\s*MODULE_NAME\s*"\s*:\s*/LOG($1, "/g;
+	s/(DBG|INFO|NOTICE|WARN|ERR|BUG|ALERT)\(\s*MODULE_NAME\s*"\s*:\s*/$1("/g;
+    }
+
+    # module name and level prefix removing magic, may change macro level
+    # if different one found in the message
+    $id='\s*[a-zA-Z0-9_]+\s*';
+    
+    s/LOG\(\s*(([A-Z_]+)|[^,]+)\s*,\s*"($id):(($id):(($id):)?)?(\s*)/
+        fix_log($1, $3, $5, $7, $8);
+    /eg;
+
+    s/(DBG|INFO|NOTICE|WARN|ERR|BUG|ALERT)\(\s*"($id):(($id):(($id):)?)?(\s*)/
+        $1 = "CRIT" if $1 eq "BUG";
+        fix_log("L_$1", $2, $4, $6, $7);
+    /eg;
+
+    # prefer shorter static-level macros
+    s/LOG\(\s*L_(DBG|INFO|NOTICE|WARN|ERR|CRIT|ALERT)\s*,\s*/
+	$1 = "BUG" if $1 eq "CRIT";
+	"$1\(";
+    /eg;
+
+    print;
+}

scripts/logging/fix-logs-all

@@ -0,0 +1,37 @@
+#!/bin/sh
+#
+# Usage: fix-logs-all [DIR]
+#
+# Fixes logging macros and messages in SER source files in DIR
+# directory (recursively).
+#
+# See doc/logging-api.txt and fix-logs script for details.
+#
+# $Id$
+
+# <filename>.ORIG backup files is created for each processed file.
+# If TEST is set, it only prints a "patch" file.
+#
+
+find ${1:-.} -type f \( -name "*.[chy]" -o -name "*.lex" -o -name "*.cc" \) | \
+    grep -v "/dprint\.[hc]$" | \
+	while read file; do
+	    echo "=== $file"
+
+	    if ! test "$TEST"; then
+		mv "$file" "$file.ORIG"
+	    fi
+
+	    if expr match "$file" ".*/modules/" >/dev/null; then
+		module=$(basename $(dirname $file))
+	    fi
+
+	    if ! test "$TEST"; then
+		fix-logs "$module" < "$file.ORIG" > "$file"
+	    else
+		fix-logs "$module" < "$file" > "$file.NEW"
+
+		diff "$file.NEW" "$file"
+		rm "$file.NEW"
+	    fi
+	done