Default generated logger config causes "Permission denied: '/homeserver.log'" for non-root containers

[schnerring]

Description

Using generate to create config files with the Docker image sets the value of handlers.file.filename inside the *.log.config file to /homeserver.log, causing the following error when running the container as non-root:

PermissionError: [Errno 13] Permission denied: '/homeserver.log'

Changing it to /data/homeserver.log fixes the issue since the synapse user has write access to that folder.

Unfortunately it's not enough to disable the file log handler. Even when disabled an empty log file is initially created.

Steps to reproduce

• Create minimal config files with generate
• Run container in non-root mode

Version information

If not matrix.org:

• Version: v1.33.1

• Install method: Docker Image

• Platform: Kubernetes

Cause

The issue lies within how the log config is generated (https://github.com/matrix-org/synapse/blob/develop/synapse/config/logger.py#L171-L180):

    def generate_files(self, config, config_dir_path):
        log_config = config.get("log_config")
        if log_config and not os.path.exists(log_config):
            log_file = self.abspath("homeserver.log")
            print(
                "Generating log config file %s which will log to %s"
                % (log_config, log_file)
            )
            with open(log_config, "w") as log_config_file:
                log_config_file.write(DEFAULT_LOG_CONFIG.substitute(log_file=log_file))

which calls:

@staticmethod
    def abspath(file_path):
        return os.path.abspath(file_path) if file_path else file_path

Since the container runs start.py in /, the above resolves to /homeserver.log

[flavienbwk]

Same problem. I've edited the logging strategy as-is to make it work :

    filename: /data/homeserver.log

[erikjohnston]

Logging to /homeserver.log by default doesn't seem ideal regardless. I'm not 100% sure where we should put the log file by default (I don't know what the standard practice for docker containers are), but I think we'd be happy to have a PR to change the defaults. We probably do want to make sure that any changes here are backwards compatible? I.e. we don't change the location for existing deployments?

[flavienbwk]

@erikjohnston Why don't you put it under /data (like all other persisted files) ?

[schnerring]

@erikjohnston I think standard practice would be to only log to console since containers are ephemeral. Or if file logging is desired, log files would be written to an attached volume for persistence.

Correct me if I'm wrong, but backward compatibility shouldn't be affected since running in "on-the-fly generate mode" is no longer supported. So any existing deployments should have a working handlers.file.filename configuration that doesn't change when upgrading Synapse. EDIT: might migrate_config break regarding backwards compatibility? Haven't looked into that one.

I ran Synapse for the first time a couple of days ago and from reading the docs, I was under the impression that running Synapse as container would be done by running in "generate mode" only. So I tripped over the following:

synapse/docker/start.py

Lines 235 to 239 in e550ab1

	Config file '%s' does not exist.
	The synapse docker image no longer supports generating a config file on-the-fly
	based on environment variables. You can migrate to a static config file by
	running with 'migrate_config'. See the README for more details.

So it's more about the first-time experience when initially generating the logger config. Typically when running Synapse as a container, the synapse user has write access to /data and Synapse is also aware of that folder during generate:

synapse/docker/start.py

Line 145 in e550ab1

data_dir = environ.get("SYNAPSE_DATA_DIR", "/data")

So I think we have two options:

1. log_file = self.abspath(environ.get("SYNAPSE_DATA_DIR", "/data") + "/homeserver.log")
2. Prevent the creation of an empty logging file, if file logging is disabled and disable file logging by default

I like 1) more.

[Half-Shot]

I would also expect logging to be directed to stdout by default, as people generally rely on Docker's logging system rather than inspecting files in mounts.

[marcdraco]

I'm going to peer out from behind my dunce's cap here and admit this one has me stumped. I'm new to docker and even newer to Matrix Synapse but I wanted to set up a small homeserver. At this stage of my knowledge, if the instructions don't explicitly work then I'm in a fix.

I usually drop into the containers (?) via an interactive shelll and tinker but I can't do that from here.

Sorry to be so ignorant, but how do I get into a docker container thing to make these changes? Or is there some other way I can fire Synapse up without going through all that rigmarole?

[jakobkmar]

This currently breaks the installation of anyone trying to install Synapse the first time using Docker, could you please change the default to /data/homeserver.log until you have decided on a better approach?

This issue really requires a quick fix as the Synapse Docker guide currently does not work due to this problem.

[k8ieone]

Yep, I just went through the installation today and ran into this problem. I just disabled file logging completely since Docker catches the console output.

[schnerring]

Yep, I just went through the installation today and ran into this problem. I just disabled file logging completely since Docker catches the console output.

Haven't tested again but this also crashed my container because despite file logging disabled, an empty log file was created.

[Houndie]

@schnerring i also didn't have luck disabling logs, but my work around was just to change the log file to /dev/null, and reduce the number of backups to 0. Works so far!

[k8ieone]

@schnerring i also didn't have luck disabling logs, but my work around was just to change the log file to /dev/null, and reduce the number of backups to 0. Works so far!

If it helps, this is my log config:

version: 1

formatters:
  precise:

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


handlers:
  console:
    class: logging.StreamHandler
    formatter: precise

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

root:
    level: INFO


    handlers: [console]


disable_existing_loggers: false

[fertigfs]

Hi all I have the same problem.
How can I disable logging.
I am a newbie in docker.

[k8ieone]

Hi all I have the same problem.
How can I disable logging.
I am a newbie in docker.

The log settings should be in /data/SERVERNAME.log.config. If you copy my log config from my previous comment, it should completely disable logging to a file.

[fertigfs]

Ok its working thank you.
Is it possible to use the nginx proxy manager container for another lxc containers outside of docker in my local lan

[k8ieone]

Is it possible to use the nginx proxy manager container for another lxc containers outside of docker in my local lan

That I don't know, I also don't think it's appropriate to discuss this here.

[richvdh]

I would also expect logging to be directed to stdout by default, as people generally rely on Docker's logging system rather than inspecting files in mounts.

I'm very confused. I thought this was the default, per

synapse/docker/conf/log.config

Lines 46 to 50 in 1171b98

	{% if LOG_FILE_PATH %}
	handlers: [console, buffer]
	{% else %}
	handlers: [console]
	{% endif %}

.

[richvdh]

ok I see. The problem is that the file handler is being created even though it's not enabled.

This seems to have been introduced by #9162, which landed in Synapse 1.33.0.

[richvdh]

@schnerring wrote:

The issue lies within how the log config is generated (https://github.com/matrix-org/synapse/blob/develop/synapse/config/logger.py#L171-L180):

This appears to be incorrect - or if it's correct, it's a different problem to what everybody else is talking about. When running with docker run matrixdotorg/synapse:latest generated, the log config is generated by docker/start.py, not Synapse itself.

[appdroidbuilder]

i have also have this problem

`
version: '2.3'
services:
postgres:
image: postgres:14
restart: unless-stopped
networks:
default:
ipv4_address: 10.10.10.2
volumes:
- ./postgresdata:/var/lib/postgresql/data

# These will be used in homeserver.yaml later on
environment:
 - POSTGRES_DB=synapse
 - POSTGRES_USER=synapse
 - POSTGRES_PASSWORD=.........

element:
image: vectorim/element-web:latest
restart: unless-stopped
volumes:
- ./element-config.json:/app/config.json
networks:
default:
ipv4_address: 10.10.10.3

synapse:
image: matrixdotorg/synapse:latest
restart: unless-stopped
networks:
default:
ipv4_address: 10.10.10.4
volumes:
- ./synapse:/data

networks:
default:
external:
name: matrix_net
`

[pReya]

Same issue here with current Synapse version.

[squahtx]

@appdroidbuilder @pReya Can you please post the error message you are seeing and the Synapse version number?

[reivilibre]

I don't see how this issue is still happening as-is and no recent reporters have stepped up to say what error message is appearing or what version of Synapse is in use, so I'll close this for now. If you have details, please ask to reopen or file a new issue linking to this one.

[plantroon]

People may have copied the old homeserver.yaml after changing their server_name instead of generating a new homeserver.yaml? At least that's what I did and only changed server_name considering the rest irrelevant or more related to what domain synapse will actually be hosted at as I want usernames with top domain but the actual software must not run on the top domain.

Then log_config line must correspond to this new server_name, otherwise it will create a default log_config file and that'll have the offending configuration filename: /homeserver.log in it which obviously causes the permission denied error.

That was my problem anyway, entirely user error I'd say. Or generally the synapse configuration is not "forgiving" or fool-proof :D

[Demorald15]

Іан дика хуьлда хьан, хьан цIе хIун ганза хIаъ

[m-emm]

People may have copied the old homeserver.yaml after changing their server_name instead of generating a new homeserver.yaml? At least that's what I did and only changed server_name considering the rest irrelevant or more related to what domain synapse will actually be hosted at as I want usernames with top domain but the actual software must not run on the top domain.

Then log_config line must correspond to this new server_name, otherwise it will create a default log_config file and that'll have the offending configuration filename: /homeserver.log in it which obviously causes the permission denied error.

That was my problem anyway, entirely user error I'd say. Or generally the synapse configuration is not "forgiving" or fool-proof :D

Check your log config location thoroughly if you get the permission denied error!

Well, I fell into a very similar trap while following a tutorial on "Install Matrix Home Server On Kubernetes" by Vincze Janos. I didn't correct the path of the log config in homeserver.yaml when moving the configuration to another directory (to /config instead of /data). Synapse was then not able to find the logging config file, and silently used a default configuration, which included a file handler trying to go to /homeserver.log, causing the same symptom as the initial description of this issue, but from quite a different cause (misconfiguration by the user, not a badly generated config file).