Restoring synapse fails

Support apps
1

My YunoHost server

Hardware: computer
YunoHost version: 4.0.8
I have access to my server : Through SSH, through the webadmin
Are you in a special context or did you perform some particular tweaking on your YunoHost instance ? : yes
If yes, please explain: Yunohost is installed in a virtual machine on the server.

Description of my issue

Following a hardware failure, I’ve had to restore the whole yunohost server.
The backed up server was updated until the last 1-2 months, and was not on buster.
When I reinstalled the new server, I started a new yunohost based on buster (I didn’t find ways to install an older jessie yunohost).
Configuration, data and many apps restored fine (Thank you yunohost and borg_ynh for making this possible and doable for me!! :heart: ), but restoring synapse and peertube have failed.

For synapse, at first it would fail with an error saying that /etc/postgresql/11 didn’t exist, so I created the directory manually.
Now this is the logs from the last attempt of restoration that failed:

  - 2020-09-19 09:22:55,985: DEBUG - + service_name=postgresql
  - 2020-09-19 09:22:55,985: WARNING - psql: could not connect to server: No such file or directory
  - 2020-09-19 09:22:55,985: DEBUG - + action=restart
  - 2020-09-19 09:22:55,985: WARNING - 	Is the server running locally and accepting
  - 2020-09-19 09:22:55,985: DEBUG - + line_match=
  - 2020-09-19 09:22:55,985: WARNING - 	connections on Unix domain socket "/var/run/postgresql/.s.PGSQL.5432"?
  - 2020-09-19 09:22:55,986: DEBUG - + length=20
  - 2020-09-19 09:22:55,986: DEBUG - + log_path=/var/log/postgresql/postgresql.log
  - 2020-09-19 09:22:55,986: DEBUG - + timeout=300
  - 2020-09-19 09:22:55,986: DEBUG - + [[ -n '' ]]
  - 2020-09-19 09:22:55,986: DEBUG - + '[' restart == reload ']'
  - 2020-09-19 09:22:55,986: DEBUG - + systemctl restart postgresql
  - 2020-09-19 09:22:55,986: DEBUG - + [[ -n '' ]]
  - 2020-09-19 09:22:55,986: DEBUG - + systemctl is-enabled postgresql -q
  - 2020-09-19 09:22:55,986: DEBUG - + '[' '!' -f /etc/yunohost/psql ']'
  - 2020-09-19 09:22:55,986: DEBUG - + local pg_hba=/etc/postgresql/11/main/pg_hba.conf
  - 2020-09-19 09:22:55,986: DEBUG - ++ ynh_string_random
  - 2020-09-19 09:22:55,986: DEBUG - ++ local legacy_args=l
  - 2020-09-19 09:22:55,986: DEBUG - ++ args_array=([l]=length=)
  - 2020-09-19 09:22:55,986: DEBUG - ++ local -A args_array
  - 2020-09-19 09:22:55,986: DEBUG - ++ local length
  - 2020-09-19 09:22:55,986: DEBUG - ++ ynh_handle_getopts_args
  - 2020-09-19 09:22:55,987: DEBUG - ++ set +o xtrace
  - 2020-09-19 09:22:55,987: DEBUG - ++ length=24
  - 2020-09-19 09:22:55,987: DEBUG - ++ dd if=/dev/urandom bs=1 count=1000
  - 2020-09-19 09:22:55,987: DEBUG - ++ tr --complement --delete A-Za-z0-9
  - 2020-09-19 09:22:55,987: DEBUG - ++ sed --quiet 's/\(.\{24\}\).*/\1/p'
  - 2020-09-19 09:22:55,987: DEBUG - + local psql_root_password=**********
  - 2020-09-19 09:22:55,987: DEBUG - + echo **********
  - 2020-09-19 09:22:55,987: DEBUG - + sudo --login --user=postgres psql '-cALTER user postgres WITH PASSWORD '\''**********'\''' postgres
  - 2020-09-19 09:22:55,987: DEBUG - + ynh_exit_properly
  - 2020-09-19 09:22:55,987: DEBUG - + local exit_code=2
  - 2020-09-19 09:22:55,987: DEBUG - + '[' 2 -eq 0 ']'
  - 2020-09-19 09:22:55,987: DEBUG - + trap '' EXIT
  - 2020-09-19 09:22:55,987: DEBUG - + set +o errexit
  - 2020-09-19 09:22:55,987: DEBUG - + set +o nounset
  - 2020-09-19 09:22:55,987: DEBUG - + sleep 0.5
  - 2020-09-19 09:22:56,489: DEBUG - + type -t ynh_clean_setup
  - 2020-09-19 09:22:56,489: DEBUG - + ynh_clean_setup
  - 2020-09-19 09:22:56,489: DEBUG - + ynh_clean_check_starting
  - 2020-09-19 09:22:56,489: DEBUG - + '[' -n '' ']'
  - 2020-09-19 09:22:56,490: DEBUG - + '[' -n '' ']'
  - 2020-09-19 09:22:56,490: DEBUG - + exit 1
  - 2020-09-19 09:22:56,533: ERROR - Could not restore synapse
  - Traceback (most recent call last):
  -   File "/usr/lib/moulinette/yunohost/backup.py", line 1407, in _restore_app
  -     env=env_dict)[0]
  -   File "/usr/lib/moulinette/yunohost/hook.py", line 347, in hook_exec
  -     raise YunohostError('hook_exec_failed', path=path)
  - YunohostError: Could not run script: /tmp/restore9UDVZc/restore

On it’s side peertube is logging the following, when failing to restore:

  - 2020-09-19 10:26:34,327: DEBUG - + local new_db_pwd=**********
  - 2020-09-19 10:26:34,327: DEBUG - + db_pwd=**********
  - 2020-09-19 10:26:34,327: DEBUG - + ynh_psql_create_user peertube **********
  - 2020-09-19 10:26:34,327: DEBUG - + local user=peertube
  - 2020-09-19 10:26:34,327: DEBUG - + local pwd=**********
  - 2020-09-19 10:26:34,327: DEBUG - + ynh_psql_execute_as_root '--sql=CREATE USER peertube WITH ENCRYPTED PASSWORD '\''**********'\'''
  - 2020-09-19 10:26:34,327: DEBUG - + local legacy_args=sd
  - 2020-09-19 10:26:34,327: DEBUG - + args_array=([s]=sql= [d]=database=)
  - 2020-09-19 10:26:34,327: DEBUG - + local -A args_array
  - 2020-09-19 10:26:34,328: DEBUG - + local sql
  - 2020-09-19 10:26:34,328: DEBUG - + local database
  - 2020-09-19 10:26:34,328: DEBUG - + ynh_handle_getopts_args '--sql=CREATE USER peertube WITH ENCRYPTED PASSWORD '\''**********'\'''
  - 2020-09-19 10:26:34,328: DEBUG - + set +o xtrace
  - 2020-09-19 10:26:34,328: DEBUG - + database=
  - 2020-09-19 10:26:34,328: DEBUG - + '[' -n '' ']'
  - 2020-09-19 10:26:34,328: DEBUG - ++ cat /etc/yunohost/psql
  - 2020-09-19 10:26:34,328: DEBUG - + ynh_psql_connect_as --user=postgres --password=**********
  - 2020-09-19 10:26:34,328: DEBUG - + local legacy_args=upd
  - 2020-09-19 10:26:34,328: DEBUG - + args_array=([u]=user= [p]=password= [d]=database=)
  - 2020-09-19 10:26:34,328: DEBUG - + local -A args_array
  - 2020-09-19 10:26:34,328: DEBUG - + local user
  - 2020-09-19 10:26:34,329: DEBUG - + local password
  - 2020-09-19 10:26:34,329: DEBUG - + local database
  - 2020-09-19 10:26:34,329: DEBUG - + ynh_handle_getopts_args --user=postgres --password=**********
  - 2020-09-19 10:26:34,329: DEBUG - + set +o xtrace
  - 2020-09-19 10:26:34,329: DEBUG - + database=
  - 2020-09-19 10:26:34,329: DEBUG - + sudo --login --user=postgres PGUSER=postgres PGPASSWORD=********** psql ''
  - 2020-09-19 10:26:34,429: DEBUG - + ynh_exit_properly
  - 2020-09-19 10:26:34,430: WARNING - psql: could not connect to server: No such file or directory
  - 2020-09-19 10:26:34,430: DEBUG - + local exit_code=2
  - 2020-09-19 10:26:34,430: WARNING - 	Is the server running locally and accepting
  - 2020-09-19 10:26:34,430: DEBUG - + '[' 2 -eq 0 ']'
  - 2020-09-19 10:26:34,430: WARNING - 	connections on Unix domain socket "/var/run/postgresql/.s.PGSQL.5432"?
  - 2020-09-19 10:26:34,430: DEBUG - + trap '' EXIT
  - 2020-09-19 10:26:34,430: DEBUG - + set +o errexit
  - 2020-09-19 10:26:34,431: DEBUG - + set +o nounset
  - 2020-09-19 10:26:34,431: DEBUG - + sleep 0.5
  - 2020-09-19 10:26:34,932: DEBUG - + type -t ynh_clean_setup
  - 2020-09-19 10:26:34,932: DEBUG - + ynh_clean_setup
  - 2020-09-19 10:26:34,932: DEBUG - + ynh_clean_check_starting
  - 2020-09-19 10:26:34,933: DEBUG - + '[' -n '' ']'
  - 2020-09-19 10:26:34,933: DEBUG - + '[' -n '' ']'
  - 2020-09-19 10:26:34,933: DEBUG - + exit 1
  - 2020-09-19 10:26:34,982: ERROR - Could not restore peertube
  - Traceback (most recent call last):
  -   File "/usr/lib/moulinette/yunohost/backup.py", line 1407, in _restore_app
  -     env=env_dict)[0]
  -   File "/usr/lib/moulinette/yunohost/hook.py", line 347, in hook_exec
  -     raise YunohostError('hook_exec_failed', path=path)
  - YunohostError: Could not run script: /tmp/restoreZYmhT9/restore

It seems that both problems are related to postgres. Maybe it’s related to passing from jessie to buster.
If anyone has an idea on how to restore synapse and/or peertube in this situation, that would be very welcome :slight_smile:

2

Well uh naively I would try to check if postgresql is running and listening on 5432 ?

3

Postgresql is not listed when running sudo yunohost service status
But it is when running sudo service postgresql status.
It says it’s active (exited), don’t know if that’s normal though:

● postgresql.service - PostgreSQL RDBMS
   Loaded: loaded (/lib/systemd/system/postgresql.service; enabled; vendor preset: enabled)
   Active: active (exited) since Sat 2020-09-19 10:26:34 CEST; 4h 45min ago
 Main PID: 16686 (code=exited, status=0/SUCCESS)
    Tasks: 0 (limit: 4915)
   Memory: 0B
   CGroup: /system.slice/postgresql.service

Sep 19 10:26:34 domain.tld systemd[1]: postgresql.service: Succeeded.
Sep 19 10:26:34 domain.tld systemd[1]: Stopped PostgreSQL RDBMS.
Sep 19 10:26:34 domain.tld systemd[1]: Stopping PostgreSQL RDBMS...
Sep 19 10:26:34 domain.tld systemd[1]: Starting PostgreSQL RDBMS...
Sep 19 10:26:34 domain.tld systemd[1]: Started PostgreSQL RDBMS.
4

Eh wokay can we confirm that postgresql-11 is installed with dpkg --list | grep postgresql

Also what about netstat -tulpn | grep 5432

1 Like
5

dpkg --list | grep postgresql gives:

ii  postgresql-11                         11.7-0+deb10u1                amd64        object-relational SQL database, version 11 server
ii  postgresql-client-11                  11.7-0+deb10u1                amd64        front-end programs for PostgreSQL 11
ii  postgresql-client-common              200+deb10u3                   all          manager for multiple PostgreSQL client versions
ii  postgresql-common                     200+deb10u3                   all          PostgreSQL database-cluster manager
ii  postgresql-contrib                    11+200+deb10u3                all          additional facilities for PostgreSQL (supported version)

So I guess the answer is yes, it is installed.

But netstat -tulpn | grep 5432 doesn’t return anything. So I guess this means it’s not postgresql is not listening on 5432.

6

So it seems that the error:
Is the server running locally and accepting connections on Unix domain socket "/var/run/postgresql/.s.PGSQL.5432"?
is a widely experienced error with postgresql.
The thing I don’t understand is that there doesn’t seem to be any configuration files for postgresql, /etc/postgresql/11 is empty, which make sense since I had to create the directory myself. But it doesn’t seem to be normal.
Maybe postgresql is just not properly installed and removing it an reinstalling it could solve the issue.

7

Waht about systemctl status postgresql@11-main and pg_lsclutsters

1 Like
8 
admin@XXX:~$ systemctl status postgresql@11-main
● postgresql@11-main.service - PostgreSQL Cluster 11-main
   Loaded: loaded (/lib/systemd/system/postgresql@.service; disabled; vendor preset: enabled)
   Active: inactive (dead)
admin@XXX:~$ sudo pg_lsclusters
Ver Cluster Port Status Owner Data directory Log file
admin@XXX:~$ pg_lsclusters
Ver Cluster Port Status Owner Data directory Log file
9

I think you already answered to this question in this thread that I’m discovering @Aleks. Thanks for the researching tips that helped me to find it.
I also had locale issues, so I guess it’s probably the same issue than in that thread.

I will try what you suggest in that post: pg_createcluster 11 main --start

10

So it actually worked and solved the postgresql issue, I’ve been able to restore peertube!! :heart:
But synapse is still failing to restore :frowning_face:

I guess the problem occur when starting synapse:

2020-09-19 19:15:35,656: DEBUG - Sep 19 19:15:35 systemd[1]: Starting Synapse Matrix homeserver...
2020-09-19 19:15:35,656: DEBUG - Sep 19 19:15:35 python[348]: /opt/yunohost/matrix-synapse/bin/python: Error while finding module specification for '\''synapse.app.homeserver'\'' (ModuleNotFoundError: No module named '\''synapse'\'')
2020-09-19 19:15:35,656: DEBUG - Sep 19 19:15:35 systemd[1]: matrix-synapse.service: Control process exited, code=exited, status=1/FAILURE
2020-09-19 19:15:35,657: DEBUG - Sep 19 19:15:35 systemd[1]: matrix-synapse.service: Failed with result '\''exit-code'\''.

But I don’t really understand what this means.

More complete log:

...
2020-09-19 19:15:35,443: DEBUG - + set -o xtrace
2020-09-19 19:15:35,443: DEBUG - + ynh_systemd_action --service_name=coturn-synapse.service --action=restart
2020-09-19 19:15:35,443: DEBUG - + local legacy_args=nalpte
2020-09-19 19:15:35,443: DEBUG - + args_array=([n]=service_name= [a]=action= [l]=line_match= [p]=log_path= [t]=timeout= [e]=length=)
2020-09-19 19:15:35,443: DEBUG - + local -A args_array
2020-09-19 19:15:35,444: DEBUG - + local service_name
2020-09-19 19:15:35,444: DEBUG - + local action
2020-09-19 19:15:35,444: DEBUG - + local line_match
2020-09-19 19:15:35,444: DEBUG - + local length
2020-09-19 19:15:35,444: DEBUG - + local log_path
2020-09-19 19:15:35,444: DEBUG - + local timeout
2020-09-19 19:15:35,444: DEBUG - + ynh_handle_getopts_args --service_name=coturn-synapse.service --action=restart
2020-09-19 19:15:35,444: DEBUG - + set +o xtrace
2020-09-19 19:15:35,444: DEBUG - + service_name=coturn-synapse.service
2020-09-19 19:15:35,444: DEBUG - + action=restart
2020-09-19 19:15:35,444: DEBUG - + line_match=
2020-09-19 19:15:35,445: DEBUG - + length=20
2020-09-19 19:15:35,445: DEBUG - + log_path=/var/log/coturn-synapse.service/coturn-synapse.service.log
2020-09-19 19:15:35,445: DEBUG - + timeout=300
2020-09-19 19:15:35,445: DEBUG - + [[ -n '' ]]
2020-09-19 19:15:35,445: DEBUG - + '[' restart == reload ']'
2020-09-19 19:15:35,445: DEBUG - + systemctl restart coturn-synapse.service
2020-09-19 19:15:35,545: DEBUG - + [[ -n '' ]]
2020-09-19 19:15:35,545: INFO - [###################.] > Restarting synapse services...
2020-09-19 19:15:35,546: DEBUG - + ynh_systemd_action --service_name=matrix-synapse --action=restart '--line_match=Synapse now listening on TCP port 8448' --log_path=/var/log/matrix-synapse/homeserver.log --timeout=300
2020-09-19 19:15:35,546: DEBUG - + local legacy_args=nalpte
2020-09-19 19:15:35,546: DEBUG - + args_array=([n]=service_name= [a]=action= [l]=line_match= [p]=log_path= [t]=timeout= [e]=length=)
2020-09-19 19:15:35,546: DEBUG - + local -A args_array
2020-09-19 19:15:35,546: DEBUG - + local service_name
2020-09-19 19:15:35,546: DEBUG - + local action
2020-09-19 19:15:35,546: DEBUG - + local line_match
2020-09-19 19:15:35,546: DEBUG - + local length
2020-09-19 19:15:35,546: DEBUG - + local log_path
2020-09-19 19:15:35,546: DEBUG - + local timeout
2020-09-19 19:15:35,546: DEBUG - + ynh_handle_getopts_args --service_name=matrix-synapse --action=restart '--line_match=Synapse now listening on TCP port 8448' --log_path=/var/log/matrix-synapse/homeserver.log --timeout=300
2020-09-19 19:15:35,546: DEBUG - + set +o xtrace
2020-09-19 19:15:35,649: DEBUG - + service_name=matrix-synapse
2020-09-19 19:15:35,649: WARNING - Job for matrix-synapse.service failed because the control process exited with error code.
2020-09-19 19:15:35,649: DEBUG - + action=restart
2020-09-19 19:15:35,649: WARNING - See "systemctl status matrix-synapse.service" and "journalctl -xe" for details.
2020-09-19 19:15:35,649: DEBUG - + line_match='Synapse now listening on TCP port 8448'
2020-09-19 19:15:35,650: WARNING - [Error] Sep 19 08:59:15 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,650: DEBUG - + length=20
2020-09-19 19:15:35,650: WARNING - Sep 19 08:59:15 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,650: DEBUG - + log_path=/var/log/matrix-synapse/homeserver.log
2020-09-19 19:15:35,650: WARNING - Sep 19 08:59:15 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,650: DEBUG - + timeout=300
2020-09-19 19:15:35,650: WARNING - Sep 19 08:59:15 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,650: DEBUG - + [[ -n Synapse now listening on TCP port 8448 ]]
2020-09-19 19:15:35,650: WARNING - Sep 19 09:11:57 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,650: DEBUG - ++ mktemp
2020-09-19 19:15:35,650: WARNING - Sep 19 09:11:57 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,651: DEBUG - + local templog=/tmp/tmp.n18N8lbXQN
2020-09-19 19:15:35,651: WARNING - Sep 19 09:11:57 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,651: DEBUG - + '[' /var/log/matrix-synapse/homeserver.log == systemd ']'
2020-09-19 19:15:35,651: WARNING - Sep 19 09:22:57 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,651: DEBUG - + local pid_tail=345
2020-09-19 19:15:35,651: WARNING - Sep 19 09:22:57 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,651: DEBUG - + '[' restart == reload ']'
2020-09-19 19:15:35,651: WARNING - Sep 19 09:22:57 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,651: DEBUG - + systemctl restart matrix-synapse
2020-09-19 19:15:35,651: WARNING - Sep 19 19:15:15 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,651: DEBUG - + tail --follow=name --retry --lines=0 /var/log/matrix-synapse/homeserver.log
2020-09-19 19:15:35,651: WARNING - Sep 19 19:15:16 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,652: DEBUG - + ynh_exec_err journalctl --quiet --no-hostname --no-pager --lines=20 --unit=matrix-synapse
2020-09-19 19:15:35,652: WARNING - Sep 19 19:15:35 systemd[1]: Starting Synapse Matrix homeserver...
2020-09-19 19:15:35,652: DEBUG - ++ eval journalctl --quiet --no-hostname --no-pager --lines=20 --unit=matrix-synapse
2020-09-19 19:15:35,652: WARNING - Sep 19 19:15:35 python[348]: /opt/yunohost/matrix-synapse/bin/python: Error while finding module specification for 'synapse.app.homeserver' (ModuleNotFoundError: No module named 'synapse')
2020-09-19 19:15:35,652: DEBUG - +++ journalctl --quiet --no-hostname --no-pager --lines=20 --unit=matrix-synapse
2020-09-19 19:15:35,652: WARNING - Sep 19 19:15:35 systemd[1]: matrix-synapse.service: Control process exited, code=exited, status=1/FAILURE
2020-09-19 19:15:35,652: DEBUG - + ynh_print_err 'Sep 19 08:59:15 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,652: WARNING - Sep 19 19:15:35 systemd[1]: matrix-synapse.service: Failed with result 'exit-code'.
2020-09-19 19:15:35,652: DEBUG - Sep 19 08:59:15 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,652: WARNING - Sep 19 19:15:35 systemd[1]: Failed to start Synapse Matrix homeserver.
2020-09-19 19:15:35,653: DEBUG - Sep 19 08:59:15 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,653: WARNING - [Error] --
2020-09-19 19:15:35,653: DEBUG - Sep 19 08:59:15 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,653: DEBUG - Sep 19 09:11:57 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,653: DEBUG - Sep 19 09:11:57 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,653: DEBUG - Sep 19 09:11:57 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,653: DEBUG - Sep 19 09:22:57 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,653: DEBUG - Sep 19 09:22:57 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,653: DEBUG - Sep 19 09:22:57 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,653: DEBUG - Sep 19 19:15:15 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,653: DEBUG - Sep 19 19:15:16 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,653: DEBUG - Sep 19 19:15:35 systemd[1]: Starting Synapse Matrix homeserver...
2020-09-19 19:15:35,653: DEBUG - Sep 19 19:15:35 python[348]: /opt/yunohost/matrix-synapse/bin/python: Error while finding module specification for '\''synapse.app.homeserver'\'' (ModuleNotFoundError: No module named '\''synapse'\'')
2020-09-19 19:15:35,653: DEBUG - Sep 19 19:15:35 systemd[1]: matrix-synapse.service: Control process exited, code=exited, status=1/FAILURE
2020-09-19 19:15:35,654: DEBUG - Sep 19 19:15:35 systemd[1]: matrix-synapse.service: Failed with result '\''exit-code'\''.
2020-09-19 19:15:35,654: DEBUG - Sep 19 19:15:35 systemd[1]: Failed to start Synapse Matrix homeserver.'
2020-09-19 19:15:35,654: DEBUG - + local legacy_args=m
2020-09-19 19:15:35,654: DEBUG - + args_array=([m]=message=)
2020-09-19 19:15:35,654: DEBUG - + local -A args_array
2020-09-19 19:15:35,654: DEBUG - + local message
2020-09-19 19:15:35,654: DEBUG - + ynh_handle_getopts_args 'Sep 19 08:59:15 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,654: DEBUG - Sep 19 08:59:15 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,654: DEBUG - Sep 19 08:59:15 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,654: DEBUG - Sep 19 08:59:15 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,654: DEBUG - Sep 19 09:11:57 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,654: DEBUG - Sep 19 09:11:57 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,654: DEBUG - Sep 19 09:11:57 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,654: DEBUG - Sep 19 09:22:57 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,655: DEBUG - Sep 19 09:22:57 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,655: DEBUG - Sep 19 09:22:57 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,655: DEBUG - Sep 19 19:15:15 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,655: DEBUG - Sep 19 19:15:16 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,655: DEBUG - Sep 19 19:15:35 systemd[1]: Starting Synapse Matrix homeserver...
2020-09-19 19:15:35,655: DEBUG - Sep 19 19:15:35 python[348]: /opt/yunohost/matrix-synapse/bin/python: Error while finding module specification for '\''synapse.app.homeserver'\'' (ModuleNotFoundError: No module named '\''synapse'\'')
2020-09-19 19:15:35,655: DEBUG - Sep 19 19:15:35 systemd[1]: matrix-synapse.service: Control process exited, code=exited, status=1/FAILURE
2020-09-19 19:15:35,655: DEBUG - Sep 19 19:15:35 systemd[1]: matrix-synapse.service: Failed with result '\''exit-code'\''.
2020-09-19 19:15:35,655: DEBUG - Sep 19 19:15:35 systemd[1]: Failed to start Synapse Matrix homeserver.'
2020-09-19 19:15:35,655: DEBUG - + set +o xtrace
2020-09-19 19:15:35,655: DEBUG - + echo '! Helper used in legacy mode !'
2020-09-19 19:15:35,655: DEBUG - + set +x
2020-09-19 19:15:35,655: DEBUG - + ynh_print_log '[Error] Sep 19 08:59:15 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,655: DEBUG - Sep 19 08:59:15 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,656: DEBUG - Sep 19 08:59:15 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,656: DEBUG - Sep 19 08:59:15 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,656: DEBUG - Sep 19 09:11:57 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,656: DEBUG - Sep 19 09:11:57 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,656: DEBUG - Sep 19 09:11:57 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,656: DEBUG - Sep 19 09:22:57 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,656: DEBUG - Sep 19 09:22:57 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,656: DEBUG - Sep 19 09:22:57 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,656: DEBUG - Sep 19 19:15:15 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,656: DEBUG - Sep 19 19:15:16 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,656: DEBUG - Sep 19 19:15:35 systemd[1]: Starting Synapse Matrix homeserver...
2020-09-19 19:15:35,656: DEBUG - Sep 19 19:15:35 python[348]: /opt/yunohost/matrix-synapse/bin/python: Error while finding module specification for '\''synapse.app.homeserver'\'' (ModuleNotFoundError: No module named '\''synapse'\'')
2020-09-19 19:15:35,656: DEBUG - Sep 19 19:15:35 systemd[1]: matrix-synapse.service: Control process exited, code=exited, status=1/FAILURE
2020-09-19 19:15:35,657: DEBUG - Sep 19 19:15:35 systemd[1]: matrix-synapse.service: Failed with result '\''exit-code'\''.
2020-09-19 19:15:35,657: DEBUG - Sep 19 19:15:35 systemd[1]: Failed to start Synapse Matrix homeserver.'
2020-09-19 19:15:35,657: DEBUG - + echo -e '[Error] Sep 19 08:59:15 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,657: DEBUG - Sep 19 08:59:15 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,657: DEBUG - Sep 19 08:59:15 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,657: DEBUG - Sep 19 08:59:15 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,657: DEBUG - Sep 19 09:11:57 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,657: DEBUG - Sep 19 09:11:57 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,657: DEBUG - Sep 19 09:11:57 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,657: DEBUG - Sep 19 09:22:57 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,657: DEBUG - Sep 19 09:22:57 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,657: DEBUG - Sep 19 09:22:57 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,657: DEBUG - Sep 19 19:15:15 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,658: DEBUG - Sep 19 19:15:16 systemd[1]: /etc/systemd/system/matrix-synapse.service:13: RuntimeDirectory= path is not normalized, ignoring:
2020-09-19 19:15:35,658: DEBUG - Sep 19 19:15:35 systemd[1]: Starting Synapse Matrix homeserver...
2020-09-19 19:15:35,658: DEBUG - Sep 19 19:15:35 python[348]: /opt/yunohost/matrix-synapse/bin/python: Error while finding module specification for '\''synapse.app.homeserver'\'' (ModuleNotFoundError: No module named '\''synapse'\'')
2020-09-19 19:15:35,658: DEBUG - Sep 19 19:15:35 systemd[1]: matrix-synapse.service: Control process exited, code=exited, status=1/FAILURE
2020-09-19 19:15:35,658: DEBUG - Sep 19 19:15:35 systemd[1]: matrix-synapse.service: Failed with result '\''exit-code'\''.
2020-09-19 19:15:35,658: DEBUG - Sep 19 19:15:35 systemd[1]: Failed to start Synapse Matrix homeserver.'
2020-09-19 19:15:35,658: DEBUG - + '[' -e /var/log/matrix-synapse/homeserver.log ']'
2020-09-19 19:15:35,658: DEBUG - + ynh_print_err --message=--
2020-09-19 19:15:35,658: DEBUG - + local legacy_args=m
2020-09-19 19:15:35,658: DEBUG - + args_array=([m]=message=)
2020-09-19 19:15:35,658: DEBUG - + local -A args_array
2020-09-19 19:15:35,658: DEBUG - + local message
2020-09-19 19:15:35,658: DEBUG - + ynh_handle_getopts_args --message=--
2020-09-19 19:15:35,658: DEBUG - + set +o xtrace
2020-09-19 19:15:35,658: DEBUG - + ynh_print_log '[Error] --'
2020-09-19 19:15:35,659: DEBUG - + echo -e '[Error] --'
2020-09-19 19:15:35,659: DEBUG - + ynh_exec_err tail --lines=20 /var/log/matrix-synapse/homeserver.log
2020-09-19 19:15:35,659: DEBUG - ++ eval tail --lines=20 /var/log/matrix-synapse/homeserver.log
2020-09-19 19:15:35,659: DEBUG - +++ tail --lines=20 /var/log/matrix-synapse/homeserver.log
...
2020-09-19 19:15:35,776: DEBUG - + ynh_die
2020-09-19 19:15:35,776: DEBUG - + local legacy_args=mc
2020-09-19 19:15:35,776: DEBUG - + args_array=([m]=message= [c]=ret_code=)
2020-09-19 19:15:35,776: DEBUG - + local -A args_array
2020-09-19 19:15:35,777: DEBUG - + local message
2020-09-19 19:15:35,777: DEBUG - + local ret_code
2020-09-19 19:15:35,777: DEBUG - + ynh_handle_getopts_args
2020-09-19 19:15:35,777: DEBUG - + set +o xtrace
2020-09-19 19:15:35,777: DEBUG - + ret_code=1
2020-09-19 19:15:35,777: DEBUG - ++ ynh_exit_properly
2020-09-19 19:15:35,777: DEBUG - ++ local exit_code=1
2020-09-19 19:15:35,777: DEBUG - ++ '[' 1 -eq 0 ']'
2020-09-19 19:15:35,777: DEBUG - ++ trap '' EXIT
2020-09-19 19:15:35,777: DEBUG - ++ set +o errexit
2020-09-19 19:15:35,777: DEBUG - ++ set +o nounset
2020-09-19 19:15:35,777: DEBUG - ++ sleep 0.5
2020-09-19 19:15:36,178: DEBUG - ++ type -t ynh_clean_setup
2020-09-19 19:15:36,178: DEBUG - ++ ynh_clean_setup
2020-09-19 19:15:36,179: DEBUG - ++ ynh_clean_check_starting
2020-09-19 19:15:36,179: DEBUG - ++ '[' -n 345 ']'
2020-09-19 19:15:36,179: DEBUG - ++ kill -SIGTERM 345
2020-09-19 19:15:36,179: DEBUG - ++ '[' -n /tmp/tmp.n18N8lbXQN ']'
2020-09-19 19:15:36,179: DEBUG - ++ ynh_secure_remove /tmp/tmp.n18N8lbXQN
2020-09-19 19:15:36,179: DEBUG - ++ local legacy_args=f
2020-09-19 19:15:36,180: DEBUG - ++ args_array=([f]=file=)
2020-09-19 19:15:36,180: DEBUG - ++ local -A args_array
2020-09-19 19:15:36,180: DEBUG - ++ local file
2020-09-19 19:15:36,180: DEBUG - ++ ynh_handle_getopts_args /tmp/tmp.n18N8lbXQN
2020-09-19 19:15:36,180: DEBUG - ++ set +o xtrace
2020-09-19 19:15:36,281: DEBUG - ++ echo '! Helper used in legacy mode !'
2020-09-19 19:15:36,281: DEBUG - ++ set +x
2020-09-19 19:15:36,281: DEBUG - ++ local 'forbidden_path=     /var/www     /home/yunohost.app'
2020-09-19 19:15:36,281: DEBUG - ++ '[' 1 -ge 2 ']'
2020-09-19 19:15:36,281: DEBUG - ++ [[ -z /tmp/tmp.n18N8lbXQN ]]
2020-09-19 19:15:36,281: DEBUG - ++ [[      /var/www     /home/yunohost.app =~ /tmp/tmp\.n18N8lbXQN ]]
2020-09-19 19:15:36,282: DEBUG - ++ [[ /tmp/tmp.n18N8lbXQN =~ ^/[[:alnum:]]+$ ]]
2020-09-19 19:15:36,282: DEBUG - ++ [[ N = \/ ]]
2020-09-19 19:15:36,282: DEBUG - ++ '[' -e /tmp/tmp.n18N8lbXQN ']'
2020-09-19 19:15:36,282: DEBUG - ++ rm --recursive /tmp/tmp.n18N8lbXQN
2020-09-19 19:15:36,282: DEBUG - ++ exit 1
2020-09-19 19:15:36,322: ERROR - Could not restore synapse

edit: It seems to be related to this issue which says that the fix is available, but maybe only in testing.

11

The solution to restoring synapse was to modify a bit the restoration script so it doesn’t fail, and the run the upgrade. More details here.

For the record, the whole process to be able to restore synapse was:

To solve locale and db issue

  • properly setup the locale with: sudo dpkg-reconfigure locales
  • run pg_createcluster 11 main --start to create the postgresql cluster that wasn’t created because of locale issue

To be able to restore the old backup into buster

  • extract the synapse archive
  • modify the file apps/synapse/settings/scripts/restore quoting/removing the line ynh_systemd_action --service_name=matrix-$app --action=restart --line_match="Synapse now listening on TCP port $synapse_tls_port" --log_path="/var/log/matrix-$app/homeserver.log" --timeout=300 in it
  • recompress the modified backup as tar.gz archive
  • restore synapse from the modified archive (the restoration should be successful, since the step causing the error doesn’t happen)
  • now synapse is restored, but not working because the service is down, but you can be upgrade the app with yunohost app upgrade synapse -u https://github.com/YunoHost-Apps/synapse_ynh/tree/master

Yay, synapse is back :slight_smile:

12

This topic was automatically closed 15 days after the last reply. New replies are no longer allowed.