Re: how to collect information regarding function calls in run time?
Sorry to revive this old thread, and thank you for the suggestions given, but I've been trying to make these work for my case with little success and I need a hand to understand what I'm doing wrong. Regarding bpftrace: This seemed like the best option since I could use it to count frames of the stack with depth 2, allowing me to know precisely the amount of times each specific call has been made. However, I could not use it because since I have to probe every function, it would raise an error related to open file limit. I've tried setting the open file limit to unlimited, but the command I used to do so said it was impossible, also the current limit is set to 1048576, so I'm guessing that probing every function isn't a viable solution. Regarding perf: I couldn't find out how to count each call with perf, but I could count how many times each function was called. Differently from bpftrace, I need to use a command for each function I would like to probe, so I created a script that would get all the functions that can be probed and call that command for each of them. Unfortunately this took too long, so I stopped after a certain number of probes were created and executed my test, at that time, the machine hanged. With a low number of functions being probed it worked fine though. Right now, the solution I can see is using bpftrace to probe a very limited number of calls, profile an execution, then repeat the profile for different set of probes, which can take a very long time. Is there an easier way (less time consuming) to achieve the same results (counting how many times each call instruction has been executed)? Thanks you for the attention, Pedro On Wed, Apr 3, 2019 at 6:23 PM Augusto Mecking Caringi < augustocaringi@gmail.com> wrote:
Hi,
On Wed, Apr 3, 2019 at 9:26 PM Pedro Terra Delboni <terra0009@gmail.com> wrote:
Hello!
I have a question about profiling, please, let me know if this is not the right mailing list to post these kind of questions.
Is there a way for me to record how many times each specific direct call to a function happened? I've seen ways of profiling the kernel that calculate how much time the system spent in each function, but having a bit more information related to calls would be really good.
I would like to know, for every function call that happens in run time, who called it (it's for a project in my University).
I've also seen (I may be mistaken here) that by compiling the kernel with perf, each function will start with a stub call which can be used for profiling purposes. I was thinking in using this stub to plug a function to dump (somewhere) the return address before it's own (so I can collect the info about where the call came from). I wonder if changing every stub calls in all functions to dump its return address wouldn't create too much of a latency impact to the point of skewing the control flow of the execution, or even making it nonviable.
Thanks in advance, any help would be great! If this is not the right place to post this question, I would appreciate if anyone could point me to the right place.
There is also a new tool called bpftrace that can help you...
https://github.com/iovisor/bpftrace
Regards,
-- Augusto Mecking Caringi
On Tue, May 14, 2019 at 10:55:40AM -0300, Pedro Terra Delboni wrote:
Sorry to revive this old thread, and thank you for the suggestions given, but I've been trying to make these work for my case with little success and I need a hand to understand what I'm doing wrong.
Given that this is a university assignment, asking for help from random people on the internet seems like an odd request, do we too get a grade for this? :) Good luck! greg k-h
Sorry, I believe I was not clear in how this relates to my university. I'm a post-graduate student working on a thesis, I'm not looking for the answer of an exercise proposed by the university. So neither you nor I can get a grade from this (though this may help me finish things sooner). On Tue, May 14, 2019 at 11:05 AM Greg KH <greg@kroah.com> wrote:
On Tue, May 14, 2019 at 10:55:40AM -0300, Pedro Terra Delboni wrote:
Sorry to revive this old thread, and thank you for the suggestions given, but I've been trying to make these work for my case with little success and I need a hand to understand what I'm doing wrong.
Given that this is a university assignment, asking for help from random people on the internet seems like an odd request, do we too get a grade for this? :)
Good luck!
greg k-h
On Tue, 14 May 2019 10:55:40 -0300, Pedro Terra Delboni said:
Regarding bpftrace: This seemed like the best option since I could use it to count frames of the stack with depth 2, allowing me to know precisely the amount of times each specific call has been made. However, I could not use it because since I have to probe every function, it would raise an error related to open file limit. I've tried setting the open file limit to unlimited, but the command I used to do so said it was impossible, also the current limit is set to 1048576, so I'm guessing that probing every function isn't a viable solution.
What problem are you trying to solve? If you're trying to count how often *every* function is called, and the fact that one way to do it has an upper limit of a million is a problem, chances are that you haven't figured out what the *question* is yet. Usually, the number of calls isn't that important, the total runtime spent in the function is important. A one-liner inline accessor function that compiles down to 2-3 machine opcodes can be called tens of thousands of times a second and not be noticed. A function that takes milliseconds to complete will be noticed if it's called only a few dozen times a second. If you're trying to figure out how the functions fit together, a static call graph analysis tool to produce a map of what calls what may be what you need. Having said that, a kernel built with gcov or ftrace support will give you the info you need. See kernel/gcove/Kconfig and http://heim.ifi.uio.no/~knuto/kernel/4.14/dev-tools/gcov.html if you want to go that route. Resources for ftrace call counts: http://www.brendangregg.com/blog/2014-07-13/linux-ftrace-function-counting.h... https://wiki.linaro.org/KenWerner/Sandbox/ftrace and see section 'function profiler'. Be prepared for your kernel to be quite slow, and have to do a *lot* of data reduction. Note that you'll probably need to run for at least several hours, and of course the function counts will be *very* dependent on what you do - what gets called while I'm doing stuff like writing e-mail is very different from what happens during a kernel compile, and both of those are different from the function counts that happen when I back up my laptop to an external USB disk. (Note I've not *tried* any of the above - this laptop is slow enough as it is :)
On Tue, May 14, 2019 at 2:46 PM Valdis Klētnieks <valdis.kletnieks@vt.edu> wrote:
On Tue, 14 May 2019 10:55:40 -0300, Pedro Terra Delboni said:
Regarding bpftrace: This seemed like the best option since I could use it to count frames of the stack with depth 2, allowing me to know precisely the amount of times each specific call has been made. However, I could not use it because since I have to probe every function, it would raise an error related to open file limit. I've tried setting the open file limit to unlimited, but the command I used to do so said it was impossible, also the current limit is set to 1048576, so I'm guessing that probing every function isn't a viable solution.
What problem are you trying to solve?
If you're trying to count how often *every* function is called, and the fact that one way to do it has an upper limit of a million is a problem, chances are that you haven't figured out what the *question* is yet.
Usually, the number of calls isn't that important, the total runtime spent in the function is important. A one-liner inline accessor function that compiles down to 2-3 machine opcodes can be called tens of thousands of times a second and not be noticed. A function that takes milliseconds to complete will be noticed if it's called only a few dozen times a second.
If you're trying to figure out how the functions fit together, a static call graph analysis tool to produce a map of what calls what may be what you need.
Having said that, a kernel built with gcov or ftrace support will give you the info you need.
See kernel/gcove/Kconfig and http://heim.ifi.uio.no/~knuto/kernel/4.14/dev-tools/gcov.html if you want to go that route.
Resources for ftrace call counts:
http://www.brendangregg.com/blog/2014-07-13/linux-ftrace-function-counting.h...
https://wiki.linaro.org/KenWerner/Sandbox/ftrace and see section 'function profiler'.
Be prepared for your kernel to be quite slow, and have to do a *lot* of data reduction.
Note that you'll probably need to run for at least several hours, and of course the function counts will be *very* dependent on what you do - what gets called while I'm doing stuff like writing e-mail is very different from what happens during a kernel compile, and both of those are different from the function counts that happen when I back up my laptop to an external USB disk.
(Note I've not *tried* any of the above - this laptop is slow enough as it is :)
Thank you for the answer, I'll follow the appointed links. I agree that the question alone seems like a weird one, I just assumed when I wrote my first email that the explaining the motivation would only consume time of the reader. The subject I'm working on is Control-Flow Integrity, which instrument a code so that each indirect jump (which are usually returns or indirect calls) verify if the address they are returning is a valid one (so there is a code stub that runs in every function call and return). One tool was implemented by one of the university researchers in order to add such instrumentation to the kernel Linux [1]. [1] https://www.blackhat.com/docs/asia-17/materials/asia-17-Moreira-Drop-The-Rop... A more "secure" version of this implementation was proven to increase the latency by quite a lot, thus it isn't a viable solution atm. The latency increase is done mostly by the instrumentation when the function returns. The reason I want to count call instructions execution is because the function return tied to the most executed call instruction will be the one that will cause the greater increase in execution time, so by inlining that call we'll be exchanging this cost for the cache impact of the code expansion (as the code stub won't exist anymore for this call). The objective is to try to measure in which cases this exchange is a viable one (so we can decide which functions to inline/expand), and also try to find how many expansions would be necessary in order to increase viability of the current solution. I understand that the profiling result will change based on execution. We don't assume that the profiling will solve the latency issue for every case, but if it does for the profiled case it would already be an interesting result. This is only researching for now, I hope the results would be interesting to the community in the future, so any help would be appreciated. Please, let me know if I wasn't clear, or if you have any other ideas. Thanks a lot
On Tue, 14 May 2019 16:11:51 -0300, Pedro Terra Delboni said:
I agree that the question alone seems like a weird one, I just assumed when I wrote my first email that the explaining the motivation would only consume time of the reader.
Asking "what problem are you trying to solve" is a standard question, because whenever a programmer is saying "I can't get X to do Y", a good 85% of the time it turns out that isn't working because using W to do Z is the already-existing API for what they actually wanted to do....
The subject I'm working on is Control-Flow Integrity, which instrument a code so that each indirect jump (which are usually returns or indirect calls) verify if the address they are returning is a valid one (so there is a code stub that runs in every function call and return).
The reason I want to count call instructions execution is because the function return tied to the most executed call instruction will be the one that will cause the greater increase in execution time, so by inlining that call we'll be exchanging this cost for the cache impact of the code expansion (as the code stub won't exist anymore for this call).
I suspect that the vast majority of functions that are *that* heavily used are either (a) already inlined or (b) too large to inline - for instance, kmalloc is used heavily, but having separate inlined copies everyplace to avoid the return statement is going to bloat the code - and even worse, make almost all the inline copies cache-cold instead of one shared cache-hot chunk of 2K. And the question we *should* be asking is *not* "is the return address a plausible one". It's "is the return address *the one we were called from*". Checking whether kmalloc is about to return to a valid call point doesn't tell you much. Finding out that kmalloc is about to return to one of the 193,358 *other* call points rather than the one it was actually called from is something big.
On Fri, May 17, 2019 at 11:09 AM Valdis Klētnieks <valdis.kletnieks@vt.edu> wrote:
On Tue, 14 May 2019 16:11:51 -0300, Pedro Terra Delboni said:
I agree that the question alone seems like a weird one, I just assumed when I wrote my first email that the explaining the motivation would only consume time of the reader.
Asking "what problem are you trying to solve" is a standard question, because whenever a programmer is saying "I can't get X to do Y", a good 85% of the time it turns out that isn't working because using W to do Z is the already-existing API for what they actually wanted to do....
The subject I'm working on is Control-Flow Integrity, which instrument a code so that each indirect jump (which are usually returns or indirect calls) verify if the address they are returning is a valid one (so there is a code stub that runs in every function call and return).
The reason I want to count call instructions execution is because the function return tied to the most executed call instruction will be the one that will cause the greater increase in execution time, so by inlining that call we'll be exchanging this cost for the cache impact of the code expansion (as the code stub won't exist anymore for this call).
I suspect that the vast majority of functions that are *that* heavily used are either (a) already inlined or (b) too large to inline - for instance, kmalloc is used heavily, but having separate inlined copies everyplace to avoid the return statement is going to bloat the code - and even worse, make almost all the inline copies cache-cold instead of one shared cache-hot chunk of 2K.
It will bloat the code and the copies will negatively impact the cache, however, the current implementation is very time consuming, to the point where we believe the cache impact is a plausible option.
And the question we *should* be asking is *not* "is the return address a plausible one". It's "is the return address *the one we were called from*". Checking whether kmalloc is about to return to a valid call point doesn't tell you much. Finding out that kmalloc is about to return to one of the 193,358 *other* call points rather than the one it was actually called from is something big.
The reason we relaxed the question from which address we were called to which address is plausible is because verifying the address which we were called is a lot harder than verifying if we are returning to a kmalloc call (whichever it may be). The implementation which just verify a plausible address added enough latency for us to believe it is a viable option. The more secure implementation which verifies if a call is returning to its exact call point is the one we are trying to find ways to make it viable.
participants (3)
-
Greg KH -
Pedro Terra Delboni -
Valdis Klētnieks