in zuul-core/src/main/java/com/netflix/zuul/netty/insights/PassportLoggingHandler.java [77:147]
private void logPassport(Channel channel) {
// Collect attributes.
CurrentPassport passport = CurrentPassport.fromChannel(channel);
HttpRequestMessage request = ClientRequestReceiver.getRequestFromChannel(channel);
HttpResponseMessage response = ClientRequestReceiver.getResponseFromChannel(channel);
SessionContext ctx = request == null ? null : request.getContext();
String topLevelRequestId = getRequestId(channel, ctx);
// Do some debug logging of the Passport.
if (LOG.isDebugEnabled()) {
LOG.debug(
"State after complete. , current-server-conns = {}, current-http-reqs = {}, status = {}, nfstatus"
+ " = {}, toplevelid = {}, req = {}, passport = {}",
ConnCounter.from(channel).getCurrentActiveConns(),
HttpMetricsChannelHandler.getInflightRequestCountFromChannel(channel),
(response == null ? getRequestId(channel, ctx) : response.getStatus()),
String.valueOf(StatusCategoryUtils.getStatusCategory(ctx)),
topLevelRequestId,
request.getInfoForLogging(),
String.valueOf(passport));
}
// Some logging of session states if certain criteria match:
if (LOG.isInfoEnabled()) {
if (passport.wasProxyAttempt()) {
if (passport.findStateBackwards(PassportState.OUT_RESP_LAST_CONTENT_SENDING) == null) {
incompleteProxySessionCounter.increment();
LOG.info(
"Incorrect final state! toplevelid = {}, {}",
topLevelRequestId,
ChannelUtils.channelInfoForLogging(channel));
}
}
if (!passport.wasProxyAttempt()) {
if (ctx != null && !isHealthcheckRequest(request)) {
// Why did we fail to attempt to proxy this request?
RequestAttempts attempts = RequestAttempts.getFromSessionContext(ctx);
LOG.debug(
"State after complete. , context-error = {}, current-http-reqs = {}, toplevelid = {}, req"
+ " = {}, attempts = {}, passport = {}",
String.valueOf(ctx.getError()),
HttpMetricsChannelHandler.getInflightRequestCountFromChannel(channel),
topLevelRequestId,
request.getInfoForLogging(),
String.valueOf(attempts),
String.valueOf(passport));
}
}
StartAndEnd inReqToOutResp = passport.findFirstStartAndLastEndStates(
PassportState.IN_REQ_HEADERS_RECEIVED, PassportState.OUT_REQ_LAST_CONTENT_SENT);
if (passport.calculateTimeBetween(inReqToOutResp) > WARN_REQ_PROCESSING_TIME_NS.get()) {
LOG.info(
"Request processing took longer than threshold! toplevelid = {}, {}",
topLevelRequestId,
ChannelUtils.channelInfoForLogging(channel));
}
StartAndEnd inRespToOutResp = passport.findLastStartAndFirstEndStates(
PassportState.IN_RESP_HEADERS_RECEIVED, PassportState.OUT_RESP_LAST_CONTENT_SENT);
if (passport.calculateTimeBetween(inRespToOutResp) > WARN_RESP_PROCESSING_TIME_NS.get()) {
LOG.info(
"Response processing took longer than threshold! toplevelid = {}, {}",
topLevelRequestId,
ChannelUtils.channelInfoForLogging(channel));
}
}
}