Structured Logging In Go Using Standard Library- Slogslog

hi welcome to programming Percy today we'll be talking about using structured logging in go using the standard Library go 1.21 has been released and that allows us to now use a module called slog which is a sub module for the log Library which allows us to use structured logging in our applications a few years ago I wrote an article about how to do structured login in go but in that article I use logaris or zero log which are third-party login libraries which was needed at that time now with slog or s-log I I'll go ahead and say slog with slog we can skip those dependencies and skipping one extra third party dependency is an amazing thing that I always strive for if you're new to programming you might say what harm does come from using a third-party logging Library what's a what's one extra dependency well there's many reasons but you should really look into log4j and you will see what catastrophic events we can have from a simple log library that gets exploited and has security vulnerabilities as our systems grows larger logs and metrics get an increasingly important role in our systems we need to understand what's going on and why things are happening and to do that we use logs and if you're just simply printing your logs in a text file and it's not structured it will be very hard to use your logs but it will have structured logs we can instead use a ingestion program such as promptail or log stash or whatever to read the structured logs into our monitoring system which will help us out a lot now structured log does not have to be Json it is commonly Json but it doesn't have to be it can be structured text rows such as I think syslog does it that way so let's just skip ahead and let's start rolling the first thing you need to do is that you need to go to go goes website and install at least a version above 1.21 if you do have a version lower than that slog will not be available so let's go ahead and create a new directory [Music] I'm going to go inside of that directory now we need to start a new module so let's go ahead I'm going to go ahead and start programming Percy slog test we've created a new module let's also create a new file called main.go to use slog we simply have to import it so let's go ahead and do a new package Main we have to import log slog let's go ahead and use it let's create a main function let's go ahead and just print out a simple message I'm going to print a info message so let's do slog.info test just to see how things roll open up a new terminal and run go run main.co bam you can see here that the log message is being printed in a structured way we have our date we have the level which is input and we have our message so that's great so to use slog it's really really easy an important thing to understand about structured logging is log levels so in our example we used info which is information and in most logging libraries the levels are hierarchical so if we have a debug message for instance let's do a debug my debug level [Music] now debug level is lower in the hierarchy than the info and it's important to understand that if we if we decrease the log level that we want to see to info let's say that we only want to see info log messages we will no longer see the debug message in slog there are just four log levels so it's very easy to get started we have the debug which is the lowest level it should print basically anything we have info which is the next level which is information which is information about stuff that's going on in the system we have warn which is warning so that's a little bit higher up now something is starting to be strange in the application so it's a warning we have errors errors is basically something has gone wrong the way we use log levels in slog is that we use level functions a column level functions because basically it's what we see here if I want to debug a log net line I use the debug function the great thing about these level functions is that they all look the same way they're functions that accept a message followed by a very attic amount of arguments we will cover these arguments very shortly so we have the debug info Warn and error simple enough let's go ahead and run this [Music] and boom you see the info worn and error what happened to debug well we haven't set the level but the default slog Handler is set to information if the error level was set to error we wouldn't see the warnings or the info message or anything below it's important to understand the hierarchy of the log messages now when we're using slog like this we're using the default Handler a Handler is something that will print out logs this is the way we use the default one if you jump into these functions you will see they use the default function.log and the default is going to use a default logger so that is great if we just want to test things out like this but what if we want to customize stuff and change How Stuff behaves we can do that using handlers now there are currently two supported handlers in slog which is the Json Handler and the text Handler Json will output output the log as a Json and text Will output something similar to this what we see here is actually the format that they create that slog creates with something called the default Handler the default Handler is not the text Handler this is a text Handler which has some formatting applied so let's go ahead and try using a Handler let's create a new Handler so we can use it and see how we can do that now one great thing about this is if we do new slog.new you can see a bunch of functions but the ones we want is to create new handlers and you can see new Json Handler and new text Handler what's great about them again is that they are following the same function signature so we could easily replace them with each other if we change our mind which one we want to use I'm gonna go ahead and create a text Handler now the first input to the text Handler is a i o writer I always want my logs to go to standard out because I usually ingest my logs from a Docker or or stuff like that so let's just go ahead and add os.standard out and let's import OS so you also find that so we have our place to write the logs to now we need to apply a Handler options the Handler option is a struct inside the slog module so let's go ahead let's just take a look at it to see what it is so we have the header option I'm just gonna go to it and let's see what it says the Handler options are options for text handlers in Json so we have a ad Source Boolean and if we if we make this true we will see the current line inside our program or source code that triggers the log we're going to enable that we can see that we can set the log level so if I don't want the debug logs I can set this to info for instance and we will no longer see the vbox and we have something called replace attribute we will take a look at replace attribute later but basically if we want to change a Time Field called time for instance we can change that to instead be named date and use a different formatting we can do that with replace attributes which is great but let's go back to our code so we need to create this log options so let's just go ahead and create that and also this is supposed to be a pointer I think yeah so a pointer to our new slog hander options I want to set the log level and I want to print all the logs I want to see the debug so set the log to slog dot level debug which is a constant and we don't have to use hard-coded strings that's nice I also want to see where in the source code the log level com the log message comes from so let's go ahead and set add source to true we go ahead and we create a new text Handler we also need to accept the output which is a log hand this isn't this is a log Handler this isn't a logger now that we have the Handler which knows how to extract and use the logs we need to create a logger object so let's go ahead and create a logger and do slog.new and we can look at new here we see new function accepts a slog Handler and that's great we have a slog Handler so let's do log Handler as an input now we need to replace the slog.debug to logger because otherwise we will be using the default logger we don't want to use the default logger we want to use our own customized logger so in short we create a log Handler and we configure it we create a new logger using our log handle and then we print a bunch of stuff let's go ahead and write and you can see that we now see a lot of different logs it looks different this is not the default Handler this is the text Handler so the timing is changed and we can see each of these level equals warning we can see the source since we added add Source we can see where in the source code this was printed so the warning comes from main.co line 19 which is pretty amazing it's really helpful when you debug stuff I do recommend to add that if we look at these log lines we can see this time equals a timestamp level equals error for instance and this is known as attributes we can add costume attributes by passing extra attributes into the logger function remember that the log functions accepted a variatic amount of arguments right you can see here it accepts many arcs and these arguments are um how we can pass custom data into the logger what if we want to log stuff such as application version or some Metric that we need to understand what's going on we can do that simply by adding them here so these attributes are really great an example would be if you have your application is deployed in multiple regions on AWS for instance now you see in your monitoring tools such as Prometheus for instance you can see that the application is acting up it's printing a bunch of errors and it can be really helpful if you see that it's not just the application it's the Europe region for instance that is acting up and you can really help you narrow down fast what's going on so adding these custom values is really important let's just remove all the log messages to make it a little bit easier to read and we will go ahead and say so what's the meaning of life for instance we want answer to meaning of life and we want to add costume metrics to this message so let's add the key answer and the value 42. it's always key values when it comes to attributes let's go ahead and run that we can see it prints what's the meaning of life as our message and the answer is equals to 42. we have successfully added an attribute to our log message which is great and this way of adding stuff is nice it's quite simple but makes it gets messy real quick if you have many many attributes it's not going to be nice it's going to be hard to understand what's what what's related also there's performance implications because you have to infer what's going on you have to map them together in the background of course but there's performance issues so instead according to the documentation or schlag they actually recommend us to use something called log attributes so slog module comes with a bunch of attributes by default which we can use and they come in the form of as functions so if we do slog.int we can see that we have a function called int which accepts a key value pair and all of these functions except key value Pairs and Returns the attribute so let's just replace the things that we had with answer and the value is 42. go ahead and rerun it we should see the same output which is amazing and I do recommend you to use there's a bit more typing to slog dot in instead of just saying answer and 42 but it really makes the code cleaner a little bit more more stuff to read but much cleaner especially if you have a bunch of attributes it's just some so worth the trade-off now sometimes we might might have attributes which are actually related at those times we can create something called a attribute Group which is nice because then we can chain the attributes together into one and nested Json so let's just go ahead and try it it's much easier to see what's actually going on so I'm actually going to share my best Pokemon rating with you guys and the way we do that is we do a debug same as before the input parameter is going to be an attribute so let's do it slog dot but instead of int or string or anything let's try a group it's a group of values let's call our group votes because these are the votes for my Pokemon ratings and let's go ahead and say I have a integer called Pikachu and he has 40 votes and then we have a second integer which is Mu and mu has 24 volts go ahead and save that so we have created a group called votes which has two attributes in it so we're missing a hold on let's add that let's run our program again and you will see votes.pikachu equals 40 and votes dot mu equals 24. so that's really amazing and this allows us to chain stuff together one thing you can imagine is you might want to have system information inside a system group for instance so you can easily kind of filter out or navigate between the groups it's just amazing to have one thing before we proceed is we have a text handle right now I don't really like the output of the text Handler so let's go ahead and try the Json header and to do that we simply rename the new text Handler into new Json Handler remember they have the same function signature so we can simply do that and restart our program you can now see we're getting the logs as Json instead which to me looks a lot nicer we might even pipe that to JQ and we get these formatted really nice blog so that's amazing and we have our groups and everything looks good but what if we have default values like what if this system information we want to print we want that to appear on all the log lines we have this giant system we don't want to add that all the time what's amazing with slog is that we can add attributes which are default attributes now we do that by going back to the log Handler now I know there were only three Fields here that we could modify but we can actually call a function called with with attributes and with attributes accepts an array of attributes that will always get added to each log message so let's just try and create a new array and it's supposed to be slog dot attributes and let's just say we want to always print what's the meaning of life again because that's always an important to remember you know so let's just add that and rerun the program with JQ for now we can see what's the meaning of life equals 42. that's being printed which is amazing so now we don't have to do that every time we can simply configure our Handler to always do it for us and this is great to this is a great idea to print application information maybe the version some configuration that you need to know about uh one even greater thing is that the group the slog dot group is actually an attribute in itself so what we can do if I always want to print my Pokemon collection for instance against is take my lines here and move them up and place them as an attribute in itself let's just format that so it looks better now the votes are being printed as a default and that's also really nice again with the system information Etc you kind of just want to add those as defaults test let's try it out so let's do logger debug test and we can see it still prints the Pikachu ratings the Pokemon votes and the meaning of life everything by default and this is great because you don't want to add all these attributes each time for instance so one thing that's quite annoying is if we create our logger like this you have to pass the logger around you can't do slog dot debug anywhere and it will print because we have our customized stuff inside the logger that we have created which works but if we take a look at if we print my log message using slog.info you will notice that that message is being printed as the same thing as before because slog.info uses the default blogger not our sexy configured logger but sometimes we might want that because if we start up our program we configure a nice cool logger and we don't want to pass that around in our application or you might want to but in cases you don't want to you might just want to replace the default logger with our logger you can do that by doing slog.set default and if we take a look at that you can see that's the default blogger of the package to use so let's go ahead and just insert our logger as the default let's go here again and let's redo a info new info rerun our program and you will now see two Json strings being printed our regular log and the second log message which is great this is what we want we want it to whenever we use slog in our modules we just want to do slog.info and you know you want it to work with whatever logger you have set up there's there's one other approach which is where you add the slog to the context or if you pass the slog and logger along inside of your application but I don't really like that approach because it's just it's messy now one final thing that we might need to do is that we might need to replace attributes and one reason for that is if you take a look at the current logs you will see that it prints time for instance it prints the time in a certain format which might not be the format that we want let's just say we want to change the time do another format I want to print the time as a date field instead and I want the time to be printed as Unix timestamps now we can go back to our log Handler when we create it we can take a look at the replace attribute field replace attribute is a function which accepts a group we and the group is basically the group where the parameter belongs to and it's a array of strings and then it accepts the attribute as a second parameter so let's just go ahead and create that and it was there's no autocomplete for that string and we want a which is our attribute and we want to return a attribute so we are accepting the current attribute that is being parsed and we return another attribute this allows us to modify it if I do a now which is the slog attribute you can see we have the key value fields we have the key and we have the value fields so what we can do is we can match the key that we want and we want to change the time key so let's go ahead if a DOT key is equals to slog dot time key one great thing about slog is they keep constants for everything that you might need to know so the time key is a constant for the time field so let's go ahead and see whenever the attribute that is being logged is the same as the time I want to change the key to date so rename to date and then I also want to change the value to Unix time the Unix time is a N64 value and we want time.now and we want the time as Unix so we also so we're giving a warning here all right so we have modified the attribute whenever it's a Time attribute now we just simply need to return it and then we also need to add a comma and we also have to import time so let's import time now that that's done basically it that's all we need to do so replace attributes allows us to iterate over the attributes and whatever we find the attribute that we want change it and we return it go ahead let's restart our program and see what happens ah we can now see time is no longer there it's instead date it's the Unix timestamp great we can replace the values that we want we can replace the attributes that we want and this is it for slog it's really a really small module which allows us to do structured logging in a really nice way I think these kind of logs are really nice to just ingest and they're really easy to work with and the slog module is really easy to work with basically replacing attributes is the most advanced things we're gonna do with it or that I ever do um using the default attributes is just amazing to add stuff that we always want to present the application version Hardware information region for the cloud being hosted we have learned about the log levels we have learned how to set the log level we have to remember if we set the log level to warning we won't see info we won't see debug we will only see logs that are above in the severity and we have also learned how we can replace the default logger for the slog module with our costume customized logger but I really hope you enjoyed it and if you do please feel free to like And subscribe to my channel

Channel: ProgrammingPercy

Views: 3,713

Keywords: go, go 1.21, slog, structured logging, structured log, logging, logging go, go logging, json logs, go json logs

Id: kgkQZnh7BbI

Length: 27min 56sec (1676 seconds)

Published: Wed Aug 09 2023