[Michael Chong]

Dear CFT Experts,
I'm trying to simulate the ability of CFT to resume a previously-interrupted file transfer due to network connectivity failure. Network connectivity failure is simulated by unplugging the network cable from the receiving CFT's machine. The interrupted file transfer did resume upon plug-in of the network cable again to the receiving CFT's machine, but the very first retry from the Sender CFT to the Receiver CFT would always be considered a retry failure. The Sender CFT's log file (as attached) would contain the following entries before and after the error at 14:58:22:

10/07/29 14:50:37 CFTS20I Communication file row number deleted: 00000064
10/07/29 14:50:37 CFTI34I PID=1012 CFTTFIL Task started successfully
10/07/29 14:50:38 CFTT57I Requester transfer started <IDTU=A000005Y PART=CFT_HQ IDF=JKT_TO_HQ IDT=G2914503 >
10/07/29 14:51:21 CFTT82E transfer aborted <IDTU=A000005Y PART=CFT_HQ IDF=JKT_TO_H IDT=G2914503 302 R 0 2f0>
10/07/29 14:51:21 CFTT88I+<IDTU=A000005Y FNAME=F:\\Sentinel_3.3.0_all_SP8_1006011115.jar NBC=16667648>
10/07/29 14:52:21 CFTI35I PID=1012 CFTTFIL Task ended
10/07/29 14:52:40 CFTI34I PID=4508 CFTTFIL Task started successfully
10/07/29 14:53:01 CFTH10E Network connect reject <PART=CFT_HQ RECOV=0 L=0 R=0 D=280 NET=TCP>
10/07/29 14:53:01 CFTT75E connect reject <IDTU=A000005Y PART=CFT_HQ IDF=JKT_TO_H IDT=G2914503 302 R 00 280>
10/07/29 14:53:01 CFTT88I+<IDTU=A000005Y FNAME=F:\\Sentinel_3.3.0_all_SP8_1006011115.jar NBC=0>
10/07/29 14:54:01 CFTI35I PID=4508 CFTTFIL Task ended
10/07/29 14:54:02 CFTI34I PID=3612 CFTTFIL Task started successfully
10/07/29 14:58:22 CFTH11E Error Opening session <PART=CFT_HQ EV=VVTIMO ST=CN0022>
10/07/29 14:58:22 CFTT75E connect reject <IDTU=A000005Y PART=CFT_HQ IDF=JKT_TO_H IDT=G2914503 302 TIMEOUT>
10/07/29 14:58:22 CFTT88I+<IDTU=A000005Y FNAME=F:\\Sentinel_3.3.0_all_SP8_1006011115.jar NBC=0>
10/07/29 14:59:00 CFTT57I Requester transfer started <IDTU=A000005Y PART=CFT_HQ IDF=JKT_TO_HQ IDT=G2914503 >
10/07/29 15:00:55 CFTT58I Requester transfer ended <IDTU=A000005Y PART=CFT_HQ IDF=JKT_TO_HQ IDT=G2914503>
10/07/29 15:00:55 CFTT88I+<IDTU=A000005Y FNAME=F:\\Sentinel_3...._1006011115.jar NBC=81856473>
10/07/29 15:00:58 CFTT59I Server reply transfered <IDTU=00000000 PART=CFT_HQ IDM=JKT_TO_HQ IDT=G2914503>
10/07/29 15:01:58 CFTI35I PID=3612 CFTTFIL Task ended

On the Receiver CFT side, the log file (as attached) would contain the following entries before and after error at 14:54:34:

10/07/29 14:51:06 CFTI34I PID=24620 CFTTFIL Task started successfully
10/07/29 14:51:06 CFTT57I Server transfer started <IDTU=A0000012 PART=CFT_JKT IDF=JKT_TO_HQ IDT=G2914503 >
10/07/29 14:51:40 CFTT82E transfer aborted <IDTU=A0000012 PART=CFT_JKT IDF=JKT_TO_H IDT=G2914503 302 R 9 e01>
10/07/29 14:51:40 CFTT88I+<IDTU=A0000012 FNAME=recv\Sentinel_3.3.0_all_SP8_1006011115.jar NBC=16647168>
10/07/29 14:52:40 CFTI35I PID=24620 CFTTFIL Task ended
10/07/29 14:54:34 CFTH19E Incoming call accept error <NCR=-29 NCS=00010054 NET=TCP>
10/07/29 14:59:28 CFTI34I PID=24936 CFTTFIL Task started successfully
10/07/29 14:59:28 CFTT57I Server transfer started <IDTU=A0000012 PART=CFT_JKT IDF=JKT_TO_HQ IDT=G2914503 >
10/07/29 15:01:24 CFTT58I Server transfer ended <IDTU=A0000012 PART=CFT_JKT IDF=JKT_TO_HQ IDT=G2914503>
10/07/29 15:01:24 CFTT88I+<IDTU=A0000012 FNAME=recv\Sentinel_3..._1006011115.jar NBC=81856473>
10/07/29 15:01:24 CFTS03I _ d:\Axway\Synchrony\Transfer_CFT\runtime\exec\RCV_ACK.bat executed <IDTU=A0000012 PART=CFT_JKT IDF=JKT_TO_HQ IDT=G2914503>
10/07/29 15:01:26 CFTS20I Communication file row number deleted: 00000021
10/07/29 15:01:26 CFTT59I Requester reply transfered <IDTU=A0000013 PART=CFT_JKT IDM=G2914503 IDT=G2915012>
10/07/29 15:02:26 CFTI35I PID=24936 CFTTFIL Task ended

The file transfer would ultimately be completed successfully with the next retry as can be observed above, but if there's no more retry for this transfer, it's considered a failed transfer.

Another issue I have observed is when I unplug the network cable of the Sender CFT's machine (different from the above scenario where I unplugged the Receiver CFT's machine). In this case, the elapsed time before the very first retry upon network connection resumption took almost 5 minutes (i.e. network connection resumption was done at about 14:42:37 and retry only at 14:47:20 below):

10/07/29 14:40:33 CFTS20I Communication file row number deleted: 00000063
10/07/29 14:40:33 CFTI34I PID=5620 CFTTFIL Task started successfully
10/07/29 14:40:34 CFTT57I Requester transfer started <IDTU=A000005X PART=CFT_HQ IDF=JKT_TO_HQ IDT=G2914403 >
10/07/29 14:41:01 CFTT82E transfer aborted <IDTU=A000005X PART=CFT_HQ IDF=JKT_TO_H IDT=G2914403 302 R 9 e01>
10/07/29 14:41:01 CFTT88I+<IDTU=A000005X FNAME=F:\\Sentinel_3.3.0_all_SP8_1006011115.jar NBC=13993472>
10/07/29 14:41:37 CFTH09E Network connect request local error <PART=CFT_HQ NCR=416 NCS=MAXCNX NET=TCP>
10/07/29 14:41:37 CFTT75E connect reject <IDTU=A000005X PART=CFT_HQ IDF=JKT_TO_H IDT=G2914403 416 MAXCNX>
10/07/29 14:41:37 CFTT88I+<IDTU=A000005X FNAME=F:\\Sentinel_3.3.0_all_SP8_1006011115.jar NBC=0>
10/07/29 14:42:37 CFTI35I PID=5620 CFTTFIL Task ended
10/07/29 14:47:20 CFTI34I PID=4556 CFTTFIL Task started successfully
10/07/29 14:47:21 CFTT57I Requester transfer started <IDTU=A000005X PART=CFT_HQ IDF=JKT_TO_HQ IDT=G2914403 >
10/07/29 14:49:20 CFTT58I Requester transfer ended <IDTU=A000005X PART=CFT_HQ IDF=JKT_TO_HQ IDT=G2914403>
10/07/29 14:49:20 CFTT88I+<IDTU=A000005X FNAME=F:\\Sentinel_3...._1006011115.jar NBC=81856473>
10/07/29 14:49:21 CFTT59I Server reply transfered <IDTU=00000000 PART=CFT_HQ IDM=JKT_TO_HQ IDT=G2914403>
10/07/29 14:50:21 CFTI35I PID=4556 CFTTFIL Task ended

The question here is how do I reduce this elapsed time before the very first retry upon network connection resumption? I have set the time between retries to 1 minute from the Sender CFT to the Receiver CFT ("CFT_HQ" - refer to the Sender CFT's extracted configuration as attached).

Lastly, I have also encountered an issue when using SSL for file transfers between two CFTs. There's no major issue when I unplug the network cable of the Sender CFT's machine, except for the delayed retry at 13:54:56 upon network connection resumption at about 13:50:58 below that took almost 5 minutes (similar to the non-SSL case above):

10/07/29 13:48:13 CFTS20I Communication file row number deleted: 00000059
10/07/29 13:48:13 CFTI34I PID=3644 CFTTFIL Task started successfully
10/07/29 13:48:13 CFTY08I PID=5784 CFTTSSL Task started successfully
10/07/29 13:48:13 CFTY19I PART=CFT_HQ SSL=SSLPROT1 opening client session CTX=20000d on task PID=5784
10/07/29 13:48:15 CFTY21I CTX=20000d Remote server certificate accepted ROOTID=SOPRACA
10/07/29 13:48:15 CFTY23I CTX=20000d Client certificate ID=USER1 ROOTID=SOPRACA
10/07/29 13:48:16 CFTY14I CTX=20000d PART=CFT_HQ SSL=SSLPROT2 client session established CIPHER=10 AUTH=BOTH
10/07/29 13:48:16 CFTT57I Requester transfer started <IDTU=A000005T PART=CFT_HQ IDF=JKT_TO_HQ IDT=G2913481 >
10/07/29 13:48:51 CFTY11I CTX=20000d PART=CFT_HQ SSL=SSLPROT2 Closing client SSL session
10/07/29 13:48:51 CFTT82E transfer aborted <IDTU=A000005T PART=CFT_HQ IDF=JKT_TO_H IDT=G2913481 302 R 9 e01>
10/07/29 13:48:51 CFTT88I+<IDTU=A000005T FNAME=F:\\Sentinel_3.3.0_all_SP8_1006011115.jar NBC=15904256>
10/07/29 13:49:51 CFTI35I PID=3644 CFTTFIL Task ended
10/07/29 13:49:51 CFTY09I PID=5784 CFTTSSL Task ended
10/07/29 13:49:58 CFTI34I PID=5592 CFTTFIL Task started successfully
10/07/29 13:49:58 CFTH09E Network connect request local error <PART=CFT_HQ NCR=416 NCS=MAXCNX NET=TCP>
10/07/29 13:49:58 CFTT75E connect reject <IDTU=A000005T PART=CFT_HQ IDF=JKT_TO_H IDT=G2913481 416 MAXCNX>
10/07/29 13:49:58 CFTT88I+<IDTU=A000005T FNAME=F:\\Sentinel_3.3.0_all_SP8_1006011115.jar NBC=0>
10/07/29 13:49:58 CFTN04E Synchronization error (connect reject) SSLTID=27659 _ CR=-1 CS=04822016
10/07/29 13:50:58 CFTI35I PID=5592 CFTTFIL Task ended
10/07/29 13:54:56 CFTI34I PID=312 CFTTFIL Task started successfully
10/07/29 13:54:57 CFTY08I PID=1968 CFTTSSL Task started successfully
10/07/29 13:54:57 CFTY19I PART=CFT_HQ SSL=SSLPROT1 opening client session CTX=20000f on task PID=1968
10/07/29 13:54:58 CFTY21I CTX=20000f Remote server certificate accepted ROOTID=SOPRACA
10/07/29 13:54:58 CFTY23I CTX=20000f Client certificate ID=USER1 ROOTID=SOPRACA
10/07/29 13:54:58 CFTY14I CTX=20000f PART=CFT_HQ SSL=SSLPROT2 client session established CIPHER=10 AUTH=BOTH
10/07/29 13:54:59 CFTT57I Requester transfer started <IDTU=A000005T PART=CFT_HQ IDF=JKT_TO_HQ IDT=G2913481 >
10/07/29 13:56:57 CFTT58I Requester transfer ended <IDTU=A000005T PART=CFT_HQ IDF=JKT_TO_HQ IDT=G2913481>
10/07/29 13:56:57 CFTT88I+<IDTU=A000005T FNAME=F:\\Sentinel_3...._1006011115.jar NBC=81856473>
10/07/29 13:57:00 CFTY20I PROT=PROTSSL1 SSL=SSLPROT1 opening server session CTX=210010 on task PID=1968
10/07/29 13:57:00 CFTY25I CTX=210010 remote address HOST=172.25.18.5
10/07/29 13:57:00 CFTY24I CTX=210010 Server certificate ID=USER1 ROOTID=SOPRACA
10/07/29 13:57:00 CFTY22I CTX=210010 Remote client certificate accepted ROOTID=SOPRACA
10/07/29 13:57:00 CFTY15I CTX=210010 PROT=PROTSSL1 SSL=SSLPROT1 server session established CIPHER=10 AUTH=BOTH
10/07/29 13:57:00 CFTT59I Server reply transfered <IDTU=00000000 PART=CFT_HQ IDM=JKT_TO_HQ IDT=G2913481>
10/07/29 13:57:12 CFTY11I CTX=20000f PART=CFT_HQ SSL=SSLPROT2 Closing client SSL session
10/07/29 13:57:15 CFTY12I CTX=210010 PROT=PROTSSL1 SSL=SSLPROT1 Closing server SSL session
10/07/29 13:58:00 CFTI35I PID=312 CFTTFIL Task ended
10/07/29 13:58:15 CFTY09I PID=1968 CFTTSSL Task ended

However, there's a major issue when I unplug the network cable of the Receiver CFT's machine, resulting in a failed transfer although network connection to the Receiver CFT's machine was made available before the number of retries was exhausted. The relevant erroneous entries in both the Sender and Receiver CFT's log files are in red below:

Sender CFT's log file (network connection resumption at about 14:05:29 below):

10/07/29 14:02:34 CFTS20I Communication file row number deleted: 00000060
10/07/29 14:02:34 CFTI34I PID=4876 CFTTFIL Task started successfully
10/07/29 14:02:35 CFTY08I PID=396 CFTTSSL Task started successfully
10/07/29 14:02:35 CFTY19I PART=CFT_HQ SSL=SSLPROT1 opening client session CTX=200011 on task PID=396
10/07/29 14:02:35 CFTY21I CTX=200011 Remote server certificate accepted ROOTID=SOPRACA
10/07/29 14:02:35 CFTY23I CTX=200011 Client certificate ID=USER1 ROOTID=SOPRACA
10/07/29 14:02:35 CFTY14I CTX=200011 PART=CFT_HQ SSL=SSLPROT2 client session established CIPHER=10 AUTH=BOTH
10/07/29 14:02:36 CFTT57I Requester transfer started <IDTU=A000005U PART=CFT_HQ IDF=JKT_TO_HQ IDT=G2914023 >
10/07/29 14:03:22 CFTT82E transfer aborted <IDTU=A000005U PART=CFT_HQ IDF=JKT_TO_H IDT=G2914023 240 RTO>
10/07/29 14:03:22 CFTT88I+<IDTU=A000005U FNAME=F:\\Sentinel_3.3.0_all_SP8_1006011115.jar NBC=17431040>
10/07/29 14:03:37 CFTY11I CTX=200011 PART=CFT_HQ SSL=SSLPROT2 Closing client SSL session
10/07/29 14:04:29 CFTH10E Network connect reject <PART=CFT_HQ RECOV=0 L=0 R=0 D=280 NET=TCP>
10/07/29 14:04:29 CFTT75E connect reject <IDTU=A000005U PART=CFT_HQ IDF=JKT_TO_H IDT=G2914023 302 R 00 280>
10/07/29 14:04:29 CFTT88I+<IDTU=A000005U FNAME=F:\\Sentinel_3.3.0_all_SP8_1006011115.jar NBC=0>
10/07/29 14:05:29 CFTY09I PID=396 CFTTSSL Task ended
10/07/29 14:05:29 CFTI35I PID=4876 CFTTFIL Task ended
10/07/29 14:06:02 CFTI34I PID=4928 CFTTFIL Task started successfully
10/07/29 14:06:02 CFTY08I PID=4336 CFTTSSL Task started successfully
10/07/29 14:06:02 CFTY19I PART=CFT_HQ SSL=SSLPROT1 opening client session CTX=200013 on task PID=4336
10/07/29 14:06:17 CFTH11E Error Opening session <PART=CFT_HQ EV=VVTIMO ST=SUP01>
10/07/29 14:06:17 CFTT75E connect reject <IDTU=A000005U PART=CFT_HQ IDF=JKT_TO_H IDT=G2914023 260 TIMEOUT>
10/07/29 14:06:17 CFTY11I CTX=200013 PART=CFT_HQ SSL=SSLPROT2 Closing client SSL session
10/07/29 14:06:17 CFTT88I+<IDTU=A000005U FNAME=F:\\Sentinel_3.3.0_all_SP8_1006011115.jar NBC=0>
10/07/29 14:07:17 CFTY09I PID=4336 CFTTSSL Task ended
10/07/29 14:07:17 CFTI35I PID=4928 CFTTFIL Task ended

Receiver CFT's log file:

10/07/29 14:03:03 CFTY08I PID=24516 CFTTSSL Task started successfully
10/07/29 14:03:03 CFTY20I PROT=PROTSSL1 SSL=SSLPROT1 opening server session CTX=20000e on task PID=24516
10/07/29 14:03:03 CFTY25I CTX=20000e remote address HOST=172.25.20.12
10/07/29 14:03:03 CFTY24I CTX=20000e Server certificate ID=USER1 ROOTID=SOPRACA
10/07/29 14:03:03 CFTY22I CTX=20000e Remote client certificate accepted ROOTID=SOPRACA
10/07/29 14:03:04 CFTY15I CTX=20000e PROT=PROTSSL1 SSL=SSLPROT1 server session established CIPHER=10 AUTH=BOTH
10/07/29 14:03:04 CFTI34I PID=23760 CFTTFIL Task started successfully
10/07/29 14:03:04 CFTT57I Server transfer started <IDTU=A000000W PART=CFT_JKT IDF=JKT_TO_HQ IDT=G2914023 >
10/07/29 14:03:41 CFTY12I CTX=20000e PROT=PROTSSL1 SSL=SSLPROT1 Closing server SSL session
10/07/29 14:03:41 CFTT82E transfer aborted <IDTU=A000000W PART=CFT_JKT IDF=JKT_TO_H IDT=G2914023 302 R 9 e01>
10/07/29 14:03:41 CFTT88I+<IDTU=A000000W FNAME=recv\Sentinel_3.3.0_all_SP8_1006011115.jar NBC=17414656>
10/07/29 14:04:41 CFTY09I PID=24516 CFTTSSL Task ended
10/07/29 14:04:41 CFTI35I PID=23760 CFTTFIL Task ended
10/07/29 14:06:35 CFTH19E Incoming call accept error <NCR=-29 NCS=00010054 NET=TCP>
10/07/29 14:06:35 CFTN04E Synchronization error (connect reject) SSLTID=28681 _ CR=-1 CS=04868096

As mentioned, this error caused the transfer to fail and as a result, no retries were performed after that. The surprising thing about this failed transfer is that it could be completed successfully upon manual re-start from the copilot catalog.

Thanks for any help,
Michael Chong
Axway Singapore

Attached File(s)

 cftext_sender.txt ( 40.72K ) Number of downloads: 2
 sender_cftlog.txt ( 20.64K ) Number of downloads: 0
 receiver_cftlog.txt ( 17.96K ) Number of downloads: 0