[
https://issues.apache.org/jira/browse/IMPALA-7371?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16664092#comment-16664092
]
bharath v commented on IMPALA-7371:
-----------------------------------
I've dug into the logs a bit and don't see anything obviously wrong. One
interesting point though is that the job seems to be spending quite a bit of
time around this test. (timestamps below). Don't see that on core tests, so
probably related to S3.
One a failed run:
{noformat}
01:39:32.276
query_test/test_hdfs_file_mods.py::TestHdfsFileMods::test_file_modifications[modification_type:
move_file | exec_option: {'batch_size': 0, 'num_nodes': 0,
'disable_codegen_rows_threshold': 0, 'disable_codegen': False,
'abort_on_error': 1, 'exec_single_node_rows_threshold': 0} | table_format:
text/none] PASSED
01:39:58.413
query_test/test_hdfs_file_mods.py::TestHdfsFileMods::test_file_modifications[modification_type:
append | exec_option: {'batch_size': 0, 'num_nodes': 0,
'disable_codegen_rows_threshold': 0, 'disable_codegen': False,
'abort_on_error': 1, 'exec_single_node_rows_threshold': 0} | table_format:
text/none] PASSED
01:44:33.785
query_test/test_insert.py::TestInsertQueries::test_insert[exec_option:
{'sync_ddl': 0, 'batch_size': 0, 'num_nodes': 0,
'disable_codegen_rows_threshold': 0, 'disable_codegen': True, 'abort_on_error':
1, 'exec_single_node_rows_threshold': 0} | table_format: text/none] FAILED
===== ~3hrs ======
04:32:22.108
query_test/test_insert.py::TestInsertQueries::test_insert[exec_option:
{'sync_ddl': 0, 'batch_size': 0, 'num_nodes': 0,
'disable_codegen_rows_threshold': 0, 'disable_codegen': False,
'abort_on_error': 1, 'exec_single_node_rows_threshold': 0} | table_format:
text/none] PASSED
04:33:21.934
query_test/test_insert.py::TestInsertQueries::test_insert_overwrite[exec_option:
{'sync_ddl': 0, 'batch_size': 0, 'num_nodes': 0,
'disable_codegen_rows_threshold': 0, 'disable_codegen': True, 'abort_on_error':
1, 'exec_single_node_rows_threshold': 0} | table_format: text/none] PASSED
04:34:26.631
query_test/test_insert.py::TestInsertQueries::test_insert_overwrite[exec_option:
{'sync_ddl': 0, 'batch_size': 0, 'num_nodes': 0,
'disable_codegen_rows_threshold': 0, 'disable_codegen': False,
'abort_on_error': 1, 'exec_single_node_rows_threshold': 0} | table_format:
text/none] PASSED
{noformat}
On a successful run
{noformat}
'exec_single_node_rows_threshold': 0} | table_format: text/none] PASSED
00:56:47.304
query_test/test_hdfs_file_mods.py::TestHdfsFileMods::test_file_modifications[modification_type:
move_file | exec_option: {'batch_size': 0, 'num_nodes': 0,
'disable_codegen_rows_threshold': 0, 'disable_codegen': False,
'abort_on_error': 1, 'exec_single_node_rows_threshold': 0} | table_format:
text/none] PASSED
00:57:07.228
query_test/test_hdfs_file_mods.py::TestHdfsFileMods::test_file_modifications[modification_type:
append | exec_option: {'batch_size': 0, 'num_nodes': 0,
'disable_codegen_rows_threshold': 0, 'disable_codegen': False,
'abort_on_error': 1, 'exec_single_node_rows_threshold': 0} | table_format:
text/none] PASSED
01:49:47.897
query_test/test_insert.py::TestInsertQueries::test_insert[exec_option:
{'sync_ddl': 0, 'batch_size': 0, 'num_nodes': 0,
'disable_codegen_rows_threshold': 0, 'disable_codegen': True, 'abort_on_error':
1, 'exec_single_node_rows_threshold': 0} | table_format: text/none] PASSED
======= ~1.5 hrs =====
03:13:49.498
query_test/test_insert.py::TestInsertQueries::test_insert[exec_option:
{'sync_ddl': 0, 'batch_size': 0, 'num_nodes': 0,
'disable_codegen_rows_threshold': 0, 'disable_codegen': False,
'abort_on_error': 1, 'exec_single_node_rows_threshold': 0} | table_format:
text/none] PASSED
03:14:16.074
query_test/test_insert.py::TestInsertQueries::test_insert_overwrite[exec_option:
{'sync_ddl': 0, 'batch_size': 0, 'num_nodes': 0,
'disable_codegen_rows_threshold': 0, 'disable_codegen': True, 'abort_on_error':
1, 'exec_single_node_rows_threshold': 0} | table_format: text/none] PASSED
03:14:44.101
query_test/test_insert.py::TestInsertQueries::test_insert_overwrite[exec_option:
{'sync_ddl': 0, 'batch_size': 0, 'num_nodes': 0,
'disable_codegen_rows_threshold': 0, 'disable_codegen': False,
'abort_on_error': 1, 'exec_single_node_rows_threshold': 0} | table_format:
text/none] PASSED
{noformat}
On the failed run, I could see a similar gap in the impalad and catalogd logs.
Not super clear where this time is spent. Needs more profiling of the jenkins
runs when this happens.
{noformat}
CodeGen: Total=0 Peak=209.00 KB
I0728 00:59:26.070897 8356 query-state.cc:424] Cancel:
query_id=fa4b08ba88a16c6b:6be1b0a200000000
I0728 00:59:26.070952 8356 query-exec-mgr.cc:155] ReleaseQueryState():
query_id=fa4b08ba88a16c6b:6be1b0a200000000 refcnt=1
<----- gap ------>
I0728 03:26:50.400184 6411 impala-beeswax-server.cc:52] query():
query=invalidate metadata functional. alltypesinsert
I0728 03:26:50.400235 6411 impala-beeswax-server.cc:427] query: Query {
01: query (string) = "invalidate metadata functional. alltypesinsert",
03: configuration (list) = list<string>[7] {
[0] = "DISABLE_CODEGEN_ROWS_THRESHOLD=0",
[1] = "BATCH_SIZE=0",
[2] = "NUM_NODES=0",
[3] = "SYNC_DDL=0",
[4] = "DISABLE_CODEGEN=False",
[5] = "ABORT_ON_ERROR=1",
[6] = "EXEC_SINGLE_NODE_ROWS_THRESHOLD=0",
},
04: hadoop_user (string) = "jenkins",
}
{noformat}
{noformat}
I0728 00:56:12.747411 900 HdfsTable.java:942] Loaded file and block metadata
for functional.alltypesinsert
I0728 00:56:12.747599 900 HdfsTable.java:1273] Incrementally loaded table
metadata for: functional.alltypesinsert
I0728 00:56:12.750581 473 catalog-server.cc:490] Collected update:
TABLE:functional.alltypesinsert, version=3444, original size=16379
I0728 00:56:12.750932 473 catalog-server.cc:490] Collected update:
CATALOG_SERVICE_ID, version=3444, original size=49
I0728 00:56:13.648466 479 catalog-server.cc:245] A catalog update with 2
entries is assembled. Catalog version: 3444 Last sent catalog version: 3443
<------ gap ----->
I0728 03:26:50.402408 899 CatalogServiceCatalog.java:1555] Invalidating table
metadata: functional.alltypesinsert
I0728 03:26:50.542961 473 catalog-server.cc:490] Collected update:
TABLE:functional.alltypesinsert, version=3445, original size=61
I0728 03:26:50.543259 473 catalog-server.cc:490] Collected update:
CATALOG_SERVICE_ID, version=3445, original size=49
I0728 03:26:52.543041 479 catalog-server.cc:245] A catalog update with 2
entries is assembled. Catalog version: 3445 Last sent catalog versio
{noformat}
> TestInsertQueries.test_insert fails on S3 with 0 rows returned
> --------------------------------------------------------------
>
> Key: IMPALA-7371
> URL: https://issues.apache.org/jira/browse/IMPALA-7371
> Project: IMPALA
> Issue Type: Bug
> Components: Catalog
> Affects Versions: Impala 3.0
> Reporter: David Knupp
> Assignee: bharath v
> Priority: Critical
> Attachments: catalogd_excerpt.INFO, impalad_excerpt.INFO,
> profile.txt, profile_excerpt.log
>
>
> Stacktrace
> {noformat}
> query_test/test_insert.py:118: in test_insert
> multiple_impalad=vector.get_value('exec_option')['sync_ddl'] == 1)
> /data/jenkins/workspace/impala-cdh6.0.x-core-s3/repos/Impala/tests/common/impala_test_suite.py:426:
> in run_test_case
> self.__verify_results_and_errors(vector, test_section, result, use_db)
> /data/jenkins/workspace/impala-cdh6.0.x-core-s3/repos/Impala/tests/common/impala_test_suite.py:299:
> in __verify_results_and_errors
> replace_filenames_with_placeholder)
> /data/jenkins/workspace/impala-cdh6.0.x-core-s3/repos/Impala/tests/common/test_result_verifier.py:434:
> in verify_raw_results
> VERIFIER_MAP[verifier](expected, actual)
> /data/jenkins/workspace/impala-cdh6.0.x-core-s3/repos/Impala/tests/common/test_result_verifier.py:261:
> in verify_query_result_is_equal
> assert expected_results == actual_results
> E assert Comparing QueryTestResults (expected vs actual):
> E 75,false,0,0,0,0,0,0,'04/01/09','0' != None
> E 76,true,1,1,1,10,1.100000023841858,10.1,'04/01/09','1' != None
> E 77,false,2,2,2,20,2.200000047683716,20.2,'04/01/09','2' != None
> E 78,true,3,3,3,30,3.299999952316284,30.3,'04/01/09','3' != None
> E 79,false,4,4,4,40,4.400000095367432,40.4,'04/01/09','4' != None
> E 80,true,5,5,5,50,5.5,50.5,'04/01/09','5' != None
> E 81,false,6,6,6,60,6.599999904632568,60.6,'04/01/09','6' != None
> E 82,true,7,7,7,70,7.699999809265137,70.7,'04/01/09','7' != None
> E 83,false,8,8,8,80,8.800000190734863,80.8,'04/01/09','8' != None
> E 84,true,9,9,9,90,9.899999618530273,90.90000000000001,'04/01/09','9' !=
> None
> E 85,false,0,0,0,0,0,0,'04/02/09','0' != None
> E 86,true,1,1,1,10,1.100000023841858,10.1,'04/02/09','1' != None
> E 87,false,2,2,2,20,2.200000047683716,20.2,'04/02/09','2' != None
> E 88,true,3,3,3,30,3.299999952316284,30.3,'04/02/09','3' != None
> E 89,false,4,4,4,40,4.400000095367432,40.4,'04/02/09','4' != None
> E 90,true,5,5,5,50,5.5,50.5,'04/02/09','5' != None
> E 91,false,6,6,6,60,6.599999904632568,60.6,'04/02/09','6' != None
> E 92,true,7,7,7,70,7.699999809265137,70.7,'04/02/09','7' != None
> E 93,false,8,8,8,80,8.800000190734863,80.8,'04/02/09','8' != None
> E 94,true,9,9,9,90,9.899999618530273,90.90000000000001,'04/02/09','9' !=
> None
> E 95,false,0,0,0,0,0,0,'04/03/09','0' != None
> E 96,true,1,1,1,10,1.100000023841858,10.1,'04/03/09','1' != None
> E 97,false,2,2,2,20,2.200000047683716,20.2,'04/03/09','2' != None
> E 98,true,3,3,3,30,3.299999952316284,30.3,'04/03/09','3' != None
> E 99,false,4,4,4,40,4.400000095367432,40.4,'04/03/09','4' != None
> E Number of rows returned (expected vs actual): 25 != 0
> {noformat}
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
