springcloud-sleuth源码解析2-TraceFilter

基于spring cloud 1.2.1版本

本章将分析server接收一个请求，trace究竟是怎么处理的。

span的生命周期

首先介绍下一个span的生命周期：

• start
  创建一个span，这时候会记录创建时间以及设置span name。如果当前线程已经存在一个span，则创建的新的span是childSpan。

// Start a span. If there was a span present in this thread it will become
// the `newSpan`'s parent.
Span newSpan = this.tracer.createSpan("calculateTax");
try {
	// ...
	// You can tag a span
	this.tracer.addTag("taxValue", taxValue);
	// ...
	// You can log an event on a span
	newSpan.logEvent("taxCalculated");
} finally {
	// Once done remember to close the span. This will allow collecting
	// the span to send it to Zipkin
	this.tracer.close(newSpan);
}

• close
  如果一个span已经准备好将自身发送到zipkin server或者其他collect的时候，便会调用close方法，记录endTime，上报span，然后从当前线程中移除span。
• continue
  将一个新的span设置到当前线程中，成为continueSpan。该方法作用是传递不同线程之间的span。对于一些异步处理代码，就需要 将span设置到异步处理线程中了。

Span continuedSpan = this.tracer.continueSpan(spanToContinue);

• detach
  从当前线程中删除span，剥离出去，但不会stop或者close span。一般跟continue方法结合使用。

// let's assume that we're in a thread Y and we've received
// the `initialSpan` from thread X
Span continuedSpan = this.tracer.continueSpan(initialSpan);
try {
	// ...
	// You can tag a span
	this.tracer.addTag("taxValue", taxValue);
	// ...
	// You can log an event on a span
	continuedSpan.logEvent("taxCalculated");
} finally {
	// Once done remember to detach the span. That way you'll
	// safely remove it from the current thread without closing it
	this.tracer.detach(continuedSpan);
}

• create with explicit parent
  创建一个span并且指定它的parent span。该方法的使用场景是在当前线程中想创建一个span，但parent span存在另一个线程当中，这样你 就可以获取到parent span，明确指定该span为要创建的span的parent。

// let's assume that we're in a thread Y and we've received
// the `initialSpan` from thread X. `initialSpan` will be the parent
// of the `newSpan`
Span newSpan = this.tracer.createSpan("calculateCommission", initialSpan);
try {
	// ...
	// You can tag a span
	this.tracer.addTag("commissionValue", commissionValue);
	// ...
	// You can log an event on a span
	newSpan.logEvent("commissionCalculated");
} finally {
	// Once done remember to close the span. This will allow collecting
	// the span to send it to Zipkin. The tags and events set on the
	// newSpan will not be present on the parent
	this.tracer.close(newSpan);
}

下面介绍TraceFilter过滤器，它拦截所有请求，我们直接看它的doFilter方法。

TraceFilter.doFilter:

@Override
public void doFilter(ServletRequest servletRequest, ServletResponse servletResponse,
		FilterChain filterChain) throws IOException, ServletException {
	if (!(servletRequest instanceof HttpServletRequest) || !(servletResponse instanceof HttpServletResponse)) {
		throw new ServletException("Filter just supports HTTP requests");
	}
	HttpServletRequest request = (HttpServletRequest) servletRequest;
	HttpServletResponse response = (HttpServletResponse) servletResponse;
	//首先从request获取到uri
	String uri = this.urlPathHelper.getPathWithinApplication(request);
	//判断是否忽略本次trace。根据两个条件判断是否忽略本次trace：
	//A、根据skipPattern判断此uri是否是skip uri，如果是返回true
	//B、从request、response的head中获取X-B3-Sampled属性，如果值为0则返回true，即不进行采样
	boolean skip = this.skipPattern.matcher(uri).matches()
			|| Span.SPAN_NOT_SAMPLED.equals(ServletUtils.getHeader(request, response, Span.SAMPLED_NAME));
	//从request中getAttribute span。表示在一个request中，如果发生了转发那直接可以在request中获取span，不需要重新生成。		
	Span spanFromRequest = getSpanFromAttribute(request);
	if (spanFromRequest != null) {
	    //不为空的话则continueSpan，下面看看continueSpan方法。
		continueSpan(request, spanFromRequest);
	}
	if (log.isDebugEnabled()) {
		log.debug("Received a request to uri [" + uri + "] that should not be sampled [" + skip + "]");
	}
	// in case of a response with exception status a exception controller will close the span
	//正如上面的注释所说，这是请求出现异常时，跳转到异常controller时处理逻辑，然后关闭span立即结束filter。
	if (!httpStatusSuccessful(response) && isSpanContinued(request)) {
		Span parentSpan = parentSpan(spanFromRequest);
		processErrorRequest(filterChain, request, new TraceHttpServletResponse(response, parentSpan), spanFromRequest);
		return;
	}
	//设置span name
	String name = HTTP_COMPONENT + ":" + uri;
	Throwable exception = null;
	try {
	    //根据request创建span，下面分析createSpan代码。
		spanFromRequest = createSpan(request, skip, spanFromRequest, name);
		//这里会触发springmvc的trace拦截器TraceHandlerInterceptor的一些方法，下一章会分析。
		filterChain.doFilter(request, new TraceHttpServletResponse(response, spanFromRequest));
	} catch (Throwable e) {
		exception = e;
		this.tracer.addTag(Span.SPAN_ERROR_TAG_NAME, ExceptionUtils.getExceptionMessage(e));
		throw e;
	} finally {
	    //对于异步request则不进行处理
		if (isAsyncStarted(request) || request.isAsyncStarted()) {
			if (log.isDebugEnabled()) {
				log.debug("The span " + spanFromRequest + " will get detached by a HandleInterceptor");
			}
			// TODO: how to deal with response annotations and async?
			return;
		}
		//如果该请求没有被spring mvc的trace拦截器拦截到，则会人工的生成一个lc类型span，作为spanFromRequest的child span，
		//弥补springmvc的trace拦截器缺失的部分，这样能保证对于zipkin来说是一个合理的调用链路。
		spanFromRequest = createSpanIfRequestNotHandled(request, spanFromRequest, name, skip);
		//分离获取关闭span，最后来分析下该方法
		detachOrCloseSpans(request, response, spanFromRequest, exception);
	}
}

TraceFilter.continueSpan:

private void continueSpan(HttpServletRequest request, Span spanFromRequest) {
        //tracer的continueSpan方法的作用是将新的span设置到当前线程中。
        //比如span a 在线程X中，span b在线程Y中，现在上下文处于线程b中，然后操作continueSpan(a),
        //即将线程Y中的span b替换成span a，然后span a中的saved span属性设置成span b，即设置当前线程span之前的current span。
        //下面分析下continueSpan方法。
		this.tracer.continueSpan(spanFromRequest);
		request.setAttribute(TraceRequestAttributes.SPAN_CONTINUED_REQUEST_ATTR, "true");
		if (log.isDebugEnabled()) {
			log.debug("There has already been a span in the request " + spanFromRequest);
		}
	}

DefaultTracer.continueSpan：

public Span continueSpan(Span span) {
		if (span != null) {
		    //日志组件，主要用于MDC输出的
			this.spanLogger.logContinuedSpan(span);
		} else {
			return null;
		}
		//createContinuedSpan方法第一个参数span是request中保存的span，或者其他上下文传递下来的。
		//第二个span，SpanContextHolder.getCurrentSpan()是从ThreadLocal获取当前线程中的span。
		//下面看下createContinuedSpan方法
		Span newSpan = createContinuedSpan(span, SpanContextHolder.getCurrentSpan());
		//将新的span保存到当前线程中
		SpanContextHolder.setCurrentSpan(newSpan);
		return newSpan;
	}

//如果当前线程span为空且被传递过来的span的saved span属性不为空，则设置新的saved span为被传递过来的span的saved span，
//否则saved span使用当前线程中的span。
private Span createContinuedSpan(Span span, Span saved) {
		if (saved == null && span.getSavedSpan() != null) {
			saved = span.getSavedSpan();
		}
		return new Span(span, saved);
	}

对于new Span(span, saved)这种构造span的形式我们来分析下saved span有何作用：
saved的span是在创建该新的span之前就已经存在当前线程中的span。有两种情况会调用该api：

1. 正如之前所说的，span从线程X复制到线程Y中
2. 当前线程中已有span，然后创建child span，child span的saved span就是parent span

TraceFilter.createSpan

/**
 * Creates a span and appends it as the current request's attribute
 */
private Span createSpan(HttpServletRequest request,
		boolean skip, Span spanFromRequest, String name) {
	//如果spanFromRequest不为空，即发生了转发等情况，那直接返回，不需要创建新的span。
	if (spanFromRequest != null) {
		if (log.isDebugEnabled()) {
			log.debug("Span has already been created - continuing with the previous one");
		}
		return spanFromRequest;
	}
	//抽取request中的header、path等信息创建span，下面将分析joinTrace方法。
	Span parent = this.spanExtractor.joinTrace(new HttpServletRequestTextMap(request));
	//如果成功从request中提取了trace信息，生成了parent
	if (parent != null) {
		if (log.isDebugEnabled()) {
			log.debug("Found a parent span " + parent + " in the request");
		}
	    //正常tags中信息不会在server端添加，而是在client端添加tags。
	    //但是如果request header中不存在span name信息，说明client没有生成span信息，导致span信息不完整，
	    //那么就需要在server端生成tags。
		addRequestTagsForParentSpan(request, parent);
		spanFromRequest = parent;
		//将生成的span保存到当前线程中，详情看DefaultTracer.continueSpan方法，前面已分析。
		this.tracer.continueSpan(spanFromRequest);
		//判断该span是否跨进程，是的话会加SR标识，即span生命周期中server recive阶段
		if (parent.isRemote()) {
			parent.logEvent(Span.SERVER_RECV);
		}
		//将span保存到request中。
		request.setAttribute(TRACE_REQUEST_ATTR, spanFromRequest);
		if (log.isDebugEnabled()) {
			log.debug("Parent span is " + parent + "");
		}
	} else {
	    //parent为空需要生成新的span
	    //如果skip为true，则会生成一个不采样标识的span
		if (skip) {
			spanFromRequest = this.tracer.createSpan(name, NeverSampler.INSTANCE);
		}
		else {
		    //根据request header中的采样标识判断直接采样，还是根据本地设置的采样器判断是否采样
		    //下面分析下DefaultTracer.createSpan方法
			String header = request.getHeader(Span.SPAN_FLAGS);
			if (Span.SPAN_SAMPLED.equals(header)) {
				spanFromRequest = this.tracer.createSpan(name, new AlwaysSampler());
			} else {
				spanFromRequest = this.tracer.createSpan(name);
			}
		}
		spanFromRequest.logEvent(Span.SERVER_RECV);
		request.setAttribute(TRACE_REQUEST_ATTR, spanFromRequest);
		if (log.isDebugEnabled()) {
			log.debug("No parent span present - creating a new span");
		}
	}
	return spanFromRequest;
}

ZipkinHttpSpanExtractor.joinTrace

public Span joinTrace(SpanTextMap textMap) {
        //carrier中保存request header、uri信息
		Map<String, String> carrier = TextMapUtil.asMap(textMap);
		//判断header中是否有Span.SPAN_FLAGS标识，且值为1，即需要采样。
		boolean debug = Span.SPAN_SAMPLED.equals(carrier.get(Span.SPAN_FLAGS));
		if (debug) {
			// we're only generating Trace ID since if there's no Span ID will assume
			// that it's equal to Trace ID
			//header中如果不存在trace id，则生成一个。
			generateIdIfMissing(carrier, Span.TRACE_ID_NAME);
		} else if (carrier.get(Span.TRACE_ID_NAME) == null) {
			// can't build a Span without trace id
			//header中没有trace id则直接返回null，不能从reqeust中提取信息构建span
			return null;
		}
		try {
			String uri = carrier.get(URI_HEADER);
			//根据uri判断是够skip
			boolean skip = this.skipPattern.matcher(uri).matches()
					|| Span.SPAN_NOT_SAMPLED.equals(carrier.get(Span.SAMPLED_NAME));
			//如果header中span id为空则根据trace id生成一个，否则直接返回header中的span id。		
			long spanId = spanId(carrier);
			//构建span
			return buildParentSpan(carrier, uri, skip, spanId);
		} catch (Exception e) {
			log.error("Exception occurred while trying to extract span from carrier", e);
			return null;
		}
	}

DefaultTracer.createSpan

public Span createSpan(String name, Sampler sampler) {
		String shortenedName = SpanNameUtil.shorten(name);
		Span span;
		//如果本地即当前线程已经存在span，则创建child span，当前线程中的span为parent span
		//如果不存在span，则创建一个完全新的span
		if (isTracing()) {
			span = createChild(getCurrentSpan(), shortenedName);
		}
		else {
			long id = createId();
			span = Span.builder().name(shortenedName)
					.traceIdHigh(this.traceId128 ? createId() : 0L)
					.traceId(id)
					.spanId(id).build();
			if (sampler == null) {
				sampler = this.defaultSampler;
			}
			span = sampledSpan(span, sampler);
			this.spanLogger.logStartedSpan(null, span);
		}
		//将创建的span保存在当前线程
		return continueSpan(span);
	}

TraceFilter.detachOrCloseSpans

private void detachOrCloseSpans(HttpServletRequest request,
			HttpServletResponse response, Span spanFromRequest, Throwable exception) {
		Span span = spanFromRequest;
		if (span != null) {
		    //添加response status到tags中
			addResponseTags(response, exception);
			//这里判断span中savedSpan不为空且请求被TraceHandlerInterceptor拦截器拦截处理过则上报savedSpan信息
			//这里上报savedSpan,我的理解是traceFilter在filter一个request的时候会创建第一个parentSpan，
			//期间不会创建childSpan，但进入springmvc handler处理期间可能会创建一些childSpan，然后设置为current span，
			//但这种span不是traceFilter关注的，它只关注server reciver时即刚接收到请求创建的span。
			if (span.hasSavedSpan() && requestHasAlreadyBeenHandled(request)) {
                //首先停止span的clock，即记录结束时间，算下开始时间与结束时间的duration。
                //然后记录server send event，表明作为server端，什么时候响应请求返回结果的。
			    //最后上报span，比如上报到zipkin或者打印log，这就取决于初始化哪种spanReporter的了。
				recordParentSpan(span.getSavedSpan());
			} else if (!requestHasAlreadyBeenHandled(request)) {
			    //如果该请求没有被TraceHandlerInterceptor拦截器拦截处理，则直接把span从当前线程中移除，停止span的clock，然后上报
			    //这里的span可能是createSpanIfRequestNotHandled创建的span。
			    //close返回savedSpan，即parentSpan
				span = this.tracer.close(span);
			}
			//上报parentSpan
			recordParentSpan(span);
			// in case of a response with exception status will close the span when exception dispatch is handled
			// checking if tracing is in progress due to async / different order of view controller processing
			if (httpStatusSuccessful(response) && this.tracer.isTracing()) {
				if (log.isDebugEnabled()) {
					log.debug("Closing the span " + span + " since the response was successful");
				}
				this.tracer.close(span);
			} else if (errorAlreadyHandled(request) && this.tracer.isTracing()) {
				if (log.isDebugEnabled()) {
					log.debug(
							"Won't detach the span " + span + " since error has already been handled");
				}
			}  else if (shouldCloseSpan(request) && this.tracer.isTracing() && stillTracingCurrentSapn(span)) {
				if (log.isDebugEnabled()) {
					log.debug(
							"Will close span " + span + " since some component marked it for closure");
				}
				this.tracer.close(span);
			} else if (this.tracer.isTracing()) {
				if (log.isDebugEnabled()) {
					log.debug("Detaching the span " + span + " since the response was unsuccessful");
				}
				this.tracer.detach(span);
			}
		}
	}

转载于:https://my.oschina.net/xiaominmin/blog/3095993