Closed pgressa closed 3 years ago
10:47:01.804 [default-nioEventLoopGroup-5-2] TRACE i.m.h.n.reactive.HandlerPublisher - Demand received for next message (state = DEMANDING). Calling context.read()
10:47:01.805 [default-nioEventLoopGroup-5-3] DEBUG i.m.h.client.netty.DefaultHttpClient - Sending HTTP POST to http://10.96.93.118:80/events
10:47:01.805 [default-nioEventLoopGroup-5-3] TRACE i.m.h.client.netty.DefaultHttpClient - Content-Type: application/json
10:47:01.805 [default-nioEventLoopGroup-5-3] TRACE i.m.h.client.netty.DefaultHttpClient - host: 10.96.93.118
10:47:01.805 [default-nioEventLoopGroup-5-3] TRACE i.m.h.client.netty.DefaultHttpClient - connection: close
10:47:01.805 [default-nioEventLoopGroup-5-3] TRACE i.m.h.client.netty.DefaultHttpClient - content-length: 285
10:47:01.805 [default-nioEventLoopGroup-5-3] TRACE i.m.h.client.netty.DefaultHttpClient - Request Body
10:47:01.805 [default-nioEventLoopGroup-5-3] TRACE i.m.h.client.netty.DefaultHttpClient - ----
10:47:01.805 [default-nioEventLoopGroup-5-3] TRACE i.m.h.client.netty.DefaultHttpClient - {"source":"api","track":"4d9742e1-8766-4e09-bc4e-c5411529e6c0","events":[{"type":"cart:addItem","detail":{"message":"Internal Server Error: No available services for ID: mushop-catalogue","_links":{"self":{"href":"/api/cart","templated":false}}},"time":[2021,5,17,10,47,1,785579000]}]}
10:47:01.805 [default-nioEventLoopGroup-5-3] TRACE i.m.h.client.netty.DefaultHttpClient - ----
10:47:01.808 [default-nioEventLoopGroup-5-3] DEBUG i.m.h.client.netty.DefaultHttpClient - Received response 400 from http://10.96.93.118:80/events
10:47:01.808 [default-nioEventLoopGroup-5-3] TRACE i.m.h.client.netty.DefaultHttpClient - Content-Type: application/json
10:47:01.808 [default-nioEventLoopGroup-5-3] TRACE i.m.h.client.netty.DefaultHttpClient - content-length: 412
10:47:01.808 [default-nioEventLoopGroup-5-3] TRACE i.m.h.client.netty.DefaultHttpClient - connection: close
10:47:01.808 [default-nioEventLoopGroup-5-3] TRACE i.m.h.client.netty.DefaultHttpClient - Response Body
10:47:01.808 [default-nioEventLoopGroup-5-3] TRACE i.m.h.client.netty.DefaultHttpClient - ----
10:47:01.808 [default-nioEventLoopGroup-5-3] TRACE i.m.h.client.netty.DefaultHttpClient - {"message":"Failed to convert argument [events] for value [null] due to: Cannot deserialize value of type `java.lang.String` from Object value (token `JsonToken.START_OBJECT`)\n at [Source: UNKNOWN; line: -1, column: -1] (through reference chain: java.lang.Object[][0]->events.model.Event[\"detail\"]->java.util.LinkedHashMap[\"_links\"])","path":"/events","_links":{"self":{"href":"/events","templated":false}}}
10:47:01.808 [default-nioEventLoopGroup-5-3] TRACE i.m.h.client.netty.DefaultHttpClient - ----
10:47:01.808 [default-nioEventLoopGroup-5-3] TRACE i.m.h.s.netty.RoutingInBoundHandler - Encoding emitted response object [Internal Server Error: No available services for ID: mushop-catalogue] using codec: io.micronaut.jackson.codec.JsonMediaTypeCodec@130496bb
10:47:01.808 [default-nioEventLoopGroup-5-3] DEBUG i.m.h.s.netty.RoutingInBoundHandler - Response 500 - POST /api/cart
Theory: when there are two consecutive requests to same service, the second will always fail.
10:47:01.785 [default-nioEventLoopGroup-5-2] ERROR i.m.h.s.netty.RoutingInBoundHandler - Unexpected error occurred: No available services for ID: mushop-catalogue
io.micronaut.discovery.exceptions.NoAvailableServiceException: No available services for ID: mushop-catalogue
at io.micronaut.http.client.loadbalance.AbstractRoundRobinLoadBalancer.getNextAvailable(AbstractRoundRobinLoadBalancer.java:56)
at io.micronaut.core.async.publisher.Publishers$1.doOnNext(Publishers.java:207)
at io.micronaut.core.async.subscriber.CompletionAwareSubscriber.onNext(CompletionAwareSubscriber.java:52)
at io.reactivex.internal.util.HalfSerializer.onNext(HalfSerializer.java:45)
at io.reactivex.internal.subscribers.StrictSubscriber.onNext(StrictSubscriber.java:97)
at io.micronaut.reactive.rxjava2.RxInstrumentedSubscriber.onNext(RxInstrumentedSubscriber.java:59)
at io.reactivex.internal.subscriptions.DeferredScalarSubscription.complete(DeferredScalarSubscription.java:132)
at io.reactivex.internal.operators.single.SingleToFlowable$SingleToFlowableObserver.onSuccess(SingleToFlowable.java:62)
at io.micronaut.reactive.rxjava2.RxInstrumentedSingleObserver.onSuccess(RxInstrumentedSingleObserver.java:65)
at io.reactivex.internal.operators.flowable.FlowableReduceSeedSingle$ReduceSeedObserver.onComplete(FlowableReduceSeedSingle.java:110)
at io.micronaut.reactive.rxjava2.RxInstrumentedSubscriber.onComplete(RxInstrumentedSubscriber.java:73)
at io.reactivex.internal.operators.flowable.FlowableFlatMap$MergeSubscriber.drainLoop(FlowableFlatMap.java:426)
at io.reactivex.internal.operators.flowable.FlowableFlatMap$MergeSubscriber.drain(FlowableFlatMap.java:366)
at io.reactivex.internal.operators.flowable.FlowableFlatMap$InnerSubscriber.onComplete(FlowableFlatMap.java:678)
at io.micronaut.reactive.rxjava2.RxInstrumentedSubscriber.onComplete(RxInstrumentedSubscriber.java:73)
at io.reactivex.internal.operators.flowable.FlowableOnErrorReturn$OnErrorReturnSubscriber.onComplete(FlowableOnErrorReturn.java:68)
at io.micronaut.reactive.rxjava2.RxInstrumentedSubscriber.onComplete(RxInstrumentedSubscriber.java:73)
at io.reactivex.internal.subscribers.BasicFuseableSubscriber.onComplete(BasicFuseableSubscriber.java:120)
at io.micronaut.reactive.rxjava2.RxInstrumentedSubscriber.onComplete(RxInstrumentedSubscriber.java:73)
at io.reactivex.internal.subscribers.BasicFuseableSubscriber.onComplete(BasicFuseableSubscriber.java:120)
at io.micronaut.reactive.rxjava2.RxInstrumentedSubscriber.onComplete(RxInstrumentedSubscriber.java:73)
at io.reactivex.internal.subscribers.BasicFuseableSubscriber.onComplete(BasicFuseableSubscriber.java:120)
at io.micronaut.reactive.rxjava2.RxInstrumentedSubscriber.onComplete(RxInstrumentedSubscriber.java:73)
at io.reactivex.internal.operators.flowable.FlowableDoOnEach$DoOnEachSubscriber.onComplete(FlowableDoOnEach.java:135)
at io.micronaut.reactive.rxjava2.RxInstrumentedSubscriber.onComplete(RxInstrumentedSubscriber.java:73)
at io.reactivex.internal.operators.flowable.FlowableOnErrorNext$OnErrorNextSubscriber.onComplete(FlowableOnErrorNext.java:125)
at io.micronaut.reactive.rxjava2.RxInstrumentedSubscriber.onComplete(RxInstrumentedSubscriber.java:73)
at io.reactivex.internal.operators.flowable.FlowableDoOnEach$DoOnEachSubscriber.onComplete(FlowableDoOnEach.java:135)
at io.micronaut.reactive.rxjava2.RxInstrumentedSubscriber.onComplete(RxInstrumentedSubscriber.java:73)
at io.reactivex.internal.operators.flowable.FlowableOnErrorNext$OnErrorNextSubscriber.onComplete(FlowableOnErrorNext.java:125)
at io.micronaut.reactive.rxjava2.RxInstrumentedSubscriber.onComplete(RxInstrumentedSubscriber.java:73)
at io.reactivex.internal.operators.flowable.FlowableFlatMap$MergeSubscriber.drainLoop(FlowableFlatMap.java:426)
at io.reactivex.internal.operators.flowable.FlowableFlatMap$MergeSubscriber.drain(FlowableFlatMap.java:366)
at io.reactivex.internal.operators.flowable.FlowableFlatMap$InnerSubscriber.onComplete(FlowableFlatMap.java:678)
at io.micronaut.reactive.rxjava2.RxInstrumentedSubscriber.onComplete(RxInstrumentedSubscriber.java:73)
at io.reactivex.internal.operators.flowable.FlowableDoOnEach$DoOnEachSubscriber.onComplete(FlowableDoOnEach.java:135)
at io.micronaut.reactive.rxjava2.RxInstrumentedSubscriber.onComplete(RxInstrumentedSubscriber.java:73)
at io.reactivex.internal.operators.flowable.FlowableSwitchMap$SwitchMapSubscriber.drain(FlowableSwitchMap.java:225)
at io.reactivex.internal.operators.flowable.FlowableSwitchMap$SwitchMapInnerSubscriber.onComplete(FlowableSwitchMap.java:414)
at io.micronaut.reactive.rxjava2.RxInstrumentedSubscriber.onComplete(RxInstrumentedSubscriber.java:73)
at io.reactivex.internal.subscribers.BasicFuseableSubscriber.onComplete(BasicFuseableSubscriber.java:120)
at io.micronaut.reactive.rxjava2.RxInstrumentedSubscriber.onComplete(RxInstrumentedSubscriber.java:73)
at java.base/java.util.Optional.ifPresent(Optional.java:183)
at io.micronaut.core.async.processor.SingleThreadedBufferingProcessor.doOnComplete(SingleThreadedBufferingProcessor.java:48)
at io.micronaut.jackson.parser.JacksonProcessor.doOnComplete(JacksonProcessor.java:137)
at io.micronaut.core.async.subscriber.SingleThreadedBufferingSubscriber.onComplete(SingleThreadedBufferingSubscriber.java:70)
at io.reactivex.internal.util.HalfSerializer.onComplete(HalfSerializer.java:90)
at io.reactivex.internal.subscribers.StrictSubscriber.onComplete(StrictSubscriber.java:109)
at io.micronaut.reactive.rxjava2.RxInstrumentedSubscriber.onComplete(RxInstrumentedSubscriber.java:73)
at io.reactivex.internal.subscribers.BasicFuseableSubscriber.onComplete(BasicFuseableSubscriber.java:120)
at io.micronaut.reactive.rxjava2.RxInstrumentedSubscriber.onComplete(RxInstrumentedSubscriber.java:73)
at io.micronaut.http.netty.reactive.HandlerPublisher.complete(HandlerPublisher.java:416)
at io.micronaut.http.netty.reactive.HandlerPublisher.handlerRemoved(HandlerPublisher.java:403)
at io.netty.channel.AbstractChannelHandlerContext.callHandlerRemoved(AbstractChannelHandlerContext.java:946)
at io.netty.channel.DefaultChannelPipeline.callHandlerRemoved0(DefaultChannelPipeline.java:637)
at io.netty.channel.DefaultChannelPipeline.remove(DefaultChannelPipeline.java:477)
at io.netty.channel.DefaultChannelPipeline.remove(DefaultChannelPipeline.java:423)
at io.micronaut.http.netty.stream.HttpStreamsHandler.removeHandlerIfActive(HttpStreamsHandler.java:429)
at io.micronaut.http.netty.stream.HttpStreamsHandler.handleReadHttpContent(HttpStreamsHandler.java:294)
at io.micronaut.http.netty.stream.HttpStreamsHandler.channelRead(HttpStreamsHandler.java:257)
at io.micronaut.http.netty.stream.HttpStreamsClientHandler.channelRead(HttpStreamsClientHandler.java:183)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
at io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:103)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
at io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.fireChannelRead(CombinedChannelDuplexHandler.java:436)
at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:324)
at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:296)
at io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:251)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
at io.netty.handler.timeout.IdleStateHandler.channelRead(IdleStateHandler.java:286)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
at io.netty.handler.ssl.SslHandler.unwrap(SslHandler.java:1534)
at io.netty.handler.ssl.SslHandler.decodeJdkCompatible(SslHandler.java:1283)
at io.netty.handler.ssl.SslHandler.decode(SslHandler.java:1330)
at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:508)
at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:447)
at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:276)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919)
at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166)
at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:719)
at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:655)
at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:581)
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:493)
at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
at java.base/java.lang.Thread.run(Thread.java:829)```
Added logging to k8s discovery client, even though there's really a LOT of calls to k8s API it seems to be reliable and always returns correct number of service instances :/
Discovered services: mushop-orders,mushop-nats,mushop-grafana-ingress,mushop-storefront,mushop-api,edge,mushop-session,mushop-newsletter,mushop-events,mushop-user,mushop-assets,payment,fulfillment,mushop-catalogue,mushop-carts
13:58:00.153 [default-nioEventLoopGroup-5-3] TRACE i.m.k.d.p.KubernetesServiceInstanceServiceProvider - Fetching Service KubernetesServiceConfiguration{serviceId='mushop-orders', name='mushop-orders', namespace='mushop', mode='service', port='null', manual=false}
13:58:00.153 [default-nioEventLoopGroup-5-3] TRACE i.m.k.d.p.KubernetesServiceInstanceServiceProvider - Fetching Service KubernetesServiceConfiguration{serviceId='mushop-nats', name='mushop-nats', namespace='mushop', mode='service', port='null', manual=false}
13:58:00.154 [default-nioEventLoopGroup-5-3] TRACE i.m.k.d.p.KubernetesServiceInstanceServiceProvider - Fetching Service KubernetesServiceConfiguration{serviceId='mushop-grafana-ingress', name='mushop-grafana-ingress', namespace='mushop', mode='service', port='null', manual=false}
13:58:00.154 [default-nioEventLoopGroup-5-3] TRACE i.m.k.d.p.KubernetesServiceInstanceServiceProvider - Fetching Service KubernetesServiceConfiguration{serviceId='mushop-storefront', name='mushop-storefront', namespace='mushop', mode='service', port='null', manual=false}
13:58:00.154 [default-nioEventLoopGroup-5-3] TRACE i.m.k.d.p.KubernetesServiceInstanceServiceProvider - Fetching Service KubernetesServiceConfiguration{serviceId='mushop-api', name='mushop-api', namespace='mushop', mode='service', port='null', manual=false}
13:58:00.155 [default-nioEventLoopGroup-5-3] TRACE i.m.k.d.p.KubernetesServiceInstanceServiceProvider - Fetching Service KubernetesServiceConfiguration{serviceId='edge', name='edge', namespace='mushop', mode='service', port='null', manual=false}
13:58:00.155 [default-nioEventLoopGroup-5-3] TRACE i.m.k.d.p.KubernetesServiceInstanceServiceProvider - Fetching Service KubernetesServiceConfiguration{serviceId='mushop-session', name='mushop-session', namespace='mushop', mode='service', port='null', manual=false}
13:58:00.156 [default-nioEventLoopGroup-5-3] TRACE i.m.k.d.p.KubernetesServiceInstanceServiceProvider - Fetching Service KubernetesServiceConfiguration{serviceId='mushop-newsletter', name='mushop-newsletter', namespace='mushop', mode='service', port='null', manual=false}
13:58:00.156 [default-nioEventLoopGroup-5-3] TRACE i.m.k.d.p.KubernetesServiceInstanceServiceProvider - Fetching Service KubernetesServiceConfiguration{serviceId='mushop-events', name='mushop-events', namespace='mushop', mode='service', port='null', manual=false}
13:58:00.156 [default-nioEventLoopGroup-5-3] TRACE i.m.k.d.p.KubernetesServiceInstanceServiceProvider - Fetching Service KubernetesServiceConfiguration{serviceId='mushop-user', name='mushop-user', namespace='mushop', mode='service', port='null', manual=false}
13:58:00.157 [default-nioEventLoopGroup-5-3] TRACE i.m.k.d.p.KubernetesServiceInstanceServiceProvider - Fetching Service KubernetesServiceConfiguration{serviceId='mushop-assets', name='mushop-assets', namespace='mushop', mode='service', port='null', manual=false}
13:58:00.157 [default-nioEventLoopGroup-5-3] TRACE i.m.k.d.p.KubernetesServiceInstanceServiceProvider - Fetching Service KubernetesServiceConfiguration{serviceId='payment', name='payment', namespace='mushop', mode='service', port='null', manual=false}
13:58:00.157 [default-nioEventLoopGroup-5-3] TRACE i.m.k.d.p.KubernetesServiceInstanceServiceProvider - Fetching Service KubernetesServiceConfiguration{serviceId='fulfillment', name='fulfillment', namespace='mushop', mode='service', port='null', manual=false}
13:58:00.158 [default-nioEventLoopGroup-5-3] TRACE i.m.k.d.p.KubernetesServiceInstanceServiceProvider - Fetching Service KubernetesServiceConfiguration{serviceId='mushop-catalogue', name='mushop-catalogue', namespace='mushop', mode='service', port='null', manual=false}
13:58:00.158 [default-nioEventLoopGroup-5-3] TRACE i.m.k.d.p.KubernetesServiceInstanceServiceProvider - Fetching Service KubernetesServiceConfiguration{serviceId='mushop-carts', name='mushop-carts', namespace='mushop', mode='service', port='null', manual=false}
13:58:00.219 [default-nioEventLoopGroup-5-3] TRACE i.m.k.d.AbstractKubernetesServiceInstanceProvider - Building ServiceInstance for serviceId [mushop-assets] and URI [http://10.96.247.63:80]
13:58:00.220 [default-nioEventLoopGroup-5-3] TRACE i.m.k.d.KubernetesDiscoveryClient - Found 1 service instances for KubernetesServiceConfiguration{serviceId='mushop-assets', name='mushop-assets', namespace='mushop', mode='service', port='null', manual=false}
13:58:00.220 [default-nioEventLoopGroup-5-3] TRACE i.m.k.d.AbstractKubernetesServiceInstanceProvider - Building ServiceInstance for serviceId [mushop-user] and URI [http://10.96.200.198:80]
13:58:00.220 [default-nioEventLoopGroup-5-3] TRACE i.m.k.d.KubernetesDiscoveryClient - Found 1 service instances for KubernetesServiceConfiguration{serviceId='mushop-user', name='mushop-user', namespace='mushop', mode='service', port='null', manual=false}
13:58:00.221 [default-nioEventLoopGroup-5-3] TRACE i.m.k.d.AbstractKubernetesServiceInstanceProvider - Building ServiceInstance for serviceId [fulfillment] and URI [http://10.96.172.10:80]
13:58:00.221 [default-nioEventLoopGroup-5-3] TRACE i.m.k.d.KubernetesDiscoveryClient - Found 1 service instances for KubernetesServiceConfiguration{serviceId='fulfillment', name='fulfillment', namespace='mushop', mode='service', port='null', manual=false}
13:58:00.221 [default-nioEventLoopGroup-5-3] TRACE i.m.k.d.AbstractKubernetesServiceInstanceProvider - Building ServiceInstance for serviceId [mushop-orders] and URI [http://10.96.117.171:80]
13:58:00.221 [default-nioEventLoopGroup-5-3] TRACE i.m.k.d.KubernetesDiscoveryClient - Found 1 service instances for KubernetesServiceConfiguration{serviceId='mushop-orders', name='mushop-orders', namespace='mushop', mode='service', port='null', manual=false}
13:58:00.222 [default-nioEventLoopGroup-5-3] TRACE i.m.k.d.AbstractKubernetesServiceInstanceProvider - Building ServiceInstance for serviceId [mushop-session] and URI [http://10.96.107.101:6379]
13:58:00.222 [default-nioEventLoopGroup-5-3] TRACE i.m.k.d.KubernetesDiscoveryClient - Found 1 service instances for KubernetesServiceConfiguration{serviceId='mushop-session', name='mushop-session', namespace='mushop', mode='service', port='null', manual=false}
13:58:00.222 [default-nioEventLoopGroup-5-3] TRACE i.m.k.d.AbstractKubernetesServiceInstanceProvider - Building ServiceInstance for serviceId [mushop-catalogue] and URI [http://10.96.168.17:80]
13:58:00.222 [default-nioEventLoopGroup-5-3] TRACE i.m.k.d.KubernetesDiscoveryClient - Found 1 service instances for KubernetesServiceConfiguration{serviceId='mushop-catalogue', name='mushop-catalogue', namespace='mushop', mode='service', port='null', manual=false}
13:58:00.222 [default-nioEventLoopGroup-5-3] TRACE i.m.k.d.AbstractKubernetesServiceInstanceProvider - Building ServiceInstance for serviceId [mushop-events] and URI [http://10.96.93.118:80]
13:58:00.222 [default-nioEventLoopGroup-5-3] TRACE i.m.k.d.KubernetesDiscoveryClient - Found 1 service instances for KubernetesServiceConfiguration{serviceId='mushop-events', name='mushop-events', namespace='mushop', mode='service', port='null', manual=false}
13:58:00.223 [default-nioEventLoopGroup-5-3] TRACE i.m.k.d.AbstractKubernetesServiceInstanceProvider - Building ServiceInstance for serviceId [mushop-storefront] and URI [http://10.96.228.133:80]
13:58:00.223 [default-nioEventLoopGroup-5-3] TRACE i.m.k.d.KubernetesDiscoveryClient - Found 1 service instances for KubernetesServiceConfiguration{serviceId='mushop-storefront', name='mushop-storefront', namespace='mushop', mode='service', port='null', manual=false}
13:58:00.223 [default-nioEventLoopGroup-5-3] TRACE i.m.k.d.AbstractKubernetesServiceInstanceProvider - Building ServiceInstance for serviceId [mushop-grafana-ingress] and URI [http://10.96.177.146:80]
13:58:00.223 [default-nioEventLoopGroup-5-3] TRACE i.m.k.d.KubernetesDiscoveryClient - Found 1 service instances for KubernetesServiceConfiguration{serviceId='mushop-grafana-ingress', name='mushop-grafana-ingress', namespace='mushop', mode='service', port='null', manual=false}
13:58:00.223 [default-nioEventLoopGroup-5-3] TRACE i.m.k.d.AbstractKubernetesServiceInstanceProvider - Building ServiceInstance for serviceId [mushop-api] and URI [http://10.96.176.234:80]
13:58:00.224 [default-nioEventLoopGroup-5-3] TRACE i.m.k.d.KubernetesDiscoveryClient - Found 1 service instances for KubernetesServiceConfiguration{serviceId='mushop-api', name='mushop-api', namespace='mushop', mode='service', port='null', manual=false}
13:58:00.224 [default-nioEventLoopGroup-5-3] TRACE i.m.k.d.AbstractKubernetesServiceInstanceProvider - Building ServiceInstance for serviceId [mushop-carts] and URI [http://10.96.22.167:80]
13:58:00.224 [default-nioEventLoopGroup-5-3] TRACE i.m.k.d.KubernetesDiscoveryClient - Found 1 service instances for KubernetesServiceConfiguration{serviceId='mushop-carts', name='mushop-carts', namespace='mushop', mode='service', port='null', manual=false}
13:58:00.224 [default-nioEventLoopGroup-5-3] TRACE i.m.k.d.AbstractKubernetesServiceInstanceProvider - Building ServiceInstance for serviceId [payment] and URI [http://10.96.167.69:80]
13:58:00.224 [default-nioEventLoopGroup-5-3] TRACE i.m.k.d.KubernetesDiscoveryClient - Found 1 service instances for KubernetesServiceConfiguration{serviceId='payment', name='payment', namespace='mushop', mode='service', port='null', manual=false}
13:58:00.225 [default-nioEventLoopGroup-5-3] DEBUG i.m.k.d.AbstractKubernetesServiceInstanceProvider - The resource [mushop-nats] has multiple ports declared [client,routes,monitoring] if you want to to use it in micronaut you have to configure it manually.
13:58:00.225 [default-nioEventLoopGroup-5-3] TRACE i.m.k.d.AbstractKubernetesServiceInstanceProvider - Building ServiceInstance for serviceId [edge] and URI [http://10.96.235.101:80]
13:58:00.225 [default-nioEventLoopGroup-5-3] TRACE i.m.k.d.KubernetesDiscoveryClient - Found 1 service instances for KubernetesServiceConfiguration{serviceId='edge', name='edge', namespace='mushop', mode='service', port='null', manual=false}
13:58:00.227 [default-nioEventLoopGroup-5-3] TRACE i.m.k.d.AbstractKubernetesServiceInstanceProvider - Building ServiceInstance for serviceId [mushop-newsletter] and URI [https://129.159.122.168:443]
13:58:00.227 [default-nioEventLoopGroup-5-3] TRACE i.m.k.d.KubernetesDiscoveryClient - Found 1 service instances for KubernetesServiceConfiguration{serviceId='mushop-newsletter', name='mushop-newsletter', namespace='mushop', mode='service', port='null', manual=false}
13:58:02.757 [RxComputationThreadPool-1] TRACE i.m.k.d.p.KubernetesServiceInstanceServiceProvider - Fetching Service KubernetesServiceConfiguration{serviceId='mushop-user', name='mushop-user', namespace='mushop', mode='service', port='null', manual=false}
13:58:02.778 [default-nioEventLoopGroup-5-3] TRACE i.m.k.d.AbstractKubernetesServiceInstanceProvider - Building ServiceInstance for serviceId [mushop-user] and URI [http://10.96.200.198:80]
13:58:02.778 [default-nioEventLoopGroup-5-3] TRACE i.m.k.d.KubernetesDiscoveryClient - Found 1 service instances for KubernetesServiceConfiguration{serviceId='mushop-user', name='mushop-user', namespace='mushop', mode='service', port='null', manual=false}
13:58:02.794 [default-nioEventLoopGroup-5-2] TRACE i.m.k.d.p.KubernetesServiceInstanceServiceProvider - Fetching Service KubernetesServiceConfiguration{serviceId='mushop-user', name='mushop-user', namespace='mushop', mode='service', port='null', manual=false}
13:58:02.811 [default-nioEventLoopGroup-5-2] TRACE i.m.k.d.AbstractKubernetesServiceInstanceProvider - Building ServiceInstance for serviceId [mushop-user] and URI [http://10.96.200.198:80]
13:58:02.811 [default-nioEventLoopGroup-5-2] TRACE i.m.k.d.KubernetesDiscoveryClient - Found 1 service instances for KubernetesServiceConfiguration{serviceId='mushop-user', name='mushop-user', namespace='mushop', mode='service', port='null', manual=false}
13:58:02.811 [default-nioEventLoopGroup-5-2] TRACE i.m.k.d.p.KubernetesServiceInstanceServiceProvider - Fetching Service KubernetesServiceConfiguration{serviceId='mushop-carts', name='mushop-carts', namespace='mushop', mode='service', port='null', manual=false}
13:58:02.825 [default-nioEventLoopGroup-5-2] TRACE i.m.k.d.AbstractKubernetesServiceInstanceProvider - Building ServiceInstance for serviceId [mushop-carts] and URI [http://10.96.22.167:80]
13:58:02.825 [default-nioEventLoopGroup-5-2] TRACE i.m.k.d.KubernetesDiscoveryClient - Found 1 service instances for KubernetesServiceConfiguration{serviceId='mushop-carts', name='mushop-carts', namespace='mushop', mode='service', port='null', manual=false}
13:58:02.825 [default-nioEventLoopGroup-5-2] TRACE i.m.k.d.p.KubernetesServiceInstanceServiceProvider - Fetching Service KubernetesServiceConfiguration{serviceId='mushop-user', name='mushop-user', namespace='mushop', mode='service', port='null', manual=false}
13:58:02.859 [default-nioEventLoopGroup-5-2] TRACE i.m.k.d.AbstractKubernetesServiceInstanceProvider - Building ServiceInstance for serviceId [mushop-user] and URI [http://10.96.200.198:80]
13:58:02.859 [default-nioEventLoopGroup-5-2] TRACE i.m.k.d.KubernetesDiscoveryClient - Found 1 service instances for KubernetesServiceConfiguration{serviceId='mushop-user', name='mushop-user', namespace='mushop', mode='service', port='null', manual=false}
13:58:02.860 [default-nioEventLoopGroup-5-2] TRACE i.m.k.d.p.KubernetesServiceInstanceServiceProvider - Fetching Service KubernetesServiceConfiguration{serviceId='mushop-events', name='mushop-events', namespace='mushop', mode='service', port='null', manual=false}
13:58:02.884 [default-nioEventLoopGroup-5-2] TRACE i.m.k.d.AbstractKubernetesServiceInstanceProvider - Building ServiceInstance for serviceId [mushop-events] and URI [http://10.96.93.118:80]
13:58:02.884 [default-nioEventLoopGroup-5-2] TRACE i.m.k.d.KubernetesDiscoveryClient - Found 1 service instances for KubernetesServiceConfiguration{serviceId='mushop-events', name='mushop-events', namespace='mushop', mode='service', port='null', manual=false}
13:58:02.894 [default-nioEventLoopGroup-5-3] ERROR i.m.h.s.netty.RoutingInBoundHandler - Unexpected error occurred: No available services for ID: mushop-user
io.micronaut.discovery.exceptions.NoAvailableServiceException: No available services for ID: mushop-user
at io.micronaut.http.client.loadbalance.AbstractRoundRobinLoadBalancer.getNextAvailable(AbstractRoundRobinLoadBalancer.java:56)
at io.micronaut.core.async.publisher.Publishers$1.doOnNext(Publishers.java:207)
at io.micronaut.core.async.subscriber.CompletionAwareSubscriber.onNext(CompletionAwareSubscriber.java:52)
at io.reactivex.internal.util.HalfSerializer.onNext(HalfSerializer.java:45)
at io.reactivex.internal.subscribers.StrictSubscriber.onNext(StrictSubscriber.java:97)
at io.micronaut.reactive.rxjava2.RxInstrumentedSubscriber.onNext(RxInstrumentedSubscriber.java:59)
at io.reactivex.internal.subscriptions.DeferredScalarSubscription.complete(DeferredScalarSubscription.java:132)
at io.reactivex.internal.operators.single.SingleToFlowable$SingleToFlowableObserver.onSuccess(SingleToFlowable.java:62)
at io.micronaut.reactive.rxjava2.RxInstrumentedSingleObserver.onSuccess(RxInstrumentedSingleObserver.java:65)
at io.reactivex.internal.operators.flowable.FlowableReduceSeedSingle$ReduceSeedObserver.onComplete(FlowableReduceSeedSingle.java:110)
at io.micronaut.reactive.rxjava2.RxInstrumentedSubscriber.onComplete(RxInstrumentedSubscriber.java:73)
at io.reactivex.internal.operators.flowable.FlowableFlatMap$MergeSubscriber.drainLoop(FlowableFlatMap.java:426)
at io.reactivex.internal.operators.flowable.FlowableFlatMap$MergeSubscriber.drain(FlowableFlatMap.java:366)
at io.reactivex.internal.operators.flowable.FlowableFlatMap$InnerSubscriber.onComplete(FlowableFlatMap.java:678)
at io.micronaut.reactive.rxjava2.RxInstrumentedSubscriber.onComplete(RxInstrumentedSubscriber.java:73)
at io.reactivex.internal.operators.flowable.FlowableDoOnEach$DoOnEachSubscriber.onComplete(FlowableDoOnEach.java:135)
at io.micronaut.reactive.rxjava2.RxInstrumentedSubscriber.onComplete(RxInstrumentedSubscriber.java:73)
at io.reactivex.internal.operators.flowable.FlowableOnErrorReturn$OnErrorReturnSubscriber.onComplete(FlowableOnErrorReturn.java:68)
at io.micronaut.reactive.rxjava2.RxInstrumentedSubscriber.onComplete(RxInstrumentedSubscriber.java:73)
at io.reactivex.internal.subscribers.BasicFuseableSubscriber.onComplete(BasicFuseableSubscriber.java:120)
at io.micronaut.reactive.rxjava2.RxInstrumentedSubscriber.onComplete(RxInstrumentedSubscriber.java:73)
at io.reactivex.internal.subscribers.BasicFuseableSubscriber.onComplete(BasicFuseableSubscriber.java:120)
at io.micronaut.reactive.rxjava2.RxInstrumentedSubscriber.onComplete(RxInstrumentedSubscriber.java:73)
at io.reactivex.internal.subscribers.BasicFuseableSubscriber.onComplete(BasicFuseableSubscriber.java:120)
at io.micronaut.reactive.rxjava2.RxInstrumentedSubscriber.onComplete(RxInstrumentedSubscriber.java:73)
at io.reactivex.internal.operators.flowable.FlowableDoOnEach$DoOnEachSubscriber.onComplete(FlowableDoOnEach.java:135)
at io.micronaut.reactive.rxjava2.RxInstrumentedSubscriber.onComplete(RxInstrumentedSubscriber.java:73)
at io.reactivex.internal.operators.flowable.FlowableOnErrorNext$OnErrorNextSubscriber.onComplete(FlowableOnErrorNext.java:125)
at io.micronaut.reactive.rxjava2.RxInstrumentedSubscriber.onComplete(RxInstrumentedSubscriber.java:73)
at io.reactivex.internal.operators.flowable.FlowableDoOnEach$DoOnEachSubscriber.onComplete(FlowableDoOnEach.java:135)
at io.micronaut.reactive.rxjava2.RxInstrumentedSubscriber.onComplete(RxInstrumentedSubscriber.java:73)
at io.reactivex.internal.operators.flowable.FlowableOnErrorNext$OnErrorNextSubscriber.onComplete(FlowableOnErrorNext.java:125)
at io.micronaut.reactive.rxjava2.RxInstrumentedSubscriber.onComplete(RxInstrumentedSubscriber.java:73)
at io.reactivex.internal.operators.flowable.FlowableFlatMap$MergeSubscriber.drainLoop(FlowableFlatMap.java:426)
at io.reactivex.internal.operators.flowable.FlowableFlatMap$MergeSubscriber.drain(FlowableFlatMap.java:366)
at io.reactivex.internal.operators.flowable.FlowableFlatMap$InnerSubscriber.onComplete(FlowableFlatMap.java:678)
at io.micronaut.reactive.rxjava2.RxInstrumentedSubscriber.onComplete(RxInstrumentedSubscriber.java:73)
at io.reactivex.internal.operators.flowable.FlowableDoOnEach$DoOnEachSubscriber.onComplete(FlowableDoOnEach.java:135)
at io.micronaut.reactive.rxjava2.RxInstrumentedSubscriber.onComplete(RxInstrumentedSubscriber.java:73)
at io.reactivex.internal.operators.flowable.FlowableSwitchMap$SwitchMapSubscriber.drain(FlowableSwitchMap.java:225)
at io.reactivex.internal.operators.flowable.FlowableSwitchMap$SwitchMapInnerSubscriber.onComplete(FlowableSwitchMap.java:414)
at io.micronaut.reactive.rxjava2.RxInstrumentedSubscriber.onComplete(RxInstrumentedSubscriber.java:73)
at io.reactivex.internal.subscribers.BasicFuseableSubscriber.onComplete(BasicFuseableSubscriber.java:120)
at io.micronaut.reactive.rxjava2.RxInstrumentedSubscriber.onComplete(RxInstrumentedSubscriber.java:73)
at java.base/java.util.Optional.ifPresent(Optional.java:178)
at io.micronaut.core.async.processor.SingleThreadedBufferingProcessor.doOnComplete(SingleThreadedBufferingProcessor.java:48)
at io.micronaut.jackson.parser.JacksonProcessor.doOnComplete(JacksonProcessor.java:137)
at io.micronaut.core.async.subscriber.SingleThreadedBufferingSubscriber.onComplete(SingleThreadedBufferingSubscriber.java:70)
at io.reactivex.internal.util.HalfSerializer.onComplete(HalfSerializer.java:90)
at io.reactivex.internal.subscribers.StrictSubscriber.onComplete(StrictSubscriber.java:109)
at io.micronaut.reactive.rxjava2.RxInstrumentedSubscriber.onComplete(RxInstrumentedSubscriber.java:73)
at io.reactivex.internal.subscribers.BasicFuseableSubscriber.onComplete(BasicFuseableSubscriber.java:120)
at io.micronaut.reactive.rxjava2.RxInstrumentedSubscriber.onComplete(RxInstrumentedSubscriber.java:73)
at io.micronaut.http.netty.reactive.HandlerPublisher.complete(HandlerPublisher.java:416)
at io.micronaut.http.netty.reactive.HandlerPublisher.handlerRemoved(HandlerPublisher.java:403)
at io.netty.channel.AbstractChannelHandlerContext.callHandlerRemoved(AbstractChannelHandlerContext.java:946)
at io.netty.channel.DefaultChannelPipeline.callHandlerRemoved0(DefaultChannelPipeline.java:637)
at io.netty.channel.DefaultChannelPipeline.remove(DefaultChannelPipeline.java:477)
at io.netty.channel.DefaultChannelPipeline.remove(DefaultChannelPipeline.java:423)
at io.micronaut.http.netty.stream.HttpStreamsHandler.removeHandlerIfActive(HttpStreamsHandler.java:429)
at io.micronaut.http.netty.stream.HttpStreamsHandler.handleReadHttpContent(HttpStreamsHandler.java:294)
at io.micronaut.http.netty.stream.HttpStreamsHandler.channelRead(HttpStreamsHandler.java:257)
at io.micronaut.http.netty.stream.HttpStreamsClientHandler.channelRead(HttpStreamsClientHandler.java:183)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
at io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:103)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
at io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.fireChannelRead(CombinedChannelDuplexHandler.java:436)
at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:324)
at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:296)
at io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:251)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
at io.netty.handler.timeout.IdleStateHandler.channelRead(IdleStateHandler.java:286)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
at io.netty.handler.ssl.SslHandler.unwrap(SslHandler.java:1534)
at io.netty.handler.ssl.SslHandler.decodeJdkCompatible(SslHandler.java:1283)
at io.netty.handler.ssl.SslHandler.decode(SslHandler.java:1330)
at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:508)
at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:447)
at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:276)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919)
at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166)
at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:719)
at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:655)
at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:581)
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:493)
at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
at java.base/java.lang.Thread.run(Thread.java:831)