Thank you for your response. I have included responses to your questions inline.
On Mon, Jun 12, 2017 at 9:20 PM, Steven Rostedt <rost...@goodmis.org> wrote: > On Mon, 12 Jun 2017 20:20:42 -0400 > Will Hawkins <wh...@virginia.edu> wrote: > >> Dear Mr. Rostedt and Kernel community, >> >> I hope that this is an appropriate place to ask this question, Please >> forgive me for wasting your time if it is not. I've searched for >> answers to this question on LKML and the "net" before asking. I >> apologize if I already missed the question and answer somewhere else. > > No no, this is the correct forum. Whew. > >> >> I was doing a gut check of my understanding of how the Kernel pages in >> a binary program for execution. I created a very small program that is >> two pages. The entry point to the program is on page a and the code >> simply jumps to the second page (b) for its termination. >> >> I compiled the program and dropped the kernel's memory caches [1]. >> Then I ran the program under perf: >> >> perf record --call-graph fp -e page-faults ../one_page_play/page > > Can you supply this program. So I can see exactly what it does? I have attached the binary to this email. I also provided the source so you can reproduce the situation directly. You can use the makefile provided as long as you have nasm installed. Although this is a response to a later question, I won't bury the lede: The program was written by hand in asm, compiled with nasm to object code and then run through gcc to get the output binary. Here is how that works: nasm -felf64 page.s && gcc -nostdlib page.o -o page The result, as far as ldd is concerned: hawkinsw@moormans:~/code/one_page_play$ ldd page not a dynamic executable > >> >> I looked at the results: >> >> perf report >> >> and the results were as I expected. There were two page faults for >> loading the code into memory and a page fault to >> copy_user_enhanced_fast_string invoked by execve's implementation when >> loading the binary. > > What does perf script show you? Here is what perf report --stdio shows: # Overhead Command Shared Object Symbol # ........ ....... ................. .................................. # 33.33% page page [.] _start | --- _start 33.33% page page [.] target | --- target 33.33% page [kernel.kallsyms] [k] copy_user_enhanced_fast_string | --- copy_user_enhanced_fast_string load_elf_binary search_binary_handler do_execve_common.isra.23 sys_execve stub_execve 0x7f51698a31e7 Here is what perf script shows: page 28787 113626.587935: page-faults: ffffffff81376609 copy_user_enhanced_fast_string ([kernel.kallsyms]) ffffffff812197bf load_elf_binary ([kernel.kallsyms]) ffffffff811c76df search_binary_handler ([kernel.kallsyms]) ffffffff811c8c8e do_execve_common.isra.23 ([kernel.kallsyms]) ffffffff811c9176 sys_execve ([kernel.kallsyms]) ffffffff8173afc9 stub_execve ([kernel.kallsyms]) 7f51698a31e7 [unknown] ([unknown]) page 28787 113626.587961: page-faults: 4000e0 _start (/home/hawkinsw/code/one_page_play/page) page 28787 113626.587968: page-faults: 401473 target (/home/hawkinsw/code/one_page_play/page) Again, this seems like exactly what I would expect. > >> >> I decided to run the application under ftrace just for fun. I wanted >> an excuse to learn more about it and this seemed like the perfect >> chance. I used the incredible trace-cmd suite for the actual >> incantation of ftrace. I won't include the actual incantations here >> because I used many of them while digging around. > > what events did you enable? Sorry for not including this in my first email. I enabled exceptions:page_fault_user. I ran the trace-cmd record like this: sudo ./trace-cmd record -e exceptions:page_fault_user -T --profile -l handle_mm_fault ../one_page_play/page and generated output like this: ./trace-cmd report --profile > >> >> The results are both expected and unexpected. I see output like this: >> >> Event: page_fault_user:0x4000e0 >> >> which indicates that there is a page fault at the program's entry >> point (and matches what I saw with the perf output). I have another >> similar entry that confirms the other expected page fault when loading >> the second page of the test application. >> >> However, I also see entries like this: >> >> Event: page_fault_user:0x7f4f590934c4 (1) > > This could very well be the dynamic linker. As I mentioned earlier, the program is statically linked. I did that for this very reason. I wanted to isolate the page faults for loading the program itself and not have to worry about interference from the static linker. I was *trying* to be intentional about getting these results. I appear to be missing the boat somewhere. > >> >> The addresses of the faults I see that match that pattern are not >> loaded into the application binary. What I discovered as I >> investigated, is that those page faults seem to occur when the kernel >> is attempting to record the output of stack traces, etc. > > Are you sure? What does ldd give you of your program? I posted this output above, a little out of order. I will repeat here: hawkinsw@moormans:~/code/one_page_play$ ldd page not a dynamic executable > >> >> After thinking through this, I came up with the following hypothesis >> which is the crux of this email: >> >> Ftrace's act of recording the traces that I requested to its ring >> buffer generated page faults of their own. These page faults are >> generated on behalf of the traced program and get reported in the >> results. > > There are no page faults that happen by the ftrace ring buffer that > would be associated with the program. This is what I would have expected, but it was/is my best guess. I > >> >> If that is correct/reasonable, it explains the differences between >> what perf is reporting and what ftrace is reporting and I am happy. >> If, however, that is a bogus conclusion, please help me understand >> what is going on. > > I'll need to know more about exactly what you are doing to help out. I hope that the information I posted above was helpful. Please let me know what additional information I can provide. Thanks again for taking the time to investigate this with me. I'm sure it's something simple that I am missing. Will > >> >> I know that everyone who is on this email is incredibly busy and has >> much to do. I hope that I've included enough information to make it >> possible for you experts to advise, but not included too much to waste >> your time. >> >> If you have the time or interest in answering, I would love to hear >> your responses. Please CC me directly on all responses. > > No worries about Ccing you directly. LKML gets over 600 emails a day. > Nobody reads it all. If someone isn't Cc'd directly, they will most > likely never respond. > >> >> Thanks again for your time! > > No problem. > > -- Steve > >> >> Will >> >> [1] I used echo 3 > /proc/sys/vm/drop_caches to accomplish this and >> issued it between every run. It may have been overkill, but I did it >> anyway. >
page
Description: Binary data
page.s
Description: Binary data
Makefile
Description: Binary data