Date: Sat, 10 Jul 2021 10:25:22 +0200 (CEST)
From: Fabien COELHO <coelho@cri.ensmp.fr>
To: Thomas Munro <thomas.munro@gmail.com>
cc: Michael Paquier <michael@paquier.xyz>,
    Andrew Dunstan <andrew@dunslane.net>,
    Alvaro Herrera <alvherre@alvh.no-ip.org>,
    Gregory Smith <gregsmithpgsql@gmail.com>,
    PostgreSQL-development <pgsql-hackers@postgresql.org>,
    david.christensen@crunchydata.com
Subject: Re: pgbench logging broken by time logic changes
In-Reply-To: 
 <CA+hUKGJzS+jfSYPdX9gT1ayhyo-qxnHAykuO_FY_Eqyoacg41A@mail.gmail.com>
Message-ID: <alpine.DEB.2.22.394.2107101021220.775110@pseudo>
References: <202106231308.lxr26cahwxuc@alvherre.pgsql>
 <alpine.DEB.2.22.394.2106232158120.1601973@pseudo>
 <YNPsPAUoVDCpPOGk@paquier.xyz>
 <alpine.DEB.2.22.394.2106240815480.1687456@pseudo>
 <c031d7e6-a903-bac0-be96-26adc8903e2c@dunslane.net>
 <YNUGcznZps/dhZK4@paquier.xyz>
 <alpine.DEB.2.22.394.2106300934360.1788422@pseudo>
 <YNwlu5S6UlsB2DQz@paquier.xyz>
 <CA+hUKG+RMaozHhU7mBMyk6cFE69M9rPE9aOuvNpbjWbvNqUL9Q@mail.gmail.com>
 <alpine.DEB.2.22.394.2106301131200.1875747@pseudo>
 <alpine.DEB.2.22.394.2106301153030.1875747@pseudo>
 <CA+hUKGJcxWd7yM=QzBSd4xd6DqxEzGhWZRNPepuLuoP0rCj3-Q@mail.gmail.com>
 <alpine.DEB.2.22.394.2107010926141.2024567@pseudo>
 <CA+hUKG+2NAmDZ9g4GMjy939AsVifj117O40M1h7zUj02bzwjcA@mail.gmail.com>
 <alpine.DEB.2.22.394.2107081510410.170227@pseudo>
 <CA+hUKGKCQ4DUo1diCg6SPhnpaYWF37uEPbHhy=FKv4Cnuqn8_g@mail.gmail.com>
 <alpine.DEB.2.22.394.2107090645160.233209@pseudo>
 <CA+hUKGJzS+jfSYPdX9gT1ayhyo-qxnHAykuO_FY_Eqyoacg41A@mail.gmail.com>
User-Agent: Alpine 2.22 (DEB 394 2020-01-19)
MIME-Version: 1.0
Content-Type: text/plain; charset=US-ASCII; format=flowed
Archived-At: 
 <https://www.postgresql.org/message-id/alpine.DEB.2.22.394.2107101021220.775110%40pseudo>
Precedence: bulk


>> 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 and expect 1-180 lines.  (180s is the current timeout
> tolerance used elsewhere to deal with
> swamped/valgrind/swapping/microsd computers, after a few rounds of
> inflation, so if you need an arbitrary large number to avoid buildfarm
> measles that's my suggestion....)
> 2.  Change doLog() to give up after end_time.  But then I think you'd
> need to make it 0-3 :-(
>
> I think the logging could be tightened up to work the way you expected
> in future work, though.  Perhaps we could change all logging to work
> with transaction start time instead of log-writing time, which doLog()
> should receive.  If you never start a transaction after end_time, then
> there can never be an aggregate that begins after that, and the whole
> thing becomes more deterministic.  That kind of alignment of aggregate
> timing with whole-run timing could also get rid of those partial
> aggregates completely.  But that's an idea for 15.
>
> So I think we should do 1 for now.  Objections or better ideas?

At least, we now that it is too much.

What about moving the test as is in the TODO section with a comment, next 
to the other one, for now?

I hesitated to suggest that before for the above risks, but I was very 
naively optimistic that it may pass because the test is not that too 
demanding.

Someone suggested to have a "real-time" configure switch to enable/disable 
time-sensitive tests.

-- 
Fabien.