Re: pgbench logging broken by time logic changes

2021-12-02 Thread Daniel Gustafsson
> On 4 Nov 2021, at 13:38, Daniel Gustafsson wrote: > >> On 11 Jul 2021, at 15:07, Fabien COELHO wrote: > >> Attached the fully "ignored" version of the time features test as a patch. > > This version of the patch is failing to apply on top of HEAD, can you please > submit a rebased version?

Re: pgbench logging broken by time logic changes

2021-11-04 Thread Daniel Gustafsson
> On 11 Jul 2021, at 15:07, Fabien COELHO wrote: > Attached the fully "ignored" version of the time features test as a patch. This version of the patch is failing to apply on top of HEAD, can you please submit a rebased version? -- Daniel Gustafsson https://vmware.com/

Re: pgbench logging broken by time logic changes

2021-07-11 Thread Fabien COELHO
Hello Thomas, I committed the code change without the new TAP tests, because I didn't want to leave the open item hanging any longer. Ok. Good. As for the test, ... [...] Argh, so there are no tests that would have caught the regressions:-( ... I know it can fail, and your v18 didn't f

Re: pgbench logging broken by time logic changes

2021-07-11 Thread Thomas Munro
Hi Fabien, I committed the code change without the new TAP tests, because I didn't want to leave the open item hanging any longer. As for the test, ... On Sat, Jul 10, 2021 at 9:36 PM Fabien COELHO wrote: > >> I hoped we were done here but I realised that your check for 1-3 log > >> lines will

Re: pgbench logging broken by time logic changes

2021-07-10 Thread Fabien COELHO
Hello again, I hoped we were done here but I realised that your check for 1-3 log lines will not survive the harsh environment of the build farm. Adding sleep(2) before the final doLog() confirms that. I had two ideas: So I think we should do 1 for now. Objections or better ideas? At lea

Re: pgbench logging broken by time logic changes

2021-07-10 Thread Fabien COELHO
Works for me: patch applies, global and local check ok. I'm fine with it. I hoped we were done here but I realised that your check for 1-3 log lines will not survive the harsh environment of the build farm. Adding sleep(2) before the final doLog() confirms that. I had two ideas: 1. Give up

Re: pgbench logging broken by time logic changes

2021-07-09 Thread Thomas Munro
On Fri, Jul 9, 2021 at 5:14 PM Fabien COELHO wrote: > Works for me: patch applies, global and local check ok. I'm fine with it. I hoped we were done here but I realised that your check for 1-3 log lines will not survive the harsh environment of the build farm. Adding sleep(2) before the final doL

Re: pgbench logging broken by time logic changes

2021-07-08 Thread Fabien COELHO
Hello Thomas, Isn't it better if we only have to throw away the first one?). This should be the user decision to drop it or not, not the tool producing it, IMO. Let me try this complaint again. [...] I understand your point. For me removing silently the last bucket is not right because

Re: pgbench logging broken by time logic changes

2021-07-08 Thread Thomas Munro
On Fri, Jul 9, 2021 at 5:15 AM Fabien COELHO wrote: > > Thanks! This doesn't seem to address the complaint, though. Don't > > you need to do something like this? (See also attached.) > > > > +initStats(&aggs, start - (start + epoch_shift) % 100); > > ISTM that this is: (start + epoch_sh

Re: pgbench logging broken by time logic changes

2021-07-08 Thread Fabien COELHO
Hello Hannu, I'm not sure we have transaction lasts for very short time that nanoseconds matters. Nanoseconds may not matter yet, but they could be handy when for example we want to determine the order of parallel query executions. We are less than an order of magnitude away from being able

Re: pgbench logging broken by time logic changes

2021-07-08 Thread Fabien COELHO
Hello Thomas, Thanks! This doesn't seem to address the complaint, though. Don't you need to do something like this? (See also attached.) +initStats(&aggs, start - (start + epoch_shift) % 100); ISTM that this is: (start + epoch_shift) / 100 * 100 That should reproduce wha

Re: pgbench logging broken by time logic changes

2021-07-08 Thread Hannu Krosing
On Thu, Jun 17, 2021 at 7:18 AM Kyotaro Horiguchi wrote: > > I'm not sure we have transaction lasts for very short time that > nanoseconds matters. > Nanoseconds may not matter yet, but they could be handy when for example we want to determine the order of parallel query executions. We are less

Re: pgbench logging broken by time logic changes

2021-07-08 Thread Thomas Munro
On Thu, Jul 1, 2021 at 8:50 PM Fabien COELHO wrote: > Attached a v14 in that spirit. Thanks! This doesn't seem to address the complaint, though. Don't you need to do something like this? (See also attached.) +initStats(&aggs, start - (start + epoch_shift) % 100); That should reproduc

Re: pgbench logging broken by time logic changes

2021-07-01 Thread Fabien COELHO
Hello Thomas, After looking at it again, here is an update which ensure 64 bits on epoch_shift computation. The code in pgbench 13 aggregates into buckets that begin on the boundaries of wall clock seconds, because it is triggered by changes in time_t. In the current patch, we aggregate data

Re: pgbench logging broken by time logic changes

2021-06-30 Thread Thomas Munro
On Wed, Jun 30, 2021 at 9:55 PM Fabien COELHO wrote: > >> Fabien, thanks for the updated patch, I'm looking at it. > > After looking at it again, here is an update which ensure 64 bits on > epoch_shift computation. Hi Fabien, The code in pgbench 13 aggregates into buckets that begin on the bound

Re: pgbench logging broken by time logic changes

2021-06-30 Thread Fabien COELHO
Fabien, thanks for the updated patch, I'm looking at it. After looking at it again, here is an update which ensure 64 bits on epoch_shift computation. -- Fabien.diff --git a/src/bin/pgbench/pgbench.c b/src/bin/pgbench/pgbench.c index 4aeccd93af..7750b5d660 100644 --- a/src/bin/pgbench/pgben

Re: pgbench logging broken by time logic changes

2021-06-30 Thread Fabien COELHO
Hello Thomas, I've added an entry on the open item on the wiki. I'm unsure about who the owner should be. There is already an item: "Incorrect time maths in pgbench". Argh *shoot*, I went over the list too quickly, looking for "log" as a keyword. Fabien, thanks for the updated patch, I

Re: pgbench logging broken by time logic changes

2021-06-30 Thread Thomas Munro
On Wed, Jun 30, 2021 at 8:05 PM Michael Paquier wrote: > On Wed, Jun 30, 2021 at 09:45:47AM +0200, Fabien COELHO wrote: > > Attached the remaining part of the patch to fix known issues on pgbench > > logging. > > > > I've added an entry on the open item on the wiki. I'm unsure about who the > > ow

Re: pgbench logging broken by time logic changes

2021-06-30 Thread Michael Paquier
On Wed, Jun 30, 2021 at 09:45:47AM +0200, Fabien COELHO wrote: > Attached the remaining part of the patch to fix known issues on pgbench > logging. > > I've added an entry on the open item on the wiki. I'm unsure about who the > owner should be. There is already an item: "Incorrect time maths in

Re: pgbench logging broken by time logic changes

2021-06-30 Thread Fabien COELHO
Bonjour Michaël, Okay, I have extracted this part from your patch, and back-patched this fix down to 11. The comments were a good addition, so I have kept them. I have also made the second regex of check_pgbench_logs() pickier with the client ID value expected, as it can only be 0. Attached

Re: pgbench logging broken by time logic changes

2021-06-24 Thread Michael Paquier
On Thu, Jun 24, 2021 at 08:03:27AM -0400, Andrew Dunstan wrote: > On 6/24/21 2:46 AM, Fabien COELHO wrote: >>> Using grep() with "$re" results in all the fields matching.  Using on >>> the contrary "/$re/" in grep(), like list_files(), would only match >>> the first one, which is correct. >> >> Ok,

Re: pgbench logging broken by time logic changes

2021-06-24 Thread Andrew Dunstan
On 6/24/21 2:46 AM, Fabien COELHO wrote: > > Bonjour Michaël, > >> Using grep() with "$re" results in all the fields matching.  Using on >> the contrary "/$re/" in grep(), like list_files(), would only match >> the first one, which is correct. > > Ok, good catch. Perl is kind of a strange languag

Re: pgbench logging broken by time logic changes

2021-06-23 Thread Fabien COELHO
Bonjour Michaël, Using grep() with "$re" results in all the fields matching. Using on the contrary "/$re/" in grep(), like list_files(), would only match the first one, which is correct. Ok, good catch. Perl is kind of a strange language. With this issue fixed, I have bumped into what looks

Re: pgbench logging broken by time logic changes

2021-06-23 Thread Michael Paquier
On Wed, Jun 23, 2021 at 10:01:28PM +0200, Fabien COELHO wrote: > Thanks for the hint! Why not, having the ability to collect data is a good > thing, so attached v10 does that. If something go wrong, the TODO section > could be extended around all calls. +check_pgbench_logs($bdir, '001_pgbench_log_

Re: pgbench logging broken by time logic changes

2021-06-23 Thread Fabien COELHO
Ola Álvaro, ... or, actually, even better would be to use a TODO block, so that the test is run and reports its status, but if it happens not to succeed it will not cause the whole test to fail. That way you'll accumulate some evidence that may serve to improve the test in the future until it

Re: pgbench logging broken by time logic changes

2021-06-23 Thread Alvaro Herrera
On 2021-Jun-23, Fabien COELHO wrote: > +# cool check that we are around 2 seconds > +# The rate may results in an unlucky schedule which triggers > +# an early exit, hence the loose bound. > +# > +# THIS TEST IS COMMENTED OUT BUT PLEASE LET IT THERE SO THAT > +# IT CAN BE ENABLED EASILY. > +# > +#

Re: pgbench logging broken by time logic changes

2021-06-23 Thread Fabien COELHO
Bonjour Michaël, Could it be possible to document the intention of the test and its coverage then? With the current patch, one has to guess what's the intention behind this case. Ok, see attached. +check_pgbench_logs($bdir, '001_pgbench_log_1', $nthreads, 1, 3, + qr{^\d{10,} \d{1,2}

Re: pgbench logging broken by time logic changes

2021-06-23 Thread Michael Paquier
On Wed, Jun 23, 2021 at 08:26:32AM +0200, Fabien COELHO wrote: >> Could we make that shorter at 1s? That will shorten the duration of >> the test run. It is easy to miss that this test is for >> --aggregate-interval (aka the logAgg() path) without a comment. > > It is for -T, -P and --aggregate-

Re: pgbench logging broken by time logic changes

2021-06-22 Thread Fabien COELHO
Hello, +# note: this test is time sensitive, and may fail on a very +# loaded host. +# note: --progress-timestamp is not tested +my $delay = pgbench( + '-T 2 -P 1 -l --aggregate-interval=1 -S -b se@2' + . ' --rate=20 --latency-limit=1000 -j ' . $nthreads + . ' -c 3 -r',

Re: pgbench logging broken by time logic changes

2021-06-22 Thread Michael Paquier
On Tue, Jun 22, 2021 at 12:06:45PM +0200, Fabien COELHO wrote: > Attached an updated v8 patch which adds (reinstate) an improved TAP test > which would have caught the various regressions on logs. > Given that such tests were removed once before, I'm unsure whether they will > be acceptable, despi

Re: pgbench logging broken by time logic changes

2021-06-22 Thread Fabien COELHO
Bonjour Michaël, If this were core server code threatening data integrity I would be inclined to be more strict, but after all pg_bench is a utility program, and I think we can allow a little more latitude. +1. Let's be flexible here. It looks better to not rush a fix, and we still have som

Re: pgbench logging broken by time logic changes

2021-06-21 Thread Michael Paquier
On Sun, Jun 20, 2021 at 10:15:55AM -0400, Andrew Dunstan wrote: > If this were core server code threatening data integrity I would be > inclined to be more strict, but after all pg_bench is a utility program, > and I think we can allow a little more latitude. +1. Let's be flexible here. It looks

Re: pgbench logging broken by time logic changes

2021-06-20 Thread Andrew Dunstan
On 6/20/21 5:02 AM, Fabien COELHO wrote: > >> Upon reflection, that amounts to the same thing really, so yeah, >> scratch that plan.  I'll defer until after that (and then I'll be >> leaning more towards the revert option). > > Sigh. I do not understand anything about the decision processus. Ye

Re: pgbench logging broken by time logic changes

2021-06-20 Thread Fabien COELHO
Upon reflection, that amounts to the same thing really, so yeah, scratch that plan. I'll defer until after that (and then I'll be leaning more towards the revert option). Sigh. I do not understand anything about the decision processus. If you do revert, please consider NOT reverting the tps

Re: pgbench logging broken by time logic changes

2021-06-20 Thread Thomas Munro
On Sun, Jun 20, 2021 at 4:52 PM Thomas Munro wrote: > On Sun, Jun 20, 2021 at 3:18 PM Alvaro Herrera > wrote: > > On 2021-Jun-19, Thomas Munro wrote: > > > Thanks for looking so far. It's the weekend here and I need to > > > unplug, but I'll test these changes and if all looks good push on > >

Re: pgbench logging broken by time logic changes

2021-06-19 Thread Thomas Munro
On Sun, Jun 20, 2021 at 3:18 PM Alvaro Herrera wrote: > On 2021-Jun-19, Thomas Munro wrote: > > Thanks for looking so far. It's the weekend here and I need to > > unplug, but I'll test these changes and if all looks good push on > > Monday. > > Surely not the same day as the beta stamp... Becaus

Re: pgbench logging broken by time logic changes

2021-06-19 Thread Alvaro Herrera
On 2021-Jun-19, Thomas Munro wrote: > Thanks for looking so far. It's the weekend here and I need to > unplug, but I'll test these changes and if all looks good push on > Monday. Surely not the same day as the beta stamp... -- Álvaro Herrera Valdivia, Chile "Always assume the user will d

Re: pgbench logging broken by time logic changes

2021-06-18 Thread Michael Paquier
On Sat, Jun 19, 2021 at 11:59:16AM +1200, Thomas Munro wrote: > Thanks for looking so far. It's the weekend here and I need to > unplug, but I'll test these changes and if all looks good push on > Monday. Thanks for the update. Have a good weekend. -- Michael signature.asc Description: PGP sig

Re: pgbench logging broken by time logic changes

2021-06-18 Thread Thomas Munro
On Fri, Jun 18, 2021 at 12:31 PM Michael Paquier wrote: > On Fri, Jun 18, 2021 at 12:49:42AM +1200, Thomas Munro wrote: > > Yeah I've been catching up with these threads. > > Thomas, do you want me to look more at this issue? I don't feel > comfortable with the idea of doing anything if you are p

Re: pgbench logging broken by time logic changes

2021-06-17 Thread Noah Misch
On Wed, Jun 16, 2021 at 03:13:30PM -0400, Andrew Dunstan wrote: > On 6/16/21 2:59 PM, Fabien COELHO wrote: > > The key feedback for me is the usual one: what is not tested does not > > work. Wow:-) > > Agreed. > > > I'm unhappy because I already added tap tests for time-sensitive > > features (-T

Re: pgbench logging broken by time logic changes

2021-06-17 Thread Michael Paquier
On Fri, Jun 18, 2021 at 12:49:42AM +1200, Thomas Munro wrote: > I'm on the fence TBH, I can see that it's really small things and it > seems we have the patches, but it's late, late enough that > benchmarking gurus are showing up to benchmark with it for real, and > it's not great to be getting in

Re: pgbench logging broken by time logic changes

2021-06-17 Thread Fabien COELHO
Hello Thomas, I prepared a draft revert patch for discussion, just in case it comes in handy. This reverts "pgbench: Improve time logic.", but "pgbench: Synchronize client threads." remains (slightly rearranged). I had a quick look. I had forgotten that this patch also fixed the long-runni

Re: pgbench logging broken by time logic changes

2021-06-17 Thread Fabien COELHO
Hello Greg, I think the only thing you and I disagree on is that you see a "first issue in a corner case" where I see a process failure that is absolutely vital for me to improve. Hmmm. I agree that improvements are needed, but for me there is simply a few missing (removed) tap tests which

Re: pgbench logging broken by time logic changes

2021-06-17 Thread Fabien COELHO
Is there an identified issue beyond the concrete example Greg gave of the timestamps? AFAICS, there is a patch which fixes all known issues linked to pgbench logging. Whether there exists other issues is possible, but the "broken" area was quite specific. There are also some TAP tests on pgb

Re: pgbench logging broken by time logic changes

2021-06-17 Thread Gregory Smith
On Wed, Jun 16, 2021 at 2:59 PM Fabien COELHO wrote: > I'm unhappy because I already added tap tests for time-sensitive features > (-T and others, maybe logging aggregates, cannot remember), which have > been removed because they could fail under some circonstances (eg very > very very very slow

Re: pgbench logging broken by time logic changes

2021-06-17 Thread Andrew Dunstan
On 6/17/21 8:49 AM, Thomas Munro wrote: > On Thu, Jun 17, 2021 at 7:24 PM Fabien COELHO wrote: >>> Seems like it should be straightforward to fix, though, with fixes >>> already proposed (though I haven't studied them yet, will do). >> I think that fixing logging is simple enough, thus a revert

Re: pgbench logging broken by time logic changes

2021-06-17 Thread Thomas Munro
On Thu, Jun 17, 2021 at 7:24 PM Fabien COELHO wrote: > > Seems like it should be straightforward to fix, though, with fixes > > already proposed (though I haven't studied them yet, will do). > > I think that fixing logging is simple enough, thus a revert is not > necessary. I prepared a draft rev

Re: pgbench logging broken by time logic changes

2021-06-17 Thread Fabien COELHO
I found you forgot to fix printProgressReport(). Indeed. Also, according to the document, interval_start in Aggregated Logging seems to be printed in seconds instead of ms. Indeed. I'm unsure about what we should really want there, but for a beta bug fix I agree that it must simply compl

Re: pgbench logging broken by time logic changes

2021-06-17 Thread Yugo NAGATA
On Thu, 17 Jun 2021 10:18:03 +0200 (CEST) Fabien COELHO wrote: > > >> Wouldn't it be better to put all those fixes into the same bag? > > > > Attached. > > Even better if the patch is not empty. I found you forgot to fix printProgressReport(). Also, according to the document, interval_start i

Re: pgbench logging broken by time logic changes

2021-06-17 Thread Fabien COELHO
Wouldn't it be better to put all those fixes into the same bag? Attached. Even better if the patch is not empty. -- Fabien.diff --git a/src/bin/pgbench/pgbench.c b/src/bin/pgbench/pgbench.c index d7479925cb..3df92bdd2b 100644 --- a/src/bin/pgbench/pgbench.c +++ b/src/bin/pgbench/pgbench.c @

Re: pgbench logging broken by time logic changes

2021-06-17 Thread Fabien COELHO
Wouldn't it be better to put all those fixes into the same bag? Attached. -- Fabien.

Re: pgbench logging broken by time logic changes

2021-06-17 Thread Fabien COELHO
Hello Thomas, Before I could get to startup timing I noticed the pgbench logging output was broken via commit 547f04e7 "Improve time logic": https://www.postgresql.org/message-id/E1lJqpF-00064e-C6%40gemulon.postgresql.org It does suck that we broke the logging and that it took 3 months for a

Re: pgbench logging broken by time logic changes

2021-06-17 Thread Fabien COELHO
Hello, I cannot say that I'm thrilled by having multiple tv stuff back in several place. I can be okay with one, though. What about the attached? Does it make sense? +1 The patch rounds down sd->start_time from ms to s but it seems to me a degradation. Yes, please we should not use time.

Re: pgbench logging broken by time logic changes

2021-06-17 Thread Fabien COELHO
Hello Yugo-san, I think we can fix this issue by using gettimeofday for logging as before this was changed. I attached the patch. I cannot say that I'm thrilled by having multiple tv stuff back in several place. I can be okay with one, though. What about the attached? Does it make sense? At

Re: pgbench logging broken by time logic changes

2021-06-16 Thread Yugo NAGATA
On Thu, 17 Jun 2021 14:17:56 +0900 (JST) Kyotaro Horiguchi wrote: > At Thu, 17 Jun 2021 12:23:42 +0900, Yugo NAGATA wrote > in > > On Wed, 16 Jun 2021 21:11:41 +0200 (CEST) > > Fabien COELHO wrote: > > > I cannot say that I'm thrilled by having multiple tv stuff back in > > > several > > >

Re: pgbench logging broken by time logic changes

2021-06-16 Thread Kyotaro Horiguchi
At Thu, 17 Jun 2021 12:23:42 +0900, Yugo NAGATA wrote in > On Wed, 16 Jun 2021 21:11:41 +0200 (CEST) > Fabien COELHO wrote: > > I cannot say that I'm thrilled by having multiple tv stuff back in several > > place. I can be okay with one, though. What about the attached? Does it > > make sense?

Re: pgbench logging broken by time logic changes

2021-06-16 Thread Yugo NAGATA
On Wed, 16 Jun 2021 21:11:41 +0200 (CEST) Fabien COELHO wrote: > > > pg_time_now(). This uses INSTR_TIME_SET_CURRENT in it, but this macro > > can call clock_gettime(CLOCK_MONOTONIC[_RAW], ) instead of gettimeofday > > or clock_gettime(CLOCK_REALTIME, ). When CLOCK_MONOTONIC[_RAW] is used, > > c

Re: pgbench logging broken by time logic changes

2021-06-16 Thread Michael Paquier
On Thu, Jun 17, 2021 at 12:36:10PM +1200, Thomas Munro wrote: > For that reason, I'm not super attached to that new pg_time_usec_t > stuff at all, and wouldn't be sad if we reverted that piece. I am > moderately attached to the sync changes, though. pgbench 13 is > objectively producing incorrect

Re: pgbench logging broken by time logic changes

2021-06-16 Thread Thomas Munro
Hi Greg, On Thu, Jun 17, 2021 at 2:49 AM Gregory Smith wrote: > Back on March 10 Thomas Munro committed and wrestled multiple reworks of the > pgbench code from Fabien and the crew. The feature to synchronize startup > I'm looking forward to testing now that I have a packaged beta. Variations

Re: pgbench logging broken by time logic changes

2021-06-16 Thread Andrew Dunstan
On 6/16/21 2:59 PM, Fabien COELHO wrote: > > Hello Greg, > >> I have a lot of community oriented work backed up behind this right >> now, so >> I'm gonna be really honest.  This time rework commit in its current form >> makes me uncomfortable at this point in the release schedule.  The >> commit

Re: pgbench logging broken by time logic changes

2021-06-16 Thread Fabien COELHO
pg_time_now(). This uses INSTR_TIME_SET_CURRENT in it, but this macro can call clock_gettime(CLOCK_MONOTONIC[_RAW], ) instead of gettimeofday or clock_gettime(CLOCK_REALTIME, ). When CLOCK_MONOTONIC[_RAW] is used, clock_gettime doesn't return epoch time. Therefore, we can use INSTR_TIME_SET_CURR

Re: pgbench logging broken by time logic changes

2021-06-16 Thread Fabien COELHO
Hello Greg, I have a lot of community oriented work backed up behind this right now, so I'm gonna be really honest. This time rework commit in its current form makes me uncomfortable at this point in the release schedule. The commit has already fought through two rounds of platform specific

Re: pgbench logging broken by time logic changes

2021-06-16 Thread Yugo NAGATA
On Wed, 16 Jun 2021 10:49:36 -0400 Gregory Smith wrote: > A lot of things are timed in pgbench now so I appreciate the idea. Y'all > started that whole big thread about sync on my birthday though and I didn't > follow the details of what that was reviewed against. For the logging use > case I s

pgbench logging broken by time logic changes

2021-06-16 Thread Gregory Smith
Back on March 10 Thomas Munro committed and wrestled multiple reworks of the pgbench code from Fabien and the crew. The feature to synchronize startup I'm looking forward to testing now that I have a packaged beta. Variations on that problem have bit me so many times I added code last year to my p