agora inbox for [email protected]
help / color / mirror / Atom feedRe: PgbackRest PointTIme Recovery : server unable to start back
13+ messages / 5 participants
[nested] [flat]
* Re: PgbackRest PointTIme Recovery : server unable to start back
@ 2024-07-26 05:15 Muhammad Ikram <[email protected]>
2024-07-26 06:33 ` Re: PgbackRest PointTIme Recovery : server unable to start back KK CHN <[email protected]>
0 siblings, 1 reply; 13+ messages in thread
From: Muhammad Ikram @ 2024-07-26 05:15 UTC (permalink / raw)
To: KK CHN <[email protected]>; +Cc: pgsql-general
Hi KK CHN
Could you check server logs ?
Your service trace suggests that it started server and then failure happened
ul 26 09:48:49 service01 systemd[1]: Started EDB Postgres Advanced Server
16.
Jul 26 09:48:50 service01 systemd[1]: edb-as-16.service: Main process
exited, code=exited, status=1/FAILURE
Regards,
Ikram
On Fri, Jul 26, 2024 at 10:04 AM KK CHN <[email protected]> wrote:
> List,
>
> Reference: https://pgbackrest.org/user-guide-rhel.html#pitr
> I am following the PTR on RHEL9 EPAS16.
> I am able to do a backup(Full, diff and incr) and restore from a full
> backup and restart of EPAS16 works fine.
>
> But when I do an incremental backup after doing the procedures
> mentioned in the PTR section of the above reference link and try
> restoring the EDB database from the INCR backup and then starting up the
> EPAS16 the server always results in dead state
>
> My repo server is another machine. If I do a full restore on the DB
> server ( sudo -u enterprisedb pgbackrest --stanza=Demo_Repo --delta
> restore) it works and the server starts without any issue.
> Restoring from Incremental backup tty output shows successful but edb
> service start results in failure.
>
> Any help is much appreciated.
>
> Krishane.
>
>
>
>
> STEPS followed:
>
> after dropping the table pg-primary *⇒* Drop the important table
> ([section]
> stopped the EDB server.
>
> $ sudo -u enterprisedb pgbackrest --stanza=Demo_Repo --delta
> --set=20240719-122703F_20240724-094727I --target-timeline=current
> --type=time "--target=2024-07-24 09:44:01.3255+05:30"
> --target-action=promote restore
> .....................................................
>
> 2024-07-26 09:48:06.343 P00 INFO: restore command end: completed
> successfully (1035ms)
>
>
> But
>
> [root@rservice01 ~]# sudo systemctl start edb-as-16.service
> [root@service01 ~]# sudo systemctl status edb-as-16.service
> × edb-as-16.service - EDB Postgres Advanced Server 16
> Loaded: loaded (/etc/systemd/system/edb-as-16.service; disabled;
> preset: disabled)
> * Active: failed* (Result: exit-code) since Fri 2024-07-26 09:48:50
> IST; 8s ago
> Duration: 242ms
> Process: 41903 ExecStartPre=/usr/edb/as16/bin/edb-as-16-check-db-dir
> ${PGDATA} (code=exited, status=0/SUCCESS)
> Process: 41908 ExecStart=/usr/edb/as16/bin/edb-postgres -D ${PGDATA}
> (code=exited, status=1/FAILURE)
> Main PID: 41908 (code=exited, status=1/FAILURE)
> CPU: 331ms
>
> Jul 26 09:48:48 service01 systemd[1]: Starting EDB Postgres Advanced
> Server 16...
> Jul 26 09:48:48 service01 edb-postgres[41908]: 2024-07-26 09:48:48 IST
> LOG: redirecting log output to logging collector process
> Jul 26 09:48:48 service01 edb-postgres[41908]: 2024-07-26 09:48:48 IST
> HINT: Future log output will appear in directory "log".
> Jul 26 09:48:49 service01 systemd[1]: Started EDB Postgres Advanced Server
> 16.
> Jul 26 09:48:50 service01 systemd[1]: edb-as-16.service: Main process
> exited, code=exited, status=1/FAILURE
> Jul 26 09:48:50 service01 systemd[1]: edb-as-16.service: Killing process
> 41909 (edb-postgres) with signal SIGKILL.
> Jul 26 09:48:50 service01 systemd[1]: edb-as-16.service: Failed with
> result 'exit-code'.
> [root@service01 ~]#
>
> why is it unable to perform a restore and recovery from an incr backup ?
>
>
>
>
>
>
>
> On The Repo Server
> [root@service02 ~]# sudo -u postgres pgbackrest --stanza=Demo_Repo info
> stanza: Demo_Repo
> status: ok
> cipher: aes-256-cbc
>
> db (current)
> wal archive min/max (16):
> 000000020000000000000021/0000000B0000000000000041
>
> full backup: 20240719-122703F
> timestamp start/stop: 2024-07-19 12:27:03+05:30 / 2024-07-19
> 12:27:06+05:30
> wal start/stop: 00000002000000000000002A /
> 00000002000000000000002A
> database size: 61.7MB, database backup size: 61.7MB
> repo1: backup size: 9.6MB
>
> incr backup: 20240719-122703F_20240719-123353I
> timestamp start/stop: 2024-07-19 12:33:53+05:30 / 2024-07-19
> 12:33:56+05:30
> wal start/stop: 00000002000000000000002C /
> 00000002000000000000002C
> database size: 61.7MB, database backup size: 6.4MB
> repo1: backup size: 6.2KB
> backup reference list: 20240719-122703F
>
> diff backup: 20240719-122703F_20240719-123408D
> timestamp start/stop: 2024-07-19 12:34:08+05:30 / 2024-07-19
> 12:34:10+05:30
> wal start/stop: 00000002000000000000002E /
> 00000002000000000000002E
> database size: 61.7MB, database backup size: 6.4MB
> repo1: backup size: 6.4KB
> backup reference list: 20240719-122703F
>
> incr backup: 20240719-122703F_20240723-110212I
> timestamp start/stop: 2024-07-23 11:02:12+05:30 / 2024-07-23
> 11:02:15+05:30
> wal start/stop: 000000070000000000000038 /
> 000000070000000000000038
> database size: 48MB, database backup size: 6.4MB
> repo1: backup size: 9.8KB
> backup reference list: 20240719-122703F,
> 20240719-122703F_20240719-123408D
>
> incr backup: 20240719-122703F_20240723-141818I
> timestamp start/stop: 2024-07-23 14:18:18+05:30 / 2024-07-23
> 14:18:22+05:30
> wal start/stop: 00000008000000000000003C /
> 00000008000000000000003C
> database size: 75.4MB, database backup size: 33.8MB
> repo1: backup size: 4.7MB
> backup reference list: 20240719-122703F,
> 20240719-122703F_20240719-123408D, 20240719-122703F_20240723-110212I
>
> incr backup: 20240719-122703F_20240724-094727I
> timestamp start/stop: 2024-07-24 09:47:27+05:30 / 2024-07-24
> 09:47:30+05:30
> wal start/stop: 00000009000000000000003D /
> 00000009000000000000003D
> database size: 62MB, database backup size: 11.5MB
> repo1: backup size: 72KB
> backup reference list: 20240719-122703F,
> 20240719-122703F_20240719-123408D, 20240719-122703F_20240723-110212I,
> 20240719-122703F_20240723-141818
>
>
>
>
--
Muhammad Ikram
^ permalink raw reply [nested|flat] 13+ messages in thread
* Re: PgbackRest PointTIme Recovery : server unable to start back
2024-07-26 05:15 Re: PgbackRest PointTIme Recovery : server unable to start back Muhammad Ikram <[email protected]>
@ 2024-07-26 06:33 ` KK CHN <[email protected]>
2024-07-26 06:57 ` Re: PgbackRest PointTIme Recovery : server unable to start back Muhammad Ikram <[email protected]>
0 siblings, 1 reply; 13+ messages in thread
From: KK CHN @ 2024-07-26 06:33 UTC (permalink / raw)
To: Muhammad Ikram <[email protected]>; +Cc: pgsql-general
here the log outputs....
When I ran
$sudo -u enterprisedb pgbackrest --stanza=Demo_Repo --delta
--set=20240719-122703F_20240724-094727I --target-timeline=current
--type=time "--target=2024-07-24 09:44:01.3255+05:30"
--target-action=promote restore
The Edb server log out put shows
...........................................................................
................................................................
2024-07-23 15:34:12 IST ERROR: syntax error at or near "selecct" at
character 1
2024-07-23 15:34:12 IST STATEMENT: selecct current_timestamp
2024-07-23 15:34:26 IST FATAL: database "enterprisedb" does not exist
2024-07-24 09:38:20 IST FATAL: database "enterprisedb" does not exist
2024-07-24 09:42:17 IST FATAL: database "test1" does not exist
2024-07-24 09:43:56 IST FATAL: database "enterprisedb" does not exist
2024-07-24 09:45:07 IST FATAL: database "enterprisedb" does not exist
2024-07-24 09:45:16 IST ERROR: relation "important_table" does not exist
at character 58
2024-07-24 09:45:16 IST STATEMENT: begin; drop table important_table;
commit; select * from important_table;
2024-07-24 09:46:00 IST LOG: checkpoint starting: time
2024-07-24 09:46:02 IST LOG: checkpoint complete: wrote 16 buffers (0.1%);
0 WAL file(s) added, 0 removed, 0 recycled; write=1.506 s, sync=0.001 s,
total=1.509 s; sync files=9, longest=0.001 s, average=0.001 s; distance=93
kB, estimate=171 kB; lsn=0/3C045768, redo lsn=0/3C045730
2024-07-24 09:47:27 IST LOG: checkpoint starting: immediate force wait
2024-07-24 09:47:27 IST LOG: checkpoint complete: wrote 2 buffers (0.0%);
0 WAL file(s) added, 0 removed, 1 recycled; write=0.001 s, sync=0.001 s,
total=0.003 s; sync files=1, longest=0.001 s, average=0.001 s;
distance=16106 kB, estimate=16106 kB; lsn=0/3D000060, redo lsn=0/3D000028
2024-07-24 09:47:27.788 P00 INFO: archive-push command begin 2.52.1:
[pg_wal/00000009000000000000003C] --exec-id=34036-c1d6de0b
--log-level-console=info --log-level-file=debug
--pg1-path=/var/lib/edb/as16/data --pg-version-force=16
--repo1-host=10.10.20.7 --repo1-host-user=postgres --stanza=Demo_Repo
2024-07-24 09:47:28.130 P00 INFO: pushed WAL file
'00000009000000000000003C' to the archive
2024-07-24 09:47:28.230 P00 INFO: archive-push command end: completed
successfully (444ms)
When I ran $ sudo systemctl start edb-as-16.service
4-07-26 11:32:56 IST LOG: starting PostgreSQL 16.3 (EnterpriseDB Advanced
Server 16.3.0) on x86_64-pc-linux-gnu, compiled by gcc (GCC) 11.4.1
20231218 (Red Hat 11.4.1-3), 64-bit
2024-07-26 11:32:56 IST LOG: listening on IPv4 address "0.0.0.0", port 5444
2024-07-26 11:32:56 IST LOG: listening on IPv6 address "::", port 5444
2024-07-26 11:32:56 IST LOG: listening on Unix socket "/tmp/.s.PGSQL.5444"
2024-07-26 11:32:56 IST LOG: database system was interrupted; last known
up at 2024-07-24 09:47:27 IST
2024-07-26 11:32:56 IST LOG: starting point-in-time recovery to 2024-07-24
09:44:01.3255+05:30
2024-07-26 11:32:56 IST LOG: starting backup recovery with redo LSN
0/3D000028, checkpoint LSN 0/3D000060, on timeline ID 9
2024-07-26 11:32:56.475 P00 INFO: archive-get command begin 2.52.1:
[00000009.history, pg_wal/RECOVERYHISTORY] --exec-id=43293-1d583a8e
--log-level-console=info --log-level-file=debug
--pg1-path=/var/lib/edb/as16/data --pg-version-force=16
--repo1-host=10.10.20.7 --repo1-host-user=postgres --stanza=Demo_Repo
2024-07-26 11:32:56.709 P00 INFO: found 00000009.history in the repo1:
16-1 archive
2024-07-26 11:32:56.809 P00 INFO: archive-get command end: completed
successfully (335ms)
2024-07-26 11:32:56 IST LOG: restored log file "00000009.history" from
archive
2024-07-26 11:32:56.816 P00 INFO: archive-get command begin 2.52.1:
[00000009000000000000003D, pg_wal/RECOVERYXLOG] --exec-id=43295-55c5d6f7
--log-level-console=info --log-level-file=debug
--pg1-path=/var/lib/edb/as16/data --pg-version-force=16
--repo1-host=10.10.20.7 --repo1-host-user=postgres --stanza=Demo_Repo
2024-07-26 11:32:56.999 P00 INFO: found 00000009000000000000003D in the
repo1: 16-1 archive
2024-07-26 11:32:57.099 P00 INFO: archive-get command end: completed
successfully (285ms)
2024-07-26 11:32:57 IST LOG: restored log file "00000009000000000000003D"
from archive
2024-07-26 11:32:57 IST LOG: redo starts at 0/3D000028
2024-07-26 11:32:57.114 P00 INFO: archive-get command begin 2.52.1:
[00000009000000000000003E, pg_wal/RECOVERYXLOG] --exec-id=43297-34867c05
--log-level-console=info --log-level-file=debug
--pg1-path=/var/lib/edb/as16/data --pg-version-force=16
--repo1-host=10.10.20.7 --repo1-host-user=postgres --stanza=Demo_Repo
2024-07-26 11:32:57.282 P00 INFO: found 00000009000000000000003E in the
repo1: 16-1 archive
2024-07-26 11:32:57.382 P00 INFO: archive-get command end: completed
successfully (270ms)
2024-07-26 11:32:57 IST LOG: restored log file "00000009000000000000003E"
from archive
2024-07-26 11:32:57.400 P00 INFO: archive-get command begin 2.52.1:
[00000009000000000000003F, pg_wal/RECOVERYXLOG] --exec-id=43299-e2db2e1b
--log-level-console=info --log-level-file=debug
--pg1-path=/var/lib/edb/as16/data --pg-version-force=16
--repo1-host=10.10.20.7 --repo1-host-user=postgres --stanza=Demo_Repo
2024-07-26 11:32:57.521 P00 INFO: unable to find 00000009000000000000003F
in the archive
2024-07-26 11:32:57.621 P00 INFO: archive-get command end: completed
successfully (222ms)
2024-07-26 11:32:57 IST LOG: completed backup recovery with redo LSN
0/3D000028 and end LSN 0/3D000100
2024-07-26 11:32:57 IST LOG: consistent recovery state reached at
0/3D000100
2024-07-26 11:32:57 IST LOG: database system is ready to accept read-only
connections
2024-07-26 11:32:57.632 P00 INFO: archive-get command begin 2.52.1:
[00000009000000000000003F, pg_wal/RECOVERYXLOG] --exec-id=43301-f613dae9
--log-level-console=info --log-level-file=debug
--pg1-path=/var/lib/edb/as16/data --pg-version-force=16
--repo1-host=10.10.20.7 --repo1-host-user=postgres --stanza=Demo_Repo
2024-07-26 11:32:57.761 P00 INFO: unable to find 00000009000000000000003F
in the archive
2024-07-26 11:32:57.861 P00 INFO: archive-get command end: completed
successfully (231ms)
2024-07-26 11:32:57 IST LOG: redo done at 0/3E000060 system usage: CPU:
user: 0.00 s, system: 0.00 s, elapsed: 0.75 s
2024-07-26 11:32:57 IST FATAL: recovery ended before configured recovery
target was reached
2024-07-26 11:32:57 IST LOG: startup process (PID 43292) exited with exit
code 1
ONLY inference I can make is
INFO unable to find 00000009000000000000003F in the archive ( This
means the EDB server (10.10.20.6 ) unable to push the archives to the
Repo server(10.10.20.7 ) ? Is that the reason for the recovery and
start backing of edb server fails ?
the pg_hba.conf entry in the EDB Server machine is as
host all all 127.0.0.1/32 ident
host all all 10.10.20.7/32 scram-sha-256
#host all all 10.10.20.7/32 trust
# IPv6 local connections:
host all all ::1/128 ident
#host all all 10.10.20.7/24 trust
# Allow replication connections from localhost, by a user with the
# replication privilege.
local replication all peer
host replication all 10.10.20.7/32
scram-sha-256
host replication all 127.0.0.1/32 ident
host replication all ::1/128 ident
Do I have to change anything in pg_hba.conf ?
my EDB Server conf as this
archive_mode = on
archive_command = 'pgbackrest --stanza=Demo_Repo archive-push %p'
log_filename = 'postgresql.log'
max_wal_senders = 5
wal_level = replica
Any help ?
Krishane
On Fri, Jul 26, 2024 at 10:45 AM Muhammad Ikram <[email protected]> wrote:
> Hi KK CHN
>
> Could you check server logs ?
> Your service trace suggests that it started server and then failure
> happened
>
> ul 26 09:48:49 service01 systemd[1]: Started EDB Postgres Advanced Server
> 16.
> Jul 26 09:48:50 service01 systemd[1]: edb-as-16.service: Main process
> exited, code=exited, status=1/FAILURE
>
>
>
> Regards,
> Ikram
>
>
> On Fri, Jul 26, 2024 at 10:04 AM KK CHN <[email protected]> wrote:
>
>> List,
>>
>> Reference: https://pgbackrest.org/user-guide-rhel.html#pitr
>> I am following the PTR on RHEL9 EPAS16.
>> I am able to do a backup(Full, diff and incr) and restore from a full
>> backup and restart of EPAS16 works fine.
>>
>> But when I do an incremental backup after doing the procedures
>> mentioned in the PTR section of the above reference link and try
>> restoring the EDB database from the INCR backup and then starting up the
>> EPAS16 the server always results in dead state
>>
>> My repo server is another machine. If I do a full restore on the DB
>> server ( sudo -u enterprisedb pgbackrest --stanza=Demo_Repo --delta
>> restore) it works and the server starts without any issue.
>> Restoring from Incremental backup tty output shows successful but edb
>> service start results in failure.
>>
>> Any help is much appreciated.
>>
>> Krishane.
>>
>>
>>
>>
>> STEPS followed:
>>
>> after dropping the table pg-primary *⇒* Drop the important table
>> ([section]
>> stopped the EDB server.
>>
>> $ sudo -u enterprisedb pgbackrest --stanza=Demo_Repo --delta
>> --set=20240719-122703F_20240724-094727I --target-timeline=current
>> --type=time "--target=2024-07-24 09:44:01.3255+05:30"
>> --target-action=promote restore
>> .....................................................
>>
>> 2024-07-26 09:48:06.343 P00 INFO: restore command end: completed
>> successfully (1035ms)
>>
>>
>> But
>>
>> [root@rservice01 ~]# sudo systemctl start edb-as-16.service
>> [root@service01 ~]# sudo systemctl status edb-as-16.service
>> × edb-as-16.service - EDB Postgres Advanced Server 16
>> Loaded: loaded (/etc/systemd/system/edb-as-16.service; disabled;
>> preset: disabled)
>> * Active: failed* (Result: exit-code) since Fri 2024-07-26 09:48:50
>> IST; 8s ago
>> Duration: 242ms
>> Process: 41903 ExecStartPre=/usr/edb/as16/bin/edb-as-16-check-db-dir
>> ${PGDATA} (code=exited, status=0/SUCCESS)
>> Process: 41908 ExecStart=/usr/edb/as16/bin/edb-postgres -D ${PGDATA}
>> (code=exited, status=1/FAILURE)
>> Main PID: 41908 (code=exited, status=1/FAILURE)
>> CPU: 331ms
>>
>> Jul 26 09:48:48 service01 systemd[1]: Starting EDB Postgres Advanced
>> Server 16...
>> Jul 26 09:48:48 service01 edb-postgres[41908]: 2024-07-26 09:48:48 IST
>> LOG: redirecting log output to logging collector process
>> Jul 26 09:48:48 service01 edb-postgres[41908]: 2024-07-26 09:48:48 IST
>> HINT: Future log output will appear in directory "log".
>> Jul 26 09:48:49 service01 systemd[1]: Started EDB Postgres Advanced
>> Server 16.
>> Jul 26 09:48:50 service01 systemd[1]: edb-as-16.service: Main process
>> exited, code=exited, status=1/FAILURE
>> Jul 26 09:48:50 service01 systemd[1]: edb-as-16.service: Killing process
>> 41909 (edb-postgres) with signal SIGKILL.
>> Jul 26 09:48:50 service01 systemd[1]: edb-as-16.service: Failed with
>> result 'exit-code'.
>> [root@service01 ~]#
>>
>> why is it unable to perform a restore and recovery from an incr backup ?
>>
>>
>>
>>
>>
>>
>>
>> On The Repo Server
>> [root@service02 ~]# sudo -u postgres pgbackrest --stanza=Demo_Repo info
>> stanza: Demo_Repo
>> status: ok
>> cipher: aes-256-cbc
>>
>> db (current)
>> wal archive min/max (16):
>> 000000020000000000000021/0000000B0000000000000041
>>
>> full backup: 20240719-122703F
>> timestamp start/stop: 2024-07-19 12:27:03+05:30 / 2024-07-19
>> 12:27:06+05:30
>> wal start/stop: 00000002000000000000002A /
>> 00000002000000000000002A
>> database size: 61.7MB, database backup size: 61.7MB
>> repo1: backup size: 9.6MB
>>
>> incr backup: 20240719-122703F_20240719-123353I
>> timestamp start/stop: 2024-07-19 12:33:53+05:30 / 2024-07-19
>> 12:33:56+05:30
>> wal start/stop: 00000002000000000000002C /
>> 00000002000000000000002C
>> database size: 61.7MB, database backup size: 6.4MB
>> repo1: backup size: 6.2KB
>> backup reference list: 20240719-122703F
>>
>> diff backup: 20240719-122703F_20240719-123408D
>> timestamp start/stop: 2024-07-19 12:34:08+05:30 / 2024-07-19
>> 12:34:10+05:30
>> wal start/stop: 00000002000000000000002E /
>> 00000002000000000000002E
>> database size: 61.7MB, database backup size: 6.4MB
>> repo1: backup size: 6.4KB
>> backup reference list: 20240719-122703F
>>
>> incr backup: 20240719-122703F_20240723-110212I
>> timestamp start/stop: 2024-07-23 11:02:12+05:30 / 2024-07-23
>> 11:02:15+05:30
>> wal start/stop: 000000070000000000000038 /
>> 000000070000000000000038
>> database size: 48MB, database backup size: 6.4MB
>> repo1: backup size: 9.8KB
>> backup reference list: 20240719-122703F,
>> 20240719-122703F_20240719-123408D
>>
>> incr backup: 20240719-122703F_20240723-141818I
>> timestamp start/stop: 2024-07-23 14:18:18+05:30 / 2024-07-23
>> 14:18:22+05:30
>> wal start/stop: 00000008000000000000003C /
>> 00000008000000000000003C
>> database size: 75.4MB, database backup size: 33.8MB
>> repo1: backup size: 4.7MB
>> backup reference list: 20240719-122703F,
>> 20240719-122703F_20240719-123408D, 20240719-122703F_20240723-110212I
>>
>> incr backup: 20240719-122703F_20240724-094727I
>> timestamp start/stop: 2024-07-24 09:47:27+05:30 / 2024-07-24
>> 09:47:30+05:30
>> wal start/stop: 00000009000000000000003D /
>> 00000009000000000000003D
>> database size: 62MB, database backup size: 11.5MB
>> repo1: backup size: 72KB
>> backup reference list: 20240719-122703F,
>> 20240719-122703F_20240719-123408D, 20240719-122703F_20240723-110212I,
>> 20240719-122703F_20240723-141818
>>
>>
>>
>>
>
> --
> Muhammad Ikram
>
>
^ permalink raw reply [nested|flat] 13+ messages in thread
* Re: PgbackRest PointTIme Recovery : server unable to start back
2024-07-26 05:15 Re: PgbackRest PointTIme Recovery : server unable to start back Muhammad Ikram <[email protected]>
2024-07-26 06:33 ` Re: PgbackRest PointTIme Recovery : server unable to start back KK CHN <[email protected]>
@ 2024-07-26 06:57 ` Muhammad Ikram <[email protected]>
0 siblings, 0 replies; 13+ messages in thread
From: Muhammad Ikram @ 2024-07-26 06:57 UTC (permalink / raw)
To: KK CHN <[email protected]>; +Cc: pgsql-general
I don't think it has anything to do with the pg_hba.conf file. Archive
seems missing. I will suggest taking a full backup, as you have mentioned
that you are able to take full backup.
Regards,
Ikram
On Fri, Jul 26, 2024 at 11:24 AM KK CHN <[email protected]> wrote:
> here the log outputs....
>
> When I ran
>
> $sudo -u enterprisedb pgbackrest --stanza=Demo_Repo --delta
> --set=20240719-122703F_20240724-094727I --target-timeline=current
> --type=time "--target=2024-07-24 09:44:01.3255+05:30"
> --target-action=promote restore
>
>
>
> The Edb server log out put shows
> ...........................................................................
> ................................................................
> 2024-07-23 15:34:12 IST ERROR: syntax error at or near "selecct" at
> character 1
> 2024-07-23 15:34:12 IST STATEMENT: selecct current_timestamp
> 2024-07-23 15:34:26 IST FATAL: database "enterprisedb" does not exist
> 2024-07-24 09:38:20 IST FATAL: database "enterprisedb" does not exist
> 2024-07-24 09:42:17 IST FATAL: database "test1" does not exist
> 2024-07-24 09:43:56 IST FATAL: database "enterprisedb" does not exist
> 2024-07-24 09:45:07 IST FATAL: database "enterprisedb" does not exist
> 2024-07-24 09:45:16 IST ERROR: relation "important_table" does not exist
> at character 58
> 2024-07-24 09:45:16 IST STATEMENT: begin; drop table important_table;
> commit; select * from important_table;
> 2024-07-24 09:46:00 IST LOG: checkpoint starting: time
> 2024-07-24 09:46:02 IST LOG: checkpoint complete: wrote 16 buffers
> (0.1%); 0 WAL file(s) added, 0 removed, 0 recycled; write=1.506 s,
> sync=0.001 s, total=1.509 s; sync files=9, longest=0.001 s, average=0.001
> s; distance=93 kB, estimate=171 kB; lsn=0/3C045768, redo lsn=0/3C045730
> 2024-07-24 09:47:27 IST LOG: checkpoint starting: immediate force wait
> 2024-07-24 09:47:27 IST LOG: checkpoint complete: wrote 2 buffers (0.0%);
> 0 WAL file(s) added, 0 removed, 1 recycled; write=0.001 s, sync=0.001 s,
> total=0.003 s; sync files=1, longest=0.001 s, average=0.001 s;
> distance=16106 kB, estimate=16106 kB; lsn=0/3D000060, redo lsn=0/3D000028
> 2024-07-24 09:47:27.788 P00 INFO: archive-push command begin 2.52.1:
> [pg_wal/00000009000000000000003C] --exec-id=34036-c1d6de0b
> --log-level-console=info --log-level-file=debug
> --pg1-path=/var/lib/edb/as16/data --pg-version-force=16
> --repo1-host=10.10.20.7 --repo1-host-user=postgres --stanza=Demo_Repo
> 2024-07-24 09:47:28.130 P00 INFO: pushed WAL file
> '00000009000000000000003C' to the archive
> 2024-07-24 09:47:28.230 P00 INFO: archive-push command end: completed
> successfully (444ms)
>
>
>
> When I ran $ sudo systemctl start edb-as-16.service
>
> 4-07-26 11:32:56 IST LOG: starting PostgreSQL 16.3 (EnterpriseDB Advanced
> Server 16.3.0) on x86_64-pc-linux-gnu, compiled by gcc (GCC) 11.4.1
> 20231218 (Red Hat 11.4.1-3), 64-bit
> 2024-07-26 11:32:56 IST LOG: listening on IPv4 address "0.0.0.0", port
> 5444
> 2024-07-26 11:32:56 IST LOG: listening on IPv6 address "::", port 5444
> 2024-07-26 11:32:56 IST LOG: listening on Unix socket "/tmp/.s.PGSQL.5444"
> 2024-07-26 11:32:56 IST LOG: database system was interrupted; last known
> up at 2024-07-24 09:47:27 IST
> 2024-07-26 11:32:56 IST LOG: starting point-in-time recovery to
> 2024-07-24 09:44:01.3255+05:30
> 2024-07-26 11:32:56 IST LOG: starting backup recovery with redo LSN
> 0/3D000028, checkpoint LSN 0/3D000060, on timeline ID 9
> 2024-07-26 11:32:56.475 P00 INFO: archive-get command begin 2.52.1:
> [00000009.history, pg_wal/RECOVERYHISTORY] --exec-id=43293-1d583a8e
> --log-level-console=info --log-level-file=debug
> --pg1-path=/var/lib/edb/as16/data --pg-version-force=16
> --repo1-host=10.10.20.7 --repo1-host-user=postgres --stanza=Demo_Repo
> 2024-07-26 11:32:56.709 P00 INFO: found 00000009.history in the repo1:
> 16-1 archive
> 2024-07-26 11:32:56.809 P00 INFO: archive-get command end: completed
> successfully (335ms)
> 2024-07-26 11:32:56 IST LOG: restored log file "00000009.history" from
> archive
> 2024-07-26 11:32:56.816 P00 INFO: archive-get command begin 2.52.1:
> [00000009000000000000003D, pg_wal/RECOVERYXLOG] --exec-id=43295-55c5d6f7
> --log-level-console=info --log-level-file=debug
> --pg1-path=/var/lib/edb/as16/data --pg-version-force=16
> --repo1-host=10.10.20.7 --repo1-host-user=postgres --stanza=Demo_Repo
> 2024-07-26 11:32:56.999 P00 INFO: found 00000009000000000000003D in the
> repo1: 16-1 archive
> 2024-07-26 11:32:57.099 P00 INFO: archive-get command end: completed
> successfully (285ms)
> 2024-07-26 11:32:57 IST LOG: restored log file "00000009000000000000003D"
> from archive
> 2024-07-26 11:32:57 IST LOG: redo starts at 0/3D000028
> 2024-07-26 11:32:57.114 P00 INFO: archive-get command begin 2.52.1:
> [00000009000000000000003E, pg_wal/RECOVERYXLOG] --exec-id=43297-34867c05
> --log-level-console=info --log-level-file=debug
> --pg1-path=/var/lib/edb/as16/data --pg-version-force=16
> --repo1-host=10.10.20.7 --repo1-host-user=postgres --stanza=Demo_Repo
> 2024-07-26 11:32:57.282 P00 INFO: found 00000009000000000000003E in the
> repo1: 16-1 archive
> 2024-07-26 11:32:57.382 P00 INFO: archive-get command end: completed
> successfully (270ms)
> 2024-07-26 11:32:57 IST LOG: restored log file "00000009000000000000003E"
> from archive
> 2024-07-26 11:32:57.400 P00 INFO: archive-get command begin 2.52.1:
> [00000009000000000000003F, pg_wal/RECOVERYXLOG] --exec-id=43299-e2db2e1b
> --log-level-console=info --log-level-file=debug
> --pg1-path=/var/lib/edb/as16/data --pg-version-force=16
> --repo1-host=10.10.20.7 --repo1-host-user=postgres --stanza=Demo_Repo
> 2024-07-26 11:32:57.521 P00 INFO: unable to find
> 00000009000000000000003F in the archive
> 2024-07-26 11:32:57.621 P00 INFO: archive-get command end: completed
> successfully (222ms)
> 2024-07-26 11:32:57 IST LOG: completed backup recovery with redo LSN
> 0/3D000028 and end LSN 0/3D000100
> 2024-07-26 11:32:57 IST LOG: consistent recovery state reached at
> 0/3D000100
> 2024-07-26 11:32:57 IST LOG: database system is ready to accept read-only
> connections
> 2024-07-26 11:32:57.632 P00 INFO: archive-get command begin 2.52.1:
> [00000009000000000000003F, pg_wal/RECOVERYXLOG] --exec-id=43301-f613dae9
> --log-level-console=info --log-level-file=debug
> --pg1-path=/var/lib/edb/as16/data --pg-version-force=16
> --repo1-host=10.10.20.7 --repo1-host-user=postgres --stanza=Demo_Repo
> 2024-07-26 11:32:57.761 P00 INFO: unable to find
> 00000009000000000000003F in the archive
> 2024-07-26 11:32:57.861 P00 INFO: archive-get command end: completed
> successfully (231ms)
> 2024-07-26 11:32:57 IST LOG: redo done at 0/3E000060 system usage: CPU:
> user: 0.00 s, system: 0.00 s, elapsed: 0.75 s
> 2024-07-26 11:32:57 IST FATAL: recovery ended before configured recovery
> target was reached
> 2024-07-26 11:32:57 IST LOG: startup process (PID 43292) exited with exit
> code 1
>
>
> ONLY inference I can make is
>
> INFO unable to find 00000009000000000000003F in the archive ( This
> means the EDB server (10.10.20.6 ) unable to push the archives to the
> Repo server(10.10.20.7 ) ? Is that the reason for the recovery and
> start backing of edb server fails ?
>
>
> the pg_hba.conf entry in the EDB Server machine is as
>
> host all all 127.0.0.1/32 ident
> host all all 10.10.20.7/32
> scram-sha-256
> #host all all 10.10.20.7/32 trust
> # IPv6 local connections:
> host all all ::1/128 ident
> #host all all 10.10.20.7/24 trust
>
> # Allow replication connections from localhost, by a user with the
> # replication privilege.
> local replication all peer
> host replication all 10.10.20.7/32
> scram-sha-256
> host replication all 127.0.0.1/32 ident
> host replication all ::1/128 ident
>
>
> Do I have to change anything in pg_hba.conf ?
>
>
> my EDB Server conf as this
>
> archive_mode = on
> archive_command = 'pgbackrest --stanza=Demo_Repo archive-push %p'
> log_filename = 'postgresql.log'
> max_wal_senders = 5
> wal_level = replica
>
>
> Any help ?
>
> Krishane
>
>
>
>
> On Fri, Jul 26, 2024 at 10:45 AM Muhammad Ikram <[email protected]> wrote:
>
>> Hi KK CHN
>>
>> Could you check server logs ?
>> Your service trace suggests that it started server and then failure
>> happened
>>
>> ul 26 09:48:49 service01 systemd[1]: Started EDB Postgres Advanced Server
>> 16.
>> Jul 26 09:48:50 service01 systemd[1]: edb-as-16.service: Main process
>> exited, code=exited, status=1/FAILURE
>>
>>
>>
>> Regards,
>> Ikram
>>
>>
>> On Fri, Jul 26, 2024 at 10:04 AM KK CHN <[email protected]> wrote:
>>
>>> List,
>>>
>>> Reference: https://pgbackrest.org/user-guide-rhel.html#pitr
>>> I am following the PTR on RHEL9 EPAS16.
>>> I am able to do a backup(Full, diff and incr) and restore from a
>>> full backup and restart of EPAS16 works fine.
>>>
>>> But when I do an incremental backup after doing the procedures
>>> mentioned in the PTR section of the above reference link and try
>>> restoring the EDB database from the INCR backup and then starting up the
>>> EPAS16 the server always results in dead state
>>>
>>> My repo server is another machine. If I do a full restore on the
>>> DB server ( sudo -u enterprisedb pgbackrest --stanza=Demo_Repo --delta
>>> restore) it works and the server starts without any issue.
>>> Restoring from Incremental backup tty output shows successful but edb
>>> service start results in failure.
>>>
>>> Any help is much appreciated.
>>>
>>> Krishane.
>>>
>>>
>>>
>>>
>>> STEPS followed:
>>>
>>> after dropping the table pg-primary *⇒* Drop the important table
>>> ([section]
>>> stopped the EDB server.
>>>
>>> $ sudo -u enterprisedb pgbackrest --stanza=Demo_Repo --delta
>>> --set=20240719-122703F_20240724-094727I --target-timeline=current
>>> --type=time "--target=2024-07-24 09:44:01.3255+05:30"
>>> --target-action=promote restore
>>> .....................................................
>>>
>>> 2024-07-26 09:48:06.343 P00 INFO: restore command end: completed
>>> successfully (1035ms)
>>>
>>>
>>> But
>>>
>>> [root@rservice01 ~]# sudo systemctl start edb-as-16.service
>>> [root@service01 ~]# sudo systemctl status edb-as-16.service
>>> × edb-as-16.service - EDB Postgres Advanced Server 16
>>> Loaded: loaded (/etc/systemd/system/edb-as-16.service; disabled;
>>> preset: disabled)
>>> * Active: failed* (Result: exit-code) since Fri 2024-07-26 09:48:50
>>> IST; 8s ago
>>> Duration: 242ms
>>> Process: 41903 ExecStartPre=/usr/edb/as16/bin/edb-as-16-check-db-dir
>>> ${PGDATA} (code=exited, status=0/SUCCESS)
>>> Process: 41908 ExecStart=/usr/edb/as16/bin/edb-postgres -D ${PGDATA}
>>> (code=exited, status=1/FAILURE)
>>> Main PID: 41908 (code=exited, status=1/FAILURE)
>>> CPU: 331ms
>>>
>>> Jul 26 09:48:48 service01 systemd[1]: Starting EDB Postgres Advanced
>>> Server 16...
>>> Jul 26 09:48:48 service01 edb-postgres[41908]: 2024-07-26 09:48:48 IST
>>> LOG: redirecting log output to logging collector process
>>> Jul 26 09:48:48 service01 edb-postgres[41908]: 2024-07-26 09:48:48 IST
>>> HINT: Future log output will appear in directory "log".
>>> Jul 26 09:48:49 service01 systemd[1]: Started EDB Postgres Advanced
>>> Server 16.
>>> Jul 26 09:48:50 service01 systemd[1]: edb-as-16.service: Main process
>>> exited, code=exited, status=1/FAILURE
>>> Jul 26 09:48:50 service01 systemd[1]: edb-as-16.service: Killing process
>>> 41909 (edb-postgres) with signal SIGKILL.
>>> Jul 26 09:48:50 service01 systemd[1]: edb-as-16.service: Failed with
>>> result 'exit-code'.
>>> [root@service01 ~]#
>>>
>>> why is it unable to perform a restore and recovery from an incr backup
>>> ?
>>>
>>>
>>>
>>>
>>>
>>>
>>>
>>> On The Repo Server
>>> [root@service02 ~]# sudo -u postgres pgbackrest --stanza=Demo_Repo info
>>> stanza: Demo_Repo
>>> status: ok
>>> cipher: aes-256-cbc
>>>
>>> db (current)
>>> wal archive min/max (16):
>>> 000000020000000000000021/0000000B0000000000000041
>>>
>>> full backup: 20240719-122703F
>>> timestamp start/stop: 2024-07-19 12:27:03+05:30 / 2024-07-19
>>> 12:27:06+05:30
>>> wal start/stop: 00000002000000000000002A /
>>> 00000002000000000000002A
>>> database size: 61.7MB, database backup size: 61.7MB
>>> repo1: backup size: 9.6MB
>>>
>>> incr backup: 20240719-122703F_20240719-123353I
>>> timestamp start/stop: 2024-07-19 12:33:53+05:30 / 2024-07-19
>>> 12:33:56+05:30
>>> wal start/stop: 00000002000000000000002C /
>>> 00000002000000000000002C
>>> database size: 61.7MB, database backup size: 6.4MB
>>> repo1: backup size: 6.2KB
>>> backup reference list: 20240719-122703F
>>>
>>> diff backup: 20240719-122703F_20240719-123408D
>>> timestamp start/stop: 2024-07-19 12:34:08+05:30 / 2024-07-19
>>> 12:34:10+05:30
>>> wal start/stop: 00000002000000000000002E /
>>> 00000002000000000000002E
>>> database size: 61.7MB, database backup size: 6.4MB
>>> repo1: backup size: 6.4KB
>>> backup reference list: 20240719-122703F
>>>
>>> incr backup: 20240719-122703F_20240723-110212I
>>> timestamp start/stop: 2024-07-23 11:02:12+05:30 / 2024-07-23
>>> 11:02:15+05:30
>>> wal start/stop: 000000070000000000000038 /
>>> 000000070000000000000038
>>> database size: 48MB, database backup size: 6.4MB
>>> repo1: backup size: 9.8KB
>>> backup reference list: 20240719-122703F,
>>> 20240719-122703F_20240719-123408D
>>>
>>> incr backup: 20240719-122703F_20240723-141818I
>>> timestamp start/stop: 2024-07-23 14:18:18+05:30 / 2024-07-23
>>> 14:18:22+05:30
>>> wal start/stop: 00000008000000000000003C /
>>> 00000008000000000000003C
>>> database size: 75.4MB, database backup size: 33.8MB
>>> repo1: backup size: 4.7MB
>>> backup reference list: 20240719-122703F,
>>> 20240719-122703F_20240719-123408D, 20240719-122703F_20240723-110212I
>>>
>>> incr backup: 20240719-122703F_20240724-094727I
>>> timestamp start/stop: 2024-07-24 09:47:27+05:30 / 2024-07-24
>>> 09:47:30+05:30
>>> wal start/stop: 00000009000000000000003D /
>>> 00000009000000000000003D
>>> database size: 62MB, database backup size: 11.5MB
>>> repo1: backup size: 72KB
>>> backup reference list: 20240719-122703F,
>>> 20240719-122703F_20240719-123408D, 20240719-122703F_20240723-110212I,
>>> 20240719-122703F_20240723-141818
>>>
>>>
>>>
>>>
>>
>> --
>> Muhammad Ikram
>>
>>
--
Muhammad Ikram
^ permalink raw reply [nested|flat] 13+ messages in thread
* PostgreSQL 15-->18 slowdown?
@ 2026-06-26 17:58 Israel Brewster <[email protected]>
2026-06-26 18:14 ` Re: PostgreSQL 15-->18 slowdown? Adrian Klaver <[email protected]>
2026-06-26 18:16 ` Re: PostgreSQL 15-->18 slowdown? Israel Brewster <[email protected]>
2026-06-26 19:35 ` Re: PostgreSQL 15-->18 slowdown? Israel Brewster <[email protected]>
0 siblings, 3 replies; 13+ messages in thread
From: Israel Brewster @ 2026-06-26 17:58 UTC (permalink / raw)
To: PostgreSQL General <[email protected]>
In postgreSQL 15, I had the below query that worked quickly. Now, I make no claims that the query is the best possible, or even a good query, but it DID work, and it did so quickly enough to be un-noticable when running.
Then I upgrade to PostgreSQL 18 - and now the query never completes (as in, I get a command timeout after at least half an hour before I get a result). Looking at the EXPLAIN (https://explain.depesz.com/s/llAQ) makes it pretty obvious why: we have a sequence scan on a large table inside a nested loop - and that sequence scan is apparently not short circuiting.
I tried the obvious: REINDEX database and VACUUM ANALYZE, but neither helped. I have my default_statistics_target set to 500 at the moment.
Then I tried SET enable_seqscan = off; Lo and behold, the query ran in only 123.888 ms (fun number :-D ) - https://explain.depesz.com/s/K2K9
What did I do wrong here? Thanks!
The query in question:
SELECT
stations.id,
stations.name as name,
latitude::float as lat,
longitude::float as lon,
elevation::float alt,
type,
coalesce(sites.name, 'Unknown') as site,
sites.id as siteid,
coalesce((SELECT true
FROM tilt_data
INNER JOIN tilt_orientation
ON tilt_data.station=tilt_orientation.station
WHERE tilt_data.station=stations.id
LIMIT 1),
false) as has_tilt,
array_to_json(volcano) as stationvolcs,
coalesce(
(SELECT array_agg(s.volcano_name ORDER BY t.ord)
FROM volcano s
JOIN unnest( volcano ) WITH ORDINALITY t(id,ord)
ON (t.id=s.volcano_id)
), '{}' ) volcnames
FROM stations
LEFT JOIN sites ON stations.siteref=sites.id
ORDER BY site, name
---
Israel Brewster
Software Engineer
Alaska Volcano Observatory
Geophysical Institute - UAF
2156 Koyukuk Drive
Fairbanks AK 99775-7320
Work: 907-474-5172
cell: 907-328-9145
^ permalink raw reply [nested|flat] 13+ messages in thread
* Re: PostgreSQL 15-->18 slowdown?
2026-06-26 17:58 PostgreSQL 15-->18 slowdown? Israel Brewster <[email protected]>
@ 2026-06-26 18:14 ` Adrian Klaver <[email protected]>
2026-06-26 18:16 ` Re: PostgreSQL 15-->18 slowdown? Adrian Klaver <[email protected]>
2026-06-26 18:19 ` Re: PostgreSQL 15-->18 slowdown? Israel Brewster <[email protected]>
2 siblings, 2 replies; 13+ messages in thread
From: Adrian Klaver @ 2026-06-26 18:14 UTC (permalink / raw)
To: Israel Brewster <[email protected]>; PostgreSQL General <[email protected]>
On 6/26/26 10:58 AM, Israel Brewster wrote:
> In postgreSQL 15, I had the below query that worked quickly. Now, I make
> no claims that the query is the best possible, or even a good query, but
> it DID work, and it did so quickly enough to be un-noticable when running.
>
> Then I upgrade to PostgreSQL 18 - and now the query never completes (as
> in, I get a command timeout after at least half an hour before I get a
> result). Looking at the EXPLAIN (https://explain.depesz.com/s/llAQ
> <https://explain.depesz.com/s/llAQ>) makes it pretty obvious why: we
> have a sequence scan on a large table inside a nested loop - and that
> sequence scan is apparently not short circuiting.
The link provided shows no times or rows, did you pick the correct one?
>
> I tried the obvious: REINDEX database and VACUUM ANALYZE, but neither
> helped. I have my default_statistics_target set to 500 at the moment.
>
> Then I tried SET enable_seqscan = off; Lo and behold, the query ran in
> only 123.888 ms (fun number :-D ) - https://explain.depesz.com/s/K2K9
> <https://explain.depesz.com/s/K2K9;
This one does not show the actual query.
> ---
> Israel Brewster
> Software Engineer
> Alaska Volcano Observatory
> Geophysical Institute - UAF
> 2156 Koyukuk Drive
> Fairbanks AK 99775-7320
> Work: 907-474-5172
> cell: 907-328-9145
>
^ permalink raw reply [nested|flat] 13+ messages in thread
* Re: PostgreSQL 15-->18 slowdown?
2026-06-26 17:58 PostgreSQL 15-->18 slowdown? Israel Brewster <[email protected]>
2026-06-26 18:14 ` Re: PostgreSQL 15-->18 slowdown? Adrian Klaver <[email protected]>
@ 2026-06-26 18:16 ` Adrian Klaver <[email protected]>
1 sibling, 0 replies; 13+ messages in thread
From: Adrian Klaver @ 2026-06-26 18:16 UTC (permalink / raw)
To: Israel Brewster <[email protected]>; PostgreSQL General <[email protected]>
On 6/26/26 11:14 AM, Adrian Klaver wrote:
>
>
> On 6/26/26 10:58 AM, Israel Brewster wrote:
>> In postgreSQL 15, I had the below query that worked quickly. Now, I
>> make no claims that the query is the best possible, or even a good
>> query, but it DID work, and it did so quickly enough to be un-
>> noticable when running.
>>
>> Then I upgrade to PostgreSQL 18 - and now the query never completes
>> (as in, I get a command timeout after at least half an hour before I
>> get a result). Looking at the EXPLAIN (https://explain.depesz.com/s/
>> llAQ <https://explain.depesz.com/s/llAQ>) makes it pretty obvious why:
>> we have a sequence scan on a large table inside a nested loop - and
>> that sequence scan is apparently not short circuiting.
>
> The link provided shows no times or rows, did you pick the correct one?
Yes you did: "I get a command timeout after at least half an hour"
Was not thinking.
>>
>> I tried the obvious: REINDEX database and VACUUM ANALYZE, but neither
>> helped. I have my default_statistics_target set to 500 at the moment.
>>
>> Then I tried SET enable_seqscan = off; Lo and behold, the query ran in
>> only 123.888 ms (fun number :-D ) - https://explain.depesz.com/s/K2K9
>> <https://explain.depesz.com/s/K2K9;
>
> This one does not show the actual query.
>
>
>> ---
>> Israel Brewster
>> Software Engineer
>> Alaska Volcano Observatory
>> Geophysical Institute - UAF
>> 2156 Koyukuk Drive
>> Fairbanks AK 99775-7320
>> Work: 907-474-5172
>> cell: 907-328-9145
>>
>
>
>
^ permalink raw reply [nested|flat] 13+ messages in thread
* Re: PostgreSQL 15-->18 slowdown?
2026-06-26 17:58 PostgreSQL 15-->18 slowdown? Israel Brewster <[email protected]>
2026-06-26 18:14 ` Re: PostgreSQL 15-->18 slowdown? Adrian Klaver <[email protected]>
@ 2026-06-26 18:19 ` Israel Brewster <[email protected]>
2026-06-26 18:40 ` Re: PostgreSQL 15-->18 slowdown? Adrian Klaver <[email protected]>
1 sibling, 1 reply; 13+ messages in thread
From: Israel Brewster @ 2026-06-26 18:19 UTC (permalink / raw)
To: Adrian Klaver <[email protected]>; +Cc: PostgreSQL General <[email protected]>
On Jun 26, 2026, at 10:14 AM, Adrian Klaver <[email protected]> wrote:
>
>
>
> On 6/26/26 10:58 AM, Israel Brewster wrote:
>> In postgreSQL 15, I had the below query that worked quickly. Now, I make no claims that the query is the best possible, or even a good query, but it DID work, and it did so quickly enough to be un-noticable when running.
>> Then I upgrade to PostgreSQL 18 - and now the query never completes (as in, I get a command timeout after at least half an hour before I get a result). Looking at the EXPLAIN (https://explain.depesz.com/s/llAQ <https://explain.depesz.com/s/llAQ;) makes it pretty obvious why: we have a sequence scan on a large table inside a nested loop - and that sequence scan is apparently not short circuiting.
>
> The link provided shows no times or rows, did you pick the correct one?
>> I tried the obvious: REINDEX database and VACUUM ANALYZE, but neither helped. I have my default_statistics_target set to 500 at the moment.
>> Then I tried SET enable_seqscan = off; Lo and behold, the query ran in only 123.888 ms (fun number :-D ) - https://explain.depesz.com/s/K2K9 <https://explain.depesz.com/s/K2K9;
>
> This one does not show the actual query.
Right, sorry. It’s the same query as in the first one though. Only difference is sequence scan off.
---
Israel Brewster
Software Engineer
Alaska Volcano Observatory
Geophysical Institute - UAF
2156 Koyukuk Drive
Fairbanks AK 99775-7320
Work: 907-474-5172
cell: 907-328-9145
>
>
>> ---
>> Israel Brewster
>> Software Engineer
>> Alaska Volcano Observatory
>> Geophysical Institute - UAF
>> 2156 Koyukuk Drive
>> Fairbanks AK 99775-7320
>> Work: 907-474-5172
>> cell: 907-328-9145
>
^ permalink raw reply [nested|flat] 13+ messages in thread
* Re: PostgreSQL 15-->18 slowdown?
2026-06-26 17:58 PostgreSQL 15-->18 slowdown? Israel Brewster <[email protected]>
2026-06-26 18:14 ` Re: PostgreSQL 15-->18 slowdown? Adrian Klaver <[email protected]>
2026-06-26 18:19 ` Re: PostgreSQL 15-->18 slowdown? Israel Brewster <[email protected]>
@ 2026-06-26 18:40 ` Adrian Klaver <[email protected]>
2026-06-26 18:55 ` Re: PostgreSQL 15-->18 slowdown? Israel Brewster <[email protected]>
0 siblings, 1 reply; 13+ messages in thread
From: Adrian Klaver @ 2026-06-26 18:40 UTC (permalink / raw)
To: Israel Brewster <[email protected]>; +Cc: PostgreSQL General <[email protected]>
On 6/26/26 11:19 AM, Israel Brewster wrote:
> On Jun 26, 2026, at 10:14 AM, Adrian Klaver <[email protected]>
> wrote:
>>
>> This one does not show the actual query.
>
> Right, sorry. It’s the same query as in the first one though. Only
> difference is sequence scan off.
What are the definitions for orientation_station_idx and
new_data_station_idx?
What are the data types for the columns they are pointing at?
>>> ---
>>> Israel Brewster
>>> Software Engineer
>>> Alaska Volcano Observatory
>>> Geophysical Institute - UAF
>>> 2156 Koyukuk Drive
>>> Fairbanks AK 99775-7320
>>> Work: 907-474-5172
>>> cell: 907-328-9145
>>
>
^ permalink raw reply [nested|flat] 13+ messages in thread
* Re: PostgreSQL 15-->18 slowdown?
2026-06-26 17:58 PostgreSQL 15-->18 slowdown? Israel Brewster <[email protected]>
2026-06-26 18:14 ` Re: PostgreSQL 15-->18 slowdown? Adrian Klaver <[email protected]>
2026-06-26 18:19 ` Re: PostgreSQL 15-->18 slowdown? Israel Brewster <[email protected]>
2026-06-26 18:40 ` Re: PostgreSQL 15-->18 slowdown? Adrian Klaver <[email protected]>
@ 2026-06-26 18:55 ` Israel Brewster <[email protected]>
0 siblings, 0 replies; 13+ messages in thread
From: Israel Brewster @ 2026-06-26 18:55 UTC (permalink / raw)
To: Adrian Klaver <[email protected]>; +Cc: PostgreSQL General <[email protected]>
> On Jun 26, 2026, at 10:40 AM, Adrian Klaver <[email protected]> wrote:
>
>
>
> On 6/26/26 11:19 AM, Israel Brewster wrote:
>> On Jun 26, 2026, at 10:14 AM, Adrian Klaver <[email protected]> wrote:
>>>
>
>>> This one does not show the actual query.
>> Right, sorry. It’s the same query as in the first one though. Only difference is sequence scan off.
>
> What are the definitions for orientation_station_idx and new_data_station_idx?
>
> What are the data types for the columns they are pointing at?
So for orientation_station_idx, that’s on the tilt_orientation table:
geodesy=# \d tilt_orientation
Table "public.tilt_orientation"
Column | Type | Collation | Nullable | Default
---------------+--------------------------+-----------+----------+--------------------
id | uuid | | not null | uuid_generate_v1()
station | uuid | | not null |
seton | timestamp with time zone | | |
x_orientation | numeric | | |
y_orientation | numeric | | |
Indexes:
"tilt_orientation_pkey" PRIMARY KEY, btree (id)
"date_idx" btree (seton)
"orientation_station_idx" btree (station) INCLUDE (y_orientation)
"sta_time_w_ynotnull_idx" UNIQUE, btree (station, seton) INCLUDE (y_orientation) WHERE y_orientation IS NOT NULL
"station_time_idx" UNIQUE, btree (station, seton)
Foreign-key constraints:
"tilt_orientation_station_fkey" FOREIGN KEY (station) REFERENCES stations(id)
geodesy=#
so it’s a UUID (yeah, I went through a phase where I was using UUID’s as primary keys…in retrospect, probably not the best idea...)
And for new_data_station_idx, that’s on the tilt_data table:
geodesy=# \d tilt_data
Table "public.tilt_data"
Column | Type | Collation | Nullable | Default
-------------+--------------------------+-----------+----------+--------------------
id | uuid | | not null | uuid_generate_v1()
station | uuid | | not null |
read_time | timestamp with time zone | | not null |
tilt_x | numeric | | |
tilt_y | numeric | | |
temperature | numeric | | |
rot_x | numeric(6,3) | | |
rot_y | numeric(6,3) | | |
Indexes:
"new_tilt_pkey" PRIMARY KEY, btree (id)
"new_data_station_idx" btree (station)
"new_data_station_time_idx" UNIQUE, btree (station, read_time)
Foreign-key constraints:
"new_tilt_data_station_fkey" FOREIGN KEY (station) REFERENCES stations(id)
Disabled user triggers:
new_rotate_tilt_data BEFORE INSERT OR UPDATE ON tilt_data FOR EACH ROW WHEN (new.tilt_x IS NOT NULL AND new.tilt_y IS NOT NULL) EXECUTE FUNCTION correct_rotation()
Tablespace: "shared_drive"
geodesy=#
…so again, a UUID. And note that tablespace “shared drive” is not actually a shared drive (anymore) - everything has been moved to a local NVMe drive.
—
Israel Brewster
Software Engineer
Alaska Volcano Observatory
Geophysical Institute - UAF
2156 Koyukuk Drive
Fairbanks AK 99775-7320
Work: 907-474-5172
cell: 907-328-9145
>
>
>>>> ---
>>>> Israel Brewster
>>>> Software Engineer
>>>> Alaska Volcano Observatory
>>>> Geophysical Institute - UAF
>>>> 2156 Koyukuk Drive
>>>> Fairbanks AK 99775-7320
>>>> Work: 907-474-5172
>>>> cell: 907-328-9145
>>>
>
^ permalink raw reply [nested|flat] 13+ messages in thread
* Re: PostgreSQL 15-->18 slowdown?
2026-06-26 17:58 PostgreSQL 15-->18 slowdown? Israel Brewster <[email protected]>
@ 2026-06-26 18:16 ` Israel Brewster <[email protected]>
2026-06-26 18:44 ` Re: PostgreSQL 15-->18 slowdown? Tom Lane <[email protected]>
2 siblings, 1 reply; 13+ messages in thread
From: Israel Brewster @ 2026-06-26 18:16 UTC (permalink / raw)
To: Ruben Morais <[email protected]>; +Cc: PostgreSQL General <[email protected]>
Thanks for the suggestion. Unfortunately, jit off didn’t help (see query plan below). And I do have indexes - as I mentioned, when I forced postgresql to *use* the indexes by setting enable_seqscan = off;, the query ran in ~125ms - back to the fast speeds I was used to in PostgreSQL 15.
I’ve tried a couple of re-writes (LATERAL JOIN and using EXISTS rather than LIMIT 1), but they don’t seem to help.
QUERY PLAN
------------------------------------------------------------------------------------------------------
Sort (cost=182445.18..182445.63 rows=177 width=152)
Sort Key: (COALESCE(sites.name, 'Unknown'::text)), stations.name
-> Hash Left Join (cost=1.29..182438.57 rows=177 width=152)
Hash Cond: (stations.siteref = sites.id)
-> Seq Scan on stations (cost=0.00..6.77 rows=177 width=87)
-> Hash (cost=1.13..1.13 rows=13 width=11)
-> Seq Scan on sites (cost=0.00..1.13 rows=13 width=11)
SubPlan 1
-> Limit (cost=0.00..0.48 rows=1 width=1)
-> Nested Loop (cost=0.00..13833793.79 rows=29105774 width=1)
-> Seq Scan on tilt_data (cost=0.00..13469970.40 rows=29105774 width=16)
Filter: (station = stations.id)
-> Materialize (cost=0.00..1.22 rows=1 width=16)
-> Seq Scan on tilt_orientation (cost=0.00..1.21 rows=1 width=16)
Filter: (station = stations.id)
SubPlan 2
-> Aggregate (cost=1030.18..1030.19 rows=1 width=32)
-> Sort (cost=1029.93..1030.05 rows=50 width=126)
Sort Key: t.ord
-> Merge Join (cost=25.27..1028.52 rows=50 width=126)
Merge Cond: ((s.volcano_id)::text = (t.id)::text)
-> Foreign Scan on volcano s (cost=25.00..1025.00 rows=1000 width=156)
Remote server startup cost: 25
-> Sort (cost=0.27..0.29 rows=10 width=40)
Sort Key: t.id
-> Function Scan on unnest t (cost=0.00..0.10 rows=10 width=40)
(26 rows)
---
Israel Brewster
Software Engineer
Alaska Volcano Observatory
Geophysical Institute - UAF
2156 Koyukuk Drive
Fairbanks AK 99775-7320
Work: 907-474-5172
cell: 907-328-9145
> On Jun 26, 2026, at 10:08 AM, Ruben Morais <[email protected]> wrote:
>
> Hi,
>
> Saw your email, and checked you have JIT enable.
> Try to disable and run the query again
>
> SET jit = off;
>
> Or test the explain with jit off, to check the plan
> EXPLAIN (jit off) SELECT ...;
>
> Jit sometime had issues in plans in postgres.
> Other solution is create indexes or rewrite the code.
>
> Regards
> Rúben Morais
>
> (+351) 965775713 <https://pt.linkedin.com/pub/r%C3%BAben-morais/21/b44/b99; [email protected] <mailto:[email protected]>
> On Fri, Jun 26, 2026, 18:58 Israel Brewster <[email protected] <mailto:[email protected]>> wrote:
>> In postgreSQL 15, I had the below query that worked quickly. Now, I make no claims that the query is the best possible, or even a good query, but it DID work, and it did so quickly enough to be un-noticable when running.
>>
>> Then I upgrade to PostgreSQL 18 - and now the query never completes (as in, I get a command timeout after at least half an hour before I get a result). Looking at the EXPLAIN (https://explain.depesz.com/s/llAQ) makes it pretty obvious why: we have a sequence scan on a large table inside a nested loop - and that sequence scan is apparently not short circuiting.
>>
>> I tried the obvious: REINDEX database and VACUUM ANALYZE, but neither helped. I have my default_statistics_target set to 500 at the moment.
>>
>> Then I tried SET enable_seqscan = off; Lo and behold, the query ran in only 123.888 ms (fun number :-D ) - https://explain.depesz.com/s/K2K9
>>
>> What did I do wrong here? Thanks!
>>
>> The query in question:
>>
>> SELECT
>> stations.id <http://stations.id/;,
>> stations.name <http://stations.name/; as name,
>> latitude::float as lat,
>> longitude::float as lon,
>> elevation::float alt,
>> type,
>> coalesce(sites.name <http://sites.name/;, 'Unknown') as site,
>> sites.id <http://sites.id/; as siteid,
>> coalesce((SELECT true
>> FROM tilt_data
>> INNER JOIN tilt_orientation
>> ON tilt_data.station=tilt_orientation.station
>> WHERE tilt_data.station=stations.id <http://stations.id/;
>> LIMIT 1),
>> false) as has_tilt,
>> array_to_json(volcano) as stationvolcs,
>> coalesce(
>> (SELECT array_agg(s.volcano_name ORDER BY t.ord)
>> FROM volcano s
>> JOIN unnest( volcano ) WITH ORDINALITY t(id,ord)
>> ON (t.id <http://t.id/>=s.volcano_id)
>> ), '{}' ) volcnames
>> FROM stations
>> LEFT JOIN sites ON stations.siteref=sites.id <http://sites.id/;
>> ORDER BY site, name
>>
>>
>> ---
>> Israel Brewster
>> Software Engineer
>> Alaska Volcano Observatory
>> Geophysical Institute - UAF
>> 2156 Koyukuk Drive <https://www.google.com/maps/search/2156+Koyukuk+Drive+Fairbanks+AK+99775-7320?entry=gmail&source...;
>> Fairbanks AK 99775-7320 <https://www.google.com/maps/search/2156+Koyukuk+Drive+Fairbanks+AK+99775-7320?entry=gmail&source...;
>> Work: 907-474-5172
>> cell: 907-328-9145
>>
^ permalink raw reply [nested|flat] 13+ messages in thread
* Re: PostgreSQL 15-->18 slowdown?
2026-06-26 17:58 PostgreSQL 15-->18 slowdown? Israel Brewster <[email protected]>
2026-06-26 18:16 ` Re: PostgreSQL 15-->18 slowdown? Israel Brewster <[email protected]>
@ 2026-06-26 18:44 ` Tom Lane <[email protected]>
2026-06-26 18:58 ` Re: PostgreSQL 15-->18 slowdown? Israel Brewster <[email protected]>
0 siblings, 1 reply; 13+ messages in thread
From: Tom Lane @ 2026-06-26 18:44 UTC (permalink / raw)
To: Israel Brewster <[email protected]>; +Cc: Ruben Morais <[email protected]>; PostgreSQL General <[email protected]>
Israel Brewster <[email protected]> writes:
> SubPlan 1
> -> Limit (cost=0.00..0.48 rows=1 width=1)
> -> Nested Loop (cost=0.00..13833793.79 rows=29105774 width=1)
> -> Seq Scan on tilt_data (cost=0.00..13469970.40 rows=29105774 width=16)
> Filter: (station = stations.id)
> -> Materialize (cost=0.00..1.22 rows=1 width=16)
> -> Seq Scan on tilt_orientation (cost=0.00..1.21 rows=1 width=16)
> Filter: (station = stations.id)
Can you show us the EXPLAIN output for this part of the plan in v15?
regards, tom lane
^ permalink raw reply [nested|flat] 13+ messages in thread
* Re: PostgreSQL 15-->18 slowdown?
2026-06-26 17:58 PostgreSQL 15-->18 slowdown? Israel Brewster <[email protected]>
2026-06-26 18:16 ` Re: PostgreSQL 15-->18 slowdown? Israel Brewster <[email protected]>
2026-06-26 18:44 ` Re: PostgreSQL 15-->18 slowdown? Tom Lane <[email protected]>
@ 2026-06-26 18:58 ` Israel Brewster <[email protected]>
0 siblings, 0 replies; 13+ messages in thread
From: Israel Brewster @ 2026-06-26 18:58 UTC (permalink / raw)
To: Tom Lane <[email protected]>; +Cc: Ruben Morais <[email protected]>; PostgreSQL General <[email protected]>
> On Jun 26, 2026, at 10:44 AM, Tom Lane <[email protected]> wrote:
>
> Israel Brewster <[email protected]> writes:
>
>> SubPlan 1
>> -> Limit (cost=0.00..0.48 rows=1 width=1)
>> -> Nested Loop (cost=0.00..13833793.79 rows=29105774 width=1)
>> -> Seq Scan on tilt_data (cost=0.00..13469970.40 rows=29105774 width=16)
>> Filter: (station = stations.id)
>> -> Materialize (cost=0.00..1.22 rows=1 width=16)
>> -> Seq Scan on tilt_orientation (cost=0.00..1.21 rows=1 width=16)
>> Filter: (station = stations.id)
>
> Can you show us the EXPLAIN output for this part of the plan in v15?
I wish I could - I was wanting to see that myself. Unfortunately, I upgraded to 18 using —link, so by the time I discovered this issue, I had no way to go back to 15 (other than restoring from backups or the like), at least to the best of my knowledge.
---
Israel Brewster
Software Engineer
Alaska Volcano Observatory
Geophysical Institute - UAF
2156 Koyukuk Drive
Fairbanks AK 99775-7320
Work: 907-474-5172
cell: 907-328-9145
>
> regards, tom lane
^ permalink raw reply [nested|flat] 13+ messages in thread
* Re: PostgreSQL 15-->18 slowdown?
2026-06-26 17:58 PostgreSQL 15-->18 slowdown? Israel Brewster <[email protected]>
@ 2026-06-26 19:35 ` Israel Brewster <[email protected]>
2 siblings, 0 replies; 13+ messages in thread
From: Israel Brewster @ 2026-06-26 19:35 UTC (permalink / raw)
To: PostgreSQL General <[email protected]>
> On Jun 26, 2026, at 9:58 AM, Israel Brewster <[email protected]> wrote:
>
> In postgreSQL 15, I had the below query that worked quickly. Now, I make no claims that the query is the best possible, or even a good query, but it DID work, and it did so quickly enough to be un-noticable when running.
> ...
Some additional information that may (or may not) be helpful: in the tilt_data table, there are only 15 distinct stations (out of a total of 177 stations) across 407,032,436 rows
…so the query planner is correct to think that if looking for a single station, it will get a large number of rows…at least if you ignore the LIMIT 1.
I did manage to find a workaround: If I change the subquery on tilt_data to this:
(stations.id = ANY (
SELECT tilt_data.station
FROM tilt_data
INNER JOIN tilt_orientation ON tilt_data.station = tilt_orientation.station
WHERE tilt_data.station = stations.id
)) as has_tilt,
things work better - still not as fast as the original query with sequence scan disabled, but fast enough to work with: https://explain.depesz.com/s/bki5
…but not only does that feel ugly (to me at least), it’s still roughly 4x slower than the original query with sequence scans disabled… Good enough to get me back up and running, but not really a great solution, I don’t think. I might also try a lookup table (materialized view), but I don’t know how much better that would be, as I would have to refresh it whenever the data changes.
—
Israel Brewster
Software Engineer
Alaska Volcano Observatory
Geophysical Institute - UAF
2156 Koyukuk Drive
Fairbanks AK 99775-7320
Work: 907-474-5172
cell: 907-328-9145
>
> ---
> Israel Brewster
> Software Engineer
> Alaska Volcano Observatory
> Geophysical Institute - UAF
> 2156 Koyukuk Drive
> Fairbanks AK 99775-7320
> Work: 907-474-5172
> cell: 907-328-9145
>
^ permalink raw reply [nested|flat] 13+ messages in thread
end of thread, other threads:[~2026-06-26 19:35 UTC | newest]
Thread overview: 13+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2024-07-26 05:15 Re: PgbackRest PointTIme Recovery : server unable to start back Muhammad Ikram <[email protected]>
2024-07-26 06:33 ` KK CHN <[email protected]>
2024-07-26 06:57 ` Muhammad Ikram <[email protected]>
2026-06-26 17:58 PostgreSQL 15-->18 slowdown? Israel Brewster <[email protected]>
2026-06-26 18:14 ` Re: PostgreSQL 15-->18 slowdown? Adrian Klaver <[email protected]>
2026-06-26 18:16 ` Re: PostgreSQL 15-->18 slowdown? Adrian Klaver <[email protected]>
2026-06-26 18:19 ` Re: PostgreSQL 15-->18 slowdown? Israel Brewster <[email protected]>
2026-06-26 18:40 ` Re: PostgreSQL 15-->18 slowdown? Adrian Klaver <[email protected]>
2026-06-26 18:55 ` Re: PostgreSQL 15-->18 slowdown? Israel Brewster <[email protected]>
2026-06-26 18:16 ` Re: PostgreSQL 15-->18 slowdown? Israel Brewster <[email protected]>
2026-06-26 18:44 ` Re: PostgreSQL 15-->18 slowdown? Tom Lane <[email protected]>
2026-06-26 18:58 ` Re: PostgreSQL 15-->18 slowdown? Israel Brewster <[email protected]>
2026-06-26 19:35 ` Re: PostgreSQL 15-->18 slowdown? Israel Brewster <[email protected]>
This inbox is served by agora; see mirroring instructions
for how to clone and mirror all data and code used for this inbox