Mailing-List: contact cygwin-help AT cygwin DOT com; run by ezmlm
List-Subscribe: <mailto:cygwin-subscribe AT cygwin DOT com>
List-Archive: <http://sources.redhat.com/ml/cygwin/>
List-Post: <mailto:cygwin AT cygwin DOT com>
List-Help: <mailto:cygwin-help AT cygwin DOT com>, <http://sources.redhat.com/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
Message-Id: <3.0.5.32.20030702071819.0083d500@incoming.verizon.net>
X-Sender: vze1u1tg AT incoming DOT verizon DOT net
Date: Wed, 02 Jul 2003 07:18:19 -0400
To: "Carlo Florendo" <carlo AT astra DOT ph>, <cygwin AT cygwin DOT com>
From: "Pierre A. Humblet" <Pierre DOT Humblet AT ieee DOT org>
Subject: Re: ls.exe slow down in cygwin 1.3.13 
In-Reply-To: <019d01c33ed0$40f343f0$200aa8c0@thorin>
Mime-Version: 1.0
Content-Type: text/plain; charset="us-ascii"

At 02:24 PM 6/30/2003 +0800, Carlo Florendo wrote:

>Last November 2002, I've upgraded cygwin and encountered a variation in
the behaviour of ls.  ls, when invoked as "ls -l" takes a
>bit longer to execute than the previous cygwin version.  (I've attached
the output of cygehck.)  I haven't upgraded cygwin since
>November 2002 last year since I'm content with my installation now.  The
current variation in the behaviour of ls is not really a
>problem but I'd be glad if I could let it behave as it used to.
>

I have asked Carlo to run a special version of ls and then a short
test program to isolate the problem. Here is the main part of the test code

     i = lstat(".", &buf);
     printf("%d\n", i);
     fflush(stdout);
     i = gettimeofday (&timeval, NULL);
     printf("%d\n", i);

and here is a part of strace
  179   46656 [main] a 1472 fstat64: 0 = fstat (1, 0x22E8A8)
  242   46898 [main] a 1472 writev: writev (1, 0x22FDE8, 1)
  116   47014 [main] a 1472 fhandler_base::write: binary write
0
  118   47132 [main] a 1472 fhandler_base::write: 2 = write (0xA042998, 2)
  102   47234 [main] a 1472 writev: 2 = write (1, 0x22FDE8, 1), errno 0
1981327 2028561 [main] a 1472 writev: writev (1, 0x22FE18, 1)
  220 2028781 [main] a 1472 fhandler_base::write: binary write
0
  132 2028913 [main] a 1472 fhandler_base::write: 2 = write (0xA042998, 2)
  108 2029021 [main] a 1472 writev: 2 = write (1, 0x22FE18, 1), errno 0 

It shows that there is a 2 s delay in gettimeofday. My hunch is that it
occurs in times.cc, in the part of hires_ms::prime () that raises then 
lowers the thread priority.
Windows has a tendency to penalize threads that just "enjoyed a good time",
compared to their current priority. Why it occurs on Carlo's system, 
I don't know.

The reason for the changes of priority is to try to insure that there is 
little delay between the calls to timeGetTime and to 
GetSystemTimeAsFileTime. Increasing the priority helps but does not make 
guarantees. Perhaps a better way would be something like

timeGetTime(& start);
for (i = 0; i < "whatever"; i++) {
  GetSystemTimeAsFileTime(&f);
  timeGetTime(& end);
  if (end - start <= "1 ms") break;
  start = end;
}
i.e. repeat the calls until they all occur very close together.

One can also add bells and whistles, for example always letting i run to
"whatever", recording the various times, and using the results from the
fastest trip through the loop.

Another possibility is to do a robust initialization only when starting 
cygwin and record the values in the cygheap for use by future processes.
This would also prevent an (unlikely) race between several threads running
hires_Xs::prime simultaneously.  

Pierre


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