Re: [Patch] Losing many samples when profiling multiple JVMs

On 06/16/2015 04:24 PM, William Cohen wrote:
> On 06/12/2015 04:49 PM, 大平怜 wrote:
>> Hi,
>>
>> Anyone has any suggestions?  I hope my patch is included in OProfile-1.1.
>>
>>
>> Thanks,
>> Rei Odaira
>>
>> 2015-05-31 22:00 GMT-05:00 大平怜 <[email protected] <mailto:[email protected]>>:
>>
>>     Hi,
>>
>>     I found when profiling multiple JVMs, many samples that should have hit JITted methods were lost due to no permanent mapping. This was because OProfile did not have correct operf_mmap for the JITted code anon regions of some of the JVMs. This error can happen as follows:
>>
>>     (1) __handle_mmap_event() creates a new operf_mmap for a small anon region of a JVM.
>>     (2) When another JVM happens to allocate its anon region at the same starting virtual address but with a larger size, __handle_mmap_event() first searches all_images_map.
>>     (3) __handle_mmap_event() finds the previously created operf_mmap in all_images_map and reuses it, because it checks only filename and start_addr.
>>     (4) As a result, when a sample hits a JITted method that was generated between the incorrect end_addr and the actual end address, __get_operf_trans() cannot find an appropriate mapping.
>>
>>     The root cause of this problem is that __handle_mmap_event() does not check end_addr when searching all_images_map. This should work for a normal file, which should have the same size when mapped to different processes, but not for anon regions, which can have different sizes in different processes. The attached patch will add this check.
>>
> 
> Hi Rei,
> 
> The patch sounds like a step in the right direction.  However, what happens when two different processes have anon regions that have the same starting address and are the same size?  It  would be preferable to use the pid of struct mmap_event to determine whether the maps for the anonymous regions are for the same process, but the struct operf_mmap doesn't keep the pid information.  Maybe the struct operf_mmap should be modified and the code include that for the anonymous memory maps.  Use pid value of 0 for mappings for multiple pids.
> 
>>     More fundamentally, I am wondering what the purpose of all_images_region is. I guess it is to reuse operf_mmap structures for more than one processes. The file names in all_images_map are stored in absolute paths, but they are compared against a file base name in __handle_mmap_event(). As a result, this comparison succeeds only for anon and [vdso]. Is this intended behavior?
>>
> 
> I haven't done that much looking in this area of the oprofile code.  I did some code archaeology with gitk to see how to code evolved and see if there was anything in the commits that described what was being addressed.  It looks like the following patch put in that particular code that your patch is modifying.  The goal is to avoid having multiple mappings for different processes with the same binaries/mappings.  There needs to be some checking earlier to see whether the mapping is something that is unique to the process (an anonymous mapping) and avoid the incorrect matching of pseudo file names ("//anon" , "/anon_hugepage").
> 
> 
> 
> Author: Maynard Johnson <[email protected]>  2012-03-27 19:03:45
> Committer: Maynard Johnson <[email protected]>  2012-03-27 19:03:45
> Parent: ed9f73aab1adb7ee368027a2532649baf867a45d (Fix problem when passed app name is of the form '<subdir>/<app_name>')
> Child:  f7f71a580b65f5fedcd1bbd94825838a94a0945a (Fix timing-related problems with app name)
> Branches: master, remotes/origin/master
> Follows: RELEASE_0_9_7
> Precedes: RELEASE_0_9_8
> 
>     Minor bug fixes and performance improvement for system-wide mode.
>     
>     The operf_sfile hashing algorithm was modified from legacy hashing
>     to use either a build-id or a checksum.  I had not yet implemented the
>     getting the build-id, so was falling back to the checksum.  Getting
>     the checksum (via gelf_checksum) was terribly expensive, especially
>     noticeable when running with the system-wide option.  So I spent
>     some time comparing using a build-id (obtained from the binary file's
>     NT_GNU_BUILD_ID note) for the hashing algorithm versus simply hashing
>     on a substring of the image name.  The simple string hash was as
>     effective as the build-id method.  Both were way better than the checksum
>     technique. In the end, I removed all of the checksum and build-id stuff,
>     and settled on the image name string hash method for finding operf_sfiles.
>     
>     Aside from the above big performance improvement described above, I also
>     created a global multimap for holding operf_mmap objects.  The operf_mmap
>     encapsulates an MMAP event.  In system-wide mode, we get lots of MMAP events
>     for the same libraries being used by many different processes, so it was
>     logical to create just one operf_mmap object per unique binary.
> 
> 
> -Will


Hi Rei,

I was thinking something along the lines of the attached patch to address this problem.  Could you try it out and see whether that resolves the issue?  Also do you have a reproducer that could be added to the testsuite to verify that this problem is fixed and doesn't get reintroduced into oprofile?

-Will

------------------------------------------------------------------------------

_______________________________________________
oprofile-list mailing list
[email protected]
https://lists.sourceforge.net/lists/listinfo/oprofile-list

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..ba2fcb4 100644
--- a/libperf_events/operf_utils.cpp
+++ b/libperf_events/operf_utils.cpp
@@ -275,6 +275,7 @@ 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->pid && (*it).second->pid == event->mmap.pid)
 				&& ((*it).second->start_addr == event->mmap.start)) {
 			mapping = (*it).second;
 			break;
@@ -291,12 +292,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");
 		}