REST test `p0=snapshot.get_repository/10_basic/Verify created repository` fails mixed cluster tests

[colings86]

build URL: https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+master+intake/1956/consoleFull

This test is failing regularly on the master branch.

Reproduce command:

./gradlew :qa:mixed-cluster:v6.4.0-SNAPSHOT#mixedClusterTestRunner -Dtests.seed=73CB2113C56667F8 -Dtests.class=org.elasticsearch.backwards.MixedClusterClientYamlTestSuiteIT -Dtests.method="test {p0=snapshot.get_repository/10_basic/Verify created repository}" -Dtests.security.manager=true -Dtests.locale=ar-SA -Dtests.timezone=America/Goose_Bay

This looks like a bwc serialisation issue as it seems that the stream is not being fully read. Possibly due to a8cea90 ?

Failure stack trace:

07:52:38   1> [2018-05-23T04:51:16,260][INFO ][o.e.b.MixedClusterClientYamlTestSuiteIT] Stash dump on test failure [{
07:52:38   1>   "stash" : {
07:52:38   1>     "body" : {
07:52:38   1>       "error" : {
07:52:38   1>         "root_cause" : [
07:52:38   1>           {
07:52:38   1>             "type" : "transport_serialization_exception",
07:52:38   1>             "reason" : "Failed to deserialize response from handler [org.elasticsearch.transport.TransportService$ContextRestoreResponseHandler]",
07:52:38   1>             "stack_trace" : "TransportSerializationException[Failed to deserialize response from handler [org.elasticsearch.transport.TransportService$ContextRestoreResponseHandler]]; nested: EOFException[tried to read: 101 bytes but only 62 remaining];
07:52:38   1> 	at org.elasticsearch.transport.TcpTransport.handleResponse(TcpTransport.java:1430)
07:52:38   1> 	at org.elasticsearch.transport.TcpTransport.messageReceived(TcpTransport.java:1389)
07:52:38   1> 	at org.elasticsearch.transport.netty4.Netty4MessageChannelHandler.channelRead(Netty4MessageChannelHandler.java:64)
07:52:38   1> 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
07:52:38   1> 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
07:52:38   1> 	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
07:52:38   1> 	at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:310)
07:52:38   1> 	at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:297)
07:52:38   1> 	at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:413)
07:52:38   1> 	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:265)
07:52:38   1> 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
07:52:38   1> 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
07:52:38   1> 	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
07:52:38   1> 	at io.netty.handler.logging.LoggingHandler.channelRead(LoggingHandler.java:241)
07:52:38   1> 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
07:52:38   1> 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
07:52:38   1> 	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
07:52:38   1> 	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1359)
07:52:38   1> 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
07:52:38   1> 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
07:52:38   1> 	at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:935)
07:52:38   1> 	at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:134)
07:52:38   1> 	at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:645)
07:52:38   1> 	at io.netty.channel.nio.NioEventLoop.processSelectedKeysPlain(NioEventLoop.java:545)
07:52:38   1> 	at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:499)
07:52:38   1> 	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:459)
07:52:38   1> 	at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858)
07:52:38   1> 	at java.base/java.lang.Thread.run(Thread.java:844)
07:52:38   1> Caused by: java.io.EOFException: tried to read: 101 bytes but only 62 remaining
07:52:38   1> 	at org.elasticsearch.transport.netty4.ByteBufStreamInput.ensureCanReadBytes(ByteBufStreamInput.java:75)
07:52:38   1> 	at org.elasticsearch.common.io.stream.FilterStreamInput.ensureCanReadBytes(FilterStreamInput.java:80)
07:52:38   1> 	at org.elasticsearch.common.io.stream.StreamInput.readArraySize(StreamInput.java:1010)
07:52:38   1> 	at org.elasticsearch.common.io.stream.StreamInput.readString(StreamInput.java:373)
07:52:38   1> 	at org.elasticsearch.cluster.node.DiscoveryNode.<init>(DiscoveryNode.java:221)
07:52:38   1> 	at org.elasticsearch.action.admin.cluster.repositories.verify.VerifyRepositoryResponse.readFrom(VerifyRepositoryResponse.java:57)
07:52:38   1> 	at org.elasticsearch.transport.TransportResponseHandler.read(TransportResponseHandler.java:47)
07:52:38   1> 	at org.elasticsearch.transport.TransportService$ContextRestoreResponseHandler.read(TransportService.java:1082)
07:52:38   1> 	at org.elasticsearch.transport.TcpTransport.handleResponse(TcpTransport.java:1426)
07:52:38   1> 	... 27 more
07:52:38   1> "
07:52:38   1>           }
07:52:38   1>         ],
07:52:38   1>         "type" : "transport_serialization_exception",
07:52:38   1>         "reason" : "Failed to deserialize response from handler [org.elasticsearch.transport.TransportService$ContextRestoreResponseHandler]",
07:52:38   1>         "caused_by" : {
07:52:38   1>           "type" : "e_o_f_exception",
07:52:38   1>           "reason" : "tried to read: 101 bytes but only 62 remaining",
07:52:38   1>           "stack_trace" : "java.io.EOFException: tried to read: 101 bytes but only 62 remaining
07:52:38   1> 	at org.elasticsearch.transport.netty4.ByteBufStreamInput.ensureCanReadBytes(ByteBufStreamInput.java:75)
07:52:38   1> 	at org.elasticsearch.common.io.stream.FilterStreamInput.ensureCanReadBytes(FilterStreamInput.java:80)
07:52:38   1> 	at org.elasticsearch.common.io.stream.StreamInput.readArraySize(StreamInput.java:1010)
07:52:38   1> 	at org.elasticsearch.common.io.stream.StreamInput.readString(StreamInput.java:373)
07:52:38   1> 	at org.elasticsearch.cluster.node.DiscoveryNode.<init>(DiscoveryNode.java:221)
07:52:38   1> 	at org.elasticsearch.action.admin.cluster.repositories.verify.VerifyRepositoryResponse.readFrom(VerifyRepositoryResponse.java:57)
07:52:38   1> 	at org.elasticsearch.transport.TransportResponseHandler.read(TransportResponseHandler.java:47)
07:52:38   1> 	at org.elasticsearch.transport.TransportService$ContextRestoreResponseHandler.read(TransportService.java:1082)
07:52:38   1> 	at org.elasticsearch.transport.TcpTransport.handleResponse(TcpTransport.java:1426)
07:52:38   1> 	at org.elasticsearch.transport.TcpTransport.messageReceived(TcpTransport.java:1389)
07:52:38   1> 	at org.elasticsearch.transport.netty4.Netty4MessageChannelHandler.channelRead(Netty4MessageChannelHandler.java:64)
07:52:38   1> 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
07:52:38   1> 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
07:52:38   1> 	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
07:52:38   1> 	at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:310)
07:52:38   1> 	at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:297)
07:52:38   1> 	at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:413)
07:52:38   1> 	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:265)
07:52:38   1> 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
07:52:38   1> 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
07:52:38   1> 	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
07:52:38   1> 	at io.netty.handler.logging.LoggingHandler.channelRead(LoggingHandler.java:241)
07:52:38   1> 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
07:52:38   1> 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
07:52:38   1> 	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
07:52:38   1> 	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1359)
07:52:38   1> 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
07:52:38   1> 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
07:52:38   1> 	at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:935)
07:52:38   1> 	at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:134)
07:52:38   1> 	at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:645)
07:52:38   1> 	at io.netty.channel.nio.NioEventLoop.processSelectedKeysPlain(NioEventLoop.java:545)
07:52:38   1> 	at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:499)
07:52:38   1> 	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:459)
07:52:38   1> 	at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858)
07:52:38   1> 	at java.base/java.lang.Thread.run(Thread.java:844)
07:52:38   1> "
07:52:38   1>         },
07:52:38   1>         "stack_trace" : "TransportSerializationException[Failed to deserialize response from handler [org.elasticsearch.transport.TransportService$ContextRestoreResponseHandler]]; nested: EOFException[tried to read: 101 bytes but only 62 remaining];
07:52:38   1> 	at org.elasticsearch.transport.TcpTransport.handleResponse(TcpTransport.java:1430)
07:52:38   1> 	at org.elasticsearch.transport.TcpTransport.messageReceived(TcpTransport.java:1389)
07:52:38   1> 	at org.elasticsearch.transport.netty4.Netty4MessageChannelHandler.channelRead(Netty4MessageChannelHandler.java:64)
07:52:38   1> 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
07:52:38   1> 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
07:52:38   1> 	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
07:52:38   1> 	at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:310)
07:52:38   1> 	at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:297)
07:52:38   1> 	at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:413)
07:52:38   1> 	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:265)
07:52:38   1> 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
07:52:38   1> 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
07:52:38   1> 	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
07:52:38   1> 	at io.netty.handler.logging.LoggingHandler.channelRead(LoggingHandler.java:241)
07:52:38   1> 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
07:52:38   1> 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
07:52:38   1> 	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
07:52:38   1> 	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1359)
07:52:38   1> 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
07:52:38   1> 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
07:52:38   1> 	at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:935)
07:52:38   1> 	at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:134)
07:52:38   1> 	at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:645)
07:52:38   1> 	at io.netty.channel.nio.NioEventLoop.processSelectedKeysPlain(NioEventLoop.java:545)
07:52:38   1> 	at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:499)
07:52:38   1> 	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:459)
07:52:38   1> 	at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858)
07:52:38   1> 	at java.base/java.lang.Thread.run(Thread.java:844)
07:52:38   1> Caused by: java.io.EOFException: tried to read: 101 bytes but only 62 remaining
07:52:38   1> 	at org.elasticsearch.transport.netty4.ByteBufStreamInput.ensureCanReadBytes(ByteBufStreamInput.java:75)
07:52:38   1> 	at org.elasticsearch.common.io.stream.FilterStreamInput.ensureCanReadBytes(FilterStreamInput.java:80)
07:52:38   1> 	at org.elasticsearch.common.io.stream.StreamInput.readArraySize(StreamInput.java:1010)
07:52:38   1> 	at org.elasticsearch.common.io.stream.StreamInput.readString(StreamInput.java:373)
07:52:38   1> 	at org.elasticsearch.cluster.node.DiscoveryNode.<init>(DiscoveryNode.java:221)
07:52:38   1> 	at org.elasticsearch.action.admin.cluster.repositories.verify.VerifyRepositoryResponse.readFrom(VerifyRepositoryResponse.java:57)
07:52:38   1> 	at org.elasticsearch.transport.TransportResponseHandler.read(TransportResponseHandler.java:47)
07:52:38   1> 	at org.elasticsearch.transport.TransportService$ContextRestoreResponseHandler.read(TransportService.java:1082)
07:52:38   1> 	at org.elasticsearch.transport.TcpTransport.handleResponse(TcpTransport.java:1426)
07:52:38   1> 	... 27 more
07:52:38   1> "
07:52:38   1>       },
07:52:38   1>       "status" : 500
07:52:38   1>     }
07:52:38   1>   }
07:52:38   1> }]

[droberts195]

This is still failing on the master branch with a similar, but not identical, error.

For example, in https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+master+intake/1976/consoleText we have:

  1> [2018-05-25T21:23:17,142][INFO ][o.e.b.MixedClusterClientYamlTestSuiteIT] Stash dump on test failure [{
  1>   "stash" : {
  1>     "body" : {
  1>       "error" : {
  1>         "root_cause" : [
  1>           {
  1>             "type" : "transport_serialization_exception",
  1>             "reason" : "Failed to deserialize response from handler [org.elasticsearch.transport.TransportService$ContextRestoreResponseHandler]",
  1>             "stack_trace" : "TransportSerializationException[Failed to deserialize response from handler [org.elasticsearch.transport.TransportService$ContextRestoreResponseHandler]]; nested: EOFException[tried to read: 111 bytes but only 43 remaining];
  1> 	at org.elasticsearch.transport.TcpTransport.handleResponse(TcpTransport.java:1502)
  1> 	at org.elasticsearch.transport.TcpTransport.messageReceived(TcpTransport.java:1461)
  1> 	at org.elasticsearch.transport.netty4.Netty4MessageChannelHandler.channelRead(Netty4MessageChannelHandler.java:63)
  1> 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
  1> 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
  1> 	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
  1> 	at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:310)
  1> 	at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:297)
  1> 	at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:413)
  1> 	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:265)
  1> 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
  1> 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
  1> 	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
  1> 	at io.netty.handler.logging.LoggingHandler.channelRead(LoggingHandler.java:241)
  1> 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
  1> 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
  1> 	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
  1> 	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1359)
  1> 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
  1> 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
  1> 	at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:935)
  1> 	at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:134)
  1> 	at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:645)
  1> 	at io.netty.channel.nio.NioEventLoop.processSelectedKeysPlain(NioEventLoop.java:545)
  1> 	at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:499)
  1> 	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:459)
  1> 	at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858)
  1> 	at java.base/java.lang.Thread.run(Thread.java:844)
  1> Caused by: java.io.EOFException: tried to read: 111 bytes but only 43 remaining
  1> 	at org.elasticsearch.transport.netty4.ByteBufStreamInput.ensureCanReadBytes(ByteBufStreamInput.java:75)
  1> 	at org.elasticsearch.common.io.stream.FilterStreamInput.ensureCanReadBytes(FilterStreamInput.java:80)
  1> 	at org.elasticsearch.common.io.stream.StreamInput.readArraySize(StreamInput.java:1005)
  1> 	at org.elasticsearch.common.io.stream.StreamInput.readString(StreamInput.java:373)
  1> 	at org.elasticsearch.cluster.node.DiscoveryNode.<init>(DiscoveryNode.java:221)
  1> 	at org.elasticsearch.common.io.stream.StreamInput.readList(StreamInput.java:938)
  1> 	at org.elasticsearch.action.admin.cluster.repositories.verify.VerifyRepositoryResponse.readFrom(VerifyRepositoryResponse.java:147)
  1> 	at org.elasticsearch.transport.TransportResponseHandler.read(TransportResponseHandler.java:47)
  1> 	at org.elasticsearch.transport.TransportService$ContextRestoreResponseHandler.read(TransportService.java:1082)
  1> 	at org.elasticsearch.transport.TcpTransport.handleResponse(TcpTransport.java:1498)
  1> 	... 27 more
  1> "
  1>           }
  1>         ],

I will re-mute the test.

[droberts195]

I suspect the problem is that the master branch says the oldest version that has a nodes member in VerifyRepositoryResponse is 7.0.0-alpha1, but the 6.x branch says it is 6.4.0.

[hub-cap]

yea, i have an open PR to fix this, but it kept failing due to flaky tests... #30796 its waiting again for another CI run to pass, keep yer fingers crossed this time!

[hub-cap]

in hindsight i should have just left the test muted until all this went in.