Uploaded image for project: 'QuickFIX/J'
  1. QuickFIX/J
  2. QFJ-62

Session Initiator Fails with "Connection failed: Failed to get the session."

    Details

    • Type: Other
    • Status: Closed
    • Priority: Default
    • Resolution: Fixed
    • Affects Version/s: 1.0.0 Final, 1.0.1, 1.0.2, 1.0.3
    • Fix Version/s: None
    • Component/s: Networking
    • Labels:
      None
    • Environment:
      Win 2k3 Server, Dell 2650 Dual 2.4Ghz 2GB Ram, BEA jrockit-R26.3.0-jdk1.5.0_06

      Description

      I tried posting this to the Mailing list, but was rejected:
      Failed to deliver to 'quickfixj-users@lists.sourceforge.net'
      SMTP module(domain lists.sourceforge.net) reports:
      host mail.sourceforge.net says:
      550 Sender verify failed
      (i did register for the mailing list)

      I've been trying to port a pojo application from QuickFix-JNI to QuickFixJ 1.0.x, however, my (initiator) session never connects, instead failing with "Connection failed: Failed to get the session."

      I haven't seen anything about this in the mail-archives, the closest thing being the issue of having to delete the quickfix fixmsg log files to avoid an EOFException, which I had already encountered.

      – as far as I can tell "Failed to get session." is a MINA IOException message, wrapped in "ConnectionFailed: " when caught by IoSessionInitiator.connect(), however I am not familiar enough with MINA for that to help me much – I would have guessed that the connection was never even being attempted, but an ethereal capture reveals the connection is at least initiated, showing

      TEST1 -> TEST2 : SYN
      TEST2 -> TEST1 : SYN,ACK
      TEST1 -> TEST2 : ACK

      I tried using both the SocketInitiator and ThreadedSocketInitiator classes, to no effect
      I also tried upgrading to mina-core-0.9.4.jar, in the blind hope that it might fix something, but it didn't.
      Tried downgrading QuickfixJ to 1.0.0, 1.0.1, 1.0.2

      below is the code being called, along with the log output (which includes the session settings), any help would be greatly appreciated.

      thanks,

      kevin ( kevin@blockorders.com )
      class FIXProxy extends Proxy implements quickfix.Application
      {
      public static void startupFix()
      {
      try
      {
      Log.dbg("ENTER startupFix");
      instance = new FIXProxy();

      Log.info(" FixProxy instantiated.");

      SessionSettings settings = new SessionSettings(new FileInputStream(instance.fixCfgFile));
      MessageStoreFactory storeFactory = new FileStoreFactory(settings);
      LogFactory logFactory = new SLF4JLogFactory(settings);
      MessageFactory messageFactory = new DefaultMessageFactory();

      Log.info("SETTINGS: [DEFAULT]");
      Properties dprop = settings.getDefaultProperties();
      Enumeration de = dprop.keys();
      while( de.hasMoreElements() )

      { String key=(String)de.nextElement(); String val = (String)dprop.get(key); Log.info(" " + key + " = " + val); }

      SessionID sid = new SessionID("FIX.4.0","TEST1","TEST2");
      Log.info("SETTINGS: ["+sid.toString()+"]");
      Properties prop = settings.getSessionProperties(sid);
      Enumeration en = prop.keys();
      while( en.hasMoreElements() )

      { String key = (String)en.nextElement(); String val = prop.getProperty(key); Log.info(" " + key + " = " + val); }

      instance.start();
      Log.info(" FixProxy started");

      try

      { initiator = new SocketInitiator(instance,storeFactory,settings, logFactory,messageFactory); }

      catch(Exception e)

      {e.printStackTrace();return;}

      Log.info(" SocketInitiator instantiated.");
      try

      { initiator.start(); }

      catch(Exception e2)

      {e2.printStackTrace();return;}

      Log.info(" SocketInitiator started.");
      }
      catch(Exception ex)

      { Log.err(ex.getMessage()); ex.printStackTrace(); }

      finally

      { Log.dbg("LEAVE startupFix"); }

      }

      2006/08/29 19:34:05 | Init session: FIX.4.0:TEST1->TEST2
      2006/08/29 19:34:05 | SETTINGS: [DEFAULT]
      2006/08/29 19:34:05 | ConnectionType = initiator
      2006/08/29 19:34:05 | LogonTimeout = 30
      2006/08/29 19:34:05 | BeginString = FIX.4.0
      2006/08/29 19:34:05 | ValidateFieldsOutOfOrder = Y
      2006/08/29 19:34:05 | ReconnectInterval = 30
      2006/08/29 19:34:05 | HeartBtInt = 60
      2006/08/29 19:34:05 | FileStorePath = D:/Logs/FixStore
      2006/08/29 19:34:05 | UseDataDictionary = N
      2006/08/29 19:34:05 | FileLogPath = D:/Logs/FixMsgs
      2006/08/29 19:34:05 | SETTINGS: [FIX.4.0:TEST1->TEST2]
      2006/08/29 19:34:05 | EndTime = 23:59:00
      2006/08/29 19:34:05 | StartTime = 00:01:00
      2006/08/29 19:34:05 | TargetCompID = TEST2
      2006/08/29 19:34:05 | SocketConnectPort = 700
      2006/08/29 19:34:05 | SenderCompID = TEST1
      2006/08/29 19:34:05 | SocketConnectHost = 127.0.0.1
      2006/08/29 19:34:05 | FixProxy started
      2006/08/29 19:34:05 | FIXProxy Transitions FROM STATE_INITIAL TO STATE_STARTING
      2006/08/29 19:34:05 | ENTER: STATE_STARTING
      2006/08/29 19:34:05 | FIXProxy Transitions FROM STATE_STARTING TO STATE_RUNNING
      2006/08/29 19:34:05 | ENTER: STATE_RUNNING
      2006/08/29 19:34:05 | Aug 29, 2006 7:34:05 PM quickfix.SLF4JLog log
      2006/08/29 19:34:05 | FIX.4.0:TEST1->TEST2: Session FIX.4.0:TEST1->TEST2 schedule is daily, 00:01:00 UTC - 23:59:00 UTC
      2006/08/29 19:34:05 | FixEngine.onCreate FIX.4.0:TEST1->TEST2
      2006/08/29 19:34:05 | Aug 29, 2006 7:34:05 PM quickfix.SLF4JLog log
      2006/08/29 19:34:05 | FIX.4.0:TEST1->TEST2: Created session: FIX.4.0:TEST1->TEST2
      2006/08/29 19:34:05 | SocketInitiator instantiated.
      2006/08/29 19:35:05 | Aug 29, 2006 7:35:05 PM quickfix.SLF4JLog log
      2006/08/29 19:35:05 | FIX.4.0:TEST1->TEST2: Connection failed: Failed to get the session.
      2006/08/29 19:35:05 | SocketInitiator started.
      2006/08/29 19:35:05 | DEBUG: LEAVE startupFix

        Attachments

          Activity

          Hide
          admin Steve Bate added a comment -

          The message does mean that MINA can't establish the socket session (versus the QF session). For example, if I start Banzai without an acceptor running I'll see this message. I can try the example code sometime but it won't be for a few days at least. I really don't have any other theories. Do you have any firewalls running on either test box?

          Show
          admin Steve Bate added a comment - The message does mean that MINA can't establish the socket session (versus the QF session). For example, if I start Banzai without an acceptor running I'll see this message. I can try the example code sometime but it won't be for a few days at least. I really don't have any other theories. Do you have any firewalls running on either test box?
          Hide
          admin Steve Bate added a comment -

          I'd expect them to behave the same. It seems like a long shot but maybe there are some low level differences in the way the sockets are configured. This is just a guess. I haven't seen any related issues being discussed on the MINA mailing list. If you gather any more information that might help diagnose the problem, please let me know.

          Show
          admin Steve Bate added a comment - I'd expect them to behave the same. It seems like a long shot but maybe there are some low level differences in the way the sockets are configured. This is just a guess. I haven't seen any related issues being discussed on the MINA mailing list. If you gather any more information that might help diagnose the problem, please let me know.
          Hide
          admin Steve Bate added a comment -

          Hi Kevin,

          I used the order executor and Banzai to try your configuration file. I made the following modifications...

          Order Executor:

          • Config: Changed FIX version to 4.0 and port to 700
          • Config: Changed compIDs to TEST2, TEST1.

          Banzai:

          • Config: Change file log and store paths for my file system.
          • Banzai.java: Used a FileLogFactory instead of ScreenLogFactory

          When I run the apps, Banza is able to connect to the executor and it creates the file logs properly.

          Order Executor:

          <20060907-13:38:16, FIX.4.0:TEST2->TEST1, event> (Session FIX.4.0:TEST2->TEST1 schedule is daily, 00:00:00 UTC - 00:00:00 UTC)
          <20060907-13:38:16, FIX.4.0:TEST2->TEST1, event> (Valid order types: [F, 2])
          <20060907-13:38:16, FIX.4.0:TEST2->TEST1, event> (Created session: FIX.4.0:TEST2->TEST1)
          press <enter> to quit
          Sep 7, 2006 3:38:16 PM quickfix.mina.acceptor.AbstractSocketAcceptor startAcceptingConnections
          INFO: Listening for connections at 0.0.0.0/0.0.0.0:700
          Sep 7, 2006 3:38:22 PM quickfix.mina.acceptor.AcceptorIoHandler sessionCreated
          INFO: MINA session created: /127.0.0.1:2295
          <20060907-13:38:22, FIX.4.0:TEST2->TEST1, incoming> (8=FIX.4.09=6135=A34=949=TEST152=20060907-13:38:2256=TEST298=0108=6010=036)
          <20060907-13:38:22, FIX.4.0:TEST2->TEST1, event> (Accepting session FIX.4.0:TEST2->TEST1 from /127.0.0.1:2295)
          <20060907-13:38:22, FIX.4.0:TEST2->TEST1, event> (Acceptor heartbeat set to 60 seconds)
          <20060907-13:38:22, FIX.4.0:TEST2->TEST1, event> (Received logon request)
          <20060907-13:38:22, FIX.4.0:TEST2->TEST1, outgoing> (8=FIX.4.09=6135=A34=949=TEST252=20060907-13:38:2256=TEST198=0108=6010=036)
          <20060907-13:38:22, FIX.4.0:TEST2->TEST1, event> (Responding to logon request)

          Banzai:

          <20060907-13:38:21, FIX.4.0:TEST1->TEST2, event> (Session FIX.4.0:TEST1->TEST2 schedule is daily, 00:01:00 UTC - 23:59:00 UTC)
          <20060907-13:38:21, FIX.4.0:TEST1->TEST2, event> (Created session: FIX.4.0:TEST1->TEST2)
          <20060907-13:38:22, FIX.4.0:TEST1->TEST2, outgoing> (8=FIX.4.09=6135=A34=949=TEST152=20060907-13:38:2256=TEST298=0108=6010=036)
          <20060907-13:38:22, FIX.4.0:TEST1->TEST2, event> (Initiated logon request)
          <20060907-13:38:22, FIX.4.0:TEST1->TEST2, incoming> (8=FIX.4.09=6135=A34=949=TEST252=20060907-13:38:2256=TEST198=0108=6010=036)
          <20060907-13:38:22, FIX.4.0:TEST1->TEST2, event> (Received logon response)
          Sep 7, 2006 3:38:22 PM quickfix.mina.initiator.InitiatorIoHandler sessionCreated
          INFO: MINA session created: /127.0.0.1:2295

          So, I don't know. It appears the configuration file is fine. I'm running out of theories about why you are seeing different behavior on your system. I haven't had anyone else report this specific kind of problem. If you have any other ideas, I'll give you whatever support I can to resolve the problem.

          Show
          admin Steve Bate added a comment - Hi Kevin, I used the order executor and Banzai to try your configuration file. I made the following modifications... Order Executor: Config: Changed FIX version to 4.0 and port to 700 Config: Changed compIDs to TEST2, TEST1. Banzai: Config: Change file log and store paths for my file system. Banzai.java: Used a FileLogFactory instead of ScreenLogFactory When I run the apps, Banza is able to connect to the executor and it creates the file logs properly. Order Executor: <20060907-13:38:16, FIX.4.0:TEST2->TEST1, event> (Session FIX.4.0:TEST2->TEST1 schedule is daily, 00:00:00 UTC - 00:00:00 UTC) <20060907-13:38:16, FIX.4.0:TEST2->TEST1, event> (Valid order types: [F, 2] ) <20060907-13:38:16, FIX.4.0:TEST2->TEST1, event> (Created session: FIX.4.0:TEST2->TEST1) press <enter> to quit Sep 7, 2006 3:38:16 PM quickfix.mina.acceptor.AbstractSocketAcceptor startAcceptingConnections INFO: Listening for connections at 0.0.0.0/0.0.0.0:700 Sep 7, 2006 3:38:22 PM quickfix.mina.acceptor.AcceptorIoHandler sessionCreated INFO: MINA session created: /127.0.0.1:2295 <20060907-13:38:22, FIX.4.0:TEST2->TEST1, incoming> (8=FIX.4.09=6135=A34=949=TEST152=20060907-13:38:2256=TEST298=0108=6010=036) <20060907-13:38:22, FIX.4.0:TEST2->TEST1, event> (Accepting session FIX.4.0:TEST2->TEST1 from /127.0.0.1:2295) <20060907-13:38:22, FIX.4.0:TEST2->TEST1, event> (Acceptor heartbeat set to 60 seconds) <20060907-13:38:22, FIX.4.0:TEST2->TEST1, event> (Received logon request) <20060907-13:38:22, FIX.4.0:TEST2->TEST1, outgoing> (8=FIX.4.09=6135=A34=949=TEST252=20060907-13:38:2256=TEST198=0108=6010=036) <20060907-13:38:22, FIX.4.0:TEST2->TEST1, event> (Responding to logon request) Banzai: <20060907-13:38:21, FIX.4.0:TEST1->TEST2, event> (Session FIX.4.0:TEST1->TEST2 schedule is daily, 00:01:00 UTC - 23:59:00 UTC) <20060907-13:38:21, FIX.4.0:TEST1->TEST2, event> (Created session: FIX.4.0:TEST1->TEST2) <20060907-13:38:22, FIX.4.0:TEST1->TEST2, outgoing> (8=FIX.4.09=6135=A34=949=TEST152=20060907-13:38:2256=TEST298=0108=6010=036) <20060907-13:38:22, FIX.4.0:TEST1->TEST2, event> (Initiated logon request) <20060907-13:38:22, FIX.4.0:TEST1->TEST2, incoming> (8=FIX.4.09=6135=A34=949=TEST252=20060907-13:38:2256=TEST198=0108=6010=036) <20060907-13:38:22, FIX.4.0:TEST1->TEST2, event> (Received logon response) Sep 7, 2006 3:38:22 PM quickfix.mina.initiator.InitiatorIoHandler sessionCreated INFO: MINA session created: /127.0.0.1:2295 So, I don't know. It appears the configuration file is fine. I'm running out of theories about why you are seeing different behavior on your system. I haven't had anyone else report this specific kind of problem. If you have any other ideas, I'll give you whatever support I can to resolve the problem.

            People

            • Assignee:
              admin Steve Bate
              Reporter:
              ksamuel kevin samuel
            • Votes:
              0 Vote for this issue
              Watchers:
              0 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: