aboutsummaryrefslogtreecommitdiff
path: root/src
diff options
context:
space:
mode:
authorJeff Davis <jdavis@postgresql.org>2015-09-07 15:40:49 -0700
committerJeff Davis <jdavis@postgresql.org>2015-09-07 15:40:49 -0700
commitb1e1862a123b6904d51fd0a607e30f5832bf9a1f (patch)
tree1fb81709321cf84a8340a3ac1a4595b493a81199 /src
parentd94c36a45ab457cf43bad76656f77778b3318523 (diff)
downloadpostgresql-b1e1862a123b6904d51fd0a607e30f5832bf9a1f.tar.gz
postgresql-b1e1862a123b6904d51fd0a607e30f5832bf9a1f.zip
Coordinate log_line_prefix options 'm' and 'n' to share a timeval.
Commit f828654e introduced the 'n' option, but it invoked gettimeofday() independently of the 'm' option. If both options were in use (or multiple 'n' options), or if 'n' was in use along with csvlog, then the reported times could be different for the same log message. To fix, initialize a global variable with gettimeofday() once per log message, and use that for both formats. Don't bother coordinating the time for the 't' option, which has much lower resolution. Per complaint by Alvaro Herrera.
Diffstat (limited to 'src')
-rw-r--r--src/backend/utils/error/elog.c32
1 files changed, 23 insertions, 9 deletions
diff --git a/src/backend/utils/error/elog.c b/src/backend/utils/error/elog.c
index 9114c55b66b..8b5b6c5241a 100644
--- a/src/backend/utils/error/elog.c
+++ b/src/backend/utils/error/elog.c
@@ -143,10 +143,14 @@ static int errordata_stack_depth = -1; /* index of topmost active frame */
static int recursion_depth = 0; /* to detect actual recursion */
-/* buffers for formatted timestamps that might be used by both
- * log_line_prefix and csv logs.
+/*
+ * Saved timeval and buffers for formatted timestamps that might be used by
+ * both log_line_prefix and csv logs.
*/
+static struct timeval saved_timeval;
+static bool saved_timeval_set = false;
+
#define FORMATTED_TS_LEN 128
static char formatted_start_time[FORMATTED_TS_LEN];
static char formatted_log_time[FORMATTED_TS_LEN];
@@ -2195,12 +2199,16 @@ write_console(const char *line, int len)
static void
setup_formatted_log_time(void)
{
- struct timeval tv;
pg_time_t stamp_time;
char msbuf[8];
- gettimeofday(&tv, NULL);
- stamp_time = (pg_time_t) tv.tv_sec;
+ if (!saved_timeval_set)
+ {
+ gettimeofday(&saved_timeval, NULL);
+ saved_timeval_set = true;
+ }
+
+ stamp_time = (pg_time_t) saved_timeval.tv_sec;
/*
* Note: we expect that guc.c will ensure that log_timezone is set up (at
@@ -2213,7 +2221,7 @@ setup_formatted_log_time(void)
pg_localtime(&stamp_time, log_timezone));
/* 'paste' milliseconds into place... */
- sprintf(msbuf, ".%03d", (int) (tv.tv_usec / 1000));
+ sprintf(msbuf, ".%03d", (int) (saved_timeval.tv_usec / 1000));
memcpy(formatted_log_time + 19, msbuf, 4);
}
@@ -2440,11 +2448,16 @@ log_line_prefix(StringInfo buf, ErrorData *edata)
break;
case 'n':
{
- struct timeval tv;
char strfbuf[128];
- gettimeofday(&tv, NULL);
- sprintf(strfbuf, "%ld.%03d", tv.tv_sec, (int)(tv.tv_usec / 1000));
+ if (!saved_timeval_set)
+ {
+ gettimeofday(&saved_timeval, NULL);
+ saved_timeval_set = true;
+ }
+
+ sprintf(strfbuf, "%ld.%03d", saved_timeval.tv_sec,
+ (int)(saved_timeval.tv_usec / 1000));
if (padding != 0)
appendStringInfo(buf, "%*s", padding, strfbuf);
@@ -2825,6 +2838,7 @@ send_message_to_server_log(ErrorData *edata)
initStringInfo(&buf);
+ saved_timeval_set = false;
formatted_log_time[0] = '\0';
log_line_prefix(&buf, edata);