By Shangzuo
When writing code or implementing a third-party tool, always log at the interface layer.
If you need to provide a third-party tool externally, remember to mark the logging implementation and adaptation layers as optional in the dependencies, for example:
<dependency>
<groupId>ch.qos.logback</groupId>
<artifactId>logback-core</artifactId>
<version>${logback.version}</version>
<scope>runtime</scope>
<optional>true</optional>
</dependency>
A simple explanation:
• <scope>runtime</scope>
: The package of the runtime will be ignored during compilation (it is considered that the runtime environment already has the corresponding package);
• <optional>true</optional>
: Dependencies will not be passed, and Maven will not automatically install this package;
Don't print content like this that only contains a separator line: log.info("========== start ==========")
, because the next line of this log is likely to come from other asynchronous tasks. If SLS is used to collect or even come from another machine, this separator line will not work at all.
The correct way is to mark by keywords, such as log.info("FooBarProcessor start, request={}", request)
, and then quickly filter by keyword FooBarProcessor
, which is applicable to both grep and SLS.
In addition, Marker can be used to make log semantics clearer (please refer to section 4. Marker in part 3, but it is a little troublesome and depends on personal preferences.
For example, it calls its method directly without an empty sentence:
Object result = rpcResource.call();
// If the result is null, the NPE is thrown.
log.info("result.userId={}", result.getUserId());
This is an old topic, so we won't elaborate on it here.
Fastjson serialization actually depends on each getter in the class. If a getter throws an exception, the entire serialization will be blocked. However, some getter exceptions are not serious problems. In this case, you can use the SerializerFeature.IgnoreErrorGetter parameter to ignore the exception thrown in the getter:
public class Foo {
private Long userId;
@Deprecated
private Long accountId;
// The getter is thrown with an exception.
public Long getAccountId() {
throw new RuntimeException("Please use userId");
}
}
// In this way, the log will not be blocked by the exception thrown by getter.
log.info("foo={}", JSON.toJSONString(foo, SerializerFeature.IgnoreErrorGetter));
For example, there is a Result
wrapper class as follows (note the isError
method), which will output "error":false
when serialized by Fastjson. If you want to ignore getter methods like this that do not correspond to entity fields, you can append the SerializerFeature.IgnoreNonFieldGetter
parameters:
@Data
public class Result<T> {
private boolean success;
private T data;
public boolean isError() {
return !success;
}
}
// If the log is printed in this way, there will be no "error": false
log.info("result={}", JSON.toJSONString(result, SerializerFeature.IgnoreNonFieldGetter));
This parameter is very helpful for printing the Result wrapper class. If the "error": false
is printed out, then when you want to use the error
keyword query error, it will match a lot of containing errors
, but not the error of the invalid data.
As we mentioned in the section 3.1. info method of the part 3, exception parameters do not occupy character templates. If your number of parameters does not match, it is likely that the printed results do not match expectations.
For example:
Exception e = new RuntimeException("blahblahblah");
log.error("exception={}", e); // In this case, IDEA will give a warning: there are fewer parameters than placeholders.
At this time, since the e
matches the corresponding {}
position, Slf4j will try to convert the exception into a string and put it into the log template. The final sentence is equivalent to:
log.error("exception={}", e.toString());
In the end, you only get the exception=blahblahblah
and the stack is lost.
The correct approach is to ensure that the exception parameter does not occupy the character template:
// After using e.getMessage() to spell the log, there is a separate e for printing the stack at the same time.
log.error("exception={}", e.getMessage(), e);
The final output will be:
exception=blahblahblah
There will be stack information after line break
Sometimes, when we pass a very large POJO,
log.info("result={}", JSON.toJSONString(result))
When you print a log, the entire log becomes very long. Not only does it affect performance, but such a large result is not necessarily helpful for actual problem troubleshooting.
You can refer to the section 3.2 Format modifiers of the part 4 to limit the maximum length of the message and discard the excess part:
%.-2000message
In fact, Logback has native support, such as %exception{50}
, which can limit the printout to 50 levels. Additionally, Logback provides more control over the exception stack. For more details, please refer to Evaluators [1].
Some students want to stack the output on one line to ensure that the expected records are retained when performing multi-layer grep
through the pipeline |
.
In fact, this capability can be supported through Logback configuration. We can use the %replace
:
%replace(%exception){'[\r\n\t]+', ' '}%nopex
Briefly explain:
• %replace(p){r, t}
: Match the given p
with regular r
, and replace the hit with t
, so the above is to replace the [\r\n\t]
(i.e. line feed, carriage return, Tab) in the %exception
with (four spaces);
• %nopex
: If not, Logback will automatically append the %exception
to the end of the log, causing the exception stack to be typed twice (one with our own conversion to one line and one with the original line feed);
If you have requirements on the length of the exception stack, you can refer to section 3.2. Format modifiers and section 6. limiting the length of log output of the part 4, we can also do this:
%.-10000replace(%exception{50}){'[\r\n\t]+', ' '}%nopex
as shown in the following code:
• Print only the first 50 layers of the stack;
• After converting to a line, the maximum length is limited to 10000, and the part exceeding the length is discarded.
In the configuration of Logback, you can output the method name and line number by %method
and %line
. However, these two items depend on the current stack trace, and the cost of obtaining the stack trace is relatively high. The log will occupy a large number of CPUs, so in general, we recommend that you do not output these fields in the log.
If the other legal name has output requirements, you can directly hard-code it into the output string, for example:
log.info("queryUserInfo, request={}, result={}", request, result);
When we call the System.out.println
, the default output location is the console. Logback also provides a ch.qos.logback.core.ConsoleAppender
to output logs to the console.
However,
• Once the machine is online, no one will be watching the console, so logging to the console is pointless and a waste of machine resources.
• When debugging locally, it's better to add breakpoints or search log files, and there's generally no need to check the console output.
• When the main
function is used to run the test code, it's better to use System.out.println
and not involve the logging system.
Recently, I took over some projects and found that an additional custom utility class LogUtil
was used for logging. However, if you take a closer look at the code, you will find that it just implements the existing capabilities of Slf4j or Logback again, including but not limited to:
Please look at the following code first:
@Data
public class Foo {
private String bar;
}
Foo foo = new Foo();
foo.setBar("baz");
// Scenario 1 (note the colon in the first parameter)
log.info("foo:{}", foo);
// Output foo:Foo{bar=baz}
// Scenario 2 (note the equal sign in the first parameter)
log.info("foo={}", JSON.toJSONString(foo));
// Output foo={"bar":"baz"}
Have you noticed the difference between the two scenarios?
In Scenario 1, we use Lombok's @ToString
to convert strings, where key-value pairs are separated by an equal sign =
. Therefore, we suggest using a colon to quickly distinguish recorded information when viewing logs.
In contrast, in Scenario 2, we recommend using an equal sign because key-value pairs are separated by colons :
in the JSON format.
[1] https://logback.qos.ch/manual/layouts.html#Evaluators
[2] https://github.com/alibaba/p3c
[3] https://github.com/alibaba/p3c/blob/master/p3c-gitbook/异常日志/日志规约.md
Disclaimer: The views expressed herein are for reference only and don't necessarily represent the official views of Alibaba Cloud.
Four Steps to Security Defense: Detection Plan (Multi-Product Integration)
991 posts | 240 followers
FollowAlibaba Cloud Community - November 9, 2021
Alibaba Cloud Community - January 25, 2024
Alibaba Cloud Community - June 14, 2024
Alibaba Cloud Community - July 31, 2024
Alibaba Cloud Community - August 5, 2024
Alibaba Cloud Community - August 5, 2024
991 posts | 240 followers
FollowFollow our step-by-step best practices guides to build your own business case.
Learn MoreExplore Web Hosting solutions that can power your personal website or empower your online business.
Learn MoreA low-code development platform to make work easier
Learn MoreExplore how our Web Hosting solutions help small and medium sized companies power their websites and online businesses.
Learn MoreMore Posts by Alibaba Cloud Community