From 9b39d7cd9bf88a17d4f1c9d75eeb464370c8206c Mon Sep 17 00:00:00 2001 From: Ruben van de Ven Date: Sat, 14 Oct 2023 13:47:07 +0200 Subject: [PATCH] Logging tweaks --- trap/plumber.py | 7 ++++++- trap/prediction_server.py | 4 ++-- trap/tracker.py | 18 ++++++------------ 3 files changed, 14 insertions(+), 15 deletions(-) diff --git a/trap/plumber.py b/trap/plumber.py index f9e2204..c0253b6 100644 --- a/trap/plumber.py +++ b/trap/plumber.py @@ -13,13 +13,18 @@ logger = logging.getLogger("trap.plumbing") def start(): args = parser.parse_args() loglevel = logging.NOTSET if args.verbose > 1 else logging.DEBUG if args.verbose > 0 else logging.INFO + logging.basicConfig( level=loglevel, ) + # set per handler, so we can set it lower for the root logger if remote logging is enabled + root_logger = logging.getLogger() + [h.setLevel(loglevel) for h in root_logger.handlers] + + if args.remote_log_addr: logging.captureWarnings(True) - root_logger = logging.getLogger() root_logger.setLevel(logging.NOTSET) # to send all records to cutelog socket_handler = SocketHandler(args.remote_log_addr, args.remote_log_port) root_logger.addHandler(socket_handler) diff --git a/trap/prediction_server.py b/trap/prediction_server.py index 4e35c30..4144739 100644 --- a/trap/prediction_server.py +++ b/trap/prediction_server.py @@ -301,7 +301,7 @@ class InferenceServer: robot_present_and_future=robot_present_and_future, full_dist=True) end = time.time() - logger.info("t=%d: took %.2f s (= %.2f Hz) w/ %d nodes and %d edges" % (timestep, end - start, + logger.debug("took %.2f s (= %.2f Hz) w/ %d nodes and %d edges" % (end - start, 1. / (end - start), len(trajectron.nodes), trajectron.scene_graph.get_num_edges())) @@ -348,7 +348,7 @@ class InferenceServer: } data = json.dumps(response) - logger.info(f"Frame delay = {time.time()-frame.time}s") + logger.info(f"Total frame delay = {time.time()-frame.time}s ({len(trajectron.nodes)} nodes & {trajectron.scene_graph.get_num_edges()} edges. Trajectron: {end - start}s)") self.prediction_socket.send_string(data) diff --git a/trap/tracker.py b/trap/tracker.py index a05eaa1..dca8336 100644 --- a/trap/tracker.py +++ b/trap/tracker.py @@ -56,16 +56,9 @@ class Tracker: def track(self): while True: msg = self.frame_sock.recv() - # after block, exhaust the queue: (superfluous now that CONFLATE is before the connect) - # i = 1 - # while True: - # try: - # msg = self.frame_sock.recv(zmq.NOBLOCK) - # i+=1 - # except Exception as e: - # break - frame: Frame = pickle.loads(msg) - logger.info(f"Frame delivery delay = {time.time()-frame.time}s") + frame: Frame = pickle.loads(msg) # frame delivery in current setup: 0.012-0.03s + # logger.info(f"Frame delivery delay = {time.time()-frame.time}s") + start_time = time.time() detections = self.detect_persons(frame.img) tracks: [Track] = self.mot_tracker.update_tracks(detections, frame=frame.img) @@ -84,10 +77,11 @@ class Tracker: "id": tid, "history": [{"x":c[0], "y":c[1]} for c in coords] # already doubles nested, fine for test } - logger.debug(f"{trajectories}") + # logger.debug(f"{trajectories}") frame.trajectories = trajectories - logger.info(f"trajectory delay = {time.time()-frame.time}s") + current_time = time.time() + logger.debug(f"Trajectories: {len(trajectories)}. Current frame delay = {current_time-frame.time}s (trajectories: {current_time - start_time}s)") self.trajectory_socket.send(pickle.dumps(frame)) # self.trajectory_socket.send_string(json.dumps(trajectories)) # provide a {ID: {id: ID, history: [[x,y],[x,y],...]}}