STDIN commands not executing

Discussion of the Co:Z Co-Processing Toolkit for z/OS
Post Reply
usaajrm
Posts: 80
Joined: Tue Feb 06, 2007 3:46 pm

STDIN commands not executing

Post by usaajrm » Fri Mar 18, 2011 4:15 pm

Please review the trace. The stdin commands are not getting executed. This is a separate but related thread to "co:z not working after upgrade".

//STDIN DD *
cd /home/id12345
echo ' i am here'
echo ' i am here' > echo.txt
pwd
/*
[20:36:06.152122] CoZLauncher[N]: version: 1.8.0 2011-02-03
[20:36:06.154095] CoZLauncher[N]: Copyright (C) Dovetailed Technologies, LLC. 2006. All rights reserved.
[20:36:06.154110] CoZLauncher[D]: target_user="id12345", target_host="server3", target_port="NULL"
[20:36:06.154126] CoZLauncher[T]: -> CoZLauncher()
[20:36:06.154147] CoZLauncher[D]: sysname=B011
[20:36:06.154155] CoZLauncher[T]: <- CoZLauncher()
[20:36:06.154163] CoZLauncher[T]: -> run()
[20:36:06.154174] CoZLauncher[D]: CoZLauncher process id=50463272. Parent pid=1
[20:36:06.154183] CoZLauncher[T]: -> logRegionSize()
[20:36:06.154191] CoZLauncher[D]: region size requested = 32768K, Actual below/above limit = 8168K / 1146880K
[20:36:06.154202] CoZLauncher[T]: <- logRegionSize()
[20:36:06.154215] CoZLauncher[T]: -> loadEtcInitOptionsEnv()
[20:36:06.155024] CoZLauncher[T]: loadEtcInitOptionsEnv: TZ=CST6CDT
[15:36:06.155174] CoZLauncher[T]: <- loadEtcInitOptionsEnv()
[15:36:06.155187] CoZLauncher[T]: -> loadConfiguration()
[15:36:06.284623] CoZLauncher: Agent output WTO is ON
[15:36:06.284702] CoZLauncher: ssh tunnelling is ON
[15:36:06.284711] CoZLauncher[D]: server-path=/usr/local/coz/bin/cozserver
[15:36:06.284719] CoZLauncher[D]: server-ports=8040-8048
[15:36:06.284728] CoZLauncher[D]: ssh-path=/bin/ssh
[15:36:06.284736] CoZLauncher[D]: ssh-tunnel=true
[15:36:06.284744] CoZLauncher[D]: ssh-shareas=YES
[15:36:06.284752] CoZLauncher[D]: agent-path=/opt/dovetail/coz/bin/cozagent
[15:36:06.284760] CoZLauncher[D]: agent-output-wto=true
[15:36:06.284768] CoZLauncher[D]: server-env-COZ_TRSUB_US-ASCII=ISO8859-1
[15:36:06.284778] CoZLauncher[D]: ssh-options=-vv
[15:36:06.284786] CoZLauncher[D]: agent-options=-LT,t
[15:36:06.284794] CoZLauncher[D]: target-env-COZ_LOG=T,t
[15:36:06.284802] CoZLauncher[T]: <- loadConfiguration()
[15:36:06.284812] CoZLauncher[T]: -> setServerEnvironment()
[15:36:06.284820] CoZLauncher[T]: -> loadEtcInitOptionsEnv()
[15:36:06.285740] CoZLauncher[T]: loadEtcInitOptionsEnv: TZ=CST6CDT
[15:36:06.286440] CoZLauncher[T]: <- loadEtcInitOptionsEnv()
[15:36:06.286461] CoZLauncher[D]: Set server environment variable:'COZ_TRSUB_US-ASCII'='ISO8859-1'
[15:36:06.286472] CoZLauncher[T]: <- setServerEnvironment()
[15:36:06.286481] CoZLauncher[T]: -> generateAuthToken()
[15:36:06.288766] CoZLauncher[T]: <- generateAuthToken()
[15:36:06.288779] CoZLauncher[T]: -> determineServerPort()
[15:36:06.288799] CoZLauncher[D]: Server port range: 8040-8048
[15:36:06.288813] CoZLauncher[D]: Attempting to start socket listener on port 8040
[15:36:06.288822] CoZLauncher[T]: -> startSocketListener(host=127.0.0.1, port=8040)
[15:36:06.414015] CoZLauncher: CoZServer listener socket bound to: 127.0.0.1:8040
[15:36:06.414708] CoZLauncher[T]: <- startSocketListener(listensock=0)
[15:36:06.414731] CoZLauncher[T]: <- determineServerPort()
[15:36:06.414740] CoZLauncher[T]: -> launchServer()
[15:36:06.414749] CoZLauncher[T]: -> buildServerCommand()
[15:36:06.414760] CoZLauncher[D]: server_cmd...
/usr/local/coz/bin/cozserver -sockfd 3
[15:36:06.414780] CoZLauncher[T]: <- buildServerCommand()
[15:36:06.414788] CoZLauncher[T]: -> spawnServer()
[15:36:06.414872] CoZLauncher[T]: server fd_map[-1,-1,2,0]
[15:36:06.414884] CoZLauncher[T]: server_stderr_fd=1
[15:36:06.417385] CoZLauncher[D]: Started CoZServer process: 33685526
[15:36:06.417422] CoZLauncher[T]: <- spawnServer()
[15:36:06.423021] CoZLauncher[T]: <- launchServer()
[15:36:06.423046] CoZLauncher[T]: -> launchAgent()
[15:36:06.423059] CoZLauncher[T]: -> buildAgentCommand()
[15:36:06.423070] CoZLauncher[T]: -> parseSshOptions()
[15:36:06.423078] CoZLauncher[D]: arg[3] = '-vv'
[15:36:06.423086] CoZLauncher[T]: <- parseSshOptions()
[15:36:06.423098] CoZLauncher[T]: -> parseCommand()
[15:36:06.423153] CoZLauncher[D]: arg[0] = '-LT,t'
[15:36:06.423165] CoZLauncher[T]: <- parseCommand(nargs=1)
[15:36:06.423174] CoZLauncher[D]: agent_cmd...
/bin/ssh -l id12345 -vv -R 8040:127.0.0.1:8040 server3 /opt/dovetail/coz/bin/cozagent -LT,t
[15:36:06.423191] CoZLauncher[T]: <- buildAgentCommand()
[15:36:06.423201] CoZLauncher[T]: -> spawnAgent()
[15:36:06.423309] CoZLauncher[T]: agent_fd_map[0,4,6]
[15:36:06.423318] CoZLauncher[T]: agent_fds[2,3,5]
[15:36:06.423890] CoZLauncher[T]: -> serverStderrThread()
[15:36:06.427384] CoZLauncher[D]: serverStderrThread completed
[15:36:06.427857] CoZLauncher[T]: <- serverStderrThread()
[15:36:06.427996] CoZLauncher[D]: Started CoZAgent process: 131097
[15:36:06.428033] CoZLauncher[T]: <- spawnAgent()
[15:36:06.428041] CoZLauncher[T]: agent FDS=[2,3,5]
[15:36:06.428181] CoZLauncher[D]: About to start target command: ''
[15:36:06.429275] CoZLauncher[T]: <- launchAgent()
[15:36:06.429290] CoZLauncher[T]: -> waitForChildren()
[15:36:06.429346] CoZLauncher[T]: -> waitStatusServer()
[15:36:06.429355] CoZLauncher[D]: CoZServer (33685526) ended with RC=0
[15:36:06.429363] CoZLauncher[T]: <- waitStatusServer()
[15:36:06.429402] CoZLauncher[D]: Signalling agent process
[15:36:06.429410] CoZLauncher[D]: Sleep before Killing child process CozAgent (131097)
[15:36:06.431991] CoZLauncher[T]: -> agentStderrThread()
[15:36:06.433505] CoZLauncher[T]: -> agentStdoutThread()
[15:36:06.437282] CoZLauncher[T]: -> agentStdinThread()
[15:36:06.647092] CoZLauncher[D]: First agent message received:
OpenSSH_5.0p1, OpenSSL 0.9.8k 25 Mar 2009
debug1: Reading configuration data /etc/ssh/ssh_config

debug1: zsshSmfSetConnSmfStatus: SMF status is 0

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

debug2: ssh_connect: needpriv 0

debug1: Connecting to server3 [10.160.2.236] port 22.

debug1: Connection established.

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

debug2: key_type_from_name: unknown key type '-----BEGIN'

debug2: key_type_from_name: unknown key type '-----END'

debug1: identity file /u/id12345/.ssh/id_dsa type 2

debug1: Remote protocol version 2.0, remote software version OpenSSH_4.3

debug1: match: OpenSSH_4.3 pat OpenSSH*

debug1: Enabling compatibility mode for protocol 2.0

debug1: Local version string SSH-2.0-OpenSSH_5.0

debug2: fd 3 setting O_NONBLOCK

debug1: SSH2_MSG_KEXINIT sent

debug1: SSH2_MSG_KEXINIT received

debug2: kex_parse_kexinit: diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group1
4-sha1,diffie-hellman-group1-sha1

debug2: kex_parse_kexinit: ssh-rsa,ssh-dss

debug2: kex_parse_kexinit: aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,cast1
28-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc@lysator.liu.se

debug2: kex_parse_kexinit: aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,cast1
28-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc@lysator.liu.se

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

debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,umac-64@openssh.com,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: diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1

debug2: kex_parse_kexinit: ssh-rsa,ssh-dss

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

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

debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96

debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96

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_setup: found hmac-md5

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

debug2: mac_setup: found hmac-md5

debug1: kex: client->server aes128-ctr 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: 139/256

debug2: bits set: 517/1024

debug1: SSH2_MSG_KEX_DH_GEX_INIT sent

debug1: expecting SSH2_MSG_KEX_DH_GEX_REPLY

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

debug1: Found key in /u/id12345/.ssh/known_hosts:2

debug2: bits set: 526/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: /u/id12345/.ssh/id_rsa (0)

debug2: key: /u/id12345/.ssh/id_dsa (3AAEF0B0)



=== Help ensure information systems are used solely for authorized purposes.
===
=== This is a business information system for authorized use only.
=== Unauthorized use and other violations of company policy may result in
=== corrective action, up to and including immediate termination, and/or
=== criminal prosecution. Use of this system and all files on it may be
=== monitored, copied, and disclosed at any time, by USAA.
===
=== By using this system you agree to the above terms and conditions.
===
=== Please do your part to protect USAA's resources.


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

debug1: Next authentication method: publickey

debug1: Trying private key: /u/id12345/.ssh/id_rsa

debug1: Offering public key: /u/id12345/.ssh/id_dsa

debug2: we sent a publickey packet, wait for reply

debug1: Server accepts key: pkalg ssh-dss blen 434

debug2: input_userauth_pk_ok: fp 5d:86:e7:23:22:86:7f:ae:10:ba:77:0b:d3:f3:3f:35

debug1: read PEM private key done: type DSA

debug1: Authentication succeeded (publickey).

debug1: Remote connections from LOCALHOST:8040 forwarded to local address 127.0.0.1:8040

debug2: fd 4 setting O_NONBLOCK

debug2: fd 5 setting O_NONBLOCK

debug2: fd 6 setting O_NONBLOCK

debug1: channel 0: new [client-session]

debug2: channel 0: send open

debug1: Entering interactive session.

debug1: remote forward success for: listen 8040, connect 127.0.0.1:8040

[15:36:07.429505] CoZLauncher[D]: Killing child process CozAgent (131097) with signal 15
[15:36:07.429872] CoZLauncher[T]: -> waitStatusAgent()
[15:36:07.429890] CoZLauncher[N]: id12345@server3 target command '<default shell>' ended with RC=0
[15:36:07.429901] CoZLauncher[T]: <- waitStatusAgent()
[15:36:07.429942] CoZLauncher[T]: <- waitForChildren(rc=0)
[15:36:07.429960] CoZLauncher[T]: -> cleanup()
[15:36:07.430626] CoZLauncher[T]: <- agentStdinThread()
debug1: channel 0: free: client-session, nchannels 1

debug1: fd 0 clearing O_NONBLOCK

debug1: fd 1 clearing O_NONBLOCK

debug1: fd 2 clearing O_NONBLOCK

[15:36:07.431274] CoZLauncher[T]: <- agentStdoutThread()
[15:36:07.431946] CoZLauncher[T]: <- agentStderrThread()
[15:36:07.432539] CoZLauncher[T]: <- cleanup()
[15:36:07.432551] CoZLauncher: CoZLauncher ended with RC=0
[15:36:07.432559] CoZLauncher[T]: <- run()
[15:36:07.432568] CoZLauncher[T]: -> ~CoZLauncher()
[15:36:07.432590] CoZLauncher[T]: <- ~CoZLauncher()

usaajrm
Posts: 80
Joined: Tue Feb 06, 2007 3:46 pm

Post by usaajrm » Mon Mar 21, 2011 10:18 pm

Here is the lastest trace. Everything looks right but the STDIN lines are not getting executed.
JCL:
//ID12345Z JOB (00000NW000000000,XX,12345),'COZ jcl ',
// MSGCLASS=J,CLASS=X,NOTIFY=ID12345
/*JOBPARM SYSAFF=B011
// JCLLIB ORDER=SYS1.COZ.SAMPJCL
//RUNCOZ EXEC PROC=COZPROC,
// LIBRARY='SYS1.COZ.LOADLIB',
// COZCFGD='OSP.PRODCARD(COZCF)',
// ARGS='-LT,t id12345@server3'
//COZCFG DD *
ssh-options=-vv
agent-options=-LT,t
target-env-COZ_LOG=T,t
/*
//STDIN DD *
fromdsn '//sys1.maclib(acb)' | grep BLKSIZE
echo "We are running on: " `uname -sr`
/*
TRACE: STDOUT
[02:44:40.985928] CoZLauncher[N]: version: 1.8.0 2011-02-03 [02:44:40.993516] CoZLauncher[N]: Copyright (C) Dovetailed Technologies, LLC. 2006. All rights reserved. [02:44:40.993530] CoZLauncher[D]: target_user="id12345", target_host="server3", target_port="NULL" [02:44:40.993546] CoZLauncher[T]: -> CoZLauncher() [02:44:40.993566] CoZLauncher[D]: sysname=B011
[02:44:40.993574] CoZLauncher[T]: <- CoZLauncher() [02:44:40.993584] CoZLauncher[T]: -> run()
[02:44:40.993593] CoZLauncher[D]: CoZLauncher process id=16908716. Parent pid=1
[02:44:40.993605] CoZLauncher[T]: -> logRegionSize()
[02:44:40.993612] CoZLauncher[D]: region size requested = 32768K, Actual below/above limit = 8168K / 1146880K [02:44:40.993621] CoZLauncher[T]: <- logRegionSize()
[02:44:40.993634] CoZLauncher[T]: -> loadEtcInitOptionsEnv()
[02:44:40.994201] CoZLauncher[T]: loadEtcInitOptionsEnv: TZ=CST6CDT
[21:44:40.994346] CoZLauncher[T]: <- loadEtcInitOptionsEnv()
[21:44:40.994358] CoZLauncher[T]: -> loadConfiguration()
[21:44:41.8144] CoZLauncher: Agent output WTO is ON
[21:44:41.8167] CoZLauncher: ssh tunnelling is ON
[21:44:41.8176] CoZLauncher[D]: server-path=/usr/local/coz/bin/cozserver
[21:44:41.8184] CoZLauncher[D]: server-ports=8040-8048
[21:44:41.8192] CoZLauncher[D]: ssh-path=/bin/ssh
[21:44:41.8200] CoZLauncher[D]: ssh-tunnel=true
[21:44:41.8208] CoZLauncher[D]: ssh-shareas=YES
[21:44:41.8216] CoZLauncher[D]: agent-path=/opt/dovetail/coz/bin/cozagent
[21:44:41.8224] CoZLauncher[D]: agent-output-wto=true
[21:44:41.8232] CoZLauncher[D]: server-env-COZ_TRSUB_US-ASCII=ISO8859-1
[21:44:41.8240] CoZLauncher[D]: ssh-options=-vv
[21:44:41.8248] CoZLauncher[D]: agent-options=-LT,t
[21:44:41.8256] CoZLauncher[D]: target-env-COZ_LOG=T,t
[21:44:41.8264] CoZLauncher[T]: <- loadConfiguration()
[21:44:41.8272] CoZLauncher[T]: -> setServerEnvironment()
[21:44:41.8280] CoZLauncher[T]: -> loadEtcInitOptionsEnv()
[21:44:41.8576] CoZLauncher[T]: loadEtcInitOptionsEnv: TZ=CST6CDT
[21:44:41.8679] CoZLauncher[T]: <- loadEtcInitOptionsEnv()
[21:44:41.8692] CoZLauncher[D]: Set server environment variable:'COZ_TRSUB_US-ASCII'='ISO8859-1'
[21:44:41.8704] CoZLauncher[T]: <- setServerEnvironment()
[21:44:41.8712] CoZLauncher[T]: -> generateAuthToken()
[21:44:41.10930] CoZLauncher[T]: <- generateAuthToken()
[21:44:41.10942] CoZLauncher[T]: -> determineServerPort()
[21:44:41.10958] CoZLauncher[D]: Server port range: 8040-8048
[21:44:41.10969] CoZLauncher[D]: Attempting to start socket listener on port 8040
[21:44:41.10978] CoZLauncher[T]: -> startSocketListener(host=127.0.0.1, port=8040)
[21:44:41.77912] CoZLauncher: CoZServer listener socket bound to: 127.0.0.1:8040
[21:44:41.78342] CoZLauncher[T]: <- startSocketListener(listensock=0)
[21:44:41.78359] CoZLauncher[T]: <- determineServerPort()
[21:44:41.78368] CoZLauncher[T]: -> launchServer()
[21:44:41.78376] CoZLauncher[T]: -> buildServerCommand()
[21:44:41.78387] CoZLauncher[D]: server_cmd...
/usr/local/coz/bin/cozserver -sockfd 3
[21:44:41.78406] CoZLauncher[T]: <- buildServerCommand()
[21:44:41.78414] CoZLauncher[T]: -> spawnServer()
[21:44:41.78500] CoZLauncher[T]: server fd_map[-1,-1,2,0]
[21:44:41.78511] CoZLauncher[T]: server_stderr_fd=1
[21:44:41.80574] CoZLauncher[D]: Started CoZServer process: 131520
[21:44:41.80629] CoZLauncher[T]: <- spawnServer()
[21:44:41.82702] CoZLauncher[T]: <- launchServer()
[21:44:41.82729] CoZLauncher[T]: -> launchAgent()
[21:44:41.82741] CoZLauncher[T]: -> buildAgentCommand()
[21:44:41.82750] CoZLauncher[T]: -> parseSshOptions()
[21:44:41.82759] CoZLauncher[D]: arg[3] = '-vv'
[21:44:41.82769] CoZLauncher[T]: <- parseSshOptions()
[21:44:41.82779] CoZLauncher[T]: -> parseCommand()
[21:44:41.82789] CoZLauncher[D]: arg[0] = '-LT,t'
[21:44:41.82801] CoZLauncher[T]: <- parseCommand(nargs=1)
[21:44:41.82851] CoZLauncher[D]: agent_cmd...
/bin/ssh -l id12345 -vv -R 8040:127.0.0.1:8040 server3 /opt/dovetail/coz/bin/cozagent -LT,t
[21:44:41.82869] CoZLauncher[T]: <- buildAgentCommand()
[21:44:41.82878] CoZLauncher[T]: -> spawnAgent()
[21:44:41.82991] CoZLauncher[T]: agent_fd_map[0,4,6]
[21:44:41.83002] CoZLauncher[T]: agent_fds[2,3,5]
[21:44:41.83875] CoZLauncher[T]: -> serverStderrThread()
[21:44:41.86086] CoZLauncher[D]: Started CoZAgent process: 131581
[21:44:41.86136] CoZLauncher[T]: <- spawnAgent()
[21:44:41.86145] CoZLauncher[T]: agent FDS=[2,3,5]
[21:44:41.86302] CoZLauncher[D]: About to start target command: ''
[21:44:41.86845] CoZLauncher[T]: <- launchAgent()
[21:44:41.86869] CoZLauncher[T]: -> waitForChildren()
[21:44:41.87126] CoZLauncher[D]: serverStderrThread completed
[21:44:41.87451] CoZLauncher[T]: -> agentStderrThread()
[21:44:41.87851] CoZLauncher[T]: <- serverStderrThread()
[21:44:41.88113] CoZLauncher[T]: -> agentStdoutThread()
[21:44:41.89095] CoZLauncher[T]: -> waitStatusServer()
[21:44:41.89111] CoZLauncher[D]: CoZServer (131520) ended with RC=0
[21:44:41.89119] CoZLauncher[T]: <- waitStatusServer()
[21:44:41.89156] CoZLauncher[D]: Signalling agent process
[21:44:41.89167] CoZLauncher[D]: Sleep before Killing child process CozAgent (131581)
[21:44:41.89227] CoZLauncher[T]: -> agentStdinThread()
[21:44:41.304348] CoZLauncher[D]: First agent message received:
OpenSSH_5.0p1, OpenSSL 0.9.8k 25 Mar 2009
debug1: Reading configuration data /etc/ssh/ssh_config
debug1: zsshSmfSetConnSmfStatus: SMF status is 0
debug1: Rhosts Authentication disabled, originating port will not be trusted.
debug2: ssh_connect: needpriv 0
debug1: Connecting to server3 [10.160.2.236] port 22.
debug1: Connection established.
debug2: key_type_from_name: unknown key type '-----BEGIN'
debug2: key_type_from_name: unknown key type '-----END'
debug1: identity file /u/id12345/.ssh/id_rsa type 1
debug1: identity file /u/id12345/.ssh/id_dsa type -1
debug1: Remote protocol version 2.0, remote software version OpenSSH_4.3
debug1: match: OpenSSH_4.3 pat OpenSSH*
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_5.0
debug2: fd 3 setting O_NONBLOCK
debug1: SSH2_MSG_KEXINIT sent
debug1: SSH2_MSG_KEXINIT received
debug2: kex_parse_kexinit: diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group1
4-sha1,diffie-hellman-group1-sha1
debug2: kex_parse_kexinit: ssh-rsa,ssh-dss
debug2: kex_parse_kexinit: aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,cast1
28-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc@lysator.liu.se
debug2: kex_parse_kexinit: aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,cast1
28-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc@lysator.liu.se
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,umac-64@openssh.com,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,umac-64@openssh.com,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: diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
debug2: kex_parse_kexinit: ssh-rsa,ssh-dss
debug2: kex_parse_kexinit: aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour128,arcfour256,arcfour,aes192-cbc,aes256-
cbc,rijndael-cbc@lysator.liu.se,aes128-ctr,aes192-ctr,aes256-ctr
debug2: kex_parse_kexinit: aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour128,arcfour256,arcfour,aes192-cbc,aes256-
cbc,rijndael-cbc@lysator.liu.se,aes128-ctr,aes192-ctr,aes256-ctr
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96
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_setup: found hmac-md5
debug1: kex: server->client aes128-ctr hmac-md5 none
debug2: mac_setup: found hmac-md5
debug1: kex: client->server aes128-ctr 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: 136/256
debug2: bits set: 511/1024
debug1: SSH2_MSG_KEX_DH_GEX_INIT sent
debug1: expecting SSH2_MSG_KEX_DH_GEX_REPLY
debug1: Host 'server3' is known and matches the RSA host key.
debug1: Found key in /u/id12345/.ssh/known_hosts:2
debug2: bits set: 503/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: /u/id12345/.ssh/id_rsa (3AAEF0B0)
debug2: key: /u/id12345/.ssh/id_dsa (0)

=== Help ensure information systems are used solely for authorized purposes.
===
=== This is a business information system for authorized use only.
=== Unauthorized use and other violations of company policy may result in
=== corrective action, up to and including immediate termination, and/or
=== criminal prosecution. Use of this system and all files on it may be
=== monitored, copied, and disclosed at any time
===
=== By using this system you agree to the above terms and conditions.
===
=== Please do your part to protect USAA's resources.
debug1: Authentications that can continue: publickey,password,keyboard-interactive
debug1: Next authentication method: publickey
debug1: Offering public key: /u/id12345/.ssh/id_rsa
debug2: we sent a publickey packet, wait for reply
debug1: Server accepts key: pkalg ssh-rsa blen 277
debug2: input_userauth_pk_ok: fp 42:fb:e9:28:cb:c6:be:a4:da:dc:d0:54:48:16:43:19 debug1: read PEM private key done: type RSA
debug1: Authentication succeeded (publickey).
debug1: Remote connections from LOCALHOST:8040 forwarded to local address 127.0.0.1:8040
debug2: fd 4 setting O_NONBLOCK
debug2: fd 5 setting O_NONBLOCK
debug2: fd 6 setting O_NONBLOCK
debug1: channel 0: new [client-session]
debug2: channel 0: send open
debug1: Entering interactive session.
debug1: remote forward success for: listen 8040, connect 127.0.0.1:8040
[21:44:42.89340] CoZLauncher[D]: Killing child process CozAgent (131581) with signal 15
[21:44:42.89580] CoZLauncher[T]: -> waitStatusAgent()
[21:44:42.89601] CoZLauncher[N]: id12345@server3 target command '<default shell>' ended with RC=0
[21:44:42.89612] CoZLauncher[T]: <- waitStatusAgent()
[21:44:42.89754] CoZLauncher[T]: <- waitForChildren(rc=0)
[21:44:42.89772] CoZLauncher[T]: -> cleanup()
debug1: channel 0: free: client-session, nchannels 1
debug1: fd 0 clearing O_NONBLOCK
debug1: fd 1 clearing O_NONBLOCK
debug1: fd 2 clearing O_NONBLOCK
[21:44:42.90377] CoZLauncher[T]: <- agentStdinThread()
[21:44:42.90825] CoZLauncher[T]: <- agentStdoutThread()
[21:44:42.91074] CoZLauncher[T]: <- agentStderrThread()
[21:44:42.92470] CoZLauncher[T]: <- cleanup()
[21:44:42.92484] CoZLauncher: CoZLauncher ended with RC=0
[21:44:42.92494] CoZLauncher[T]: <- run()
[21:44:42.92502] CoZLauncher[T]: -> ~CoZLauncher()
[21:44:42.92522] CoZLauncher[T]: <- ~CoZLauncher()

usaajrm
Posts: 80
Joined: Tue Feb 06, 2007 3:46 pm

Post by usaajrm » Tue Mar 22, 2011 3:59 pm

my saga continues. we installed 1.6 on a separate z/os system. The launcher works to two different linux machines. I've include a segment of the launcher between the two systems. Any insight would be appreciated. I can only see that the child process gets killed. I can only think this is due the tcp ip session being terminated. I just don't know what is driving the termination.

Trace segment for successful execution:
...
debug1: Authentication succeeded (publickey).
debug1: Connections to remote port 8040 forwarded to local address 127.0.0.1:8040
debug2: fd 4 setting O_NONBLOCK
debug2: fd 5 setting O_NONBLOCK
debug2: fd 6 setting O_NONBLOCK
debug1: channel 0: new Ýclient-session¨
debug2: channel 0: send open
debug1: Entering interactive session.
debug1: remote forward success for: listen 8040, connect 127.0.0.1:8040
debug2: callback start
debug2: ssh_session2_setup: id 0
debug1: Sending command: /opt/dovetail/coz/bin/cozagent -LT,t
debug2: channel 0: request exec
debug2: callback done
debug2: channel 0: open confirm rwindow 0 rmax 32768
debug2: channel 0: rcvd adjust 2097152
debug2: channel 0: rcvd ext data 40
debug2: channel 0: rcvd ext data 58
debug2: channel 0: rcvd ext data 189
debug2: channel 0: rcvd ext data 167
...

Trace segment for unsuccessful execution:
...
debug1: Authentication succeeded (publickey).
debug1: Remote connections from LOCALHOST:8040 forwarded to local address 127.0.1:8040
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.
debug1: remote forward success for: listen 8040, connect 127.0.0.1:8040
Ý14:09:26.289379¨ CoZLauncherÝD¨: Killing child process CozAgent (33686029) with signal 15
Ý14:09:26.289619¨ CoZLauncherÝN¨: nw29233@testbat3l target command '<default shell>' ended with RC=0
debug1: channel 0: free: client-session, nchannels 1
debug3: channel 0: status: The following connections are open:
#0 client-session (t3 r-1 i0/0 o0/0 fd 4/5 cfd -1)
debug3: channel 0: close_fds r 4 w 5 e 6 c -1
debug1: fd 0 clearing O_NONBLOCK
debug1: fd 1 clearing O_NONBLOCK
debug1: fd 2 clearing O_NONBLOCK
...

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

Post by dovetail » Tue Mar 22, 2011 4:17 pm

Please clarify the differences between what works and what doesn't.

- I see you are using Co:Z Launcher 1.8.0 on z/OS. What version of Co:Z Target Toolkit are you using on the target linux machine(s)?

- In addition to what you are tracing, turn on the following traces as well:

//COZCFG DD *
agent-options=-LD,t
target-env-COZ_LOG=D,t
/*

- send us the complete working and not-working job logs/traces. If you wish, you can email to info@dovetail.com

usaajrm
Posts: 80
Joined: Tue Feb 06, 2007 3:46 pm

Post by usaajrm » Tue Mar 22, 2011 10:51 pm

I have sent the traces to your email

usaajrm
Posts: 80
Joined: Tue Feb 06, 2007 3:46 pm

Post by usaajrm » Wed Mar 23, 2011 12:02 pm

Thank you. For those who follow this thread. The problem was the upgrade to 1.8. the z/OS admin's load failed and it was not noticed. This left the /usr/local/coz/bin directory with several empty files. One of the was the cozserver. We chased several rabbits until finding this. We've added checking the directory to the top of the list. Hence, the several threads on this forum with the same conclusion. Thanks dovetail.

Post Reply