 Yeah, well, thank you. Thanks for showing up. I wouldn't have thought that so many people are interested in logging. They're good. So the agenda is pretty simple. First of all, try to explain why logging might be useful because at least my impression is that it's one of the most, let's say, underused modules. Then how do we make it work? So I'm just showing around a little bit of the source code and a little bit about structure. And then some optional content in case I run over, including the all-time favorite is logging slow. So this used to be a pie's notebooks. And for scaling issues, I just made some screenshots and turned it into PDF. But you can get all the code and get up. And well, let's start with the ugly part. If you don't use a logging module and start with the most basic way to get out your message, you start with most likely use print. You can use it for multiple things. So looking at that, we have normal information. So this first one, debugging. You want to know what our program is doing, what values are in there at the moment. We might run into a situation where something goes wrong. We also want to report on that. We also do this at a different level. So we have this little division function that really does only a division. Then we call that from another function that just, well, iterates through a complete task. And now we have four calls that we might want to see at one point in time. Normally, if you were to write that, you would probably start, okay, that's interesting. I'll add a print statement. Printed, later on we move the statement. If this program runs into a problem during a long run, you may add some functionality to write into a file. This is all good and well. It has some limitations. So it looks like this. You get all information out. But the only thing that you actually get when you look at it is all the things that you wrote yourself. So that's all text that is in the print statements. And it's all handled the same. You can't really differentiate between the debug level, the error level, et cetera. So print has some limitations. We have to select ourselves what we want to log, how important it is, how we want to handle it. We have to write all the information we want to add to a message. Might be timing information, that might be information about, well, function parameters, whatever you can think of. You have to do it yourself, which also means that you have a good chance to end up with messages who are slightly different. Now, it's not a problem if you read them, but it starts to be a problem if you want to use them in a parser, for example. So I had a situation once where we actually used logging, not on Python, but from Java with different logging configurations and slightly strange logging configurations. That became a huge pain to actually parse those because they were also slightly different. And if you do it by hand, if you do different forms for dates, it will be worse. Finally, we only have limited control where our message does end up. So you can print to a file, you can print to the console, you can even write your own functionality to write to both. But once you start doing this, you basically implement your own little logging module and chance now that the logging that you actually need is already in the standard lab. So what's different with logging? We have more structure. Structure in this case is pretty good because it not only helps you to parse the thing, it also helps you recognize what's in your messages. So you get a nice state stamp, so all the same size, get your error information, you get the name of the logger, it's all pretty nice. And the logging module provides us with all the different infrastructure that we need to set this up. So logging is good. Do you notice a slightly more theoretical band? If you have a message that you want to output from your program, you might ask yourself, how important is this? Do I need this every time I run this program or do I really care about if something is going wrong or if I'm interested into debugging? Where does it come from? As your program goes, you'll have multiple modules, multiple libraries in there that may or may not produce interesting messages and you want to control over that. You also want some information about context. When did this happen? You may, even if you do logging for the web and add session information and things like that, so that in your log, you can really follow a user along. What happened? That's the thing that you normally think first about when you write a logging message, that's what you're writing. If I'm doing this or this function failed, and finally, how does it all look like? So normally, if you think about logging, you'll think about text string, but it's completely reasonable with just a few changes to maybe write it from JSON, which, again, makes parsing much simpler and moves you slowly into the direction of structured logging where you can send your log messages to a database and do some pretty advanced querying, which will be extremely hard if you did it all by hand in text in the beginning. Finally, if we have our message, we want also to control where this message ends up. So do we send it to a file? If we send it to a file, do we want a rotating handler? Do we want, in a multiprocess environment, maybe send it to a socket or a database? Do we want to aggregate it? And this is all things that you, well, would have to implement if you just go the print way, which is what you'll implement. The challenge there is, it implements all of it, not always in the, let's say, most transparent way. So there are some, well, let's say, things that you should know about when you start with logging. But to keep things easy, this is just the same program we had previously, and now just with logging. Now, what you say there is that it does not really add much code to your program. This is even a pretty bad example, because what we have there is, well, no real business logic or programming at all. It's just a division. But even there, each log message is just like a winner statement, and you have some extremely easy configuration up there. So this logging basic config, basically just tells the module that it should include debug messages in the output, and then we get a logup. It's two lines extra and four lines that are different, so no worries. And that links us with this kind of output. But you can say that even with this little changes, we get some bonus features. So we have a more standardized format. We have the log level in for debug, always at the beginning. We have the name of the logger. We only requested one logger, which is why it's always root. And then we have our logger message. But also we have the stack trace for the exception log. Going back. When we did this printf, we just said that we log exception. We had a problem there. Which log exception, you not only generate an error message, so a log level error, but you also send out the stack trace. Makes parsing again somewhat harder if you do it in a file. You can change it as well. But you get this information essentially for free. Well, the second code is just the second iteration. We got results. So for this, we need some of the change. We got a lot of extra features. I'm marking the things that we want out of the logging module to the actual infrastructure of the logging module. So what we actually used for our logging messages is the logpoint debug logpilotinfo is a logger. You request a logger from the logging module, and then you have different functions that serve to indicate whether it's interesting message, debug, or something that will bring your system to its knees critical. You can have different loggers at different places in your program, and you can request different ones. The loggers themselves have some configuration, so they know to which handler they'll talk. They know their debug level. We go into that later. And they send out their messages, log records, via a filter, a filter's optional, tune handler. Handler could be steam handler, writing to console, file handler, rotating file handler, sockets, queue for multiprocessing. I think there are 14 and counting in the module. It's quite likely that you find something that is useful to you. Maybe not perfect, but useful. Also, we say handler is a formator. The formator turns the log message, think a dict, into the actual text that you point out. So, there's a couple of different objects. They are arranged in a tree, as we'll see later, but it's not very complicated to get them. And if you call base config, what happens, let's say, on the hood, is that it just setups a very basic logging infrastructure for you, so it gives you a logger, it gives you a stream handler, it gives you a standard formator, and then it puts out this information that we saw previously. Now, the most interesting thing is usually what log messages should we use. Debug, like the name suggests, is mostly for debugging. So, if you need extra information because you're looking into some problem, it's not something you would have enabled as you run your program. Can I end up in your log files? Usually the space shouldn't be a problem, but it's maybe a little too chatted. Info is information like, I'm starting my program, I'm doing this, I'm not calling this function. Might be interesting, let's you know where you are in your program, but again, not as important. Warning is just that, something that, at one point in time, you should probably look into. Then your error, something went wrong, and finally critical, your program is about crash or needs to be terminated. So, there's also where it helps you to just structure what you're writing, to think about what information do I want to communicate to you. And as you put these out, you see that you got the logging level plus the information, and logging exception is just a special case of error where also the stack to brace is added. And if you only keep, let's say, one thing out of this whole talk, but most likely business. Of course, that helps you already to build your structured log, and you can build from there. So the most basic thing is just gets a lot of messages into the program, set up, or fine-tuning can happen afterwards. Now we go slightly more complex. This is basic config. Basic config is just the easy way to configure the logging module. Mostly for scripts. So if you want to do just one call to get your logging, it's basic config. What I do there, in addition to the slide before, that first of all, I add some format specification. There are two of those, one the date format. Basically, the standard format is also used for in the daytime module for parsing and printing to say what information you want to get out there. One thing to keep in mind is that milliseconds are not included, for some reason or other on the format string. And the format string tells us on what information we want the logging module to include. The interesting thing is that the only part of this message that we supply is the last part message. Everything else is provided by the logger. So the logger will tell you what the time is, specified by date format, plus a millisecond. The level of the log, it will give you the name of the logger message. As you see later, you'll get much more information if you want it, including the line in your source code, including the thread or process ID. So you can log almost everything about your program in there, and in a way that you'll find the course of the log entry later on. You will see that in addition to the log message, a pure text string, you add some... Thanks. You add some information. The 1, 3, 1.3 there. This uses the oldest style string formatting. I think from 3.2 onwards you can also use the new style string formats. And that would be just a configuration option in the formator. For this talk, I just used a simple word. So, slightly more complex, basic config now is a format string, with a date string, and lock level debug. If you ever start logging with debug and info and your messages don't show up, that's what you forgot. The default configuration has the default logger set to warning only, so debug and info messages get dropped. Now, I don't particularly like basic config, because at the end you'll have to learn two different modes of set up the logging. It has this interesting feature that it is only called once. So, once it is called, it's set up the logging system, and if you call it again, it will not necessarily change it, which can be confusing. So, my suggestion would be to go with this directly. It's slightly longer, but at least in my view, it's easier to understand. So, you request the logger, then you set a level for this logger, then you get your handler, assign the logger to the handler, together with the formator, and you have your logging system set up. Essentially the same thing we did before. You can use this, I could edit here. So, just in your Python code, maybe just write a little module, log in set up that you import, it will usually work. If you go for slightly more complex situations, you will do something different. But, just going back what we did here, so we got logger, we assigned a stream handler to the logger, and we assigned a default formator or formator to the stream handler. And the logger always has this log level on which it's enabled or not. In more detail, so the formator has, it's two format strings, one for the time, one for the message. The log info message has the, let's say, textual part, whatever you want to say in prose, and some parameters that get added to the string. And following from this configuration, you got your actual log message. These are all the things that would be available in the log record to add to your message. I've actually taken out some, because there are quite a lot of them. Some of them are quite surprising, like function name and the line number. By default, they are in there. You can disable them for performance reason. If you want to, it doesn't make much of a difference. So, just take away, in your logging, you can really point to the Python code where the log message originated from, which may not be useful on the same day that you write it, but maybe useful when you see a log message, say, two weeks, two months, two years after you wrote the code. This is the final way to set it up, tick config. There's also a configuration file config, but I like this more. It is not actually easy to read, but it is quite powerful. So, what you should take away, the yellow parts are just the different objects that we have seen previously. So, we have a logger down there, the handler and the formator, or which of them reference each other. So, the logger knows that it has one handler named console, and the handler knows that it's one formator named long format. And all the other parameters are sent in there. The nice thing about this is that it's quite easy to add information, and if you have your login configuration in a file outside your program code, it's quite easy to reload the whole system. You can change your login configuration from outside. You can add, and there's where things get slightly more interesting, different handlers to your loggers. So, what you do here is just load the same config, then add a second handler, and then lock one message again. And as you can see, there's this cat log file. Now, my message ends up in my console and also in my file handler. And, well, if you want to, you can add as many handlers as you want to. So, this is our, I'm sure we know, so we have different file handlers and a swim handler. The thing to keep in mind on the log level is that you can have different handlers with different levels. So, if you say, I only want errors in my files, but everything in my console, you can do that. Like I said, so if we just set the file handler to only print the warnings and ignore the debugging info, it will not show up in your file. This is, I do have it quite easy. So, you load your basic config, modify it a little bit, and get more information. You can also, this is where things get interesting in terms of structure at child's loggers. So, we just request other loggers, normally with, well, some name or name.dot, which maps quite well to the name of modules. And what you create is some logging tree. So, you have a tree of logging objects, and you would normally configure this in a way that you attach the file handlers and everything else to the root logger, then add the child loggers below that, and then you have some switches to which to configure where log messages are. So, normally, start the root logger, configure it, and then add one extra logger per module, and best practice is to add name for this. So, go a little bit faster because there's one thing that I'd like to show you. You cannot filter. Filters are a little bit of dark magic. So, it's just a function that you call with your log message, which then decides whether it gets passed on or not. You can also modify the log record. So, if you want to add extra information, you can do that. And for that, I'll just refer you to the iPad notebook. The interesting thing, and the most likely reason is things are fail as this workflow. So, once you have your logging tree built, the, let's say, way that a logging message is passed up the tree is not really intuitive. So, you have a logging call. If it is not enabled at the logger of origin, it gets rejected. If not, a record is created, and the local filters are applied. Now, if there is a handler at the current level, this handler will be called. If not, it will go to the parent. At the parent, it will not work with the filters and it will not work with the level. So, at this moment, the only way to get the message out is the handler, which is also quite nice because you know that the handlers are responsible for filtering the methods, and then it gets emitted. It's actually standard documentation from the module. I just, well, made a little bit more colorful. But I think if you ever run into any problem with logging, this is the most likely cause because there are quite a lot of things that you can tweak or not tweak. Okay, so that's just some basic code for filtering. As you can see, from sweet point something, you can add callables. Before that, it was just an object that had a filter method. So for the 2.7 users, it's slightly inconvenient, but not much more complicated. And you can do a lot of extra things. So you can get the dictionary of the log record and add information, which is actually something that happens with the logging modules. It's not as ugly as it seems. And the log record that's created there looks about like this. So you can see that Ipython strings there. So it's created out from the Ipython logging hierarchy. So, tons of information that you might find useful or, well, not, depends. But just, yeah, behind the scenes. So, if you run into problems to do that, so see what my logging tree like, I want to recommend just one module. Logging Tree, it's somewhere on GitHub, just group it, it's also on pet. It prints out the whole logging tree. This is about page one of, let's guess, five that gets created when you call the, or visualize the logging tree from an Ipython notebook because Ipython serves as quite a lot of logging modules. As a little exercise for yourself, I just recommend open a Python console, import requests and print the logging tree. So, requests or all other modules will also add their own logs, which are by default not enabled. So they have a not set handler and logging never not set. But they are there and you can reconfigure them and use them if you want to. Okay. Thank you, Siphen. We are unfortunately out of time for questions, but I'm sure you'll be answering them in the hallways. Sure. If people have questions about logging. So thank you once more.