Re: perf report segfault

Re: perf report segfault

[Jiri Olsa]

On Tue, Oct 09, 2018 at 11:27:04AM -0500, Anthony LaTorre wrote:
> Hi,
> 
> I'm currently running Linux kernel 4.18.10-100.fc27.x86_64 and have a
> problem profiling a program that used to work. Currently when I
> profile the program with the following command:
> 
> $ perf record -F 99 -p PID --call-graph dwarf sleep 10
> 
> it produces a data file which causes perf report to segfault:
> 
> $ perf report
> perf: Segmentation fault
> -------- backtrace --------
> perf(+0x325302)[0x55860ae79302]
> /lib64/libc.so.6(+0x347d0)[0x7fbc8f3987d0]
> perf(+0x273e80)[0x55860adc7e80]
> perf(unwind__get_entries+0x1d9)[0x55860ae4ace9]
> perf(thread__resolve_callchain+0xfd)[0x55860adce7dd]
> perf(sample__resolve_callchain+0x58)[0x55860adc45b8]
> perf(hist_entry_iter__add+0x98)[0x55860adfa908]
> perf(+0x1ab8d9)[0x55860acff8d9]
> perf(+0x280603)[0x55860add4603]
> perf(+0x283c63)[0x55860add7c63]
> perf(+0x280e04)[0x55860add4e04]
> perf(perf_session__process_events+0x8ae)[0x55860add6bee]
> perf(cmd_report+0x190f)[0x55860ad01a4f]
> perf(+0x21a961)[0x55860ad6e961]
> perf(+0x21ac6e)[0x55860ad6ec6e]
> perf(main+0x361)[0x55860ace8411]
> /lib64/libc.so.6(__libc_start_main+0xea)[0x7fbc8f384fea]
> perf(_start+0x2a)[0x55860ace889a]
> 
> I've attached the data file which is causing the issue.
> 
> The perf version is:
> 
> $ perf --version
> perf version 4.18.10
> 
> and I'm running Fedora 27 if that makes a difference.
> 
> I've tried to reproduce with simpler programs so I could send a
> minimal working example, but it doesn't appear to cause the issue.

please do, I can't reproduce this

thanks,
jirka

Re: perf report segfault

[Anthony LaTorre]

Can you reproduce the segfault from the perf.data file I provided?

Tony
On Tue, Oct 9, 2018 at 11:47 AM Jiri Olsa <jolsa@redhat.com> wrote:
>
> On Tue, Oct 09, 2018 at 11:27:04AM -0500, Anthony LaTorre wrote:
> > Hi,
> >
> > I'm currently running Linux kernel 4.18.10-100.fc27.x86_64 and have a
> > problem profiling a program that used to work. Currently when I
> > profile the program with the following command:
> >
> > $ perf record -F 99 -p PID --call-graph dwarf sleep 10
> >
> > it produces a data file which causes perf report to segfault:
> >
> > $ perf report
> > perf: Segmentation fault
> > -------- backtrace --------
> > perf(+0x325302)[0x55860ae79302]
> > /lib64/libc.so.6(+0x347d0)[0x7fbc8f3987d0]
> > perf(+0x273e80)[0x55860adc7e80]
> > perf(unwind__get_entries+0x1d9)[0x55860ae4ace9]
> > perf(thread__resolve_callchain+0xfd)[0x55860adce7dd]
> > perf(sample__resolve_callchain+0x58)[0x55860adc45b8]
> > perf(hist_entry_iter__add+0x98)[0x55860adfa908]
> > perf(+0x1ab8d9)[0x55860acff8d9]
> > perf(+0x280603)[0x55860add4603]
> > perf(+0x283c63)[0x55860add7c63]
> > perf(+0x280e04)[0x55860add4e04]
> > perf(perf_session__process_events+0x8ae)[0x55860add6bee]
> > perf(cmd_report+0x190f)[0x55860ad01a4f]
> > perf(+0x21a961)[0x55860ad6e961]
> > perf(+0x21ac6e)[0x55860ad6ec6e]
> > perf(main+0x361)[0x55860ace8411]
> > /lib64/libc.so.6(__libc_start_main+0xea)[0x7fbc8f384fea]
> > perf(_start+0x2a)[0x55860ace889a]
> >
> > I've attached the data file which is causing the issue.
> >
> > The perf version is:
> >
> > $ perf --version
> > perf version 4.18.10
> >
> > and I'm running Fedora 27 if that makes a difference.
> >
> > I've tried to reproduce with simpler programs so I could send a
> > minimal working example, but it doesn't appear to cause the issue.
>
> please do, I can't reproduce this
>
> thanks,
> jirka

Re: perf report segfault

[Anthony LaTorre]

Ok, I can reliably reproduce it by profiling the following program:

#include <math.h>

int main(int argc, char **argv)
{
    int i;
    double sum;

    while (1) {
        sum += exp(++i);
    }

    return 0;
}

compiled with:

$ cc -o test test.c -lm

with the following command:

$ perf record -F 99 -p 20016 --call-graph dwarf sleep 10

Tony
On Tue, Oct 9, 2018 at 1:54 PM Anthony LaTorre <tlatorre9@gmail.com> wrote:
>
> Can you reproduce the segfault from the perf.data file I provided?
>
> Tony
> On Tue, Oct 9, 2018 at 11:47 AM Jiri Olsa <jolsa@redhat.com> wrote:
> >
> > On Tue, Oct 09, 2018 at 11:27:04AM -0500, Anthony LaTorre wrote:
> > > Hi,
> > >
> > > I'm currently running Linux kernel 4.18.10-100.fc27.x86_64 and have a
> > > problem profiling a program that used to work. Currently when I
> > > profile the program with the following command:
> > >
> > > $ perf record -F 99 -p PID --call-graph dwarf sleep 10
> > >
> > > it produces a data file which causes perf report to segfault:
> > >
> > > $ perf report
> > > perf: Segmentation fault
> > > -------- backtrace --------
> > > perf(+0x325302)[0x55860ae79302]
> > > /lib64/libc.so.6(+0x347d0)[0x7fbc8f3987d0]
> > > perf(+0x273e80)[0x55860adc7e80]
> > > perf(unwind__get_entries+0x1d9)[0x55860ae4ace9]
> > > perf(thread__resolve_callchain+0xfd)[0x55860adce7dd]
> > > perf(sample__resolve_callchain+0x58)[0x55860adc45b8]
> > > perf(hist_entry_iter__add+0x98)[0x55860adfa908]
> > > perf(+0x1ab8d9)[0x55860acff8d9]
> > > perf(+0x280603)[0x55860add4603]
> > > perf(+0x283c63)[0x55860add7c63]
> > > perf(+0x280e04)[0x55860add4e04]
> > > perf(perf_session__process_events+0x8ae)[0x55860add6bee]
> > > perf(cmd_report+0x190f)[0x55860ad01a4f]
> > > perf(+0x21a961)[0x55860ad6e961]
> > > perf(+0x21ac6e)[0x55860ad6ec6e]
> > > perf(main+0x361)[0x55860ace8411]
> > > /lib64/libc.so.6(__libc_start_main+0xea)[0x7fbc8f384fea]
> > > perf(_start+0x2a)[0x55860ace889a]
> > >
> > > I've attached the data file which is causing the issue.
> > >
> > > The perf version is:
> > >
> > > $ perf --version
> > > perf version 4.18.10
> > >
> > > and I'm running Fedora 27 if that makes a difference.
> > >
> > > I've tried to reproduce with simpler programs so I could send a
> > > minimal working example, but it doesn't appear to cause the issue.
> >
> > please do, I can't reproduce this
> >
> > thanks,
> > jirka

Re: perf report segfault

[Jiri Olsa]

On Tue, Oct 09, 2018 at 01:54:48PM -0500, Anthony LaTorre wrote:
> Can you reproduce the segfault from the perf.data file I provided?

nope, but if it's dwarf callchain related I'd need perf archive
output to reproduce.. please run:

---
  $ perf record ...
  $ perf archive
  Now please run:

  $ tar xvf perf.data.tar.bz2 -C ~/.debug

  wherever you need to run 'perf report' on.
  $
---

and send/publish both perf.data and perf.data.tar.bz2 files

thanks,
jirka

Re: perf report segfault

[Jiri Olsa]

On Tue, Oct 09, 2018 at 03:18:12PM -0500, Anthony LaTorre wrote:
> Ok, I can reliably reproduce it by profiling the following program:
> 
> #include <math.h>
> 
> int main(int argc, char **argv)
> {
>     int i;
>     double sum;
> 
>     while (1) {
>         sum += exp(++i);
>     }
> 
>     return 0;
> }
> 
> compiled with:
> 
> $ cc -o test test.c -lm
> 
> with the following command:
> 
> $ perf record -F 99 -p 20016 --call-graph dwarf sleep 10

still nothing.. any chance you could try on latest perf sources?

	$ git clone git://git.kernel.org/pub/scm/linux/kernel/git/acme/linux.git
	$ cd linux
	$ git checkout -b perf/core origin/perf/core
	$ cd tools/perf
	$ make
	$ ./perf ...

you might need some packages mentioned in (search for 'yum install'):
  https://perf.wiki.kernel.org/index.php/Jolsa_Howto_Install_Sources

it's little outdated, but the packages lists will do

thanks,
jirka

Re: perf report segfault

[Anthony LaTorre]

Ok, I tried it with the version compiled from the latest sources and I
don't get the segfault, so it must be an issue with the version
distributed with Fedora 27.

Tony
On Tue, Oct 9, 2018 at 4:47 PM Anthony LaTorre <tlatorre9@gmail.com> wrote:
>
> I can try building perf from the latest sources. I've attached the
> perf.data and perf.data.tar.bz2 from the test program I sent earlier.
> On Tue, Oct 9, 2018 at 4:42 PM Jiri Olsa <jolsa@redhat.com> wrote:
> >
> > On Tue, Oct 09, 2018 at 03:18:12PM -0500, Anthony LaTorre wrote:
> > > Ok, I can reliably reproduce it by profiling the following program:
> > >
> > > #include <math.h>
> > >
> > > int main(int argc, char **argv)
> > > {
> > >     int i;
> > >     double sum;
> > >
> > >     while (1) {
> > >         sum += exp(++i);
> > >     }
> > >
> > >     return 0;
> > > }
> > >
> > > compiled with:
> > >
> > > $ cc -o test test.c -lm
> > >
> > > with the following command:
> > >
> > > $ perf record -F 99 -p 20016 --call-graph dwarf sleep 10
> >
> > still nothing.. any chance you could try on latest perf sources?
> >
> >         $ git clone git://git.kernel.org/pub/scm/linux/kernel/git/acme/linux.git
> >         $ cd linux
> >         $ git checkout -b perf/core origin/perf/core
> >         $ cd tools/perf
> >         $ make
> >         $ ./perf ...
> >
> > you might need some packages mentioned in (search for 'yum install'):
> >   https://perf.wiki.kernel.org/index.php/Jolsa_Howto_Install_Sources
> >
> > it's little outdated, but the packages lists will do
> >
> > thanks,
> > jirka

Re: perf report segfault

[Jiri Olsa]

On Tue, Oct 09, 2018 at 04:47:31PM -0500, Anthony LaTorre wrote:
> I can try building perf from the latest sources. I've attached the
> perf.data and perf.data.tar.bz2 from the test program I sent earlier.

cool, reproduced.. it seems to get introduced by:
  2a9d5050dc84 perf script: Show correct offsets for DWARF-based unwinding

reverting that patch fixes the issue for me, but looks like
we could just make th attached check and prevent the crash

adding Sandipan Das to the loop, the author of that commit, any idea?

thanks,
jirka


---
diff --git a/tools/perf/util/machine.c b/tools/perf/util/machine.c
index c4acd2001db0..ea68c805c7ac 100644
--- a/tools/perf/util/machine.c
+++ b/tools/perf/util/machine.c
@@ -2312,7 +2312,6 @@ static int unwind_entry(struct unwind_entry *entry, void *arg)
 {
 	struct callchain_cursor *cursor = arg;
 	const char *srcline = NULL;
-	u64 addr;
 
 	if (symbol_conf.hide_unresolved && entry->sym == NULL)
 		return 0;
@@ -2320,13 +2319,15 @@ static int unwind_entry(struct unwind_entry *entry, void *arg)
 	if (append_inlines(cursor, entry->map, entry->sym, entry->ip) == 0)
 		return 0;
 
-	/*
-	 * Convert entry->ip from a virtual address to an offset in
-	 * its corresponding binary.
-	 */
-	addr = map__map_ip(entry->map, entry->ip);
+	if (entry->map) {
+		/*
+		 * Convert entry->ip from a virtual address to an offset in
+		 * its corresponding binary.
+		 */
+		u64 addr = map__map_ip(entry->map, entry->ip);
+		srcline = callchain_srcline(entry->map, entry->sym, addr);
+	}
 
-	srcline = callchain_srcline(entry->map, entry->sym, addr);
 	return callchain_cursor_append(cursor, entry->ip,
 				       entry->map, entry->sym,
 				       false, NULL, 0, 0, 0, srcline);

Re: perf report segfault

[Sandipan Das]

Hi Jiri,

Yes, this happens when entry->map is NULL. While your fix seems correct, the
following commit from Milian Wolff had already addressed this. I think this
was pulled in with one of Arnaldo's recent perf/urgent updates.

ff4ce2885af8 ("perf report: Don't try to map ip to invalid map")

Adding Milian to the loop as well.

With Regards,
Sandipan

On 10/10/18 3:50 AM, Jiri Olsa wrote:
> On Tue, Oct 09, 2018 at 04:47:31PM -0500, Anthony LaTorre wrote:
>> I can try building perf from the latest sources. I've attached the
>> perf.data and perf.data.tar.bz2 from the test program I sent earlier.
> 
> cool, reproduced.. it seems to get introduced by:
>   2a9d5050dc84 perf script: Show correct offsets for DWARF-based unwinding
> 
> reverting that patch fixes the issue for me, but looks like
> we could just make th attached check and prevent the crash
> 
> adding Sandipan Das to the loop, the author of that commit, any idea?
> 
> thanks,
> jirka
> 
> 
> ---
> diff --git a/tools/perf/util/machine.c b/tools/perf/util/machine.c
> index c4acd2001db0..ea68c805c7ac 100644
> --- a/tools/perf/util/machine.c
> +++ b/tools/perf/util/machine.c
> @@ -2312,7 +2312,6 @@ static int unwind_entry(struct unwind_entry *entry, void *arg)
>  {
>  	struct callchain_cursor *cursor = arg;
>  	const char *srcline = NULL;
> -	u64 addr;
>  
>  	if (symbol_conf.hide_unresolved && entry->sym == NULL)
>  		return 0;
> @@ -2320,13 +2319,15 @@ static int unwind_entry(struct unwind_entry *entry, void *arg)
>  	if (append_inlines(cursor, entry->map, entry->sym, entry->ip) == 0)
>  		return 0;
>  
> -	/*
> -	 * Convert entry->ip from a virtual address to an offset in
> -	 * its corresponding binary.
> -	 */
> -	addr = map__map_ip(entry->map, entry->ip);
> +	if (entry->map) {
> +		/*
> +		 * Convert entry->ip from a virtual address to an offset in
> +		 * its corresponding binary.
> +		 */
> +		u64 addr = map__map_ip(entry->map, entry->ip);
> +		srcline = callchain_srcline(entry->map, entry->sym, addr);
> +	}
>  
> -	srcline = callchain_srcline(entry->map, entry->sym, addr);
>  	return callchain_cursor_append(cursor, entry->ip,
>  				       entry->map, entry->sym,
>  				       false, NULL, 0, 0, 0, srcline);
> 

Re: perf report segfault

[Ingo Molnar]

* Sandipan Das <sandipan@linux.ibm.com> wrote:

> Hi Jiri,
> 
> Yes, this happens when entry->map is NULL. While your fix seems correct, the
> following commit from Milian Wolff had already addressed this. I think this
> was pulled in with one of Arnaldo's recent perf/urgent updates.
> 
> ff4ce2885af8 ("perf report: Don't try to map ip to invalid map")

Ok, I'll send the pending perf/urgent tooling bits to Greg/Linus later today,
to make sure this is fixed upstream as well.

Thanks,

	Ingo

Re: perf report segfault

[Jiri Olsa]

On Wed, Oct 10, 2018 at 11:13:47AM +0530, Sandipan Das wrote:
> Hi Jiri,
> 
> Yes, this happens when entry->map is NULL. While your fix seems correct, the
> following commit from Milian Wolff had already addressed this. I think this
> was pulled in with one of Arnaldo's recent perf/urgent updates.
> 
> ff4ce2885af8 ("perf report: Don't try to map ip to invalid map")
> 
> Adding Milian to the loop as well.

yea.. I knew I saw that code just recently ;-)

thanks,
jirka

> 
> With Regards,
> Sandipan
> 
> On 10/10/18 3:50 AM, Jiri Olsa wrote:
> > On Tue, Oct 09, 2018 at 04:47:31PM -0500, Anthony LaTorre wrote:
> >> I can try building perf from the latest sources. I've attached the
> >> perf.data and perf.data.tar.bz2 from the test program I sent earlier.
> > 
> > cool, reproduced.. it seems to get introduced by:
> >   2a9d5050dc84 perf script: Show correct offsets for DWARF-based unwinding
> > 
> > reverting that patch fixes the issue for me, but looks like
> > we could just make th attached check and prevent the crash
> > 
> > adding Sandipan Das to the loop, the author of that commit, any idea?
> > 
> > thanks,
> > jirka
> > 
> > 
> > ---
> > diff --git a/tools/perf/util/machine.c b/tools/perf/util/machine.c
> > index c4acd2001db0..ea68c805c7ac 100644
> > --- a/tools/perf/util/machine.c
> > +++ b/tools/perf/util/machine.c
> > @@ -2312,7 +2312,6 @@ static int unwind_entry(struct unwind_entry *entry, void *arg)
> >  {
> >  	struct callchain_cursor *cursor = arg;
> >  	const char *srcline = NULL;
> > -	u64 addr;
> >  
> >  	if (symbol_conf.hide_unresolved && entry->sym == NULL)
> >  		return 0;
> > @@ -2320,13 +2319,15 @@ static int unwind_entry(struct unwind_entry *entry, void *arg)
> >  	if (append_inlines(cursor, entry->map, entry->sym, entry->ip) == 0)
> >  		return 0;
> >  
> > -	/*
> > -	 * Convert entry->ip from a virtual address to an offset in
> > -	 * its corresponding binary.
> > -	 */
> > -	addr = map__map_ip(entry->map, entry->ip);
> > +	if (entry->map) {
> > +		/*
> > +		 * Convert entry->ip from a virtual address to an offset in
> > +		 * its corresponding binary.
> > +		 */
> > +		u64 addr = map__map_ip(entry->map, entry->ip);
> > +		srcline = callchain_srcline(entry->map, entry->sym, addr);
> > +	}
> >  
> > -	srcline = callchain_srcline(entry->map, entry->sym, addr);
> >  	return callchain_cursor_append(cursor, entry->ip,
> >  				       entry->map, entry->sym,
> >  				       false, NULL, 0, 0, 0, srcline);
> > 
> 

Re: perf report segfault

[Arnaldo Carvalho de Melo]

Em Wed, Oct 10, 2018 at 12:20:04AM +0200, Jiri Olsa escreveu:
> On Tue, Oct 09, 2018 at 04:47:31PM -0500, Anthony LaTorre wrote:
> > I can try building perf from the latest sources. I've attached the
> > perf.data and perf.data.tar.bz2 from the test program I sent earlier.
> 
> cool, reproduced.. it seems to get introduced by:
>   2a9d5050dc84 perf script: Show correct offsets for DWARF-based unwinding
> 
> reverting that patch fixes the issue for me, but looks like
> we could just make th attached check and prevent the crash
> 
> adding Sandipan Das to the loop, the author of that commit, any idea?

commit ff4ce2885af8f9e8e99864d78dbeb4673f089c76
Author: Milian Wolff <milian.wolff@kdab.com>
Date:   Wed Sep 26 15:52:05 2018 +0200

    perf report: Don't try to map ip to invalid map
    
    Fixes a crash when the report encounters an address that could not be
    associated with an mmaped region:
    
      #0  0x00005555557bdc4a in callchain_srcline (ip=<error reading variable: Cannot access memory at address 0x38>, sym=0x0, map=0x0) at util/machine.c:2329
      #1  unwind_entry (entry=entry@entry=0x7fffffff9180, arg=arg@entry=0x7ffff5642498) at util/machine.c:2329
      #2  0x00005555558370af in entry (arg=0x7ffff5642498, cb=0x5555557bdb50 <unwind_entry>, thread=<optimized out>, ip=18446744073709551615) at util/unwind-libunwind-local.c:586
      #3  get_entries (ui=ui@entry=0x7fffffff9620, cb=0x5555557bdb50 <unwind_entry>, arg=0x7ffff5642498, max_stack=<optimized out>) at util/unwind-libunwind-local.c:703
      #4  0x0000555555837192 in _unwind__get_entries (cb=<optimized out>, arg=<optimized out>, thread=<optimized out>, data=<optimized out>, max_stack=<optimized out>) at util/unwind-libunwind-
local.c:725
      #5  0x00005555557c310f in thread__resolve_callchain_unwind (max_stack=127, sample=0x7fffffff9830, evsel=0x555555c7b3b0, cursor=0x7ffff5642498, thread=0x555555c7f6f0) at util/machine.c:235
1
      #6  thread__resolve_callchain (thread=0x555555c7f6f0, cursor=0x7ffff5642498, evsel=0x555555c7b3b0, sample=0x7fffffff9830, parent=0x7fffffff97b8, root_al=0x7fffffff9750, max_stack=127) at 
util/machine.c:2378
      #7  0x00005555557ba4ee in sample__resolve_callchain (sample=<optimized out>, cursor=<optimized out>, parent=parent@entry=0x7fffffff97b8, evsel=<optimized out>, al=al@entry=0x7fffffff9750,
          max_stack=<optimized out>) at util/callchain.c:1085
    
    Signed-off-by: Milian Wolff <milian.wolff@kdab.com>
    Tested-by: Sandipan Das <sandipan@linux.ibm.com>
    Acked-by: Jiri Olsa <jolsa@kernel.org>
    Cc: Jin Yao <yao.jin@linux.intel.com>
    Cc: Namhyung Kim <namhyung@kernel.org>
    Fixes: 2a9d5050dc84 ("perf script: Show correct offsets for DWARF-based unwinding")
    Link: http://lkml.kernel.org/r/20180926135207.30263-1-milian.wolff@kdab.com
    Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>