2025-11-21 17:39:35,536 - INFO - ya.test.671317  - pytest_runtest_setup: ####################################################################################################
2025-11-21 17:39:35,542 - INFO - ya.test.671317  - pytest_runtest_setup: test_all_supported_compression[zstd_9_compression-COMPRESSION = "zstd", COMPRESSION_LEVEL = 9]
2025-11-21 17:39:35,543 - INFO - ya.test.671317  - pytest_runtest_setup: ####################################################################################################
2025-11-21 17:39:35,543 - INFO - ya.test.671317  - pytest_runtest_setup: Test setup
2025-11-21 17:39:35,550 - INFO - ya.test.671317  - pytest_runtest_call: Test call (class_name: alter_compression.py::TestAllCompression, test_name: test_all_supported_compression[zstd_9_compression-COMPRESSION = "zstd", COMPRESSION_LEVEL = 9])
2025-11-21 17:39:35,551 - DEBUG - ydb.query.pool.671317  - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:39:35,552 - DEBUG - ydb.connection.671317  - _prepare_call: RpcState(ExecuteQuery, 430da407-3170-4852-bce6-8071a94466fe, ghrun-zme4sewyte.auto.internal:32388): creating call state
2025-11-21 17:39:35,553 - DEBUG - ydb.connection.671317  - _log_request: RpcState(ExecuteQuery, 430da407-3170-4852-bce6-8071a94466fe, ghrun-zme4sewyte.auto.internal:32388): request = { session_id: "ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "\n                CREATE TABLE `/Root/all_compression/all_supported_compression/zstd_9_compression` (\n                    value Uint64 NOT NULL,\n                    value1 Uint64,\n                    PRIMARY KEY(value),\n                    FAMILY default (COMPRESSION = \"zstd\", COMPRESSION_LEVEL = 9)\n                )\n                WITH (STORE = COLUMN)\n                " } stats_mode: STATS_MODE_NONE }
2025-11-21 17:39:35,556 - DEBUG - ydb.connection.671317  - _log_response: RpcState(ExecuteQuery, 430da407-3170-4852-bce6-8071a94466fe, ghrun-zme4sewyte.auto.internal:32388): response = { <_MultiThreadedRendezvous object> }
2025-11-21 17:39:39,843 - DEBUG - ydb.query.pool.671317  - release: Session returned to queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:39:39,844 - INFO - __tests__.alter_compression.671317  - test_all_supported_compression: Table /Root/all_compression/all_supported_compression/zstd_9_compression created
2025-11-21 17:39:39,844 - DEBUG - ydb.query.pool.671317  - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:39:39,845 - DEBUG - ydb.connection.671317  - _prepare_call: RpcState(ExecuteQuery, 1d8a7a5d-20be-4cc9-9e0c-697e34b5ca5f, ghrun-zme4sewyte.auto.internal:32388): creating call state
2025-11-21 17:39:39,846 - DEBUG - ydb.connection.671317  - _log_request: RpcState(ExecuteQuery, 1d8a7a5d-20be-4cc9-9e0c-697e34b5ca5f, ghrun-zme4sewyte.auto.internal:32388): request = { session_id: "ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) AS Rows FROM `/Root/all_compression/all_supported_compression/zstd_9_compression`" } stats_mode: STATS_MODE_NONE }
2025-11-21 17:39:39,855 - DEBUG - ydb.connection.671317  - _log_response: RpcState(ExecuteQuery, 1d8a7a5d-20be-4cc9-9e0c-697e34b5ca5f, ghrun-zme4sewyte.auto.internal:32388): response = { <_MultiThreadedRendezvous object> }
2025-11-21 17:39:41,433 - DEBUG - ydb.query.pool.671317  - release: Session returned to queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:39:41,434 - DEBUG - ydb.query.pool.671317  - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:39:41,435 - DEBUG - ydb.connection.671317  - _prepare_call: RpcState(ExecuteQuery, 5d3c4756-7b6e-4daf-8142-a19ade1f3b89, ghrun-zme4sewyte.auto.internal:32388): creating call state
2025-11-21 17:39:41,436 - DEBUG - ydb.connection.671317  - _log_request: RpcState(ExecuteQuery, 5d3c4756-7b6e-4daf-8142-a19ade1f3b89, ghrun-zme4sewyte.auto.internal:32388): request = { session_id: "ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "\n                $row_count = 100000;\n                $prev_count = 0;\n                $rows= ListMap(ListFromRange(0, $row_count), ($i) -> {\n                    return <|\n                        value: $i + $prev_count,\n                        value1: $i + $prev_count,\n                    |>;\n                });\n                UPSERT INTO `/Root/all_compression/all_supported_compression/zstd_9_compression`\n                SELECT * FROM AS_TABLE($rows);\n            " } stats_mode: STATS_MODE_NONE }
2025-11-21 17:39:41,440 - DEBUG - ydb.connection.671317  - _log_response: RpcState(ExecuteQuery, 5d3c4756-7b6e-4daf-8142-a19ade1f3b89, ghrun-zme4sewyte.auto.internal:32388): response = { <_MultiThreadedRendezvous object> }
2025-11-21 17:39:44,030 - DEBUG - ydb.query.pool.671317  - release: Session returned to queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:39:44,031 - DEBUG - ydb.query.pool.671317  - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:39:44,032 - DEBUG - ydb.connection.671317  - _prepare_call: RpcState(ExecuteQuery, aea7c26c-74fd-4daf-bc9a-0cbf2f75c65c, ghrun-zme4sewyte.auto.internal:32388): creating call state
2025-11-21 17:39:44,033 - DEBUG - ydb.connection.671317  - _log_request: RpcState(ExecuteQuery, aea7c26c-74fd-4daf-bc9a-0cbf2f75c65c, ghrun-zme4sewyte.auto.internal:32388): request = { session_id: "ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "select TierName, sum(Rows) as Rows, count(*) as Portions from `/Root/all_compression/all_supported_compression/zstd_9_compression/.sys/primary_index_portion_stats` group by TierName" } stats_mode: STATS_MODE_NONE }
2025-11-21 17:39:44,035 - DEBUG - ydb.connection.671317  - _log_response: RpcState(ExecuteQuery, aea7c26c-74fd-4daf-bc9a-0cbf2f75c65c, ghrun-zme4sewyte.auto.internal:32388): response = { <_MultiThreadedRendezvous object> }
2025-11-21 17:39:45,549 - DEBUG - ydb.query.pool.671317  - release: Session returned to queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:39:45,550 - DEBUG - ydb.query.pool.671317  - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:39:45,557 - DEBUG - ydb.connection.671317  - _prepare_call: RpcState(ExecuteQuery, 6c1bd1c6-e751-4c46-b044-f2c54f6c631c, ghrun-zme4sewyte.auto.internal:32388): creating call state
2025-11-21 17:39:45,558 - DEBUG - ydb.connection.671317  - _log_request: RpcState(ExecuteQuery, 6c1bd1c6-e751-4c46-b044-f2c54f6c631c, ghrun-zme4sewyte.auto.internal:32388): request = { session_id: "ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "\n            select TierName, count(*) as Portions, sum(BlobSize) as BlobSize, sum(BlobCount) as BlobCount from (\n                select TabletId, PortionId, TierName, sum(BlobRangeSize) as BlobSize, count(*) as BlobCount from `/Root/all_compression/all_supported_compression/zstd_9_compression/.sys/primary_index_stats` group by TabletId, PortionId, TierName\n            ) group by TierName\n        " } stats_mode: STATS_MODE_NONE }
2025-11-21 17:39:45,560 - DEBUG - ydb.connection.671317  - _log_response: RpcState(ExecuteQuery, 6c1bd1c6-e751-4c46-b044-f2c54f6c631c, ghrun-zme4sewyte.auto.internal:32388): response = { <_MultiThreadedRendezvous object> }
2025-11-21 17:39:47,928 - DEBUG - ydb.query.pool.671317  - release: Session returned to queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:39:47,928 - INFO - __tests__.alter_compression.671317  - upsert_and_wait_portions: 100000 rows in /Root/all_compression/all_supported_compression/zstd_9_compression. portions: {'__DEFAULT': {'Rows': 100000, 'Portions': 64}}, blobs: {'__DEFAULT': {'Portions': 64, 'BlobSize': 318048, 'BlobCount': 128}}
2025-11-21 17:39:47,929 - DEBUG - ydb.query.pool.671317  - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:39:47,930 - DEBUG - ydb.connection.671317  - _prepare_call: RpcState(ExecuteQuery, ac34b9ab-822d-4f61-97fd-e2a943b607ad, ghrun-zme4sewyte.auto.internal:32388): creating call state
2025-11-21 17:39:47,931 - DEBUG - ydb.connection.671317  - _log_request: RpcState(ExecuteQuery, ac34b9ab-822d-4f61-97fd-e2a943b607ad, ghrun-zme4sewyte.auto.internal:32388): request = { session_id: "ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "\n                $row_count = 100000;\n                $prev_count = 100000;\n                $rows= ListMap(ListFromRange(0, $row_count), ($i) -> {\n                    return <|\n                        value: $i + $prev_count,\n                        value1: $i + $prev_count,\n                    |>;\n                });\n                UPSERT INTO `/Root/all_compression/all_supported_compression/zstd_9_compression`\n                SELECT * FROM AS_TABLE($rows);\n            " } stats_mode: STATS_MODE_NONE }
2025-11-21 17:39:47,933 - DEBUG - ydb.connection.671317  - _log_response: RpcState(ExecuteQuery, ac34b9ab-822d-4f61-97fd-e2a943b607ad, ghrun-zme4sewyte.auto.internal:32388): response = { <_MultiThreadedRendezvous object> }
2025-11-21 17:39:50,010 - DEBUG - ydb.query.pool.671317  - release: Session returned to queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:39:50,011 - DEBUG - ydb.query.pool.671317  - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:39:50,012 - DEBUG - ydb.connection.671317  - _prepare_call: RpcState(ExecuteQuery, 862a4842-6d27-4c7f-b8ee-cc741f1e581d, ghrun-zme4sewyte.auto.internal:32388): creating call state
2025-11-21 17:39:50,013 - DEBUG - ydb.connection.671317  - _log_request: RpcState(ExecuteQuery, 862a4842-6d27-4c7f-b8ee-cc741f1e581d, ghrun-zme4sewyte.auto.internal:32388): request = { session_id: "ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "select TierName, sum(Rows) as Rows, count(*) as Portions from `/Root/all_compression/all_supported_compression/zstd_9_compression/.sys/primary_index_portion_stats` group by TierName" } stats_mode: STATS_MODE_NONE }
2025-11-21 17:39:50,015 - DEBUG - ydb.connection.671317  - _log_response: RpcState(ExecuteQuery, 862a4842-6d27-4c7f-b8ee-cc741f1e581d, ghrun-zme4sewyte.auto.internal:32388): response = { <_MultiThreadedRendezvous object> }
2025-11-21 17:39:50,464 - DEBUG - ydb.query.pool.671317  - release: Session returned to queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:39:50,465 - DEBUG - ydb.query.pool.671317  - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:39:50,466 - DEBUG - ydb.connection.671317  - _prepare_call: RpcState(ExecuteQuery, f59a5407-f54e-494f-90f0-6fb40ea4c588, ghrun-zme4sewyte.auto.internal:32388): creating call state
2025-11-21 17:39:50,467 - DEBUG - ydb.connection.671317  - _log_request: RpcState(ExecuteQuery, f59a5407-f54e-494f-90f0-6fb40ea4c588, ghrun-zme4sewyte.auto.internal:32388): request = { session_id: "ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "\n            select TierName, count(*) as Portions, sum(BlobSize) as BlobSize, sum(BlobCount) as BlobCount from (\n                select TabletId, PortionId, TierName, sum(BlobRangeSize) as BlobSize, count(*) as BlobCount from `/Root/all_compression/all_supported_compression/zstd_9_compression/.sys/primary_index_stats` group by TabletId, PortionId, TierName\n            ) group by TierName\n        " } stats_mode: STATS_MODE_NONE }
2025-11-21 17:39:50,468 - DEBUG - ydb.connection.671317  - _log_response: RpcState(ExecuteQuery, f59a5407-f54e-494f-90f0-6fb40ea4c588, ghrun-zme4sewyte.auto.internal:32388): response = { <_MultiThreadedRendezvous object> }
2025-11-21 17:39:50,875 - DEBUG - ydb.query.pool.671317  - release: Session returned to queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:39:50,876 - INFO - __tests__.alter_compression.671317  - upsert_and_wait_portions: 200000 rows in /Root/all_compression/all_supported_compression/zstd_9_compression. portions: {'__DEFAULT': {'Rows': 200000, 'Portions': 128}}, blobs: {'__DEFAULT': {'Portions': 128, 'BlobSize': 637344, 'BlobCount': 256}}
2025-11-21 17:39:50,877 - DEBUG - ydb.query.pool.671317  - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:39:50,877 - DEBUG - ydb.connection.671317  - _prepare_call: RpcState(ExecuteQuery, 225e7010-4003-4d22-9495-1f6367f8bbb9, ghrun-zme4sewyte.auto.internal:32388): creating call state
2025-11-21 17:39:50,879 - DEBUG - ydb.connection.671317  - _log_request: RpcState(ExecuteQuery, 225e7010-4003-4d22-9495-1f6367f8bbb9, ghrun-zme4sewyte.auto.internal:32388): request = { session_id: "ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "\n                $row_count = 100000;\n                $prev_count = 200000;\n                $rows= ListMap(ListFromRange(0, $row_count), ($i) -> {\n                    return <|\n                        value: $i + $prev_count,\n                        value1: $i + $prev_count,\n                    |>;\n                });\n                UPSERT INTO `/Root/all_compression/all_supported_compression/zstd_9_compression`\n                SELECT * FROM AS_TABLE($rows);\n            " } stats_mode: STATS_MODE_NONE }
2025-11-21 17:39:50,880 - DEBUG - ydb.connection.671317  - _log_response: RpcState(ExecuteQuery, 225e7010-4003-4d22-9495-1f6367f8bbb9, ghrun-zme4sewyte.auto.internal:32388): response = { <_MultiThreadedRendezvous object> }
2025-11-21 17:39:52,642 - DEBUG - ydb.query.pool.671317  - release: Session returned to queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:39:52,642 - DEBUG - ydb.query.pool.671317  - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:39:52,643 - DEBUG - ydb.connection.671317  - _prepare_call: RpcState(ExecuteQuery, 16cb2f81-91e4-4652-8285-51121727f0a0, ghrun-zme4sewyte.auto.internal:32388): creating call state
2025-11-21 17:39:52,644 - DEBUG - ydb.connection.671317  - _log_request: RpcState(ExecuteQuery, 16cb2f81-91e4-4652-8285-51121727f0a0, ghrun-zme4sewyte.auto.internal:32388): request = { session_id: "ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "select TierName, sum(Rows) as Rows, count(*) as Portions from `/Root/all_compression/all_supported_compression/zstd_9_compression/.sys/primary_index_portion_stats` group by TierName" } stats_mode: STATS_MODE_NONE }
2025-11-21 17:39:52,645 - DEBUG - ydb.connection.671317  - _log_response: RpcState(ExecuteQuery, 16cb2f81-91e4-4652-8285-51121727f0a0, ghrun-zme4sewyte.auto.internal:32388): response = { <_MultiThreadedRendezvous object> }
2025-11-21 17:39:53,006 - DEBUG - ydb.query.pool.671317  - release: Session returned to queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:39:53,007 - DEBUG - ydb.query.pool.671317  - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:39:53,008 - DEBUG - ydb.connection.671317  - _prepare_call: RpcState(ExecuteQuery, 7c57b578-6444-4884-b3a4-2c4ccef374f5, ghrun-zme4sewyte.auto.internal:32388): creating call state
2025-11-21 17:39:53,009 - DEBUG - ydb.connection.671317  - _log_request: RpcState(ExecuteQuery, 7c57b578-6444-4884-b3a4-2c4ccef374f5, ghrun-zme4sewyte.auto.internal:32388): request = { session_id: "ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "\n            select TierName, count(*) as Portions, sum(BlobSize) as BlobSize, sum(BlobCount) as BlobCount from (\n                select TabletId, PortionId, TierName, sum(BlobRangeSize) as BlobSize, count(*) as BlobCount from `/Root/all_compression/all_supported_compression/zstd_9_compression/.sys/primary_index_stats` group by TabletId, PortionId, TierName\n            ) group by TierName\n        " } stats_mode: STATS_MODE_NONE }
2025-11-21 17:39:53,012 - DEBUG - ydb.connection.671317  - _log_response: RpcState(ExecuteQuery, 7c57b578-6444-4884-b3a4-2c4ccef374f5, ghrun-zme4sewyte.auto.internal:32388): response = { <_MultiThreadedRendezvous object> }
2025-11-21 17:39:53,552 - DEBUG - ydb.query.pool.671317  - release: Session returned to queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:39:53,613 - INFO - __tests__.alter_compression.671317  - upsert_and_wait_portions: 300000 rows in /Root/all_compression/all_supported_compression/zstd_9_compression. portions: {'__DEFAULT': {'Rows': 300000, 'Portions': 192}}, blobs: {'__DEFAULT': {'Portions': 192, 'BlobSize': 956384, 'BlobCount': 384}}
2025-11-21 17:39:53,614 - DEBUG - ydb.query.pool.671317  - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:39:53,615 - DEBUG - ydb.connection.671317  - _prepare_call: RpcState(ExecuteQuery, fe65e109-6404-4f98-b4b4-83b1129e27e9, ghrun-zme4sewyte.auto.internal:32388): creating call state
2025-11-21 17:39:53,616 - DEBUG - ydb.connection.671317  - _log_request: RpcState(ExecuteQuery, fe65e109-6404-4f98-b4b4-83b1129e27e9, ghrun-zme4sewyte.auto.internal:32388): request = { session_id: "ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "\n                $row_count = 100000;\n                $prev_count = 300000;\n                $rows= ListMap(ListFromRange(0, $row_count), ($i) -> {\n                    return <|\n                        value: $i + $prev_count,\n                        value1: $i + $prev_count,\n                    |>;\n                });\n                UPSERT INTO `/Root/all_compression/all_supported_compression/zstd_9_compression`\n                SELECT * FROM AS_TABLE($rows);\n            " } stats_mode: STATS_MODE_NONE }
2025-11-21 17:39:53,617 - DEBUG - ydb.connection.671317  - _log_response: RpcState(ExecuteQuery, fe65e109-6404-4f98-b4b4-83b1129e27e9, ghrun-zme4sewyte.auto.internal:32388): response = { <_MultiThreadedRendezvous object> }
2025-11-21 17:39:55,527 - DEBUG - ydb.query.pool.671317  - release: Session returned to queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:39:55,528 - DEBUG - ydb.query.pool.671317  - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:39:55,529 - DEBUG - ydb.connection.671317  - _prepare_call: RpcState(ExecuteQuery, 55dda7fe-411d-42bb-a990-8cdf4b5f619c, ghrun-zme4sewyte.auto.internal:32388): creating call state
2025-11-21 17:39:55,530 - DEBUG - ydb.connection.671317  - _log_request: RpcState(ExecuteQuery, 55dda7fe-411d-42bb-a990-8cdf4b5f619c, ghrun-zme4sewyte.auto.internal:32388): request = { session_id: "ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "select TierName, sum(Rows) as Rows, count(*) as Portions from `/Root/all_compression/all_supported_compression/zstd_9_compression/.sys/primary_index_portion_stats` group by TierName" } stats_mode: STATS_MODE_NONE }
2025-11-21 17:39:55,531 - DEBUG - ydb.connection.671317  - _log_response: RpcState(ExecuteQuery, 55dda7fe-411d-42bb-a990-8cdf4b5f619c, ghrun-zme4sewyte.auto.internal:32388): response = { <_MultiThreadedRendezvous object> }
2025-11-21 17:39:55,804 - DEBUG - ydb.query.pool.671317  - release: Session returned to queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:39:55,805 - DEBUG - ydb.query.pool.671317  - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:39:55,806 - DEBUG - ydb.connection.671317  - _prepare_call: RpcState(ExecuteQuery, f46569ac-0f4a-42b1-acac-4f37396b5531, ghrun-zme4sewyte.auto.internal:32388): creating call state
2025-11-21 17:39:55,806 - DEBUG - ydb.connection.671317  - _log_request: RpcState(ExecuteQuery, f46569ac-0f4a-42b1-acac-4f37396b5531, ghrun-zme4sewyte.auto.internal:32388): request = { session_id: "ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "\n            select TierName, count(*) as Portions, sum(BlobSize) as BlobSize, sum(BlobCount) as BlobCount from (\n                select TabletId, PortionId, TierName, sum(BlobRangeSize) as BlobSize, count(*) as BlobCount from `/Root/all_compression/all_supported_compression/zstd_9_compression/.sys/primary_index_stats` group by TabletId, PortionId, TierName\n            ) group by TierName\n        " } stats_mode: STATS_MODE_NONE }
2025-11-21 17:39:55,807 - DEBUG - ydb.connection.671317  - _log_response: RpcState(ExecuteQuery, f46569ac-0f4a-42b1-acac-4f37396b5531, ghrun-zme4sewyte.auto.internal:32388): response = { <_MultiThreadedRendezvous object> }
2025-11-21 17:39:56,278 - DEBUG - ydb.query.pool.671317  - release: Session returned to queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:39:56,279 - INFO - __tests__.alter_compression.671317  - upsert_and_wait_portions: 400000 rows in /Root/all_compression/all_supported_compression/zstd_9_compression. portions: {'__DEFAULT': {'Rows': 400000, 'Portions': 256}}, blobs: {'__DEFAULT': {'Portions': 256, 'BlobSize': 1275744, 'BlobCount': 512}}
2025-11-21 17:39:56,279 - DEBUG - ydb.query.pool.671317  - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:39:56,280 - DEBUG - ydb.connection.671317  - _prepare_call: RpcState(ExecuteQuery, 7363ebc9-4b84-4ea1-ab5f-442dd3b72b69, ghrun-zme4sewyte.auto.internal:32388): creating call state
2025-11-21 17:39:56,280 - DEBUG - ydb.connection.671317  - _log_request: RpcState(ExecuteQuery, 7363ebc9-4b84-4ea1-ab5f-442dd3b72b69, ghrun-zme4sewyte.auto.internal:32388): request = { session_id: "ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "\n                $row_count = 100000;\n                $prev_count = 400000;\n                $rows= ListMap(ListFromRange(0, $row_count), ($i) -> {\n                    return <|\n                        value: $i + $prev_count,\n                        value1: $i + $prev_count,\n                    |>;\n                });\n                UPSERT INTO `/Root/all_compression/all_supported_compression/zstd_9_compression`\n                SELECT * FROM AS_TABLE($rows);\n            " } stats_mode: STATS_MODE_NONE }
2025-11-21 17:39:56,282 - DEBUG - ydb.connection.671317  - _log_response: RpcState(ExecuteQuery, 7363ebc9-4b84-4ea1-ab5f-442dd3b72b69, ghrun-zme4sewyte.auto.internal:32388): response = { <_MultiThreadedRendezvous object> }
2025-11-21 17:39:58,093 - DEBUG - ydb.query.pool.671317  - release: Session returned to queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:39:58,094 - DEBUG - ydb.query.pool.671317  - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:39:58,095 - DEBUG - ydb.connection.671317  - _prepare_call: RpcState(ExecuteQuery, 010e27de-6217-4db3-9c21-ead0f889b398, ghrun-zme4sewyte.auto.internal:32388): creating call state
2025-11-21 17:39:58,096 - DEBUG - ydb.connection.671317  - _log_request: RpcState(ExecuteQuery, 010e27de-6217-4db3-9c21-ead0f889b398, ghrun-zme4sewyte.auto.internal:32388): request = { session_id: "ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "select TierName, sum(Rows) as Rows, count(*) as Portions from `/Root/all_compression/all_supported_compression/zstd_9_compression/.sys/primary_index_portion_stats` group by TierName" } stats_mode: STATS_MODE_NONE }
2025-11-21 17:39:58,097 - DEBUG - ydb.connection.671317  - _log_response: RpcState(ExecuteQuery, 010e27de-6217-4db3-9c21-ead0f889b398, ghrun-zme4sewyte.auto.internal:32388): response = { <_MultiThreadedRendezvous object> }
2025-11-21 17:39:58,477 - DEBUG - ydb.query.pool.671317  - release: Session returned to queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:39:58,478 - DEBUG - ydb.query.pool.671317  - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:39:58,478 - DEBUG - ydb.connection.671317  - _prepare_call: RpcState(ExecuteQuery, 26f88eb2-fd58-4463-95fe-bce977a9f589, ghrun-zme4sewyte.auto.internal:32388): creating call state
2025-11-21 17:39:58,479 - DEBUG - ydb.connection.671317  - _log_request: RpcState(ExecuteQuery, 26f88eb2-fd58-4463-95fe-bce977a9f589, ghrun-zme4sewyte.auto.internal:32388): request = { session_id: "ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "\n            select TierName, count(*) as Portions, sum(BlobSize) as BlobSize, sum(BlobCount) as BlobCount from (\n                select TabletId, PortionId, TierName, sum(BlobRangeSize) as BlobSize, count(*) as BlobCount from `/Root/all_compression/all_supported_compression/zstd_9_compression/.sys/primary_index_stats` group by TabletId, PortionId, TierName\n            ) group by TierName\n        " } stats_mode: STATS_MODE_NONE }
2025-11-21 17:39:58,481 - DEBUG - ydb.connection.671317  - _log_response: RpcState(ExecuteQuery, 26f88eb2-fd58-4463-95fe-bce977a9f589, ghrun-zme4sewyte.auto.internal:32388): response = { <_MultiThreadedRendezvous object> }
2025-11-21 17:39:59,008 - DEBUG - ydb.query.pool.671317  - release: Session returned to queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:39:59,009 - INFO - __tests__.alter_compression.671317  - upsert_and_wait_portions: 500000 rows in /Root/all_compression/all_supported_compression/zstd_9_compression. portions: {'__DEFAULT': {'Rows': 500000, 'Portions': 320}}, blobs: {'__DEFAULT': {'Portions': 320, 'BlobSize': 1594704, 'BlobCount': 640}}
2025-11-21 17:39:59,009 - DEBUG - ydb.query.pool.671317  - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:39:59,010 - DEBUG - ydb.connection.671317  - _prepare_call: RpcState(ExecuteQuery, e0917bbd-6761-4aa3-9fd4-15f499c7d09e, ghrun-zme4sewyte.auto.internal:32388): creating call state
2025-11-21 17:39:59,011 - DEBUG - ydb.connection.671317  - _log_request: RpcState(ExecuteQuery, e0917bbd-6761-4aa3-9fd4-15f499c7d09e, ghrun-zme4sewyte.auto.internal:32388): request = { session_id: "ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "\n                $row_count = 100000;\n                $prev_count = 500000;\n                $rows= ListMap(ListFromRange(0, $row_count), ($i) -> {\n                    return <|\n                        value: $i + $prev_count,\n                        value1: $i + $prev_count,\n                    |>;\n                });\n                UPSERT INTO `/Root/all_compression/all_supported_compression/zstd_9_compression`\n                SELECT * FROM AS_TABLE($rows);\n            " } stats_mode: STATS_MODE_NONE }
2025-11-21 17:39:59,013 - DEBUG - ydb.connection.671317  - _log_response: RpcState(ExecuteQuery, e0917bbd-6761-4aa3-9fd4-15f499c7d09e, ghrun-zme4sewyte.auto.internal:32388): response = { <_MultiThreadedRendezvous object> }
2025-11-21 17:40:00,587 - DEBUG - ydb.query.pool.671317  - release: Session returned to queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:40:00,588 - DEBUG - ydb.query.pool.671317  - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:40:00,588 - DEBUG - ydb.connection.671317  - _prepare_call: RpcState(ExecuteQuery, 54b0e1d8-41a3-48b7-8077-c74f3ec8a473, ghrun-zme4sewyte.auto.internal:32388): creating call state
2025-11-21 17:40:00,589 - DEBUG - ydb.connection.671317  - _log_request: RpcState(ExecuteQuery, 54b0e1d8-41a3-48b7-8077-c74f3ec8a473, ghrun-zme4sewyte.auto.internal:32388): request = { session_id: "ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "select TierName, sum(Rows) as Rows, count(*) as Portions from `/Root/all_compression/all_supported_compression/zstd_9_compression/.sys/primary_index_portion_stats` group by TierName" } stats_mode: STATS_MODE_NONE }
2025-11-21 17:40:00,590 - DEBUG - ydb.connection.671317  - _log_response: RpcState(ExecuteQuery, 54b0e1d8-41a3-48b7-8077-c74f3ec8a473, ghrun-zme4sewyte.auto.internal:32388): response = { <_MultiThreadedRendezvous object> }
2025-11-21 17:40:00,869 - DEBUG - ydb.query.pool.671317  - release: Session returned to queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:40:00,870 - DEBUG - ydb.query.pool.671317  - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:40:00,871 - DEBUG - ydb.connection.671317  - _prepare_call: RpcState(ExecuteQuery, 9c5d892f-a017-4c10-ac46-d7a422a7e97f, ghrun-zme4sewyte.auto.internal:32388): creating call state
2025-11-21 17:40:00,871 - DEBUG - ydb.connection.671317  - _log_request: RpcState(ExecuteQuery, 9c5d892f-a017-4c10-ac46-d7a422a7e97f, ghrun-zme4sewyte.auto.internal:32388): request = { session_id: "ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "\n            select TierName, count(*) as Portions, sum(BlobSize) as BlobSize, sum(BlobCount) as BlobCount from (\n                select TabletId, PortionId, TierName, sum(BlobRangeSize) as BlobSize, count(*) as BlobCount from `/Root/all_compression/all_supported_compression/zstd_9_compression/.sys/primary_index_stats` group by TabletId, PortionId, TierName\n            ) group by TierName\n        " } stats_mode: STATS_MODE_NONE }
2025-11-21 17:40:00,873 - DEBUG - ydb.connection.671317  - _log_response: RpcState(ExecuteQuery, 9c5d892f-a017-4c10-ac46-d7a422a7e97f, ghrun-zme4sewyte.auto.internal:32388): response = { <_MultiThreadedRendezvous object> }
2025-11-21 17:40:01,434 - DEBUG - ydb.query.pool.671317  - release: Session returned to queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:40:01,435 - INFO - __tests__.alter_compression.671317  - upsert_and_wait_portions: 600000 rows in /Root/all_compression/all_supported_compression/zstd_9_compression. portions: {'__DEFAULT': {'Rows': 600000, 'Portions': 384}}, blobs: {'__DEFAULT': {'Portions': 384, 'BlobSize': 1913888, 'BlobCount': 768}}
2025-11-21 17:40:01,435 - DEBUG - ydb.query.pool.671317  - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:40:01,436 - DEBUG - ydb.connection.671317  - _prepare_call: RpcState(ExecuteQuery, eb580a3c-31d9-4c0a-9d32-d19c0febb736, ghrun-zme4sewyte.auto.internal:32388): creating call state
2025-11-21 17:40:01,437 - DEBUG - ydb.connection.671317  - _log_request: RpcState(ExecuteQuery, eb580a3c-31d9-4c0a-9d32-d19c0febb736, ghrun-zme4sewyte.auto.internal:32388): request = { session_id: "ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "\n                $row_count = 100000;\n                $prev_count = 600000;\n                $rows= ListMap(ListFromRange(0, $row_count), ($i) -> {\n                    return <|\n                        value: $i + $prev_count,\n                        value1: $i + $prev_count,\n                    |>;\n                });\n                UPSERT INTO `/Root/all_compression/all_supported_compression/zstd_9_compression`\n                SELECT * FROM AS_TABLE($rows);\n            " } stats_mode: STATS_MODE_NONE }
2025-11-21 17:40:01,439 - DEBUG - ydb.connection.671317  - _log_response: RpcState(ExecuteQuery, eb580a3c-31d9-4c0a-9d32-d19c0febb736, ghrun-zme4sewyte.auto.internal:32388): response = { <_MultiThreadedRendezvous object> }
2025-11-21 17:40:03,498 - DEBUG - ydb.query.pool.671317  - release: Session returned to queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:40:03,499 - DEBUG - ydb.query.pool.671317  - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:40:03,500 - DEBUG - ydb.connection.671317  - _prepare_call: RpcState(ExecuteQuery, b4db1a02-1831-4463-8451-a4571c1af908, ghrun-zme4sewyte.auto.internal:32388): creating call state
2025-11-21 17:40:03,501 - DEBUG - ydb.connection.671317  - _log_request: RpcState(ExecuteQuery, b4db1a02-1831-4463-8451-a4571c1af908, ghrun-zme4sewyte.auto.internal:32388): request = { session_id: "ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "select TierName, sum(Rows) as Rows, count(*) as Portions from `/Root/all_compression/all_supported_compression/zstd_9_compression/.sys/primary_index_portion_stats` group by TierName" } stats_mode: STATS_MODE_NONE }
2025-11-21 17:40:03,502 - DEBUG - ydb.connection.671317  - _log_response: RpcState(ExecuteQuery, b4db1a02-1831-4463-8451-a4571c1af908, ghrun-zme4sewyte.auto.internal:32388): response = { <_MultiThreadedRendezvous object> }
2025-11-21 17:40:03,854 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver.671317  - context_resolve: Preparing initial endpoint to resolve endpoints
2025-11-21 17:40:03,855 - DEBUG - ydb.connection.671317  - channel_factory: Channel options: [('grpc.max_receive_message_length', 64000000), ('grpc.max_send_message_length', 64000000), ('grpc.primary_user_agent', 'python-library'), ('grpc.lb_policy_name', 'round_robin'), ('grpc.keepalive_time_ms', 1250), ('grpc.keepalive_timeout_ms', 10000), ('grpc.http2.max_pings_without_data', 0), ('grpc.keepalive_permit_without_calls', 0)]
2025-11-21 17:40:03,898 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver.671317  - context_resolve: Resolving endpoints for database /Root
2025-11-21 17:40:03,899 - DEBUG - ydb.connection.671317  - _prepare_call: RpcState(ListEndpoints, 0378db7a-0d4b-499a-b542-d00d764ec76e, localhost:32388): creating call state
2025-11-21 17:40:03,900 - DEBUG - ydb.connection.671317  - _log_request: RpcState(ListEndpoints, 0378db7a-0d4b-499a-b542-d00d764ec76e, localhost:32388): request = { database: "/Root" }
2025-11-21 17:40:03,925 - DEBUG - ydb.connection.671317  - _log_response: RpcState(ListEndpoints, 0378db7a-0d4b-499a-b542-d00d764ec76e, localhost:32388): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Discovery.ListEndpointsResult] { endpoints { address: "ghrun-zme4sewyte.auto.internal" port: 32388 service: "legacy" service: "tablet_service" service: "yql" service: "discovery" service: "cms" service: "locking" service: "kesus" service: "pq" service: "pqcd" service: "pqv1" service: "topic" service: "datastreams" service: "scripting" service: "clickhouse_internal" service: "rate_limiter" service: "analytics" service: "export" service: "import" service: "yq" service: "keyvalue" service: "monitoring" service: "auth" service: "query_service" service: "view" location: "1" node_id: 1 } self_location: "1" } } } }
2025-11-21 17:40:03,927 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver.671317  - _add_debug_details: Resolved endpoints for database /Root: DiscoveryResult <self_location: 1, endpoints [<Endpoint ghrun-zme4sewyte.auto.internal:32388, location 1, ssl: False>]>
2025-11-21 17:40:03,927 - DEBUG - ydb.connection.671317  - close: Closing channel for endpoint localhost:32388
2025-11-21 17:40:03,931 - DEBUG - ydb.query.pool.671317  - release: Session returned to queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:40:03,932 - DEBUG - ydb.query.pool.671317  - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:40:03,933 - DEBUG - ydb.connection.671317  - _prepare_call: RpcState(ExecuteQuery, cd4d6b0f-ffbd-4456-bd78-6d9eebd44986, ghrun-zme4sewyte.auto.internal:32388): creating call state
2025-11-21 17:40:03,934 - DEBUG - ydb.connection.671317  - _log_request: RpcState(ExecuteQuery, cd4d6b0f-ffbd-4456-bd78-6d9eebd44986, ghrun-zme4sewyte.auto.internal:32388): request = { session_id: "ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "\n            select TierName, count(*) as Portions, sum(BlobSize) as BlobSize, sum(BlobCount) as BlobCount from (\n                select TabletId, PortionId, TierName, sum(BlobRangeSize) as BlobSize, count(*) as BlobCount from `/Root/all_compression/all_supported_compression/zstd_9_compression/.sys/primary_index_stats` group by TabletId, PortionId, TierName\n            ) group by TierName\n        " } stats_mode: STATS_MODE_NONE }
2025-11-21 17:40:03,937 - DEBUG - ydb.connection.671317  - _log_response: RpcState(ExecuteQuery, cd4d6b0f-ffbd-4456-bd78-6d9eebd44986, ghrun-zme4sewyte.auto.internal:32388): response = { <_MultiThreadedRendezvous object> }
2025-11-21 17:40:04,779 - DEBUG - ydb.query.pool.671317  - release: Session returned to queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:40:04,780 - INFO - __tests__.alter_compression.671317  - upsert_and_wait_portions: 700000 rows in /Root/all_compression/all_supported_compression/zstd_9_compression. portions: {'__DEFAULT': {'Rows': 700000, 'Portions': 448}}, blobs: {'__DEFAULT': {'Portions': 448, 'BlobSize': 2233024, 'BlobCount': 896}}
2025-11-21 17:40:04,780 - DEBUG - ydb.query.pool.671317  - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:40:04,781 - DEBUG - ydb.connection.671317  - _prepare_call: RpcState(ExecuteQuery, 8c90e21b-816b-47cb-8433-29f54dc53552, ghrun-zme4sewyte.auto.internal:32388): creating call state
2025-11-21 17:40:04,783 - DEBUG - ydb.connection.671317  - _log_request: RpcState(ExecuteQuery, 8c90e21b-816b-47cb-8433-29f54dc53552, ghrun-zme4sewyte.auto.internal:32388): request = { session_id: "ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "\n                $row_count = 100000;\n                $prev_count = 700000;\n                $rows= ListMap(ListFromRange(0, $row_count), ($i) -> {\n                    return <|\n                        value: $i + $prev_count,\n                        value1: $i + $prev_count,\n                    |>;\n                });\n                UPSERT INTO `/Root/all_compression/all_supported_compression/zstd_9_compression`\n                SELECT * FROM AS_TABLE($rows);\n            " } stats_mode: STATS_MODE_NONE }
2025-11-21 17:40:04,785 - DEBUG - ydb.connection.671317  - _log_response: RpcState(ExecuteQuery, 8c90e21b-816b-47cb-8433-29f54dc53552, ghrun-zme4sewyte.auto.internal:32388): response = { <_MultiThreadedRendezvous object> }
2025-11-21 17:40:07,059 - DEBUG - ydb.query.pool.671317  - release: Session returned to queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:40:07,059 - DEBUG - ydb.query.pool.671317  - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:40:07,060 - DEBUG - ydb.connection.671317  - _prepare_call: RpcState(ExecuteQuery, 4088945d-2073-485d-a3dd-f579beefc55a, ghrun-zme4sewyte.auto.internal:32388): creating call state
2025-11-21 17:40:07,061 - DEBUG - ydb.connection.671317  - _log_request: RpcState(ExecuteQuery, 4088945d-2073-485d-a3dd-f579beefc55a, ghrun-zme4sewyte.auto.internal:32388): request = { session_id: "ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "select TierName, sum(Rows) as Rows, count(*) as Portions from `/Root/all_compression/all_supported_compression/zstd_9_compression/.sys/primary_index_portion_stats` group by TierName" } stats_mode: STATS_MODE_NONE }
2025-11-21 17:40:07,067 - DEBUG - ydb.connection.671317  - _log_response: RpcState(ExecuteQuery, 4088945d-2073-485d-a3dd-f579beefc55a, ghrun-zme4sewyte.auto.internal:32388): response = { <_MultiThreadedRendezvous object> }
2025-11-21 17:40:07,520 - DEBUG - ydb.query.pool.671317  - release: Session returned to queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:40:07,521 - DEBUG - ydb.query.pool.671317  - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:40:07,522 - DEBUG - ydb.connection.671317  - _prepare_call: RpcState(ExecuteQuery, 6a7ba1eb-7ace-4a2d-bc36-c039bb37a503, ghrun-zme4sewyte.auto.internal:32388): creating call state
2025-11-21 17:40:07,523 - DEBUG - ydb.connection.671317  - _log_request: RpcState(ExecuteQuery, 6a7ba1eb-7ace-4a2d-bc36-c039bb37a503, ghrun-zme4sewyte.auto.internal:32388): request = { session_id: "ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "\n            select TierName, count(*) as Portions, sum(BlobSize) as BlobSize, sum(BlobCount) as BlobCount from (\n                select TabletId, PortionId, TierName, sum(BlobRangeSize) as BlobSize, count(*) as BlobCount from `/Root/all_compression/all_supported_compression/zstd_9_compression/.sys/primary_index_stats` group by TabletId, PortionId, TierName\n            ) group by TierName\n        " } stats_mode: STATS_MODE_NONE }
2025-11-21 17:40:07,525 - DEBUG - ydb.connection.671317  - _log_response: RpcState(ExecuteQuery, 6a7ba1eb-7ace-4a2d-bc36-c039bb37a503, ghrun-zme4sewyte.auto.internal:32388): response = { <_MultiThreadedRendezvous object> }
2025-11-21 17:40:08,191 - DEBUG - ydb.query.pool.671317  - release: Session returned to queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:40:08,191 - INFO - __tests__.alter_compression.671317  - upsert_and_wait_portions: 800000 rows in /Root/all_compression/all_supported_compression/zstd_9_compression. portions: {'__DEFAULT': {'Rows': 800000, 'Portions': 512}}, blobs: {'__DEFAULT': {'Portions': 512, 'BlobSize': 2552512, 'BlobCount': 1024}}
2025-11-21 17:40:08,192 - DEBUG - ydb.query.pool.671317  - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:40:08,193 - DEBUG - ydb.connection.671317  - _prepare_call: RpcState(ExecuteQuery, 7150cb33-fcc5-419e-888f-36839b41a897, ghrun-zme4sewyte.auto.internal:32388): creating call state
2025-11-21 17:40:08,193 - DEBUG - ydb.connection.671317  - _log_request: RpcState(ExecuteQuery, 7150cb33-fcc5-419e-888f-36839b41a897, ghrun-zme4sewyte.auto.internal:32388): request = { session_id: "ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "\n                $row_count = 100000;\n                $prev_count = 800000;\n                $rows= ListMap(ListFromRange(0, $row_count), ($i) -> {\n                    return <|\n                        value: $i + $prev_count,\n                        value1: $i + $prev_count,\n                    |>;\n                });\n                UPSERT INTO `/Root/all_compression/all_supported_compression/zstd_9_compression`\n                SELECT * FROM AS_TABLE($rows);\n            " } stats_mode: STATS_MODE_NONE }
2025-11-21 17:40:08,195 - DEBUG - ydb.connection.671317  - _log_response: RpcState(ExecuteQuery, 7150cb33-fcc5-419e-888f-36839b41a897, ghrun-zme4sewyte.auto.internal:32388): response = { <_MultiThreadedRendezvous object> }
2025-11-21 17:40:10,563 - DEBUG - ydb.query.pool.671317  - release: Session returned to queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:40:10,564 - DEBUG - ydb.query.pool.671317  - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:40:10,570 - DEBUG - ydb.connection.671317  - _prepare_call: RpcState(ExecuteQuery, 11d80e8e-3072-4b4c-a4c9-b1b50b166ea5, ghrun-zme4sewyte.auto.internal:32388): creating call state
2025-11-21 17:40:10,571 - DEBUG - ydb.connection.671317  - _log_request: RpcState(ExecuteQuery, 11d80e8e-3072-4b4c-a4c9-b1b50b166ea5, ghrun-zme4sewyte.auto.internal:32388): request = { session_id: "ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "select TierName, sum(Rows) as Rows, count(*) as Portions from `/Root/all_compression/all_supported_compression/zstd_9_compression/.sys/primary_index_portion_stats` group by TierName" } stats_mode: STATS_MODE_NONE }
2025-11-21 17:40:10,573 - DEBUG - ydb.connection.671317  - _log_response: RpcState(ExecuteQuery, 11d80e8e-3072-4b4c-a4c9-b1b50b166ea5, ghrun-zme4sewyte.auto.internal:32388): response = { <_MultiThreadedRendezvous object> }
2025-11-21 17:40:10,994 - DEBUG - ydb.query.pool.671317  - release: Session returned to queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:40:10,995 - DEBUG - ydb.query.pool.671317  - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:40:10,996 - DEBUG - ydb.connection.671317  - _prepare_call: RpcState(ExecuteQuery, 28e62404-c117-4762-93a9-fdf63464d6e6, ghrun-zme4sewyte.auto.internal:32388): creating call state
2025-11-21 17:40:10,997 - DEBUG - ydb.connection.671317  - _log_request: RpcState(ExecuteQuery, 28e62404-c117-4762-93a9-fdf63464d6e6, ghrun-zme4sewyte.auto.internal:32388): request = { session_id: "ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "\n            select TierName, count(*) as Portions, sum(BlobSize) as BlobSize, sum(BlobCount) as BlobCount from (\n                select TabletId, PortionId, TierName, sum(BlobRangeSize) as BlobSize, count(*) as BlobCount from `/Root/all_compression/all_supported_compression/zstd_9_compression/.sys/primary_index_stats` group by TabletId, PortionId, TierName\n            ) group by TierName\n        " } stats_mode: STATS_MODE_NONE }
2025-11-21 17:40:10,999 - DEBUG - ydb.connection.671317  - _log_response: RpcState(ExecuteQuery, 28e62404-c117-4762-93a9-fdf63464d6e6, ghrun-zme4sewyte.auto.internal:32388): response = { <_MultiThreadedRendezvous object> }
2025-11-21 17:40:11,826 - DEBUG - ydb.query.pool.671317  - release: Session returned to queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:40:11,827 - INFO - __tests__.alter_compression.671317  - upsert_and_wait_portions: 900000 rows in /Root/all_compression/all_supported_compression/zstd_9_compression. portions: {'__DEFAULT': {'Rows': 900000, 'Portions': 576}}, blobs: {'__DEFAULT': {'Portions': 576, 'BlobSize': 2871520, 'BlobCount': 1152}}
2025-11-21 17:40:11,827 - DEBUG - ydb.query.pool.671317  - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:40:11,828 - DEBUG - ydb.connection.671317  - _prepare_call: RpcState(ExecuteQuery, 92c3253b-ca03-404e-8b97-b00af9506fb6, ghrun-zme4sewyte.auto.internal:32388): creating call state
2025-11-21 17:40:11,829 - DEBUG - ydb.connection.671317  - _log_request: RpcState(ExecuteQuery, 92c3253b-ca03-404e-8b97-b00af9506fb6, ghrun-zme4sewyte.auto.internal:32388): request = { session_id: "ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "\n                $row_count = 100000;\n                $prev_count = 900000;\n                $rows= ListMap(ListFromRange(0, $row_count), ($i) -> {\n                    return <|\n                        value: $i + $prev_count,\n                        value1: $i + $prev_count,\n                    |>;\n                });\n                UPSERT INTO `/Root/all_compression/all_supported_compression/zstd_9_compression`\n                SELECT * FROM AS_TABLE($rows);\n            " } stats_mode: STATS_MODE_NONE }
2025-11-21 17:40:11,836 - DEBUG - ydb.connection.671317  - _log_response: RpcState(ExecuteQuery, 92c3253b-ca03-404e-8b97-b00af9506fb6, ghrun-zme4sewyte.auto.internal:32388): response = { <_MultiThreadedRendezvous object> }
2025-11-21 17:40:13,912 - DEBUG - ydb.query.pool.671317  - release: Session returned to queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:40:13,913 - DEBUG - ydb.query.pool.671317  - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:40:13,914 - DEBUG - ydb.connection.671317  - _prepare_call: RpcState(ExecuteQuery, 085d5f22-aa74-4daa-8688-9b73059dd556, ghrun-zme4sewyte.auto.internal:32388): creating call state
2025-11-21 17:40:13,915 - DEBUG - ydb.connection.671317  - _log_request: RpcState(ExecuteQuery, 085d5f22-aa74-4daa-8688-9b73059dd556, ghrun-zme4sewyte.auto.internal:32388): request = { session_id: "ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "select TierName, sum(Rows) as Rows, count(*) as Portions from `/Root/all_compression/all_supported_compression/zstd_9_compression/.sys/primary_index_portion_stats` group by TierName" } stats_mode: STATS_MODE_NONE }
2025-11-21 17:40:13,917 - DEBUG - ydb.connection.671317  - _log_response: RpcState(ExecuteQuery, 085d5f22-aa74-4daa-8688-9b73059dd556, ghrun-zme4sewyte.auto.internal:32388): response = { <_MultiThreadedRendezvous object> }
2025-11-21 17:40:14,350 - DEBUG - ydb.query.pool.671317  - release: Session returned to queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:40:14,351 - DEBUG - ydb.query.pool.671317  - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:40:14,351 - DEBUG - ydb.connection.671317  - _prepare_call: RpcState(ExecuteQuery, e4360075-f573-4236-8b2e-e2bec20f6f8f, ghrun-zme4sewyte.auto.internal:32388): creating call state
2025-11-21 17:40:14,352 - DEBUG - ydb.connection.671317  - _log_request: RpcState(ExecuteQuery, e4360075-f573-4236-8b2e-e2bec20f6f8f, ghrun-zme4sewyte.auto.internal:32388): request = { session_id: "ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "\n            select TierName, count(*) as Portions, sum(BlobSize) as BlobSize, sum(BlobCount) as BlobCount from (\n                select TabletId, PortionId, TierName, sum(BlobRangeSize) as BlobSize, count(*) as BlobCount from `/Root/all_compression/all_supported_compression/zstd_9_compression/.sys/primary_index_stats` group by TabletId, PortionId, TierName\n            ) group by TierName\n        " } stats_mode: STATS_MODE_NONE }
2025-11-21 17:40:14,354 - DEBUG - ydb.connection.671317  - _log_response: RpcState(ExecuteQuery, e4360075-f573-4236-8b2e-e2bec20f6f8f, ghrun-zme4sewyte.auto.internal:32388): response = { <_MultiThreadedRendezvous object> }
2025-11-21 17:40:15,532 - DEBUG - ydb.query.pool.671317  - release: Session returned to queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:40:15,533 - INFO - __tests__.alter_compression.671317  - upsert_and_wait_portions: 1000000 rows in /Root/all_compression/all_supported_compression/zstd_9_compression. portions: {'__DEFAULT': {'Rows': 1000000, 'Portions': 640}}, blobs: {'__DEFAULT': {'Portions': 640, 'BlobSize': 3191024, 'BlobCount': 1280}}
2025-11-21 17:40:15,533 - DEBUG - ydb.query.pool.671317  - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:40:15,534 - DEBUG - ydb.connection.671317  - _prepare_call: RpcState(ExecuteQuery, 27b6503d-e43e-4013-83fe-e13b790fc300, ghrun-zme4sewyte.auto.internal:32388): creating call state
2025-11-21 17:40:15,535 - DEBUG - ydb.connection.671317  - _log_request: RpcState(ExecuteQuery, 27b6503d-e43e-4013-83fe-e13b790fc300, ghrun-zme4sewyte.auto.internal:32388): request = { session_id: "ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) AS Rows FROM `/Root/all_compression/all_supported_compression/zstd_9_compression`" } stats_mode: STATS_MODE_NONE }
2025-11-21 17:40:15,536 - DEBUG - ydb.connection.671317  - _log_response: RpcState(ExecuteQuery, 27b6503d-e43e-4013-83fe-e13b790fc300, ghrun-zme4sewyte.auto.internal:32388): response = { <_MultiThreadedRendezvous object> }
2025-11-21 17:40:17,610 - DEBUG - ydb.query.pool.671317  - release: Session returned to queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:40:17,611 - DEBUG - ydb.query.pool.671317  - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:40:17,612 - DEBUG - ydb.connection.671317  - _prepare_call: RpcState(ExecuteQuery, 58e8a24e-4d30-4f2a-ad07-6bc92f66e2bb, ghrun-zme4sewyte.auto.internal:32388): creating call state
2025-11-21 17:40:17,613 - DEBUG - ydb.connection.671317  - _log_request: RpcState(ExecuteQuery, 58e8a24e-4d30-4f2a-ad07-6bc92f66e2bb, ghrun-zme4sewyte.auto.internal:32388): request = { session_id: "ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "select TierName, sum(Rows) as Rows, count(*) as Portions from `/Root/all_compression/all_supported_compression/zstd_9_compression/.sys/primary_index_portion_stats` group by TierName" } stats_mode: STATS_MODE_NONE }
2025-11-21 17:40:17,615 - DEBUG - ydb.connection.671317  - _log_response: RpcState(ExecuteQuery, 58e8a24e-4d30-4f2a-ad07-6bc92f66e2bb, ghrun-zme4sewyte.auto.internal:32388): response = { <_MultiThreadedRendezvous object> }
2025-11-21 17:40:18,198 - DEBUG - ydb.query.pool.671317  - release: Session returned to queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:40:18,199 - DEBUG - ydb.query.pool.671317  - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:40:18,200 - DEBUG - ydb.connection.671317  - _prepare_call: RpcState(ExecuteQuery, 8a1ada3f-ecbd-458f-9d6e-24035919bb8f, ghrun-zme4sewyte.auto.internal:32388): creating call state
2025-11-21 17:40:18,201 - DEBUG - ydb.connection.671317  - _log_request: RpcState(ExecuteQuery, 8a1ada3f-ecbd-458f-9d6e-24035919bb8f, ghrun-zme4sewyte.auto.internal:32388): request = { session_id: "ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "select TierName, sum(Rows) as Rows, count(*) as Portions from `/Root/all_compression/all_supported_compression/zstd_9_compression/.sys/primary_index_portion_stats` group by TierName" } stats_mode: STATS_MODE_NONE }
2025-11-21 17:40:18,203 - DEBUG - ydb.connection.671317  - _log_response: RpcState(ExecuteQuery, 8a1ada3f-ecbd-458f-9d6e-24035919bb8f, ghrun-zme4sewyte.auto.internal:32388): response = { <_MultiThreadedRendezvous object> }
2025-11-21 17:40:18,718 - DEBUG - ydb.query.pool.671317  - release: Session returned to queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:40:18,719 - DEBUG - ydb.query.pool.671317  - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:40:18,720 - DEBUG - ydb.connection.671317  - _prepare_call: RpcState(ExecuteQuery, 85018c92-58d6-4a68-912f-174249d61cf5, ghrun-zme4sewyte.auto.internal:32388): creating call state
2025-11-21 17:40:18,721 - DEBUG - ydb.connection.671317  - _log_request: RpcState(ExecuteQuery, 85018c92-58d6-4a68-912f-174249d61cf5, ghrun-zme4sewyte.auto.internal:32388): request = { session_id: "ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `/Root/all_compression/all_supported_compression/zstd_9_compression/.sys/primary_index_stats` WHERE Activity == 1 AND EntityName = \"value\"" } stats_mode: STATS_MODE_NONE }
2025-11-21 17:40:18,742 - DEBUG - ydb.connection.671317  - _log_response: RpcState(ExecuteQuery, 85018c92-58d6-4a68-912f-174249d61cf5, ghrun-zme4sewyte.auto.internal:32388): response = { <_MultiThreadedRendezvous object> }
2025-11-21 17:40:23,998 - DEBUG - ydb.query.pool.671317  - release: Session returned to queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:40:34,035 - DEBUG - ydb.query.pool.671317  - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:40:34,036 - DEBUG - ydb.connection.671317  - _prepare_call: RpcState(ExecuteQuery, 3c1bc514-025d-4add-bcf1-0cdb6a78ae1b, ghrun-zme4sewyte.auto.internal:32388): creating call state
2025-11-21 17:40:34,037 - DEBUG - ydb.connection.671317  - _log_request: RpcState(ExecuteQuery, 3c1bc514-025d-4add-bcf1-0cdb6a78ae1b, ghrun-zme4sewyte.auto.internal:32388): request = { session_id: "ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `/Root/all_compression/all_supported_compression/zstd_9_compression/.sys/primary_index_stats` WHERE Activity == 1 AND EntityName = \"value\"" } stats_mode: STATS_MODE_NONE }
2025-11-21 17:40:34,039 - DEBUG - ydb.connection.671317  - _log_response: RpcState(ExecuteQuery, 3c1bc514-025d-4add-bcf1-0cdb6a78ae1b, ghrun-zme4sewyte.auto.internal:32388): response = { <_MultiThreadedRendezvous object> }
2025-11-21 17:40:38,198 - DEBUG - ydb.query.pool.671317  - release: Session returned to queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:40:38,241 - INFO - root.671317  - get_volumes_column: Table `/Root/all_compression/all_supported_compression/zstd_9_compression`, volumes `value` (8000000, 1595512)
2025-11-21 17:40:38,243 - DEBUG - ydb.query.pool.671317  - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:40:38,243 - DEBUG - ydb.connection.671317  - _prepare_call: RpcState(ExecuteQuery, 058cd20f-13f0-4da2-b30d-48c210a50e6b, ghrun-zme4sewyte.auto.internal:32388): creating call state
2025-11-21 17:40:38,244 - DEBUG - ydb.connection.671317  - _log_request: RpcState(ExecuteQuery, 058cd20f-13f0-4da2-b30d-48c210a50e6b, ghrun-zme4sewyte.auto.internal:32388): request = { session_id: "ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "select TierName, sum(Rows) as Rows, count(*) as Portions from `/Root/all_compression/all_supported_compression/zstd_9_compression/.sys/primary_index_portion_stats` group by TierName" } stats_mode: STATS_MODE_NONE }
2025-11-21 17:40:38,245 - DEBUG - ydb.connection.671317  - _log_response: RpcState(ExecuteQuery, 058cd20f-13f0-4da2-b30d-48c210a50e6b, ghrun-zme4sewyte.auto.internal:32388): response = { <_MultiThreadedRendezvous object> }
2025-11-21 17:40:38,558 - DEBUG - ydb.query.pool.671317  - release: Session returned to queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:40:38,559 - DEBUG - ydb.query.pool.671317  - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:40:38,560 - DEBUG - ydb.connection.671317  - _prepare_call: RpcState(ExecuteQuery, f11ba049-e091-483b-a02f-b4b1d7c5698f, ghrun-zme4sewyte.auto.internal:32388): creating call state
2025-11-21 17:40:38,561 - DEBUG - ydb.connection.671317  - _log_request: RpcState(ExecuteQuery, f11ba049-e091-483b-a02f-b4b1d7c5698f, ghrun-zme4sewyte.auto.internal:32388): request = { session_id: "ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `/Root/all_compression/all_supported_compression/zstd_9_compression/.sys/primary_index_stats` WHERE Activity == 1 AND EntityName = \"value\"" } stats_mode: STATS_MODE_NONE }
2025-11-21 17:40:38,563 - DEBUG - ydb.connection.671317  - _log_response: RpcState(ExecuteQuery, f11ba049-e091-483b-a02f-b4b1d7c5698f, ghrun-zme4sewyte.auto.internal:32388): response = { <_MultiThreadedRendezvous object> }
2025-11-21 17:40:42,143 - DEBUG - ydb.query.pool.671317  - release: Session returned to queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:40:52,178 - DEBUG - ydb.query.pool.671317  - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:40:52,179 - DEBUG - ydb.connection.671317  - _prepare_call: RpcState(ExecuteQuery, 1776ac4e-7a30-482a-a7d8-e08a15218620, ghrun-zme4sewyte.auto.internal:32388): creating call state
2025-11-21 17:40:52,180 - DEBUG - ydb.connection.671317  - _log_request: RpcState(ExecuteQuery, 1776ac4e-7a30-482a-a7d8-e08a15218620, ghrun-zme4sewyte.auto.internal:32388): request = { session_id: "ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `/Root/all_compression/all_supported_compression/zstd_9_compression/.sys/primary_index_stats` WHERE Activity == 1 AND EntityName = \"value\"" } stats_mode: STATS_MODE_NONE }
2025-11-21 17:40:52,183 - DEBUG - ydb.connection.671317  - _log_response: RpcState(ExecuteQuery, 1776ac4e-7a30-482a-a7d8-e08a15218620, ghrun-zme4sewyte.auto.internal:32388): response = { <_MultiThreadedRendezvous object> }
2025-11-21 17:40:54,220 - DEBUG - ydb.query.pool.671317  - release: Session returned to queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:41:04,234 - DEBUG - ydb.query.pool.671317  - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:41:04,235 - DEBUG - ydb.connection.671317  - _prepare_call: RpcState(ExecuteQuery, 3befb8a4-ef18-46b7-8d83-0bf9931b381a, ghrun-zme4sewyte.auto.internal:32388): creating call state
2025-11-21 17:41:04,236 - DEBUG - ydb.connection.671317  - _log_request: RpcState(ExecuteQuery, 3befb8a4-ef18-46b7-8d83-0bf9931b381a, ghrun-zme4sewyte.auto.internal:32388): request = { session_id: "ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `/Root/all_compression/all_supported_compression/zstd_9_compression/.sys/primary_index_stats` WHERE Activity == 1 AND EntityName = \"value\"" } stats_mode: STATS_MODE_NONE }
2025-11-21 17:41:04,238 - DEBUG - ydb.connection.671317  - _log_response: RpcState(ExecuteQuery, 3befb8a4-ef18-46b7-8d83-0bf9931b381a, ghrun-zme4sewyte.auto.internal:32388): response = { <_MultiThreadedRendezvous object> }
2025-11-21 17:41:05,024 - DEBUG - ydb.query.pool.671317  - release: Session returned to queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:41:15,029 - DEBUG - ydb.query.pool.671317  - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:41:15,030 - DEBUG - ydb.connection.671317  - _prepare_call: RpcState(ExecuteQuery, bb5a4ee8-89e9-4010-b34a-40bd2a7967b0, ghrun-zme4sewyte.auto.internal:32388): creating call state
2025-11-21 17:41:15,031 - DEBUG - ydb.connection.671317  - _log_request: RpcState(ExecuteQuery, bb5a4ee8-89e9-4010-b34a-40bd2a7967b0, ghrun-zme4sewyte.auto.internal:32388): request = { session_id: "ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `/Root/all_compression/all_supported_compression/zstd_9_compression/.sys/primary_index_stats` WHERE Activity == 1 AND EntityName = \"value\"" } stats_mode: STATS_MODE_NONE }
2025-11-21 17:41:15,039 - DEBUG - ydb.connection.671317  - _log_response: RpcState(ExecuteQuery, bb5a4ee8-89e9-4010-b34a-40bd2a7967b0, ghrun-zme4sewyte.auto.internal:32388): response = { <_MultiThreadedRendezvous object> }
2025-11-21 17:41:15,884 - DEBUG - ydb.query.pool.671317  - release: Session returned to queue: ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=
2025-11-21 17:41:15,888 - INFO - root.671317  - get_volumes_column: Table `/Root/all_compression/all_supported_compression/zstd_9_compression`, volumes `value` (8000000, 1465240)
2025-11-21 17:41:15,889 - INFO - root.671317  - test_all_supported_compression: compression in `/Root/all_compression/all_supported_compression/zstd_9_compression` 8092160 / 1465240: 5.522753951571073
2025-11-21 17:41:15,891 - INFO - ya.test.671317  - pytest_runtest_teardown: Test teardown
2025-11-21 17:41:15,893 - DEBUG - ydb.connection.671317  - _prepare_call: RpcState(DeleteSession, 8382cc72-e35e-43b2-8da5-b0261ab794cc, ghrun-zme4sewyte.auto.internal:32388): creating call state
2025-11-21 17:41:15,893 - DEBUG - ydb.connection.671317  - _log_request: RpcState(DeleteSession, 8382cc72-e35e-43b2-8da5-b0261ab794cc, ghrun-zme4sewyte.auto.internal:32388): request = { session_id: "ydb://session/3?node_id=1&id=OWZkZjQ4YWMtZDk2YWM1ZTctOWViZjQ0NzctOTAyOWQyMmY=" }
2025-11-21 17:41:15,907 - DEBUG - ydb.connection.671317  - _log_response: RpcState(DeleteSession, 8382cc72-e35e-43b2-8da5-b0261ab794cc, ghrun-zme4sewyte.auto.internal:32388): response = { status: SUCCESS }
2025-11-21 17:41:15,909 - DEBUG - ydb.query.pool.671317  - stop: All session were deleted.
2025-11-21 17:41:15,914 - DEBUG - ydb.topic.671317  - close: Close topic client
2025-11-21 17:41:15,914 - DEBUG - ydb.topic.671317  - close: Topic client was closed
2025-11-21 17:41:15,915 - DEBUG - ydb.connection.671317  - close: Closing channel for endpoint localhost:32388
2025-11-21 17:41:15,919 - DEBUG - ydb.connection.671317  - close: Closing channel for endpoint ghrun-zme4sewyte.auto.internal:32388
2025-11-21 17:41:15,921 - INFO - ydb.pool.Discovery.671317  - run: Successfully terminated discovery process
2025-11-21 17:41:15,926 - DEBUG - ydb.connection.671317  - _rpc_error_handler: RpcState(AttachSession, 30f2c8ff-8d22-449f-b030-64466ecc87ee, ghrun-zme4sewyte.auto.internal:32388): received error, <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.CANCELLED
	details = "Locally cancelled by application!"
	debug_error_string = "None"
>
2025-11-21 17:41:32,959 - INFO - ydb.tests.library.harness.kikimr_runner.671317  - stop: Stopped node localhost:32388/1
2025-11-21 17:41:32,963 - DEBUG - library.python.filelock.671317  - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/31672
2025-11-21 17:41:32,964 - DEBUG - library.python.filelock.671317  - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/9994
2025-11-21 17:41:32,965 - DEBUG - library.python.filelock.671317  - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/29651
2025-11-21 17:41:32,967 - DEBUG - library.python.filelock.671317  - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/32388
2025-11-21 17:41:32,967 - DEBUG - library.python.filelock.671317  - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/5202
