2025-11-11 15:39:08,120 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-11-11 15:39:08,120 - INFO - ya.test - pytest_runtest_setup: test_log_deviation[180]
2025-11-11 15:39:08,120 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-11-11 15:39:08,121 - INFO - ya.test - pytest_runtest_setup: Test setup
2025-11-11 15:39:08,122 - INFO - ya.test - pytest_runtest_call: Test call (class_name: test_log_scenario.py::TestLogScenario, test_name: test_log_deviation[180])
2025-11-11 15:39:08,123 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/iofl/001ef6/ydb/apps/ydb/ydb
2025-11-11 15:39:08,123 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/iofl/001ef6/ydb/apps/ydb/ydb -e grpc://localhost:22586 -d /Root workload log --path log init --path log --store column --ttl 1000 with wait = True
2025-11-11 15:39:08,124 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.5
2025-11-11 15:39:08,130 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.5
2025-11-11 15:39:08,137 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/iofl/001ef6/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:22586', '-d', '/Root', 'workload', 'log', '--path', 'log', 'init', '--path', 'log', '--store', 'column', '--ttl', '1000']' in 'None' (waiting)
2025-11-11 15:39:08,162 - DEBUG - ya.test - execute: Command pid: 892528
2025-11-11 15:39:09,587 - DEBUG - ya.test - _save_outputs: Command (pid 892528) rc: 0
2025-11-11 15:39:09,587 - DEBUG - ya.test - _save_outputs: Command (pid 892528) elapsed time (sec): 1.4235939979553223
2025-11-11 15:39:09,587 - DEBUG - ya.test - _save_outputs: Command (pid 892528) idrss: 0
2025-11-11 15:39:09,588 - DEBUG - ya.test - _save_outputs: Command (pid 892528) inblock: 0
2025-11-11 15:39:09,588 - DEBUG - ya.test - _save_outputs: Command (pid 892528) isrss: 0
2025-11-11 15:39:09,588 - DEBUG - ya.test - _save_outputs: Command (pid 892528) ixrss: 0
2025-11-11 15:39:09,588 - DEBUG - ya.test - _save_outputs: Command (pid 892528) majflt: 0
2025-11-11 15:39:09,588 - DEBUG - ya.test - _save_outputs: Command (pid 892528) maxrss: 474620
2025-11-11 15:39:09,588 - DEBUG - ya.test - _save_outputs: Command (pid 892528) minflt: 3539
2025-11-11 15:39:09,589 - DEBUG - ya.test - _save_outputs: Command (pid 892528) msgrcv: 0
2025-11-11 15:39:09,589 - DEBUG - ya.test - _save_outputs: Command (pid 892528) msgsnd: 0
2025-11-11 15:39:09,589 - DEBUG - ya.test - _save_outputs: Command (pid 892528) nivcsw: 37
2025-11-11 15:39:09,589 - DEBUG - ya.test - _save_outputs: Command (pid 892528) nsignals: 0
2025-11-11 15:39:09,589 - DEBUG - ya.test - _save_outputs: Command (pid 892528) nswap: 0
2025-11-11 15:39:09,589 - DEBUG - ya.test - _save_outputs: Command (pid 892528) nvcsw: 116
2025-11-11 15:39:09,590 - DEBUG - ya.test - _save_outputs: Command (pid 892528) oublock: 8
2025-11-11 15:39:09,590 - DEBUG - ya.test - _save_outputs: Command (pid 892528) stime: 0.018463999999999998
2025-11-11 15:39:09,590 - DEBUG - ya.test - _save_outputs: Command (pid 892528) utime: 0.07016399999999999
2025-11-11 15:39:09,590 - DEBUG - ya.test - _save_outputs: Command (pid 892528) wtime: 1.449
2025-11-11 15:39:09,590 - DEBUG - ya.test - _save_outputs: Command (pid 892528) output:
Init tables ...
Init tables ...Ok

2025-11-11 15:39:09,591 - DEBUG - ya.test - _save_outputs: Command (pid 892528) errors:

2025-11-11 15:39:09,591 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MjM3MzUwYTAtNjlhNTdhY2YtZWVkOTkxYWYtZmU5MDBkYzY=
2025-11-11 15:39:09,593 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, d0631d2a-4e5d-40bc-af35-e8bde87ae43e, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:09,594 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, d0631d2a-4e5d-40bc-af35-e8bde87ae43e, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=MjM3MzUwYTAtNjlhNTdhY2YtZWVkOTkxYWYtZmU5MDBkYzY=" 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-11 15:39:09,595 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, d0631d2a-4e5d-40bc-af35-e8bde87ae43e, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:09,686 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MjM3MzUwYTAtNjlhNTdhY2YtZWVkOTkxYWYtZmU5MDBkYzY=
2025-11-11 15:39:09,686 - INFO - root - _insert_rows: YdbWorkloadLog bulk_upsert
2025-11-11 15:39:09,686 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/iofl/001ef6/ydb/apps/ydb/ydb -e grpc://localhost:22586 -d /Root workload log --path log run bulk_upsert --seconds 3 --threads 10 --rows 500 --timestamp_deviation 180 with wait = True
2025-11-11 15:39:09,687 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.6
2025-11-11 15:39:09,688 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.6
2025-11-11 15:39:09,688 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/iofl/001ef6/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:22586', '-d', '/Root', 'workload', 'log', '--path', 'log', 'run', 'bulk_upsert', '--seconds', '3', '--threads', '10', '--rows', '500', '--timestamp_deviation', '180']' in 'None' (waiting)
2025-11-11 15:39:09,708 - DEBUG - ya.test - execute: Command pid: 893378
2025-11-11 15:39:10,315 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-11-11 15:39:10,316 - DEBUG - ydb.connection - channel_factory: Channel options: [('grpc.max_receive_message_length', 64000000), ('grpc.max_send_message_length', 64000000), ('grpc.primary_user_agent', 'python-library'), ('grpc.lb_policy_name', 'round_robin'), ('grpc.keepalive_time_ms', 1250), ('grpc.keepalive_timeout_ms', 10000), ('grpc.http2.max_pings_without_data', 0), ('grpc.keepalive_permit_without_calls', 0)]
2025-11-11 15:39:10,368 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database /Root
2025-11-11 15:39:10,368 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, f0e79223-b9f9-4403-b497-526cd8f84b36, localhost:7821): creating call state
2025-11-11 15:39:10,369 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, f0e79223-b9f9-4403-b497-526cd8f84b36, localhost:7821): request = { database: "/Root" }
2025-11-11 15:39:10,372 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, f0e79223-b9f9-4403-b497-526cd8f84b36, localhost:7821): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Discovery.ListEndpointsResult] { endpoints { address: "ghrun-3ynj4chmly.auto.internal" port: 7821 service: "legacy" service: "tablet_service" service: "yql" service: "discovery" service: "cms" service: "locking" service: "kesus" service: "pq" service: "pqcd" service: "pqv1" service: "topic" service: "datastreams" service: "scripting" service: "clickhouse_internal" service: "rate_limiter" service: "analytics" service: "export" service: "import" service: "yq" service: "keyvalue" service: "monitoring" service: "auth" service: "query_service" service: "view" location: "1" node_id: 1 } self_location: "1" } } } }
2025-11-11 15:39:10,372 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Resolved endpoints for database /Root: DiscoveryResult <self_location: 1, endpoints [<Endpoint ghrun-3ynj4chmly.auto.internal:7821, location 1, ssl: False>]>
2025-11-11 15:39:10,372 - DEBUG - ydb.connection - close: Closing channel for endpoint localhost:7821
2025-11-11 15:39:14,619 - DEBUG - ya.test - _wait: Process resource usage is not available as process finished before wait4 was called
2025-11-11 15:39:14,620 - DEBUG - ya.test - _save_outputs: Command (pid 893378) rc: 0
2025-11-11 15:39:14,620 - DEBUG - ya.test - _save_outputs: Command (pid 893378) elapsed time (sec): 4.909458875656128
2025-11-11 15:39:14,620 - DEBUG - ya.test - _save_outputs: Command (pid 893378) wtime: 4.932
2025-11-11 15:39:14,620 - DEBUG - ya.test - _save_outputs: Command (pid 893378) 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	      2	2	0	0	1639	1655	1655	1655
3	     18	18	0	0	2031	2207	2239	2239

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

2025-11-11 15:39:14,620 - DEBUG - ya.test - _save_outputs: Command (pid 893378) errors:

2025-11-11 15:39:14,621 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZDQ4ZjdmNzctOTMxMGM2ZWEtOWM0ZGFhMTYtODI3YzYxNzM=
2025-11-11 15:39:14,621 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, a758c41e-2ce0-49b5-a93e-00017534b9c0, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:14,622 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, a758c41e-2ce0-49b5-a93e-00017534b9c0, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=ZDQ4ZjdmNzctOTMxMGM2ZWEtOWM0ZGFhMTYtODI3YzYxNzM=" 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-11 15:39:14,622 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, a758c41e-2ce0-49b5-a93e-00017534b9c0, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:16,363 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZDQ4ZjdmNzctOTMxMGM2ZWEtOWM0ZGFhMTYtODI3YzYxNzM=
2025-11-11 15:39:16,364 - INFO - root - test_log_deviation: Count rows after insert 10000 before wait
2025-11-11 15:39:16,364 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OTMwMmMwNTEtNDBlYzEwYzQtNGQ0Y2YxYzYtOTNjYTVjZWI=
2025-11-11 15:39:16,364 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 46b0f490-f147-46d0-9c11-f81137f4fcd5, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:16,370 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 46b0f490-f147-46d0-9c11-f81137f4fcd5, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=OTMwMmMwNTEtNDBlYzEwYzQtNGQ0Y2YxYzYtOTNjYTVjZWI=" 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-11 15:39:16,380 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 46b0f490-f147-46d0-9c11-f81137f4fcd5, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:16,696 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=OTMwMmMwNTEtNDBlYzEwYzQtNGQ0Y2YxYzYtOTNjYTVjZWI=
2025-11-11 15:39:16,696 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ODc3YmViZjAtZWJmYzcwNTItZTMyZTE4NzItMzNkYWRkYjI=
2025-11-11 15:39:16,697 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, eb9dd399-fa6c-4f16-9246-8d7a427cef85, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:16,697 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, eb9dd399-fa6c-4f16-9246-8d7a427cef85, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=ODc3YmViZjAtZWJmYzcwNTItZTMyZTE4NzItMzNkYWRkYjI=" 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-11 15:39:16,698 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, eb9dd399-fa6c-4f16-9246-8d7a427cef85, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:16,891 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ODc3YmViZjAtZWJmYzcwNTItZTMyZTE4NzItMzNkYWRkYjI=
2025-11-11 15:39:16,910 - INFO - root - _insert_rows: YdbWorkloadLog bulk_upsert
2025-11-11 15:39:16,910 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/iofl/001ef6/ydb/apps/ydb/ydb -e grpc://localhost:22586 -d /Root workload log --path log run bulk_upsert --seconds 3 --threads 10 --rows 500 --timestamp_deviation 180 with wait = True
2025-11-11 15:39:16,911 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.7
2025-11-11 15:39:16,912 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.7
2025-11-11 15:39:16,912 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/iofl/001ef6/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:22586', '-d', '/Root', 'workload', 'log', '--path', 'log', 'run', 'bulk_upsert', '--seconds', '3', '--threads', '10', '--rows', '500', '--timestamp_deviation', '180']' in 'None' (waiting)
2025-11-11 15:39:16,931 - DEBUG - ya.test - execute: Command pid: 897515
2025-11-11 15:39:16,948 - INFO - root - _insert_rows: YdbWorkloadLog insert
2025-11-11 15:39:16,949 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/iofl/001ef6/ydb/apps/ydb/ydb -e grpc://localhost:22586 -d /Root workload log --path log run insert --seconds 3 --threads 10 --rows 500 --timestamp_deviation 180 with wait = True
2025-11-11 15:39:16,950 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.8
2025-11-11 15:39:16,950 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.8
2025-11-11 15:39:16,950 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/iofl/001ef6/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:22586', '-d', '/Root', 'workload', 'log', '--path', 'log', 'run', 'insert', '--seconds', '3', '--threads', '10', '--rows', '500', '--timestamp_deviation', '180']' in 'None' (waiting)
2025-11-11 15:39:16,962 - DEBUG - ya.test - execute: Command pid: 897524
2025-11-11 15:39:16,971 - INFO - root - _insert_rows: YdbWorkloadLog upsert
2025-11-11 15:39:16,972 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/iofl/001ef6/ydb/apps/ydb/ydb -e grpc://localhost:22586 -d /Root workload log --path log run upsert --seconds 3 --threads 10 --rows 500 --timestamp_deviation 180 with wait = True
2025-11-11 15:39:16,973 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.9
2025-11-11 15:39:16,973 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.9
2025-11-11 15:39:16,974 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/iofl/001ef6/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:22586', '-d', '/Root', 'workload', 'log', '--path', 'log', 'run', 'upsert', '--seconds', '3', '--threads', '10', '--rows', '500', '--timestamp_deviation', '180']' in 'None' (waiting)
2025-11-11 15:39:16,995 - DEBUG - ya.test - execute: Command pid: 897540
2025-11-11 15:39:17,008 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZmJkM2E0YWItYzU5YWM2MmUtYzUzYjJlNTYtM2ZiYmY2MzA=
2025-11-11 15:39:17,008 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 450e4e41-e2f6-41b6-b47c-ca4b08fb5b63, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:17,009 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 450e4e41-e2f6-41b6-b47c-ca4b08fb5b63, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=ZmJkM2E0YWItYzU5YWM2MmUtYzUzYjJlNTYtM2ZiYmY2MzA=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-11 15:39:17,010 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 450e4e41-e2f6-41b6-b47c-ca4b08fb5b63, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:17,024 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NjM5MjdhMGYtY2NlYmE1MDctOWM3MjI3NGEtOWMzMDVjZTA=
2025-11-11 15:39:17,024 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, c28ff160-9f1c-4244-a68c-353cdb8b9b8e, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:17,025 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, c28ff160-9f1c-4244-a68c-353cdb8b9b8e, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=NjM5MjdhMGYtY2NlYmE1MDctOWM3MjI3NGEtOWMzMDVjZTA=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-11 15:39:17,026 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, c28ff160-9f1c-4244-a68c-353cdb8b9b8e, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:17,027 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZWQ4MzM4YmQtOTAyZmI2NmItYzFiZTNmODUtZDVmNTVjZTI=
2025-11-11 15:39:17,028 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 571a7e75-a920-4e34-af85-05516b6f5b21, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:17,028 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 571a7e75-a920-4e34-af85-05516b6f5b21, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=ZWQ4MzM4YmQtOTAyZmI2NmItYzFiZTNmODUtZDVmNTVjZTI=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-11 15:39:17,029 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 571a7e75-a920-4e34-af85-05516b6f5b21, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:17,039 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWY3MjIxNzEtYmMxOTc5YTYtMmExNTJlMGMtMzcxNzRlYmM=
2025-11-11 15:39:17,040 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, b4857ff9-80cd-40f9-b5cf-a1c5266831ee, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:17,041 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, b4857ff9-80cd-40f9-b5cf-a1c5266831ee, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=OWY3MjIxNzEtYmMxOTc5YTYtMmExNTJlMGMtMzcxNzRlYmM=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-11 15:39:17,043 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, b4857ff9-80cd-40f9-b5cf-a1c5266831ee, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:17,057 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YmNjYjZkMWItMjJkNTUwN2YtYTU4ZjgwNmUtY2E2YjZlNzU=
2025-11-11 15:39:17,058 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, df039e05-f32b-47c2-bbb5-a30cd7fb5d2e, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:17,059 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, df039e05-f32b-47c2-bbb5-a30cd7fb5d2e, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=YmNjYjZkMWItMjJkNTUwN2YtYTU4ZjgwNmUtY2E2YjZlNzU=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-11 15:39:17,060 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, df039e05-f32b-47c2-bbb5-a30cd7fb5d2e, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:17,067 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YjJkNTI5YWEtNWE5ZjdlNTQtZjIzMjNmOGMtNWUwZWVhZjk=
2025-11-11 15:39:17,073 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, b4b758ec-63f5-4e4a-a945-265179e8bf93, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:17,074 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, b4b758ec-63f5-4e4a-a945-265179e8bf93, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=YjJkNTI5YWEtNWE5ZjdlNTQtZjIzMjNmOGMtNWUwZWVhZjk=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-11 15:39:17,074 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, b4b758ec-63f5-4e4a-a945-265179e8bf93, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:17,084 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MjM3MzUwYTAtNjlhNTdhY2YtZWVkOTkxYWYtZmU5MDBkYzY=
2025-11-11 15:39:17,084 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 98d465fa-e671-4624-b59a-33e503d92ade, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:17,085 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 98d465fa-e671-4624-b59a-33e503d92ade, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=MjM3MzUwYTAtNjlhNTdhY2YtZWVkOTkxYWYtZmU5MDBkYzY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-11 15:39:17,086 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 98d465fa-e671-4624-b59a-33e503d92ade, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:17,100 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZDQ4ZjdmNzctOTMxMGM2ZWEtOWM0ZGFhMTYtODI3YzYxNzM=
2025-11-11 15:39:17,100 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 7c294efb-5726-4ee3-b6c0-39037ca0fb19, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:17,101 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 7c294efb-5726-4ee3-b6c0-39037ca0fb19, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=ZDQ4ZjdmNzctOTMxMGM2ZWEtOWM0ZGFhMTYtODI3YzYxNzM=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-11 15:39:17,102 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 7c294efb-5726-4ee3-b6c0-39037ca0fb19, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:17,118 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OTMwMmMwNTEtNDBlYzEwYzQtNGQ0Y2YxYzYtOTNjYTVjZWI=
2025-11-11 15:39:17,119 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, d0f66dde-a622-4a0a-9d43-12ff3b049655, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:17,119 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, d0f66dde-a622-4a0a-9d43-12ff3b049655, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=OTMwMmMwNTEtNDBlYzEwYzQtNGQ0Y2YxYzYtOTNjYTVjZWI=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-11 15:39:17,120 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, d0f66dde-a622-4a0a-9d43-12ff3b049655, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:17,126 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ODc3YmViZjAtZWJmYzcwNTItZTMyZTE4NzItMzNkYWRkYjI=
2025-11-11 15:39:17,127 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, f7481ea1-53df-41e9-b082-0a9a9840d756, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:17,127 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, f7481ea1-53df-41e9-b082-0a9a9840d756, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=ODc3YmViZjAtZWJmYzcwNTItZTMyZTE4NzItMzNkYWRkYjI=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-11 15:39:17,128 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, f7481ea1-53df-41e9-b082-0a9a9840d756, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:21,747 - DEBUG - ya.test - _wait: Process resource usage is not available as process finished before wait4 was called
2025-11-11 15:39:21,748 - DEBUG - ya.test - _save_outputs: Command (pid 897524) rc: 0
2025-11-11 15:39:21,748 - DEBUG - ya.test - _save_outputs: Command (pid 897524) elapsed time (sec): 4.785318374633789
2025-11-11 15:39:21,748 - DEBUG - ya.test - _save_outputs: Command (pid 897524) wtime: 4.797
2025-11-11 15:39:21,749 - DEBUG - ya.test - _save_outputs: Command (pid 897524) 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-11 15:39:21,749 - DEBUG - ya.test - _save_outputs: Command (pid 897524) errors:

2025-11-11 15:39:21,883 - DEBUG - ya.test - _wait: Process resource usage is not available as process finished before wait4 was called
2025-11-11 15:39:21,920 - DEBUG - ya.test - _save_outputs: Command (pid 897540) rc: 0
2025-11-11 15:39:21,920 - DEBUG - ya.test - _save_outputs: Command (pid 897540) elapsed time (sec): 4.923931121826172
2025-11-11 15:39:21,920 - DEBUG - ya.test - _save_outputs: Command (pid 897540) wtime: 4.946
2025-11-11 15:39:21,921 - DEBUG - ya.test - _save_outputs: Command (pid 897540) 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	7	0	0	0	0
3	      0	0	0	13	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-11 15:39:21,921 - DEBUG - ya.test - _save_outputs: Command (pid 897540) errors:

2025-11-11 15:39:25,136 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=OTMwMmMwNTEtNDBlYzEwYzQtNGQ0Y2YxYzYtOTNjYTVjZWI=
2025-11-11 15:39:25,137 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OTMwMmMwNTEtNDBlYzEwYzQtNGQ0Y2YxYzYtOTNjYTVjZWI=
2025-11-11 15:39:25,137 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 48e75538-6b8f-481b-84aa-a506eea7a7ac, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:25,138 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 48e75538-6b8f-481b-84aa-a506eea7a7ac, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=OTMwMmMwNTEtNDBlYzEwYzQtNGQ0Y2YxYzYtOTNjYTVjZWI=" 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-11 15:39:25,138 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 48e75538-6b8f-481b-84aa-a506eea7a7ac, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:25,139 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZmJkM2E0YWItYzU5YWM2MmUtYzUzYjJlNTYtM2ZiYmY2MzA=
2025-11-11 15:39:25,140 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZmJkM2E0YWItYzU5YWM2MmUtYzUzYjJlNTYtM2ZiYmY2MzA=
2025-11-11 15:39:25,140 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, ae23d2a9-fe19-4249-a89a-6a6d2915bc42, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:25,141 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, ae23d2a9-fe19-4249-a89a-6a6d2915bc42, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=ZmJkM2E0YWItYzU5YWM2MmUtYzUzYjJlNTYtM2ZiYmY2MzA=" 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-11 15:39:25,142 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, ae23d2a9-fe19-4249-a89a-6a6d2915bc42, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:25,148 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NjM5MjdhMGYtY2NlYmE1MDctOWM3MjI3NGEtOWMzMDVjZTA=
2025-11-11 15:39:25,149 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NjM5MjdhMGYtY2NlYmE1MDctOWM3MjI3NGEtOWMzMDVjZTA=
2025-11-11 15:39:25,149 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 12c3d5eb-3eab-440c-96ed-1a403eafcdac, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:25,149 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 12c3d5eb-3eab-440c-96ed-1a403eafcdac, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=NjM5MjdhMGYtY2NlYmE1MDctOWM3MjI3NGEtOWMzMDVjZTA=" 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-11 15:39:25,150 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 12c3d5eb-3eab-440c-96ed-1a403eafcdac, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:25,217 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZWQ4MzM4YmQtOTAyZmI2NmItYzFiZTNmODUtZDVmNTVjZTI=
2025-11-11 15:39:25,218 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZWQ4MzM4YmQtOTAyZmI2NmItYzFiZTNmODUtZDVmNTVjZTI=
2025-11-11 15:39:25,218 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 04c93202-71a8-48d4-8cb1-700d477cbc18, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:25,219 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 04c93202-71a8-48d4-8cb1-700d477cbc18, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=ZWQ4MzM4YmQtOTAyZmI2NmItYzFiZTNmODUtZDVmNTVjZTI=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(2)" } stats_mode: STATS_MODE_NONE }
2025-11-11 15:39:25,219 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 04c93202-71a8-48d4-8cb1-700d477cbc18, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:25,223 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZDQ4ZjdmNzctOTMxMGM2ZWEtOWM0ZGFhMTYtODI3YzYxNzM=
2025-11-11 15:39:25,224 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZDQ4ZjdmNzctOTMxMGM2ZWEtOWM0ZGFhMTYtODI3YzYxNzM=
2025-11-11 15:39:25,224 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 147eb0e6-62b0-4476-8c2f-0fb92f3d10e1, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:25,225 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 147eb0e6-62b0-4476-8c2f-0fb92f3d10e1, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=ZDQ4ZjdmNzctOTMxMGM2ZWEtOWM0ZGFhMTYtODI3YzYxNzM=" 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-11 15:39:25,225 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 147eb0e6-62b0-4476-8c2f-0fb92f3d10e1, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:25,332 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YmNjYjZkMWItMjJkNTUwN2YtYTU4ZjgwNmUtY2E2YjZlNzU=
2025-11-11 15:39:25,333 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YmNjYjZkMWItMjJkNTUwN2YtYTU4ZjgwNmUtY2E2YjZlNzU=
2025-11-11 15:39:25,333 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, c53369df-a40e-46ce-8681-b0f43923b1e9, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:25,334 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, c53369df-a40e-46ce-8681-b0f43923b1e9, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=YmNjYjZkMWItMjJkNTUwN2YtYTU4ZjgwNmUtY2E2YjZlNzU=" 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-11 15:39:25,335 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, c53369df-a40e-46ce-8681-b0f43923b1e9, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:25,335 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MjM3MzUwYTAtNjlhNTdhY2YtZWVkOTkxYWYtZmU5MDBkYzY=
2025-11-11 15:39:25,336 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MjM3MzUwYTAtNjlhNTdhY2YtZWVkOTkxYWYtZmU5MDBkYzY=
2025-11-11 15:39:25,336 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, c142e87c-3e68-47b9-a98b-92f41db7c97e, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:25,336 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, c142e87c-3e68-47b9-a98b-92f41db7c97e, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=MjM3MzUwYTAtNjlhNTdhY2YtZWVkOTkxYWYtZmU5MDBkYzY=" 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-11 15:39:25,337 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, c142e87c-3e68-47b9-a98b-92f41db7c97e, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:25,356 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YjJkNTI5YWEtNWE5ZjdlNTQtZjIzMjNmOGMtNWUwZWVhZjk=
2025-11-11 15:39:25,357 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YjJkNTI5YWEtNWE5ZjdlNTQtZjIzMjNmOGMtNWUwZWVhZjk=
2025-11-11 15:39:25,357 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, f2208e7e-2d57-45f1-aff8-e6338a9d7451, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:25,357 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, f2208e7e-2d57-45f1-aff8-e6338a9d7451, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=YjJkNTI5YWEtNWE5ZjdlNTQtZjIzMjNmOGMtNWUwZWVhZjk=" 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-11 15:39:25,358 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, f2208e7e-2d57-45f1-aff8-e6338a9d7451, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:25,377 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ODc3YmViZjAtZWJmYzcwNTItZTMyZTE4NzItMzNkYWRkYjI=
2025-11-11 15:39:25,377 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ODc3YmViZjAtZWJmYzcwNTItZTMyZTE4NzItMzNkYWRkYjI=
2025-11-11 15:39:25,378 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 25be2154-e58c-4024-91d5-048ed5adf319, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:25,378 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 25be2154-e58c-4024-91d5-048ed5adf319, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=ODc3YmViZjAtZWJmYzcwNTItZTMyZTE4NzItMzNkYWRkYjI=" 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-11 15:39:25,379 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 25be2154-e58c-4024-91d5-048ed5adf319, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:25,379 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=OWY3MjIxNzEtYmMxOTc5YTYtMmExNTJlMGMtMzcxNzRlYmM=
2025-11-11 15:39:25,380 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWY3MjIxNzEtYmMxOTc5YTYtMmExNTJlMGMtMzcxNzRlYmM=
2025-11-11 15:39:25,380 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 9c796708-a430-4872-a55d-173cfc4288e2, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:25,380 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 9c796708-a430-4872-a55d-173cfc4288e2, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=OWY3MjIxNzEtYmMxOTc5YTYtMmExNTJlMGMtMzcxNzRlYmM=" 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-11 15:39:25,381 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 9c796708-a430-4872-a55d-173cfc4288e2, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:25,414 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-11-11 15:39:25,415 - DEBUG - ydb.connection - channel_factory: Channel options: [('grpc.max_receive_message_length', 64000000), ('grpc.max_send_message_length', 64000000), ('grpc.primary_user_agent', 'python-library'), ('grpc.lb_policy_name', 'round_robin'), ('grpc.keepalive_time_ms', 1250), ('grpc.keepalive_timeout_ms', 10000), ('grpc.http2.max_pings_without_data', 0), ('grpc.keepalive_permit_without_calls', 0)]
2025-11-11 15:39:25,468 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database /Root
2025-11-11 15:39:25,468 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, 33291683-c709-4596-bdbe-fb06040c6a69, localhost:3243): creating call state
2025-11-11 15:39:25,469 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, 33291683-c709-4596-bdbe-fb06040c6a69, localhost:3243): request = { database: "/Root" }
2025-11-11 15:39:25,476 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, 33291683-c709-4596-bdbe-fb06040c6a69, localhost:3243): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Discovery.ListEndpointsResult] { endpoints { address: "ghrun-3ynj4chmly.auto.internal" port: 3243 service: "legacy" service: "tablet_service" service: "yql" service: "discovery" service: "cms" service: "locking" service: "kesus" service: "pq" service: "pqcd" service: "pqv1" service: "topic" service: "datastreams" service: "scripting" service: "clickhouse_internal" service: "rate_limiter" service: "analytics" service: "export" service: "import" service: "yq" service: "keyvalue" service: "monitoring" service: "auth" service: "query_service" service: "view" location: "1" node_id: 1 } self_location: "1" } } } }
2025-11-11 15:39:25,477 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Resolved endpoints for database /Root: DiscoveryResult <self_location: 1, endpoints [<Endpoint ghrun-3ynj4chmly.auto.internal:3243, location 1, ssl: False>]>
2025-11-11 15:39:25,477 - DEBUG - ydb.connection - close: Closing channel for endpoint localhost:3243
2025-11-11 15:39:29,520 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MjM3MzUwYTAtNjlhNTdhY2YtZWVkOTkxYWYtZmU5MDBkYzY=
2025-11-11 15:39:29,521 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MjM3MzUwYTAtNjlhNTdhY2YtZWVkOTkxYWYtZmU5MDBkYzY=
2025-11-11 15:39:29,521 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 9f4fe2c6-7b11-452d-9a40-d939ac000ada, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:29,522 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 9f4fe2c6-7b11-452d-9a40-d939ac000ada, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=MjM3MzUwYTAtNjlhNTdhY2YtZWVkOTkxYWYtZmU5MDBkYzY=" 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-11 15:39:29,523 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 9f4fe2c6-7b11-452d-9a40-d939ac000ada, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:29,577 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=OTMwMmMwNTEtNDBlYzEwYzQtNGQ0Y2YxYzYtOTNjYTVjZWI=
2025-11-11 15:39:29,578 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OTMwMmMwNTEtNDBlYzEwYzQtNGQ0Y2YxYzYtOTNjYTVjZWI=
2025-11-11 15:39:29,578 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 3c85a273-36fe-442a-a2b7-fa4689df4081, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:29,579 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 3c85a273-36fe-442a-a2b7-fa4689df4081, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=OTMwMmMwNTEtNDBlYzEwYzQtNGQ0Y2YxYzYtOTNjYTVjZWI=" 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-11 15:39:29,580 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 3c85a273-36fe-442a-a2b7-fa4689df4081, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:35,394 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YmNjYjZkMWItMjJkNTUwN2YtYTU4ZjgwNmUtY2E2YjZlNzU=
2025-11-11 15:39:35,395 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YmNjYjZkMWItMjJkNTUwN2YtYTU4ZjgwNmUtY2E2YjZlNzU=
2025-11-11 15:39:35,396 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, c03fe9a8-2bb2-4a73-9a93-612e218bb3be, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:35,396 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, c03fe9a8-2bb2-4a73-9a93-612e218bb3be, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=YmNjYjZkMWItMjJkNTUwN2YtYTU4ZjgwNmUtY2E2YjZlNzU=" 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-11 15:39:35,397 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, c03fe9a8-2bb2-4a73-9a93-612e218bb3be, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:35,534 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ODc3YmViZjAtZWJmYzcwNTItZTMyZTE4NzItMzNkYWRkYjI=
2025-11-11 15:39:35,535 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ODc3YmViZjAtZWJmYzcwNTItZTMyZTE4NzItMzNkYWRkYjI=
2025-11-11 15:39:35,536 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, f6cc3092-d6bf-4f39-8f3a-b320b1074403, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:35,536 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, f6cc3092-d6bf-4f39-8f3a-b320b1074403, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=ODc3YmViZjAtZWJmYzcwNTItZTMyZTE4NzItMzNkYWRkYjI=" 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-11 15:39:35,537 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, f6cc3092-d6bf-4f39-8f3a-b320b1074403, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:35,620 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZmJkM2E0YWItYzU5YWM2MmUtYzUzYjJlNTYtM2ZiYmY2MzA=
2025-11-11 15:39:35,627 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZmJkM2E0YWItYzU5YWM2MmUtYzUzYjJlNTYtM2ZiYmY2MzA=
2025-11-11 15:39:35,635 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, acf27fc0-8f4a-4bd0-83a7-460ddd2a212c, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:35,636 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, acf27fc0-8f4a-4bd0-83a7-460ddd2a212c, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=ZmJkM2E0YWItYzU5YWM2MmUtYzUzYjJlNTYtM2ZiYmY2MzA=" 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-11 15:39:35,637 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, acf27fc0-8f4a-4bd0-83a7-460ddd2a212c, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:36,092 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=OTMwMmMwNTEtNDBlYzEwYzQtNGQ0Y2YxYzYtOTNjYTVjZWI=
2025-11-11 15:39:36,093 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OTMwMmMwNTEtNDBlYzEwYzQtNGQ0Y2YxYzYtOTNjYTVjZWI=
2025-11-11 15:39:36,093 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 0ff18e1c-09d0-4a30-9521-c8584929019f, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:36,094 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 0ff18e1c-09d0-4a30-9521-c8584929019f, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=OTMwMmMwNTEtNDBlYzEwYzQtNGQ0Y2YxYzYtOTNjYTVjZWI=" 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-11 15:39:36,094 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 0ff18e1c-09d0-4a30-9521-c8584929019f, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:36,579 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MjM3MzUwYTAtNjlhNTdhY2YtZWVkOTkxYWYtZmU5MDBkYzY=
2025-11-11 15:39:36,580 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MjM3MzUwYTAtNjlhNTdhY2YtZWVkOTkxYWYtZmU5MDBkYzY=
2025-11-11 15:39:36,580 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 469c0c5c-30fe-4278-9612-3baf6b9dfda9, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:36,581 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 469c0c5c-30fe-4278-9612-3baf6b9dfda9, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=MjM3MzUwYTAtNjlhNTdhY2YtZWVkOTkxYWYtZmU5MDBkYzY=" 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-11 15:39:36,582 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 469c0c5c-30fe-4278-9612-3baf6b9dfda9, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:36,785 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZDQ4ZjdmNzctOTMxMGM2ZWEtOWM0ZGFhMTYtODI3YzYxNzM=
2025-11-11 15:39:36,849 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZWQ4MzM4YmQtOTAyZmI2NmItYzFiZTNmODUtZDVmNTVjZTI=
2025-11-11 15:39:36,908 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NjM5MjdhMGYtY2NlYmE1MDctOWM3MjI3NGEtOWMzMDVjZTA=
2025-11-11 15:39:36,933 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZDQ4ZjdmNzctOTMxMGM2ZWEtOWM0ZGFhMTYtODI3YzYxNzM=
2025-11-11 15:39:36,933 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 4b387a7b-2314-45d3-9cc0-4ef34d038534, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:36,934 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 4b387a7b-2314-45d3-9cc0-4ef34d038534, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=ZDQ4ZjdmNzctOTMxMGM2ZWEtOWM0ZGFhMTYtODI3YzYxNzM=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(2)" } stats_mode: STATS_MODE_NONE }
2025-11-11 15:39:36,935 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 4b387a7b-2314-45d3-9cc0-4ef34d038534, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:36,935 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZWQ4MzM4YmQtOTAyZmI2NmItYzFiZTNmODUtZDVmNTVjZTI=
2025-11-11 15:39:36,947 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 5edfc0fd-929d-48f0-8396-d385c25c5574, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:36,948 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 5edfc0fd-929d-48f0-8396-d385c25c5574, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=ZWQ4MzM4YmQtOTAyZmI2NmItYzFiZTNmODUtZDVmNTVjZTI=" 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-11 15:39:36,949 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 5edfc0fd-929d-48f0-8396-d385c25c5574, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:36,951 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NjM5MjdhMGYtY2NlYmE1MDctOWM3MjI3NGEtOWMzMDVjZTA=
2025-11-11 15:39:36,951 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 206aea49-059b-41e1-8c1c-72e84156a751, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:36,952 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 206aea49-059b-41e1-8c1c-72e84156a751, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=NjM5MjdhMGYtY2NlYmE1MDctOWM3MjI3NGEtOWMzMDVjZTA=" 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-11 15:39:36,952 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 206aea49-059b-41e1-8c1c-72e84156a751, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:36,955 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=OWY3MjIxNzEtYmMxOTc5YTYtMmExNTJlMGMtMzcxNzRlYmM=
2025-11-11 15:39:36,957 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWY3MjIxNzEtYmMxOTc5YTYtMmExNTJlMGMtMzcxNzRlYmM=
2025-11-11 15:39:36,958 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 03d8003d-f885-4988-9537-4e6d9c47a922, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:36,958 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 03d8003d-f885-4988-9537-4e6d9c47a922, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=OWY3MjIxNzEtYmMxOTc5YTYtMmExNTJlMGMtMzcxNzRlYmM=" 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-11 15:39:36,959 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 03d8003d-f885-4988-9537-4e6d9c47a922, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:36,960 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YjJkNTI5YWEtNWE5ZjdlNTQtZjIzMjNmOGMtNWUwZWVhZjk=
2025-11-11 15:39:36,963 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YjJkNTI5YWEtNWE5ZjdlNTQtZjIzMjNmOGMtNWUwZWVhZjk=
2025-11-11 15:39:36,963 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 49955992-2ab0-4bb0-bbd9-1bff60150672, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:36,964 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 49955992-2ab0-4bb0-bbd9-1bff60150672, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=YjJkNTI5YWEtNWE5ZjdlNTQtZjIzMjNmOGMtNWUwZWVhZjk=" 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-11 15:39:36,965 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 49955992-2ab0-4bb0-bbd9-1bff60150672, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:38,275 - DEBUG - ya.test - _wait: Process resource usage is not available as process finished before wait4 was called
2025-11-11 15:39:38,275 - DEBUG - ya.test - _save_outputs: Command (pid 897515) rc: 0
2025-11-11 15:39:38,276 - DEBUG - ya.test - _save_outputs: Command (pid 897515) elapsed time (sec): 21.34316325187683
2025-11-11 15:39:38,276 - DEBUG - ya.test - _save_outputs: Command (pid 897515) wtime: 21.363
2025-11-11 15:39:38,276 - DEBUG - ya.test - _save_outputs: Command (pid 897515) 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	      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	10	0	0	0	0

2025-11-11 15:39:38,276 - DEBUG - ya.test - _save_outputs: Command (pid 897515) errors:

2025-11-11 15:39:40,053 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ODc3YmViZjAtZWJmYzcwNTItZTMyZTE4NzItMzNkYWRkYjI=
2025-11-11 15:39:40,053 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ODc3YmViZjAtZWJmYzcwNTItZTMyZTE4NzItMzNkYWRkYjI=
2025-11-11 15:39:40,054 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, ef9c0d1a-5c57-4551-93c6-8f4bbdf94a70, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:40,054 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, ef9c0d1a-5c57-4551-93c6-8f4bbdf94a70, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=ODc3YmViZjAtZWJmYzcwNTItZTMyZTE4NzItMzNkYWRkYjI=" 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-11 15:39:40,055 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, ef9c0d1a-5c57-4551-93c6-8f4bbdf94a70, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:40,079 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YmNjYjZkMWItMjJkNTUwN2YtYTU4ZjgwNmUtY2E2YjZlNzU=
2025-11-11 15:39:40,080 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YmNjYjZkMWItMjJkNTUwN2YtYTU4ZjgwNmUtY2E2YjZlNzU=
2025-11-11 15:39:40,080 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, a81287c4-4cf7-4d7f-a2cd-e83062a52384, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:40,081 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, a81287c4-4cf7-4d7f-a2cd-e83062a52384, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=YmNjYjZkMWItMjJkNTUwN2YtYTU4ZjgwNmUtY2E2YjZlNzU=" 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-11 15:39:40,082 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, a81287c4-4cf7-4d7f-a2cd-e83062a52384, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:40,492 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MjM3MzUwYTAtNjlhNTdhY2YtZWVkOTkxYWYtZmU5MDBkYzY=
2025-11-11 15:39:40,622 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=OTMwMmMwNTEtNDBlYzEwYzQtNGQ0Y2YxYzYtOTNjYTVjZWI=
2025-11-11 15:39:42,875 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZmJkM2E0YWItYzU5YWM2MmUtYzUzYjJlNTYtM2ZiYmY2MzA=
2025-11-11 15:39:42,876 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MjM3MzUwYTAtNjlhNTdhY2YtZWVkOTkxYWYtZmU5MDBkYzY=
2025-11-11 15:39:42,877 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 83360ce4-3248-4876-8630-927980576eaa, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:42,877 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 83360ce4-3248-4876-8630-927980576eaa, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=MjM3MzUwYTAtNjlhNTdhY2YtZWVkOTkxYWYtZmU5MDBkYzY=" 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-11 15:39:42,878 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 83360ce4-3248-4876-8630-927980576eaa, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:43,923 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=OWY3MjIxNzEtYmMxOTc5YTYtMmExNTJlMGMtMzcxNzRlYmM=
2025-11-11 15:39:43,924 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OTMwMmMwNTEtNDBlYzEwYzQtNGQ0Y2YxYzYtOTNjYTVjZWI=
2025-11-11 15:39:43,924 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, cccbdb52-1f63-41dd-8cb9-c534d6632024, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:43,925 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, cccbdb52-1f63-41dd-8cb9-c534d6632024, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=OTMwMmMwNTEtNDBlYzEwYzQtNGQ0Y2YxYzYtOTNjYTVjZWI=" 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-11 15:39:43,926 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, cccbdb52-1f63-41dd-8cb9-c534d6632024, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:44,012 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YjJkNTI5YWEtNWE5ZjdlNTQtZjIzMjNmOGMtNWUwZWVhZjk=
2025-11-11 15:39:44,013 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZmJkM2E0YWItYzU5YWM2MmUtYzUzYjJlNTYtM2ZiYmY2MzA=
2025-11-11 15:39:44,013 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, e2dfd61e-55f3-40e5-bf9a-5981ea636e55, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:44,014 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, e2dfd61e-55f3-40e5-bf9a-5981ea636e55, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=ZmJkM2E0YWItYzU5YWM2MmUtYzUzYjJlNTYtM2ZiYmY2MzA=" 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-11 15:39:44,014 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, e2dfd61e-55f3-40e5-bf9a-5981ea636e55, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:44,172 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZDQ4ZjdmNzctOTMxMGM2ZWEtOWM0ZGFhMTYtODI3YzYxNzM=
2025-11-11 15:39:44,173 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWY3MjIxNzEtYmMxOTc5YTYtMmExNTJlMGMtMzcxNzRlYmM=
2025-11-11 15:39:44,173 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, ca7c08a7-f54a-458a-9e86-30a57128e4ad, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:44,174 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, ca7c08a7-f54a-458a-9e86-30a57128e4ad, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=OWY3MjIxNzEtYmMxOTc5YTYtMmExNTJlMGMtMzcxNzRlYmM=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(3)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(2))" } stats_mode: STATS_MODE_NONE }
2025-11-11 15:39:44,174 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, ca7c08a7-f54a-458a-9e86-30a57128e4ad, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:44,257 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ODc3YmViZjAtZWJmYzcwNTItZTMyZTE4NzItMzNkYWRkYjI=
2025-11-11 15:39:44,259 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NjM5MjdhMGYtY2NlYmE1MDctOWM3MjI3NGEtOWMzMDVjZTA=
2025-11-11 15:39:44,260 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YjJkNTI5YWEtNWE5ZjdlNTQtZjIzMjNmOGMtNWUwZWVhZjk=
2025-11-11 15:39:44,260 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 1ca4be1b-8b38-415c-8dd0-5f768d48b437, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:44,261 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 1ca4be1b-8b38-415c-8dd0-5f768d48b437, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=YjJkNTI5YWEtNWE5ZjdlNTQtZjIzMjNmOGMtNWUwZWVhZjk=" 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-11 15:39:44,261 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 1ca4be1b-8b38-415c-8dd0-5f768d48b437, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:44,346 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YmNjYjZkMWItMjJkNTUwN2YtYTU4ZjgwNmUtY2E2YjZlNzU=
2025-11-11 15:39:44,366 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZWQ4MzM4YmQtOTAyZmI2NmItYzFiZTNmODUtZDVmNTVjZTI=
2025-11-11 15:39:44,366 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZDQ4ZjdmNzctOTMxMGM2ZWEtOWM0ZGFhMTYtODI3YzYxNzM=
2025-11-11 15:39:44,367 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 610a489a-bf3a-4fd9-855e-74903a0bbcb5, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:44,367 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 610a489a-bf3a-4fd9-855e-74903a0bbcb5, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=ZDQ4ZjdmNzctOTMxMGM2ZWEtOWM0ZGFhMTYtODI3YzYxNzM=" 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-11 15:39:44,368 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 610a489a-bf3a-4fd9-855e-74903a0bbcb5, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:46,945 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=OTMwMmMwNTEtNDBlYzEwYzQtNGQ0Y2YxYzYtOTNjYTVjZWI=
2025-11-11 15:39:47,219 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MjM3MzUwYTAtNjlhNTdhY2YtZWVkOTkxYWYtZmU5MDBkYzY=
2025-11-11 15:39:47,312 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZmJkM2E0YWItYzU5YWM2MmUtYzUzYjJlNTYtM2ZiYmY2MzA=
2025-11-11 15:39:47,333 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=OWY3MjIxNzEtYmMxOTc5YTYtMmExNTJlMGMtMzcxNzRlYmM=
2025-11-11 15:39:47,359 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZDQ4ZjdmNzctOTMxMGM2ZWEtOWM0ZGFhMTYtODI3YzYxNzM=
2025-11-11 15:39:47,371 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YjJkNTI5YWEtNWE5ZjdlNTQtZjIzMjNmOGMtNWUwZWVhZjk=
2025-11-11 15:39:47,372 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ODc3YmViZjAtZWJmYzcwNTItZTMyZTE4NzItMzNkYWRkYjI=
2025-11-11 15:39:47,373 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 44d4efca-73cd-4754-8016-e0cbf4972251, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:47,374 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 44d4efca-73cd-4754-8016-e0cbf4972251, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=ODc3YmViZjAtZWJmYzcwNTItZTMyZTE4NzItMzNkYWRkYjI=" 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-11 15:39:47,374 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 44d4efca-73cd-4754-8016-e0cbf4972251, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:47,832 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ODc3YmViZjAtZWJmYzcwNTItZTMyZTE4NzItMzNkYWRkYjI=
2025-11-11 15:39:47,832 - INFO - root - test_log_deviation: check insert: 10008 10000
2025-11-11 15:39:47,833 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.10
2025-11-11 15:39:47,834 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.10
2025-11-11 15:39:47,834 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/iofl/001ef6/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:22586', '-d', '/Root', 'workload', 'log', '--path', 'log', 'clean']' in 'None' (waiting)
2025-11-11 15:39:47,854 - DEBUG - ya.test - execute: Command pid: 915504
2025-11-11 15:39:48,497 - DEBUG - ya.test - _save_outputs: Command (pid 915504) rc: 0
2025-11-11 15:39:48,498 - DEBUG - ya.test - _save_outputs: Command (pid 915504) elapsed time (sec): 0.6426804065704346
2025-11-11 15:39:48,498 - DEBUG - ya.test - _save_outputs: Command (pid 915504) idrss: 0
2025-11-11 15:39:48,498 - DEBUG - ya.test - _save_outputs: Command (pid 915504) inblock: 0
2025-11-11 15:39:48,498 - DEBUG - ya.test - _save_outputs: Command (pid 915504) isrss: 0
2025-11-11 15:39:48,499 - DEBUG - ya.test - _save_outputs: Command (pid 915504) ixrss: 0
2025-11-11 15:39:48,499 - DEBUG - ya.test - _save_outputs: Command (pid 915504) majflt: 0
2025-11-11 15:39:48,499 - DEBUG - ya.test - _save_outputs: Command (pid 915504) maxrss: 474620
2025-11-11 15:39:48,499 - DEBUG - ya.test - _save_outputs: Command (pid 915504) minflt: 3537
2025-11-11 15:39:48,499 - DEBUG - ya.test - _save_outputs: Command (pid 915504) msgrcv: 0
2025-11-11 15:39:48,499 - DEBUG - ya.test - _save_outputs: Command (pid 915504) msgsnd: 0
2025-11-11 15:39:48,500 - DEBUG - ya.test - _save_outputs: Command (pid 915504) nivcsw: 61
2025-11-11 15:39:48,500 - DEBUG - ya.test - _save_outputs: Command (pid 915504) nsignals: 0
2025-11-11 15:39:48,500 - DEBUG - ya.test - _save_outputs: Command (pid 915504) nswap: 0
2025-11-11 15:39:48,500 - DEBUG - ya.test - _save_outputs: Command (pid 915504) nvcsw: 120
2025-11-11 15:39:48,500 - DEBUG - ya.test - _save_outputs: Command (pid 915504) oublock: 8
2025-11-11 15:39:48,500 - DEBUG - ya.test - _save_outputs: Command (pid 915504) stime: 0.008343
2025-11-11 15:39:48,500 - DEBUG - ya.test - _save_outputs: Command (pid 915504) utime: 0.079265
2025-11-11 15:39:48,501 - DEBUG - ya.test - _save_outputs: Command (pid 915504) wtime: 0.663
2025-11-11 15:39:48,501 - DEBUG - ya.test - _save_outputs: Command (pid 915504) output:
Remove path log...
Remove path log...Ok

2025-11-11 15:39:48,501 - DEBUG - ya.test - _save_outputs: Command (pid 915504) errors:

2025-11-11 15:39:48,503 - INFO - ya.test - pytest_runtest_teardown: Test teardown
2025-11-11 15:39:48,512 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, 794f79c2-1b8e-49fd-ab3b-5cea01720cb7, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:48,512 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, 794f79c2-1b8e-49fd-ab3b-5cea01720cb7, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=NjM5MjdhMGYtY2NlYmE1MDctOWM3MjI3NGEtOWMzMDVjZTA=" }
2025-11-11 15:39:48,560 - DEBUG - ydb.connection - _log_response: RpcState(DeleteSession, 794f79c2-1b8e-49fd-ab3b-5cea01720cb7, ghrun-3ynj4chmly.auto.internal:22586): response = { status: SUCCESS }
2025-11-11 15:39:48,561 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, e12afbba-8cf0-4f9d-a6b9-4545854a9d4a, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:48,562 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, e12afbba-8cf0-4f9d-a6b9-4545854a9d4a, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=YmNjYjZkMWItMjJkNTUwN2YtYTU4ZjgwNmUtY2E2YjZlNzU=" }
2025-11-11 15:39:48,564 - DEBUG - ydb.connection - _rpc_error_handler: RpcState(AttachSession, d4326eeb-7381-4d2b-b90f-69bdc83975ac, ghrun-3ynj4chmly.auto.internal:22586): received error, <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.CANCELLED
	details = "Locally cancelled by application!"
	debug_error_string = "None"
>
2025-11-11 15:39:48,572 - DEBUG - ydb.connection - _log_response: RpcState(DeleteSession, e12afbba-8cf0-4f9d-a6b9-4545854a9d4a, ghrun-3ynj4chmly.auto.internal:22586): response = { status: SUCCESS }
2025-11-11 15:39:48,573 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, ed8d025b-785b-4b88-aed0-6277fdbe147d, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:48,573 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, ed8d025b-785b-4b88-aed0-6277fdbe147d, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=ZWQ4MzM4YmQtOTAyZmI2NmItYzFiZTNmODUtZDVmNTVjZTI=" }
2025-11-11 15:39:48,579 - DEBUG - ydb.connection - _log_response: RpcState(DeleteSession, ed8d025b-785b-4b88-aed0-6277fdbe147d, ghrun-3ynj4chmly.auto.internal:22586): response = { status: SUCCESS }
2025-11-11 15:39:48,581 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, 6a2204f3-acc7-45e9-ac59-3797fee96a56, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:48,581 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, 6a2204f3-acc7-45e9-ac59-3797fee96a56, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=OTMwMmMwNTEtNDBlYzEwYzQtNGQ0Y2YxYzYtOTNjYTVjZWI=" }
2025-11-11 15:39:48,585 - DEBUG - ydb.connection - _log_response: RpcState(DeleteSession, 6a2204f3-acc7-45e9-ac59-3797fee96a56, ghrun-3ynj4chmly.auto.internal:22586): response = { status: SUCCESS }
2025-11-11 15:39:48,585 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, 0dbd6f7c-1060-459d-8af1-095b600f9640, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:48,586 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, 0dbd6f7c-1060-459d-8af1-095b600f9640, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=MjM3MzUwYTAtNjlhNTdhY2YtZWVkOTkxYWYtZmU5MDBkYzY=" }
2025-11-11 15:39:48,591 - DEBUG - ydb.connection - _log_response: RpcState(DeleteSession, 0dbd6f7c-1060-459d-8af1-095b600f9640, ghrun-3ynj4chmly.auto.internal:22586): response = { status: SUCCESS }
2025-11-11 15:39:48,592 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, be3f7130-9c66-4a27-9898-474d3ac28b6a, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:48,593 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, be3f7130-9c66-4a27-9898-474d3ac28b6a, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=ZmJkM2E0YWItYzU5YWM2MmUtYzUzYjJlNTYtM2ZiYmY2MzA=" }
2025-11-11 15:39:48,596 - DEBUG - ydb.connection - _log_response: RpcState(DeleteSession, be3f7130-9c66-4a27-9898-474d3ac28b6a, ghrun-3ynj4chmly.auto.internal:22586): response = { status: SUCCESS }
2025-11-11 15:39:48,597 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, 02df7591-2c8c-4b1b-8d11-8bf697f81b83, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:48,597 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, 02df7591-2c8c-4b1b-8d11-8bf697f81b83, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=OWY3MjIxNzEtYmMxOTc5YTYtMmExNTJlMGMtMzcxNzRlYmM=" }
2025-11-11 15:39:48,598 - DEBUG - ydb.connection - _rpc_error_handler: RpcState(AttachSession, 990ce70b-ec69-43de-823d-ec62456e508e, ghrun-3ynj4chmly.auto.internal:22586): received error, <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.CANCELLED
	details = "Locally cancelled by application!"
	debug_error_string = "None"
>
2025-11-11 15:39:48,604 - DEBUG - ydb.connection - _log_response: RpcState(DeleteSession, 02df7591-2c8c-4b1b-8d11-8bf697f81b83, ghrun-3ynj4chmly.auto.internal:22586): response = { status: SUCCESS }
2025-11-11 15:39:48,604 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, bf4568b2-c72b-4ee8-a93f-162d239d8717, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:48,604 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, bf4568b2-c72b-4ee8-a93f-162d239d8717, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=ZDQ4ZjdmNzctOTMxMGM2ZWEtOWM0ZGFhMTYtODI3YzYxNzM=" }
2025-11-11 15:39:48,606 - DEBUG - ydb.connection - _log_response: RpcState(DeleteSession, bf4568b2-c72b-4ee8-a93f-162d239d8717, ghrun-3ynj4chmly.auto.internal:22586): response = { status: SUCCESS }
2025-11-11 15:39:48,607 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, 1363f1f0-c7d9-4625-82fa-5f94390251f8, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:48,607 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, 1363f1f0-c7d9-4625-82fa-5f94390251f8, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=YjJkNTI5YWEtNWE5ZjdlNTQtZjIzMjNmOGMtNWUwZWVhZjk=" }
2025-11-11 15:39:48,623 - DEBUG - ydb.connection - _log_response: RpcState(DeleteSession, 1363f1f0-c7d9-4625-82fa-5f94390251f8, ghrun-3ynj4chmly.auto.internal:22586): response = { status: SUCCESS }
2025-11-11 15:39:48,624 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, 8bd337f2-3798-4592-a959-224b8ea9d042, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:48,624 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, 8bd337f2-3798-4592-a959-224b8ea9d042, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=ODc3YmViZjAtZWJmYzcwNTItZTMyZTE4NzItMzNkYWRkYjI=" }
2025-11-11 15:39:48,645 - DEBUG - ydb.connection - _log_response: RpcState(DeleteSession, 8bd337f2-3798-4592-a959-224b8ea9d042, ghrun-3ynj4chmly.auto.internal:22586): response = { status: SUCCESS }
2025-11-11 15:39:48,646 - DEBUG - ydb.query.pool - stop: All session were deleted.
2025-11-11 15:39:48,646 - DEBUG - ydb.topic - close: Close topic client
2025-11-11 15:39:48,646 - DEBUG - ydb.topic - close: Topic client was closed
2025-11-11 15:39:48,646 - DEBUG - ydb.connection - close: Closing channel for endpoint localhost:22586
2025-11-11 15:39:48,651 - DEBUG - ydb.connection - close: Closing channel for endpoint ghrun-3ynj4chmly.auto.internal:22586
2025-11-11 15:39:48,652 - INFO - ydb.pool.Discovery - run: Successfully terminated discovery process
2025-11-11 15:39:55,695 - INFO - ydb.tests.library.harness.kikimr_runner - stop: Stopped node localhost:22586/1
2025-11-11 15:39:55,696 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/12999
2025-11-11 15:39:55,697 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/4845
2025-11-11 15:39:55,697 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/7109
2025-11-11 15:39:55,697 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/22586
2025-11-11 15:39:55,697 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/11396
