[CI] Failures in various sql tests due to ZoneRulesException: Unknown time-zone ID: Asia/Qostanay

[astefan]

Build scan: multiple. One of them https://gradle-enterprise.elastic.co/s/b5joeiwm33tdm

Repro line:

./gradlew ':x-pack:plugin:sql:qa:single-node:integTestRunner' \
  -Dtests.seed=28FE821C9735C914 \
  -Dtests.class=org.elasticsearch.xpack.sql.qa.single_node.JdbcResultSetIT \
  -Dtests.method="testNoInfiniteRecursiveGetObjectCalls" \
  -Dtests.security.manager=true \
  -Dtests.locale=ja-JP-u-ca-japanese-x-lvariant-JP \
  -Dtests.timezone=Africa/Porto-Novo \
  -Dcompiler.java=11 \
  -Druntime.java=8

Reproduces locally?: no

Applicable branches: 6.8

Failure history: started failing on May 11th.

Failure excerpt:

00:26:33 ERROR   0.12s | JdbcResultSetIT.testGettingInvalidLong <<< FAILURES!
00:26:33    > Throwable #1: java.sql.SQLException: Server sent bad type [x_content_parse_exception]. Original type was [[1:57] [sql/query] failed to parse field [time_zone]]. [org.elasticsearch.common.xcontent.XContentParseException: [1:57] [sql/query] failed to parse field [time_zone]
00:26:33    > 	at org.elasticsearch.common.xcontent.ObjectParser.parseValue(ObjectParser.java:316)
00:26:33    > 	at org.elasticsearch.common.xcontent.ObjectParser.parseSub(ObjectParser.java:362)
00:26:33    > 	at org.elasticsearch.common.xcontent.ObjectParser.parse(ObjectParser.java:168)
00:26:33    > 	at org.elasticsearch.common.xcontent.ObjectParser.apply(ObjectParser.java:182)
00:26:33    > 	at org.elasticsearch.xpack.sql.action.SqlQueryRequest.fromXContent(SqlQueryRequest.java:135)
00:26:33    > 	at org.elasticsearch.xpack.sql.plugin.RestSqlQueryAction.prepareRequest(RestSqlQueryAction.java:46)
00:26:33    > 	at org.elasticsearch.rest.BaseRestHandler.handleRequest(BaseRestHandler.java:91)
00:26:33    > 	at org.elasticsearch.rest.RestController.dispatchRequest(RestController.java:240)
00:26:33    > 	at org.elasticsearch.rest.RestController.tryAllHandlers(RestController.java:336)
00:26:33    > 	at org.elasticsearch.rest.RestController.dispatchRequest(RestController.java:174)
00:26:33    > 	at org.elasticsearch.http.netty4.Netty4HttpServerTransport.dispatchRequest(Netty4HttpServerTransport.java:551)
00:26:33    > 	at org.elasticsearch.http.netty4.Netty4HttpRequestHandler.channelRead0(Netty4HttpRequestHandler.java:137)
00:26:33    > 	at io.netty.channel.SimpleChannelInboundHandler.channelRead(SimpleChannelInboundHandler.java:105)
00:26:33    > 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
00:26:33    > 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
00:26:33    > 	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
00:26:33    > 	at org.elasticsearch.http.netty4.pipelining.HttpPipeliningHandler.channelRead(HttpPipeliningHandler.java:68)
00:26:33    > 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
00:26:33    > 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
00:26:33    > 	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
00:26:33    > 	at io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:102)
00:26:33    > 	at io.netty.handler.codec.MessageToMessageCodec.channelRead(MessageToMessageCodec.java:111)
00:26:33    > 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
00:26:33    > 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
00:26:33    > 	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
00:26:33    > 	at io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:102)
00:26:33    > 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
00:26:33    > 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
00:26:33    > 	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
00:26:33    > 	at io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:102)
00:26:33    > 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
00:26:33    > 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
00:26:33    > 	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
00:26:33    > 	at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:323)
00:26:33    > 	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:297)
00:26:33    > 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
00:26:33    > 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
00:26:33    > 	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
00:26:33    > 	at io.netty.handler.timeout.IdleStateHandler.channelRead(IdleStateHandler.java:286)
00:26:33    > 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
00:26:33    > 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
00:26:33    > 	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
00:26:33    > 	at io.netty.channel.ChannelInboundHandlerAdapter.channelRead(ChannelInboundHandlerAdapter.java:86)
00:26:33    > 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
00:26:33    > 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
00:26:33    > 	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
00:26:33    > 	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1434)
00:26:33    > 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
00:26:33    > 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
00:26:33    > 	at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:965)
00:26:33    > 	at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:163)
00:26:33    > 	at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:656)
00:26:33    > 	at io.netty.channel.nio.NioEventLoop.processSelectedKeysPlain(NioEventLoop.java:556)
00:26:33    > 	at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:510)
00:26:33    > 	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:470)
00:26:33    > 	at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:909)
00:26:33    > 	at java.base/java.lang.Thread.run(Thread.java:834)
00:26:33    > Caused by: java.time.zone.ZoneRulesException: Unknown time-zone ID: Asia/Qostanay
00:26:33    > 	at java.base/java.time.zone.ZoneRulesProvider.getProvider(ZoneRulesProvider.java:279)
00:26:33    > 	at java.base/java.time.zone.ZoneRulesProvider.getRules(ZoneRulesProvider.java:234)
00:26:33    > 	at java.base/java.time.ZoneRegion.ofId(ZoneRegion.java:120)
00:26:33    > 	at java.base/java.time.ZoneId.of(ZoneId.java:408)
00:26:33    > 	at java.base/java.time.ZoneId.of(ZoneId.java:356)
00:26:33    > 	at org.elasticsearch.xpack.sql.action.AbstractSqlQueryRequest.lambda$objectParser$3(AbstractSqlQueryRequest.java:79)
00:26:33    > 	at org.elasticsearch.common.xcontent.ObjectParser.lambda$declareField$1(ObjectParser.java:213)
00:26:33    > 	at org.elasticsearch.common.xcontent.ObjectParser.parseValue(ObjectParser.java:314)
00:26:33    > 	... 56 more

[elasticmachine]

Pinging @elastic/es-ql (Team:QL)

[astefan]

Managed to reproduce this one. It's all about the java version.

Compiler JDK Version  : 11 (18.9 11.0.2 [OpenJDK 64-Bit Server VM 11.0.2+7])
23:48:35   Compiler java.home    : /var/lib/jenkins/.java/openjdk-11.0.2-linux
23:48:35   Runtime JDK Version   : 1.8 (Oracle Corporation 1.8.0_281 [Java HotSpot(TM) 64-Bit Server VM 25.281-b09])
23:48:35   Runtime java.home     : /var/lib/jenkins/.java/java8
23:48:35   Gradle JDK Version    : 11 (18.9 11.0.2 [OpenJDK 64-Bit Server VM 11.0.2+7])
23:48:35   Gradle java.home      : /var/lib/jenkins/.java/openjdk-11.0.2-linux

According to #72490 the Joda version has been updated two days ago to 2.10.10 and the Java 11 version used in CI doesn't seem to be the latest one. With 11.0.11 the issue doesn't reproduce for me.
Looking at the tzdata updates over time https://www.oracle.com/java/technologies/tzdata-versions.html:

tzdata2018h
2018/12/23

...
New zone Asia/Qostanay because Qostanay, Kazakhstan didn't move.
....

If I'm not mistaken this update ^ went into 11.0.4 which is consistent with the behavior I see in this test: 11.0.2 complains that Asia/Qostanay is not a recognized timezone while 11.0.11 doesn't.
@mark-vieira can you, please, double check the Java 11 CI version we use for tests?

[astefan]

Relates to #72963.

[astefan]

Also, the local test that fails on my machine show these logs:

[2021-05-12T12:19:48,114][INFO ][o.e.e.NodeEnvironment    ] [node-0] using [1] data paths, mounts [[Work (D:)]], net usable_space [373.8gb], net total_space [553.8gb], types [NTFS]
[2021-05-12T12:19:48,116][INFO ][o.e.e.NodeEnvironment    ] [node-0] heap size [494.9mb], compressed ordinary object pointers [true]
[2021-05-12T12:19:48,118][INFO ][o.e.n.Node               ] [node-0] node name [node-0], node ID [l6xZV3O8QguSV_6LGuzU7Q]
[2021-05-12T12:19:48,118][INFO ][o.e.n.Node               ] [node-0] version[6.8.16-SNAPSHOT], pid[12516], build[default/zip/103f38c/2021-05-12T08:30:43.562157300Z], OS[Windows 10/10.0/amd64], JVM[Oracle Corporation/OpenJDK 64-Bit Server VM/11.0.2/11.0.2+9]
[2021-05-12T12:19:48,118][INFO ][o.e.n.Node               ] [node-0] JVM arguments [-Xms1g, -Xmx1g, -XX:+UseConcMarkSweepGC, -XX:CMSInitiatingOccupancyFraction=75, -XX:+UseCMSInitiatingOccupancyOnly, -Des.networkaddress.cache.ttl=60, -Des.networkaddress.cache.negative.ttl=10, -XX:+AlwaysPreTouch, -Xss1m, -Djava.awt.headless=true, -Dfile.encoding=UTF-8, -Djna.nosys=true, -XX:-OmitStackTraceInFastThrow, -Dio.netty.noUnsafe=true, -Dio.netty.noKeySetOptimization=true, -Dio.netty.recycler.maxCapacityPerThread=

The jvm being used is 11.0.2. The runtime jvm to be used in this test according to the reproduceable command -Druntime.java=8.

[mark-vieira]

Looks like we indeed were not correctly using RUNTIME_JAVA_HOME for external test clusters in the 6.8 branch. That has probably been the case for a long time 🤦

I've opened #73003 to fix that, but I'm not sure it'll necessarily fix the errors. Athough it at least with make the behavior consistent.

[mark-vieira]

Not surprisingly my PR picked up a different error. Since we've effectively not been testing against runtime javas properly for who knows how long, my fear is merging the "fix" will break countless other things. That said, if we do have incompatibilities we should probably find out.

https://gradle-enterprise.elastic.co/s/kjpid2amlnu5m/console-log?task=:x-pack:plugin:sql:qa:single-node:integTestRunner

[astefan]

@mark-vieira I've looked at that failure you mentioned. Its root cause is not ES SQL or even Elasticsearch specific imo, but JVM specific. The query that is failing is SELECT TAN(RADIANS(66)). Which is basically Math.tan(Math.toRadians(66)). I tested locally a simple java program running the previous Math formula. This is what I got:

java 1.8.0_291	java 13.0.2
2.246036773904215	2.2460367739042164

Which is surprising given that this has never been caught before. If we test ES on 1.8, both runtime and compilation, this failure should have been caught somehow. To me it looks like different Java behavior unless I'm missing something.

[mark-vieira]

That's exactly the case. We've only been running integration test clusters using the Gradle JDK (11). So no, we wouldn't have caught it until the fix in that PR.

[astefan]

Then how about upgrading jdk 11 (and all other JDKs) to the latest, which should have been the like this in the first place?

[mark-vieira]

I'll reach out to infra to see why these aren't being regularly updated. For some reason it's still 11.0.2.

https://jvm-catalog.elastic.co/jdk/latest_openjdk_11_linux