Homebrew-core: brew postgresql-upgrade-database fails with initb

Created on 5 Sep 2020  路  12Comments  路  Source: Homebrew/homebrew-core

Bug report

I can now reproduce the problem. Please see post below to see problem in a reproducible format.

  • [ x] ran brew update and can still reproduce the problem?
    On the other hand, brew update did not update any postgresl formulae. I have also asked this [question]https://stackoverflow.com/questions/63749141/initb-fails-for-brew-postgresql-upgrade-database) on SO but received no answer.
  • [ x] ran brew doctor, fixed all issues and can still reproduce the problem?
    I have run brew doctor and fixed a number of issues, but cannot reproduce the problem (see above).
  • [ x] ran brew gist-logs <formula> (where <formula> is the name of the formula that failed) and included the output link?
    When I run brew gist-logs postgresql-upgrade-database I get this output:
    Error: No available formula with the name "postgresql-upgrade-database"
  • [ ] if brew gist-logs didn't work: ran brew config and brew doctor and included their output with your issue?
    Included brew_config.txt and brew_doctor.txt and brew_doctor1.txt (output of brew doctor after trying to fix issues outlined initial run of brew_doctor
    brew_config.txt
    temp_brew_doctor.txt
    brew_doctor1.txt
    temp_brew_update.txt

What you were trying to do (and why)

Running brew postgresql-upgrade-database to upgrade database and data from 11.8 to 12

What happened (include command output)


Command output



Upgrading postgresql data from 11 to 12...

Stopping postgresql@11... (might take a while)

==> Successfully stopped postgresql@11 (label: homebrew.mxcl.postgresql@11)

waiting for server to shut down.... done

server stopped

==> Moving postgresql data from /usr/local/var/postgres to /usr/local/var/postgres.old...

==> Creating database...

Error: Upgrading postgresql data from 11 to 12 failed!

==> Moving postgresql data back from /usr/local/var/postgres.old to /usr/local/var/postgres...

Error: Failure while executing; /usr/local/Cellar/postgresql/12.4/bin/initdb --lc-collate=en_US.UTF-8 --lc-ctype=en_US.UTF-8 --lc-messages=en_US.UTF-8 --lc-monetary=en_US.UTF-8 --lc-numeric=en_US.UTF-8 --lc-time=en_US.UTF-8 -E\ UTF8 /usr/local/var/postgres exited with 1.

What you expected to happen

I expected the version of posgres to be updated to the most recent version 12 and my data migrated from the version 11 format to the version 12 format.

Step-by-step reproduction instructions (by running brew install commands)

Just run brew postgresql-upgrade-database. This issue looks very similar to this issue.

help wanted
Source
picture obromios

Most helpful comment

Thanks @MikeMcQuaid. Understood. I'll try to take a look at it this week.

picture arbourd on 16 Nov 2020
👍2

All 12 comments

  • [ x] ran brew update and can still reproduce the problem?
    Yes.

  • [x ] ran brew doctor, fixed all issues and can still reproduce the problem?

  • [ x] ran brew gist-logs <formula> (where <formula> is the name of the formula that failed) and included the output link?
    When I run brew gist-logs postgresql-upgrade-database I get this output:
    Error: No available formula with the name "postgresql-upgrade-database"

  • [ x] if brew gist-logs didn't work: ran brew config and brew doctor and included their output with your issue?
    The output from brew doctor is
Warning: Some installed formulae were deleted!
You should find replacements for the following formulae:
  python@2

Warning: You have unlinked kegs in your Cellar.
Leaving kegs unlinked can lead to build-trouble and cause brews that depend on
those kegs to fail to run properly once built. Run `brew link` on these:
  python@2
  python

However I have [email protected] linked.

Output from brew_config was 

HOMEBREW_VERSION: 2.5.0
ORIGIN: https://github.com/Homebrew/brew.git
HEAD: 2ec8266697b2c9838cef86f8f97b5f392d0f926d
Last commit: 5 days ago
Core tap ORIGIN: https://github.com/Homebrew/homebrew-core
Core tap HEAD: 06a6ac51e2ed2930a21942ecfae1f8edcd5bfd67
Core tap last commit: 26 hours ago
Core tap branch: master
HOMEBREW_PREFIX: /usr/local
HOMEBREW_CASK_OPTS: []
HOMEBREW_MAKE_JOBS: 4
Homebrew Ruby: 2.6.3 => /System/Library/Frameworks/Ruby.framework/Versions/2.6/usr/bin/ruby
CPU: quad-core 64-bit kabylake
Clang: 11.0 build 1103
Git: 2.24.3 => /Library/Developer/CommandLineTools/usr/bin/git
Curl: 7.64.1 => /usr/bin/curl
macOS: 10.15.5-x86_64
CLT: 11.5.0.0.1.1588476445
Xcode: N/A

What you were trying to do (and why)

Running brew postgresql-upgrade-database to upgrade database and data from 11.8 to 12


Command output


==> Upgrading postgresql data from 11 to 12...

waiting for server to start....2020-09-13 07:31:24.237 AEST [22171] LOG:  listening on IPv6 address "::1", port 5432

2020-09-13 07:31:24.237 AEST [22171] LOG:  listening on IPv4 address "127.0.0.1", port 5432

2020-09-13 07:31:24.238 AEST [22171] LOG:  listening on Unix socket "/tmp/.s.PGSQL.5432"

2020-09-13 07:31:24.247 AEST [22172] LOG:  database system was shut down at 2020-09-13 07:31:09 AEST

2020-09-13 07:31:24.251 AEST [22171] LOG:  database system is ready to accept connections

 done

server started

waiting for server to shut down...2020-09-13 07:31:24.464 AEST [22171] LOG:  received fast shutdown request

.2020-09-13 07:31:24.466 AEST [22171] LOG:  aborting any active transactions

2020-09-13 07:31:24.467 AEST [22171] LOG:  background worker "logical replication launcher" (PID 22178) exited with exit code 1

2020-09-13 07:31:24.467 AEST [22173] LOG:  shutting down

2020-09-13 07:31:24.475 AEST [22171] LOG:  database system is shut down

 done

server stopped

==> Moving postgresql data from /usr/local/var/postgres to /usr/local/var/postgres.old...

==> Creating database...

Error: Upgrading postgresql data from 11 to 12 failed!

==> Moving postgresql data back from /usr/local/var/postgres.old to /usr/local/var/postgres...

Error: Failure while executing; /usr/local/Cellar/postgresql/12.4/bin/initdb --lc-collate=en_AU.UTF-8 --lc-ctype=en_AU.UTF-8 --lc-messages=en_AU.UTF-8 --lc-monetary=en_AU.UTF-8 --lc-numeric=en_AU.UTF-8 --lc-time=en_AU.UTF-8 -E\ UTF8 /usr/local/var/postgres exited with 1.

What you expected to happen

I expected the version of posgres to be updated to the most recent version 12 and my data migrated from the version 11 format to the version 12 format.

Step-by-step reproduction instructions (by running brew install commands)

These steps reproduce the problem:

  • brew install postgres
  • cd /usr/local/var/
  • rm -rf postgres
  • initdb /usr/local/var/postgres
  • brew postgresql-upgrade-database

This issue looks very similar to this issue.

obromios picture obromios on 13 Sep 2020

Can you do a brew update to pull in https://github.com/Homebrew/homebrew-core/pull/60694 and see if that resolves your issue?

dtrodrigues picture dtrodrigues on 14 Sep 2020

I did a brew update and it did update taps related to homebrew cask and core, but still had the same problem. I then updated the operating system from 10.15.5 to 10.15.6, did another brew update which updated a tap related to homebrew core, but still have the same problem.

obromios picture obromios on 14 Sep 2020

This is on a spare development laptop, so I have the option of fixing it by uninstalling version 11 and installing version 12, and recreating my databases from scratch. I am holding off doing this as it would mean I am not able to reproduce the problem for you. The spare machine is for travel, so just to let you know that I plan to do this next weekend, unless I hear from someone.

obromios picture obromios on 27 Sep 2020

As foreshadowed, my work around for this was to

brew uninstall --force postgresql
 brew install postgresql@12
cd /usr/local/var/
rm -rf postgres
initdb /usr/local/var/postgres

and all was right with the world. Clearly this means I had to reinitialise all my databases, so is only good for a development machine.

obromios picture obromios on 18 Oct 2020

I have not been able to successfully update my Postgres since 2015. I have lazily just reinitialized my database but know this is a problem vexing another developer on my team so have dug more into it since I currently have a reproducible issue on my machine migrating from 12 --> 13.


Shell output of brew postgresql-upgrade-database

mzagaja@Matthew-Zagaja-MacBook-Pro /u/l/v/p/pg_snapshots> brew postgresql-upgrade-database
==> Upgrading postgresql data from 12 to 13...
waiting for server to start....2020-11-15 18:34:52.883 EST [76559] LOG:  starting PostgreSQL 12.4 on x86_64-apple-darwin20.1.0, compiled by Apple clang version 12.0.0 (clang-1200.0.32.27), 64-bit
2020-11-15 18:34:52.885 EST [76559] LOG:  listening on IPv6 address "::1", port 5432
2020-11-15 18:34:52.885 EST [76559] LOG:  listening on IPv4 address "127.0.0.1", port 5432
2020-11-15 18:34:52.886 EST [76559] LOG:  listening on Unix socket "/tmp/.s.PGSQL.5432"
2020-11-15 18:34:52.925 EST [76560] LOG:  database system was shut down at 2020-11-15 18:15:22 EST
2020-11-15 18:34:52.933 EST [76559] LOG:  database system is ready to accept connections
 done
server started
waiting for server to shut down....2020-11-15 18:34:53.167 EST [76559] LOG:  received fast shutdown request
2020-11-15 18:34:53.169 EST [76559] LOG:  aborting any active transactions
2020-11-15 18:34:53.170 EST [76559] LOG:  background worker "logical replication launcher" (PID 76566) exited with exit code 1
2020-11-15 18:34:53.171 EST [76561] LOG:  shutting down
2020-11-15 18:34:53.186 EST [76559] LOG:  database system is shut down
 done
server stopped
==> Moving postgresql data from /usr/local/var/postgres to /usr/local/var/postgres.old...
==> Creating database...
The files belonging to this database system will be owned by user "mzagaja".
This user must also own the server process.

The database cluster will be initialized with locale "en_US.UTF-8".
The default text search configuration will be set to "english".

Data page checksums are disabled.

fixing permissions on existing directory /usr/local/var/postgres ... ok
creating subdirectories ... ok
selecting dynamic shared memory implementation ... posix
selecting default max_connections ... 100
selecting default shared_buffers ... 128MB
selecting default time zone ... America/New_York
creating configuration files ... ok
running bootstrap script ... ok
performing post-bootstrap initialization ... ok
syncing data to disk ... ok

initdb: warning: enabling "trust" authentication for local connections
You can change this by editing pg_hba.conf or using the option -A, or
--auth-local and --auth-host, the next time you run initdb.

Success. You can now start the database server using:

    /usr/local/opt/postgresql/bin/pg_ctl -D /usr/local/var/postgres -l logfile start

==> Migrating and upgrading data...
Performing Consistency Checks
-----------------------------
Checking cluster versions                                   ok
Checking database user is the install user                  ok
Checking database connection settings                       ok
Checking for prepared transactions                          ok
Checking for reg* data types in user tables                 ok
Checking for contrib/isn with bigint-passing mismatch       ok
Creating dump of global objects                             ok
Creating dump of database schemas
  dedham_master_plan_survey_development
*failure*

Consult the last few lines of "pg_upgrade_dump_53187.log" for
the probable cause of the failure.
Failure, exiting

*failure*

Consult the last few lines of "pg_upgrade_dump_54190.log" for
the probable cause of the failure.
Failure, exiting

*failure*

Consult the last few lines of "pg_upgrade_dump_18625.log" for
the probable cause of the failure.
Failure, exiting

*failure*

Consult the last few lines of "pg_upgrade_dump_18214.log" for
the probable cause of the failure.
Failure, exiting

child process exited abnormally: status 256
Failure, exiting
Error: Upgrading postgresql data from 12 to 13 failed!
==> Removing empty postgresql initdb database...
==> Moving postgresql data back from /usr/local/var/postgres.old to /usr/local/var/postgres...
Error: Failure while executing; `/usr/local/opt/postgresql/bin/pg_upgrade -r -b /usr/local/Cellar/postgresql@12/12.4_1/bin -B /usr/local/opt/postgresql/bin -d /usr/local/var/postgres.old -D /usr/local/var/postgres -j 4` exited with 1.

The error messages in the log files are mostly the same.


Log output from pg_dump

command: "/usr/local/opt/postgresql/bin/pg_dump" --host /usr/local/var/log --port 50432 --username mzagaja --schema-only --quote-all-identifiers --binary-upgrade --format=custom  --file="pg_upgrade_dump_18625.custom" 'dbname='"'"'ctnj-vote_test'"'"'' >> "pg_upgrade_dump_18625.log" 2>&1
pg_dump: error: query failed: FATAL:  terminating connection due to administrator command
server closed the connection unexpectedly
    This probably means the server terminated abnormally
    before or while processing the request.
pg_dump: error: query was: SELECT oid, tableoid, pol.polname, pol.polcmd, pol.polpermissive, CASE WHEN pol.polroles = '{0}' THEN NULL ELSE    pg_catalog.array_to_string(ARRAY(SELECT pg_catalog.quote_ident(rolname) from pg_catalog.pg_roles WHERE oid = ANY(pol.polroles)), ', ') END AS polroles, pg_catalog.pg_get_expr(pol.polqual, pol.polrelid) AS polqual, pg_catalog.pg_get_expr(pol.polwithcheck, pol.polrelid) AS polwithcheck FROM pg_catalog.pg_policy pol WHERE polrelid = '18626'
command: "/usr/local/opt/postgresql/bin/pg_dump" --host /usr/local/var/log --port 50432 --username mzagaja --schema-only --quote-all-identifiers --binary-upgrade --format=custom  --file="pg_upgrade_dump_18625.custom" 'dbname='"'"'ctnj-vote_test'"'"'' >> "pg_upgrade_dump_18625.log" 2>&1
pg_dump: error: query failed: FATAL:  terminating connection due to administrator command
server closed the connection unexpectedly
    This probably means the server terminated abnormally
    before or while processing the request.
pg_dump: error: query was: SELECT t.tableoid, t.oid, t.relname AS indexname, inh.inhparent AS parentidx, pg_catalog.pg_get_indexdef(i.indexrelid) AS indexdef, i.indnkeyatts AS indnkeyatts, i.indnatts AS indnatts, i.indkey, i.indisclustered, i.indisreplident, c.contype, c.conname, c.condeferrable, c.condeferred, c.tableoid AS contableoid, c.oid AS conoid, pg_catalog.pg_get_constraintdef(c.oid, false) AS condef, (SELECT spcname FROM pg_catalog.pg_tablespace s WHERE s.oid = t.reltablespace) AS tablespace, t.reloptions AS indreloptions, (SELECT pg_catalog.array_agg(attnum ORDER BY attnum)   FROM pg_catalog.pg_attribute   WHERE attrelid = i.indexrelid AND     attstattarget >= 0) AS indstatcols,(SELECT pg_catalog.array_agg(attstattarget ORDER BY attnum)   FROM pg_catalog.pg_attribute   WHERE attrelid = i.indexrelid AND     attstattarget >= 0) AS indstatvals FROM pg_catalog.pg_index i JOIN pg_catalog.pg_class t ON (t.oid = i.indexrelid) JOIN pg_catalog.pg_class t2 ON (t2.oid = i.indrelid) LEFT JOIN pg_catalog.pg_constraint c ON (i.indrelid = c.conrelid AND i.indexrelid = c.conindid AND c.contype IN ('p','u','x')) LEFT JOIN pg_catalog.pg_inherits inh ON (inh.inhrelid = indexrelid) WHERE i.indrelid = '18653'::pg_catalog.oid AND (i.indisvalid OR t2.relkind = 'p') AND i.indisready ORDER BY indexname

One of the pg_dump commands also fails due to PostGIS.


Log output from pg_dump

command: "/usr/local/opt/postgresql/bin/pg_dump" --host /usr/local/var/log --port 50432 --username mzagaja --schema-only --quote-all-identifiers --binary-upgrade --format=custom  --file="pg_upgrade_dump_53187.custom" 'dbname=art_spaces_development' >> "pg_upgrade_dump_53187.log" 2>&1
pg_dump: error: query failed: FATAL:  terminating connection due to administrator command
server closed the connection unexpectedly
    This probably means the server terminated abnormally
    before or while processing the request.
pg_dump: error: query was: SELECT tableoid, oid, collname, collnamespace, (SELECT rolname FROM pg_catalog.pg_roles WHERE oid = collowner) AS rolname FROM pg_collation
command: "/usr/local/opt/postgresql/bin/pg_dump" --host /usr/local/var/log --port 50432 --username mzagaja --schema-only --quote-all-identifiers --binary-upgrade --format=custom  --file="pg_upgrade_dump_53187.custom" 'dbname=art_spaces_development' >> "pg_upgrade_dump_53187.log" 2>&1
pg_dump: error: query failed: ERROR:  could not access file "$libdir/postgis-3": No such file or directory
pg_dump: error: query was: SELECT
a.attnum,
a.attname,
a.atttypmod,
a.attstattarget,
a.attstorage,
t.typstorage,
a.attnotnull,
a.atthasdef,
a.attisdropped,
a.attlen,
a.attalign,
a.attislocal,
pg_catalog.format_type(t.oid, a.atttypmod) AS atttypname,
a.attgenerated,
CASE WHEN a.atthasmissing AND NOT a.attisdropped THEN a.attmissingval ELSE null END AS attmissingval,
a.attidentity,
pg_catalog.array_to_string(ARRAY(SELECT pg_catalog.quote_ident(option_name) || ' ' || pg_catalog.quote_literal(option_value) FROM pg_catalog.pg_options_to_table(attfdwoptions) ORDER BY option_name), E',
    ') AS attfdwoptions,
CASE WHEN a.attcollation <> t.typcollation THEN a.attcollation ELSE 0 END AS attcollation,
array_to_string(a.attoptions, ', ') AS attoptions
FROM pg_catalog.pg_attribute a LEFT JOIN pg_catalog.pg_type t ON a.atttypid = t.oid
WHERE a.attrelid = '55202'::pg_catalog.oid AND a.attnum > 0::pg_catalog.int2
ORDER BY a.attnum

Looking at /usr/local/var/log/postgresql.log after doing a brew unlink postgresql && brew link postgresql@12 && brew services start postgresql@12 I can see

2020-11-15 23:51:27.459 GMT [88090] LOG:  could not open directory "/usr/local/share/postgresql/timezone": No such file or directory
2020-11-15 23:51:27.459 GMT [88090] LOG:  invalid value for parameter "log_timezone": "America/New_York"
2020-11-15 23:51:27.460 GMT [88090] LOG:  could not open directory "/usr/local/share/postgresql/timezone": No such file or directory
2020-11-15 23:51:27.460 GMT [88090] LOG:  invalid value for parameter "TimeZone": "America/New_York"
2020-11-15 23:51:27.460 GMT [88090] FATAL:  configuration file "/usr/local/var/postgres/postgresql.conf" contains errors

Googling did not reveal any ready to try fixes or culprits for the terminating connection log messages from Postgres. The culprit for me may or may not be PostGIS but I would expect more than one log file to include that error if it were blocking. I am open to next steps suggestions for debugging here.

mzagaja picture mzagaja on 16 Nov 2020

2020-11-15 23:51:27.459 GMT [88090] LOG: could not open directory "/usr/local/share/postgresql/timezone": No such file or directory

What's the output of ls -l /usr/local/share/postgresql/?

gromgit picture gromgit on 16 Nov 2020

I have not been able to successfully update my Postgres since 2015.

This predates the existence of this script which means we're unlikely to fix your issue.

Closing this out as it's specific to a few users. This script is provided as a helper and is a shallow wrapper around postgres commands. If it doesn't work for you: we'll need PRs or you'll need to intervene directly.

MikeMcQuaid picture MikeMcQuaid on 16 Nov 2020

I don't think it's specific to a few users. I think any pre-existing Postgres install is affected by this. Simply reinstalling doesn't work either.

This is breaking for Postgres 13 if you had 12 in before.

arbourd picture arbourd on 16 Nov 2020

Reopening but marking help wanted to make clear no maintainers are likely to fix this. I wrote this script already but don't use PostgreSQL in my development any more.

MikeMcQuaid picture MikeMcQuaid on 16 Nov 2020
👍2

Thanks @MikeMcQuaid. Understood. I'll try to take a look at it this week.

arbourd picture arbourd on 16 Nov 2020
👍2

I am happy to help debug this as well. I may have some bandwidth Wednesday and Thursday night.

mzagaja picture mzagaja on 17 Nov 2020
Was this page helpful?
0 / 5 - 0 ratings

Related issues

daviderestivo picture daviderestivo  路  4Comments
ghost picture ghost  路  3Comments
kiendang picture kiendang  路  3Comments
ralexx picture ralexx  路  4Comments
sstadick picture sstadick  路  4Comments