From: Andrew H. <ap...@re...> - 2014-07-30 16:38:04
|
There's a bug in Oprofile for AArch64 where "opreport -l" prints out lots of symbols as "x". Like this: 21690 604433 1.0010 27.8939 libjvm.so PhaseChaitin::build_ifg_physical(ResourceArea*) 20856 625289 0.9625 28.8564 libjvm.so ConnectionGraph::add_fields_to_worklist(FieldNode*, PointsToNode*) 20707 645996 0.9556 29.8120 libjvm.so $x 19824 665820 0.9149 30.7269 libjvm.so PhaseIdealLoop::is_dominator(Node*, Node*) 19483 685303 0.8991 31.6260 libjvm.so $x 17863 703166 0.8244 32.4504 libjvm.so SymbolTable::lookup_only(char const*, int, unsigned int&) 17530 720696 0.8090 33.2593 libjvm.so PhaseChaitin::interfere_with_live(unsigned int, IndexSet*) 16381 737077 0.7560 34.0153 libjvm.so PhaseIdealLoop::Dominators() 16124 753201 0.7441 34.7594 libjvm.so MachNode::rematerialize() const 15886 769087 0.7331 35.4925 libjvm.so SpinPause 14797 783884 0.6829 36.1754 libjvm.so $x It turns out that these "$x" symbols aren't symbols at all, but "mapping symbols". The AArch64 ELF specification requires that special symbols be inserted into object files to mark certain features: $x At the start of a region of code containing AArch64 instructions. $d At the start of a region of data. These symbols should be ignored by tools. The fix in Oprofile is trivial: diff --git a/libpp/profile_container.cpp b/libpp/profile_container.cpp index e543f51..ec8438c 100644 --- a/libpp/profile_container.cpp +++ b/libpp/profile_container.cpp @@ -81,6 +81,9 @@ void profile_container::add(profile_t const & profile, for (symbol_index_t i = 0; i < abfd.syms.size(); ++i) { + if (abfd.syms[i].name() == "$x") + continue; + unsigned long long start = 0, end = 0; symbol_entry symb_entry; And now the output looks like this: 21690 604433 1.1579 32.2665 libjvm.so PhaseChaitin::build_ifg_physical(ResourceArea*) 20856 625289 1.1134 33.3798 libjvm.so ConnectionGraph::add_fields_to_worklist(FieldNode*, PointsToNode*) 19824 645113 1.0583 34.4381 libjvm.so PhaseIdealLoop::is_dominator(Node*, Node*) 17863 662976 0.9536 35.3917 libjvm.so SymbolTable::lookup_only(char const*, int, unsigned int&) 17530 680506 0.9358 36.3275 libjvm.so PhaseChaitin::interfere_with_live(unsigned int, IndexSet*) 16381 696887 0.8745 37.2019 libjvm.so PhaseIdealLoop::Dominators() 16124 713011 0.8607 38.0627 libjvm.so MachNode::rematerialize() const 15886 728897 0.8480 38.9107 libjvm.so SpinPause 14687 743584 0.7840 39.6948 libjvm.so PhaseLive::add_liveout(Block*, IndexSet*, VectorSet&) Andrew. |
From: Andrew H. <ap...@re...> - 2014-07-30 17:03:43
|
There's a bug in Oprofile for AArch64 where "opreport -l" prints out lots of symbols as "x". Like this: 21690 604433 1.0010 27.8939 libjvm.so PhaseChaitin::build_ifg_physical(ResourceArea*) 20856 625289 0.9625 28.8564 libjvm.so ConnectionGraph::add_fields_to_worklist(FieldNode*, PointsToNode*) 20707 645996 0.9556 29.8120 libjvm.so $x 19824 665820 0.9149 30.7269 libjvm.so PhaseIdealLoop::is_dominator(Node*, Node*) 19483 685303 0.8991 31.6260 libjvm.so $x 17863 703166 0.8244 32.4504 libjvm.so SymbolTable::lookup_only(char const*, int, unsigned int&) 17530 720696 0.8090 33.2593 libjvm.so PhaseChaitin::interfere_with_live(unsigned int, IndexSet*) 16381 737077 0.7560 34.0153 libjvm.so PhaseIdealLoop::Dominators() 16124 753201 0.7441 34.7594 libjvm.so MachNode::rematerialize() const 15886 769087 0.7331 35.4925 libjvm.so SpinPause 14797 783884 0.6829 36.1754 libjvm.so $x It turns out that these "$x" symbols aren't symbols at all, but "mapping symbols". The AArch64 ELF specification requires that special symbols be inserted into object files to mark certain features: $x At the start of a region of code containing AArch64 instructions. $d At the start of a region of data. These symbols should be ignored by tools. The fix in Oprofile is trivial: diff --git a/libpp/profile_container.cpp b/libpp/profile_container.cpp index e543f51..ec8438c 100644 --- a/libpp/profile_container.cpp +++ b/libpp/profile_container.cpp @@ -81,6 +81,9 @@ void profile_container::add(profile_t const & profile, for (symbol_index_t i = 0; i < abfd.syms.size(); ++i) { + if (abfd.syms[i].name() == "$x") + continue; + unsigned long long start = 0, end = 0; symbol_entry symb_entry; And now the output looks like this: 21690 604433 1.1579 32.2665 libjvm.so PhaseChaitin::build_ifg_physical(ResourceArea*) 20856 625289 1.1134 33.3798 libjvm.so ConnectionGraph::add_fields_to_worklist(FieldNode*, PointsToNode*) 19824 645113 1.0583 34.4381 libjvm.so PhaseIdealLoop::is_dominator(Node*, Node*) 17863 662976 0.9536 35.3917 libjvm.so SymbolTable::lookup_only(char const*, int, unsigned int&) 17530 680506 0.9358 36.3275 libjvm.so PhaseChaitin::interfere_with_live(unsigned int, IndexSet*) 16381 696887 0.8745 37.2019 libjvm.so PhaseIdealLoop::Dominators() 16124 713011 0.8607 38.0627 libjvm.so MachNode::rematerialize() const 15886 728897 0.8480 38.9107 libjvm.so SpinPause 14687 743584 0.7840 39.6948 libjvm.so PhaseLive::add_liveout(Block*, IndexSet*, VectorSet&) Andrew. |
From: Andrew H. <ap...@re...> - 2014-07-30 17:06:28
|
I kept getting "now trying to kill convert pid..." error messages. Turns out that there is only a 5s wait for the daemon to terminate, which is nowhere near long enough if you have lot of symbols. This fixed it, but a fixed time limit seems wrong: diff --git a/pe_profiling/operf.cpp b/pe_profiling/operf.cpp index 51f55a5..b12aadf 100644 --- a/pe_profiling/operf.cpp +++ b/pe_profiling/operf.cpp @@ -492,10 +492,10 @@ static end_code_t _kill_operf_read_pid(end_code_t rc) int option = WNOHANG; int wait_rc; gettimeofday(&tv, NULL); - if (tv.tv_sec > start_time_sec + 5) { + if (tv.tv_sec > start_time_sec + 45) { keep_trying = false; option = 0; - cerr << "now trying to kill convert pid..." << endl; + cerr << "now trying to kill convert pid 45s..." << endl; if (kill(operf_read_pid, SIGUSR1) < 0) { perror("Attempt to stop operf-read process failed"); Andrew. |
From: Maynard J. <may...@us...> - 2014-07-30 22:27:05
|
On 07/30/2014 12:06 PM, Andrew Haley wrote: > I kept getting "now trying to kill convert pid..." error messages. > Turns out that there is only a 5s wait for the daemon to terminate, > which is nowhere near long enough if you have lot of symbols. Andrew, what were you profiling when you saw this? Unfortunately, the term "convert" is used for two different tasks in the internal workings of operf. First, we have the perf_events-formatted data from the kernel being converted to oprofile sample file format. Second, we run the opjitconv to convert any JVM jitdump files to ELF files. It is the latter task for which you are seeing this message. I agree the fixed time limit is not ideal. I'm guessing you are profiling lots of JVMs to see this message. When profiling a large busy system, the conversion of perf-format data to oprofile sample file format can cause noticeable overhead, and you might want to think about using the --lazy-conversion option in that case. As for the patch, I'm not sure I want to change one hard-coded time limit for another. I'll give this some thought. -Maynard > > This fixed it, but a fixed time limit seems wrong: > > diff --git a/pe_profiling/operf.cpp b/pe_profiling/operf.cpp > index 51f55a5..b12aadf 100644 > --- a/pe_profiling/operf.cpp > +++ b/pe_profiling/operf.cpp > @@ -492,10 +492,10 @@ static end_code_t _kill_operf_read_pid(end_code_t rc) > int option = WNOHANG; > int wait_rc; > gettimeofday(&tv, NULL); > - if (tv.tv_sec > start_time_sec + 5) { > + if (tv.tv_sec > start_time_sec + 45) { > keep_trying = false; > option = 0; > - cerr << "now trying to kill convert pid..." << endl; > + cerr << "now trying to kill convert pid 45s..." << endl; > > if (kill(operf_read_pid, SIGUSR1) < 0) { > perror("Attempt to stop operf-read process failed"); > > Andrew. > > > ------------------------------------------------------------------------------ > Infragistics Professional > Build stunning WinForms apps today! > Reboot your WinForms applications with our WinForms controls. > Build a bridge from your legacy apps to the future. > http://pubads.g.doubleclick.net/gampad/clk?id=153845071&iu=/4140/ostg.clktrk > _______________________________________________ > oprofile-list mailing list > opr...@li... > https://lists.sourceforge.net/lists/listinfo/oprofile-list > |
From: Andrew H. <ap...@re...> - 2014-07-31 08:26:04
|
On 30/07/14 23:26, Maynard Johnson wrote: > On 07/30/2014 12:06 PM, Andrew Haley wrote: >> I kept getting "now trying to kill convert pid..." error messages. >> Turns out that there is only a 5s wait for the daemon to terminate, >> which is nowhere near long enough if you have lot of symbols. > Andrew, what were you profiling when you saw this? The HotSpot JVM. > Unfortunately, the term "convert" is used for two different tasks in > the internal workings of operf. First, we have the > perf_events-formatted data from the kernel being converted to > oprofile sample file format. Second, we run the opjitconv to > convert any JVM jitdump files to ELF files. It is the latter task > for which you are seeing this message. I agree the fixed time limit > is not ideal. I'm guessing you are profiling lots of JVMs to see > this message. No, just the one: it takes a long time. > When profiling a large busy system, the conversion of perf-format > data to oprofile sample file format can cause noticeable overhead, > and you might want to think about using the --lazy-conversion option > in that case. > > As for the patch, I'm not sure I want to change one hard-coded time > limit for another. I'll give this some thought. Whatever you do, please give an error message that tells the user what to do. The hard time limit makes no sense to me. Andrew. |
From: Maynard J. <may...@us...> - 2014-07-31 14:30:59
|
On 07/30/2014 12:06 PM, Andrew Haley wrote: > I kept getting "now trying to kill convert pid..." error messages. Andrew, can you please reproduce this problem, running operf with "-V debug". Then attach all operf debug output to your reply. Thanks. -Maynard > Turns out that there is only a 5s wait for the daemon to terminate, > which is nowhere near long enough if you have lot of symbols. > > This fixed it, but a fixed time limit seems wrong: > > diff --git a/pe_profiling/operf.cpp b/pe_profiling/operf.cpp > index 51f55a5..b12aadf 100644 > --- a/pe_profiling/operf.cpp > +++ b/pe_profiling/operf.cpp > @@ -492,10 +492,10 @@ static end_code_t _kill_operf_read_pid(end_code_t rc) > int option = WNOHANG; > int wait_rc; > gettimeofday(&tv, NULL); > - if (tv.tv_sec > start_time_sec + 5) { > + if (tv.tv_sec > start_time_sec + 45) { > keep_trying = false; > option = 0; > - cerr << "now trying to kill convert pid..." << endl; > + cerr << "now trying to kill convert pid 45s..." << endl; > > if (kill(operf_read_pid, SIGUSR1) < 0) { > perror("Attempt to stop operf-read process failed"); > > Andrew. > > > ------------------------------------------------------------------------------ > Infragistics Professional > Build stunning WinForms apps today! > Reboot your WinForms applications with our WinForms controls. > Build a bridge from your legacy apps to the future. > http://pubads.g.doubleclick.net/gampad/clk?id=153845071&iu=/4140/ostg.clktrk > _______________________________________________ > oprofile-list mailing list > opr...@li... > https://lists.sourceforge.net/lists/listinfo/oprofile-list > |
From: Maynard J. <may...@us...> - 2014-07-31 17:11:09
|
On 07/30/2014 05:26 PM, Maynard Johnson wrote: > On 07/30/2014 12:06 PM, Andrew Haley wrote: >> I kept getting "now trying to kill convert pid..." error messages. >> Turns out that there is only a 5s wait for the daemon to terminate, >> which is nowhere near long enough if you have lot of symbols. > Andrew, what were you profiling when you saw this? Unfortunately, the term "convert" is used for two different tasks in the internal workings of operf. First, we have the perf_events-formatted data from the kernel being converted to oprofile sample file format. Second, we run the opjitconv to convert any JVM jitdump files to ELF files. It is the latter task for which you are seeing this message. I agree the fixed time limit is not ideal. I'm guessing you are profiling lots of JVMs to see this message. When profiling a large busy system, the conversion of perf-format data to oprofile sample file format can cause noticeable overhead, and you might want to think about using the --lazy-conversion option in that case. > > As for the patch, I'm not sure I want to change one hard-coded time limit for another. I'll give this some thought. Andrew, I *did* give this some more thought today . . . and realized my analysis above was wrong. Below is a more complete analysis. Unless operf is run with --lazy-conversion, a separate process (the "convert pid" as referred to in the message; 'operf_read_pid' as referred to in the code) is forked to read perf_events-formatted kernel data from a pipe. The pipe writer is another oprofile process -- operf_record_pid -- which is reading the actual kernel data. The operf_read_pid converts this data to oprofile sample files. This conversion process is fairly expensive, so it's not unusual for it to take a little while after profiling stops for it to complete. And the more samples there are (i.e., the longer the profile runs), the longer while it will take. When profiling stops, we call _kill_operf_read_pid and the 5 second timeout begins, waiting for operf_read_pid to finish its conversion. You have obviously bumped up against that timeout big time. Having a hard-coded timeout was a bad idea; we should always allow that conversion process to finish. I will post a patch that will show status of conver! sion (prin t a "." for each second of work). Thanks for reporting this. -Maynard > > -Maynard >> >> This fixed it, but a fixed time limit seems wrong: >> >> diff --git a/pe_profiling/operf.cpp b/pe_profiling/operf.cpp >> index 51f55a5..b12aadf 100644 >> --- a/pe_profiling/operf.cpp >> +++ b/pe_profiling/operf.cpp >> @@ -492,10 +492,10 @@ static end_code_t _kill_operf_read_pid(end_code_t rc) >> int option = WNOHANG; >> int wait_rc; >> gettimeofday(&tv, NULL); >> - if (tv.tv_sec > start_time_sec + 5) { >> + if (tv.tv_sec > start_time_sec + 45) { >> keep_trying = false; >> option = 0; >> - cerr << "now trying to kill convert pid..." << endl; >> + cerr << "now trying to kill convert pid 45s..." << endl; >> >> if (kill(operf_read_pid, SIGUSR1) < 0) { >> perror("Attempt to stop operf-read process failed"); >> >> Andrew. >> >> >> ------------------------------------------------------------------------------ >> Infragistics Professional >> Build stunning WinForms apps today! >> Reboot your WinForms applications with our WinForms controls. >> Build a bridge from your legacy apps to the future. >> http://pubads.g.doubleclick.net/gampad/clk?id=153845071&iu=/4140/ostg.clktrk >> _______________________________________________ >> oprofile-list mailing list >> opr...@li... >> https://lists.sourceforge.net/lists/listinfo/oprofile-list >> > > > ------------------------------------------------------------------------------ > Infragistics Professional > Build stunning WinForms apps today! > Reboot your WinForms applications with our WinForms controls. > Build a bridge from your legacy apps to the future. > http://pubads.g.doubleclick.net/gampad/clk?id=153845071&iu=/4140/ostg.clktrk > _______________________________________________ > oprofile-list mailing list > opr...@li... > https://lists.sourceforge.net/lists/listinfo/oprofile-list > |
From: Maynard J. <may...@us...> - 2014-08-01 15:43:03
|
On 07/31/2014 12:10 PM, Maynard Johnson wrote: > On 07/30/2014 05:26 PM, Maynard Johnson wrote: >> On 07/30/2014 12:06 PM, Andrew Haley wrote: >>> I kept getting "now trying to kill convert pid..." error messages. >>> Turns out that there is only a 5s wait for the daemon to terminate, >>> which is nowhere near long enough if you have lot of symbols. >> Andrew, what were you profiling when you saw this? Unfortunately, the term "convert" is used for two different tasks in the internal workings of operf. First, we have the perf_events-formatted data from the kernel being converted to oprofile sample file format. Second, we run the opjitconv to convert any JVM jitdump files to ELF files. It is the latter task for which you are seeing this message. I agree the fixed time limit is not ideal. I'm guessing you are profiling lots of JVMs to see this message. When profiling a large busy system, the conversion of perf-format data to oprofile sample file format can cause noticeable overhead, and you might want to think about using the --lazy-conversion option in that case. >> >> As for the patch, I'm not sure I want to change one hard-coded time limit for another. I'll give this some thought. > Andrew, > I *did* give this some more thought today . . . and realized my analysis above was wrong. Below is a more complete analysis. > > Unless operf is run with --lazy-conversion, a separate process (the "convert pid" as referred to in the message; 'operf_read_pid' as referred to in the code) is forked to read perf_events-formatted kernel data from a pipe. The pipe writer is another oprofile process -- operf_record_pid -- which is reading the actual kernel data. The operf_read_pid converts this data to oprofile sample files. This conversion process is fairly expensive, so it's not unusual for it to take a little while after profiling stops for it to complete. And the more samples there are (i.e., the longer the profile runs), the longer while it will take. When profiling stops, we call _kill_operf_read_pid and the 5 second timeout begins, waiting for operf_read_pid to finish its conversion. You have obviously bumped up against that timeout big time. Having a hard-coded timeout was a bad idea; we should always allow that conversion process to finish. I will post a patch that will show status of conv! er! Andrew . . . I posted a patch to the oprofile-list ("[PATCH] operf main process improperly killing conversion process") to address this issue. Please give it a test drive when you have the time. Thanks. -Maynard > sion (prin > t a "." for each second of work). > > Thanks for reporting this. > > -Maynard > >> >> -Maynard >>> >>> This fixed it, but a fixed time limit seems wrong: >>> >>> diff --git a/pe_profiling/operf.cpp b/pe_profiling/operf.cpp >>> index 51f55a5..b12aadf 100644 >>> --- a/pe_profiling/operf.cpp >>> +++ b/pe_profiling/operf.cpp >>> @@ -492,10 +492,10 @@ static end_code_t _kill_operf_read_pid(end_code_t rc) >>> int option = WNOHANG; >>> int wait_rc; >>> gettimeofday(&tv, NULL); >>> - if (tv.tv_sec > start_time_sec + 5) { >>> + if (tv.tv_sec > start_time_sec + 45) { >>> keep_trying = false; >>> option = 0; >>> - cerr << "now trying to kill convert pid..." << endl; >>> + cerr << "now trying to kill convert pid 45s..." << endl; >>> >>> if (kill(operf_read_pid, SIGUSR1) < 0) { >>> perror("Attempt to stop operf-read process failed"); >>> >>> Andrew. >>> >>> >>> ------------------------------------------------------------------------------ >>> Infragistics Professional >>> Build stunning WinForms apps today! >>> Reboot your WinForms applications with our WinForms controls. >>> Build a bridge from your legacy apps to the future. >>> http://pubads.g.doubleclick.net/gampad/clk?id=153845071&iu=/4140/ostg.clktrk >>> _______________________________________________ >>> oprofile-list mailing list >>> opr...@li... >>> https://lists.sourceforge.net/lists/listinfo/oprofile-list >>> >> >> >> ------------------------------------------------------------------------------ >> Infragistics Professional >> Build stunning WinForms apps today! >> Reboot your WinForms applications with our WinForms controls. >> Build a bridge from your legacy apps to the future. >> http://pubads.g.doubleclick.net/gampad/clk?id=153845071&iu=/4140/ostg.clktrk >> _______________________________________________ >> oprofile-list mailing list >> opr...@li... >> https://lists.sourceforge.net/lists/listinfo/oprofile-list >> > > > ------------------------------------------------------------------------------ > Infragistics Professional > Build stunning WinForms apps today! > Reboot your WinForms applications with our WinForms controls. > Build a bridge from your legacy apps to the future. > http://pubads.g.doubleclick.net/gampad/clk?id=153845071&iu=/4140/ostg.clktrk > _______________________________________________ > oprofile-list mailing list > opr...@li... > https://lists.sourceforge.net/lists/listinfo/oprofile-list > |
From: Andrew H. <ap...@re...> - 2014-08-01 15:47:51
|
On 08/01/2014 04:42 PM, Maynard Johnson wrote: > Andrew . . . I posted a patch to the oprofile-list ("[PATCH] operf main process improperly killing conversion process") to address this issue. No you didn't. It didn't get there, anyway. Andrew. |
From: Maynard J. <may...@us...> - 2014-08-06 13:55:51
|
On 08/01/2014 10:42 AM, Maynard Johnson wrote: > On 07/31/2014 12:10 PM, Maynard Johnson wrote: >> On 07/30/2014 05:26 PM, Maynard Johnson wrote: >>> On 07/30/2014 12:06 PM, Andrew Haley wrote: >>>> I kept getting "now trying to kill convert pid..." error messages. >>>> Turns out that there is only a 5s wait for the daemon to terminate, >>>> which is nowhere near long enough if you have lot of symbols. >>> Andrew, what were you profiling when you saw this? Unfortunately, the term "convert" is used for two different tasks in the internal workings of operf. First, we have the perf_events-formatted data from the kernel being converted to oprofile sample file format. Second, we run the opjitconv to convert any JVM jitdump files to ELF files. It is the latter task for which you are seeing this message. I agree the fixed time limit is not ideal. I'm guessing you are profiling lots of JVMs to see this message. When profiling a large busy system, the conversion of perf-format data to oprofile sample file format can cause noticeable overhead, and you might want to think about using the --lazy-conversion option in that case. >>> >>> As for the patch, I'm not sure I want to change one hard-coded time limit for another. I'll give this some thought. >> Andrew, >> I *did* give this some more thought today . . . and realized my analysis above was wrong. Below is a more complete analysis. >> >> Unless operf is run with --lazy-conversion, a separate process (the "convert pid" as referred to in the message; 'operf_read_pid' as referred to in the code) is forked to read perf_events-formatted kernel data from a pipe. The pipe writer is another oprofile process -- operf_record_pid -- which is reading the actual kernel data. The operf_read_pid converts this data to oprofile sample files. This conversion process is fairly expensive, so it's not unusual for it to take a little while after profiling stops for it to complete. And the more samples there are (i.e., the longer the profile runs), the longer while it will take. When profiling stops, we call _kill_operf_read_pid and the 5 second timeout begins, waiting for operf_read_pid to finish its conversion. You have obviously bumped up against that timeout big time. Having a hard-coded timeout was a bad idea; we should always allow that conversion process to finish. I will post a patch that will show status of con! v! > er! > Andrew . . . I posted a patch to the oprofile-list ("[PATCH] operf main process improperly killing conversion process") to address this issue. Please give it a test drive when you have the time. Hi, Andrew, If you can still reproduce the original problem, I would appreciate if you could apply this patch and test if resolves the situation. Thanks. -Maynard > > Thanks. > -Maynard >> sion (prin >> t a "." for each second of work). >> >> Thanks for reporting this. >> >> -Maynard >> >>> >>> -Maynard >>>> >>>> This fixed it, but a fixed time limit seems wrong: >>>> >>>> diff --git a/pe_profiling/operf.cpp b/pe_profiling/operf.cpp >>>> index 51f55a5..b12aadf 100644 >>>> --- a/pe_profiling/operf.cpp >>>> +++ b/pe_profiling/operf.cpp >>>> @@ -492,10 +492,10 @@ static end_code_t _kill_operf_read_pid(end_code_t rc) >>>> int option = WNOHANG; >>>> int wait_rc; >>>> gettimeofday(&tv, NULL); >>>> - if (tv.tv_sec > start_time_sec + 5) { >>>> + if (tv.tv_sec > start_time_sec + 45) { >>>> keep_trying = false; >>>> option = 0; >>>> - cerr << "now trying to kill convert pid..." << endl; >>>> + cerr << "now trying to kill convert pid 45s..." << endl; >>>> >>>> if (kill(operf_read_pid, SIGUSR1) < 0) { >>>> perror("Attempt to stop operf-read process failed"); >>>> >>>> Andrew. >>>> |
From: Maynard J. <may...@us...> - 2014-07-30 22:15:39
|
On 07/30/2014 11:37 AM, Andrew Haley wrote: > There's a bug in Oprofile for AArch64 where "opreport -l" prints out lots > of symbols as "x". Like this: > > 21690 604433 1.0010 27.8939 libjvm.so PhaseChaitin::build_ifg_physical(ResourceArea*) > 20856 625289 0.9625 28.8564 libjvm.so ConnectionGraph::add_fields_to_worklist(FieldNode*, PointsToNode*) > 20707 645996 0.9556 29.8120 libjvm.so $x > 19824 665820 0.9149 30.7269 libjvm.so PhaseIdealLoop::is_dominator(Node*, Node*) > 19483 685303 0.8991 31.6260 libjvm.so $x > 17863 703166 0.8244 32.4504 libjvm.so SymbolTable::lookup_only(char const*, int, unsigned int&) > 17530 720696 0.8090 33.2593 libjvm.so PhaseChaitin::interfere_with_live(unsigned int, IndexSet*) > 16381 737077 0.7560 34.0153 libjvm.so PhaseIdealLoop::Dominators() > 16124 753201 0.7441 34.7594 libjvm.so MachNode::rematerialize() const > 15886 769087 0.7331 35.4925 libjvm.so SpinPause > 14797 783884 0.6829 36.1754 libjvm.so $x > > > It turns out that these "$x" symbols aren't symbols at all, but > "mapping symbols". The AArch64 ELF specification requires that > special symbols be inserted into object files to mark certain > features: > > $x > At the start of a region of code containing AArch64 instructions. > > $d > At the start of a region of data. > > These symbols should be ignored by tools. The fix in Oprofile is > trivial: > > diff --git a/libpp/profile_container.cpp b/libpp/profile_container.cpp > index e543f51..ec8438c 100644 > --- a/libpp/profile_container.cpp > +++ b/libpp/profile_container.cpp > @@ -81,6 +81,9 @@ void profile_container::add(profile_t const & profile, > > for (symbol_index_t i = 0; i < abfd.syms.size(); ++i) { > > + if (abfd.syms[i].name() == "$x") > + continue; Andrew, This seems to be just applying a band aid to the problem. We end up losing samples that were incorrectly attributed to this special symbol, right? Those samples are probably for a real symbol I would expect. Is there any way to figure that out? -Maynard > + > unsigned long long start = 0, end = 0; > symbol_entry symb_entry; > > And now the output looks like this: > > 21690 604433 1.1579 32.2665 libjvm.so PhaseChaitin::build_ifg_physical(ResourceArea*) > 20856 625289 1.1134 33.3798 libjvm.so ConnectionGraph::add_fields_to_worklist(FieldNode*, PointsToNode*) > 19824 645113 1.0583 34.4381 libjvm.so PhaseIdealLoop::is_dominator(Node*, Node*) > 17863 662976 0.9536 35.3917 libjvm.so SymbolTable::lookup_only(char const*, int, unsigned int&) > 17530 680506 0.9358 36.3275 libjvm.so PhaseChaitin::interfere_with_live(unsigned int, IndexSet*) > 16381 696887 0.8745 37.2019 libjvm.so PhaseIdealLoop::Dominators() > 16124 713011 0.8607 38.0627 libjvm.so MachNode::rematerialize() const > 15886 728897 0.8480 38.9107 libjvm.so SpinPause > 14687 743584 0.7840 39.6948 libjvm.so PhaseLive::add_liveout(Block*, IndexSet*, VectorSet&) > > Andrew. > > ------------------------------------------------------------------------------ > Infragistics Professional > Build stunning WinForms apps today! > Reboot your WinForms applications with our WinForms controls. > Build a bridge from your legacy apps to the future. > http://pubads.g.doubleclick.net/gampad/clk?id=153845071&iu=/4140/ostg.clktrk > _______________________________________________ > oprofile-list mailing list > opr...@li... > https://lists.sourceforge.net/lists/listinfo/oprofile-list > |
From: Andrew H. <ap...@re...> - 2014-07-31 08:21:44
|
On 30/07/14 23:15, Maynard Johnson wrote: > On 07/30/2014 11:37 AM, Andrew Haley wrote: >> There's a bug in Oprofile for AArch64 where "opreport -l" prints out lots >> of symbols as "x". Like this: >> >> 21690 604433 1.0010 27.8939 libjvm.so PhaseChaitin::build_ifg_physical(ResourceArea*) >> 20856 625289 0.9625 28.8564 libjvm.so ConnectionGraph::add_fields_to_worklist(FieldNode*, PointsToNode*) >> 20707 645996 0.9556 29.8120 libjvm.so $x >> 19824 665820 0.9149 30.7269 libjvm.so PhaseIdealLoop::is_dominator(Node*, Node*) >> 19483 685303 0.8991 31.6260 libjvm.so $x >> 17863 703166 0.8244 32.4504 libjvm.so SymbolTable::lookup_only(char const*, int, unsigned int&) >> 17530 720696 0.8090 33.2593 libjvm.so PhaseChaitin::interfere_with_live(unsigned int, IndexSet*) >> 16381 737077 0.7560 34.0153 libjvm.so PhaseIdealLoop::Dominators() >> 16124 753201 0.7441 34.7594 libjvm.so MachNode::rematerialize() const >> 15886 769087 0.7331 35.4925 libjvm.so SpinPause >> 14797 783884 0.6829 36.1754 libjvm.so $x >> >> >> It turns out that these "$x" symbols aren't symbols at all, but >> "mapping symbols". The AArch64 ELF specification requires that >> special symbols be inserted into object files to mark certain >> features: >> >> $x >> At the start of a region of code containing AArch64 instructions. >> >> $d >> At the start of a region of data. >> >> These symbols should be ignored by tools. The fix in Oprofile is >> trivial: >> >> diff --git a/libpp/profile_container.cpp b/libpp/profile_container.cpp >> index e543f51..ec8438c 100644 >> --- a/libpp/profile_container.cpp >> +++ b/libpp/profile_container.cpp >> @@ -81,6 +81,9 @@ void profile_container::add(profile_t const & profile, >> >> for (symbol_index_t i = 0; i < abfd.syms.size(); ++i) { >> >> + if (abfd.syms[i].name() == "$x") >> + continue; > This seems to be just applying a band aid to the problem. We end up losing samples that were incorrectly attributed to this special symbol, right? Those samples are probably for a real symbol I would expect. Is there any way to figure that out? I don't really know Oprofile well enough. I take it that those symbols are read earlier in the process? Al we need to do is throw them away at that stage. I'll have a look. Andrew. |
From: Andrew H. <ap...@re...> - 2014-07-31 10:43:28
|
On 07/30/2014 11:15 PM, Maynard Johnson wrote: > This seems to be just applying a band aid to the problem. We end up > losing samples that were incorrectly attributed to this special > symbol, right? Those samples are probably for a real symbol I would > expect. Is there any way to figure that out? I don't know what's going on at this level. Does perf do the mapping from addresses to symbols, or is that done later by oprofile? I haven't yet been able to find the code which takes an address and figures out which symbol that address maps to. Andrew. |
From: Maynard J. <may...@us...> - 2014-07-31 13:42:38
|
On 07/31/2014 05:43 AM, Andrew Haley wrote: > On 07/30/2014 11:15 PM, Maynard Johnson wrote: > >> This seems to be just applying a band aid to the problem. We end up >> losing samples that were incorrectly attributed to this special >> symbol, right? Those samples are probably for a real symbol I would >> expect. Is there any way to figure that out? > > I don't know what's going on at this level. Does perf do the mapping > from addresses to symbols, or is that done later by oprofile? I > haven't yet been able to find the code which takes an address and > figures out which symbol that address maps to. Hi, Andrew, It may turn out that, due to sampling skid (where sample addresses can be off by a few instructions, we just simply can't avoid attributing a small number of samples to this $x symbol. In your initial posting on the topic, the percentages for $x samples were very low. Do you ever see a relatively high percentage of samples for $x symbols? Or, if you were to total up all samples for $x symbols, is it a relatively high number compared to the total samples? If the answer is "no", it's never a high percentage of samples being attributed to $x symbols, then the best way to handle this is to filter them out at the point where we first gather the symbols for the op_bfd object. Look at the libutil++/bfd_support.cpp:interesting_symbol function. As a matter of fact, you'll see where we already filter out some ARM assembler internal mapping symbols. On the other hand, if the percentage of samples you'd be throwing away is pretty high, then further debugging is needed . . . so co! ntinue rea ding the "OPROFILE INTERNALS" part of my reply. OPROFILE INTERNALS ------------------ When you run one of oprofile's post-profiling tools (e.g., opreport), it identifies all of the binary files (executables, shared libs) for which samples have been collected. For each binary, an "op_bfd" object is created, which is backed by a bfd obtained from libbfd via the bfd_fdopenr() function. It's during the construction of the op_bfd object that the symbols for the corresponding binary are gathered, using libbfd functions. Then, in libpp/profile_container.cpp:add, for a given op_bfd object, oprofile iterates over the symbols and matches up the addresses of profile samples with each symbol. In particular, when "abfd.get_symbol_range()" is called for the symbol "$x" to get the start and end addresses, we use profile.samples_range() to get an iterator pair to accumulate the samples that fit in that range. And evidently, the count of samples returned from accumulate for $x is non-zero! Your patch simply throws away those samples. I suggest running opreport with the "--verbose=all --symbols" and search for the debug output for "$x" symbol which will give you the start and end addresses for it. How big is the range? Is the range accurate? Then do an 'objdump -d' on one of these binaries having a $x symbol and try to figure out if libbfd is handling this symbol properly. -Maynard > > Andrew. > |
From: Andrew H. <ap...@re...> - 2014-07-31 13:50:42
|
On 07/31/2014 02:42 PM, Maynard Johnson wrote: > On 07/31/2014 05:43 AM, Andrew Haley wrote: >> On 07/30/2014 11:15 PM, Maynard Johnson wrote: >> >>> This seems to be just applying a band aid to the problem. We end up >>> losing samples that were incorrectly attributed to this special >>> symbol, right? Those samples are probably for a real symbol I would >>> expect. Is there any way to figure that out? >> >> I don't know what's going on at this level. Does perf do the mapping >> from addresses to symbols, or is that done later by oprofile? I >> haven't yet been able to find the code which takes an address and >> figures out which symbol that address maps to. > It may turn out that, due to sampling skid (where sample addresses > can be off by a few instructions, we just simply can't avoid > attributing a small number of samples to this $x symbol. Why? As far as I'm aware the $x symbols only ever overlap real symbols -- they are never the only symbol that refers to an object -- so they can just be ignored, and we could pick the true symbols instead.. > In your initial posting on the topic, the percentages for $x samples > were very low. Some of them were as much as 1% of the total run time. The total attributed to "$x" symbols is maybe 5%. > Do you ever see a relatively high percentage of > samples for $x symbols? Or, if you were to total up all samples for > $x symbols, is it a relatively high number compared to the total > samples? If the answer is "no", it's never a high percentage of > samples being attributed to $x symbols, then the best way to handle > this is to filter them out at the point where we first gather the > symbols for the op_bfd object. Look at the > libutil++/bfd_support.cpp:interesting_symbol function. As a matter > of fact, you'll see where we already filter out some ARM assembler > internal mapping symbols. On the other hand, if the percentage of > samples you'd be throwing away is pretty high, then further > debugging is needed . . . so continue rea ding the "OPROFILE > INTERNALS" part of my reply. > > OPROFILE INTERNALS > ------------------ > When you run one of oprofile's post-profiling tools (e.g., > opreport), it identifies all of the binary files (executables, > shared libs) for which samples have been collected. For each > binary, an "op_bfd" object is created, which is backed by a bfd > obtained from libbfd via the bfd_fdopenr() function. It's during the > construction of the op_bfd object that the symbols for the > corresponding binary are gathered, using libbfd functions. Then, in > libpp/profile_container.cpp:add, for a given op_bfd object, oprofile > iterates over the symbols and matches up the addresses of profile > samples with each symbol. In particular, when > "abfd.get_symbol_range()" is called for the symbol "$x" to get the > start and end addresses, we use profile.samples_range() to get an > iterator pair to accumulate the samples that fit in that range. And > evidently, the count of samples returned from accumulate for $x is > non-zero! Your patch simply throws away those samples. > > I suggest running opreport with the "--verbose=all --symbols" and > search for the debug output for "$x" symbol which will give you the > start and end addresses for it. How big is the range? Is the range > accurate? Then do an 'objdump -d' on one of these binaries having a > $x symbol and try to figure out if libbfd is handling this symbol > properly. OK, will do. Thanks, Andrew. |
From: William C. <wc...@re...> - 2014-07-31 14:03:53
|
On 07/31/2014 04:21 AM, Andrew Haley wrote: > On 30/07/14 23:15, Maynard Johnson wrote: >> On 07/30/2014 11:37 AM, Andrew Haley wrote: >>> There's a bug in Oprofile for AArch64 where "opreport -l" prints out lots >>> of symbols as "x". Like this: >>> >>> 21690 604433 1.0010 27.8939 libjvm.so PhaseChaitin::build_ifg_physical(ResourceArea*) >>> 20856 625289 0.9625 28.8564 libjvm.so ConnectionGraph::add_fields_to_worklist(FieldNode*, PointsToNode*) >>> 20707 645996 0.9556 29.8120 libjvm.so $x >>> 19824 665820 0.9149 30.7269 libjvm.so PhaseIdealLoop::is_dominator(Node*, Node*) >>> 19483 685303 0.8991 31.6260 libjvm.so $x >>> 17863 703166 0.8244 32.4504 libjvm.so SymbolTable::lookup_only(char const*, int, unsigned int&) >>> 17530 720696 0.8090 33.2593 libjvm.so PhaseChaitin::interfere_with_live(unsigned int, IndexSet*) >>> 16381 737077 0.7560 34.0153 libjvm.so PhaseIdealLoop::Dominators() >>> 16124 753201 0.7441 34.7594 libjvm.so MachNode::rematerialize() const >>> 15886 769087 0.7331 35.4925 libjvm.so SpinPause >>> 14797 783884 0.6829 36.1754 libjvm.so $x >>> >>> >>> It turns out that these "$x" symbols aren't symbols at all, but >>> "mapping symbols". The AArch64 ELF specification requires that >>> special symbols be inserted into object files to mark certain >>> features: >>> >>> $x >>> At the start of a region of code containing AArch64 instructions. >>> >>> $d >>> At the start of a region of data. >>> >>> These symbols should be ignored by tools. The fix in Oprofile is >>> trivial: >>> >>> diff --git a/libpp/profile_container.cpp b/libpp/profile_container.cpp >>> index e543f51..ec8438c 100644 >>> --- a/libpp/profile_container.cpp >>> +++ b/libpp/profile_container.cpp >>> @@ -81,6 +81,9 @@ void profile_container::add(profile_t const & profile, >>> >>> for (symbol_index_t i = 0; i < abfd.syms.size(); ++i) { >>> >>> + if (abfd.syms[i].name() == "$x") >>> + continue; > >> This seems to be just applying a band aid to the problem. We end up losing samples that were incorrectly attributed to this special symbol, right? Those samples are probably for a real symbol I would expect. Is there any way to figure that out? > Hi Andrew, Have you tried running the same experiment on x86-64 and compared the resulting output? I suspect that the "$x" map to some methods but for some reason oprofile is not getting the right location/name and ends up with "$x". It would be good to compare the output to get some clue what "$x" might be. You might also use "opreport --detail --symbols" to see where the samples are actually recorded and see where those $x functions are being located. The "--detail" will provide a huge amount of output. The sample skid is unlikely to be causing the problem. That would just be different address in the same method or another method, so it should still have a mapping for the real method name. -Will > I don't really know Oprofile well enough. I take it that those symbols > are read earlier in the process? Al we need to do is throw them away > at that stage. I'll have a look. > > Andrew. > > |
From: Andrew H. <ap...@re...> - 2014-07-31 14:13:47
|
On 07/31/2014 03:03 PM, William Cohen wrote: > Have you tried running the same experiment on x86-64 and compared > the resulting output? I suspect that the "$x" map to some methods > but for some reason oprofile is not getting the right location/name > and ends up with "$x". It would be good to compare the output to > get some clue what "$x" might be. You might also use "opreport > --detail --symbols" to see where the samples are actually recorded > and see where those $x functions are being located. The "--detail" > will provide a huge amount of output. Sure, x86-64 is fine: it doesn't have mapping symbols. I can see all the "$x" symbols in the symtab on AArch64. Andrew. |
From: William C. <wc...@re...> - 2014-07-31 15:01:04
|
On 07/31/2014 10:13 AM, Andrew Haley wrote: > On 07/31/2014 03:03 PM, William Cohen wrote: > >> Have you tried running the same experiment on x86-64 and compared >> the resulting output? I suspect that the "$x" map to some methods >> but for some reason oprofile is not getting the right location/name >> and ends up with "$x". It would be good to compare the output to >> get some clue what "$x" might be. You might also use "opreport >> --detail --symbols" to see where the samples are actually recorded >> and see where those $x functions are being located. The "--detail" >> will provide a huge amount of output. > > Sure, x86-64 is fine: it doesn't have mapping symbols. I can see all > the "$x" symbols in the symtab on AArch64. > > Andrew. > Hi Andrew, The "--details" output was to see if there was a pattern to attribution to "$x". Using the "Detailed examination of Java task processor usage" from https://access.redhat.com/articles/911073 I am able to reproduce the issue: $ operf java -agentlib:jvmti_oprofile -jar dacapo-9.12-bach.jar sunflow $ opreport --symbols |grep "\$x" Using /discer.farm/home/wcohen/dacampo/oprofile_data/samples/ for samples directory. WARNING: Lost samples detected! See /discer.farm/home/wcohen/dacampo/oprofile_data/samples/operf.log for details. warning: /no-vmlinux could not be found. warning: [vdso] (tgid:6974 range:0x3ff96b10000-0x3ff96b2ffff) could not be found. 469 0.0591 libc-2.17.so $x 331 0.0417 libz.so.1.2.7 $x 88 0.0111 libc-2.17.so $x 56 0.0071 libz.so.1.2.7 $x 27 0.0034 ld-2.17.so $x 21 0.0026 libc-2.17.so $x 14 0.0018 libpthread-2.17.so $x 13 0.0016 libpthread-2.17.so $x 10 0.0013 libc-2.17.so $x 10 0.0013 libpthread-2.17.so $x 9 0.0011 libc-2.17.so $x 9 0.0011 libopagent.so.1.0.1 $x 5 6.3e-04 ld-2.17.so $x 4 5.0e-04 ld-2.17.so $x 4 5.0e-04 ld-2.17.so $x 4 5.0e-04 libc-2.17.so $x 4 5.0e-04 libjvmti_oprofile.so.0.0.0 $x 3 3.8e-04 ld-2.17.so $x 3 3.8e-04 libz.so.1.2.7 $x 2 2.5e-04 ld-2.17.so $x 2 2.5e-04 ld-2.17.so $x 2 2.5e-04 libc-2.17.so $x 1 1.3e-04 ld-2.17.so $x 1 1.3e-04 ld-2.17.so $x 1 1.3e-04 ld-2.17.so $x 1 1.3e-04 ld-2.17.so $x 1 1.3e-04 ld-2.17.so $x 1 1.3e-04 ld-2.17.so $x 1 1.3e-04 libc-2.17.so $x 1 1.3e-04 libc-2.17.so $x 1 1.3e-04 libc-2.17.so $x 1 1.3e-04 libc-2.17.so $x 1 1.3e-04 libc-2.17.so $x 1 1.3e-04 libc-2.17.so $x 1 1.3e-04 libdl-2.17.so $x 1 1.3e-04 libdl-2.17.so $x 1 1.3e-04 libjvmti_oprofile.so.0.0.0 $x $ opreport --symbols --details|more /$x ...skipping 00000000000851e8 469 0.0591 libc-2.17.so $x 00000000000851e8 14 2.9851 00000000000851f8 14 2.9851 0000000000085200 13 2.7719 0000000000085214 8 1.7058 0000000000085218 1 0.2132 0000000000085220 3 0.6397 0000000000085224 38 8.1023 0000000000085228 5 1.0661 000000000008522c 2 0.4264 0000000000085230 1 0.2132 0000000000085234 50 10.6610 0000000000085238 5 1.0661 0000000000085240 9 1.9190 0000000000085244 41 8.7420 0000000000085250 60 12.7932 0000000000085254 1 0.2132 0000000000085258 1 0.2132 0000000000085260 40 8.5288 0000000000085268 21 4.4776 0000000000085274 4 0.8529 0000000000085278 2 0.4264 0000000000085280 7 1.4925 0000000000085290 24 5.1173 000000000008529c 2 0.4264 00000000000852a0 7 1.4925 00000000000852b0 13 2.7719 00000000000852bc 1 0.2132 00000000000852c0 1 0.2132 00000000000852d0 71 15.1386 00000000000852d8 3 0.6397 00000000000852ec 6 1.2793 00000000000852fc 1 0.2132 looking through the "objdump -d /usr/lib64/libc-2.17.so" looks like it matches up with _wordcopy_fwd_aligned: 00000000000851e8 <_wordcopy_fwd_aligned>: 851e8: 92400843 and x3, x2, #0x7 851ec: d1000463 sub x3, x3, #0x1 851f0: f100187f cmp x3, #0x6 ... Took a look at some other $x examples: 0000000000006b18 331 0.0417 libz.so.1.2.7 $x interior of some function 0000000000036a64 88 0.0111 libc-2.17.so $x maps to 0000000000036a64 <msort_with_tmp.part.0>: 00000000000095a4 56 0.0071 libz.so.1.2.7 $x interior of some function 0000000000016150 27 0.0034 ld-2.17.so $x maps to strcmp So it looks like the samples are being mapped to some functions, but the function names are not being recorded correctly in some cases. -Will |
From: Andrew H. <ap...@re...> - 2014-07-31 15:13:38
|
I think this is the correct fix: diff --git a/libutil++/bfd_support.cpp b/libutil++/bfd_support.cpp index a3bee99..d5fd70d 100644 --- a/libutil++/bfd_support.cpp +++ b/libutil++/bfd_support.cpp @@ -475,7 +475,8 @@ bool interesting_symbol(asymbol * sym) /* ARM assembler internal mapping symbols aren't interesting */ if ((strcmp("$a", sym->name) == 0) || (strcmp("$t", sym->name) == 0) || - (strcmp("$d", sym->name) == 0)) + (strcmp("$d", sym->name) == 0) || + (strcmp("$x", sym->name) == 0)) return false; // C++ exception stuff Andrew. |
From: Maynard J. <may...@us...> - 2014-07-31 16:23:26
|
On 07/31/2014 10:13 AM, Andrew Haley wrote: > I think this is the correct fix: Andrew, I think so too, especially in light of what Will has shown in his note. Although I don't really know what these special symbols are used for, I can see how they may have the same starting address of some other symbol. In libutil++/op_bfd.cpp:get_symbols, we iterate over the collection of symbols we got from libbfd and remove duplicates (i.e., where the vma is the same). It seems that the algorithm just happens to be keeping the $x symbol instead of the one we want. Following the removal of the duplicates, we then ascertain the length of each symbol that's still left in the collection. So the $x symbols end up having a non-zero length given to them by virtue of how that algorithm works. So I believe filtering out the $x symbols before removing duplicates should fix this. I'll commit this patch later today or tomorrow if I don't hear anything contrary from either you or Will. Thanks. -Maynard > > diff --git a/libutil++/bfd_support.cpp b/libutil++/bfd_support.cpp > index a3bee99..d5fd70d 100644 > --- a/libutil++/bfd_support.cpp > +++ b/libutil++/bfd_support.cpp > @@ -475,7 +475,8 @@ bool interesting_symbol(asymbol * sym) > /* ARM assembler internal mapping symbols aren't interesting */ > if ((strcmp("$a", sym->name) == 0) || > (strcmp("$t", sym->name) == 0) || > - (strcmp("$d", sym->name) == 0)) > + (strcmp("$d", sym->name) == 0) || > + (strcmp("$x", sym->name) == 0)) > return false; > > // C++ exception stuff > > Andrew. > > > ------------------------------------------------------------------------------ > Infragistics Professional > Build stunning WinForms apps today! > Reboot your WinForms applications with our WinForms controls. > Build a bridge from your legacy apps to the future. > http://pubads.g.doubleclick.net/gampad/clk?id=153845071&iu=/4140/ostg.clktrk > _______________________________________________ > oprofile-list mailing list > opr...@li... > https://lists.sourceforge.net/lists/listinfo/oprofile-list > |
From: Maynard J. <may...@us...> - 2014-08-01 14:27:42
|
On 07/31/2014 11:23 AM, Maynard Johnson wrote: > On 07/31/2014 10:13 AM, Andrew Haley wrote: >> I think this is the correct fix: > Andrew, > I think so too, especially in light of what Will has shown in his note. Although I don't really know what these special symbols are used for, I can see how they may have the same starting address of some other symbol. In libutil++/op_bfd.cpp:get_symbols, we iterate over the collection of symbols we got from libbfd and remove duplicates (i.e., where the vma is the same). It seems that the algorithm just happens to be keeping the $x symbol instead of the one we want. Following the removal of the duplicates, we then ascertain the length of each symbol that's still left in the collection. So the $x symbols end up having a non-zero length given to them by virtue of how that algorithm works. So I believe filtering out the $x symbols before removing duplicates should fix this. > > I'll commit this patch later today or tomorrow if I don't hear anything contrary from either you or Will. Patch committed. Thanks for reporting this. -Maynard > > Thanks. > -Maynard >> >> diff --git a/libutil++/bfd_support.cpp b/libutil++/bfd_support.cpp >> index a3bee99..d5fd70d 100644 >> --- a/libutil++/bfd_support.cpp >> +++ b/libutil++/bfd_support.cpp >> @@ -475,7 +475,8 @@ bool interesting_symbol(asymbol * sym) >> /* ARM assembler internal mapping symbols aren't interesting */ >> if ((strcmp("$a", sym->name) == 0) || >> (strcmp("$t", sym->name) == 0) || >> - (strcmp("$d", sym->name) == 0)) >> + (strcmp("$d", sym->name) == 0) || >> + (strcmp("$x", sym->name) == 0)) >> return false; >> >> // C++ exception stuff >> >> Andrew. >> >> >> ------------------------------------------------------------------------------ >> Infragistics Professional >> Build stunning WinForms apps today! >> Reboot your WinForms applications with our WinForms controls. >> Build a bridge from your legacy apps to the future. >> http://pubads.g.doubleclick.net/gampad/clk?id=153845071&iu=/4140/ostg.clktrk >> _______________________________________________ >> oprofile-list mailing list >> opr...@li... >> https://lists.sourceforge.net/lists/listinfo/oprofile-list >> > > > ------------------------------------------------------------------------------ > Infragistics Professional > Build stunning WinForms apps today! > Reboot your WinForms applications with our WinForms controls. > Build a bridge from your legacy apps to the future. > http://pubads.g.doubleclick.net/gampad/clk?id=153845071&iu=/4140/ostg.clktrk > _______________________________________________ > oprofile-list mailing list > opr...@li... > https://lists.sourceforge.net/lists/listinfo/oprofile-list > |
From: William C. <wc...@re...> - 2014-07-31 18:47:13
|
On 07/31/2014 11:13 AM, Andrew Haley wrote: > I think this is the correct fix: > > diff --git a/libutil++/bfd_support.cpp b/libutil++/bfd_support.cpp > index a3bee99..d5fd70d 100644 > --- a/libutil++/bfd_support.cpp > +++ b/libutil++/bfd_support.cpp > @@ -475,7 +475,8 @@ bool interesting_symbol(asymbol * sym) > /* ARM assembler internal mapping symbols aren't interesting */ > if ((strcmp("$a", sym->name) == 0) || > (strcmp("$t", sym->name) == 0) || > - (strcmp("$d", sym->name) == 0)) > + (strcmp("$d", sym->name) == 0) || > + (strcmp("$x", sym->name) == 0)) > return false; > > // C++ exception stuff > > Andrew. Hi Andrew, This patch does seem to clean up the "$x". I applied the patch and compared the output between the unpatched and patched version. It seems to map all the previous "$x" names to reasonable names function names. Thanks, -Will |