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 1tAWyj-00GH1c-8X for pgsql-admin@arkaria.postgresql.org; Mon, 11 Nov 2024 16:09:24 +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 1tAWyg-00FkJj-DT for pgsql-admin@arkaria.postgresql.org; Mon, 11 Nov 2024 16:09:22 +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 1tAWyf-00FkJZ-R5 for pgsql-admin@lists.postgresql.org; Mon, 11 Nov 2024 16:09:22 +0000 Received: from mout.kundenserver.de ([212.227.126.187]) by makus.postgresql.org with esmtps (TLS1.3) tls TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384 (Exim 4.94.2) (envelope-from ) id 1tAWyc-001Kl9-UC for pgsql-admin@lists.postgresql.org; Mon, 11 Nov 2024 16:09:20 +0000 DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=msym.fr; s=s1-ionos; t=1731341356; x=1731946156; i=msalais@msym.fr; bh=5+rorrKWaRgaYQiJu5nWekATAOxvLH4bLpYbclemxG4=; h=X-UI-Sender-Class:From:To:Cc:References:In-Reply-To:Subject:Date: Message-ID:MIME-Version:Content-Type:cc:content-transfer-encoding: content-type:date:from:message-id:mime-version:reply-to:subject: to; b=06HTIMphp1b6g8yCc1G6cTR7yZGdF7dl/b5LvAYUMVjjp6cCiUAwVheu9FQbSNYg Oe755fMPEEt9QRLxVqHylGPddJHsSBm6LtQENITvI4hWeKZlEWnnf363jQlFZ4aJA OXmFugV0TSV9uc52uG7TmSI3EUQX67fk86c9TTEGYo+WBKTgV2/PEwkvNfFZsLw9w 7HpGFkuIZ39iSF0MxRq9vVgmyPp4IwGSGorv0MaDkrwNcuEnaMdkHTu9ketuP6NOm C6dkHXM0U3i7i4r8gAOKrDUbb04l5sHkS91CRzNUXcJBO6RL+bArcbrK68jjmWXHD uhbzmjXwMoQG9sTOOg== X-UI-Sender-Class: 55c96926-9e95-11ee-ae09-1f7a4046a0f6 Received: from msim1 ([78.197.128.121]) by mrelayeu.kundenserver.de (mreue009 [212.227.15.168]) with ESMTPSA (Nemesis) id 1MdeSn-1tk8uT0OCv-00pJ6R; Mon, 11 Nov 2024 17:09:16 +0100 From: To: "'Edwin UY'" , "'Tom Lane'" Cc: "'David G. Johnston'" , References: <216310.1731300338@sss.pgh.pa.us> In-Reply-To: Subject: RE: How to check if session is a hung thread/session Date: Mon, 11 Nov 2024 17:09:14 +0100 Message-ID: <025001db3454$0dbc19d0$29344d70$@msym.fr> MIME-Version: 1.0 Content-Type: multipart/alternative; boundary="----=_NextPart_000_0251_01DB345C.6F80CFF0" X-Mailer: Microsoft Outlook 16.0 Thread-Index: AQHpJyumZGZs4fAGYOIY4unxp+zzMQFTn0fNAjOgUJAA+gjKYQHUa+pesmOg24A= Content-Language: fr X-Provags-ID: V03:K1:jt01zXBvO43uPBQ2fmG+dhKYRTfr8whjBo6GPRKl7lj+UPICFME IxQq4VOdmwJQYkIo5nJbqDDzHs3kJT7x/wymRY1PIJTZ9fIXJQ65dk3bXHP0tDJYL+Z239p TIxToVfV5z48pNqYBA5Z9qzYtL/zinp3eIGYsT2Sprw140qCzxJQuotyHvfO7SX7TxU7L/K kMirU77FjltZz398NFTMA== X-Spam-Flag: NO UI-OutboundReport: notjunk:1;M01:P0:8Rv457CuZCs=;zpWl1yc5NnYijMyQlTTYf4IGJZ0 ty7rwQf4aaBERDosaRY/5PbH6Dy/vIhQYQnn2D1uz7nE5IROFJ2qBUn9ywzXMaYQ8I8wz/YTk A/aQt7VGCvBupqft9AZfj6NzTDuI4WnjCY5ywjpYM0/tpUh0dLS36jtKuhWIdxGfwMbESN/F9 PRre8d+QNrU0een9l32bZa9/1CBHlaXcWKVL7FkxgA2inTw2FdqXspjIBxSxDDU3d7mhO9+2n 5DMCCU5wXYDLd4Yb1TJsowp3fkiCpQvCZ/mMhwCzHu8nSeqrZmN+wSDSWapJRoxz5QOxCtFqa fK7UdwbmTD4GMXd1EqcmWw5wdCFT4tR6SDLM/EqyAmaSLez2/4yXQXJCEvui9xnOQHCG9oUXR gjkhnG4vjPJV7c3VNvPzu6rKN9x7f1hd48HtId82PvBOLV95bGalhu01xHE9pOr4FNklmE0TA oLQcE83eW8UrZ2XMcUTFnh4tpoqc7UOt9iDjSqQokr4II3E3dNkUG8bDwtgwE/oiLuq3yl0oa RW5rmE+Bz2EfsIVazHtb1H+6DobEkbu7WUCDXFahYmz0kF/NxoFZfisqTiBF2etDdU3dfVpjq 1Yj+cc4SBLDnKQzS8ironWld3wp430b+giKuZbhg9H2NB6BWUsr5MGOagbaRDvprbsuNCM9DO 8Uhy5byzECDQsCuDQd8KCZhbiiZeoW/8ZixtP94YW8G9tm18mBE1/HCCj4cI5BO+hVQ53mBGi bdfQTVdjcf5zu9J4y/Ea+J/er1P9wJSHBvJmcO4xB7cgXf4KSIkEi04d04ptOpAa6Ubh+u/zk QU5/qTX8TH3PPMCeYQ/5kw7OpDYkcn8jpiu8SePoWywj9Rg8IDtE++HM0BzQ53ipmo List-Id: List-Help: List-Subscribe: List-Post: List-Owner: List-Archive: Archived-At: Precedence: bulk This is a multipart message in MIME format. ------=_NextPart_000_0251_01DB345C.6F80CFF0 Content-Type: text/plain; charset="UTF-8" Content-Transfer-Encoding: quoted-printable Hi, =20 The log you expose doesn=E2=80=99t mean a dead lock! It comes from = setting deadlock_timeout parameter. Its value is 1 second by default. = When a session waits for a lock more than this threshold then a test to = see if we are in a deadlock condition is triggered. It is simply that we = are waiting to obtain a lock for longer that the value of = deadlock_timeout. Any way it could be interpreted as a performance = problem when we are frequently waiting more than 1 sec for a = lock=E2=80=A6 =20 Regards =20 Michel SALAIS De : Edwin UY =20 Envoy=C3=A9 : lundi 11 novembre 2024 07:45 =C3=80 : Tom Lane Cc : David G. Johnston ; = pgsql-admin@lists.postgresql.org Objet : Re: How to check if session is a hung thread/session =20 Thanks Tom, =20 OK, I've decided to 'painfully' look at the PostgreSQL RDS logs and it = is showing something like below.=20 There seems to be a locking/deadlock issue of some sort somewhere.=20 I have checked the other days' log prior to the patching and these = appear to be a 'normal' occurrence for this database and it wasn't = affecting the application nonetheless. After the patching, it starts affecting the application. Not sure what = else I can check on the Aurora PostgreSQL RDS end. I may request them to = restart the app server. =20 [25751]:LOG: process 25751 still waiting for ShareLock on transaction = 114953443 after 1000.054 ms [25751]:DETAIL: Process holding the lock: 22297. Wait queue: 25751. [25751]:CONTEXT: while locking tuple (1,17) in relation "[table_name]" [25751]:STATEMENT: [SQL_STATEMENT] for update [25751]:LOG: process 25751 acquired ShareLock on transaction 114953443 = after 4756.967 ms [25751]:CONTEXT: while locking tuple (1,17) in relation " [table_name] = " =20 =20 On Mon, Nov 11, 2024 at 5:45=E2=80=AFPM Tom Lane > wrote: Edwin UY > writes: > I thought it could be the backend has sent something back to the = client but > it never received it and it just kept on doing the same at some = intervals. Your pg_stat_activity output shows the backend is idle, meaning it's waiting for a client command. While the session has been around for days, we can see the last client command was about 47 minutes ago, from your "now() - pg_stat_activity.query_start AS duration" column. I see no reason to think there is anything interesting here at all, except for a client that is sitting doing nothing for long periods. regards, tom lane ------=_NextPart_000_0251_01DB345C.6F80CFF0 Content-Type: text/html; charset="UTF-8" Content-Transfer-Encoding: quoted-printable

Hi,

 

The log you expose doesn=E2=80=99t = mean a dead lock! It comes from setting deadlock_timeout parameter. Its = value is 1 second by default. When a session waits for a lock more than = this threshold then a test to see if we are in a deadlock condition is = triggered. It is simply that we are waiting to obtain a lock for longer = that the value of deadlock_timeout. Any way it could be interpreted as a = performance problem when we are frequently waiting more than 1 sec for a = lock=E2=80=A6

 

Regards

 

Michel = SALAIS

De : Edwin UY = <edwin.uy@gmail.com>
Envoy=C3=A9 : lundi 11 = novembre 2024 07:45
=C3=80 : Tom Lane = <tgl@sss.pgh.pa.us>
Cc : David G. Johnston = <david.g.johnston@gmail.com>; = pgsql-admin@lists.postgresql.org
Objet : Re: How to check = if session is a hung thread/session

 

Thanks Tom,

 

OK, I've decided to 'painfully' look at the PostgreSQL = RDS logs and it is showing something like below. =

There seems to be a = locking/deadlock issue of some sort somewhere. =

I have checked the other = days' log prior to the patching and these appear to be a 'normal' = occurrence for this database and it wasn't affecting the application = nonetheless.

After the = patching, it starts affecting the application. Not sure what else I can = check on the Aurora PostgreSQL RDS end. I may request them to restart = the app server.

 

[25751]:LOG: =  process 25751 still waiting for ShareLock on transaction 114953443 = after 1000.054 ms

[25751]:DETAIL:  Process holding the lock: 22297. Wait queue: = 25751.

[25751]:CONTEXT:  while locking = tuple (1,17) in relation = "[table_name]"

[25751]:STATEMENT:  [SQL_STATEMENT] for = update
[25751]:LOG:  process 25751 acquired ShareLock on = transaction 114953443 after 4756.967 ms
[25751]:CONTEXT:  while = locking tuple (1,17) in relation " [table_name] "

 

 

On = Mon, Nov 11, 2024 at 5:45=E2=80=AFPM Tom Lane <tgl@sss.pgh.pa.us> = wrote:

Edwin UY = <edwin.uy@gmail.com> writes:
> I thought = it could be the backend has sent something back to the client = but
> it never received it and it just kept on doing the same at = some intervals.

Your pg_stat_activity output shows the backend is = idle, meaning it's
waiting for a client command.  While the = session has been around for
days, we can see the last client command = was about 47 minutes ago,
from your "now() - = pg_stat_activity.query_start AS duration" column.
I see no = reason to think there is anything interesting here at all,
except for = a client that is sitting doing nothing for long periods.

  =                     =   regards, tom = lane

------=_NextPart_000_0251_01DB345C.6F80CFF0--