Hello all,
WinXP SP 3, Cygwin1.dll 1.7.7 (latest stable download), sshd and ssh
latest stable. I created a root user (!), empty /var/empty that belongs to
root, but deviate (by ssh-host-config) from the standard by
Port 22
StrictModes no
UsePrivilegeSeparation no
Compression no
Subsystem sftp /usr/sbin/sftp-server
I did my
mkpasswd -l > /etc/passwd
mkgroup -l > /etc/group
Connection establishes but I cannot continue to work (note the line
"debug1: Connection established"):
mar...@martin004 ~
$ cygrunsrv --start sshd
mar...@martin004 ~
$ strace -f -o /tmp/strace.out ssh -vvv mar...@192.168.178.2
OpenSSH_5.6p1, OpenSSL 0.9.8q 2 Dec 2010
debug1: Reading configuration data /etc/ssh_config
debug2: ssh_connect: needpriv 0
debug1: Connecting to 192.168.178.2 [192.168.178.2] port 22.
debug1: Connection established.
debug1: identity file /home/martin/.ssh/id_rsa type -1
debug1: identity file /home/martin/.ssh/id_rsa-cert type -1
debug3: Not a RSA1 key file /home/martin/.ssh/id_dsa.
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
debug1: identity file /home/martin/.ssh/id_dsa type 2
debug1: ssh_dss_verify: signature correct
debug1: identity file /home/martin/.ssh/id_dsa-cert type 4
Funnily enough, /tmp/strace.out shows (less with line numbers)
1024 90 285650 [main] ssh 928 fhandler_base::set_flags: flags
0x100000, supplied_bin 0x10000
1025 36 285686 [main] ssh 928 fhandler_base::set_flags: filemode
set to text
1026 38 285724 [main] ssh 928 fhandler_base::open: 0 = NtCreateFile
(0x5D0, 80100000, \??\C:\cygwin\home\martin\.ssh\id_dsa-c
o, NULL, 0, 7, 1, 4020, NULL, 0)
1027 338 286062 [main] ssh 928 fhandler_base::open: 1 =
fhandler_base::open (\??\C:\cygwin\home\martin\.ssh\id_dsa-cert.pub, 0
1028 49 286111 [main] ssh 928 fhandler_base::open_fs: 1 =
fhandler_disk_file::open (\??\C:\cygwin\home\martin\.ssh\id_dsa-cer
)
1029 40 286151 [main] ssh 928 open: 4 = open
(/home/martin/.ssh/id_dsa-cert.pub, 0x0)
1030 177 286328 [main] ssh 928 _cygwin_istext_for_stdio: fd 4:
defaulting to text
1031 235 286563 [main] ssh 928 cygpsid::debug_print: get_sids_info:
owner SID = S-1-5-21-484763869-823518204-682003330-1005
1032 48 286611 [main] ssh 928 cygpsid::debug_print: get_sids_info:
group SID = S-1-5-21-484763869-823518204-682003330-513
1033 42 286653 [main] ssh 928 get_info_from_sd: ACL 1A4, uid 1005,
gid 513
1034 45 286698 [main] ssh 928 fhandler_base::fstat_helper: 0 =
fstat (\??\C:\cygwin\home\martin\.ssh\id_dsa-cert.pub, 0x23831
e=4D2B76EC st_size=1605, st_mode=0x81A4, st_ino=125256364636259231,
sizeof=96
1035 64 286762 [main] ssh 928 fstat64: 0 = fstat (4, 0x238318)
1036 61 286823 [main] ssh 928 fhandler_base::set_flags: flags
0x110000, supplied_bin 0x0
1037 34 286857 [main] ssh 928 fhandler_base::set_flags:
O_TEXT/O_BINARY set in flags 0x10000
1038 41 286898 [main] ssh 928 fhandler_base::set_flags: filemode
set to binary
1039 41 286939 [main] ssh 928 setmode:
(4<\??\C:\cygwin\home\martin\.ssh\id_dsa-cert.pub>, 0x10000) returning text
1040 37 286976 [main] ssh 928 readv: readv (4, 0x238334, 1)
blocking, sigcatchers 0
1041 94 287070 [main] ssh 928 fhandler_base::read: returning 1605,
binary mode
1042 31 287101 [main] ssh 928 readv: 1605 = readv (4, 0x238334, 1),
errno 2
1043 38 287139 [main] ssh 928 fhandler_base::set_flags: flags
0x120000, supplied_bin 0x0
1044 41 287180 [main] ssh 928 fhandler_base::set_flags:
O_TEXT/O_BINARY set in flags 0x20000
1045 38 287218 [main] ssh 928 fhandler_base::set_flags: filemode
set to text
1046 32 287250 [main] ssh 928 setmode:
(4<\??\C:\cygwin\home\martin\.ssh\id_dsa-cert.pub>, 0x20000) returning
binary
1047 10227 297477 [main] ssh 928 fhandler_console::write: 237E88, 43
1048 58 297535 [main] ssh 928 fhandler_console::write: at 100(d)
state is 0
1049 180 297715 [main] ssh 928 fhandler_console::write: at 10(0x20)
state is 0
1050 73 297788 [main] ssh 928 fhandler_console::write: 43 =
fhandler_console::write (,..43)
1051 934 298722 [main] ssh 928 close: close (4)
1052 41 298763 [main] ssh 928 fhandler_base::close: closing
'/home/martin/.ssh/id_dsa-cert.pub' handle 0x5D0
1053 520 299283 [main] ssh 928 close: 0 = close (4)
1054 320 299603 [main] ssh 928 fhandler_console::write: 23B088, 60
1055 37 299640 [main] ssh 928 fhandler_console::write: at 100(d)
state is 0
1056 142 299782 [main] ssh 928 fhandler_console::write: at 10(0x20)
state is 0
1057 74 299856 [main] ssh 928 fhandler_console::write: 60 =
fhandler_console::write (,..60)
1058 389 300245 [main] ssh 928 sig_send: sendsig 0x748, pid 928,
signal -34, its_me 1
1059 137 300382 [main] ssh 928 sig_send: wakeup 0x5D4
1060 55 300437 [main] ssh 928 sig_send: Waiting for pack.wakeup
0x5D4
1061 54 300491 [sig] ssh 928 wait_sig: signalling pack.wakeup 0x5D4
1062 44 300535 [main] ssh 928 sig_send: returning 0x0 from sending
signal -34
1063 42 300577 [main] ssh 928 sigaction_worker: signal 13, newact
0x0, oa 0x0
1064 31 300608 [main] ssh 928 sig_send: sendsig 0x748, pid 928,
signal -34, its_me 1
1065 39 300647 [main] ssh 928 sig_send: wakeup 0x5D4
1066 42 300689 [main] ssh 928 sig_send: Waiting for pack.wakeup
0x5D4
1067 44 300733 [sig] ssh 928 wait_sig: signalling pack.wakeup 0x5D4
1068 36 300769 [main] ssh 928 sig_send: returning 0x0 from sending
signal -34
1069 31 300800 [main] ssh 928 sigaction_worker: signal 13, newact
0x23B4AC (handler 0x1), oa 0x0
1070 29 300829 [main] ssh 928 sig_send: sendsig 0x748, pid 928,
signal -13, its_me 1
1071 35 300864 [main] ssh 928 sig_send: wakeup 0x5D4
1072 33 300897 [main] ssh 928 sig_send: Waiting for pack.wakeup
0x5D4
1073 42 300939 [sig] ssh 928 wait_sig: signalling pack.wakeup 0x5D4
1074 225 301164 [main] ssh 928 sig_send: returning 0x0 from sending
signal -13
1075 124 301288 [main] ssh 928 readv: readv (3, 0x23B194, 1)
blocking, sigcatchers 0
If I search backwards for " 3 = open ", I find
383 29 170778 [main] ssh 928 open: 3 = open (/dev/urandom, 0x1C000)
384 28 170806 [main] ssh 928 fhandler_base::fstat: here
385 29 170835 [main] ssh 928 time: 1294694125 = time (0)
386 44 170879 [main] ssh 928 fstat64: 0 = fstat (3, 0x23B320)
In this state, sshd forked a process that occupies a complete cpu. Trying
strace -p does not reveal much:
$ strace -p 3432
Windows process 2052 attached
**********************************************
Program name: C:\cygwin\usr\sbin\sshd.exe (pid 3432, ppid 1888)
App version: 1007.7, api: 0.230
DLL version: 1007.7, api: 0.230
DLL build: 2010-08-31 09:58
OS version: Windows NT-5.1
Heap size: 402653184
Date/Time: 2011-01-10 23:04:01
**********************************************
and no more output. So it looks like a busy loop. Similar holds for the
ssh strace when it hangs. It looks like
$ strace -p 3312
Windows process 3784 attached
**********************************************
Program name: C:\cygwin\bin\ssh.exe (pid 3312, ppid 3876)
App version: 1007.7, api: 0.230
DLL version: 1007.7, api: 0.230
DLL build: 2010-08-31 09:58
OS version: Windows NT-5.1
Heap size: 402653184
Date/Time: 2011-01-10 23:14:20
**********************************************
I tried the same with SyslogFacility LOCAL0 and LogLevel DEBUG3 in
/etc/sshd_config. /var/log/sshd.log is created but it remains empty. Can I
get more info? Unluckily, I did not find further info about the
SyslogFacility destinations.
Anybody any pointers where to look and what to look for?
Thanks for your time and enlightenment.
Where do I search further? Or does somebody even have a solution for my
problem?
--
Problem reports: http://cygwin.com/problems.html
FAQ: http://cygwin.com/faq/
Documentation: http://cygwin.com/docs.html
Unsubscribe info: http://cygwin.com/ml/#unsubscribe-simple
