[VL] TProtocolException: Invalid data

[FelixYBW]

Backend

VL (Velox)

Bug description

24/05/07 14:12:50 ERROR [Executor task launch worker for task 6355.0 in stage 0.0 (TID 6377)] util.TaskResources: Task 6377 failed by error: 
org.apache.gluten.exception.GlutenException: java.lang.RuntimeException: Exception: VeloxRuntimeError
Error Source: RUNTIME
Error Code: INVALID_STATE
Reason: Operator::getOutput failed for [operator: TableScan, plan node ID: 0]: TProtocolException: Invalid data
Retriable: False
Function: runInternal
File: /home/binweiyang/gluten/ep/build-velox/build/velox_ep/velox/exec/Driver.cpp
Line: 594
Stack trace:
# 0  _ZN8facebook5velox7process10StackTraceC1Ei
# 1  _ZN8facebook5velox14VeloxExceptionC1EPKcmS3_St17basic_string_viewIcSt11char_traitsIcEES7_S7_S7_bNS1_4TypeES7_
# 2  _ZN8facebook5velox6detail14veloxCheckFailINS0_17VeloxRuntimeErrorERKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEEEEvRKNS1_18VeloxCheckFailArgsET0_
# 3  _ZN8facebook5velox4exec6Driver11runInternalERSt10shared_ptrIS2_ERS3_INS1_13BlockingStateEERS3_INS0_9RowVectorEE.cold
# 4  _ZN8facebook5velox4exec6Driver4nextERSt10shared_ptrINS1_13BlockingStateEE
# 5  _ZN8facebook5velox4exec4Task4nextEPN5folly10SemiFutureINS3_4UnitEEE
# 6  _ZN6gluten24WholeStageResultIterator4nextEv
# 7  Java_org_apache_gluten_vectorized_ColumnarBatchOutIterator_nativeHasNext
# 8  0x00007f0ad11bf427

It's the first stage of parquet scan. Many partitions success, some failed due to above reason.

@rui-mo is it caused by substrait?

Spark version

None

Spark configurations

No response

System information

No response

Relevant logs

No response

[FelixYBW]

fixed by velox

[acvictor]

@FelixYBW what was the cause of this? I am also facing an issue where task is randomly failing with

2025-02-13 22:29:17,909 ERROR TaskResources [Executor task launch worker for task 61.0 in stage 63.0 (TID 763)]: Task 763 failed by error: 
org.apache.gluten.exception.GlutenException: org.apache.gluten.exception.GlutenException: Exception: VeloxRuntimeError
Error Source: RUNTIME
Error Code: INVALID_STATE
Reason: Operator::getOutput failed for [operator: TableScan, plan node ID: 0]: TProtocolException: Invalid data
Retriable: False
DisplayReason: False
Function: runInternal
File: /root/velox/velox/exec/Driver.cpp
Line: 639
Stack trace:
# 0  _ZN8facebook5velox7process10StackTraceC1Ei
# 1  _ZN8facebook5velox14VeloxExceptionC2EPKcmS3_St17basic_string_viewIcSt11char_traitsIcEES7_S7_S7_bbNS1_4TypeES7_
# 2  _ZN8facebook5velox6detail14veloxCheckFailINS0_17VeloxRuntimeErrorERKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEEEEvRKNS1_18VeloxCheckFailArgsET0_
# 3  _ZN8facebook5velox4exec6Driver11runInternalERSt10shared_ptrIS2_ERS3_INS1_13BlockingStateEERS3_INS0_9RowVectorEE.cold
# 4  _ZN8facebook5velox4exec6Driver4nextERSt10shared_ptrINS1_13BlockingStateEE
# 5  _ZN8facebook5velox4exec4Task4nextEPN5folly10SemiFutureINS3_4UnitEEE
# 6  _ZN6gluten24WholeStageResultIterator4nextEv
# 7  Java_org_apache_gluten_vectorized_ColumnarBatchOutIterator_nativeHasNext
# 8  0x000076c2143d48f0

  at org.apache.gluten.vectorized.GeneralOutIterator.hasNext(GeneralOutIterator.java:39)
  at scala.collection.convert.Wrappers$JIteratorWrapper.hasNext(Wrappers.scala:45)
  at org.apache.gluten.utils.iterator.IteratorsV1$InvocationFlowProtection.hasNext(IteratorsV1.scala:159)
  at org.apache.gluten.utils.iterator.IteratorsV1$IteratorCompleter.hasNext(IteratorsV1.scala:71)
  at org.apache.gluten.utils.iterator.IteratorsV1$PayloadCloser.hasNext(IteratorsV1.scala:37)
  at org.apache.gluten.utils.iterator.IteratorsV1$LifeTimeAccumulator.hasNext(IteratorsV1.scala:100)
  at org.apache.spark.InterruptibleIterator.hasNext(InterruptibleIterator.scala:37)
  at scala.collection.Iterator$$anon$10.hasNext(Iterator.scala:460)
  at org.apache.spark.shuffle.ColumnarShuffleWriter.internalWrite(ColumnarShuffleWriter.scala:121)
  at org.apache.spark.shuffle.ColumnarShuffleWriter.write(ColumnarShuffleWriter.scala:232)
  at org.apache.spark.shuffle.ShuffleWriteProcessor.write(ShuffleWriteProcessor.scala:59)
  at org.apache.spark.scheduler.ShuffleMapTask.runTask(ShuffleMapTask.scala:104)
  at org.apache.spark.scheduler.ShuffleMapTask.runTask(ShuffleMapTask.scala:54)
  at org.apache.spark.TaskContext.runTaskWithListeners(TaskContext.scala:166)
  at org.apache.spark.scheduler.Task.run(Task.scala:141)
  at org.apache.spark.executor.Executor$TaskRunner.$anonfun$run$4(Executor.scala:620)
  at org.apache.spark.util.SparkErrorUtils.tryWithSafeFinally(SparkErrorUtils.scala:64)
  at org.apache.spark.util.SparkErrorUtils.tryWithSafeFinally$(SparkErrorUtils.scala:61)
  at org.apache.spark.util.Utils$.tryWithSafeFinally(Utils.scala:94)
  at org.apache.spark.executor.Executor$TaskRunner.run(Executor.scala:623)
  at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
  at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
  at java.base/java.lang.Thread.run(Thread.java:829)

Is there any particular commit I need?

[FelixYBW]

Did you enabled multiple IO threads? It's caused by a exit of a background thread. So the root cause varies.

[acvictor]

Did you enabled multiple IO threads? It's caused by a exit of a background thread. So the root cause varies.

Yes, we have multiple IO threads enabled. cc @zhli1142015

[liujiayi771]

@FelixYBW @rui-mo Is this issue caused only by multiple IO threads? I encountered a job that didn't have multiple IO threads enabled, but it also had this exception.

[FelixYBW]

@FelixYBW @rui-mo Is this issue caused only by multiple IO threads? I encountered a job that didn't have multiple IO threads enabled, but it also had this exception.

The error is caused by background thread. If a background thread run into exception and exit. The main thread report the error eventually. Most possible reason is the multiple IO thread.

[alexr17]

@FelixYBW Is there a way to understand why the background thread runs into exception? We are seeing this occasionally too.

[alexr17]

I think this issue may be related: duckdb/duckdb#8940

[FelixYBW]

I think this issue may be related: duckdb/duckdb#8940

Thank you to share the hint. Let me check how we can confirm. The issue is noted during a customer test, only 1 query reports sometimes. After Velox is upgraded, the issue is not reproduciable on that query. At the time we fixed a I/O issue which leads me to suspect it's related to that issue.

Obviously the root cause isn't the I/O issue we fixed.

[FelixYBW]

The root cause is that the data fetched from S3 is corrupt for some reason, but S3 doesn't report any error. The error is raised during decoding. The task succeeds after retries.