working case, invoked in DOS window, 20051216 23:59:19 snapshot --v-v------------------C-U-T---H-E-R-E-------------------------v-v-- $ uname -a # sorry, DOS cmd.exe window, wrapped lines ~120 chars CYGWIN_NT-5.0 OurServer108 1.5.19s(0.148/4/2) 20051216 23:59:19 i686 unknown unknown Cygwin $ true > /var/log/sshd_test.log $ ssh localhost date staffuser1@localhost's password: debug1: permanently_set_uid: 15773/16027 debug3: Copy environment: ALLUSERSPROFILE=C:\\Documents and Settings\\All Users debug3: Copy environment: COMMONPROGRAMFILES=C:\\Program Files\\Common Files debug3: Copy environment: COMPUTERNAME=OurServer108 debug3: Copy environment: COMSPEC=C:\\WINNT\\system32\\cmd.exe debug3: Copy environment: CYGWIN=binmode tty ntsec smbntsec debug3: Copy environment: NUMBER_OF_PROCESSORS=4 debug3: Copy environment: OS=Windows_NT debug3: Copy environment: PATH=/drv/c/bcm63/bin:/drv/c/bcm63/jre/bin:/drv/c/bcm63/bin/util:/drv/c/WINNT/system32:/drv/c/ WINNT:/drv/c/WINNT/System32/Wbem:/aut/perl5/bin:/drv/c/Program Files/Resource Kit/:/drv/c/Program Files/Support Tools/:/ drv/c/PROGRA~1/BMCSOF~1/common/globalc/bin/Windows-x86:/drv/c/Progra~1/tivoli/tsm/baclient:/drv/c/PROGRA~1/BMCSOF~1/PATR OL~1/bin:/drv/c/Program Files/Symantec/pcAnywhere/:/drv/c/HPOV/bin:/drv/c/HPOV/bin/OpC:./:/usr/bin debug3: Copy environment: PATHEXT=.COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH debug3: Copy environment: PROCESSOR_ARCHITECTURE=x86 debug3: Copy environment: PROCESSOR_IDENTIFIER=x86 Family 15 Model 2 Stepping 7, GenuineIntel debug3: Copy environment: PROCESSOR_LEVEL=15 debug3: Copy environment: PROCESSOR_REVISION=0207 debug3: Copy environment: PROGRAMFILES=C:\\Program Files debug3: Copy environment: SYSTEMDRIVE=C: debug3: Copy environment: SYSTEMROOT=C:\\WINNT debug3: Copy environment: TEMP=/drv/c/TEMP debug3: Copy environment: TMP=/drv/c/TMP debug3: Copy environment: WINDIR=C:\\WINNT Environment: ALLUSERSPROFILE=C:\Documents and Settings\All Users COMMONPROGRAMFILES=C:\Program Files\Common Files COMPUTERNAME=OurServer108 COMSPEC=C:\WINNT\system32\cmd.exe CYGWIN=binmode tty ntsec smbntsec NUMBER_OF_PROCESSORS=4 OS=Windows_NT PATH=/drv/c/bcm63/bin:/drv/c/bcm63/jre/bin:/drv/c/bcm63/bin/util:/drv/c/WINNT/system32:/drv/c/WINNT:/drv/c/WINNT/Syste m32/Wbem:/aut/perl5/bin:/drv/c/Program Files/Resource Kit/:/drv/c/Program Files/Su PATHEXT=.COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH PROCESSOR_ARCHITECTURE=x86 PROCESSOR_IDENTIFIER=x86 Family 15 Model 2 Stepping 7, GenuineIntel PROCESSOR_LEVEL=15 PROCESSOR_REVISION=0207 PROGRAMFILES=C:\Program Files SYSTEMDRIVE=C: SYSTEMROOT=C:\WINNT TEMP=/drv/c/TEMP TMP=/drv/c/TMP WINDIR=C:\WINNT USER=staffuser1 LOGNAME=staffuser1 HOME=/home/local/staffuser1 MAIL=/var/spool/mail/staffuser1 SHELL=/bin/bash SSH_CLIENT=127.0.0.1 1287 22 SSH_CONNECTION=127.0.0.1 1287 127.0.0.1 22 debug3: channel 0: close_fds r -1 w -1 e -1 c -1 Mon Dec 26 11:23:49 CST 2005 $ : worked just fine, see date output above $ cat /var/log/sshd_test.log # line wrapping munges the 1st debug1 word below d ebug1: fd 4 clearing O_NONBLOCK debug1: Server will not fork when running in debugging mode. debug3: send_rexec_state: entering fd = 7 config len 188 debug3: ssh_msg_send: type 0 debug3: send_rexec_state: done debug1: rexec start in 4 out 4 newsock 4 pipe -1 sock 7 debug1: inetd sockets after dupping: 3, 3 Connection from 127.0.0.1 port 1287 debug1: Client protocol version 2.0; client software version OpenSSH_4.2 debug1: match: OpenSSH_4.2 pat OpenSSH* debug1: Enabling compatibility mode for protocol 2.0 debug1: Local version string SSH-1.99-OpenSSH_4.2 debug2: fd 3 setting O_NONBLOCK debug2: Network child is on pid 464 debug3: preauth child monitor started debug1: list_hostkey_types: ssh-rsa,ssh-dss debug3: mm_request_receive entering 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 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: 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: mac_init: found hmac-md5 debug1: kex: client->server aes128-cbc hmac-md5 none debug2: mac_init: found hmac-md5 debug1: kex: server->client aes128-cbc hmac-md5 none debug1: SSH2_MSG_KEX_DH_GEX_REQUEST received debug3: mm_request_send entering: type 0 debug3: mm_choose_dh: waiting for MONITOR_ANS_MODULI debug3: monitor_read: checking request 0 debug3: mm_request_receive_expect entering: type 1 debug3: mm_answer_moduli: got parameters: 1024 1024 8192 debug3: mm_request_receive entering debug3: mm_request_send entering: type 1 debug2: monitor_read: 0 used once, disabling now debug3: mm_choose_dh: remaining 0 debug3: mm_request_receive entering debug1: SSH2_MSG_KEX_DH_GEX_GROUP sent debug2: dh_gen_key: priv key bits set: 130/256 debug2: bits set: 524/1024 debug1: expecting SSH2_MSG_KEX_DH_GEX_INIT debug2: bits set: 494/1024 debug3: mm_key_sign entering debug3: mm_request_send entering: type 4 debug3: mm_key_sign: waiting for MONITOR_ANS_SIGN debug3: monitor_read: checking request 4 debug3: mm_request_receive_expect entering: type 5 debug3: mm_answer_sign debug3: mm_request_receive entering debug3: mm_answer_sign: signature 0x452d20(143) debug3: mm_request_send entering: type 5 debug2: monitor_read: 4 used once, disabling now debug1: SSH2_MSG_KEX_DH_GEX_REPLY sent debug3: mm_request_receive entering 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: KEX done debug1: userauth-request for user staffuser1 service ssh-connection method none debug1: attempt 0 failures 0 debug3: mm_getpwnamallow entering debug3: mm_request_send entering: type 6 debug3: mm_getpwnamallow: waiting for MONITOR_ANS_PWNAM debug3: monitor_read: checking request 6 debug3: mm_request_receive_expect entering: type 7 debug3: mm_answer_pwnamallow debug3: mm_request_receive entering debug3: mm_answer_pwnamallow: sending MONITOR_ANS_PWNAM: 1 debug3: mm_request_send entering: type 7 debug2: monitor_read: 6 used once, disabling now debug2: input_userauth_request: setting up authctxt for staffuser1 debug3: mm_request_receive entering debug3: mm_inform_authserv entering debug3: mm_request_send entering: type 3 debug3: monitor_read: checking request 3 debug2: input_userauth_request: try method none debug3: mm_answer_authserv: service=ssh-connection, style= debug2: monitor_read: 3 used once, disabling now debug3: mm_request_receive entering debug3: mm_auth_password entering debug3: mm_request_send entering: type 10 debug3: mm_auth_password: waiting for MONITOR_ANS_AUTHPASSWORD debug3: monitor_read: checking request 10 debug3: mm_request_receive_expect entering: type 11 debug3: mm_answer_authpassword: sending result 0 debug3: mm_request_receive entering debug3: mm_request_send entering: type 11 Failed none for staffuser1 from 127.0.0.1 port 1287 ssh2 debug3: mm_auth_password: user not authenticated debug3: mm_request_receive entering Failed none for staffuser1 from 127.0.0.1 port 1287 ssh2 debug1: userauth-request for user staffuser1 service ssh-connection method keyboard-interactive debug1: attempt 1 failures 1 debug2: input_userauth_request: try method keyboard-interactive debug1: keyboard-interactive devs debug1: auth2_challenge: user=staffuser1 devs= debug1: kbdint_alloc: devices '' debug2: auth2_challenge_start: devices Failed keyboard-interactive for staffuser1 from 127.0.0.1 port 1287 ssh2 debug1: userauth-request for user staffuser1 service ssh-connection method password debug1: attempt 2 failures 2 debug2: input_userauth_request: try method password debug3: mm_auth_password entering debug3: mm_request_send entering: type 10 debug3: mm_auth_password: waiting for MONITOR_ANS_AUTHPASSWORD debug3: monitor_read: checking request 10 debug3: mm_request_receive_expect entering: type 11 debug3: mm_request_receive entering debug3: mm_answer_authpassword: sending result 1 debug3: mm_request_send entering: type 11 Accepted password for staffuser1 from 127.0.0.1 port 1287 ssh2 debug3: mm_auth_password: user authenticated debug1: monitor_child_preauth: staffuser1 has been authenticated by privileged process Accepted password for staffuser1 from 127.0.0.1 port 1287 ssh2 debug3: mm_get_keystate: Waiting for new keys debug3: mm_request_receive_expect entering: type 24 debug3: mm_send_keystate: Sending new keys: 0x453eb0 0x4535f8 debug3: mm_request_receive entering debug3: mm_newkeys_to_blob: converting 0x453eb0 debug3: mm_newkeys_to_blob: converting 0x4535f8 debug3: mm_send_keystate: New keys have been sent debug3: mm_send_keystate: Sending compression state debug3: mm_request_send entering: type 24 debug3: mm_send_keystate: Finished sending state debug3: mm_newkeys_from_blob: 0x452d20(118) debug2: mac_init: found hmac-md5 debug3: mm_get_keystate: Waiting for second key debug3: mm_newkeys_from_blob: 0x452d20(118) debug2: mac_init: found hmac-md5 debug3: mm_get_keystate: Getting compression state debug3: mm_get_keystate: Getting Network I/O buffers debug3: mm_share_sync: Share sync debug3: mm_share_sync: Share sync end debug2: set_newkeys: mode 0 debug2: set_newkeys: mode 1 debug1: Entering interactive session for SSH2. debug2: fd 4 setting O_NONBLOCK debug2: fd 5 setting O_NONBLOCK debug1: server_init_dispatch_20 debug1: server_input_channel_open: ctype session rchan 0 win 131072 max 32768 debug1: input_session_request debug1: channel 0: new [server-session] debug1: session_new: init debug1: session_new: session 0 debug1: session_open: channel 0 debug1: session_open: session 0: link with channel 0 debug1: server_input_channel_open: confirm session debug1: server_input_channel_req: channel 0 request exec reply 0 debug1: session_by_channel: session 0 channel 0 debug1: session_input_channel_req: session 0 req exec debug2: fd 8 setting O_NONBLOCK debug2: fd 7 setting O_NONBLOCK debug2: fd 10 setting O_NONBLOCK debug2: channel 0: read 251 from efd 10 debug2: channel 0: rwin 131072 elen 251 euse 1 debug2: channel 0: sent ext data 251 debug2: channel 0: read 814 from efd 10 debug2: channel 0: rwin 130821 elen 814 euse 1 debug2: channel 0: sent ext data 814 debug2: channel 0: read 426 from efd 10 debug2: channel 0: rwin 130007 elen 426 euse 1 debug2: channel 0: sent ext data 426 debug2: channel 0: read 48 from efd 10 debug2: channel 0: rwin 129581 elen 48 euse 1 debug2: channel 0: sent ext data 48 debug2: channel 0: read 8 from efd 10 debug2: channel 0: rwin 129533 elen 8 euse 1 debug2: channel 0: sent ext data 8 debug2: channel 0: read 2 from efd 10 debug2: channel 0: rwin 129525 elen 2 euse 1 debug2: channel 0: sent ext data 2 debug2: channel 0: read 55 from efd 10 debug2: channel 0: rwin 129523 elen 55 euse 1 debug2: channel 0: sent ext data 55 debug2: channel 0: read 52 from efd 10 debug2: channel 0: rwin 129468 elen 52 euse 1 debug2: channel 0: sent ext data 52 debug2: channel 0: read 63 from efd 10 debug2: channel 0: rwin 129416 elen 63 euse 1 debug2: channel 0: sent ext data 63 debug2: channel 0: read 63 from efd 10 debug2: channel 0: rwin 129353 elen 63 euse 1 debug2: channel 0: sent ext data 63 debug2: channel 0: read 17 from efd 10 debug2: channel 0: rwin 129290 elen 17 euse 1 debug2: channel 0: sent ext data 17 debug2: channel 0: read 204 from efd 10 debug2: channel 0: rwin 129273 elen 204 euse 1 debug2: channel 0: sent ext data 204 debug2: channel 0: read 90 from efd 10 debug2: channel 0: rwin 129069 elen 90 euse 1 debug2: channel 0: sent ext data 90 debug2: channel 0: read 93 from efd 10 debug2: channel 0: rwin 128979 elen 93 euse 1 debug2: channel 0: sent ext data 93 debug2: channel 0: read 27 from efd 10 debug2: channel 0: rwin 128886 elen 27 euse 1 debug2: channel 0: sent ext data 27 debug2: channel 0: read 51 from efd 10 debug2: channel 0: rwin 128859 elen 51 euse 1 debug2: channel 0: sent ext data 51 debug2: channel 0: read 43 from efd 10 debug2: channel 0: rwin 128808 elen 43 euse 1 debug2: channel 0: sent ext data 43 debug2: channel 0: read 53 from efd 10 debug2: channel 0: rwin 128765 elen 53 euse 1 debug2: channel 0: sent ext data 53 debug2: channel 0: read 19 from efd 10 debug2: channel 0: rwin 128712 elen 19 euse 1 debug2: channel 0: sent ext data 19 debug2: channel 0: read 60 from efd 10 debug2: channel 0: rwin 128693 elen 60 euse 1 debug2: channel 0: sent ext data 60 debug2: channel 0: read 51 from efd 10 debug2: channel 0: rwin 128633 elen 51 euse 1 debug2: channel 0: sent ext data 51 debug2: channel 0: read 96 from efd 10 debug2: channel 0: rwin 128582 elen 96 euse 1 debug2: channel 0: sent ext data 96 debug1: Received SIGCHLD. debug1: session_by_pid: pid 2880 debug1: session_exit_message: session 0 channel 0 pid 2880 debug2: channel 0: request exit-status confirm 0 debug1: session_exit_message: release channel 0 debug2: channel 0: write failed debug2: channel 0: close_write debug2: channel 0: output open -> closed debug1: session_close: session 0 pid 2880 debug2: notify_done: reading debug2: channel 0: read 0 from efd 10 debug2: channel 0: closing read-efd 10 debug2: channel 0: read<=0 rfd 8 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: send close debug3: channel 0: will not send data after close debug2: channel 0: rcvd close debug3: channel 0: will not send data after close debug2: channel 0: is dead debug2: channel 0: garbage collecting debug1: channel 0: free: server-session, nchannels 1 debug3: channel 0: status: The following connections are open: #0 server-session (t4 r0 i3/0 o3/0 fd -1/-1 cfd -1) debug3: channel 0: close_fds r -1 w -1 e -1 c -1 Connection closed by 127.0.0.1 debug1: do_cleanup Closing connection to 127.0.0.1 $