2025-11-25 15:04:30,536 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-11-25 15:04:30,553 - INFO - ya.test - pytest_runtest_setup: test_log_deviation[180]
2025-11-25 15:04:30,554 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-11-25 15:04:30,554 - INFO - ya.test - pytest_runtest_setup: Test setup
2025-11-25 15:04:30,560 - INFO - ya.test - pytest_runtest_call: Test call (class_name: test_log_scenario.py::TestLogScenario, test_name: test_log_deviation[180])
2025-11-25 15:04:30,560 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/fvd5/0002c2/ydb/apps/ydb/ydb
2025-11-25 15:04:30,564 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/fvd5/0002c2/ydb/apps/ydb/ydb -e grpc://localhost:4007 -d /Root workload log --path log init --path log --store column --ttl 1000 with wait = True
2025-11-25 15:04:30,565 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.5
2025-11-25 15:04:30,567 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.5
2025-11-25 15:04:30,575 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/fvd5/0002c2/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:4007', '-d', '/Root', 'workload', 'log', '--path', 'log', 'init', '--path', 'log', '--store', 'column', '--ttl', '1000']' in 'None' (waiting)
2025-11-25 15:04:30,589 - DEBUG - ya.test - execute: Command pid: 3917104
2025-11-25 15:04:31,237 - DEBUG - ya.test - _save_outputs: Command (pid 3917104) rc: 0
2025-11-25 15:04:31,238 - DEBUG - ya.test - _save_outputs: Command (pid 3917104) elapsed time (sec): 0.642174482345581
2025-11-25 15:04:31,239 - DEBUG - ya.test - _save_outputs: Command (pid 3917104) idrss: 0
2025-11-25 15:04:31,239 - DEBUG - ya.test - _save_outputs: Command (pid 3917104) inblock: 0
2025-11-25 15:04:31,239 - DEBUG - ya.test - _save_outputs: Command (pid 3917104) isrss: 0
2025-11-25 15:04:31,252 - DEBUG - ya.test - _save_outputs: Command (pid 3917104) ixrss: 0
2025-11-25 15:04:31,259 - DEBUG - ya.test - _save_outputs: Command (pid 3917104) majflt: 0
2025-11-25 15:04:31,264 - DEBUG - ya.test - _save_outputs: Command (pid 3917104) maxrss: 799556
2025-11-25 15:04:31,267 - DEBUG - ya.test - _save_outputs: Command (pid 3917104) minflt: 3474
2025-11-25 15:04:31,272 - DEBUG - ya.test - _save_outputs: Command (pid 3917104) msgrcv: 0
2025-11-25 15:04:31,272 - DEBUG - ya.test - _save_outputs: Command (pid 3917104) msgsnd: 0
2025-11-25 15:04:31,273 - DEBUG - ya.test - _save_outputs: Command (pid 3917104) nivcsw: 39
2025-11-25 15:04:31,273 - DEBUG - ya.test - _save_outputs: Command (pid 3917104) nsignals: 0
2025-11-25 15:04:31,273 - DEBUG - ya.test - _save_outputs: Command (pid 3917104) nswap: 0
2025-11-25 15:04:31,273 - DEBUG - ya.test - _save_outputs: Command (pid 3917104) nvcsw: 151
2025-11-25 15:04:31,273 - DEBUG - ya.test - _save_outputs: Command (pid 3917104) oublock: 8
2025-11-25 15:04:31,278 - DEBUG - ya.test - _save_outputs: Command (pid 3917104) stime: 0.021699
2025-11-25 15:04:31,279 - DEBUG - ya.test - _save_outputs: Command (pid 3917104) utime: 0.052076
2025-11-25 15:04:31,279 - DEBUG - ya.test - _save_outputs: Command (pid 3917104) wtime: 0.649
2025-11-25 15:04:31,279 - DEBUG - ya.test - _save_outputs: Command (pid 3917104) output:
Init tables ...
Init tables ...Ok

2025-11-25 15:04:31,279 - DEBUG - ya.test - _save_outputs: Command (pid 3917104) errors:

2025-11-25 15:04:31,280 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ODU2ODJhMDgtY2JlZjFlYWUtN2QzODE3Ni1lMGUyNzFjYQ==
2025-11-25 15:04:31,280 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 25bf365f-cf40-4a8c-8282-4f45fff8900b, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:04:31,282 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 25bf365f-cf40-4a8c-8282-4f45fff8900b, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=ODU2ODJhMDgtY2JlZjFlYWUtN2QzODE3Ni1lMGUyNzFjYQ==" 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-11-25 15:04:31,298 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 25bf365f-cf40-4a8c-8282-4f45fff8900b, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:04:31,333 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ODU2ODJhMDgtY2JlZjFlYWUtN2QzODE3Ni1lMGUyNzFjYQ==
2025-11-25 15:04:31,333 - INFO - root - _insert_rows: YdbWorkloadLog bulk_upsert
2025-11-25 15:04:31,334 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/fvd5/0002c2/ydb/apps/ydb/ydb -e grpc://localhost:4007 -d /Root workload log --path log run bulk_upsert --seconds 3 --threads 10 --rows 500 --timestamp_deviation 180 with wait = True
2025-11-25 15:04:31,336 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.6
2025-11-25 15:04:31,340 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.6
2025-11-25 15:04:31,344 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/fvd5/0002c2/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:4007', '-d', '/Root', 'workload', 'log', '--path', 'log', 'run', 'bulk_upsert', '--seconds', '3', '--threads', '10', '--rows', '500', '--timestamp_deviation', '180']' in 'None' (waiting)
2025-11-25 15:04:31,345 - DEBUG - ya.test - execute: Command pid: 3917193
2025-11-25 15:04:36,083 - DEBUG - ya.test - _wait: Process resource usage is not available as process finished before wait4 was called
2025-11-25 15:04:36,083 - DEBUG - ya.test - _save_outputs: Command (pid 3917193) rc: 0
2025-11-25 15:04:36,094 - DEBUG - ya.test - _save_outputs: Command (pid 3917193) elapsed time (sec): 4.736616134643555
2025-11-25 15:04:36,094 - DEBUG - ya.test - _save_outputs: Command (pid 3917193) wtime: 4.738
2025-11-25 15:04:36,096 - DEBUG - ya.test - _save_outputs: Command (pid 3917193) output:
Window	    Txs	Txs/Sec	Retries	Errors	p50(ms)	p95(ms)	p99(ms)	pMax(ms)
1	      2	2	0	0	627	823	823	823
2	      9	9	0	0	1135	1367	1367	1367
3	     19	19	0	0	1375	1591	1647	1647

Total	    Txs	Txs/Sec	Retries	Errors	p50(ms)	p95(ms)	p99(ms)	pMax(ms)
3	     30	10	0	0	1175	1591	1647	1647

2025-11-25 15:04:36,107 - DEBUG - ya.test - _save_outputs: Command (pid 3917193) errors:

2025-11-25 15:04:36,107 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MTQxYTEwMDUtZTFkMGFhN2MtMTEwNzE4MzAtZjMwZmMzNjc=
2025-11-25 15:04:36,111 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, e7967e9e-3c24-48c7-86fb-0cb4fbc16838, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:04:36,112 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, e7967e9e-3c24-48c7-86fb-0cb4fbc16838, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=MTQxYTEwMDUtZTFkMGFhN2MtMTEwNzE4MzAtZjMwZmMzNjc=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "select count(*) as Rows from `log`" } stats_mode: STATS_MODE_NONE }
2025-11-25 15:04:36,113 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, e7967e9e-3c24-48c7-86fb-0cb4fbc16838, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:04:37,492 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MTQxYTEwMDUtZTFkMGFhN2MtMTEwNzE4MzAtZjMwZmMzNjc=
2025-11-25 15:04:37,492 - INFO - root - test_log_deviation: Count rows after insert 15000 before wait
2025-11-25 15:04:37,492 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YmI4NDQ2NGMtMWZiN2JjMTktM2Q4Zjk5MjktMjQ4NGJhZWY=
2025-11-25 15:04:37,493 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 74e35884-8316-4eef-a8ab-37fd458b32a8, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:04:37,495 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 74e35884-8316-4eef-a8ab-37fd458b32a8, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=YmI4NDQ2NGMtMWZiN2JjMTktM2Q4Zjk5MjktMjQ4NGJhZWY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "select count(*) as Rows from `log`" } stats_mode: STATS_MODE_NONE }
2025-11-25 15:04:37,496 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 74e35884-8316-4eef-a8ab-37fd458b32a8, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:04:38,517 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YmI4NDQ2NGMtMWZiN2JjMTktM2Q4Zjk5MjktMjQ4NGJhZWY=
2025-11-25 15:04:38,518 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=Yjc1ZTk3MDEtNzMyMTQ4NjAtYmIyYWE5NWQtN2JlZDNhNmY=
2025-11-25 15:04:38,518 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, f5ab43a1-f005-4c6e-aba9-ee0639ed993b, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:04:38,519 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, f5ab43a1-f005-4c6e-aba9-ee0639ed993b, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=Yjc1ZTk3MDEtNzMyMTQ4NjAtYmIyYWE5NWQtN2JlZDNhNmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "select count(*) as Rows from `log`" } stats_mode: STATS_MODE_NONE }
2025-11-25 15:04:38,519 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, f5ab43a1-f005-4c6e-aba9-ee0639ed993b, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:04:39,724 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=Yjc1ZTk3MDEtNzMyMTQ4NjAtYmIyYWE5NWQtN2JlZDNhNmY=
2025-11-25 15:04:39,726 - INFO - root - _insert_rows: YdbWorkloadLog bulk_upsert
2025-11-25 15:04:39,727 - INFO - root - _insert_rows: YdbWorkloadLog insert
2025-11-25 15:04:39,733 - INFO - root - _insert_rows: YdbWorkloadLog upsert
2025-11-25 15:04:39,734 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ODZmZDcyNzEtOGVkMTQ1YTYtMjExNWJlMmEtN2ViN2JiNjA=
2025-11-25 15:04:39,750 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 670455f2-31f9-42b8-8751-c8958ba85c27, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:04:39,750 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 670455f2-31f9-42b8-8751-c8958ba85c27, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=ODZmZDcyNzEtOGVkMTQ1YTYtMjExNWJlMmEtN2ViN2JiNjA=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-25 15:04:39,749 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/fvd5/0002c2/ydb/apps/ydb/ydb -e grpc://localhost:4007 -d /Root workload log --path log run upsert --seconds 3 --threads 10 --rows 500 --timestamp_deviation 180 with wait = True
2025-11-25 15:04:39,779 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.7
2025-11-25 15:04:39,747 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/fvd5/0002c2/ydb/apps/ydb/ydb -e grpc://localhost:4007 -d /Root workload log --path log run bulk_upsert --seconds 3 --threads 10 --rows 500 --timestamp_deviation 180 with wait = True
2025-11-25 15:04:39,751 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YTdjMjk4NTYtMjI1NGIyYTktY2NlNDEyYTMtMmI1ZjVlYTU=
2025-11-25 15:04:39,773 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 670455f2-31f9-42b8-8751-c8958ba85c27, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:04:39,748 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/fvd5/0002c2/ydb/apps/ydb/ydb -e grpc://localhost:4007 -d /Root workload log --path log run insert --seconds 3 --threads 10 --rows 500 --timestamp_deviation 180 with wait = True
2025-11-25 15:04:39,794 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 77cf7c5a-b446-4059-bac1-de3e2896f3e9, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:04:39,810 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 77cf7c5a-b446-4059-bac1-de3e2896f3e9, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=YTdjMjk4NTYtMjI1NGIyYTktY2NlNDEyYTMtMmI1ZjVlYTU=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-25 15:04:39,794 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=Njc5NTUyOWMtM2E5YjU5NTItYWMxYjYzYjAtYWZmNGZhYTk=
2025-11-25 15:04:39,811 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 77cf7c5a-b446-4059-bac1-de3e2896f3e9, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:04:39,800 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.7
2025-11-25 15:04:39,795 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.8
2025-11-25 15:04:39,826 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 03f19445-f29f-4e94-b13c-11140d733e57, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:04:39,880 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 03f19445-f29f-4e94-b13c-11140d733e57, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=Njc5NTUyOWMtM2E5YjU5NTItYWMxYjYzYjAtYWZmNGZhYTk=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-25 15:04:39,829 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.9
2025-11-25 15:04:39,859 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/fvd5/0002c2/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:4007', '-d', '/Root', 'workload', 'log', '--path', 'log', 'run', 'upsert', '--seconds', '3', '--threads', '10', '--rows', '500', '--timestamp_deviation', '180']' in 'None' (waiting)
2025-11-25 15:04:39,879 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.8
2025-11-25 15:04:39,827 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NWI4YzBkNTYtMzYxZDRjNGQtM2Q4ZTc5ZjMtZjIzODllMjM=
2025-11-25 15:04:39,888 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 03f19445-f29f-4e94-b13c-11140d733e57, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:04:39,892 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.9
2025-11-25 15:04:39,902 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 00271658-a646-454c-8c2b-8f2bbb4511a9, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:04:39,904 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZDFkYmRmZTUtNDNiN2IyOS0xZjEwNmM1OS03MTE2MTMyZA==
2025-11-25 15:04:39,904 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/fvd5/0002c2/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:4007', '-d', '/Root', 'workload', 'log', '--path', 'log', 'run', 'bulk_upsert', '--seconds', '3', '--threads', '10', '--rows', '500', '--timestamp_deviation', '180']' in 'None' (waiting)
2025-11-25 15:04:39,917 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, b0b97c5f-de45-41bf-92b0-6f1823e9e5bf, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:04:39,906 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/fvd5/0002c2/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:4007', '-d', '/Root', 'workload', 'log', '--path', 'log', 'run', 'insert', '--seconds', '3', '--threads', '10', '--rows', '500', '--timestamp_deviation', '180']' in 'None' (waiting)
2025-11-25 15:04:39,947 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, b0b97c5f-de45-41bf-92b0-6f1823e9e5bf, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=ZDFkYmRmZTUtNDNiN2IyOS0xZjEwNmM1OS03MTE2MTMyZA==" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-25 15:04:39,963 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, b0b97c5f-de45-41bf-92b0-6f1823e9e5bf, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:04:39,921 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZTNiYjVjODAtYWFhYjk3NDctYTFjNGRjNC1iYWMyZGZkYw==
2025-11-25 15:04:39,928 - DEBUG - ya.test - execute: Command pid: 3920540
2025-11-25 15:04:39,916 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 00271658-a646-454c-8c2b-8f2bbb4511a9, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=NWI4YzBkNTYtMzYxZDRjNGQtM2Q4ZTc5ZjMtZjIzODllMjM=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-25 15:04:40,012 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 00271658-a646-454c-8c2b-8f2bbb4511a9, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:04:39,951 - DEBUG - ya.test - execute: Command pid: 3920558
2025-11-25 15:04:39,898 - DEBUG - ya.test - execute: Command pid: 3920527
2025-11-25 15:04:40,009 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ODU2ODJhMDgtY2JlZjFlYWUtN2QzODE3Ni1lMGUyNzFjYQ==
2025-11-25 15:04:40,009 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 33fa283a-3f4c-4484-9461-3614e76131b6, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:04:40,033 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 33fa283a-3f4c-4484-9461-3614e76131b6, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=ZTNiYjVjODAtYWFhYjk3NDctYTFjNGRjNC1iYWMyZGZkYw==" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-25 15:04:40,038 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 33fa283a-3f4c-4484-9461-3614e76131b6, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:04:40,032 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MTQxYTEwMDUtZTFkMGFhN2MtMTEwNzE4MzAtZjMwZmMzNjc=
2025-11-25 15:04:40,032 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 8ff4616f-349b-47b4-aa52-019936da3932, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:04:40,049 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 8ff4616f-349b-47b4-aa52-019936da3932, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=ODU2ODJhMDgtY2JlZjFlYWUtN2QzODE3Ni1lMGUyNzFjYQ==" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-25 15:04:40,063 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 8ff4616f-349b-47b4-aa52-019936da3932, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:04:40,049 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 6e235fcd-7d13-4fd0-a5e8-66dd2acc5d84, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:04:40,102 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 6e235fcd-7d13-4fd0-a5e8-66dd2acc5d84, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=MTQxYTEwMDUtZTFkMGFhN2MtMTEwNzE4MzAtZjMwZmMzNjc=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-25 15:04:40,110 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 6e235fcd-7d13-4fd0-a5e8-66dd2acc5d84, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:04:40,050 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YmI4NDQ2NGMtMWZiN2JjMTktM2Q4Zjk5MjktMjQ4NGJhZWY=
2025-11-25 15:04:40,139 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 8572ff68-b8af-468b-a802-a78ca8a0b9dd, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:04:40,140 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 8572ff68-b8af-468b-a802-a78ca8a0b9dd, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=YmI4NDQ2NGMtMWZiN2JjMTktM2Q4Zjk5MjktMjQ4NGJhZWY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-25 15:04:40,140 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=Yjc1ZTk3MDEtNzMyMTQ4NjAtYmIyYWE5NWQtN2JlZDNhNmY=
2025-11-25 15:04:40,178 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 8572ff68-b8af-468b-a802-a78ca8a0b9dd, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:04:40,198 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, d36bcb84-7a86-4788-adbe-f60a30307371, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:04:40,200 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, d36bcb84-7a86-4788-adbe-f60a30307371, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=Yjc1ZTk3MDEtNzMyMTQ4NjAtYmIyYWE5NWQtN2JlZDNhNmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-25 15:04:40,205 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, d36bcb84-7a86-4788-adbe-f60a30307371, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:04:40,549 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-11-25 15:04:40,550 - 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-11-25 15:04:40,586 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database /Root
2025-11-25 15:04:40,590 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, 6e28cfff-d501-43d7-a43a-8a5aa4037041, localhost:4007): creating call state
2025-11-25 15:04:40,591 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, 6e28cfff-d501-43d7-a43a-8a5aa4037041, localhost:4007): request = { database: "/Root" }
2025-11-25 15:04:40,903 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, 6e28cfff-d501-43d7-a43a-8a5aa4037041, localhost:4007): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Discovery.ListEndpointsResult] { endpoints { address: "ghrun-n7olz6xni4.auto.internal" port: 4007 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-25 15:04:40,921 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Resolved endpoints for database /Root: DiscoveryResult <self_location: 1, endpoints [<Endpoint ghrun-n7olz6xni4.auto.internal:4007, location 1, ssl: False>]>
2025-11-25 15:04:40,922 - INFO - ydb.connection - close: Closing channel for endpoint localhost:4007
2025-11-25 15:04:43,551 - DEBUG - ya.test - _wait: Process resource usage is not available as process finished before wait4 was called
2025-11-25 15:04:43,551 - DEBUG - ya.test - _save_outputs: Command (pid 3920527) rc: 0
2025-11-25 15:04:43,555 - DEBUG - ya.test - _save_outputs: Command (pid 3920527) elapsed time (sec): 3.5382163524627686
2025-11-25 15:04:43,556 - DEBUG - ya.test - _save_outputs: Command (pid 3920527) wtime: 3.656
2025-11-25 15:04:43,556 - DEBUG - ya.test - _save_outputs: Command (pid 3920527) 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-11-25 15:04:43,560 - DEBUG - ya.test - _save_outputs: Command (pid 3920527) errors:

2025-11-25 15:04:43,581 - DEBUG - ya.test - _wait: Process resource usage is not available as process finished before wait4 was called
2025-11-25 15:04:43,582 - DEBUG - ya.test - _save_outputs: Command (pid 3920558) rc: 0
2025-11-25 15:04:43,582 - DEBUG - ya.test - _save_outputs: Command (pid 3920558) elapsed time (sec): 3.569361448287964
2025-11-25 15:04:43,586 - DEBUG - ya.test - _save_outputs: Command (pid 3920558) wtime: 3.634
2025-11-25 15:04:43,590 - DEBUG - ya.test - _save_outputs: Command (pid 3920558) 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-11-25 15:04:43,602 - DEBUG - ya.test - _save_outputs: Command (pid 3920558) errors:

2025-11-25 15:05:00,211 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=Yjc1ZTk3MDEtNzMyMTQ4NjAtYmIyYWE5NWQtN2JlZDNhNmY=
2025-11-25 15:05:00,230 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=Yjc1ZTk3MDEtNzMyMTQ4NjAtYmIyYWE5NWQtN2JlZDNhNmY=
2025-11-25 15:05:00,231 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 183c42fc-1c50-48ed-bec7-698dcd4478dd, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:05:00,213 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MTQxYTEwMDUtZTFkMGFhN2MtMTEwNzE4MzAtZjMwZmMzNjc=
2025-11-25 15:05:00,224 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YmI4NDQ2NGMtMWZiN2JjMTktM2Q4Zjk5MjktMjQ4NGJhZWY=
2025-11-25 15:05:00,249 - DEBUG - ya.test - _wait: Process resource usage is not available as process finished before wait4 was called
2025-11-25 15:05:00,250 - DEBUG - ya.test - _save_outputs: Command (pid 3920540) rc: 0
2025-11-25 15:05:00,251 - DEBUG - ya.test - _save_outputs: Command (pid 3920540) elapsed time (sec): 20.238963842391968
2025-11-25 15:05:00,251 - DEBUG - ya.test - _save_outputs: Command (pid 3920540) wtime: 20.328
2025-11-25 15:05:00,243 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MTQxYTEwMDUtZTFkMGFhN2MtMTEwNzE4MzAtZjMwZmMzNjc=
2025-11-25 15:05:00,256 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 70df2b20-7a3e-4b5d-b5b9-aa0d800dac64, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:05:00,235 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ODU2ODJhMDgtY2JlZjFlYWUtN2QzODE3Ni1lMGUyNzFjYQ==
2025-11-25 15:05:00,256 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 70df2b20-7a3e-4b5d-b5b9-aa0d800dac64, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=MTQxYTEwMDUtZTFkMGFhN2MtMTEwNzE4MzAtZjMwZmMzNjc=" 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-11-25 15:05:00,232 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 183c42fc-1c50-48ed-bec7-698dcd4478dd, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=Yjc1ZTk3MDEtNzMyMTQ4NjAtYmIyYWE5NWQtN2JlZDNhNmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(1)" } stats_mode: STATS_MODE_NONE }
2025-11-25 15:05:00,251 - DEBUG - ya.test - _save_outputs: Command (pid 3920540) 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	18431	19839	19839	19839

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

2025-11-25 15:05:00,259 - DEBUG - ya.test - _save_outputs: Command (pid 3920540) errors:

2025-11-25 15:05:00,257 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YmI4NDQ2NGMtMWZiN2JjMTktM2Q4Zjk5MjktMjQ4NGJhZWY=
2025-11-25 15:05:00,260 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 70df2b20-7a3e-4b5d-b5b9-aa0d800dac64, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:05:00,274 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, b14dd9c6-bbb5-46fd-8198-dece4659779b, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:05:00,261 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 183c42fc-1c50-48ed-bec7-698dcd4478dd, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:05:00,275 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ODU2ODJhMDgtY2JlZjFlYWUtN2QzODE3Ni1lMGUyNzFjYQ==
2025-11-25 15:05:00,315 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 67c39824-e901-4590-903d-08d9617324f7, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:05:00,293 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, b14dd9c6-bbb5-46fd-8198-dece4659779b, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=YmI4NDQ2NGMtMWZiN2JjMTktM2Q4Zjk5MjktMjQ4NGJhZWY=" 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-11-25 15:05:00,318 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 67c39824-e901-4590-903d-08d9617324f7, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=ODU2ODJhMDgtY2JlZjFlYWUtN2QzODE3Ni1lMGUyNzFjYQ==" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(6)" } stats_mode: STATS_MODE_NONE }
2025-11-25 15:05:00,324 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, b14dd9c6-bbb5-46fd-8198-dece4659779b, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:05:00,332 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 67c39824-e901-4590-903d-08d9617324f7, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:05:00,729 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NWI4YzBkNTYtMzYxZDRjNGQtM2Q4ZTc5ZjMtZjIzODllMjM=
2025-11-25 15:05:00,729 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NWI4YzBkNTYtMzYxZDRjNGQtM2Q4ZTc5ZjMtZjIzODllMjM=
2025-11-25 15:05:00,738 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 46b68c94-ccdd-4f92-8d4a-cda2618638a2, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:05:00,739 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 46b68c94-ccdd-4f92-8d4a-cda2618638a2, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=NWI4YzBkNTYtMzYxZDRjNGQtM2Q4ZTc5ZjMtZjIzODllMjM=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(1)" } stats_mode: STATS_MODE_NONE }
2025-11-25 15:05:00,740 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 46b68c94-ccdd-4f92-8d4a-cda2618638a2, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:05:00,818 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZTNiYjVjODAtYWFhYjk3NDctYTFjNGRjNC1iYWMyZGZkYw==
2025-11-25 15:05:00,819 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZTNiYjVjODAtYWFhYjk3NDctYTFjNGRjNC1iYWMyZGZkYw==
2025-11-25 15:05:00,819 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 6596fdb6-d744-4e4f-920a-3f173e48270c, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:05:00,820 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 6596fdb6-d744-4e4f-920a-3f173e48270c, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=ZTNiYjVjODAtYWFhYjk3NDctYTFjNGRjNC1iYWMyZGZkYw==" 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-11-25 15:05:00,821 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 6596fdb6-d744-4e4f-920a-3f173e48270c, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:05:01,249 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZDFkYmRmZTUtNDNiN2IyOS0xZjEwNmM1OS03MTE2MTMyZA==
2025-11-25 15:05:01,249 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZDFkYmRmZTUtNDNiN2IyOS0xZjEwNmM1OS03MTE2MTMyZA==
2025-11-25 15:05:01,250 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 5ca8f970-a185-48d0-9090-eed321068915, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:05:01,250 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 5ca8f970-a185-48d0-9090-eed321068915, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=ZDFkYmRmZTUtNDNiN2IyOS0xZjEwNmM1OS03MTE2MTMyZA==" 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-11-25 15:05:01,251 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 5ca8f970-a185-48d0-9090-eed321068915, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:05:01,308 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ODZmZDcyNzEtOGVkMTQ1YTYtMjExNWJlMmEtN2ViN2JiNjA=
2025-11-25 15:05:01,309 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ODZmZDcyNzEtOGVkMTQ1YTYtMjExNWJlMmEtN2ViN2JiNjA=
2025-11-25 15:05:01,311 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 7acd404a-3321-438a-9535-db5be23bb766, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:05:01,313 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 7acd404a-3321-438a-9535-db5be23bb766, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=ODZmZDcyNzEtOGVkMTQ1YTYtMjExNWJlMmEtN2ViN2JiNjA=" 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-11-25 15:05:01,314 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 7acd404a-3321-438a-9535-db5be23bb766, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:05:01,405 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=Njc5NTUyOWMtM2E5YjU5NTItYWMxYjYzYjAtYWZmNGZhYTk=
2025-11-25 15:05:01,424 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YTdjMjk4NTYtMjI1NGIyYTktY2NlNDEyYTMtMmI1ZjVlYTU=
2025-11-25 15:05:01,431 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=Njc5NTUyOWMtM2E5YjU5NTItYWMxYjYzYjAtYWZmNGZhYTk=
2025-11-25 15:05:01,439 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 61be2946-bc30-4901-a2b8-4ca056e432d1, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:05:01,442 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 61be2946-bc30-4901-a2b8-4ca056e432d1, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=Njc5NTUyOWMtM2E5YjU5NTItYWMxYjYzYjAtYWZmNGZhYTk=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(6)" } stats_mode: STATS_MODE_NONE }
2025-11-25 15:05:01,440 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YTdjMjk4NTYtMjI1NGIyYTktY2NlNDEyYTMtMmI1ZjVlYTU=
2025-11-25 15:05:01,445 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 61be2946-bc30-4901-a2b8-4ca056e432d1, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:05:01,452 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 6a62ddd1-8602-4202-a788-642fe4c8a824, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:05:01,459 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 6a62ddd1-8602-4202-a788-642fe4c8a824, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=YTdjMjk4NTYtMjI1NGIyYTktY2NlNDEyYTMtMmI1ZjVlYTU=" 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-11-25 15:05:01,465 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 6a62ddd1-8602-4202-a788-642fe4c8a824, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:05:01,941 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MTQxYTEwMDUtZTFkMGFhN2MtMTEwNzE4MzAtZjMwZmMzNjc=
2025-11-25 15:05:01,942 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MTQxYTEwMDUtZTFkMGFhN2MtMTEwNzE4MzAtZjMwZmMzNjc=
2025-11-25 15:05:01,943 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, ba048c41-acfd-4543-af18-f0e7a6e5c3e6, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:05:01,945 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, ba048c41-acfd-4543-af18-f0e7a6e5c3e6, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=MTQxYTEwMDUtZTFkMGFhN2MtMTEwNzE4MzAtZjMwZmMzNjc=" 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-11-25 15:05:01,946 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, ba048c41-acfd-4543-af18-f0e7a6e5c3e6, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:05:02,750 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MTQxYTEwMDUtZTFkMGFhN2MtMTEwNzE4MzAtZjMwZmMzNjc=
2025-11-25 15:05:02,770 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MTQxYTEwMDUtZTFkMGFhN2MtMTEwNzE4MzAtZjMwZmMzNjc=
2025-11-25 15:05:02,770 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, f8fb5f2e-3325-4cc8-86d7-bc5384762105, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:05:02,771 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, f8fb5f2e-3325-4cc8-86d7-bc5384762105, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=MTQxYTEwMDUtZTFkMGFhN2MtMTEwNzE4MzAtZjMwZmMzNjc=" 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-11-25 15:05:02,771 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, f8fb5f2e-3325-4cc8-86d7-bc5384762105, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:05:05,099 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MTQxYTEwMDUtZTFkMGFhN2MtMTEwNzE4MzAtZjMwZmMzNjc=
2025-11-25 15:05:05,309 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZTNiYjVjODAtYWFhYjk3NDctYTFjNGRjNC1iYWMyZGZkYw==
2025-11-25 15:05:05,319 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MTQxYTEwMDUtZTFkMGFhN2MtMTEwNzE4MzAtZjMwZmMzNjc=
2025-11-25 15:05:05,321 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, b31c3936-7b9d-425f-89b0-2e4f2877bf46, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:05:05,351 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, b31c3936-7b9d-425f-89b0-2e4f2877bf46, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=MTQxYTEwMDUtZTFkMGFhN2MtMTEwNzE4MzAtZjMwZmMzNjc=" 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-11-25 15:05:05,358 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, b31c3936-7b9d-425f-89b0-2e4f2877bf46, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:05:06,306 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MTQxYTEwMDUtZTFkMGFhN2MtMTEwNzE4MzAtZjMwZmMzNjc=
2025-11-25 15:05:06,306 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZTNiYjVjODAtYWFhYjk3NDctYTFjNGRjNC1iYWMyZGZkYw==
2025-11-25 15:05:06,307 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, a6e7a959-88c6-42d1-a7da-c2c911ca3b66, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:05:06,309 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, a6e7a959-88c6-42d1-a7da-c2c911ca3b66, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=ZTNiYjVjODAtYWFhYjk3NDctYTFjNGRjNC1iYWMyZGZkYw==" 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-11-25 15:05:06,310 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, a6e7a959-88c6-42d1-a7da-c2c911ca3b66, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:05:08,139 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZTNiYjVjODAtYWFhYjk3NDctYTFjNGRjNC1iYWMyZGZkYw==
2025-11-25 15:05:08,760 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ODU2ODJhMDgtY2JlZjFlYWUtN2QzODE3Ni1lMGUyNzFjYQ==
2025-11-25 15:05:08,779 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MTQxYTEwMDUtZTFkMGFhN2MtMTEwNzE4MzAtZjMwZmMzNjc=
2025-11-25 15:05:08,780 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 154caeae-770c-4859-bd67-35cae119b609, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:05:08,787 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 154caeae-770c-4859-bd67-35cae119b609, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=MTQxYTEwMDUtZTFkMGFhN2MtMTEwNzE4MzAtZjMwZmMzNjc=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(6)" } stats_mode: STATS_MODE_NONE }
2025-11-25 15:05:08,803 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 154caeae-770c-4859-bd67-35cae119b609, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:05:10,039 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=Njc5NTUyOWMtM2E5YjU5NTItYWMxYjYzYjAtYWZmNGZhYTk=
2025-11-25 15:05:10,045 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZTNiYjVjODAtYWFhYjk3NDctYTFjNGRjNC1iYWMyZGZkYw==
2025-11-25 15:05:10,046 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 87ad87b6-7e4e-4e53-9185-ece4bb4152d1, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:05:10,046 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 87ad87b6-7e4e-4e53-9185-ece4bb4152d1, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=ZTNiYjVjODAtYWFhYjk3NDctYTFjNGRjNC1iYWMyZGZkYw==" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(6)" } stats_mode: STATS_MODE_NONE }
2025-11-25 15:05:10,066 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 87ad87b6-7e4e-4e53-9185-ece4bb4152d1, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:05:11,656 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZTNiYjVjODAtYWFhYjk3NDctYTFjNGRjNC1iYWMyZGZkYw==
2025-11-25 15:05:11,657 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ODU2ODJhMDgtY2JlZjFlYWUtN2QzODE3Ni1lMGUyNzFjYQ==
2025-11-25 15:05:11,660 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 0b14e952-4b6e-4b2e-8c1b-9e095d949e22, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:05:11,662 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 0b14e952-4b6e-4b2e-8c1b-9e095d949e22, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=ODU2ODJhMDgtY2JlZjFlYWUtN2QzODE3Ni1lMGUyNzFjYQ==" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(7)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(6))" } stats_mode: STATS_MODE_NONE }
2025-11-25 15:05:11,667 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 0b14e952-4b6e-4b2e-8c1b-9e095d949e22, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:05:12,084 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MTQxYTEwMDUtZTFkMGFhN2MtMTEwNzE4MzAtZjMwZmMzNjc=
2025-11-25 15:05:12,085 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=Njc5NTUyOWMtM2E5YjU5NTItYWMxYjYzYjAtYWZmNGZhYTk=
2025-11-25 15:05:12,088 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, a20f90ac-921b-45b6-ac3d-5725a333e5df, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:05:12,089 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, a20f90ac-921b-45b6-ac3d-5725a333e5df, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=Njc5NTUyOWMtM2E5YjU5NTItYWMxYjYzYjAtYWZmNGZhYTk=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(7)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(6))" } stats_mode: STATS_MODE_NONE }
2025-11-25 15:05:12,117 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, a20f90ac-921b-45b6-ac3d-5725a333e5df, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:05:12,208 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ODZmZDcyNzEtOGVkMTQ1YTYtMjExNWJlMmEtN2ViN2JiNjA=
2025-11-25 15:05:12,231 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZTNiYjVjODAtYWFhYjk3NDctYTFjNGRjNC1iYWMyZGZkYw==
2025-11-25 15:05:12,273 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, f4b9e890-accc-44d8-929c-a48e038f2fb8, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:05:12,273 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, f4b9e890-accc-44d8-929c-a48e038f2fb8, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=ZTNiYjVjODAtYWFhYjk3NDctYTFjNGRjNC1iYWMyZGZkYw==" 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-11-25 15:05:12,290 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, f4b9e890-accc-44d8-929c-a48e038f2fb8, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:05:13,937 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ODU2ODJhMDgtY2JlZjFlYWUtN2QzODE3Ni1lMGUyNzFjYQ==
2025-11-25 15:05:13,952 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=Njc5NTUyOWMtM2E5YjU5NTItYWMxYjYzYjAtYWZmNGZhYTk=
2025-11-25 15:05:14,075 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZDFkYmRmZTUtNDNiN2IyOS0xZjEwNmM1OS03MTE2MTMyZA==
2025-11-25 15:05:14,123 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MTQxYTEwMDUtZTFkMGFhN2MtMTEwNzE4MzAtZjMwZmMzNjc=
2025-11-25 15:05:14,131 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZTNiYjVjODAtYWFhYjk3NDctYTFjNGRjNC1iYWMyZGZkYw==
2025-11-25 15:05:14,139 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YTdjMjk4NTYtMjI1NGIyYTktY2NlNDEyYTMtMmI1ZjVlYTU=
2025-11-25 15:05:14,140 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YmI4NDQ2NGMtMWZiN2JjMTktM2Q4Zjk5MjktMjQ4NGJhZWY=
2025-11-25 15:05:14,142 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, da64e916-35b4-4b5c-81ca-be2e40cfb0de, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:05:14,149 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ODZmZDcyNzEtOGVkMTQ1YTYtMjExNWJlMmEtN2ViN2JiNjA=
2025-11-25 15:05:14,257 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, da64e916-35b4-4b5c-81ca-be2e40cfb0de, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=MTQxYTEwMDUtZTFkMGFhN2MtMTEwNzE4MzAtZjMwZmMzNjc=" 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-11-25 15:05:14,280 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, da64e916-35b4-4b5c-81ca-be2e40cfb0de, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:05:14,274 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ODU2ODJhMDgtY2JlZjFlYWUtN2QzODE3Ni1lMGUyNzFjYQ==
2025-11-25 15:05:14,282 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 80287c4d-7340-4cc9-b33d-98c92606d170, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:05:14,274 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, d1e984ce-ba9f-49cd-a046-a0aa6562e4ec, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:05:14,294 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, d1e984ce-ba9f-49cd-a046-a0aa6562e4ec, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=ODZmZDcyNzEtOGVkMTQ1YTYtMjExNWJlMmEtN2ViN2JiNjA=" 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-11-25 15:05:14,298 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, d1e984ce-ba9f-49cd-a046-a0aa6562e4ec, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:05:14,282 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=Njc5NTUyOWMtM2E5YjU5NTItYWMxYjYzYjAtYWZmNGZhYTk=
2025-11-25 15:05:14,290 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 80287c4d-7340-4cc9-b33d-98c92606d170, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=ODU2ODJhMDgtY2JlZjFlYWUtN2QzODE3Ni1lMGUyNzFjYQ==" 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-11-25 15:05:14,300 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 0db57768-da31-4bef-9ab1-3e67dd4a6973, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:05:14,313 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 0db57768-da31-4bef-9ab1-3e67dd4a6973, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=Njc5NTUyOWMtM2E5YjU5NTItYWMxYjYzYjAtYWZmNGZhYTk=" 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-11-25 15:05:14,313 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 80287c4d-7340-4cc9-b33d-98c92606d170, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:05:14,330 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 0db57768-da31-4bef-9ab1-3e67dd4a6973, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:05:14,367 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NWI4YzBkNTYtMzYxZDRjNGQtM2Q4ZTc5ZjMtZjIzODllMjM=
2025-11-25 15:05:14,448 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZDFkYmRmZTUtNDNiN2IyOS0xZjEwNmM1OS03MTE2MTMyZA==
2025-11-25 15:05:14,458 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=Yjc1ZTk3MDEtNzMyMTQ4NjAtYmIyYWE5NWQtN2JlZDNhNmY=
2025-11-25 15:05:14,472 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, e58ee7b5-9db8-4501-b630-9ed6b88ccaca, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:05:14,580 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, e58ee7b5-9db8-4501-b630-9ed6b88ccaca, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=ZDFkYmRmZTUtNDNiN2IyOS0xZjEwNmM1OS03MTE2MTMyZA==" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(1)" } stats_mode: STATS_MODE_NONE }
2025-11-25 15:05:14,553 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZTNiYjVjODAtYWFhYjk3NDctYTFjNGRjNC1iYWMyZGZkYw==
2025-11-25 15:05:14,626 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, fcdb8f15-ba6d-4192-a155-583757fa2494, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:05:14,627 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, fcdb8f15-ba6d-4192-a155-583757fa2494, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=ZTNiYjVjODAtYWFhYjk3NDctYTFjNGRjNC1iYWMyZGZkYw==" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(1)" } stats_mode: STATS_MODE_NONE }
2025-11-25 15:05:14,628 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, e58ee7b5-9db8-4501-b630-9ed6b88ccaca, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:05:14,650 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, fcdb8f15-ba6d-4192-a155-583757fa2494, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:05:19,719 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ODZmZDcyNzEtOGVkMTQ1YTYtMjExNWJlMmEtN2ViN2JiNjA=
2025-11-25 15:05:19,918 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=Njc5NTUyOWMtM2E5YjU5NTItYWMxYjYzYjAtYWZmNGZhYTk=
2025-11-25 15:05:19,919 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YTdjMjk4NTYtMjI1NGIyYTktY2NlNDEyYTMtMmI1ZjVlYTU=
2025-11-25 15:05:19,926 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 7c88d878-f553-4ae6-9928-73d36caeecf8, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:05:19,927 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 7c88d878-f553-4ae6-9928-73d36caeecf8, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=YTdjMjk4NTYtMjI1NGIyYTktY2NlNDEyYTMtMmI1ZjVlYTU=" 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-11-25 15:05:19,928 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ODU2ODJhMDgtY2JlZjFlYWUtN2QzODE3Ni1lMGUyNzFjYQ==
2025-11-25 15:05:19,935 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 7c88d878-f553-4ae6-9928-73d36caeecf8, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:05:19,934 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MTQxYTEwMDUtZTFkMGFhN2MtMTEwNzE4MzAtZjMwZmMzNjc=
2025-11-25 15:05:19,946 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YmI4NDQ2NGMtMWZiN2JjMTktM2Q4Zjk5MjktMjQ4NGJhZWY=
2025-11-25 15:05:19,958 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 65c83360-d70d-4b50-b64b-9b5d55fbb6a1, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:05:19,959 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 65c83360-d70d-4b50-b64b-9b5d55fbb6a1, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=YmI4NDQ2NGMtMWZiN2JjMTktM2Q4Zjk5MjktMjQ4NGJhZWY=" 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-11-25 15:05:19,960 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NWI4YzBkNTYtMzYxZDRjNGQtM2Q4ZTc5ZjMtZjIzODllMjM=
2025-11-25 15:05:19,982 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, a3a63ae2-19a4-4c7f-8782-712fd0408eab, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:05:19,987 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, a3a63ae2-19a4-4c7f-8782-712fd0408eab, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=NWI4YzBkNTYtMzYxZDRjNGQtM2Q4ZTc5ZjMtZjIzODllMjM=" 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-11-25 15:05:19,988 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, a3a63ae2-19a4-4c7f-8782-712fd0408eab, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:05:19,982 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 65c83360-d70d-4b50-b64b-9b5d55fbb6a1, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:05:20,012 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZTNiYjVjODAtYWFhYjk3NDctYTFjNGRjNC1iYWMyZGZkYw==
2025-11-25 15:05:20,013 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=Yjc1ZTk3MDEtNzMyMTQ4NjAtYmIyYWE5NWQtN2JlZDNhNmY=
2025-11-25 15:05:20,013 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, fecaa922-4fa3-44f2-aea0-eee652cd3ceb, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:05:20,018 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, fecaa922-4fa3-44f2-aea0-eee652cd3ceb, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=Yjc1ZTk3MDEtNzMyMTQ4NjAtYmIyYWE5NWQtN2JlZDNhNmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(2)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(1))" } stats_mode: STATS_MODE_NONE }
2025-11-25 15:05:20,019 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, fecaa922-4fa3-44f2-aea0-eee652cd3ceb, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:05:20,058 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZDFkYmRmZTUtNDNiN2IyOS0xZjEwNmM1OS03MTE2MTMyZA==
2025-11-25 15:05:20,059 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ODZmZDcyNzEtOGVkMTQ1YTYtMjExNWJlMmEtN2ViN2JiNjA=
2025-11-25 15:05:20,074 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 130636b6-9d07-467a-b032-1042e7907313, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:05:20,086 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 130636b6-9d07-467a-b032-1042e7907313, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=ODZmZDcyNzEtOGVkMTQ1YTYtMjExNWJlMmEtN2ViN2JiNjA=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(2)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(1))" } stats_mode: STATS_MODE_NONE }
2025-11-25 15:05:20,095 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 130636b6-9d07-467a-b032-1042e7907313, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:05:24,337 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YTdjMjk4NTYtMjI1NGIyYTktY2NlNDEyYTMtMmI1ZjVlYTU=
2025-11-25 15:05:24,341 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NWI4YzBkNTYtMzYxZDRjNGQtM2Q4ZTc5ZjMtZjIzODllMjM=
2025-11-25 15:05:24,350 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YmI4NDQ2NGMtMWZiN2JjMTktM2Q4Zjk5MjktMjQ4NGJhZWY=
2025-11-25 15:05:24,385 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ODZmZDcyNzEtOGVkMTQ1YTYtMjExNWJlMmEtN2ViN2JiNjA=
2025-11-25 15:05:24,394 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=Yjc1ZTk3MDEtNzMyMTQ4NjAtYmIyYWE5NWQtN2JlZDNhNmY=
2025-11-25 15:05:24,395 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=Njc5NTUyOWMtM2E5YjU5NTItYWMxYjYzYjAtYWZmNGZhYTk=
2025-11-25 15:05:24,396 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, eedfd44b-88fc-4b47-a2d4-6fb1b90ff729, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:05:24,396 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, eedfd44b-88fc-4b47-a2d4-6fb1b90ff729, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=Njc5NTUyOWMtM2E5YjU5NTItYWMxYjYzYjAtYWZmNGZhYTk=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "select count(*) as Rows from `log`" } stats_mode: STATS_MODE_NONE }
2025-11-25 15:05:24,397 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, eedfd44b-88fc-4b47-a2d4-6fb1b90ff729, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:05:25,606 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=Njc5NTUyOWMtM2E5YjU5NTItYWMxYjYzYjAtYWZmNGZhYTk=
2025-11-25 15:05:25,618 - INFO - root - test_log_deviation: check insert: 20000 15000
2025-11-25 15:05:25,636 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.10
2025-11-25 15:05:25,647 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.10
2025-11-25 15:05:25,649 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/fvd5/0002c2/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:4007', '-d', '/Root', 'workload', 'log', '--path', 'log', 'clean']' in 'None' (waiting)
2025-11-25 15:05:25,663 - DEBUG - ya.test - execute: Command pid: 3938236
2025-11-25 15:05:25,994 - DEBUG - ya.test - _save_outputs: Command (pid 3938236) rc: 0
2025-11-25 15:05:25,994 - DEBUG - ya.test - _save_outputs: Command (pid 3938236) elapsed time (sec): 0.3198282718658447
2025-11-25 15:05:26,002 - DEBUG - ya.test - _save_outputs: Command (pid 3938236) idrss: 0
2025-11-25 15:05:26,009 - DEBUG - ya.test - _save_outputs: Command (pid 3938236) inblock: 0
2025-11-25 15:05:26,010 - DEBUG - ya.test - _save_outputs: Command (pid 3938236) isrss: 0
2025-11-25 15:05:26,010 - DEBUG - ya.test - _save_outputs: Command (pid 3938236) ixrss: 0
2025-11-25 15:05:26,021 - DEBUG - ya.test - _save_outputs: Command (pid 3938236) majflt: 0
2025-11-25 15:05:26,027 - DEBUG - ya.test - _save_outputs: Command (pid 3938236) maxrss: 799556
2025-11-25 15:05:26,036 - DEBUG - ya.test - _save_outputs: Command (pid 3938236) minflt: 3475
2025-11-25 15:05:26,049 - DEBUG - ya.test - _save_outputs: Command (pid 3938236) msgrcv: 0
2025-11-25 15:05:26,049 - DEBUG - ya.test - _save_outputs: Command (pid 3938236) msgsnd: 0
2025-11-25 15:05:26,049 - DEBUG - ya.test - _save_outputs: Command (pid 3938236) nivcsw: 38
2025-11-25 15:05:26,068 - DEBUG - ya.test - _save_outputs: Command (pid 3938236) nsignals: 0
2025-11-25 15:05:26,068 - DEBUG - ya.test - _save_outputs: Command (pid 3938236) nswap: 0
2025-11-25 15:05:26,073 - DEBUG - ya.test - _save_outputs: Command (pid 3938236) nvcsw: 126
2025-11-25 15:05:26,121 - DEBUG - ya.test - _save_outputs: Command (pid 3938236) oublock: 8
2025-11-25 15:05:26,121 - DEBUG - ya.test - _save_outputs: Command (pid 3938236) stime: 0.023549
2025-11-25 15:05:26,121 - DEBUG - ya.test - _save_outputs: Command (pid 3938236) utime: 0.051022
2025-11-25 15:05:26,121 - DEBUG - ya.test - _save_outputs: Command (pid 3938236) wtime: 0.335
2025-11-25 15:05:26,121 - DEBUG - ya.test - _save_outputs: Command (pid 3938236) output:
Remove path log...
Remove path log...Ok

2025-11-25 15:05:26,122 - DEBUG - ya.test - _save_outputs: Command (pid 3938236) errors:

2025-11-25 15:05:26,143 - INFO - ya.test - pytest_runtest_teardown: Test teardown
