QFJ-885 Send logout message before stopping initiators #101

alphafoobar · 2017-02-24T18:00:17Z

Because logout sets a flag indicating we should logout, we rely on another thread to send the logout message.

If we stop the initiators first that doesn't happen.

See JIRA: (QFJ-885)[http://www.quickfixj.org/jira/browse/QFJ-885]

Because logout sets a flag indicating we should logout, we rely on another thread to send the logout message. If we stop the initiators first that doesn't happen. See JIRA: (QFJ-885)[http://www.quickfixj.org/jira/browse/QFJ-885]

alphafoobar · 2017-02-24T22:22:15Z

quickfixj-core/src/main/java/quickfix/ThreadedSocketInitiator.java

        logoutAllSessions(forceDisconnect);
+        stopSessionTimer();


This is probably superfluous, since stopInitiators() will call this anyway.

Yeah, call to stopSessionTimer() has been removed in 5f36509
And stopInitiators() was also added in that commit, but it seems it would have been better to move it below the logoutAllSessions() call.

alphafoobar · 2017-02-24T22:25:46Z

quickfixj-core/src/main/java/quickfix/ThreadedSocketInitiator.java

        logoutAllSessions(forceDisconnect);
+        stopSessionTimer();
        if (!forceDisconnect) {
            waitForLogout();


This isn't required because logoutAllSessions(forceDisconnect) does exactly the same, unless the sessions weren't initialised... in which case any point waiting for logout?

You are right, it is not necessary.

chrjohn · 2017-02-25T15:34:55Z

Hi @alphafoobar
Thanks for the PR. I'll have a look.
I recall doing the same changes on a private branch but there was some unit test failing afterwards. Will check again.
Cheers,
Chris.

alphafoobar · 2017-02-26T13:35:26Z

Hi @chrjohn
NP, I'll take a look at what unit testing is around this. If I didn't break one, then I should add one.
Cheers,
James

chrjohn · 2017-02-26T18:16:48Z

Hi @alphafoobar , regarding the unit test: I checked it and there was no existing test failing but one that I wrote to check for the correct behaviour. But I did not get around to correct the problem due to time constraints.

However, there have to be more changes to correct the problem since you were only changing the ThreadedSocketInitiator. But the problems were reported against the default SocketInitiator.
Did you observe the problematic behaviour only with the ThreadedSocketInitiator or did you not try with the default SocketInitiator?

Thanks,
Chris.

alphafoobar · 2017-02-26T23:15:18Z

Hi @chrjohn,

Thanks for checking, we only use the ThreadedSocketInitiator.

Cheers
James

See JIRA: (QFJ-885)[http://www.quickfixj.org/jira/browse/QFJ-885]

This allows the logout message to be generated and sent. Otherwise `stopHandlingMessages` enqueues the `END_OF_STREAM` message. See JIRA: (QFJ-885)[http://www.quickfixj.org/jira/browse/QFJ-885]

Incorporating peer review feedback.

These comments are specifically related to the test > SingleThreadedEventHandlingStrategyTest.shouldCleanUpInitiatorQFJMessageProcessorThreadAfterStop:248 : TestTimedOut The call to stopHandlingMessages should happen after calling logout. Otherwise a logout message won't be sent. ```java logoutAllSessions(forceDisconnect); stopInitiators(); eventHandlingStrategy.stopHandlingMessages(); ``` Assuming sessions have connected, this refactor is fine. When sessions do not connect as per this test, the `initialize` method (which ends up waiting for a connection) blocks the eventual call to `stop`, since both are mostly guarded by `this`.

Since it would require further refactoring of the SocketInitiator.

alphafoobar · 2017-02-28T02:02:14Z

Hi @chrjohn

I have added some unit testing that shows a logout is happening, I was able to add those tests onto an unpatched branch and show that a logout was not sent.

I also looked at adding this for the SocketInitiator as I saw this does class does exhibit the same symptoms. But that appears to require more work for the acceptance tests to work, so I backed that change out.

Thanks,
James

chrjohn · 2017-02-28T10:13:58Z

Thanks @alphafoobar , I will take a look shortly.

This reverts commit 39492ff.

Without posting the END_OF_STREAM message which is responsible for disconnecting the session connector and prevent the processing of the LOGOUT message and any others that might be queued. JIRA: QFJ-885

Following the same approach as the SocketInitiator. JIRA: QFJ-885

chrjohn · 2017-03-06T16:10:00Z

Hi @alphafoobar, does your build run successfully with this changes? I have several unit test failures, e.g. in SocketInitiatorTest.testDoubleStartOfInitiator.
Thanks,
Chris.

alphafoobar · 2017-03-06T20:21:17Z

Hi @chrjohn,

Sorry about that, I am seeing that unit test fail. I'll look into why that's happening.

Cheers,
James

This change pulls the stopHandlingMessages method out of the synchronized block. Using the stop first pattern seems to let the Acceptor's QFJ Message Processing thread to linger. JIRA: QFJ-885

JIRA: QFJ-885

alphafoobar · 2017-03-07T00:47:02Z

Hi @chrjohn,

With the changes in this PR, the QFJ Message Processor threads weren't dying as quickly. So the problem wasn't that SocketInitiatorTest.testDoubleStartOfInitiator had initiated two sessions; but instead that the others tests may still have had lingering Acceptor threads.

Sending the END_OF_STREAM message before the synchronization block is good for emptying the message queue, but not quite as good for closing the collection quickly.

Since the acceptor change is breaking tests I've backed it out.

Cheers,
James

chrjohn · 2017-03-09T09:12:48Z

Hi @alphafoobar , thanks for your input. I am thinking about relaxing the synchronization around the start()/stop() methods of the Initiator to prevent the deadlock when stopHandlingMessages() is called on an Initiator in the block() method. The synchronization is merely done so that you cannot call stop() and start() concurrently. However, the SingleThreadedEventHandlingStrategy itself already checks if there already is a message processing thread active and throws an Exception in that case.

What do you think?
Cheers,
Chris.

alphafoobar · 2017-03-09T23:02:37Z

Hi @chrjohn

It sounds sensible, starting and stopping the initiator/acceptors are activities that are unlikely to see much contention and the ThreadedSocketInitiator start/stop methods aren't synchronized.

I've been thinking that it would make more sense for the blocking thread to add the END_OF_STREAM message on the end of the queue once it realises it has been stopped, for example in SingleThreadedEventHandlingStrategy.block():

if (!eventQueue.isEmpty()) {
    final List<SessionMessageEvent> tempList = new ArrayList<>();
    eventQueue.drainTo(tempList);
    for (SessionMessageEvent event : tempList) {
        event.processMessage();
    }
    for (Session quickfixSession : sessionConnector.getManagedSessions()) {
        new SessionMessageEvent(quickfixSession, END_OF_STREAM).processMessage();
    }
}

I'm happy to help,
James

chrjohn · 2017-04-06T19:26:45Z

Hi @alphafoobar ,
after reviewing your changes again, I think I found an easier (i.e. less invasive) way to correct the behaviour.
One part of the solution were definitely the changes in https://github.com/quickfix-j/quickfixj/pull/101/files#diff-76633e507f7b944754a248ac2d00434c
Will check again and come back.
Thanks,
Chris.

alphafoobar · 2017-04-07T05:54:34Z

Hi Chris, sounds good. Cheers!

chrjohn · 2017-04-11T22:27:15Z

Hi @alphafoobar,
I have created a new pull request #109 based on your changes. After fiddling around with your pull request and doing some other changes it was a bit of a mess. ;) So I hope it is OK with you to close this PR and that #109 resolves your issues.
Thanks for all your help and cheers,
Chris.

@alphafoobar

QFJ-885 Logout message is not sent out - based on #101 by @alphafoobar

@alphafoobar

QFJ-885 Logout message is not sent out - based on #101 by @alphafoobar (cherry picked from commit 916f260)

alphafoobar · 2017-04-12T21:30:10Z

Cool, thanks @chrjohn !

Send logout message before stopping initiators

1948448

Because logout sets a flag indicating we should logout, we rely on another thread to send the logout message. If we stop the initiators first that doesn't happen. See JIRA: (QFJ-885)[http://www.quickfixj.org/jira/browse/QFJ-885]

alphafoobar changed the title ~~Send logout message before stopping initiators~~ QFJ-885 Send logout message before stopping initiators Feb 24, 2017

alphafoobar commented Feb 24, 2017

View reviewed changes

chrjohn added this to the QFJ 1.6.4 milestone Feb 25, 2017

alphafoobar added 6 commits February 27, 2017 23:46

Add unit test to confirm that a Logout has been sent

6791502

See JIRA: (QFJ-885)[http://www.quickfixj.org/jira/browse/QFJ-885]

Re-order logoutAllSessions and stopHandlingMessages

1e3e43b

This allows the logout message to be generated and sent. Otherwise `stopHandlingMessages` enqueues the `END_OF_STREAM` message. See JIRA: (QFJ-885)[http://www.quickfixj.org/jira/browse/QFJ-885]

Re-formatted logoutAllSessions in SessionConnector

60753b3

Removed redundant methods calls from stop

72a8193

Incorporating peer review feedback.

Removed SingleThreaded socket stop test

39492ff

Since it would require further refactoring of the SocketInitiator.

alphafoobar added 2 commits March 4, 2017 20:47

Revert "Removed SingleThreaded socket stop test"

a5a3734

This reverts commit 39492ff.

Allow single threaded initiator to stop message processing loop

7ce6b02

Without posting the END_OF_STREAM message which is responsible for disconnecting the session connector and prevent the processing of the LOGOUT message and any others that might be queued. JIRA: QFJ-885

alphafoobar force-pushed the bugfix/QFJ-885-Send-logout-message-on-shutdown branch from 259507f to 7ce6b02 Compare March 4, 2017 23:29

Allow SocketAcceptor to stop processing messages when stop requested

439c21d

Following the same approach as the SocketInitiator. JIRA: QFJ-885

alphafoobar force-pushed the bugfix/QFJ-885-Send-logout-message-on-shutdown branch from 15d087b to 439c21d Compare March 5, 2017 00:01

alphafoobar added 2 commits March 7, 2017 00:18

Backed out SocketAcceptor change

8397e99

This change pulls the stopHandlingMessages method out of the synchronized block. Using the stop first pattern seems to let the Acceptor's QFJ Message Processing thread to linger. JIRA: QFJ-885

Remove accidentally committed unused method.

c184920

JIRA: QFJ-885

chrjohn referenced this pull request Apr 4, 2017

Patched classes provided with ticket that fixes #895

a72d3ef

chrjohn mentioned this pull request Apr 11, 2017

QFJ-885 Logout message is not sent out #109

Merged

chrjohn closed this Apr 11, 2017

chrjohn added a commit that referenced this pull request Apr 12, 2017

Merge pull request #109 from quickfix-j/qfj-885-logout-message

916f260

QFJ-885 Logout message is not sent out - based on #101 by @alphafoobar

chrjohn added a commit that referenced this pull request Apr 12, 2017

Merge pull request #109 from quickfix-j/qfj-885-logout-message

9d12665

QFJ-885 Logout message is not sent out - based on #101 by @alphafoobar (cherry picked from commit 916f260)

philipwhiuk mentioned this pull request Jun 9, 2020

Graceful disconnect functionality #300

Open

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

QFJ-885 Send logout message before stopping initiators #101

QFJ-885 Send logout message before stopping initiators #101

alphafoobar commented Feb 24, 2017

alphafoobar Feb 24, 2017

chrjohn Feb 25, 2017 •

edited

alphafoobar Feb 24, 2017

chrjohn Feb 25, 2017

chrjohn commented Feb 25, 2017

alphafoobar commented Feb 26, 2017

chrjohn commented Feb 26, 2017 •

edited

alphafoobar commented Feb 26, 2017

alphafoobar commented Feb 28, 2017

chrjohn commented Feb 28, 2017

chrjohn commented Mar 6, 2017

alphafoobar commented Mar 6, 2017

alphafoobar commented Mar 7, 2017

chrjohn commented Mar 9, 2017

alphafoobar commented Mar 9, 2017

chrjohn commented Apr 6, 2017

alphafoobar commented Apr 7, 2017

chrjohn commented Apr 11, 2017

alphafoobar commented Apr 12, 2017

QFJ-885 Send logout message before stopping initiators #101

QFJ-885 Send logout message before stopping initiators #101

Conversation

alphafoobar commented Feb 24, 2017

alphafoobar Feb 24, 2017

Choose a reason for hiding this comment

chrjohn Feb 25, 2017 • edited

Choose a reason for hiding this comment

alphafoobar Feb 24, 2017

Choose a reason for hiding this comment

chrjohn Feb 25, 2017

Choose a reason for hiding this comment

chrjohn commented Feb 25, 2017

alphafoobar commented Feb 26, 2017

chrjohn commented Feb 26, 2017 • edited

alphafoobar commented Feb 26, 2017

alphafoobar commented Feb 28, 2017

chrjohn commented Feb 28, 2017

chrjohn commented Mar 6, 2017

alphafoobar commented Mar 6, 2017

alphafoobar commented Mar 7, 2017

chrjohn commented Mar 9, 2017

alphafoobar commented Mar 9, 2017

chrjohn commented Apr 6, 2017

alphafoobar commented Apr 7, 2017

chrjohn commented Apr 11, 2017

alphafoobar commented Apr 12, 2017

chrjohn Feb 25, 2017 •

edited

chrjohn commented Feb 26, 2017 •

edited