X-Recipient: archive-cygwin AT delorie DOT com
DomainKey-Signature: a=rsa-sha1; c=nofws; d=sourceware.org; h=list-id
	:list-unsubscribe:list-subscribe:list-archive:list-post
	:list-help:sender:subject:to:references:from:message-id:date
	:mime-version:in-reply-to:content-type
	:content-transfer-encoding; q=dns; s=default; b=lzQaRloS3Ekfw6/H
	O9534590kj3ZUadQcNfqZ8XG5k8+1ZyqjD6xijA22Ym9tHRjpaoqNFG5vMz0cAhG
	+i+f4J19VcX1hP20Fp1JOG7UcNx/ZvkNlbruuBE/w5pfuXwXe9KKd4ySXExX9mjo
	9jH3ZxOBo8vC7zpSioasbJ7924w=
DKIM-Signature: v=1; a=rsa-sha1; c=relaxed; d=sourceware.org; h=list-id
	:list-unsubscribe:list-subscribe:list-archive:list-post
	:list-help:sender:subject:to:references:from:message-id:date
	:mime-version:in-reply-to:content-type
	:content-transfer-encoding; s=default; bh=SsMsypMGwjr0yXH+STeDDo
	yDcuc=; b=iOQT1EHWHB4atLMXPPRKVvb2IOAVfn39W1S46XcV1qnskTEoJBHm1N
	8HQsA0OV8cif9CJdtujWsd7yVeQpTG5NeMoMjw98W6tR7uqJh/hfGqoPnPrnFcsF
	AG7Gsc3FIIaqfZWw+Bqwcq6Nc6VuoFtQzU81UE0eBCFq4p+EYmyBQ=
Mailing-List: contact cygwin-help AT cygwin DOT com; run by ezmlm
List-Id: <cygwin.cygwin.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
Authentication-Results: sourceware.org; auth=none
X-Virus-Found: No
X-Spam-SWARE-Status: No, score=-0.3 required=5.0 tests=AWL,BAYES_50,RCVD_IN_DNSWL_LOW,RP_MATCHES_RCVD,SPF_PASS autolearn=ham version=3.3.2 spammy=humble, ended, Geisert, geisert
X-HELO: sasl.smtp.pobox.com
Subject: Re: long I/O delays when strace is running
To: cygwin AT cygwin DOT com
References: <be8713ec-5b68-e0e9-c5a5-d48fce491a2d AT pobox DOT com> <91DCAC3CB99C724EB365BB64677FBE7B16EBBD AT MX204CL04 DOT corp DOT emc DOT com> <46e39bce-9782-5c74-c196-35ee97ebbc64 AT pobox DOT com> <ace81c86-80d5-bef9-6b93-7d36dde5a4e8 AT pobox DOT com> <bff9c5ea-85d9-bf4e-2f25-271c1490565f AT pobox DOT com> <58F9D314 DOT 2000100 AT maxrnd DOT com>
From: Daniel Santos <daniel DOT santos AT pobox DOT com>
Message-ID: <7d56e728-32a3-9179-b002-e83880e297d0@pobox.com>
Date: Fri, 21 Apr 2017 07:13:16 -0500
User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:45.0) Gecko/20100101 Thunderbird/45.5.1
MIME-Version: 1.0
In-Reply-To: <58F9D314.2000100@maxrnd.com>
Content-Type: text/plain; charset=windows-1252; format=flowed
Content-Transfer-Encoding: 7bit
X-Pobox-Relay-ID: 3FF18C5C-268B-11E7-9891-C260AE2156B6-06139138!pb-smtp2.pobox.com
X-IsSubscribed: yes

On 04/21/2017 04:38 AM, Mark Geisert wrote:
>
> I can reproduce your issue on a real Win7.64 machine so that removes 
> any possible virtual machine root cause.  I was running 'top -s1' in 
> one window while running your testcase in another window.  Yes, top 
> froze for many seconds at a time, then caught its display up, only to 
> freeze again repeatedly.  It was still frozen for a while after your 
> testcase had ended (!), then caught up. Your mention of pinfo::init 
> and 'ps' along with my usage of 'top' leads me to think this may be 
> somehow related to the /proc filesystem.
>
> Here's my humble contribution to the discussion:
>
> ~ time w
>  02:15:52 up 3 days, 20:34,  0 users,  load average: 0.99, 0.62, 0.31
> USER     TTY        LOGIN@   IDLE   JCPU   PCPU WHAT
>
> real    0m0.203s    <-- OK, nice and fast
> user    0m0.077s
> sys     0m0.139s
>
> ~ time strace -o w.out w
>  02:16:23 up 3 days, 20:34,  0 users,  load average: 0.54, 0.55, 0.29
> USER     TTY        LOGIN@   IDLE   JCPU   PCPU WHAT
>
> real    0m28.487s   <-- but stracing it is much, much slower
> user    0m0.015s
> sys     0m0.000s
>
> The 'w' command is normally pretty fast.  Running it under strace 
> makes it take an unreasonably long time.  Something seems busted 
> somewhere.  The strace output for this example has many occurrences of 
> ~3.1-second delays that seem to occur as w is accumulating process 
> time information for all processes.
>
> ..mark

Thanks for the help Mark.  My current suspicion is that the _pinfo isn't 
getting initialized when the process is exec-ed by strace, but I haven't 
proved that.  I added a dump() member function to _pinfo, but it crashes 
and I can't seem to debug that in gdb (it makes a stacktrace file 
instead of letting me debug).  So the cygpid.<n> shared object is there, 
but I'm suspecting that it's either all zeros or just not fully 
initialized -- and this is for the pid of the strace process.  So for 
each strace process, there's a 2-3 second delay when trying to read the 
process list.

Daniel


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