[
https://issues.apache.org/jira/browse/IMPALA-9091?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17041085#comment-17041085
]
Zoltán Borók-Nagy commented on IMPALA-9091:
-------------------------------------------
Unfortunately I couldn't reproduce it. Seems like the test is flawed in some
way. I don't think it should be a blocker for the release.
> 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: Zoltán Borók-Nagy
> Priority: Critical
> Labels: flaky
>
> 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:SET_DENY_RESERVATION_PROBABILITY@1.0";
> -- 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:SET_DENY_RESERVATION_PROBABILITY@1.0";
> -- 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}
> The actual amount was:
> ParquetRowGroupIdealReservation: (Avg: 4.12 MB (4325376) ; Min: 4.12 MB
> (4325376) ; Max: 4.12 MB (4325376) ; Number of samples: 1)
> Compared to my system, the files sizes are pretty similar:
> {noformat}
> HDFS partitions=1/1 files=3 size=193.99MB
> {noformat}
> vs
> {noformat}
> E HDFS partitions=1/1 files=3 size=193.97MB
> {noformat}
> I think the file layout must just be slightly different.
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
---------------------------------------------------------------------
To unsubscribe, e-mail: issues-all-unsubscr...@impala.apache.org
For additional commands, e-mail: issues-all-h...@impala.apache.org
