Re: [HACKERS] Bogus "Non-functional update" notices

I wrote:
>> With fairly current sources (last cvs update on 7/20), I am seeing
>> occasional occurrences of
>> NOTICE: Non-functional update, only first update is performed

I have been digging into this some more, and I am getting more and more
convinced that there is a significant underlying bug.

What I've discovered is that in the cases where this message appears
(which, again, is only once every few hundred tries) the update scan
is *finding the same tuple twice*. The second time through, the tuple
has already been marked as deleted by the current command, and it is
this marking that causes heap_replace to emit the "Non-functional
update" warning and return without processing the tuple.

An example trace is

QUERY: BEGIN TRANSACTION; LOCK marketorderhistory
RESULT: DELETE 0
QUERY: UPDATE marketorderhistory SET completionTime = '1998-05-11 20:00:00 GMT' WHERE oid = 34900::oid AND completionTime IS NULL
NOTICE: heap_replace OID 34900 t_xmin 20270 t_xmax 0 t_cmin 6 t_cmax 0
NOTICE: heap_replace OID 34900 t_xmin 20270 t_xmax 20496 t_cmin 6 t_cmax 3
NOTICE: Non-functional update, only first update is performed
NOTICE: current trans ID 20496 cmd id 3 scan id 3
RESULT: UPDATE 1

(The "NOTICE: heap_replace" lines are from debug code I added to print
ID info about the tuple found by heap_replace. This is printed every
time through the routine, just before the non-functional-update test.
The "NOTICE: current trans" line is printed only if the test triggers.)

In this particular situation, the only bad consequence is the display
of a bogus notice message, but it seems to me that having a scan find
the same tuple multiple times is a Very Bad Thing. (If the test in
heap_replace really is intended to clean up after this condition,
then it ought not be emitting a message.)

I have only seen this happen when the UPDATE was using an index scan to
find the tuples to update (the table in this example has a btree index
on oid). So, somehow the index is returning the same tuple more than
once.

I have managed to construct a simple, if not quick, test case that
repeatably causes an instance of the bogus message --- it's attached in
the form of a pgTcl script. The trace (from my backend with extra
printout) looks like

...
NOTICE: heap_replace OID 87736 t_xmin 113200 t_xmax 0 t_cmin 0 t_cmax 0
NOTICE: heap_replace OID 87735 t_xmin 113199 t_xmax 0 t_cmin 0 t_cmax 0
NOTICE: heap_replace OID 87734 t_xmin 113198 t_xmax 0 t_cmin 0 t_cmax 0
NOTICE: heap_replace OID 87734 t_xmin 113198 t_xmax 113601 t_cmin 0 t_cmax 0
NOTICE: Non-functional update, only first update is performed
NOTICE: current trans ID 113601 cmd id 0 scan id 0
NOTICE: heap_replace OID 87733 t_xmin 113197 t_xmax 0 t_cmin 0 t_cmax 0
NOTICE: heap_replace OID 87732 t_xmin 113196 t_xmax 0 t_cmin 0 t_cmax 0
...
where the failure occurs at the 200th UPDATE command.

regards, tom lane

#!/usr/local/pgsql/bin/pgtclsh

set pgconn [pg_connect play]

set res [pg_exec $pgconn \
"DROP TABLE updatebug"]
pg_result $res -clear

set res [pg_exec $pgconn \
"CREATE TABLE updatebug (key int4 not null, val int4)"]
pg_result $res -clear

set res [pg_exec $pgconn \
"CREATE UNIQUE INDEX updatebug_i ON updatebug USING btree(key)"]
pg_result $res -clear

for {set i 0} {$i <= 10000} {incr i} {
set res [pg_exec $pgconn "INSERT INTO updatebug VALUES($i, NULL)"]
pg_result $res -clear
}

# Vacuum to ensure that optimizer will decide to use index for updates...
set res [pg_exec $pgconn \
"VACUUM VERBOSE ANALYZE updatebug"]
pg_result $res -clear

puts "table built..."

for {set i 10000} {$i >= 0} {incr i -1} {
set res [pg_exec $pgconn \
"UPDATE updatebug SET val = 1 WHERE key = $i"]
pg_result $res -clear
}