捕获失败和系统状态(第一部分)

工程 | Alef Arendsen | 2008年1月7日 | ...

在Spring Experience上,我主持了一个关于各个方面的会议。其中之一是我上周描述的Hibernate同步方面。另一个是能够捕获第一次失败和系统状态的方面,有时称为首次失败数据捕获 (FFDC)。我主持这次会议是为了展示一些非常有用的方面,但人们在实践中可能还没有遇到过。我经常听到人们询问日志记录、跟踪、事务管理和安全性以外的其他方面。我认为Hibernate同步方面和FFDC方面是很好的例子。

介绍

FFDC 的目标是在发生错误时捕获有关系统当前状态的尽可能多的信息。以下条目解释了此方面的工作原理以及如何在您自己的应用程序中使用它。

让我们设定以下两个目标

  • 当错误从业务服务中逃逸时,我们希望记录调用上下文,这意味着在业务服务执行的上下文中发生的所有调用
  • 当错误从业务服务中逃逸时,我们希望记录错误的根本原因,这不仅是指最顶层的异常(从方法中逃逸的异常),还包括可能已被包装、吞咽或重新抛出的_第一个_异常

为此,首先让我们设计一个能够跟踪我们想要记录的数据的类。我们将此类称为CallContext。我省略了实际实现。我将在我的下一篇文章中发布代码,这里的实现并不重要,除此之外,它只是一个相当简单的数 据持有者。


public class CallContext {

	/**
	 * Registers the root call of this call context.
	 * We want to distinguish between the root call
	 * and all subsequent calls issued in the context
	 * of the root call.
	 */
	public void setRootCall(JoinPoint rootCall) { ... }
	
	/**
	 * Registers a call at a certain depth.
	 * @param the call to register
	 * @param the depth of the call
	 */ 
	public void registerCall(JoinPoint call, int depth) { ... }
	
	/**
	 * Registers the first failure of this call context.
	 * A first failure might already have occurred in which
	 * case subsequent registrations of the same or different
	 * failures will be ignored.
	 */
	public void setFirstFailure(Throwable t) { ... }
	
	/**
	 * Log the entire call context (i.e. output it to
	 * System.out).
	 */
	public void log(Throwable t) { ... }
}

如您所见,我们使用AspectJ JoinPoint类型来识别程序中发生的事件。

定义四个场景

所以,我们已经准备好数据了。接下来,让我们稍微改写一下我们之前设定的两个目标,并创建一个我们希望在程序中发生的事情列表
  • 在调用业务服务之前,我们希望将根调用与当前调用上下文注册
  • 在业务服务上下文中进行调用之前,我们希望将(以及当前深度)调用与当前调用上下文注册
  • 当业务服务内部发生异常时,将其与当前调用上下文注册为第一次失败
  • 在异常从业务服务中逃逸之后,我们希望记录当前调用上下文

如您所见,我只是稍微对事情进行了一些切分,以便出现“在_某些事情_发生之前/之后,做_某些事情_”形式的句子。唯一剩下的就是识别这两个_某些事情_,我们就完成了。让我们分别处理这三个不同的逻辑部分。

在业务服务之前,将根调用与当前上下文注册

使用AspectJ,这相对容易实现。让我们假设业务服务可以通过可以添加到方法或类的@BusinessService注解来标识。如果将其添加到类中,则该类上的所有方法都是业务服务。如果将其添加到方法中,则只有该方法是业务服务。换句话说:业务服务是_在反过来由@BusinessService注解的类中定义的方法_或_由@BusinessService本身注解的方法_。在AspectJ中,这归结为以下内容(有关AspectJ切点表达式语言的精确语法的更多信息,请参阅http://www.eclipse.org/aspectj//doc/released/progguide/semantics-pointcuts.html)。

pointcut businessService() : call(* (@BusinessService *..*).*(..)) || call(@BusinessService * *(..));

现在我们已经确定了业务服务,我们可以完成第一个场景


public aspect FirstFailureDataCapturer {

	public CallContext callContext = new CallContext();
	
	pointcut businessService() : call(@BusinessService *..*).*(..)) || 
			call(@BusinessService * *(..));
	
	before() : businessService() {
		// 'thisJoinPoint' is an implicit variable (just like 'this')
		// that represents the current join point
		this.callContext.setRootCall(thisJoinPoint);
	}
}

在业务服务上下文中进行调用之前,将其与当前调用上下文注册

我们完成了第一个场景,让我们处理第二个场景。我们已经确定了什么是业务服务。我们希望捕获业务服务上下文中的所有调用。可以如下标识任意调用

pointcut methodCall() : call(* *(..));

如果我们使用此切点,我们将使该场景适用于_所有方法_,但我们只想将其应用于业务服务内部的方法。因此,我们需要限制此切点的范围。我们可以使用_cflow_切点指示符来做到这一点。_cflow切点指示符_采用另一个切点,并将其限制在该切点的上下文中发生的事情。让我们看看如何使用它来解决手头的问题。将以下内容理解为:“业务服务中的方法调用是在业务服务的控制流中(同时)的方法调用(参考上面定义的切点)”。


pointcut methodCallInBusinessService() : methodCall() && cflow(businessService());

让我们更进一步,假设我们不想注册_所有_方法调用,而只想注册有限的集合。以下定义了一个可跟踪的方法,仅识别我认为相关的 方法。它还排除了在方面本身(或方面的控制流中)定义的方法。后者可以防止发生无限循环。让我们也大声朗读一下:可跟踪的方法是在业务服务中的方法调用(参考上面定义的切点),同时不在FirstFailureDataCapturer中定义的正在执行的advice的控制流中,并且它也不应该是对equals()、hashCode()或getClass()的调用。


pointcut traceableMethod() : 
	methodCallInBusinessService() &&
	!cflow(within(FirstFailureDataCapturer) && adviceexecution()) &&
	!call(* equals(Object)) && !call(* hashCode()) && !call(* getClass());

让我们使用此切点来实现我们已经识别的第二个场景。在上文对场景的描述中,我们没有指定我们还需要跟踪当前深度。我们使用before advice来记录当前调用。让我们也使用相同的advice来跟踪深度,并使用after advice将深度重置为其先前状态。


public aspect FirstFailureDataCapturer {

	public CallContext callContext = new CallContext();
	
	public int currentDepth = 0;
	
	// other pointcuts and advices omitted

	pointcut methodCallInBusinessService() : methodCall() && cflow(businessService());
	
	pointcut traceableMethod() : 
		methodCallInBusinessService() &&
		!cflow(within(FirstFailureDataCapturer) && adviceexecution())) &&
		!call(* equals(Object)) && !call(* hashCode()) && !call(* getClass());
		
	before() : traceableMethod() {
		currentDepth++;
		callContext.registerCall(thisJoinPoint, currentDepth);
	}
	
	after() : traceableMethod() {
		currentDepth--;
	}
}

当业务服务内部发生异常时,将其与当前调用上下文注册

现在我们完成了第二个场景,我们已经捕获了几乎所有我们想要捕获的状态。我们想要捕获的最后一件事是在同一业务服务的上下文中发生的第一个异常。

潜在的故障点是a)从方法中逃逸的异常或b)方法内部的异常处理程序(然后被包装、吞咽,可能被重新抛出等)。让我们使用此定义来实现我们的第三个场景。第一个切点只是使用可跟踪的方法切点来标识潜在的故障点。我们将在稍后使用after throwing advice来完成我们场景的一部分。第二个更有趣一些。它定义了一个切点,该切点标识业务服务控制流中的异常处理程序(catch块)。使用此切点,我们可以例如标识被捕获、包装和重新抛出的异常(或被捕获和吞咽的异常)。


pointcut potentialFailurePoint() : traceableMethod();
	
pointcut exceptionHandler(Throwable t) : handler(*) && args(t) && cflow(businessService());

我们将使用before和after advice来完成第三个场景。首先:在异常处理程序之前,记录异常


public aspect FirstFailureDataCapturer {

	private CallContext context = new CallContext();

	// other members omitted

	before(Throwable t) : exceptionHandler(t) {
		this.callContext.setFirstFailure(t);
	}
}

现在,让我们定义另一个advice


public aspect FirstFailureDataCapturer {

	private CallContext context = new CallContext();

	// other members omitted

	after() throwing(Throwable t) : potentialFailurePoint() {
		this.callContext.setFirstFailure(t);
	}
}

在异常从业务服务中逃逸之后,记录当前调用上下文

我们需要做的最后一件事是在业务服务执行导致异常的情况下记录当前调用上下文。我们已经拥有所有成分(切点)可以直接跳到advice,所以让我们继续。

public aspect FirstFailureDataCapturer {

	private CallContext context = new CallContext();

	// other members omitted

	after() throwing(Throwable t) : businessService() {
		this.callContext.log(t);
	}
}

以CarPlant为例

在我的Spring Experience会议上,我使用了我的(臭名昭著的)CarPlant示例来展示FirstFailureDataCapturer。CarPlant是一个相对较小的系统,能够制造汽车。制造汽车是一个两步过程:1)从CarPartsInventory系统获取零件;2)要求CarAssemblyLine将零件组装成汽车。CarPlant本身

@BusinessService public Car manufactureCar(CarModel model) {
	Set <Part> parts = inventory.getPartsForModel(model);
	
	return assemblyLine.assembleCarFromParts(model, parts);
}

在此示例中,CarPartsInventory是一个存根,实际上没有任何有用的作用


public Set<Part> getPartsForModel(CarModel model) {
	return new HashSet<Part>();
}

这里有趣的部分是CarAssemblyLine。正如您在下面的代码中看到的,CarAssemblyLine中有一些奇怪的代码。它首先抛出一个异常,自己捕获它,然后将其重新抛出为一个相当无意义的异常。


public Car assembleCarFromParts(CarModel model, Set<Part> parts) {
		
	try {
		throw new OnStrikeException("The workers are on strike!");
	} catch (OnStrikeException e) {
		throw new MeaninglessException();
	}
}

显然,在正常情况下,问题的根本原因永远不会在这种情况下被识别出来(它被捕获,没有被记录……抛出了不同的异常,并且根本原因没有传递),我们也永远无法准确地在实际和第一次失败(OnStrikeException)发生时注册系统状态。幸运的是,现在我们有了FirstFailureDataCapturer,我们可以注册根本原因并记录它。您可以在下面找到我运行的测试的序列图和一些输出。如您所见,我们不仅获得了调用堆栈,还获得了**在此业务服务执行的上下文中发生的所有调用**,或者换句话说:整个调用树。

ffdc.png

捕获系统状态

如果您仔细观察,您可以看到第一个被转储的异常是MeaninglessException。但是,在MeaninglessException被转储之后,有一条消息说有一个与MeaninglessException不同的根本原因,然后转储实际异常。堆栈跟踪还提到实际异常是在第18行引起的,而MeaninglessException起源于第20行。

现在我们已经确定了发生故障的_实际_点,我们也可以开始捕获系统状态。正如您可以想象的那样,CarPlant:18处的系统状态可能与CarPlant:20处的系统状态不同,而我们的FirstFailureDataCapturer允许我们在_正确的时间点_注册系统状态。

那么系统状态到底是什么呢?好吧,这完全取决于运行时、您的特定应用程序以及您感兴趣的内容。以下是一些示例

  • 当前登录的用户
  • 当前的汽车制造请求
  • 任何技术系统状态(线程数量、缓存统计信息等)
  • 发生此异常的节点

现在捕获系统状态非常容易,例如,我们可以在CallContext.setFirstFailure()方法内执行此操作。

第二部分呢?

这个方面还没有完成!第一次出现完整方面时,它的编码如下

public aspect FirstFailureDataCapturer {

	public CallContext callContext = new CallContext();
	
	pointcut businessService() : call(@BusinessService * *(..)) || call(* (@BusinessService *..*).*(..)) || call(@BusinessService * *(..));
	
	before() : businessService() {
		// 'thisJoinPoint' is an implicit variable (just like 'this')
		// that represents the current join point
		this.callContext.setRootCall(thisJoinPoint);
	}
}

如你所见,调用上下文在 FirstFailureDataCapturer 实例化时被实例化。当然,现在的问题是:FirstFailureDataCapturer 将何时以及被实例化多少次? 回答了这个问题后,你可能会想到另一个问题:如果在多线程环境中使用这个方面会发生什么? 在下一部分,我将讨论所有这些,并对这个方面进行一些修改以使其更加完善。同时,你当然也可以在评论中尝试回答这些问题:)!我还会在下一部分提供该方面的源代码。

获取Spring通讯

关注Spring通讯

订阅

领先一步

VMware 提供培训和认证,助您快速提升。

了解更多

获取支持

Tanzu Spring在一个简单的订阅中提供对OpenJDK™、Spring和Apache Tomcat®的支持和二进制文件。

了解更多

即将举行的活动

查看Spring社区中所有即将举行的活动。

查看全部