search

Azure / iotedge

The IoT Edge OSS project
MIT License
1.46k stars 459 forks source link

Adding a route to empty routes object leads to a crash of local edgeHub #359

Closed C1oudNinja closed 6 years ago

C1oudNinja commented 6 years ago

Expected Behavior

After adding a route to empty routes object in edgeHub desired properties via deployment.json, the added route should work.

Current Behavior

After adding the route by applying new deployment.json the edgeHub crashes

Steps to Reproduce

  1. Delete all routes so that "routes : {}" is present in active deployment
  2. Add a route to deployment: "routes": { "newRoute":"FROM /* INTO $upstream"}
  3. Watch logs in edgeHub module

Context (Environment)

Device (Host) Operating System

uname -mrs Linux 4.14.59-rt37-preempt-rt x86_64

Architecture

uname -m x86_64

Container Operating System

Linux containers

Runtime Versions

iotedged

self compiled version based on commit: https://github.com/Azure/iotedge/commit/038c9059058e4dfcbaad81845f6db2fa8543eb91

Edge Agent

1.0.2

Edge Hub

1.0.2

Docker

Client: Version: 18.06.0-ce API version: 1.38 Go version: go1.10.3 Git commit: 0ffa8257ec673ed6849b73b03fb01b0cac90fdb3 Built: Wed Aug 15 09:02:59 2018 OS/Arch: linux/amd64 Experimental: false

Server: Engine: Version: 18.06.0-ce API version: 1.38 (minimum version 1.12) Go version: go1.10.3 Git commit: 0ffa8257ec673ed6849b73b03fb01b0cac90fdb3 Built: Wed Aug 15 09:03:56 2018 OS/Arch: linux/amd64 Experimental: false

Logs

2018-09-26 17:31:09.475 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.RoutingEdgeHub] - Desired properties update message received for TSBG07023537/$edgeHub
2018-09-26 17:31:09.476 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.TwinManager] - In order desired property patch from 180 to 181 for device TSBG07023537/$edgeHub
2018-09-26 17:31:09.487 +00:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Core.EdgeHubConnection] - Obtained edge hub config patch update from module twin
2018-09-26 17:31:09.488 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.ConnectionManager] - Obtained cloud connection for device TSBG07023537/$edgeHub
2018-09-26 17:31:09.624 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceConnectivityManager] - IotHub call succeeded
2018-09-26 17:31:09.624 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient] - Operation UpdateReportedPropertiesAsync succeeded for TSBG07023537/$edgeHub
2018-09-26 17:31:09.624 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudProxy] - Updating reported properties for device TSBG07023537/$edgeHub
2018-09-26 17:31:09.624 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.TwinManager] - Successfully sent reported properties to cloud for TSBG07023537/$edgeHub and reported properties version 0
2018-09-26 17:31:09.625 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.TwinManager] - Updated cached reported property for TSBG07023537/$edgeHub at reported property version 2344 cloudVerified True
2018-09-26 17:31:09.625 +00:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Core.Config.ConfigUpdater] - Updating edge hub configuration
2018-09-26 17:31:09.696 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 346 with batch size 10.
2018-09-26 17:31:09.696 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 346.
2018-09-26 17:31:09.697 +00:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Core.Config.ConfigUpdater] - Set the following 1 route(s) in edge hub
2018-09-26 17:31:09.698 +00:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Core.Config.ConfigUpdater] - marvo: FROM /* INTO $upstream
2018-09-26 17:31:09.698 +00:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Updated message store TTL to 7200 seconds
2018-09-26 17:31:09.698 +00:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Core.Config.ConfigUpdater] - Updated the edge hub store and forward configuration
2018-09-26 17:31:09.698 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.TwinManager] - Sent desired properties at version 181 to device TSBG07023537/$edgeHub
2018-09-26 17:31:10.219 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Mqtt.MessagingServiceClient] - Processing message for device Id TSBG07023537/DeviceTelemetry
2018-09-26 17:31:10.219 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.RoutingEdgeHub] - Received message from TSBG07023537/DeviceTelemetry
2018-09-26 17:31:10.234 +00:00 [WRN] [DotNetty.Common.Utilities.ReferenceCountUtil] - Failed to release a message: PublishPacket[Type=PUBLISH, QualityOfService=AtLeastOnce, Duplicate=False, Retain=False]
DotNetty.Common.Utilities.IllegalReferenceCountException: refCnt: 0, decrement: 1
   at DotNetty.Buffers.AbstractReferenceCountedByteBuffer.Release0(Int32 decrement)
   at DotNetty.Common.Utilities.ReferenceCountUtil.SafeRelease(Object msg)
2018-09-26 17:31:10.255 +00:00 [INF] [ProtocolGateway] - Failed to complete the processors, Microsoft.Azure.Devices.ProtocolGateway.Mqtt.ChannelMessageProcessingException ---> RocksDbSharp.RocksDbException: Invalid argument: Invalid column family specified in write batch
   at RocksDbSharp.Native.rocksdb_delete_cf(IntPtr db, IntPtr writeOptions, Byte[] key, Int64 keylen, ColumnFamilyHandle cf)
   at Microsoft.Azure.Devices.Edge.Storage.RocksDb.ColumnFamilyDbStore.Remove(Byte[] key) in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Storage.RocksDb/ColumnFamilyDbStore.cs:line 53
   at Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore.Add(String endpointId, IMessage message) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Core/storage/MessageStore.cs:line 115
   at Microsoft.Azure.Devices.Routing.Core.Endpoints.StoringAsyncEndpointExecutor.Invoke(IMessage message) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Routing.Core/endpoints/StoringAsyncEndpointExecutor.cs:line 61
   at Microsoft.Azure.Devices.Routing.Core.Dispatcher.DispatchInternal(IEndpointExecutor exec, IMessage message) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Routing.Core/Dispatcher.cs:line 108
   at Microsoft.Azure.Devices.Edge.Hub.Mqtt.MessagingServiceClient.SendAsync(IMessage message) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Mqtt/MessagingServiceClient.cs:line 87
   at Microsoft.Azure.Devices.ProtocolGateway.Mqtt.MqttAdapter.PublishToServerAsync(IChannelHandlerContext context, IMessagingServiceClient sendingClient, PublishPacket packet, String messageType)
   at Microsoft.Azure.Devices.ProtocolGateway.Mqtt.MessageAsyncProcessorBase`1.StartQueueProcessingAsync(IChannelHandlerContext context)
   --- End of inner exception stack trace ---
   at Microsoft.Azure.Devices.ProtocolGateway.Mqtt.MqttAdapter.CompletePublishAsync(IChannelHandlerContext context, PublishPacket will)
   at Microsoft.Azure.Devices.ProtocolGateway.Mqtt.MqttAdapter.CloseServiceConnection(IChannelHandlerContext context, Exception cause, PublishPacket will), 1f801252
2018-09-26 17:31:10.266 +00:00 [WRN] [ProtocolGateway] - Closing connection for device: TSBG07023537/DeviceTelemetry, scope: -> PUBLISH, System.AggregateException: One or more errors occurred. () ---> Microsoft.Azure.Devices.ProtocolGateway.Mqtt.ChannelMessageProcessingException ---> RocksDbSharp.RocksDbException: Invalid argument: Invalid column family specified in write batch
   at RocksDbSharp.Native.rocksdb_delete_cf(IntPtr db, IntPtr writeOptions, Byte[] key, Int64 keylen, ColumnFamilyHandle cf)
   at Microsoft.Azure.Devices.Edge.Storage.RocksDb.ColumnFamilyDbStore.Remove(Byte[] key) in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Storage.RocksDb/ColumnFamilyDbStore.cs:line 53
   at Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore.Add(String endpointId, IMessage message) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Core/storage/MessageStore.cs:line 115
   at Microsoft.Azure.Devices.Routing.Core.Endpoints.StoringAsyncEndpointExecutor.Invoke(IMessage message) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Routing.Core/endpoints/StoringAsyncEndpointExecutor.cs:line 61
   at Microsoft.Azure.Devices.Routing.Core.Dispatcher.DispatchInternal(IEndpointExecutor exec, IMessage message) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Routing.Core/Dispatcher.cs:line 108
   at Microsoft.Azure.Devices.Edge.Hub.Mqtt.MessagingServiceClient.SendAsync(IMessage message) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Mqtt/MessagingServiceClient.cs:line 87
   at Microsoft.Azure.Devices.ProtocolGateway.Mqtt.MqttAdapter.PublishToServerAsync(IChannelHandlerContext context, IMessagingServiceClient sendingClient, PublishPacket packet, String messageType)
   at Microsoft.Azure.Devices.ProtocolGateway.Mqtt.MessageAsyncProcessorBase`1.StartQueueProcessingAsync(IChannelHandlerContext context)
   --- End of inner exception stack trace ---
   at Microsoft.Azure.Devices.ProtocolGateway.Mqtt.MqttAdapter.CompletePublishAsync(IChannelHandlerContext context, PublishPacket will)
   at Microsoft.Azure.Devices.ProtocolGateway.Mqtt.MqttAdapter.CloseServiceConnection(IChannelHandlerContext context, Exception cause, PublishPacket will)
   --- End of inner exception stack trace ---
---> (Inner Exception #0) Microsoft.Azure.Devices.ProtocolGateway.Mqtt.ChannelMessageProcessingException ---> RocksDbSharp.RocksDbException: Invalid argument: Invalid column family specified in write batch
   at RocksDbSharp.Native.rocksdb_delete_cf(IntPtr db, IntPtr writeOptions, Byte[] key, Int64 keylen, ColumnFamilyHandle cf)
   at Microsoft.Azure.Devices.Edge.Storage.RocksDb.ColumnFamilyDbStore.Remove(Byte[] key) in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Storage.RocksDb/ColumnFamilyDbStore.cs:line 53
   at Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore.Add(String endpointId, IMessage message) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Core/storage/MessageStore.cs:line 115
   at Microsoft.Azure.Devices.Routing.Core.Endpoints.StoringAsyncEndpointExecutor.Invoke(IMessage message) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Routing.Core/endpoints/StoringAsyncEndpointExecutor.cs:line 61
   at Microsoft.Azure.Devices.Routing.Core.Dispatcher.DispatchInternal(IEndpointExecutor exec, IMessage message) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Routing.Core/Dispatcher.cs:line 108
   at Microsoft.Azure.Devices.Edge.Hub.Mqtt.MessagingServiceClient.SendAsync(IMessage message) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Mqtt/MessagingServiceClient.cs:line 87
   at Microsoft.Azure.Devices.ProtocolGateway.Mqtt.MqttAdapter.PublishToServerAsync(IChannelHandlerContext context, IMessagingServiceClient sendingClient, PublishPacket packet, String messageType)
   at Microsoft.Azure.Devices.ProtocolGateway.Mqtt.MessageAsyncProcessorBase`1.StartQueueProcessingAsync(IChannelHandlerContext context)
   --- End of inner exception stack trace ---
   at Microsoft.Azure.Devices.ProtocolGateway.Mqtt.MqttAdapter.CompletePublishAsync(IChannelHandlerContext context, PublishPacket will)
   at Microsoft.Azure.Devices.ProtocolGateway.Mqtt.MqttAdapter.CloseServiceConnection(IChannelHandlerContext context, Exception cause, PublishPacket will)<---
, 1f801252
2018-09-26 17:31:10.275 +00:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Mqtt.MessagingServiceClient] - Disposing MessagingServiceClient for device Id TSBG07023537/DeviceTelemetry because of exception - System.AggregateException: One or more errors occurred. () ---> Microsoft.Azure.Devices.ProtocolGateway.Mqtt.ChannelMessageProcessingException ---> RocksDbSharp.RocksDbException: Invalid argument: Invalid column family specified in write batch
   at RocksDbSharp.Native.rocksdb_delete_cf(IntPtr db, IntPtr writeOptions, Byte[] key, Int64 keylen, ColumnFamilyHandle cf)
   at Microsoft.Azure.Devices.Edge.Storage.RocksDb.ColumnFamilyDbStore.Remove(Byte[] key) in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Storage.RocksDb/ColumnFamilyDbStore.cs:line 53
   at Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore.Add(String endpointId, IMessage message) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Core/storage/MessageStore.cs:line 115
   at Microsoft.Azure.Devices.Routing.Core.Endpoints.StoringAsyncEndpointExecutor.Invoke(IMessage message) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Routing.Core/endpoints/StoringAsyncEndpointExecutor.cs:line 61
   at Microsoft.Azure.Devices.Routing.Core.Dispatcher.DispatchInternal(IEndpointExecutor exec, IMessage message) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Routing.Core/Dispatcher.cs:line 108
   at Microsoft.Azure.Devices.Edge.Hub.Mqtt.MessagingServiceClient.SendAsync(IMessage message) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Mqtt/MessagingServiceClient.cs:line 87
   at Microsoft.Azure.Devices.ProtocolGateway.Mqtt.MqttAdapter.PublishToServerAsync(IChannelHandlerContext context, IMessagingServiceClient sendingClient, PublishPacket packet, String messageType)
   at Microsoft.Azure.Devices.ProtocolGateway.Mqtt.MessageAsyncProcessorBase`1.StartQueueProcessingAsync(IChannelHandlerContext context)
   --- End of inner exception stack trace ---
   at Microsoft.Azure.Devices.ProtocolGateway.Mqtt.MqttAdapter.CompletePublishAsync(IChannelHandlerContext context, PublishPacket will)
   at Microsoft.Azure.Devices.ProtocolGateway.Mqtt.MqttAdapter.CloseServiceConnection(IChannelHandlerContext context, Exception cause, PublishPacket will)
   --- End of inner exception stack trace ---
---> (Inner Exception #0) Microsoft.Azure.Devices.ProtocolGateway.Mqtt.ChannelMessageProcessingException ---> RocksDbSharp.RocksDbException: Invalid argument: Invalid column family specified in write batch
   at RocksDbSharp.Native.rocksdb_delete_cf(IntPtr db, IntPtr writeOptions, Byte[] key, Int64 keylen, ColumnFamilyHandle cf)
   at Microsoft.Azure.Devices.Edge.Storage.RocksDb.ColumnFamilyDbStore.Remove(Byte[] key) in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Storage.RocksDb/ColumnFamilyDbStore.cs:line 53
   at Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore.Add(String endpointId, IMessage message) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Core/storage/MessageStore.cs:line 115
   at Microsoft.Azure.Devices.Routing.Core.Endpoints.StoringAsyncEndpointExecutor.Invoke(IMessage message) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Routing.Core/endpoints/StoringAsyncEndpointExecutor.cs:line 61
   at Microsoft.Azure.Devices.Routing.Core.Dispatcher.DispatchInternal(IEndpointExecutor exec, IMessage message) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Routing.Core/Dispatcher.cs:line 108
   at Microsoft.Azure.Devices.Edge.Hub.Mqtt.MessagingServiceClient.SendAsync(IMessage message) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Mqtt/MessagingServiceClient.cs:line 87
   at Microsoft.Azure.Devices.ProtocolGateway.Mqtt.MqttAdapter.PublishToServerAsync(IChannelHandlerContext context, IMessagingServiceClient sendingClient, PublishPacket packet, String messageType)
   at Microsoft.Azure.Devices.ProtocolGateway.Mqtt.MessageAsyncProcessorBase`1.StartQueueProcessingAsync(IChannelHandlerContext context)
   --- End of inner exception stack trace ---
   at Microsoft.Azure.Devices.ProtocolGateway.Mqtt.MqttAdapter.CompletePublishAsync(IChannelHandlerContext context, PublishPacket will)
   at Microsoft.Azure.Devices.ProtocolGateway.Mqtt.MqttAdapter.CloseServiceConnection(IChannelHandlerContext context, Exception cause, PublishPacket will)<---

Additional Information

You can overcome this by redeploying the edgeHub with another version. But this is not the solution which I would prefer

myagley commented 6 years ago

Thank you for the issue report. I can repro behavior. I will get back to you after some investigation. Thanks.