[Ltrace-devel] Infinite stream of breakpoint events

Andreas Schwab schwab at linux-m68k.org
Fri Jul 24 22:14:47 UTC 2015 

When running the attach-process-dlopen test on ppc64 or ppc64le ltrace
is receiving an endless stream of breakpoint events:

$ ./ltrace -e* -D10 testsuite/ltrace.minor/exe testsuite/ltrace.minor
DEBUG: events.c:258: event: SYSCALL: pid=17899, sysnum=45
DEBUG: events.c:263: event: SYSRET: pid=17899, sysnum=45
DEBUG: events.c:258: event: SYSCALL: pid=17899, sysnum=90
DEBUG: events.c:263: event: SYSRET: pid=17899, sysnum=90
DEBUG: events.c:258: event: SYSCALL: pid=17899, sysnum=33
DEBUG: events.c:263: event: SYSRET: pid=17899, sysnum=33
DEBUG: events.c:258: event: SYSCALL: pid=17899, sysnum=5
DEBUG: events.c:263: event: SYSRET: pid=17899, sysnum=5
DEBUG: events.c:258: event: SYSCALL: pid=17899, sysnum=108
DEBUG: events.c:263: event: SYSRET: pid=17899, sysnum=108
DEBUG: events.c:258: event: SYSCALL: pid=17899, sysnum=90
DEBUG: events.c:263: event: SYSRET: pid=17899, sysnum=90
DEBUG: events.c:258: event: SYSCALL: pid=17899, sysnum=6
DEBUG: events.c:263: event: SYSRET: pid=17899, sysnum=6
DEBUG: events.c:258: event: SYSCALL: pid=17899, sysnum=5
DEBUG: events.c:263: event: SYSRET: pid=17899, sysnum=5
DEBUG: events.c:258: event: SYSCALL: pid=17899, sysnum=3
DEBUG: events.c:263: event: SYSRET: pid=17899, sysnum=3
DEBUG: events.c:258: event: SYSCALL: pid=17899, sysnum=108
DEBUG: events.c:263: event: SYSRET: pid=17899, sysnum=108
DEBUG: events.c:258: event: SYSCALL: pid=17899, sysnum=90
DEBUG: events.c:263: event: SYSRET: pid=17899, sysnum=90
DEBUG: events.c:258: event: SYSCALL: pid=17899, sysnum=125
DEBUG: events.c:263: event: SYSRET: pid=17899, sysnum=125
DEBUG: events.c:258: event: SYSCALL: pid=17899, sysnum=90
DEBUG: events.c:263: event: SYSRET: pid=17899, sysnum=90
DEBUG: events.c:258: event: SYSCALL: pid=17899, sysnum=6
DEBUG: events.c:263: event: SYSRET: pid=17899, sysnum=6
DEBUG: events.c:258: event: SYSCALL: pid=17899, sysnum=5
DEBUG: events.c:263: event: SYSRET: pid=17899, sysnum=5
DEBUG: events.c:258: event: SYSCALL: pid=17899, sysnum=3
DEBUG: events.c:263: event: SYSRET: pid=17899, sysnum=3
DEBUG: events.c:258: event: SYSCALL: pid=17899, sysnum=108
DEBUG: events.c:263: event: SYSRET: pid=17899, sysnum=108
DEBUG: events.c:258: event: SYSCALL: pid=17899, sysnum=90
DEBUG: events.c:263: event: SYSRET: pid=17899, sysnum=90
DEBUG: events.c:258: event: SYSCALL: pid=17899, sysnum=90
DEBUG: events.c:263: event: SYSRET: pid=17899, sysnum=90
DEBUG: events.c:258: event: SYSCALL: pid=17899, sysnum=125
DEBUG: events.c:263: event: SYSRET: pid=17899, sysnum=125
DEBUG: events.c:258: event: SYSCALL: pid=17899, sysnum=90
DEBUG: events.c:263: event: SYSRET: pid=17899, sysnum=90
DEBUG: events.c:258: event: SYSCALL: pid=17899, sysnum=90
DEBUG: events.c:263: event: SYSRET: pid=17899, sysnum=90
DEBUG: events.c:258: event: SYSCALL: pid=17899, sysnum=6
DEBUG: events.c:263: event: SYSRET: pid=17899, sysnum=6
DEBUG: events.c:258: event: SYSCALL: pid=17899, sysnum=90
DEBUG: events.c:263: event: SYSRET: pid=17899, sysnum=90
DEBUG: events.c:258: event: SYSCALL: pid=17899, sysnum=125
DEBUG: events.c:263: event: SYSRET: pid=17899, sysnum=125
DEBUG: events.c:258: event: SYSCALL: pid=17899, sysnum=125
DEBUG: events.c:263: event: SYSRET: pid=17899, sysnum=125
DEBUG: events.c:258: event: SYSCALL: pid=17899, sysnum=125
DEBUG: events.c:263: event: SYSRET: pid=17899, sysnum=125
DEBUG: events.c:258: event: SYSCALL: pid=17899, sysnum=125
DEBUG: events.c:263: event: SYSRET: pid=17899, sysnum=125
DEBUG: events.c:258: event: SYSCALL: pid=17899, sysnum=91
DEBUG: events.c:263: event: SYSRET: pid=17899, sysnum=91
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x100006cc
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x10000640
exe->__libc_start_main(2, 't', 'L', { 22, [ 0, 0, 0, 0... ] }, 0x3fff88ec05e8, { nil, 0x100110b8, 0x100110d0, 0x100110e8 }, nil <no return ...>
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x10000644
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x100006b8
exe->strlen( <no return ...>
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x100006bc
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x10000928
<... strlen resumed> )                           = <void>
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x1000067c
exe->sprintf( <no return ...>
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x10000680
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88cbbb80
libc.so.6->__strchrnul( <no return ...>
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88cbbb84
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88cef470
<... __strchrnul resumed> )                      = <void>
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88cbbbb8
libc.so.6->__GI_strlen( <no return ...>
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88cbbbbc
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88cf3100
<... __GI_strlen resumed> )                      = <void>
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88cbbd94
libc.so.6->__GI_memcpy( <no return ...>
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88cbbd98
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88d40a98
<... __GI_memcpy resumed> )                      = <void>
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88cbbb80
libc.so.6->__strchrnul( <no return ...>
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88cbbb84
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88cf1eb8
<... __strchrnul resumed> )                      = <void>
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88cbbbb8
libc.so.6->__GI_strlen( <no return ...>
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88cbbbbc
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88cf3100
<... __GI_strlen resumed> )                      = <void>
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88cbbb80
libc.so.6->__strchrnul( <no return ...>
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88cbbb84
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88cf1eb8
<... __strchrnul resumed> )                      = <void>
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x100009c0
<... sprintf resumed> )                          = <void>
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x10000690
exe->dlopen(0x3fffdaad3910, 1, 0, 5 <unfinished ...>
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x10000694
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88e89238
ld64.so.1->malloc( <no return ...>
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88e8923c
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88cbbc44
libc.so.6->_dl_find_dso_for_object( <no return ...>
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88cbbc48
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88df438c
<... _dl_find_dso_for_object resumed> )          = <void>
DEBUG: events.c:258: event: SYSCALL: pid=17899, sysnum=45
DEBUG: events.c:263: event: SYSRET: pid=17899, sysnum=45
DEBUG: events.c:258: event: SYSCALL: pid=17899, sysnum=45
DEBUG: events.c:263: event: SYSRET: pid=17899, sysnum=45
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88d33280
libc.so.6->__libc_memset( <no return ...>
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88d33284
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88d33288
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88d3328c
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88d33290
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88d33294
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88d33298
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88d3329c
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88d332a0
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88d332a4
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88d332e0
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88d332e4
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88d33310
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88d33314
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88d33320
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88d33324
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88d332b0
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88d332b4
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88d332b8
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88d332bc
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88d332c0
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88d332c4
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88d332c8
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88d332cc
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88d33330
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88d33334
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88d33338
DEBUG: events.c:336: event: BREAKPOINT: pid=17899, addr=0x3fff88d28c04

The last line is repeated infinitely (and ltrace is not interruptable).
The addr=0x3fff8ff98c04 is the return address from memset (the previous
insn at 0x3fff8ffa3338 was blr).

This was uncovered by commit bf82100 (Fix address biasing in PPC
backend), but the bug is older than that.  Bisecting while
cherry-picking bf82100 on every candidate identified 73b85aa (Support
tracing P_PPC64_JMP_IREL slots) as the bad commit.

Andreas.

-- 
Andreas Schwab, schwab at linux-m68k.org
GPG Key fingerprint = 58CA 54C7 6D53 942B 1756  01D3 44D5 214B 8276 4ED5
"And now for something completely different."

More information about the Ltrace-devel mailing list