Want this course?
Logging on the JVM
Course: JVM Fundamentals for Clojure
A lot of people requested this lesson. How do we set up logging on the JVM? It turns out that it's not that hard. We can do it with a few lines of code. In this lesson, we see how to use logging in libraries and in applications.
Hello, we're going to be looking at logging in clojure on the JVM. Logging is one of those things that you might have never had to do in terms of setting it up and configuring it or choosing what logging library you're going to use. So this is trying to be kind of an introduction to the ecosystem, but the ecosystem is a little complicated and has a lot of history, so sometimes you'll do research, and the stuff is just out of date. But what I'm going to try to give you is the current recommended set up for your libraries and applications in clojure. Okay, so that said, libraries and applications are a little different. If you got an application, it is going to be running in a certain environment.
You're going to want to configure the logging so that it goes where you want it to go. Whereas with a library, you're expecting it to be used in another application, so you don't want to configure the logging. You just want it to work with whatever logging system is in the application. And so that is how it is set up. Let's go over how a library should set up logging. The first thing is, we need to go into our project. And I got this pulled up. This is a library called clojure.tools.logging. It's an official org.clojure library. And what it does is it will automatically select from a list of known logging providers. It will select the first one that works, that exists. And you use that one.
So what happens is that it tries the first one, and if it is not there it tries the second one, all the way until the end, which is the default Java logging system. And what that means is that it's going to work. It's going to find one. But it's going to automatically select another one if it exists. So got that imported, and now the way it works is with a series of macros, clojure.tools.logging will require it, there. And so I have this function calculate average.
Let me go to my repl. If I calculate average, let's say ten and two. Oh, I misspelled that. Right, okay, so we get the right answer. But let's say we want to log every time we do this, for you know illustrative purposes. So we want to say calculating the average of some numbers. Now I compile it. Okay we don't see the output here because the default is still set up because it's not an application it's a library.
It's actually going to the standard out for this application, which is here. And so we see this log message. on February ninth, twenty-seventeen at 1:27 PM, this class invoked info, calculating the average of some numbers. This is just the standard way it's done, and that's really what you want in a library, just leave it alone because it's not the best log output but whatever application you are running in will actually be able to configure it for what they want.
Okay, so let's say, well I want more information in here. You can actually use the macros. Okay so let me back up a second. So there are different macros for the different logging levels. So there is is for instance warn. There is error. There's debugg. And all of these are at their own level. Like this is the warning, this is the severe, the debugg, the debug also looks like a prints app, and it prints an info message.
Oh wait sorry. No debug looks like it is turned off. Right so debugging is, you know, it's only a development time you are going to be debugging. And so that is often turned off. Okay so there is different log levels. You can also put in a thrown exceptions, so if I want to say catch the exception, because what if numbers is empty, that means that count numbers is going to be zero. So I can do, catch exception e and then log error, and then I pass in that exception, caught an exception calculating the average.
Okay let's get rid of these guys. Let's look at the repl. And if I do that there shouldn't be any logging messages, right. Let me move up here. Okay so now if I calculate the average of an empty list, severe, caught an exception calculating the average, and then we see that it is set up to print out the stack trace. Okay so those are a couple of things that you can do with this logging library. It takes a message and an exception or just the message. But here is another thing, let's say that I want to do an info but I want to have a richer message. Because this message is just a string, I want to include more values in there.
I can actually use infof, and all the log levels have this. Infof, optional first thing is the thrill-able, is the exception, but then it takes a format string. So calculating the average of a %d. See I never remember these format things, so I'm going to look them up. I want an integral, decimal integer. Yeah, a d, okay. This is on the Java.util.formatter class documentation. So let's go here calculating the average of %d numbers. And then you give it the count.
Okay, let's go back to the repl, calculate average. And we'll see in here, info, calculating the average of 0 numbers. And then it caught that exception or I could do 11,2,3,21, like that. And calculating the average of four numbers. Okay so that let's you do a formatter, you have as many format thingies in the string as you want, and then of course, you have to put that many arguments to format, to the f version. And like I said it has warnf, errorf, all that, and you can put the exception here, if you have one.
Okay, so maybe I want to do that. I want to put errorf here, caught in calculating the average of %d numbers, count numbers, so I don't do it every time, only when I get an error. That's cool, so calculating. Yes, caught an exception calculating an average of zero numbers, divide by zero.
Okay, so that's a library. If you got a library, you just include clojure.tools.logging and you start putting in the logging macro calls at every point you want to log, at whatever log level is appropriate. If you want to do an application, you're going to need to setup one more thing plus the configuration.
Okay, so let's go and set up that thing. You still need tools.logging, but the other thing you want is called logback. Logback is written by someone who has written several logging systems for the JVM. They get better over time. And this is the recommended one in general for the JVM, as you just include logback classic.
Okay, this is for an application, remember. So I'm just going to put that in there, and I'm going to set up my logging name space to be a main name space that way I can run it like a program. So dash main args, and I'm going to do a couple of things. I'm going to log info starting up the app. And then I'm going to do shutting down the app.
Then I'm going to do a system dot this slash exit, which is what you should be doing. And in the middle I guess I'll calculate some averages, so calculate average. Let's do this in a little loop, dotimes did ten of them and then calculate the average of range ten. Let's print it out. And then we are going to sleep for half a second. Okay, so let's go back to the shell, and we're going to do a lein run. I didn't do the main, did I? I forgot that, okay, main is jvm-playground.logging.
Okay so this is a nicer logging message I think. It's on one line, first of all. It has the time. It doesn't have the date. I could put that in. It says what the name space is that's running it. It's got the level. Or is that the name space or something else? I think that is something else. So where is this all configured? Let's check. There is actually a file that you should put in there called logback.xml, and this is going to get read in when the JVM starts. And it configures everything up.
So there is a thing called an appender, which is basically the output of your logs. And this one is defining us one called standard out, and it's using this class called ConsoleAppender. And it just prints it out to standard out, and of course it handles threading, so different threads outputting at the same time are going to get appended without overriding each other. So each line is going to be added separately. And then you have this thing called an encoder pattern. And that's what let's you say how it's going to get printed out. I notice this one is on one line. It's got the date here or the time. You can put in the date if you want. This is the thread. The name of the thread that was running, that log, that message, the level, and then the logger.
How does that look like? Yeah, this one, is whatever was logging it. Okay, and then it's the message. And then a new line. Okay so you can configure this. Look up in the docs, which I'll link to in the notes that have all the different things you can put in that log message, which is cool. It is very configurable. You just start it up. The other thing about this logback is it implements, or I guess, it depends on SL4J, which is a logging system similar to clojure.tools.logging. It's just a wrapper on other logging systems, so you can actually switch out the logging at runtime.
Meaning you know, when it gets run the first time, this other thing will be able to choose how things are logged. But that's kind of a complicated thing. Everyone chooses logback anyway. Except if you are like running in an application container or whatever, then it will happen automatically however that's configured. But still logback supports all of that. Okay, and notice that I'm using just one appender in my root level debug. Right, so that means this level is what level do I start logging at. I want to start logging at the debug level. And then you say what appenders do I go to while stadardout. That refers to this one up here. So you can do multiple appenders. So I want to also append to a file. The file is errors.log. Yeah, it's append true. And let's see, if I run this again. Oops, oops. I feel like I wrote this program wrong. Oh range ten, that's not what I meant, range X is what I meant.
Anyway that's not that important, There we go, divide by zero. That's what I wanted to see. It was caught so it's going to keep going. But it is going to log that error, see on one line and then boom an exception. And I think that is all configurable, what gets there. But notice how, when we are doing it at the counsel, the print line statements here are getting mixed in with the log statements, so let's open up that file errors.log, and we'll see that we have the log all here in our log file, so you know you can put that wherever you want it, specify exactly where you want the log file to be when it gets run. And of course, another thing is you can have that logback.xml be outside of your apps source code. And so wherever you deploy it, it gets read in from there. Okay, so that's logging on the JVM. This is the recommended set up that will get you working for libraries and applications.