Re: Delays between "connection received" and "connection authenticated" because of localhost entries in hba

2024-10-30 Thread Daniel Westermann (DWE)
>> What we've found out so far is, that this only happens if we have a 
>> localhost(or any other hostname) line before the line matching our 
>> connection, something like this:
>> host    replication x localhost    md5
>> host    all x xx.xx.xx.0/24    md5

... which is quite hard to do if you don't know which one it will be

Regards
Daniel



Re: Delays between "connection received" and "connection authenticated" because of localhost entries in hba

2024-10-30 Thread Daniel Westermann (DWE)
>>Greg Sabino Mullane  writes:
>> I'd echo the suggestion to strace this. You can use the pre_auth_delay
>> setting to help facilitate that. See:

>IIUC, the delays are rare and unpredictable, so that strace'ing seems
>unlikely to be practical.

>If rebuilding from source is feasible, you could insert monitoring
>elog(LOG) calls around the name lookup (that is, around the
>pg_getnameinfo_all call in src/backend/libpq/hba.c).  This would
>confirm or disprove the theory that the name lookup is the source
>of the issue, which is about as much as we'd get out of strace.

Thanks for all your tips/hints

Regards
Daniel



Re: Index Partition Size Double of its Table Partition?

2024-10-30 Thread Don Seiler
On Wed, Oct 30, 2024 at 11:23 AM Peter Geoghegan  wrote:

>
> If a substantial amount of the index was written by CREATE INDEX (and
> not by retail inserts) then my theory is unlikely to be correct. It
> could just be that you managed to absorb most inserts in one
> partition, but not in the other. That's probably possible when there
> are only relatively small differences in the number of inserts that
> need to use of the space left behind by fillfactor in each case. In
> general page splits tend to come in distinct "waves" after CREATE
> INDEX is run.
>

What do you mean by "absorb" the inserts?

It sounds like the answer will be "No", but: Would rebuilding the index
after the month-end (when inserts have stopped on this partition) change
anything?

Don.
-- 
Don Seiler
www.seiler.us


Index Partition Size Double of its Table Partition?

2024-10-30 Thread Don Seiler
We're trying out a new non-unique covering (including) index on a couple of
table partitions. We put the index on partitions for last month and this
month. Both table partitions have similar sizes (45-46 GB) and row counts
(330-333 million). The covering index on last month's partition is 50GB,
but this month's index is 79GB already. The table is basically write-only
as well. So there shouldn't be any real bloat here.

One thing worth mentioning is that the table is 4 columns, the index is on
two of them and includes the other two. I can't think of an explanation for
the index being so much larger than its table, especially compared to last
month's index.

Curious if anyone has any thoughts on what might be causing this.
-- 
Don Seiler
www.seiler.us


Re: Index Partition Size Double of its Table Partition?

2024-10-30 Thread Don Seiler
On Wed, Oct 30, 2024 at 10:45 AM Peter Geoghegan  wrote:

>
> It sounds like you have no updates and deletes. Right? So the only
> thing that could be different is the way that the pages are being
> split (aside from variations in the width of index tuples, which seems
> highly unlikely to be the only factor).
>

Correct, the table only sees inserts as far as DML goes.


> The heuristics used to trigger the relevant behavior are fairly
> conservative. I wonder if we should be more aggressive about it.
>
> > I should have also included that this is on PG 15 (currently 15.8 but we
> created the indexes when it was still 15.7) on Ubuntu 22.04 LTS.
>
> That shouldn't matter, as far as this theory of mine is concerned.
> Anything after 12 could be affected by the issue I'm thinking of.
>

Why would last month's index be so much smaller?

Both indexes were created using CONCURRENTLY, as each was created during
its month when we started testing. The September index was created toward
the end of the month (Sep 26), whereas the October one was created Oct 1.
Both table partitions are getting regularly autovacuum/autoanalyze work.

Don.
-- 
Don Seiler
www.seiler.us


Re: Index Partition Size Double of its Table Partition?

2024-10-30 Thread Peter Geoghegan
On Wed, Oct 30, 2024 at 11:24 AM Don Seiler  wrote:
> One thing worth mentioning is that the table is 4 columns, the index is on 
> two of them and includes the other two. I can't think of an explanation for 
> the index being so much larger than its table, especially compared to last 
> month's index.
>
> Curious if anyone has any thoughts on what might be causing this.

You mentioned that this has 4 columns. Sounds like this could be a
"locally monotonically increasing index". I wonder if you're
benefiting from this optimization, though only inconsistently:

https://www.youtube.com/watch?v=p5RaATILoiE&t=2079s
https://git.postgresql.org/gitweb/?p=postgresql.git;a=commit;h=f21668f3

Of course, this is only a guess. I vaguely recall a complaint that
sounded vaguely like yours, also involving partitioning.

--
Peter Geoghegan




Re: Index Partition Size Double of its Table Partition?

2024-10-30 Thread Don Seiler
On Wed, Oct 30, 2024 at 10:35 AM Peter Geoghegan  wrote:

> On Wed, Oct 30, 2024 at 11:24 AM Don Seiler  wrote:
> > One thing worth mentioning is that the table is 4 columns, the index is
> on two of them and includes the other two. I can't think of an explanation
> for the index being so much larger than its table, especially compared to
> last month's index.
> >
> > Curious if anyone has any thoughts on what might be causing this.
>
> You mentioned that this has 4 columns. Sounds like this could be a
> "locally monotonically increasing index". I wonder if you're
> benefiting from this optimization, though only inconsistently:
>
> https://www.youtube.com/watch?v=p5RaATILoiE&t=2079s
> https://git.postgresql.org/gitweb/?p=postgresql.git;a=commit;h=f21668f3
>
> Of course, this is only a guess. I vaguely recall a complaint that
> sounded vaguely like yours, also involving partitioning.
>

Thanks Peter, I'll look into that shortly.

I should have also included that this is on PG 15 (currently 15.8 but we
created the indexes when it was still 15.7) on Ubuntu 22.04 LTS.

Don.

-- 
Don Seiler
www.seiler.us


Re: Index Partition Size Double of its Table Partition?

2024-10-30 Thread Peter Geoghegan
On Wed, Oct 30, 2024 at 11:39 AM Don Seiler  wrote:
> Thanks Peter, I'll look into that shortly.

It sounds like you have no updates and deletes. Right? So the only
thing that could be different is the way that the pages are being
split (aside from variations in the width of index tuples, which seems
highly unlikely to be the only factor).

The heuristics used to trigger the relevant behavior are fairly
conservative. I wonder if we should be more aggressive about it.

> I should have also included that this is on PG 15 (currently 15.8 but we 
> created the indexes when it was still 15.7) on Ubuntu 22.04 LTS.

That shouldn't matter, as far as this theory of mine is concerned.
Anything after 12 could be affected by the issue I'm thinking of.

-- 
Peter Geoghegan




Re: Index Partition Size Double of its Table Partition?

2024-10-30 Thread Peter Geoghegan
On Wed, Oct 30, 2024 at 12:08 PM Don Seiler  wrote:
> Why would last month's index be so much smaller?

Because the split heuristics worked as designed there. That's the
theory, at least.

> Both indexes were created using CONCURRENTLY, as each was created during its 
> month when we started testing. The September index was created toward the end 
> of the month (Sep 26), whereas the October one was created Oct 1.  Both table 
> partitions are getting regularly autovacuum/autoanalyze work.

If a substantial amount of the index was written by CREATE INDEX (and
not by retail inserts) then my theory is unlikely to be correct. It
could just be that you managed to absorb most inserts in one
partition, but not in the other. That's probably possible when there
are only relatively small differences in the number of inserts that
need to use of the space left behind by fillfactor in each case. In
general page splits tend to come in distinct "waves" after CREATE
INDEX is run.

-- 
Peter Geoghegan




What to do with a PAAS-pg server

2024-10-30 Thread alexander al (leiden)
Hi,

we have a supplier (via our client) who has an self build PAAS-version
of postgresql. Ok, you would say, that's fine. But, there is always an
but, we think the settings are not quite ok. We really want to know how
much memory etc there is on that server. So we can recommend the
recommended settings. Is there a way to get those information on the
server itself from psql?

regards,

Alexander Al






Re: What to do with a PAAS-pg server

2024-10-30 Thread Ron Johnson
Settings, like "SELECT * FROM pg_settings;"

On Wed, Oct 30, 2024 at 11:32 AM alexander al (leiden) 
wrote:

> Hi,
>
> we have a supplier (via our client) who has an self build PAAS-version
> of postgresql. Ok, you would say, that's fine. But, there is always an
> but, we think the settings are not quite ok. We really want to know how
> much memory etc there is on that server. So we can recommend the
> recommended settings. Is there a way to get those information on the
> server itself from psql?
>
> regards,
>
> Alexander Al
>
>
>
>
>

-- 
Death to , and butter sauce.
Don't boil me, I'm still alive.
 crustacean!


Re: Random memory related errors on live postgres 14.13 instance on Ubuntu 22.04 LTS

2024-10-30 Thread Vijaykumar Jain
On Wed, 30 Oct 2024 at 13:04, Ian J Cottee  wrote:

> Hello everyone, I’ve been using postgres for over 25 years now and never
> had any major issues which were not caused by my own stupidity. In the last
> 24 hours however I’ve had a number of issues on one client's server which I
> assume are a bug in postgres or a possible hardware issue (they are running
> on a Linode) but I need some clarification and would welcome advice on how
> to proceed. I will also forward this mail to Linode support to ask them to
> check for any memory issues they can detect.
>
>
>
> This particular Postgres is running on Ubuntu LTS 22.04 and has the
> following version information:
>
>
>
> ```
>
> PostgreSQL 14.13 (Ubuntu 14.13-0ubuntu0.22.04.1) on x86_64-pc-linux-gnu,
> compiled by gcc (Ubuntu 11.4.0-1ubuntu1~22.04) 11.4.0, 64-bit
>
> ```
>
>
> The quick summary is that over a 24 hour period I had the following errors
> appear in the postgres logs at different times causing the system processes
> to restart:
>
>
>- stuck spinlock detected
>- free(): corrupted unsorted chunks
>- double free or corruption (!prev)
>- corrupted size vs. prev_size
>- corrupted double-linked list
>- *** stack smashing detected ***: terminated
>- Segmentation fault
>
>
>

are you using the postgresql setup compiled from source ?
listing the output of pg_config may give the details

are there any extensions installed, can you list those extensions.

if you have access to source packages ,
Getting a stack trace of a running PostgreSQL backend on Linux/BSD -
PostgreSQL wiki

can you generate a stacktrace from the process that is crashing or if it
dumped a core, then backtrace from the core dump.

will it be possible to share the actual logs both postgresql and kernel
around the incident ...

Do you have access to core dumps which these crashes may have generated ? i
think ABRT / segmentation faults would generate one.

do you collect stats of system. around the time of crash do you any
abnormal usage of io or cpu or memory , along with locks held in postgresql
setup etc.





> Here’s the more detailed breakdown.
>
>
>
> On Monday evening this week, the following event occurred on the server
>
>
>
> ```
>
> 2024-10-28 18:12:47.145 GMT [575437] xxx@xxx PANIC: stuck spinlock
> detected at LWLockWaitListLock,
> ./build/../src/backend/storage/lmgr/lwlock.c:913
>
```
>
>
>
I think a backtrace here would help what part of call stack led to this.
this alone does not look like any bug.




> Followed by:
>
>
>
> ```
>
> 2024-10-28 18:12:47.249 GMT [1880289] LOG: terminating any other active
> server processes
>
> 2024-10-28 18:12:47.284 GMT [1880289] LOG: all server processes
> terminated; reinitializing
>
> ```
>
> And eventually
>
>
> ```
>
> 2024-10-28 18:12:48.474 GMT [575566] xxx@xxx FATAL: the database system
> is in recovery mode
>
> 2024-10-28 18:12:48.476 GMT [575550] LOG: database system was not properly
> shut down; automatic recovery in progress
>
> 2024-10-28 18:12:48.487 GMT [575550] LOG: redo starts at DD/405E83A8
>
> 2024-10-28 18:12:48.487 GMT [575550] LOG: invalid record length at
> DD/405EF818: wanted 24, got 0
>
> 2024-10-28 18:12:48.487 GMT [575550] LOG: redo done at DD/405EF7E0 system
> usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s
>
> 2024-10-28 18:12:48.515 GMT [1880289] LOG: database system is ready to
> accept connections
>
> ```
>
> This wasn’t noticed by myself or any users as they tend to all be finished
> by 17:30.  However later,
>
>
>


> ```
>
> 2024-10-28 20:27:15.258 GMT [611459] xxx@xxx LOG: unexpected EOF on
> client connection with an open transaction
>
> 2024-10-28 21:01:05.934 GMT [620373] xxx@ LOG: unexpected EOF on
> client connection with an open transaction
>
> free(): corrupted unsorted chunks
>

it all seems like memory corruption or some leak ... valgrind ? to get more
details if leak ...



> 2024-10-28 21:15:02.203 GMT [1880289] LOG: server process (PID 623803) was
> terminated by signal 6: Aborted
>
> 2024-10-28 21:15:02.204 GMT [1880289] LOG: terminating any other active
> server processes
>
> ```
>
>
>
> This time it could not recover and I didn’t notice until early the next
> morning whilst doing some routine checks.
>
>
>
> ```
>
> 2024-10-28 21:15:03.643 GMT [623807] LOG: database system was not properly
> shut down; automatic recovery in progress
>
> 2024-10-28 21:15:03.655 GMT [623807] LOG: redo starts at DD/47366740
>
> 2024-10-28 21:15:03.663 GMT [623807] LOG: invalid record length at
> DD/475452A0: wanted 24, got 0
>
> 2024-10-28 21:15:03.663 GMT [623807] LOG: redo done at DD/47545268 system
> usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s
>
> 2024-10-28 21:15:03.682 GMT [623829] xxx@xxx FATAL: the database system
> is in recovery mode
>
> double free or corruption (!prev)
>
> 2024-10-28 21:15:03.832 GMT [1880289] LOG: startup process (PID 623807)

Re: Delays between "connection received" and "connection authenticated" because of localhost entries in hba

2024-10-30 Thread Greg Sabino Mullane
I'd echo the suggestion to strace this. You can use the pre_auth_delay
setting to help facilitate that. See:

https://www.postgresql.org/docs/current/runtime-config-developer.html

Cheers,
Greg


Re: Delays between "connection received" and "connection authenticated" because of localhost entries in hba

2024-10-30 Thread Tom Lane
Greg Sabino Mullane  writes:
> I'd echo the suggestion to strace this. You can use the pre_auth_delay
> setting to help facilitate that. See:

IIUC, the delays are rare and unpredictable, so that strace'ing seems
unlikely to be practical.

If rebuilding from source is feasible, you could insert monitoring
elog(LOG) calls around the name lookup (that is, around the
pg_getnameinfo_all call in src/backend/libpq/hba.c).  This would
confirm or disprove the theory that the name lookup is the source
of the issue, which is about as much as we'd get out of strace.

regards, tom lane




Re: Index Partition Size Double of its Table Partition?

2024-10-30 Thread David Mullineux
Are you able to cluster the table ? The idea is that rows ordered in the
same way  as the index might reduce it's size ?

On Wed, 30 Oct 2024, 16:29 Don Seiler,  wrote:

> On Wed, Oct 30, 2024 at 11:23 AM Peter Geoghegan  wrote:
>
>>
>> If a substantial amount of the index was written by CREATE INDEX (and
>> not by retail inserts) then my theory is unlikely to be correct. It
>> could just be that you managed to absorb most inserts in one
>> partition, but not in the other. That's probably possible when there
>> are only relatively small differences in the number of inserts that
>> need to use of the space left behind by fillfactor in each case. In
>> general page splits tend to come in distinct "waves" after CREATE
>> INDEX is run.
>>
>
> What do you mean by "absorb" the inserts?
>
> It sounds like the answer will be "No", but: Would rebuilding the index
> after the month-end (when inserts have stopped on this partition) change
> anything?
>
> Don.
> --
> Don Seiler
> www.seiler.us
>


Random memory related errors on live postgres 14.13 instance on Ubuntu 22.04 LTS

2024-10-30 Thread Ian J Cottee
Hello everyone, I’ve been using postgres for over 25 years now and never
had any major issues which were not caused by my own stupidity. In the last
24 hours however I’ve had a number of issues on one client's server which I
assume are a bug in postgres or a possible hardware issue (they are running
on a Linode) but I need some clarification and would welcome advice on how
to proceed. I will also forward this mail to Linode support to ask them to
check for any memory issues they can detect.



This particular Postgres is running on Ubuntu LTS 22.04 and has the
following version information:



```

PostgreSQL 14.13 (Ubuntu 14.13-0ubuntu0.22.04.1) on x86_64-pc-linux-gnu,
compiled by gcc (Ubuntu 11.4.0-1ubuntu1~22.04) 11.4.0, 64-bit

```


The quick summary is that over a 24 hour period I had the following errors
appear in the postgres logs at different times causing the system processes
to restart:


   - stuck spinlock detected
   - free(): corrupted unsorted chunks
   - double free or corruption (!prev)
   - corrupted size vs. prev_size
   - corrupted double-linked list
   - *** stack smashing detected ***: terminated
   - Segmentation fault



Here’s the more detailed breakdown.



On Monday evening this week, the following event occurred on the server



```

2024-10-28 18:12:47.145 GMT [575437] xxx@xxx PANIC: stuck spinlock detected
at LWLockWaitListLock, ./build/../src/backend/storage/lmgr/lwlock.c:913

```



Followed by:



```

2024-10-28 18:12:47.249 GMT [1880289] LOG: terminating any other active
server processes

2024-10-28 18:12:47.284 GMT [1880289] LOG: all server processes terminated;
reinitializing

```

And eventually


```

2024-10-28 18:12:48.474 GMT [575566] xxx@xxx FATAL: the database system is
in recovery mode

2024-10-28 18:12:48.476 GMT [575550] LOG: database system was not properly
shut down; automatic recovery in progress

2024-10-28 18:12:48.487 GMT [575550] LOG: redo starts at DD/405E83A8

2024-10-28 18:12:48.487 GMT [575550] LOG: invalid record length at
DD/405EF818: wanted 24, got 0

2024-10-28 18:12:48.487 GMT [575550] LOG: redo done at DD/405EF7E0 system
usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s

2024-10-28 18:12:48.515 GMT [1880289] LOG: database system is ready to
accept connections

```

This wasn’t noticed by myself or any users as they tend to all be finished
by 17:30.  However later,



```

2024-10-28 20:27:15.258 GMT [611459] xxx@xxx LOG: unexpected EOF on client
connection with an open transaction

2024-10-28 21:01:05.934 GMT [620373] xxx@ LOG: unexpected EOF on client
connection with an open transaction

free(): corrupted unsorted chunks

2024-10-28 21:15:02.203 GMT [1880289] LOG: server process (PID 623803) was
terminated by signal 6: Aborted

2024-10-28 21:15:02.204 GMT [1880289] LOG: terminating any other active
server processes

```



This time it could not recover and I didn’t notice until early the next
morning whilst doing some routine checks.



```

2024-10-28 21:15:03.643 GMT [623807] LOG: database system was not properly
shut down; automatic recovery in progress

2024-10-28 21:15:03.655 GMT [623807] LOG: redo starts at DD/47366740

2024-10-28 21:15:03.663 GMT [623807] LOG: invalid record length at
DD/475452A0: wanted 24, got 0

2024-10-28 21:15:03.663 GMT [623807] LOG: redo done at DD/47545268 system
usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s

2024-10-28 21:15:03.682 GMT [623829] xxx@xxx FATAL: the database system is
in recovery mode

double free or corruption (!prev)

2024-10-28 21:15:03.832 GMT [1880289] LOG: startup process (PID 623807) was
terminated by signal 6: Aborted

2024-10-28 21:15:03.832 GMT [1880289] LOG: aborting startup due to startup
process failure

2024-10-28 21:15:03.835 GMT [1880289] LOG: database system is shut down

```



When I noticed in the morning it was able to start without an issue. From
googling it appeared to be a memory issue and I wondered if the problem was
sorted now the server process had stopped completely and restarted. The
problem was not sorted although all the above errors were recovered from
automatically without any input from myself or the client’s noticing.



```

corrupted size vs. prev_size

2024-10-29 09:55:24.417 GMT [894747] LOG: background worker "parallel
worker" (PID 947642) was terminated by signal 6: Aborted

```



```

corrupted double-linked list

2024-10-29 13:14:28.322 GMT [894747] LOG: background worker "parallel
worker" (PID 1019071) was terminated by signal 6: Aborted

```



```

*** stack smashing detected ***: terminated

2024-10-28 15:24:30.331 GMT [1880289] LOG: background worker "parallel
worker" (PID 528630) was terminated by signal 6: A\ borted

```



```

2024-10-28 15:40:26.617 GMT [1880289] LOG: background worker "parallel
worker" (PID 533515) was terminated by signal 11: \

Segmentation fault

2024-10-28 15:40:26.617 GMT [1880289] DETAIL: Failed process was running:
SELECT "formula_line".id FROM "formul\

```



I rebooted the server at 18:30