Thread: Re: [BUGS] BUG #5412: test case produced, possible race condition.

I wrote:
> [ theory about cause of Rusty's crash ]

I started to doubt this theory after wondering why the problem hadn't
been exposed by CLOBBER_CACHE_ALWAYS testing, which is done routinely
by the buildfarm.  That setting would surely cause the cache flush to
happen at the troublesome time.  After a good deal more investigation,
I found out why it doesn't crash with that.  The problematic case is
for a relation that has rd_newRelfilenodeSubid nonzero but
rd_createSubid zero (ie, it's been truncated in the current xact).
Given that, RelationFlushRelation will attempt a rebuild but
RelationCacheInvalidate won't exempt the relation from destruction.
However, if you do a TRUNCATE under CLOBBER_CACHE_ALWAYS, the relcache
entry gets blown away immediately at the conclusion of that command,
because we'll do a RelationCacheInvalidate as a consequence of
CLOBBER_CACHE_ALWAYS.  When the relcache entry is rebuilt for later use,
it won't have rd_newRelfilenodeSubid set, so it's not a hazard anymore.
In order to expose this bug, the relcache entry has to survive past the
TRUNCATE and then a cache flush has to occur while we are in process of
rebuilding it, not before.

What this suggests is that CLOBBER_CACHE_ALWAYS is actually too strong
to provide a thorough test of cache flush hazards.  Maybe we need an
alternate setting along the lines of CLOBBER_CACHE_SOMETIMES that would
randomly choose whether or not to flush at any given opportunity.  But
if such a setup did produce a crash, it'd be awfully hard to reproduce
for investigation.  Ideas?

There is another slightly odd thing here, which is that the stack trace
Rusty provided clearly shows the crash occurring during processing of a
local relcache invalidation message for the truncated relation.  This
would be expected during execution of the TRUNCATE itself, but at that
point the rel has positive refcnt so there's no problem.  According to
the stack trace the active SQL command is an INSERT ... SELECT, and I
wouldn't expect that to queue any relcache invals.  Are there any
triggers or other unusual things in the real application (not the
watered-down test case) that would be triggered in INSERT/SELECT?
        regards, tom lane

Tom Lane <tgl@sss.pgh.pa.us> wrote:
> What this suggests is that CLOBBER_CACHE_ALWAYS is actually too
> strong to provide a thorough test of cache flush hazards.  Maybe
> we need an alternate setting along the lines of
> CLOBBER_CACHE_SOMETIMES that would randomly choose whether or not
> to flush at any given opportunity. But if such a setup did produce
> a crash, it'd be awfully hard to reproduce for investigation. 
> Ideas?
Seed the random number generator such that each run of the test gets
the same "random" numbers?  Or *allow* the seed to be set, with the
default being a random seed which is logged so that it can be forced
for a repeat of the run?
-Kevin

Rusty Conover <rconover@infogears.com> writes:
> On Apr 14, 2010, at 2:31 PM, Tom Lane wrote:
>> There is another slightly odd thing here, which is that the stack trace
>> Rusty provided clearly shows the crash occurring during processing of a
>> local relcache invalidation message for the truncated relation.

> The test case program was the smallest thing I could write to reproduce the problem consistently on my machine, but I
couldn'treproduce it consistently on other machines and architectures.  I'm glad Heikki was able to also see the crash
onhis hardware.  I can take Heikki's patch back out and get a new stack trace from the test program if that would be
usefulto you.
 

Yeah, I'm curious to know if the stack trace is the same for crashes in
the watered-down test case.  AFAICS, relcache invals triggered by the
TRUNCATE itself ought to be serviced before we get out of the TRUNCATE;
and after that, the xact is holding exclusive lock on the table so
there's no way that we should get a remote inval on the specific relation
(not to mention that the trace is clearly about a local inval not an
incoming remote inval).  So I don't understand why the trace says that
it's happening during a subsequent INSERT.

Mind you, Heikki's patch looks like a good idea in any case; but I'm
not sure that there isn't something else going on here.
        regards, tom lane

Rusty Conover <rconover@infogears.com> writes:
> [ same stack trace for the simplified test case ]

Ah, got it finally.  There *is* a relcache flush happening during INSERT
in the 8.4 code, because of FSM extension:

(gdb) bt
#0  RegisterRelcacheInvalidation (dbId=40264, relId=848094) at inval.c:439
#1  0x000000000067a30d in CacheInvalidateRelcache (relation=0x7f39b88403f0)   at inval.c:1141
#2  0x00000000005c9c45 in fsm_extend (fsm_nblocks=<value optimized out>,    rel=<value optimized out>) at
freespace.c:589
#3  fsm_readbuf (fsm_nblocks=<value optimized out>, rel=<value optimized out>)   at freespace.c:522
#4  0x00000000005ca2e4 in fsm_set_and_search (rel=0x9d48,    addr=<value optimized out>, slot=0, newValue=220 '\334',
minValue=200 '\310') at freespace.c:608
 
#5  0x00000000005ca675 in RecordAndGetPageWithFreeSpace (rel=0x7f39b88403f0,    oldPage=<value optimized out>,
oldSpaceAvail=<valueoptimized out>,    spaceNeeded=<value optimized out>) at freespace.c:163
 
#6  0x0000000000464149 in RelationGetBufferForTuple (relation=0x7f39b88403f0,    len=<value optimized out>,
otherBuffer=0,options=<value optimized out>,    bistate=<value optimized out>) at hio.c:303
 
#7  0x0000000000462e77 in heap_insert (relation=0x7f39b88403f0, tup=0x14aa580,    cid=<value optimized out>, options=0,
bistate=0x0)at heapam.c:1890
 

This code path doesn't exist in CVS HEAD, which means (I think) that the
given test case can't fail in HEAD.  I think I got myself confused by
experimenting variously with HEAD and 8.4 in regular and
CLOBBER_CACHE_ALWAYS modes --- only one of those four combinations will
exhibit a failure with this test case.

Although the particular case apparently can't arise in HEAD, I'm going
to apply Heikki's patch there anyway, since there's clearly a risk of
related problems.
        regards, tom lane

"Kevin Grittner" <Kevin.Grittner@wicourts.gov> writes:
> Tom Lane <tgl@sss.pgh.pa.us> wrote:
>> What this suggests is that CLOBBER_CACHE_ALWAYS is actually too
>> strong to provide a thorough test of cache flush hazards.  Maybe
>> we need an alternate setting along the lines of
>> CLOBBER_CACHE_SOMETIMES that would randomly choose whether or not
>> to flush at any given opportunity. But if such a setup did produce
>> a crash, it'd be awfully hard to reproduce for investigation. 
>> Ideas?
> Seed the random number generator such that each run of the test gets
> the same "random" numbers?  Or *allow* the seed to be set, with the
> default being a random seed which is logged so that it can be forced
> for a repeat of the run?

The seed alone wouldn't be enough to duplicate the behavior, since
the behavior of random() typically varies across platforms.  So we
might get a report and still be unable to reproduce it.
        regards, tom lane

Tom Lane <tgl@sss.pgh.pa.us> wrote:
> The seed alone wouldn't be enough to duplicate the behavior, since
> the behavior of random() typically varies across platforms.  So we
> might get a report and still be unable to reproduce it.
At least the person getting the initial failure would be able to
recreate it, and possibly provide a stack trace.
-Kevin

"Kevin Grittner" <Kevin.Grittner@wicourts.gov> writes:
> Tom Lane <tgl@sss.pgh.pa.us> wrote:
>> The seed alone wouldn't be enough to duplicate the behavior, since
>> the behavior of random() typically varies across platforms.  So we
>> might get a report and still be unable to reproduce it.
> At least the person getting the initial failure would be able to
> recreate it, and possibly provide a stack trace.

On second thought, since there's no need for a particularly high-quality
RNG here, we could just embed some brain-dead one-liner implementation,
which should behave the same everywhere.
        regards, tom lane

Tom Lane <tgl@sss.pgh.pa.us> wrote:
> On second thought, since there's no need for a particularly
> high-quality RNG here, we could just embed some brain-dead
> one-liner implementation, which should behave the same everywhere.
Sounds good to me.
-Kevin