2025-11-25 14:48:30,250 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-11-25 14:48:30,250 - INFO - ya.test - pytest_runtest_setup: test_log_deviation[180]
2025-11-25 14:48:30,252 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-11-25 14:48:30,258 - INFO - ya.test - pytest_runtest_setup: Test setup
2025-11-25 14:48:30,264 - INFO - ya.test - pytest_runtest_call: Test call (class_name: test_log_scenario.py::TestLogScenario, test_name: test_log_deviation[180])
2025-11-25 14:48:30,265 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/g0y6/0007d0/ydb/apps/ydb/ydb
2025-11-25 14:48:30,270 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/g0y6/0007d0/ydb/apps/ydb/ydb -e grpc://localhost:3598 -d /Root workload log --path log init --path log --store column --ttl 1000 with wait = True
2025-11-25 14:48:30,274 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.5
2025-11-25 14:48:30,275 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.5
2025-11-25 14:48:30,276 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/g0y6/0007d0/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:3598', '-d', '/Root', 'workload', 'log', '--path', 'log', 'init', '--path', 'log', '--store', 'column', '--ttl', '1000']' in 'None' (waiting)
2025-11-25 14:48:30,315 - DEBUG - ya.test - execute: Command pid: 3693601
2025-11-25 14:48:30,931 - DEBUG - ya.test - _save_outputs: Command (pid 3693601) rc: 0
2025-11-25 14:48:30,935 - DEBUG - ya.test - _save_outputs: Command (pid 3693601) elapsed time (sec): 0.6144835948944092
2025-11-25 14:48:30,941 - DEBUG - ya.test - _save_outputs: Command (pid 3693601) idrss: 0
2025-11-25 14:48:30,962 - DEBUG - ya.test - _save_outputs: Command (pid 3693601) inblock: 0
2025-11-25 14:48:30,962 - DEBUG - ya.test - _save_outputs: Command (pid 3693601) isrss: 0
2025-11-25 14:48:30,962 - DEBUG - ya.test - _save_outputs: Command (pid 3693601) ixrss: 0
2025-11-25 14:48:30,962 - DEBUG - ya.test - _save_outputs: Command (pid 3693601) majflt: 0
2025-11-25 14:48:30,962 - DEBUG - ya.test - _save_outputs: Command (pid 3693601) maxrss: 531328
2025-11-25 14:48:30,962 - DEBUG - ya.test - _save_outputs: Command (pid 3693601) minflt: 3476
2025-11-25 14:48:30,963 - DEBUG - ya.test - _save_outputs: Command (pid 3693601) msgrcv: 0
2025-11-25 14:48:30,963 - DEBUG - ya.test - _save_outputs: Command (pid 3693601) msgsnd: 0
2025-11-25 14:48:30,963 - DEBUG - ya.test - _save_outputs: Command (pid 3693601) nivcsw: 59
2025-11-25 14:48:30,963 - DEBUG - ya.test - _save_outputs: Command (pid 3693601) nsignals: 0
2025-11-25 14:48:30,963 - DEBUG - ya.test - _save_outputs: Command (pid 3693601) nswap: 0
2025-11-25 14:48:30,963 - DEBUG - ya.test - _save_outputs: Command (pid 3693601) nvcsw: 162
2025-11-25 14:48:30,964 - DEBUG - ya.test - _save_outputs: Command (pid 3693601) oublock: 8
2025-11-25 14:48:30,964 - DEBUG - ya.test - _save_outputs: Command (pid 3693601) stime: 0.015806999999999998
2025-11-25 14:48:30,964 - DEBUG - ya.test - _save_outputs: Command (pid 3693601) utime: 0.059657999999999996
2025-11-25 14:48:30,964 - DEBUG - ya.test - _save_outputs: Command (pid 3693601) wtime: 0.65
2025-11-25 14:48:30,964 - DEBUG - ya.test - _save_outputs: Command (pid 3693601) output:
Init tables ...
Init tables ...Ok

2025-11-25 14:48:30,964 - DEBUG - ya.test - _save_outputs: Command (pid 3693601) errors:

2025-11-25 14:48:30,965 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YzFiZWI2NDktOWYxZjRmYzYtYWU3NjNjLTFhZDZmMTk1
2025-11-25 14:48:30,978 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, bb7fadf1-1c4a-4eb7-8e25-3495b81c009b, ghrun-n7olz6xni4.auto.internal:3598): creating call state
2025-11-25 14:48:30,979 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, bb7fadf1-1c4a-4eb7-8e25-3495b81c009b, ghrun-n7olz6xni4.auto.internal:3598): request = { session_id: "ydb://session/3?node_id=1&id=YzFiZWI2NDktOWYxZjRmYzYtYWU3NjNjLTFhZDZmMTk1" 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 14:48:30,980 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, bb7fadf1-1c4a-4eb7-8e25-3495b81c009b, ghrun-n7olz6xni4.auto.internal:3598): response = { <_MultiThreadedRendezvous object> }
2025-11-25 14:48:31,041 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YzFiZWI2NDktOWYxZjRmYzYtYWU3NjNjLTFhZDZmMTk1
2025-11-25 14:48:31,045 - INFO - root - _insert_rows: YdbWorkloadLog bulk_upsert
2025-11-25 14:48:31,046 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/g0y6/0007d0/ydb/apps/ydb/ydb -e grpc://localhost:3598 -d /Root workload log --path log run bulk_upsert --seconds 3 --threads 10 --rows 500 --timestamp_deviation 180 with wait = True
2025-11-25 14:48:31,047 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.6
2025-11-25 14:48:31,055 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.6
2025-11-25 14:48:31,055 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/g0y6/0007d0/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:3598', '-d', '/Root', 'workload', 'log', '--path', 'log', 'run', 'bulk_upsert', '--seconds', '3', '--threads', '10', '--rows', '500', '--timestamp_deviation', '180']' in 'None' (waiting)
2025-11-25 14:48:31,057 - DEBUG - ya.test - execute: Command pid: 3693862
2025-11-25 14:48:35,312 - DEBUG - ya.test - _wait: Process resource usage is not available as process finished before wait4 was called
2025-11-25 14:48:35,313 - DEBUG - ya.test - _save_outputs: Command (pid 3693862) rc: 0
2025-11-25 14:48:35,351 - DEBUG - ya.test - _save_outputs: Command (pid 3693862) elapsed time (sec): 4.254737854003906
2025-11-25 14:48:35,429 - DEBUG - ya.test - _save_outputs: Command (pid 3693862) wtime: 4.257
2025-11-25 14:48:35,430 - DEBUG - ya.test - _save_outputs: Command (pid 3693862) output:
Window	    Txs	Txs/Sec	Retries	Errors	p50(ms)	p95(ms)	p99(ms)	pMax(ms)
1	      2	2	0	0	799	807	807	807
2	     10	10	0	0	1023	1287	1287	1287
3	     18	18	0	0	1311	1423	1439	1439

Total	    Txs	Txs/Sec	Retries	Errors	p50(ms)	p95(ms)	p99(ms)	pMax(ms)
3	     30	10	0	0	1159	1423	1439	1439

2025-11-25 14:48:35,430 - DEBUG - ya.test - _save_outputs: Command (pid 3693862) errors:

2025-11-25 14:48:35,432 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NzFhYThlNmQtNTJkZmNjNGQtNjJlZTEyY2EtZDkzMjgyYzU=
2025-11-25 14:48:35,432 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 6147fca1-7c34-4243-a3a4-b1f1466b0e58, ghrun-n7olz6xni4.auto.internal:3598): creating call state
2025-11-25 14:48:35,447 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 6147fca1-7c34-4243-a3a4-b1f1466b0e58, ghrun-n7olz6xni4.auto.internal:3598): request = { session_id: "ydb://session/3?node_id=1&id=NzFhYThlNmQtNTJkZmNjNGQtNjJlZTEyY2EtZDkzMjgyYzU=" 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 14:48:35,486 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 6147fca1-7c34-4243-a3a4-b1f1466b0e58, ghrun-n7olz6xni4.auto.internal:3598): response = { <_MultiThreadedRendezvous object> }
2025-11-25 14:48:37,665 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NzFhYThlNmQtNTJkZmNjNGQtNjJlZTEyY2EtZDkzMjgyYzU=
2025-11-25 14:48:37,666 - INFO - root - test_log_deviation: Count rows after insert 15000 before wait
2025-11-25 14:48:37,666 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MTVhZTVmMGItMTBjNmU2MDItNDljOGJlMmQtNTY4NmZkNjA=
2025-11-25 14:48:37,674 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 5a25d528-425b-4644-b223-34a5f3dbe2b7, ghrun-n7olz6xni4.auto.internal:3598): creating call state
2025-11-25 14:48:37,678 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 5a25d528-425b-4644-b223-34a5f3dbe2b7, ghrun-n7olz6xni4.auto.internal:3598): request = { session_id: "ydb://session/3?node_id=1&id=MTVhZTVmMGItMTBjNmU2MDItNDljOGJlMmQtNTY4NmZkNjA=" 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 14:48:37,679 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 5a25d528-425b-4644-b223-34a5f3dbe2b7, ghrun-n7olz6xni4.auto.internal:3598): response = { <_MultiThreadedRendezvous object> }
2025-11-25 14:48:39,009 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MTVhZTVmMGItMTBjNmU2MDItNDljOGJlMmQtNTY4NmZkNjA=
2025-11-25 14:48:39,026 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MjJhOGMyZmItZjM4ODEzY2YtMjU4ZTMzOTktM2I0OTU4ZmM=
2025-11-25 14:48:39,026 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 3b589164-cea2-4f52-b4a9-0d3dc971c3cf, ghrun-n7olz6xni4.auto.internal:3598): creating call state
2025-11-25 14:48:39,027 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 3b589164-cea2-4f52-b4a9-0d3dc971c3cf, ghrun-n7olz6xni4.auto.internal:3598): request = { session_id: "ydb://session/3?node_id=1&id=MjJhOGMyZmItZjM4ODEzY2YtMjU4ZTMzOTktM2I0OTU4ZmM=" 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 14:48:39,032 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 3b589164-cea2-4f52-b4a9-0d3dc971c3cf, ghrun-n7olz6xni4.auto.internal:3598): response = { <_MultiThreadedRendezvous object> }
2025-11-25 14:48:39,901 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MjJhOGMyZmItZjM4ODEzY2YtMjU4ZTMzOTktM2I0OTU4ZmM=
2025-11-25 14:48:39,917 - INFO - root - _insert_rows: YdbWorkloadLog bulk_upsert
2025-11-25 14:48:39,918 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/g0y6/0007d0/ydb/apps/ydb/ydb -e grpc://localhost:3598 -d /Root workload log --path log run bulk_upsert --seconds 3 --threads 10 --rows 500 --timestamp_deviation 180 with wait = True
2025-11-25 14:48:39,919 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.7
2025-11-25 14:48:39,920 - INFO - root - _insert_rows: YdbWorkloadLog insert
2025-11-25 14:48:39,920 - INFO - root - _insert_rows: YdbWorkloadLog upsert
2025-11-25 14:48:39,921 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OGQxZjJlODgtOTU4ODNhZTAtNzIyY2QwYS04NzZiYTU2MA==
2025-11-25 14:48:39,950 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/g0y6/0007d0/ydb/apps/ydb/ydb -e grpc://localhost:3598 -d /Root workload log --path log run insert --seconds 3 --threads 10 --rows 500 --timestamp_deviation 180 with wait = True
2025-11-25 14:48:39,950 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/g0y6/0007d0/ydb/apps/ydb/ydb -e grpc://localhost:3598 -d /Root workload log --path log run upsert --seconds 3 --threads 10 --rows 500 --timestamp_deviation 180 with wait = True
2025-11-25 14:48:39,955 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 8654039e-2d0e-4d9c-a8db-5d1c2109747b, ghrun-n7olz6xni4.auto.internal:3598): creating call state
2025-11-25 14:48:39,955 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NTVkYThmZDktNzk3NThmYi1mMTMyYjE1LWE4Mzg2NWMx
2025-11-25 14:48:39,961 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.7
2025-11-25 14:48:39,964 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.8
2025-11-25 14:48:39,966 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.9
2025-11-25 14:48:39,971 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 6a678759-cd71-46c3-9021-a7ca0a5a25b3, ghrun-n7olz6xni4.auto.internal:3598): creating call state
2025-11-25 14:48:39,966 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 8654039e-2d0e-4d9c-a8db-5d1c2109747b, ghrun-n7olz6xni4.auto.internal:3598): request = { session_id: "ydb://session/3?node_id=1&id=OGQxZjJlODgtOTU4ODNhZTAtNzIyY2QwYS04NzZiYTU2MA==" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-25 14:48:39,971 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NzFlMGJkMDEtZWNhMzk3ZGQtNTgxNzliZTctODc1NmZiNDI=
2025-11-25 14:48:39,973 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/g0y6/0007d0/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:3598', '-d', '/Root', 'workload', 'log', '--path', 'log', 'run', 'bulk_upsert', '--seconds', '3', '--threads', '10', '--rows', '500', '--timestamp_deviation', '180']' in 'None' (waiting)
2025-11-25 14:48:39,978 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.8
2025-11-25 14:48:39,983 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.9
2025-11-25 14:48:39,986 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 61c6a38a-96c6-4515-b072-eb54c1ec24bc, ghrun-n7olz6xni4.auto.internal:3598): creating call state
2025-11-25 14:48:39,994 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZDBjODU1NmMtMmZmYzE2NDAtNDhmMTk3YS1lNDJhMzJiYg==
2025-11-25 14:48:39,985 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 6a678759-cd71-46c3-9021-a7ca0a5a25b3, ghrun-n7olz6xni4.auto.internal:3598): request = { session_id: "ydb://session/3?node_id=1&id=NTVkYThmZDktNzk3NThmYi1mMTMyYjE1LWE4Mzg2NWMx" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-25 14:48:40,002 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 6a678759-cd71-46c3-9021-a7ca0a5a25b3, ghrun-n7olz6xni4.auto.internal:3598): response = { <_MultiThreadedRendezvous object> }
2025-11-25 14:48:39,996 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 61c6a38a-96c6-4515-b072-eb54c1ec24bc, ghrun-n7olz6xni4.auto.internal:3598): request = { session_id: "ydb://session/3?node_id=1&id=NzFlMGJkMDEtZWNhMzk3ZGQtNTgxNzliZTctODc1NmZiNDI=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-25 14:48:40,003 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 61c6a38a-96c6-4515-b072-eb54c1ec24bc, ghrun-n7olz6xni4.auto.internal:3598): response = { <_MultiThreadedRendezvous object> }
2025-11-25 14:48:39,986 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 8654039e-2d0e-4d9c-a8db-5d1c2109747b, ghrun-n7olz6xni4.auto.internal:3598): response = { <_MultiThreadedRendezvous object> }
2025-11-25 14:48:39,988 - DEBUG - ya.test - execute: Command pid: 3695603
2025-11-25 14:48:39,989 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/g0y6/0007d0/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:3598', '-d', '/Root', 'workload', 'log', '--path', 'log', 'run', 'insert', '--seconds', '3', '--threads', '10', '--rows', '500', '--timestamp_deviation', '180']' in 'None' (waiting)
2025-11-25 14:48:39,994 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/g0y6/0007d0/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:3598', '-d', '/Root', 'workload', 'log', '--path', 'log', 'run', 'upsert', '--seconds', '3', '--threads', '10', '--rows', '500', '--timestamp_deviation', '180']' in 'None' (waiting)
2025-11-25 14:48:40,000 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, de5da97c-7a67-46dd-93d2-eb54a0f0ef31, ghrun-n7olz6xni4.auto.internal:3598): creating call state
2025-11-25 14:48:40,000 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MzljNGQ3YTUtOTljZjJhNzYtNWIxODZjYjAtZTRjMjllOTA=
2025-11-25 14:48:40,015 - DEBUG - ya.test - execute: Command pid: 3695609
2025-11-25 14:48:40,024 - DEBUG - ya.test - execute: Command pid: 3695613
2025-11-25 14:48:40,025 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, de5da97c-7a67-46dd-93d2-eb54a0f0ef31, ghrun-n7olz6xni4.auto.internal:3598): request = { session_id: "ydb://session/3?node_id=1&id=ZDBjODU1NmMtMmZmYzE2NDAtNDhmMTk3YS1lNDJhMzJiYg==" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-25 14:48:40,032 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, de5da97c-7a67-46dd-93d2-eb54a0f0ef31, ghrun-n7olz6xni4.auto.internal:3598): response = { <_MultiThreadedRendezvous object> }
2025-11-25 14:48:40,026 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NjEwNDA3NzctZjk0MjU1MWMtMTQxYjhlYTgtMTEwZDk4NA==
2025-11-25 14:48:40,035 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 129f87f4-3c89-4088-98b0-5ebac4cc8308, ghrun-n7olz6xni4.auto.internal:3598): creating call state
2025-11-25 14:48:40,026 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, a20dff5d-8a87-499f-af2d-f46714911af1, ghrun-n7olz6xni4.auto.internal:3598): creating call state
2025-11-25 14:48:40,035 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YzFiZWI2NDktOWYxZjRmYzYtYWU3NjNjLTFhZDZmMTk1
2025-11-25 14:48:40,043 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 129f87f4-3c89-4088-98b0-5ebac4cc8308, ghrun-n7olz6xni4.auto.internal:3598): request = { session_id: "ydb://session/3?node_id=1&id=NjEwNDA3NzctZjk0MjU1MWMtMTQxYjhlYTgtMTEwZDk4NA==" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-25 14:48:40,067 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 129f87f4-3c89-4088-98b0-5ebac4cc8308, ghrun-n7olz6xni4.auto.internal:3598): response = { <_MultiThreadedRendezvous object> }
2025-11-25 14:48:40,062 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 97076752-4340-482e-a6c3-eb51043e2cd5, ghrun-n7olz6xni4.auto.internal:3598): creating call state
2025-11-25 14:48:40,063 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NzFhYThlNmQtNTJkZmNjNGQtNjJlZTEyY2EtZDkzMjgyYzU=
2025-11-25 14:48:40,081 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, fc72fb29-d5c7-40b1-9ff2-92d5c86f3f41, ghrun-n7olz6xni4.auto.internal:3598): creating call state
2025-11-25 14:48:40,059 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, a20dff5d-8a87-499f-af2d-f46714911af1, ghrun-n7olz6xni4.auto.internal:3598): request = { session_id: "ydb://session/3?node_id=1&id=MzljNGQ3YTUtOTljZjJhNzYtNWIxODZjYjAtZTRjMjllOTA=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-25 14:48:40,119 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, a20dff5d-8a87-499f-af2d-f46714911af1, ghrun-n7olz6xni4.auto.internal:3598): response = { <_MultiThreadedRendezvous object> }
2025-11-25 14:48:40,073 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 97076752-4340-482e-a6c3-eb51043e2cd5, ghrun-n7olz6xni4.auto.internal:3598): request = { session_id: "ydb://session/3?node_id=1&id=YzFiZWI2NDktOWYxZjRmYzYtYWU3NjNjLTFhZDZmMTk1" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-25 14:48:40,100 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, fc72fb29-d5c7-40b1-9ff2-92d5c86f3f41, ghrun-n7olz6xni4.auto.internal:3598): request = { session_id: "ydb://session/3?node_id=1&id=NzFhYThlNmQtNTJkZmNjNGQtNjJlZTEyY2EtZDkzMjgyYzU=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-25 14:48:40,085 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MTVhZTVmMGItMTBjNmU2MDItNDljOGJlMmQtNTY4NmZkNjA=
2025-11-25 14:48:40,134 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 97076752-4340-482e-a6c3-eb51043e2cd5, ghrun-n7olz6xni4.auto.internal:3598): response = { <_MultiThreadedRendezvous object> }
2025-11-25 14:48:40,140 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, fc72fb29-d5c7-40b1-9ff2-92d5c86f3f41, ghrun-n7olz6xni4.auto.internal:3598): response = { <_MultiThreadedRendezvous object> }
2025-11-25 14:48:40,141 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 7a959806-8a78-4c17-be3f-52ab76f09ea1, ghrun-n7olz6xni4.auto.internal:3598): creating call state
2025-11-25 14:48:40,142 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MjJhOGMyZmItZjM4ODEzY2YtMjU4ZTMzOTktM2I0OTU4ZmM=
2025-11-25 14:48:40,154 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 7a959806-8a78-4c17-be3f-52ab76f09ea1, ghrun-n7olz6xni4.auto.internal:3598): request = { session_id: "ydb://session/3?node_id=1&id=MTVhZTVmMGItMTBjNmU2MDItNDljOGJlMmQtNTY4NmZkNjA=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-25 14:48:40,157 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 7a959806-8a78-4c17-be3f-52ab76f09ea1, ghrun-n7olz6xni4.auto.internal:3598): response = { <_MultiThreadedRendezvous object> }
2025-11-25 14:48:40,155 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 3a7aff28-2bc2-4072-a860-15c921705531, ghrun-n7olz6xni4.auto.internal:3598): creating call state
2025-11-25 14:48:40,169 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 3a7aff28-2bc2-4072-a860-15c921705531, ghrun-n7olz6xni4.auto.internal:3598): request = { session_id: "ydb://session/3?node_id=1&id=MjJhOGMyZmItZjM4ODEzY2YtMjU4ZTMzOTktM2I0OTU4ZmM=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-25 14:48:40,170 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 3a7aff28-2bc2-4072-a860-15c921705531, ghrun-n7olz6xni4.auto.internal:3598): response = { <_MultiThreadedRendezvous object> }
2025-11-25 14:48:43,858 - DEBUG - ya.test - _wait: Process resource usage is not available as process finished before wait4 was called
2025-11-25 14:48:43,858 - DEBUG - ya.test - _save_outputs: Command (pid 3695609) rc: 0
2025-11-25 14:48:43,858 - DEBUG - ya.test - _save_outputs: Command (pid 3695609) elapsed time (sec): 3.8284730911254883
2025-11-25 14:48:43,858 - DEBUG - ya.test - _save_outputs: Command (pid 3695609) wtime: 3.85
2025-11-25 14:48:43,859 - DEBUG - ya.test - _save_outputs: Command (pid 3695609) 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 14:48:43,859 - DEBUG - ya.test - _save_outputs: Command (pid 3695609) errors:

2025-11-25 14:48:44,066 - DEBUG - ya.test - _wait: Process resource usage is not available as process finished before wait4 was called
2025-11-25 14:48:44,066 - DEBUG - ya.test - _save_outputs: Command (pid 3695613) rc: 0
2025-11-25 14:48:44,067 - DEBUG - ya.test - _save_outputs: Command (pid 3695613) elapsed time (sec): 4.0355384349823
2025-11-25 14:48:44,067 - DEBUG - ya.test - _save_outputs: Command (pid 3695613) wtime: 4.043
2025-11-25 14:48:44,067 - DEBUG - ya.test - _save_outputs: Command (pid 3695613) 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 14:48:44,067 - DEBUG - ya.test - _save_outputs: Command (pid 3695613) errors:

2025-11-25 14:48:57,078 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NzFhYThlNmQtNTJkZmNjNGQtNjJlZTEyY2EtZDkzMjgyYzU=
2025-11-25 14:48:57,078 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NzFhYThlNmQtNTJkZmNjNGQtNjJlZTEyY2EtZDkzMjgyYzU=
2025-11-25 14:48:57,082 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, b11765f3-fe73-40ab-8d43-f4690da305ac, ghrun-n7olz6xni4.auto.internal:3598): creating call state
2025-11-25 14:48:57,086 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, b11765f3-fe73-40ab-8d43-f4690da305ac, ghrun-n7olz6xni4.auto.internal:3598): request = { session_id: "ydb://session/3?node_id=1&id=NzFhYThlNmQtNTJkZmNjNGQtNjJlZTEyY2EtZDkzMjgyYzU=" 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-25 14:48:57,094 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, b11765f3-fe73-40ab-8d43-f4690da305ac, ghrun-n7olz6xni4.auto.internal:3598): response = { <_MultiThreadedRendezvous object> }
2025-11-25 14:48:57,103 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MjJhOGMyZmItZjM4ODEzY2YtMjU4ZTMzOTktM2I0OTU4ZmM=
2025-11-25 14:48:57,107 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MjJhOGMyZmItZjM4ODEzY2YtMjU4ZTMzOTktM2I0OTU4ZmM=
2025-11-25 14:48:57,113 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 83f7ddea-0743-4e8f-8f9a-d23b8d0f97f2, ghrun-n7olz6xni4.auto.internal:3598): creating call state
2025-11-25 14:48:57,118 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 83f7ddea-0743-4e8f-8f9a-d23b8d0f97f2, ghrun-n7olz6xni4.auto.internal:3598): request = { session_id: "ydb://session/3?node_id=1&id=MjJhOGMyZmItZjM4ODEzY2YtMjU4ZTMzOTktM2I0OTU4ZmM=" 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-25 14:48:57,146 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YzFiZWI2NDktOWYxZjRmYzYtYWU3NjNjLTFhZDZmMTk1
2025-11-25 14:48:57,163 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YzFiZWI2NDktOWYxZjRmYzYtYWU3NjNjLTFhZDZmMTk1
2025-11-25 14:48:57,178 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 8148be9f-e97f-442a-8bd5-e08bdfac151a, ghrun-n7olz6xni4.auto.internal:3598): creating call state
2025-11-25 14:48:57,164 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 83f7ddea-0743-4e8f-8f9a-d23b8d0f97f2, ghrun-n7olz6xni4.auto.internal:3598): response = { <_MultiThreadedRendezvous object> }
2025-11-25 14:48:57,181 - DEBUG - ya.test - _wait: Process resource usage is not available as process finished before wait4 was called
2025-11-25 14:48:57,218 - DEBUG - ya.test - _save_outputs: Command (pid 3695603) rc: 0
2025-11-25 14:48:57,219 - DEBUG - ya.test - _save_outputs: Command (pid 3695603) elapsed time (sec): 17.210395336151123
2025-11-25 14:48:57,219 - DEBUG - ya.test - _save_outputs: Command (pid 3695603) wtime: 17.231
2025-11-25 14:48:57,219 - DEBUG - ya.test - _save_outputs: Command (pid 3695603) 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	15103	16639	16639	16639

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

2025-11-25 14:48:57,198 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MzljNGQ3YTUtOTljZjJhNzYtNWIxODZjYjAtZTRjMjllOTA=
2025-11-25 14:48:57,189 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MTVhZTVmMGItMTBjNmU2MDItNDljOGJlMmQtNTY4NmZkNjA=
2025-11-25 14:48:57,216 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 8148be9f-e97f-442a-8bd5-e08bdfac151a, ghrun-n7olz6xni4.auto.internal:3598): request = { session_id: "ydb://session/3?node_id=1&id=YzFiZWI2NDktOWYxZjRmYzYtYWU3NjNjLTFhZDZmMTk1" 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-25 14:48:57,222 - DEBUG - ya.test - _save_outputs: Command (pid 3695603) errors:

2025-11-25 14:48:57,254 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MTVhZTVmMGItMTBjNmU2MDItNDljOGJlMmQtNTY4NmZkNjA=
2025-11-25 14:48:57,279 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 6e60a4bb-eaef-48a7-bbfc-f6832040f229, ghrun-n7olz6xni4.auto.internal:3598): creating call state
2025-11-25 14:48:57,279 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MzljNGQ3YTUtOTljZjJhNzYtNWIxODZjYjAtZTRjMjllOTA=
2025-11-25 14:48:57,328 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 6e60a4bb-eaef-48a7-bbfc-f6832040f229, ghrun-n7olz6xni4.auto.internal:3598): request = { session_id: "ydb://session/3?node_id=1&id=MTVhZTVmMGItMTBjNmU2MDItNDljOGJlMmQtNTY4NmZkNjA=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(8)" } stats_mode: STATS_MODE_NONE }
2025-11-25 14:48:57,256 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 8148be9f-e97f-442a-8bd5-e08bdfac151a, ghrun-n7olz6xni4.auto.internal:3598): response = { <_MultiThreadedRendezvous object> }
2025-11-25 14:48:57,334 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 575bbebd-6d28-4af6-a602-da82b99bf3c0, ghrun-n7olz6xni4.auto.internal:3598): creating call state
2025-11-25 14:48:57,347 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 6e60a4bb-eaef-48a7-bbfc-f6832040f229, ghrun-n7olz6xni4.auto.internal:3598): response = { <_MultiThreadedRendezvous object> }
2025-11-25 14:48:57,394 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 575bbebd-6d28-4af6-a602-da82b99bf3c0, ghrun-n7olz6xni4.auto.internal:3598): request = { session_id: "ydb://session/3?node_id=1&id=MzljNGQ3YTUtOTljZjJhNzYtNWIxODZjYjAtZTRjMjllOTA=" 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 14:48:57,399 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 575bbebd-6d28-4af6-a602-da82b99bf3c0, ghrun-n7olz6xni4.auto.internal:3598): response = { <_MultiThreadedRendezvous object> }
2025-11-25 14:48:57,823 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=OGQxZjJlODgtOTU4ODNhZTAtNzIyY2QwYS04NzZiYTU2MA==
2025-11-25 14:48:57,824 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OGQxZjJlODgtOTU4ODNhZTAtNzIyY2QwYS04NzZiYTU2MA==
2025-11-25 14:48:57,825 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 6a03a22f-64f6-4600-adf8-1e125147c60f, ghrun-n7olz6xni4.auto.internal:3598): creating call state
2025-11-25 14:48:57,834 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 6a03a22f-64f6-4600-adf8-1e125147c60f, ghrun-n7olz6xni4.auto.internal:3598): request = { session_id: "ydb://session/3?node_id=1&id=OGQxZjJlODgtOTU4ODNhZTAtNzIyY2QwYS04NzZiYTU2MA==" 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-25 14:48:57,909 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 6a03a22f-64f6-4600-adf8-1e125147c60f, ghrun-n7olz6xni4.auto.internal:3598): response = { <_MultiThreadedRendezvous object> }
2025-11-25 14:48:57,941 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZDBjODU1NmMtMmZmYzE2NDAtNDhmMTk3YS1lNDJhMzJiYg==
2025-11-25 14:48:57,942 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZDBjODU1NmMtMmZmYzE2NDAtNDhmMTk3YS1lNDJhMzJiYg==
2025-11-25 14:48:57,942 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, d8c65984-a438-4678-9453-bf8f747fce0e, ghrun-n7olz6xni4.auto.internal:3598): creating call state
2025-11-25 14:48:57,942 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, d8c65984-a438-4678-9453-bf8f747fce0e, ghrun-n7olz6xni4.auto.internal:3598): request = { session_id: "ydb://session/3?node_id=1&id=ZDBjODU1NmMtMmZmYzE2NDAtNDhmMTk3YS1lNDJhMzJiYg==" 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 14:48:57,943 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, d8c65984-a438-4678-9453-bf8f747fce0e, ghrun-n7olz6xni4.auto.internal:3598): response = { <_MultiThreadedRendezvous object> }
2025-11-25 14:48:58,033 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NTVkYThmZDktNzk3NThmYi1mMTMyYjE1LWE4Mzg2NWMx
2025-11-25 14:48:58,033 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NTVkYThmZDktNzk3NThmYi1mMTMyYjE1LWE4Mzg2NWMx
2025-11-25 14:48:58,034 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, f0bbe1f7-c729-4e23-97ec-004ed27fe071, ghrun-n7olz6xni4.auto.internal:3598): creating call state
2025-11-25 14:48:58,034 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, f0bbe1f7-c729-4e23-97ec-004ed27fe071, ghrun-n7olz6xni4.auto.internal:3598): request = { session_id: "ydb://session/3?node_id=1&id=NTVkYThmZDktNzk3NThmYi1mMTMyYjE1LWE4Mzg2NWMx" 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 14:48:58,035 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, f0bbe1f7-c729-4e23-97ec-004ed27fe071, ghrun-n7olz6xni4.auto.internal:3598): response = { <_MultiThreadedRendezvous object> }
2025-11-25 14:48:58,051 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NzFlMGJkMDEtZWNhMzk3ZGQtNTgxNzliZTctODc1NmZiNDI=
2025-11-25 14:48:58,086 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NzFlMGJkMDEtZWNhMzk3ZGQtNTgxNzliZTctODc1NmZiNDI=
2025-11-25 14:48:58,091 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 7d8f477d-3c24-4dd7-9bac-95385751ba0a, ghrun-n7olz6xni4.auto.internal:3598): creating call state
2025-11-25 14:48:58,099 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 7d8f477d-3c24-4dd7-9bac-95385751ba0a, ghrun-n7olz6xni4.auto.internal:3598): request = { session_id: "ydb://session/3?node_id=1&id=NzFlMGJkMDEtZWNhMzk3ZGQtNTgxNzliZTctODc1NmZiNDI=" 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 14:48:58,100 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 7d8f477d-3c24-4dd7-9bac-95385751ba0a, ghrun-n7olz6xni4.auto.internal:3598): response = { <_MultiThreadedRendezvous object> }
2025-11-25 14:48:58,116 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NjEwNDA3NzctZjk0MjU1MWMtMTQxYjhlYTgtMTEwZDk4NA==
2025-11-25 14:48:58,125 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NjEwNDA3NzctZjk0MjU1MWMtMTQxYjhlYTgtMTEwZDk4NA==
2025-11-25 14:48:58,169 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, e0e24a9c-451c-4973-af03-c5b016557b33, ghrun-n7olz6xni4.auto.internal:3598): creating call state
2025-11-25 14:48:58,170 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, e0e24a9c-451c-4973-af03-c5b016557b33, ghrun-n7olz6xni4.auto.internal:3598): request = { session_id: "ydb://session/3?node_id=1&id=NjEwNDA3NzctZjk0MjU1MWMtMTQxYjhlYTgtMTEwZDk4NA==" 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 14:48:58,189 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, e0e24a9c-451c-4973-af03-c5b016557b33, ghrun-n7olz6xni4.auto.internal:3598): response = { <_MultiThreadedRendezvous object> }
2025-11-25 14:49:00,355 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MTVhZTVmMGItMTBjNmU2MDItNDljOGJlMmQtNTY4NmZkNjA=
2025-11-25 14:49:00,357 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MTVhZTVmMGItMTBjNmU2MDItNDljOGJlMmQtNTY4NmZkNjA=
2025-11-25 14:49:00,372 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 0c0d4d3e-72d0-47fb-bae8-923fd532eb07, ghrun-n7olz6xni4.auto.internal:3598): creating call state
2025-11-25 14:49:00,373 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 0c0d4d3e-72d0-47fb-bae8-923fd532eb07, ghrun-n7olz6xni4.auto.internal:3598): request = { session_id: "ydb://session/3?node_id=1&id=MTVhZTVmMGItMTBjNmU2MDItNDljOGJlMmQtNTY4NmZkNjA=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(8)" } stats_mode: STATS_MODE_NONE }
2025-11-25 14:49:00,374 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 0c0d4d3e-72d0-47fb-bae8-923fd532eb07, ghrun-n7olz6xni4.auto.internal:3598): response = { <_MultiThreadedRendezvous object> }
2025-11-25 14:49:01,122 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MjJhOGMyZmItZjM4ODEzY2YtMjU4ZTMzOTktM2I0OTU4ZmM=
2025-11-25 14:49:01,126 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MjJhOGMyZmItZjM4ODEzY2YtMjU4ZTMzOTktM2I0OTU4ZmM=
2025-11-25 14:49:01,127 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, b5f7990b-4936-4d80-b64e-8223eba98c7a, ghrun-n7olz6xni4.auto.internal:3598): creating call state
2025-11-25 14:49:01,127 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, b5f7990b-4936-4d80-b64e-8223eba98c7a, ghrun-n7olz6xni4.auto.internal:3598): request = { session_id: "ydb://session/3?node_id=1&id=MjJhOGMyZmItZjM4ODEzY2YtMjU4ZTMzOTktM2I0OTU4ZmM=" 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-25 14:49:01,138 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=OGQxZjJlODgtOTU4ODNhZTAtNzIyY2QwYS04NzZiYTU2MA==
2025-11-25 14:49:01,153 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OGQxZjJlODgtOTU4ODNhZTAtNzIyY2QwYS04NzZiYTU2MA==
2025-11-25 14:49:01,155 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, b5f7990b-4936-4d80-b64e-8223eba98c7a, ghrun-n7olz6xni4.auto.internal:3598): response = { <_MultiThreadedRendezvous object> }
2025-11-25 14:49:01,214 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, da9c917b-de11-4a04-9608-389cb95a41de, ghrun-n7olz6xni4.auto.internal:3598): creating call state
2025-11-25 14:49:01,238 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, da9c917b-de11-4a04-9608-389cb95a41de, ghrun-n7olz6xni4.auto.internal:3598): request = { session_id: "ydb://session/3?node_id=1&id=OGQxZjJlODgtOTU4ODNhZTAtNzIyY2QwYS04NzZiYTU2MA==" 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-25 14:49:01,239 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, da9c917b-de11-4a04-9608-389cb95a41de, ghrun-n7olz6xni4.auto.internal:3598): response = { <_MultiThreadedRendezvous object> }
2025-11-25 14:49:01,835 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MjJhOGMyZmItZjM4ODEzY2YtMjU4ZTMzOTktM2I0OTU4ZmM=
2025-11-25 14:49:01,836 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MjJhOGMyZmItZjM4ODEzY2YtMjU4ZTMzOTktM2I0OTU4ZmM=
2025-11-25 14:49:01,836 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 8ca7b999-0a0b-47d6-ade0-29969e92dab3, ghrun-n7olz6xni4.auto.internal:3598): creating call state
2025-11-25 14:49:01,837 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 8ca7b999-0a0b-47d6-ade0-29969e92dab3, ghrun-n7olz6xni4.auto.internal:3598): request = { session_id: "ydb://session/3?node_id=1&id=MjJhOGMyZmItZjM4ODEzY2YtMjU4ZTMzOTktM2I0OTU4ZmM=" 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-25 14:49:01,838 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 8ca7b999-0a0b-47d6-ade0-29969e92dab3, ghrun-n7olz6xni4.auto.internal:3598): response = { <_MultiThreadedRendezvous object> }
2025-11-25 14:49:02,092 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MTVhZTVmMGItMTBjNmU2MDItNDljOGJlMmQtNTY4NmZkNjA=
2025-11-25 14:49:02,119 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MTVhZTVmMGItMTBjNmU2MDItNDljOGJlMmQtNTY4NmZkNjA=
2025-11-25 14:49:02,121 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 96d402a5-d63f-4aa0-aa18-80872ce54c02, ghrun-n7olz6xni4.auto.internal:3598): creating call state
2025-11-25 14:49:02,143 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 96d402a5-d63f-4aa0-aa18-80872ce54c02, ghrun-n7olz6xni4.auto.internal:3598): request = { session_id: "ydb://session/3?node_id=1&id=MTVhZTVmMGItMTBjNmU2MDItNDljOGJlMmQtNTY4NmZkNjA=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(9)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(8))" } stats_mode: STATS_MODE_NONE }
2025-11-25 14:49:02,146 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 96d402a5-d63f-4aa0-aa18-80872ce54c02, ghrun-n7olz6xni4.auto.internal:3598): response = { <_MultiThreadedRendezvous object> }
2025-11-25 14:49:03,093 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=OGQxZjJlODgtOTU4ODNhZTAtNzIyY2QwYS04NzZiYTU2MA==
2025-11-25 14:49:03,175 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OGQxZjJlODgtOTU4ODNhZTAtNzIyY2QwYS04NzZiYTU2MA==
2025-11-25 14:49:03,175 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 293e5e7b-0671-4251-b977-ed3b94c30c03, ghrun-n7olz6xni4.auto.internal:3598): creating call state
2025-11-25 14:49:03,176 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 293e5e7b-0671-4251-b977-ed3b94c30c03, ghrun-n7olz6xni4.auto.internal:3598): request = { session_id: "ydb://session/3?node_id=1&id=OGQxZjJlODgtOTU4ODNhZTAtNzIyY2QwYS04NzZiYTU2MA==" 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-25 14:49:03,185 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 293e5e7b-0671-4251-b977-ed3b94c30c03, ghrun-n7olz6xni4.auto.internal:3598): response = { <_MultiThreadedRendezvous object> }
2025-11-25 14:49:03,195 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MTVhZTVmMGItMTBjNmU2MDItNDljOGJlMmQtNTY4NmZkNjA=
2025-11-25 14:49:03,727 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZDBjODU1NmMtMmZmYzE2NDAtNDhmMTk3YS1lNDJhMzJiYg==
2025-11-25 14:49:03,736 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MTVhZTVmMGItMTBjNmU2MDItNDljOGJlMmQtNTY4NmZkNjA=
2025-11-25 14:49:03,783 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NTVkYThmZDktNzk3NThmYi1mMTMyYjE1LWE4Mzg2NWMx
2025-11-25 14:49:03,795 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, e8769c51-c6d9-4111-80a9-f70df5cfd314, ghrun-n7olz6xni4.auto.internal:3598): creating call state
2025-11-25 14:49:03,913 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, e8769c51-c6d9-4111-80a9-f70df5cfd314, ghrun-n7olz6xni4.auto.internal:3598): request = { session_id: "ydb://session/3?node_id=1&id=MTVhZTVmMGItMTBjNmU2MDItNDljOGJlMmQtNTY4NmZkNjA=" 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 14:49:03,917 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, e8769c51-c6d9-4111-80a9-f70df5cfd314, ghrun-n7olz6xni4.auto.internal:3598): response = { <_MultiThreadedRendezvous object> }
2025-11-25 14:49:03,915 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=OGQxZjJlODgtOTU4ODNhZTAtNzIyY2QwYS04NzZiYTU2MA==
2025-11-25 14:49:03,822 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZDBjODU1NmMtMmZmYzE2NDAtNDhmMTk3YS1lNDJhMzJiYg==
2025-11-25 14:49:03,966 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 78b13a6f-18c2-4b1b-97d9-d01ae1b8391d, ghrun-n7olz6xni4.auto.internal:3598): creating call state
2025-11-25 14:49:03,967 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 78b13a6f-18c2-4b1b-97d9-d01ae1b8391d, ghrun-n7olz6xni4.auto.internal:3598): request = { session_id: "ydb://session/3?node_id=1&id=ZDBjODU1NmMtMmZmYzE2NDAtNDhmMTk3YS1lNDJhMzJiYg==" 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 14:49:03,969 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 78b13a6f-18c2-4b1b-97d9-d01ae1b8391d, ghrun-n7olz6xni4.auto.internal:3598): response = { <_MultiThreadedRendezvous object> }
2025-11-25 14:49:06,183 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MjJhOGMyZmItZjM4ODEzY2YtMjU4ZTMzOTktM2I0OTU4ZmM=
2025-11-25 14:49:06,721 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NzFlMGJkMDEtZWNhMzk3ZGQtNTgxNzliZTctODc1NmZiNDI=
2025-11-25 14:49:06,724 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MTVhZTVmMGItMTBjNmU2MDItNDljOGJlMmQtNTY4NmZkNjA=
2025-11-25 14:49:06,770 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NTVkYThmZDktNzk3NThmYi1mMTMyYjE1LWE4Mzg2NWMx
2025-11-25 14:49:06,770 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, b8a0cf0d-4fc4-434f-aa78-0e2c99b333cc, ghrun-n7olz6xni4.auto.internal:3598): creating call state
2025-11-25 14:49:06,772 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZDBjODU1NmMtMmZmYzE2NDAtNDhmMTk3YS1lNDJhMzJiYg==
2025-11-25 14:49:06,779 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OGQxZjJlODgtOTU4ODNhZTAtNzIyY2QwYS04NzZiYTU2MA==
2025-11-25 14:49:06,791 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, b8a0cf0d-4fc4-434f-aa78-0e2c99b333cc, ghrun-n7olz6xni4.auto.internal:3598): request = { session_id: "ydb://session/3?node_id=1&id=NTVkYThmZDktNzk3NThmYi1mMTMyYjE1LWE4Mzg2NWMx" 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 14:49:06,806 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, b8a0cf0d-4fc4-434f-aa78-0e2c99b333cc, ghrun-n7olz6xni4.auto.internal:3598): response = { <_MultiThreadedRendezvous object> }
2025-11-25 14:49:06,800 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MjJhOGMyZmItZjM4ODEzY2YtMjU4ZTMzOTktM2I0OTU4ZmM=
2025-11-25 14:49:06,817 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, e28e0369-087a-4a94-a717-fa6e85dc94ec, ghrun-n7olz6xni4.auto.internal:3598): creating call state
2025-11-25 14:49:06,844 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, e28e0369-087a-4a94-a717-fa6e85dc94ec, ghrun-n7olz6xni4.auto.internal:3598): request = { session_id: "ydb://session/3?node_id=1&id=MjJhOGMyZmItZjM4ODEzY2YtMjU4ZTMzOTktM2I0OTU4ZmM=" 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 14:49:06,798 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, c03f46f6-8797-4ded-bfdf-5c5ee0bee393, ghrun-n7olz6xni4.auto.internal:3598): creating call state
2025-11-25 14:49:06,849 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, e28e0369-087a-4a94-a717-fa6e85dc94ec, ghrun-n7olz6xni4.auto.internal:3598): response = { <_MultiThreadedRendezvous object> }
2025-11-25 14:49:06,927 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, c03f46f6-8797-4ded-bfdf-5c5ee0bee393, ghrun-n7olz6xni4.auto.internal:3598): request = { session_id: "ydb://session/3?node_id=1&id=OGQxZjJlODgtOTU4ODNhZTAtNzIyY2QwYS04NzZiYTU2MA==" 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 14:49:07,023 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, c03f46f6-8797-4ded-bfdf-5c5ee0bee393, ghrun-n7olz6xni4.auto.internal:3598): response = { <_MultiThreadedRendezvous object> }
2025-11-25 14:49:09,081 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MjJhOGMyZmItZjM4ODEzY2YtMjU4ZTMzOTktM2I0OTU4ZmM=
2025-11-25 14:49:09,111 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NzFhYThlNmQtNTJkZmNjNGQtNjJlZTEyY2EtZDkzMjgyYzU=
2025-11-25 14:49:09,140 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NzFlMGJkMDEtZWNhMzk3ZGQtNTgxNzliZTctODc1NmZiNDI=
2025-11-25 14:49:09,142 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 85cca2e1-b2ce-4fde-96c0-2437402fd250, ghrun-n7olz6xni4.auto.internal:3598): creating call state
2025-11-25 14:49:09,142 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 85cca2e1-b2ce-4fde-96c0-2437402fd250, ghrun-n7olz6xni4.auto.internal:3598): request = { session_id: "ydb://session/3?node_id=1&id=NzFlMGJkMDEtZWNhMzk3ZGQtNTgxNzliZTctODc1NmZiNDI=" 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-25 14:49:09,143 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 85cca2e1-b2ce-4fde-96c0-2437402fd250, ghrun-n7olz6xni4.auto.internal:3598): response = { <_MultiThreadedRendezvous object> }
2025-11-25 14:49:09,141 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NTVkYThmZDktNzk3NThmYi1mMTMyYjE1LWE4Mzg2NWMx
2025-11-25 14:49:09,163 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MzljNGQ3YTUtOTljZjJhNzYtNWIxODZjYjAtZTRjMjllOTA=
2025-11-25 14:49:09,196 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MTVhZTVmMGItMTBjNmU2MDItNDljOGJlMmQtNTY4NmZkNjA=
2025-11-25 14:49:09,216 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 00ae5073-1280-467a-81ed-3a2b388dd9b2, ghrun-n7olz6xni4.auto.internal:3598): creating call state
2025-11-25 14:49:09,224 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 00ae5073-1280-467a-81ed-3a2b388dd9b2, ghrun-n7olz6xni4.auto.internal:3598): request = { session_id: "ydb://session/3?node_id=1&id=MTVhZTVmMGItMTBjNmU2MDItNDljOGJlMmQtNTY4NmZkNjA=" 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 14:49:09,235 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 00ae5073-1280-467a-81ed-3a2b388dd9b2, ghrun-n7olz6xni4.auto.internal:3598): response = { <_MultiThreadedRendezvous object> }
2025-11-25 14:49:09,232 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YzFiZWI2NDktOWYxZjRmYzYtYWU3NjNjLTFhZDZmMTk1
2025-11-25 14:49:09,346 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZDBjODU1NmMtMmZmYzE2NDAtNDhmMTk3YS1lNDJhMzJiYg==
2025-11-25 14:49:09,353 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 82f12a52-9742-465e-9c40-0c2972579f0f, ghrun-n7olz6xni4.auto.internal:3598): creating call state
2025-11-25 14:49:09,356 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 82f12a52-9742-465e-9c40-0c2972579f0f, ghrun-n7olz6xni4.auto.internal:3598): request = { session_id: "ydb://session/3?node_id=1&id=ZDBjODU1NmMtMmZmYzE2NDAtNDhmMTk3YS1lNDJhMzJiYg==" 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-25 14:49:09,361 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 82f12a52-9742-465e-9c40-0c2972579f0f, ghrun-n7olz6xni4.auto.internal:3598): response = { <_MultiThreadedRendezvous object> }
2025-11-25 14:49:09,408 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NjEwNDA3NzctZjk0MjU1MWMtMTQxYjhlYTgtMTEwZDk4NA==
2025-11-25 14:49:09,460 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MjJhOGMyZmItZjM4ODEzY2YtMjU4ZTMzOTktM2I0OTU4ZmM=
2025-11-25 14:49:09,472 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 18932004-eecf-48f6-8ae5-d03dfc37a4c2, ghrun-n7olz6xni4.auto.internal:3598): creating call state
2025-11-25 14:49:09,475 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 18932004-eecf-48f6-8ae5-d03dfc37a4c2, ghrun-n7olz6xni4.auto.internal:3598): request = { session_id: "ydb://session/3?node_id=1&id=MjJhOGMyZmItZjM4ODEzY2YtMjU4ZTMzOTktM2I0OTU4ZmM=" 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 14:49:09,494 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 18932004-eecf-48f6-8ae5-d03dfc37a4c2, ghrun-n7olz6xni4.auto.internal:3598): response = { <_MultiThreadedRendezvous object> }
2025-11-25 14:49:09,948 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=OGQxZjJlODgtOTU4ODNhZTAtNzIyY2QwYS04NzZiYTU2MA==
2025-11-25 14:49:09,958 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NzFhYThlNmQtNTJkZmNjNGQtNjJlZTEyY2EtZDkzMjgyYzU=
2025-11-25 14:49:09,958 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, ac0406b3-3e47-45f4-8e95-e8ae56ec2ed6, ghrun-n7olz6xni4.auto.internal:3598): creating call state
2025-11-25 14:49:09,959 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, ac0406b3-3e47-45f4-8e95-e8ae56ec2ed6, ghrun-n7olz6xni4.auto.internal:3598): request = { session_id: "ydb://session/3?node_id=1&id=NzFhYThlNmQtNTJkZmNjNGQtNjJlZTEyY2EtZDkzMjgyYzU=" 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 14:49:09,959 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, ac0406b3-3e47-45f4-8e95-e8ae56ec2ed6, ghrun-n7olz6xni4.auto.internal:3598): response = { <_MultiThreadedRendezvous object> }
2025-11-25 14:49:13,816 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NzFhYThlNmQtNTJkZmNjNGQtNjJlZTEyY2EtZDkzMjgyYzU=
2025-11-25 14:49:13,975 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MTVhZTVmMGItMTBjNmU2MDItNDljOGJlMmQtNTY4NmZkNjA=
2025-11-25 14:49:13,975 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NTVkYThmZDktNzk3NThmYi1mMTMyYjE1LWE4Mzg2NWMx
2025-11-25 14:49:13,976 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 87dec7a8-7156-494f-b89b-e8f3f7ab6923, ghrun-n7olz6xni4.auto.internal:3598): creating call state
2025-11-25 14:49:13,976 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 87dec7a8-7156-494f-b89b-e8f3f7ab6923, ghrun-n7olz6xni4.auto.internal:3598): request = { session_id: "ydb://session/3?node_id=1&id=NTVkYThmZDktNzk3NThmYi1mMTMyYjE1LWE4Mzg2NWMx" 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 14:49:13,985 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 87dec7a8-7156-494f-b89b-e8f3f7ab6923, ghrun-n7olz6xni4.auto.internal:3598): response = { <_MultiThreadedRendezvous object> }
2025-11-25 14:49:14,272 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZDBjODU1NmMtMmZmYzE2NDAtNDhmMTk3YS1lNDJhMzJiYg==
2025-11-25 14:49:14,272 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MzljNGQ3YTUtOTljZjJhNzYtNWIxODZjYjAtZTRjMjllOTA=
2025-11-25 14:49:14,273 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 29364ca1-b709-4ea6-90fd-ff9fd355b37b, ghrun-n7olz6xni4.auto.internal:3598): creating call state
2025-11-25 14:49:14,273 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 29364ca1-b709-4ea6-90fd-ff9fd355b37b, ghrun-n7olz6xni4.auto.internal:3598): request = { session_id: "ydb://session/3?node_id=1&id=MzljNGQ3YTUtOTljZjJhNzYtNWIxODZjYjAtZTRjMjllOTA=" 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-25 14:49:14,274 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 29364ca1-b709-4ea6-90fd-ff9fd355b37b, ghrun-n7olz6xni4.auto.internal:3598): response = { <_MultiThreadedRendezvous object> }
2025-11-25 14:49:14,350 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NzFlMGJkMDEtZWNhMzk3ZGQtNTgxNzliZTctODc1NmZiNDI=
2025-11-25 14:49:14,370 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YzFiZWI2NDktOWYxZjRmYzYtYWU3NjNjLTFhZDZmMTk1
2025-11-25 14:49:14,371 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 16d32d03-b611-4c7a-a535-ece44967e22c, ghrun-n7olz6xni4.auto.internal:3598): creating call state
2025-11-25 14:49:14,380 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 16d32d03-b611-4c7a-a535-ece44967e22c, ghrun-n7olz6xni4.auto.internal:3598): request = { session_id: "ydb://session/3?node_id=1&id=YzFiZWI2NDktOWYxZjRmYzYtYWU3NjNjLTFhZDZmMTk1" 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-25 14:49:14,422 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MjJhOGMyZmItZjM4ODEzY2YtMjU4ZTMzOTktM2I0OTU4ZmM=
2025-11-25 14:49:14,425 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NTVkYThmZDktNzk3NThmYi1mMTMyYjE1LWE4Mzg2NWMx
2025-11-25 14:49:14,431 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NjEwNDA3NzctZjk0MjU1MWMtMTQxYjhlYTgtMTEwZDk4NA==
2025-11-25 14:49:14,430 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 16d32d03-b611-4c7a-a535-ece44967e22c, ghrun-n7olz6xni4.auto.internal:3598): response = { <_MultiThreadedRendezvous object> }
2025-11-25 14:49:14,475 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, e89b22bd-1440-4823-86a2-333e88fa307a, ghrun-n7olz6xni4.auto.internal:3598): creating call state
2025-11-25 14:49:14,495 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, e89b22bd-1440-4823-86a2-333e88fa307a, ghrun-n7olz6xni4.auto.internal:3598): request = { session_id: "ydb://session/3?node_id=1&id=NjEwNDA3NzctZjk0MjU1MWMtMTQxYjhlYTgtMTEwZDk4NA==" 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 14:49:14,507 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, e89b22bd-1440-4823-86a2-333e88fa307a, ghrun-n7olz6xni4.auto.internal:3598): response = { <_MultiThreadedRendezvous object> }
2025-11-25 14:49:16,411 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YzFiZWI2NDktOWYxZjRmYzYtYWU3NjNjLTFhZDZmMTk1
2025-11-25 14:49:16,433 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MzljNGQ3YTUtOTljZjJhNzYtNWIxODZjYjAtZTRjMjllOTA=
2025-11-25 14:49:16,456 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NjEwNDA3NzctZjk0MjU1MWMtMTQxYjhlYTgtMTEwZDk4NA==
2025-11-25 14:49:16,485 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OGQxZjJlODgtOTU4ODNhZTAtNzIyY2QwYS04NzZiYTU2MA==
2025-11-25 14:49:16,490 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, cb69dc75-687f-4035-b9a0-f9d39a19212f, ghrun-n7olz6xni4.auto.internal:3598): creating call state
2025-11-25 14:49:16,498 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, cb69dc75-687f-4035-b9a0-f9d39a19212f, ghrun-n7olz6xni4.auto.internal:3598): request = { session_id: "ydb://session/3?node_id=1&id=OGQxZjJlODgtOTU4ODNhZTAtNzIyY2QwYS04NzZiYTU2MA==" 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 14:49:16,518 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, cb69dc75-687f-4035-b9a0-f9d39a19212f, ghrun-n7olz6xni4.auto.internal:3598): response = { <_MultiThreadedRendezvous object> }
2025-11-25 14:49:17,538 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=OGQxZjJlODgtOTU4ODNhZTAtNzIyY2QwYS04NzZiYTU2MA==
2025-11-25 14:49:17,563 - INFO - root - test_log_deviation: check insert: 20000 15000
2025-11-25 14:49:17,581 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.10
2025-11-25 14:49:17,606 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.10
2025-11-25 14:49:17,607 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/g0y6/0007d0/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:3598', '-d', '/Root', 'workload', 'log', '--path', 'log', 'clean']' in 'None' (waiting)
2025-11-25 14:49:17,661 - DEBUG - ya.test - execute: Command pid: 3716552
2025-11-25 14:49:17,962 - DEBUG - ya.test - _save_outputs: Command (pid 3716552) rc: 0
2025-11-25 14:49:17,962 - DEBUG - ya.test - _save_outputs: Command (pid 3716552) elapsed time (sec): 0.29128289222717285
2025-11-25 14:49:17,963 - DEBUG - ya.test - _save_outputs: Command (pid 3716552) idrss: 0
2025-11-25 14:49:17,963 - DEBUG - ya.test - _save_outputs: Command (pid 3716552) inblock: 0
2025-11-25 14:49:17,963 - DEBUG - ya.test - _save_outputs: Command (pid 3716552) isrss: 0
2025-11-25 14:49:17,969 - DEBUG - ya.test - _save_outputs: Command (pid 3716552) ixrss: 0
2025-11-25 14:49:17,970 - DEBUG - ya.test - _save_outputs: Command (pid 3716552) majflt: 0
2025-11-25 14:49:18,009 - DEBUG - ya.test - _save_outputs: Command (pid 3716552) maxrss: 531328
2025-11-25 14:49:18,010 - DEBUG - ya.test - _save_outputs: Command (pid 3716552) minflt: 3483
2025-11-25 14:49:18,010 - DEBUG - ya.test - _save_outputs: Command (pid 3716552) msgrcv: 0
2025-11-25 14:49:18,010 - DEBUG - ya.test - _save_outputs: Command (pid 3716552) msgsnd: 0
2025-11-25 14:49:18,010 - DEBUG - ya.test - _save_outputs: Command (pid 3716552) nivcsw: 44
2025-11-25 14:49:18,010 - DEBUG - ya.test - _save_outputs: Command (pid 3716552) nsignals: 0
2025-11-25 14:49:18,011 - DEBUG - ya.test - _save_outputs: Command (pid 3716552) nswap: 0
2025-11-25 14:49:18,051 - DEBUG - ya.test - _save_outputs: Command (pid 3716552) nvcsw: 136
2025-11-25 14:49:18,051 - DEBUG - ya.test - _save_outputs: Command (pid 3716552) oublock: 8
2025-11-25 14:49:18,053 - DEBUG - ya.test - _save_outputs: Command (pid 3716552) stime: 0.038895
2025-11-25 14:49:18,053 - DEBUG - ya.test - _save_outputs: Command (pid 3716552) utime: 0.042156
2025-11-25 14:49:18,053 - DEBUG - ya.test - _save_outputs: Command (pid 3716552) wtime: 0.296
2025-11-25 14:49:18,063 - DEBUG - ya.test - _save_outputs: Command (pid 3716552) output:
Remove path log...
Remove path log...Ok

2025-11-25 14:49:18,064 - DEBUG - ya.test - _save_outputs: Command (pid 3716552) errors:

2025-11-25 14:49:18,084 - INFO - ya.test - pytest_runtest_teardown: Test teardown
