[
https://issues.apache.org/jira/browse/IMPALA-7594?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Tim Armstrong updated IMPALA-7594:
----------------------------------
Description:
Similar to IMPALA-7580, I hit this on a build of one of my patches when running
under ASAN. The branch had the fix for IMPALA-7580 in it (it's based off
038af345933fde4fbcc9bc524f4ca93bfc08c633):
{noformat}
custom_cluster.test_automatic_invalidation.TestAutomaticCatalogInvalidation.test_local_catalog
(from pytest)
Failing for the past 2 builds (Since Failed#3242 )
Took 30 sec.
add description
Error Message
assert 1537339209.989275 < 1537339209.65928 + where 1537339209.989275 =
<built-in function time>() + where <built-in function time> = time.time
Stacktrace
custom_cluster/test_automatic_invalidation.py:70: in test_local_catalog
self._run_test(cursor)
custom_cluster/test_automatic_invalidation.py:58: in _run_test
assert time.time() < timeout
E assert 1537339209.989275 < 1537339209.65928
E + where 1537339209.989275 = <built-in function time>()
E + where <built-in function time> = time.time
Standard Error
-- 2018-09-18 23:39:39,498 INFO MainThread: Starting cluster with command:
/data/jenkins/workspace/impala-private-parameterized/repos/Impala/bin/start-impala-cluster.py
--cluster_size=3 --num_coordinators=3
--log_dir=/data/jenkins/workspace/impala-private-parameterized/repos/Impala/logs/custom_cluster_tests
--log_level=1 '--impalad_args="--invalidate_tables_timeout_s=20
--use_local_catalog" ' '--state_store_args="--statestore_update_frequency_ms=50
--statestore_priority_update_frequency_ms=50
--statestore_heartbeat_frequency_ms=50" '
'--catalogd_args="--invalidate_tables_timeout_s=20
--catalog_topic_mode=minimal" '
23:39:40 MainThread: Starting State Store logging to
/data/jenkins/workspace/impala-private-parameterized/repos/Impala/logs/custom_cluster_tests/statestored.INFO
23:39:41 MainThread: Starting Catalog Service logging to
/data/jenkins/workspace/impala-private-parameterized/repos/Impala/logs/custom_cluster_tests/catalogd.INFO
23:39:42 MainThread: Starting Impala Daemon logging to
/data/jenkins/workspace/impala-private-parameterized/repos/Impala/logs/custom_cluster_tests/impalad.INFO
23:39:43 MainThread: Starting Impala Daemon logging to
/data/jenkins/workspace/impala-private-parameterized/repos/Impala/logs/custom_cluster_tests/impalad_node1.INFO
23:39:44 MainThread: Starting Impala Daemon logging to
/data/jenkins/workspace/impala-private-parameterized/repos/Impala/logs/custom_cluster_tests/impalad_node2.INFO
23:39:47 MainThread: Found 3 impalad/1 statestored/1 catalogd process(es)
23:39:47 MainThread: Getting num_known_live_backends from
impala-ec2-centos74-m5-4xlarge-ondemand-01b4.vpc.cloudera.com:25000
23:39:47 MainThread: Waiting for num_known_live_backends=3. Current value: 2
23:39:48 MainThread: Getting num_known_live_backends from
impala-ec2-centos74-m5-4xlarge-ondemand-01b4.vpc.cloudera.com:25000
23:39:48 MainThread: num_known_live_backends has reached value: 3
23:39:48 MainThread: Getting num_known_live_backends from
impala-ec2-centos74-m5-4xlarge-ondemand-01b4.vpc.cloudera.com:25001
23:39:48 MainThread: num_known_live_backends has reached value: 3
23:39:48 MainThread: Getting num_known_live_backends from
impala-ec2-centos74-m5-4xlarge-ondemand-01b4.vpc.cloudera.com:25002
23:39:48 MainThread: num_known_live_backends has reached value: 3
23:39:48 MainThread: Impala Cluster Running with 3 nodes (3 coordinators, 3
executors).
-- 2018-09-18 23:39:48,471 INFO MainThread: Found 3 impalad/1 statestored/1
catalogd process(es)
-- 2018-09-18 23:39:48,471 INFO MainThread: Getting metric:
statestore.live-backends from
impala-ec2-centos74-m5-4xlarge-ondemand-01b4.vpc.cloudera.com:25010
-- 2018-09-18 23:39:48,472 INFO MainThread: Metric
'statestore.live-backends' has reached desired value: 4
-- 2018-09-18 23:39:48,472 INFO MainThread: Getting num_known_live_backends
from impala-ec2-centos74-m5-4xlarge-ondemand-01b4.vpc.cloudera.com:25000
-- 2018-09-18 23:39:48,473 INFO MainThread: num_known_live_backends has
reached value: 3
-- 2018-09-18 23:39:48,473 INFO MainThread: Getting num_known_live_backends
from impala-ec2-centos74-m5-4xlarge-ondemand-01b4.vpc.cloudera.com:25001
-- 2018-09-18 23:39:48,474 INFO MainThread: num_known_live_backends has
reached value: 3
-- 2018-09-18 23:39:48,474 INFO MainThread: Getting num_known_live_backends
from impala-ec2-centos74-m5-4xlarge-ondemand-01b4.vpc.cloudera.com:25002
-- 2018-09-18 23:39:48,475 INFO MainThread: num_known_live_backends has
reached value: 3
-- connecting to: localhost:21000
-- 2018-09-18 23:39:48,475 ERROR MainThread: Failed to open transport
(tries_left=3)
Traceback (most recent call last):
File
"/data/jenkins/workspace/impala-private-parameterized/repos/Impala/infra/python/env/lib/python2.7/site-packages/impala/hiveserver2.py",
line 940, in _execute
return func(request)
File
"/data/jenkins/workspace/impala-private-parameterized/repos/Impala/infra/python/env/lib/python2.7/site-packages/impala/_thrift_gen/TCLIService/TCLIService.py",
line 175, in OpenSession
return self.recv_OpenSession()
File
"/data/jenkins/workspace/impala-private-parameterized/repos/Impala/infra/python/env/lib/python2.7/site-packages/impala/_thrift_gen/TCLIService/TCLIService.py",
line 186, in recv_OpenSession
(fname, mtype, rseqid) = self._iprot.readMessageBegin()
File
"/data/jenkins/workspace/impala-private-parameterized/Impala-Toolchain/thrift-0.9.3-p4/python/lib64/python2.7/site-packages/thrift/protocol/TBinaryProtocol.py",
line 126, in readMessageBegin
sz = self.readI32()
File
"/data/jenkins/workspace/impala-private-parameterized/Impala-Toolchain/thrift-0.9.3-p4/python/lib64/python2.7/site-packages/thrift/protocol/TBinaryProtocol.py",
line 206, in readI32
buff = self.trans.readAll(4)
File
"/data/jenkins/workspace/impala-private-parameterized/Impala-Toolchain/thrift-0.9.3-p4/python/lib64/python2.7/site-packages/thrift/transport/TTransport.py",
line 58, in readAll
chunk = self.read(sz - have)
File
"/data/jenkins/workspace/impala-private-parameterized/Impala-Toolchain/thrift-0.9.3-p4/python/lib64/python2.7/site-packages/thrift/transport/TTransport.py",
line 159, in read
self.__rbuf = StringIO(self.__trans.read(max(sz, self.__rbuf_size)))
File
"/data/jenkins/workspace/impala-private-parameterized/Impala-Toolchain/thrift-0.9.3-p4/python/lib64/python2.7/site-packages/thrift/transport/TSocket.py",
line 120, in read
message='TSocket read 0 bytes')
TTransportException: TSocket read 0 bytes
{noformat}
was:
Similar to IMPALA-7580, I hit this on a build of one of my patches. The branch
had the fix for IMPALA-7580 in it (it's based off
038af345933fde4fbcc9bc524f4ca93bfc08c633):
{noformat}
custom_cluster.test_automatic_invalidation.TestAutomaticCatalogInvalidation.test_local_catalog
(from pytest)
Failing for the past 2 builds (Since Failed#3242 )
Took 30 sec.
add description
Error Message
assert 1537339209.989275 < 1537339209.65928 + where 1537339209.989275 =
<built-in function time>() + where <built-in function time> = time.time
Stacktrace
custom_cluster/test_automatic_invalidation.py:70: in test_local_catalog
self._run_test(cursor)
custom_cluster/test_automatic_invalidation.py:58: in _run_test
assert time.time() < timeout
E assert 1537339209.989275 < 1537339209.65928
E + where 1537339209.989275 = <built-in function time>()
E + where <built-in function time> = time.time
Standard Error
-- 2018-09-18 23:39:39,498 INFO MainThread: Starting cluster with command:
/data/jenkins/workspace/impala-private-parameterized/repos/Impala/bin/start-impala-cluster.py
--cluster_size=3 --num_coordinators=3
--log_dir=/data/jenkins/workspace/impala-private-parameterized/repos/Impala/logs/custom_cluster_tests
--log_level=1 '--impalad_args="--invalidate_tables_timeout_s=20
--use_local_catalog" ' '--state_store_args="--statestore_update_frequency_ms=50
--statestore_priority_update_frequency_ms=50
--statestore_heartbeat_frequency_ms=50" '
'--catalogd_args="--invalidate_tables_timeout_s=20
--catalog_topic_mode=minimal" '
23:39:40 MainThread: Starting State Store logging to
/data/jenkins/workspace/impala-private-parameterized/repos/Impala/logs/custom_cluster_tests/statestored.INFO
23:39:41 MainThread: Starting Catalog Service logging to
/data/jenkins/workspace/impala-private-parameterized/repos/Impala/logs/custom_cluster_tests/catalogd.INFO
23:39:42 MainThread: Starting Impala Daemon logging to
/data/jenkins/workspace/impala-private-parameterized/repos/Impala/logs/custom_cluster_tests/impalad.INFO
23:39:43 MainThread: Starting Impala Daemon logging to
/data/jenkins/workspace/impala-private-parameterized/repos/Impala/logs/custom_cluster_tests/impalad_node1.INFO
23:39:44 MainThread: Starting Impala Daemon logging to
/data/jenkins/workspace/impala-private-parameterized/repos/Impala/logs/custom_cluster_tests/impalad_node2.INFO
23:39:47 MainThread: Found 3 impalad/1 statestored/1 catalogd process(es)
23:39:47 MainThread: Getting num_known_live_backends from
impala-ec2-centos74-m5-4xlarge-ondemand-01b4.vpc.cloudera.com:25000
23:39:47 MainThread: Waiting for num_known_live_backends=3. Current value: 2
23:39:48 MainThread: Getting num_known_live_backends from
impala-ec2-centos74-m5-4xlarge-ondemand-01b4.vpc.cloudera.com:25000
23:39:48 MainThread: num_known_live_backends has reached value: 3
23:39:48 MainThread: Getting num_known_live_backends from
impala-ec2-centos74-m5-4xlarge-ondemand-01b4.vpc.cloudera.com:25001
23:39:48 MainThread: num_known_live_backends has reached value: 3
23:39:48 MainThread: Getting num_known_live_backends from
impala-ec2-centos74-m5-4xlarge-ondemand-01b4.vpc.cloudera.com:25002
23:39:48 MainThread: num_known_live_backends has reached value: 3
23:39:48 MainThread: Impala Cluster Running with 3 nodes (3 coordinators, 3
executors).
-- 2018-09-18 23:39:48,471 INFO MainThread: Found 3 impalad/1 statestored/1
catalogd process(es)
-- 2018-09-18 23:39:48,471 INFO MainThread: Getting metric:
statestore.live-backends from
impala-ec2-centos74-m5-4xlarge-ondemand-01b4.vpc.cloudera.com:25010
-- 2018-09-18 23:39:48,472 INFO MainThread: Metric
'statestore.live-backends' has reached desired value: 4
-- 2018-09-18 23:39:48,472 INFO MainThread: Getting num_known_live_backends
from impala-ec2-centos74-m5-4xlarge-ondemand-01b4.vpc.cloudera.com:25000
-- 2018-09-18 23:39:48,473 INFO MainThread: num_known_live_backends has
reached value: 3
-- 2018-09-18 23:39:48,473 INFO MainThread: Getting num_known_live_backends
from impala-ec2-centos74-m5-4xlarge-ondemand-01b4.vpc.cloudera.com:25001
-- 2018-09-18 23:39:48,474 INFO MainThread: num_known_live_backends has
reached value: 3
-- 2018-09-18 23:39:48,474 INFO MainThread: Getting num_known_live_backends
from impala-ec2-centos74-m5-4xlarge-ondemand-01b4.vpc.cloudera.com:25002
-- 2018-09-18 23:39:48,475 INFO MainThread: num_known_live_backends has
reached value: 3
-- connecting to: localhost:21000
-- 2018-09-18 23:39:48,475 ERROR MainThread: Failed to open transport
(tries_left=3)
Traceback (most recent call last):
File
"/data/jenkins/workspace/impala-private-parameterized/repos/Impala/infra/python/env/lib/python2.7/site-packages/impala/hiveserver2.py",
line 940, in _execute
return func(request)
File
"/data/jenkins/workspace/impala-private-parameterized/repos/Impala/infra/python/env/lib/python2.7/site-packages/impala/_thrift_gen/TCLIService/TCLIService.py",
line 175, in OpenSession
return self.recv_OpenSession()
File
"/data/jenkins/workspace/impala-private-parameterized/repos/Impala/infra/python/env/lib/python2.7/site-packages/impala/_thrift_gen/TCLIService/TCLIService.py",
line 186, in recv_OpenSession
(fname, mtype, rseqid) = self._iprot.readMessageBegin()
File
"/data/jenkins/workspace/impala-private-parameterized/Impala-Toolchain/thrift-0.9.3-p4/python/lib64/python2.7/site-packages/thrift/protocol/TBinaryProtocol.py",
line 126, in readMessageBegin
sz = self.readI32()
File
"/data/jenkins/workspace/impala-private-parameterized/Impala-Toolchain/thrift-0.9.3-p4/python/lib64/python2.7/site-packages/thrift/protocol/TBinaryProtocol.py",
line 206, in readI32
buff = self.trans.readAll(4)
File
"/data/jenkins/workspace/impala-private-parameterized/Impala-Toolchain/thrift-0.9.3-p4/python/lib64/python2.7/site-packages/thrift/transport/TTransport.py",
line 58, in readAll
chunk = self.read(sz - have)
File
"/data/jenkins/workspace/impala-private-parameterized/Impala-Toolchain/thrift-0.9.3-p4/python/lib64/python2.7/site-packages/thrift/transport/TTransport.py",
line 159, in read
self.__rbuf = StringIO(self.__trans.read(max(sz, self.__rbuf_size)))
File
"/data/jenkins/workspace/impala-private-parameterized/Impala-Toolchain/thrift-0.9.3-p4/python/lib64/python2.7/site-packages/thrift/transport/TSocket.py",
line 120, in read
message='TSocket read 0 bytes')
TTransportException: TSocket read 0 bytes
{noformat}
> TestAutomaticCatalogInvalidation.test_local_catalog still hitting timeout
> -------------------------------------------------------------------------
>
> Key: IMPALA-7594
> URL: https://issues.apache.org/jira/browse/IMPALA-7594
> Project: IMPALA
> Issue Type: Bug
> Components: Infrastructure
> Affects Versions: Impala 3.1.0
> Reporter: Tim Armstrong
> Assignee: Tianyi Wang
> Priority: Critical
> Labels: flaky
>
> Similar to IMPALA-7580, I hit this on a build of one of my patches when
> running under ASAN. The branch had the fix for IMPALA-7580 in it (it's based
> off 038af345933fde4fbcc9bc524f4ca93bfc08c633):
> {noformat}
> custom_cluster.test_automatic_invalidation.TestAutomaticCatalogInvalidation.test_local_catalog
> (from pytest)
> Failing for the past 2 builds (Since Failed#3242 )
> Took 30 sec.
> add description
> Error Message
> assert 1537339209.989275 < 1537339209.65928 + where 1537339209.989275 =
> <built-in function time>() + where <built-in function time> = time.time
> Stacktrace
> custom_cluster/test_automatic_invalidation.py:70: in test_local_catalog
> self._run_test(cursor)
> custom_cluster/test_automatic_invalidation.py:58: in _run_test
> assert time.time() < timeout
> E assert 1537339209.989275 < 1537339209.65928
> E + where 1537339209.989275 = <built-in function time>()
> E + where <built-in function time> = time.time
> Standard Error
> -- 2018-09-18 23:39:39,498 INFO MainThread: Starting cluster with
> command:
> /data/jenkins/workspace/impala-private-parameterized/repos/Impala/bin/start-impala-cluster.py
> --cluster_size=3 --num_coordinators=3
> --log_dir=/data/jenkins/workspace/impala-private-parameterized/repos/Impala/logs/custom_cluster_tests
> --log_level=1 '--impalad_args="--invalidate_tables_timeout_s=20
> --use_local_catalog" '
> '--state_store_args="--statestore_update_frequency_ms=50
> --statestore_priority_update_frequency_ms=50
> --statestore_heartbeat_frequency_ms=50" '
> '--catalogd_args="--invalidate_tables_timeout_s=20
> --catalog_topic_mode=minimal" '
> 23:39:40 MainThread: Starting State Store logging to
> /data/jenkins/workspace/impala-private-parameterized/repos/Impala/logs/custom_cluster_tests/statestored.INFO
> 23:39:41 MainThread: Starting Catalog Service logging to
> /data/jenkins/workspace/impala-private-parameterized/repos/Impala/logs/custom_cluster_tests/catalogd.INFO
> 23:39:42 MainThread: Starting Impala Daemon logging to
> /data/jenkins/workspace/impala-private-parameterized/repos/Impala/logs/custom_cluster_tests/impalad.INFO
> 23:39:43 MainThread: Starting Impala Daemon logging to
> /data/jenkins/workspace/impala-private-parameterized/repos/Impala/logs/custom_cluster_tests/impalad_node1.INFO
> 23:39:44 MainThread: Starting Impala Daemon logging to
> /data/jenkins/workspace/impala-private-parameterized/repos/Impala/logs/custom_cluster_tests/impalad_node2.INFO
> 23:39:47 MainThread: Found 3 impalad/1 statestored/1 catalogd process(es)
> 23:39:47 MainThread: Getting num_known_live_backends from
> impala-ec2-centos74-m5-4xlarge-ondemand-01b4.vpc.cloudera.com:25000
> 23:39:47 MainThread: Waiting for num_known_live_backends=3. Current value: 2
> 23:39:48 MainThread: Getting num_known_live_backends from
> impala-ec2-centos74-m5-4xlarge-ondemand-01b4.vpc.cloudera.com:25000
> 23:39:48 MainThread: num_known_live_backends has reached value: 3
> 23:39:48 MainThread: Getting num_known_live_backends from
> impala-ec2-centos74-m5-4xlarge-ondemand-01b4.vpc.cloudera.com:25001
> 23:39:48 MainThread: num_known_live_backends has reached value: 3
> 23:39:48 MainThread: Getting num_known_live_backends from
> impala-ec2-centos74-m5-4xlarge-ondemand-01b4.vpc.cloudera.com:25002
> 23:39:48 MainThread: num_known_live_backends has reached value: 3
> 23:39:48 MainThread: Impala Cluster Running with 3 nodes (3 coordinators, 3
> executors).
> -- 2018-09-18 23:39:48,471 INFO MainThread: Found 3 impalad/1
> statestored/1 catalogd process(es)
> -- 2018-09-18 23:39:48,471 INFO MainThread: Getting metric:
> statestore.live-backends from
> impala-ec2-centos74-m5-4xlarge-ondemand-01b4.vpc.cloudera.com:25010
> -- 2018-09-18 23:39:48,472 INFO MainThread: Metric
> 'statestore.live-backends' has reached desired value: 4
> -- 2018-09-18 23:39:48,472 INFO MainThread: Getting
> num_known_live_backends from
> impala-ec2-centos74-m5-4xlarge-ondemand-01b4.vpc.cloudera.com:25000
> -- 2018-09-18 23:39:48,473 INFO MainThread: num_known_live_backends has
> reached value: 3
> -- 2018-09-18 23:39:48,473 INFO MainThread: Getting
> num_known_live_backends from
> impala-ec2-centos74-m5-4xlarge-ondemand-01b4.vpc.cloudera.com:25001
> -- 2018-09-18 23:39:48,474 INFO MainThread: num_known_live_backends has
> reached value: 3
> -- 2018-09-18 23:39:48,474 INFO MainThread: Getting
> num_known_live_backends from
> impala-ec2-centos74-m5-4xlarge-ondemand-01b4.vpc.cloudera.com:25002
> -- 2018-09-18 23:39:48,475 INFO MainThread: num_known_live_backends has
> reached value: 3
> -- connecting to: localhost:21000
> -- 2018-09-18 23:39:48,475 ERROR MainThread: Failed to open transport
> (tries_left=3)
> Traceback (most recent call last):
> File
> "/data/jenkins/workspace/impala-private-parameterized/repos/Impala/infra/python/env/lib/python2.7/site-packages/impala/hiveserver2.py",
> line 940, in _execute
> return func(request)
> File
> "/data/jenkins/workspace/impala-private-parameterized/repos/Impala/infra/python/env/lib/python2.7/site-packages/impala/_thrift_gen/TCLIService/TCLIService.py",
> line 175, in OpenSession
> return self.recv_OpenSession()
> File
> "/data/jenkins/workspace/impala-private-parameterized/repos/Impala/infra/python/env/lib/python2.7/site-packages/impala/_thrift_gen/TCLIService/TCLIService.py",
> line 186, in recv_OpenSession
> (fname, mtype, rseqid) = self._iprot.readMessageBegin()
> File
> "/data/jenkins/workspace/impala-private-parameterized/Impala-Toolchain/thrift-0.9.3-p4/python/lib64/python2.7/site-packages/thrift/protocol/TBinaryProtocol.py",
> line 126, in readMessageBegin
> sz = self.readI32()
> File
> "/data/jenkins/workspace/impala-private-parameterized/Impala-Toolchain/thrift-0.9.3-p4/python/lib64/python2.7/site-packages/thrift/protocol/TBinaryProtocol.py",
> line 206, in readI32
> buff = self.trans.readAll(4)
> File
> "/data/jenkins/workspace/impala-private-parameterized/Impala-Toolchain/thrift-0.9.3-p4/python/lib64/python2.7/site-packages/thrift/transport/TTransport.py",
> line 58, in readAll
> chunk = self.read(sz - have)
> File
> "/data/jenkins/workspace/impala-private-parameterized/Impala-Toolchain/thrift-0.9.3-p4/python/lib64/python2.7/site-packages/thrift/transport/TTransport.py",
> line 159, in read
> self.__rbuf = StringIO(self.__trans.read(max(sz, self.__rbuf_size)))
> File
> "/data/jenkins/workspace/impala-private-parameterized/Impala-Toolchain/thrift-0.9.3-p4/python/lib64/python2.7/site-packages/thrift/transport/TSocket.py",
> line 120, in read
> message='TSocket read 0 bytes')
> TTransportException: TSocket read 0 bytes
> {noformat}
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
---------------------------------------------------------------------
To unsubscribe, e-mail: issues-all-unsubscr...@impala.apache.org
For additional commands, e-mail: issues-all-h...@impala.apache.org
