Forum » .NET assembly / COM library »

Resume disconnected transfer fails with access denied (550) in PowerShell script

Advertisement

MikkoK
Joined:
Posts:
4
Location:
Finland

Resume disconnected transfer fails with access denied (550) in PowerShell script

Hi

I'm trying to write a simple PowerShell script for uploading a zip file to another computer with Windows IIS FTP server running on it so I can time the upload with Windows task scheduler. The script also extracts the zip file and runs some other commands on the remote computer but that's irrelevant to the problem.

The connection is over a mobile VPN so it's very prone to all sorts of network problems and disconnects. I read that WinSCP can handle disconnections and resume upload. I'm simulating disconnections simply by disconnecting the network cable from the mobile router on the remote computer.

Here's the part of the script that handles the uploading: 
$sessionOptions = New-Object WinSCP.SessionOptions -Property @{
     Protocol = [WinSCP.Protocol]::Ftp
     HostName = $ip
     UserName = $user
     Password = $password
     Timeout = New-TimeSpan -Hours 1
}
 
Write-Host "Uploading $item to $ip..."
 
$transferOptions = New-Object WinSCP.TransferOptions
$resumeSupport = New-Object WinSCP.TransferResumeSupport
$resumeSupport.state = [WinSCP.TransferResumeSupportState]::Smart
$resumeSupport.Threshold = 1000
$permissions = New-Object WinSCP.FilePermissions
$permissions.Text = "rwxrwxrwx"
$transferOptions.ResumeSupport = $resumeSupport
$transferOptions.FilePermissions = $permissions
 
$session = New-Object WinSCP.Session
$session.SessionLogPath = "./sessionlog.txt"
$session.ReconnectTime = New-TimeSpan -Seconds 3600
$session.Open($sessionOptions)
$session.PutFileToDirectory($item.FullName, ".", $false, $transferOptions)
As you can see I've tried fiddling with some settings but no luck. Every time there is a disconnection the upload fails with a
]Exception calling "PutFileToDirectory" with "4" argument(s): "Error transferring file 'F:\asuntoikkuna_update\upload\YIT Kanavanluotsi.zip'.
Copying files to remote side failed.
Here's the session log. Apparently the relevant part here is the 550 response from the server? The server is not allowing to resume the upload for some reason. Is there some settings that I should change on the server or what am I doing wrong? 
. 2021-10-28 13.00.24.217 --------------------------------------------------------------------------
. 2021-10-28 13.00.24.217 WinSCP Version 5.19.4 (Build 11829 2021-10-24) (OS 10.0.19041 - Windows 10 Enterprise)
. 2021-10-28 13.00.24.217 Configuration: nul
. 2021-10-28 13.00.24.217 Log level: Normal
. 2021-10-28 13.00.24.217 Local account: MIKKO\User
. 2021-10-28 13.00.24.217 Working directory: F:\asuntoikkuna_update
. 2021-10-28 13.00.24.217 Process ID: 13076
. 2021-10-28 13.00.24.232 Ancestor processes: powershell_ise, explorer, ...
. 2021-10-28 13.00.24.232 Command-line: "F:\asuntoikkuna_update\winscp.exe" /xmllog="C:\Users\User\AppData\Local\Temp\wscp4CD4.01C891E1.tmp" /xmlgroups /xmllogrequired /nointeractiveinput /stdout /stdin /dotnet=5.19.4  /ini=nul /log="./sessionlog.txt"  /console /consoleinstance=_19668_60321755_920
. 2021-10-28 13.00.24.232 Time zone: Current: GMT+3, Standard: GMT+2 (FLE Standard Time), DST: GMT+3 (FLE Daylight Time), DST Start: 28.03.2021, DST End: 31.10.2021
. 2021-10-28 13.00.24.233 Login time: torstai 28. lokakuu 2021 13.00.24
. 2021-10-28 13.00.24.233 --------------------------------------------------------------------------
. 2021-10-28 13.00.24.233 Script: Retrospectively logging previous script records:
> 2021-10-28 13.00.24.233 Script: option batch on
< 2021-10-28 13.00.24.233 Script: batch           on        
< 2021-10-28 13.00.24.233 Script: reconnecttime   120       
> 2021-10-28 13.00.24.233 Script: option confirm off
< 2021-10-28 13.00.24.233 Script: confirm         off       
> 2021-10-28 13.00.24.233 Script: option reconnecttime 3600
< 2021-10-28 13.00.24.233 Script: reconnecttime   3600      
> 2021-10-28 13.00.24.233 Script: open ftp://Asuntoikkuna:***@10.100.2.10 -passive=1 -timeout=3600
. 2021-10-28 13.00.24.233 --------------------------------------------------------------------------
. 2021-10-28 13.00.24.233 Session name: Asuntoikkuna@10.100.2.10 (Ad-Hoc site)
. 2021-10-28 13.00.24.233 Host name: 10.100.2.10 (Port: 21)
. 2021-10-28 13.00.24.233 User name: Asuntoikkuna (Password: Yes, Key file: No, Passphrase: No)
. 2021-10-28 13.00.24.233 Transfer Protocol: FTP
. 2021-10-28 13.00.24.233 Ping type: Dummy, Ping interval: 30 sec; Timeout: 3600 sec
. 2021-10-28 13.00.24.233 Disable Nagle: No
. 2021-10-28 13.00.24.233 Proxy: None
. 2021-10-28 13.00.24.233 Send buffer: 262144
. 2021-10-28 13.00.24.233 UTF: Auto
. 2021-10-28 13.00.24.233 FTPS: None [Client certificate: No]
. 2021-10-28 13.00.24.233 FTP: Passive: Yes [Force IP: Auto]; MLSD: Auto [List all: Auto]; HOST: Auto
. 2021-10-28 13.00.24.233 Local directory: default, Remote directory: home, Update: Yes, Cache: Yes
. 2021-10-28 13.00.24.233 Cache directory changes: Yes, Permanent: Yes
. 2021-10-28 13.00.24.233 Recycle bin: Delete to: No, Overwritten to: No, Bin path: 
. 2021-10-28 13.00.24.233 Timezone offset: 0h 0m
. 2021-10-28 13.00.24.233 --------------------------------------------------------------------------
< 2021-10-28 13.00.24.238 Script: Connecting to 10.100.2.10 ...
. 2021-10-28 13.00.24.238 Connecting to 10.100.2.10 ...
. 2021-10-28 13.00.24.270 Connected with 10.100.2.10. Waiting for welcome message...
< 2021-10-28 13.00.24.292 220 Microsoft FTP Service
> 2021-10-28 13.00.24.292 USER Asuntoikkuna
< 2021-10-28 13.00.24.310 331 Password required
> 2021-10-28 13.00.24.310 PASS ********
< 2021-10-28 13.00.24.328 230 User logged in.
> 2021-10-28 13.00.24.328 SYST
. 2021-10-28 13.00.24.347 The server is probably running Windows, assuming that directory listing timestamps are affected by DST.
< 2021-10-28 13.00.24.347 215 Windows_NT
> 2021-10-28 13.00.24.347 FEAT
< 2021-10-28 13.00.24.367 211-Extended features supported:
< 2021-10-28 13.00.24.369  LANG EN*
< 2021-10-28 13.00.24.369  UTF8
< 2021-10-28 13.00.24.386  AUTH TLS;TLS-C;SSL;TLS-P;
< 2021-10-28 13.00.24.386  PBSZ
< 2021-10-28 13.00.24.386  PROT C;P;
< 2021-10-28 13.00.24.386  CCC
< 2021-10-28 13.00.24.386  HOST
< 2021-10-28 13.00.24.386  SIZE
< 2021-10-28 13.00.24.386  MDTM
< 2021-10-28 13.00.24.386  REST STREAM
< 2021-10-28 13.00.24.386 211 END
> 2021-10-28 13.00.24.386 OPTS UTF8 ON
< 2021-10-28 13.00.24.392 200 OPTS UTF8 command successful - UTF8 encoding now ON.
< 2021-10-28 13.00.24.392 Script: Connected
. 2021-10-28 13.00.24.392 Connected
. 2021-10-28 13.00.24.392 --------------------------------------------------------------------------
. 2021-10-28 13.00.24.392 Using FTP protocol.
. 2021-10-28 13.00.24.392 Doing startup conversation with host.
< 2021-10-28 13.00.24.392 Script: Starting the session...
> 2021-10-28 13.00.24.392 PWD
< 2021-10-28 13.00.24.411 257 "/" is current directory.
. 2021-10-28 13.00.24.411 Getting current directory name.
. 2021-10-28 13.00.24.411 Startup conversation with host finished.
< 2021-10-28 13.00.24.411 Script: Session started.
< 2021-10-28 13.00.24.411 Script: Active session: [1] Asuntoikkuna@10.100.2.10
> 2021-10-28 13.00.24.448 Script: pwd
< 2021-10-28 13.00.24.448 Script: /
> 2021-10-28 13.00.24.510 Script: put  -permissions="777" -preservetime -transfer="binary" -resumesupport="1000" -- "F:\asuntoikkuna_update\upload\YIT Kanavanluotsi.zip" "./"
. 2021-10-28 13.00.24.511 Copying 1 files/directories to remote directory "./" - total size: 11 843 452 585
. 2021-10-28 13.00.24.511   PrTime: Yes; PrRO: No; Rght: rwxrwxrwx; PrR: Yes (No); FnCs: N; RIC: 0100; Resume: S (1024000); CalcS: No; Mask: 
. 2021-10-28 13.00.24.511   TM: B; ClAr: No; RemEOF: No; RemBOM: No; CPS: 0; NewerOnly: No; EncryptNewFiles: Yes; ExcludeHiddenFiles: No; ExcludeEmptyDirectories: No; InclM: ; ResumeL: 0
. 2021-10-28 13.00.24.511   AscM: *.*html; *.htm; *.txt; *.php; *.php3; *.cgi; *.c; *.cpp; *.h; *.pas; *.bas; *.tex; *.pl; *.js; .htaccess; *.xtml; *.css; *.cfg; *.ini; *.sh; *.xml
. 2021-10-28 13.00.24.511 File: 'F:\asuntoikkuna_update\upload\YIT Kanavanluotsi.zip' [2021-10-22T08:13:04.644Z] [11843452585]
. 2021-10-28 13.00.24.511 Copying "F:\asuntoikkuna_update\upload\YIT Kanavanluotsi.zip" to remote directory started.
. 2021-10-28 13.00.24.511 Binary transfer mode selected.
. 2021-10-28 13.00.24.511 Starting upload of F:\asuntoikkuna_update\upload\YIT Kanavanluotsi.zip
> 2021-10-28 13.00.24.511 TYPE I
< 2021-10-28 13.00.24.527 200 Type set to I.
> 2021-10-28 13.00.24.527 PASV
< 2021-10-28 13.00.24.550 227 Entering Passive Mode (10,100,2,10,250,95).
> 2021-10-28 13.00.24.551 STOR YIT Kanavanluotsi.zip
. 2021-10-28 13.00.24.551 Connecting to 10.100.2.10:64095 ...
< 2021-10-28 13.00.24.581 150 Opening BINARY mode data connection.
. 2021-10-28 13.00.25.587 Increasing send buffer from 262144 to 524288
. 2021-10-28 13.00.26.579 Increasing send buffer from 524288 to 1048576
. 2021-10-28 13.00.27.580 Increasing send buffer from 1048576 to 2097152
. 2021-10-28 13.01.02.642 Increasing send buffer from 2097152 to 4194304
. 2021-10-28 13.03.34.062 An existing connection was forcibly closed by the remote host.
 
. 2021-10-28 13.03.34.062 Transfer connection failed, closing
. 2021-10-28 13.03.34.062 Copying files to remote side failed.
. 2021-10-28 13.03.34.062 Connection was lost, asking what to do.
. 2021-10-28 13.03.34.062 Asking user:
. 2021-10-28 13.03.34.062 **Lost connection.** ("An existing connection was forcibly closed by the remote host.
 
. 2021-10-28 13.03.34.062 ","Transfer connection failed, closing","Copying files to remote side failed.")
< 2021-10-28 13.03.34.062 Script: Lost connection.
< 2021-10-28 13.03.34.062 Script: An existing connection was forcibly closed by the remote host.
 
< 2021-10-28 13.03.34.062 
 
< 2021-10-28 13.03.34.062 Transfer connection failed, closing
 
< 2021-10-28 13.03.34.062 Copying files to remote side failed.
. 2021-10-28 13.03.39.077 Answer: Retry
< 2021-10-28 13.03.39.077 Script: Connecting to 10.100.2.10 ...
. 2021-10-28 13.03.39.077 Connecting to 10.100.2.10 ...
. 2021-10-28 13.03.39.143 Connected with 10.100.2.10. Waiting for welcome message...
< 2021-10-28 13.03.39.162 220 Microsoft FTP Service
> 2021-10-28 13.03.39.162 USER Asuntoikkuna
< 2021-10-28 13.03.39.183 331 Password required
> 2021-10-28 13.03.39.183 PASS ********
< 2021-10-28 13.03.39.196 230 User logged in.
> 2021-10-28 13.03.39.196 SYST
. 2021-10-28 13.03.39.216 The server is probably running Windows, assuming that directory listing timestamps are affected by DST.
< 2021-10-28 13.03.39.216 215 Windows_NT
> 2021-10-28 13.03.39.216 FEAT
< 2021-10-28 13.03.39.234 211-Extended features supported:
< 2021-10-28 13.03.39.237  LANG EN*
< 2021-10-28 13.03.39.237  UTF8
< 2021-10-28 13.03.39.237  AUTH TLS;TLS-C;SSL;TLS-P;
< 2021-10-28 13.03.39.237  PBSZ
< 2021-10-28 13.03.39.237  PROT C;P;
< 2021-10-28 13.03.39.237  CCC
< 2021-10-28 13.03.39.237  HOST
< 2021-10-28 13.03.39.237  SIZE
< 2021-10-28 13.03.39.237  MDTM
< 2021-10-28 13.03.39.237  REST STREAM
< 2021-10-28 13.03.39.237 211 END
> 2021-10-28 13.03.39.237 OPTS UTF8 ON
< 2021-10-28 13.03.39.259 200 OPTS UTF8 command successful - UTF8 encoding now ON.
< 2021-10-28 13.03.39.259 Script: Connected
. 2021-10-28 13.03.39.259 Connected
. 2021-10-28 13.03.39.259 Doing startup conversation with host.
< 2021-10-28 13.03.39.259 Script: Starting the session...
> 2021-10-28 13.03.39.259 PWD
< 2021-10-28 13.03.39.278 257 "/" is current directory.
. 2021-10-28 13.03.39.278 Changing directory to "/".
> 2021-10-28 13.03.39.278 CWD /
< 2021-10-28 13.03.39.296 250 CWD command successful.
. 2021-10-28 13.03.39.296 Getting current directory name.
> 2021-10-28 13.03.39.296 PWD
< 2021-10-28 13.03.39.315 257 "/" is current directory.
. 2021-10-28 13.03.39.315 Startup conversation with host finished.
< 2021-10-28 13.03.39.315 Script: Session started.
. 2021-10-28 13.03.39.315 File: 'F:\asuntoikkuna_update\upload\YIT Kanavanluotsi.zip' [2021-10-22T08:13:04.644Z] [11843452585]
. 2021-10-28 13.03.39.315 Copying "F:\asuntoikkuna_update\upload\YIT Kanavanluotsi.zip" to remote directory started.
. 2021-10-28 13.03.39.315 Binary transfer mode selected.
. 2021-10-28 13.03.39.315 Starting upload of F:\asuntoikkuna_update\upload\YIT Kanavanluotsi.zip
> 2021-10-28 13.03.39.315 TYPE A
< 2021-10-28 13.03.39.333 200 Type set to A.
> 2021-10-28 13.03.39.333 PASV
< 2021-10-28 13.03.39.351 227 Entering Passive Mode (10,100,2,10,250,96).
> 2021-10-28 13.03.39.351 LIST
. 2021-10-28 13.03.39.351 Connecting to 10.100.2.10:64096 ...
< 2021-10-28 13.03.39.369 150 Opening ASCII mode data connection.
. 2021-10-28 13.03.39.396 04-21-20  08:13AM               650752 Asuntoikkuna.exe
. 2021-10-28 13.03.39.396 05-31-21  03:40PM       <DIR>          Asuntoikkuna_Data
. 2021-10-28 13.03.39.396 05-19-21  09:00AM       <DIR>          Hameenpuisto39
. 2021-10-28 13.03.39.396 05-07-18  04:03PM       <DIR>          kanavanvahti3.0-AI
. 2021-10-28 13.03.39.396 11-25-20  09:32AM       <DIR>          MonoBleedingEdge
. 2021-10-28 13.03.39.396 06-08-21  03:04PM       <DIR>          Nasintahystaja
. 2021-10-28 13.03.39.396 05-07-18  03:26PM       <DIR>          Näsinkeula Asuntoikkuna
. 2021-10-28 13.03.39.396 09-09-21  04:42PM       <DIR>          Rantapoukama
. 2021-10-28 13.03.39.396 01-14-21  11:27AM                   14 streaming.txt
. 2021-10-28 13.03.39.396 09-28-20  09:46AM                  401 streamingcheck.ps1
. 2021-10-28 13.03.39.396 11-30-20  02:09PM       <DIR>          Suvituuli
. 2021-10-28 13.03.39.396 06-04-20  11:34AM       <DIR>          Tahtitorni
. 2021-10-28 13.03.39.396 10-26-21  09:53AM       <DIR>          Teatterineuvos
. 2021-10-28 13.03.39.396 04-21-20  08:14AM              1094600 UnityCrashHandler64.exe
. 2021-10-28 13.03.39.396 04-21-20  08:14AM             25829832 UnityPlayer.dll
. 2021-10-28 13.03.39.396 06-04-20  11:34AM       <DIR>          YIT Aallonharja
. 2021-10-28 13.03.39.396 06-04-20  08:04AM       <DIR>          YIT Kanavamestari
. 2021-10-28 13.03.39.396 10-27-21  02:19PM       <DIR>          YIT Kanavanluotsi
. 2021-10-28 13.03.39.396 10-28-21  01:01PM                    0 YIT Kanavanluotsi.zip
. 2021-10-28 13.03.39.396 10-22-19  03:38PM       <DIR>          YIT Rantakaari
. 2021-10-28 13.03.39.396 11-06-20  09:24AM       <DIR>          YIT Rantapuisto
. 2021-10-28 13.03.39.396 06-01-21  03:48PM       <DIR>          YIT Rantaraitti
. 2021-10-28 13.03.39.396 09-22-20  05:44PM       <DIR>          YIT Vedenvalke
< 2021-10-28 13.03.39.396 226 Transfer complete.
. 2021-10-28 13.03.39.396 Data connection closed
. 2021-10-28 13.03.39.397 Warning: Timezone difference was not detected yet, timestamps may be incorrect
> 2021-10-28 13.03.39.397 TYPE I
< 2021-10-28 13.03.39.421 200 Type set to I.
> 2021-10-28 13.03.39.421 PASV
< 2021-10-28 13.03.39.439 227 Entering Passive Mode (10,100,2,10,250,97).
> 2021-10-28 13.03.39.439 REST 0
< 2021-10-28 13.03.39.458 350 Restarting at 0.
> 2021-10-28 13.03.39.458 STOR YIT Kanavanluotsi.zip
. 2021-10-28 13.03.39.458 Connecting to 10.100.2.10:64097 ...
< 2021-10-28 13.03.39.479 550 
. 2021-10-28 13.03.39.479 Copying files to remote side failed.
* 2021-10-28 13.03.39.479 (ExtException) **Copying files to remote side failed.**
. 2021-10-28 13.03.39.479 Asking user:
. 2021-10-28 13.03.39.479 Error transferring file 'F:\asuntoikkuna_update\upload\YIT Kanavanluotsi.zip'. ("Copying files to remote side failed.")
< 2021-10-28 13.03.39.479 Script: Error transferring file 'F:\asuntoikkuna_update\upload\YIT Kanavanluotsi.zip'.
< 2021-10-28 13.03.39.480 Script: Copying files to remote side failed.
. 2021-10-28 13.03.39.480 Answer: Abort
* 2021-10-28 13.03.39.480 (ESkipFile) Error transferring file 'F:\asuntoikkuna_update\upload\YIT Kanavanluotsi.zip'.
* 2021-10-28 13.03.39.480 Copying files to remote side failed.
. 2021-10-28 13.03.39.480 Copying finished: Transferred: 0, Elapsed: 0.03.14, CPS: 0/s
. 2021-10-28 13.03.39.480 Script: Failed
Last edited by MikkoK on 2021-11-01 12:56; edited 1 time in total

Reply with quote

Advertisement

MikkoK

Any help with this would be appreciated. I tried switching to FileZilla server but the problem persists. Upload doesn't resume after a disconnection. Also it appears that when resuming upload is attempted it creates a new session on FileZilla server admin interface. The old session still shows as uploading (even though there is no traffic) and new session shows as idle. Is this supposed to happen?

Reply with quote

MikkoK
Joined:
Posts:
4
Location:
Finland

Thanks for the reply.

Like this? 
$session = New-Object WinSCP.Session
$session.SessionLogPath = "./sessionlog.txt"
$session.AddRawConfiguration("Interface\SessionReopenAuto", "2000")
$session.Open($sessionOptions)
$session.PutFileToDirectory($item.FullName, "/")
Doesn't seem to work, still the same problem. As you said the session seems to not be disconnected and the file is locked. Even a completely new upload attempt fails immediately with the same error until I go to server settings and manually kill the old session. Should I adjust server data or control channel timeouts?

Edit: Well I tried setting both control and data channel timeouts to 1 second but it doesn't have any effect. Session remains open and file is locked for a long while after disconnecting.

Reply with quote

MikkoK
Joined:
Posts:
4
Location:
Finland

The IIS channel timeout settings don't seem to have any effect. The timeouts appear to always be the default 300 seconds no matter what is in the settings. So I set Interface\SessionReopenAuto to 360000 milliseconds and SessionOptions.TimeoutInMilliseconds to 600000 (this has to be bigger than Interface\SessionReopenAuto or there will be an error) and that seems to have done the trick. It's a bit stupid of a solution as now there is a 6 minute delay before upload resumes after a disconnect but at least it works now.

Reply with quote

Advertisement

You can post new topics in this forum

Documentation

Support

Associations

Follow Us