2025-11-14 06:51:57,031 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-11-14 06:51:57,031 - INFO - ya.test - pytest_runtest_setup: test_create_and_drop_tenants[enable_alter_database_create_hive_first--true]
2025-11-14 06:51:57,031 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-11-14 06:51:57,031 - INFO - ya.test - pytest_runtest_setup: Test setup
2025-11-14 06:51:57,032 - INFO - ydb.tests.library.fixtures - ydb_cluster: destroy ydb_cluster for __tests__.test_dynamic_tenants
2025-11-14 06:52:00,033 - INFO - ydb.tests.library.harness.kikimr_runner - stop: Stopped node localhost:1308/1
2025-11-14 06:52:00,034 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/32341
2025-11-14 06:52:00,035 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/18344
2025-11-14 06:52:00,035 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/2478
2025-11-14 06:52:00,035 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/17788
2025-11-14 06:52:00,035 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/6187
2025-11-14 06:52:00,035 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/2966
2025-11-14 06:52:00,035 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/28856
2025-11-14 06:52:00,035 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/32382
2025-11-14 06:52:00,036 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/21189
2025-11-14 06:52:00,036 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/25256
2025-11-14 06:52:00,036 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/11786
2025-11-14 06:52:00,036 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/20815
2025-11-14 06:52:00,036 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/29637
2025-11-14 06:52:00,036 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/22297
2025-11-14 06:52:00,036 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/17307
2025-11-14 06:52:00,037 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/19813
2025-11-14 06:52:00,037 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/27267
2025-11-14 06:52:00,037 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/9310
2025-11-14 06:52:00,037 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/24297
2025-11-14 06:52:00,037 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/10975
2025-11-14 06:52:00,037 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/10218
2025-11-14 06:52:00,038 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/3084
2025-11-14 06:52:00,038 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/30600
2025-11-14 06:52:00,038 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/32004
2025-11-14 06:52:00,038 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/15697
2025-11-14 06:52:00,038 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/14938
2025-11-14 06:52:00,039 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/12663
2025-11-14 06:52:00,039 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/16682
2025-11-14 06:52:00,039 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/20787
2025-11-14 06:52:00,039 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/30234
2025-11-14 06:52:00,039 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/12599
2025-11-14 06:52:00,039 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/30332
2025-11-14 06:52:00,039 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/3262
2025-11-14 06:52:00,040 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/5357
2025-11-14 06:52:00,040 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/24256
2025-11-14 06:52:00,040 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/13399
2025-11-14 06:52:00,040 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/16709
2025-11-14 06:52:00,040 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/10432
2025-11-14 06:52:00,040 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/24298
2025-11-14 06:52:00,040 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/25623
2025-11-14 06:52:00,041 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/19851
2025-11-14 06:52:00,041 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/18770
2025-11-14 06:52:00,041 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/16387
2025-11-14 06:52:00,041 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/13441
2025-11-14 06:52:00,041 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/31288
2025-11-14 06:52:00,041 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/8114
2025-11-14 06:52:00,041 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/3245
2025-11-14 06:52:00,042 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/2939
2025-11-14 06:52:00,042 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/11568
2025-11-14 06:52:00,042 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/12772
2025-11-14 06:52:00,042 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/63613
2025-11-14 06:52:00,042 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/6090
2025-11-14 06:52:00,042 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/30121
2025-11-14 06:52:00,043 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/1308
2025-11-14 06:52:00,043 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/25178
2025-11-14 06:52:00,105 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/rl7h/0030e4/ydb/apps/ydbd/ydbd
2025-11-14 06:52:00,109 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/28642
2025-11-14 06:52:00,114 - INFO - ydb.tests.library.fixtures - ydb_cluster: setup ydb_cluster for __tests__.test_dynamic_tenants
2025-11-14 06:52:00,114 - INFO - ydb.tests.library.fixtures - ydb_cluster: setup ydb_cluster as local
2025-11-14 06:52:00,115 - DEBUG - ydb.tests.library.harness.kikimr_runner - start: Working directory: /home/runner/.ya/build/build_root/rl7h/0030e4/r3tmp/kikimr_cluster_kpnd6pdx
2025-11-14 06:52:00,150 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/rl7h/0030e4/ydb/apps/ydbd/ydbd
2025-11-14 06:52:00,151 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/14696
2025-11-14 06:52:00,151 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/17860
2025-11-14 06:52:00,151 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/28947
2025-11-14 06:52:00,152 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/5001
2025-11-14 06:52:00,152 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: CFG_DIR_PATH="/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/kikimr_configs"
2025-11-14 06:52:00,153 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: Final command: /home/runner/.ya/build/build_root/rl7h/0030e4/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/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/node_1/logfile_bmjmcszw.log --grpc-port=14696 --mon-port=17860 --ic-port=28642
2025-11-14 06:52:00,153 - DEBUG - ydb.tests.library.harness.kikimr_runner - format_pdisk: Formatting pdisk SectorMap:1:64 on node localhost:14696/1, disk_size 68719476736
2025-11-14 06:52:00,154 - DEBUG - ya.test - execute: Executing '('/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/apps/ydbd/ydbd', 'server', '--suppress-version-check', '--yaml-config=/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/kikimr_configs/config.yaml', '--node=1', '--log-file-name=/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/node_1/logfile_bmjmcszw.log', '--grpc-port=14696', '--mon-port=17860', '--ic-port=28642')' in '/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/node_1' (no wait)
2025-11-14 06:52:00,155 - DEBUG - ya.test - execute: Command pid: 1371559
2025-11-14 06:52:00,157 - INFO - ydb.tests.library.harness.kikimr_runner - start: Started node localhost:14696/1
2025-11-14 06:52:01,904 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/rl7h/0030e4/ydb/apps/ydbd/ydbd
2025-11-14 06:52:01,904 - DEBUG - ydb.tests.library.harness.kikimr_runner - __call_kikimr_new_cli: Executing command = ['/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/apps/ydbd/ydbd', '--server=grpc://localhost:14696', '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: 28642\n      }\n      HostConfigId: 1\n    }\n  }\n}\n']
2025-11-14 06:52:01,905 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydbd.out.3
2025-11-14 06:52:01,905 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydbd.err.3
2025-11-14 06:52:01,906 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/apps/ydbd/ydbd', '--server=grpc://localhost:14696', '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: 28642\n      }\n      HostConfigId: 1\n    }\n  }\n}\n']' in 'None' (waiting)
2025-11-14 06:52:01,907 - DEBUG - ya.test - execute: Command pid: 1372739
2025-11-14 06:52:02,240 - DEBUG - ya.test - _save_outputs: Command (pid 1372739) rc: 0
2025-11-14 06:52:02,241 - DEBUG - ya.test - _save_outputs: Command (pid 1372739) elapsed time (sec): 0.3330652713775635
2025-11-14 06:52:02,241 - DEBUG - ya.test - _save_outputs: Command (pid 1372739) idrss: 0
2025-11-14 06:52:02,241 - DEBUG - ya.test - _save_outputs: Command (pid 1372739) inblock: 0
2025-11-14 06:52:02,242 - DEBUG - ya.test - _save_outputs: Command (pid 1372739) isrss: 0
2025-11-14 06:52:02,242 - DEBUG - ya.test - _save_outputs: Command (pid 1372739) ixrss: 0
2025-11-14 06:52:02,242 - DEBUG - ya.test - _save_outputs: Command (pid 1372739) majflt: 0
2025-11-14 06:52:02,242 - DEBUG - ya.test - _save_outputs: Command (pid 1372739) maxrss: 525772
2025-11-14 06:52:02,242 - DEBUG - ya.test - _save_outputs: Command (pid 1372739) minflt: 19682
2025-11-14 06:52:02,242 - DEBUG - ya.test - _save_outputs: Command (pid 1372739) msgrcv: 0
2025-11-14 06:52:02,243 - DEBUG - ya.test - _save_outputs: Command (pid 1372739) msgsnd: 0
2025-11-14 06:52:02,243 - DEBUG - ya.test - _save_outputs: Command (pid 1372739) nivcsw: 2
2025-11-14 06:52:02,243 - DEBUG - ya.test - _save_outputs: Command (pid 1372739) nsignals: 0
2025-11-14 06:52:02,243 - DEBUG - ya.test - _save_outputs: Command (pid 1372739) nswap: 0
2025-11-14 06:52:02,243 - DEBUG - ya.test - _save_outputs: Command (pid 1372739) nvcsw: 159
2025-11-14 06:52:02,244 - DEBUG - ya.test - _save_outputs: Command (pid 1372739) oublock: 8
2025-11-14 06:52:02,244 - DEBUG - ya.test - _save_outputs: Command (pid 1372739) stime: 0.215975
2025-11-14 06:52:02,244 - DEBUG - ya.test - _save_outputs: Command (pid 1372739) utime: 0.074839
2025-11-14 06:52:02,244 - DEBUG - ya.test - _save_outputs: Command (pid 1372739) wtime: 0.334
2025-11-14 06:52:02,244 - DEBUG - ya.test - _save_outputs: Command (pid 1372739) output:
Status {
  Success: true
}
Status {
  Success: true
}
Success: true
ConfigTxSeqNo: 5

2025-11-14 06:52:02,245 - DEBUG - ya.test - _save_outputs: Command (pid 1372739) errors:

2025-11-14 06:52:02,246 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/rl7h/0030e4/ydb/apps/ydbd/ydbd
2025-11-14 06:52:02,246 - DEBUG - ydb.tests.library.harness.kikimr_runner - __call_kikimr_new_cli: Executing command = ['/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/apps/ydbd/ydbd', '--server=grpc://localhost:14696', '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:52:02,247 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydbd.out.4
2025-11-14 06:52:02,248 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydbd.err.4
2025-11-14 06:52:02,248 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/apps/ydbd/ydbd', '--server=grpc://localhost:14696', '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:52:02,249 - DEBUG - ya.test - execute: Command pid: 1373077
2025-11-14 06:52:02,602 - DEBUG - ya.test - _save_outputs: Command (pid 1373077) rc: 0
2025-11-14 06:52:02,602 - DEBUG - ya.test - _save_outputs: Command (pid 1373077) elapsed time (sec): 0.3517446517944336
2025-11-14 06:52:02,602 - DEBUG - ya.test - _save_outputs: Command (pid 1373077) idrss: 0
2025-11-14 06:52:02,603 - DEBUG - ya.test - _save_outputs: Command (pid 1373077) inblock: 0
2025-11-14 06:52:02,603 - DEBUG - ya.test - _save_outputs: Command (pid 1373077) isrss: 0
2025-11-14 06:52:02,603 - DEBUG - ya.test - _save_outputs: Command (pid 1373077) ixrss: 0
2025-11-14 06:52:02,603 - DEBUG - ya.test - _save_outputs: Command (pid 1373077) majflt: 0
2025-11-14 06:52:02,603 - DEBUG - ya.test - _save_outputs: Command (pid 1373077) maxrss: 525764
2025-11-14 06:52:02,603 - DEBUG - ya.test - _save_outputs: Command (pid 1373077) minflt: 19683
2025-11-14 06:52:02,604 - DEBUG - ya.test - _save_outputs: Command (pid 1373077) msgrcv: 0
2025-11-14 06:52:02,604 - DEBUG - ya.test - _save_outputs: Command (pid 1373077) msgsnd: 0
2025-11-14 06:52:02,604 - DEBUG - ya.test - _save_outputs: Command (pid 1373077) nivcsw: 2
2025-11-14 06:52:02,604 - DEBUG - ya.test - _save_outputs: Command (pid 1373077) nsignals: 0
2025-11-14 06:52:02,604 - DEBUG - ya.test - _save_outputs: Command (pid 1373077) nswap: 0
2025-11-14 06:52:02,605 - DEBUG - ya.test - _save_outputs: Command (pid 1373077) nvcsw: 144
2025-11-14 06:52:02,605 - DEBUG - ya.test - _save_outputs: Command (pid 1373077) oublock: 8
2025-11-14 06:52:02,605 - DEBUG - ya.test - _save_outputs: Command (pid 1373077) stime: 0.223095
2025-11-14 06:52:02,605 - DEBUG - ya.test - _save_outputs: Command (pid 1373077) utime: 0.08594399999999999
2025-11-14 06:52:02,605 - DEBUG - ya.test - _save_outputs: Command (pid 1373077) wtime: 0.353
2025-11-14 06:52:02,605 - DEBUG - ya.test - _save_outputs: Command (pid 1373077) output:
Status {
  Success: true
}
Success: true
ConfigTxSeqNo: 6

2025-11-14 06:52:02,606 - DEBUG - ya.test - _save_outputs: Command (pid 1373077) errors:

2025-11-14 06:52:02,606 - INFO - ydb.tests.library.harness.kikimr_runner - __run: Binding storage pools to domain Root: {'dynamic_storage_pool:1': 'hdd'}
2025-11-14 06:52:02,622 - INFO - ydb.tests.library.harness.kikimr_runner - __run: Cluster started and initialized
2025-11-14 06:52:02,630 - INFO - ya.test - pytest_runtest_call: Test call (class_name: test_dynamic_tenants.py, test_name: test_create_and_drop_tenants[enable_alter_database_create_hive_first--true])
2025-11-14 06:52:03,138 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/rl7h/0030e4/ydb/apps/ydbd/ydbd
2025-11-14 06:52:03,139 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/13521
2025-11-14 06:52:03,139 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/4127
2025-11-14 06:52:03,139 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/12512
2025-11-14 06:52:03,139 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/2420
2025-11-14 06:52:03,140 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/26355
2025-11-14 06:52:03,140 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: CFG_DIR_PATH="/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/kikimr_configs"
2025-11-14 06:52:03,140 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: Final command: /home/runner/.ya/build/build_root/rl7h/0030e4/ydb/apps/ydbd/ydbd server --suppress-version-check --yaml-config=$CFG_DIR_PATH/config.yaml --node-broker=localhost:14696 --tenant=/Root/users/database_0 --log-file-name=/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/slot_1/logfile_fptb8hyg.log --grpc-port=13521 --mon-port=4127 --ic-port=12512
2025-11-14 06:52:03,141 - DEBUG - ya.test - execute: Executing '('/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/apps/ydbd/ydbd', 'server', '--suppress-version-check', '--yaml-config=/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/kikimr_configs/config.yaml', '--node-broker=localhost:14696', '--tenant=/Root/users/database_0', '--log-file-name=/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/slot_1/logfile_fptb8hyg.log', '--grpc-port=13521', '--mon-port=4127', '--ic-port=12512')' in '/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/slot_1' (no wait)
2025-11-14 06:52:03,143 - DEBUG - ya.test - execute: Command pid: 1374278
2025-11-14 06:52:03,144 - INFO - ydb.tests.library.harness.kikimr_runner - start: Started node localhost:13521/1
2025-11-14 06:52:05,148 - 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:52:05,150 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-11-14 06:52:05,151 - 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:52:05,152 - DEBUG - ydb.table.SessionPool - subscribe: Active session queue is empty, subscribe waiter for a session
2025-11-14 06:52:05,154 - DEBUG - ydb.table.SessionPool - subscribe: Subscribe waiter <Future at 0x7fe892990bf0 state=pending>
2025-11-14 06:52:05,156 - 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:52:05,156 - DEBUG - ydb.table.SessionPool - _create: Created session <ydb.table.Session object at 0x7fe8929aa680>
2025-11-14 06:52:05,157 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7fe8929aa680>
2025-11-14 06:52:05,157 - 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:52:05,158 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database /Root/users/database_0
2025-11-14 06:52:05,159 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, 9963867b-a9f7-4cec-9a6b-b32ada54c680, localhost:14696): creating call state
2025-11-14 06:52:05,159 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, 9963867b-a9f7-4cec-9a6b-b32ada54c680, localhost:14696): request = { database: "/Root/users/database_0" }
2025-11-14 06:52:05,162 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, 9963867b-a9f7-4cec-9a6b-b32ada54c680, localhost:14696): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Discovery.ListEndpointsResult] { endpoints { address: "ghrun-iuibjpfjoa.auto.internal" port: 13521 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:52:05,162 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Resolved endpoints for database /Root/users/database_0: DiscoveryResult <self_location: 1, endpoints [<Endpoint ghrun-iuibjpfjoa.auto.internal:13521, location , ssl: False>]>
2025-11-14 06:52:05,162 - 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:52:05,166 - INFO - ydb.connection - close: Closing channel for endpoint localhost:14696
2025-11-14 06:52:05,166 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7fe8929aa680>
2025-11-14 06:52:05,167 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, b93eff6c-e308-4c45-98eb-2f7d3fe8d2a1, ghrun-iuibjpfjoa.auto.internal:13521): creating call state
2025-11-14 06:52:05,167 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, b93eff6c-e308-4c45-98eb-2f7d3fe8d2a1, ghrun-iuibjpfjoa.auto.internal:13521): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-11-14 06:52:05,169 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, b93eff6c-e308-4c45-98eb-2f7d3fe8d2a1, ghrun-iuibjpfjoa.auto.internal:13521): on response callback started
2025-11-14 06:52:05,170 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, b93eff6c-e308-4c45-98eb-2f7d3fe8d2a1, ghrun-iuibjpfjoa.auto.internal:13521): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=50000&id=OTAwZmNmYjEtOWQ4NDk4MDMtY2Y5NzBmNDMtODU2ZTY4ZTA=" } } } }
2025-11-14 06:52:05,170 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe8929aa680>
2025-11-14 06:52:05,171 - DEBUG - ydb.table.SessionPool - put: Replying to waiter with a session <ydb.table.Session object at 0x7fe8929aa680>
2025-11-14 06:52:05,171 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateTable, c3414daa-ddbc-4685-8953-98df9b40116e, ghrun-iuibjpfjoa.auto.internal:13521): creating call state
2025-11-14 06:52:05,172 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, b93eff6c-e308-4c45-98eb-2f7d3fe8d2a1, ghrun-iuibjpfjoa.auto.internal:13521): on response callback success
2025-11-14 06:52:05,173 - DEBUG - ydb.connection - _log_request: RpcState(CreateTable, c3414daa-ddbc-4685-8953-98df9b40116e, ghrun-iuibjpfjoa.auto.internal:13521): request = { session_id: "ydb://session/3?node_id=50000&id=OTAwZmNmYjEtOWQ4NDk4MDMtY2Y5NzBmNDMtODU2ZTY4ZTA=" path: "/Root/users/database_0/table" columns { name: "id" type { optional_type { item { type_id: UINT64 } } } } columns { name: "value" type { optional_type { item { type_id: UTF8 } } } } primary_key: "id" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:05,204 - DEBUG - ydb.connection - _log_response: RpcState(CreateTable, c3414daa-ddbc-4685-8953-98df9b40116e, ghrun-iuibjpfjoa.auto.internal:13521): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:52:05,205 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe8929aa680>
2025-11-14 06:52:05,206 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateTable, 48e937ec-d0f1-49c3-aed9-edc2f8eeea92, ghrun-iuibjpfjoa.auto.internal:13521): creating call state
2025-11-14 06:52:05,206 - DEBUG - ydb.connection - _log_request: RpcState(CreateTable, 48e937ec-d0f1-49c3-aed9-edc2f8eeea92, ghrun-iuibjpfjoa.auto.internal:13521): request = { session_id: "ydb://session/3?node_id=50000&id=OTAwZmNmYjEtOWQ4NDk4MDMtY2Y5NzBmNDMtODU2ZTY4ZTA=" path: "/Root/users/database_0/table_for_rm" columns { name: "id" type { optional_type { item { type_id: UINT64 } } } } columns { name: "value" type { optional_type { item { type_id: UTF8 } } } } primary_key: "id" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:05,227 - DEBUG - ydb.connection - _log_response: RpcState(CreateTable, 48e937ec-d0f1-49c3-aed9-edc2f8eeea92, ghrun-iuibjpfjoa.auto.internal:13521): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:52:05,228 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe8929aa680>
2025-11-14 06:52:05,228 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteDataQuery, 57eb2889-342b-4592-b93f-ce7ce731cee0, ghrun-iuibjpfjoa.auto.internal:13521): creating call state
2025-11-14 06:52:05,229 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteDataQuery, 57eb2889-342b-4592-b93f-ce7ce731cee0, ghrun-iuibjpfjoa.auto.internal:13521): request = { session_id: "ydb://session/3?node_id=50000&id=OTAwZmNmYjEtOWQ4NDk4MDMtY2Y5NzBmNDMtODU2ZTY4ZTA=" tx_control { begin_tx { serializable_read_write { } } commit_tx: true } query { yql_text: "\n                        upsert into table (id, value)\n                        values (1u, \"/Root/users/database_0\");\n                        upsert into table_for_rm (id, value)\n                        values (2u, \"/Root/users/database_0\");\n                        " } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:05,251 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteDataQuery, 57eb2889-342b-4592-b93f-ce7ce731cee0, ghrun-iuibjpfjoa.auto.internal:13521): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { tx_meta { } } } } }
2025-11-14 06:52:05,252 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe8929aa680>
2025-11-14 06:52:05,253 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteDataQuery, 4d324522-2029-4d52-821f-dda469ce5588, ghrun-iuibjpfjoa.auto.internal:13521): creating call state
2025-11-14 06:52:05,253 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteDataQuery, 4d324522-2029-4d52-821f-dda469ce5588, ghrun-iuibjpfjoa.auto.internal:13521): request = { session_id: "ydb://session/3?node_id=50000&id=OTAwZmNmYjEtOWQ4NDk4MDMtY2Y5NzBmNDMtODU2ZTY4ZTA=" tx_control { begin_tx { serializable_read_write { } } commit_tx: true } query { yql_text: "\n                        select id, value FROM table;\n                        select id, value FROM table_for_rm;\n                        " } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:05,281 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteDataQuery, 4d324522-2029-4d52-821f-dda469ce5588, ghrun-iuibjpfjoa.auto.internal:13521): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { result_sets { columns { name: "id" type { optional_type { item { type_id: UINT64 } } } } columns { name: "value" type { optional_type { item { type_id: UTF8 } } } } rows { items { uint64_value: 1 } items { text_value: "/Root/users/database_0" } } } result_sets { columns { name: "id" type { optional_type { item { type_id: UINT64 } } } } columns { name: "value" type { optional_type { item { type_id: UTF8 } } } } rows { items { uint64_value: 2 } items { text_value: "/Root/users/database_0" } } } tx_meta { } } } } }
2025-11-14 06:52:05,281 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe8929aa680>
2025-11-14 06:52:05,282 - DEBUG - ydb.connection - _prepare_call: RpcState(DropTable, 73313a3b-9bef-4009-8784-2bea6fdec4c2, ghrun-iuibjpfjoa.auto.internal:13521): creating call state
2025-11-14 06:52:05,282 - DEBUG - ydb.connection - _log_request: RpcState(DropTable, 73313a3b-9bef-4009-8784-2bea6fdec4c2, ghrun-iuibjpfjoa.auto.internal:13521): request = { session_id: "ydb://session/3?node_id=50000&id=OTAwZmNmYjEtOWQ4NDk4MDMtY2Y5NzBmNDMtODU2ZTY4ZTA=" path: "/Root/users/database_0/table_for_rm" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:05,296 - DEBUG - ydb.connection - _log_response: RpcState(DropTable, 73313a3b-9bef-4009-8784-2bea6fdec4c2, ghrun-iuibjpfjoa.auto.internal:13521): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:52:05,296 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe8929aa680>
2025-11-14 06:52:05,297 - DEBUG - ydb.table.SessionPool - stop: Requested session pool stop.
2025-11-14 06:52:05,297 - DEBUG - ydb.table.SessionPool - stop: Session pool is under stop, cancelling all in flight waiters.
2025-11-14 06:52:05,297 - DEBUG - ydb.table.SessionPool - stop: Destroying sessions in active queue
2025-11-14 06:52:05,297 - DEBUG - ydb.table.SessionPool - _destroy: Requested session destroy: <ydb.table.Session object at 0x7fe8929aa680>, reason: session-pool-terminated
2025-11-14 06:52:05,297 - DEBUG - ydb.table.SessionPool - _terminate_event: Terminated session pool.
2025-11-14 06:52:05,297 - DEBUG - ydb.table.SessionPool - _destroy: Session <ydb.table.Session object at 0x7fe8929aa680> is no longer active. Current active count 0.
2025-11-14 06:52:05,298 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, 92b01f15-4265-4dc3-93c8-ea23d16647b8, ghrun-iuibjpfjoa.auto.internal:13521): creating call state
2025-11-14 06:52:05,298 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, 92b01f15-4265-4dc3-93c8-ea23d16647b8, ghrun-iuibjpfjoa.auto.internal:13521): request = { session_id: "ydb://session/3?node_id=50000&id=OTAwZmNmYjEtOWQ4NDk4MDMtY2Y5NzBmNDMtODU2ZTY4ZTA=" operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-11-14 06:52:05,299 - DEBUG - ydb.table.SessionPool - _destroy: Sent delete on session <ydb.table.Session object at 0x7fe8929aa680>
2025-11-14 06:52:05,300 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, 92b01f15-4265-4dc3-93c8-ea23d16647b8, ghrun-iuibjpfjoa.auto.internal:13521): on response callback started
2025-11-14 06:52:05,300 - DEBUG - ydb.table.SessionPool - stop: Destroyed active sessions
2025-11-14 06:52:05,301 - DEBUG - ydb.connection - _log_response: RpcState(DeleteSession, 92b01f15-4265-4dc3-93c8-ea23d16647b8, ghrun-iuibjpfjoa.auto.internal:13521): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:52:05,301 - INFO - ydb.connection - close: Closing channel for endpoint localhost:14696
2025-11-14 06:52:05,301 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, 92b01f15-4265-4dc3-93c8-ea23d16647b8, ghrun-iuibjpfjoa.auto.internal:13521): on response callback success
2025-11-14 06:52:05,361 - INFO - ydb.connection - close: Closing channel for endpoint ghrun-iuibjpfjoa.auto.internal:13521
2025-11-14 06:52:05,369 - INFO - ydb.pool.Discovery - run: Successfully terminated discovery process
2025-11-14 06:52:05,370 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - remove_database: /Root/users/database_0
2025-11-14 06:52:05,370 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_send_op: /Root/users/database_0: send console operation, token None
2025-11-14 06:52:05,373 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_send_op: /Root/users/database_0: response from console: RemoveTenantResponse {
  Response {
    operation {
      id: "ydb://cmsrequest/5?tenant=/Root/users/database_0&cmstid=72057594037936131&txid=1763103125371486&action=2"
    }
  }
}
Status {
  Code: STATUS_CODE_UNSPECIFIED
}

2025-11-14 06:52:05,374 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_op: /Root/users/database_0: wait console operation done
2025-11-14 06:52:05,876 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_op: /Root/users/database_0: console operation done
2025-11-14 06:52:05,876 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_tenant_gone: /Root/users/database_0: wait tenant gone
2025-11-14 06:52:05,878 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_tenant_gone: /Root/users/database_0: tenant gone
2025-11-14 06:52:06,878 - INFO - ydb.tests.library.harness.kikimr_runner - stop: Stopped node localhost:13521/1
2025-11-14 06:52:07,384 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/rl7h/0030e4/ydb/apps/ydbd/ydbd
2025-11-14 06:52:07,385 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/21600
2025-11-14 06:52:07,385 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/27559
2025-11-14 06:52:07,385 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/30142
2025-11-14 06:52:07,386 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/25584
2025-11-14 06:52:07,386 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/8453
2025-11-14 06:52:07,386 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: CFG_DIR_PATH="/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/kikimr_configs"
2025-11-14 06:52:07,387 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: Final command: /home/runner/.ya/build/build_root/rl7h/0030e4/ydb/apps/ydbd/ydbd server --suppress-version-check --yaml-config=$CFG_DIR_PATH/config.yaml --node-broker=localhost:14696 --tenant=/Root/users/database_1 --log-file-name=/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/slot_2/logfile_eexsapbe.log --grpc-port=21600 --mon-port=27559 --ic-port=30142
2025-11-14 06:52:07,387 - DEBUG - ya.test - execute: Executing '('/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/apps/ydbd/ydbd', 'server', '--suppress-version-check', '--yaml-config=/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/kikimr_configs/config.yaml', '--node-broker=localhost:14696', '--tenant=/Root/users/database_1', '--log-file-name=/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/slot_2/logfile_eexsapbe.log', '--grpc-port=21600', '--mon-port=27559', '--ic-port=30142')' in '/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/slot_2' (no wait)
2025-11-14 06:52:07,388 - DEBUG - ya.test - execute: Command pid: 1378087
2025-11-14 06:52:07,389 - INFO - ydb.tests.library.harness.kikimr_runner - start: Started node localhost:21600/2
2025-11-14 06:52:09,392 - 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:52:09,394 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-11-14 06:52:09,395 - 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:52:09,395 - DEBUG - ydb.table.SessionPool - subscribe: Active session queue is empty, subscribe waiter for a session
2025-11-14 06:52:09,398 - DEBUG - ydb.table.SessionPool - subscribe: Subscribe waiter <Future at 0x7fe892971690 state=pending>
2025-11-14 06:52:09,399 - 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:52:09,400 - DEBUG - ydb.table.SessionPool - _create: Created session <ydb.table.Session object at 0x7fe892971fa0>
2025-11-14 06:52:09,400 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7fe892971fa0>
2025-11-14 06:52:09,401 - 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:52:09,402 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database /Root/users/database_1
2025-11-14 06:52:09,402 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, 82cbe67d-ffa3-4a28-91d5-bad615d244de, localhost:14696): creating call state
2025-11-14 06:52:09,402 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, 82cbe67d-ffa3-4a28-91d5-bad615d244de, localhost:14696): request = { database: "/Root/users/database_1" }
2025-11-14 06:52:09,405 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, 82cbe67d-ffa3-4a28-91d5-bad615d244de, localhost:14696): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Discovery.ListEndpointsResult] { endpoints { address: "ghrun-iuibjpfjoa.auto.internal" port: 21600 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: 50001 } self_location: "1" } } } }
2025-11-14 06:52:09,405 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Resolved endpoints for database /Root/users/database_1: DiscoveryResult <self_location: 1, endpoints [<Endpoint ghrun-iuibjpfjoa.auto.internal:21600, location , ssl: False>]>
2025-11-14 06:52:09,406 - 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:52:09,408 - INFO - ydb.connection - close: Closing channel for endpoint localhost:14696
2025-11-14 06:52:09,409 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7fe892971fa0>
2025-11-14 06:52:09,409 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, e09e399a-7221-4331-930d-ce7bb14fb511, ghrun-iuibjpfjoa.auto.internal:21600): creating call state
2025-11-14 06:52:09,410 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, e09e399a-7221-4331-930d-ce7bb14fb511, ghrun-iuibjpfjoa.auto.internal:21600): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-11-14 06:52:09,412 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, e09e399a-7221-4331-930d-ce7bb14fb511, ghrun-iuibjpfjoa.auto.internal:21600): on response callback started
2025-11-14 06:52:09,413 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, e09e399a-7221-4331-930d-ce7bb14fb511, ghrun-iuibjpfjoa.auto.internal:21600): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=50001&id=MmZkYzg3MTktNzIyYzVlYWYtMjdmZmE3OGYtOGQxMWZhYzQ=" } } } }
2025-11-14 06:52:09,413 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe892971fa0>
2025-11-14 06:52:09,413 - DEBUG - ydb.table.SessionPool - put: Replying to waiter with a session <ydb.table.Session object at 0x7fe892971fa0>
2025-11-14 06:52:09,414 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, e09e399a-7221-4331-930d-ce7bb14fb511, ghrun-iuibjpfjoa.auto.internal:21600): on response callback success
2025-11-14 06:52:09,414 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateTable, b2b5be00-1a8c-403a-99ff-aa6ae45c462c, ghrun-iuibjpfjoa.auto.internal:21600): creating call state
2025-11-14 06:52:09,415 - DEBUG - ydb.connection - _log_request: RpcState(CreateTable, b2b5be00-1a8c-403a-99ff-aa6ae45c462c, ghrun-iuibjpfjoa.auto.internal:21600): request = { session_id: "ydb://session/3?node_id=50001&id=MmZkYzg3MTktNzIyYzVlYWYtMjdmZmE3OGYtOGQxMWZhYzQ=" path: "/Root/users/database_1/table" columns { name: "id" type { optional_type { item { type_id: UINT64 } } } } columns { name: "value" type { optional_type { item { type_id: UTF8 } } } } primary_key: "id" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:09,446 - DEBUG - ydb.connection - _log_response: RpcState(CreateTable, b2b5be00-1a8c-403a-99ff-aa6ae45c462c, ghrun-iuibjpfjoa.auto.internal:21600): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:52:09,446 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe892971fa0>
2025-11-14 06:52:09,447 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateTable, e9028314-3633-4c23-82d2-1a9c47165743, ghrun-iuibjpfjoa.auto.internal:21600): creating call state
2025-11-14 06:52:09,447 - DEBUG - ydb.connection - _log_request: RpcState(CreateTable, e9028314-3633-4c23-82d2-1a9c47165743, ghrun-iuibjpfjoa.auto.internal:21600): request = { session_id: "ydb://session/3?node_id=50001&id=MmZkYzg3MTktNzIyYzVlYWYtMjdmZmE3OGYtOGQxMWZhYzQ=" path: "/Root/users/database_1/table_for_rm" columns { name: "id" type { optional_type { item { type_id: UINT64 } } } } columns { name: "value" type { optional_type { item { type_id: UTF8 } } } } primary_key: "id" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:09,469 - DEBUG - ydb.connection - _log_response: RpcState(CreateTable, e9028314-3633-4c23-82d2-1a9c47165743, ghrun-iuibjpfjoa.auto.internal:21600): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:52:09,470 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe892971fa0>
2025-11-14 06:52:09,470 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteDataQuery, 42891fc5-6278-4433-8dbe-e98f95779ac8, ghrun-iuibjpfjoa.auto.internal:21600): creating call state
2025-11-14 06:52:09,471 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteDataQuery, 42891fc5-6278-4433-8dbe-e98f95779ac8, ghrun-iuibjpfjoa.auto.internal:21600): request = { session_id: "ydb://session/3?node_id=50001&id=MmZkYzg3MTktNzIyYzVlYWYtMjdmZmE3OGYtOGQxMWZhYzQ=" tx_control { begin_tx { serializable_read_write { } } commit_tx: true } query { yql_text: "\n                        upsert into table (id, value)\n                        values (1u, \"/Root/users/database_1\");\n                        upsert into table_for_rm (id, value)\n                        values (2u, \"/Root/users/database_1\");\n                        " } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:09,491 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteDataQuery, 42891fc5-6278-4433-8dbe-e98f95779ac8, ghrun-iuibjpfjoa.auto.internal:21600): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { tx_meta { } } } } }
2025-11-14 06:52:09,492 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe892971fa0>
2025-11-14 06:52:09,493 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteDataQuery, 0e9bc1b4-2367-4246-b323-55a6eb2b80ca, ghrun-iuibjpfjoa.auto.internal:21600): creating call state
2025-11-14 06:52:09,493 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteDataQuery, 0e9bc1b4-2367-4246-b323-55a6eb2b80ca, ghrun-iuibjpfjoa.auto.internal:21600): request = { session_id: "ydb://session/3?node_id=50001&id=MmZkYzg3MTktNzIyYzVlYWYtMjdmZmE3OGYtOGQxMWZhYzQ=" tx_control { begin_tx { serializable_read_write { } } commit_tx: true } query { yql_text: "\n                        select id, value FROM table;\n                        select id, value FROM table_for_rm;\n                        " } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:09,518 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteDataQuery, 0e9bc1b4-2367-4246-b323-55a6eb2b80ca, ghrun-iuibjpfjoa.auto.internal:21600): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { result_sets { columns { name: "id" type { optional_type { item { type_id: UINT64 } } } } columns { name: "value" type { optional_type { item { type_id: UTF8 } } } } rows { items { uint64_value: 1 } items { text_value: "/Root/users/database_1" } } } result_sets { columns { name: "id" type { optional_type { item { type_id: UINT64 } } } } columns { name: "value" type { optional_type { item { type_id: UTF8 } } } } rows { items { uint64_value: 2 } items { text_value: "/Root/users/database_1" } } } tx_meta { } } } } }
2025-11-14 06:52:09,519 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe892971fa0>
2025-11-14 06:52:09,520 - DEBUG - ydb.connection - _prepare_call: RpcState(DropTable, 14d0a861-516f-42e0-b68f-a95d35daa650, ghrun-iuibjpfjoa.auto.internal:21600): creating call state
2025-11-14 06:52:09,520 - DEBUG - ydb.connection - _log_request: RpcState(DropTable, 14d0a861-516f-42e0-b68f-a95d35daa650, ghrun-iuibjpfjoa.auto.internal:21600): request = { session_id: "ydb://session/3?node_id=50001&id=MmZkYzg3MTktNzIyYzVlYWYtMjdmZmE3OGYtOGQxMWZhYzQ=" path: "/Root/users/database_1/table_for_rm" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:09,534 - DEBUG - ydb.connection - _log_response: RpcState(DropTable, 14d0a861-516f-42e0-b68f-a95d35daa650, ghrun-iuibjpfjoa.auto.internal:21600): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:52:09,534 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe892971fa0>
2025-11-14 06:52:09,535 - DEBUG - ydb.table.SessionPool - stop: Requested session pool stop.
2025-11-14 06:52:09,535 - DEBUG - ydb.table.SessionPool - stop: Session pool is under stop, cancelling all in flight waiters.
2025-11-14 06:52:09,535 - DEBUG - ydb.table.SessionPool - _terminate_event: Terminated session pool.
2025-11-14 06:52:09,535 - DEBUG - ydb.table.SessionPool - stop: Destroying sessions in active queue
2025-11-14 06:52:09,536 - DEBUG - ydb.table.SessionPool - _destroy: Requested session destroy: <ydb.table.Session object at 0x7fe892971fa0>, reason: session-pool-terminated
2025-11-14 06:52:09,536 - DEBUG - ydb.table.SessionPool - _destroy: Session <ydb.table.Session object at 0x7fe892971fa0> is no longer active. Current active count 0.
2025-11-14 06:52:09,536 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, b72f74fa-f332-40d6-8e66-ca1279db27da, ghrun-iuibjpfjoa.auto.internal:21600): creating call state
2025-11-14 06:52:09,537 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, b72f74fa-f332-40d6-8e66-ca1279db27da, ghrun-iuibjpfjoa.auto.internal:21600): request = { session_id: "ydb://session/3?node_id=50001&id=MmZkYzg3MTktNzIyYzVlYWYtMjdmZmE3OGYtOGQxMWZhYzQ=" operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-11-14 06:52:09,538 - DEBUG - ydb.table.SessionPool - _destroy: Sent delete on session <ydb.table.Session object at 0x7fe892971fa0>
2025-11-14 06:52:09,539 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, b72f74fa-f332-40d6-8e66-ca1279db27da, ghrun-iuibjpfjoa.auto.internal:21600): on response callback started
2025-11-14 06:52:09,539 - DEBUG - ydb.table.SessionPool - stop: Destroyed active sessions
2025-11-14 06:52:09,540 - DEBUG - ydb.connection - _log_response: RpcState(DeleteSession, b72f74fa-f332-40d6-8e66-ca1279db27da, ghrun-iuibjpfjoa.auto.internal:21600): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:52:09,540 - INFO - ydb.connection - close: Closing channel for endpoint localhost:14696
2025-11-14 06:52:09,541 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, b72f74fa-f332-40d6-8e66-ca1279db27da, ghrun-iuibjpfjoa.auto.internal:21600): on response callback success
2025-11-14 06:52:09,605 - INFO - ydb.connection - close: Closing channel for endpoint ghrun-iuibjpfjoa.auto.internal:21600
2025-11-14 06:52:09,610 - INFO - ydb.pool.Discovery - run: Successfully terminated discovery process
2025-11-14 06:52:09,611 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - remove_database: /Root/users/database_1
2025-11-14 06:52:09,611 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_send_op: /Root/users/database_1: send console operation, token None
2025-11-14 06:52:09,613 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_send_op: /Root/users/database_1: response from console: RemoveTenantResponse {
  Response {
    operation {
      id: "ydb://cmsrequest/5?tenant=/Root/users/database_1&cmstid=72057594037936131&txid=1763103129611860&action=2"
    }
  }
}
Status {
  Code: STATUS_CODE_UNSPECIFIED
}

2025-11-14 06:52:09,614 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_op: /Root/users/database_1: wait console operation done
2025-11-14 06:52:10,116 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_op: /Root/users/database_1: console operation done
2025-11-14 06:52:10,116 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_tenant_gone: /Root/users/database_1: wait tenant gone
2025-11-14 06:52:10,117 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_tenant_gone: /Root/users/database_1: tenant gone
2025-11-14 06:52:11,118 - INFO - ydb.tests.library.harness.kikimr_runner - stop: Stopped node localhost:21600/2
2025-11-14 06:52:11,624 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/rl7h/0030e4/ydb/apps/ydbd/ydbd
2025-11-14 06:52:11,624 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/9621
2025-11-14 06:52:11,624 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/5265
2025-11-14 06:52:11,625 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/17595
2025-11-14 06:52:11,625 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/32555
2025-11-14 06:52:11,625 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/10067
2025-11-14 06:52:11,626 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: CFG_DIR_PATH="/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/kikimr_configs"
2025-11-14 06:52:11,626 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: Final command: /home/runner/.ya/build/build_root/rl7h/0030e4/ydb/apps/ydbd/ydbd server --suppress-version-check --yaml-config=$CFG_DIR_PATH/config.yaml --node-broker=localhost:14696 --tenant=/Root/users/database_2 --log-file-name=/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/slot_3/logfile_yxlwatvn.log --grpc-port=9621 --mon-port=5265 --ic-port=17595
2025-11-14 06:52:11,626 - DEBUG - ya.test - execute: Executing '('/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/apps/ydbd/ydbd', 'server', '--suppress-version-check', '--yaml-config=/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/kikimr_configs/config.yaml', '--node-broker=localhost:14696', '--tenant=/Root/users/database_2', '--log-file-name=/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/slot_3/logfile_yxlwatvn.log', '--grpc-port=9621', '--mon-port=5265', '--ic-port=17595')' in '/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/slot_3' (no wait)
2025-11-14 06:52:11,627 - DEBUG - ya.test - execute: Command pid: 1381042
2025-11-14 06:52:11,628 - INFO - ydb.tests.library.harness.kikimr_runner - start: Started node localhost:9621/3
2025-11-14 06:52:13,631 - 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:52:13,633 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-11-14 06:52:13,634 - 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:52:13,634 - DEBUG - ydb.table.SessionPool - subscribe: Active session queue is empty, subscribe waiter for a session
2025-11-14 06:52:13,636 - DEBUG - ydb.table.SessionPool - subscribe: Subscribe waiter <Future at 0x7fe89295b990 state=pending>
2025-11-14 06:52:13,637 - 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:52:13,637 - DEBUG - ydb.table.SessionPool - _create: Created session <ydb.table.Session object at 0x7fe8929592d0>
2025-11-14 06:52:13,638 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7fe8929592d0>
2025-11-14 06:52:13,638 - 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:52:13,639 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database /Root/users/database_2
2025-11-14 06:52:13,639 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, 3a317e45-dacd-46d1-a824-aad718c923b8, localhost:14696): creating call state
2025-11-14 06:52:13,640 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, 3a317e45-dacd-46d1-a824-aad718c923b8, localhost:14696): request = { database: "/Root/users/database_2" }
2025-11-14 06:52:13,642 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, 3a317e45-dacd-46d1-a824-aad718c923b8, localhost:14696): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Discovery.ListEndpointsResult] { endpoints { address: "ghrun-iuibjpfjoa.auto.internal" port: 9621 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: 50002 } self_location: "1" } } } }
2025-11-14 06:52:13,642 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Resolved endpoints for database /Root/users/database_2: DiscoveryResult <self_location: 1, endpoints [<Endpoint ghrun-iuibjpfjoa.auto.internal:9621, location , ssl: False>]>
2025-11-14 06:52:13,642 - 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:52:13,645 - INFO - ydb.connection - close: Closing channel for endpoint localhost:14696
2025-11-14 06:52:13,646 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7fe8929592d0>
2025-11-14 06:52:13,646 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, 1ca8b16a-a87b-46e0-b566-7ce215393092, ghrun-iuibjpfjoa.auto.internal:9621): creating call state
2025-11-14 06:52:13,647 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, 1ca8b16a-a87b-46e0-b566-7ce215393092, ghrun-iuibjpfjoa.auto.internal:9621): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-11-14 06:52:13,649 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, 1ca8b16a-a87b-46e0-b566-7ce215393092, ghrun-iuibjpfjoa.auto.internal:9621): on response callback started
2025-11-14 06:52:13,649 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, 1ca8b16a-a87b-46e0-b566-7ce215393092, ghrun-iuibjpfjoa.auto.internal:9621): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=50002&id=ZjNlODUyOWUtOGFkNzA4MDItYzA4OWFkYWMtMTRlZjdhNTI=" } } } }
2025-11-14 06:52:13,650 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe8929592d0>
2025-11-14 06:52:13,650 - DEBUG - ydb.table.SessionPool - put: Replying to waiter with a session <ydb.table.Session object at 0x7fe8929592d0>
2025-11-14 06:52:13,650 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, 1ca8b16a-a87b-46e0-b566-7ce215393092, ghrun-iuibjpfjoa.auto.internal:9621): on response callback success
2025-11-14 06:52:13,651 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateTable, cdee49d2-1051-4467-b6e1-56bfc314e8ab, ghrun-iuibjpfjoa.auto.internal:9621): creating call state
2025-11-14 06:52:13,651 - DEBUG - ydb.connection - _log_request: RpcState(CreateTable, cdee49d2-1051-4467-b6e1-56bfc314e8ab, ghrun-iuibjpfjoa.auto.internal:9621): request = { session_id: "ydb://session/3?node_id=50002&id=ZjNlODUyOWUtOGFkNzA4MDItYzA4OWFkYWMtMTRlZjdhNTI=" path: "/Root/users/database_2/table" columns { name: "id" type { optional_type { item { type_id: UINT64 } } } } columns { name: "value" type { optional_type { item { type_id: UTF8 } } } } primary_key: "id" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:13,677 - DEBUG - ydb.connection - _log_response: RpcState(CreateTable, cdee49d2-1051-4467-b6e1-56bfc314e8ab, ghrun-iuibjpfjoa.auto.internal:9621): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:52:13,678 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe8929592d0>
2025-11-14 06:52:13,678 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateTable, bc48f438-b941-48cd-8f45-bc1bf4bc489d, ghrun-iuibjpfjoa.auto.internal:9621): creating call state
2025-11-14 06:52:13,679 - DEBUG - ydb.connection - _log_request: RpcState(CreateTable, bc48f438-b941-48cd-8f45-bc1bf4bc489d, ghrun-iuibjpfjoa.auto.internal:9621): request = { session_id: "ydb://session/3?node_id=50002&id=ZjNlODUyOWUtOGFkNzA4MDItYzA4OWFkYWMtMTRlZjdhNTI=" path: "/Root/users/database_2/table_for_rm" columns { name: "id" type { optional_type { item { type_id: UINT64 } } } } columns { name: "value" type { optional_type { item { type_id: UTF8 } } } } primary_key: "id" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:13,698 - DEBUG - ydb.connection - _log_response: RpcState(CreateTable, bc48f438-b941-48cd-8f45-bc1bf4bc489d, ghrun-iuibjpfjoa.auto.internal:9621): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:52:13,699 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe8929592d0>
2025-11-14 06:52:13,699 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteDataQuery, 88c8c2fe-7035-47d9-acf2-8fa6a038d157, ghrun-iuibjpfjoa.auto.internal:9621): creating call state
2025-11-14 06:52:13,702 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteDataQuery, 88c8c2fe-7035-47d9-acf2-8fa6a038d157, ghrun-iuibjpfjoa.auto.internal:9621): request = { session_id: "ydb://session/3?node_id=50002&id=ZjNlODUyOWUtOGFkNzA4MDItYzA4OWFkYWMtMTRlZjdhNTI=" tx_control { begin_tx { serializable_read_write { } } commit_tx: true } query { yql_text: "\n                        upsert into table (id, value)\n                        values (1u, \"/Root/users/database_2\");\n                        upsert into table_for_rm (id, value)\n                        values (2u, \"/Root/users/database_2\");\n                        " } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:13,724 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteDataQuery, 88c8c2fe-7035-47d9-acf2-8fa6a038d157, ghrun-iuibjpfjoa.auto.internal:9621): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { tx_meta { } } } } }
2025-11-14 06:52:13,724 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe8929592d0>
2025-11-14 06:52:13,725 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteDataQuery, 89f006d3-5990-4eb3-9eaf-19e96791e058, ghrun-iuibjpfjoa.auto.internal:9621): creating call state
2025-11-14 06:52:13,725 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteDataQuery, 89f006d3-5990-4eb3-9eaf-19e96791e058, ghrun-iuibjpfjoa.auto.internal:9621): request = { session_id: "ydb://session/3?node_id=50002&id=ZjNlODUyOWUtOGFkNzA4MDItYzA4OWFkYWMtMTRlZjdhNTI=" tx_control { begin_tx { serializable_read_write { } } commit_tx: true } query { yql_text: "\n                        select id, value FROM table;\n                        select id, value FROM table_for_rm;\n                        " } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:13,757 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteDataQuery, 89f006d3-5990-4eb3-9eaf-19e96791e058, ghrun-iuibjpfjoa.auto.internal:9621): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { result_sets { columns { name: "id" type { optional_type { item { type_id: UINT64 } } } } columns { name: "value" type { optional_type { item { type_id: UTF8 } } } } rows { items { uint64_value: 1 } items { text_value: "/Root/users/database_2" } } } result_sets { columns { name: "id" type { optional_type { item { type_id: UINT64 } } } } columns { name: "value" type { optional_type { item { type_id: UTF8 } } } } rows { items { uint64_value: 2 } items { text_value: "/Root/users/database_2" } } } tx_meta { } } } } }
2025-11-14 06:52:13,757 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe8929592d0>
2025-11-14 06:52:13,758 - DEBUG - ydb.connection - _prepare_call: RpcState(DropTable, 2d4ad756-871e-47f1-a19e-49dc94aa1aeb, ghrun-iuibjpfjoa.auto.internal:9621): creating call state
2025-11-14 06:52:13,759 - DEBUG - ydb.connection - _log_request: RpcState(DropTable, 2d4ad756-871e-47f1-a19e-49dc94aa1aeb, ghrun-iuibjpfjoa.auto.internal:9621): request = { session_id: "ydb://session/3?node_id=50002&id=ZjNlODUyOWUtOGFkNzA4MDItYzA4OWFkYWMtMTRlZjdhNTI=" path: "/Root/users/database_2/table_for_rm" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:13,772 - DEBUG - ydb.connection - _log_response: RpcState(DropTable, 2d4ad756-871e-47f1-a19e-49dc94aa1aeb, ghrun-iuibjpfjoa.auto.internal:9621): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:52:13,773 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe8929592d0>
2025-11-14 06:52:13,773 - DEBUG - ydb.table.SessionPool - stop: Requested session pool stop.
2025-11-14 06:52:13,773 - DEBUG - ydb.table.SessionPool - stop: Session pool is under stop, cancelling all in flight waiters.
2025-11-14 06:52:13,774 - DEBUG - ydb.table.SessionPool - _terminate_event: Terminated session pool.
2025-11-14 06:52:13,774 - DEBUG - ydb.table.SessionPool - stop: Destroying sessions in active queue
2025-11-14 06:52:13,774 - DEBUG - ydb.table.SessionPool - _destroy: Requested session destroy: <ydb.table.Session object at 0x7fe8929592d0>, reason: session-pool-terminated
2025-11-14 06:52:13,775 - DEBUG - ydb.table.SessionPool - _destroy: Session <ydb.table.Session object at 0x7fe8929592d0> is no longer active. Current active count 0.
2025-11-14 06:52:13,775 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, 4582358c-c941-41fd-b87e-a3e3f9ccc01a, ghrun-iuibjpfjoa.auto.internal:9621): creating call state
2025-11-14 06:52:13,775 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, 4582358c-c941-41fd-b87e-a3e3f9ccc01a, ghrun-iuibjpfjoa.auto.internal:9621): request = { session_id: "ydb://session/3?node_id=50002&id=ZjNlODUyOWUtOGFkNzA4MDItYzA4OWFkYWMtMTRlZjdhNTI=" operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-11-14 06:52:13,777 - DEBUG - ydb.table.SessionPool - _destroy: Sent delete on session <ydb.table.Session object at 0x7fe8929592d0>
2025-11-14 06:52:13,777 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, 4582358c-c941-41fd-b87e-a3e3f9ccc01a, ghrun-iuibjpfjoa.auto.internal:9621): on response callback started
2025-11-14 06:52:13,778 - DEBUG - ydb.table.SessionPool - stop: Destroyed active sessions
2025-11-14 06:52:13,778 - DEBUG - ydb.connection - _log_response: RpcState(DeleteSession, 4582358c-c941-41fd-b87e-a3e3f9ccc01a, ghrun-iuibjpfjoa.auto.internal:9621): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:52:13,779 - INFO - ydb.connection - close: Closing channel for endpoint localhost:14696
2025-11-14 06:52:13,779 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, 4582358c-c941-41fd-b87e-a3e3f9ccc01a, ghrun-iuibjpfjoa.auto.internal:9621): on response callback success
2025-11-14 06:52:13,842 - INFO - ydb.connection - close: Closing channel for endpoint ghrun-iuibjpfjoa.auto.internal:9621
2025-11-14 06:52:13,848 - INFO - ydb.pool.Discovery - run: Successfully terminated discovery process
2025-11-14 06:52:13,848 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - remove_database: /Root/users/database_2
2025-11-14 06:52:13,848 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_send_op: /Root/users/database_2: send console operation, token None
2025-11-14 06:52:13,851 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_send_op: /Root/users/database_2: response from console: RemoveTenantResponse {
  Response {
    operation {
      id: "ydb://cmsrequest/5?tenant=/Root/users/database_2&cmstid=72057594037936131&txid=1763103133849164&action=2"
    }
  }
}
Status {
  Code: STATUS_CODE_UNSPECIFIED
}

2025-11-14 06:52:13,851 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_op: /Root/users/database_2: wait console operation done
2025-11-14 06:52:14,353 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_op: /Root/users/database_2: console operation done
2025-11-14 06:52:14,353 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_tenant_gone: /Root/users/database_2: wait tenant gone
2025-11-14 06:52:14,354 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_tenant_gone: /Root/users/database_2: tenant gone
2025-11-14 06:52:15,355 - INFO - ydb.tests.library.harness.kikimr_runner - stop: Stopped node localhost:9621/3
2025-11-14 06:52:15,861 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/rl7h/0030e4/ydb/apps/ydbd/ydbd
2025-11-14 06:52:15,862 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/9234
2025-11-14 06:52:15,862 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/4245
2025-11-14 06:52:15,862 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/26484
2025-11-14 06:52:15,863 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/62208
2025-11-14 06:52:15,863 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/23112
2025-11-14 06:52:15,863 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: CFG_DIR_PATH="/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/kikimr_configs"
2025-11-14 06:52:15,864 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: Final command: /home/runner/.ya/build/build_root/rl7h/0030e4/ydb/apps/ydbd/ydbd server --suppress-version-check --yaml-config=$CFG_DIR_PATH/config.yaml --node-broker=localhost:14696 --tenant=/Root/users/database_3 --log-file-name=/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/slot_4/logfile_en0uv7nl.log --grpc-port=9234 --mon-port=4245 --ic-port=26484
2025-11-14 06:52:15,864 - DEBUG - ya.test - execute: Executing '('/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/apps/ydbd/ydbd', 'server', '--suppress-version-check', '--yaml-config=/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/kikimr_configs/config.yaml', '--node-broker=localhost:14696', '--tenant=/Root/users/database_3', '--log-file-name=/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/slot_4/logfile_en0uv7nl.log', '--grpc-port=9234', '--mon-port=4245', '--ic-port=26484')' in '/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/slot_4' (no wait)
2025-11-14 06:52:15,865 - DEBUG - ya.test - execute: Command pid: 1384297
2025-11-14 06:52:15,866 - INFO - ydb.tests.library.harness.kikimr_runner - start: Started node localhost:9234/4
2025-11-14 06:52:17,869 - 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:52:17,871 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-11-14 06:52:17,872 - DEBUG - ydb.table.SessionPool - subscribe: Active session queue is empty, subscribe waiter for a session
2025-11-14 06:52:17,872 - 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:52:17,872 - DEBUG - ydb.table.SessionPool - subscribe: Subscribe waiter <Future at 0x7fe894ba9dc0 state=pending>
2025-11-14 06:52:17,874 - 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:52:17,875 - DEBUG - ydb.table.SessionPool - _create: Created session <ydb.table.Session object at 0x7fe894baba30>
2025-11-14 06:52:17,875 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7fe894baba30>
2025-11-14 06:52:17,876 - 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:52:17,878 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database /Root/users/database_3
2025-11-14 06:52:17,878 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, 8ce3c113-4a8f-4612-9538-86ec6ec39e65, localhost:14696): creating call state
2025-11-14 06:52:17,878 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, 8ce3c113-4a8f-4612-9538-86ec6ec39e65, localhost:14696): request = { database: "/Root/users/database_3" }
2025-11-14 06:52:17,881 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, 8ce3c113-4a8f-4612-9538-86ec6ec39e65, localhost:14696): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Discovery.ListEndpointsResult] { endpoints { address: "ghrun-iuibjpfjoa.auto.internal" port: 9234 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: 50003 } self_location: "1" } } } }
2025-11-14 06:52:17,881 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Resolved endpoints for database /Root/users/database_3: DiscoveryResult <self_location: 1, endpoints [<Endpoint ghrun-iuibjpfjoa.auto.internal:9234, location , ssl: False>]>
2025-11-14 06:52:17,881 - 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:52:17,884 - INFO - ydb.connection - close: Closing channel for endpoint localhost:14696
2025-11-14 06:52:17,884 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7fe894baba30>
2025-11-14 06:52:17,884 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, 107c1a75-cd35-4272-8e9c-4f2309b5da61, ghrun-iuibjpfjoa.auto.internal:9234): creating call state
2025-11-14 06:52:17,885 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, 107c1a75-cd35-4272-8e9c-4f2309b5da61, ghrun-iuibjpfjoa.auto.internal:9234): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-11-14 06:52:17,887 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, 107c1a75-cd35-4272-8e9c-4f2309b5da61, ghrun-iuibjpfjoa.auto.internal:9234): on response callback started
2025-11-14 06:52:17,887 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, 107c1a75-cd35-4272-8e9c-4f2309b5da61, ghrun-iuibjpfjoa.auto.internal:9234): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=50003&id=ZmQzNDQ4MjItMWYwYzczZjQtNTc3YThhZDgtMjEwN2M4YQ==" } } } }
2025-11-14 06:52:17,888 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe894baba30>
2025-11-14 06:52:17,888 - DEBUG - ydb.table.SessionPool - put: Replying to waiter with a session <ydb.table.Session object at 0x7fe894baba30>
2025-11-14 06:52:17,888 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, 107c1a75-cd35-4272-8e9c-4f2309b5da61, ghrun-iuibjpfjoa.auto.internal:9234): on response callback success
2025-11-14 06:52:17,889 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateTable, 6be07491-3e92-4c58-a92b-d6dcafb3bc68, ghrun-iuibjpfjoa.auto.internal:9234): creating call state
2025-11-14 06:52:17,889 - DEBUG - ydb.connection - _log_request: RpcState(CreateTable, 6be07491-3e92-4c58-a92b-d6dcafb3bc68, ghrun-iuibjpfjoa.auto.internal:9234): request = { session_id: "ydb://session/3?node_id=50003&id=ZmQzNDQ4MjItMWYwYzczZjQtNTc3YThhZDgtMjEwN2M4YQ==" path: "/Root/users/database_3/table" columns { name: "id" type { optional_type { item { type_id: UINT64 } } } } columns { name: "value" type { optional_type { item { type_id: UTF8 } } } } primary_key: "id" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:17,920 - DEBUG - ydb.connection - _log_response: RpcState(CreateTable, 6be07491-3e92-4c58-a92b-d6dcafb3bc68, ghrun-iuibjpfjoa.auto.internal:9234): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:52:17,921 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe894baba30>
2025-11-14 06:52:17,921 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateTable, 808457c1-098a-43e4-a3b5-7ec7345ea64d, ghrun-iuibjpfjoa.auto.internal:9234): creating call state
2025-11-14 06:52:17,922 - DEBUG - ydb.connection - _log_request: RpcState(CreateTable, 808457c1-098a-43e4-a3b5-7ec7345ea64d, ghrun-iuibjpfjoa.auto.internal:9234): request = { session_id: "ydb://session/3?node_id=50003&id=ZmQzNDQ4MjItMWYwYzczZjQtNTc3YThhZDgtMjEwN2M4YQ==" path: "/Root/users/database_3/table_for_rm" columns { name: "id" type { optional_type { item { type_id: UINT64 } } } } columns { name: "value" type { optional_type { item { type_id: UTF8 } } } } primary_key: "id" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:17,941 - DEBUG - ydb.connection - _log_response: RpcState(CreateTable, 808457c1-098a-43e4-a3b5-7ec7345ea64d, ghrun-iuibjpfjoa.auto.internal:9234): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:52:17,941 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe894baba30>
2025-11-14 06:52:17,941 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteDataQuery, cad7a6ae-c616-4c5f-a87c-94de217e4d20, ghrun-iuibjpfjoa.auto.internal:9234): creating call state
2025-11-14 06:52:17,942 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteDataQuery, cad7a6ae-c616-4c5f-a87c-94de217e4d20, ghrun-iuibjpfjoa.auto.internal:9234): request = { session_id: "ydb://session/3?node_id=50003&id=ZmQzNDQ4MjItMWYwYzczZjQtNTc3YThhZDgtMjEwN2M4YQ==" tx_control { begin_tx { serializable_read_write { } } commit_tx: true } query { yql_text: "\n                        upsert into table (id, value)\n                        values (1u, \"/Root/users/database_3\");\n                        upsert into table_for_rm (id, value)\n                        values (2u, \"/Root/users/database_3\");\n                        " } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:17,964 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteDataQuery, cad7a6ae-c616-4c5f-a87c-94de217e4d20, ghrun-iuibjpfjoa.auto.internal:9234): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { tx_meta { } } } } }
2025-11-14 06:52:17,965 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe894baba30>
2025-11-14 06:52:17,966 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteDataQuery, 4f7e694e-dd6c-4f3d-b416-bdc5ae4d5640, ghrun-iuibjpfjoa.auto.internal:9234): creating call state
2025-11-14 06:52:17,966 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteDataQuery, 4f7e694e-dd6c-4f3d-b416-bdc5ae4d5640, ghrun-iuibjpfjoa.auto.internal:9234): request = { session_id: "ydb://session/3?node_id=50003&id=ZmQzNDQ4MjItMWYwYzczZjQtNTc3YThhZDgtMjEwN2M4YQ==" tx_control { begin_tx { serializable_read_write { } } commit_tx: true } query { yql_text: "\n                        select id, value FROM table;\n                        select id, value FROM table_for_rm;\n                        " } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:17,988 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteDataQuery, 4f7e694e-dd6c-4f3d-b416-bdc5ae4d5640, ghrun-iuibjpfjoa.auto.internal:9234): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { result_sets { columns { name: "id" type { optional_type { item { type_id: UINT64 } } } } columns { name: "value" type { optional_type { item { type_id: UTF8 } } } } rows { items { uint64_value: 1 } items { text_value: "/Root/users/database_3" } } } result_sets { columns { name: "id" type { optional_type { item { type_id: UINT64 } } } } columns { name: "value" type { optional_type { item { type_id: UTF8 } } } } rows { items { uint64_value: 2 } items { text_value: "/Root/users/database_3" } } } tx_meta { } } } } }
2025-11-14 06:52:17,989 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe894baba30>
2025-11-14 06:52:17,989 - DEBUG - ydb.connection - _prepare_call: RpcState(DropTable, 385fd40b-a7c0-4079-ae08-f46b2fc7d315, ghrun-iuibjpfjoa.auto.internal:9234): creating call state
2025-11-14 06:52:17,989 - DEBUG - ydb.connection - _log_request: RpcState(DropTable, 385fd40b-a7c0-4079-ae08-f46b2fc7d315, ghrun-iuibjpfjoa.auto.internal:9234): request = { session_id: "ydb://session/3?node_id=50003&id=ZmQzNDQ4MjItMWYwYzczZjQtNTc3YThhZDgtMjEwN2M4YQ==" path: "/Root/users/database_3/table_for_rm" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:18,003 - DEBUG - ydb.connection - _log_response: RpcState(DropTable, 385fd40b-a7c0-4079-ae08-f46b2fc7d315, ghrun-iuibjpfjoa.auto.internal:9234): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:52:18,004 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe894baba30>
2025-11-14 06:52:18,004 - DEBUG - ydb.table.SessionPool - stop: Requested session pool stop.
2025-11-14 06:52:18,004 - DEBUG - ydb.table.SessionPool - stop: Session pool is under stop, cancelling all in flight waiters.
2025-11-14 06:52:18,004 - DEBUG - ydb.table.SessionPool - _terminate_event: Terminated session pool.
2025-11-14 06:52:18,005 - DEBUG - ydb.table.SessionPool - stop: Destroying sessions in active queue
2025-11-14 06:52:18,005 - DEBUG - ydb.table.SessionPool - _destroy: Requested session destroy: <ydb.table.Session object at 0x7fe894baba30>, reason: session-pool-terminated
2025-11-14 06:52:18,006 - DEBUG - ydb.table.SessionPool - _destroy: Session <ydb.table.Session object at 0x7fe894baba30> is no longer active. Current active count 0.
2025-11-14 06:52:18,006 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, 29f1f2e5-bc85-40d1-a236-3d80214a0a4e, ghrun-iuibjpfjoa.auto.internal:9234): creating call state
2025-11-14 06:52:18,006 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, 29f1f2e5-bc85-40d1-a236-3d80214a0a4e, ghrun-iuibjpfjoa.auto.internal:9234): request = { session_id: "ydb://session/3?node_id=50003&id=ZmQzNDQ4MjItMWYwYzczZjQtNTc3YThhZDgtMjEwN2M4YQ==" operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-11-14 06:52:18,008 - DEBUG - ydb.table.SessionPool - _destroy: Sent delete on session <ydb.table.Session object at 0x7fe894baba30>
2025-11-14 06:52:18,008 - DEBUG - ydb.table.SessionPool - stop: Destroyed active sessions
2025-11-14 06:52:18,008 - INFO - ydb.connection - close: Closing channel for endpoint localhost:14696
2025-11-14 06:52:18,008 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, 29f1f2e5-bc85-40d1-a236-3d80214a0a4e, ghrun-iuibjpfjoa.auto.internal:9234): on response callback started
2025-11-14 06:52:18,009 - DEBUG - ydb.connection - _log_response: RpcState(DeleteSession, 29f1f2e5-bc85-40d1-a236-3d80214a0a4e, ghrun-iuibjpfjoa.auto.internal:9234): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:52:18,009 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, 29f1f2e5-bc85-40d1-a236-3d80214a0a4e, ghrun-iuibjpfjoa.auto.internal:9234): on response callback success
2025-11-14 06:52:18,081 - INFO - ydb.connection - close: Closing channel for endpoint ghrun-iuibjpfjoa.auto.internal:9234
2025-11-14 06:52:18,087 - INFO - ydb.pool.Discovery - run: Successfully terminated discovery process
2025-11-14 06:52:18,088 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - remove_database: /Root/users/database_3
2025-11-14 06:52:18,089 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_send_op: /Root/users/database_3: send console operation, token None
2025-11-14 06:52:18,092 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_send_op: /Root/users/database_3: response from console: RemoveTenantResponse {
  Response {
    operation {
      id: "ydb://cmsrequest/5?tenant=/Root/users/database_3&cmstid=72057594037936131&txid=1763103138090594&action=2"
    }
  }
}
Status {
  Code: STATUS_CODE_UNSPECIFIED
}

2025-11-14 06:52:18,093 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_op: /Root/users/database_3: wait console operation done
2025-11-14 06:52:18,595 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_op: /Root/users/database_3: console operation done
2025-11-14 06:52:18,595 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_tenant_gone: /Root/users/database_3: wait tenant gone
2025-11-14 06:52:18,596 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_tenant_gone: /Root/users/database_3: tenant gone
2025-11-14 06:52:19,596 - INFO - ydb.tests.library.harness.kikimr_runner - stop: Stopped node localhost:9234/4
2025-11-14 06:52:20,103 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/rl7h/0030e4/ydb/apps/ydbd/ydbd
2025-11-14 06:52:20,104 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/18200
2025-11-14 06:52:20,104 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/28457
2025-11-14 06:52:20,105 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/25412
2025-11-14 06:52:20,105 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/25403
2025-11-14 06:52:20,105 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/4149
2025-11-14 06:52:20,106 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: CFG_DIR_PATH="/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/kikimr_configs"
2025-11-14 06:52:20,106 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: Final command: /home/runner/.ya/build/build_root/rl7h/0030e4/ydb/apps/ydbd/ydbd server --suppress-version-check --yaml-config=$CFG_DIR_PATH/config.yaml --node-broker=localhost:14696 --tenant=/Root/users/database_4 --log-file-name=/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/slot_5/logfile_ufi23s09.log --grpc-port=18200 --mon-port=28457 --ic-port=25412
2025-11-14 06:52:20,106 - DEBUG - ya.test - execute: Executing '('/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/apps/ydbd/ydbd', 'server', '--suppress-version-check', '--yaml-config=/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/kikimr_configs/config.yaml', '--node-broker=localhost:14696', '--tenant=/Root/users/database_4', '--log-file-name=/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/slot_5/logfile_ufi23s09.log', '--grpc-port=18200', '--mon-port=28457', '--ic-port=25412')' in '/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/slot_5' (no wait)
2025-11-14 06:52:20,108 - DEBUG - ya.test - execute: Command pid: 1387755
2025-11-14 06:52:20,108 - INFO - ydb.tests.library.harness.kikimr_runner - start: Started node localhost:18200/5
2025-11-14 06:52:22,112 - 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:52:22,114 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-11-14 06:52:22,115 - 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:52:22,115 - DEBUG - ydb.table.SessionPool - subscribe: Active session queue is empty, subscribe waiter for a session
2025-11-14 06:52:22,118 - DEBUG - ydb.table.SessionPool - subscribe: Subscribe waiter <Future at 0x7fe893126900 state=pending>
2025-11-14 06:52:22,118 - 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:52:22,118 - DEBUG - ydb.table.SessionPool - _create: Created session <ydb.table.Session object at 0x7fe8927b4740>
2025-11-14 06:52:22,119 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7fe8927b4740>
2025-11-14 06:52:22,120 - 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:52:22,121 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database /Root/users/database_4
2025-11-14 06:52:22,122 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, 4b903983-43d5-491d-bfda-46e1cbfbbaff, localhost:14696): creating call state
2025-11-14 06:52:22,122 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, 4b903983-43d5-491d-bfda-46e1cbfbbaff, localhost:14696): request = { database: "/Root/users/database_4" }
2025-11-14 06:52:22,124 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, 4b903983-43d5-491d-bfda-46e1cbfbbaff, localhost:14696): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Discovery.ListEndpointsResult] { endpoints { address: "ghrun-iuibjpfjoa.auto.internal" port: 18200 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: 50004 } self_location: "1" } } } }
2025-11-14 06:52:22,125 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Resolved endpoints for database /Root/users/database_4: DiscoveryResult <self_location: 1, endpoints [<Endpoint ghrun-iuibjpfjoa.auto.internal:18200, location , ssl: False>]>
2025-11-14 06:52:22,125 - 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:52:22,128 - INFO - ydb.connection - close: Closing channel for endpoint localhost:14696
2025-11-14 06:52:22,128 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7fe8927b4740>
2025-11-14 06:52:22,130 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, c4324d58-ffc7-437a-94b6-2e481cb69671, ghrun-iuibjpfjoa.auto.internal:18200): creating call state
2025-11-14 06:52:22,130 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, c4324d58-ffc7-437a-94b6-2e481cb69671, ghrun-iuibjpfjoa.auto.internal:18200): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-11-14 06:52:22,133 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, c4324d58-ffc7-437a-94b6-2e481cb69671, ghrun-iuibjpfjoa.auto.internal:18200): on response callback started
2025-11-14 06:52:22,133 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, c4324d58-ffc7-437a-94b6-2e481cb69671, ghrun-iuibjpfjoa.auto.internal:18200): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=50004&id=NjZmYzc2YWEtYmJkYzdhNjQtZWQyNWRkMDktNjE1MTRjZTQ=" } } } }
2025-11-14 06:52:22,134 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe8927b4740>
2025-11-14 06:52:22,134 - DEBUG - ydb.table.SessionPool - put: Replying to waiter with a session <ydb.table.Session object at 0x7fe8927b4740>
2025-11-14 06:52:22,134 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, c4324d58-ffc7-437a-94b6-2e481cb69671, ghrun-iuibjpfjoa.auto.internal:18200): on response callback success
2025-11-14 06:52:22,135 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateTable, 5a1d492e-421f-4695-a3f5-842fe4a1dc7d, ghrun-iuibjpfjoa.auto.internal:18200): creating call state
2025-11-14 06:52:22,136 - DEBUG - ydb.connection - _log_request: RpcState(CreateTable, 5a1d492e-421f-4695-a3f5-842fe4a1dc7d, ghrun-iuibjpfjoa.auto.internal:18200): request = { session_id: "ydb://session/3?node_id=50004&id=NjZmYzc2YWEtYmJkYzdhNjQtZWQyNWRkMDktNjE1MTRjZTQ=" path: "/Root/users/database_4/table" columns { name: "id" type { optional_type { item { type_id: UINT64 } } } } columns { name: "value" type { optional_type { item { type_id: UTF8 } } } } primary_key: "id" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:22,166 - DEBUG - ydb.connection - _log_response: RpcState(CreateTable, 5a1d492e-421f-4695-a3f5-842fe4a1dc7d, ghrun-iuibjpfjoa.auto.internal:18200): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:52:22,167 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe8927b4740>
2025-11-14 06:52:22,167 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateTable, 71bd322f-bfe6-4cc2-bc20-3671213e63e2, ghrun-iuibjpfjoa.auto.internal:18200): creating call state
2025-11-14 06:52:22,168 - DEBUG - ydb.connection - _log_request: RpcState(CreateTable, 71bd322f-bfe6-4cc2-bc20-3671213e63e2, ghrun-iuibjpfjoa.auto.internal:18200): request = { session_id: "ydb://session/3?node_id=50004&id=NjZmYzc2YWEtYmJkYzdhNjQtZWQyNWRkMDktNjE1MTRjZTQ=" path: "/Root/users/database_4/table_for_rm" columns { name: "id" type { optional_type { item { type_id: UINT64 } } } } columns { name: "value" type { optional_type { item { type_id: UTF8 } } } } primary_key: "id" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:22,190 - DEBUG - ydb.connection - _log_response: RpcState(CreateTable, 71bd322f-bfe6-4cc2-bc20-3671213e63e2, ghrun-iuibjpfjoa.auto.internal:18200): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:52:22,191 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe8927b4740>
2025-11-14 06:52:22,192 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteDataQuery, e46dab94-df17-4e31-a91f-14e735fd142e, ghrun-iuibjpfjoa.auto.internal:18200): creating call state
2025-11-14 06:52:22,192 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteDataQuery, e46dab94-df17-4e31-a91f-14e735fd142e, ghrun-iuibjpfjoa.auto.internal:18200): request = { session_id: "ydb://session/3?node_id=50004&id=NjZmYzc2YWEtYmJkYzdhNjQtZWQyNWRkMDktNjE1MTRjZTQ=" tx_control { begin_tx { serializable_read_write { } } commit_tx: true } query { yql_text: "\n                        upsert into table (id, value)\n                        values (1u, \"/Root/users/database_4\");\n                        upsert into table_for_rm (id, value)\n                        values (2u, \"/Root/users/database_4\");\n                        " } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:22,213 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteDataQuery, e46dab94-df17-4e31-a91f-14e735fd142e, ghrun-iuibjpfjoa.auto.internal:18200): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { tx_meta { } } } } }
2025-11-14 06:52:22,213 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe8927b4740>
2025-11-14 06:52:22,214 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteDataQuery, c495f8eb-879d-4c01-b9b7-6a12e84cb9e9, ghrun-iuibjpfjoa.auto.internal:18200): creating call state
2025-11-14 06:52:22,215 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteDataQuery, c495f8eb-879d-4c01-b9b7-6a12e84cb9e9, ghrun-iuibjpfjoa.auto.internal:18200): request = { session_id: "ydb://session/3?node_id=50004&id=NjZmYzc2YWEtYmJkYzdhNjQtZWQyNWRkMDktNjE1MTRjZTQ=" tx_control { begin_tx { serializable_read_write { } } commit_tx: true } query { yql_text: "\n                        select id, value FROM table;\n                        select id, value FROM table_for_rm;\n                        " } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:22,239 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteDataQuery, c495f8eb-879d-4c01-b9b7-6a12e84cb9e9, ghrun-iuibjpfjoa.auto.internal:18200): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { result_sets { columns { name: "id" type { optional_type { item { type_id: UINT64 } } } } columns { name: "value" type { optional_type { item { type_id: UTF8 } } } } rows { items { uint64_value: 1 } items { text_value: "/Root/users/database_4" } } } result_sets { columns { name: "id" type { optional_type { item { type_id: UINT64 } } } } columns { name: "value" type { optional_type { item { type_id: UTF8 } } } } rows { items { uint64_value: 2 } items { text_value: "/Root/users/database_4" } } } tx_meta { } } } } }
2025-11-14 06:52:22,239 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe8927b4740>
2025-11-14 06:52:22,240 - DEBUG - ydb.connection - _prepare_call: RpcState(DropTable, b58ab696-79e5-4582-af47-1e8fdaa96d08, ghrun-iuibjpfjoa.auto.internal:18200): creating call state
2025-11-14 06:52:22,241 - DEBUG - ydb.connection - _log_request: RpcState(DropTable, b58ab696-79e5-4582-af47-1e8fdaa96d08, ghrun-iuibjpfjoa.auto.internal:18200): request = { session_id: "ydb://session/3?node_id=50004&id=NjZmYzc2YWEtYmJkYzdhNjQtZWQyNWRkMDktNjE1MTRjZTQ=" path: "/Root/users/database_4/table_for_rm" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:22,255 - DEBUG - ydb.connection - _log_response: RpcState(DropTable, b58ab696-79e5-4582-af47-1e8fdaa96d08, ghrun-iuibjpfjoa.auto.internal:18200): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:52:22,255 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe8927b4740>
2025-11-14 06:52:22,256 - DEBUG - ydb.table.SessionPool - stop: Requested session pool stop.
2025-11-14 06:52:22,256 - DEBUG - ydb.table.SessionPool - stop: Session pool is under stop, cancelling all in flight waiters.
2025-11-14 06:52:22,256 - DEBUG - ydb.table.SessionPool - _terminate_event: Terminated session pool.
2025-11-14 06:52:22,257 - DEBUG - ydb.table.SessionPool - stop: Destroying sessions in active queue
2025-11-14 06:52:22,257 - DEBUG - ydb.table.SessionPool - _destroy: Requested session destroy: <ydb.table.Session object at 0x7fe8927b4740>, reason: session-pool-terminated
2025-11-14 06:52:22,258 - DEBUG - ydb.table.SessionPool - _destroy: Session <ydb.table.Session object at 0x7fe8927b4740> is no longer active. Current active count 0.
2025-11-14 06:52:22,258 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, 532b78b9-1cd8-4e86-8bed-61ffbb0003ae, ghrun-iuibjpfjoa.auto.internal:18200): creating call state
2025-11-14 06:52:22,258 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, 532b78b9-1cd8-4e86-8bed-61ffbb0003ae, ghrun-iuibjpfjoa.auto.internal:18200): request = { session_id: "ydb://session/3?node_id=50004&id=NjZmYzc2YWEtYmJkYzdhNjQtZWQyNWRkMDktNjE1MTRjZTQ=" operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-11-14 06:52:22,260 - DEBUG - ydb.table.SessionPool - _destroy: Sent delete on session <ydb.table.Session object at 0x7fe8927b4740>
2025-11-14 06:52:22,260 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, 532b78b9-1cd8-4e86-8bed-61ffbb0003ae, ghrun-iuibjpfjoa.auto.internal:18200): on response callback started
2025-11-14 06:52:22,261 - DEBUG - ydb.table.SessionPool - stop: Destroyed active sessions
2025-11-14 06:52:22,261 - DEBUG - ydb.connection - _log_response: RpcState(DeleteSession, 532b78b9-1cd8-4e86-8bed-61ffbb0003ae, ghrun-iuibjpfjoa.auto.internal:18200): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:52:22,261 - INFO - ydb.connection - close: Closing channel for endpoint localhost:14696
2025-11-14 06:52:22,262 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, 532b78b9-1cd8-4e86-8bed-61ffbb0003ae, ghrun-iuibjpfjoa.auto.internal:18200): on response callback success
2025-11-14 06:52:22,324 - INFO - ydb.connection - close: Closing channel for endpoint ghrun-iuibjpfjoa.auto.internal:18200
2025-11-14 06:52:22,330 - INFO - ydb.pool.Discovery - run: Successfully terminated discovery process
2025-11-14 06:52:22,331 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - remove_database: /Root/users/database_4
2025-11-14 06:52:22,331 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_send_op: /Root/users/database_4: send console operation, token None
2025-11-14 06:52:22,335 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_send_op: /Root/users/database_4: response from console: RemoveTenantResponse {
  Response {
    operation {
      id: "ydb://cmsrequest/5?tenant=/Root/users/database_4&cmstid=72057594037936131&txid=1763103142333025&action=2"
    }
  }
}
Status {
  Code: STATUS_CODE_UNSPECIFIED
}

2025-11-14 06:52:22,335 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_op: /Root/users/database_4: wait console operation done
2025-11-14 06:52:22,838 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_op: /Root/users/database_4: console operation done
2025-11-14 06:52:22,838 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_tenant_gone: /Root/users/database_4: wait tenant gone
2025-11-14 06:52:22,839 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_tenant_gone: /Root/users/database_4: tenant gone
2025-11-14 06:52:23,840 - INFO - ydb.tests.library.harness.kikimr_runner - stop: Stopped node localhost:18200/5
2025-11-14 06:52:24,347 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/rl7h/0030e4/ydb/apps/ydbd/ydbd
2025-11-14 06:52:24,348 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/18237
2025-11-14 06:52:24,348 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/14387
2025-11-14 06:52:24,348 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/17198
2025-11-14 06:52:24,349 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/5186
2025-11-14 06:52:24,349 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/12715
2025-11-14 06:52:24,350 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: CFG_DIR_PATH="/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/kikimr_configs"
2025-11-14 06:52:24,350 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: Final command: /home/runner/.ya/build/build_root/rl7h/0030e4/ydb/apps/ydbd/ydbd server --suppress-version-check --yaml-config=$CFG_DIR_PATH/config.yaml --node-broker=localhost:14696 --tenant=/Root/users/database_5 --log-file-name=/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/slot_6/logfile_3t3oil8w.log --grpc-port=18237 --mon-port=14387 --ic-port=17198
2025-11-14 06:52:24,351 - DEBUG - ya.test - execute: Executing '('/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/apps/ydbd/ydbd', 'server', '--suppress-version-check', '--yaml-config=/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/kikimr_configs/config.yaml', '--node-broker=localhost:14696', '--tenant=/Root/users/database_5', '--log-file-name=/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/slot_6/logfile_3t3oil8w.log', '--grpc-port=18237', '--mon-port=14387', '--ic-port=17198')' in '/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/slot_6' (no wait)
2025-11-14 06:52:24,352 - DEBUG - ya.test - execute: Command pid: 1389510
2025-11-14 06:52:24,353 - INFO - ydb.tests.library.harness.kikimr_runner - start: Started node localhost:18237/6
2025-11-14 06:52:26,357 - 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:52:26,358 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-11-14 06:52:26,359 - 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:52:26,361 - DEBUG - ydb.table.SessionPool - subscribe: Active session queue is empty, subscribe waiter for a session
2025-11-14 06:52:26,362 - DEBUG - ydb.table.SessionPool - subscribe: Subscribe waiter <Future at 0x7fe892623cb0 state=pending>
2025-11-14 06:52:26,363 - 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:52:26,364 - DEBUG - ydb.table.SessionPool - _create: Created session <ydb.table.Session object at 0x7fe892623a80>
2025-11-14 06:52:26,364 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7fe892623a80>
2025-11-14 06:52:26,364 - 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:52:26,365 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database /Root/users/database_5
2025-11-14 06:52:26,366 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, 82fd8c47-395b-4839-870c-e64acbdbb427, localhost:14696): creating call state
2025-11-14 06:52:26,366 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, 82fd8c47-395b-4839-870c-e64acbdbb427, localhost:14696): request = { database: "/Root/users/database_5" }
2025-11-14 06:52:26,368 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, 82fd8c47-395b-4839-870c-e64acbdbb427, localhost:14696): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Discovery.ListEndpointsResult] { endpoints { address: "ghrun-iuibjpfjoa.auto.internal" port: 18237 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: 50005 } self_location: "1" } } } }
2025-11-14 06:52:26,369 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Resolved endpoints for database /Root/users/database_5: DiscoveryResult <self_location: 1, endpoints [<Endpoint ghrun-iuibjpfjoa.auto.internal:18237, location , ssl: False>]>
2025-11-14 06:52:26,369 - 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:52:26,372 - INFO - ydb.connection - close: Closing channel for endpoint localhost:14696
2025-11-14 06:52:26,373 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7fe892623a80>
2025-11-14 06:52:26,373 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, a7d5b14c-d9fb-47a7-845e-725dc7e146e3, ghrun-iuibjpfjoa.auto.internal:18237): creating call state
2025-11-14 06:52:26,374 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, a7d5b14c-d9fb-47a7-845e-725dc7e146e3, ghrun-iuibjpfjoa.auto.internal:18237): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-11-14 06:52:26,376 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, a7d5b14c-d9fb-47a7-845e-725dc7e146e3, ghrun-iuibjpfjoa.auto.internal:18237): on response callback started
2025-11-14 06:52:26,377 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, a7d5b14c-d9fb-47a7-845e-725dc7e146e3, ghrun-iuibjpfjoa.auto.internal:18237): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=50005&id=ODYwZGRiMjktZmI0MjEyMDYtNzMyOTYzMTctNWQ5OWI1ZDU=" } } } }
2025-11-14 06:52:26,377 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe892623a80>
2025-11-14 06:52:26,377 - DEBUG - ydb.table.SessionPool - put: Replying to waiter with a session <ydb.table.Session object at 0x7fe892623a80>
2025-11-14 06:52:26,377 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, a7d5b14c-d9fb-47a7-845e-725dc7e146e3, ghrun-iuibjpfjoa.auto.internal:18237): on response callback success
2025-11-14 06:52:26,378 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateTable, 8ade82a1-0664-478f-ab0e-892fe65a6915, ghrun-iuibjpfjoa.auto.internal:18237): creating call state
2025-11-14 06:52:26,379 - DEBUG - ydb.connection - _log_request: RpcState(CreateTable, 8ade82a1-0664-478f-ab0e-892fe65a6915, ghrun-iuibjpfjoa.auto.internal:18237): request = { session_id: "ydb://session/3?node_id=50005&id=ODYwZGRiMjktZmI0MjEyMDYtNzMyOTYzMTctNWQ5OWI1ZDU=" path: "/Root/users/database_5/table" columns { name: "id" type { optional_type { item { type_id: UINT64 } } } } columns { name: "value" type { optional_type { item { type_id: UTF8 } } } } primary_key: "id" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:26,411 - DEBUG - ydb.connection - _log_response: RpcState(CreateTable, 8ade82a1-0664-478f-ab0e-892fe65a6915, ghrun-iuibjpfjoa.auto.internal:18237): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:52:26,412 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe892623a80>
2025-11-14 06:52:26,412 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateTable, 8f04def9-d216-49f9-aa23-0b29a4033a89, ghrun-iuibjpfjoa.auto.internal:18237): creating call state
2025-11-14 06:52:26,413 - DEBUG - ydb.connection - _log_request: RpcState(CreateTable, 8f04def9-d216-49f9-aa23-0b29a4033a89, ghrun-iuibjpfjoa.auto.internal:18237): request = { session_id: "ydb://session/3?node_id=50005&id=ODYwZGRiMjktZmI0MjEyMDYtNzMyOTYzMTctNWQ5OWI1ZDU=" path: "/Root/users/database_5/table_for_rm" columns { name: "id" type { optional_type { item { type_id: UINT64 } } } } columns { name: "value" type { optional_type { item { type_id: UTF8 } } } } primary_key: "id" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:26,434 - DEBUG - ydb.connection - _log_response: RpcState(CreateTable, 8f04def9-d216-49f9-aa23-0b29a4033a89, ghrun-iuibjpfjoa.auto.internal:18237): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:52:26,435 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe892623a80>
2025-11-14 06:52:26,436 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteDataQuery, 57c3c73f-41a1-4406-961e-ec62a1180c1a, ghrun-iuibjpfjoa.auto.internal:18237): creating call state
2025-11-14 06:52:26,437 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteDataQuery, 57c3c73f-41a1-4406-961e-ec62a1180c1a, ghrun-iuibjpfjoa.auto.internal:18237): request = { session_id: "ydb://session/3?node_id=50005&id=ODYwZGRiMjktZmI0MjEyMDYtNzMyOTYzMTctNWQ5OWI1ZDU=" tx_control { begin_tx { serializable_read_write { } } commit_tx: true } query { yql_text: "\n                        upsert into table (id, value)\n                        values (1u, \"/Root/users/database_5\");\n                        upsert into table_for_rm (id, value)\n                        values (2u, \"/Root/users/database_5\");\n                        " } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:26,462 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteDataQuery, 57c3c73f-41a1-4406-961e-ec62a1180c1a, ghrun-iuibjpfjoa.auto.internal:18237): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { tx_meta { } } } } }
2025-11-14 06:52:26,462 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe892623a80>
2025-11-14 06:52:26,463 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteDataQuery, 8c8f1a42-147b-47a0-a129-d4db9bcf6257, ghrun-iuibjpfjoa.auto.internal:18237): creating call state
2025-11-14 06:52:26,464 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteDataQuery, 8c8f1a42-147b-47a0-a129-d4db9bcf6257, ghrun-iuibjpfjoa.auto.internal:18237): request = { session_id: "ydb://session/3?node_id=50005&id=ODYwZGRiMjktZmI0MjEyMDYtNzMyOTYzMTctNWQ5OWI1ZDU=" tx_control { begin_tx { serializable_read_write { } } commit_tx: true } query { yql_text: "\n                        select id, value FROM table;\n                        select id, value FROM table_for_rm;\n                        " } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:26,490 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteDataQuery, 8c8f1a42-147b-47a0-a129-d4db9bcf6257, ghrun-iuibjpfjoa.auto.internal:18237): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { result_sets { columns { name: "id" type { optional_type { item { type_id: UINT64 } } } } columns { name: "value" type { optional_type { item { type_id: UTF8 } } } } rows { items { uint64_value: 1 } items { text_value: "/Root/users/database_5" } } } result_sets { columns { name: "id" type { optional_type { item { type_id: UINT64 } } } } columns { name: "value" type { optional_type { item { type_id: UTF8 } } } } rows { items { uint64_value: 2 } items { text_value: "/Root/users/database_5" } } } tx_meta { } } } } }
2025-11-14 06:52:26,490 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe892623a80>
2025-11-14 06:52:26,491 - DEBUG - ydb.connection - _prepare_call: RpcState(DropTable, 559181ca-703b-446a-8133-5620d95f8070, ghrun-iuibjpfjoa.auto.internal:18237): creating call state
2025-11-14 06:52:26,492 - DEBUG - ydb.connection - _log_request: RpcState(DropTable, 559181ca-703b-446a-8133-5620d95f8070, ghrun-iuibjpfjoa.auto.internal:18237): request = { session_id: "ydb://session/3?node_id=50005&id=ODYwZGRiMjktZmI0MjEyMDYtNzMyOTYzMTctNWQ5OWI1ZDU=" path: "/Root/users/database_5/table_for_rm" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:26,507 - DEBUG - ydb.connection - _log_response: RpcState(DropTable, 559181ca-703b-446a-8133-5620d95f8070, ghrun-iuibjpfjoa.auto.internal:18237): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:52:26,507 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe892623a80>
2025-11-14 06:52:26,507 - DEBUG - ydb.table.SessionPool - stop: Requested session pool stop.
2025-11-14 06:52:26,508 - DEBUG - ydb.table.SessionPool - stop: Session pool is under stop, cancelling all in flight waiters.
2025-11-14 06:52:26,508 - DEBUG - ydb.table.SessionPool - stop: Destroying sessions in active queue
2025-11-14 06:52:26,508 - DEBUG - ydb.table.SessionPool - _destroy: Requested session destroy: <ydb.table.Session object at 0x7fe892623a80>, reason: session-pool-terminated
2025-11-14 06:52:26,508 - DEBUG - ydb.table.SessionPool - _destroy: Session <ydb.table.Session object at 0x7fe892623a80> is no longer active. Current active count 0.
2025-11-14 06:52:26,508 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, 0f6c9e9a-4ec7-4f59-997d-eb3c041686e4, ghrun-iuibjpfjoa.auto.internal:18237): creating call state
2025-11-14 06:52:26,509 - DEBUG - ydb.table.SessionPool - _terminate_event: Terminated session pool.
2025-11-14 06:52:26,509 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, 0f6c9e9a-4ec7-4f59-997d-eb3c041686e4, ghrun-iuibjpfjoa.auto.internal:18237): request = { session_id: "ydb://session/3?node_id=50005&id=ODYwZGRiMjktZmI0MjEyMDYtNzMyOTYzMTctNWQ5OWI1ZDU=" operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-11-14 06:52:26,512 - DEBUG - ydb.table.SessionPool - _destroy: Sent delete on session <ydb.table.Session object at 0x7fe892623a80>
2025-11-14 06:52:26,512 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, 0f6c9e9a-4ec7-4f59-997d-eb3c041686e4, ghrun-iuibjpfjoa.auto.internal:18237): on response callback started
2025-11-14 06:52:26,513 - DEBUG - ydb.table.SessionPool - stop: Destroyed active sessions
2025-11-14 06:52:26,513 - DEBUG - ydb.connection - _log_response: RpcState(DeleteSession, 0f6c9e9a-4ec7-4f59-997d-eb3c041686e4, ghrun-iuibjpfjoa.auto.internal:18237): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:52:26,513 - INFO - ydb.connection - close: Closing channel for endpoint localhost:14696
2025-11-14 06:52:26,514 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, 0f6c9e9a-4ec7-4f59-997d-eb3c041686e4, ghrun-iuibjpfjoa.auto.internal:18237): on response callback success
2025-11-14 06:52:26,568 - INFO - ydb.connection - close: Closing channel for endpoint ghrun-iuibjpfjoa.auto.internal:18237
2025-11-14 06:52:26,575 - INFO - ydb.pool.Discovery - run: Successfully terminated discovery process
2025-11-14 06:52:26,575 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - remove_database: /Root/users/database_5
2025-11-14 06:52:26,576 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_send_op: /Root/users/database_5: send console operation, token None
2025-11-14 06:52:26,579 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_send_op: /Root/users/database_5: response from console: RemoveTenantResponse {
  Response {
    operation {
      id: "ydb://cmsrequest/5?tenant=/Root/users/database_5&cmstid=72057594037936131&txid=1763103146576463&action=2"
    }
  }
}
Status {
  Code: STATUS_CODE_UNSPECIFIED
}

2025-11-14 06:52:26,580 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_op: /Root/users/database_5: wait console operation done
2025-11-14 06:52:27,081 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_op: /Root/users/database_5: console operation done
2025-11-14 06:52:27,082 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_tenant_gone: /Root/users/database_5: wait tenant gone
2025-11-14 06:52:27,083 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_tenant_gone: /Root/users/database_5: tenant gone
2025-11-14 06:52:28,084 - INFO - ydb.tests.library.harness.kikimr_runner - stop: Stopped node localhost:18237/6
2025-11-14 06:52:28,589 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/rl7h/0030e4/ydb/apps/ydbd/ydbd
2025-11-14 06:52:28,590 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/3609
2025-11-14 06:52:28,590 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/30902
2025-11-14 06:52:28,591 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/27713
2025-11-14 06:52:28,591 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/23535
2025-11-14 06:52:28,591 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/23535
2025-11-14 06:52:28,591 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/23536
2025-11-14 06:52:28,592 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/19104
2025-11-14 06:52:28,592 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: CFG_DIR_PATH="/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/kikimr_configs"
2025-11-14 06:52:28,592 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: Final command: /home/runner/.ya/build/build_root/rl7h/0030e4/ydb/apps/ydbd/ydbd server --suppress-version-check --yaml-config=$CFG_DIR_PATH/config.yaml --node-broker=localhost:14696 --tenant=/Root/users/database_6 --log-file-name=/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/slot_7/logfile_dges6to_.log --grpc-port=3609 --mon-port=30902 --ic-port=27713
2025-11-14 06:52:28,593 - DEBUG - ya.test - execute: Executing '('/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/apps/ydbd/ydbd', 'server', '--suppress-version-check', '--yaml-config=/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/kikimr_configs/config.yaml', '--node-broker=localhost:14696', '--tenant=/Root/users/database_6', '--log-file-name=/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/slot_7/logfile_dges6to_.log', '--grpc-port=3609', '--mon-port=30902', '--ic-port=27713')' in '/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/slot_7' (no wait)
2025-11-14 06:52:28,595 - DEBUG - ya.test - execute: Command pid: 1392448
2025-11-14 06:52:28,595 - INFO - ydb.tests.library.harness.kikimr_runner - start: Started node localhost:3609/7
2025-11-14 06:52:30,602 - 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:52:30,604 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-11-14 06:52:30,605 - 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:52:30,605 - DEBUG - ydb.table.SessionPool - subscribe: Active session queue is empty, subscribe waiter for a session
2025-11-14 06:52:30,610 - DEBUG - ydb.table.SessionPool - subscribe: Subscribe waiter <Future at 0x7fe8931178a0 state=pending>
2025-11-14 06:52:30,611 - 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:52:30,611 - DEBUG - ydb.table.SessionPool - _create: Created session <ydb.table.Session object at 0x7fe893114600>
2025-11-14 06:52:30,612 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7fe893114600>
2025-11-14 06:52:30,612 - 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:52:30,614 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database /Root/users/database_6
2025-11-14 06:52:30,614 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, 8d2cfeca-7ea0-4e6d-b8b8-4f0d8a0b1c86, localhost:14696): creating call state
2025-11-14 06:52:30,615 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, 8d2cfeca-7ea0-4e6d-b8b8-4f0d8a0b1c86, localhost:14696): request = { database: "/Root/users/database_6" }
2025-11-14 06:52:30,618 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, 8d2cfeca-7ea0-4e6d-b8b8-4f0d8a0b1c86, localhost:14696): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Discovery.ListEndpointsResult] { endpoints { address: "ghrun-iuibjpfjoa.auto.internal" port: 3609 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: 50006 } self_location: "1" } } } }
2025-11-14 06:52:30,619 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Resolved endpoints for database /Root/users/database_6: DiscoveryResult <self_location: 1, endpoints [<Endpoint ghrun-iuibjpfjoa.auto.internal:3609, location , ssl: False>]>
2025-11-14 06:52:30,619 - 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:52:30,622 - INFO - ydb.connection - close: Closing channel for endpoint localhost:14696
2025-11-14 06:52:30,622 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7fe893114600>
2025-11-14 06:52:30,623 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, bcac3229-3dcb-46d8-87f8-41e2d052c4e3, ghrun-iuibjpfjoa.auto.internal:3609): creating call state
2025-11-14 06:52:30,624 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, bcac3229-3dcb-46d8-87f8-41e2d052c4e3, ghrun-iuibjpfjoa.auto.internal:3609): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-11-14 06:52:30,627 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, bcac3229-3dcb-46d8-87f8-41e2d052c4e3, ghrun-iuibjpfjoa.auto.internal:3609): on response callback started
2025-11-14 06:52:30,628 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, bcac3229-3dcb-46d8-87f8-41e2d052c4e3, ghrun-iuibjpfjoa.auto.internal:3609): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=50006&id=NzAyN2U2YjAtOTU2YWQyZWYtMmZkMDBjLWFmZDFkNDA0" } } } }
2025-11-14 06:52:30,628 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe893114600>
2025-11-14 06:52:30,629 - DEBUG - ydb.table.SessionPool - put: Replying to waiter with a session <ydb.table.Session object at 0x7fe893114600>
2025-11-14 06:52:30,629 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, bcac3229-3dcb-46d8-87f8-41e2d052c4e3, ghrun-iuibjpfjoa.auto.internal:3609): on response callback success
2025-11-14 06:52:30,631 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateTable, d0890865-25b6-4eb7-833b-d44845bb098b, ghrun-iuibjpfjoa.auto.internal:3609): creating call state
2025-11-14 06:52:30,632 - DEBUG - ydb.connection - _log_request: RpcState(CreateTable, d0890865-25b6-4eb7-833b-d44845bb098b, ghrun-iuibjpfjoa.auto.internal:3609): request = { session_id: "ydb://session/3?node_id=50006&id=NzAyN2U2YjAtOTU2YWQyZWYtMmZkMDBjLWFmZDFkNDA0" path: "/Root/users/database_6/table" columns { name: "id" type { optional_type { item { type_id: UINT64 } } } } columns { name: "value" type { optional_type { item { type_id: UTF8 } } } } primary_key: "id" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:30,749 - DEBUG - ydb.connection - _log_response: RpcState(CreateTable, d0890865-25b6-4eb7-833b-d44845bb098b, ghrun-iuibjpfjoa.auto.internal:3609): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:52:30,749 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe893114600>
2025-11-14 06:52:30,750 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateTable, fffb5832-fbb4-414e-824a-a0b3c03935de, ghrun-iuibjpfjoa.auto.internal:3609): creating call state
2025-11-14 06:52:30,750 - DEBUG - ydb.connection - _log_request: RpcState(CreateTable, fffb5832-fbb4-414e-824a-a0b3c03935de, ghrun-iuibjpfjoa.auto.internal:3609): request = { session_id: "ydb://session/3?node_id=50006&id=NzAyN2U2YjAtOTU2YWQyZWYtMmZkMDBjLWFmZDFkNDA0" path: "/Root/users/database_6/table_for_rm" columns { name: "id" type { optional_type { item { type_id: UINT64 } } } } columns { name: "value" type { optional_type { item { type_id: UTF8 } } } } primary_key: "id" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:30,778 - DEBUG - ydb.connection - _log_response: RpcState(CreateTable, fffb5832-fbb4-414e-824a-a0b3c03935de, ghrun-iuibjpfjoa.auto.internal:3609): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:52:30,778 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe893114600>
2025-11-14 06:52:30,779 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteDataQuery, 47c27d0d-0f67-40cc-9aca-11192e35bbfb, ghrun-iuibjpfjoa.auto.internal:3609): creating call state
2025-11-14 06:52:30,780 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteDataQuery, 47c27d0d-0f67-40cc-9aca-11192e35bbfb, ghrun-iuibjpfjoa.auto.internal:3609): request = { session_id: "ydb://session/3?node_id=50006&id=NzAyN2U2YjAtOTU2YWQyZWYtMmZkMDBjLWFmZDFkNDA0" tx_control { begin_tx { serializable_read_write { } } commit_tx: true } query { yql_text: "\n                        upsert into table (id, value)\n                        values (1u, \"/Root/users/database_6\");\n                        upsert into table_for_rm (id, value)\n                        values (2u, \"/Root/users/database_6\");\n                        " } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:30,803 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteDataQuery, 47c27d0d-0f67-40cc-9aca-11192e35bbfb, ghrun-iuibjpfjoa.auto.internal:3609): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { tx_meta { } } } } }
2025-11-14 06:52:30,804 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe893114600>
2025-11-14 06:52:30,805 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteDataQuery, cb5874b1-1810-4398-a7b3-a614ccb9e1ff, ghrun-iuibjpfjoa.auto.internal:3609): creating call state
2025-11-14 06:52:30,805 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteDataQuery, cb5874b1-1810-4398-a7b3-a614ccb9e1ff, ghrun-iuibjpfjoa.auto.internal:3609): request = { session_id: "ydb://session/3?node_id=50006&id=NzAyN2U2YjAtOTU2YWQyZWYtMmZkMDBjLWFmZDFkNDA0" tx_control { begin_tx { serializable_read_write { } } commit_tx: true } query { yql_text: "\n                        select id, value FROM table;\n                        select id, value FROM table_for_rm;\n                        " } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:30,835 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteDataQuery, cb5874b1-1810-4398-a7b3-a614ccb9e1ff, ghrun-iuibjpfjoa.auto.internal:3609): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { result_sets { columns { name: "id" type { optional_type { item { type_id: UINT64 } } } } columns { name: "value" type { optional_type { item { type_id: UTF8 } } } } rows { items { uint64_value: 1 } items { text_value: "/Root/users/database_6" } } } result_sets { columns { name: "id" type { optional_type { item { type_id: UINT64 } } } } columns { name: "value" type { optional_type { item { type_id: UTF8 } } } } rows { items { uint64_value: 2 } items { text_value: "/Root/users/database_6" } } } tx_meta { } } } } }
2025-11-14 06:52:30,836 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe893114600>
2025-11-14 06:52:30,836 - DEBUG - ydb.connection - _prepare_call: RpcState(DropTable, af6ad7d1-5b06-4247-ad70-9352a790a5bb, ghrun-iuibjpfjoa.auto.internal:3609): creating call state
2025-11-14 06:52:30,837 - DEBUG - ydb.connection - _log_request: RpcState(DropTable, af6ad7d1-5b06-4247-ad70-9352a790a5bb, ghrun-iuibjpfjoa.auto.internal:3609): request = { session_id: "ydb://session/3?node_id=50006&id=NzAyN2U2YjAtOTU2YWQyZWYtMmZkMDBjLWFmZDFkNDA0" path: "/Root/users/database_6/table_for_rm" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:30,853 - DEBUG - ydb.connection - _log_response: RpcState(DropTable, af6ad7d1-5b06-4247-ad70-9352a790a5bb, ghrun-iuibjpfjoa.auto.internal:3609): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:52:30,854 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe893114600>
2025-11-14 06:52:30,854 - DEBUG - ydb.table.SessionPool - stop: Requested session pool stop.
2025-11-14 06:52:30,854 - DEBUG - ydb.table.SessionPool - stop: Session pool is under stop, cancelling all in flight waiters.
2025-11-14 06:52:30,855 - DEBUG - ydb.table.SessionPool - _terminate_event: Terminated session pool.
2025-11-14 06:52:30,855 - DEBUG - ydb.table.SessionPool - stop: Destroying sessions in active queue
2025-11-14 06:52:30,856 - DEBUG - ydb.table.SessionPool - _destroy: Requested session destroy: <ydb.table.Session object at 0x7fe893114600>, reason: session-pool-terminated
2025-11-14 06:52:30,856 - DEBUG - ydb.table.SessionPool - _destroy: Session <ydb.table.Session object at 0x7fe893114600> is no longer active. Current active count 0.
2025-11-14 06:52:30,856 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, 5d19ba2b-8a46-435a-9824-214384e5b03e, ghrun-iuibjpfjoa.auto.internal:3609): creating call state
2025-11-14 06:52:30,857 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, 5d19ba2b-8a46-435a-9824-214384e5b03e, ghrun-iuibjpfjoa.auto.internal:3609): request = { session_id: "ydb://session/3?node_id=50006&id=NzAyN2U2YjAtOTU2YWQyZWYtMmZkMDBjLWFmZDFkNDA0" operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-11-14 06:52:30,859 - DEBUG - ydb.table.SessionPool - _destroy: Sent delete on session <ydb.table.Session object at 0x7fe893114600>
2025-11-14 06:52:30,859 - DEBUG - ydb.table.SessionPool - stop: Destroyed active sessions
2025-11-14 06:52:30,859 - INFO - ydb.connection - close: Closing channel for endpoint localhost:14696
2025-11-14 06:52:30,860 - INFO - ydb.connection - close: Closing channel for endpoint ghrun-iuibjpfjoa.auto.internal:3609
2025-11-14 06:52:30,861 - INFO - ydb.pool.Discovery - run: Successfully terminated discovery process
2025-11-14 06:52:30,860 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, 5d19ba2b-8a46-435a-9824-214384e5b03e, ghrun-iuibjpfjoa.auto.internal:3609): on response callback started
2025-11-14 06:52:30,861 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - remove_database: /Root/users/database_6
2025-11-14 06:52:30,862 - DEBUG - ydb.connection - _log_response: RpcState(DeleteSession, 5d19ba2b-8a46-435a-9824-214384e5b03e, ghrun-iuibjpfjoa.auto.internal:3609): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:52:30,864 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_send_op: /Root/users/database_6: send console operation, token None
2025-11-14 06:52:30,865 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, 5d19ba2b-8a46-435a-9824-214384e5b03e, ghrun-iuibjpfjoa.auto.internal:3609): on response callback success
2025-11-14 06:52:30,869 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_send_op: /Root/users/database_6: response from console: RemoveTenantResponse {
  Response {
    operation {
      id: "ydb://cmsrequest/5?tenant=/Root/users/database_6&cmstid=72057594037936131&txid=1763103150866000&action=2"
    }
  }
}
Status {
  Code: STATUS_CODE_UNSPECIFIED
}

2025-11-14 06:52:30,870 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_op: /Root/users/database_6: wait console operation done
2025-11-14 06:52:31,372 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_op: /Root/users/database_6: console operation done
2025-11-14 06:52:31,373 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_tenant_gone: /Root/users/database_6: wait tenant gone
2025-11-14 06:52:31,374 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_tenant_gone: /Root/users/database_6: tenant gone
2025-11-14 06:52:34,378 - INFO - ydb.tests.library.harness.kikimr_runner - stop: Stopped node localhost:3609/7
2025-11-14 06:52:34,886 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/rl7h/0030e4/ydb/apps/ydbd/ydbd
2025-11-14 06:52:34,889 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/29582
2025-11-14 06:52:34,889 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/28567
2025-11-14 06:52:34,889 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/29215
2025-11-14 06:52:34,890 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/10476
2025-11-14 06:52:34,890 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/31801
2025-11-14 06:52:34,891 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: CFG_DIR_PATH="/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/kikimr_configs"
2025-11-14 06:52:34,891 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: Final command: /home/runner/.ya/build/build_root/rl7h/0030e4/ydb/apps/ydbd/ydbd server --suppress-version-check --yaml-config=$CFG_DIR_PATH/config.yaml --node-broker=localhost:14696 --tenant=/Root/users/database_7 --log-file-name=/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/slot_8/logfile_hf1ew3sw.log --grpc-port=29582 --mon-port=28567 --ic-port=29215
2025-11-14 06:52:34,892 - DEBUG - ya.test - execute: Executing '('/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/apps/ydbd/ydbd', 'server', '--suppress-version-check', '--yaml-config=/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/kikimr_configs/config.yaml', '--node-broker=localhost:14696', '--tenant=/Root/users/database_7', '--log-file-name=/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/slot_8/logfile_hf1ew3sw.log', '--grpc-port=29582', '--mon-port=28567', '--ic-port=29215')' in '/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/slot_8' (no wait)
2025-11-14 06:52:34,894 - DEBUG - ya.test - execute: Command pid: 1399954
2025-11-14 06:52:34,894 - INFO - ydb.tests.library.harness.kikimr_runner - start: Started node localhost:29582/8
2025-11-14 06:52:36,899 - 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:52:36,901 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-11-14 06:52:36,903 - 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:52:36,903 - DEBUG - ydb.table.SessionPool - subscribe: Active session queue is empty, subscribe waiter for a session
2025-11-14 06:52:36,906 - DEBUG - ydb.table.SessionPool - subscribe: Subscribe waiter <Future at 0x7fe894c441f0 state=pending>
2025-11-14 06:52:36,906 - 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:52:36,907 - DEBUG - ydb.table.SessionPool - _create: Created session <ydb.table.Session object at 0x7fe894c44b50>
2025-11-14 06:52:36,908 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7fe894c44b50>
2025-11-14 06:52:36,909 - 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:52:36,910 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database /Root/users/database_7
2025-11-14 06:52:36,911 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, 2f2fd463-ddd7-4562-92de-2e4707424e1c, localhost:14696): creating call state
2025-11-14 06:52:36,912 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, 2f2fd463-ddd7-4562-92de-2e4707424e1c, localhost:14696): request = { database: "/Root/users/database_7" }
2025-11-14 06:52:36,915 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, 2f2fd463-ddd7-4562-92de-2e4707424e1c, localhost:14696): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Discovery.ListEndpointsResult] { endpoints { address: "ghrun-iuibjpfjoa.auto.internal" port: 29582 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: 50007 } self_location: "1" } } } }
2025-11-14 06:52:36,916 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Resolved endpoints for database /Root/users/database_7: DiscoveryResult <self_location: 1, endpoints [<Endpoint ghrun-iuibjpfjoa.auto.internal:29582, location , ssl: False>]>
2025-11-14 06:52:36,918 - 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:52:36,924 - INFO - ydb.connection - close: Closing channel for endpoint localhost:14696
2025-11-14 06:52:36,924 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7fe894c44b50>
2025-11-14 06:52:36,925 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, eb0d8380-818e-4432-9ae9-c7de1183efb6, ghrun-iuibjpfjoa.auto.internal:29582): creating call state
2025-11-14 06:52:36,926 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, eb0d8380-818e-4432-9ae9-c7de1183efb6, ghrun-iuibjpfjoa.auto.internal:29582): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-11-14 06:52:36,929 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, eb0d8380-818e-4432-9ae9-c7de1183efb6, ghrun-iuibjpfjoa.auto.internal:29582): on response callback started
2025-11-14 06:52:36,930 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, eb0d8380-818e-4432-9ae9-c7de1183efb6, ghrun-iuibjpfjoa.auto.internal:29582): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=50007&id=NWM4MjVhM2EtODUwYzRkYWQtNDhjYzAxMmQtMzNjZTU1OWY=" } } } }
2025-11-14 06:52:36,930 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe894c44b50>
2025-11-14 06:52:36,930 - DEBUG - ydb.table.SessionPool - put: Replying to waiter with a session <ydb.table.Session object at 0x7fe894c44b50>
2025-11-14 06:52:36,931 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateTable, f71c9bb8-9eb9-47fe-832d-a7e1f62955cf, ghrun-iuibjpfjoa.auto.internal:29582): creating call state
2025-11-14 06:52:36,931 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, eb0d8380-818e-4432-9ae9-c7de1183efb6, ghrun-iuibjpfjoa.auto.internal:29582): on response callback success
2025-11-14 06:52:36,932 - DEBUG - ydb.connection - _log_request: RpcState(CreateTable, f71c9bb8-9eb9-47fe-832d-a7e1f62955cf, ghrun-iuibjpfjoa.auto.internal:29582): request = { session_id: "ydb://session/3?node_id=50007&id=NWM4MjVhM2EtODUwYzRkYWQtNDhjYzAxMmQtMzNjZTU1OWY=" path: "/Root/users/database_7/table" columns { name: "id" type { optional_type { item { type_id: UINT64 } } } } columns { name: "value" type { optional_type { item { type_id: UTF8 } } } } primary_key: "id" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:36,967 - DEBUG - ydb.connection - _log_response: RpcState(CreateTable, f71c9bb8-9eb9-47fe-832d-a7e1f62955cf, ghrun-iuibjpfjoa.auto.internal:29582): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:52:36,968 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe894c44b50>
2025-11-14 06:52:36,969 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateTable, a95be199-2bb2-4b7d-88a5-543bcf6227ee, ghrun-iuibjpfjoa.auto.internal:29582): creating call state
2025-11-14 06:52:36,969 - DEBUG - ydb.connection - _log_request: RpcState(CreateTable, a95be199-2bb2-4b7d-88a5-543bcf6227ee, ghrun-iuibjpfjoa.auto.internal:29582): request = { session_id: "ydb://session/3?node_id=50007&id=NWM4MjVhM2EtODUwYzRkYWQtNDhjYzAxMmQtMzNjZTU1OWY=" path: "/Root/users/database_7/table_for_rm" columns { name: "id" type { optional_type { item { type_id: UINT64 } } } } columns { name: "value" type { optional_type { item { type_id: UTF8 } } } } primary_key: "id" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:36,996 - DEBUG - ydb.connection - _log_response: RpcState(CreateTable, a95be199-2bb2-4b7d-88a5-543bcf6227ee, ghrun-iuibjpfjoa.auto.internal:29582): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:52:36,996 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe894c44b50>
2025-11-14 06:52:36,997 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteDataQuery, 565480b2-6020-49cb-80f7-5dbe65032809, ghrun-iuibjpfjoa.auto.internal:29582): creating call state
2025-11-14 06:52:36,998 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteDataQuery, 565480b2-6020-49cb-80f7-5dbe65032809, ghrun-iuibjpfjoa.auto.internal:29582): request = { session_id: "ydb://session/3?node_id=50007&id=NWM4MjVhM2EtODUwYzRkYWQtNDhjYzAxMmQtMzNjZTU1OWY=" tx_control { begin_tx { serializable_read_write { } } commit_tx: true } query { yql_text: "\n                        upsert into table (id, value)\n                        values (1u, \"/Root/users/database_7\");\n                        upsert into table_for_rm (id, value)\n                        values (2u, \"/Root/users/database_7\");\n                        " } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:37,024 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteDataQuery, 565480b2-6020-49cb-80f7-5dbe65032809, ghrun-iuibjpfjoa.auto.internal:29582): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { tx_meta { } } } } }
2025-11-14 06:52:37,024 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe894c44b50>
2025-11-14 06:52:37,025 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteDataQuery, 6d58b41b-528e-4e8c-9443-e365a8be3c88, ghrun-iuibjpfjoa.auto.internal:29582): creating call state
2025-11-14 06:52:37,026 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteDataQuery, 6d58b41b-528e-4e8c-9443-e365a8be3c88, ghrun-iuibjpfjoa.auto.internal:29582): request = { session_id: "ydb://session/3?node_id=50007&id=NWM4MjVhM2EtODUwYzRkYWQtNDhjYzAxMmQtMzNjZTU1OWY=" tx_control { begin_tx { serializable_read_write { } } commit_tx: true } query { yql_text: "\n                        select id, value FROM table;\n                        select id, value FROM table_for_rm;\n                        " } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:37,057 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteDataQuery, 6d58b41b-528e-4e8c-9443-e365a8be3c88, ghrun-iuibjpfjoa.auto.internal:29582): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { result_sets { columns { name: "id" type { optional_type { item { type_id: UINT64 } } } } columns { name: "value" type { optional_type { item { type_id: UTF8 } } } } rows { items { uint64_value: 1 } items { text_value: "/Root/users/database_7" } } } result_sets { columns { name: "id" type { optional_type { item { type_id: UINT64 } } } } columns { name: "value" type { optional_type { item { type_id: UTF8 } } } } rows { items { uint64_value: 2 } items { text_value: "/Root/users/database_7" } } } tx_meta { } } } } }
2025-11-14 06:52:37,058 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe894c44b50>
2025-11-14 06:52:37,058 - DEBUG - ydb.connection - _prepare_call: RpcState(DropTable, a814cdf4-7d80-4f44-9874-ecfd7b2d5ce1, ghrun-iuibjpfjoa.auto.internal:29582): creating call state
2025-11-14 06:52:37,059 - DEBUG - ydb.connection - _log_request: RpcState(DropTable, a814cdf4-7d80-4f44-9874-ecfd7b2d5ce1, ghrun-iuibjpfjoa.auto.internal:29582): request = { session_id: "ydb://session/3?node_id=50007&id=NWM4MjVhM2EtODUwYzRkYWQtNDhjYzAxMmQtMzNjZTU1OWY=" path: "/Root/users/database_7/table_for_rm" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:37,075 - DEBUG - ydb.connection - _log_response: RpcState(DropTable, a814cdf4-7d80-4f44-9874-ecfd7b2d5ce1, ghrun-iuibjpfjoa.auto.internal:29582): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:52:37,076 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe894c44b50>
2025-11-14 06:52:37,076 - DEBUG - ydb.table.SessionPool - stop: Requested session pool stop.
2025-11-14 06:52:37,076 - DEBUG - ydb.table.SessionPool - stop: Session pool is under stop, cancelling all in flight waiters.
2025-11-14 06:52:37,076 - DEBUG - ydb.table.SessionPool - stop: Destroying sessions in active queue
2025-11-14 06:52:37,077 - DEBUG - ydb.table.SessionPool - _destroy: Requested session destroy: <ydb.table.Session object at 0x7fe894c44b50>, reason: session-pool-terminated
2025-11-14 06:52:37,077 - DEBUG - ydb.table.SessionPool - _terminate_event: Terminated session pool.
2025-11-14 06:52:37,077 - DEBUG - ydb.table.SessionPool - _destroy: Session <ydb.table.Session object at 0x7fe894c44b50> is no longer active. Current active count 0.
2025-11-14 06:52:37,078 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, fbcc9fc9-cd42-4a9f-99aa-8f978a6d6d40, ghrun-iuibjpfjoa.auto.internal:29582): creating call state
2025-11-14 06:52:37,078 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, fbcc9fc9-cd42-4a9f-99aa-8f978a6d6d40, ghrun-iuibjpfjoa.auto.internal:29582): request = { session_id: "ydb://session/3?node_id=50007&id=NWM4MjVhM2EtODUwYzRkYWQtNDhjYzAxMmQtMzNjZTU1OWY=" operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-11-14 06:52:37,079 - DEBUG - ydb.table.SessionPool - _destroy: Sent delete on session <ydb.table.Session object at 0x7fe894c44b50>
2025-11-14 06:52:37,080 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, fbcc9fc9-cd42-4a9f-99aa-8f978a6d6d40, ghrun-iuibjpfjoa.auto.internal:29582): on response callback started
2025-11-14 06:52:37,080 - DEBUG - ydb.table.SessionPool - stop: Destroyed active sessions
2025-11-14 06:52:37,081 - DEBUG - ydb.connection - _log_response: RpcState(DeleteSession, fbcc9fc9-cd42-4a9f-99aa-8f978a6d6d40, ghrun-iuibjpfjoa.auto.internal:29582): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:52:37,081 - INFO - ydb.connection - close: Closing channel for endpoint localhost:14696
2025-11-14 06:52:37,081 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, fbcc9fc9-cd42-4a9f-99aa-8f978a6d6d40, ghrun-iuibjpfjoa.auto.internal:29582): on response callback success
2025-11-14 06:52:37,113 - INFO - ydb.connection - close: Closing channel for endpoint ghrun-iuibjpfjoa.auto.internal:29582
2025-11-14 06:52:37,127 - INFO - ydb.pool.Discovery - run: Successfully terminated discovery process
2025-11-14 06:52:37,128 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - remove_database: /Root/users/database_7
2025-11-14 06:52:37,128 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_send_op: /Root/users/database_7: send console operation, token None
2025-11-14 06:52:37,132 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_send_op: /Root/users/database_7: response from console: RemoveTenantResponse {
  Response {
    operation {
      id: "ydb://cmsrequest/5?tenant=/Root/users/database_7&cmstid=72057594037936131&txid=1763103157129804&action=2"
    }
  }
}
Status {
  Code: STATUS_CODE_UNSPECIFIED
}

2025-11-14 06:52:37,132 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_op: /Root/users/database_7: wait console operation done
2025-11-14 06:52:37,635 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_op: /Root/users/database_7: console operation done
2025-11-14 06:52:37,635 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_tenant_gone: /Root/users/database_7: wait tenant gone
2025-11-14 06:52:37,637 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_tenant_gone: /Root/users/database_7: tenant gone
2025-11-14 06:52:40,638 - INFO - ydb.tests.library.harness.kikimr_runner - stop: Stopped node localhost:29582/8
2025-11-14 06:52:41,146 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/rl7h/0030e4/ydb/apps/ydbd/ydbd
2025-11-14 06:52:41,147 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/16087
2025-11-14 06:52:41,148 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/12689
2025-11-14 06:52:41,149 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/27618
2025-11-14 06:52:41,149 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/30378
2025-11-14 06:52:41,150 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/27489
2025-11-14 06:52:41,152 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: CFG_DIR_PATH="/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/kikimr_configs"
2025-11-14 06:52:41,152 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: Final command: /home/runner/.ya/build/build_root/rl7h/0030e4/ydb/apps/ydbd/ydbd server --suppress-version-check --yaml-config=$CFG_DIR_PATH/config.yaml --node-broker=localhost:14696 --tenant=/Root/users/database_8 --log-file-name=/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/slot_9/logfile_3exfi8r3.log --grpc-port=16087 --mon-port=12689 --ic-port=27618
2025-11-14 06:52:41,154 - DEBUG - ya.test - execute: Executing '('/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/apps/ydbd/ydbd', 'server', '--suppress-version-check', '--yaml-config=/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/kikimr_configs/config.yaml', '--node-broker=localhost:14696', '--tenant=/Root/users/database_8', '--log-file-name=/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/slot_9/logfile_3exfi8r3.log', '--grpc-port=16087', '--mon-port=12689', '--ic-port=27618')' in '/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/slot_9' (no wait)
2025-11-14 06:52:41,155 - DEBUG - ya.test - execute: Command pid: 1405406
2025-11-14 06:52:41,156 - INFO - ydb.tests.library.harness.kikimr_runner - start: Started node localhost:16087/9
2025-11-14 06:52:43,161 - 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:52:43,164 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-11-14 06:52:43,165 - 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:52:43,165 - DEBUG - ydb.table.SessionPool - subscribe: Active session queue is empty, subscribe waiter for a session
2025-11-14 06:52:43,168 - DEBUG - ydb.table.SessionPool - subscribe: Subscribe waiter <Future at 0x7fe89312e220 state=pending>
2025-11-14 06:52:43,170 - 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:52:43,170 - DEBUG - ydb.table.SessionPool - _create: Created session <ydb.table.Session object at 0x7fe89313e5e0>
2025-11-14 06:52:43,171 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7fe89313e5e0>
2025-11-14 06:52:43,172 - 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:52:43,172 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database /Root/users/database_8
2025-11-14 06:52:43,173 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, fcdb3713-9a4c-47ba-8d87-ac0a87ffa0c6, localhost:14696): creating call state
2025-11-14 06:52:43,173 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, fcdb3713-9a4c-47ba-8d87-ac0a87ffa0c6, localhost:14696): request = { database: "/Root/users/database_8" }
2025-11-14 06:52:43,177 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, fcdb3713-9a4c-47ba-8d87-ac0a87ffa0c6, localhost:14696): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Discovery.ListEndpointsResult] { endpoints { address: "ghrun-iuibjpfjoa.auto.internal" port: 16087 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: 50008 } self_location: "1" } } } }
2025-11-14 06:52:43,178 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Resolved endpoints for database /Root/users/database_8: DiscoveryResult <self_location: 1, endpoints [<Endpoint ghrun-iuibjpfjoa.auto.internal:16087, location , ssl: False>]>
2025-11-14 06:52:43,178 - 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:52:43,181 - INFO - ydb.connection - close: Closing channel for endpoint localhost:14696
2025-11-14 06:52:43,181 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7fe89313e5e0>
2025-11-14 06:52:43,182 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, b247b480-f64d-47a5-9ea4-71131097d27b, ghrun-iuibjpfjoa.auto.internal:16087): creating call state
2025-11-14 06:52:43,183 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, b247b480-f64d-47a5-9ea4-71131097d27b, ghrun-iuibjpfjoa.auto.internal:16087): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-11-14 06:52:43,186 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, b247b480-f64d-47a5-9ea4-71131097d27b, ghrun-iuibjpfjoa.auto.internal:16087): on response callback started
2025-11-14 06:52:43,187 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, b247b480-f64d-47a5-9ea4-71131097d27b, ghrun-iuibjpfjoa.auto.internal:16087): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=50008&id=NTE2ZjVjMzItNjliZGU4ZmEtYzdkOWM3MDQtNjNlNGNjYTA=" } } } }
2025-11-14 06:52:43,187 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe89313e5e0>
2025-11-14 06:52:43,187 - DEBUG - ydb.table.SessionPool - put: Replying to waiter with a session <ydb.table.Session object at 0x7fe89313e5e0>
2025-11-14 06:52:43,187 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, b247b480-f64d-47a5-9ea4-71131097d27b, ghrun-iuibjpfjoa.auto.internal:16087): on response callback success
2025-11-14 06:52:43,188 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateTable, cd65dca3-deda-438c-8be9-44fc86c1ae0a, ghrun-iuibjpfjoa.auto.internal:16087): creating call state
2025-11-14 06:52:43,189 - DEBUG - ydb.connection - _log_request: RpcState(CreateTable, cd65dca3-deda-438c-8be9-44fc86c1ae0a, ghrun-iuibjpfjoa.auto.internal:16087): request = { session_id: "ydb://session/3?node_id=50008&id=NTE2ZjVjMzItNjliZGU4ZmEtYzdkOWM3MDQtNjNlNGNjYTA=" path: "/Root/users/database_8/table" columns { name: "id" type { optional_type { item { type_id: UINT64 } } } } columns { name: "value" type { optional_type { item { type_id: UTF8 } } } } primary_key: "id" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:43,221 - DEBUG - ydb.connection - _log_response: RpcState(CreateTable, cd65dca3-deda-438c-8be9-44fc86c1ae0a, ghrun-iuibjpfjoa.auto.internal:16087): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:52:43,222 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe89313e5e0>
2025-11-14 06:52:43,223 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateTable, 754148d3-97e7-428d-bf04-2f7f1f38999d, ghrun-iuibjpfjoa.auto.internal:16087): creating call state
2025-11-14 06:52:43,223 - DEBUG - ydb.connection - _log_request: RpcState(CreateTable, 754148d3-97e7-428d-bf04-2f7f1f38999d, ghrun-iuibjpfjoa.auto.internal:16087): request = { session_id: "ydb://session/3?node_id=50008&id=NTE2ZjVjMzItNjliZGU4ZmEtYzdkOWM3MDQtNjNlNGNjYTA=" path: "/Root/users/database_8/table_for_rm" columns { name: "id" type { optional_type { item { type_id: UINT64 } } } } columns { name: "value" type { optional_type { item { type_id: UTF8 } } } } primary_key: "id" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:43,246 - DEBUG - ydb.connection - _log_response: RpcState(CreateTable, 754148d3-97e7-428d-bf04-2f7f1f38999d, ghrun-iuibjpfjoa.auto.internal:16087): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:52:43,246 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe89313e5e0>
2025-11-14 06:52:43,247 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteDataQuery, 651d9ba0-5848-48d6-b05c-7a5f415943e0, ghrun-iuibjpfjoa.auto.internal:16087): creating call state
2025-11-14 06:52:43,248 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteDataQuery, 651d9ba0-5848-48d6-b05c-7a5f415943e0, ghrun-iuibjpfjoa.auto.internal:16087): request = { session_id: "ydb://session/3?node_id=50008&id=NTE2ZjVjMzItNjliZGU4ZmEtYzdkOWM3MDQtNjNlNGNjYTA=" tx_control { begin_tx { serializable_read_write { } } commit_tx: true } query { yql_text: "\n                        upsert into table (id, value)\n                        values (1u, \"/Root/users/database_8\");\n                        upsert into table_for_rm (id, value)\n                        values (2u, \"/Root/users/database_8\");\n                        " } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:43,274 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteDataQuery, 651d9ba0-5848-48d6-b05c-7a5f415943e0, ghrun-iuibjpfjoa.auto.internal:16087): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { tx_meta { } } } } }
2025-11-14 06:52:43,275 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe89313e5e0>
2025-11-14 06:52:43,275 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteDataQuery, 27b3e1fe-4843-43eb-830a-c3d10a1ece93, ghrun-iuibjpfjoa.auto.internal:16087): creating call state
2025-11-14 06:52:43,276 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteDataQuery, 27b3e1fe-4843-43eb-830a-c3d10a1ece93, ghrun-iuibjpfjoa.auto.internal:16087): request = { session_id: "ydb://session/3?node_id=50008&id=NTE2ZjVjMzItNjliZGU4ZmEtYzdkOWM3MDQtNjNlNGNjYTA=" tx_control { begin_tx { serializable_read_write { } } commit_tx: true } query { yql_text: "\n                        select id, value FROM table;\n                        select id, value FROM table_for_rm;\n                        " } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:43,306 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteDataQuery, 27b3e1fe-4843-43eb-830a-c3d10a1ece93, ghrun-iuibjpfjoa.auto.internal:16087): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { result_sets { columns { name: "id" type { optional_type { item { type_id: UINT64 } } } } columns { name: "value" type { optional_type { item { type_id: UTF8 } } } } rows { items { uint64_value: 1 } items { text_value: "/Root/users/database_8" } } } result_sets { columns { name: "id" type { optional_type { item { type_id: UINT64 } } } } columns { name: "value" type { optional_type { item { type_id: UTF8 } } } } rows { items { uint64_value: 2 } items { text_value: "/Root/users/database_8" } } } tx_meta { } } } } }
2025-11-14 06:52:43,307 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe89313e5e0>
2025-11-14 06:52:43,308 - DEBUG - ydb.connection - _prepare_call: RpcState(DropTable, 8bce60e7-d0ca-4afb-94d8-0db03f3cb688, ghrun-iuibjpfjoa.auto.internal:16087): creating call state
2025-11-14 06:52:43,308 - DEBUG - ydb.connection - _log_request: RpcState(DropTable, 8bce60e7-d0ca-4afb-94d8-0db03f3cb688, ghrun-iuibjpfjoa.auto.internal:16087): request = { session_id: "ydb://session/3?node_id=50008&id=NTE2ZjVjMzItNjliZGU4ZmEtYzdkOWM3MDQtNjNlNGNjYTA=" path: "/Root/users/database_8/table_for_rm" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:43,322 - DEBUG - ydb.connection - _log_response: RpcState(DropTable, 8bce60e7-d0ca-4afb-94d8-0db03f3cb688, ghrun-iuibjpfjoa.auto.internal:16087): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:52:43,323 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe89313e5e0>
2025-11-14 06:52:43,324 - DEBUG - ydb.table.SessionPool - stop: Requested session pool stop.
2025-11-14 06:52:43,324 - DEBUG - ydb.table.SessionPool - stop: Session pool is under stop, cancelling all in flight waiters.
2025-11-14 06:52:43,324 - DEBUG - ydb.table.SessionPool - _terminate_event: Terminated session pool.
2025-11-14 06:52:43,325 - DEBUG - ydb.table.SessionPool - stop: Destroying sessions in active queue
2025-11-14 06:52:43,325 - DEBUG - ydb.table.SessionPool - _destroy: Requested session destroy: <ydb.table.Session object at 0x7fe89313e5e0>, reason: session-pool-terminated
2025-11-14 06:52:43,326 - DEBUG - ydb.table.SessionPool - _destroy: Session <ydb.table.Session object at 0x7fe89313e5e0> is no longer active. Current active count 0.
2025-11-14 06:52:43,326 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, dac65c38-02bc-46f7-a985-145a4d591a39, ghrun-iuibjpfjoa.auto.internal:16087): creating call state
2025-11-14 06:52:43,326 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, dac65c38-02bc-46f7-a985-145a4d591a39, ghrun-iuibjpfjoa.auto.internal:16087): request = { session_id: "ydb://session/3?node_id=50008&id=NTE2ZjVjMzItNjliZGU4ZmEtYzdkOWM3MDQtNjNlNGNjYTA=" operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-11-14 06:52:43,328 - DEBUG - ydb.table.SessionPool - _destroy: Sent delete on session <ydb.table.Session object at 0x7fe89313e5e0>
2025-11-14 06:52:43,328 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, dac65c38-02bc-46f7-a985-145a4d591a39, ghrun-iuibjpfjoa.auto.internal:16087): on response callback started
2025-11-14 06:52:43,329 - DEBUG - ydb.table.SessionPool - stop: Destroyed active sessions
2025-11-14 06:52:43,329 - DEBUG - ydb.connection - _log_response: RpcState(DeleteSession, dac65c38-02bc-46f7-a985-145a4d591a39, ghrun-iuibjpfjoa.auto.internal:16087): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:52:43,330 - INFO - ydb.connection - close: Closing channel for endpoint localhost:14696
2025-11-14 06:52:43,330 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, dac65c38-02bc-46f7-a985-145a4d591a39, ghrun-iuibjpfjoa.auto.internal:16087): on response callback success
2025-11-14 06:52:43,374 - INFO - ydb.connection - close: Closing channel for endpoint ghrun-iuibjpfjoa.auto.internal:16087
2025-11-14 06:52:43,383 - INFO - ydb.pool.Discovery - run: Successfully terminated discovery process
2025-11-14 06:52:43,384 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - remove_database: /Root/users/database_8
2025-11-14 06:52:43,384 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_send_op: /Root/users/database_8: send console operation, token None
2025-11-14 06:52:43,387 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_send_op: /Root/users/database_8: response from console: RemoveTenantResponse {
  Response {
    operation {
      id: "ydb://cmsrequest/5?tenant=/Root/users/database_8&cmstid=72057594037936131&txid=1763103163385420&action=2"
    }
  }
}
Status {
  Code: STATUS_CODE_UNSPECIFIED
}

2025-11-14 06:52:43,388 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_op: /Root/users/database_8: wait console operation done
2025-11-14 06:52:43,890 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_op: /Root/users/database_8: console operation done
2025-11-14 06:52:43,891 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_tenant_gone: /Root/users/database_8: wait tenant gone
2025-11-14 06:52:43,892 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_tenant_gone: /Root/users/database_8: tenant gone
2025-11-14 06:52:44,893 - INFO - ydb.tests.library.harness.kikimr_runner - stop: Stopped node localhost:16087/9
2025-11-14 06:52:45,399 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/rl7h/0030e4/ydb/apps/ydbd/ydbd
2025-11-14 06:52:45,400 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/1948
2025-11-14 06:52:45,400 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/65441
2025-11-14 06:52:45,401 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/22092
2025-11-14 06:52:45,401 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/8087
2025-11-14 06:52:45,402 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/10281
2025-11-14 06:52:45,402 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: CFG_DIR_PATH="/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/kikimr_configs"
2025-11-14 06:52:45,403 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: Final command: /home/runner/.ya/build/build_root/rl7h/0030e4/ydb/apps/ydbd/ydbd server --suppress-version-check --yaml-config=$CFG_DIR_PATH/config.yaml --node-broker=localhost:14696 --tenant=/Root/users/database_9 --log-file-name=/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/slot_10/logfile_rvnadxx1.log --grpc-port=1948 --mon-port=65441 --ic-port=22092
2025-11-14 06:52:45,404 - DEBUG - ya.test - execute: Executing '('/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/apps/ydbd/ydbd', 'server', '--suppress-version-check', '--yaml-config=/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/kikimr_configs/config.yaml', '--node-broker=localhost:14696', '--tenant=/Root/users/database_9', '--log-file-name=/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/slot_10/logfile_rvnadxx1.log', '--grpc-port=1948', '--mon-port=65441', '--ic-port=22092')' in '/home/runner/.ya/build/build_root/rl7h/0030e4/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_dynamic_tenants.py.test_create_and_drop_tenants.enable_alter_database_create_hive_first--true/cluster/slot_10' (no wait)
2025-11-14 06:52:45,405 - DEBUG - ya.test - execute: Command pid: 1409524
2025-11-14 06:52:45,406 - INFO - ydb.tests.library.harness.kikimr_runner - start: Started node localhost:1948/10
2025-11-14 06:52:47,410 - 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:52:47,412 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-11-14 06:52:47,413 - DEBUG - ydb.table.SessionPool - subscribe: Active session queue is empty, subscribe waiter for a session
2025-11-14 06:52:47,413 - 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:52:47,414 - DEBUG - ydb.table.SessionPool - subscribe: Subscribe waiter <Future at 0x7fe892753b20 state=pending>
2025-11-14 06:52:47,417 - 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:52:47,417 - DEBUG - ydb.table.SessionPool - _create: Created session <ydb.table.Session object at 0x7fe894c1a360>
2025-11-14 06:52:47,418 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7fe894c1a360>
2025-11-14 06:52:47,419 - 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:52:47,420 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database /Root/users/database_9
2025-11-14 06:52:47,421 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, 4b42714a-5cef-46c9-873f-ed92e93560b3, localhost:14696): creating call state
2025-11-14 06:52:47,421 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, 4b42714a-5cef-46c9-873f-ed92e93560b3, localhost:14696): request = { database: "/Root/users/database_9" }
2025-11-14 06:52:47,424 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, 4b42714a-5cef-46c9-873f-ed92e93560b3, localhost:14696): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Discovery.ListEndpointsResult] { endpoints { address: "ghrun-iuibjpfjoa.auto.internal" port: 1948 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: 50009 } self_location: "1" } } } }
2025-11-14 06:52:47,425 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Resolved endpoints for database /Root/users/database_9: DiscoveryResult <self_location: 1, endpoints [<Endpoint ghrun-iuibjpfjoa.auto.internal:1948, location , ssl: False>]>
2025-11-14 06:52:47,425 - 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:52:47,428 - INFO - ydb.connection - close: Closing channel for endpoint localhost:14696
2025-11-14 06:52:47,429 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7fe894c1a360>
2025-11-14 06:52:47,430 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, ce7feb7a-04b2-4f6b-a5c2-c77c62e4f79c, ghrun-iuibjpfjoa.auto.internal:1948): creating call state
2025-11-14 06:52:47,430 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, ce7feb7a-04b2-4f6b-a5c2-c77c62e4f79c, ghrun-iuibjpfjoa.auto.internal:1948): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-11-14 06:52:47,433 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, ce7feb7a-04b2-4f6b-a5c2-c77c62e4f79c, ghrun-iuibjpfjoa.auto.internal:1948): on response callback started
2025-11-14 06:52:47,434 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, ce7feb7a-04b2-4f6b-a5c2-c77c62e4f79c, ghrun-iuibjpfjoa.auto.internal:1948): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=50009&id=ODhhZDE3ZjktYjg0NmM0ZGYtYjU3MDNkOWMtZGM5MThiYg==" } } } }
2025-11-14 06:52:47,434 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe894c1a360>
2025-11-14 06:52:47,435 - DEBUG - ydb.table.SessionPool - put: Replying to waiter with a session <ydb.table.Session object at 0x7fe894c1a360>
2025-11-14 06:52:47,435 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, ce7feb7a-04b2-4f6b-a5c2-c77c62e4f79c, ghrun-iuibjpfjoa.auto.internal:1948): on response callback success
2025-11-14 06:52:47,436 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateTable, 085cd798-90a7-438a-876b-d9bb08d7c929, ghrun-iuibjpfjoa.auto.internal:1948): creating call state
2025-11-14 06:52:47,437 - DEBUG - ydb.connection - _log_request: RpcState(CreateTable, 085cd798-90a7-438a-876b-d9bb08d7c929, ghrun-iuibjpfjoa.auto.internal:1948): request = { session_id: "ydb://session/3?node_id=50009&id=ODhhZDE3ZjktYjg0NmM0ZGYtYjU3MDNkOWMtZGM5MThiYg==" path: "/Root/users/database_9/table" columns { name: "id" type { optional_type { item { type_id: UINT64 } } } } columns { name: "value" type { optional_type { item { type_id: UTF8 } } } } primary_key: "id" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:47,476 - DEBUG - ydb.connection - _log_response: RpcState(CreateTable, 085cd798-90a7-438a-876b-d9bb08d7c929, ghrun-iuibjpfjoa.auto.internal:1948): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:52:47,476 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe894c1a360>
2025-11-14 06:52:47,477 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateTable, a0dc4c1a-93c4-4f58-92b6-720a89dbf953, ghrun-iuibjpfjoa.auto.internal:1948): creating call state
2025-11-14 06:52:47,478 - DEBUG - ydb.connection - _log_request: RpcState(CreateTable, a0dc4c1a-93c4-4f58-92b6-720a89dbf953, ghrun-iuibjpfjoa.auto.internal:1948): request = { session_id: "ydb://session/3?node_id=50009&id=ODhhZDE3ZjktYjg0NmM0ZGYtYjU3MDNkOWMtZGM5MThiYg==" path: "/Root/users/database_9/table_for_rm" columns { name: "id" type { optional_type { item { type_id: UINT64 } } } } columns { name: "value" type { optional_type { item { type_id: UTF8 } } } } primary_key: "id" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:47,504 - DEBUG - ydb.connection - _log_response: RpcState(CreateTable, a0dc4c1a-93c4-4f58-92b6-720a89dbf953, ghrun-iuibjpfjoa.auto.internal:1948): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:52:47,505 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe894c1a360>
2025-11-14 06:52:47,505 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteDataQuery, c985e05f-52d0-4587-8c88-ed64509282a3, ghrun-iuibjpfjoa.auto.internal:1948): creating call state
2025-11-14 06:52:47,506 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteDataQuery, c985e05f-52d0-4587-8c88-ed64509282a3, ghrun-iuibjpfjoa.auto.internal:1948): request = { session_id: "ydb://session/3?node_id=50009&id=ODhhZDE3ZjktYjg0NmM0ZGYtYjU3MDNkOWMtZGM5MThiYg==" tx_control { begin_tx { serializable_read_write { } } commit_tx: true } query { yql_text: "\n                        upsert into table (id, value)\n                        values (1u, \"/Root/users/database_9\");\n                        upsert into table_for_rm (id, value)\n                        values (2u, \"/Root/users/database_9\");\n                        " } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:47,528 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteDataQuery, c985e05f-52d0-4587-8c88-ed64509282a3, ghrun-iuibjpfjoa.auto.internal:1948): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { tx_meta { } } } } }
2025-11-14 06:52:47,528 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe894c1a360>
2025-11-14 06:52:47,529 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteDataQuery, ec84ab04-606a-412d-a70b-a691ec5193e4, ghrun-iuibjpfjoa.auto.internal:1948): creating call state
2025-11-14 06:52:47,530 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteDataQuery, ec84ab04-606a-412d-a70b-a691ec5193e4, ghrun-iuibjpfjoa.auto.internal:1948): request = { session_id: "ydb://session/3?node_id=50009&id=ODhhZDE3ZjktYjg0NmM0ZGYtYjU3MDNkOWMtZGM5MThiYg==" tx_control { begin_tx { serializable_read_write { } } commit_tx: true } query { yql_text: "\n                        select id, value FROM table;\n                        select id, value FROM table_for_rm;\n                        " } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:47,559 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteDataQuery, ec84ab04-606a-412d-a70b-a691ec5193e4, ghrun-iuibjpfjoa.auto.internal:1948): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { result_sets { columns { name: "id" type { optional_type { item { type_id: UINT64 } } } } columns { name: "value" type { optional_type { item { type_id: UTF8 } } } } rows { items { uint64_value: 1 } items { text_value: "/Root/users/database_9" } } } result_sets { columns { name: "id" type { optional_type { item { type_id: UINT64 } } } } columns { name: "value" type { optional_type { item { type_id: UTF8 } } } } rows { items { uint64_value: 2 } items { text_value: "/Root/users/database_9" } } } tx_meta { } } } } }
2025-11-14 06:52:47,560 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe894c1a360>
2025-11-14 06:52:47,561 - DEBUG - ydb.connection - _prepare_call: RpcState(DropTable, 50dbea08-c477-4108-b1e1-279a3506ec3b, ghrun-iuibjpfjoa.auto.internal:1948): creating call state
2025-11-14 06:52:47,561 - DEBUG - ydb.connection - _log_request: RpcState(DropTable, 50dbea08-c477-4108-b1e1-279a3506ec3b, ghrun-iuibjpfjoa.auto.internal:1948): request = { session_id: "ydb://session/3?node_id=50009&id=ODhhZDE3ZjktYjg0NmM0ZGYtYjU3MDNkOWMtZGM5MThiYg==" path: "/Root/users/database_9/table_for_rm" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 06:52:47,576 - DEBUG - ydb.connection - _log_response: RpcState(DropTable, 50dbea08-c477-4108-b1e1-279a3506ec3b, ghrun-iuibjpfjoa.auto.internal:1948): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:52:47,577 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fe894c1a360>
2025-11-14 06:52:47,577 - DEBUG - ydb.table.SessionPool - stop: Requested session pool stop.
2025-11-14 06:52:47,577 - DEBUG - ydb.table.SessionPool - stop: Session pool is under stop, cancelling all in flight waiters.
2025-11-14 06:52:47,577 - DEBUG - ydb.table.SessionPool - _terminate_event: Terminated session pool.
2025-11-14 06:52:47,578 - DEBUG - ydb.table.SessionPool - stop: Destroying sessions in active queue
2025-11-14 06:52:47,578 - DEBUG - ydb.table.SessionPool - _destroy: Requested session destroy: <ydb.table.Session object at 0x7fe894c1a360>, reason: session-pool-terminated
2025-11-14 06:52:47,578 - DEBUG - ydb.table.SessionPool - _destroy: Session <ydb.table.Session object at 0x7fe894c1a360> is no longer active. Current active count 0.
2025-11-14 06:52:47,579 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, a6d3c7d5-5878-46c0-b845-933469d3e1c5, ghrun-iuibjpfjoa.auto.internal:1948): creating call state
2025-11-14 06:52:47,579 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, a6d3c7d5-5878-46c0-b845-933469d3e1c5, ghrun-iuibjpfjoa.auto.internal:1948): request = { session_id: "ydb://session/3?node_id=50009&id=ODhhZDE3ZjktYjg0NmM0ZGYtYjU3MDNkOWMtZGM5MThiYg==" operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-11-14 06:52:47,581 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, a6d3c7d5-5878-46c0-b845-933469d3e1c5, ghrun-iuibjpfjoa.auto.internal:1948): on response callback started
2025-11-14 06:52:47,582 - DEBUG - ydb.connection - _log_response: RpcState(DeleteSession, a6d3c7d5-5878-46c0-b845-933469d3e1c5, ghrun-iuibjpfjoa.auto.internal:1948): response = { operation { ready: true status: SUCCESS } }
2025-11-14 06:52:47,583 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, a6d3c7d5-5878-46c0-b845-933469d3e1c5, ghrun-iuibjpfjoa.auto.internal:1948): on response callback success
2025-11-14 06:52:47,583 - DEBUG - ydb.table.SessionPool - _destroy: Sent delete on session <ydb.table.Session object at 0x7fe894c1a360>
2025-11-14 06:52:47,583 - DEBUG - ydb.table.SessionPool - stop: Destroyed active sessions
2025-11-14 06:52:47,584 - INFO - ydb.connection - close: Closing channel for endpoint localhost:14696
2025-11-14 06:52:47,623 - INFO - ydb.connection - close: Closing channel for endpoint ghrun-iuibjpfjoa.auto.internal:1948
2025-11-14 06:52:47,631 - INFO - ydb.pool.Discovery - run: Successfully terminated discovery process
2025-11-14 06:52:47,632 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - remove_database: /Root/users/database_9
2025-11-14 06:52:47,632 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_send_op: /Root/users/database_9: send console operation, token None
2025-11-14 06:52:47,636 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_send_op: /Root/users/database_9: response from console: RemoveTenantResponse {
  Response {
    operation {
      id: "ydb://cmsrequest/5?tenant=/Root/users/database_9&cmstid=72057594037936131&txid=1763103167633988&action=2"
    }
  }
}
Status {
  Code: STATUS_CODE_UNSPECIFIED
}

2025-11-14 06:52:47,637 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_op: /Root/users/database_9: wait console operation done
2025-11-14 06:52:48,138 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_op: /Root/users/database_9: console operation done
2025-11-14 06:52:48,139 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_tenant_gone: /Root/users/database_9: wait tenant gone
2025-11-14 06:52:48,140 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_tenant_gone: /Root/users/database_9: tenant gone
2025-11-14 06:52:49,141 - INFO - ydb.tests.library.harness.kikimr_runner - stop: Stopped node localhost:1948/10
2025-11-14 06:52:49,144 - INFO - ya.test - pytest_runtest_teardown: Test teardown
