"output" timestamp now taken from mesg's time generated

This enhances performance and, as some have pointed out, is
probably also more consistent with what users expect how
the various output-timestamp related function should work. This
commit needs some more testing.

5 files changed, 29 insertions, 11 deletions

diff --git a/runtime/datetime.c b/runtime/datetime.c
index 20ca6191..aa1956d7 100644
--- a/runtime/datetime.c
+++ b/runtime/datetime.c
@@ -62,9 +62,14 @@ DEFobjCurrIf(errmsg)
  * most portable and removes the need for additional structures
  * (but I have to admit it is somewhat "bulky";)).
  *
- * Obviously, all caller-provided pointers must not be NULL...
+ * Obviously, *t must not be NULL...
+ *
+ * rgerhards, 2008-10-07: added ttSeconds to provide a way to 
+ * obtain the second-resolution UNIX timestamp. This is needed
+ * in some situations to minimize time() calls (namely when doing
+ * output processing). This can be left NULL if not needed.
  */
-static void getCurrTime(struct syslogTime *t)
+static void getCurrTime(struct syslogTime *t, time_t *ttSeconds)
 {
 	struct timeval tp;
 	struct tm *tm;
@@ -83,6 +88,9 @@ static void getCurrTime(struct syslogTime *t)
 #	else
 		gettimeofday(&tp, NULL);
 #	endif
+	if(ttSeconds != NULL)
+		*ttSeconds = tp.tv_sec;
+
 	tm = localtime_r((time_t*) &(tp.tv_sec), &tmBuf);
 
 	t->year = tm->tm_year + 1900;
diff --git a/runtime/datetime.h b/runtime/datetime.h
index 2210af02..0739588d 100644
--- a/runtime/datetime.h
+++ b/runtime/datetime.h
@@ -35,7 +35,7 @@ typedef struct datetime_s {
 
 /* interfaces */
 BEGINinterface(datetime) /* name must also be changed in ENDinterface macro! */
-	void (*getCurrTime)(struct syslogTime *t);
+	void (*getCurrTime)(struct syslogTime *t, time_t *ttSeconds);
 	rsRetVal (*ParseTIMESTAMP3339)(struct syslogTime *pTime, char** ppszTS);
 	rsRetVal (*ParseTIMESTAMP3164)(struct syslogTime *pTime, char** pszTS);
 	int (*formatTimestampToMySQL)(struct syslogTime *ts, char* pDst, size_t iLenDst);
diff --git a/runtime/msg.c b/runtime/msg.c
index df8c1572..fd838591 100644
--- a/runtime/msg.c
+++ b/runtime/msg.c
@@ -286,11 +286,12 @@ finalize_it:
  * udp input).
  * rgerhards, 2008-10-06
  */
-rsRetVal msgConstructWithTime(msg_t **ppThis, struct syslogTime *stTime)
+rsRetVal msgConstructWithTime(msg_t **ppThis, struct syslogTime *stTime, time_t ttGenTime)
 {
 	DEFiRet;
 
 	CHKiRet(msgBaseConstruct(ppThis));
+	(*ppThis)->ttGenTime = ttGenTime;
 	memcpy(&(*ppThis)->tRcvdAt, stTime, sizeof(struct syslogTime));
 	memcpy(&(*ppThis)->tTIMESTAMP, stTime, sizeof(struct syslogTime));
 
@@ -316,7 +317,7 @@ rsRetVal msgConstruct(msg_t **ppThis)
 	 * especially as I think there is no codepath currently where it would not be
 	 * required (after I have cleaned up the pathes ;)). -- rgerhards, 2008-10-02
 	 */
-	datetime.getCurrTime(&((*ppThis)->tRcvdAt));
+	datetime.getCurrTime(&((*ppThis)->tRcvdAt), &((*ppThis)->ttGenTime));
 	memcpy(&(*ppThis)->tTIMESTAMP, &(*ppThis)->tRcvdAt, sizeof(struct syslogTime));
 
 finalize_it:
@@ -442,7 +443,7 @@ msg_t* MsgDup(msg_t* pOld)
 	assert(pOld != NULL);
 
 	BEGINfunc
-	if(msgConstruct(&pNew) != RS_RET_OK) {
+	if(msgConstructWithTime(&pNew, &pOld->tTIMESTAMP, pOld->ttGenTime) != RS_RET_OK) {
 		return NULL;
 	}
 
@@ -453,8 +454,7 @@ msg_t* MsgDup(msg_t* pOld)
 	pNew->bParseHOSTNAME = pOld->bParseHOSTNAME;
 	pNew->msgFlags = pOld->msgFlags;
 	pNew->iProtocolVersion = pOld->iProtocolVersion;
-	memcpy(&pNew->tRcvdAt, &pOld->tRcvdAt, sizeof(struct syslogTime));
-	memcpy(&pNew->tTIMESTAMP, &pOld->tTIMESTAMP, sizeof(struct syslogTime));
+	pNew->ttGenTime = pOld->ttGenTime;
 	tmpCOPYSZ(Severity);
 	tmpCOPYSZ(SeverityStr);
 	tmpCOPYSZ(Facility);
@@ -508,6 +508,7 @@ static rsRetVal MsgSerialize(msg_t *pThis, strm_t *pStrm)
 	objSerializeSCALAR(pStrm, iSeverity, SHORT);
 	objSerializeSCALAR(pStrm, iFacility, SHORT);
 	objSerializeSCALAR(pStrm, msgFlags, INT);
+	objSerializeSCALAR(pStrm, ttGenTime, INT);
 	objSerializeSCALAR(pStrm, tRcvdAt, SYSLOGTIME);
 	objSerializeSCALAR(pStrm, tTIMESTAMP, SYSLOGTIME);
 
@@ -1669,7 +1670,7 @@ static uchar *getNOW(eNOWType eNow)
 		return NULL;
 	}
 
-	datetime.getCurrTime(&t);
+	datetime.getCurrTime(&t, NULL);
 	switch(eNow) {
 	case NOW_NOW:
 		snprintf((char*) pBuf, tmpBUFSIZE, "%4.4d-%2.2d-%2.2d", t.year, t.month, t.day);
@@ -2477,6 +2478,8 @@ rsRetVal MsgSetProperty(msg_t *pThis, var_t *pProp)
 		MsgSetPROCID(pThis, (char*) rsCStrGetSzStrNoNULL(pProp->val.pStr));
 	} else if(isProp("pCSMSGID")) {
 		MsgSetMSGID(pThis, (char*) rsCStrGetSzStrNoNULL(pProp->val.pStr));
+ 	} else if(isProp("ttGenTime")) {
+		pThis->ttGenTime = pProp->val.num;
 	} else if(isProp("tRcvdAt")) {
 		memcpy(&pThis->tRcvdAt, &pProp->val.vSyslogTime, sizeof(struct syslogTime));
 	} else if(isProp("tTIMESTAMP")) {
diff --git a/runtime/msg.h b/runtime/msg.h
index d3c0718b..d2fc2f30 100644
--- a/runtime/msg.h
+++ b/runtime/msg.h
@@ -99,6 +99,13 @@ struct msg {
 	cstr_t *pCSAPPNAME;	/* APP-NAME */
 	cstr_t *pCSPROCID;	/* PROCID */
 	cstr_t *pCSMSGID;	/* MSGID */
+	time_t ttGenTime;	/* time msg object was generated, same as tRcvdAt, but a Unix timestamp.
+				   While this field looks redundant, it is required because a Unix timestamp
+				   is used at later processing stages (namely in the output arena). Thanks to
+				   the subleties of how time is defined, there is no reliable way to reconstruct
+				   the Unix timestamp from the syslogTime fields (in practice, we may be close
+				   enough to reliable, but I prefer to leave the subtle things to the OS, where
+				   it obviously is solved in way or another...). */
 	struct syslogTime tRcvdAt;/* time the message entered this program */
 	char *pszRcvdAt3164;	/* time as RFC3164 formatted string (always 15 charcters) */
 	char *pszRcvdAt3339;	/* time as RFC3164 formatted string (32 charcters at most) */
@@ -119,7 +126,7 @@ struct msg {
 PROTOTYPEObjClassInit(msg);
 char* getProgramName(msg_t*);
 rsRetVal msgConstruct(msg_t **ppThis);
-rsRetVal msgConstructWithTime(msg_t **ppThis, struct syslogTime *stTime);
+rsRetVal msgConstructWithTime(msg_t **ppThis, struct syslogTime *stTime, time_t ttGenTime);
 rsRetVal msgDestruct(msg_t **ppM);
 msg_t* MsgDup(msg_t* pOld);
 msg_t *MsgAddRef(msg_t *pM);
diff --git a/runtime/sysvar.c b/runtime/sysvar.c
index 5eec8f67..c102d1f5 100644
--- a/runtime/sysvar.c
+++ b/runtime/sysvar.c
@@ -84,7 +84,7 @@ getNOW(eNOWType eNow, cstr_t **ppStr)
 	uchar szBuf[16];
 	struct syslogTime t;
 
-	datetime.getCurrTime(&t);
+	datetime.getCurrTime(&t, NULL);
 	switch(eNow) {
 	case NOW_NOW:
 		snprintf((char*) szBuf, sizeof(szBuf)/sizeof(uchar), "%4.4d-%2.2d-%2.2d", t.year, t.month, t.day);