1.log4j fire
By the end of 2021, log4j was completely popular. Log4j, as one of the most important components in the whole java ecosystem, was exposed to high-risk vulnerabilities. Because of the vulnerabilities of log4j, countless small partners immediately spent all night fixing bug s. Today, let's not talk about the vulnerability of log4j, but about the logging module in python.
2. Basic structure of logging
logging mainly contains four basic components
Logger:
class Logger(Filterer):
"""
Instances of the Logger class represent a single logging channel. A
"logging channel" indicates an area of an application. Exactly how an
"area" is defined is up to the application developer. Since an
application can have any number of areas, logging channels are identified
by a unique string. Application areas can be nested (e.g. an area
of "input processing" might include sub-areas "read CSV files", "read
XLS files" and "read Gnumeric files"). To cater for this natural nesting,
channel names are organized into a namespace hierarchy where levels are
separated by periods, much like the Java or Python package namespace. So
in the instance given above, channel names might be "input" for the upper
level, and "input.csv", "input.xls" and "input.gnu" for the sub-levels.
There is no arbitrary limit to the depth of nesting.
"""
Logger is an "Application", that is, the API interface directly used in the Application. We can see the usage of logger in the following examples.
Handler
class Handler(Filterer):
"""
Handler instances dispatch logging events to specific destinations.
The base handler class. Acts as a placeholder which defines the Handler
interface. Handlers can optionally use Formatter instances to format
records as desired. By default, no formatter is specified; in this case,
the 'raw' message as determined by record.message is logged.
"""
The Handler is responsible for distributing the logs to the specified destination.
Filter:
class Filter(object):
"""
Filter instances are used to perform arbitrary filtering of LogRecords.
Loggers and Handlers can optionally use Filter instances to filter
records as desired. The base filter class only allows events which are
below a certain point in the logger hierarchy. For example, a filter
initialized with "A.B" will allow events logged by loggers "A.B",
"A.B.C", "A.B.C.D", "A.B.D" etc. but not "A.BB", "B.A.B" etc. If
initialized with the empty string, all events are passed.
"""
Filter can filter any log, and decide which logs to keep output and which logs not to display.
Formatter:
class Formatter(object):
"""
Formatter instances are used to convert a LogRecord to text.
Formatters need to know how a LogRecord is constructed. They are
responsible for converting a LogRecord to (usually) a string which can
be interpreted by either a human or an external system. The base Formatter
allows a formatting string to be specified. If none is supplied, the
the style-dependent default value, "%(message)s", "{message}", or
"${message}", is used.
The Formatter can be initialized with a format string which makes use of
knowledge of the LogRecord attributes - e.g. the default value mentioned
above makes use of the fact that the user's message and arguments are pre-
formatted into a LogRecord's message attribute. Currently, the useful
attributes in a LogRecord are described by:
%(name)s Name of the logger (logging channel)
%(levelno)s Numeric logging level for the message (DEBUG, INFO,
WARNING, ERROR, CRITICAL)
%(levelname)s Text logging level for the message ("DEBUG", "INFO",
"WARNING", "ERROR", "CRITICAL")
%(pathname)s Full pathname of the source file where the logging
call was issued (if available)
%(filename)s Filename portion of pathname
%(module)s Module (name portion of filename)
%(lineno)d Source line number where the logging call was issued
(if available)
%(funcName)s Function name
%(created)f Time when the LogRecord was created (time.time()
return value)
%(asctime)s Textual time when the LogRecord was created
%(msecs)d Millisecond portion of the creation time
%(relativeCreated)d Time in milliseconds when the LogRecord was created,
relative to the time the logging module was loaded
(typically at application startup time)
%(thread)d Thread ID (if available)
%(threadName)s Thread name (if available)
%(process)d Process ID (if available)
%(message)s The result of record.getMessage(), computed just as
the record is emitted
"""
The Formatter determines the output format of the log.
3. Project practice
project-xxx logs Application.py config.py logger.conf ...
The above is an example of an online project, application Py is the application, config Py is the entry API of logger Conf is the specific configuration of logging.
Where config Py is
import logging.config
logging.config.fileConfig("logger.conf")
console_logger = logging.getLogger()
logger = logging.getLogger(name="rotatingFileLogger")
The above code first defines the address of the configuration file, that is, the logger under the current peer directory Conf file.
At the same time, two types of logs are defined:
console_logger and logger. The specific configurations of these two logs are shown in logger Conf file.
4. Detailed explanation of configuration information
Look at logger Contents of conf
[loggers]
keys=root,rotatingFileLogger
[handlers]
keys=consoleHandler,rotatingFileHandler
[formatters]
keys=simpleFormatter
[logger_root]
level=INFO
handlers=consoleHandler
[logger_rotatingFileLogger]
level=INFO
handlers=consoleHandler,rotatingFileHandler
qualname=rotatingFileLogger
propagate=0
[handler_consoleHandler]
class=StreamHandler
level=INFO
formatter=simpleFormatter
args=(sys.stdout,)
[handler_rotatingFileHandler]
class=handlers.RotatingFileHandler
level=INFO
formatter=simpleFormatter
args=("logs/rotating_logging.log", "a", 1*1024*1024, 5)
[formatter_simpleFormatter]
format=%(asctime)s - %(module)s - %(thread)d - %(levelname)s : %(message)s
datefmt=%Y-%m-%d %H:%M:%S
Focus on the content of the above configuration file
1.loggers: the configured logger information must contain a logger called root. When we use the parameterless function logging When getlogger (), root is returned by default. In our example above, console_logger = logging.getLogger() returns the root logger.
2.handlers: specify which handlers are required. In the above example, we have specified two, consolehandler and rotatingfilehandler, which will be configured for different handlers later.
3.Filters: Filter is not configured in the instance.
4.formatters: set the log format. In the example, it is simple formatter.
The above four items can be considered as global configuration, and the following logger_xxx, handler_xxx, formatter_xxx is a detailed configuration for the declaration in the global configuration.
With handler_ Take rotatingfilehandler as an example
[handler_rotatingFileHandler]
class=handlers.RotatingFileHandler
level=INFO
formatter=simpleFormatter
args=("logs/rotating_logging.log", "a", 1*1024*1024, 5)
First, we use handlers The rotatingfilehandler class performs logical processing.
At the same time, the level of logging is INFO and the format is simpleFormatter.
The order and meaning of args:
filename: file name, indicating where the file appears
when: time, in what time unit
Interval: time interval
backupCount: the number of backups, and the maximum number of logs saved
Encoding: encoding method
Delay: delay writing
utc: standard time.
In the above example, the log is rotated in the logs folder_ logging. Log, the generation method is append, the time interval is 1024*1024s, and the maximum number of files is 5.
5. Example test
First, let's do a simple test
Application.py
def log_demo():
from config import logger
import time
curtime = time.strftime("%Y%m%d %H:%M:%S", time.localtime())
logger.info("code begin run at: %s", curtime)
print(curtime)
time.sleep(2)
endtime = time.strftime("%Y%m%d %H:%M:%S", time.localtime())
logger.info("code end run at: %s", endtime)
log_demo()
After running the above code, the original logs folder is empty, and now the file rotating will be generated_ logging. Log, the file contents are as follows:
2022-01-03 21:05:30 - Application- 4492389824 - INFO : code begin run at: 20220103 21:05:30 2022-01-03 21:05:32 - Application- 4492389824 - INFO : code end run at: 20220103 21:05:32
If we record exception information
def log_demo():
from config import logger
import time
curtime = time.strftime("%Y%m%d %H:%M:%S", time.localtime())
logger.info("code begin run at: %s", curtime)
try:
result = 2 / 0
except ZeroDivisionError as ex:
logger.error("there is some exception: %s", repr(ex))
endtime = time.strftime("%Y%m%d %H:%M:%S", time.localtime())
logger.info("ccode end run at: %s", endtime)
log_demo()
The log is:
2022-01-03 21:13:01 - Application - 4472901056 - INFO : code begin run at: 20220103 21:13:01
2022-01-03 21:13:01 - Application - 4472901056 - ERROR : there is some exception: ZeroDivisionError('division by zero')
2022-01-03 21:13:01 - Application - 4472901056 - INFO : ccode end run at: 20220103 21:13:01
Although the above code has our own output exception log, there is no stack information of error code, and the stack information of error code is very important in daily debugging, operation and maintenance.
To achieve the goal is very simple, just put the logger Error becomes logger Exception, and the log output is:
2022-01-03 21:14:41 - Student - 4573265344 - INFO : code begin run at: 20220103 21:14:41
2022-01-03 21:14:41 - Student - 4573265344 - ERROR : there is some exception: ZeroDivisionError('division by zero')
Traceback (most recent call last):
File "/xxx/xxx/Application.py", line 189, in log_demo
result = 2 / 0
ZeroDivisionError: division by zero
2022-01-03 21:14:41 - Student - 4573265344 - INFO : ccode end run at: 20220103 21:14:41
Through the above log output, it is easy to locate the error code stack!