Bug 13022 - probe module("*").function("*") does not work on arm
Summary: probe module("*").function("*") does not work on arm
Status: RESOLVED FIXED
Alias: None
Product: systemtap
Classification: Unclassified
Component: translator (show other bugs)
Version: unspecified
: P2 normal
Target Milestone: ---
Assignee: Unassigned
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2011-07-23 16:38 UTC by William Cohen
Modified: 2012-11-15 15:45 UTC (History)
0 users

See Also:
Host:
Target: arm
Build:
Last reconfirmed:


Attachments
Section information for /lib/modules/2.6.31.14.24-efikamx/kernel/fs/ext3/ext3.ko (1.09 KB, text/plain)
2011-07-23 18:49 UTC, William Cohen
Details
Output of 'stap -vvvvvv -L ...' (1.70 KB, text/plain)
2011-07-25 13:49 UTC, William Cohen
Details

Note You need to log in before you can comment on or make changes to this bug.
Description William Cohen 2011-07-23 16:38:17 UTC
When running the systemtap testsuite on an arm machine running fedora 13 a number of the tests do not work because the module("*").function("*") probes do not work. Below is a one line example that demonstrates the problem on arm:

../install/bin/stap -p4 -k -e 'probe module("ext3").function("zero_user") {print("I am here\n"); exit();}'

Results in:

semantic error: libdwfl failure (dwfl_module_relocate_address): no matching address range
Pass 3: translation failed.  Try again with another '--vp 001' option.
Keeping temporary directory "/tmp/stapQxJahh"

The module is installed and stap -L works fine:

[wcohen@thumb obj]$ lsmod|grep ^ext3
ext3                  123180  1 
[wcohen@thumb obj]$ ../install/bin/stap -L 'module("ext3").function("zero_user")'
module("ext3").function("zero_user@include/linux/highmem.h:164") $page:struct page* $size:unsigned int $start:unsigned int

Use gdb and set a breakpoint at dwarf_wrappers.cxx:30 to get a backtrace for the earlier one-liner:


(gdb) where
#0  dwfl_assert (desc="dwfl_module_relocate_address", rc=<value optimized out>)
    at ../systemtap/dwarf_wrappers.cxx:30
#1  0x000782b0 in dwfl_assert (m=0x1f9, userdata=<value optimized out>, 
    name=<value optimized out>, base=65536, arg=0x7e9757dc)
    at ../systemtap/dwarf_wrappers.h:43
#2  dump_unwindsyms (m=0x1f9, userdata=<value optimized out>, 
    name=<value optimized out>, base=65536, arg=0x7e9757dc)
    at ../systemtap/translate.cxx:5058
#3  0x2ab8927c in dwfl_getmodules (dwfl=0xc07c50, 
    callback=0x77a60 <dump_unwindsyms(Dwfl_Module*, void**, char const*, Dwarf_Addr, void*)>, arg=0x7e9757dc, offset=1) at dwfl_getmodules.c:103
#4  0x0006ea40 in emit_symbol_data (s=...) at ../systemtap/translate.cxx:5607
#5  0x000772e8 in translate_pass (s=...) at ../systemtap/translate.cxx:6049
#6  0x00016ef0 in passes_0_4 (s=...) at ../systemtap/main.cxx:760
#7  0x00017ffc in main (argc=<value optimized out>, argv=<value optimized out>)
    at ../systemtap/main.cxx:998


The same problem has been mentioned on:
https://wiki.linaro.org/Platform/DevPlatform/systemtap
Comment 1 William Cohen 2011-07-23 18:35:53 UTC
Set breakpoint __libdwfl_seterrno to find out where the errno gets set and rerun the example:

Breakpoint 2, __libdwfl_seterrno (error=327711) at dwfl_error.c:143
143	  global_error = canonicalize (error);
(gdb) where
#0  __libdwfl_seterrno (error=327711) at dwfl_error.c:143
#1  0x2ab87dc0 in find_section (mod=<value optimized out>, addr=0x7ed1c5d8)
    at derelocate.c:351
#2  0x00077f34 in dump_unwindsyms (m=0x1f9, userdata=<value optimized out>, 
    name=<value optimized out>, base=65536, arg=0x7ed1c7dc)
    at ../systemtap/translate.cxx:5057
#3  0x2ab8927c in dwfl_getmodules (dwfl=0xc07c50, 
    callback=0x77a60 <dump_unwindsyms(Dwfl_Module*, void**, char const*, Dwarf_Addr, void*)>, arg=0x7ed1c7dc, offset=1) at dwfl_getmodules.c:103
#4  0x0006ea40 in emit_symbol_data (s=...) at ../systemtap/translate.cxx:5607
#5  0x000772e8 in translate_pass (s=...) at ../systemtap/translate.cxx:6049
#6  0x00016ef0 in passes_0_4 (s=...) at ../systemtap/main.cxx:760
#7  0x00017ffc in main (argc=<value optimized out>, argv=<value optimized out>)
    at ../systemtap/main.cxx:998

set breakpoint in find_section and see what is being passed in:

Breakpoint 1, find_section (mod=0xbd7f40, addr=0x7eb66bc8) at derelocate.c:322
322	  if (unlikely (mod->reloc_info == NULL) && cache_sections (mod) < 0)
(gdb) print *mod
$1 = {dwfl = 0xbc6a20, next = 0xbd2dd8, userdata = 0x0, 
  name = 0xbc7c40 "ext3", low_addr = 65536, high_addr = 94532, main = {
    name = 0xbd8008 "/lib/modules/2.6.31.14.24-efikamx/build/fs/ext3/ext3.ko", 
    fd = -1, valid = false, relocated = false, elf = 0xbc8f40, bias = 0}, 
  debug = {name = 0x0, fd = 0, valid = false, relocated = false, 
    elf = 0xbc8f40, bias = 0}, ebl = 0xbd1138, e_type = 1, 
  elferr = DWFL_E_NOERROR, reloc_info = 0xc480d8, symfile = 0xbd7f60, 
  symdata = 0xbca978, syments = 987, symstrdata = 0xbcaa00, symxndxdata = 0x0, 
  dw = 0xbdb650, symerr = DWFL_E_NOERROR, dwerr = DWFL_E_NOERROR, 
  first_cu = 0x0, cu = 0x0, lazy_cu_root = 0x0, aranges = 0x0, 
  build_id_bits = 0x0, build_id_vaddr = 0, build_id_len = 0, ncu = 0, 
  lazycu = 1, naranges = 0, dwarf_cfi = 0x0, eh_cfi = 0x0, segment = 0, 
  gc = false}
Comment 2 William Cohen 2011-07-23 18:49:33 UTC
Created attachment 5860 [details]
Section information for /lib/modules/2.6.31.14.24-efikamx/kernel/fs/ext3/ext3.ko

find_section() looking for section that contains:

(gdb) print *addr
$13 = 28232
(gdb) print/x *addr
$14 = 0x6e48

Doesn't seem to find the right section. Possible suspects:

-gcc for arm getting the arm section information wrong
-translator getting address wrong
-elfutils messing up
Comment 3 William Cohen 2011-07-25 13:49:03 UTC
Created attachment 5862 [details]
Output of 'stap -vvvvvv -L ...'
Comment 4 William Cohen 2011-07-25 14:43:15 UTC
It looks like the ARM sections are violating the assumption in find_section that the sections are non-overlapping regions of memory. This causes the binary search to end up in the wrong section:

in find_section():

find_section should find the .text section. However that overlaps .rodata, .bss, .data, and .note.gnu.build-id sections.  As result the converges to sections 3 or 4 which do not contain the addr.

(gdb) print sections->count
$1 = 16
(gdb) print sections->refs[0]
$2 = {scn = 0xbc9108, relocs = 0xbc9190, name = 0x2e70886a ".text", 
  start = 36, end = 79072}
(gdb) print sections->refs[1]
$3 = {scn = 0xbc9438, relocs = 0xbc94c0, name = 0x2e708892 ".rodata", 
  start = 224, end = 3520}
(gdb) print sections->refs[2]
$4 = {scn = 0xbc9d40, relocs = 0x0, name = 0x2e708950 ".bss", start = 344, 
  end = 352}
(gdb) print sections->refs[3]
$5 = {scn = 0xbc9b20, relocs = 0xbc9ba8, name = 0x2e70892c ".data", 
  start = 1672, end = 1808}
(gdb) print sections->refs[4]
$6 = {scn = 0xbc9080, relocs = 0x0, name = 0x2e708853 ".note.gnu.build-id", 
  start = 65536, end = 65572}
(gdb) print sections->refs[5]
$7 = {scn = 0xbc9218, relocs = 0xbc92a0, name = 0x2e7088b3 ".exit.text", 
  start = 79072, end = 79120}
(gdb) print sections->refs[6]
$8 = {scn = 0xbc9328, relocs = 0xbc93b0, name = 0x2e7088e1 ".init.text", 
  start = 79120, end = 79344}
(gdb) print sections->refs[7]
$9 = {scn = 0xbc9548, relocs = 0x0, name = 0x2e70889a ".rodata.str1.1", 
  start = 79344, end = 89685}
(gdb) print sections->refs[8]
$10 = {scn = 0xbc95d0, relocs = 0x0, name = 0x2e7088a9 ".ARM.extab.exit.text", 
  start = 89688, end = 89700}
(gdb) print sections->refs[9]
$11 = {scn = 0xbc9658, relocs = 0xbc96e0, 
  name = 0x2e7088c2 ".ARM.exidx.exit.text", start = 89700, end = 89708}
(gdb) print sections->refs[10]
$12 = {scn = 0xbc9768, relocs = 0x0, name = 0x2e7088d7 ".ARM.extab.init.text", 
  start = 89708, end = 89732}
(gdb) print sections->refs[11]
$13 = {scn = 0xbc97f0, relocs = 0xbc9878, 
  name = 0x2e7088f0 ".ARM.exidx.init.text", start = 89732, end = 89748}
(gdb) print sections->refs[12]
$14 = {scn = 0xbc9900, relocs = 0x0, name = 0x2e708905 ".modinfo", 
  start = 89748, end = 89996}
(gdb) print sections->refs[13]
$15 = {scn = 0xbc9988, relocs = 0x0, name = 0x2e70890e ".ARM.extab", 
  start = 89996, end = 92516}
(gdb) print sections->refs[14]
$16 = {scn = 0xbc9a10, relocs = 0xbc9a98, name = 0x2e70891d ".ARM.exidx", 
  start = 92516, end = 94188}
(gdb) print sections->refs[15]
$17 = {scn = 0xbc9c30, relocs = 0xbc9cb8, 
  name = 0x2e708936 ".gnu.linkonce.this_module", start = 94188, end = 94532}
Comment 5 William Cohen 2011-07-25 20:37:26 UTC
Posted the ext3.ko module at:

http://people.redhat.com/wcohen/arm/ext3.ko
Comment 6 William Cohen 2011-10-13 16:30:34 UTC
The current version of systemtap is now building modules, but the .section field of the stap_dwarf_probes appears to be bogus in many cases. For example:

../install/bin/stap  -v  -k -e 'probe module("ext3").function("ext3_readpages").call
{print("I am here\n"); exit();}'

produces:

} stap_dwarf_probes[] = {
  { .address=(unsigned long)0x5768ULL, .module="ext3", .section="", .probe=(&stap_probes[0]), },
};

The .address and .module look to be correct, but it looks like the .section should be ".text".
Comment 7 William Cohen 2011-10-13 18:52:32 UTC
There is something wrong with the way the elfutils is reading in the
module section data Below is the output of eu-readelf and the various
sections in find_section().  The section->refs[n] in find_section
violate the ordered and non-overlapping assumptions made in the
find_section() binary search.

A couple things different on the arm eu-readelf versus x86: the Addr
column has non-zero values and the offsets(Off) are not monotonically
increasing.

$ eu-readelf -S ./kernel/fs/ext3/ext3.ko
There are 50 section headers, starting at offset 0x15f874:

Section Headers:
[Nr] Name                 Type         Addr     Off    Size   ES Flags Lk Inf Al
[ 0]                      NULL         00000000 000000 000000  0        0   0  0
[ 1] .note.gnu.build-id   NOTE         00000000 000034 000024  0 A      0   0  4
[ 2] .text                PROGBITS     00000024 000058 0134bc  0 AX     0   0  4
[ 3] .rel.text            REL          00000000 160044 003ca8  8       48   2  4
[ 4] .exit.text           PROGBITS     00000000 013514 000030  0 AX     0   0  4
[ 5] .rel.exit.text       REL          00000000 163cec 000028  8       48   4  4
[ 6] .init.text           PROGBITS     00000000 013544 0000e0  0 AX     0   0  4
[ 7] .rel.init.text       REL          00000000 163d14 000060  8       48   6  4
[ 8] .rodata              PROGBITS     000000e0 013624 000ce0  0 A      0   0  4
[ 9] .rel.rodata          REL          00000000 163d74 000520  8       48   8  4
[10] .rodata.str1.1       PROGBITS     00000000 014304 002865  1 AMS    0   0  1
[11] .ARM.extab.exit.text PROGBITS     00000000 016b6c 00000c  0 A      0   0  4
[12] .ARM.exidx.exit.text ARM_EXIDX    00000000 016b78 000008  0 AL     4   0  4
[13] .rel.ARM.exidx.exit.text REL          00000000 164294 000018  8       48  12  4
[14] .ARM.extab.init.text PROGBITS     00000000 016b80 000018  0 A      0   0  4
[15] .ARM.exidx.init.text ARM_EXIDX    00000000 016b98 000010  0 AL     6   0  4
[16] .rel.ARM.exidx.init.text REL          00000000 1642ac 000030  8       48  15  4
[17] .modinfo             PROGBITS     00000000 016ba8 0000f8  0 A      0   0  4
[18] .ARM.extab           PROGBITS     00000000 016ca0 0009d8  0 A      0   0  4
[19] .ARM.exidx           ARM_EXIDX    00000000 017678 000688  0 AL     2   0  4
[20] .rel.ARM.exidx       REL          00000000 1642dc 000da0  8       48  19  4
[21] .data                PROGBITS     00000688 017d00 000088  0 WA     0   0  4
[22] .rel.data            REL          00000000 16507c 0000e8  8       48  21  4
[23] .gnu.linkonce.this_module PROGBITS     00000000 017d88 000158  0 WA     0   0  4
[24] .rel.gnu.linkonce.this_module REL          00000000 165164 000010  8       48  23  4
[25] .bss                 NOBITS       00000158 017ee0 000008  0 WA     0   0  4
[26] .note.GNU-stack      PROGBITS     00000000 017ee0 000000  0        0   0  1
[27] .ARM.attributes      ARM_ATTRIBUTES 00000000 017ee0 00002d  0        0   0  1
[28] .comment             PROGBITS     00000000 017f0d 000384  1 MS     0   0  1
[29] .debug_aranges       PROGBITS     00000000 018291 000258  0        0   0  1
[30] .rel.debug_aranges   REL          00000000 165174 000138  8       48  29  4
[31] .debug_pubnames      PROGBITS     00000000 0184e9 0009dc  0        0   0  1
[32] .rel.debug_pubnames  REL          00000000 1652ac 000098  8       48  31  4
[33] .debug_info          PROGBITS     00000000 018ec5 0a80ff  0        0   0  1
[34] .rel.debug_info      REL          00000000 165344 0593b0  8       48  33  4
[35] .debug_abbrev        PROGBITS     00000000 0c0fc4 005730  0        0   0  1
[36] .debug_line          PROGBITS     00000000 0c66f4 00ba2e  0        0   0  1
[37] .rel.debug_line      REL          00000000 1be6f4 0000a8  8       48  36  4
[38] .debug_frame         PROGBITS     00000000 0d2124 0031b4  0        0   0  4
[39] .rel.debug_frame     REL          00000000 1be79c 000d40  8       48  38  4
[40] .debug_str           PROGBITS     00000000 0d52d8 059b7f  1 MS     0   0  1
[41] .debug_loc           PROGBITS     00000000 12ee57 019834  0        0   0  1
[42] .rel.debug_loc       REL          00000000 1bf4dc 004c78  8       48  41  4
[43] .debug_pubtypes      PROGBITS     00000000 14868b 013aab  0        0   0  1
[44] .rel.debug_pubtypes  REL          00000000 1c4154 0000a0  8       48  43  4
[45] .debug_ranges        PROGBITS     00000000 15c136 003550  0        0   0  1
[46] .rel.debug_ranges    REL          00000000 1c41f4 000a20  8       48  45  4
[47] .shstrtab            STRTAB       00000000 15f686 0001ec  0        0   0  1
[48] .symtab              SYMTAB       00000000 1c4c14 003db0 16       49 667  4
[49] .strtab              STRTAB       00000000 1c89c4 00269e  0        0   0  1


(gdb) s
dwfl_module_relocate_address (mod=0xbe05a0, addr=0x7e81aaf4)
    at derelocate.c:363
...
(gdb) print sections->count
$8 = 16
(gdb) print sections->refs[0]
$9 = {scn = 0xbe40a8, relocs = 0xbe4130, name = 0x2de616b8 ".text", 
  start = 36, end = 79072}
(gdb) print sections->refs[1]
$10 = {scn = 0xbe43d8, relocs = 0xbe4460, name = 0x2de616e0 ".rodata", 
  start = 224, end = 3520}
(gdb) print sections->refs[2]
$11 = {scn = 0xbe4ce0, relocs = 0x0, name = 0x2de6179e ".bss", start = 344, 
  end = 352}
(gdb) print sections->refs[3]
$12 = {scn = 0xbe4ac0, relocs = 0xbe4b48, name = 0x2de6177a ".data", 
  start = 1672, end = 1808}
(gdb) print sections->refs[4]
$13 = {scn = 0xbe4020, relocs = 0x0, name = 0x2de616a1 ".note.gnu.build-id", 
  start = 65536, end = 65572}
(gdb) print sections->refs[5]
$14 = {scn = 0xbe41b8, relocs = 0xbe4240, name = 0x2de61701 ".exit.text", 
  start = 79072, end = 79120}
(gdb) print sections->refs[6]
$15 = {scn = 0xbe42c8, relocs = 0xbe4350, name = 0x2de6172f ".init.text", 
  start = 79120, end = 79344}
(gdb) print sections->refs[7]
$16 = {scn = 0xbe44e8, relocs = 0x0, name = 0x2de616e8 ".rodata.str1.1", 
  start = 79344, end = 89685}
(gdb) print sections->refs[8]
$17 = {scn = 0xbe4570, relocs = 0x0, name = 0x2de616f7 ".ARM.extab.exit.text", 
  start = 89688, end = 89700}
(gdb) print sections->refs[9]
$18 = {scn = 0xbe45f8, relocs = 0xbe4680, 
  name = 0x2de61710 ".ARM.exidx.exit.text", start = 89700, end = 89708}
(gdb) print sections->refs[10]
$19 = {scn = 0xbe4708, relocs = 0x0, name = 0x2de61725 ".ARM.extab.init.text", 
  start = 89708, end = 89732}
(gdb) print sections->refs[11]
$20 = {scn = 0xbe4790, relocs = 0xbe4818, 
  name = 0x2de6173e ".ARM.exidx.init.text", start = 89732, end = 89748}
(gdb) print sections->refs[12]
$21 = {scn = 0xbe48a0, relocs = 0x0, name = 0x2de61753 ".modinfo", 
  start = 89748, end = 89996}
(gdb) print sections->refs[13]
$22 = {scn = 0xbe4928, relocs = 0x0, name = 0x2de6175c ".ARM.extab", 
  start = 89996, end = 92516}
(gdb) print sections->refs[14]
$23 = {scn = 0xbe49b0, relocs = 0xbe4a38, name = 0x2de6176b ".ARM.exidx", 
  start = 92516, end = 94188}
(gdb) print sections->refs[15]
$24 = {scn = 0xbe4bd0, relocs = 0xbe4c58, 
  name = 0x2de61784 ".gnu.linkonce.this_module", start = 94188, end = 94532}
Comment 8 William Cohen 2012-11-15 15:45:33 UTC
This appears to be no longer a problem arm F18.  The ext3 modules
doesn't seem to be around on this particular kernel so used a slightly
different one liners on the iptable_nat module.


$ ../install/bin/stap -p4 -k -e 'probe module("iptable_nat").function("*") {print("I am here\n"); exit();}'
stap_1671.ko
Keeping temporary directory "/tmp/staprJLmCb"
$ staprun -v /tmp/staprJLmCb/stap_1671.ko
I am here
stapio:cleanup_and_exit:452 detach=0
stapio:cleanup_and_exit:469 closing control channel
staprun:remove_module:261 Module stap_1671 removed.