Manage Your Ruby Logs Like a Pro | AppSignal Blog
Mai 17, às 00:00
14 min de leitura
Logs are essential to any application's development. Most Ruby logs are verbose and chunky, so digging for exactly what you need can be difficult. Even though they contain useful information, you might not get as much value as you should from logs if you don't know how to use them effectively.
In this article, we'll explore:
- The importance of logging
- How to use Ruby's inbuilt logging utilities —
- Log levels and their differences
- Customizing your logs using JSON
- Integrating a logging library, using Lograge as an example
Let's get started.
To follow along with this tutorial, you should have the following:
- A local installation of Ruby (we'll be using Ruby 3.2.0 for the tutorial).
- Some experience with Ruby.
Let's start by answering the question: "Why do we need to log, anyway?"
Why We Log
Before we dive in, it helps to know exactly why we log in the first place.
Logs provide us with information on what's happening inside our Ruby app. This is very useful for tasks like debugging errors and collecting critical app metrics. Log data depends on the type of app we have and the environment it is running on.
With that out of the way, let's introduce Ruby's inbuilt logging utilities.
Ruby’s Inbuilt Logging Utilities:
puts and Logger
Ruby comes with two logging utilities. One is
puts, a method provided
by the IO class (other methods include
The other inbuilt logging utility is the Logger class.
Let's explore each in more detail, starting with
puts method — which is actually syntactic sugar for
STDOUT.puts — is a way
of writing Ruby program messages to the
STDOUT output stream (usually a
puts will print out the given message string and add a
new line to the end of the output.
The example below shows a simple use case where we use
puts to output each line's length from a given text file:
Then we run the above Ruby script and pass in the text file as the argument:
And once the script has run, each line's length is written out to the console:
This simple example provides a glimpse into the world of the input/output (IO) streams at the heart of logging. Basically, anytime you run a Ruby program, you spawn the following IO streams:
STDIN- This stream accepts commands into your Ruby program — for example, a key pressed on a user's keyboard.
STDOUTwrites to an output — for example, a terminal displayed on a user's screen.
STDERRwrites to an output just like the
STDOUTone, but with a subtle difference that we'll cover in the next section.
Each of these is integral to logging and understanding how they work forms the basis of properly applying logs in Ruby apps.
The Limitations of
puts in Ruby
puts is a convenient and easy
logging method for simple Ruby programs, you
will very quickly need a proper logging library instead.
Here are a couple of its limitations:
- Automatic timestamps aren't included by default - Unless you manually customize
puts, you will not get any timestamps in your log output.
- Output is not categorized into appropriate log levels - We'll cover
this in more detail later, but the
putsmethod has no way to categorize output messages according to standard log levels.
These features are basic requirements for any logging solution. The fact that
they are missing from the
puts method by default (coupled with the manual
customization needed to have meaningful output messages) means that our
ability to properly log using the method is limited.
So let's now consider a more robust solution, the Ruby Logger class.
Logging with Ruby Logger
The Logger class is a
sophisticated logging utility that can create single or multiple
event logs from a Ruby application. Logger comes bundled in Ruby, so no gem installation is needed to get it up and running. You only need a
require statement somewhere at the top of your script:
After that, instantiate a new Logger object as below:
Note: The Logger class can accept a number of arguments, but the first one is almost always the log stream output, followed by other arguments like the retention policy (how long logs should be kept, how much the log files should grow in size before they are rotated, etc.)
You will get output similar to this:
From the printed log message, we have:
- The log level's shortened format - Indicated by the leading "D". In this
case, it shows that this is an
infolevel log entry.
- A timestamp - A full timestamp of the log entry.
- A process ID - The ID of the server process running the program.
- The log level type in full.
- A program name - An optional argument that can be added to a Logger entry (we'll see how in a later code example).
- The log message - The message output that will be printed in the log entry (also optional).
Each of these log entry components is important, and together they give context to app events that lead to the creation of log entries.
That said, one aspect of log entry that deserves more coverage is the log level. Let's take a look at it next.
Understanding Log Levels
A log level setting tells the Logger a log message's severity. The severity level depends upon the event that resulted in that log output.
There are six levels of severity, ranging from the least to the most severe:
And here's the output:
Log levels can help filter out app and server events that warrant your attention. To put this into context, consider these differences between log levels:
debug- This is the default log level and the most information-rich. When this log level is enabled, your log entries will include pretty much every request happening in your app. This is particularly useful for a debugging session.
info- A level above
debug. Just like the previous log level, enabling this level will result in some very information-rich log entries of your app's events.
infolog entries will tell you what's going on with your app — for instance, running processes and method calls.
warn- Any log entries at this level usually mean that your app encountered a problem, but nothing so severe that your app can't continue to function as expected (for example, you may have used an outdated method call for a gem or library.)
error- At this level, your app has encountered an error that stops it from proceeding with the action that caused the error. However, this does not stop other parts of the app from working as expected. For example, if your app references a recently moved file, an
errorlog entry will likely be generated.
fatal- Your app has encountered an error that stops it from working any further. This could be caused by anything from running out of memory on the production server or a crashed background job.
unknown- The actual cause of an error cannot be reliably traced.
Now that we have more information on log levels, let's see how to practically use them in a Ruby app.
Using Log Levels in a Ruby Application
In a development environment, the default log level is set to
As mentioned earlier, if your app's log level is set to
info), your output will include everything happening in the app.
You will have very information-rich log entries that make
for easier debugging in development.
However, in production, it isn't wise to use the
For starters, a production app will likely have too many processes, users, and method calls going on, so could very easily generate thousands (if not millions) of log entries. If these entries are being saved to log files on a production server, you can quickly run out of disk space.
Secondly, any attempt to sift for important
fatal entries is extremely inefficient in production simply because you will have too much
information to go through. So, you should only log entries
when something "important" happens or when your app malfunctions in such a way
that the user experience is affected.
It therefore makes
more sense to set the log level at something more manageable like the
level, for example.
Although setting the log level can reduce the amount of information in the log entries, it doesn't help format the entries in any way. To do that, you need to customize the log output.
Customizing Log Output in Ruby
Customizing log output involves changing the format of how log entries look and the information they contain when printed out.
By default, log entries printed to the terminal will be in black and white text. But for some logs, a little color can go a long way. You can colorize default log output using ANSI color codes.
In Ruby, this is possible using a gem like Colorize or Rainbow.
You can format the printed output from your Ruby
program using either of these gems. This example code uses
Rainbow to colorize some sample log
And here's the colorized log output:
The other way to format log entries goes beyond just customizing the look and feel. First, consider the simple Logger entry below:
It's good to note that you are not limited to using the log entry as is. It is entirely possible to customize a log message by tweaking the log entry components. Let's see how.
The first step is to call
Logger.new, and then add some log entries:
Which gives us this output:
It's also possible to customize a program name in the log entry, like so:
And here's the subsequent output:
By customizing the log entry's program name, you can add even more contextual information to your logs.
Now, let's look at how to customize all of the log entry's components all at once:
Here, we use the logger entry formatter
proc, which takes four arguments — severity, datetime, the program's name, and the message — to format the log
entry and output a string formatted in the way specified.
Great — but we can still do better! So far, everything we've done has produced log outputs in an unstructured format. But log entries can build up quickly in a production app that has thousands of users and millions of processes. Parsing unstructured logs can take up significant time and is very inefficient.
What if there was a way to quickly and efficiently search through log files? Enter JSON.
Logging into JSON
It's not the only format that has structured text — there are others like YAML and even TOML. Both YAML and TOML function best as configuration files, though, while JSON's structure makes it really good for logging.
Here's some code that outputs a JSON-formatted log entry:
At first glance, it's not easy to see why one would even want to do something like this. But with JSON formatted logs, it's possible to:
- Easily parse logs as they are now structured in a particular format (compared to the mass of unstructured entries characteristic of default logs). You can search for particular pieces of information using JSON keys tied to specific values.
- Forward these logs to a proper log processing tool that can process log outputs of almost any size.
So we've seen how useful Logger can be. But that does not mean the library is perfect.
Logger does have its imperfections, and we'll look at these next.
Limitations of Logger
If you use Logger to write output to log files frequently, one challenge you'll likely face is unreadable characters messing up your log files. These are caused by colorization ANSI codes not being parsed correctly in the log output files.
For example, consider this example code:
If you try to open the resulting log file, you'll notice it contains a bunch of unreadable characters in the log message section:
One way to fix this problem is by using a string regex to escape these
characters. For example, the
Colorize gem contains a convenient
Another limitation of Logger, especially for busy
production apps, is that default Logger entries can end up as
information-rich multi-line entries (even when the log level has been set to
something above the
info levels, like the
If you're in charge of such an app, debugging can easily become a messy affair as you have to go through a mass of unstructured text to get what you want.
Considering these limitations, let's seek a better logging solution — one that has the features we've been lacking in most of the solutions we've outlined so far.
Integrating a Third-Party Logging Library
You can choose from a number of third-party logging libraries, including Logging — based on Java's log4j library — and Lograge. Lograge is a feature-rich logging library meant to simplify the often messy and verbose Rails logs characteristic of the default application logger.
Also worth mentioning is httplog, a specialized logging library for tracking third-party API calls that might not be captured in regular logs.
For this article, we'll look at Lograge.
Lograge for Logging in Rails
According to Lograge's GitHub page, Lograge is an attempt at bringing sanity to Rails' unusable and unparsable log output.
Lograge replaces the default Rails logger and simplifies output to single lines, with all the important information included. The resulting output is much easier to read through than the Rails logger.
Getting Started with Lograge
To get started with Lograge, open up your project's Gemfile and add the following line:
bundle install to finalize the installation.
Logging in Rails: Using Lograge with AppSignal
With Lograge installed, you're halfway through setting up a capable logging solution for your app. The next obvious question is what you'll use to read and parse the logs. SSHing into your server to read through log tails is highly inefficient, so what to do?
Well, AppSignal has a new logging feature that is perfect for this.
To get started, install the latest version of the AppSignal for Ruby gem by adding it to your Gemfile:
bundle install. If you already have the gem installed in your project, just run
bundle update appsignal to get the latest version.
Next, add an initializer with the following information:
And that's it! You can now conveniently access your app's logs from AppSignal's logging dashboard:
In this article, we took a deep dive into the world of Ruby logs. We
puts, the Logger class, and how to customize log messages using
JSON. We finally explored logging using Lograge and AppSignal.
Obviously, logging in Ruby goes much deeper. Use this post as a stepping stone to learn more. You might also find our Making the Most of Your Logs in Rails and Audit Logging in Ruby and Rails posts useful.
Thanks for reading!
P.S. If you'd like to read Ruby Magic posts as soon as they get off the press, subscribe to our Ruby Magic newsletter and never miss a single post!
Hoje, às 15:34
Hoje, às 15:23
Hoje, às 15:01
Hoje, às 15:00
Hoje, às 14:29
Hoje, às 14:13
Hoje, às 14:00
Hoje, às 13:59
Hoje, às 13:51
AI | Techcrunch
Hoje, às 13:33