[
https://issues.apache.org/jira/browse/IMPALA-8906?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Tamas Mate updated IMPALA-8906:
-------------------------------
Fix Version/s: Impala 3.4.0
> 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
> Fix For: Impala 3.4.0
>
> 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: [email protected]
For additional commands, e-mail: [email protected]
