Uploaded image for project: 'IMPALA'
  1. IMPALA
  2. IMPALA-12711

DDL/DML errors are not shown in impalad logs

    XMLWordPrintableJSON

Details

    • Bug
    • Status: Resolved
    • Major
    • Resolution: Fixed
    • Impala 4.1.0, Impala 4.2.0, Impala 4.1.1, Impala 4.1.2, Impala 4.3.0
    • Impala 4.4.0
    • Backend
    • None

    Description

      Since IMPALA-10811, DDLs are executed in an async thread by default. The errors are not logged after that. For instance, run "INVALIDATE METADATA a.b" on an inexisting table, the error shown in the client is "ERROR: TableNotFoundException: Table not found: a.b". However, in the impalad logs, it looks like the statement succeeds.

      I0115 13:47:43.256397 23443 Frontend.java:2072] dc497affd5678498:365a460000000000] Analyzing query: INVALIDATE METADATA a.b db: default
      I0115 13:47:43.256489 23443 Frontend.java:2084] dc497affd5678498:365a460000000000] The original executor group sets from executor membership snapshot: [TExecutorGroupSet(curr_num_executors:3, expected_num_executors:20, exec_group_name_prefix:)]
      I0115 13:47:43.256561 23443 RequestPoolService.java:200] dc497affd5678498:365a460000000000] Default pool only, scheduler allocation is not specified.
      I0115 13:47:43.256652 23443 Frontend.java:2104] dc497affd5678498:365a460000000000] A total of 1 executor group sets to be considered for auto-scaling: [TExecutorGroupSet(curr_num_executors:3, expected_num_executors:20, exec_group_name_prefix:, max_mem_limit:9223372036854775807, num_cores_per_executor:2147483647)]
      I0115 13:47:43.256775 23443 Frontend.java:2138] dc497affd5678498:365a460000000000] Consider executor group set: TExecutorGroupSet(curr_num_executors:3, expected_num_executors:20, exec_group_name_prefix:, max_mem_limit:9223372036854775807, num_cores_per_executor:2147483647) with assumption of 0 cores per node.
      I0115 13:47:43.263244 23443 AnalysisContext.java:508] dc497affd5678498:365a460000000000] Analysis took 4 ms
      I0115 13:47:43.264606 23443 BaseAuthorizationChecker.java:114] dc497affd5678498:365a460000000000] Authorization check took 1 ms
      I0115 13:47:43.264681 23443 Frontend.java:2400] dc497affd5678498:365a460000000000] Analysis and authorization finished.
      I0115 13:47:43.301832 23443 Frontend.java:2319] dc497affd5678498:365a460000000000] Selected executor group: TExecutorGroupSet(curr_num_executors:3, expected_num_executors:20, exec_group_name_prefix:, max_mem_limit:9223372036854775807, num_cores_per_executor:2147483647), reason: query is not auto-scalable
      I0115 13:47:43.305258 23443 client-request-state.cc:785] dc497affd5678498:365a460000000000] DDL exec mode=asynchronous
      I0115 13:47:43.306367 23443 impala-hs2-server.cc:573] ExecuteStatement(): return_val=TExecuteStatementResp {
        01: status (struct) = TStatus {
          01: statusCode (i32) = 0,
        },
        02: operationHandle (struct) = TOperationHandle {
          01: operationId (struct) = THandleIdentifier {
            01: guid (string) = "\x98\x84g\xd5\xffzI\xdc\x00\x00\x00\x00\x00FZ6",
            02: secret (string) = "<HIDDEN>",
          },     
          02: operationType (i32) = 0,
          03: hasResultSet (bool) = false,
        },
      }
      I0115 13:47:43.509263 23443 impala-hs2-server.cc:887] CloseOperation(): query_id=dc497affd5678498:365a460000000000
      I0115 13:47:43.509281 23443 impala-server.cc:1554] UnregisterQuery(): query_id=dc497affd5678498:365a460000000000
      I0115 13:47:43.509642 23298 impala-server.cc:1586] Query successfully unregistered: query_id=dc497affd5678498:365a460000000000

      If the DDL is executed with "set enable_async_ddl_execution=false", the error is shown in the logs:

      I0115 13:48:31.054708 23794 Frontend.java:2072] 8a48ab2ae184395d:dd53cfc100000000] Analyzing query: INVALIDATE METADATA a.b db: default
      I0115 13:48:31.054780 23794 Frontend.java:2084] 8a48ab2ae184395d:dd53cfc100000000] The original executor group sets from executor membership snapshot: [TExecutorGroupSet(curr_num_executors:3, expected_num_executors:20, exec_group_name_prefix:)]
      I0115 13:48:31.054841 23794 RequestPoolService.java:200] 8a48ab2ae184395d:dd53cfc100000000] Default pool only, scheduler allocation is not specified.
      I0115 13:48:31.054934 23794 Frontend.java:2104] 8a48ab2ae184395d:dd53cfc100000000] A total of 1 executor group sets to be considered for auto-scaling: [TExecutorGroupSet(curr_num_executors:3, expected_num_executors:20, exec_group_name_prefix:, max_mem_limit:9223372036854775807, num_cores_per_executor:2147483647)]
      I0115 13:48:31.055053 23794 Frontend.java:2138] 8a48ab2ae184395d:dd53cfc100000000] Consider executor group set: TExecutorGroupSet(curr_num_executors:3, expected_num_executors:20, exec_group_name_prefix:, max_mem_limit:9223372036854775807, num_cores_per_executor:2147483647) with assumption of 0 cores per node.
      I0115 13:48:31.055748 23794 AnalysisContext.java:508] 8a48ab2ae184395d:dd53cfc100000000] Analysis took 0 ms
      I0115 13:48:31.055960 23794 BaseAuthorizationChecker.java:114] 8a48ab2ae184395d:dd53cfc100000000] Authorization check took 0 ms
      I0115 13:48:31.056037 23794 Frontend.java:2400] 8a48ab2ae184395d:dd53cfc100000000] Analysis and authorization finished.
      I0115 13:48:31.056233 23794 Frontend.java:2319] 8a48ab2ae184395d:dd53cfc100000000] Selected executor group: TExecutorGroupSet(curr_num_executors:3, expected_num_executors:20, exec_group_name_prefix:, max_mem_limit:9223372036854775807, num_cores_per_executor:2147483647), reason: query is not auto-scalable
      I0115 13:48:31.056829 23794 client-request-state.cc:785] 8a48ab2ae184395d:dd53cfc100000000] DDL exec mode=synchronous
      I0115 13:48:31.191787 23794 client-request-state.cc:264] 8a48ab2ae184395d:dd53cfc100000000] TableNotFoundException: Table not found: a.b  // <---- This is the error we should log
      I0115 13:48:31.191802 23794 impala-server.cc:1554] 8a48ab2ae184395d:dd53cfc100000000] UnregisterQuery(): query_id=8a48ab2ae184395d:dd53cfc100000000
      I0115 13:48:31.192154 23300 impala-server.cc:1586] Query successfully unregistered: query_id=8a48ab2ae184395d:dd53cfc100000000
      

      Attachments

        Issue Links

          Activity

            People

              stigahuang Quanlong Huang
              stigahuang Quanlong Huang
              Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved: