element-hq / element-hq/synapse

`synapse.logging.RemoteHandler` stops logging after a few seconds due to `_connection_waiter = deferred`

Open
#17,480 3 comments 1 reaction 0 assignees View on GitHub
O-Occasional S-Major T-Defect
Dominant language
Python
Stars
4.6k
Forks
600
Avg merge
5d 22h
Merged PRs (30d)
51

Description

### Description

Hello!

On a mostly fresh install of Matrix synapse, when a logging handler is set up with `class: synapse.logging.RemoteHandler`, it stops sending logs from that handler a few seconds after starting. I can verify with `tcpdump` that no more packets are being sent.

After the startup log lines, I usually see one or two requests being processed, and then nothing forever.

Other handlers continue to log just fine.

Experimenting with Synapse's logger, I could trace this down to `self._connection_waiter = deferred` in `synapse/logging/_remote.py`. Commenting this line fixes the behavior, and logs arrive continuously.

### Steps to reproduce

- Set up logging as shown in config
- Set up log receiver: `nc -l -p 12401 -vv`
- (Also set up package dump: `tcpdump -i $interface port 12401`)
- Start Synapse
- Observe a few seconds of logs, then silence

### Homeserver

private

### Synapse Version

1.111.0

### Installation Method

Debian packages from packages.matrix.org

### Database

PostgreSQL, single server, fresh with no porting or backup restores

### Workers

I don't know

### Platform

Running on Debian 12. Issue was observed with 1.95.1 from Debian's pkg repo aswell as 1.111.0 from packages.matrix.org's repo

### Configuration

log.yaml:
```
version: 1
formatters:
precise:
format: '%(asctime)s - %(name)s - %(lineno)d - %(levelname)s - %(request)s- %(message)s'
journal_fmt:
format: '%(name)s: [%(request)s] %(message)s'
structured:
class: synapse.logging.TerseJsonFormatter
filters:
context:
(): synapse.util.logcontext.LoggingContextFilter
request: ""
handlers:
file:
class: logging.handlers.WatchedFileHandler
formatter: precise
filename: /var/log/matrix-synapse/homeserver.log
filters: [context]
level: DEBUG
encoding: utf8
console:
class: logging.StreamHandler
formatter: precise
level: WARN
journal:
class: systemd.journal.JournalHandler
formatter: journal_fmt
filters: [context]
level: WARN
SYSLOG_IDENTIFIER: synapse
graylog:
class: synapse.logging.RemoteHandler
formatter: structured
filters: [context]
level: DEBUG
host: server.domain.tld
port: 12401
loggers:
twisted:
level: WARN
synapse:
level: INFO
synapse.metrics:
level: WARN
synapse.http.federation.well_known_resolver:
level: WARN
synapse.storage.TIME:
level: WARN
synapse.http.matrixfederationclient:
level: WARN
root:
level: INFO
handlers: [file, journal, graylog]
```

### Relevant log output

```shell
Nothing. Not even with `DEBUG` do the other log handlers mention anything about the RemoteHandler.
```

### Anything else that would be useful to know?

Thanks!

Contributor guide

Open the contributing guide

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.