Re: Status of autovacuum and the sporadic stats failures ?

Andrew Dunstan <andrew(at)dunslane(dot)net> writes:
> Tom Lane wrote:
>> It'd be interesting to try to gather stats on the length of the delay
>> taken, but I don't see a good way to do that within the current
>> regression-test infrastructure.

> Have it log something that will appear on the postmaster log but not the
> client log? Buildfarm members mostly post their complete postmaster
> logs, and we could postprocess those.

I've applied a patch along this line --- it'll emit LOG messages like

LOG: wait_for_stats delayed 0.112799018621445 seconds

The patch itself is pretty ugly :-(. I thought at first that we could
just have a plpgsql function loop until it saw a change in the stats,
but that does not work because the backend keeps its stats snapshot
until end of transaction --- so if the stats aren't updated when the
function first looks, they never will appear to. My second try was to
watch the mod timestamp of pgstat.stat, but that didn't work real well
either because it has only one-second resolution. As committed, the
patch is watching for a change in the size of pgstat.stat, which it
forces by making a new table. Ugh. I think it's worth doing as a means
of gathering information about what's happening in the buildfarm, but
I don't really want to leave it there for posterity.

We could make it cleaner by inventing a function to clear out the cached
statistics within a transaction, perhaps "pg_stat_reset_snaphot()" or
some such name. If anyone thinks that that would be of general
usefulness, I'll see about making it happen.

regards, tom lane

-- save current stats-file size
CREATE TEMP TABLE prevfilesize AS
SELECT size FROM pg_stat_file('global/pgstat.stat');

-- make and touch a previously nonexistent table
CREATE TABLE stats_hack (f1 int);
SELECT * FROM stats_hack;

-- wait for stats collector to update
create function wait_for_stats() returns void as $$
declare
start_time timestamptz := clock_timestamp();
oldsize bigint;
newsize bigint;
begin
-- fetch previous stats-file size
select size into oldsize from prevfilesize;

-- we don't want to wait forever; loop will exit after 30 seconds
for i in 1 .. 300 loop

-- look for update of stats file
select size into newsize from pg_stat_file('global/pgstat.stat');

exit when newsize != oldsize;

-- wait a little
perform pg_sleep(0.1);

end loop;

-- report time waited in postmaster log (where it won't change test output)
raise log 'wait_for_stats delayed % seconds',
extract(epoch from clock_timestamp() - start_time);
end
$$ language plpgsql;

SELECT wait_for_stats();

DROP TABLE stats_hack;