Spring Boot Tips : Part 3 - How to implement Logging in SpringBoot applications

[Music] welcome to the part 3 of springboard tips series logging is a very important and common requirement for most of the applications and springboot is all about making it easy to implement those common requirements so let us explore how to implement login in spring boot applications so in this episode we are going to take a quick look at how we used to do logging before springboard and how spring boot is making it easy to implement logging with its default logging support and how we can tweak and customize those logging configurations and how we can implement logging specific to a selected profile maybe we want to do logging in a different way in dev environment we want to do differently in production environment so how spring supports that and also finally we are going to take a quick look at what are the some common best practices for logging let us take a quick look at what are the options available for logging in java so there is java util logging within jdk itself and there used to be a common slacking which was uh heavily used and then there is log4j log back and log4j2 j was locking so there are plenty of options and then there is slf rj which is not the actual logging uh implementer but it's a packet to other login providers so basically if you rely upon slf rj api only you will be able to switch any of the implementation maybe you want to use slfrg along with log4j2 or slfrg with logback so the advantage is even if you want to switch any of the logging library provider uh your code won't change that's a good improvement and let us see how we usually do logging in our application right let's say we are using log4c so this is how we usually do uh we create a log for say properties file and configure what is the appender and what is the pattern that we want to use and all that and we get a reference to uh logger like this logo.catlogger and whatever the class you want to use and there is other option like instead of using properties file you may want to use xml configuration of xml so you can use appenders same thing we can implement but instead of log4j if you want to log back you need to create a different xml configuration file as syntax could be slightly different but the point i am trying to make is depending on the library you are using and depending on the configuration format that you want to use whether xml or properties the logging configuration changes so now coming to springboard so again springboot is all about making it easy to implement common application requirement and logging is used uh in every application if you are putting your application in production you should take logging very seriously because if anything goes wrong that is where you will be looking at first what went wrong and springboot comes with logging support by default you don't have to configure anything out of the box when you create a springboot application it is already pre-configured with slf rj and log back okay but if you want to switch log back to log4j2 for any reason it's very easy to switch and without doing any custom configuration it is simply adding a log4j to starter and excluding the default logging starter that's all you need to do to switch to log version 2. and even the best part is you don't have to create those uh configuration files like the uh like log4j2 properties or logos xml logba logback.xml you don't have to create those xmls and simply you can configure most of these logging configuration properties in application.properties file only you don't have to create but for any reason you need more control over the login configuration then definitely you can go ahead and create those uh login configuration files like like log back dot xml or log4j2.xml and springboot will respect that so it is very convenient and very easy to configure within the application.properties itself okay let's create a simple springboard application and see how we can implement logging have created a simple springboot application and we have a main entry point class over here and an empty application properties nothing configured and also i have one demo controller with a simple resting endpoint okay let me run this application and here i am getting a logger instance and i am using slf rj classes over here and i am obtaining the logger for demo controller and when i hit the end point hello i am logging what is the name that i provided okay now let us call this api point yeah we got the response and now if we take a look at console it is already printing in word okay so it's working i did not do anything i simply get this logger and it is working i have not configured anything we don't have any log for the properties or log back xml files nothing and if even if you take a look at palm dot xml so here we have a starter web and we have devtools lombok and test nothing is configured explicitly for logging but still i am able to get all this logging and even if you take a look at the logs there is plenty of good information usual timestamp and what is the log level and this is a pid process id and this is what is the thread and what is the class and the actual message so we got good uh locking message out of the box we don't configure anything but just let us understand how this all work fine okay now when we add this startup web dependency if you explore the dependencies of it now i am expanding this starter web dependency and i can see here it depends on spring boot starter okay even if you expand that there is springboard starter logging there is a another startup that again depends on this springboard starter logging and even if you expand it more we can see it has slf rj and then log back classic dependencies added so even though we are not explicitly adding this logging dependencies when we add any springboot starter which internally depends on springboard starter and which transitively pulls springboard starter logging that's how we got all the dependencies fine we got the dependencies but where are we specifying what is the log format what pieces we want to put in the locks where are we specifying it right so let us take a peek at within the logging starter itself okay so if i navigate to spring boot logging okay not spring boot so here i am checking inside spring boot jar file there we can find logging package and here there is log4j2 logback and if we expand logback there are um defaults.xml so here if you see there are some common patterns that are defined uh console log pattern so what what needs to print what is the default timestamp pattern here and what is the log level and this is to print process id and here we have a message and package name so all what is the pattern that we want to follow and for the file logging pattern so some constants are defined in defaults.xml file and there is console offender where it include it defines the console vendor it specifies what is the pattern to use and what is the cache set and this is the console of printer class we need to use and again there is another file up under xml configuration file this is a rolling file appender and specifies what is the pattern and cache set and what is the log file name to uh use for logging and a rolling policy defined like what is the file pattern for this and uh what is the rolling policy like what is the max size and all that okay so if you take another look at this base xml we are including those defaults which define all those patterns and everything and then it includes log file uh what is the default login location log file location and it also includes console appender file appender so spring boot by default defines this common patterns for console opener and file appender and internally if you don't specify anything it is going to use these configuration files and then log accordingly that's why without we having to do anything we are able to get this logging out of the box using these defaults if we want to change anything ah for any reason then we can start and tweak those configurations using let's say i want to change log level default log level by default it is let's say locking level dot root by default it is uh info i think let us change it to debug okay now right now we are getting info and one messages only right now i am changing the root log level to debug and if i restart you can see we will get a lot more debug messages because we enabled a debug level so it will print a lot of debug messages as well right so the point is we don't have to create any of those logging library specific xmls or properties files you can tweak the login configuration within the application.properties itself for example if i print right now in my controller i'm using log logger info right so what if i use trace and let me change it back to info which is a default it won't print isn't it because we have used trace but trace level is not enabled the default is info only now even if i make this api call i won't see that message here so how i can change it okay currently my controller is in com.civil apps package i can go and change the login level logging level dot com dot civil apps equals to trace i want to enable trace for my com.civil apps package i'm restarting it so now if i make a api call i will see this logging statement here so that's how easy it is to simply change it and also for any reason if we by default by default console appender is enabled and logging file appender is not enabled let's say we want to enable file append how we can do that logging dot talking dot file name let's say i want it to be myapp.log and by mentioning this logging file name it it enables both console appender as well as file appender both we can see here all the logs and if i refresh i can see my app.log also if i make a pay again in ap call i am able to see both in this logging file and console also so it is that easy just add a property you got console appender and file appender working fine now if we go back and typically this is how you can customize various things like suppose you want to set logging level to one for words spring framework and for hibernate you want to enable debug level this is how you can do it and another interesting feature that is added is let's say you have several packages in your application and for a bunch of packages you want to enable certain log level let's say debug level so instead of specifying all those different packages and then specifying the log level you can group them let's say for example for whatever reason in my application i have com.civil apps and org.civil apps packages and i can logically group them under civa labs group okay civil login.group.civalabs and specify all those packages and using that group name i can enable a specific uh log level i don't have to specify uh com dot logging.level.com.apps equals to debug logging dot level dot org dot civil apps equals to debug like that i can group them logically and then i can enable one specific level for the entire group that's a very good convenience within your application probably you want to enable some level at the controller level and for all the business logic you want to uh enable differently a different log level that's easy to achieve in this log groups pattern okay and also you can tweak what is the pattern that you want to use for any reason if the default login pattern is not suitable for you you can change it and also simply enabling this logging file name you will be able to specify and enable this file appender an interesting feature provided by most of the logging libraries is mdc mapped diagnostic context so let's say we are building an api and only authenticated users call this api and you want to print who is the user calling certain apis and every log statement you want to include who is the user calling this one okay so uh to implement that the the easiest way would be to have a filter and extract the user information from request and put it in the mdc and you can configure your logging pattern to include those mdc context variables okay let us take a look at it and how we can implement this so right now we did not overwrite any pattern here which means by default we are using what comes out of the box let's take this console log button here so i am overriding the default logging pattern for console i am going to remove most of the things just to be to make it simpler okay okay now if i restart okay everything looks fine and if i make a call i'm still seeing this uh logging fine okay now uh what we can do um here just for getting to know the concept of mdc let's say whenever somebody makes this uh api call we want to put slf rc mdc dot port uh user id let's say one two three four okay so i am putting a user id in mdc and i am restarting this so behind the scenes mdc is use thread local so that it won't mess with other requests it's it's this data will be pertained only for that particular request so now if we make a api call we got it but we how do we uh make this user id appear in log files right so let's see after pid i want to print user id column so this is the format to print any mdc variable percentage x and within braces you need to put your variable name that you have used in your mdc key okay so we just specified user id x and variable user id okay now if i restart and i'm making a api call here you can see by default when it print it print nothing and when i make api call because by that time we have this user id variable in mdc context we are able to see this value here but this is not how we intend to use it right we want to automatically do it for all the log statements so let's create a filter so i will call it as mdc filter and springboard provides this convenience class of once per request filter and i'll mark this as a spring component and springboard will take care of automatically registering this filter and all i need to do is implement do filter internal here i am going to do filter chain dot to filter request and response i will simply delegate this and finally so here before proceeding to i'll put mdc dot put user id so ideally here we should be getting the token i mean now who is the user from request or something probably this is what maybe you want to use request start getter get header and say user id and you might want to [Music] get user id from header and then use it but for sake of discussion let us put some random ui id okay and i'm going to put that in mdc and finally once the request processing is done we should be clearing this up i'm going to remove user id or you can even use to clear completely clear all the variables not just user writing okay so uh here to recap what we are doing we have created a filter extending once per request filter from spring framework and we are marking it as a spring component so that it will automatically register as a filter and we are delegating the actual call to our respective controllers but before that we are extracting the user id and then putting it into mdc under this user id variable and then once the request is done we are clearing the mdc context okay now we don't need to specify it over here okay and in our application properties we have user id colon percentage x and user id we are printing user id from the mdc okay let us restart and verify whether we are getting this value or not so here if you take a look at it ah we can see this user id value automatically printed okay cool [Music] but here in the above logs if you take a look at it is empty may be fine but if you want to put some default value when the actual value is not present so this is a notation to have default value colon dash and maybe here you can put anonymous or guest or something like that i'll put guest so if i restart yeah by default there is no value so that's why we can have a guest printed over here but when i make this api call it's going to print md7 okay nice one another cool feature like if you notice there are these log levels printed in different colors and the class names printed in different colors so you want to color your variables here here you we can simply follow what it is doing let's take this percentage clr and i want to print it with magenta only okay okay now you notice right our user id is also getting printed in the color cool what if i not only have user id let's say i also have some correlation id so that i can see all the logs that belongs to a particular request let's say i have some correlation id and you can yeah you can generate again using random uuid okay so uh how do we print it again same we can go back to our configuration file and then we would be able to add another similar to this we could we could add another one specifying that correlation id okay um let me take this key here and put it over here so i can just print space okay this works now just to verify so okay it has this correlation id yeah it is printing correlation but let's say you want to print all the variables that are there in the mdc so the easiest way is instead of specifying one variable you can simply print percentage x without specifying any particular variable in this way it is going to print all the variables that are there in the mdc let me restart so it is no more correlation id it is like context let us name it as context okay and so now if i make an api call you can see first of all we still have this user id printed over here but under context it has both user id and correlation id as well so if you want to print everything you don't have to specify after percentage x what is the variable you want to print if you simply leave it to percentage x it's going to print all the variables like the way here we had good fun with tweaking these patterns and all using mdc but let's say there is a limitation of how much you can configure here let's say you want to add a new appender like smtp offender or json based up under things like that which you cannot configure solely through these properties file so in that case you can actually create logback.xml file and put the configuration over there instead of configuring through properties in application.properties you can actually create logback dot xml and yeah here we can uh reuse um that are already defined within the spring framework itself we have this defaults xml and we have file appender so under defaults right we have all the variables defined and we have console appender and file appender so we can reuse them we can specify okay i want to have um now i can import both console and file appenders from the existing resources and i can specify okay root level i want to have uh info and i i want to redirect all the logs to console appender and i can specify these lock levels so this is how you usually do even without springboard and when you have this file spring boot will respect this okay now i removed all the properties logging related properties from my application properties file i have this logback.xml and if i restart it right now so still it's going to work as same so this default format of logback.xml configuration works fine but what if you want to use a different appender if you are running with a local profile and if you are running with any non-local profile let's say you are running with a dev profile qa profile or staging prod anything and you might want to use file appender instead of console opener how do you do that conditionally by default if you use logback.xml alone you cannot do that but there is a springboard extension for back which allows us to do that instead of using logback.xml we should name it as logback hyphen spring.xml let us check in the official documentation how we can use a profile specific configuration if you go to springboot docs under core features there is logging under which there is log back extensions section so here you can see we can use this spring profile name property to customize what configuration you want to enable if we are running with staging profile and here we have it's not a simple one profile we can also check whether it is tab profile or staging still do this and if it is not production that means any profile apart from production enable this so let us take this and here i can put if it is local profile i want to use only console but if it is any other profile that is non-local i want to use let's say file appender okay i can remove it here right so here we have one spring profile definition which is local and in that case if it is if the application is running with local profile we are printing it to the console only if it is any other profile apart from local maybe it is w q a anything so we are using file printer so this is how we can customize the login configuration based on the profile and also there is one more important feature in addition to spring profile we can also actually use uh spring properties that we define in our properties file or through environment variables so we can take this spring property definition and include at the top and change it to region and i'm i want to read it from app dot region property and i would like to use us east one as the default recently and now um because if you look at file appender the actual file name would be using this log file uh variable name so let us define that variable here property equals to log file and value equals to so how i want to name my log file i want to use [Music] region hyphen myapp.log so what i am doing here i am using this string property to read the variable uh to read the property app.region value and put it in name region and with a default value of used1 and i am creating a log file property with region prefix and myapp.log okay now if i don't configure app.regionvalue anything here it would use us east one but as i have app.region it should take us to and generate the log file as us is to hyphen myapp.log file okay now let us start the application and see let me refresh so here you can see us is to my app okay so that way you can you can use properties dynamically from app region and yeah the good thing is these variables are not required to statically define here for example you are running your application in aws and this region could be dynamic depending on which region you are running your application but as long as you are able to replace this with system properties or environment variables that is good let us say let us tweak our application configuration and modify options and environment variables we can say app underscore region equals to ap south east 2 just i am trying to change app.region value dynamically using environment variable now if i restart the application so it created ap southeast to myapp.log file so that's how you can use any dynamic properties from application properties okay we have looked at various configuration options and how to tweak them now let's also just quickly uh take a look at how we can change default logging which is using log back to log4j2 so it's really as simple as excluding default logging spring would start logging yeah excluded that but you need to then include what is the starter you want to use for logging spring boot starter um not locking it would be log4j2 okay so this is all you need to do to switch to log version two okay and again in this in the same way instead of using log back hyphen spring dot xml to tweak further uh the default configuration you need to create log4j2 hyphen spring.xml if you want to customize that's all you have to do okay i think we have covered good enough ground about how to do logging in springboot applications now let us take a glance at what are some common best practices while doing logging so one of the common requirement is to be able to identify all the logs related to a particular request let's say when a user makes a api call or something we may end up writing a bunch of log statements and when something goes wrong we want to identify all the log statements that belongs to a particular request in that case um this correlation id or tracking id whatever you call with mdc that helps a lot and next thing is to make sure not to log any sensitive data sometimes we just print an entire object and maybe by mistake there is a twisting method which is printing all the variables and that object might contain a sense to data like passwords or keys something like that so you need to be very careful about logging this sense to data you need to double check before printing an entire object or whatever comes out of the box from request parameters things like that and another one is if you if you notice in in some code bases there is is debug enabled is trace enabled the checks are there and again this is one of the popular interview question as well by default if you make this log level let's say info automatically it won't print these debug statements or trace statements right then why do we need to check is debug enabled is trace enabled if they are not enabled anyway those log statements won't be printed so the reason being usually we use debug or tracing log statements to print more detailed information that may involve even calling some other methods also so if we don't check that let's go to our controller let's say here i am doing logger.trace um [Music] some message and then maybe i am calling some a method or to print some verbose info okay so here whether trace is enabled or not this method will still be executed so uh it's a waste of execution time by it it's unnecessarily you are allocating more memory and performing some operations uh by calling this method and finally it is going to check whether trace is enabled uh if not it's not going to be useful so that is why you will typically check for logger dot is debug enabled and then print so with this one uh here itself the check happens and then there is no need to execute this method and then again are you going to put for every uh info or are all kinds of statements no usually we use a trace and debug to print verbose information uh checking only for those makes sense you don't have to check for every log level okay cool and in the recent times like we are moving towards micro services and we want to use some centralized logging stack like elk elastic log stash and kibana or elastic elastic sets and fluency and kibana so in that kind of a setup you might want to use structure logging may be in json format instead of this plain text based logging you might want to use a structured login and also if you are doing this distributed systems and this associating correlation id and tracking id with mdc is okay for a single service but you are running a group of micro services and you might want to track entire call chain from one micro service to another micro service then you might need this distributed tracing feature and there is a project called spring cloud sleuth which provides that facility so this is one another uh important uh topic when you deal with microservices okay so um yeah these are the few things that you need to keep in mind while implementing logging and if you find any other practices also please uh comment below okay so that others also get benefit out of it okay that's all about logging and i hope this video is really helpful and thanks for watching [Music]

Channel: SivaLabs

Views: 4,318

Keywords: java, spring, spring-boot, logging, best-practices

Id: tmj6QphzAPo

Length: 44min 21sec (2661 seconds)

Published: Tue May 17 2022