Compare commits

...

4 Commits

Author SHA1 Message Date
Раис Юсупалиев 02f5ef93b0 улучшены логи, otel collector добавлен в git
Deploy / deploy (push) Successful in 50s
2026-06-20 05:24:17 +03:00
Раис Юсупалиев aeee641c6c поправлена гонка статусов от tabnk
Deploy / deploy (push) Successful in 48s
2026-06-20 01:12:16 +03:00
Раис Юсупалиев cbcd9ca1bc логи для нотификации tbank
Deploy / deploy (push) Successful in 56s
2026-06-20 00:26:48 +03:00
Раис Юсупалиев 65c07f1da3 фикс поллинга накладной
Deploy / deploy (push) Successful in 9m37s
2026-06-19 23:52:46 +03:00
18 changed files with 444 additions and 47 deletions
+6 -3
View File
@@ -26,6 +26,7 @@ jobs:
echo "APP_PORT=8004"
echo "POSTGRES_PORT=5433"
echo "REDIS_PORT=6380"
echo 'METRICS_FILTER_EXPRESSION=not IsMatch(resource.attributes["container.name"], "-stage$")'
echo "COMPOSE_PROJECT=g2s-aggregator-stage"
echo "DEPLOY_DIR=/home/deploy/g2s-aggregator-stage"
} >> "$GITHUB_ENV"
@@ -36,6 +37,7 @@ jobs:
echo "APP_PORT=8003"
echo "POSTGRES_PORT=5432"
echo "REDIS_PORT=6379"
echo 'METRICS_FILTER_EXPRESSION=IsMatch(resource.attributes["container.name"], "-stage$")'
echo "COMPOSE_PROJECT=g2s-aggregator"
echo "DEPLOY_DIR=/home/deploy/g2s-aggregator"
} >> "$GITHUB_ENV"
@@ -73,8 +75,6 @@ jobs:
run: |
set -euo pipefail
apt update && apt install -y gettext-base
# Экспортируем все секреты как env-переменные
while IFS= read -r -d '' entry; do
key="${entry%%=*}"
@@ -103,16 +103,19 @@ jobs:
exit 1
fi
done
envsubst < "$src" > "$dst"
perl -pe 's/\$\{(\w+)\}/exists $ENV{$1} ? $ENV{$1} : ""/ge' "$src" > "$dst"
}
render config.template.yaml config.rendered.yaml
render docker-compose.template.yml docker-compose.rendered.yml
render otel-collector-config.template.yaml otel-collector-config.rendered.yaml
scp -i ~/.ssh/deploy_key config.rendered.yaml \
deploy@194.58.121.203:$DEPLOY_DIR/config.yaml
scp -i ~/.ssh/deploy_key docker-compose.rendered.yml \
deploy@194.58.121.203:$DEPLOY_DIR/docker-compose.yml
scp -i ~/.ssh/deploy_key otel-collector-config.rendered.yaml \
deploy@194.58.121.203:$DEPLOY_DIR/otel-collector-config.yaml
- name: Deploy
run: |
+1
View File
@@ -2,6 +2,7 @@
*.iml
/config.yaml
/docker-compose.yml
/otel-collector-config.yaml
__pycache__
http-client.private.env.json
scripts
@@ -233,6 +233,13 @@ class CDEKClient:
url,
failure_message="CDEK get order failed",
)
requests_with_errors = _extract_requests_with_errors(raw_payload)
if requests_with_errors:
log.warning(
"cdek_order_request_errors",
cdek_order_uuid=cdek_order_uuid,
requests=requests_with_errors,
)
try:
return map_cdek_order_info_response(raw_payload)
except CDEKOrderMappingError as exc:
@@ -513,3 +520,28 @@ def _response_text_or_none(response: httpx.Response) -> str | None:
return response.text
except Exception:
return None
def _extract_requests_with_errors(
payload: dict[str, Any],
) -> list[dict[str, object]]:
requests = payload.get("requests")
if not isinstance(requests, list):
return []
requests_with_errors: list[dict[str, object]] = []
for request in requests:
if not isinstance(request, dict):
continue
errors = request.get("errors")
if not isinstance(errors, list) or not errors:
continue
requests_with_errors.append(
{
"request_uuid": request.get("request_uuid"),
"type": request.get("type"),
"state": request.get("state"),
"errors": errors,
}
)
return requests_with_errors
@@ -173,6 +173,13 @@ def _latest_status_code(statuses: object) -> str | None:
def _extract_waybill(payload: dict[str, Any]) -> tuple[str | None, str | None]:
entity = payload.get("entity")
related_entities = (
entity.get("related_entities")
if isinstance(entity, dict)
else None
)
if not isinstance(related_entities, list):
related_entities = payload.get("related_entities")
if not isinstance(related_entities, list):
return None, None
+24
View File
@@ -241,9 +241,23 @@ async def handle_tbank_payment_notification(
notification: TBankPaymentNotification,
service: AggregatorService = Depends(get_aggregator_service),
) -> PlainTextResponse:
logger.info(
"tbank_notification_received",
order_id=notification.OrderId,
status=notification.Status,
success=notification.Success,
payment_id=notification.PaymentId,
error_code=notification.ErrorCode,
amount=notification.Amount,
)
try:
response_body = await service.handle_tbank_payment_notification(notification)
except InvalidTBankPaymentNotificationError as exc:
logger.warning(
"tbank_notification_rejected",
order_id=notification.OrderId,
reason="invalid_token",
)
raise HTTPException(
status_code=status.HTTP_400_BAD_REQUEST,
detail={
@@ -252,6 +266,11 @@ async def handle_tbank_payment_notification(
},
) from exc
except TBankPaymentNotificationProcessingError as exc:
logger.error(
"tbank_notification_processing_failed",
order_id=notification.OrderId,
exc_info=True,
)
raise HTTPException(
status_code=status.HTTP_503_SERVICE_UNAVAILABLE,
detail={
@@ -260,6 +279,11 @@ async def handle_tbank_payment_notification(
},
) from exc
except AggregatorServiceError as exc:
logger.error(
"tbank_notification_processing_failed",
order_id=notification.OrderId,
exc_info=True,
)
raise HTTPException(
status_code=status.HTTP_503_SERVICE_UNAVAILABLE,
detail={
+37
View File
@@ -17,3 +17,40 @@ def resolve_tbank_payment_notification_action(
if status == "CONFIRMED" and success is True and error_code == "0":
return TBankPaymentNotificationAction.REGISTER_CDEK_ORDER
return TBankPaymentNotificationAction.ACKNOWLEDGE_ONLY
# Монотонный приоритет статусов платежа TBank по жизненному циклу.
# Используется, чтобы внеочередное уведомление не понижало уже записанный статус
# (например, AUTHORIZED, пришедший после CONFIRMED, не должен затирать CONFIRMED).
# Неизвестные статусы получают ранг 0 и не перезаписывают известный статус.
_TBANK_PAYMENT_STATUS_RANK: dict[str, int] = {
"NEW": 10,
"FORM_SHOWED": 20,
"AUTHORIZING": 30,
"3DS_CHECKING": 30,
"3DS_CHECKED": 30,
"REJECTED": 40,
"AUTH_FAIL": 40,
"DEADLINE_EXPIRED": 40,
"AUTHORIZED": 40,
"CONFIRMING": 50,
"CONFIRMED": 60,
"REVERSING": 70,
"PARTIAL_REVERSED": 70,
"REVERSED": 70,
"REFUNDING": 70,
"PARTIAL_REFUNDED": 70,
"REFUNDED": 70,
"CANCELED": 70,
}
def tbank_payment_status_rank(status: str) -> int:
return _TBANK_PAYMENT_STATUS_RANK.get(status, 0)
def should_apply_tbank_payment_status(current: str | None, new: str) -> bool:
"""Применять новый статус, только если он не понижает текущий по жизненному циклу."""
if current is None:
return True
return tbank_payment_status_rank(new) >= tbank_payment_status_rank(current)
+6 -3
View File
@@ -50,10 +50,13 @@ class OrderRepository:
self,
session: AsyncSession,
order_uuid: str,
*,
for_update: bool = False,
) -> Order | None:
result = await session.execute(
select(Order).where(Order.order_uuid == order_uuid)
)
statement = select(Order).where(Order.order_uuid == order_uuid)
if for_update:
statement = statement.with_for_update()
result = await session.execute(statement)
return result.scalar_one_or_none()
async def mark_payment_status(
+29 -2
View File
@@ -1,9 +1,10 @@
"""Centralized runtime logging bootstrap."""
import json
import logging
import sys
from collections.abc import Iterable
from typing import TextIO
from typing import Any, TextIO
import structlog
@@ -31,8 +32,9 @@ def configure_logging(
structlog.reset_defaults()
structlog.configure(
processors=[
*_shared_processors(),
structlog.stdlib.PositionalArgumentsFormatter(),
_render_context_in_event,
*_shared_processors(),
structlog.processors.StackInfoRenderer(),
structlog.processors.format_exc_info,
structlog.stdlib.ProcessorFormatter.wrap_for_formatter,
@@ -60,6 +62,31 @@ def _shared_processors() -> tuple[structlog.types.Processor, ...]:
)
def _render_context_in_event(
_logger: Any,
_method_name: str,
event_dict: structlog.types.EventDict,
) -> structlog.types.EventDict:
event = str(event_dict.get("event", ""))
context = " ".join(
f"{key}={_serialize_log_value(value)}"
for key, value in sorted(event_dict.items())
if key not in {"event", "exc_info", "stack_info"}
)
event_dict["event"] = f"{event} {context}" if context else event
return event_dict
def _serialize_log_value(value: object) -> str:
return json.dumps(
value,
ensure_ascii=False,
sort_keys=True,
separators=(",", ":"),
default=str,
)
def _configure_logger(
logger: logging.Logger,
*,
+33 -7
View File
@@ -30,6 +30,7 @@ from app.adapters.tbank.base import (
from app.domain.payment_notifications import (
TBankPaymentNotificationAction,
resolve_tbank_payment_notification_action,
should_apply_tbank_payment_status,
)
from app.domain.price import (
DEFAULT_PROVIDER_PRICE_MULTIPLIER,
@@ -425,6 +426,10 @@ class AggregatorService:
try:
self._payment_adapter.verify_payment_notification(notification)
except TBankPaymentNotificationTokenError as exc:
logger.warning(
"tbank_notification_token_invalid",
order_id=notification.OrderId,
)
raise InvalidTBankPaymentNotificationError(
"TBank payment notification token is invalid."
) from exc
@@ -438,6 +443,12 @@ class AggregatorService:
success=notification.Success,
error_code=notification.ErrorCode,
)
logger.info(
"tbank_notification_action_resolved",
order_id=notification.OrderId,
status=notification.Status,
action=action.name,
)
order = await self._load_order_and_mark_payment_status(notification)
if action is TBankPaymentNotificationAction.ACKNOWLEDGE_ONLY:
@@ -445,6 +456,11 @@ class AggregatorService:
provider = self._resolve_order_provider(order)
if self._has_existing_registration(order, provider):
logger.info(
"tbank_notification_registration_skipped_duplicate",
order_id=notification.OrderId,
provider=provider,
)
return "OK"
registration_result = await self._register_provider_order(
@@ -455,6 +471,11 @@ class AggregatorService:
provider=provider,
result=registration_result,
)
logger.info(
"tbank_notification_order_registered",
order_id=notification.OrderId,
provider=provider,
)
await self._send_payment_confirmation_email(
order, order_uuid=notification.OrderId
)
@@ -517,9 +538,12 @@ class AggregatorService:
try:
async with self._order_repository.session() as session:
# FOR UPDATE: сериализуем конкурентные уведомления по одному заказу,
# чтобы внеочередной статус не затирал уже записанный (lost update).
order = await self._order_repository.get_order_by_order_uuid(
session,
notification.OrderId,
for_update=True,
)
if order is None:
logger.warning(
@@ -529,19 +553,21 @@ class AggregatorService:
raise TBankPaymentNotificationProcessingError(
"Order was not found for TBank payment notification."
)
updated_order = await self._order_repository.mark_payment_status(
if should_apply_tbank_payment_status(
order.payment_status, notification.Status
):
await self._order_repository.mark_payment_status(
session,
notification.OrderId,
notification.Status,
notification.PaymentId,
)
if updated_order is None:
logger.warning(
"tbank_payment_notification_order_not_found",
else:
logger.info(
"tbank_payment_status_downgrade_skipped",
order_uuid=notification.OrderId,
)
raise TBankPaymentNotificationProcessingError(
"Order was not found for TBank payment notification."
current_status=order.payment_status,
incoming_status=notification.Status,
)
return order
except TBankPaymentNotificationProcessingError:
+5 -5
View File
@@ -116,11 +116,11 @@ class WaybillEmailSenderService:
while not stop_event.is_set():
try:
summary = await self.poll_once()
logger.info(
"waybill_email_tick "
f"processed={summary.processed} "
f"succeeded={summary.succeeded} "
f"failed={summary.failed}"
logger.debug(
"waybill_email_tick",
processed=summary.processed,
succeeded=summary.succeeded,
failed=summary.failed,
)
except Exception:
logger.exception("waybill_email_tick_failed")
+5 -5
View File
@@ -115,11 +115,11 @@ class WaybillPollerService:
while not stop_event.is_set():
try:
summary = await self.poll_once()
logger.info(
"waybill_poll_tick "
f"processed={summary.processed} "
f"succeeded={summary.succeeded} "
f"failed={summary.failed}"
logger.debug(
"waybill_poll_tick",
processed=summary.processed,
succeeded=summary.succeeded,
failed=summary.failed,
)
except Exception:
logger.exception("waybill_poll_tick_failed")
+109
View File
@@ -0,0 +1,109 @@
receivers:
otlp:
protocols:
grpc:
endpoint: 0.0.0.0:4317
http:
endpoint: 0.0.0.0:4318
filelog:
include:
- /var/lib/docker/containers/*/*-json.log
include_file_path: true
operators:
- type: json_parser
parse_to: attributes
on_error: send
- type: filter
expr: |
attributes["attrs"] == nil or
attributes["attrs"]["tag"] == nil or
(
attributes["attrs"]["tag"] != "g2s-aggregator${CONTAINER_SUFFIX}" and
attributes["attrs"]["tag"] != "g2s-aggregator-migrations${CONTAINER_SUFFIX}" and
attributes["attrs"]["tag"] != "g2s-aggregator-waybill-poller${CONTAINER_SUFFIX}" and
attributes["attrs"]["tag"] != "g2s-aggregator-waybill-email-sender${CONTAINER_SUFFIX}"
)
on_error: send
- type: regex_parser
parse_from: attributes["attrs"]["tag"]
regex: '^(?P<service_name>g2s-aggregator(?:-migrations|-waybill-poller|-waybill-email-sender)?)(?:-stage)?$'
on_error: send
- type: move
from: attributes["service_name"]
to: resource["service.name"]
on_error: send
- type: regex_parser
parse_from: attributes["log.file.path"]
regex: '^/var/lib/docker/containers/(?P<container_id>[^/]+)/'
on_error: send
- type: move
from: attributes["container_id"]
to: resource["service.instance.id"]
on_error: send
- type: remove
field: attributes["attrs"]
on_error: send
- type: json_parser
parse_from: attributes.log
parse_to: attributes
on_error: send
- type: time_parser
parse_from: attributes.timestamp
layout: '%Y-%m-%dT%H:%M:%S.%fZ'
on_error: send
- type: severity_parser
parse_from: attributes.level
on_error: send
- type: move
from: attributes.event
to: body
on_error: send
- type: remove
field: attributes.log
on_error: send
docker_stats:
endpoint: unix:///var/run/docker.sock
collection_interval: 30s
container_labels_as_resource_attributes: true
api_version: "1.43"
processors:
resource/env:
attributes:
- key: deployment.environment
value: "${ENV_NAME}"
action: upsert
- key: service.namespace
value: g2s
action: upsert
resource/version:
attributes:
- key: service.version
value: "${IMAGE_TAG}"
action: upsert
filter/environment:
error_mode: ignore
metrics:
metric:
- '${METRICS_FILTER_EXPRESSION}'
exporters:
otlp:
endpoint: "${SIGNOZ_OTLP_ENDPOINT}"
tls:
insecure: true
service:
pipelines:
traces:
receivers: [otlp]
processors: [resource/env, resource/version]
exporters: [otlp]
logs:
receivers: [filelog]
processors: [resource/env, resource/version]
exporters: [otlp]
metrics:
receivers: [docker_stats]
processors: [filter/environment, resource/env]
exporters: [otlp]
@@ -1,5 +1,6 @@
import asyncio
from typing import Any
from unittest.mock import patch
import httpx
import pytest
@@ -64,11 +65,11 @@ def test_get_order_parses_status_and_waybill_uuid() -> None:
"statuses": [
{"code": "ACCEPTED", "date_time": "2026-05-24T10:00:00+0000"}
],
},
"related_entities": [
{"type": "waybill", "uuid": "waybill-uuid-1"}
],
},
},
request=httpx.Request("GET", "https://api.cdek.test/v2/orders/cdek-order-uuid"),
)
http_client = SequenceHTTPClient([response])
@@ -87,6 +88,55 @@ def test_get_order_parses_status_and_waybill_uuid() -> None:
assert http_client.calls[0]["headers"] == {"Authorization": "Bearer test-token"}
def test_get_order_logs_request_errors() -> None:
response = httpx.Response(
200,
json={
"entity": {"uuid": "cdek-order-uuid", "statuses": []},
"requests": [
{
"request_uuid": "request-uuid",
"type": "CREATE",
"state": "INVALID",
"errors": [
{
"code": "invalid_order",
"message": "Order data is invalid",
}
],
}
],
},
request=httpx.Request(
"GET", "https://api.cdek.test/v2/orders/cdek-order-uuid"
),
)
client = _make_client(SequenceHTTPClient([response]))
with patch(
"app.adapters.delivery_providers.cdek.client.log.warning"
) as warning_mock:
asyncio.run(client.get_order("cdek-order-uuid"))
warning_mock.assert_called_once_with(
"cdek_order_request_errors",
cdek_order_uuid="cdek-order-uuid",
requests=[
{
"request_uuid": "request-uuid",
"type": "CREATE",
"state": "INVALID",
"errors": [
{
"code": "invalid_order",
"message": "Order data is invalid",
}
],
}
],
)
def test_get_order_retries_on_5xx_and_succeeds() -> None:
flaky = httpx.Response(
503,
@@ -42,7 +42,8 @@ def test_map_cdek_order_response_extracts_order_uuid_without_waybill() -> None:
def test_map_cdek_order_response_extracts_waybill_from_related_entities() -> None:
result = map_cdek_order_response(
{
"entity": {"uuid": "cdek-order-uuid"},
"entity": {
"uuid": "cdek-order-uuid",
"related_entities": [
{"type": "delivery", "uuid": "ignored"},
{
@@ -51,6 +52,7 @@ def test_map_cdek_order_response_extracts_waybill_from_related_entities() -> Non
"url": "https://cdek.test/waybill/1.pdf",
},
],
},
}
)
@@ -61,6 +63,26 @@ def test_map_cdek_order_response_extracts_waybill_from_related_entities() -> Non
)
def test_map_cdek_order_response_supports_root_related_entities() -> None:
result = map_cdek_order_response(
{
"entity": {"uuid": "cdek-order-uuid"},
"related_entities": [
{
"type": "waybill",
"uuid": "waybill-uuid-legacy",
},
],
}
)
assert result == CDEKOrderRegistrationResult(
order_uuid="cdek-order-uuid",
waybill_uuid="waybill-uuid-legacy",
waybill_url=None,
)
def test_map_cdek_existing_order_response_returns_waybill_for_duplicate() -> None:
result = map_cdek_existing_order_response(
{
@@ -224,10 +246,10 @@ def test_map_cdek_order_info_response_picks_latest_status_by_date_time() -> None
{"code": "ACCEPTED", "date_time": "2026-05-24T10:00:00+0000"},
{"code": "INVALID", "date_time": "2026-05-24T10:00:05+0000"},
],
},
"related_entities": [
{"type": "waybill", "uuid": "waybill-uuid-1"}
],
},
}
)
@@ -1,6 +1,7 @@
from app.domain.payment_notifications import (
TBankPaymentNotificationAction,
resolve_tbank_payment_notification_action,
should_apply_tbank_payment_status,
)
@@ -53,3 +54,27 @@ def test_unknown_status_acknowledges_only() -> None:
)
assert result is TBankPaymentNotificationAction.ACKNOWLEDGE_ONLY
def test_authorized_does_not_downgrade_confirmed() -> None:
assert should_apply_tbank_payment_status("CONFIRMED", "AUTHORIZED") is False
def test_confirmed_overwrites_authorized() -> None:
assert should_apply_tbank_payment_status("AUTHORIZED", "CONFIRMED") is True
def test_first_status_always_applies() -> None:
assert should_apply_tbank_payment_status(None, "AUTHORIZED") is True
def test_same_status_applies() -> None:
assert should_apply_tbank_payment_status("CONFIRMED", "CONFIRMED") is True
def test_refund_overwrites_confirmed() -> None:
assert should_apply_tbank_payment_status("CONFIRMED", "REFUNDED") is True
def test_unknown_status_does_not_overwrite_known() -> None:
assert should_apply_tbank_payment_status("CONFIRMED", "WAT") is False
+27
View File
@@ -24,6 +24,33 @@ def test_application_log_is_serialized_as_json() -> None:
_reset_logging()
def test_structured_context_is_preserved_and_rendered_in_event() -> None:
stream = StringIO()
configure_logging(stream=stream)
structlog.get_logger("app.test").warning(
"application_event",
order_uuid="order-1",
attempt=2,
retryable=True,
details={"code": "invalid"},
)
payload = json.loads(stream.getvalue().splitlines()[0])
assert payload["event"] == (
'application_event attempt=2 details={"code":"invalid"} '
'order_uuid="order-1" retryable=true'
)
assert payload["order_uuid"] == "order-1"
assert payload["attempt"] == 2
assert payload["retryable"] is True
assert payload["details"] == {"code": "invalid"}
_reset_logging()
def test_uvicorn_loggers_use_shared_json_logging_setup() -> None:
stream = StringIO()
+3 -1
View File
@@ -136,7 +136,9 @@ class StubOrderRepository:
def session(self) -> StubSession:
return StubSession()
async def get_order_by_order_uuid(self, session: object, order_uuid: str) -> StoredOrder:
async def get_order_by_order_uuid(
self, session: object, order_uuid: str, *, for_update: bool = False
) -> StoredOrder:
return self._order
async def mark_payment_status(
@@ -90,6 +90,8 @@ class StubOrderRepository:
self,
session: object,
order_uuid: str,
*,
for_update: bool = False,
) -> StoredOrder | None:
self.calls.append(("get_order_by_order_uuid", (session, order_uuid)))
return self._orders.get(order_uuid)