1

I am having trouble starting my JmsListener while the application is running. I tried this answer on the topic, but no luck.

I have autoStartup set to false in my JmsListenerContainerFactory, and I have messages waiting on the queue. But when I call the controller in the code below, nothing happens. The JmsLister does not start to consume messages.

Any help would be appreciated.

Controller code:

@RestController
public class MessageController {

    private final JmsListenerEndpointRegistry jmsListenerEndpointRegistry;

    public MessageController(JmsListenerEndpointRegistry jmsListenerEndpointRegistry) {
        this.jmsListenerEndpointRegistry = jmsListenerEndpointRegistry;
    }

    @GetMapping("messages/start")
    public ResponseEntity start() {
        if(jmsListenerEndpointRegistry.isRunning())
            return ResponseEntity.badRequest().build(); // second time I request this endpoint it says it is running

        jmsListenerEndpointRegistry.getListenerContainerIds().forEach(id -> {
            MessageListenerContainer listenerContainer = jmsListenerEndpointRegistry.getListenerContainer(id);
            if (listenerContainer != null) {
                listenerContainer.start();
            }
        });
        jmsListenerEndpointRegistry.start();
        return ResponseEntity.ok().build();
    }
}

Edit: this is the debug log from when I send the request to the controller:

19:59:41.231 [http-nio-8080-exec-2] DEBUG o.s.web.servlet.DispatcherServlet - GET "/messages/start", parameters={}
19:59:41.238 [http-nio-8080-exec-2] DEBUG o.s.w.s.m.m.a.RequestMappingHandlerMapping - Mapped to MessageController#start()
19:59:53.764 [http-nio-8080-exec-2] DEBUG o.a.a.transport.WireFormatNegotiator - Sending: WireFormatInfo { version=12, properties={StackTraceEnabled=true, PlatformDetails=Java, CacheEnabled=true, Host=mqserver, TcpNoDelayEnabled=true, SizePrefixDisabled=false, CacheSize=1024, ProviderName=ActiveMQ, TightEncodingEnabled=true, MaxFrameSize=9223372036854775807, MaxInactivityDuration=30000, MaxInactivityDurationInitalDelay=10000, ProviderVersion=5.15.11}, magic=[A,c,t,i,v,e,M,Q]}
19:59:53.773 [ActiveMQ Transport: tcp://mqserver/127.0.0.1:49040@48600] DEBUG o.a.a.transport.InactivityMonitor - Using min of local: WireFormatInfo { version=12, properties={StackTraceEnabled=true, PlatformDetails=Java, CacheEnabled=true, Host=mqserver, TcpNoDelayEnabled=true, SizePrefixDisabled=false, CacheSize=1024, ProviderName=ActiveMQ, TightEncodingEnabled=true, MaxFrameSize=9223372036854775807, MaxInactivityDuration=30000, MaxInactivityDurationInitalDelay=10000, ProviderVersion=5.15.11}, magic=[A,c,t,i,v,e,M,Q]} and remote: WireFormatInfo { version=9, properties={CacheSize=1024, SizePrefixDisabled=false, TcpNoDelayEnabled=true, StackTraceEnabled=true, CacheEnabled=true, MaxFrameSize=9223372036854775807, TightEncodingEnabled=true, MaxInactivityDuration=30000, MaxInactivityDurationInitalDelay=10000}, magic=[A,c,t,i,v,e,M,Q]}
19:59:53.774 [ActiveMQ Transport: tcp://mqserver/127.0.0.1:49040@48600] DEBUG o.a.a.transport.WireFormatNegotiator - Received WireFormat: WireFormatInfo { version=9, properties={CacheSize=1024, SizePrefixDisabled=false, TcpNoDelayEnabled=true, StackTraceEnabled=true, CacheEnabled=true, MaxFrameSize=9223372036854775807, TightEncodingEnabled=true, MaxInactivityDuration=30000, MaxInactivityDurationInitalDelay=10000}, magic=[A,c,t,i,v,e,M,Q]}
19:59:53.774 [ActiveMQ Transport: tcp://mqserver/127.0.0.1:49040@48600] DEBUG o.a.a.transport.WireFormatNegotiator - tcp://mqserver/127.0.0.1:49040@48600 before negotiation: OpenWireFormat{version=12, cacheEnabled=false, stackTraceEnabled=false, tightEncodingEnabled=false, sizePrefixDisabled=false, maxFrameSize=9223372036854775807}
19:59:53.790 [ActiveMQ Transport: tcp://mqserver/127.0.0.1:49040@48600] DEBUG o.a.a.transport.WireFormatNegotiator - tcp://mqserver/127.0.0.1:49040@48600 after negotiation: OpenWireFormat{version=9, cacheEnabled=true, stackTraceEnabled=true, tightEncodingEnabled=true, sizePrefixDisabled=false, maxFrameSize=9223372036854775807}
19:59:53.895 [http-nio-8080-exec-2] DEBUG o.s.j.l.DefaultMessageListenerContainer - Established shared JMS Connection
19:59:53.896 [http-nio-8080-exec-2] DEBUG o.s.j.l.DefaultMessageListenerContainer - Resumed paused task: org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker@4fc72d52
20:00:00.326 [DefaultMessageListenerContainer-1] DEBUG o.a.a.thread.TaskRunnerFactory - Initialized TaskRunnerFactory[ActiveMQ Session Task] using ExecutorService: java.util.concurrent.ThreadPoolExecutor@4364b2e9[Running, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 0]

Edit: I was testing against the wrong ActiveMq instance, but the accepted answer helped me test and debug the "error" in an easy and effective way

thomas77
  • 1,100
  • 13
  • 27

1 Answers1

2

Strange; this works fine for me...

@SpringBootApplication
public class So60762328Application {

    public static void main(String[] args) {
        SpringApplication.run(So60762328Application.class, args);
    }

    @JmsListener(destination = "foo")
    public void listen(String in) {
        System.out.println(in);
    }

    @Bean
    public ApplicationRunner runner(JmsTemplate template, DefaultJmsListenerContainerFactory factory,
            JmsListenerEndpointRegistry registry) {

        factory.setAutoStartup(false);
        return args -> {
            template.convertAndSend("foo", "bar");
            System.out.println("Hit Enter to start container(s)");
            System.in.read();
            registry.getListenerContainers().forEach(container -> container.start());
        };
    }

}

and

Hit Enter to start container(s)

2020-03-19 15:18:47.046 DEBUG 46151 --- [           main] o.s.j.l.DefaultMessageListenerContainer  : Established shared JMS Connection
2020-03-19 15:18:47.046 DEBUG 46151 --- [           main] o.s.j.l.DefaultMessageListenerContainer  : Resumed paused task: org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker@189aa67a
2020-03-19 15:18:47.047 DEBUG 46151 --- [enerContainer-1] o.s.j.c.CachingConnectionFactory         : Registering cached JMS Session for mode 0: ActiveMQSession {id=ID:Gollum2.local-53059-1584645521078-4:1:2,started=true} java.lang.Object@5f2fc1ae
2020-03-19 15:18:47.057 DEBUG 46151 --- [enerContainer-1] o.s.j.l.DefaultMessageListenerContainer  : Received message of type [class org.apache.activemq.command.ActiveMQTextMessage] from consumer [ActiveMQMessageConsumer { value=ID:Gollum2.local-53059-1584645521078-4:1:2:1, started=true }] of session [Cached JMS Session: ActiveMQSession {id=ID:Gollum2.local-53059-1584645521078-4:1:2,started=true} java.lang.Object@5f2fc1ae]
2020-03-19 15:18:47.058 DEBUG 46151 --- [enerContainer-1] .s.j.l.a.MessagingMessageListenerAdapter : Processing [org.springframework.jms.listener.adapter.AbstractAdaptableMessageListener$MessagingMessageConverterAdapter$LazyResolutionMessage@564c24f3]
bar

You seem to be missing Registering cached JMS Session for mode 0:.

Try bumping the log level up to TRACE.

Gary Russell
  • 166,535
  • 14
  • 146
  • 179
  • Maybe take a thread dump to see what the `[DefaultMessageListenerContainer-1]` thread is doing (or if it's missing). – Gary Russell Mar 19 '20 at 19:54
  • One possibility is the container's `TaskExecutor` has no available threads. That won't happen with the default executor. – Gary Russell Mar 19 '20 at 20:02
  • Omg, I have activemq-instances for different environments, but the only difference between them are port number and have been testing on the wrong instance :/. But I accept your answer because of the ingenious test-application you provided me. It really, really helped me in debugging! – thomas77 Mar 20 '20 at 06:24