Re: long I/O delays when strace is running

[Daniel Santos <daniel dot santos at pobox dot com>]

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.

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
}

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.

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.

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