eclipse-mosquitto / mosquitto

Eclipse Mosquitto - An open source MQTT broker
https://mosquitto.org
Other
9.08k stars 2.4k forks source link

Mosquitto hanging on startup in docker image when log_dest = stdout #2338

Open alexmcorrigan opened 3 years ago

alexmcorrigan commented 3 years ago

I am running the latest eclipse-mosquitto docker image (currently 2.0.12) on a raspberry pi 4 with 'Raspian GNU /Linux 10 (buster)'.

I find that when I mount a config file that specifies log_dest to file:

log_dest file /mosquitto/log/mosquitto.log

... the broker starts up straight away, accepts connections, receives and forwards messages etc.

However, when I mount the same config file but with log_dest to stdout:

log_dest stdout

... the broker startup hangs on <timestamp>: mosquitto version 2.0.12 starting and doesn't progress any further, accepts no connections etc.

I believe this very much related to the issue reported in this ticket: https://github.com/eclipse/mosquitto/issues/773, but that seems to have been closed early before resolution.

I'm not sure what else to be looking at to investigate further, so please advise next steps to look into this.

My preference would be to not persist logs inside the docker container but have an external service collect them through the docker interface, hence wanting the stdout option.

The complete config file I am using:

persistence false
log_dest stdout
connection_messages true
listener 1883
allow_anonymous true
ralight commented 3 years ago

Hi Alex,

Thanks for the report. I've just tested this out and it works for me. I'll list what details I can think of below so you can compare to what you're doing and say where there is a difference.

I'm on Linux 64-bit, running docker 19.03.13. My config file is at conf/mosquitto.conf and looks exactly like yours:

persistence false
log_dest stdout
connection_messages true
listener 1883
allow_anonymous true

I ran an instance like this: docker run -it -v ${PWD}/conf:/mosquitto/config -p 1883:1883 eclipse-mosquitto:2. The log looked like this, including when I connected a client to check the operation.

1634078472: mosquitto version 2.0.12 starting
1634078472: Config loaded from /mosquitto/config/mosquitto.conf.
1634078472: Opening ipv4 listen socket on port 1883.
1634078472: Opening ipv6 listen socket on port 1883.
1634078472: mosquitto version 2.0.12 running
1634078492: New connection from 172.17.0.1:38522 on port 1883.
1634078492: New client connected from 172.17.0.1:38522 as auto-9274B564-6E95-6219-7C2C-7D4782DF3D08 (p2, c1, k60).
1634078493: Client auto-9274B564-6E95-6219-7C2C-7D4782DF3D08 disconnected.
alexmcorrigan commented 3 years ago

Thanks for looking into this. I spent best part of the day yesterday looking into my whole setup and can confirm everything works fine end-to-end.

I added extra logging via callbacks on both publisher and subscriber to check each step was occurring as expected. What I found was the broker was dropping connections to both after some seconds. Without the extra logging on the publisher and subscriber I wouldn't have noticed. So improving the session management on each I am able to maintain a stable connection over n time.

What I was missing though was (via stdout) the broker logging the the session disconnect messages, or any logging at all after the initial mosquitto version 2.0.12 starting. It really threw me a red herring thinking it hadn't fully started.

Will try your command for starting to see if I get more info via the stdout...

lorenx commented 2 years ago

Might be related to https://github.com/eclipse/mosquitto/issues/2354?

aeciolevy commented 2 years ago

I am getting the same issue OS: macOS 12.3 Docker: 20.10.17, build 100c701

this is my mosquitto.conf

#log_type error
log_type notice
log_type information
log_type debug
log_type websockets
#log_type all
connection_messages true
#log_dest topic
log_dest stdout
#allow_anonymous false
#Extra Listeners
listener 9001
protocol websockets
websockets_log_level 6

listener 1883 0.0.0.0
allow_anonymous true

I get this output when I run

docker run -it -p 1883:1883 -p 9001:9001 -v mosquitto.conf:${PWD}/config/mosquitto.conf -v ${PWD}/data -v ${PWD}/log eclipse-mosquitto
1662151909: mosquitto version 2.0.15 starting
1662151909: Config loaded from /mosquitto/config/mosquitto.conf.
1662151909: Starting in local only mode. Connections will only be possible from clients running on this machine.
1662151909: Create a configuration file which defines a listener to allow remote access.
1662151909: For more details see https://mosquitto.org/documentation/authentication-methods/
1662151909: Opening ipv4 listen socket on port 1883.
1662151909: Opening ipv6 listen socket on port 1883.
1662151909: Error: Address not available
1662151909: mosquitto version 2.0.15 running

If I use the docker-compose.yml

version: '3.1'
services:
  mosquitto:
    image: eclipse-mosquitto
    hostname: mosquitto
    container_name: mosquitto
    network_mode: host
    volumes:
      - $PWD/config:/mosquitto/config
      - $PWD/data:/mosquitto/data
      - $PWD/log:/mosquitto/log

I get this

[+] Running 1/0
 ⠿ Container mosquitto  Created                                                                                    0.0s
Attaching to mosquitto
mosquitto  | 1662152214: mosquitto version 2.0.15 starting