Message-ID: <gh-pgjdbc-pgjdbc-3840-c3420887365@github.com>
From: "wgfm (@wgfm)" <noreply+wgfm@github.com>
To: "pgjdbc/pgjdbc" <noreply+pgjdbc-pgjdbc@github.com>
Date: Mon, 20 Oct 2025 07:21:55 +0000
Subject: Re: [pgjdbc/pgjdbc] issue #3840: Periodic latency spikes to Postgres in large scale deployment
In-Reply-To: <gh-pgjdbc-pgjdbc-3840@github.com>
References: <gh-pgjdbc-pgjdbc-3840@github.com>
List-Id: <gh-pgjdbc-pgjdbc.github.com>
X-GitHub-Author-Login: wgfm
X-GitHub-Comment-Id: 3420887365
X-GitHub-Comment-Type: issue_comment
X-GitHub-Issue: 3840
X-GitHub-Repo: pgjdbc/pgjdbc
X-GitHub-Type: comment
X-GitHub-Url: https://github.com/pgjdbc/pgjdbc/issues/3840#issuecomment-3420887365
Content-Type: text/plain; charset=utf-8

Unfortunately, I can't provide our JFRs, as those are classified. I may be able to walk you through one in a video call if that would be useful, but I'll have to get clearance first.

Here's a redacted stack trace for a socket read wait event, though nothing looks out of the ordinary here to me:

```
Thread.run()
ThreadPoolExecutor$Worker.run()
ThreadPoolExecutor.runWorker(ThreadPoolExecutor$Worker)
MyShadowReader.read(long, long, boolean, boolean)
OurOpenTracingUtilKtKt.traceSync(String, Function1)
OurOpenTracingUtil.applyWithTracerSpan(String, Function)
OurOpenTracingUtil.doWithTracerSpan(String, Function)
OurOpenTracingUtil.doWithTracerSpan(String, Span, Function)
OurOpenTracingUtilKtKt$$Lambda$7552+0x000000080410e890.292814703.apply(Object)
OurOpenTracingUtilKtKt.traceSync$lambda$0(Function1, Span)
MyShadowReader$$Lambda$7573+0x000000080413ebe0.845997003.invoke(Object)
MyShadowReader.read$lambda$10(MyShadowReader, long, long, boolean, boolean, Span)
MyPostgresRepository.findOne(long, long, boolean, boolean)
MyQuery.get(long, long, boolean, boolean)
DefaultDSLContext.fetchOne(String, Object[])
ResultQueryTrait.fetchOne()
AbstractResultQuery.fetchLazyNonAutoClosing()
AbstractResultQuery.fetchLazy()
AbstractQuery.execute()
AbstractResultQuery.execute(ExecuteContext, ExecuteListener)
Tools.executeStatementAndGetFirstResultSet(ExecuteContext, int)
DefaultPreparedStatement.execute()
$Proxy579.execute()
OurConnectionMetricsDataSourceProxy$ConnectionMetricsInvocationHandler$StatementMetricsInvocationHandler.invoke(Object, Method, Object[])
OurConnectionMetricsDataSourceProxy$ConnectionMetricsInvocationHandler.executeMethod(Callable)
OurConnectionMetricsDataSourceProxy$ConnectionMetricsInvocationHandler$StatementMetricsInvocationHandler$$Lambda$6626+0x0000000803d43c48.764783219.call()
OurConnectionMetricsDataSourceProxy$ConnectionMetricsInvocationHandler$StatementMetricsInvocationHandler.lambda$invoke$0(Method, Object[])
Method.invoke(Object, Object[])
DelegatingMethodAccessorImpl.invoke(Object, Object[])
GeneratedMethodAccessor272.invoke(Object, Object[])
$Proxy579.execute()
OurQueryMetricsDataSourceProxy$ConnectionMetricsInvocationHandler$StatementMetricsInvocationHandler.invoke(Object, Method, Object[])
OurQueryMetricsDataSourceProxy$ConnectionMetricsInvocationHandler.executeMethod(Callable)
OurQueryMetricsDataSourceProxy$ConnectionMetricsInvocationHandler$StatementMetricsInvocationHandler$$Lambda$6627+0x0000000803d50000.1175461386.call()
OurQueryMetricsDataSourceProxy$ConnectionMetricsInvocationHandler$StatementMetricsInvocationHandler.lambda$invoke$0(Method, Object[])
Method.invoke(Object, Object[])
DelegatingMethodAccessorImpl.invoke(Object, Object[])
GeneratedMethodAccessor272.invoke(Object, Object[])
HikariProxyPreparedStatement.execute()
ProxyPreparedStatement.execute()
PgPreparedStatement.execute()
PgPreparedStatement.executeWithFlags(int)
PgStatement.execute(CachedQuery, ParameterList, int)
PgStatement.executeInternal(CachedQuery, ParameterList, int)
QueryExecutorImpl.execute(Query, ParameterList, ResultHandler, int, int, int, boolean)
QueryExecutorImpl.processResults(ResultHandler, int, boolean)
PGStream.receiveChar()
VisibleBufferedInputStream.read()
VisibleBufferedInputStream.ensureBytes(int)
VisibleBufferedInputStream.ensureBytes(int, boolean)
VisibleBufferedInputStream.readMore(int, boolean)
SSLSocketImpl$AppInputStream.read(byte[], int, int)
SSLSocketImpl.readApplicationRecord(ByteBuffer)
SSLSocketInputRecord.bytesInCompletePacket()
SSLSocketInputRecord.readHeader()
SSLSocketInputRecord.read(InputStream, byte[], int, int)
```

And for the Java Monitor Wait event:

```
TimerThread.run()
TimerThread.mainLoop()
Object.wait(long)
```

> I do not see how TimerThread code could result in "at 1-2 seconds past the minute mark"

That's what I expected from looking through the driver code. Thanks for the confirmation.

> SharedTimer would wait in Object.wait in case the application uses something like java.sql.Statement#setQueryTimeout

From what I've seen, our code only very rarely uses timeouts on queries, and mostly for queries that are run during manual administrative tasks. It could be that middlewares, frameworks, or libraries set timeouts, or expose timeouts with a different API, though. I'll have a closer look.

I'm okay closing the issue, as this looks like a dead end in my investigation. Thanks again for your support.