From 843ba589b4b03e392f0f18bba38a4e231e871a72 Mon Sep 17 00:00:00 2001 From: Giuseppe Lo Presti Date: Tue, 22 Mar 2016 18:30:01 +0100 Subject: [PATCH 1/2] Added/improved many log messages to trace sockets usage and fixed two socket leaks --- rpyc/utils/server.py | 18 +++++++++++++----- 1 file changed, 13 insertions(+), 5 deletions(-) diff --git a/rpyc/utils/server.py b/rpyc/utils/server.py index cc17bec1..23cb0405 100644 --- a/rpyc/utils/server.py +++ b/rpyc/utils/server.py @@ -141,7 +141,7 @@ def accept(self): return sock.setblocking(True) - self.logger.info("accepted %s:%s", addrinfo[0], addrinfo[1]) + self.logger.info("accepted %s:%s with fd %d", addrinfo[0], addrinfo[1], sock.fileno()) self.clients.add(sock) self._accept_method(sock) @@ -356,6 +356,7 @@ def _drop_connection(self, fd): # the active connection has already been removed pass # close connection + self.logger.info("Closing connection for fd %d", fd) conn.close() def _add_inactive_connection(self, fd): @@ -392,7 +393,7 @@ def _poll_inactive_clients(self): except Exception: ex = sys.exc_info()[1] # "Caught exception in Worker thread" message - self.logger.warning("failed to poll clients, caught exception : %s", str(ex)) + self.logger.warning("Failed to poll clients, caught exception : %s", str(ex)) # wait a bit so that we do not loop too fast in case of error time.sleep(0.2) @@ -436,7 +437,7 @@ def _serve_clients(self): except Exception: ex = sys.exc_info()[1] # "Caught exception in Worker thread" message - self.logger.warning("failed to serve client, caught exception : %s", str(ex)) + self.logger.warning("Failed to serve client, caught exception : %s", str(ex)) # wait a bit so that we do not loop too fast in case of error time.sleep(0.2) @@ -450,7 +451,7 @@ def _authenticate_and_build_connection(self, sock): try: sock, credentials = self.authenticator(sock) except AuthenticationError: - self.logger.info("%s:%s failed to authenticate, rejecting connection", h, p) + self.logger.warning("%s:%s failed to authenticate, rejecting connection", h, p) return None else: credentials = None @@ -467,13 +468,20 @@ def _accept_method(self, sock): conn = self._authenticate_and_build_connection(sock) # put the connection in the active queue if conn: + h, p = sock.getpeername() fd = conn.fileno() + self.logger.debug("Created connection to %s:%d with fd %d", h, p, fd) self.fd_to_conn[fd] = conn self._add_inactive_connection(fd) self.clients.clear() + else: + self.logger.warning("Failed to authenticate and build connection, closing %s:%d", h, p) + sock.close() except Exception: + h, p = sock.getpeername() ex = sys.exc_info()[1] - self.logger.warning("failed to serve client, caught exception : %s", str(ex)) + self.logger.warning("Failed to serve client for %s:%d, caught exception : %s", h, p, str(ex)) + sock.close() class ForkingServer(Server): From 12544f416b08c17bd681666df29cad31a2dffc7e Mon Sep 17 00:00:00 2001 From: Giuseppe Lo Presti Date: Thu, 31 Mar 2016 10:07:02 +0200 Subject: [PATCH 2/2] Fixed usage of system-level poll(). The bug in compat.py was unveiled after fixing bug #182 and observing spinning processes. After that, the poll() call in server.py became too slow (1s instead of 1ms), leading to timeouts. The new value allows for not spinning too fast yet reacting quickly to new incoming connections. --- rpyc/lib/compat.py | 5 ++++- rpyc/utils/server.py | 4 ++-- 2 files changed, 6 insertions(+), 3 deletions(-) diff --git a/rpyc/lib/compat.py b/rpyc/lib/compat.py index e5d55dfa..76a8dc16 100644 --- a/rpyc/lib/compat.py +++ b/rpyc/lib/compat.py @@ -92,7 +92,7 @@ def register(self, fd, mode): if "e" in mode: flags |= select_module.POLLERR if "h" in mode: - # POLLRDHUP is a linux only extension, not know to python, but nevertheless + # POLLRDHUP is a linux only extension, not known to python, but nevertheless # used and thus needed in the flags POLLRDHUP = 0x2000 flags |= select_module.POLLHUP | select_module.POLLNVAL | POLLRDHUP @@ -101,6 +101,9 @@ def register(self, fd, mode): def unregister(self, fd): self._poll.unregister(fd) def poll(self, timeout = None): + if timeout: + # the real poll takes milliseconds while we have seconds here + timeout = 1000*timeout events = self._poll.poll(timeout) processed = [] for fd, evt in events: diff --git a/rpyc/utils/server.py b/rpyc/utils/server.py index 23cb0405..47f0053d 100644 --- a/rpyc/utils/server.py +++ b/rpyc/utils/server.py @@ -385,9 +385,9 @@ def _poll_inactive_clients(self): Check whether inactive clients have become active''' while self.active: try: - # the actual poll, with a timeout of 1s so that we can exit in case + # the actual poll, with a timeout of 0.1s so that we can exit in case # we re not active anymore - active_clients = self.poll_object.poll(1) + active_clients = self.poll_object.poll(0.1) # for each client that became active, put them in the active queue self._handle_poll_result(active_clients) except Exception: