search

YunoHost-Apps / mautrix_signal_ynh

Matrix signal package for YunoHost
GNU Affero General Public License v3.0
4 stars 10 forks source link

Mautrix-signal fail starting at startup time #111

Open Thatoo opened 5 months ago

Thatoo commented 5 months ago

Describe the bug

When the server restart, mautrix-signal fails to start but afterwards, I can start it manually.

Context

Steps to reproduce

Expected behavior

Mautrix signal should start automatically after the server boot.

Logs


LOGFILE: journalctl
-- Journal begins at Mon 2024-04-08 11:44:39 CEST, ends at Mon 2024-06-24 10:28:14 CEST. --
juin 23 02:01:22 systemd[1]: mautrix_signal.service: Main process exited, code=exited, status=2/INVALIDARGUMENT
juin 23 02:01:22 systemd[1]: mautrix_signal.service: Failed with result 'exit-code'.
juin 23 09:38:37 systemd[1]: Started Matrix Signal Bridge.
juin 23 09:38:37 mautrix-signal[14688]: 2024-06-23T09:38:37+02:00 INF Initializing bridge built_at="Jun 16 2024, 21:03:57" go_version=go1.22.4 name=mautrix-signal version=0.6.2
juin 23 09:38:37 mautrix-signal[14688]: 2024-06-23T09:38:37+02:00 INF Initializing libsignal version:0.51.0 component=libsignal file=rust/bridge/ffi/src/logging.rs line=106 target=signal_ffi::logging
juin 23 09:38:37 mautrix-signal[14688]: 2024-06-23T09:38:37+02:00 INF Bridge initialization complete, starting...
juin 23 09:38:37 mautrix-signal[14688]: 2024-06-23T09:38:37+02:00 INF Database is up to date current_version=20 db_section=main latest_known_version=20 oldest_compatible_version=17
juin 23 09:38:37 mautrix-signal[14688]: 2024-06-23T09:38:37+02:00 INF Database is up to date current_version=5 db_section=matrix_state latest_known_version=5 oldest_compatible_version=5
juin 23 09:38:37 mautrix-signal[14688]: 2024-06-23T09:38:37+02:00 INF Starting HTTP listener address=localhost:8450
juin 23 09:38:37 mautrix-signal[14688]: 2024-06-23T09:38:37+02:00 INF Database is up to date current_version=15 db_section=crypto latest_known_version=15 oldest_compatible_version=15
juin 23 09:38:37 mautrix-signal[14688]: 2024-06-23T09:38:37+02:00 INF Database is up to date current_version=16 db_section=signalmeow latest_known_version=16 oldest_compatible_version=13
juin 23 09:38:37 mautrix-signal[14688]: 2024-06-23T09:38:37+02:00 INF Bridge started!
juin 24 02:00:03 systemd[1]: Stopping Matrix Signal Bridge...
juin 24 02:00:03 mautrix-signal[14688]: 2024-06-24T02:00:03+02:00 INF Interrupt received, stopping...
juin 24 02:00:03 mautrix-signal[14688]: 2024-06-24T02:00:03+02:00 ERR Request failed error="request error: Get \"https://matrix.MYDOMAIN.tld/_matrix/client/v3/sync?filter=0&since=s46669_2699100_100_51968_8270_28_5046_29045_0_3&timeout=30000&user_id=%40signalbot%3AMYDOMAIN.tld\": context canceled" as_user_id=@signalbot:MYDOMAIN.tld duration=2776.979477 method=GET req_id=1974 url=https://matrix.MYDOMAIN.tld/_matrix/client/v3/sync?filter=0&since=s46669_2699100_100_51968_8270_28_5046_29045_0_3&timeout=30000&user_id=%40signalbot%3AMYDOMAIN.tld
juin 24 02:00:03 mautrix-signal[14688]: 2024-06-24T02:00:03+02:00 INF Bridge bot to-device syncer stopped without error component=crypto
juin 24 02:00:03 mautrix-signal[14688]: 2024-06-24T02:00:03+02:00 INF Bridge stopped.
juin 24 02:00:03 systemd[1]: mautrix_signal.service: Succeeded.
juin 24 02:00:03 systemd[1]: Stopped Matrix Signal Bridge.
juin 24 02:00:03 systemd[1]: mautrix_signal.service: Consumed 6.518s CPU time.
-- Boot fc79e2d3d410427f95f3dc56754dbb79 --
juin 24 02:01:17 systemd[1]: Started Matrix Signal Bridge.
juin 24 02:01:17 mautrix-signal[523]: 2024-06-24T02:01:17+02:00 INF Initializing bridge built_at="Jun 16 2024, 21:03:57" go_version=go1.22.4 name=mautrix-signal version=0.6.2
juin 24 02:01:17 mautrix-signal[523]: 2024-06-24T02:01:17+02:00 INF Initializing libsignal version:0.51.0 component=libsignal file=rust/bridge/ffi/src/logging.rs line=106 target=signal_ffi::logging
juin 24 02:01:17 mautrix-signal[523]: 2024-06-24T02:01:17+02:00 INF Bridge initialization complete, starting...
juin 24 02:01:17 mautrix-signal[523]: panic: failed to check if table exists: dial tcp [::1]:5432: connect: connection refused
juin 24 02:01:17 mautrix-signal[523]: goroutine 1 [running]:
juin 24 02:01:17 mautrix-signal[523]: go.mau.fi/util/dbutil.(*Database).tableExistsNoError(0x10?, {0x1c2c118?, 0xc0002aee40?}, {0x1a72599?, 0x539d0a?})
juin 24 02:01:17 mautrix-signal[523]:         /builds/mautrix/signal/.cache/pkg/mod/go.mau.fi/util@v0.5.0/dbutil/upgrades.go:108 +0x73
juin 24 02:01:17 mautrix-signal[523]: go.mau.fi/util/dbutil.(*Database).checkDatabaseOwner(0xc000194000, {0x1c2c118, 0xc0002aee40})
juin 24 02:01:17 mautrix-signal[523]:         /builds/mautrix/signal/.cache/pkg/mod/go.mau.fi/util@v0.5.0/dbutil/upgrades.go:123 +0x8a
juin 24 02:01:17 mautrix-signal[523]: go.mau.fi/util/dbutil.(*Database).Upgrade(0xc000194000, {0x1c2c118, 0xc0002aee40})
juin 24 02:01:17 mautrix-signal[523]:         /builds/mautrix/signal/.cache/pkg/mod/go.mau.fi/util@v0.5.0/dbutil/upgrades.go:157 +0x3a
juin 24 02:01:17 mautrix-signal[523]: maunium.net/go/mautrix/bridge.(*Bridge).start(0xc0000f6008)
juin 24 02:01:17 mautrix-signal[523]:         /builds/mautrix/signal/.cache/pkg/mod/maunium.net/go/mautrix@v0.19.0-beta.1/bridge/bridge.go:718 +0x2a8
juin 24 02:01:17 mautrix-signal[523]: maunium.net/go/mautrix/bridge.(*Bridge).Main(0xc0000f6008)
juin 24 02:01:17 mautrix-signal[523]:         /builds/mautrix/signal/.cache/pkg/mod/maunium.net/go/mautrix@v0.19.0-beta.1/bridge/bridge.go:908 +0x614
juin 24 02:01:17 mautrix-signal[523]: main.main()
juin 24 02:01:17 mautrix-signal[523]:         /builds/mautrix/signal/main.go:351 +0x2a5
juin 24 02:01:17 systemd[1]: mautrix_signal.service: Main process exited, code=exited, status=2/INVALIDARGUMENT
juin 24 02:01:17 systemd[1]: mautrix_signal.service: Failed with result 'exit-code'.
juin 24 10:28:14 systemd[1]: Started Matrix Signal Bridge.
juin 24 10:28:14 mautrix-signal[13548]: 2024-06-24T10:28:14+02:00 INF Initializing bridge built_at="Jun 16 2024, 21:03:57" go_version=go1.22.4 name=mautrix-signal version=0.6.2
juin 24 10:28:14 mautrix-signal[13548]: 2024-06-24T10:28:14+02:00 INF Initializing libsignal version:0.51.0 component=libsignal file=rust/bridge/ffi/src/logging.rs line=106 target=signal_ffi::logging
juin 24 10:28:14 mautrix-signal[13548]: 2024-06-24T10:28:14+02:00 INF Bridge initialization complete, starting...
juin 24 10:28:14 mautrix-signal[13548]: 2024-06-24T10:28:14+02:00 INF Database is up to date current_version=20 db_section=main latest_known_version=20 oldest_compatible_version=17
juin 24 10:28:14 mautrix-signal[13548]: 2024-06-24T10:28:14+02:00 INF Database is up to date current_version=5 db_section=matrix_state latest_known_version=5 oldest_compatible_version=5
juin 24 10:28:14 mautrix-signal[13548]: 2024-06-24T10:28:14+02:00 INF Starting HTTP listener address=localhost:8450
juin 24 10:28:14 mautrix-signal[13548]: 2024-06-24T10:28:14+02:00 INF Database is up to date current_version=15 db_section=crypto latest_known_version=15 oldest_compatible_version=15
juin 24 10:28:14 mautrix-signal[13548]: 2024-06-24T10:28:14+02:00 INF Database is up to date current_version=16 db_section=signalmeow latest_known_version=16 oldest_compatible_version=13
juin 24 10:28:14 mautrix-signal[13548]: 2024-06-24T10:28:14+02:00 INF Bridge started!

LOGFILE: /var/log/mautrix_signal/mautrix_signal.log
{"level":"info","name":"mautrix-signal","version":"0.6.2","built_at":"Jun 16 2024, 21:03:57","go_version":"go1.22.4","time":"2024-06-24T10:28:14.10017875+02:00","message":"Initializing bridge"}
{"level":"info","component":"signalmeow","component":"libsignal","target":"signal_ffi::logging","file":"rust/bridge/ffi/src/logging.rs","line":106,"time":"2024-06-24T10:28:14.101122804+02:00","message":"Initializing libsignal version:0.51.0"}
{"level":"info","time":"2024-06-24T10:28:14.101511371+02:00","message":"Bridge initialization complete, starting..."}
{"level":"info","db_section":"main","current_version":20,"oldest_compatible_version":17,"latest_known_version":20,"time":"2024-06-24T10:28:14.167745605+02:00","message":"Database is up to date"}
{"level":"info","db_section":"matrix_state","current_version":5,"oldest_compatible_version":5,"latest_known_version":5,"time":"2024-06-24T10:28:14.174348681+02:00","message":"Database is up to date"}
{"level":"info","address":"localhost:8450","time":"2024-06-24T10:28:14.174753965+02:00","message":"Starting HTTP listener"}
{"level":"info","db_section":"crypto","current_version":15,"oldest_compatible_version":15,"latest_known_version":15,"time":"2024-06-24T10:28:14.547626193+02:00","message":"Database is up to date"}
{"level":"info","db_section":"signalmeow","current_version":16,"oldest_compatible_version":13,"latest_known_version":16,"time":"2024-06-24T10:28:14.615250824+02:00","message":"Database is up to date"}
{"level":"info","time":"2024-06-24T10:28:14.616721515+02:00","message":"Bridge started!"}
Thatoo commented 4 months ago 
juil. 01 02:01:16 systemd[1]: Started Matrix Signal Bridge.
juil. 01 02:01:17 mautrix-signal[486]: 2024-07-01T02:01:17+02:00 INF Initializing bridge built_at="Jun 16 2024, 21:03:57" go_version=go1.22.4 name=mautrix-signal version=0.6.2
juil. 01 02:01:17 mautrix-signal[486]: 2024-07-01T02:01:17+02:00 INF Initializing libsignal version:0.51.0 component=libsignal file=rust/bridge/ffi/src/logging.rs line=106 target=signal_ffi::logging
juil. 01 02:01:17 mautrix-signal[486]: 2024-07-01T02:01:17+02:00 INF Bridge initialization complete, starting...
juil. 01 02:01:17 mautrix-signal[486]: panic: failed to check if table exists: dial tcp [::1]:5432: connect: connection refused
juil. 01 02:01:17 mautrix-signal[486]: goroutine 1 [running]:
juil. 01 02:01:17 mautrix-signal[486]: go.mau.fi/util/dbutil.(*Database).tableExistsNoError(0x10?, {0x1c2c118?, 0xc0003a8d20?}, {0x1a72599?, 0x539d0a?})
juil. 01 02:01:17 mautrix-signal[486]:         /builds/mautrix/signal/.cache/pkg/mod/go.mau.fi/util@v0.5.0/dbutil/upgrades.go:108 +0x73
juil. 01 02:01:17 mautrix-signal[486]: go.mau.fi/util/dbutil.(*Database).checkDatabaseOwner(0xc0000de090, {0x1c2c118, 0xc0003a8d20})
juil. 01 02:01:17 mautrix-signal[486]:         /builds/mautrix/signal/.cache/pkg/mod/go.mau.fi/util@v0.5.0/dbutil/upgrades.go:123 +0x8a
juil. 01 02:01:17 mautrix-signal[486]: go.mau.fi/util/dbutil.(*Database).Upgrade(0xc0000de090, {0x1c2c118, 0xc0003a8d20})
juil. 01 02:01:17 mautrix-signal[486]:         /builds/mautrix/signal/.cache/pkg/mod/go.mau.fi/util@v0.5.0/dbutil/upgrades.go:157 +0x3a
juil. 01 02:01:17 mautrix-signal[486]: maunium.net/go/mautrix/bridge.(*Bridge).start(0xc0003a0508)
juil. 01 02:01:17 mautrix-signal[486]:         /builds/mautrix/signal/.cache/pkg/mod/maunium.net/go/mautrix@v0.19.0-beta.1/bridge/bridge.go:718 +0x2a8
juil. 01 02:01:17 mautrix-signal[486]: maunium.net/go/mautrix/bridge.(*Bridge).Main(0xc0003a0508)
juil. 01 02:01:17 mautrix-signal[486]:         /builds/mautrix/signal/.cache/pkg/mod/maunium.net/go/mautrix@v0.19.0-beta.1/bridge/bridge.go:908 +0x614
juil. 01 02:01:17 mautrix-signal[486]: main.main()
juil. 01 02:01:17 mautrix-signal[486]:         /builds/mautrix/signal/main.go:351 +0x2a5
juil. 01 02:01:17 systemd[1]: mautrix_signal.service: Main process exited, code=exited, status=2/INVALIDARGUMENT
juil. 01 02:01:17 systemd[1]: mautrix_signal.service: Failed with result 'exit-code'.

What could be this INVALIDARGUMENT?

Here is what I have set in /opt/yunohost/mautrix_signal/config.yaml

    permissions:
        '*': relay
        'domain.tld': user
        '@administrator:domain.tld': admin

But it can't be a config.yaml error, otherwise it would not start at all, not even manually.

Any idea what it could be and how to solve this issue?

Thatoo commented 4 months ago

Well actually the issue seems more related to

juin 24 02:01:17 mautrix-signal[523]: panic: failed to check if table exists: dial tcp [::1]:5432: connect: connection refused

than INVALIDARGUMENT.

Maybe setting a delay after boot, could solve this issue, couldn't it?

Thatoo commented 4 months ago

I wanted to make a PR but Im afraid I merged it or I don't get how to make the PR from my commit https://github.com/YunoHost-Apps/mautrix_signal_ynh/commit/193b702d2f4a3456f30871a58195830dd81de164