Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add-on is shutting down #16

Closed
Sholofly opened this issue Apr 1, 2022 · 47 comments
Closed

Add-on is shutting down #16

Sholofly opened this issue Apr 1, 2022 · 47 comments

Comments

@Sholofly
Copy link

Sholofly commented Apr 1, 2022

Hi can't start the addon anymore since upgrading to 2.0.0

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 system-defined composite types in user tables  ok
Checking for reg* data types in user tables                 ok
Checking for contrib/isn with bigint-passing mismatch       ok
Checking for user-defined encoding conversions              ok
Checking for user-defined postfix operators                 ok
Creating dump of global objects                             ok
Creating dump of database schemas
  dsmrreader
  homeassistant
  postgres
  template1
                                                            ok
Checking for presence of required libraries                 fatal
Your installation references loadable libraries that are missing from the
new installation.  You can add these libraries to the new installation,
or remove the functions using them from the old installation.  A list of
problem libraries is in the file:
    loadable_libraries.txt
Failure, exiting
[15:30:43] ERROR: PostgreSQL could not upgrade! Please inspect any errors in the lines above!
[15:30:43] ERROR: Upgrade was not succesfull.
[cont-init.d] init.sh: exited 1.
[cont-finish.d] executing container finish scripts...
[cont-finish.d] 99-message.sh: executing... 
-----------------------------------------------------------
                Oops! Something went wrong.

 We are so sorry, but something went terribly wrong when
 starting or running this add-on.
 
 Be sure to check the log above, line by line, for hints.
-----------------------------------------------------------
[cont-finish.d] 99-message.sh: exited 0.
[cont-finish.d] done.
[s6-finish] waiting for services.
[s6-finish] sending all processes the TERM signal.
[s6-finish] sending all processes the KILL signal and exiting.

How do iI access the loadable_libraries.txt?

@dhover
Copy link

dhover commented Apr 1, 2022

The file loadable_libraries.txt should be inside the container. You can start a shell inside the container with the Portainer AddOn.
Install the Portainer AddOn and start the WebUI then go to Containers and search for the timescaledb container.

image

Press on the fourth icon to start the shell inside the container.

@expaso
Copy link
Owner

expaso commented Apr 1, 2022

If I could get a hand on that file, I could see what library he is talking about, and maybe compile it in.
Also, what architecture are you on?

@mgiebels
Copy link

mgiebels commented Apr 1, 2022

I have the same problem when I upgrade.
I have downgrade it to the previous version and it works again
Iam on a Nuc with hass only on it

@Sholofly
Copy link
Author

Sholofly commented Apr 2, 2022

After a full reboot this issue was gone and then I had the same issue as in #15. Because of that I downgraded the add on with a backup. It's now running smoothly again.

@expaso
Copy link
Owner

expaso commented Apr 2, 2022

@Sholofly , the postgis message is not fatal.
It's just trying to upgrade postgis just to be sure, otherwise the upgrade process would fail.

Can you confirm this? Or do you still have update issues?

@mgiebels
Copy link

mgiebels commented Apr 2, 2022

Same issue here or is the upgrade taking long?

Data page checksums are disabled.
fixing permissions on existing directory /data/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 ... UTC
creating configuration files ... ok
running bootstrap script ... ok
sh: locale: not found
2022-04-02 19:04:31.507 UTC [343] WARNING: no usable system locales were found
performing post-bootstrap initialization ... ok
syncing data to disk ... ok
Success.
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.
[21:04:35] INFO: done
[21:04:35] NOTICE: Upgrading PostgreSql...
[21:04:35] INFO: Starting PostgreSQL-12 first..
2022-04-02 19:04:35.430 UTC [355] LOG: starting PostgreSQL 12.10 on x86_64-alpine-linux-musl, compiled by gcc (Alpine 10.3.1_git20211027) 10.3.1 20211027, 64-bit
2022-04-02 19:04:35.431 UTC [355] LOG: listening on IPv4 address "0.0.0.0", port 5432
2022-04-02 19:04:35.431 UTC [355] LOG: listening on IPv6 address "::", port 5432
2022-04-02 19:04:35.449 UTC [355] LOG: listening on Unix socket "/run/postgresql/.s.PGSQL.5432"
2022-04-02 19:04:35.468 UTC [355] LOG: listening on Unix socket "/tmp/.s.PGSQL.5432"
2022-04-02 19:04:35.506 UTC [360] LOG: database system was shut down at 2022-04-02 19:04:23 UTC
2022-04-02 19:04:35.520 UTC [355] LOG: database system is ready to accept connections
2022-04-02 19:04:35.525 UTC [366] LOG: TimescaleDB background worker launcher connected to shared catalogs
[21:04:36] INFO: Upgrading Timescale extentions..
[21:04:36] INFO: Updating Timescale Extension for database system databases..
2022-04-02 19:04:36.440 UTC [368] LOG: terminating TimescaleDB job scheduler due to administrator command
2022-04-02 19:04:36.441 UTC [368] FATAL: terminating connection due to administrator command
2022-04-02 19:04:36.443 UTC [355] LOG: background worker "TimescaleDB Background Worker Scheduler" (PID 368) exited with exit code 1
terminating TimescaleDB scheduler entrypoint due to administrator command2022-04-02 19:04:37.155 UTC [382] FATAL: terminating connection due to administrator command
2022-04-02 19:04:37.156 UTC [355] LOG: background worker "TimescaleDB Background Worker Scheduler" (PID 382) exited with exit code 1
ALTER EXTENSION
terminating TimescaleDB scheduler entrypoint due to administrator command2022-04-02 19:04:37.998 UTC [387] FATAL: terminating connection due to administrator command
2022-04-02 19:04:37.999 UTC [355] LOG: background worker "TimescaleDB Background Worker Scheduler" (PID 387) exited with exit code 1
2022-04-02 19:04:38.032 UTC [389] ERROR: TimescaleDB background worker connected to template database, exiting
2022-04-02 19:04:38.033 UTC [355] LOG: background worker "TimescaleDB Background Worker Scheduler" (PID 389) exited with exit code 1
ALTER EXTENSION
[21:04:38] INFO: Updating Timescale Extension for database: 'homeassistant'
2022-04-02 19:04:38.137 UTC [371] LOG: terminating TimescaleDB job scheduler due to administrator command
2022-04-02 19:04:38.137 UTC [371] FATAL: terminating connection due to administrator command
2022-04-02 19:04:38.138 UTC [355] LOG: background worker "TimescaleDB Background Worker Scheduler" (PID 371) exited with exit code 1
terminating TimescaleDB scheduler entrypoint due to administrator command2022-04-02 19:04:39.010 UTC [398] FATAL: terminating connection due to administrator command
2022-04-02 19:04:39.011 UTC [355] LOG: background worker "TimescaleDB Background Worker Scheduler" (PID 398) exited with exit code 1
ALTER EXTENSION
[21:04:39] INFO: done
2022-04-02 19:04:39.058 UTC [355] LOG: received smart shutdown request
2022-04-02 19:05:35.584 UTC [441] FATAL: the database system is shutting down
2022-04-02 19:05:36.340 UTC [443] FATAL: the database system is shutting down
2022-04-02 19:05:37.578 UTC [445] FATAL: the database system is shutting down
2022-04-02 19:05:39.574 UTC [447] FATAL: the database system is shutting down
2022-04-02 19:05:41.438 UTC [449] FATAL: the database system is shutting down
2022-04-02 19:05:41.586 UTC [450] FATAL: the database system is shutting down
2022-04-02 19:05:43.579 UTC [453] FATAL: the database system is shutting down
2022-04-02 19:05:45.581 UTC [455] FATAL: the database system is shutting down
2022-04-02 19:05:46.536 UTC [457] FATAL: the database system is shutting down
2022-04-02 19:05:47.577 UTC [459] FATAL: the database system is shutting down
2022-04-02 19:05:49.574 UTC [461] FATAL: the database system is shutting down
2022-04-02 19:05:51.574 UTC [463] FATAL: the database system is shutting down
2022-04-02 19:05:51.636 UTC [465] FATAL: the database system is shutting down
2022-04-02 19:05:53.569 UTC [467] FATAL: the database system is shutting down
2022-04-02 19:05:55.563 UTC [469] FATAL: the database system is shutting down
2022-04-02 19:05:56.616 UTC [471] FATAL: the database system is shutting down
2022-04-02 19:05:56.647 UTC [472] FATAL: the database system is shutting down
2022-04-02 19:05:56.735 UTC [473] FATAL: the database system is shutting down
2022-04-02 19:06:01.831 UTC [478] FATAL: the database system is shutting down
2022-04-02 19:06:06.966 UTC [482] FATAL: the database system is shutting down
2022-04-02 19:06:12.080 UTC [487] FATAL: the database system is shutting down
2022-04-02 19:06:17.192 UTC [491] FATAL: the database system is shutting down
2022-04-02 19:06:22.295 UTC [496] FATAL: the database system is shutting down
2022-04-02 19:06:27.394 UTC [501] FATAL: the database system is shutting down
2022-04-02 19:06:32.501 UTC [505] FATAL: the database system is shutting down
2022-04-02 19:06:37.610 UTC [510] FATAL: the database system is shutting down
2022-04-02 19:06:38.052 UTC [511] FATAL: the database system is shutting down
2022-04-02 19:06:42.709 UTC [515] FATAL: the database system is shutting down
2022-04-02 19:06:47.811 UTC [520] FATAL: the database system is shutting down
2022-04-02 19:06:52.911 UTC [524] FATAL: the database system is shutting down
2022-04-02 19:06:58.013 UTC [529] FATAL: the database system is shutting down
2022-04-02 19:07:03.120 UTC [533] FATAL: the database system is shutting down
2022-04-02 19:07:08.232 UTC [538] FATAL: the database system is shutting down
2022-04-02 19:07:13.338 UTC [543] FATAL: the database system is shutting down
2022-04-02 19:07:18.442 UTC [547] FATAL: the database system is shutting down
2022-04-02 19:07:23.553 UTC [552] FATAL: the database system is shutting down
2022-04-02 19:07:28.657 UTC [556] FATAL: the database system is shutting down
2022-04-02 19:07:33.757 UTC [561] FATAL: the database system is shutting down
2022-04-02 19:07:38.861 UTC [566] FATAL: the database system is shutting down
2022-04-02 19:07:43.970 UTC [570] FATAL: the database system is shutting down
2022-04-02 19:07:49.075 UTC [575] FATAL: the database system is shutting down
2022-04-02 19:07:54.179 UTC [579] FATAL: the database system is shutting down
2022-04-02 19:07:59.280 UTC [584] FATAL: the database system is shutting down
2022-04-02 19:08:04.383 UTC [588] FATAL: the database system is shutting down
2022-04-02 19:08:09.490 UTC [593] FATAL: the database system is shutting down
2022-04-02 19:08:14.596 UTC [597] FATAL: the database system is shutting down

@expaso
Copy link
Owner

expaso commented Apr 3, 2022

Indeed, the system is being shutdown from outside, and could not complete it's upgrade.
What are your system specs? I will try to test with synthetic extra delays to reproduce

@arjen-w
Copy link

arjen-w commented Apr 3, 2022

I have the same issue. The loadable-libraries.txt shows the following:
could not load library "$libdir/timescaledb-1.7.4": ERROR: could not access file "$libdir/timescaledb-1.7.4": No such file or directory
In database: dsmrreader

pg_upgrade_dump shows:
command: "/usr/libexec/postgresql14/pg_dump" --host /data/postgres12 --port 50432 --username postgres --schema-only --quote-all-identifiers --binary-upgrade --format=custom --file="pg_upgrade_dump_1.custom" 'dbname=template1' >> "pg_upgrade_dump_1.log" 2>&1
pg_dump: warning: there are circular foreign-key constraints on this table:
pg_dump: hypertable
pg_dump: You might not be able to restore the dump without using --disable-triggers or temporarily dropping the constraints.
pg_dump: Consider using a full dump instead of a --data-only dump to avoid this problem.
pg_dump: warning: there are circular foreign-key constraints on this table:
pg_dump: chunk
pg_dump: You might not be able to restore the dump without using --disable-triggers or temporarily dropping the constraints.
pg_dump: Consider using a full dump instead of a --data-only dump to avoid this problem.

pg_upgrade_server_log shows:
command: "/usr/libexec/postgresql12/pg_ctl" -w -l "pg_upgrade_server.log" -D "/data/postgres12" -o "-p 50432 -b -c listen_addresses='' -c unix_socket_permissions=0700 -c unix_socket_directories='/data/postgres12'" start >> "pg_upgrade_server.log" 2>&1
waiting for server to start....2022-04-03 09:34:13.832 UTC [412] LOG: starting PostgreSQL 12.10 on x86_64-alpine-linux-musl, compiled by gcc (Alpine 10.3.1_git20211027) 10.3.1 20211027, 64-bit
2022-04-03 09:34:13.838 UTC [412] LOG: listening on Unix socket "/data/postgres12/.s.PGSQL.50432"
2022-04-03 09:34:13.872 UTC [413] LOG: database system was shut down at 2022-04-03 09:34:13 UTC
2022-04-03 09:34:13.881 UTC [412] LOG: database system is ready to accept connections
2022-04-03 09:34:13.883 UTC [418] LOG: TimescaleDB background worker launcher connected to shared catalogs
2022-04-03 09:34:13.903 UTC [420] ERROR: tried calling catalog_get when extension isn't loaded
2022-04-03 09:34:13.904 UTC [412] LOG: background worker "TimescaleDB Background Worker Scheduler" (PID 420) exited with exit code 1
2022-04-03 09:34:13.908 UTC [421] ERROR: tried calling catalog_get when extension isn't loaded
2022-04-03 09:34:13.909 UTC [422] ERROR: tried calling catalog_get when extension isn't loaded
2022-04-03 09:34:13.910 UTC [412] LOG: background worker "TimescaleDB Background Worker Scheduler" (PID 421) exited with exit code 1
2022-04-03 09:34:13.911 UTC [412] LOG: background worker "TimescaleDB Background Worker Scheduler" (PID 422) exited with exit code 1
done
server started

I have created a complete file copy of the add-on after the upgrade, so if you want more info, let me know.

@expaso
Copy link
Owner

expaso commented Apr 4, 2022

Hi @arjen-w,

Do you have enough free disk space to perform the upgrade?

ERROR: tried calling catalog_get when extension looks like na old error: timescale/timescaledb#1682 (comment)

If so, could you please pass the file-copy of the addon so I can investigate.

@expaso
Copy link
Owner

expaso commented Apr 4, 2022

After investigating all your logs, I think I could identify 2 issues:

  1. During Upgrade: ERROR: tried calling catalog_get when extension isn't loaded.

This is a timescale-bug (timescale/timescaledb#1682 (comment)) that sometimes seems triggered. Perhaps due to low disk-space during upgrade?

  1. Upgrade was aborted with error, after reboot a "clean installation" is performed by the addon.

Errors like Your installation references loadable libraries that are missing from the new installation are observed.
This seems to be related to the 2-step upgrade process of the timescale add-on.
First, the addon starts an old postgresql 12 server, and tries to update timescale to 2.6, otherwise pg_update cannot upgrade.
Next, a full upgrade to Postgresql 14 is performed, using the Postgresql 14 version of Timescale.

This first step is failing, and it looks like the upgrade to Timescale 2.6 fails because the database is actively being used (thus, the timescale addon is being loaded).

To fix this, I'm building a new update that tries to block incoming connections during this process...

For users that don't have a backup, and are stuck with the 'empty password' problem: no worries. All your data is still there. Please give a shout here and I will instruct how to retry the upgrade process using your original data.

@snerdish
Copy link

snerdish commented Apr 4, 2022

Thanks for following this up - if there's a gist with the procedure to retry the upgrade process with original data I'd be happy to give it a whirl.

@arjen-w
Copy link

arjen-w commented Apr 5, 2022

Hi @arjen-w,

Do you have enough free disk space to perform the upgrade?

ERROR: tried calling catalog_get when extension looks like na old error: timescale/timescaledb#1682 (comment)

If so, could you please pass the file-copy of the addon so I can investigate.

I defintely do have enough diskspace.
I can provide a copy of the failed upgrade and a copy of the current add-on.
Do you want them as an HA backup or just as a plain file copy (zipped)?

@expaso
Copy link
Owner

expaso commented Apr 5, 2022

@arjen-w a plan zipped copy fill do fine. All files and logfiles there! Thanks so much!

@arjen-w
Copy link

arjen-w commented Apr 5, 2022

you should be able to download it from here: https://1drv.ms/u/s!ArMQ8sywUxlQiuIRvO3bmWkLXxwFKQ PAssword is timescaledb

@woutercoppens
Copy link

Problem is still present in 2.0.1

`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 system-defined composite types in user tables ok
Checking for reg* data types in user tables ok
Checking for contrib/isn with bigint-passing mismatch ok
Checking for user-defined encoding conversions ok
Checking for user-defined postfix operators ok
Creating dump of global objects ok
Creating dump of database schemas
dsmrreader
homeassistant
postgres
template1
ok
Checking for presence of required libraries fatal
Your installation references loadable libraries that are missing from the
new installation. You can add these libraries to the new installation,
or remove the functions using them from the old installation. A list of
problem libraries is in the file:
loadable_libraries.txt
Failure, exiting
[15:27:08] ERROR: PostgreSQL could not upgrade! Please inspect any errors in the lines above!
[15:27:08] ERROR: Upgrade was not succesfull.
[cont-init.d] init.sh: exited 1.
[cont-finish.d] executing container finish scripts...
[cont-finish.d] 99-message.sh: executing...

            Oops! Something went wrong.

We are so sorry, but something went terribly wrong when
starting or running this add-on.

Be sure to check the log above, line by line, for hints.

[cont-finish.d] 99-message.sh: exited 0.
[cont-finish.d] done.
[s6-finish] waiting for services.
[s6-finish] sending all processes the TERM signal.`

@mgiebels
Copy link

mgiebels commented Apr 5, 2022

Also here on 2.0.1 it is not working

--auth-local and --auth-host, the next time you run initdb.
syncing data to disk ... ok
Success.
[15:59:12] INFO: done
[15:59:12] NOTICE: Upgrading PostgreSql...
[15:59:12] INFO: Starting PostgreSQL-12 first..
2022-04-05 13:59:12.545 UTC [356] LOG: starting PostgreSQL 12.10 on x86_64-alpine-linux-musl, compiled by gcc (Alpine 10.3.1_git20211027) 10.3.1 20211027, 64-bit
2022-04-05 13:59:12.545 UTC [356] LOG: listening on IPv4 address "0.0.0.0", port 5432
2022-04-05 13:59:12.545 UTC [356] LOG: listening on IPv6 address "::", port 5432
2022-04-05 13:59:12.563 UTC [356] LOG: listening on Unix socket "/run/postgresql/.s.PGSQL.5432"
2022-04-05 13:59:12.581 UTC [356] LOG: listening on Unix socket "/tmp/.s.PGSQL.5432"
2022-04-05 13:59:12.627 UTC [361] LOG: database system was shut down at 2022-04-05 13:58:40 UTC
2022-04-05 13:59:12.643 UTC [356] LOG: database system is ready to accept connections
2022-04-05 13:59:12.645 UTC [367] LOG: TimescaleDB background worker launcher connected to shared catalogs
[15:59:13] INFO: Upgrading Timescale extentions..
[15:59:13] INFO: Updating Timescale Extension for database system databases..
NOTICE: version "2.6.0" of extension "timescaledb" is already installed
ALTER EXTENSION
ALTER EXTENSION
NOTICE: version "2.6.0" of extension "timescaledb" is already installed
[15:59:13] INFO: Updating Timescale Extension for database: 'homeassistant'
NOTICE: version "2.6.0" of extension "timescaledb" is already installed
ALTER EXTENSION
[15:59:13] INFO: done
2022-04-05 13:59:13.652 UTC [356] LOG: received smart shutdown request
2022-04-05 13:59:13.663 UTC [373] LOG: terminating TimescaleDB job scheduler due to administrator command
2022-04-05 13:59:13.663 UTC [374] LOG: terminating TimescaleDB job scheduler due to administrator command
2022-04-05 13:59:13.663 UTC [372] LOG: terminating TimescaleDB job scheduler due to administrator command
2022-04-05 13:59:13.664 UTC [374] FATAL: terminating connection due to administrator command
2022-04-05 13:59:13.664 UTC [372] FATAL: terminating connection due to administrator command
2022-04-05 13:59:13.664 UTC [369] LOG: terminating TimescaleDB job scheduler due to administrator command
2022-04-05 13:59:13.664 UTC [369] FATAL: terminating connection due to administrator command
2022-04-05 13:59:13.665 UTC [371] LOG: terminating TimescaleDB job scheduler due to administrator command
2022-04-05 13:59:13.665 UTC [371] FATAL: terminating connection due to administrator command
2022-04-05 13:59:13.665 UTC [373] FATAL: terminating connection due to administrator command
2022-04-05 13:59:13.666 UTC [370] LOG: terminating TimescaleDB job scheduler due to administrator command
2022-04-05 13:59:13.666 UTC [370] FATAL: terminating connection due to administrator command
2022-04-05 13:59:13.666 UTC [356] LOG: background worker "TimescaleDB Background Worker Scheduler" (PID 374) exited with exit code 1
terminating TimescaleDB background worker launcher due to administrator command2022-04-05 13:59:13.668 UTC [356] LOG: background worker "TimescaleDB Background Worker Scheduler" (PID 370) exited with exit code 1
2022-04-05 13:59:13.668 UTC [367] FATAL: terminating connection due to administrator command
2022-04-05 13:59:13.668 UTC [356] LOG: background worker "TimescaleDB Background Worker Scheduler" (PID 371) exited with exit code 1
2022-04-05 13:59:13.668 UTC [356] LOG: background worker "logical replication launcher" (PID 368) exited with exit code 1
2022-04-05 13:59:13.668 UTC [356] LOG: background worker "TimescaleDB Background Worker Scheduler" (PID 373) exited with exit code 1
2022-04-05 13:59:13.669 UTC [372] LOG: terminating TimescaleDB job scheduler due to administrator command
2022-04-05 13:59:13.669 UTC [356] LOG: background worker "TimescaleDB Background Worker Launcher" (PID 367) exited with exit code 1
2022-04-05 13:59:13.669 UTC [356] LOG: background worker "TimescaleDB Background Worker Scheduler" (PID 369) exited with exit code 1
2022-04-05 13:59:13.670 UTC [356] LOG: background worker "TimescaleDB Background Worker Scheduler" (PID 372) exited with exit code 1
2022-04-05 13:59:13.670 UTC [362] LOG: shutting down
2022-04-05 13:59:13.762 UTC [356] LOG: database system is shut down
[15:59:13] NOTICE: Upgrading databases..
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 system-defined composite types in user tables ok
Checking for reg* data types in user tables ok
Checking for contrib/isn with bigint-passing mismatch ok
Checking for user-defined encoding conversions ok
Checking for user-defined postfix operators ok
Creating dump of global objects ok
Creating dump of database schemas
dsmrreader
dsmrreader2
dsmrreaderltem
homeassistant
metabase
postgres
template1
ok
Checking for presence of required libraries fatal
Your installation references loadable libraries that are missing from the
new installation. You can add these libraries to the new installation,
or remove the functions using them from the old installation. A list of
problem libraries is in the file:
loadable_libraries.txt
Failure, exiting
[15:59:21] ERROR: PostgreSQL could not upgrade! Please inspect any errors in the lines above!
[15:59:21] ERROR: Upgrade was not succesfull.
[cont-init.d] init.sh: exited 1.
[cont-finish.d] executing container finish scripts...
[cont-finish.d] 99-message.sh: executing...

            Oops! Something went wrong.

We are so sorry, but something went terribly wrong when
starting or running this add-on.

Be sure to check the log above, line by line, for hints.

[cont-finish.d] 99-message.sh: exited 0.
[cont-finish.d] done.
[s6-finish] waiting for services.
[s6-finish] sending all processes the TERM signal.

@bartbakels
Copy link

Same issue here on v2 and v2.01

@deku-m
Copy link

deku-m commented Apr 5, 2022

Got the same as above 2.0.1 still fails.

selecting dynamic shared memory implementation ... posix
selecting default max_connections ... 100
selecting default shared_buffers ... 128MB
selecting default time zone ... UTC
creating configuration files ... ok
running bootstrap script ... ok
sh: locale: not found
2022-04-05 18:13:36.332 UTC [344] WARNING:  no usable system locales were found
performing post-bootstrap initialization ... 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.
syncing data to disk ... ok
Success.
[20:13:36] INFO: done
[20:13:36] NOTICE: Upgrading PostgreSql...
[20:13:36] INFO: Starting PostgreSQL-12 first..
2022-04-05 18:13:36.988 UTC [357] LOG:  starting PostgreSQL 12.10 on x86_64-alpine-linux-musl, compiled by gcc (Alpine 10.3.1_git20211027) 10.3.1 20211027, 64-bit
2022-04-05 18:13:36.989 UTC [357] LOG:  listening on IPv4 address "0.0.0.0", port 5432
2022-04-05 18:13:36.989 UTC [357] LOG:  listening on IPv6 address "::", port 5432
2022-04-05 18:13:36.993 UTC [357] LOG:  listening on Unix socket "/run/postgresql/.s.PGSQL.5432"
2022-04-05 18:13:36.997 UTC [357] LOG:  listening on Unix socket "/tmp/.s.PGSQL.5432"
2022-04-05 18:13:37.007 UTC [362] LOG:  database system was shut down at 2022-04-05 18:13:11 UTC
2022-04-05 18:13:37.011 UTC [357] LOG:  database system is ready to accept connections
2022-04-05 18:13:37.013 UTC [368] LOG:  TimescaleDB background worker launcher connected to shared catalogs
[20:13:37] INFO: Upgrading Timescale extentions..
[20:13:37] INFO: Updating Timescale Extension for database system databases..
NOTICE:  version "2.6.0" of extension "timescaledb" is already installed
ALTER EXTENSION
NOTICE:  version "2.6.0" of extension "timescaledb" is already installed
ALTER EXTENSION
[20:13:38] INFO: Updating Timescale Extension for database: 'homeassistant'
NOTICE:  version "2.6.0" of extension "timescaledb" is already installed
ALTER EXTENSION
[20:13:38] INFO: done
2022-04-05 18:13:38.043 UTC [357] LOG:  received smart shutdown request
2022-04-05 18:13:38.047 UTC [372] LOG:  terminating TimescaleDB job scheduler due to administrator command
2022-04-05 18:13:38.047 UTC [371] LOG:  terminating TimescaleDB job scheduler due to administrator command
2022-04-05 18:13:38.047 UTC [371] FATAL:  terminating connection due to administrator command
2022-04-05 18:13:38.048 UTC [370] LOG:  terminating TimescaleDB job scheduler due to administrator command
2022-04-05 18:13:38.048 UTC [372] FATAL:  terminating connection due to administrator command
terminating TimescaleDB background worker launcher due to administrator command2022-04-05 18:13:38.049 UTC [368] FATAL:  terminating connection due to administrator command
2022-04-05 18:13:38.049 UTC [370] FATAL:  terminating connection due to administrator command
2022-04-05 18:13:38.049 UTC [357] LOG:  background worker "logical replication launcher" (PID 369) exited with exit code 1
2022-04-05 18:13:38.049 UTC [370] LOG:  terminating TimescaleDB job scheduler due to administrator command
2022-04-05 18:13:38.049 UTC [357] LOG:  background worker "TimescaleDB Background Worker Scheduler" (PID 371) exited with exit code 1
2022-04-05 18:13:38.049 UTC [357] LOG:  background worker "TimescaleDB Background Worker Scheduler" (PID 372) exited with exit code 1
2022-04-05 18:13:38.050 UTC [357] LOG:  background worker "TimescaleDB Background Worker Launcher" (PID 368) exited with exit code 1
2022-04-05 18:13:38.051 UTC [357] LOG:  background worker "TimescaleDB Background Worker Scheduler" (PID 370) exited with exit code 1
2022-04-05 18:13:38.051 UTC [363] LOG:  shutting down
2022-04-05 18:13:38.072 UTC [357] LOG:  database system is shut down
[20:13:38] NOTICE: Upgrading databases..
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 system-defined composite types in user tables  ok
Checking for reg* data types in user tables                 ok
Checking for contrib/isn with bigint-passing mismatch       ok
Checking for user-defined encoding conversions              ok
Checking for user-defined postfix operators                 ok
Creating dump of global objects                             ok
Creating dump of database schemas
  dsmrreader
  homeassistant
  postgres
  template1
                                                            ok
Checking for presence of required libraries                 fatal
Your installation references loadable libraries that are missing from the
new installation.  You can add these libraries to the new installation,
or remove the functions using them from the old installation.  A list of
problem libraries is in the file:
    loadable_libraries.txt
Failure, exiting
[20:13:40] ERROR: PostgreSQL could not upgrade! Please inspect any errors in the lines above!
[20:13:40] ERROR: Upgrade was not succesfull.
[cont-init.d] init.sh: exited 1.
[cont-finish.d] executing container finish scripts...
[cont-finish.d] 99-message.sh: executing... 
-----------------------------------------------------------
                Oops! Something went wrong.

 We are so sorry, but something went terribly wrong when
 starting or running this add-on.
 
 Be sure to check the log above, line by line, for hints.
-----------------------------------------------------------
[cont-finish.d] 99-message.sh: exited 0.
[cont-finish.d] done.
[s6-finish] waiting for services.
[s6-finish] sending all processes the TERM signal.
[s6-finish] sending all processes the KILL signal and exiting.

@expaso
Copy link
Owner

expaso commented Apr 5, 2022

Hey... wait! @deku-m, @arjen-w, @bartbakels and @mgiebels,

Do you have your timescale-capable databases listed in the configuration-section?
If not, can you fill them in?
The addon loops trough this list to determine what databases actually use Timescale, and upgrades the timescale addon only in those databases, before trying to do the conversion to Postgres 14.

image

In the add-on dump from @arjen-w (thanks again! really helpful!) I see this error in the loadable_libraries.txt:

could not load library "$libdir/timescaledb-1.7.4": ERROR: could not access file "$libdir/timescaledb-1.7.4": No such file or directory In database: dsmrreader

But not in other databases....

@Simanias
Copy link

Simanias commented Apr 5, 2022

@expaso both databases are timescale enabled and I have the same problems as mentioned above.
Schermafbeelding 2022-04-05 om 22 06 41

@expaso
Copy link
Owner

expaso commented Apr 5, 2022

@Simanias, could you post the error message from the loadable_libraries.txt file? It's located within the addon in the /data/postgres directory after the addon tried to upgrade.

It will tell what database is flawed, and what add-on version he is trying to load.
For all the above, it's trying to load the old timescale version (1.7.4) instead of 2.6.0.

Or can you post a screenshot from pg_admin and view the extensions, like so:

image

@expaso expaso closed this as completed Apr 5, 2022
@expaso expaso reopened this Apr 5, 2022
@arjen-w
Copy link

arjen-w commented Apr 6, 2022

@expaso both databases are timescale enabled and I have the same problems as mentioned above. Schermafbeelding 2022-04-05 om 22 06 41

Same here. databases are listed as shown by @Simanias .
Error is indeed looking for extension 1.7.4
My screenshot of PgAdmin:
image

@expaso
Copy link
Owner

expaso commented Apr 6, 2022

Hi @arjen-w,

I am really trying to wrap my head around this: In the archive you sent me, the dsmrreader database is not in the timescale-enabled list of the addon config:

image

And it is exactly this missing database that is complaining about the upgrade.
But in your screenshot, it's there in the list.

What is your state of the addon now? Are you running 1.1.6 with this database enabled?

Either way, I will try to see if I can just query this for the upgrade, instead of relying on this list.

@deku-m
Copy link

deku-m commented Apr 7, 2022

Hey... wait! @deku-m, @arjen-w, @bartbakels and @mgiebels,

Do you have your timescale-capable databases listed in the configuration-section? If not, can you fill them in? The addon loops trough this list to determine what databases actually use Timescale, and upgrades the timescale addon only in those databases, before trying to do the conversion to Postgres 14.

image

In the add-on dump from @arjen-w (thanks again! really helpful!) I see this error in the loadable_libraries.txt:

could not load library "$libdir/timescaledb-1.7.4": ERROR: could not access file "$libdir/timescaledb-1.7.4": No such file or directory In database: dsmrreader

But not in other databases....

HI,

Indeed at my side it was the timescale_enabled which was missing for dsmr.
Addon is now up and running.

@arjen-w
Copy link

arjen-w commented Apr 7, 2022

HI,

Indeed at my side it was the timescale_enabled which was missing for dsmr. Addon is now up and running.

Same here! after adding it into the config lines, the upgrade went fine! Not sure how I missed that yesterday whilie I was checking that...

@expaso
Copy link
Owner

expaso commented Apr 7, 2022

Sweet! 🥳! I thought I was going nuts! 🤯 ..
Thanks for your confirmation!

I have the code ready to not rely on this list, but instead query it out myself, just to be sure.
Can do the same for the Postgis exention (this clears some non-fatal but confusing errors from the logs).
Will test this out and launch in a couple of days, but at least it's not necessary for the upgrade process.

As you can see, it's not a trivial upgrade within the add-on itself. That's why it took a while ;).
I had to juggle multiple Postgres versions and extensions around in just the right mix with different architectures.
Unless Postgres 15 is around the corner, the updates will be minimal and focused again around TimescaleDB itself.

Thank you all for your support! 🙏

@mgiebels
Copy link

mgiebels commented Apr 7, 2022

It didn't work for me and I just started over so I lost old data unfortunately.
After my upgrade to 2.0.1 it went wrong.
And a rollback also failed, he no longer starts.
And I don't get old data back either I work on Homeassistant on NUC but I don't work with docker installed it directly on the ssd.

@DavyRoswinkel
Copy link

I only keep getting the Postgis error. Apart from that everything works.

@expaso
Copy link
Owner

expaso commented Apr 7, 2022

I only keep getting the Postgis error. Apart from that everything works.

This error is non-fatal. The addon tries to update this extension on all databases just to be sure.
I will push an update soon that will be a little bit more intelligent about this, but it's not fatal.

@expaso
Copy link
Owner

expaso commented Apr 7, 2022

It didn't work for me and I just started over so I lost old data unfortunately. After my upgrade to 2.0.1 it went wrong. And a rollback also failed, he no longer starts. And I don't get old data back either I work on Homeassistant on NUC but I don't work with docker installed it directly on the ssd.

I can help you with this. I assume you did not press 'remove' on the addon? If not, your data is still there.
Do you run HASSOS? Or are you running another form of supervised Home Assistant?

@mgiebels
Copy link

mgiebels commented Apr 7, 2022

It didn't work for me and I just started over so I lost old data unfortunately. After my upgrade to 2.0.1 it went wrong. And a rollback also failed, he no longer starts. And I don't get old data back either I work on Homeassistant on NUC but I don't work with docker installed it directly on the ssd.

I can help you with this. I assume you did not press 'remove' on the addon? If not, your data is still there. Do you run HASSOS? Or are you running another form of supervised Home Assistant?

I did press remove because I couldn't get it to work anymore.
But I had a sql backup via dropbox, but I didn't know how to get it in.

I installed HASS directly on my SSD

@expaso
Copy link
Owner

expaso commented Apr 7, 2022

If the SQL backup was created using pg_dump, you could just do a pg_restore on a freshly installer add-on.

@mgiebels
Copy link

mgiebels commented Apr 7, 2022

I have no idea actually this info is in there. (a part of the sql)

-- PostgreSQL database dump

-- Dumped from database version 12.4
-- Dumped by pg_dump version 14.2

SET statement_timeout = 0;
SET lock_timeout = 0;
SET idle_in_transaction_session_timeout = 0;
SET client_encoding = 'UTF8';
SET standard_conforming_strings = on;
SELECT pg_catalog.set_config('search_path', '', false);
SET check_function_bodies = false;
SET xmloption = content;
SET client_min_messages = warning;
SET row_security = off;

I just wouldn't know how to do a restore and where because I can't access my computer via pgadmin

@bartbakels
Copy link

bartbakels commented Apr 7, 2022

I do have timescale enabled on my dsmrreader db but still get an error.

i run on a supervised has on vmware esxi

config:

databases:

  • dsmrreader
    timescale_enabled:
  • dsmrreader
    timescaledb:
    telemetry: basic
    maxmemory: 512MB
    maxcpus: '4'
    max_connections: 20
    system_packages: []
    init_commands: []

Workorder

shutdown dsmr
Shutdown timescale
Upgrade
Start timescale
Timescale fails to start due to db upgrade error

`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.
[13:26:14] INFO: done
[13:26:14] NOTICE: Upgrading PostgreSql...
[13:26:14] INFO: Starting PostgreSQL-12 first..
2022-04-07 11:26:14.479 UTC [356] LOG: starting PostgreSQL 12.10 on x86_64-alpine-linux-musl, compiled by gcc (Alpine 10.3.1_git20211027) 10.3.1 20211027, 64-bit
2022-04-07 11:26:14.479 UTC [356] LOG: listening on IPv4 address "0.0.0.0", port 5432
2022-04-07 11:26:14.479 UTC [356] LOG: listening on IPv6 address "::", port 5432
2022-04-07 11:26:14.480 UTC [356] LOG: listening on Unix socket "/run/postgresql/.s.PGSQL.5432"
2022-04-07 11:26:14.481 UTC [356] LOG: listening on Unix socket "/tmp/.s.PGSQL.5432"
2022-04-07 11:26:14.490 UTC [361] LOG: database system was shut down at 2022-04-07 11:23:08 UTC
2022-04-07 11:26:14.493 UTC [356] LOG: database system is ready to accept connections
2022-04-07 11:26:14.497 UTC [367] LOG: TimescaleDB background worker launcher connected to shared catalogs
[13:26:15] INFO: Upgrading Timescale extentions..
[13:26:15] INFO: Updating Timescale Extension for database system databases..
2022-04-07 11:26:15.494 UTC [369] LOG: terminating TimescaleDB job scheduler due to administrator command
2022-04-07 11:26:15.494 UTC [369] FATAL: terminating connection due to administrator command
2022-04-07 11:26:15.497 UTC [356] LOG: background worker "TimescaleDB Background Worker Scheduler" (PID 369) exited with exit code 1
terminating TimescaleDB scheduler entrypoint due to administrator command2022-04-07 11:26:15.803 UTC [378] FATAL: terminating connection due to administrator command
2022-04-07 11:26:15.804 UTC [356] LOG: background worker "TimescaleDB Background Worker Scheduler" (PID 378) exited with exit code 1
ALTER EXTENSION
terminating TimescaleDB scheduler entrypoint due to administrator command2022-04-07 11:26:16.197 UTC [382] FATAL: terminating connection due to administrator command
2022-04-07 11:26:16.199 UTC [356] LOG: background worker "TimescaleDB Background Worker Scheduler" (PID 382) exited with exit code 1
2022-04-07 11:26:16.223 UTC [383] ERROR: TimescaleDB background worker connected to template database, exiting
2022-04-07 11:26:16.224 UTC [356] LOG: background worker "TimescaleDB Background Worker Scheduler" (PID 383) exited with exit code 1
ALTER EXTENSION
[13:26:16] INFO: Updating Timescale Extension for database: 'dsmrreader'
2022-04-07 11:26:16.285 UTC [371] LOG: terminating TimescaleDB job scheduler due to administrator command
2022-04-07 11:26:16.285 UTC [371] FATAL: terminating connection due to administrator command
2022-04-07 11:26:16.286 UTC [356] LOG: background worker "TimescaleDB Background Worker Scheduler" (PID 371) exited with exit code 1
terminating TimescaleDB scheduler entrypoint due to administrator command2022-04-07 11:26:16.607 UTC [392] FATAL: terminating connection due to administrator command
2022-04-07 11:26:16.608 UTC [356] LOG: background worker "TimescaleDB Background Worker Scheduler" (PID 392) exited with exit code 1
ALTER EXTENSION
[13:26:16] INFO: done
2022-04-07 11:26:16.639 UTC [356] LOG: received smart shutdown request
2022-04-07 11:26:16.640 UTC [379] LOG: terminating TimescaleDB job scheduler due to administrator command
2022-04-07 11:26:16.640 UTC [370] LOG: terminating TimescaleDB job scheduler due to administrator command
2022-04-07 11:26:16.640 UTC [370] FATAL: terminating connection due to administrator command
terminating TimescaleDB background worker launcher due to administrator command2022-04-07 11:26:16.641 UTC [367] FATAL: terminating connection due to administrator command
2022-04-07 11:26:16.641 UTC [379] FATAL: terminating connection due to administrator command
2022-04-07 11:26:16.641 UTC [356] LOG: background worker "logical replication launcher" (PID 368) exited with exit code 1
2022-04-07 11:26:16.642 UTC [356] LOG: background worker "TimescaleDB Background Worker Launcher" (PID 367) exited with exit code 1
2022-04-07 11:26:16.642 UTC [370] LOG: terminating TimescaleDB job scheduler due to administrator command
2022-04-07 11:26:16.642 UTC [379] LOG: terminating TimescaleDB job scheduler due to administrator command
2022-04-07 11:26:16.643 UTC [356] LOG: background worker "TimescaleDB Background Worker Scheduler" (PID 370) exited with exit code 1
2022-04-07 11:26:16.643 UTC [356] LOG: background worker "TimescaleDB Background Worker Scheduler" (PID 379) exited with exit code 1
2022-04-07 11:26:16.644 UTC [393] LOG: terminating TimescaleDB job scheduler due to administrator command
2022-04-07 11:26:16.644 UTC [393] LOG: terminating TimescaleDB job scheduler due to administrator command
2022-04-07 11:26:16.644 UTC [393] FATAL: terminating connection due to administrator command
2022-04-07 11:26:16.645 UTC [356] LOG: background worker "TimescaleDB Background Worker Scheduler" (PID 393) exited with exit code 1
2022-04-07 11:26:16.645 UTC [362] LOG: shutting down
2022-04-07 11:26:16.683 UTC [356] LOG: database system is shut down
[13:26:16] NOTICE: Upgrading databases..
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 system-defined composite types in user tables ok
Checking for reg* data types in user tables ok
Checking for contrib/isn with bigint-passing mismatch ok
Checking for user-defined encoding conversions ok
Checking for user-defined postfix operators ok
Creating dump of global objects ok
Creating dump of database schemas
dsmrreader
homeassistant
postgres
template1
ok
Checking for presence of required libraries fatal
Your installation references loadable libraries that are missing from the
new installation. You can add these libraries to the new installation,
or remove the functions using them from the old installation. A list of
problem libraries is in the file:
loadable_libraries.txt
Failure, exiting
[13:26:19] ERROR: PostgreSQL could not upgrade! Please inspect any errors in the lines above!
[13:26:19] ERROR: Upgrade was not succesfull.
[cont-init.d] init.sh: exited 1.
[cont-finish.d] executing container finish scripts...
[cont-finish.d] 99-message.sh: executing...

            Oops! Something went wrong.

We are so sorry, but something went terribly wrong when
starting or running this add-on.

Be sure to check the log above, line by line, for hints.

[cont-finish.d] 99-message.sh: exited 0.
[cont-finish.d] done.
[s6-finish] waiting for services.
[s6-finish] sending all processes the TERM signal.`

@expaso
Copy link
Owner

expaso commented Apr 7, 2022

I have no idea actually this info is in there. (a part of the sql) † -- PostgreSQL database dump †

-- Dumped from database version 12.4 -- Dumped by pg_dump version 14.2

SET statement_timeout = 0; SET lock_timeout = 0; SET idle_in_transaction_session_timeout = 0; SET client_encoding = 'UTF8'; SET standard_conforming_strings = on; SELECT pg_catalog.set_config('search_path', '', false); SET check_function_bodies = false; SET xmloption = content; SET client_min_messages = warning; SET row_security = off;

I just wouldn't know how to do a restore and where because I can't access my computer via pgadmin

You can just use pg_restore as far as I can see, from any linux machine with Posgres 14 tools available. See also: https://www.postgresql.org/docs/9.2/app-pgrestore.html

See also: https://www.tecmint.com/backup-and-restore-postgresql-database/#:~:text=To%20restore%20a%20PostgreSQL%20database%2C%20you%20can%20use,of%20the%20non-plain-text%20formats%20%28custom%2C%20tar%2C%20or%20directory%29.

@kennethhaspeel
Copy link

After upgrading to 2.0, the addon wouldn't start. I restored a backup (1.6) but still no luck. Now i just upgraded to 2.1 but now i keep getting the same error
2022-04-07 16:32:43.772 UTC [576] FATAL: password authentication failed for user "postgres" 2022-04-07 16:32:43.772 UTC [576] DETAIL: User "postgres" has no password assigned

I cannot check in pgadmin since it keeps asking me for a password but there is none.
I'm running home assistant on a NUC with debian, docker and plenty of disk space
There is another topic with this problem but i read you would continue here. Maybe I overlooked but i'm seeing a solution to this specific problem

@snerdish
Copy link

snerdish commented Apr 7, 2022

Sadly, 2.0.1 didn't fix this. Exactly the same error as before ("Checking for presence of required libraries fatal"). Due to time constraints I haven't been able to log in via root to examine the container, nor will the add-on remain up long enough for any pgadmin4 sanity checks.

RPi4 with HA OS.

@atli-c
Copy link

atli-c commented Apr 9, 2022

I had problems upgrading to 2.0.0 (I wrote in #14) and restored from backup. Now, I just upgraded to 2.0.1 and it's working for me 👍

@kennethhaspeel
Copy link

kennethhaspeel commented Apr 10, 2022

I restored a backup so i went back from 2.0 to 1.1.6 (so maybe i could upgrade to 2.0.1 in the next step) but even the backup is not really working

2022-04-10 08:30:02.992 UTC [411] LOG:  starting PostgreSQL 12.4 on x86_64-alpine-linux-musl, compiled by gcc (Alpine 9.3.0) 9.3.0, 64-bit
2022-04-10 08:30:02.992 UTC [411] LOG:  listening on IPv4 address "0.0.0.0", port 5432
2022-04-10 08:30:02.992 UTC [411] LOG:  listening on IPv6 address "::", port 5432
2022-04-10 08:30:02.994 UTC [411] LOG:  listening on Unix socket "/run/postgresql/.s.PGSQL.5432"
2022-04-10 08:30:02.996 UTC [411] LOG:  listening on Unix socket "/tmp/.s.PGSQL.5432"
2022-04-10 08:30:03.050 UTC [416] LOG:  database system was interrupted; last known up at 2022-03-31 13:32:18 UTC
2022-04-10 08:30:03.512 UTC [416] LOG:  invalid primary checkpoint record
2022-04-10 08:30:03.512 UTC [416] PANIC:  could not locate a valid checkpoint record
2022-04-10 08:30:03.954 UTC [419] FATAL:  the database system is starting up
2022-04-10 08:30:03.956 UTC [420] FATAL:  the database system is starting up
2022-04-10 08:30:04.969 UTC [425] FATAL:  the database system is starting up
2022-04-10 08:30:04.973 UTC [426] FATAL:  the database system is starting up
2022-04-10 08:30:06.059 UTC [431] FATAL:  the database system is starting up
2022-04-10 08:30:06.062 UTC [432] FATAL:  the database system is starting up
2022-04-10 08:30:07.079 UTC [437] FATAL:  the database system is starting up
2022-04-10 08:30:07.081 UTC [438] FATAL:  the database system is starting up
2022-04-10 08:30:08.094 UTC [443] FATAL:  the database system is starting up
2022-04-10 08:30:08.096 UTC [444] FATAL:  the database system is starting up
2022-04-10 08:30:09.103 UTC [449] FATAL:  the database system is starting up
2022-04-10 08:30:09.104 UTC [450] FATAL:  the database system is starting up
2022-04-10 08:30:10.045 UTC [411] LOG:  startup process (PID 416) was terminated by signal 6: Aborted
2022-04-10 08:30:10.046 UTC [411] LOG:  aborting startup due to startup process failure
2022-04-10 08:30:10.163 UTC [411] LOG:  database system is shut down

So i don't think there's any point in upgrading to 2.0.1 if the 1.1.6 version isn't working

EDIT: i took the gamble and upgraded the non-working version 1.1.6 and this is the result

2022-04-10 09:05:09.458 UTC [356] LOG:  starting PostgreSQL 12.10 on x86_64-alpine-linux-musl, compiled by gcc (Alpine 10.3.1_git20211027) 10.3.1 20211027, 64-bit
2022-04-10 09:05:09.458 UTC [356] LOG:  listening on IPv4 address "0.0.0.0", port 5432
2022-04-10 09:05:09.458 UTC [356] LOG:  listening on IPv6 address "::", port 5432
2022-04-10 09:05:09.461 UTC [356] LOG:  listening on Unix socket "/run/postgresql/.s.PGSQL.5432"
2022-04-10 09:05:09.463 UTC [356] LOG:  listening on Unix socket "/tmp/.s.PGSQL.5432"
2022-04-10 09:05:09.512 UTC [361] LOG:  database system was interrupted; last known up at 2022-03-31 13:32:18 UTC
2022-04-10 09:05:10.004 UTC [361] LOG:  invalid primary checkpoint record
2022-04-10 09:05:10.005 UTC [361] PANIC:  could not locate a valid checkpoint record
2022-04-10 09:05:10.456 UTC [363] FATAL:  the database system is starting up
2022-04-10 09:05:11.498 UTC [366] FATAL:  the database system is starting up
2022-04-10 09:05:12.526 UTC [369] FATAL:  the database system is starting up
2022-04-10 09:05:13.542 UTC [372] FATAL:  the database system is starting up
2022-04-10 09:05:14.554 UTC [375] FATAL:  the database system is starting up
2022-04-10 09:05:15.569 UTC [378] FATAL:  the database system is starting up
2022-04-10 09:05:16.581 UTC [381] FATAL:  the database system is starting up
2022-04-10 09:05:17.190 UTC [356] LOG:  startup process (PID 361) was terminated by signal 6: Aborted
2022-04-10 09:05:17.190 UTC [356] LOG:  aborting startup due to startup process failure
2022-04-10 09:05:17.305 UTC [356] LOG:  database system is shut down

I thought the 2.0 version of this addon came with PostgreSQL 14

@expaso
Copy link
Owner

expaso commented Apr 11, 2022

Sadly, 2.0.1 didn't fix this. Exactly the same error as before ("Checking for presence of required libraries fatal"). Due to time constraints I haven't been able to log in via root to examine the container, nor will the add-on remain up long enough for any pgadmin4 sanity checks.

RPi4 with HA OS.

Have you checked that all timescale-enabled databases are listed in the 'timescale-enabled' section of the addon?

@expaso
Copy link
Owner

expaso commented Apr 11, 2022

I restored a backup so i went back from 2.0 to 1.1.6 (so maybe i could upgrade to 2.0.1 in the next step) but even the backup is not really working

2022-04-10 08:30:02.992 UTC [411] LOG:  starting PostgreSQL 12.4 on x86_64-alpine-linux-musl, compiled by gcc (Alpine 9.3.0) 9.3.0, 64-bit
2022-04-10 08:30:02.992 UTC [411] LOG:  listening on IPv4 address "0.0.0.0", port 5432
2022-04-10 08:30:02.992 UTC [411] LOG:  listening on IPv6 address "::", port 5432
2022-04-10 08:30:02.994 UTC [411] LOG:  listening on Unix socket "/run/postgresql/.s.PGSQL.5432"
2022-04-10 08:30:02.996 UTC [411] LOG:  listening on Unix socket "/tmp/.s.PGSQL.5432"
2022-04-10 08:30:03.050 UTC [416] LOG:  database system was interrupted; last known up at 2022-03-31 13:32:18 UTC
2022-04-10 08:30:03.512 UTC [416] LOG:  invalid primary checkpoint record
2022-04-10 08:30:03.512 UTC [416] PANIC:  could not locate a valid checkpoint record
2022-04-10 08:30:03.954 UTC [419] FATAL:  the database system is starting up
2022-04-10 08:30:03.956 UTC [420] FATAL:  the database system is starting up
2022-04-10 08:30:04.969 UTC [425] FATAL:  the database system is starting up
2022-04-10 08:30:04.973 UTC [426] FATAL:  the database system is starting up
2022-04-10 08:30:06.059 UTC [431] FATAL:  the database system is starting up
2022-04-10 08:30:06.062 UTC [432] FATAL:  the database system is starting up
2022-04-10 08:30:07.079 UTC [437] FATAL:  the database system is starting up
2022-04-10 08:30:07.081 UTC [438] FATAL:  the database system is starting up
2022-04-10 08:30:08.094 UTC [443] FATAL:  the database system is starting up
2022-04-10 08:30:08.096 UTC [444] FATAL:  the database system is starting up
2022-04-10 08:30:09.103 UTC [449] FATAL:  the database system is starting up
2022-04-10 08:30:09.104 UTC [450] FATAL:  the database system is starting up
2022-04-10 08:30:10.045 UTC [411] LOG:  startup process (PID 416) was terminated by signal 6: Aborted
2022-04-10 08:30:10.046 UTC [411] LOG:  aborting startup due to startup process failure
2022-04-10 08:30:10.163 UTC [411] LOG:  database system is shut down

So i don't think there's any point in upgrading to 2.0.1 if the 1.1.6 version isn't working

EDIT: i took the gamble and upgraded the non-working version 1.1.6 and this is the result

2022-04-10 09:05:09.458 UTC [356] LOG:  starting PostgreSQL 12.10 on x86_64-alpine-linux-musl, compiled by gcc (Alpine 10.3.1_git20211027) 10.3.1 20211027, 64-bit
2022-04-10 09:05:09.458 UTC [356] LOG:  listening on IPv4 address "0.0.0.0", port 5432
2022-04-10 09:05:09.458 UTC [356] LOG:  listening on IPv6 address "::", port 5432
2022-04-10 09:05:09.461 UTC [356] LOG:  listening on Unix socket "/run/postgresql/.s.PGSQL.5432"
2022-04-10 09:05:09.463 UTC [356] LOG:  listening on Unix socket "/tmp/.s.PGSQL.5432"
2022-04-10 09:05:09.512 UTC [361] LOG:  database system was interrupted; last known up at 2022-03-31 13:32:18 UTC
2022-04-10 09:05:10.004 UTC [361] LOG:  invalid primary checkpoint record
2022-04-10 09:05:10.005 UTC [361] PANIC:  could not locate a valid checkpoint record
2022-04-10 09:05:10.456 UTC [363] FATAL:  the database system is starting up
2022-04-10 09:05:11.498 UTC [366] FATAL:  the database system is starting up
2022-04-10 09:05:12.526 UTC [369] FATAL:  the database system is starting up
2022-04-10 09:05:13.542 UTC [372] FATAL:  the database system is starting up
2022-04-10 09:05:14.554 UTC [375] FATAL:  the database system is starting up
2022-04-10 09:05:15.569 UTC [378] FATAL:  the database system is starting up
2022-04-10 09:05:16.581 UTC [381] FATAL:  the database system is starting up
2022-04-10 09:05:17.190 UTC [356] LOG:  startup process (PID 361) was terminated by signal 6: Aborted
2022-04-10 09:05:17.190 UTC [356] LOG:  aborting startup due to startup process failure
2022-04-10 09:05:17.305 UTC [356] LOG:  database system is shut down

I thought the 2.0 version of this addon came with PostgreSQL 14

Correct, this version comes with Postgres 14. But.. to upgrade from 12 to 14, there are a certain tricky steps involved, namely:

  1. Upgrade timescale WHILE RUNNING Postgres 12
  2. Upgrade Postgres from 12 to 14
  3. Upgrade the rest of the addons

In your case, it looks like Postgres 12 was not correctly shut-down before trying the upgrade.

database system was interrupted; last known up at 2022-03-31 13:32:18 UTC
2022-04-10 08:30:03.512 UTC [416] LOG: invalid primary checkpoint record
2022-04-10 08:30:03.512 UTC [416] PANIC: could not locate a valid checkpoint record

Can you try again when the addon was shutdown properly?

@snerdish
Copy link

Aha, thanks for that - somehow I missed that I needed to add my ltss db to the yaml config. Is it not possible to check for existing database timescaledb status programatically?

I also noted the following; apologies if this is also something I've missed.

2022-04-11 23:24:00.944 UTC [496] STATEMENT: SELECT PostGIS_Extensions_Upgrade();
ERROR: function postgis_extensions_upgrade() does not exist
LINE 1: SELECT PostGIS_Extensions_Upgrade();
^
HINT: No function matches the given name and argument types. You might need to add explicit type casts.
[09:24:00] INFO: Upgrading PostGIS for database: 'ha-ltss'
NOTICE: Extension postgis_raster is not available or not packagable for some reason
NOTICE: Extension postgis_topology is not available or not packagable for some reason
NOTICE: Extension postgis_tiger_geocoder is not available or not packagable for some reason
postgis_extensions_upgrade

Upgrade completed, run SELECT postgis_full_version(); for details
(1 row)
[09:24:01] INFO: done

@kennethhaspeel
Copy link

Correct, this version comes with Postgres 14. But.. to upgrade from 12 to 14, there are a certain tricky steps involved, namely:

  1. Upgrade timescale WHILE RUNNING Postgres 12
  2. Upgrade Postgres from 12 to 14
  3. Upgrade the rest of the addons

In your case, it looks like Postgres 12 was not correctly shut-down before trying the upgrade.

database system was interrupted; last known up at 2022-03-31 13:32:18 UTC 2022-04-10 08:30:03.512 UTC [416] LOG: invalid primary checkpoint record 2022-04-10 08:30:03.512 UTC [416] PANIC: could not locate a valid checkpoint record

Can you try again when the addon was shutdown properly?

No luck. The upgrade breaks on starting PostgreSql 12.

[18:10:20] INFO: done
[18:10:20] NOTICE: Upgrading PostgreSql...
[18:10:20] INFO: Starting PostgreSQL-12 first..
2022-04-12 16:10:20.657 UTC [357] LOG:  starting PostgreSQL 12.10 on x86_64-alpine-linux-musl, compiled by gcc (Alpine 10.3.1_git20211027) 10.3.1 20211027, 64-bit
2022-04-12 16:10:20.658 UTC [357] LOG:  listening on IPv4 address "0.0.0.0", port 5432
2022-04-12 16:10:20.658 UTC [357] LOG:  listening on IPv6 address "::", port 5432
2022-04-12 16:10:20.660 UTC [357] LOG:  listening on Unix socket "/run/postgresql/.s.PGSQL.5432"
2022-04-12 16:10:20.662 UTC [357] LOG:  listening on Unix socket "/tmp/.s.PGSQL.5432"
2022-04-12 16:10:20.712 UTC [362] LOG:  database system was interrupted; last known up at 2022-03-31 13:32:18 UTC
2022-04-12 16:10:21.214 UTC [362] LOG:  invalid primary checkpoint record
2022-04-12 16:10:21.214 UTC [362] PANIC:  could not locate a valid checkpoint record
2022-04-12 16:10:21.647 UTC [364] FATAL:  the database system is starting up
2022-04-12 16:10:22.656 UTC [367] FATAL:  the database system is starting up
2022-04-12 16:10:23.666 UTC [370] FATAL:  the database system is starting up
2022-04-12 16:10:24.679 UTC [373] FATAL:  the database system is starting up
2022-04-12 16:10:25.694 UTC [376] FATAL:  the database system is starting up
2022-04-12 16:10:26.706 UTC [379] FATAL:  the database system is starting up
2022-04-12 16:10:27.722 UTC [382] FATAL:  the database system is starting up
2022-04-12 16:10:28.143 UTC [357] LOG:  startup process (PID 362) was terminated by signal 6: Aborted
2022-04-12 16:10:28.143 UTC [357] LOG:  aborting startup due to startup process failure
2022-04-12 16:10:28.265 UTC [357] LOG:  database system is shut down

It seems the database won't start because of that "invalid primary checkpoint record".

Would be a shame to lose this database. More than a year of Solar panel, energy consumption, ... data. And another database (,postgis, not timescale) for another project.

@dschien
Copy link

dschien commented Apr 19, 2022

Hi, this is related to #14 - which is marked as closed. However, I don't think that the problem is really solved.

Over there, the recommended approach is to downgrade and then re-direct a copy of the data directory.

If anyone has successfully done this, I would appreciate a step-by-step summary.

@expaso
Copy link
Owner

expaso commented Apr 19, 2022

@kennethhaspeel Are you on Discord? If so, PM me at Expaso #3263 and I can try to guide you through it..

@dschien Maybe.. the upgrade process is protected against an error as in: when the upgrade fails, it will restore the data directories to it's old positions..but.. if Postgres fails to start due above conditions, the upgrade process is aborted too early and will not recover by itself. I am currently creating a config option to reboot this upgrade process.

Can you SSH into your homeassistant as in, port 2222 ?
I can help you to execute those steps by hand if you like, so you can continue right away.
Reach out on Discord: Expaso #3263 , I will try to help you get past the message.

@expaso
Copy link
Owner

expaso commented Apr 19, 2022

@expaso
Copy link
Owner

expaso commented Sep 17, 2022

No more people to help out? Closing issue! Thank you guys!

@expaso expaso closed this as completed Sep 17, 2022
@github-actions github-actions bot locked and limited conversation to collaborators Aug 18, 2024
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
None yet
Projects
None yet
Development

No branches or pull requests