diff --git a/core/monitoring/monitoring.py b/core/monitoring/monitoring.py index 7ae6e29b..7e7e7c0a 100644 --- a/core/monitoring/monitoring.py +++ b/core/monitoring/monitoring.py @@ -274,6 +274,11 @@ def sampling_save_time(self, app_name, value): monitoring_msg = f"{app_name}_save_time" monitoring.got_histogram_observe(_filter_monitoring_msg(monitoring_msg), value) + @silence_it + def sampling_total_time(self, app_name, value): + monitoring_msg = f"{app_name}_total_time" + monitoring.got_histogram_observe(_filter_monitoring_msg(monitoring_msg), value) + @silence_it def sampling_mq_waiting_time(self, app_name, value): monitoring_msg = f"{app_name}_mq_waiting_time" diff --git a/smart_kit/start_points/main_loop_async_http.py b/smart_kit/start_points/main_loop_async_http.py index dfb9cc79..b0c22b65 100644 --- a/smart_kit/start_points/main_loop_async_http.py +++ b/smart_kit/start_points/main_loop_async_http.py @@ -146,24 +146,29 @@ async def process_message(self, message: SmartAppFromMessage, *args, **kwargs): params={log_const.KEY_NAME: "incoming_policy_message", "masked_message": message.masked_value}) db_uid = message.db_uid - with StatsTimer() as load_timer: - user = await self.load_user(db_uid, message) - monitoring.sampling_load_time(self.app_name, load_timer.secs) - stats += f"Loading time: {load_timer.msecs} msecs\n" - with StatsTimer() as script_timer: - commands = await self.model.answer(message, user) - if commands: - answer = self._generate_answers(user, commands, message) - else: - answer = None - - stats += f"Script time: {script_timer.msecs} msecs\n" - with StatsTimer() as save_timer: - await self.save_user(db_uid, user, message) - monitoring.sampling_save_time(self.app_name, save_timer.secs) - stats += f"Saving time: {save_timer.msecs} msecs\n" + with StatsTimer() as total_timer: + with StatsTimer() as load_timer: + user = await self.load_user(db_uid, message) + monitoring.sampling_load_time(self.app_name, load_timer.secs) + stats += f"Loading time: {load_timer.msecs} msecs\n" + with StatsTimer() as script_timer: + commands = await self.model.answer(message, user) + if commands: + answer = self._generate_answers(user, commands, message) + else: + answer = None + + monitoring.sampling_script_time(self.app_name, script_timer.secs) + stats += f"Script time: {script_timer.msecs} msecs\n" + with StatsTimer() as save_timer: + await self.save_user(db_uid, user, message) + monitoring.sampling_save_time(self.app_name, save_timer.secs) + stats += f"Saving time: {save_timer.msecs} msecs\n" + await self.postprocessor.postprocess(user, message) + + monitoring.sampling_total_time(self.app_name, total_timer.secs) + stats += f"Total time: {total_timer.msecs} msecs\n" log(stats, params={log_const.KEY_NAME: "timings"}) - await self.postprocessor.postprocess(user, message) return answer, stats, user async def get_health_check(self, request: aiohttp.web.Request):