Re: [BUGS] Breakage with VACUUM ANALYSE + partitions - Mailing list pgsql-hackers

On 26 April 2016 at 22:32, Andres Freund <andres@anarazel.de> wrote:
> On 2016-04-26 17:25:18 -0400, Robert Haas wrote:
>> On Mon, Apr 25, 2016 at 4:57 PM, Andres Freund <andres@anarazel.de> wrote:
>> > On 2016-04-25 16:29:36 -0400, Robert Haas wrote:
>> >> On Mon, Apr 25, 2016 at 2:05 PM, Andres Freund <andres@anarazel.de> wrote:
>> >> > Well, I posted a patch. I'd have applied it too (after addressing your
>> >> > comments obviously), except that there's some interdependencies with the
>> >> > nsmg > 0 thread (some of my tests fail spuriously without that
>> >> > fixed). Early last week I waited for a patch on that thread, but when
>> >> > that didn't materialize by Friday I switched to work on that [1].  With
>> >> > both fixes applied I can't reproduce any problems anymore.
>> >>
>> >> OK.  What are the interdependencies?  You've said that a few times but
>> >> I am not clear on what the nature of those interdependencies is.
>> >
>> > I added checks to smgr/md.c that verify that the smgr state is
>> > consistent with the on-file state. Without the two issues in [1] fixed,
>> > these tests fail in a standby, while running regression tests.  Adding
>> > those tests made me notice a bug in an unreleased version of the patch,
>> > so it seems they're worthwhile to run.
>>
>> Footnote [1] is used, but not defined.
>
> Oops, it's the thread you replied too..
>
>> I think it makes sense to go ahead and push this fix rather soon.
>
> Will do.

I've noticed another breakage, which I can reproduce consistently.

createdb pgbench
pgbench -i -s 100 --unlogged-tables pgbench
psql -f pgbench_partitions.sql pgbench
vacuumdb -z pgbench
createdb test

Which produces:

createdb: database creation failed: ERROR:  checkpoint request failed
HINT:  Consult recent messages in the server log for details.

2016-04-28 17:36:00 BST [18605]: [1-1] user=thom,db=postgres,client=[local] DEBUG:  postgres child[18605]: starting with (
2016-04-28 17:36:00 BST [18605]: [2-1] user=thom,db=postgres,client=[local] DEBUG:      postgres
2016-04-28 17:36:00 BST [18605]: [3-1] user=thom,db=postgres,client=[local] DEBUG:  )
2016-04-28 17:36:00 BST [18605]: [4-1] user=thom,db=postgres,client=[local] DEBUG:  InitPostgres
2016-04-28 17:36:00 BST [18605]: [5-1] user=thom,db=postgres,client=[local] DEBUG:  StartTransaction
2016-04-28 17:36:00 BST [18605]: [6-1] user=thom,db=postgres,client=[local] DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nest
lvl: 1, children:
2016-04-28 17:36:00 BST [18605]: [7-1] user=thom,db=postgres,client=[local] DEBUG:  CommitTransaction
2016-04-28 17:36:00 BST [18605]: [8-1] user=thom,db=postgres,client=[local] DEBUG:  name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nest
lvl: 1, children:
2016-04-28 17:36:00 BST [18605]: [9-1] user=thom,db=postgres,client=[local] DEBUG:  StartTransactionCommand
2016-04-28 17:36:00 BST [18605]: [10-1] user=thom,db=postgres,client=[local] STATEMENT:  CREATE DATABASE test;
2016-04-28 17:36:00 BST [18605]: [11-1] user=thom,db=postgres,client=[local] DEBUG:  StartTransaction
2016-04-28 17:36:00 BST [18605]: [12-1] user=thom,db=postgres,client=[local] STATEMENT:  CREATE DATABASE test;
2016-04-28 17:36:00 BST [18605]: [13-1] user=thom,db=postgres,client=[local] DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nes
tlvl: 1, children:
2016-04-28 17:36:00 BST [18605]: [14-1] user=thom,db=postgres,client=[local] STATEMENT:  CREATE DATABASE test;
2016-04-28 17:36:00 BST [18605]: [15-1] user=thom,db=postgres,client=[local] DEBUG:  ProcessUtility
2016-04-28 17:36:00 BST [18605]: [16-1] user=thom,db=postgres,client=[local] STATEMENT:  CREATE DATABASE test;
2016-04-28 17:36:00 BST [18108]: [46-1] user=,db=,client= DEBUG:  performing replication slot checkpoint
2016-04-28 17:36:00 BST [18105]: [158-1] user=,db=,client= DEBUG:  server process (PID 18582) exited with exit code 0
2016-04-28 17:36:08 BST [18108]: [47-1] user=,db=,client= DEBUG:  could not fsync file "base/24581/24594.1" but retrying: No such file or directory
2016-04-28 17:36:08 BST [18108]: [48-1] user=,db=,client= ERROR:  could not fsync file "base/24581/24594.1": No such file or directory
2016-04-28 17:36:08 BST [18605]: [17-1] user=thom,db=postgres,client=[local] ERROR:  checkpoint request failed
2016-04-28 17:36:08 BST [18605]: [18-1] user=thom,db=postgres,client=[local] HINT:  Consult recent messages in the server log for details.
2016-04-28 17:36:08 BST [18605]: [19-1] user=thom,db=postgres,client=[local] STATEMENT:  CREATE DATABASE test;
2016-04-28 17:36:08 BST [18605]: [20-1] user=thom,db=postgres,client=[local] DEBUG:  shmem_exit(0): 1 before_shmem_exit callbacks to make
2016-04-28 17:36:08 BST [18605]: [21-1] user=thom,db=postgres,client=[local] DEBUG:  shmem_exit(0): 6 on_shmem_exit callbacks to make
2016-04-28 17:36:08 BST [18605]: [22-1] user=thom,db=postgres,client=[local] DEBUG:  proc_exit(0): 3 callbacks to make
2016-04-28 17:36:08 BST [18605]: [23-1] user=thom,db=postgres,client=[local] DEBUG:  exit(0)
2016-04-28 17:36:08 BST [18605]: [24-1] user=thom,db=postgres,client=[local] DEBUG:  shmem_exit(-1): 0 before_shmem_exit callbacks to make
2016-04-28 17:36:08 BST [18605]: [25-1] user=thom,db=postgres,client=[local] DEBUG:  shmem_exit(-1): 0 on_shmem_exit callbacks to make
2016-04-28 17:36:08 BST [18605]: [26-1] user=thom,db=postgres,client=[local] DEBUG:  proc_exit(-1): 0 callbacks to make
2016-04-28 17:36:08 BST [18105]: [159-1] user=,db=,client= DEBUG:  server process (PID 18605) exited with exit code 0
2016-04-28 17:36:09 BST [18108]: [49-1] user=,db=,client= DEBUG:  checkpointer updated shared memory configuration values

Relfilenode 24594 corresponds to the empty pgbench_accounts parent table.

Thom