Thanks Igor for your help, pls see strace results below:
On Sat 12/24/05 23:45 EST cygwin@cygwin.com wrote:
> On Sat, 24 Dec 2005, Tom Rodman wrote:
>
> > Problem: 'ssh localhost date' asks for password, I type it, I'm
> > authenticated, but no output is seen from the date command
> > (original post has details)
> >
> > Corrina, and cgf wrote WJFFM:
> > http://cygwin.com/ml/cygwin/2005-12/msg00801.html
> >
> > So what is special about my setup? What additional information should
> > I supply? Are there any debugging approaches you can suggest? Could I
> > somehow run strace, if so please give me the exact command line(s).
>
> As an adaptation of your own command:
--snip
> Try:
>
> cygrunsrv -I sshd_test -p /usr/bin/strace.exe -a '-o /var/tmp/sshd_strace
> /usr/sbin/sshd.exe -ddd' -e CYGWIN="$CYGWIN"
I setup the sshd_test service as you indicated above Igor.
Here are the test results, my hope is that some kind soul :->
will analyze them:
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
[EMAIL PROTECTED]'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,[EMAIL PROTECTED],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,[EMAIL PROTECTED],aes128-ctr,aes192-ctr,aes256-ctr
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,[EMAIL
PROTECTED],hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,[EMAIL
PROTECTED],hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: none,[EMAIL PROTECTED]
debug2: kex_parse_kexinit: none,[EMAIL PROTECTED]
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,[EMAIL PROTECTED],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,[EMAIL PROTECTED],aes128-ctr,aes192-ctr,aes256-ctr
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,[EMAIL
PROTECTED],hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,[EMAIL
PROTECTED],hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: none,[EMAIL PROTECTED],zlib
debug2: kex_parse_kexinit: none,[EMAIL PROTECTED],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
$
failing case, invoked in DOS window, 20051224 14:32:37 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.149/4/2) 20051224 14:32:37 i686 unknown
unknown Cygwin
$ true > /var/log/sshd_test.log
$ ssh localhost date
[EMAIL PROTECTED]'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/PROG
RA~1/BMCSOF~1/common/globalc/bin/Windows-x86:/drv/c/Progra~1/tivoli/tsm/baclient:/drv/c/PROGRA~1/BMCSOF~1/PATROL~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/System32/W
bem:/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 1782 22
SSH_CONNECTION=127.0.0.1 1782 127.0.0.1 22
debug3: channel 0: close_fds r -1 w -1 e -1 c -1
$ : failed, ie no output from date command is seen 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 1782
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 852
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,r
[EMAIL PROTECTED],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,r
[EMAIL PROTECTED],aes128-ctr,aes192-ctr,aes256-ctr
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,[EMAIL
PROTECTED],hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,[EMAIL
PROTECTED],hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: none,[EMAIL PROTECTED]
debug2: kex_parse_kexinit: none,[EMAIL PROTECTED]
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,r
[EMAIL PROTECTED],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,r
[EMAIL PROTECTED],aes128-ctr,aes192-ctr,aes256-ctr
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,[EMAIL
PROTECTED],hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,[EMAIL
PROTECTED],hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: none,[EMAIL PROTECTED],zlib
debug2: kex_parse_kexinit: none,[EMAIL PROTECTED],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: 133/256
debug2: bits set: 509/1024
debug1: expecting SSH2_MSG_KEX_DH_GEX_INIT
debug2: bits set: 518/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 0x452bf8(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 1782 ssh2
debug3: mm_auth_password: user not authenticated
debug3: mm_request_receive entering
Failed none for staffuser1 from 127.0.0.1 port 1782 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 1782 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 1782 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 1782 ssh2
debug3: mm_get_keystate: Waiting for new keys
debug3: mm_request_receive_expect entering: type 24
debug3: mm_send_keystate: Sending new keys: 0x453708 0x452fa0
debug3: mm_request_receive entering
debug3: mm_newkeys_to_blob: converting 0x453708
debug3: mm_newkeys_to_blob: converting 0x452fa0
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: 0x452178(118)
debug2: mac_init: found hmac-md5
debug3: mm_get_keystate: Waiting for second key
debug3: mm_newkeys_from_blob: 0x452178(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 42 from efd 10
debug2: channel 0: rwin 131072 elen 42 euse 1
debug2: channel 0: sent ext data 42
debug2: channel 0: read 885 from efd 10
debug2: channel 0: rwin 131030 elen 885 euse 1
debug2: channel 0: sent ext data 885
debug2: channel 0: read 478 from efd 10
debug2: channel 0: rwin 130145 elen 478 euse 1
debug2: channel 0: sent ext data 478
debug2: channel 0: read 132 from efd 10
debug2: channel 0: rwin 129667 elen 132 euse 1
debug2: channel 0: sent ext data 132
debug2: channel 0: read 8 from efd 10
debug2: channel 0: rwin 129535 elen 8 euse 1
debug2: channel 0: sent ext data 8
debug2: channel 0: read 4 from efd 10
debug2: channel 0: rwin 129527 elen 4 euse 1
debug2: channel 0: sent ext data 4
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 78 from efd 10
debug2: channel 0: rwin 129468 elen 78 euse 1
debug2: channel 0: sent ext data 78
debug2: channel 0: read 37 from efd 10
debug2: channel 0: rwin 129390 elen 37 euse 1
debug2: channel 0: sent ext data 37
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 71 from efd 10
debug2: channel 0: rwin 128979 elen 71 euse 1
debug2: channel 0: sent ext data 71
debug2: channel 0: read 49 from efd 10
debug2: channel 0: rwin 128908 elen 49 euse 1
debug2: channel 0: sent ext data 49
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 37 from efd 10
debug2: channel 0: rwin 128765 elen 37 euse 1
debug2: channel 0: sent ext data 37
debug2: channel 0: read 35 from efd 10
debug2: channel 0: rwin 128728 elen 35 euse 1
debug2: channel 0: sent ext data 35
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 19 from efd 10
debug2: channel 0: rwin 128633 elen 19 euse 1
debug2: channel 0: sent ext data 19
debug2: channel 0: read 32 from efd 10
debug2: channel 0: rwin 128614 elen 32 euse 1
debug2: channel 0: sent ext data 32
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 5084
debug1: session_exit_message: session 0 channel 0 pid 5084
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 5084
debug2: notify_done: reading
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: read 0 from efd 10
debug2: channel 0: closing read-efd 10
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
$
--snip
> > Maybe I'll get lucky, and someone other than me, w/developer skills
> > will duplicate the problem, just try:
> >
> > ssh localhost date #pls use a snapshot after Dec 16
>
> Don't know what's special about your setup,
If you can duplicate the problem, then my guess is there is nothing
special about my setup, but it's still a mystery why Corinna,
and cgf were not seeing the problem.
> but I was able to reproduce
> this on my laptop with a 12/22 self-built DLL -- I'll see what I can do to
> debug this (no promises, though)...
Thanks again for any effort you put in.
--
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/
