2025-11-01 20:01:05,517 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-11-01 20:01:05,517 - INFO - ya.test - pytest_runtest_setup: test_log_deviation[180]
2025-11-01 20:01:05,518 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-11-01 20:01:05,524 - INFO - ya.test - pytest_runtest_setup: Test setup
2025-11-01 20:01:05,527 - INFO - ya.test - pytest_runtest_call: Test call (class_name: test_log_scenario.py::TestLogScenario, test_name: test_log_deviation[180])
2025-11-01 20:01:05,528 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/vv82/002f47/ydb/apps/ydb/ydb
2025-11-01 20:01:05,529 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/vv82/002f47/ydb/apps/ydb/ydb -e grpc://localhost:64916 -d /Root workload log --path log init --path log --store column --ttl 1000 with wait = True
2025-11-01 20:01:05,551 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.5
2025-11-01 20:01:05,552 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.5
2025-11-01 20:01:05,566 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/vv82/002f47/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:64916', '-d', '/Root', 'workload', 'log', '--path', 'log', 'init', '--path', 'log', '--store', 'column', '--ttl', '1000']' in 'None' (waiting)
2025-11-01 20:01:05,736 - DEBUG - ya.test - execute: Command pid: 3334431
2025-11-01 20:01:06,352 - DEBUG - ya.test - _save_outputs: Command (pid 3334431) rc: 0
2025-11-01 20:01:06,352 - DEBUG - ya.test - _save_outputs: Command (pid 3334431) elapsed time (sec): 0.5355095863342285
2025-11-01 20:01:06,352 - DEBUG - ya.test - _save_outputs: Command (pid 3334431) idrss: 0
2025-11-01 20:01:06,353 - DEBUG - ya.test - _save_outputs: Command (pid 3334431) inblock: 0
2025-11-01 20:01:06,353 - DEBUG - ya.test - _save_outputs: Command (pid 3334431) isrss: 0
2025-11-01 20:01:06,353 - DEBUG - ya.test - _save_outputs: Command (pid 3334431) ixrss: 0
2025-11-01 20:01:06,354 - DEBUG - ya.test - _save_outputs: Command (pid 3334431) majflt: 0
2025-11-01 20:01:06,355 - DEBUG - ya.test - _save_outputs: Command (pid 3334431) maxrss: 717124
2025-11-01 20:01:06,358 - DEBUG - ya.test - _save_outputs: Command (pid 3334431) minflt: 3543
2025-11-01 20:01:06,359 - DEBUG - ya.test - _save_outputs: Command (pid 3334431) msgrcv: 0
2025-11-01 20:01:06,359 - DEBUG - ya.test - _save_outputs: Command (pid 3334431) msgsnd: 0
2025-11-01 20:01:06,359 - DEBUG - ya.test - _save_outputs: Command (pid 3334431) nivcsw: 39
2025-11-01 20:01:06,386 - DEBUG - ya.test - _save_outputs: Command (pid 3334431) nsignals: 0
2025-11-01 20:01:06,386 - DEBUG - ya.test - _save_outputs: Command (pid 3334431) nswap: 0
2025-11-01 20:01:06,387 - DEBUG - ya.test - _save_outputs: Command (pid 3334431) nvcsw: 174
2025-11-01 20:01:06,412 - DEBUG - ya.test - _save_outputs: Command (pid 3334431) oublock: 8
2025-11-01 20:01:06,412 - DEBUG - ya.test - _save_outputs: Command (pid 3334431) stime: 0.020555999999999998
2025-11-01 20:01:06,417 - DEBUG - ya.test - _save_outputs: Command (pid 3334431) utime: 0.069893
2025-11-01 20:01:06,417 - DEBUG - ya.test - _save_outputs: Command (pid 3334431) wtime: 0.762
2025-11-01 20:01:06,433 - DEBUG - ya.test - _save_outputs: Command (pid 3334431) output:
Init tables ...
Init tables ...Ok

2025-11-01 20:01:06,434 - DEBUG - ya.test - _save_outputs: Command (pid 3334431) errors:

2025-11-01 20:01:06,434 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NDZiYjk5MGUtZTM2M2YzYTItNTRlMTY0MzYtN2U2NDhiYTk=
2025-11-01 20:01:06,435 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, de4261bd-c59c-4e34-9a9a-dd1bfcc1a00b, ghrun-mjpjznvske.auto.internal:64916): creating call state
2025-11-01 20:01:06,441 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, de4261bd-c59c-4e34-9a9a-dd1bfcc1a00b, ghrun-mjpjznvske.auto.internal:64916): request = { session_id: "ydb://session/3?node_id=1&id=NDZiYjk5MGUtZTM2M2YzYTItNTRlMTY0MzYtN2U2NDhiYTk=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "ALTER OBJECT `//Root/log` (TYPE TABLE) SET (ACTION=UPSERT_OPTIONS, `SCAN_READER_POLICY_NAME`=`SIMPLE`) " } stats_mode: STATS_MODE_NONE }
2025-11-01 20:01:06,448 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, de4261bd-c59c-4e34-9a9a-dd1bfcc1a00b, ghrun-mjpjznvske.auto.internal:64916): response = { <_MultiThreadedRendezvous object> }
2025-11-01 20:01:06,507 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NDZiYjk5MGUtZTM2M2YzYTItNTRlMTY0MzYtN2U2NDhiYTk=
2025-11-01 20:01:06,528 - INFO - root - _insert_rows: YdbWorkloadLog bulk_upsert
2025-11-01 20:01:06,529 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/vv82/002f47/ydb/apps/ydb/ydb -e grpc://localhost:64916 -d /Root workload log --path log run bulk_upsert --seconds 3 --threads 10 --rows 500 --timestamp_deviation 180 with wait = True
2025-11-01 20:01:06,548 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.6
2025-11-01 20:01:06,549 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.6
2025-11-01 20:01:06,579 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/vv82/002f47/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:64916', '-d', '/Root', 'workload', 'log', '--path', 'log', 'run', 'bulk_upsert', '--seconds', '3', '--threads', '10', '--rows', '500', '--timestamp_deviation', '180']' in 'None' (waiting)
2025-11-01 20:01:06,632 - DEBUG - ya.test - execute: Command pid: 3335952
2025-11-01 20:01:10,568 - DEBUG - ya.test - _wait: Process resource usage is not available as process finished before wait4 was called
2025-11-01 20:01:10,569 - DEBUG - ya.test - _save_outputs: Command (pid 3335952) rc: 0
2025-11-01 20:01:10,569 - DEBUG - ya.test - _save_outputs: Command (pid 3335952) elapsed time (sec): 3.9358510971069336
2025-11-01 20:01:10,573 - DEBUG - ya.test - _save_outputs: Command (pid 3335952) wtime: 3.937
2025-11-01 20:01:10,574 - DEBUG - ya.test - _save_outputs: Command (pid 3335952) output:
Window	    Txs	Txs/Sec	Retries	Errors	p50(ms)	p95(ms)	p99(ms)	pMax(ms)
1	     10	10	0	0	563	683	683	683
2	     12	12	0	0	747	787	815	815
3	     23	23	0	0	755	855	887	887

Total	    Txs	Txs/Sec	Retries	Errors	p50(ms)	p95(ms)	p99(ms)	pMax(ms)
3	     45	15	0	0	739	843	887	887

2025-11-01 20:01:10,574 - DEBUG - ya.test - _save_outputs: Command (pid 3335952) errors:

2025-11-01 20:01:10,574 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NzVjNDBkY2QtYzU0MWU3ZDYtY2E2YzI5MTMtZmYzY2JjYzM=
2025-11-01 20:01:10,580 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 9cc2024e-05cb-46c0-b41b-5e5215717735, ghrun-mjpjznvske.auto.internal:64916): creating call state
2025-11-01 20:01:10,581 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 9cc2024e-05cb-46c0-b41b-5e5215717735, ghrun-mjpjznvske.auto.internal:64916): request = { session_id: "ydb://session/3?node_id=1&id=NzVjNDBkY2QtYzU0MWU3ZDYtY2E2YzI5MTMtZmYzY2JjYzM=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "select count(*) as Rows from `log`" } stats_mode: STATS_MODE_NONE }
2025-11-01 20:01:10,583 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 9cc2024e-05cb-46c0-b41b-5e5215717735, ghrun-mjpjznvske.auto.internal:64916): response = { <_MultiThreadedRendezvous object> }
2025-11-01 20:01:11,085 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NzVjNDBkY2QtYzU0MWU3ZDYtY2E2YzI5MTMtZmYzY2JjYzM=
2025-11-01 20:01:11,101 - INFO - root - test_log_deviation: Count rows after insert 22500 before wait
2025-11-01 20:01:11,107 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NTRhNWE5MjAtYjNkNGIwZjItMzZiOGY5NjctOTlkYWQ2NGQ=
2025-11-01 20:01:11,116 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, f6d1c3de-3ba9-44d2-9a3d-cffd4f8f7d46, ghrun-mjpjznvske.auto.internal:64916): creating call state
2025-11-01 20:01:11,117 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, f6d1c3de-3ba9-44d2-9a3d-cffd4f8f7d46, ghrun-mjpjznvske.auto.internal:64916): request = { session_id: "ydb://session/3?node_id=1&id=NTRhNWE5MjAtYjNkNGIwZjItMzZiOGY5NjctOTlkYWQ2NGQ=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "select count(*) as Rows from `log`" } stats_mode: STATS_MODE_NONE }
2025-11-01 20:01:11,132 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, f6d1c3de-3ba9-44d2-9a3d-cffd4f8f7d46, ghrun-mjpjznvske.auto.internal:64916): response = { <_MultiThreadedRendezvous object> }
2025-11-01 20:01:11,423 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NTRhNWE5MjAtYjNkNGIwZjItMzZiOGY5NjctOTlkYWQ2NGQ=
2025-11-01 20:01:11,428 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZWYwODM1YWItOWE5Y2RhYjYtNzZlN2IyNTQtOTQzNjhiNWY=
2025-11-01 20:01:11,428 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, c685250f-aa1f-4c47-bd59-802cad33dd92, ghrun-mjpjznvske.auto.internal:64916): creating call state
2025-11-01 20:01:11,465 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, c685250f-aa1f-4c47-bd59-802cad33dd92, ghrun-mjpjznvske.auto.internal:64916): request = { session_id: "ydb://session/3?node_id=1&id=ZWYwODM1YWItOWE5Y2RhYjYtNzZlN2IyNTQtOTQzNjhiNWY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "select count(*) as Rows from `log`" } stats_mode: STATS_MODE_NONE }
2025-11-01 20:01:11,466 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, c685250f-aa1f-4c47-bd59-802cad33dd92, ghrun-mjpjznvske.auto.internal:64916): response = { <_MultiThreadedRendezvous object> }
2025-11-01 20:01:11,692 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZWYwODM1YWItOWE5Y2RhYjYtNzZlN2IyNTQtOTQzNjhiNWY=
2025-11-01 20:01:11,694 - INFO - root - _insert_rows: YdbWorkloadLog bulk_upsert
2025-11-01 20:01:11,695 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/vv82/002f47/ydb/apps/ydb/ydb -e grpc://localhost:64916 -d /Root workload log --path log run bulk_upsert --seconds 3 --threads 10 --rows 500 --timestamp_deviation 180 with wait = True
2025-11-01 20:01:11,695 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.7
2025-11-01 20:01:11,696 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.7
2025-11-01 20:01:11,696 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/vv82/002f47/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:64916', '-d', '/Root', 'workload', 'log', '--path', 'log', 'run', 'bulk_upsert', '--seconds', '3', '--threads', '10', '--rows', '500', '--timestamp_deviation', '180']' in 'None' (waiting)
2025-11-01 20:01:11,699 - DEBUG - ya.test - execute: Command pid: 3338546
2025-11-01 20:01:11,700 - INFO - root - _insert_rows: YdbWorkloadLog insert
2025-11-01 20:01:11,700 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/vv82/002f47/ydb/apps/ydb/ydb -e grpc://localhost:64916 -d /Root workload log --path log run insert --seconds 3 --threads 10 --rows 500 --timestamp_deviation 180 with wait = True
2025-11-01 20:01:11,701 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.8
2025-11-01 20:01:11,701 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.8
2025-11-01 20:01:11,701 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/vv82/002f47/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:64916', '-d', '/Root', 'workload', 'log', '--path', 'log', 'run', 'insert', '--seconds', '3', '--threads', '10', '--rows', '500', '--timestamp_deviation', '180']' in 'None' (waiting)
2025-11-01 20:01:11,705 - DEBUG - ya.test - execute: Command pid: 3338551
2025-11-01 20:01:11,705 - INFO - root - _insert_rows: YdbWorkloadLog upsert
2025-11-01 20:01:11,743 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/vv82/002f47/ydb/apps/ydb/ydb -e grpc://localhost:64916 -d /Root workload log --path log run upsert --seconds 3 --threads 10 --rows 500 --timestamp_deviation 180 with wait = True
2025-11-01 20:01:11,713 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MTNjM2M0NDktYWE3NGRmMzMtM2QwZWUtYTg4ZWFiN2E=
2025-11-01 20:01:11,767 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 2a9edb3c-3221-41f1-8433-261a61c307db, ghrun-mjpjznvske.auto.internal:64916): creating call state
2025-11-01 20:01:11,775 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 2a9edb3c-3221-41f1-8433-261a61c307db, ghrun-mjpjznvske.auto.internal:64916): request = { session_id: "ydb://session/3?node_id=1&id=MTNjM2M0NDktYWE3NGRmMzMtM2QwZWUtYTg4ZWFiN2E=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-01 20:01:11,767 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MmFiZjcxYWQtNzI0ZmMzZmMtZDEzZDhmMTEtOTU4ODg4NmQ=
2025-11-01 20:01:11,800 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, e017d848-b388-4633-8fd4-5c8486a238bf, ghrun-mjpjznvske.auto.internal:64916): creating call state
2025-11-01 20:01:11,807 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, e017d848-b388-4633-8fd4-5c8486a238bf, ghrun-mjpjznvske.auto.internal:64916): request = { session_id: "ydb://session/3?node_id=1&id=MmFiZjcxYWQtNzI0ZmMzZmMtZDEzZDhmMTEtOTU4ODg4NmQ=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-01 20:01:11,808 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, e017d848-b388-4633-8fd4-5c8486a238bf, ghrun-mjpjznvske.auto.internal:64916): response = { <_MultiThreadedRendezvous object> }
2025-11-01 20:01:11,802 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=M2FmMTljM2QtYjM5ZDY2MjUtMmVmMmE3ZjgtZjliN2EzZTc=
2025-11-01 20:01:11,849 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 63a132b1-ac20-4d32-b3fa-03ae404a85ca, ghrun-mjpjznvske.auto.internal:64916): creating call state
2025-11-01 20:01:11,776 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 2a9edb3c-3221-41f1-8433-261a61c307db, ghrun-mjpjznvske.auto.internal:64916): response = { <_MultiThreadedRendezvous object> }
2025-11-01 20:01:11,767 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.9
2025-11-01 20:01:11,849 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 63a132b1-ac20-4d32-b3fa-03ae404a85ca, ghrun-mjpjznvske.auto.internal:64916): request = { session_id: "ydb://session/3?node_id=1&id=M2FmMTljM2QtYjM5ZDY2MjUtMmVmMmE3ZjgtZjliN2EzZTc=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-01 20:01:11,850 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZjA5Mjc3MzctYzE1MTA4ZDEtMjdiMGM5MzktMjAzYmY2YTY=
2025-11-01 20:01:11,857 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 63a132b1-ac20-4d32-b3fa-03ae404a85ca, ghrun-mjpjznvske.auto.internal:64916): response = { <_MultiThreadedRendezvous object> }
2025-11-01 20:01:11,864 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 2276ee2d-e8c7-408c-a8fd-239d29a99e21, ghrun-mjpjznvske.auto.internal:64916): creating call state
2025-11-01 20:01:11,870 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 2276ee2d-e8c7-408c-a8fd-239d29a99e21, ghrun-mjpjznvske.auto.internal:64916): request = { session_id: "ydb://session/3?node_id=1&id=ZjA5Mjc3MzctYzE1MTA4ZDEtMjdiMGM5MzktMjAzYmY2YTY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-01 20:01:11,937 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 2276ee2d-e8c7-408c-a8fd-239d29a99e21, ghrun-mjpjznvske.auto.internal:64916): response = { <_MultiThreadedRendezvous object> }
2025-11-01 20:01:11,867 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=N2VhZTVhMmYtYjcxMjM0NWEtYWNlNDAzMWQtNWI3ODEzODQ=
2025-11-01 20:01:11,940 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, cc4a238e-ec86-4e5e-9c75-1f6dee11b3cd, ghrun-mjpjznvske.auto.internal:64916): creating call state
2025-11-01 20:01:11,940 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZGEwOGY3ZWEtNWZmOGRlM2EtY2U3N2E5ZjQtZDFlZjQwMA==
2025-11-01 20:01:12,000 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, cbf8f5ca-89de-494c-92f7-abb7012cf54f, ghrun-mjpjznvske.auto.internal:64916): creating call state
2025-11-01 20:01:12,007 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, cbf8f5ca-89de-494c-92f7-abb7012cf54f, ghrun-mjpjznvske.auto.internal:64916): request = { session_id: "ydb://session/3?node_id=1&id=ZGEwOGY3ZWEtNWZmOGRlM2EtY2U3N2E5ZjQtZDFlZjQwMA==" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-01 20:01:12,008 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, cbf8f5ca-89de-494c-92f7-abb7012cf54f, ghrun-mjpjznvske.auto.internal:64916): response = { <_MultiThreadedRendezvous object> }
2025-11-01 20:01:12,001 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NDZiYjk5MGUtZTM2M2YzYTItNTRlMTY0MzYtN2U2NDhiYTk=
2025-11-01 20:01:11,948 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, cc4a238e-ec86-4e5e-9c75-1f6dee11b3cd, ghrun-mjpjznvske.auto.internal:64916): request = { session_id: "ydb://session/3?node_id=1&id=N2VhZTVhMmYtYjcxMjM0NWEtYWNlNDAzMWQtNWI3ODEzODQ=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-01 20:01:12,160 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, cc4a238e-ec86-4e5e-9c75-1f6dee11b3cd, ghrun-mjpjznvske.auto.internal:64916): response = { <_MultiThreadedRendezvous object> }
2025-11-01 20:01:12,115 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, e177a202-4bd8-401c-85ed-d29ade4f99ac, ghrun-mjpjznvske.auto.internal:64916): creating call state
2025-11-01 20:01:12,264 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, e177a202-4bd8-401c-85ed-d29ade4f99ac, ghrun-mjpjznvske.auto.internal:64916): request = { session_id: "ydb://session/3?node_id=1&id=NDZiYjk5MGUtZTM2M2YzYTItNTRlMTY0MzYtN2U2NDhiYTk=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-01 20:01:11,942 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.9
2025-11-01 20:01:12,115 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NzVjNDBkY2QtYzU0MWU3ZDYtY2E2YzI5MTMtZmYzY2JjYzM=
2025-11-01 20:01:12,287 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, e177a202-4bd8-401c-85ed-d29ade4f99ac, ghrun-mjpjznvske.auto.internal:64916): response = { <_MultiThreadedRendezvous object> }
2025-11-01 20:01:12,379 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/vv82/002f47/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:64916', '-d', '/Root', 'workload', 'log', '--path', 'log', 'run', 'upsert', '--seconds', '3', '--threads', '10', '--rows', '500', '--timestamp_deviation', '180']' in 'None' (waiting)
2025-11-01 20:01:12,407 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 16ac6b14-d8bc-4eeb-8e7b-730706436928, ghrun-mjpjznvske.auto.internal:64916): creating call state
2025-11-01 20:01:12,408 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NTRhNWE5MjAtYjNkNGIwZjItMzZiOGY5NjctOTlkYWQ2NGQ=
2025-11-01 20:01:12,415 - DEBUG - ya.test - execute: Command pid: 3339165
2025-11-01 20:01:12,416 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 16ac6b14-d8bc-4eeb-8e7b-730706436928, ghrun-mjpjznvske.auto.internal:64916): request = { session_id: "ydb://session/3?node_id=1&id=NzVjNDBkY2QtYzU0MWU3ZDYtY2E2YzI5MTMtZmYzY2JjYzM=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-01 20:01:12,417 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 87a72055-b1af-4e18-a36e-afeeae502ecc, ghrun-mjpjznvske.auto.internal:64916): creating call state
2025-11-01 20:01:12,418 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZWYwODM1YWItOWE5Y2RhYjYtNzZlN2IyNTQtOTQzNjhiNWY=
2025-11-01 20:01:12,526 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 6e04edb2-a7f8-493f-ba79-4da7fbd52f9e, ghrun-mjpjznvske.auto.internal:64916): creating call state
2025-11-01 20:01:12,525 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 87a72055-b1af-4e18-a36e-afeeae502ecc, ghrun-mjpjznvske.auto.internal:64916): request = { session_id: "ydb://session/3?node_id=1&id=NTRhNWE5MjAtYjNkNGIwZjItMzZiOGY5NjctOTlkYWQ2NGQ=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-01 20:01:12,671 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 87a72055-b1af-4e18-a36e-afeeae502ecc, ghrun-mjpjznvske.auto.internal:64916): response = { <_MultiThreadedRendezvous object> }
2025-11-01 20:01:12,606 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 6e04edb2-a7f8-493f-ba79-4da7fbd52f9e, ghrun-mjpjznvske.auto.internal:64916): request = { session_id: "ydb://session/3?node_id=1&id=ZWYwODM1YWItOWE5Y2RhYjYtNzZlN2IyNTQtOTQzNjhiNWY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-01 20:01:12,524 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 16ac6b14-d8bc-4eeb-8e7b-730706436928, ghrun-mjpjznvske.auto.internal:64916): response = { <_MultiThreadedRendezvous object> }
2025-11-01 20:01:12,701 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 6e04edb2-a7f8-493f-ba79-4da7fbd52f9e, ghrun-mjpjznvske.auto.internal:64916): response = { <_MultiThreadedRendezvous object> }
2025-11-01 20:01:16,080 - DEBUG - ya.test - _wait: Process resource usage is not available as process finished before wait4 was called
2025-11-01 20:01:16,128 - DEBUG - ya.test - _save_outputs: Command (pid 3339165) rc: 0
2025-11-01 20:01:16,128 - DEBUG - ya.test - _save_outputs: Command (pid 3339165) elapsed time (sec): 3.6680076122283936
2025-11-01 20:01:16,129 - DEBUG - ya.test - _save_outputs: Command (pid 3339165) wtime: 3.714
2025-11-01 20:01:16,129 - DEBUG - ya.test - _save_outputs: Command (pid 3339165) output:
Window	    Txs	Txs/Sec	Retries	Errors	p50(ms)	p95(ms)	p99(ms)	pMax(ms)
1	      0	0	0	0	0	0	0	0
2	      0	0	0	10	0	0	0	0
3	      0	0	0	10	0	0	0	0

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

2025-11-01 20:01:16,129 - DEBUG - ya.test - _save_outputs: Command (pid 3339165) errors:

2025-11-01 20:01:16,467 - DEBUG - ya.test - _wait: Process resource usage is not available as process finished before wait4 was called
2025-11-01 20:01:16,468 - DEBUG - ya.test - _save_outputs: Command (pid 3338551) rc: 0
2025-11-01 20:01:16,468 - DEBUG - ya.test - _save_outputs: Command (pid 3338551) elapsed time (sec): 4.742854595184326
2025-11-01 20:01:16,468 - DEBUG - ya.test - _save_outputs: Command (pid 3338551) wtime: 4.766
2025-11-01 20:01:16,482 - DEBUG - ya.test - _save_outputs: Command (pid 3338551) 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	17	0	0	0	0

Total	    Txs	Txs/Sec	Retries	Errors	p50(ms)	p95(ms)	p99(ms)	pMax(ms)
3	      0	0	0	27	0	0	0	0

2025-11-01 20:01:16,483 - DEBUG - ya.test - _save_outputs: Command (pid 3338551) errors:

2025-11-01 20:01:20,636 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MmFiZjcxYWQtNzI0ZmMzZmMtZDEzZDhmMTEtOTU4ODg4NmQ=
2025-11-01 20:01:20,673 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MmFiZjcxYWQtNzI0ZmMzZmMtZDEzZDhmMTEtOTU4ODg4NmQ=
2025-11-01 20:01:20,704 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 4c80b0ca-6feb-4c14-bdd2-f30e26dce991, ghrun-mjpjznvske.auto.internal:64916): creating call state
2025-11-01 20:01:20,708 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 4c80b0ca-6feb-4c14-bdd2-f30e26dce991, ghrun-mjpjznvske.auto.internal:64916): request = { session_id: "ydb://session/3?node_id=1&id=MmFiZjcxYWQtNzI0ZmMzZmMtZDEzZDhmMTEtOTU4ODg4NmQ=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(5)" } stats_mode: STATS_MODE_NONE }
2025-11-01 20:01:20,724 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 4c80b0ca-6feb-4c14-bdd2-f30e26dce991, ghrun-mjpjznvske.auto.internal:64916): response = { <_MultiThreadedRendezvous object> }
2025-11-01 20:01:20,926 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=M2FmMTljM2QtYjM5ZDY2MjUtMmVmMmE3ZjgtZjliN2EzZTc=
2025-11-01 20:01:21,014 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=M2FmMTljM2QtYjM5ZDY2MjUtMmVmMmE3ZjgtZjliN2EzZTc=
2025-11-01 20:01:21,019 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 2fe991c8-eda7-4faa-9158-f0268bf75f37, ghrun-mjpjznvske.auto.internal:64916): creating call state
2025-11-01 20:01:21,020 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 2fe991c8-eda7-4faa-9158-f0268bf75f37, ghrun-mjpjznvske.auto.internal:64916): request = { session_id: "ydb://session/3?node_id=1&id=M2FmMTljM2QtYjM5ZDY2MjUtMmVmMmE3ZjgtZjliN2EzZTc=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(7)" } stats_mode: STATS_MODE_NONE }
2025-11-01 20:01:21,022 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 2fe991c8-eda7-4faa-9158-f0268bf75f37, ghrun-mjpjznvske.auto.internal:64916): response = { <_MultiThreadedRendezvous object> }
2025-11-01 20:01:21,087 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MTNjM2M0NDktYWE3NGRmMzMtM2QwZWUtYTg4ZWFiN2E=
2025-11-01 20:01:21,087 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MTNjM2M0NDktYWE3NGRmMzMtM2QwZWUtYTg4ZWFiN2E=
2025-11-01 20:01:21,088 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 690707c0-c36c-4f4b-b646-017af1bba6b2, ghrun-mjpjznvske.auto.internal:64916): creating call state
2025-11-01 20:01:21,089 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 690707c0-c36c-4f4b-b646-017af1bba6b2, ghrun-mjpjznvske.auto.internal:64916): request = { session_id: "ydb://session/3?node_id=1&id=MTNjM2M0NDktYWE3NGRmMzMtM2QwZWUtYTg4ZWFiN2E=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(6)" } stats_mode: STATS_MODE_NONE }
2025-11-01 20:01:21,109 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 690707c0-c36c-4f4b-b646-017af1bba6b2, ghrun-mjpjznvske.auto.internal:64916): response = { <_MultiThreadedRendezvous object> }
2025-11-01 20:01:21,136 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZjA5Mjc3MzctYzE1MTA4ZDEtMjdiMGM5MzktMjAzYmY2YTY=
2025-11-01 20:01:21,137 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZjA5Mjc3MzctYzE1MTA4ZDEtMjdiMGM5MzktMjAzYmY2YTY=
2025-11-01 20:01:21,138 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 6c90f813-bf8b-44ef-a576-9bc566008271, ghrun-mjpjznvske.auto.internal:64916): creating call state
2025-11-01 20:01:21,140 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 6c90f813-bf8b-44ef-a576-9bc566008271, ghrun-mjpjznvske.auto.internal:64916): request = { session_id: "ydb://session/3?node_id=1&id=ZjA5Mjc3MzctYzE1MTA4ZDEtMjdiMGM5MzktMjAzYmY2YTY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(6)" } stats_mode: STATS_MODE_NONE }
2025-11-01 20:01:21,145 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 6c90f813-bf8b-44ef-a576-9bc566008271, ghrun-mjpjznvske.auto.internal:64916): response = { <_MultiThreadedRendezvous object> }
2025-11-01 20:01:21,218 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZGEwOGY3ZWEtNWZmOGRlM2EtY2U3N2E5ZjQtZDFlZjQwMA==
2025-11-01 20:01:21,219 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZGEwOGY3ZWEtNWZmOGRlM2EtY2U3N2E5ZjQtZDFlZjQwMA==
2025-11-01 20:01:21,220 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, ed332be0-b24b-4dbf-acbf-e5ee91e7ece5, ghrun-mjpjznvske.auto.internal:64916): creating call state
2025-11-01 20:01:21,223 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, ed332be0-b24b-4dbf-acbf-e5ee91e7ece5, ghrun-mjpjznvske.auto.internal:64916): request = { session_id: "ydb://session/3?node_id=1&id=ZGEwOGY3ZWEtNWZmOGRlM2EtY2U3N2E5ZjQtZDFlZjQwMA==" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(6)" } stats_mode: STATS_MODE_NONE }
2025-11-01 20:01:21,224 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, ed332be0-b24b-4dbf-acbf-e5ee91e7ece5, ghrun-mjpjznvske.auto.internal:64916): response = { <_MultiThreadedRendezvous object> }
2025-11-01 20:01:21,389 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=N2VhZTVhMmYtYjcxMjM0NWEtYWNlNDAzMWQtNWI3ODEzODQ=
2025-11-01 20:01:21,398 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=N2VhZTVhMmYtYjcxMjM0NWEtYWNlNDAzMWQtNWI3ODEzODQ=
2025-11-01 20:01:21,408 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 66969090-3df3-4fa0-859b-2d7057eb1bc6, ghrun-mjpjznvske.auto.internal:64916): creating call state
2025-11-01 20:01:21,409 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 66969090-3df3-4fa0-859b-2d7057eb1bc6, ghrun-mjpjznvske.auto.internal:64916): request = { session_id: "ydb://session/3?node_id=1&id=N2VhZTVhMmYtYjcxMjM0NWEtYWNlNDAzMWQtNWI3ODEzODQ=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(10)" } stats_mode: STATS_MODE_NONE }
2025-11-01 20:01:21,411 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 66969090-3df3-4fa0-859b-2d7057eb1bc6, ghrun-mjpjznvske.auto.internal:64916): response = { <_MultiThreadedRendezvous object> }
2025-11-01 20:01:21,429 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NDZiYjk5MGUtZTM2M2YzYTItNTRlMTY0MzYtN2U2NDhiYTk=
2025-11-01 20:01:21,430 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NDZiYjk5MGUtZTM2M2YzYTItNTRlMTY0MzYtN2U2NDhiYTk=
2025-11-01 20:01:21,430 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, b7669dba-5f08-47b4-92a0-a2f4ef94b30b, ghrun-mjpjznvske.auto.internal:64916): creating call state
2025-11-01 20:01:21,431 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, b7669dba-5f08-47b4-92a0-a2f4ef94b30b, ghrun-mjpjznvske.auto.internal:64916): request = { session_id: "ydb://session/3?node_id=1&id=NDZiYjk5MGUtZTM2M2YzYTItNTRlMTY0MzYtN2U2NDhiYTk=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(7)" } stats_mode: STATS_MODE_NONE }
2025-11-01 20:01:21,433 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, b7669dba-5f08-47b4-92a0-a2f4ef94b30b, ghrun-mjpjznvske.auto.internal:64916): response = { <_MultiThreadedRendezvous object> }
2025-11-01 20:01:22,047 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NzVjNDBkY2QtYzU0MWU3ZDYtY2E2YzI5MTMtZmYzY2JjYzM=
2025-11-01 20:01:22,047 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NzVjNDBkY2QtYzU0MWU3ZDYtY2E2YzI5MTMtZmYzY2JjYzM=
2025-11-01 20:01:22,048 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 036caccc-a649-4ee7-bed3-2fea9b47ceed, ghrun-mjpjznvske.auto.internal:64916): creating call state
2025-11-01 20:01:22,048 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 036caccc-a649-4ee7-bed3-2fea9b47ceed, ghrun-mjpjznvske.auto.internal:64916): request = { session_id: "ydb://session/3?node_id=1&id=NzVjNDBkY2QtYzU0MWU3ZDYtY2E2YzI5MTMtZmYzY2JjYzM=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(9)" } stats_mode: STATS_MODE_NONE }
2025-11-01 20:01:22,062 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 036caccc-a649-4ee7-bed3-2fea9b47ceed, ghrun-mjpjznvske.auto.internal:64916): response = { <_MultiThreadedRendezvous object> }
2025-11-01 20:01:22,128 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZWYwODM1YWItOWE5Y2RhYjYtNzZlN2IyNTQtOTQzNjhiNWY=
2025-11-01 20:01:22,140 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZWYwODM1YWItOWE5Y2RhYjYtNzZlN2IyNTQtOTQzNjhiNWY=
2025-11-01 20:01:22,144 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 6f087b1b-e840-4e52-b66d-70bad15498db, ghrun-mjpjznvske.auto.internal:64916): creating call state
2025-11-01 20:01:22,159 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 6f087b1b-e840-4e52-b66d-70bad15498db, ghrun-mjpjznvske.auto.internal:64916): request = { session_id: "ydb://session/3?node_id=1&id=ZWYwODM1YWItOWE5Y2RhYjYtNzZlN2IyNTQtOTQzNjhiNWY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(10)" } stats_mode: STATS_MODE_NONE }
2025-11-01 20:01:22,163 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 6f087b1b-e840-4e52-b66d-70bad15498db, ghrun-mjpjznvske.auto.internal:64916): response = { <_MultiThreadedRendezvous object> }
2025-11-01 20:01:22,265 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NTRhNWE5MjAtYjNkNGIwZjItMzZiOGY5NjctOTlkYWQ2NGQ=
2025-11-01 20:01:22,276 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-11-01 20:01:22,329 - 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-01 20:01:22,310 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NTRhNWE5MjAtYjNkNGIwZjItMzZiOGY5NjctOTlkYWQ2NGQ=
2025-11-01 20:01:22,348 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database /Root
2025-11-01 20:01:22,364 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, f1197d68-6049-4364-bfe7-77a3b67b060a, ghrun-mjpjznvske.auto.internal:64916): creating call state
2025-11-01 20:01:22,364 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, 8cbab14f-4364-4786-be14-0f47d9b4989c, localhost:7640): creating call state
2025-11-01 20:01:22,381 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, 8cbab14f-4364-4786-be14-0f47d9b4989c, localhost:7640): request = { database: "/Root" }
2025-11-01 20:01:22,383 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, f1197d68-6049-4364-bfe7-77a3b67b060a, ghrun-mjpjznvske.auto.internal:64916): request = { session_id: "ydb://session/3?node_id=1&id=NTRhNWE5MjAtYjNkNGIwZjItMzZiOGY5NjctOTlkYWQ2NGQ=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(10)" } stats_mode: STATS_MODE_NONE }
2025-11-01 20:01:22,394 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, 8cbab14f-4364-4786-be14-0f47d9b4989c, localhost:7640): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Discovery.ListEndpointsResult] { endpoints { address: "ghrun-mjpjznvske.auto.internal" port: 7640 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-01 20:01:22,397 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, f1197d68-6049-4364-bfe7-77a3b67b060a, ghrun-mjpjznvske.auto.internal:64916): response = { <_MultiThreadedRendezvous object> }
2025-11-01 20:01:22,473 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Resolved endpoints for database /Root: DiscoveryResult <self_location: 1, endpoints [<Endpoint ghrun-mjpjznvske.auto.internal:7640, location 1, ssl: False>]>
2025-11-01 20:01:22,475 - DEBUG - ydb.connection - close: Closing channel for endpoint localhost:7640
2025-11-01 20:01:22,810 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=N2VhZTVhMmYtYjcxMjM0NWEtYWNlNDAzMWQtNWI3ODEzODQ=
2025-11-01 20:01:22,816 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=N2VhZTVhMmYtYjcxMjM0NWEtYWNlNDAzMWQtNWI3ODEzODQ=
2025-11-01 20:01:22,852 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 3866d66e-0436-497d-879e-fcb3fe61f43c, ghrun-mjpjznvske.auto.internal:64916): creating call state
2025-11-01 20:01:22,860 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 3866d66e-0436-497d-879e-fcb3fe61f43c, ghrun-mjpjznvske.auto.internal:64916): request = { session_id: "ydb://session/3?node_id=1&id=N2VhZTVhMmYtYjcxMjM0NWEtYWNlNDAzMWQtNWI3ODEzODQ=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(10)" } stats_mode: STATS_MODE_NONE }
2025-11-01 20:01:22,885 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 3866d66e-0436-497d-879e-fcb3fe61f43c, ghrun-mjpjznvske.auto.internal:64916): response = { <_MultiThreadedRendezvous object> }
2025-11-01 20:01:23,121 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZWYwODM1YWItOWE5Y2RhYjYtNzZlN2IyNTQtOTQzNjhiNWY=
2025-11-01 20:01:23,150 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZWYwODM1YWItOWE5Y2RhYjYtNzZlN2IyNTQtOTQzNjhiNWY=
2025-11-01 20:01:23,150 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 7f83f904-758c-4bd9-a565-31514dff724a, ghrun-mjpjznvske.auto.internal:64916): creating call state
2025-11-01 20:01:23,159 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 7f83f904-758c-4bd9-a565-31514dff724a, ghrun-mjpjznvske.auto.internal:64916): request = { session_id: "ydb://session/3?node_id=1&id=ZWYwODM1YWItOWE5Y2RhYjYtNzZlN2IyNTQtOTQzNjhiNWY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(10)" } stats_mode: STATS_MODE_NONE }
2025-11-01 20:01:23,166 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 7f83f904-758c-4bd9-a565-31514dff724a, ghrun-mjpjznvske.auto.internal:64916): response = { <_MultiThreadedRendezvous object> }
2025-11-01 20:01:23,349 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NTRhNWE5MjAtYjNkNGIwZjItMzZiOGY5NjctOTlkYWQ2NGQ=
2025-11-01 20:01:23,350 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NTRhNWE5MjAtYjNkNGIwZjItMzZiOGY5NjctOTlkYWQ2NGQ=
2025-11-01 20:01:23,351 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, a5a0bb17-62de-44a6-b489-02988684e010, ghrun-mjpjznvske.auto.internal:64916): creating call state
2025-11-01 20:01:23,351 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, a5a0bb17-62de-44a6-b489-02988684e010, ghrun-mjpjznvske.auto.internal:64916): request = { session_id: "ydb://session/3?node_id=1&id=NTRhNWE5MjAtYjNkNGIwZjItMzZiOGY5NjctOTlkYWQ2NGQ=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(10)" } stats_mode: STATS_MODE_NONE }
2025-11-01 20:01:23,356 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, a5a0bb17-62de-44a6-b489-02988684e010, ghrun-mjpjznvske.auto.internal:64916): response = { <_MultiThreadedRendezvous object> }
2025-11-01 20:01:23,501 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NzVjNDBkY2QtYzU0MWU3ZDYtY2E2YzI5MTMtZmYzY2JjYzM=
2025-11-01 20:01:23,546 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NzVjNDBkY2QtYzU0MWU3ZDYtY2E2YzI5MTMtZmYzY2JjYzM=
2025-11-01 20:01:23,562 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 9c54d19a-a690-4d57-8647-2fe08e735bcf, ghrun-mjpjznvske.auto.internal:64916): creating call state
2025-11-01 20:01:23,565 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 9c54d19a-a690-4d57-8647-2fe08e735bcf, ghrun-mjpjznvske.auto.internal:64916): request = { session_id: "ydb://session/3?node_id=1&id=NzVjNDBkY2QtYzU0MWU3ZDYtY2E2YzI5MTMtZmYzY2JjYzM=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(9)" } stats_mode: STATS_MODE_NONE }
2025-11-01 20:01:23,566 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 9c54d19a-a690-4d57-8647-2fe08e735bcf, ghrun-mjpjznvske.auto.internal:64916): response = { <_MultiThreadedRendezvous object> }
2025-11-01 20:01:23,661 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=N2VhZTVhMmYtYjcxMjM0NWEtYWNlNDAzMWQtNWI3ODEzODQ=
2025-11-01 20:01:23,661 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=N2VhZTVhMmYtYjcxMjM0NWEtYWNlNDAzMWQtNWI3ODEzODQ=
2025-11-01 20:01:23,662 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 7d670408-d1bd-49cf-b3d3-4dfac5d8267f, ghrun-mjpjznvske.auto.internal:64916): creating call state
2025-11-01 20:01:23,676 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZWYwODM1YWItOWE5Y2RhYjYtNzZlN2IyNTQtOTQzNjhiNWY=
2025-11-01 20:01:23,739 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 7d670408-d1bd-49cf-b3d3-4dfac5d8267f, ghrun-mjpjznvske.auto.internal:64916): request = { session_id: "ydb://session/3?node_id=1&id=N2VhZTVhMmYtYjcxMjM0NWEtYWNlNDAzMWQtNWI3ODEzODQ=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(11)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(10))" } stats_mode: STATS_MODE_NONE }
2025-11-01 20:01:23,746 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 7d670408-d1bd-49cf-b3d3-4dfac5d8267f, ghrun-mjpjznvske.auto.internal:64916): response = { <_MultiThreadedRendezvous object> }
2025-11-01 20:01:23,745 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZWYwODM1YWItOWE5Y2RhYjYtNzZlN2IyNTQtOTQzNjhiNWY=
2025-11-01 20:01:23,791 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 6fcda286-fb1c-4192-b3fe-b7540d5911ab, ghrun-mjpjznvske.auto.internal:64916): creating call state
2025-11-01 20:01:23,794 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 6fcda286-fb1c-4192-b3fe-b7540d5911ab, ghrun-mjpjznvske.auto.internal:64916): request = { session_id: "ydb://session/3?node_id=1&id=ZWYwODM1YWItOWE5Y2RhYjYtNzZlN2IyNTQtOTQzNjhiNWY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(11)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(10))" } stats_mode: STATS_MODE_NONE }
2025-11-01 20:01:23,796 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 6fcda286-fb1c-4192-b3fe-b7540d5911ab, ghrun-mjpjznvske.auto.internal:64916): response = { <_MultiThreadedRendezvous object> }
2025-11-01 20:01:24,300 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=N2VhZTVhMmYtYjcxMjM0NWEtYWNlNDAzMWQtNWI3ODEzODQ=
2025-11-01 20:01:24,301 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NzVjNDBkY2QtYzU0MWU3ZDYtY2E2YzI5MTMtZmYzY2JjYzM=
2025-11-01 20:01:24,303 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=N2VhZTVhMmYtYjcxMjM0NWEtYWNlNDAzMWQtNWI3ODEzODQ=
2025-11-01 20:01:24,303 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 86fe5608-3405-4371-9082-6ad083ac44eb, ghrun-mjpjznvske.auto.internal:64916): creating call state
2025-11-01 20:01:24,315 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 86fe5608-3405-4371-9082-6ad083ac44eb, ghrun-mjpjznvske.auto.internal:64916): request = { session_id: "ydb://session/3?node_id=1&id=N2VhZTVhMmYtYjcxMjM0NWEtYWNlNDAzMWQtNWI3ODEzODQ=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(10)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(9))" } stats_mode: STATS_MODE_NONE }
2025-11-01 20:01:24,309 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZWYwODM1YWItOWE5Y2RhYjYtNzZlN2IyNTQtOTQzNjhiNWY=
2025-11-01 20:01:24,316 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 86fe5608-3405-4371-9082-6ad083ac44eb, ghrun-mjpjznvske.auto.internal:64916): response = { <_MultiThreadedRendezvous object> }
2025-11-01 20:01:24,631 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NTRhNWE5MjAtYjNkNGIwZjItMzZiOGY5NjctOTlkYWQ2NGQ=
2025-11-01 20:01:24,634 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NzVjNDBkY2QtYzU0MWU3ZDYtY2E2YzI5MTMtZmYzY2JjYzM=
2025-11-01 20:01:24,635 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 39415ec0-2087-4b2d-93a7-c246bb047c5e, ghrun-mjpjznvske.auto.internal:64916): creating call state
2025-11-01 20:01:24,641 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 39415ec0-2087-4b2d-93a7-c246bb047c5e, ghrun-mjpjznvske.auto.internal:64916): request = { session_id: "ydb://session/3?node_id=1&id=NzVjNDBkY2QtYzU0MWU3ZDYtY2E2YzI5MTMtZmYzY2JjYzM=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(11)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(10))" } stats_mode: STATS_MODE_NONE }
2025-11-01 20:01:24,643 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 39415ec0-2087-4b2d-93a7-c246bb047c5e, ghrun-mjpjznvske.auto.internal:64916): response = { <_MultiThreadedRendezvous object> }
2025-11-01 20:01:24,645 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NDZiYjk5MGUtZTM2M2YzYTItNTRlMTY0MzYtN2U2NDhiYTk=
2025-11-01 20:01:24,729 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZWYwODM1YWItOWE5Y2RhYjYtNzZlN2IyNTQtOTQzNjhiNWY=
2025-11-01 20:01:24,736 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, cb197b0f-3a5d-4903-8f33-ac5103315536, ghrun-mjpjznvske.auto.internal:64916): creating call state
2025-11-01 20:01:24,739 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, cb197b0f-3a5d-4903-8f33-ac5103315536, ghrun-mjpjznvske.auto.internal:64916): request = { session_id: "ydb://session/3?node_id=1&id=ZWYwODM1YWItOWE5Y2RhYjYtNzZlN2IyNTQtOTQzNjhiNWY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(7)" } stats_mode: STATS_MODE_NONE }
2025-11-01 20:01:24,743 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, cb197b0f-3a5d-4903-8f33-ac5103315536, ghrun-mjpjznvske.auto.internal:64916): response = { <_MultiThreadedRendezvous object> }
2025-11-01 20:01:24,765 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=M2FmMTljM2QtYjM5ZDY2MjUtMmVmMmE3ZjgtZjliN2EzZTc=
2025-11-01 20:01:24,777 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MTNjM2M0NDktYWE3NGRmMzMtM2QwZWUtYTg4ZWFiN2E=
2025-11-01 20:01:24,794 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MmFiZjcxYWQtNzI0ZmMzZmMtZDEzZDhmMTEtOTU4ODg4NmQ=
2025-11-01 20:01:24,795 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NzVjNDBkY2QtYzU0MWU3ZDYtY2E2YzI5MTMtZmYzY2JjYzM=
2025-11-01 20:01:24,795 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=N2VhZTVhMmYtYjcxMjM0NWEtYWNlNDAzMWQtNWI3ODEzODQ=
2025-11-01 20:01:24,803 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZjA5Mjc3MzctYzE1MTA4ZDEtMjdiMGM5MzktMjAzYmY2YTY=
2025-11-01 20:01:24,805 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZGEwOGY3ZWEtNWZmOGRlM2EtY2U3N2E5ZjQtZDFlZjQwMA==
2025-11-01 20:01:24,850 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NTRhNWE5MjAtYjNkNGIwZjItMzZiOGY5NjctOTlkYWQ2NGQ=
2025-11-01 20:01:25,027 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 5edbe08b-f98b-436c-aa47-44ada099b8a3, ghrun-mjpjznvske.auto.internal:64916): creating call state
2025-11-01 20:01:25,028 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 5edbe08b-f98b-436c-aa47-44ada099b8a3, ghrun-mjpjznvske.auto.internal:64916): request = { session_id: "ydb://session/3?node_id=1&id=NTRhNWE5MjAtYjNkNGIwZjItMzZiOGY5NjctOTlkYWQ2NGQ=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(7)" } stats_mode: STATS_MODE_NONE }
2025-11-01 20:01:25,028 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NDZiYjk5MGUtZTM2M2YzYTItNTRlMTY0MzYtN2U2NDhiYTk=
2025-11-01 20:01:25,037 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 5edbe08b-f98b-436c-aa47-44ada099b8a3, ghrun-mjpjznvske.auto.internal:64916): response = { <_MultiThreadedRendezvous object> }
2025-11-01 20:01:25,068 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZWYwODM1YWItOWE5Y2RhYjYtNzZlN2IyNTQtOTQzNjhiNWY=
2025-11-01 20:01:25,094 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 54aa8054-8def-4b18-91c5-72ec89da044b, ghrun-mjpjznvske.auto.internal:64916): creating call state
2025-11-01 20:01:25,095 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=M2FmMTljM2QtYjM5ZDY2MjUtMmVmMmE3ZjgtZjliN2EzZTc=
2025-11-01 20:01:25,171 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NTRhNWE5MjAtYjNkNGIwZjItMzZiOGY5NjctOTlkYWQ2NGQ=
2025-11-01 20:01:25,193 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 54aa8054-8def-4b18-91c5-72ec89da044b, ghrun-mjpjznvske.auto.internal:64916): request = { session_id: "ydb://session/3?node_id=1&id=NDZiYjk5MGUtZTM2M2YzYTItNTRlMTY0MzYtN2U2NDhiYTk=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(6)" } stats_mode: STATS_MODE_NONE }
2025-11-01 20:01:25,196 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 051a99d6-d656-443e-a9a5-9cf36082c28b, ghrun-mjpjznvske.auto.internal:64916): creating call state
2025-11-01 20:01:25,204 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 051a99d6-d656-443e-a9a5-9cf36082c28b, ghrun-mjpjznvske.auto.internal:64916): request = { session_id: "ydb://session/3?node_id=1&id=M2FmMTljM2QtYjM5ZDY2MjUtMmVmMmE3ZjgtZjliN2EzZTc=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(5)" } stats_mode: STATS_MODE_NONE }
2025-11-01 20:01:25,205 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 051a99d6-d656-443e-a9a5-9cf36082c28b, ghrun-mjpjznvske.auto.internal:64916): response = { <_MultiThreadedRendezvous object> }
2025-11-01 20:01:25,196 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MTNjM2M0NDktYWE3NGRmMzMtM2QwZWUtYTg4ZWFiN2E=
2025-11-01 20:01:25,199 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 54aa8054-8def-4b18-91c5-72ec89da044b, ghrun-mjpjznvske.auto.internal:64916): response = { <_MultiThreadedRendezvous object> }
2025-11-01 20:01:25,244 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, a80e51ec-cfc7-4407-b2d4-9d85c8ed5379, ghrun-mjpjznvske.auto.internal:64916): creating call state
2025-11-01 20:01:25,314 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, a80e51ec-cfc7-4407-b2d4-9d85c8ed5379, ghrun-mjpjznvske.auto.internal:64916): request = { session_id: "ydb://session/3?node_id=1&id=MTNjM2M0NDktYWE3NGRmMzMtM2QwZWUtYTg4ZWFiN2E=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(6)" } stats_mode: STATS_MODE_NONE }
2025-11-01 20:01:25,366 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, a80e51ec-cfc7-4407-b2d4-9d85c8ed5379, ghrun-mjpjznvske.auto.internal:64916): response = { <_MultiThreadedRendezvous object> }
2025-11-01 20:01:25,248 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MmFiZjcxYWQtNzI0ZmMzZmMtZDEzZDhmMTEtOTU4ODg4NmQ=
2025-11-01 20:01:25,412 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, dbf62111-0cbd-40df-85ed-d891c7ecfaa0, ghrun-mjpjznvske.auto.internal:64916): creating call state
2025-11-01 20:01:25,413 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, dbf62111-0cbd-40df-85ed-d891c7ecfaa0, ghrun-mjpjznvske.auto.internal:64916): request = { session_id: "ydb://session/3?node_id=1&id=MmFiZjcxYWQtNzI0ZmMzZmMtZDEzZDhmMTEtOTU4ODg4NmQ=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(6)" } stats_mode: STATS_MODE_NONE }
2025-11-01 20:01:25,415 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NzVjNDBkY2QtYzU0MWU3ZDYtY2E2YzI5MTMtZmYzY2JjYzM=
2025-11-01 20:01:25,419 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, dbf62111-0cbd-40df-85ed-d891c7ecfaa0, ghrun-mjpjznvske.auto.internal:64916): response = { <_MultiThreadedRendezvous object> }
2025-11-01 20:01:25,438 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 87d1a301-46af-47fe-ac47-43da90f83cc9, ghrun-mjpjznvske.auto.internal:64916): creating call state
2025-11-01 20:01:25,440 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=N2VhZTVhMmYtYjcxMjM0NWEtYWNlNDAzMWQtNWI3ODEzODQ=
2025-11-01 20:01:25,484 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, a5a54761-b75b-43a4-b9d7-fb096fd4069a, ghrun-mjpjznvske.auto.internal:64916): creating call state
2025-11-01 20:01:25,485 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, a5a54761-b75b-43a4-b9d7-fb096fd4069a, ghrun-mjpjznvske.auto.internal:64916): request = { session_id: "ydb://session/3?node_id=1&id=N2VhZTVhMmYtYjcxMjM0NWEtYWNlNDAzMWQtNWI3ODEzODQ=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(8)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(7))" } stats_mode: STATS_MODE_NONE }
2025-11-01 20:01:25,497 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, a5a54761-b75b-43a4-b9d7-fb096fd4069a, ghrun-mjpjznvske.auto.internal:64916): response = { <_MultiThreadedRendezvous object> }
2025-11-01 20:01:25,455 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 87d1a301-46af-47fe-ac47-43da90f83cc9, ghrun-mjpjznvske.auto.internal:64916): request = { session_id: "ydb://session/3?node_id=1&id=NzVjNDBkY2QtYzU0MWU3ZDYtY2E2YzI5MTMtZmYzY2JjYzM=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(8)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(7))" } stats_mode: STATS_MODE_NONE }
2025-11-01 20:01:25,599 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 87d1a301-46af-47fe-ac47-43da90f83cc9, ghrun-mjpjznvske.auto.internal:64916): response = { <_MultiThreadedRendezvous object> }
2025-11-01 20:01:26,236 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NDZiYjk5MGUtZTM2M2YzYTItNTRlMTY0MzYtN2U2NDhiYTk=
2025-11-01 20:01:26,236 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZjA5Mjc3MzctYzE1MTA4ZDEtMjdiMGM5MzktMjAzYmY2YTY=
2025-11-01 20:01:26,237 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 593d9242-0758-478e-88f0-860636bba024, ghrun-mjpjznvske.auto.internal:64916): creating call state
2025-11-01 20:01:26,237 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 593d9242-0758-478e-88f0-860636bba024, ghrun-mjpjznvske.auto.internal:64916): request = { session_id: "ydb://session/3?node_id=1&id=ZjA5Mjc3MzctYzE1MTA4ZDEtMjdiMGM5MzktMjAzYmY2YTY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(7)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(6))" } stats_mode: STATS_MODE_NONE }
2025-11-01 20:01:26,239 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 593d9242-0758-478e-88f0-860636bba024, ghrun-mjpjznvske.auto.internal:64916): response = { <_MultiThreadedRendezvous object> }
2025-11-01 20:01:26,240 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MTNjM2M0NDktYWE3NGRmMzMtM2QwZWUtYTg4ZWFiN2E=
2025-11-01 20:01:26,245 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MmFiZjcxYWQtNzI0ZmMzZmMtZDEzZDhmMTEtOTU4ODg4NmQ=
2025-11-01 20:01:26,249 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZGEwOGY3ZWEtNWZmOGRlM2EtY2U3N2E5ZjQtZDFlZjQwMA==
2025-11-01 20:01:26,252 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=N2VhZTVhMmYtYjcxMjM0NWEtYWNlNDAzMWQtNWI3ODEzODQ=
2025-11-01 20:01:26,253 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NzVjNDBkY2QtYzU0MWU3ZDYtY2E2YzI5MTMtZmYzY2JjYzM=
2025-11-01 20:01:26,259 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=M2FmMTljM2QtYjM5ZDY2MjUtMmVmMmE3ZjgtZjliN2EzZTc=
2025-11-01 20:01:26,262 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 540e9740-f89a-4c9b-a24e-707d59b37ce2, ghrun-mjpjznvske.auto.internal:64916): creating call state
2025-11-01 20:01:26,262 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZWYwODM1YWItOWE5Y2RhYjYtNzZlN2IyNTQtOTQzNjhiNWY=
2025-11-01 20:01:26,313 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 540e9740-f89a-4c9b-a24e-707d59b37ce2, ghrun-mjpjznvske.auto.internal:64916): request = { session_id: "ydb://session/3?node_id=1&id=ZGEwOGY3ZWEtNWZmOGRlM2EtY2U3N2E5ZjQtZDFlZjQwMA==" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(7)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(6))" } stats_mode: STATS_MODE_NONE }
2025-11-01 20:01:26,348 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NTRhNWE5MjAtYjNkNGIwZjItMzZiOGY5NjctOTlkYWQ2NGQ=
2025-11-01 20:01:26,347 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, c349a1f4-10bc-4dbb-9289-6a71c1751060, ghrun-mjpjznvske.auto.internal:64916): creating call state
2025-11-01 20:01:26,349 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 540e9740-f89a-4c9b-a24e-707d59b37ce2, ghrun-mjpjznvske.auto.internal:64916): response = { <_MultiThreadedRendezvous object> }
2025-11-01 20:01:26,350 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 08a5efc8-2887-4251-a834-138093387d8c, ghrun-mjpjznvske.auto.internal:64916): creating call state
2025-11-01 20:01:26,356 - DEBUG - ya.test - _wait: Process resource usage is not available as process finished before wait4 was called
2025-11-01 20:01:26,396 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, c349a1f4-10bc-4dbb-9289-6a71c1751060, ghrun-mjpjznvske.auto.internal:64916): request = { session_id: "ydb://session/3?node_id=1&id=ZWYwODM1YWItOWE5Y2RhYjYtNzZlN2IyNTQtOTQzNjhiNWY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(7)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(6))" } stats_mode: STATS_MODE_NONE }
2025-11-01 20:01:26,411 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 08a5efc8-2887-4251-a834-138093387d8c, ghrun-mjpjznvske.auto.internal:64916): request = { session_id: "ydb://session/3?node_id=1&id=NTRhNWE5MjAtYjNkNGIwZjItMzZiOGY5NjctOTlkYWQ2NGQ=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(6)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(5))" } stats_mode: STATS_MODE_NONE }
2025-11-01 20:01:26,420 - DEBUG - ya.test - _save_outputs: Command (pid 3338546) rc: 0
2025-11-01 20:01:26,431 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, c349a1f4-10bc-4dbb-9289-6a71c1751060, ghrun-mjpjznvske.auto.internal:64916): response = { <_MultiThreadedRendezvous object> }
2025-11-01 20:01:26,500 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 08a5efc8-2887-4251-a834-138093387d8c, ghrun-mjpjznvske.auto.internal:64916): response = { <_MultiThreadedRendezvous object> }
2025-11-01 20:01:26,500 - DEBUG - ya.test - _save_outputs: Command (pid 3338546) elapsed time (sec): 14.712179183959961
2025-11-01 20:01:26,516 - DEBUG - ya.test - _save_outputs: Command (pid 3338546) wtime: 14.715
2025-11-01 20:01:26,517 - DEBUG - ya.test - _save_outputs: Command (pid 3338546) output:
Window	    Txs	Txs/Sec	Retries	Errors	p50(ms)	p95(ms)	p99(ms)	pMax(ms)
1	      0	0	0	0	0	0	0	0
2	      0	0	0	0	0	0	0	0
3	     10	10	0	0	13311	14335	14335	14335

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

2025-11-01 20:01:26,518 - DEBUG - ya.test - _save_outputs: Command (pid 3338546) errors:

2025-11-01 20:01:27,310 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZWYwODM1YWItOWE5Y2RhYjYtNzZlN2IyNTQtOTQzNjhiNWY=
2025-11-01 20:01:27,315 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZGEwOGY3ZWEtNWZmOGRlM2EtY2U3N2E5ZjQtZDFlZjQwMA==
2025-11-01 20:01:27,332 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZjA5Mjc3MzctYzE1MTA4ZDEtMjdiMGM5MzktMjAzYmY2YTY=
2025-11-01 20:01:27,415 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NTRhNWE5MjAtYjNkNGIwZjItMzZiOGY5NjctOTlkYWQ2NGQ=
2025-11-01 20:01:27,439 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NDZiYjk5MGUtZTM2M2YzYTItNTRlMTY0MzYtN2U2NDhiYTk=
2025-11-01 20:01:27,440 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, e2b1239b-1d6c-4bd5-a696-d3c3a8745b70, ghrun-mjpjznvske.auto.internal:64916): creating call state
2025-11-01 20:01:27,480 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, e2b1239b-1d6c-4bd5-a696-d3c3a8745b70, ghrun-mjpjznvske.auto.internal:64916): request = { session_id: "ydb://session/3?node_id=1&id=NDZiYjk5MGUtZTM2M2YzYTItNTRlMTY0MzYtN2U2NDhiYTk=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "select count(*) as Rows from `log`" } stats_mode: STATS_MODE_NONE }
2025-11-01 20:01:27,481 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, e2b1239b-1d6c-4bd5-a696-d3c3a8745b70, ghrun-mjpjznvske.auto.internal:64916): response = { <_MultiThreadedRendezvous object> }
2025-11-01 20:01:27,733 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NDZiYjk5MGUtZTM2M2YzYTItNTRlMTY0MzYtN2U2NDhiYTk=
2025-11-01 20:01:27,736 - INFO - root - test_log_deviation: check insert: 27500 22500
2025-11-01 20:01:27,738 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.10
2025-11-01 20:01:27,778 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.10
2025-11-01 20:01:27,807 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/vv82/002f47/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:64916', '-d', '/Root', 'workload', 'log', '--path', 'log', 'clean']' in 'None' (waiting)
2025-11-01 20:01:27,809 - DEBUG - ya.test - execute: Command pid: 3350103
2025-11-01 20:01:28,096 - DEBUG - ya.test - _save_outputs: Command (pid 3350103) rc: 0
2025-11-01 20:01:28,096 - DEBUG - ya.test - _save_outputs: Command (pid 3350103) elapsed time (sec): 0.2807633876800537
2025-11-01 20:01:28,096 - DEBUG - ya.test - _save_outputs: Command (pid 3350103) idrss: 0
2025-11-01 20:01:28,097 - DEBUG - ya.test - _save_outputs: Command (pid 3350103) inblock: 0
2025-11-01 20:01:28,097 - DEBUG - ya.test - _save_outputs: Command (pid 3350103) isrss: 0
2025-11-01 20:01:28,097 - DEBUG - ya.test - _save_outputs: Command (pid 3350103) ixrss: 0
2025-11-01 20:01:28,101 - DEBUG - ya.test - _save_outputs: Command (pid 3350103) majflt: 0
2025-11-01 20:01:28,101 - DEBUG - ya.test - _save_outputs: Command (pid 3350103) maxrss: 717124
2025-11-01 20:01:28,102 - DEBUG - ya.test - _save_outputs: Command (pid 3350103) minflt: 3537
2025-11-01 20:01:28,113 - DEBUG - ya.test - _save_outputs: Command (pid 3350103) msgrcv: 0
2025-11-01 20:01:28,113 - DEBUG - ya.test - _save_outputs: Command (pid 3350103) msgsnd: 0
2025-11-01 20:01:28,113 - DEBUG - ya.test - _save_outputs: Command (pid 3350103) nivcsw: 37
2025-11-01 20:01:28,113 - DEBUG - ya.test - _save_outputs: Command (pid 3350103) nsignals: 0
2025-11-01 20:01:28,113 - DEBUG - ya.test - _save_outputs: Command (pid 3350103) nswap: 0
2025-11-01 20:01:28,114 - DEBUG - ya.test - _save_outputs: Command (pid 3350103) nvcsw: 174
2025-11-01 20:01:28,139 - DEBUG - ya.test - _save_outputs: Command (pid 3350103) oublock: 8
2025-11-01 20:01:28,201 - DEBUG - ya.test - _save_outputs: Command (pid 3350103) stime: 0.021499
2025-11-01 20:01:28,201 - DEBUG - ya.test - _save_outputs: Command (pid 3350103) utime: 0.060197999999999995
2025-11-01 20:01:28,201 - DEBUG - ya.test - _save_outputs: Command (pid 3350103) wtime: 0.286
2025-11-01 20:01:28,201 - DEBUG - ya.test - _save_outputs: Command (pid 3350103) output:
Remove path log...
Remove path log...Ok

2025-11-01 20:01:28,201 - DEBUG - ya.test - _save_outputs: Command (pid 3350103) errors:

2025-11-01 20:01:28,206 - INFO - ya.test - pytest_runtest_teardown: Test teardown
