Re: [Patch] Losing many samples when profiling multiple JVMs
William Cohen <[email protected]>
| Newsgroups | gmane.linux.oprofile |
|---|---|
| Message-ID | <[email protected]> |
On 06/29/2015 01:10 PM, 大平怜 wrote:
> Hello,
>
> I created a small test case (attached) to reproduce this problem.
> This code assumes x86.
>
>> gcc -O2 -o oprofile_anon_remap_test oprofile_anon_remap_test.c
>> operf ./oprofile_anon_remap_test 10000
>> opreport
>
> opreport should print many samples hit at "anon". However, it does not
> in the current version, and if you look at oprofile_data/samples/operf.log,
> many samples fall into "Nr. samples lost due to no permanent mapping".
>
>
> Regards,
> Rei Odaira
Hi,
Sorry, it has taken me a while to get back to this.
I am including Andrew Haley on this email because he works on the JVM
and has used oprofile to monitor performance of JVM generated code.
He might be able to give some feedback this issue and whether the
proposed fix is sufficient.
Thanks for the reproducer code. It was very helpful. I have modified the
reproducer to be more portable to other machines and added support for
arm and arm64. It is trivial to add support for additional processors.
Below is example compile and run of the code which exhibits the problem you observed.
[wcohen@santana ~]$ gcc -g -o oprofile_anon_remap_testa oprofile_anon_remap_testa.c
[wcohen@santana ~]$ operf ./oprofile_anon_remap_testa 10000
operf: Profiler started
* * * * WARNING: Profiling rate was throttled back by the kernel * * * *
The number of samples actually recorded is less than expected, but is
probably still statistically valid. Decreasing the sampling rate is the
best option if you want to avoid throttling.
WARNING: Lost samples detected! See /home/wcohen/oprofile_data/samples/operf.log for details.
Lowering the sampling rate may reduce or eliminate lost samples.
See the '--events' option description in the operf man page for help.
Profiling done.
[wcohen@santana ~]$ opreport
Using /home/wcohen/oprofile_data/samples/ for samples directory.
WARNING! Some of the events were throttled. Throttling occurs when
the initial sample rate is too high, causing an excessive number of
interrupts. Decrease the sampling frequency. Check the directory
/home/wcohen/oprofile_data/samples/current/stats/throttled
for the throttled event names.
WARNING: Lost samples detected! See /home/wcohen/oprofile_data/samples/operf.log for details.
CPU: Intel Ivy Bridge microarchitecture, speed 3300 MHz (estimated)
Counted CPU_CLK_UNHALTED events (Clock cycles when not halted) with a unit mask of 0x00 (No unit mask) count 100000
CPU_CLK_UNHALT...|
samples| %|
------------------
800 100.000 oprofile_anon_remap_testa
CPU_CLK_UNHALT...|
samples| %|
------------------
447 55.8750 oprofile_anon_remap_testa
207 25.8750 libc-2.21.so
141 17.6250 kallsyms
3 0.3750 kvm
2 0.2500 ld-2.21.so
As mentioned in earlier email it looks like oprofile tracking of mmaps
is getting confused by the large mmap getting carved into smaller
mmaps. The changes in the mmap are likely being done by the jvm to
mark regions as executable. For oprofile's purposes it is not that
important to track changes on that level. If a new mapping falls
within an existing anon mapping, there is no need create a new
mapping. Attached is a patch that discards those mapping changes
within existing mappings. I have also built a fedora 22 rpm with the
git checkout and this patch
at:http://koji.fedoraproject.org/koji/taskinfo?taskID=10313853. It
seems to provide saner output for the reproducer
[wcohen@santana ~]$ operf ./oprofile_anon_remap_testa 10000
operf: Profiler started
* * * * WARNING: Profiling rate was throttled back by the kernel * * * *
The number of samples actually recorded is less than expected, but is
probably still statistically valid. Decreasing the sampling rate is the
best option if you want to avoid throttling.
Profiling done.
[wcohen@santana ~]$ opreport
Using /home/wcohen/oprofile_data/samples/ for samples directory.
WARNING! Some of the events were throttled. Throttling occurs when
the initial sample rate is too high, causing an excessive number of
interrupts. Decrease the sampling frequency. Check the directory
/home/wcohen/oprofile_data/samples/current/stats/throttled
for the throttled event names.
CPU: Intel Ivy Bridge microarchitecture, speed 3300 MHz (estimated)
Counted CPU_CLK_UNHALTED events (Clock cycles when not halted) with a unit mask of 0x00 (No unit mask) count 100000
CPU_CLK_UNHALT...|
samples| %|
------------------
394553 100.000 oprofile_anon_remap_testa
CPU_CLK_UNHALT...|
samples| %|
------------------
393758 99.7985 anon (tgid:16764 range:0x7ffa7d680000-0x7ffa7ea81fff)
456 0.1156 oprofile_anon_remap_testa
185 0.0469 libc-2.21.so
152 0.0385 kallsyms
1 2.5e-04 kvm
1 2.5e-04 ld-2.21.so
-Will
------------------------------------------------------------------------------
Don't Limit Your Business. Reach for the Cloud.
GigeNET's Cloud Solutions provide you with the tools and support that
you need to offload your IT needs and focus on growing your business.
Configured For All Businesses. Start Your Cloud Today.
https://www.gigenetcloud.com/
_______________________________________________
oprofile-list mailing list
[email protected]
https://lists.sourceforge.net/lists/listinfo/oprofile-list
oprofile_anon_remap_testa.c
(text/x-csrc, 3.9 KB)
/*
* This test case is to make sure that oprofile collects the samples
* hit at the extended region of an anon buffer.
* This code assumes x86.
*/
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <sys/mman.h>
#include <unistd.h>
typedef int (*func_t)(void);
/* If MINIMUM_BUFFER_SIZE is too small (like 4 KB), the anon buffer can
overlap with the memory region of other library files such as ld-...,
so any samples hit at the anon buffer are incorrectly attributed to
the library files. 10 MB is large enough on Ubuntu 14.04/x86. */
#define MINIMUM_BUFFER_SIZE (10 * 1024 * 1024)
#if defined (__i386__) || defined (__x86_64__)
/* add $0x1,%eax */
char add_inst[3]={0x83, 0xc0, 0x01};
/* retq */
char ret_inst[1]={0xc3};
#elif defined(__arm__)
/* add r0, r0, #1 */
char add_inst[4]={0x01, 0x00, 0x80, 0xe2};
/* bx lr */
char ret_inst[4]={0x1e, 0xff, 0x2f, 0xe1};
#elif defined(__aarch64__)
/* add x0, x0, #1 */
char add_inst[4]={0x00, 0x04, 0x00, 0x91};
/* ret */
char ret_inst[4]={0xc0, 0x03, 0x5f, 0xd6};
#else
error unsupported architecture
#endif
/* Fill the extended region of the buffer with add and ret.
buffer func_start_addr
| |
v v
<-- initial_buffer_size -->
<----- remapped_buffer_size ----->
|.........................|add add add add add ... add ret|
*/
static func_t
initialize_anon_func(char *buffer, size_t initial_buffer_size, size_t remapped_buffer_size)
{
char *func_start_addr = buffer + initial_buffer_size;
char *func_end_addr = buffer + remapped_buffer_size - 1;
char *cursor;
int add_size = sizeof(add_inst);
int ret_size = sizeof(ret_inst);
for (cursor = func_start_addr; cursor + add_size + ret_size < func_end_addr; cursor += add_size) {
memcpy(cursor, add_inst, add_size);
}
memcpy(cursor, ret_inst, ret_size);
return (func_t)func_start_addr;
}
int
main(int argc, char *argv[])
{
void *buffer;
int ret;
size_t page_size;
size_t initial_buffer_size;
size_t remapped_buffer_size;
func_t anon_func;
int iter;
int iter_max;
if (argc != 2) {
fprintf(stderr, "Usage: oprofile_anon_remap_test <num iterations>\n");
exit(1);
}
iter_max = atoi(argv[1]);
page_size = (size_t)sysconf(_SC_PAGESIZE);
initial_buffer_size = (MINIMUM_BUFFER_SIZE / page_size + 1) * page_size;
/* remapped_buffer_size must be larger than initial_buffer_size */
remapped_buffer_size = initial_buffer_size * 2;
/* First, reserve remapped_buffer_size bytes of virtual memory.
Don't specify PROT_EXEC. This mmap is to increase the chance of
the following two mmap's to succeed. */
buffer = mmap(NULL, remapped_buffer_size, PROT_NONE, MAP_PRIVATE | MAP_ANON | MAP_NORESERVE, 0, 0);
if (buffer == MAP_FAILED) {
perror("mmap");
exit(1);
}
/* This munmap might be unnecessary. */
ret = munmap(buffer, remapped_buffer_size);
if (ret == -1) {
perror("munmap");
exit(1);
}
/* Next, mmap initial_buffer_size bytes from the "buffer" address
with PROT_EXEC. The kernel will notify oprofile of the new
executable mmap region.
*/
buffer = mmap(buffer, initial_buffer_size, PROT_EXEC | PROT_READ | PROT_WRITE, MAP_PRIVATE | MAP_ANON | MAP_FIXED, 0, 0);
if (buffer == MAP_FAILED) {
perror("second mmap");
exit(1);
}
/* Lastly, extend the buffer to remapped_buffer_size bytes with PROT_EXEC.
The kernel will notify oprofile again.
mremap(2) should be used instead? */
buffer = mmap(buffer, remapped_buffer_size, PROT_EXEC | PROT_READ | PROT_WRITE, MAP_PRIVATE | MAP_ANON | MAP_FIXED, 0, 0);
if (buffer == MAP_FAILED) {
perror("third mmap");
exit(1);
}
anon_func = initialize_anon_func(buffer, initial_buffer_size, remapped_buffer_size);
/* Execute the function generated in the extended region of the buffer
many times so that a number of samples hit there. */
for (iter = 0; iter < iter_max; iter++) {
anon_func();
}
}
oprofile-mmap_range.patch
(text/x-patch, 1.7 KB)
diff --git a/libperf_events/operf_process_info.h b/libperf_events/operf_process_info.h
index f98591f..3138ffb 100644
--- a/libperf_events/operf_process_info.h
+++ b/libperf_events/operf_process_info.h
@@ -25,6 +25,7 @@ struct operf_mmap {
u64 start_addr;
u64 end_addr;
u64 pgoff;
+ u32 pid;
bool is_anon_mapping;
bool is_hypervisor;
char filename[PATH_MAX];
diff --git a/libperf_events/operf_utils.cpp b/libperf_events/operf_utils.cpp
index 90a0765..7e6ed76 100644
--- a/libperf_events/operf_utils.cpp
+++ b/libperf_events/operf_utils.cpp
@@ -275,7 +275,10 @@ static void __handle_mmap_event(event_t * event)
range = all_images_map.equal_range(image_basename);
for (it = range.first; it != range.second; it++) {
if (((strcmp((*it).second->filename, image_basename.c_str())) == 0)
- && ((*it).second->start_addr == event->mmap.start)) {
+ && ((*it).second->pid && (*it).second->pid == event->mmap.pid)
+ && ((*it).second->start_addr <= event->mmap.start
+ && ((*it).second->end_addr >= event->mmap.start + event->mmap.len)))
+ {
mapping = (*it).second;
break;
}
@@ -291,12 +294,15 @@ static void __handle_mmap_event(event_t * event)
*/
if (mapping->filename[0] == '[') {
mapping->is_anon_mapping = true;
+ mapping->pid = event->mmap.pid;
} else if ((strncmp(mapping->filename, "//anon",
strlen("//anon")) == 0)) {
mapping->is_anon_mapping = true;
+ mapping->pid = event->mmap.pid;
strcpy(mapping->filename, "anon");
} else if ((strncmp(mapping->filename, "/anon_hugepage",
strlen("/anon_hugepage")) == 0)) {
+ mapping->pid = event->mmap.pid;
mapping->is_anon_mapping = true;
strcpy(mapping->filename, "anon");
}