Kohi #003: Logging and Assertions (Kohi Vulkan Game Engine Series)

hello everyone and welcome back to the kohi game engine series where we are building a game engine from the ground up using c and vulcan so today we're actually going to jump in and get a couple things out of the way that we're going to need for the rest of our application development and that is logging and assertions and we're going to get started on those things right now so before we jump into the video i would like to take a second and thank the channel's partners arsleya and wen chang the partners are the highest tier of membership on the channel so i thank you guys for your support i'd also like to take a quick moment and thank everybody under the supporters section all of you guys that are listed here on the screen thank you very much for your support it's greatly appreciated if you're interested in supporting the channel one way that you can do that is you can go ahead and click the join button below this video if you'd like more information on memberships i'll go ahead and post a link in the description below as well as a card in the upper corner of the screen with that stuff out of the way let's go ahead and jump into it so if you recall last time basically we set up our main method and we can compile this now on windows or linux so it no longer matters which operating system you are following along on you will be able to keep up there will be a little bit more platform specific code that we'll have to write that's probably going to be either in the next video or maybe the video after that but after that stuff is written we probably won't be touching platform code for quite a bit so as i mentioned before we are going to knock out logging and assertions so i want to go ahead and start with logging now our logger is going to start off being fairly simple but we are going to be increasing its capabilities as we progress through the series so the very first thing we're going to want to do is under our engine source we actually probably should clean some of this stuff up a little bit so we have our defines here we have our test cnh we're not going to actually need these files anymore so i'm actually going to go ahead and delete these and under source i'm going to create a new folder and i'm going to call it core and this is where a lot of our code for that core application level that i mentioned in the architecture video is going to go so we're going to try and keep things organized sort of in sections or in layers of architectures if you will so under core we want a new file we're going to call this logger.h logger.h is going to start off with two simple things a pragma once and an include of defines.h because we need those types next we have the individual log levels and as you see here we have six different levels of logging so we have one for fatal errors which are errors that basically cause the application to have to crash for example not having file right access or not being able to open a renderer things that basically do not allow the application to run and then we have our error level which is sort of a step below that where it's still a serious type of error but perhaps the application can recover from it it won't run correctly but it could potentially still run if there's an error then there's a warning which is basically saying that something happened that is causing things that are sub-optimal in our application but we can continue and it should operate as normal then we have info which is just your basic level of logging for informational purposes and then we have some additional ones here which are lowest levels we have debug which is specifically for debug level information this is included only in sort of debug or or test builds a release build we would not be outputting anything for debug and the same is actually true for trace trace is actually more verbose if you will than debug it includes very low level detail and it's very very verbose so trace is going to be something we'll use sparingly of course because we don't want to spam our logs but it may help us in some scenarios when we want to actually filter these things out so basically these last two here are only going to be included on debug builds when whenever we get to the point where we're building a release build these two things will not be included and you guys will see how we do that coming up here shortly with that one other thing that i want to go ahead and define is what levels of logging are enabled so we're going to have the ability to switch warning on and off info on and off and the same for debug and trace and the reason that we're doing this is because maybe we want to be able to control things at this level now you'll notice that there's no switch in here for fatal or error those things will always log even in release builds no matter what those should always be reported so we have switches for these bottom four and then these bottom two are only included uh in debug builds so to accomplish that we're going to stick in one more check here where basically we're going to say if it's a release build if this k release is defined uh and equal to one then we're going to overwrite these defines for debug and trace and set them to zero so that they are disabled as you can see right here we're actually building debug um so these things won't actually get output but whenever we switch to a release build that is what will shut this off as with most systems in this engine we are going to have two main methods which is initialize and shut down in this case they're specific to logging and these will do various things that need to be done in order to stand the system up now initially there won't be much of anything for us to do but eventually uh this initialize will do things like create a file that needs to be there in order to be written to so that we can actually write our logging messages to disk um we're not actually going to be doing that portion until we get to some of the platform code but i want to go ahead and scaffold this stuff out now so that we don't have to come back to this later and and set this stuff up okay so the next method that we're going to need is a k api meaning we're going to export this it's a method called log output and basically what this does is it takes a level and it takes a message and then it takes variatic arguments here which basically works a little bit like printf where you can supply any number of arguments to it and it will basically take this message treat it as a format string and then input these parameters that you pass into that string and this is going to be something that we're not going to use directly but we're going to call this from our other level of logging functions so log output is basically going to be where all of the logging output funnels through so that is what that function is for all right and the next thing that we're going to do is we're going to define something called k fatal and this is actually what we're going to call to log fatal messages now you'll see here it takes a message parameter and variatic arguments and it expands to log output and you'll note that it automatically fills in the log level here and then it puts in the message and then fills out our variatic arguments here if you guys want to understand a little bit more on how this works feel free to look that up it's a little bit compiler specific so this is the way that gcc and clang need to handle it in our case but it's not a detail that i wish to sort of deep dive on so i'm going to kind of pass over it but this is basically how you do variatic arguments within the preprocessor okay so the next one is k error so in this case we basically have the almost exact same thing except instead of outputting fatal we output error and we're also just to be safe we're going to wrap these in if not def checks i suppose i could do that with fatal too it's not as important for this one but it is more important on the next one which is warning so with warnings we have kwarn which again looks like the exact same thing we output to log output with a log level of warning message variatic arguments here but the difference with this one is is we can switch it on and off so here it checks to see if our log warn enabled that we defined up here at the top is set to one if it is it goes ahead and defines it this way and says you know we're logging a warning level message if this is anything except one or zero if we happen to to disable it it basically defines k1 as nothing so what this has the advantage of doing over using straight function calls is if we were to build with log warn enabled set to something other than one basically what this does is it removes the call entirely so the call is actually not compiled into the code at all it uh it simply just becomes nothing and this is a way for us to not have to go through and remove various levels of calls in the system if we want to sort of exclude them so they are included if that level of logging is enabled otherwise they are basically defined as nothing which still allows it to compile but compiles to nothing all right so keeping up with our enumeration up here the next level is info so same thing if info is enabled then we define our k info with a log level of info and again if it's not enabled we take it out and keeping with that same theme we have the same for debug so we have kdebug with a level of log level of debug same exact as before just for the debug level and finally the same is true for tracing so uh if we've decided at some point that we want to disable tracing we could actually just come up here and shut this off and not even have to use this flag if we decided that we wanted to do that so this seems like a lot of setup but it's it's nice it's a nice way for us to have granular control over what level of logging that we have right that is pretty much it for the logger h file now as you may have guessed we also need an implementation file for this called logger.c and we will include logger.h and logger.c is actually pretty straightforward there's not a whole lot that we have to do we only have to really set up a couple of methods here one thing that we want to do is go back to our header file and we need to define these methods right the initialize the shutdown and the log output so i'm going to go ahead and paste those here okay and for now these are going to do not much of anything so i'm going to put a note in here that our initialize logging is going to create a log file and then our shutdown logging is actually going to clean up any logging perform any cleanup that needs to be done and write up queued entries so what do i mean by queued entries so as i said our logging system is actually going to be evolving over time so we're going to create a simple one for now just to get things up and running and it's basically going to immediately spit out to the console whatever is provided to it right eventually not only do we want to add file reads and writes to this to be able to append login information but we also eventually are going to want to do that on a different thread or potentially from multiple threads at once right and typically disk access is pretty slow by comparison so we generally only want to do that you know sort of in batches and so what we're going to wind up doing eventually is setting up a system where whenever we log output we'll go ahead and display the console output immediately but the file output will sort of queue up and then once that queue accumulates enough data to actually be written out then we'll write it all out once just to keep the number of file rates down and this log output will or that sorry this shutdown logging will make a final call to make sure that any entries that are queued up also get written out to file before we shut down so just to kind of give you guys an idea of where we're going with that obviously for now this initialized logging needs to return a boolean so i'm going to have that return true and shutdown logging doesn't actually return anything so i'm not going to put anything in there for now so the next thing we're going to want is something temporary so i'm actually going to put a to-do temporary up here because we're actually going to need to remove this when we get to the platform layer but we're going to want to include stdio and we're going to need that for printf and a couple of other things so we're going to need that we're going to need string.h and we're also going to need stdrg.h and that is actually what is going to allow us to work with these variatic arguments one of the things that we're going to need to do is right to the console in order to do that we actually want to perform some string formatting as i said before we're basically going to take this message we're going to take whatever is passed in here and do some formatting on that but then we also have this log level and so the log level we actually want to hold also a string representation of that and then output uh basically a log level prepended onto this message right and so what we're going to do is we're going to create a array of level strings one for each level right so if we look back at our enumeration we have our fatal error worn info etc and here we have a array of strings essentially c strings fatal error worn info debug trace and what we're going to do is we're going to take the appropriate string here and prepend it onto the message for the log level that's passed in the other thing that we're going to want to track is we're going to want to know whether or not what we are actually doing is an error and basically we're saying if the level is less than two then it's an error and where that less than two comes from is our enumeration so you'll note that a log level of fatal is zero and a log level of error is one so both of these count as errors and that's because we're going to handle the logging a little bit differently for errors than we do anything else at least on the windows platform and again some of these things are kind of platform specific so we're not going to use that right away but i wanted to go ahead and get it in there anyway so that is where the less than two comes from so the next thing we're going to do is create a character array that's 32 32 000 characters long and we're going to zero out that memory now the reason i'm doing this is so that we do not have to do a dynamic memory allocation because that is slow this is done on the stack which automatically makes it much faster than allocating memory dynamically using malik so we create our array technically this imposes a 32k character limit on a single log entry but as i put here don't do that i don't think it's gonna be a problem for us if we need to we can always come back and address this later but in an effort to avoid dynamic allocation this is the way we're doing it for now so the next thing that we're going to do is we are going to use this built-in va list arg pointer and what this is is it basically allows us to take this argument list here create a pointer to that which essentially is a character array under the hood uh the reason i'm using this type here is because of this reason right here which is basically uh microsoft's headers override the way that the va list works and it complains about some type casting here so in order to work around this with clang i'm using this instead of the standard va list that you may see elsewhere so we have our built-in va list arg pointer and then this va start is basically saying okay we're going to start using this list to perform operations against it right and the uh the argument that we're going to start with as our sort of last argument before the variatic arguments is this message right so uh it doesn't care about this it basically just needs to know that this particular parameter is the last parameter that's passed in before we hit these so this is saying that's where we need to start is right after this and then we're going to do a vsn printf which takes this message uses the pointers that we have here the yardpointer and uh takes a size of the buffer which is 32 000 which is the same length that we have up here and outputs the formatted string to outmessage which is our buffer here and once that is done then we need to call va end to clean up anything that was that was created and or used for this va start so basically anywhere we have a va start we have to have a va end before we actually close out of this scope of of work that we're doing otherwise it'll throw an error so once we've done that then we now have the formatted message in a string great uh so that takes care of this portion of it but there is one more thing that i mentioned before where we need to prepend our tag so to speak or our log level onto the string and we can't do that here because we don't know what the contents of message is right so we need to actually take the new out message and prepend this text to that so in order to accomplish that we will call s printf which is basically saying we want to print f to a string and again we're going to target out message right so our out message is actually both our buffer um output as well as uh the input that we're going to have right we're basically going to output to the out message and then here is our format string so this percent s is basically saying we want to use a string here and then another string immediately after and then we automatically want to append a new line character this is the escape sequence for a new line so that in the console we actually all of our log messages appear on a separate line and this will actually ring true for files as well so we're basically going to say we're going to output two strings and then a new line the first string is going to be our error text right here or level string so it'll be one of these whichever lines up with log level and then the second one will be out message and so this is how we're actually going to perform that prepend operation as right here okay so the next thing we're going to do is we're going to printf which is basically going to print it out to the console right now and again we're just going to pass this uh into a string so we're going to take our out message and just output it here you can technically do this but there are security issues with that so it's not generally recommended that you actually proceed that way usually it's it's a lot safer to actually do it this way so this is the way we're going to do it this bit here is actually temporary this is actually going to become platform specific because we have some special things that we can do on uh some platforms to control things a little bit differently when we have an error here so for now we're going to printf which is basically just a straight output to the console so i'm actually going to say platform specific output is a to do here and we will come back to that okay and this is basically all there is to our log output for now uh there are eventually going to be things that we're going to add to this to actually output it to a file as well but we are not going to do that right now we want to keep things nice and light and simple okay so that does it for our logging system for right now so i'm going to go ahead actually and go to our main.c and get rid of this include test h actually i'm just going to replace that with core logger.h and you'll note that i'm using the angle brackets here and not a set of quotes because this is actually technically a separate or a separate location from from this so technically this engine code could exist somewhere on somewhere else on disk and this does not require us to sort of you know do a dot dot slash to go up a directory and and navigate our directories that way we can just simply do it this way and it says it comes from one of the folders in our configured include paths so we'll get rid of that replace that with logger h and then in our main we're actually going to let's go ahead and output actually one for each of these levels right so we have our our k fatal our error our warren just to go ahead and sort of exercise our code a little bit i'm just going to output a message right and i'm just going to say a test message and let's go ahead and we'll stuff a floating point number in there and we'll say 3.14 f right and that'll just prove to us that our our formatting works as well so i want to do a fatal and i'm actually going to paste some copies of this here and i'm going to change this to error and warn info debug and trace okay and i'll set a break point here on our return zero get rid of that one go ahead and build and oh it's complaining that i have an unused variable is error so let's go back to our logger.c and i'm actually just going to comment this out we are going to need that but for right now it's bleating about that being unused so i'll go ahead and comment that out okay so we've built successfully so now if i go ahead and run we're getting it twice so it looks like we did something wrong here so let's go ahead and have a look at that so simple mistake we actually need a separate out message buffer here i'm going to say let's call this just out message 2 and output to it instead and then print it out what's basically happening here is this buffer is being overwritten as it's sort of processing these arguments and so if we go ahead and run again we will see that we get what we expect right and so that pretty much concludes our logging that's pretty much all there is to that for now again we will come back and we will improve this a little bit but for now that is where we're going to leave that so the second thing that i want to cover really quickly is assertions now assertions are something that is very important for debugging purposes it is something that basically allows us to in assert for lack of a better term that something is true in the application and if if it is not true then we can sort of halt the application because um it's a way for us to basically say you know if this isn't true we want to sort of break the application and stop it here so that we can examine the data and see what's going on and so in core i'm going to create a file called asserts.h and the s there is important because there is such a thing as assert.h it is a library in the standard it is a header file in the standard c library but we are not going to use that we are going to write our own assertion functions and i will show you why uh here in a moment but it should be called asserts dot h and so uh the first thing that we're going to do is like we have in the past we are going to pragma once and include defines and then we are also going to set a flag called k assertions enabled and this is basically going to allow us to turn assertions on and off similar to our various level of debugging or logging rather and so we can actually disable assertions just by commenting out this line so i put a comment in there to that effect so the next thing that we want to do is we want to do a quick check to see if assertions are enabled and we're using the visual studio compiler then we actually have to treat things a little bit different than if we're using something else on a different platform now one thing about playing on windows is it does actually emulate some of the microsoft extensions which is why some of the things like debug break which is microsoft specific actually show up in here and so we actually need to take this into account we can't just go purely with all the gcc extensions so in this case i'm going to go ahead and include intrinsics.h which gives us the underscore underscore debug break here this basically halts the application whenever this is called and so this debug break is a macro that we're defining depending on platform that is either defined as this debug break or built-in trap which is what gcc uses and either way we can call this code from anywhere and not have to worry about what compiler we're actually using so we'll go ahead and define that and then this is actually going to include this is actually going to include like a bunch of stuff because you'll see here that we're actually missing an end if so we'll actually close this off in a few minutes so the next thing that we're going to want to do is we are going to want a method called report assertion failure and this is actually going to output some information to us in a format that we can actually see what happened so the expression is going to be a string representation of the code that was running that caused the assertion failure a message is basically going to be a string that we can provide uh whenever we're asserting something um if we want to as an additional explanation as to the context of the code that that's a failed assertion and then the name of the file is here this is the name of the code file itself that the assertion occurred in so you know it'll be like an h file or a c file something like that and then the actual line number uh within the file so when this is all compiled it will actually know based on some things that we're going to pass it what the code was that was running as well as what file and line it was in so it'll help us greatly in debugging so the very first thing that we're going to want is something called k assert and uh for those of you who haven't figured this out yet the k that you're going to see in front of some stuff is just for cohe because there are assertion macros that might be defined in various libraries and things and i don't want to collide with those so putting a k in front of it basically guarantees at least loosely that it shouldn't be defined anywhere else okay so basically uh this is the assertion function that we're going to call it's a preprocessor function just like the logging and we're going to pass to it a expression so this ultimately needs to evaluate to a boolean expression similar to if you were to put it in an if or an else if type of code block and so what we want to do here is we want to say if the expression evaluates to true we do nothing otherwise we actually want to report the assertion failure and call debrug break now you're probably wondering why i don't just do this there are situations where just checking not like that might not be enough you could wind up in some situations where there's like a double negative things like that so it's always better to evaluate the expression here as being true first and if it is not true then we proceed with reporting the assertion failure and calling debug break so that is it for the assertion you'll notice in here that when it calls a search and failure this pound expression is basically saying take what's passed here and spit it out as a string we are not passing anything in message for this this underscore underscore file underscore underscore is a macro that basically takes uh the current file that this appears in and outputs it as a string and the line does the same thing with the file's line number except as an integer and so that is sort of how this works and so obviously if we are hard coding message to be nothing here then we need one that allows us to provide a message so we have ksr underscore message and all this does is it's the exact same thing it just instead of passing an empty string here it allows you to pass a message in string format which it then passes on to report assertion failure otherwise it's identical okay so the next one we want to put in here is k assert debug so we're checking first off to see if we're in a debug build this k assert debug is basically going to perform the same type of logic that happens whenever we are building a release build where debug and trace messages do not get logged this is the same for these type of assertions because there are some assertions where we'll want to do that in a debug build but we might not necessarily want to do that in a release build so these two here will be present no matter what what kind of build we're making whereas this one actually gets snipped out and defined as nothing if we are in a release build so that just gives us a little bit more granular control there okay so finally back up to this so if our assertions are enabled we're doing all of this however we have an else block here because we what if they're not enabled well we can't just leave these hanging right like if we want assertions off completely we still have to define these things and we still have to actually do the same thing that we're doing here but for debug message and chaoser so right under here we are actually defining these things as doing nothing at all in the else case and then of course any if preprocessor needs an end if and so that's where we actually close that block off from all the way up here so if if k insertions enabled is defined then it will perform all of this if it is not defined it will define them as nothing and there we have it so the only other thing that we have to do to finish off our assertion is we've declared this report assertion failure function here but we don't actually have an implementation for this and where it might make sense to just create an asserts dot c um and define it there it would really be the only function that's there and what this is ultimately going to do is call our logging anyways so i'm going to go ahead and define this in logger.c and this sort of emphasizes a point in and c where you don't necessarily have to include the implementation of something in a file with the same name as the header file so just because this is a search.h doesn't mean that its implementation has to be asserts.c we can actually put its implementation in logger.c and so that's actually what we're going to do right here at the top we're going to we're going to define our report assertion failure within our logger.c and the reason we're going to do that is because we want to call log output okay and log output of course calls this same method down here passing fatal and then it says assertion failure the actual failure what the message is if it's included otherwise it'll just be an empty string in file and line number nicely formatted for us so that we can actually see what's going on nice and easily okay uh and actually we do not have a couple minor things here i should fix actually first off this k api does not belong in the c file that should only be in the header and this probably should be exported as well so it is available outside of the library and then this is calling log output but log output is actually not defined till down here which is going to be a problem so actually let me move this to the bottom otherwise i'll have to forward declare it at the top of the file and that's not really necessary for this okay so that should be it let's just build this real quick make sure that it at least builds correctly okay and what i'll do now is go ahead to our main.c and i will include core a search.h and i'll go ahead and k assert so i'll go ahead and just put false here which is going to go ahead and immediately trigger an assertion right because whatever's in here has to be a boolean in fact actually let me use a better example let me say one double equals zero right so we know that this is not going to be true so we should have an assertion thrown so let's go ahead and run this unresolved external okay that is usually because oh i know why uh because the logger needs to include search.h there we go okay now we should run and there we go so you'll notice that it actually broke on that line and we got a message in our console a fatal message in our console saying assertion failure one equals zero we didn't get a message here but it says here's the actual file here's the line number so you guys could probably see how this will be useful in the development of our application so that's great it actually broke here just like we wanted it to without us having to set a breakpoint so that is pretty much all there is to logging and assertions so that is about what i wanted to cover in this video thank you guys so much for watching if you like this video feel free to hit the like button uh subscribe and hit the little bell so that you get notifications when the next video in this series drops and thank you guys so much for watching and i'll see you next time [Music]

Channel: Travis Vroman

Views: 3,318

Keywords: write a game engine, write your own game engine, make a game engine, how to write a game engine, learn to write a game engine, writing a game engine, make your own game engine, game development, game dev, game engine, game developer, how to, tutorial, programming, gamedev, vulkan game engine, vulkan, game engine series, how to make a game engine, vulkan api, 3d game engine, vulkan engine, vulkan tutorial, 3d graphics, learn vulkan, 3d vulkan, how to vulkan, vulkan renderer

Id: l9e8PJskYnI

Length: 36min 23sec (2183 seconds)

Published: Fri Mar 26 2021