Mailing List Archive

Couldn't wait for ssh process: No child processes
RedHat Enterprise Linux 5.3
OpenSSH_4.3p2, OpenSSL 0.9.8e-fips-rhel5 01 Jul 2008

I am using swatch to monitor the vsftpd log and the secure log for FTP
and SFTP inbound transfers then trigger a script to send the file
outbound. When I use the sftp command to send a file outbound, I am
getting "Couldn't wait for ssh process: No child processes" with a
return code of 255. Here's the strange thing:

swatch -> script2.sh -> sftp command -> fails with RC 255
swatch -> script1.sh -> script2.sh -> sftp command -> successful with RC 0
swatch -> script2.sh -> sftp command piped through tee -> successful with RC 255

Script1.sh is just a simple script that calls script2.sh with the same
arguments that swatch passed from the log line.

Failed Transfer
=================================================
debug1: Reading configuration data /etc/ssh/ssh_config
debug1: Applying options for *
debug2: ssh_connect: needpriv 0
debug1: Connecting to jdad1-ak-fis.bfusa.com [172.16.15.121] port 22.
debug1: Connection established.
debug1: permanently_set_uid: 0/0
debug3: Not a RSA1 key file /usr/local/bin/fileMover.remote/id_rsa.
debug2: key_type_from_name: unknown key type '-----BEGIN'
debug3: key_read: missing keytype
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug2: key_type_from_name: unknown key type '-----END'
debug3: key_read: missing keytype
debug1: identity file /usr/local/bin/fileMover.remote/id_rsa type 1
debug1: loaded 1 keys
debug1: Remote protocol version 2.0, remote software version OpenSSH_5.3
debug1: match: OpenSSH_5.3 pat OpenSSH*
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_4.3
debug2: fd 4 setting O_NONBLOCK
debug1: SSH2_MSG_KEXINIT sent
debug1: SSH2_MSG_KEXINIT received
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,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-sha256,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-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,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-cbc,3des-cbc,blowfish-cbc,cast128-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
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: 122/256
debug2: bits set: 486/1024
debug1: SSH2_MSG_KEX_DH_GEX_INIT sent
debug1: expecting SSH2_MSG_KEX_DH_GEX_REPLY
debug3: check_host_in_hostfile: filename
/usr/local/bin/fileMover.remote/jdad1-ak-fis.bfusa.com.knownhosts
debug3: check_host_in_hostfile: match line 1
debug3: check_host_in_hostfile: filename
/usr/local/bin/fileMover.remote/jdad1-ak-fis.bfusa.com.knownhosts
debug3: check_host_in_hostfile: match line 1
debug1: Host 'jdad1-ak-fis.bfusa.com' is known and matches the RSA host key.
debug1: Found key in
/usr/local/bin/fileMover.remote/jdad1-ak-fis.bfusa.com.knownhosts:1
debug2: bits set: 495/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: /usr/local/bin/fileMover.remote/id_rsa (0x2b01706ffc70)
debug1: Authentications that can continue:
publickey,password,keyboard-interactive
debug3: start over, passed a different list
publickey,password,keyboard-interactive
debug3: preferred gssapi-with-mic,publickey
debug3: authmethod_lookup publickey
debug3: remaining preferred: ,publickey
debug3: authmethod_is_enabled publickey
debug1: Next authentication method: publickey
debug1: Offering public key: /usr/local/bin/fileMover.remote/id_rsa
debug3: send_pubkey_test
debug2: we sent a publickey packet, wait for reply
debug1: Server accepts key: pkalg ssh-rsa blen 277
debug2: input_userauth_pk_ok: SHA1 fp
3c:b9:31:b5:63:dc:e3:f8:34:77:f3:b0:37:95:3c:f7:a0:d5:a3:1d
debug3: sign_and_send_pubkey
debug1: read PEM private key done: type RSA
debug1: Authentication succeeded (publickey).
debug2: fd 5 setting O_NONBLOCK
debug3: fd 6 is O_NONBLOCK
debug2: fd 7 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: client_session2_setup: id 0
debug1: Sending environment.
debug3: Ignored env GREP_COLOR
debug3: Ignored env HOSTNAME
debug3: Ignored env TERM
debug3: Ignored env SHELL
debug3: Ignored env HISTSIZE
debug3: Ignored env USER
debug3: Ignored env LS_COLORS
debug3: Ignored env PATH
debug3: Ignored env MAIL
debug3: Ignored env PWD
debug3: Ignored env INPUTRC
debug1: Sending env LANG = en_US.UTF-8
debug2: channel 0: request env confirm 0
debug3: Ignored env SSH_ASKPASS
debug3: Ignored env HOME
debug3: Ignored env SHLVL
debug3: Ignored env LOGNAME
debug3: Ignored env PGP_HOME_DIR
debug3: Ignored env LESSOPEN
debug3: Ignored env DISPLAY
debug3: Ignored env G_BROKEN_FILENAMES
debug3: Ignored env XAUTHORITY
debug3: Ignored env _
debug1: Sending subsystem: sftp
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: Remote version: 3
debug2: Init extension: "posix-rename@openssh.com"
debug2: Init extension: "statvfs@openssh.com"
debug2: Init extension: "fstatvfs@openssh.com"
debug3: Sent message fd 4 T:16 I:1
debug3: SSH_FXP_REALPATH . -> /home/bbtsjda1
debug3: Sent message fd 4 T:17 I:2
debug3: Received stat reply T:105 I:2
debug3: Sent message fd 4 T:16 I:3
debug3: SSH_FXP_REALPATH /home/bbtsjda1/ -> /home/bbtsjda1
debug3: Sent message fd 4 T:17 I:4
debug3: Received stat reply T:105 I:4
debug3: Sent message fd 4 T:16 I:5
debug3: SSH_FXP_REALPATH /cygdrive/d/jda/jdav752/tmserver/in ->
/cygdrive/d/jda/jdav752/tmserver/in
debug3: Sent message fd 4 T:17 I:6
debug3: Received stat reply T:105 I:6
debug3: Looking up /home/jonesdavida/dave-jda-t_e_s_t.txt
debug3: Sent message fd 4 T:17 I:7
debug3: Received stat reply T:101 I:7
debug1: Couldn't stat remote file: No such file or directory
debug3: Sent message SSH2_FXP_OPEN I:8
P:/cygdrive/d/jda/jdav752/tmserver/in/dave-jda-t_e_s_t_03022010_135930.txt
debug3: Sent message SSH2_FXP_WRITE I:9 O:0 S:541
debug3: SSH2_FXP_STATUS 0
debug3: In write loop, ack for 9 541 bytes at 0
debug3: Sent message SSH2_FXP_CLOSE I:9
debug3: SSH2_FXP_STATUS 0
debug3: Sent message fd 4 T:7 I:10
debug3: Received stat reply T:105 I:10
debug3: Sent message fd 4 T:7 I:11
debug3: Received stat reply T:105 I:11
debug3: Sending SSH2_FXP_READDIR I:13
debug3: Received reply T:104 I:13
debug3: Received 14 SSH2_FXP_NAME responses
debug3: Sending SSH2_FXP_READDIR I:14
debug3: Received reply T:101 I:14
debug3: Received SSH2_FXP_STATUS 1
debug3: Sent message SSH2_FXP_CLOSE I:15
debug3: SSH2_FXP_STATUS 0
debug2: channel 0: read<=0 rfd 5 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:
debug3: channel 0: close_fds r -1 w -1 e 7 c -1
debug1: fd 0 clearing O_NONBLOCK
debug3: fd 1 is not O_NONBLOCK
debug1: fd 2 clearing O_NONBLOCK
debug1: Transferred: stdin 0, stdout 0, stderr 0 bytes in 1.3 seconds
debug1: Bytes per second: stdin 0.0, stdout 0.0, stderr 0.0
debug1: Exit status 0
Couldn't wait for ssh process: No child processes^M
+ RC=255


Successful transfer
=================================================
debug1: Reading configuration data /etc/ssh/ssh_config
debug1: Applying options for *
debug2: ssh_connect: needpriv 0
debug1: Connecting to jdad1-ak-fis.bfusa.com [172.16.15.121] port 22.
debug1: Connection established.
debug1: permanently_set_uid: 0/0
debug3: Not a RSA1 key file /usr/local/bin/fileMover.remote/id_rsa.
debug2: key_type_from_name: unknown key type '-----BEGIN'
debug3: key_read: missing keytype
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug2: key_type_from_name: unknown key type '-----END'
debug3: key_read: missing keytype
debug1: identity file /usr/local/bin/fileMover.remote/id_rsa type 1
debug1: loaded 1 keys
debug1: Remote protocol version 2.0, remote software version OpenSSH_5.3
debug1: match: OpenSSH_5.3 pat OpenSSH*
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_4.3
debug2: fd 4 setting O_NONBLOCK
debug1: SSH2_MSG_KEXINIT sent
debug1: SSH2_MSG_KEXINIT received
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,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-sha256,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-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,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-cbc,3des-cbc,blowfish-cbc,cast128-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
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: 115/256
debug2: bits set: 522/1024
debug1: SSH2_MSG_KEX_DH_GEX_INIT sent
debug1: expecting SSH2_MSG_KEX_DH_GEX_REPLY
debug3: check_host_in_hostfile: filename
/usr/local/bin/fileMover.remote/jdad1-ak-fis.bfusa.com.knownhosts
debug3: check_host_in_hostfile: match line 1
debug3: check_host_in_hostfile: filename
/usr/local/bin/fileMover.remote/jdad1-ak-fis.bfusa.com.knownhosts
debug3: check_host_in_hostfile: match line 1
debug1: Host 'jdad1-ak-fis.bfusa.com' is known and matches the RSA host key.
debug1: Found key in
/usr/local/bin/fileMover.remote/jdad1-ak-fis.bfusa.com.knownhosts:1
debug2: bits set: 510/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: /usr/local/bin/fileMover.remote/id_rsa (0x2b0ec30fdc70)
debug1: Authentications that can continue:
publickey,password,keyboard-interactive
debug3: start over, passed a different list
publickey,password,keyboard-interactive
debug3: preferred gssapi-with-mic,publickey
debug3: authmethod_lookup publickey
debug3: remaining preferred: ,publickey
debug3: authmethod_is_enabled publickey
debug1: Next authentication method: publickey
debug1: Offering public key: /usr/local/bin/fileMover.remote/id_rsa
debug3: send_pubkey_test
debug2: we sent a publickey packet, wait for reply
debug1: Server accepts key: pkalg ssh-rsa blen 277
debug2: input_userauth_pk_ok: SHA1 fp
3c:b9:31:b5:63:dc:e3:f8:34:77:f3:b0:37:95:3c:f7:a0:d5:a3:1d
debug3: sign_and_send_pubkey
debug1: read PEM private key done: type RSA
debug1: Authentication succeeded (publickey).
debug2: fd 5 setting O_NONBLOCK
debug3: fd 6 is O_NONBLOCK
debug2: fd 7 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: client_session2_setup: id 0
debug1: Sending environment.
debug3: Ignored env GREP_COLOR
debug3: Ignored env HOSTNAME
debug3: Ignored env TERM
debug3: Ignored env SHELL
debug3: Ignored env HISTSIZE
debug3: Ignored env USER
debug3: Ignored env LS_COLORS
debug3: Ignored env PATH
debug3: Ignored env MAIL
debug3: Ignored env PWD
debug3: Ignored env INPUTRC
debug1: Sending env LANG = en_US.UTF-8
debug2: channel 0: request env confirm 0
debug3: Ignored env SSH_ASKPASS
debug3: Ignored env HOME
debug3: Ignored env SHLVL
debug3: Ignored env LOGNAME
debug3: Ignored env PGP_HOME_DIR
debug3: Ignored env LESSOPEN
debug3: Ignored env DISPLAY
debug3: Ignored env G_BROKEN_FILENAMES
debug3: Ignored env XAUTHORITY
debug3: Ignored env _
debug1: Sending subsystem: sftp
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: Remote version: 3
debug2: Init extension: "posix-rename@openssh.com"
debug2: Init extension: "statvfs@openssh.com"
debug2: Init extension: "fstatvfs@openssh.com"
debug3: Sent message fd 4 T:16 I:1
debug3: SSH_FXP_REALPATH . -> /home/bbtsjda1
debug3: Sent message fd 4 T:17 I:2
debug3: Received stat reply T:105 I:2
debug3: Sent message fd 4 T:16 I:3
debug3: SSH_FXP_REALPATH /home/bbtsjda1/ -> /home/bbtsjda1
debug3: Sent message fd 4 T:17 I:4
debug3: Received stat reply T:105 I:4
debug3: Sent message fd 4 T:16 I:5
debug3: SSH_FXP_REALPATH /cygdrive/d/jda/jdav752/tmserver/in ->
/cygdrive/d/jda/jdav752/tmserver/in
debug3: Sent message fd 4 T:17 I:6
debug3: Received stat reply T:105 I:6
debug3: Looking up /home/jonesdavida/dave-jda-t_e_s_t.txt
debug3: Sent message fd 4 T:17 I:7
debug3: Received stat reply T:101 I:7
debug1: Couldn't stat remote file: No such file or directory
debug3: Sent message SSH2_FXP_OPEN I:8
P:/cygdrive/d/jda/jdav752/tmserver/in/dave-jda-t_e_s_t_03022010_135420.txt
debug3: Sent message SSH2_FXP_WRITE I:9 O:0 S:541
debug3: SSH2_FXP_STATUS 0
debug3: In write loop, ack for 9 541 bytes at 0
debug3: Sent message SSH2_FXP_CLOSE I:9
debug3: SSH2_FXP_STATUS 0
debug3: Sent message fd 4 T:7 I:10
debug3: Received stat reply T:105 I:10
debug3: Sent message fd 4 T:7 I:11
debug3: Received stat reply T:105 I:11
debug3: Sending SSH2_FXP_READDIR I:13
debug3: Received reply T:104 I:13
debug3: Received 11 SSH2_FXP_NAME responses
debug3: Sending SSH2_FXP_READDIR I:14
debug3: Received reply T:101 I:14
debug3: Received SSH2_FXP_STATUS 1
debug3: Sent message SSH2_FXP_CLOSE I:15
debug3: SSH2_FXP_STATUS 0
debug2: channel 0: read<=0 rfd 5 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:
debug3: channel 0: close_fds r -1 w -1 e 7 c -1
debug1: fd 0 clearing O_NONBLOCK
debug3: fd 1 is not O_NONBLOCK
debug1: fd 2 clearing O_NONBLOCK
debug1: Transferred: stdin 0, stdout 0, stderr 0 bytes in 1.3 seconds
debug1: Bytes per second: stdin 0.0, stdout 0.0, stderr 0.0
debug1: Exit status 0
Couldn't wait for ssh process: No child processes^M
+ RC=0


Problem is 100% consistent and reproducible.

Anyone have any ideas?


--
Dave Jones
Re: Couldn't wait for ssh process: No child processes [ In reply to ]
Read the first part of my original email where swatch can launch script2
directly and it will work when I tee the output but fails without piping the
output to tee. This makes me think that it's something related to the
timing or relationship of the child process spawning by the sftp code.

Also, if you Google this error message, you will see that someone had the
same problem launching sftp from SAP via a script. So it doesn't seem to
matter what is launching the sftp command but there has to be something
in common.

Dave

On Wed, Mar 3, 2010 at 3:00 PM, Dominik George <nik@naturalnet.de> wrote:

> Look at what exactly swatch spawns. Script1 will spawn a shiny new shell
> for script2, swatch probably doesnt.
> --
> Sent from my Android phone with K-9 Mail. Please excuse my brevity.
>
>
> "Dave Jones" <davejones70@gmail.com> schrieb:
>
> >RedHat Enterprise Linux 5.3
> >OpenSSH_4.3p2, OpenSSL 0.9.8e-fips-rhel5 01 Jul 2008
> >
> >I am using swatch to monitor the vsftpd log and the secure log for FTP
> >and SFTP inbound transfers then trigger a script to send the file
> >outbound. When I use the sftp command to send a file outbound, I am
> >getting "Couldn't wait for ssh process: No child processes" with a
> >return code of 255. Here's the strange thing:
> >
> >swatch -> script2.sh -> sftp command -> fails with RC 255
> >swatch -> script1.sh -> script2.sh -> sftp command -> successful with RC 0
> >swatch -> script2.sh -> sftp command piped through tee -> successful with
> RC 255
> >
> >Script1.sh is just a simple script that calls script2.sh with the same
> >arguments that swatch passed from the log line.
Re: Couldn't wait for ssh process: No child processes [ In reply to ]
On Wed, Mar 03, 2010 at 12:28:18PM -0600, Dave Jones wrote:
> I am using swatch to monitor the vsftpd log and the secure log for FTP
> and SFTP inbound transfers then trigger a script to send the file
> outbound. When I use the sftp command to send a file outbound, I am
> getting "Couldn't wait for ssh process: No child processes" with a
> return code of 255. Here's the strange thing:

RC 255 == RC -1, which I believe very often means that a child program
could not be fork()'d or exec()'d. My first guess -- and it's just a
guess -- is that your script does not specify the path to your sftp
binary, and it's not in the $PATH that swatch passes to its children.
Adding the second shell script may somehow reinstate the $PATH that
contains the path to the binary. To be honest, based on what you
described, this scenario seems a little bit unlikely; but I can't
think of one that's more likely. That this succeeds when piped
through tee (though, *what* is piped through tee?), seems like a very
odd wild card. I might be inclined to think that this had something
to do with stdin/stdout being or not being a tty, but it looks to me
like it should not be a tty in all 3 cases... Hard to say for sure
though. Depends on what swatch does, and on what the scripts do.

> swatch -> script2.sh -> sftp command -> fails with RC 255
> swatch -> script1.sh -> script2.sh -> sftp command -> successful with RC 0
> swatch -> script2.sh -> sftp command piped through tee -> successful with RC 255

This little diagram tells us surprisingly little of importance. We
don't positively know:

- what the value of $PATH is at any given point
- what script2.sh looks like, and most importantly how it's invoked
- what script1.sh looks like, and most importantly how it's invoked
- whether or not stdin/stdout is a TTY at any given point
- where (i.e. what program) the error message you quoted came from
- what platform(s) this is (though it looks like the server is cygwin)
- etc.

If your shell is bash, then how it is invoked by the shell script
actually could matter quite a lot. If script2.sh is invoked as:

#!/bin/sh

but script1.sh is invoked as:

#!/bin/bash

...then this might actually lend support to my theory above. In such a
case, the script invoked as /bin/bash could possibly source the .rc
files (i.e. of the user as which the script was invoked, which could change
the environment of its children quite drastically (for example, if
$BASH_ENV is set in the environment -- unlikely but possible).

And of course, if either of these scripts sets any environment
variables or otherwise manipulates the environment the script runs in,
all bets are off.

Another possibility is that the arguments are not quoted properly as
passed from swatch to your script, *AND* they're not quoted properly
in script1.sh, and the two wrongs in this case actually do make a
right; e.g. swatch passes the args all as one string, and the
intermediate script expands the string without quoting such that each
token is passed as a distinct argument, which by chance is actually
what was intended in the first place, so it works "by accident"
essentially.

From the log of the failed transfer:

> debug1: Transferred: stdin 0, stdout 0, stderr 0 bytes in 1.3 seconds
> debug1: Bytes per second: stdin 0.0, stdout 0.0, stderr 0.0
> debug1: Exit status 0
> Couldn't wait for ssh process: No child processes^M
> + RC=255

This seems to suggest that whatever ssh command was run by swatch
actually succeeded (debug1: Exit status 0), but just didn't do what
you expected it to. It could be caused by a problem with command-line
quoting either in your script itself, or in how swatch calls it; and
somehow interposing the extra script fixes it. Or, it could be that
the error is not related to SSH at all. Or, all that could be
complete hogwash.

From your "successful" log:

> debug1: Transferred: stdin 0, stdout 0, stderr 0 bytes in 1.3 seconds
> debug1: Bytes per second: stdin 0.0, stdout 0.0, stderr 0.0
> debug1: Exit status 0
> Couldn't wait for ssh process: No child processes^M
> + RC=0

Note that the same error message appears. Either this output was from
a session that was not really successful, or maybe the error message
is irrelevant to the problem? Without doing a side-by-side comparison
of the two logs, it looks to me like the only significant difference
was the RC itself. That suggests to me that the problem is not with
the SSH session, but with some other command that's in the script, or
with the way swatch is invoking the child. Or, maybe it's a cygwin
sshd bug... But, unless one of my guesses was right, I don't think
there's enough information here to figure out what the problem is. In
particular, were I to spend more time on this problem, I'd want to
know what platform(s) this is running on, and see the actual scripts
involved.

Hope that helps...

--
Derek D. Martin
http://www.pizzashack.org/
GPG Key ID: 0x81CFE75D