search

Azure / azure-iot-sdk-python

A Python SDK for connecting devices to Microsoft Azure IoT services
MIT License
422 stars 375 forks source link

Module to module communication shows "exception -" in logs while code does not show anything and I'm not seeing any messages #1174

Open timmermansjoy opened 6 months ago

timmermansjoy commented 6 months ago

Context

Description of the issue

I'm trying to do module to module communication. I have 2 scripts receiver.py and sender.py for both of these I created a user like said here. However when I try to send messages to each other it does not work. The code itself does not give any errors and just finishes. however when looking at the iot-hub logs it shows behaviour that there is indeed something going wrong.

the route created to do the communication on is: FROM /messages/modules/msg_sender/outputs/* INTO BrokeredEndpoint("/modules/msg_receiver/inputs/test")

The credentials piece of code is just a class I created from the link I send converted to python, this just works since I can create the client.

Code sample exhibiting the issue

sender.py code (run with sudo -u sender /home/s360box/mini_hal/.venv/bin/python3 sending.py):

import asyncio
from azure.iot.device.aio import IoTHubModuleClient
from azure.iot.device import Message
from credentials import AzureCredentials

async def send_message_to_output(message_content, sas_token, output_name):
    client = IoTHubModuleClient.create_from_sastoken(sas_token, gateway_hostname="localhost")
    await client.connect()
    print("Module connected to IoT Hub.")
    message = Message(message_content)
    print(f"Sending message to {output_name}: {message_content}")
    await client.send_message_to_output(message, output_name)
    print("Message sent.")

    await client.disconnect()
    print("Module disconnected.")

if __name__ == "__main__":
    sas_token = AzureCredentials().sas_string
    output_name = "test"
    message_content = "Hello from Module"
    loop = asyncio.get_event_loop()
    res = loop.run_until_complete(send_message_to_output(message_content, sas_token, output_name))

receiver.py code (run with sudo -u receiver /home/s360box/mini_hal/.venv/bin/python3 mqtt_recieving.py):

import asyncio
from azure.iot.device.aio import IoTHubModuleClient
from credentials import AzureCredentials

async def message_handler(message):
    print(f"Received message on input", message)

async def main(device_sas_token):
    client = IoTHubModuleClient.create_from_sastoken(device_sas_token, gateway_hostname="localhost")
    await client.connect()
    print("Module connected to IoT Hub, waiting for messages on input...")

    client.on_message_received = message_handler

    try:
        while True:
            await asyncio.sleep(10)
    except asyncio.CancelledError:
        pass
    finally:
        await client.disconnect()
        print("Module disconnected.")

if __name__ == "__main__":
    device_sas_token = AzureCredentials().sas_string
    loop = asyncio.get_event_loop()
    res = loop.run_until_complete(main(device_sas_token))

Console log of the issue

python console with logging level to info:

INFO:azure.iot.device.common.mqtt_transport:Creating client for connecting using MQTT over TCP
INFO:azure.iot.device.iothub.aio.async_clients:Connecting to Hub...
INFO:azure.iot.device.common.mqtt_transport:Connect using port 8883 (TCP)
INFO:azure.iot.device.common.mqtt_transport:connected with result code: 0
INFO:azure.iot.device.common.pipeline.pipeline_stages_mqtt:_on_mqtt_connected called
INFO:azure.iot.device.iothub.abstract_clients:Connection State - Connected
INFO:azure.iot.device.iothub.aio.async_clients:Successfully connected to Hub
Module connected to IoT Hub.
Sending message to test: Hello from Module
INFO:azure.iot.device.iothub.aio.async_clients:Sending message to output:test...
INFO:azure.iot.device.common.mqtt_transport:publishing on devices/S360N2231205LNT7CZ/modules/msg-sender/messages/events/%24.on=test
INFO:azure.iot.device.common.mqtt_transport:payload published for 1
INFO:azure.iot.device.iothub.aio.async_clients:Successfully sent message to output: test
Message sent.
INFO:azure.iot.device.iothub.aio.async_clients:Disconnecting from Hub...
INFO:azure.iot.device.common.mqtt_transport:disconnecting MQTT client
INFO:azure.iot.device.common.mqtt_transport:disconnected with result code: 0
INFO:azure.iot.device.common.pipeline.pipeline_stages_mqtt:MQTTTransportStage: _on_mqtt_disconnect called
INFO:azure.iot.device.iothub.abstract_clients:Connection State - Disconnected
INFO:azure.iot.device.iothub.abstract_clients:Cleared all pending method requests due to disconnect
INFO:azure.iot.device.iothub.aio.async_clients:Successfully disconnected from Hub
Module disconnected.

IOT Logs where we can see an exception happen but its just -:

<6> 2024-03-04 14:28:44.330 +00:00 [INF] - Client S360N2231205LNT7CZ/msg-sender in device scope authenticated locally.
<6> 2024-03-04 14:28:44.331 +00:00 [INF] - Successfully generated identity for clientId S360N2231205LNT7CZ/msg-sender and username neu-n-iot-hub.azure-devices.net/S360N2231205LNT7CZ/msg-sender/?api-version=2019-10-01&DeviceClientType=azure-iot-device-iothub-py%2F2.12.0%283.6.9%3BLinux%20%238%20SMP%20PREEMPT%20Wed%20Dec%2013%2011%3A20%3A25%20CET%202023%3Baarch64%29
<6> 2024-03-04 14:28:44.331 +00:00 [INF] - "ClientAuthenticated, S360N2231205LNT7CZ/msg-sender, 496c72b8"
<6> 2024-03-04 14:28:44.332 +00:00 [INF] - New device connection for device S360N2231205LNT7CZ/msg-sender
<6> 2024-03-04 14:28:44.332 +00:00 [INF] - Client S360N2231205LNT7CZ/msg-sender connected to edgeHub, processing existing subscriptions.
<6> 2024-03-04 14:28:44.333 +00:00 [INF] - Bind device proxy for device S360N2231205LNT7CZ/msg-sender
<6> 2024-03-04 14:28:44.333 +00:00 [INF] - Binding message channel for device Id S360N2231205LNT7CZ/msg-sender
<6> 2024-03-04 14:28:49.350 +00:00 [INF] - "Closing connection for device: S360N2231205LNT7CZ/msg-sender, , "
<6> 2024-03-04 14:28:49.351 +00:00 [INF] - **Disposing MessagingServiceClient for device Id S360N2231205LNT7CZ/msg-sender because of exception -** 
<6> 2024-03-04 14:28:49.351 +00:00 [INF] - Setting device proxy inactive for device Id S360N2231205LNT7CZ/msg-sender
<6> 2024-03-04 14:28:49.351 +00:00 [INF] - Removing device connection for device S360N2231205LNT7CZ/msg-sender with removeCloudConnection flag 'True'.
<6> 2024-03-04 14:28:49.355 +00:00 [INF] - Retrying cloud proxy operation SendMessageAsync for S360N2231205LNT7CZ/msg-sender.
<6> 2024-03-04 14:28:49.362 +00:00 [INF] - Attempting to connect to IoT Hub for client S360N2231205LNT7CZ/msg-sender via AMQP...
<6> 2024-03-04 14:28:49.446 +00:00 [INF] - Closing receiver in cloud proxy 929baa9d-961f-4963-bcad-30b1f259777c for S360N2231205LNT7CZ/msg-sender
<6> 2024-03-04 14:28:49.447 +00:00 [INF] - Closed cloud proxy 929baa9d-961f-4963-bcad-30b1f259777c for S360N2231205LNT7CZ/msg-sender
<6> 2024-03-04 14:28:49.447 +00:00 [INF] - Device connection removed for device S360N2231205LNT7CZ/msg-sender
<6> 2024-03-04 14:28:49.447 +00:00 [INF] - Remove device connection for device S360N2231205LNT7CZ/msg-sender
<6> 2024-03-04 14:28:49.518 +00:00 [INF] - Cloud connection for S360N2231205LNT7CZ/msg-sender is True
<6> 2024-03-04 14:28:49.518 +00:00 [INF] - Connection status for S360N2231205LNT7CZ/msg-sender changed to ConnectionEstablished
<6> 2024-03-04 14:28:49.518 +00:00 [INF] - Client S360N2231205LNT7CZ/msg-sender connected to cloud, processing existing subscriptions.
<6> 2024-03-04 14:28:49.519 +00:00 [INF] - Created cloud proxy for client S360N2231205LNT7CZ/msg-sender via AMQP, with client operation timeout 20 seconds.
<6> 2024-03-04 14:28:49.519 +00:00 [INF] - Initialized cloud proxy c1720fc9-8705-43e9-a275-89e8d4f7c367 for S360N2231205LNT7CZ/msg-sender
<6> 2024-03-04 14:28:49.519 +00:00 [INF] - Created cloud connection for client S360N2231205LNT7CZ/msg-sender
olivakar commented 6 months ago

The doc that is being followed - I am not able to see anything for routing set up - are u following something else for routes set up between modules?