Thread: PATCH: numeric timestamp in log_line_prefix
Hi, from time to time I need to correlate PostgreSQL logs to other logs, containing numeric timestamps - a prime example of that is pgbench. With %t and %m that's not quite trivial, because of timezones etc. I propose adding two new log_line_prefix escape sequences - %T and %M, doing the same thing as %t and %m, but formatting the value as a number. Patch attached, I'll add it to CF 2015-06. regards -- Tomas Vondra http://www.2ndQuadrant.com/ PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services
Attachment
On Sun, Mar 22, 2015 at 12:47:12AM +0100, Tomas Vondra wrote: > Hi, > > from time to time I need to correlate PostgreSQL logs to other logs, > containing numeric timestamps - a prime example of that is pgbench. With > %t and %m that's not quite trivial, because of timezones etc. > > I propose adding two new log_line_prefix escape sequences - %T and %M, > doing the same thing as %t and %m, but formatting the value as a number. > > Patch attached, I'll add it to CF 2015-06. Uh, I think you mean "number" here: <entry>Time stamp without milliseconds (as a numer)</entry> ----- Also, what "number" do you mean? Unix time since 1970? -- Bruce Momjian <bruce@momjian.us> http://momjian.us EnterpriseDB http://enterprisedb.com + Everyone has their own god. +
On 22.3.2015 02:35, Bruce Momjian wrote: > On Sun, Mar 22, 2015 at 12:47:12AM +0100, Tomas Vondra wrote: >> Hi, >> >> from time to time I need to correlate PostgreSQL logs to other logs, >> containing numeric timestamps - a prime example of that is pgbench. With >> %t and %m that's not quite trivial, because of timezones etc. >> >> I propose adding two new log_line_prefix escape sequences - %T and %M, >> doing the same thing as %t and %m, but formatting the value as a number. >> >> Patch attached, I'll add it to CF 2015-06. > > Uh, I think you mean "number" here: > > <entry>Time stamp without milliseconds (as a numer)</entry> > ----- Oh, right, that's a stupid typo. > > Also, what "number" do you mean? Unix time since 1970? Yes, the usual unix timestamp. -- Tomas Vondra http://www.2ndQuadrant.com/ PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services
On Sun, Mar 22, 2015 at 02:41:44AM +0100, Tomas Vondra wrote: > > Uh, I think you mean "number" here: > > > > <entry>Time stamp without milliseconds (as a numer)</entry> > > ----- > > Oh, right, that's a stupid typo. > > > > > Also, what "number" do you mean? Unix time since 1970? > > Yes, the usual unix timestamp. I think you need to find out where we reference that and use the same wording. -- Bruce Momjian <bruce@momjian.us> http://momjian.us EnterpriseDB http://enterprisedb.com + Everyone has their own god. +
Bruce Momjian wrote: > On Sun, Mar 22, 2015 at 02:41:44AM +0100, Tomas Vondra wrote: > > > Uh, I think you mean "number" here: > > > > > > <entry>Time stamp without milliseconds (as a numer)</entry> > > > ----- > > > > Oh, right, that's a stupid typo. > > > > > > > > Also, what "number" do you mean? Unix time since 1970? > > > > Yes, the usual unix timestamp. > > I think you need to find out where we reference that and use the same > wording. We use "Unix epoch" in various places. -- Álvaro Herrera http://www.2ndQuadrant.com/ PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services
On 22 March 2015 at 12:47, Tomas Vondra <tomas.vondra@2ndquadrant.com> wrote:
I propose adding two new log_line_prefix escape sequences - %T and %M,
doing the same thing as %t and %m, but formatting the value as a number.
Hi Tomas,
I just had a quick glance at this.
Is there a reason you didn't include code to support the space padding for the new log_line_prefixes?
The others support %<padding><char> in the prefix, to allow left or right alignment of the item.
Also, what's the reason for timestamp_str? Could you not just use appendStringInfo() and skip the temporary buffer?
Regards
David Rowley
About the feature: I find it is a good thing. It may help scripting over the logs, for instance to compute delays between events, whereas the full date-time-tz syntax is maybe nice but heavier to work with afterwards. In addition to the comments already made (typo in doc, padding...): + sprintf(timestamp_str, "%ld.%.03d", + tv.tv_sec, (int)(tv.tv_usec / 1000)); I'm not sure that the "." in "%.03d" is useful. ISTM that it is used for floatting point formatting, but is not needed with integers. -- Fabien.
On 22.3.2015 16:58, Fabien COELHO wrote: > > About the feature: I find it is a good thing. It may help scripting over > the logs, for instance to compute delays between events, whereas the > full date-time-tz syntax is maybe nice but heavier to work with afterwards. > > In addition to the comments already made (typo in doc, padding...): > > + sprintf(timestamp_str, "%ld.%.03d", > + tv.tv_sec, (int)(tv.tv_usec / 1000)); > > I'm not sure that the "." in "%.03d" is useful. ISTM that it is used for > floatting point formatting, but is not needed with integers. It is needed for integers, because you need to make sure 1 millisecond is formatted as .001 and not .1. -- Tomas Vondra http://www.2ndQuadrant.com/ PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services
On 22.3.2015 08:14, David Rowley wrote: > Hi Tomas, > > I just had a quick glance at this. > Is there a reason you didn't include code to support the space padding > for the new log_line_prefixes? > The others support %<padding><char> in the prefix, to allow left or > right alignment of the item. Didn't realize that, will fix in the next version. > > Also, what's the reason for timestamp_str? Could you not just use > appendStringInfo() and skip the temporary buffer? Yeah, that's probably a good idea too. > > Regards > > David Rowley -- Tomas Vondra http://www.2ndQuadrant.com/ PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services
>> I'm not sure that the "." in "%.03d" is useful. ISTM that it is used for >> floatting point formatting, but is not needed with integers. > > It is needed for integers, because you need to make sure 1 millisecond > is formatted as .001 and not .1. ISTM that the "03" does that on its own: sh> printf "%03d\n" 0 1 2 000 001 002 -- Fabien.
On 2015-03-22 00:47:12 +0100, Tomas Vondra wrote: > from time to time I need to correlate PostgreSQL logs to other logs, > containing numeric timestamps - a prime example of that is pgbench. With > %t and %m that's not quite trivial, because of timezones etc. I have a hard time seing this is sufficient cause for adding more format codes. They're not free runtime and documentation wise. -0.5 from me. Greetings, Andres Freund -- Andres Freund http://www.2ndQuadrant.com/PostgreSQL Development, 24x7 Support, Training & Services
> On 2015-03-22 00:47:12 +0100, Tomas Vondra wrote: >> from time to time I need to correlate PostgreSQL logs to other logs, >> containing numeric timestamps - a prime example of that is pgbench. With >> %t and %m that's not quite trivial, because of timezones etc. > > I have a hard time seing this is sufficient cause for adding more format > codes. They're not free runtime and documentation wise. -0.5 from me. The proposed format is much simpler to manage in a script, and if you're interested in runtime, its formatting would be less expensive than %t and %m. -- Fabien.
Fabien COELHO <coelho@cri.ensmp.fr> writes: >> On 2015-03-22 00:47:12 +0100, Tomas Vondra wrote: >>> from time to time I need to correlate PostgreSQL logs to other logs, >>> containing numeric timestamps - a prime example of that is pgbench. With >>> %t and %m that's not quite trivial, because of timezones etc. >> I have a hard time seing this is sufficient cause for adding more format >> codes. They're not free runtime and documentation wise. -0.5 from me. > The proposed format is much simpler to manage in a script, and if you're > interested in runtime, its formatting would be less expensive than %t and > %m. Maybe, but do we really need two? How about just %M? Also, having just one would open the door to calling it something like %u (for Unix timestamp), which would avoid introducing the concept of upper case meaning something-different-from-but-related-to into log_line_prefix format codes. We don't have any upper case codes in there now, and I'd prefer not to go there if we don't have to. regards, tom lane
On Sat, Mar 21, 2015 at 4:47 PM, Tomas Vondra <tomas.vondra@2ndquadrant.com> wrote:
Hi,
from time to time I need to correlate PostgreSQL logs to other logs,
containing numeric timestamps - a prime example of that is pgbench. With
%t and %m that's not quite trivial, because of timezones etc.
I propose adding two new log_line_prefix escape sequences - %T and %M,
doing the same thing as %t and %m, but formatting the value as a number.
Patch attached, I'll add it to CF 2015-06.
I've wanted this before as well. But what is the point of %T? Does printing the milliseconds cause
some kind of detectable performance hit?
I don't think I've ever thought myself "You know, I really wish I hadn't included the milliseconds in that timestamp".
Same question for %t, but that ship has already sailed.
Cheers,
Jeff
[oops, stalled because of wrong From, resending just to the list] On Sun, 22 Mar 2015, Tom Lane wrote: >> The proposed format is much simpler to manage in a script, and if you're >> interested in runtime, its formatting would be less expensive than %t and >> %m. > > Maybe, but do we really need two? How about just %M? Yep, truncating or rounding if needed is quite easy. > Also, having just one would open the door to calling it something like > %u (for Unix timestamp), Should be ok as well. -- Fabien.
On 22.3.2015 19:45, Fabien COELHO wrote: > >>> I'm not sure that the "." in "%.03d" is useful. ISTM that it is used for >>> floatting point formatting, but is not needed with integers. >> >> It is needed for integers, because you need to make sure 1 millisecond >> is formatted as .001 and not .1. > > ISTM that the "03" does that on its own: > > sh> printf "%03d\n" 0 1 2 > 000 > 001 > 002 Oh, right - one dot too many. Thanks, will fix that. -- Tomas Vondra http://www.2ndQuadrant.com/ PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services
On 22.3.2015 20:25, Fabien COELHO wrote: > >>> The proposed format is much simpler to manage in a script, and if you're >>> interested in runtime, its formatting would be less expensive than %t >>> and >>> %m. >> >> Maybe, but do we really need two? How about just %M? > > I guess Tomas put 2 formats because there was 2 time formats to > begin with, but truncating/rouding if someone really wants seconds is > quite easy. Yes, that's why I added two - to reflect %t and %m. I'm OK with using just one of them - I don't really care for the milliseconds at this moment, but I'd probably choose that option. >> Also, having just one would open the door to calling it something >> like %u (for Unix timestamp), > > I guess that is okay as well. Whatever, I don't really care. It's slightly confusing because unix timestams are usually integers, but IMHO that's minor difference. -- Tomas Vondra http://www.2ndQuadrant.com/ PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services
>> The proposed format is much simpler to manage in a script, and if you're >> interested in runtime, its formatting would be less expensive than %t and >> %m. > > Maybe, but do we really need two? How about just %M? I guess Tomas put 2 formats because there was 2 time formats to begin with, but truncating/rouding if someone really wants seconds is quite easy. > Also, having just one would open the door to calling it something like > %u (for Unix timestamp), I guess that is okay as well. -- Fabien.
On 3/22/15 2:59 PM, Tomas Vondra wrote: > On 22.3.2015 20:25, Fabien COELHO wrote: >> > >>>> >>>The proposed format is much simpler to manage in a script, and if you're >>>> >>>interested in runtime, its formatting would be less expensive than %t >>>> >>>and >>>> >>>%m. >>> >> >>> >>Maybe, but do we really need two? How about just %M? >> > >> >I guess Tomas put 2 formats because there was 2 time formats to >> >begin with, but truncating/rouding if someone really wants seconds is >> >quite easy. > Yes, that's why I added two - to reflect %t and %m. I'm OK with using > just one of them - I don't really care for the milliseconds at this > moment, but I'd probably choose that option. I assume we're using milli instead of micro because that's what everyone else does? It seems odd since we natively support microseconds, but I guess if milliseconds is more normal for logging that's OK. FWIW, I don't see a problem with both %T and %M (whatever M ends up meaning), but I don't really care either way. -- Jim Nasby, Data Architect, Blue Treble Consulting Data in Trouble? Get it in Treble! http://BlueTreble.com
On 23.3.2015 23:02, Jim Nasby wrote: > On 3/22/15 2:59 PM, Tomas Vondra wrote: >> On 22.3.2015 20:25, Fabien COELHO wrote: >> >>> I guess Tomas put 2 formats because there was 2 time formats >>> to begin with, but truncating/rouding if someone really wants >>> seconds is quite easy. >> >> Yes, that's why I added two - to reflect %t and %m. I'm OK with >> using just one of them - I don't really care for the milliseconds >> at this moment, but I'd probably choose that option. > > I assume we're using milli instead of micro because that's what > everyone else does? It seems odd since we natively support > microseconds, but I guess if milliseconds is more normal for logging > that's OK. That's because %m is using milliseconds. I don't think microseconds are really useful here ... > FWIW, I don't see a problem with both %T and %M (whatever M ends up > meaning), but I don't really care either way. Same here. -- Tomas Vondra http://www.2ndQuadrant.com/ PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services
Hello Tomas, > from time to time I need to correlate PostgreSQL logs to other logs, > containing numeric timestamps - a prime example of that is pgbench. With > %t and %m that's not quite trivial, because of timezones etc. > > I propose adding two new log_line_prefix escape sequences - %T and %M, > doing the same thing as %t and %m, but formatting the value as a number. > > Patch attached, I'll add it to CF 2015-06. Are you planing to update this patch? I was wanting to use it for some tests and figured out that it had stayed as a proposal, too bad. I would suggest to maybe follow Tom's %u idea and fix the implementation details wrt to comments received? It seems to me that always having milliseconds "123456789.012" would be fine, it can easily be filtered out if not necessary or would be there if useful, so maybe just one more format is enough. -- Fabien.
Hi, On 08/22/2015 08:39 AM, Fabien COELHO wrote: > > Hello Tomas, > >> from time to time I need to correlate PostgreSQL logs to other logs, >> containing numeric timestamps - a prime example of that is pgbench. With >> %t and %m that's not quite trivial, because of timezones etc. >> >> I propose adding two new log_line_prefix escape sequences - %T and %M, >> doing the same thing as %t and %m, but formatting the value as a number. >> >> Patch attached, I'll add it to CF 2015-06. > > Are you planing to update this patch? I was wanting to use it for some > tests and figured out that it had stayed as a proposal, too bad. > > I would suggest to maybe follow Tom's %u idea and fix the implementation > details wrt to comments received? Yes, I plan to update it according to those comments. regards -- Tomas Vondra http://www.2ndQuadrant.com PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services
Hi all, attached is a v2 of the patch, reworked based on the comments. 1) fix the docs (explicitly say that it's a Unix epoch) 2) handle 'padding' properly 3) get rid of timestamp_str - use appendString* methods directly 4) support just the "with milliseconds" using '%n' escape sequence All those changes are quite trivial. The only annoying bit is that both '%u' and '%e' are already used, so none of the obvious choices for 'Unix Epoch' are available. So I simply took (%m+1) which is %n. regards -- Tomas Vondra http://www.2ndQuadrant.com PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services
Attachment
Hello Tomas, Review of v2: > attached is a v2 of the patch, reworked based on the comments. The patch applies cleanly to head, it compiles, I tested it and it mostly work as expected, see below. > 1) fix the docs (explicitly say that it's a Unix epoch) I would add the word "numeric" in front of timestamp both in the doc and in the postgresql.conf.sample, as it justifies the chosen %n. > 2) handle 'padding' properly I tried that without success. ISTM that what is padded is the empty string, and the timestamp is just printed on its own without padding afterwards. I think that it should use a string buffer and then used the padding on the string, as case 'c' or 't' for instance. > 3) get rid of timestamp_str - use appendString* methods directly See above, I'm afraid it is necessary for padding, because there are two formatted fields. > 4) support just the "with milliseconds" using '%n' escape sequence Ok. > All those changes are quite trivial. The only annoying bit is that both '%u' > and '%e' are already used, so none of the obvious choices for 'Unix Epoch' > are available. So I simply took (%m+1) which is %n. It stands for "numeric" as well, so I think it is quite nice. -- Fabien.
On 08/22/2015 09:54 PM, Fabien COELHO wrote: > > Hello Tomas, > > Review of v2: > >> attached is a v2 of the patch, reworked based on the comments. > > The patch applies cleanly to head, it compiles, I tested it and it > mostly work as expected, see below. > >> 1) fix the docs (explicitly say that it's a Unix epoch) > > I would add the word "numeric" in front of timestamp both in the doc and > in the postgresql.conf.sample, as it justifies the chosen %n. I think we're already using 'unix epoch' in the docs without explicitly stating that it's a numeric value, so I don't think we should use it here as it'd be inconsistent. > >> 2) handle 'padding' properly > > I tried that without success. ISTM that what is padded is the empty > string, and the timestamp is just printed on its own without padding > afterwards. > > I think that it should use a string buffer and then used the padding on > the string, as case 'c' or 't' for instance. Hmmm, I'm not entirely sure how exactly the padding is supposed to work (IIRC I've never used it), and I thought it behaved correctly. But maybe not - I think the safest thing is copy what 't' does, so I've done that in attached v3 of the patch. regards -- Tomas Vondra http://www.2ndQuadrant.com PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services
Attachment
>>> 1) fix the docs (explicitly say that it's a Unix epoch) >> >> I would add the word "numeric" in front of timestamp both in the doc and >> in the postgresql.conf.sample, as it justifies the chosen %n. > > I think we're already using 'unix epoch' in the docs without explicitly > stating that it's a numeric value, so I don't think we should use it here as > it'd be inconsistent. The point was to justify the choice of 'n' somehow. >>> 2) handle 'padding' properly > > Hmmm, I'm not entirely sure how exactly the padding is supposed to work (IIRC > I've never used it), and I thought it behaved correctly. But maybe not - I > think the safest thing is copy what 't' does, so I've done that in attached > v3 of the patch. Ok. Version 3 applies and compiles, and padding now works as expected. Here is a v4 that I also tested, and where I just removed a spurious '.' in the millisecond format. -- Fabien.
On 08/23/2015 09:28 AM, Fabien COELHO wrote: > >>>> 1) fix the docs (explicitly say that it's a Unix epoch) >>> >>> I would add the word "numeric" in front of timestamp both in the doc and >>> in the postgresql.conf.sample, as it justifies the chosen %n. >> >> I think we're already using 'unix epoch' in the docs without >> explicitly stating that it's a numeric value, so I don't think we >> should use it here as it'd be inconsistent. > > The point was to justify the choice of 'n' somehow. > >>>> 2) handle 'padding' properly >> >> Hmmm, I'm not entirely sure how exactly the padding is supposed to >> work (IIRC I've never used it), and I thought it behaved correctly. >> But maybe not - I think the safest thing is copy what 't' does, so >> I've done that in attached v3 of the patch. > > Ok. Version 3 applies and compiles, and padding now works as expected. > > Here is a v4 that I also tested, and where I just removed a spurious '.' > in the millisecond format. Thanks for spotting that. regards -- Tomas Vondra http://www.2ndQuadrant.com PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services
> + case 'n': > + { > + struct timeval tv; > + char strfbuf[128]; > + > + gettimeofday(&tv, NULL); > + sprintf(strfbuf, "%ld.%03d", tv.tv_sec, (int)(tv.tv_usec / 1000)); > + > + if (padding != 0) > + appendStringInfo(buf, "%*s", padding, strfbuf); > + else > + appendStringInfoString(buf, strfbuf); > + } > + break; I wonder about this separate gettimeofday() call. We already have formatted_log_time which is used for CSV logs and freeform log lines (stderr/syslog); if we introduce a separate gettimeofday() call here, and the user has %n in freeform log and CSV logging is active, the timings will diverge occasionally. Maybe I'm worrying over nothing, because really what use case is there for having the two log formats enabled at the same time? Yet somebody went some lengths to ensure they are consistent; I think we should do likewise here. I'm happy to be outvoted on this, so consider this a -0.5 for this particular implementation. -- Álvaro Herrera http://www.2ndQuadrant.com/ PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services
On Sun, 2015-03-22 at 19:47 +0100, Andres Freund wrote: > On 2015-03-22 00:47:12 +0100, Tomas Vondra wrote: > > from time to time I need to correlate PostgreSQL logs to other logs, > > containing numeric timestamps - a prime example of that is pgbench. With > > %t and %m that's not quite trivial, because of timezones etc. > > I have a hard time seing this is sufficient cause for adding more format > codes. They're not free runtime and documentation wise. -0.5 from me. I am about to commit this patch (the one that adds a single extra option). Although nothing is free, the cost seems very low, and at least three people have expressed interest in this patch. What tips the balance is that we expose the unix epoch in the pgbench logs, as Tomas points out. Regards,Jeff Davis
Jeff Davis wrote: > On Sun, 2015-03-22 at 19:47 +0100, Andres Freund wrote: > > On 2015-03-22 00:47:12 +0100, Tomas Vondra wrote: > > > from time to time I need to correlate PostgreSQL logs to other logs, > > > containing numeric timestamps - a prime example of that is pgbench. With > > > %t and %m that's not quite trivial, because of timezones etc. > > > > I have a hard time seing this is sufficient cause for adding more format > > codes. They're not free runtime and documentation wise. -0.5 from me. > > I am about to commit this patch (the one that adds a single extra > option). Although nothing is free, the cost seems very low, and at least > three people have expressed interest in this patch. Did you see my message at http://www.postgresql.org/message-id/20150907192719.GS2912@alvherre.pgsql ? -- Álvaro Herrera http://www.2ndQuadrant.com/ PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services
On Mon, 2015-09-07 at 17:47 -0300, Alvaro Herrera wrote: > Jeff Davis wrote: > > On Sun, 2015-03-22 at 19:47 +0100, Andres Freund wrote: > > > On 2015-03-22 00:47:12 +0100, Tomas Vondra wrote: > > > > from time to time I need to correlate PostgreSQL logs to other logs, > > > > containing numeric timestamps - a prime example of that is pgbench. With > > > > %t and %m that's not quite trivial, because of timezones etc. > > > > > > I have a hard time seing this is sufficient cause for adding more format > > > codes. They're not free runtime and documentation wise. -0.5 from me. > > > > I am about to commit this patch (the one that adds a single extra > > option). Although nothing is free, the cost seems very low, and at least > > three people have expressed interest in this patch. > > Did you see my message at http://www.postgresql.org/message-id/20150907192719.GS2912@alvherre.pgsql ? I guess we were looking at this at the same time, and I missed your message and committed it. I will investigate now. Regards,Jeff Davis
> I wonder about this separate gettimeofday() call. We already have > formatted_log_time which is used for CSV logs and freeform log lines > (stderr/syslog); if we introduce a separate gettimeofday() call here, > and the user has %n in freeform log and CSV logging is active, the > timings will diverge occasionally. > > Maybe I'm worrying over nothing, because really what use case is there > for having the two log formats enabled at the same time? Yet somebody > went some lengths to ensure they are consistent; I think we should do > likewise here. We now have three time-related options[1]: t, m, and n; and they each acquire the time independently. Are you suggesting that we make all three consistent, or only m and n? The cleanest fix would be for the global variable to only hold the timeval, and then format it once for the CSV log (always 'm' format) and once for the regular log ('m', 'n', or 't'). If the regular log uses 'm', that would be some wasted cycles formatting it the same way twice. Is it worth a little extra ugliness to cache both the timeval and the formatted string? Regards,Jeff Davis [1] As of minutes ago, after I missed your message by a few minutes.
Jeff Davis wrote: > > I wonder about this separate gettimeofday() call. We already have > > formatted_log_time which is used for CSV logs and freeform log lines > > (stderr/syslog); if we introduce a separate gettimeofday() call here, > > and the user has %n in freeform log and CSV logging is active, the > > timings will diverge occasionally. > > > > Maybe I'm worrying over nothing, because really what use case is there > > for having the two log formats enabled at the same time? Yet somebody > > went some lengths to ensure they are consistent; I think we should do > > likewise here. > > We now have three time-related options[1]: t, m, and n; and they each > acquire the time independently. Are you suggesting that we make all > three consistent, or only m and n? I noticed %t, but I don't think we care since the precision is so poor. Making m and n work in unison seems enough. I think it would be reasonably simple to handle %t in the same way, but I'm not sure we care. (TBH I question that %t has any usefulness at all. Maybe we should phase it out ...) > The cleanest fix would be for the global variable to only hold the > timeval, and then format it once for the CSV log (always 'm' format) and > once for the regular log ('m', 'n', or 't'). If the regular log uses > 'm', that would be some wasted cycles formatting it the same way twice. > Is it worth a little extra ugliness to cache both the timeval and the > formatted string? I think the extra ugliness is warranted, since it's not THAT much additional ugliness, and not doing it could be considered a regression; apparently strftime can be slower even than snprintf, so doing it twice per log message might be excessive overhead. -- Álvaro Herrera http://www.2ndQuadrant.com/ PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services
On Mon, 2015-09-07 at 18:28 -0300, Alvaro Herrera wrote: > I noticed %t, but I don't think we care since the precision is so poor. > Making m and n work in unison seems enough. I think it would be > reasonably simple to handle %t in the same way, but I'm not sure we > care. OK. > I think the extra ugliness is warranted, since it's not THAT much > additional ugliness, and not doing it could be considered a regression; > apparently strftime can be slower even than snprintf, so doing it twice > per log message might be excessive overhead. Patch attached. Please take a quick look. Regards, Jeff Davis
Attachment
Jeff Davis wrote: > On Mon, 2015-09-07 at 18:28 -0300, Alvaro Herrera wrote: > > I think the extra ugliness is warranted, since it's not THAT much > > additional ugliness, and not doing it could be considered a regression; > > apparently strftime can be slower even than snprintf, so doing it twice > > per log message might be excessive overhead. > > Patch attached. Please take a quick look. Looks good. -- Álvaro Herrera http://www.2ndQuadrant.com/ PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services