RE: SFTP client via PASE, large files possibly timing out -- MIDRANGE-L

I increased the timeout setting in the expect script from 30 to 90.
set timeout 90
I'm now seeing 100% in the output.

However, the code used to copy output is truncating, only 16 records copied, which I believe is now giving I believe a false error.

sftp> lcd /BRC/TOA
sftp> put BRCSAI_1105_1310 to_toa/inventory_upload/BRCSAI_1105_1310
Uploading BRCSAI_1105_1310 to /to_toa/inventory_upload/BRCSAI_1105_1310

BRCSAI_1105_1310 0% 0 0.0KB/s --:-- ETA
BRCSAI_1105_1310 1% 1504KB 1.5MB/s 01:13 ETA
BRCSAI_1105_1310 2% 3232KB 1.5MB/s 01:10 ETA
BRCSAI_1105_1310 4% 4896KB 1.5MB/s 01:09 ETA
BRCSAI_1105_1310 5% 6528KB 1.5MB/s 01:07 ETA
BRCSAI_1105_1310 7% 8064KB 1.5MB/s 01:06 ETA
BRCSAI_1105_1310 8% 9536KB 1.5MB/s 01:06 ETA
BRCSAI_1105_1310 9% 11MB 1.5MB/s 01:06 ETA
BRCSAI_1105_1310 11% 12MB 1.5MB/s 01:04 ETA
BRCSAI_1105_1310 12% 14MB 1.5MB/s 01:03 ETA
BRCSAI_1105_1310 14% 15MB 1.5MB/s 01:02 ETA
BRCSAI_1105_1310 15% 17MB 1.5MB/s 01:01 ETA
BRCSAI_1105_1310 16% 18MB 1.5MB/s 00:59 ETA
BRCSAI_1105_1310 18% 20MB 1.5MB/s 00:58 ETA
BRCSAI_1105_1310 19% 22MB 1.5MB/s 00:57 ETA
BRCSAI_1105_1310 21% 23MB 1.5MB/s 00:57 ETA
BRCSAI_1105_1310 22% 24MB 1.5MB/s 00:55 ETA
BRCSAI_1105_1310 23% 26MB 1.5MB/s 00:54 ETA
BRCSAI_1105_1310 25% 28MB 1.5MB/s 00:53 ETA
BRCSAI_1105_1310 27% 30MB 1.5MB/s 00:53 ETA
BRCSAI_1105_1310 28% 31MB 1.5MB/s 00:52 ETA
BRCSAI_1105_1310 30% 33MB 1.5MB/s 00:49 ETA
BRCSAI_1105_1310 31% 34MB 1.5MB/s 00:49 ETA
BRCSAI_1105_1310 33% 36MB 1.5MB/s 00:47 ETA
BRCSAI_1105_1310 34% 38MB 1.5MB/s 00:46 ETA
BRCSAI_1105_1310 36% 39MB 1.5MB/s 00:45 ETA
BRCSAI_1105_1310 37% 41MB 1.5MB/s 00:44 ETA
BRCSAI_1105_1310 38% 42MB 1.5MB/s 00:43 ETA
BRCSAI_1105_1310 40% 44MB 1.6MB/s 00:41 ETA
BRCSAI_1105_1310 41% 45MB 1.5MB/s 00:41 ETA
BRCSAI_1105_1310 43% 47MB 1.5MB/s 00:40 ETA
BRCSAI_1105_1310 44% 49MB 1.6MB/s 00:39 ETA
BRCSAI_1105_1310 46% 50MB 1.6MB/s 00:37 ETA
BRCSAI_1105_1310 47% 52MB 1.6MB/s 00:37 ETA
BRCSAI_1105_1310 48% 53MB 1.5MB/s 00:36 ETA
BRCSAI_1105_1310 50% 55MB 1.5MB/s 00:35 ETA
BRCSAI_1105_1310 51% 56MB 1.5MB/s 00:34 ETA
BRCSAI_1105_1310 52% 58MB 1.5MB/s 00:33 ETA
BRCSAI_1105_1310 54% 59MB 1.6MB/s 00:31 ETA
BRCSAI_1105_1310 56% 61MB 1.5MB/s 00:32 ETA
BRCSAI_1105_1310 57% 63MB 1.5MB/s 00:31 ETA
BRCSAI_1105_1310 58% 64MB 1.5MB/s 00:30 ETA
BRCSAI_1105_1310 60% 66MB 1.5MB/s 00:28 ETA
BRCSAI_1105_1310 61% 67MB 1.5MB/s 00:27 ETA
BRCSAI_1105_1310 63% 69MB 1.5MB/s 00:26 ETA
BRCSAI_1105_1310 64% 70MB 1.5MB/s 00:25 ETA
BRCSAI_1105_1310 66% 72MB 1.5MB/s 00:24 ETA
BRCSAI_1105_1310 67% 73MB 1.5MB/s 00:23 ETA
BRCSAI_1105_1310 68% 75MB 1.5MB/s 00:22 ETA
BRCSAI_1105_1310 70% 77MB 1.5MB/s 00:20 ETA
BRCSAI_1105_1310 71% 78MB 1.6MB/s 00:19 ETA
BRCSAI_1105_1310 73% 80MB 1.6MB/s 00:18 ETA
BRCSAI_1105_1310 74% 81MB 1.5MB/s 00:17 ETA
BRCSAI_1105_1310 76% 83MB 1.5MB/s 00:16 ETA
BRCSAI_1105_1310 77% 84MB 1.5MB/s 00:15 ETA
BRCSAI_1105_1310 79% 86MB 1.5MB/s 00:14 ETA
BRCSAI_1105_1310 80% 88MB 1.6MB/s 00:13 ETA
BRCSAI_1105_1310 81% 89MB 1.6MB/s 00:12 ETA
BRCSAI_1105_1310 83% 91MB 1.6MB/s 00:11 ETA
BRCSAI_1105_1310 84% 92MB 1.6MB/s 00:10 ETA
BRCSAI_1105_1310 86% 94MB 1.6MB/s 00:09 ETA
BRCSAI_1105_1310 87% 96MB 1.6MB/s 00:08 ETA
BRCSAI_1105_1310 89% 97MB 1.6MB/s 00:07 ETA
BRCSAI_1105_1310 90% 99MB 1.6MB/s 00:06 ETA
BRCSAI_1105_1310 92% 101MB 1.6MB/s 00:05 ETA
BRCSAI_1105_1310 93% 102MB 1.6MB/s 00:04 ETA
BRCSAI_1105_1310 95% 104MB 1.5MB/s 00:03 ETA
BRCSAI_1105_1310 96% 105MB 1.5MB/s 00:02 ETA
BRCSAI_1105_1310 97% 106MB 1.5MB/s 00:01 ETA
BRCSAI_1105_1310 99% 108MB 1.5MB/s 00:00 ETA
BRCSAI_1105_1310 100% 109MB 1.5MB/s 01:12
sftp> 2015-11-13,13:42:56

*NONE Command 11/13/15 13:40:09.973076 QCADRV QSYS 0463 TOACLP03T BRCPGMSN 000E
Message . . . . : 800 - CRTPF FILE(QTEMP/SYFPHY01) RCDLEN(1024)
CPC7301 Completion 00 11/13/15 13:40:10.004855 QDDCPF QSYS 056D TOACLP03T BRCPGMSN 000E
Message . . . . : File SYFPHY01 created in library QTEMP.
CPC7305 Completion 00 11/13/15 13:40:10.030364 QDDCPFM QSYS 005B TOACLP03T BRCPGMSN 000E
Message . . . . : Member SYFPHY01 added to file SYFPHY01 in QTEMP.
*NONE Command 11/13/15 13:40:10.030481 QCLCLCPR QSYS 04CF TOACLP03T BRCPGMSN 0015
Message . . . . : 1100 - CALL PGM(QP2SHELL) /* The CALL command
contains parameters */
*NONE Command 11/13/15 13:42:57.835090 QCADRV QSYS 0463 TOACLP03T BRCPGMSN 001A
Message . . . . : 1900 - CPYFRMIMPF
FROMSTMF('/home/SFTPXFER/TOA/toageneric.output') TOFILE(QTEMP/SYFPHY01)
MBROPT(*REPLACE) TOCCSID(37) RCDDLM(*ALL) FLDDLM('|') RPLNULLVAL(*FLDDFT)
CPC2206 Completion 00 11/13/15 13:42:57.861964 QSYCHONR QSYS 0695 QLIINSRT QSYS 051B
Message . . . . : Ownership of object QCPIMTEMPS in QTEMP type *USRSPC
changed.
CPC2206 Completion 00 11/13/15 13:42:57.874708 QSYCHONR QSYS 0695 QLIINSRT QSYS 051B
Message . . . . : Ownership of object QACPTEMP01 in QTEMP type *USRSPC
changed.
CPC2206 Completion 00 11/13/15 13:42:57.896532 QSYCHONR QSYS 0695 QLIINSRT QSYS 051B
Message . . . . : Ownership of object QACPTEMP01 in QTEMP type *USRSPC
changed.
CPC2206 Completion 00 11/13/15 13:42:57.912704 QSYCHONR QSYS 0695 QLIINSRT QSYS 051B
Message . . . . : Ownership of object QCFT648728 in QTEMP type *USRSPC
changed.
CPC2206 Completion 00 11/13/15 13:42:57.980743 QSYCHONR QSYS 0695 QLIINSRT QSYS 051B
Message . . . . : Ownership of object Q7F5FF02 in QTEMP type *FILE changed.
CPC3101 Completion 00 11/13/15 13:42:57.982990 QDBCLRPF QSYS 0241 QC2SYS QSYS *STMT
To module . . . . . . . . . : QC2SYS
To procedure . . . . . . . : system
Statement . . . . . . . . . : 13
More...
Message . . . . : Member SYFPHY01 file SYFPHY01 in QTEMP cleared.
CPIA083 Diagnostic 10 11/13/15 13:42:58.034439 QCPIMPRT QSYS *STMT QDBCTHREAD QSYS *STMT
From module . . . . . . . . : QCPIMPRT
From procedure . . . . . . : Send_type_msg
Statement . . . . . . . . . : 24
To module . . . . . . . . . : QDBCTHTWRK
To procedure . . . . . . . : start__17qdbcth_ThreadWorkFP17qdbcth_ThreadPoo
l
Statement . . . . . . . . . : 8
Message . . . . : Stream file copied to object with truncated records.
CPC2959 Completion 00 11/13/15 13:42:58.053774 QCPIMPRT QSYS *STMT TOACLP03T BRCPGMSN 001A
From module . . . . . . . . : QCPIMPRT
From procedure . . . . . . : Send_type_msg
Statement . . . . . . . . . : 24
Message . . . . : 16 records copied to member SYFPHY01.

Paul

-----Original Message-----
From: MIDRANGE-L [mailto:midrange-l-bounces@xxxxxxxxxxxx] On Behalf Of Scott Klement
Sent: Friday, November 13, 2015 12:49 AM
To: Midrange Systems Technical Discussion
Subject: Re: SFTP client via PASE, large files possibly timing out

Paul,

Unless I'm misunderstanding your symptoms, you're looking at the wrong settings, here...

My understanding is that your file transfer is looking good, transferring data successfully until all of the sudden, mysteriously, the transfer is cut off after 45 seconds.

But, you are checking things related to "inactivity". Inactivity means that NOTHING is sent for the timeout period. Inactivity would never cut you off in the middle of a file transfer that's progressing!

I know the timeout settings are set higher, but let's use 45 seconds as an example to explain what 'inactivity' timeouts mean... if you had an inactivity timeout of 45 seconds that was affecting you, this is what would happen: (1) You'd start the transfer. (2) At some point (maybe right away, or maybe several minutes later) the transfer would "freeze"
where no new data was transfering for some reason like a network glitch or something. (3) 45 seconds after freezing up -- which is to say, 45 seconds without a single byte being transferred -- the timeout would
kick in and disconnect you. If the transfer never froze up, the
timeout would never occur (even if the file took hours to send)

That's what an inactivity timeout is... it means things are stalled.
Nothing at all is transferred in the timeout period, not even a single byte. As long as at least one byte is sent in that 45 seconds, it would not occur.

However, that's not how I understand your symptom. I understood that it was cutting you off while the transfer was successfully going.. So unless i'm misunderstnading, what you're experiencing cannot be an inactivity timeout. It's a timeout that occurs even on an active session... right?

The 4 settings you mentioned, however...

1- an INACTIVITY timeout on your router.

2- Keepalive... this is completely unrelated.

3- FTP server settings -- completely unrelated, you are not using FTP.
Even if you were, it's not the server.

4- SSH is the right tool to check for settings on... but again, this is an INACTIVITY timeout.

Unfortunately, I have no clue what would cause the issue you're seeing.
I've never seen this happen before. But, unless the session _is_
stalling for 45 seconds, this isn't an "inactivity" timeout. It's a "you only have 45 seconds total to use this connection before I cut you off" timeout, which is very different.

It's like saying to your teenaged daughter "you can only be on the phone for 10 minutes per day". (Time limit) That's very different from "as long as you say at least one word every 10 minutes you can stay on the phone, but if you don't say anything for 10 minutes i'll cut you off"
(inactivity timeout)

On 11/12/2015 2:03 PM, Steinmetz, Paul wrote:

I discovered a new piece to this puzzle.
For this one specific remote server:
All files are successful that complete in 45 seconds or less.
All files taking longer than 45 seconds fail.

Somewhere, there must be a 45 second timer/timeout setting.
These have been checked and confirmed.

1- It could be at the firewall/router's idle timeout level. - 5 minutes.
2- Verify the TCP keepalive on the iSeries (CHGTCPA). - TCP keep alive . . . . . . . . . 5
3- General FTP Server Inactivity Timeout Value see the following doc: The default inactivity timeout value is 300 seconds. The default transfer timeout value is 420 seconds. Inactivity timeout . . . . . . . 300
-http://www.ibm.com/support/docview.wss?uid=nas8N1011178
4- Timeout in SSH: Disconnecting Inactive SSH Sessions on the IBM I The TMOUT and TIMEOUT PASE environment variables have a value of 600 seconds. If there is no activity within an SSH session for 10 minutes
-http://www.ibm.com/support/docview.wss?uid=nas8N1013311

Paul

-----Original Message-----
From: MIDRANGE-L [mailto:midrange-l-bounces@xxxxxxxxxxxx] On Behalf Of
Scott Klement
Sent: Tuesday, November 03, 2015 4:39 PM
To: Midrange Systems Technical Discussion
Subject: Re: SFTP client via PASE, large files possibly timing out

FWIW.. I have used sftp to send extremely large files, such as whole server backups, without any problems at all. I did not have to set up anything in particular, it just worked.

When you are having trouble with your larger files (imho, 110mb isn't really very big) does it always stop at the exact same byte position?
Or does it vary?

If it varies, I'd suggest this is probably a network issue rather than a software issue. A flaky cable/switch/router/etc is causing the data to get screwed up somewhere, causing the transfer to abort.

IF it's always the same, then I would look for some sort of size limit being set up somewhere, most likely on the server-side.

Also, you could also try using scp rather than sftp and see if that matters at all. Just as a lark...

On 11/3/2015 8:34 AM, Steinmetz, Paul wrote:

I changed the SFTP process to send a 3mb zip file instead of the 110mb uncompressed file.
SFTP now working with a zipped 3mb file.
Large file issue for SFTP still exists, possibly 30 to 40mb limit.
Still looking to resolve this issue.

--
This is the Midrange Systems Technical Discussion (MIDRANGE-L) mailing list To post a message email: MIDRANGE-L@xxxxxxxxxxxx To subscribe, unsubscribe, or change list options,
visit: http://lists.midrange.com/mailman/listinfo/midrange-l
or email: MIDRANGE-L-request@xxxxxxxxxxxx Before posting, please take a moment to review the archives at http://archive.midrange.com/midrange-l.