[CI] GenerativeIT test failing

[elasticsearchmachine]

Build Scans:

• elasticsearch-periodic #10881 / openjdk24_checkpart3_java-matrix
• elasticsearch-pull-request #95338 / part-3
• elasticsearch-pull-request #95333 / part-3
• elasticsearch-pull-request #95323 / part-3
• elasticsearch-pull-request #95269 / part-3
• elasticsearch-pull-request #95228 / part-3
• elasticsearch-pull-request #95139 / part-3
• elasticsearch-pull-request #94810 / part-3
• elasticsearch-pull-request #94785 / part-3
• elasticsearch-pull-request #94730 / part-3

Reproduction Line:

./gradlew ":x-pack:plugin:esql:qa:server:single-node:javaRestTest" --tests "org.elasticsearch.xpack.esql.qa.single_node.GenerativeIT.test" -Dtests.seed=AA9A6A6B3863E1DE -Dtests.locale=lag-Latn-TZ -Dtests.timezone=America/Detroit -Druntime.java=24

Applicable branches:
main

Reproduces locally?:
N/A

Failure History:
See dashboard

Failure Message:

java.lang.AssertionError: query: from client_cidr* | SAMPLE 0.19568499805794204| rename env as message | lookup join message_types_lookup on message | limit 6070 | limit 10313 | dissect message "%{message} %{client_cidr}" | eval  `type` = null, `client_cidr` = false | sort message DESC NULLS LAST | grok message "%{WORD:message}" | limit 14642 | SAMPLE 0.43909259644136533 | SAMPLE 0.8497606742275678 | where  NOT false| rename message as message | lookup join message_types_lookup on message | FORK  (where  NOT false) (where  NOT false | grok message "%{WORD:type} %{WORD:message}"  | limit 11332) (where true) | WHERE _fork == "fork1" | DROP _fork | keep `message`, message, `client_cidr`
exception: method [POST], host [http://[::1]:42245], URI [/_query?format=json&pretty=true&error_trace=true], status line [HTTP/1.1 400 Bad Request]
{
  "error" : {
    "root_cause" : [
      {
        "type" : "verification_exception",
        "reason" : "Found 1 problem\nline -1:-1: Column [type] has conf
[truncated]

Issue Reasons:

• [main] 12 failures in test test (1.2% fail rate in 975 executions)
• [main] 11 failures in step part-3 (2.6% fail rate in 421 executions)
• [main] 11 failures in pipeline elasticsearch-pull-request (2.7% fail rate in 415 executions)

Note:
This issue was created using new test triage automation. Please report issues or feedback to es-delivery.

[elasticsearchmachine]

This has been muted on branch 9.1

Mute Reasons:

• [9.1] 3 failures in test test (0.7% fail rate in 401 executions)

Build Scans:

• elasticsearch-periodic-platform-support #10528 / oraclelinux-8_platform-support-unix
• elasticsearch-pull-request #90270 / part-3
• elasticsearch-intake #27985 / part3

[elasticsearchmachine]

Pinging @elastic/es-analytical-engine (Team:Analytics)

[astefan]

I've spent some time in trying to reproduce this failure. Using the repro line from the CI failures didn't bring any success. Also, this was on 9.1

So, I went back to main because it was easier for me to experiment and I added the following query to lookup-join.csv-spec:

specialTestFromGenerativeIT
from sample_d*,languages_mixed_numerics,apps
| rename language_code_byte as language_code
| lookup join languages_lookup on language_code
| rename id as language_code
| lookup join languages_lookup on language_code
| sort language_code_short DESC NULLS LAST, name ASC NULLS LAST, language_name
;

@timestamp:unsupported|client_ip:unsupported|event_duration:l| language_code:i | language_code_double:d | language_code_float:d  |language_code_half_float:d|language_code_integer:i| language_code_long:l |language_code_scaled_float:d|language_code_short:i|       message:keyword       |     name:keyword      |    version:version    | language_name:keyword 
null           |null           |null           |null           |32767.0               |32767.0               |32768.0                 |32767                |32767               |32767.0                   |32767              |null                 |null           |null           |null           
null           |null           |null           |null           |128.0                 |128.0                 |128.0                   |128                  |128                 |128.0                     |128                |null                 |null           |null           |null
;

Then I ran the test in series of 10 iterations like so:

gradlew :x-pack:plugin:esql:qa:server:multi-node:javaRestTest --tests "org.elasticsearch.xpack.esql.qa.multi_node.EsqlSpecIT" -Dtests.method="*SpecialTestFromGenerativeIT*" -Dtests.iters=10

Apart from the tests that fail because the order of the results is not right (the test above returns many more rows, but I added in this comment only two lines; I don't think it's relevant how many rows are returned), there are failures as reported in the original issue.

[2025-09-10T12:59:00,979][WARN ][o.e.x.e.a.EsqlResponseListener] [test-cluster-1] partial failure at path: /_query, params: {pretty=true, format=smile, error_trace=true} shard [[_na_][sample_data][0]], reason [java.lang.IllegalStateException: Found 1 problem
line 6:3: Plan [TopN[[Order[language_name{f}#72,ASC,LAST]],1000[INTEGER]]] optimized incorrectly due to missing references [language_name{f}#72]
	at org.elasticsearch.xpack.esql.optimizer.PostOptimizationPhasePlanVerifier.verify(PostOptimizationPhasePlanVerifier.java:44)
	at org.elasticsearch.xpack.esql.optimizer.LocalLogicalPlanOptimizer.localOptimize(LocalLogicalPlanOptimizer.java:93)
	at org.elasticsearch.xpack.esql.planner.PlannerUtils.lambda$localPlan$14(PlannerUtils.java:226)
	at org.elasticsearch.xpack.esql.core.tree.Node.lambda$transformUp$10(Node.java:238)
	at org.elasticsearch.xpack.esql.core.tree.Node.transformUp(Node.java:233)
	at org.elasticsearch.xpack.esql.core.tree.Node.lambda$transformUp$9(Node.java:231)
	at org.elasticsearch.xpack.esql.core.tree.Node.transformChildren(Node.java:256)
	at org.elasticsearch.xpack.esql.core.tree.Node.transformUp(Node.java:231)
	at org.elasticsearch.xpack.esql.core.tree.Node.transformUp(Node.java:238)
	at org.elasticsearch.xpack.esql.planner.PlannerUtils.localPlan(PlannerUtils.java:218)
	at org.elasticsearch.xpack.esql.planner.PlannerUtils.localPlan(PlannerUtils.java:203)
	at org.elasticsearch.xpack.esql.planner.PlannerUtils.localPlan(PlannerUtils.java:188)
	at org.elasticsearch.xpack.esql.plugin.ComputeService.runCompute(ComputeService.java:640)
	at org.elasticsearch.xpack.esql.plugin.DataNodeComputeHandler$DataNodeRequestExecutor.lambda$runBatch$4(DataNodeComputeHandler.java:332)
	at org.elasticsearch.server@9.2.0-SNAPSHOT/org.elasticsearch.action.ActionListener$2.onResponse(ActionListener.java:258)
	at org.elasticsearch.server@9.2.0-SNAPSHOT/org.elasticsearch.action.ActionRunnable$2.accept(ActionRunnable.java:58)
	at org.elasticsearch.server@9.2.0-SNAPSHOT/org.elasticsearch.action.ActionRunnable$2.accept(ActionRunnable.java:55)
	at org.elasticsearch.server@9.2.0-SNAPSHOT/org.elasticsearch.action.ActionRunnable$4.doRun(ActionRunnable.java:101)
	at org.elasticsearch.server@9.2.0-SNAPSHOT/org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:27)
	at org.elasticsearch.xpack.esql.plugin.DataNodeComputeHandler$DataNodeRequestExecutor.lambda$acquireSearchContexts$7(DataNodeComputeHandler.java:389)
	at org.elasticsearch.base@9.2.0-SNAPSHOT/org.elasticsearch.core.AbstractRefCounted$1.closeInternal(AbstractRefCounted.java:125)
	at org.elasticsearch.base@9.2.0-SNAPSHOT/org.elasticsearch.core.AbstractRefCounted.decRef(AbstractRefCounted.java:77)
	at org.elasticsearch.server@9.2.0-SNAPSHOT/org.elasticsearch.action.support.RefCountingRunnable.close(RefCountingRunnable.java:113)
	at org.elasticsearch.xpack.esql.plugin.DataNodeComputeHandler$DataNodeRequestExecutor.acquireSearchContexts(DataNodeComputeHandler.java:402)
	at org.elasticsearch.xpack.esql.plugin.DataNodeComputeHandler$DataNodeRequestExecutor.runBatch(DataNodeComputeHandler.java:297)
	at org.elasticsearch.xpack.esql.plugin.DataNodeComputeHandler$DataNodeRequestExecutor.start(DataNodeComputeHandler.java:258)
	at org.elasticsearch.xpack.esql.plugin.DataNodeComputeHandler.runComputeOnDataNode(DataNodeComputeHandler.java:470)
	at org.elasticsearch.xpack.esql.plugin.DataNodeComputeHandler.messageReceived(DataNodeComputeHandler.java:533)
	at org.elasticsearch.xpack.esql.plugin.DataNodeComputeHandler.messageReceived(DataNodeComputeHandler.java:68)
	at org.elasticsearch.server@9.2.0-SNAPSHOT/org.elasticsearch.transport.RequestHandlerRegistry.processMessageReceived(RequestHandlerRegistry.java:86)
	at org.elasticsearch.server@9.2.0-SNAPSHOT/org.elasticsearch.transport.TransportService$6.doRun(TransportService.java:1102)
	at org.elasticsearch.server@9.2.0-SNAPSHOT/org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingAbstractRunnable.doRun(ThreadContext.java:1067)
	at org.elasticsearch.server@9.2.0-SNAPSHOT/org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:27)
	at org.elasticsearch.server@9.2.0-SNAPSHOT/org.elasticsearch.common.util.concurrent.TimedRunnable.doRun(TimedRunnable.java:35)
	at org.elasticsearch.server@9.2.0-SNAPSHOT/org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingAbstractRunnable.doRun(ThreadContext.java:1067)
	at org.elasticsearch.server@9.2.0-SNAPSHOT/org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:27)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1095)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:619)
	at java.base/java.lang.Thread.run(Thread.java:1447)
], cause [java.lang.IllegalStateException: Found 1 problem
line 6:3: Plan [TopN[[Order[language_name{f}#72,ASC,LAST]],1000[INTEGER]]] optimized incorrectly due to missing references [language_name{f}#72]
	at org.elasticsearch.xpack.esql.optimizer.PostOptimizationPhasePlanVerifier.verify(PostOptimizationPhasePlanVerifier.java:44)
	at org.elasticsearch.xpack.esql.optimizer.LocalLogicalPlanOptimizer.localOptimize(LocalLogicalPlanOptimizer.java:93)
	at org.elasticsearch.xpack.esql.planner.PlannerUtils.lambda$localPlan$14(PlannerUtils.java:226)
	at org.elasticsearch.xpack.esql.core.tree.Node.lambda$transformUp$10(Node.java:238)
	at org.elasticsearch.xpack.esql.core.tree.Node.transformUp(Node.java:233)
	at org.elasticsearch.xpack.esql.core.tree.Node.lambda$transformUp$9(Node.java:231)
	at org.elasticsearch.xpack.esql.core.tree.Node.transformChildren(Node.java:256)
	at org.elasticsearch.xpack.esql.core.tree.Node.transformUp(Node.java:231)
	at org.elasticsearch.xpack.esql.core.tree.Node.transformUp(Node.java:238)
	at org.elasticsearch.xpack.esql.planner.PlannerUtils.localPlan(PlannerUtils.java:218)
	at org.elasticsearch.xpack.esql.planner.PlannerUtils.localPlan(PlannerUtils.java:203)
	at org.elasticsearch.xpack.esql.planner.PlannerUtils.localPlan(PlannerUtils.java:188)
	at org.elasticsearch.xpack.esql.plugin.ComputeService.runCompute(ComputeService.java:640)

@alex-spies I am assigning you on this one, you know much better than me this functionality and if a different assignee is better suited to have a look at this failure, based on the recent changes history.

[luigidellaquila]

Thanks for the analysis @astefan!

Out of curiosity, how frequent is the problem? Do you think it's worth adding that exception to the exclusions in the generative tests?
I can do it quickly, but it will make us blind against plan consistency checks

[alex-spies]

Managed to repro, the instructions are delightful @astefan , thank you.

Made the rule executor noisy in my test run and got meaningful logs in this build scan.

Looks like it is unrelated to lookup join itself; there's something weird going on with PushDownAndCombineOrderBy when it pushes an OrderBy past two projections. This is a bit hard to read, but check out what happens to the language_name{f}#67 attribute which the OrderBy depends on:

[2025-09-10T08:26:35,683][INFO ][o.e.x.e.o.L.changes      ] [test-cluster-0] Rule logical.PushDownAndCombineOrderBy applied with change	
Project[[!@timestamp, !client_ip, event_duration{f}#55, id{f}#56, language_code_double{f}#57, language_code_float{f}#5                                                                                                                                                                                                                                                                                              = Project[[!@timestamp, !client_ip, event_duration{f}#55, id{f}#56, language_code_double{f}#57, language_code_float{f}#5	
8, language_code_half_float{f}#59, language_code_integer{f}#60, language_code_long{f}#61, language_code_scaled_float{f}#62, language_code_short{f}#63, message{f}#64, name{f}#65, version{f}#66, language_name{f}#67]]                                                                                                                                                                                              = 8, language_code_half_float{f}#59, language_code_integer{f}#60, language_code_long{f}#61, language_code_scaled_float{f}#62, language_code_short{f}#63, message{f}#64, name{f}#65, version{f}#66, language_name{f}#67]]	
\_Limit[1000[INTEGER],false]                                                                                                                                                                                                                                                                                                                                                                                        = \_Limit[1000[INTEGER],false]	
  \_OrderBy[[Order[language_name{f}#67,ASC,LAST]]]                                                                                                                                                                                                                                                                                                                                                                  !   \_Project[[!@timestamp, !client_ip, event_duration{f}#55, id{r}#56, language_code_byte{r}#68, language_code_double{r}#57	
    \_Project[[!@timestamp, !client_ip, event_duration{f}#55, id{r}#56, language_code_byte{r}#68, language_code_double{r}#57                                                                                                                                                                                                                                                                                        ! , language_code_float{r}#58, language_code_half_float{r}#59, language_code_integer{r}#60, language_code_long{r}#61, language_code_scaled_float{r}#62, language_code_short{r}#63, message{f}#64, name{r}#65, version{r}#66, language_name{r}#67]]	
, language_code_float{r}#58, language_code_half_float{r}#59, language_code_integer{r}#60, language_code_long{r}#61, language_code_scaled_float{r}#62, language_code_short{r}#63, message{f}#64, name{r}#65, version{r}#66, language_name{r}#67]]                                                                                                                                                                    !     \_Project[[!@timestamp, !client_ip, event_duration{f}#55, id{r}#56, id{r}#56 AS language_code_byte#68, language_code_dou	
      \_Project[[!@timestamp, !client_ip, event_duration{f}#55, id{r}#56, id{r}#56 AS language_code_byte#68, language_code_dou                                                                                                                                                                                                                                                                                      ! ble{r}#57, language_code_double{r}#57 AS language_code_float#58, language_code_double{r}#57 AS language_code_half_float#59, id{r}#56 AS language_code_integer#60, language_code_long{r}#61, language_code_double{r}#57 AS language_code_scaled_float#62, id{r}#56 AS language_code_short#63, message{f}#64, language_name{r}#69 AS name#65, version{r}#66, $$language_name$temp_name$72{r}#73 AS language_name#67]]	
ble{r}#57, language_code_double{r}#57 AS language_code_float#58, language_code_double{r}#57 AS language_code_half_float#59, id{r}#56 AS language_code_integer#60, language_code_long{r}#61, language_code_double{r}#57 AS language_code_scaled_float#62, id{r}#56 AS language_code_short#63, message{f}#64, language_name{r}#69 AS name#65, version{r}#66, $$language_name$temp_name$72{r}#73 AS language_name#67]] !       \_OrderBy[[Order[language_name{f}#67,ASC,LAST]]]	
        \_Eval[[null[KEYWORD] AS $$language_name$temp_name$72#73]]                                                                                                                                                                                                                                                                                                                                                  =         \_Eval[[null[KEYWORD] AS $$language_name$temp_name$72#73]]	
          \_Join[LEFT,[language_code_byte{f}#68],[language_code_byte{f}#68],[language_code{f}#70]]                                                                                                                                                                                                                                                                                                                  =           \_Join[LEFT,[language_code_byte{f}#68],[language_code_byte{f}#68],[language_code{f}#70]]	
            |_Eval[[null[INTEGER] AS id#56, null[DOUBLE] AS language_code_double#57, null[LONG] AS language_code_long#61, null[KE                                                                                                                                                                                                                                                                                   =             |_Eval[[null[INTEGER] AS id#56, null[DOUBLE] AS language_code_double#57, null[LONG] AS language_code_long#61, null[KE	
YWORD] AS language_name#69, null[VERSION] AS version#66]]                                                                                                                                                                                                                                                                                                                                                           = YWORD] AS language_name#69, null[VERSION] AS version#66]]	
            | \_EsRelation[sample_d*,languages_mixed_numerics,apps][!@timestamp, !client_ip, event_duration{f}#55, id{f..]                                                                                                                                                                                                                                                                                          =             | \_EsRelation[sample_d*,languages_mixed_numerics,apps][!@timestamp, !client_ip, event_duration{f}#55, id{f..]	
            \_EsRelation[languages_lookup][LOOKUP][language_code{f}#70]    

[astefan]

Thanks for the analysis @astefan!

Out of curiosity, how frequent is the problem? Do you think it's worth adding that exception to the exclusions in the generative tests? I can do it quickly, but it will make us blind against plan consistency checks

I wouldn't add an exclusion. This was reproduce-able (for me) on multi-node tests, it doesn't seem to be as frequent as to warrant an exclusion, yet imo.

[alex-spies]

Managed to repro this in a unit test. PushDownAndCombineOrderBy doesn't correctly propagate the rename from an upstream projection it's being pushed down past in the following, very simple case:

 OrderBy[[Order[a{f}#1,ASC,ANY]]]
 \_Project[[aTemp{r}#2 AS a#1]]
   \_Eval[[null[INTEGER] AS aTemp#2]]
     \_EsRelation[HczXbGrM][LOGSDB][a{f}#1]

Such Eval aTemp = null::integer are added by rules that deal with missing fields. The projection re-uses the same name id so that the downstream OrderBy correctly uses the null attribute rather than still requiring field extraction for the a field attribute.