AlterNats icon indicating copy to clipboard operation
AlterNats copied to clipboard

NATS Windows service will terminate unexpectedly from simple request-response

Open BentTranberg opened this issue 2 years ago • 2 comments

The following simple test program written in F# will cause the NATS server (v 2.9.1 (latest)) running as a Windows service to terminate unexpectedly. Although that's not a problem with AlterNats, it's a rather serious situation to have the NATS server just blow up. Of course there's a slight problem with AlterNats and MessagePack too.

If the AlterNats.MessagePack streaming is not used, then there is no problem.

If the NATS server is not running as a service, but just as a regular program, then the server does not crash, and the following line is written in the console window:

[2800] 2022/09/25 12:40:56.820241 [[31mERR[0m] [::1]:53040 - cid:6 - "v1.0.0:C#" - processPub Bad or Missing Size: 'Time _INBOX.bb300782-d251-4255-9f16-72116ebfbebd.1 '

In addition there will be an exception regarding failed streaming in the test program.

This is the test program, consisting of just two rather small files, so I'll just list them here.

If you want to test this in Visual Studio 2022, you can just create an F# console application named TestAlt, and paste the contents of these two files into the respective files in VS.

Program.fs

module TestAlt.Main

open System
open Microsoft.Extensions.Logging
open AlterNats

type TimeRequest = { WhoIsAsking:string }

type TimeResponse = { TheTime: DateTime }

let timeHandler (request: TimeRequest) : TimeResponse =
    Console.WriteLine $"Triggered key Time. Asking: {request.WhoIsAsking}"
    { TheTime = DateTime.Now }

let getNatsOptions () =
    let connectOptions = ConnectOptions.Default
    connectOptions.Echo <- true
    let options = NatsOptions.Default
    options.LoggerFactory <- new MinimumConsoleLoggerFactory(LogLevel.Information)
    options.Serializer <- MessagePackNatsSerializer() // crashes NATS-server !
    options.ConnectOptions <- connectOptions
    options

[<EntryPoint>]
let main args =
    let conn = NatsConnection (getNatsOptions ())

    conn.SubscribeRequestAsync<TimeRequest,TimeResponse>("Time", timeHandler).AsTask().Wait()
    let timeResponse = conn.RequestAsync("Time", { WhoIsAsking = "Me!" }).AsTask()
    timeResponse.Wait()
    let timeResult = timeResponse.Result
    Console.WriteLine $"Time result : {timeResult}"

    Console.WriteLine "Press any key to quit."
    Console.ReadKey() |> ignore
    0

TestAlt.fsproj

<Project Sdk="Microsoft.NET.Sdk">

  <PropertyGroup>
    <OutputType>Exe</OutputType>
    <TargetFramework>net6.0</TargetFramework>
  </PropertyGroup>

  <ItemGroup>
    <Compile Include="Program.fs" />
  </ItemGroup>

  <ItemGroup>
    <PackageReference Include="AlterNats" Version="1.0.5" />
    <PackageReference Include="AlterNats.MessagePack" Version="1.0.5" />
  </ItemGroup>

</Project>

BentTranberg avatar Sep 25 '22 10:09 BentTranberg

Length is missing in MessagePack, message length should be after the Reply Inbox but before the binary data

# the .......... is binary data
PUB Time _INBOX.64137a17-0e93-4e53-baaf-52d17298d791.1 ..........

caleblloyd avatar Sep 26 '22 14:09 caleblloyd

The reason is that the Serializer threw an exception, the message was never seraized:

Try to connect NATS nats://127.0.0.1:4222
Received ServerInfo: ServerInfo { Id = ND3RMMQZO5PT673Y6IJAV5FUMSBP7HN7XSTYVIRDTWDO3MEU5M7SHFFD, Name = ND3RMMQZO5PT673Y6IJAV5FUMSBP7HN7XSTYVIRDTWDO3MEU5M7SHFFD, Version = 2.8.4, ProtocolVersion = 1, GitCommit = 66524ed, GoVersion = go1.17.10, Host = 0.0.0.0, Port = 4222, HeadersSupported = True, AuthRequired = False, TlsRequired = False, TlsVerify = False, TlsAvailable = False, MaxPayload = 1048576, JetStreamAvailable = False, ClientId = 8, ClientIp = 127.0.0.1, Nonce = , Cluster = , ClusterDynamic = False, ClientConnectUrls = , WebSocketConnectUrls = , LameDuckMode = False }
Connect succeed , NATS nats://127.0.0.1:4222
Internal error occured on WriteLoop.
MessagePack.MessagePackSerializationException: Failed to serialize TestAlt.Main+TimeRequest value.
 ---> MessagePack.FormatterNotRegisteredException: TestAlt.Main+TimeRequest is not registered in resolver: MessagePack.Resolvers.StandardResolver
   at MessagePack.FormatterResolverExtensions.Throw(Type t, IFormatterResolver resolver)
   at MessagePack.MessagePackSerializer.Serialize[T](MessagePackWriter& writer, T value, MessagePackSerializerOptions options)
   --- End of inner exception stack trace ---
   at MessagePack.MessagePackSerializer.Serialize[T](MessagePackWriter& writer, T value, MessagePackSerializerOptions options)
   at MessagePack.MessagePackSerializer.Serialize[T](IBufferWriter`1 writer, T value, MessagePackSerializerOptions options, CancellationToken cancellationToken)
   at AlterNats.MessagePackNatsSerializer.Serialize[T](ICountableBufferWriter bufferWriter, T value)
   at AlterNats.Commands.ProtocolWriter.WritePublish[T](NatsKey& subject, ReadOnlyMemory`1 inboxPrefix, Int32 id, T value, INatsSerializer serializer)
   at AlterNats.Commands.RequestAsyncCommand`2.Write(ProtocolWriter writer)
   at AlterNats.NatsPipeliningWriteProtocolProcessor.WriteLoopAsync()
Unhandled exception. System.AggregateException: One or more errors occurred. (A task was canceled.)
 ---> System.Threading.Tasks.TaskCanceledException: A task was canceled.
   at System.Threading.Tasks.Task.GetExceptions(Boolean includeTaskCanceledExceptions)
   at System.Threading.Tasks.Task.Wait(Int32 millisecondsTimeout, CancellationToken cancellationToken)
   at System.Threading.Tasks.Task.Wait()
   at TestAlt.Main.main(String[] args) in /home/caleb/Downloads/TestAlt/TestAlt/Program.fs:line 33
--- End of stack trace from previous location ---

   --- End of inner exception stack trace ---
   at System.Threading.Tasks.Task.Wait(Int32 millisecondsTimeout, CancellationToken cancellationToken)
   at System.Threading.Tasks.Task.Wait()
   at TestAlt.Main.main(String[] args) in /home/caleb/Downloads/TestAlt/TestAlt/Program.fs:line 33

caleblloyd avatar Sep 26 '22 14:09 caleblloyd