Azure / azure-sdk-for-java

This repository is for active development of the Azure SDK for Java. For consumers of the SDK we recommend visiting our public developer docs at https://docs.microsoft.com/java/azure/ or our versioned developer docs at https://azure.github.io/azure-sdk-for-java.
MIT License
2.31k stars 1.97k forks source link

[BUG] Connection stays open after message sendage #34570

Closed khauser closed 1 year ago

khauser commented 1 year ago

Describe the bug After I send a message the application stays open apx. 15 min and closes itself with the added exception. The message was send successful early in the beginning of these 15 min.

Exception or Stack Trace

2023-04-19 09:29:48.835  INFO 8 --- [windows.net:-1]] org.apache.qpid.jms.JmsConnection        : Connection ID:4240fa83-9b92-4962-9b4b-b7c6fb7ac2ef:1 connected to server: amqps://<our servicebus>.servicebus.windows.net
2023-04-19 09:39:48.944  INFO 8 --- [-b7c6fb7ac2ef:1] org.apache.qpid.jms.JmsSession           : A JMS MessageProducer has been closed: JmsProducerInfo { ID:4240fa83-9b92-4962-9b4b-b7c6fb7ac2ef:1:1:1, destination = <our queue> }
2023-04-19 09:44:48.849  INFO 8 --- [-b7c6fb7ac2ef:1] o.s.j.c.CachingConnectionFactory         : Encountered a JMSException - resetting the underlying JMS Connection

org.apache.qpid.jms.JmsConnectionRemotelyClosedException: The connection was inactive for more than the allowed 300000 milliseconds and is closed by container 'LinkTracker'. TrackingId:e73821d2ebc44946b2a99784d7436a9b_G7, SystemTracker:gateway7, Timestamp:2023-04-19T09:44:48 [condition = amqp:connection:forced]
    at org.apache.qpid.jms.provider.exceptions.ProviderConnectionRemotelyClosedException.toJMSException(ProviderConnectionRemotelyClosedException.java:37) ~[qpid-jms-client-0.53.0.jar!/:na]
    at org.apache.qpid.jms.exceptions.JmsExceptionSupport.create(JmsExceptionSupport.java:80) ~[qpid-jms-client-0.53.0.jar!/:na]
    at org.apache.qpid.jms.exceptions.JmsExceptionSupport.create(JmsExceptionSupport.java:112) ~[qpid-jms-client-0.53.0.jar!/:na]
    at org.apache.qpid.jms.JmsConnection.onAsyncException(JmsConnection.java:1546) ~[qpid-jms-client-0.53.0.jar!/:na]
    at org.apache.qpid.jms.JmsConnection.onProviderException(JmsConnection.java:1530) ~[qpid-jms-client-0.53.0.jar!/:na]
    at org.apache.qpid.jms.JmsConnection.onConnectionFailure(JmsConnection.java:1374) ~[qpid-jms-client-0.53.0.jar!/:na]
    at org.apache.qpid.jms.provider.amqp.AmqpProvider.fireProviderException(AmqpProvider.java:1150) ~[qpid-jms-client-0.53.0.jar!/:na]
    at org.apache.qpid.jms.provider.amqp.AmqpAbstractResource.closeResource(AmqpAbstractResource.java:185) ~[qpid-jms-client-0.53.0.jar!/:na]
    at org.apache.qpid.jms.provider.amqp.AmqpConnection.processRemoteClose(AmqpConnection.java:151) ~[qpid-jms-client-0.53.0.jar!/:na]
    at org.apache.qpid.jms.provider.amqp.AmqpProvider.processUpdates(AmqpProvider.java:961) ~[qpid-jms-client-0.53.0.jar!/:na]
    at org.apache.qpid.jms.provider.amqp.AmqpProvider.onData(AmqpProvider.java:871) ~[qpid-jms-client-0.53.0.jar!/:na]
    at org.apache.qpid.jms.transports.netty.NettyTcpTransport$NettyTcpTransportHandler.channelRead0(NettyTcpTransport.java:563) ~[qpid-jms-client-0.53.0.jar!/:na]
    at org.apache.qpid.jms.transports.netty.NettyTcpTransport$NettyTcpTransportHandler.channelRead0(NettyTcpTransport.java:556) ~[qpid-jms-client-0.53.0.jar!/:na]
    at io.netty.channel.SimpleChannelInboundHandler.channelRead(SimpleChannelInboundHandler.java:99) ~[netty-transport-4.1.87.Final.jar!/:4.1.87.Final]
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444) ~[netty-transport-4.1.87.Final.jar!/:4.1.87.Final]
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) ~[netty-transport-4.1.87.Final.jar!/:4.1.87.Final]
    at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412) ~[netty-transport-4.1.87.Final.jar!/:4.1.87.Final]
    at io.netty.handler.ssl.SslHandler.unwrap(SslHandler.java:1373) ~[netty-handler-4.1.87.Final.jar!/:4.1.87.Final]
    at io.netty.handler.ssl.SslHandler.decodeJdkCompatible(SslHandler.java:1236) ~[netty-handler-4.1.87.Final.jar!/:4.1.87.Final]
    at io.netty.handler.ssl.SslHandler.decode(SslHandler.java:1285) ~[netty-handler-4.1.87.Final.jar!/:4.1.87.Final]
    at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:529) ~[netty-codec-4.1.87.Final.jar!/:4.1.87.Final]
    at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:468) ~[netty-codec-4.1.87.Final.jar!/:4.1.87.Final]
    at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:290) ~[netty-codec-4.1.87.Final.jar!/:4.1.87.Final]
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444) ~[netty-transport-4.1.87.Final.jar!/:4.1.87.Final]
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) ~[netty-transport-4.1.87.Final.jar!/:4.1.87.Final]
    at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412) ~[netty-transport-4.1.87.Final.jar!/:4.1.87.Final]
    at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410) ~[netty-transport-4.1.87.Final.jar!/:4.1.87.Final]
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:440) ~[netty-transport-4.1.87.Final.jar!/:4.1.87.Final]
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) ~[netty-transport-4.1.87.Final.jar!/:4.1.87.Final]
    at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919) ~[netty-transport-4.1.87.Final.jar!/:4.1.87.Final]
    at io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:800) ~[netty-transport-classes-epoll-4.1.87.Final.jar!/:4.1.87.Final]
    at io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:499) ~[netty-transport-classes-epoll-4.1.87.Final.jar!/:4.1.87.Final]
    at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:397) ~[netty-transport-classes-epoll-4.1.87.Final.jar!/:4.1.87.Final]
    at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997) ~[netty-common-4.1.87.Final.jar!/:4.1.87.Final]

To Reproduce Spring Boot application

plugins {
    id 'org.springframework.boot' version '2.7.8'
    id 'io.spring.dependency-management' version '1.0.11.RELEASE'
...
ext {
    set('azureVersion', '4.4.1')
}
dependencies {
  implementation group: 'com.azure.spring', name: 'spring-cloud-azure-starter-servicebus-jms', version: "${azureVersion}"

Code Snippet

    @Autowired
    private JmsTemplate jmsTemplate;

    @Autowired
    private GZIPCompressor gzipCompressor;

    public void send(String queueName, String content)
    {
        jmsTemplate.convertAndSend(queueName, gzipCompressor.compress(content.getBytes()));
    }

Expected behavior The application shall send the message and close itself smoothly.

Setup (please complete the following information):

moarychan commented 1 year ago

Closing it due to the repeat issue https://github.com/Azure/azure-sdk-for-java/issues/31966

khauser commented 1 year ago

@moarychan: I also saw the other issue but the stacktrace is almost completely different. Please reopen

moarychan commented 1 year ago

@khauser , thanks for your update, please provide if anything missing. We appreciate your input and will review this matter as soon as possible. We'll keep you updated on the progress of our review.

khauser commented 1 year ago

Hi there,

are there any news to this problem? Our ADO pipelines last 15 min longer due to this issue...

Regards, Karsten

Netyyyy commented 1 year ago

Hi @khauser , could you help provide a minimal application about this problem, thanks.

khauser commented 1 year ago

While making the showcase project I noticed that the problem sits in front of the computer...

By using Springs ApplicationRunner for sending just a message I missed to exit/close the Spring Boot Application.

@ConditionalOnProperty(prefix = "job.autorun", name = "enabled", havingValue = "true", matchIfMissing = true)
@Slf4j
@Component
@Order(1)
class MessengerApplicationRunner implements ApplicationRunner
{
    @Autowired
    private MessageSender testplanMessageSender;

    @Autowired
    private ApplicationContext appContext;

    @Override
    public void run(ApplicationArguments args) throws Exception
    {
        log.info("ApplicationRunner#run()");

        messageSender.sendmMessage("testqueue", "Hello, World");

        SpringApplication.exit(appContext, () -> 0);
    }
}

With this exit now the application is closed as expected after message sendage.

Big sorry for the inconvenience!