[IMPALA-7418] test_udf_errors - returns Cancelled instead of actual error

• 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
• Target Version: Impala 3.1.0
• Epic Color: ghx-label-5
• Assignee: Pooja Nilangekar
• Reporter: Tim Armstrong
• Created: 09/Aug/18 17:33
• Updated: 19/Sep/18 22:24
• Resolved: 24/Aug/18 03:30

Description

query_test.test_udfs.TestUdfExecution.test_udf_errors[exec_option: {'disable_codegen_rows_threshold': 0, 'disable_codegen': True, 'exec_single_node_rows_threshold': 0, 'enable_expr_rewrites': True} | table_format: text/none] (from pytest)
Failing for the past 1 build (Since Failed#2925 )
Took 19 sec.
add description
Error Message

query_test/test_udfs.py:415: in test_udf_errors     self.run_test_case('QueryTest/udf-errors', vector, use_db=unique_database) common/impala_test_suite.py:412: in run_test_case     self.__verify_exceptions(test_section['CATCH'], str(e), use_db) common/impala_test_suite.py:290: in __verify_exceptions     (expected_str, actual_str) E   AssertionError: Unexpected exception string. Expected: BadExpr2 prepare error E   Not found in actual: ImpalaBeeswaxException: Query aborted:Cancelled

Stacktrace

query_test/test_udfs.py:415: in test_udf_errors
    self.run_test_case('QueryTest/udf-errors', vector, use_db=unique_database)
common/impala_test_suite.py:412: in run_test_case
    self.__verify_exceptions(test_section['CATCH'], str(e), use_db)
common/impala_test_suite.py:290: in __verify_exceptions
    (expected_str, actual_str)
E   AssertionError: Unexpected exception string. Expected: BadExpr2 prepare error
E   Not found in actual: ImpalaBeeswaxException: Query aborted:Cancelled

Standard Error

SET sync_ddl=False;
-- executing against localhost:21000
DROP DATABASE IF EXISTS `test_udf_errors_be4e0293` CASCADE;

MainThread: Started query bd4790b45c20640d:9c62ffba00000000
SET sync_ddl=False;
-- executing against localhost:21000
CREATE DATABASE `test_udf_errors_be4e0293`;

MainThread: Started query 474595a3ecba67bd:7a14c8400000000
MainThread: Created database "test_udf_errors_be4e0293" for test ID "query_test/test_udfs.py::TestUdfExecution::()::test_udf_errors[exec_option: {'disable_codegen_rows_threshold': 0, 'disable_codegen': True, 'exec_single_node_rows_threshold': 0, 'enable_expr_rewrites': True} | table_format: text/none]"
-- executing against localhost:21000
use test_udf_errors_be4e0293;

MainThread: Started query 264b0cd09d289c09:cc5dafed00000000
SET disable_codegen_rows_threshold=0;
SET disable_codegen=True;
SET exec_single_node_rows_threshold=0;
SET enable_expr_rewrites=True;
-- executing against localhost:21000
create function if not exists hive_pi() returns double
location '/test-warehouse/hive-exec.jar'
symbol='org.apache.hadoop.hive.ql.udf.UDFPI';

MainThread: Started query ba41ccb6f020becd:db23209f00000000
-- executing against localhost:21000
create function if not exists foo() returns double
location '/test-warehouse/not-a-real-file.so'
symbol='FnDoesNotExist';

-- executing against localhost:21000
create function if not exists foo() returns double
location '/test-warehouse/not-a-real-file.so'
symbol='FnDoesNotExist';

-- executing against localhost:21000
create function if not exists foo (string, string) returns string location
'/test-warehouse/test_udf_errors_be4e0293_bad_udf.ll' symbol='MyAwesomeUdf';

-- executing against localhost:21000
create function if not exists twenty_args(int, int, int, int, int, int,
    int, int, int, int, int, int, int, int, int, int, int, int, int, int) returns int
location '/test-warehouse/libTestUdfs.so'
symbol='TwentyArgs';

MainThread: Started query 6b4dc82f22e2f0f6:9d28ab0300000000
-- executing against localhost:21000
select twenty_args(1,2,3,4,5,6,7,8,9,10,11,12,13,14,15,16,17,18,19,20);

MainThread: Started query d40ea0f1effacd1:22e5c31f00000000
-- executing against localhost:21000
create function if not exists twenty_one_args(int, int, int, int, int, int,
    int, int, int, int, int, int, int, int, int, int, int, int, int, int, int) returns int
location '/test-warehouse/libTestUdfs.so'
symbol='TwentyOneArgs';

MainThread: Started query 12453a7e4b13fa4d:d163be3300000000
-- executing against localhost:21000
select twenty_one_args(1,2,3,4,5,6,7,8,9,10,11,12,13,14,15,16,17,18,19,20,21);

MainThread: Started query 26461e2ce5ce3adf:3544166a00000000
-- executing against localhost:21000
create function if not exists nine_args_ir(int, int, int, int, int, int,
    int, int, int) returns int
location '/test-warehouse/test-udfs.ll'
symbol='NineArgs';

MainThread: Started query 5b4599e5b1728cf3:47d44f2100000000
-- executing against localhost:21000
select nine_args_ir(1,2,3,4,5,6,7,8,9);

MainThread: Started query a64b4c1f588c7201:3ecfc39600000000
-- executing against localhost:21000
create function if not exists bad_expr(double) returns boolean
location '/test-warehouse/libTestUdfs.so'
symbol='BadExpr' prepare_fn='BadExprPrepare' close_fn='BadExprClose';

MainThread: Started query 9649b1c86826ffba:ef97b6bb00000000
-- executing against localhost:21000
create function if not exists bad_expr2(double) returns boolean
location '/test-warehouse/libTestUdfs.so'
symbol='BadExpr' prepare_fn='BadExpr2Prepare' close_fn='BadExprClose';

MainThread: Started query ec42f91cdc2b0a0e:53c863d800000000
-- executing against localhost:21000
select count(t1.int_col) from functional.alltypes t1 join functional.alltypes t2
on (bad_expr(rand()) = (t2.bool_col && t1.bool_col));

MainThread: Started query 9b4a86470ad7a5ba:f3c62e6000000000
-- executing against localhost:21000
select count(t1.int_col) from functional.alltypes t1 join functional.alltypes t2
on (bad_expr2(rand()) = (t2.bool_col && t1.bool_col));

MainThread: Started query e24faf2aa198849f:bccd6d6000000000
-- executing against localhost:21000
select count(int_col) from functional.alltypes where bad_expr(rand());

MainThread: Started query f6400e152de0995a:a2fc1d4800000000
-- executing against localhost:21000
select count(int_col) from functional.alltypes where bad_expr2(rand());

MainThread: Started query 4f4c1edb15bde2c3:9e247d1400000000
18/08/09 03:15:22 INFO fs.TrashPolicyDefault: Moved: 'hdfs://localhost:20500/test-warehouse/test_udf_errors_be4e0293_bad_udf.ll' to trash at: hdfs://localhost:20500/user/ubuntu/.Trash/Current/test-warehouse/test_udf_errors_be4e0293_bad_udf.ll

This started failing on Ubuntu 16.04 GVOs. E.g. https://jenkins.impala.io/job/ubuntu-16.04-from-scratch/2925 https://jenkins.impala.io/job/ubuntu-16.04-from-scratch/2923/

I can reproduce locally after looping for ~4-5 iterations on average with

while impala-py.test tests/query_test/test_udfs.py -k errors -n4 --verbose; do date; done

Issue Links

• is duplicated by: IMPALA-7328 Errors in HdfsScanner::Open() errors get swallowed up
• relates to: IMPALA-7335 Assertion Failure - test_corrupt_files