2025-12-12 10:05:19,637 - INFO - ya.test.2060683  - pytest_runtest_setup: ####################################################################################################
2025-12-12 10:05:19,665 - INFO - ya.test.2060683  - pytest_runtest_setup: test_lost_update_on_value_with_upsert_p4
2025-12-12 10:05:19,700 - INFO - ya.test.2060683  - pytest_runtest_setup: ####################################################################################################
2025-12-12 10:05:19,701 - INFO - ya.test.2060683  - pytest_runtest_setup: Test setup
2025-12-12 10:05:19,710 - INFO - ya.test.2060683  - pytest_runtest_call: Test call (class_name: test_isolation.py::TestTransactionIsolation, test_name: test_lost_update_on_value_with_upsert_p4)
2025-12-12 10:05:19,723 - DEBUG - ydb.connection.2060683  - _prepare_call: RpcState(CreateSession, 34368b17-68fc-4df0-9d17-271bfcb1a09b, ghrun-llwi4fnhxu.auto.internal:27863): creating call state
2025-12-12 10:05:19,734 - DEBUG - ydb.connection.2060683  - _log_request: RpcState(CreateSession, 34368b17-68fc-4df0-9d17-271bfcb1a09b, ghrun-llwi4fnhxu.auto.internal:27863): request = { operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-12-12 10:05:19,742 - DEBUG - ydb.connection.2060683  - _log_response: RpcState(CreateSession, 34368b17-68fc-4df0-9d17-271bfcb1a09b, ghrun-llwi4fnhxu.auto.internal:27863): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=1&id=NWRlMDJlODctZmM5YzYyMWUtYzFmYjNiMjEtOGQ1YjgzMzQ=" } } } }
2025-12-12 10:05:19,743 - DEBUG - ydb.connection.2060683  - _prepare_call: RpcState(ExecuteSchemeQuery, e26f3a33-c1d6-4180-b4f9-215dd3691749, ghrun-llwi4fnhxu.auto.internal:27863): creating call state
2025-12-12 10:05:19,749 - DEBUG - ydb.connection.2060683  - _log_request: RpcState(ExecuteSchemeQuery, e26f3a33-c1d6-4180-b4f9-215dd3691749, ghrun-llwi4fnhxu.auto.internal:27863): request = { session_id: "ydb://session/3?node_id=1&id=NWRlMDJlODctZmM5YzYyMWUtYzFmYjNiMjEtOGQ1YjgzMzQ=" yql_text: "create table test_lost_update_on_value_with_upsert_p4 (id Int32, value Int32, primary key(id)); " operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-12-12 10:05:19,831 - DEBUG - ydb.connection.2060683  - _log_response: RpcState(ExecuteSchemeQuery, e26f3a33-c1d6-4180-b4f9-215dd3691749, ghrun-llwi4fnhxu.auto.internal:27863): response = { operation { ready: true status: SUCCESS } }
2025-12-12 10:05:19,833 - DEBUG - ydb.connection.2060683  - _prepare_call: RpcState(ExecuteDataQuery, 6c680841-965b-49e2-90df-37172f641da4, ghrun-llwi4fnhxu.auto.internal:27863): creating call state
2025-12-12 10:05:19,833 - DEBUG - ydb.connection.2060683  - _log_request: RpcState(ExecuteDataQuery, 6c680841-965b-49e2-90df-37172f641da4, ghrun-llwi4fnhxu.auto.internal:27863): request = { session_id: "ydb://session/3?node_id=1&id=NWRlMDJlODctZmM5YzYyMWUtYzFmYjNiMjEtOGQ1YjgzMzQ=" tx_control { begin_tx { serializable_read_write { } } commit_tx: true } query { yql_text: "upsert into test_lost_update_on_value_with_upsert_p4 (id, value) values (1, 10), (2, 20); " } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-12-12 10:05:19,870 - DEBUG - ydb.connection.2060683  - _log_response: RpcState(ExecuteDataQuery, 6c680841-965b-49e2-90df-37172f641da4, ghrun-llwi4fnhxu.auto.internal:27863): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { tx_meta { } } } } }
2025-12-12 10:05:19,873 - DEBUG - ydb.connection.2060683  - _prepare_call: RpcState(ExecuteDataQuery, e9a484d2-d54a-430c-bf48-6ed412f88a56, ghrun-llwi4fnhxu.auto.internal:27863): creating call state
2025-12-12 10:05:19,877 - DEBUG - ydb.connection.2060683  - _log_request: RpcState(ExecuteDataQuery, e9a484d2-d54a-430c-bf48-6ed412f88a56, ghrun-llwi4fnhxu.auto.internal:27863): request = { session_id: "ydb://session/3?node_id=1&id=NWRlMDJlODctZmM5YzYyMWUtYzFmYjNiMjEtOGQ1YjgzMzQ=" tx_control { begin_tx { serializable_read_write { } } } query { yql_text: " select id, value from test_lost_update_on_value_with_upsert_p4 where id = 1;" } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-12-12 10:05:19,908 - DEBUG - ydb.connection.2060683  - _log_response: RpcState(ExecuteDataQuery, e9a484d2-d54a-430c-bf48-6ed412f88a56, ghrun-llwi4fnhxu.auto.internal:27863): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { result_sets { columns { name: "id" type { optional_type { item { type_id: INT32 } } } } columns { name: "value" type { optional_type { item { type_id: INT32 } } } } rows { items { int32_value: 1 } items { int32_value: 10 } } format: FORMAT_VALUE } tx_meta { id: "01kc90ban09td79z27szwcdqrq" } } } } }
2025-12-12 10:05:19,910 - DEBUG - ydb.connection.2060683  - _prepare_call: RpcState(ExecuteDataQuery, aaccf61a-3fae-4922-b617-0204df70f882, ghrun-llwi4fnhxu.auto.internal:27863): creating call state
2025-12-12 10:05:19,915 - DEBUG - ydb.connection.2060683  - _log_request: RpcState(ExecuteDataQuery, aaccf61a-3fae-4922-b617-0204df70f882, ghrun-llwi4fnhxu.auto.internal:27863): request = { session_id: "ydb://session/3?node_id=1&id=NWRlMDJlODctZmM5YzYyMWUtYzFmYjNiMjEtOGQ1YjgzMzQ=" tx_control { begin_tx { serializable_read_write { } } } query { yql_text: " select id, value from test_lost_update_on_value_with_upsert_p4 where id = 1;" } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-12-12 10:05:19,939 - DEBUG - ydb.connection.2060683  - _log_response: RpcState(ExecuteDataQuery, aaccf61a-3fae-4922-b617-0204df70f882, ghrun-llwi4fnhxu.auto.internal:27863): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { result_sets { columns { name: "id" type { optional_type { item { type_id: INT32 } } } } columns { name: "value" type { optional_type { item { type_id: INT32 } } } } rows { items { int32_value: 1 } items { int32_value: 10 } } format: FORMAT_VALUE } tx_meta { id: "01kc90bap02975164y77zvnp86" } } } } }
2025-12-12 10:05:19,977 - DEBUG - ydb.connection.2060683  - _prepare_call: RpcState(ExecuteDataQuery, 68ac2ccf-3fb7-4fb8-bcd8-58b89e443b1e, ghrun-llwi4fnhxu.auto.internal:27863): creating call state
2025-12-12 10:05:19,980 - DEBUG - ydb.connection.2060683  - _log_request: RpcState(ExecuteDataQuery, 68ac2ccf-3fb7-4fb8-bcd8-58b89e443b1e, ghrun-llwi4fnhxu.auto.internal:27863): request = { session_id: "ydb://session/3?node_id=1&id=NWRlMDJlODctZmM5YzYyMWUtYzFmYjNiMjEtOGQ1YjgzMzQ=" tx_control { tx_id: "01kc90ban09td79z27szwcdqrq" } query { yql_text: " upsert into test_lost_update_on_value_with_upsert_p4 (id, value) VALUES (1, 11);" } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-12-12 10:05:20,000 - DEBUG - ydb.connection.2060683  - _log_response: RpcState(ExecuteDataQuery, 68ac2ccf-3fb7-4fb8-bcd8-58b89e443b1e, ghrun-llwi4fnhxu.auto.internal:27863): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { tx_meta { id: "01kc90ban09td79z27szwcdqrq" } } } } }
2025-12-12 10:05:20,001 - DEBUG - ydb.connection.2060683  - _prepare_call: RpcState(CommitTransaction, 764f1b7b-f09f-4838-aea7-d38c2fb2d305, ghrun-llwi4fnhxu.auto.internal:27863): creating call state
2025-12-12 10:05:20,002 - DEBUG - ydb.connection.2060683  - _log_request: RpcState(CommitTransaction, 764f1b7b-f09f-4838-aea7-d38c2fb2d305, ghrun-llwi4fnhxu.auto.internal:27863): request = { session_id: "ydb://session/3?node_id=1&id=NWRlMDJlODctZmM5YzYyMWUtYzFmYjNiMjEtOGQ1YjgzMzQ=" tx_id: "01kc90ban09td79z27szwcdqrq" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-12-12 10:05:20,015 - DEBUG - ydb.connection.2060683  - _log_response: RpcState(CommitTransaction, 764f1b7b-f09f-4838-aea7-d38c2fb2d305, ghrun-llwi4fnhxu.auto.internal:27863): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CommitTransactionResult] { } } } }
2025-12-12 10:05:20,016 - DEBUG - ydb.connection.2060683  - _prepare_call: RpcState(ExecuteDataQuery, 0c955f7b-00f3-4095-a11a-9b51e5948c0c, ghrun-llwi4fnhxu.auto.internal:27863): creating call state
2025-12-12 10:05:20,017 - DEBUG - ydb.connection.2060683  - _log_request: RpcState(ExecuteDataQuery, 0c955f7b-00f3-4095-a11a-9b51e5948c0c, ghrun-llwi4fnhxu.auto.internal:27863): request = { session_id: "ydb://session/3?node_id=1&id=NWRlMDJlODctZmM5YzYyMWUtYzFmYjNiMjEtOGQ1YjgzMzQ=" tx_control { tx_id: "01kc90bap02975164y77zvnp86" } query { yql_text: " upsert into test_lost_update_on_value_with_upsert_p4 (id, value) VALUES (1, 12);" } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-12-12 10:05:20,044 - DEBUG - ydb.connection.2060683  - _log_response: RpcState(ExecuteDataQuery, 0c955f7b-00f3-4095-a11a-9b51e5948c0c, ghrun-llwi4fnhxu.auto.internal:27863): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { tx_meta { id: "01kc90bap02975164y77zvnp86" } } } } }
2025-12-12 10:05:20,048 - DEBUG - ydb.connection.2060683  - _prepare_call: RpcState(CommitTransaction, 243c02bd-18d9-431b-845e-661278ae6589, ghrun-llwi4fnhxu.auto.internal:27863): creating call state
2025-12-12 10:05:20,048 - DEBUG - ydb.connection.2060683  - _log_request: RpcState(CommitTransaction, 243c02bd-18d9-431b-845e-661278ae6589, ghrun-llwi4fnhxu.auto.internal:27863): request = { session_id: "ydb://session/3?node_id=1&id=NWRlMDJlODctZmM5YzYyMWUtYzFmYjNiMjEtOGQ1YjgzMzQ=" tx_id: "01kc90bap02975164y77zvnp86" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-12-12 10:05:20,057 - DEBUG - ydb.connection.2060683  - _log_response: RpcState(CommitTransaction, 243c02bd-18d9-431b-845e-661278ae6589, ghrun-llwi4fnhxu.auto.internal:27863): response = { operation { ready: true status: ABORTED issues { message: "Transaction locks invalidated. Table: `/Root/test_lost_update_on_value_with_upsert_p4`." issue_code: 2001 severity: 1 issues { message: "Operation is aborting because locks are not valid" issue_code: 2001 severity: 1 } } } }
2025-12-12 10:05:20,079 - INFO - ya.test.2060683  - pytest_runtest_teardown: Test teardown
