Daniel Becker created IMPALA-12289:
--------------------------------------
Summary: TestCodegen.test_const_scalar_expr_in_union fails in some
builds
Key: IMPALA-12289
URL: https://issues.apache.org/jira/browse/IMPALA-12289
Project: IMPALA
Issue Type: Bug
Components: Backend
Reporter: Daniel Becker
TestCodegen.test_const_scalar_expr_in_union fails in some builds with stacktrace
{code:java}
query_test/test_codegen.py:101: in test_const_scalar_expr_in_union
use_db=unique_database) common/impala_test_suite.py:799: in run_test_case
update_section=pytest.config.option.update_results)
common/test_result_verifier.py:645: in verify_runtime_profile actual)) E
AssertionError: Did not find matches for lines in runtime profile: E EXPECTED
LINES: E ExecOption: Codegen Disabled for const scalar expressions, Codegen
Enabled E E ACTUAL PROFILE: E Query (id=d746fbe14fd36202:2ffbcb2a00000000): E
DEBUG MODE WARNING: Query profile created while running a DEBUG build of
Impala. Use RELEASE builds to measure query performance. E - InactiveTotalTime:
0.000ns E - TotalTime: 0.000ns E Summary: E Session ID:
eb47fa7238fd6349:9ec3a1a4befa9985 E Session Type: BEESWAX E Start Time:
2023-07-09 19:32:12.734225000 E End Time: 2023-07-09 19:32:12.889853000 E Query
Type: QUERY E Query State: FINISHED E Impala Query State: FINISHED E Query
Status: OK E Impala Version: impalad version 4.0.0-SNAPSHOT DEBUG (build
bb98e817be2accad210ccf5d02c7b26dd68e951d) E User: jenkins E Connected User:
jenkins E Delegated User: E Network Address: 127.0.0.1:60140 E Default Db:
test_const_scalar_expr_in_union_1333b581 E Sql Statement: select 1,2,3 union
all select 4,5,6 union all select 7,8,9 order by 1 E Coordinator:
impala-ec2-centos79-m6i-4xlarge-ondemand-0c92.vpc.cloudera.com:27000 E Query
Options (set by configuration):
EXEC_SINGLE_NODE_ROWS_THRESHOLD=0,DISABLE_CODEGEN_ROWS_THRESHOLD=1,TIMEZONE=America/Los_Angeles,CLIENT_IDENTIFIER=query_test/test_codegen.py::TestCodegen::()::test_const_scalar_expr_in_union[protocol:beeswax|exec_option:{'exec_single_node_rows_threshold':0}|table_format:text/none]
E Query Options (set by configuration and planner):
EXEC_SINGLE_NODE_ROWS_THRESHOLD=0,MT_DOP=0,DISABLE_CODEGEN_ROWS_THRESHOLD=1,TIMEZONE=America/Los_Angeles,CLIENT_IDENTIFIER=query_test/test_codegen.py::TestCodegen::()::test_const_scalar_expr_in_union[protocol:beeswax|exec_option:{'exec_single_node_rows_threshold':0}|table_format:text/none]
E Plan: E ---------------- E Max Per-Host Resource Reservation: Memory=10.00MB
Threads=1 E Per-Host Resource Estimates: Memory=10MB E Analyzed query: SELECT
CAST(1 AS TINYINT), CAST(2 AS TINYINT), CAST(3 AS E TINYINT) UNION ALL SELECT
CAST(4 AS TINYINT), CAST(5 AS TINYINT), CAST(6 AS E TINYINT) UNION ALL (SELECT
CAST(7 AS TINYINT), CAST(8 AS TINYINT), CAST(9 AS E TINYINT)) ORDER BY CAST(1
AS TINYINT) ASC E E F00:PLAN FRAGMENT [UNPARTITIONED] hosts=1 instances=1 E |
Per-Host Resources: mem-estimate=10.00MB mem-reservation=10.00MB
thread-reservation=1 E PLAN-ROOT SINK E | output exprs: 1, 2, 3 E |
mem-estimate=4.00MB mem-reservation=4.00MB spill-buffer=2.00MB
thread-reservation=0 E | E 01:SORT E | order by: 1 ASC E | mem-estimate=6.00MB
mem-reservation=6.00MB spill-buffer=2.00MB thread-reservation=0 E | tuple-ids=1
row-size=3B cardinality=3 E | in pipelines: 01(GETNEXT) E | E 00:UNION E
constant-operands=3 E mem-estimate=0B mem-reservation=0B thread-reservation=0 E
tuple-ids=0 row-size=3B cardinality=3 E in pipelines: <none> E ----------------
E Estimated Per-Host Mem: 10485760 E Request Pool: default-pool E Per Host Min
Memory Reservation:
impala-ec2-centos79-m6i-4xlarge-ondemand-0c92.vpc.cloudera.com:27000(10.00 MB)
E Per Host Number of Fragment Instances:
impala-ec2-centos79-m6i-4xlarge-ondemand-0c92.vpc.cloudera.com:27000(1) E
Admission result: Admitted immediately E Cluster Memory Admitted: 10.00 MB E
Executor Group: empty group (using coordinator only) E ExecSummary: E Operator
#Hosts #Inst Avg Time Max Time #Rows Est. #Rows Peak Mem Est. Peak Mem Detail E
-------------------------------------------------------------------------------------------------
E F00:ROOT 1 1 0.000ns 0.000ns 4.01 MB 4.00 MB E 01:SORT 1 1 0.000ns 0.000ns 3
3 6.02 MB 6.00 MB E 00:UNION 1 1 0.000ns 0.000ns 3 3 0 0 E Errors: E Query
Compilation: 948.436us E - Metadata of all 0 tables cached: 152.682us
(152.682us) E - Analysis finished: 431.607us (278.925us) E - Authorization
finished (noop): 470.202us (38.595us) E - Value transfer graph computed:
518.528us (48.326us) E - Single node plan created: 574.903us (56.375us) E -
Runtime filters computed: 605.147us (30.244us) E - Distributed plan created:
611.428us (6.281us) E - Planning finished: 948.436us (337.008us) E Query
Timeline: 155.997ms E - Query submitted: 0.000ns (0.000ns) E - Planning
finished: 999.985us (999.985us) E - Submit for admission: 999.985us (0.000ns) E
- Completed admission: 1.999ms (999.985us) E - Ready to start on 1 backends:
1.999ms (0.000ns) E - All 1 execution backends (1 fragment instances) started:
2.999ms (999.984us) E - Rows available: 131.998ms (128.998ms) E - First row
fetched: 152.997ms (20.999ms) E - Last row fetched: 152.997ms (0.000ns) E -
Released admission control resources: 154.997ms (1.999ms) E -
AdmissionControlTimeSinceLastUpdate: 48.000ms E -
ComputeScanRangeAssignmentTimer: 0.000ns E - InactiveTotalTime: 0.000ns E -
TotalTime: 0.000ns E Frontend: E - InactiveTotalTime: 0.000ns E - TotalTime:
0.000ns E ImpalaServer: E - ClientFetchWaitTimeStats: (Avg: 20.999ms ; Min:
20.999ms ; Max: 20.999ms ; Number of samples: 1) E - ClientFetchWaitTimer:
20.999ms E - InactiveTotalTime: 0.000ns E - NumRowsFetched: 3 (3) E -
NumRowsFetchedFromCache: 0 (0) E - RPCCount: 8 (8) E - RPCReadTimer: 19.000us E
- RPCWriteTimer: 103.000us E - RowMaterializationRate: 1.50 K/sec E -
RowMaterializationTimer: 1.999ms E - TotalTime: 0.000ns E Execution Profile
d746fbe14fd36202:2ffbcb2a00000000:(Total: 131.998ms, non-child: 0.000ns, %
non-child: 0.00%) E Number of filters: 0 E Filter routing table: E ID Src. Node
Tgt. Node(s) Target type Partition filter Pending (Expected) First arrived
Completed Enabled Bloom Size Est fpp Min value Max value E
--------------------------------------------------------------------------------------------------------------------------------------------------------------
E Backend startup latencies: Count: 1, sum: 1ms, min / max: 1ms / 1ms, 25th
%-ile: 1ms, 50th %-ile: 1ms, 75th %-ile: 1ms, 90th %-ile: 1ms, 95th %-ile: 1ms,
99.9th %-ile: 1ms E Slowest backend to start up:
impala-ec2-centos79-m6i-4xlarge-ondemand-0c92.vpc.cloudera.com:27000 E Per Node
Peak Memory Usage:
impala-ec2-centos79-m6i-4xlarge-ondemand-0c92.vpc.cloudera.com:27000(11.40 MB)
E Per Node Bytes Read:
impala-ec2-centos79-m6i-4xlarge-ondemand-0c92.vpc.cloudera.com:27000(0) E Per
Node User Time:
impala-ec2-centos79-m6i-4xlarge-ondemand-0c92.vpc.cloudera.com:27000(127.599ms)
E Per Node System Time:
impala-ec2-centos79-m6i-4xlarge-ondemand-0c92.vpc.cloudera.com:27000(997.000us)
E - ExchangeScanRatio: 0.00 E - FiltersReceived: 0 (0) E - FinalizationTimer:
0.000ns E - InactiveTotalTime: 0.000ns E - InnerNodeSelectivityRatio: 0.00 E -
NumBackends: 1 (1) E - NumCompletedBackends: 1 (1) E - NumFragmentInstances: 1
(1) E - NumFragments: 1 (1) E - TotalBytesRead: 0 E - TotalBytesSent: 0 E -
TotalCpuTime: 128.596ms E - TotalInnerBytesSent: 0 E - TotalScanBytesSent: 0 E
- TotalTime: 131.998ms E Per Node Profiles: E - InactiveTotalTime: 0.000ns E -
TotalTime: 0.000ns E
impala-ec2-centos79-m6i-4xlarge-ondemand-0c92.vpc.cloudera.com:27000: E -
AdmissionSlots: 1 (1) E - BloomFilterBytes: 0 E - InactiveTotalTime: 0.000ns E
- ScratchBytesRead: 0 E - ScratchBytesWritten: 0 E - ScratchFileUsedBytes: 0 E
- ScratchReads: 0 (0) E - ScratchWrites: 0 (0) E - TotalEncryptionTime: 0.000ns
E - TotalReadBlockTime: 0.000ns E - TotalTime: 0.000ns E -
UncompressedScratchBytesWritten: 0 E Buffer pool: E - AllocTime: 0.000ns E -
CompressionTime: 0.000ns E - CumulativeAllocationBytes: 0 E -
CumulativeAllocations: 0 (0) E - EncryptionTime: 0.000ns E - InactiveTotalTime:
0.000ns E - PeakReservation: 0 E - PeakUnpinnedBytes: 0 E -
PeakUsedReservation: 0 E - ReadIoBytes: 0 E - ReadIoOps: 0 (0) E -
ReadIoWaitTime: 0.000ns E - ReservationLimit: 0 E - SystemAllocTime: 0.000ns E
- TotalTime: 0.000ns E - WriteIoBytes: 0 E - WriteIoOps: 0 (0) E -
WriteIoWaitTime: 0.000ns E JVM: E - GcCount: 0 (0) E -
GcNumInfoThresholdExceeded: 0 (0) E - GcNumWarnThresholdExceeded: 0 (0) E -
GcTimeMillis: 0 E - GcTotalExtraSleepTimeMillis: 0 E - InactiveTotalTime:
0.000ns E - TotalTime: 0.000ns E Fragment F00: E - InactiveTotalTime: 0.000ns E
- TotalTime: 0.000ns E CodeGen:(Total: 127.998ms, non-child: 127.998ms, %
non-child: 100.00%) E - CodegenCompileThreadInvoluntaryContextSwitches: 0 (0) E
- CodegenCompileThreadTotalWallClockTime: 0.000ns E -
CodegenCompileThreadSysTime: 0.000ns E - CodegenCompileThreadUserTime: 0.000ns
E - CodegenCompileThreadVoluntaryContextSwitches: 0 (0) E -
CodegenInvoluntaryContextSwitches: 0 (0) E - CodegenTotalWallClockTime:
127.998ms E - CodegenSysTime: 992.000us E - CodegenUserTime: 127.010ms E -
CodegenVoluntaryContextSwitches: 0 (0) E - CompileTime: 11.999ms E -
InactiveTotalTime: 0.000ns E - IrGenerationTime: 5.999ms E - LoadTime: 0.000ns
E - MainThreadCodegenTime: 110.998ms E - ModuleBitcodeSize: 3.28 MB (3435184) E
- NumFunctions: 85 (85) E - NumInstructions: 2.86K (2861) E - OptimizationTime:
91.998ms E - PeakMemoryUsage: 1.40 MB (1464832) E - PrepareTime: 16.999ms E -
TotalTime: 127.998ms E Averaged Fragment F00:(Total: 148.997ms, non-child:
127.998ms, % non-child: 85.91%) E split sizes: min: 0, max: 0, avg: 0, stddev:
0 E completion times: min:151.997ms max:151.997ms mean: 151.997ms
stddev:0.000ns E execution rates: min:0.00 /sec max:0.00 /sec mean:0.00 /sec
stddev:0.00 /sec E num instances: 1 E - AverageThreadTokens: 0.00 E -
BytesAssigned: 0 E - CompletionTime: 151.997ms E - ExchangeScanRatio: 0.00 E -
ExecutionRate: 0.00 /sec E - InactiveTotalTime: 0.000ns E - PeakMemoryUsage:
10.02 MB (10510336) E - PeakReservation: 10.00 MB (10485760) E -
PeakUsedReservation: 0 E - PerHostPeakMemUsage: 11.40 MB (11958784) E -
RowsProduced: 3 (3) E - TotalNetworkReceiveTime: 0.000ns E -
TotalNetworkSendTime: 0.000ns E - TotalStorageWaitTime: 0.000ns E -
TotalThreadsInvoluntaryContextSwitches: 0 (0) E -
TotalThreadsTotalWallClockTime: 148.997ms E - TotalThreadsSysTime: 997.000us E
- TotalThreadsUserTime: 127.599ms E - TotalThreadsVoluntaryContextSwitches: 1
(1) E - TotalTime: 148.997ms E Fragment Instance Lifecycle Timings: E -
ExecTime: 20.999ms E - ExecTreeExecTime: 0.000ns E - InactiveTotalTime: 0.000ns
E - OpenTime: 127.998ms E - ExecTreeOpenTime: 0.000ns E - PrepareTime: 0.000ns
E - ExecTreePrepareTime: 0.000ns E - TotalTime: 0.000ns E
PLAN_ROOT_SINK:(Total: 20.999ms, non-child: 0.000ns, % non-child: 0.00%) E -
CreateResultSetTime: 0.000ns E - InactiveTotalTime: 20.999ms E -
PeakMemoryUsage: 4.01 MB (4202496) E - RowBatchGetWaitTime: 0.000ns E -
RowBatchSendWaitTime: 0.000ns E - RowsSent: 3 (3) E - RowsSentRate: 142.00 /sec
E - TotalTime: 20.999ms E Buffer pool: E - AllocTime: 0.000ns E -
CompressionTime: 0.000ns E - CumulativeAllocationBytes: 2.00 MB (2097152) E -
CumulativeAllocations: 1 (1) E - EncryptionTime: 0.000ns E - InactiveTotalTime:
0.000ns E - PeakReservation: 4.00 MB (4194304) E - PeakUnpinnedBytes: 0 E -
PeakUsedReservation: 2.00 MB (2097152) E - ReadIoBytes: 0 E - ReadIoOps: 0 (0)
E - ReadIoWaitTime: 0.000ns E - ReservationLimit: 100.00 MB (104857600) E -
SystemAllocTime: 0.000ns E - TotalTime: 0.000ns E - WriteIoBytes: 0 E -
WriteIoOps: 0 (0) E - WriteIoWaitTime: 0.000ns E SORT_NODE (id=1): E -
AddBatchTime: (Avg: 0.000ns ; Min: 0.000ns ; Max: 0.000ns ; Number of samples:
1) E - NumRowsPerRun: (Avg: 3 (3) ; Min: 3 (3) ; Max: 3 (3) ; Number of
samples: 1) E - InMemorySortTime: 0.000ns E - InactiveTotalTime: 0.000ns E -
InitialRunsCreated: 1 (1) E - PeakMemoryUsage: 6.02 MB (6307840) E -
RowsReturned: 3 (3) E - RowsReturnedRate: 0 E - SortDataSize: 12.00 B (12) E -
SpilledRuns: 0 (0) E - TotalMergesPerformed: 0 (0) E - TotalTime: 0.000ns E
Buffer pool: E - AllocTime: 0.000ns E - CompressionTime: 0.000ns E -
CumulativeAllocationBytes: 2.00 MB (2097152) E - CumulativeAllocations: 1 (1) E
- EncryptionTime: 0.000ns E - InactiveTotalTime: 0.000ns E - PeakReservation:
6.00 MB (6291456) E - PeakUnpinnedBytes: 0 E - PeakUsedReservation: 2.00 MB
(2097152) E - ReadIoBytes: 0 E - ReadIoOps: 0 (0) E - ReadIoWaitTime: 0.000ns E
- SystemAllocTime: 0.000ns E - TotalTime: 0.000ns E - WriteIoBytes: 0 E -
WriteIoOps: 0 (0) E - WriteIoWaitTime: 0.000ns E UNION_NODE (id=0): E -
InactiveTotalTime: 0.000ns E - PeakMemoryUsage: 0 E - RowsReturned: 3 (3) E -
RowsReturnedRate: 0 E - TotalTime: 0.000ns E Coordinator Fragment F00: E -
InactiveTotalTime: 0.000ns E - TotalTime: 0.000ns E Instance
d746fbe14fd36202:2ffbcb2a00000000
(host=impala-ec2-centos79-m6i-4xlarge-ondemand-0c92.vpc.cloudera.com:27000):(Total:
148.997ms, non-child: 127.998ms, % non-child: 85.91%) E Last report received
time: 2023-07-09 19:32:12.889 E Fragment Instance Lifecycle Event Timeline:
149.997ms E - Prepare Finished: 999.985us (999.985us) E - Open Finished:
128.998ms (127.998ms) E - First Batch Produced: 128.998ms (0.000ns) E - First
Batch Sent: 128.998ms (0.000ns) E - ExecInternal Finished: 149.997ms (20.999ms)
E - AverageThreadTokens: 0.00 E - BytesAssigned: 0 E - CompletionTime:
151.997ms E - ExchangeScanRatio: 0.00 E - ExecutionRate: 0.00 /sec E -
InactiveTotalTime: 0.000ns E - PeakMemoryUsage: 10.02 MB (10510336) E -
PeakReservation: 10.00 MB (10485760) E - PeakUsedReservation: 0 E -
PerHostPeakMemUsage: 11.40 MB (11958784) E - RowsProduced: 3 (3) E -
TotalNetworkReceiveTime: 0.000ns E - TotalNetworkSendTime: 0.000ns E -
TotalStorageWaitTime: 0.000ns E - TotalThreadsInvoluntaryContextSwitches: 0 (0)
E - TotalThreadsTotalWallClockTime: 148.997ms E - TotalThreadsSysTime:
997.000us E - TotalThreadsUserTime: 127.599ms E -
TotalThreadsVoluntaryContextSwitches: 1 (1) E - TotalTime: 148.997ms E Fragment
Instance Lifecycle Timings: E - ExecTime: 20.999ms E - ExecTreeExecTime:
0.000ns E - InactiveTotalTime: 0.000ns E - OpenTime: 127.998ms E -
ExecTreeOpenTime: 0.000ns E - PrepareTime: 0.000ns E - ExecTreePrepareTime:
0.000ns E - TotalTime: 0.000ns E PLAN_ROOT_SINK:(Total: 20.999ms, non-child:
0.000ns, % non-child: 0.00%) E - CreateResultSetTime: 0.000ns E -
InactiveTotalTime: 20.999ms E - PeakMemoryUsage: 4.01 MB (4202496) E -
RowBatchGetWaitTime: 0.000ns E - RowBatchSendWaitTime: 0.000ns E - RowsSent: 3
(3) E - RowsSentRate: 142.00 /sec E - TotalTime: 20.999ms E Buffer pool: E -
AllocTime: 0.000ns E - CompressionTime: 0.000ns E - CumulativeAllocationBytes:
2.00 MB (2097152) E - CumulativeAllocations: 1 (1) E - EncryptionTime: 0.000ns
E - InactiveTotalTime: 0.000ns E - PeakReservation: 4.00 MB (4194304) E -
PeakUnpinnedBytes: 0 E - PeakUsedReservation: 2.00 MB (2097152) E -
ReadIoBytes: 0 E - ReadIoOps: 0 (0) E - ReadIoWaitTime: 0.000ns E -
ReservationLimit: 100.00 MB (104857600) E - SystemAllocTime: 0.000ns E -
TotalTime: 0.000ns E - WriteIoBytes: 0 E - WriteIoOps: 0 (0) E -
WriteIoWaitTime: 0.000ns E SORT_NODE (id=1): E SortType: Total E ExecOption:
Codegen Enabled E Node Lifecycle Event Timeline: 128.998ms E - Open Started:
128.998ms (128.998ms) E - Open Finished: 128.998ms (0.000ns) E - First Batch
Requested: 128.998ms (0.000ns) E - First Batch Returned: 128.998ms (0.000ns) E
- Last Batch Returned: 128.998ms (0.000ns) E - Closed: 128.998ms (0.000ns) E -
AddBatchTime: (Avg: 0.000ns ; Min: 0.000ns ; Max: 0.000ns ; Number of samples:
1) E - NumRowsPerRun: (Avg: 3 (3) ; Min: 3 (3) ; Max: 3 (3) ; Number of
samples: 1) E - InMemorySortTime: 0.000ns E - InactiveTotalTime: 0.000ns E -
InitialRunsCreated: 1 (1) E - PeakMemoryUsage: 6.02 MB (6307840) E -
RowsReturned: 3 (3) E - RowsReturnedRate: 0 E - SortDataSize: 12.00 B (12) E -
SpilledRuns: 0 (0) E - TotalMergesPerformed: 0 (0) E - TotalTime: 0.000ns E
Buffer pool: E - AllocTime: 0.000ns E - CompressionTime: 0.000ns E -
CumulativeAllocationBytes: 2.00 MB (2097152) E - CumulativeAllocations: 1 (1) E
- EncryptionTime: 0.000ns E - InactiveTotalTime: 0.000ns E - PeakReservation:
6.00 MB (6291456) E - PeakUnpinnedBytes: 0 E - PeakUsedReservation: 2.00 MB
(2097152) E - ReadIoBytes: 0 E - ReadIoOps: 0 (0) E - ReadIoWaitTime: 0.000ns E
- SystemAllocTime: 0.000ns E - TotalTime: 0.000ns E - WriteIoBytes: 0 E -
WriteIoOps: 0 (0) E - WriteIoWaitTime: 0.000ns E UNION_NODE (id=0): E
ExecOption: Codegen Enabled, Codegen Disabled for const scalar expressions E
Node Lifecycle Event Timeline: 128.998ms E - Open Started: 128.998ms
(128.998ms) E - Open Finished: 128.998ms (0.000ns) E - First Batch Requested:
128.998ms (0.000ns) E - First Batch Returned: 128.998ms (0.000ns) E - Last
Batch Returned: 128.998ms (0.000ns) E - Closed: 128.998ms (0.000ns) E -
InactiveTotalTime: 0.000ns E - PeakMemoryUsage: 0 E - RowsReturned: 3 (3) E -
RowsReturnedRate: 0 E - TotalTime: 0.000ns{code}
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
