def iterate_behavior_timeouts(self): now = time.time() while now > (self.behaviors_timeouts.get_head_key() or float("inf")): _, behavior_timeout_value = self.behaviors_timeouts.pop() db_uid, callback_id, mq_message, kafka_key = behavior_timeout_value try: save_tries = 0 user_save_no_collisions = False user = None while save_tries < self.user_save_collisions_tries and not user_save_no_collisions: save_tries += 1 orig_message_raw = json.loads(mq_message.value()) orig_message_raw[ SmartAppFromMessage. MESSAGE_NAME] = message_names.LOCAL_TIMEOUT timeout_from_message = self._get_timeout_from_message( orig_message_raw, callback_id, headers=mq_message.headers()) user = self.load_user(db_uid, timeout_from_message) commands = self.model.answer(timeout_from_message, user) topic_key = self._get_topic_key(mq_message) answers = self._generate_answers( user=user, commands=commands, message=timeout_from_message, topic_key=topic_key, kafka_key=kafka_key) user_save_no_collisions = self.save_user( db_uid, user, mq_message) if user and not user_save_no_collisions: log("MainLoop.iterate_behavior_timeouts: save user got collision on uid %(uid)s db_version %(db_version)s.", user=user, params={ log_const.KEY_NAME: "ignite_collision", "db_uid": db_uid, "message_key": mq_message.key(), "kafka_key": kafka_key, "uid": user.id, "db_version": str(user.variables.get(user.USER_DB_VERSION)) }, level="WARNING") continue if not user_save_no_collisions: log("MainLoop.iterate_behavior_timeouts: db_save collision all tries left on uid %(uid)s db_version %(db_version)s.", user=user, params={ log_const.KEY_NAME: "ignite_collision", "db_uid": db_uid, "message_key": mq_message.key(), "message_partition": mq_message.partition(), "kafka_key": kafka_key, "uid": user.id, "db_version": str(user.variables.get(user.USER_DB_VERSION)) }, level="WARNING") smart_kit_metrics.counter_save_collision_tries_left( self.app_name) self.save_behavior_timeouts(user, mq_message, kafka_key) for answer in answers: self._send_request(user, answer, mq_message) except: log("%(class_name)s error.", params={ log_const.KEY_NAME: "error_handling_timeout", "class_name": self.__class__.__name__, log_const.REQUEST_VALUE: str(mq_message.value()) }, level="ERROR", exc_info=True)
def iterate(self, kafka_key): consumer = self.consumers[kafka_key] mq_message = None message_value = None try: mq_message = None message_value = None stats = "" with StatsTimer() as poll_timer: mq_message = consumer.poll() if mq_message: stats += "Polling time: {} msecs\n".format(poll_timer.msecs) topic_key = self._get_topic_key(mq_message) save_tries = 0 user_save_no_collisions = False user = None db_uid = None while save_tries < self.user_save_collisions_tries and not user_save_no_collisions: save_tries += 1 message_value = mq_message.value() message = SmartAppFromMessage( message_value, headers=mq_message.headers(), masking_fields=self.masking_fields) # TODO вернуть проверку ключа!!! if message.validate( ): # and self.check_message_key(message, mq_message.key()): log("INCOMING FROM TOPIC: %(topic)s partition %(message_partition)s HEADERS: %(headers)s DATA: %(incoming_data)s", params={ log_const.KEY_NAME: "incoming_message", "topic": mq_message.topic(), "message_partition": mq_message.partition(), "message_key": mq_message.key(), "kafka_key": kafka_key, "incoming_data": str(message.masked_value), "headers": str(mq_message.headers()), MESSAGE_ID_STR: message.incremental_id }) db_uid = message.db_uid span = jaeger_utils.get_incoming_spam( self.tracer, message, mq_message) with self.tracer.scope_manager.activate(span, True) as scope: with StatsTimer() as load_timer: user = self.load_user(db_uid, message) with self.tracer.scope_manager.activate(span, True) as scope: with self.tracer.start_span( 'Loading time', child_of=scope.span) as span: smart_kit_metrics.sampling_load_time( self.app_name, load_timer.secs) stats += "Loading time: {} msecs\n".format( load_timer.msecs) with StatsTimer() as script_timer: commands = self.model.answer(message, user) with self.tracer.start_span( 'Script time', child_of=scope.span) as span: answers = self._generate_answers( user=user, commands=commands, message=message, topic_key=topic_key, kafka_key=kafka_key) smart_kit_metrics.sampling_script_time( self.app_name, script_timer.secs) stats += "Script time: {} msecs\n".format( script_timer.msecs) with self.tracer.start_span( 'Saving time', child_of=scope.span) as span: with StatsTimer() as save_timer: user_save_no_collisions = self.save_user( db_uid, user, message) smart_kit_metrics.sampling_save_time( self.app_name, save_timer.secs) stats += "Saving time: {} msecs\n".format( save_timer.msecs) if not user_save_no_collisions: log("MainLoop.iterate: save user got collision on uid %(uid)s db_version %(db_version)s.", user=user, params={ log_const.KEY_NAME: "ignite_collision", "db_uid": db_uid, "message_key": mq_message.key(), "message_partition": mq_message.partition(), "kafka_key": kafka_key, "uid": user.id, "db_version": str( user.variables.get( user.USER_DB_VERSION)) }, level="WARNING") continue self.save_behavior_timeouts( user, mq_message, kafka_key) if mq_message.headers() is None: mq_message.set_headers([]) self.tracer.inject(span_context=span.context, format=jaeger_kafka_codec.KAFKA_MAP, carrier=mq_message.headers()) if answers: for answer in answers: with StatsTimer() as publish_timer: self._send_request(user, answer, mq_message) stats += "Publishing time: {} msecs".format( publish_timer.msecs) log(stats) else: try: data = message.masked_value except: data = "<DATA FORMAT ERROR>" log(f"Message validation failed, skip message handling.", params={ log_const.KEY_NAME: "invalid_message", "data": data }, level="ERROR") smart_kit_metrics.counter_invalid_message( self.app_name) if user and not user_save_no_collisions: log("MainLoop.iterate: db_save collision all tries left on uid %(uid)s db_version %(db_version)s.", user=user, params={ log_const.KEY_NAME: "ignite_collision", "db_uid": db_uid, "message_key": mq_message.key(), "message_partition": mq_message.partition(), "kafka_key": kafka_key, "uid": user.id, "db_version": str(user.variables.get(user.USER_DB_VERSION)) }, level="WARNING") smart_kit_metrics.counter_save_collision_tries_left( self.app_name) consumer.commit_offset(mq_message) except KafkaException as kafka_exp: log("kafka error: %(kafka_exp)s. MESSAGE: {}.".format( message_value), params={ log_const.KEY_NAME: log_const.STARTUP_VALUE, "kafka_exp": str(kafka_exp), log_const.REQUEST_VALUE: str(message_value) }, level="ERROR", exc_info=True) except Exception: try: log("%(class_name)s iterate error. Kafka key %(kafka_key)s MESSAGE: {}." .format(message_value), params={ log_const.KEY_NAME: log_const.STARTUP_VALUE, "kafka_key": kafka_key }, level="ERROR", exc_info=True) consumer.commit_offset(mq_message) except Exception: log("Error handling worker fail exception.", level="ERROR", exc_info=True)
def process_message(self, mq_message, consumer, kafka_key, stats): topic_key = self._get_topic_key(mq_message, kafka_key) save_tries = 0 user_save_no_collisions = False user = None db_uid = None message = None while save_tries < self.user_save_collisions_tries and not user_save_no_collisions: save_tries += 1 message_value = mq_message.value() message = SmartAppFromMessage( message_value, headers=mq_message.headers(), masking_fields=self.masking_fields, creation_time=consumer.get_msg_create_time(mq_message)) # TODO вернуть проверку ключа!!! if message.validate(): waiting_message_time = 0 if message.creation_time: waiting_message_time = time.time( ) * 1000 - message.creation_time stats += "Waiting message: {} msecs\n".format( waiting_message_time) stats += "Mid: {}\n".format(message.incremental_id) smart_kit_metrics.sampling_mq_waiting_time( self.app_name, waiting_message_time / 1000) self.check_message_key(message, mq_message.key(), user) log("INCOMING FROM TOPIC: %(topic)s partition %(message_partition)s HEADERS: %(headers)s DATA: %(incoming_data)s", params={ log_const.KEY_NAME: "incoming_message", "topic": mq_message.topic(), "message_partition": mq_message.partition(), "message_key": mq_message.key(), "message_id": message.incremental_id, "kafka_key": kafka_key, "incoming_data": str(message.masked_value), "length": len(message.value), "headers": str(mq_message.headers()), "waiting_message": waiting_message_time, "surface": message.device.surface, MESSAGE_ID_STR: message.incremental_id }, user=user) db_uid = message.db_uid with StatsTimer() as load_timer: user = self.load_user(db_uid, message) smart_kit_metrics.sampling_load_time(self.app_name, load_timer.secs) stats += "Loading time: {} msecs\n".format(load_timer.msecs) with StatsTimer() as script_timer: commands = self.model.answer(message, user) answers = self._generate_answers(user=user, commands=commands, message=message, topic_key=topic_key, kafka_key=kafka_key) smart_kit_metrics.sampling_script_time(self.app_name, script_timer.secs) stats += "Script time: {} msecs\n".format(script_timer.msecs) with StatsTimer() as save_timer: user_save_no_collisions = self.save_user( db_uid, user, message) smart_kit_metrics.sampling_save_time(self.app_name, save_timer.secs) stats += "Saving time: {} msecs\n".format(save_timer.msecs) if not user_save_no_collisions: log("MainLoop.iterate: save user got collision on uid %(uid)s db_version %(db_version)s.", user=user, params={ log_const.KEY_NAME: "ignite_collision", "db_uid": db_uid, "message_key": mq_message.key(), "message_partition": mq_message.partition(), "kafka_key": kafka_key, "uid": user.id, "db_version": str(user.variables.get(user.USER_DB_VERSION)) }, level="WARNING") continue self.save_behavior_timeouts(user, mq_message, kafka_key) if mq_message.headers() is None: mq_message.set_headers([]) if answers: for answer in answers: with StatsTimer() as publish_timer: self._send_request(user, answer, mq_message) stats += "Publishing time: {} msecs".format( publish_timer.msecs) log(stats, user=user) else: try: data = message.masked_value except: data = "<DATA FORMAT ERROR>" log(f"Message validation failed, skip message handling.", params={ log_const.KEY_NAME: "invalid_message", "data": data }, level="ERROR") smart_kit_metrics.counter_invalid_message(self.app_name) if user and not user_save_no_collisions: log("MainLoop.iterate: db_save collision all tries left on uid %(uid)s db_version %(db_version)s.", user=user, params={ log_const.KEY_NAME: "ignite_collision", "db_uid": db_uid, "message_key": mq_message.key(), "message_partition": mq_message.partition(), "kafka_key": kafka_key, "uid": user.id, "db_version": str(user.variables.get(user.USER_DB_VERSION)) }, level="WARNING") self.postprocessor.postprocess(user, message) smart_kit_metrics.counter_save_collision_tries_left(self.app_name) consumer.commit_offset(mq_message)