[QFJ-62] Session Initiator Fails with "Connection failed: Failed to get the session." Created: 05/Sep/06  Updated: 22/Sep/06  Resolved: 22/Sep/06

Status: Closed
Project: QuickFIX/J
Component/s: Networking
Affects Version/s: 1.0.0 Final, 1.0.1, 1.0.2, 1.0.3
Fix Version/s: None

Type: Other Priority: Default
Reporter: kevin samuel Assignee: Steve Bate
Resolution: Fixed Votes: 0
Labels: None
Environment:

Win 2k3 Server, Dell 2650 Dual 2.4Ghz 2GB Ram, BEA jrockit-R26.3.0-jdk1.5.0_06

Attachments: File JFIX.cfg    

 Description   

I tried posting this to the Mailing list, but was rejected:
Failed to deliver to '[email protected]'
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 ( [email protected] )
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

 Comments   
Comment by Steve Bate [ 06/Sep/06 ]

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?

Comment by Steve Bate [ 06/Sep/06 ]

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.

Comment by Steve Bate [ 07/Sep/06 ]

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.

Generated at Fri May 17 05:56:37 UTC 2024 using JIRA 7.5.2#75007-sha1:9f5725bb824792b3230a5d8716f0c13e296a3cae.