Broker not sending messages

[shanepowell-ast]

I'm hoping I'm just doing something wrong, but I can't seem to manage to get the Broker working quite right.

Here is my setup:

if __name__ == '__main__':

    formatter = "[%(asctime)s] :: %(levelname)s :: %(name)s :: %(message)s"
    logging.basicConfig(level=logging.DEBUG, format=formatter)

    conf = {
        'listeners': {
            'default': {
                'type': 'tcp',
                'bind': '0.0.0.0:1883'
            },
            'ws1': {
                'type': 'ws',
                'bind': '0.0.0.0:9001'
            }
        },
        'auth': {
            'allow-anonymous': True
        },
        'topic-check': {
            'enabled': False
        }
    }
    mqttBroker = Broker(conf)
    asyncio.get_event_loop().run_until_complete(mqttBroker.start())
    asyncio.get_event_loop().run_forever()

I've tried MQTT-Explorer (which I use for all my mqtt work) and the mqtt client plugin for VSCode.
I'm able to connect to either the tcp or the ws port no problem.
I see the log messages output for all the connections on the broker.
I see the messages being posted to the broker log, and I see what appears to be an attempt to send out the messages.
But... no messages seem to make it out to any clients I've tried.

Here is the Broker log when I sent a very basic message to a simple topic.
topic: test
message: two

[2022-05-22 20:58:11,052] :: DEBUG :: amqtt.broker.plugins :: Plugins len(_fired_events)=3
[2022-05-22 20:58:11,052] :: INFO :: amqtt.broker.plugins.event_logger_plugin :: ### 'on_mqtt_packet_received' EVENT FIRED ###
[2022-05-22 20:58:11,053] :: DEBUG :: amqtt.broker.plugins.packet_logger_plugin :: mqtt-explorer-4a9e38c0 <-in-- PublishPacket(ts=2022-05-22 20:58:11.052645, fixed=MQTTFixedHeader(length=11, flags=0x2), variable=PublishVariableHeader(topic=test, packet_id=54150), payload=PublishPayload(data="bytearray(b'two')"))
[2022-05-22 20:58:11,053] :: DEBUG :: amqtt.mqtt.protocol.handler :: Add message to delivery
[2022-05-22 20:58:11,053] :: DEBUG :: amqtt.broker.plugins :: Plugins len(_fired_events)=6
[2022-05-22 20:58:11,053] :: DEBUG :: amqtt.mqtt.protocol.handler :: Message queue size: 1
[2022-05-22 20:58:11,053] :: DEBUG :: amqtt.mqtt.protocol.handler :: Delivering message <amqtt.session.IncomingApplicationMessage object at 0x7fc58c36e3c0>
[2022-05-22 20:58:11,053] :: INFO :: amqtt.broker.plugins.event_logger_plugin :: ### 'on_mqtt_packet_sent' EVENT FIRED ###
[2022-05-22 20:58:11,053] :: DEBUG :: amqtt.broker.plugins.packet_logger_plugin :: mqtt-explorer-4a9e38c0 -out-> PubackPacket(ts=2022-05-22 20:58:11.053226, fixed=MQTTFixedHeader(length=2, flags=0x0), variable=PacketIdVariableHeader(packet_id=54150), payload=None)
[2022-05-22 20:58:11,053] :: DEBUG :: amqtt.broker :: mqtt-explorer-4a9e38c0 handling message delivery
[2022-05-22 20:58:11,054] :: DEBUG :: amqtt.broker.plugins :: Plugins len(_fired_events)=1
[2022-05-22 20:58:11,054] :: INFO :: amqtt.broker.plugins.event_logger_plugin :: ### 'on_broker_message_received' EVENT FIRED ###
[2022-05-22 20:58:11,054] :: DEBUG :: amqtt.broker :: broadcasting {'session': Session(clientId=mqtt-explorer-4a9e38c0, state=connected), 'topic': 'test', 'data': bytearray(b'two')}
[2022-05-22 20:58:11,054] :: DEBUG :: amqtt.mqtt.protocol.handler :: 0 message(s) available for delivery

MQTT-Explorer never received any message though.
MQTT-Explorer also automatically subscribes to the root wildcard, so It should see every single message that is sent on all topics. However, no topics even appear in it's topic list.

Thanks for any help.
I hope I'm just missing something obvious.

edit
Just to be sure I wasn't doing something glaringly wrong.
I tried just running the broker from the shell . Same outcome.
the connection to the broker through mqtt-explorer is good, but no messages seem to find their way out.

> pip3 install amqtt
spowell@stowe $amqtt
[2022-05-25 12:30:50,699] :: INFO - Finished processing state new exit callbacks.
[2022-05-25 12:30:50,699] :: INFO - Finished processing state starting enter callbacks.
[2022-05-25 12:30:50,700] :: INFO - ### 'on_broker_pre_start' EVENT FIRED ###
[2022-05-25 12:30:50,700] :: INFO - Listener 'default' bind to 0.0.0.0:1883 (max_connections=-1)
[2022-05-25 12:30:50,700] :: INFO - Finished processing state starting exit callbacks.
[2022-05-25 12:30:50,700] :: INFO - Finished processing state started enter callbacks.
[2022-05-25 12:30:50,700] :: INFO - ### 'on_broker_post_start' EVENT FIRED ###
[2022-05-25 12:31:09,497] :: INFO - Listener 'default': 1 connections acquired
[2022-05-25 12:31:09,497] :: INFO - Connection from 127.0.0.1:54592 on listener 'default'
[2022-05-25 12:31:09,500] :: INFO - ### 'on_mqtt_packet_received' EVENT FIRED ###
[2022-05-25 12:31:09,501] :: INFO - Finished processing state new exit callbacks.
[2022-05-25 12:31:09,501] :: INFO - Finished processing state connected enter callbacks.
[2022-05-25 12:31:09,502] :: INFO - ### 'on_mqtt_packet_sent' EVENT FIRED ###
[2022-05-25 12:31:09,502] :: INFO - ### 'on_broker_client_connected' EVENT FIRED ###
[2022-05-25 12:31:09,505] :: INFO - ### 'on_mqtt_packet_received' EVENT FIRED ###
[2022-05-25 12:31:09,506] :: INFO - ### 'on_mqtt_packet_received' EVENT FIRED ###
[2022-05-25 12:31:09,506] :: INFO - ### 'on_mqtt_packet_sent' EVENT FIRED ###
[2022-05-25 12:31:09,507] :: INFO - ### 'on_mqtt_packet_sent' EVENT FIRED ###
[2022-05-25 12:31:16,648] :: INFO - ### 'on_mqtt_packet_received' EVENT FIRED ###
[2022-05-25 12:31:16,649] :: INFO - ### 'on_mqtt_packet_sent' EVENT FIRED ###
[2022-05-25 12:31:16,650] :: INFO - ### 'on_broker_message_received' EVENT FIRED ###
[2022-05-25 12:31:58,747] :: INFO - ### 'on_mqtt_packet_received' EVENT FIRED ###
[2022-05-25 12:31:58,749] :: INFO - Finished processing state connected exit callbacks.
[2022-05-25 12:31:58,749] :: INFO - Finished processing state disconnected enter callbacks.
[2022-05-25 12:31:58,749] :: INFO - Listener 'default': 0 connections acquired
[2022-05-25 12:31:58,749] :: INFO - ### 'on_broker_client_disconnected' EVENT FIRED ###

[projectgus]

@shanepowell-ast FWIW I had this problem with the 0.10.1 version installed from pip, but not with current master. There are 77 commits between 0.10.1 and the current master so I'm guessing it got fixed in one of those?

[not-f-elsner]

We just released a new version, please check if this one works for you and let me know: https://pypi.org/project/amqtt/0.11.0b1/

[mlasch]

I may have the same issue. The problem seems to relate with the websocket listener. I changed the example above slightly to

...
    mqttBroker = Broker(conf)
    asyncio.get_event_loop().run_until_complete(mqttBroker.start())
    asyncio.get_event_loop().run_until_complete(mqttBroker.shutdown())

The shutdown freezes at await server.close_instance() in broker.py when trying to close the ws1 listener.

Tested with amqtt==0.11.0b1 on Python 3.10.6.

[mlasch]

I got the issue solved for me. I still had websockets==9.1 installed in my poetry env. Installing in a clean environment, I got websockets==10.4 which works now with the example above.