On Apr 3, 2013, at 10:10 AM, David Smith <[email protected]> wrote:

> After that change, oneTimeCode)( doesn't complain, but the function that
> is supposed to be called by oneTimeCode() doesn't actually get called
> either.
> 
> Here's the output DYNINST_DEBUG_PROCCONTROL=1 produces when
> oneTimeCode() is called.

That's... odd. It's certainly making an iRPC (ProcControl terminology for a 
oneTimeCode). And finishing it too. Are you sure the output is from the right 
point in program execution? 

Drew

> 
> ====
> [../src/process.C:6596-U] - Running SYNC RPC
> [../src/irpc.C:321-U] - Posting iRPC 4 to process 29334, selecting a
> thread...
> [../src/irpc.C:359-U] - Thread 29334 has 0 running/posted iRPCs
> [../src/irpc.C:367-U] - Selected thread 29334 for iRPC 4
> [../src/irpc.C:376-U] - Posting iRPC 4 to thread 29334
> [../src/process.C:8387-U] - Adjusting counter SyncRPCs by 1, before 0,
> after 1
> [../src/irpc.C:431-U] - RPC 4 already has allocated memory, added to end
> [../src/irpc.C:496-U] - Posted iRPC list for 29334:
>       U-4(167),
> [../src/process.C:4424-U] - Changing user state for 29334/29334 from
> stopped to running
> [../src/mailbox.C:120-U] - Added event Nop to mailbox, size = 1 + 0 + 0 = 1
> [../src/process.C:952-U] - Top of waitAndHandleEvents.  Block = true
> [../src/process.C:1001-U] - Polling for events = !F && ((T && !F && F)
> || F || F || F || F || F || F || F)
> [../src/mailbox.C:171-U] - Returning event Nop from mailbox
> [../src/handler.C:402-U] - Event Nop added to handle list with handler
> Nop Handler
> [../src/handler.C:419-U] - Have event Nop on Nop Handler
> [../src/handler.C:437-U] - Handling event 'Nop' with handler 'Nop Handler'
> [../src/process.C:778-U] - At top of syncRunState for 29334
> [../src/process.C:3344-U] - 29334/29334: setting target state to Running
> [../src/process.C:3562-U] - Checking thread 29334/29334 for events
> thrown before continue
> [../src/process.C:3570-U] - Found thread 29334/29334 ready to run IRPC,
> not continuing
> [../src/process.C:4296-U] - Desyncing 29334/29334 irpc setup state to
> level 1
> [../src/process.C:4424-U] - Changing irpc setup state for 29334/29334
> from dontcare to stopped
> [../src/event.C:132-U] - Setting callback suppress for RPCLaunch
> [../src/mailbox.C:120-U] - Added event RPCLaunch to mailbox, size = 1 +
> 0 + 0 = 1
> [../src/process.C:815-U] - Checking if any ProcStop events on 29334 are
> ready
> [../src/process.C:3344-U] - 29334/29334: setting target state to Stopped
> [../src/process.C:827-U] - Current Threading State for 29334:
> [../src/process.C:843-U] - 29334/29334 hand: stopped, gen: stopped, irpc
> setup: stopped, code: ----S----------RSS
> [../src/process.C:852-U] - Running plat_syncRunState on 29334
> [../src/process.C:1001-U] - Polling for events = !F && ((T && !T && ?)
> || F || F || F || F || F || F || F)
> [../src/mailbox.C:171-U] - Returning event RPCLaunch from mailbox
> [../src/handler.C:402-U] - Event RPCLaunch added to handle list with
> handler iRPC Launch Handler
> [../src/handler.C:419-U] - Have event RPCLaunch on iRPC Launch Handler
> [../src/handler.C:437-U] - Handling event 'RPCLaunch' with handler 'iRPC
> Launch Handler'
> [../src/irpc.C:1202-U] - Handling next posted irpc 4 on 29334/29334 of
> type User in state Prepping
> [../src/irpc.C:1210-U] - Marking RPC 4 on 29334/29334 as prepped
> [../src/irpc.C:1220-U] - Saving RPC state on 29334/29334
> [../src/irpc.C:710-U] - Saving state for iRPC 4
> [../src/irpc.C:728-U] - Saving original application registers for
> 29334/29334
> [../src/process.C:3681-U] - Reading registers for thread 29334
> [../src/process.C:3695-U] - plat_getAllRegisters on 29334/29334
> [../src/linux.C:1935-U] - Register x86_64::rip has value 30f56ef679,
> offset 128
> [../src/linux.C:1935-U] - Register x86_64::rax has value 0, offset 80
> [../src/linux.C:1935-U] - Register x86_64::rcx has value
> ffffffffffffffff, offset 88
> [../src/linux.C:1935-U] - Register x86_64::rdx has value 30f56ef679,
> offset 96
> [../src/linux.C:1935-U] - Register x86_64::rbx has value 7ffff6f7181c,
> offset 40
> [../src/linux.C:1935-U] - Register x86_64::rsp has value 7fffffffddd8,
> offset 152
> [../src/linux.C:1935-U] - Register x86_64::rbp has value 7296, offset 32
> [../src/linux.C:1935-U] - Register x86_64::rsi has value 7, offset 104
> [../src/linux.C:1935-U] - Register x86_64::rdi has value 7296, offset 112
> [../src/linux.C:1935-U] - Register x86_64::r8 has value 7ffff6f7181c,
> offset 72
> [../src/linux.C:1935-U] - Register x86_64::r9 has value 7ffff6f7181c,
> offset 64
> [../src/linux.C:1935-U] - Register x86_64::r10 has value 30f59bbb00,
> offset 56
> [../src/linux.C:1935-U] - Register x86_64::r11 has value 246, offset 48
> [../src/linux.C:1935-U] - Register x86_64::r12 has value 7, offset 24
> [../src/linux.C:1935-U] - Register x86_64::r13 has value 0, offset 16
> [../src/linux.C:1935-U] - Register x86_64::r14 has value 0, offset 8
> [../src/linux.C:1935-U] - Register x86_64::r15 has value 0, offset 0
> [../src/linux.C:1935-U] - Register x86_64::ds has value 0, offset 184
> [../src/linux.C:1935-U] - Register x86_64::es has value 0, offset 192
> [../src/linux.C:1935-U] - Register x86_64::fs has value 0, offset 200
> [../src/linux.C:1935-U] - Register x86_64::gs has value 0, offset 208
> [../src/linux.C:1935-U] - Register x86_64::cs has value 33, offset 136
> [../src/linux.C:1935-U] - Register x86_64::ss has value 2b, offset 160
> [../src/linux.C:1935-U] - Register x86_64::flags has value 246, offset 144
> [../src/linux.C:1935-U] - Register x86_64::orax has value c8, offset 120
> [../src/linux.C:1935-U] - Register x86_64::fsbase has value
> 7ffff6d46740, offset 168
> [../src/linux.C:1935-U] - Register x86_64::gsbase has value 0, offset 176
> [../src/linux.C:1935-U] - Register x86_64::dr0 has value 0, offset 848
> [../src/linux.C:1935-U] - Register x86_64::dr1 has value 0, offset 856
> [../src/linux.C:1935-U] - Register x86_64::dr2 has value 0, offset 864
> [../src/linux.C:1935-U] - Register x86_64::dr3 has value 0, offset 872
> [../src/linux.C:1935-U] - Register x86_64::dr4 has value 0, offset 880
> [../src/linux.C:1935-U] - Register x86_64::dr5 has value 0, offset 888
> [../src/linux.C:1935-U] - Register x86_64::dr6 has value 0, offset 896
> [../src/linux.C:1935-U] - Register x86_64::dr7 has value 0, offset 904
> [../src/process.C:3719-U] - Successfully retrieved all registers for 29334
> [../src/irpc.C:739-U] - Saving original 167 bytes of memory at
> 3080000750 from application for 29334/29334
> [../src/process.C:1321-U] - Reading from remote memory 3080000750 to
> 0x5bb0a60, size = 167 on 29334/29334
> [../src/irpc.C:1245-U] - Writing RPC on 29334
> [../src/irpc.C:770-U] - Writing rpc 4 memory to 3080000750->30800007f7
> [../src/process.C:1378-U] - Writing to remote memory 3080000750 from
> 0x5baf470, size = 167 on 29334/29334
> [../src/irpc.C:788-U] - IRPC: Setting 29334/29334 PC to 3080000758
> [../src/process.C:3889-U] - 29334/29334: Setting x86_64::rip to
> 0x3080000758...
> [../src/process.C:3914-U] - Setting register x86_64::rip for thread
> 29334 to 3080000758
> [../src/linux.C:2194-U] - Set register x86_64::rip (size 8, offset 128)
> to value 3080000758
> [../src/irpc.C:817-U] - Moving next iRPC for 29334/29334 to running
> [../src/process.C:4321-U] - Restoring 29334/29334 irpc setup state to
> level 0
> [../src/process.C:4424-U] - Changing irpc setup state for 29334/29334
> from stopped to dontcare
> [../src/process.C:778-U] - At top of syncRunState for 29334
> [../src/process.C:3344-U] - 29334/29334: setting target state to Running
> [../src/process.C:3562-U] - Checking thread 29334/29334 for events
> thrown before continue
> [../src/process.C:815-U] - Checking if any ProcStop events on 29334 are
> ready
> [../src/process.C:3344-U] - 29334/29334: setting target state to Running
> [../src/process.C:827-U] - Current Threading State for 29334:
> [../src/process.C:843-U] - 29334/29334 hand: stopped, gen: stopped,
> user: running, code: ---------------RSS
> [../src/process.C:852-U] - Running plat_syncRunState on 29334
> [../src/process.C:3009-U] - intCont on thread 29334/29334
> [../src/linux.C:1134-U] - Continuing thread 29334
> [../src/linux.C:1184-U] - Calling PTRACE_CONT on 29334 with signal 0
> [../src/process.C:8387-U] - Adjusting counter HandlerRunningThreads by
> 1, before 0, after 1
> [../src/process.C:8387-U] - Adjusting counter SyncRPCRunningThreads by
> 1, before 0, after 1
> [../src/process.C:4424-U] - Changing handler state for 29334/29334 from
> stopped to running
> [../src/process.C:8387-U] - Adjusting counter GeneratorRunningThreads by
> 1, before 0, after 1
> [../src/process.C:4424-U] - Changing generator state for 29334/29334
> from stopped to running
> [../src/process.C:5830-U] - Clearing register pool for 29334/29334
> [../src/memcache.C:573-U] - Clearing memCache
> [../src/generator.C:277-G] - Entry to generator::hasLiveProc()
> [../src/generator.C:287-G] - Generator has running threads, returning
> true from hasLiveProc
> [../src/generator.C:441-G] - processWait returning true
> [../src/generator.C:143-G] - Setting generator state to system_blocked
> [../src/generator.C:206-G] - About to getEvent()
> [../src/linux.C:117-G] - blocking in waitpid
> [../src/linux.C:138-G] - Waitpid return status 1407 for pid 29334:
> [../src/linux.C:144-G] - Stopped with signal 5
> [../src/generator.C:208-G] - Got event
> [../src/generator.C:143-G] - Setting generator state to decoding
> [../src/linux.C:271-G] - Decoding event for 29334/29334
> [../src/linux.C:278-G] - Decoded to signal 5
> [../src/linux.C:1979-G] - Register x86_64::rip has value 0x30800007f6
> [../src/irpc.C:930-G] - 29334/29334 trap at 30800007f5 lies between
> 3080000750 and 30800007f7, is iRPC 4 trap
> [../src/linux.C:397-G] - Decoded event to rpc completion on 29334/29334
> at 30800007f5
> [../src/generator.C:143-G] - Setting generator state to statesync
> [../src/process.C:2130-G] - Event RPC is thread synchronous, marking
> thread 29334 generator stopped
> [../src/process.C:8387-G] - Adjusting counter GeneratorRunningThreads by
> -1, before 1, after 0
> [../src/process.C:4424-G] - Changing generator state for 29334/29334
> from running to stopped
> [../src/generator.C:143-G] - Setting generator state to queueing
> [../src/mailbox.C:120-G] - Added event RPC to mailbox, size = 1 + 0 + 0 = 1
> [../src/generator.C:143-G] - Setting generator state to none
> [../src/generator.C:143-G] - Setting generator state to process_blocked
> [../src/generator.C:428-G] - Checking for live processes
> [../src/generator.C:277-G] - Entry to generator::hasLiveProc()
> [../src/generator.C:307-G] - No live processes, ret false
> [../src/generator.C:430-G] - Checked and found no live processes
> [../src/process.C:1001-U] - Blocking for events = !F && ((T && !T && ?)
> || T || ? || ? || ? || ? || ? || ?)
> [../src/mailbox.C:171-U] - Returning event RPC from mailbox
> [../src/process.C:2130-U] - Event RPC is thread synchronous, marking
> thread 29334 handler stopped
> [../src/process.C:8387-U] - Adjusting counter HandlerRunningThreads by
> -1, before 1, after 0
> [../src/process.C:8387-U] - Adjusting counter SyncRPCRunningThreads by
> -1, before 1, after 0
> [../src/process.C:4424-U] - Changing handler state for 29334/29334 from
> running to stopped
> [../src/handler.C:402-U] - Event RPC added to handle list with handler
> iRPC PreCallback Handler
> [../src/handler.C:402-U] - Event RPC added to handle list with handler
> Callback
> [../src/handler.C:402-U] - Event RPC added to handle list with handler
> RPC Handler
> [../src/handler.C:419-U] - Have event RPC on iRPC PreCallback Handler
> [../src/handler.C:419-U] - Have event RPC on Callback
> [../src/handler.C:419-U] - Have event RPC on RPC Handler
> [../src/handler.C:437-U] - Handling event 'RPC' with handler 'iRPC
> PreCallback Handler'
> [../src/process.C:4424-U] - Changing user state for 29334/29334 from
> running to stopped
> [../src/handler.C:437-U] - Handling event 'RPC' with handler 'Callback'
> [../src/handler.C:2161-U] - Changing callback state of 29334 before CB
> [../src/process.C:4296-U] - Desyncing 29334/29334 callback state to level 1
> [../src/process.C:4424-U] - Changing callback state for 29334/29334 from
> dontcare to ditto
> [../src/process.C:4354-U] - Leaving user state for 29334/29334 in state
> stopped
> [../src/handler.C:2184-U] - Triggering callback for event 'RPC'
> [../src/handler.C:2189-U] - Triggering callback #0 for event 'RPC'
> [../src/process.C:3795-U] - Get register value for thread 29334,
> register x86_64::rax
> [../src/linux.C:1979-U] - Register x86_64::rax has value 0x0
> [../src/process.C:3867-U] - Returning register value 0 for register
> x86_64::rax on 29334
> [../src/response.C:286-U] - Waiting for async event 375, complete
> [../src/handler.C:2200-U] - Callback #0 return cbProcStop/cbProcStop
> [../src/process.C:4354-U] - Leaving user state for 29334/29334 in state
> stopped
> [../src/handler.C:2218-U] - Handling return value for main process
> [../src/handler.C:2143-U] - Callbacks returned process stop
> [../src/process.C:4354-U] - Leaving user state for 29334/29334 in state
> stopped
> [../src/handler.C:2223-U] - Handling return value for child process/thread
> [../src/handler.C:2243-U] - Restoring callback state of 29334/29334 after CB
> [../src/process.C:4321-U] - Restoring 29334/29334 callback state to level 0
> [../src/process.C:4424-U] - Changing callback state for 29334/29334 from
> ditto to dontcare
> [../src/handler.C:437-U] - Handling event 'RPC' with handler 'RPC Handler'
> [../src/irpc.C:1028-U] - Handling RPC 4 completion on 29334/29334
> [../src/irpc.C:1044-U] - Restoring memory to 3080000750 from 0x5bb0a60
> of size 167
> [../src/process.C:1378-U] - Writing to remote memory 3080000750 from
> 0x5bb0a60, size = 167 on 29334/29334
> [../src/irpc.C:1086-U] - Restoring all registers
> [../src/process.C:3750-U] - Setting registers for thread 29334
> [../src/linux.C:2142-U] - Register x86_64::rip gets value 30f56ef679,
> offset 128
> [../src/linux.C:2142-U] - Register x86_64::rax gets value 0, offset 80
> [../src/linux.C:2142-U] - Register x86_64::rcx gets value
> ffffffffffffffff, offset 88
> [../src/linux.C:2142-U] - Register x86_64::rdx gets value 30f56ef679,
> offset 96
> [../src/linux.C:2142-U] - Register x86_64::rbx gets value 7ffff6f7181c,
> offset 40
> [../src/linux.C:2142-U] - Register x86_64::rsp gets value 7fffffffddd8,
> offset 152
> [../src/linux.C:2142-U] - Register x86_64::rbp gets value 7296, offset 32
> [../src/linux.C:2142-U] - Register x86_64::rsi gets value 7, offset 104
> [../src/linux.C:2142-U] - Register x86_64::rdi gets value 7296, offset 112
> [../src/linux.C:2142-U] - Register x86_64::r8 gets value 7ffff6f7181c,
> offset 72
> [../src/linux.C:2142-U] - Register x86_64::r9 gets value 7ffff6f7181c,
> offset 64
> [../src/linux.C:2142-U] - Register x86_64::r10 gets value 30f59bbb00,
> offset 56
> [../src/linux.C:2142-U] - Register x86_64::r11 gets value 246, offset 48
> [../src/linux.C:2142-U] - Register x86_64::r12 gets value 7, offset 24
> [../src/linux.C:2142-U] - Register x86_64::r13 gets value 0, offset 16
> [../src/linux.C:2142-U] - Register x86_64::r14 gets value 0, offset 8
> [../src/linux.C:2142-U] - Register x86_64::r15 gets value 0, offset 0
> [../src/linux.C:2142-U] - Register x86_64::ds gets value 0, offset 184
> [../src/linux.C:2142-U] - Register x86_64::es gets value 0, offset 192
> [../src/linux.C:2142-U] - Register x86_64::fs gets value 0, offset 200
> [../src/linux.C:2142-U] - Register x86_64::gs gets value 0, offset 208
> [../src/linux.C:2142-U] - Register x86_64::cs gets value 33, offset 136
> [../src/linux.C:2142-U] - Register x86_64::ss gets value 2b, offset 160
> [../src/linux.C:2142-U] - Register x86_64::flags gets value 246, offset 144
> [../src/linux.C:2142-U] - Register x86_64::orax gets value c8, offset 120
> [../src/linux.C:2142-U] - Register x86_64::fsbase gets value
> 7ffff6d46740, offset 168
> [../src/linux.C:2142-U] - Register x86_64::gsbase gets value 0, offset 176
> [../src/linux.C:2070-U] - Successfully set the values of all registers
> for 29334
> [../src/process.C:3767-U] - Successfully set all registers for 29334
> [../src/irpc.C:1126-U] - RPC 4 is moving to state finished
> [../src/process.C:8387-U] - Adjusting counter SyncRPCs by -1, before 1,
> after 0
> [../src/process.C:778-U] - At top of syncRunState for 29334
> [../src/process.C:3344-U] - 29334/29334: setting target state to Stopped
> [../src/process.C:815-U] - Checking if any ProcStop events on 29334 are
> ready
> [../src/process.C:3344-U] - 29334/29334: setting target state to Stopped
> [../src/process.C:827-U] - Current Threading State for 29334:
> [../src/process.C:843-U] - 29334/29334 hand: stopped, gen: stopped,
> user: stopped, code: ---------------SSS
> [../src/process.C:852-U] - Running plat_syncRunState on 29334
> [../src/process.C:1001-U] - Polling for events = !F && ((T && !T && ?)
> || F || F || F || F || F || F || F)
> [../src/mailbox.C:149-U] - Polled mailbox for messages, but none found
> [../src/process.C:1020-U] - Returning after handling events
> [../src/process.C:1126-U] - Leaving WaitAndHandleEvents with return
> true, 'cause we're done
> [../src/process.C:8628-H] - Handler starting to check for events
> [../src/process.C:8636-H] - Events already handled, going back to sleep
> [../src/process.C:8628-H] - Handler starting to check for events
> [../src/process.C:8636-H] - Events already handled, going back to sleep
> [../src/process.C:6124-U] - User triggered event handling
> [../src/process.C:952-U] - Top of waitAndHandleEvents.  Block = false
> [../src/process.C:1001-U] - Polling for events = !F && ((F && !? && ?)
> || F || F || F || F || F || F || F)
> [../src/mailbox.C:149-U] - Polled mailbox for messages, but none found
> [../src/process.C:1041-U] - Poll failed to find events
> [../src/process.C:1126-U] - Leaving WaitAndHandleEvents with return
> false, 'cause we're done
> [../src/process.C:6134-U] - Polling Process::handleEvents returning
> false due to no events
> ====
> 
> -- 
> David Smith
> [email protected]
> Red Hat
> http://www.redhat.com
> 256.217.0141 (direct)
> 256.837.0057 (fax)

--
Andrew Bernat
Paradyn Project
[email protected]
http://www.cs.wisc.edu/~bernat




_______________________________________________
Dyninst-api mailing list
[email protected]
https://lists.cs.wisc.edu/mailman/listinfo/dyninst-api

Reply via email to