Re: ANALYZE: ERROR: tuple already updated by self

On Tue, Jun 18, 2019 at 06:12:33PM -0500, Justin Pryzby wrote:
> A customers DB crashed due to OOM.  While investigating the issue in our
> report, I created MV stats, which causes this error:
> 
> ts=# CREATE STATISTICS sectors_stats (dependencies) ON site_id,sect_id FROM sectors;
> CREATE STATISTICS
> ts=# ANALYZE sectors;
> ERROR:  XX000: tuple already updated by self
> LOCATION:  simple_heap_update, heapam.c:4613

> I'm guessing the issue is with pg_statistic_ext, which I haven't touched.
> 
> Next step seems to be to truncate pg_statistic{,ext} and re-analyze the DB.

Confirmed the issue is there.

ts=# analyze sectors;
ERROR:  tuple already updated by self
ts=# begin; delete from pg_statistic_ext; analyze sectors;
BEGIN
DELETE 87
ANALYZE

On Tue, Jun 18, 2019 at 04:30:33PM -0700, Andres Freund wrote:
> Any chance to get a backtrace for the error?

Sure:

(gdb) bt
#0  errfinish (dummy=0) at elog.c:414
#1  0x000000000085e834 in elog_finish (elevel=<value optimized out>, fmt=<value optimized out>) at elog.c:1376
#2  0x00000000004b93bd in simple_heap_update (relation=0x7fee161700c8, otid=0x1fb7f44, tup=0x1fb7f40) at heapam.c:4613
#3  0x000000000051bdb7 in CatalogTupleUpdate (heapRel=0x7fee161700c8, otid=0x1fb7f44, tup=0x1fb7f40) at indexing.c:234
#4  0x000000000071e5ca in statext_store (onerel=0x7fee16140de8, totalrows=100843, numrows=100843, rows=0x1fd4028,
natts=33260176,vacattrstats=0x1fb7ef0) at extended_stats.c:344
 
#5  BuildRelationExtStatistics (onerel=0x7fee16140de8, totalrows=100843, numrows=100843, rows=0x1fd4028,
natts=33260176,vacattrstats=0x1fb7ef0) at extended_stats.c:130
 
#6  0x0000000000588346 in do_analyze_rel (onerel=0x7fee16140de8, options=2, params=0x7ffe5b6bf8b0, va_cols=0x0,
acquirefunc=0x492b4,relpages=36, inh=true, in_outer_xact=false, elevel=13) at analyze.c:627
 
#7  0x00000000005891e1 in analyze_rel (relid=<value optimized out>, relation=0x1ea22a0, options=2,
params=0x7ffe5b6bf8b0,va_cols=0x0, in_outer_xact=false, bstrategy=0x1f38090) at analyze.c:317
 
#8  0x00000000005fb689 in vacuum (options=2, relations=0x1f381f0, params=0x7ffe5b6bf8b0, bstrategy=<value optimized
out>,isTopLevel=<value optimized out>) at vacuum.c:357
 
#9  0x00000000005fbafe in ExecVacuum (vacstmt=<value optimized out>, isTopLevel=<value optimized out>) at vacuum.c:141
#10 0x0000000000757a30 in standard_ProcessUtility (pstmt=0x1ea2410, queryString=0x1ea18c0 "ANALYZE sectors;",
context=PROCESS_UTILITY_TOPLEVEL,params=0x0, queryEnv=0x0, dest=0x1ea26d0, completionTag=0x7ffe5b6bfdf0 "")
 
    at utility.c:670
#11 0x00007fee163a4344 in pgss_ProcessUtility (pstmt=0x1ea2410, queryString=0x1ea18c0 "ANALYZE sectors;",
context=PROCESS_UTILITY_TOPLEVEL,params=0x0, queryEnv=0x0, dest=0x1ea26d0, completionTag=0x7ffe5b6bfdf0 "")
 
    at pg_stat_statements.c:1005
#12 0x0000000000753779 in PortalRunUtility (portal=0x1f1a8e0, pstmt=0x1ea2410, isTopLevel=<value optimized out>,
setHoldSnapshot=<valueoptimized out>, dest=0x1ea26d0, completionTag=<value optimized out>) at pquery.c:1178
 
#13 0x000000000075464d in PortalRunMulti (portal=0x1f1a8e0, isTopLevel=true, setHoldSnapshot=false, dest=0x1ea26d0,
altdest=0x1ea26d0,completionTag=0x7ffe5b6bfdf0 "") at pquery.c:1331
 
#14 0x0000000000754de8 in PortalRun (portal=0x1f1a8e0, count=9223372036854775807, isTopLevel=true, run_once=true,
dest=0x1ea26d0,altdest=0x1ea26d0, completionTag=0x7ffe5b6bfdf0 "") at pquery.c:799
 
#15 0x0000000000751987 in exec_simple_query (query_string=0x1ea18c0 "ANALYZE sectors;") at postgres.c:1145
#16 0x0000000000752931 in PostgresMain (argc=<value optimized out>, argv=<value optimized out>, dbname=0x1edbad8 "ts",
username=<valueoptimized out>) at postgres.c:4182
 
#17 0x00000000006e1ba7 in BackendRun (argc=<value optimized out>, argv=<value optimized out>) at postmaster.c:4358
#18 BackendStartup (argc=<value optimized out>, argv=<value optimized out>) at postmaster.c:4030
#19 ServerLoop (argc=<value optimized out>, argv=<value optimized out>) at postmaster.c:1707
#20 PostmasterMain (argc=<value optimized out>, argv=<value optimized out>) at postmaster.c:1380
#21 0x0000000000656210 in main (argc=3, argv=0x1e9c4d0) at main.c:228

#3  0x000000000051bdb7 in CatalogTupleUpdate (heapRel=0x7fee161700c8, otid=0x1fb7f44, tup=0x1fb7f40) at indexing.c:234
        indstate = 0x1fb84a0
#4  0x000000000071e5ca in statext_store (onerel=0x7fee16140de8, totalrows=100843, numrows=100843, rows=0x1fd4028,
natts=33260176,vacattrstats=0x1fb7ef0) at extended_stats.c:344
 
        stup = 0x1fb7f40
        oldtup = 0x7fee16158530
        values = {0, 0, 0, 0, 0, 0, 0, 33260544}
        nulls = {true, true, true, true, true, true, true, false}
        replaces = {false, false, false, false, false, false, true, true}
#5  BuildRelationExtStatistics (onerel=0x7fee16140de8, totalrows=100843, numrows=100843, rows=0x1fd4028,
natts=33260176,vacattrstats=0x1fb7ef0) at extended_stats.c:130
 
        stat = <value optimized out>
        stats = <value optimized out>
        lc2 = <value optimized out>
        ndistinct = <value optimized out>
        dependencies = <value optimized out>
        pg_stext = 0x7fee161700c8
        lc = 0x1fb8290
        stats = 0xfb6a172d
        cxt = 0x1fb7de0
        oldcxt = 0x1f6dd60
        __func__ = "BuildRelationExtStatistics"


Ah: the table is an inheritence parent.  If I uninherit its child, there's no
error during ANALYZE.  MV stats on the child are ok:

ts=# CREATE STATISTICS vzw_sectors_stats (dependencies) ON site_id,sect_id FROM vzw_sectors;
CREATE STATISTICS
ts=# ANALYZE vzw_sectors;
ANALYZE

I'm not sure what the behavior is intended to be, and probably the other parent
tables I've added stats are all relkind=p.

FWIW, we also have some FKs, like:

    "sectors_site_id_fkey" FOREIGN KEY (site_id) REFERENCES sites(site_id)

Justin