You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@qpid.apache.org by ch...@apache.org on 2020/11/03 19:42:53 UTC
[qpid-dispatch] branch dev-protocol-adaptors-2 updated:
DISPATCH-1820: Improve logging to investigate TCP test hangs
This is an automated email from the ASF dual-hosted git repository.
chug pushed a commit to branch dev-protocol-adaptors-2
in repository https://gitbox.apache.org/repos/asf/qpid-dispatch.git
The following commit(s) were added to refs/heads/dev-protocol-adaptors-2 by this push:
new a5cefb5 DISPATCH-1820: Improve logging to investigate TCP test hangs
a5cefb5 is described below
commit a5cefb5e34f4a3fa9c763f3e3a29b187a2e85472
Author: Chuck Rolke <ch...@apache.org>
AuthorDate: Tue Nov 3 14:41:52 2020 -0500
DISPATCH-1820: Improve logging to investigate TCP test hangs
---
tests/TCP_echo_client.py | 1 +
tests/TCP_echo_server.py | 28 ++++++++++++----
tests/system_tests_tcp_adaptor.py | 67 +++++++++++++++++++++++++++++----------
3 files changed, 74 insertions(+), 22 deletions(-)
diff --git a/tests/TCP_echo_client.py b/tests/TCP_echo_client.py
index ae5364c..8465ad5 100755
--- a/tests/TCP_echo_client.py
+++ b/tests/TCP_echo_client.py
@@ -94,6 +94,7 @@ class TcpEchoClient():
self._thread.start()
def run(self):
+ self.logger.log("%s Client is starting up" % (self.prefix))
try:
start_time = time.time()
self.is_running = True
diff --git a/tests/TCP_echo_server.py b/tests/TCP_echo_server.py
index 34f72bb..d8a23d4 100755
--- a/tests/TCP_echo_server.py
+++ b/tests/TCP_echo_server.py
@@ -123,11 +123,19 @@ class TcpEchoServer():
total_echoed = 0
# set up listening socket
- self.sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
- self.sock.bind((self.HOST, self.port))
- self.sock.listen()
- self.sock.setblocking(False)
- self.logger.log('%s Listening on host:%s, port:%d' % (self.prefix, self.HOST, self.port))
+ try:
+ self.sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
+ self.sock.bind((self.HOST, self.port))
+ self.sock.listen()
+ self.sock.setblocking(False)
+ self.logger.log('%s Listening on host:%s, port:%d' % (self.prefix, self.HOST, self.port))
+ except Exception as exc:
+ self.error = ('%s Opening listen socket %s:%d exception: %s' %
+ (self.prefix, self.HOST, self.port, traceback.format_exc()))
+ logger.log(self.error)
+ sel.unregister(sock)
+ sock.close()
+ return 1
# set up selector
sel = selectors.DefaultSelector()
@@ -183,10 +191,18 @@ class TcpEchoServer():
try:
recv_data = sock.recv(1024)
except ConnectionResetError as exc:
- logger.log('%s Connection to %s:%d closed by peer' % (self.prefix, data.addr[0], data.addr[1]))
+ logger.log('%s Connection to %s:%d closed by peer' %
+ (self.prefix, data.addr[0], data.addr[1]))
sel.unregister(sock)
sock.close()
return 0
+ except Exception as exc:
+ self.error = ('%s Connection to %s:%d exception: %s' %
+ (self.prefix, data.addr[0], data.addr[1], traceback.format_exc()))
+ logger.log(self.error)
+ sel.unregister(sock)
+ sock.close()
+ return 1
if recv_data:
data.outb += recv_data
logger.log('%s read from: %s:%d len:%d: %s' % (self.prefix, data.addr[0], data.addr[1], len(recv_data),
diff --git a/tests/system_tests_tcp_adaptor.py b/tests/system_tests_tcp_adaptor.py
index c2df88d..e290cec 100644
--- a/tests/system_tests_tcp_adaptor.py
+++ b/tests/system_tests_tcp_adaptor.py
@@ -23,8 +23,8 @@ from __future__ import absolute_import
from __future__ import print_function
import os
+import time
import traceback
-from time import sleep
from threading import Event
from threading import Timer
@@ -48,6 +48,8 @@ class TcpAdaptorOneRouterEcho(TestCase, Process):
tcp_client_listener_port = None
tcp_server_listener_port = None
+ echo_timeout = 30 # local timeout to wait for one echo client to finish
+
@classmethod
def setUpClass(cls):
"""Start a router"""
@@ -81,14 +83,22 @@ class TcpAdaptorOneRouterEcho(TestCase, Process):
router('A', 'interior', cls.amqp_listener_port, cls.tcp_client_listener_port,
cls.tcp_server_listener_port, "some_address", "best_site")
- cls.logger = Logger(title="TcpAdaptorOneRouterEcho-testClass", print_to_console=True)
+ cls.logger = Logger(title="TcpAdaptorOneRouterEcho-testClass",
+ print_to_console=True,
+ save_for_dump=False)
+ cls.logger.log(" amqp_listener_port : %d" % cls.amqp_listener_port)
+ cls.logger.log(" tcp_client_listener_port : %d" % cls.tcp_client_listener_port)
+ cls.logger.log(" tcp_server_listener_port : %d" % cls.tcp_server_listener_port)
- def do_test_echo(self, test_name, logger, host, port, size, count):
+ def do_test_echo(self, test_name, logger, host, port, size, count, print_client_logs):
# Run echo client. Return true if it works.
name = "%s_%s_%s_%s" % (test_name, port, size, count)
client_prefix = "ECHO_CLIENT %s" % name
- client_logger = Logger(title=client_prefix, print_to_console=False, save_for_dump=True)
+ client_logger = Logger(title=client_prefix,
+ print_to_console=print_client_logs,
+ save_for_dump=False)
result = True # assume it works
+ start_time = time.time()
try:
# start client
client = TcpEchoClient(prefix=client_prefix,
@@ -103,7 +113,13 @@ class TcpAdaptorOneRouterEcho(TestCase, Process):
# wait for client to finish
keep_waiting = True
while keep_waiting:
- sleep(0.1)
+ time.sleep(0.1)
+ elapsed = time.time() - start_time
+ if elapsed > self.echo_timeout:
+ client.error = "TIMEOUT - local wait time exceeded"
+ logger.log("%s %s" % (name, client.error))
+ keep_waiting = False
+ result = False
if client.error is not None:
logger.log("%s Client stopped with error: %s" % (name, client.error))
keep_waiting = False
@@ -121,10 +137,12 @@ class TcpAdaptorOneRouterEcho(TestCase, Process):
(name, traceback.format_exc()))
result = False
+ # wait for client to exit
+ client.wait()
+
if not result:
- # On failure, dump the client log through the test log. Compound logs here we go
- for line in client_logger.logs:
- logger.log("Failed client log: %s" % line)
+ pass
+
return result
def test_01_tcp_echo_one_router(self):
@@ -133,10 +151,16 @@ class TcpAdaptorOneRouterEcho(TestCase, Process):
Run many echo clients.
:return:
"""
+ # define logging
+ print_logs_server = True
+ print_logs_client = True
+
# start echo server
test_name = "test_01_tcp_echo_one_router"
server_prefix = "ECHO_SERVER %s" % test_name
- server_logger = Logger(title=test_name, print_to_console=False, save_for_dump=True)
+ server_logger = Logger(title=test_name,
+ print_to_console=print_logs_server,
+ save_for_dump=False)
server = TcpEchoServer(prefix=server_prefix,
port=self.tcp_server_listener_port,
timeout=TIMEOUT,
@@ -145,13 +169,23 @@ class TcpAdaptorOneRouterEcho(TestCase, Process):
# run series of clients to test
result = True
- for size in [1]:
- for count in [1]:
- test_info = "Starting echo client %s host:localhost, port:%d, size:%d, count:%d" % \
- (test_name, self.tcp_client_listener_port, size, count)
- self.logger.log(test_info)
- result = self.do_test_echo(test_name, self.logger, "localhost",
- self.tcp_client_listener_port, size, count)
+ for size in [1, 50, 1000]:
+ for count in [1, 10]:
+ # make sure server is still running
+ if server.error is not None:
+ logger.log("%s Server stopped with error: %s" % (name, server.error))
+ result = False
+ if server.exit_status is not None:
+ logger.log("%s Server stopped with status: %s" % (name, server.exit_status))
+ result = False
+ # run another test client
+ if result:
+ test_info = "Starting echo client %s host:localhost, port:%d, size:%d, count:%d" % \
+ (test_name, self.tcp_client_listener_port, size, count)
+ self.logger.log(test_info)
+ result = self.do_test_echo(test_name, self.logger, "localhost",
+ self.tcp_client_listener_port, size, count,
+ print_logs_client)
if not result:
break
if not result:
@@ -159,6 +193,7 @@ class TcpAdaptorOneRouterEcho(TestCase, Process):
# stop echo server
server.wait()
assert result, "Test case failed %s" % test_info
+ self.logger.log("Test test_01_tcp_echo_one_router: SUCCESS")
if __name__== '__main__':
unittest.main(main_module())
---------------------------------------------------------------------
To unsubscribe, e-mail: commits-unsubscribe@qpid.apache.org
For additional commands, e-mail: commits-help@qpid.apache.org