2025-12-12 17:19:32,808 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-12-12 17:19:32,809 - INFO - ya.test - pytest_runtest_setup: test_log_deviation[180]
2025-12-12 17:19:32,809 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-12-12 17:19:32,809 - INFO - ya.test - pytest_runtest_setup: Test setup
2025-12-12 17:19:32,811 - INFO - ya.test - pytest_runtest_call: Test call (class_name: test_log_scenario.py::TestLogScenario, test_name: test_log_deviation[180])
2025-12-12 17:19:32,811 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/cfdu/002020/ydb/apps/ydb/ydb
2025-12-12 17:19:32,811 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/cfdu/002020/ydb/apps/ydb/ydb -e grpc://localhost:8320 -d /Root workload log --path log init --path log --store column --ttl 1000 with wait = True
2025-12-12 17:19:32,852 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.5
2025-12-12 17:19:32,860 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.5
2025-12-12 17:19:32,860 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/cfdu/002020/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:8320', '-d', '/Root', 'workload', 'log', '--path', 'log', 'init', '--path', 'log', '--store', 'column', '--ttl', '1000']' in 'None' (waiting)
2025-12-12 17:19:32,862 - DEBUG - ya.test - execute: Command pid: 230704
2025-12-12 17:19:33,392 - DEBUG - ya.test - _save_outputs: Command (pid 230704) rc: 0
2025-12-12 17:19:33,393 - DEBUG - ya.test - _save_outputs: Command (pid 230704) elapsed time (sec): 0.522451639175415
2025-12-12 17:19:33,393 - DEBUG - ya.test - _save_outputs: Command (pid 230704) idrss: 0
2025-12-12 17:19:33,394 - DEBUG - ya.test - _save_outputs: Command (pid 230704) inblock: 0
2025-12-12 17:19:33,402 - DEBUG - ya.test - _save_outputs: Command (pid 230704) isrss: 0
2025-12-12 17:19:33,419 - DEBUG - ya.test - _save_outputs: Command (pid 230704) ixrss: 0
2025-12-12 17:19:33,428 - DEBUG - ya.test - _save_outputs: Command (pid 230704) majflt: 0
2025-12-12 17:19:33,445 - DEBUG - ya.test - _save_outputs: Command (pid 230704) maxrss: 658520
2025-12-12 17:19:33,446 - DEBUG - ya.test - _save_outputs: Command (pid 230704) minflt: 3489
2025-12-12 17:19:33,446 - DEBUG - ya.test - _save_outputs: Command (pid 230704) msgrcv: 0
2025-12-12 17:19:33,446 - DEBUG - ya.test - _save_outputs: Command (pid 230704) msgsnd: 0
2025-12-12 17:19:33,446 - DEBUG - ya.test - _save_outputs: Command (pid 230704) nivcsw: 17
2025-12-12 17:19:33,446 - DEBUG - ya.test - _save_outputs: Command (pid 230704) nsignals: 0
2025-12-12 17:19:33,446 - DEBUG - ya.test - _save_outputs: Command (pid 230704) nswap: 0
2025-12-12 17:19:33,447 - DEBUG - ya.test - _save_outputs: Command (pid 230704) nvcsw: 172
2025-12-12 17:19:33,447 - DEBUG - ya.test - _save_outputs: Command (pid 230704) oublock: 8
2025-12-12 17:19:33,447 - DEBUG - ya.test - _save_outputs: Command (pid 230704) stime: 0.028187
2025-12-12 17:19:33,447 - DEBUG - ya.test - _save_outputs: Command (pid 230704) utime: 0.048320999999999996
2025-12-12 17:19:33,447 - DEBUG - ya.test - _save_outputs: Command (pid 230704) wtime: 0.524
2025-12-12 17:19:33,447 - DEBUG - ya.test - _save_outputs: Command (pid 230704) output:
Init tables ...
Init tables ...Ok

2025-12-12 17:19:33,448 - DEBUG - ya.test - _save_outputs: Command (pid 230704) errors:

2025-12-12 17:19:33,448 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZWVjOTA2YzktODkxY2RiOTItOTJhNTgwMmItNjM4NzhmYzQ=
2025-12-12 17:19:33,448 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 5195f037-5e7c-42a6-9d66-9db611e2a595, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:19:33,456 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 5195f037-5e7c-42a6-9d66-9db611e2a595, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=ZWVjOTA2YzktODkxY2RiOTItOTJhNTgwMmItNjM4NzhmYzQ=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "ALTER OBJECT `//Root/log` (TYPE TABLE) SET (ACTION=UPSERT_OPTIONS, `SCAN_READER_POLICY_NAME`=`SIMPLE`) " } stats_mode: STATS_MODE_NONE }
2025-12-12 17:19:33,457 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 5195f037-5e7c-42a6-9d66-9db611e2a595, ghrun-lmjjgjftxu.auto.internal:8320): response = { <_MultiThreadedRendezvous object> }
2025-12-12 17:19:33,504 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZWVjOTA2YzktODkxY2RiOTItOTJhNTgwMmItNjM4NzhmYzQ=
2025-12-12 17:19:33,504 - INFO - root - _insert_rows: YdbWorkloadLog bulk_upsert
2025-12-12 17:19:33,504 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/cfdu/002020/ydb/apps/ydb/ydb -e grpc://localhost:8320 -d /Root workload log --path log run bulk_upsert --seconds 3 --threads 10 --rows 500 --timestamp_deviation 180 with wait = True
2025-12-12 17:19:33,506 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.6
2025-12-12 17:19:33,508 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.6
2025-12-12 17:19:33,516 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/cfdu/002020/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:8320', '-d', '/Root', 'workload', 'log', '--path', 'log', 'run', 'bulk_upsert', '--seconds', '3', '--threads', '10', '--rows', '500', '--timestamp_deviation', '180']' in 'None' (waiting)
2025-12-12 17:19:33,518 - DEBUG - ya.test - execute: Command pid: 231174
2025-12-12 17:19:37,568 - DEBUG - ya.test - _wait: Process resource usage is not available as process finished before wait4 was called
2025-12-12 17:19:37,571 - DEBUG - ya.test - _save_outputs: Command (pid 231174) rc: 0
2025-12-12 17:19:37,572 - DEBUG - ya.test - _save_outputs: Command (pid 231174) elapsed time (sec): 4.017690420150757
2025-12-12 17:19:37,572 - DEBUG - ya.test - _save_outputs: Command (pid 231174) wtime: 4.052
2025-12-12 17:19:37,572 - DEBUG - ya.test - _save_outputs: Command (pid 231174) output:
Window	    Txs	Txs/Sec	Retries	Errors	p50(ms)	p95(ms)	p99(ms)	pMax(ms)
1	      8	8	0	0	707	919	919	919
2	     12	12	0	0	939	995	1039	1039
3	     20	20	0	0	911	935	935	935

Total	    Txs	Txs/Sec	Retries	Errors	p50(ms)	p95(ms)	p99(ms)	pMax(ms)
3	     40	13.3333	0	0	911	975	1039	1039

2025-12-12 17:19:37,572 - DEBUG - ya.test - _save_outputs: Command (pid 231174) errors:

2025-12-12 17:19:37,573 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NWM5MDAwZTctMzJmYzEyZWUtOTk5Mzg1OGItNzYwZDQ3MjM=
2025-12-12 17:19:37,573 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 4941325e-858b-4e9f-91f3-74e8fa9f4df7, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:19:37,574 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 4941325e-858b-4e9f-91f3-74e8fa9f4df7, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=NWM5MDAwZTctMzJmYzEyZWUtOTk5Mzg1OGItNzYwZDQ3MjM=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "select count(*) as Rows from `log`" } stats_mode: STATS_MODE_NONE }
2025-12-12 17:19:37,575 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 4941325e-858b-4e9f-91f3-74e8fa9f4df7, ghrun-lmjjgjftxu.auto.internal:8320): response = { <_MultiThreadedRendezvous object> }
2025-12-12 17:19:40,530 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NWM5MDAwZTctMzJmYzEyZWUtOTk5Mzg1OGItNzYwZDQ3MjM=
2025-12-12 17:19:40,538 - INFO - root - test_log_deviation: Count rows after insert 20000 before wait
2025-12-12 17:19:40,538 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZTE1Zjk1OTctNzRiOTQyYTgtOGMwY2MxYWYtNGZiM2ZmMzY=
2025-12-12 17:19:40,538 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, f8a72d77-23c9-4a36-a4f0-f707b2f6bad5, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:19:40,548 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, f8a72d77-23c9-4a36-a4f0-f707b2f6bad5, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=ZTE1Zjk1OTctNzRiOTQyYTgtOGMwY2MxYWYtNGZiM2ZmMzY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "select count(*) as Rows from `log`" } stats_mode: STATS_MODE_NONE }
2025-12-12 17:19:40,569 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, f8a72d77-23c9-4a36-a4f0-f707b2f6bad5, ghrun-lmjjgjftxu.auto.internal:8320): response = { <_MultiThreadedRendezvous object> }
2025-12-12 17:19:42,651 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZTE1Zjk1OTctNzRiOTQyYTgtOGMwY2MxYWYtNGZiM2ZmMzY=
2025-12-12 17:19:42,661 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MzI5OGIxY2YtN2IyODY3MDgtOGJhY2NlMWYtNmZmMTA0YjM=
2025-12-12 17:19:42,662 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, ead976e7-fc62-44b2-ab9a-50b467f87882, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:19:42,683 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, ead976e7-fc62-44b2-ab9a-50b467f87882, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=MzI5OGIxY2YtN2IyODY3MDgtOGJhY2NlMWYtNmZmMTA0YjM=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "select count(*) as Rows from `log`" } stats_mode: STATS_MODE_NONE }
2025-12-12 17:19:42,684 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, ead976e7-fc62-44b2-ab9a-50b467f87882, ghrun-lmjjgjftxu.auto.internal:8320): response = { <_MultiThreadedRendezvous object> }
2025-12-12 17:19:45,077 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MzI5OGIxY2YtN2IyODY3MDgtOGJhY2NlMWYtNmZmMTA0YjM=
2025-12-12 17:19:45,092 - INFO - root - _insert_rows: YdbWorkloadLog bulk_upsert
2025-12-12 17:19:45,092 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/cfdu/002020/ydb/apps/ydb/ydb -e grpc://localhost:8320 -d /Root workload log --path log run bulk_upsert --seconds 3 --threads 10 --rows 500 --timestamp_deviation 180 with wait = True
2025-12-12 17:19:45,093 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.7
2025-12-12 17:19:45,094 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.7
2025-12-12 17:19:45,094 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/cfdu/002020/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:8320', '-d', '/Root', 'workload', 'log', '--path', 'log', 'run', 'bulk_upsert', '--seconds', '3', '--threads', '10', '--rows', '500', '--timestamp_deviation', '180']' in 'None' (waiting)
2025-12-12 17:19:45,103 - DEBUG - ya.test - execute: Command pid: 237054
2025-12-12 17:19:45,104 - INFO - root - _insert_rows: YdbWorkloadLog insert
2025-12-12 17:19:45,141 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/cfdu/002020/ydb/apps/ydb/ydb -e grpc://localhost:8320 -d /Root workload log --path log run insert --seconds 3 --threads 10 --rows 500 --timestamp_deviation 180 with wait = True
2025-12-12 17:19:45,116 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZGJjNDZjZGUtNDMzNWFmZjUtYzZmMGE0MmUtZGE3MzhmM2U=
2025-12-12 17:19:45,142 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 9bdc56be-05e3-4f19-9957-4bc1aad3ecc2, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:19:45,143 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 9bdc56be-05e3-4f19-9957-4bc1aad3ecc2, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=ZGJjNDZjZGUtNDMzNWFmZjUtYzZmMGE0MmUtZGE3MzhmM2U=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-12-12 17:19:45,116 - INFO - root - _insert_rows: YdbWorkloadLog upsert
2025-12-12 17:19:45,144 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 9bdc56be-05e3-4f19-9957-4bc1aad3ecc2, ghrun-lmjjgjftxu.auto.internal:8320): response = { <_MultiThreadedRendezvous object> }
2025-12-12 17:19:45,145 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.8
2025-12-12 17:19:45,148 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NjMzMjBjYWEtOWRhOWNkOWYtNTgzOTkxZTAtYjViOGVmY2M=
2025-12-12 17:19:45,152 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/cfdu/002020/ydb/apps/ydb/ydb -e grpc://localhost:8320 -d /Root workload log --path log run upsert --seconds 3 --threads 10 --rows 500 --timestamp_deviation 180 with wait = True
2025-12-12 17:19:45,153 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, c5ad43ee-b53c-49f0-b10d-f1da82e465da, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:19:45,201 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, c5ad43ee-b53c-49f0-b10d-f1da82e465da, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=NjMzMjBjYWEtOWRhOWNkOWYtNTgzOTkxZTAtYjViOGVmY2M=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-12-12 17:19:45,182 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.8
2025-12-12 17:19:45,197 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.9
2025-12-12 17:19:45,153 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YjczMmEwMjYtZWQwMWVhY2EtMmNiNzBlMDQtMjBjZjkz
2025-12-12 17:19:45,220 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, c5ad43ee-b53c-49f0-b10d-f1da82e465da, ghrun-lmjjgjftxu.auto.internal:8320): response = { <_MultiThreadedRendezvous object> }
2025-12-12 17:19:45,222 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/cfdu/002020/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:8320', '-d', '/Root', 'workload', 'log', '--path', 'log', 'run', 'insert', '--seconds', '3', '--threads', '10', '--rows', '500', '--timestamp_deviation', '180']' in 'None' (waiting)
2025-12-12 17:19:45,224 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, d39e200b-e153-4105-9bc2-5e1ea93be706, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:19:45,285 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, d39e200b-e153-4105-9bc2-5e1ea93be706, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=YjczMmEwMjYtZWQwMWVhY2EtMmNiNzBlMDQtMjBjZjkz" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-12-12 17:19:45,285 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, d39e200b-e153-4105-9bc2-5e1ea93be706, ghrun-lmjjgjftxu.auto.internal:8320): response = { <_MultiThreadedRendezvous object> }
2025-12-12 17:19:45,224 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NDBlYmNjN2ItMzU2NzA5NjgtNTU2YmE5MGItYzYxOGFlMjA=
2025-12-12 17:19:45,287 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 2d0242d4-2d73-40d4-a5b8-a61f6dac620c, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:19:45,287 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 2d0242d4-2d73-40d4-a5b8-a61f6dac620c, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=NDBlYmNjN2ItMzU2NzA5NjgtNTU2YmE5MGItYzYxOGFlMjA=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-12-12 17:19:45,225 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.9
2025-12-12 17:19:45,293 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/cfdu/002020/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:8320', '-d', '/Root', 'workload', 'log', '--path', 'log', 'run', 'upsert', '--seconds', '3', '--threads', '10', '--rows', '500', '--timestamp_deviation', '180']' in 'None' (waiting)
2025-12-12 17:19:45,292 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=Yzg3NWM1ZjktNjZlZGU1M2UtOWFjOTk2ODEtNzM2NjNiMDU=
2025-12-12 17:19:45,318 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 262cb7fa-c210-4197-be8e-281fc9fda466, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:19:45,318 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 262cb7fa-c210-4197-be8e-281fc9fda466, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=Yzg3NWM1ZjktNjZlZGU1M2UtOWFjOTk2ODEtNzM2NjNiMDU=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-12-12 17:19:45,284 - DEBUG - ya.test - execute: Command pid: 237231
2025-12-12 17:19:45,316 - DEBUG - ya.test - execute: Command pid: 237235
2025-12-12 17:19:45,317 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 2d0242d4-2d73-40d4-a5b8-a61f6dac620c, ghrun-lmjjgjftxu.auto.internal:8320): response = { <_MultiThreadedRendezvous object> }
2025-12-12 17:19:45,320 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 262cb7fa-c210-4197-be8e-281fc9fda466, ghrun-lmjjgjftxu.auto.internal:8320): response = { <_MultiThreadedRendezvous object> }
2025-12-12 17:19:45,321 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NzlkMzA0MmQtNGQwZGI0YmEtZWJjNWJhZTgtYzE5NDJhZTM=
2025-12-12 17:19:45,332 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 5bf553ef-a117-4031-8bd9-5d336fbf0f3a, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:19:45,334 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 5bf553ef-a117-4031-8bd9-5d336fbf0f3a, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=NzlkMzA0MmQtNGQwZGI0YmEtZWJjNWJhZTgtYzE5NDJhZTM=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-12-12 17:19:45,334 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZWVjOTA2YzktODkxY2RiOTItOTJhNTgwMmItNjM4NzhmYzQ=
2025-12-12 17:19:45,349 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 5bf553ef-a117-4031-8bd9-5d336fbf0f3a, ghrun-lmjjgjftxu.auto.internal:8320): response = { <_MultiThreadedRendezvous object> }
2025-12-12 17:19:45,365 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 558a5262-ee7f-4e63-8e35-69dadd571ba2, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:19:45,371 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 558a5262-ee7f-4e63-8e35-69dadd571ba2, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=ZWVjOTA2YzktODkxY2RiOTItOTJhNTgwMmItNjM4NzhmYzQ=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-12-12 17:19:45,371 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 558a5262-ee7f-4e63-8e35-69dadd571ba2, ghrun-lmjjgjftxu.auto.internal:8320): response = { <_MultiThreadedRendezvous object> }
2025-12-12 17:19:45,365 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NWM5MDAwZTctMzJmYzEyZWUtOTk5Mzg1OGItNzYwZDQ3MjM=
2025-12-12 17:19:45,384 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 61fdb5a6-7ef1-4356-bbb4-171b4b16421e, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:19:45,385 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 61fdb5a6-7ef1-4356-bbb4-171b4b16421e, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=NWM5MDAwZTctMzJmYzEyZWUtOTk5Mzg1OGItNzYwZDQ3MjM=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-12-12 17:19:45,386 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 61fdb5a6-7ef1-4356-bbb4-171b4b16421e, ghrun-lmjjgjftxu.auto.internal:8320): response = { <_MultiThreadedRendezvous object> }
2025-12-12 17:19:45,388 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZTE1Zjk1OTctNzRiOTQyYTgtOGMwY2MxYWYtNGZiM2ZmMzY=
2025-12-12 17:19:45,408 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 4b31e761-83dd-4e10-a1a3-b507e1ff2c81, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:19:45,409 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 4b31e761-83dd-4e10-a1a3-b507e1ff2c81, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=ZTE1Zjk1OTctNzRiOTQyYTgtOGMwY2MxYWYtNGZiM2ZmMzY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-12-12 17:19:45,410 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 4b31e761-83dd-4e10-a1a3-b507e1ff2c81, ghrun-lmjjgjftxu.auto.internal:8320): response = { <_MultiThreadedRendezvous object> }
2025-12-12 17:19:45,410 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MzI5OGIxY2YtN2IyODY3MDgtOGJhY2NlMWYtNmZmMTA0YjM=
2025-12-12 17:19:45,411 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 8b047e7f-4007-4e31-823d-33c515595461, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:19:45,436 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 8b047e7f-4007-4e31-823d-33c515595461, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=MzI5OGIxY2YtN2IyODY3MDgtOGJhY2NlMWYtNmZmMTA0YjM=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-12-12 17:19:45,456 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 8b047e7f-4007-4e31-823d-33c515595461, ghrun-lmjjgjftxu.auto.internal:8320): response = { <_MultiThreadedRendezvous object> }
2025-12-12 17:19:48,950 - DEBUG - ya.test - _wait: Process resource usage is not available as process finished before wait4 was called
2025-12-12 17:19:48,951 - DEBUG - ya.test - _save_outputs: Command (pid 237231) rc: 0
2025-12-12 17:19:48,951 - DEBUG - ya.test - _save_outputs: Command (pid 237231) elapsed time (sec): 3.630812168121338
2025-12-12 17:19:48,951 - DEBUG - ya.test - _save_outputs: Command (pid 237231) wtime: 3.675
2025-12-12 17:19:48,951 - DEBUG - ya.test - _save_outputs: Command (pid 237231) output:
Window	    Txs	Txs/Sec	Retries	Errors	p50(ms)	p95(ms)	p99(ms)	pMax(ms)
1	      0	0	0	0	0	0	0	0
2	      0	0	0	10	0	0	0	0
3	      0	0	0	10	0	0	0	0

Total	    Txs	Txs/Sec	Retries	Errors	p50(ms)	p95(ms)	p99(ms)	pMax(ms)
3	      0	0	0	20	0	0	0	0

2025-12-12 17:19:48,996 - DEBUG - ya.test - _save_outputs: Command (pid 237231) errors:

2025-12-12 17:19:50,793 - DEBUG - ya.test - _wait: Process resource usage is not available as process finished before wait4 was called
2025-12-12 17:19:50,849 - DEBUG - ya.test - _save_outputs: Command (pid 237235) rc: 0
2025-12-12 17:19:50,851 - DEBUG - ya.test - _save_outputs: Command (pid 237235) elapsed time (sec): 5.523560523986816
2025-12-12 17:19:50,884 - DEBUG - ya.test - _save_outputs: Command (pid 237235) wtime: 5.555
2025-12-12 17:19:50,896 - DEBUG - ya.test - _save_outputs: Command (pid 237235) output:
Window	    Txs	Txs/Sec	Retries	Errors	p50(ms)	p95(ms)	p99(ms)	pMax(ms)
1	      0	0	0	0	0	0	0	0
2	      0	0	0	10	0	0	0	0
3	      0	0	0	15	0	0	0	0

Total	    Txs	Txs/Sec	Retries	Errors	p50(ms)	p95(ms)	p99(ms)	pMax(ms)
3	      0	0	0	25	0	0	0	0

2025-12-12 17:19:50,896 - DEBUG - ya.test - _save_outputs: Command (pid 237235) errors:

2025-12-12 17:19:51,436 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-12-12 17:19:51,500 - DEBUG - ydb.connection - 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-12-12 17:19:51,524 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database /Root
2025-12-12 17:19:51,528 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, 92d41f14-f3da-4da2-bf5c-146b355d5a4b, localhost:8320): creating call state
2025-12-12 17:19:51,529 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, 92d41f14-f3da-4da2-bf5c-146b355d5a4b, localhost:8320): request = { database: "/Root" }
2025-12-12 17:19:51,657 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, 92d41f14-f3da-4da2-bf5c-146b355d5a4b, localhost:8320): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Discovery.ListEndpointsResult] { endpoints { address: "ghrun-lmjjgjftxu.auto.internal" port: 8320 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-12-12 17:19:51,658 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Resolved endpoints for database /Root: DiscoveryResult <self_location: 1, endpoints [<Endpoint ghrun-lmjjgjftxu.auto.internal:8320, location 1, ssl: False>]>
2025-12-12 17:19:51,658 - INFO - ydb.connection - close: Closing channel for endpoint localhost:8320
2025-12-12 17:20:01,769 - DEBUG - ya.test - _wait: Process resource usage is not available as process finished before wait4 was called
2025-12-12 17:20:01,795 - DEBUG - ya.test - _save_outputs: Command (pid 237054) rc: 0
2025-12-12 17:20:01,795 - DEBUG - ya.test - _save_outputs: Command (pid 237054) elapsed time (sec): 16.65446662902832
2025-12-12 17:20:01,795 - DEBUG - ya.test - _save_outputs: Command (pid 237054) wtime: 16.7
2025-12-12 17:20:01,796 - DEBUG - ya.test - _save_outputs: Command (pid 237054) output:
Window	    Txs	Txs/Sec	Retries	Errors	p50(ms)	p95(ms)	p99(ms)	pMax(ms)
1	      0	0	0	0	0	0	0	0
2	      0	0	0	0	0	0	0	0
3	     10	10	0	0	16255	16511	16511	16511

Total	    Txs	Txs/Sec	Retries	Errors	p50(ms)	p95(ms)	p99(ms)	pMax(ms)
3	     10	3.33333	0	0	16255	16511	16511	16511

2025-12-12 17:20:01,796 - DEBUG - ya.test - _save_outputs: Command (pid 237054) errors:

2025-12-12 17:20:32,358 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZTE1Zjk1OTctNzRiOTQyYTgtOGMwY2MxYWYtNGZiM2ZmMzY=
2025-12-12 17:20:32,362 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MzI5OGIxY2YtN2IyODY3MDgtOGJhY2NlMWYtNmZmMTA0YjM=
2025-12-12 17:20:32,370 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZTE1Zjk1OTctNzRiOTQyYTgtOGMwY2MxYWYtNGZiM2ZmMzY=
2025-12-12 17:20:32,371 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, f25dc32c-30dd-450d-8f7a-812c871564e0, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:20:32,371 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, f25dc32c-30dd-450d-8f7a-812c871564e0, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=ZTE1Zjk1OTctNzRiOTQyYTgtOGMwY2MxYWYtNGZiM2ZmMzY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(8)" } stats_mode: STATS_MODE_NONE }
2025-12-12 17:20:32,372 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, f25dc32c-30dd-450d-8f7a-812c871564e0, ghrun-lmjjgjftxu.auto.internal:8320): response = { <_MultiThreadedRendezvous object> }
2025-12-12 17:20:32,373 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MzI5OGIxY2YtN2IyODY3MDgtOGJhY2NlMWYtNmZmMTA0YjM=
2025-12-12 17:20:32,373 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 70bce8d8-ace3-445c-b74d-783279cc9c63, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:20:32,373 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 70bce8d8-ace3-445c-b74d-783279cc9c63, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=MzI5OGIxY2YtN2IyODY3MDgtOGJhY2NlMWYtNmZmMTA0YjM=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(9)" } stats_mode: STATS_MODE_NONE }
2025-12-12 17:20:32,374 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 70bce8d8-ace3-445c-b74d-783279cc9c63, ghrun-lmjjgjftxu.auto.internal:8320): response = { <_MultiThreadedRendezvous object> }
2025-12-12 17:20:32,446 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NjMzMjBjYWEtOWRhOWNkOWYtNTgzOTkxZTAtYjViOGVmY2M=
2025-12-12 17:20:32,446 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NjMzMjBjYWEtOWRhOWNkOWYtNTgzOTkxZTAtYjViOGVmY2M=
2025-12-12 17:20:32,447 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 76ab990e-95fd-4108-b0fa-7be29ff829e6, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:20:32,447 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 76ab990e-95fd-4108-b0fa-7be29ff829e6, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=NjMzMjBjYWEtOWRhOWNkOWYtNTgzOTkxZTAtYjViOGVmY2M=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(8)" } stats_mode: STATS_MODE_NONE }
2025-12-12 17:20:32,448 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 76ab990e-95fd-4108-b0fa-7be29ff829e6, ghrun-lmjjgjftxu.auto.internal:8320): response = { <_MultiThreadedRendezvous object> }
2025-12-12 17:20:32,537 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZGJjNDZjZGUtNDMzNWFmZjUtYzZmMGE0MmUtZGE3MzhmM2U=
2025-12-12 17:20:32,538 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZGJjNDZjZGUtNDMzNWFmZjUtYzZmMGE0MmUtZGE3MzhmM2U=
2025-12-12 17:20:32,540 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NDBlYmNjN2ItMzU2NzA5NjgtNTU2YmE5MGItYzYxOGFlMjA=
2025-12-12 17:20:32,540 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NDBlYmNjN2ItMzU2NzA5NjgtNTU2YmE5MGItYzYxOGFlMjA=
2025-12-12 17:20:32,541 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 5539d648-a0c8-48ec-9d26-f078c94f19cd, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:20:32,541 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 5539d648-a0c8-48ec-9d26-f078c94f19cd, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=NDBlYmNjN2ItMzU2NzA5NjgtNTU2YmE5MGItYzYxOGFlMjA=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(3)" } stats_mode: STATS_MODE_NONE }
2025-12-12 17:20:32,542 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 5539d648-a0c8-48ec-9d26-f078c94f19cd, ghrun-lmjjgjftxu.auto.internal:8320): response = { <_MultiThreadedRendezvous object> }
2025-12-12 17:20:32,542 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, ece613d2-9d2f-446a-853c-98a7086edda5, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:20:32,543 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, ece613d2-9d2f-446a-853c-98a7086edda5, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=ZGJjNDZjZGUtNDMzNWFmZjUtYzZmMGE0MmUtZGE3MzhmM2U=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(5)" } stats_mode: STATS_MODE_NONE }
2025-12-12 17:20:32,543 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, ece613d2-9d2f-446a-853c-98a7086edda5, ghrun-lmjjgjftxu.auto.internal:8320): response = { <_MultiThreadedRendezvous object> }
2025-12-12 17:20:32,544 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NWM5MDAwZTctMzJmYzEyZWUtOTk5Mzg1OGItNzYwZDQ3MjM=
2025-12-12 17:20:32,545 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NWM5MDAwZTctMzJmYzEyZWUtOTk5Mzg1OGItNzYwZDQ3MjM=
2025-12-12 17:20:32,545 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 2bdc17e5-26dc-41e0-9dca-3414be05a566, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:20:32,545 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 2bdc17e5-26dc-41e0-9dca-3414be05a566, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=NWM5MDAwZTctMzJmYzEyZWUtOTk5Mzg1OGItNzYwZDQ3MjM=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(8)" } stats_mode: STATS_MODE_NONE }
2025-12-12 17:20:32,546 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 2bdc17e5-26dc-41e0-9dca-3414be05a566, ghrun-lmjjgjftxu.auto.internal:8320): response = { <_MultiThreadedRendezvous object> }
2025-12-12 17:20:32,557 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NzlkMzA0MmQtNGQwZGI0YmEtZWJjNWJhZTgtYzE5NDJhZTM=
2025-12-12 17:20:32,572 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NzlkMzA0MmQtNGQwZGI0YmEtZWJjNWJhZTgtYzE5NDJhZTM=
2025-12-12 17:20:32,566 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZWVjOTA2YzktODkxY2RiOTItOTJhNTgwMmItNjM4NzhmYzQ=
2025-12-12 17:20:32,566 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YjczMmEwMjYtZWQwMWVhY2EtMmNiNzBlMDQtMjBjZjkz
2025-12-12 17:20:32,573 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, bf2cfddc-a5da-49a5-97c8-6f2d34289a47, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:20:32,573 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YjczMmEwMjYtZWQwMWVhY2EtMmNiNzBlMDQtMjBjZjkz
2025-12-12 17:20:32,579 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 5c45257a-069d-454b-916b-63d25b8bc5a4, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:20:32,575 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, bf2cfddc-a5da-49a5-97c8-6f2d34289a47, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=NzlkMzA0MmQtNGQwZGI0YmEtZWJjNWJhZTgtYzE5NDJhZTM=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(7)" } stats_mode: STATS_MODE_NONE }
2025-12-12 17:20:32,579 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 5c45257a-069d-454b-916b-63d25b8bc5a4, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=YjczMmEwMjYtZWQwMWVhY2EtMmNiNzBlMDQtMjBjZjkz" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(8)" } stats_mode: STATS_MODE_NONE }
2025-12-12 17:20:32,581 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZWVjOTA2YzktODkxY2RiOTItOTJhNTgwMmItNjM4NzhmYzQ=
2025-12-12 17:20:32,581 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, bf2cfddc-a5da-49a5-97c8-6f2d34289a47, ghrun-lmjjgjftxu.auto.internal:8320): response = { <_MultiThreadedRendezvous object> }
2025-12-12 17:20:32,582 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 455a8f3f-d77b-4d12-a862-461ea8503f2f, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:20:32,583 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 455a8f3f-d77b-4d12-a862-461ea8503f2f, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=ZWVjOTA2YzktODkxY2RiOTItOTJhNTgwMmItNjM4NzhmYzQ=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(8)" } stats_mode: STATS_MODE_NONE }
2025-12-12 17:20:32,584 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 5c45257a-069d-454b-916b-63d25b8bc5a4, ghrun-lmjjgjftxu.auto.internal:8320): response = { <_MultiThreadedRendezvous object> }
2025-12-12 17:20:32,585 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 455a8f3f-d77b-4d12-a862-461ea8503f2f, ghrun-lmjjgjftxu.auto.internal:8320): response = { <_MultiThreadedRendezvous object> }
2025-12-12 17:20:32,646 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=Yzg3NWM1ZjktNjZlZGU1M2UtOWFjOTk2ODEtNzM2NjNiMDU=
2025-12-12 17:20:32,647 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=Yzg3NWM1ZjktNjZlZGU1M2UtOWFjOTk2ODEtNzM2NjNiMDU=
2025-12-12 17:20:32,647 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, e3012fd7-3d88-4fa0-9ef5-6a63cf09bd70, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:20:32,648 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, e3012fd7-3d88-4fa0-9ef5-6a63cf09bd70, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=Yzg3NWM1ZjktNjZlZGU1M2UtOWFjOTk2ODEtNzM2NjNiMDU=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(10)" } stats_mode: STATS_MODE_NONE }
2025-12-12 17:20:32,648 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, e3012fd7-3d88-4fa0-9ef5-6a63cf09bd70, ghrun-lmjjgjftxu.auto.internal:8320): response = { <_MultiThreadedRendezvous object> }
2025-12-12 17:20:33,009 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=Yzg3NWM1ZjktNjZlZGU1M2UtOWFjOTk2ODEtNzM2NjNiMDU=
2025-12-12 17:20:33,010 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=Yzg3NWM1ZjktNjZlZGU1M2UtOWFjOTk2ODEtNzM2NjNiMDU=
2025-12-12 17:20:33,010 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 5d071189-3339-4ef9-b033-6cef1eef7b74, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:20:33,022 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 5d071189-3339-4ef9-b033-6cef1eef7b74, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=Yzg3NWM1ZjktNjZlZGU1M2UtOWFjOTk2ODEtNzM2NjNiMDU=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(10)" } stats_mode: STATS_MODE_NONE }
2025-12-12 17:20:33,052 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 5d071189-3339-4ef9-b033-6cef1eef7b74, ghrun-lmjjgjftxu.auto.internal:8320): response = { <_MultiThreadedRendezvous object> }
2025-12-12 17:20:33,271 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=Yzg3NWM1ZjktNjZlZGU1M2UtOWFjOTk2ODEtNzM2NjNiMDU=
2025-12-12 17:20:33,284 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=Yzg3NWM1ZjktNjZlZGU1M2UtOWFjOTk2ODEtNzM2NjNiMDU=
2025-12-12 17:20:33,284 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 720fccf3-a277-4786-a884-96ae32631222, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:20:33,285 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 720fccf3-a277-4786-a884-96ae32631222, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=Yzg3NWM1ZjktNjZlZGU1M2UtOWFjOTk2ODEtNzM2NjNiMDU=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(11)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(10))" } stats_mode: STATS_MODE_NONE }
2025-12-12 17:20:33,286 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 720fccf3-a277-4786-a884-96ae32631222, ghrun-lmjjgjftxu.auto.internal:8320): response = { <_MultiThreadedRendezvous object> }
2025-12-12 17:20:33,721 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=Yzg3NWM1ZjktNjZlZGU1M2UtOWFjOTk2ODEtNzM2NjNiMDU=
2025-12-12 17:20:33,756 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MzI5OGIxY2YtN2IyODY3MDgtOGJhY2NlMWYtNmZmMTA0YjM=
2025-12-12 17:20:33,764 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=Yzg3NWM1ZjktNjZlZGU1M2UtOWFjOTk2ODEtNzM2NjNiMDU=
2025-12-12 17:20:33,765 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 0c7bbdcf-7579-448d-b279-82c5479cf6e8, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:20:33,765 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 0c7bbdcf-7579-448d-b279-82c5479cf6e8, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=Yzg3NWM1ZjktNjZlZGU1M2UtOWFjOTk2ODEtNzM2NjNiMDU=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(9)" } stats_mode: STATS_MODE_NONE }
2025-12-12 17:20:33,766 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 0c7bbdcf-7579-448d-b279-82c5479cf6e8, ghrun-lmjjgjftxu.auto.internal:8320): response = { <_MultiThreadedRendezvous object> }
2025-12-12 17:20:34,032 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZWVjOTA2YzktODkxY2RiOTItOTJhNTgwMmItNjM4NzhmYzQ=
2025-12-12 17:20:34,086 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MzI5OGIxY2YtN2IyODY3MDgtOGJhY2NlMWYtNmZmMTA0YjM=
2025-12-12 17:20:34,089 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 20f930c9-67af-4e75-932e-31b960404f1b, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:20:34,089 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 20f930c9-67af-4e75-932e-31b960404f1b, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=MzI5OGIxY2YtN2IyODY3MDgtOGJhY2NlMWYtNmZmMTA0YjM=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(8)" } stats_mode: STATS_MODE_NONE }
2025-12-12 17:20:34,097 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 20f930c9-67af-4e75-932e-31b960404f1b, ghrun-lmjjgjftxu.auto.internal:8320): response = { <_MultiThreadedRendezvous object> }
2025-12-12 17:20:34,124 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NWM5MDAwZTctMzJmYzEyZWUtOTk5Mzg1OGItNzYwZDQ3MjM=
2025-12-12 17:20:34,126 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZWVjOTA2YzktODkxY2RiOTItOTJhNTgwMmItNjM4NzhmYzQ=
2025-12-12 17:20:34,136 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZTE1Zjk1OTctNzRiOTQyYTgtOGMwY2MxYWYtNGZiM2ZmMzY=
2025-12-12 17:20:34,151 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NjMzMjBjYWEtOWRhOWNkOWYtNTgzOTkxZTAtYjViOGVmY2M=
2025-12-12 17:20:34,155 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 0678f520-b00d-44a1-88a7-dbc1645afcd2, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:20:34,179 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NWM5MDAwZTctMzJmYzEyZWUtOTk5Mzg1OGItNzYwZDQ3MjM=
2025-12-12 17:20:34,190 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YjczMmEwMjYtZWQwMWVhY2EtMmNiNzBlMDQtMjBjZjkz
2025-12-12 17:20:34,194 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 0678f520-b00d-44a1-88a7-dbc1645afcd2, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=ZWVjOTA2YzktODkxY2RiOTItOTJhNTgwMmItNjM4NzhmYzQ=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(8)" } stats_mode: STATS_MODE_NONE }
2025-12-12 17:20:34,197 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, be89382e-6634-41a5-acf2-8a8fe4d5330f, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:20:34,202 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZTE1Zjk1OTctNzRiOTQyYTgtOGMwY2MxYWYtNGZiM2ZmMzY=
2025-12-12 17:20:34,208 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, be89382e-6634-41a5-acf2-8a8fe4d5330f, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=NWM5MDAwZTctMzJmYzEyZWUtOTk5Mzg1OGItNzYwZDQ3MjM=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(8)" } stats_mode: STATS_MODE_NONE }
2025-12-12 17:20:34,208 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 7539fad2-a53c-4e85-9c78-b1e203b150f4, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:20:34,209 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 0678f520-b00d-44a1-88a7-dbc1645afcd2, ghrun-lmjjgjftxu.auto.internal:8320): response = { <_MultiThreadedRendezvous object> }
2025-12-12 17:20:34,209 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NjMzMjBjYWEtOWRhOWNkOWYtNTgzOTkxZTAtYjViOGVmY2M=
2025-12-12 17:20:34,210 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 7539fad2-a53c-4e85-9c78-b1e203b150f4, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=ZTE1Zjk1OTctNzRiOTQyYTgtOGMwY2MxYWYtNGZiM2ZmMzY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(8)" } stats_mode: STATS_MODE_NONE }
2025-12-12 17:20:34,210 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, be89382e-6634-41a5-acf2-8a8fe4d5330f, ghrun-lmjjgjftxu.auto.internal:8320): response = { <_MultiThreadedRendezvous object> }
2025-12-12 17:20:34,211 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 7ae88693-21f6-46ba-a538-583ab4babbf5, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:20:34,212 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 7ae88693-21f6-46ba-a538-583ab4babbf5, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=NjMzMjBjYWEtOWRhOWNkOWYtNTgzOTkxZTAtYjViOGVmY2M=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(8)" } stats_mode: STATS_MODE_NONE }
2025-12-12 17:20:34,212 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 7539fad2-a53c-4e85-9c78-b1e203b150f4, ghrun-lmjjgjftxu.auto.internal:8320): response = { <_MultiThreadedRendezvous object> }
2025-12-12 17:20:34,222 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 7ae88693-21f6-46ba-a538-583ab4babbf5, ghrun-lmjjgjftxu.auto.internal:8320): response = { <_MultiThreadedRendezvous object> }
2025-12-12 17:20:34,308 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=Yzg3NWM1ZjktNjZlZGU1M2UtOWFjOTk2ODEtNzM2NjNiMDU=
2025-12-12 17:20:34,309 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YjczMmEwMjYtZWQwMWVhY2EtMmNiNzBlMDQtMjBjZjkz
2025-12-12 17:20:34,316 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, fc3b423d-b59f-49cd-8073-b7191b2d8c43, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:20:34,318 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, fc3b423d-b59f-49cd-8073-b7191b2d8c43, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=YjczMmEwMjYtZWQwMWVhY2EtMmNiNzBlMDQtMjBjZjkz" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(10)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(9))" } stats_mode: STATS_MODE_NONE }
2025-12-12 17:20:34,327 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, fc3b423d-b59f-49cd-8073-b7191b2d8c43, ghrun-lmjjgjftxu.auto.internal:8320): response = { <_MultiThreadedRendezvous object> }
2025-12-12 17:20:34,962 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YjczMmEwMjYtZWQwMWVhY2EtMmNiNzBlMDQtMjBjZjkz
2025-12-12 17:20:35,038 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MzI5OGIxY2YtN2IyODY3MDgtOGJhY2NlMWYtNmZmMTA0YjM=
2025-12-12 17:20:35,038 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=Yzg3NWM1ZjktNjZlZGU1M2UtOWFjOTk2ODEtNzM2NjNiMDU=
2025-12-12 17:20:35,039 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 36fa7293-a229-460d-93c3-4e7e5b2a7944, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:20:35,039 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 36fa7293-a229-460d-93c3-4e7e5b2a7944, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=Yzg3NWM1ZjktNjZlZGU1M2UtOWFjOTk2ODEtNzM2NjNiMDU=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(9)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(8))" } stats_mode: STATS_MODE_NONE }
2025-12-12 17:20:35,040 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 36fa7293-a229-460d-93c3-4e7e5b2a7944, ghrun-lmjjgjftxu.auto.internal:8320): response = { <_MultiThreadedRendezvous object> }
2025-12-12 17:20:35,045 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NjMzMjBjYWEtOWRhOWNkOWYtNTgzOTkxZTAtYjViOGVmY2M=
2025-12-12 17:20:35,047 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NWM5MDAwZTctMzJmYzEyZWUtOTk5Mzg1OGItNzYwZDQ3MjM=
2025-12-12 17:20:35,048 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZWVjOTA2YzktODkxY2RiOTItOTJhNTgwMmItNjM4NzhmYzQ=
2025-12-12 17:20:35,049 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZTE1Zjk1OTctNzRiOTQyYTgtOGMwY2MxYWYtNGZiM2ZmMzY=
2025-12-12 17:20:35,058 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YjczMmEwMjYtZWQwMWVhY2EtMmNiNzBlMDQtMjBjZjkz
2025-12-12 17:20:35,061 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, abcb6f00-4747-4fdb-8bc5-64bad8138826, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:20:35,061 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, abcb6f00-4747-4fdb-8bc5-64bad8138826, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=YjczMmEwMjYtZWQwMWVhY2EtMmNiNzBlMDQtMjBjZjkz" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(9)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(8))" } stats_mode: STATS_MODE_NONE }
2025-12-12 17:20:35,062 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MzI5OGIxY2YtN2IyODY3MDgtOGJhY2NlMWYtNmZmMTA0YjM=
2025-12-12 17:20:35,064 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, e7552719-a3e6-4dff-b239-b6f09ba6c814, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:20:35,065 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, e7552719-a3e6-4dff-b239-b6f09ba6c814, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=MzI5OGIxY2YtN2IyODY3MDgtOGJhY2NlMWYtNmZmMTA0YjM=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(9)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(8))" } stats_mode: STATS_MODE_NONE }
2025-12-12 17:20:35,065 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NjMzMjBjYWEtOWRhOWNkOWYtNTgzOTkxZTAtYjViOGVmY2M=
2025-12-12 17:20:35,066 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, cd37b97d-2c53-4754-827e-238113d7649d, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:20:35,067 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NWM5MDAwZTctMzJmYzEyZWUtOTk5Mzg1OGItNzYwZDQ3MjM=
2025-12-12 17:20:35,067 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, cd37b97d-2c53-4754-827e-238113d7649d, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=NjMzMjBjYWEtOWRhOWNkOWYtNTgzOTkxZTAtYjViOGVmY2M=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(9)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(8))" } stats_mode: STATS_MODE_NONE }
2025-12-12 17:20:35,067 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, abcb6f00-4747-4fdb-8bc5-64bad8138826, ghrun-lmjjgjftxu.auto.internal:8320): response = { <_MultiThreadedRendezvous object> }
2025-12-12 17:20:35,068 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 07e2a81d-05eb-4afe-ad0d-fbe4bde10aa7, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:20:35,069 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NzlkMzA0MmQtNGQwZGI0YmEtZWJjNWJhZTgtYzE5NDJhZTM=
2025-12-12 17:20:35,069 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, e7552719-a3e6-4dff-b239-b6f09ba6c814, ghrun-lmjjgjftxu.auto.internal:8320): response = { <_MultiThreadedRendezvous object> }
2025-12-12 17:20:35,070 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, cd37b97d-2c53-4754-827e-238113d7649d, ghrun-lmjjgjftxu.auto.internal:8320): response = { <_MultiThreadedRendezvous object> }
2025-12-12 17:20:35,071 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 07e2a81d-05eb-4afe-ad0d-fbe4bde10aa7, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=NWM5MDAwZTctMzJmYzEyZWUtOTk5Mzg1OGItNzYwZDQ3MjM=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(9)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(8))" } stats_mode: STATS_MODE_NONE }
2025-12-12 17:20:35,075 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZWVjOTA2YzktODkxY2RiOTItOTJhNTgwMmItNjM4NzhmYzQ=
2025-12-12 17:20:35,081 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 18e23f8a-1eac-4c76-b267-0d8ab4e978ae, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:20:35,082 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 18e23f8a-1eac-4c76-b267-0d8ab4e978ae, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=ZWVjOTA2YzktODkxY2RiOTItOTJhNTgwMmItNjM4NzhmYzQ=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(7)" } stats_mode: STATS_MODE_NONE }
2025-12-12 17:20:35,083 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 07e2a81d-05eb-4afe-ad0d-fbe4bde10aa7, ghrun-lmjjgjftxu.auto.internal:8320): response = { <_MultiThreadedRendezvous object> }
2025-12-12 17:20:35,084 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 18e23f8a-1eac-4c76-b267-0d8ab4e978ae, ghrun-lmjjgjftxu.auto.internal:8320): response = { <_MultiThreadedRendezvous object> }
2025-12-12 17:20:35,566 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MzI5OGIxY2YtN2IyODY3MDgtOGJhY2NlMWYtNmZmMTA0YjM=
2025-12-12 17:20:35,568 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=Yzg3NWM1ZjktNjZlZGU1M2UtOWFjOTk2ODEtNzM2NjNiMDU=
2025-12-12 17:20:35,570 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NjMzMjBjYWEtOWRhOWNkOWYtNTgzOTkxZTAtYjViOGVmY2M=
2025-12-12 17:20:35,575 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YjczMmEwMjYtZWQwMWVhY2EtMmNiNzBlMDQtMjBjZjkz
2025-12-12 17:20:35,580 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NWM5MDAwZTctMzJmYzEyZWUtOTk5Mzg1OGItNzYwZDQ3MjM=
2025-12-12 17:20:35,591 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZWVjOTA2YzktODkxY2RiOTItOTJhNTgwMmItNjM4NzhmYzQ=
2025-12-12 17:20:35,592 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZTE1Zjk1OTctNzRiOTQyYTgtOGMwY2MxYWYtNGZiM2ZmMzY=
2025-12-12 17:20:35,592 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 240d9e76-1f84-4623-bb7f-0f4181b2e494, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:20:35,592 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 240d9e76-1f84-4623-bb7f-0f4181b2e494, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=ZTE1Zjk1OTctNzRiOTQyYTgtOGMwY2MxYWYtNGZiM2ZmMzY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(8)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(7))" } stats_mode: STATS_MODE_NONE }
2025-12-12 17:20:35,593 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 240d9e76-1f84-4623-bb7f-0f4181b2e494, ghrun-lmjjgjftxu.auto.internal:8320): response = { <_MultiThreadedRendezvous object> }
2025-12-12 17:20:35,999 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZGJjNDZjZGUtNDMzNWFmZjUtYzZmMGE0MmUtZGE3MzhmM2U=
2025-12-12 17:20:36,013 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NzlkMzA0MmQtNGQwZGI0YmEtZWJjNWJhZTgtYzE5NDJhZTM=
2025-12-12 17:20:36,014 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 2054155f-491a-4728-a820-f933e359b70e, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:20:36,014 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 2054155f-491a-4728-a820-f933e359b70e, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=NzlkMzA0MmQtNGQwZGI0YmEtZWJjNWJhZTgtYzE5NDJhZTM=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(5)" } stats_mode: STATS_MODE_NONE }
2025-12-12 17:20:36,015 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 2054155f-491a-4728-a820-f933e359b70e, ghrun-lmjjgjftxu.auto.internal:8320): response = { <_MultiThreadedRendezvous object> }
2025-12-12 17:20:36,021 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZTE1Zjk1OTctNzRiOTQyYTgtOGMwY2MxYWYtNGZiM2ZmMzY=
2025-12-12 17:20:36,518 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NzlkMzA0MmQtNGQwZGI0YmEtZWJjNWJhZTgtYzE5NDJhZTM=
2025-12-12 17:20:36,523 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MzI5OGIxY2YtN2IyODY3MDgtOGJhY2NlMWYtNmZmMTA0YjM=
2025-12-12 17:20:36,534 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, b819130b-723b-4850-9849-e2bd20312f2c, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:20:36,545 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, b819130b-723b-4850-9849-e2bd20312f2c, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=MzI5OGIxY2YtN2IyODY3MDgtOGJhY2NlMWYtNmZmMTA0YjM=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(6)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(5))" } stats_mode: STATS_MODE_NONE }
2025-12-12 17:20:36,560 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, b819130b-723b-4850-9849-e2bd20312f2c, ghrun-lmjjgjftxu.auto.internal:8320): response = { <_MultiThreadedRendezvous object> }
2025-12-12 17:20:36,571 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NDBlYmNjN2ItMzU2NzA5NjgtNTU2YmE5MGItYzYxOGFlMjA=
2025-12-12 17:20:36,609 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=Yzg3NWM1ZjktNjZlZGU1M2UtOWFjOTk2ODEtNzM2NjNiMDU=
2025-12-12 17:20:36,615 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, b28d05f5-e5dc-46fb-8639-2d5354812bd3, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:20:36,634 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, b28d05f5-e5dc-46fb-8639-2d5354812bd3, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=Yzg3NWM1ZjktNjZlZGU1M2UtOWFjOTk2ODEtNzM2NjNiMDU=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(3)" } stats_mode: STATS_MODE_NONE }
2025-12-12 17:20:36,648 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, b28d05f5-e5dc-46fb-8639-2d5354812bd3, ghrun-lmjjgjftxu.auto.internal:8320): response = { <_MultiThreadedRendezvous object> }
2025-12-12 17:20:36,889 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MzI5OGIxY2YtN2IyODY3MDgtOGJhY2NlMWYtNmZmMTA0YjM=
2025-12-12 17:20:37,014 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=Yzg3NWM1ZjktNjZlZGU1M2UtOWFjOTk2ODEtNzM2NjNiMDU=
2025-12-12 17:20:37,014 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NjMzMjBjYWEtOWRhOWNkOWYtNTgzOTkxZTAtYjViOGVmY2M=
2025-12-12 17:20:37,015 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 325b612a-c5a1-4baa-ae5a-74cffbebb2d3, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:20:37,015 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 325b612a-c5a1-4baa-ae5a-74cffbebb2d3, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=NjMzMjBjYWEtOWRhOWNkOWYtNTgzOTkxZTAtYjViOGVmY2M=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(4)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(3))" } stats_mode: STATS_MODE_NONE }
2025-12-12 17:20:37,016 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 325b612a-c5a1-4baa-ae5a-74cffbebb2d3, ghrun-lmjjgjftxu.auto.internal:8320): response = { <_MultiThreadedRendezvous object> }
2025-12-12 17:20:37,300 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NjMzMjBjYWEtOWRhOWNkOWYtNTgzOTkxZTAtYjViOGVmY2M=
2025-12-12 17:20:37,318 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YjczMmEwMjYtZWQwMWVhY2EtMmNiNzBlMDQtMjBjZjkz
2025-12-12 17:20:37,318 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 0d3d5f9b-b253-44b8-924d-afa4f4178ff9, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:20:37,319 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 0d3d5f9b-b253-44b8-924d-afa4f4178ff9, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=YjczMmEwMjYtZWQwMWVhY2EtMmNiNzBlMDQtMjBjZjkz" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "select count(*) as Rows from `log`" } stats_mode: STATS_MODE_NONE }
2025-12-12 17:20:37,319 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 0d3d5f9b-b253-44b8-924d-afa4f4178ff9, ghrun-lmjjgjftxu.auto.internal:8320): response = { <_MultiThreadedRendezvous object> }
2025-12-12 17:20:37,583 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YjczMmEwMjYtZWQwMWVhY2EtMmNiNzBlMDQtMjBjZjkz
2025-12-12 17:20:37,583 - INFO - root - test_log_deviation: check insert: 25000 20000
2025-12-12 17:20:37,585 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.10
2025-12-12 17:20:37,585 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.10
2025-12-12 17:20:37,586 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/cfdu/002020/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:8320', '-d', '/Root', 'workload', 'log', '--path', 'log', 'clean']' in 'None' (waiting)
2025-12-12 17:20:37,587 - DEBUG - ya.test - execute: Command pid: 275015
2025-12-12 17:20:37,730 - DEBUG - ya.test - _save_outputs: Command (pid 275015) rc: 0
2025-12-12 17:20:37,731 - DEBUG - ya.test - _save_outputs: Command (pid 275015) elapsed time (sec): 0.14320898056030273
2025-12-12 17:20:37,731 - DEBUG - ya.test - _save_outputs: Command (pid 275015) idrss: 0
2025-12-12 17:20:37,731 - DEBUG - ya.test - _save_outputs: Command (pid 275015) inblock: 0
2025-12-12 17:20:37,731 - DEBUG - ya.test - _save_outputs: Command (pid 275015) isrss: 0
2025-12-12 17:20:37,731 - DEBUG - ya.test - _save_outputs: Command (pid 275015) ixrss: 0
2025-12-12 17:20:37,732 - DEBUG - ya.test - _save_outputs: Command (pid 275015) majflt: 0
2025-12-12 17:20:37,732 - DEBUG - ya.test - _save_outputs: Command (pid 275015) maxrss: 658520
2025-12-12 17:20:37,732 - DEBUG - ya.test - _save_outputs: Command (pid 275015) minflt: 3487
2025-12-12 17:20:37,732 - DEBUG - ya.test - _save_outputs: Command (pid 275015) msgrcv: 0
2025-12-12 17:20:37,732 - DEBUG - ya.test - _save_outputs: Command (pid 275015) msgsnd: 0
2025-12-12 17:20:37,732 - DEBUG - ya.test - _save_outputs: Command (pid 275015) nivcsw: 5
2025-12-12 17:20:37,732 - DEBUG - ya.test - _save_outputs: Command (pid 275015) nsignals: 0
2025-12-12 17:20:37,733 - DEBUG - ya.test - _save_outputs: Command (pid 275015) nswap: 0
2025-12-12 17:20:37,733 - DEBUG - ya.test - _save_outputs: Command (pid 275015) nvcsw: 201
2025-12-12 17:20:37,733 - DEBUG - ya.test - _save_outputs: Command (pid 275015) oublock: 8
2025-12-12 17:20:37,733 - DEBUG - ya.test - _save_outputs: Command (pid 275015) stime: 0.016760999999999998
2025-12-12 17:20:37,733 - DEBUG - ya.test - _save_outputs: Command (pid 275015) utime: 0.041901999999999995
2025-12-12 17:20:37,733 - DEBUG - ya.test - _save_outputs: Command (pid 275015) wtime: 0.144
2025-12-12 17:20:37,734 - DEBUG - ya.test - _save_outputs: Command (pid 275015) output:
Remove path log...
Remove path log...Ok

2025-12-12 17:20:37,734 - DEBUG - ya.test - _save_outputs: Command (pid 275015) errors:

2025-12-12 17:20:37,736 - INFO - ya.test - pytest_runtest_teardown: Test teardown
2025-12-12 17:20:37,737 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, 30383256-ac0b-46ef-8dc9-9539ab836943, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:20:37,737 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, 30383256-ac0b-46ef-8dc9-9539ab836943, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=NWM5MDAwZTctMzJmYzEyZWUtOTk5Mzg1OGItNzYwZDQ3MjM=" }
2025-12-12 17:20:37,762 - DEBUG - ydb.connection - _log_response: RpcState(DeleteSession, 30383256-ac0b-46ef-8dc9-9539ab836943, ghrun-lmjjgjftxu.auto.internal:8320): response = { status: SUCCESS }
2025-12-12 17:20:37,764 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, 51e7dab7-caab-4fe1-a8dc-c29b589b7b31, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:20:37,764 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, 51e7dab7-caab-4fe1-a8dc-c29b589b7b31, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=ZWVjOTA2YzktODkxY2RiOTItOTJhNTgwMmItNjM4NzhmYzQ=" }
2025-12-12 17:20:37,766 - DEBUG - ydb.connection - _log_response: RpcState(DeleteSession, 51e7dab7-caab-4fe1-a8dc-c29b589b7b31, ghrun-lmjjgjftxu.auto.internal:8320): response = { status: SUCCESS }
2025-12-12 17:20:37,766 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, 69377187-0b16-4f53-be1e-3e83973d47d6, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:20:37,767 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, 69377187-0b16-4f53-be1e-3e83973d47d6, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=ZGJjNDZjZGUtNDMzNWFmZjUtYzZmMGE0MmUtZGE3MzhmM2U=" }
2025-12-12 17:20:37,768 - DEBUG - ydb.connection - _log_response: RpcState(DeleteSession, 69377187-0b16-4f53-be1e-3e83973d47d6, ghrun-lmjjgjftxu.auto.internal:8320): response = { status: SUCCESS }
2025-12-12 17:20:37,769 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, 5fd2b115-65d7-43c5-bd60-4f7b932bf4a6, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:20:37,769 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, 5fd2b115-65d7-43c5-bd60-4f7b932bf4a6, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=ZTE1Zjk1OTctNzRiOTQyYTgtOGMwY2MxYWYtNGZiM2ZmMzY=" }
2025-12-12 17:20:37,772 - DEBUG - ydb.connection - _log_response: RpcState(DeleteSession, 5fd2b115-65d7-43c5-bd60-4f7b932bf4a6, ghrun-lmjjgjftxu.auto.internal:8320): response = { status: SUCCESS }
2025-12-12 17:20:37,773 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, 984f261e-c56d-4bef-b125-cffd14385ca3, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:20:37,773 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, 984f261e-c56d-4bef-b125-cffd14385ca3, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=NzlkMzA0MmQtNGQwZGI0YmEtZWJjNWJhZTgtYzE5NDJhZTM=" }
2025-12-12 17:20:37,775 - DEBUG - ydb.connection - _log_response: RpcState(DeleteSession, 984f261e-c56d-4bef-b125-cffd14385ca3, ghrun-lmjjgjftxu.auto.internal:8320): response = { status: SUCCESS }
2025-12-12 17:20:37,775 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, 462d8676-994f-4a9d-9502-88d33bf9863a, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:20:37,777 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, 462d8676-994f-4a9d-9502-88d33bf9863a, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=NDBlYmNjN2ItMzU2NzA5NjgtNTU2YmE5MGItYzYxOGFlMjA=" }
2025-12-12 17:20:37,779 - DEBUG - ydb.connection - _log_response: RpcState(DeleteSession, 462d8676-994f-4a9d-9502-88d33bf9863a, ghrun-lmjjgjftxu.auto.internal:8320): response = { status: SUCCESS }
2025-12-12 17:20:37,781 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, b4c286f8-4525-4889-a397-130b9e6e88eb, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:20:37,781 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, b4c286f8-4525-4889-a397-130b9e6e88eb, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=MzI5OGIxY2YtN2IyODY3MDgtOGJhY2NlMWYtNmZmMTA0YjM=" }
2025-12-12 17:20:37,782 - DEBUG - ydb.connection - _log_response: RpcState(DeleteSession, b4c286f8-4525-4889-a397-130b9e6e88eb, ghrun-lmjjgjftxu.auto.internal:8320): response = { status: SUCCESS }
2025-12-12 17:20:37,783 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, 9d81f5a6-71ea-43a3-9364-75ab5b5e4763, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:20:37,783 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, 9d81f5a6-71ea-43a3-9364-75ab5b5e4763, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=Yzg3NWM1ZjktNjZlZGU1M2UtOWFjOTk2ODEtNzM2NjNiMDU=" }
2025-12-12 17:20:37,811 - DEBUG - ydb.connection - _log_response: RpcState(DeleteSession, 9d81f5a6-71ea-43a3-9364-75ab5b5e4763, ghrun-lmjjgjftxu.auto.internal:8320): response = { status: SUCCESS }
2025-12-12 17:20:37,818 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, fa49edd9-3fa1-4c9f-b1d8-857c73552e20, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:20:37,830 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, fa49edd9-3fa1-4c9f-b1d8-857c73552e20, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=NjMzMjBjYWEtOWRhOWNkOWYtNTgzOTkxZTAtYjViOGVmY2M=" }
2025-12-12 17:20:37,831 - DEBUG - ydb.connection - _log_response: RpcState(DeleteSession, fa49edd9-3fa1-4c9f-b1d8-857c73552e20, ghrun-lmjjgjftxu.auto.internal:8320): response = { status: SUCCESS }
2025-12-12 17:20:37,843 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, 472cd0ba-4672-4650-8e68-be57b5d6d411, ghrun-lmjjgjftxu.auto.internal:8320): creating call state
2025-12-12 17:20:37,845 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, 472cd0ba-4672-4650-8e68-be57b5d6d411, ghrun-lmjjgjftxu.auto.internal:8320): request = { session_id: "ydb://session/3?node_id=1&id=YjczMmEwMjYtZWQwMWVhY2EtMmNiNzBlMDQtMjBjZjkz" }
2025-12-12 17:20:37,847 - DEBUG - ydb.connection - _log_response: RpcState(DeleteSession, 472cd0ba-4672-4650-8e68-be57b5d6d411, ghrun-lmjjgjftxu.auto.internal:8320): response = { status: SUCCESS }
2025-12-12 17:20:37,847 - DEBUG - ydb.query.pool - stop: All session were deleted.
2025-12-12 17:20:37,848 - DEBUG - ydb.topic - close: Close topic client
2025-12-12 17:20:37,849 - DEBUG - ydb.topic - close: Topic client was closed
2025-12-12 17:20:37,849 - INFO - ydb.connection - close: Closing channel for endpoint localhost:8320
2025-12-12 17:20:37,849 - INFO - ydb.connection - close: Closing channel for endpoint ghrun-lmjjgjftxu.auto.internal:8320
2025-12-12 17:20:37,851 - INFO - ydb.pool.Discovery - run: Successfully terminated discovery process
2025-12-12 17:20:44,852 - INFO - ydb.tests.library.harness.kikimr_runner - stop: Stopped node localhost:8320/1
2025-12-12 17:20:44,883 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/3962
2025-12-12 17:20:44,896 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/13750
2025-12-12 17:20:44,919 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/20961
2025-12-12 17:20:44,930 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/8320
2025-12-12 17:20:44,958 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/3448
