2025-11-01 16:46:00,623 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-11-01 16:46:00,627 - INFO - ya.test - pytest_runtest_setup: test_log_deviation[180]
2025-11-01 16:46:00,627 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-11-01 16:46:00,627 - INFO - ya.test - pytest_runtest_setup: Test setup
2025-11-01 16:46:00,632 - INFO - ya.test - pytest_runtest_call: Test call (class_name: test_log_scenario.py::TestLogScenario, test_name: test_log_deviation[180])
2025-11-01 16:46:00,633 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/q6a6/0020b8/ydb/apps/ydb/ydb
2025-11-01 16:46:00,633 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/q6a6/0020b8/ydb/apps/ydb/ydb -e grpc://localhost:10083 -d /Root workload log --path log init --path log --store column --ttl 1000 with wait = True
2025-11-01 16:46:00,634 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.5
2025-11-01 16:46:00,636 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.5
2025-11-01 16:46:00,636 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/q6a6/0020b8/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:10083', '-d', '/Root', 'workload', 'log', '--path', 'log', 'init', '--path', 'log', '--store', 'column', '--ttl', '1000']' in 'None' (waiting)
2025-11-01 16:46:00,637 - DEBUG - ya.test - execute: Command pid: 3053862
2025-11-01 16:46:01,209 - DEBUG - ya.test - _save_outputs: Command (pid 3053862) rc: 0
2025-11-01 16:46:01,210 - DEBUG - ya.test - _save_outputs: Command (pid 3053862) elapsed time (sec): 0.5715303421020508
2025-11-01 16:46:01,210 - DEBUG - ya.test - _save_outputs: Command (pid 3053862) idrss: 0
2025-11-01 16:46:01,215 - DEBUG - ya.test - _save_outputs: Command (pid 3053862) inblock: 0
2025-11-01 16:46:01,215 - DEBUG - ya.test - _save_outputs: Command (pid 3053862) isrss: 0
2025-11-01 16:46:01,215 - DEBUG - ya.test - _save_outputs: Command (pid 3053862) ixrss: 0
2025-11-01 16:46:01,215 - DEBUG - ya.test - _save_outputs: Command (pid 3053862) majflt: 0
2025-11-01 16:46:01,216 - DEBUG - ya.test - _save_outputs: Command (pid 3053862) maxrss: 909920
2025-11-01 16:46:01,218 - DEBUG - ya.test - _save_outputs: Command (pid 3053862) minflt: 3547
2025-11-01 16:46:01,219 - DEBUG - ya.test - _save_outputs: Command (pid 3053862) msgrcv: 0
2025-11-01 16:46:01,219 - DEBUG - ya.test - _save_outputs: Command (pid 3053862) msgsnd: 0
2025-11-01 16:46:01,219 - DEBUG - ya.test - _save_outputs: Command (pid 3053862) nivcsw: 27
2025-11-01 16:46:01,219 - DEBUG - ya.test - _save_outputs: Command (pid 3053862) nsignals: 0
2025-11-01 16:46:01,220 - DEBUG - ya.test - _save_outputs: Command (pid 3053862) nswap: 0
2025-11-01 16:46:01,220 - DEBUG - ya.test - _save_outputs: Command (pid 3053862) nvcsw: 170
2025-11-01 16:46:01,220 - DEBUG - ya.test - _save_outputs: Command (pid 3053862) oublock: 8
2025-11-01 16:46:01,220 - DEBUG - ya.test - _save_outputs: Command (pid 3053862) stime: 0.030473999999999998
2025-11-01 16:46:01,220 - DEBUG - ya.test - _save_outputs: Command (pid 3053862) utime: 0.052242
2025-11-01 16:46:01,231 - DEBUG - ya.test - _save_outputs: Command (pid 3053862) wtime: 0.573
2025-11-01 16:46:01,231 - DEBUG - ya.test - _save_outputs: Command (pid 3053862) output:
Init tables ...
Init tables ...Ok

2025-11-01 16:46:01,235 - DEBUG - ya.test - _save_outputs: Command (pid 3053862) errors:

2025-11-01 16:46:01,261 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YjEyMDZhYWYtNjFlNGZkMjQtYTc4YzA2OGItZTIyOWQwYzc=
2025-11-01 16:46:01,261 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, c04f2152-0e95-498a-8a5d-c68b5f487fa2, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:46:01,263 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, c04f2152-0e95-498a-8a5d-c68b5f487fa2, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YjEyMDZhYWYtNjFlNGZkMjQtYTc4YzA2OGItZTIyOWQwYzc=" 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-01 16:46:01,264 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, c04f2152-0e95-498a-8a5d-c68b5f487fa2, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:01,297 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YjEyMDZhYWYtNjFlNGZkMjQtYTc4YzA2OGItZTIyOWQwYzc=
2025-11-01 16:46:01,298 - INFO - root - _insert_rows: YdbWorkloadLog bulk_upsert
2025-11-01 16:46:01,298 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/q6a6/0020b8/ydb/apps/ydb/ydb -e grpc://localhost:10083 -d /Root workload log --path log run bulk_upsert --seconds 3 --threads 10 --rows 500 --timestamp_deviation 180 with wait = True
2025-11-01 16:46:01,300 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.6
2025-11-01 16:46:01,302 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.6
2025-11-01 16:46:01,303 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/q6a6/0020b8/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:10083', '-d', '/Root', 'workload', 'log', '--path', 'log', 'run', 'bulk_upsert', '--seconds', '3', '--threads', '10', '--rows', '500', '--timestamp_deviation', '180']' in 'None' (waiting)
2025-11-01 16:46:01,306 - DEBUG - ya.test - execute: Command pid: 3054626
2025-11-01 16:46:05,034 - DEBUG - ya.test - _wait: Process resource usage is not available as process finished before wait4 was called
2025-11-01 16:46:05,059 - DEBUG - ya.test - _save_outputs: Command (pid 3054626) rc: 0
2025-11-01 16:46:05,059 - DEBUG - ya.test - _save_outputs: Command (pid 3054626) elapsed time (sec): 3.751913070678711
2025-11-01 16:46:05,059 - DEBUG - ya.test - _save_outputs: Command (pid 3054626) wtime: 3.755
2025-11-01 16:46:05,060 - DEBUG - ya.test - _save_outputs: Command (pid 3054626) output:
Window	    Txs	Txs/Sec	Retries	Errors	p50(ms)	p95(ms)	p99(ms)	pMax(ms)
1	     13	13	0	0	505	583	631	631
2	     15	15	0	0	631	719	723	723
3	     22	22	0	0	711	771	779	779

Total	    Txs	Txs/Sec	Retries	Errors	p50(ms)	p95(ms)	p99(ms)	pMax(ms)
3	     50	16.6667	0	0	631	771	779	779

2025-11-01 16:46:05,060 - DEBUG - ya.test - _save_outputs: Command (pid 3054626) errors:

2025-11-01 16:46:05,060 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NjE0OTEzZDMtNzI2MjE0YjctNmM0ZjM2MWItNDRkMTIxODQ=
2025-11-01 16:46:05,065 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 1dd7b877-56c6-42c5-ab92-968f232981fe, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:46:05,065 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 1dd7b877-56c6-42c5-ab92-968f232981fe, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=NjE0OTEzZDMtNzI2MjE0YjctNmM0ZjM2MWItNDRkMTIxODQ=" 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-01 16:46:05,066 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 1dd7b877-56c6-42c5-ab92-968f232981fe, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:05,676 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NjE0OTEzZDMtNzI2MjE0YjctNmM0ZjM2MWItNDRkMTIxODQ=
2025-11-01 16:46:05,746 - INFO - root - test_log_deviation: Count rows after insert 25000 before wait
2025-11-01 16:46:05,746 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OGZhNWExZWUtNWRjYTZlMjctZmU5YmQyM2EtYzJkYmIzYzY=
2025-11-01 16:46:05,747 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 833fdd8c-381d-4f3a-929c-eb295c475ec2, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:46:05,748 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 833fdd8c-381d-4f3a-929c-eb295c475ec2, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=OGZhNWExZWUtNWRjYTZlMjctZmU5YmQyM2EtYzJkYmIzYzY=" 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-01 16:46:05,748 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 833fdd8c-381d-4f3a-929c-eb295c475ec2, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:05,966 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=OGZhNWExZWUtNWRjYTZlMjctZmU5YmQyM2EtYzJkYmIzYzY=
2025-11-01 16:46:05,967 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YTAwODk3ZjgtYzJlZjY3ODYtM2JjMzliZmItOTAxNDA2ZDk=
2025-11-01 16:46:05,967 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 8091e258-2635-4766-874c-1a052e2a210a, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:46:05,968 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 8091e258-2635-4766-874c-1a052e2a210a, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YTAwODk3ZjgtYzJlZjY3ODYtM2JjMzliZmItOTAxNDA2ZDk=" 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-01 16:46:05,968 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 8091e258-2635-4766-874c-1a052e2a210a, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:06,089 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YTAwODk3ZjgtYzJlZjY3ODYtM2JjMzliZmItOTAxNDA2ZDk=
2025-11-01 16:46:06,119 - INFO - root - _insert_rows: YdbWorkloadLog bulk_upsert
2025-11-01 16:46:06,120 - INFO - root - _insert_rows: YdbWorkloadLog insert
2025-11-01 16:46:06,121 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YjU2YmFmNDktYTU1YzIwZTUtYTIxNDE1NjQtN2RhOTM2NGI=
2025-11-01 16:46:06,188 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 2f1bc9be-e82c-417b-a12f-05909277ac1b, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:46:06,121 - INFO - root - _insert_rows: YdbWorkloadLog upsert
2025-11-01 16:46:06,243 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/q6a6/0020b8/ydb/apps/ydb/ydb -e grpc://localhost:10083 -d /Root workload log --path log run upsert --seconds 3 --threads 10 --rows 500 --timestamp_deviation 180 with wait = True
2025-11-01 16:46:06,244 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.7
2025-11-01 16:46:06,187 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/q6a6/0020b8/ydb/apps/ydb/ydb -e grpc://localhost:10083 -d /Root workload log --path log run insert --seconds 3 --threads 10 --rows 500 --timestamp_deviation 180 with wait = True
2025-11-01 16:46:06,186 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/q6a6/0020b8/ydb/apps/ydb/ydb -e grpc://localhost:10083 -d /Root workload log --path log run bulk_upsert --seconds 3 --threads 10 --rows 500 --timestamp_deviation 180 with wait = True
2025-11-01 16:46:06,188 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YTcyMzhlMTAtNjYyODk0MjItYTZkYWJmZTItYmRjNWIxYWE=
2025-11-01 16:46:06,352 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 26ce7d42-d682-4681-98cb-5d02cc436d54, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:46:06,353 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 26ce7d42-d682-4681-98cb-5d02cc436d54, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YTcyMzhlMTAtNjYyODk0MjItYTZkYWJmZTItYmRjNWIxYWE=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-01 16:46:06,313 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.9
2025-11-01 16:46:06,313 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.7
2025-11-01 16:46:06,253 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.8
2025-11-01 16:46:06,354 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 26ce7d42-d682-4681-98cb-5d02cc436d54, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:06,189 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 2f1bc9be-e82c-417b-a12f-05909277ac1b, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YjU2YmFmNDktYTU1YzIwZTUtYTIxNDE1NjQtN2RhOTM2NGI=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-01 16:46:06,355 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NGVkODJlMGMtOTIwMmYyMTAtMzI1MzQ4NWQtYmE4ZjhjZTg=
2025-11-01 16:46:06,400 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 22888e74-2b5b-429f-a522-1f1e759845ba, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:46:06,400 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YmJlMWE2NTAtYjYxYTFiYjItMWIwZDUyZC04OGVhOTI3MQ==
2025-11-01 16:46:06,393 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/q6a6/0020b8/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:10083', '-d', '/Root', 'workload', 'log', '--path', 'log', 'run', 'upsert', '--seconds', '3', '--threads', '10', '--rows', '500', '--timestamp_deviation', '180']' in 'None' (waiting)
2025-11-01 16:46:06,393 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.9
2025-11-01 16:46:06,391 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 2f1bc9be-e82c-417b-a12f-05909277ac1b, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:06,391 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.8
2025-11-01 16:46:06,412 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 22888e74-2b5b-429f-a522-1f1e759845ba, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=NGVkODJlMGMtOTIwMmYyMTAtMzI1MzQ4NWQtYmE4ZjhjZTg=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-01 16:46:06,412 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 7de1fa60-ac6e-4007-82b6-7f9a55c76dbc, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:46:06,448 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 7de1fa60-ac6e-4007-82b6-7f9a55c76dbc, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YmJlMWE2NTAtYjYxYTFiYjItMWIwZDUyZC04OGVhOTI3MQ==" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-01 16:46:06,450 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 7de1fa60-ac6e-4007-82b6-7f9a55c76dbc, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:06,413 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NTVkMzgxMTItYTU4YzMzOGUtYmZlNTRmZTEtODMyNWVlOTU=
2025-11-01 16:46:06,450 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 7827ff3b-833d-4c30-ac2c-1775415eac3b, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:46:06,452 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 7827ff3b-833d-4c30-ac2c-1775415eac3b, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=NTVkMzgxMTItYTU4YzMzOGUtYmZlNTRmZTEtODMyNWVlOTU=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-01 16:46:06,424 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/q6a6/0020b8/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:10083', '-d', '/Root', 'workload', 'log', '--path', 'log', 'run', 'bulk_upsert', '--seconds', '3', '--threads', '10', '--rows', '500', '--timestamp_deviation', '180']' in 'None' (waiting)
2025-11-01 16:46:06,425 - DEBUG - ya.test - execute: Command pid: 3056783
2025-11-01 16:46:06,437 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/q6a6/0020b8/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:10083', '-d', '/Root', 'workload', 'log', '--path', 'log', 'run', 'insert', '--seconds', '3', '--threads', '10', '--rows', '500', '--timestamp_deviation', '180']' in 'None' (waiting)
2025-11-01 16:46:06,451 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MTFlYjE2ZDEtZGUzODg3ZGItYzhkOGJjYzctNzY2YTJlMA==
2025-11-01 16:46:06,441 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 22888e74-2b5b-429f-a522-1f1e759845ba, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:06,452 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 7827ff3b-833d-4c30-ac2c-1775415eac3b, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:06,479 - DEBUG - ya.test - execute: Command pid: 3056823
2025-11-01 16:46:06,485 - DEBUG - ya.test - execute: Command pid: 3056824
2025-11-01 16:46:06,486 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, b496b4dd-95e0-4c89-b322-09e31e5ca627, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:46:06,486 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YjEyMDZhYWYtNjFlNGZkMjQtYTc4YzA2OGItZTIyOWQwYzc=
2025-11-01 16:46:06,516 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 4f3445bf-c91a-450e-b5a9-04f87437284b, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:46:06,517 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 4f3445bf-c91a-450e-b5a9-04f87437284b, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YjEyMDZhYWYtNjFlNGZkMjQtYTc4YzA2OGItZTIyOWQwYzc=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-01 16:46:06,518 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 4f3445bf-c91a-450e-b5a9-04f87437284b, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:06,518 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NjE0OTEzZDMtNzI2MjE0YjctNmM0ZjM2MWItNDRkMTIxODQ=
2025-11-01 16:46:06,544 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, b768c603-171e-42bc-aea3-d500ca67de89, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:46:06,545 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, b768c603-171e-42bc-aea3-d500ca67de89, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=NjE0OTEzZDMtNzI2MjE0YjctNmM0ZjM2MWItNDRkMTIxODQ=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-01 16:46:06,546 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, b768c603-171e-42bc-aea3-d500ca67de89, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:06,512 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, b496b4dd-95e0-4c89-b322-09e31e5ca627, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=MTFlYjE2ZDEtZGUzODg3ZGItYzhkOGJjYzctNzY2YTJlMA==" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-01 16:46:06,547 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, b496b4dd-95e0-4c89-b322-09e31e5ca627, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:06,547 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OGZhNWExZWUtNWRjYTZlMjctZmU5YmQyM2EtYzJkYmIzYzY=
2025-11-01 16:46:06,547 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 08fe6fb6-1c49-4a11-abc3-5d947b7e4f78, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:46:06,560 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 08fe6fb6-1c49-4a11-abc3-5d947b7e4f78, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=OGZhNWExZWUtNWRjYTZlMjctZmU5YmQyM2EtYzJkYmIzYzY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-01 16:46:06,561 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 08fe6fb6-1c49-4a11-abc3-5d947b7e4f78, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:06,548 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YTAwODk3ZjgtYzJlZjY3ODYtM2JjMzliZmItOTAxNDA2ZDk=
2025-11-01 16:46:06,561 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, cf55fe54-0f74-4a7b-bdc6-c7642cc97356, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:46:06,562 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, cf55fe54-0f74-4a7b-bdc6-c7642cc97356, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YTAwODk3ZjgtYzJlZjY3ODYtM2JjMzliZmItOTAxNDA2ZDk=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-01 16:46:06,563 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, cf55fe54-0f74-4a7b-bdc6-c7642cc97356, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:10,362 - DEBUG - ya.test - _wait: Process resource usage is not available as process finished before wait4 was called
2025-11-01 16:46:10,370 - DEBUG - ya.test - _save_outputs: Command (pid 3056824) rc: 0
2025-11-01 16:46:10,371 - DEBUG - ya.test - _save_outputs: Command (pid 3056824) elapsed time (sec): 3.8586106300354004
2025-11-01 16:46:10,371 - DEBUG - ya.test - _save_outputs: Command (pid 3056824) wtime: 3.888
2025-11-01 16:46:10,371 - DEBUG - ya.test - _save_outputs: Command (pid 3056824) 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-01 16:46:10,375 - DEBUG - ya.test - _save_outputs: Command (pid 3056824) errors:

2025-11-01 16:46:10,419 - DEBUG - ya.test - _wait: Process resource usage is not available as process finished before wait4 was called
2025-11-01 16:46:10,419 - DEBUG - ya.test - _save_outputs: Command (pid 3056783) rc: 0
2025-11-01 16:46:10,419 - DEBUG - ya.test - _save_outputs: Command (pid 3056783) elapsed time (sec): 3.9383668899536133
2025-11-01 16:46:10,420 - DEBUG - ya.test - _save_outputs: Command (pid 3056783) wtime: 4.006
2025-11-01 16:46:10,420 - DEBUG - ya.test - _save_outputs: Command (pid 3056783) 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-01 16:46:10,420 - DEBUG - ya.test - _save_outputs: Command (pid 3056783) errors:

2025-11-01 16:46:13,847 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NTVkMzgxMTItYTU4YzMzOGUtYmZlNTRmZTEtODMyNWVlOTU=
2025-11-01 16:46:13,848 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NTVkMzgxMTItYTU4YzMzOGUtYmZlNTRmZTEtODMyNWVlOTU=
2025-11-01 16:46:13,862 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 6dec0510-a640-4c70-a463-3bc4be294407, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:46:13,871 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 6dec0510-a640-4c70-a463-3bc4be294407, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=NTVkMzgxMTItYTU4YzMzOGUtYmZlNTRmZTEtODMyNWVlOTU=" 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-11-01 16:46:13,871 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 6dec0510-a640-4c70-a463-3bc4be294407, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:13,874 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YmJlMWE2NTAtYjYxYTFiYjItMWIwZDUyZC04OGVhOTI3MQ==
2025-11-01 16:46:13,888 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YmJlMWE2NTAtYjYxYTFiYjItMWIwZDUyZC04OGVhOTI3MQ==
2025-11-01 16:46:13,888 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, a2bc4107-ec38-46fe-8c24-69b8206df798, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:46:13,889 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, a2bc4107-ec38-46fe-8c24-69b8206df798, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YmJlMWE2NTAtYjYxYTFiYjItMWIwZDUyZC04OGVhOTI3MQ==" 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-01 16:46:13,890 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, a2bc4107-ec38-46fe-8c24-69b8206df798, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:13,893 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YjEyMDZhYWYtNjFlNGZkMjQtYTc4YzA2OGItZTIyOWQwYzc=
2025-11-01 16:46:13,899 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YjEyMDZhYWYtNjFlNGZkMjQtYTc4YzA2OGItZTIyOWQwYzc=
2025-11-01 16:46:13,905 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, bf0d7cec-d9ba-4a13-bf94-8ccc99f42285, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:46:13,906 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, bf0d7cec-d9ba-4a13-bf94-8ccc99f42285, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YjEyMDZhYWYtNjFlNGZkMjQtYTc4YzA2OGItZTIyOWQwYzc=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(4)" } stats_mode: STATS_MODE_NONE }
2025-11-01 16:46:13,922 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NGVkODJlMGMtOTIwMmYyMTAtMzI1MzQ4NWQtYmE4ZjhjZTg=
2025-11-01 16:46:13,907 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YjU2YmFmNDktYTU1YzIwZTUtYTIxNDE1NjQtN2RhOTM2NGI=
2025-11-01 16:46:13,923 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YjU2YmFmNDktYTU1YzIwZTUtYTIxNDE1NjQtN2RhOTM2NGI=
2025-11-01 16:46:13,924 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, bf0d7cec-d9ba-4a13-bf94-8ccc99f42285, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:13,925 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YTcyMzhlMTAtNjYyODk0MjItYTZkYWJmZTItYmRjNWIxYWE=
2025-11-01 16:46:13,928 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NGVkODJlMGMtOTIwMmYyMTAtMzI1MzQ4NWQtYmE4ZjhjZTg=
2025-11-01 16:46:13,928 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 6d567497-540e-4514-b7d0-aecc87e6d731, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:46:13,932 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 6d567497-540e-4514-b7d0-aecc87e6d731, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YjU2YmFmNDktYTU1YzIwZTUtYTIxNDE1NjQtN2RhOTM2NGI=" 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-11-01 16:46:13,931 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YTcyMzhlMTAtNjYyODk0MjItYTZkYWJmZTItYmRjNWIxYWE=
2025-11-01 16:46:13,930 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 30afa53d-eff8-4068-9889-90ccdffe3b71, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:46:13,933 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 6d567497-540e-4514-b7d0-aecc87e6d731, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:13,953 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 5eba4f21-6c9a-4ae0-bd42-5623c0144028, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:46:13,999 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 30afa53d-eff8-4068-9889-90ccdffe3b71, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=NGVkODJlMGMtOTIwMmYyMTAtMzI1MzQ4NWQtYmE4ZjhjZTg=" 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-01 16:46:14,001 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 5eba4f21-6c9a-4ae0-bd42-5623c0144028, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YTcyMzhlMTAtNjYyODk0MjItYTZkYWJmZTItYmRjNWIxYWE=" 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-11-01 16:46:14,004 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 30afa53d-eff8-4068-9889-90ccdffe3b71, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:14,007 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NjE0OTEzZDMtNzI2MjE0YjctNmM0ZjM2MWItNDRkMTIxODQ=
2025-11-01 16:46:14,016 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 5eba4f21-6c9a-4ae0-bd42-5623c0144028, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:14,023 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NjE0OTEzZDMtNzI2MjE0YjctNmM0ZjM2MWItNDRkMTIxODQ=
2025-11-01 16:46:14,026 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, c32f6ed6-1098-454f-b70a-e973d75a6c4b, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:46:14,028 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, c32f6ed6-1098-454f-b70a-e973d75a6c4b, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=NjE0OTEzZDMtNzI2MjE0YjctNmM0ZjM2MWItNDRkMTIxODQ=" 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-01 16:46:14,030 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, c32f6ed6-1098-454f-b70a-e973d75a6c4b, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:14,106 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YTAwODk3ZjgtYzJlZjY3ODYtM2JjMzliZmItOTAxNDA2ZDk=
2025-11-01 16:46:14,107 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YTAwODk3ZjgtYzJlZjY3ODYtM2JjMzliZmItOTAxNDA2ZDk=
2025-11-01 16:46:14,111 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 639f6dc5-8143-4d4b-aed7-3ca5ef17ac37, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:46:14,125 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 639f6dc5-8143-4d4b-aed7-3ca5ef17ac37, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YTAwODk3ZjgtYzJlZjY3ODYtM2JjMzliZmItOTAxNDA2ZDk=" 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-01 16:46:14,126 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 639f6dc5-8143-4d4b-aed7-3ca5ef17ac37, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:14,131 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=OGZhNWExZWUtNWRjYTZlMjctZmU5YmQyM2EtYzJkYmIzYzY=
2025-11-01 16:46:14,131 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OGZhNWExZWUtNWRjYTZlMjctZmU5YmQyM2EtYzJkYmIzYzY=
2025-11-01 16:46:14,131 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 85d410d5-e2c0-4cf3-a74c-4edc23402a3b, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:46:14,132 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 85d410d5-e2c0-4cf3-a74c-4edc23402a3b, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=OGZhNWExZWUtNWRjYTZlMjctZmU5YmQyM2EtYzJkYmIzYzY=" 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-01 16:46:14,132 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 85d410d5-e2c0-4cf3-a74c-4edc23402a3b, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:14,141 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MTFlYjE2ZDEtZGUzODg3ZGItYzhkOGJjYzctNzY2YTJlMA==
2025-11-01 16:46:14,155 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MTFlYjE2ZDEtZGUzODg3ZGItYzhkOGJjYzctNzY2YTJlMA==
2025-11-01 16:46:14,155 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, b55f73cd-6a25-478d-a5b0-e1a7be90d6bf, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:46:14,156 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, b55f73cd-6a25-478d-a5b0-e1a7be90d6bf, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=MTFlYjE2ZDEtZGUzODg3ZGItYzhkOGJjYzctNzY2YTJlMA==" 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-01 16:46:14,156 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, b55f73cd-6a25-478d-a5b0-e1a7be90d6bf, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:15,810 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YmJlMWE2NTAtYjYxYTFiYjItMWIwZDUyZC04OGVhOTI3MQ==
2025-11-01 16:46:15,811 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YmJlMWE2NTAtYjYxYTFiYjItMWIwZDUyZC04OGVhOTI3MQ==
2025-11-01 16:46:15,858 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 491ecff0-54a3-4952-8a3c-433339d3b5eb, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:46:15,859 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 491ecff0-54a3-4952-8a3c-433339d3b5eb, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YmJlMWE2NTAtYjYxYTFiYjItMWIwZDUyZC04OGVhOTI3MQ==" 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-01 16:46:15,859 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 491ecff0-54a3-4952-8a3c-433339d3b5eb, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:16,984 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YTcyMzhlMTAtNjYyODk0MjItYTZkYWJmZTItYmRjNWIxYWE=
2025-11-01 16:46:16,985 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YTcyMzhlMTAtNjYyODk0MjItYTZkYWJmZTItYmRjNWIxYWE=
2025-11-01 16:46:16,985 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 47de08e7-f9fb-4224-b032-9c3696b7feaa, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:46:16,986 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 47de08e7-f9fb-4224-b032-9c3696b7feaa, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YTcyMzhlMTAtNjYyODk0MjItYTZkYWJmZTItYmRjNWIxYWE=" 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-11-01 16:46:16,992 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 47de08e7-f9fb-4224-b032-9c3696b7feaa, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:18,696 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YmJlMWE2NTAtYjYxYTFiYjItMWIwZDUyZC04OGVhOTI3MQ==
2025-11-01 16:46:18,699 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YmJlMWE2NTAtYjYxYTFiYjItMWIwZDUyZC04OGVhOTI3MQ==
2025-11-01 16:46:18,699 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 63c764f2-aae2-424f-9ce4-b999255ad07a, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:46:18,710 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 63c764f2-aae2-424f-9ce4-b999255ad07a, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YmJlMWE2NTAtYjYxYTFiYjItMWIwZDUyZC04OGVhOTI3MQ==" 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-01 16:46:18,711 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 63c764f2-aae2-424f-9ce4-b999255ad07a, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:19,533 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YTcyMzhlMTAtNjYyODk0MjItYTZkYWJmZTItYmRjNWIxYWE=
2025-11-01 16:46:19,534 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YTcyMzhlMTAtNjYyODk0MjItYTZkYWJmZTItYmRjNWIxYWE=
2025-11-01 16:46:19,537 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 5a0e72ce-65d0-4d21-bed2-2fbdaa002dc7, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:46:19,543 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 5a0e72ce-65d0-4d21-bed2-2fbdaa002dc7, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YTcyMzhlMTAtNjYyODk0MjItYTZkYWJmZTItYmRjNWIxYWE=" 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-11-01 16:46:19,556 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 5a0e72ce-65d0-4d21-bed2-2fbdaa002dc7, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:19,617 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NTVkMzgxMTItYTU4YzMzOGUtYmZlNTRmZTEtODMyNWVlOTU=
2025-11-01 16:46:19,622 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NTVkMzgxMTItYTU4YzMzOGUtYmZlNTRmZTEtODMyNWVlOTU=
2025-11-01 16:46:19,625 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, b32dd48a-f407-4924-afda-15c8c9eed63d, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:46:19,629 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, b32dd48a-f407-4924-afda-15c8c9eed63d, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=NTVkMzgxMTItYTU4YzMzOGUtYmZlNTRmZTEtODMyNWVlOTU=" 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-11-01 16:46:19,644 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, b32dd48a-f407-4924-afda-15c8c9eed63d, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:19,646 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YmJlMWE2NTAtYjYxYTFiYjItMWIwZDUyZC04OGVhOTI3MQ==
2025-11-01 16:46:19,694 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YjU2YmFmNDktYTU1YzIwZTUtYTIxNDE1NjQtN2RhOTM2NGI=
2025-11-01 16:46:19,702 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YmJlMWE2NTAtYjYxYTFiYjItMWIwZDUyZC04OGVhOTI3MQ==
2025-11-01 16:46:19,722 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, a11235ca-734e-4d4e-8de8-e22202ad6456, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:46:19,722 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, a11235ca-734e-4d4e-8de8-e22202ad6456, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YmJlMWE2NTAtYjYxYTFiYjItMWIwZDUyZC04OGVhOTI3MQ==" 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-11-01 16:46:19,726 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, a11235ca-734e-4d4e-8de8-e22202ad6456, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:19,835 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NGVkODJlMGMtOTIwMmYyMTAtMzI1MzQ4NWQtYmE4ZjhjZTg=
2025-11-01 16:46:19,860 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YjU2YmFmNDktYTU1YzIwZTUtYTIxNDE1NjQtN2RhOTM2NGI=
2025-11-01 16:46:19,861 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, dabac020-c648-4e76-a41f-acdd044f35f6, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:46:19,862 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, dabac020-c648-4e76-a41f-acdd044f35f6, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YjU2YmFmNDktYTU1YzIwZTUtYTIxNDE1NjQtN2RhOTM2NGI=" 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-01 16:46:19,863 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YTcyMzhlMTAtNjYyODk0MjItYTZkYWJmZTItYmRjNWIxYWE=
2025-11-01 16:46:19,864 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, dabac020-c648-4e76-a41f-acdd044f35f6, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:19,867 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=OGZhNWExZWUtNWRjYTZlMjctZmU5YmQyM2EtYzJkYmIzYzY=
2025-11-01 16:46:19,887 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NjE0OTEzZDMtNzI2MjE0YjctNmM0ZjM2MWItNDRkMTIxODQ=
2025-11-01 16:46:19,902 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NGVkODJlMGMtOTIwMmYyMTAtMzI1MzQ4NWQtYmE4ZjhjZTg=
2025-11-01 16:46:19,912 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, f07384a0-dfa7-49cc-aeb3-55c173dd93bf, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:46:19,913 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YTcyMzhlMTAtNjYyODk0MjItYTZkYWJmZTItYmRjNWIxYWE=
2025-11-01 16:46:19,914 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, f07384a0-dfa7-49cc-aeb3-55c173dd93bf, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=NGVkODJlMGMtOTIwMmYyMTAtMzI1MzQ4NWQtYmE4ZjhjZTg=" 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-01 16:46:19,915 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, b8a50d4c-6c69-4549-a2d7-0061d8b66234, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:46:19,934 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, f07384a0-dfa7-49cc-aeb3-55c173dd93bf, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:19,953 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, b8a50d4c-6c69-4549-a2d7-0061d8b66234, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YTcyMzhlMTAtNjYyODk0MjItYTZkYWJmZTItYmRjNWIxYWE=" 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-01 16:46:19,955 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YTAwODk3ZjgtYzJlZjY3ODYtM2JjMzliZmItOTAxNDA2ZDk=
2025-11-01 16:46:19,983 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, b8a50d4c-6c69-4549-a2d7-0061d8b66234, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:20,022 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OGZhNWExZWUtNWRjYTZlMjctZmU5YmQyM2EtYzJkYmIzYzY=
2025-11-01 16:46:20,023 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, bdb78b43-6274-4baa-bce3-45de4f99dcaf, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:46:20,029 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, bdb78b43-6274-4baa-bce3-45de4f99dcaf, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=OGZhNWExZWUtNWRjYTZlMjctZmU5YmQyM2EtYzJkYmIzYzY=" 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-01 16:46:20,047 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, bdb78b43-6274-4baa-bce3-45de4f99dcaf, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:20,054 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MTFlYjE2ZDEtZGUzODg3ZGItYzhkOGJjYzctNzY2YTJlMA==
2025-11-01 16:46:20,052 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YjEyMDZhYWYtNjFlNGZkMjQtYTc4YzA2OGItZTIyOWQwYzc=
2025-11-01 16:46:20,094 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NjE0OTEzZDMtNzI2MjE0YjctNmM0ZjM2MWItNDRkMTIxODQ=
2025-11-01 16:46:20,123 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, d51c8034-ea26-46bd-8266-34f205a506e3, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:46:20,123 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, d51c8034-ea26-46bd-8266-34f205a506e3, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=NjE0OTEzZDMtNzI2MjE0YjctNmM0ZjM2MWItNDRkMTIxODQ=" 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-01 16:46:20,130 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, d51c8034-ea26-46bd-8266-34f205a506e3, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:20,127 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YTAwODk3ZjgtYzJlZjY3ODYtM2JjMzliZmItOTAxNDA2ZDk=
2025-11-01 16:46:20,131 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, a2795d7f-9580-4470-b559-d655dcd1653e, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:46:20,131 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, a2795d7f-9580-4470-b559-d655dcd1653e, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YTAwODk3ZjgtYzJlZjY3ODYtM2JjMzliZmItOTAxNDA2ZDk=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(4)" } stats_mode: STATS_MODE_NONE }
2025-11-01 16:46:20,132 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, a2795d7f-9580-4470-b559-d655dcd1653e, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:21,038 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NTVkMzgxMTItYTU4YzMzOGUtYmZlNTRmZTEtODMyNWVlOTU=
2025-11-01 16:46:21,039 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YjEyMDZhYWYtNjFlNGZkMjQtYTc4YzA2OGItZTIyOWQwYzc=
2025-11-01 16:46:21,053 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, e723fefa-1481-46ed-b44f-634a6b05af85, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:46:21,055 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, e723fefa-1481-46ed-b44f-634a6b05af85, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YjEyMDZhYWYtNjFlNGZkMjQtYTc4YzA2OGItZTIyOWQwYzc=" 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-11-01 16:46:21,057 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, e723fefa-1481-46ed-b44f-634a6b05af85, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:21,415 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YmJlMWE2NTAtYjYxYTFiYjItMWIwZDUyZC04OGVhOTI3MQ==
2025-11-01 16:46:21,431 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MTFlYjE2ZDEtZGUzODg3ZGItYzhkOGJjYzctNzY2YTJlMA==
2025-11-01 16:46:21,439 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, f4d3b447-3629-4d1b-a682-caa1f5a35630, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:46:21,443 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, f4d3b447-3629-4d1b-a682-caa1f5a35630, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=MTFlYjE2ZDEtZGUzODg3ZGItYzhkOGJjYzctNzY2YTJlMA==" 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-11-01 16:46:21,444 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, f4d3b447-3629-4d1b-a682-caa1f5a35630, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:22,375 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NGVkODJlMGMtOTIwMmYyMTAtMzI1MzQ4NWQtYmE4ZjhjZTg=
2025-11-01 16:46:22,376 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NTVkMzgxMTItYTU4YzMzOGUtYmZlNTRmZTEtODMyNWVlOTU=
2025-11-01 16:46:22,380 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 6d9a1213-521f-47b8-b74a-f4ae89ee6b45, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:46:22,381 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 6d9a1213-521f-47b8-b74a-f4ae89ee6b45, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=NTVkMzgxMTItYTU4YzMzOGUtYmZlNTRmZTEtODMyNWVlOTU=" 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-01 16:46:22,382 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 6d9a1213-521f-47b8-b74a-f4ae89ee6b45, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:22,387 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=OGZhNWExZWUtNWRjYTZlMjctZmU5YmQyM2EtYzJkYmIzYzY=
2025-11-01 16:46:22,389 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YmJlMWE2NTAtYjYxYTFiYjItMWIwZDUyZC04OGVhOTI3MQ==
2025-11-01 16:46:22,389 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 9b743d67-4a4c-427d-bce2-e6cbee0355fc, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:46:22,390 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 9b743d67-4a4c-427d-bce2-e6cbee0355fc, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YmJlMWE2NTAtYjYxYTFiYjItMWIwZDUyZC04OGVhOTI3MQ==" 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-01 16:46:22,390 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 9b743d67-4a4c-427d-bce2-e6cbee0355fc, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:22,394 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YjU2YmFmNDktYTU1YzIwZTUtYTIxNDE1NjQtN2RhOTM2NGI=
2025-11-01 16:46:22,398 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YjEyMDZhYWYtNjFlNGZkMjQtYTc4YzA2OGItZTIyOWQwYzc=
2025-11-01 16:46:22,398 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YTcyMzhlMTAtNjYyODk0MjItYTZkYWJmZTItYmRjNWIxYWE=
2025-11-01 16:46:22,400 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NGVkODJlMGMtOTIwMmYyMTAtMzI1MzQ4NWQtYmE4ZjhjZTg=
2025-11-01 16:46:22,405 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 30074bb7-a86b-4627-8b98-6d05b3a13ee9, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:46:22,406 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 30074bb7-a86b-4627-8b98-6d05b3a13ee9, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=NGVkODJlMGMtOTIwMmYyMTAtMzI1MzQ4NWQtYmE4ZjhjZTg=" 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-01 16:46:22,408 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 30074bb7-a86b-4627-8b98-6d05b3a13ee9, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:22,409 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OGZhNWExZWUtNWRjYTZlMjctZmU5YmQyM2EtYzJkYmIzYzY=
2025-11-01 16:46:22,409 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 9718d0f2-a8e2-4280-8833-bf47e21772e8, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:46:22,410 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 9718d0f2-a8e2-4280-8833-bf47e21772e8, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=OGZhNWExZWUtNWRjYTZlMjctZmU5YmQyM2EtYzJkYmIzYzY=" 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-01 16:46:22,411 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 9718d0f2-a8e2-4280-8833-bf47e21772e8, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:22,412 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MTFlYjE2ZDEtZGUzODg3ZGItYzhkOGJjYzctNzY2YTJlMA==
2025-11-01 16:46:22,414 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YTAwODk3ZjgtYzJlZjY3ODYtM2JjMzliZmItOTAxNDA2ZDk=
2025-11-01 16:46:22,419 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NjE0OTEzZDMtNzI2MjE0YjctNmM0ZjM2MWItNDRkMTIxODQ=
2025-11-01 16:46:22,447 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YjU2YmFmNDktYTU1YzIwZTUtYTIxNDE1NjQtN2RhOTM2NGI=
2025-11-01 16:46:22,454 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 85fb4621-9b2f-45e1-8d40-1e6366d74957, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:46:22,455 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 85fb4621-9b2f-45e1-8d40-1e6366d74957, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YjU2YmFmNDktYTU1YzIwZTUtYTIxNDE1NjQtN2RhOTM2NGI=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(5)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(4))" } stats_mode: STATS_MODE_NONE }
2025-11-01 16:46:22,457 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YjEyMDZhYWYtNjFlNGZkMjQtYTc4YzA2OGItZTIyOWQwYzc=
2025-11-01 16:46:22,480 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 6ea8edf2-8cd4-4989-a591-acfbc010a153, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:46:22,481 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 6ea8edf2-8cd4-4989-a591-acfbc010a153, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YjEyMDZhYWYtNjFlNGZkMjQtYTc4YzA2OGItZTIyOWQwYzc=" 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-01 16:46:22,482 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 6ea8edf2-8cd4-4989-a591-acfbc010a153, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:22,470 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 85fb4621-9b2f-45e1-8d40-1e6366d74957, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:23,754 - DEBUG - ya.test - _wait: Process resource usage is not available as process finished before wait4 was called
2025-11-01 16:46:23,756 - DEBUG - ya.test - _save_outputs: Command (pid 3056823) rc: 0
2025-11-01 16:46:23,756 - DEBUG - ya.test - _save_outputs: Command (pid 3056823) elapsed time (sec): 17.250539779663086
2025-11-01 16:46:23,757 - DEBUG - ya.test - _save_outputs: Command (pid 3056823) wtime: 17.281
2025-11-01 16:46:23,757 - DEBUG - ya.test - _save_outputs: Command (pid 3056823) 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	15423	17023	17023	17023

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

2025-11-01 16:46:23,757 - DEBUG - ya.test - _save_outputs: Command (pid 3056823) errors:

2025-11-01 16:46:23,967 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NTVkMzgxMTItYTU4YzMzOGUtYmZlNTRmZTEtODMyNWVlOTU=
2025-11-01 16:46:24,039 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NGVkODJlMGMtOTIwMmYyMTAtMzI1MzQ4NWQtYmE4ZjhjZTg=
2025-11-01 16:46:24,043 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=OGZhNWExZWUtNWRjYTZlMjctZmU5YmQyM2EtYzJkYmIzYzY=
2025-11-01 16:46:24,049 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YmJlMWE2NTAtYjYxYTFiYjItMWIwZDUyZC04OGVhOTI3MQ==
2025-11-01 16:46:24,062 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YjU2YmFmNDktYTU1YzIwZTUtYTIxNDE1NjQtN2RhOTM2NGI=
2025-11-01 16:46:24,077 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YjEyMDZhYWYtNjFlNGZkMjQtYTc4YzA2OGItZTIyOWQwYzc=
2025-11-01 16:46:24,078 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YTcyMzhlMTAtNjYyODk0MjItYTZkYWJmZTItYmRjNWIxYWE=
2025-11-01 16:46:24,087 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 52679d45-a6f2-4db0-b70d-6a727b6c908c, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:46:24,088 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 52679d45-a6f2-4db0-b70d-6a727b6c908c, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YTcyMzhlMTAtNjYyODk0MjItYTZkYWJmZTItYmRjNWIxYWE=" 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-01 16:46:24,089 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 52679d45-a6f2-4db0-b70d-6a727b6c908c, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:24,307 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YTcyMzhlMTAtNjYyODk0MjItYTZkYWJmZTItYmRjNWIxYWE=
2025-11-01 16:46:24,308 - INFO - root - test_log_deviation: check insert: 30000 25000
2025-11-01 16:46:24,310 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.10
2025-11-01 16:46:24,311 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.10
2025-11-01 16:46:24,311 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/q6a6/0020b8/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:10083', '-d', '/Root', 'workload', 'log', '--path', 'log', 'clean']' in 'None' (waiting)
2025-11-01 16:46:24,313 - DEBUG - ya.test - execute: Command pid: 3063660
2025-11-01 16:46:24,522 - DEBUG - ya.test - _save_outputs: Command (pid 3063660) rc: 0
2025-11-01 16:46:24,523 - DEBUG - ya.test - _save_outputs: Command (pid 3063660) elapsed time (sec): 0.20574045181274414
2025-11-01 16:46:24,523 - DEBUG - ya.test - _save_outputs: Command (pid 3063660) idrss: 0
2025-11-01 16:46:24,523 - DEBUG - ya.test - _save_outputs: Command (pid 3063660) inblock: 0
2025-11-01 16:46:24,524 - DEBUG - ya.test - _save_outputs: Command (pid 3063660) isrss: 0
2025-11-01 16:46:24,524 - DEBUG - ya.test - _save_outputs: Command (pid 3063660) ixrss: 0
2025-11-01 16:46:24,524 - DEBUG - ya.test - _save_outputs: Command (pid 3063660) majflt: 0
2025-11-01 16:46:24,524 - DEBUG - ya.test - _save_outputs: Command (pid 3063660) maxrss: 909920
2025-11-01 16:46:24,524 - DEBUG - ya.test - _save_outputs: Command (pid 3063660) minflt: 3550
2025-11-01 16:46:24,524 - DEBUG - ya.test - _save_outputs: Command (pid 3063660) msgrcv: 0
2025-11-01 16:46:24,536 - DEBUG - ya.test - _save_outputs: Command (pid 3063660) msgsnd: 0
2025-11-01 16:46:24,536 - DEBUG - ya.test - _save_outputs: Command (pid 3063660) nivcsw: 34
2025-11-01 16:46:24,536 - DEBUG - ya.test - _save_outputs: Command (pid 3063660) nsignals: 0
2025-11-01 16:46:24,537 - DEBUG - ya.test - _save_outputs: Command (pid 3063660) nswap: 0
2025-11-01 16:46:24,537 - DEBUG - ya.test - _save_outputs: Command (pid 3063660) nvcsw: 130
2025-11-01 16:46:24,537 - DEBUG - ya.test - _save_outputs: Command (pid 3063660) oublock: 8
2025-11-01 16:46:24,537 - DEBUG - ya.test - _save_outputs: Command (pid 3063660) stime: 0.016078
2025-11-01 16:46:24,537 - DEBUG - ya.test - _save_outputs: Command (pid 3063660) utime: 0.064314
2025-11-01 16:46:24,537 - DEBUG - ya.test - _save_outputs: Command (pid 3063660) wtime: 0.21
2025-11-01 16:46:24,538 - DEBUG - ya.test - _save_outputs: Command (pid 3063660) output:
Remove path log...
Remove path log...Ok

2025-11-01 16:46:24,538 - DEBUG - ya.test - _save_outputs: Command (pid 3063660) errors:

2025-11-01 16:46:24,562 - INFO - ya.test - pytest_runtest_teardown: Test teardown
