Hello,
For some time now, I have seen a timeout error in the postgres executor:
o.a.j.b.postgres.utils.PostgresExecutor - Time out executing Postgres query.
May need to check either jOOQ reactive issue or Postgres DB performance.
This was mainly happening in TMail and was reported here:
https://github.com/linagora/tmail-backend/issues/1599
I have now found a way to reproduce this reliably with the Docker image built
from the current James master (bf100353ac3c4fc76d9ecced7472528b43e1ca21).
When using opensearch as the search backend and triggering a full reindex with curl -XPOST
'http://<IP>:<port>/mailboxes?task=reIndex&messagesPerSecond=1', I observe the
following behavior:
2026-09-25T10:29:41.968Z [INFO ] o.a.j.webadmin.mdc.LoggingRequestFilter -
WebAdmin request received
2026-09-25T10:29:41.974Z [INFO ] o.a.m.tools.indexer.ReIndexerPerformer -
Starting a full reindex
2026-09-25T10:29:41.985Z [INFO ] o.a.j.webadmin.mdc.LoggingResponseFilter -
WebAdmin response received
2026-09-25T10:29:43.178Z [INFO ]
o.a.j.m.o.e.OpenSearchListeningMessageSearchIndex - Indexing mailbox
email-88f7e4e1-cb74-47fb-a4f6-3046afc29714 of user re-indexing on message 1
2026-09-25T10:29:44.120Z [INFO ]
o.a.j.m.o.e.OpenSearchListeningMessageSearchIndex - Indexing mailbox
email-88f7e4e1-cb74-47fb-a4f6-3046afc29714 of user re-indexing on message 2
2026-09-25T10:29:45.125Z [INFO ]
o.a.j.m.o.e.OpenSearchListeningMessageSearchIndex - Indexing mailbox
email-88f7e4e1-cb74-47fb-a4f6-3046afc29714 of user re-indexing on message 3
2026-09-25T10:29:46.128Z [INFO ]
o.a.j.m.o.e.OpenSearchListeningMessageSearchIndex - Indexing mailbox
email-88f7e4e1-cb74-47fb-a4f6-3046afc29714 of user re-indexing on message 4
2026-09-25T10:29:47.131Z [INFO ]
o.a.j.m.o.e.OpenSearchListeningMessageSearchIndex - Indexing mailbox
email-88f7e4e1-cb74-47fb-a4f6-3046afc29714 of user re-indexing on message 5
2026-09-25T10:29:48.135Z [INFO ]
o.a.j.m.o.e.OpenSearchListeningMessageSearchIndex - Indexing mailbox
email-88f7e4e1-cb74-47fb-a4f6-3046afc29714 of user re-indexing on message 6
2026-09-25T10:29:49.137Z [INFO ]
o.a.j.m.o.e.OpenSearchListeningMessageSearchIndex - Indexing mailbox
email-88f7e4e1-cb74-47fb-a4f6-3046afc29714 of user re-indexing on message 7
2026-09-25T10:29:50.147Z [INFO ]
o.a.j.m.o.e.OpenSearchListeningMessageSearchIndex - Indexing mailbox
email-88f7e4e1-cb74-47fb-a4f6-3046afc29714 of user re-indexing on message 8
2026-09-25T10:29:51.143Z [INFO ]
o.a.j.m.o.e.OpenSearchListeningMessageSearchIndex - Indexing mailbox
email-88f7e4e1-cb74-47fb-a4f6-3046afc29714 of user re-indexing on message 9
2026-09-25T10:29:52.052Z [ERROR] o.a.j.b.postgres.utils.PostgresExecutor - Time
out executing Postgres query. May need to check either jOOQ reactive issue or
Postgres DB performance.
java.util.concurrent.TimeoutException: Did not observe any item or terminal
signal within 10000ms in 'flatMapMany' (and no fallback has been configured)
at
reactor.core.publisher.FluxTimeout$TimeoutMainSubscriber.handleTimeout(FluxTimeout.java:296)
at
reactor.core.publisher.FluxTimeout$TimeoutMainSubscriber.doTimeout(FluxTimeout.java:281)
at
reactor.core.publisher.FluxTimeout$TimeoutTimeoutSubscriber.onNext(FluxTimeout.java:420)
at
reactor.core.publisher.FluxOnErrorReturn$ReturnSubscriber.onNext(FluxOnErrorReturn.java:162)
at
reactor.core.publisher.MonoDelay$MonoDelayRunnable.propagateDelay(MonoDelay.java:270)
at
reactor.core.publisher.MonoDelay$MonoDelayRunnable.run(MonoDelay.java:285)
at reactor.core.scheduler.SchedulerTask.call(SchedulerTask.java:68)
at reactor.core.scheduler.SchedulerTask.call(SchedulerTask.java:28)
at java.base/java.util.concurrent.FutureTask.run(Unknown Source)
at
java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown
Source)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown
Source)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown
Source)
at java.base/java.lang.Thread.run(Unknown Source)
2026-09-25T10:29:52.058Z [INFO ] o.a.m.tools.indexer.ReIndexerPerformer - Full
reindex finished
2026-09-25T10:29:52.059Z [ERROR] o.a.james.task.SerialTaskManagerWorker - Task
was partially performed. Check logs for more details. Taskid :
TaskId{value=9553e1df-9ad0-42d6-b90d-30c5882b8d17}
This error always happens 10 seconds after starting the reindex task.
Therefore, exactly 9 batches of the size specified with messagesPerSecond are
processed.
When indexing 2 messages per second, the indexer manages to index the first 18
messages, when indexing 5 messages per second, the first 45 messages are
indexed, and so on...
I don't know much about this part of the codebase and would be happy about help
to debug this.
Did somebody else ever see this error or can somebody else reproduce it?
Best regards,
Felix
---
Gesellschaft für interkulturelles
Zusammenleben gGmbH (GIZ)
Felix Auringer
IT
Reformationsplatz 2
13597 Berlin
Tel: 030/513 0100 00; Fax: 030/513 0100 09
www.giz.berlin; [email protected]
Amtsgericht Charlottenburg HRB 200872 B
Geschäftsführerin: Dr. Britta Marschke
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
