From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (qmail 41220 invoked by alias); 23 Apr 2017 07:43:08 -0000 Mailing-List: contact cygwin-help@cygwin.com; run by ezmlm Precedence: bulk List-Id: List-Subscribe: List-Archive: List-Post: List-Help: , Sender: cygwin-owner@cygwin.com Mail-Followup-To: cygwin@cygwin.com Received: (qmail 41207 invoked by uid 89); 23 Apr 2017 07:43:06 -0000 Authentication-Results: sourceware.org; auth=none X-Virus-Found: No X-Spam-SWARE-Status: No, score=-0.7 required=5.0 tests=AWL,BAYES_00,KAM_LAZY_DOMAIN_SECURITY autolearn=no version=3.3.2 spammy=duration, H*r:8.12.11, H*F:U*mark, speculation X-HELO: m0.truegem.net Received: from m0.truegem.net (HELO m0.truegem.net) (69.55.228.47) by sourceware.org (qpsmtpd/0.93/v0.84-503-g423c35a) with ESMTP; Sun, 23 Apr 2017 07:43:03 +0000 Received: (from daemon@localhost) by m0.truegem.net (8.12.11/8.12.11) id v3N7h3nx025899 for ; Sun, 23 Apr 2017 00:43:03 -0700 (PDT) (envelope-from mark@maxrnd.com) Received: from 76-217-5-154.lightspeed.irvnca.sbcglobal.net(76.217.5.154), claiming to be "[192.168.1.100]" via SMTP by m0.truegem.net, id smtpdkbpPmw; Sun Apr 23 00:42:52 2017 Subject: Re: long I/O delays when strace is running To: cygwin@cygwin.com References: <91DCAC3CB99C724EB365BB64677FBE7B16EBBD@MX204CL04.corp.emc.com> <46e39bce-9782-5c74-c196-35ee97ebbc64@pobox.com> <58F9D314.2000100@maxrnd.com> <7d56e728-32a3-9179-b002-e83880e297d0@pobox.com> <58FA83DB.3000209@maxrnd.com> From: Mark Geisert Message-ID: <58FC5AFB.3010903@maxrnd.com> Date: Sun, 23 Apr 2017 18:15:00 -0000 User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:43.0) Gecko/20100101 Firefox/43.0 SeaMonkey/2.40 MIME-Version: 1.0 In-Reply-To: Content-Type: text/plain; charset=windows-1252; format=flowed Content-Transfer-Encoding: 7bit X-SW-Source: 2017-04/txt/msg00295.txt.bz2 Daniel Santos wrote: > > On 04/21/2017 05:12 PM, Mark Geisert wrote: >> >> Re debugging strace itself, you may not realize that strace is not a >> Cygwin-native program. It's a Windows-native program. So debugging it with >> Cygwin gdb is problematic. >> >> I can tell you roughly how strace operates. It launches the target program >> with CreateProcess(), not with exec(). It acts as the debugger of the target >> in order to receive Windows DEBUG_EVENTs for things like DLL loads, thread >> creation, etc. etc. The Cygwin DLL in the target can tell when it's being run >> under strace and generates trace lines with OutputDebugString() calls that >> strace receives as DEBUG_EVENTs. strace then just outputs the trace line. >> >> strace does have to explicitly ContinueDebugEvent() on each DEBUG_EVENT it >> receives, and if there's some issue with that then the target program will >> remain suspended awaiting that continue. I've never seen an issue with this >> but it's another possible place to look, I suppose. >> >> Why strace appears to interact badly with /proc accesses, I have no idea. >> >> ..mark > > Well thank you, I wish I had read this earlier. I've been trying to debug (with > gdb) strace (following children) and now I know why the debugger is blowing > through breakpoints, because I may be debugging strace, but strace debugging > it's own child. I added a _pinfo::dump () member function that I'm calling from > pinfo::init () after the test "if (!created && !(flag & PID_NEW))" and it's > crashing because for some processes, the entire _pinfo struct isn't mapped in, > just the first page. Of course, I'm a newbie in this sphere, so maybe I've > missed something and there's sometimes a reason for this? (The first part of > the struct looks normal.) Otherwise, that would be another odd flaw. I don't know enough about pinfo.h and pinfo.cc to say anything definite on this. > Anyway, I can see that the strace process's shared _pinfo object is never fully > populated: > > _pinfo 0x30000 { > pid 2800, > process_state 0x00000001, > ppid 0, > exitcode 0 > cygstarted 0, > dwProcessId 0x00000AF0, > progname "D:\cygwin64\bin\strace.exe", > uid 0, > gid 0, > pgid 0, > sid 0, > ctty 0, > has_pgid_children 0 > start_time 1492881370, > nice 0, > stopsig 0, > sendsig 0x0, > exec_sendsig 0x0, > exec_dwProcessId 0 > } Again, strace.exe is a Windows executable, so perhaps some of those fields don't make sense for a non-Cygwin process and are not initialized? Purely speculation on my part. > So I would venture to say that is a problem. Also, pinfo::init() should > probably issure some error message if it waits 2-ish seconds and the struct > still isn't correctly populated. That seems right. I unfortunately don't know why the code presumes the struct is always populated within a certain (small) amount of time. The complaint comment about minimum possible sleep duration sure makes it seem like it's always supposed to be populated very quickly. > Is there a way to debug the children of strace? It would make it a lot easier. > That's part of why I wrote the _pinfo::debug(), but also when I debug strace > with gdb, the _pinfo struct IS properly populated. The best problems are the > ones that disappear when you try to debug them. strace always acts as the debugger of the target process you start strace with (or attach to; see '-p' in strace's help). strace has a switch '-f' == '--trace-children' that defaults to being ON. So by default strace is getting DEBUG_EVENTs from the target strace launched as well as any process the target creates. If you explicitly set the '-f' flag, you're actually turning OFF that default and *only* the target process sends DEBUG_EVENTs. In that case any process the target creates will be invisible to strace. You could conceivably debug those sub-processes with gdb but you likely won't be able to catch them at their startup unless they wait for your attach. ..mark -- 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