 So welcome everyone glad you could make it after the booze cruise from last night So of course our software has no bugs the hardware we run on has no issues and Everything works as it should so we're all happy campers however Sometimes we do need to find and need to debug something to inspect our System and analyze what's going on and we've always had tools such as k trace gdb or Good old ddb To help us Well analyze and debug our problems in those rare cases where we have them But sometimes we need a tool that allows us to dig deeper into the system and to give us a more holistic view of what's going on and And detrace can be a valuable addition to the list of tools we already have So detrace is the dynamic tracing and analysis tool Originating at Sun or at least made production ready by Sun and it's found its way into many other systems So it was initially developed for Solaris And of course free BSD net BSD macOS and Linux all have an implementation these days So today I'd like to Talk to you about the efforts in open BSD and the ongoing efforts. I should say of Perhaps eventually someday maybe we'll have detrace proper So first of all a quick look at detrace What it is and and why We should care about it. They'll go into CTF Give an overview of the current state of affairs CTF and detrace in open BSD So for those of you who don't know me Jasper Lieves Adrianse Or Jasper for short been involved with open BSD since about 2006 mostly Well working in ports and particular GNOME Been playing with Oction and more recently through random number generators For the URNG driver and of course CTF So by day I work as a UNIX engineer at snow in the Netherlands and by night I hide behind these aliases on github and Twitter so you can stalk me or harass me if you prefer so so Perhaps a long time from now in the source tree still far away but at least the DB and CTF part have been undergoing for a little over a year now and Was mentioned the purpose of this talk is to give you a status update of where we are and The efforts that went into it Of course brief explanation of detrace and CTF itself So let's start with the end game or end goal first It's our goal to have detrace one way or another But it does require many other pieces to be in place first An analogy I've been using in the past couple of days to describe to people where we are and how far away we are From having detrace is picture a puzzle. So we have the corner pieces. We found them We are working on filling in the edges and we sort of know what the picture puzzle should look like when it's completed by looking at other systems And we're slowly but surely working on filling in the missing pieces, which at this point are still a Lot So what is detrace really it's What's the name implies a dynamic tracing framework? the way it works is that it's using minimal impact probes Which don't have any effect when detrace is not enabled and have a minimal Or a small as possible effect when it is in place So as I mentioned it was made production ready by Sun in 2003 publicly released in Solaris a couple of years later and Since it's found its way into macOS 2007 freebies the netbies the in Linux followed shortly There has been an attempt To port detrace to QNX. However, just like QNX is future. It's sort of unknown and Detrace is CDL licensed, which May not be an issue for certain systems. However, it's a clear blocker for OpenBSD So that's the main reason why we cannot simply take the original source code of detrace and of the tools Around it such as the CTF tools so we cannot import those because of licensing issues. So detrace works with Providers and probes, which I'll show a bit more about in the next slide But also want to mention D the language D which allows for writing scripts Of course the main way of interacting with detrace is by writing the expressions on the command line and Brandon Greg wrote the treat detrace toolkit, which is a very comprehensive set of scripts Or using detrace but providing top or IO snoop like functionality. So this is one way to As much very short Demonstration of what detrace looks like so you call detrace and you provide it with a probe to use in this case. We're using a wild card. So we're using the Cisco three columns entry Probe which means that there's a wild card in there So if the Cisco provider then to namespace separators and an invisible wild card a column and the entry so what that means is the What we're doing right here is For every Cisco that gets entered Hence the entry probe we print or we trace the executable name So for example as you can see when we fire up detrace, you see that's Entering the IO control Cisco twice and then QMU comes along and does Some other things and the sample was Taken from smartOS So as you can see we're not inspecting a single application here. We're Instrumenting the system as a whole. I didn't provide any application to trace and you can see that detrace and QMU are running so another slightly more complex example, but still near trivial is to show the number of bytes written per process and Summing them and when you quit detrace it'll print its summary and based on this you can Analyze your system further create some fancy graphs And these were taken from Brandon's detrace one liners of the XD which if you don't know it It's a small treasure trove of neat one liners such as this one So why should you care about detrace if you know detracing if you've used it? You probably consider it a valuable and very handy tool, but if you don't Why should you? Be interested and perhaps to get involved in the effort in OpenBSD So we have a number of tools trust K trace S trace And L trace of which the letter to we have on OpenBSD already but they're Cisco tracers or or only for tracing user land and What these tools certainly have their application They may give you a too narrow view of the system And Detrace also addresses the observability problem So what that means is when you inspect something or observe something the thing you're Observing is affected by you looking at it. For example If you're K tracing an application it may behave differently from when it's running Uncaged trace which is quite Opposite of what you're doing since you're observing Well bad behavior for them when you want to see why that's happening and you're K tracing it And it may end up doing something else or behaving slightly different ways than What it's doing otherwise and detrace does not exhibit this behavior and also Detrace allows for very very fine grained Inspection albeit short-term You wouldn't want to write your monitoring scripts or long-term Analysis using detrace There are more appropriate tools for that since it's more for short-term inspection and debugging and analysis And speaking of inspection You've probably all seen the shouting in the data center video If not, I urge you to look it up on YouTube. It's a prime example of how to use or abuse Detrace to observe what's going on in your system and of course with a more complete tool chest of tools You don't need sprint f debugging anymore or Let's not overstate the case less at least so how does detrace actually work? So there are a number of providers For example the Cisco provider that I showed earlier There's the IO Provider the sys info, but also fbt. That's the function boundary tracing provider Of these Fbt will be the first targeted provider in OpenBSD So providers provide probes we saw the Cisco entry probe earlier Using the wild card and here were For example the Cisco exact V entry probe is just for inspecting the exact V Cisco So the fbt probe Works by patching the function boundaries So as soon as you are about to execute a function the function prologue Will be dynamically altered or or patched It saves the original instruction you were about to execute it then Runs the probe which does whatever it needs to do and when the probe is done Running it all emulates the original instruction. You were about to execute when you entered the function So currently we do have code for this in OpenBSD already. It was committed by Marta During or shortly before the general hackathon in Cambridge Although right now it's it's hidden under the ddb prof kernel compile time option but it's the first real Code we have for for tracing or probing so when a function is about to return The last Step would be to execute the probe if it needs to do that and When the probe is done processing it'll emulate the last instruction of function and function self returns normally So from an outside point of view nothing Happened The function still did what it need to do. It just got its prologue and epilogue altered so one key thing with detrays compared to other tools is that it saves its results in in per CPU buffers and it doesn't Directly export these back into user land. So you're not running into the top problem So if you're running top on the system with a lot of processes running, you'll see that top itself will be one of the Processes consuming most CPU time. That's because it's continuously gathering the information and directly Providing it back to you Whereas with detrays it'll by default on one second intervals It'll Well, it'll collect the data and at the given interval it'll export it back to user land so you're not continuously Impacting the application or system you're tracing with the tool that is tracing it and they're playing Or they're they're battling for CPU time So that's a key Of feature of detrays Of course detrays needs to know about what functions are which symbols are available and their types And that's where CTF comes into play and no not this CTF This one the compact type format so CTF can be considered a compacted notation of labels functions and For the other types that it supports is the full list It's generally though in practice basically always Compressed in Zlib And there are two versions of CTF available But within open BSD we only target right now the version to the latest version Version one isn't really in active use anymore So there's no reason why we should develop our tools to use that on Solaris It CTF is extracted from steps. Whereas on other systems. It's using dwarf So dwarf is generated by the compiler When you compile your source code with the minus G option to generate the debug symbols The compiler will keep track of everything that Might be useful for future debugging and saves it into several sections in the elf object file however, because Dwarf is so What huge? It's not feasible to distribute kernels That always have this extra information at so for example kernel built with all the debug options I'm sorry all the debug information Stored in it is about four times bigger with all the dwarf arts compared to Just having CTF back one August when we enabled Including CTF in all the kernels The growth was about one to two Mac And that's including the natural growth that just happens during hackathon So the CTF data gets stored into the elf object file as well It can be distributed as a separate binary Data file however in practice, it's always stored in the Standard dot Sun W CTF section So when you look at a kernel of open BSD these days you'll see that it does have this particular section Which means that it does have all the CTF data of all the symbols functions variable strings you name it It's in there. So It can be considered a subset of dwarf but in reality, it's more the Extracted form of whatever is relevant for Detrace or CTF or in our case right now DDB dwarf also Support many other languages than what we care about in our kernel Where we don't care about Pascal or modular or C++ or whatever CTF is only concerned with C Pure simple C no assembler that either So dwarf also contains information on line numbers To be able to map your code into line numbers and file information. That is not part of CTF However, it is information we Are quite interested in providing so right now for a developer to extract that information they have to be running a Kernel which contains all the debug information However, we generally Don't recommend users running this kernel. So when they do run into a crash We have to provide them with this kernel so they can Retrigger the crash get the relevant information and it would be so much simpler if we could also Save this information in some way Not part of CTF, but it's something that that That dwarf provides so here's an example of CTF dump. It's one of our own CTF tools So running this on the the BSD kernel just shows the header with the CTF Magic number the version encoded and further information. That's relevant to parsing tools Of of this fairly simple and structured format. It's not like dwarf where you have your completion unit your your debugging information entry and all sorts of extra tags and And fields that you need to parse in order to get whatever is relevant So for dwarf the relevant Information is stored primarily in two sections the info Debug info and debug abbreviation section abbreviated to a breath so within the completion unit a Die is generated for every variable type function etc and these dies themselves can be tagged with whatever is applicable to this This die so it can be tagged as a variable or a pointer as well as attributes relevant to it and Because dies can be nested it creates a tree like structure that Tools like dwarf dump are able to traverse and dump a representation of the elf of sorry to dwarf information. So This is a Some output of dwarf dump with all the information it knows about this object file and Most of it is quite relevant to a debugger, but not for CTF So the dwarf code that gets generated an open BST right now is dwarf 2 In newer versions of dwarf have been released in over recent years. So for example version 3 added support for C++ or better support for C++ Fortran 90 allocatable data Version 4 came with better compression, which is interesting But also support for C++ 10, which well we have no use for in our kernel version luckily Person 5 was released earlier this day this year standardized actually And came with many other improvements such as what way better compression still faster lookups better annotations and descriptions however The compiler we have right now doesn't fully emit store 5 But it may be at one point interesting to move further along with what our tools Can use since they're currently still limited to version 2 so CTF tools it's great to have an object file which contains the dwarf information But in order to well make something useful out of it and to turn it into CTF We need a number of tools So Solaris developed The CTF tools package which contains CTF convert merge and dump however Their CDDL licensed So that was a blocker for us to move forward with CTF since we couldn't import it into our tree back in 2016 we did import it into ports where we're a bit more lenient When it comes to licensing and it's using the lip dwarf and lip elf Libraries, which we don't have in base either and it was quite the Effort to find the right combination of Lip elf or not using lip elf to port the Solaris specific data structures to open BSD which applies Specifically to CTF merge at some point we may also want to use lip CTF If we have enough consumers in the base system right now we only have a very small number But as its usage increases we could also distribute that as part of the base system It is part of other operating systems on the other hand So having the CDDL licensed CTF tools and ports was a great kickstarter for us to move forward Not worry about this part of the problem, but actually move forward on Using the CTF data so MPI Set out to rewriting rather creating a new implementation under a more liberal license That it is fit for inclusion in the open BSD base system So we ended up with CTF conf which has functionality similar or equivalent to CTF convert We dropped CTF merge I'll tell you why in a bit We have CTF dump which Is a visual representation of the CTF data which is a very helpful tool in verifying that CTF cons actually works and generates what we expected and then we have CTF strip and This is a really nice trick So our kernels now get built with minus G by default so they generate all the dwarf data and Then we strip them But we're not using the regular strip We're using CTF strip which does CTF convert on the object file, and if that fails it'll fall back to Plane strip which removes all the dwarf data, and we end up with a regular kernel no CTF However, CTF convert worked It wrote out the CTF data into a separate file Which we then use opt copy to insert back into the object file, and that's basically what CTF merge does it takes all the object files and merges all of their CTF data into a single Representation which then gets inserted into the final object file That's quite a complex process the merging itself, but also to insert the The data into the object file And we have opt copy in in base so why not make a small little Shortcut and and use what's there already. Maybe at some point We can add more smarts to CTF strip But then we basically end up implementing large parts of opt copy in CTF strip so Yeah, why why go there so That's that We do have CTF data available for all all our platforms right now We have some support for it in DDP which allows all the platforms to make use of this There are some some portability Or tasks Related to portability in other parts of this effort, but CTF is available for all our platforms and all our kernels So this is a quick example of running CTF dump on a kernel from a couple of weeks ago Displaying the strings available in the the object found the current on this case So the first column are the indices which are referred to From other parts of the the CTF data as we can see right here for example for the types so in this representation We can see that the type integer has index 12 It's encoding is signed And the others it's a long list. So I just snipped it for brevity But here we can see how it's used So for example the DB num arcs function Which is used by the trace command from DDB to look up the number of arguments that a function has So its index is 4009 and it returns 12 the 12 refers back to the So the 12 up here refers back to the 12 up there So we know that DB num arcs returns integer Which in this case is the number of arguments We can also see that its arguments are of these types which Is a pointer which refers to a struct So we know that the first argument of DB num arcs is a struct call frame struct We can defer the rest based on what else is there So this is also an interesting way of parsing all your Your functions and mapping their Types and their arguments So DDB DDB is the in kernel debugger of all BSD's And it was actually the first consumer of CTF data. So back at the hackathon 2016 We started working on CTF and we Needed a way to verify that the work we were doing was valid and would actually lead to somewhere and DDB seemed like the obvious starting point Which for me was a very fun and challenging project during the hackathon to dive into the bootloader in order to load the CTF data As well as an adventure into DDB So From within DDB We can inspect the CTF data of the currently running kernel so when the kernel gets loaded by the bootloader the Dots and W's CTF data gets loaded and DDB knows where it's loaded at and when required it It's using that data for example for trace So trace on AMD 64 and i36 at the time it showed you the function names But it couldn't figure out how many arguments the functions had Other platforms such as spark64 did have well architectural advantages and they could figure it out but AMD 64 i36 couldn't Later the p-print commando or command Became CTF aware and most recently the show struct command as well So this is what? Trace looked like in DDB before having CTF So as you can see It has no idea of the number of arguments and with DDB Yeah, so the p-enter still doesn't have any but the others are properly filled in So that was the first validation of well So it's actually working what we're producing even though it's with the original CTF tools But still the way we're integrating it into our kernel does work so pretty printing NCPUs are pretty printing it in general is using the CTF data in order to figure out how to represent the kernel Data as something human readable and defer the types from it. So as you can see We're printing the DB CTF variable Right here we have the CTF header So using the show struct command as we know that it's a struct we can also Print that and see everything that's contained in it. So this is the CTF header Data of the kernel that's actually running right now or So where are we at right now? the dynamic profiling part from MPI was committed during the 2016 general hackathon and at that time we really made some great efforts into getting started and Figuring out all the components needed at least CTF wise So we imported the original tools into ports They're still there at the moment even though we have our own free tools In the base system, but they still serve as a useful reference implementation And at that hackathon the original DDB code for CTF was committed as well and then about a year later The tools were imported into base And we actually built CTF enabled kernels by default. So this was a huge step in moving forward and getting CTF to the people as it were So sometime after you hackathon actually one of our developers DOG committed go to remove the old DDB struct kernel compile time option and Have showed struct new CTF. So that was another way of moving forward and Validating the effort and as you can see the Hackathons have been tremendously important in the development of not only CTF But of OpenBSD in general So while they're sponsored by the OpenBSD foundation, but essentially funded by you. So keep them coming Of course, there's still a lot more work to be done For example, we could make an effort in catching up on modern or more recent Dwarf versions we could Cut out CTF conf and see if the compiler Could actually be made to work for us since it already knows all the The types and everything that has to go into Dwarf. Why not make an intermediate step and Generate CTF right away Of course, there's some portability issues to be addressed still So for example the dynamic profile in part is only for MD 64 I 36 at the moment and We can extend the usage of CTF for trace into other architectures as well because most of them have been relying on their internal Resolving of the number of arguments But why not make use of CTF since it's there And of course eventually We may have detrace it's still long ways down the road but We're making an effort and Getting the word out to people and getting people interested and involved that will really help to Get this completed so to recap We have our own ISV licensed CTF toolchain in base All our kernels are built with CTF data and properly inspectable through DTB It's still a long way to go, but we're making good progress. Of course you can help So I'd like to thank MPI for all his hard work at getting us Started writing the tools and being well mental support Of course your BC con foundation for well inviting me here and snow for having given me the time to attend this year's conference Well, it's not 40 minutes It's it's part of the build process. So it's something that users Don't see or don't notice a delay when they boot a kernel It on a fast AMD 64 machine like this laptop it takes It I've actually not verified or tested how long CTF script takes on Well arm 32 or something last fast But it'll probably several minutes and not 40. Yeah Yeah, definitely, and I think we should Spend some time as well to look at other architectures and then see the impact there and an extent and improve on those as well Yeah, so With the Load bits elf flag, I believe That data gets also the CTF data also gets written out to your core file and then you can Do postmortem analysis on your your use land binary at least For now our effort is mainly focused towards the kernel But yeah, it will be Quite helpful to do postmortem analysis and debugging eventually. Thank you