ボディボディ損失で再試行
Postmanの設定では、500のレスポンスコードに対してGetリクエストだけがリトライされますが、Postのようなリクエストでは、まだBodyを送信する段階に達していない例外だけがリトライされます。あるいは、Postmanを使ってBody付きのGetリクエストを作るだけで、リトライするのが普通なのでしょうか？
/test-exception-thrownセクション6のEurekaServerを起動し、インターフェイスを変更してRequestBodyパラメータを追加します：
@RequestMapping(value = "/test-exception-thrown", method = {RequestMethod.GET, RequestMethod.POST, RequestMethod.PUT, RequestMethod.DELETE})
public String testExceptionThrown(HttpServletRequest httpServletRequest, @RequestBody Map<String, String> body) {
log.info("testExceptionThrow called {}, {}", httpServletRequest.getMethod(), body);
if (shouldThrowException) {
throw new IllegalStateException();
}
return zone;
}
zone1-service-provider-instance1zone1-service-provider-instance2zone1-service-provider-instance1ここで、例外をスローするインターフェイスアクセスのインスタンスです。zone1-service-provider-instance1zone1-service-provider-instance2zone1-service-provider-instance2ゲートウェイを起動し、インターフェイスを呼び出すためにPostmanを使用して、再試行があることがわかりました、リクエストは、最初に 、に送信され、次に 、に再試行が400エラーを返しました、つまり、RequestBodyを受信しませんでした、これは何が起こったのか？
Apiゲートウェイ呼び出しログ
.781 INFO [service-api-gateway,fce1bd17,fce1bd17]
[boundedElastic-1][com.github.hashjang.hoxton.api.gateway.filter.InstanceCircuitBreakerFilter:54]: try to send request to: http://...:/--wn: stats: {"numberOfNotPermittedCalls":0,"numberOfSlowCalls":0,"numberOfBufferedCalls":0,"slowCallRate":-1.0,"failureRate":-1.0,"numberOfSuccessfulCalls":0,"numberOfFailedCalls":0,"numberOfSlowSuccessfulCalls":0,"numberOfSlowFailedCalls":0}
.115 INFO [service-api-gateway,fce1bd17,fce1bd17]
[boundedElastic-1][com.github.hashjang.hoxton.api.gateway.filter.InstanceCircuitBreakerFilter:54]: try to send request to: http://...:/--wn: stats: {"numberOfNotPermittedCalls":0,"numberOfSlowCalls":0,"numberOfBufferedCalls":1,"slowCallRate":-1.0,"failureRate":-1.0,"numberOfSuccessfulCalls":1,"numberOfFailedCalls":0,"numberOfSlowSuccessfulCalls":0,"numberOfSlowFailedCalls":0}
zone1-service-provider-instance1ジャーナル
.789 ERROR
[service-provider,,]
[XNIO-2 task-4][io.undertow.servlet.api.LoggingExceptionHandler:80]:UT: Exception handling request to /test-exception-thrown
zone1-service-provider-instance2ジャーナル
.133 WARN
[service-provider,fce1bd17,da6d3f91fcfc053f]
[XNIO-2 task-5][org.springframework.web.servlet.handler.AbstractHandlerExceptionResolver:199]:Resolved [org.springframework.http.converter.HttpMessageNotReadableException: Required request body is missing: public java.lang.String com.github.hashjang.hoxton.service.provider.controller.TestServiceController.testExceptionThrown(javax.servlet.http.HttpServletRequest,java.util.Map<java.lang.String, java.lang.String>)]
問題を特定するには、一番最初に LogFilter を追加して、Body のトレースを有効にします：
@Component
public class LogFilter implements GlobalFilter, Ordered {
@Override
public Mono<Void> filter(ServerWebExchange exchange, GatewayFilterChain chain) {
return chain.filter(exchange.mutate().request(new ServerHttpRequestDecorator(exchange.getRequest()) {
@Override
public Flux<DataBuffer> getBody() {
//bodyログを開き、フィルタの本体の操作を記録する
return exchange.getRequest().getBody().log();
}
}).build());
}
@Override
public int getOrder() {
//初めに
return Ordered.HIGHEST_PRECEDENCE;
}
}
ゲートウェイを再起動し、リクエストを送信します：
.026 INFO [service-api-gateway,1ae3da3c7,1ae3da3c7]
[boundedElastic-1][com.github.hashjang.hoxton.api.gateway.filter.InstanceCircuitBreakerFilter:54]: try to send request to: http://...:/--wn: stats: {"numberOfNotPermittedCalls":0,"numberOfSlowSuccessfulCalls":0,"numberOfSuccessfulCalls":0,"numberOfSlowFailedCalls":0,"numberOfFailedCalls":0,"failureRate":-1.0,"slowCallRate":-1.0,"numberOfBufferedCalls":0,"numberOfSlowCalls":0}
.034 INFO [service-api-gateway,,]
[reactor-http-nio-4][reactor.util.Loggers$Slf4JLogger:274]: onContextUpdate(Context3{class brave.propagation.TraceContext=1ae3da3c7/1ae3da3c7, class org.springframework.cloud.sleuth.instrument.web.client.HttpClientBeanPostProcessor$CurrentClientSpan=NoopSpan(1ae3da3c7/38ecc8fd2b789c2e), reactor.onDiscard.local=reactor.core.publisher.Operators$$Lambda$ddb4af})
.034 INFO [service-api-gateway,1ae3da3c7,1ae3da3c7]
[reactor-http-nio-2][reactor.util.Loggers$Slf4JLogger:274]: onSubscribe([Fuseable] ScopePassingSpanSubscriber)
.034 INFO [service-api-gateway,1ae3da3c7,1ae3da3c7]
[reactor-http-nio-2][reactor.util.Loggers$Slf4JLogger:274]: request(unbounded)
.035 INFO [service-api-gateway,1ae3da3c7,1ae3da3c7]
[reactor-http-nio-2][reactor.util.Loggers$Slf4JLogger:274]: onNext(PooledSlicedByteBuf(ridx: 0, widx: 10, cap: 10/10, unwrapped: PooledUnsafeDirectByteBuf(ridx: 326, widx: 326, cap: 1024)))
.035 INFO [service-api-gateway,1ae3da3c7,1ae3da3c7]
[reactor-http-nio-2][reactor.util.Loggers$Slf4JLogger:274]: onComplete()
.165 INFO [service-api-gateway,1ae3da3c7,1ae3da3c7]
[boundedElastic-1][com.github.hashjang.hoxton.api.gateway.filter.InstanceCircuitBreakerFilter:54]: try to send request to: http://...:/--wn: stats: {"numberOfNotPermittedCalls":0,"numberOfSlowSuccessfulCalls":0,"numberOfSuccessfulCalls":0,"numberOfSlowFailedCalls":0,"numberOfFailedCalls":0,"failureRate":-1.0,"slowCallRate":-1.0,"numberOfBufferedCalls":0,"numberOfSlowCalls":0}
.169 INFO [service-api-gateway,,]
[reactor-http-nio-3][reactor.util.Loggers$Slf4JLogger:274]: onContextUpdate(Context3{class brave.propagation.TraceContext=1ae3da3c7/1ae3da3c7, class org.springframework.cloud.sleuth.instrument.web.client.HttpClientBeanPostProcessor$CurrentClientSpan=NoopSpan(1ae3da3c7/d05978ee5d1cb64c), reactor.onDiscard.local=reactor.core.publisher.Operators$$Lambda$daa8})
.170 INFO [service-api-gateway,1ae3da3c7,1ae3da3c7]
[reactor-http-nio-2][reactor.util.Loggers$Slf4JLogger:274]: onSubscribe([Fuseable] ScopePassingSpanSubscriber)
.170 INFO [service-api-gateway,1ae3da3c7,1ae3da3c7]
[reactor-http-nio-2][reactor.util.Loggers$Slf4JLogger:274]: request(unbounded)
.170 INFO [service-api-gateway,1ae3da3c7,1ae3da3c7]
[reactor-http-nio-2][reactor.util.Loggers$Slf4JLogger:274]: onComplete()
このBodyのFluxは、再試行する際にも同じ元のFluxを使用していますが、このFluxは最初の呼び出しによってすでに消費されているため、再度消費しようとすると、消費完了に直接戻り、使用できないことがわかりました：onNext(PooledSlicedByteBuf(ridx: 0, widx: 10, cap: 10/10, unwrapped: PooledUnsafeDirectByteBuf(ridx: 326, widx: 326, cap: 1024)))
Publisher<Void> publisher = chain.filter(exchange.mutate().request(
new ServerHttpRequestDecorator(request) {
@Override
public Flux<DataBuffer> getBody() {
int currentIteration = exchange
.getAttributeOrDefault(RETRY_ITERATION_KEY, -1);
//それは再試行であるかどうかを判断するためにcurrentIterationによると、そうでない場合は、元のリクエストフラックスのボディを返す
//もしそうなら、再試行も正しいボディを持っていることを確認するために、Fluxを再生成するためにキャッシュされた文字列を返す
return currentIteration > -1 ? Flux.from(Mono.just(dataBufferFactory.wrap(((String) exchange.getAttributes().get(BODY)).getBytes()))) :
request.getBody().map(dataBuffer -> {
if (LEGAL_LOG_MEDIA_TYPES.contains(contentType)) {
try {
String body = (String) exchange.getAttributes().get(BODY);
if (body == null) { byte[] content = new byte[dataBuffer.readableByteCount()]; try { dataBuffer.read(content); } finally { DataBufferUtils.release(dataBuffer); } String s = new String(content, Charset.defaultCharset()); exchange.getAttributes().put(BODY, s); dataBuffer = dataBufferFactory.wrap(s.getBytes());
} else { dataBuffer = dataBufferFactory.wrap(body.getBytes());
}
} catch (Exception e) {
log.error("error read body in retry", e);
}
}
return dataBuffer;
});
}
}
).build())
AdaptCachedBodyGlobalFilter AdaptCachedBodyGlobalFilterもう1つは、Spring Cloud Gatewayですでに利用可能なキャッシュ機構を使うことです：
public class AdaptCachedBodyGlobalFilter
implements GlobalFilter, Ordered, ApplicationListener<EnableBodyCachingEvent> {
/**
* RequestBodyルートをキャッシュする
*/
private ConcurrentMap<String, Boolean> routesToCache = new ConcurrentHashMap<>();
/**
* RequestBodyの属性キーをキャッシュする。
*/
@Deprecated
public static final String CACHED_REQUEST_BODY_KEY = CACHED_REQUEST_BODY_ATTR;
/**
* EnableBodyCachingEventを受信し、EnableBodyCachingEventのRouteIdをキャッシュ対象のRouteのMapに追加する。
*/
@Override
public void onApplicationEvent(EnableBodyCachingEvent event) {
this.routesToCache.putIfAbsent(event.getRouteId(), true);
}
//。。。。少し
}
グローバルな再試行なので、Bodyをキャッシュする仕組みをすべてのRouteに追加することができ、次のように実装できます：
@Configuration
@EnableConfigurationProperties(ApiGatewayRetryConfig.class)
@LoadBalancerClients(defaultConfiguration = CommonLoadBalancerConfig.class)
public class ApiGatewayConfig {
@Autowired
private AdaptCachedBodyGlobalFilter adaptCachedBodyGlobalFilter;
@Autowired
private GatewayProperties gatewayProperties;
@PostConstruct
public void init() {
//各パスは、ボディでリクエストを再試行するときに、再試行されたリクエストは、元のボディは1回限りのnettyベースのFluxReceiveであるため、ボディを持っていないように、ボディキャッシュをやろう。
gatewayProperties.getRoutes().forEach(routeDefinition -> {
EnableBodyCachingEvent enableBodyCachingEvent = new EnableBodyCachingEvent(new Object(), routeDefinition.getId());
adaptCachedBodyGlobalFilter.onApplicationEvent(enableBodyCachingEvent);
});
}
}
この修正後、ゲートウェイを再起動し、トリガー再試行を再度呼び出します：
.972 INFO [service-api-gateway,72eba79a3afc324f,72eba79a3afc324f]
[reactor-http-nio-2][reactor.util.Loggers$Slf4JLogger:274]: onContextUpdate(Context2{class brave.propagation.TraceContext=72eba79a3afc324f/72eba79a3afc324f, reactor.onDiscard.local=reactor.core.publisher.Operators$$Lambda$7bc})
.972 INFO [service-api-gateway,72eba79a3afc324f,72eba79a3afc324f]
[reactor-http-nio-2][reactor.util.Loggers$Slf4JLogger:274]: onSubscribe([Fuseable] ScopePassingSpanSubscriber)
.973 INFO [service-api-gateway,72eba79a3afc324f,72eba79a3afc324f]
[reactor-http-nio-2][reactor.util.Loggers$Slf4JLogger:274]: request(unbounded)
.973 INFO [service-api-gateway,72eba79a3afc324f,72eba79a3afc324f]
[reactor-http-nio-2][reactor.util.Loggers$Slf4JLogger:274]: onNext(PooledSlicedByteBuf(ridx: 0, widx: 10, cap: 10/10, unwrapped: PooledUnsafeDirectByteBuf(ridx: 326, widx: 326, cap: 512)))
.974 INFO [service-api-gateway,72eba79a3afc324f,72eba79a3afc324f]
[reactor-http-nio-2][reactor.util.Loggers$Slf4JLogger:274]: onComplete()
.986 INFO [service-api-gateway,72eba79a3afc324f,72eba79a3afc324f]
[boundedElastic-1][com.github.hashjang.hoxton.api.gateway.filter.InstanceCircuitBreakerFilter:54]: try to send request to: http://...:/--wn: stats: {"numberOfNotPermittedCalls":0,"failureRate":-1.0,"slowCallRate":-1.0,"numberOfSlowFailedCalls":0,"numberOfFailedCalls":0,"numberOfSlowSuccessfulCalls":0,"numberOfSuccessfulCalls":0,"numberOfBufferedCalls":0,"numberOfSlowCalls":0}
.138 INFO [service-api-gateway,72eba79a3afc324f,72eba79a3afc324f]
[boundedElastic-1][com.github.hashjang.hoxton.api.gateway.filter.InstanceCircuitBreakerFilter:54]: try to send request to: http://...:/--wn: stats: {"numberOfNotPermittedCalls":0,"failureRate":-1.0,"slowCallRate":-1.0,"numberOfSlowFailedCalls":0,"numberOfFailedCalls":0,"numberOfSlowSuccessfulCalls":0,"numberOfSuccessfulCalls":1,"numberOfBufferedCalls":1,"numberOfSlowCalls":0}
再試行コールが見つかりました。ボディは失われず、再試行は成功しました。
