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)