RSB Participants stuck on deactivation

[DivineThreepwood]

Release: rsb 0.18

In most cases the rsb participants can not be deactivated when calling the deactivation method of different participants simultaneously. After checking the stack trace it seems like a unlucky copy paste mistake in the SpreadReceiver.leave(...) method.

            // join the group
            SpreadReceiver.this.spread.leave(group);

            // wait until the membership message confirms the join
            membershipHandler.waitForMessage();

at least the comments are wrong because we are leaving the spread group and not joining it.
The thread blocks forever at the waitForMessage() method. Calling it after joining the group makes sense, but after leaving the group it's maybe not the best idea to wait for new incoming messages, right? Because the thread blocks the subscriptions lock at rsb.transport.spread.SpreadMultiReceiver.unsubscribe(SpreadMultiReceiver.java:341) all other participants calling the deactivation method blocks as well.

I would suggest to just remove themembershipHandler.waitForMessage();
call.

Stacktrace of the thread leaving the spread group:

"ShutdownDaemon[UnitRemotePool]" #299 prio=5 os_prio=31 cpu=1.95ms elapsed=478.97s tid=0x00007ff8038e5800 nid=0xe5007 in Object.wait()  [0x000070002a4f9000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(java.base@11.0.4/Native Method)
	- waiting on 
	at java.lang.Object.wait(java.base@11.0.4/Object.java:328)
	at rsb.transport.spread.SpreadReceiver$OneTimeWaitingMembershipHander.waitForMessage(SpreadReceiver.java:106)
	- waiting to re-lock in wait() <0x00000007896579f0> (a java.lang.Object)
	at rsb.transport.spread.SpreadReceiver$StateActive.leave(SpreadReceiver.java:322)
	at rsb.transport.spread.SpreadReceiver.leave(SpreadReceiver.java:415)
	at rsb.transport.spread.SpreadMultiReceiver.manageLeave(SpreadMultiReceiver.java:316)
	- locked <0x0000000782be5208> (a java.util.HashMap)
	at rsb.transport.spread.SpreadMultiReceiver.unsubscribe(SpreadMultiReceiver.java:360)
	- locked <0x0000000782be5208> (a java.util.HashMap)
	at rsb.transport.spread.MultiSpreadInPushConnector.deactivate(MultiSpreadInPushConnector.java:128)
	at rsb.eventprocessing.RouteConfiguratorUtility.deactivate(RouteConfiguratorUtility.java:119)
	- locked <0x0000000783b38f30> (a rsb.eventprocessing.RouteConfiguratorUtility)
	at rsb.eventprocessing.DefaultPushInRouteConfigurator.deactivate(DefaultPushInRouteConfigurator.java:79)
	- locked <0x0000000783b38f30> (a rsb.eventprocessing.RouteConfiguratorUtility)
	at rsb.Listener$StateActive.deactivate(Listener.java:97)
	at rsb.Listener.deactivate(Listener.java:196)
	at org.openbase.jul.extension.rsb.com.RSBSynchronizedParticipant.deactivate(RSBSynchronizedParticipant.java:217)

Example Stacktrace of all other participants:

"pool-1-thread-1" #37 prio=5 os_prio=31 cpu=152.51ms elapsed=779.29s tid=0x00007ff7fc1f1000 nid=0x6703 waiting for monitor entry  [0x000070000f801000]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at rsb.transport.spread.SpreadMultiReceiver.unsubscribe(SpreadMultiReceiver.java:341)
	- waiting to lock <0x0000000782be5208> (a java.util.HashMap)
	at rsb.transport.spread.MultiSpreadInPushConnector.deactivate(MultiSpreadInPushConnector.java:128)
	at rsb.eventprocessing.RouteConfiguratorUtility.deactivate(RouteConfiguratorUtility.java:119)
	- locked <0x0000000783c36438> (a rsb.eventprocessing.RouteConfiguratorUtility)
	at rsb.eventprocessing.DefaultPushInRouteConfigurator.deactivate(DefaultPushInRouteConfigurator.java:79)
	- locked <0x0000000783c36438> (a rsb.eventprocessing.RouteConfiguratorUtility)
	at rsb.Listener$StateActive.deactivate(Listener.java:97)
	at rsb.Listener.deactivate(Listener.java:196)
	at rsb.patterns.Method$StateActive.deactivate(Method.java:83)
	at rsb.patterns.Method.deactivate(Method.java:207)
	at rsb.patterns.Server$StateActive.deactivate(Server.java:77)
	at rsb.patterns.Server.deactivate(Server.java:225)
	- locked <0x0000000783c33858> (a rsb.patterns.LocalServer)
	at org.openbase.jul.extension.rsb.com.RSBSynchronizedParticipant.lambda$deactivate$0(RSBSynchronizedParticipant.java:205)

Code Example to reproduce:

import rsb.Event;
import rsb.Factory;
import rsb.RSBException;
import rsb.config.ParticipantConfig;
import rsb.patterns.Callback;
import rsb.patterns.LocalServer;
import rsb.patterns.RemoteServer;
import rsb.transport.spread.InPushConnectorFactoryRegistry;
import rsb.transport.spread.SharedInPushConnectorFactory;

import java.util.logging.Level;
import java.util.logging.Logger;

public class DeactivationOnEventLoadTest {

    // ----- setup test parameter ---------------------------------------
    public static final boolean EXIT_ON_ERROR               = false;
    public static final boolean STOP_PRINT_ON_ERROR         = true;
    public static final boolean ENABLE_CONNECTION_SHARING   = true;
    public static final long    SLEEP_TIME_BETWEEN_MESSES   = 10;
    public static final Level   LOG_LEVEL                   = Level.ALL;
    // ------------------------------------------------------------------

    // other static fields
    private static final String KEY_IN_PUSH_FACTORY = "shareIfPossible";
    private static final String METTHOD = "testmethod";

    public static void main(String[] args) throws InterruptedException {

        Logger.getLogger("").setLevel(LOG_LEVEL);

        // setup participant config
        int runCounter = 0;
        final ParticipantConfig participantConfig = Factory.getInstance().getDefaultParticipantConfig();
        if (ENABLE_CONNECTION_SHARING) {
            InPushConnectorFactoryRegistry.getInstance().registerFactory(KEY_IN_PUSH_FACTORY, new SharedInPushConnectorFactory());

            // instruct the spread transport to use your newly registered factory
            // for creating in push connector instances
            participantConfig.getOrCreateTransport("spread")
                    .getOptions()
                    .setProperty("transport.spread.java.infactory", KEY_IN_PUSH_FACTORY);
        }

        // start test
        mainLoop:
        while (!Thread.interrupted()) {

            // prepare run
            runCounter++;
            int serverRemotePairCount = runCounter * 10;
            final ShutdownHandler shutdownHandler = new ShutdownHandler(serverRemotePairCount);

            System.out.println("Start run " + runCounter + " with " + serverRemotePairCount * 2 + " participants...");
            for (int i = 0; i < serverRemotePairCount; i++) {
                final String id = Integer.toString(i);

                // create server
                new Thread("ServerThread-" + id) {
                    @Override
                    public void run() {
                        try {
                            LocalServer server = Factory.getInstance().createLocalServer("/test/scope/" + id, participantConfig);
                            server.addMethod("testmethod", new Callback() {
                                @Override
                                public Event internalInvoke(Event request) {
                                    return new Event(Void.class, null);
                                }
                            });
                            server.activate();
                            shutdownHandler.activeParticipants++;

                            while (!shutdownHandler.shutdown) {
                                Thread.sleep(SLEEP_TIME_BETWEEN_MESSES);
                            }

                            server.deactivate();
                            shutdownHandler.activeParticipants--;
                        } catch (RSBException | InterruptedException e) {
                            e.printStackTrace();
                        }

                    }
                }.start();

                // create remote
                new Thread("RemoteThread-" + id) {

                    @Override
                    public void run() {
                        try {
                            RemoteServer remote = Factory.getInstance().createRemoteServer("/test/scope/" + id, participantConfig);

                            remote.activate();
                            shutdownHandler.activeParticipants++;

                            while (!shutdownHandler.shutdown) {
                                remote.callAsync(METTHOD, new Event(Void.class, null));
                                Thread.sleep(SLEEP_TIME_BETWEEN_MESSES);
                            }

                            remote.deactivate();
                            shutdownHandler.activeParticipants--;
                        } catch (Exception e) {
                            e.printStackTrace();
                        }

                    }
                }.start();
            }

            System.out.println("Wait until pool is active...");
            while (shutdownHandler.activeParticipants != serverRemotePairCount * 2) {
                Thread.yield();
            }

            // wait some additional time to increase message load
            Thread.sleep(2000);

            System.out.println("Initiate Shutdown...");
            shutdownHandler.shutdown = true;

            int lastCount = -1;
            while (shutdownHandler.activeParticipants != 0) {

                System.out.println("Shutdown progress: " + shutdownHandler.getProgress() + "% " + (shutdownHandler.activeParticipants == lastCount ? "(deactivation stuck detected)" : ""));

                if (lastCount == shutdownHandler.activeParticipants) {
                    Thread.sleep(2000);
                    if ((STOP_PRINT_ON_ERROR || EXIT_ON_ERROR) && lastCount == shutdownHandler.activeParticipants) {
                        System.err.println("Shutdown failed in run " + runCounter + " with " + serverRemotePairCount * 2 + " participants where " + shutdownHandler.activeParticipants + " could not be deactivated!");
                        break mainLoop;
                    }
                }
                lastCount = shutdownHandler.activeParticipants;
                Thread.sleep(200);
            }
            System.out.println("Shutdown progress: 100% (successful)");
        }
        System.out.println("Exit test. Probably some threads do not terminate because of the deactivation failure.");

        if (EXIT_ON_ERROR) {
            System.exit(200);
        }
    }

    static class ShutdownHandler {
        private boolean shutdown = false;
        private transient int activeParticipants = 0;
        private final int totalParticipantCount;

        public ShutdownHandler(int totalParticipantCount) {
            this.totalParticipantCount = totalParticipantCount;
        }

        public int getProgress() {
            return (100 - (int) ((activeParticipants / (totalParticipantCount * 2d)) * 100d));
        }
    }
}

Code Example Log

/Library/Java/JavaVirtualMachines/zulu11.33.15-ca-jdk11.0.4-macosx_x64/bin/java -Dvisualvm.id=60730495710092 "-javaagent:/Users/divine/Library/Application Support/JetBrains/Toolbox/apps/IDEA-U/ch-0/192.7142.36/IntelliJ IDEA.app/Contents/lib/idea_rt.jar=59640:/Users/divine/Library/Application Support/JetBrains/Toolbox/apps/IDEA-U/ch-0/192.7142.36/IntelliJ IDEA.app/Contents/bin" -Dfile.encoding=UTF-8 -classpath /Users/divine/workspace/openbase/bco/module/jul/extension/rsb/com/target/classes:/Users/divine/workspace/openbase/bco/module/jul/extension/type/interface/target/classes:/Users/divine/.m2/repository/org/openbase/type/1.0-SNAPSHOT/type-1.0-SNAPSHOT.jar:/Users/divine/workspace/openbase/bco/module/jul/extension/type/util/target/classes:/Users/divine/workspace/openbase/bco/module/jul/extension/rsb/interface/target/classes:/Users/divine/workspace/openbase/bco/module/jul/extension/rsb/scope/target/classes:/Users/divine/workspace/openbase/bco/module/jul/extension/type/processing/target/classes:/Users/divine/workspace/openbase/bco/module/jul/extension/protobuf/target/classes:/Users/divine/workspace/openbase/bco/module/jul/processing/json/target/classes:/Users/divine/workspace/openbase/bco/module/jul/processing/default/target/classes:/Users/divine/.m2/repository/commons-lang/commons-lang/2.6/commons-lang-2.6.jar:/Users/divine/.m2/repository/java3d/vecmath/1.3.1/vecmath-1.3.1.jar:/Users/divine/.m2/repository/com/fasterxml/jackson/core/jackson-core/2.10.0.pr3/jackson-core-2.10.0.pr3.jar:/Users/divine/.m2/repository/com/fasterxml/jackson/core/jackson-databind/2.10.0.pr3/jackson-databind-2.10.0.pr3.jar:/Users/divine/.m2/repository/com/fasterxml/jackson/core/jackson-annotations/2.10.0.pr3/jackson-annotations-2.10.0.pr3.jar:/Users/divine/.m2/repository/com/googlecode/protobuf-java-format/protobuf-java-format/1.4/protobuf-java-format-1.4.jar:/Users/divine/.m2/repository/com/google/code/gson/gson/2.6.2/gson-2.6.2.jar:/Users/divine/workspace/openbase/bco/module/jul/interface/target/classes:/Users/divine/workspace/openbase/bco/module/jul/annotation/target/classes:/Users/divine/workspace/openbase/bco/module/jul/schedule/target/classes:/Users/divine/workspace/openbase/bco/module/jul/pattern/default/target/classes:/Users/divine/workspace/openbase/bco/module/jul/pattern/controller/target/classes:/Users/divine/.m2/repository/rsb/rsb/0.18.4/rsb-0.18.4.jar:/Users/divine/.m2/repository/com/google/protobuf/protobuf-java/3.0.2/protobuf-java-3.0.2.jar:/Users/divine/.m2/repository/com/github/jnr/jnr-ffi/2.0.9/jnr-ffi-2.0.9.jar:/Users/divine/.m2/repository/com/github/jnr/jffi/1.2.11/jffi-1.2.11.jar:/Users/divine/.m2/repository/com/github/jnr/jffi/1.2.11/jffi-1.2.11-native.jar:/Users/divine/.m2/repository/org/ow2/asm/asm/5.0.3/asm-5.0.3.jar:/Users/divine/.m2/repository/org/ow2/asm/asm-commons/5.0.3/asm-commons-5.0.3.jar:/Users/divine/.m2/repository/org/ow2/asm/asm-analysis/5.0.3/asm-analysis-5.0.3.jar:/Users/divine/.m2/repository/org/ow2/asm/asm-tree/5.0.3/asm-tree-5.0.3.jar:/Users/divine/.m2/repository/org/ow2/asm/asm-util/5.0.3/asm-util-5.0.3.jar:/Users/divine/.m2/repository/com/github/jnr/jnr-x86asm/1.0.2/jnr-x86asm-1.0.2.jar:/Users/divine/workspace/openbase/bco/module/jul/exception/target/classes:/Users/divine/.m2/repository/org/openbase/jps/3.4.16-SNAPSHOT/jps-3.4.16-SNAPSHOT.jar:/Users/divine/.m2/repository/org/fusesource/jansi/jansi/1.11/jansi-1.11.jar:/Users/divine/.m2/repository/ch/qos/logback/logback-classic/1.2.3/logback-classic-1.2.3.jar:/Users/divine/.m2/repository/ch/qos/logback/logback-core/1.2.3/logback-core-1.2.3.jar:/Users/divine/.m2/repository/org/slf4j/slf4j-api/1.7.25/slf4j-api-1.7.25.jar:/Users/divine/.m2/repository/commons-io/commons-io/2.6/commons-io-2.6.jar:/Users/divine/.m2/repository/org/apache/commons/commons-lang3/3.9/commons-lang3-3.9.jar org.openbase.jul.extension.rsb.com.test.DeactivationOnEventLoadTest
WARNING: An illegal reflective access operation has occurred
WARNING: Illegal reflective access by com.google.protobuf.UnsafeUtil (file:/Users/divine/.m2/repository/com/google/protobuf/protobuf-java/3.0.2/protobuf-java-3.0.2.jar) to field java.nio.Buffer.address
WARNING: Please consider reporting this to the maintainers of com.google.protobuf.UnsafeUtil
WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
WARNING: All illegal access operations will be denied in a future release
Start run 1 with 20 participants...
Wait until pool is active...
Initiate Shutdown...
Shutdown progress: 0% 
Nov 08, 2019 3:57:25 PM rsb.introspection.IntrospectionParticipantObserver destroyed
INFO: Deactivating introspection protocol handler since no more participants exist
Shutdown progress: 100% (successful)
Start run 2 with 40 participants...
Wait until pool is active...
Initiate Shutdown...
Shutdown progress: 0% 
Nov 08, 2019 3:57:27 PM rsb.introspection.IntrospectionParticipantObserver destroyed
INFO: Deactivating introspection protocol handler since no more participants exist
Shutdown progress: 100% (successful)
Start run 3 with 60 participants...
Wait until pool is active...
Initiate Shutdown...
Shutdown progress: 0% 
Nov 08, 2019 3:57:30 PM rsb.introspection.IntrospectionParticipantObserver destroyed
INFO: Deactivating introspection protocol handler since no more participants exist
Shutdown progress: 100% (successful)
Start run 4 with 80 participants...
Wait until pool is active...
Initiate Shutdown...
Shutdown progress: 0% 
Nov 08, 2019 3:57:32 PM rsb.introspection.IntrospectionParticipantObserver destroyed
INFO: Deactivating introspection protocol handler since no more participants exist
Shutdown progress: 100% (successful)
Start run 5 with 100 participants...
Wait until pool is active...
Initiate Shutdown...
Shutdown progress: 0% 
Shutdown progress: 12% 
Shutdown progress: 12% (deactivation stuck detected)
Exit test. Probably some threads do not terminate because of the deactivation failure.
Shutdown failed in run 5 with 100 participants where 88 could not be deactivated!

Critical Stacktrace

"RemoteThread-14" #455 prio=5 os_prio=31 cpu=32.33ms elapsed=280.49s tid=0x00007fe32eb74800 nid=0x1bd0b in Object.wait()  [0x0000700006fa9000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(java.base@11.0.4/Native Method)
	- waiting on 
	at java.lang.Object.wait(java.base@11.0.4/Object.java:328)
	at rsb.transport.spread.SpreadReceiver$OneTimeWaitingMembershipHander.waitForMessage(SpreadReceiver.java:106)
	- waiting to re-lock in wait() <0x00000007871e3718> (a java.lang.Object)
	at rsb.transport.spread.SpreadReceiver$StateActive.leave(SpreadReceiver.java:322)
	at rsb.transport.spread.SpreadReceiver.leave(SpreadReceiver.java:415)
	at rsb.transport.spread.SpreadMultiReceiver.manageLeave(SpreadMultiReceiver.java:316)
	- locked <0x000000078027a4e8> (a java.util.HashMap)
	at rsb.transport.spread.SpreadMultiReceiver.unsubscribe(SpreadMultiReceiver.java:360)
	- locked <0x000000078027a4e8> (a java.util.HashMap)
	at rsb.transport.spread.MultiSpreadInPushConnector.deactivate(MultiSpreadInPushConnector.java:128)
	at rsb.eventprocessing.RouteConfiguratorUtility.deactivate(RouteConfiguratorUtility.java:119)
	- locked <0x00000007836374f0> (a rsb.eventprocessing.RouteConfiguratorUtility)
	at rsb.eventprocessing.DefaultPushInRouteConfigurator.deactivate(DefaultPushInRouteConfigurator.java:79)
	- locked <0x00000007836374f0> (a rsb.eventprocessing.RouteConfiguratorUtility)
	at rsb.Listener$StateActive.deactivate(Listener.java:97)
	at rsb.Listener.deactivate(Listener.java:196)
	at rsb.patterns.Method$StateActive.deactivate(Method.java:83)
	at rsb.patterns.Method.deactivate(Method.java:207)
	at rsb.patterns.Server$StateActive.deactivate(Server.java:77)
	at rsb.patterns.Server.deactivate(Server.java:225)
	- locked <0x0000000783630bd8> (a rsb.patterns.RemoteServer)
	at org.openbase.jul.extension.rsb.com.test.DeactivationOnEventLoadTest$2.run(DeactivationOnEventLoadTest.java:104)

[scymtym]

Thank you for the report.

First of all, could you provide a self-contained test program that allows reproducing the issue? Otherwise we have no way of making sure we understand and fix the problem properly. Furthermore, log messages for the rsb.transport.spread package at level FINEST could help.

at least the comments are wrong because we are leaving the spread group and not joining it.

Of course.

The thread blocks forever at the waitForMessage() method. Calling it after joining the group makes sense, but after leaving the group it's maybe not the best idea to wait for new incoming messages, right?

If waitForMessage never returns, something is wrong since Spread is definitely supposed to send a membership notification for leaving the group. I wouldn't say waiting for the leave operation to complete doesn't make sense. Otherwise, for example, we wouldn't know at which point we definitely no longer receive messages for the group in question.

Because the thread blocks the subscriptions lock [...]

That in itself is not a problem since the leave operation must finish in a finite (short) amount of time.

I could imagine something like the Spread message queue being full or maybe a deadlock caused by calling deactivate() from an unexpected place, but again, a self-contained test program or log messages may shed light onto the issue.

[DivineThreepwood]

Thanks for your fast response.

First of all, could you provide a self-contained test program that allows reproducing the issue? Otherwise we have no way of making sure we understand and fix the problem properly.

I just added an example code blob to the main issue description.

Furthermore, log messages for the rsb.transport.spread package at level FINEST could help.

I switched the log level to "ALL" but got no additional log messages, any idea?

If waitForMessage never returns, something is wrong since Spread is definitely supposed to send a membership notification for leaving the group.

That's good to know.

[DivineThreepwood]

Could you reproduce the issue by using the offered code snipped?
Otherwise, please let me know if I can further support you to solve this issue.

[scymtym]

Could you reproduce the issue by using the offered code snipped?

After changing the code a bit more, I think I could reproduce the issue.

[scymtym]

After fixing the example program (shutdownHandler.activeParticipants needs locking) and digging some more, I tracked this down to the Spread daemon killing the session when the number of participants gets too large.

We could produce a better error message but the fundamental issue will remain: if you increase the number of servers and simultaneous method calls sufficiently, the process will fall behind with respect to receiving and processing its Spread messages and ultimately be disconnected from the Spread session.

You are welcome to reopen the issue if you can come up with a different way of reproducing the hanging deactivation.

[DivineThreepwood]

After fixing the example program (shutdownHandler.activeParticipants needs locking)

Actually, I can't see the synchronization issue, should the transient int activeParticipants not handle the sync? Did you upload the synchronized test code version anywhere so I can build not top of it?

Spread daemon killing the session when the number of participants gets too large.

Okay, that's strange because in bco the communication of all participant (bco-validate is testing the connection of each unit) is just fine until the system shutdown gets initiated and calls the participants deactivation method.

I am really interested in solving this issue, I spend already some hours the find out what's causing it and some additional ones to reproduce it via the test code. I am sorry if the test code did not uncover the right bug, but please make sure that the deactivation of participants never stuck forever, in any case. So way are you still waiting to receive a message if the Spread daemon has already killed the session and will never responds to your request? Could you not just declare a timeout and in case spread is not responding and just print a warning message and finally deactivate the participant.

This bug is really annoying. I spend at least 30 seconds each day to kill bco sessions because of this bug so I would really appreciate if we could fix it together.

Therefore, please reopen the issue because I have no permission to do it and I will deliver the missing piece of test code to reproduce the described issue.

[scymtym]

Okay, that's strange because in bco the communication of all participant (bco-validate is testing the connection of each unit) is just fine until the system shutdown gets initiated and calls the participants deactivation method.

A relatively easy way to determine whether this happens or not is adding the following to the spread.conf configuration file:

DebugFlags = { PRINT SESSION EXIT }

and then running the daemon as

spread -n localhost -c spread.conf | grep kill

If the session is killed for not keeping up in terms of processing incoming messages, the daemon outputs something the following:

$ spread -n localhost -c spread.conf | grep kill
Sess_write: killing mbox 10 for not reading
Sess_kill: killing session r3234-10 ( mailbox 10 )

[DivineThreepwood]

I tried to synchronize the participant counter via an monitor but still get the same result:

static class ShutdownHandler {
        private boolean shutdown = false;
        private int activeParticipants = 0;
        private final int totalParticipantCount;

        private static final Object COUNTER_LOCK = new Object();

        public ShutdownHandler(int totalParticipantCount) {
            this.totalParticipantCount = totalParticipantCount;
        }

        public void increaseParticipantCounter() {
            synchronized (COUNTER_LOCK) {
                activeParticipants++;
            }
        }

        public void decreaseParticipantCounter() {
            synchronized (COUNTER_LOCK) {
                activeParticipants--;
            }
        }


        public int getProgress() {
            synchronized (COUNTER_LOCK) {
                return (100 - (int) ((activeParticipants / (totalParticipantCount * 2d)) * 100d));
            }
        }
    }

Shutdown progress: 10% (deactivation stuck detected)
Shutdown failed in run 6 with 120 participants where 108 could not be deactivated!

Spread daemon killing the session when the number of participants gets too large.

But 120 participants should not be too large, right?
Could you upload your test code modification so I can test it in my setup?

[scymtym]

Shutdown progress: 10% (deactivation stuck detected)
Shutdown failed in run 6 with 120 participants where 108 could not be deactivated!

The heuristic is wrong. It checks (assuming the locking issue is fixed) whether any participants have been deactivated within the last 200 ms. With a heavily loaded Spread daemon, the time between deactivations can easily be longer than that since the message queue is full of method call messages when the deactivation happens. Not breaking out of the loop after seeing lastCount == count once, reveals that more progress is made. That said, the test is designed in a way that ensures eventual failure since the amount of sent messages is increased until the receiver can no longer keep up.

But 120 participants should not be too large, right?

Of course. The number of participants is only indirectly related to the problem. The real issue is 240 threads (requests and replies) sending messages.

Could you upload your test code modification so I can test it in my setup?

The only change I made (apart from the locking that you already added) is removing the break mainLoop line. But as I said, I'm not sure what this program could demonstrate other than the fact that the receiver will eventually be unable to keep up.

[DivineThreepwood]

The heuristic is wrong. It checks (assuming the locking issue is fixed) whether any participants have been deactivated within the last 200 ms. ... That said, the test is designed in a way that ensures eventual failure since the amount of sent messages is increased until the receiver can no longer keep up.

I just feel like we are not talking about the same issue, here. I just added the main loop break to not stuck forever in the print loop. As soon as theshutdown flag is set to true there are no further messages send and the deactivation message called. If I set EXIT_ON_ERROR = false and EXIT_ON_ERROR = false (similar to removing the break mainLoop) the test output looks like this:

Start run 6 with 120 participants...
Wait until pool is active...
Initiate Shutdown...
Shutdown progress: 0% 
Shutdown progress: 9% 
Shutdown progress: 9% (deactivation stuck detected)
Shutdown failed in run 6 with 120 participants where 110 could not be deactivated!
Shutdown progress: 9% (deactivation stuck detected)
Shutdown failed in run 6 with 120 participants where 110 could not be deactivated!
Shutdown progress: 9% (deactivation stuck detected)
Shutdown failed in run 6 with 120 participants where 110 could not be deactivated!
Shutdown progress: 9% (deactivation stuck detected)
Shutdown failed in run 6 with 120 participants where 110 could not be deactivated!
Shutdown progress: 9% (deactivation stuck detected)
Shutdown failed in run 6 with 120 participants where 110 could not be deactivated!
Shutdown progress: 9% (deactivation stuck detected)
Shutdown failed in run 6 with 120 participants where 110 could not be deactivated!
Shutdown progress: 9% (deactivation stuck detected)
Shutdown failed in run 6 with 120 participants where 110 could not be deactivated!
Shutdown progress: 9% (deactivation stuck detected)
Shutdown failed in run 6 with 120 participants where 110 could not be deactivated!
Shutdown progress: 9% (deactivation stuck detected)
Shutdown failed in run 6 with 120 participants where 110 could not be deactivated!
Shutdown progress: 9% (deactivation stuck detected)
Shutdown failed in run 6 with 120 participants where 110 could not be deactivated!
Shutdown progress: 9% (deactivation stuck detected)
Shutdown failed in run 6 with 120 participants where 110 could not be deactivated!
Shutdown progress: 9% (deactivation stuck detected)
Shutdown failed in run 6 with 120 participants where 110 could not be deactivated!
Shutdown progress: 9% (deactivation stuck detected)
Shutdown failed in run 6 with 120 participants where 110 could not be deactivated!
Shutdown progress: 9% (deactivation stuck detected)
Shutdown failed in run 6 with 120 participants where 110 could not be deactivated!
Shutdown progress: 9% (deactivation stuck detected)
Shutdown failed in run 6 with 120 participants where 110 could not be deactivated!
Shutdown progress: 9% (deactivation stuck detected)
Shutdown failed in run 6 with 120 participants where 110 could not be deactivated!

and those prints continue until I terminate the test program.

With a heavily loaded Spread daemon, the time between deactivations can easily be longer than that since the message queue is full of method call messages when the deactivation happens.

It would totally agree that deactivations can easily be longer but I am talking about a never terminating deactivation call not just an delay.