Randomly NServiceBus MessageDeserializationException because of Newtonsoft JsonReaderException

Question

We're experiencing randomly exceptions when deserializing commands. We have a send-only API that puts messages in a queue. The tries to consume the message but fails. It occurs randomly no matter what message type. Sometimes the backend can deserialize the message. We set up NServiceBus to use NewtonSoft.Json (API uses 12.0.3 and Backend uses 12.0.1) with default settings. We don't make use of the unobtrusive mode since we declare our commands with ICommand. As transport we use Azure ServiceBus.

The most disturbing thing is: We have an almost exact same infrastructure in our staging environment (BETA) and everything works fine. When we reproduce the same message on both environments (BETA and PRODUCTION) the message can be deserialized on BETA with the same data whereas on PRODUCTION it can't. All headers and body data are equal, even the enclosed message types. Both environments use identical (binary same) binaries. Both environments run on nearly identical configured app services on Azure (e.g. net core 3.1, win 64-bit).

{
  "AmqpMessage": null,
  "Body": "{\"Email\":\"vofil69829@bbsaili.com\",\"AccountantId\":{\"Value\":\"75f61737-b9e8-40a3-a1c4-23d7bd61c527\"}}",
  "MessageId": "d829e8ce-261f-4033-a294-f279c0390851",
  "PartitionKey": null,
  "TransactionPartitionKey": null,
  "SessionId": null,
  "ReplyToSessionId": null,
  "TimeToLive": "10675199.02:48:05.4775807",
  "CorrelationId": "2ca22dd7-396b-4950-acb6-ad4800ac9d65",
  "Subject": null,
  "To": null,
  "ContentType": "application/json",
  "ReplyTo": null,
  "ScheduledEnqueueTime": "0001-01-01T00:00:00+00:00",
  "ApplicationProperties": {
    "NServiceBus.Transport.Encoding": "application/octect-stream",
    "NServiceBus.MessageId": "2ca22dd7-396b-4950-acb6-ad4800ac9d65",
    "NServiceBus.MessageIntent": "Send",
    "NServiceBus.ConversationId": "97743453-c3ac-4e08-a1df-ad4800ac9d65",
    "NServiceBus.CorrelationId": "2ca22dd7-396b-4950-acb6-ad4800ac9d65",
    "NServiceBus.OriginatingMachine": "dw1sdwk00002R",
    "NServiceBus.OriginatingEndpoint": "AwarenessCenter.Api",
    "$.diagnostics.originating.hostid": "a5a720d14ccabd7a8ba708f5bc79b2a3",
    "NServiceBus.ContentType": "application/json",
    "NServiceBus.EnclosedMessageTypes": "AwarenessCenter.Domain.Users.Registration.InviteUserCommand, AwarenessCenter.Domain, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null",
    "NServiceBus.Version": "7.4.4",
    "NServiceBus.TimeSent": "2021-06-15 10:28:28:288468 Z",
    "Diagnostic-Id": "00-1d6433cf14ae654a84e290f66d5faf25-3b4885ae29c8fc4f-00",
    "NServiceBus.ExceptionInfo.ExceptionType": "NServiceBus.MessageDeserializationException",
    "NServiceBus.ExceptionInfo.InnerExceptionType": "Newtonsoft.Json.JsonReaderException",
    "NServiceBus.ExceptionInfo.HelpLink": null,
    "NServiceBus.ExceptionInfo.Message": "An error occurred while attempting to extract logical messages from incoming physical message 2ca22dd7-396b-4950-acb6-ad4800ac9d65",
    "NServiceBus.ExceptionInfo.Source": "NServiceBus.Core",
    "NServiceBus.ExceptionInfo.StackTrace": "NServiceBus.MessageDeserializationException: An error occurred while attempting to extract logical messages from incoming physical message 2ca22dd7-396b-4950-acb6-ad4800ac9d65\r\n ---> Newtonsoft.Json.JsonReaderException: Unexpected character encountered while parsing value: {. Path 'AccountantId', line 1, position 50.\r\n   at Newtonsoft.Json.JsonTextReader.ReadStringValue(ReadType readType)\r\n   at Newtonsoft.Json.JsonTextReader.ReadAsString()\r\n   at Newtonsoft.Json.JsonReader.ReadForType(JsonContract contract, Boolean hasConverter)\r\n   at Newtonsoft.Json.Serialization.JsonSerializerInternalReader.PopulateObject(Object newObject, JsonReader reader, JsonObjectContract contract, JsonProperty member, String id)\r\n   at Newtonsoft.Json.Serialization.JsonSerializerInternalReader.CreateObject(JsonReader reader, Type objectType, JsonContract contract, JsonProperty member, JsonContainerContract containerContract, JsonProperty containerMember, Object existingValue)\r\n   at Newtonsoft.Json.Serialization.JsonSerializerInternalReader.CreateValueInternal(JsonReader reader, Type objectType, JsonContract contract, JsonProperty member, JsonContainerContract containerContract, JsonProperty containerMember, Object existingValue)\r\n   at Newtonsoft.Json.Serialization.JsonSerializerInternalReader.Deserialize(JsonReader reader, Type objectType, Boolean checkAdditionalContent)\r\n   at Newtonsoft.Json.JsonSerializer.DeserializeInternal(JsonReader reader, Type objectType)\r\n   at NServiceBus.Newtonsoft.Json.JsonMessageSerializer.ReadObject(Stream stream, Boolean isArrayStream, Type type)\r\n   at NServiceBus.Newtonsoft.Json.JsonMessageSerializer.DeserializeMultipleMessageTypes(Stream stream, IList`1 messageTypes, Boolean isArrayStream)\r\n   at NServiceBus.Newtonsoft.Json.JsonMessageSerializer.Deserialize(Stream stream, IList`1 messageTypes)\r\n   at NServiceBus.DeserializeMessageConnector.Extract(IncomingMessage physicalMessage) in /_/src/NServiceBus.Core/Pipeline/Incoming/DeserializeMessageConnector.cs:line 119\r\n   at NServiceBus.DeserializeMessageConnector.ExtractWithExceptionHandling(IncomingMessage message) in /_/src/NServiceBus.Core/Pipeline/Incoming/DeserializeMessageConnector.cs:line 53\r\n   --- End of inner exception stack trace ---\r\n   at NServiceBus.DeserializeMessageConnector.ExtractWithExceptionHandling(IncomingMessage message) in /_/src/NServiceBus.Core/Pipeline/Incoming/DeserializeMessageConnector.cs:line 53\r\n   at NServiceBus.DeserializeMessageConnector.Invoke(IIncomingPhysicalMessageContext context, Func`2 stage) in /_/src/NServiceBus.Core/Pipeline/Incoming/DeserializeMessageConnector.cs:line 29\r\n   at NServiceBus.InvokeAuditPipelineBehavior.Invoke(IIncomingPhysicalMessageContext context, Func`2 next) in /_/src/NServiceBus.Core/Audit/InvokeAuditPipelineBehavior.cs:line 27\r\n   at NServiceBus.ProcessingStatisticsBehavior.Invoke(IIncomingPhysicalMessageContext context, Func`2 next) in /_/src/NServiceBus.Core/Performance/Statistics/ProcessingStatisticsBehavior.cs:line 32\r\n   at NServiceBus.TransportReceiveToPhysicalMessageConnector.Invoke(ITransportReceiveContext context, Func`2 next) in /_/src/NServiceBus.Core/Pipeline/Incoming/TransportReceiveToPhysicalMessageConnector.cs:line 61\r\n   at NServiceBus.MainPipelineExecutor.Invoke(MessageContext messageContext) in /_/src/NServiceBus.Core/Pipeline/MainPipelineExecutor.cs:line 50\r\n   at NServiceBus.Transport.AzureServiceBus.MessagePump.InnerProcessMessage(Task`1 receiveTask)",
    "NServiceBus.TimeOfFailure": "2021-06-15 10:28:28:346039 Z",
    "NServiceBus.ExceptionInfo.Data.Message ID": "2ca22dd7-396b-4950-acb6-ad4800ac9d65",
    "NServiceBus.ExceptionInfo.Data.Transport message ID": "b6c3a3cf-84bf-4235-8551-35a1daf4bc5d",
    "NServiceBus.FailedQ": "AwarenessCenter.Backend",
    "NServiceBus.ProcessingMachine": "dw1sdwk00002R",
    "NServiceBus.ProcessingEndpoint": "AwarenessCenter.Backend",
    "$.diagnostics.hostid": "f0377aabcaf4cc26d4afb3e60b704550",
    "$.diagnostics.hostdisplayname": "dw1sdwk00002R"
  },
  "LockToken": "00000000-0000-0000-0000-000000000000",
  "DeliveryCount": 0,
  "LockedUntil": "0001-01-01T00:00:00+00:00",
  "SequenceNumber": 541,
  "DeadLetterSource": null,
  "PartitionId": 0,
  "EnqueuedSequenceNumber": 0,
  "EnqueuedTime": "2021-06-15T10:28:28.396+00:00",
  "LockTokenGuid": "00000000-0000-0000-0000-000000000000",
  "ExpiresAt": "9999-12-31T23:59:59.9999999+00:00",
  "DeadLetterReason": null,
  "DeadLetterErrorDescription": null
}

Answer 1

So after we deployed a third time with the exact same codebasis the problem resolved by itself. We have no idea what caused the issue.

Answer 2

I suspect the serialization of the message is not done properly or the type serialized and deserialized are not identical. That what the exception is thrown by NServiceBus is hinting at (see NServiceBus.ExceptionInfo.StackTrace header for details. Specifically

An error occurred while attempting to extract logical messages from incoming physical message 2ca22dd7-396b-4950-acb6-ad4800ac9d65\r\n ---> Newtonsoft.Json.JsonReaderException: Unexpected character encountered while parsing value: {. Path 'AccountantId', line 1, position 50

Based on the serialized payload

"{"Email":"vofil69829@bbsaili.com","AccountantId":{"Value":"75f61737-b9e8-40a3-a1c4-23d7bd61c527"}}"

looks like the AccountantId is not a simple type but rather a nested type since JSON translates into

{
    "Email":"vofil69829@bbsaili.com",
    "AccountantId":
    {
        "Value":"75f61737-b9e8-40a3-a1c4-23d7bd61c527"
    }
}

Where I suspect on the receiving side the expectation is to see a message of the following type

class SomeContract
{
  public string Email { get; set; }
  public Guid AccountantId { get; set; }
}