fix(sms): кампании больше не долбят один номер бесконечно (код 107 у сотен SMS)

Причина «кучи ошибок 107»: номер попытки читался из строки лога
(attempts = item.get("attempts", 1)), а каждая повторная отправка вставляла
НОВУЮ строку с attempts=1. Условие attempts < max_attempts выполнялось всегда,
поэтому группа уходила в повтор каждые 5 минут бесконечно: заказ ТП-010543
(9780187307) — 461 отправка за 3,5 суток, ни одна не доставлена, в ручную
работу заказ не ушёл.

- номер попытки считается по группе (count строк кампании) и пишется в строку
  и в order_groups.sms_attempts;
- в выборке на отправку жёсткий лимит попыток — повтор невозможен даже при
  сбое статуса;
- попытки исчерпаны → manual_required («нужен менеджер»), а не send_failed;
- новый шаг 4: группа с исчерпанными попытками, застрявшая в link_ready,
  сама уходит в manual_required (самолечение);
- то же исправление во второй кампании (second_sms) — там тот же баг.
This commit is contained in:
hermes 2026-09-21 17:28:46 +02:00
parent c58f2b0629
commit 2067ff7d89
2 changed files with 131 additions and 18 deletions

View File

@ -172,7 +172,7 @@ def send_telegram(message, chat_id):
# ─── State Machine ─────────────────────────────────────────────────────────── # ─── State Machine ───────────────────────────────────────────────────────────
def get_groups_to_send(conn): def get_groups_to_send(conn, max_attempts):
"""Группы, которым ещё не отправили SMS. """Группы, которым ещё не отправили SMS.
Режимы (из sms_city_profiles): Режимы (из sms_city_profiles):
@ -183,7 +183,7 @@ def get_groups_to_send(conn):
cur.execute(""" cur.execute("""
SELECT og.id, og.group_key, og.customer_name, og.customer_phone, SELECT og.id, og.group_key, og.customer_name, og.customer_phone,
og.customer_phone_normalized, og.delivery_link, og.notification_status, og.customer_phone_normalized, og.delivery_link, og.notification_status,
og.delivery_type, og.town, og.delivery_type, og.town, og.sms_attempts,
-- Профиль города (fallback на дефолтные значения если нет записи) -- Профиль города (fallback на дефолтные значения если нет записи)
COALESCE(scp.delivery_mode, 'link') as delivery_mode, COALESCE(scp.delivery_mode, 'link') as delivery_mode,
COALESCE(scp.delivery_text, '') as delivery_text, COALESCE(scp.delivery_text, '') as delivery_text,
@ -228,8 +228,15 @@ def get_groups_to_send(conn):
AND scl.status IN ('sent', 'checking') AND scl.status IN ('sent', 'checking')
AND scl.created_at > NOW() - INTERVAL '2 hours' AND scl.created_at > NOW() - INTERVAL '2 hours'
) )
-- Лимит попыток: считаем ВСЕ строки кампании по группе, а не строку,
-- которую проверяем (иначе счётчик всегда 1 и повторы бесконечны)
AND (
SELECT count(*) FROM sms_campaign_log scl2
WHERE scl2.order_group_id = og.id
AND scl2.campaign_type = 'first_sms'
) < %s
ORDER BY og.created_at ASC ORDER BY og.created_at ASC
""") """, (max_attempts,))
return [dict(r) for r in cur.fetchall()] return [dict(r) for r in cur.fetchall()]
def get_sms_to_check(conn, max_duration_min): def get_sms_to_check(conn, max_duration_min):
@ -310,6 +317,22 @@ def update_order_group(conn, group_id, fields):
cur.execute(f"UPDATE order_groups SET {', '.join(set_parts)} WHERE id = %s", values) cur.execute(f"UPDATE order_groups SET {', '.join(set_parts)} WHERE id = %s", values)
conn.commit() conn.commit()
def count_sms_attempts(conn, group_id, campaign_type="first_sms"):
"""Сколько раз эту SMS уже пытались отправить (строк в логе этой кампании).
Номер попытки — свойство ГРУППЫ, а не строки лога: каждая попытка создаёт
новую строку, поэтому в самой строке всегда было бы attempts=1, условие
«attempts < max_attempts» выполнялось бы вечно и кампания слала бы SMS
каждые 5 минут бесконечно (проверено на заказе ТП-010543: 457 отправок за
3,5 суток, ни одна не доставлена, в ручную работу заказ не ушёл).
"""
with conn.cursor() as cur:
cur.execute("""
SELECT COUNT(*) FROM sms_campaign_log
WHERE order_group_id = %s AND campaign_type = %s
""", (group_id, campaign_type))
return cur.fetchone()[0]
# ─── Основная логика ───────────────────────────────────────────────────────── # ─── Основная логика ─────────────────────────────────────────────────────────
def step_send_new(conn, settings): def step_send_new(conn, settings):
@ -319,7 +342,7 @@ def step_send_new(conn, settings):
max_attempts = settings.get("max_attempts", 2) max_attempts = settings.get("max_attempts", 2)
second_sms_delay = settings.get("second_sms_delay_hours", 3) second_sms_delay = settings.get("second_sms_delay_hours", 3)
groups = get_groups_to_send(conn) groups = get_groups_to_send(conn, max_attempts)
log.info(f"Step 1: {len(groups)} groups to send SMS") log.info(f"Step 1: {len(groups)} groups to send SMS")
sent_count = 0 sent_count = 0
@ -363,6 +386,8 @@ def step_send_new(conn, settings):
log.info(f"TEST MODE: sending to {send_phone} instead of {phone}") log.info(f"TEST MODE: sending to {send_phone} instead of {phone}")
log.info(f"Sending SMS to {name} (orig={phone}, send={send_phone})") log.info(f"Sending SMS to {name} (orig={phone}, send={send_phone})")
attempt_no = count_sms_attempts(conn, group_id) + 1
log.info(f"Group {group_id}: attempt {attempt_no}/{max_attempts}")
sms_id, raw, code = send_sms(send_phone, sms_text, api_id) sms_id, raw, code = send_sms(send_phone, sms_text, api_id)
if sms_id: if sms_id:
@ -374,7 +399,7 @@ def step_send_new(conn, settings):
sms_text=sms_text, sms_text=sms_text,
status="sent", status="sent",
sms_code=code, sms_code=code,
attempts=1, attempts=attempt_no,
) )
# ДВОЙНАЯ ЗАЩИТА: сразу меняем notification_status # ДВОЙНАЯ ЗАЩИТА: сразу меняем notification_status
if sms_mode == "notification": if sms_mode == "notification":
@ -384,6 +409,7 @@ def step_send_new(conn, settings):
"sms_sent_at": "NOW()", "sms_sent_at": "NOW()",
"first_sms_sent_at": "NOW()", "first_sms_sent_at": "NOW()",
"status": "first_sms_sent", "status": "first_sms_sent",
"sms_attempts": attempt_no,
}) })
log.info(f"Group {group_id}: NOTIFICATION SMS sent, status→first_sms_sent (no second SMS)") log.info(f"Group {group_id}: NOTIFICATION SMS sent, status→first_sms_sent (no second SMS)")
else: else:
@ -391,6 +417,7 @@ def step_send_new(conn, settings):
update_order_group(conn, group_id, { update_order_group(conn, group_id, {
"notification_status": "sms_sending", "notification_status": "sms_sending",
"sms_sent_at": "NOW()", "sms_sent_at": "NOW()",
"sms_attempts": attempt_no,
}) })
log.info(f"Group {group_id}: LINK SMS sent, status→sms_sending") log.info(f"Group {group_id}: LINK SMS sent, status→sms_sending")
sent_count += 1 sent_count += 1
@ -404,7 +431,7 @@ def step_send_new(conn, settings):
sms_text=sms_text, sms_text=sms_text,
status="send_failed", status="send_failed",
sms_code=code, sms_code=code,
attempts=1, attempts=attempt_no,
error_message=error, error_message=error,
) )
log.error(f"Group {group_id}: SMS send failed (code={code}): {error[:200]}") log.error(f"Group {group_id}: SMS send failed (code={code}): {error[:200]}")
@ -412,6 +439,7 @@ def step_send_new(conn, settings):
update_order_group(conn, group_id, { update_order_group(conn, group_id, {
"notification_status": "send_failed", "notification_status": "send_failed",
"last_sms_error": error[:200], "last_sms_error": error[:200],
"sms_attempts": attempt_no,
}) })
send_telegram(f"❌ SMS не отправлена: {name} ({phone})\nКод: {code}\nОшибка: {error[:200]}", tg_chat) send_telegram(f"❌ SMS не отправлена: {name} ({phone})\nКод: {code}\nОшибка: {error[:200]}", tg_chat)
@ -435,7 +463,7 @@ def step_check_status(conn, settings):
group_id = str(item["order_group_id"]) group_id = str(item["order_group_id"])
name = item.get("customer_name") or item.get("group_key", "—") name = item.get("customer_name") or item.get("group_key", "—")
phone = item.get("customer_phone", "") phone = item.get("customer_phone", "")
attempts = item.get("attempts", 1) attempts = item.get("attempts") or 1
was_needs_check = item.get("needs_check", False) was_needs_check = item.get("needs_check", False)
code, raw, api_code = check_sms_status(sms_id, api_id) code, raw, api_code = check_sms_status(sms_id, api_id)
@ -481,9 +509,11 @@ def step_check_status(conn, settings):
}) })
else: else:
update_order_group(conn, group_id, { update_order_group(conn, group_id, {
"notification_status": "send_failed", "notification_status": "manual_required",
"last_sms_error": f"Delivery failed after {max_attempts} attempts (code={code})", "last_sms_error": f"SMS не доставлена после {max_attempts} попыток (код {code})",
}) })
log.error(f"Group {group_id}: attempts exhausted ({attempts}/{max_attempts}), "
f"notification_status→manual_required")
send_telegram(f"⚠️ SMS не доставлена после {max_attempts} попыток: {name} ({phone})\nКод: {code}", tg_chat) send_telegram(f"⚠️ SMS не доставлена после {max_attempts} попыток: {name} ({phone})\nКод: {code}", tg_chat)
elif code in LIMIT_ERROR_CODES: elif code in LIMIT_ERROR_CODES:
@ -519,7 +549,7 @@ def step_handle_expired(conn, settings):
group_id = str(item["order_group_id"]) group_id = str(item["order_group_id"])
name = item.get("customer_name") or item.get("group_key", "—") name = item.get("customer_name") or item.get("group_key", "—")
phone = item.get("customer_phone", "") phone = item.get("customer_phone", "")
attempts = item.get("attempts", 1) attempts = item.get("attempts") or 1
delivery_link = item.get("delivery_link", "") delivery_link = item.get("delivery_link", "")
log.warning(f"Group {group_id}: SMS expired after {max_duration} min, attempts={attempts}/{max_attempts}") log.warning(f"Group {group_id}: SMS expired after {max_duration} min, attempts={attempts}/{max_attempts}")
@ -544,6 +574,63 @@ def step_handle_expired(conn, settings):
tg_chat, tg_chat,
) )
def step_release_exhausted(conn, settings):
"""Шаг 4: группы, у которых попытки исчерпаны, а статус остался 'link_ready'.
Такое состояние возникает как следствие сбоя счётчика: группа выпадает из
выборки по лимиту попыток, но из очереди не уходит — висит в 'link_ready'
вечно, клиент не получает ссылку, в ручную работу заказ не переводится.
Шаг закрывает эту дыру: попытки кончились → «нужен менеджер».
"""
max_attempts = settings.get("max_attempts", 2)
tg_chat = settings.get("telegram_chat_id", TELEGRAM_CHAT_ID)
with conn.cursor(cursor_factory=RealDictCursor) as cur:
cur.execute("""
SELECT og.id, og.group_key, og.customer_name, og.customer_phone,
(SELECT count(*) FROM sms_campaign_log l
WHERE l.order_group_id = og.id
AND l.campaign_type = 'first_sms') AS attempts
FROM order_groups og
WHERE og.delivery_status = 'pending_confirmation'
AND COALESCE(og.notification_status, '') = 'link_ready'
AND (
SELECT count(*) FROM sms_campaign_log l
WHERE l.order_group_id = og.id
AND l.campaign_type = 'first_sms'
) >= %s
-- Активная отправка в работе — не мешаем ей
AND NOT EXISTS (
SELECT 1 FROM sms_campaign_log l2
WHERE l2.order_group_id = og.id
AND l2.campaign_type = 'first_sms'
AND l2.status IN ('sent', 'checking')
)
""", (max_attempts,))
groups = [dict(r) for r in cur.fetchall()]
for group in groups:
group_id = str(group["id"])
name = group.get("customer_name") or group.get("group_key", "—")
phone = group.get("customer_phone", "")
attempts = group.get("attempts") or max_attempts
log.warning(f"Group {group_id}: попыток {attempts}/{max_attempts}, статус остался link_ready "
f"→ manual_required (клиент SMS не получил)")
update_order_group(conn, group_id, {
"notification_status": "manual_required",
"last_sms_error": f"SMS не доставлена после {attempts} попыток — нужен менеджер",
})
send_telegram(
f"🔧 <b>Нужен менеджер</b>\n{name} ({phone})\n"
f"SMS не доставлена после {attempts} попыток — клиенту не ушла ссылка",
tg_chat,
)
if groups:
log.info(f"Step 4: {len(groups)} groups released from link_ready → manual_required")
return len(groups)
# ─── Main ──────────────────────────────────────────────────────────────────── # ─── Main ────────────────────────────────────────────────────────────────────
def main(): def main():
@ -565,8 +652,9 @@ def main():
sent = step_send_new(conn, settings) sent = step_send_new(conn, settings)
delivered = step_check_status(conn, settings) delivered = step_check_status(conn, settings)
step_handle_expired(conn, settings) step_handle_expired(conn, settings)
released = step_release_exhausted(conn, settings)
log.info(f"Run summary: sent={sent}, delivered={delivered}") log.info(f"Run summary: sent={sent}, delivered={delivered}, released_to_manual={released}")
if sent > 0 or delivered > 0: if sent > 0 or delivered > 0:
send_telegram( send_telegram(

View File

@ -207,7 +207,7 @@ def send_telegram(message, chat_id):
# ─── State Machine ─────────────────────────────────────────────────────────── # ─── State Machine ───────────────────────────────────────────────────────────
def get_groups_to_send(conn): def get_groups_to_send(conn, max_attempts):
"""Группы, где первая SMS доставлена, но клиент не согласовал, """Группы, где первая SMS доставлена, но клиент не согласовал,
и пришло время для второй SMS (next_notification_check_at <= NOW()). и пришло время для второй SMS (next_notification_check_at <= NOW()).
second_sms_sent_at IS NULL — вторая SMS ещё не отправлена. second_sms_sent_at IS NULL — вторая SMS ещё не отправлена.
@ -243,8 +243,15 @@ def get_groups_to_send(conn):
AND scl.status IN ('sent', 'checking') AND scl.status IN ('sent', 'checking')
AND scl.created_at > NOW() - INTERVAL '2 hours' AND scl.created_at > NOW() - INTERVAL '2 hours'
) )
-- Лимит попыток: считаем ВСЕ строки кампании по группе, а не строку,
-- которую проверяем (иначе счётчик всегда 1 и повторы бесконечны)
AND (
SELECT count(*) FROM sms_campaign_log scl2
WHERE scl2.order_group_id = og.id
AND scl2.campaign_type = 'second_sms'
) < %s
ORDER BY og.created_at ASC ORDER BY og.created_at ASC
""") """, (max_attempts,))
return [dict(r) for r in cur.fetchall()] return [dict(r) for r in cur.fetchall()]
def get_sms_to_check(conn, max_duration_min): def get_sms_to_check(conn, max_duration_min):
@ -327,6 +334,21 @@ def update_order_group(conn, group_id, fields):
# ─── Проверка рабочего времени ──────────────────────────────────────────────── # ─── Проверка рабочего времени ────────────────────────────────────────────────
def count_sms_attempts(conn, group_id, campaign_type=CAMPAIGN_TYPE):
"""Сколько раз эту SMS уже пытались отправить (строк в логе кампании).
Номер попытки — свойство ГРУППЫ, а не строки лога: каждая попытка создаёт
новую строку, поэтому в строке всегда было бы attempts=1, условие
«attempts < max_attempts» выполнялось бы вечно и вторая SMS уходила бы
каждые 5 минут бесконечно.
"""
with conn.cursor() as cur:
cur.execute("""
SELECT COUNT(*) FROM sms_campaign_log
WHERE order_group_id = %s AND campaign_type = %s
""", (group_id, campaign_type))
return cur.fetchone()[0]
def is_within_work_hours(settings): def is_within_work_hours(settings):
"""Проверка: сейчас рабочие часы. """Проверка: сейчас рабочие часы.
settings: work_hours_start, work_hours_end (часы 0-23), work_days ('1,2,3,4,5') settings: work_hours_start, work_hours_end (часы 0-23), work_days ('1,2,3,4,5')
@ -354,8 +376,9 @@ def step_send_new(conn, settings):
"""Шаг 1: Отправка второй SMS группам, где первая доставлена, но нет согласования""" """Шаг 1: Отправка второй SMS группам, где первая доставлена, но нет согласования"""
api_id = settings.get("sms_api_id", SMS_API_ID) api_id = settings.get("sms_api_id", SMS_API_ID)
tg_chat = settings.get("telegram_chat_id", TELEGRAM_CHAT_ID) tg_chat = settings.get("telegram_chat_id", TELEGRAM_CHAT_ID)
max_attempts = settings.get("max_attempts", 2)
groups = get_groups_to_send(conn) groups = get_groups_to_send(conn, max_attempts)
log.info(f"Step 1: {len(groups)} groups to send second SMS") log.info(f"Step 1: {len(groups)} groups to send second SMS")
sent_count = 0 sent_count = 0
@ -387,6 +410,8 @@ def step_send_new(conn, settings):
log.info(f"TEST MODE: sending to {send_phone} instead of {phone}") log.info(f"TEST MODE: sending to {send_phone} instead of {phone}")
log.info(f"Sending second SMS to {name} (orig={phone}, send={send_phone})") log.info(f"Sending second SMS to {name} (orig={phone}, send={send_phone})")
attempt_no = count_sms_attempts(conn, group_id) + 1
log.info(f"Group {group_id}: second SMS attempt {attempt_no}/{max_attempts}")
sms_id, raw, code = send_sms(send_phone, sms_text, api_id) sms_id, raw, code = send_sms(send_phone, sms_text, api_id)
if sms_id: if sms_id:
@ -398,7 +423,7 @@ def step_send_new(conn, settings):
sms_text=sms_text, sms_text=sms_text,
status="sent", status="sent",
sms_code=code, sms_code=code,
attempts=1, attempts=attempt_no,
) )
# ДВОЙНАЯ ЗАЩИТА: notification_status → second_sms_sending # ДВОЙНАЯ ЗАЩИТА: notification_status → second_sms_sending
update_order_group(conn, group_id, { update_order_group(conn, group_id, {
@ -416,7 +441,7 @@ def step_send_new(conn, settings):
sms_text=sms_text, sms_text=sms_text,
status="send_failed", status="send_failed",
sms_code=code, sms_code=code,
attempts=1, attempts=attempt_no,
error_message=error, error_message=error,
) )
log.error(f"Group {group_id}: second SMS send failed (code={code}): {error[:200]}") log.error(f"Group {group_id}: second SMS send failed (code={code}): {error[:200]}")
@ -445,7 +470,7 @@ def step_check_status(conn, settings):
group_id = str(item["order_group_id"]) group_id = str(item["order_group_id"])
name = item.get("customer_name") or item.get("group_key", "—") name = item.get("customer_name") or item.get("group_key", "—")
phone = item.get("customer_phone", "") phone = item.get("customer_phone", "")
attempts = item.get("attempts", 1) attempts = item.get("attempts") or 1
code, raw, api_code = check_sms_status(sms_id, api_id) code, raw, api_code = check_sms_status(sms_id, api_id)
@ -527,7 +552,7 @@ def step_handle_expired(conn, settings):
group_id = str(item["order_group_id"]) group_id = str(item["order_group_id"])
name = item.get("customer_name") or item.get("group_key", "—") name = item.get("customer_name") or item.get("group_key", "—")
phone = item.get("customer_phone", "") phone = item.get("customer_phone", "")
attempts = item.get("attempts", 1) attempts = item.get("attempts") or 1
log.warning(f"Group {group_id}: second SMS expired after {max_duration} min, attempts={attempts}/{max_attempts}") log.warning(f"Group {group_id}: second SMS expired after {max_duration} min, attempts={attempts}/{max_attempts}")
update_sms_log(conn, log_id, status="expired", update_sms_log(conn, log_id, status="expired",