Re: [HACKERS] Problem with log_timezone not being set during early startup
Tom Lane wrote: I came across a problem with the log_timezone patch. Given these conditions: * log_min_messages is at least debug3 * log_line_prefix includes %t or %m * log_timezone is not explicitly set in postgresql.conf the postmaster will dump core during startup, because it tries to format an elog message using log_timezone while the variable is still NULL. I can think of several ways of fixing this, but they all have drawbacks: 1. Tweak elog.c so that the timestamp-formatting escapes are disregarded if log_timezone is still NULL. This is simple and robust, but some will complain that early-startup messages are formatted differently from those appearing later. I don't put a lot of weight on that, because it is *necessarily* the case that messages appearing before GUCs are all initialized will look different from those later. But it's a bit annoying, and might be more than a bit annoying for CSV-format logging. Any way to tweak this place and have it log in GMT instead, when log_timezone is NULL? That way it would only change the early startup messages (thus avoiding the concern in #2), but it'd still show the timezone (different from the system, but it'd be something deterministic). I think that's better than just dropping the TZ information. If not, I still agree with you that #1 is the best way to go from these. 2. Tweak pg_localtime() so that it takes a null tz argument as meaning GMT. I find this one pretty ugly --- it seems to remove a useful error check even after startup. Also, it's not clear whether having messages that are labeled in the wrong timezone is better or worse than not labeling them at all. I'm also a bit worried whether invoking tzload() too early in startup would work reliably. Depends on what you mean with wrong timezone. If they're labelled with a timezone that's not the same as the time is in, then it's very very bad because it gives you the wrong time. If you mean labeling them as GMT when the user expected EST (or whatever), think that's better than no TZ at all - as long as we specify the TZ, the time is exact, even if the user may need to do some calculations to figure out it in the local one. I do agree that removing that error check is bad. //Magnus ---(end of broadcast)--- TIP 7: You can help support the PostgreSQL project by donating at http://www.postgresql.org/about/donate
Re: [HACKERS] Problem with log_timezone not being set during early startup
Magnus Hagander [EMAIL PROTECTED] writes: Any way to tweak this place and have it log in GMT instead, when log_timezone is NULL? I think this is just a variant of my #2. The main risk factor IMHO is that the first call is going to invoke tzload() for the GMT zone (pgtz does not seem to special-case GMT in any meaningful way), and it's not entirely clear how much infrastructure has to be up before that would work. It's probably all right, seeing that we won't get here until GUC has set log_line_prefix to something nondefault, but I haven't tried it. There's a value judgment involved here: is it better to print timestamps in GMT (which the user won't be expecting) than to not print them at all? I can see arguments on both sides of that. regards, tom lane ---(end of broadcast)--- TIP 7: You can help support the PostgreSQL project by donating at http://www.postgresql.org/about/donate
Re: [HACKERS] Problem with log_timezone not being set during early startup
On Sat, Aug 04, 2007 at 12:12:46PM -0400, Tom Lane wrote: There's a value judgment involved here: is it better to print timestamps in GMT (which the user won't be expecting) than to not print them at all? I can see arguments on both sides of that. As long as it's clear that the times are in GMT I think that's better. Something else to consider... normally you'd have to have a pretty serious condition to run into this in normal usage, right? (I doubt there's many folks that use any debug level, let alone 3) I think that gives us more flexibility. -- Decibel!, aka Jim Nasby[EMAIL PROTECTED] EnterpriseDB http://enterprisedb.com 512.569.9461 (cell) pgpnQP1C7keFc.pgp Description: PGP signature
Re: [HACKERS] Problem with log_timezone not being set during early startup
Decibel! [EMAIL PROTECTED] writes: Something else to consider... normally you'd have to have a pretty serious condition to run into this in normal usage, right? (I doubt there's many folks that use any debug level, let alone 3) I think that gives us more flexibility. Yeah. This whole issue will really only affect developers, except for cases where startup fails completely. I complained earlier that tzload() might be unsafe if invoked too early, but actually there's a worse issue, which is circularity: it's far from clear that that code path cannot invoke elog itself. (Even if it doesn't today, someone might innocently stick a debugging elog into someplace like get_share_path.) This could be worked around, with some hack on the order of forcing GMT zone to be loaded before we begin GUC initialization, but I'm really wondering how much work we want to put into a marginal nicety. regards, tom lane ---(end of broadcast)--- TIP 3: Have you checked our extensive FAQ? http://www.postgresql.org/docs/faq
Re: [HACKERS] Problem with log_timezone not being set during early startup
On Sat, Aug 04, 2007 at 12:46:32PM -0400, Tom Lane wrote: Decibel! [EMAIL PROTECTED] writes: Something else to consider... normally you'd have to have a pretty serious condition to run into this in normal usage, right? (I doubt there's many folks that use any debug level, let alone 3) I think that gives us more flexibility. Yeah. This whole issue will really only affect developers, except for cases where startup fails completely. And when startup fails completely, you're far less likely to care about timezone. Perhaps if we don't have log_timezone set yet we could output something such as 'LOCALTIME' so that it was obvious. Or maybe output whatever $TZ is set to? -- Decibel!, aka Jim Nasby[EMAIL PROTECTED] EnterpriseDB http://enterprisedb.com 512.569.9461 (cell) pgpHbuL5Zpsw5.pgp Description: PGP signature
Re: [HACKERS] Problem with log_timezone not being set during early startup
Decibel! [EMAIL PROTECTED] writes:
Perhaps if we don't have log_timezone set yet we could output something
such as 'LOCALTIME' so that it was obvious. Or maybe output whatever $TZ
is set to?
I think you're confused. This is not a matter of knowing what to print
for the timezone part, it's how do we print the timestamp at all.
I've got a patch that seems to work, but I'm a bit dissatisfied with
making guc.c explicitly aware of this issue. Haven't thought of a
better place to put the call though...
regards, tom lane
Index: src/backend/utils/error/elog.c
===
RCS file: /cvsroot/pgsql/src/backend/utils/error/elog.c,v
retrieving revision 1.192
diff -c -r1.192 elog.c
*** src/backend/utils/error/elog.c 4 Aug 2007 01:26:54 - 1.192
--- src/backend/utils/error/elog.c 4 Aug 2007 17:21:26 -
***
*** 1497,1512
{
struct timeval tv;
pg_time_t stamp_time;
charstrfbuf[128],
msbuf[8];
gettimeofday(tv, NULL);
stamp_time = (pg_time_t) tv.tv_sec;
pg_strftime(strfbuf, sizeof(strfbuf),
/* leave room
for milliseconds... */
%Y-%m-%d
%H:%M:%S %Z,
!
pg_localtime(stamp_time, log_timezone));
/* 'paste' milliseconds into place... */
sprintf(msbuf, .%03d, (int)
(tv.tv_usec / 1000));
--- 1497,1521
{
struct timeval tv;
pg_time_t stamp_time;
+ pg_tz *tz;
charstrfbuf[128],
msbuf[8];
gettimeofday(tv, NULL);
stamp_time = (pg_time_t) tv.tv_sec;
+ /*
+* Normally we print log timestamps in
log_timezone, but
+* during startup we could get here
before that's set.
+* If so, fall back to gmt_timezone
(which must be set
+* up already).
+*/
+ tz = log_timezone ? log_timezone :
gmt_timezone;
+
pg_strftime(strfbuf, sizeof(strfbuf),
/* leave room
for milliseconds... */
%Y-%m-%d
%H:%M:%S %Z,
!
pg_localtime(stamp_time, tz));
/* 'paste' milliseconds into place... */
sprintf(msbuf, .%03d, (int)
(tv.tv_usec / 1000));
***
*** 1518,1539
case 't':
{
pg_time_t stamp_time =
(pg_time_t) time(NULL);
charstrfbuf[128];
pg_strftime(strfbuf, sizeof(strfbuf),
%Y-%m-%d
%H:%M:%S %Z,
!
pg_localtime(stamp_time, log_timezone));
appendStringInfoString(buf, strfbuf);
}
break;
case 's':
{
pg_time_t stamp_time =
(pg_time_t) MyStartTime;
charstrfbuf[128];
pg_strftime(strfbuf, sizeof(strfbuf),
%Y-%m-%d
%H:%M:%S %Z,
!
pg_localtime(stamp_time, log_timezone));
appendStringInfoString(buf, strfbuf);
}
break;
--- 1527,1554
case 't':
{
