AMQP internal error with azure sdk for java client

blewars commented 1 year ago

Hello, my team is using this emulator for integration testing our azure serverless function which consumes messages from service bus.

Issue description

We've been able to start the emulator, the rabbit instance, and our function instance in Docker containers, and all are reporting as healthy in the container logs.

But we're seeing errors in the emulator's container logs when we sent a message to it from a test client, and it's failing to:

Acknowledge receipt of the message to the client
Forward the message on to the rabbit container (there are no logs acknowledging any activity in the rabbit container).

From the emulator container logs:

warn: ServiceBusEmulator.ServiceBusEmulatorHost[0]
      AMQP SSL errors RemoteCertificateNotAvailable.
SEND AMQP 3 1 0 0
SEND sasl-mechanisms(sasl-server-mechanisms:[MSSBCBS,EXTERNAL,ANONYMOUS])
RECV sasl-init(mechanism:ANONYMOUS)
SEND sasl-outcome(code:Ok)
SEND AMQP 0 1.0.0
SEND (ch=0) open(container-id:AMQPNetLite-1e17eae8,host-name:localhost,max-frame-size:262144,channel-max:255,idle-time-out:1073741823)
RECV AMQP 0 1 0 0
RECV (ch=0) open(container-id:MF_83339e_1687506202624,host-name:localhost,max-frame-size:65536,channel-max:65535,idle-time-out:30000,properties:[product:azure-messaging-servicebus,framework:jre:null;vendor:null;jvm17.0.7+7-LTS,version:7.14.1,platform:Windows 10 10.0,user-agent:azsdk-java-azure-messaging-servicebus/7.14.1 (17.0.7; Windows 10; 10.0)])
RECV (ch=0) begin(next-outgoing-id:1,incoming-window:2147483647,outgoing-window:2147483647,handle-max:65535)
SEND (ch=0) begin(remote-channel:0,next-outgoing-id:0,incoming-window:2048,outgoing-window:2147483647,handle-max:1023)
RECV (ch=1) begin(next-outgoing-id:1,incoming-window:2147483647,outgoing-window:2147483647,handle-max:65535)
SEND (ch=1) begin(remote-channel:1,next-outgoing-id:0,incoming-window:2048,outgoing-window:2147483647,handle-max:1023)
RECV (ch=1) attach(name:cbs:sender,handle:0,role:False,snd-settle-mode:Settled,rcv-settle-mode:First,source:source(),target:target(address:$cbs),incomplete-unsettled:False,initial-delivery-count:0)
SEND (ch=1) attach(name:cbs:sender,handle:0,role:True,snd-settle-mode:Settled,rcv-settle-mode:First,source:source(),target:target(address:$cbs),incomplete-unsettled:False,initial-delivery-count:0,max-message-size:2147483647)
SEND (ch=1) flow(next-in-id:1,in-window:2048,next-out-id:0,out-window:2147483647,handle:0,delivery-count:0,link-credit:100,drain:False)
RECV (ch=1) attach(name:cbs:receiver,handle:1,role:True,snd-settle-mode:Settled,rcv-settle-mode:First,source:source(address:$cbs),target:target(address:cbs-client-reply-to))
SEND (ch=1) attach(name:cbs:receiver,handle:1,role:False,snd-settle-mode:Settled,rcv-settle-mode:First,source:source(address:$cbs),target:target(address:cbs-client-reply-to),initial-delivery-count:0,max-message-size:2147483647)
RECV (ch=1) flow(next-in-id:0,in-window:2147483647,next-out-id:1,out-window:2147483647,handle:1,delivery-count:0,link-credit:1)
RECV (ch=1) transfer(handle:0,delivery-id:0,delivery-tag:6331356130633263333364643436393439303232623866393936383063636432,message-format:0,settled:True) payload 363
SEND (ch=0) close(error:error(condition:amqp:internal-error,description:Unable to cast object of type 'System.UInt64' to type 'System.String'.))

We suspect that the issue is related to the casting error referenced on the final line of the log, but we've been unable to track down what's causing it.

Expected behaviour

The emulator should acknowledge the message to the client application and forward the message onto the rabbit container.

What we've tried

Our messaging client is written in Kotlin and leverages the official Azure SDK for Java (https://mvnrepository.com/artifact/com.azure/azure-messaging-servicebus/7.14.1), like this:

    val sender = ServiceBusClientBuilder()
        .connectionString("our-connection-string-here")
        .sender()
        .queueName("our-queue-name-here")
        .buildClient()

    sender.sendMessage(ServiceBusMessage(BinaryData.fromString("Hello world")))

    sender.close()

We've also tried:

Sending the message as a simple string instead of a BinaryData object
Setting the content type of the message to "text/plain"
Sending the message as a JSON formatted string
Sending the message using an async client
Not closing the sender client after sending the message and leaving the connection open

blewars commented 1 year ago

I am wondering whether the delivery tag generated by the Azure SDK is invalid. According to Rabbit's docs, a delivery tag is a 64 bit long value, and thus its maximum value is 9223372036854775807 (see: https://www.rabbitmq.com/confirms.html).

But from the emulator logs, we can see a much larger value being recorded: RECV (ch=1) transfer(handle:0,delivery-id:0,delivery-tag:6331356130633263333364643436393439303232623866393936383063636432,message-format:0,settled:True) payload 363

But I'm not certain whether this is related.

ederaildo commented 1 year ago

Here my log with a big delivery-tag. At the beginning appears an error RemoteCertificateNotAvailable, but in test with .Net occurs same error but all integration works.

ServiceBusEmulator.ServiceBusEmulatorHost[0]
AMQP SSL errors RemoteCertificateNotAvailable.
SEND AMQP 3 1 0 0
SEND sasl-mechanisms(sasl-server-mechanisms:[MSSBCBS,EXTERNAL,ANONYMOUS])
RECV sasl-init(mechanism:ANONYMOUS)
SEND sasl-outcome(code:Ok)
SEND AMQP 0 1.0.0
SEND (ch=0) open(container-id:AMQPNetLite-34d92b7e,host-name:localhost,max-frame-size:262144,channel-max:255,idle-time-out:1073741823)
RECV AMQP 0 1 0 0
RECV (ch=0) open(container-id:MF_d88451_1686853156801,host-name:localhost,max-frame-size:65536,channel-max:65535,idle-time-out:30000,properties:[product:azure-messaging-servicebus,framework:jre:null;vendor:null;jvm17.0.2+8-LTS-86,version:7.13.4,platform:Windows 10 10.0,user-agent:az-si-sb/5.1.0 azsdk-java-azure-messaging-servicebus/7.13.4 (17.0.2; Windows 10; 10.0)])
RECV (ch=0) begin(next-outgoing-id:1,incoming-window:2147483647,outgoing-window:2147483647,handle-max:65535)
SEND (ch=0) begin(remote-channel:0,next-outgoing-id:0,incoming-window:2048,outgoing-window:2147483647,handle-max:1023)
RECV (ch=1) begin(next-outgoing-id:1,incoming-window:2147483647,outgoing-window:2147483647,handle-max:65535)
SEND (ch=1) begin(remote-channel:1,next-outgoing-id:0,incoming-window:2048,outgoing-window:2147483647,handle-max:1023)
RECV (ch=1) attach(name:cbs:sender,handle:0,role:False,snd-settle-mode:Settled,rcv-settle-mode:First,source:source(),target:target(address:$cbs),incomplete-unsettled:False,initial-delivery-count:0)
SEND (ch=1) attach(name:cbs:sender,handle:0,role:True,snd-settle-mode:Settled,rcv-settle-mode:First,source:source(),target:target(address:$cbs),incomplete-unsettled:False,initial-delivery-count:0,max-message-size:2147483647)
SEND (ch=1) flow(next-in-id:1,in-window:2048,next-out-id:0,out-window:2147483647,handle:0,delivery-count:0,link-credit:100,drain:False)
RECV (ch=1) attach(name:cbs:receiver,handle:1,role:True,snd-settle-mode:Settled,rcv-settle-mode:First,source:source(address:$cbs),target:target(address:cbs-client-reply-to))
SEND (ch=1) attach(name:cbs:receiver,handle:1,role:False,snd-settle-mode:Settled,rcv-settle-mode:First,source:source(address:$cbs),target:target(address:cbs-client-reply-to),initial-delivery-count:0,max-message-size:2147483647)
RECV (ch=1) flow(next-in-id:0,in-window:2147483647,next-out-id:1,out-window:2147483647,handle:1,delivery-count:0,link-credit:1)
RECV (ch=1) transfer(handle:0,delivery-id:0,delivery-tag:6463336133343335653662353430613738323435623034626436653236663534,message-format:0,settled:True) payload 471
Valid $cbs request; SharedAccessSignature sr=amqp%3A%2F%2Flocalhost%2Ft-requested%2Fsubscriptions%2Fms-ms&sig=WVK1XYY9qR%2BAkQ8mrsYKvh0EPUVI13NcCJCv5jUWlRI%3D&se=1688417946&skn=all
SEND (ch=0) close(error:error(condition:amqp:internal-error,description:Unable to cast object of type 'System.UInt64' to type 'System.String'.))

I tried to debug locally by .Net App but without success, I couldn't simulate this error by .Net app

jbaudisc commented 1 year ago

I have the same issue when trying to connect the spring-cloud-azure 5.5.0 client to the service bus emulator. Is the workaround to use the InMemory storage? How can I configure the InMemory storage?

piotr-rojek / devopsifyme-sbemulator