APAR status
Closed as program error.
Error description
An IBM MQ 9.3.0.1 Managed File Transfer agent has been configured with one or more resource monitors defined. In order to investigate an issue, the agent is configured to generate a trace from startup using the steps shown in the: Collecting a Managed File Transfer agent trace from startup topic in the MQ 9.3 sections of IBM Documentation (the URI of this topic is https://www.ibm.com/docs/en/ibm-mq/9.3?topic=tmftam-collecting-m anaged-file-transfer-agent-trace-from-startup). When the fteStartAgent command is run, the agent process appears to start successfully. However, the agent is unresponsive and is unable to perform any managed transfer requests, and the resource monitors that have been defined on it do not run. A Javacore taken when the issue occurs shows that there is a deadlock between two threads, as shown in the example below: Thread 1: ------------- "RecoveryThread" ... ... Blocked on: java/util/logging/FileHandler@0x00000000E0098C38 Owned by: "pool-1-thread-1" (J9VMThread:0x000000000056D000, java/lang/Thread:0x00000000FFEB6E20) ... Java callstack: at java/util/logging/FileHandler.publish(FileHandler.java:726(Compi led Code)) (entered lock: java/util/logging/FileHandler@0x00000000E0098C38, entry count: 1) at java/util/logging/Logger.log(Logger.java:749(Compiled Code)) at java/util/logging/Logger.doLog(Logger.java:776(Compiled Code)) at java/util/logging/Logger.logp(Logger.java:996) at com/ibm/msg/client/commonservices/j2se/trace/DefaultTracer.trace Data(DefaultTracer.java:414) at com/ibm/msg/client/commonservices/trace/Trace.traceDataInternal( Trace.java:1277(Compiled Code)) at com/ibm/msg/client/commonservices/trace/Trace.data(Trace.java:11 14) at com/ibm/wmqfte/ras/impl/WMQTraceHandler.publish(WMQTraceHandler. java:289(Compiled Code)) at java/util/logging/Logger.log(Logger.java:749(Compiled Code)) at com/ibm/wmqfte/ras/impl/TraceImpl.dataImplementation(TraceImpl.j ava:176) at com/ibm/wmqfte/ras/Trace.data(Trace.java:321) at com/ibm/wmqfte/utils/FTEPlatformUtils.isEmbeddedAgent(FTEPlatfor mUtils.java:168) at com/ibm/wmqfte/ras/impl/ResourceMonitorLogFormatter.format(Resou rceMonitorLogFormatter.java:96) (entered lock: com/ibm/wmqfte/ras/impl/ResourceMonitorLogFormatter@0x00000000E0 293A78, entry count: 1) at java/util/logging/StreamHandler.publish(StreamHandler.java:222(C ompiled Code)) (entered lock: com/ibm/wmqfte/ras/impl/SecureFileHandler@0x00000000E0291FD0, entry count: 2) at com/ibm/wmqfte/ras/impl/SecureFileHandler.publish(SecureFileHand ler.java:231) (entered lock: com/ibm/wmqfte/ras/impl/SecureFileHandler@0x00000000E0291FD0, entry count: 1) at com/ibm/wmqfte/ras/impl/ResourceMonitorLogHandler.publish(Resour ceMonitorLogHandler.java:216) at java/util/logging/Logger.log(Logger.java:749(Compiled Code)) at com/ibm/wmqfte/ras/impl/TraceImpl.dataImplementation(TraceImpl.j ava:176) at com/ibm/wmqfte/ras/Trace.data(Trace.java:267) at com/ibm/wmqfte/monitor/management/MonitorManager.startMonitor(Mo nitorManager.java:814) at com/ibm/wmqfte/monitor/management/MonitorManager.registerMonitor (MonitorManager.java:1353) at com/ibm/wmqfte/monitor/management/MonitorManager.recoveryMonitor (MonitorManager.java:1193) at com/ibm/wmqfte/agent/AgentRecoveryRunnable.recoverResourceMonito r(AgentRecoveryRunnable.java:1024) at com/ibm/wmqfte/agent/AgentRecoveryRunnable.run(AgentRecoveryRunn able.java:279) at java/lang/Thread.run(Thread.java:830) at com/ibm/wmqfte/thread/FTEThread.run(FTEThread.java:70) Thread 2: ------------- "pool-1-thread-1" .... .... Blocked on: com/ibm/wmqfte/ras/impl/SecureFileHandler@0x00000000E0291FD0 Owned by: "RecoveryThread" (J9VMThread:0x00000000004FD000, java/lang/Thread:0x00000000E04ADDF8) ... Java callstack: at com/ibm/wmqfte/ras/impl/SecureFileHandler.publish(SecureFileHand ler.java:231) (entered lock: com/ibm/wmqfte/ras/impl/SecureFileHandler@0x00000000E0291FD0, entry count: 1) at com/ibm/wmqfte/ras/impl/ResourceMonitorLogHandler.publish(Resour ceMonitorLogHandler.java:216) at java/util/logging/Logger.log(Logger.java:749(Compiled Code)) at com/ibm/wmqfte/ras/impl/TraceImpl.entryImplementation(TraceImpl. java:79(Compiled Code)) at com/ibm/wmqfte/ras/Trace.entry(Trace.java:121) at com/ibm/wmqfte/monitor/configuration/ResourcesConfiguration.getR esourceConfigurations(ResourcesConfiguration.java:436) at com/ibm/wmqfte/monitor/configuration/ResourcesConfiguration.toSt ring(ResourcesConfiguration.java:470) at com/ibm/wmqfte/monitor/configuration/MonitorConfiguration.toStri ng(MonitorConfiguration.java:465) at java/lang/String.valueOf(String.java:3467(Compiled Code)) at java/lang/StringBuilder.append(StringBuilder.java:537) at com/ibm/wmqfte/monitor/management/MonitorImpl.toString(MonitorIm pl.java:346) at java/lang/String.valueOf(String.java:3467(Compiled Code)) at com/ibm/msg/client/commonservices/j2se/trace/TraceUtils$GenericF ormatAdapter.formatObject(TraceUtils.java:492(Compiled Code)) at com/ibm/msg/client/commonservices/j2se/trace/TraceUtils.formatOb ject(TraceUtils.java:97) at com/ibm/msg/client/commonservices/j2se/trace/HumanFormatter$Entr yFormatAdapter.formatRecord(HumanFormatter.java:938(Compiled Code)) at com/ibm/msg/client/commonservices/j2se/trace/HumanFormatter$Mess ageFormatAdapter.formatRecord(HumanFormatter.java:1330(Compiled Code)) at com/ibm/msg/client/commonservices/j2se/trace/HumanFormatter.form at(HumanFormatter.java:355(Compiled Code)) at java/util/logging/StreamHandler.publish(StreamHandler.java:222(C ompiled Code)) (entered lock: java/util/logging/FileHandler@0x00000000E0098C38, entry count: 2) at java/util/logging/FileHandler.publish(FileHandler.java:729(Compi led Code)) (entered lock: java/util/logging/FileHandler@0x00000000E0098C38, entry count: 1) at java/util/logging/Logger.log(Logger.java:749(Compiled Code)) at java/util/logging/Logger.doLog(Logger.java:776(Compiled Code)) at java/util/logging/Logger.logp(Logger.java:1022) at com/ibm/msg/client/commonservices/j2se/trace/DefaultTracer.metho dEntry(DefaultTracer.java:389) at com/ibm/msg/client/commonservices/trace/Trace.methodEntryInterna l(Trace.java:810(Compiled Code)) at com/ibm/msg/client/commonservices/trace/Trace.entry(Trace.java:7 45(Compiled Code)) at com/ibm/wmqfte/ras/impl/WMQTraceHandler.publish(WMQTraceHandler. java:266(Compiled Code)) at java/util/logging/Logger.log(Logger.java:749(Compiled Code)) at com/ibm/wmqfte/ras/impl/TraceImpl.entryImplementation(TraceImpl. java:79(Compiled Code)) at com/ibm/wmqfte/ras/Trace.entry(Trace.java:153) at com/ibm/wmqfte/monitor/management/MonitorTimerTask.run(MonitorTi merTask.java:71) at java/util/concurrent/Executors$RunnableAdapter.call(Executors.ja va:522) at java/util/concurrent/FutureTask.runAndReset(FutureTask.java:319) at java/util/concurrent/ScheduledThreadPoolExecutor$ScheduledFuture Task.access$301(ScheduledThreadPoolExecutor.java:191) at java/util/concurrent/ScheduledThreadPoolExecutor$ScheduledFuture Task.run(ScheduledThreadPoolExecutor.java:305) at java/util/concurrent/ThreadPoolExecutor.runWorker(ThreadPoolExec utor.java:1160) at java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExe cutor.java:635) at java/lang/Thread.run(Thread.java:830) at com/ibm/wmqfte/ras/impl/WMQTraceHandler.publish(WMQTraceHandler. java:266(Compiled Code)) at java/util/logging/Logger.log(Logger.java:749(Compiled Code)) at com/ibm/wmqfte/ras/impl/TraceImpl.entryImplementation(TraceImpl. java:79(Compiled Code)) at com/ibm/wmqfte/ras/Trace.entry(Trace.java:153) at com/ibm/wmqfte/monitor/management/MonitorTimerTask.run(MonitorTi merTask.java:71) at java/util/concurrent/Executors$RunnableAdapter.call(Executors.ja va:522) at java/util/concurrent/FutureTask.runAndReset(FutureTask.java:319) at java/util/concurrent/ScheduledThreadPoolExecutor$ScheduledFuture Task.access$301(ScheduledThreadPoolExecutor.java:191) at java/util/concurrent/ScheduledThreadPoolExecutor$ScheduledFuture Task.run(ScheduledThreadPoolExecutor.java:305) at java/util/concurrent/ThreadPoolExecutor.runWorker(ThreadPoolExec utor.java:1160) at java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExe cutor.java:635) at java/lang/Thread.run(Thread.java:830)
Local fix
Problem summary
**************************************************************** USERS AFFECTED: This issue affects users of MQ 9.3.0.1 Managed File Transfer (MFT) who have agents that: - Have one or more resource monitors defined. - And have been configured with the agent property: trace=<trace_specification> set, to generate trace from startup. Platforms affected: MultiPlatform **************************************************************** PROBLEM DESCRIPTION: APAR IT41603 [https://www.ibm.com/support/pages/apar/IT41603] resolved a deadlock that could occur when an MQ Managed File Transfer (MFT) agent that had one or more resource monitors defined was started up with trace enabled. The fix for this issue was included in MQ 9.3.0.1. However, shortly after that Fix Pack was released, it was found that the fix did not completely resolve the deadlock. This meant that the issue could still be seen when using MQ 9.3.0.1.
Problem conclusion
To resolve this issue, the original fix for IT41603 has been reworked to include some additional changes to the internal trace mechanism which prevent the deadlock from occurring. --------------------------------------------------------------- The fix is targeted for delivery in the following PTFs: Version Maintenance Level v9.3 LTS 9.3.0.2 v9.x CD 9.3.2 The latest available maintenance can be obtained from 'WebSphere MQ Recommended Fixes' http://www-1.ibm.com/support/docview.wss?rs=171&uid=swg27006037 If the maintenance level is not yet available information on its planned availability can be found in 'WebSphere MQ Planned Maintenance Release Dates' http://www-1.ibm.com/support/docview.wss?rs=171&uid=swg27006309 ---------------------------------------------------------------
Temporary fix
Comments
APAR Information
APAR number
IT42253
Reported component name
MQ BASE V9.3
Reported component ID
5724H7291
Reported release
930
Status
CLOSED PER
PE
NoPE
HIPER
NoHIPER
Special Attention
NoSpecatt / Xsystem
Submitted date
2022-10-13
Closed date
2022-10-20
Last modified date
2022-10-20
APAR is sysrouted FROM one or more of the following:
APAR is sysrouted TO one or more of the following:
Fix information
Fixed component name
MQ BASE V9.3
Fixed component ID
5724H7291
Applicable component levels
[{"Business Unit":{"code":"BU059","label":"IBM Software w\/o TPS"},"Product":{"code":"SSYHRD","label":"IBM MQ"},"Platform":[{"code":"PF025","label":"Platform Independent"}],"Version":"9.3","Line of Business":{"code":"LOB45","label":"Automation"}}]
Document Information
Modified date:
21 October 2022