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);
			}
		}
	}