DMARC-Filter: OpenDMARC Filter v1.4.2 sourceware.org 54C08385DDDF
Message-ID: <19c300bb-97ff-4dee-be8c-2215b38f0a1c@gmail.com>
Date: Sun, 30 Jun 2024 20:33:19 +0900
MIME-Version: 1.0
User-Agent: Thunderbird Daily
Subject: Re: ssh-add -l hangs under cygwin test 3.6.0-0.139.g...
To: cygwin AT cygwin DOT com
Newsgroups: gmane.os.cygwin
References: <bd97f4a1-0298-4422-8594-40f0989d13ce AT SystematicSW DOT ab DOT ca>
Content-Language: en-US
In-Reply-To: <bd97f4a1-0298-4422-8594-40f0989d13ce@SystematicSW.ab.ca>
Precedence: list
From: jojelino via Cygwin <cygwin AT cygwin DOT com>
Reply-To: jojelino <jojelino AT gmail DOT com>
Content-Transfer-Encoding: 7bit
Content-Type: text/plain; charset="us-ascii"; Format="flowed"
Errors-To: cygwin-bounces+archive-cygwin=delorie DOT com AT cygwin DOT com
Sender: "Cygwin" <cygwin-bounces+archive-cygwin=delorie DOT com AT cygwin DOT com>

On 6/29/2024 2:39 PM, Brian Inglis via Cygwin wrote:
> Reran cygport --debug upload and command hanging was ssh-add -l!
> 
   296   72109 [main] ssh-add 63275 win32env_to_cygenv: 0xA000232E0: 
TERM_PROGRAM=mintty
   189   72298 [main] ssh-add 63275 win32env_to_cygenv: 0xA00023300: 
TERM_PROGRAM_VERSION=3.7.1

I was able to reproduce this problem by entering below command with 
ffmpeg from https://www.gyan.dev/ffmpeg/builds/ , this ffmpeg build 
spams putc. So, without piping its output to `tee', It would not 
possible track down any cause among lengthy trace output.

strace mintty -e /bin/timeout 10 sh -c './ffmpeg -h full|& tee'

In summary, When `timeout' expires, `timeout' signals SIGHUP to pgrp of 
itself, btw some member of the pgrp may have acquired any of 
synchronization object of some part of cygwin internal when a member 
process of the pgrp did encounter the signal interrupt from `timeout'. 
In my case it was output_mutex of pty.

  1565 10693297 [main] timeout 745 kill_pgrp: pid 0, signal 15
  2701 15224348 [main] mintty 744 
fhandler_pty_master::process_slave_output: bytes read 256
  1736 9525442 [sig] sh 746 proc_subproc: args: 4, 1
  3137 6700294 [main] tee 748 fhandler_pty_slave::write: pty5, 
write(0x7FFFFC780, 1024)
  1347 9526789 [sig] sh 746 proc_subproc: clear waiting threads
  2084 15226432 [main] mintty 744 
fhandler_pty_master::process_slave_output: returning 256
  1110 6701404 [main] tee 748 fhandler_pty_slave::write: (1267): pty 
output_mutex (0x4C0): waiti
-1 ms
   732 9527521 [sig] sh 746 checkstate: child_procs count 2
  3648 10696945 [main] timeout 745 open_shared: name cygpid.724, shared 
0x1A0050000 (wanted 0x1A
0000), h 0x16C, m 6, created 0
  1055 6702459 [main] tee 748 fhandler_pty_slave::write: (1267): pty 
output_mutex: acquired

  2092 15753306 [main] mintty 744 fhandler_pty_master::close: (2095): 
pty output_mutex (0x4AC):
ting -1 ms

And below is a location where `tee' did hang.

#3  0x00007ffd0e408fdf in fhandler_pty_slave::write (this=0x800009a10,
     ptr=0x7ffffc780, len=<optimized out>)
     at ../../.././winsup/cygwin/fhandler/pty.cc:1268
1268      if (!process_opost_output (get_output_handle (), ptr, towrite, 
false,
(gdb)  li
1263      termios_printf ("pty%d, write(%p, %lu)", get_minor (), ptr, len);
1264
1265      push_process_state process_state (PID_TTYOU);
1266
1267      acquire_output_mutex (mutex_timeout);
1268      if (!process_opost_output (get_output_handle (), ptr, towrite, 
false,
1269                                 get_ttyp (), is_nonblocking ()))


I ended up prepending two CancelIo call just above of 
acquire_output_mutex located in fhandler_pty_master::close of pty.cc.

 >	  CancelIo(get_ttyp()->to_master());
 >	  CancelIo(get_ttyp()->to_master_nat());
	  acquire_output_mutex (mutex_timeout);

Hope it helps

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