2
I am executing SFTP to put a file to a new external client. We have about 10 other clients, some internal and some external, that we upload to without problems. This new client is on a VPN with us (some of our other clients are also on VPNs with us, but not all), and responds to a put command with an EOF after transmitting about 40M of a 50M file. This has happened on 10 of the last 14 executions.
Except for two occasions, the EOF is received once, on the first run of the day, about 5:00 AM. When I run SFTP again in a few minutes, the put command works and the complete file is transmitted. For the rest of the day it works also. In the same execution, we also send two other files, one is 1M and the other is 10M. My script sorts the list of files by file size, so the smaller files are sent first. This is all within the same connection. My script first connects, sends the password and makes sure it is accepted, does a change directory, ls command and df command. Then there is a loop in the script, to put all the files that are listed. The first two files are put successfully and then the third is put, but it fails with an EOF.
On the two occasions that are the exception, I received an EOF on the second attempt, and then the put succeeded on the third attempt. altogether, that was 10 out of the last 14 runs. The other four runs worked successfully the first time (of the day). This job runs around the same time (4:50 to 5:15). I have talked to the client and change the time slightly to get around the intervals they run their folder monitor process. But that does not make a difference.
We are running OpenSSH_6.0p1 on AIX 7.1 and they are running OpenSSH_7.4p1 on CentOS Linux 7.4. Twice I have tried to run the SFTP from the command line with the verbose option (-vvv) and the put worked on those two occasions. I will update my script to somehow capture verbose output to a log file. But I have gotten this EOF both in a script and at the command line, so I don't think it is the script. And I can send two other files first ok, so it is not just a problem with the first file sent. And it is not just a file size problem, even though it only fails on the 50M file, because it works fine a few minutes later.
So some of my questions are - what can cause an EOF on a put operation? I have found the version 2 RFC spec for SFTP and I don't see mention of an EOF for put operations, only for get operations. Could there be some background process on CentOS Linux that can cause an EOF on a large file transfer? It takes about 25 seconds to transmit. Could this possibly be a network error? Could the network quality be poor at first, but after a few minutes automatically upgrade to a higher level of quality? The client is 2700 miles away. Thank you for any comments. Peter
UPDATE: the vendor sent me their SFTP debug log and I don't see any specific cause:
28745 debug1: request 786: write "/upload/X_Y_Z_file_20180315040147.txt" (handle 0) off 25329664 len 32768
28745 debug3: request 786: sent status 0
28745 sent status Success
28745 debug1: request 787: write "/upload/X_Y_Z_file_20180315040147.txt" (handle 0) off 25362432 len 32768
28745 debug3: request 787: sent status 0
28745 sent status Success
28745 debug1: request 788: write "/upload/X_Y_Z_file_20180315040147.txt" (handle 0) off 25395200 len 32768
28745 debug3: request 788: sent status 0
28745 sent status Success
28745 debug1: read eof
28745 forced close "/upload/X_Y_Z_file_20180315040147.txt" bytes read 0 written 25427968
28745 session closed for local user abc from [1.2.3.4]
Edit: I don't think my script is the problem (but I know how that sounds), because I get the same problem whether I use a script or run the SFTP command from the command line. The script uses EXPECT to trap the SFTP response, which is one of '100%', or EOF or TIMEOUT. I will attach the script once I figure out how to do that.
Edit: Here is the script for the sftp put:
#! /usr/bin/ksh
# The following line is seen as a continuecomment by Tcl\
exec $QUOVADX_INSTALL_DIR/integrator/bin/hcitcl "$0" ${1+"$@"}
# subroutines first
proc gts {} {
set tt [clock format [clock seconds] -format {%y/%m/%d %H:%M:%S} ]
set ms [format %03d [expr {[clock clicks -milliseconds] % 1000}]]
return $tt.$ms
}
# proc to write to debug file
proc debugw {msg} {
global debugfile
set fh [open $debugfile a] ; puts $fh "$msg" ; close $fh
}
set frdir [lindex $argv 0]
set lfile [lindex $argv 1]
set todir [lindex $argv 2]
set site [lindex $argv 3]
set debug $::env(cldebug)
set parmfile $::env(clparmfile)
set module "sftp_put_list"
# get debugfilename
if {$debug} {set debugfile [exec getdebugfile.tcl] ; global debugfile}
if {$debug} {debugw "[gts] $module start"}
if {$debug} {debugw "[gts] $module processing files in list $lfile"}
# get SFTP connection parms from parmfile using $site as key
set hfile [open $parmfile r] ; set data [read $hfile] ; close $hfile
set lList [split $data "\n"] ; set pos [lsearch -regexp $lList "^key_sftp_$site"]
lassign [split [lindex $lList $pos] " "] key port url pass
if {$debug > 1} {debugw "[gts] $module key: $key port $port url $url pass $pass"}
# url with vertical bar means the first part is the userid and second is the url
set userList [split "$url" "|"] ; lassign $userList user url
if {$debug} {debugw "[gts] $module userList: $userList"}
set ullen [llength $userList]
if {$debug} {debugw "[gts] $module userList length: $ullen"}
log_user 0
# start/spawn the sftp process - either simple user url or separate user
if {[llength $userList] eq 1} {
set hname "$user"
spawn /usr/bin/sftp -o Port=$port -o ConnectTimeout=60 $user
if {$debug} {debugw "[gts] $module connection uses simple user url $user"}
} else {
set hname "$url"
spawn /usr/bin/sftp -o Port=$port -o ConnectTimeout=60 -o User=$user $url
if {$debug} {debugw "[gts] $module connection uses separate user $user and url $url"}
}
set pass_word_prompt "*?assword:*"
set sftp_prompt "*?ftp>"
set timeout 300
set sftp_put_timeout 1000
set prompt_timeout 300
#--------------------------------------------------------------
# first, wait for the password prompt - if a password is required!
#--------------------------------------------------------------
if {$pass ne "#"} {
expect {
eof {
echo "sftp EOF waiting for password prompt|NA"
if {$debug} {debugw "[gts] $module EOF received waiting for password prompt from $hname - exit 8"}
exit 8
}
"$pass_word_prompt" {
if {$debug} {debugw "[gts] $module password prompt received and answered"}
}
timeout {
echo "sftp timeout waiting for password prompt|NA"
if {$debug} {debugw "[gts] $module timeout waiting for password prompt from $hname - exit 8"}
exit 8
}
}
set timeout $prompt_timeout
send "$pass\r"
expect {
eof {
echo "sftp EOF waiting for command prompt after entering password|NA"
if {$debug} {debugw "[gts] $module EOF received waiting for command prompt from $hname after entering password - exit 8"}
exit 8
}
"$sftp_prompt" {
if {$debug} {debugw "[gts] $module received command prompt; will enter LCD command"}
}
timeout {
echo "sftp timeout after $prompt_timeout seconds waiting for command prompt after entering password|NA"
if {$debug} {debugw "[gts] $module timeout after $prompt_timeout seconds waiting for command prompt from $hname after entering password - exit 8"}
exit 8
}
}
} else {
expect {
eof {
echo "sftp EOF waiting for command prompt after logging on|NA"
if {$debug} {debugw "[gts] $module EOF received waiting for command prompt from $hname after logging on - exit 8"}
exit 8
}
"$sftp_prompt" {
if {$debug} {debugw "[gts] $module received command prompt; will enter LCD command"}
}
timeout {
echo "sftp timeout after $prompt_timeout seconds waiting for command prompt after logging on|NA"
if {$debug} {debugw "[gts] $module timeout after $prompt_timeout seconds waiting for command prompt from $hname after logging on - exit 8"}
exit 8
}
}
}
#--------------------------------------------------------------
# lcd to local directory from where you will send the file(s)
#--------------------------------------------------------------
set timeout $prompt_timeout
send "lcd $frdir\r"
expect {
eof {
echo "sftp EOF waiting for command prompt after entering LCD|NA"
if {$debug} {debugw "[gts] $module EOF received waiting for command prompt from $hname after entering LCD - exit 8"}
exit 8
}
"$sftp_prompt" {
if {$debug} {debugw "[gts] $module received command prompt after LCD ; will enter CD command"}
}
timeout {
echo "sftp timeout after $prompt_timeout seconds waiting for command prompt after entering LCD|NA"
if {$debug} {debugw "[gts] $module timeout after $prompt_timeout seconds waiting for command prompt from $hname after entering LCD - exit 8"}
exit 8
}
}
#--------------------------------------------------------------
# cd to remote directory where you will put the file(s)
#--------------------------------------------------------------
set timeout $prompt_timeout
send "cd $todir\r"
expect {
eof {
echo "sftp EOF waiting for command prompt after entering CD command|NA"
if {$debug} {debugw "[gts] $module EOF received waiting for prompt from $hname after entering CD command - exit 8"}
exit 8
}
"No such file or directory" {
echo "remote directory $todir not found or not accessible|NA"
if {$debug} {debugw "[gts] $module remote directory $todir not found or not accessible at $hname - exit 8"}
exit 8
}
"$sftp_prompt" {
if {$debug} {debugw "[gts] $module received command prompt after CD; will execute PWD command"}
}
timeout {
echo "sftp timeout after $prompt_timeout seconds waiting for prompt after entering CD command|NA"
if {$debug} {debugw "[gts] $module timeout after $prompt_timeou seconds waiting for command prompt from $hname after entering CD command - exit 8"}
exit 8
}
}
#--------------------------------------------------------------
# print working directory
#--------------------------------------------------------------
set timeout $prompt_timeout
send "pwd\r"
expect {
eof {
echo "sftp EOF waiting for command prompt after entering pwd command|NA"
if {$debug} {debugw "[gts] $module EOF received waiting for prompt from $hname after entering pwd command - exit 8"}
exit 8
}
"$sftp_prompt" {
set response $expect_out(0,string)
set rwd [lindex [split "$response" ":"] 1]
set rwd [lindex [split "$rwd" "\r" ] 0]
if {$debug} {debugw "[gts] $module pwd: $rwd"}
if {$debug} {debugw "[gts] $module received command prompt after PWD; will execute DIR command"}
}
timeout {
echo "sftp timeout after $prompt_timeout seconds waiting for prompt after entering pwd command|NA"
if {$debug} {debugw "[gts] $module timeout after $prompt_timeout seconds waiting for command prompt from $hname after entering pwd command - exit 8"}
exit 8
}
}
#--------------------------------------------------------------
# directory list
#--------------------------------------------------------------
set timeout $prompt_timeout
send "ls -l\r"
expect {
eof {
echo "sftp EOF waiting for command prompt after entering dir command|NA"
if {$debug} {debugw "[gts] $module EOF received waiting for prompt from $hname after entering dir command - exit 8"}
exit 8
}
"$sftp_prompt" {
set response $expect_out(0,string)
set dir [lrange [split "$response" "\r"] 1 end-1]
set dir [string map {\{ "" \} ""} "$dir"]
set dir [string trim "$dir"]
if {$debug} {debugw "[gts] $module dir: \r$dir"}
if {$debug} {debugw "[gts] $module received command prompt after DIR; will execute PUT command"}
}
timeout {
echo "sftp timeout after $prompt_timeout seconds waiting for prompt after entering dir command|NA"
if {$debug} {debugw "[gts] $module timeout after $prompt_timeout seconds waiting for command prompt from $hname after entering dir command - exit 8"}
exit 8
}
}
#------------------------------------------------
# loop through list of files - put each file to remote sftp server
#------------------------------------------------
set hfile [open $lfile r] ; set data [read $hfile] ; close $hfile
set flist [string map {"\n" " "} "$data" ] ; set flist [string trim "$flist"]
set flist [split $flist " "] ; set nfiles [llength $flist]
if {$debug} {debugw "[gts] $module $nfiles file names found in list file $lfile"}
set ct 0
while {$ct < $nfiles} {
set nextfile [lindex $flist $ct]
if {$debug} {debugw "[gts] $module starting SFTP Put for filename $nextfile"}
set dct [expr $ct + 1]
set timeout $sftp_put_timeout
send "put $nextfile\r"
expect {
eof {
set response $expect_out(0,string)
echo "sftp EOF waiting for command prompt after entering put command|$nextfile"
if {$debug} {debugw "[gts] $module put file $dct - $nextfile failed"}
if {$debug} {debugw "[gts] $module EOF response from Put:\n$response"}
if {$debug} {debugw "[gts] $module EOF received waiting for prompt from $hname after entering put command - exit 8"}
exit 8
}
"100%*$sftp_prompt" {
if {$debug} {debugw "[gts] $module received PUT 100% and command prompt after PUT"}
if {$debug} {debugw "[gts] $module put file $dct - $nextfile succeeded"}
}
timeout {
echo "sftp timeout after $sftp_put_timeout seconds waiting for prompt after entering put command|$nextfile"
if {$debug} {debugw "[gts] $module timeout after $sftp_put_timeout seconds waiting for command prompt from $hname after entering put command - exit 8"}
exit 8
}
}
incr ct
}
#--------------------------------------------------------------
# post transfer directory list
#--------------------------------------------------------------
set timeout $prompt_timeout
send "ls -l\r"
expect {
eof {
echo "sftp EOF waiting for command prompt after entering dir command|NA"
if {$debug} {debugw "[gts] $module EOF received waiting for prompt from $hname after entering dir command - exit 8"}
exit 8
}
"$sftp_prompt" {
set response $expect_out(0,string)
set dir [lrange [split "$response" "\r"] 1 end-1]
set dir [string map {\{ "" \} ""} "$dir"]
set dir [string trim "$dir"]
if {$debug} {debugw "[gts] $module dir: \r$dir"}
if {$debug} {debugw "[gts] $module received command prompt after dir; will execute QUIT command"}
}
timeout {
echo "sftp timeout after $prompt_timeout seconds waiting for prompt after entering dir command|NA"
if {$debug} {debugw "[gts] $module timeout after $prompt_timeout seconds waiting for command prompt from $hname after entering dir command - exit 8"}
exit 8
}
}
#---------------------------------------------------------
# sftp checks for spawn EOF and will terminate prematurely
# unless you add extra expect command
#---------------------------------------------------------
set timeout $prompt_timeout
send "quit\r"
expect {
eof {
if {$debug} {debugw "[gts] $module EOF expected and received after QUIT command|NA"}
exit 0
}
"$sftp_prompt" {
echo "unexpected sftp prompt after entering QUIT command - should be EOF|NA"
if {$debug} {debugw "[gts] $module unexpected sftp prompt after entering QUIT command - should be EOF - exit 2"}
exit 2
}
timeout {
echo "sftp timeout after $prompt_timeout seconds waiting for EOF after QUIT command|NA"
if {$debug} {debugw "[gts] $module sftp timeout after $prompt_timeout seconds waiting for EOF after QUIT command - exit 8"}
exit 8
}
}
exit 0
P. Heggie
Posted 2018-03-15T17:42:38.560
Reputation: 21