Connection closed?

A discussion of Co:Z sftp, a port of OpenSSH sftp for z/OS
Post Reply
LIonel_Dyck
Posts: 10
Joined: Thu Jun 25, 2020 9:18 am

Connection closed?

Post by LIonel_Dyck » Thu Jun 25, 2020 11:18 am

I just installed Co:Z SFTP on our z/OS 2.4 system and it works great. I then copied/installed it on our z/OS 2.2 system and it doesn't work so well:

/u/slbd>sftp slbd@127.0.0.1
slbd@127.0.0.1's password:
FOTS0841 Connection closed
>/u/slbd>

What should I look for to resolve this?

dovetail
Site Admin
Posts: 1951
Joined: Thu Jul 29, 2004 12:12 pm

Re: Connection closed?

Post by dovetail » Thu Jun 25, 2020 3:27 pm

It sounds like something might be wrong with the SSHD server on this system?

try:

sftp -vvv slbd@127.0.0.1

so that you can get a trace.

Note: This isn't your problem, if your client is z/OS with Co:Z installed, then you would want to use the Co:Z enhance sftp client for z/OS:

cozsftp -vvv slbd@127.0.0.1

LIonel_Dyck
Posts: 10
Joined: Thu Jun 25, 2020 9:18 am

Re: Connection closed?

Post by LIonel_Dyck » Thu Jun 25, 2020 6:40 pm

No joy but here's the trace:

/u/slbd>cozsftp -vvv slbd@127.0.0.1
Co:Z SFTP version: 6.1.0 (7.6p1) 2020-05-01
Copyright (C) Dovetailed Technologies, LLC. 2008-2020. All rights reserved.
Connecting to 127.0.0.1...
[18:39:19.523777] debug3: connect_to_server arg=/bin/ssh
[18:39:19.523793] debug3: connect_to_server arg=-oForwardX11 no
[18:39:19.523798] debug3: connect_to_server arg=-oForwardAgent no
[18:39:19.523812] debug3: connect_to_server arg=-oClearAllForwardings yes
[18:39:19.523815] debug3: connect_to_server arg=-v
[18:39:19.523818] debug3: connect_to_server arg=-v
[18:39:19.523822] debug3: connect_to_server arg=-v
[18:39:19.523825] debug3: connect_to_server arg=-l
[18:39:19.523828] debug3: connect_to_server arg=slbd
[18:39:19.523831] debug3: connect_to_server arg=-oProtocol 2
[18:39:19.523834] debug3: connect_to_server arg=-s
[18:39:19.523838] debug3: connect_to_server arg=--
[18:39:19.523841] debug3: connect_to_server arg=127.0.0.1
[18:39:19.523844] debug3: connect_to_server arg=sftp
[18:39:19.526288] debug2: setting ssh _CEE_RUNOPTS=HEAP(12M,1M,ANYWHERE,FREE),ENVAR("_CEE_REALLOC_CONTROL=256K,25")
OpenSSH_6.4, OpenSSL 1.0.2h 3 May 2016
debug1: Reading configuration data /etc/ssh/ssh_config
debug3: setUseZEDC: 0
debug1: zsshSmfSetConnSmfStatus: SMF status is 0
debug2: ssh_connect: needpriv 0
debug1: Connecting to 127.0.0.1 [127.0.0.1] port 22.
debug1: Connection established.
debug1: cipher_init: none from source OpenSSL, used in non-FIPS mode
debug1: cipher_init: none from source OpenSSL, used in non-FIPS mode
debug3: zsshGetpw: passwd name=SLBD, uid=38055432, gid=0, dir=/u/slbd, shell=/bin/sh
debug3: Incorrect RSA1 identifier
debug3: Could not load "/u/slbd/.ssh/id_rsa" as a RSA1 public key
debug1: identity file /u/slbd/.ssh/id_rsa type 1
debug1: identity file /u/slbd/.ssh/id_rsa-cert type -1
debug1: identity file /u/slbd/.ssh/id_dsa type -1
debug1: identity file /u/slbd/.ssh/id_dsa-cert type -1
debug1: identity file /u/slbd/.ssh/id_ecdsa type -1
debug1: identity file /u/slbd/.ssh/id_ecdsa-cert type -1
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_6.4
debug1: Remote protocol version 2.0, remote software version OpenSSH_6.4
debug1: match: OpenSSH_6.4 pat OpenSSH*
debug2: fd 3 setting O_NONBLOCK
debug3: load_hostkeys: loading entries for host "127.0.0.1" from file "/u/slbd/.ssh/known_hosts"
debug3: load_hostkeys: found key type ECDSA in file /u/slbd/.ssh/known_hosts:80
debug3: load_hostkeys: loaded 1 keys
debug3: order_hostkeyalgs: prefer hostkeyalgs: ecdsa-sha2-nistp256-cert-v01@openssh.com,ecdsa-sha2-nistp384-cert-v01@openssh.com,ecdsa-sha2-nistp521-cert-v01@openssh.com,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521
debug1: SSH2_MSG_KEXINIT sent
debug1: SSH2_MSG_KEXINIT received
debug2: kex_parse_kexinit: ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
debug2: kex_parse_kexinit: ecdsa-sha2-nistp256-cert-v01@openssh.com,ecdsa-sha2-nistp384-cert-v01@openssh.com,ecdsa-sha2-nistp521-cert-v01@openssh.com,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,ssh-rsa-cert-v01@openssh.com,ssh-dss-cert-v01@openssh.com,ssh-rsa-cert-v00@openssh.com,ssh-dss-cert-v00@openssh.com,ssh-rsa,ssh-dss
debug2: kex_parse_kexinit: aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-gcm@openssh.com,aes256-gcm@openssh.com,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc@lysator.liu.se
debug2: kex_parse_kexinit: aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-gcm@openssh.com,aes256-gcm@openssh.com,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc@lysator.liu.se
debug2: kex_parse_kexinit: hmac-md5-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-ripemd160-etm@openssh.com,hmac-sha1-96-etm@openssh.com,hmac-md5-96-etm@openssh.com,hmac-md5,hmac-sha1,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: hmac-md5-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-ripemd160-etm@openssh.com,hmac-sha1-96-etm@openssh.com,hmac-md5-96-etm@openssh.com,hmac-md5,hmac-sha1,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: none,zlib@openssh.com,zlib
debug2: kex_parse_kexinit: none,zlib@openssh.com,zlib
debug2: kex_parse_kexinit:
debug2: kex_parse_kexinit:
debug2: kex_parse_kexinit: first_kex_follows 0
debug2: kex_parse_kexinit: reserved 0
debug2: kex_parse_kexinit: ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
debug2: kex_parse_kexinit: ssh-rsa,ssh-dss,ecdsa-sha2-nistp256
debug2: kex_parse_kexinit: aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-gcm@openssh.com,aes256-gcm@openssh.com,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc@lysator.liu.se
debug2: kex_parse_kexinit: aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-gcm@openssh.com,aes256-gcm@openssh.com,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc@lysator.liu.se
debug2: kex_parse_kexinit: hmac-md5-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-ripemd160-etm@openssh.com,hmac-sha1-96-etm@openssh.com,hmac-md5-96-etm@openssh.com,hmac-md5,hmac-sha1,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: hmac-md5-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-ripemd160-etm@openssh.com,hmac-sha1-96-etm@openssh.com,hmac-md5-96-etm@openssh.com,hmac-md5,hmac-sha1,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: none
debug2: kex_parse_kexinit: none
debug2: kex_parse_kexinit:
debug2: kex_parse_kexinit:
debug2: kex_parse_kexinit: first_kex_follows 0
debug2: kex_parse_kexinit: reserved 0
debug1: mac_setup_by_alg: hmac-md5-etm@openssh.com from source OpenSSL, used in non-FIPS mode
debug2: mac_setup: found hmac-md5-etm@openssh.com
debug1: kex: server->client aes128-ctr hmac-md5-etm@openssh.com none
debug1: mac_setup_by_alg: hmac-md5-etm@openssh.com from source OpenSSL, used in non-FIPS mode
debug2: mac_setup: found hmac-md5-etm@openssh.com
debug1: kex: client->server aes128-ctr hmac-md5-etm@openssh.com none
debug1: choose_kex: ecdh-sha2-nistp256 from source OpenSSL, used in non-FIPS mode
debug1: sending SSH2_MSG_KEX_ECDH_INIT
debug1: expecting SSH2_MSG_KEX_ECDH_REPLY
debug1: Server host key: ECDSA MD5 fp 95:6a:34:8a:d5:6f:e3:e5:b1:b9:8d:55:09:5b:88:fd
debug3: load_hostkeys: loading entries for host "127.0.0.1" from file "/u/slbd/.ssh/known_hosts"
debug3: load_hostkeys: found key type ECDSA in file /u/slbd/.ssh/known_hosts:80
debug3: load_hostkeys: loaded 1 keys
debug1: Host '127.0.0.1' is known and matches the ECDSA host key.
debug1: Found key in /u/slbd/.ssh/known_hosts:80
debug1: ssh_ecdsa_verify: signature correct
debug2: kex_derive_keys
debug2: set_newkeys: mode 1
debug1: cipher_init: aes128-ctr from source CPACF, used in non-FIPS mode
debug1: SSH2_MSG_NEWKEYS sent
debug1: expecting SSH2_MSG_NEWKEYS
debug1: SSH2_MSG_NEWKEYS received
debug2: set_newkeys: mode 0
debug1: cipher_init: aes128-ctr from source CPACF, used in non-FIPS mode
debug1: SSH2_MSG_SERVICE_REQUEST sent
debug2: service_accept: ssh-userauth
debug1: SSH2_MSG_SERVICE_ACCEPT received
debug2: key: /u/slbd/.ssh/id_rsa (1B531930),
debug2: key: /u/slbd/.ssh/id_dsa (0),
debug2: key: /u/slbd/.ssh/id_ecdsa (0),
debug1: Authentications that can continue: publickey,password
debug3: start over, passed a different list publickey,password
debug3: preferred publickey,keyboard-interactive,password
debug3: authmethod_lookup publickey
debug3: remaining preferred: keyboard-interactive,password
debug3: authmethod_is_enabled publickey
debug1: Next authentication method: publickey
debug1: Offering RSA public key: /u/slbd/.ssh/id_rsa
debug3: send_pubkey_test
debug2: we sent a publickey packet, wait for reply
debug1: Authentications that can continue: publickey,password
debug1: Trying private key: /u/slbd/.ssh/id_dsa
debug3: no such identity: /u/slbd/.ssh/id_dsa: EDC5129I No such file or directory. (errno2=0x053B006C)
debug1: Trying private key: /u/slbd/.ssh/id_ecdsa
debug3: no such identity: /u/slbd/.ssh/id_ecdsa: EDC5129I No such file or directory. (errno2=0x053B006C)
debug2: we did not send a packet, disable method
debug3: authmethod_lookup password
debug3: remaining preferred: ,password
debug3: authmethod_is_enabled password
debug1: Next authentication method: password
slbd@127.0.0.1's password:
debug3: packet_send2: adding 64 (len 53 padlen 11 extra_pad 64)
debug2: we sent a password packet, wait for reply
debug1: Authentication succeeded (password).
Authenticated to 127.0.0.1 ([127.0.0.1]:22).
debug3: options.client_smf = none
debug2: fd 4 setting O_NONBLOCK
debug2: fd 5 setting O_NONBLOCK
debug1: channel 0: new [client-session]
debug3: ssh_session2_open: channel_new: 0
debug2: channel 0: send open
debug1: Requesting no-more-sessions@openssh.com
debug1: Entering interactive session.
debug2: callback start
debug2: fd 3 setting TCP_NODELAY
debug2: client_session2_setup: id 0
debug1: Sending subsystem: sftp
debug3: channel 0: is not converting type "subsystem"
debug2: channel 0: request subsystem confirm 1
debug2: callback done
debug2: channel 0: open confirm rwindow 0 rmax 32768
debug2: channel 0: rcvd adjust 2097152
debug2: channel_input_status_confirm: type 99 id 0
debug2: subsystem request accepted on channel 0
debug1: client_input_channel_req: channel 0 rtype exit-status reply 0
debug3: channel 0: is not converting type "exit-status"
debug1: client_input_channel_req: channel 0 rtype eow@openssh.com reply 0
debug2: channel 0: rcvd eow
debug2: channel 0: close_read
debug2: channel 0: input open -> closed
debug3: channel 0: is not converting type "eow@openssh.com"
debug2: channel 0: rcvd eof
debug2: channel 0: output open -> drain
debug2: channel 0: obuf empty
debug2: channel 0: close_write
debug2: channel 0: output drain -> closed
debug2: channel 0: rcvd close
debug3: channel 0: will not send data after close
debug2: channel 0: almost dead
debug2: channel 0: gc: notify user
debug2: channel 0: gc: user detached
debug2: channel 0: send close
debug2: channel 0: is dead
debug2: channel 0: garbage collecting
debug1: channel 0: free: client-session, nchannels 1
debug3: channel 0: status: The following connections are open:
#0 client-session (t4 r0 i3/0 o3/0 fd -1/-1 cfd -1)

debug1: fd 0 clearing O_NONBLOCK
debug1: fd 1 clearing O_NONBLOCK
Transferred: sent 2736, received 2140 bytes, in 3.6 seconds
Bytes per second: sent 761.8, received 595.9
debug1: Exit status 127
Connection closed.
[18:39:30.664301] Connection closed
[18:39:30.664314] debug1: _zos_exit(255): SSH failed to start connection (12)
/u/slbd>

dovetail
Site Admin
Posts: 1951
Joined: Thu Jul 29, 2004 12:12 pm

Re: Connection closed?

Post by dovetail » Thu Jun 25, 2020 7:41 pm

This looks like there is a problem when the SSHD server tries to start the sftp subsystem program.

Check the /etc/ssh/sshd_config file, specifically the "Subsystem" line to see that it points to the Co:Z SFTP server shell script.
The line should look something like:

Subsystem sftp /usr/local/coz/bin/sftp-server.sh

... assuming that /usr/local/coz is the base install directory for Co:Z SFTP. Check for a typo.

This covered in Step 1 here: https://www.dovetail.com/docs/sftp/conf ... start_sftp

If you change sshd_config, you will need to either restart SSHD or use the kill -HUP command documented here.

Another problem might be that if you somehow copied the Co:Z install filesystem without getting all of the permissions and extended attributes right, then you will have problems like this if sftp-server.sh isn't world-executable.

LIonel_Dyck
Posts: 10
Joined: Thu Jun 25, 2020 9:18 am

Re: Connection closed?

Post by LIonel_Dyck » Fri Jun 26, 2020 2:18 am

Solved - my sshd_config was missing the /bin - once again the problem was between the keyboard and the chair :(

Post Reply