Skip to content
This repository has been archived by the owner on Apr 26, 2024. It is now read-only.

Synapse not starting anymore after update to 1.58.0: ModuleNotFoundError: No module named 'systemd' #12631

Closed
heini opened this issue May 4, 2022 · 7 comments · Fixed by #12640
Assignees
Labels
T-Defect Bugs, crashes, hangs, security vulnerabilities, or other reported issues. X-Regression Something broke which worked on a previous release

Comments

@heini
Copy link
Contributor

heini commented May 4, 2022

Description

With a logging configuration that logs to systemd's journal, Synapse 1.58.0 doesn't restart anymore, because of

May 04 08:10:16 chat matrix-synapse[188389]: Traceback (most recent call last):
May 04 08:10:16 chat matrix-synapse[188389]:   File "/usr/lib/python3.9/logging/config.py", line 385, in resolve
May 04 08:10:16 chat matrix-synapse[188389]:     found = self.importer(used)
May 04 08:10:16 chat matrix-synapse[188389]: ModuleNotFoundError: No module named 'systemd'
May 04 08:10:16 chat matrix-synapse[188389]: The above exception was the direct cause of the following exception:
May 04 08:10:16 chat matrix-synapse[188389]: Traceback (most recent call last):
May 04 08:10:16 chat matrix-synapse[188389]:   File "/usr/lib/python3.9/logging/config.py", line 564, in configure
May 04 08:10:16 chat matrix-synapse[188389]:     handler = self.configure_handler(handlers[name])
May 04 08:10:16 chat matrix-synapse[188389]:   File "/usr/lib/python3.9/logging/config.py", line 722, in configure_handler
May 04 08:10:16 chat matrix-synapse[188389]:     klass = self.resolve(cname)
May 04 08:10:16 chat matrix-synapse[188389]:   File "/usr/lib/python3.9/logging/config.py", line 398, in resolve
May 04 08:10:16 chat matrix-synapse[188389]:     raise v
May 04 08:10:16 chat matrix-synapse[188389]:   File "/usr/lib/python3.9/logging/config.py", line 385, in resolve
May 04 08:10:16 chat matrix-synapse[188389]:     found = self.importer(used)
May 04 08:10:16 chat matrix-synapse[188389]: ValueError: Cannot resolve 'systemd.journal.JournalHandler': No module named 'systemd'
May 04 08:10:16 chat matrix-synapse[188389]: The above exception was the direct cause of the following exception:
May 04 08:10:16 chat matrix-synapse[188389]: Traceback (most recent call last):
May 04 08:10:16 chat matrix-synapse[188389]:   File "/usr/lib/python3.9/runpy.py", line 197, in _run_module_as_main
May 04 08:10:16 chat matrix-synapse[188389]:     return _run_code(code, main_globals, None,
May 04 08:10:16 chat matrix-synapse[188389]:   File "/usr/lib/python3.9/runpy.py", line 87, in _run_code
May 04 08:10:16 chat matrix-synapse[188389]:     exec(code, run_globals)
May 04 08:10:16 chat matrix-synapse[188389]:   File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/synapse/app/homeserver.py", line 460, in <module>
May 04 08:10:16 chat matrix-synapse[188389]:     main()
May 04 08:10:16 chat matrix-synapse[188389]:   File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/synapse/app/homeserver.py", line 450, in main
May 04 08:10:16 chat matrix-synapse[188389]:     hs = setup(sys.argv[1:])
May 04 08:10:16 chat matrix-synapse[188389]:   File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/synapse/app/homeserver.py", line 377, in setup
May 04 08:10:16 chat matrix-synapse[188389]:     synapse.config.logger.setup_logging(hs, config, use_worker_options=False)

as long as this logging configuration is in place (which worked fine before):

version: 1

formatters:
  precise:
    format: '%(asctime)s - %(name)s - %(lineno)d - %(levelname)s - %(request)s - %(message)s'

handlers:
  journal:
    class: systemd.journal.JournalHandler
    formatter: precise
    level: INFO

loggers:
  synapse.storage.SQL:
    # beware: increasing this to DEBUG will make synapse log sensitive
    # information such as access tokens.
    handlers: [journal]
    level: INFO

  twisted:
    handlers: [journal]

root:
  handlers: [journal]
  level: INFO

disable_existing_loggers: true

If I comment out usage of this file in my homeserver.yaml, it works again. Guess this is due to the new Python packaging...

Steps to reproduce

  • Update to 1.58.0 using Debian package
  • Restart the server with above logging config in place

Version information

  • Version: 1.58.0
  • Install method: Debian package
  • Platform: Debian Bullseye
@DMRobertson
Copy link
Contributor

Thanks for reporting. This sounds like a regression in the debian packages (#12449). I'll try to confirm and fix this tomorrow.

@DMRobertson DMRobertson self-assigned this May 4, 2022
@DMRobertson DMRobertson added X-Regression Something broke which worked on a previous release T-Defect Bugs, crashes, hangs, security vulnerabilities, or other reported issues. labels May 4, 2022
@DMRobertson
Copy link
Contributor

DMRobertson commented May 4, 2022

Specifically, I think we need to add --extras systemd to this line:

poetry export --extras all --extras test -o exported_requirements.txt

Edit: updated in the light of my next comment. We want --extras systemd --extras cache_memory.

@DMRobertson
Copy link
Contributor

Sanity checking that I didn't miss anything else as follows.

dpkg -c matrix-synapse-py3_1.57.0+sid1_amd64.deb | awk '{print $NF}' | sort | uniq > 1.57.txt
dpkg -c matrix-synapse-py3_1.58.0+sid1_amd64.deb | awk '{print $NF}' | sort | uniq > 1.58.txt
\egrep -o "site-packages/[^/]+/" 1.57.txt | sort | uniq > 1.57.packages.txt
\egrep -o "site-packages/[^/]+/" 1.58.txt | sort | uniq > 1.58.packages.txt
diff -u 1.57.packages.txt 1.58.packages.txt 
--- 1.57.packages.txt	2022-05-05 11:50:29.166465893 +0100
+++ 1.58.packages.txt	2022-05-05 11:50:35.862514251 +0100
@@ -2,13 +2,13 @@
 site-packages/attrs/
 site-packages/attrs-21.4.0.dist-info/
 site-packages/authlib/
-site-packages/Authlib-1.0.1.dist-info/
+site-packages/Authlib-0.15.5.dist-info/
 site-packages/automat/
 site-packages/Automat-20.2.0.dist-info/
 site-packages/bcrypt/
 site-packages/bcrypt-3.2.0.dist-info/
 site-packages/bleach/
-site-packages/bleach-5.0.0.dist-info/
+site-packages/bleach-4.1.0.dist-info/
 site-packages/canonicaljson-1.6.0.dist-info/
 site-packages/certifi/
 site-packages/certifi-2021.10.8.dist-info/
@@ -20,7 +20,7 @@
 site-packages/constantly/
 site-packages/constantly-15.1.0.dist-info/
 site-packages/cryptography/
-site-packages/cryptography-36.0.2.dist-info/
+site-packages/cryptography-36.0.1.dist-info/
 site-packages/dateutil/
 site-packages/defusedxml/
 site-packages/defusedxml-0.7.1.dist-info/
@@ -28,7 +28,7 @@
 site-packages/elementpath/
 site-packages/elementpath-2.5.0.dist-info/
 site-packages/frozendict/
-site-packages/frozendict-2.3.1.dist-info/
+site-packages/frozendict-2.3.0.dist-info/
 site-packages/hiredis/
 site-packages/hiredis-2.0.0.dist-info/
 site-packages/hyperlink/
@@ -43,7 +43,7 @@
 site-packages/jaeger_client/
 site-packages/jaeger_client-4.8.0.dist-info/
 site-packages/jinja2/
-site-packages/Jinja2-3.1.1.dist-info/
+site-packages/Jinja2-3.0.3.dist-info/
 site-packages/jsonschema/
 site-packages/jsonschema-4.4.0.dist-info/
 site-packages/jwt/
@@ -52,10 +52,10 @@
 site-packages/lxml/
 site-packages/lxml-4.8.0.dist-info/
 site-packages/markupsafe/
-site-packages/MarkupSafe-2.1.1.dist-info/
+site-packages/MarkupSafe-2.1.0.dist-info/
 site-packages/matrix_common/
 site-packages/matrix_common-1.1.0.dist-info/
-site-packages/matrix_synapse-1.57.0.dist-info/
+site-packages/matrix_synapse-1.58.0.dist-info/
 site-packages/matrix_synapse_ldap3-0.2.0.dist-info/
 site-packages/mock/
 site-packages/mock-4.0.3.dist-info/
@@ -73,15 +73,15 @@
 site-packages/parameterized/
 site-packages/parameterized-0.8.1.dist-info/
 site-packages/phonenumbers/
-site-packages/phonenumbers-8.12.46.dist-info/
+site-packages/phonenumbers-8.12.44.dist-info/
 site-packages/PIL/
-site-packages/Pillow-9.1.0.dist-info/
+site-packages/Pillow-9.0.1.dist-info/
 site-packages/Pillow.libs/
 site-packages/pip/
 site-packages/pip-22.0.4.dist-info/
 site-packages/pkg_resources/
 site-packages/prometheus_client/
-site-packages/prometheus_client-0.14.1.dist-info/
+site-packages/prometheus_client-0.14.0.dist-info/
 site-packages/psycopg2/
 site-packages/psycopg2-2.9.3.dist-info/
 site-packages/pyasn1/
@@ -89,29 +89,25 @@
 site-packages/pyasn1_modules/
 site-packages/pyasn1_modules-0.2.8.dist-info/
 site-packages/__pycache__/
-site-packages/pycparser/
-site-packages/pycparser-2.21.dist-info/
 site-packages/PyJWT-2.3.0.dist-info/
 site-packages/pymacaroons/
 site-packages/pymacaroons-0.13.0.dist-info/
-site-packages/pympler/
-site-packages/Pympler-1.0.1.dist-info/
 site-packages/PyNaCl-1.5.0.dist-info/
 site-packages/pyOpenSSL-22.0.0.dist-info/
 site-packages/pyparsing/
-site-packages/pyparsing-3.0.8.dist-info/
+site-packages/pyparsing-3.0.7.dist-info/
 site-packages/pyrsistent/
 site-packages/pyrsistent-0.18.1.dist-info/
 site-packages/pysaml2-7.1.2.dist-info/
 site-packages/python_dateutil-2.8.2.dist-info/
 site-packages/pytz/
-site-packages/pytz-2022.1.dist-info/
+site-packages/pytz-2021.3.dist-info/
 site-packages/PyYAML-6.0.dist-info/
 site-packages/requests/
 site-packages/requests-2.27.1.dist-info/
 site-packages/saml2/
 site-packages/sentry_sdk/
-site-packages/sentry_sdk-1.5.10.dist-info/
+site-packages/sentry_sdk-1.5.7.dist-info/
 site-packages/service_identity/
 site-packages/service_identity-21.1.0.dist-info/
 site-packages/setuptools/
@@ -124,13 +120,10 @@
 site-packages/sortedcontainers/
 site-packages/sortedcontainers-2.4.0.dist-info/
 site-packages/synapse/
-site-packages/synmark/
-site-packages/systemd/
-site-packages/systemd_python-234.dist-info/
 site-packages/threadloop/
 site-packages/threadloop-1.0.2.dist-info/
 site-packages/thrift/
-site-packages/thrift-0.16.0.dist-info/
+site-packages/thrift-0.15.0.dist-info/
 site-packages/tornado/
 site-packages/tornado-6.1.dist-info/
 site-packages/treq/
@@ -138,11 +131,11 @@
 site-packages/twisted/
 site-packages/Twisted-22.4.0.dist-info/
 site-packages/txredisapi-1.4.7.dist-info/
-site-packages/typing_extensions-4.2.0.dist-info/
+site-packages/typing_extensions-4.1.1.dist-info/
 site-packages/unpaddedbase64/
 site-packages/unpaddedbase64-2.1.0.dist-info/
 site-packages/urllib3/
-site-packages/urllib3-1.26.9.dist-info/
+site-packages/urllib3-1.26.8.dist-info/
 site-packages/webencodings/
 site-packages/webencodings-0.5.1.dist-info/
 site-packages/wheel/

We also lost pympler. So we want --extras cache_memory too.

I'm not sure if this change is due to how debian packages are built, or if we unintentionally changed the contents of the all extra.

@anoadragon453
Copy link
Member

Thank you for the report!

This is fixed in Synapse v1.58.1, which is due to be released shortly today.

@heini
Copy link
Contributor Author

heini commented May 5, 2022

Wow, that was fast, thanks a lot. Will see if I can already get it...

@heini
Copy link
Contributor Author

heini commented May 5, 2022

Got the package. Synapse starts fine again with my systemd logging configuration enabled.

@anoadragon453
Copy link
Member

@heini Great! Thanks for confirming :)

SpiritCroc pushed a commit to SpiritCroc/synapse-old that referenced this issue May 12, 2022
Synapse 1.58.1 (2022-05-05)
===========================

This patch release includes a fix to the Debian packages, installing the
`systemd` and `cache_memory` extra package groups, which were incorrectly
omitted in v1.58.0. This primarily prevented Synapse from starting
when the `systemd.journal.JournalHandler` log handler was configured.
See [matrix-org#12631](matrix-org#12631) for further information.

Otherwise, no significant changes since 1.58.0.
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
T-Defect Bugs, crashes, hangs, security vulnerabilities, or other reported issues. X-Regression Something broke which worked on a previous release
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants