[Bug translator/17190] New: 'stap -l' output not useful as stap input

[Bug translator/17190] New: 'stap -l' output not useful as stap input

[dsmith at redhat dot com]

https://sourceware.org/bugzilla/show_bug.cgi?id=17190

            Bug ID: 17190
           Summary: 'stap -l' output not useful as stap input
           Product: systemtap
           Version: unspecified
            Status: NEW
          Severity: normal
          Priority: P2
         Component: translator
          Assignee: systemtap at sourceware dot org
          Reporter: dsmith at redhat dot com

While working on bug #17140, I came across this. 

First use 'stap -l' to get a listing of function probe points:

====
# stap -l 'kernel.function("z*@mm/*.c").call'
kernel.function("zap_huge_pmd@mm/huge_memory.c:1412").call
kernel.function("zap_page_range@mm/memory.c:1401").call
kernel.function("zap_page_range_single@mm/memory.c:1427").call
kernel.function("zap_vma_ptes@mm/memory.c:1455").call
kernel.function("zone_absent_pages_in_node@mm/page_alloc.c:4506").call
kernel.function("zone_balanced@mm/vmscan.c:2675").call
kernel.function("zone_batchsize@mm/page_alloc.c:4061").call
kernel.function("zone_dirty_ok@mm/page-writeback.c:344").call
kernel.function("zone_pcp_reset@mm/page_alloc.c:6178").call
kernel.function("zone_pcp_update@mm/page_alloc.c:6172").call
kernel.function("zone_reclaimable_pages@mm/vmscan.c:150").call
kernel.function("zone_spanned_pages_in_node@mm/page_alloc.c:4445").call
kernel.function("zone_wait_table_init@mm/page_alloc.c:4174").call
kernel.function("zone_watermark_ok@mm/page_alloc.c:1662").call
kernel.function("zone_watermark_ok_safe@mm/page_alloc.c:1669").call
kernel.function("zoneinfo_open@mm/vmstat.c:1087").call
kernel.function("zoneinfo_show@mm/vmstat.c:1072").call
kernel.function("zoneinfo_show_print@mm/vmstat.c:1006").call
====

Now, try to use the first one in a probe:

====
# stap -vp4 -e 'probe
kernel.function("zap_huge_pmd@mm/huge_memory.c:1412").call { printf("here\n")
}'
Pass 1: parsed user script and 105 library script(s) using
143884virt/28892res/3120shr/26140data kb, in 150usr/20sys/550real ms.
WARNING: For probing a particular line, use a .statement() probe, not
.function(): keyword at <input>:1:1
 source: probe kernel.function("zap_huge_pmd@mm/huge_memory.c:1412").call {
printf("here\n") }
         ^
semantic error: no line records for mm/huge_memory.c:1412 [man error::dwarf]
(try :1414)

semantic error: while resolving probe point: identifier 'kernel' at :1:7
        source: probe
kernel.function("zap_huge_pmd@mm/huge_memory.c:1412").call { printf("here\n") }
                      ^

semantic error: no match (similar functions: zap_huge_pmd, mk_huge_pmd,
copy_huge_pmd, move_huge_pmd, change_huge_pmd)

Pass 2: analyzed script: 0 probe(s), 0 function(s), 0 embed(s), 0 global(s)
using 159484virt/45176res/3928shr/41740data kb, in 160usr/50sys/1478real ms.
Pass 2: analysis failed.  [man error::pass2]
====

So, according to stap, zap_huge_pmd() doesn't exist at 1412. It might exist at
1414. Let's give that a shot:

====
stap -vp4 -e 'probe kernel.function("zap_huge_pmd@mm/huge_memory.c:1414").call
{ printf("here\n") }'
Pass 1: parsed user script and 105 library script(s) using
143884virt/28892res/3120shr/26140data kb, in 140usr/10sys/158real ms.
WARNING: For probing a particular line, use a .statement() probe, not
.function(): keyword at <input>:1:1
 source: probe kernel.function("zap_huge_pmd@mm/huge_memory.c:1414").call {
printf("here\n") }
         ^
Pass 2: analyzed script: 1 probe(s), 0 function(s), 0 embed(s), 0 global(s)
using 159884virt/45488res/3900shr/42140data kb, in 220usr/60sys/290real ms.
Pass 3: translated to C into
"/tmp/stap1FJc9E/stap_13688915453ad5ced72ffb549af941f4_1049_src.c" using
159884virt/45816res/4224shr/42140data kb, in 0usr/40sys/47real ms.
/root/.systemtap/cache/13/stap_13688915453ad5ced72ffb549af941f4_1049.ko
Pass 4: compiled C into "stap_13688915453ad5ced72ffb549af941f4_1049.ko" in
1110usr/170sys/1278real ms.
====

So, why didn't 'stap -l' tell me the function was at 1414 in the first place?

-- 
You are receiving this mail because:
You are the assignee for the bug.

[Bug translator/17190] 'stap -l' output not useful as stap input

[jlebon at redhat dot com]

https://sourceware.org/bugzilla/show_bug.cgi?id=17190

Jonathan Lebon <jlebon at redhat dot com> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
                 CC|                            |jlebon at redhat dot com

--- Comment #1 from Jonathan Lebon <jlebon at redhat dot com> ---
Hey David,

(In reply to David Smith from comment #0)
> So, why didn't 'stap -l' tell me the function was at 1414 in the first place?

This is because stap -l uses the declaration line of the function, rather than
the first valid probe-able lineno of the function. See also the comment block
in dwflpp::collect_lines_for_single_lineno():

  /* Here, we handle ABSOLUTE and RELATIVE lineno types. Relative line numbers
   * are a bit special. The issue is that functions (esp. inlined ones) may not
   * even have a LR corresponding to the first valid line of code. So, applying
   * an offset to the 'first' LR found in the DIE can be quite imprecise.
   *     Instead, we use decl_line, which although does not necessarily have a
   * LR associated with it (it can sometimes still happen esp. if the code is
   * written in OTB-style), it serves as an anchor on which we can apply the
   * offset to yield a lineno that will not change with compiler optimization.
   *     It also has the added benefit of being consistent with the lineno
   * printed by e.g. stap -l kernel.function("vfs_read"), so users can be
   * confident from what lineno we adjust.
   */

This means that e.g. in your example:

  kernel.function("zap_huge_pmd@mm/huge_memory.c:1412").call

The function was declared at lineno 1412, but the first valid lineno you can
probe is at 1414.

I'm thinking we could modify the current behaviour so that if the decl line is
given, simply silently adjust to the first valid lineno in the function. We can
also then squash the WARNING about using .statement() instead of .function().

-- 
You are receiving this mail because:
You are the assignee for the bug.

[Bug translator/17190] 'stap -l' output not useful as stap input

[jlebon at redhat dot com]

https://sourceware.org/bugzilla/show_bug.cgi?id=17190

Jonathan Lebon <jlebon at redhat dot com> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|NEW                         |RESOLVED
         Resolution|---                         |FIXED

--- Comment #2 from Jonathan Lebon <jlebon at redhat dot com> ---
This should now be fixed with commit c5142c6. For example:

$ stap -l 'kernel.function("z*@mm/*.c").call'
kernel.function("zap_huge_pmd@mm/huge_memory.c:1343").call
kernel.function("zap_page_range@mm/memory.c:1395").call
kernel.function("zap_page_range_single@mm/memory.c:1421").call
kernel.function("zap_vma_ptes@mm/memory.c:1449").call
kernel.function("zbud_alloc@mm/zbud.c:250").call
kernel.function("zbud_create_pool@mm/zbud.c:202").call
kernel.function("zbud_destroy_pool@mm/zbud.c:226").call
kernel.function("zbud_free@mm/zbud.c:326").call
kernel.function("zbud_get_pool_size@mm/zbud.c:504").call
kernel.function("zbud_map@mm/zbud.c:483").call
kernel.function("zbud_reclaim_page@mm/zbud.c:401").call
kernel.function("zbud_unmap@mm/zbud.c:493").call
kernel.function("zlc_zone_worth_trying@mm/page_alloc.c:1807").call
kernel.function("zone_absent_pages_in_node@mm/page_alloc.c:4611").call
kernel.function("zone_balanced@mm/vmscan.c:2779").call
kernel.function("zone_batchsize@mm/page_alloc.c:4123").call
kernel.function("zone_dirty_ok@mm/page-writeback.c:344").call
kernel.function("zone_pagecache_reclaimable@mm/vmscan.c:3531").call
kernel.function("zone_pcp_reset@mm/page_alloc.c:6424").call
kernel.function("zone_pcp_update@mm/page_alloc.c:6413").call
kernel.function("zone_reclaim@mm/vmscan.c:3642").call
kernel.function("zone_reclaimable@mm/vmscan.c:164").call
kernel.function("zone_reclaimable_pages@mm/vmscan.c:150").call
kernel.function("zone_spanned_pages_in_node@mm/page_alloc.c:4550").call
kernel.function("zone_statistics@mm/vmstat.c:557").call
kernel.function("zone_wait_table_init@mm/page_alloc.c:4279").call
kernel.function("zone_watermark_ok@mm/page_alloc.c:1723").call
kernel.function("zone_watermark_ok_safe@mm/page_alloc.c:1730").call
kernel.function("zoneinfo_open@mm/vmstat.c:1127").call
kernel.function("zoneinfo_show@mm/vmstat.c:1112").call
kernel.function("zoneinfo_show_print@mm/vmstat.c:1046").call
kernel.function("zs_cpu_notifier@mm/zsmalloc.c:786").call
kernel.function("zs_create_pool@mm/zsmalloc.c:859").call
kernel.function("zs_destroy_pool@mm/zsmalloc.c:891").call
kernel.function("zs_exit@mm/zsmalloc.c:813").call
kernel.function("zs_free@mm/zsmalloc.c:969").call
kernel.function("zs_get_total_size_bytes@mm/zsmalloc.c:1101").call
kernel.function("zs_init@mm/zsmalloc.c:826").call
kernel.function("zs_malloc@mm/zsmalloc.c:919").call
kernel.function("zs_map_object@mm/zsmalloc.c:1025").call
kernel.function("zs_unmap_object@mm/zsmalloc.c:1068").call
kernel.function("zswap_cpu_notifier@mm/zswap.c:376").call
kernel.function("zswap_entry_put@mm/zswap.c:307").call
kernel.function("zswap_free_entry@mm/zswap.c:290").call
kernel.function("zswap_frontswap_init@mm/zswap.c:818").call
kernel.function("zswap_frontswap_invalidate_area@mm/zswap.c:796").call
kernel.function("zswap_frontswap_invalidate_page@mm/zswap.c:772").call
kernel.function("zswap_frontswap_load@mm/zswap.c:734").call
kernel.function("zswap_frontswap_store@mm/zswap.c:635").call
kernel.function("zswap_writeback_entry@mm/zswap.c:528").call

Let's try the first line:

$ stap -l 'kernel.function("zap_huge_pmd@mm/huge_memory.c:1343").call'
kernel.function("zap_huge_pmd@mm/huge_memory.c:1343").call

-- 
You are receiving this mail because:
You are the assignee for the bug.