lists.openwall.net   lists  /  announce  owl-users  owl-dev  john-users  john-dev  passwdqc-users  yescrypt  popa3d-users  /  oss-security  kernel-hardening  musl  sabotage  tlsify  passwords  /  crypt-dev  xvendor  /  Bugtraq  Full-Disclosure  linux-kernel  linux-netdev  linux-ext4  linux-hardening  linux-cve-announce  PHC 
Open Source and information security mailing list archives
 
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [<thread-prev] [day] [month] [year] [list]
Message-ID: <20200403175902.GA18789@5f9ad775e7f6>
Date:   Fri, 3 Apr 2020 17:59:04 +0000
From:   Daniel Shaulov <daniel.shaulov@...il.com>
To:     Arnaldo Carvalho de Melo <arnaldo.melo@...il.com>
Cc:     Daniel Shaulov <daniel.shaulov@...nulate.io>,
        Peter Zijlstra <peterz@...radead.org>,
        Ingo Molnar <mingo@...hat.com>,
        Mark Rutland <mark.rutland@....com>,
        Alexander Shishkin <alexander.shishkin@...ux.intel.com>,
        Jiri Olsa <jolsa@...hat.com>,
        Namhyung Kim <namhyung@...nel.org>,
        Masami Hiramatsu <mhiramat@...nel.org>,
        Thomas Gleixner <tglx@...utronix.de>,
        Greg Kroah-Hartman <gregkh@...uxfoundation.org>,
        Thomas Richter <tmricht@...ux.ibm.com>,
        linux-kernel@...r.kernel.org
Subject: Re: [PATCH] perf probe: Add support for DW_OP_call_frame_cfa vars

On Fri, Apr 03, 2020 at 10:02:51AM -0300, Arnaldo Carvalho de Melo wrote:
> Em Thu, Apr 02, 2020 at 08:25:24PM +0000, Daniel Shaulov escreveu:
> > On Thu, Apr 02, 2020 at 03:49:43PM -0300, Arnaldo Carvalho de Melo wrote:
> > > Daniel, next time please consider providing precise steps to show what
> > > wasn't working and then how the patch solves the problem, i.e. get some
> > > go program, show the command lines used to build, probe, etc.
> > >
> > > - Arnaldo
> > 
> > Sure thing:
> > 
> > ---- contents of example.go ----
> > package main
> > 
> > import "fmt"
> > 
> > func example(param1 int, param2 int) {
> > 	fmt.Println(param1, param2)
> > }
> > 
> > func main() {
> > 	example(111, 222)
> > }
> > ---- end contents of example.go ----
> > 
> > Build with:
> > $ go build example.go
> > 
> > Note that the output file is named after the directory.
> > 
> > Then try to probe it with:
> > $ perf probe -x ./example 'main.example param1 param2'
> > 
> > The result is:
> > > Target program is compiled without optimization. Skipping prologue.
> > > Probe on address 0x4820f0 to force probing at the function entry.
> > >
> > > Sorry, we don't support this variable location yet.
> > >   Error: Failed to add events.
> > 
> > With my changes the event is added successfuly.
> > The reason for the change can be observed in the output of:
> > $ readelf --debug-dump=info ./example
> > 
> > Where we have the following for the main.example function (with go >= 1.10):
> >  <1><63dd2>: Abbrev Number: 2 (DW_TAG_subprogram)
> >     <63dd3>   DW_AT_name        : main.example
> >     <63de0>   DW_AT_low_pc      : 0x4820f0
> >     <63de8>   DW_AT_high_pc     : 0x4821c2
> >     <63df0>   DW_AT_frame_base  : 1 byte block: 9c 	(DW_OP_call_frame_cfa)
> >     <63df2>   DW_AT_decl_file   : 0x1
> >     <63df6>   DW_AT_external    : 1
> >  <2><63df7>: Abbrev Number: 14 (DW_TAG_formal_parameter)
> >     <63df8>   DW_AT_name        : param1
> >     <63dff>   DW_AT_variable_parameter: 0
> >     <63e00>   DW_AT_decl_line   : 5
> >     <63e01>   DW_AT_type        : <0x220f>
> >     <63e05>   DW_AT_location    : 1 byte block: 9c 	(DW_OP_call_frame_cfa)
> >  <2><63e07>: Abbrev Number: 14 (DW_TAG_formal_parameter)
> >     <63e08>   DW_AT_name        : param2
> >     <63e0f>   DW_AT_variable_parameter: 0
> >     <63e10>   DW_AT_decl_line   : 5
> >     <63e11>   DW_AT_type        : <0x220f>
> >     <63e15>   DW_AT_location    : 2 byte block: 91 8 	(DW_OP_fbreg: 8)
> >  <2><63e18>: Abbrev Number: 0
>  
> > The go compiler (after 1.10) uses DW_OP_call_frame_cfa for the first parameter and DW_OP_fbreg for the rest.
> > On go versions lower than 1.10, it used DW_OP_call_frame_cfa for all parameters.
> > Here is example output of the readelf on main.example, compiled with go1.9.7:
> >  <1><2634d>: Abbrev Number: 2 (DW_TAG_subprogram)
> >     <2634e>   DW_AT_name        : main.example
> >     <2635b>   DW_AT_low_pc      : 0x487db0
> >     <26363>   DW_AT_high_pc     : 0x487e99
> >     <2636b>   DW_AT_frame_base  : 1 byte block: 9c 	(DW_OP_call_frame_cfa)
> >     <2636d>   DW_AT_external    : 1
> >  <2><2636e>: Abbrev Number: 5 (DW_TAG_formal_parameter)
> >     <2636f>   DW_AT_name        : param1
> >     <26376>   DW_AT_location    : 1 byte block: 9c 	(DW_OP_call_frame_cfa)
> >     <26378>   DW_AT_type        : <0x27f1c>
> >  <2><2637c>: Abbrev Number: 5 (DW_TAG_formal_parameter)
> >     <2637d>   DW_AT_name        : param2
> >     <26384>   DW_AT_location    : 4 byte block: 9c 11 8 22 	(DW_OP_call_frame_cfa; DW_OP_consts: 8; DW_OP_plus)
> >     <26389>   DW_AT_type        : <0x27f1c>
> >  <2><2638d>: Abbrev Number: 0
> > 
> > Hope this makes things easier to understand.
> 
> Right, but I tried following your instructions here and got up to this:
> 
>  <0><76ded>: Abbrev Number: 1 (DW_TAG_compile_unit)
>     <76dee>   DW_AT_name        : main
>     <76df3>   DW_AT_language    : 22    (Go)
>     <76df4>   DW_AT_stmt_list   : 0x27a7d
>     <76df8>   DW_AT_low_pc      : 0x48cd90
>     <76e00>   DW_AT_ranges      : 0x2e0
>     <76e04>   DW_AT_comp_dir    : .
>     <76e06>   DW_AT_producer    : Go cmd/compile go1.13.6
>     <76e1e>   Unknown AT value: 2905: main
>  <1><76e23>: Abbrev Number: 4 (DW_TAG_subprogram)
>     <76e24>   DW_AT_name        : main.example
>     <76e31>   DW_AT_inline      : 1     (inlined)
>     <76e32>   DW_AT_external    : 1
>  <2><76e33>: Abbrev Number: 17 (DW_TAG_formal_parameter)
>     <76e34>   DW_AT_name        : param1
>     <76e3b>   DW_AT_variable_parameter: 0
>     <76e3c>   DW_AT_type        : <0x37430>
>  <2><76e40>: Abbrev Number: 17 (DW_TAG_formal_parameter)
>     <76e41>   DW_AT_name        : param2
>     <76e48>   DW_AT_variable_parameter: 0
>     <76e49>   DW_AT_type        : <0x37430>
>  <2><76e4d>: Abbrev Number: 0
> 
> 
> Which, with or without your patch ends with:
> 
> [acme@...e daniel.shaulov@...il.com]$ perf probe -x ./example 'main.example param1 param2'
> Failed to find 'param1' in this function.
> Probe point 'main.example' not found.
>   Error: Failed to add events.
> [acme@...e daniel.shaulov@...il.com]$
> 
> [acme@...e perf]$ rpm -q golang-bin
> golang-bin-1.13.6-1.fc31.x86_64
> [acme@...e perf]$ cat /etc/fedora-release
> Fedora release 31 (Thirty One)
> [acme@...e perf]$
> 
> Has the behaviour changed again in 1.13? Or is this some optimization
> level that fedora sets that ends up auto-inlining that main.example
> routine?
> 
> [acme@...e daniel.shaulov@...il.com]$ readelf --debug-dump=info ./example | grep main\.example -B10 -A13
>  <0><76ded>: Abbrev Number: 1 (DW_TAG_compile_unit)
>     <76dee>   DW_AT_name        : main
>     <76df3>   DW_AT_language    : 22	(Go)
>     <76df4>   DW_AT_stmt_list   : 0x27a7d
>     <76df8>   DW_AT_low_pc      : 0x48cd90
>     <76e00>   DW_AT_ranges      : 0x2e0
>     <76e04>   DW_AT_comp_dir    : .
>     <76e06>   DW_AT_producer    : Go cmd/compile go1.13.6
>     <76e1e>   Unknown AT value: 2905: main
>  <1><76e23>: Abbrev Number: 4 (DW_TAG_subprogram)
>     <76e24>   DW_AT_name        : main.example
>     <76e31>   DW_AT_inline      : 1	(inlined)
>     <76e32>   DW_AT_external    : 1
>  <2><76e33>: Abbrev Number: 17 (DW_TAG_formal_parameter)
>     <76e34>   DW_AT_name        : param1
>     <76e3b>   DW_AT_variable_parameter: 0
>     <76e3c>   DW_AT_type        : <0x37430>
>  <2><76e40>: Abbrev Number: 17 (DW_TAG_formal_parameter)
>     <76e41>   DW_AT_name        : param2
>     <76e48>   DW_AT_variable_parameter: 0
>     <76e49>   DW_AT_type        : <0x37430>
>  <2><76e4d>: Abbrev Number: 0
>  <1><76e4e>: Abbrev Number: 4 (DW_TAG_subprogram)
>     <76e4f>   DW_AT_name        : fmt.Println
> [acme@...e daniel.shaulov@...il.com]$
> 
> - Arnaldo

Ok, so I looked into it a little bit.
I was using go1.10.4 (that's the one in Ubuntu 18.04 repo)

Apperantly they improved inlining in go1.12
https://golang.org/doc/go1.12#compiler
> More functions are now eligible for inlining by default,
> including functions that do nothing but call another function.

I added "//go:noinline" to the example function and it works in go1.12 and go1.13.6
---- contents of example.go ----
package main

import "fmt"

//go:noinline
func example(param1 int, param2 int) {
	fmt.Println(param1, param2)
}

func main() {
	example(111, 222)
}
---- end contents of example.go ----

There were some other changes to the dwarf output and in 1.13.6 with "//go:noinline" it looks like this:
$ readelf --debug-dump=info ./example | grep main\.example -A17
 <1><76e8f>: Abbrev Number: 3 (DW_TAG_subprogram)
    <76e90>   DW_AT_name        : main.example
    <76e9d>   DW_AT_low_pc      : 0x48ce90
    <76ea5>   DW_AT_high_pc     : 0x48cf58
    <76ead>   DW_AT_frame_base  : 1 byte block: 9c      (DW_OP_call_frame_cfa)
    <76eaf>   DW_AT_decl_file   : 0x1
    <76eb3>   DW_AT_external    : 1
 <2><76eb4>: Abbrev Number: 16 (DW_TAG_formal_parameter)
    <76eb5>   DW_AT_name        : param1
    <76ebc>   DW_AT_variable_parameter: 0
    <76ebd>   DW_AT_decl_line   : 6
    <76ebe>   DW_AT_type        : <0x37472>
    <76ec2>   DW_AT_location    : 0x7cd57 (location list)
 <2><76ec6>: Abbrev Number: 16 (DW_TAG_formal_parameter)
    <76ec7>   DW_AT_name        : param2
    <76ece>   DW_AT_variable_parameter: 0
    <76ecf>   DW_AT_decl_line   : 6
    <76ed0>   DW_AT_type        : <0x37472>
    <76ed4>   DW_AT_location    : 0x7cd8a (location list)

The "0x7cd57 (location list)" can be read with another readelf:
$ readelf --debug-dump=loc ./example | grep 7cd57 -A5
    0007cd57 ffffffffffffffff 000000000048ce90 (base address)
    0007cd67 000000000048ce90 000000000048cf58 (DW_OP_call_frame_cfa)
    0007cd7a <End of list>
    0007cd8a ffffffffffffffff 000000000048ce90 (base address)
    0007cd9a 000000000048ce90 000000000048cf58 (DW_OP_fbreg: 8)
    0007cdae <End of list>

So it is basically the same as what I was getting with go1.10, but with a deref in the way.
I guess dwarf_getlocation_addr abstracts the difference away since my code still works.

Note - in go1.11, I think there was some bug, because it shows up like this in readelf:
 <1><72a95>: Abbrev Number: 2 (DW_TAG_subprogram)
    <72a96>   DW_AT_name        : main.example
    <72aa3>   DW_AT_low_pc      : 0x4850b0
    <72aab>   DW_AT_high_pc     : 0x48516e
    <72ab3>   DW_AT_frame_base  : 1 byte block: 9c      (DW_OP_call_frame_cfa)
    <72ab5>   DW_AT_decl_file   : 0x1
    <72ab9>   DW_AT_external    : 1
 <2><72aba>: Abbrev Number: 14 (DW_TAG_formal_parameter)
    <72abb>   DW_AT_name        : param1
    <72ac2>   DW_AT_variable_parameter: 0
    <72ac3>   DW_AT_decl_line   : 6
    <72ac4>   DW_AT_type        : <0x3118>
    <72ac8>   DW_AT_location    : 0 byte block:         ()
 <2><72ac9>: Abbrev Number: 14 (DW_TAG_formal_parameter)
    <72aca>   DW_AT_name        : param2
    <72ad1>   DW_AT_variable_parameter: 0
    <72ad2>   DW_AT_decl_line   : 6
    <72ad3>   DW_AT_type        : <0x3118>
    <72ad7>   DW_AT_location    : 0 byte block:         ()
 <2><72ad8>: Abbrev Number: 0

And perf has no way to find the parameters (DW_AT_location is empty).

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ