impala-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Joe McDonnell (JIRA)" <j...@apache.org>
Subject [jira] [Resolved] (IMPALA-5488) TestValidateMetrics fails sometimes when running tests on Isilon
Date Wed, 21 Jun 2017 22:20:00 GMT

     [ https://issues.apache.org/jira/browse/IMPALA-5488?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]

Joe McDonnell resolved IMPALA-5488.
-----------------------------------
       Resolution: Fixed
    Fix Version/s: Impala 2.10.0

commit 53287df0a11ba43ff12067267cf2e3b0ffad075c
Author: Joe McDonnell <joemcdonnell@cloudera.com>
Date:   Wed Jun 14 11:29:38 2017 -0700

    IMPALA-5488: Fix handling of exclusive HDFS file handles
    
    This change fixes three issues:
    1. File handle caching is expected to be disabled for
    remote files (using exclusive HDFS file handles),
    however the file handles are still being cached.
    2. The retry logic for exclusive file handles is broken,
    leading the number of open files to be incorrect.
    3. There is no test coverage for disabling the file
    handle cache.
    
    To fix issue #1, when a scan range is requesting an
    exclusive file handle from the cache, it will always
    request a newly opened file handle. It also will destroy
    the file handle when the scan range is closed.
    
    To fix issue #2, exclusive file handles will no longer
    retry IOs. Since the exclusive file handle is always
    a fresh file handle, it will never have a bad file
    handle from the cache. This returns the logic to
    its state before IMPALA-4623 in these cases. If a
    file handle is borrowed from the cache, then the
    code will continue to retry once with a fresh handle.
    
    To fix issue #3, custom_cluster/test_hdfs_fd_caching.py
    now does both positive and negative tests for the file
    handle cache. It verifies that setting
    max_cached_file_handles to zero disables caching. It
    also verifies that caching is disabled on remote
    files. (This change will resolve IMPALA-5390.)
    
    Change-Id: I4c03696984285cc9ce463edd969c5149cd83a861
    Reviewed-on: http://gerrit.cloudera.org:8080/7181
    Reviewed-by: Dan Hecht <dhecht@cloudera.com>
    Tested-by: Impala Public Jenkins


> TestValidateMetrics fails sometimes when running tests on Isilon
> ----------------------------------------------------------------
>
>                 Key: IMPALA-5488
>                 URL: https://issues.apache.org/jira/browse/IMPALA-5488
>             Project: IMPALA
>          Issue Type: Bug
>          Components: Backend
>    Affects Versions: Impala 2.10.0
>            Reporter: Tim Armstrong
>            Assignee: Joe McDonnell
>            Priority: Blocker
>              Labels: flaky
>             Fix For: Impala 2.10.0
>
>
> This happened on commit e0f69ca1da448246a6260099c64f4cc5862188a2. I'm unsure when it
started failing, because it was masked by IMPALA-5423. The last green Isilon build was 014c5603f867907963f3821948f90d526e9a4789,
which is before the file handle cache change was merged.
> {code}
> 23:32:26 ============ 1367 passed, 82 skipped, 28 xfailed in 3965.31 seconds ============
> 23:32:26 ============================= test session starts ==============================
> 23:32:26 platform linux2 -- Python 2.6.6, pytest-2.9.2, py-1.4.32, pluggy-0.3.1 -- /data/jenkins/workspace/impala-umbrella-build-and-test-isilon/repos/Impala/bin/../infra/python/env/bin/python
> 23:32:26 cachedir: .cache
> 23:32:26 rootdir: /data/jenkins/workspace/impala-umbrella-build-and-test-isilon/repos/Impala/tests,
inifile: pytest.ini
> 23:32:26 plugins: random-0.2, xdist-1.15.0
> 23:32:26 collecting ... collected 2 items
> 23:32:26 
> 23:32:26 verifiers/test_verify_metrics.py::TestValidateMetrics::test_metrics_are_zero
FAILED
> 23:32:26 verifiers/test_verify_metrics.py::TestValidateMetrics::test_num_unused_buffers
PASSED
> 23:32:26 
> 23:32:26  generated xml file: /data/jenkins/workspace/impala-umbrella-build-and-test-isilon/repos/Impala/logs/ee_tests/results/TEST-impala-verify-metrics.xml

> 23:32:26 =========================== short test summary info ============================
> 23:32:26 FAIL verifiers/test_verify_metrics.py::TestValidateMetrics::()::test_metrics_are_zero
> 23:32:26 =================================== FAILURES ===================================
> 23:32:26 __________________ TestValidateMetrics.test_metrics_are_zero ___________________
> 23:32:26 verifiers/test_verify_metrics.py:34: in test_metrics_are_zero
> 23:32:26     verifier.verify_metrics_are_zero()
> 23:32:26 verifiers/metric_verifier.py:44: in verify_metrics_are_zero
> 23:32:26     self.wait_for_metric(metric, 0, timeout)
> 23:32:26 verifiers/metric_verifier.py:59: in wait_for_metric
> 23:32:26     self.impalad_service.wait_for_metric_value(metric_name, expected_value,
timeout)
> 23:32:26 common/impala_service.py:89: in wait_for_metric_value
> 23:32:26     (metric_name, expected_value, timeout)
> 23:32:26 E   AssertionError: Metric value impala-server.io-mgr.num-open-files did not
reach value 0 in 60s
> 23:32:26 ----------------------------- Captured stderr call -----------------------------
> 23:32:26 MainThread: Getting metric: impala-server.hash-table.total-bytes from localhost:25000
> 23:32:26 MainThread: Metric 'impala-server.hash-table.total-bytes' has reach desired
value: 0
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> 23:32:26 MainThread: Getting metric: impala-server.io-mgr.num-open-files from localhost:25000
> 23:32:26 MainThread: Waiting for metric value 'impala-server.io-mgr.num-open-files'=0.
Current value: 2
> 23:32:26 MainThread: Sleeping 1s before next retry.
> {code}



--
This message was sent by Atlassian JIRA
(v6.4.14#64029)

Mime
View raw message