Re: Questions about btree_gin vs btree_gist for low cardinality columns

[Morris de Oryx]

Since I've been wondering about this subject, I figured I'd take a bit of
time and try to do some tests. I'm not new to databases or coding, but have
been using Postgres for less than two years. I haven't tried to generate
large blocks of test data directly in Postgres before, so I'm *sure* that
there are better ways to do what I've done here. No worries, this gave me a
chance to work through at least some of the questions/problems in setting
up and running tests.

Anyway, I populated a table with 1M rows of data with very little in them,
just a two-character state abbreviation. There are only 59 values, and the
distribution is fairly even as I used random() without any tricks to shape
the distribution. So, each value is roughly 1/60th of the total row count.
Not realistic, but what I've got.

For this table, I built four different kind of index and tried each one out
with a count(*) query on a single exact match. I also checked out the size
of each index.

Headline results:

Partial index: Smaller (as expeced), fast.
B-tree index: Big, fast.
GIN: Small, slow.
Hash: Large, slow. ("Large" may be exaggerated in comparison with a B-tree
because of my test data.)

I'm wondering how much impact it had that I used such very small strings,
and how much difference it made that the data was so evenly distributed.

If anyone has any insights, I'd be grateful to hear them. I'm posting the
various bits of code involved below for anyone following along at home.

First, my version string as that can make a difference (we deploy on RDS, I
develop on macOS):

PostgreSQL 11.3 on x86_64-apple-darwin16.7.0, compiled by Apple LLVM
version 8.1.0 (clang-802.0.42), 64-bit

There's a simple lookup table with the 59 abbreviations
(AL,AR,AS,AZ,CA,CO,CT,DC,DE,FL,FM,GA,GU,HI,IA,ID,IL,IN,KS,KY,LA,MA,MD,ME,MH,MI,MN,MO,MP,MS,MT,NC,ND,NE,NH,NJ,NM,NV,NY,OH,OK,OR,PA,PR,PW,RI,SC,SD,TN,TX,UT,VA,VI,VT,WA,WI,WV,WY)

BEGIN;
CREATE TABLE IF NOT EXISTS api.state (
abbr text
);
COMMIT;

And here's the test data table definition:

BEGIN;
CREATE TABLE IF NOT EXISTS ascendco.state_test (
abbr text,
num integer -- I didn't end up using this.
);
COMMIT;

I wanted to create 1M rows and bashed around with generate_series,
recursive CTEs...and didn't get it working. So I wrote a tiny function
instead:

/* random() produces are pretty consistent distribution of numbers.
   For ideas on generating other distributions, this piece looks good:
   https://chartio.com/learn/sql/random-sequences/
*/

CREATE OR REPLACE FUNCTION api.generate_state_test_rows (loop_max int)
   RETURNS int AS $$

DECLARE
   counter integer := 0;

BEGIN
   IF (loop_max < 1) THEN
  RETURN 0 ;
   END IF;

   WHILE counter <= loop_max LOOP
counter := counter + 1 ;

insert into state_test (num,abbr)

 values (
  random() * 100,   -- Get a random number between
0-1,000,000.
 (select abbr -- Get a random state abbreviation out of our
tiny related table.
from state
   order by random()
  limit 1)
);

   END LOOP ;

   RETURN 1;
END;

$$ LANGUAGE plpgsql

The horror. The horror. But it works:

select * from generate_state_test_rows(100);

Okay, so that's the data set up. Next, the indexes and their sizes:

DROP INDEX IF EXISTS abbr_partial_ma;
DROP INDEX IF EXISTS abbr_btree;
DROP INDEX IF EXISTS abbr_gin;
DROP INDEX IF EXISTS abbr_hash;

CREATE INDEX abbr_partial_ma  ON state_test(abbr) WHERE abbr = 'MA';
CREATE INDEX abbr_btree ON state_test USING btree (abbr);
CREATE INDEX abbr_gin   ON state_test USING gin (abbr);
CREATE INDEX abbr_hash  ON state_test USING hash (abbr);

select 'Partial' as method, pg_table_size('abbr_partial_ma'),
pg_table_size('abbr_partial_ma') / 1024 || ' Kb' as "kb" union all
select 'B tree' as  method, pg_table_size('abbr_btree'),
 pg_table_size('abbr_btree') / 1024  || ' Kb' as "kb" union all
select 'GIN'as  method, pg_table_size('abbr_gin'),
 pg_table_size('abbr_gin')   / 1024  || ' Kb' as "kb" union all
select 'Hash'   as  method, pg_table_size('abbr_hash'),
pg_table_size('abbr_hash')  / 1024  || ' Kb' as "kb"

methodpg_table_sizekb
Partial   401408392 Kb
B tree2248704021960 Kb
GIN   19169281872 Kb
Hash  4925030448096 Kb

Okay, so the partial index is smaller, basically proportional to the
fraction of the file it's indexing. So that makes sense, and is good to
know. The hash index size is...harder to explain...very big. Maybe my tiny
strings? Not sure what size Postgres hashes to. A hash of a two character
string is likely about worst-case. The B-tree is pretty big.

Okay, timing tests. I was hoping that the GIN would do well, but it didn't.
Here are some explain dumps.

B-tree (partial, just on this one value)
Aggregate  (cost=389.43..389.44 rows=1 width=8)
  ->  Index Only Scan using abbr_btree on state_test  (cost=0.42..346.68
rows=17100 width=0)
Index Cond: (abbr = 'MA'::text

Re: Questions about btree_gin vs btree_gist for low cardinality columns

[Gavin Flower]

On 01/06/2019 14:52, Morris de Oryx wrote:
[...]
For an example, imagine an address table with 100M US street addresses 
with two character state abbreviations. So, say there are around 60 
values in there (the USPS is the mail system for a variety of US 
territories, possessions and friends in the Pacific.) Okay, so what's 
the best index type for state abbreviation? For the sake of argument, 
assume a normal distribution so something like FM (Federated States of 
Micronesia) is on a tail end and CA or NY are a whole lot more common.


[...]

I'd expect the distribution of values to be closer to a power law than 
the Normal distribution -- at very least a few states would have the 
most lookups.  But this is my gut feel, not based on any scientific 
analysis!



Cheers,
Gavin

Re: Questions about btree_gin vs btree_gist for low cardinality columns

[Morris de Oryx]

On Sat, Jun 1, 2019 at 6:24 PM Gavin Flower 
wrote:

> On 01/06/2019 14:52, Morris de Oryx wrote:
>
> I'd expect the distribution of values to be closer to a power law than
> the Normal distribution -- at very least a few states would have the
> most lookups.  But this is my gut feel, not based on any scientific
> analysis!


G'day and thanks! (I'm in the country to the left of you) Yeah, and my
mocked data divides things up fairly evenly :(

I meant to mention that when I did my tests that I only had one index on at
a time to prevent confusion. I also ran the speed tests several times so
each was on a warm cache.

Re: Questions about btree_gin vs btree_gist for low cardinality columns

[Peter J. Holzer]

On 2019-06-01 17:44:00 +1000, Morris de Oryx wrote:
> Since I've been wondering about this subject, I figured I'd take a bit of time
> and try to do some tests. I'm not new to databases or coding, but have been
> using Postgres for less than two years. I haven't tried to generate large
> blocks of test data directly in Postgres before, so I'm sure that there are
> better ways to do what I've done here. No worries, this gave me a chance to
> work through at least some of the questions/problems in setting up and running
> tests.
> 
> Anyway, I populated a table with 1M rows of data with very little in them, 
> just
> a two-character state abbreviation. There are only 59 values, and the
> distribution is fairly even as I used random() without any tricks to shape the
> distribution. So, each value is roughly 1/60th of the total row count. Not
> realistic, but what I've got.
> 
> For this table, I built four different kind of index and tried each one out
> with a count(*) query on a single exact match. I also checked out the size of
> each index. 
> 
> Headline results:
> 
> Partial index: Smaller (as expeced), fast.
> B-tree index: Big, fast.
> GIN: Small, slow.
> Hash: Large, slow. ("Large" may be exaggerated in comparison with a B-tree
> because of my test data.)

You didn't post any times (or the queries you timed), so I don't know
what "fast" and "slow" mean.

I used your setup to time
select sum(num) from state_test where abbr = 'MA';
on my laptop (i5-7Y54, 16GB RAM, SSD, Pgsql 10.8) and here are the
results:

hjp=> select method, count(*),
min(time_ms),
avg(time_ms),
percentile_cont(0.5) within group (order by time_ms) as median,
max(time_ms)
from state_test_times
group by method
order by 5;

 method  | count |  min   |   avg   | median |  max   
-+---++-++
 Partial | 5 |   9.05 |  9.7724 |  9.185 | 12.151
 B tree  | 5 |  9.971 | 12.8036 | 10.226 |   21.6
 GIN | 5 |  9.542 | 10.3644 | 10.536 | 10.815
 Hash| 5 | 10.801 | 11.7448 | 11.047 | 14.875

All the times are pretty much the same. GIN is third by median, but the
difference is tiny, and it is secondy by minium and average and even
first by maximum.

In this case all the queries do a bitmap scan, so the times are probably
dominated by reading the heap, not the index.

> method    pg_table_size    kb
> Partial   401408    392 Kb
> B tree    22487040    21960 Kb
> GIN       1916928    1872 Kb
> Hash      49250304    48096 Kb

I get the same sizes.


> Okay, so the partial index is smaller, basically proportional to the fraction
> of the file it's indexing. So that makes sense, and is good to know.

Yeah. But to cover all values you would need 59 partial indexes, which
gets you back to the size of the full btree index. My test shows that it
might be faster, though, which might make the hassle of having to
maintain a large number of indexes worthwhile.

> The hash index size is...harder to explain...very big. Maybe my tiny
> strings? Not sure what size Postgres hashes to. A hash of a two
> character string is likely about worst-case.

I think that a hash index is generally a poor fit for low cardinality
indexes: You get a lot of equal values, which are basically hash
collisions. Unless the index is specifically designed to handle this
(e.g. by storing the key only once and then a tuple list per key, like a
GIN index does) it will balloon out trying to reduce the number of
collisions.

hp

-- 
   _  | Peter J. Holzer| we build much bigger, better disasters now
|_|_) || because we have much more sophisticated
| |   | h...@hjp.at | management tools.
__/   | http://www.hjp.at/ | -- Ross Anderson 


signature.asc
Description: PGP signature

Re: psql: FATAL: the database system is starting up

[Adrian Klaver]

On 5/31/19 7:53 PM, Tom K wrote:





There are two places to connect with the Patroni community: on github,
via Issues and PRs, and on channel #patroni in the PostgreSQL Slack. If
you're using Patroni, or just interested, please join us.


Will post there as well.  Thank you.  My thinking was to post here first 
since I suspect the Patroni community will simply refer me back here 
given that the PostgreSQL errors are originating directly from PostgreSQL.



That being said, can you start the copied Postgres instance without
using the Patroni instrumentation?


Yes, that is something I have been trying to do actually.  But I hit a 
dead end with the three errors above.


So what I did is to copy a single node's backed up copy of the data 
files to */data/patroni* of the same node ( this is the psql data 
directory as defined through patroni ) of the same node then ran this ( 
psql03 = 192.168.0.118 ):


# sudo su - postgres
$ /usr/pgsql-10/bin/postgres -D /data/patroni 
--config-file=/data/patroni/postgresql.conf 
--listen_addresses=192.168.0.118 --max_worker_processes=8 
--max_locks_per_transaction=64 --wal_level=replica 
--track_commit_timestamp=off --max_prepared_transactions=0 --port=5432 
--max_replication_slots=10 --max_connections=100 --hot_standby=on 
--cluster_name=postgres --wal_log_hints=on --max_wal_senders=10 -d 5


Why all the options?
That should be covered in postgresql.conf, no?



This resulted in one of the 3 messages above.  Hence the post here.  If 
I can start a single instance, I should be fine since I could then 1) 
replicate over to the other two or 2) simply take a dump, reinitialize 
all the databases then restore the dump.




What if you move the recovery.conf file out?

The below looks like missing/corrupted/incorrect files. Hard to tell 
without knowing what Patroni did?


Using the above procedure I get one of three error messages when using 
the data files of each node:


[ PSQL01 ]
postgres: postgres: startup process waiting for 00010008

[ PSQL02 ]
PANIC:replicationcheckpointhas wrong magic 0 instead of  307747550

[ PSQL03 }
FATAL:syntax error inhistory file:f2W

And I can't start any one of them.



 >
 > Thx,
 > TK
 >



-- 
Adrian Klaver

adrian.kla...@aklaver.com 




--
Adrian Klaver
adrian.kla...@aklaver.com

Re: psql: FATAL: the database system is starting up

[Tom K]

On Sat, Jun 1, 2019 at 9:55 AM Adrian Klaver 
wrote:

> On 5/31/19 7:53 PM, Tom K wrote:
> >
>
> > There are two places to connect with the Patroni community: on
> github,
> > via Issues and PRs, and on channel #patroni in the PostgreSQL Slack.
> If
> > you're using Patroni, or just interested, please join us.
> >
> >
> > Will post there as well.  Thank you.  My thinking was to post here first
> > since I suspect the Patroni community will simply refer me back here
> > given that the PostgreSQL errors are originating directly from
> PostgreSQL.
> >
> >
> > That being said, can you start the copied Postgres instance without
> > using the Patroni instrumentation?
> >
> >
> > Yes, that is something I have been trying to do actually.  But I hit a
> > dead end with the three errors above.
> >
> > So what I did is to copy a single node's backed up copy of the data
> > files to */data/patroni* of the same node ( this is the psql data
> > directory as defined through patroni ) of the same node then ran this (
> > psql03 = 192.168.0.118 ):
> >
> > # sudo su - postgres
> > $ /usr/pgsql-10/bin/postgres -D /data/patroni
> > --config-file=/data/patroni/postgresql.conf
> > --listen_addresses=192.168.0.118 --max_worker_processes=8
> > --max_locks_per_transaction=64 --wal_level=replica
> > --track_commit_timestamp=off --max_prepared_transactions=0 --port=5432
> > --max_replication_slots=10 --max_connections=100 --hot_standby=on
> > --cluster_name=postgres --wal_log_hints=on --max_wal_senders=10 -d 5
>
> Why all the options?
> That should be covered in postgresql.conf, no?
>
> >
> > This resulted in one of the 3 messages above.  Hence the post here.  If
> > I can start a single instance, I should be fine since I could then 1)
> > replicate over to the other two or 2) simply take a dump, reinitialize
> > all the databases then restore the dump.
> >
>
> What if you move the recovery.conf file out?


Will try.


>
> The below looks like missing/corrupted/incorrect files. Hard to tell
> without knowing what Patroni did?


Storage disappeared from underneath these clusters.  The OS was of course
still in memory making futile attempts to write to disk, which would never
complete.

My best guess is that Patroni or postgress was in the middle of some writes
across the clusters when the failure occurred.


>
> > Using the above procedure I get one of three error messages when using
> > the data files of each node:
> >
> > [ PSQL01 ]
> > postgres: postgres: startup process waiting for 00010008
> >
> > [ PSQL02 ]
> > PANIC:replicationcheckpointhas wrong magic 0 instead of  307747550
> >
> > [ PSQL03 }
> > FATAL:syntax error inhistory file:f2W
> >
> > And I can't start any one of them.
> >
> >
> >
> >  >
> >  > Thx,
> >  > TK
> >  >
> >
> >
> >
> > --
> > Adrian Klaver
> > adrian.kla...@aklaver.com 
> >
>
>
> --
> Adrian Klaver
> adrian.kla...@aklaver.com
>

Re: psql: FATAL: the database system is starting up

[Adrian Klaver]

On 6/1/19 12:32 PM, Tom K wrote:







What if you move the recovery.conf file out?


Will try.



The below looks like missing/corrupted/incorrect files. Hard to tell
without knowing what Patroni did?


Storage disappeared from underneath these clusters.  The OS was of 
course still in memory making futile attempts to write to disk, which 
would never complete.


My best guess is that Patroni or postgress was in the middle of some 
writes across the clusters when the failure occurred.


So to be clear all three clusters where writing to the same storage 
medium and there was no WAL archiving to some other storage?








--
Adrian Klaver
adrian.kla...@aklaver.com

Re: psql: FATAL: the database system is starting up

[Tom K]

On Sat, Jun 1, 2019 at 3:32 PM Tom K  wrote:

>
>
> On Sat, Jun 1, 2019 at 9:55 AM Adrian Klaver 
> wrote:
>
>> On 5/31/19 7:53 PM, Tom K wrote:
>> >
>>
>> > There are two places to connect with the Patroni community: on
>> github,
>> > via Issues and PRs, and on channel #patroni in the PostgreSQL
>> Slack. If
>> > you're using Patroni, or just interested, please join us.
>> >
>> >
>> > Will post there as well.  Thank you.  My thinking was to post here
>> first
>> > since I suspect the Patroni community will simply refer me back here
>> > given that the PostgreSQL errors are originating directly from
>> PostgreSQL.
>> >
>> >
>> > That being said, can you start the copied Postgres instance without
>> > using the Patroni instrumentation?
>> >
>> >
>> > Yes, that is something I have been trying to do actually.  But I hit a
>> > dead end with the three errors above.
>> >
>> > So what I did is to copy a single node's backed up copy of the data
>> > files to */data/patroni* of the same node ( this is the psql data
>> > directory as defined through patroni ) of the same node then ran this (
>> > psql03 = 192.168.0.118 ):
>> >
>> > # sudo su - postgres
>> > $ /usr/pgsql-10/bin/postgres -D /data/patroni
>> > --config-file=/data/patroni/postgresql.conf
>> > --listen_addresses=192.168.0.118 --max_worker_processes=8
>> > --max_locks_per_transaction=64 --wal_level=replica
>> > --track_commit_timestamp=off --max_prepared_transactions=0 --port=5432
>> > --max_replication_slots=10 --max_connections=100 --hot_standby=on
>> > --cluster_name=postgres --wal_log_hints=on --max_wal_senders=10 -d 5
>>
>> Why all the options?
>> That should be covered in postgresql.conf, no?
>>
>> >
>> > This resulted in one of the 3 messages above.  Hence the post here.  If
>> > I can start a single instance, I should be fine since I could then 1)
>> > replicate over to the other two or 2) simply take a dump, reinitialize
>> > all the databases then restore the dump.
>> >
>>
>> What if you move the recovery.conf file out?
>
>
> Will try.
>
>
>>
>> The below looks like missing/corrupted/incorrect files. Hard to tell
>> without knowing what Patroni did?
>
>
> Storage disappeared from underneath these clusters.  The OS was of course
> still in memory making futile attempts to write to disk, which would never
> complete.
>
> My best guess is that Patroni or postgress was in the middle of some
> writes across the clusters when the failure occurred.
>

Of note are the characters f2W below.  I see nothing in the postgres source
code to indicate this is any recognizable postgres message.  A part of me
suspects that the postgres binaries got corrupted.   Had this case occur
with glib-common and a reinstall fixed it.  However the postgres binaries
csum matches a standalone install perfectly so that should not be an issue.



>
>>
>> > Using the above procedure I get one of three error messages when using
>> > the data files of each node:
>> >
>> > [ PSQL01 ]
>> > postgres: postgres: startup process waiting for 00010008
>> >
>> > [ PSQL02 ]
>> > PANIC:replicationcheckpointhas wrong magic 0 instead of  307747550
>> >
>> > [ PSQL03 }
>> > FATAL:syntax error inhistory file:f2W
>> >
>> > And I can't start any one of them.
>> >
>> >
>> >
>> >  >
>> >  > Thx,
>> >  > TK
>> >  >
>> >
>> >
>> >
>> > --
>> > Adrian Klaver
>> > adrian.kla...@aklaver.com 
>> >
>>
>>
>> --
>> Adrian Klaver
>> adrian.kla...@aklaver.com
>>
>

Re: psql: FATAL: the database system is starting up

[Adrian Klaver]

On 6/1/19 12:42 PM, Tom K wrote:







Of note are the characters f2W below.  I see nothing in the postgres 
source code to indicate this is any recognizable postgres message.  A 
part of me suspects that the postgres binaries got corrupted.   Had this 
case occur with glib-common and a reinstall fixed it.  However the 
postgres binaries csum matches a standalone install perfectly so that 
should not be an issue.


It comes from timeline.c:

https://doxygen.postgresql.org/bin_2pg__rewind_2timeline_8c.html

pg_log_error("syntax error in history file: %s", fline);

...

There should be another error message after the above.


--
Adrian Klaver
adrian.kla...@aklaver.com

Re: psql: FATAL: the database system is starting up

[Tom K]

On Sat, Jun 1, 2019 at 4:11 PM Adrian Klaver 
wrote:

> On 6/1/19 12:32 PM, Tom K wrote:
> >
> >
>
> >
> > What if you move the recovery.conf file out?
> >
> >
> > Will try.
> >
> >
> >
> > The below looks like missing/corrupted/incorrect files. Hard to tell
> > without knowing what Patroni did?
> >
> >
> > Storage disappeared from underneath these clusters.  The OS was of
> > course still in memory making futile attempts to write to disk, which
> > would never complete.
> >
> > My best guess is that Patroni or postgress was in the middle of some
> > writes across the clusters when the failure occurred.
>
> So to be clear all three clusters where writing to the same storage
> medium and there was no WAL archiving to some other storage?


Yep, cheap LAB hardware with no power redundancy ( yet ) .


>
> >
> >
>
>
> --
> Adrian Klaver
> adrian.kla...@aklaver.com
>

Re: psql: FATAL: the database system is starting up

[Adrian Klaver]

On 6/1/19 2:08 PM, Tom K wrote:







Yep, cheap LAB hardware with no power redundancy ( yet ) .


I don't suppose a pg_dump was done anytime recently?


--
Adrian Klaver
adrian.kla...@aklaver.com

Re: psql: FATAL: the database system is starting up

[Tom K]

On Sat, Jun 1, 2019 at 4:52 PM Adrian Klaver 
wrote:

> On 6/1/19 12:42 PM, Tom K wrote:
> >
> >
>
> >
> > Of note are the characters f2W below.  I see nothing in the postgres
> > source code to indicate this is any recognizable postgres message.  A
> > part of me suspects that the postgres binaries got corrupted.   Had this
> > case occur with glib-common and a reinstall fixed it.  However the
> > postgres binaries csum matches a standalone install perfectly so that
> > should not be an issue.
>
> It comes from timeline.c:
>
> https://doxygen.postgresql.org/bin_2pg__rewind_2timeline_8c.html
>
> pg_log_error("syntax error in history file: %s", fline);
>
> ...
>
> There should be another error message after the above.
>

Nope.  Here's the full set of lines in the postgres logs when running the
above line:

2019-06-01 17:13:03.261 EDT [14909] LOG:  database system was shut down at
2019-05-22 01:55:13 EDT
2019-06-01 17:13:03.261 EDT [14909] DEBUG:  primary_slot_name =
'postgresql2'
2019-06-01 17:13:03.261 EDT [14909] DEBUG:  standby_mode = 'on'
2019-06-01 17:13:03.261 EDT [14909] DEBUG:  recovery_target_timeline =
latest
2019-06-01 17:13:03.261 EDT [14909] WARNING:  recovery command file
"recovery.conf" specified neither primary_conninfo nor restore_command
2019-06-01 17:13:03.261 EDT [14909] HINT:  The database server will
regularly poll the pg_wal subdirectory to check for files placed there.
2019-06-01 17:13:03.263 EDT [14909] LOG:  entering standby mode
2019-06-01 17:13:03.263 EDT [14909] FATAL:  syntax error in history file:
f2W
2019-06-01 17:13:03.263 EDT [14909] HINT:  Expected a numeric timeline ID.
2019-06-01 17:13:03.263 EDT [14909] DEBUG:  shmem_exit(1): 1
before_shmem_exit callbacks to make
2019-06-01 17:13:03.263 EDT [14909] DEBUG:  shmem_exit(1): 4 on_shmem_exit
callbacks to make
2019-06-01 17:13:03.263 EDT [14909] DEBUG:  proc_exit(1): 2 callbacks to
make
2019-06-01 17:13:03.263 EDT [14909] DEBUG:  exit(1)
2019-06-01 17:13:03.264 EDT [14909] DEBUG:  shmem_exit(-1): 0
before_shmem_exit callbacks to make
2019-06-01 17:13:03.264 EDT [14909] DEBUG:  shmem_exit(-1): 0 on_shmem_exit
callbacks to make
2019-06-01 17:13:03.264 EDT [14909] DEBUG:  proc_exit(-1): 0 callbacks to
make
2019-06-01 17:13:03.265 EDT [14907] DEBUG:  reaping dead processes
2019-06-01 17:13:03.265 EDT [14907] LOG:  startup process (PID 14909)
exited with exit code 1
2019-06-01 17:13:03.265 EDT [14907] LOG:  aborting startup due to startup
process failure
2019-06-01 17:13:03.265 EDT [14907] DEBUG:  shmem_exit(1): 0
before_shmem_exit callbacks to make
2019-06-01 17:13:03.266 EDT [14907] DEBUG:  shmem_exit(1): 5 on_shmem_exit
callbacks to make
2019-06-01 17:13:03.266 EDT [14907] DEBUG:  cleaning up dynamic shared
memory control segment with ID 1669075945
2019-06-01 17:13:03.268 EDT [14907] DEBUG:  proc_exit(1): 2 callbacks to
make
2019-06-01 17:13:03.268 EDT [14907] LOG:  database system is shut down
2019-06-01 17:13:03.268 EDT [14907] DEBUG:  exit(1)
2019-06-01 17:13:03.268 EDT [14907] DEBUG:  shmem_exit(-1): 0
before_shmem_exit callbacks to make
2019-06-01 17:13:03.268 EDT [14907] DEBUG:  shmem_exit(-1): 0 on_shmem_exit
callbacks to make
2019-06-01 17:13:03.268 EDT [14907] DEBUG:  proc_exit(-1): 0 callbacks to
make
2019-06-01 17:13:03.270 EDT [14908] DEBUG:  logger shutting down
2019-06-01 17:13:03.270 EDT [14908] DEBUG:  shmem_exit(0): 0
before_shmem_exit callbacks to make
2019-06-01 17:13:03.270 EDT [14908] DEBUG:  shmem_exit(0): 0 on_shmem_exit
callbacks to make
2019-06-01 17:13:03.270 EDT [14908] DEBUG:  proc_exit(0): 0 callbacks to
make
2019-06-01 17:13:03.270 EDT [14908] DEBUG:  exit(0)
2019-06-01 17:13:03.270 EDT [14908] DEBUG:  shmem_exit(-1): 0
before_shmem_exit callbacks to make
2019-06-01 17:13:03.270 EDT [14908] DEBUG:  shmem_exit(-1): 0 on_shmem_exit
callbacks to make
2019-06-01 17:13:03.270 EDT [14908] DEBUG:  proc_exit(-1): 0 callbacks to
make
^C
-bash-4.2$

What's interesting is that f2W isn't a string you'd expect to be printed as
part of the code logic   ( I mean, what is f2W? ).

postgresql10-server-10.8-1PGDG.rhel7.x86_64
postgresql10-libs-10.8-1PGDG.rhel7.x86_64
postgresql10-contrib-10.8-1PGDG.rhel7.x86_64
postgresql10-10.8-1PGDG.rhel7.x86_64

Without the recovery.conf file it actually started up.  Going to try to get
a dump then continue to try and recover in place.

2019-06-01 17:17:29.777 EDT [14936] DEBUG:  StartTransaction(1) name:
unnamed; blockState: DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0
2019-06-01 17:17:29.777 EDT [14936] DEBUG:  CommitTransaction(1) name:
unnamed; blockState: STARTED; state: INPROGR, xid/subid/cid: 0/1/0
2019-06-01 17:17:29.778 EDT [14937] DEBUG:  received inquiry for database 0
2019-06-01 17:17:29.778 EDT [14937] DEBUG:  writing stats file
"pg_stat_tmp/global.stat"
2019-06-01 17:17:29.779 EDT [14937] DEBUG:  writing stats file
"pg_stat_tmp/db_0.stat"
2019-06-01 17:17:29.790 EDT [15013] DEBUG:  InitPostgres
2019-06-01 17:17:29.790 EDT [15013] DEBUG:  my backend ID is 3
2019-06-

Re: psql: FATAL: the database system is starting up

[Tom K]

On Sat, Jun 1, 2019 at 5:30 PM Tom K  wrote:

>
>
> On Sat, Jun 1, 2019 at 4:52 PM Adrian Klaver 
> wrote:
>
>> On 6/1/19 12:42 PM, Tom K wrote:
>> >
>> >
>>
>> >
>> > Of note are the characters f2W below.  I see nothing in the postgres
>> > source code to indicate this is any recognizable postgres message.  A
>> > part of me suspects that the postgres binaries got corrupted.   Had
>> this
>> > case occur with glib-common and a reinstall fixed it.  However the
>> > postgres binaries csum matches a standalone install perfectly so that
>> > should not be an issue.
>>
>> It comes from timeline.c:
>>
>> https://doxygen.postgresql.org/bin_2pg__rewind_2timeline_8c.html
>>
>> pg_log_error("syntax error in history file: %s", fline);
>>
>> ...
>>
>> There should be another error message after the above.
>>
>
> Nope.  Here's the full set of lines in the postgres logs when running the
> above line:
>
> 2019-06-01 17:13:03.261 EDT [14909] LOG:  database system was shut down at
> 2019-05-22 01:55:13 EDT
> 2019-06-01 17:13:03.261 EDT [14909] DEBUG:  primary_slot_name =
> 'postgresql2'
> 2019-06-01 17:13:03.261 EDT [14909] DEBUG:  standby_mode = 'on'
> 2019-06-01 17:13:03.261 EDT [14909] DEBUG:  recovery_target_timeline =
> latest
> 2019-06-01 17:13:03.261 EDT [14909] WARNING:  recovery command file
> "recovery.conf" specified neither primary_conninfo nor restore_command
> 2019-06-01 17:13:03.261 EDT [14909] HINT:  The database server will
> regularly poll the pg_wal subdirectory to check for files placed there.
> 2019-06-01 17:13:03.263 EDT [14909] LOG:  entering standby mode
> 2019-06-01 17:13:03.263 EDT [14909] FATAL:  syntax error in history file:
> f2W
> 2019-06-01 17:13:03.263 EDT [14909] HINT:  Expected a numeric timeline ID.
> 2019-06-01 17:13:03.263 EDT [14909] DEBUG:  shmem_exit(1): 1
> before_shmem_exit callbacks to make
> 2019-06-01 17:13:03.263 EDT [14909] DEBUG:  shmem_exit(1): 4 on_shmem_exit
> callbacks to make
> 2019-06-01 17:13:03.263 EDT [14909] DEBUG:  proc_exit(1): 2 callbacks to
> make
> 2019-06-01 17:13:03.263 EDT [14909] DEBUG:  exit(1)
> 2019-06-01 17:13:03.264 EDT [14909] DEBUG:  shmem_exit(-1): 0
> before_shmem_exit callbacks to make
> 2019-06-01 17:13:03.264 EDT [14909] DEBUG:  shmem_exit(-1): 0
> on_shmem_exit callbacks to make
> 2019-06-01 17:13:03.264 EDT [14909] DEBUG:  proc_exit(-1): 0 callbacks to
> make
> 2019-06-01 17:13:03.265 EDT [14907] DEBUG:  reaping dead processes
> 2019-06-01 17:13:03.265 EDT [14907] LOG:  startup process (PID 14909)
> exited with exit code 1
> 2019-06-01 17:13:03.265 EDT [14907] LOG:  aborting startup due to startup
> process failure
> 2019-06-01 17:13:03.265 EDT [14907] DEBUG:  shmem_exit(1): 0
> before_shmem_exit callbacks to make
> 2019-06-01 17:13:03.266 EDT [14907] DEBUG:  shmem_exit(1): 5 on_shmem_exit
> callbacks to make
> 2019-06-01 17:13:03.266 EDT [14907] DEBUG:  cleaning up dynamic shared
> memory control segment with ID 1669075945
> 2019-06-01 17:13:03.268 EDT [14907] DEBUG:  proc_exit(1): 2 callbacks to
> make
> 2019-06-01 17:13:03.268 EDT [14907] LOG:  database system is shut down
> 2019-06-01 17:13:03.268 EDT [14907] DEBUG:  exit(1)
> 2019-06-01 17:13:03.268 EDT [14907] DEBUG:  shmem_exit(-1): 0
> before_shmem_exit callbacks to make
> 2019-06-01 17:13:03.268 EDT [14907] DEBUG:  shmem_exit(-1): 0
> on_shmem_exit callbacks to make
> 2019-06-01 17:13:03.268 EDT [14907] DEBUG:  proc_exit(-1): 0 callbacks to
> make
> 2019-06-01 17:13:03.270 EDT [14908] DEBUG:  logger shutting down
> 2019-06-01 17:13:03.270 EDT [14908] DEBUG:  shmem_exit(0): 0
> before_shmem_exit callbacks to make
> 2019-06-01 17:13:03.270 EDT [14908] DEBUG:  shmem_exit(0): 0 on_shmem_exit
> callbacks to make
> 2019-06-01 17:13:03.270 EDT [14908] DEBUG:  proc_exit(0): 0 callbacks to
> make
> 2019-06-01 17:13:03.270 EDT [14908] DEBUG:  exit(0)
> 2019-06-01 17:13:03.270 EDT [14908] DEBUG:  shmem_exit(-1): 0
> before_shmem_exit callbacks to make
> 2019-06-01 17:13:03.270 EDT [14908] DEBUG:  shmem_exit(-1): 0
> on_shmem_exit callbacks to make
> 2019-06-01 17:13:03.270 EDT [14908] DEBUG:  proc_exit(-1): 0 callbacks to
> make
> ^C
> -bash-4.2$
>
> What's interesting is that f2W isn't a string you'd expect to be printed
> as part of the code logic   ( I mean, what is f2W? ).
>
> postgresql10-server-10.8-1PGDG.rhel7.x86_64
> postgresql10-libs-10.8-1PGDG.rhel7.x86_64
> postgresql10-contrib-10.8-1PGDG.rhel7.x86_64
> postgresql10-10.8-1PGDG.rhel7.x86_64
>
> Without the recovery.conf file it actually started up.  Going to try to
> get a dump then continue to try and recover in place.
>
> 2019-06-01 17:17:29.777 EDT [14936] DEBUG:  StartTransaction(1) name:
> unnamed; blockState: DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0
> 2019-06-01 17:17:29.777 EDT [14936] DEBUG:  CommitTransaction(1) name:
> unnamed; blockState: STARTED; state: INPROGR, xid/subid/cid: 0/1/0
> 2019-06-01 17:17:29.778 EDT [14937] DEBUG:  received inquiry for database 0
> 2019-06-01 17:17:29.778 EDT [14937] DEBUG:  writing stat

Re: psql: FATAL: the database system is starting up

[Adrian Klaver]

On 6/1/19 2:30 PM, Tom K wrote:



On Sat, Jun 1, 2019 at 4:52 PM Adrian Klaver > wrote:


On 6/1/19 12:42 PM, Tom K wrote:
 >
 >

 >
 > Of note are the characters f2W below.  I see nothing in the postgres
 > source code to indicate this is any recognizable postgres
message.  A
 > part of me suspects that the postgres binaries got corrupted.  
Had this

 > case occur with glib-common and a reinstall fixed it.  However the
 > postgres binaries csum matches a standalone install perfectly so
that
 > should not be an issue.

It comes from timeline.c:

https://doxygen.postgresql.org/bin_2pg__rewind_2timeline_8c.html

pg_log_error("syntax error in history file: %s", fline);

...

There should be another error message after the above.


Nope.  Here's the full set of lines in the postgres logs when running 
the above line:




2019-06-01 17:13:03.263 EDT [14909] FATAL:  syntax error in history 
file: f2W

2019-06-01 17:13:03.263 EDT [14909] HINT:  Expected a numeric timeline ID.


Actually the above HINT is what I was looking for.


^C
-bash-4.2$

What's interesting is that f2W isn't a string you'd expect to be printed 
as part of the code logic   ( I mean, what is f2W? ).


As the HINT said neither was Postgres. That is probably down to file 
corruption.





The point of the POC and the LAB is to test these things across failures 
as well as various configurations.  To that end, I'm just as curious how 
to recover from these error conditions as I am just getting things to work.


I think what it proved was that a single point of failure is not good 
and that there needs to be steps taken to prevent or deal with it e.g. 
second location backup of some sort.







-- 
Adrian Klaver

adrian.kla...@aklaver.com 




--
Adrian Klaver
adrian.kla...@aklaver.com

Re: psql: FATAL: the database system is starting up

[Adrian Klaver]

On 6/1/19 2:31 PM, Tom K wrote:







Spoke too soon.  There's no tables when it's started without the 
recovery.conf file.


Where there any errors in the start up?

Are there databases in the clusters system(template1, postgres, etc) or 
user?


Did you start against the correct PG_DATA directory?





--
Adrian Klaver
adrian.kla...@aklaver.com

Re: psql: FATAL: the database system is starting up

[Tom K]

On Sat, Jun 1, 2019 at 5:51 PM Adrian Klaver 
wrote:

> On 6/1/19 2:31 PM, Tom K wrote:
> >
> >
>
> >
> > Spoke too soon.  There's no tables when it's started without the
> > recovery.conf file.
>
> Where there any errors in the start up?
>

Nothing I would discern as a startup error:

[root@psql03 patroni]# sudo su - postgres
Last login: Sat Jun  1 17:30:31 EDT 2019 on pts/1
-bash-4.2$ /usr/pgsql-10/bin/postgres -D /data/patroni
--config-file=/data/patroni/postgresql.conf
--listen_addresses=192.168.0.118 --max_worker_processes=8
--max_locks_per_transaction=64 --wal_level=replica
--track_commit_timestamp=off --max_prepared_transactions=0 --port=5432
--max_replication_slots=10 --max_connections=100 --hot_standby=on
--cluster_name=postgres --wal_log_hints=on --max_wal_senders=10 -d 5
2019-06-01 17:41:27.477 EDT [15209] DEBUG:  postgres: PostmasterMain:
initial environment dump:
2019-06-01 17:41:27.477 EDT [15209] DEBUG:
 -
2019-06-01 17:41:27.477 EDT [15209] DEBUG:  XDG_SESSION_ID=219
2019-06-01 17:41:27.477 EDT [15209] DEBUG:  HOSTNAME=psql03.nix.mds.xyz
2019-06-01 17:41:27.477 EDT [15209] DEBUG:  SHELL=/bin/bash
2019-06-01 17:41:27.477 EDT [15209] DEBUG:  TERM=xterm
2019-06-01 17:41:27.477 EDT [15209] DEBUG:  HISTSIZE=1000
2019-06-01 17:41:27.477 EDT [15209] DEBUG:  USER=postgres
2019-06-01 17:41:27.477 EDT [15209] DEBUG:
 
LS_COLORS=rs=0:di=01;34:ln=01;36:mh=00:pi=40;33:so=01;35:do=01;35:bd=40;33;01:cd=40;33;01:or=40;31;01:mi=01;05;37;41:su=37;41:sg=30;43:ca=30;41:tw=30;42:ow=34;42:st=37;44:ex=01;32:*.tar=01;31:*.tgz=01;31:*.arc=01;31:*.arj=01;31:*.taz=01;31:*.lha=01;31:*.lz4=01;31:*.lzh=01;31:*.lzma=01;31:*.tlz=01;31:*.txz=01;31:*.tzo=01;31:*.t7z=01;31:*.zip=01;31:*.z=01;31:*.Z=01;31:*.dz=01;31:*.gz=01;31:*.lrz=01;31:*.lz=01;31:*.lzo=01;31:*.xz=01;31:*.bz2=01;31:*.bz=01;31:*.tbz=01;31:*.tbz2=01;31:*.tz=01;31:*.deb=01;31:*.rpm=01;31:*.jar=01;31:*.war=01;31:*.ear=01;31:*.sar=01;31:*.rar=01;31:*.alz=01;31:*.ace=01;31:*.zoo=01;31:*.cpio=01;31:*.7z=01;31:*.rz=01;31:*.cab=01;31:*.jpg=01;35:*.jpeg=01;35:*.gif=01;35:*.bmp=01;35:*.pbm=01;35:*.pgm=01;35:*.ppm=01;35:*.tga=01;35:*.xbm=01;35:*.xpm=01;35:*.tif=01;35:*.tiff=01;35:*.png=01;35:*.svg=01;35:*.svgz=01;35:*.mng=01;35:*.pcx=01;35:*.mov=01;35:*.mpg=01;35:*.mpeg=01;35:*.m2v=01;35:*.mkv=01;35:*.webm=01;35:*.ogm=01;35:*.mp4=01;35:*.m4v=01;35:*.mp4v=01;35:*.vob=01;35:*.qt=01;35:*.nuv=01;35:*.wmv=01;35:*.asf=01;35:*.rm=01;35:*.rmvb=01;35:*.flc=01;35:*.avi=01;35:*.fli=01;35:*.flv=01;35:*.gl=01;35:*.dl=01;35:*.xcf=01;35:*.xwd=01;35:*.yuv=01;35:*.cgm=01;35:*.emf=01;35:*.axv=01;35:*.anx=01;35:*.ogv=01;35:*.ogx=01;35:*.aac=01;36:*.au=01;36:*.flac=01;36:*.mid=01;36:*.midi=01;36:*.mka=01;36:*.mp3=01;36:*.mpc=01;36:*.ogg=01;36:*.ra=01;36:*.wav=01;36:*.axa=01;36:*.oga=01;36:*.spx=01;36:*.xspf=01;36:
2019-06-01 17:41:27.477 EDT [15209] DEBUG:
 MAIL=/var/spool/mail/postgres
2019-06-01 17:41:27.477 EDT [15209] DEBUG:
 PATH=/usr/local/bin:/bin:/usr/bin:/usr/local/sbin:/usr/sbin:/usr/pgsql-10/bin/
2019-06-01 17:41:27.477 EDT [15209] DEBUG:  PWD=/var/lib/pgsql
2019-06-01 17:41:27.477 EDT [15209] DEBUG:  LANG=en_US.UTF-8
2019-06-01 17:41:27.477 EDT [15209] DEBUG:  HISTCONTROL=ignoredups
2019-06-01 17:41:27.477 EDT [15209] DEBUG:  SHLVL=1
2019-06-01 17:41:27.477 EDT [15209] DEBUG:  HOME=/var/lib/pgsql
2019-06-01 17:41:27.477 EDT [15209] DEBUG:  LOGNAME=postgres
2019-06-01 17:41:27.478 EDT [15209] DEBUG:
 PGDATA=/var/lib/pgsql/10/data
2019-06-01 17:41:27.478 EDT [15209] DEBUG:
 LESSOPEN=||/usr/bin/lesspipe.sh %s
2019-06-01 17:41:27.478 EDT [15209] DEBUG:  _=/usr/pgsql-10/bin/postgres
2019-06-01 17:41:27.478 EDT [15209] DEBUG:
 PGLOCALEDIR=/usr/pgsql-10/share/locale
2019-06-01 17:41:27.478 EDT [15209] DEBUG:
 PGSYSCONFDIR=/etc/sysconfig/pgsql
2019-06-01 17:41:27.478 EDT [15209] DEBUG:  LC_COLLATE=en_US.UTF-8
2019-06-01 17:41:27.478 EDT [15209] DEBUG:  LC_CTYPE=en_US.UTF-8
2019-06-01 17:41:27.478 EDT [15209] DEBUG:  LC_MESSAGES=en_US.UTF-8
2019-06-01 17:41:27.478 EDT [15209] DEBUG:  LC_MONETARY=C
2019-06-01 17:41:27.478 EDT [15209] DEBUG:  LC_NUMERIC=C
2019-06-01 17:41:27.478 EDT [15209] DEBUG:  LC_TIME=C
2019-06-01 17:41:27.478 EDT [15209] DEBUG:
 -
2019-06-01 17:41:27.494 EDT [15209] DEBUG:  registering background worker
"logical replication launcher"
2019-06-01 17:41:27.495 EDT [15209] LOG:  listening on IPv4 address
"192.168.0.118", port 5432
2019-06-01 17:41:27.498 EDT [15209] LOG:  listening on Unix socket
"./.s.PGSQL.5432"
2019-06-01 17:41:27.499 EDT [15209] DEBUG:  invoking
IpcMemoryCreate(size=148545536)
2019-06-01 17:41:27.499 EDT [15209] DEBUG:  mmap(148897792) with
MAP_HUGETLB failed, huge pages disabled: Cannot allocate memory
2019-06-01 17:41:27.514 EDT [15209] DEBUG:  SlruScanDirectory invoking
callback on pg_notify/
2019-06-01 17:41:27.514 EDT [15209] DEBUG:  removing file "pg_notify/"
2019-06-01 17:41:27.51

Re: psql: FATAL: the database system is starting up

[Tom K]

On Sat, Jun 1, 2019 at 6:05 PM Tom K  wrote:

>
>
> On Sat, Jun 1, 2019 at 5:51 PM Adrian Klaver 
> wrote:
>
>> On 6/1/19 2:31 PM, Tom K wrote:
>> >
>> >
>>
>> >
>> > Spoke too soon.  There's no tables when it's started without the
>> > recovery.conf file.
>>
>> Where there any errors in the start up?
>>
>
> Nothing I would discern as a startup error:
>
> [root@psql03 patroni]# sudo su - postgres
> Last login: Sat Jun  1 17:30:31 EDT 2019 on pts/1
> -bash-4.2$ /usr/pgsql-10/bin/postgres -D /data/patroni
> --config-file=/data/patroni/postgresql.conf
> --listen_addresses=192.168.0.118 --max_worker_processes=8
> --max_locks_per_transaction=64 --wal_level=replica
> --track_commit_timestamp=off --max_prepared_transactions=0 --port=5432
> --max_replication_slots=10 --max_connections=100 --hot_standby=on
> --cluster_name=postgres --wal_log_hints=on --max_wal_senders=10 -d 5
> 2019-06-01 17:41:27.477 EDT [15209] DEBUG:  postgres: PostmasterMain:
> initial environment dump:
> 2019-06-01 17:41:27.477 EDT [15209] DEBUG:
>  -
> 2019-06-01 17:41:27.477 EDT [15209] DEBUG:  XDG_SESSION_ID=219
> 2019-06-01 17:41:27.477 EDT [15209] DEBUG:  HOSTNAME=
> psql03.nix.mds.xyz
> 2019-06-01 17:41:27.477 EDT [15209] DEBUG:  SHELL=/bin/bash
> 2019-06-01 17:41:27.477 EDT [15209] DEBUG:  TERM=xterm
> 2019-06-01 17:41:27.477 EDT [15209] DEBUG:  HISTSIZE=1000
> 2019-06-01 17:41:27.477 EDT [15209] DEBUG:  USER=postgres
> 2019-06-01 17:41:27.477 EDT [15209] DEBUG:
>  
> LS_COLORS=rs=0:di=01;34:ln=01;36:mh=00:pi=40;33:so=01;35:do=01;35:bd=40;33;01:cd=40;33;01:or=40;31;01:mi=01;05;37;41:su=37;41:sg=30;43:ca=30;41:tw=30;42:ow=34;42:st=37;44:ex=01;32:*.tar=01;31:*.tgz=01;31:*.arc=01;31:*.arj=01;31:*.taz=01;31:*.lha=01;31:*.lz4=01;31:*.lzh=01;31:*.lzma=01;31:*.tlz=01;31:*.txz=01;31:*.tzo=01;31:*.t7z=01;31:*.zip=01;31:*.z=01;31:*.Z=01;31:*.dz=01;31:*.gz=01;31:*.lrz=01;31:*.lz=01;31:*.lzo=01;31:*.xz=01;31:*.bz2=01;31:*.bz=01;31:*.tbz=01;31:*.tbz2=01;31:*.tz=01;31:*.deb=01;31:*.rpm=01;31:*.jar=01;31:*.war=01;31:*.ear=01;31:*.sar=01;31:*.rar=01;31:*.alz=01;31:*.ace=01;31:*.zoo=01;31:*.cpio=01;31:*.7z=01;31:*.rz=01;31:*.cab=01;31:*.jpg=01;35:*.jpeg=01;35:*.gif=01;35:*.bmp=01;35:*.pbm=01;35:*.pgm=01;35:*.ppm=01;35:*.tga=01;35:*.xbm=01;35:*.xpm=01;35:*.tif=01;35:*.tiff=01;35:*.png=01;35:*.svg=01;35:*.svgz=01;35:*.mng=01;35:*.pcx=01;35:*.mov=01;35:*.mpg=01;35:*.mpeg=01;35:*.m2v=01;35:*.mkv=01;35:*.webm=01;35:*.ogm=01;35:*.mp4=01;35:*.m4v=01;35:*.mp4v=01;35:*.vob=01;35:*.qt=01;35:*.nuv=01;35:*.wmv=01;35:*.asf=01;35:*.rm=01;35:*.rmvb=01;35:*.flc=01;35:*.avi=01;35:*.fli=01;35:*.flv=01;35:*.gl=01;35:*.dl=01;35:*.xcf=01;35:*.xwd=01;35:*.yuv=01;35:*.cgm=01;35:*.emf=01;35:*.axv=01;35:*.anx=01;35:*.ogv=01;35:*.ogx=01;35:*.aac=01;36:*.au=01;36:*.flac=01;36:*.mid=01;36:*.midi=01;36:*.mka=01;36:*.mp3=01;36:*.mpc=01;36:*.ogg=01;36:*.ra=01;36:*.wav=01;36:*.axa=01;36:*.oga=01;36:*.spx=01;36:*.xspf=01;36:
> 2019-06-01 17:41:27.477 EDT [15209] DEBUG:
>  MAIL=/var/spool/mail/postgres
> 2019-06-01 17:41:27.477 EDT [15209] DEBUG:
>  
> PATH=/usr/local/bin:/bin:/usr/bin:/usr/local/sbin:/usr/sbin:/usr/pgsql-10/bin/
> 2019-06-01 17:41:27.477 EDT [15209] DEBUG:  PWD=/var/lib/pgsql
> 2019-06-01 17:41:27.477 EDT [15209] DEBUG:  LANG=en_US.UTF-8
> 2019-06-01 17:41:27.477 EDT [15209] DEBUG:  HISTCONTROL=ignoredups
> 2019-06-01 17:41:27.477 EDT [15209] DEBUG:  SHLVL=1
> 2019-06-01 17:41:27.477 EDT [15209] DEBUG:  HOME=/var/lib/pgsql
> 2019-06-01 17:41:27.477 EDT [15209] DEBUG:  LOGNAME=postgres
> 2019-06-01 17:41:27.478 EDT [15209] DEBUG:
>  PGDATA=/var/lib/pgsql/10/data
> 2019-06-01 17:41:27.478 EDT [15209] DEBUG:
>  LESSOPEN=||/usr/bin/lesspipe.sh %s
> 2019-06-01 17:41:27.478 EDT [15209] DEBUG:
>  _=/usr/pgsql-10/bin/postgres
> 2019-06-01 17:41:27.478 EDT [15209] DEBUG:
>  PGLOCALEDIR=/usr/pgsql-10/share/locale
> 2019-06-01 17:41:27.478 EDT [15209] DEBUG:
>  PGSYSCONFDIR=/etc/sysconfig/pgsql
> 2019-06-01 17:41:27.478 EDT [15209] DEBUG:  LC_COLLATE=en_US.UTF-8
> 2019-06-01 17:41:27.478 EDT [15209] DEBUG:  LC_CTYPE=en_US.UTF-8
> 2019-06-01 17:41:27.478 EDT [15209] DEBUG:  LC_MESSAGES=en_US.UTF-8
> 2019-06-01 17:41:27.478 EDT [15209] DEBUG:  LC_MONETARY=C
> 2019-06-01 17:41:27.478 EDT [15209] DEBUG:  LC_NUMERIC=C
> 2019-06-01 17:41:27.478 EDT [15209] DEBUG:  LC_TIME=C
> 2019-06-01 17:41:27.478 EDT [15209] DEBUG:
>  -
> 2019-06-01 17:41:27.494 EDT [15209] DEBUG:  registering background worker
> "logical replication launcher"
> 2019-06-01 17:41:27.495 EDT [15209] LOG:  listening on IPv4 address
> "192.168.0.118", port 5432
> 2019-06-01 17:41:27.498 EDT [15209] LOG:  listening on Unix socket
> "./.s.PGSQL.5432"
> 2019-06-01 17:41:27.499 EDT [15209] DEBUG:  invoking
> IpcMemoryCreate(size=148545536)
> 2019-06-01 17:41:27.499 EDT [15209] DEBUG:  mmap(148897792) with
> MAP_HUGETLB failed, huge pages disabled: Cannot allocate memory
> 20

Re: psql: FATAL: the database system is starting up

[Adrian Klaver]

On 6/1/19 3:14 PM, Tom K wrote:





** Correction.  There is postgres, template1 and template2 but none of 
the other databases we had.


In a psql session do:

select oid, datname from pg_database ;

Then go to /data/patroni an drill down to the base directory. In that 
directory there should be sub-directories with numbers equal to the oid 
values from the query. If not then something is wrong. That could be:


1) Wrong data directory.

2) Copied over incorrect data directory.

Basically if the only sub-directories are for the system databases then 
the user databases do not exist. You might want to look at some of the 
other clusters to see what is there.




--
Adrian Klaver
adrian.kla...@aklaver.com

Re: psql: FATAL: the database system is starting up

[Adrian Klaver]

On 6/1/19 3:14 PM, Tom K wrote:



** Correction.  There is postgres, template1 and template2 but none of 
the other databases we had.


Just noticed, is that really template2 or is it actually template0?


--
Adrian Klaver
adrian.kla...@aklaver.com

Re: psql: FATAL: the database system is starting up

[Tom K]

On Sat, Jun 1, 2019 at 6:39 PM Adrian Klaver 
wrote:

> On 6/1/19 3:14 PM, Tom K wrote:
>
> >
> > ** Correction.  There is postgres, template1 and template2 but none of
> > the other databases we had.
>
> Just noticed, is that really template2 or is it actually template0?


Apologies.  You're right, that was a typo:

-bash-4.2$ psql -h psql03 -U postgres
Password for user postgres:
psql (10.8)
Type "help" for help.

postgres=# \l
  List of databases
   Name|  Owner   | Encoding |   Collate   |Ctype|   Access
privileges
---+--+--+-+-+---
 postgres  | postgres | UTF8 | en_US.UTF-8 | en_US.UTF-8 |
 template0 | postgres | UTF8 | en_US.UTF-8 | en_US.UTF-8 | =c/postgres
 +
   |  |  | | |
postgres=CTc/postgres
 template1 | postgres | UTF8 | en_US.UTF-8 | en_US.UTF-8 | =c/postgres
 +
   |  |  | | |
postgres=CTc/postgres
(3 rows)

postgres=#



>
> --
> Adrian Klaver
> adrian.kla...@aklaver.com
>

Re: psql: FATAL: the database system is starting up

[Tom K]

On Sat, Jun 1, 2019 at 6:36 PM Adrian Klaver 
wrote:

> On 6/1/19 3:14 PM, Tom K wrote:
> >
> >
>
> > ** Correction.  There is postgres, template1 and template2 but none of
> > the other databases we had.
>
> In a psql session do:
>
> select oid, datname from pg_database ;
>
> Then go to /data/patroni an drill down to the base directory. In that
> directory there should be sub-directories with numbers equal to the oid
> values from the query. If not then something is wrong. That could be:
>
> 1) Wrong data directory.
>
> 2) Copied over incorrect data directory.
>
> Basically if the only sub-directories are for the system databases then
> the user databases do not exist. You might want to look at some of the
> other clusters to see what is there.
>
>
>

-bash-4.2$ pwd
/var/lib/pgsql
-bash-4.2$ psql -h psql03 -U postgres
Password for user postgres:
psql (10.8)
Type "help" for help.

postgres=# \l
  List of databases
   Name|  Owner   | Encoding |   Collate   |Ctype|   Access
privileges
---+--+--+-+-+---
 postgres  | postgres | UTF8 | en_US.UTF-8 | en_US.UTF-8 |
 template0 | postgres | UTF8 | en_US.UTF-8 | en_US.UTF-8 | =c/postgres
 +
   |  |  | | |
postgres=CTc/postgres
 template1 | postgres | UTF8 | en_US.UTF-8 | en_US.UTF-8 | =c/postgres
 +
   |  |  | | |
postgres=CTc/postgres
(3 rows)

postgres=# select oid, datname from pg_database ;
  oid  |  datname
---+---
 13806 | postgres
 1 | template1
 13805 | template0
(3 rows)

postgres=#
postgres=# cd /data/patroni
postgres-# ls -altri
postgres-# pwd
postgres-# pwd
postgres-# ls -altrid
postgres-# ;
ERROR:  syntax error at or near "cd"
LINE 1: cd /data/patroni
^
postgres=# \q
-bash-4.2$ ls -altri
total 652
134299846 drwxr-xr-x. 39 root root   4096 Oct 24  2018 ..
 67178653 -rw-r--r--.  1 postgres postgres 30 Oct 24  2018
.pgsql_profile
134734937 drwx--.  4 postgres postgres 31 May  8 06:25 10
 67178637 drwx--.  3 postgres postgres   4096 May  8 06:25 .
 68994450 -rw-r--r--.  1 postgres postgres 204336 May 26 22:37 s1.log
 67677594 -rwx--.  1 postgres postgres266 May 26 23:06 .bash_profile
 68994451 -rw-r--r--.  1 postgres postgres 433920 May 26 23:44 s2.log
 68391913 -rw---.  1 postgres postgres   4716 Jun  1 17:34 .bash_history
 67178638 -rw---.  1 postgres postgres325 Jun  1 18:54 .psql_history
-bash-4.2$ cd /data/patroni/
-bash-4.2$ ls -altri
total 144
 69085037 drwxr-xr-x.  3 root root20 Oct 23  2018 ..
135316997 -rw---.  1 postgres postgres   206 Oct 29  2018
backup_label.old
201708781 drwx--.  2 postgres postgres 6 Oct 29  2018 pg_commit_ts
  1502746 drwx--.  2 postgres postgres 6 Oct 29  2018 pg_dynshmem
 68994449 drwx--.  2 postgres postgres 6 Oct 29  2018 pg_twophase
  1502749 drwx--.  2 postgres postgres 6 Oct 29  2018 pg_snapshots
201708785 drwx--.  2 postgres postgres 6 Oct 29  2018 pg_serial
  1502747 drwx--.  4 postgres postgres34 Oct 29  2018 pg_multixact
 67677559 drwx--.  5 postgres postgres38 Oct 29  2018 base
  1502751 drwx--.  2 postgres postgres17 Oct 29  2018 pg_xact
  1502750 drwx--.  2 postgres postgres 6 Oct 29  2018 pg_tblspc
134668882 -rw---.  1 postgres postgres88 Oct 29  2018
postgresql.auto.conf
134500181 -rw---.  1 postgres postgres 3 Oct 29  2018 PG_VERSION
134500173 -rw---.  1 postgres postgres  1636 Oct 29  2018 pg_ident.conf
134500171 -rw---.  1 postgres postgres  4730 Oct 29  2018 pg_hba.conf
134668883 -rw---.  1 postgres postgres 22783 Oct 29  2018
postgresql.base.conf
134500170 -rw---.  1 postgres postgres   124 Oct 29  2018
patroni.dynamic.json
134668889 -rw-r--r--.  1 postgres postgres90 Oct 29  2018 recovery.done
201708786 drwx--.  2 postgres postgres17 Oct 29  2018 pg_subtrans
134500162 drwx--.  2 postgres postgres  4096 Nov  4  2018 log
134500182 drwx--.  3 postgres postgres  8192 Apr 28 06:06 pg_wal
  1502748 drwx--.  4 postgres postgres42 May 22 01:55 pg_replslot
134668893 -rw-r--r--.  1 postgres postgres90 May 26 22:34 t.txt
134668885 -rw-r--r--.  1 postgres postgres   575 May 26 22:34
postgresql.conf
134668886 -rw-r--r--.  1 postgres postgres   575 May 26 22:34
postgresql.conf.backup
134668884 -rw---.  1 postgres postgres 22783 May 26 22:34
postgresql.base.conf.backup
134500172 -rw---.  1 postgres postgres  4730 May 26 22:34
pg_hba.conf.backup
134500174 -rw---.  1 postgres postgres  1636 May 26 22:34
pg_ident.conf.backup
 68994437 drwx--.  4 postgres postgres65 Jun  1 17:34 pg_logical
134734900 -rw---.  1 postgres postgres38 Jun  1 18:53
.s.PGSQL.5432.lock
134734941 srwxrwxrwx.  1 postgres postgres 0 Jun  1 18:53 .s.PGSQL.5432
201708783

Re: Questions about btree_gin vs btree_gist for low cardinality columns

[Morris de Oryx]

Peter, thanks a lot for picking up on what I started, improving it, and
reporting back. I *thought *I was providing timing estimates from the
EXPLAIN cost dumps. Seems not. Well, there's another thing that I've
learned.

Your explanation of why the hash index bloats out makes complete sense, I
ought to have thought that.

Can you tell me how you get timing results into state_test_times? I know
how to turn on time display in psql, but I much prefer to use straight SQL.
The reason for that is my production code is always run through a SQL
session, not typing things into psql.

On Sat, Jun 1, 2019 at 11:53 PM Peter J. Holzer  wrote:

> On 2019-06-01 17:44:00 +1000, Morris de Oryx wrote:
> > Since I've been wondering about this subject, I figured I'd take a bit
> of time
> > and try to do some tests. I'm not new to databases or coding, but have
> been
> > using Postgres for less than two years. I haven't tried to generate large
> > blocks of test data directly in Postgres before, so I'm sure that there
> are
> > better ways to do what I've done here. No worries, this gave me a chance
> to
> > work through at least some of the questions/problems in setting up and
> running
> > tests.
> >
> > Anyway, I populated a table with 1M rows of data with very little in
> them, just
> > a two-character state abbreviation. There are only 59 values, and the
> > distribution is fairly even as I used random() without any tricks to
> shape the
> > distribution. So, each value is roughly 1/60th of the total row count.
> Not
> > realistic, but what I've got.
> >
> > For this table, I built four different kind of index and tried each one
> out
> > with a count(*) query on a single exact match. I also checked out the
> size of
> > each index.
> >
> > Headline results:
> >
> > Partial index: Smaller (as expeced), fast.
> > B-tree index: Big, fast.
> > GIN: Small, slow.
> > Hash: Large, slow. ("Large" may be exaggerated in comparison with a
> B-tree
> > because of my test data.)
>
> You didn't post any times (or the queries you timed), so I don't know
> what "fast" and "slow" mean.
>
> I used your setup to time
> select sum(num) from state_test where abbr = 'MA';
> on my laptop (i5-7Y54, 16GB RAM, SSD, Pgsql 10.8) and here are the
> results:
>
> hjp=> select method, count(*),
> min(time_ms),
> avg(time_ms),
> percentile_cont(0.5) within group (order by time_ms) as median,
> max(time_ms)
> from state_test_times
> group by method
> order by 5;
>
>  method  | count |  min   |   avg   | median |  max
> -+---++-++
>  Partial | 5 |   9.05 |  9.7724 |  9.185 | 12.151
>  B tree  | 5 |  9.971 | 12.8036 | 10.226 |   21.6
>  GIN | 5 |  9.542 | 10.3644 | 10.536 | 10.815
>  Hash| 5 | 10.801 | 11.7448 | 11.047 | 14.875
>
> All the times are pretty much the same. GIN is third by median, but the
> difference is tiny, and it is secondy by minium and average and even
> first by maximum.
>
> In this case all the queries do a bitmap scan, so the times are probably
> dominated by reading the heap, not the index.
>
> > methodpg_table_sizekb
> > Partial   401408392 Kb
> > B tree2248704021960 Kb
> > GIN   19169281872 Kb
> > Hash  4925030448096 Kb
>
> I get the same sizes.
>
>
> > Okay, so the partial index is smaller, basically proportional to the
> fraction
> > of the file it's indexing. So that makes sense, and is good to know.
>
> Yeah. But to cover all values you would need 59 partial indexes, which
> gets you back to the size of the full btree index. My test shows that it
> might be faster, though, which might make the hassle of having to
> maintain a large number of indexes worthwhile.
>
> > The hash index size is...harder to explain...very big. Maybe my tiny
> > strings? Not sure what size Postgres hashes to. A hash of a two
> > character string is likely about worst-case.
>
> I think that a hash index is generally a poor fit for low cardinality
> indexes: You get a lot of equal values, which are basically hash
> collisions. Unless the index is specifically designed to handle this
> (e.g. by storing the key only once and then a tuple list per key, like a
> GIN index does) it will balloon out trying to reduce the number of
> collisions.
>
> hp
>
> --
>_  | Peter J. Holzer| we build much bigger, better disasters now
> |_|_) || because we have much more sophisticated
> | |   | h...@hjp.at | management tools.
> __/   | http://www.hjp.at/ | -- Ross Anderson 
>

Re: psql: FATAL: the database system is starting up

[Adrian Klaver]

On 6/1/19 3:56 PM, Tom K wrote:







postgres=# select oid, datname from pg_database ;
   oid  |  datname
---+---
  13806 | postgres
      1 | template1
  13805 | template0
(3 rows)



So there are only the system databases available


-bash-4.2$ cd /data/patroni/
-bash-4.2$ ls -altri
total 144
  69085037 drwxr-xr-x.  3 root     root        20 Oct 23  2018 ..
135316997 -rw---.  1 postgres postgres   206 Oct 29  2018 
backup_label.old

201708781 drwx--.  2 postgres postgres     6 Oct 29  2018 pg_commit_ts
   1502746 drwx--.  2 postgres postgres     6 Oct 29  2018 pg_dynshmem
  68994449 drwx--.  2 postgres postgres     6 Oct 29  2018 pg_twophase
   1502749 drwx--.  2 postgres postgres     6 Oct 29  2018 pg_snapshots
201708785 drwx--.  2 postgres postgres     6 Oct 29  2018 pg_serial
   1502747 drwx--.  4 postgres postgres    34 Oct 29  2018 pg_multixact
  67677559 drwx--.  5 postgres postgres    38 Oct 29  2018 base


base/ is the directory you need to look in. I'm guessing it is only 
going to show the oid/ for the three db's above and  pgsql_tmp/


For more info on this see:
https://www.postgresql.org/docs/10/storage-file-layout.html

The below looks like the RH package installed data directory. Also looks 
like it either has never had initdb run against or the files where removed.


I thought you said you had copied in data directories from the other 
nodes, did I remember correctly?



-bash-4.2$ cd
-bash-4.2$ cd 10
-bash-4.2$ ls
backups  data
-bash-4.2$ pwd
/var/lib/pgsql/10
-bash-4.2$ cd data/
-bash-4.2$ ls -altri
total 0
134734937 drwx--. 4 postgres postgres 31 May  8 06:25 ..
    245519 drwx--. 2 postgres postgres  6 May  8 06:25 .
-bash-4.2$ cd ..
-bash-4.2$ pwd
/var/lib/pgsql/10
-bash-4.2$ cd ..
-bash-4.2$



--
Adrian Klaver
adrian.kla...@aklaver.com

Re: psql: FATAL: the database system is starting up

[Tom K]

On Sat, Jun 1, 2019 at 7:12 PM Adrian Klaver 
wrote:

> On 6/1/19 3:56 PM, Tom K wrote:
> >
> >
>
> >
> > postgres=# select oid, datname from pg_database ;
> >oid  |  datname
> > ---+---
> >   13806 | postgres
> >   1 | template1
> >   13805 | template0
> > (3 rows)
> >
>
> So there are only the system databases available
>
> > -bash-4.2$ cd /data/patroni/
> > -bash-4.2$ ls -altri
> > total 144
> >   69085037 drwxr-xr-x.  3 root root20 Oct 23  2018 ..
> > 135316997 -rw---.  1 postgres postgres   206 Oct 29  2018
> > backup_label.old
> > 201708781 drwx--.  2 postgres postgres 6 Oct 29  2018
> pg_commit_ts
> >1502746 drwx--.  2 postgres postgres 6 Oct 29  2018
> pg_dynshmem
> >   68994449 drwx--.  2 postgres postgres 6 Oct 29  2018
> pg_twophase
> >1502749 drwx--.  2 postgres postgres 6 Oct 29  2018
> pg_snapshots
> > 201708785 drwx--.  2 postgres postgres 6 Oct 29  2018 pg_serial
> >1502747 drwx--.  4 postgres postgres34 Oct 29  2018
> pg_multixact
> >   67677559 drwx--.  5 postgres postgres38 Oct 29  2018 base
>
> base/ is the directory you need to look in. I'm guessing it is only
> going to show the oid/ for the three db's above and  pgsql_tmp/
>
> For more info on this see:
> https://www.postgresql.org/docs/10/storage-file-layout.html
>
> The below looks like the RH package installed data directory. Also looks
> like it either has never had initdb run against or the files where removed.
>
> I thought you said you had copied in data directories from the other
> nodes, did I remember correctly?
>
> > -bash-4.2$ cd
> > -bash-4.2$ cd 10
> > -bash-4.2$ ls
> > backups  data
> > -bash-4.2$ pwd
> > /var/lib/pgsql/10
> > -bash-4.2$ cd data/
> > -bash-4.2$ ls -altri
> > total 0
> > 134734937 drwx--. 4 postgres postgres 31 May  8 06:25 ..
> > 245519 drwx--. 2 postgres postgres  6 May  8 06:25 .
> > -bash-4.2$ cd ..
> > -bash-4.2$ pwd
> > /var/lib/pgsql/10
> > -bash-4.2$ cd ..
> > -bash-4.2$
>
>
Yep, you remembered correctly.

I copied the files as they were, out to a temporary folder under root for
each node but never dug into base/ etc any further to check things.  So
here's the state of things in the base/ folder of the backup of each node.

[ PSQL03 ]
[root@psql03 base]# ls -altri
total 40
42424 drwx--.  2 postgres postgres 8192 Oct 29  2018 1
 67714749 drwx--.  2 postgres postgres 8192 Oct 29  2018 13805
202037206 drwx--.  5 postgres postgres   38 Oct 29  2018 .
134312175 drwx--.  2 postgres postgres 8192 May 22 01:55 13806
89714 drwxr-xr-x. 20 root root 4096 May 22 22:43 ..
[root@psql03 base]#



[ PSQL02 ]
 [root@psql02 base]# ls -altri
total 412
201426668 drwx--.  2 postgres postgres  8192 Oct 29  2018 1
   743426 drwx--.  2 postgres postgres  8192 Mar 24 03:47 13805
135326327 drwx--.  2 postgres postgres 16384 Mar 24 20:15 40970
   451699 drwx--.  2 postgres postgres 40960 Mar 25 19:47 16395
  1441696 drwx--.  2 postgres postgres  8192 Mar 31 15:09 131137
 68396137 drwx--.  2 postgres postgres  8192 Mar 31 15:09 131138
135671065 drwx--.  2 postgres postgres  8192 Mar 31 15:09 131139
204353100 drwx--.  2 postgres postgres  8192 Mar 31 15:09 131140
135326320 drwx--. 17 postgres postgres  4096 Apr 14 10:08 .
 68574415 drwx--.  2 postgres postgres 12288 Apr 28 06:06 131142
   288896 drwx--.  2 postgres postgres 16384 Apr 28 06:06 131141
203015232 drwx--.  2 postgres postgres  8192 Apr 28 06:06 131136
135326328 drwx--.  2 postgres postgres 40960 May  5 22:09 24586
 67282461 drwx--.  2 postgres postgres  8192 May  5 22:09 13806
 67640961 drwx--.  2 postgres postgres 20480 May  5 22:09 131134
203500274 drwx--.  2 postgres postgres 16384 May  5 22:09 155710
134438257 drwxr-xr-x. 20 root root  4096 May 22 01:44 ..
[root@psql02 base]# pwd
/root/postgres-patroni-backup/base
[root@psql02 base]#


[ PSQL01 ]
[root@psql01 base]# ls -altri
total 148
134704615 drwx--.  2 postgres postgres  8192 Oct 29  2018 1
201547700 drwx--.  2 postgres postgres  8192 Oct 29  2018 13805
   160398 drwx--.  2 postgres postgres  8192 Feb 24 23:53 13806
 67482137 drwx--.  7 postgres postgres62 Feb 24 23:54 .
135909671 drwx--.  2 postgres postgres 24576 Feb 24 23:54 24586
13555 drwx--.  2 postgres postgres 24576 Feb 24 23:54 16395
 67178716 drwxr-xr-x. 20 root root  4096 May 22 01:53 ..
[root@psql01 base]# pwd
/root/postgresql-patroni-etcd/base
[root@psql01 base]#

Looks like this crash was far more catastrophic then I thought.  By the
looks of things, thinking on psql02 would be my best bet.



> --
> Adrian Klaver
> adrian.kla...@aklaver.com
>

Re: psql: FATAL: the database system is starting up

[Adrian Klaver]

On 6/1/19 4:22 PM, Tom K wrote:





I thought you said you had copied in data directories from the other
nodes, did I remember correctly?



Yep, you remembered correctly.

I copied the files as they were, out to a temporary folder under root 
for each node but never dug into base/ etc any further to check things.  
So here's the state of things in the base/ folder of the backup of each 
node.






Looks like this crash was far more catastrophic then I thought.  By the 
looks of things, thinking on psql02 would be my best bet.





Assuming the other files in the cluster are all there and not corrupted.


--
Adrian Klaver
adrian.kla...@aklaver.com

Re: psql: FATAL: the database system is starting up

[Adrian Klaver]

On 6/1/19 4:22 PM, Tom K wrote:







Looks like this crash was far more catastrophic then I thought.  By the 
looks of things, thinking on psql02 would be my best bet.




The more I look at it the more I think the replication was not doing 
what you thought it was doing. That psql02 was the primary and that 
psql01 and psql03 where out of sync and/or defunct standbys.




--
Adrian Klaver
adrian.kla...@aklaver.com

Re: Questions about btree_gin vs btree_gist for low cardinality columns

[Morris de Oryx]

>From what Peter showed, the answer to (part of) the original questions
seems to be that *yes*, a B-tree GIN can be quite appealing. The test times
aren't too worrisome, and the index size is about 1/12th of a B-tree. I
added on the sizes, and divided each index size by a full B-tree:

Method  Count  Min   Avg Median Max  KB
KB/B-Tree
Partial 5  9.0509.77249.185 12.151  392 0.018
B-tree  5  9.971   12.8036   10.226 21.600   21,960 1.000
GIN 5  9.542   10.3644   10.536 10.8151,872 0.085
Hash5 10.801   11.7448   11.047 14.875   48,096 2.190

I'm not great at ASCII tables, I'm attaching a picture...don't know if that
works here.

[image: results_table.jpeg]

I guess I'd say at this point:

* The test case I set up is kind of silly and definitely not representative
of a variety of data distributions.

* Hash index is not well-matched to low-cardinality (=== "high collision")
values.

* Partial B-trees aren't going to save space if you need one for each
distinct value. And there's an overhead to index maintenance, so there's
that. (But partial indexes in Postgres are fantastic in the right
situationsthis probably isn't one.)

* A B-tree GIN index performs well and is space-efficient.

Might be overriding a bit here from an artificial/toy test, but I find the
results Peter offered pretty encouraging. It *really *feels wrong to use a
standard B-tree for low-cardinality columns. It's just a badly matched data
structure. Hash toothere you see the results quite dramatically, but
it's a closely related problem. A GIN index *seems* like it's well-matched
to low-cardinality indexing.

Now that this is all in my head a bit, I'm hoping for more feedback and
real-world observations. Any commentary appreciated.

On Sun, Jun 2, 2019 at 9:10 AM Morris de Oryx 
wrote:

> Peter, thanks a lot for picking up on what I started, improving it, and
> reporting back. I *thought *I was providing timing estimates from the
> EXPLAIN cost dumps. Seems not. Well, there's another thing that I've
> learned.
>
> Your explanation of why the hash index bloats out makes complete sense, I
> ought to have thought that.
>
> Can you tell me how you get timing results into state_test_times? I know
> how to turn on time display in psql, but I much prefer to use straight SQL.
> The reason for that is my production code is always run through a SQL
> session, not typing things into psql.
>
> On Sat, Jun 1, 2019 at 11:53 PM Peter J. Holzer  wrote:
>
>> On 2019-06-01 17:44:00 +1000, Morris de Oryx wrote:
>> > Since I've been wondering about this subject, I figured I'd take a bit
>> of time
>> > and try to do some tests. I'm not new to databases or coding, but have
>> been
>> > using Postgres for less than two years. I haven't tried to generate
>> large
>> > blocks of test data directly in Postgres before, so I'm sure that there
>> are
>> > better ways to do what I've done here. No worries, this gave me a
>> chance to
>> > work through at least some of the questions/problems in setting up and
>> running
>> > tests.
>> >
>> > Anyway, I populated a table with 1M rows of data with very little in
>> them, just
>> > a two-character state abbreviation. There are only 59 values, and the
>> > distribution is fairly even as I used random() without any tricks to
>> shape the
>> > distribution. So, each value is roughly 1/60th of the total row count.
>> Not
>> > realistic, but what I've got.
>> >
>> > For this table, I built four different kind of index and tried each one
>> out
>> > with a count(*) query on a single exact match. I also checked out the
>> size of
>> > each index.
>> >
>> > Headline results:
>> >
>> > Partial index: Smaller (as expeced), fast.
>> > B-tree index: Big, fast.
>> > GIN: Small, slow.
>> > Hash: Large, slow. ("Large" may be exaggerated in comparison with a
>> B-tree
>> > because of my test data.)
>>
>> You didn't post any times (or the queries you timed), so I don't know
>> what "fast" and "slow" mean.
>>
>> I used your setup to time
>> select sum(num) from state_test where abbr = 'MA';
>> on my laptop (i5-7Y54, 16GB RAM, SSD, Pgsql 10.8) and here are the
>> results:
>>
>> hjp=> select method, count(*),
>> min(time_ms),
>> avg(time_ms),
>> percentile_cont(0.5) within group (order by time_ms) as median,
>> max(time_ms)
>> from state_test_times
>> group by method
>> order by 5;
>>
>>  method  | count |  min   |   avg   | median |  max
>> -+---++-++
>>  Partial | 5 |   9.05 |  9.7724 |  9.185 | 12.151
>>  B tree  | 5 |  9.971 | 12.8036 | 10.226 |   21.6
>>  GIN | 5 |  9.542 | 10.3644 | 10.536 | 10.815
>>  Hash| 5 | 10.801 | 11.7448 | 11.047 | 14.875
>>
>> All the times are pretty much the same. GIN is third by median, but the
>> difference is tiny, and it is secondy by minium and average and even
>> first by max

Re: psql: FATAL: the database system is starting up

[Tom K]

On Sat, Jun 1, 2019 at 7:34 PM Adrian Klaver 
wrote:

> On 6/1/19 4:22 PM, Tom K wrote:
> >
> >
>
> >
> > Looks like this crash was far more catastrophic then I thought.  By the
> > looks of things, thinking on psql02 would be my best bet.
> >
>
> The more I look at it the more I think the replication was not doing
> what you thought it was doing. That psql02 was the primary and that
> psql01 and psql03 where out of sync and/or defunct standbys.
>

Now that I look at the files myself, that's the conclusion I was coming to
myself.  Sample config:

[root@psql02 base]# cat /etc/patroni.yml
scope: postgres
namespace: /db/
name: postgresql1

restapi:
listen: 192.168.0.124:8008
connect_address: 192.168.0.124:8008

etcd:
host: 192.168.0.124:2379

bootstrap:
dcs:
ttl: 30
loop_wait: 10
retry_timeout: 10
maximum_lag_on_failover: 1048576
postgresql:
use_pg_rewind: true

initdb:
- encoding: UTF8
- data-checksums

pg_hba:
- host replication replicator 127.0.0.1/32 md5
- host replication replicator 192.168.0.108/0 md5
- host replication replicator 192.168.0.124/0 md5
- host replication replicator 192.168.0.118/0 md5
- host all all 0.0.0.0/0 md5

users:
admin:
password: admin
options:
- createrole
- createdb

postgresql:
listen: 192.168.0.124:5432
bin_dir: /usr/pgsql-10/bin
connect_address: 192.168.0.124:5432
data_dir: /data/patroni
pgpass: /tmp/pgpass
unix_socket_directories: /data/patroni
authentication:
replication:
username: replicator
password: rep-pass
superuser:
username: postgres
password: 
parameters:
unix_socket_directories: '.'

tags:
nofailover: false
noloadbalance: false
clonefrom: false
nosync: false
[root@psql02 base]#

Or perhaps when the system crashed, the filesystem check simply moved the
folders out due to corruption.


>
>
>
> --
> Adrian Klaver
> adrian.kla...@aklaver.com
>

Re: psql: FATAL: the database system is starting up

[Tom K]

So the best bet will be trying to get through this error then:

[ PSQL02 ]
PANIC:replication check point has wrong magic 0 instead of  307747550




On Sat, Jun 1, 2019 at 8:21 PM Tom K  wrote:

>
>
> On Sat, Jun 1, 2019 at 7:34 PM Adrian Klaver 
> wrote:
>
>> On 6/1/19 4:22 PM, Tom K wrote:
>> >
>> >
>>
>> >
>> > Looks like this crash was far more catastrophic then I thought.  By the
>> > looks of things, thinking on psql02 would be my best bet.
>> >
>>
>> The more I look at it the more I think the replication was not doing
>> what you thought it was doing. That psql02 was the primary and that
>> psql01 and psql03 where out of sync and/or defunct standbys.
>>
>
> Now that I look at the files myself, that's the conclusion I was coming to
> myself.  Sample config:
>
> [root@psql02 base]# cat /etc/patroni.yml
> scope: postgres
> namespace: /db/
> name: postgresql1
>
> restapi:
> listen: 192.168.0.124:8008
> connect_address: 192.168.0.124:8008
>
> etcd:
> host: 192.168.0.124:2379
>
> bootstrap:
> dcs:
> ttl: 30
> loop_wait: 10
> retry_timeout: 10
> maximum_lag_on_failover: 1048576
> postgresql:
> use_pg_rewind: true
>
> initdb:
> - encoding: UTF8
> - data-checksums
>
> pg_hba:
> - host replication replicator 127.0.0.1/32 md5
> - host replication replicator 192.168.0.108/0 md5
> - host replication replicator 192.168.0.124/0 md5
> - host replication replicator 192.168.0.118/0 md5
> - host all all 0.0.0.0/0 md5
>
> users:
> admin:
> password: admin
> options:
> - createrole
> - createdb
>
> postgresql:
> listen: 192.168.0.124:5432
> bin_dir: /usr/pgsql-10/bin
> connect_address: 192.168.0.124:5432
> data_dir: /data/patroni
> pgpass: /tmp/pgpass
> unix_socket_directories: /data/patroni
> authentication:
> replication:
> username: replicator
> password: rep-pass
> superuser:
> username: postgres
> password: 
> parameters:
> unix_socket_directories: '.'
>
> tags:
> nofailover: false
> noloadbalance: false
> clonefrom: false
> nosync: false
> [root@psql02 base]#
>
> Or perhaps when the system crashed, the filesystem check simply moved the
> folders out due to corruption.
>
>
>>
>>
>>
>> --
>> Adrian Klaver
>> adrian.kla...@aklaver.com
>>
>

Re: psql: FATAL: the database system is starting up

[Tom K]

On Sat, Jun 1, 2019 at 8:25 PM Tom K  wrote:

> So the best bet will be trying to get through this error then:
>
> [ PSQL02 ]
> PANIC:replication check point has wrong magic 0 instead of  307747550
>
>
>
>
> On Sat, Jun 1, 2019 at 8:21 PM Tom K  wrote:
>
>>
>>
>> On Sat, Jun 1, 2019 at 7:34 PM Adrian Klaver 
>> wrote:
>>
>>> On 6/1/19 4:22 PM, Tom K wrote:
>>> >
>>> >
>>>
>>> >
>>> > Looks like this crash was far more catastrophic then I thought.  By
>>> the
>>> > looks of things, thinking on psql02 would be my best bet.
>>> >
>>>
>>> The more I look at it the more I think the replication was not doing
>>> what you thought it was doing. That psql02 was the primary and that
>>> psql01 and psql03 where out of sync and/or defunct standbys.
>>>
>>
>> Now that I look at the files myself, that's the conclusion I was coming
>> to myself.  Sample config:
>>
>> [root@psql02 base]# cat /etc/patroni.yml
>> scope: postgres
>> namespace: /db/
>> name: postgresql1
>>
>> restapi:
>> listen: 192.168.0.124:8008
>> connect_address: 192.168.0.124:8008
>>
>> etcd:
>> host: 192.168.0.124:2379
>>
>> bootstrap:
>> dcs:
>> ttl: 30
>> loop_wait: 10
>> retry_timeout: 10
>> maximum_lag_on_failover: 1048576
>> postgresql:
>> use_pg_rewind: true
>>
>> initdb:
>> - encoding: UTF8
>> - data-checksums
>>
>> pg_hba:
>> - host replication replicator 127.0.0.1/32 md5
>> - host replication replicator 192.168.0.108/0 md5
>> - host replication replicator 192.168.0.124/0 md5
>> - host replication replicator 192.168.0.118/0 md5
>> - host all all 0.0.0.0/0 md5
>>
>> users:
>> admin:
>> password: admin
>> options:
>> - createrole
>> - createdb
>>
>> postgresql:
>> listen: 192.168.0.124:5432
>> bin_dir: /usr/pgsql-10/bin
>> connect_address: 192.168.0.124:5432
>> data_dir: /data/patroni
>> pgpass: /tmp/pgpass
>> unix_socket_directories: /data/patroni
>> authentication:
>> replication:
>> username: replicator
>> password: rep-pass
>> superuser:
>> username: postgres
>> password: 
>> parameters:
>> unix_socket_directories: '.'
>>
>> tags:
>> nofailover: false
>> noloadbalance: false
>> clonefrom: false
>> nosync: false
>> [root@psql02 base]#
>>
>> Or perhaps when the system crashed, the filesystem check simply moved the
>> folders out due to corruption.
>>
>>
>>>
>>>
Trying what we did above but on the second node:

2019-06-01 20:28:45.305 EDT [21745] LOG:  database system was interrupted;
last known up at 2019-04-28 06:06:24 EDT
2019-06-01 20:28:46.142 EDT [21745] DEBUG:  primary_slot_name =
'postgresql1'
2019-06-01 20:28:46.142 EDT [21745] DEBUG:  standby_mode = 'on'
2019-06-01 20:28:46.142 EDT [21745] DEBUG:  recovery_target_timeline =
latest
2019-06-01 20:28:46.142 EDT [21745] WARNING:  recovery command file
"recovery.conf" specified neither primary_conninfo nor restore_command
2019-06-01 20:28:46.142 EDT [21745] HINT:  The database server will
regularly poll the pg_wal subdirectory to check for files placed there.
2019-06-01 20:28:46.142 EDT [21745] LOG:  entering standby mode
2019-06-01 20:28:46.142 EDT [21745] LOG:  invalid record length at
0/4C35CDF8: wanted 24, got 0
2019-06-01 20:28:46.142 EDT [21745] LOG:  invalid primary checkpoint record
2019-06-01 20:28:46.142 EDT [21745] LOG:  using previous checkpoint record
at 0/4C34EDA8
2019-06-01 20:28:46.142 EDT [21745] DEBUG:  redo record is at 0/4C34ED70;
shutdown FALSE
2019-06-01 20:28:46.143 EDT [21745] DEBUG:  next transaction ID: 0:1409831;
next OID: 237578
2019-06-01 20:28:46.143 EDT [21745] DEBUG:  next MultiXactId: 48; next
MultiXactOffset: 174
2019-06-01 20:28:46.143 EDT [21745] DEBUG:  oldest unfrozen transaction ID:
549, in database 1
2019-06-01 20:28:46.143 EDT [21745] DEBUG:  oldest MultiXactId: 1, in
database 1
2019-06-01 20:28:46.143 EDT [21745] DEBUG:  commit timestamp Xid
oldest/newest: 0/0
2019-06-01 20:28:46.143 EDT [21745] DEBUG:  transaction ID wrap limit is
2147484196, limited by database with OID 1
2019-06-01 20:28:46.143 EDT [21745] DEBUG:  MultiXactId wrap limit is
2147483648, limited by database with OID 1
2019-06-01 20:28:46.143 EDT [21745] DEBUG:  starting up replication slots
2019-06-01 20:28:46.143 EDT [21745] DEBUG:  starting up replication origin
progress state
2019-06-01 20:28:46.143 EDT [21745] PANIC:  replication checkpoint has
wrong magic 0 instead of 307747550
2019-06-01 20:28:46.143 EDT [21743] DEBUG:  reaping dead processes
2019-06-01 20:28:46.143 EDT [21743] LOG:  startup process (PID 21745) was
terminated by signal 6: Aborted
2019-06-01 20:28:46.143 EDT [21743] LOG:  aborting startup due to startup
process failure
2019-06-01 20:28:46.144 EDT [21743] DEBUG:  shmem_exit(1): 0
before_shmem_exit callbacks to make
2019-06-01 20:28:46.144 EDT [21743] DEBUG:  shmem_exit(1): 5 o

Re: psql: FATAL: the database system is starting up

[Adrian Klaver]

On 6/1/19 5:21 PM, Tom K wrote:



On Sat, Jun 1, 2019 at 7:34 PM Adrian Klaver > wrote:


On 6/1/19 4:22 PM, Tom K wrote:
 >
 >

 >
 > Looks like this crash was far more catastrophic then I thought. 
By the

 > looks of things, thinking on psql02 would be my best bet.
 >

The more I look at it the more I think the replication was not doing
what you thought it was doing. That psql02 was the primary and that
psql01 and psql03 where out of sync and/or defunct standbys.


Now that I look at the files myself, that's the conclusion I was coming 
to myself.  Sample config:


The below would be for someone that uses and understands Patroni. That 
would not be me:)




[root@psql02 base]# cat /etc/patroni.yml
scope: postgres
namespace: /db/
name: postgresql1

restapi:
     listen: 192.168.0.124:8008 
     connect_address: 192.168.0.124:8008 




Or perhaps when the system crashed, the filesystem check simply moved 
the folders out due to corruption.


That would leave the cluster in an inconsistent state and you would not 
have been able to start the one you got going.


--
Adrian Klaver
adrian.kla...@aklaver.com

Re: psql: FATAL: the database system is starting up

[Tom K]

That file just generates the postgres configs.   Here is what is generated:

-bash-4.2$ cat postgresql.conf
# Do not edit this file manually!
# It will be overwritten by Patroni!
include 'postgresql.base.conf'

cluster_name = 'postgres'
hot_standby = 'on'
listen_addresses = '192.168.0.124'
max_connections = '100'
max_locks_per_transaction = '64'
max_prepared_transactions = '0'
max_replication_slots = '10'
max_wal_senders = '10'
max_worker_processes = '8'
port = '5432'
track_commit_timestamp = 'off'
unix_socket_directories = '.'
wal_keep_segments = '8'
wal_level = 'replica'
wal_log_hints = 'on'
hba_file = '/data/patroni/pg_hba.conf'
ident_file = '/data/patroni/pg_ident.conf'
-bash-4.2$ cat /data/patroni/pg_hba.conf
# PostgreSQL Client Authentication Configuration File
# ===
#
# Refer to the "Client Authentication" section in the PostgreSQL
# documentation for a complete description of this file.  A short
# synopsis follows.
#
# This file controls: which hosts are allowed to connect, how clients
# are authenticated, which PostgreSQL user names they can use, which
# databases they can access.  Records take one of these forms:
#
# local  DATABASE  USER  METHOD  [OPTIONS]
# host   DATABASE  USER  ADDRESS  METHOD  [OPTIONS]
# hostsslDATABASE  USER  ADDRESS  METHOD  [OPTIONS]
# hostnossl  DATABASE  USER  ADDRESS  METHOD  [OPTIONS]
#
# (The uppercase items must be replaced by actual values.)
#
# The first field is the connection type: "local" is a Unix-domain
# socket, "host" is either a plain or SSL-encrypted TCP/IP socket,
# "hostssl" is an SSL-encrypted TCP/IP socket, and "hostnossl" is a
# plain TCP/IP socket.
#
# DATABASE can be "all", "sameuser", "samerole", "replication", a
# database name, or a comma-separated list thereof. The "all"
# keyword does not match "replication". Access to replication
# must be enabled in a separate record (see example below).
#
# USER can be "all", a user name, a group name prefixed with "+", or a
# comma-separated list thereof.  In both the DATABASE and USER fields
# you can also write a file name prefixed with "@" to include names
# from a separate file.
#
# ADDRESS specifies the set of hosts the record matches.  It can be a
# host name, or it is made up of an IP address and a CIDR mask that is
# an integer (between 0 and 32 (IPv4) or 128 (IPv6) inclusive) that
# specifies the number of significant bits in the mask.  A host name
# that starts with a dot (.) matches a suffix of the actual host name.
# Alternatively, you can write an IP address and netmask in separate
# columns to specify the set of hosts.  Instead of a CIDR-address, you
# can write "samehost" to match any of the server's own IP addresses,
# or "samenet" to match any address in any subnet that the server is
# directly connected to.
#
# METHOD can be "trust", "reject", "md5", "password", "scram-sha-256",
# "gss", "sspi", "ident", "peer", "pam", "ldap", "radius" or "cert".
# Note that "password" sends passwords in clear text; "md5" or
# "scram-sha-256" are preferred since they send encrypted passwords.
#
# OPTIONS are a set of options for the authentication in the format
# NAME=VALUE.  The available options depend on the different
# authentication methods -- refer to the "Client Authentication"
# section in the documentation for a list of which options are
# available for which authentication methods.
#
# Database and user names containing spaces, commas, quotes and other
# special characters must be quoted.  Quoting one of the keywords
# "all", "sameuser", "samerole" or "replication" makes the name lose
# its special character, and just match a database or username with
# that name.
#
# This file is read on server startup and when the server receives a
# SIGHUP signal.  If you edit the file on a running system, you have to
# SIGHUP the server for the changes to take effect, run "pg_ctl reload",
# or execute "SELECT pg_reload_conf()".
#
# Put your actual configuration here
# --
#
# If you want to allow non-local connections, you need to add more
# "host" records.  In that case you will also need to make PostgreSQL
# listen on a non-local interface via the listen_addresses
# configuration parameter, or via the -i or -h command line switches.

# CAUTION: Configuring the system for local "trust" authentication
# allows any local user to connect as any PostgreSQL user, including
# the database superuser.  If you do not trust all your local users,
# use another authentication method.


# TYPE  DATABASEUSERADDRESS METHOD

# "local" is for Unix domain socket connections only
local   all all trust
# IPv4 local connections:
hostall all 127.0.0.1/32trust
# IPv6 local connections:
hostall all ::1/128 trust
# Allow replication connections from localhost, by a user with t

Re: psql: FATAL: the database system is starting up

[Adrian Klaver]

On 6/1/19 5:32 PM, Tom K wrote:




Trying what we did above but on the second node:



Was this node the primary?

To me the below looks like there are replication slots set up that are 
failing. Not sure how to deal with this at the moment. You might try 
single-user mode:


https://www.postgresql.org/docs/10/app-postgres.html
Single-User Mode
...

and see if that at least gets the server started. This is a highly 
restricted so do not expect much usability.



Removing the recovery.conf and restarting yields the following messages:

2019-06-01 20:31:12.231 EDT [21910] LOG:  database system was 
interrupted; last known up at 2019-04-28 06:06:24 EDT
2019-06-01 20:31:12.505 EDT [21910] LOG:  invalid record length at 
0/4C35CDF8: wanted 24, got 0

2019-06-01 20:31:12.505 EDT [21910] LOG:  invalid primary checkpoint record
2019-06-01 20:31:12.505 EDT [21910] LOG:  using previous checkpoint 
record at 0/4C34EDA8
2019-06-01 20:31:12.505 EDT [21910] DEBUG:  redo record is at 
0/4C34ED70; shutdown FALSE
2019-06-01 20:31:12.505 EDT [21910] DEBUG:  next transaction ID: 
0:1409831; next OID: 237578
2019-06-01 20:31:12.505 EDT [21910] DEBUG:  next MultiXactId: 48; next 
MultiXactOffset: 174
2019-06-01 20:31:12.505 EDT [21910] DEBUG:  oldest unfrozen transaction 
ID: 549, in database 1
2019-06-01 20:31:12.505 EDT [21910] DEBUG:  oldest MultiXactId: 1, in 
database 1
2019-06-01 20:31:12.505 EDT [21910] DEBUG:  commit timestamp Xid 
oldest/newest: 0/0
2019-06-01 20:31:12.505 EDT [21910] DEBUG:  transaction ID wrap limit is 
2147484196, limited by database with OID 1
2019-06-01 20:31:12.505 EDT [21910] DEBUG:  MultiXactId wrap limit is 
2147483648, limited by database with OID 1

2019-06-01 20:31:12.505 EDT [21910] DEBUG:  starting up replication slots
2019-06-01 20:31:12.505 EDT [21910] DEBUG:  starting up replication 
origin progress state
2019-06-01 20:31:12.505 EDT [21910] PANIC:  replication checkpoint has 
wrong magic 0 instead of 307747550

2019-06-01 20:31:12.506 EDT [21908] DEBUG:  reaping dead processes
2019-06-01 20:31:12.506 EDT [21908] LOG:  startup process (PID 21910) 
was terminated by signal 6: Aborted
2019-06-01 20:31:12.506 EDT [21908] LOG:  aborting startup due to 
startup process failure
2019-06-01 20:31:12.506 EDT [21908] DEBUG:  shmem_exit(1): 0 
before_shmem_exit callbacks to make
2019-06-01 20:31:12.506 EDT [21908] DEBUG:  shmem_exit(1): 5 
on_shmem_exit callbacks to make
2019-06-01 20:31:12.506 EDT [21908] DEBUG:  cleaning up dynamic shared 
memory control segment with ID 976986759
2019-06-01 20:31:12.508 EDT [21908] DEBUG:  proc_exit(1): 2 callbacks to 
make

2019-06-01 20:31:12.508 EDT [21908] LOG:  database system is shut down
2019-06-01 20:31:12.508 EDT [21908] DEBUG:  exit(1)
2019-06-01 20:31:12.508 EDT [21908] DEBUG:  shmem_exit(-1): 0 
before_shmem_exit callbacks to make
2019-06-01 20:31:12.508 EDT [21908] DEBUG:  shmem_exit(-1): 0 
on_shmem_exit callbacks to make
2019-06-01 20:31:12.508 EDT [21908] DEBUG:  proc_exit(-1): 0 callbacks 
to make

2019-06-01 20:31:12.510 EDT [21909] DEBUG:  logger shutting down
2019-06-01 20:31:12.510 EDT [21909] DEBUG:  shmem_exit(0): 0 
before_shmem_exit callbacks to make
2019-06-01 20:31:12.510 EDT [21909] DEBUG:  shmem_exit(0): 0 
on_shmem_exit callbacks to make
2019-06-01 20:31:12.510 EDT [21909] DEBUG:  proc_exit(0): 0 callbacks to 
make

2019-06-01 20:31:12.510 EDT [21909] DEBUG:  exit(0)
2019-06-01 20:31:12.510 EDT [21909] DEBUG:  shmem_exit(-1): 0 
before_shmem_exit callbacks to make
2019-06-01 20:31:12.510 EDT [21909] DEBUG:  shmem_exit(-1): 0 
on_shmem_exit callbacks to make
2019-06-01 20:31:12.510 EDT [21909] DEBUG:  proc_exit(-1): 0 callbacks 
to make


-- 
Adrian Klaver

adrian.kla...@aklaver.com 




--
Adrian Klaver
adrian.kla...@aklaver.com

Re: psql: FATAL: the database system is starting up

[Tom K]

On Sat, Jun 1, 2019 at 8:53 PM Adrian Klaver 
wrote:

> On 6/1/19 5:32 PM, Tom K wrote:
>
> >
> >
> > Trying what we did above but on the second node:
> >
>
> Was this node the primary?
>
> To me the below looks like there are replication slots set up that are
> failing. Not sure how to deal with this at the moment. You might try
> single-user mode:
>
> https://www.postgresql.org/docs/10/app-postgres.html
> Single-User Mode
> ...
>
> and see if that at least gets the server started. This is a highly
> restricted so do not expect much usability.
>

These servers did crash before however didn't' notice anything particularly
wrong at the time. Perhaps a better check was in order.

Here is the result from attempting to start the DB in single user mode.

-bash-4.2$ /usr/pgsql-10/bin/postgres --single -D /data/patroni
--config-file=/data/patroni/postgresql.conf --hot_standby=off
--listen_addresses=192.168.0.124 --max_worker_processes=8
--max_locks_per_transaction=64 --wal_level=replica --cluster_name=postgres
--wal_log_hints=on --max_wal_senders=10 --track_commit_timestamp=off
--max_prepared_transactions=0 --port=5432 --max_replication_slots=10
--max_connections=20 -d 5 2>&1
2019-06-01 23:04:20.876 EDT [31831] DEBUG:  invoking
IpcMemoryCreate(size=144687104)
2019-06-01 23:04:20.877 EDT [31831] DEBUG:  mmap(144703488) with
MAP_HUGETLB failed, huge pages disabled: Cannot allocate memory
2019-06-01 23:04:20.890 EDT [31831] DEBUG:  SlruScanDirectory invoking
callback on pg_notify/
2019-06-01 23:04:20.890 EDT [31831] DEBUG:  removing file "pg_notify/"
2019-06-01 23:04:20.890 EDT [31831] DEBUG:  dynamic shared memory system
will support 128 segments
2019-06-01 23:04:20.891 EDT [31831] DEBUG:  created dynamic shared memory
control segment 846930886 (3088 bytes)
2019-06-01 23:04:20.891 EDT [31831] DEBUG:  InitPostgres
2019-06-01 23:04:20.891 EDT [31831] DEBUG:  my backend ID is 1
2019-06-01 23:04:20.891 EDT [31831] LOG:  database system was interrupted;
last known up at 2019-04-28 06:06:24 EDT
2019-06-01 23:04:21.239 EDT [31831] LOG:  invalid record length at
0/4C35CDF8: wanted 24, got 0
2019-06-01 23:04:21.239 EDT [31831] LOG:  invalid primary checkpoint record
2019-06-01 23:04:21.239 EDT [31831] LOG:  using previous checkpoint record
at 0/4C34EDA8
2019-06-01 23:04:21.239 EDT [31831] DEBUG:  redo record is at 0/4C34ED70;
shutdown FALSE
2019-06-01 23:04:21.239 EDT [31831] DEBUG:  next transaction ID: 0:1409831;
next OID: 237578
2019-06-01 23:04:21.239 EDT [31831] DEBUG:  next MultiXactId: 48; next
MultiXactOffset: 174
2019-06-01 23:04:21.239 EDT [31831] DEBUG:  oldest unfrozen transaction ID:
549, in database 1
2019-06-01 23:04:21.239 EDT [31831] DEBUG:  oldest MultiXactId: 1, in
database 1
2019-06-01 23:04:21.239 EDT [31831] DEBUG:  commit timestamp Xid
oldest/newest: 0/0
2019-06-01 23:04:21.239 EDT [31831] DEBUG:  transaction ID wrap limit is
2147484196, limited by database with OID 1
2019-06-01 23:04:21.239 EDT [31831] DEBUG:  MultiXactId wrap limit is
2147483648, limited by database with OID 1
2019-06-01 23:04:21.239 EDT [31831] DEBUG:  starting up replication slots
2019-06-01 23:04:21.239 EDT [31831] DEBUG:  starting up replication origin
progress state
2019-06-01 23:04:21.239 EDT [31831] PANIC:  replication checkpoint has
wrong magic 0 instead of 307747550
Aborted
-bash-4.2$
-bash-4.2$ /usr/pgsql-10/bin/postgres --single -D /data/patroni
--config-file=/data/patroni/postgresql.conf
2019-06-01 23:06:28.679 EDT [31969] LOG:  database system was interrupted;
last known up at 2019-04-28 06:06:24 EDT
2019-06-01 23:06:28.953 EDT [31969] LOG:  invalid record length at
0/4C35CDF8: wanted 24, got 0
2019-06-01 23:06:28.953 EDT [31969] LOG:  invalid primary checkpoint record
2019-06-01 23:06:28.953 EDT [31969] LOG:  using previous checkpoint record
at 0/4C34EDA8
2019-06-01 23:06:28.953 EDT [31969] PANIC:  replication checkpoint has
wrong magic 0 instead of 307747550
Aborted
-bash-4.2$



>
> > Removing the recovery.conf and restarting yields the following messages:
> >
> > 2019-06-01 20:31:12.231 EDT [21910] LOG:  database system was
> > interrupted; last known up at 2019-04-28 06:06:24 EDT
> > 2019-06-01 20:31:12.505 EDT [21910] LOG:  invalid record length at
> > 0/4C35CDF8: wanted 24, got 0
> > 2019-06-01 20:31:12.505 EDT [21910] LOG:  invalid primary checkpoint
> record
> > 2019-06-01 20:31:12.505 EDT [21910] LOG:  using previous checkpoint
> > record at 0/4C34EDA8
> > 2019-06-01 20:31:12.505 EDT [21910] DEBUG:  redo record is at
> > 0/4C34ED70; shutdown FALSE
> > 2019-06-01 20:31:12.505 EDT [21910] DEBUG:  next transaction ID:
> > 0:1409831; next OID: 237578
> > 2019-06-01 20:31:12.505 EDT [21910] DEBUG:  next MultiXactId: 48; next
> > MultiXactOffset: 174
> > 2019-06-01 20:31:12.505 EDT [21910] DEBUG:  oldest unfrozen transaction
> > ID: 549, in database 1
> > 2019-06-01 20:31:12.505 EDT [21910] DEBUG:  oldest MultiXactId: 1, in
> > database 1
> > 2019-06-01 20:31:12.505 EDT [21910] DEBUG:  commit timestamp Xid
>