Received: from malur.postgresql.org ([217.196.149.56]) by arkaria.postgresql.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_CBC_SHA1:256) (Exim 4.89) (envelope-from ) id 1hdNqi-0002KW-AX for pgsql-hackers@arkaria.postgresql.org; Tue, 18 Jun 2019 23:49:12 +0000 Received: from localhost ([127.0.0.1] helo=malur.postgresql.org) by malur.postgresql.org with esmtp (Exim 4.89) (envelope-from ) id 1hdNqh-000637-5E for pgsql-hackers@arkaria.postgresql.org; Tue, 18 Jun 2019 23:49:11 +0000 Received: from magus.postgresql.org ([2a02:c0:301:0:ffff::29]) by malur.postgresql.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_CBC_SHA1:256) (Exim 4.89) (envelope-from ) id 1hdNqg-000630-T1 for pgsql-hackers@lists.postgresql.org; Tue, 18 Jun 2019 23:49:10 +0000 Received: from mail-io1-xd2d.google.com ([2607:f8b0:4864:20::d2d]) by magus.postgresql.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_CBC_SHA1:256) (Exim 4.89) (envelope-from ) id 1hdNqa-0000ls-5I for pgsql-hackers@postgresql.org; Tue, 18 Jun 2019 23:49:10 +0000 Received: by mail-io1-xd2d.google.com with SMTP id e3so33837919ioc.12 for ; Tue, 18 Jun 2019 16:49:03 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=telsasoft-com.20150623.gappssmtp.com; s=20150623; h=date:from:to:subject:message-id:references:mime-version :content-disposition:in-reply-to:user-agent; bh=pdJ7yKEpv12hr/DUcKehGiP/WSe0+yfDAT/I502hsEc=; b=W0kwKVaseU5TRkxD332o+/PqlIjXuW0WH/1houz83f2zZDcPmt2KvUMJ4xyeJN2zej EKZfzMNfeVrV96VorvbAu86mVYBa8HSM4owOkQAvMZfEgOLUbgvbonujZwMA0PMga/dF LWGIUAyENjjnA9Kl+v9dxFsqlnPDtgQ/zcNwixhph34uCDe5EoI5n+RVfRFbGszui83w Xb0kTB3WVxF+JKPcxOfWM1ma7eWexcQfmFdgTjMDQpGvZAvQrbtSgTZFwjkvdU8ez+/F o0v7NgGWk4/QRjJFVREtEDyRUVtko3mPWZtphJZMrqfo39HJb8Jz+fEx28W1Mpb8X2Q0 MEBQ== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:date:from:to:subject:message-id:references :mime-version:content-disposition:in-reply-to:user-agent; bh=pdJ7yKEpv12hr/DUcKehGiP/WSe0+yfDAT/I502hsEc=; b=sHMThNLBdP7izcv+Jx45WlvWxJaMe07MDM3C1Hjv7Hnb49eeBzBf7OX4hNvDMMp/Vx q8KvtsUy1Pz1nVsiVSfPQ2h9HxMo2xoPlaT6x9nnwh1xOwJbosJlY2TfOq6HfzcNRWbb qz2iDXYsNzBgpFXVReKGi8MrPFoACi5FobiPxdk9EU6ZcUkRzIlEY0ewX3TN8EzDMi6M 1g4uDtML2AfsCiAj6RLAOY6BqUuwVzSg864IGHI7d3bMsRjyzkV/+xeJ7byMhUDC9vr9 Q+qKS5ugdhiD+fKR87154a2TylJEVDEUMNx+KC2EMZLIqYDC//r+FHhEDiD67AQXw/E7 /RUw== X-Gm-Message-State: APjAAAW5V909vh90fvIP1ZiLCOoLezwcxEPlKoeh10LfYw+ao2E6DQl2 bY97H2F9bq4IuPo5qcPw6x9ADrSGq+U= X-Google-Smtp-Source: APXvYqxSD+o+nmflR6dpP876Y8G3KuVKaefpJoezFVTnM84mJUsG7ZdRL5wzYqqlvFeBeO8xNv4Jig== X-Received: by 2002:a02:5489:: with SMTP id t131mr90222694jaa.70.1560901741110; Tue, 18 Jun 2019 16:49:01 -0700 (PDT) Received: from pryzbyj (charmander.telsasoft.com. [50.244.222.1]) by smtp.gmail.com with ESMTPSA id n26sm11614001ioc.74.2019.06.18.16.48.59 for (version=TLS1_2 cipher=ECDHE-RSA-AES128-GCM-SHA256 bits=128/128); Tue, 18 Jun 2019 16:49:00 -0700 (PDT) Received: by pryzbyj (Postfix, from userid 1000) id BFB55800A33; Tue, 18 Jun 2019 18:48:58 -0500 (CDT) Date: Tue, 18 Jun 2019 18:48:58 -0500 From: Justin Pryzby To: pgsql-hackers@postgresql.org Subject: Re: ANALYZE: ERROR: tuple already updated by self Message-ID: <20190618234858.GK16019@telsasoft.com> References: <20190618231233.GA27470@telsasoft.com> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: <20190618231233.GA27470@telsasoft.com> User-Agent: Mutt/1.5.24 (2015-08-30) List-Id: List-Help: List-Subscribe: List-Post: List-Owner: List-Archive: Precedence: bulk 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=, fmt=) 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=, 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=, isTopLevel=) at vacuum.c:357 #9 0x00000000005fbafe in ExecVacuum (vacstmt=, isTopLevel=) 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=, setHoldSnapshot=, dest=0x1ea26d0, completionTag=) 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=, argv=, dbname=0x1edbad8 "ts", username=) at postgres.c:4182 #17 0x00000000006e1ba7 in BackendRun (argc=, argv=) at postmaster.c:4358 #18 BackendStartup (argc=, argv=) at postmaster.c:4030 #19 ServerLoop (argc=, argv=) at postmaster.c:1707 #20 PostmasterMain (argc=, argv=) 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 = stats = lc2 = ndistinct = dependencies = 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