Another logging tweaks

This commit is contained in:
Artem30801
2019-04-19 11:26:35 +03:00
parent f35d25a7b4
commit 09649c96db
3 changed files with 38 additions and 37 deletions

View File

@@ -21,11 +21,12 @@ logging.basicConfig( # TODO all prints as logs
level=logging.DEBUG, # INFO
format="%(asctime)s [%(name)-7.7s] [%(threadName)-12.12s] [%(levelname)-5.5s] %(message)s",
handlers=[
logging.NullHandler()
#logging.FileHandler("client_logs.log"),
#logging.StreamHandler(),
logging.FileHandler("client_logs.log"),
logging.StreamHandler(),
])
logger = logging.getLogger(__name__)
ConfigOption = collections.namedtuple("ConfigOption", ["section", "option", "value"])
active_client = None # maybe needs to be refactored
@@ -110,33 +111,33 @@ class Client(object):
self._process_connections()
except (KeyboardInterrupt, InterruptedError):
logging.critical("Caught interrupt, exiting!")
logger.critical("Caught interrupt, exiting!")
self.selector.close()
def _reconnect(self, timeout=2, attempt_limit=5):
logging.info("Trying to connect to {}:{} ...".format(self.server_host, self.server_port))
logger.info("Trying to connect to {}:{} ...".format(self.server_host, self.server_port))
attempt_count = 0
while not self.connected:
logging.info("Waiting for connection, attempt {}".format(attempt_count))
logger.info("Waiting for connection, attempt {}".format(attempt_count))
try:
self.client_socket = socket.socket()
self.client_socket.settimeout(timeout)
self.client_socket.connect((self.server_host, self.server_port))
except socket.error as error:
if error.errno != errno.EINTR:
logging.warning("Can not connect due error: {}".format(error))
logger.warning("Can not connect due error: {}".format(error))
attempt_count += 1
time.sleep(timeout)
else:
logging.critical("Shutting down on keyboard interrupt")
logger.critical("Shutting down on keyboard interrupt")
raise KeyboardInterrupt
else:
logging.info("Connection to server successful!")
logger.info("Connection to server successful!")
self._connect()
break
if attempt_count >= attempt_limit:
logging.info("Too many attempts. Trying to get new server IP")
logger.info("Too many attempts. Trying to get new server IP")
self.broadcast_bind()
attempt_count = 0
@@ -161,7 +162,7 @@ class Client(object):
message.income_raw = data
message.process_message()
if message.content:
logging.info("Received broadcast message {} from {}".format(message.content, addr))
logger.info("Received broadcast message {} from {}".format(message.content, addr))
if message.content["command"] == "server_ip":
args = message.content["args"]
self.server_port = int(args["port"])
@@ -169,7 +170,7 @@ class Client(object):
self.write_config(False,
ConfigOption("SERVER", "port", self.server_port),
ConfigOption("SERVER", "host", self.server_host))
logging.info("Binding to new IP: {}:{}".format(self.server_host, self.server_port))
logger.info("Binding to new IP: {}:{}".format(self.server_host, self.server_port))
break
finally:
broadcast_client.close()
@@ -186,7 +187,7 @@ class Client(object):
try:
connection.process_events(mask)
except Exception as error:
logging.error(
logger.error(
"Exception {} occurred for {}! Resetting connection!".format(error, connection.addr)
)
self.server_connection.close()
@@ -194,7 +195,7 @@ class Client(object):
break
if not self.selector.get_map():
logging.warning("No active connections left!")
logger.warning("No active connections left!")
return
@@ -209,7 +210,7 @@ def _response_time():
@messaging.message_callback("config_write")
def _command_config_write(*args, **kwargs):
options = [ConfigOption(**raw_option) for raw_option in kwargs["options"]]
logging.info("Writing config options: {}".format(options))
logger.info("Writing config options: {}".format(options))
active_client.write_config(kwargs["reload"], *options)
if __name__ == "__main__":

View File

@@ -11,7 +11,6 @@ import play_animation
import ros_logging
class CopterClient(client.Client):
def load_config(self):
super(CopterClient, self).load_config()
@@ -74,7 +73,7 @@ def _command_takeoff(*args, **kwargs):
if __name__ == "__main__":
ros_logging.route_logger_to_ros(messaging.__name__)
rospy.init_node('Swarm_client', anonymous=True)
ros_logging.route_logger_to_ros()
copter_client = CopterClient()
copter_client.start()

View File

@@ -15,6 +15,7 @@ except ImportError:
PendingRequest = collections.namedtuple("PendingRequest", ["value", "requested_value", # "expires_on",
"callback", "callback_args", "callback_kwargs",
])
logger = logging.getLogger(__name__)
class MessageManager:
@@ -133,7 +134,7 @@ class MessageManager:
def message_callback(string_command):
def inner(f):
ConnectionManager.messages_callbacks[string_command] = f
logging.debug("Registered message function {} for {}".format(f, string_command))
logger.debug("Registered message function {} for {}".format(f, string_command))
def wrapper(*args, **kwargs):
return f(*args, **kwargs)
@@ -146,7 +147,7 @@ def message_callback(string_command):
def request_callback(string_command):
def inner(f):
ConnectionManager.requests_callbacks[string_command] = f
logging.debug("Registered callback function {} for {}".format(f, string_command))
logger.debug("Registered callback function {} for {}".format(f, string_command))
def wrapper(*args, **kwargs):
return f(*args, **kwargs)
@@ -202,13 +203,13 @@ class ConnectionManager(object):
self._set_selector_events_mask('rw')
def close(self):
logging.info("Closing connection to {}".format(self.addr))
logger.info("Closing connection to {}".format(self.addr))
try:
self.selector.unregister(self.socket)
except AttributeError:
pass
except Exception as error:
logging.error("{}: Error during selector unregistering: {}".format(self.addr, error))
logger.error("{}: Error during selector unregistering: {}".format(self.addr, error))
finally:
self.selector = None
@@ -217,7 +218,7 @@ class ConnectionManager(object):
except AttributeError:
pass
except OSError as error:
logging.error("{}: Error during socket closing: {}".format(self.addr, error))
logger.error("{}: Error during socket closing: {}".format(self.addr, error))
finally:
self.socket = None
@@ -255,9 +256,9 @@ class ConnectionManager(object):
else:
if data:
self._recv_buffer += data
logging.debug("Received {} from {}".format(data, self.addr))
logger.debug("Received {} from {}".format(data, self.addr))
else:
logging.warning("Connection to {} lost!".format(self.addr))
logger.warning("Connection to {} lost!".format(self.addr))
if not self.resume_queue:
self._recv_buffer = b''
@@ -265,7 +266,7 @@ class ConnectionManager(object):
def process_received(self, income_message):
message_type = income_message.jsonheader["message-type"]
logging.debug("Received message! Header: {}, content: {}".format(
logger.debug("Received message! Header: {}, content: {}".format(
income_message.jsonheader, income_message.content))
if message_type == "message":
@@ -283,9 +284,9 @@ class ConnectionManager(object):
try:
self.messages_callbacks[command](**args)
except KeyError:
logging.warning("Command {} does not exist!".format(command))
logger.warning("Command {} does not exist!".format(command))
except Exception as error:
logging.error("Error during command {} execution: {}".format(command, error))
logger.error("Error during command {} execution: {}".format(command, error))
def _process_request(self, message):
command = message.content["requested_value"]
@@ -294,9 +295,9 @@ class ConnectionManager(object):
try:
value = self.requests_callbacks[command](**args)
except KeyError:
logging.warning("Request {} does not exist!".format(command))
logger.warning("Request {} does not exist!".format(command))
except Exception as error: # TODO send response error\cancel
logging.error("Error during command {} execution: {}".format(command, error))
logger.error("Error during command {} execution: {}".format(command, error))
else:
self._send_response(command, request_id, value)
@@ -310,7 +311,7 @@ class ConnectionManager(object):
print(request)
value = message.content["value"]
print(45)
logging.debug(
logger.debug(
"Request successfully closed with value {}".format(message.content["value"])
)
@@ -319,7 +320,7 @@ class ConnectionManager(object):
break
else:
logging.warning("Unexpected response!")
logger.warning("Unexpected response!")
def _process_filetransfer(self, message): # TODO path?
if message.jsonheader["content-type"] == "binary":
@@ -328,9 +329,9 @@ class ConnectionManager(object):
with open(filepath, 'wb') as f:
f.write(message.content)
except OSError as error:
logging.error("File {} can not be written due error: {}".format(filepath, error))
logger.error("File {} can not be written due error: {}".format(filepath, error))
else:
logging.info("File {} successfully received ".format(filepath))
logger.info("File {} successfully received ".format(filepath))
def write(self):
with self._send_lock:
@@ -347,7 +348,7 @@ class ConnectionManager(object):
# Resource temporarily unavailable (errno EWOULDBLOCK)
pass
except Exception as error:
logging.warning("Attempt to send message {} to {} failed due error: {}".format(
logger.warning("Attempt to send message {} to {} failed due error: {}".format(
self._send_buffer, self.addr, error))
if not self.resume_queue:
@@ -355,7 +356,7 @@ class ConnectionManager(object):
raise error
else:
logging.debug("Sent {} to {}".format(self._send_buffer[:sent], self.addr))
logger.debug("Sent {} to {}".format(self._send_buffer[:sent], self.addr))
self._send_buffer = self._send_buffer[sent:]
def _send(self, data):
@@ -392,9 +393,9 @@ class ConnectionManager(object):
with open(filepath, 'rb') as f:
data = f.read()
except OSError as error:
logging.warning("File can not be opened due error: ".format(error))
logger.warning("File can not be opened due error: ".format(error))
else:
logging.info("Sending file {} to {} (as: {})".format(filepath, self.addr, dest_filepath))
logger.info("Sending file {} to {} (as: {})".format(filepath, self.addr, dest_filepath))
self._send(MessageManager.create_message(
data, "binary", "filetransfer", "binary", {"filepath": dest_filepath}
))