Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]


Groups > linux.kernel > #1327217 > unrolled thread

Re: [PATCH v8 2/4] perf inject: add jitdump mmap injection support

Started byArnaldo Carvalho de Melo <acme@kernel.org>
First post2016-02-04 23:00 +0100
Last post2016-02-08 20:00 +0100
Articles 7 — 2 participants

Back to article view | Back to linux.kernel

This discussion starts older than the indexed window; earlier articles aren't shown. The article labeled Started by below is the oldest one visible, not the original post.


Contents

  Re: [PATCH v8 2/4] perf inject: add jitdump mmap injection support Arnaldo Carvalho de Melo <acme@kernel.org> - 2016-02-04 23:00 +0100
    Re: [PATCH v8 2/4] perf inject: add jitdump mmap injection support Stephane Eranian <eranian@google.com> - 2016-02-05 00:10 +0100
      Re: [PATCH v8 2/4] perf inject: add jitdump mmap injection support Arnaldo Carvalho de Melo <acme@kernel.org> - 2016-02-05 14:50 +0100
        Re: [PATCH v8 2/4] perf inject: add jitdump mmap injection support Arnaldo Carvalho de Melo <acme@kernel.org> - 2016-02-05 15:00 +0100
          Re: [PATCH v8 2/4] perf inject: add jitdump mmap injection support Arnaldo Carvalho de Melo <acme@kernel.org> - 2016-02-05 15:00 +0100
            Re: [PATCH v8 2/4] perf inject: add jitdump mmap injection support Arnaldo Carvalho de Melo <acme@kernel.org> - 2016-02-05 15:30 +0100
              Re: [PATCH v8 2/4] perf inject: add jitdump mmap injection support Stephane Eranian <eranian@google.com> - 2016-02-08 20:00 +0100

#1327217 — Re: [PATCH v8 2/4] perf inject: add jitdump mmap injection support

FromArnaldo Carvalho de Melo <acme@kernel.org>
Date2016-02-04 23:00 +0100
SubjectRe: [PATCH v8 2/4] perf inject: add jitdump mmap injection support
Message-ID<qYA6u-7KA-7@gated-at.bofh.it>
Em Fri, Jan 22, 2016 at 01:22:51PM -0800, Stephane Eranian escreveu:
> On Fri, Jan 22, 2016 at 12:44 PM, Arnaldo Carvalho de Melo
> <acme@redhat.com> wrote:
> > Em Mon, Nov 30, 2015 at 10:02:21AM +0100, Stephane Eranian escreveu:
> >> This patch adds a --jit/-j option to perf inject.
> >>
> >> This options injects MMAP records into the perf.data
> >> file to cover the jitted code mmaps. It also emits
> >> ELF images for each function in the jidump file.
> >> Those images are created where the jitdump file is.
> >> The MMAP records point to that location as well.
> >>
> >> Typical flow:
> >> $ perf record -k mono -- java -agentpath:libpjvmti.so java_class
> >> $ perf inject --jit -i perf.data -o perf.data.jitted
> >> $ perf report -i perf.data.jitted
> >
> > So, it fails 'make -C tools/perf build-test', specifically the one where
> > we ask for a NO_LIBELF build, trying to fix:
> >
> I have rebase to tip.git last night. Will try your branch today.
> Will add a couple of minor adjustments and also better documentation
> on how to use it.

So, trying to continue with this, digged for instructions on how to
build this the libjvmti.so thing, figure out its java-devel (aka
java-1.8.0-openjdk-devel).

And I needed this to build it, hacky tho, as was what was there before,
BTW, what distro was it you tested this for that
update-java-alternatives to be available?

I'm keeping what I have a perf/jit branch in my git tree.

- Arnaldo


diff --git a/tools/perf/jvmti/Makefile b/tools/perf/jvmti/Makefile
index 5e46f518e045..d7005f1608d2 100644
--- a/tools/perf/jvmti/Makefile
+++ b/tools/perf/jvmti/Makefile
@@ -33,7 +33,8 @@ VLIBJVMTI=libjvmti.so.$(VERSION)
 SLDFLAGS=-shared -Wl,-soname -Wl,$(VLIBJVMTI)
 SOLIBEXT=so
 
-JDIR=$(shell /usr/sbin/update-java-alternatives -l | head -1 | cut -d ' ' -f 3)
+#JDIR=$(shell /usr/sbin/update-java-alternatives -l | head -1 | cut -d ' ' -f 3)
+JDIR=$(shell alternatives --display java | tail -1 | cut -d' ' -f 5 | sed 's%/jre/bin/java.%%g')
 # -lrt required in 32-bit mode for clock_gettime()
 LIBS=-lelf -lrt
 INCDIR=-I $(JDIR)/include -I $(JDIR)/include/linux

[toc] | [next] | [standalone]


#1327323

FromStephane Eranian <eranian@google.com>
Date2016-02-05 00:10 +0100
Message-ID<qYBcf-i9-57@gated-at.bofh.it>
In reply to#1327217
Hi,

On Thu, Feb 4, 2016 at 1:53 PM, Arnaldo Carvalho de Melo
<acme@kernel.org> wrote:
> Em Fri, Jan 22, 2016 at 01:22:51PM -0800, Stephane Eranian escreveu:
>> On Fri, Jan 22, 2016 at 12:44 PM, Arnaldo Carvalho de Melo
>> <acme@redhat.com> wrote:
>> > Em Mon, Nov 30, 2015 at 10:02:21AM +0100, Stephane Eranian escreveu:
>> >> This patch adds a --jit/-j option to perf inject.
>> >>
>> >> This options injects MMAP records into the perf.data
>> >> file to cover the jitted code mmaps. It also emits
>> >> ELF images for each function in the jidump file.
>> >> Those images are created where the jitdump file is.
>> >> The MMAP records point to that location as well.
>> >>
>> >> Typical flow:
>> >> $ perf record -k mono -- java -agentpath:libpjvmti.so java_class
>> >> $ perf inject --jit -i perf.data -o perf.data.jitted
>> >> $ perf report -i perf.data.jitted
>> >
>> > So, it fails 'make -C tools/perf build-test', specifically the one where
>> > we ask for a NO_LIBELF build, trying to fix:
>> >
>> I have rebase to tip.git last night. Will try your branch today.
>> Will add a couple of minor adjustments and also better documentation
>> on how to use it.
>
> So, trying to continue with this, digged for instructions on how to
> build this the libjvmti.so thing, figure out its java-devel (aka
> java-1.8.0-openjdk-devel).
>
I will try on Ubuntu again with the latest JVM.
Clearly the environment is different.

> And I needed this to build it, hacky tho, as was what was there before,
> BTW, what distro was it you tested this for that
> update-java-alternatives to be available?
>
Ubuntu Trusty and Wily.

> I'm keeping what I have a perf/jit branch in my git tree.
>

Ok, I will try it out.
Thanks.

>
> diff --git a/tools/perf/jvmti/Makefile b/tools/perf/jvmti/Makefile
> index 5e46f518e045..d7005f1608d2 100644
> --- a/tools/perf/jvmti/Makefile
> +++ b/tools/perf/jvmti/Makefile
> @@ -33,7 +33,8 @@ VLIBJVMTI=libjvmti.so.$(VERSION)
>  SLDFLAGS=-shared -Wl,-soname -Wl,$(VLIBJVMTI)
>  SOLIBEXT=so
>
> -JDIR=$(shell /usr/sbin/update-java-alternatives -l | head -1 | cut -d ' ' -f 3)
> +#JDIR=$(shell /usr/sbin/update-java-alternatives -l | head -1 | cut -d ' ' -f 3)
> +JDIR=$(shell alternatives --display java | tail -1 | cut -d' ' -f 5 | sed 's%/jre/bin/java.%%g')
>  # -lrt required in 32-bit mode for clock_gettime()
>  LIBS=-lelf -lrt
>  INCDIR=-I $(JDIR)/include -I $(JDIR)/include/linux

[toc] | [prev] | [next] | [standalone]


#1327708

FromArnaldo Carvalho de Melo <acme@kernel.org>
Date2016-02-05 14:50 +0100
Message-ID<qYOVQ-SY-17@gated-at.bofh.it>
In reply to#1327323
Em Thu, Feb 04, 2016 at 03:02:59PM -0800, Stephane Eranian escreveu:
> > I'm keeping what I have a perf/jit branch in my git tree.

What am I doing wrong? Continuing to investigate...

[acme@jouet linux]$ cd tools/perf/jvmti/
[acme@jouet jvmti]$ make clean
rm -f *.o *.so.* *.so *.lo
[acme@jouet jvmti]$ make
cc -fPIC -DPIC -I /usr/lib/jvm/java-1.8.0-openjdk-1.8.0.71-1.b15.fc23.x86_64/include -I /usr/lib/jvm/java-1.8.0-openjdk-1.8.0.71-1.b15.fc23.x86_64/include/linux -O2 -g -Werror -Wall -c libjvmti.c -o libjvmti.lo
cc -fPIC -DPIC -I /usr/lib/jvm/java-1.8.0-openjdk-1.8.0.71-1.b15.fc23.x86_64/include -I /usr/lib/jvm/java-1.8.0-openjdk-1.8.0.71-1.b15.fc23.x86_64/include/linux -O2 -g -Werror -Wall -c jvmti_agent.c -o jvmti_agent.lo
cc -I /usr/lib/jvm/java-1.8.0-openjdk-1.8.0.71-1.b15.fc23.x86_64/include -I /usr/lib/jvm/java-1.8.0-openjdk-1.8.0.71-1.b15.fc23.x86_64/include/linux -O2 -g -Werror -Wall -shared -Wl,-soname -Wl,libjvmti.so.1  -o libjvmti.so.1.0.0 libjvmti.lo jvmti_agent.lo -lelf -lrt
ln -sf libjvmti.so.1.0.0 libjvmti.so
[acme@jouet jvmti]$ 
[acme@jouet java]$ cat hello.java 
public class hello {
	public static void main(String[] args) {
                 System.out.println("Hello, World");
       	}
}
[acme@jouet java]$ javac hello.java 
[acme@jouet java]$ java hello
Hello, World
[acme@jouet java]$ 
[acme@jouet java]$ java -agentpath:/home/acme/git/linux/tools/perf/jvmti/libjvmti.so hello.java 
java: jvmti: jitdump in /home/acme/.debug/jit/java-jit-20160205.XXIKKHRA/jit-27730.dump
#
# A fatal error has been detected by the Java Runtime Environment:
#
#  SIGSEGV (0xb) at pc=0x00007f4aaed9bb3a, pid=27730, tid=139957992613632
#
# JRE version: OpenJDK Runtime Environment (8.0_71-b15) (build 1.8.0_71-b15)
# Java VM: OpenJDK 64-Bit Server VM (25.71-b15 mixed mode linux-amd64 compressed oops)
# Problematic frame:
# C  [libc.so.6+0x8ab3a]  strlen+0x2a
#
# Failed to write core dump. Core dumps have been disabled. To enable core dumping, try "ulimit -c unlimited" before starting Java again
#
# An error report file with more information is saved as:
# /home/acme/java/hs_err_pid27730.log
#
# If you would like to submit a bug report, please visit:
#   http://bugreport.java.com/bugreport/crash.jsp
#
Aborted (core dumped)
[acme@jouet java]$
[acme@jouet java]$ type java
java is hashed (/usr/bin/java)
[acme@jouet java]$ ls -la /usr/bin/java
lrwxrwxrwx. 1 root root 22 Jan 26 10:45 /usr/bin/java -> /etc/alternatives/java
[acme@jouet java]$ ls -la /etc/alternatives/java
lrwxrwxrwx. 1 root root 71 Jan 26 10:45 /etc/alternatives/java -> /usr/lib/jvm/java-1.8.0-openjdk-1.8.0.71-1.b15.fc23.x86_64/jre/bin/java
[acme@jouet java]$ rpm -qf /usr/lib/jvm/java-1.8.0-openjdk-1.8.0.71-1.b15.fc23.x86_64/jre/bin/java
java-1.8.0-openjdk-headless-1.8.0.71-1.b15.fc23.x86_64
[acme@jouet java]$

[acme@jouet java]$ vim hs_err_pid27730.log
[acme@jouet java]$ ulimit -c unlimited
[acme@jouet java]$ rm -f *.log
[acme@jouet java]$ 
[acme@jouet java]$ java -agentpath:/home/acme/git/linux/tools/perf/jvmti/libjvmti.so hello.java 
java: jvmti: jitdump in /home/acme/.debug/jit/java-jit-20160205.XXJ6KUZS/jit-27922.dump
#
# A fatal error has been detected by the Java Runtime Environment:
#
#  SIGSEGV (0xb) at pc=0x00007fef53f31b3a, pid=27922, tid=140665269741312
#
# JRE version: OpenJDK Runtime Environment (8.0_71-b15) (build 1.8.0_71-b15)
# Java VM: OpenJDK 64-Bit Server VM (25.71-b15 mixed mode linux-amd64 compressed oops)
# Problematic frame:
# C  [libc.so.6+0x8ab3a]  strlen+0x2a
#
# Core dump written. Default location: /home/acme/java/core or core.27922
#
# An error report file with more information is saved as:
# /home/acme/java/hs_err_pid27922.log
#
# If you would like to submit a bug report, please visit:
#   http://bugreport.java.com/bugreport/crash.jsp
#
Aborted (core dumped)
[acme@jouet java]$ dnf --enablerepo='*debug*' install /usr/lib/debug/.build-id/4c/91a5aff28a4820b667eab14b2188229ef63503
java-1.8.0-openjdk-debuginfo-1.8.0.71-1.b15.fc23.x86_64.rpm      7.0 MB/s |  75 MB   00:10    

[acme@jouet java]$ gdb -c core.27922 
GNU gdb (GDB) Fedora 7.10.1-30.fc23
Copyright (C) 2015 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-redhat-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word".
[New LWP 27935]
[New LWP 27922]
[New LWP 27926]
[New LWP 27923]
[New LWP 27924]
[New LWP 27925]
[New LWP 27933]
[New LWP 27928]
[New LWP 27929]
[New LWP 27934]
[New LWP 27930]
[New LWP 27936]
[New LWP 27931]
[New LWP 27927]
[New LWP 27932]
Reading symbols from /usr/lib/jvm/java-1.8.0-openjdk-1.8.0.71-1.b15.fc23.x86_64/jre/bin/java...Reading symbols from /usr/lib/debug/usr/lib/jvm/java-1.8.0-openjdk-1.8.0.71-1.b15.fc23.x86_64/jre/bin/java.debug...done.
done.
Missing separate debuginfo for /home/acme/git/linux/tools/perf/jvmti/libjvmti.so
Try: dnf --enablerepo='*debug*' install /usr/lib/debug/.build-id/af/a16eaaafdfc278c5ade69b9c63b20d733c0baf
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `java -agentpath:/home/acme/git/linux/tools/perf/jvmti/libjvmti.so hello.java'.
Program terminated with signal SIGABRT, Aborted.
#0  0x00007fef53edba98 in raise () from /lib64/libc.so.6
[Current thread is 1 (Thread 0x7fef2f6f6700 (LWP 27935))]
Missing separate debuginfos, use: dnf debuginfo-install elfutils-libelf-0.165-2.fc23.x86_64 glibc-2.22-7.fc23.x86_64 libgcc-5.3.1-2.fc23.x86_64 libstdc++-5.3.1-2.fc23.x86_64 zlib-1.2.8-9.fc23.x86_64
(gdb) bt
#0  0x00007fef53edba98 in raise () from /lib64/libc.so.6
#1  0x00007fef53edd69a in abort () from /lib64/libc.so.6
#2  0x00007fef53820ff9 in os::abort (dump_core=<optimized out>)
    at /usr/src/debug/java-1.8.0-openjdk-1.8.0.71-1.b15.fc23.x86_64/openjdk/hotspot/src/os/linux/vm/os_linux.cpp:1500
#3  0x00007fef539d1737 in VMError::report_and_die (this=this@entry=0x7fef2f6f4310)
    at /usr/src/debug/java-1.8.0-openjdk-1.8.0.71-1.b15.fc23.x86_64/openjdk/hotspot/src/share/vm/utilities/vmError.cpp:1060
#4  0x00007fef5382a2cf in JVM_handle_linux_signal (sig=sig@entry=11, info=info@entry=0x7fef2f6f45b0, ucVoid=ucVoid@entry=0x7fef2f6f4480, 
    abort_if_unrecognized=abort_if_unrecognized@entry=1)
    at /usr/src/debug/java-1.8.0-openjdk-1.8.0.71-1.b15.fc23.x86_64/openjdk/hotspot/src/os_cpu/linux_x86/vm/os_linux_x86.cpp:541
#5  0x00007fef5381e138 in signalHandler (sig=11, info=0x7fef2f6f45b0, uc=0x7fef2f6f4480)
    at /usr/src/debug/java-1.8.0-openjdk-1.8.0.71-1.b15.fc23.x86_64/openjdk/hotspot/src/os/linux/vm/os_linux.cpp:4233
#6  <signal handler called>
#7  0x00007fef53f31b3a in strlen () from /lib64/libc.so.6
#8  0x00007fef51e8e4c1 in compiled_method_load_cb (jvmti=0x7fef4c003ef0, method=<optimized out>, code_size=520, code_addr=0x7fef3d0ffd00, map_length=<optimized out>, 
    map=0x0, compile_info=0x7fef04019e80) at libjvmti.c:85
#9  0x00007fef536982b1 in JvmtiExport::post_compiled_method_load (nm=nm@entry=0x7fef3d0ffb90)
    at /usr/src/debug/java-1.8.0-openjdk-1.8.0.71-1.b15.fc23.x86_64/openjdk/hotspot/src/share/vm/prims/jvmtiExport.cpp:1793
#10 0x00007fef536a68d4 in JvmtiDeferredEvent::post (this=<optimized out>)
    at /usr/src/debug/java-1.8.0-openjdk-1.8.0.71-1.b15.fc23.x86_64/openjdk/hotspot/src/share/vm/prims/jvmtiImpl.cpp:957
#11 0x00007fef538c54a8 in ServiceThread::service_thread_entry (jt=0x7fef4c0d0000, __the_thread__=0x7fef4c0d0000)
    at /usr/src/debug/java-1.8.0-openjdk-1.8.0.71-1.b15.fc23.x86_64/openjdk/hotspot/src/share/vm/runtime/serviceThread.cpp:120
#12 0x00007fef53976343 in JavaThread::thread_main_inner (this=this@entry=0x7fef4c0d0000)
    at /usr/src/debug/java-1.8.0-openjdk-1.8.0.71-1.b15.fc23.x86_64/openjdk/hotspot/src/share/vm/runtime/thread.cpp:1699
#13 0x00007fef53976814 in JavaThread::run (this=0x7fef4c0d0000)
    at /usr/src/debug/java-1.8.0-openjdk-1.8.0.71-1.b15.fc23.x86_64/openjdk/hotspot/src/share/vm/runtime/thread.cpp:1679
#14 0x00007fef5381ffc2 in java_start (thread=0x7fef4c0d0000)
    at /usr/src/debug/java-1.8.0-openjdk-1.8.0.71-1.b15.fc23.x86_64/openjdk/hotspot/src/os/linux/vm/os_linux.cpp:782
#15 0x00007fef5489860a in start_thread () from /lib64/libpthread.so.0
#16 0x00007fef53fa9a4d in clone () from /lib64/libc.so.6
(gdb)


And it generates this file:

/home/acme/.debug/jit/java-jit-20160205.XXIKKHRA/jit-27730.dump

Continuing...

- Arnaldo

[toc] | [prev] | [next] | [standalone]


#1327718

FromArnaldo Carvalho de Melo <acme@kernel.org>
Date2016-02-05 15:00 +0100
Message-ID<qYP5x-Xo-27@gated-at.bofh.it>
In reply to#1327708
Em Fri, Feb 05, 2016 at 10:47:31AM -0300, Arnaldo Carvalho de Melo escreveu:
> Em Thu, Feb 04, 2016 at 03:02:59PM -0800, Stephane Eranian escreveu:
> > > I'm keeping what I have a perf/jit branch in my git tree.
> 
> What am I doing wrong? Continuing to investigate...
> #7  0x00007fef53f31b3a in strlen () from /lib64/libc.so.6
> #8  0x00007fef51e8e4c1 in compiled_method_load_cb (jvmti=0x7fef4c003ef0, method=<optimized out>, code_size=520, code_addr=0x7fef3d0ffd00, map_length=<optimized out>, 
>     map=0x0, compile_info=0x7fef04019e80) at libjvmti.c:85


Ok, this bandaid cured the segfault:


-------------------------------------------------------------
diff --git a/tools/perf/jvmti/libjvmti.c b/tools/perf/jvmti/libjvmti.c
index 745f20c7b4bd..92ffbe4ff160 100644
--- a/tools/perf/jvmti/libjvmti.c
+++ b/tools/perf/jvmti/libjvmti.c
@@ -82,7 +82,7 @@ compiled_method_load_cb(jvmtiEnv *jvmti,
 		 * append file name, we use loops and not string ops to avoid modifying
 		 * class_sign which is used later for the symbol name
 		 */
-		for (j = 0; i < (PATH_MAX - 1) && j < strlen(file_name); j++, i++)
+		for (j = 0; i < (PATH_MAX - 1) && file_name && j < strlen(file_name); j++, i++)
 			fn[i] = file_name[j];
 		fn[i] = '\0';
 	} else {
-------------------------------------------------------------

Now:

[acme@jouet java]$ java -agentpath:/home/acme/git/linux/tools/perf/jvmti/libjvmti.so hello.java 
java: jvmti: jitdump in /home/acme/.debug/jit/java-jit-20160205.XXdDr2Wr/jit-28322.dump
Error: Could not find or load main class hello.java
[acme@jouet java]$

Do I need to set CLASSPATH or something? /me tries...



> #9  0x00007fef536982b1 in JvmtiExport::post_compiled_method_load (nm=nm@entry=0x7fef3d0ffb90)
>     at /usr/src/debug/java-1.8.0-openjdk-1.8.0.71-1.b15.fc23.x86_64/openjdk/hotspot/src/share/vm/prims/jvmtiExport.cpp:1793
> #10 0x00007fef536a68d4 in JvmtiDeferredEvent::post (this=<optimized out>)
>     at /usr/src/debug/java-1.8.0-openjdk-1.8.0.71-1.b15.fc23.x86_64/openjdk/hotspot/src/share/vm/prims/jvmtiImpl.cpp:957
> #11 0x00007fef538c54a8 in ServiceThread::service_thread_entry (jt=0x7fef4c0d0000, __the_thread__=0x7fef4c0d0000)
>     at /usr/src/debug/java-1.8.0-openjdk-1.8.0.71-1.b15.fc23.x86_64/openjdk/hotspot/src/share/vm/runtime/serviceThread.cpp:120
> #12 0x00007fef53976343 in JavaThread::thread_main_inner (this=this@entry=0x7fef4c0d0000)
>     at /usr/src/debug/java-1.8.0-openjdk-1.8.0.71-1.b15.fc23.x86_64/openjdk/hotspot/src/share/vm/runtime/thread.cpp:1699
> #13 0x00007fef53976814 in JavaThread::run (this=0x7fef4c0d0000)
>     at /usr/src/debug/java-1.8.0-openjdk-1.8.0.71-1.b15.fc23.x86_64/openjdk/hotspot/src/share/vm/runtime/thread.cpp:1679
> #14 0x00007fef5381ffc2 in java_start (thread=0x7fef4c0d0000)
>     at /usr/src/debug/java-1.8.0-openjdk-1.8.0.71-1.b15.fc23.x86_64/openjdk/hotspot/src/os/linux/vm/os_linux.cpp:782
> #15 0x00007fef5489860a in start_thread () from /lib64/libpthread.so.0
> #16 0x00007fef53fa9a4d in clone () from /lib64/libc.so.6
> (gdb)
> 
> 
> And it generates this file:
> 
> /home/acme/.debug/jit/java-jit-20160205.XXIKKHRA/jit-27730.dump
> 
> Continuing...
> 
> - Arnaldo

[toc] | [prev] | [next] | [standalone]


#1327722

FromArnaldo Carvalho de Melo <acme@kernel.org>
Date2016-02-05 15:00 +0100
Message-ID<qYP5x-Xo-35@gated-at.bofh.it>
In reply to#1327718
Em Fri, Feb 05, 2016 at 10:51:18AM -0300, Arnaldo Carvalho de Melo escreveu:
> Em Fri, Feb 05, 2016 at 10:47:31AM -0300, Arnaldo Carvalho de Melo escreveu:
> > Em Thu, Feb 04, 2016 at 03:02:59PM -0800, Stephane Eranian escreveu:
> > > > I'm keeping what I have a perf/jit branch in my git tree.
> > 
> > What am I doing wrong? Continuing to investigate...
> > #7  0x00007fef53f31b3a in strlen () from /lib64/libc.so.6
> > #8  0x00007fef51e8e4c1 in compiled_method_load_cb (jvmti=0x7fef4c003ef0, method=<optimized out>, code_size=520, code_addr=0x7fef3d0ffd00, map_length=<optimized out>, 
> >     map=0x0, compile_info=0x7fef04019e80) at libjvmti.c:85
> 
> 
> Ok, this bandaid cured the segfault:
> 
> 
> -------------------------------------------------------------
> diff --git a/tools/perf/jvmti/libjvmti.c b/tools/perf/jvmti/libjvmti.c
> index 745f20c7b4bd..92ffbe4ff160 100644
> --- a/tools/perf/jvmti/libjvmti.c
> +++ b/tools/perf/jvmti/libjvmti.c
> @@ -82,7 +82,7 @@ compiled_method_load_cb(jvmtiEnv *jvmti,
>  		 * append file name, we use loops and not string ops to avoid modifying
>  		 * class_sign which is used later for the symbol name
>  		 */
> -		for (j = 0; i < (PATH_MAX - 1) && j < strlen(file_name); j++, i++)
> +		for (j = 0; i < (PATH_MAX - 1) && file_name && j < strlen(file_name); j++, i++)
>  			fn[i] = file_name[j];
>  		fn[i] = '\0';
>  	} else {
> -------------------------------------------------------------
> 
> Now:
> 
> [acme@jouet java]$ java -agentpath:/home/acme/git/linux/tools/perf/jvmti/libjvmti.so hello.java 
> java: jvmti: jitdump in /home/acme/.debug/jit/java-jit-20160205.XXdDr2Wr/jit-28322.dump
> Error: Could not find or load main class hello.java
> [acme@jouet java]$
> 
> Do I need to set CLASSPATH or something? /me tries...

Duh:

[acme@jouet java]$ java -agentpath:/home/acme/git/linux/tools/perf/jvmti/libjvmti.so hello
java: jvmti: jitdump in /home/acme/.debug/jit/java-jit-20160205.XXFb472a/jit-28966.dump
Hello, World
[acme@jouet java]$ 

- Arnaldo

[toc] | [prev] | [next] | [standalone]


#1327785

FromArnaldo Carvalho de Melo <acme@kernel.org>
Date2016-02-05 15:30 +0100
Message-ID<qYPyx-1p9-11@gated-at.bofh.it>
In reply to#1327722
Em Fri, Feb 05, 2016 at 10:57:17AM -0300, Arnaldo Carvalho de Melo escreveu:
> Duh:
> 
> [acme@jouet java]$ java -agentpath:/home/acme/git/linux/tools/perf/jvmti/libjvmti.so hello
> java: jvmti: jitdump in /home/acme/.debug/jit/java-jit-20160205.XXFb472a/jit-28966.dump
> Hello, World
> [acme@jouet java]$ 

Ok, so mucho progress:

[acme@jouet java]$ perf record -k 1 java -agentpath:/home/acme/git/linux/tools/perf/jvmti/libjvmti.so hello
java: jvmti: jitdump in /home/acme/.debug/jit/java-jit-20160205.XXIiqiq7/jit-31400.dump
Hello, World
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.030 MB perf.data (268 samples) ]
[acme@jouet java]$ perf inject --jit -i perf.data -o perf.data.jitted
[acme@jouet java]$ perf report -D -i perf.data | grep PERF_RECORD_MMAP > mmaps.before
Failed to open /tmp/perf-31400.map, continuing without symbols
[acme@jouet java]$ perf report -D -i perf.data. | grep PERF_RECORD_MMAP > mmaps.before
perf.data.jitted      perf.data.jitted.old  perf.data.old         
[acme@jouet java]$ perf report -D -i perf.data.jitted | grep PERF_RECORD_MMAP > mmaps.jitted
[acme@jouet java]$ diff -u mmaps.before mmaps.jitted
--- mmaps.before	2016-02-05 11:01:16.019257683 -0300
+++ mmaps.jitted	2016-02-05 11:01:28.966232802 -0300
<SNIP>
+77539479986521 0xfc80 [0xa0]: PERF_RECORD_MMAP2 31400/31413: [0x7f3f7d102880(0xc0) @ 0x40 fd:02 1840179 1]: --xs /home/acme/.debug/jit/java-jit-20160205.XXIiqiq7/jitted-31400-281.so
+77539480189814 0xfd20 [0xa0]: PERF_RECORD_MMAP2 31400/31413: [0x7f3f7d0fef60(0x80) @ 0x40 fd:02 1840180 1]: --xs /home/acme/.debug/jit/java-jit-20160205.XXIiqiq7/jitted-31400-282.so
+77539480541065 0xfdc0 [0xa0]: PERF_RECORD_MMAP2 31400/31413: [0x7f3f7d102560(0x180) @ 0x40 fd:02 1840181 1]: --xs /home/acme/.debug/jit/java-jit-20160205.XXIiqiq7/jitted-31400-283.so
+77539480541871 0xfe60 [0xa0]: PERF_RECORD_MMAP2 31400/31413: [0x7f3f7d102360(0x180) @ 0x40 fd:02 1840182 1]: --xs /home/acme/.debug/jit/java-jit-20160205.XXIiqiq7/jitted-31400-284.so
+77539480848667 0xff00 [0xa0]: PERF_RECORD_MMAP2 31400/31413: [0x7f3f7d102160(0x180) @ 0x40 fd:02 1840183 1]: --xs /home/acme/.debug/jit/java-jit-20160205.XXIiqiq7/jitted-31400-285.so
+77539480910925 0xffa0 [0xa0]: PERF_RECORD_MMAP2 31400/31413: [0x7f3f7d101f60(0x180) @ 0x40 fd:02 1840184 1]: --xs /home/acme/.debug/jit/java-jit-20160205.XXIiqiq7/jitted-31400-286.so
<SNIP>

Quite a lot of those, but I noticed this, probably harmless, at the start:

 0 0x3fd8 [0x88]: PERF_RECORD_MMAP -1/0: [0xffffffffa0991000(0x5000) @ 0]: x /lib/modules/4.3.4-300.fc23.x86_64/kernel/net/dns_resolver/dns_resolver.ko.xz
 0 0x4060 [0x78]: PERF_RECORD_MMAP -1/0: [0xffffffffa0996000(0x7b000) @ 0]: x /lib/modules/4.3.4-300.fc23.x86_64/kernel/fs/nfs/nfsv4.ko.xz
 0 0x40d8 [0x88]: PERF_RECORD_MMAP -1/0: [0xffffffffa0a11000(0x5f5eefff) @ 0]: x /lib/modules/4.3.4-300.fc23.x86_64/kernel/drivers/usb/storage/usb-storage.ko.xz
-77539437123281 0x6b98 [0xa0]: PERF_RECORD_MMAP2 31400/31400: [0x557b73152000(0x202000) @ 0 fd:00 7858 3897326142]: r-xp /usr/lib/jvm/java-1.8.0-openjdk-1.8.0.71-1.b15.fc23.x86_64/jre/bin/java
+77539437123281 0x42a0 [0xa0]: PERF_RECORD_MMAP2 31400/31400: [0x557b73152000(0x202000) @ 0 fd:00 7858 3897326142]: r-xp /usr/lib/jvm/java-1.8.0-openjdk-1.8.0.71-1.b15.fc23.x86_64/jre/bin/java

I.e. the MMAP records for the kernel modules comes in ok, humm, because
probably you don't hook on PERF_RECORD_MMAP in perf-inject, just on MMAP2, and
in those the only difference is the second field, 0x6b98 -> 0x42a0, what is
that?

static void dump_event(struct perf_evlist *evlist, union perf_event *event,
                       u64 file_offset, struct perf_sample *sample)
{
        if (sample)
                perf_evlist__print_tstamp(evlist, event, sample);

        printf("%#" PRIx64 " [%#x]: PERF_RECORD_%s", file_offset,
               event->header.size, perf_event__name(event->header.type));

File offset, what changed?

-0x7c18 [0x8]: event: 68
-.
-. ... raw event: size 8 bytes
-.  0000:  44 00 00 00 00 00 08 00                          D.......
-.
-0x7c18 [0x8]: PERF_RECORD_FINISHED_ROUND
-
-0x6a80 [0x28]: event: 9

Humm, inject doesn't preserves PERF_RECORD_FINISHED_ROUND? Or user events in
general? On purpose?

- Arnaldo

[toc] | [prev] | [next] | [standalone]


#1329479

FromStephane Eranian <eranian@google.com>
Date2016-02-08 20:00 +0100
Message-ID<qZZcu-LY-7@gated-at.bofh.it>
In reply to#1327785
Hi Arnaldo,

Sorry for the delay, I missed your message.

I tried with openjdk-8 on Ubuntu/Wily and I do not get the crash using
the same hello world test program.
In fact, if I print file_name, it is never NULL for me.

$ java -agentpath:/home/eranian/tip/tools/perf/jvmti/libjvmti.so hello
java: jvmti: jitdump in
/home/eranian/.debug/jit/java-jit-20160208.XX8wCwyY/jit-20156.dump
java: FILE_NAME: Object.java
java: FILE_NAME: String.java
java: FILE_NAME: String.java
java: FILE_NAME: String.java
java: FILE_NAME: String.java
java: FILE_NAME: String.java
java: FILE_NAME: System.java
java: FILE_NAME: Math.java
java: FILE_NAME: Object.java
java: FILE_NAME: Reference.java
java: FILE_NAME: AbstractStringBuilder.java
java: FILE_NAME: ThreadLocal.java
java: FILE_NAME: AbstractStringBuilder.java
java: FILE_NAME: String.java
Hello, World

So I am not sure what is different in your setup especially if the
function GetSourceFileName() did not fail.
Could you print file_name in your code to check?


As for the MMAP, it is normal to have the extra mmaps pointing to the
jitted code.
Event for a simple program as hello world, there are several function
jitted, including the
java interpreter itself. There is one MMAP for each jitted function.



On Fri, Feb 5, 2016 at 6:24 AM, Arnaldo Carvalho de Melo
<acme@kernel.org> wrote:
>
> Em Fri, Feb 05, 2016 at 10:57:17AM -0300, Arnaldo Carvalho de Melo escreveu:
> > Duh:
> >
> > [acme@jouet java]$ java -agentpath:/home/acme/git/linux/tools/perf/jvmti/libjvmti.so hello
> > java: jvmti: jitdump in /home/acme/.debug/jit/java-jit-20160205.XXFb472a/jit-28966.dump
> > Hello, World
> > [acme@jouet java]$
>
> Ok, so mucho progress:
>
> [acme@jouet java]$ perf record -k 1 java -agentpath:/home/acme/git/linux/tools/perf/jvmti/libjvmti.so hello
> java: jvmti: jitdump in /home/acme/.debug/jit/java-jit-20160205.XXIiqiq7/jit-31400.dump
> Hello, World
> [ perf record: Woken up 1 times to write data ]
> [ perf record: Captured and wrote 0.030 MB perf.data (268 samples) ]
> [acme@jouet java]$ perf inject --jit -i perf.data -o perf.data.jitted
> [acme@jouet java]$ perf report -D -i perf.data | grep PERF_RECORD_MMAP > mmaps.before
> Failed to open /tmp/perf-31400.map, continuing without symbols
> [acme@jouet java]$ perf report -D -i perf.data. | grep PERF_RECORD_MMAP > mmaps.before
> perf.data.jitted      perf.data.jitted.old  perf.data.old
> [acme@jouet java]$ perf report -D -i perf.data.jitted | grep PERF_RECORD_MMAP > mmaps.jitted
> [acme@jouet java]$ diff -u mmaps.before mmaps.jitted
> --- mmaps.before        2016-02-05 11:01:16.019257683 -0300
> +++ mmaps.jitted        2016-02-05 11:01:28.966232802 -0300
> <SNIP>
> +77539479986521 0xfc80 [0xa0]: PERF_RECORD_MMAP2 31400/31413: [0x7f3f7d102880(0xc0) @ 0x40 fd:02 1840179 1]: --xs /home/acme/.debug/jit/java-jit-20160205.XXIiqiq7/jitted-31400-281.so
> +77539480189814 0xfd20 [0xa0]: PERF_RECORD_MMAP2 31400/31413: [0x7f3f7d0fef60(0x80) @ 0x40 fd:02 1840180 1]: --xs /home/acme/.debug/jit/java-jit-20160205.XXIiqiq7/jitted-31400-282.so
> +77539480541065 0xfdc0 [0xa0]: PERF_RECORD_MMAP2 31400/31413: [0x7f3f7d102560(0x180) @ 0x40 fd:02 1840181 1]: --xs /home/acme/.debug/jit/java-jit-20160205.XXIiqiq7/jitted-31400-283.so
> +77539480541871 0xfe60 [0xa0]: PERF_RECORD_MMAP2 31400/31413: [0x7f3f7d102360(0x180) @ 0x40 fd:02 1840182 1]: --xs /home/acme/.debug/jit/java-jit-20160205.XXIiqiq7/jitted-31400-284.so
> +77539480848667 0xff00 [0xa0]: PERF_RECORD_MMAP2 31400/31413: [0x7f3f7d102160(0x180) @ 0x40 fd:02 1840183 1]: --xs /home/acme/.debug/jit/java-jit-20160205.XXIiqiq7/jitted-31400-285.so
> +77539480910925 0xffa0 [0xa0]: PERF_RECORD_MMAP2 31400/31413: [0x7f3f7d101f60(0x180) @ 0x40 fd:02 1840184 1]: --xs /home/acme/.debug/jit/java-jit-20160205.XXIiqiq7/jitted-31400-286.so
> <SNIP>
>
> Quite a lot of those, but I noticed this, probably harmless, at the start:
>
>  0 0x3fd8 [0x88]: PERF_RECORD_MMAP -1/0: [0xffffffffa0991000(0x5000) @ 0]: x /lib/modules/4.3.4-300.fc23.x86_64/kernel/net/dns_resolver/dns_resolver.ko.xz
>  0 0x4060 [0x78]: PERF_RECORD_MMAP -1/0: [0xffffffffa0996000(0x7b000) @ 0]: x /lib/modules/4.3.4-300.fc23.x86_64/kernel/fs/nfs/nfsv4.ko.xz
>  0 0x40d8 [0x88]: PERF_RECORD_MMAP -1/0: [0xffffffffa0a11000(0x5f5eefff) @ 0]: x /lib/modules/4.3.4-300.fc23.x86_64/kernel/drivers/usb/storage/usb-storage.ko.xz
> -77539437123281 0x6b98 [0xa0]: PERF_RECORD_MMAP2 31400/31400: [0x557b73152000(0x202000) @ 0 fd:00 7858 3897326142]: r-xp /usr/lib/jvm/java-1.8.0-openjdk-1.8.0.71-1.b15.fc23.x86_64/jre/bin/java
> +77539437123281 0x42a0 [0xa0]: PERF_RECORD_MMAP2 31400/31400: [0x557b73152000(0x202000) @ 0 fd:00 7858 3897326142]: r-xp /usr/lib/jvm/java-1.8.0-openjdk-1.8.0.71-1.b15.fc23.x86_64/jre/bin/java
>
> I.e. the MMAP records for the kernel modules comes in ok, humm, because
> probably you don't hook on PERF_RECORD_MMAP in perf-inject, just on MMAP2, and
> in those the only difference is the second field, 0x6b98 -> 0x42a0, what is
> that?
>
I have both MMAP and MMAP2 hooks for the jit mode of perf inject.

>
> static void dump_event(struct perf_evlist *evlist, union perf_event *event,
>                        u64 file_offset, struct perf_sample *sample)
> {
>         if (sample)
>                 perf_evlist__print_tstamp(evlist, event, sample);
>
>         printf("%#" PRIx64 " [%#x]: PERF_RECORD_%s", file_offset,
>                event->header.size, perf_event__name(event->header.type));
>
> File offset, what changed?
>
As for this, the offset is not recorded in the MMAP2 record, this is
an artifact of the __perf_Session__process_events()
which passes the file_offset in the perf.data file (read by mmapping).
The offsets are changed because we inject
new mmap records, and thus the existing MMAP may be moved to a later
position in the file.

Hope this helps.

>
> -0x7c18 [0x8]: event: 68
> -.
> -. ... raw event: size 8 bytes
> -.  0000:  44 00 00 00 00 00 08 00                          D.......
> -.
> -0x7c18 [0x8]: PERF_RECORD_FINISHED_ROUND
> -
> -0x6a80 [0x28]: event: 9
>
> Humm, inject doesn't preserves PERF_RECORD_FINISHED_ROUND? Or user events in
> general? On purpose?
>
> - Arnaldo

[toc] | [prev] | [standalone]


Back to top | Article view | linux.kernel


csiph-web