Re: [DynInst_API:] Hung process


Date: Wed, 18 Feb 2015 14:17:06 -0600
From: Bill Williams <bill@xxxxxxxxxxx>
Subject: Re: [DynInst_API:] Hung process
On 02/18/2015 01:54 PM, Josh Stone wrote:
On 02/18/2015 11:42 AM, Bill Williams wrote:
On 02/18/2015 01:37 PM, Gerard wrote:
Ah ok, I didn't know that.

About how reproducible is the error, I run it three times (without the
change you suggested) and every time stopped at around 32000 threads.
Now I added appProc->continueExecution() and it happened again after
creating 32322 threads, so it seems this is not the problem.

Then it's got to be that somewhere in here, we're messing up internal
stop/continue state without that propagating out to the user level.
Debug logs will tell me something eventually...sadly, they're verbose
and time-consuming.

Which kernel version/distribution are you using, by the way?

TIDs usually wrap at 2^15, so they'll be reused in this test.
Perhaps this is confusing dyninst somewhere?

That's certainly a possibility; we're hitting our starvation case (theoretically running process generates no ptrace events) when the TID and PID once again are the same, which I would expect guarantees that we've recycled a LWPID.

I've attached the tag end of a log that should reflect Gerard's problem; there's postponed syscall handling going on, but by initial mark 1 eyeball nothing's obviously broken (aside from the results)...

--
--bw

Bill Williams
Paradyn Project
bill@xxxxxxxxxxx
[linux.C:140-G] - blocking in waitpid
[process.C:1043-H] - Returning after handling events
[linux.C:161-G] - Waitpid return status 1407 for pid 29642:
[process.C:1131-H] - Leaving WaitAndHandleEvents with return true, 'cause we're done
[linux.C:167-G] - Stopped with signal 5
[process.C:8389-H] - Handler starting to check for events
[generator.C:209-G] - Got event
[process.C:8397-H] - Events already handled, going back to sleep
[generator.C:144-G] - Setting generator state to decoding
[linux.C:294-G] - Decoding event for 29628/29642
[linux.C:301-G] - Decoded to signal 5
[process.C:6111-U] - User triggered event handling
[process.C:973-U] - Top of waitAndHandleEvents.  Block = true
[process.C:1024-U] - Blocking for events = !F && ((T && !F && T) || ? || ? || ? || ? || ? || ? || ? || ?)
[mailbox.C:155-U] - Blocking for events from mailbox, queue size = 0
[linux.C:2184-G] - Register x86_64::rip has value 0x3b26a07c5f
[irpc.C:930-G] - 29628/29642 is not running any iRPCs, trap is not RPC completion
[linux.C:483-G] - Decoded event to breakpoint restore
[generator.C:144-G] - Setting generator state to statesync
[process.C:2294-G] - Event BreakpointRestore is thread synchronous, marking thread 29642 generator stopped
[process.C:8145-G] - Adjusting counter GeneratorRunningThreads by -1, before 1, after 0
[process.C:4392-G] - Changing generator state for 29628/29642 from running to stopped
[generator.C:144-G] - Setting generator state to queueing
[mailbox.C:120-G] - Added event BreakpointRestore to mailbox, size = 1 + 0 + 0 = 1
[generator.C:144-G] - Setting generator state to none
[mailbox.C:171-U] - Returning event BreakpointRestore from mailbox
[generator.C:144-G] - Setting generator state to process_blocked
[process.C:2294-U] - Event BreakpointRestore is thread synchronous, marking thread 29642 handler stopped
[generator.C:429-G] - Checking for live processes
[generator.C:278-G] - Entry to generator::hasLiveProc()
[generator.C:308-G] - No live processes, ret false
[generator.C:431-G] - Checked and found no live processes
[process.C:8145-U] - Adjusting counter HandlerRunningThreads by -1, before 1, after 0
[process.C:4392-U] - Changing handler state for 29628/29642 from running to stopped
[handler.C:402-U] - Event BreakpointRestore added to handle list with handler Breakpoint Restore
[handler.C:419-U] - Have event BreakpointRestore on Breakpoint Restore
[handler.C:437-U] - Handling event 'BreakpointRestore' with handler 'Breakpoint Restore'
[handler.C:1648-U] - Restoring breakpoint at 3b26a05dd0 for 29628/29642
[process.C:4106-U] - 29628/29642 marking clearing bp (nil) (at 0x0)
[process.C:8145-U] - Adjusting counter ClearingBPs by -1, before 1, after 0
[process.C:4392-U] - Changing breakpoint resume state for 29628/29642 from running to stopped
[handler.C:1656-U] - Restoring breakpoint to process
[process.C:1545-U] - Writing to remote memory 3b26a05dd0 from 0x7fff53b14530, size = 1 on 29628/29628
[handler.C:1678-U] - Restoring thread state after breakpoint restore
[process.C:4295-U] - Restoring 29628/29628 breakpoint resume state to level 0
[process.C:4392-U] - Changing breakpoint resume state for 29628/29628 from stopped to dontcare
[process.C:4295-U] - Restoring 29628/29642 breakpoint resume state to level 0
[process.C:4392-U] - Changing breakpoint resume state for 29628/29642 from stopped to dontcare
[process.C:798-U] - At top of syncRunState for 29628
[process.C:3271-U] - 29628/29628: setting target state to Running
[process.C:3271-U] - 29628/29642: setting target state to Running
[process.C:3496-U] - Checking thread 29628/29628 for events thrown before continue
[process.C:3496-U] - Checking thread 29628/29642 for events thrown before continue
[process.C:835-U] - Checking if any ProcStop events on 29628 are ready
[process.C:3271-U] - 29628/29628: setting target state to Running
[process.C:3271-U] - 29628/29642: setting target state to Running
[process.C:847-U] - Current Threading State for 29628:
[process.C:863-U] - 29628/29628 hand: stopped, gen: stopped, user: running, code: ----------------RSS
[process.C:863-U] - 29628/29642 hand: stopped, gen: stopped, user: running, code: ----------------RSS
[process.C:872-U] - Running plat_syncRunState on 29628
[process.C:2931-U] - intCont on thread 29628/29628
[linux.C:1256-U] - Continuing thread 29628
[linux.C:1316-U] - Calling PTRACE_CONT on 29628 with signal 0
[process.C:8145-U] - Adjusting counter HandlerRunningThreads by 1, before 0, after 1
[process.C:4392-U] - Changing handler state for 29628/29628 from stopped to running
[process.C:8145-U] - Adjusting counter GeneratorRunningThreads by 1, before 0, after 1
[process.C:4392-U] - Changing generator state for 29628/29628 from stopped to running
[process.C:5811-U] - Clearing register pool for 29628/29628
[memcache.C:573-U] - Clearing memCache
[process.C:2931-U] - intCont on thread 29628/29642
[generator.C:278-G] - Entry to generator::hasLiveProc()
[generator.C:288-G] - Generator has running threads, returning true from hasLiveProc
[generator.C:442-G] - processWait returning true
[linux.C:1256-U] - Continuing thread 29642
[generator.C:144-G] - Setting generator state to system_blocked
[linux.C:1316-U] - Calling PTRACE_CONT on 29642 with signal 0
[generator.C:207-G] - About to getEvent()
[linux.C:140-G] - blocking in waitpid
[process.C:8145-U] - Adjusting counter HandlerRunningThreads by 1, before 1, after 2
[process.C:4392-U] - Changing handler state for 29628/29642 from stopped to running
[linux.C:161-G] - Waitpid return status 394623 for pid 29642:
[process.C:8145-U] - Adjusting counter GeneratorRunningThreads by 1, before 1, after 2
[linux.C:167-G] - Stopped with signal 5
[process.C:4392-U] - Changing generator state for 29628/29642 from stopped to running
[generator.C:209-G] - Got event
[process.C:5811-U] - Clearing register pool for 29628/29642
[generator.C:144-G] - Setting generator state to decoding
[memcache.C:573-U] - Clearing memCache
[process.C:1024-U] - Polling for events = !F && ((T && !T && ?) || F || F || F || F || F || F || F || F)
[linux.C:294-G] - Decoding event for 29628/29642
[mailbox.C:149-U] - Polled mailbox for messages, but none found
[linux.C:301-G] - Decoded to signal 5
[process.C:1043-U] - Returning after handling events
[linux.C:393-G] - Decoded event to pre-exit on 29628/29642
[process.C:1131-U] - Leaving WaitAndHandleEvents with return true, 'cause we're done
[generator.C:144-G] - Setting generator state to statesync
[process.C:6111-U] - User triggered event handling
[process.C:973-U] - Top of waitAndHandleEvents.  Block = true
[process.C:2294-G] - Event pre-LWPDestroy is thread synchronous, marking thread 29642 generator stopped
[process.C:1024-U] - Blocking for events = !F && ((T && !F && T) || ? || ? || ? || ? || ? || ? || ? || ?)
[process.C:8145-G] - Adjusting counter GeneratorRunningThreads by -1, before 2, after 1
[mailbox.C:155-U] - Blocking for events from mailbox, queue size = 0
[process.C:4392-G] - Changing generator state for 29628/29642 from running to stopped
[generator.C:144-G] - Setting generator state to queueing
[mailbox.C:120-G] - Added event pre-LWPDestroy to mailbox, size = 1 + 0 + 0 = 1
[generator.C:144-G] - Setting generator state to none
[generator.C:144-G] - Setting generator state to process_blocked
[generator.C:429-G] - Checking for live processes
[generator.C:278-G] - Entry to generator::hasLiveProc()
[generator.C:288-G] - Generator has running threads, returning true from hasLiveProc
[mailbox.C:171-U] - Returning event pre-LWPDestroy from mailbox
[generator.C:442-G] - processWait returning true
[process.C:2294-U] - Event pre-LWPDestroy is thread synchronous, marking thread 29642 handler stopped
[generator.C:144-G] - Setting generator state to system_blocked
[process.C:8145-U] - Adjusting counter HandlerRunningThreads by -1, before 2, after 1
[generator.C:207-G] - About to getEvent()
[process.C:4392-U] - Changing handler state for 29628/29642 from running to stopped
[linux.C:140-G] - blocking in waitpid
[handler.C:402-U] - Event pre-LWPDestroy added to handle list with handler Thread Destroy
[handler.C:402-U] - Event pre-LWPDestroy added to handle list with handler Callback
[handler.C:402-U] - Event pre-LWPDestroy added to handle list with handler Thread Cleanup
[handler.C:419-U] - Have event pre-LWPDestroy on Thread Destroy
[handler.C:419-U] - Have event pre-LWPDestroy on Callback
[handler.C:419-U] - Have event pre-LWPDestroy on Thread Cleanup
[handler.C:437-U] - Handling event 'pre-LWPDestroy' with handler 'Thread Destroy'
[handler.C:983-U] - Handling pre-thread destroy for 29642
[handler.C:437-U] - Handling event 'pre-LWPDestroy' with handler 'Callback'
[handler.C:2250-U] - Changing callback state of 29628 before CB
[process.C:4270-U] - Desyncing 29628/29628 callback state to level 1
[process.C:4392-U] - Changing callback state for 29628/29628 from dontcare to ditto
[process.C:4270-U] - Desyncing 29628/29642 callback state to level 1
[process.C:4392-U] - Changing callback state for 29628/29642 from dontcare to ditto
[process.C:4392-U] - Changing user state for 29628/29642 from running to stopped
[handler.C:2273-U] - Triggering callback for event 'pre-LWPDestroy'
[handler.C:2278-U] - Triggering callback #0 for event 'pre-LWPDestroy'
[handler.C:2289-U] - Callback #0 return cbThreadStop/cbDefault
[process.C:4392-U] - Changing user state for 29628/29642 from stopped to running
[handler.C:2307-U] - Handling return value for main process
[handler.C:2213-U] - Callbacks returned thread stop
[process.C:4392-U] - Changing user state for 29628/29642 from running to stopped
[handler.C:2312-U] - Handling return value for child process/thread
[handler.C:2332-U] - Restoring callback state of 29628/29642 after CB
[process.C:4295-U] - Restoring 29628/29628 callback state to level 0
[process.C:4392-U] - Changing callback state for 29628/29628 from ditto to dontcare
[process.C:4295-U] - Restoring 29628/29642 callback state to level 0
[process.C:4392-U] - Changing callback state for 29628/29642 from ditto to dontcare
[handler.C:437-U] - Handling event 'pre-LWPDestroy' with handler 'Thread Cleanup'
[handler.C:1053-U] - Nothing to do in HandleThreadCleanup
[process.C:798-U] - At top of syncRunState for 29628
[process.C:3271-U] - 29628/29628: setting target state to Running
[process.C:3271-U] - 29628/29642: setting target state to Stopped
[process.C:3496-U] - Checking thread 29628/29628 for events thrown before continue
[process.C:835-U] - Checking if any ProcStop events on 29628 are ready
[process.C:3271-U] - 29628/29628: setting target state to Running
[process.C:3271-U] - 29628/29642: setting target state to Stopped
[process.C:847-U] - Current Threading State for 29628:
[process.C:863-U] - 29628/29628 hand: running, gen: running, user: running, code: ----------------RRR
[process.C:863-U] - 29628/29642 hand: stopped, gen: stopped, user: stopped, code: ----------------SSS
[process.C:872-U] - Running plat_syncRunState on 29628
[process.C:1024-U] - Polling for events = !F && ((T && !T && ?) || F || F || F || F || F || F || F || F)
[mailbox.C:149-U] - Polled mailbox for messages, but none found
[process.C:1043-U] - Returning after handling events
[process.C:1131-U] - Leaving WaitAndHandleEvents with return true, 'cause we're done
[procset.C:1486-U] - User stopping entire process 29628
[process.C:4392-U] - Changing user state for 29628/29628 from running to stopped
[process.C:4328-U] - Leaving user state for 29628/29642 in state stopped
[mailbox.C:120-U] - Added event Nop to mailbox, size = 1 + 0 + 0 = 1
[process.C:973-U] - Top of waitAndHandleEvents.  Block = false
[process.C:1024-U] - Polling for events = !F && ((F && !? && ?) || F || F || F || F || F || F || F || F)
[mailbox.C:171-U] - Returning event Nop from mailbox
[handler.C:402-U] - Event Nop added to handle list with handler Nop Handler
[handler.C:419-U] - Have event Nop on Nop Handler
[handler.C:437-U] - Handling event 'Nop' with handler 'Nop Handler'
[process.C:798-U] - At top of syncRunState for 29628
[process.C:3271-U] - 29628/29628: setting target state to Stopped
[process.C:3271-U] - 29628/29642: setting target state to Stopped
[process.C:835-U] - Checking if any ProcStop events on 29628 are ready
[process.C:3271-U] - 29628/29628: setting target state to Stopped
[process.C:3271-U] - 29628/29642: setting target state to Stopped
[process.C:847-U] - Current Threading State for 29628:
[process.C:863-U] - 29628/29628 hand: running, gen: running, user: stopped, code: ----------------SRR
[process.C:863-U] - 29628/29642 hand: stopped, gen: stopped, user: stopped, code: ----------------SSS
[process.C:872-U] - Running plat_syncRunState on 29628
[process.C:2897-U] - intStop on thread 29628/29628
[process.C:3093-U] - Setting pending stop to true, thread 29628/29628
[process.C:8145-U] - Adjusting counter PendingStops by 1, before 0, after 1
[process.C:4270-U] - Desyncing 29628/29628 pending stop state to level 1
[process.C:4392-U] - Changing pending stop state for 29628/29628 from dontcare to running
[process.C:3112-U] - 	 Pending stop level is 1
[linux.C:1382-U] - Sending 19 to 29628
[process.C:1024-U] - Blocking for events = !F && ((F && !? && ?) || F || T || ? || ? || ? || ? || ? || ?)
[linux.C:161-G] - Waitpid return status 4991 for pid 29628:
[linux.C:167-G] - Stopped with signal 19
[mailbox.C:155-U] - Blocking for events from mailbox, queue size = 0
[generator.C:209-G] - Got event
[generator.C:144-G] - Setting generator state to decoding
[linux.C:294-G] - Decoding event for 29628/29628
[linux.C:301-G] - Decoded to signal 19
[linux.C:358-G] - Recieved pending SIGSTOP on 29628/29628
[generator.C:144-G] - Setting generator state to statesync
[process.C:2294-G] - Event Stop is thread synchronous, marking thread 29628 generator stopped
[process.C:8145-G] - Adjusting counter GeneratorRunningThreads by -1, before 1, after 0
[process.C:4392-G] - Changing generator state for 29628/29628 from running to stopped
[generator.C:144-G] - Setting generator state to queueing
[mailbox.C:120-G] - Added event Stop to mailbox, size = 1 + 0 + 0 = 1
[generator.C:144-G] - Setting generator state to none
[mailbox.C:171-U] - Returning event Stop from mailbox
[generator.C:144-G] - Setting generator state to process_blocked
[process.C:2294-U] - Event Stop is thread synchronous, marking thread 29628 handler stopped
[generator.C:429-G] - Checking for live processes
[process.C:8145-U] - Adjusting counter HandlerRunningThreads by -1, before 1, after 0
[generator.C:278-G] - Entry to generator::hasLiveProc()
[process.C:4392-U] - Changing handler state for 29628/29628 from running to stopped
[generator.C:308-G] - No live processes, ret false
[handler.C:402-U] - Event Stop added to handle list with handler Thread Stop
[generator.C:431-G] - Checked and found no live processes
[handler.C:402-U] - Event Stop added to handle list with handler Callback
[handler.C:419-U] - Have event Stop on Thread Stop
[handler.C:419-U] - Have event Stop on Callback
[handler.C:437-U] - Handling event 'Stop' with handler 'Thread Stop'
[handler.C:1119-U] - Handling thread stop for 29628/29628
[process.C:3093-U] - Setting pending stop to false, thread 29628/29628
[process.C:4295-U] - Restoring 29628/29628 pending stop state to level 0
[process.C:4392-U] - Changing pending stop state for 29628/29628 from running to dontcare
[process.C:8145-U] - Adjusting counter PendingStops by -1, before 1, after 0
[process.C:3112-U] - 	 Pending stop level is 0
[handler.C:437-U] - Handling event 'Stop' with handler 'Callback'
[handler.C:2128-U] - No callback registered for event type 'Stop'
[process.C:798-U] - At top of syncRunState for 29628
[process.C:3271-U] - 29628/29628: setting target state to Stopped
[process.C:3271-U] - 29628/29642: setting target state to Stopped
[process.C:835-U] - Checking if any ProcStop events on 29628 are ready
[process.C:3271-U] - 29628/29628: setting target state to Stopped
[process.C:3271-U] - 29628/29642: setting target state to Stopped
[process.C:847-U] - Current Threading State for 29628:
[process.C:863-U] - 29628/29628 hand: stopped, gen: stopped, user: stopped, code: ----------------SSS
[process.C:863-U] - 29628/29642 hand: stopped, gen: stopped, user: stopped, code: ----------------SSS
[process.C:872-U] - Running plat_syncRunState on 29628
[process.C:1024-U] - Polling for events = !F && ((F && !? && ?) || F || F || F || F || F || F || F || F)
[mailbox.C:149-U] - Polled mailbox for messages, but none found
[process.C:1043-U] - Returning after handling events
[process.C:1131-U] - Leaving WaitAndHandleEvents with return true, 'cause we're done
[procset.C:1464-U] - User continuing entire process 29628
[process.C:4392-U] - Changing user state for 29628/29628 from stopped to running
[process.C:4392-U] - Changing user state for 29628/29642 from stopped to running
[mailbox.C:120-U] - Added event Nop to mailbox, size = 1 + 0 + 0 = 1
[process.C:6111-U] - User triggered event handling
[process.C:973-U] - Top of waitAndHandleEvents.  Block = true
[process.C:1024-U] - Polling for events = !F && ((T && !F && F) || F || F || F || F || F || F || F || F)
[mailbox.C:171-U] - Returning event Nop from mailbox
[handler.C:402-U] - Event Nop added to handle list with handler Nop Handler
[handler.C:419-U] - Have event Nop on Nop Handler
[handler.C:437-U] - Handling event 'Nop' with handler 'Nop Handler'
[process.C:798-U] - At top of syncRunState for 29628
[process.C:3271-U] - 29628/29628: setting target state to Running
[process.C:3271-U] - 29628/29642: setting target state to Running
[process.C:3496-U] - Checking thread 29628/29628 for events thrown before continue
[process.C:3496-U] - Checking thread 29628/29642 for events thrown before continue
[process.C:835-U] - Checking if any ProcStop events on 29628 are ready
[process.C:3271-U] - 29628/29628: setting target state to Running
[process.C:3271-U] - 29628/29642: setting target state to Running
[process.C:847-U] - Current Threading State for 29628:
[process.C:863-U] - 29628/29628 hand: stopped, gen: stopped, user: running, code: ----------------RSS
[process.C:863-U] - 29628/29642 hand: stopped, gen: stopped, user: running, code: ----------------RSS
[process.C:872-U] - Running plat_syncRunState on 29628
[process.C:2931-U] - intCont on thread 29628/29628
[linux.C:1256-U] - Continuing thread 29628
[linux.C:1316-U] - Calling PTRACE_CONT on 29628 with signal 0
[process.C:8145-U] - Adjusting counter HandlerRunningThreads by 1, before 0, after 1
[process.C:4392-U] - Changing handler state for 29628/29628 from stopped to running
[process.C:8145-U] - Adjusting counter GeneratorRunningThreads by 1, before 0, after 1
[process.C:4392-U] - Changing generator state for 29628/29628 from stopped to running
[process.C:5811-U] - Clearing register pool for 29628/29628
[memcache.C:573-U] - Clearing memCache
[process.C:2931-U] - intCont on thread 29628/29642
[linux.C:1256-U] - Continuing thread 29642
[linux.C:1316-U] - Calling PTRACE_CONT on 29642 with signal 0
[process.C:8145-U] - Adjusting counter HandlerRunningThreads by 1, before 1, after 2
[process.C:4392-U] - Changing handler state for 29628/29642 from stopped to running
[process.C:8145-U] - Adjusting counter GeneratorRunningThreads by 1, before 1, after 2
[process.C:4392-U] - Changing generator state for 29628/29642 from stopped to running
[process.C:5811-U] - Clearing register pool for 29628/29642
[memcache.C:573-U] - Clearing memCache
[process.C:1024-U] - Polling for events = !F && ((T && !T && ?) || F || F || F || F || F || F || F || F)
[generator.C:278-G] - Entry to generator::hasLiveProc()
[mailbox.C:149-U] - Polled mailbox for messages, but none found
[generator.C:288-G] - Generator has running threads, returning true from hasLiveProc
[process.C:1043-U] - Returning after handling events
[generator.C:442-G] - processWait returning true
[process.C:1131-U] - Leaving WaitAndHandleEvents with return true, 'cause we're done
[generator.C:144-G] - Setting generator state to system_blocked
[process.C:6111-U] - User triggered event handling
[generator.C:207-G] - About to getEvent()
[process.C:973-U] - Top of waitAndHandleEvents.  Block = true
[linux.C:140-G] - blocking in waitpid
[process.C:1024-U] - Blocking for events = !F && ((T && !F && T) || ? || ? || ? || ? || ? || ? || ? || ?)
[linux.C:161-G] - Waitpid return status 4991 for pid 29643:
[mailbox.C:155-U] - Blocking for events from mailbox, queue size = 0
[linux.C:167-G] - Stopped with signal 19
[generator.C:209-G] - Got event
[generator.C:144-G] - Setting generator state to decoding
[generator.C:144-G] - Setting generator state to statesync
[generator.C:144-G] - Setting generator state to queueing
[generator.C:144-G] - Setting generator state to none
[generator.C:144-G] - Setting generator state to process_blocked
[generator.C:429-G] - Checking for live processes
[generator.C:278-G] - Entry to generator::hasLiveProc()
[generator.C:288-G] - Generator has running threads, returning true from hasLiveProc
[generator.C:442-G] - processWait returning true
[generator.C:144-G] - Setting generator state to system_blocked
[generator.C:207-G] - About to getEvent()
[linux.C:140-G] - blocking in waitpid
[linux.C:161-G] - Waitpid return status 0 for pid 29642:
[linux.C:163-G] - Exited with 0
[generator.C:209-G] - Got event
[generator.C:144-G] - Setting generator state to decoding
[linux.C:294-G] - Decoding event for 29628/29642
[linux.C:617-G] - Decoded exit of thread 29628/29642 with code 0
[process.C:8145-G] - Adjusting counter GeneratorRunningThreads by -1, before 2, after 1
[process.C:8145-G] - Adjusting counter GeneratorNonExitedThreads by -1, before 2, after 1
[process.C:4392-G] - Changing generator state for 29628/29642 from running to exited
[generator.C:144-G] - Setting generator state to statesync
[generator.C:144-G] - Setting generator state to queueing
[mailbox.C:120-G] - Added event post-LWPDestroy to mailbox, size = 1 + 0 + 0 = 1
[generator.C:144-G] - Setting generator state to none
[mailbox.C:171-U] - Returning event post-LWPDestroy from mailbox
[generator.C:144-G] - Setting generator state to process_blocked
[handler.C:402-U] - Event post-LWPDestroy added to handle list with handler Thread Destroy
[generator.C:429-G] - Checking for live processes
[handler.C:402-U] - Event post-LWPDestroy added to handle list with handler Callback
[generator.C:278-G] - Entry to generator::hasLiveProc()
[handler.C:402-U] - Event post-LWPDestroy added to handle list with handler Thread Cleanup
[generator.C:288-G] - Generator has running threads, returning true from hasLiveProc
[handler.C:419-U] - Have event post-LWPDestroy on Thread Destroy
[generator.C:442-G] - processWait returning true
[handler.C:419-U] - Have event post-LWPDestroy on Callback
[generator.C:144-G] - Setting generator state to system_blocked
[handler.C:419-U] - Have event post-LWPDestroy on Thread Cleanup
[generator.C:207-G] - About to getEvent()
[handler.C:437-U] - Handling event 'post-LWPDestroy' with handler 'Thread Destroy'
[linux.C:140-G] - blocking in waitpid
[handler.C:997-U] - Handling post-thread destroy for 29628/29642
[linux.C:161-G] - Waitpid return status 198015 for pid 29628:
[linux.C:167-G] - Stopped with signal 5
[generator.C:209-G] - Got event
[generator.C:144-G] - Setting generator state to decoding
[linux.C:294-G] - Decoding event for 29628/29628
[linux.C:301-G] - Decoded to signal 5
[linux.C:426-G] - Decoded event to clone on 29628/29628
[handler.C:437-U] - Handling event 'post-LWPDestroy' with handler 'Callback'
[handler.C:2250-U] - Changing callback state of 29628 before CB
[process.C:4270-U] - Desyncing 29628/29628 callback state to level 1
[process.C:4392-U] - Changing callback state for 29628/29628 from dontcare to ditto
[process.C:4270-U] - Desyncing 29628/29642 callback state to level 1
[process.C:4392-U] - Changing callback state for 29628/29642 from dontcare to ditto
[handler.C:2273-U] - Triggering callback for event 'post-LWPDestroy'
[handler.C:2278-U] - Triggering callback #0 for event 'post-LWPDestroy'
[handler.C:2289-U] - Callback #0 return cbThreadStop/cbDefault
[handler.C:2307-U] - Handling return value for main process
[linux.C:452-G] - Postponing event until syscall exit on 29628/29628
[handler.C:2213-U] - Callbacks returned thread stop
[generator.C:144-G] - Setting generator state to statesync
[process.C:4392-U] - Changing user state for 29628/29642 from running to stopped
[process.C:2294-G] - Event PostponedSyscall is thread synchronous, marking thread 29628 generator stopped
[handler.C:2312-U] - Handling return value for child process/thread
[process.C:8145-G] - Adjusting counter GeneratorRunningThreads by -1, before 1, after 0
[handler.C:2332-U] - Restoring callback state of 29628/29642 after CB
[process.C:4392-G] - Changing generator state for 29628/29628 from running to stopped
[process.C:4295-U] - Restoring 29628/29628 callback state to level 0
[generator.C:144-G] - Setting generator state to queueing
[process.C:4392-U] - Changing callback state for 29628/29628 from ditto to dontcare
[mailbox.C:120-G] - Added event PostponedSyscall to mailbox, size = 1 + 0 + 0 = 1
[process.C:4295-U] - Restoring 29628/29642 callback state to level 0
[generator.C:144-G] - Setting generator state to none
[process.C:4392-U] - Changing callback state for 29628/29642 from ditto to dontcare
[generator.C:144-G] - Setting generator state to process_blocked
[handler.C:437-U] - Handling event 'post-LWPDestroy' with handler 'Thread Cleanup'
[generator.C:429-G] - Checking for live processes
[handler.C:1068-U] - Cleaning thread 29628/29642 from HandleThreadCleanup handler.
[generator.C:278-G] - Entry to generator::hasLiveProc()
[generator.C:308-G] - No live processes, ret false
[generator.C:431-G] - Checked and found no live processes
[process.C:4392-U] - Changing user state for 29628/29642 from stopped to exited
[process.C:4392-U] - Changing exiting state for 29628/29642 from dontcare to exited
[process.C:8145-U] - Adjusting counter HandlerRunningThreads by -1, before 2, after 1
[generator.C:278-G] - Entry to generator::hasLiveProc()
[generator.C:308-G] - No live processes, ret false
[generator.C:431-G] - Checked and found no live processes
[process.C:798-U] - At top of syncRunState for 29628
[process.C:3271-U] - 29628/29628: setting target state to Running
[process.C:3496-U] - Checking thread 29628/29628 for events thrown before continue
[process.C:835-U] - Checking if any ProcStop events on 29628 are ready
[process.C:3271-U] - 29628/29628: setting target state to Running
[process.C:847-U] - Current Threading State for 29628:
[process.C:863-U] - 29628/29628 hand: running, gen: stopped, user: running, code: ----------------RRS
[process.C:872-U] - Running plat_syncRunState on 29628
[process.C:1024-U] - Polling for events = !F && ((T && !T && ?) || F || F || F || F || F || F || F || F)
[mailbox.C:171-U] - Returning event PostponedSyscall from mailbox
[process.C:2294-U] - Event PostponedSyscall is thread synchronous, marking thread 29628 handler stopped
[process.C:8145-U] - Adjusting counter HandlerRunningThreads by -1, before 1, after 0
[process.C:4392-U] - Changing handler state for 29628/29628 from running to stopped
[handler.C:402-U] - Event PostponedSyscall added to handle list with handler Postponed Syscall
[handler.C:419-U] - Have event PostponedSyscall on Postponed Syscall
[handler.C:437-U] - Handling event 'PostponedSyscall' with handler 'Postponed Syscall'
[process.C:4270-U] - Desyncing 29628/29628 postponed syscall state to level 1
[process.C:4392-U] - Changing postponed syscall state for 29628/29628 from dontcare to running
[process.C:798-U] - At top of syncRunState for 29628
[process.C:3271-U] - 29628/29628: setting target state to Running
[process.C:3496-U] - Checking thread 29628/29628 for events thrown before continue
[process.C:835-U] - Checking if any ProcStop events on 29628 are ready
[process.C:3271-U] - 29628/29628: setting target state to Running
[process.C:847-U] - Current Threading State for 29628:
[process.C:863-U] - 29628/29628 hand: stopped, gen: stopped, postponed syscall: running, code: --R-------------RSS
[process.C:872-U] - Running plat_syncRunState on 29628
[process.C:2931-U] - intCont on thread 29628/29628
[linux.C:1256-U] - Continuing thread 29628
[linux.C:1301-U] - Calling PTRACE_SYSCALL on 29628 with signal 0
[process.C:8145-U] - Adjusting counter HandlerRunningThreads by 1, before 0, after 1
[process.C:4392-U] - Changing handler state for 29628/29628 from stopped to running
[process.C:8145-U] - Adjusting counter GeneratorRunningThreads by 1, before 0, after 1
[process.C:4392-U] - Changing generator state for 29628/29628 from stopped to running
[process.C:5811-U] - Clearing register pool for 29628/29628
[memcache.C:573-U] - Clearing memCache
[generator.C:278-G] - Entry to generator::hasLiveProc()
[generator.C:288-G] - Generator has running threads, returning true from hasLiveProc
[process.C:1024-U] - Polling for events = !F && ((T && !T && ?) || F || F || F || F || F || F || F || F)
[generator.C:442-G] - processWait returning true
[mailbox.C:149-U] - Polled mailbox for messages, but none found
[generator.C:144-G] - Setting generator state to system_blocked
[generator.C:207-G] - About to getEvent()
[process.C:1043-U] - Returning after handling events
[linux.C:140-G] - blocking in waitpid
[process.C:1131-U] - Leaving WaitAndHandleEvents with return true, 'cause we're done
[linux.C:161-G] - Waitpid return status 34175 for pid 29628:
[procset.C:1486-U] - User stopping entire process 29628
[linux.C:167-G] - Stopped with signal 133
[process.C:4392-U] - Changing user state for 29628/29628 from running to stopped
[generator.C:209-G] - Got event
[mailbox.C:120-U] - Added event Nop to mailbox, size = 1 + 0 + 0 = 1
[generator.C:144-G] - Setting generator state to decoding
[process.C:973-U] - Top of waitAndHandleEvents.  Block = false
[linux.C:294-G] - Decoding event for 29628/29628
[process.C:1024-U] - Polling for events = !F && ((F && !? && ?) || F || F || F || F || F || F || F || F)
[linux.C:301-G] - Decoded to signal 133
[mailbox.C:171-U] - Returning event Nop from mailbox
[linux.C:310-G] - Decoded event to syscall-stop on 29628/29628
[handler.C:402-U] - Event Nop added to handle list with handler Nop Handler
[linux.C:320-G] - Resuming clone event after syscall exit on 29628/29628
[handler.C:419-U] - Have event Nop on Nop Handler
[linux.C:323-G] - Parent half of paired event, postponing decode until child arrives
[handler.C:437-U] - Handling event 'Nop' with handler 'Nop Handler'
[generator.C:144-G] - Setting generator state to statesync
[process.C:798-U] - At top of syncRunState for 29628
[generator.C:144-G] - Setting generator state to queueing
[process.C:3271-U] - 29628/29628: setting target state to Running
[generator.C:144-G] - Setting generator state to none
[process.C:3496-U] - Checking thread 29628/29628 for events thrown before continue
[generator.C:144-G] - Setting generator state to process_blocked
[generator.C:429-G] - Checking for live processes
[generator.C:278-G] - Entry to generator::hasLiveProc()
[generator.C:288-G] - Generator has running threads, returning true from hasLiveProc
[generator.C:442-G] - processWait returning true
[generator.C:144-G] - Setting generator state to system_blocked
[generator.C:207-G] - About to getEvent()
[linux.C:140-G] - blocking in waitpid
[process.C:835-U] - Checking if any ProcStop events on 29628 are ready
[process.C:3271-U] - 29628/29628: setting target state to Running
[process.C:847-U] - Current Threading State for 29628:
[process.C:863-U] - 29628/29628 hand: running, gen: running, postponed syscall: running, code: --R-------------SRR
[process.C:872-U] - Running plat_syncRunState on 29628
[process.C:1024-U] - Polling for events = !F && ((F && !? && ?) || F || F || F || F || F || F || F || F)
[mailbox.C:149-U] - Polled mailbox for messages, but none found
[process.C:1043-U] - Returning after handling events
[process.C:1131-U] - Leaving WaitAndHandleEvents with return true, 'cause we're done
[procset.C:1464-U] - User continuing entire process 29628
[process.C:4392-U] - Changing user state for 29628/29628 from stopped to running
[mailbox.C:120-U] - Added event Nop to mailbox, size = 1 + 0 + 0 = 1
[process.C:6111-U] - User triggered event handling
[process.C:973-U] - Top of waitAndHandleEvents.  Block = true
[process.C:1024-U] - Blocking for events = !F && ((T && !F && T) || ? || ? || ? || ? || ? || ? || ? || ?)
[mailbox.C:171-U] - Returning event Nop from mailbox
[handler.C:402-U] - Event Nop added to handle list with handler Nop Handler
[handler.C:419-U] - Have event Nop on Nop Handler
[handler.C:437-U] - Handling event 'Nop' with handler 'Nop Handler'
[process.C:798-U] - At top of syncRunState for 29628
[process.C:3271-U] - 29628/29628: setting target state to Running
[process.C:3496-U] - Checking thread 29628/29628 for events thrown before continue
[process.C:835-U] - Checking if any ProcStop events on 29628 are ready
[process.C:3271-U] - 29628/29628: setting target state to Running
[process.C:847-U] - Current Threading State for 29628:
[process.C:863-U] - 29628/29628 hand: running, gen: running, postponed syscall: running, code: --R-------------RRR
[process.C:872-U] - Running plat_syncRunState on 29628
[process.C:1024-U] - Polling for events = !F && ((T && !T && ?) || F || F || F || F || F || F || F || F)
[mailbox.C:149-U] - Polled mailbox for messages, but none found
[process.C:1043-U] - Returning after handling events
[process.C:1131-U] - Leaving WaitAndHandleEvents with return true, 'cause we're done
[process.C:6111-U] - User triggered event handling
[process.C:973-U] - Top of waitAndHandleEvents.  Block = true
[process.C:1024-U] - Blocking for events = !F && ((T && !F && T) || ? || ? || ? || ? || ? || ? || ? || ?)
[mailbox.C:155-U] - Blocking for events from mailbox, queue size = 0
[← Prev in Thread] Current Thread [Next in Thread→]