[IMPALA-7600] Mem limit exceeded in test_kudu_scan_mem_usage

• Type: Bug
• Status: Resolved
• Priority: Blocker
• Resolution: Fixed
• Affects Version/s: Impala 3.1.0
• Fix Version/s: Impala 3.1.0
• Component/s: Backend
• Labels: broken-build flaky
• Epic Color: ghx-label-1
• Assignee: Tim Armstrong
• Reporter: Thomas Tauber-Marshall
• Created: 20/Sep/18 16:44
• Updated: 26/Sep/18 17:18
• Resolved: 26/Sep/18 17:18

Description

Seen in an exhaustive release build:

00:05:35  TestScanMemLimit.test_kudu_scan_mem_usage[exec_option: {'batch_size': 0, 'num_nodes': 0, 'disable_codegen_rows_threshold': 5000, 'disable_codegen': False, 'abort_on_error': 1, 'debug_action': None, 'exec_single_node_rows_threshold': 0} | table_format: avro/snap/block] 
00:05:35 [gw6] linux2 -- Python 2.7.5 /data/jenkins/workspace/impala-asf-master-exhaustive-release/repos/Impala/bin/../infra/python/env/bin/python
00:05:35 query_test/test_mem_usage_scaling.py:358: in test_kudu_scan_mem_usage
00:05:35     self.run_test_case('QueryTest/kudu-scan-mem-usage', vector)
00:05:35 common/impala_test_suite.py:408: in run_test_case
00:05:35     result = self.__execute_query(target_impalad_client, query, user=user)
00:05:35 common/impala_test_suite.py:623: in __execute_query
00:05:35     return impalad_client.execute(query, user=user)
00:05:35 common/impala_connection.py:160: in execute
00:05:35     return self.__beeswax_client.execute(sql_stmt, user=user)
00:05:35 beeswax/impala_beeswax.py:176: in execute
00:05:35     handle = self.__execute_query(query_string.strip(), user=user)
00:05:35 beeswax/impala_beeswax.py:350: in __execute_query
00:05:35     self.wait_for_finished(handle)
00:05:35 beeswax/impala_beeswax.py:371: in wait_for_finished
00:05:35     raise ImpalaBeeswaxException("Query aborted:" + error_log, None)
00:05:35 E   ImpalaBeeswaxException: ImpalaBeeswaxException:
00:05:35 E    Query aborted:Memory limit exceeded: Error occurred on backend impala-ec2-centos74-m5-4xlarge-ondemand-0e2c.vpc.cloudera.com:22000 by fragment b34270820f59a0c9:a507139e00000001
00:05:35 E   Memory left in process limit: 10.12 GB
00:05:35 E   Memory left in query limit: -16.92 KB
00:05:35 E   Query(b34270820f59a0c9:a507139e00000000): memory limit exceeded. Limit=4.00 MB Reservation=0 ReservationLimit=0 OtherMemory=4.02 MB Total=4.02 MB Peak=4.02 MB
00:05:35 E     Fragment b34270820f59a0c9:a507139e00000000: Reservation=0 OtherMemory=40.10 KB Total=40.10 KB Peak=340.00 KB
00:05:35 E       EXCHANGE_NODE (id=2): Reservation=32.00 KB OtherMemory=0 Total=32.00 KB Peak=32.00 KB
00:05:35 E         KrpcDeferredRpcs: Total=0 Peak=0
00:05:35 E       PLAN_ROOT_SINK: Total=0 Peak=0
00:05:35 E       CodeGen: Total=103.00 B Peak=332.00 KB
00:05:35 E     Fragment b34270820f59a0c9:a507139e00000001: Reservation=0 OtherMemory=3.98 MB Total=3.98 MB Peak=3.98 MB
00:05:35 E       SORT_NODE (id=1): Total=342.00 KB Peak=342.00 KB
00:05:35 E       KUDU_SCAN_NODE (id=0): Total=3.63 MB Peak=3.63 MB
00:05:35 E         Queued Batches: Total=3.30 MB Peak=3.63 MB
00:05:35 E       KrpcDataStreamSender (dst_id=2): Total=1.16 KB Peak=1.16 KB
00:05:35 E       CodeGen: Total=3.66 KB Peak=1.14 MB
00:05:35 E   
00:05:35 E   Memory limit exceeded: Error occurred on backend impala-ec2-centos74-m5-4xlarge-ondemand-0e2c.vpc.cloudera.com:22000 by fragment b34270820f59a0c9:a507139e00000001
00:05:35 E   Memory left in process limit: 10.12 GB
00:05:35 E   Memory left in query limit: -16.92 KB
00:05:35 E   Query(b34270820f59a0c9:a507139e00000000): memory limit exceeded. Limit=4.00 MB Reservation=0 ReservationLimit=0 OtherMemory=4.02 MB Total=4.02 MB Peak=4.02 MB
00:05:35 E     Fragment b34270820f59a0c9:a507139e00000000: Reservation=0 OtherMemory=40.10 KB Total=40.10 KB Peak=340.00 KB
00:05:35 E       EXCHANGE_NODE (id=2): Reservation=32.00 KB OtherMemory=0 Total=32.00 KB Peak=32.00 KB
00:05:35 E         KrpcDeferredRpcs: Total=0 Peak=0
00:05:35 E       PLAN_ROOT_SINK: Total=0 Peak=0
00:05:35 E       CodeGen: Total=103.00 B Peak=332.00 KB
00:05:35 E     Fragment b34270820f59a0c9:a507139e00000001: Reservation=0 OtherMemory=3.98 MB Total=3.98 MB Peak=3.98 MB
00:05:35 E       SORT_NODE (id=1): Total=342.00 KB Peak=342.00 KB
00:05:35 E       KUDU_SCAN_NODE (id=0): Total=3.63 MB Peak=3.63 MB
00:05:35 E         Queued Batches: Total=3.30 MB Peak=3.63 MB
00:05:35 E       KrpcDataStreamSender (dst_id=2): Total=1.16 KB Peak=1.16 KB
00:05:35 E       CodeGen: Total=3.66 KB Peak=1.14 MB (1 of 2 similar)
00:05:35 ----------------------------- Captured stderr call -----------------------------
00:05:35 -- executing against localhost:21000
00:05:35 use functional_avro_snap;
00:05:35 
00:05:35 -- 2018-09-19 22:07:44,471 INFO     MainThread: Started query ca487b9fdcc14d67:5877646700000000
00:05:35 SET batch_size=0;
00:05:35 SET num_nodes=0;
00:05:35 SET disable_codegen_rows_threshold=5000;
00:05:35 SET abort_on_error=1;
00:05:35 SET exec_single_node_rows_threshold=0;
00:05:35 -- executing against localhost:21000
00:05:35 set num_scanner_threads=2;
00:05:35 
00:05:35 -- 2018-09-19 22:07:44,479 INFO     MainThread: Started query a844f6df669e6277:c2511d6400000000
00:05:35 -- executing against localhost:21000
00:05:35 
00:05:35 set mem_limit=4mb;
00:05:35 
00:05:35 -- 2018-09-19 22:07:44,485 INFO     MainThread: Started query 1d43ce905b1ad27e:1ec1a2dc00000000
00:05:35 -- executing against localhost:21000
00:05:35 
00:05:35 select * from tpch_kudu.orders
00:05:35 order by o_orderkey limit 3;
00:05:35 
00:05:35 -- 2018-09-19 22:07:48,569 INFO     MainThread: Started query b34270820f59a0c9:a507139e00000000
00:05:35 -- executing against localhost:21000
00:05:35 SET NUM_SCANNER_THREADS="0";
00:05:35 
00:05:35 -- 2018-09-19 22:07:49,303 INFO     MainThread: Started query 5946281b49f7d917:111effba00000000
00:05:35 -- executing against localhost:21000
00:05:35 SET MEM_LIMIT="0";
00:05:35 
00:05:35 -- 2018-09-19 22:07:49,307 INFO     MainThread: Started query 734c732142b4ba2f:b1a41a9d00000000

Issue Links

• relates to: IMPALA-7465 Hit memory limit in TestScanMemLimit.test_kudu_scan_mem_usage on ASAN build