Mule ESB Http项目转换为Tomcat项目(9) 日志问题处理

最新推荐文章于 2018-06-22 11:17:54 发布

weixin_33785108

最新推荐文章于 2018-06-22 11:17:54 发布

阅读量312

点赞数

文章标签： java json 人工智能

原文链接：https://my.oschina.net/u/237688/blog/701740

版权

2019独角兽企业重金招聘Python工程师标准>>>

Mule ESB项目的日志输出有两种方式，可以在流程中添加Logger组件输出日志，也可以在自定义的代码中添加日志输出。Mule ESB日志使用Log4j2库进行输出，Mule ESB 企业版使用的log4j2版本是2.1。

我们在ESB项目中拖入一个Logger控件，输出经过Transformer转化后的Json 报文。

这里Logger控件里的Message内容为#[message.payloadAs(java.lang.String)]，使用的是MEL(Mule Expression Language)，等效于message.getPayloadAsString()

拖拽Logger控件后，在项目的src/main/resources目录下生成了log4j2.xml文件，用于配置Log4j2的日志输出

log4j2.xml的内容如下:

<?xml version="1.0" encoding="utf-8"?>
<Configuration>
    <Appenders>
        <RollingFile name="file" fileName="${sys:mule.home}${sys:file.separator}logs${sys:file.separator}testproject.log" 
                 filePattern="${sys:mule.home}${sys:file.separator}logs${sys:file.separator}testproject-%i.log">
            <PatternLayout pattern="%d [%t] %-5p %c - %m%n" />
            <SizeBasedTriggeringPolicy size="10 MB" />
            <DefaultRolloverStrategy max="10"/>
        </RollingFile>
    </Appenders>
    <Loggers>
        <!-- CXF is used heavily by Mule for web services -->
        <AsyncLogger name="org.apache.cxf" level="WARN"/>

        <!-- Apache Commons tend to make a lot of noise which can clutter the log-->
        <AsyncLogger name="org.apache" level="WARN"/>

        <!-- Reduce startup noise -->
        <AsyncLogger name="org.springframework.beans.factory" level="WARN"/>

        <!-- Mule classes -->
        <AsyncLogger name="org.mule" level="INFO"/>
        <AsyncLogger name="com.mulesoft" level="INFO"/>

        <!-- Reduce DM verbosity -->
        <AsyncLogger name="org.jetel" level="WARN"/>
        <AsyncLogger name="Tracking" level="WARN"/>
        
        <AsyncRoot level="INFO">
            <AppenderRef ref="file" />
        </AsyncRoot>
    </Loggers>
</Configuration>

可以看出Mule ESB的日志输出采用的是异步方式。

以Debug方式启动ESB项目, 调用ESB接口，控制台输出了Json报文日志

INFO  2016-06-29 15:15:33,335 [[testproject].HTTP_Listener_Configuration.worker.01] org.mule.api.processor.LoggerMessageProcessor: {"students":[{"name":"张三","id":"197","class":"1年1班"},{"name":"李四","id":"198","class":"1年2班"},{"name":"赵五","id":"199","class":"1年3班"}]}

同时查看项目对应的日志文件(位置在Anypoint Studio的workspace目录的.mule/logs子目录下)

打开testproject.log文件，可以看到上述的日志信息也写入了日志文件。

从日志信息可以看出，Logger控件的日志是在org.mule.api.processor.LoggerMessageProcessor类中输出的，具体是在log(MuleEvent event)方法中输出的

protected void log(MuleEvent event) 
{
    if (event == null) 
    {
        logWithLevel(null);
    } 
    else 
    {
        if (StringUtils.isEmpty(message)) 
        {
            logWithLevel(event.getMessage());
        } else 
        {
            LogLevel logLevel = LogLevel.valueOf(level);
            if (LogLevel.valueOf(level).isEnabled(logger)) 
            {
                logLevel.log(logger, expressionManager.parse(message, event));
            }
        }
    }
}

public enum LogLevel
{
   INFO
   {
      @Override
      public void log(Log logger, Object object) 
      {
         logger.info(object);
      }

而记录日志的logger对象是在ESB项目启动，加载Mule容器时调用LoggerMessageProcessor类的initLogger方法构造的,构造Logger的大致流程是这样的：

这里的流程图只描绘了LoggerMessageProcessor的logger对象构建的几个主要类和方法，可以看出Logger控件的日志输出与Mule容器的启动和初始化密切相关。如果ESB项目迁移到Web项目，则实际运行环境变成了Tomcat环境，加载类变成了org.mule.config.builders.MuleXmlBuilderContextListener，而我们查看MuleXmlBuilderContextListener类的初始化方法

public void initialize(ServletContext context)
    {
        String config = context.getInitParameter(INIT_PARAMETER_MULE_CONFIG);
        ....................
        try
        {
            muleContext = createMuleContext(config, context);
            context.setAttribute(MuleProperties.MULE_CONTEXT_PROPERTY, muleContext);
            muleContext.start();
        }
        ....................

可以看出这里没有对MuleContainer的初始化方法调用，Logger Component使用的Logger对象没有被初始化，因此在Web项目里使用Logger组件将不会输出日志，无论是控制台还是文件，我们需要自定义Logger类输出日志。

我们在用于转换的Transformer类中添加Log4j2的Logger对象

private static Logger logger = LogManager.getLogger(CustomJsonTransformer.class);

再在json报文转换结束后使用这个logger对象输出转换后的json报文。

 try {
	            String jsonMessage = message.getPayloadAsString();	
	            //添加信息
	            JSONObject jsonMap = updateStudentInfos(jsonMessage);
	            transformJsonStr = jsonMap.toJSONString();
	            if(!Strings.isBlank(transformJsonStr))
	            {
	            	logger.info("The json message after transformation is:" + transformJsonStr);
	            }
	        } catch (Exception e) {
	        		e.printStackTrace();
	        }

因为我们使用的是Log4j2在Tomcat容器中进行日志输出，根据查阅的资料，我们需要引入log4j-web这个jar包，因为Mule默认使用的log4j-core版本是2.1，我们引入的log4j-web也使用2.1版本，将这个jar文件拷贝到mule_libs/opt目录下。

此外我们需要修改log4j2.xml文件，ESB项目创建的log4j2.xml的日志文件输出到mule的workspace目录下，我们将其修改为输出到tomcat的logs目录下，修改后的log4j2.xml文件

<?xml version="1.0" encoding="utf-8"?>
<Configuration>
	<properties>
    	<property name="logPath">${sys:catalina.home}/logs/</property>
  	</properties>

 	 <Appenders>
 	 	<Console name="Console" target="SYSTEM_OUT">
            <PatternLayout pattern="%d [%t] %-5p %c - %m%n"/>
        </Console>
        <!-- <RollingFile name="file" fileName="${logPath}/testproject.log"
            filePattern="${logPath}/testproject-%d{MM-dd-yyyy}-%i.log"> -->
        <RollingFile name="file" fileName="${logPath}/testproject.log" 
                 filePattern="${logPath}/testproject-%i.log" append="true" immediateFlush="true">
            <PatternLayout pattern="%d [%t] %-5p %c - %m%n" />
            <!-- <Policies>
                <TimeBasedTriggeringPolicy />
                <SizeBasedTriggeringPolicy size="10 MB"/>
            </Policies> -->
            <SizeBasedTriggeringPolicy size="10 MB" />
            <DefaultRolloverStrategy max="10"/>
        </RollingFile>
    </Appenders>
    <Loggers>
    
    	 <!-- Apache Commons tend to make a lot of noise which can clutter the log-->
        <AsyncLogger name="org.apache" level="WARN"/>
    
    	<!-- Reduce startup noise -->
        <AsyncLogger name="org.springframework.beans.factory" level="WARN"/>
        
        <!-- Mule classes -->
        <AsyncLogger name="org.mule" level="INFO"/>
        <AsyncLogger name="com.mulesoft" level="INFO"/>        
        <Logger name="com.mule.spring" level="INFO"/>
        
        <Root level="INFO">
        	<AppenderRef ref="Console"/>
            <AppenderRef ref="file" />
        </Root>
    </Loggers>   
</Configuration>

这里的${sys:catalina.home}指的是当前运行的tomcat根目录，另外基于我们自定义的代码包路径，我们添加了一个Logger。

需要注意的是在web项目中，log4j2.xml文件必须放置在WEB-INF根目录下，和web.xml同一级目录，为此我们需要将log4j2.xml文件移动到src/main/app目录下。

修改完成后，我们部署重新生成的web项目到tomcat环境，调用接口。

可以看到Tomcat的运行时窗口输出了日志信息:

同时在tomcat的logs目录下生成了testproject.log文件，

testproject.log文件中输出了控制台窗口输出的json报文日志

使用自定义Logger，我们可以将需要的程序运行信息输出到控制台和日志文件，对于自定义代码中抛出的异常，我们可以直接输出日志，但如果是流程运行过程中抛出的异常信息，该如何捕捉异常信息，并将其输出呢？

我们需要使用Mule的Catch Exception Strategy控件。

我们在流程文件中加入Catch Exception Strategy控件，放置在Error Handling下

我们在这个控件中拖入两个控件，Set Payload和Logger控件，

<catch-exception-strategy doc:name="Catch Exception Strategy">
     <set-payload value="#[exception.cause.message]" encoding="UTF-8" mimeType="text/plain" doc:name="Set Payload"/>
     <logger message="#[exception.cause.message]" level="ERROR" doc:name="Logger"/>
</catch-exception-strategy>

Set Payload控件将异常信息设置为Mule Message的Payload，返回给调用端(否则Mule Message的Payload仍然是请求的Payload)，logger控件则将异常信息作为日志输出。

#[message.cause.exception]同样是MEL表达式，表示异常的Root Cause信息。

添加完异常处理控件后，我们修改自定义的Transformer类的transformMessage方法，将原先返回的转换好的json报文替换为null。这样当运行到Data Weaver数据映射时，流程将会抛出异常，我们可以查看异常信息是如何被Catch Exception Strategy控件捕捉并处理的。

调用ESB接口后，系统输出的异常日志为：

ERROR 2016-06-29 18:20:30,035 [[testproject].HTTP_Listener_Configuration.worker.01] org.mule.api.processor.LoggerMessageProcessor: The object transformed is of type: 
"SimpleDataType{type=org.mule.transport.NullPayload, mimeType='*/*', encoding='null'}", 
but the expected return type is "SimpleDataType{type=java.lang.String, mimeType='application/json', encoding='UTF-8'}".

调用端返回的响应消息是:

这里输出的异常信息仅显示了异常的Root Cause信息，如果要详细的堆栈信息，我们需要修改#[message.cause.exception]为#[org.mule.util.ExceptionUtils.getFullStackTrace(exception)]

<catch-exception-strategy doc:name="Catch Exception Strategy">
     <set-payload value="#[org.mule.util.ExceptionUtils.getFullStackTrace(exception)]" encoding="UTF-8" mimeType="text/plain" doc:name="Set Payload"/>
     <logger message="#[org.mule.util.ExceptionUtils.getFullStackTrace(exception)]" level="ERROR" doc:name="Logger"/>
</catch-exception-strategy>

修改后再调用接口，异常的堆栈信息被输出到日志和调用端

由于添加了Catch Exception Strategy控件，流程运行过程中的异常被捕捉了，返回的响应状态代码变成了200，这显然不是服务器端真实的状态，因此我们需要重新设置响应的Status Code.

我们在Catch Exception Strategy控件中添加设置Status Code状态的代码

<set-property propertyName="http.status" value="#[500]" doc:name="Set Http Status" />

再次调用接口，可以看到返回的响应Status Code变成了500

在Web项目中，我们不能使用Logger输出日志,我们有三种方式输出日志:

1)自定义Transformer中添加Logger输出日志。

2)自定义Component中添加Logger输出日志。

3)自定义MessageProcessor在处理Mule Event时输出日志。

第一种方式上面已经提到了,这里不再赘述，重点说一下第二种和第三种方式。

从Mule 3.8起，自定义Component需要实现接口org.mule.api.lifecycle.Callable的onCall方法

我们自定义的Component类代码如下:

package com.mule.spring.components;

import org.mule.api.MuleEventContext;
import org.mule.api.lifecycle.Callable;
import org.mule.util.ExceptionUtils;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;

public class CustomComponent implements Callable 
{

	private static Logger logger = LogManager.getLogger(CustomComponent.class);

	@Override
	public Object onCall(MuleEventContext eventContext) throws Exception {
		String exceptionMessage = 
				ExceptionUtils.getFullStackTrace(eventContext.getMessage().getExceptionPayload().getException());
		logger.error(exceptionMessage);	
        return eventContext.getMessage();
	}
}

在Catch Exception Strategy中引用这个Component如下:

<component class="com.mule.spring.components.CustomComponent" doc:name="Custom Component"/>

自定义MessageProcessor如下：

package com.mule.spring.messageprocessors;

import org.mule.api.MuleEvent;
import org.mule.api.MuleException;
import org.mule.api.processor.MessageProcessor;
import org.mule.util.ExceptionUtils;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;

public class LoggerMessageProcessor implements MessageProcessor {

	private static Logger logger = LogManager.getLogger(LoggerMessageProcessor.class);
	
	@Override
	public MuleEvent process(MuleEvent event) throws MuleException 
	{		
		String exceptionMessage = 
        		ExceptionUtils.getFullStackTrace(event.getMessage().getExceptionPayload().getException());
        logger.error(exceptionMessage);	
		return event;
	}

}

在Catch Exception Strategy中引用这个Message Processor如下:

<custom-processor class="com.mule.spring.messageprocessors.LoggerMessageProcessor" />

由于输出堆栈信息时引用了common-lang的ExceptionUtils类(org.mule.utils.ExceptionUtils的父类)，我们需要在pom.xml中引入common-lang的jar包保证编译通过。

<dependency>
     <groupId>commons-lang</groupId>
	 <artifactId>commons-lang</artifactId>
     <version>2.6</version>
     <scope>provided</scope>
</dependency>

Web项目最后的Catch Exception Strategy设置如下:

<catch-exception-strategy doc:name="Catch Exception Strategy">
     <set-payload value="#[org.mule.util.ExceptionUtils.getFullStackTrace(exception)]" encoding="UTF-8" mimeType="text/plain" doc:name="Set Payload"/>
     <!-- <component class="com.mule.spring.components.CustomComponent" doc:name="Custom Component"/> -->
     <custom-processor class="com.mule.spring.messageprocessors.LoggerMessageProcessor" />
     <set-property propertyName="http.status" value="#[500]" doc:name="Set Http Status" />
     <message-properties-transformer>
	    <add-message-property key="Content-Type" value="text/plain;charset=utf-8" />
	 </message-properties-transformer>        
</catch-exception-strategy>

这里设置Content-Type为text/plain,因为返回的异常堆栈信息是纯文本形式，不是json或者xml形式。

重新编译web项目并部署，调用接口，可以看到返回的响应是500: Internal Server Error