Search code examples
spring-cloud-streamsolace

Sink only application gets stopped - Channel Closed (smfclient 2) no error


We are developing a prototype using spring cloud stream solace binders. When my application defines a source and sink and publishes a message regularly and sink prints the message in uppercase - everything works as expected. But when we try to run application with only sink configuration the application stops after connecting successfully to broker. Logs are provided below.

spring:
  cloud:
    stream:
     bindings:
        fjp-greetings-in:
          destination: <TOPIC_NAME_HERE>
          group: <QUEUE_NAME_HERE>
solace:
  java:
    host: tcp://<HOST_NAME_HERE>:<PORT_HERE>
    msgVpn: <VPN_NAME_HERE>
    clientUsername: <USERNAME_HERE>
    clientPassword: <PWD_HERE>
    connectRetries: -1
    reconnectRetries: -1

public interface GreetingsStreams {
    String INPUT = "greetings-in";
    @Input(INPUT)
    SubscribableChannel inboundGreetings();

@SpringBootApplication
@EnableBinding(GreetingsStreams.class)
@Slf4j
public class PocSpringcloudstreamApplication {

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

    @StreamListener(GreetingsStreams.INPUT)
    public void handle(String msg) {
        log.info("Received Message: " + msg.toUpperCase());
    }

Below are the logs from the console when trying to run the application from spring boot dashboard in STS-

2019-08-23 12:11:24.906 DEBUG 8956 --- [1_ReactorThread] c.s.jcsmp.impl.flow.FlowHandleImpl       : Flow 76: Starting sub ad timer: scheduled new timer in 1000
2019-08-23 12:11:24.920 DEBUG 8956 --- [1_ReactorThread] c.s.jcsmp.impl.flow.FlowHandleImpl       : Flow 76: Enqueue to delivery: msg=1, dest=<TOPIC_NAME_HERE>
2019-08-23 12:11:24.928 DEBUG 8956 --- [1_ReactorThread] c.s.jcsmp.impl.ReconnectFreqManager      : Timer expiry: checking reconnect counter.
2019-08-23 12:11:24.928 DEBUG 8956 --- [1_ReactorThread] c.s.jcsmp.impl.ReconnectFreqManager      : Reconnect frequency OK: count=1
2019-08-23 12:11:24.929 DEBUG 8956 --- [1_ReactorThread] c.s.j.impl.client.ClientRequestResponse  : Stopping request timer (SMP-SmpRequest)
2019-08-23 12:11:24.929 DEBUG 8956 --- [           main] c.s.j.protocol.impl.TcpClientChannel     : Error Response (400) - Subscription Already Exists - Queue '<QUEUE_NAME_HERE>' - Topic '<TOPIC_NAME_HERE>'
2019-08-23 12:11:24.930  WARN 8956 --- [           main] c.s.s.c.s.b.p.SolaceQueueProvisioner     : Queue <QUEUE_NAME_HERE> is already subscribed to topic <TOPIC_NAME_HERE>, SUBSCRIPTION_ALREADY_PRESENT error will be ignored...
2019-08-23 12:11:24.930  INFO 8956 --- [           main] c.s.s.c.s.b.i.JCSMPInboundChannelAdapter : started com.solace.spring.cloud.stream.binder.inbound.JCSMPInboundChannelAdapter@746b18fd
2019-08-23 12:11:24.958  INFO 8956 --- [           main] f.p.s.PocSpringcloudstreamApplication : Started PocSpringcloudstreamApplication in 37.017 seconds (JVM running for 40.443)
2019-08-23 12:11:24.966 DEBUG 8956 --- [       Thread-6] c.s.jcsmp.impl.flow.SubFlowManagerImpl   : SubFlowManagerImpl closing... close 1 flows
2019-08-23 12:11:24.967 DEBUG 8956 --- [       Thread-6] c.s.jcsmp.impl.flow.FlowHandleImpl       : Flow 76: pauseFlowInternally=false
2019-08-23 12:11:24.967 DEBUG 8956 --- [       Thread-6] c.s.jcsmp.impl.flow.FlowHandleImpl       : Flow 76: _startState=STOPPED
2019-08-23 12:11:24.967 DEBUG 8956 --- [       Thread-6] c.s.jcsmp.impl.flow.FlowHandleImpl       : Flow 76: Clear AD timer
2019-08-23 12:11:24.985 DEBUG 8956 --- [       Thread-6] c.s.jcsmp.impl.flow.FlowHandleImpl       : Flow 76: Clear AD timer
2019-08-23 12:11:24.985 DEBUG 8956 --- [       Thread-6] c.s.jcsmp.impl.flow.FlowHandleImpl       : Flow 76: window size 0 due to startState=STOPPED
2019-08-23 12:11:24.985 DEBUG 8956 --- [       Thread-6] c.s.jcsmp.impl.flow.FlowHandleImpl       : Flow 76: getWindowSize()=0
2019-08-23 12:11:24.985 DEBUG 8956 --- [       Thread-6] c.s.jcsmp.impl.flow.FlowSmfUtil          : tpCreateAck: flow_d: 76, TpMsgId: 1, windowSz: 0
2019-08-23 12:11:24.985 DEBUG 8956 --- [       Thread-6] c.s.jcsmp.impl.flow.FlowHandleImpl       : tpCreateAck: flow_d: 76, tt_lastInOrderTpMsg: 1, tt_windowSz: 0
2019-08-23 12:11:24.985 DEBUG 8956 --- [       Thread-6] c.s.j.impl.queues.UnackedMessageList2    : UNACKLIST-ack>>> reason=flow-closing flow=76
2019-08-23 12:11:24.985 DEBUG 8956 --- [       Thread-6] c.s.j.protocol.impl.TcpClientChannel     : Client channel (smfclient 2) stopping KA timer
2019-08-23 12:11:24.985 DEBUG 8956 --- [       Thread-6] c.s.jcsmp.protocol.impl.TcpChannel       : Canceled KA timer
2019-08-23 12:11:24.986  INFO 8956 --- [       Thread-6] c.s.j.protocol.impl.TcpClientChannel     : Channel Closed (smfclient 2)
2019-08-23 12:11:24.986 DEBUG 8956 --- [       Thread-6] c.s.jcsmp.protocol.smf.SimpleSmfClient   : Local addr: xxxx   Remote addr: xxxx(smfclient 2) Closing socket
2019-08-23 12:11:24.987 DEBUG 8956 --- [       Thread-6] c.s.jcsmp.impl.JCSMPBasicSession         : JCSMPSession[xxxx@tcp://xxxx] (0001)closed
2019-08-23 12:11:24.988  INFO 8956 --- [       Thread-6] c.s.s.c.s.b.i.JCSMPInboundChannelAdapter : Stopping consumer flow from queue <QUEUE_NAME_HERE> <inbound adapter ID: 8def919b-8367-4922-8451-34e0865c5d0c>
2019-08-23 12:11:24.989 DEBUG 8956 --- [       Thread-6] c.s.jcsmp.impl.JCSMPBasicSession         : waiting for session reconnect done, sessionID= JCSMPSession[xxxx@xxxx:xxxx] (0001), called from close
2019-08-23 12:11:24.989  INFO 8956 --- [       Thread-6] c.s.s.c.s.b.i.JCSMPInboundChannelAdapter : stopped com.solace.spring.cloud.stream.binder.inbound.JCSMPInboundChannelAdapter@746b18fd
2019-08-23 12:11:24.989  INFO 8956 --- [       Thread-6] o.s.c.stream.binder.BinderErrorChannel   : Channel 'application.<QUEUE_NAME_HERE>.errors' has 1 subscriber(s).
2019-08-23 12:11:24.989  INFO 8956 --- [       Thread-6] o.s.c.stream.binder.BinderErrorChannel   : Channel 'application.<QUEUE_NAME_HERE>.errors' has 0 subscriber(s).
2019-08-23 12:11:24.990  INFO 8956 --- [       Thread-6] o.s.i.endpoint.EventDrivenConsumer       : Removing {logging-channel-adapter:_org.springframework.integration.errorLogger} as a subscriber to the 'errorChannel' channel
2019-08-23 12:11:24.990  INFO 8956 --- [       Thread-6] o.s.i.channel.PublishSubscribeChannel    : Channel 'application.errorChannel' has 0 subscriber(s).
2019-08-23 12:11:24.990  INFO 8956 --- [       Thread-6] o.s.i.endpoint.EventDrivenConsumer       : stopped _org.springframework.integration.errorLogger
2019-08-23 12:11:24.991  INFO 8956 --- [       Thread-6] o.s.s.c.ThreadPoolTaskScheduler          : Shutting down ExecutorService 'taskScheduler'
2019-08-23 12:11:24.999  INFO 8956 --- [       Thread-6] o.s.i.monitor.IntegrationMBeanExporter   : Summary on shutdown: <QUEUE_NAME_HERE>.errors
2019-08-23 12:11:24.999  INFO 8956 --- [       Thread-6] o.s.i.monitor.IntegrationMBeanExporter   : Summary on shutdown: greetings-in
2019-08-23 12:11:24.999  INFO 8956 --- [       Thread-6] o.s.i.monitor.IntegrationMBeanExporter   : Summary on shutdown: nullChannel
2019-08-23 12:11:24.999  INFO 8956 --- [       Thread-6] o.s.i.monitor.IntegrationMBeanExporter   : Summary on shutdown: errorChannel
2019-08-23 12:11:24.999  INFO 8956 --- [       Thread-6] o.s.i.monitor.IntegrationMBeanExporter   : Summary on shutdown: _org.springframework.integration.errorLogger.handler


Solution

  • Can you try to add the spring-boot-starter-web dependency to your pom and see if that fixes your issue?

    <dependency>
       <groupId>org.springframework.boot</groupId>
       <artifactId>spring-boot-starter-web</artifactId>
    </dependency>