2025-11-11 16:04:18,932 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-11-11 16:04:18,937 - INFO - ya.test - pytest_runtest_setup: test_log_deviation[180]
2025-11-11 16:04:18,937 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-11-11 16:04:18,937 - INFO - ya.test - pytest_runtest_setup: Test setup
2025-11-11 16:04:18,939 - INFO - ya.test - pytest_runtest_call: Test call (class_name: test_log_scenario.py::TestLogScenario, test_name: test_log_deviation[180])
2025-11-11 16:04:18,940 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/72pg/000725/ydb/apps/ydb/ydb
2025-11-11 16:04:18,973 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/72pg/000725/ydb/apps/ydb/ydb -e grpc://localhost:30334 -d /Root workload log --path log init --path log --store column --ttl 1000 with wait = True
2025-11-11 16:04:18,993 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.5
2025-11-11 16:04:19,002 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.5
2025-11-11 16:04:19,002 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/72pg/000725/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:30334', '-d', '/Root', 'workload', 'log', '--path', 'log', 'init', '--path', 'log', '--store', 'column', '--ttl', '1000']' in 'None' (waiting)
2025-11-11 16:04:19,012 - DEBUG - ya.test - execute: Command pid: 3274774
2025-11-11 16:04:20,030 - DEBUG - ya.test - _save_outputs: Command (pid 3274774) rc: 0
2025-11-11 16:04:20,030 - DEBUG - ya.test - _save_outputs: Command (pid 3274774) elapsed time (sec): 1.0083777904510498
2025-11-11 16:04:20,031 - DEBUG - ya.test - _save_outputs: Command (pid 3274774) idrss: 0
2025-11-11 16:04:20,031 - DEBUG - ya.test - _save_outputs: Command (pid 3274774) inblock: 0
2025-11-11 16:04:20,047 - DEBUG - ya.test - _save_outputs: Command (pid 3274774) isrss: 0
2025-11-11 16:04:20,047 - DEBUG - ya.test - _save_outputs: Command (pid 3274774) ixrss: 0
2025-11-11 16:04:20,062 - DEBUG - ya.test - _save_outputs: Command (pid 3274774) majflt: 0
2025-11-11 16:04:20,062 - DEBUG - ya.test - _save_outputs: Command (pid 3274774) maxrss: 744152
2025-11-11 16:04:20,062 - DEBUG - ya.test - _save_outputs: Command (pid 3274774) minflt: 3485
2025-11-11 16:04:20,063 - DEBUG - ya.test - _save_outputs: Command (pid 3274774) msgrcv: 0
2025-11-11 16:04:20,063 - DEBUG - ya.test - _save_outputs: Command (pid 3274774) msgsnd: 0
2025-11-11 16:04:20,063 - DEBUG - ya.test - _save_outputs: Command (pid 3274774) nivcsw: 53
2025-11-11 16:04:20,063 - DEBUG - ya.test - _save_outputs: Command (pid 3274774) nsignals: 0
2025-11-11 16:04:20,063 - DEBUG - ya.test - _save_outputs: Command (pid 3274774) nswap: 0
2025-11-11 16:04:20,064 - DEBUG - ya.test - _save_outputs: Command (pid 3274774) nvcsw: 169
2025-11-11 16:04:20,075 - DEBUG - ya.test - _save_outputs: Command (pid 3274774) oublock: 8
2025-11-11 16:04:20,076 - DEBUG - ya.test - _save_outputs: Command (pid 3274774) stime: 0.022352999999999998
2025-11-11 16:04:20,076 - DEBUG - ya.test - _save_outputs: Command (pid 3274774) utime: 0.05812
2025-11-11 16:04:20,076 - DEBUG - ya.test - _save_outputs: Command (pid 3274774) wtime: 1.021
2025-11-11 16:04:20,076 - DEBUG - ya.test - _save_outputs: Command (pid 3274774) output:
Init tables ...
Init tables ...Ok

2025-11-11 16:04:20,077 - DEBUG - ya.test - _save_outputs: Command (pid 3274774) errors:

2025-11-11 16:04:20,095 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZWVmZjI5OC0zMzc4NjZjYy0yNzc5OGQ4Ny1kYTIzZjQ4Nw==
2025-11-11 16:04:20,095 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, de547e4b-ee8b-49e2-9bbc-a352a5adff4b, ghrun-l3u76ogmey.auto.internal:30334): creating call state
2025-11-11 16:04:20,099 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, de547e4b-ee8b-49e2-9bbc-a352a5adff4b, ghrun-l3u76ogmey.auto.internal:30334): request = { session_id: "ydb://session/3?node_id=1&id=ZWVmZjI5OC0zMzc4NjZjYy0yNzc5OGQ4Ny1kYTIzZjQ4Nw==" 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 16:04:20,100 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, de547e4b-ee8b-49e2-9bbc-a352a5adff4b, ghrun-l3u76ogmey.auto.internal:30334): response = { <_MultiThreadedRendezvous object> }
2025-11-11 16:04:20,193 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZWVmZjI5OC0zMzc4NjZjYy0yNzc5OGQ4Ny1kYTIzZjQ4Nw==
2025-11-11 16:04:20,193 - INFO - root - _insert_rows: YdbWorkloadLog bulk_upsert
2025-11-11 16:04:20,193 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/72pg/000725/ydb/apps/ydb/ydb -e grpc://localhost:30334 -d /Root workload log --path log run bulk_upsert --seconds 3 --threads 10 --rows 500 --timestamp_deviation 180 with wait = True
2025-11-11 16:04:20,196 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.6
2025-11-11 16:04:20,200 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.6
2025-11-11 16:04:20,201 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/72pg/000725/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:30334', '-d', '/Root', 'workload', 'log', '--path', 'log', 'run', 'bulk_upsert', '--seconds', '3', '--threads', '10', '--rows', '500', '--timestamp_deviation', '180']' in 'None' (waiting)
2025-11-11 16:04:20,207 - DEBUG - ya.test - execute: Command pid: 3275590
2025-11-11 16:04:24,554 - DEBUG - ya.test - _wait: Process resource usage is not available as process finished before wait4 was called
2025-11-11 16:04:24,554 - DEBUG - ya.test - _save_outputs: Command (pid 3275590) rc: 0
2025-11-11 16:04:24,564 - DEBUG - ya.test - _save_outputs: Command (pid 3275590) elapsed time (sec): 4.346026182174683
2025-11-11 16:04:24,570 - DEBUG - ya.test - _save_outputs: Command (pid 3275590) wtime: 4.349
2025-11-11 16:04:24,688 - DEBUG - ya.test - _save_outputs: Command (pid 3275590) output:
Window	    Txs	Txs/Sec	Retries	Errors	p50(ms)	p95(ms)	p99(ms)	pMax(ms)
1	      2	2	0	0	791	807	807	807
2	     11	11	0	0	987	1239	1239	1239
3	     17	17	0	0	1343	1495	1567	1567

Total	    Txs	Txs/Sec	Retries	Errors	p50(ms)	p95(ms)	p99(ms)	pMax(ms)
3	     30	10	0	0	1191	1495	1567	1567

2025-11-11 16:04:24,688 - DEBUG - ya.test - _save_outputs: Command (pid 3275590) errors:

2025-11-11 16:04:24,688 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YzY4ZDI4ZTUtN2VjZjVmZjktZWU1ZTc1MGQtYzUwYjQxMTU=
2025-11-11 16:04:24,720 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, c87465bf-ab1e-4986-8ef0-542959b0583b, ghrun-l3u76ogmey.auto.internal:30334): creating call state
2025-11-11 16:04:24,725 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, c87465bf-ab1e-4986-8ef0-542959b0583b, ghrun-l3u76ogmey.auto.internal:30334): request = { session_id: "ydb://session/3?node_id=1&id=YzY4ZDI4ZTUtN2VjZjVmZjktZWU1ZTc1MGQtYzUwYjQxMTU=" 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 16:04:24,735 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, c87465bf-ab1e-4986-8ef0-542959b0583b, ghrun-l3u76ogmey.auto.internal:30334): response = { <_MultiThreadedRendezvous object> }
2025-11-11 16:04:25,873 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-11-11 16:04:25,874 - 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 16:04:25,891 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database /Root
2025-11-11 16:04:25,910 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, 09bbfc9e-c0ea-4159-ae47-7ba4cf7ff2c1, localhost:30334): creating call state
2025-11-11 16:04:25,911 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, 09bbfc9e-c0ea-4159-ae47-7ba4cf7ff2c1, localhost:30334): request = { database: "/Root" }
2025-11-11 16:04:25,925 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, 09bbfc9e-c0ea-4159-ae47-7ba4cf7ff2c1, localhost:30334): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Discovery.ListEndpointsResult] { endpoints { address: "ghrun-l3u76ogmey.auto.internal" port: 30334 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 16:04:25,926 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Resolved endpoints for database /Root: DiscoveryResult <self_location: 1, endpoints [<Endpoint ghrun-l3u76ogmey.auto.internal:30334, location 1, ssl: False>]>
2025-11-11 16:04:25,926 - INFO - ydb.connection - close: Closing channel for endpoint localhost:30334
2025-11-11 16:04:26,279 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YzY4ZDI4ZTUtN2VjZjVmZjktZWU1ZTc1MGQtYzUwYjQxMTU=
2025-11-11 16:04:26,280 - INFO - root - test_log_deviation: Count rows after insert 15000 before wait
2025-11-11 16:04:26,280 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OGQzNzg3ODUtYTBjZDJjM2EtYWJjOGNmYTMtOThmMWZlZmE=
2025-11-11 16:04:26,281 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 5ab6e838-bbd9-4fec-b735-197a8fea5168, ghrun-l3u76ogmey.auto.internal:30334): creating call state
2025-11-11 16:04:26,281 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 5ab6e838-bbd9-4fec-b735-197a8fea5168, ghrun-l3u76ogmey.auto.internal:30334): request = { session_id: "ydb://session/3?node_id=1&id=OGQzNzg3ODUtYTBjZDJjM2EtYWJjOGNmYTMtOThmMWZlZmE=" 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 16:04:26,282 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 5ab6e838-bbd9-4fec-b735-197a8fea5168, ghrun-l3u76ogmey.auto.internal:30334): response = { <_MultiThreadedRendezvous object> }
2025-11-11 16:04:29,192 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=OGQzNzg3ODUtYTBjZDJjM2EtYWJjOGNmYTMtOThmMWZlZmE=
2025-11-11 16:04:29,198 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MWU2ZmE1YzEtNjEyMzdhZi1hMTY0OTY5Yy1mM2MyMmI0ZA==
2025-11-11 16:04:29,222 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 4f009ea0-6dd9-4a0d-977b-37bd99fa2e79, ghrun-l3u76ogmey.auto.internal:30334): creating call state
2025-11-11 16:04:29,222 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 4f009ea0-6dd9-4a0d-977b-37bd99fa2e79, ghrun-l3u76ogmey.auto.internal:30334): request = { session_id: "ydb://session/3?node_id=1&id=MWU2ZmE1YzEtNjEyMzdhZi1hMTY0OTY5Yy1mM2MyMmI0ZA==" 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 16:04:29,227 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 4f009ea0-6dd9-4a0d-977b-37bd99fa2e79, ghrun-l3u76ogmey.auto.internal:30334): response = { <_MultiThreadedRendezvous object> }
2025-11-11 16:04:30,388 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MWU2ZmE1YzEtNjEyMzdhZi1hMTY0OTY5Yy1mM2MyMmI0ZA==
2025-11-11 16:04:30,391 - INFO - root - _insert_rows: YdbWorkloadLog bulk_upsert
2025-11-11 16:04:30,392 - INFO - root - _insert_rows: YdbWorkloadLog insert
2025-11-11 16:04:30,393 - INFO - root - _insert_rows: YdbWorkloadLog upsert
2025-11-11 16:04:30,393 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZDIxNjVhNDgtYzllMjRkLTk1ZDBhOWM2LTYxY2E5MWZi
2025-11-11 16:04:30,416 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 14f527d5-f4f3-49a2-9ee0-78534109d4ff, ghrun-l3u76ogmey.auto.internal:30334): creating call state
2025-11-11 16:04:30,404 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/72pg/000725/ydb/apps/ydb/ydb -e grpc://localhost:30334 -d /Root workload log --path log run insert --seconds 3 --threads 10 --rows 500 --timestamp_deviation 180 with wait = True
2025-11-11 16:04:30,406 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/72pg/000725/ydb/apps/ydb/ydb -e grpc://localhost:30334 -d /Root workload log --path log run upsert --seconds 3 --threads 10 --rows 500 --timestamp_deviation 180 with wait = True
2025-11-11 16:04:30,417 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 14f527d5-f4f3-49a2-9ee0-78534109d4ff, ghrun-l3u76ogmey.auto.internal:30334): request = { session_id: "ydb://session/3?node_id=1&id=ZDIxNjVhNDgtYzllMjRkLTk1ZDBhOWM2LTYxY2E5MWZi" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-11 16:04:30,403 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/72pg/000725/ydb/apps/ydb/ydb -e grpc://localhost:30334 -d /Root workload log --path log run bulk_upsert --seconds 3 --threads 10 --rows 500 --timestamp_deviation 180 with wait = True
2025-11-11 16:04:30,417 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NjNkZjFlZmItM2ZlZDJjNjgtNzliNjIxZTctYjJmZWYxZGQ=
2025-11-11 16:04:30,420 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.7
2025-11-11 16:04:30,422 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.8
2025-11-11 16:04:30,426 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 14f527d5-f4f3-49a2-9ee0-78534109d4ff, ghrun-l3u76ogmey.auto.internal:30334): response = { <_MultiThreadedRendezvous object> }
2025-11-11 16:04:30,435 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, a36f009c-02dc-45bb-8aa4-3f7f1aa0054c, ghrun-l3u76ogmey.auto.internal:30334): creating call state
2025-11-11 16:04:30,429 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.9
2025-11-11 16:04:30,439 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, a36f009c-02dc-45bb-8aa4-3f7f1aa0054c, ghrun-l3u76ogmey.auto.internal:30334): request = { session_id: "ydb://session/3?node_id=1&id=NjNkZjFlZmItM2ZlZDJjNjgtNzliNjIxZTctYjJmZWYxZGQ=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-11 16:04:30,435 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZjFlOGZiNmMtODU0N2I1NWYtNGJjNzRhODgtM2Q1MDg2ZmY=
2025-11-11 16:04:30,437 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.7
2025-11-11 16:04:30,442 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YTEyZDJjYmItOGU1OGJmZTYtZDk1M2YyNGItNjhiYzA0YTQ=
2025-11-11 16:04:30,442 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 62a8f53a-3114-440d-bd74-9a208ddff90b, ghrun-l3u76ogmey.auto.internal:30334): creating call state
2025-11-11 16:04:30,442 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, a36f009c-02dc-45bb-8aa4-3f7f1aa0054c, ghrun-l3u76ogmey.auto.internal:30334): response = { <_MultiThreadedRendezvous object> }
2025-11-11 16:04:30,444 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OTMzZWNhMzItOTA2NWY2OTYtYmYxNDZhM2MtNTg1NzI4ZTY=
2025-11-11 16:04:30,443 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/72pg/000725/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:30334', '-d', '/Root', 'workload', 'log', '--path', 'log', 'run', 'insert', '--seconds', '3', '--threads', '10', '--rows', '500', '--timestamp_deviation', '180']' in 'None' (waiting)
2025-11-11 16:04:30,446 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 62a8f53a-3114-440d-bd74-9a208ddff90b, ghrun-l3u76ogmey.auto.internal:30334): request = { session_id: "ydb://session/3?node_id=1&id=ZjFlOGZiNmMtODU0N2I1NWYtNGJjNzRhODgtM2Q1MDg2ZmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-11 16:04:30,446 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.8
2025-11-11 16:04:30,472 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/72pg/000725/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:30334', '-d', '/Root', 'workload', 'log', '--path', 'log', 'run', 'upsert', '--seconds', '3', '--threads', '10', '--rows', '500', '--timestamp_deviation', '180']' in 'None' (waiting)
2025-11-11 16:04:30,444 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, d1f0a458-81ef-4ba8-a346-fdf83e19c47a, ghrun-l3u76ogmey.auto.internal:30334): creating call state
2025-11-11 16:04:30,449 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 1099c39e-d1ae-47d5-8bfe-8d90cc202b95, ghrun-l3u76ogmey.auto.internal:30334): creating call state
2025-11-11 16:04:30,450 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ODQ0YzdkNTUtNzlhMjk1YjMtYjZkMGJkZGUtMzYzMjk0M2Y=
2025-11-11 16:04:30,467 - DEBUG - ya.test - execute: Command pid: 3279380
2025-11-11 16:04:30,446 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.9
2025-11-11 16:04:30,530 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/72pg/000725/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:30334', '-d', '/Root', 'workload', 'log', '--path', 'log', 'run', 'bulk_upsert', '--seconds', '3', '--threads', '10', '--rows', '500', '--timestamp_deviation', '180']' in 'None' (waiting)
2025-11-11 16:04:30,473 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 62a8f53a-3114-440d-bd74-9a208ddff90b, ghrun-l3u76ogmey.auto.internal:30334): response = { <_MultiThreadedRendezvous object> }
2025-11-11 16:04:30,517 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, d1f0a458-81ef-4ba8-a346-fdf83e19c47a, ghrun-l3u76ogmey.auto.internal:30334): request = { session_id: "ydb://session/3?node_id=1&id=YTEyZDJjYmItOGU1OGJmZTYtZDk1M2YyNGItNjhiYzA0YTQ=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-11 16:04:30,538 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, d1f0a458-81ef-4ba8-a346-fdf83e19c47a, ghrun-l3u76ogmey.auto.internal:30334): response = { <_MultiThreadedRendezvous object> }
2025-11-11 16:04:30,520 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 1099c39e-d1ae-47d5-8bfe-8d90cc202b95, ghrun-l3u76ogmey.auto.internal:30334): request = { session_id: "ydb://session/3?node_id=1&id=OTMzZWNhMzItOTA2NWY2OTYtYmYxNDZhM2MtNTg1NzI4ZTY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-11 16:04:30,542 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 1099c39e-d1ae-47d5-8bfe-8d90cc202b95, ghrun-l3u76ogmey.auto.internal:30334): response = { <_MultiThreadedRendezvous object> }
2025-11-11 16:04:30,510 - DEBUG - ya.test - execute: Command pid: 3279411
2025-11-11 16:04:30,524 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZWVmZjI5OC0zMzc4NjZjYy0yNzc5OGQ4Ny1kYTIzZjQ4Nw==
2025-11-11 16:04:30,543 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, a0e72a04-eaff-454e-9008-cf3c7502eecf, ghrun-l3u76ogmey.auto.internal:30334): creating call state
2025-11-11 16:04:30,544 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, a0e72a04-eaff-454e-9008-cf3c7502eecf, ghrun-l3u76ogmey.auto.internal:30334): request = { session_id: "ydb://session/3?node_id=1&id=ZWVmZjI5OC0zMzc4NjZjYy0yNzc5OGQ4Ny1kYTIzZjQ4Nw==" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-11 16:04:30,545 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, a0e72a04-eaff-454e-9008-cf3c7502eecf, ghrun-l3u76ogmey.auto.internal:30334): response = { <_MultiThreadedRendezvous object> }
2025-11-11 16:04:30,546 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YzY4ZDI4ZTUtN2VjZjVmZjktZWU1ZTc1MGQtYzUwYjQxMTU=
2025-11-11 16:04:30,523 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, abd66444-0c91-4542-851b-217456c8a0ac, ghrun-l3u76ogmey.auto.internal:30334): creating call state
2025-11-11 16:04:30,551 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, abd66444-0c91-4542-851b-217456c8a0ac, ghrun-l3u76ogmey.auto.internal:30334): request = { session_id: "ydb://session/3?node_id=1&id=ODQ0YzdkNTUtNzlhMjk1YjMtYjZkMGJkZGUtMzYzMjk0M2Y=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-11 16:04:30,552 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, abd66444-0c91-4542-851b-217456c8a0ac, ghrun-l3u76ogmey.auto.internal:30334): response = { <_MultiThreadedRendezvous object> }
2025-11-11 16:04:30,553 - DEBUG - ya.test - execute: Command pid: 3279479
2025-11-11 16:04:30,554 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OGQzNzg3ODUtYTBjZDJjM2EtYWJjOGNmYTMtOThmMWZlZmE=
2025-11-11 16:04:30,555 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, fa190774-39fa-43df-b7c7-4e7960146779, ghrun-l3u76ogmey.auto.internal:30334): creating call state
2025-11-11 16:04:30,555 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, fa190774-39fa-43df-b7c7-4e7960146779, ghrun-l3u76ogmey.auto.internal:30334): request = { session_id: "ydb://session/3?node_id=1&id=OGQzNzg3ODUtYTBjZDJjM2EtYWJjOGNmYTMtOThmMWZlZmE=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-11 16:04:30,556 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, fa190774-39fa-43df-b7c7-4e7960146779, ghrun-l3u76ogmey.auto.internal:30334): response = { <_MultiThreadedRendezvous object> }
2025-11-11 16:04:30,557 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MWU2ZmE1YzEtNjEyMzdhZi1hMTY0OTY5Yy1mM2MyMmI0ZA==
2025-11-11 16:04:30,557 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 9c5e1a73-823e-4c51-99de-8647738d3d22, ghrun-l3u76ogmey.auto.internal:30334): creating call state
2025-11-11 16:04:30,558 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 9c5e1a73-823e-4c51-99de-8647738d3d22, ghrun-l3u76ogmey.auto.internal:30334): request = { session_id: "ydb://session/3?node_id=1&id=MWU2ZmE1YzEtNjEyMzdhZi1hMTY0OTY5Yy1mM2MyMmI0ZA==" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-11 16:04:30,559 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 9c5e1a73-823e-4c51-99de-8647738d3d22, ghrun-l3u76ogmey.auto.internal:30334): response = { <_MultiThreadedRendezvous object> }
2025-11-11 16:04:30,547 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 227b4a8d-f980-4ba6-b484-9fd2c4f06c5f, ghrun-l3u76ogmey.auto.internal:30334): creating call state
2025-11-11 16:04:30,563 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 227b4a8d-f980-4ba6-b484-9fd2c4f06c5f, ghrun-l3u76ogmey.auto.internal:30334): request = { session_id: "ydb://session/3?node_id=1&id=YzY4ZDI4ZTUtN2VjZjVmZjktZWU1ZTc1MGQtYzUwYjQxMTU=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-11 16:04:30,564 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 227b4a8d-f980-4ba6-b484-9fd2c4f06c5f, ghrun-l3u76ogmey.auto.internal:30334): response = { <_MultiThreadedRendezvous object> }
2025-11-11 16:04:35,664 - DEBUG - ya.test - _wait: Process resource usage is not available as process finished before wait4 was called
2025-11-11 16:04:35,664 - DEBUG - ya.test - _save_outputs: Command (pid 3279380) rc: 0
2025-11-11 16:04:35,689 - DEBUG - ya.test - _save_outputs: Command (pid 3279380) elapsed time (sec): 5.135190486907959
2025-11-11 16:04:35,683 - DEBUG - ya.test - _wait: Process resource usage is not available as process finished before wait4 was called
2025-11-11 16:04:35,697 - DEBUG - ya.test - _save_outputs: Command (pid 3279380) wtime: 5.213
2025-11-11 16:04:35,717 - DEBUG - ya.test - _save_outputs: Command (pid 3279380) 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	8	0	0	0	0
3	      0	0	0	12	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 16:04:35,717 - DEBUG - ya.test - _save_outputs: Command (pid 3279380) errors:

2025-11-11 16:04:35,715 - DEBUG - ya.test - _save_outputs: Command (pid 3279411) rc: 0
2025-11-11 16:04:35,721 - DEBUG - ya.test - _save_outputs: Command (pid 3279411) elapsed time (sec): 5.159867525100708
2025-11-11 16:04:35,725 - DEBUG - ya.test - _save_outputs: Command (pid 3279411) wtime: 5.228
2025-11-11 16:04:35,726 - DEBUG - ya.test - _save_outputs: Command (pid 3279411) 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 16:04:35,726 - DEBUG - ya.test - _save_outputs: Command (pid 3279411) errors:

2025-11-11 16:04:51,764 - DEBUG - ya.test - _wait: Process resource usage is not available as process finished before wait4 was called
2025-11-11 16:04:51,779 - DEBUG - ya.test - _save_outputs: Command (pid 3279479) rc: 0
2025-11-11 16:04:51,783 - DEBUG - ya.test - _save_outputs: Command (pid 3279479) elapsed time (sec): 21.220722913742065
2025-11-11 16:04:51,784 - DEBUG - ya.test - _save_outputs: Command (pid 3279479) wtime: 21.244
2025-11-11 16:04:51,785 - DEBUG - ya.test - _save_outputs: Command (pid 3279479) 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 16:04:51,787 - DEBUG - ya.test - _save_outputs: Command (pid 3279479) errors:

2025-11-11 16:04:58,260 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZWVmZjI5OC0zMzc4NjZjYy0yNzc5OGQ4Ny1kYTIzZjQ4Nw==
2025-11-11 16:04:58,268 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZWVmZjI5OC0zMzc4NjZjYy0yNzc5OGQ4Ny1kYTIzZjQ4Nw==
2025-11-11 16:04:58,269 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 5522ee36-b99f-46e9-99d7-d079f75d98fa, ghrun-l3u76ogmey.auto.internal:30334): creating call state
2025-11-11 16:04:58,269 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 5522ee36-b99f-46e9-99d7-d079f75d98fa, ghrun-l3u76ogmey.auto.internal:30334): request = { session_id: "ydb://session/3?node_id=1&id=ZWVmZjI5OC0zMzc4NjZjYy0yNzc5OGQ4Ny1kYTIzZjQ4Nw==" 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 16:04:58,270 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 5522ee36-b99f-46e9-99d7-d079f75d98fa, ghrun-l3u76ogmey.auto.internal:30334): response = { <_MultiThreadedRendezvous object> }
2025-11-11 16:04:58,679 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZjFlOGZiNmMtODU0N2I1NWYtNGJjNzRhODgtM2Q1MDg2ZmY=
2025-11-11 16:04:58,679 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZjFlOGZiNmMtODU0N2I1NWYtNGJjNzRhODgtM2Q1MDg2ZmY=
2025-11-11 16:04:58,680 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 9619381b-8091-4fe4-a5d6-b0669401a202, ghrun-l3u76ogmey.auto.internal:30334): creating call state
2025-11-11 16:04:58,680 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 9619381b-8091-4fe4-a5d6-b0669401a202, ghrun-l3u76ogmey.auto.internal:30334): request = { session_id: "ydb://session/3?node_id=1&id=ZjFlOGZiNmMtODU0N2I1NWYtNGJjNzRhODgtM2Q1MDg2ZmY=" 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-11 16:04:58,681 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 9619381b-8091-4fe4-a5d6-b0669401a202, ghrun-l3u76ogmey.auto.internal:30334): response = { <_MultiThreadedRendezvous object> }
2025-11-11 16:04:58,834 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MWU2ZmE1YzEtNjEyMzdhZi1hMTY0OTY5Yy1mM2MyMmI0ZA==
2025-11-11 16:04:58,835 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MWU2ZmE1YzEtNjEyMzdhZi1hMTY0OTY5Yy1mM2MyMmI0ZA==
2025-11-11 16:04:58,835 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 03f14f0e-9e3d-4e39-a328-29f908afc54b, ghrun-l3u76ogmey.auto.internal:30334): creating call state
2025-11-11 16:04:58,836 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 03f14f0e-9e3d-4e39-a328-29f908afc54b, ghrun-l3u76ogmey.auto.internal:30334): request = { session_id: "ydb://session/3?node_id=1&id=MWU2ZmE1YzEtNjEyMzdhZi1hMTY0OTY5Yy1mM2MyMmI0ZA==" 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 16:04:58,837 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 03f14f0e-9e3d-4e39-a328-29f908afc54b, ghrun-l3u76ogmey.auto.internal:30334): response = { <_MultiThreadedRendezvous object> }
2025-11-11 16:04:58,876 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=OTMzZWNhMzItOTA2NWY2OTYtYmYxNDZhM2MtNTg1NzI4ZTY=
2025-11-11 16:04:58,878 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OTMzZWNhMzItOTA2NWY2OTYtYmYxNDZhM2MtNTg1NzI4ZTY=
2025-11-11 16:04:58,879 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, bbcdf95b-92a7-4a14-9b2a-fb20e4c96045, ghrun-l3u76ogmey.auto.internal:30334): creating call state
2025-11-11 16:04:58,879 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, bbcdf95b-92a7-4a14-9b2a-fb20e4c96045, ghrun-l3u76ogmey.auto.internal:30334): request = { session_id: "ydb://session/3?node_id=1&id=OTMzZWNhMzItOTA2NWY2OTYtYmYxNDZhM2MtNTg1NzI4ZTY=" 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 16:04:58,881 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, bbcdf95b-92a7-4a14-9b2a-fb20e4c96045, ghrun-l3u76ogmey.auto.internal:30334): response = { <_MultiThreadedRendezvous object> }
2025-11-11 16:04:59,855 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MWU2ZmE1YzEtNjEyMzdhZi1hMTY0OTY5Yy1mM2MyMmI0ZA==
2025-11-11 16:04:59,856 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MWU2ZmE1YzEtNjEyMzdhZi1hMTY0OTY5Yy1mM2MyMmI0ZA==
2025-11-11 16:04:59,857 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 3270d910-c69d-41e7-a891-c8fad6c3fa28, ghrun-l3u76ogmey.auto.internal:30334): creating call state
2025-11-11 16:04:59,858 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 3270d910-c69d-41e7-a891-c8fad6c3fa28, ghrun-l3u76ogmey.auto.internal:30334): request = { session_id: "ydb://session/3?node_id=1&id=MWU2ZmE1YzEtNjEyMzdhZi1hMTY0OTY5Yy1mM2MyMmI0ZA==" 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 16:04:59,859 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 3270d910-c69d-41e7-a891-c8fad6c3fa28, ghrun-l3u76ogmey.auto.internal:30334): response = { <_MultiThreadedRendezvous object> }
2025-11-11 16:04:59,876 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YTEyZDJjYmItOGU1OGJmZTYtZDk1M2YyNGItNjhiYzA0YTQ=
2025-11-11 16:04:59,876 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YTEyZDJjYmItOGU1OGJmZTYtZDk1M2YyNGItNjhiYzA0YTQ=
2025-11-11 16:04:59,877 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 829777e9-9de4-4bbc-8aeb-24b4daf468f8, ghrun-l3u76ogmey.auto.internal:30334): creating call state
2025-11-11 16:04:59,879 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 829777e9-9de4-4bbc-8aeb-24b4daf468f8, ghrun-l3u76ogmey.auto.internal:30334): request = { session_id: "ydb://session/3?node_id=1&id=YTEyZDJjYmItOGU1OGJmZTYtZDk1M2YyNGItNjhiYzA0YTQ=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(10)" } stats_mode: STATS_MODE_NONE }
2025-11-11 16:04:59,880 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 829777e9-9de4-4bbc-8aeb-24b4daf468f8, ghrun-l3u76ogmey.auto.internal:30334): response = { <_MultiThreadedRendezvous object> }
2025-11-11 16:04:59,888 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=OTMzZWNhMzItOTA2NWY2OTYtYmYxNDZhM2MtNTg1NzI4ZTY=
2025-11-11 16:04:59,889 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OTMzZWNhMzItOTA2NWY2OTYtYmYxNDZhM2MtNTg1NzI4ZTY=
2025-11-11 16:04:59,895 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 62f559a6-544b-409c-9a5d-30ca752105a5, ghrun-l3u76ogmey.auto.internal:30334): creating call state
2025-11-11 16:04:59,896 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 62f559a6-544b-409c-9a5d-30ca752105a5, ghrun-l3u76ogmey.auto.internal:30334): request = { session_id: "ydb://session/3?node_id=1&id=OTMzZWNhMzItOTA2NWY2OTYtYmYxNDZhM2MtNTg1NzI4ZTY=" 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 16:04:59,897 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 62f559a6-544b-409c-9a5d-30ca752105a5, ghrun-l3u76ogmey.auto.internal:30334): response = { <_MultiThreadedRendezvous object> }
2025-11-11 16:05:00,029 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZWVmZjI5OC0zMzc4NjZjYy0yNzc5OGQ4Ny1kYTIzZjQ4Nw==
2025-11-11 16:05:00,037 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZWVmZjI5OC0zMzc4NjZjYy0yNzc5OGQ4Ny1kYTIzZjQ4Nw==
2025-11-11 16:05:00,038 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, a8fe4f78-37f8-495d-a6f7-2372a0ef55bc, ghrun-l3u76ogmey.auto.internal:30334): creating call state
2025-11-11 16:05:00,050 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, a8fe4f78-37f8-495d-a6f7-2372a0ef55bc, ghrun-l3u76ogmey.auto.internal:30334): request = { session_id: "ydb://session/3?node_id=1&id=ZWVmZjI5OC0zMzc4NjZjYy0yNzc5OGQ4Ny1kYTIzZjQ4Nw==" 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 16:05:00,056 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, a8fe4f78-37f8-495d-a6f7-2372a0ef55bc, ghrun-l3u76ogmey.auto.internal:30334): response = { <_MultiThreadedRendezvous object> }
2025-11-11 16:05:00,282 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=OGQzNzg3ODUtYTBjZDJjM2EtYWJjOGNmYTMtOThmMWZlZmE=
2025-11-11 16:05:00,288 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OGQzNzg3ODUtYTBjZDJjM2EtYWJjOGNmYTMtOThmMWZlZmE=
2025-11-11 16:05:00,289 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 9be62934-9996-42c4-a292-2cdc3f7d7a46, ghrun-l3u76ogmey.auto.internal:30334): creating call state
2025-11-11 16:05:00,290 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 9be62934-9996-42c4-a292-2cdc3f7d7a46, ghrun-l3u76ogmey.auto.internal:30334): request = { session_id: "ydb://session/3?node_id=1&id=OGQzNzg3ODUtYTBjZDJjM2EtYWJjOGNmYTMtOThmMWZlZmE=" 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 16:05:00,295 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 9be62934-9996-42c4-a292-2cdc3f7d7a46, ghrun-l3u76ogmey.auto.internal:30334): response = { <_MultiThreadedRendezvous object> }
2025-11-11 16:05:00,633 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YTEyZDJjYmItOGU1OGJmZTYtZDk1M2YyNGItNjhiYzA0YTQ=
2025-11-11 16:05:00,634 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YTEyZDJjYmItOGU1OGJmZTYtZDk1M2YyNGItNjhiYzA0YTQ=
2025-11-11 16:05:00,636 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 1ba522fc-50ae-47f1-ae0f-d29e177d2595, ghrun-l3u76ogmey.auto.internal:30334): creating call state
2025-11-11 16:05:00,636 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 1ba522fc-50ae-47f1-ae0f-d29e177d2595, ghrun-l3u76ogmey.auto.internal:30334): request = { session_id: "ydb://session/3?node_id=1&id=YTEyZDJjYmItOGU1OGJmZTYtZDk1M2YyNGItNjhiYzA0YTQ=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(10)" } stats_mode: STATS_MODE_NONE }
2025-11-11 16:05:00,637 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 1ba522fc-50ae-47f1-ae0f-d29e177d2595, ghrun-l3u76ogmey.auto.internal:30334): response = { <_MultiThreadedRendezvous object> }
2025-11-11 16:05:00,723 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ODQ0YzdkNTUtNzlhMjk1YjMtYjZkMGJkZGUtMzYzMjk0M2Y=
2025-11-11 16:05:00,724 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ODQ0YzdkNTUtNzlhMjk1YjMtYjZkMGJkZGUtMzYzMjk0M2Y=
2025-11-11 16:05:00,725 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 5939efbb-d834-4fad-aaae-840a8d86795e, ghrun-l3u76ogmey.auto.internal:30334): creating call state
2025-11-11 16:05:00,733 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 5939efbb-d834-4fad-aaae-840a8d86795e, ghrun-l3u76ogmey.auto.internal:30334): request = { session_id: "ydb://session/3?node_id=1&id=ODQ0YzdkNTUtNzlhMjk1YjMtYjZkMGJkZGUtMzYzMjk0M2Y=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(10)" } stats_mode: STATS_MODE_NONE }
2025-11-11 16:05:00,738 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 5939efbb-d834-4fad-aaae-840a8d86795e, ghrun-l3u76ogmey.auto.internal:30334): response = { <_MultiThreadedRendezvous object> }
2025-11-11 16:05:00,783 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZjFlOGZiNmMtODU0N2I1NWYtNGJjNzRhODgtM2Q1MDg2ZmY=
2025-11-11 16:05:00,804 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZjFlOGZiNmMtODU0N2I1NWYtNGJjNzRhODgtM2Q1MDg2ZmY=
2025-11-11 16:05:00,805 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, f6236fc6-4c80-4e00-ac2c-7e044abb63c8, ghrun-l3u76ogmey.auto.internal:30334): creating call state
2025-11-11 16:05:00,809 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, f6236fc6-4c80-4e00-ac2c-7e044abb63c8, ghrun-l3u76ogmey.auto.internal:30334): request = { session_id: "ydb://session/3?node_id=1&id=ZjFlOGZiNmMtODU0N2I1NWYtNGJjNzRhODgtM2Q1MDg2ZmY=" 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-11 16:05:00,810 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, f6236fc6-4c80-4e00-ac2c-7e044abb63c8, ghrun-l3u76ogmey.auto.internal:30334): response = { <_MultiThreadedRendezvous object> }
2025-11-11 16:05:00,839 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MWU2ZmE1YzEtNjEyMzdhZi1hMTY0OTY5Yy1mM2MyMmI0ZA==
2025-11-11 16:05:00,839 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MWU2ZmE1YzEtNjEyMzdhZi1hMTY0OTY5Yy1mM2MyMmI0ZA==
2025-11-11 16:05:00,840 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, f2f1ba75-1d60-47f3-b7b2-b365cf41c819, ghrun-l3u76ogmey.auto.internal:30334): creating call state
2025-11-11 16:05:00,840 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, f2f1ba75-1d60-47f3-b7b2-b365cf41c819, ghrun-l3u76ogmey.auto.internal:30334): request = { session_id: "ydb://session/3?node_id=1&id=MWU2ZmE1YzEtNjEyMzdhZi1hMTY0OTY5Yy1mM2MyMmI0ZA==" 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 16:05:00,844 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, f2f1ba75-1d60-47f3-b7b2-b365cf41c819, ghrun-l3u76ogmey.auto.internal:30334): response = { <_MultiThreadedRendezvous object> }
2025-11-11 16:05:00,906 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZDIxNjVhNDgtYzllMjRkLTk1ZDBhOWM2LTYxY2E5MWZi
2025-11-11 16:05:00,907 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZDIxNjVhNDgtYzllMjRkLTk1ZDBhOWM2LTYxY2E5MWZi
2025-11-11 16:05:00,907 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, bc756aa0-b7a2-40e7-b7b0-8bd69330c573, ghrun-l3u76ogmey.auto.internal:30334): creating call state
2025-11-11 16:05:00,908 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, bc756aa0-b7a2-40e7-b7b0-8bd69330c573, ghrun-l3u76ogmey.auto.internal:30334): request = { session_id: "ydb://session/3?node_id=1&id=ZDIxNjVhNDgtYzllMjRkLTk1ZDBhOWM2LTYxY2E5MWZi" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(1)" } stats_mode: STATS_MODE_NONE }
2025-11-11 16:05:00,909 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, bc756aa0-b7a2-40e7-b7b0-8bd69330c573, ghrun-l3u76ogmey.auto.internal:30334): response = { <_MultiThreadedRendezvous object> }
2025-11-11 16:05:01,445 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NjNkZjFlZmItM2ZlZDJjNjgtNzliNjIxZTctYjJmZWYxZGQ=
2025-11-11 16:05:01,445 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NjNkZjFlZmItM2ZlZDJjNjgtNzliNjIxZTctYjJmZWYxZGQ=
2025-11-11 16:05:01,446 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 59a03089-f78a-451e-aef1-a73c00c4f644, ghrun-l3u76ogmey.auto.internal:30334): creating call state
2025-11-11 16:05:01,446 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 59a03089-f78a-451e-aef1-a73c00c4f644, ghrun-l3u76ogmey.auto.internal:30334): request = { session_id: "ydb://session/3?node_id=1&id=NjNkZjFlZmItM2ZlZDJjNjgtNzliNjIxZTctYjJmZWYxZGQ=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(1)" } stats_mode: STATS_MODE_NONE }
2025-11-11 16:05:01,447 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 59a03089-f78a-451e-aef1-a73c00c4f644, ghrun-l3u76ogmey.auto.internal:30334): response = { <_MultiThreadedRendezvous object> }
2025-11-11 16:05:01,552 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YzY4ZDI4ZTUtN2VjZjVmZjktZWU1ZTc1MGQtYzUwYjQxMTU=
2025-11-11 16:05:01,553 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YzY4ZDI4ZTUtN2VjZjVmZjktZWU1ZTc1MGQtYzUwYjQxMTU=
2025-11-11 16:05:01,553 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, d5e4a951-3e3d-4cb8-b8bc-e0181497c318, ghrun-l3u76ogmey.auto.internal:30334): creating call state
2025-11-11 16:05:01,554 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, d5e4a951-3e3d-4cb8-b8bc-e0181497c318, ghrun-l3u76ogmey.auto.internal:30334): request = { session_id: "ydb://session/3?node_id=1&id=YzY4ZDI4ZTUtN2VjZjVmZjktZWU1ZTc1MGQtYzUwYjQxMTU=" 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 16:05:01,555 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, d5e4a951-3e3d-4cb8-b8bc-e0181497c318, ghrun-l3u76ogmey.auto.internal:30334): response = { <_MultiThreadedRendezvous object> }
2025-11-11 16:05:01,559 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=OTMzZWNhMzItOTA2NWY2OTYtYmYxNDZhM2MtNTg1NzI4ZTY=
2025-11-11 16:05:01,560 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OTMzZWNhMzItOTA2NWY2OTYtYmYxNDZhM2MtNTg1NzI4ZTY=
2025-11-11 16:05:01,560 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, d4f5a3e1-9fa9-44cd-a845-aae76d2c4e44, ghrun-l3u76ogmey.auto.internal:30334): creating call state
2025-11-11 16:05:01,561 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, d4f5a3e1-9fa9-44cd-a845-aae76d2c4e44, ghrun-l3u76ogmey.auto.internal:30334): request = { session_id: "ydb://session/3?node_id=1&id=OTMzZWNhMzItOTA2NWY2OTYtYmYxNDZhM2MtNTg1NzI4ZTY=" 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 16:05:01,562 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, d4f5a3e1-9fa9-44cd-a845-aae76d2c4e44, ghrun-l3u76ogmey.auto.internal:30334): response = { <_MultiThreadedRendezvous object> }
2025-11-11 16:05:01,563 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ODQ0YzdkNTUtNzlhMjk1YjMtYjZkMGJkZGUtMzYzMjk0M2Y=
2025-11-11 16:05:01,591 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ODQ0YzdkNTUtNzlhMjk1YjMtYjZkMGJkZGUtMzYzMjk0M2Y=
2025-11-11 16:05:01,592 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, c6fb4983-b191-477e-b9b4-edbeb3fed7d6, ghrun-l3u76ogmey.auto.internal:30334): creating call state
2025-11-11 16:05:01,592 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, c6fb4983-b191-477e-b9b4-edbeb3fed7d6, ghrun-l3u76ogmey.auto.internal:30334): request = { session_id: "ydb://session/3?node_id=1&id=ODQ0YzdkNTUtNzlhMjk1YjMtYjZkMGJkZGUtMzYzMjk0M2Y=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(10)" } stats_mode: STATS_MODE_NONE }
2025-11-11 16:05:01,593 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, c6fb4983-b191-477e-b9b4-edbeb3fed7d6, ghrun-l3u76ogmey.auto.internal:30334): response = { <_MultiThreadedRendezvous object> }
2025-11-11 16:05:01,728 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YTEyZDJjYmItOGU1OGJmZTYtZDk1M2YyNGItNjhiYzA0YTQ=
2025-11-11 16:05:01,728 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YTEyZDJjYmItOGU1OGJmZTYtZDk1M2YyNGItNjhiYzA0YTQ=
2025-11-11 16:05:01,729 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, c0e1717b-8653-478d-af64-1f90cdb84d9a, ghrun-l3u76ogmey.auto.internal:30334): creating call state
2025-11-11 16:05:01,729 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, c0e1717b-8653-478d-af64-1f90cdb84d9a, ghrun-l3u76ogmey.auto.internal:30334): request = { session_id: "ydb://session/3?node_id=1&id=YTEyZDJjYmItOGU1OGJmZTYtZDk1M2YyNGItNjhiYzA0YTQ=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(11)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(10))" } stats_mode: STATS_MODE_NONE }
2025-11-11 16:05:01,731 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, c0e1717b-8653-478d-af64-1f90cdb84d9a, ghrun-l3u76ogmey.auto.internal:30334): response = { <_MultiThreadedRendezvous object> }
2025-11-11 16:05:02,429 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ODQ0YzdkNTUtNzlhMjk1YjMtYjZkMGJkZGUtMzYzMjk0M2Y=
2025-11-11 16:05:02,430 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ODQ0YzdkNTUtNzlhMjk1YjMtYjZkMGJkZGUtMzYzMjk0M2Y=
2025-11-11 16:05:02,434 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, c78d15bd-0201-4c25-8823-b95d7857132f, ghrun-l3u76ogmey.auto.internal:30334): creating call state
2025-11-11 16:05:02,443 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, c78d15bd-0201-4c25-8823-b95d7857132f, ghrun-l3u76ogmey.auto.internal:30334): request = { session_id: "ydb://session/3?node_id=1&id=ODQ0YzdkNTUtNzlhMjk1YjMtYjZkMGJkZGUtMzYzMjk0M2Y=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(11)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(10))" } stats_mode: STATS_MODE_NONE }
2025-11-11 16:05:02,451 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, c78d15bd-0201-4c25-8823-b95d7857132f, ghrun-l3u76ogmey.auto.internal:30334): response = { <_MultiThreadedRendezvous object> }
2025-11-11 16:05:02,480 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=OTMzZWNhMzItOTA2NWY2OTYtYmYxNDZhM2MtNTg1NzI4ZTY=
2025-11-11 16:05:02,600 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ODQ0YzdkNTUtNzlhMjk1YjMtYjZkMGJkZGUtMzYzMjk0M2Y=
2025-11-11 16:05:02,613 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MWU2ZmE1YzEtNjEyMzdhZi1hMTY0OTY5Yy1mM2MyMmI0ZA==
2025-11-11 16:05:02,625 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YTEyZDJjYmItOGU1OGJmZTYtZDk1M2YyNGItNjhiYzA0YTQ=
2025-11-11 16:05:03,988 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=OGQzNzg3ODUtYTBjZDJjM2EtYWJjOGNmYTMtOThmMWZlZmE=
2025-11-11 16:05:03,994 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OTMzZWNhMzItOTA2NWY2OTYtYmYxNDZhM2MtNTg1NzI4ZTY=
2025-11-11 16:05:04,032 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, f5d94e65-f03b-4b9b-9cca-d85ab52a3a5e, ghrun-l3u76ogmey.auto.internal:30334): creating call state
2025-11-11 16:05:04,032 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, f5d94e65-f03b-4b9b-9cca-d85ab52a3a5e, ghrun-l3u76ogmey.auto.internal:30334): request = { session_id: "ydb://session/3?node_id=1&id=OTMzZWNhMzItOTA2NWY2OTYtYmYxNDZhM2MtNTg1NzI4ZTY=" 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 16:05:04,038 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, f5d94e65-f03b-4b9b-9cca-d85ab52a3a5e, ghrun-l3u76ogmey.auto.internal:30334): response = { <_MultiThreadedRendezvous object> }
2025-11-11 16:05:04,147 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZWVmZjI5OC0zMzc4NjZjYy0yNzc5OGQ4Ny1kYTIzZjQ4Nw==
2025-11-11 16:05:04,147 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ODQ0YzdkNTUtNzlhMjk1YjMtYjZkMGJkZGUtMzYzMjk0M2Y=
2025-11-11 16:05:04,152 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 6d5dbc9e-8c8f-4c99-9ee7-ad3452e0aa12, ghrun-l3u76ogmey.auto.internal:30334): creating call state
2025-11-11 16:05:04,153 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 6d5dbc9e-8c8f-4c99-9ee7-ad3452e0aa12, ghrun-l3u76ogmey.auto.internal:30334): request = { session_id: "ydb://session/3?node_id=1&id=ODQ0YzdkNTUtNzlhMjk1YjMtYjZkMGJkZGUtMzYzMjk0M2Y=" 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 16:05:04,154 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 6d5dbc9e-8c8f-4c99-9ee7-ad3452e0aa12, ghrun-l3u76ogmey.auto.internal:30334): response = { <_MultiThreadedRendezvous object> }
2025-11-11 16:05:06,111 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=OTMzZWNhMzItOTA2NWY2OTYtYmYxNDZhM2MtNTg1NzI4ZTY=
2025-11-11 16:05:06,112 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MWU2ZmE1YzEtNjEyMzdhZi1hMTY0OTY5Yy1mM2MyMmI0ZA==
2025-11-11 16:05:06,112 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, e975c90e-51b5-40a9-835c-292fa1e6a2df, ghrun-l3u76ogmey.auto.internal:30334): creating call state
2025-11-11 16:05:06,113 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, e975c90e-51b5-40a9-835c-292fa1e6a2df, ghrun-l3u76ogmey.auto.internal:30334): request = { session_id: "ydb://session/3?node_id=1&id=MWU2ZmE1YzEtNjEyMzdhZi1hMTY0OTY5Yy1mM2MyMmI0ZA==" 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 16:05:06,136 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, e975c90e-51b5-40a9-835c-292fa1e6a2df, ghrun-l3u76ogmey.auto.internal:30334): response = { <_MultiThreadedRendezvous object> }
2025-11-11 16:05:06,327 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ODQ0YzdkNTUtNzlhMjk1YjMtYjZkMGJkZGUtMzYzMjk0M2Y=
2025-11-11 16:05:07,206 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZjFlOGZiNmMtODU0N2I1NWYtNGJjNzRhODgtM2Q1MDg2ZmY=
2025-11-11 16:05:07,206 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YTEyZDJjYmItOGU1OGJmZTYtZDk1M2YyNGItNjhiYzA0YTQ=
2025-11-11 16:05:07,207 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, aa584593-3471-4316-a585-5ce5ccb413de, ghrun-l3u76ogmey.auto.internal:30334): creating call state
2025-11-11 16:05:07,208 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, aa584593-3471-4316-a585-5ce5ccb413de, ghrun-l3u76ogmey.auto.internal:30334): request = { session_id: "ydb://session/3?node_id=1&id=YTEyZDJjYmItOGU1OGJmZTYtZDk1M2YyNGItNjhiYzA0YTQ=" 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-11 16:05:07,209 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, aa584593-3471-4316-a585-5ce5ccb413de, ghrun-l3u76ogmey.auto.internal:30334): response = { <_MultiThreadedRendezvous object> }
2025-11-11 16:05:07,619 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MWU2ZmE1YzEtNjEyMzdhZi1hMTY0OTY5Yy1mM2MyMmI0ZA==
2025-11-11 16:05:08,952 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YTEyZDJjYmItOGU1OGJmZTYtZDk1M2YyNGItNjhiYzA0YTQ=
2025-11-11 16:05:09,645 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NjNkZjFlZmItM2ZlZDJjNjgtNzliNjIxZTctYjJmZWYxZGQ=
2025-11-11 16:05:09,732 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OGQzNzg3ODUtYTBjZDJjM2EtYWJjOGNmYTMtOThmMWZlZmE=
2025-11-11 16:05:09,733 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 1b7b3eca-2eb4-4dba-b24c-8d56a1bf70d4, ghrun-l3u76ogmey.auto.internal:30334): creating call state
2025-11-11 16:05:09,755 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 1b7b3eca-2eb4-4dba-b24c-8d56a1bf70d4, ghrun-l3u76ogmey.auto.internal:30334): request = { session_id: "ydb://session/3?node_id=1&id=OGQzNzg3ODUtYTBjZDJjM2EtYWJjOGNmYTMtOThmMWZlZmE=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(1)" } stats_mode: STATS_MODE_NONE }
2025-11-11 16:05:09,766 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 1b7b3eca-2eb4-4dba-b24c-8d56a1bf70d4, ghrun-l3u76ogmey.auto.internal:30334): response = { <_MultiThreadedRendezvous object> }
2025-11-11 16:05:09,770 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YzY4ZDI4ZTUtN2VjZjVmZjktZWU1ZTc1MGQtYzUwYjQxMTU=
2025-11-11 16:05:09,859 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZWVmZjI5OC0zMzc4NjZjYy0yNzc5OGQ4Ny1kYTIzZjQ4Nw==
2025-11-11 16:05:09,859 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, b84e9f92-b95c-4e6e-a6cc-a0b4c7a2eb3d, ghrun-l3u76ogmey.auto.internal:30334): creating call state
2025-11-11 16:05:09,863 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, b84e9f92-b95c-4e6e-a6cc-a0b4c7a2eb3d, ghrun-l3u76ogmey.auto.internal:30334): request = { session_id: "ydb://session/3?node_id=1&id=ZWVmZjI5OC0zMzc4NjZjYy0yNzc5OGQ4Ny1kYTIzZjQ4Nw==" 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 16:05:09,864 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, b84e9f92-b95c-4e6e-a6cc-a0b4c7a2eb3d, ghrun-l3u76ogmey.auto.internal:30334): response = { <_MultiThreadedRendezvous object> }
2025-11-11 16:05:09,883 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZDIxNjVhNDgtYzllMjRkLTk1ZDBhOWM2LTYxY2E5MWZi
2025-11-11 16:05:10,009 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OTMzZWNhMzItOTA2NWY2OTYtYmYxNDZhM2MtNTg1NzI4ZTY=
2025-11-11 16:05:10,010 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 145aa71f-776d-4c77-845d-9ceeb7264277, ghrun-l3u76ogmey.auto.internal:30334): creating call state
2025-11-11 16:05:10,011 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 145aa71f-776d-4c77-845d-9ceeb7264277, ghrun-l3u76ogmey.auto.internal:30334): request = { session_id: "ydb://session/3?node_id=1&id=OTMzZWNhMzItOTA2NWY2OTYtYmYxNDZhM2MtNTg1NzI4ZTY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(1)" } stats_mode: STATS_MODE_NONE }
2025-11-11 16:05:10,011 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 145aa71f-776d-4c77-845d-9ceeb7264277, ghrun-l3u76ogmey.auto.internal:30334): response = { <_MultiThreadedRendezvous object> }
2025-11-11 16:05:12,736 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=OGQzNzg3ODUtYTBjZDJjM2EtYWJjOGNmYTMtOThmMWZlZmE=
2025-11-11 16:05:12,737 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ODQ0YzdkNTUtNzlhMjk1YjMtYjZkMGJkZGUtMzYzMjk0M2Y=
2025-11-11 16:05:12,737 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 36390f3c-b811-4ccd-b53d-00158d8b0ebc, ghrun-l3u76ogmey.auto.internal:30334): creating call state
2025-11-11 16:05:12,740 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZWVmZjI5OC0zMzc4NjZjYy0yNzc5OGQ4Ny1kYTIzZjQ4Nw==
2025-11-11 16:05:12,747 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 36390f3c-b811-4ccd-b53d-00158d8b0ebc, ghrun-l3u76ogmey.auto.internal:30334): request = { session_id: "ydb://session/3?node_id=1&id=ODQ0YzdkNTUtNzlhMjk1YjMtYjZkMGJkZGUtMzYzMjk0M2Y=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(2)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(1))" } stats_mode: STATS_MODE_NONE }
2025-11-11 16:05:12,747 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=OTMzZWNhMzItOTA2NWY2OTYtYmYxNDZhM2MtNTg1NzI4ZTY=
2025-11-11 16:05:12,748 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZjFlOGZiNmMtODU0N2I1NWYtNGJjNzRhODgtM2Q1MDg2ZmY=
2025-11-11 16:05:12,766 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 36390f3c-b811-4ccd-b53d-00158d8b0ebc, ghrun-l3u76ogmey.auto.internal:30334): response = { <_MultiThreadedRendezvous object> }
2025-11-11 16:05:12,772 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 7a3c439d-791d-4368-9356-d182a4d616f4, ghrun-l3u76ogmey.auto.internal:30334): creating call state
2025-11-11 16:05:12,773 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MWU2ZmE1YzEtNjEyMzdhZi1hMTY0OTY5Yy1mM2MyMmI0ZA==
2025-11-11 16:05:12,779 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 72434726-d590-4381-85da-3faae6b18510, ghrun-l3u76ogmey.auto.internal:30334): creating call state
2025-11-11 16:05:12,787 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 72434726-d590-4381-85da-3faae6b18510, ghrun-l3u76ogmey.auto.internal:30334): request = { session_id: "ydb://session/3?node_id=1&id=MWU2ZmE1YzEtNjEyMzdhZi1hMTY0OTY5Yy1mM2MyMmI0ZA==" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(2)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(1))" } stats_mode: STATS_MODE_NONE }
2025-11-11 16:05:12,788 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 72434726-d590-4381-85da-3faae6b18510, ghrun-l3u76ogmey.auto.internal:30334): response = { <_MultiThreadedRendezvous object> }
2025-11-11 16:05:12,776 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 7a3c439d-791d-4368-9356-d182a4d616f4, ghrun-l3u76ogmey.auto.internal:30334): request = { session_id: "ydb://session/3?node_id=1&id=ZjFlOGZiNmMtODU0N2I1NWYtNGJjNzRhODgtM2Q1MDg2ZmY=" 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 16:05:12,803 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 7a3c439d-791d-4368-9356-d182a4d616f4, ghrun-l3u76ogmey.auto.internal:30334): response = { <_MultiThreadedRendezvous object> }
2025-11-11 16:05:14,908 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZjFlOGZiNmMtODU0N2I1NWYtNGJjNzRhODgtM2Q1MDg2ZmY=
2025-11-11 16:05:14,921 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ODQ0YzdkNTUtNzlhMjk1YjMtYjZkMGJkZGUtMzYzMjk0M2Y=
2025-11-11 16:05:14,939 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MWU2ZmE1YzEtNjEyMzdhZi1hMTY0OTY5Yy1mM2MyMmI0ZA==
2025-11-11 16:05:14,941 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YTEyZDJjYmItOGU1OGJmZTYtZDk1M2YyNGItNjhiYzA0YTQ=
2025-11-11 16:05:14,947 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 3af32c81-685f-4c22-8e81-8731c028eb88, ghrun-l3u76ogmey.auto.internal:30334): creating call state
2025-11-11 16:05:14,948 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 3af32c81-685f-4c22-8e81-8731c028eb88, ghrun-l3u76ogmey.auto.internal:30334): request = { session_id: "ydb://session/3?node_id=1&id=YTEyZDJjYmItOGU1OGJmZTYtZDk1M2YyNGItNjhiYzA0YTQ=" 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 16:05:14,949 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 3af32c81-685f-4c22-8e81-8731c028eb88, ghrun-l3u76ogmey.auto.internal:30334): response = { <_MultiThreadedRendezvous object> }
2025-11-11 16:05:15,604 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YTEyZDJjYmItOGU1OGJmZTYtZDk1M2YyNGItNjhiYzA0YTQ=
2025-11-11 16:05:15,605 - INFO - root - test_log_deviation: check insert: 20000 15000
2025-11-11 16:05:15,608 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.10
2025-11-11 16:05:15,615 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.10
2025-11-11 16:05:15,616 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/72pg/000725/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:30334', '-d', '/Root', 'workload', 'log', '--path', 'log', 'clean']' in 'None' (waiting)
2025-11-11 16:05:15,617 - DEBUG - ya.test - execute: Command pid: 3299150
2025-11-11 16:05:15,923 - DEBUG - ya.test - _save_outputs: Command (pid 3299150) rc: 0
2025-11-11 16:05:15,923 - DEBUG - ya.test - _save_outputs: Command (pid 3299150) elapsed time (sec): 0.3050994873046875
2025-11-11 16:05:15,924 - DEBUG - ya.test - _save_outputs: Command (pid 3299150) idrss: 0
2025-11-11 16:05:15,924 - DEBUG - ya.test - _save_outputs: Command (pid 3299150) inblock: 0
2025-11-11 16:05:15,924 - DEBUG - ya.test - _save_outputs: Command (pid 3299150) isrss: 0
2025-11-11 16:05:15,924 - DEBUG - ya.test - _save_outputs: Command (pid 3299150) ixrss: 0
2025-11-11 16:05:15,924 - DEBUG - ya.test - _save_outputs: Command (pid 3299150) majflt: 0
2025-11-11 16:05:15,924 - DEBUG - ya.test - _save_outputs: Command (pid 3299150) maxrss: 744152
2025-11-11 16:05:15,925 - DEBUG - ya.test - _save_outputs: Command (pid 3299150) minflt: 3485
2025-11-11 16:05:15,925 - DEBUG - ya.test - _save_outputs: Command (pid 3299150) msgrcv: 0
2025-11-11 16:05:15,925 - DEBUG - ya.test - _save_outputs: Command (pid 3299150) msgsnd: 0
2025-11-11 16:05:15,925 - DEBUG - ya.test - _save_outputs: Command (pid 3299150) nivcsw: 48
2025-11-11 16:05:15,925 - DEBUG - ya.test - _save_outputs: Command (pid 3299150) nsignals: 0
2025-11-11 16:05:15,925 - DEBUG - ya.test - _save_outputs: Command (pid 3299150) nswap: 0
2025-11-11 16:05:15,925 - DEBUG - ya.test - _save_outputs: Command (pid 3299150) nvcsw: 173
2025-11-11 16:05:15,926 - DEBUG - ya.test - _save_outputs: Command (pid 3299150) oublock: 8
2025-11-11 16:05:15,926 - DEBUG - ya.test - _save_outputs: Command (pid 3299150) stime: 0.012874
2025-11-11 16:05:15,926 - DEBUG - ya.test - _save_outputs: Command (pid 3299150) utime: 0.077244
2025-11-11 16:05:15,926 - DEBUG - ya.test - _save_outputs: Command (pid 3299150) wtime: 0.306
2025-11-11 16:05:15,926 - DEBUG - ya.test - _save_outputs: Command (pid 3299150) output:
Remove path log...
Remove path log...Ok

2025-11-11 16:05:15,927 - DEBUG - ya.test - _save_outputs: Command (pid 3299150) errors:

2025-11-11 16:05:15,932 - INFO - ya.test - pytest_runtest_teardown: Test teardown
