Docker v1.92.2: Exception with logging, synapse doesn't start

Bandie commented 1 year ago

Description

With the version 1.92.2 which also contains the Debian update, I suspect that some python libs has changed. It seems to affect the logging. Config wise I use the logging sample config you can find here.

Steps to reproduce

Steps to reproduce:

pull synapse version v1.92.2 or (currently) latest via Docker
recreate and start
Exception appears, synapse doesn't run

Steps to unreproduce:

pull synapse version v1.92.1 via Docker
recreate and start
synapse runs

Homeserver

chaospott.de:8448

Synapse Version

v1.92.2

Installation Method

Docker (matrixdotorg/synapse)

Database

postgres15, single, no ports or restored backups

Workers

Single process

Platform

VM, firewalled Debian 10

Configuration

No response

Relevant log output

Starting synapse with args -m synapse.app.homeserver --config-path /data/homeserver.yaml
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/logging/config.py", line 586, in configure
    handler = self.configure_handler(handlers[name])
              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/logging/config.py", line 758, in configure_handler
    result = factory(**kwargs)
             ^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/synapse/logging/handlers.py", line 50, in __init__
    self._flushing_thread.start()
  File "/usr/local/lib/python3.11/threading.py", line 957, in start
    _start_new_thread(self._bootstrap, ())
RuntimeError: can't start new thread

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "<frozen runpy>", line 198, in _run_module_as_main
  File "<frozen runpy>", line 88, in _run_code
  File "/usr/local/lib/python3.11/site-packages/synapse/app/homeserver.py", line 399, in <module>
    main()
  File "/usr/local/lib/python3.11/site-packages/synapse/app/homeserver.py", line 389, in main
    hs = setup(sys.argv[1:])
         ^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/synapse/app/homeserver.py", line 348, in setup
    synapse.config.logger.setup_logging(hs, config, use_worker_options=False)
  File "/usr/local/lib/python3.11/site-packages/synapse/config/logger.py", line 341, in setup_logging
    _setup_stdlib_logging(config, log_config_path, logBeginner=logBeginner)
  File "/usr/local/lib/python3.11/site-packages/synapse/config/logger.py", line 239, in _setup_stdlib_logging
    _load_logging_config(log_config_path)
  File "/usr/local/lib/python3.11/site-packages/synapse/config/logger.py", line 296, in _load_logging_config
    logging.config.dictConfig(log_config)
  File "/usr/local/lib/python3.11/logging/config.py", line 823, in dictConfig
    dictConfigClass(config).configure()
  File "/usr/local/lib/python3.11/logging/config.py", line 590, in configure
    raise ValueError('Unable to configure handler '
ValueError: Unable to configure handler 'buffer'

Anything else that would be useful to know?

No response

olafpeter commented 1 year ago

same config, same problem

DMRobertson commented 1 year ago

Trying to reproduce this locally, I see something different:

$ docker run --mount type=volume,src=synapse-data,dst=/data     -p 8008:8008     matrixdotorg/synapse:v1.92.2
Starting synapse with args -m synapse.app.homeserver --config-path /data/homeserver.yaml
This server is configured to use 'matrix.org' as its trusted key server via the
'trusted_key_servers' config option. 'matrix.org' is a good choice for a key
server since it is long-lived, stable and trusted. However, some admins may
wish to use another server for this purpose.

To suppress this warning and continue using 'matrix.org', admins should set
'suppress_key_server_warning' to 'true' in homeserver.yaml.
--------------------------------------------------------------------------------
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/logging/config.py", line 573, in configure
    handler = self.configure_handler(handlers[name])
              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/logging/config.py", line 758, in configure_handler
    result = factory(**kwargs)
             ^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/logging/handlers.py", line 214, in __init__
    BaseRotatingHandler.__init__(self, filename, 'a', encoding=encoding,
  File "/usr/local/lib/python3.11/logging/handlers.py", line 58, in __init__
    logging.FileHandler.__init__(self, filename, mode=mode,
  File "/usr/local/lib/python3.11/logging/__init__.py", line 1181, in __init__
    StreamHandler.__init__(self, self._open())
                                 ^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/logging/__init__.py", line 1213, in _open
    return open_func(self.baseFilename, self.mode,
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
FileNotFoundError: [Errno 2] No such file or directory: '/var/log/matrix-synapse/homeserver.log'

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "<frozen runpy>", line 198, in _run_module_as_main
  File "<frozen runpy>", line 88, in _run_code
  File "/usr/local/lib/python3.11/site-packages/synapse/app/homeserver.py", line 399, in <module>
    main()
  File "/usr/local/lib/python3.11/site-packages/synapse/app/homeserver.py", line 389, in main
    hs = setup(sys.argv[1:])
         ^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/synapse/app/homeserver.py", line 348, in setup
    synapse.config.logger.setup_logging(hs, config, use_worker_options=False)
  File "/usr/local/lib/python3.11/site-packages/synapse/config/logger.py", line 341, in setup_logging
    _setup_stdlib_logging(config, log_config_path, logBeginner=logBeginner)
  File "/usr/local/lib/python3.11/site-packages/synapse/config/logger.py", line 239, in _setup_stdlib_logging
    _load_logging_config(log_config_path)
  File "/usr/local/lib/python3.11/site-packages/synapse/config/logger.py", line 296, in _load_logging_config
    logging.config.dictConfig(log_config)
  File "/usr/local/lib/python3.11/logging/config.py", line 823, in dictConfig
    dictConfigClass(config).configure()
  File "/usr/local/lib/python3.11/logging/config.py", line 580, in configure
    raise ValueError('Unable to configure handler '
ValueError: Unable to configure handler 'file'

DMRobertson commented 1 year ago

RuntimeError: can't start new thread

It looks like you'll need to upgrade your host's installed version of docker (or podman or similar). See https://stackoverflow.com/a/70093119/5252017 or https://medium.com/nttlabs/ubuntu-21-10-and-fedora-35-do-not-work-on-docker-20-10-9-1cd439d9921.

Can you try that out and see if that resolves the problem for you?

DMRobertson commented 1 year ago

olafpeter commented 1 year ago

That was the job, thanks. Solved for me

clokep commented 1 year ago

Sounds like we're all set.

Ahwxorg commented 11 months ago

I get these logs, running Docker 20.10.24+dfsg1

Container should be the newest one, here is my docker-compose.yaml section for synapse:

services:
  synapse:
    image: docker.io/matrixdotorg/synapse:latest
    # Since synapse does not retry to connect to the database, restart upon
    # failure
    restart: always
    # See the readme for a full documentation of the environment settings
    # NOTE: You must edit homeserver.yaml to use postgres, it defaults to sqlite
    environment:
      - SYNAPSE_CONFIG_PATH=/data/homeserver.yaml
    volumes:
      # You may either store all the files in a local folder
      - ./synapse:/data
      # .. or you may split this between different storage points
      # - ./files:/data
      # - /path/to/ssd:/data/uploads
      # - /path/to/large_hdd:/data/media
    ports:
      - 8008:8008/tcp
    networks:
      - matrix

matrix-synapse-synapse-1             | Traceback (most recent call last):
matrix-synapse-synapse-1             |   File "/usr/local/lib/python3.11/logging/config.py", line 573, in configure
matrix-synapse-synapse-1             |     handler = self.configure_handler(handlers[name])
matrix-synapse-synapse-1             |               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
matrix-synapse-synapse-1             |   File "/usr/local/lib/python3.11/logging/config.py", line 758, in configure_handler
matrix-synapse-synapse-1             |     result = factory(**kwargs)
matrix-synapse-synapse-1             |              ^^^^^^^^^^^^^^^^^
matrix-synapse-synapse-1             |   File "/usr/local/lib/python3.11/logging/handlers.py", line 214, in __init__
matrix-synapse-synapse-1             |     BaseRotatingHandler.__init__(self, filename, 'a', encoding=encoding,
matrix-synapse-synapse-1             |   File "/usr/local/lib/python3.11/logging/handlers.py", line 58, in __init__
matrix-synapse-synapse-1             |     logging.FileHandler.__init__(self, filename, mode=mode,
matrix-synapse-synapse-1             |   File "/usr/local/lib/python3.11/logging/__init__.py", line 1181, in __init__
matrix-synapse-synapse-1             |     StreamHandler.__init__(self, self._open())
matrix-synapse-synapse-1             |                                  ^^^^^^^^^^^^
matrix-synapse-synapse-1             |   File "/usr/local/lib/python3.11/logging/__init__.py", line 1213, in _open
matrix-synapse-synapse-1             |     return open_func(self.baseFilename, self.mode,
matrix-synapse-synapse-1             |            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
matrix-synapse-synapse-1             | FileNotFoundError: [Errno 2] No such file or directory: '/home/synapse/synapse/homeserver.log'
matrix-synapse-synapse-1             |
matrix-synapse-synapse-1             | The above exception was the direct cause of the following exception:
matrix-synapse-synapse-1             |
matrix-synapse-synapse-1             | Traceback (most recent call last):
matrix-synapse-synapse-1             |   File "<frozen runpy>", line 198, in _run_module_as_main
matrix-synapse-synapse-1             |   File "<frozen runpy>", line 88, in _run_code
matrix-synapse-synapse-1             |   File "/usr/local/lib/python3.11/site-packages/synapse/app/homeserver.py", line 399, in <module>
matrix-synapse-synapse-1             |     main()
matrix-synapse-synapse-1             |   File "/usr/local/lib/python3.11/site-packages/synapse/app/homeserver.py", line 389, in main
matrix-synapse-synapse-1             |     hs = setup(sys.argv[1:])
matrix-synapse-synapse-1             |          ^^^^^^^^^^^^^^^^^^^
matrix-synapse-synapse-1             |   File "/usr/local/lib/python3.11/site-packages/synapse/app/homeserver.py", line 348, in setup
matrix-synapse-synapse-1             |     synapse.config.logger.setup_logging(hs, config, use_worker_options=False)
matrix-synapse-synapse-1             |   File "/usr/local/lib/python3.11/site-packages/synapse/config/logger.py", line 341, in setup_logging
matrix-synapse-synapse-1             |     _setup_stdlib_logging(config, log_config_path, logBeginner=logBeginner)
matrix-synapse-synapse-1             |   File "/usr/local/lib/python3.11/site-packages/synapse/config/logger.py", line 239, in _setup_stdlib_logging
matrix-synapse-synapse-1             |     _load_logging_config(log_config_path)
matrix-synapse-synapse-1             |   File "/usr/local/lib/python3.11/site-packages/synapse/config/logger.py", line 296, in _load_logging_config
matrix-synapse-synapse-1             |     logging.config.dictConfig(log_config)
matrix-synapse-synapse-1             |   File "/usr/local/lib/python3.11/logging/config.py", line 823, in dictConfig
matrix-synapse-synapse-1             |     dictConfigClass(config).configure()
matrix-synapse-synapse-1             |   File "/usr/local/lib/python3.11/logging/config.py", line 580, in configure
matrix-synapse-synapse-1             |     raise ValueError('Unable to configure handler '
matrix-synapse-synapse-1             | ValueError: Unable to configure handler 'file'
matrix-synapse-synapse-1 exited with code 1

Ahwxorg commented 11 months ago

I had been running synapse using this guide previously, as a different user, but I want to switch to Docker.

matrix-org / synapse