One more signal problem

[Jens Kessmeier <j dot kessmeier at teles dot de>]

I have trouble with the ptty code over months.

CYGWIN_NT-4.0 BONSEI 1.3.12s(0.53/3/2) 20020626 01:38:25 i586 unknown

See strace output below.

Description:

(a) Telnet session from system A to cygwin system B
(b) Type telnet escape char and quit, or kill telnet
(c) Another telnet session from system A to cygwin system B
(d) On system B telnetd of step (a) is gone, user shell (a) is running

Process list on system B after (a):

     UID     PID    PPID TTY     STIME COMMAND
   admin      95       1     ?    Feb 14 /usr/sbin/syslogd
   admin     114       1    ?    Feb 14 /usr/local/bin/ntpd
   admin     133       1    ?    Feb 14 /usr/sbin/cron
   admin     142       1    ?    Feb 14 /usr/sbin/inetd
   admin     425       1    ?    Feb 17 /usr/sbin/sshd
   admin     256     142   ?  17:09:13 /usr/libexec/in.telnetd
   admin      94     256   0  17:09:17 /bin/bash               <-
   admin     303      94   0  17:09:34 /usr/bin/ps

Process list on system B after (c):

     UID     PID    PPID TTY     STIME COMMAND
   admin      95       1   ?    Feb 14 /usr/sbin/syslogd
   admin     114       1   ?    Feb 14 /usr/local/bin/ntpd
   admin     133       1   ?    Feb 14 /usr/sbin/cron
   admin     142       1   ?    Feb 14 /usr/sbin/inetd
   admin     425       1   ?    Feb 17 /usr/sbin/sshd
   admin      94       1   0  17:09:17 /bin/bash              <- ?
   admin     277     142   ?  17:12:20 /usr/libexec/in.telnetd
   admin      99     277   1  17:12:24 /bin/bash
   admin      65      99   1  17:12:34 /usr/bin/ps

Do not wonder about the pids. The strace is from another session with the
same result.

Bash strace output

 2439    2439 [sig] -bash 133 wait_sig: looping
33851060 33853499 [main] -bash 133 fhandler_tty_slave::read: read(22F47F, 1)
handle 0x180

Telnetd strace output

 2008    2008 [sig] in.telnetd 122 wait_sig: looping
8456702 8458710 [select_socket] in.telnetd 122 thread_socket: Win32 select
returned 1
  761 8459471 [select_socket] in.telnetd 122 thread_socket: s 0xA01CD38,
testing fd 0 (/dev/tcp)
  509 8459980 [select_socket] in.telnetd 122 thread_socket: read_ready
 1208 8461188 [main] in.telnetd 122 select_stuff::wait: woke up.  wait_ret
2.  verifying
  503 8461691 [main] in.telnetd 122 select_stuff::wait: gotone 1
  441 8462132 [main] in.telnetd 122 select_stuff::wait: returning 0
  437 8462569 [main] in.telnetd 122 select_stuff::cleanup: calling cleanup
routines
  719 8463288 [select_pipe] in.telnetd 122 thread_pipe: stopping
 1576 8464864 [main] in.telnetd 122 socket_cleanup: si 0xA01CD98 si->thread
0x48
  452 8465316 [main] in.telnetd 122 socket_cleanup: connection to
si->exitsock 0x1B4
 3220 8468536 [main] in.telnetd 122 socket_cleanup: returning
  705 8469241 [main] in.telnetd 122 peek_socket: considering handle 0x8
  512 8469753 [main] in.telnetd 122 peek_socket: adding read fd_set
/dev/tcp, fd 0
  450 8470203 [main] in.telnetd 122 peek_socket: adding except fd_set
/dev/tcp, fd 0
  550 8470753 [main] in.telnetd 122 peek_socket: WINSOCK_SELECT returned 1
  463 8471216 [main] in.telnetd 122 set_bits: me 0xA01CD38, testing fd 0
(/dev/tcp)
  448 8471664 [main] in.telnetd 122 set_bits: ready 1
  440 8472104 [main] in.telnetd 122 select_stuff::poll: returning 1
  459 8472563 [main] in.telnetd 122 select_stuff::cleanup: calling cleanup
routines
  452 8473015 [main] in.telnetd 122 select_stuff::~select_stuff: deleting
select records
 1237 8474252 [main] in.telnetd 122 _read: read (0, 0x40FD04, 1024)
nonblocking, sigcatchers 1
  471 8474723 [main] in.telnetd 122 peek_socket: considering handle 0x8
  461 8475184 [main] in.telnetd 122 peek_socket: adding read fd_set
/dev/tcp, fd 0
  533 8475717 [main] in.telnetd 122 peek_socket: WINSOCK_SELECT returned 1
  465 8476182 [main] in.telnetd 122 fhandler_base::ready_for_read:
read_ready 1, avail 1
  454 8476636 [main] in.telnetd 122 fhandler_socket::recv: Fallback to
winsock 1 recv call
  561 8477197 [main] in.telnetd 122 _read: 0 = read (0, 0x40FD04, 1024),
errno 2
  460 8477657 [main] in.telnetd 122 _open: open (/var/run/utmp, 0x2)
  575 8478232 [main] in.telnetd 122 normalize_posix_path: src /var/run/utmp
  454 8478686 [main] in.telnetd 122 normalize_posix_path: /var/run/utmp =
normalize_posix_path (/var/run/utmp)
  506 8479192 [main] in.telnetd 122 mount_info::conv_to_win32_path:
conv_to_win32_path (/var/run/utmp)
  486 8479678 [main] in.telnetd 122 mount_info::conv_to_win32_path: src_path
/var/run/utmp, dst e:\var\run\utmp, flags 0x2, rc 0
 1346 8481024 [main] in.telnetd 122 symlink_info::check: not a symlink
  486 8481510 [main] in.telnetd 122 symlink_info::check: 0 = symlink.check
(e:\var\run\utmp, 0x22EF38) (0x2)
  503 8482013 [main] in.telnetd 122 path_conv::check: root_dir(e:\),
this->path(e:\var\run\utmp), set_has_acls(8)
  487 8482500 [main] in.telnetd 122 dtable::build_fhandler: fd 4, fh
0x61680710
  466 8482966 [main] in.telnetd 122 fhandler_base::open: (e:\var\run\utmp,
0x100002) query_open 0
  753 8483719 [main] in.telnetd 122 fhandler_base::open: 0x168 = CreateFileA
(e:\var\run\utmp, 0xC0000000, 0x7, 0x22F378, 0x3, 0x2000080, 0)
  513 8484232 [main] in.telnetd 122 fhandler_base::set_flags: flags
0x100002, supplied_bin 0x10000
  449 8484681 [main] in.telnetd 122 fhandler_base::set_flags: filemode set
to text
  460 8485141 [main] in.telnetd 122 fhandler_base::open: 1 =
fhandler_base::open (e:\var\run\utmp, 0x100002)
  454 8485595 [main] in.telnetd 122 fhandler_disk_file::open: 1 =
fhandler_disk_file::open (e:\var\run\utmp, 0x2)
  460 8486055 [main] in.telnetd 122 _open: 4 = open (/var/run/utmp, 0x2)
  456 8486511 [main] in.telnetd 122 normalize_posix_path: src
e:\var\run\utmp
  505 8487016 [main] in.telnetd 122 mount_info::conv_to_posix_path:
conv_to_posix_path (e:\var\run\utmp, no-keep-rel, no-add-slash)
  462 8487478 [main] in.telnetd 122 normalize_win32_path: e:\var\run\utmp =
normalize_win32_path (e:\var\run\utmp)
  549 8488027 [main] in.telnetd 122 mount_info::conv_to_posix_path:
/var/run/utmp = conv_to_posix_path (e:\var\run\utmp)
  461 8488488 [main] in.telnetd 122 mount_info::conv_to_win32_path:
conv_to_win32_path (/var/run/utmp)
  479 8488967 [main] in.telnetd 122 mount_info::conv_to_win32_path: src_path
/var/run/utmp, dst e:\var\run\utmp, flags 0x2, rc 0
 1117 8490084 [main] in.telnetd 122 symlink_info::check: not a symlink
  489 8490573 [main] in.telnetd 122 symlink_info::check: 0 = symlink.check
(e:\var\run\utmp, 0x22EF08) (0x2)
  474 8491047 [main] in.telnetd 122 path_conv::check: root_dir(e:\),
this->path(e:\var\run\utmp), set_has_acls(8)
  601 8491648 [main] in.telnetd 122 fhandler_disk_file::fstat_by_handle: 1 =
GetFileInformationByHandle (e:\var\run\utmp, 360)
 1898 8493546 [main] in.telnetd 122 fhandler_disk_file::fstat_helper: 0 =
fstat (, 0x22F728) st_atime=3D197A05 st_size=924, st_mode=0x81B4,
st_ino=12452990, sizeof=80
  519 8494065 [main] in.telnetd 122 fstat64: 0 = fstat (4, 0x22F728)
  862 8494927 [main] in.telnetd 122 _read: read (4, 0xA01CD38, 924)
blocking, sigcatchers 1
  446 8495373 [main] in.telnetd 122 _read: non-interruptible read
  775 8496148 [main] in.telnetd 122 fhandler_base::read: read 924 bytes (
0x7 0x0 0x0 0x0 0x0 0x0 0x0 0x0 t t y 0 0x0 0x0 0x0 0x0 ...)
  487 8496635 [main] in.telnetd 122 fhandler_base::read: returning 924
chars, text mode
  462 8497097 [main] in.telnetd 122 _read: 924 = read (4, 0xA01CD38, 924),
errno 2
  462 8497559 [main] in.telnetd 122 fhandler_base::lseek: lseek
(/var/run/utmp, 616, 0)
  473 8498032 [main] in.telnetd 122 fhandler_base::lseek: setting file
pointer to 0 (high), 616 (low)
  466 8498498 [main] in.telnetd 122 lseek64: 616 = lseek (0, 4, 0)
  482 8498980 [main] in.telnetd 122 time: 1025080155 = time (A01CFBC)
  450 8499430 [main] in.telnetd 122 _write: write (4, 0xA01CFA0, 308)
  451 8499881 [main] in.telnetd 122 fhandler_base::write: text write
  481 8500362 [main] in.telnetd 122 fhandler_base::write: 308 = write
(0xA01CFA0, 308)
  476 8500838 [main] in.telnetd 122 _write: 308 = write (4, 0xA01CFA0, 308)
  449 8501287 [main] in.telnetd 122 _close: close (4)
  436 8501723 [main] in.telnetd 122 fhandler_base::close: closing
'/var/run/utmp' handle 0x168
  738 8502461 [main] in.telnetd 122 _close: 0 = close (4)
  491 8502952 [main] in.telnetd 122 _open: open (/var/log/wtmp, 0x10009)
  454 8503406 [main] in.telnetd 122 normalize_posix_path: src /var/log/wtmp
  486 8503892 [main] in.telnetd 122 normalize_posix_path: /var/log/wtmp =
normalize_posix_path (/var/log/wtmp)
  458 8504350 [main] in.telnetd 122 mount_info::conv_to_win32_path:
conv_to_win32_path (/var/log/wtmp)
  479 8504829 [main] in.telnetd 122 mount_info::conv_to_win32_path: src_path
/var/log/wtmp, dst e:\var\log\wtmp, flags 0x2, rc 0
 1136 8505965 [main] in.telnetd 122 symlink_info::check: not a symlink
  489 8506454 [main] in.telnetd 122 symlink_info::check: 0 = symlink.check
(e:\var\log\wtmp, 0x22EF38) (0x2)
  477 8506931 [main] in.telnetd 122 path_conv::check: root_dir(e:\),
this->path(e:\var\log\wtmp), set_has_acls(8)
  505 8507436 [main] in.telnetd 122 dtable::build_fhandler: fd 4, fh
0x61680710
  460 8507896 [main] in.telnetd 122 fhandler_base::open: (e:\var\log\wtmp,
0x110009) query_open 0
  728 8508624 [main] in.telnetd 122 fhandler_base::open: 0xF4 = CreateFileA
(e:\var\log\wtmp, 0x40000000, 0x7, 0x22F378, 0x3, 0x2000080, 0)
  517 8509141 [main] in.telnetd 122 fhandler_base::set_flags: flags
0x110009, supplied_bin 0x10000
  453 8509594 [main] in.telnetd 122 fhandler_base::set_flags:
O_TEXT/O_BINARY set in flags 0x10000
  452 8510046 [main] in.telnetd 122 fhandler_base::set_flags: filemode set
to binary
  456 8510502 [main] in.telnetd 122 fhandler_base::open: 1 =
fhandler_base::open (e:\var\log\wtmp, 0x110009)
  482 8510984 [main] in.telnetd 122 fhandler_disk_file::open: 1 =
fhandler_disk_file::open (e:\var\log\wtmp, 0x10009)
  458 8511442 [main] in.telnetd 122 _open: 4 = open (/var/log/wtmp, 0x10009)
  490 8511932 [main] in.telnetd 122 time: 1025080155 = time (411000)
  504 8512436 [main] in.telnetd 122 _write: write (4, 0x410FE4, 308)
  477 8512913 [main] in.telnetd 122 fhandler_base::write: binary write
 1107 8514020 [main] in.telnetd 122 fhandler_base::write: 308 = write
(0x410FE4, 308)
  505 8514525 [main] in.telnetd 122 _write: 308 = write (4, 0x410FE4, 308)
  459 8514984 [main] in.telnetd 122 _close: close (4)
  440 8515424 [main] in.telnetd 122 fhandler_base::close: closing
'/var/log/wtmp' handle 0xF4
  949 8516373 [main] in.telnetd 122 _close: 0 = close (4)
  535 8516908 [main] in.telnetd 122 normalize_posix_path: src /dev/tty2
  450 8517358 [main] in.telnetd 122 normalize_posix_path: /dev/tty2 =
normalize_posix_path (/dev/tty2)
  450 8517808 [main] in.telnetd 122 mount_info::conv_to_win32_path:
conv_to_win32_path (/dev/tty2)
  476 8518284 [main] in.telnetd 122 mount_info::conv_to_win32_path: src_path
/dev/tty2, dst \dev\tty2, flags 0x2, rc 0
  459 8518743 [main] in.telnetd 122 chmod: 0 = chmod (/dev/tty2, 0x1B6)
  465 8519208 [main] in.telnetd 122 normalize_posix_path: src /dev/tty2
  440 8519648 [main] in.telnetd 122 normalize_posix_path: /dev/tty2 =
normalize_posix_path (/dev/tty2)
  474 8520122 [main] in.telnetd 122 mount_info::conv_to_win32_path:
conv_to_win32_path (/dev/tty2)
  460 8520582 [main] in.telnetd 122 mount_info::conv_to_win32_path: src_path
/dev/tty2, dst \dev\tty2, flags 0x2, rc 0
  460 8521042 [main] in.telnetd 122 chown_worker: 0 = chown (/dev/tty2,...)
  450 8521492 [main] in.telnetd 122 normalize_posix_path: src /dev/pty2
  513 8522005 [main] in.telnetd 122 normalize_posix_path: /dev/pty2 =
normalize_posix_path (/dev/pty2)
  456 8522461 [main] in.telnetd 122 mount_info::conv_to_win32_path:
conv_to_win32_path (/dev/pty2)
  502 8522963 [main] in.telnetd 122 mount_info::conv_to_win32_path: src_path
/dev/pty2, dst \dev\tty2, flags 0x2, rc 0
  458 8523421 [main] in.telnetd 122 chmod: 0 = chmod (/dev/pty2, 0x1B6)
  462 8523883 [main] in.telnetd 122 normalize_posix_path: src /dev/pty2
  442 8524325 [main] in.telnetd 122 normalize_posix_path: /dev/pty2 =
normalize_posix_path (/dev/pty2)
  449 8524774 [main] in.telnetd 122 mount_info::conv_to_win32_path:
conv_to_win32_path (/dev/pty2)
  485 8525259 [main] in.telnetd 122 mount_info::conv_to_win32_path: src_path
/dev/pty2, dst e:\dev\pty2, flags 0x2, rc 0
 1238 8526497 [main] in.telnetd 122 symlink_info::check: GetFileAttributes
(e:\dev\pty2) failed
  511 8527008 [main] in.telnetd 122 geterrno_from_win_error: windows error 2
== errno 2
  706 8527714 [main] in.telnetd 122 symlink_info::check: GetFileAttributes
(e:\dev\pty2.lnk) failed
  582 8528296 [main] in.telnetd 122 geterrno_from_win_error: windows error 2
== errno 2
  465 8528761 [main] in.telnetd 122 symlink_info::check: 0 = symlink.check
(e:\dev\pty2, 0x22EF38) (0x2)
  470 8529231 [main] in.telnetd 122 mount_info::conv_to_win32_path:
conv_to_win32_path (/dev)
  466 8529697 [main] in.telnetd 122 mount_info::conv_to_win32_path: src_path
/dev, dst e:\dev, flags 0x2, rc 0
  693 8530390 [main] in.telnetd 122 symlink_info::check: not a symlink
  461 8530851 [main] in.telnetd 122 symlink_info::check: 0 = symlink.check
(e:\dev, 0x22EF38) (0x2)
  471 8531322 [main] in.telnetd 122 path_conv::check: root_dir(e:\),
this->path(e:\dev\pty2), set_has_acls(8)
  802 8532124 [main] in.telnetd 122 chown_worker: 0 = chown (/dev/pty2,...)
  726 8532850 [main] in.telnetd 122 cygwin_shutdown: 0 = shutdown (0, 2)
  644 8533494 [main] in.telnetd 122 do_exit: do_exit (1)
  617 8534111 [main] in.telnetd 122 void: 0x4054E4 = signal (20, 0x1)
  448 8534559 [main] in.telnetd 122 void: 0x0 = signal (1, 0x1)
  443 8535002 [main] in.telnetd 122 void: 0x0 = signal (2, 0x1)
  437 8535439 [main] in.telnetd 122 void: 0x0 = signal (3, 0x1)
  675 8536114 [main] in.telnetd 122 fhandler_socket::close: 0 =
fhandler_socket::close()
  704 8536818 [main] in.telnetd 122 fhandler_socket::close: 0 =
fhandler_socket::close()
  688 8537506 [main] in.telnetd 122 fhandler_socket::close: 0 =
fhandler_socket::close()
  649 8538155 [main] in.telnetd 122 fhandler_tty_common::close: no more
masters left. sending EOF
 1399 8539554 [main] in.telnetd 122 fhandler_tty_common::close: tty2
<0xB8,0xB4> closed
  569 8540123 [main] in.telnetd 122 fhandler_pty_master::close: freeing tty2
(2)
  899 8541022 [main] in.telnetd 122 proc_terminate: nchildren 1, nzombies 0
 1573 8542595 [proc] in.telnetd 122 wait_subproc: looping
  600 8543195 [proc] in.telnetd 122 wait_subproc: done
 1115 8544310 [main] in.telnetd 122 proc_subproc: args: 3, 1
  501 8544811 [main] in.telnetd 122 proc_subproc: clear waiting threads
  444 8545255 [main] in.telnetd 122 proc_subproc: finished clearing
  435 8545690 [main] in.telnetd 122 proc_subproc: returning 1
  460 8546150 [main] in.telnetd 122 proc_terminate: 133(84) closed child
handle
  497 8546647 [main] in.telnetd 122 proc_terminate: leaving
  448 8547095 [main] in.telnetd 122 sigproc_terminate: entering
  430 8547525 [main] in.telnetd 122 sigproc_terminate: done
  889 8548414 [main] in.telnetd 122 __to_clock_t: dwHighDateTime 0,
dwLowDateTime 1902736
  453 8548867 [main] in.telnetd 122 __to_clock_t: total 00000000 000000BE
  461 8549328 [main] in.telnetd 122 __to_clock_t: dwHighDateTime 0,
dwLowDateTime 1301872
  450 8549778 [main] in.telnetd 122 __to_clock_t: total 00000000 00000082
 6784 8556562 [main] in.telnetd 122 _pinfo::exit: Calling ExitProcess 1

After I see this line,

649 8538155 [main] in.telnetd 122 fhandler_tty_common::close: no more
masters left. sending EOF

EOF ? Should be SIGHUP or not.

I am wrong ? Please answer.

--
Unsubscribe info:      http://cygwin.com/ml/#unsubscribe-simple
Bug reporting:         http://cygwin.com/bugs.html
Documentation:         http://cygwin.com/docs.html
FAQ:                   http://cygwin.com/faq/