Unhandled exception when sending message between modules

mitkodev commented 6 years ago

I stumbled upon a well hidden error, while trying to send a message from one iot edge device module to another. I just wanted to test something and sent this message:

var msg = new Message(Encoding.UTF8.GetBytes(JsonConvert.SerializeObject(new { IsEmergencyModeOn = isEmergencyModeOn })))
{
    Properties =
    {
        ["CSDeviceType"] = "Obu"
    }
};
await this.moduleClient.SendEventAsync("output1", msg);

This somehow silently breaks the channel between these two modules. Here is the log from the edgeHub while in debug mode:

018-08-29 16:15:15.852 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint testobu/devicesetup/outpu1 starting from 2 with batch size 10.
2018-08-29 16:15:15.854 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint testobu/devicesetup/outpu1 with batch size 1. Next start offset = 3.
2018-08-29 16:15:15.855 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.ModuleEndpoint] - Sending 1 message(s) to module testobu/devicesetup.
2018-08-29 16:15:15.855 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Device.DeviceMessageHandler] - Sent message with correlation ID 2229ea33-c59e-4f55-9589-b5473e404b08 to testobu/devicesetup
2018-08-29 16:15:15.987 +00:00 [DBG] [DotNetty.Buffers.PoolThreadCache`1[[System.Byte[], System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]]] - Freed 1 thread-local buffer(s) from thread: null
2018-08-29 16:15:16.182 +00:00 [INF] [ProtocolGateway] - Closing connection for device: testobu/devicesetup, ,
2018-08-29 16:15:16.187 +00:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Mqtt.MessagingServiceClient] - Disposing MessagingServiceClient for device Id testobu/devicesetup because of exception -
2018-08-29 16:15:16.200 +00:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Mqtt.DeviceProxy] - Setting device proxy inactive for device Id testobu/devicesetup
2018-08-29 16:15:16.354 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient] - Received connection status changed callback with connection status Disabled and reason Client_Close
2018-08-29 16:15:16.364 +00:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudProxy] - Closing receiver for device testobu/devicesetup in cloud proxy 947d1360-c5cd-42f1-a1c8-c7d989bba60a
2018-08-29 16:15:16.366 +00:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudProxy] - Closed cloud proxy 947d1360-c5cd-42f1-a1c8-c7d989bba60a for device testobu/devicesetup
2018-08-29 16:15:16.368 +00:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Core.ConnectionManager] - Device connection removed for device testobu/devicesetup
2018-08-29 16:15:16.375 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.EdgeHubConnection] - Updating device testobu/devicesetup connection status to Disconnected
2018-08-29 16:15:16.417 +00:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Core.Device.DeviceMessageHandler] - Remove device connection for device testobu/devicesetup

and as expected no messages are received anymore in the destination module. Even worse, the "broken" messages are kept in the local queue of the edgeHub and even after restart of the destination module, it tries to send them again and breaks.

Any suggestion what is wrong with the message that is sent and how to work it out.

Device (Host) Operating System

Ubuntu 18.04

Architecture

amd64

Container Operating System

Linux containers

Runtime Versions

iotedged iotedge 1.0.1 (6e5e86dcf0c9a3732fc72a64d9ec9b0fcb2d6fad)

Edge Agent mcr.microsoft.com/azureiotedge-agent:1.0

Edge Hub mcr.microsoft.com/azureiotedge-hub:1.0

Microsoft.Azure.Devices.Client - 1.18.0

Transport type - MQTT

aribeironovaes commented 6 years ago

Hi @ddimitrov90 ,

I will try to repro it tomorrow. Meanwhile, can you give more information about your environment? (There is a template on the github issue), it would be great if you can fill (edit your message) to give us some more context to repro.

I can't see on top of my head anything wrong with your message. Maybe the property of the message, but this will depend on the version of the SDK you are using (Are you using 1.18.0?).

I will try it our first thing tomorrow.

Thanks,

Angelo Ribeiro.

veyalla commented 6 years ago

@ddimitrov90 which version of .NET Core are your modules using? If it's not 2.1, can you please test with that?

mitkodev commented 6 years ago

.NET core version 2.1 is being used.

lt72 commented 4 years ago

@ddimitrov90 Hello, sorry for the delay here. Did you manage to get your scenario working, or do you still need help?

lt72 commented 4 years ago

Closing this issue as it seems stale. Please re-open as needed.

Azure / iotedge