mosquitto

mosquitto copied to clipboard

Running the latest mosquitto docker container (eclipse-mosquitto:2.0.12) I noticed that logging to stdout is buffered when no tty is present (running docker without -it).

The problem can be observed using this config file:

log_dest stdout
log_timestamp true
log_timestamp_format %Y-%m-%dT%H:%M:%S
connection_messages true

listener 1883 0.0.0.0
allow_anonymous true

und running this command:

> docker run --rm  -p 1883:1883  -v $PWD/mosquitto.conf:/mosquitto/config/mosquitto.conf eclipse-mosquitto:2.0.12 |  ruby -pe 'print Time.now.strftime("[%Y-%m-%d %H:%M:%S] ")'
[2021-10-26 17:24:05] 2021-10-26T15:24:05: mosquitto version 2.0.12 starting
[2021-10-26 17:24:21] 2021-10-26T15:24:05: Config loaded from /mosquitto/config/mosquitto.conf.
[2021-10-26 17:24:21] 2021-10-26T15:24:05: Opening ipv4 listen socket on port 1883.
[2021-10-26 17:24:21] 2021-10-26T15:24:05: mosquitto version 2.0.12 running
[2021-10-26 17:24:21] 2021-10-26T15:24:10: New connection from 172.17.0.1:64122 on port 1883.
[2021-10-26 17:24:21] 2021-10-26T15:24:10: New client connected from 172.17.0.1:64122 as auto-87371EAC-237D-8C15-0160-E050A6DB324E (p2, c1, k60).
[2021-10-26 17:24:21] 2021-10-26T15:24:10: Client auto-87371EAC-237D-8C15-0160-E050A6DB324E disconnected.
[2021-10-26 17:24:21] 2021-10-26T15:24:16: New connection from 172.17.0.1:64126 on port 1883.
[2021-10-26 17:24:21] 2021-10-26T15:24:16: New client connected from 172.17.0.1:64126 as auto-DB0713D7-6D8F-54FB-4CA7-99C84C8CFCF3 (p2, c1, k60).
[2021-10-26 17:24:21] 2021-10-26T15:24:16: Client auto-DB0713D7-6D8F-54FB-4CA7-99C84C8CFCF3 disconnected.
[2021-10-26 17:24:21] 2021-10-26T15:24:21: New connection from 172.17.0.1:64130 on port 1883.
[2021-10-26 17:24:21] 2021-10-26T15:24:21: New client connected from 172.17.0.1:64130 as auto-E070F4AE-CE76-B1CB-3A58-E9651E5BF7CB (p2, c1, k60).

This difference in the two timestamps shows that the output is buffered and only flushed after some time or bytes are accumulated.

This behaviour can't be reproduced when logging to stderr.

Update: I can reproduce the issue using the image eclipse-mosquitto:1.6.11 but not with eclipse-mosquitto:1.6.10 so it looks like this regression was introduced with the 1.6.11 release.

I can confirm this issue, had to go back to 1.6.10.

Still present in mosquitto 2.0.15. My simple workaround is just logging to stderr. Not sure if this can cause some side effects in docker.