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=<value optimized 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=<value optimized 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