"bytes left unconsumed" error occured on azure-servicebus-2.0.0-PREVIEW-7.jar, but same code works well on azure-servicebus-2.0.0-PREVIEW-5.jar

[yuhaii]

Focus on exceptions 2018-10-31 09:47:40.921 WARN 21888 --- [b9-e3c4d2e0b9c7] c.m.a.s.primitives.MessagingFactory : Reactor error occured

com.microsoft.azure.servicebus.primitives.ServiceBusException: bytes left unconsumed, TrackingId: 037bc9f0-f0d8-43b0-b98a-2129fd9ead00, at: 2018-10-31T09:47:40.917-05:00[America/Chicago] at com.microsoft.azure.servicebus.primitives.MessagingFactory$RunReactor.run(MessagingFactory.java:586) ~[azure-servicebus-2.0.0-PREVIEW-7.jar:na] at java.lang.Thread.run(Thread.java:745) [na:1.8.0_101] Caused by: org.apache.qpid.proton.engine.TransportException: bytes left unconsumed at org.apache.qpid.proton.engine.impl.ssl.SimpleSslTransportWrapper.unwrapInput(SimpleSslTransportWrapper.java:142) ~[proton-j-0.29.0.jar:na] at org.apache.qpid.proton.engine.impl.ssl.SimpleSslTransportWrapper.process(SimpleSslTransportWrapper.java:361) ~[proton-j-0.29.0.jar:na] at org.apache.qpid.proton.engine.impl.ssl.SslImpl$UnsecureClientAwareTransportWrapper.process(SslImpl.java:144) ~[proton-j-0.29.0.jar:na] at org.apache.qpid.proton.engine.impl.TransportImpl.process(TransportImpl.java:1513) ~[proton-j-0.29.0.jar:na] at org.apache.qpid.proton.reactor.impl.IOHandler$1.run(IOHandler.java:233) ~[proton-j-0.29.0.jar:na] at org.apache.qpid.proton.reactor.impl.SelectableImpl.readable(SelectableImpl.java:118) ~[proton-j-0.29.0.jar:na] at org.apache.qpid.proton.reactor.impl.IOHandler.handleQuiesced(IOHandler.java:60) ~[proton-j-0.29.0.jar:na] at org.apache.qpid.proton.reactor.impl.IOHandler.onUnhandled(IOHandler.java:389) ~[proton-j-0.29.0.jar:na] at org.apache.qpid.proton.engine.BaseHandler.onReactorQuiesced(BaseHandler.java:87) ~[proton-j-0.29.0.jar:na] at org.apache.qpid.proton.engine.BaseHandler.handle(BaseHandler.java:206) ~[proton-j-0.29.0.jar:na] at org.apache.qpid.proton.engine.impl.EventImpl.dispatch(EventImpl.java:108) ~[proton-j-0.29.0.jar:na] at org.apache.qpid.proton.reactor.impl.ReactorImpl.dispatch(ReactorImpl.java:324) ~[proton-j-0.29.0.jar:na] at org.apache.qpid.proton.reactor.impl.ReactorImpl.process(ReactorImpl.java:292) ~[proton-j-0.29.0.jar:na] at com.microsoft.azure.servicebus.primitives.MessagingFactory$RunReactor.run(MessagingFactory.java:564) ~[azure-servicebus-2.0.0-PREVIEW-7.jar:na] ... 1 common frames omitted

Describe the bug The most recent maven jar for azure-servicebus 2.0.0-PREVIEW-7 started to produce failures reading from message queue: "com.microsoft.azure.servicebus.primitives.ServiceBusException: bytes left unconsumed".

To Reproduce Here is the code that sets up our connection to the queue:

public void initialize_OutQueuesClient(G2_MessageHandler mmh, String outboundQueueName) throws G2CommunicationsException { // Initialize log.info("Create OB queue client: " + outboundQueueName); try { IQueueClient outboundQueueClient = new QueueClient(new ConnectionStringBuilder(connectionString, outboundQueueName), ReceiveMode.PEEKLOCK); outboundQueueClientMap.put(outboundQueueName, outboundQueueClient); // Register message handler on agent side to receive messages from server: mmh.setQueueClient(outboundQueueClient); outboundQueueClient.registerMessageHandler(mmh, new MessageHandlerOptions(1, false, Duration.ofMinutes(1))); //mmh.setG2CommunicationsServices(this, outboundQueueClient); } catch (InterruptedException | ServiceBusException e) { log.error("ServiceException Error in MessagingSerivces: " + e.getMessage(), e); throw new G2CommunicationsException(e.getMessage(), e, "InitializeMessengerServices"); } }

This exact same code works messages on other queues, and the message that is failing repeatedly for me works fine if I revert back to a previous version "2.0.0-PREVIEW-5" of the com.microsoft.azure jar.

Expected behavior The message should be normally received.

Observed behavior Raise exception.

Environment (please complete the following information):

• OS: [e.g. iOS]
• SDK Version : azure-servicebus-2.0.0-PREVIEW-7.jar

Additional context I am testing azure-servicebus-2.0.0-PREVIEW-7.jar. I find that if I set the DataLen = 10000; the registered receiver will stop working. not sure whether it have relation with this issue. Following is my testing code( ------ notice that it is not the code generate "bytes left unconsumed" error ------)

import com.microsoft.azure.servicebus.; import com.microsoft.azure.servicebus.primitives.ConnectionStringBuilder; import com.google.gson.Gson; import java.time.Duration; import java.util.; import java.util.concurrent.*;

public final class ServiveBusVersionTest { static String ConnectionString = "Endpoint=sb://servicebussha.servicebus.windows.net/;SharedAccessKeyName=RootManageSharedAccessKey;SharedAccessKey=xxxxxxx"; static String QueueName = "testsha"; static Gson GSON = new com.google.gson.Gson(); static int DataLen = 10000; static int SendTimes = 100;

public static void main(String[] args) {
    try {
        run();
    } catch (Exception e) {
        System.out.println(e.getMessage());
        e.printStackTrace();
    }
}

public static void run() throws Exception {

    QueueClient sbClient = new QueueClient(new ConnectionStringBuilder(ConnectionString, QueueName),
            ReceiveMode.PEEKLOCK);
    registerReceiver(sbClient);
    sendMessagesAsync(sbClient);

    Thread.sleep(1000*60*100);
    sbClient.close();
}

static CompletableFuture<Void> sendMessagesAsync(QueueClient sendClient) {
    List<CompletableFuture> tasks = new ArrayList<CompletableFuture>();
    for (int i = 0; i < SendTimes; i++) {
        final String messageId = Integer.toString(i);
        Message message = new Message(repeat('@', DataLen));
        message.setContentType("string");
        message.setLabel("test");
        message.setMessageId(messageId);
        message.setTimeToLive(Duration.ofDays(7));
        System.out.printf("\nMessage sending: Id = %s", message.getMessageId());
        tasks.add(sendClient.sendAsync(message));
    }
    return CompletableFuture.allOf(tasks.toArray(new CompletableFuture<?>[tasks.size()]));
}

static void registerReceiver(QueueClient queueClient) throws Exception {
    queueClient.registerMessageHandler(new IMessageHandler() {
        public CompletableFuture<Void> onMessageAsync(IMessage message) {
            System.out.printf("\nReceive message: " + message.toString());
            return CompletableFuture.completedFuture(null);
        }

        public void notifyException(Throwable throwable, ExceptionPhase exceptionPhase) {
            System.out.printf(exceptionPhase + "-" + throwable.getMessage());
        }
    }, new MessageHandlerOptions(10, true, Duration.ofDays(7)), Executors.newFixedThreadPool(10));
}

public static String repeat(char what, int howmany) {
    char[] chars = new char[howmany];
    Arrays.fill(chars, what);
    return new String(chars);
}

}

[yuhaii]

Hello Team,

Do you have any update on this?

Thank you!

[yuhaii]

We can steady reproduce this issue now. I am confirming with our customer to see whether we can provide their testing code to you.

I use my queue to try to reproduce this issue. I send the long messages ( see message content in attached file ) with “service bus explorer”. I can steady reproduce this issue with my service bus.

This is the call stack I find out:

2018-11-09 20:00:41 WARN c.m.a.s.p.MessagingFactory:577 - UnHandled exception while processing events in reactor: org.apache.qpid.proton.engine.HandlerException: org.apache.qpid.proton.engine.TransportException: bytes left unconsumed at org.apache.qpid.proton.engine.impl.EventImpl.dispatch(EventImpl.java:112) at org.apache.qpid.proton.reactor.impl.ReactorImpl.dispatch(ReactorImpl.java:324) at org.apache.qpid.proton.reactor.impl.ReactorImpl.process(ReactorImpl.java:292) at com.microsoft.azure.servicebus.primitives.MessagingFactory$RunReactor.run(MessagingFactory.java:564) at java.lang.Thread.run(Unknown Source) Caused by: org.apache.qpid.proton.engine.TransportException: bytes left unconsumed at org.apache.qpid.proton.engine.impl.ssl.SimpleSslTransportWrapper.unwrapInput(SimpleSslTransportWrapper.java:142) at org.apache.qpid.proton.engine.impl.ssl.SimpleSslTransportWrapper.process(SimpleSslTransportWrapper.java:361) at org.apache.qpid.proton.engine.impl.ssl.SslImpl$UnsecureClientAwareTransportWrapper.process(SslImpl.java:144) at org.apache.qpid.proton.engine.impl.TransportImpl.process(TransportImpl.java:1513) at org.apache.qpid.proton.reactor.impl.IOHandler$1.run(IOHandler.java:233) at org.apache.qpid.proton.reactor.impl.SelectableImpl.readable(SelectableImpl.java:118) at org.apache.qpid.proton.reactor.impl.IOHandler.handleQuiesced(IOHandler.java:60) at org.apache.qpid.proton.reactor.impl.IOHandler.onUnhandled(IOHandler.java:389) at org.apache.qpid.proton.engine.BaseHandler.onReactorQuiesced(BaseHandler.java:87) at org.apache.qpid.proton.engine.BaseHandler.handle(BaseHandler.java:206) at org.apache.qpid.proton.engine.impl.EventImpl.dispatch(EventImpl.java:108) ... 4 common frames omitted

We can see that the exception throw from org.apache.qpid SDK.

Then the exception capture by our service bus SDK:

I think this issue have relation with SSL unwrap the messages and find the mismatch of stream and flag ( capacity? ).

I changed to “2.0.0-PREVIEW-5” version and this “bytes left unconsumed” issue do not reproduce.

[yuhaii]

This is the code to reproduce this “bytes left unconsumed” issue : ServiceBusTest--myConStr.zip

There are message in my SB queue. You can use it to reproduce this issue. Just import this Marven project and run as debug and you will see this issue.

@yvgopal , are you convenient to take a look at this issue? thanks in advance!

[yvgopal]

Let me investigate and get back to you by the end of this week. Until then, continue using PREVIEW-5.

[yuhaii]

Got it. thank you very much!

[yuhaii]

Good day. @yvgopal . Do you have any update on this issue? Thanks!