1

We are using quickfixj in our system via apache camel:

        <dependency>
            <groupId>org.apache.camel</groupId>
            <artifactId>camel-quickfix</artifactId>
            <version>${camel.version}</version>
        </dependency>

We are now trying to troubleshoot the problem with our FIX channel and want to understand where the delay with message communication is – in our network while sending the message or on the bank side.

quickfixj has an outgoing message logging but the problem is logging is done before sending the message and the message itself then sent asynchronously

private boolean send(String messageString) {
        getLog().onOutgoing(messageString); // message is logged here
        ...
        return responder.send(messageString); // async sent inside 
    }

So is there any way to make some log only after the message is sent? This way we will understand if there is really some delay between the first log and actually sending the message and what time that sending takes.

Thanks.

UPD: Based on Christoph's answer, trying the following:

val engine = (camelContext.getEndpoint(fixConfiguration.fixEndpoint) as QuickfixjEndpoint).engine
engine::class.java.getDeclaredField("acceptor").let {
   it.isAccessible = true
   val acceptor = it.get(engine) as SessionConnector

   val loggingFilter = LoggingFilter()
   loggingFilter.sessionOpenedLogLevel = LogLevel.NONE // don't log this event
   loggingFilter.sessionCreatedLogLevel = LogLevel.NONE // don't log this event
   acceptor.setIoFilterChainBuilder { chain -> chain.addLast("LoggingFilter", loggingFilter) }
}
Christoph John
  • 3,003
  • 2
  • 13
  • 23
Maksim Vorontsov
  • 799
  • 8
  • 18
  • Have you tried turning on DEBUG logging? I think MINA should log the message when it is sent out. MINA is the underlying communication framework. – Christoph John Feb 12 '21 at 14:18
  • Hey, thanks for the quick response. Just tried to turn on trace for `org.apache.mina` but only can see in logs `Processing a MESSAGE_RECEIVED for session `. No info on outgoing messages – Maksim Vorontsov Feb 12 '21 at 14:26
  • Hmm need to check in the code later. IIRC there is a message encoder which should be called. But it is in QFJ code. Try turning on DEBUG for org.quickfixj. Don't want to browse the code on my phone now. ;) Might check later if there are other options beside Wireshark. – Christoph John Feb 12 '21 at 16:25

1 Answers1

1

I tested around a little bit and think the way to go would be to employ a org.apache.mina.filter.logging.LoggingFilter.

I assume you are using an Initiator but it will of course also work with an Acceptor.

LoggingFilter loggingFilter = new LoggingFilter();
loggingFilter.setSessionOpenedLogLevel(LogLevel.NONE);   // don't log this event
loggingFilter.setSessionCreatedLogLevel(LogLevel.NONE);  // don't log this event
initiator.setIoFilterChainBuilder(chain -> chain.addLast("LoggingFilter", loggingFilter));

This will create events like these in your log:

Feb 13, 2021 1:05:11 AM org.apache.mina.filter.logging.LoggingFilter log
INFO: SENT: 8=FIX.4.29=6735=A34=149=TW52=20210213-00:05:11.18456=ISLD98=0108=30141=Y10=244
...
Feb 13, 2021 1:05:11 AM org.apache.mina.filter.logging.LoggingFilter log
INFO: RECEIVED: 8=FIX.4.29=6735=A34=149=ISLD52=20210213-00:05:11.22456=TW98=0108=30141=Y10=239
Christoph John
  • 3,003
  • 2
  • 13
  • 23
  • Seems like that I actually need, but do you know if there is a way to configure it while using `camel-quickfix-starter`? Actually cannot find a way to obtain already created acceptor as we are totally relying on `QuickfixjComponentAutoConfiguration` – Maksim Vorontsov Feb 14 '21 at 17:21
  • Just tried to find out what your possiblities are with `camel-quickfix-starter` but indeed it looks like you cannot get hold of the connector to set the desired options. :( So I think at the moment the most straight-forward way will be to analyse this using tcpdump which should show exactly when the message is sent out. But I understand that this is not what you originally wanted. Maybe someone with more experience with Apache Camel can suggest other options. But you have no more logging than the QFJ logging available? Camel does not log anything useful? – Christoph John Feb 15 '21 at 12:01
  • BTW, you can set `SocketSynchronousWrites=Y` to force synchronous sending, but not sure how that will help you further. How big are your delays BTW? What is the `52=SendingTime` on your received `Logon` message compared to your local time? – Christoph John Feb 15 '21 at 12:03
  • 1
    Edited my question, I found the only `hacky` way to achieve this. Will test today and let you know if it works :) – Maksim Vorontsov Feb 15 '21 at 12:36
  • LOL, I didn't dare to suggest you something like that. ;) – Christoph John Feb 15 '21 at 13:22
  • 1
    That worked, thank you very much! We need this just for a few days to see if there is an issue or not, so that approach will do its job :D Ofc, not a long term solution – Maksim Vorontsov Feb 15 '21 at 14:59
  • 1
    Glad to hear that. Let me know if there are any other QFJ related issues. – Christoph John Feb 15 '21 at 18:14