fix: устранить MissingGreenlet в автоплатежах и починить traceback в логах

- subtract_user_balance: пишем promo_offer_log в отдельной сессии вместо rollback после commit, который экспайрил объекты основной сессии и ломал последующие обращения к subscription/user attrs
- monitoring_service._process_autopayments: перезагружаем subscription с eager-load user/tariff после списания, оборачиваем каждую итерацию в try/except + rollback, чтобы одна ошибка не валила весь батч
- logging_config: новый processor _auto_capture_exc_info автоматически подтягивает traceback из sys.exc_info() или error-kwarg → полный traceback в файле, консоли и Telegram без exc_info=True на каждом вызове
- logging_handler: дублирующая логика захвата exc_info в TelegramNotifierProcessor как резерв

app/database/crud/user.py

@@ -710,30 +710,52 @@ async def subtract_user_balance(
             await db.refresh(user)
 
         if consume_promo_offer and log_context:
-            try:
+            # Пишем лог в ОТДЕЛЬНОЙ сессии, чтобы его commit/rollback не касался
-                await log_promo_offer_action(
+            # основной сессии caller'а. Иначе rollback в случае фейла логирования
-                    db,
+            # экспайрит объекты сессии и следующее обращение к subscription/user
-                    user_id=user.id,
+            # attrs у caller'а падает с MissingGreenlet.
-                    offer_id=log_context.get('offer_id'),
+            if commit:
-                    action='consumed',
+                try:
-                    source=log_context.get('source'),
+                    from app.database.database import AsyncSessionLocal
-                    percent=log_context.get('percent'),
+
-                    effect_type=log_context.get('effect_type'),
+                    async with AsyncSessionLocal() as log_db:
-                    details=log_context.get('details'),
+                        await log_promo_offer_action(
-                    commit=commit,
+                            log_db,
-                )
+                            user_id=user.id,
-            except Exception as log_error:  # pragma: no cover - defensive logging
+                            offer_id=log_context.get('offer_id'),
-                logger.warning(
+                            action='consumed',
-                    'Failed to record promo offer consumption log for user', user_id=user.id, log_error=log_error
+                            source=log_context.get('source'),
-                )
+                            percent=log_context.get('percent'),
-                if commit:
+                            effect_type=log_context.get('effect_type'),
-                    try:
+                            details=log_context.get('details'),
-                        await db.rollback()
+                            commit=True,
-                    except Exception as rollback_error:  # pragma: no cover - defensive logging
-                        logger.warning(
-                            'Failed to rollback session after promo offer consumption log failure',
-                            rollback_error=rollback_error,
                         )
+                except Exception as log_error:  # pragma: no cover - defensive logging
+                    logger.warning(
+                        'Failed to record promo offer consumption log for user',
+                        user_id=user.id,
+                        log_error=log_error,
+                    )
+            else:
+                # Caller управляет транзакцией — пишем в его сессию без commit.
+                try:
+                    await log_promo_offer_action(
+                        db,
+                        user_id=user.id,
+                        offer_id=log_context.get('offer_id'),
+                        action='consumed',
+                        source=log_context.get('source'),
+                        percent=log_context.get('percent'),
+                        effect_type=log_context.get('effect_type'),
+                        details=log_context.get('details'),
+                        commit=False,
+                    )
+                except Exception as log_error:  # pragma: no cover - defensive logging
+                    logger.warning(
+                        'Failed to record promo offer consumption log for user',
+                        user_id=user.id,
+                        log_error=log_error,
+                    )
 
         logger.info('✅ Средства списаны: →', old_balance=old_balance, balance_kopeks=user.balance_kopeks)
         return True

app/logging_config.py

@@ -15,6 +15,7 @@ Usage::
 from __future__ import annotations
 
 import logging
+import sys
 from typing import Any
 
 import structlog
@@ -56,6 +57,43 @@ def _prefix_logger_name(logger: Any, method_name: str, event_dict: dict[str, Any
     return event_dict
 
 
+def _auto_capture_exc_info(logger: Any, method_name: str, event_dict: dict[str, Any]) -> dict[str, Any]:
+    """Auto-populate event_dict['exc_info'] so tracebacks render in files/console.
+
+    Without this, callers must pass ``exc_info=True`` at every ``logger.error``
+    site. Instead, we try:
+      1. exc_info=True → replace with sys.exc_info() (standard structlog behaviour)
+      2. no exc_info but we're inside an active except block → use sys.exc_info()
+      3. error/exc/exception/e/err kwarg is a BaseException with __traceback__ →
+         synthesize an exc_info tuple from it
+
+    Result: ``logger.error('msg', error=e)`` inside any ``except`` block now
+    renders the full traceback to files, console, and Telegram automatically.
+    """
+    exc_info = event_dict.get('exc_info')
+    if exc_info is True:
+        current = sys.exc_info()
+        if current[1] is not None:
+            event_dict['exc_info'] = current
+        return event_dict
+
+    if exc_info:
+        return event_dict
+
+    current = sys.exc_info()
+    if current[1] is not None:
+        event_dict['exc_info'] = current
+        return event_dict
+
+    for key in ('error', 'exc', 'exception', 'e', 'err'):
+        candidate = event_dict.get(key)
+        if isinstance(candidate, BaseException) and candidate.__traceback__ is not None:
+            event_dict['exc_info'] = (type(candidate), candidate, candidate.__traceback__)
+            return event_dict
+
+    return event_dict
+
+
 def setup_logging() -> tuple[logging.Formatter, logging.Formatter, Any]:
     """Configure structlog and return formatters + notifier.
 
@@ -82,6 +120,11 @@ def setup_logging() -> tuple[logging.Formatter, logging.Formatter, Any]:
         structlog.stdlib.PositionalArgumentsFormatter(),
         timestamper,
         structlog.processors.StackInfoRenderer(),
+        # Auto-capture traceback from sys.exc_info()/error-kwarg BEFORE any
+        # consumer looks at event_dict. Runs for ALL log levels so files,
+        # console, and Telegram all see the same traceback without requiring
+        # every caller to pass exc_info=True.
+        _auto_capture_exc_info,
         # TelegramNotifierProcessor MUST run while exc_info is still a raw
         # tuple so it can extract the traceback for Telegram notifications.
         # ConsoleRenderer handles exc_info formatting downstream (with Rich

app/logging_handler.py

@@ -129,13 +129,28 @@ class TelegramNotifierProcessor:
         if any(logger_name.startswith(prefix) for prefix in IGNORED_LOGGER_PREFIXES):
             return event_dict
 
-        # 4. Resolve exc_info=True to actual tuple while still in except block.
+        # 4. Resolve exc_info into actual tuple while still in except block.
         # logger.exception() sets exc_info=True (bool); we need the tuple for
         # traceback extraction. sys.exc_info() works because the processor runs
         # synchronously inside the except clause.
+        #
+        # If exc_info is not passed at all, auto-capture traceback from:
+        #   (a) sys.exc_info() — works when logger.error is called inside except
+        #   (b) error/exc/exception kwargs if they carry __traceback__
+        # This avoids having to pass exc_info=True at every logger.error site.
         exc_info = event_dict.get('exc_info')
         if exc_info is True:
             event_dict['exc_info'] = sys.exc_info()
+        elif not exc_info:
+            current = sys.exc_info()
+            if current[1] is not None:
+                event_dict['exc_info'] = current
+            else:
+                for key in ('error', 'exc', 'exception', 'e', 'err'):
+                    candidate = event_dict.get(key)
+                    if isinstance(candidate, BaseException) and candidate.__traceback__ is not None:
+                        event_dict['exc_info'] = (type(candidate), candidate, candidate.__traceback__)
+                        break
 
         # 5. Bot not initialized yet — skip
         bot = self._bot

app/services/monitoring_service.py

@@ -1203,159 +1203,202 @@ class MonitoringService:
             failed_count = 0
 
             for subscription in autopay_subscriptions:
-                from app.database.crud.subscription import is_recently_updated_by_webhook
-
-                if is_recently_updated_by_webhook(subscription):
-                    logger.debug(
-                        'Пропуск автоплатежа подписки : обновлена вебхуком недавно', subscription_id=subscription.id
-                    )
-                    continue
-
-                user = subscription.user
-                if not user:
-                    continue
-
-                user_identifier = user.telegram_id or f'email:{user.id}'
-
-                # Определяем период продления: из тарифа (минимальный) или 30 дней по умолчанию
-                tariff = getattr(subscription, 'tariff', None)
-                if tariff:
-                    autopay_period = tariff.get_shortest_period() or 30
-                else:
-                    autopay_period = 30
-
                 try:
-                    from app.database.crud.user import lock_user_for_pricing
+                    from app.database.crud.subscription import is_recently_updated_by_webhook
-                    from app.services.pricing_engine import pricing_engine
 
-                    user = await lock_user_for_pricing(db, user.id)
+                    if is_recently_updated_by_webhook(subscription):
+                        logger.debug(
+                            'Пропуск автоплатежа подписки : обновлена вебхуком недавно', subscription_id=subscription.id
+                        )
+                        continue
 
-                    pricing = await pricing_engine.calculate_renewal_price(
+                    user = subscription.user
-                        db,
+                    if not user:
-                        subscription,
+                        continue
-                        autopay_period,
-                        user=user,
-                    )
-                    renewal_cost = pricing.final_total
-                except Exception as e:
-                    logger.error(
-                        'Ошибка расчёта стоимости автопродления, пропускаем',
-                        subscription_id=subscription.id,
-                        user_id=user.id,
-                        error=str(e),
-                    )
-                    failed_count += 1
-                    continue
 
-                if renewal_cost <= 0:
+                    user_identifier = user.telegram_id or f'email:{user.id}'
-                    logger.warning(
-                        'Нулевая стоимость автопродления, пропускаем',
-                        subscription_id=subscription.id,
-                        user_id=user.id,
-                        renewal_cost=renewal_cost,
-                    )
-                    failed_count += 1
-                    continue
 
-                # calculate_renewal_price уже включает promo_group + promo_offer скидки.
+                    # Определяем период продления: из тарифа (минимальный) или 30 дней по умолчанию
-                # Не применяем promo_offer повторно — только consume-им при успешной оплате.
+                    tariff = getattr(subscription, 'tariff', None)
-                charge_amount = renewal_cost
+                    if tariff:
-                promo_discount_percent = get_user_active_promo_discount_percent(user)
+                        autopay_period = tariff.get_shortest_period() or 30
+                    else:
+                        autopay_period = 30
 
-                autopay_key = f'autopay_{user.id}_{subscription.id}'
+                    try:
-                if autopay_key in self._notified_users:
+                        from app.database.crud.user import lock_user_for_pricing
-                    continue
+                        from app.services.pricing_engine import pricing_engine
 
-                if user.balance_kopeks >= charge_amount:
+                        user = await lock_user_for_pricing(db, user.id)
-                    success = await subtract_user_balance(
-                        db,
-                        user,
-                        charge_amount,
-                        'Автопродление подписки',
-                        consume_promo_offer=promo_discount_percent > 0,
-                        mark_as_paid_subscription=True,
-                    )
 
-                    if success:
+                        pricing = await pricing_engine.calculate_renewal_price(
-                        # extend_subscription сам обработает EXPIRED→ACTIVE переход
-                        # (проверяет status + end_date для определения was_expired)
-                        if subscription.status == SubscriptionStatus.EXPIRED.value:
-                            logger.info(
-                                '🔄 Autopay: продление EXPIRED подписки (восстановление)',
-                                subscription_id=subscription.id,
-                                user_id=user.id,
-                            )
-                        old_end_date = subscription.end_date
-                        await extend_subscription(db, subscription, autopay_period)
-                        await self.subscription_service.update_remnawave_user(
                             db,
                             subscription,
-                            reset_traffic=settings.RESET_TRAFFIC_ON_PAYMENT,
+                            autopay_period,
-                            reset_reason='автопродление подписки',
+                            user=user,
+                        )
+                        renewal_cost = pricing.final_total
+                    except Exception as e:
+                        logger.error(
+                            'Ошибка расчёта стоимости автопродления, пропускаем',
+                            subscription_id=subscription.id,
+                            user_id=user.id,
+                            error=str(e),
+                        )
+                        failed_count += 1
+                        continue
+
+                    if renewal_cost <= 0:
+                        logger.warning(
+                            'Нулевая стоимость автопродления, пропускаем',
+                            subscription_id=subscription.id,
+                            user_id=user.id,
+                            renewal_cost=renewal_cost,
+                        )
+                        failed_count += 1
+                        continue
+
+                    # calculate_renewal_price уже включает promo_group + promo_offer скидки.
+                    # Не применяем promo_offer повторно — только consume-им при успешной оплате.
+                    charge_amount = renewal_cost
+                    promo_discount_percent = get_user_active_promo_discount_percent(user)
+
+                    autopay_key = f'autopay_{user.id}_{subscription.id}'
+                    if autopay_key in self._notified_users:
+                        continue
+
+                    if user.balance_kopeks >= charge_amount:
+                        success = await subtract_user_balance(
+                            db,
+                            user,
+                            charge_amount,
+                            'Автопродление подписки',
+                            consume_promo_offer=promo_discount_percent > 0,
+                            mark_as_paid_subscription=True,
                         )
 
-                        # Создаём транзакцию, чтобы автопродление было видно в статистике и карточке пользователя
+                        if success:
-                        try:
+                            # subtract_user_balance мог оставить сессию в expired state
-                            from app.database.crud.transaction import create_transaction
+                            # (напр. rollback внутри log_promo_offer_action при consume_promo_offer).
-                            from app.database.models import PaymentMethod, TransactionType
+                            # Перезагружаем subscription с eager-загрузкой user/tariff, чтобы
-
+                            # избежать MissingGreenlet на последующих обращениях к subscription.*
-                            transaction = await create_transaction(
+                            refetch_result = await db.execute(
-                                db=db,
+                                select(Subscription)
-                                user_id=user.id,
+                                .options(
-                                type=TransactionType.SUBSCRIPTION_PAYMENT,
+                                    selectinload(Subscription.user),
-                                amount_kopeks=charge_amount,
+                                    selectinload(Subscription.tariff),
-                                description=f'Автопродление подписки на {autopay_period} дней',
-                                payment_method=PaymentMethod.BALANCE,
-                            )
-                        except Exception as exc:
-                            logger.warning('Не удалось создать транзакцию автопродления', user_id=user.id, exc=exc)
-                            transaction = None
-
-                        # Отправляем уведомление администраторам
-                        try:
-                            from app.services.subscription_renewal_service import with_admin_notification_service
-
-                            if transaction:
-                                await with_admin_notification_service(
-                                    lambda svc: svc.send_subscription_extension_notification(
-                                        db,
-                                        user,
-                                        subscription,
-                                        transaction,
-                                        autopay_period,
-                                        old_end_date,
-                                        new_end_date=subscription.end_date,
-                                        balance_after=user.balance_kopeks,
-                                    )
                                 )
-                        except Exception as exc:
+                                .where(Subscription.id == subscription.id)
+                            )
+                            refreshed_subscription = refetch_result.scalar_one_or_none()
+                            if refreshed_subscription is None:
+                                logger.warning(
+                                    'Подписка пропала после списания — пропускаем шаги продления',
+                                    subscription_id=subscription.id,
+                                    user_id=user.id,
+                                )
+                                processed_count += 1
+                                self._notified_users.add(autopay_key)
+                                continue
+                            subscription = refreshed_subscription
+
+                            # extend_subscription сам обработает EXPIRED→ACTIVE переход
+                            # (проверяет status + end_date для определения was_expired)
+                            if subscription.status == SubscriptionStatus.EXPIRED.value:
+                                logger.info(
+                                    '🔄 Autopay: продление EXPIRED подписки (восстановление)',
+                                    subscription_id=subscription.id,
+                                    user_id=user.id,
+                                )
+                            old_end_date = subscription.end_date
+                            await extend_subscription(db, subscription, autopay_period)
+                            await self.subscription_service.update_remnawave_user(
+                                db,
+                                subscription,
+                                reset_traffic=settings.RESET_TRAFFIC_ON_PAYMENT,
+                                reset_reason='автопродление подписки',
+                            )
+
+                            # Создаём транзакцию, чтобы автопродление было видно в статистике и карточке пользователя
+                            try:
+                                from app.database.crud.transaction import create_transaction
+                                from app.database.models import PaymentMethod, TransactionType
+
+                                transaction = await create_transaction(
+                                    db=db,
+                                    user_id=user.id,
+                                    type=TransactionType.SUBSCRIPTION_PAYMENT,
+                                    amount_kopeks=charge_amount,
+                                    description=f'Автопродление подписки на {autopay_period} дней',
+                                    payment_method=PaymentMethod.BALANCE,
+                                )
+                            except Exception as exc:
+                                logger.warning('Не удалось создать транзакцию автопродления', user_id=user.id, exc=exc)
+                                transaction = None
+
+                            # Отправляем уведомление администраторам
+                            try:
+                                from app.services.subscription_renewal_service import with_admin_notification_service
+
+                                if transaction:
+                                    await with_admin_notification_service(
+                                        lambda svc: svc.send_subscription_extension_notification(
+                                            db,
+                                            user,
+                                            subscription,
+                                            transaction,
+                                            autopay_period,
+                                            old_end_date,
+                                            new_end_date=subscription.end_date,
+                                            balance_after=user.balance_kopeks,
+                                        )
+                                    )
+                            except Exception as exc:
+                                logger.warning(
+                                    'Не удалось отправить админ-уведомление об автопродлении', user_id=user.id, exc=exc
+                                )
+
+                            # Send notification via appropriate channel
+                            if user.telegram_id and self.bot:
+                                await self._send_autopay_success_notification(
+                                    user, charge_amount, autopay_period, subscription=subscription
+                                )
+                            elif not user.telegram_id:
+                                # Email-only user - use notification delivery service
+                                await notification_delivery_service.notify_autopay_success(
+                                    user=user,
+                                    amount_kopeks=charge_amount,
+                                    new_expires_at=subscription.end_date,
+                                )
+
+                            processed_count += 1
+                            self._notified_users.add(autopay_key)
+                            logger.info(
+                                '💳 Автопродление подписки пользователя успешно (списано , скидка %)',
+                                user_identifier=user_identifier,
+                                charge_amount=charge_amount,
+                                promo_discount_percent=promo_discount_percent,
+                            )
+                        else:
+                            failed_count += 1
+                            if await self._check_autopay_fail_cooldown(user.id, user_identifier):
+                                if user.telegram_id and self.bot:
+                                    await self._send_autopay_failed_notification(
+                                        user, user.balance_kopeks, charge_amount, subscription=subscription
+                                    )
+                                elif not user.telegram_id:
+                                    await notification_delivery_service.notify_autopay_failed(
+                                        user=user,
+                                        reason='Ошибка списания средств',
+                                    )
+                                await self._set_autopay_fail_cooldown(user.id, user_identifier)
                             logger.warning(
-                                'Не удалось отправить админ-уведомление об автопродлении', user_id=user.id, exc=exc
+                                '💳 Ошибка списания средств для автопродления пользователя',
+                                user_identifier=user_identifier,
                             )
-
-                        # Send notification via appropriate channel
-                        if user.telegram_id and self.bot:
-                            await self._send_autopay_success_notification(
-                                user, charge_amount, autopay_period, subscription=subscription
-                            )
-                        elif not user.telegram_id:
-                            # Email-only user - use notification delivery service
-                            await notification_delivery_service.notify_autopay_success(
-                                user=user,
-                                amount_kopeks=charge_amount,
-                                new_expires_at=subscription.end_date,
-                            )
-
-                        processed_count += 1
-                        self._notified_users.add(autopay_key)
-                        logger.info(
-                            '💳 Автопродление подписки пользователя успешно (списано , скидка %)',
-                            user_identifier=user_identifier,
-                            charge_amount=charge_amount,
-                            promo_discount_percent=promo_discount_percent,
-                        )
                     else:
                         failed_count += 1
+
                         if await self._check_autopay_fail_cooldown(user.id, user_identifier):
                             if user.telegram_id and self.bot:
                                 await self._send_autopay_failed_notification(
@@ -1364,30 +1407,33 @@ class MonitoringService:
                             elif not user.telegram_id:
                                 await notification_delivery_service.notify_autopay_failed(
                                     user=user,
-                                    reason='Ошибка списания средств',
+                                    reason='Недостаточно средств на балансе',
                                 )
                             await self._set_autopay_fail_cooldown(user.id, user_identifier)
+
                         logger.warning(
-                            '💳 Ошибка списания средств для автопродления пользователя', user_identifier=user_identifier
+                            '💳 Недостаточно средств для автопродления у пользователя',
+                            user_identifier=user_identifier,
                         )
-                else:
+                except Exception as sub_error:
                     failed_count += 1
-
+                    logger.error(
-                    if await self._check_autopay_fail_cooldown(user.id, user_identifier):
+                        'Ошибка автопродления отдельной подписки',
-                        if user.telegram_id and self.bot:
+                        subscription_id=getattr(subscription, 'id', None),
-                            await self._send_autopay_failed_notification(
+                        user_id=getattr(subscription, 'user_id', None),
-                                user, user.balance_kopeks, charge_amount, subscription=subscription
+                        error=sub_error,
-                            )
+                        exc_info=True,
-                        elif not user.telegram_id:
-                            await notification_delivery_service.notify_autopay_failed(
-                                user=user,
-                                reason='Недостаточно средств на балансе',
-                            )
-                        await self._set_autopay_fail_cooldown(user.id, user_identifier)
-
-                    logger.warning(
-                        '💳 Недостаточно средств для автопродления у пользователя', user_identifier=user_identifier
                     )
+                    # Сессия могла «протухнуть» (MissingGreenlet, rollback после commit и т.п.) —
+                    # откатываемся, чтобы следующая итерация работала с чистой сессией.
+                    try:
+                        await db.rollback()
+                    except Exception as rollback_error:
+                        logger.warning(
+                            'Не удалось сделать rollback сессии после ошибки автопродления',
+                            rollback_error=rollback_error,
+                        )
+                    continue
 
             if processed_count > 0 or failed_count > 0:
                 await self._log_monitoring_event(
@@ -1398,7 +1444,7 @@ class MonitoringService:
                 )
 
         except Exception as e:
-            logger.error('Ошибка обработки автоплатежей', error=e)
+            logger.error('Ошибка обработки автоплатежей', error=e, exc_info=True)
 
     async def _send_subscription_expired_notification(
         self, user: User, subscription: Subscription, *, tariff_name: str | None = None