[
https://issues.apache.org/jira/browse/IMPALA-8906?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16975289#comment-16975289
]
ASF subversion and git services commented on IMPALA-8906:
---------------------------------------------------------
Commit 96394b4e3f653139d0a9a36e34122528fae6dcde in impala's branch
refs/heads/master from Tamas Mate
[ https://gitbox.apache.org/repos/asf?p=impala.git;h=96394b4 ]
IMPALA-8906: Fix flaky profile observability test
The test_query_profile_contains_query_compilation_metadata_load_events
is flaky because only non-zero stats are printed and the test is not
prepared to handle lines appearing based on conditions.
In general, zero values are printed in the profile as well, this makes
profile parsing simpler. Therefore, instead of changing the test the
condition has been removed as part of this change and the test is
updated accordingly.
Change-Id: I7f6172d75294c1dea8f6be086ebb303725c92620
Reviewed-on: http://gerrit.cloudera.org:8080/14704
Tested-by: Impala Public Jenkins <impala-public-jenk...@cloudera.com>
Reviewed-by: Csaba Ringhofer <csringho...@cloudera.com>
> TestObservability.test_query_profile_contains_query_compilation_metadata_load_events
> is flaky
> ---------------------------------------------------------------------------------------------
>
> Key: IMPALA-8906
> URL: https://issues.apache.org/jira/browse/IMPALA-8906
> Project: IMPALA
> Issue Type: Bug
> Components: Backend
> Reporter: Sahil Takiar
> Assignee: Tamas Mate
> Priority: Major
> Labels: broken-build, flaky
> Attachments: jenkins.impala.io.txt
>
>
> This test failed in a recent run of ubuntu-16.04-dockerised-tests:
> [https://jenkins.impala.io/job/ubuntu-16.04-dockerised-tests/1100/testReport/junit/query_test.test_observability/TestObservability/test_query_profile_contains_query_compilation_metadata_load_events/]
> Error Message:
> {code:java}
> query_test/test_observability.py:340: in
> test_query_profile_contains_query_compilation_metadata_load_events
> self.__verify_profile_event_sequence(load_event_regexes, runtime_profile)
> query_test/test_observability.py:432: in __verify_profile_event_sequence
> assert event_regex_index == 0, \ E AssertionError:
> CatalogFetch.PartitionLists.Misses not in -
> CatalogFetch.PartitionLists.Hits: 1 E Query
> (id=56480a470616cf3c:7cfadfbe00000000): 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:
> 854d1d6ab3cb65b7:9ba11e621c088385 E Session Type: BEESWAX E
> Start Time: 2019-08-28 20:01:05.725329000 E End Time: 2019-08-28
> 20:01:07.305869000 E Query Type: QUERY E Query State:
> FINISHED E Query Status: OK E Impala Version: impalad version
> 3.4.0-SNAPSHOT DEBUG (build 207b1443ff1b116d2d031dc5325ce971af80c4a6) E
> User: ubuntu E Connected User: ubuntu E Delegated User: E
> Network Address: 172.18.0.1:44044 E Default Db: default E
> Sql Statement: select * from functional.alltypes E Coordinator:
> f6d78aab23cf:22000 E Query Options (set by configuration):
> DEBUG_ACTION=CRS_BEFORE_ADMISSION:SLEEP@1000,TIMEZONE=Zulu,CLIENT_IDENTIFIER=query_test/test_observability.py::TestObservability::()::test_exec_summary_in_runtime_profile
> E Query Options (set by configuration and planner):
> DEBUG_ACTION=CRS_BEFORE_ADMISSION:SLEEP@1000,MT_DOP=0,TIMEZONE=Zulu,CLIENT_IDENTIFIER=query_test/test_observability.py::TestObservability::()::test_exec_summary_in_runtime_profile
> E Plan: E ---------------- E Max Per-Host Resource
> Reservation: Memory=32.00KB Threads=3 E Per-Host Resource Estimates:
> Memory=160MB E Codegen disabled by planner E Analyzed query: SELECT *
> FROM functional.alltypes E E F01:PLAN FRAGMENT [UNPARTITIONED]
> hosts=1 instances=1 E | Per-Host Resources: mem-estimate=490.49KB
> mem-reservation=0B thread-reservation=1 E PLAN-ROOT SINK E |
> mem-estimate=0B mem-reservation=0B thread-reservation=0 E | E
> 01:EXCHANGE [UNPARTITIONED] E | mem-estimate=490.49KB mem-reservation=0B
> thread-reservation=0 E | tuple-ids=0 row-size=89B cardinality=7.30K E
> | in pipelines: 00(GETNEXT) E | E F00:PLAN FRAGMENT [RANDOM]
> hosts=3 instances=3 E Per-Host Resources: mem-estimate=160.00MB
> mem-reservation=32.00KB thread-reservation=2 E 00:SCAN HDFS
> [functional.alltypes, RANDOM] E HDFS partitions=24/24 files=24
> size=478.45KB E stored statistics: E table: rows=7.30K
> size=478.45KB E partitions: 24/24 rows=7.30K E columns: all
> E extrapolated-rows=disabled max-scan-range-rows=310 E
> mem-estimate=160.00MB mem-reservation=32.00KB thread-reservation=1 E
> tuple-ids=0 row-size=89B cardinality=7.30K E in pipelines: 00(GETNEXT)
> E ---------------- E Estimated Per-Host Mem: 168274422 E
> Request Pool: default-pool E Per Host Min Memory Reservation:
> 6db176633e3a:22000(32.00 KB) bf5c6b4d70c3:22000(32.00 KB)
> f6d78aab23cf:22000(32.00 KB) E Per Host Number of Fragment Instances:
> 6db176633e3a:22000(1) bf5c6b4d70c3:22000(1) f6d78aab23cf:22000(2) E
> Admission result: Admitted immediately E Cluster Memory Admitted:
> 481.44 MB 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 323.998ms 323.998ms
> 0 0 E 01:EXCHANGE
> 1 3.999ms 3.999ms 7.30K 7.30K 776.00 KB 490.49 KB
> UNPARTITIONED E F00:EXCHANGE SENDER 3 7.999ms 19.999ms
> 1.55 KB 0 E
> 00:SCAN HDFS 3 66.666ms 163.999ms 7.30K 7.30K 1.38
> MB 160.00 MB functional.alltypes E Errors: E Query
> Compilation: 139.437ms E - Metadata of all 1 tables cached:
> 116.233ms (116.233ms) E - Analysis finished: 116.458ms (225.333us)
> E - Authorization finished (noop): 116.480ms (21.466us) E
> - Value transfer graph computed: 116.628ms (148.642us) E -
> Single node plan created: 133.186ms (16.557ms) E - Runtime filters
> computed: 133.229ms (43.430us) E - Distributed plan created:
> 133.256ms (27.095us) E - Planning finished: 139.437ms (6.180ms) E
> Query Timeline: 1s587ms E - Query submitted: 0.000ns
> (0.000ns) E - Planning finished: 143.999ms (143.999ms) E
> - Submit for admission: 1s147ms (1s003ms) E - Completed
> admission: 1s147ms (0.000ns) E - Ready to start on 3 backends:
> 1s147ms (0.000ns) E - All 3 execution backends (4 fragment
> instances) started: 1s167ms (19.999ms) E - Rows available: 1s195ms
> (27.999ms) E - First row fetched: 1s211ms (15.999ms) E
> - Last row fetched: 1s575ms (363.998ms) E - Released admission
> control resources: 1s583ms (7.999ms) E -
> AdmissionControlTimeSinceLastUpdate: 77.000ms E -
> ComputeScanRangeAssignmentTimer: 0.000ns E Frontend: E -
> CatalogFetch.ColumnStats.Misses: 13 E -
> CatalogFetch.ColumnStats.Requests: 13 E -
> CatalogFetch.ColumnStats.Time: 9ms E - CatalogFetch.Config.Hits: 1
> E - CatalogFetch.Config.Requests: 1 E -
> CatalogFetch.Config.Time: 0 E - CatalogFetch.DatabaseList.Hits: 1
> E - CatalogFetch.DatabaseList.Requests: 1 E -
> CatalogFetch.DatabaseList.Time: 0 E -
> CatalogFetch.PartitionLists.Hits: 1 E -
> CatalogFetch.PartitionLists.Requests: 1 E -
> CatalogFetch.PartitionLists.Time: 0 E -
> CatalogFetch.Partitions.Hits: 48 E -
> CatalogFetch.Partitions.Misses: 20 E -
> CatalogFetch.Partitions.Requests: 68 E -
> CatalogFetch.Partitions.Time: 8ms E - CatalogFetch.RPCs.Bytes:
> 27.93 KB (28604) E - CatalogFetch.RPCs.Requests: 3 E -
> CatalogFetch.RPCs.Time: 116ms E - CatalogFetch.TableNames.Hits: 2
> E - CatalogFetch.TableNames.Requests: 2 E -
> CatalogFetch.TableNames.Time: 0 E - CatalogFetch.Tables.Misses: 1
> E - CatalogFetch.Tables.Requests: 1 E -
> CatalogFetch.Tables.Time: 105ms E ImpalaServer: E -
> ClientFetchWaitTimer: 51.999ms E - RowMaterializationTimer:
> 335.998ms E Execution Profile 56480a470616cf3c:7cfadfbe00000000:(Total:
> 383.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: 9ms / 17ms, 25th
> %-ile: 9ms, 50th %-ile: 10ms, 75th %-ile: 10ms, 90th %-ile: 17ms, 95th %-ile:
> 17ms, 99.9th %-ile: 17ms E Slowest backend to start up:
> bf5c6b4d70c3:22000 E Per Node Peak Memory Usage:
> 6db176633e3a:22000(1.63 MB) bf5c6b4d70c3:22000(1.62 MB)
> f6d78aab23cf:22000(1.06 MB) E Per Node Bytes Read:
> 6db176633e3a:22000(161.29 KB) bf5c6b4d70c3:22000(157.38 KB)
> f6d78aab23cf:22000(159.77 KB) E Per Node User Time:
> 6db176633e3a:22000(16.000ms) bf5c6b4d70c3:22000(16.000ms)
> f6d78aab23cf:22000(160.000ms) E Per Node System Time:
> 6db176633e3a:22000(0.000ns) bf5c6b4d70c3:22000(0.000ns)
> f6d78aab23cf:22000(0.000ns) E - ExchangeScanRatio: 0.59 E
> - FiltersReceived: 0 (0) E - FinalizationTimer: 0.000ns E -
> InnerNodeSelectivityRatio: 0.00 E - NumBackends: 3 (3) E -
> NumFragmentInstances: 4 (4) E - NumFragments: 2 (2) E -
> TotalBytesRead: 478.45 KB (489934) E - TotalBytesSent: 283.47 KB
> (290271) E - TotalCpuTime: 192.000ms E -
> TotalInnerBytesSent: 0 E - TotalScanBytesSent: 283.47 KB (290271) E
> Per Node Profiles: E 6db176633e3a:22000: 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 bf5c6b4d70c3:22000: 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 f6d78aab23cf:22000: 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: 403.998ms, non-child: 3.999ms, % non-child: 0.99%) E
> split sizes: min: 0, max: 0, avg: 0, stddev: 0 E completion times:
> min:415.998ms max:415.998ms mean: 415.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: 784.00 KB (802816) E - PeakReservation:
> 0 E - PeakUsedReservation: 0 E - PerHostPeakMemUsage:
> 1.06 MB (1113656) E - RowsProduced: 7.30K (7300) E -
> TotalNetworkReceiveTime: 23.999ms E - TotalNetworkSendTime:
> 0.000ns E - TotalStorageWaitTime: 0.000ns E -
> TotalThreadsInvoluntaryContextSwitches: 78 (78) E -
> TotalThreadsTotalWallClockTime: 399.998ms E -
> TotalThreadsSysTime: 0.000ns E - TotalThreadsUserTime: 140.000ms
> 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: 399.998ms E - ExecTreeExecTime:
> 27.999ms E - OpenTime: 0.000ns E -
> ExecTreeOpenTime: 0.000ns E - PrepareTime: 3.999ms E
> - ExecTreePrepareTime: 0.000ns E PLAN_ROOT_SINK:(Total:
> 371.998ms, non-child: 371.998ms, % non-child: 100.00%) E -
> PeakMemoryUsage: 0 E EXCHANGE_NODE (id=1):(Total: 27.999ms,
> non-child: 27.999ms, % non-child: 100.00%) E -
> ConvertRowBatchTime: 3.999ms E - PeakMemoryUsage: 776.00 KB
> (794624) E - RowsReturned: 7.30K (7300) E -
> RowsReturnedRate: 260.71 K/sec E Buffer pool: E -
> AllocTime: 0.000ns E - CumulativeAllocationBytes: 960.00 KB
> (983040) E - CumulativeAllocations: 48 (48) E -
> PeakReservation: 776.00 KB (794624) E - PeakUnpinnedBytes: 0 E
> - PeakUsedReservation: 776.00 KB (794624) 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: 0.000ns E - TotalBytesDequeued: 705.76 KB
> (722700) E - TotalGetBatchTime: 23.999ms E -
> DataWaitTime: 23.999ms E Enqueue: E -
> DeserializeRowBatchTime: 3.999ms E - TotalBatchesEnqueued: 24
> (24) E - TotalBatchesReceived: 24 (24) E -
> TotalBytesReceived: 283.47 KB (290271) E - TotalEarlySenders:
> 1 (1) E - TotalEosReceived: 3 (3) E -
> TotalHasDeferredRPCsTime: 53.864us E - TotalRPCsDeferred: 1
> (1) E Coordinator Fragment F01: E Instance
> 56480a470616cf3c:7cfadfbe00000000 (host=f6d78aab23cf:22000):(Total:
> 403.998ms, non-child: 3.999ms, % non-child: 0.99%) E Last report
> received time: 2019-08-28 20:01:07.300 E Fragment Instance
> Lifecycle Event Timeline: 415.998ms E - Prepare Finished:
> 15.999ms (15.999ms) E - Open Finished: 15.999ms (0.000ns) E
> - First Batch Produced: 39.999ms (23.999ms) E -
> First Batch Sent: 87.999ms (47.999ms) E - ExecInternal
> Finished: 415.998ms (327.998ms) E - MemoryUsage (500.000ms):
> 784.00 KB E - AverageThreadTokens: 0.00 E -
> BloomFilterBytes: 0 E - ExchangeScanRatio: 0.00 E
> - PeakMemoryUsage: 784.00 KB (802816) E - PeakReservation: 0 E
> - PeakUsedReservation: 0 E - PerHostPeakMemUsage:
> 1.06 MB (1113656) E - RowsProduced: 7.30K (7300) E
> - TotalNetworkReceiveTime: 23.999ms E - TotalNetworkSendTime:
> 0.000ns E - TotalStorageWaitTime: 0.000ns E -
> TotalThreadsInvoluntaryContextSwitches: 78 (78) E -
> TotalThreadsTotalWallClockTime: 399.998ms E -
> TotalThreadsSysTime: 0.000ns E - TotalThreadsUserTime:
> 140.000ms 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:
> 399.998ms E - ExecTreeExecTime: 27.999ms E -
> OpenTime: 0.000ns E - ExecTreeOpenTime: 0.000ns E
> - PrepareTime: 3.999ms E - ExecTreePrepareTime: 0.000ns
> E PLAN_ROOT_SINK:(Total: 371.998ms, non-child: 323.998ms, %
> non-child: 87.10%) E - PeakMemoryUsage: 0 E
> EXCHANGE_NODE (id=1):(Total: 27.999ms, non-child: 3.999ms, % non-child:
> 14.29%) E Node Lifecycle Event Timeline: 415.998ms E
> - Open Started: 15.999ms (15.999ms) E - Open Finished:
> 15.999ms (0.000ns) E - First Batch Requested: 15.999ms
> (0.000ns) E - First Batch Returned: 39.999ms (23.999ms) E
> - Last Batch Returned: 407.998ms (367.998ms) E
> - Closed: 415.998ms (7.999ms) E - ConvertRowBatchTime: 3.999ms
> E - PeakMemoryUsage: 776.00 KB (794624) E -
> RowsReturned: 7.30K (7300) E - RowsReturnedRate: 260.71 K/sec
> E Buffer pool: E - AllocTime: 0.000ns E
> - CumulativeAllocationBytes: 960.00 KB (983040) E
> - CumulativeAllocations: 48 (48) E - PeakReservation: 776.00
> KB (794624) E - PeakUnpinnedBytes: 0 E -
> PeakUsedReservation: 776.00 KB (794624) 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): 502.73 KB E - FirstBatchWaitTime:
> 0.000ns E - TotalBytesDequeued: 705.76 KB (722700) E
> - TotalGetBatchTime: 23.999ms E - DataWaitTime:
> 23.999ms E Enqueue: E - BytesReceived
> (500.000ms): 283.47 KB E - DeferredQueueSize (500.000ms): 0
> E - DispatchTime: (Avg: 178.622us ; Min: 53.536us ; Max:
> 1.203ms ; Number of samples: 23) E -
> DeserializeRowBatchTime: 3.999ms E - TotalBatchesEnqueued:
> 24 (24) E - TotalBatchesReceived: 24 (24) E
> - TotalBytesReceived: 283.47 KB (290271) E -
> TotalEarlySenders: 1 (1) E - TotalEosReceived: 3 (3) E
> - TotalHasDeferredRPCsTime: 53.864us E -
> TotalRPCsDeferred: 1 (1) E Averaged Fragment F00:(Total: 118.666ms,
> non-child: 0.000ns, % non-child: 0.00%) E split sizes: min: 157.38
> KB, max: 161.29 KB, avg: 159.48 KB, stddev: 1.61 KB E completion
> times: min:95.999ms max:415.998ms mean: 205.332ms stddev:148.998ms E
> execution rates: min:384.07 KB/sec max:1.60 MB/sec mean:1.16 MB/sec
> stddev:572.06 KB/sec E num instances: 3 E -
> AverageThreadTokens: 0.00 E - BloomFilterBytes: 0 E -
> ExchangeScanRatio: 0.59 E - PeakMemoryUsage: 1.18 MB (1239266) E
> - PeakReservation: 117.33 KB (120149) E -
> PeakUsedReservation: 0 E - PerHostPeakMemUsage: 1.44 MB (1506872)
> E - RowsProduced: 2.43K (2433) E -
> TotalNetworkReceiveTime: 0.000ns E - TotalNetworkSendTime:
> 43.999ms E - TotalStorageWaitTime: 5.333ms E -
> TotalThreadsInvoluntaryContextSwitches: 41 (41) E -
> TotalThreadsTotalWallClockTime: 235.998ms E -
> TotalThreadsSysTime: 0.000ns E - TotalThreadsUserTime: 17.333ms
> E - TotalThreadsVoluntaryContextSwitches: 25 (25) 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: 117.332ms E - ExecTreeExecTime:
> 66.666ms E - OpenTime: 0.000ns E -
> ExecTreeOpenTime: 0.000ns E - PrepareTime: 1.333ms E
> - ExecTreePrepareTime: 0.000ns E KrpcDataStreamSender
> (dst_id=1):(Total: 51.999ms, non-child: 51.999ms, % non-child: 100.00%) E
> - EosSent: 1 (1) E - PeakMemoryUsage: 1.55 KB (1592) E
> - RowsSent: 2.43K (2433) E - RpcFailure: 0 (0) E
> - RpcRetry: 0 (0) E - SerializeBatchTime: 3.999ms E
> - TotalBytesSent: 94.49 KB (96757) E -
> UncompressedRowBatchSize: 235.25 KB (240900) E HDFS_SCAN_NODE
> (id=0):(Total: 66.666ms, non-child: 66.666ms, % non-child: 100.00%) E
> - AverageHdfsReadThreadConcurrency: 0.00 E -
> AverageScannerThreadConcurrency: 0.00 E - BytesRead: 159.48 KB
> (163311) E - BytesReadDataNodeCache: 0 E -
> BytesReadLocal: 0 E - BytesReadRemoteUnexpected: 0 E
> - BytesReadShortCircuit: 0 E - CachedFileHandlesHitCount: 8 (8)
> E - CachedFileHandlesMissCount: 0 (0) E -
> CollectionItemsRead: 0 (0) E - DataCacheHitBytes: 132.99 KB
> (136181) E - DataCacheHitCount: 6 (6) E -
> DataCacheMissBytes: 26.49 KB (27130) E - DataCacheMissCount: 1
> (1) E - DataCachePartialHitCount: 0 (0) E -
> DecompressionTime: 0.000ns E - DelimiterParseTime: 6.666ms E
> - MaterializeTupleTime(*): 67.999ms E -
> MaxCompressedTextFileLength: 0 E - NumDisksAccessed: 1 (1) E
> - NumScannerThreadMemUnavailable: 0 (0) E -
> NumScannerThreadReservationsDenied: 0 (0) E -
> NumScannerThreadsStarted: 2 (2) E - PeakMemoryUsage: 1.01 MB
> (1061546) E - PeakScannerThreadConcurrency: 2 (2) E
> - PerReadThreadRawHdfsThroughput: 4.27 MB/sec E -
> RemoteScanRanges: 4 (4) E - RowBatchBytesEnqueued: 1.95 MB
> (2048000) E - RowBatchQueueGetWaitTime: 58.666ms E
> - RowBatchQueuePeakMemoryUsage: 894.67 KB (916138) E -
> RowBatchQueuePutWaitTime: 0.000ns E - RowBatchesEnqueued: 16
> (16) E - RowsRead: 2.43K (2433) E - RowsReturned:
> 2.43K (2433) E - RowsReturnedRate: 27.18 K/sec E -
> ScanRangesComplete: 8 (8) E - ScannerIoWaitTime: 5.333ms E
> - ScannerThreadWorklessLoops: 0 (0) E -
> ScannerThreadsInvoluntaryContextSwitches: 39 (39) E -
> ScannerThreadsTotalWallClockTime: 118.666ms E -
> ScannerThreadsSysTime: 0.000ns E - ScannerThreadsUserTime:
> 13.333ms E - ScannerThreadsVoluntaryContextSwitches: 7 (7) E
> - TotalRawHdfsOpenFileTime(*): 0.000ns E -
> TotalRawHdfsReadTime(*): 3.999ms E - TotalReadThroughput: 0.00
> /sec E Buffer pool: E - AllocTime: 0.000ns E
> - CumulativeAllocationBytes: 256.00 KB (262144) E -
> CumulativeAllocations: 8 (8) E - PeakReservation: 117.33 KB
> (120149) E - PeakUnpinnedBytes: 0 E -
> PeakUsedReservation: 74.67 KB (76458) 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 Fragment F00: E Instance
> 56480a470616cf3c:7cfadfbe00000001 (host=f6d78aab23cf:22000):(Total:
> 167.999ms, non-child: 0.000ns, % non-child: 0.00%) E Last report
> received time: 2019-08-28 20:01:07.300 E Hdfs split stats
> (<volume id>:<# splits>/<split lengths>): -1:8/159.77 KB E
> Fragment Instance Lifecycle Event Timeline: 219.999ms E -
> Prepare Finished: 31.999ms (31.999ms) E - Open Finished:
> 31.999ms (0.000ns) E - First Batch Produced: 67.999ms
> (35.999ms) E - First Batch Sent: 67.999ms (0.000ns) E
> - ExecInternal Finished: 219.999ms (151.999ms) E -
> AverageThreadTokens: 0.00 E - BloomFilterBytes: 0 E
> - ExchangeScanRatio: 0.59 E - PeakMemoryUsage: 303.55 KB
> (310840) E - PeakReservation: 64.00 KB (65536) E -
> PeakUsedReservation: 0 E - PerHostPeakMemUsage: 1.06 MB
> (1113656) E - RowsProduced: 2.44K (2440) E -
> TotalNetworkReceiveTime: 0.000ns E - TotalNetworkSendTime:
> 3.999ms E - TotalStorageWaitTime: 0.000ns E -
> TotalThreadsInvoluntaryContextSwitches: 62 (62) E -
> TotalThreadsTotalWallClockTime: 331.998ms E -
> TotalThreadsSysTime: 0.000ns E - TotalThreadsUserTime:
> 20.000ms E - TotalThreadsVoluntaryContextSwitches: 27 (27) 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: 167.999ms E
> - ExecTreeExecTime: 163.999ms E - OpenTime: 0.000ns 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: Codegen Disabled: disabled due
> to optimization hints E - NetworkThroughput: (Avg: 32.50
> MB/sec ; Min: 1.83 MB/sec ; Max: 47.13 MB/sec ; Number of samples: 8) E
> - EosSent: 1 (1) E - PeakMemoryUsage: 1.55 KB (1592)
> E - RowsSent: 2.44K (2440) E - RpcFailure: 0
> (0) E - RpcRetry: 0 (0) E - SerializeBatchTime:
> 0.000ns E - TotalBytesSent: 94.89 KB (97166) E
> - UncompressedRowBatchSize: 235.90 KB (241560) E HDFS_SCAN_NODE
> (id=0):(Total: 163.999ms, non-child: 163.999ms, % non-child: 100.00%) E
> Hdfs split stats (<volume id>:<# splits>/<split lengths>):
> -1:8/159.77 KB E ExecOption: Codegen Disabled: disabled due to
> optimization hints, Codegen enabled: 0 out of 8 E Hdfs Read
> Thread Concurrency Bucket: 0:0% 1:0% 2:0% 3:0% 4:0% 5:0% 6:0% E
> File Formats: TEXT/NONE:8 E Node Lifecycle Event Timeline:
> 219.999ms E - Open Started: 31.999ms (31.999ms) E
> - Open Finished: 31.999ms (0.000ns) E - First Batch
> Requested: 31.999ms (0.000ns) E - First Batch Returned:
> 67.999ms (35.999ms) E - Last Batch Returned: 195.999ms
> (127.999ms) E - Closed: 219.999ms (23.999ms) E
> - InitialRangeActualReservation: (Avg: 32.00 KB (32768) ; Min: 32.00 KB
> (32768) ; Max: 32.00 KB (32768) ; Number of samples: 8) E -
> InitialRangeIdealReservation: (Avg: 32.00 KB (32768) ; Min: 32.00 KB (32768)
> ; Max: 32.00 KB (32768) ; Number of samples: 8) E -
> ParquetCompressedBytesReadPerColumn: 0 (Number of samples: 0) E
> - ParquetUncompressedBytesReadPerColumn: 0 (Number of samples: 0) E
> - AverageHdfsReadThreadConcurrency: 0.00 E -
> AverageScannerThreadConcurrency: 0.00 E - BytesRead: 159.77
> KB (163608) E - BytesReadDataNodeCache: 0 E -
> BytesReadLocal: 0 E - BytesReadRemoteUnexpected: 0 E
> - BytesReadShortCircuit: 0 E - CachedFileHandlesHitCount:
> 8 (8) E - CachedFileHandlesMissCount: 0 (0) E -
> CollectionItemsRead: 0 (0) E - DataCacheHitBytes: 159.77 KB
> (163608) E - DataCacheHitCount: 8 (8) E -
> DataCacheMissBytes: 0 E - DataCacheMissCount: 0 (0) E
> - DataCachePartialHitCount: 0 (0) E - DecompressionTime:
> 0.000ns E - DelimiterParseTime: 3.999ms E -
> MaterializeTupleTime(*): 143.999ms E -
> MaxCompressedTextFileLength: 0 E - NumDisksAccessed: 1 (1) E
> - NumScannerThreadMemUnavailable: 0 (0) E -
> NumScannerThreadReservationsDenied: 0 (0) E -
> NumScannerThreadsStarted: 1 (1) E - PeakMemoryUsage: 294.00 KB
> (301056) E - PeakScannerThreadConcurrency: 1 (1) E
> - PerReadThreadRawHdfsThroughput: 0.00 /sec E -
> RemoteScanRanges: 0 (0) E - RowBatchBytesEnqueued: 1.95 MB
> (2048000) E - RowBatchQueueGetWaitTime: 163.999ms E
> - RowBatchQueuePeakMemoryUsage: 254.00 KB (260096) E -
> RowBatchQueuePutWaitTime: 0.000ns E - RowBatchesEnqueued: 16
> (16) E - RowsRead: 2.44K (2440) E -
> RowsReturned: 2.44K (2440) E - RowsReturnedRate: 14.88 K/sec E
> - ScanRangesComplete: 8 (8) E -
> ScannerIoWaitTime: 0.000ns E - ScannerThreadWorklessLoops: 0
> (0) E - ScannerThreadsInvoluntaryContextSwitches: 60 (60) E
> - ScannerThreadsTotalWallClockTime: 163.999ms E
> - ScannerThreadsSysTime: 0.000ns E - ScannerThreadsUserTime:
> 16.000ms E - ScannerThreadsVoluntaryContextSwitches: 5 (5) E
> - TotalRawHdfsOpenFileTime(*): 0.000ns E -
> TotalRawHdfsReadTime(*): 0.000ns E - TotalReadThroughput: 0.00
> /sec E Buffer pool: E - AllocTime: 0.000ns E
> - CumulativeAllocationBytes: 256.00 KB (262144) E
> - CumulativeAllocations: 8 (8) E - PeakReservation:
> 64.00 KB (65536) E - PeakUnpinnedBytes: 0 E
> - PeakUsedReservation: 32.00 KB (32768) 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 Instance
> 56480a470616cf3c:7cfadfbe00000003 (host=6db176633e3a:22000):(Total: 99.999ms,
> non-child: 0.000ns, % non-child: 0.00%) E Last report received
> time: 2019-08-28 20:01:06.986 E Hdfs split stats (<volume id>:<#
> splits>/<split lengths>): -1:8/161.29 KB E Fragment Instance
> Lifecycle Event Timeline: 99.999ms E - Prepare Finished:
> 3.999ms (3.999ms) E - Open Finished: 3.999ms (0.000ns) E
> - First Batch Produced: 3.999ms (0.000ns) E - First
> Batch Sent: 11.999ms (7.999ms) E - ExecInternal Finished:
> 99.999ms (87.999ms) E - AverageThreadTokens: 0.00 E
> - BloomFilterBytes: 0 E - ExchangeScanRatio: 0.59 E
> - PeakMemoryUsage: 1.63 MB (1709624) E - PeakReservation:
> 128.00 KB (131072) E - PeakUsedReservation: 0 E -
> PerHostPeakMemUsage: 1.63 MB (1709624) E - RowsProduced: 2.46K
> (2460) E - TotalNetworkReceiveTime: 0.000ns E -
> TotalNetworkSendTime: 79.999ms E - TotalStorageWaitTime: 0.000ns
> E - TotalThreadsInvoluntaryContextSwitches: 36 (36) E
> - TotalThreadsTotalWallClockTime: 163.999ms E -
> TotalThreadsSysTime: 0.000ns E - TotalThreadsUserTime:
> 16.000ms E - TotalThreadsVoluntaryContextSwitches: 25 (25) 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: 95.999ms E
> - ExecTreeExecTime: 0.000ns E - OpenTime: 0.000ns E
> - ExecTreeOpenTime: 0.000ns E - PrepareTime:
> 3.999ms E - ExecTreePrepareTime: 0.000ns E
> KrpcDataStreamSender (dst_id=1):(Total: 99.999ms, non-child: 19.999ms, %
> non-child: 20.00%) E ExecOption: Codegen Disabled: disabled due
> to optimization hints E - NetworkThroughput: (Avg: 2.08 MB/sec
> ; Min: 892.97 KB/sec ; Max: 5.42 MB/sec ; Number of samples: 8) E
> - EosSent: 1 (1) E - PeakMemoryUsage: 1.55 KB (1592) E
> - RowsSent: 2.46K (2460) E - RpcFailure: 0 (0) E
> - RpcRetry: 0 (0) E - SerializeBatchTime: 7.999ms E
> - TotalBytesSent: 95.36 KB (97644) E -
> UncompressedRowBatchSize: 237.83 KB (243540) E HDFS_SCAN_NODE
> (id=0): E Hdfs split stats (<volume id>:<# splits>/<split
> lengths>): -1:8/161.29 KB E ExecOption: Codegen Disabled:
> disabled due to optimization hints, Codegen enabled: 0 out of 8 E
> Hdfs Read Thread Concurrency Bucket: 0:0% 1:0% 2:0% 3:0% 4:0% 5:0% 6:0% E
> File Formats: TEXT/NONE:8 E Node Lifecycle Event
> Timeline: 99.999ms E - Open Started: 3.999ms (3.999ms) E
> - Open Finished: 3.999ms (0.000ns) E - First
> Batch Requested: 3.999ms (0.000ns) E - First Batch Returned:
> 3.999ms (0.000ns) E - Last Batch Returned: 87.999ms
> (83.999ms) E - Closed: 99.999ms (11.999ms) E
> - InitialRangeActualReservation: (Avg: 32.00 KB (32768) ; Min: 32.00 KB
> (32768) ; Max: 32.00 KB (32768) ; Number of samples: 8) E -
> InitialRangeIdealReservation: (Avg: 32.00 KB (32768) ; Min: 32.00 KB (32768)
> ; Max: 32.00 KB (32768) ; Number of samples: 8) E -
> ParquetCompressedBytesReadPerColumn: 0 (Number of samples: 0) E
> - ParquetUncompressedBytesReadPerColumn: 0 (Number of samples: 0) E
> - AverageHdfsReadThreadConcurrency: 0.00 E -
> AverageScannerThreadConcurrency: 0.00 E - BytesRead: 161.29
> KB (165166) E - BytesReadDataNodeCache: 0 E -
> BytesReadLocal: 0 E - BytesReadRemoteUnexpected: 0 E
> - BytesReadShortCircuit: 0 E - CachedFileHandlesHitCount:
> 8 (8) E - CachedFileHandlesMissCount: 0 (0) E -
> CollectionItemsRead: 0 (0) E - DataCacheHitBytes: 141.59 KB
> (144987) E - DataCacheHitCount: 7 (7) E -
> DataCacheMissBytes: 19.71 KB (20179) E - DataCacheMissCount: 1
> (1) E - DataCachePartialHitCount: 0 (0) E -
> DecompressionTime: 0.000ns E - DelimiterParseTime: 0.000ns E
> - MaterializeTupleTime(*): 19.999ms E -
> MaxCompressedTextFileLength: 0 E - NumDisksAccessed: 1 (1) E
> - NumScannerThreadMemUnavailable: 0 (0) E -
> NumScannerThreadReservationsDenied: 0 (0) E -
> NumScannerThreadsStarted: 3 (3) E - PeakMemoryUsage: 1.38 MB
> (1447936) E - PeakScannerThreadConcurrency: 3 (3) E
> - PerReadThreadRawHdfsThroughput: 0.00 /sec E -
> RemoteScanRanges: 3 (3) E - RowBatchBytesEnqueued: 1.95 MB
> (2048000) E - RowBatchQueueGetWaitTime: 0.000ns E
> - RowBatchQueuePeakMemoryUsage: 1.32 MB (1386496) E -
> RowBatchQueuePutWaitTime: 0.000ns E - RowBatchesEnqueued: 16
> (16) E - RowsRead: 2.46K (2460) E -
> RowsReturned: 2.46K (2460) E - RowsReturnedRate: 0 E
> - ScanRangesComplete: 8 (8) E - ScannerIoWaitTime:
> 0.000ns E - ScannerThreadWorklessLoops: 0 (0) E
> - ScannerThreadsInvoluntaryContextSwitches: 32 (32) E -
> ScannerThreadsTotalWallClockTime: 67.999ms E -
> ScannerThreadsSysTime: 0.000ns E - ScannerThreadsUserTime:
> 12.000ms E - ScannerThreadsVoluntaryContextSwitches: 7 (7) E
> - TotalRawHdfsOpenFileTime(*): 0.000ns E -
> TotalRawHdfsReadTime(*): 0.000ns E - TotalReadThroughput: 0.00
> /sec E Buffer pool: E - AllocTime: 0.000ns E
> - CumulativeAllocationBytes: 256.00 KB (262144) E
> - CumulativeAllocations: 8 (8) E - PeakReservation:
> 128.00 KB (131072) E - PeakUnpinnedBytes: 0 E
> - PeakUsedReservation: 64.00 KB (65536) 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 Instance
> 56480a470616cf3c:7cfadfbe00000002 (host=bf5c6b4d70c3:22000):(Total: 87.999ms,
> non-child: 0.000ns, % non-child: 0.00%) E Last report received
> time: 2019-08-28 20:01:06.987 E Hdfs split stats (<volume id>:<#
> splits>/<split lengths>): -1:8/157.38 KB E Fragment Instance
> Lifecycle Event Timeline: 95.999ms E - Prepare Finished:
> 7.999ms (7.999ms) E - Open Finished: 7.999ms (0.000ns) E
> - First Batch Produced: 43.999ms (35.999ms) E - First
> Batch Sent: 43.999ms (0.000ns) E - ExecInternal Finished:
> 95.999ms (51.999ms) E - AverageThreadTokens: 0.00 E
> - BloomFilterBytes: 0 E - ExchangeScanRatio: 0.59 E
> - PeakMemoryUsage: 1.62 MB (1697336) E - PeakReservation:
> 160.00 KB (163840) E - PeakUsedReservation: 0 E -
> PerHostPeakMemUsage: 1.62 MB (1697336) E - RowsProduced: 2.40K
> (2400) E - TotalNetworkReceiveTime: 0.000ns E -
> TotalNetworkSendTime: 47.999ms E - TotalStorageWaitTime:
> 15.999ms E - TotalThreadsInvoluntaryContextSwitches: 27 (27) E
> - TotalThreadsTotalWallClockTime: 211.999ms E -
> TotalThreadsSysTime: 0.000ns E - TotalThreadsUserTime:
> 16.000ms E - TotalThreadsVoluntaryContextSwitches: 24 (24) 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: 87.999ms E
> - ExecTreeExecTime: 35.999ms E - OpenTime: 0.000ns E
> - ExecTreeOpenTime: 0.000ns E - PrepareTime:
> 0.000ns E - ExecTreePrepareTime: 0.000ns E
> KrpcDataStreamSender (dst_id=1):(Total: 51.999ms, non-child: 3.999ms, %
> non-child: 7.69%) E ExecOption: Codegen Disabled: disabled due
> to optimization hints E - NetworkThroughput: (Avg: 2.35 MB/sec
> ; Min: 1.05 MB/sec ; Max: 3.73 MB/sec ; Number of samples: 8) E
> - EosSent: 1 (1) E - PeakMemoryUsage: 1.55 KB (1592) E
> - RowsSent: 2.40K (2400) E - RpcFailure: 0 (0) E
> - RpcRetry: 0 (0) E - SerializeBatchTime: 3.999ms E
> - TotalBytesSent: 93.22 KB (95461) E -
> UncompressedRowBatchSize: 232.03 KB (237600) E HDFS_SCAN_NODE
> (id=0):(Total: 35.999ms, non-child: 35.999ms, % non-child: 100.00%) E
> Hdfs split stats (<volume id>:<# splits>/<split lengths>): -1:8/157.38
> KB E ExecOption: Codegen Disabled: disabled due to optimization
> hints, Codegen enabled: 0 out of 8 E Hdfs Read Thread
> Concurrency Bucket: 0:0% 1:0% 2:0% 3:0% 4:0% 5:0% 6:0% E File
> Formats: TEXT/NONE:8 E Node Lifecycle Event Timeline: 95.999ms
> E - Open Started: 7.999ms (7.999ms) E -
> Open Finished: 7.999ms (0.000ns) E - First Batch Requested:
> 7.999ms (0.000ns) E - First Batch Returned: 43.999ms
> (35.999ms) E - Last Batch Returned: 91.999ms (47.999ms) E
> - Closed: 95.999ms (3.999ms) E -
> InitialRangeActualReservation: (Avg: 32.00 KB (32768) ; Min: 32.00 KB (32768)
> ; Max: 32.00 KB (32768) ; Number of samples: 8) E -
> InitialRangeIdealReservation: (Avg: 32.00 KB (32768) ; Min: 32.00 KB (32768)
> ; Max: 32.00 KB (32768) ; Number of samples: 8) E -
> ParquetCompressedBytesReadPerColumn: 0 (Number of samples: 0) E
> - ParquetUncompressedBytesReadPerColumn: 0 (Number of samples: 0) E
> - AverageHdfsReadThreadConcurrency: 0.00 E -
> AverageScannerThreadConcurrency: 0.00 E - BytesRead: 157.38
> KB (161160) E - BytesReadDataNodeCache: 0 E -
> BytesReadLocal: 0 E - BytesReadRemoteUnexpected: 0 E
> - BytesReadShortCircuit: 0 E - CachedFileHandlesHitCount:
> 8 (8) E - CachedFileHandlesMissCount: 0 (0) E -
> CollectionItemsRead: 0 (0) E - DataCacheHitBytes: 97.61 KB
> (99949) E - DataCacheHitCount: 5 (5) E -
> DataCacheMissBytes: 59.78 KB (61211) E - DataCacheMissCount: 3
> (3) E - DataCachePartialHitCount: 0 (0) E -
> DecompressionTime: 0.000ns E - DelimiterParseTime: 15.999ms E
> - MaterializeTupleTime(*): 39.999ms E -
> MaxCompressedTextFileLength: 0 E - NumDisksAccessed: 1 (1) E
> - NumScannerThreadMemUnavailable: 0 (0) E -
> NumScannerThreadReservationsDenied: 0 (0) E -
> NumScannerThreadsStarted: 4 (4) E - PeakMemoryUsage: 1.37 MB
> (1435648) E - PeakScannerThreadConcurrency: 4 (4) E
> - PerReadThreadRawHdfsThroughput: 12.81 MB/sec E -
> RemoteScanRanges: 9 (9) E - RowBatchBytesEnqueued: 1.95 MB
> (2048000) E - RowBatchQueueGetWaitTime: 11.999ms E
> - RowBatchQueuePeakMemoryUsage: 1.05 MB (1101824) E -
> RowBatchQueuePutWaitTime: 0.000ns E - RowBatchesEnqueued: 16
> (16) E - RowsRead: 2.40K (2400) E -
> RowsReturned: 2.40K (2400) E - RowsReturnedRate: 66.67 K/sec E
> - ScanRangesComplete: 8 (8) E -
> ScannerIoWaitTime: 15.999ms E - ScannerThreadWorklessLoops: 0
> (0) E - ScannerThreadsInvoluntaryContextSwitches: 26 (26) E
> - ScannerThreadsTotalWallClockTime: 123.999ms E
> - ScannerThreadsSysTime: 0.000ns E - ScannerThreadsUserTime:
> 12.000ms E - ScannerThreadsVoluntaryContextSwitches: 9 (9) E
> - TotalRawHdfsOpenFileTime(*): 0.000ns E -
> TotalRawHdfsReadTime(*): 11.999ms E - TotalReadThroughput:
> 0.00 /sec E Buffer pool: E - AllocTime:
> 0.000ns E - CumulativeAllocationBytes: 256.00 KB (262144) E
> - CumulativeAllocations: 8 (8) E -
> PeakReservation: 160.00 KB (163840) 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 E assert 10 ==
> 0Stacktracequery_test/test_observability.py:340: in
> test_query_profile_contains_query_compilation_metadata_load_events
> self.__verify_profile_event_sequence(load_event_regexes, runtime_profile)
> query_test/test_observability.py:432: in __verify_profile_event_sequence
> assert event_regex_index == 0, \
> E AssertionError: CatalogFetch.PartitionLists.Misses not in -
> CatalogFetch.PartitionLists.Hits: 1
> E Query (id=56480a470616cf3c:7cfadfbe00000000):
> 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: 854d1d6ab3cb65b7:9ba11e621c088385
> E Session Type: BEESWAX
> E Start Time: 2019-08-28 20:01:05.725329000
> E End Time: 2019-08-28 20:01:07.305869000
> E Query Type: QUERY
> E Query State: FINISHED
> E Query Status: OK
> E Impala Version: impalad version 3.4.0-SNAPSHOT DEBUG (build
> 207b1443ff1b116d2d031dc5325ce971af80c4a6)
> E User: ubuntu
> E Connected User: ubuntu
> E Delegated User:
> E Network Address: 172.18.0.1:44044
> E Default Db: default
> E Sql Statement: select * from functional.alltypes
> E Coordinator: f6d78aab23cf:22000
> E Query Options (set by configuration):
> DEBUG_ACTION=CRS_BEFORE_ADMISSION:SLEEP@1000,TIMEZONE=Zulu,CLIENT_IDENTIFIER=query_test/test_observability.py::TestObservability::()::test_exec_summary_in_runtime_profile
> E Query Options (set by configuration and planner):
> DEBUG_ACTION=CRS_BEFORE_ADMISSION:SLEEP@1000,MT_DOP=0,TIMEZONE=Zulu,CLIENT_IDENTIFIER=query_test/test_observability.py::TestObservability::()::test_exec_summary_in_runtime_profile
> E Plan:
> E ----------------
> E Max Per-Host Resource Reservation: Memory=32.00KB Threads=3
> E Per-Host Resource Estimates: Memory=160MB
> E Codegen disabled by planner
> E Analyzed query: SELECT * FROM functional.alltypes
> E
> E F01:PLAN FRAGMENT [UNPARTITIONED] hosts=1 instances=1
> E | Per-Host Resources: mem-estimate=490.49KB mem-reservation=0B
> thread-reservation=1
> E PLAN-ROOT SINK
> E | mem-estimate=0B mem-reservation=0B thread-reservation=0
> E |
> E 01:EXCHANGE [UNPARTITIONED]
> E | mem-estimate=490.49KB mem-reservation=0B thread-reservation=0
> E | tuple-ids=0 row-size=89B cardinality=7.30K
> E | in pipelines: 00(GETNEXT)
> E |
> E F00:PLAN FRAGMENT [RANDOM] hosts=3 instances=3
> E Per-Host Resources: mem-estimate=160.00MB mem-reservation=32.00KB
> thread-reservation=2
> E 00:SCAN HDFS [functional.alltypes, RANDOM]
> E HDFS partitions=24/24 files=24 size=478.45KB
> E stored statistics:
> E table: rows=7.30K size=478.45KB
> E partitions: 24/24 rows=7.30K
> E columns: all
> E extrapolated-rows=disabled max-scan-range-rows=310
> E mem-estimate=160.00MB mem-reservation=32.00KB thread-reservation=1
> E tuple-ids=0 row-size=89B cardinality=7.30K
> E in pipelines: 00(GETNEXT)
> E ----------------
> E Estimated Per-Host Mem: 168274422
> E Request Pool: default-pool
> E Per Host Min Memory Reservation: 6db176633e3a:22000(32.00 KB)
> bf5c6b4d70c3:22000(32.00 KB) f6d78aab23cf:22000(32.00 KB)
> E Per Host Number of Fragment Instances: 6db176633e3a:22000(1)
> bf5c6b4d70c3:22000(1) f6d78aab23cf:22000(2)
> E Admission result: Admitted immediately
> E Cluster Memory Admitted: 481.44 MB
> 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 323.998ms 323.998ms
> 0 0
> E 01:EXCHANGE 1 3.999ms 3.999ms 7.30K 7.30K
> 776.00 KB 490.49 KB UNPARTITIONED
> E F00:EXCHANGE SENDER 3 7.999ms 19.999ms
> 1.55 KB 0
> E 00:SCAN HDFS 3 66.666ms 163.999ms 7.30K 7.30K
> 1.38 MB 160.00 MB functional.alltypes
> E Errors:
> E Query Compilation: 139.437ms
> E - Metadata of all 1 tables cached: 116.233ms (116.233ms)
> E - Analysis finished: 116.458ms (225.333us)
> E - Authorization finished (noop): 116.480ms (21.466us)
> E - Value transfer graph computed: 116.628ms (148.642us)
> E - Single node plan created: 133.186ms (16.557ms)
> E - Runtime filters computed: 133.229ms (43.430us)
> E - Distributed plan created: 133.256ms (27.095us)
> E - Planning finished: 139.437ms (6.180ms)
> E Query Timeline: 1s587ms
> E - Query submitted: 0.000ns (0.000ns)
> E - Planning finished: 143.999ms (143.999ms)
> E - Submit for admission: 1s147ms (1s003ms)
> E - Completed admission: 1s147ms (0.000ns)
> E - Ready to start on 3 backends: 1s147ms (0.000ns)
> E - All 3 execution backends (4 fragment instances) started:
> 1s167ms (19.999ms)
> E - Rows available: 1s195ms (27.999ms)
> E - First row fetched: 1s211ms (15.999ms)
> E - Last row fetched: 1s575ms (363.998ms)
> E - Released admission control resources: 1s583ms (7.999ms)
> E - AdmissionControlTimeSinceLastUpdate: 77.000ms
> E - ComputeScanRangeAssignmentTimer: 0.000ns
> E Frontend:
> E - CatalogFetch.ColumnStats.Misses: 13
> E - CatalogFetch.ColumnStats.Requests: 13
> E - CatalogFetch.ColumnStats.Time: 9ms
> E - CatalogFetch.Config.Hits: 1
> E - CatalogFetch.Config.Requests: 1
> E - CatalogFetch.Config.Time: 0
> E - CatalogFetch.DatabaseList.Hits: 1
> E - CatalogFetch.DatabaseList.Requests: 1
> E - CatalogFetch.DatabaseList.Time: 0
> E - CatalogFetch.PartitionLists.Hits: 1
> E - CatalogFetch.PartitionLists.Requests: 1
> E - CatalogFetch.PartitionLists.Time: 0
> E - CatalogFetch.Partitions.Hits: 48
> E - CatalogFetch.Partitions.Misses: 20
> E - CatalogFetch.Partitions.Requests: 68
> E - CatalogFetch.Partitions.Time: 8ms
> E - CatalogFetch.RPCs.Bytes: 27.93 KB (28604)
> E - CatalogFetch.RPCs.Requests: 3
> E - CatalogFetch.RPCs.Time: 116ms
> E - CatalogFetch.TableNames.Hits: 2
> E - CatalogFetch.TableNames.Requests: 2
> E - CatalogFetch.TableNames.Time: 0
> E - CatalogFetch.Tables.Misses: 1
> E - CatalogFetch.Tables.Requests: 1
> E - CatalogFetch.Tables.Time: 105ms
> E ImpalaServer:
> E - ClientFetchWaitTimer: 51.999ms
> E - RowMaterializationTimer: 335.998ms
> E Execution Profile 56480a470616cf3c:7cfadfbe00000000:(Total:
> 383.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: 9ms / 17ms, 25th
> %-ile: 9ms, 50th %-ile: 10ms, 75th %-ile: 10ms, 90th %-ile: 17ms, 95th %-ile:
> 17ms, 99.9th %-ile: 17ms
> E Slowest backend to start up: bf5c6b4d70c3:22000
> E Per Node Peak Memory Usage: 6db176633e3a:22000(1.63 MB)
> bf5c6b4d70c3:22000(1.62 MB) f6d78aab23cf:22000(1.06 MB)
> E Per Node Bytes Read: 6db176633e3a:22000(161.29 KB)
> bf5c6b4d70c3:22000(157.38 KB) f6d78aab23cf:22000(159.77 KB)
> E Per Node User Time: 6db176633e3a:22000(16.000ms)
> bf5c6b4d70c3:22000(16.000ms) f6d78aab23cf:22000(160.000ms)
> E Per Node System Time: 6db176633e3a:22000(0.000ns)
> bf5c6b4d70c3:22000(0.000ns) f6d78aab23cf:22000(0.000ns)
> E - ExchangeScanRatio: 0.59
> E - FiltersReceived: 0 (0)
> E - FinalizationTimer: 0.000ns
> E - InnerNodeSelectivityRatio: 0.00
> E - NumBackends: 3 (3)
> E - NumFragmentInstances: 4 (4)
> E - NumFragments: 2 (2)
> E - TotalBytesRead: 478.45 KB (489934)
> E - TotalBytesSent: 283.47 KB (290271)
> E - TotalCpuTime: 192.000ms
> E - TotalInnerBytesSent: 0
> E - TotalScanBytesSent: 283.47 KB (290271)
> E Per Node Profiles:
> E 6db176633e3a:22000:
> 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 bf5c6b4d70c3:22000:
> 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 f6d78aab23cf:22000:
> 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: 403.998ms, non-child: 3.999ms, %
> non-child: 0.99%)
> E split sizes: min: 0, max: 0, avg: 0, stddev: 0
> E completion times: min:415.998ms max:415.998ms mean: 415.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: 784.00 KB (802816)
> E - PeakReservation: 0
> E - PeakUsedReservation: 0
> E - PerHostPeakMemUsage: 1.06 MB (1113656)
> E - RowsProduced: 7.30K (7300)
> E - TotalNetworkReceiveTime: 23.999ms
> E - TotalNetworkSendTime: 0.000ns
> E - TotalStorageWaitTime: 0.000ns
> E - TotalThreadsInvoluntaryContextSwitches: 78 (78)
> E - TotalThreadsTotalWallClockTime: 399.998ms
> E - TotalThreadsSysTime: 0.000ns
> E - TotalThreadsUserTime: 140.000ms
> 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: 399.998ms
> E - ExecTreeExecTime: 27.999ms
> E - OpenTime: 0.000ns
> E - ExecTreeOpenTime: 0.000ns
> E - PrepareTime: 3.999ms
> E - ExecTreePrepareTime: 0.000ns
> E PLAN_ROOT_SINK:(Total: 371.998ms, non-child: 371.998ms, %
> non-child: 100.00%)
> E - PeakMemoryUsage: 0
> E EXCHANGE_NODE (id=1):(Total: 27.999ms, non-child: 27.999ms, %
> non-child: 100.00%)
> E - ConvertRowBatchTime: 3.999ms
> E - PeakMemoryUsage: 776.00 KB (794624)
> E - RowsReturned: 7.30K (7300)
> E - RowsReturnedRate: 260.71 K/sec
> E Buffer pool:
> E - AllocTime: 0.000ns
> E - CumulativeAllocationBytes: 960.00 KB (983040)
> E - CumulativeAllocations: 48 (48)
> E - PeakReservation: 776.00 KB (794624)
> E - PeakUnpinnedBytes: 0
> E - PeakUsedReservation: 776.00 KB (794624)
> 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: 0.000ns
> E - TotalBytesDequeued: 705.76 KB (722700)
> E - TotalGetBatchTime: 23.999ms
> E - DataWaitTime: 23.999ms
> E Enqueue:
> E - DeserializeRowBatchTime: 3.999ms
> E - TotalBatchesEnqueued: 24 (24)
> E - TotalBatchesReceived: 24 (24)
> E - TotalBytesReceived: 283.47 KB (290271)
> E - TotalEarlySenders: 1 (1)
> E - TotalEosReceived: 3 (3)
> E - TotalHasDeferredRPCsTime: 53.864us
> E - TotalRPCsDeferred: 1 (1)
> E Coordinator Fragment F01:
> E Instance 56480a470616cf3c:7cfadfbe00000000
> (host=f6d78aab23cf:22000):(Total: 403.998ms, non-child: 3.999ms, % non-child:
> 0.99%)
> E Last report received time: 2019-08-28 20:01:07.300
> E Fragment Instance Lifecycle Event Timeline: 415.998ms
> E - Prepare Finished: 15.999ms (15.999ms)
> E - Open Finished: 15.999ms (0.000ns)
> E - First Batch Produced: 39.999ms (23.999ms)
> E - First Batch Sent: 87.999ms (47.999ms)
> E - ExecInternal Finished: 415.998ms (327.998ms)
> E - MemoryUsage (500.000ms): 784.00 KB
> E - AverageThreadTokens: 0.00
> E - BloomFilterBytes: 0
> E - ExchangeScanRatio: 0.00
> E - PeakMemoryUsage: 784.00 KB (802816)
> E - PeakReservation: 0
> E - PeakUsedReservation: 0
> E - PerHostPeakMemUsage: 1.06 MB (1113656)
> E - RowsProduced: 7.30K (7300)
> E - TotalNetworkReceiveTime: 23.999ms
> E - TotalNetworkSendTime: 0.000ns
> E - TotalStorageWaitTime: 0.000ns
> E - TotalThreadsInvoluntaryContextSwitches: 78 (78)
> E - TotalThreadsTotalWallClockTime: 399.998ms
> E - TotalThreadsSysTime: 0.000ns
> E - TotalThreadsUserTime: 140.000ms
> 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: 399.998ms
> E - ExecTreeExecTime: 27.999ms
> E - OpenTime: 0.000ns
> E - ExecTreeOpenTime: 0.000ns
> E - PrepareTime: 3.999ms
> E - ExecTreePrepareTime: 0.000ns
> E PLAN_ROOT_SINK:(Total: 371.998ms, non-child: 323.998ms, %
> non-child: 87.10%)
> E - PeakMemoryUsage: 0
> E EXCHANGE_NODE (id=1):(Total: 27.999ms, non-child: 3.999ms, %
> non-child: 14.29%)
> E Node Lifecycle Event Timeline: 415.998ms
> E - Open Started: 15.999ms (15.999ms)
> E - Open Finished: 15.999ms (0.000ns)
> E - First Batch Requested: 15.999ms (0.000ns)
> E - First Batch Returned: 39.999ms (23.999ms)
> E - Last Batch Returned: 407.998ms (367.998ms)
> E - Closed: 415.998ms (7.999ms)
> E - ConvertRowBatchTime: 3.999ms
> E - PeakMemoryUsage: 776.00 KB (794624)
> E - RowsReturned: 7.30K (7300)
> E - RowsReturnedRate: 260.71 K/sec
> E Buffer pool:
> E - AllocTime: 0.000ns
> E - CumulativeAllocationBytes: 960.00 KB (983040)
> E - CumulativeAllocations: 48 (48)
> E - PeakReservation: 776.00 KB (794624)
> E - PeakUnpinnedBytes: 0
> E - PeakUsedReservation: 776.00 KB (794624)
> 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): 502.73 KB
> E - FirstBatchWaitTime: 0.000ns
> E - TotalBytesDequeued: 705.76 KB (722700)
> E - TotalGetBatchTime: 23.999ms
> E - DataWaitTime: 23.999ms
> E Enqueue:
> E - BytesReceived (500.000ms): 283.47 KB
> E - DeferredQueueSize (500.000ms): 0
> E - DispatchTime: (Avg: 178.622us ; Min: 53.536us ; Max:
> 1.203ms ; Number of samples: 23)
> E - DeserializeRowBatchTime: 3.999ms
> E - TotalBatchesEnqueued: 24 (24)
> E - TotalBatchesReceived: 24 (24)
> E - TotalBytesReceived: 283.47 KB (290271)
> E - TotalEarlySenders: 1 (1)
> E - TotalEosReceived: 3 (3)
> E - TotalHasDeferredRPCsTime: 53.864us
> E - TotalRPCsDeferred: 1 (1)
> E Averaged Fragment F00:(Total: 118.666ms, non-child: 0.000ns, %
> non-child: 0.00%)
> E split sizes: min: 157.38 KB, max: 161.29 KB, avg: 159.48 KB,
> stddev: 1.61 KB
> E completion times: min:95.999ms max:415.998ms mean: 205.332ms
> stddev:148.998ms
> E execution rates: min:384.07 KB/sec max:1.60 MB/sec mean:1.16
> MB/sec stddev:572.06 KB/sec
> E num instances: 3
> E - AverageThreadTokens: 0.00
> E - BloomFilterBytes: 0
> E - ExchangeScanRatio: 0.59
> E - PeakMemoryUsage: 1.18 MB (1239266)
> E - PeakReservation: 117.33 KB (120149)
> E - PeakUsedReservation: 0
> E - PerHostPeakMemUsage: 1.44 MB (1506872)
> E - RowsProduced: 2.43K (2433)
> E - TotalNetworkReceiveTime: 0.000ns
> E - TotalNetworkSendTime: 43.999ms
> E - TotalStorageWaitTime: 5.333ms
> E - TotalThreadsInvoluntaryContextSwitches: 41 (41)
> E - TotalThreadsTotalWallClockTime: 235.998ms
> E - TotalThreadsSysTime: 0.000ns
> E - TotalThreadsUserTime: 17.333ms
> E - TotalThreadsVoluntaryContextSwitches: 25 (25)
> 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: 117.332ms
> E - ExecTreeExecTime: 66.666ms
> E - OpenTime: 0.000ns
> E - ExecTreeOpenTime: 0.000ns
> E - PrepareTime: 1.333ms
> E - ExecTreePrepareTime: 0.000ns
> E KrpcDataStreamSender (dst_id=1):(Total: 51.999ms, non-child:
> 51.999ms, % non-child: 100.00%)
> E - EosSent: 1 (1)
> E - PeakMemoryUsage: 1.55 KB (1592)
> E - RowsSent: 2.43K (2433)
> E - RpcFailure: 0 (0)
> E - RpcRetry: 0 (0)
> E - SerializeBatchTime: 3.999ms
> E - TotalBytesSent: 94.49 KB (96757)
> E - UncompressedRowBatchSize: 235.25 KB (240900)
> E HDFS_SCAN_NODE (id=0):(Total: 66.666ms, non-child: 66.666ms, %
> non-child: 100.00%)
> E - AverageHdfsReadThreadConcurrency: 0.00
> E - AverageScannerThreadConcurrency: 0.00
> E - BytesRead: 159.48 KB (163311)
> E - BytesReadDataNodeCache: 0
> E - BytesReadLocal: 0
> E - BytesReadRemoteUnexpected: 0
> E - BytesReadShortCircuit: 0
> E - CachedFileHandlesHitCount: 8 (8)
> E - CachedFileHandlesMissCount: 0 (0)
> E - CollectionItemsRead: 0 (0)
> E - DataCacheHitBytes: 132.99 KB (136181)
> E - DataCacheHitCount: 6 (6)
> E - DataCacheMissBytes: 26.49 KB (27130)
> E - DataCacheMissCount: 1 (1)
> E - DataCachePartialHitCount: 0 (0)
> E - DecompressionTime: 0.000ns
> E - DelimiterParseTime: 6.666ms
> E - MaterializeTupleTime(*): 67.999ms
> E - MaxCompressedTextFileLength: 0
> E - NumDisksAccessed: 1 (1)
> E - NumScannerThreadMemUnavailable: 0 (0)
> E - NumScannerThreadReservationsDenied: 0 (0)
> E - NumScannerThreadsStarted: 2 (2)
> E - PeakMemoryUsage: 1.01 MB (1061546)
> E - PeakScannerThreadConcurrency: 2 (2)
> E - PerReadThreadRawHdfsThroughput: 4.27 MB/sec
> E - RemoteScanRanges: 4 (4)
> E - RowBatchBytesEnqueued: 1.95 MB (2048000)
> E - RowBatchQueueGetWaitTime: 58.666ms
> E - RowBatchQueuePeakMemoryUsage: 894.67 KB (916138)
> E - RowBatchQueuePutWaitTime: 0.000ns
> E - RowBatchesEnqueued: 16 (16)
> E - RowsRead: 2.43K (2433)
> E - RowsReturned: 2.43K (2433)
> E - RowsReturnedRate: 27.18 K/sec
> E - ScanRangesComplete: 8 (8)
> E - ScannerIoWaitTime: 5.333ms
> E - ScannerThreadWorklessLoops: 0 (0)
> E - ScannerThreadsInvoluntaryContextSwitches: 39 (39)
> E - ScannerThreadsTotalWallClockTime: 118.666ms
> E - ScannerThreadsSysTime: 0.000ns
> E - ScannerThreadsUserTime: 13.333ms
> E - ScannerThreadsVoluntaryContextSwitches: 7 (7)
> E - TotalRawHdfsOpenFileTime(*): 0.000ns
> E - TotalRawHdfsReadTime(*): 3.999ms
> E - TotalReadThroughput: 0.00 /sec
> E Buffer pool:
> E - AllocTime: 0.000ns
> E - CumulativeAllocationBytes: 256.00 KB (262144)
> E - CumulativeAllocations: 8 (8)
> E - PeakReservation: 117.33 KB (120149)
> E - PeakUnpinnedBytes: 0
> E - PeakUsedReservation: 74.67 KB (76458)
> 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 Fragment F00:
> E Instance 56480a470616cf3c:7cfadfbe00000001
> (host=f6d78aab23cf:22000):(Total: 167.999ms, non-child: 0.000ns, % non-child:
> 0.00%)
> E Last report received time: 2019-08-28 20:01:07.300
> E Hdfs split stats (<volume id>:<# splits>/<split lengths>):
> -1:8/159.77 KB
> E Fragment Instance Lifecycle Event Timeline: 219.999ms
> E - Prepare Finished: 31.999ms (31.999ms)
> E - Open Finished: 31.999ms (0.000ns)
> E - First Batch Produced: 67.999ms (35.999ms)
> E - First Batch Sent: 67.999ms (0.000ns)
> E - ExecInternal Finished: 219.999ms (151.999ms)
> E - AverageThreadTokens: 0.00
> E - BloomFilterBytes: 0
> E - ExchangeScanRatio: 0.59
> E - PeakMemoryUsage: 303.55 KB (310840)
> E - PeakReservation: 64.00 KB (65536)
> E - PeakUsedReservation: 0
> E - PerHostPeakMemUsage: 1.06 MB (1113656)
> E - RowsProduced: 2.44K (2440)
> E - TotalNetworkReceiveTime: 0.000ns
> E - TotalNetworkSendTime: 3.999ms
> E - TotalStorageWaitTime: 0.000ns
> E - TotalThreadsInvoluntaryContextSwitches: 62 (62)
> E - TotalThreadsTotalWallClockTime: 331.998ms
> E - TotalThreadsSysTime: 0.000ns
> E - TotalThreadsUserTime: 20.000ms
> E - TotalThreadsVoluntaryContextSwitches: 27 (27)
> 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: 167.999ms
> E - ExecTreeExecTime: 163.999ms
> E - OpenTime: 0.000ns
> 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: Codegen Disabled: disabled due to optimization
> hints
> E - NetworkThroughput: (Avg: 32.50 MB/sec ; Min: 1.83 MB/sec ;
> Max: 47.13 MB/sec ; Number of samples: 8)
> E - EosSent: 1 (1)
> E - PeakMemoryUsage: 1.55 KB (1592)
> E - RowsSent: 2.44K (2440)
> E - RpcFailure: 0 (0)
> E - RpcRetry: 0 (0)
> E - SerializeBatchTime: 0.000ns
> E - TotalBytesSent: 94.89 KB (97166)
> E - UncompressedRowBatchSize: 235.90 KB (241560)
> E HDFS_SCAN_NODE (id=0):(Total: 163.999ms, non-child: 163.999ms,
> % non-child: 100.00%)
> E Hdfs split stats (<volume id>:<# splits>/<split lengths>):
> -1:8/159.77 KB
> E ExecOption: Codegen Disabled: disabled due to optimization
> hints, Codegen enabled: 0 out of 8
> E Hdfs Read Thread Concurrency Bucket: 0:0% 1:0% 2:0% 3:0% 4:0%
> 5:0% 6:0%
> E File Formats: TEXT/NONE:8
> E Node Lifecycle Event Timeline: 219.999ms
> E - Open Started: 31.999ms (31.999ms)
> E - Open Finished: 31.999ms (0.000ns)
> E - First Batch Requested: 31.999ms (0.000ns)
> E - First Batch Returned: 67.999ms (35.999ms)
> E - Last Batch Returned: 195.999ms (127.999ms)
> E - Closed: 219.999ms (23.999ms)
> E - InitialRangeActualReservation: (Avg: 32.00 KB (32768) ;
> Min: 32.00 KB (32768) ; Max: 32.00 KB (32768) ; Number of samples: 8)
> E - InitialRangeIdealReservation: (Avg: 32.00 KB (32768) ;
> Min: 32.00 KB (32768) ; Max: 32.00 KB (32768) ; Number of samples: 8)
> E - ParquetCompressedBytesReadPerColumn: 0 (Number of samples:
> 0)
> E - ParquetUncompressedBytesReadPerColumn: 0 (Number of
> samples: 0)
> E - AverageHdfsReadThreadConcurrency: 0.00
> E - AverageScannerThreadConcurrency: 0.00
> E - BytesRead: 159.77 KB (163608)
> E - BytesReadDataNodeCache: 0
> E - BytesReadLocal: 0
> E - BytesReadRemoteUnexpected: 0
> E - BytesReadShortCircuit: 0
> E - CachedFileHandlesHitCount: 8 (8)
> E - CachedFileHandlesMissCount: 0 (0)
> E - CollectionItemsRead: 0 (0)
> E - DataCacheHitBytes: 159.77 KB (163608)
> E - DataCacheHitCount: 8 (8)
> E - DataCacheMissBytes: 0
> E - DataCacheMissCount: 0 (0)
> E - DataCachePartialHitCount: 0 (0)
> E - DecompressionTime: 0.000ns
> E - DelimiterParseTime: 3.999ms
> E - MaterializeTupleTime(*): 143.999ms
> E - MaxCompressedTextFileLength: 0
> E - NumDisksAccessed: 1 (1)
> E - NumScannerThreadMemUnavailable: 0 (0)
> E - NumScannerThreadReservationsDenied: 0 (0)
> E - NumScannerThreadsStarted: 1 (1)
> E - PeakMemoryUsage: 294.00 KB (301056)
> E - PeakScannerThreadConcurrency: 1 (1)
> E - PerReadThreadRawHdfsThroughput: 0.00 /sec
> E - RemoteScanRanges: 0 (0)
> E - RowBatchBytesEnqueued: 1.95 MB (2048000)
> E - RowBatchQueueGetWaitTime: 163.999ms
> E - RowBatchQueuePeakMemoryUsage: 254.00 KB (260096)
> E - RowBatchQueuePutWaitTime: 0.000ns
> E - RowBatchesEnqueued: 16 (16)
> E - RowsRead: 2.44K (2440)
> E - RowsReturned: 2.44K (2440)
> E - RowsReturnedRate: 14.88 K/sec
> E - ScanRangesComplete: 8 (8)
> E - ScannerIoWaitTime: 0.000ns
> E - ScannerThreadWorklessLoops: 0 (0)
> E - ScannerThreadsInvoluntaryContextSwitches: 60 (60)
> E - ScannerThreadsTotalWallClockTime: 163.999ms
> E - ScannerThreadsSysTime: 0.000ns
> E - ScannerThreadsUserTime: 16.000ms
> E - ScannerThreadsVoluntaryContextSwitches: 5 (5)
> E - TotalRawHdfsOpenFileTime(*): 0.000ns
> E - TotalRawHdfsReadTime(*): 0.000ns
> E - TotalReadThroughput: 0.00 /sec
> E Buffer pool:
> E - AllocTime: 0.000ns
> E - CumulativeAllocationBytes: 256.00 KB (262144)
> E - CumulativeAllocations: 8 (8)
> E - PeakReservation: 64.00 KB (65536)
> E - PeakUnpinnedBytes: 0
> E - PeakUsedReservation: 32.00 KB (32768)
> 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 Instance 56480a470616cf3c:7cfadfbe00000003
> (host=6db176633e3a:22000):(Total: 99.999ms, non-child: 0.000ns, % non-child:
> 0.00%)
> E Last report received time: 2019-08-28 20:01:06.986
> E Hdfs split stats (<volume id>:<# splits>/<split lengths>):
> -1:8/161.29 KB
> E Fragment Instance Lifecycle Event Timeline: 99.999ms
> E - Prepare Finished: 3.999ms (3.999ms)
> E - Open Finished: 3.999ms (0.000ns)
> E - First Batch Produced: 3.999ms (0.000ns)
> E - First Batch Sent: 11.999ms (7.999ms)
> E - ExecInternal Finished: 99.999ms (87.999ms)
> E - AverageThreadTokens: 0.00
> E - BloomFilterBytes: 0
> E - ExchangeScanRatio: 0.59
> E - PeakMemoryUsage: 1.63 MB (1709624)
> E - PeakReservation: 128.00 KB (131072)
> E - PeakUsedReservation: 0
> E - PerHostPeakMemUsage: 1.63 MB (1709624)
> E - RowsProduced: 2.46K (2460)
> E - TotalNetworkReceiveTime: 0.000ns
> E - TotalNetworkSendTime: 79.999ms
> E - TotalStorageWaitTime: 0.000ns
> E - TotalThreadsInvoluntaryContextSwitches: 36 (36)
> E - TotalThreadsTotalWallClockTime: 163.999ms
> E - TotalThreadsSysTime: 0.000ns
> E - TotalThreadsUserTime: 16.000ms
> E - TotalThreadsVoluntaryContextSwitches: 25 (25)
> 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: 95.999ms
> E - ExecTreeExecTime: 0.000ns
> E - OpenTime: 0.000ns
> E - ExecTreeOpenTime: 0.000ns
> E - PrepareTime: 3.999ms
> E - ExecTreePrepareTime: 0.000ns
> E KrpcDataStreamSender (dst_id=1):(Total: 99.999ms, non-child:
> 19.999ms, % non-child: 20.00%)
> E ExecOption: Codegen Disabled: disabled due to optimization
> hints
> E - NetworkThroughput: (Avg: 2.08 MB/sec ; Min: 892.97 KB/sec
> ; Max: 5.42 MB/sec ; Number of samples: 8)
> E - EosSent: 1 (1)
> E - PeakMemoryUsage: 1.55 KB (1592)
> E - RowsSent: 2.46K (2460)
> E - RpcFailure: 0 (0)
> E - RpcRetry: 0 (0)
> E - SerializeBatchTime: 7.999ms
> E - TotalBytesSent: 95.36 KB (97644)
> E - UncompressedRowBatchSize: 237.83 KB (243540)
> E HDFS_SCAN_NODE (id=0):
> E Hdfs split stats (<volume id>:<# splits>/<split lengths>):
> -1:8/161.29 KB
> E ExecOption: Codegen Disabled: disabled due to optimization
> hints, Codegen enabled: 0 out of 8
> E Hdfs Read Thread Concurrency Bucket: 0:0% 1:0% 2:0% 3:0% 4:0%
> 5:0% 6:0%
> E File Formats: TEXT/NONE:8
> E Node Lifecycle Event Timeline: 99.999ms
> E - Open Started: 3.999ms (3.999ms)
> E - Open Finished: 3.999ms (0.000ns)
> E - First Batch Requested: 3.999ms (0.000ns)
> E - First Batch Returned: 3.999ms (0.000ns)
> E - Last Batch Returned: 87.999ms (83.999ms)
> E - Closed: 99.999ms (11.999ms)
> E - InitialRangeActualReservation: (Avg: 32.00 KB (32768) ;
> Min: 32.00 KB (32768) ; Max: 32.00 KB (32768) ; Number of samples: 8)
> E - InitialRangeIdealReservation: (Avg: 32.00 KB (32768) ;
> Min: 32.00 KB (32768) ; Max: 32.00 KB (32768) ; Number of samples: 8)
> E - ParquetCompressedBytesReadPerColumn: 0 (Number of samples:
> 0)
> E - ParquetUncompressedBytesReadPerColumn: 0 (Number of
> samples: 0)
> E - AverageHdfsReadThreadConcurrency: 0.00
> E - AverageScannerThreadConcurrency: 0.00
> E - BytesRead: 161.29 KB (165166)
> E - BytesReadDataNodeCache: 0
> E - BytesReadLocal: 0
> E - BytesReadRemoteUnexpected: 0
> E - BytesReadShortCircuit: 0
> E - CachedFileHandlesHitCount: 8 (8)
> E - CachedFileHandlesMissCount: 0 (0)
> E - CollectionItemsRead: 0 (0)
> E - DataCacheHitBytes: 141.59 KB (144987)
> E - DataCacheHitCount: 7 (7)
> E - DataCacheMissBytes: 19.71 KB (20179)
> E - DataCacheMissCount: 1 (1)
> E - DataCachePartialHitCount: 0 (0)
> E - DecompressionTime: 0.000ns
> E - DelimiterParseTime: 0.000ns
> E - MaterializeTupleTime(*): 19.999ms
> E - MaxCompressedTextFileLength: 0
> E - NumDisksAccessed: 1 (1)
> E - NumScannerThreadMemUnavailable: 0 (0)
> E - NumScannerThreadReservationsDenied: 0 (0)
> E - NumScannerThreadsStarted: 3 (3)
> E - PeakMemoryUsage: 1.38 MB (1447936)
> E - PeakScannerThreadConcurrency: 3 (3)
> E - PerReadThreadRawHdfsThroughput: 0.00 /sec
> E - RemoteScanRanges: 3 (3)
> E - RowBatchBytesEnqueued: 1.95 MB (2048000)
> E - RowBatchQueueGetWaitTime: 0.000ns
> E - RowBatchQueuePeakMemoryUsage: 1.32 MB (1386496)
> E - RowBatchQueuePutWaitTime: 0.000ns
> E - RowBatchesEnqueued: 16 (16)
> E - RowsRead: 2.46K (2460)
> E - RowsReturned: 2.46K (2460)
> E - RowsReturnedRate: 0
> E - ScanRangesComplete: 8 (8)
> E - ScannerIoWaitTime: 0.000ns
> E - ScannerThreadWorklessLoops: 0 (0)
> E - ScannerThreadsInvoluntaryContextSwitches: 32 (32)
> E - ScannerThreadsTotalWallClockTime: 67.999ms
> E - ScannerThreadsSysTime: 0.000ns
> E - ScannerThreadsUserTime: 12.000ms
> E - ScannerThreadsVoluntaryContextSwitches: 7 (7)
> E - TotalRawHdfsOpenFileTime(*): 0.000ns
> E - TotalRawHdfsReadTime(*): 0.000ns
> E - TotalReadThroughput: 0.00 /sec
> E Buffer pool:
> E - AllocTime: 0.000ns
> E - CumulativeAllocationBytes: 256.00 KB (262144)
> E - CumulativeAllocations: 8 (8)
> E - PeakReservation: 128.00 KB (131072)
> E - PeakUnpinnedBytes: 0
> E - PeakUsedReservation: 64.00 KB (65536)
> 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 Instance 56480a470616cf3c:7cfadfbe00000002
> (host=bf5c6b4d70c3:22000):(Total: 87.999ms, non-child: 0.000ns, % non-child:
> 0.00%)
> E Last report received time: 2019-08-28 20:01:06.987
> E Hdfs split stats (<volume id>:<# splits>/<split lengths>):
> -1:8/157.38 KB
> E Fragment Instance Lifecycle Event Timeline: 95.999ms
> E - Prepare Finished: 7.999ms (7.999ms)
> E - Open Finished: 7.999ms (0.000ns)
> E - First Batch Produced: 43.999ms (35.999ms)
> E - First Batch Sent: 43.999ms (0.000ns)
> E - ExecInternal Finished: 95.999ms (51.999ms)
> E - AverageThreadTokens: 0.00
> E - BloomFilterBytes: 0
> E - ExchangeScanRatio: 0.59
> E - PeakMemoryUsage: 1.62 MB (1697336)
> E - PeakReservation: 160.00 KB (163840)
> E - PeakUsedReservation: 0
> E - PerHostPeakMemUsage: 1.62 MB (1697336)
> E - RowsProduced: 2.40K (2400)
> E - TotalNetworkReceiveTime: 0.000ns
> E - TotalNetworkSendTime: 47.999ms
> E - TotalStorageWaitTime: 15.999ms
> E - TotalThreadsInvoluntaryContextSwitches: 27 (27)
> E - TotalThreadsTotalWallClockTime: 211.999ms
> E - TotalThreadsSysTime: 0.000ns
> E - TotalThreadsUserTime: 16.000ms
> E - TotalThreadsVoluntaryContextSwitches: 24 (24)
> 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: 87.999ms
> E - ExecTreeExecTime: 35.999ms
> E - OpenTime: 0.000ns
> E - ExecTreeOpenTime: 0.000ns
> E - PrepareTime: 0.000ns
> E - ExecTreePrepareTime: 0.000ns
> E KrpcDataStreamSender (dst_id=1):(Total: 51.999ms, non-child:
> 3.999ms, % non-child: 7.69%)
> E ExecOption: Codegen Disabled: disabled due to optimization
> hints
> E - NetworkThroughput: (Avg: 2.35 MB/sec ; Min: 1.05 MB/sec ;
> Max: 3.73 MB/sec ; Number of samples: 8)
> E - EosSent: 1 (1)
> E - PeakMemoryUsage: 1.55 KB (1592)
> E - RowsSent: 2.40K (2400)
> E - RpcFailure: 0 (0)
> E - RpcRetry: 0 (0)
> E - SerializeBatchTime: 3.999ms
> E - TotalBytesSent: 93.22 KB (95461)
> E - UncompressedRowBatchSize: 232.03 KB (237600)
> E HDFS_SCAN_NODE (id=0):(Total: 35.999ms, non-child: 35.999ms, %
> non-child: 100.00%)
> E Hdfs split stats (<volume id>:<# splits>/<split lengths>):
> -1:8/157.38 KB
> E ExecOption: Codegen Disabled: disabled due to optimization
> hints, Codegen enabled: 0 out of 8
> E Hdfs Read Thread Concurrency Bucket: 0:0% 1:0% 2:0% 3:0% 4:0%
> 5:0% 6:0%
> E File Formats: TEXT/NONE:8
> E Node Lifecycle Event Timeline: 95.999ms
> E - Open Started: 7.999ms (7.999ms)
> E - Open Finished: 7.999ms (0.000ns)
> E - First Batch Requested: 7.999ms (0.000ns)
> E - First Batch Returned: 43.999ms (35.999ms)
> E - Last Batch Returned: 91.999ms (47.999ms)
> E - Closed: 95.999ms (3.999ms)
> E - InitialRangeActualReservation: (Avg: 32.00 KB (32768) ;
> Min: 32.00 KB (32768) ; Max: 32.00 KB (32768) ; Number of samples: 8)
> E - InitialRangeIdealReservation: (Avg: 32.00 KB (32768) ;
> Min: 32.00 KB (32768) ; Max: 32.00 KB (32768) ; Number of samples: 8)
> E - ParquetCompressedBytesReadPerColumn: 0 (Number of samples:
> 0)
> E - ParquetUncompressedBytesReadPerColumn: 0 (Number of
> samples: 0)
> E - AverageHdfsReadThreadConcurrency: 0.00
> E - AverageScannerThreadConcurrency: 0.00
> E - BytesRead: 157.38 KB (161160)
> E - BytesReadDataNodeCache: 0
> E - BytesReadLocal: 0
> E - BytesReadRemoteUnexpected: 0
> E - BytesReadShortCircuit: 0
> E - CachedFileHandlesHitCount: 8 (8)
> E - CachedFileHandlesMissCount: 0 (0)
> E - CollectionItemsRead: 0 (0)
> E - DataCacheHitBytes: 97.61 KB (99949)
> E - DataCacheHitCount: 5 (5)
> E - DataCacheMissBytes: 59.78 KB (61211)
> E - DataCacheMissCount: 3 (3)
> E - DataCachePartialHitCount: 0 (0)
> E - DecompressionTime: 0.000ns
> E - DelimiterParseTime: 15.999ms
> E - MaterializeTupleTime(*): 39.999ms
> E - MaxCompressedTextFileLength: 0
> E - NumDisksAccessed: 1 (1)
> E - NumScannerThreadMemUnavailable: 0 (0)
> E - NumScannerThreadReservationsDenied: 0 (0)
> E - NumScannerThreadsStarted: 4 (4)
> E - PeakMemoryUsage: 1.37 MB (1435648)
> E - PeakScannerThreadConcurrency: 4 (4)
> E - PerReadThreadRawHdfsThroughput: 12.81 MB/sec
> E - RemoteScanRanges: 9 (9)
> E - RowBatchBytesEnqueued: 1.95 MB (2048000)
> E - RowBatchQueueGetWaitTime: 11.999ms
> E - RowBatchQueuePeakMemoryUsage: 1.05 MB (1101824)
> E - RowBatchQueuePutWaitTime: 0.000ns
> E - RowBatchesEnqueued: 16 (16)
> E - RowsRead: 2.40K (2400)
> E - RowsReturned: 2.40K (2400)
> E - RowsReturnedRate: 66.67 K/sec
> E - ScanRangesComplete: 8 (8)
> E - ScannerIoWaitTime: 15.999ms
> E - ScannerThreadWorklessLoops: 0 (0)
> E - ScannerThreadsInvoluntaryContextSwitches: 26 (26)
> E - ScannerThreadsTotalWallClockTime: 123.999ms
> E - ScannerThreadsSysTime: 0.000ns
> E - ScannerThreadsUserTime: 12.000ms
> E - ScannerThreadsVoluntaryContextSwitches: 9 (9)
> E - TotalRawHdfsOpenFileTime(*): 0.000ns
> E - TotalRawHdfsReadTime(*): 11.999ms
> E - TotalReadThroughput: 0.00 /sec
> E Buffer pool:
> E - AllocTime: 0.000ns
> E - CumulativeAllocationBytes: 256.00 KB (262144)
> E - CumulativeAllocations: 8 (8)
> E - PeakReservation: 160.00 KB (163840)
> 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
> E assert 10 == 0{code}
--
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
