Thread: BUG #7494: WAL replay speed depends heavily on the shared_buffers size

Hello Andreas,

it is more then a year now, that I have not returned to that topic.

As we still have a problem with very slow WAL replay in situations, when we
create and drop a lot of temporary tables, I have made a small synthetic
test.
I have build the simplest steaming replication using PostgreSQL 9.3rc1.

My goal was to see, if the recovery process will be able to keep up with
this WAL flow.

Running this sproc on the master:

CREATE OR REPLACE FUNCTION public.f()
 RETURNS integer
 LANGUAGE plpgsql
AS $function$
begin

  CREATE TEMP TABLE temp_table_to_test_replication AS
    SELECT s.i as id from generate_series(1, 100) as s(i);
  DROP TABLE temp_table_to_test_replication;
  RETURN 1;
end;
$function$

leads to writing of WAL files. Is it an expected behavior? Is it expected
that WAL files are filled  when the only thing, that sproc is supposed to
do is to create and drop a temporary table. Are these catalog changes?

(I was calling it with:

seq 1000 | xargs -l -n 1 -P 5 -I x psql -tA -c "select f();" > /dev/null

for that call pg_stat_replication.sent_location moved from 0/21891CB0 to
0/21DFEC74 or 5689284 bytes
)


WAL files are also written when executing a stored procedure, that was
writing into an UNLOGGED table:

CREATE OR REPLACE FUNCTION public.s()
 RETURNS integer
 LANGUAGE plpgsql
AS $function$
begin
  INSERT INTO unlogged_test_table SELECT pg_backend_pid() FROM
generate_series(1,100) as s(i);
  DELETE FROM unlogged_test_table WHERE id = pg_backend_pid();
  RETURN pg_backend_pid();
end;
$function$

(WAL position moved from 0/21E51894 to 0/21E5B58C for 40184 bytes)

Also as I recreated the same table as a LOGGED one, the WAL diff generated
becomes 11668768 that is what I would expect.

WAL files are not being generated when calling really read-only sprocs like
now() :)

Regards,

Valentine Gogichashvili

Oh, here is more context about this issue:
http://www.postgresql.org/message-id/201208171307.16342.andres@2ndquadrant.com

-- Valentin

On Wed, Aug 28, 2013 at 1:28 AM, Valentine Gogichashvili
<valgog@gmail.com>wrote:

> Hello Andreas,
>
> it is more then a year now, that I have not returned to that topic.
>
> As we still have a problem with very slow WAL replay in situations, when
> we create and drop a lot of temporary tables, I have made a small synthetic
> test.
> I have build the simplest steaming replication using PostgreSQL 9.3rc1.
>
> My goal was to see, if the recovery process will be able to keep up with
> this WAL flow.
>
> Running this sproc on the master:
>
> CREATE OR REPLACE FUNCTION public.f()
>  RETURNS integer
>  LANGUAGE plpgsql
> AS $function$
> begin
>
>   CREATE TEMP TABLE temp_table_to_test_replication AS
>     SELECT s.i as id from generate_series(1, 100) as s(i);
>   DROP TABLE temp_table_to_test_replication;
>   RETURN 1;
> end;
> $function$
>
> leads to writing of WAL files. Is it an expected behavior? Is it expected
> that WAL files are filled  when the only thing, that sproc is supposed to
> do is to create and drop a temporary table. Are these catalog changes?
>
> (I was calling it with:
>
> seq 1000 | xargs -l -n 1 -P 5 -I x psql -tA -c "select f();" > /dev/null
>
> for that call pg_stat_replication.sent_location moved from 0/21891CB0 to
> 0/21DFEC74 or 5689284 bytes
> )
>
>
> WAL files are also written when executing a stored procedure, that was
> writing into an UNLOGGED table:
>
> CREATE OR REPLACE FUNCTION public.s()
>  RETURNS integer
>  LANGUAGE plpgsql
> AS $function$
> begin
>   INSERT INTO unlogged_test_table SELECT pg_backend_pid() FROM
> generate_series(1,100) as s(i);
>   DELETE FROM unlogged_test_table WHERE id = pg_backend_pid();
>   RETURN pg_backend_pid();
> end;
> $function$
>
> (WAL position moved from 0/21E51894 to 0/21E5B58C for 40184 bytes)
>
> Also as I recreated the same table as a LOGGED one, the WAL diff generated
> becomes 11668768 that is what I would expect.
>
> WAL files are not being generated when calling really read-only sprocs
> like now() :)
>
> Regards,
>
> Valentine Gogichashvili
>

On 28.08.2013 02:28, Valentine Gogichashvili wrote:
> Running this sproc on the master:
>
> CREATE OR REPLACE FUNCTION public.f()
>   RETURNS integer
>   LANGUAGE plpgsql
> AS $function$
> begin
>
>    CREATE TEMP TABLE temp_table_to_test_replication AS
>      SELECT s.i as id from generate_series(1, 100) as s(i);
>    DROP TABLE temp_table_to_test_replication;
>    RETURN 1;
> end;
> $function$
>
> leads to writing of WAL files. Is it an expected behavior? Is it expected
> that WAL files are filled  when the only thing, that sproc is supposed to
> do is to create and drop a temporary table. Are these catalog changes?

Yep, creating/dropping temp tables are catalog changes, which are
WAL-logged.

- Heikki

On 2013-08-28 11:50:17 +0200, Valentine Gogichashvili wrote:
> Oh, here is more context about this issue:
> http://www.postgresql.org/message-id/201208171307.16342.andres@2ndquadrant.com

I think that backtrace and explanation pretty much explained what's
going on. Did you try 9.3 to see whether things got better there?

Alternatively, it might be very worthwile to try to get way from
per-transaction or even per-function temporary tables. As you've
discovered, they have quite the cost...

Greetings,

Andres Freund

--
 Andres Freund                       http://www.2ndQuadrant.com/
 PostgreSQL Development, 24x7 Support, Training & Services