This is the largest room I've ever given a presentation to, so thank you for showing
up.
Also, let's see.
How many of you are using logging right now in your job?
Wow.
Okay, that's a lot of you.
This is the wrong talk.
No, I'm just kidding.
How many of you would say you're doing Python logging well?
Yeah, that's what I thought.
Well, it's okay.
You're in the right conversation because we're going to tell you all about how you get started
with Python logging and all the wonderful things that, hold on, that's my boss, hold
on.
Hey, yeah, I'm in the middle of a presentation right now.
What's up?
He deployed on a Saturday?
Are you kidding me?
What do you mean, production's broken?
Yeah, tell me you check the logs.
He's not logging.
Oh my goodness.
Well, please don't fire him.
Tell him to tune into my talk.
We're going to go over the basics of logging and then we're going to get all the way down
into some more advanced logging configurations.
Okay?
Yeah.
Ciao.
So, nobody wants to be in that situation.
Honestly, that went over way better than I thought it would.
Nobody wants to be in that situation.
So before we get too deep though, I'm going to just say hi.
I'm David.
I'm a developer advocate for OpenSearch.
Thanks to the OpenSearch group for letting me come here.
OpenSearch is commonly used as a log store, so it fits in nice with Python logging.
Previous to this, I'd worked as a data engineer, network automation engineer, DevOps engineer.
I've done a lot of engineering and all of them had one thing in common and it was I
needed a lot of logs to really understand what was going on at any point in my application.
So you might want to get your phones out at this point.
I have lots of QR codes.
Just kidding.
There are only three.
And we're going to go to code right after this one.
So that's my link tree if you want to connect with me and hear more about OpenSearch because
I'll talk your ear off, I promise.
So with that, you can follow along.
There's a gist for this whole presentation.
It can all run for the most part.
I was working on it last night till very late.
And we're going to go ahead and get started.
So as with anything, we're going to import logging off to the races.
And now you can check off your JIRA card and put it on the backlog.
Just kidding.
We all know that logging is a lot more than just importing logging.
So we're going to start with the logger.
Logger is kind of the core concept of Python logging and all loggers start with a name.
So we're going to do underscore underscore name.
Does anyone know what underscore underscore name actually will resolve to in this instance?
Any guesses?
It's underscore underscore main.
Come on, guys.
So we create a logger.
We give it a name.
And fun fact of the day, that logger is global.
I can import Python logging and do get logger, of course, from anywhere and use this logger.
As it's too small.
Yes.
There we go.
Try not to delete code while I'm at it.
There we go.
We're going to make this smaller.
We're going to make this up here.
So as we know with logging, there are several different levels you can set.
These levels are a filtering mechanism for Python logging.
Fun fact of the day, though, most people don't know this, is these logger or these levels
actually resolve two numbers.
And those numbers are used to do filtering.
And fun fact of the day, you can actually make your own log levels as if five, six,
six log levels, seven log levels isn't enough.
You could add more potentially if you needed that.
So we're going to go ahead and send this to terminal.
And we're going to take a look at all those log levels.
Here we are.
As we can see, they resolve to 10, 20, 30, 30, 30, 30, 40, and 50.
So warn and warning both resolve to the same log level.
So they're both there in case you need two log levels that have the same level.
And these levels, again, are used for filtering.
So as you are sending out logs, they're used to filter out logs that maybe are less important.
So the number, the lower the importance of the log.
So let's talk about emitting a log.
Here we're going to go ahead and send a log with logger.info.
So that's going to emit a log from the logger with the info level attached to it.
Upper case info is for sending logs, upper case info is the level.
And nothing actually happens.
It just gets sent to the terminal and nothing happens.
And the reason why nothing happens is because we've not told it where it needs to go.
We need log handlers.
So that is what we do.
We're going to build a simple syslog handler for, sorry, streaming handler for sending to
standard out now.
So handlers receive logs from the logger.
It's pretty straightforward.
I'm going to go ahead and create this real quick.
We're going to set the level of our handler.
Remember our levels are our wonderful filtering mechanism.
Set the level to warning.
And the top one will not show up, but the bottom one should because it is greater than
warning.
And there it is.
This will.
That's pretty dull.
Nobody really wants a log that says this will.
That tells us nothing.
You have no clue what's going on in your application.
What time did this will?
What time will it won't?
So we need to add some context.
And the way we get context is, of course, with log formatters.
And I've jumped ahead too far in my presentation.
We're just going to take a quick back step real quick.
We're going to talk about some of the other handlers that are built in.
So there's the rotating file handle.
This one's particularly useful if you have too many logs and your file gets too large.
It can actually automatically rotate that file every X amount of size into a new file.
And then you can specify for it to delete logs after a certain amount of time or a certain
amount of files.
We have the syslog handler.
Syslog is a standard for logging.
HTTP lets you send logs to arbitrary HTTP endpoints.
Time rotating file handler, believe it or not, is a timed rotation of your log files.
Whether it be every day, every minute, or please God forbid every second, do not do
that.
You will end up with thousands of files.
I did actually every hour once, and that was a huge mistake.
I ended up with like 15,000 files after a little bit.
And the SMTP handler, if you are masochistic.
Now we'll talk about formatters.
OK.
So let's go ahead.
We're going to create, set our console handle to the info level.
We're going to create a formatter.
The formatter is going to include the date and time, the name of the logger.
Which again, if you're using underscore underscore name, that's going to be the name of your
module, whether that's like search dot util dot whatever.
And then the level name that it was admitted at, and a message.
Pretty straightforward.
Then we set the formatter.
Formatter gets attached to handlers again.
Logger dot info.
Look at my pretty log.
Well, just kidding.
There's no log there.
Is it because I have a bug?
Because I wrote this way too late at night?
Probably.
Or more likely because there was something I actually tricked you on earlier.
The truth is, the reason our first log wasn't admitted wasn't because there wasn't a handler
attached to it, but it's because Python's logging library by default sets loggers and
handlers to the warning level right out of the gate, and we admitted at the warning level.
So fun fact, you actually need to set the level for both the logger and your handlers.
So we'll go ahead and do that.
We'll set the logger level, and we're off to the races.
Let's look at this pretty log.
Man, that is so beautiful.
Now I know exactly when I had a pretty log.
I know exactly where it happened in the main.
I know what level it was at.
It was informational log.
So we've talked about a lot so far.
We've talked about loggers, handlers.
So let's do a top to bottom just real quick to make sure we're all talking about the
same thing.
So we have loggers.
Loggers emit a log at some level.
They also filter out logs at some level.
So if your logger is set to filter out warning logs and you send it an info, it's never
going to get to the handler.
Handlers receive logs and then send them to some specified output, whatever that may
be.
And then formatters attach to handlers, and they enrich the output.
So they add context.
And there's a bunch of other contexts.
That's not mentioned here.
It's in a Python logging library.
I guess it's like at a certain time in the presentation, it just decides it wants to
do that.
So these are all wonderful.
Wait a minute.
I'm getting there.
Logging.
Yes.
All right.
Here we go.
We're just going to scroll on.
Oh, yes.
Here we go.
So setting up logs from, you know, in each individual module is a pain.
So you can actually pre-create loggers ahead of time with a dictionary config or a YAML
config file because I know all of us just love creating YAML configs and having them
everywhere.
So with this, you can create as many logs as you want and specify them with dictionary
config.
One other really important thing to mention, and I probably should have hit it when I was
talking about loggers at the get-go, there's a specific reason why you can set it at the
logger level and at the handler level.
So handlers give you very fine-tune access over what you're looking at.
So where it's going, which output, you know.
So a lot of times people will specify certain levels for handlers and then they will use
their global debug level to set their loggers.
So say, for example, you're debugging an application locally, you're going to set that to debug,
of course, but when you push it to production, you don't want that.
So a lot of people will have, you know, a production logging config and a development
environment logging config.
So with that, there is actually one other slight challenge with loggers, and that is
they're blocking operations.
So like I said earlier, if you're a masochist and you like the SMTP log handler, you could
be in a real pinch.
So say, for example, I'm on your application, you have this nice web server, and all of
a sudden it hits a critical error, it sends a message to your SMTP server, and your SMTP
server is slow, it's chugging, so you're taking five to ten seconds for it to register
that and send a response.
Do you think I'm going to stay on your web page for five to ten seconds while it sends
an error log?
Heck, no, I'm closing out and I'm going to somewhere else, I don't know, amazon.com
to buy whatever I needed.
So we have to handle this.
We have to understand that, hey, this could potentially block, so how do we unblock our
applications?
Well, it's by making our applications simpler, obviously, and using multi-threading.
That was a joke, you can laugh.
So with this, we can actually import queues, and what happens is there's a queue handler
and a queue listener.
So the queue is the shared memory space that can be accessed both the handler and the listener.
You create the handler, the handler receives all the logs, and then distributes them to
the queue.
The queue listener starts up on its own independent thread, and it's going to listen to the log
queue, and then distribute it to any of the handlers that you specified it should.
So let's go through that end to end again.
We've got queue handlers, receive the logs, place them on a queue, the queue hands it
over to the queue listener, which then hands it on to your other loggers.
Now your application is unblocked.
It drops that queue, or that log on the queue, and then it's off to the races.
You can use SMTPlib if you really wanted to.
So let's talk about pulling this all together now, right?
So we have these logs, they sit on our local machines, and that's fine, but if you are
a large organization, you might have hundreds of servers.
Take a second to breathe.
You might have hundreds of servers, hundreds of network devices or whatever, and I'll give
a real example of when I could have used this.
So when I was a network automation engineer, we had a particular log that my boss found
on some of the servers, or router switches, et cetera, and I spent the next three hours
logging into each individual one.
We had thousands of network devices.
So I logged into enough of them, wrote down the logs, and then correlated, and I said,
oh, look, every Thursday and Saturday at the exact same time, this log happens.
One email later finds out security team is pen testing against us, and we don't need
to worry about it.
Again, three hours, just trying to correlate what log was happening where, when.
So this is exactly what you can avoid by using something like OpenSearch, ElasticSearch,
Loki to aggregate your logs.
And again, if you do want to follow along with this later, this just is a Docker compose
file that will let you spin up some sample containers with OpenSearch.
So we'll import logging in our OpenSearch library, create an OpenSearch client, and this is where
I'm going to break for just a moment and talk about custom handlers.
So we mentioned handlers are where you send your logs.
You can implement custom handlers, believe it or not.
All you need to do is, I was going to say, inherit from, there we go, that's probably
the right word, logging.handler.
Then you create and emit definition, and that needs to have self and record, and that will
send the record wherever you specify.
So in our case, we have, it's going to take, and it's going to format created time.
Also I did not implement the formatting library, because I wanted to send it as a dictionary
to OpenSearch just because that's what it works with.
You can also use something like FluentDit, FluentBit, or FluentDlogStash to parse out
your logs later, and we'll talk about that just briefly.
So we've got our created time.
We've created this wonderful record, OpenSearchClient.index, we'll send that log to OpenSearch.
There we go.
And then we'll set it up.
So we're going to create our logger named log.
We're going to set the logger's level to info so that we get the info records.
We're going to create the OpenSearchHandler and add logging.info, set that level, and
add our handler.
And we're off to the races.
Boom.
Well, that was kind of anticlimactic.
You can't actually see it going into OpenSearch.
But I promise you, it chugged along and it went into OpenSearch and, ha-za, let's go
into OpenSearch.
And this is actually OpenSearch dashboards.
So again, if you do this on your local machine, passwords admin, usernames admin.
Very secure.
We're actually looking to change that, but that is coming soon.
So we go here and we're going to go into stack management, hang with me for just a second.
So we created a custom index with this, and that index is named based off of the logger
that sent it.
So we've got logger name, which was log, and then with the date time so that we can roll
those off after a certain amount of days.
We're going to create an index pattern.
And we are going to say, we're going to say absolutely nothing because this is the problem
with doing things like, oh, just kidding, I just don't know how to use OpenSearch.
Here we go.
It's only my job.
Don't worry.
Boss, I swear, if you're watching this, no, I'm just kidding.
So there we go.
So we have these two indexes that have been created because I was testing yesterday and
today.
So logstar just says, hey, any index that looks like log with anything after it, group
them together.
Ask for a time field, which is our created field, and create index pattern.
There we go.
OpenSearch, auto-detects, all of these different files, types, et cetera.
You can actually specify mappings, and I actually really recommend that because different visualizations
require different types of mappings, but that is not what we're talking about today.
We're talking about Python logs, darn it.
So we're going to go over to Discover and go into our logs, and we are going to make
sure we're looking at today's logs.
Actually, well, let's look at this week.
Here we go.
And we have three hits.
There we are.
These are our logs.
Look ma, I'm logging.
And you could actually see the exact point in time when I switch from this is my log
to look ma, I'm logging.
So that was, yeah, I had 2.37 p.m., so anyhow, with this, you can actually go ahead and
then visualize spikes, peaks, valleys, when this is happening.
You can enrich it with device information.
So you can say, hey, when was this log sent?
Is there a particular device that's having a lot of issues?
So now instead of logging into all of your servers, you can go and bounce the correct
ones.
And if you saw Doton's presentation yesterday, you'll know you can use this for monitoring
anything, whether it's CI CD pipelines, Python logs, network logs, et cetera.
So let's see.
Look at that.
You're doing more logging now than 99% of the population.
So congratulations.
Clap your hands for yourselves.
So I'm going to talk real quick about just a very simple, common logging architecture
for capturing distributed logs and why you would want to do that.
So more often than not, you're probably actually going to want to log your, you don't want
to put your logs locally on the file system.
And the reason why is because your file system is not going to go down, and God forbid if
it goes down, there's no hope for that log getting out anyways.
Your service remotely could disconnect because whether you're doing an upgrade or something
along those lines, so it acts as a little bit of a caching mechanism.
And then you'll normally have it logged to a file, and then you could use something like
Fluent Bit or Beats, and those will ship your logs out.
And the wonderful thing about this architecture is, again, if OpenSearch was to go down because
you're doing an update, or if something was to happen critical with your Python app, it
can quickly write that log out, and you can also do enrichment.
So I talked about getting which server sent that log.
So Fluent D, Data Prepper, and Log Stash all can take and enrich your logs with the context
information that came with them.
So say, for example, it says, I received this log from X, Y, and Z server, 10, 20, 90,
32, 83, or something like that.
Then it can go and do a reverse DNS lookup and say, hey, who has that?
Which service is assigned to that?
And then it can add that information in and then push it into OpenSearch.
So now you've all of a sudden gone from having a log that says, hello world, to or got here,
please, please, do not.
And you can have it pushed into OpenSearch, know what service is causing the issues, and
visualize on dashboards.
With that, I'm finished.
Please scan, look at OpenSearch if you're curious.
It is open source, Apache 2 licensed.
All of our features are being developed in the open.
And with that, I want to ask it, does anyone have any questions?
Yeah.
Thank you.
Hello?
Okay.
How would you...
I'm mostly familiar with Sentry, and I'm very curious how would you compare this to that,
because as far as my friends told me, they're pretty different products, but they do similar
stuff.
Yeah.
So Sentry is more of an APM, isn't it?
Is that word familiar?
Okay.
So OpenSearch has some APM capabilities, which is, I don't remember the word for it, but
it's for app monitoring and specific to the application.
So this has some APM capabilities.
It might not go as deep as some of your auto configurations for other APM tools though,
but it can ingest APM logs.
So that's a good question.
Thank you.
You had two async questions from the chats.
The first one is, what about f-strings and logging?
Because I wrote this presentation in like a couple hours, and yeah.
So I'm trying to modernize, but again, it's old habits die hard, so I'm still using f-strings.
Please don't get on me.
It was the next one, sorry.
Yeah.
The question is, what about structured logging, and in particular, strike log?
I'm not actually familiar with strut log.
So I'm actually moving myself more towards using OpenTelemetry instead of logging, or
alongside logging, we'll say.
So OpenTelemetry gives you a trace, actually, which can tell you the full stack of what
happened during your application.
So everything down from which function was called to which load balancer sent the information
over.
So you get an end-to-end trace of what happened, which in my opinion, I think, is a little
bit more handy than just logs.
I think we have one more question in the middle.
Just a quick question from the discussion I'm having with the code worker.
So we're thinking about moving our logs to JSON format, because it's easy to understand
for non-Python people and searchable.
If we were to switch to OpenSearch, and I really liked the presentation, do you think
it's still feasible to make logs searchable in and of itself, or is OpenSearch that's
stable and usable and from your experience, there's no need to search on your logs?
Yeah.
No, that's a great question.
You do need to search your logs.
OpenSearch is a search engine at its core, and that is why it is as good as it is with
logs.
As for JSON versus other formats, I think there's no particular preference, but OpenSearch
is certainly stable.
We have 150 million downloads, so we are here to stay.
It's been adopted by a lot of companies such as Oracle, Ivan, Instacluster, Opster, Amazon
Web Services, of course, because I work there, and many others.
So I would say it is very stable, production-ready to use, and yeah, it's a really great way
to search your logs.
In fact, I have a lightning talk at 1655 in another room, so I think it's a Kubernetes
room.
So if you want to talk more about searching your logs, I'm going to be talking about search
relevance for logs.
So thank you.
Thank you, online people.
Thanks a lot.