Forum » Support and Bug Reports »

Post a reply

Before posting, please read how to report bug or request support effectively.

Bug reports without an attached log file are usually useless.

Options
Add an Attachment

If you do not want to add an Attachment to your Post, please leave the Fields blank.

(maximum 10 MB; please compress large files; only common media, archive, text and programming file formats are allowed)

Options

Topic review

cjwinn

Well, this is also strange. I let the PowerShell script continue to run. Almost 9.5 hours later, the WinSCP session log resumes logging activity with the tar command that is next in my script, but it errors out before proceeding to download the compressed file. The relevant code from my script is below. 
$session.MoveFile("$remoteFileDirectory/*","$archiveFolder/")
 
$archiveFileName = "archive_$fileDate.tar.gz"
 
$archiveCommand = 'cd "' + $archiveFolder + '/" ; tar -czvf "' + $archiveFileName + '" "' + $archiveFolder + '/"'
 
log "Archive Command: $archiveCommand"
 
$result = $session.ExecuteCommand($archiveCommand)
$result.Check()
 
log $result.ErrorOutput
log $result.Output
 
$transferResult = $session.GetFiles("$archiveFolder/$archiveFileName", "$stagingDirectoryFull\", $false, $transferOptions)
 
$transferResultJson = ConvertTo-Json $transferResult
 
Expand-Tar "$stagingDirectoryFull\$archiveFileName" $stagingDirectoryFull -targzExtract
 
log "Download Complete. Archiving Downloaded Files..."

Below is the section of the WinSCP Session log where the log pauses at 14:07:56.358 and then resumes at 23:32:19:187 on line 134105 by connecting to the FTP server again. 
. 2020-10-30 14:07:56.286 Moving file "/home/<redacted>-prod/outbound/<file name redacted>.json" to "/home/<redacted>-prod/archive/2020/10/30/<file name redacted>.json".

> 2020-10-30 14:07:56.286 Type: SSH_FXP_RENAME, Size: 105, Number: 5755922

< 2020-10-30 14:07:56.357 Type: SSH_FXP_STATUS, Size: 24, Number: 5755922

< 2020-10-30 14:07:56.357 Status code: 0

< 2020-10-30 14:07:56.358 Script: /home/<redacted>-prod/outbound/<file name redacted>.json

> 2020-10-30 23:32:19.187 Script: call cd "/home/<redacted>-prod/archive/2020/10/30/" ; tar -czvf "archive_20201030_131927.tar.gz" "/home/<redacted>-prod/archive/2020/10/30/"

< 2020-10-30 23:32:19.188 Script: Searching for host...

. 2020-10-30 23:32:19.189 [Shell] Looking up host "<url redacted>" for SSH connection

. 2020-10-30 23:32:19.248 [Shell] Connecting to <IP Address redacted> port 22

< 2020-10-30 23:32:19.319 Script: Connecting to host...

I have attached the Session Log. Unfortunately, even with the debug log level set at 0, the size of the debug log is still over 25GB, so I cannot upload it or open it.

I received the following error in the PowerShell session. 
2020-10-30 23:32:16 - Archive Command: cd "/home/<redacted>-prod/archive/2020/10/30/" ; tar -czvf "archive_20201030_131927.tar.gz" "/home/<redacted>-prod/archive/2020/10/30/"

PS D:\Temp\Script\Miscellaneous> TerminatingError(archive.ps1): "Exception calling "Check" with "0" argument(s): "Network error: Software caused connection abort

Error changing directory to '/home/<redacted>-prod/archive/2020/10/30'.""

D:\Temp\Script\Miscellaneous\archive.ps1 : Exception calling "Check" with "0" argument(s): "Network 

error: Software caused connection abort

Error changing directory to '/home/<redacted>-prod/archive/2020/10/30'."

At line:1 char:1

+ D:\Temp\Script\Miscellaneous\archive.ps1 `

+ ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

    + CategoryInfo          : NotSpecified: (:) [archive.ps1], MethodInvocationException

    + FullyQualifiedErrorId : SessionRemoteException,archive.ps1

D:\Temp\Script\Miscellaneous\archive.ps1 : Exception calling "Check" with "0" argument(s): "Network

error: Software caused connection abort

Error changing directory to '/home/<redacted>-prod/archive/2020/10/30'."

At line:1 char:1

+ D:\Temp\Script\Miscellaneous\archive.ps1 `

+ ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

    + CategoryInfo          : NotSpecified: (:) [archive.ps1], MethodInvocationException

    + FullyQualifiedErrorId : SessionRemoteException,archive.ps1
cjwinn

I tried changing my approach by moving the files to an archive folder first so that I could then compress them into a .tar.gz file. This is necessary because a new file is dropped into the main directory every 10-20 seconds or so, and I want to make sure that anything I download also gets archived. I figured by moving all the files to an archive folder first and then creating the .tar.gz file off of that directory, I could avoid any issues of archiving files that aren't included in the .tar.gz.

When I tested my code with a small number of files (5–10), it worked just fine. However, when I pointed it at the directory with ~22k files, it completed the move to the archive folder and then appears to hang. My PowerShell script is sitting there not doing anything. The session log (attached) hasn't updated for the past 10 minutes. The debug log, even though it's set to a DebugLogLevel of 0, is currently sitting at about 27GB in size, meaning there's no chance I can upload it or even open it to view it for that matter.

Below is the line of code where I move the files. It appears to complete this command and then hang. 
$session.MoveFile("$remoteFileDirectory/*","$archiveFolder/")

Is it possible this volume of files is just too high for the WinSCP .NET Assembly to handle?
cjwinn

Finally was able to get a more reasonably sized debug log.
cjwinn

Re: EnumerateRemoteFiles hangs indefinitely

So this is odd. I set the log level to 0, and the debug log file size still shot up to ~250MB pretty quickly. I set it to -1, and the same thing is still happening. Am I doing something wrong? 
$debugLogPathWinSCP = "$logDirectory\WinSCPDebug_$fileDate.log"
$session.DebugLogPath = $debugLogPathWinSCP
$session.DebugLogLevel = 0

$debugLogPathWinSCP = "$logDirectory\WinSCPDebug_$fileDate.log"
$session.DebugLogPath = $debugLogPathWinSCP
$session.DebugLogLevel = -1
cjwinn

Oops, I didn't realize I had that set to 2. I set it to 0 and kicked it off again. It takes about an hour to fail, and I will upload once it is finished.
martin

Re: EnumerateRemoteFiles hangs indefinitely

For a start, please attach session log file on a normal logging level (0).
cjwinn

EnumerateRemoteFiles hangs indefinitely

Hello,

I am using WinSCP .NET Assembly in Powershell to download files from an SFTP server. I am using $session.EnumerateRemoteFiles to get a list of files from a directory with about 12,000 very small files (1-2kb json files), and it appears to hang forever. Looking at the session log, I see the following. 
. 2020-10-29 16:21:30.499 Session upkeep

. 2020-10-29 16:21:30.499 Looking for network events

. 2020-10-29 16:21:30.499 Timeout waiting for network events

In the debug log, around that time, it appears to dump the xml log and then continue logging out the following over and over repeatedly. 
[2020-10-29 16:24:19.861] [0011]     Log contents has not changed

[2020-10-29 16:24:19.862] [0011]   SessionLogReader.Read leaving

[2020-10-29 16:24:19.862] [0011]   Session.ReadFile entering

[2020-10-29 16:24:19.862] [0011]   Session.ReadFile leaving

[2020-10-29 16:24:19.863] [0011]   SessionLogReader.Read entering

[2020-10-29 16:24:19.863] [0011]     Read node 1587: Element group

[2020-10-29 16:24:19.982] [0011]     Log contents has not changed

[2020-10-29 16:24:19.983] [0011]   SessionLogReader.Read leaving

[2020-10-29 16:24:19.983] [0011]   Session.ReadFile entering

[2020-10-29 16:24:19.983] [0011]   Session.ReadFile leaving

[2020-10-29 16:24:19.984] [0011]   SessionLogReader.Read entering

[2020-10-29 16:24:19.984] [0011]     Read node 1588: Whitespace

As far as I can tell from the session log, it appears to be listing all the files and then hanging before returning the results to Powershell.
Here's a snippet of my code where this is hanging. 
$winSCPLocation = Clean-FolderPath $winSCPLocation "\" -noStart
Add-Type -Path $winSCPLocation
 
try
{
   # Setup session options
   $sessionOptions = New-Object WinSCP.SessionOptions -Property @{
      Protocol = [WinSCP.Protocol]::"sftp"
      HostName = $sourceAddress
      UserName = $sourceUser
      PortNumber = $sourcePort
      GiveUpSecurityAndAcceptAnySshHostKey = 1
   }
 
   $sessionOptions.SshPrivateKeyPath = "$sourceKeyDirectory"
 
   #Set Key Exchange Algorithm Selection Policy
   $sessionOptions.AddRawSettings("KEX", "ecdh,dh-gex-sha1,dh-group14-sha1,rsa,dh-group1-sha1,WARN")
 
   #Set Optimize Connection Buffer Size to off (0) and set SshSimple to 1 to completely disable optimzation of connection buffer size
   $sessionOptions.AddRawSettings("SendBuf",0)
   $sessionOptions.AddRawSettings("SshSimple",1)
 
   $session = New-Object WinSCP.Session
 
   if ($winSCPSessionLogEnabled)
   {
      $sessionLogPathWinSCP = "$logDirectory\WinSCPSession_$fileDate.log"
      $session.SessionLogPath = $sessionLogPathWinSCP
      $winSCPSessionLogLocation = "WinSCP Session Log Location: $sessionLogPathWinSCP"
   }
   else
   {
      $winSCPSessionLogLocation = ""
   }
   if ($winSCPDebugLogEnabled)
   {
      $debugLogPathWinSCP = "$logDirectory\WinSCPDebug_$fileDate.log"
      $session.DebugLogPath = $debugLogPathWinSCP
      $session.DebugLogLevel = 2
      
      $winSCPDebugLogLocation = "WinSCP Debug Log Location: $debugLogPathWinSCP"
   }
   else
   {
      $winSCPSessionLogLocation = ""
   }
}
catch
{
 
   log -statement "Error: $($_.Exception.Message)" RED
   exit 1
}
 
log -statement "Attempting connection for sftp" GREEN
$session.Open($sessionOptions)
log -statement "sftp Connection Established - Still Connected" GREEN
 
$fileList = $session.EnumerateRemoteFiles("/home/test","*.json", [WinSCP.EnumerationOptions]::None)

I have attached the session log. The debug log is too large to upload here, even compressed (~12MB compressed).

Thanks!

Documentation

Support

Associations

Follow Us