MFT Taking 6 Minutes 1 Second To Release Connection From Remote Sftp Server (Doc ID 2692764.1)

Last updated on MAY 15, 2023

Applies to:

Symptoms

On : 12.2.1.3.0 version, MFT Runtime Server

ACTUAL BEHAVIOR
---------------
MFT taking longer time to release connection from remote sftp server
 

EXPECTED BEHAVIOR
-----------------------
MFT should not be taking so long to release the connection

From the logs we could see delay in the process on close waiting.

mft_server1-mft-diagnostic-xxxxx.log

[2020-06-22T09:12:55.130-03:00] [mft_server1] [NOTIFICATION] [] [oracle.mft.TRANSPORT] [tid: JCA-work-instance:FTP Adapter-2] [userId: ] [ecid: 17845edd-60a2-423a-bcfd-c8bab6b4038c-00001dc8,0] [APP: mft-app] [partition-name: DOMAIN] [tenant-name: GLOBAL] [FlowId: 0000NBRwXMG5i^W5xzO5yW1Uw9wM000001] oracle.mft.TRANSPORT.: Endpoint is in development mode
...
...

[2020-06-22T09:12:57.002-03:00] [mft_server1] [TRACE] [] [oracle.mft.adapter.ftp] [tid: JCA-work-instance:JMSAdapter-7] [userId: ] [ecid: 17845edd-60a2-423a-bcfd-c8bab6b4038c-00001dc8,0:7:226:19] [APP: mft-app] [partition-name: DOMAIN] [tenant-name: GLOBAL] [FlowId: 0000NBRwXMG5i^W5xzO5yW1Uw9wM000001] [SRC_CLASS: oracle.tip.adapter.ftp.SFTPClient] [SRC_METHOD: checkDirAvailability] Closing sftp channel
...
...
mft_server1-mft-diagnostic-xxxxx.log

[2020-06-22T09:15:57.094-03:00] [mft_server1] [TRACE] [] [oracle.mft.adapter.ftp] [tid: JCA-work-instance:JMSAdapter-7] [userId: ] [ecid: 17845edd-60a2-423a-bcfd-c8bab6b4038c-00001dc8,0:7:226:19] [APP: mft-app] [partition-name: DOMAIN] [tenant-name: GLOBAL] [FlowId: 0000NBRwXMG5i^W5xzO5yW1Uw9wM000001] [SRC_CLASS: oracle.tip.adapter.ftp.SFTPClient] [SRC_METHOD: checkDirAvailability] Closed sftp channel
...
...
[2020-06-22T09:15:57.802-03:00] [mft_server1] [TRACE] [] [oracle.mft.adapter.ftp] [tid: JCA-work-instance:JMSAdapter-7] [userId: ] [ecid: 17845edd-60a2-423a-bcfd-c8bab6b4038c-00001dc8,0:7:226:19] [APP: mft-app] [partition-name: DOMAIN] [tenant-name: GLOBAL] [FlowId: 0000NBRwXMG5i^W5xzO5yW1Uw9wM000001] [SRC_CLASS: oracle.tip.adapter.ftp.SFTPClient] [SRC_METHOD: storeFileAsStream] Closing sftp channel
...
....

mft_server1-mft-diagnostic-xxxxx.log

[2020-06-22T09:18:57.865-03:00] [mft_server1] [TRACE] [] [oracle.mft.adapter.ftp] [tid: JCA-work-instance:JMSAdapter-7] [userId: ] [ecid: 17845edd-60a2-423a-bcfd-c8bab6b4038c-00001dc8,0:7:226:19] [APP: mft-app] [partition-name: DOMAIN] [tenant-name: GLOBAL] [FlowId: 0000NBRwXMG5i^W5xzO5yW1Uw9wM000001] [SRC_CLASS: oracle.tip.adapter.ftp.SFTPClient] [SRC_METHOD: storeFileAsStream] Closed sftp channel
...
...
[2020-06-22T09:18:57.868-03:00] [mft_server1] [NOTIFICATION] [] [oracle.mft.TRANSPORT] [tid: JCA-work-instance:JMSAdapter-7] [userId: ] [ecid: 17845edd-60a2-423a-bcfd-c8bab6b4038c-00001dc8,0:7:226:19] [APP: mft-app] [partition-name: DOMAIN] [tenant-name: GLOBAL] [FlowId: 0000NBRwXMG5i^W5xzO5yW1Uw9wM000001] oracle.mft.TRANSPORT.: Time taken in file transfer = [361779]

Tracking with ecid with TRACE logs:
In this case we could see the transfer starting at 2020-06-22T09:12:55.

There are pauses noted around 2020-06-22T09:12:57.002-03:00 (Closing sftp channel) before it again resumed at 2020-06-22T09:15:57.094-03:00 (Closed sftp channel)
Again it was seen pausing at 2020-06-22T09:15:57.802-03:00 (Closing sftp channel) before again resuming at 2020-06-22T09:18:57.865-03:00 (Closed sftp channel)

Later the transfer was completed at 2020-06-22T09:18:57.868-03:00


Basically transfer is taking less time but it is taking longer time waiting to close the sftp channel (in the logs "Closing sftp channel").

Changes

Cause

My Oracle Support provides customers with access to over a million knowledge articles and a vibrant support community of peers and Oracle experts.