You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues-all@impala.apache.org by "Quanlong Huang (Jira)" <ji...@apache.org> on 2019/12/25 13:38:00 UTC

[jira] [Commented] (IMPALA-9091) query_test.test_scanners.TestScannerReservation.test_scanners flaky

    [ https://issues.apache.org/jira/browse/IMPALA-9091?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17003277#comment-17003277 ] 

Quanlong Huang commented on IMPALA-9091:
----------------------------------------

Hit this here: https://jenkins.impala.io/job/ubuntu-16.04-from-scratch/9400/

> 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-unsubscribe@impala.apache.org
For additional commands, e-mail: issues-all-help@impala.apache.org