# LOG日志

# 日志级别

日志记录器(Logger)是日志处理的核心组件,V5采用标准的log4j日志记录标准。log4j具有5种正常级别(Level)。

1. static Level DEBUG : DEBUG Level指出细粒度信息事件对调试应用程序是非常有帮助的,一般认为比较重要的方法执行需要详细查看运行情况的则开启debug。

2. static Level INFO INFO level表明消息在粗粒度级别上突出强调应用程序的运行过程,只需要了解该方法是否运行的可以使用INFO

3. static Level WARN WARN level表明会出现潜在错误的情形。

4. static Level ERROR ERROR level指出虽然发生错误事件,但仍然不影响系统的继续运行。一般异常处理等情况都需要ERROR

5. static Level FATAL FATAL level指出每个严重的错误事件将会导致应用程序的退出。

———————————————— 版权声明:遵循CC 4.0 BY-SA版权协议,转载请附上原文出处链接及本声明。 原文链接:https://blog.csdn.net/m0_37179470/article/details/81238012

# 开发示例

记录Log日志前提,需要在当前类下注册Log全局变量,LOG日志记录代码如下:

public class ShowManagerImpl implements ShowManager {
    // 1、初始化logger
	private static final Log logger = CtpLogFactory.getLog(ShowManagerImpl.class);

	@Override
	public void deleteShowbarById(Long showbarInfoId) throws BusinessException, NotExistedException, NotAuthorizationException {
		ShowbarInfo showbarInfo = getShowbarByIdWithAuth(showbarInfoId);
		if (showbarInfo == null) {
            // 2、使用warn级别记录日志
			logger.warn("无权限或未找到对应主题:" + showbarInfoId);
			throw new NotExistedException();
		}
		if (hasShowbarAuth(ShowBarAuth.Delete, showbarInfo,isShowbarAdmin(AppContext.currentUserId(),showbarInfo.getAccountId()))) {
			int total = showbarAuthManager.deleteAll(showbarInfo.getId());
            // 3、使用info级别记录日志
			logger.info(String.format("%s完成%s条数据的批量删除!",showbarInfoId,total));
			try {
				eTagCacheManager.updateETagDate(ShowConstants.SHOWPOST_CHANGE_ETAG, ShowConstants.SHOWPOST_CHANGE_ETAG);
			} catch (Exception e) {
                // 4、使用error级别记录日志
				logger.error("更新Etag异常!",e);
			}
		} else {
			if(logger.isDebugEnabled()){
                // 5、使用debug级别记录日志
                logger.debug(AppContext.currentUserName() + "没有删除当前主题的权限:" + showbarInfoId);
			}
			throw new NotAuthorizationException();
		}
	}
}

# 反模式

下面这种Logger的定义将对开发人员带来灾难性后果:找不到源代码位置!

public class ReqUtil {
	// Bad code!!!
  	private static final org.apache.commons.logging.Log logger  = CtpLogFactory.getLog(Constants.class); 
}

上面代码的问题在于.getLog(Constants.class):当前类是ReqUtil,但是注册的LOG指向了Constants.class,将会导致Log记录日志的时候显示代码位置在Constants下,导致开发人员花费大量时间分析问题:

# Log 本来是ReqUtil抛出的,但是被记录在Constants下
19:54:56 [localhost-startStop-1] ERROR: Constants: - org.quartz.ObjectAlreadyExistsException

# LOG配置文件

log4j通过XML配置管理各模块日志粒度。

产品源码下,日志配置文件存放于:

/ctp-common/src/main/webapp/WEB-INF/cfgHome/base/log4j2_sys_starting.xml
/ctp-common/src/main/webapp/WEB-INF/cfgHome/base/log4j2_sys_running.xml
/ctp-common/src/main/webapp/WEB-INF/cfgHome/base/log4j2-properties.xml

生产系统下,日志存放于:

/seeyon/WEB-INF/cfgHome/base/log4j2_sys_starting.xml  -- 启动过程中日志
/seeyon/WEB-INF/cfgHome/base/log4j2_sys_running.xml   -- 启动后,运行过程中日志
/seeyon/WEB-INF/cfgHome/base/log4j2-properties.xml    -- Log日志全局配置

# 如何看懂日志配置?

如下图所示,只要日志名称为org.hibernate.SQLorg.hibernate.SQL.xxx都受此配置管控,此配置要求error级别才记录日志,并且日志存放位置是sql.log、error.log:

基于此规范就可以自行调整日志级别。

1721809816010.png

# 动态更新日志级别

线上系统如果需要调整日志输出级别,不用停服,可以使用系统管理员登录->系统监控->底部操作按钮->运行态改变日志级别。

如下图login默认是INFO,如果想输出DEBUG的login日志,则选中该行的DEBUG立刻生效。

运行态改动日志级别有效时间:如果系统不停服,随后日志都会以调整后的级别输出。系统重启之后,日志级别会被还原为初始状态。

1714303350724.png

1714303361515.png

# 最佳实践

# DEBUG日志

debug日志通常用于做数据跟踪使用,默认生产系统下debug日志不会被开启,需要调试跟踪的时候可以自行动态开启,通过日志观察代码数据走向。在编写代码的时候,记录尽量多的debug日志将有利于分析生产系统上的问题。

注意记录debug日志外层需要包装if(logger.isDebugEnabled())判断,什么原因自己想想。

if("zh".equals(lang)) {
 // 思考题:为何推荐在外层进行一次log.isDebugEnabled()判断?
 if(logger.isDebugEnabled()) {       
  logger.debug("zh lang:" + lang);
 }
 String country = locale.getCountry();
 if(Strings.isNotBlank(country)) {
  country = country.toLowerCase();
 }
 // 兼容华为平板 zh_HANS-CN
 if(country.endsWith("cn")) {
  loc = Locale.SIMPLIFIED_CHINESE;
  if(logger.isDebugEnabled()) {       
   logger.debug("SIMPLIFIED_CHINESE lang:" + country);
  }
 }else if(country.endsWith("tw")){
  loc = Locale.TRADITIONAL_CHINESE;
  if(logger.isDebugEnabled()) {       
   logger.debug("TRADITIONAL_CHINESE lang:" + country);
  }
 }
}

# INFO日志

info日志是比较常用的日志记录类型,如果你有些关键跟踪数据需要放入日志文件中就可以使用.info方法。比如方法执行耗时、一些日志动作记录等等。

long startTime = System.currentTimeMillis();
logger.info("Initializer [" + beanName + "] start:");
consoleLogger.info("Initializer [" + beanName + "] start:");
try {
    initializers.get(beanName).initialize();
} catch (Exception e) {
    logger.error(e.getMessage(), e);
}
long l = System.currentTimeMillis() - startTime;
if (initializers.get(beanName) instanceof AbstractSystemInitializer) {
    AbstractSystemInitializer aci = (AbstractSystemInitializer) initializers.get(beanName);
    logger.info(beanName + "," + aci.getSortOrder() + "," + l);
} else {
    logger.info(beanName + ",-," + l);
}

logger.info("Initializer [" + beanName + "] 耗时:" + l + " MS");

# WARN日志

warn级别的日志主要是提醒可能存在潜在问题。

if(!file.exists()){
  log.warn(path + " 分区不存在,请检查分区配置并确定对应磁盘位置有效!");
}

# ERROR日志

异常catch处理都推荐使用.error记录异常,而且一定是使用logger.error("",Throwable)的方法。

  try {
   
  } catch (Exception e) {
   // 注意error传两个参数
   logger.error("", e);
  }

# 反模式

# catch块未做处理

try {
	StringBuilder newMsg = new StringBuilder();
	Map<String, String> mapMsg = JSONUtil.parseJSONString(m, Map.class);
	mapMsg.forEach((key, value) -> {newMsg.append(value);});
	m = newMsg.toString();
} catch (BusinessException e) {
	// Bad Code 空代码
}

catch块未做处理会导致:异常被吞掉,增加问题的排查难度。正确的写法是:

try {
	
} catch (BusinessException e) {
	// 正确写法
	logger.error("",e);
}

# 滥用printStackTrace()

try {
	map = privilegeMenuManager.getByMember(user.getId(),user.getLoginAccount());
} catch (BusinessException e) {
	// Bad Code 错误的写法
	e.printStackTrace();
}

使用printStackTrace()会导致:日志仅仅输出到控制台而不会写入到LOG日志文件,当服务器重启后,控制台信息不会被保留,日志丢失! 正确的写法是:

try {
	
} catch (BusinessException e) {
	// 正确写法
	logger.error("",e);
}

# 用错log.error(e)

try {
	
} catch (BusinessException e) {
	// Bad Code 错误写法
	logger.error(e);
}

log.error(e)会导致:仅会将报错的异常类型打印出来,报错详细堆栈不会被输出。问题如下:

# 日志中仅有报错的类型 java.lang.NumberFormatException,但是没有详细堆栈,无法定位具体的报错信息点,排查问题困难。
11:00:41 [584907570157383680 - 10.6.3.71] [H-95] ERROR: CtripRestDataManagerImpl: - For input string: "" [code : 1182292592]
java.lang.NumberFormatException: For input string: ""
11:00:42 [584907570157383680 - 10.6.3.71] [H-95]  INFO: ColManagerImpl: - xxxx

正确的写法是logger.error("",e)用带两个参数的API:

try {
	
} catch (BusinessException e) {
	// 正确写法
	logger.error("",e);
}

# 严禁记录敏感数据

红线:千万不要把用户名、密码等敏感信息写入到日志文件中,这是禁忌!!!

// Bad Code 严禁向LOG文件写入敏感数据
logger.info("帐号:"+user.getLoginName()+",密码:"+user.getPassword()+",联系电话:"+user.getPhone());

# V8.1以上日志调整说明

1、为什么要对日志进行改造?

  • 减少冗余日志的输出,为日志瘦身
  • 减轻磁盘IO的负载

2、改造了哪些方面?

  • 限制了日志Message的长度:当超过1024个字节,就会被截断。

  • 限制了异常堆栈日志的输出次数:同一个方法的同一个位置抛出了同一个异常栈,堆栈信息一天只会打印一次。

  • 所有的堆栈信息都会额外打印到error.log文件中:error.log和其它日志文件一样,每天都会滚动生成;error.log的最大容量是500M,超过了也会发生滚动。

3、如何找到堆栈日志信息?

  • 每一个error级别的日志后面的生成一个code码,通这个code码在error.log里边查找,就可找到相应的堆栈信息。

4、由于输出的Message被截断了,我想看到全部的message该怎么办?

  • 修改seeyon\WEB-INF\cfgHome\base\log4j2-appenders.xml配置
	<!-- 比如 -->
    <CtpRollingFile name="ctp" fileName="${rootPath}/ctp.log"
                 filePattern="${rootPath}/${fileDate}/ctp.log.${fileDate}.%i.log">
        <Policies>
            <OnStartupTriggeringPolicy/>
            <SizeBasedTriggeringPolicy size="${fileSize}"/>
            <TimeBasedTriggeringPolicy/>
        </Policies>
        <PatternLayout charset="UTF-8" pattern="${patternLayout}"/>
        <DefaultRolloverStrategy max="${rollMax}" fileIndex="max"/>
    </CtpRollingFile>
    <!-- 修改为 -->
    <RollingFile name="ctp" fileName="${rootPath}/ctp.log"
                 filePattern="${rootPath}/${fileDate}/ctp.log.${fileDate}.%i.log">
        <Policies>
            <OnStartupTriggeringPolicy/>
            <SizeBasedTriggeringPolicy size="${fileSize}"/>
            <TimeBasedTriggeringPolicy/>
        </Policies>
        <PatternLayout charset="UTF-8" pattern="${patternLayout}"/>
        <DefaultRolloverStrategy max="${rollMax}" fileIndex="max"/>
    </RollingFile>
创建人:het
修改人:het