This is the mail archive of the cygwin mailing list for the Cygwin project.


Index Nav: [Date Index] [Subject Index] [Author Index] [Thread Index]
Message Nav: [Date Prev] [Date Next] [Thread Prev] [Thread Next]
Other format: [Raw text]

Re: sshd: fork of unprivileged child failed


--On 04 June 2006 19:06 -0500 Renà Berber wrote:

Robin Walker wrote:
--On 04 June 2006 16:27 -0500 Renà Berber wrote:
Robin Walker wrote:

In the Windows Application Log there are, for each failed connection
attempt, entries of the form:

sshd: PID xxxx: fatal: fork of unprivileged child failed.

What is you configuration in respect to privilege separation?

UsePrivilegeSeparation yes

Did you check if the rest of the configuration for using privilege separation was done (i.e. the creation of the unprivileged user sshd, the creation of the /var/empty directory with owner SYSTEM and all access).

Yes - all those features are correct, as made by ssh-host-config earlier the same day.


The error message shows that the main sshd server is running but it
cannot spawn child processes, which it always does on a new connection
(privilege or not) so the second process failure is the interesting part.
The error message doesn't show anything from that second process.

Surely, it won't show anything from the second process, because the second process never got created (fork failed)?


One of the frustrating things about this issue is that it is non-deterministic: sometimes it works, and sometimes it doesn't. For instance, here is a verbose ssh client trace of three consecutive attempts, made within seconds of each other: the first fails (fork failure in Application Log), the second works, the third fails (fork failure). Given that the second one worked, the basic settings in the system must be OK.

C:\Documents and Settings\rdhw>ssh -vvv 127.0.0.1
OpenSSH_4.3p2, OpenSSL 0.9.8a 11 Oct 2005
debug1: Reading configuration data /etc/ssh_config
debug2: ssh_connect: needpriv 0
debug1: Connecting to 127.0.0.1 [127.0.0.1] port 22.
debug1: Connection established.
debug1: identity file /home/rdhw/.ssh/identity type -1
debug1: identity file /home/rdhw/.ssh/id_rsa type -1
debug1: identity file /home/rdhw/.ssh/id_dsa type -1
debug1: Remote protocol version 1.99, 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_4.3
debug2: fd 3 setting O_NONBLOCK
debug1: SSH2_MSG_KEXINIT sent
Read from socket failed: Connection reset by peer

C:\Documents and Settings\rdhw>ssh -vvv 127.0.0.1
OpenSSH_4.3p2, OpenSSL 0.9.8a 11 Oct 2005
debug1: Reading configuration data /etc/ssh_config
debug2: ssh_connect: needpriv 0
debug1: Connecting to 127.0.0.1 [127.0.0.1] port 22.
debug1: Connection established.
debug1: identity file /home/rdhw/.ssh/identity type -1
debug1: identity file /home/rdhw/.ssh/id_rsa type -1
debug1: identity file /home/rdhw/.ssh/id_dsa type -1
debug1: Remote protocol version 1.99, 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_4.3
debug2: fd 3 setting O_NONBLOCK
debug1: SSH2_MSG_KEXINIT sent
debug1: SSH2_MSG_KEXINIT received
debug2: kex_parse_kexinit: diffie-hellman-group-exchange-sha1,diffie-hellman-gro
up14-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,arcfour1
28,arcfour256,arcfour,aes192-cbc,aes256-cbc,rijndael-cbc@lysator.liu.se,aes128-c
tr,aes192-ctr,aes256-ctr
debug2: kex_parse_kexinit: aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour1
28,arcfour256,arcfour,aes192-cbc,aes256-cbc,rijndael-cbc@lysator.liu.se,aes128-c
tr,aes192-ctr,aes256-ctr
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160@open
ssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160@open
ssh.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-gro
up14-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,arcfour1
28,arcfour256,arcfour,aes192-cbc,aes256-cbc,rijndael-cbc@lysator.liu.se,aes128-c
tr,aes192-ctr,aes256-ctr
debug2: kex_parse_kexinit: aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour1
28,arcfour256,arcfour,aes192-cbc,aes256-cbc,rijndael-cbc@lysator.liu.se,aes128-c
tr,aes192-ctr,aes256-ctr
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160@open
ssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160@open
ssh.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: 139/256
debug2: bits set: 518/1024
debug1: SSH2_MSG_KEX_DH_GEX_INIT sent
debug1: expecting SSH2_MSG_KEX_DH_GEX_REPLY
debug3: check_host_in_hostfile: filename /home/rdhw/.ssh/known_hosts
debug3: check_host_in_hostfile: match line 8
debug1: Host '127.0.0.1' is known and matches the RSA host key.
debug1: Found key in /home/rdhw/.ssh/known_hosts:8
debug2: bits set: 523/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: /home/rdhw/.ssh/identity (0x0)
debug2: key: /home/rdhw/.ssh/id_rsa (0x0)
debug2: key: /home/rdhw/.ssh/id_dsa (0x0)
debug1: Authentications that can continue: publickey,password,keyboard-interacti
ve
debug3: start over, passed a different list publickey,password,keyboard-interact
ive
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: /home/rdhw/.ssh/identity
debug3: no such identity: /home/rdhw/.ssh/identity
debug1: Trying private key: /home/rdhw/.ssh/id_rsa
debug3: no such identity: /home/rdhw/.ssh/id_rsa
debug1: Trying private key: /home/rdhw/.ssh/id_dsa
debug3: no such identity: /home/rdhw/.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
debug1: Authentications that can continue: publickey,password,keyboard-interacti
ve
debug3: userauth_kbdint: disable: no info_req_seen
debug2: we did not send a packet, disable method
debug3: authmethod_lookup password
debug3: remaining preferred:
debug3: authmethod_is_enabled password
debug1: Next authentication method: password
rdhw@127.0.0.1's password:
debug3: packet_send2: adding 64 (len 56 padlen 8 extra_pad 64)
debug2: we sent a password packet, wait for reply
debug1: Authentication succeeded (password).
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
debug2: channel 0: request pty-req confirm 0
debug2: channel 0: request shell confirm 0
debug2: fd 3 setting TCP_NODELAY
debug2: callback done
debug2: channel 0: open confirm rwindow 0 rmax 32768
debug2: channel 0: rcvd adjust 131072
Last login: Mon Jun 5 09:45:06 2006 from localhost


rdhw@qjunbur ~
$ exit
debug1: client_input_channel_req: channel 0 rtype exit-status reply 0
logout
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
debug2: channel 0: close_read
debug2: channel 0: input open -> closed
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)

debug3: channel 0: close_fds r -1 w -1 e 6 c -1
Connection to 127.0.0.1 closed.
debug1: Transferred: stdin 0, stdout 0, stderr 33 bytes in 149.2 seconds
debug1: Bytes per second: stdin 0.0, stdout 0.0, stderr 0.2

C:\Documents and Settings\rdhw>ssh -vvv 127.0.0.1
OpenSSH_4.3p2, OpenSSL 0.9.8a 11 Oct 2005
debug1: Reading configuration data /etc/ssh_config
debug2: ssh_connect: needpriv 0
debug1: Connecting to 127.0.0.1 [127.0.0.1] port 22.
debug1: Connection established.
debug1: identity file /home/rdhw/.ssh/identity type -1
debug1: identity file /home/rdhw/.ssh/id_rsa type -1
debug1: identity file /home/rdhw/.ssh/id_dsa type -1
debug1: Remote protocol version 1.99, 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_4.3
debug2: fd 3 setting O_NONBLOCK
debug1: SSH2_MSG_KEXINIT sent
Read from socket failed: Connection reset by peer
C:\Documents and Settings\rdhw>


... and then *sometimes* I get this, where the interactive session gets created, but then fails in the shell:


debug1: Entering interactive session.
debug2: callback start
debug2: client_session2_setup: id 0
debug2: channel 0: request pty-req confirm 0
debug2: channel 0: request shell confirm 0
debug2: fd 3 setting TCP_NODELAY
debug2: callback done
debug2: channel 0: open confirm rwindow 0 rmax 32768
debug2: channel 0: rcvd adjust 131072
Last login: Mon Jun 5 10:19:04 2006 from localhost
8 [main] ? (2980) C:\cygwin\bin\bash.exe: *** fatal error - couldn't alloc
ate heap, Win32 error 487, base 0x4D0000, top 0x4E0000, reserve_size 61440, allo
csize 65536, page_const 4096
2695 [main] -bash 4052 child_copy: stack write copy failed, 0x22E340..0x23000
0, done 0, windows pid 2286196, Win32 error 5
-bash: fork: No error
-bash-3.1$


Why is bash unable to create heap? Before you ask, this PC has 2GB of RAM, and these experiments were conducted with no significant other applications active.

You could try changing that setting, sshd will spawn a second process but
this time under user SYSTEM... if that works then we can narrow the
possibilities.

Using "UsePrivilegeSeparation no" eliminates the initial fork failure in sshd, but then (most of the time) gives the errors in bash as shown above. It rarely results in a successful bash session.


/usr/share/doc/Cygwin/openssh.README and for WinXP the recommendation is
only to use ssh-host-config and ssh-user-config.

ssh-host-config has been done, but I am happy with the defaults for the time being and have not done ssh-user-config.


--
Robin Walker (Junior Bursar), Queens' College, Cambridge CB3 9ET, UK
rdhw@cam.ac.uk  http://www.queens.cam.ac.uk/  Tel:+44 1223 335528

Attachment: cygcheck.out
Description: Text document

--
Unsubscribe info:      http://cygwin.com/ml/#unsubscribe-simple
Problem reports:       http://cygwin.com/problems.html
Documentation:         http://cygwin.com/docs.html
FAQ:                   http://cygwin.com/faq/

Index Nav: [Date Index] [Subject Index] [Author Index] [Thread Index]
Message Nav: [Date Prev] [Date Next] [Thread Prev] [Thread Next]