X-Recipient:	archive-cygwin AT delorie DOT com
X-SWARE-Spam-Status:	No, hits=-1.5 required=5.0 tests=AWL,BAYES_00,RCVD_IN_DNSWL_NONE,UNPARSEABLE_RELAY
X-Spam-Check-By:	sourceware.org
X-Yahoo-SMTP:	jenXL62swBAWhMTL3wnej93oaS0ClBQOAKs8jbEbx_o-
Date:	Wed, 3 Aug 2011 09:18:29 -0400
From:	Christopher Faylor <cgf-use-the-mailinglist-please AT cygwin DOT com>
To:	cygwin AT cygwin DOT com
Subject:	Re: Commands slow in wait_sig.
Message-ID:	<20110803131828.GA22371@ednor.casa.cgf.cx>
Reply-To:	cygwin AT cygwin DOT com
Mail-Followup-To:	cygwin AT cygwin DOT com
References:	<BLU150-W37E84393708DF1AED6DA6EAB3A0 AT phx DOT gbl>
MIME-Version:	1.0
In-Reply-To:	<BLU150-W37E84393708DF1AED6DA6EAB3A0@phx.gbl>
User-Agent:	Mutt/1.5.20 (2009-06-14)
Mailing-List:	contact cygwin-help AT cygwin DOT com; run by ezmlm
List-Id:	<cygwin.cygwin.com>
List-Unsubscribe:	<mailto:cygwin-unsubscribe-archive-cygwin=delorie DOT com AT cygwin DOT com>
List-Subscribe:	<mailto:cygwin-subscribe AT cygwin DOT com>
List-Archive:	<http://sourceware.org/ml/cygwin/>
List-Post:	<mailto:cygwin AT cygwin DOT com>
List-Help:	<mailto:cygwin-help AT cygwin DOT com>, <http://sourceware.org/ml/#faqs>
Sender:	cygwin-owner AT cygwin DOT com
Mail-Followup-To:	cygwin AT cygwin DOT com
Delivered-To:	mailing list cygwin AT cygwin DOT com

On Wed, Aug 03, 2011 at 04:44:29PM +0900, texas salsa wrote:
>
>Hello there,
>
>I use Cygwin to do some complex text processing jobs using shell scripts on Thinkpad X200s Windows XP sp3. It had worked fine before but at some point I noticed the job started to take much time to complete. It is taking about ten times period compare to before. I don't know what had triggered this exactly.
>
>$ while true ;do /usr/bin/date ;done|uniq -c
>????? 1 Wed Aug? 3 16:21:05???? 2011
>????? 1 Wed Aug? 3 16:21:06???? 2011
>????? 1 Wed Aug? 3 16:21:08???? 2011
>????? 1 Wed Aug? 3 16:21:09???? 2011
>????? 1 Wed Aug? 3 16:21:10???? 2011
>????? 2 Wed Aug? 3 16:21:11???? 2011
>????? 1 Wed Aug? 3 16:21:12???? 2011
>$ time date
>Wed Aug? 3 16:23:19???? 2011
>real??? 0m0.905s
>user??? 0m0.077s
>sys???? 0m0.562s
>
>$ uname -a
>CYGWIN_NT-5.1 IBM-8DE0336DAA4 1.7.9(0.237/5/3) 2011-03-29 10:10 i686 Cygwin
>????? 
>So one command take about 1 sec to complete. On other machines with similar configuration the above testing shows about 10 forks/sec on average.
>
>The following is strace date information
>
>?7070??? 9351 [main] date 1780 _cygtls::remove: wait 0xFFFFFFFF
>?? 76??? 9427 [main] date 1780 _cygtls::remove: removed 0x22CE64 element 0
>?? 64??? 9491 [main] date 1780 _cygtls::remove: wait 0xFFFFFFFF
>?? 34??? 9525 [main] date 1780 _cygtls::remove: removed 0x22CE64 element 0
>? 218??? 9743 [sig] date 1780 wait_sig: entering ReadFile loop, my_readsig 0x764, my_sendsig 0x760
>332702? 342445 [main] date 1780 mount_info::conv_to_posix_path: conv_to_posix_path (C:\cygwin\home\admuser, no-keep-rel, no-add-slash)
>?? 80? 342525 [main] date 1780 normalize_win32_path: C:\cygwin\home\admuser = normalize_win32_path (C:\cygwin\home\admuser)
>? 165? 342690 [main] date 1780 mount_info::conv_to_posix_path: /home/admuser = conv_to_posix_path (C:\cygwin\home\admuser)
>?2047? 344737 [main] date 1780 _cygwin_istext_for_stdio: fd 0: not open
>?
>It looks like that "wait_sig: entering ReadFile loop" taking much time
>in the command processing.  So firstly I supposed "Slow performance
>Win7/64" discussion last month may apply to this.  I tested 2011-08-01
>snapshot and it doubled the performance like 2 forks/sec, but wait_sig
>still taking much time and I suspect there is another problem in the
>code or specific problem in my PC.

Nothing in the above indicates that there is a problem in wait_sig.
The delta times in an strace do not mean "This is how long an operation
took".  They just indicate the number of microseconds since the last
update to strace output.

What the above says is:

1) wait_sig is about to call ReadFile.  It has been 9743 microseconds
since strace last reported anytinng.

2) There was a lag of 342445 microseconds before something happened in
main.  That could be symptomatic of the problem which the 8/01 snapshot
works around.  Or not.

If it is only happening on one system that obviously points to BLODA.

cgf

--
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

- Raw text -