jvm-profiling-tools / perf-map-agent

A java agent to generate method mappings to use with the linux `perf` tool
GNU General Public License v2.0
1.65k stars 260 forks source link

Research using uprobes on JIT'd methods #26

Open jrudolph opened 8 years ago

jrudolph commented 8 years ago

Challenges:

ceeaspb commented 8 years ago

@jrudolph I found some info on the first bullet point:

openjdk has an option

-XX:+UseOprofile

which has the interesting property of mapping the codecache VMA to a writable executable file.

# pmap $(jps|awk '/Scratch/{print $1}' )|grep hs-vm-
00007f14087b3000   2496K rwx-- hs-vm-2125-1 (deleted)

It does however delete it after mapping it. This is done in hotspot/src/os/linux/vm/os_linux.cpp :

// Rationale behind this function:
//  current (Mon Apr 25 20:12:18 MSD 2005) oprofile drops samples without executable
//  mapping for address (see lookup_dcookie() in the kernel module), thus we cannot get
//  samples for JITted code. Here we create private executable mapping over the code cache
//  and then we can use standard (well, almost, as mapping can change) way to provide
//  info for the reporting script by storing timestamp and location of symbol
void linux_wrap_code(char* base, size_t size) {

  static volatile jint cnt = 0;

  if (!UseOprofile) {
    return;
  }

  char buf[PATH_MAX+1];
  int num = Atomic::add(1, &cnt);

  snprintf(buf, sizeof(buf), "%s/hs-vm-%d-%d",
           os::get_temp_directory(), os::current_process_id(), num);
  unlink(buf);

  int fd = ::open(buf, O_CREAT | O_RDWR, S_IRWXU);

  if (fd != -1) {
    off_t rv = ::lseek(fd, size-2, SEEK_SET);
    if (rv != (off_t)-1) {
      if (::write(fd, "", 1) == 1) {
        mmap(base, size,
             PROT_READ|PROT_WRITE|PROT_EXEC,
             MAP_PRIVATE|MAP_FIXED|MAP_NORESERVE, fd, 0);
      }
    }
    ::close(fd);
    unlink(buf);

So what happens if we don't unlink it?

# pmap $(jps|awk '/Scratch/{print $1}' )|grep hs-vm-
00007f6d79000000   2496K rwx-- hs-vm-2257-1

Looking inside the codecache VMA:

perf-map reports the function location as normal:

# grep doit /tmp/perf-$(jps|awk '/Scratch/{print $1}' ).map|tail -1
7f6d791563c0 660 LScratch;.doit

print assembly correlates with the memory address of the compiled method :

<print_nmethod stamp='0.482'>
Compiled method (c2)     482  118       4       Scratch::doit (425 bytes)
 total in heap  [0x00007f6d79156090,0x00007f6d79157f78] = 7912
 relocation     [0x00007f6d791561b8,0x00007f6d791563c0] = 520
 main code      [0x00007f6d791563c0,0x00007f6d79156a20] = 1632
...
  # {method} {0x00007f6d8ce34748} &apos;doit&apos; &apos;(I)I&apos; in &apos;Scratch&apos;
  # parm0:    rsi       = int
  #           [sp+0x30]  (sp of caller)
  0x00007f6d791563c0: mov    %eax,-0x14000(%rsp)
  0x00007f6d791563c7: push   %rbp
  0x00007f6d791563c8: sub    $0x20,%rsp         ;*synchronization entry
                                                ; - Scratch::doit@-1 (line 25)
...
<nmethod compile_id='118' compiler='C2' level='4' entry='0x00007f6d791563c0' size='7912' 
address='0x00007f6d79156090' relocation_offset='296' insts_offset='816' stub_offset='2448' 
scopes_data_offset='2920' scopes_pcs_offset='3968' dependencies_offset='7232' 
handler_table_offset='7240' oops_offset='2888' method='Scratch doit (I)I' bytes='425' count='5539' 
iicount='5539' stamp='0.500'/>

If we try and create the uprobe on the function (could be via perf or ftrace):

# perf probe  -vvv -x /tmp/hs-vm-$(jps|awk '/Scratch/{print $1}' )-1 0x1563c0
probe-definition(0): 0x1563c0 
symbol:0x1563c0 file:(null) line:0 offset:0 return:0 lazy:(null)
0 arguments
Opening /sys/kernel/debug/tracing/uprobe_events write=1
Added new event:
Writing event: p:probe_hs/abs_1563c0 /tmp/hs-vm-2257-1:0x1563c0
  probe_hs:abs_1563c0  (on 0x1563c0 in /tmp/hs-vm-2257-1)

You can now use it in all perf tools, such as:

perf record -e probe_hs:abs_1563c0 -aR sleep 1

the create doesn’t report any error.

# perf record -e probe_hs:abs_1563c0 -aR sleep 1
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.102 MB perf.data ]
# perf script|wc -l
0

but no data is recorded, I guess because of the VMA being writeable (your next bullet point). That's as far as I got for now. Investigation could go in a couple of different directions from here.

jrudolph commented 8 years ago

Cool, that already looks quite promising. Thanks for the research, @ceeaspb.

ceeaspb commented 8 years ago

loosely related, changing to a file backed VMA may need this recent perf patch (not for uprobes but perf events): https://lkml.org/lkml/2015/11/19/580

jrudolph commented 8 years ago

perf record -e probe_hs:abs_1563c0 -aR sleep 1

You are running the probe against sleep. Would that trigger the probe?

ceeaspb commented 8 years ago

Hi @jrudolph - yes because it has the -a system wide collection option. the sleep here is just a dummy command to set the record duration. I was running it directly with ftrace to double check. Also for example, uprobing the wrap_code jvm function:

# perf record -e probe_libjvm:abs_896940 -aR sleep 100 &

## run Scratch program

# fg %1 
## cntl-C

# perf script
            java  1947 [001]   250.430272: probe_libjvm:abs_896940: (7f910c676940)
ghost commented 5 years ago

I'm also researching on a way to use uprobe for dynamic tracing in Java, using eBPF. Is there any update on this? Thanks.

IluckySi commented 3 months ago

I'm also researching on a way to use uprobe for dynamic tracing in Java, using eBPF. Is there any update on this? Thanks.

IluckySi commented 3 months ago

Hi @jrudolph,May I ask you a question! Does ebpf probe support JIT'd method(java) using /tmp/perf-${pid}.map generated by perf-map-agent project using bin/create-java-perf-map.sh $pid command?

When I use cilium to load EBPF program,code as following,An error occurred:_creating perfuprobe PMU: token /proc/13096/exe:0x733f8cc7aaa0: opening perf event: invalid argument.
link, err := exe.Uprobe("Lsun/net/www/protocol/http/HttpURLConnection;::setRequestProperty", t.uprobes["uprobe_HttpURLConnection_setRequestProperty"], &link.UprobeOptions{Address: 0x733f8cc7aaa0}), We suspect that the address from the perf-${pid}.map is not actual address,i want to know 733f8cc7aaa0 mean what? how to convert it to a static address? Thank you very much!

root@ubuntu22:/data/ilucky/cloudwise/euspace# cat /tmp/perf-13096.map | grep setRequestProperty 733f8cc7aaa0 fd0 Lsun/net/www/protocol/http/HttpURLConnection;::setRequestProperty

jrudolph commented 2 months ago

We suspect that the address from the perf-${pid}.map is not actual address,i want to know 733f8cc7aaa0 mean what? how to convert it to a static address? Thank you very much!

Yes that's the full (virtual) address. The problem is that uprobe expects addresses to be relative to a memory mapped executable, however, JIT code gets compiled into an anonymous mapping that (currently) cannot be addressed with uprobes...