YunoHost-Apps / synapse_ynh

Matrix server (synapse) package for YunoHost
https://matrix.org/
GNU General Public License v3.0
79 stars 43 forks source link

Error upgrading from 1.74.0 to 1.84.1 #384

Closed jorge-vitrubio closed 1 year ago

jorge-vitrubio commented 1 year ago

Describe the bug

applied update from synapse version 1.74.0~ynh1 to 1.84.1~ynh1

Context

Steps to reproduce

Expected behavior

a connection to the synapse/ matrix from whatever app: using nheko in debian, and SchildiChat from f-droid in LineageOS

Logs

ended_at: 2023-06-02 17:12:11.463450
env:
  BASH_XTRACEFD: '7'
  NO_BACKUP_UPGRADE: '0'
  YNH_APP_ACTION: upgrade
  YNH_APP_BASEDIR: /var/cache/yunohost/app_tmp_work_dirs/app_s9pxz9id
  YNH_APP_CURRENT_VERSION: 1.74.0~ynh1
  YNH_APP_ID: synapse
  YNH_APP_INSTANCE_NAME: synapse
  YNH_APP_INSTANCE_NUMBER: '1'
  YNH_APP_MANIFEST_VERSION: 1.84.1~ynh1
  YNH_APP_PACKAGING_FORMAT: '1.0'
  YNH_APP_UPGRADE_TYPE: UPGRADE_APP
  YNH_ARCH: amd64
  YNH_CWD: /var/cache/yunohost/app_tmp_work_dirs/app_s9pxz9id/scripts
  YNH_DEBIAN_VERSION: bullseye
  YNH_INTERFACE: cli
  YNH_STDRETURN: /tmp/tmpuysjdue_/stdreturn
error: null
interface: cli
operation: app_upgrade
parent: null
related_to:
- - app
  - synapse
started_at: 2023-06-02 17:02:22.663643
success: true
yunohost_version: 11.1.20

....

2023-06-02 19:02:27,292: DEBUG - 756  Jun 02 18:28:30 maindomain.tld python[1654]: 2023-06-02 18:28:30,681 - synapse.config.appservice - 45 - WARNING - main- Expected None to be a list of AS config files.
2023-06-02 19:02:27,292: DEBUG - 756  Jun 02 18:28:31 maindomain.tld python[1654]: 2023-06-02 18:28:31,154 - synapse.app - 49 - WARNING - sentinel- Failed to listen on 0.0.0.0, continuing because listening on [::]
2023-06-02 19:02:27,292: DEBUG - 756  Jun 02 18:44:15 maindomain.tld python[1654]: 2023-06-02 18:44:15,190 - synapse.rest.media.v1.media_repository - 476 - WARNING - GET-10- Not retrying destination 'musaik.net'
2023-06-02 19:02:27,292: DEBUG - 756  Jun 02 18:44:15 maindomain.tld python[1654]: 2023-06-02 18:44:15,306 - synapse.rest.media.v1.media_repository - 476 - WARNING - GET-17- Not retrying destination 'musaik.net'
2023-06-02 19:02:27,292: DEBUG - 756  Jun 02 18:44:15 maindomain.tld python[1654]: 2023-06-02 18:44:15,393 - synapse.rest.media.v1.media_repository - 476 - WARNING - GET-22- Not retrying destination 'musaik.net'
2023-06-02 19:02:27,292: DEBUG - 756  Jun 02 18:44:15 maindomain.tld python[1654]: 2023-06-02 18:44:15,431 - synapse.rest.media.v1.media_repository - 476 - WARNING - GET-23- Not retrying destination 'musaik.net'

...

2023-06-02 19:02:59,236: WARNING - ERROR: pip's dependency resolver does not currently take into account all the packages that are installed. This behaviour is the source of the following dependency conflicts.
2023-06-02 19:02:59,238: WARNING - setuptools-rust 1.5.2 requires setuptools>=62.4, but you have setuptools 60.8.2 which is incompatible.

...

2023-06-02 19:03:46,744: WARNING - Additionnal URL 'maindomain.tld/.well-known/matrix' already removed in the additional URL for permission 'synapse.server_api'

...

2023-06-02 19:12:06,880: WARNING - The service matrix-synapse didn't fully executed the action restart before the timeout.

...

2023-06-02 19:12:06,895: WARNING - Please find here an extract of the end of the log of the service matrix-synapse:

...

2023-06-02 19:12:06,939: WARNING - Jun 02 19:11:53 systemd[1]: matrix-synapse.service: Scheduled restart job, restart counter is at 38.

...

2023-06-02 19:12:06,946: WARNING - Jun 02 19:11:53 systemd[1]: Stopped Synapse Matrix homeserver.
2023-06-02 19:12:06,949: WARNING - Jun 02 19:11:53 systemd[1]: matrix-synapse.service: Consumed 4.130s CPU time.
2023-06-02 19:12:06,949: WARNING - Jun 02 19:11:53 systemd[1]: Starting Synapse Matrix homeserver...
2023-06-02 19:12:06,950: WARNING - Jun 02 19:11:56 systemd[1]: Started Synapse Matrix homeserver.
2023-06-02 19:12:06,950: WARNING - Jun 02 19:11:57 python[29778]: Error in configuration at 'a.p.p._.s.e.r.v.i.c.e._.c.o.n.f.i.g._.f.i.l.e.s':
2023-06-02 19:12:06,950: WARNING - Jun 02 19:11:57 python[29778]:   Expected 'None' to be a list of AS config files:
2023-06-02 19:12:06,951: WARNING - Jun 02 19:11:58 systemd[1]: matrix-synapse.service: Main process exited, code=exited, status=1/FAILURE
2023-06-02 19:12:06,952: WARNING - Jun 02 19:11:58 systemd[1]: matrix-synapse.service: Failed with result 'exit-code'.
2023-06-02 19:12:06,952: WARNING - Jun 02 19:11:58 systemd[1]: matrix-synapse.service: Consumed 3.981s CPU time.
2023-06-02 19:12:06,952: WARNING - Jun 02 19:12:01 systemd[1]: matrix-synapse.service: Scheduled restart job, restart counter is at 39.
2023-06-02 19:12:06,953: WARNING - Jun 02 19:12:01 systemd[1]: Stopped Synapse Matrix homeserver.
2023-06-02 19:12:06,953: WARNING - Jun 02 19:12:01 systemd[1]: matrix-synapse.service: Consumed 3.981s CPU time.
2023-06-02 19:12:06,955: WARNING - Jun 02 19:12:01 systemd[1]: Starting Synapse Matrix homeserver...
2023-06-02 19:12:06,955: WARNING - Jun 02 19:12:03 systemd[1]: Started Synapse Matrix homeserver.
2023-06-02 19:12:06,955: WARNING - Jun 02 19:12:05 python[29805]: Error in configuration at 'a.p.p._.s.e.r.v.i.c.e._.c.o.n.f.i.g._.f.i.l.e.s':
2023-06-02 19:12:06,956: WARNING - Jun 02 19:12:05 python[29805]:   Expected 'None' to be a list of AS config files:
2023-06-02 19:12:06,956: WARNING - Jun 02 19:12:05 systemd[1]: matrix-synapse.service: Main process exited, code=exited, status=1/FAILURE
2023-06-02 19:12:06,956: WARNING - Jun 02 19:12:05 systemd[1]: matrix-synapse.service: Failed with result 'exit-code'.
2023-06-02 19:12:06,959: WARNING - Jun 02 19:12:05 systemd[1]: matrix-synapse.service: Consumed 4.316s CPU time.

...

2023-06-02 19:12:06,975: WARNING - \-\-\-

...

2023-06-02 19:12:07,005: WARNING - 2023-06-02 19:01:59,712 - synapse.access.http.8008 - 460 - INFO - GET-171- 213.195.101.33 - 8008 - {None} Processed request: 0.001sec/0.001sec (0.003sec, 0.000sec) (0.000sec/0.000sec/0) 788B 200 "GET /_matrix/client/versions HTTP/1.0" "mtxclient v0.9.2" [0 dbevts]

...

2023-06-02 19:12:07,012: WARNING - 2023-06-02 19:02:00,924 - synapse.storage.databases.main.event_push_actions - 1454 - INFO - rotate_notifs-66- Rotating notifications
2023-06-02 19:12:07,015: WARNING - 2023-06-02 19:02:00,929 - synapse.storage.databases.main.event_push_actions - 1677 - INFO - rotate_notifs-66- Rotating notifications up to: 28266
2023-06-02 19:12:07,015: WARNING - 2023-06-02 19:02:00,936 - synapse.storage.databases.main.event_push_actions - 1776 - INFO - rotate_notifs-66- Rotating notifications, handling 0 rows
2023-06-02 19:12:07,015: WARNING - 2023-06-02 19:02:00,945 - synapse.storage.databases.main.event_push_actions - 1869 - INFO - rotate_notifs-66- Rotating notifications, deleted 0 push actions
2023-06-02 19:12:07,016: WARNING - 2023-06-02 19:02:01,120 - synapse.util.caches.lrucache - 212 - INFO - LruCache._expire_old_entries-66- Dropped 0 items from caches
2023-06-02 19:12:07,016: WARNING - 2023-06-02 19:02:10,811 - synapse.access.http.8008 - 460 - INFO - GET-169- 213.195.101.33 - 8008 - {@jorge:maindomain.tld} Processed request: 30.012sec/0.002sec (0.013sec, 0.003sec) (0.002sec/0.005sec/4) 246B 200 "GET /_matrix/client/v3/sync?set_presence=online&since=s28266_686898_0_14817_6384_31_5290_26677_0&timeout=30000 HTTP/1.0" "mtxclient v0.9.2" [0 dbevts]
2023-06-02 19:12:07,016: WARNING - 2023-06-02 19:02:11,273 - synapse.metrics._gc - 120 - INFO - sentinel- Collecting gc 1
2023-06-02 19:12:07,016: WARNING - 2023-06-02 19:02:14,701 - synapse.access.http.8008 - 460 - INFO - GET-173- 213.195.101.33 - 8008 - {None} Processed request: 0.001sec/0.001sec (0.001sec, 0.000sec) (0.000sec/0.000sec/0) 788B 200 "GET /_matrix/client/versions HTTP/1.0" "mtxclient v0.9.2" [0 dbevts]
2023-06-02 19:12:07,017: WARNING - 2023-06-02 19:02:25,906 - twisted - 274 - INFO - sentinel- Received SIGTERM, shutting down.
2023-06-02 19:12:07,017: WARNING - 2023-06-02 19:02:25,907 - synapse.storage.databases.main.lock - 92 - INFO - LockStore._on_shutdown-0- Dropping held locks due to shutdown
2023-06-02 19:12:07,018: WARNING - 2023-06-02 19:02:25,907 - synapse.storage.databases.main.lock - 101 - INFO - LockStore._on_shutdown-0- Dropped locks due to shutdown
2023-06-02 19:12:07,018: WARNING - 2023-06-02 19:02:25,908 - synapse.handlers.presence - 768 - INFO - presence.on_shutdown-0- Performing _on_shutdown. Persisting 11 unpersisted changes
2023-06-02 19:12:07,018: WARNING - 2023-06-02 19:02:25,909 - synapse.app._base - 495 - INFO - sentinel- Shutting down...
2023-06-02 19:12:07,018: WARNING - 2023-06-02 19:02:25,920 - synapse.handlers.presence - 781 - INFO - presence.on_shutdown-0- Finished _on_shutdown
2023-06-02 19:12:07,019: WARNING - 2023-06-02 19:02:25,921 - twisted - 274 - INFO - sentinel- (TLS Port 8448 Closed)
2023-06-02 19:12:07,019: WARNING - 2023-06-02 19:02:25,924 - synapse.http.site - 372 - INFO - GET-172- Connection from client lost before response was sent
2023-06-02 19:12:07,019: WARNING - 2023-06-02 19:02:25,924 - twisted - 274 - INFO - sentinel- (TCP Port 8008 Closed)
2023-06-02 19:12:07,019: WARNING - 2023-06-02 19:02:25,925 - twisted - 274 - INFO - sentinel- (TCP Port 8008 Closed)
2023-06-02 19:12:07,019: WARNING - 2023-06-02 19:02:25,947 - twisted - 274 - INFO - sentinel- Main loop terminated.

...

2023-06-02 19:12:07,171: INFO - [####################] > Upgrade of synapse completed

...

2023-06-02 19:12:11,417: SUCCESS - synapse upgraded

https://paste.yunohost.org/raw/lokokubodo

I have come back to the backup previous to the upgrade and the synapse install it is working ok, even with the my_weapp restored for the main domain.

eclecticvx commented 1 year ago

Experienced the same issue.

Resolved by removing the line app_service_config_files: from /etc/matrix-synapse/conf.d/app_service.yaml

The file above had only that line, with no other configuration options. Now the file is completely empty.

I do not have any config files in /etc/matrix-synapse/app-service/

Commit which gave me the clue: b1968a55cb1ab413e5c4a7e2b1082760a7fae6d9

jorge-vitrubio commented 1 year ago

so, I did as you said, I commented that line so would have no effect.

ended_at: 2023-06-05 08:32:49.392472
error: "Could not restore synapse: Something unexpected went wrong: \nTraceback (most\
  \ recent call last):\n  File \"/usr/lib/python3/dist-packages/yunohost/backup.py\"\
  , line 1465, in _restore_app\n    permission_create(\n  File \"/usr/lib/python3/dist-packages/yunohost/log.py\"\
  , line 410, in func_wrapper\n    result = func(*args, **kwargs)\n  File \"/usr/lib/python3/dist-packages/yunohost/permission.py\"\
  , line 401, in permission_create\n    raise YunohostValidationError(\"permission_already_exist\"\
  , permission=permission)\nyunohost.utils.error.YunohostValidationError: Permission\
  \ 'synapse.admin_api' already exists\n"
interface: cli
operation: backup_restore_app
parent: null
related_to:
- - app
  - synapse
started_at: 2023-06-05 08:32:49.101353
success: false
yunohost_version: 11.1.20

============

2023-06-05 10:32:49,117: INFO - Restoring synapse...
2023-06-05 10:32:49,384: DEBUG - initializing ldap interface
2023-06-05 10:32:49,391: ERROR - Could not restore synapse: Something unexpected went wrong: 
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/yunohost/backup.py", line 1465, in _restore_app
    permission_create(
  File "/usr/lib/python3/dist-packages/yunohost/log.py", line 410, in func_wrapper
    result = func(*args, **kwargs)
  File "/usr/lib/python3/dist-packages/yunohost/permission.py", line 401, in permission_create
    raise YunohostValidationError("permission_already_exist", permission=permission)
yunohost.utils.error.YunohostValidationError: Permission 'synapse.admin_api' already exists

now I am stuck with no option even to install a new synapse and loosing history

` yunohost app install synapse`

produces this errors

  app: synapse
  force: false
  label: null
  no_remove_on_failure: false
ended_at: 2023-06-05 08:35:09.329683
error: Permission 'synapse.main' already exists
interface: cli
operation: app_install
parent: null
related_to:
- - app
  - synapse
started_at: 2023-06-05 08:35:09.287148
success: false
yunohost_version: 11.1.20

============

2023-06-05 10:35:09,310: INFO - Installing synapse...

so, in order to clean up permissions I followed this indications https://github.com/YunoHost-Apps/synapse_ynh/issues/329#issuecomment-1236519608

sudo yunohost tools shell -c "from yunohost.permission import permission_delete; permission_delete('synapse.main', force=True)"
sudo yunohost tools shell -c "from yunohost.permission import permission_delete; permission_delete('synapse.server_api', force=True)"
sudo yunohost tools shell -c "from yunohost.permission import permission_delete; permission_delete('synapse.server_client_infos', force=True)"

this allowed me to recover the bakcup but I am still stuck with the upgrade

jorge-vitrubio commented 1 year ago

so, How I solved it:

once I had the backup reinstalled, i did: