Command line open compared to exe session usage

Advertisement

dpreston
Joined:
Posts:
4
Location:
Rochester, Mn

Command line open compared to exe session usage

I am using winscp: 4.1.9 on Windows XP.
I created a session which works fine, I receive a error command 'groups' failed with return code 1 and error message -bsh: groups: not found. I press OK.
Then the session opens.
I can transfer files using SFTP.
The SFTP server is an AS400 v 5.3.
The winscp.com version will not connect. I created a script file and execute by: winscp.com /script:=winscpscr.txt /log=winscplog.txt
I received the error: connection has been unexpectedly closed. Server sent command exit status 1.
my script file:
open sftp://sftpusr2:sftpuser@192.168.1.6:22
option transfer binary
option confirm off
lcd c:\dictfldr\
cd /home/sftpuser
put -delete *.*
exit

the log file:
WinSCP Version 4.1.9 (Build 416) (OS 5.1.2600 Service Pack 3)
Login time: Monday, June 15, 2009 2:48:02 PM
--------------------------------------------------------------------------
Session name: sftpusr2@192.168.1.6
Host name: 192.168.1.6 (Port: 22)
User name: sftpusr2 (Password: Yes, Key file: No)
Tunnel: No
Transfer Protocol: SFTP
Ping type: -, Ping interval: 30 sec; Timeout: 15 sec
Proxy: none
SSH protocol version: 2; Compression: No
Bypass authentication: No
Try agent: Yes; Agent forwarding: No; TIS/CryptoCard: No; KI: Yes; GSSAPI: No
Ciphers: aes,blowfish,3des,WARN,arcfour,des; Ssh2DES: No
SSH Bugs: -,-,-,-,-,-,-,-
SFTP Bugs: -,-
Return code variable: Autodetect; Lookup user groups: Yes
Shell: default, EOL: 0
Clear aliases: Yes, Unset nat.vars: Yes, Resolve symlinks: Yes
LS: ls -la, Ign LS warn: Yes, Scp1 Comp: No
Local directory: default, Remote directory: home, Update: No, Cache: Yes
Cache directory changes: Yes, Permanent: Yes
DST mode: 1
--------------------------------------------------------------------------
Looking up host "192.168.1.6"
Connecting to 192.168.1.6 port 22
Server version: SSH-1.5-OpenSSH_3.5p1
We claim version: SSH-1.5-WinSCP_release_4.1.9
Using SSH protocol version 1
Received public keys
Host key fingerprint is:
2048 e8:c4:5e:75:8f:cc:69:02:40:b3:94:e1:b9:db:4b:3d
Encrypted session key
AES not supported in SSH-1, skipping
Using Blowfish encryption
Trying to enable encryption...
Initialised Blowfish-128 CBC encryption
Installing CRC compensation attack detector
Successfully started encryption
Sent username "sftpusr2"
Prompt (6, SSH password, , &Password: )
Using stored password.
Sending password with camouflage packets
Sent password
Authentication successful
Started session
--------------------------------------------------------------------------
Using SFTP protocol.
Doing startup conversation with host.
Type: SSH_FXP_INIT, Size: 5, Number: -1
! bsh: sftp-server: not found
Server sent command exit status 1
Disconnected

Reply with quote

Advertisement

martin
Site Admin
martin avatar
Joined:
Posts:
40,476
Location:
Prague, Czechia

Re: Command line open compared to exe session usage

Can you post a log file from successful session? You can also try to use "open your_session_name".

Reply with quote

dpreston
Joined:
Posts:
4
Location:
Rochester, Mn

Login Problems

I found out 2 things. The SFTP connection via the GUI interface was falling back to SCP. When I unchecked the fallback box it would not connect at all.

Today I cant connect at all except FTP. The server is running but not responding to windows requests.

Thanks, Doug

Reply with quote

dpreston
Joined:
Posts:
4
Location:
Rochester, Mn

Successful connect Log file

We had to start a job on the server to initiate the SSH.
Below is the log file - SSH working!
Thanks for the information.

2009-06-22 12:00:13.236 WinSCP Version 4.1.9 (Build 416) (OS 5.1.2600 Service Pack 3)
. 2009-06-22 12:00:13.236 Login time: Monday, June 22, 2009 12:00:13 PM
. 2009-06-22 12:00:13.236 --------------------------------------------------------------------------
. 2009-06-22 12:00:13.236 Session name: 192.168.1.6
. 2009-06-22 12:00:13.236 Host name: 192.168.1.6 (Port: 22)
. 2009-06-22 12:00:13.236 User name: (Password: No, Key file: No)
. 2009-06-22 12:00:13.236 Tunnel: No
. 2009-06-22 12:00:13.236 Transfer Protocol: SFTP (SCP)
. 2009-06-22 12:00:13.236 Ping type: -, Ping interval: 30 sec; Timeout: 15 sec
. 2009-06-22 12:00:13.236 Proxy: none
. 2009-06-22 12:00:13.236 SSH protocol version: 2; Compression: No
. 2009-06-22 12:00:13.236 Bypass authentication: No
. 2009-06-22 12:00:13.236 Try agent: Yes; Agent forwarding: No; TIS/CryptoCard: No; KI: Yes; GSSAPI: No
. 2009-06-22 12:00:13.236 Ciphers: aes,blowfish,3des,WARN,arcfour,des; Ssh2DES: No
. 2009-06-22 12:00:13.236 SSH Bugs: -,-,-,-,-,-,-,-
. 2009-06-22 12:00:13.236 SFTP Bugs: -,-
. 2009-06-22 12:00:13.236 Return code variable: Autodetect; Lookup user groups: Yes
. 2009-06-22 12:00:13.236 Shell: default, EOL: 1
. 2009-06-22 12:00:13.236 Clear aliases: Yes, Unset nat.vars: Yes, Resolve symlinks: Yes
. 2009-06-22 12:00:13.236 LS: ls -la, Ign LS warn: Yes, Scp1 Comp: No
. 2009-06-22 12:00:13.236 Local directory: C:\Documents and Settings\Doug\My Documents, Remote directory: /home/sftpuser, Update: No, Cache: Yes
. 2009-06-22 12:00:13.236 Cache directory changes: Yes, Permanent: Yes
. 2009-06-22 12:00:13.236 DST mode: 0
. 2009-06-22 12:00:13.236 --------------------------------------------------------------------------
. 2009-06-22 12:00:13.299 Looking up host "192.168.1.6"
. 2009-06-22 12:00:13.314 Connecting to 192.168.1.6 port 22
. 2009-06-22 12:00:14.346 Server version: SSH-1.99-OpenSSH_3.5p1
. 2009-06-22 12:00:14.346 We claim version: SSH-2.0-WinSCP_release_4.1.9
. 2009-06-22 12:00:14.346 SSPI: acquired credentials for: Doug@DOUGPRESTON
. 2009-06-22 12:00:14.346 Cannot convert IP address to SPN: DNS is not trusted
. 2009-06-22 12:00:14.346 GSSKEX disabled: The operation completed successfully.

. 2009-06-22 12:00:14.346 Using SSH protocol version 2
. 2009-06-22 12:00:14.392 Doing Diffie-Hellman group exchange
. 2009-06-22 12:00:15.205 Doing Diffie-Hellman key exchange with hash SHA-1
. 2009-06-22 12:00:29.611 Host key fingerprint is:
. 2009-06-22 12:00:29.611 ssh-rsa 1024 36:13:df:83:e3:43:c1:01:f9:00:d7:60:bd:cb:66:de
. 2009-06-22 12:00:29.611 Initialised AES-256 CBC client->server encryption
. 2009-06-22 12:00:29.611 Initialised HMAC-SHA1 client->server MAC algorithm
. 2009-06-22 12:00:29.611 Initialised AES-256 CBC server->client encryption
. 2009-06-22 12:00:29.611 Initialised HMAC-SHA1 server->client MAC algorithm
. 2009-06-22 12:00:29.611 Prompt (1, SSH login name, , login as: )
. 2009-06-22 12:00:36.642 Keyboard-interactive authentication refused
. 2009-06-22 12:00:36.642 Prompt (6, SSH password, , &Password: )
. 2009-06-22 12:00:39.158 Sent password
. 2009-06-22 12:00:39.299 Access granted
. 2009-06-22 12:00:39.314 Opened channel for session
. 2009-06-22 12:00:40.392 Started a shell/command
. 2009-06-22 12:00:40.392 --------------------------------------------------------------------------
. 2009-06-22 12:00:40.392 Using SFTP protocol.
. 2009-06-22 12:00:40.392 Doing startup conversation with host.
> 2009-06-22 12:00:40.408 Type: SSH_FXP_INIT, Size: 5, Number: -1
< 2009-06-22 12:00:42.392 Type: SSH_FXP_VERSION, Size: 5, Number: -1
. 2009-06-22 12:00:42.392 SFTP version 3 negotiated.
. 2009-06-22 12:00:42.392 We believe the server has signed timestamps bug
. 2009-06-22 12:00:42.392 We will use UTF-8 strings for status messages only
. 2009-06-22 12:00:42.392 Limiting packet size to OpenSSH sftp-server limit of 262148 bytes
. 2009-06-22 12:00:42.392 Changing directory to "/home/sftpuser".
. 2009-06-22 12:00:42.392 Getting real path for '/home/sftpuser'
> 2009-06-22 12:00:42.392 Type: SSH_FXP_REALPATH, Size: 23, Number: 9744
< 2009-06-22 12:00:42.408 Type: SSH_FXP_NAME, Size: 49, Number: 9744
. 2009-06-22 12:00:42.408 Real path is '/home/sftpuser'
. 2009-06-22 12:00:42.408 Trying to open directory "/home/sftpuser".
> 2009-06-22 12:00:42.408 Type: SSH_FXP_LSTAT, Size: 23, Number: 9991
< 2009-06-22 12:00:42.424 Type: SSH_FXP_ATTRS, Size: 37, Number: 9991
. 2009-06-22 12:00:42.424 Getting current directory name.
. 2009-06-22 12:00:42.424 Listing directory "/home/sftpuser".
> 2009-06-22 12:00:42.424 Type: SSH_FXP_OPENDIR, Size: 23, Number: 10251
< 2009-06-22 12:00:42.424 Type: SSH_FXP_HANDLE, Size: 13, Number: 10251
> 2009-06-22 12:00:42.424 Type: SSH_FXP_READDIR, Size: 13, Number: 10508
< 2009-06-22 12:00:42.564 Type: SSH_FXP_NAME, Size: 1019, Number: 10508
> 2009-06-22 12:00:42.564 Type: SSH_FXP_READDIR, Size: 13, Number: 10764
< 2009-06-22 12:00:42.564 Type: SSH_FXP_STATUS, Size: 28, Number: 10764
< 2009-06-22 12:00:42.564 Status/error code: 1
> 2009-06-22 12:00:42.564 Type: SSH_FXP_CLOSE, Size: 13, Number: 11012
. 2009-06-22 12:00:42.564 Startup conversation with host finished.
. 2009-06-22 12:00:47.736 Cached directory change via ".." to "/home".
. 2009-06-22 12:00:47.736 Getting current directory name.
. 2009-06-22 12:00:47.736 Listing directory "/home".
> 2009-06-22 12:00:47.736 Type: SSH_FXP_OPENDIR, Size: 14, Number: 11275
< 2009-06-22 12:00:47.736 Type: SSH_FXP_STATUS, Size: 24, Number: 11012
. 2009-06-22 12:00:47.736 Discarding reserved response
< 2009-06-22 12:00:47.752 Type: SSH_FXP_HANDLE, Size: 13, Number: 11275
> 2009-06-22 12:00:47.752 Type: SSH_FXP_READDIR, Size: 13, Number: 11532
< 2009-06-22 12:00:47.830 Type: SSH_FXP_NAME, Size: 647, Number: 11532
> 2009-06-22 12:00:47.830 Type: SSH_FXP_READDIR, Size: 13, Number: 11788
< 2009-06-22 12:00:47.830 Type: SSH_FXP_STATUS, Size: 28, Number: 11788
< 2009-06-22 12:00:47.830 Status/error code: 1
> 2009-06-22 12:00:47.830 Type: SSH_FXP_CLOSE, Size: 13, Number: 12036
. 2009-06-22 12:00:48.642 Cached directory change via ".." to "/".
. 2009-06-22 12:00:48.642 Getting current directory name.
. 2009-06-22 12:00:48.642 Listing directory "/".
> 2009-06-22 12:00:48.642 Type: SSH_FXP_OPENDIR, Size: 10, Number: 12299
< 2009-06-22 12:00:48.642 Type: SSH_FXP_STATUS, Size: 24, Number: 12036
. 2009-06-22 12:00:48.642 Discarding reserved response
< 2009-06-22 12:00:48.658 Type: SSH_FXP_HANDLE, Size: 13, Number: 12299
> 2009-06-22 12:00:48.658 Type: SSH_FXP_READDIR, Size: 13, Number: 12556
< 2009-06-22 12:00:49.424 Type: SSH_FXP_NAME, Size: 4990, Number: 12556
> 2009-06-22 12:00:49.424 Type: SSH_FXP_READDIR, Size: 13, Number: 12812
. 2009-06-22 12:00:49.424 Reading symlink "bin".
> 2009-06-22 12:00:49.424 Type: SSH_FXP_READLINK, Size: 13, Number: 13075
> 2009-06-22 12:00:49.424 Type: SSH_FXP_STAT, Size: 13, Number: 13329
< 2009-06-22 12:00:49.439 Type: SSH_FXP_STATUS, Size: 28, Number: 12812
. 2009-06-22 12:00:49.439 Storing reserved response
< 2009-06-22 12:00:49.627 Type: SSH_FXP_NAME, Size: 37, Number: 13075
< 2009-06-22 12:00:49.627 Type: SSH_FXP_ATTRS, Size: 37, Number: 13329
. 2009-06-22 12:00:49.627 Reading symlink "lib".
> 2009-06-22 12:00:49.627 Type: SSH_FXP_READLINK, Size: 13, Number: 13587
> 2009-06-22 12:00:49.627 Type: SSH_FXP_STAT, Size: 13, Number: 13841
< 2009-06-22 12:00:49.642 Type: SSH_FXP_NAME, Size: 37, Number: 13587
< 2009-06-22 12:00:49.830 Type: SSH_FXP_ATTRS, Size: 37, Number: 13841
. 2009-06-22 12:00:49.830 Reading symlink "AS400JT".
> 2009-06-22 12:00:49.830 Type: SSH_FXP_READLINK, Size: 17, Number: 14099
> 2009-06-22 12:00:49.830 Type: SSH_FXP_STAT, Size: 17, Number: 14353
< 2009-06-22 12:00:49.846 Type: SSH_FXP_NAME, Size: 73, Number: 14099
< 2009-06-22 12:00:50.033 Type: SSH_FXP_ATTRS, Size: 37, Number: 14353
< 2009-06-22 12:00:50.033 Status/error code: 1
> 2009-06-22 12:00:50.033 Type: SSH_FXP_CLOSE, Size: 13, Number: 14596
. 2009-06-22 12:00:55.033 Changing directory to "Roxanne".
. 2009-06-22 12:00:55.033 Getting real path for '/Roxanne'
> 2009-06-22 12:00:55.033 Type: SSH_FXP_REALPATH, Size: 17, Number: 14864
< 2009-06-22 12:00:55.033 Type: SSH_FXP_STATUS, Size: 24, Number: 14596
. 2009-06-22 12:00:55.033 Discarding reserved response
< 2009-06-22 12:00:55.049 Type: SSH_FXP_NAME, Size: 37, Number: 14864
. 2009-06-22 12:00:55.049 Real path is '/Roxanne'
. 2009-06-22 12:00:55.049 Trying to open directory "/Roxanne".
> 2009-06-22 12:00:55.049 Type: SSH_FXP_LSTAT, Size: 17, Number: 15111
< 2009-06-22 12:00:55.049 Type: SSH_FXP_ATTRS, Size: 37, Number: 15111
. 2009-06-22 12:00:55.049 Getting current directory name.
. 2009-06-22 12:00:55.049 Listing directory "/Roxanne".
> 2009-06-22 12:00:55.049 Type: SSH_FXP_OPENDIR, Size: 17, Number: 15371
< 2009-06-22 12:00:55.111 Type: SSH_FXP_HANDLE, Size: 13, Number: 15371
> 2009-06-22 12:00:55.111 Type: SSH_FXP_READDIR, Size: 13, Number: 15628
< 2009-06-22 12:00:55.939 Type: SSH_FXP_NAME, Size: 2591, Number: 15628
> 2009-06-22 12:00:55.939 Type: SSH_FXP_READDIR, Size: 13, Number: 15884
< 2009-06-22 12:00:55.955 Type: SSH_FXP_STATUS, Size: 28, Number: 15884
< 2009-06-22 12:00:55.955 Status/error code: 1
> 2009-06-22 12:00:55.955 Type: SSH_FXP_CLOSE, Size: 13, Number: 16132
. 2009-06-22 12:01:06.408 File: "/Roxanne/DOBBELAERE.pdf"
. 2009-06-22 12:01:06.408 Copying "/Roxanne/DOBBELAERE.pdf" to local directory started.
. 2009-06-22 12:01:06.408 Binary transfer mode selected.
. 2009-06-22 12:01:06.408 Opening remote file.
> 2009-06-22 12:01:06.408 Type: SSH_FXP_OPEN, Size: 40, Number: 16387
< 2009-06-22 12:01:06.408 Type: SSH_FXP_STATUS, Size: 24, Number: 16132
. 2009-06-22 12:01:06.408 Discarding reserved response
< 2009-06-22 12:01:06.424 Type: SSH_FXP_HANDLE, Size: 13, Number: 16387
> 2009-06-22 12:01:06.424 Type: SSH_FXP_FSTAT, Size: 13, Number: 16648
> 2009-06-22 12:01:06.424 Type: SSH_FXP_READ, Size: 25, Number: 16901
< 2009-06-22 12:01:06.424 Type: SSH_FXP_ATTRS, Size: 37, Number: 16648
. 2009-06-22 12:01:06.424 Storing reserved response
< 2009-06-22 12:01:06.471 Status/error code: 1
. 2009-06-22 12:01:06.471 3 skipped SSH_FXP_WRITE, SSH_FXP_READ, SSH_FXP_DATA and SSH_FXP_STATUS packets.
> 2009-06-22 12:01:06.471 Type: SSH_FXP_CLOSE, Size: 13, Number: 17412
. 2009-06-22 12:36:25.846 Closing connection.
. 2009-06-22 12:36:25.846 Sending special code: 12
. 2009-06-22 12:36:25.846 Sent EOF message

Reply with quote

martin
Site Admin
martin avatar

Re: Successful connect Log file

In the log I see that fallback to SCP is enabled, but it is not used, regular SFTP session is started. I'm confused.

Reply with quote

Advertisement

dpreston
Joined:
Posts:
4
Location:
Rochester, Mn

Re: Successful connect Log file

martin wrote:

In the log I see that fallback to SCP is enabled, but it is not used, regular SFTP session is started. I'm confused.

Yes, you are right. I am not sure why it did not work the other day, but it works correctly now! Thanks for looking into my problem.

Doug

Reply with quote

Advertisement

You can post new topics in this forum