Failed to update reported properties

[ilseokoh]

Type of issue

• [x] Bug
• [ ] New feature
• [ ] Enhancement

Description

I always got 1 failed simulated device when I make 3 devices. As a result, I didn't have updated properties and can't call a direct method with timeout error. Web page reported there were failed twin update and failed messages.

I got error message from service machine.

[INFO][2020-02-17 02:43:18.034][WebService.1c9eb143-a436-4a06-b8d9-6993a751a943][SimulationManager.cs:233:PrintStats] Simulation stats, {"SimulationId":"d48bb25f-6ee2-4fbe-9949-39349cafc90d","PartitionsInThisNode":1,"DevicesInThisNode":3,"ConnectedDevicesInThisNode":3,"NodesInTheCluster":1,"RateLimitMessagesThroughput":2000.0,"RateLimitClusterSize":1} [INFO][2020-02-17 02:43:18.034][WebService.1c9eb143-a436-4a06-b8d9-6993a751a943][Agent.cs:246:LogProcessStats] Process stats, {"ThreadsCount":31,"WorkingSetMemoryMB":123,"VirtualMemoryMB":21255,"PrivateMemoryMB":0}

[ERROR][2020-02-17 02:43:21.633][WebService.1c9eb143-a436-4a06-b8d9-6993a751a943][DeviceClient.cs:411:SendRawMessageAsync] Message delivery failed due to unexpected error: Transient network error occurred, please retry., {"timeSpentMsecs":60007,"deviceId":"d48bb25f-6ee2-4fbe-9949-39349cafc90d.19ea2150-2b4e-4503-b82c-a37af3e9a4fc.3","Protocol":"AMQP","e":{"ExceptionFullName":"Microsoft.Azure.Devices.Client.Exceptions.IotHubCommunicationException","ExceptionMessage":"Transient network error occurred, please retry.","StackTrace":" at Microsoft.Azure.Devices.Client.Transport.ErrorDelegatingHandler.ExecuteWithErrorHandlingAsync[T](Func1 asyncOperation)\n at Microsoft.Azure.Devices.Client.Transport.RetryDelegatingHandler.<>c__DisplayClass14_0.<<SendEventAsync>b__0>d.MoveNext()\n--- End of stack trace from previous location where exception was thrown ---\n at Microsoft.Azure.Devices.Client.Transport.RetryDelegatingHandler.SendEventAsync(Message message, CancellationToken cancellationToken)\n at Microsoft.Azure.Devices.Client.InternalClient.SendEventAsync(Message message)\n at Microsoft.Azure.IoTSolutions.DeviceSimulation.Services.DeviceClient.SendRawMessageAsync(Message message) in /home/vsts/work/1/s/simulation-service/Services/DeviceClient.cs:line 308","Source":"Microsoft.Azure.Devices.Client","Data":{},"InnerException":{"ExceptionFullName":"System.TimeoutException","ExceptionMessage":"The operation did not complete within the allocated time 00:01:00 for object message.","StackTrace":" at Microsoft.Azure.Amqp.AsyncResult.End[TAsyncResult](IAsyncResult result)\n at Microsoft.Azure.Amqp.SendingAmqpLink.EndSendMessage(IAsyncResult result)\n at System.Threading.Tasks.TaskFactory1.FromAsyncCoreLogic(IAsyncResult iar, Func2 endFunction, Action1 endAction, Task1 promise, Boolean requiresSynchronization)\n--- End of stack trace from previous location where exception was thrown ---\n at Microsoft.Azure.Devices.Client.Transport.Amqp.AmqpLinkHelper.SendAmqpMessageAsync(SendingAmqpLink sendingAmqpLink, AmqpMessage message, TimeSpan timeout)\n at Microsoft.Azure.Devices.Client.Transport.Amqp.AmqpUnit.SendMessageAsync(AmqpMessage message, TimeSpan timeout)\n at Microsoft.Azure.Devices.Client.Transport.Amqp.AmqpUnit.SendEventAsync(AmqpMessage message, TimeSpan timeout)\n at Microsoft.Azure.Devices.Client.Transport.Amqp.AmqpTransportHandler.SendEventAsync(Message message, CancellationToken cancellationToken)\n at Microsoft.Azure.Devices.Client.Transport.ErrorDelegatingHandler.<>c__DisplayClass22_0.<<ExecuteWithErrorHandlingAsync>b__0>d.MoveNext()\n--- End of stack trace from previous location where exception was thrown ---\n at Microsoft.Azure.Devices.Client.Transport.ErrorDelegatingHandler.ExecuteWithErrorHandlingAsync[T](Func1 asyncOperation)","Source":"System.Private.CoreLib","Data":{},"InnerException":null}}} [ERROR][2020-02-17 02:43:21.635][WebService.1c9eb143-a436-4a06-b8d9-6993a751a943][SendTelemetry.cs:122:SendTelemetryMessageAsync] Unexpected telemetry error, {"timeSpentMsecs":60008,"deviceId":"d48bb25f-6ee2-4fbe-9949-39349cafc90d.19ea2150-2b4e-4503-b82c-a37af3e9a4fc.3","e":{"ExceptionFullName":"Microsoft.Azure.IoTSolutions.DeviceSimulation.Services.Exceptions.TelemetrySendException","ExceptionMessage":"Message delivery failed due to unexpected error: Transient network error occurred, please retry.","StackTrace":" at Microsoft.Azure.IoTSolutions.DeviceSimulation.Services.DeviceClient.SendRawMessageAsync(Message message) in /home/vsts/work/1/s/simulation-service/Services/DeviceClient.cs:line 414\n at Microsoft.Azure.IoTSolutions.DeviceSimulation.Services.DeviceClient.SendJsonMessageAsync(String message, DeviceModelMessageSchema schema) in /home/vsts/work/1/s/simulation-service/Services/DeviceClient.cs:line 481\n at Microsoft.Azure.IoTSolutions.DeviceSimulation.Services.DeviceClient.SendMessageAsync(String message, DeviceModelMessageSchema schema) in /home/vsts/work/1/s/simulation-service/Services/DeviceClient.cs:line 188\n at Microsoft.Azure.IoTSolutions.DeviceSimulation.SimulationAgent.DeviceTelemetry.SendTelemetry.SendTelemetryMessageAsync(String msg) in /home/vsts/work/1/s/simulation-service/SimulationAgent/DeviceTelemetry/SendTelemetry.cs:line 89","Source":"Microsoft.Azure.IoTSolutions.DeviceSimulation.Services","Data":{},"InnerException":{"ExceptionFullName":"Microsoft.Azure.Devices.Client.Exceptions.IotHubCommunicationException","ExceptionMessage":"Transient network error occurred, please retry.","StackTrace":" at Microsoft.Azure.Devices.Client.Transport.ErrorDelegatingHandler.ExecuteWithErrorHandlingAsync[T](Func1 asyncOperation)\n at Microsoft.Azure.Devices.Client.Transport.RetryDelegatingHandler.<>c__DisplayClass14_0.<<SendEventAsync>b__0>d.MoveNext()\n--- End of stack trace from previous location where exception was thrown ---\n at Microsoft.Azure.Devices.Client.Transport.RetryDelegatingHandler.SendEventAsync(Message message, CancellationToken cancellationToken)\n at Microsoft.Azure.Devices.Client.InternalClient.SendEventAsync(Message message)\n at Microsoft.Azure.IoTSolutions.DeviceSimulation.Services.DeviceClient.SendRawMessageAsync(Message message) in /home/vsts/work/1/s/simulation-service/Services/DeviceClient.cs:line 308","Source":"Microsoft.Azure.Devices.Client","Data":{},"InnerException":{"ExceptionFullName":"System.TimeoutException","ExceptionMessage":"The operation did not complete within the allocated time 00:01:00 for object message.","StackTrace":" at Microsoft.Azure.Amqp.AsyncResult.End[TAsyncResult](IAsyncResult result)\n at Microsoft.Azure.Amqp.SendingAmqpLink.EndSendMessage(IAsyncResult result)\n at System.Threading.Tasks.TaskFactory1.FromAsyncCoreLogic(IAsyncResult iar, Func2 endFunction, Action1 endAction, Task`1 promise, Boolean requiresSynchronization)\n--- End of stack trace from previous location where exception was thrown ---\n at Microsoft.Azure.Devices.Client.Transport.Amqp.AmqpLinkHelper.SendAmqpMessageAsync(SendingAmqpLink sendingAmqpLink, AmqpMessage message, TimeSpan timeout)\n at Microsoft. ...

/home/vsts/work/1/s/simulation-service/Services/DeviceClient.cs:line 271\n at Microsoft.Azure.IoTSolutions.DeviceSimulation.SimulationAgent.DeviceProperties.UpdateReportedProperties.RunAsync() in /home/vsts/work/1/s/simulation-service/SimulationAgent/DeviceProperties/UpdateReportedProperties.cs:line 54","Source":"Microsoft.Azure.IoTSolutions.DeviceSimulation.Services","Data":{},"InnerException":{"ExceptionFullName":"Microsoft.Azure.Devices.Client.Exceptions.IotHubCommunicationException","ExceptionMessage":"The operation did not complete within the allocated time 00:01:00 for object message.","StackTrace":" at

Microsoft.Azure.Devices.Client.Transport.Amqp.AmqpTransportHandler.SendTwinPatchAsync(TwinCollection reportedProperties, CancellationToken cancellationToken)\n at Microsoft.Azure.Devices.Client.Transport.ErrorDelegatingHandler.<>cDisplayClass22_0.<b0>d.MoveNext()\n--- End of stack trace from previous location where exception was thrown ---\n at Microsoft.Azure.Devices.Client.Transport.ErrorDelegatingHandler.ExecuteWithErrorHandlingAsync[T](Func`1 asyncOperation)\n at Microsoft.Azure.Devices.Client.Transport.RetryDelegatingHandler.<>cDisplayClass25_0.<b0>d.MoveNext()\n--- End of stack trace from previous location where exception was thrown ---\n at Microsoft.Azure.Devices.Client.Transport.RetryDelegatingHandler.SendTwinPatchAsync(TwinCollection reportedProperties, CancellationToken cancellationToken)\n at Microsoft.Azure.Devices.Client.InternalClient.UpdateReportedPropertiesAsync(TwinCollection reportedProperties)\n at Microsoft.Azure.IoTSolutions.DeviceSimulation.Services.DeviceClient.UpdatePropertiesAsync(ISmartDictionary properties) in /home/vsts/work/1/s/simulation-service/Services/DeviceClient.cs:line 217","Source":"Microsoft.Azure.Devices.Client","Data":{},"InnerException":{"ExceptionFullName":"System.TimeoutException","ExceptionMessage":"The operation did not complete within the allocated time 00:01:00 for object message.","StackTrace":" at Microsoft.Azure.Amqp.AsyncResult.End[TAsyncResult](IAsyncResult result)\n at Microsoft.Azure.Amqp.SendingAmqpLink.EndSendMessage(IAsyncResult result)\n at System.Threading.Tasks.TaskFactory1.FromAsyncCoreLogic(IAsyncResult iar, Func2 endFunction, Action1 endAction, Task1 promise, Boolean requiresSynchronization)\n--- End of stack trace from previous location where exception was thrown ---\n at Microsoft.Azure.Devices.Client.Transport.Amqp.AmqpLinkHelper.SendAmqpMessageAsync(SendingAmqpLink sendingAmqpLink, AmqpMessage message, TimeSpan timeout)\n at Microsoft.Azure.Devices.Client.Transport.Amqp.AmqpUnit.SendTwinMessageAsync(AmqpMessage message, TimeSpan timeout)\n at Microsoft.Azure.Devices.Client.Transport.Amqp.AmqpTransportHandler.RoundTripTwinMessage(AmqpMessage amqpMessage, CancellationToken cancellationToken)\n at Microsoft.Azure.Devices.Client.Transport.Amqp.AmqpTransportHandler.SendTwinPatchAsync(TwinCollection reportedProperties, CancellationToken cancellationToken)","Source":"System.Private.CoreLib","Data":{},"InnerException":null}}}}

Steps to reproduce

1. [First step] - Add new device model iot-counter.json

   {
   "SchemaVersion": "1.0.0",
   "Id": "iot-hand-counter-01",
   "Version": "0.0.1",
   "Name": "IoT hand tally counter",
   "Description": "",
   "Protocol": "AMQP",
   "Simulation": {
       "InitialState": {
           "hit": 0,
           "hitTime": ""
       },
       "Interval": "00:00:10",
       "Scripts": [
           {
           "Type": "javascript",
           "Path": "iot-counter-state.js"
           }
       ]
   },
   "Properties": {
       "Type": "Rebutton",
       "ResetTime": "",
       "TotalCount": 0
   },
   "Telemetry": [
       {
           "Interval": "00:00:10",
           "MessageTemplate": "{\"hit\":${hit}, \"hitTime\": \"${hitTime}\"}",
           "MessageSchema": {
               "Name": "iot-hand-counter;v1",
               "Format": "JSON",
               "Fields": {
                   "hit": "integer"
               }
           }
       }
   ],
   "CloudToDeviceMethods": {
       "ResetCount": {
           "Type": "javascript",
           "Path": "reset-method.js"
       }
   }
   }

   iot-counter-state.js

   
   /*global log*/
   /*global updateState*/
   /*global updateProperty*/
   /*jslint node: true*/

"use strict";

// Default state var state = { hit: 1, hitTime: "" };

// Default properties var properties = { Type: "Rebutton", ResetTime: "", TotalCount: 0 };

/**

• Restore the global state using data from the previous iteration.
• @param previousState device state from the previous iteration

• @param previousProperties device properties from the previous iteration */ function restoreSimulation(previousState, previousProperties) { // If the previous state is null, force a default state if (previousState) { state = previousState; } else { log("Using default state"); }

  if (previousProperties) { properties = previousProperties; } else { log("Using default properties"); } }

/**

• Entry point function called by the simulation engine.
• Returns updated simulation state.
• Device property updates must call updateProperties() to persist.
• @param context The context contains current time, device model and id
• @param previousState The device state since the last iteration

• @param previousProperties The device properties since the last iteration / /jslint unparam: true*/ function main(context, previousState, previousProperties) {

  // Restore the global device properties and the global state before // generating the new telemetry, so that the telemetry can apply changes // using the previous function state. restoreSimulation(previousState, previousProperties);

  // just increse the hit count state.hit = previousState.hit + 1; state.hitTime = context.currentTime; // calc total count properties.TotalCount = Number(previousProperties.TotalCount) + state.hit;

  updateState(state); updateProperty("TotalCount", properties.TotalCount); }

  
  reset-method.js
  ```javascript
  /*global log*/
  /*global updateState*/
  /*global updateProperty*/
  /*global sleep*/
  /*jslint node: true*/

"use strict";

// Default properties var properties = { Type: "Rebutton", ResetTime: "", TotalCount: 0 };

/**

• Entry point function called by the simulation engine.
• @param context The context contains current time, device model and id
• @param previousState The device state since the last iteration

• @param previousProperties The device properties since the last iteration / /jslint unparam: true*/ function main(context, previousState, previousProperties) {

  var state = { hit: 1, hitTime: "" };

  // just increse the hit count state.hit = 0; state.hitTime = context.currentTime;

  // reset total count properties.TotalCount = 0; properties.ResetTime = context.currentTime;

  updateState(state); updateProperty("ResetTime", properties.ResetTime); updateProperty("TotalCount", properties.TotalCount); }

2. [Second step] - Add new simulation only 3 devices

3. [and so on...]

Expected behavior

All device run properly. No failed messages.

Current behavior <!-- The actual behavior observed --

1. twin update failed on the first device
2. direct method error on the first device. The others work properly.

Context and Environment

• Operating System: ...
• GitHub branch:
• Node.js Runtime: ...

[ilseokoh]

I submit this in a wrong place.