2025-11-14 06:50:50,374 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-11-14 06:50:50,374 - INFO - ya.test - pytest_runtest_setup: test_database_admin_cant_change_database_admin_group[remove-other-admin]
2025-11-14 06:50:50,374 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-11-14 06:50:50,374 - INFO - ya.test - pytest_runtest_setup: Test setup
2025-11-14 06:50:50,444 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/rl7h/0030a4/ydb/apps/ydbd/ydbd
2025-11-14 06:50:50,446 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/23042
2025-11-14 06:50:50,449 - INFO - ydb.tests.library.fixtures - ydb_cluster: setup ydb_cluster for __tests__.test_user_administration
2025-11-14 06:50:50,449 - INFO - ydb.tests.library.fixtures - ydb_cluster: setup ydb_cluster as local
2025-11-14 06:50:50,450 - DEBUG - ydb.tests.library.harness.kikimr_runner - start: Working directory: /home/runner/.ya/build/build_root/rl7h/0030a4/r3tmp/kikimr_cluster_mc0ph5s8
2025-11-14 06:50:50,488 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/rl7h/0030a4/ydb/apps/ydbd/ydbd
2025-11-14 06:50:50,489 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/8713
2025-11-14 06:50:50,489 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/4527
2025-11-14 06:50:50,489 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/6788
2025-11-14 06:50:50,490 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/25894
2025-11-14 06:50:50,490 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: CFG_DIR_PATH="/home/runner/.ya/build/build_root/rl7h/0030a4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk15/testing_out_stuff/test_user_administration.py.test_database_admin_cant_change_database_admin_group.remove-other-admin/cluster/kikimr_configs"
2025-11-14 06:50:50,490 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: Final command: /home/runner/.ya/build/build_root/rl7h/0030a4/ydb/apps/ydbd/ydbd server --suppress-version-check --yaml-config=$CFG_DIR_PATH/config.yaml --node=1 --log-file-name=/home/runner/.ya/build/build_root/rl7h/0030a4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk15/testing_out_stuff/test_user_administration.py.test_database_admin_cant_change_database_admin_group.remove-other-admin/cluster/node_1/logfile_1gdj3e8m.log --grpc-port=8713 --mon-port=4527 --ic-port=23042
2025-11-14 06:50:50,491 - DEBUG - ydb.tests.library.harness.kikimr_runner - format_pdisk: Formatting pdisk SectorMap:1:64 on node localhost:8713/1, disk_size 68719476736
2025-11-14 06:50:50,492 - DEBUG - ya.test - execute: Executing '('/home/runner/.ya/build/build_root/rl7h/0030a4/ydb/apps/ydbd/ydbd', 'server', '--suppress-version-check', '--yaml-config=/home/runner/.ya/build/build_root/rl7h/0030a4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk15/testing_out_stuff/test_user_administration.py.test_database_admin_cant_change_database_admin_group.remove-other-admin/cluster/kikimr_configs/config.yaml', '--node=1', '--log-file-name=/home/runner/.ya/build/build_root/rl7h/0030a4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk15/testing_out_stuff/test_user_administration.py.test_database_admin_cant_change_database_admin_group.remove-other-admin/cluster/node_1/logfile_1gdj3e8m.log', '--grpc-port=8713', '--mon-port=4527', '--ic-port=23042')' in '/home/runner/.ya/build/build_root/rl7h/0030a4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk15/testing_out_stuff/test_user_administration.py.test_database_admin_cant_change_database_admin_group.remove-other-admin/cluster/node_1' (no wait)
2025-11-14 06:50:50,493 - DEBUG - ya.test - execute: Command pid: 1285776
2025-11-14 06:50:50,494 - INFO - ydb.tests.library.harness.kikimr_runner - start: Started node localhost:8713/1
2025-11-14 06:50:52,294 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/rl7h/0030a4/ydb/apps/ydbd/ydbd
2025-11-14 06:50:52,295 - DEBUG - ydb.tests.library.harness.kikimr_runner - __call_kikimr_new_cli: Executing command = ['/home/runner/.ya/build/build_root/rl7h/0030a4/ydb/apps/ydbd/ydbd', '--server=grpc://localhost:8713', 'admin', 'blobstorage', 'config', 'invoke', '--proto=Command {\n  DefineHostConfig {\n    HostConfigId: 1\n    Drive {\n      Path: "SectorMap:1:64"\n    }\n  }\n}\nCommand {\n  DefineBox {\n    BoxId: 1\n    Host {\n      Key {\n        Fqdn: "localhost"\n        IcPort: 23042\n      }\n      HostConfigId: 1\n    }\n  }\n}\n']
2025-11-14 06:50:52,296 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydbd.out
2025-11-14 06:50:52,296 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydbd.err
2025-11-14 06:50:52,296 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/rl7h/0030a4/ydb/apps/ydbd/ydbd', '--server=grpc://localhost:8713', 'admin', 'blobstorage', 'config', 'invoke', '--proto=Command {\n  DefineHostConfig {\n    HostConfigId: 1\n    Drive {\n      Path: "SectorMap:1:64"\n    }\n  }\n}\nCommand {\n  DefineBox {\n    BoxId: 1\n    Host {\n      Key {\n        Fqdn: "localhost"\n        IcPort: 23042\n      }\n      HostConfigId: 1\n    }\n  }\n}\n']' in 'None' (waiting)
2025-11-14 06:50:52,297 - DEBUG - ya.test - execute: Command pid: 1288261
2025-11-14 06:50:52,677 - DEBUG - ya.test - _save_outputs: Command (pid 1288261) rc: 0
2025-11-14 06:50:52,678 - DEBUG - ya.test - _save_outputs: Command (pid 1288261) elapsed time (sec): 0.37902331352233887
2025-11-14 06:50:52,678 - DEBUG - ya.test - _save_outputs: Command (pid 1288261) idrss: 0
2025-11-14 06:50:52,678 - DEBUG - ya.test - _save_outputs: Command (pid 1288261) inblock: 0
2025-11-14 06:50:52,678 - DEBUG - ya.test - _save_outputs: Command (pid 1288261) isrss: 0
2025-11-14 06:50:52,678 - DEBUG - ya.test - _save_outputs: Command (pid 1288261) ixrss: 0
2025-11-14 06:50:52,679 - DEBUG - ya.test - _save_outputs: Command (pid 1288261) majflt: 0
2025-11-14 06:50:52,679 - DEBUG - ya.test - _save_outputs: Command (pid 1288261) maxrss: 525792
2025-11-14 06:50:52,679 - DEBUG - ya.test - _save_outputs: Command (pid 1288261) minflt: 19682
2025-11-14 06:50:52,679 - DEBUG - ya.test - _save_outputs: Command (pid 1288261) msgrcv: 0
2025-11-14 06:50:52,679 - DEBUG - ya.test - _save_outputs: Command (pid 1288261) msgsnd: 0
2025-11-14 06:50:52,679 - DEBUG - ya.test - _save_outputs: Command (pid 1288261) nivcsw: 19
2025-11-14 06:50:52,680 - DEBUG - ya.test - _save_outputs: Command (pid 1288261) nsignals: 0
2025-11-14 06:50:52,680 - DEBUG - ya.test - _save_outputs: Command (pid 1288261) nswap: 0
2025-11-14 06:50:52,680 - DEBUG - ya.test - _save_outputs: Command (pid 1288261) nvcsw: 125
2025-11-14 06:50:52,680 - DEBUG - ya.test - _save_outputs: Command (pid 1288261) oublock: 8
2025-11-14 06:50:52,680 - DEBUG - ya.test - _save_outputs: Command (pid 1288261) stime: 0.23030099999999998
2025-11-14 06:50:52,680 - DEBUG - ya.test - _save_outputs: Command (pid 1288261) utime: 0.103238
2025-11-14 06:50:52,680 - DEBUG - ya.test - _save_outputs: Command (pid 1288261) wtime: 0.38
2025-11-14 06:50:52,681 - DEBUG - ya.test - _save_outputs: Command (pid 1288261) output:
Status {
  Success: true
}
Status {
  Success: true
}
Success: true
ConfigTxSeqNo: 5

2025-11-14 06:50:52,681 - DEBUG - ya.test - _save_outputs: Command (pid 1288261) errors:

2025-11-14 06:50:52,682 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/rl7h/0030a4/ydb/apps/ydbd/ydbd
2025-11-14 06:50:52,682 - DEBUG - ydb.tests.library.harness.kikimr_runner - __call_kikimr_new_cli: Executing command = ['/home/runner/.ya/build/build_root/rl7h/0030a4/ydb/apps/ydbd/ydbd', '--server=grpc://localhost:8713', 'admin', 'blobstorage', 'config', 'invoke', '--proto=Command {\n  DefineStoragePool {\n    BoxId: 1\n    StoragePoolId: 1\n    Name: "dynamic_storage_pool:1"\n    ErasureSpecies: "none"\n    VDiskKind: "Default"\n    Kind: "hdd"\n    NumGroups: 2\n    PDiskFilter {\n      Property {\n        Type: ROT\n      }\n      Property {\n        Kind: 0\n      }\n    }\n  }\n}\n']
2025-11-14 06:50:52,683 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydbd.out.0
2025-11-14 06:50:52,683 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydbd.err.0
2025-11-14 06:50:52,684 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/rl7h/0030a4/ydb/apps/ydbd/ydbd', '--server=grpc://localhost:8713', 'admin', 'blobstorage', 'config', 'invoke', '--proto=Command {\n  DefineStoragePool {\n    BoxId: 1\n    StoragePoolId: 1\n    Name: "dynamic_storage_pool:1"\n    ErasureSpecies: "none"\n    VDiskKind: "Default"\n    Kind: "hdd"\n    NumGroups: 2\n    PDiskFilter {\n      Property {\n        Type: ROT\n      }\n      Property {\n        Kind: 0\n      }\n    }\n  }\n}\n']' in 'None' (waiting)
2025-11-14 06:50:52,685 - DEBUG - ya.test - execute: Command pid: 1288820
2025-11-14 06:50:53,067 - DEBUG - ya.test - _save_outputs: Command (pid 1288820) rc: 0
2025-11-14 06:50:53,067 - DEBUG - ya.test - _save_outputs: Command (pid 1288820) elapsed time (sec): 0.3811929225921631
2025-11-14 06:50:53,067 - DEBUG - ya.test - _save_outputs: Command (pid 1288820) idrss: 0
2025-11-14 06:50:53,068 - DEBUG - ya.test - _save_outputs: Command (pid 1288820) inblock: 0
2025-11-14 06:50:53,068 - DEBUG - ya.test - _save_outputs: Command (pid 1288820) isrss: 0
2025-11-14 06:50:53,068 - DEBUG - ya.test - _save_outputs: Command (pid 1288820) ixrss: 0
2025-11-14 06:50:53,068 - DEBUG - ya.test - _save_outputs: Command (pid 1288820) majflt: 0
2025-11-14 06:50:53,068 - DEBUG - ya.test - _save_outputs: Command (pid 1288820) maxrss: 525780
2025-11-14 06:50:53,068 - DEBUG - ya.test - _save_outputs: Command (pid 1288820) minflt: 19680
2025-11-14 06:50:53,069 - DEBUG - ya.test - _save_outputs: Command (pid 1288820) msgrcv: 0
2025-11-14 06:50:53,069 - DEBUG - ya.test - _save_outputs: Command (pid 1288820) msgsnd: 0
2025-11-14 06:50:53,069 - DEBUG - ya.test - _save_outputs: Command (pid 1288820) nivcsw: 9
2025-11-14 06:50:53,069 - DEBUG - ya.test - _save_outputs: Command (pid 1288820) nsignals: 0
2025-11-14 06:50:53,069 - DEBUG - ya.test - _save_outputs: Command (pid 1288820) nswap: 0
2025-11-14 06:50:53,069 - DEBUG - ya.test - _save_outputs: Command (pid 1288820) nvcsw: 133
2025-11-14 06:50:53,069 - DEBUG - ya.test - _save_outputs: Command (pid 1288820) oublock: 8
2025-11-14 06:50:53,069 - DEBUG - ya.test - _save_outputs: Command (pid 1288820) stime: 0.253355
2025-11-14 06:50:53,070 - DEBUG - ya.test - _save_outputs: Command (pid 1288820) utime: 0.084451
2025-11-14 06:50:53,070 - DEBUG - ya.test - _save_outputs: Command (pid 1288820) wtime: 0.382
2025-11-14 06:50:53,070 - DEBUG - ya.test - _save_outputs: Command (pid 1288820) output:
Status {
  Success: true
}
Success: true
ConfigTxSeqNo: 6

2025-11-14 06:50:53,070 - DEBUG - ya.test - _save_outputs: Command (pid 1288820) errors:

2025-11-14 06:50:53,070 - INFO - ydb.tests.library.harness.kikimr_runner - __run: Binding storage pools to domain Root: {'dynamic_storage_pool:1': 'hdd'}
2025-11-14 06:50:53,086 - INFO - ydb.tests.library.harness.kikimr_runner - __run: Cluster started and initialized
2025-11-14 06:50:53,094 - 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')]
2025-11-14 06:50:53,096 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-11-14 06:50:53,099 - 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')]
2025-11-14 06:50:53,099 - DEBUG - ydb.table.SessionPool - subscribe: Active session queue is empty, subscribe waiter for a session
2025-11-14 06:50:53,103 - DEBUG - ydb.table.SessionPool - subscribe: Subscribe waiter <Future at 0x7f0033cbdf50 state=pending>
2025-11-14 06:50:53,104 - DEBUG - ydb.table.SessionPool - subscribe: Session pool is not large enough (active_count < size: 0 < 100). will create a new session.
2025-11-14 06:50:53,105 - DEBUG - ydb.table.SessionPool - _create: Created session <ydb.table.Session object at 0x7f0033c929a0>
2025-11-14 06:50:53,105 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7f0033c929a0>
2025-11-14 06:50:53,106 - ERROR - ydb.table.SessionPool - _on_session_create: Failed to create session. Put event to a delayed queue. Reason: Couldn't find valid connection
2025-11-14 06:50:53,109 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database /Root
2025-11-14 06:50:53,109 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, 2d0d2960-cf78-40dc-a4d0-b0ec39d35716, localhost:8713): creating call state
2025-11-14 06:50:53,110 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, 2d0d2960-cf78-40dc-a4d0-b0ec39d35716, localhost:8713): request = { database: "/Root" }
2025-11-14 06:50:53,113 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, 2d0d2960-cf78-40dc-a4d0-b0ec39d35716, localhost:8713): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Discovery.ListEndpointsResult] { endpoints { address: "ghrun-iuibjpfjoa.auto.internal" port: 8713 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-14 06:50:53,114 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Resolved endpoints for database /Root: DiscoveryResult <self_location: 1, endpoints [<Endpoint ghrun-iuibjpfjoa.auto.internal:8713, location 1, ssl: False>]>
2025-11-14 06:50:53,114 - 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')]
2025-11-14 06:50:53,118 - INFO - ydb.connection - close: Closing channel for endpoint localhost:8713
2025-11-14 06:50:53,119 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7f0033c929a0>
2025-11-14 06:50:53,120 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, c4f615cd-ed7f-40f0-9712-867fea96c552, ghrun-iuibjpfjoa.auto.internal:8713): creating call state
2025-11-14 06:50:53,120 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, c4f615cd-ed7f-40f0-9712-867fea96c552, ghrun-iuibjpfjoa.auto.internal:8713): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-11-14 06:50:53,122 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, c4f615cd-ed7f-40f0-9712-867fea96c552, ghrun-iuibjpfjoa.auto.internal:8713): on response callback started
2025-11-14 06:50:53,123 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, c4f615cd-ed7f-40f0-9712-867fea96c552, ghrun-iuibjpfjoa.auto.internal:8713): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=1&id=YWYyNTUyODItYzliNzE3YjQtZjEyYTFiYzItZDZhMTY5MjQ=" } } } }
2025-11-14 06:50:53,123 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7f0033c929a0>
2025-11-14 06:50:53,124 - DEBUG - ydb.table.SessionPool - put: Replying to waiter with a session <ydb.table.Session object at 0x7f0033c929a0>
2025-11-14 06:50:53,124 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, c4f615cd-ed7f-40f0-9712-867fea96c552, ghrun-iuibjpfjoa.auto.internal:8713): on response callback success
2025-11-14 06:50:53,124 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteSchemeQuery, 0a76ea95-e071-4af3-b9e6-2ee53811da1b, ghrun-iuibjpfjoa.auto.internal:8713): creating call state
2025-11-14 06:50:53,125 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteSchemeQuery, 0a76ea95-e071-4af3-b9e6-2ee53811da1b, ghrun-iuibjpfjoa.auto.internal:8713): request = { session_id: "ydb://session/3?node_id=1&id=YWYyNTUyODItYzliNzE3YjQtZjEyYTFiYzItZDZhMTY5MjQ=" yql_text: "create user clusteradmin password \'1234\'" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:50:53,135 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteSchemeQuery, 0a76ea95-e071-4af3-b9e6-2ee53811da1b, ghrun-iuibjpfjoa.auto.internal:8713): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:50:53,135 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7f0033c929a0>
2025-11-14 06:50:53,136 - INFO - ydb.connection - close: Closing channel for endpoint localhost:8713
2025-11-14 06:50:53,313 - INFO - ydb.connection - close: Closing channel for endpoint ghrun-iuibjpfjoa.auto.internal:8713
2025-11-14 06:50:53,321 - INFO - ydb.pool.Discovery - run: Successfully terminated discovery process
2025-11-14 06:50:53,322 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - remove_database: /Root/test_user_administration
2025-11-14 06:50:53,322 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_send_op: /Root/test_user_administration: send console operation, token root@builtin
2025-11-14 06:50:53,324 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_send_op: /Root/test_user_administration: response from console: RemoveTenantResponse {
  Response {
    operation {
      ready: true
      status: NOT_FOUND
      issues {
        message: "Database \'/Root/test_user_administration\' doesn\'t exist"
        severity: 1
      }
    }
  }
}
Status {
  Code: NOT_FOUND
  Reason: "Database \'/Root/test_user_administration\' doesn\'t exist"
}

2025-11-14 06:50:53,324 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_op: /Root/test_user_administration: wait console operation done
2025-11-14 06:50:53,829 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_op: /Root/test_user_administration: console operation done
2025-11-14 06:50:53,830 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_tenant_gone: /Root/test_user_administration: wait tenant gone
2025-11-14 06:50:53,831 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_tenant_gone: /Root/test_user_administration: tenant gone
2025-11-14 06:50:53,832 - DEBUG - ydb.tests.library.fixtures - ydb_database_ctx: create database /Root/test_user_administration: create path and declare internals
2025-11-14 06:50:54,340 - DEBUG - ydb.tests.library.fixtures - ydb_database_ctx: create database /Root/test_user_administration: start nodes and construct internals
2025-11-14 06:50:54,341 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/rl7h/0030a4/ydb/apps/ydbd/ydbd
2025-11-14 06:50:54,341 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/9668
2025-11-14 06:50:54,341 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/3831
2025-11-14 06:50:54,342 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/22805
2025-11-14 06:50:54,342 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/13273
2025-11-14 06:50:54,342 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/61725
2025-11-14 06:50:54,343 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: CFG_DIR_PATH="/home/runner/.ya/build/build_root/rl7h/0030a4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk15/testing_out_stuff/test_user_administration.py.test_database_admin_cant_change_database_admin_group.remove-other-admin/cluster/kikimr_configs"
2025-11-14 06:50:54,343 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: Final command: /home/runner/.ya/build/build_root/rl7h/0030a4/ydb/apps/ydbd/ydbd server --suppress-version-check --yaml-config=$CFG_DIR_PATH/config.yaml --node-broker=localhost:8713 --tenant=/Root/test_user_administration --log-file-name=/home/runner/.ya/build/build_root/rl7h/0030a4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk15/testing_out_stuff/test_user_administration.py.test_database_admin_cant_change_database_admin_group.remove-other-admin/cluster/slot_1/logfile_qmzjpk61.log --grpc-port=9668 --mon-port=3831 --ic-port=22805
2025-11-14 06:50:54,344 - DEBUG - ya.test - execute: Executing '('/home/runner/.ya/build/build_root/rl7h/0030a4/ydb/apps/ydbd/ydbd', 'server', '--suppress-version-check', '--yaml-config=/home/runner/.ya/build/build_root/rl7h/0030a4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk15/testing_out_stuff/test_user_administration.py.test_database_admin_cant_change_database_admin_group.remove-other-admin/cluster/kikimr_configs/config.yaml', '--node-broker=localhost:8713', '--tenant=/Root/test_user_administration', '--log-file-name=/home/runner/.ya/build/build_root/rl7h/0030a4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk15/testing_out_stuff/test_user_administration.py.test_database_admin_cant_change_database_admin_group.remove-other-admin/cluster/slot_1/logfile_qmzjpk61.log', '--grpc-port=9668', '--mon-port=3831', '--ic-port=22805')' in '/home/runner/.ya/build/build_root/rl7h/0030a4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk15/testing_out_stuff/test_user_administration.py.test_database_admin_cant_change_database_admin_group.remove-other-admin/cluster/slot_1' (no wait)
2025-11-14 06:50:54,346 - DEBUG - ya.test - execute: Command pid: 1291238
2025-11-14 06:50:54,347 - INFO - ydb.tests.library.harness.kikimr_runner - start: Started node localhost:9668/1
2025-11-14 06:50:54,347 - DEBUG - ydb.tests.library.fixtures - ydb_database_ctx: create database /Root/test_user_administration: wait construction done
2025-11-14 06:53:05,402 - DEBUG - ydb.tests.library.fixtures - ydb_database_ctx: create database /Root/test_user_administration: database up
2025-11-14 06:53:05,403 - 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')]
2025-11-14 06:53:05,405 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-11-14 06:53:05,407 - DEBUG - ydb.table.SessionPool - subscribe: Active session queue is empty, subscribe waiter for a session
2025-11-14 06:53:05,407 - 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')]
2025-11-14 06:53:05,407 - DEBUG - ydb.table.SessionPool - subscribe: Subscribe waiter <Future at 0x7f0033e85230 state=pending>
2025-11-14 06:53:05,410 - DEBUG - ydb.table.SessionPool - subscribe: Session pool is not large enough (active_count < size: 0 < 100). will create a new session.
2025-11-14 06:53:05,411 - DEBUG - ydb.table.SessionPool - _create: Created session <ydb.table.Session object at 0x7f0033e8e0e0>
2025-11-14 06:53:05,412 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7f0033e8e0e0>
2025-11-14 06:53:05,413 - ERROR - ydb.table.SessionPool - _on_session_create: Failed to create session. Put event to a delayed queue. Reason: Couldn't find valid connection
2025-11-14 06:53:05,414 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database /Root/test_user_administration
2025-11-14 06:53:05,414 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, 5f7d4f4d-2374-4560-8d89-7e56ccfe1447, localhost:8713): creating call state
2025-11-14 06:53:05,414 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, 5f7d4f4d-2374-4560-8d89-7e56ccfe1447, localhost:8713): request = { database: "/Root/test_user_administration" }
2025-11-14 06:53:05,418 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, 5f7d4f4d-2374-4560-8d89-7e56ccfe1447, localhost:8713): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Discovery.ListEndpointsResult] { endpoints { address: "ghrun-iuibjpfjoa.auto.internal" port: 9668 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" node_id: 50000 } self_location: "1" } } } }
2025-11-14 06:53:05,418 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Resolved endpoints for database /Root/test_user_administration: DiscoveryResult <self_location: 1, endpoints [<Endpoint ghrun-iuibjpfjoa.auto.internal:9668, location , ssl: False>]>
2025-11-14 06:53:05,419 - 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')]
2025-11-14 06:53:05,422 - INFO - ydb.connection - close: Closing channel for endpoint localhost:8713
2025-11-14 06:53:05,423 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7f0033e8e0e0>
2025-11-14 06:53:05,424 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, eb401fa0-dfbb-4fd6-a667-cfb266a8062a, ghrun-iuibjpfjoa.auto.internal:9668): creating call state
2025-11-14 06:53:05,425 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, eb401fa0-dfbb-4fd6-a667-cfb266a8062a, ghrun-iuibjpfjoa.auto.internal:9668): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-11-14 06:53:05,427 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, eb401fa0-dfbb-4fd6-a667-cfb266a8062a, ghrun-iuibjpfjoa.auto.internal:9668): on response callback started
2025-11-14 06:53:05,428 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, eb401fa0-dfbb-4fd6-a667-cfb266a8062a, ghrun-iuibjpfjoa.auto.internal:9668): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=50000&id=ODdjNmFlZGYtNDg5YzFjYWItMjA3YzFmNzctNWM4Y2JhZGY=" } } } }
2025-11-14 06:53:05,429 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7f0033e8e0e0>
2025-11-14 06:53:05,429 - DEBUG - ydb.table.SessionPool - put: Replying to waiter with a session <ydb.table.Session object at 0x7f0033e8e0e0>
2025-11-14 06:53:05,430 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteSchemeQuery, 67cfc4d1-1c05-4435-8549-c51c2355561d, ghrun-iuibjpfjoa.auto.internal:9668): creating call state
2025-11-14 06:53:05,430 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, eb401fa0-dfbb-4fd6-a667-cfb266a8062a, ghrun-iuibjpfjoa.auto.internal:9668): on response callback success
2025-11-14 06:53:05,431 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteSchemeQuery, 67cfc4d1-1c05-4435-8549-c51c2355561d, ghrun-iuibjpfjoa.auto.internal:9668): request = { session_id: "ydb://session/3?node_id=50000&id=ODdjNmFlZGYtNDg5YzFjYWItMjA3YzFmNzctNWM4Y2JhZGY=" yql_text: "create user dbadmin password \'1234\'" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:53:05,444 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteSchemeQuery, 67cfc4d1-1c05-4435-8549-c51c2355561d, ghrun-iuibjpfjoa.auto.internal:9668): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:53:05,445 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteSchemeQuery, 4d0c304f-27c2-4404-8a73-580deb13cf6f, ghrun-iuibjpfjoa.auto.internal:9668): creating call state
2025-11-14 06:53:05,446 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteSchemeQuery, 4d0c304f-27c2-4404-8a73-580deb13cf6f, ghrun-iuibjpfjoa.auto.internal:9668): request = { session_id: "ydb://session/3?node_id=50000&id=ODdjNmFlZGYtNDg5YzFjYWItMjA3YzFmNzctNWM4Y2JhZGY=" yql_text: "create group dbadmins" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:53:05,453 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteSchemeQuery, 4d0c304f-27c2-4404-8a73-580deb13cf6f, ghrun-iuibjpfjoa.auto.internal:9668): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:53:05,454 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteSchemeQuery, 5ad7d2d5-5f1b-4841-ac48-50e698e08fa2, ghrun-iuibjpfjoa.auto.internal:9668): creating call state
2025-11-14 06:53:05,456 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteSchemeQuery, 5ad7d2d5-5f1b-4841-ac48-50e698e08fa2, ghrun-iuibjpfjoa.auto.internal:9668): request = { session_id: "ydb://session/3?node_id=50000&id=ODdjNmFlZGYtNDg5YzFjYWItMjA3YzFmNzctNWM4Y2JhZGY=" yql_text: "alter group dbadmins add user dbadmin" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:53:05,464 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteSchemeQuery, 5ad7d2d5-5f1b-4841-ac48-50e698e08fa2, ghrun-iuibjpfjoa.auto.internal:9668): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:53:05,465 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteSchemeQuery, a5011096-c1fb-45f2-94cc-92bea2d95fe3, ghrun-iuibjpfjoa.auto.internal:9668): creating call state
2025-11-14 06:53:05,466 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteSchemeQuery, a5011096-c1fb-45f2-94cc-92bea2d95fe3, ghrun-iuibjpfjoa.auto.internal:9668): request = { session_id: "ydb://session/3?node_id=50000&id=ODdjNmFlZGYtNDg5YzFjYWItMjA3YzFmNzctNWM4Y2JhZGY=" yql_text: "create user ordinaryuser password \'1234\'" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:53:05,475 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteSchemeQuery, a5011096-c1fb-45f2-94cc-92bea2d95fe3, ghrun-iuibjpfjoa.auto.internal:9668): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:53:05,476 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteSchemeQuery, 66962b27-d9b0-4844-9a7e-0f01a2346b01, ghrun-iuibjpfjoa.auto.internal:9668): creating call state
2025-11-14 06:53:05,476 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteSchemeQuery, 66962b27-d9b0-4844-9a7e-0f01a2346b01, ghrun-iuibjpfjoa.auto.internal:9668): request = { session_id: "ydb://session/3?node_id=50000&id=ODdjNmFlZGYtNDg5YzFjYWItMjA3YzFmNzctNWM4Y2JhZGY=" yql_text: "create group ordinarygroup" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:53:05,483 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteSchemeQuery, 66962b27-d9b0-4844-9a7e-0f01a2346b01, ghrun-iuibjpfjoa.auto.internal:9668): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:53:05,484 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteSchemeQuery, bcb1610f-c6dd-480a-b0b1-446e1a70f5d8, ghrun-iuibjpfjoa.auto.internal:9668): creating call state
2025-11-14 06:53:05,484 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteSchemeQuery, bcb1610f-c6dd-480a-b0b1-446e1a70f5d8, ghrun-iuibjpfjoa.auto.internal:9668): request = { session_id: "ydb://session/3?node_id=50000&id=ODdjNmFlZGYtNDg5YzFjYWItMjA3YzFmNzctNWM4Y2JhZGY=" yql_text: "create user dbadmin2 password \'1234\'" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:53:05,494 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteSchemeQuery, bcb1610f-c6dd-480a-b0b1-446e1a70f5d8, ghrun-iuibjpfjoa.auto.internal:9668): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:53:05,494 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteSchemeQuery, 611cb808-0190-4632-aa4a-48b2116b4c83, ghrun-iuibjpfjoa.auto.internal:9668): creating call state
2025-11-14 06:53:05,495 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteSchemeQuery, 611cb808-0190-4632-aa4a-48b2116b4c83, ghrun-iuibjpfjoa.auto.internal:9668): request = { session_id: "ydb://session/3?node_id=50000&id=ODdjNmFlZGYtNDg5YzFjYWItMjA3YzFmNzctNWM4Y2JhZGY=" yql_text: "create user dbadmin3 password \'1234\' nologin" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:53:05,505 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteSchemeQuery, 611cb808-0190-4632-aa4a-48b2116b4c83, ghrun-iuibjpfjoa.auto.internal:9668): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:53:05,506 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteSchemeQuery, 51a1a614-f522-4fcb-8e5d-e5436a182b24, ghrun-iuibjpfjoa.auto.internal:9668): creating call state
2025-11-14 06:53:05,507 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteSchemeQuery, 51a1a614-f522-4fcb-8e5d-e5436a182b24, ghrun-iuibjpfjoa.auto.internal:9668): request = { session_id: "ydb://session/3?node_id=50000&id=ODdjNmFlZGYtNDg5YzFjYWItMjA3YzFmNzctNWM4Y2JhZGY=" yql_text: "create user dbadmin4 password \'1234\'" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:53:05,516 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteSchemeQuery, 51a1a614-f522-4fcb-8e5d-e5436a182b24, ghrun-iuibjpfjoa.auto.internal:9668): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:53:05,517 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteSchemeQuery, 62319af7-ea1d-41b1-9c54-d9bb131a773e, ghrun-iuibjpfjoa.auto.internal:9668): creating call state
2025-11-14 06:53:05,517 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteSchemeQuery, 62319af7-ea1d-41b1-9c54-d9bb131a773e, ghrun-iuibjpfjoa.auto.internal:9668): request = { session_id: "ydb://session/3?node_id=50000&id=ODdjNmFlZGYtNDg5YzFjYWItMjA3YzFmNzctNWM4Y2JhZGY=" yql_text: "create group dbsubadmins" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:53:05,524 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteSchemeQuery, 62319af7-ea1d-41b1-9c54-d9bb131a773e, ghrun-iuibjpfjoa.auto.internal:9668): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:53:05,525 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteSchemeQuery, b723c641-543d-42d0-8365-f1dbf601e96c, ghrun-iuibjpfjoa.auto.internal:9668): creating call state
2025-11-14 06:53:05,525 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteSchemeQuery, b723c641-543d-42d0-8365-f1dbf601e96c, ghrun-iuibjpfjoa.auto.internal:9668): request = { session_id: "ydb://session/3?node_id=50000&id=ODdjNmFlZGYtNDg5YzFjYWItMjA3YzFmNzctNWM4Y2JhZGY=" yql_text: "alter group dbadmins add user dbadmin2, dbadmin3, dbadmin4, dbsubadmins" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:53:05,538 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteSchemeQuery, b723c641-543d-42d0-8365-f1dbf601e96c, ghrun-iuibjpfjoa.auto.internal:9668): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:53:05,539 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7f0033e8e0e0>
2025-11-14 06:53:05,539 - DEBUG - ydb.connection - _prepare_call: RpcState(ModifyPermissions, 43674a3f-e759-4b2f-a7db-0658f75e6ef8, ghrun-iuibjpfjoa.auto.internal:9668): creating call state
2025-11-14 06:53:05,540 - DEBUG - ydb.connection - _log_request: RpcState(ModifyPermissions, 43674a3f-e759-4b2f-a7db-0658f75e6ef8, ghrun-iuibjpfjoa.auto.internal:9668): request = { operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } path: "/Root/test_user_administration" actions { change_owner: "dbadmins" } }
2025-11-14 06:53:05,544 - DEBUG - ydb.connection - _log_response: RpcState(ModifyPermissions, 43674a3f-e759-4b2f-a7db-0658f75e6ef8, ghrun-iuibjpfjoa.auto.internal:9668): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:53:05,544 - INFO - ydb.connection - close: Closing channel for endpoint localhost:8713
2025-11-14 06:53:05,617 - INFO - ydb.connection - close: Closing channel for endpoint ghrun-iuibjpfjoa.auto.internal:9668
2025-11-14 06:53:05,625 - INFO - ydb.pool.Discovery - run: Successfully terminated discovery process
2025-11-14 06:53:05,628 - INFO - ya.test - pytest_runtest_call: Test call (class_name: test_user_administration.py, test_name: test_database_admin_cant_change_database_admin_group[remove-other-admin])
2025-11-14 06:53:05,629 - 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')]
2025-11-14 06:53:05,633 - DEBUG - ydb.connection - _prepare_call: RpcState(Login, dd84cab4-111f-450b-9862-5fef8367d5cd, localhost:8713): creating call state
2025-11-14 06:53:05,634 - DEBUG - ydb.connection - _log_request: RpcState(Login, dd84cab4-111f-450b-9862-5fef8367d5cd, localhost:8713): request = { operation_params { operation_timeout { seconds: 10 } cancel_after { seconds: 10 } } user: "dbadmin" password: "1234" }
2025-11-14 06:53:05,710 - DEBUG - ydb.connection - _log_response: RpcState(Login, dd84cab4-111f-450b-9862-5fef8367d5cd, localhost:8713): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Auth.LoginResult] { token: "eyJhbGciOiJQUzI1NiIsImtpZCI6IjEifQ.eyJhdWQiOlsiXC9Sb290XC90ZXN0X3VzZXJfYWRtaW5pc3RyYXRpb24iXSwiZXhwIjoxNzYzMTQ2Mzg1LCJpYXQiOjE3NjMxMDMxODUsInN1YiI6ImRiYWRtaW4ifQ.Ir_BUNbymX3_GVRYtmCVA4Q0TPmZwjcSQh54xkry0733klTDbzKAoabD8-QBi2Jju5qfSJ8CKQx7HQtSzqk-VLK_FoAxH9_qBZsB-mSupw8luP01f__i0GciO3Z5W7lwKUO3IOduLFBsscbVcx-Pb4h-Nrrpw04Gkjy1NpRbchQIpPFt9JfiDVcdBzXr7tFud5wAnHq7oP4YOzAyd-sFBd5eF8b-JbkoDe277Uj-E6k99CAkE2EAJ-ZL960Z0oJRivx15_l7fTFrQyUT7qKFon-FOmIcpXZsbc9by-A5LekuQbFjsoGN67-dQQdvP-JXSWssuZN_2RgUF9dejMSO3Q" } } } }
2025-11-14 06:53:05,710 - INFO - ydb.connection - close: Closing channel for endpoint localhost:8713
2025-11-14 06:53:05,836 - 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')]
2025-11-14 06:53:05,838 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-11-14 06:53:05,839 - 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')]
2025-11-14 06:53:05,842 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database /Root/test_user_administration
2025-11-14 06:53:05,843 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, f6f24717-fa34-4e86-8239-b0f80ffb98fe, localhost:8713): creating call state
2025-11-14 06:53:05,843 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, f6f24717-fa34-4e86-8239-b0f80ffb98fe, localhost:8713): request = { database: "/Root/test_user_administration" }
2025-11-14 06:53:05,846 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, f6f24717-fa34-4e86-8239-b0f80ffb98fe, localhost:8713): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Discovery.ListEndpointsResult] { endpoints { address: "ghrun-iuibjpfjoa.auto.internal" port: 9668 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" node_id: 50000 } self_location: "1" } } } }
2025-11-14 06:53:05,847 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Resolved endpoints for database /Root/test_user_administration: DiscoveryResult <self_location: 1, endpoints [<Endpoint ghrun-iuibjpfjoa.auto.internal:9668, location , ssl: False>]>
2025-11-14 06:53:05,847 - 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')]
2025-11-14 06:53:05,851 - INFO - ydb.connection - close: Closing channel for endpoint localhost:8713
2025-11-14 06:53:05,852 - DEBUG - ydb.table.SessionPool - subscribe: Active session queue is empty, subscribe waiter for a session
2025-11-14 06:53:05,852 - DEBUG - ydb.table.SessionPool - subscribe: Subscribe waiter <Future at 0x7f003368b4e0 state=pending>
2025-11-14 06:53:05,853 - DEBUG - ydb.table.SessionPool - subscribe: Session pool is not large enough (active_count < size: 0 < 100). will create a new session.
2025-11-14 06:53:05,853 - DEBUG - ydb.table.SessionPool - _create: Created session <ydb.table.Session object at 0x7f003368b440>
2025-11-14 06:53:05,854 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7f003368b440>
2025-11-14 06:53:05,854 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, 1858417a-8830-49ed-8fdb-d5938a3a8276, ghrun-iuibjpfjoa.auto.internal:9668): creating call state
2025-11-14 06:53:05,854 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, 1858417a-8830-49ed-8fdb-d5938a3a8276, ghrun-iuibjpfjoa.auto.internal:9668): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-11-14 06:53:05,857 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, 1858417a-8830-49ed-8fdb-d5938a3a8276, ghrun-iuibjpfjoa.auto.internal:9668): on response callback started
2025-11-14 06:53:05,858 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, 1858417a-8830-49ed-8fdb-d5938a3a8276, ghrun-iuibjpfjoa.auto.internal:9668): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=50000&id=YmZkZWRjYTYtNmM2OWMzMy1mZWNmMTdkMS02YzRkN2U3MA==" } } } }
2025-11-14 06:53:05,858 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7f003368b440>
2025-11-14 06:53:05,858 - DEBUG - ydb.table.SessionPool - put: Replying to waiter with a session <ydb.table.Session object at 0x7f003368b440>
2025-11-14 06:53:05,859 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteSchemeQuery, 5328ddd7-26f5-4199-a6ee-c0179208286a, ghrun-iuibjpfjoa.auto.internal:9668): creating call state
2025-11-14 06:53:05,859 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, 1858417a-8830-49ed-8fdb-d5938a3a8276, ghrun-iuibjpfjoa.auto.internal:9668): on response callback success
2025-11-14 06:53:05,860 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteSchemeQuery, 5328ddd7-26f5-4199-a6ee-c0179208286a, ghrun-iuibjpfjoa.auto.internal:9668): request = { session_id: "ydb://session/3?node_id=50000&id=YmZkZWRjYTYtNmM2OWMzMy1mZWNmMTdkMS02YzRkN2U3MA==" yql_text: "alter group dbadmins drop user dbadmin2" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:53:05,866 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteSchemeQuery, 5328ddd7-26f5-4199-a6ee-c0179208286a, ghrun-iuibjpfjoa.auto.internal:9668): response = { operation { ready: true status: UNAUTHORIZED issues { message: "Execution" issue_code: 1060 severity: 1 issues { position { row: 1 column: 1 } message: "Executing ALTER GROUP" end_position { row: 1 column: 1 } severity: 1 issues { message: "Access denied for scheme request" issue_code: 2018 severity: 1 issues { message: "Access denied." severity: 1 } } } } } }
2025-11-14 06:53:05,867 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7f003368b440>
2025-11-14 06:53:05,868 - INFO - ydb.connection - close: Closing channel for endpoint localhost:8713
2025-11-14 06:53:06,046 - INFO - ydb.connection - close: Closing channel for endpoint ghrun-iuibjpfjoa.auto.internal:9668
2025-11-14 06:53:06,054 - INFO - ydb.pool.Discovery - run: Successfully terminated discovery process
2025-11-14 06:53:06,056 - INFO - ya.test - pytest_runtest_teardown: Test teardown
