Re: BUG #10533: 9.4 beta1 assertion failure in autovacuum process

Just tried this again against the lastest HEAD
(fe7337f2dc3177da19b647fcda3a33b73da82e14) and still running into same
thing. Failed at different pgtap test point, but core dump seems the same.


TRAP: FailedAssertion("!(CritSectionCount == 0 || (CurrentMemoryContext) ==
ErrorContext || (MyAuxProcType == CheckpointerProcess))", File: "mcxt.c",
Line: 670)
LOG:  server process (PID 20484) was terminated by signal 6: Aborted
DETAIL:  Failed process was running: autovacuum: VACUUM ANALYZE
mimeo_source.updater_test_source
LOG:  terminating any other active server processes


#0  0x00007fa886b2e037 in raise () from /lib/x86_64-linux-gnu/libc.so.6
#1  0x00007fa886b31698 in abort () from /lib/x86_64-linux-gnu/libc.so.6
#2  0x000000000079ca87 in ExceptionalCondition (
    conditionName=conditionName@entry=0x952890 "!(CritSectionCount == 0 ||
(CurrentMemoryContext) == ErrorContext || (MyAuxProcType ==
CheckpointerProcess))",
    errorType=errorType@entry=0x7d7470 "FailedAssertion",
fileName=fileName@entry=0x95252e "mcxt.c", lineNumber=lineNumber@entry=670)
at assert.c:54
#3  0x00000000007bf510 in palloc (size=128) at mcxt.c:670
#4  0x00000000007d68e3 in psprintf (fmt=0x972a49 "base/%u/%u") at
psprintf.c:60
#5  0x00000000006b2417 in mdopen (behavior=EXTENSION_FAIL,
forknum=MAIN_FORKNUM, reln=0x16502d0) at md.c:562
#6  mdopen (reln=0x16502d0, forknum=MAIN_FORKNUM, behavior=EXTENSION_FAIL)
at md.c:552
#7  0x00000000006b3547 in _mdfd_getseg (reln=reln@entry=0x16502d0,
forknum=forknum@entry=MAIN_FORKNUM, blkno=blkno@entry=4, skipFsync=0
'\000',
    behavior=behavior@entry=EXTENSION_FAIL) at md.c:1707
#8  0x00000000006b3eb8 in mdwrite (reln=0x16502d0, forknum=MAIN_FORKNUM,
blocknum=4, buffer=0x7fa87e62f5c0 "\001", skipFsync=<optimized out>) at
md.c:742
#9  0x000000000068b50d in FlushBuffer (reln=0x16502d0, buf=0x7fa87d88ad80)
at bufmgr.c:2002
#10 FlushBuffer (buf=0x7fa87d88ad80, reln=<optimized out>) at bufmgr.c:1917
#11 0x000000000068be81 in BufferAlloc (foundPtr=0x7fffd5a8081e "",
strategy=0x0, blockNum=0, forkNum=VISIBILITYMAP_FORKNUM, relpersistence=112
'p', smgr=0x164e7d8)
    at bufmgr.c:687
#12 ReadBuffer_common (smgr=0x164e7d8, relpersistence=<optimized out>,
forkNum=forkNum@entry=VISIBILITYMAP_FORKNUM, blockNum=blockNum@entry=0,
mode=RBM_ZERO_ON_ERROR,
    strategy=0x0, hit=hit@entry=0x7fffd5a808cf "") at bufmgr.c:335
#13 0x000000000068c50b in ReadBufferExtended (reln=reln@entry=0x7fa88778ff30,
forkNum=forkNum@entry=VISIBILITYMAP_FORKNUM, blockNum=blockNum@entry=0,
    mode=mode@entry=RBM_ZERO_ON_ERROR, strategy=strategy@entry=0x0) at
bufmgr.c:254
#14 0x00000000004a5c55 in vm_readbuf (rel=rel@entry=0x7fa88778ff30,
blkno=blkno@entry=0, extend=extend@entry=0 '\000') at visibilitymap.c:563
#15 0x00000000004a67f4 in visibilitymap_test (rel=rel@entry=0x7fa88778ff30,
heapBlk=heapBlk@entry=0, buf=buf@entry=0x7fffd5a81a4c) at
visibilitymap.c:354
#16 0x00000000005b2a12 in lazy_vacuum_page (onerel=onerel@entry=0x7fa88778ff30,
blkno=blkno@entry=0, buffer=buffer@entry=5091, tupindex=<optimized out>,
tupindex@entry=0,
    vacrelstats=vacrelstats@entry=0x1637a68,
vmbuffer=vmbuffer@entry=0x7fffd5a81a4c)
at vacuumlazy.c:1245
#17 0x00000000005b2ccf in lazy_vacuum_heap (onerel=onerel@entry=0x7fa88778ff30,
vacrelstats=vacrelstats@entry=0x1637a68) at vacuumlazy.c:1152
#18 0x00000000005b346e in lazy_scan_heap (scan_all=0 '\000', nindexes=3,
Irel=<optimized out>, vacrelstats=0x1637a68, onerel=0x7fa88778ff30) at
vacuumlazy.c:1080
#19 lazy_vacuum_rel (onerel=onerel@entry=0x7fa88778ff30,
vacstmt=vacstmt@entry=0x7fffd5a82160, bstrategy=<optimized out>) at
vacuumlazy.c:239
#20 0x00000000005b0fca in vacuum_rel (relid=relid@entry=25939,
vacstmt=vacstmt@entry=0x7fffd5a82160, do_toast=do_toast@entry=0 '\000',
    for_wraparound=for_wraparound@entry=0 '\000') at vacuum.c:1202
#21 0x00000000005b1de6 in vacuum (vacstmt=vacstmt@entry=0x7fffd5a82160,
relid=<optimized out>, do_toast=do_toast@entry=0 '\000',
bstrategy=<optimized out>,
    bstrategy@entry=0x1693458, for_wraparound=0 '\000',
isTopLevel=isTopLevel@entry=1 '\001') at vacuum.c:234
---Type <return> to continue, or q <return> to quit---
#22 0x000000000064ee53 in autovacuum_do_vac_analyze (bstrategy=0x1693458,
tab=0x1693570) at autovacuum.c:2796
#23 do_autovacuum () at autovacuum.c:2326
#24 0x000000000064f395 in AutoVacWorkerMain (argv=0x0, argc=0) at
autovacuum.c:1678
#25 0x000000000064fa42 in StartAutoVacWorker () at autovacuum.c:1463
#26 0x000000000065d0cd in StartAutovacuumWorker () at postmaster.c:5188
#27 sigusr1_handler (postgres_signal_arg=<optimized out>) at
postmaster.c:4842
#28 <signal handler called>
#29 0x00007fa886be9e03 in select () from /lib/x86_64-linux-gnu/libc.so.6
#30 0x000000000045e702 in ServerLoop () at postmaster.c:1530
#31 0x000000000065dfbe in PostmasterMain (argc=argc@entry=3,
argv=argv@entry=0x15d2930)
at postmaster.c:1223
#32 0x000000000045f9b2 in main (argc=3, argv=0x15d2930) at main.c:227


--
Keith Fiske
Database Administrator
OmniTI Computer Consulting, Inc.
http://www.keithf4.com


On Fri, Jun 6, 2014 at 4:58 PM, Andres Freund <andres@2ndquadrant.com>
wrote:

> On 2014-06-06 16:55:58 -0400, Alvaro Herrera wrote:
> > Keith Fiske wrote:
> > > Not sure if this is the same issue originally reported, but the
> description
> > > sounded the same. I can get this to happen pretty reliably in 9.4beta1
> with
> > > the pgtap test suite for one of my extensions -
> >
> > Uh, this is a completely different problem.  We discussed long ago that
> > those pallocs in relpath() were going to cause a problem:
>
> I actually don't think it's a different problem. If we'd restructure
> things so the critical sections are separate this wouldn't be a
> problem. It's imo not a particularly good idea to mdopen() inside a
> critical section either.
>
> Greetings,
>
> Andres Freund
>
> --
>  Andres Freund                     http://www.2ndQuadrant.com/
>  PostgreSQL Development, 24x7 Support, Training & Services
>