Software quality. Introduction to logging
Theory
§1. Introduction
Imagine you are investigating a robbery and are trying to figure out what happened. You have witnesses whose testimonies are very vague, but there is no evidence. It will be very difficult to unravel such a mess. If only there were recordings from surveillance cameras to restore the chronology of the events...
So now, let's say you are investigating a bug, but what 'surveillance cameras' do you have in that case? Obviously, we need records of everything that happened with the program before the incident. Also, it would be nice to know during which operation it happened. All such records are usually kept in a log. So what is a log?
§2. Log
Logging refers to the act of recording during the execution of an application. Logs are records that give us information about the events in a software application. This record could be a message that is enough to understand the event that happened, it may include a timestamp, a description, and a severity level. These events could be user-generated or system-generated. We use either a log file or, sometimes, the standard output to make these records.
We need logging for several reasons. Firstly, it will save a lot of time when we are troubleshooting our application at a later stage. If the program, for example, broke or something went wrong in it, then we can find the exact moment at which the error occurred in the log. This makes the debugging process a lot easier. Secondly, it is also possible to trace who used the program with the log. If it is, say, a site, one can find out who sent the requests. Also, logs help to monitor the operation of a particular system, which makes verification and reporting a whole lot easier. This way, we are always aware of how our programs work and how well they perform.
There are several things to consider when logging: when do we log? what do we log? how do we log? Let’s find out the answers to these questions.
§3. When, What, and How
As we've mentioned above, there are several common reasons to generate logs:
- troubleshooting
- auditing
- profiling
- statistics
What we log usually depends on the application. In any case, we should be able to understand the execution path of a program through the logs. It is important to avoid excessive logging as it is costly. For example, there's no need to log the start and the end of every method, and their arguments, since they are easy to track. Logs are meant to cover server issues, database issues, networking issues, errors from unanticipated user inputs, states of dynamically created objects, and configuration values.
Providing contextual information in your log messages is very important as well. Often, the success or failure of a program depends on the user inputs. So, you need to put them in your log messages if necessary. For example, when authenticating a user, log the username that is inputted. Context is also important when your program runs in a concurrent environment. In such a case the thread name can be added to the log message.
§4. Log levels
We said earlier that a lot of important information can be added to the log file. But what kind of information is it? There are different types that correspond to the accepted logging levels: Debug, Info, Warn, Error, and Fatal (from the least critical level to the most critical one).
Let’s see what those log levels are for.
Debug logs are used to diagnose applications. Debugging messages inform us about what the program is doing at a certain step and what it gets as a result of these actions. For example, a message can contain information about the output of some function, so that we can see if it should be fixed.
Info is used to log important information about an application. It is used to log service start, service stop, configurations, assumptions. For example, the information about the user who has just registered on the website.
Warn logs are considered to be the first level of application failure. They are usually applied to log repeated attempts to access a resource, missing secondary data, or switching from a primary server to a backup server. For instance, there can be a message about a possible disconnection with the server. However, it does not affect the user at this point.
Error log level is used for more critical problems. These kinds of issues usually affect the result of the operation but do not terminate the program. Errors are considered to be the second level of application failures. For example, there can be a message that a user could not log in because the database was temporarily unavailable.
Fatal is the third level of application failures. It is used to indicate a much more serious error that causes the termination of the program. Such a message may say that the program totally failed and depending on the time and conditions of this failure the developers can find out how to fix the problem.
Great, now we know what bugs are usually written into the log file. Now we need to display the log. But what should be displayed? In order to make the log readable and understandable, there is a special recording format. Let's find out more about it below.
§5. Log Format
To investigate a bug, we need to know when it happened, how serious it was, and who came across it. Thus, the log format generally looks like this:
[date time][log level][message]
So, it starts with the date and time of when the error occurred. Then comes the log level, and the last thing is the message with the explanation of what exactly happened. More specifically, if we, for example, want to monitor who registers on our site, we need the corresponding logs with Info log level. Then every time a user sends data to the site, we will log a message about this event. For example, on February 2, 2021, a user with the nickname 'demo' registered on the site at 3 pm. Then the log will look like this:
[2021-02-02 15:00:00] [INFO] User 'demo' has registered
And if some user named 'alex98' cannot log in because of some technical issues, we will receive an Error message:
[2021-02-02 01:00:10] [ERROR] User 'alex98' cannot log in because the database is temporarily unavailable
Thus, we will know that user 'alex98' failed to log in due to our database being temporarily unavailable. We have localized the problem and know exactly what we need to do: check the database and fix it.
There is also a more complex version of this format called The Common Log Format.
§6. Conclusion
So, we've figured out what logs are and what they are for. We've also learned what types of logs there are and how we can issue a log message. Now you can start using logs to monitor the operation of your system at any given time.
You can also view Lesson on hyperskill.org.
Practical tasks and answers
Tasks and answer options are given. The correct option is highlighted in blue color.
№1. Unexpected results
Question: Which log level would you use to write a message stating that there was a mistake in the program, and thus the result does not coincide with the expected?
Select one option from the list:
- Debug
- Error ✔
- Fatal
- Info
Explanation. The appropriate log level to write a message stating that there was a mistake in the program and the result does not coincide with the expected is Error.
№2. Adding debug logs for a math operation script
Question: Fill the blanks in the following Python script to add logging for debugging purposes. The script aims to perform a simple math operation (division), but it is failing due to an unhandled exception. Your task is to fill the blanks to complete the logging configuration.
Fill in the gaps with the relevant code elements:
import
def example_function():
logging.basicConfig(level=logging.INFO)
('This is an example info log')
try:
print(5/0)
except Exception as e:
('Exception occurred', exc_info=True)
example_function()
Variants: logging, logging.info, logging.error.
Solution:
Here is the completed Python script with logging added:
import logging
def example_function():
logging.basicConfig(level=logging.INFO)
logging.info('This is an example info log')
try:
print(5/0)
except Exception as e:
logging.error('Exception occurred', exc_info=True)
example_function()
Explanation. In this updated script, we have imported the logging module. We then configure the logging level to INFO using basicConfig. We then add an info log message to indicate that the function is running. Inside the try block, we attempt to perform a math operation that will raise an exception. If an exception is raised, we log an error message with exc_info=True, which will include the stack trace in the log output.
№3. Log format
Question: What are the basic things to be mentioned in a log according to the examples from the topic?
Select one or more options from the list:
- date ✔
- log level ✔
- time ✔
- developer's facebook status
- user's phone number
- log message ✔
Explanation. It is important to include a clear and concise log message that describes what happened, along with the date and time of the event and the log level to indicate the severity of the event. Developer's Facebook status or user's phone number are not relevant information to be included in a log.
№4. Common reasons
Question: What are the common reasons for generating a log? Choose several answers.
Select one or more options from the list:
- downloading a website
- finding a problem ✔
- ordering pizza online
- statistics ✔
Explanation. Logs are often used to troubleshoot issues or identify bugs in software. They can also be used to gather statistics or other information about how a system is performing. Downloading a website or ordering pizza online are not common reasons for generating a log.
№5. Termination of the program
Question: Suppose your program encountered a problem that caused it to stop working completely. What log level can you use to log this issue?
Select one option from the list:
- Debug
- Info
- Warn
- Error
- Fatal ✔
Explanation. The appropriate log level to use when a program encounters an issue that causes it to stop working completely is Fatal. The Fatal log level indicates that the application has encountered a severe error and is unable to continue running. This log level should be used when the application is in an unrecoverable state and must be terminated immediately.
№6. Connecting to a database server
Question: Your application is going to connect to a database server. You want to log configuration data of the database server. Which log level is more appropriate for that?
Select one option from the list
- Debug
- Info ✔
- Warn
- Error
- Fatal
Explanation. The appropriate log level to use when logging configuration data of a database server is Info. The Info log level is used to provide information about the application's state and behavior, and is appropriate for logging details such as configuration data. This log level indicates that the application is functioning normally and provides useful information for troubleshooting and debugging.
№7. Not a good practice
Question: Which of the following is NOT a good practice for logging?
Select one option from the list
- Doing structural logging
- Do contextual logging
- Logging every function call ✔
- Use logging instance for each class
Explanation. Logging every function call is NOT a good practice for logging. While logging can be a useful tool for troubleshooting and debugging, it is important to use it judiciously to avoid cluttering the log with unnecessary information. Logging every function call can quickly lead to an overwhelming amount of log data, making it difficult to identify relevant information. Instead, it is better to focus on doing structural logging and contextual logging, and to use a logging instance for each class to organize log messages and make them easier to manage.
№8. Creating a simple logging functionality
Question: Suppose you've been tasked with creating a simple logging functionality in a Python application. Your alloted task includes setting the log level to INFO and logging a message 'Intro to logging in Python'. Fill the blanks in the provided code to complete this function:
Fill in the gaps with the relevant code elements:
import
def intro_to_logging():
logging. (level=logging.INFO)
logging. ("Intro to logging in Python")
intro_to_logging()
Variants: info, logging, basicConfig.
Solution:
Here is the completed Python script with logging added:
import logging
def intro_to_logging():
logging.basicConfig(level=logging.INFO)
logging.info("Intro to logging in Python")
intro_to_logging()
Explanation. In this updated script, we have imported the logging module. We then configure the logging level to INFO using basicConfig. We then add an info log message to indicate that the function is running. The log message "Intro to logging in Python" will be displayed in the console output.
№9. The order of logging based on severity
Question: What is the ORDER of Log Level based on Severity? Reorder the following log levels from least severity (top) to highest severity (bottom).
Put the items in the correct order:
- Debug (least severe)
- Info
- Warn
- Error
- Fatal (most severe)
