Set up Logging with Log4j2 in Java and IntelliJ IDEA

in this video I'm going to give a quick overview of log4j and I'm going to show how to implement it in a simple Java program an IntelliJ IDEA so first of all why do we want log for J why can't we just use system out print line well system out print line just kind of puts stuff somewhere where logging has the concept of levels and these levels can be very important because we can use them to filter our logs so some logs are more important than others also system out print line tends to go to one place where proper logging can send our log messages to multiple places if we want maybe to a file to a database to an email into a console and may have many other places as well the reality is whoever really looks at system out print line it ends up mixed up with a bunch of other stuff when I tend to see system out print line used I tend to see it used by people who just don't understand how to use a debugger and in that case I recommend using a debugger so the logging levels are very important because it's an indication of severity so we have a couple of a couple special log levels here we have off which means don't show anything in all which means show everything in between those two we have kind of a descending list of severity so if we log something at fatal that means our program is crashing or is about to crash or something really bad is happening error is an exception was thrown maybe we could recover from it maybe we couldn't Warren is just something feels off kind of like an array of length zero where we're expecting some data we want to say yeah that doesn't feel right info is just normal okay I'm starting to read a file now I'm writing to a database and then debug and Trace are both kind of fine-grained things that we tend to use early on when we're deploying software and I'll say that these logging levels really come in handy when we're trying to debug for part of my career I was implementing point of sale systems of retailers and there's one particular retailer in Mexico where I worked and they were running on a very limited Hardware profile in their stores and a lot of my job was trying to figure out why we were getting defects and it was tricky because this is a high volume cash register and I'm trying to figure out why something happened two days ago when I wasn't even there so what I would typically do is take the logs and I would filter it by severity level to at least give me a clue and then I could keep digging and put together a hypothesis on why something happened and then hopefully roll out a fix or close the issue if it was something that felt like a one-off so that was really handy at that point and at that point we were using text files for logging but nowadays there are a lot of log aggregators that will aggregate logs across multiple sources which is really important with microservices because a customer single journey through our application could hit a series of microservices that are not necessarily connected at least maybe connected by a correlation ID but not necessarily connected by that especially if it's a scaled microservice where there could be multiple instances running so the ability to create these logs and to place them in different places and then aggregate them together later by a correlation ID or filter them by the severity level will really really save us time when we do what frankly we do a lot of as developers and that is production support so understanding log for J log for J really has two major Concepts loggers are things that gather logs in code so we can reference a logger when we want to make a log statement and then appenders take those log messages and publish them somewhere and what's neat is that loggers can subscribe to multiple appenders so if we have a case where we want to write to a file but we also want to alert for a fatal maybe we alert by sending a text message we could use an appender to do that and we can filter the log levels both on the loader and on the appender so first of all we need a bit of configuration we need to set up our Palm XML with this dependency of course at the time you're watching this video the latest version might be different so I encourage you to go out and grab the latest version so navigate to my palm XML and I jump in the dependencies and you see that I've set this dependency here I already synced it to save us a bit of time but basically we just add that dependency to the dependencies section in our pomxml now there's a configuration file called logfordj2.xml and I wanted to paste it in here but actually it it ended up getting too big and then it kind of Squish down the font so I'm just going to do this one live as long as we put it in the right place and name it the right name log for J will be able to find this automatically so I start by going to source and then Main and then resources right click and I say new file and log4j2.xml again that file name is very important and then I'm going to just paste in a pre-configured log for J configuration that I have at the top we have a property with the name layout which sets the layout of our logging messages so it gives them a standard look and feel so D is date T is time and then we have our level and then we have the logger that's producing this message and then we have the message that came from the program and a line separator for this operating system now log4j is an Apache project so you see you can simply navigate here and it has a description of all the different options that you have for this layout now after that we have our appenders and remember that our appenders are things that will publish the log file somewhere so I've set a couple up here one is console just our normal console like we'll see down here an IntelliJ IDEA when I expand this up and then also a file and you see that the file has a pattern layout as well so we can get a little more granular there on that file now we can have multiple loggers the default logger is often considered the root logger but we can make additional loggers as well and you see that here I made a logger called Vehicles we also know that logger can publish to multiple appenders which is how we get the log messages that can go to a console go to a file database and even trigger a text message all simultaneously from the same logger so you see here I'm referring to log file which is a file where I'm going to be appending these log messages and then also console up here which just writes to our standard system out now in the log file you'll note that I'm referencing a file called app.log and that's the file where our logs are going to go so you know I just have it sitting out kind of it um root level right now but yeah ideally we might put that on an absolute path or even send it to a special computer uh that's just going to have our log files we could log to a different computer if we want log to a database anything like that but for Simplicity I'm simply having it logged to a file called app.log Next we need to publish to the log from our code so first of all we're going to use one of these logger messages here to instantiate our logger and then we can use logger Dot and the different severity level to send a log message so remember the severity levels uh really the ones that are important here are fatal error war and info debug and Trace and you see in my example I have info and error the other ones I mentioned also exist debug Trace fatal warn so on and so so forth so the first thing we need to do is set up this logger variable when we're starting when we're at the very top of our class either when we're instantiating an object or very early on in construction of that class so that we can use the logger after that we need to insert these log messages wherever we think they're appropriate and very important do it at the correct logging level sometimes I've seen Junior programmers who log everything at air level even just normal stuff it's like no stop stop you know when you're looking at a log that was generated over two minutes and could easily be 30 megabytes worth of information the ability to search by just error is very important and if you're logging everything at air that's going to slow you down significantly so understanding those levels is crucial so back to our program and I'm going to go to an inventory reader class that I made previously and at the top I'm going to add that statement to initialize our logger and so just kind of put it up here this is going to be called shortly after the Constructor for this class is called if that's called but nonetheless because I'm declaring it as an attribute and good idea to make it private but since I'm declaring it as an attribute that means that all of my methods have access to this attribute called logger so we go to create vehicle and let's go ahead and say logger.info and we'll say just a simple message reading vehicles then let's go ahead and repeat this down at the end of the method and we'll say finished reading vehicles now we have an interesting scenario here which is we have a catch Block in a best practice with exceptions is you should always log in a catch block even if you don't think you have to there again that's where going back after the fact and tracing back is really valuable when you have these nuggets we understand what was happening in the exception so for this we can try a different logging level we'll want to do it before we throw it log this one at error now let's run our program and I anticipate that we're going to see a new file created called app.log and I anticipate that we'll also see a bit of output in the console as we run our program so I'll tell you what why don't I go ahead and debug it and watch this one at a time so snap a break point here and then we will debug now note I've already stepped over that logger.info note in IntelliJ if I go to console you'll see info Vehicles reading Vehicles you'll also see the time stamp and the thread just as that format told us it would but notice the important thing is it's telling us the severity level right here so I'll go ahead and go through this and I'll tell you what I'm going to snap another break point right in my other two log messages I do not anticipate log.error to be invoked just yet because I It should read this file cleanly so we shouldn't see that invoke but we should see the last one invoked so I continue and looks like I went a little too fast there but nonetheless you notice that we have our other info statement in the logger let's take a look at app.log and sure enough this is the destination of our other appender and it has similar messages so go back to inventory reader and I finish now I did say that appenders can have different severity levels so let's try this I'm going to say for the console only show me errors but for the file show me everything so I go back to log4j at 2.xml and I simply go to the appender that I want to change and I add this line level range filter Min level error max level error which means it's only going to see error messages of course I could adjust that to get more messages but let's say we just want to see error messages here unmatched is accept so if it's an error we'll go ahead and use it on mismatch equals deny let's run our program one more time in what I anticipate now is that we won't get these info messages in the console however we will still get them in our app.log now it's going to append to app.log so you notice it has the Old Log statements here but let's watch what happens when we go ahead and run this with the updated filter on our offender so you see we got the two new info messages in our app.log now let's scroll up on the console and you see sure enough we did not receive the error message in the console so that's how log4j can effectively filter logs and send them only to the right destination another way that I used this when I was working in point of sale is we did exactly this we had one file that would have all of the log information and then a console that would only show errors or we could have that in a file that only shows it errors when someone told me the point of sale device had crashed it may be uh 1 pm the previous day a lot of times the first thing I would do is go to the file that just has the errors to try to see what was happening at that point and once I start to come up with a hypothesis then I'd go to the more detail log file to see exactly what steps were taken to get to that error little tricky work but it was kind of fun too so okay now we need to test our Theory out though will we still see errors in the console and when we see everything in our app.log well for that I can essentially Force an exception to happen I'm going to give this file that we're reading an invalid name and what I anticipate will happen then is going to catch it down here in this catch block and that's going to give us our error message let's go ahead and run this in debug mode so we can watch that happen Okay I anticipate this will throw an exception I'm going to choose step over which if everything worked properly would go to the next line to execute but if there is an exception this will jump right to the catch block and sure enough here's our catch block and you notice that we have an exception it says no such file inventory 2.txt so we log it let's go to our console look at that there's our error in the console no info lines but we still have an error log for J uh sorry app.log and again remember it's going to keep appending to this file each time we run so we have our initial info and now we have an error message we go back and it's going to throw this runtime exception which is interesting because it's going to skip line 63 and it gives us a bit more information on the console so what you see here is we typically had a reading Vehicles finished reading Vehicles reading Vehicles finished reading Vehicles now we have reading vehicles and we have error here so it didn't get to the finished treating Vehicles because there was an exception thrown it looks like it could probably be a little bit more verbose in what we're throwing here I should have said e.getmessage I think I tried to and might have typed over myself but nonetheless we do see now that we're able to log at different levels and we're able to configure our penders to listen to certain levels of logging information so this is absolutely critical to production support it's not the thing we tend to think of in backlog refinement or Sprint planning but it's definitely something that is going to come in very handy especially in today's world where we have mobile apps where there's Hardware we don't even own and we want to find some things out about it and that concept I mentioned about microservices and correlation IDs so I would put this pretty high on the list of must have skills for a good developer and I hope this video helped you get there and as always I look forward to reading your comments thank you

Channel: Brandan Jones

Views: 12,194

Keywords: IntelliJ IDEA, Java, all, debug, error, fatal, info, log.error, log.info, log4j, log4j2.xml, off, trace, warn

Id: T_lWpqOWaE0

Length: 15min 20sec (920 seconds)

Published: Sun Apr 23 2023