Received: from malur.postgresql.org ([217.196.149.56]) by arkaria.postgresql.org with esmtps (TLS1.3) tls TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384 (Exim 4.94.2) (envelope-from ) id 1t5pFH-008nh1-67 for pgsql-hackers@arkaria.postgresql.org; Tue, 29 Oct 2024 16:39:03 +0000 Received: from localhost ([127.0.0.1] helo=malur.postgresql.org) by malur.postgresql.org with esmtp (Exim 4.94.2) (envelope-from ) id 1t5pFF-000OZH-EN for pgsql-hackers@arkaria.postgresql.org; Tue, 29 Oct 2024 16:39:01 +0000 Received: from makus.postgresql.org ([2001:4800:3e1:1::229]) by malur.postgresql.org with esmtps (TLS1.3) tls TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384 (Exim 4.94.2) (envelope-from ) id 1t5pFE-000OYR-Vn for pgsql-hackers@lists.postgresql.org; Tue, 29 Oct 2024 16:39:01 +0000 Received: from mail-lf1-f41.google.com ([209.85.167.41]) by makus.postgresql.org with esmtps (TLS1.3) tls TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256 (Exim 4.94.2) (envelope-from ) id 1t5pFB-003Thq-Sc for pgsql-hackers@postgresql.org; Tue, 29 Oct 2024 16:39:00 +0000 Received: by mail-lf1-f41.google.com with SMTP id 2adb3069b0e04-539fbe22ac0so5780992e87.2 for ; Tue, 29 Oct 2024 09:38:57 -0700 (PDT) X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20230601; t=1730219936; x=1730824736; h=cc:to:subject:message-id:date:from:in-reply-to:references :mime-version:x-gm-message-state:from:to:cc:subject:date:message-id :reply-to; bh=DNOoG+2lR1SbviR6DGjMu9FHlfqsLDBWCHP4ngS9tlw=; b=sTFPeqHUBt1caAiDq9W3g9gAyUC2Jfa8vjvdc0udfdGAmOykyE81ZTV32CIQbVm5hQ TX7SzueFv1VEjXbZpaZq2NZ/jM9Vy3hWaXbyT9HmErFq9xmjzSxqdYKWT6AFOd8EDwDv GLhopaI8m+rwx7rS+qfFscwOhUyyDIf+aARX30Fd8zfjUFTzmskrLEfJhKMWoLbRCEqy HundCes/+NYu2I5vm2sUauY7sXZQMXQQE0dWSR/OLV5yZ4salg/r5LyEOBjd2NaPWes8 hmsosvCvwmMjmgjsJFBfWO9zl/5PenzGnN6f5R3mIaYDY8jQNaRopqZ+OINMjvYIAt1x ubOw== X-Forwarded-Encrypted: i=1; AJvYcCWEdwMGVTjvN9gZEQ55sNjHOkeNZh/6R1SXT6dT/IbegqyiS8iFdpZeR0PJ6C2PchMbLZTCJYLgKIw1QVr5@postgresql.org X-Gm-Message-State: AOJu0YwCFp4+aNAY6CyK9XxAwhJYj+ZnHevHz8iyaY2alAN983B/Og+P H0sOnT7yQDMlV4HVplbwn3Kb2LwcSkwb+i3n+9KTBr6ncBCdNAjw8kUX6tcWdXAYWbOoVBsUVcl ZLul8dPQDZ0nzs3gNRQARDKauUs0= X-Google-Smtp-Source: AGHT+IE3B+2SE/J5p121I0Jm09bEBfcTKErjB6goUptsprNjlU8mafq4lAbX5YenNVdW2L8IX3Q8VYFsaYsvuz/AQpE= X-Received: by 2002:a05:6512:3404:b0:530:ad7d:8957 with SMTP id 2adb3069b0e04-53b34b36e63mr5933959e87.49.1730219935626; Tue, 29 Oct 2024 09:38:55 -0700 (PDT) MIME-Version: 1.0 References: <202408221436.o6girevg72sx@alvherre.pgsql> In-Reply-To: From: Thom Brown Date: Tue, 29 Oct 2024 16:38:28 +0000 Message-ID: Subject: Re: MultiXact\SLRU buffers configuration To: Michael Paquier Cc: Alvaro Herrera , "Andrey M. Borodin" , vignesh C , Andrew Borodin , Yura Sokolov , Andres Freund , Thomas Munro , Gilles Darold , Alexander Korotkov , Daniel Gustafsson , Kyotaro Horiguchi , pgsql-hackers mailing list Content-Type: multipart/alternative; boundary="000000000000a583550625a038b9" List-Id: List-Help: List-Subscribe: List-Post: List-Owner: List-Archive: Archived-At: Precedence: bulk --000000000000a583550625a038b9 Content-Type: text/plain; charset="UTF-8" On Fri, 23 Aug 2024 at 01:29, Michael Paquier wrote: > On Thu, Aug 22, 2024 at 10:36:38AM -0400, Alvaro Herrera wrote: > > On 2024-Aug-22, Michael Paquier wrote: > >> I'm not sure that we need to get down to that until somebody has a > >> case where they want to rely on stats of injection points for their > >> stuff. At this stage, I only want the stats to be enabled to provide > >> automated checks for the custom pgstats APIs, so disabling it by > >> default and enabling it only in the stats test of the module > >> injection_points sounds kind of enough to me for now. > > > > Oh! I thought the stats were useful by themselves. > > Yep, currently they're not, but I don't want to discard that they'll > never be, either. Perhaps there would be a case where somebody would > like to run a callback N times and trigger a condition? That's > something where the stats could be useful, but I don't have a specific > case for that now. I'm just imagining possibilities. > I believe I am seeing the problem being discussed occuring on a production system running 15.6, causing ever-increasing replay lag on the standby, until I cancel the offending process on the standby and force it to process its interrupts. Here's the backtrace before I do that: #0 0x00007f4503b81876 in select () from /lib64/libc.so.6 #1 0x0000558b0956891a in pg_usleep (microsec=microsec@entry=1000) at pgsleep.c:56 #2 0x0000558b0917e01a in GetMultiXactIdMembers (from_pgupgrade=false, onlyLock=, members=0x7ffcd2a9f1e0, multi=109187502) at multixact.c:1392 #3 GetMultiXactIdMembers (multi=109187502, members=members@entry=0x7ffcd2a9f1e0, from_pgupgrade=from_pgupgrade@entry=false, onlyLock=onlyLock@entry=false) at multixact.c:1224 #4 0x0000558b0913de15 in MultiXactIdGetUpdateXid (xmax=, t_infomask=) at heapam.c:6924 #5 0x0000558b09146028 in HeapTupleGetUpdateXid (tuple=tuple@entry=0x7f440d428308) at heapam.c:6965 #6 0x0000558b0914c02f in HeapTupleSatisfiesMVCC (htup=0x558b0b7cbf20, htup=0x558b0b7cbf20, buffer=8053429, snapshot=0x558b0b63a2d8) at heapam_visibility.c:1089 #7 HeapTupleSatisfiesVisibility (tup=tup@entry=0x7ffcd2a9f2b0, snapshot=snapshot@entry=0x558b0b63a2d8, buffer=buffer@entry=8053429) at heapam_visibility.c:1771 #8 0x0000558b0913e819 in heapgetpage (sscan=sscan@entry=0x558b0b7ccfa0, page=page@entry=115) at heapam.c:468 #9 0x0000558b0913eb7e in heapgettup_pagemode (scan=scan@entry=0x558b0b7ccfa0, dir=ForwardScanDirection, nkeys=0, key=0x0) at heapam.c:1120 #10 0x0000558b0913fb5e in heap_getnextslot (sscan=0x558b0b7ccfa0, direction=, slot=0x558b0b7cc000) at heapam.c:1352 #11 0x0000558b092c0e7a in table_scan_getnextslot (slot=0x558b0b7cc000, direction=ForwardScanDirection, sscan=) at ../../../src/include/access/tableam.h:1046 #12 SeqNext (node=0x558b0b7cbe10) at nodeSeqscan.c:80 #13 0x0000558b0929b9bf in ExecScan (node=0x558b0b7cbe10, accessMtd=0x558b092c0df0 , recheckMtd=0x558b092c0dc0 ) at execScan.c:198 #14 0x0000558b09292cb2 in ExecProcNode (node=0x558b0b7cbe10) at ../../../src/include/executor/executor.h:262 #15 ExecutePlan (execute_once=, dest=0x558b0bca1350, direction=, numberTuples=0, sendTuples=, operation=CMD_SELECT, use_parallel_mode=, planstate=0x558b0b7cbe10, estate=0x558b0b7cbbe8) at execMain.c:1636 #16 standard_ExecutorRun (queryDesc=0x558b0b8c9798, direction=, count=0, execute_once=) at execMain.c:363 #17 0x00007f44f64d43c5 in pgss_ExecutorRun (queryDesc=0x558b0b8c9798, direction=ForwardScanDirection, count=0, execute_once=) at pg_stat_statements.c:1010 #18 0x0000558b093fda0f in PortalRunSelect (portal=portal@entry=0x558b0b6ba458, forward=forward@entry=true, count=0, count@entry=9223372036854775807, dest=dest@entry=0x558b0bca1350) at pquery.c:924 #19 0x0000558b093fedb8 in PortalRun (portal=portal@entry=0x558b0b6ba458, count=count@entry=9223372036854775807, isTopLevel=isTopLevel@entry=true, run_once=run_once@entry=true, dest=dest@entry=0x558b0bca1350, altdest=altdest@entry=0x558b0bca1350, qc=0x7ffcd2a9f7a0) at pquery.c:768 #20 0x0000558b093fb243 in exec_simple_query ( query_string=0x558b0b6170c8 "") at postgres.c:1250 #21 0x0000558b093fd412 in PostgresMain (dbname=, username=) at postgres.c:4598 #22 0x0000558b0937e170 in BackendRun (port=, port=) at postmaster.c:4514 #23 BackendStartup (port=) at postmaster.c:4242 #24 ServerLoop () at postmaster.c:1809 #25 0x0000558b0937f147 in PostmasterMain (argc=argc@entry=5, argv=argv@entry=0x558b0b5d0a30) at postmaster.c:1481 #26 0x0000558b09100a2c in main (argc=5, argv=0x558b0b5d0a30) at main.c:202 This occurred twice, meaning 2 processes needed terminating. Thom --000000000000a583550625a038b9 Content-Type: text/html; charset="UTF-8" Content-Transfer-Encoding: quoted-printable
On Fri, 23 Aug 2024 at 01:29, Michael Paquier <michael@paquier.xyz> wrote:
On Thu, Aug 22, 2024 at 10:36:38AM = -0400, Alvaro Herrera wrote:
> On 2024-Aug-22, Michael Paquier wrote:
>> I'm not sure that we need to get down to that until somebody h= as a
>> case where they want to rely on stats of injection points for thei= r
>> stuff.=C2=A0 At this stage, I only want the stats to be enabled to= provide
>> automated checks for the custom pgstats APIs, so disabling it by >> default and enabling it only in the stats test of the module
>> injection_points sounds kind of enough to me for now.
>
> Oh!=C2=A0 I thought the stats were useful by themselves.

Yep, currently they're not, but I don't want to discard that they&#= 39;ll
never be, either.=C2=A0 Perhaps there would be a case where somebody would<= br> like to run a callback N times and trigger a condition?=C2=A0 That's something where the stats could be useful, but I don't have a specific =
case for that now.=C2=A0 I'm just imagining possibilities.

I believe I am seeing the problem being discussed o= ccuring on a production system running 15.6, causing ever-increasing replay= lag on the standby, until I cancel the offending process on the standby an= d force it to process its interrupts.

Here's t= he backtrace before I do that:

#0 =C2=A00x0000= 7f4503b81876 in select () from /lib64/libc.so.6
#1 =C2=A00x0000558b09568= 91a in pg_usleep (microsec=3Dmicrosec@entry=3D1000) at pgsleep.c:56
#2 = =C2=A00x0000558b0917e01a in GetMultiXactIdMembers (from_pgupgrade=3Dfalse, = onlyLock=3D<optimized out>, members=3D0x7ffcd2a9f1e0, multi=3D1091875= 02) at multixact.c:1392
#3 =C2=A0GetMultiXactIdMembers (multi=3D10918750= 2, members=3Dmembers@entry=3D0x7ffcd2a9f1e0, from_pgupgrade=3Dfrom_pgupgrad= e@entry=3Dfalse, onlyLock=3DonlyLock@entry=3Dfalse) at multixact.c:1224
= #4 =C2=A00x0000558b0913de15 in MultiXactIdGetUpdateXid (xmax=3D<optimize= d out>, t_infomask=3D<optimized out>) at heapam.c:6924
#5 =C2= =A00x0000558b09146028 in HeapTupleGetUpdateXid (tuple=3Dtuple@entry=3D0x7f4= 40d428308) at heapam.c:6965
#6 =C2=A00x0000558b0914c02f in HeapTupleSati= sfiesMVCC (htup=3D0x558b0b7cbf20, htup=3D0x558b0b7cbf20, buffer=3D8053429, = snapshot=3D0x558b0b63a2d8) at heapam_visibility.c:1089
#7 =C2=A0HeapTupl= eSatisfiesVisibility (tup=3Dtup@entry=3D0x7ffcd2a9f2b0, snapshot=3Dsnapshot= @entry=3D0x558b0b63a2d8, buffer=3Dbuffer@entry=3D8053429) at heapam_visibil= ity.c:1771
#8 =C2=A00x0000558b0913e819 in heapgetpage (sscan=3Dsscan@ent= ry=3D0x558b0b7ccfa0, page=3Dpage@entry=3D115) at heapam.c:468
#9 =C2=A00= x0000558b0913eb7e in heapgettup_pagemode (scan=3Dscan@entry=3D0x558b0b7ccfa= 0, dir=3DForwardScanDirection, nkeys=3D0, key=3D0x0) at heapam.c:1120
#1= 0 0x0000558b0913fb5e in heap_getnextslot (sscan=3D0x558b0b7ccfa0, direction= =3D<optimized out>, slot=3D0x558b0b7cc000) at heapam.c:1352
#11 0x= 0000558b092c0e7a in table_scan_getnextslot (slot=3D0x558b0b7cc000, directio= n=3DForwardScanDirection, sscan=3D<optimized out>) at ../../../src/in= clude/access/tableam.h:1046
#12 SeqNext (node=3D0x558b0b7cbe10) at nodeS= eqscan.c:80
#13 0x0000558b0929b9bf in ExecScan (node=3D0x558b0b7cbe10, a= ccessMtd=3D0x558b092c0df0 <SeqNext>, recheckMtd=3D0x558b092c0dc0 <= SeqRecheck>) at execScan.c:198
#14 0x0000558b09292cb2 in ExecProcNode= (node=3D0x558b0b7cbe10) at ../../../src/include/executor/executor.h:262#15 ExecutePlan (execute_once=3D<optimized out>, dest=3D0x558b0bca13= 50, direction=3D<optimized out>, numberTuples=3D0, sendTuples=3D<o= ptimized out>, operation=3DCMD_SELECT, use_parallel_mode=3D<optimized= out>, planstate=3D0x558b0b7cbe10, estate=3D0x558b0b7cbbe8)
=C2=A0 = =C2=A0 at execMain.c:1636
#16 standard_ExecutorRun (queryDesc=3D0x558b0b= 8c9798, direction=3D<optimized out>, count=3D0, execute_once=3D<op= timized out>) at execMain.c:363
#17 0x00007f44f64d43c5 in pgss_Execut= orRun (queryDesc=3D0x558b0b8c9798, direction=3DForwardScanDirection, count= =3D0, execute_once=3D<optimized out>) at pg_stat_statements.c:1010#18 0x0000558b093fda0f in PortalRunSelect (portal=3Dportal@entry=3D0x558b0= b6ba458, forward=3Dforward@entry=3Dtrue, count=3D0, count@entry=3D922337203= 6854775807, dest=3Ddest@entry=3D0x558b0bca1350) at pquery.c:924
#19 0x00= 00558b093fedb8 in PortalRun (portal=3Dportal@entry=3D0x558b0b6ba458, count= =3Dcount@entry=3D9223372036854775807, isTopLevel=3DisTopLevel@entry=3Dtrue,= run_once=3Drun_once@entry=3Dtrue, dest=3Ddest@entry=3D0x558b0bca1350,
= =C2=A0 =C2=A0 altdest=3Daltdest@entry=3D0x558b0bca1350, qc=3D0x7ffcd2a9f7a0= ) at pquery.c:768
#20 0x0000558b093fb243 in exec_simple_query (
=C2= =A0 =C2=A0 query_string=3D0x558b0b6170c8 "<redacted>")
= =C2=A0 =C2=A0 at postgres.c:1250
#21 0x0000558b093fd412 in PostgresMain = (dbname=3D<optimized out>, username=3D<optimized out>) at postg= res.c:4598
#22 0x0000558b0937e170 in BackendRun (port=3D<optimized ou= t>, port=3D<optimized out>) at postmaster.c:4514
#23 BackendSta= rtup (port=3D<optimized out>) at postmaster.c:4242
#24 ServerLoop = () at postmaster.c:1809
#25 0x0000558b0937f147 in PostmasterMain (argc= =3Dargc@entry=3D5, argv=3Dargv@entry=3D0x558b0b5d0a30) at postmaster.c:1481=
#26 0x0000558b09100a2c in main (argc=3D5, argv=3D0x558b0b5d0a30) at mai= n.c:202
=C2=A0
This occurred twice, meaning 2 processes= needed terminating.

Thom
--000000000000a583550625a038b9--