* Cleaned up XdsLoadStatsStore.
- Renamed the StatsStore interface to XdsLoadStatsStore and its corresponding implementation is XdsLoadStatsStoreImpl.
- Revised/reworded specification for XdsLoadStatsStore.
* Cleaned up ClientLoadCounter specification.
Reworded specification for ClientLoadCounter
* Cleaned up XdsLoadReportClient, reworded specifications, formatted tests.
* Removed Xds prefix from LoadStatsStore.
* Removed Xds prefix from XdsLoadReportClient.
In case a negotiating handler misses a read, and it reaches the WBAEH, it should cause a failure. Also, if closing the channel fails while handling another error, log the second failure.
* augmented xds child balancer helper with orcaOobReportingHelperWrapper and added an interface method in LocalityStore for updating out-of-band backend metrics reporting interval
* added an callback for passing load reporting interval received from lrs response to xDS load balancer, thus, LocalityStore for configuring OOB backend metrics reporting
* moved XdsLoadReportCallback interface into XdsLoadReportClient
* Redefined StatsStore interface.
- Removed interface method StatsStore#interceptPickResult and implementation do not take the resposibility intercepting PickResult with locality-level load recording.
- Introduce a wrapper class for SubchannelPicker to let users wrap SubchannelPicker by themselves, with client side load recording logic.
- Associate the corresponding locality counter with child helper when it is created, child helper will intercept the SubchannelPicker it creates.
* Renamed backend metrics listener class to be more abstract, hides the implementation detail of doing locality-level aggregation.
* Integrate client load recording and backend metrics recording with xDS load balancer.
- Created LoadRecordingSubchannelPicker class for applying XdsClientLoadRecorder that records client load to PickResult.
- Created MetricsObservingSubchannel class for applying OrcaReportingTracerFactory that takes listener to receive ORCA reports to PickResult.
- In xDS load balancer LocalityStore, the original picker is wrapped two layers inside the above wrappers.
* Renamed XdsClientLoadRecorder to ClientLoadRecorder. It should only be used for testing, xDS load balancer should use SubchannelPicker wrappers instead of this load recorder directly.
* Removed redudent layer of wrapping for SubchannelPicker in LocalityStore
* Added toString for SubchannelPicker wrapper classes.
* Rename ClientLoadRecorder to LoadRecordingStreamTracerFactory.
* Renamed StreamInstrumentedSubchannelPicker to TracerWrappingSubchannelPicker.
* Eliminate duplicated code in LocalityStoreTest, put them into a loop.
We only care about when closing is done, not whether it is successful or not.
If there's a failure, we're already going to log a warning. Use await to avoid
throwing unexpectedly.
Works for #4740
- Subclasses of `AbstractClientStream` include remote address in insight if available.
- `DelayedStream` adds buffered time, and the insight of real stream if it's set.
- `RetriableStream` insights outputs of Substreams.
Example error message:
```
deadline exceeded after 8112071ns. [buffered_nanos=24763, remote_addr=foo.test.google.fr/127.0.0.1:44749]
```
or
```
deadline exceeded after 8112071ns. [buffered_nanos=22344324763, waiting_for_connection]
```
This is related to #4776 but taking a more usage-specific approach.
In #5892 getAttributes() is called without any regard of timing.
Currently DelayedStream.getAttributes() wil throw if called before
passThrough was set. Just to be safe, we are removing that
restriction and making it clear on the javadoc.
On the other hand, we intend to keep the timing restriction on
ClientCall.getAttributes().
Maven does not include transitive runtime dependencies in the
compile-time classpath (testing shows Gradle 4 does; docs say
Gradle 5 doesn't). So if a user references the shaded
NettyServerBuilder without also depending on grpc-core directly,
compilation will fail because AbstractServerImplBuilder couldn't
be found.
This isn't technically a problem, since we're not wanting to encourage
users to reference the shaded classes directly. But some users will
certainly reference the classes anyway and the error is pretty confusing
while also being trivially worked around. In other words: it justs
wastes people's time and benefits nobody.
Fixes#5881
This change is needed after trying to use the new style protocol negotiators internally. The problem is that some handlers fire the event in handlerAdded, which is too early. The followup PNE is fired after handlerAdded, which breaks the composibility of the negotiators.
To fix this, this change modifies the negotiation flow. Specifically:
* Negotiators should NEVER fire a negotiation from handlerAdded, instead they should wait until userEventTriggered
* Negotiators now do state checking on the PNE. If it is set twice, it fails. If it has not been received when doing the next stage of negotiation, it fails.
* WBAEH now fires the initial, default event. This is the only handler that can fire it from handlerAdded
The tests updated are ones not using WBAEH (which they probably should). This change ensures attributes aren't lost when doing negotiation.
This change removes the WriteQueue linking and splits it out into each
of the commands, so that the trace is more precise, and the tag
information is correct.
It is still unclear what the initial Tag should be for ClientCallImpl,
since it should not access the TransportState to get the HTTP/2 stream id.
The issue: HealthCheckingLoadBalancer.shutdown() calls
hcState.onSubchannelState(SHUTDOWN) which removes that hcState from
helper.hcStates. Therefore, if more than one Subchannels are present,
ConcurrentModificationException will be thrown.
This is an alternative approach from #5848 that was reverted in #5875. Thanks to #5883, HealthCheckingLoadBalancer.shutdown() no longer has to fake SHUTDOWN notifications, and can completely rely on Subchannels' real SHUTDOWN notifications for triggering the clean-up.
This reverts commit e795f14bed. It breaks some of
our internal tests. At the very least the cast fails because we are reusing the
service for something without going through the normal stub. There may also
have been a test hang, but it'd take more effort to figure out.
No more methods on the `LoadBalancer` will be called after
`LoadBalancer#shutdown()` is called. This includes
`LoadBalancer#handleSubchannelState()` too. `SubchannelStateListener`
inherited this restriction. However, this special case makes
`onSubchannelState(SHUTDOWN)` an unreliable way of being notified
about `Subchannel` SHUTDOWN, and may confuse/complicate a
wrapping `LoadBalancer` that expects the full notification (e.g., #5875).
The javadoc isn't clear whether this restriction applies. I think
it's more useful to make it no apply.
We were logging when withDeadline() was used, not when the Context was used. As
discovered while looking at https://stackoverflow.com/q/56593692/4690866 .
In e19e8f7d updateTimeoutHeaders was removed and logIfContextNarrowedTimeout
was called directly. However, the two methods had reverse ordering of
callDeadine/outerCallDeadline and the caller did not get their arguments
swapped.
* fixed bug of intercepting a PickResult with no Subchannel, it should just return the original PickResult. Also, the test was not correct, fixed it.
* changed ClientLoadCounter to a mock in XdsLoadStatsStoreTest, it's not necessary to instantiate a real instance.
* added a TODO comment for suggesting a warning for desired locality counter missing when intercepting a PickResult
* use isSameInstanceAs for verifying intercepting invalid PickResult instead of isEqualTo.
panic mode was temporarily disabled by #4152 and re-enabled by #4245,
but the tests were not. This has caused a few test code that was
broken but not executed at all.
This reverts commit c6f15162ff. It broke
an internal health checking test because the server wouldn't shut down.
We assume the health checking RPC isn't getting closed.
* integrate recordDropRequest in LocalityStore
* integrated StatsStore#addLocality and StatsStore#removeLocality in LocalityStore in handling EDS response.
* integrated picker interception in LocalityStore
* integrate XdsLoadReportClient in XdsLoadBalancer
* put removing locality counters after updating subchannl pickers to narrow down race window
* fixed modifier for XdsLoadReportClientFactory
* refactor handleNewConfig method in XdsLoadBalancer for better readability
* edited message for closing lb rpc when balancer name changes
* weaker the specification of XdsLoadReportClient to allow start/stop be called multiple times.
* removed lrsWorking flag as we relaxed precondition of calling start/stop on XdsLoadReportClient
* refactor initLbChannel to be a factory method for better readability
* added comment for the case when child policy changes, lrs should not be affected
* changed comments for eliminating potential load lose upon locality update.
* make lb RPC cancellation message more informative
Transport level exceptions (e.g. "Connection reset by peer") are not
useful and clutter the logs. `NettyServerTransport` contains logic to
log such exceptions at level `FINE`.
When running with epoll, transport level exceptions are prefixed with
additional contextual information (e.g. "syscall:read(..) failed:") that
causes the exceptions to be logged at level `INFO`.
Update the filtering logic to match on error messages _containing_ the
blacklisted messages, rather than using string equality.
Closes#5872.
Signed-off-by: Nick Travers <n.e.travers@gmail.com>
gRPC issues flushes after close in the WriteQueue, which can show up as an NPE in the framer. This was thought to have been handled, by checking to see if there were any pending writes, but if the close() call gets far enough, the writes will be null. This causes an NPE when the flush comes though.
The issue is difficult to reproduce, and I think my test case emulates the failure. EmbeddedChannel is different than the normal Channels we use, making the precise ordering tough. The test case isn't exactly what the production code would do, but it does have the same ordering.
cc @jiangtaoli2016
Sample Stack trace:
```
Jun 10, 2019 2:09:03 PM io.grpc.ChannelLogger log
FINEST: [OobChannel<10>] Entering SHUTDOWN state
Jun 10, 2019 2:09:03 PM io.grpc.ChannelLogger log
FINEST: [Subchannel-OOB<11>: (fake-authority-that-is-always-the-same)] NettyClientTransport<14>: (/0:0:0:0:0:0:0:1:20008) SHUTDOWN with UNAVAILABLE(OobChannel is shutdown)
Jun 10, 2019 2:09:03 PM io.grpc.netty.NettyClientHandler close
FINE: Network channel being closed by the application.
Jun 10, 2019 2:09:03 PM io.grpc.internal.ClientCallImpl logIfContextNarrowedTimeout
FINE: Call timeout set to '4999299080' ns, due to context deadline. Explicit call timeout was not set.
Jun 10, 2019 2:09:03 PM io.netty.handler.codec.http2.Http2FrameLogger logGoAway
FINE: [id: 0x4bcebba6, L:/0:0:0:0:0:0:0:1:33296 - R:/0:0:0:0:0:0:0:1:20008] OUTBOUND GO_AWAY: lastStreamId=0 errorCode=0 length=0 bytes=
Jun 10, 2019 2:09:03 PM io.grpc.netty.NettyClientHandler onConnectionError
FINE: Caught a connection error
java.lang.NullPointerException
at io.grpc.alts.internal.TsiFrameHandler.flush(TsiFrameHandler.java:126)
at io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:754)
at io.netty.channel.AbstractChannelHandlerContext.invokeFlush(AbstractChannelHandlerContext.java:746)
at io.netty.channel.AbstractChannelHandlerContext.flush(AbstractChannelHandlerContext.java:732)
at io.netty.handler.codec.http2.Http2ConnectionHandler.flush(Http2ConnectionHandler.java:201)
at io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:754)
at io.netty.channel.AbstractChannelHandlerContext.invokeFlush(AbstractChannelHandlerContext.java:746)
at io.netty.channel.AbstractChannelHandlerContext.flush(AbstractChannelHandlerContext.java:732)
at io.netty.channel.DefaultChannelPipeline.flush(DefaultChannelPipeline.java:978)
at io.netty.channel.AbstractChannel.flush(AbstractChannel.java:253)
at io.grpc.netty.WriteQueue.flush(WriteQueue.java:124)
at io.grpc.netty.WriteQueue.access$000(WriteQueue.java:32)
at io.grpc.netty.WriteQueue$1.run(WriteQueue.java:44)
at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:163)
at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:405)
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:500)
at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:906)
at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
at java.lang.Thread.run(Thread.java:748)
Jun 10, 2019 2:09:03 PM io.netty.channel.AbstractChannelHandlerContext notifyHandlerException
WARNING: An exception was thrown by a user handler while handling an exceptionCaught event
java.lang.NullPointerException
at io.grpc.alts.internal.TsiFrameHandler.flush(TsiFrameHandler.java:126)
at io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:754)
at io.netty.channel.AbstractChannelHandlerContext.invokeFlush(AbstractChannelHandlerContext.java:746)
at io.netty.channel.AbstractChannelHandlerContext.flush(AbstractChannelHandlerContext.java:732)
at io.netty.handler.codec.http2.Http2ConnectionHandler.onError(Http2ConnectionHandler.java:629)
at io.grpc.netty.AbstractNettyHandler.exceptionCaught(AbstractNettyHandler.java:81)
at io.netty.channel.AbstractChannelHandlerContext.invokeExceptionCaught(AbstractChannelHandlerContext.java:297)
at io.netty.channel.AbstractChannelHandlerContext.invokeExceptionCaught(AbstractChannelHandlerContext.java:276)
at io.netty.channel.AbstractChannelHandlerContext.fireExceptionCaught(AbstractChannelHandlerContext.java:268)
at io.netty.channel.ChannelInboundHandlerAdapter.exceptionCaught(ChannelInboundHandlerAdapter.java:143)
at io.netty.channel.AbstractChannelHandlerContext.invokeExceptionCaught(AbstractChannelHandlerContext.java:297)
at io.netty.channel.AbstractChannelHandlerContext.notifyHandlerException(AbstractChannelHandlerContext.java:836)
at io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:756)
at io.netty.channel.AbstractChannelHandlerContext.invokeFlush(AbstractChannelHandlerContext.java:746)
at io.netty.channel.AbstractChannelHandlerContext.flush(AbstractChannelHandlerContext.java:732)
at io.netty.handler.codec.http2.Http2ConnectionHandler.flush(Http2ConnectionHandler.java:201)
at io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:754)
at io.netty.channel.AbstractChannelHandlerContext.invokeFlush(AbstractChannelHandlerContext.java:746)
at io.netty.channel.AbstractChannelHandlerContext.flush(AbstractChannelHandlerContext.java:732)
at io.netty.channel.DefaultChannelPipeline.flush(DefaultChannelPipeline.java:978)
at io.netty.channel.AbstractChannel.flush(AbstractChannel.java:253)
at io.grpc.netty.WriteQueue.flush(WriteQueue.java:124)
at io.grpc.netty.WriteQueue.access$000(WriteQueue.java:32)
at io.grpc.netty.WriteQueue$1.run(WriteQueue.java:44)
at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:163)
at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:405)
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:500)
at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:906)
at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
at java.lang.Thread.run(Thread.java:748)
Jun 10, 2019 2:09:03 PM io.grpc.netty.NettyClientHandler channelInactive
FINE: Network channel is closed
Jun 10, 2019 2:09:03 PM io.grpc.ChannelLogger log
FINEST: [Subchannel-OOB<11>: (fake-authority-that-is-always-the-same)] NettyClientTransport<14>: (/0:0:0:0:0:0:0:1:20008) Terminated
Jun 10, 2019 2:09:03 PM io.grpc.ChannelLogger log
FINEST: [Subchannel-OOB<11>: (fake-authority-that-is-always-the-same)] Terminated
```
Carl Mastrangelo
Chengyuan Zhang
ZHANG Dapeng
Jihun Cho
Zhaonian Luan
Eric Anderson
Kun Zhang
Nick Travers
Sebastian Schmidt