Tim Armstrong created IMPALA-9091:
-------------------------------------
Summary:
query_test.test_scanners.TestScannerReservation.test_scanners flaky
Key: IMPALA-9091
URL: https://issues.apache.org/jira/browse/IMPALA-9091
Project: IMPALA
Issue Type: Bug
Components: Infrastructure
Reporter: Tim Armstrong
Assignee: Tim Armstrong
https://jenkins.impala.io/job/ubuntu-16.04-from-scratch/8463
{noformat}
E AssertionError: Did not find matches for lines in runtime profile:
E EXPECTED LINES:
E row_regex:.*ParquetRowGroupIdealReservation.*Avg: 3.50 MB.*
E
E ACTUAL PROFILE:
E Query (id=3b48738ce971e36b:b6f52bf500000000):
E DEBUG MODE WARNING: Query profile created while running a DEBUG build of
Impala. Use RELEASE builds to measure query performance.
E Summary:
E Session ID: 2e4c96b22f2ac6e3:88afa967b63e7983
E Session Type: BEESWAX
E Start Time: 2019-10-24 21:22:06.311001000
E End Time: 2019-10-24 21:22:06.520778000
E Query Type: QUERY
E Query State: FINISHED
E Query Status: OK
E Impala Version: impalad version 3.4.0-SNAPSHOT DEBUG (build
8c60e91f7c3812aca14739535a994d21c51fc0b0)
E User: ubuntu
E Connected User: ubuntu
E Delegated User:
E Network Address: ::ffff:127.0.0.1:37312
E Default Db: functional
E Sql Statement: select * from tpch_parquet.lineitem
E where l_orderkey < 10
E Coordinator: ip-172-31-20-105:22000
E Query Options (set by configuration):
ABORT_ON_ERROR=1,EXEC_SINGLE_NODE_ROWS_THRESHOLD=0,DISABLE_CODEGEN_ROWS_THRESHOLD=0,TIMEZONE=Universal,CLIENT_IDENTIFIER=query_test/test_scanners.py::TestScannerReservation::()::test_scanners[protocol:beeswax|exec_option:{'batch_size':0;'num_nodes':0;'disable_codegen_rows_threshold':0;'disable_codegen':False;'abort_on_error':1;'exec_single_node_rows_threshold':0}|table_form
E Query Options (set by configuration and planner):
ABORT_ON_ERROR=1,EXEC_SINGLE_NODE_ROWS_THRESHOLD=0,MT_DOP=0,DISABLE_CODEGEN_ROWS_THRESHOLD=0,TIMEZONE=Universal,CLIENT_IDENTIFIER=query_test/test_scanners.py::TestScannerReservation::()::test_scanners[protocol:beeswax|exec_option:{'batch_size':0;'num_nodes':0;'disable_codegen_rows_threshold':0;'disable_codegen':False;'abort_on_error':1;'exec_single_node_rows_threshold':0}|table_form
E Plan:
E ----------------
E Max Per-Host Resource Reservation: Memory=40.00MB Threads=3
E Per-Host Resource Estimates: Memory=1.26GB
E Analyzed query: SELECT * FROM tpch_parquet.lineitem WHERE l_orderkey <
CAST(10
E AS BIGINT)
E
E F01:PLAN FRAGMENT [UNPARTITIONED] hosts=1 instances=1
E | Per-Host Resources: mem-estimate=10.69MB mem-reservation=0B
thread-reservation=1
E PLAN-ROOT SINK
E | output exprs: tpch_parquet.lineitem.l_orderkey,
tpch_parquet.lineitem.l_partkey, tpch_parquet.lineitem.l_suppkey,
tpch_parquet.lineitem.l_linenumber, tpch_parquet.lineitem.l_quantity,
tpch_parquet.lineitem.l_extendedprice, tpch_parquet.lineitem.l_discount,
tpch_parquet.lineitem.l_tax, tpch_parquet.lineitem.l_returnflag,
tpch_parquet.lineitem.l_linestatus, tpch_parquet.lineitem.l_shipdate,
tpch_parquet.lineitem.l_commitdate, tpch_parquet.lineitem.l_receiptdate,
tpch_parquet.lineitem.l_shipinstruct, tpch_parquet.lineitem.l_shipmode,
tpch_parquet.lineitem.l_comment
E | mem-estimate=0B mem-reservation=0B thread-reservation=0
E |
E 01:EXCHANGE [UNPARTITIONED]
E | mem-estimate=10.69MB mem-reservation=0B thread-reservation=0
E | tuple-ids=0 row-size=231B cardinality=600.12K
E | in pipelines: 00(GETNEXT)
E |
E F00:PLAN FRAGMENT [RANDOM] hosts=3 instances=3
E Per-Host Resources: mem-estimate=1.25GB mem-reservation=40.00MB
thread-reservation=2
E 00:SCAN HDFS [tpch_parquet.lineitem, RANDOM]
E HDFS partitions=1/1 files=3 size=193.97MB
E predicates: l_orderkey < CAST(10 AS BIGINT)
E stored statistics:
E table: rows=6.00M size=193.97MB
E columns: all
E extrapolated-rows=disabled max-scan-range-rows=2.14M
E parquet statistics predicates: l_orderkey < CAST(10 AS BIGINT)
E parquet dictionary predicates: l_orderkey < CAST(10 AS BIGINT)
E mem-estimate=1.25GB mem-reservation=40.00MB thread-reservation=1
E tuple-ids=0 row-size=231B cardinality=600.12K
E in pipelines: 00(GETNEXT)
E ----------------
E Estimated Per-Host Mem: 1353384279
E Request Pool: default-pool
E Per Host Min Memory Reservation: ip-172-31-20-105:22001(40.00 MB)
ip-172-31-20-105:22002(40.00 MB) ip-172-31-20-105:22000(40.00 MB)
E Per Host Number of Fragment Instances: ip-172-31-20-105:22001(1)
ip-172-31-20-105:22002(1) ip-172-31-20-105:22000(2)
E Admission result: Admitted immediately
E Cluster Memory Admitted: 3.78 GB
E Executor Group: default
E ExecSummary:
E Operator #Hosts Avg Time Max Time #Rows Est. #Rows Peak
Mem Est. Peak Mem Detail
E
---------------------------------------------------------------------------------------------------------------------
E F01:ROOT 1 0.000ns 0.000ns
0 0
E 01:EXCHANGE 1 0.000ns 0.000ns 25 600.12K 16.00
KB 10.69 MB UNPARTITIONED
E F00:EXCHANGE SENDER 3 0.000ns 0.000ns
824.00 B 0
E 00:SCAN HDFS 3 34.666ms 103.999ms 25 600.12K 45.19
MB 1.25 GB tpch_parquet.lineitem
E Errors:
E Query Compilation: 1.594ms
E - Metadata of all 1 tables cached: 161.262us (161.262us)
E - Analysis finished: 334.355us (173.093us)
E - Authorization finished (noop): 345.717us (11.362us)
E - Value transfer graph computed: 431.146us (85.429us)
E - Single node plan created: 1.042ms (610.955us)
E - Runtime filters computed: 1.067ms (25.100us)
E - Distributed plan created: 1.086ms (19.135us)
E - Planning finished: 1.594ms (508.537us)
E Query Timeline: 211.998ms
E - Query submitted: 0.000ns (0.000ns)
E - Planning finished: 0.000ns (0.000ns)
E - Submit for admission: 0.000ns (0.000ns)
E - Completed admission: 0.000ns (0.000ns)
E - Ready to start on 3 backends: 3.999ms (3.999ms)
E - All 3 execution backends (4 fragment instances) started: 3.999ms
(0.000ns)
E - Rows available: 179.998ms (175.998ms)
E - First row fetched: 203.998ms (23.999ms)
E - Last row fetched: 203.998ms (0.000ns)
E - Released admission control resources: 207.998ms (3.999ms)
E - AdmissionControlTimeSinceLastUpdate: 30.000ms
E - ComputeScanRangeAssignmentTimer: 0.000ns
E Frontend:
E ImpalaServer:
E - ClientFetchWaitTimer: 23.999ms
E - NumRowsFetched: 25 (25)
E - NumRowsFetchedFromCache: 0 (0)
E - RowMaterializationRate: 3.12 K/sec
E - RowMaterializationTimer: 7.999ms
E Execution Profile 3b48738ce971e36b:b6f52bf500000000:(Total: 183.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
E
-------------------------------------------------------------------------------------------------------------------
E Backend startup latencies: Count: 3, min / max: 1ms / 2ms, 25th %-ile:
1ms, 50th %-ile: 1ms, 75th %-ile: 1ms, 90th %-ile: 2ms, 95th %-ile: 2ms, 99.9th
%-ile: 2ms
E Slowest backend to start up: ip-172-31-20-105:22001
E Per Node Peak Memory Usage: ip-172-31-20-105:22001(40.14 MB)
ip-172-31-20-105:22002(45.20 MB) ip-172-31-20-105:22000(40.34 MB)
E Per Node Bytes Read: ip-172-31-20-105:22001(100.00 KB)
ip-172-31-20-105:22002(3.25 MB) ip-172-31-20-105:22000(100.00 KB)
E Per Node User Time: ip-172-31-20-105:22001(56.000ms)
ip-172-31-20-105:22002(168.000ms) ip-172-31-20-105:22000(136.000ms)
E Per Node System Time: ip-172-31-20-105:22001(0.000ns)
ip-172-31-20-105:22002(0.000ns) ip-172-31-20-105:22000(0.000ns)
E - ExchangeScanRatio: 0.00
E - FiltersReceived: 0 (0)
E - FinalizationTimer: 0.000ns
E - InnerNodeSelectivityRatio: 0.00
E - NumBackends: 3 (3)
E - NumCompletedBackends: 3 (3)
E - NumFragmentInstances: 4 (4)
E - NumFragments: 2 (2)
E - TotalBytesRead: 3.45 MB (3617314)
E - TotalBytesSent: 3.30 KB (3375)
E - TotalCpuTime: 360.000ms
E - TotalInnerBytesSent: 0
E - TotalScanBytesSent: 3.30 KB (3375)
E Per Node Profiles:
E ip-172-31-20-105:22001:
E - AdmissionSlots: 1 (1)
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 ip-172-31-20-105:22002:
E - AdmissionSlots: 1 (1)
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 ip-172-31-20-105:22000:
E - AdmissionSlots: 1 (1)
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 Averaged Fragment F01:(Total: 199.998ms, non-child: 0.000ns, %
non-child: 0.00%)
E split sizes: min: 0, max: 0, avg: 0, stddev: 0
E completion times: min:203.998ms max:203.998ms mean: 203.998ms
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 - BloomFilterBytes: 0
E - ExchangeScanRatio: 0.00
E - PeakMemoryUsage: 210.00 KB (215040)
E - PeakReservation: 0
E - PeakUsedReservation: 0
E - PerHostPeakMemUsage: 40.34 MB (42301240)
E - RowsProduced: 25 (25)
E - TotalNetworkReceiveTime: 91.999ms
E - TotalNetworkSendTime: 0.000ns
E - TotalStorageWaitTime: 0.000ns
E - TotalThreadsInvoluntaryContextSwitches: 9 (9)
E - TotalThreadsTotalWallClockTime: 199.998ms
E - TotalThreadsSysTime: 0.000ns
E - TotalThreadsUserTime: 80.000ms
E - TotalThreadsVoluntaryContextSwitches: 3 (3)
E Buffer pool:
E - AllocTime: 0.000ns
E - CumulativeAllocationBytes: 0
E - CumulativeAllocations: 0 (0)
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 - WriteIoBytes: 0
E - WriteIoOps: 0 (0)
E - WriteIoWaitTime: 0.000ns
E Fragment Instance Lifecycle Timings:
E - ExecTime: 23.999ms
E - ExecTreeExecTime: 0.000ns
E - OpenTime: 175.998ms
E - ExecTreeOpenTime: 91.999ms
E - PrepareTime: 0.000ns
E - ExecTreePrepareTime: 0.000ns
E PLAN_ROOT_SINK:(Total: 23.999ms, non-child: 23.999ms, % non-child:
100.00%)
E - PeakMemoryUsage: 0
E - RowsSent: 25 (25)
E - RowsSentRate: 1.04 K/sec
E EXCHANGE_NODE (id=1):(Total: 91.999ms, non-child: 91.999ms, %
non-child: 100.00%)
E - ConvertRowBatchTime: 0.000ns
E - PeakMemoryUsage: 16.00 KB (16384)
E - RowsReturned: 25 (25)
E - RowsReturnedRate: 271.00 /sec
E Buffer pool:
E - AllocTime: 0.000ns
E - CumulativeAllocationBytes: 16.00 KB (16384)
E - CumulativeAllocations: 2 (2)
E - PeakReservation: 16.00 KB (16384)
E - PeakUnpinnedBytes: 0
E - PeakUsedReservation: 16.00 KB (16384)
E - ReadIoBytes: 0
E - ReadIoOps: 0 (0)
E - ReadIoWaitTime: 0.000ns
E - SystemAllocTime: 0.000ns
E - WriteIoBytes: 0
E - WriteIoOps: 0 (0)
E - WriteIoWaitTime: 0.000ns
E Dequeue:
E - FirstBatchWaitTime: 91.999ms
E - TotalBytesDequeued: 5.87 KB (6006)
E - TotalGetBatchTime: 91.999ms
E - DataWaitTime: 91.999ms
E Enqueue:
E - DeserializeRowBatchTime: 0.000ns
E - TotalBatchesEnqueued: 1 (1)
E - TotalBatchesReceived: 1 (1)
E - TotalBytesReceived: 3.30 KB (3375)
E - TotalEarlySenders: 0 (0)
E - TotalEosReceived: 3 (3)
E - TotalHasDeferredRPCsTime: 0.000ns
E - TotalRPCsDeferred: 0 (0)
E CodeGen:(Total: 83.999ms, non-child: 83.999ms, % non-child: 100.00%)
E - CodegenInvoluntaryContextSwitches: 9 (9)
E - CodegenTotalWallClockTime: 83.999ms
E - CodegenSysTime: 0.000ns
E - CodegenUserTime: 80.000ms
E - CodegenVoluntaryContextSwitches: 0 (0)
E - CompileTime: 7.999ms
E - IrGenerationTime: 0.000ns
E - LoadTime: 0.000ns
E - ModuleBitcodeSize: 2.44 MB (2558836)
E - NumFunctions: 20 (20)
E - NumInstructions: 404 (404)
E - OptimizationTime: 39.999ms
E - PeakMemoryUsage: 202.00 KB (206848)
E - PrepareTime: 31.999ms
E Coordinator Fragment F01:
E Instance 3b48738ce971e36b:b6f52bf500000000
(host=ip-172-31-20-105:22000):(Total: 199.998ms, non-child: 0.000ns, %
non-child: 0.00%)
E Last report received time: 2019-10-24 21:22:06.520
E Fragment Instance Lifecycle Event Timeline: 199.998ms
E - Prepare Finished: 0.000ns (0.000ns)
E - Open Finished: 175.998ms (175.998ms)
E - First Batch Produced: 175.998ms (0.000ns)
E - First Batch Sent: 199.998ms (23.999ms)
E - ExecInternal Finished: 199.998ms (0.000ns)
E - MemoryUsage (500.000ms): 9.98 KB
E - AverageThreadTokens: 0.00
E - BloomFilterBytes: 0
E - ExchangeScanRatio: 0.00
E - PeakMemoryUsage: 210.00 KB (215040)
E - PeakReservation: 0
E - PeakUsedReservation: 0
E - PerHostPeakMemUsage: 40.34 MB (42301240)
E - RowsProduced: 25 (25)
E - TotalNetworkReceiveTime: 91.999ms
E - TotalNetworkSendTime: 0.000ns
E - TotalStorageWaitTime: 0.000ns
E - TotalThreadsInvoluntaryContextSwitches: 9 (9)
E - TotalThreadsTotalWallClockTime: 199.998ms
E - TotalThreadsSysTime: 0.000ns
E - TotalThreadsUserTime: 80.000ms
E - TotalThreadsVoluntaryContextSwitches: 3 (3)
E Buffer pool:
E - AllocTime: 0.000ns
E - CumulativeAllocationBytes: 0
E - CumulativeAllocations: 0 (0)
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 - WriteIoBytes: 0
E - WriteIoOps: 0 (0)
E - WriteIoWaitTime: 0.000ns
E Fragment Instance Lifecycle Timings:
E - ExecTime: 23.999ms
E - ExecTreeExecTime: 0.000ns
E - OpenTime: 175.998ms
E - ExecTreeOpenTime: 91.999ms
E - PrepareTime: 0.000ns
E - ExecTreePrepareTime: 0.000ns
E PLAN_ROOT_SINK:(Total: 23.999ms, non-child: 0.000ns, % non-child:
0.00%)
E - PeakMemoryUsage: 0
E - RowsSent: 25 (25)
E - RowsSentRate: 1.04 K/sec
E EXCHANGE_NODE (id=1):(Total: 91.999ms, non-child: 0.000ns, %
non-child: 0.00%)
E Node Lifecycle Event Timeline: 199.998ms
E - Open Started: 83.999ms (83.999ms)
E - Open Finished: 175.998ms (91.999ms)
E - First Batch Requested: 175.998ms (0.000ns)
E - First Batch Returned: 175.998ms (0.000ns)
E - Last Batch Returned: 175.998ms (0.000ns)
E - Closed: 199.998ms (23.999ms)
E - ConvertRowBatchTime: 0.000ns
E - PeakMemoryUsage: 16.00 KB (16384)
E - RowsReturned: 25 (25)
E - RowsReturnedRate: 271.00 /sec
E Buffer pool:
E - AllocTime: 0.000ns
E - CumulativeAllocationBytes: 16.00 KB (16384)
E - CumulativeAllocations: 2 (2)
E - PeakReservation: 16.00 KB (16384)
E - PeakUnpinnedBytes: 0
E - PeakUsedReservation: 16.00 KB (16384)
E - ReadIoBytes: 0
E - ReadIoOps: 0 (0)
E - ReadIoWaitTime: 0.000ns
E - SystemAllocTime: 0.000ns
E - WriteIoBytes: 0
E - WriteIoOps: 0 (0)
E - WriteIoWaitTime: 0.000ns
E Dequeue:
E - BytesDequeued (500.000ms): 0
E - FirstBatchWaitTime: 91.999ms
E - TotalBytesDequeued: 5.87 KB (6006)
E - TotalGetBatchTime: 91.999ms
E - DataWaitTime: 91.999ms
E Enqueue:
E - BytesReceived (500.000ms): 0
E - DeferredQueueSize (500.000ms): 0
E - DispatchTime: (Avg: 101.747us ; Min: 101.747us ; Max:
101.747us ; Number of samples: 1)
E - DeserializeRowBatchTime: 0.000ns
E - TotalBatchesEnqueued: 1 (1)
E - TotalBatchesReceived: 1 (1)
E - TotalBytesReceived: 3.30 KB (3375)
E - TotalEarlySenders: 0 (0)
E - TotalEosReceived: 3 (3)
E - TotalHasDeferredRPCsTime: 0.000ns
E - TotalRPCsDeferred: 0 (0)
E CodeGen:(Total: 83.999ms, non-child: 83.999ms, % non-child: 100.00%)
E - CodegenInvoluntaryContextSwitches: 9 (9)
E - CodegenTotalWallClockTime: 83.999ms
E - CodegenSysTime: 0.000ns
E - CodegenUserTime: 80.000ms
E - CodegenVoluntaryContextSwitches: 0 (0)
E - CompileTime: 7.999ms
E - IrGenerationTime: 0.000ns
E - LoadTime: 0.000ns
E - ModuleBitcodeSize: 2.44 MB (2558836)
E - NumFunctions: 20 (20)
E - NumInstructions: 404 (404)
E - OptimizationTime: 39.999ms
E - PeakMemoryUsage: 202.00 KB (206848)
E - PrepareTime: 31.999ms
E Averaged Fragment F00:(Total: 99.999ms, non-child: 0.000ns, %
non-child: 0.00%)
E split sizes: min: 55.81 MB, max: 69.22 MB, avg: 64.66 MB, stddev:
6.26 MB
E completion times: min:59.999ms max:203.998ms mean: 147.999ms
stddev:62.991ms
E execution rates: min:273.57 MB/sec max:1.12 GB/sec mean:602.41
MB/sec stddev:389.21 MB/sec
E num instances: 3
E - AverageThreadTokens: 0.67
E - BloomFilterBytes: 0
E - ExchangeScanRatio: 0.00
E - PeakMemoryUsage: 41.76 MB (43785568)
E - PeakReservation: 40.00 MB (41943040)
E - PeakUsedReservation: 0
E - PerHostPeakMemUsage: 41.89 MB (43926734)
E - RowsProduced: 8 (8)
E - TotalNetworkReceiveTime: 0.000ns
E - TotalNetworkSendTime: 2.666ms
E - TotalStorageWaitTime: 0.000ns
E - TotalThreadsInvoluntaryContextSwitches: 25 (25)
E - TotalThreadsTotalWallClockTime: 134.665ms
E - TotalThreadsSysTime: 0.000ns
E - TotalThreadsUserTime: 93.333ms
E - TotalThreadsVoluntaryContextSwitches: 10 (10)
E Buffer pool:
E - AllocTime: 0.000ns
E - CumulativeAllocationBytes: 0
E - CumulativeAllocations: 0 (0)
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 - WriteIoBytes: 0
E - WriteIoOps: 0 (0)
E - WriteIoWaitTime: 0.000ns
E Fragment Instance Lifecycle Timings:
E - ExecTime: 37.333ms
E - ExecTreeExecTime: 34.666ms
E - OpenTime: 62.666ms
E - ExecTreeOpenTime: 0.000ns
E - PrepareTime: 0.000ns
E - ExecTreePrepareTime: 0.000ns
E KrpcDataStreamSender (dst_id=1):(Total: 2.666ms, non-child: 2.666ms,
% non-child: 100.00%)
E - EosSent: 1 (1)
E - PeakMemoryUsage: 824.00 B (824)
E - RowsSent: 8 (8)
E - RpcFailure: 0 (0)
E - RpcRetry: 0 (0)
E - SerializeBatchTime: 0.000ns
E - TotalBytesSent: 1.10 KB (1125)
E - UncompressedRowBatchSize: 1.96 KB (2002)
E HDFS_SCAN_NODE (id=0):(Total: 34.666ms, non-child: 34.666ms, %
non-child: 100.00%)
E - AverageHdfsReadThreadConcurrency: 0.00
E - AverageScannerThreadConcurrency: 0.33
E - BytesRead: 1.15 MB (1205771)
E - BytesReadDataNodeCache: 0
E - BytesReadLocal: 1.15 MB (1205771)
E - BytesReadRemoteUnexpected: 0
E - BytesReadShortCircuit: 1.15 MB (1205771)
E - CachedFileHandlesHitCount: 9 (9)
E - CachedFileHandlesMissCount: 0 (0)
E - CollectionItemsRead: 0 (0)
E - DataCacheHitBytes: 0
E - DataCacheHitCount: 0 (0)
E - DataCacheMissBytes: 0
E - DataCacheMissCount: 0 (0)
E - DataCachePartialHitCount: 0 (0)
E - DecompressionTime: 2.666ms
E - MaterializeTupleTime(*): 5.333ms
E - MaxCompressedTextFileLength: 0
E - NumColumns: 16 (16)
E - NumDictFilteredRowGroups: 0 (0)
E - NumDisksAccessed: 1 (1)
E - NumPages: 666 (666)
E - NumRowGroups: 1 (1)
E - NumRowGroupsWithPageIndex: 1 (1)
E - NumScannerThreadMemUnavailable: 0 (0)
E - NumScannerThreadReservationsDenied: 0 (0)
E - NumScannerThreadsStarted: 1 (1)
E - NumScannersWithNoReads: 0 (0)
E - NumStatsFilteredPages: 651 (651)
E - NumStatsFilteredRowGroups: 0 (0)
E - PeakMemoryUsage: 41.75 MB (43775309)
E - PeakScannerThreadConcurrency: 1 (1)
E - PerReadThreadRawHdfsThroughput: 135.60 MB/sec
E - RemoteScanRanges: 0 (0)
E - RowBatchBytesEnqueued: 1.03 MB (1075813)
E - RowBatchQueueGetWaitTime: 34.666ms
E - RowBatchQueuePeakMemoryUsage: 573.41 KB (587175)
E - RowBatchQueuePutWaitTime: 0.000ns
E - RowBatchesEnqueued: 2 (2)
E - RowsRead: 10.77K (10766)
E - RowsReturned: 8 (8)
E - RowsReturnedRate: 80.00 /sec
E - ScanRangesComplete: 1 (1)
E - ScannerIoWaitTime: 0.000ns
E - ScannerThreadWorklessLoops: 0 (0)
E - ScannerThreadsInvoluntaryContextSwitches: 5 (5)
E - ScannerThreadsTotalWallClockTime: 34.666ms
E - ScannerThreadsSysTime: 0.000ns
E - ScannerThreadsUserTime: 33.333ms
E - ScannerThreadsVoluntaryContextSwitches: 5 (5)
E - TotalRawHdfsOpenFileTime(*): 0.000ns
E - TotalRawHdfsReadTime(*): 2.666ms
E - TotalReadThroughput: 2.17 MB/sec
E Buffer pool:
E - AllocTime: 0.000ns
E - CumulativeAllocationBytes: 1.50 MB (1572864)
E - CumulativeAllocations: 6 (6)
E - PeakReservation: 40.00 MB (41943040)
E - PeakUnpinnedBytes: 0
E - PeakUsedReservation: 1.46 MB (1529173)
E - ReadIoBytes: 0
E - ReadIoOps: 0 (0)
E - ReadIoWaitTime: 0.000ns
E - SystemAllocTime: 0.000ns
E - WriteIoBytes: 0
E - WriteIoOps: 0 (0)
E - WriteIoWaitTime: 0.000ns
E CodeGen:(Total: 62.666ms, non-child: 62.666ms, % non-child: 100.00%)
E - CodegenInvoluntaryContextSwitches: 20 (20)
E - CodegenTotalWallClockTime: 62.666ms
E - CodegenSysTime: 0.000ns
E - CodegenUserTime: 56.000ms
E - CodegenVoluntaryContextSwitches: 0 (0)
E - CompileTime: 3.999ms
E - IrGenerationTime: 2.666ms
E - LoadTime: 0.000ns
E - ModuleBitcodeSize: 2.44 MB (2558836)
E - NumFunctions: 16 (16)
E - NumInstructions: 262 (262)
E - OptimizationTime: 29.333ms
E - PeakMemoryUsage: 131.00 KB (134144)
E - PrepareTime: 25.333ms
E Fragment F00:
E Instance 3b48738ce971e36b:b6f52bf500000001
(host=ip-172-31-20-105:22002):(Total: 175.998ms, non-child: 0.000ns, %
non-child: 0.00%)
E Last report received time: 2019-10-24 21:22:06.495
E Hdfs split stats (<volume id>:<# splits>/<split lengths>):
0:1/69.22 MB
E Fragment Instance Lifecycle Event Timeline: 175.998ms
E - Prepare Finished: 0.000ns (0.000ns)
E - Open Finished: 71.999ms (71.999ms)
E - First Batch Produced: 175.998ms (103.999ms)
E - First Batch Sent: 175.998ms (0.000ns)
E - ExecInternal Finished: 175.998ms (0.000ns)
E - MemoryUsage (500.000ms): 43.26 MB
E - ThreadUsage (500.000ms): 2
E - AverageThreadTokens: 2.00
E - BloomFilterBytes: 0
E - ExchangeScanRatio: 0.00
E - PeakMemoryUsage: 45.20 MB (47392762)
E - PeakReservation: 40.00 MB (41943040)
E - PeakUsedReservation: 0
E - PerHostPeakMemUsage: 45.20 MB (47392762)
E - RowsProduced: 25 (25)
E - TotalNetworkReceiveTime: 0.000ns
E - TotalNetworkSendTime: 0.000ns
E - TotalStorageWaitTime: 0.000ns
E - TotalThreadsInvoluntaryContextSwitches: 40 (40)
E - TotalThreadsTotalWallClockTime: 279.998ms
E - TotalThreadsSysTime: 0.000ns
E - TotalThreadsUserTime: 168.000ms
E - TotalThreadsVoluntaryContextSwitches: 18 (18)
E Buffer pool:
E - AllocTime: 0.000ns
E - CumulativeAllocationBytes: 0
E - CumulativeAllocations: 0 (0)
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 - WriteIoBytes: 0
E - WriteIoOps: 0 (0)
E - WriteIoWaitTime: 0.000ns
E Fragment Instance Lifecycle Timings:
E - ExecTime: 103.999ms
E - ExecTreeExecTime: 103.999ms
E - OpenTime: 71.999ms
E - ExecTreeOpenTime: 0.000ns
E - PrepareTime: 0.000ns
E - ExecTreePrepareTime: 0.000ns
E KrpcDataStreamSender (dst_id=1):
E ExecOption: Unpartitioned Sender Codegen Disabled: not needed
E - BytesSent (500.000ms): 0
E - NetworkThroughput: (Avg: 3.49 MB/sec ; Min: 3.49 MB/sec ; Max:
3.49 MB/sec ; Number of samples: 1)
E - EosSent: 1 (1)
E - PeakMemoryUsage: 824.00 B (824)
E - RowsSent: 25 (25)
E - RpcFailure: 0 (0)
E - RpcRetry: 0 (0)
E - SerializeBatchTime: 0.000ns
E - TotalBytesSent: 3.30 KB (3375)
E - UncompressedRowBatchSize: 5.87 KB (6006)
E HDFS_SCAN_NODE (id=0):(Total: 103.999ms, non-child: 103.999ms, %
non-child: 100.00%)
E Hdfs split stats (<volume id>:<# splits>/<split lengths>):
0:1/69.22 MB
E ExecOption: PARQUET Codegen Enabled, Codegen enabled: 1 out of 1
E Hdfs Read Thread Concurrency Bucket: 0:100% 1:0% 2:0% 3:0% 4:0%
5:0% 6:0% 7:0%
E File Formats: PARQUET/SNAPPY:1
E Node Lifecycle Event Timeline: 175.998ms
E - Open Started: 71.999ms (71.999ms)
E - Open Finished: 71.999ms (0.000ns)
E - First Batch Requested: 71.999ms (0.000ns)
E - First Batch Returned: 175.998ms (103.999ms)
E - Last Batch Returned: 175.998ms (0.000ns)
E - Closed: 175.998ms (0.000ns)
E - BytesRead (500.000ms): 3.25 MB
E - FooterProcessingTime: (Avg: 3.999ms ; Min: 3.999ms ; Max:
3.999ms ; Number of samples: 1)
E - InitialRangeActualReservation: (Avg: 40.00 MB (41943040) ;
Min: 40.00 MB (41943040) ; Max: 40.00 MB (41943040) ; Number of samples: 1)
E - InitialRangeIdealReservation: (Avg: 128.00 KB (131072) ; Min:
128.00 KB (131072) ; Max: 128.00 KB (131072) ; Number of samples: 1)
E - PageIndexProcessingTime: (Avg: 31.999ms ; Min: 31.999ms ; Max:
31.999ms ; Number of samples: 1)
E - ParquetCompressedBytesReadPerColumn: (Avg: 125.41 KB (128421)
; Min: 30.69 KB (31424) ; Max: 429.91 KB (440228) ; Number of samples: 16)
E - ParquetCompressedPageSize: (Avg: 45.60 KB (46698) ; Min: 26.67
KB (27308) ; Max: 74.06 KB (75841) ; Number of samples: 44)
E - ParquetRowGroupActualReservation: (Avg: 40.00 MB (41943040) ;
Min: 40.00 MB (41943040) ; Max: 40.00 MB (41943040) ; Number of samples: 1)
E - ParquetRowGroupIdealReservation: (Avg: 4.12 MB (4325376) ;
Min: 4.12 MB (4325376) ; Max: 4.12 MB (4325376) ; Number of samples: 1)
E - ParquetUncompressedBytesReadPerColumn: (Avg: 176.66 KB
(180896) ; Min: 61.84 KB (63321) ; Max: 1023.81 KB (1048379) ; Number of
samples: 16)
E - ParquetUncompressedPageSize: (Avg: 64.24 KB (65780) ; Min:
61.84 KB (63321) ; Max: 78.89 KB (80788) ; Number of samples: 44)
E - AverageHdfsReadThreadConcurrency: 0.00
E - AverageScannerThreadConcurrency: 1.00
E - BytesRead: 3.25 MB (3412514)
E - BytesReadDataNodeCache: 0
E - BytesReadLocal: 3.25 MB (3412514)
E - BytesReadRemoteUnexpected: 0
E - BytesReadShortCircuit: 3.25 MB (3412514)
E - CachedFileHandlesHitCount: 27 (27)
E - CachedFileHandlesMissCount: 0 (0)
E - CollectionItemsRead: 0 (0)
E - DataCacheHitBytes: 0
E - DataCacheHitCount: 0 (0)
E - DataCacheMissBytes: 0
E - DataCacheMissCount: 0 (0)
E - DataCachePartialHitCount: 0 (0)
E - DecompressionTime: 7.999ms
E - MaterializeTupleTime(*): 15.999ms
E - MaxCompressedTextFileLength: 0
E - NumColumns: 16 (16)
E - NumDictFilteredRowGroups: 0 (0)
E - NumDisksAccessed: 1 (1)
E - NumPages: 2.00K (1998)
E - NumRowGroups: 1 (1)
E - NumRowGroupsWithPageIndex: 1 (1)
E - NumScannerThreadMemUnavailable: 0 (0)
E - NumScannerThreadReservationsDenied: 0 (0)
E - NumScannerThreadsStarted: 1 (1)
E - NumScannersWithNoReads: 0 (0)
E - NumStatsFilteredPages: 1.95K (1954)
E - NumStatsFilteredRowGroups: 0 (0)
E - PeakMemoryUsage: 45.19 MB (47382503)
E - PeakScannerThreadConcurrency: 1 (1)
E - PerReadThreadRawHdfsThroughput: 406.81 MB/sec
E - RemoteScanRanges: 0 (0)
E - RowBatchBytesEnqueued: 3.08 MB (3227439)
E - RowBatchQueueGetWaitTime: 103.999ms
E - RowBatchQueuePeakMemoryUsage: 1.65 MB (1728758)
E - RowBatchQueuePutWaitTime: 0.000ns
E - RowBatchesEnqueued: 3 (3)
E - RowsRead: 32.30K (32300)
E - RowsReturned: 25 (25)
E - RowsReturnedRate: 240.00 /sec
E - ScanRangesComplete: 1 (1)
E - ScannerIoWaitTime: 0.000ns
E - ScannerThreadWorklessLoops: 0 (0)
E - ScannerThreadsInvoluntaryContextSwitches: 17 (17)
E - ScannerThreadsTotalWallClockTime: 103.999ms
E - ScannerThreadsSysTime: 0.000ns
E - ScannerThreadsUserTime: 100.000ms
E - ScannerThreadsVoluntaryContextSwitches: 12 (12)
E - TotalRawHdfsOpenFileTime(*): 0.000ns
E - TotalRawHdfsReadTime(*): 7.999ms
E - TotalReadThroughput: 6.51 MB/sec
E Buffer pool:
E - AllocTime: 0.000ns
E - CumulativeAllocationBytes: 4.25 MB (4456448)
E - CumulativeAllocations: 17 (17)
E - PeakReservation: 40.00 MB (41943040)
E - PeakUnpinnedBytes: 0
E - PeakUsedReservation: 4.12 MB (4325376)
E - ReadIoBytes: 0
E - ReadIoOps: 0 (0)
E - ReadIoWaitTime: 0.000ns
E - SystemAllocTime: 0.000ns
E - WriteIoBytes: 0
E - WriteIoOps: 0 (0)
E - WriteIoWaitTime: 0.000ns
E CodeGen:(Total: 71.999ms, non-child: 71.999ms, % non-child: 100.00%)
E - CodegenInvoluntaryContextSwitches: 23 (23)
E - CodegenTotalWallClockTime: 71.999ms
E - CodegenSysTime: 0.000ns
E - CodegenUserTime: 64.000ms
E - CodegenVoluntaryContextSwitches: 0 (0)
E - CompileTime: 3.999ms
E - IrGenerationTime: 3.999ms
E - LoadTime: 0.000ns
E - ModuleBitcodeSize: 2.44 MB (2558836)
E - NumFunctions: 16 (16)
E - NumInstructions: 262 (262)
E - OptimizationTime: 31.999ms
E - PeakMemoryUsage: 131.00 KB (134144)
E - PrepareTime: 31.999ms
E Instance 3b48738ce971e36b:b6f52bf500000003
(host=ip-172-31-20-105:22000):(Total: 63.999ms, non-child: 0.000ns, %
non-child: 0.00%)
E Last report received time: 2019-10-24 21:22:06.519
E Hdfs split stats (<volume id>:<# splits>/<split lengths>):
1:1/55.81 MB
E Fragment Instance Lifecycle Event Timeline: 63.999ms
E - Prepare Finished: 0.000ns (0.000ns)
E - Open Finished: 59.999ms (59.999ms)
E - First Batch Produced: 59.999ms (0.000ns)
E - First Batch Sent: 59.999ms (0.000ns)
E - ExecInternal Finished: 63.999ms (3.999ms)
E - AverageThreadTokens: 0.00
E - BloomFilterBytes: 0
E - ExchangeScanRatio: 0.00
E - PeakMemoryUsage: 40.04 MB (41981971)
E - PeakReservation: 40.00 MB (41943040)
E - PeakUsedReservation: 0
E - PerHostPeakMemUsage: 40.34 MB (42301240)
E - RowsProduced: 0 (0)
E - TotalNetworkReceiveTime: 0.000ns
E - TotalNetworkSendTime: 3.999ms
E - TotalStorageWaitTime: 0.000ns
E - TotalThreadsInvoluntaryContextSwitches: 26 (26)
E - TotalThreadsTotalWallClockTime: 63.999ms
E - TotalThreadsSysTime: 0.000ns
E - TotalThreadsUserTime: 56.000ms
E - TotalThreadsVoluntaryContextSwitches: 6 (6)
E Buffer pool:
E - AllocTime: 0.000ns
E - CumulativeAllocationBytes: 0
E - CumulativeAllocations: 0 (0)
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 - WriteIoBytes: 0
E - WriteIoOps: 0 (0)
E - WriteIoWaitTime: 0.000ns
E Fragment Instance Lifecycle Timings:
E - ExecTime: 3.999ms
E - ExecTreeExecTime: 0.000ns
E - OpenTime: 59.999ms
E - ExecTreeOpenTime: 0.000ns
E - PrepareTime: 0.000ns
E - ExecTreePrepareTime: 0.000ns
E KrpcDataStreamSender (dst_id=1):(Total: 3.999ms, non-child:
0.000ns, % non-child: 0.00%)
E ExecOption: Unpartitioned Sender Codegen Disabled: not needed
E - NetworkThroughput: 0.00 /sec (Number of samples: 0)
E - EosSent: 1 (1)
E - PeakMemoryUsage: 824.00 B (824)
E - RowsSent: 0 (0)
E - RpcFailure: 0 (0)
E - RpcRetry: 0 (0)
E - SerializeBatchTime: 0.000ns
E - TotalBytesSent: 0
E - UncompressedRowBatchSize: 0
E HDFS_SCAN_NODE (id=0):
E Hdfs split stats (<volume id>:<# splits>/<split lengths>):
1:1/55.81 MB
E ExecOption: PARQUET Codegen Enabled, Codegen enabled: 1 out of 1
E Hdfs Read Thread Concurrency Bucket: 0:0% 1:0% 2:0% 3:0% 4:0%
5:0% 6:0% 7:0%
E File Formats: PARQUET/NONE:1
E Node Lifecycle Event Timeline: 63.999ms
E - Open Started: 59.999ms (59.999ms)
E - Open Finished: 59.999ms (0.000ns)
E - First Batch Requested: 59.999ms (0.000ns)
E - First Batch Returned: 59.999ms (0.000ns)
E - Last Batch Returned: 59.999ms (0.000ns)
E - Closed: 63.999ms (3.999ms)
E - FooterProcessingTime: (Avg: 0.000ns ; Min: 0.000ns ; Max:
0.000ns ; Number of samples: 1)
E - InitialRangeActualReservation: (Avg: 40.00 MB (41943040) ;
Min: 40.00 MB (41943040) ; Max: 40.00 MB (41943040) ; Number of samples: 1)
E - InitialRangeIdealReservation: (Avg: 128.00 KB (131072) ; Min:
128.00 KB (131072) ; Max: 128.00 KB (131072) ; Number of samples: 1)
E - PageIndexProcessingTime: 0.000ns (Number of samples: 0)
E - ParquetCompressedBytesReadPerColumn: 0 (Number of samples: 0)
E - ParquetCompressedPageSize: 0 (Number of samples: 0)
E - ParquetRowGroupActualReservation: 0 (Number of samples: 0)
E - ParquetRowGroupIdealReservation: 0 (Number of samples: 0)
E - ParquetUncompressedBytesReadPerColumn: 0 (Number of samples: 0)
E - ParquetUncompressedPageSize: 0 (Number of samples: 0)
E - AverageHdfsReadThreadConcurrency: 0.00
E - AverageScannerThreadConcurrency: 0.00
E - BytesRead: 100.00 KB (102400)
E - BytesReadDataNodeCache: 0
E - BytesReadLocal: 100.00 KB (102400)
E - BytesReadRemoteUnexpected: 0
E - BytesReadShortCircuit: 100.00 KB (102400)
E - CachedFileHandlesHitCount: 1 (1)
E - CachedFileHandlesMissCount: 0 (0)
E - CollectionItemsRead: 0 (0)
E - DataCacheHitBytes: 0
E - DataCacheHitCount: 0 (0)
E - DataCacheMissBytes: 0
E - DataCacheMissCount: 0 (0)
E - DataCachePartialHitCount: 0 (0)
E - DecompressionTime: 0.000ns
E - MaterializeTupleTime(*): 0.000ns
E - MaxCompressedTextFileLength: 0
E - NumColumns: 16 (16)
E - NumDictFilteredRowGroups: 0 (0)
E - NumDisksAccessed: 1 (1)
E - NumPages: 0 (0)
E - NumRowGroups: 1 (1)
E - NumRowGroupsWithPageIndex: 1 (1)
E - NumScannerThreadMemUnavailable: 0 (0)
E - NumScannerThreadReservationsDenied: 0 (0)
E - NumScannerThreadsStarted: 1 (1)
E - NumScannersWithNoReads: 0 (0)
E - NumStatsFilteredPages: 0 (0)
E - NumStatsFilteredRowGroups: 1 (1)
E - PeakMemoryUsage: 40.03 MB (41971712)
E - PeakScannerThreadConcurrency: 1 (1)
E - PerReadThreadRawHdfsThroughput: 0.00 /sec
E - RemoteScanRanges: 0 (0)
E - RowBatchBytesEnqueued: 0
E - RowBatchQueueGetWaitTime: 0.000ns
E - RowBatchQueuePeakMemoryUsage: 16.00 KB (16384)
E - RowBatchQueuePutWaitTime: 0.000ns
E - RowBatchesEnqueued: 2 (2)
E - RowsRead: 0 (0)
E - RowsReturned: 0 (0)
E - RowsReturnedRate: 0
E - ScanRangesComplete: 1 (1)
E - ScannerIoWaitTime: 0.000ns
E - ScannerThreadWorklessLoops: 0 (0)
E - ScannerThreadsInvoluntaryContextSwitches: 0 (0)
E - ScannerThreadsTotalWallClockTime: 0.000ns
E - ScannerThreadsSysTime: 0.000ns
E - ScannerThreadsUserTime: 0.000ns
E - ScannerThreadsVoluntaryContextSwitches: 2 (2)
E - TotalRawHdfsOpenFileTime(*): 0.000ns
E - TotalRawHdfsReadTime(*): 0.000ns
E - TotalReadThroughput: 0.00 /sec
E Buffer pool:
E - AllocTime: 0.000ns
E - CumulativeAllocationBytes: 128.00 KB (131072)
E - CumulativeAllocations: 1 (1)
E - PeakReservation: 40.00 MB (41943040)
E - PeakUnpinnedBytes: 0
E - PeakUsedReservation: 128.00 KB (131072)
E - ReadIoBytes: 0
E - ReadIoOps: 0 (0)
E - ReadIoWaitTime: 0.000ns
E - SystemAllocTime: 0.000ns
E - WriteIoBytes: 0
E - WriteIoOps: 0 (0)
E - WriteIoWaitTime: 0.000ns
E CodeGen:(Total: 59.999ms, non-child: 59.999ms, % non-child: 100.00%)
E - CodegenInvoluntaryContextSwitches: 26 (26)
E - CodegenTotalWallClockTime: 59.999ms
E - CodegenSysTime: 0.000ns
E - CodegenUserTime: 52.000ms
E - CodegenVoluntaryContextSwitches: 0 (0)
E - CompileTime: 3.999ms
E - IrGenerationTime: 0.000ns
E - LoadTime: 0.000ns
E - ModuleBitcodeSize: 2.44 MB (2558836)
E - NumFunctions: 16 (16)
E - NumInstructions: 262 (262)
E - OptimizationTime: 27.999ms
E - PeakMemoryUsage: 131.00 KB (134144)
E - PrepareTime: 23.999ms
E Instance 3b48738ce971e36b:b6f52bf500000002
(host=ip-172-31-20-105:22001):(Total: 59.999ms, non-child: 0.000ns, %
non-child: 0.00%)
E Last report received time: 2019-10-24 21:22:06.376
E Hdfs split stats (<volume id>:<# splits>/<split lengths>):
1:1/68.94 MB
E Fragment Instance Lifecycle Event Timeline: 59.999ms
E - Prepare Finished: 0.000ns (0.000ns)
E - Open Finished: 55.999ms (55.999ms)
E - First Batch Produced: 55.999ms (0.000ns)
E - First Batch Sent: 55.999ms (0.000ns)
E - ExecInternal Finished: 59.999ms (3.999ms)
E - AverageThreadTokens: 0.00
E - BloomFilterBytes: 0
E - ExchangeScanRatio: 0.00
E - PeakMemoryUsage: 40.04 MB (41981971)
E - PeakReservation: 40.00 MB (41943040)
E - PeakUsedReservation: 0
E - PerHostPeakMemUsage: 40.14 MB (42086200)
E - RowsProduced: 0 (0)
E - TotalNetworkReceiveTime: 0.000ns
E - TotalNetworkSendTime: 3.999ms
E - TotalStorageWaitTime: 0.000ns
E - TotalThreadsInvoluntaryContextSwitches: 11 (11)
E - TotalThreadsTotalWallClockTime: 59.999ms
E - TotalThreadsSysTime: 0.000ns
E - TotalThreadsUserTime: 56.000ms
E - TotalThreadsVoluntaryContextSwitches: 6 (6)
E Buffer pool:
E - AllocTime: 0.000ns
E - CumulativeAllocationBytes: 0
E - CumulativeAllocations: 0 (0)
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 - WriteIoBytes: 0
E - WriteIoOps: 0 (0)
E - WriteIoWaitTime: 0.000ns
E Fragment Instance Lifecycle Timings:
E - ExecTime: 3.999ms
E - ExecTreeExecTime: 0.000ns
E - OpenTime: 55.999ms
E - ExecTreeOpenTime: 0.000ns
E - PrepareTime: 0.000ns
E - ExecTreePrepareTime: 0.000ns
E KrpcDataStreamSender (dst_id=1):(Total: 3.999ms, non-child:
0.000ns, % non-child: 0.00%)
E ExecOption: Unpartitioned Sender Codegen Disabled: not needed
E - NetworkThroughput: 0.00 /sec (Number of samples: 0)
E - EosSent: 1 (1)
E - PeakMemoryUsage: 824.00 B (824)
E - RowsSent: 0 (0)
E - RpcFailure: 0 (0)
E - RpcRetry: 0 (0)
E - SerializeBatchTime: 0.000ns
E - TotalBytesSent: 0
E - UncompressedRowBatchSize: 0
E HDFS_SCAN_NODE (id=0):
E Hdfs split stats (<volume id>:<# splits>/<split lengths>):
1:1/68.94 MB
E ExecOption: PARQUET Codegen Enabled, Codegen enabled: 1 out of 1
E Hdfs Read Thread Concurrency Bucket: 0:0% 1:0% 2:0% 3:0% 4:0%
5:0% 6:0% 7:0%
E File Formats: PARQUET/NONE:1
E Node Lifecycle Event Timeline: 59.999ms
E - Open Started: 55.999ms (55.999ms)
E - Open Finished: 55.999ms (0.000ns)
E - First Batch Requested: 55.999ms (0.000ns)
E - First Batch Returned: 55.999ms (0.000ns)
E - Last Batch Returned: 55.999ms (0.000ns)
E - Closed: 59.999ms (3.999ms)
E - FooterProcessingTime: (Avg: 0.000ns ; Min: 0.000ns ; Max:
0.000ns ; Number of samples: 1)
E - InitialRangeActualReservation: (Avg: 40.00 MB (41943040) ;
Min: 40.00 MB (41943040) ; Max: 40.00 MB (41943040) ; Number of samples: 1)
E - InitialRangeIdealReservation: (Avg: 128.00 KB (131072) ; Min:
128.00 KB (131072) ; Max: 128.00 KB (131072) ; Number of samples: 1)
E - PageIndexProcessingTime: 0.000ns (Number of samples: 0)
E - ParquetCompressedBytesReadPerColumn: 0 (Number of samples: 0)
E - ParquetCompressedPageSize: 0 (Number of samples: 0)
E - ParquetRowGroupActualReservation: 0 (Number of samples: 0)
E - ParquetRowGroupIdealReservation: 0 (Number of samples: 0)
E - ParquetUncompressedBytesReadPerColumn: 0 (Number of samples: 0)
E - ParquetUncompressedPageSize: 0 (Number of samples: 0)
E - AverageHdfsReadThreadConcurrency: 0.00
E - AverageScannerThreadConcurrency: 0.00
E - BytesRead: 100.00 KB (102400)
E - BytesReadDataNodeCache: 0
E - BytesReadLocal: 100.00 KB (102400)
E - BytesReadRemoteUnexpected: 0
E - BytesReadShortCircuit: 100.00 KB (102400)
E - CachedFileHandlesHitCount: 1 (1)
E - CachedFileHandlesMissCount: 0 (0)
E - CollectionItemsRead: 0 (0)
E - DataCacheHitBytes: 0
E - DataCacheHitCount: 0 (0)
E - DataCacheMissBytes: 0
E - DataCacheMissCount: 0 (0)
E - DataCachePartialHitCount: 0 (0)
E - DecompressionTime: 0.000ns
E - MaterializeTupleTime(*): 0.000ns
E - MaxCompressedTextFileLength: 0
E - NumColumns: 16 (16)
E - NumDictFilteredRowGroups: 0 (0)
E - NumDisksAccessed: 1 (1)
E - NumPages: 0 (0)
E - NumRowGroups: 1 (1)
E - NumRowGroupsWithPageIndex: 1 (1)
E - NumScannerThreadMemUnavailable: 0 (0)
E - NumScannerThreadReservationsDenied: 0 (0)
E - NumScannerThreadsStarted: 1 (1)
E - NumScannersWithNoReads: 0 (0)
E - NumStatsFilteredPages: 0 (0)
E - NumStatsFilteredRowGroups: 1 (1)
E - PeakMemoryUsage: 40.03 MB (41971712)
E - PeakScannerThreadConcurrency: 1 (1)
E - PerReadThreadRawHdfsThroughput: 0.00 /sec
E - RemoteScanRanges: 0 (0)
E - RowBatchBytesEnqueued: 0
E - RowBatchQueueGetWaitTime: 0.000ns
E - RowBatchQueuePeakMemoryUsage: 16.00 KB (16384)
E - RowBatchQueuePutWaitTime: 0.000ns
E - RowBatchesEnqueued: 2 (2)
E - RowsRead: 0 (0)
E - RowsReturned: 0 (0)
E - RowsReturnedRate: 0
E - ScanRangesComplete: 1 (1)
E - ScannerIoWaitTime: 0.000ns
E - ScannerThreadWorklessLoops: 0 (0)
E - ScannerThreadsInvoluntaryContextSwitches: 0 (0)
E - ScannerThreadsTotalWallClockTime: 0.000ns
E - ScannerThreadsSysTime: 0.000ns
E - ScannerThreadsUserTime: 0.000ns
E - ScannerThreadsVoluntaryContextSwitches: 2 (2)
E - TotalRawHdfsOpenFileTime(*): 0.000ns
E - TotalRawHdfsReadTime(*): 0.000ns
E - TotalReadThroughput: 0.00 /sec
E Buffer pool:
E - AllocTime: 0.000ns
E - CumulativeAllocationBytes: 128.00 KB (131072)
E - CumulativeAllocations: 1 (1)
E - PeakReservation: 40.00 MB (41943040)
E - PeakUnpinnedBytes: 0
E - PeakUsedReservation: 128.00 KB (131072)
E - ReadIoBytes: 0
E - ReadIoOps: 0 (0)
E - ReadIoWaitTime: 0.000ns
E - SystemAllocTime: 0.000ns
E - WriteIoBytes: 0
E - WriteIoOps: 0 (0)
E - WriteIoWaitTime: 0.000ns
E CodeGen:(Total: 55.999ms, non-child: 55.999ms, % non-child: 100.00%)
E - CodegenInvoluntaryContextSwitches: 11 (11)
E - CodegenTotalWallClockTime: 55.999ms
E - CodegenSysTime: 0.000ns
E - CodegenUserTime: 52.000ms
E - CodegenVoluntaryContextSwitches: 0 (0)
E - CompileTime: 3.999ms
E - IrGenerationTime: 3.999ms
E - LoadTime: 0.000ns
E - ModuleBitcodeSize: 2.44 MB (2558836)
E - NumFunctions: 16 (16)
E - NumInstructions: 262 (262)
E - OptimizationTime: 27.999ms
E - PeakMemoryUsage: 131.00 KB (134144)
E - PrepareTime: 19.999ms
Standard Error
SET
client_identifier=query_test/test_scanners.py::TestScannerReservation::()::test_scanners[protocol:beeswax|exec_option:{'batch_size':0;'num_nodes':0;'disable_codegen_rows_threshold':0;'disable_codegen':False;'abort_on_error':1;'exec_single_node_rows_threshold':0}|table_form;
-- connecting to: localhost:21000
-- connecting to localhost:21050 with impyla
-- 2019-10-24 21:22:05,050 INFO MainThread: Closing active operation
SET
client_identifier=query_test/test_scanners.py::TestScannerReservation::()::test_scanners[protocol:beeswax|exec_option:{'batch_size':0;'num_nodes':0;'disable_codegen_rows_threshold':0;'disable_codegen':False;'abort_on_error':1;'exec_single_node_rows_threshold':0}|table_form;
-- executing against localhost:21000
use functional;
-- 2019-10-24 21:22:05,075 INFO MainThread: Started query
e248ba275ba5e355:da835d2600000000
SET
client_identifier=query_test/test_scanners.py::TestScannerReservation::()::test_scanners[protocol:beeswax|exec_option:{'batch_size':0;'num_nodes':0;'disable_codegen_rows_threshold':0;'disable_codegen':False;'abort_on_error':1;'exec_single_node_rows_threshold':0}|table_form;
SET batch_size=0;
SET num_nodes=0;
SET disable_codegen_rows_threshold=0;
SET disable_codegen=False;
SET abort_on_error=1;
SET exec_single_node_rows_threshold=0;
-- 2019-10-24 21:22:05,079 INFO MainThread: Starting new HTTP connection
(1): localhost
-- executing against localhost:21000
select count(*)
from tpch.customer;
-- 2019-10-24 21:22:05,133 INFO MainThread: Started query
c0407fb4abe5cb79:01382c3c00000000
-- executing against localhost:21000
set debug_action="-1:OPEN:[email protected]";
-- 2019-10-24 21:22:05,314 INFO MainThread: Started query
3740903b380750d4:c3b6d70b00000000
-- executing against localhost:21000
select count(*)
from tpch.customer;
-- 2019-10-24 21:22:05,323 INFO MainThread: Started query
864d954f4cba7551:623d121e00000000
-- executing against localhost:21000
SET DEBUG_ACTION="";
-- 2019-10-24 21:22:05,507 INFO MainThread: Started query
5c4793e99d8d83c0:8fd8853800000000
-- executing against localhost:21000
select min(l_comment)
from tpch_parquet.lineitem;
-- 2019-10-24 21:22:05,517 INFO MainThread: Started query
0047aea945d7eab9:a2099f5900000000
-- executing against localhost:21000
set debug_action="-1:OPEN:[email protected]";
-- 2019-10-24 21:22:05,906 INFO MainThread: Started query
b943762af9702dd4:a30c282600000000
-- executing against localhost:21000
select min(l_comment)
from tpch_parquet.lineitem;
-- 2019-10-24 21:22:05,914 INFO MainThread: Started query
864966e3a973691f:0a495e4600000000
-- executing against localhost:21000
SET DEBUG_ACTION="";
-- 2019-10-24 21:22:06,301 INFO MainThread: Started query
ff43c88b7ebaf930:469f3bf600000000
-- executing against localhost:21000
select * from tpch_parquet.lineitem
where l_orderkey < 10;
{noformat}
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
