QuickFixJ应用异常：FIX日志有消息但Java未接收的排查与解决

我们有一款运行数月的QuickFixJ Java应用，近期从Windows服务器迁移至Unix服务器后出现异常：订单执行消息已记录在FIX消息日志中，但未被应用的QuickFixJ MessageCracker接收，且日志中无35=3拒绝消息。以下是详细异常情况及后续排查动作：

首次异常（2023-05-15） #

交易消息于20230515-16:08:45.677记录在FIX日志，但同期事件日志无相关记录，半分钟后出现如下日志：

20230515-12:43:35: Sent SequenceReset TO: 7 
20230515-16:09:31: Sent test request TEST 
20230515-16:09:58: Disconnecting: Timed out waiting for heartbeat 
20230515-16:09:58: java.lang.reflect.UndeclaredThrowableException 
java.lang.reflect.UndeclaredThrowableException at 
com.sun.proxy.$Proxy183.onConnect(Unknown Source) at 
quickfix.Session.setResponder(Session.java:567)

未被Java代码接收的消息日志示例：

8=FIX.4.49=37835=849=XXXX56=VVVV34=93852=20230515-16:08:45.69337=17070005240=2526=BI-710202-I11=41F5517A-0563-6F62-1CB0C34522E02B8B453=1448=307802=1523=VVVV382=1375=307337=VVVV17=1707000_29009=792443150=F39=21=L1068955=STAC48=CI000000035222=454=238=9040=244=19559=6432=2023051532=9031=195151=014=906=060=20230515-16:08:45.537381=17550.00111=010=056

次日异常（2023-05-16） #

FIX消息于20230516-10:48:46.816记录在日志：

8=FIX.4.49=39735=849=vvv56=xxx34=137852=20230516-10:48:46.81637=17070255240=1526=CI-710206-I11=6A1FAA42-0453-1001-0FAA9A63AD1F0620453=1448=307802=1523=xxx17=1707025_1150=039=01=L1068955=NSBC48=CI000000241622=454=138=140=244=338059=0151=114=06=060=20230516-10:48:46.660111=158=Entr?e de l'ordre: Ordre ? cours limit?, Achat 1 actions NSBC ? 3?380,00, ordre valable jour.10=111

同期事件日志如下：

20230516-08:57:40: Received ResendRequest FROM: 2 TO: infinity
20230516-08:57:40: Resending message: 2
20230516-08:57:40: Resending message: 3
20230516-08:57:40: Resending message: 4
20230516-08:57:40: Resending message: 5
20230516-08:57:40: Sent SequenceReset TO: 7
20230516-10:40:29: Sent test request TEST
20230516-10:44:52: Sent test request TEST
20230516-10:46:55: Sent test request TEST
20230516-10:48:03: Sent test request TEST
20230516-10:49:12: Sent test request TEST
20230516-10:49:26: Reject sent for message 1340: SendingTime     accuracy problem:52
20230516-10:49:26: Reject sent for message 1341: SendingTime     accuracy problem:52
20230516-10:49:26: Reject sent for message 1342: SendingTime accuracy problem:52
20230516-10:49:26: Reject sent for message 1343: SendingTime accuracy problem:52
20230516-10:49:26: Reject sent for message 1344: SendingTime accuracy problem:52
20230516-10:49:26: Reject sent for message 1345: SendingTime accuracy problem:52
20230516-10:49:26: Reject sent for message 1346: SendingTime accuracy problem:52
20230516-10:49:26: Reject sent for message 1347: SendingTime accuracy problem:52
20230516-10:49:30: Disconnecting: Timed out waiting for logout response

该消息同样未被Java代码接收，同时事件日志出现Session状态异常：

20230516-10:49:31: quickfix.SessionException Logon state is not 
valid for message (MsgType=AE)
20230516-10:49:31: Already disconnected: Verifying message failed:       quickfix.SessionException: Logon state is not valid for message (MsgType=AE)
20230516-10:49:31: quickfix.SessionException Logon state is not valid for message (MsgType=W)
20230516-10:49:31: Already disconnected: Verifying message failed: quickfix.SessionException: Logon state is not valid for message (MsgType=W)

排查尝试 #

已添加配置CheckLatency=N避免时间差异导致断开连接，但问题仍存在：订单市场回复时间早于下单请求数秒，导致Java监听器接收消息延迟，尽管FIX日志已记录该消息。

问题原因分析 #

1. 时间同步问题：迁移到Unix服务器后，服务器时间与FIX对手方时间未同步，导致SendingTime校验失败，触发消息拒绝和Session断开。断开后收到的消息无法进入正常处理流程，只能被记录到日志但无法被MessageCracker接收。
2. Session状态异常：Session因心跳超时或时间校验问题断开后，后续接收的消息会被Session层拦截（因状态不合法），不会转发给MessageCracker处理，仅记录到日志。
3. 时区/时间格式差异：Windows与Unix系统的时区或时间处理方式不同，导致消息中的时间戳（如52字段）在Session层校验时出现偏差，引发一系列异常。
4. 消息序列混乱：SequenceReset操作后，消息序列可能出现不一致，导致后续消息无法被正确识别和转发。

预防与解决方案 #

• 强制时间同步：在Unix服务器上配置NTP服务，确保服务器时间与对手方服务器时间误差控制在毫秒级，避免SendingTime校验失败。
• 调整FIX会话配置：
  • 除CheckLatency=N外，可配置TimeWindow参数放宽时间校验的容忍范围（如TimeWindow=120，允许2分钟的时间偏差）。
  • 合理设置心跳间隔（HeartBtInt）和测试请求超时时间，减少因网络波动导致的Session断开。
• Session状态监控与自动恢复：添加Session状态监听，当检测到Session断开时，自动触发重连逻辑，并在重连完成后检查消息序列一致性，必要时发起ResendRequest。
• 优化消息处理线程：检查MessageCracker的消息处理逻辑，避免阻塞线程导致消息堆积；确保QuickFixJ的线程池配置足够处理峰值消息量。
• 迁移后环境验证：在正式迁移前，在Unix测试环境中验证时间同步、时区设置、Session稳定性等关键指标，确保与Windows环境行为一致。
• 增强日志监控：添加Session层和MessageCracker层的详细日志，记录消息从接收至转发的全流程，便于快速定位异常点。

内容的提问来源于stack exchange，提问作者user666