Updated log function, add a format_message function, debuging etc.

Implement the set_ident function (wich update the internal preffix & suffix
representations)

include/logger.h

@@ -56,11 +56,15 @@
 #define PYFCGI_LOGGER_FMT_MAX PYFCGI_LOGGER_MAX
 #define PYFCGI_LOGGER_FIELD_MAX 24
 #define PYFCGI_LOGGER_FMT_PARSE_ERRSZ 64
+/**@brief The size of the @ref struct pyfcgi_logger_format_t.buf allocated to
+ * the message field */
+#define PYFCGI_LOGGER_MSG_BUF_SZ 64
 
-#define PYFCGI_LOG_DTM_LEN 10
+#define PYFCGI_LOG_DTM_LEN 25
 #define PYFCGI_LOG_LVL_LEN 7
 #define PYFCGI_LOG_TYP_LEN 7
-#define PYFCGI_LOG_PID_LEN 5
+#define PYFCGI_LOG_PID_LEN 4
+#define PYFCGI_LOG_PID_FMT "%04d"
 
 #define SYSLOG_syslog syslog
 #define SYSLOG_vsyslog vsyslog
@@ -143,14 +147,21 @@ typedef struct pyfcgi_logger_fmt_field_s pyfcgi_logger_fmt_field_t;
 typedef union pyfcgi_logger_fmt_field_u pyfcgi_logger_fmt_value_t;
 typedef enum pyfcgi_logger_field_type pyfcgi_logger_field_type_e;
 typedef struct strftime_args_s strftime_args_t;
+typedef struct ident_args_s ident_args_t;
 typedef union pyfcgi_logger_field_args pyfcgi_logger_field_args_u;
 
 
 static const short SYSLOG_LVLS[8] = {LOG_EMERG, LOG_ALERT, LOG_CRIT, LOG_ERR,
                                      LOG_WARNING, LOG_NOTICE, LOG_INFO, LOG_DEBUG};
-static const char* PYFCGI_LOGGER_LVLNAME[] = {"Emergency", "Alert", "Critical",
-                                              "Error", "Warning", "Notice",
-					      "Info", "Debug"};
+static const char* PYFCGI_LOGGER_LVLNAME[] = {
+	" Emerge",
+	"  Alert",
+	" Critic",
+	"  Error",
+	"Warning",
+	" Notice",
+	"   Info",
+	"  Debug"};
 
 static const char* PYFCGI_LOGGER_TYPNAME[] = {"Global", "Access", "Internal",
                                               "Worker", "Master"};
@@ -188,9 +199,15 @@ struct strftime_args_s
 	//const struct tm *tm; // fecthed each time
 };
 
+struct ident_args_s
+{
+	size_t len;
+};
+
 union pyfcgi_logger_field_args
 {
 	strftime_args_t datetime;
+	ident_args_t ident;
 };
 
 /**@brief Logger format field's type
@@ -222,6 +239,10 @@ struct pyfcgi_logger_fmt_field_s
 	pyfcgi_logger_field_args_u args;
 	/**@brief Points in prefix or sufix buffer */
 	char *buf_ptr;
+	/**@brief Field offset in msg buffer (prefix or sufix) */
+	size_t buf_off;
+	/**@brief 1 if in suffix else 0 */
+	short suff;
 };
 
 /**@brief Logger format data
@@ -236,10 +257,14 @@ struct pyfcgi_logger_format_s
 	int nfield;
 	/**@brief Preallocated buffer for prefix & suffix */
 	char *buf;
+	size_t buflen[2];
 	/**@brief Message prefix */
 	char *prefix;
 	/**@brief Message suffix */
 	char *suffix;
+
+	char *_msg;
+	size_t _msglen;
 };
 
 /**@brief Informations on a logger
@@ -279,7 +304,11 @@ struct pyfcgi_conf_logger_s
 	//char **format;
 	unsigned char format_sz;
 
-	/**@brief Internal pipe to tee(2) the message on loggers */
+	/**@brief Buffer for message field formating */
+	char *msg_buf;
+	size_t msg_buf_sz;
+
+	/**@brief Internal pipe to tee(2) the message on loggers (USELESS)*/
 	int pipes[2];
 };
 #include "conf.h"
@@ -376,8 +405,26 @@ const char* pyfcgi_logger_value_facility(short);
  */
 int pyfcgi_logger_open(pyfcgi_logger_t*);
 
+/**@brief Set programm identity for logger
+ * @note ident is global to a process
+ * @note this function triggers the refresh of the loggers internal
+ * buffers if needed (see @ref pyfcgi_logger_format_bufinit() )
+ * @param const char* new_ident
+ * @return 0 if no error
+ */
 int pyfcgi_logger_set_ident(const char*);
 
+/**@brief Format a message using a @ref struct pyfcgi_logger_format_s
+ * @note alloc and write the logline in the attribute _msg
+ * @param pyfcgi_logger_format_t the pyfcgi logger format structure
+ * @param loglvl_t the loglevel (see @ref pyfcgi_log() )
+ * @param char* message the message sent by user
+ * @param size_t len the message len
+ * @return NULL if error
+ */
+char* vpyfcgi_logger_format_message(pyfcgi_logger_format_t *fmt,
+	loglvl_t lvl, const char* message, size_t len);
+
 int pyfcgi_log(loglvl_t, const char*, ...);
 int vpyfcgi_log(loglvl_t, const char*, va_list);
 

src/logger.c

@@ -196,7 +196,7 @@ int pyfcgi_logger_format_bufinit(pyfcgi_logger_format_t* fmt)
 {
 	unsigned short i;
 	size_t pre_sz, suf_sz;
-	char *cur;
+	char *cur, pid[PYFCGI_LOG_PID_LEN];
 	fmt->buf = fmt->prefix = fmt->suffix = NULL;
 	if(!fmt || !fmt->nfield)
 	{
@@ -216,6 +216,8 @@ int pyfcgi_logger_format_bufinit(pyfcgi_logger_format_t* fmt)
 	pre_sz = 0;
 	while(i<fmt->nfield && fmt->fields[i].type != pyfcgi_logger_field_msg)
 	{
+		fmt->fields[i].buf_off = pre_sz;
+		fmt->fields[i].suff = 0;
 		pre_sz+=fmt->fields[i].len;
 		i++;
 	}
@@ -223,6 +225,8 @@ int pyfcgi_logger_format_bufinit(pyfcgi_logger_format_t* fmt)
 	suf_sz = 0;
 	while(i<fmt->nfield && fmt->fields[i].type != pyfcgi_logger_field_msg)
 	{
+		fmt->fields[i].buf_off = suf_sz;
+		fmt->fields[i].suff = 1;
 		suf_sz+=fmt->fields[i].len;
 		i++;
 	}
@@ -236,8 +240,16 @@ int pyfcgi_logger_format_bufinit(pyfcgi_logger_format_t* fmt)
 		           strerror(errno));
 		return PYFCGI_ERR;
 	}
+	memset(fmt->buf, ' ', (pre_sz + suf_sz));
 	fmt->prefix = pre_sz?fmt->buf:NULL;
 	fmt->suffix = suf_sz?(fmt->buf + pre_sz):NULL;
+	fmt->prefix[pre_sz-1] = '\0';
+	if(fmt->suffix)
+	{
+		fmt->suffix[suf_sz-1] = '\0';
+	}
+	fmt->buflen[0] = pre_sz - 1;//not counting '\0'
+	fmt->buflen[1] = suf_sz;
 
 	i=0;
 	cur = fmt->prefix;
@@ -247,13 +259,25 @@ int pyfcgi_logger_format_bufinit(pyfcgi_logger_format_t* fmt)
 			fmt->fields[i].type != pyfcgi_logger_field_msg)
 		{
 			fmt->fields[i].buf_ptr = cur;
-			if(fmt->fields[i].len && (
-				fmt->fields[i].type == pyfcgi_logger_field_const ||
-				fmt->fields[i].type == pyfcgi_logger_field_ident))
-			{// copy const fields
-				strncpy(cur, fmt->fields[i].val,
-					fmt->fields[i].len);
+			memset(cur, ' ', fmt->fields[i].len);
+			switch(fmt->fields[i].type)
+			{
+				
+				case pyfcgi_logger_field_const:
+				case pyfcgi_logger_field_ident:
+					memcpy(cur, fmt->fields[i].val,
+						fmt->fields[i].len);
+					break;
+				case pyfcgi_logger_field_pid:
+					snprintf(pid, PYFCGI_LOG_PID_LEN+1,
+						PYFCGI_LOG_PID_FMT,
+						*((pid_t*)fmt->fields[i].val));
+					memcpy(cur, pid, PYFCGI_LOG_PID_LEN);
+					break;
+				default:
+					break;
 			}
+//dprintf(2, "field %d type %d off %ld len %ld '%s' p'%s' s'%s'\n", i, fmt->fields[i].type, fmt->fields[i].buf_off, fmt->fields[i].len, cur, fmt->prefix, fmt->suffix);
 			cur += fmt->fields[i].len;
 			i++;
 		}
@@ -356,7 +380,7 @@ int pyfcgi_logger_parse_field(const char** ptr, const char *start,
 			cur_field->val = &(PyFCGI_conf.context.pid);
 			break;
 		case pyfcgi_logger_field_ident:
-			default_len = 0;
+			default_len = PyFCGI_conf.logs.ident?strlen(PyFCGI_conf.logs.ident):0;
 			cur_field->val = &(PyFCGI_conf.logs.ident);
 			break;
 		case pyfcgi_logger_field_msg:
@@ -456,8 +480,8 @@ int pyfcgi_logger_parse_field_sz(const char **ptr, size_t *size)
 const char* pyfcgi_logger_value_level(short lvl)
 {
 	short idx;
-	idx = (lvl & 0xF0) >> 4;
-	if(idx < 0 || idx >= sizeof(PYFCGI_LOGGER_LVLNAME))
+	idx = ((lvl & 0xF0) >> 4)-1;
+	if(idx < 0 || idx > 7)
 	{
 		return NULL;
 	}
@@ -489,6 +513,144 @@ int pyfcgi_logger_open(pyfcgi_logger_t *logger)
 	return 0;
 }
 
+int pyfcgi_logger_set_ident(const char* new_ident)
+{
+	pyfcgi_conf_logger_t *conf;
+	pyfcgi_logger_format_t *fmt;
+	pyfcgi_logger_fmt_field_t *field;
+	size_t i, j, len;
+	short upd;
+
+	conf = &PyFCGI_conf.logs;
+	if( !(conf->ident = strdup(new_ident)) )
+	{
+		pyfcgi_log(LOG_ALERT,
+			"Error duplicating identity for logger : %s",
+			strerror(errno));
+		return PYFCGI_FATAL;
+	}
+	len = strlen(new_ident);
+	for(i=0; i<conf->format_sz; i++)
+	{
+		fmt = &(conf->formats[i]);
+		upd = 0;
+		for(j=0; j<fmt->nfield; j++)
+		{
+			field = &(fmt->fields[j]);
+			if(field->type == pyfcgi_logger_field_ident)
+			{
+				field->len = len;
+				upd = 0;
+			}
+		}
+		if(upd)
+		{
+			pyfcgi_logger_format_bufinit(fmt);
+		}
+	}
+	return 0;
+}
+
+char* vpyfcgi_logger_format_message(pyfcgi_logger_format_t *fmt,
+	loglvl_t lvl, const char* message, size_t fmt_msg_len)
+{
+	char *_msgptr;
+	size_t maxlen;
+	int ret;
+	void *tmp;
+	size_t i, suff_off;
+	pyfcgi_logger_fmt_field_t *field;
+	struct tm *curtime;
+	time_t _curtime;
+	size_t (*_strftime)(char*, size_t, const char*, const struct tm*);
+
+
+	if(!fmt->_msg)
+	{ //first message, allocating message buffer
+		fmt->_msglen = fmt->buflen[0] + fmt->buflen[1] + fmt_msg_len;
+		// rounding upper
+		fmt->_msglen >>= 6;
+		fmt->_msglen++;
+		fmt->_msglen <<= 6;
+		fmt->_msg = malloc(sizeof(char) * fmt->_msglen);
+		if(!fmt->_msg)
+		{
+			//TODO : error
+dprintf(2, "ERROR ALLOC _msg : %s", strerror(errno));
+			return NULL;
+		}
+		memset(fmt->_msg, ' ', sizeof(char)*fmt->_msglen);
+		fmt->_msg[fmt->_msglen - 1] = '\0';
+		memcpy(fmt->_msg, fmt->prefix, fmt->buflen[0]);
+	}
+	while(1)
+	{
+		maxlen = fmt->_msglen - (fmt->buflen[0] + fmt->buflen[1]);
+		if(fmt_msg_len < maxlen)
+		{
+			// TODO check errors
+			break;
+		}
+		fmt->_msglen = fmt_msg_len + fmt->buflen[0] + fmt->buflen[1];
+		fmt->_msglen >>= 6;
+		fmt->_msglen++;
+		fmt->_msglen <<= 6;
+		tmp = realloc(fmt->_msg, sizeof(char) * fmt->_msglen);
+		if(!tmp)
+		{
+			//TODO : error
+dprintf(2, "ERROR REALLOC _msg : %s", strerror(errno));
+			return NULL;
+		}
+	}
+	memcpy(fmt->_msg + fmt->buflen[0], message, fmt_msg_len);
+	suff_off = fmt->buflen[0] + fmt_msg_len;
+	if(fmt->buflen[1])
+	{
+		strncpy(fmt->_msg + suff_off, fmt->suffix,
+			fmt->buflen[1]);
+		//TODO check errors
+	}
+	else
+	{
+		fmt->_msg[suff_off] = '\0';
+	}
+	// update fmt->_msg dynamic fields
+	time(&_curtime);
+	curtime = localtime(&_curtime);
+	for(i=0; i<fmt->nfield; i++)
+	{
+		field = &(fmt->fields[i]);
+		_msgptr = fmt->_msg;
+		_msgptr += fmt->fields->suff?suff_off:0;
+		_msgptr += field->buf_off;
+		switch(field->type)
+		{
+			case pyfcgi_logger_field_datetime:
+				_strftime = field->val?field->val:strftime;
+				ret = _strftime(_msgptr, field->len,
+					field->args.datetime.format,
+					curtime);
+				if(!ret)
+				{
+					//TODO ERROR
+dprintf(2,"Not enough space to write datetime in '%s', need more than %ld\n",
+	fmt->fmt, field->len);
+				}
+				_msgptr[ret] = ' ';
+				break;
+			case pyfcgi_logger_field_level:
+				memcpy(_msgptr,
+					pyfcgi_logger_value_level(lvl),
+					field->len);
+				break;
+			default:
+				break;
+		}
+	}
+	return fmt->_msg;
+}
+
 int pyfcgi_log(loglvl_t lvl, const char *fmt, ...)
 {
 	int ret;
@@ -503,76 +665,65 @@ int vpyfcgi_log(loglvl_t lvl, const char *fmt, va_list ap)
 {
 	int len, ret;
 	pyfcgi_conf_logger_t *conf;
+	pyfcgi_logger_t *logger;
 	unsigned char i;
-	char buf[512];
+	size_t msglen, real_len;
+	void *tmp;
 	va_list o_ap;
 
+
 	conf = &PyFCGI_conf.logs;
 
 	va_copy(o_ap, ap);
 	_vsyslog(lvl, fmt, o_ap);
 	va_end(o_ap);
 
-	len = 0;
-	if(conf->format_sz > 1)
-	{
-		len = vdprintf(conf->pipes[1], fmt, ap);
-		if(len < 0)
+	ret = 0;
+	// processing message before sending it to formats
+	while(1)
+	{
+		va_copy(o_ap, ap);
+		msglen = vsnprintf(conf->msg_buf, conf->msg_buf_sz, fmt, o_ap);
+		real_len = msglen;
+		va_end(o_ap);
+		// Rounding msglen
+		msglen >>=6;
+		msglen++;
+		msglen <<=6;
+		if(msglen <= conf->msg_buf_sz)
 		{
-			_syslog(LOG_ALERT, 
-			       "Unable to write to multiplexer pipe when trying to log : %s",
-			       strerror(errno));
-			return PYFCGI_FATAL;
+			break;
 		}
-	}
-	else if (conf->format_sz)
-	{
-		len = vdprintf(conf->loggers[0].fd, fmt, ap);
-		if(len < 0)
+		conf->msg_buf_sz = msglen;
+		tmp = realloc(conf->msg_buf,
+			sizeof(char)*conf->msg_buf_sz);
+		if(!tmp)
 		{
-			_syslog(LOG_ALERT, 
-			       "Unable to write to single FD to '%s' when trying to log : %s",
-			       conf->loggers[0].filename, strerror(errno));
+			// TODO : error
+dprintf(2, "ERROR REALLOC conf_msg : %s", strerror(errno));
+			if(conf->msg_buf) { free(conf->msg_buf); }
 			return PYFCGI_FATAL;
 		}
-		return 0;
+		conf->msg_buf = tmp;
+	}
+
+	// populating format messages
+	for(i=0; i<conf->format_sz; i++)
+	{
+		vpyfcgi_logger_format_message(&(conf->formats[i]), lvl,
+			conf->msg_buf, real_len);
 	}
-	for(i=0; i<conf->logger_sz-1; i++)
+	for(i=0; i<conf->logger_sz; i++)
 	{
-		ret = tee(conf->pipes[0], conf->loggers[i].fd, len, 0);
-		if(ret < 0)
+		logger = &(conf->loggers[i]);
+		len = dprintf(logger->fd, conf->formats[logger->fmt_id]._msg);
+		if(len < 0)
 		{
 			_syslog(LOG_ALERT, 
-			       "Unable to splice to last logfile '%s' : %s",
+			       "Unable to write to single FD to '%s' when trying to log : %s",
 			       conf->loggers[i].filename, strerror(errno));
-			return PYFCGI_FATAL;
+			ret = PYFCGI_FATAL;
 		}
 	}
-	ret = splice(conf->pipes[0], NULL, conf->loggers[i].fd, NULL, len, 0);
-	if(ret < 0)
-	{
-		_syslog(LOG_ALERT, 
-		       "Unable to splice to last logfile '%s' : %s",
-		       conf->loggers[i].filename, strerror(errno));
-		return PYFCGI_ERR;
-	}
-	if(ret < len)
-	{
-		_syslog(LOG_WARNING, 
-		       "Unable to splice all data to logfile. Flushing pipe.");
-
-		do
-		{
-			len -= (ret<len)?ret:len;
-			ret = read(conf->pipes[0], buf, (len>sizeof(buf))?sizeof(buf):len);
-			if(ret < 0)
-			{
-				_syslog(LOG_CRIT,
-				        "Logger pipe seems broken, unable to flush : %s",
-					strerror(errno));
-				return PYFCGI_ERR;
-			}
-		}while(len);
-	}
-	return 0;
+	return ret;
 }