Skip to content

TcpNioClientConnectionFactory.stop() logs "Selector closed" at ERROR on every normal stop due to selector-close/active-flag ordering #11269

Description

@rburaksaritas

In what version(s) of Spring Integration are you seeing this issue?

spring-integration-ip 6.4.4

Also confirmed still present, unchanged, on the main branch as of 2026-08-13:
https://github.com/spring-projects/spring-integration/blob/main/spring-integration-ip/src/main/java/org/springframework/integration/ip/tcp/connection/TcpNioClientConnectionFactory.java

Affected file (same path in both the 6.4.4 tag and main):
spring-integration-ip/src/main/java/org/springframework/integration/ip/tcp/connection/TcpNioClientConnectionFactory.java


Describe the bug

TcpNioClientConnectionFactory.stop() closes the NIO selector before calling super.stop(), which is what actually flips the active flag to false:

// TcpNioClientConnectionFactory
@Override
public void stop() {
    Selector selectorToClose = this.selector;
    if (selectorToClose != null) {
        try {
            selectorToClose.close();     // (1) wakes the blocked selector thread almost immediately
        }
        catch (Exception ex) {
            logger.error(ex, "Error closing selector");
        }
    }
    super.stop();                        // (2) AbstractConnectionFactory.stop() sets `this.active = false;` — but only here
}
// AbstractConnectionFactory
@Override
public void stop() {
    this.active = false;   // only set here, i.e. after the selector is already closed by the subclass override above
    ...
}

The factory's own background thread is blocked in Selector.select() inside run():

@Override
public void run() {
    try {
        this.selector = Selector.open();
        while (isActive()) {
            processSelectorWhileActive();
        }
    }
    catch (ClosedSelectorException cse) {
        if (isActive()) {                // (3) checked here
            logger.error(cse, "Selector closed");
        }
    }
    ...
}

Because step (1) unblocks the background thread almost instantly, it typically reaches check (3) before the calling thread finishes step (2). At that point isActive() is still true (it hasn't been set to false yet), so the factory logs ClosedSelectorException at ERROR — even though this is a completely normal, intentional stop() call (e.g. during graceful application shutdown, or a client-side failover that calls stop()/start() to switch servers).

In practice this means every normal shutdown of a TcpNioClientConnectionFactory-based client logs a spurious ERROR, which is noisy in production logs/alerting and gets mistaken for a real problem.

Suggested fix

Set the active flag to false before closing the selector, e.g.:

@Override
public void stop() {
    setActive(false);           // flip first
    Selector selectorToClose = this.selector;
    if (selectorToClose != null) {
        try {
            selectorToClose.close();
        }
        catch (Exception ex) {
            logger.error(ex, "Error closing selector");
        }
    }
    super.stop();                // still fine to call; setting active=false again is idempotent
}

This preserves the "log ERROR if the selector closes unexpectedly while still active" behavior for genuine failures, while eliminating the false positive on intentional stops.

We've applied exactly this as a downstream workaround (a thin subclass overriding stop()) and confirmed with live-socket integration tests cycling stop()/start() that the ERROR log no longer appears.


To Reproduce

  1. Create and start a TcpNioClientConnectionFactory (or a TcpReceivingChannelAdapter/TcpSendingMessageHandler built on one) connected to any TCP endpoint.
  2. Call factory.stop() from application code, or let it happen as part of normal Spring context shutdown (ContextClosedEventSmartLifecycle auto-stop).
  3. Observe the factory's logger emit, at ERROR level, on effectively every stop (not intermittently):
    ERROR ... o.s.i.i.t.c.TcpNioClientConnectionFactory - Selector closed
    java.nio.channels.ClosedSelectorException: null
        at java.base/sun.nio.ch.SelectorImpl.ensureOpen(...)
        at java.base/sun.nio.ch.SelectorImpl.lockAndDoSelect(...)
        at java.base/sun.nio.ch.SelectorImpl.select(...)
        at org.springframework.integration.ip.tcp.connection.TcpNioClientConnectionFactory.processSelectorWhileActive(TcpNioClientConnectionFactory.java:...)
    

Expected behavior

A normal, intentional stop() call should not produce an ERROR-level log. The isActive() guard in run()'s catch block exists specifically to distinguish "stopped on purpose" from "selector closed unexpectedly" — but it can't do its job because the flag isn't flipped to false until after the resource that races it is already closed.


Sample

No public minimal-reproduction repository yet — happy to put one together if useful. The bug is fully self-contained and doesn't need a real remote server: any test that does factory.start(); ...; factory.stop(); on a TcpNioClientConnectionFactory pointed at a listening socket reproduces the ERROR log on stop.

Below is a self-contained JUnit 5 test that demonstrates it directly against the stock TcpNioClientConnectionFactory (only spring-integration-ip, logback-classic and junit-jupiter on the classpath — no Spring context needed). It registers one real connection so super.stop()'s connection-cleanup loop does actual work, which is what gives the background selector thread a realistic chance to lose the race; without a registered connection the race is much harder to hit locally. Retries a bounded number of times since this is a genuine OS-scheduling race, not deterministic on every single call — in our runs it reliably reproduces within the first few attempts (e.g. attempt 2/30):

class TcpNioClientConnectionFactorySelectorClosedBugTest {

    private static final String SELECTOR_CLOSED_MESSAGE = "Selector closed";
    private static final int MAX_ATTEMPTS = 30;
    private static final long POST_STOP_WAIT_MILLIS = 80;

    @Test
    void stop_logs_selector_closed_error_even_on_a_normal_stop() throws Exception {
        for (int attempt = 1; attempt <= MAX_ATTEMPTS; attempt++) {
            if (stopOnceAndCheckForSelectorClosedError()) {
                System.out.println("Reproduced 'Selector closed' ERROR on attempt " + attempt + "/" + MAX_ATTEMPTS);
                return;
            }
        }
        fail("Expected '" + SELECTOR_CLOSED_MESSAGE + "' ERROR to be logged at least once in "
                + MAX_ATTEMPTS + " attempts");
    }

    private boolean stopOnceAndCheckForSelectorClosedError() throws Exception {
        try (ServerSocket serverSocket = new ServerSocket(0)) {
            serverSocket.setReuseAddress(true);
            ExecutorService taskExecutor = Executors.newCachedThreadPool();
            try {
                TcpNioClientConnectionFactory factory =
                        new TcpNioClientConnectionFactory("localhost", serverSocket.getLocalPort());
                factory.setTaskExecutor(taskExecutor);
                factory.setApplicationEventPublisher(event -> { });

                Logger factoryLogger = (Logger) LoggerFactory.getLogger(factory.getClass());
                factoryLogger.setLevel(Level.ALL);
                ListAppender<ILoggingEvent> logAppender = new ListAppender<>();
                logAppender.start();
                factoryLogger.addAppender(logAppender);
                try {
                    factory.start();
                    // wait for the background selector thread to actually be blocked in select()
                    Thread.sleep(200);
                    // register a real connection so super.stop()'s connection-closing loop does
                    // actual work, giving the background thread a realistic chance to loop back
                    // into select() before the calling thread flips the active flag
                    factory.getConnection();

                    factory.stop();
                    Thread.sleep(POST_STOP_WAIT_MILLIS);

                    return logAppender.list.stream().anyMatch(event ->
                            event.getLevel() == Level.ERROR
                                    && SELECTOR_CLOSED_MESSAGE.equals(event.getFormattedMessage()));
                } finally {
                    factoryLogger.detachAppender(logAppender);
                }
            } finally {
                taskExecutor.shutdownNow();
            }
        }
    }
}

We also have the downstream workaround itself, and a second test proving it eliminates the ERROR across the same number of attempts.

The fix — a thin subclass that flips active to false before closing the selector:

/**
 * Upstream TcpNioClientConnectionFactory.stop() closes the NIO selector before marking the
 * factory inactive, so the selector's own background thread can observe isActive() == true
 * when its blocked select() wakes with a ClosedSelectorException, causing it to log
 * "Selector closed" at ERROR on every normal stop. Flipping the flag first removes that window.
 */
class RaceSafeTcpNioClientConnectionFactory extends TcpNioClientConnectionFactory {

    RaceSafeTcpNioClientConnectionFactory(String host, int port) {
        super(host, port);
    }

    @Override
    public void stop() {
        setActive(false);
        super.stop();
    }
}

The test — same harness as above, run against both the stock factory and the fixed one, over the same number of attempts:

/**
 * Demonstrates the bug against the stock TcpNioClientConnectionFactory, and proves
 * RaceSafeTcpNioClientConnectionFactory (above) eliminates it across the same number of attempts.
 */
class RaceSafeTcpNioClientConnectionFactoryIntegrationTest {

    private static final String SELECTOR_CLOSED_MESSAGE = "Selector closed";
    private static final int MAX_ATTEMPTS = 30;
    private static final long POST_STOP_WAIT_MILLIS = 80;

    @Test
    void plain_factory_logs_selector_closed_error_on_normal_stop() throws Exception {
        for (int attempt = 1; attempt <= MAX_ATTEMPTS; attempt++) {
            if (stopOnceAndCheckForSelectorClosedError(TcpNioClientConnectionFactory::new)) {
                log.info("Reproduced 'Selector closed' ERROR on attempt {}/{}", attempt, MAX_ATTEMPTS);
                return;
            }
        }
        fail("Expected '" + SELECTOR_CLOSED_MESSAGE + "' ERROR to be logged at least once in "
                + MAX_ATTEMPTS + " attempts (reproduces the upstream spring-integration-ip ordering bug)");
    }

    @Test
    void race_safe_factory_does_not_log_selector_closed_error_on_normal_stop() throws Exception {
        for (int attempt = 1; attempt <= MAX_ATTEMPTS; attempt++) {
            assertThat(stopOnceAndCheckForSelectorClosedError(RaceSafeTcpNioClientConnectionFactory::new))
                    .as("RaceSafeTcpNioClientConnectionFactory must never log '%s' (attempt %d/%d)",
                            SELECTOR_CLOSED_MESSAGE, attempt, MAX_ATTEMPTS)
                    .isFalse();
        }
    }

    // same stopOnceAndCheckForSelectorClosedError(...) helper as the Sample test above,
    // parameterized on which factory class to construct
    private boolean stopOnceAndCheckForSelectorClosedError(
            BiFunction<String, Integer, TcpNioClientConnectionFactory> factoryConstructor) throws Exception {
        try (ServerSocket serverSocket = new ServerSocket(0)) {
            serverSocket.setReuseAddress(true);
            ExecutorService taskExecutor = Executors.newCachedThreadPool();
            try {
                TcpNioClientConnectionFactory factory =
                        factoryConstructor.apply("localhost", serverSocket.getLocalPort());
                factory.setTaskExecutor(taskExecutor);

                Logger factoryLogger = (Logger) LoggerFactory.getLogger(factory.getClass());
                Level originalLevel = factoryLogger.getLevel();
                factoryLogger.setLevel(Level.ALL);
                ListAppender<ILoggingEvent> logAppender = new ListAppender<>();
                logAppender.start();
                factoryLogger.addAppender(logAppender);
                try {
                    factory.start();
                    await().atMost(5, TimeUnit.SECONDS)
                            .until(() -> ReflectionTestUtils.getField(factory, "selector") != null);
                    factory.getConnection();

                    factory.stop();
                    Thread.sleep(POST_STOP_WAIT_MILLIS);

                    return logAppender.list.stream().anyMatch(event ->
                            event.getLevel() == Level.ERROR
                                    && SELECTOR_CLOSED_MESSAGE.equals(event.getFormattedMessage()));
                } finally {
                    factoryLogger.detachAppender(logAppender);
                    factoryLogger.setLevel(originalLevel);
                }
            } finally {
                taskExecutor.shutdownNow();
            }
        }
    }
}

Metadata

Metadata

Assignees

No one assigned

    Type

    No type

    Projects

    No projects

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions