Introduction to low-level profiling and tracing
CC Attribution - NonCommercial - ShareAlike 3.0 Unported:
You are free to use, adapt and copy, distribute and transmit the work or content in adapted or unchanged form for any legal and non-commercial purpose as long as the work is attributed to the author in the manner specified by the author or licensor and the work or content is shared also in adapted form only under the conditions of this
Heimes, Christian
Python has built-in tracing and profiling facilities in form of callback hooks in the sys module. The settrace and setprofile callbacks have several drawbacks. They slow down the Python interpreter considerable and only allow tracing of Python code. Modern OS and CPUs come with a variety of APIs for efficient and low-level tracing down to system calls, Kernel space code, and hardware events. Some tools even create code that runs in Kernel space. This talks is an introduction and comparison of various low and high level tools for profiling and tracing as well as visualization tools like flame graphs. It covers ptrace, perf, SystemTap, and BCC/eBPF. Ptrace based commands like strace are easy to use but slow. Perf allows lightweight profiling of hardware events and CPU instructions. SystemTap is a powerful toolkit plus DSL to instrument probe points inside the Kernel as well as static SystemTap/DTrace markers in libs and languages like Java, PHP, and Python. CPython comes with a set of instrumentations for SystemTap. BCC is a collection of tools that run as JIT optimized eBPF code in Kernel space. The talk is an introduction to basic concepts of low-level tracing and profiling on Linux. The main goal is the show the potential of the tools.
 Good morning everybody. I have to say you're missing five other excellent talks, so thanks for coming for my talk. This is a very heavily battled slot at the moment. Hi, I'm Christian Heimus. I'm going to talk to you about profiling and tracing with different tooling. One reason why I started to look into the topic was an issue I faced a couple of years ago that, well, every five minutes there was a blocking. The whole system didn't respond for a couple of seconds and we couldn't figure that out for a long time. Most were angry because we lost a bit of money. That's really annoying. The two things I will show you, you can actually figure that out. The similar talk we got yesterday, which I missed while I was giving another talk with Steve Dower, by Christoph Hare, who looked into why is a problem with the GIL or a problem with me because the system is not responding. One of the final motivations for this talk is something when I parted this talk, originally talked at a general web developer conference with examples in Python and PHP to pure Python using requests, figured out there's a big block, almost 40% wasting on something very, very interesting. This is a flame graph of requests call. At the end we will see what that thing actually is, this block, and why you should use request.session if you do a lot of requests in a loop. Alternative title for this talk is actually two and a half use cases for tracing tools because you can use the tracing tools not only for debugging and profiling, there's also something very cool for anybody working in quality engineering or testing, which I will show later on. I learned that just a year ago at another conference. So who am I? Hi. I'm from Hamburg, Python call developer using Python for 18 years almost now, working mostly in security in Python and I'm making money by working for Red Hat on security engineering, software stack called free IPA. So a gender and gull to the stock is to explain what this picture is all about. So this is a, not all, a big fraction of different profiling and tracing and performance investigation tools for Linux. For different kinds of the stack down from what the CPU is doing on a very, very low level to very, very high level what the application is doing. After a short introduction, I will introduce you to user space tracing tools based on the P traces call and the second half will be about kernel tracing and hardware tracing tool that can go down to the very, very low level summary and I may have, I don't think maybe five minutes of question and answers. Some special thanks. So a lot of these demos I'm going to show are based on tooling and blog posts by Brandon Greg. So if you're interested in profiling and tracing, go to Brandon Greg's website. He's fantastic. Victor's dinner also has been investing lots of time to optimize Python and has some very helpful explanations how to do proper benchmarking because benchmarking is super hard and super hard to get correct. Dimitri Lavin, I'm at him, the maintainer of S trace at a conference a while ago, along some of the cool new tricks and another engineer Redhead showed me another couple of tricks for tracing for system engineers. So this is a combination of some talks I saw before, some tooling I've been using for a while and yeah. Introduction. So some terminology, most people think of debugging as like identifying like removing bugs, which is usually if you do debugging as an engineer, it's very costly because you have to invest time. You can't do that easily on a production system because you slow down production system a lot so you need to build your additional fake production system or your staging system at data and you can't actually do much of the same things because you don't see kind of traffic patterns. So this is a better thing. It's tracing, which I will show, he is more like observing monitoring. We do it the right way, that's why there's small star on your face. It doesn't slow down your production system much. It's still a small impact, but it's mostly okay and better than having big performance issue in production. And once you do tracing and get data as a byproduct, you can also do some kind of profiling and data analysis and visualization of what's going wrong. A methodology, so there are different kinds of tracing. The simplest part you may know is like application level tracing, you will debug build, you have some kind of tooling that writes lock files somewhere like my SQL slow query, Python at a high level, set trace call, you can add a call back that gets called when something is going on, et cetera, et cetera. There are also more user space tracing that go a bit deeper like on the C level, you can load something into your process space, you can use P tracing, even deeper is kernel space tracing, which uses the kernel to investigate what the operating system is doing on a lower level or how user space communicates with kernel space and hardware. And finally, there's actual hardware tracing. So any modern CPUs had special capabilities to do hardware performance counting, power management unit controls, you can see what different health cache levels and just things you could actually do. To do tracing, you often have to do some special steps, you have to install some tooling, often you need special permission, so you can't do some of the tracing as a user and sometimes not even as an admin, so you have to disable some protections like you have to disable secure boot to inject kernel models because low level tracing is often like life patching your kernel, which is a bit scary but also very cool. Just write stuff that runs in the kernel, unlimited, accessing all hardware, yeah. But to do tracing, profiling and understanding what's going on, a big issue is statistics are very hard. You should at least know a bit of statistics and you may know the first phrase, the second one is German for who measures fertilizer, so just to... or manure, yeah. So to understand statistics, just some things if you're interested in that you should learn about as different kinds or what's different than average mean and for profiling often they're useful to you with the percentile. So how good are 95% of all requests or 99% because you don't often care that much about outliers or you want to specifically know when there's a big outlier. There are different kind of errors, you can have observational errors, you can have random errors that modify your output, they're also kind of biases, so if you're looking very hard at some area, have some opinions about that, you try to confirm your own opinion or the human factor while you may be looking in the wrong direction. There's also very misleading ways to present data that can actually fool you or fool other people so Vatican City has like 2.27 pove square kilometer which is a correct result but totally yeah, misleading. If you use a sampling profiler, not profiling like every instance but do regular sampling, you can have like sampling errors, Nick was channel theorem is a fun thing if you book more than images or any kind of other sampling or any kind of electronic. And there are multiple papers on the topic, a lot of that one is very fun to read, producing run data without doing anything obviously wrong. This is a very fun paper that claims like stuff that went wrong because people are looking the wrong way. And computers are very, very noisy, so this is one second of my laptop doing nothing and this, well, well lots of going on although it's doing actually nothing in the background. So CPUs, power states, etc. So Victor Stinnos blog explains how you have to configure and reboot and set up your kernel and rebating system to make sure that you remove some of the noise for some of the CPUs and get rid of RQ handlers and balancers and whatever. One of the things is we had a very fun back a while ago where depending on your environment how the length of like your host name or how much environment variables you have in your system changes the way how memory is allocated and if you go over threshold then you may suddenly go from just a couple of mem app calls to a lot of mapping and unmapping of the memory of pages that can change your performance a lot. It just took us ages to figure that out. So let's profile. Very easy case. So the first thing I'm going to show is reading a file and the simple thing you can do in Python is just to take the time, do something, take the time again. While there are multiple issues with that kind of approach, you're missing a fun talk on the other side like what a day has 24 hours plus minus one. Why if you have time zone switches, if you have like a clock show that's changing, you have to use a clock source to do profiling that does not change on your surroundings. So this clock source I'm using here is a bad one. So if you do profiling like on the ST switch, you get like takes our extra or I get negative results for that. So it's one of the caveats you should mention, should take care of. So some of the examples I'm using next one is just a very simple shell thing. It's doing cat. Things I'm using Python to open read from file. And some of the more advanced things I'm using HTTPS with requests. Most of you know it does a lot of things. So it does like network operations, file operations, it does something with SSL, OpenSSL, TLS encryption and a lot of things. So it shows lots of different areas where you can get very surprising results. So section one, Ptrace. Ptrace is very old feature from the old Unix days, about 1985. It's a way to do the user space tracing and it's used by lots of tooling. You may not. You can use the new debugger to debug a C program, if you use Strace, if you do code coverage of any kind of C library, a lot of libraries you will use Ptrace more like. And Ptrace is useful but slow and useful and it's mostly easy to use. So one example here is I'm using Ltrace at the library called tracer to see if it's big enough. Perfect. And to see what if I do requests, I want to see all variables or all function called starting with SSL, C to X, something at any library that's loaded. So that's the at sign after that is the library. That shows me different function calls I'm getting, which libraries are the type SSL model, the internal dash SSL, underscore SSL, and there are a couple of calls to see which memory addresses are called and the results return results on the right side. Not very helpful but you can see if, for example, I want to investigate if you have programs calling, especially function at all, it's rather nice for that. You can also do something like count how many memory allocations you do. So I'm running two processes and two different shells, so I get the pit, then I use Ltrace to trace malloc, realloc, and free at any library. As soon as I do that pit, I run requests call and I get how many allocations I get and free calls I get. But one downside from pitrace is it's slow. So that one took instead of half a second or a very slow, like three, four seconds. So the overhead is extremely high because Ltrace has to jump back and forth between kernel space and user space a lot. Similar tool is the tall Strace where you can investigate system calls and developed by Paul Kranburg in 1991 and now maintained by Dimitri11. And so the logo of Strace is an ostrich. Why an ostrich? Well, if you know Dutch or maybe German, it's straus. It's the name of the bird. So in German or in Dutch, it's Dutch. So that's straus. And with Strace, you do system call tracing. So what's system call tracing? Oh. Does it load? No, it doesn't load. Oh, is it back in my... Okay, that's supposed to be a circle of the different rings of a CPU. You see a bit of the circle that's around because a way how modern operating systems work is that all processes run in user space. User space is not allowed directly to do anything with hardware, even like memories virtualized, access to any kind of hardware calls abstracted by the kernel. You have to tell the kernel, please open that file for me. Please do something, send something for me on the network device. And this is done by a syscall. So you call a feature in the kernel, the kernel does some verification and then talks for you to the operating system and goes back. And this is called a syscall. And anytime you do a syscall, you have to do a context switch. So the kernel has to save the user space state, set up his kernel space state on the CPU, do something and go back. And that takes a lot of time, which you can't see in here. Well, it works as a city. So it's tracing like you, one thing is make open a file. So you want to like catch this etsy, oh, that's release file and see which files are actually opened by care in that way. And you see like nothing. Well, that's bad. Strange, we're tracing open, but open is the system called to open a file still is no result. It's peculiar. So let's just look for all syscalls made and you see, oh, it doesn't call open, it called something called open at or open at. So the kernel does not have guys once to scroll for specific tasks, they open like a family of syscalls to do related things. And GPC decided to move away from the old open syscall because not available on all operating systems and CPU architectures, but use open at a while ago. So one thing if you want to stress like open calls is to use like this regular expression or even easier. There are like multiple families of things I will explain in a minute. And this approach ultimately the regular expression is a bit bad if you like stat, it's that code like get status of a file like file size and permission, they are like a plentitude of differences calls which may or may not be available or may or may not give you the correct results. And GPC does the correct thing but you need to actually track them all. So easier way to do that comes next, but first, yeah. First look at how the stress open at call works. So if I open at stress that you see like multiple calls and the result on the right side is the low level file descriptor which is in this example OA3 because the program opens the file, reads something, closes it and then the kernel reused the same file descriptor number. Or I can do something else and rather new feature is dash capital P to trace all activity on one file. You see it's doing, it's actually doing a real like because it's a sim link and then do some stat calls, read something and finally closes the file. So this is rather nifty tool to see what operations process does. Again there are multiple helper classes. So you want anything with a file you can use a percent file, percent desk is anything with a file descriptor, this really suckers in file operations. An operation of different family class you can help and there are other multiple helpers to get like more output and have stress give you a more detailed analysis of what's going on. For example, tracing all file access by writing a program. This is a request call that tries to load some CA certs in the present. So I use that feature a lot to investigate why something doesn't work. I expect that that's one configuration mistake I had in one of my systems. Another thing is to see network activity. So if you do like a network call, the first thing you'll do is DNS log up. You see it's open a socket to INET Dgram that's UDP socket. Does something on port 43. It looks for Python and then gets back an IP address and then next one connects to that IP address and does a request. And with the right options you see actually what's going on in the internal data structures. The straight includes also a nice way to learn more about how operating systems and GDPC in kernel works. A cool feature for any kind of tester is something called temporary. You can actually modify and play around and disturb how syscalls work. For example, I inject an error into the socket syscall. It opens a new socket and say, okay, EM file is not an error number. So in ERNA on a pit and do something and if I do a request, then, okay, DNS log up doesn't work because the first socket call doing a DNS log is just intercepted and get an error on. I can also do something like, okay, don't want to just intercept the first one. I want to accept the second and any following one. So that's the when equals to plus. And now the DNS logout works but the first connection fails because I can't open a file as there are too many open file descriptors. That's the EM file error number. Or perhaps you want to slow down like some operations reading right into a file, slow down some kind of network operations. You can do something to slow that down with s trace two. You can add a delay either in the beginning or in the exit of a system call. And that slows down like copying from def zero to def null from three dot two gigabytes a second to just about 10 megabytes a second. Just by slowing it down a bit. One thing is, for example, you want to analyze a program that removes temp file. So let's just disable the unlink call. Unlink is the internal name to remove a name from a file handler on disk. So let's remove in Unix speak. And yeah. So you see that it's injected and the file is still there but the program doesn't get an error on it. So it doesn't fail from the perspective of the program but it doesn't do anything. So it's just return volume zero. And yeah. Pause a little bit. So verdict. I'll use L trace, especially s trace a lot because it's easy to use for small simple tasks. It's powerful and usually doesn't need extra privileges. But on the other hand, it's slow and especially L trace does not work with any kind of modern binaries when they're compiled with special flags. So if you have a bin now thing, then there's missing some information in the header and L trace can analyze and see what's happening. So they was high level tracing. It's a bit lower to actually see what's my operating system doing, what's my kernel doing, what's my hardware doing. There are several tracing capabilities inside the kernel for different kind of tasks. So a lot of tracing is for example the kernel tracing. You can see what the file system is doing, what your hardware drivers are doing. The CPU tracing capabilities, you can see what your CPU cache is doing, what your memory management unit is doing, handling memory. Or there's also a way to do user space tracing from the kernel space. So P trace is very slow because P trace, anytime you do something, has to copy the values back to user space and copy it back and copy lots of data with efficient user space tracing in kernel space. You can do lots of pre-filtering and the kernel stored in an efficient ring buffer and then have another process extract the ring buffer with the pre-filtered or pre-aggregated results to a file. That's very, very efficient. Different and yeah, what I mentioned before, it's a fun way to learn more about how actually the kernel works. And data sources are kernel probes and user space probes, K-probe, U-probe. Different event handlers, the kernel defines several events, CPU has several events, some kind of chips on your motherboard made event events that are handled by the kernel and offered to you. And they're different kind of user space things. So UCT I will explain later on with some examples in Python, yeah, K-probe, U-probe, with kernel probes you can see almost everything happening inside the kernel and with user space also almost everything. Things you can't inject or intercept is anything that's statically internally optimized C function or internalized C functions, they are optimized away by the compiler and they're no longer available but the rest, yeah. And performance counter, this is a small, small, small part of which kind of performance counters you actually have. I think pages usually like 20 pages or so on my screen, I have a big screen, so it's a lot. So something you can do is like, yeah, these are almost 1,000 different events I have on my system. So kernel tries events you can see, it's here for example, I'm listening to Cfg80211, that's the standard for wireless network cards and I get the base station frames and get base station packages, so I see what my wireless network card is doing when connecting to a new base station. And you see different frequencies, you see activities, you see that in the end it's connecting to the physical hardware to band 1 and frequency 5180 and Mac number and other stuff and these are two of the events you can see. If you want to know what your system is doing, fun tool. So the advanced tools, I'm going, I mentioned, I will not cover all of these tools, I'm going quite quickly, ftrace because ftrace is the foundation of the other tooling using a function tracing in the kernel. The Perf tool to handle Perf events, BCC and extended package filter language tools are a new way to write kernel programs and BStacyCurl has a virtual machine with a jit that you can run EBPF programs in. System tab, the last tool we explain and there's several more tools, so like LTTNG, which is a cool tool developed by the University of Montreal. Detrace and system tab, so if you look into the Python documentation on the instrumentation, system tab is one way to do detracing on Linux of original developer Sun. Ftrace, the function tracer, you can do function tracing on a system that just has a kernel and a busy box because you only need very low level shell commands to do that and the rest you can do with the virtual file system. So just one example is I have one issue on one system that's data on FS, I want to see which kind of kernel calls, just a simple Python program does, it opens the file and reads something and you see I have a function graph attached to any kind of NFS kernel function, this is the call stack inside the kernel or the kernel does to read something from NFS store. Or different representation is I want to see because I noticed that getting permissions from NFS was very slow, so give me anything, NFS permission related and give me the call stack of that. You see here it does two different open calls, first it does a check using new stat and something and the second one just opens the actual file, see at the end it does this open or 64, that's the entry point where the user space calls into kernel space and then the kernel space does permission checks if you're allowed to open the file. The issue we are having here is that the meta data cache for permissions had some issues and didn't cache the permissions correct way. Perf counting on Linux, as I mentioned before, different ways to do that, in most cases you can do that as an unprimvoled user, you can also, the tooling has high level, look into Python, Java, Node.js, PHP and whatever else you're using. One thing, it's very fun, so what does my CPU do when I compile Cpython on my system? So I hear it in Perf, getting stats and calling the command make dash j, so do parallel builds of Cpython. You see how many context features I got, how many CPU instructions it took to compile Cpython on my laptop, how often the level one, level two cache would utilize, very nice way to see if your algorithm, so if you're in data science, you want to have a algorithm that uses the CPU cache very efficiently and you see you have some of the issue there, well, or how good compiling Cpython uses the toolbook utilization. So these days, computers have two boosts, they allow you to basically handle one physical CPU course to virtual CPU course and in theory you can utilization of two, which would mean that both course, virtual course would be perfectly used, one at seven is a very good ratio, so there are a lot of ways to do that. You can also do user space probing, so I use, while I go to the example of Ltrace, the Perf works a bit different first, you have to define your probing points, which you want to get and then you can get statistics about that, how often the differences are called and so the plain one without any tracing took my slow hotel network like a bit more than half a second, the Ltrace variant almost 3.5, 3 or 4 seconds and with Perf it's just a bit slower, no, a bit more than a millisecond slower than the virtual one, so that's much more efficient and to get like Perf results, I'll use another approach to get a call graph from a request call, so first you have to record what you're doing, then you have to do reporting annotating and finally you can pipe it through a script and create something called a flame graph, the graph I showed before and if you do that, first calling Python, you get something like that, which is a bit hard to read and it also contains both things happening in request but also all the operations happening while starting Python and shutting Python down, it's only counting user space time, so it doesn't see any time it's having in kernel space like doing network transactions. So we want to look closer, just want to know what requests does internally, using the similar approaches before getting the pit, running Perf on that pit, just do the one request, can I press control C, stop that, do the flame graph, now you see that graph, now here again the box, if you look at the very low, you see something called X549 store load locations, so that calls wasting almost 40% locating, loading and parsing the root CA certs to validate requests. So if you do SLE connection, you have to load root CA, trust anchors, that loading takes very, very long time because it does a lot of internal operations and if you do request.get and loop, you always have to do the same operations, load CA certs from the disk, do some operations, put it into special memory structures, validate them, etc. etc. So the correct way is use a session or reuse SSL context to load only the root CA's one time and you're fine. There was something I just figured out like a week ago when I updated the slides from using PHP examples, used curl and PHP, my original slides from the web developer conference to Python. Other advanced tools to look deeper into the kernel, a bit easier to use than doing raw function tracing as the BCC compiler collection, which I like a lot. It's a way to write something Python mixed with C code which will then generate eBPF programs and upload them into your kernel and do some kind of rations. This BCC collection is a collection of a lot of tools. This is a slightly older explanation on listing of different tools and things you see around except for the C Java node PHP Python Ruby thing, these are all tools that are already available and ready to use in the example directory of BCC. For example, one tool is X for slow operations tool which shows you which processes on your computer take a lot of time doing something on the X for file system. This is for me, BESH does something, it's a Balo control using KDE, Balo CTL is like the index database that indexes files on your file system and there's also a mud storage that's part of Mozilla Firefox to store cookies. These are some processes that take a lot of time on my X for files in my home directory. Or get TCP connections but filter them by user. So with TCP dump you can get all TCP connections but you don't see the user ID. This TCP connect program can filter connections like by user ID or other things that are available in the kernel space but not available to tools like TCP dump. Or how about we break all SSL encryption with SSL sniff using request call, using accepting calling identity because I don't want to have like Gzip compression, makes it hard to reach. And run the program and I get like clear text results. That one uses user space probes to hook into OpenSSL before SSL write in crypt stature or after SSL read decrypt stature. And then it dumps all the traffic and it works for all processes on the computer. So that one only attaches to one pit but you can run it on your system and it will dump all the SSL encrypted traffic to a file. Or how about you want to see which files are open. So you can run that small script with BPF trace and accept all just enter open AT calls and just dump the command name of the PID and the file open. It just will print lots and lots of output on your screen, all file activity on your computer. Or how about you want to know how memory allocations are handled. So this is a histogram of all sizes of memory allocations for request call. So you see on the left side the ranges so one byte or two to four bytes allocated like 61 times et cetera and these are very cool tools to just look very quickly into your process so you can give you an idea of what may go wrong. The most powerful tool I currently know of is system tab. System tab is a way to write kernel models that does system interception and profiling and including using user space defined probes. So use DTS, a way where a program can tell system tab where there's something that could be intercepted or done. So Python offers multiple user space probes like function entry, function return, GCC done to see what the garbage collector is doing, imports or different line activities and the last one I added for 3.8 is for auditing hooks. PHP has even more ones and if you look into Java, they're going a bit overboard, 521. The time I wrote the initial version of that talk like half a year ago, probably more now. If you do tracing with system tab or S tab command, they say one problem, I give you my leper very secure and which kind of prevents me from using system tab because system tab creates a kernel model and tries to load into the kernel. If you run your kernel securely with secure boot, you're not allowed to inject any random unsigned kernel model. So the first thing you have to do is reboot your computer and disable secure boot or figure out how to do kernel signing on your laptop with a Mocha key. So let's trace Python. Let's see how you can write your first S tab program to trace what's happening inside Python. So we have to define a probe around, attach the probe around to a process which is actually not necessarily a process name, maybe sometimes a library name and then we use a marker and the marker is always double underscore, dunder for some reasons, over the entry point has the single dunder. So it gets multiple arguments. The first one is string pointers. You have to use user string to go with the remodel name. We didn't like the current time using the current time and the thread identifier to store them in a kind of hash map. And then print out some stuff and incrementing the depth. The other way around, second one goes on a fine load done which gets the model name but also information once the import is successful or not. Keeping the time and printing some stuff and just to run your first S tab program, I need root permissions to inject the kernel model for good reasons. So I'm using the import S tab program and run this Python pass. You see the different imports, including nested imports, you see the encodings model, loads codecs or the site model tries to load user customized and the time stamps and when it's done. So, and they talked yesterday about GIL or no GIL. I think he sits over there somewhere. He added additional user space probes, used DTs to investigate when the GIL is allocated or GIL is acquired, released or when somebody tries to get the GIL. And this is something I may add to actually the next version of Python. You can see when there's any kind of congestion on the GIL. It's a cool thing. So, verdict, kernel space, user space tracing. Sorry. I think you get a lot of detailed information, which is also one of the issues. You get so much information that you may get overwhelmed. It's very fast, mostly efficient. The overhead is like 10%, 15%, 20%, depending on what you're doing. You can get extremely detailed information on what your hardware is doing. There's a variety of pre-built tooling. But yeah, the learning curve can be very steep. I've been playing around with it for a year now. Still not very good at it. And yeah, and also if you do it the wrong way, so if you do something like enable, dumping all call stacks for all call functions, you turn your big server into a very, very slow computer or even slower than that one. Yeah. So, in my opinion, and this is actually, I watched Swiss Army Knife before I knew they were going to EuroPython, so this is from my first version, Strace and the BPF Trace are very nice tools, very quick hacks and quick approaches. VCC is very cool if you can use the pre-built tools for writing new tools. It's not that hard. You need to know a bit of Python, a bit of C, because the mix is very wild. You use like Ginger templates with C code inside Python code to do something, generate new code, so it's a bit like Python, but for kernel models. Perf is great if you want to go very, very low level. I don't have, I may have time to show you a video what we did in C Python to investigate an issue and the long ad operation to add two numbers. I think it's all enough time. CinePap is very interesting if you use like user space defined probing and there's going to be an approach to replace some of the C code, actually, the BPF code, so then you no longer have to run scary kernel models inside your kernel or just run the BPF program inside the JIT of the kernel. It's a bit more saner and safer. Ftrace is useful either if you're just booting up the system that has no user space tooling yet or for all the kernels and again, BPF is really the future. You want to learn more. Brandon Gregg's website is just the beginning of everything to tracing. He's just fantastic. EPPF and I supervised a project. There are multiple books on system tab that are really great. There has been a talk on Pi base 16 by even free man who got into more details how to extract stack crisis in Python from kernel space and getting a bit more deeper on that topic. Can take like three minutes of questions and I will take questions and just show you the video. Okay, where's my mask? So I'm compiling Python, running a perf on that and going deep into which to be instructions like executed. So run and any questions? Any questions? Anybody has any questions? Thank you, Christian. Any questions please come to the microphone in front. Okay, no questions? Oh, there's somebody coming. Okay, hello. Hi, thanks for your talk. So when I was using native code, it was very interesting to use as true trace and similar tools but for interpreted languages, I thought it was a bit more difficult because as you see all the code which the interpreter is actually doing and I found it hard to actually associate my code with the traces. Yes, that's one issue if you cross language boundaries like from native C code or native code on interpreted code or between I used to do like Java and Python mixed up on the same process or.NET and Python the same process, it gets harder. So there are ways to extract like stack traces, backtraces of calls using these tooling. So GDB has a lot of scripting to extract information and this is something like a call to action. If you're interested to do more system tab, even Freeman, he wrote or is some proof of concept tooling and Instagram, Facebook, they are the one that usually contributed the first instrumentation calls to Python and they have some tooling but they're not yet open source. I hope that I can convince somebody at Instagram that it may be released some of the tooling which they use to optimize the Instagram web services for Python 3.7, I think. That would be cool. Again, yeah, it's a big issue. That's why you need extra work on that. I agree. So one very quick question maybe. Can we use these tools in Docker environment and can we prepare the Docker environment to trigger them remotely, for example? So yes and no, if you're able to, depending with tools you have, so S-christ should work if you don't need to attach it to a different PID, some of the other tooling, you probably don't want to allow your Docker daemon to modify your kernel. But if you have access to the base system, so the system that runs your container environment, you can run there as a privileged user because containers are just processes in a different namespace on the same computer, that would work. So the level of the kernel tracing tool is probably not for security reasons. However, any other container platform restricts SUSCAL, especially the P-trace, attach and kernel loading SUSCALs. But again, use base system that would work. Okay. Okay, thanks. You're welcome. If you have any more questions, I will be here like... We have, yeah, sorry. Any end of the week. So thank you again.
 Good morning everybody.  I have to say you're missing five other excellent talks, so thanks for coming for my talk.  This is a very heavily battled slot at the moment.  Hi, I'm Christian Heimus.  I'm going to talk to you about profiling and tracing with different tooling.  One reason why I started to look into the topic was an issue I faced a couple of years  ago that, well, every five minutes there was a blocking.  The whole system didn't respond for a couple of seconds and we couldn't figure that out  for a long time.  Most were angry because we lost a bit of money.  That's really annoying.  The two things I will show you, you can actually figure that out.  The similar talk we got yesterday, which I missed while I was giving another talk with  Steve Dower, by Christoph Hare, who looked into why is a problem with the GIL or a problem  with me because the system is not responding.  One of the final motivations for this talk is something when I parted this talk, originally  talked at a general web developer conference with examples in Python and PHP to pure Python  using requests, figured out there's a big block, almost 40% wasting on something very,  very interesting.  This is a flame graph of requests call.  At the end we will see what that thing actually is, this block, and why you should use request.session  if you do a lot of requests in a loop.  Alternative title for this talk is actually two and a half use cases for tracing tools  because you can use the tracing tools not only for debugging and profiling, there's  also something very cool for anybody working in quality engineering or testing, which I  will show later on.  I learned that just a year ago at another conference.  So who am I?  Hi.  I'm from Hamburg, Python call developer using Python for 18 years almost now, working mostly  in security in Python and I'm making money by working for Red Hat on security engineering,  software stack called free IPA.  So a gender and gull to the stock is to explain what this picture is all about.  So this is a, not all, a big fraction of different profiling and tracing and performance investigation  tools for Linux.  For different kinds of the stack down from what the CPU is doing on a very, very low  level to very, very high level what the application is doing.  After a short introduction, I will introduce you to user space tracing tools based on the  P traces call and the second half will be about kernel tracing and hardware tracing  tool that can go down to the very, very low level summary and I may have, I don't think  maybe five minutes of question and answers.  Some special thanks.  So a lot of these demos I'm going to show are based on tooling and blog posts by Brandon  Greg.  So if you're interested in profiling and tracing, go to Brandon Greg's website.  He's fantastic.  Victor's dinner also has been investing lots of time to optimize Python and has some very  helpful explanations how to do proper benchmarking because benchmarking is super hard and super  hard to get correct.  Dimitri Lavin, I'm at him, the maintainer of S trace at a conference a while ago, along  some of the cool new tricks and another engineer Redhead showed me another couple of tricks  for tracing for system engineers.  So this is a combination of some talks I saw before, some tooling I've been using for  a while and yeah.  Introduction.  So some terminology, most people think of debugging as like identifying like removing  bugs, which is usually if you do debugging as an engineer, it's very costly because you  have to invest time.  You can't do that easily on a production system because you slow down production system a  lot so you need to build your additional fake production system or your staging system  at data and you can't actually do much of the same things because you don't see kind  of traffic patterns.  So this is a better thing.  It's tracing, which I will show, he is more like observing monitoring.  We do it the right way, that's why there's small star on your face.  It doesn't slow down your production system much.  It's still a small impact, but it's mostly okay and better than having big performance  issue in production.  And once you do tracing and get data as a byproduct, you can also do some kind of profiling  and data analysis and visualization of what's going wrong.  A methodology, so there are different kinds of tracing.  The simplest part you may know is like application level tracing, you will debug build, you have  some kind of tooling that writes lock files somewhere like my SQL slow query, Python  at a high level, set trace call, you can add a call back that gets called when something  is going on, et cetera, et cetera.  There are also more user space tracing that go a bit deeper like on the C level, you can  load something into your process space, you can use P tracing, even deeper is kernel  space tracing, which uses the kernel to investigate what the operating system is doing on a lower  level or how user space communicates with kernel space and hardware.  And finally, there's actual hardware tracing.  So any modern CPUs had special capabilities to do hardware performance counting, power  management unit controls, you can see what different health cache levels and just things  you could actually do.  To do tracing, you often have to do some special steps, you have to install some tooling, often  you need special permission, so you can't do some of the tracing as a user and sometimes  not even as an admin, so you have to disable some protections like you have to disable  secure boot to inject kernel models because low level tracing is often like life patching  your kernel, which is a bit scary but also very cool.  Just write stuff that runs in the kernel, unlimited, accessing all hardware, yeah.  But to do tracing, profiling and understanding what's going on, a big issue is statistics  are very hard.  You should at least know a bit of statistics and you may know the first phrase, the second  one is German for who measures fertilizer, so just to... or manure, yeah.  So to understand statistics, just some things if you're interested in that you should learn  about as different kinds or what's different than average mean and for profiling often  they're useful to you with the percentile.  So how good are 95% of all requests or 99% because you don't often care that much about  outliers or you want to specifically know when there's a big outlier.  There are different kind of errors, you can have observational errors, you can have random  errors that modify your output, they're also kind of biases, so if you're looking very  hard at some area, have some opinions about that, you try to confirm your own opinion  or the human factor while you may be looking in the wrong direction.  There's also very misleading ways to present data that can actually fool you or fool other  people so Vatican City has like 2.27 pove square kilometer which is a correct result but totally  yeah, misleading.  If you use a sampling profiler, not profiling like every instance but do regular sampling,  you can have like sampling errors, Nick was channel theorem is a fun thing if you book  more than images or any kind of other sampling or any kind of electronic.  And there are multiple papers on the topic, a lot of that one is very fun to read, producing  run data without doing anything obviously wrong.  This is a very fun paper that claims like stuff that went wrong because people are looking  the wrong way.  And computers are very, very noisy, so this is one second of my laptop doing nothing and  this, well, well lots of going on although it's doing actually nothing in the background.  So CPUs, power states, etc.  So Victor Stinnos blog explains how you have to configure and reboot and set up your kernel  and rebating system to make sure that you remove some of the noise for some of the CPUs  and get rid of RQ handlers and balancers and whatever.  One of the things is we had a very fun back a while ago where depending on your environment  how the length of like your host name or how much environment variables you have in your  system changes the way how memory is allocated and if you go over threshold then you may suddenly  go from just a couple of mem app calls to a lot of mapping and unmapping of the memory  of pages that can change your performance a lot.  It just took us ages to figure that out.  So let's profile.  Very easy case.  So the first thing I'm going to show is reading a file and the simple thing you can do in  Python is just to take the time, do something, take the time again.  While there are multiple issues with that kind of approach, you're missing a fun talk  on the other side like what a day has 24 hours plus minus one.  Why if you have time zone switches, if you have like a clock show that's changing, you  have to use a clock source to do profiling that does not change on your surroundings.  So this clock source I'm using here is a bad one.  So if you do profiling like on the ST switch, you get like takes our extra or I get negative  results for that.  So it's one of the caveats you should mention, should take care of.  So some of the examples I'm using next one is just a very simple shell thing.  It's doing cat.  Things I'm using Python to open read from file.  And some of the more advanced things I'm using HTTPS with requests.  Most of you know it does a lot of things.  So it does like network operations, file operations, it does something with SSL, OpenSSL, TLS encryption  and a lot of things.  So it shows lots of different areas where you can get very surprising results.  So section one, Ptrace.  Ptrace is very old feature from the old Unix days, about 1985.  It's a way to do the user space tracing and it's used by lots of tooling.  You may not.  You can use the new debugger to debug a C program, if you use Strace, if you do code  coverage of any kind of C library, a lot of libraries you will use Ptrace more like.  And Ptrace is useful but slow and useful and it's mostly easy to use.  So one example here is I'm using Ltrace at the library called tracer to see if it's  big enough.  Perfect.  And to see what if I do requests, I want to see all variables or all function called  starting with SSL, C to X, something at any library that's loaded.  So that's the at sign after that is the library.  That shows me different function calls I'm getting, which libraries are the type SSL  model, the internal dash SSL, underscore SSL, and there are a couple of calls to see which  memory addresses are called and the results return results on the right side.  Not very helpful but you can see if, for example, I want to investigate if you have programs  calling, especially function at all, it's rather nice for that.  You can also do something like count how many memory allocations you do.  So I'm running two processes and two different shells, so I get the pit, then I use Ltrace  to trace malloc, realloc, and free at any library.  As soon as I do that pit, I run requests call and I get how many allocations I get and free  calls I get.  But one downside from pitrace is it's slow.  So that one took instead of half a second or a very slow, like three, four seconds.  So the overhead is extremely high because Ltrace has to jump back and forth between  kernel space and user space a lot.  Similar tool is the tall Strace where you can investigate system calls and developed  by Paul Kranburg in 1991 and now maintained by Dimitri11.  And so the logo of Strace is an ostrich.  Why an ostrich?  Well, if you know Dutch or maybe German, it's straus.  It's the name of the bird.  So in German or in Dutch, it's Dutch.  So that's straus.  And with Strace, you do system call tracing.  So what's system call tracing?  Oh.  Does it load?  No, it doesn't load.  Oh, is it back in my...  Okay, that's supposed to be a circle of the different rings of a CPU.  You see a bit of the circle that's around because a way how modern operating systems  work is that all processes run in user space.  User space is not allowed directly to do anything with hardware, even like memories  virtualized, access to any kind of hardware calls abstracted by the kernel.  You have to tell the kernel, please open that file for me.  Please do something, send something for me on the network device.  And this is done by a syscall.  So you call a feature in the kernel, the kernel does some verification and then talks for  you to the operating system and goes back.  And this is called a syscall.  And anytime you do a syscall, you have to do a context switch.  So the kernel has to save the user space state, set up his kernel space state on the CPU,  do something and go back.  And that takes a lot of time, which you can't see in here.  Well, it works as a city.  So it's tracing like you, one thing is make open a file.  So you want to like catch this etsy, oh, that's release file and see which files are actually  opened by care in that way.  And you see like nothing.  Well, that's bad.  Strange, we're tracing open, but open is the system called to open a file still is no result.  It's peculiar.  So let's just look for all syscalls made and you see, oh, it doesn't call open, it called  something called open at or open at.  So the kernel does not have guys once to scroll for specific tasks, they open like a family  of syscalls to do related things.  And GPC decided to move away from the old open syscall because not available on all operating  systems and CPU architectures, but use open at a while ago.  So one thing if you want to stress like open calls is to use like this regular expression  or even easier.  There are like multiple families of things I will explain in a minute.  And this approach ultimately the regular expression is a bit bad if you like stat, it's that code  like get status of a file like file size and permission, they are like a plentitude of differences  calls which may or may not be available or may or may not give you the correct results.  And GPC does the correct thing but you need to actually track them all.  So easier way to do that comes next, but first, yeah.  First look at how the stress open at call works.  So if I open at stress that you see like multiple calls and the result on the right  side is the low level file descriptor which is in this example OA3 because the program  opens the file, reads something, closes it and then the kernel reused the same file descriptor  number.  Or I can do something else and rather new feature is dash capital P to trace all activity  on one file.  You see it's doing, it's actually doing a real like because it's a sim link and then  do some stat calls, read something and finally closes the file.  So this is rather nifty tool to see what operations process does.  Again there are multiple helper classes.  So you want anything with a file you can use a percent file, percent desk is anything with  a file descriptor, this really suckers in file operations.  An operation of different family class you can help and there are other multiple helpers  to get like more output and have stress give you a more detailed analysis of what's going  on.  For example, tracing all file access by writing a program.  This is a request call that tries to load some CA certs in the present.  So I use that feature a lot to investigate why something doesn't work.  I expect that that's one configuration mistake I had in one of my systems.  Another thing is to see network activity.  So if you do like a network call, the first thing you'll do is DNS log up.  You see it's open a socket to INET Dgram that's UDP socket.  Does something on port 43.  It looks for Python and then gets back an IP address and then next one connects to that  IP address and does a request.  And with the right options you see actually what's going on in the internal data structures.  The straight includes also a nice way to learn more about how operating systems and GDPC  in kernel works.  A cool feature for any kind of tester is something called temporary.  You can actually modify and play around and disturb how syscalls work.  For example, I inject an error into the socket syscall.  It opens a new socket and say, okay, EM file is not an error number.  So in ERNA on a pit and do something and if I do a request, then, okay, DNS log up doesn't  work because the first socket call doing a DNS log is just intercepted and get an error  on.  I can also do something like, okay, don't want to just intercept the first one.  I want to accept the second and any following one.  So that's the when equals to plus.  And now the DNS logout works but the first connection fails because I can't open a file  as there are too many open file descriptors.  That's the EM file error number.  Or perhaps you want to slow down like some operations reading right into a file, slow  down some kind of network operations.  You can do something to slow that down with s trace two.  You can add a delay either in the beginning or in the exit of a system call.  And that slows down like copying from def zero to def null from three dot two gigabytes a  second to just about 10 megabytes a second.  Just by slowing it down a bit.  One thing is, for example, you want to analyze a program that removes temp file.  So let's just disable the unlink call.  Unlink is the internal name to remove a name from a file handler on disk.  So let's remove in Unix speak.  And yeah.  So you see that it's injected and the file is still there but the program doesn't get  an error on it.  So it doesn't fail from the perspective of the program but it doesn't do anything.  So it's just return volume zero.  And yeah.  Pause a little bit.  So verdict.  I'll use L trace, especially s trace a lot because it's easy to use for small simple  tasks.  It's powerful and usually doesn't need extra privileges.  But on the other hand, it's slow and especially L trace does not work with any kind of modern  binaries when they're compiled with special flags.  So if you have a bin now thing, then there's missing some information in the header and  L trace can analyze and see what's happening.  So they was high level tracing.  It's a bit lower to actually see what's my operating system doing, what's my kernel  doing, what's my hardware doing.  There are several tracing capabilities inside the kernel for different kind of tasks.  So a lot of tracing is for example the kernel tracing.  You can see what the file system is doing, what your hardware drivers are doing.  The CPU tracing capabilities, you can see what your CPU cache is doing, what your memory  management unit is doing, handling memory.  Or there's also a way to do user space tracing from the kernel space.  So P trace is very slow because P trace, anytime you do something, has to copy the values back  to user space and copy it back and copy lots of data with efficient user space tracing  in kernel space.  You can do lots of pre-filtering and the kernel stored in an efficient ring buffer and then  have another process extract the ring buffer with the pre-filtered or pre-aggregated results  to a file.  That's very, very efficient.  Different and yeah, what I mentioned before, it's a fun way to learn more about how actually  the kernel works.  And data sources are kernel probes and user space probes, K-probe, U-probe.  Different event handlers, the kernel defines several events, CPU has several events, some  kind of chips on your motherboard made event events that are handled by the kernel and  offered to you.  And they're different kind of user space things.  So UCT I will explain later on with some examples in Python, yeah, K-probe, U-probe, with kernel  probes you can see almost everything happening inside the kernel and with user space also  almost everything.  Things you can't inject or intercept is anything that's statically internally optimized C  function or internalized C functions, they are optimized away by the compiler and they're  no longer available but the rest, yeah.  And performance counter, this is a small, small, small part of which kind of performance  counters you actually have.  I think pages usually like 20 pages or so on my screen, I have a big screen, so it's  a lot.  So something you can do is like, yeah, these are almost 1,000 different events I have on  my system.  So kernel tries events you can see, it's here for example, I'm listening to Cfg80211, that's  the standard for wireless network cards and I get the base station frames and get base  station packages, so I see what my wireless network card is doing when connecting to a  new base station.  And you see different frequencies, you see activities, you see that in the end it's connecting  to the physical hardware to band 1 and frequency 5180 and Mac number and other stuff and these  are two of the events you can see.  If you want to know what your system is doing, fun tool.  So the advanced tools, I'm going, I mentioned, I will not cover all of these tools, I'm going  quite quickly, ftrace because ftrace is the foundation of the other tooling using a function  tracing in the kernel.  The Perf tool to handle Perf events, BCC and extended package filter language tools are  a new way to write kernel programs and BStacyCurl has a virtual machine with a jit that you  can run EBPF programs in.  System tab, the last tool we explain and there's several more tools, so like LTTNG, which is  a cool tool developed by the University of Montreal.  Detrace and system tab, so if you look into the Python documentation on the instrumentation,  system tab is one way to do detracing on Linux of original developer Sun.  Ftrace, the function tracer, you can do function tracing on a system that just has a kernel  and a busy box because you only need very low level shell commands to do that and the  rest you can do with the virtual file system.  So just one example is I have one issue on one system that's data on FS, I want to see  which kind of kernel calls, just a simple Python program does, it opens the file and  reads something and you see I have a function graph attached to any kind of NFS kernel function,  this is the call stack inside the kernel or the kernel does to read something from NFS  store.  Or different representation is I want to see because I noticed that getting permissions  from NFS was very slow, so give me anything, NFS permission related and give me the call  stack of that.  You see here it does two different open calls, first it does a check using new stat and something  and the second one just opens the actual file, see at the end it does this open or 64, that's  the entry point where the user space calls into kernel space and then the kernel space  does permission checks if you're allowed to open the file.  The issue we are having here is that the meta data cache for permissions had some issues  and didn't cache the permissions correct way.  Perf counting on Linux, as I mentioned before, different ways to do that, in most cases you  can do that as an unprimvoled user, you can also, the tooling has high level, look into  Python, Java, Node.js, PHP and whatever else you're using.  One thing, it's very fun, so what does my CPU do when I compile Cpython on my system?  So I hear it in Perf, getting stats and calling the command make dash j, so do parallel builds  of Cpython.  You see how many context features I got, how many CPU instructions it took to compile Cpython  on my laptop, how often the level one, level two cache would utilize, very nice way to  see if your algorithm, so if you're in data science, you want to have a algorithm that  uses the CPU cache very efficiently and you see you have some of the issue there, well,  or how good compiling Cpython uses the toolbook utilization.  So these days, computers have two boosts, they allow you to basically handle one physical  CPU course to virtual CPU course and in theory you can utilization of two, which would mean  that both course, virtual course would be perfectly used, one at seven is a very good  ratio, so there are a lot of ways to do that.  You can also do user space probing, so I use, while I go to the example of Ltrace, the Perf works  a bit different first, you have to define your probing points, which you want to get  and then you can get statistics about that, how often the differences are called and so  the plain one without any tracing took my slow hotel network like a bit more than half  a second, the Ltrace variant almost 3.5, 3 or 4 seconds and with Perf it's just a bit  slower, no, a bit more than a millisecond slower than the virtual one, so that's much  more efficient and to get like Perf results, I'll use another approach to get a call graph  from a request call, so first you have to record what you're doing, then you have to  do reporting annotating and finally you can pipe it through a script and create something  called a flame graph, the graph I showed before and if you do that, first calling Python,  you get something like that, which is a bit hard to read and it also contains both things  happening in request but also all the operations happening while starting Python and shutting  Python down, it's only counting user space time, so it doesn't see any time it's having  in kernel space like doing network transactions.  So we want to look closer, just want to know what requests does internally, using the similar  approaches before getting the pit, running Perf on that pit, just do the one request,  can I press control C, stop that, do the flame graph, now you see that graph, now here again  the box, if you look at the very low, you see something called X549 store load locations,  so that calls wasting almost 40% locating, loading and parsing the root CA certs to validate  requests.  So if you do SLE connection, you have to load root CA, trust anchors, that loading takes  very, very long time because it does a lot of internal operations and if you do request.get  and loop, you always have to do the same operations, load CA certs from the disk, do some operations,  put it into special memory structures, validate them, etc. etc.  So the correct way is use a session or reuse SSL context to load only the root CA's one  time and you're fine.  There was something I just figured out like a week ago when I updated the slides from  using PHP examples, used curl and PHP, my original slides from the web developer conference  to Python.  Other advanced tools to look deeper into the kernel, a bit easier to use than doing raw  function tracing as the BCC compiler collection, which I like a lot.  It's a way to write something Python mixed with C code which will then generate eBPF  programs and upload them into your kernel and do some kind of rations.  This BCC collection is a collection of a lot of tools.  This is a slightly older explanation on listing of different tools and things you see around  except for the C Java node PHP Python Ruby thing, these are all tools that are already  available and ready to use in the example directory of BCC.  For example, one tool is X for slow operations tool which shows you which processes on your  computer take a lot of time doing something on the X for file system.  This is for me, BESH does something, it's a Balo control using KDE, Balo CTL is like  the index database that indexes files on your file system and there's also a mud storage  that's part of Mozilla Firefox to store cookies.  These are some processes that take a lot of time on my X for files in my home directory.  Or get TCP connections but filter them by user.  So with TCP dump you can get all TCP connections but you don't see the user ID.  This TCP connect program can filter connections like by user ID or other things that are available  in the kernel space but not available to tools like TCP dump.  Or how about we break all SSL encryption with SSL sniff using request call, using accepting  calling identity because I don't want to have like Gzip compression, makes it hard to reach.  And run the program and I get like clear text results.  That one uses user space probes to hook into OpenSSL before SSL write in crypt stature or  after SSL read decrypt stature.  And then it dumps all the traffic and it works for all processes on the computer.  So that one only attaches to one pit but you can run it on your system and it will dump  all the SSL encrypted traffic to a file.  Or how about you want to see which files are open.  So you can run that small script with BPF trace and accept all just enter open AT calls  and just dump the command name of the PID and the file open.  It just will print lots and lots of output on your screen, all file activity on your  computer.  Or how about you want to know how memory allocations are handled.  So this is a histogram of all sizes of memory allocations for request call.  So you see on the left side the ranges so one byte or two to four bytes allocated like  61 times et cetera and these are very cool tools to just look very quickly into your  process so you can give you an idea of what may go wrong.  The most powerful tool I currently know of is system tab.  System tab is a way to write kernel models that does system interception and profiling  and including using user space defined probes.  So use DTS, a way where a program can tell system tab where there's something that could  be intercepted or done.  So Python offers multiple user space probes like function entry, function return, GCC  done to see what the garbage collector is doing, imports or different line activities  and the last one I added for 3.8 is for auditing hooks.  PHP has even more ones and if you look into Java, they're going a bit overboard, 521.  The time I wrote the initial version of that talk like half a year ago, probably more now.  If you do tracing with system tab or S tab command, they say one problem, I give you  my leper very secure and which kind of prevents me from using system tab because system tab  creates a kernel model and tries to load into the kernel.  If you run your kernel securely with secure boot, you're not allowed to inject any random  unsigned kernel model.  So the first thing you have to do is reboot your computer and disable secure boot or figure  out how to do kernel signing on your laptop with a Mocha key.  So let's trace Python.  Let's see how you can write your first S tab program to trace what's happening inside  Python.  So we have to define a probe around, attach the probe around to a process which is actually  not necessarily a process name, maybe sometimes a library name and then we use a marker and  the marker is always double underscore, dunder for some reasons, over the entry point has  the single dunder.  So it gets multiple arguments.  The first one is string pointers.  You have to use user string to go with the remodel name.  We didn't like the current time using the current time and the thread identifier to store them  in a kind of hash map.  And then print out some stuff and incrementing the depth.  The other way around, second one goes on a fine load done which gets the model name but  also information once the import is successful or not.  Keeping the time and printing some stuff and just to run your first S tab program, I need  root permissions to inject the kernel model for good reasons.  So I'm using the import S tab program and run this Python pass.  You see the different imports, including nested imports, you see the encodings model, loads  codecs or the site model tries to load user customized and the time stamps and when it's  done.  So, and they talked yesterday about GIL or no GIL.  I think he sits over there somewhere.  He added additional user space probes, used DTs to investigate when the GIL is allocated  or GIL is acquired, released or when somebody tries to get the GIL.  And this is something I may add to actually the next version of Python.  You can see when there's any kind of congestion on the GIL.  It's a cool thing.  So, verdict, kernel space, user space tracing.  Sorry.  I think you get a lot of detailed information, which is also one of the issues.  You get so much information that you may get overwhelmed.  It's very fast, mostly efficient.  The overhead is like 10%, 15%, 20%, depending on what you're doing.  You can get extremely detailed information on what your hardware is doing.  There's a variety of pre-built tooling.  But yeah, the learning curve can be very steep.  I've been playing around with it for a year now.  Still not very good at it.  And yeah, and also if you do it the wrong way, so if you do something like enable, dumping  all call stacks for all call functions, you turn your big server into a very, very slow  computer or even slower than that one.  Yeah.  So, in my opinion, and this is actually, I watched Swiss Army Knife before I knew they  were going to EuroPython, so this is from my first version, Strace and the BPF Trace  are very nice tools, very quick hacks and quick approaches.  VCC is very cool if you can use the pre-built tools for writing new tools.  It's not that hard.  You need to know a bit of Python, a bit of C, because the mix is very wild.  You use like Ginger templates with C code inside Python code to do something, generate  new code, so it's a bit like Python, but for kernel models.  Perf is great if you want to go very, very low level.  I don't have, I may have time to show you a video what we did in C Python to investigate  an issue and the long ad operation to add two numbers.  I think it's all enough time.  CinePap is very interesting if you use like user space defined probing and there's going  to be an approach to replace some of the C code, actually, the BPF code, so then you  no longer have to run scary kernel models inside your kernel or just run the BPF program  inside the JIT of the kernel.  It's a bit more saner and safer.  Ftrace is useful either if you're just booting up the system that has no user space tooling  yet or for all the kernels and again, BPF is really the future.  You want to learn more.  Brandon Gregg's website is just the beginning of everything to tracing.  He's just fantastic.  EPPF and I supervised a project.  There are multiple books on system tab that are really great.  There has been a talk on Pi base 16 by even free man who got into more details how to  extract stack crisis in Python from kernel space and getting a bit more deeper on that  topic.  Can take like three minutes of questions and I will take questions and just show you the  video.  Okay, where's my mask?  So I'm compiling Python, running a perf on that and going deep into which to be instructions  like executed.  So run and any questions?  Any questions?  Anybody has any questions?  Thank you, Christian.  Any questions please come to the microphone in front.  Okay, no questions?  Oh, there's somebody coming.  Okay, hello.  Hi, thanks for your talk.  So when I was using native code, it was very interesting to use as true trace and similar  tools but for interpreted languages, I thought it was a bit more difficult because as you  see all the code which the interpreter is actually doing and I found it hard to actually  associate my code with the traces.  Yes, that's one issue if you cross language boundaries like from native C code or native  code on interpreted code or between I used to do like Java and Python mixed up on the  same process or.NET and Python the same process, it gets harder.  So there are ways to extract like stack traces, backtraces of calls using these tooling.  So GDB has a lot of scripting to extract information and this is something like a call to action.  If you're interested to do more system tab, even Freeman, he wrote or is some proof of  concept tooling and Instagram, Facebook, they are the one that usually contributed the first  instrumentation calls to Python and they have some tooling but they're not yet open source.  I hope that I can convince somebody at Instagram that it may be released some of the tooling  which they use to optimize the Instagram web services for Python 3.7, I think.  That would be cool.  Again, yeah, it's a big issue.  That's why you need extra work on that.  I agree.  So one very quick question maybe.  Can we use these tools in Docker environment and can we prepare the Docker environment  to trigger them remotely, for example?  So yes and no, if you're able to, depending with tools you have, so S-christ should work  if you don't need to attach it to a different PID, some of the other tooling, you probably  don't want to allow your Docker daemon to modify your kernel.  But if you have access to the base system, so the system that runs your container environment,  you can run there as a privileged user because containers are just processes in a different  namespace on the same computer, that would work.  So the level of the kernel tracing tool is probably not for security reasons.  However, any other container platform restricts SUSCAL, especially the P-trace, attach and  kernel loading SUSCALs.  But again, use base system that would work.  Okay.  Okay, thanks.  You're welcome.  If you have any more questions, I will be here like...  We have, yeah, sorry.  Any end of the week.  So thank you again.
Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_0_155.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_156_815.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_816_1151.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_1152_1199.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_1200_1367.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_1368_1559.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_1560_1619.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_1620_1679.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_1680_2195.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_2196_2411.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_2412_2687.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_2688_2807.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_2808_3443.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_3444_3539.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_3540_3695.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_3696_4043.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_4044_4331.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_4332_4559.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_4560_4679.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_4680_5747.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_5748_5795.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_5796_9959.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_9960_12863.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_12864_13103.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_13104_13295.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_13296_13643.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_13644_13907.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_13908_13979.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_13980_16403.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_16404_16463.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_16464_22103.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_22104_22703.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_22704_25223.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_25224_26819.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_26820_31199.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_31200_31571.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_31572_31715.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_31716_32003.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_32004_36659.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_36660_38783.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_38784_45527.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_45528_45587.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_45588_46151.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_46152_47171.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_47172_47375.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_47376_47519.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_47520_47579.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_47580_52307.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_52308_54011.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_54012_59207.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_59208_59267.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_59268_61511.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_61512_62363.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_62364_62495.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_62496_62699.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_62700_62783.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_62784_62903.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_62904_62963.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_62964_63419.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_63420_63599.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_63600_63743.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_63744_64103.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_64104_66479.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_66480_67343.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_67344_67787.png Christian_Heimes_-_Introduction_to_low-level_profiling_and_tracing_NS8aU-Rpfvg_67788_68011.png