Couldn't get handle: Permission denied running SFTP in Co:Z

Randy · Post by **Randy** » Tue Jul 27, 2010 12:32 pm

I am trying to send a z/OS sequential dataset to a UNIX host. The authentication key exchange is successfull as is the batch password exchange.

I get the

ZosDataset: Opening dataset DD:UPLOAD for read

message and some minutes later I get

[62.203] Couldn't get handle: Permission denied

(the values in brackets vary from run to run).

The STDIN datastream is:

Code: Select all

# Customize these ...
coz_bin="/usr/lpp/coz/bin"
remoteuser="hawconv"
server="VQ2UA649"
#servercp="ISO8859-1"
remotepath="/sap_stage/QEC/conv/qtc/"
remotefile="OM03400.DT100717"

# These can be used to read the ssh password from a (secured) dataset
# if you don't want to setup public/private keypairs
export PASSWD_DSN='SYS1.COZ.FTPCNTL'
export SSH_ASKPASS=$coz_bin/read_passwd_dsn.sh
export DISPLAY=none

ssh_opts="-oBatchMode=no"      # allows ssh to use SSH_ASKPASS program
ssh_opts="$ssh_opts -oConnectTimeout=60"
ssh_opts="$ssh_opts -oServerAliveInterval=60"
ssh_opts="$ssh_opts -oStrictHostKeyChecking=no" # accept initial host ke

# Invoke the Co:Z sftp client with an in-line batch of commands
# that uploads a local z/OS dataset to a remote UNIX file.
# Note that "-oBatchMode=no" must be specified before "-b"
#      since ssh opts are first-sticky
# Add -vvv parm before -b- for debugging handel problem, rh 20100727
$coz_bin/cozsftp  $ssh_opts -vvv -b- $remoteuser@$server <<EOB
# Add lzopts loglevel for debugging Handle error, rh 20100727
lzopts loglevel=I
put //DD:UPLOAD $remotepath$remotefile
EOB

The UPLOAD DD is:

Code: Select all

//UPLOAD DD DSN=VRH0.COMSTAR.WR6590.OM03400.DT100717,DISP=OLD

The relevant portions of STDOUT ans STDERR are:

cozsftp> put //DD:UPLOAD /sap_stage/QEC/conv/qtc/OM03400.DT100717
Uploading //DD:UPLOAD to /sap_stage/QEC/conv/qtc/OM03400.DT100717
Co:Z cozsftp version: 1.7.0 (5.0p1) 2010-06-07
Copyright (C) Dovetailed Technologies, LLC. 2008. All rights reserved.
[01.921] debug3: connect_to_server arg=/bin/ssh
[01.921] debug3: connect_to_server arg=-oForwardX11 no
[01.921] debug3: connect_to_server arg=-oForwardAgent no
[01.921] debug3: connect_to_server arg=-oClearAllForwardings yes
[01.921] debug3: connect_to_server arg=-oBatchMode=no
[01.921] debug3: connect_to_server arg=-oConnectTimeout=60
[01.921] debug3: connect_to_server arg=-oServerAliveInterval=60
[01.921] debug3: connect_to_server arg=-oStrictHostKeyChecking=no
[01.921] debug3: connect_to_server arg=-v
[01.921] debug3: connect_to_server arg=-v
[01.921] debug3: connect_to_server arg=-v
[01.921] debug3: connect_to_server arg=-obatchmode yes
[01.921] debug3: connect_to_server arg=-lhawconv
[01.921] debug3: connect_to_server arg=-oProtocol 2
[01.922] debug3: connect_to_server arg=-s
[01.922] debug3: connect_to_server arg=VQ2UA649
[01.922] debug3: connect_to_server arg=sftp
OpenSSH_3.8.1p1, OpenSSL 0.9.7d 17 Mar 2004
debug1: Reading configuration data /etc/ssh/ssh_config

debug3: Seeding PRNG from /usr/lib/ssh/ssh-rand-helper

debug1: Rhosts Authentication disabled, originating port will not be trusted.

debug2: ssh_connect: needpriv 0

debug1: Connecting to VQ2UA649 [170.225.44.175] port 22.

debug2: fd 3 setting O_NONBLOCK

debug1: fd 3 clearing O_NONBLOCK

debug1: Connection established.

debug1: identity file /.ssh/id_rsa type -1

debug1: identity file /.ssh/id_dsa type -1

debug1: Remote protocol version 2.0, remote software version OpenSSH_5.0

debug1: match: OpenSSH_5.0 pat OpenSSH*

debug1: Enabling compatibility mode for protocol 2.0

debug1: Local version string SSH-2.0-OpenSSH_3.8.1p1

debug3: RNG is ready, skipping seeding

debug1: SSH2_MSG_KEXINIT sent

debug2: kex_parse_kexinit: diffie-hellman-group-exchange-sha1,diffie-hellman-gro

debug2: kex_parse_kexinit: ssh-rsa,ssh-dss

debug2: kex_parse_kexinit: aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour,
s128-ctr,aes192-ctr,aes256-ctr

debug2: kex_parse_kexinit: aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour,
s128-ctr,aes192-ctr,aes256-ctr

debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160@open

debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160@open

debug2: kex_parse_kexinit: none,zlib

debug2: kex_parse_kexinit: none,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: diffie-hellman-group-exchange-sha256,diffie-hellman-g
e-hellman-group1-sha1

debug2: kex_parse_kexinit: ssh-rsa,ssh-dss

debug2: kex_parse_kexinit: aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour1
-cbc@lysator.liu.se,aes128-ctr,aes192-ctr,aes256-ctr

debug2: kex_parse_kexinit: aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour
-cbc@lysator.liu.se,aes128-ctr,aes192-ctr,aes256-ctr

debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,umac-64@openssh.com,hmac-ripemd16

debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,umac-64@openssh.com,hmac-ripemd16

debug2: kex_parse_kexinit: none,zlib@openssh.com

debug2: kex_parse_kexinit: none,zlib@openssh.com

debug2: kex_parse_kexinit:

debug2: kex_parse_kexinit:

debug2: kex_parse_kexinit: first_kex_follows 0

debug2: kex_parse_kexinit: reserved 0

debug2: mac_init: found hmac-md5

debug1: kex: server->client aes128-cbc hmac-md5 none

debug2: mac_init: found hmac-md5

debug1: kex: client->server aes128-cbc hmac-md5 none

debug1: SSH2_MSG_KEX_DH_GEX_REQUEST(1024<1024<8192) sent

debug1: expecting SSH2_MSG_KEX_DH_GEX_GROUP
debug2: dh_gen_key: priv key bits set: 137/256

debug2: bits set: 507/1024

debug1: SSH2_MSG_KEX_DH_GEX_INIT sent

debug1: expecting SSH2_MSG_KEX_DH_GEX_REPLY

debug3: check_host_in_hostfile: filename /.ssh/known_hosts

debug3: check_host_in_hostfile: match line 1

debug3: check_host_in_hostfile: filename /.ssh/known_hosts

debug3: check_host_in_hostfile: match line 1

debug1: Host 'vq2ua649' is known and matches the RSA host key.

debug1: Found key in /.ssh/known_hosts:1

debug2: bits set: 542/1024

debug1: ssh_rsa_verify: signature correct

debug2: kex_derive_keys

debug2: set_newkeys: mode 1

debug1: SSH2_MSG_NEWKEYS sent

debug1: expecting SSH2_MSG_NEWKEYS

debug2: set_newkeys: mode 0

debug1: SSH2_MSG_NEWKEYS received

debug1: SSH2_MSG_SERVICE_REQUEST sent

debug2: service_accept: ssh-userauth

debug1: SSH2_MSG_SERVICE_ACCEPT received

debug2: key: /.ssh/id_rsa (0)

debug2: key: /.ssh/id_dsa (0)

debug1: Authentications that can continue: publickey,password,keyboard-interact

debug3: start over, passed a different list publickey,password,keyboard-interac

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: Trying private key: /.ssh/id_rsa

debug3: no such identity: /.ssh/id_rsa

debug1: Trying private key: /.ssh/id_dsa
debug3: no such identity: /.ssh/id_dsa

debug2: we did not send a packet, disable method

debug3: authmethod_lookup keyboard-interactive

debug3: remaining preferred: password

debug3: authmethod_is_enabled keyboard-interactive

debug1: Next authentication method: keyboard-interactive

debug2: userauth_kbdint

debug2: we sent a keyboard-interactive packet, wait for reply

debug2: input_userauth_info_req

debug2: input_userauth_info_req: num_prompts 1

fromdsn(SYS1.COZ.FTPCNTL)[N]: 1 records/80 bytes read; 81 bytes written in 0.01
debug3: packet_send2: adding 16 (len 94 padlen 18 extra_pad 64)

debug2: input_userauth_info_req

debug2: input_userauth_info_req: num_prompts 0

debug3: packet_send2: adding 48 (len 10 padlen 6 extra_pad 64)

debug1: Authentication succeeded (keyboard-interactive).

debug2: fd 4 setting O_NONBLOCK
debug2: fd 5 setting O_NONBLOCK

debug2: fd 6 setting O_NONBLOCK

debug1: channel 0: new [client-session]

debug3: ssh_session2_open: channel_new: 0

debug2: channel 0: send open

debug1: Entering interactive session.

debug2: callback start

debug2: ssh_session2_setup: id 0

debug1: Sending subsystem: sftp

debug2: channel 0: request subsystem

debug2: callback done

debug2: channel 0: open confirm rwindow 0 rmax 32768

debug2: channel 0: rcvd adjust 2097152

[10.035] debug2: Remote version: 3
[10.088] debug2: Init extension: "posix-rename@openssh.com"
[10.088] debug3: Sent message fd 6 T:16 I:1
[10.134] debug3: SSH_FXP_REALPATH . -> /
ZosDataset: Opening dataset DD:UPLOAD for read
[62.168] debug3: Sent message SSH2_FXP_OPEN I:2 P:/sap_stage/QEC/conv/qtc/OM034
ZosDataset: Closing dataset //DD:UPLOAD - 0 records read, 0 bytes sent
[62.206] debug3: process_put() err=-1
debug2: channel 0: read<=0 rfd 4 len 0

debug2: channel 0: read failed

debug2: channel 0: close_read

debug2: channel 0: input open -> drain

debug2: channel 0: ibuf empty

debug2: channel 0: send eof

debug2: channel 0: input drain -> closed

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

debug1: client_input_channel_req: channel 0 rtype exit-status reply 0

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)

debug3: channel 0: close_fds r -1 w -1 e 6

debug1: fd 0 clearing O_NONBLOCK

debug1: fd 1 clearing O_NONBLOCK

debug1: fd 2 clearing O_NONBLOCK

debug1: Transferred: stdin 0, stdout 0, stderr 0 bytes in 152.3 seconds

debug1: Bytes per second: stdin 0.0, stdout 0.0, stderr 0.0

debug1: Exit status 0

(note that the far righthand portion of some text is truncated due to screen size)

Post by **dovetail** » Fri Jul 30, 2010 12:18 pm

According to this log, the remote server rejected the request to open the file, due to a permission (security) problem.

From the remote path name, it looks like you are using a Windows server. Are you using cygwin with OpenSSH as your SSH/SFTP server? If so, you may want to log in remotely via ssh to this server using the same userid to verify that you have access to the files.

In later versions of Windows (Vista, Windows7), there are some gotchas for setting up cygwin/OpenSSH in order to get the logged in user's security setup correctly. Search the cygwin lists for more information.

Randy · Post by **Randy** » Fri Jul 30, 2010 12:46 pm

That's the way it looked to me also, but I'm new to USS and FTP, so wanted confirmation.

Resolved. Target USERID was in the wrong security group.
FYI Target is either AIX or HPUX.

Thanks for your help.