ExecuteCommand tries to open new connection that times out

Advertisement

vranoch
Joined:
Posts:
2

ExecuteCommand tries to open new connection that times out

Hi,

I try to implement some basic integration: open connection, copy files to remote host, execute command, retrieve result files.

Opening a session and transferring files works fine but when I call even trivial
sesion.ExecuteCommand("echo HELLO");
the library tries to open a new connection what finally times out.

What is wrong? (doing the same procedure from PuTTY works just fine).

Thanks Jan

the code:
using (Session session = new Session())
{
   try
   {
      // Connect
      session.Open(this.sessionOptions);
      session.DebugLogPath = @"C:\TEMP\remote_test_execution\WinSCP.log";
 
      session.ExecuteCommand("echo HELLO").Check();
   }
   catch 
   {
      this.LogOutoutOfFailedSession(session);
      throw;
   }
   finally
   {
      session.RemoveFiles(remoteOutputFileName);
      session.RemoveFiles(remoteLogFileName);
   }
}

The session output:
winscp> option batch on
batch           on        
reconnecttime   120       
winscp> option confirm off
confirm         off       
winscp> option reconnecttime 120
reconnecttime   120       
winscp> open "sftp://komix%5Cvrana:***@localhost" -hostkey="ssh-rsa 3072 oJdqIecUBpIDrb+ctARaHQsgR0RRW2bHsiGqTX4f4vw" -timeout=15
Searching for host...
Connecting to host...
Authenticating...
Using username "komix\vrana".
Authenticating with pre-entered password.
Authenticated.
Starting the session...
Session started.
Active session: [1] komix\vrana@localhost
winscp> pwd
/C:/Users/vrana
winscp> call echo HELLO
Searching for host...
Connecting to host...
Authenticating...
Using username "komix\vrana".
Authenticating with pre-entered password.
Authenticated.
Starting the session...
Host is not communicating for more than 15 seconds.
Still waiting...
Note: If the problem repeats, try turning off 'Optimize connection buffer size'.
Warning: Aborting this operation will close connection!
(A)bort (60 s): Abort
Terminated by user.
Error skipping startup message. Your shell is probably incompatible with the application (BASH is recommended).
winscp> exit

the WinSCP log:
[2021-10-07 15:52:25.489] [000d] .NET Framework build
[2021-10-07 15:52:25.489] [000d] Executing assembly: WinSCPnet, Version=1.8.3.11614, Culture=neutral, PublicKeyToken=2271ec4a3c56d0bf
[2021-10-07 15:52:25.489] [000d] Executing assembly codebase: file:///D:/Projects/ERIAN/local/Develop/GIT/FinalDebug/WinSCPnet.DLL
[2021-10-07 15:52:25.489] [000d] Executing assembly location: D:\Projects\ERIAN\local\Develop\GIT\FinalDebug\WinSCPnet.dll
[2021-10-07 15:52:25.489] [000d] Entry Assembly: unmanaged
[2021-10-07 15:52:25.489] [000d] Operating system: Microsoft Windows NT 6.3.9600.0
[2021-10-07 15:52:25.489] [000d] Timezone: +02:00; Střední Evropa (letní čas)
[2021-10-07 15:52:25.490] [000d] User: VRANA@KOMIX@VRANA; Interactive: True
[2021-10-07 15:52:25.490] [000d] Runtime: 4.0.30319.42000
[2021-10-07 15:52:25.490] [000d] Console encoding: Input: Středoevropské jazyky (Windows) (1250); Output: Středoevropské jazyky (Windows) (1250)
[2021-10-07 15:52:25.490] [000d] Working directory: D:\Projects\ERIAN\local\Develop\GIT\Support\Solutions\TestResults\VRANA_VRANA 2021-10-07 15_51_48\Out
[2021-10-07 15:52:25.491] [000d] Assembly path: D:\Projects\ERIAN\local\Develop\GIT\FinalDebug\WinSCPnet.DLL
[2021-10-07 15:52:25.491] [000d] Assembly product version: 5.19.2.0
[2021-10-07 15:52:53.262] [000d] Session.CreateCallstackAndLock entering
[2021-10-07 15:52:53.263] [000d]   Command: [call echo HELLO]
[2021-10-07 15:52:53.263] [000d]   ExeSessionProcess.ExecuteCommand entering
[2021-10-07 15:52:53.264] [0006] Scheduling output: [winscp> call echo HELLO]
[2021-10-07 15:52:53.265] [0006] ExeSessionProcess.ProcessEvent entering
[2021-10-07 15:52:53.265] [0006]   Scheduling output: [Searching for host...]
[2021-10-07 15:52:53.265] [000d]   ExeSessionProcess.ExecuteCommand leaving
[2021-10-07 15:52:53.265] [0006] ExeSessionProcess.ProcessEvent leaving
[2021-10-07 15:52:53.265] [000d]   SessionLogReader.Read entering
[2021-10-07 15:52:53.265] [000d]     Read node 20: Whitespace 
  
[2021-10-07 15:52:53.266] [000d]     Log contents:
<?xml version="1.0" encoding="UTF-8"?>
<session xmlns="http://winscp.net/schema/session/1.0" name="komix\vrana@localhost" start="2021-10-07T13:52:24.545Z">
  <group name="open sftp://komix%5Cvrana:***@localhost -hostkey=&quot;ssh-rsa 3072 oJdqIecUBpIDrb+ctARaHQsgR0RRW2bHsiGqTX4f4vw&quot; -timeout=15" start="2021-10-07T13:52:25.105Z">
  </group>
  <group name="pwd" start="2021-10-07T13:52:25.408Z">
    <cwd>
      <cwd value="/C:/Users/vrana" />
      <result success="true" />
    </cwd>
  </group>
  <group name="call echo HELLO" start="2021-10-07T13:52:53.264Z">

[2021-10-07 15:52:53.266] [000d]   SessionLogReader.Read leaving
[2021-10-07 15:52:53.266] [000d]   SessionLogReader.Read entering
[2021-10-07 15:52:53.266] [000d]     Read node 21: Element group
[2021-10-07 15:52:53.266] [000d]     Log contents has not changed
[2021-10-07 15:52:53.266] [000d]   SessionLogReader.Read leaving
[2021-10-07 15:52:53.266] [000d]   SessionLogReader.Read entering
[2021-10-07 15:52:53.266] [000d]     Waiting for log update and dispatching events for 50
[2021-10-07 15:52:53.267] [000d]     Output: [winscp> call echo HELLO]
[2021-10-07 15:52:53.267] [000d]     Output: [Searching for host...]
[2021-10-07 15:52:53.268] [0006] ExeSessionProcess.ProcessEvent entering
[2021-10-07 15:52:53.268] [0006]   Scheduling output: [Connecting to host...]
[2021-10-07 15:52:53.268] [0006] ExeSessionProcess.ProcessEvent leaving
[2021-10-07 15:52:53.269] [000d]     Output: [Connecting to host...]
[2021-10-07 15:52:53.334] [000d]     Waiting for log update and dispatching events for 100
[2021-10-07 15:52:53.442] [000d]     Waiting for log update and dispatching events for 200
[2021-10-07 15:52:53.506] [0006] ExeSessionProcess.ProcessEvent entering
[2021-10-07 15:52:53.506] [0006]   Scheduling output: [Authenticating...]
[2021-10-07 15:52:53.506] [0006] ExeSessionProcess.ProcessEvent leaving
[2021-10-07 15:52:53.506] [000d]     Output: [Authenticating...]
[2021-10-07 15:52:53.507] [0006] ExeSessionProcess.ProcessEvent entering
[2021-10-07 15:52:53.507] [0006]   Scheduling output: [Using username "komix\vrana".]
[2021-10-07 15:52:53.507] [0006] ExeSessionProcess.ProcessEvent leaving
[2021-10-07 15:52:53.508] [000d]     Output: [Using username "komix\vrana".]
[2021-10-07 15:52:53.579] [0006] ExeSessionProcess.ProcessEvent entering
[2021-10-07 15:52:53.579] [0006]   Scheduling output: [Authenticating with pre-entered password.]
[2021-10-07 15:52:53.579] [0006] ExeSessionProcess.ProcessEvent leaving
[2021-10-07 15:52:53.580] [000d]     Output: [Authenticating with pre-entered password.]
[2021-10-07 15:52:53.656] [000d]     Waiting for log update and dispatching events for 400
[2021-10-07 15:52:53.717] [0006] ExeSessionProcess.ProcessEvent entering
[2021-10-07 15:52:53.717] [0006]   Scheduling output: [Authenticated.]
[2021-10-07 15:52:53.717] [0006] ExeSessionProcess.ProcessEvent leaving
[2021-10-07 15:52:53.718] [000d]     Output: [Authenticated.]
[2021-10-07 15:52:53.718] [0006] ExeSessionProcess.ProcessEvent entering
[2021-10-07 15:52:53.718] [0006]   Scheduling output: [Starting the session...]
[2021-10-07 15:52:53.718] [0006] ExeSessionProcess.ProcessEvent leaving
[2021-10-07 15:52:53.719] [000d]     Output: [Starting the session...]
[2021-10-07 15:52:54.072] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:52:54.881] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:52:55.690] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:52:56.512] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:52:57.327] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:52:58.142] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:52:58.947] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:52:59.755] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:00.577] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:01.378] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:02.203] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:03.019] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:03.838] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:04.643] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:05.465] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:06.282] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:07.092] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:07.899] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:08.713] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:09.533] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:10.075] [0006] ExeSessionProcess.ProcessEvent entering
[2021-10-07 15:53:10.075] [0006]   Scheduling output: [Host is not communicating for more than 15 seconds.]
[2021-10-07 15:53:10.075] [0006]   Scheduling output: [Still waiting...]
[2021-10-07 15:53:10.075] [0006]   Scheduling output: [Note: If the problem repeats, try turning off 'Optimize connection buffer size'.]
[2021-10-07 15:53:10.076] [0006]   Scheduling output: [Warning: Aborting this operation will close connection!]
[2021-10-07 15:53:10.076] [0006] ExeSessionProcess.ProcessEvent leaving
[2021-10-07 15:53:10.076] [000d]     Output: [Host is not communicating for more than 15 seconds.]
[2021-10-07 15:53:10.076] [000d]     Output: [Still waiting...]
[2021-10-07 15:53:10.076] [000d]     Output: [Note: If the problem repeats, try turning off 'Optimize connection buffer size'.]
[2021-10-07 15:53:10.076] [000d]     Output: [Warning: Aborting this operation will close connection!]
[2021-10-07 15:53:10.077] [0006] ExeSessionProcess.ProcessEvent entering
[2021-10-07 15:53:10.078] [0006] ExeSessionProcess.ProcessEvent leaving
[2021-10-07 15:53:10.341] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:11.152] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:11.958] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:12.768] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:13.593] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:14.402] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:15.215] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:16.027] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:16.837] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:17.649] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:18.466] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:19.280] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:20.092] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:20.901] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:21.708] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:22.529] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:23.338] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:24.145] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:24.956] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:25.779] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:26.590] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:27.397] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:28.220] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:29.030] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:29.840] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:30.653] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:31.460] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:32.280] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:33.089] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:33.899] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:34.710] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:35.523] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:36.334] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:37.147] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:37.957] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:38.774] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:39.585] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:40.401] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:41.209] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:42.030] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:42.839] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:43.651] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:44.463] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:45.271] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:46.084] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:46.902] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:47.717] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:48.528] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:49.334] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:50.147] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:50.967] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:51.774] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:52.583] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:53.405] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:54.218] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:55.027] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:55.836] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:56.650] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:57.462] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:58.271] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:59.096] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:53:59.901] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:54:00.713] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:54:01.524] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:54:02.338] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:54:03.152] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:54:03.966] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:54:04.783] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:54:05.593] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:54:06.403] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:54:07.212] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:54:08.032] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:54:08.839] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:54:09.649] [000d]     Waiting for log update and dispatching events for 800
[2021-10-07 15:54:10.458] [000d]     Timeout waiting for WinSCP to respond - asking for callstack
[2021-10-07 15:54:10.459] [000d]     ExeSessionProcess.RequestCallstack entering
[2021-10-07 15:54:10.459] [000d]       Setting event WinSCPCallstack21520
[2021-10-07 15:54:10.521] [000d]       Callstack file D:\tmp\_tmp\WinSCPCallstack21520.txt has been created
[2021-10-07 15:54:10.633] [000d]       (00071D1C) ntdll.dll.ZwDelayExecution
(001239CA) KERNELBASE.dll.Sleep
(0005F8DB) 
(0011DC36) KERNELBASE.dll.LoadStringBaseExW
(00FAFE97) 
(00FB0838) 
(00FB1276) 
(00FAB020) 
(00FC029C) 
(003775C1) 
(00FC03C1) 
(00FC09D8) 
(00FC0105) 
(00FC0136) 
(003775B2) 
(00438A80) 
(00D742BD) 
(003775C1) 
(00FC03C1) 
(00438A9C) 
(0043B88C) 
(003775C1) 
(00FC03C1) 
(00D7428F) 
(00F961AD) 
(003775B2) 
(00DBECCD) 
(0043C9F3) 
(00FC03C1) 
(00438A9C) 
(0043B88C) 
(003775C1) 
(00FC03C1) 
(00C742C4) 
(00D32587) 
(00D34902) 
(00FAA4C3) 
(00D31D32) 
(00C861E9) 
(00438ABD) 
(00FBF14E) 
(00D31F7E) 
(00D31FB0) 
(00D11232) 
(00D32E50) 
(003775C1) 
(00FC03C1) 
(00D117B4) 
(00D11863) 
(00438A9C) 
(0043B88C) 
(003775C1) 
(00D11D74) 
(00DC0274) 
(00D11A55) 
(003775C1) 
(00FC03C1) 
(00DC491A) 
(00DC4949) 
(00FC03C1) 
(00DBABCC) 
(0043A458) 
(0043A746) 
(0043A797) 
(00439B88) 
(003ABE1C) 
(0000308C) 
(0043A4C8) 
(00439C23) 
(00438A9C) 
(00439A98) 
(00D3CD5B) 
(00FC03C1) 
(00DCD4CE) 
(00D21B8E) 
(00D22876) 
(00FC03C1) 
(00D22C95) 
(00D22CAD) 
(00D1DF61) @@Scpfilesystem@Finalize
(00D1EF89) 
(00407C83) 
(00407CAE) 
(00CCD69C) 
(00D7E700) 
(00407CAE) 
(00CCD69C) 
(00D74583) 
(00DDD60E) 
(00D2C35E) 
(00065288) 
(00C8E3F8) 
(00D204F7) 
(0005B75B) 
(0005B37F) 
(00064A1F) 
(003775B2) 
(00FC0233) 
(00CE280F) 
(00438A9C) 
(0043B88C) 
(003775C1) 
(00FC03C1) 
(000C51C6) 
(0006D1CA) 
(003775C1) 
(00FC03C1) 
(00438A9C) 
(0043B88C) 
(00106F51) 
(003775C1) 
(00242BF5) 
(002433DA) 
(00FAA61A) 
(0004B7B7) ntdll.dll.RtlDeactivateActivationContextUnsafeFast
(00FAA4C3) 
(003C79D8) 
(000426D9) USER32.dll
(00039665) USER32.dll
(000398A9) USER32.dll
(000396A7) USER32.dll
(00039478) USER32.dll
(000398A9) USER32.dll
(00002650) 
(00002658) 
(00FBA625) 
(0001EA27) KERNEL32.DLL.BaseThreadInitThunk
(00066A9C) ntdll.dll.RtlGetAppContainerNamedObjectPath
(00066A69) ntdll.dll.RtlGetAppContainerNamedObjectPath

[2021-10-07 15:54:10.633] [000d]     ExeSessionProcess.RequestCallstack leaving
[2021-10-07 15:54:10.633] [000d]     Session.Cleanup entering
[2021-10-07 15:54:10.633] [000d]       Terminating process
[2021-10-07 15:54:10.633] [000d]       Command: [exit]
[2021-10-07 15:54:10.633] [000d]       ExeSessionProcess.ExecuteCommand entering
[2021-10-07 15:54:10.633] [000d]       ExeSessionProcess.ExecuteCommand leaving
[2021-10-07 15:54:10.633] [000d]       ExeSessionProcess.Close entering
[2021-10-07 15:54:10.633] [000d]         Waiting for process to exit (2000 ms)
[2021-10-07 15:54:10.757] [0006] ExeSessionProcess.ProcessEvent entering
[2021-10-07 15:54:10.757] [0006]   Scheduling output: [(A)bort (60 s): Abort]
[2021-10-07 15:54:10.757] [0006] ExeSessionProcess.ProcessEvent leaving
[2021-10-07 15:54:10.765] [0006] ExeSessionProcess.ProcessEvent entering
[2021-10-07 15:54:10.765] [0006]   Scheduling output: [Terminated by user.]
[2021-10-07 15:54:10.765] [0006]   Scheduling output: [Error skipping startup message. Your shell is probably incompatible with the application (BASH is recommended).]
[2021-10-07 15:54:10.765] [0006] ExeSessionProcess.ProcessEvent leaving
[2021-10-07 15:54:10.765] [0006] ExeSessionProcess.ProcessEvent entering
[2021-10-07 15:54:10.765] [0006]   ExeSessionProcess.ProcessTitleEvent entering
[2021-10-07 15:54:10.765] [0006]     Not-supported title event [komix\vrana@localhost - WinSCP]
[2021-10-07 15:54:10.765] [0006]   ExeSessionProcess.ProcessTitleEvent leaving
[2021-10-07 15:54:10.766] [0006] ExeSessionProcess.ProcessEvent leaving
[2021-10-07 15:54:10.766] [0006] ExeSessionProcess.ProcessEvent entering
[2021-10-07 15:54:10.766] [0006] ExeSessionProcess.ProcessEvent leaving
[2021-10-07 15:54:10.767] [0006] ExeSessionProcess.ProcessEvent entering
[2021-10-07 15:54:10.767] [0006]   ExeSessionProcess.ProcessInputEvent entering
[2021-10-07 15:54:10.768] [0006]     Scheduling output: [winscp> exit]
[2021-10-07 15:54:10.768] [0006]   ExeSessionProcess.ProcessInputEvent leaving
[2021-10-07 15:54:10.768] [0006] ExeSessionProcess.ProcessEvent leaving
[2021-10-07 15:54:10.818] [000d]       ExeSessionProcess.Close leaving
[2021-10-07 15:54:10.818] [000d]       ExeSessionProcess.Dispose entering
[2021-10-07 15:54:10.881] [0006] Aborted
[2021-10-07 15:54:10.890] [000d]         Closing job
[2021-10-07 15:54:10.890] [000d]       ExeSessionProcess.Dispose leaving
[2021-10-07 15:54:10.890] [000d]       Disposing log readers
[2021-10-07 15:54:10.890] [000d]       SessionElementLogReader.Dispose entering
[2021-10-07 15:54:10.890] [000d]         ElementLogReader.Dispose(session@0) entering
[2021-10-07 15:54:10.890] [000d]           ElementLogReader.ReadToEnd(session@0) entering
[2021-10-07 15:54:10.890] [000d]             SessionLogReader.Read entering
[2021-10-07 15:54:10.890] [000d]               Not reading, session has timed out
[2021-10-07 15:54:10.890] [000d]             SessionLogReader.Read leaving
[2021-10-07 15:54:10.890] [000d]           ElementLogReader.ReadToEnd(session@0) leaving
[2021-10-07 15:54:10.890] [000d]         ElementLogReader.Dispose(session@0) leaving
[2021-10-07 15:54:10.890] [000d]       SessionElementLogReader.Dispose leaving
[2021-10-07 15:54:10.891] [000d]       SessionLogReader.Dispose entering
[2021-10-07 15:54:10.891] [000d]         Log contents:
<?xml version="1.0" encoding="UTF-8"?>
<session xmlns="http://winscp.net/schema/session/1.0" name="komix\vrana@localhost" start="2021-10-07T13:52:24.545Z">
  <group name="open sftp://komix%5Cvrana:***@localhost -hostkey=&quot;ssh-rsa 3072 oJdqIecUBpIDrb+ctARaHQsgR0RRW2bHsiGqTX4f4vw&quot; -timeout=15" start="2021-10-07T13:52:25.105Z">
  </group>
  <group name="pwd" start="2021-10-07T13:52:25.408Z">
    <cwd>
      <cwd value="/C:/Users/vrana" />
      <result success="true" />
    </cwd>
  </group>
  <group name="call echo HELLO" start="2021-10-07T13:52:53.264Z">
    <call>
      <command value="echo HELLO" />
      <destination value="/C:/Users/vrana" />
      <result success="false">
        <message>Terminated by user.</message>
        <message>Error skipping startup message. Your shell is probably incompatible with the application (BASH is recommended).</message>
      </result>
    </call>
    <failure>
      <message>Terminated by user.</message>
      <message>Error skipping startup message. Your shell is probably incompatible with the application (BASH is recommended).</message>
    </failure>
  </group>
  <group name="exit" start="2021-10-07T13:54:10.768Z">
  </group>
</session>

[2021-10-07 15:54:10.891] [000d]         Closing log
[2021-10-07 15:54:10.891] [000d]       SessionLogReader.Dispose leaving
[2021-10-07 15:54:10.891] [000d]       Deleting XML log file [D:\tmp\_tmp\wscp14DC.03FA645B.tmp]
[2021-10-07 15:54:10.891] [000d]     Session.Cleanup leaving
[2021-10-07 15:54:10.891] [000d]     Exception: System.TimeoutException: Timeout waiting for WinSCP to respond
[2021-10-07 15:54:10.953] [000d]   SessionLogReader.Read leaving
[2021-10-07 15:54:10.953] [000d]   ElementLogReader.Dispose(group@1) entering
[2021-10-07 15:54:10.953] [000d]     ElementLogReader.ReadToEnd(group@1) entering
[2021-10-07 15:54:10.954] [000d]       SessionLogReader.Read entering
[2021-10-07 15:54:10.954] [000d]         Not reading, session has timed out
[2021-10-07 15:54:10.954] [000d]       SessionLogReader.Read leaving
[2021-10-07 15:54:10.954] [000d]     ElementLogReader.ReadToEnd(group@1) leaving
[2021-10-07 15:54:10.954] [000d]   ElementLogReader.Dispose(group@1) leaving
[2021-10-07 15:54:10.954] [000d] Session.CreateCallstackAndLock leaving
[2021-10-07 15:54:56.000] [000d] Session.CreateCallstackAndLock entering
[2021-10-07 15:54:56.001] [000d]   Session.DoRemoveFiles entering
[2021-10-07 15:54:56.001] [000d]     Exception: System.InvalidOperationException: Session is not opened
[2021-10-07 15:54:56.036] [000d]   Session.DoRemoveFiles leaving
[2021-10-07 15:54:56.036] [000d] Session.CreateCallstackAndLock leaving
[2021-10-07 15:54:56.037] [000d] Session.CreateCallstackAndLock entering
[2021-10-07 15:54:56.037] [000d]   Session.Cleanup entering
[2021-10-07 15:54:56.037] [000d]     Disposing log readers
[2021-10-07 15:54:56.037] [000d]   Session.Cleanup leaving

Reply with quote

Advertisement

vranoch
Joined:
Posts:
2

Got it :-(

The problem resides in this sentence (of the documentation :-( ):
With SFTP protocol, that does not allow execution of arbitrary remote command, separate shell session will be automatically opened
I first tried the default SFTP mode. When I try the SCP mode, the session even does not open. Unfortunately it look like that OpenSSH on Windows 10 does not support SCP. (I try to find a way to transparently remotely execute on both Linux and Windows hosts...

Is there any chance how to make the OpenSSH server on Windows support SCP?

Thanks Jan

Reply with quote

martin
Site Admin
martin avatar
Joined:
Posts:
36,205
Location:
Prague, Czechia

Re: Got it :-(

It's not about "SCP". It's rather that WinSCP needs Unix-like shell. You can have Unix-like shell in Windows 10. But on the other hand, why don't you use for example ssh or plink to execute your command?

Reply with quote

Advertisement

You can post new topics in this forum