fix(tradein/scrapers): метка наблюдения — время строки, а не старта транзакции (#2731) #2742

Merged

bot-backend merged 1 commit from fix/2731-clock-timestamp-content into main

2026-08-06 16:19:57 +00:00

bot-backend commented

2026-08-06 16:13:03 +00:00

Collaborator

Что

observed_at / scraped_at / last_seen_at писались NOW() == transaction_timestamp(). Писатель объявлений коммитит ОДИН раз в конце batch'а, поэтому все строки вызова несли одну метку.

Замер на проде 2026-08-06 (строк / различных меток):

писатель	колонка	замер	схлопывается
save_listings	`listings_snapshots.observed_at`	run 3303 — 219/1 (7 мин работы), 3299 — 235/1, 3229 — 2643/55	да
save_listings	`listings.scraped_at` / `last_seen_at`	по часам 219/1, 235/1, 297/1; eq == rows во всех корзинах	да
detail-писатели (4 провайдера)	`listings.detail_enriched_at`	153/153, 97/97, 19/19	нет — коммит поштучный
listing_source_snapshot	`listing_source_snapshots.observed_at`	89827/1	да, но ЧЕСТНО (один statement)
sber_index	`sber_price_index.fetched_at`	639/9	да, но ЧЕСТНО (одна выкачка = много строк)

Соразмерность

Фильтры свежести и TTL не искажены: смещение равно длительности прогона (минуты; худший случай 17.3 ч у cian_full_load) против окна 14 суток — 0.03-5%. Формулировка «долгие прогоны ломают фильтр свежести» проверена и снята.

Настоящая цена — разрешение во времени: темп сбора и порядок строк внутри прогона по данным не восстановить (отсюда же следовала невозможность бэкфилла run_id, #2701).

Почему `statement_timestamp()`, а не `clock_timestamp()` как в #2702/#2718

Здесь одним statement'ом пишутся ДВЕ колонки, обязанные совпадать: после #2206 scraped_at = last_seen_at у 100% строк, и на этом равенстве стоит предикат миграции 161 (WHERE last_seen_at > scraped_at как признак «видели живым, но не пере-скрейпили»). Проверено на проде:

clock_timestamp() = clock_timestamp()          -> f
statement_timestamp() = statement_timestamp()  -> t

clock_timestamp() развёл бы колонки на микросекунды — создал бы расхождение там, где его сейчас нет. statement_timestamp() при этом двигается от запроса к запросу внутри одной транзакции (замер: 1.2 с между соседними запросами при неподвижном now()), а каждый upsert объявления — свой запрос.

Что НЕ тронуто и почему

Set-based писатели (listing_source_snapshots — 89 827 строк одним INSERT … SELECT; deactivate_stale_avito — data-modifying CTE) оставлены на now(): там одна метка — правда о statement'е. clock_timestamp() дал бы ложное разрешение — на проде count(DISTINCT clock_timestamp()) по 200 000 строк одного statement'а = 27 783 значения, кодирующих порядок обработки строк планировщиком, а не порядок наблюдения.

detail_enriched_at не менялся: замер показал, что он НЕ схлопывается (коммит поштучный) — правка была бы холостой.

Потребители, опирающиеся на схлопнутость

Не найдено. observed_at вообще не читается ни бэкендом, ни фронтом (только писатели). Ни одного GROUP BY/DISTINCT по этим колонкам в коде нет. Единственное место, зависящее от ОТНОШЕНИЯ колонок, — миграция 161 (last_seen_at > scraped_at), и её инвариант сохранён выбором statement_timestamp().

Историческая граница

Миграция 232 — только COMMENT ON COLUMN (идемпотентна, данных не трогает): фиксирует дату перехода (#2731, 2026-08-06) в комментарии каждой из трёх колонок и то, что исторические строки невосстановимы — внутрипрогонное время нигде больше не сохранялось.

Test plan

tests/test_2731_observation_timestamps.py — модель БД на трёх функциях времени: писатель, отработавший дольше секунды, оставляет РАЗЛИЧНЫЕ метки у строк, и scraped_at == last_seen_at внутри строки
Фальсификация: на старом коде (NOW()) падают 3 из 5 тестов (обе поведенческие + инвариант источника)
«Починка» через clock_timestamp() тоже падает — модель воспроизводит разброс двух вызовов в одном statement'е
Полный прогон backend-сьюта: 3863 passed, 10 skipped
Прод: дождаться городского обхода Циана и показать, что у его строк метки различны

Refs #2731

## Что `observed_at` / `scraped_at` / `last_seen_at` писались `NOW()` == `transaction_timestamp()`. Писатель объявлений коммитит ОДИН раз в конце batch'а, поэтому все строки вызова несли одну метку. Замер на проде 2026-08-06 (строк / различных меток): | писатель | колонка | замер | схлопывается | |---|---|---|---| | save_listings | `listings_snapshots.observed_at` | run 3303 — 219/1 (7 мин работы), 3299 — 235/1, 3229 — 2643/55 | да | | save_listings | `listings.scraped_at` / `last_seen_at` | по часам 219/1, 235/1, 297/1; eq == rows во всех корзинах | да | | detail-писатели (4 провайдера) | `listings.detail_enriched_at` | 153/153, 97/97, 19/19 | **нет** — коммит поштучный | | listing_source_snapshot | `listing_source_snapshots.observed_at` | 89827/1 | да, но ЧЕСТНО (один statement) | | sber_index | `sber_price_index.fetched_at` | 639/9 | да, но ЧЕСТНО (одна выкачка = много строк) | ## Соразмерность Фильтры свежести и TTL **не искажены**: смещение равно длительности прогона (минуты; худший случай 17.3 ч у `cian_full_load`) против окна 14 суток — 0.03-5%. Формулировка «долгие прогоны ломают фильтр свежести» проверена и снята. Настоящая цена — разрешение во времени: темп сбора и порядок строк внутри прогона по данным не восстановить (отсюда же следовала невозможность бэкфилла `run_id`, #2701). ## Почему `statement_timestamp()`, а не `clock_timestamp()` как в #2702/#2718 Здесь одним statement'ом пишутся ДВЕ колонки, обязанные совпадать: после #2206 `scraped_at = last_seen_at` у 100% строк, и на этом равенстве стоит предикат миграции 161 (`WHERE last_seen_at > scraped_at` как признак «видели живым, но не пере-скрейпили»). Проверено на проде: ``` clock_timestamp() = clock_timestamp() -> f statement_timestamp() = statement_timestamp() -> t ``` `clock_timestamp()` развёл бы колонки на микросекунды — создал бы расхождение там, где его сейчас нет. `statement_timestamp()` при этом двигается от запроса к запросу внутри одной транзакции (замер: 1.2 с между соседними запросами при неподвижном `now()`), а каждый upsert объявления — свой запрос. ## Что НЕ тронуто и почему Set-based писатели (`listing_source_snapshots` — 89 827 строк одним `INSERT … SELECT`; `deactivate_stale_avito` — data-modifying CTE) оставлены на `now()`: там одна метка — правда о statement'е. `clock_timestamp()` дал бы ложное разрешение — на проде `count(DISTINCT clock_timestamp())` по 200 000 строк одного statement'а = 27 783 значения, кодирующих порядок обработки строк планировщиком, а не порядок наблюдения. `detail_enriched_at` не менялся: замер показал, что он НЕ схлопывается (коммит поштучный) — правка была бы холостой. ## Потребители, опирающиеся на схлопнутость Не найдено. `observed_at` вообще не читается ни бэкендом, ни фронтом (только писатели). Ни одного `GROUP BY`/`DISTINCT` по этим колонкам в коде нет. Единственное место, зависящее от ОТНОШЕНИЯ колонок, — миграция 161 (`last_seen_at > scraped_at`), и её инвариант сохранён выбором `statement_timestamp()`. ## Историческая граница Миграция 232 — только `COMMENT ON COLUMN` (идемпотентна, данных не трогает): фиксирует дату перехода (#2731, 2026-08-06) в комментарии каждой из трёх колонок и то, что исторические строки **невосстановимы** — внутрипрогонное время нигде больше не сохранялось. ## Test plan - [x] `tests/test_2731_observation_timestamps.py` — модель БД на трёх функциях времени: писатель, отработавший дольше секунды, оставляет РАЗЛИЧНЫЕ метки у строк, и `scraped_at == last_seen_at` внутри строки - [x] Фальсификация: на старом коде (`NOW()`) падают 3 из 5 тестов (обе поведенческие + инвариант источника) - [x] «Починка» через `clock_timestamp()` тоже падает — модель воспроизводит разброс двух вызовов в одном statement'е - [x] Полный прогон backend-сьюта: 3863 passed, 10 skipped - [ ] Прод: дождаться городского обхода Циана и показать, что у его строк метки различны Refs #2731

bot-backend added 1 commit 2026-08-06 16:13:04 +00:00

fix(tradein/scrapers): метка наблюдения — время строки, а не старта транзакции (#2731 )

CI / changes (pull_request) Successful in 13s

Details

CI Trade-In / changes (pull_request) Successful in 13s

Details

CI Trade-In / browser-tests (pull_request) Has been skipped

Details

CI Trade-In / frontend-checks (pull_request) Has been skipped

Details

CI / backend-tests (pull_request) Has been skipped

Details

CI / frontend-tests (pull_request) Has been skipped

Details

CI / openapi-codegen-check (pull_request) Has been skipped

Details

CI Trade-In / backend-tests (pull_request) Successful in 3m36s

Details

54714f0aa2

save_listings и upsert_listing_snapshot писали observed_at/scraped_at/last_seen_at
через NOW() == transaction_timestamp(). Коммит у писателя один, в конце всего batch'а,
поэтому все строки вызова несли одну метку: прод 2026-08-06 — run 3303 219 строк на
1 метку при семи минутах работы, run 3229 2643 строки на 55 меток (метка на вызов
save_listings, не на строку).

Цена — не фильтры свежести: смещение равно длительности прогона (минуты; худший
случай 17.3 ч у cian_full_load) против окна в 14 суток, то есть 0.03-5%. Теряется
разрешение во времени — темп сбора и порядок строк внутри прогона по данным не
восстановить, отсюда же следовала невозможность бэкфилла run_id (#2701).

statement_timestamp(), а НЕ clock_timestamp() как в #2702/#2718: здесь одним
statement'ом пишутся ДВЕ колонки, обязанные совпадать (после #2206 scraped_at =
last_seen_at у 100% строк, на этом равенстве стоит предикат миграции 161).
Прод-проверка: clock_timestamp() = clock_timestamp() → false, а
statement_timestamp() = statement_timestamp() → true; при этом statement_timestamp()
двигается от запроса к запросу внутри одной транзакции, а каждый upsert — свой запрос.

Set-based писатели (listing_source_snapshots 89827 строк одним statement'ом,
deactivate_stale_avito) намеренно НЕ тронуты: там одна метка — правда о statement'е,
а clock_timestamp() дал бы ложное разрешение (прод: 27783 разных значения на 200000
строк одного statement'а, кодирующих порядок обработки, а не наблюдения).

Миграция 232 — только COMMENT ON COLUMN: фиксирует дату перехода и то, что
исторические строки невосстановимы (внутрипрогонное время нигде не сохранялось).

Refs #2731