2025-11-14 07:05:48,863 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-11-14 07:05:48,863 - INFO - ya.test - pytest_runtest_setup: test_stop_start[enable_alter_database_create_hive_first--true]
2025-11-14 07:05:48,863 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-11-14 07:05:48,863 - INFO - ya.test - pytest_runtest_setup: Test setup
2025-11-14 07:05:48,864 - INFO - ydb.tests.library.fixtures - ydb_cluster: destroy ydb_cluster for __tests__.test_tenants
2025-11-14 07:05:51,884 - INFO - ydb.tests.library.harness.kikimr_runner - stop: Stopped node localhost:64867/1
2025-11-14 07:05:51,888 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/28648
2025-11-14 07:05:51,889 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/15511
2025-11-14 07:05:51,889 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/14668
2025-11-14 07:05:51,889 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/5573
2025-11-14 07:05:51,889 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/12369
2025-11-14 07:05:51,890 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/2900
2025-11-14 07:05:51,890 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/8253
2025-11-14 07:05:51,890 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/17859
2025-11-14 07:05:51,890 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/16225
2025-11-14 07:05:51,890 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/10461
2025-11-14 07:05:51,891 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/10532
2025-11-14 07:05:51,891 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/28792
2025-11-14 07:05:51,891 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/29081
2025-11-14 07:05:51,891 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/4762
2025-11-14 07:05:51,891 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/4254
2025-11-14 07:05:51,891 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/16129
2025-11-14 07:05:51,892 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/16849
2025-11-14 07:05:51,892 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/25556
2025-11-14 07:05:51,892 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/64867
2025-11-14 07:05:51,892 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/26495
2025-11-14 07:05:51,989 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/rl7h/0030a0/ydb/apps/ydbd/ydbd
2025-11-14 07:05:51,990 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/5111
2025-11-14 07:05:51,991 - INFO - ydb.tests.library.fixtures - ydb_cluster: setup ydb_cluster for __tests__.test_tenants
2025-11-14 07:05:51,991 - INFO - ydb.tests.library.fixtures - ydb_cluster: setup ydb_cluster as local
2025-11-14 07:05:51,992 - DEBUG - ydb.tests.library.harness.kikimr_runner - start: Working directory: /home/runner/.ya/build/build_root/rl7h/0030a0/r3tmp/kikimr_cluster_4en7l9vo
2025-11-14 07:05:52,039 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/rl7h/0030a0/ydb/apps/ydbd/ydbd
2025-11-14 07:05:52,039 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/13394
2025-11-14 07:05:52,040 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/31778
2025-11-14 07:05:52,040 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/3981
2025-11-14 07:05:52,040 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/6100
2025-11-14 07:05:52,041 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: CFG_DIR_PATH="/home/runner/.ya/build/build_root/rl7h/0030a0/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk12/testing_out_stuff/test_tenants.py.TestTenants.test_stop_start.enable_alter_database_create_hive_first--true/cluster/kikimr_configs"
2025-11-14 07:05:52,041 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: Final command: /home/runner/.ya/build/build_root/rl7h/0030a0/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/0030a0/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk12/testing_out_stuff/test_tenants.py.TestTenants.test_stop_start.enable_alter_database_create_hive_first--true/cluster/node_1/logfile_bs00j0d3.log --grpc-port=13394 --mon-port=31778 --ic-port=5111
2025-11-14 07:05:52,042 - DEBUG - ydb.tests.library.harness.kikimr_runner - format_pdisk: Formatting pdisk SectorMap:1:64 on node localhost:13394/1, disk_size 68719476736
2025-11-14 07:05:52,043 - DEBUG - ya.test - execute: Executing '('/home/runner/.ya/build/build_root/rl7h/0030a0/ydb/apps/ydbd/ydbd', 'server', '--suppress-version-check', '--yaml-config=/home/runner/.ya/build/build_root/rl7h/0030a0/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk12/testing_out_stuff/test_tenants.py.TestTenants.test_stop_start.enable_alter_database_create_hive_first--true/cluster/kikimr_configs/config.yaml', '--node=1', '--log-file-name=/home/runner/.ya/build/build_root/rl7h/0030a0/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk12/testing_out_stuff/test_tenants.py.TestTenants.test_stop_start.enable_alter_database_create_hive_first--true/cluster/node_1/logfile_bs00j0d3.log', '--grpc-port=13394', '--mon-port=31778', '--ic-port=5111')' in '/home/runner/.ya/build/build_root/rl7h/0030a0/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk12/testing_out_stuff/test_tenants.py.TestTenants.test_stop_start.enable_alter_database_create_hive_first--true/cluster/node_1' (no wait)
2025-11-14 07:05:52,048 - DEBUG - ya.test - execute: Command pid: 2407866
2025-11-14 07:05:52,049 - INFO - ydb.tests.library.harness.kikimr_runner - start: Started node localhost:13394/1
2025-11-14 07:05:53,889 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/rl7h/0030a0/ydb/apps/ydbd/ydbd
2025-11-14 07:05:53,890 - DEBUG - ydb.tests.library.harness.kikimr_runner - __call_kikimr_new_cli: Executing command = ['/home/runner/.ya/build/build_root/rl7h/0030a0/ydb/apps/ydbd/ydbd', '--server=grpc://localhost:13394', '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: 5111\n      }\n      HostConfigId: 1\n    }\n  }\n}\n']
2025-11-14 07:05:53,891 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydbd.out.5
2025-11-14 07:05:53,891 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydbd.err.5
2025-11-14 07:05:53,891 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/rl7h/0030a0/ydb/apps/ydbd/ydbd', '--server=grpc://localhost:13394', '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: 5111\n      }\n      HostConfigId: 1\n    }\n  }\n}\n']' in 'None' (waiting)
2025-11-14 07:05:53,892 - DEBUG - ya.test - execute: Command pid: 2409058
2025-11-14 07:05:54,575 - DEBUG - ya.test - _save_outputs: Command (pid 2409058) rc: 0
2025-11-14 07:05:54,575 - DEBUG - ya.test - _save_outputs: Command (pid 2409058) elapsed time (sec): 0.6815199851989746
2025-11-14 07:05:54,575 - DEBUG - ya.test - _save_outputs: Command (pid 2409058) idrss: 0
2025-11-14 07:05:54,575 - DEBUG - ya.test - _save_outputs: Command (pid 2409058) inblock: 0
2025-11-14 07:05:54,576 - DEBUG - ya.test - _save_outputs: Command (pid 2409058) isrss: 0
2025-11-14 07:05:54,576 - DEBUG - ya.test - _save_outputs: Command (pid 2409058) ixrss: 0
2025-11-14 07:05:54,576 - DEBUG - ya.test - _save_outputs: Command (pid 2409058) majflt: 0
2025-11-14 07:05:54,576 - DEBUG - ya.test - _save_outputs: Command (pid 2409058) maxrss: 525764
2025-11-14 07:05:54,576 - DEBUG - ya.test - _save_outputs: Command (pid 2409058) minflt: 19682
2025-11-14 07:05:54,576 - DEBUG - ya.test - _save_outputs: Command (pid 2409058) msgrcv: 0
2025-11-14 07:05:54,577 - DEBUG - ya.test - _save_outputs: Command (pid 2409058) msgsnd: 0
2025-11-14 07:05:54,577 - DEBUG - ya.test - _save_outputs: Command (pid 2409058) nivcsw: 108
2025-11-14 07:05:54,577 - DEBUG - ya.test - _save_outputs: Command (pid 2409058) nsignals: 0
2025-11-14 07:05:54,577 - DEBUG - ya.test - _save_outputs: Command (pid 2409058) nswap: 0
2025-11-14 07:05:54,577 - DEBUG - ya.test - _save_outputs: Command (pid 2409058) nvcsw: 88
2025-11-14 07:05:54,577 - DEBUG - ya.test - _save_outputs: Command (pid 2409058) oublock: 8
2025-11-14 07:05:54,577 - DEBUG - ya.test - _save_outputs: Command (pid 2409058) stime: 0.29206499999999996
2025-11-14 07:05:54,578 - DEBUG - ya.test - _save_outputs: Command (pid 2409058) utime: 0.109037
2025-11-14 07:05:54,578 - DEBUG - ya.test - _save_outputs: Command (pid 2409058) wtime: 0.683
2025-11-14 07:05:54,578 - DEBUG - ya.test - _save_outputs: Command (pid 2409058) output:
Status {
  Success: true
}
Status {
  Success: true
}
Success: true
ConfigTxSeqNo: 4

2025-11-14 07:05:54,578 - DEBUG - ya.test - _save_outputs: Command (pid 2409058) errors:

2025-11-14 07:05:54,579 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/rl7h/0030a0/ydb/apps/ydbd/ydbd
2025-11-14 07:05:54,579 - DEBUG - ydb.tests.library.harness.kikimr_runner - __call_kikimr_new_cli: Executing command = ['/home/runner/.ya/build/build_root/rl7h/0030a0/ydb/apps/ydbd/ydbd', '--server=grpc://localhost:13394', '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 07:05:54,580 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydbd.out.6
2025-11-14 07:05:54,581 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydbd.err.6
2025-11-14 07:05:54,581 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/rl7h/0030a0/ydb/apps/ydbd/ydbd', '--server=grpc://localhost:13394', '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 07:05:54,593 - DEBUG - ya.test - execute: Command pid: 2409447
2025-11-14 07:05:55,043 - DEBUG - ya.test - _save_outputs: Command (pid 2409447) rc: 0
2025-11-14 07:05:55,044 - DEBUG - ya.test - _save_outputs: Command (pid 2409447) elapsed time (sec): 0.44979214668273926
2025-11-14 07:05:55,044 - DEBUG - ya.test - _save_outputs: Command (pid 2409447) idrss: 0
2025-11-14 07:05:55,044 - DEBUG - ya.test - _save_outputs: Command (pid 2409447) inblock: 0
2025-11-14 07:05:55,045 - DEBUG - ya.test - _save_outputs: Command (pid 2409447) isrss: 0
2025-11-14 07:05:55,045 - DEBUG - ya.test - _save_outputs: Command (pid 2409447) ixrss: 0
2025-11-14 07:05:55,045 - DEBUG - ya.test - _save_outputs: Command (pid 2409447) majflt: 0
2025-11-14 07:05:55,045 - DEBUG - ya.test - _save_outputs: Command (pid 2409447) maxrss: 525780
2025-11-14 07:05:55,045 - DEBUG - ya.test - _save_outputs: Command (pid 2409447) minflt: 19681
2025-11-14 07:05:55,046 - DEBUG - ya.test - _save_outputs: Command (pid 2409447) msgrcv: 0
2025-11-14 07:05:55,046 - DEBUG - ya.test - _save_outputs: Command (pid 2409447) msgsnd: 0
2025-11-14 07:05:55,046 - DEBUG - ya.test - _save_outputs: Command (pid 2409447) nivcsw: 82
2025-11-14 07:05:55,046 - DEBUG - ya.test - _save_outputs: Command (pid 2409447) nsignals: 0
2025-11-14 07:05:55,046 - DEBUG - ya.test - _save_outputs: Command (pid 2409447) nswap: 0
2025-11-14 07:05:55,046 - DEBUG - ya.test - _save_outputs: Command (pid 2409447) nvcsw: 94
2025-11-14 07:05:55,047 - DEBUG - ya.test - _save_outputs: Command (pid 2409447) oublock: 8
2025-11-14 07:05:55,047 - DEBUG - ya.test - _save_outputs: Command (pid 2409447) stime: 0.29533899999999996
2025-11-14 07:05:55,047 - DEBUG - ya.test - _save_outputs: Command (pid 2409447) utime: 0.07583
2025-11-14 07:05:55,047 - DEBUG - ya.test - _save_outputs: Command (pid 2409447) wtime: 0.462
2025-11-14 07:05:55,047 - DEBUG - ya.test - _save_outputs: Command (pid 2409447) output:
Status {
  Success: true
}
Success: true
ConfigTxSeqNo: 5

2025-11-14 07:05:55,048 - DEBUG - ya.test - _save_outputs: Command (pid 2409447) errors:

2025-11-14 07:05:55,048 - INFO - ydb.tests.library.harness.kikimr_runner - __run: Binding storage pools to domain Root: {'dynamic_storage_pool:1': 'hdd'}
2025-11-14 07:05:55,092 - INFO - ydb.tests.library.harness.kikimr_runner - __run: Cluster started and initialized
2025-11-14 07:05:55,108 - INFO - ya.test - pytest_runtest_call: Test call (class_name: test_tenants.py::TestTenants, test_name: test_stop_start[enable_alter_database_create_hive_first--true])
2025-11-14 07:05:55,108 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - remove_database: /Root/test_stop_start_enable_alter_database_create_hive_first--true_
2025-11-14 07:05:55,109 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_send_op: /Root/test_stop_start_enable_alter_database_create_hive_first--true_: send console operation, token None
2025-11-14 07:05:55,112 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_send_op: /Root/test_stop_start_enable_alter_database_create_hive_first--true_: response from console: RemoveTenantResponse {
  Response {
    operation {
      ready: true
      status: NOT_FOUND
      issues {
        message: "Database \'/Root/test_stop_start_enable_alter_database_create_hive_first--true_\' doesn\'t exist"
        severity: 1
      }
    }
  }
}
Status {
  Code: NOT_FOUND
  Reason: "Database \'/Root/test_stop_start_enable_alter_database_create_hive_first--true_\' doesn\'t exist"
}

2025-11-14 07:05:55,113 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_op: /Root/test_stop_start_enable_alter_database_create_hive_first--true_: wait console operation done
2025-11-14 07:05:55,618 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_op: /Root/test_stop_start_enable_alter_database_create_hive_first--true_: console operation done
2025-11-14 07:05:55,618 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_tenant_gone: /Root/test_stop_start_enable_alter_database_create_hive_first--true_: wait tenant gone
2025-11-14 07:05:55,619 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_tenant_gone: /Root/test_stop_start_enable_alter_database_create_hive_first--true_: tenant gone
2025-11-14 07:05:55,620 - DEBUG - ydb.tests.library.fixtures - ydb_database_ctx: create database /Root/test_stop_start_enable_alter_database_create_hive_first--true_: create path and declare internals
2025-11-14 07:05:56,144 - DEBUG - ydb.tests.library.fixtures - ydb_database_ctx: create database /Root/test_stop_start_enable_alter_database_create_hive_first--true_: start nodes and construct internals
2025-11-14 07:05:56,144 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/rl7h/0030a0/ydb/apps/ydbd/ydbd
2025-11-14 07:05:56,145 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/23497
2025-11-14 07:05:56,145 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/28552
2025-11-14 07:05:56,146 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/2118
2025-11-14 07:05:56,146 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/31474
2025-11-14 07:05:56,146 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/10503
2025-11-14 07:05:56,147 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: CFG_DIR_PATH="/home/runner/.ya/build/build_root/rl7h/0030a0/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk12/testing_out_stuff/test_tenants.py.TestTenants.test_stop_start.enable_alter_database_create_hive_first--true/cluster/kikimr_configs"
2025-11-14 07:05:56,147 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: Final command: /home/runner/.ya/build/build_root/rl7h/0030a0/ydb/apps/ydbd/ydbd server --suppress-version-check --yaml-config=$CFG_DIR_PATH/config.yaml --node-broker=localhost:13394 --tenant=/Root/test_stop_start_enable_alter_database_create_hive_first--true_ --log-file-name=/home/runner/.ya/build/build_root/rl7h/0030a0/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk12/testing_out_stuff/test_tenants.py.TestTenants.test_stop_start.enable_alter_database_create_hive_first--true/cluster/slot_1/logfile_bmpsbldg.log --grpc-port=23497 --mon-port=28552 --ic-port=2118
2025-11-14 07:05:56,148 - DEBUG - ya.test - execute: Executing '('/home/runner/.ya/build/build_root/rl7h/0030a0/ydb/apps/ydbd/ydbd', 'server', '--suppress-version-check', '--yaml-config=/home/runner/.ya/build/build_root/rl7h/0030a0/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk12/testing_out_stuff/test_tenants.py.TestTenants.test_stop_start.enable_alter_database_create_hive_first--true/cluster/kikimr_configs/config.yaml', '--node-broker=localhost:13394', '--tenant=/Root/test_stop_start_enable_alter_database_create_hive_first--true_', '--log-file-name=/home/runner/.ya/build/build_root/rl7h/0030a0/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk12/testing_out_stuff/test_tenants.py.TestTenants.test_stop_start.enable_alter_database_create_hive_first--true/cluster/slot_1/logfile_bmpsbldg.log', '--grpc-port=23497', '--mon-port=28552', '--ic-port=2118')' in '/home/runner/.ya/build/build_root/rl7h/0030a0/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk12/testing_out_stuff/test_tenants.py.TestTenants.test_stop_start.enable_alter_database_create_hive_first--true/cluster/slot_1' (no wait)
2025-11-14 07:05:56,157 - DEBUG - ya.test - execute: Command pid: 2411015
2025-11-14 07:05:56,157 - INFO - ydb.tests.library.harness.kikimr_runner - start: Started node localhost:23497/1
2025-11-14 07:05:56,158 - DEBUG - ydb.tests.library.fixtures - ydb_database_ctx: create database /Root/test_stop_start_enable_alter_database_create_hive_first--true_: wait construction done
2025-11-14 07:05:58,164 - DEBUG - ydb.tests.library.fixtures - ydb_database_ctx: create database /Root/test_stop_start_enable_alter_database_create_hive_first--true_: database up
2025-11-14 07:05:58,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 07:05:58,167 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-11-14 07:05:58,168 - 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 07:05:58,170 - DEBUG - ydb.table.SessionPool - subscribe: Active session queue is empty, subscribe waiter for a session
2025-11-14 07:05:58,170 - DEBUG - ydb.table.SessionPool - subscribe: Subscribe waiter <Future at 0x7f0df8b6fee0 state=pending>
2025-11-14 07:05:58,171 - DEBUG - ydb.table.SessionPool - subscribe: Session pool is not large enough (active_count < size: 0 < 100). will create a new session.
2025-11-14 07:05:58,171 - DEBUG - ydb.table.SessionPool - _create: Created session <ydb.table.Session object at 0x7f0df8b570d0>
2025-11-14 07:05:58,171 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7f0df8b570d0>
2025-11-14 07:05:58,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 07:05:58,174 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database /Root/test_stop_start_enable_alter_database_create_hive_first--true_
2025-11-14 07:05:58,174 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, 1df0a709-2148-4d6f-b129-39e12cb85870, localhost:13394): creating call state
2025-11-14 07:05:58,175 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, 1df0a709-2148-4d6f-b129-39e12cb85870, localhost:13394): request = { database: "/Root/test_stop_start_enable_alter_database_create_hive_first--true_" }
2025-11-14 07:05:58,177 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, 1df0a709-2148-4d6f-b129-39e12cb85870, localhost:13394): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Discovery.ListEndpointsResult] { endpoints { address: "ghrun-iuibjpfjoa.auto.internal" port: 23497 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 07:05:58,178 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Resolved endpoints for database /Root/test_stop_start_enable_alter_database_create_hive_first--true_: DiscoveryResult <self_location: 1, endpoints [<Endpoint ghrun-iuibjpfjoa.auto.internal:23497, location , ssl: False>]>
2025-11-14 07:05:58,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 07:05:58,185 - INFO - ydb.connection - close: Closing channel for endpoint localhost:13394
2025-11-14 07:05:58,185 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7f0df8b570d0>
2025-11-14 07:05:58,186 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, 5e501573-13e3-48d4-950c-38a03a93f251, ghrun-iuibjpfjoa.auto.internal:23497): creating call state
2025-11-14 07:05:58,186 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, 5e501573-13e3-48d4-950c-38a03a93f251, ghrun-iuibjpfjoa.auto.internal:23497): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-11-14 07:05:58,190 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, 5e501573-13e3-48d4-950c-38a03a93f251, ghrun-iuibjpfjoa.auto.internal:23497): on response callback started
2025-11-14 07:05:58,191 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, 5e501573-13e3-48d4-950c-38a03a93f251, ghrun-iuibjpfjoa.auto.internal:23497): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=50000&id=NGFmY2RlNjktNGRkNmE5NWYtYzkxNDJhZS1jMzZjN2Y5" } } } }
2025-11-14 07:05:58,191 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7f0df8b570d0>
2025-11-14 07:05:58,191 - DEBUG - ydb.table.SessionPool - put: Replying to waiter with a session <ydb.table.Session object at 0x7f0df8b570d0>
2025-11-14 07:05:58,191 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, 5e501573-13e3-48d4-950c-38a03a93f251, ghrun-iuibjpfjoa.auto.internal:23497): on response callback success
2025-11-14 07:05:58,192 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteSchemeQuery, 0ab5a220-197c-48a8-956f-a0e11f188ea5, ghrun-iuibjpfjoa.auto.internal:23497): creating call state
2025-11-14 07:05:58,192 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteSchemeQuery, 0ab5a220-197c-48a8-956f-a0e11f188ea5, ghrun-iuibjpfjoa.auto.internal:23497): request = { session_id: "ydb://session/3?node_id=50000&id=NGFmY2RlNjktNGRkNmE5NWYtYzkxNDJhZS1jMzZjN2Y5" yql_text: "\n                CREATE TABLE `table_0` (id utf8, PRIMARY KEY (id));\n            " operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 07:05:58,253 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteSchemeQuery, 0ab5a220-197c-48a8-956f-a0e11f188ea5, ghrun-iuibjpfjoa.auto.internal:23497): response = { operation { ready: true status: SUCCESS } }
2025-11-14 07:05:58,254 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7f0df8b570d0>
2025-11-14 07:05:58,254 - DEBUG - ydb.tests.library.fixtures - ydb_database_ctx: destroy database /Root/test_stop_start_enable_alter_database_create_hive_first--true_: remove path and dismantle internals
2025-11-14 07:05:58,254 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - remove_database: /Root/test_stop_start_enable_alter_database_create_hive_first--true_
2025-11-14 07:05:58,255 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_send_op: /Root/test_stop_start_enable_alter_database_create_hive_first--true_: send console operation, token None
2025-11-14 07:05:58,257 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_send_op: /Root/test_stop_start_enable_alter_database_create_hive_first--true_: response from console: RemoveTenantResponse {
  Response {
    operation {
      id: "ydb://cmsrequest/5?tenant=/Root/test_stop_start_enable_alter_database_create_hive_first--true_&cmstid=72057594037936131&txid=1763103958255412&action=2"
    }
  }
}
Status {
  Code: STATUS_CODE_UNSPECIFIED
}

2025-11-14 07:05:58,258 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_op: /Root/test_stop_start_enable_alter_database_create_hive_first--true_: wait console operation done
2025-11-14 07:05:58,765 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_op: /Root/test_stop_start_enable_alter_database_create_hive_first--true_: console operation done
2025-11-14 07:05:58,766 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_tenant_gone: /Root/test_stop_start_enable_alter_database_create_hive_first--true_: wait tenant gone
2025-11-14 07:05:58,769 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_tenant_gone: /Root/test_stop_start_enable_alter_database_create_hive_first--true_: tenant gone
2025-11-14 07:05:58,769 - DEBUG - ydb.tests.library.fixtures - ydb_database_ctx: destroy database /Root/test_stop_start_enable_alter_database_create_hive_first--true_: stop nodes
2025-11-14 07:06:10,775 - INFO - ydb.tests.library.harness.kikimr_runner - stop: Stopped node localhost:23497/1
2025-11-14 07:06:10,776 - DEBUG - ydb.tests.library.fixtures - ydb_database_ctx: destroy database /Root/test_stop_start_enable_alter_database_create_hive_first--true_: database down
2025-11-14 07:06:10,776 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - remove_database: /Root/test_stop_start_enable_alter_database_create_hive_first--true_
2025-11-14 07:06:10,776 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_send_op: /Root/test_stop_start_enable_alter_database_create_hive_first--true_: send console operation, token None
2025-11-14 07:06:10,779 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_send_op: /Root/test_stop_start_enable_alter_database_create_hive_first--true_: response from console: RemoveTenantResponse {
  Response {
    operation {
      ready: true
      status: NOT_FOUND
      issues {
        message: "Database \'/Root/test_stop_start_enable_alter_database_create_hive_first--true_\' doesn\'t exist"
        severity: 1
      }
    }
  }
}
Status {
  Code: NOT_FOUND
  Reason: "Database \'/Root/test_stop_start_enable_alter_database_create_hive_first--true_\' doesn\'t exist"
}

2025-11-14 07:06:10,779 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_op: /Root/test_stop_start_enable_alter_database_create_hive_first--true_: wait console operation done
2025-11-14 07:06:11,285 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_op: /Root/test_stop_start_enable_alter_database_create_hive_first--true_: console operation done
2025-11-14 07:06:11,286 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_tenant_gone: /Root/test_stop_start_enable_alter_database_create_hive_first--true_: wait tenant gone
2025-11-14 07:06:11,293 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_tenant_gone: /Root/test_stop_start_enable_alter_database_create_hive_first--true_: tenant gone
2025-11-14 07:06:11,293 - DEBUG - ydb.tests.library.fixtures - ydb_database_ctx: create database /Root/test_stop_start_enable_alter_database_create_hive_first--true_: create path and declare internals
2025-11-14 07:06:11,811 - DEBUG - ydb.tests.library.fixtures - ydb_database_ctx: create database /Root/test_stop_start_enable_alter_database_create_hive_first--true_: start nodes and construct internals
2025-11-14 07:06:11,812 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/rl7h/0030a0/ydb/apps/ydbd/ydbd
2025-11-14 07:06:11,812 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/29509
2025-11-14 07:06:11,813 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/65348
2025-11-14 07:06:11,813 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/4805
2025-11-14 07:06:11,813 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/1968
2025-11-14 07:06:11,814 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/16001
2025-11-14 07:06:11,815 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: CFG_DIR_PATH="/home/runner/.ya/build/build_root/rl7h/0030a0/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk12/testing_out_stuff/test_tenants.py.TestTenants.test_stop_start.enable_alter_database_create_hive_first--true/cluster/kikimr_configs"
2025-11-14 07:06:11,815 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: Final command: /home/runner/.ya/build/build_root/rl7h/0030a0/ydb/apps/ydbd/ydbd server --suppress-version-check --yaml-config=$CFG_DIR_PATH/config.yaml --node-broker=localhost:13394 --tenant=/Root/test_stop_start_enable_alter_database_create_hive_first--true_ --log-file-name=/home/runner/.ya/build/build_root/rl7h/0030a0/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk12/testing_out_stuff/test_tenants.py.TestTenants.test_stop_start.enable_alter_database_create_hive_first--true/cluster/slot_2/logfile_rrp85l6l.log --grpc-port=29509 --mon-port=65348 --ic-port=4805
2025-11-14 07:06:11,816 - DEBUG - ya.test - execute: Executing '('/home/runner/.ya/build/build_root/rl7h/0030a0/ydb/apps/ydbd/ydbd', 'server', '--suppress-version-check', '--yaml-config=/home/runner/.ya/build/build_root/rl7h/0030a0/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk12/testing_out_stuff/test_tenants.py.TestTenants.test_stop_start.enable_alter_database_create_hive_first--true/cluster/kikimr_configs/config.yaml', '--node-broker=localhost:13394', '--tenant=/Root/test_stop_start_enable_alter_database_create_hive_first--true_', '--log-file-name=/home/runner/.ya/build/build_root/rl7h/0030a0/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk12/testing_out_stuff/test_tenants.py.TestTenants.test_stop_start.enable_alter_database_create_hive_first--true/cluster/slot_2/logfile_rrp85l6l.log', '--grpc-port=29509', '--mon-port=65348', '--ic-port=4805')' in '/home/runner/.ya/build/build_root/rl7h/0030a0/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk12/testing_out_stuff/test_tenants.py.TestTenants.test_stop_start.enable_alter_database_create_hive_first--true/cluster/slot_2' (no wait)
2025-11-14 07:06:11,820 - DEBUG - ya.test - execute: Command pid: 2421596
2025-11-14 07:06:11,820 - INFO - ydb.tests.library.harness.kikimr_runner - start: Started node localhost:29509/2
2025-11-14 07:06:11,821 - DEBUG - ydb.tests.library.fixtures - ydb_database_ctx: create database /Root/test_stop_start_enable_alter_database_create_hive_first--true_: wait construction done
2025-11-14 07:06:13,828 - DEBUG - ydb.tests.library.fixtures - ydb_database_ctx: create database /Root/test_stop_start_enable_alter_database_create_hive_first--true_: database up
2025-11-14 07:06:13,828 - 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 07:06:13,830 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-11-14 07:06:13,831 - 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 07:06:13,834 - DEBUG - ydb.table.SessionPool - subscribe: Active session queue is empty, subscribe waiter for a session
2025-11-14 07:06:13,834 - DEBUG - ydb.table.SessionPool - subscribe: Subscribe waiter <Future at 0x7f0df8a8d000 state=pending>
2025-11-14 07:06:13,835 - DEBUG - ydb.table.SessionPool - subscribe: Session pool is not large enough (active_count < size: 0 < 100). will create a new session.
2025-11-14 07:06:13,835 - DEBUG - ydb.table.SessionPool - _create: Created session <ydb.table.Session object at 0x7f0df8a9b440>
2025-11-14 07:06:13,835 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7f0df8a9b440>
2025-11-14 07:06:13,835 - 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 07:06:13,856 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database /Root/test_stop_start_enable_alter_database_create_hive_first--true_
2025-11-14 07:06:13,857 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, 3f00a8f7-db0a-4a02-b2bd-18cea3765ed3, localhost:13394): creating call state
2025-11-14 07:06:13,857 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, 3f00a8f7-db0a-4a02-b2bd-18cea3765ed3, localhost:13394): request = { database: "/Root/test_stop_start_enable_alter_database_create_hive_first--true_" }
2025-11-14 07:06:13,865 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, 3f00a8f7-db0a-4a02-b2bd-18cea3765ed3, localhost:13394): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Discovery.ListEndpointsResult] { endpoints { address: "ghrun-iuibjpfjoa.auto.internal" port: 29509 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 07:06:13,866 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Resolved endpoints for database /Root/test_stop_start_enable_alter_database_create_hive_first--true_: DiscoveryResult <self_location: 1, endpoints [<Endpoint ghrun-iuibjpfjoa.auto.internal:29509, location , ssl: False>]>
2025-11-14 07:06:13,866 - 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 07:06:13,889 - INFO - ydb.connection - close: Closing channel for endpoint localhost:13394
2025-11-14 07:06:13,889 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7f0df8a9b440>
2025-11-14 07:06:13,890 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, 33cec3b7-d4d0-4cb1-889c-c1e81d70faf0, ghrun-iuibjpfjoa.auto.internal:29509): creating call state
2025-11-14 07:06:13,890 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, 33cec3b7-d4d0-4cb1-889c-c1e81d70faf0, ghrun-iuibjpfjoa.auto.internal:29509): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-11-14 07:06:13,901 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, 33cec3b7-d4d0-4cb1-889c-c1e81d70faf0, ghrun-iuibjpfjoa.auto.internal:29509): on response callback started
2025-11-14 07:06:13,902 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, 33cec3b7-d4d0-4cb1-889c-c1e81d70faf0, ghrun-iuibjpfjoa.auto.internal:29509): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=50001&id=M2QwZmRjNzktNWU0YjE5MDEtOWUwMDY2Y2YtYTNjNDBhNzQ=" } } } }
2025-11-14 07:06:13,902 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, 33cec3b7-d4d0-4cb1-889c-c1e81d70faf0, ghrun-iuibjpfjoa.auto.internal:29509): on response callback success
2025-11-14 07:06:13,903 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7f0df8a9b440>
2025-11-14 07:06:13,903 - DEBUG - ydb.table.SessionPool - put: Replying to waiter with a session <ydb.table.Session object at 0x7f0df8a9b440>
2025-11-14 07:06:13,905 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteSchemeQuery, a84481d3-c448-440f-b853-38876244c0ae, ghrun-iuibjpfjoa.auto.internal:29509): creating call state
2025-11-14 07:06:13,905 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteSchemeQuery, a84481d3-c448-440f-b853-38876244c0ae, ghrun-iuibjpfjoa.auto.internal:29509): request = { session_id: "ydb://session/3?node_id=50001&id=M2QwZmRjNzktNWU0YjE5MDEtOWUwMDY2Y2YtYTNjNDBhNzQ=" yql_text: "\n                CREATE TABLE `table_1` (id utf8, PRIMARY KEY (id));\n            " operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 07:06:14,023 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteSchemeQuery, a84481d3-c448-440f-b853-38876244c0ae, ghrun-iuibjpfjoa.auto.internal:29509): response = { operation { ready: true status: SUCCESS } }
2025-11-14 07:06:14,023 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7f0df8a9b440>
2025-11-14 07:06:14,024 - DEBUG - ydb.tests.library.fixtures - ydb_database_ctx: destroy database /Root/test_stop_start_enable_alter_database_create_hive_first--true_: remove path and dismantle internals
2025-11-14 07:06:14,024 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - remove_database: /Root/test_stop_start_enable_alter_database_create_hive_first--true_
2025-11-14 07:06:14,024 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_send_op: /Root/test_stop_start_enable_alter_database_create_hive_first--true_: send console operation, token None
2025-11-14 07:06:14,029 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_send_op: /Root/test_stop_start_enable_alter_database_create_hive_first--true_: response from console: RemoveTenantResponse {
  Response {
    operation {
      id: "ydb://cmsrequest/5?tenant=/Root/test_stop_start_enable_alter_database_create_hive_first--true_&cmstid=72057594037936131&txid=1763103974027030&action=2"
    }
  }
}
Status {
  Code: STATUS_CODE_UNSPECIFIED
}

2025-11-14 07:06:14,030 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_op: /Root/test_stop_start_enable_alter_database_create_hive_first--true_: wait console operation done
2025-11-14 07:06:14,537 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_op: /Root/test_stop_start_enable_alter_database_create_hive_first--true_: console operation done
2025-11-14 07:06:14,557 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_tenant_gone: /Root/test_stop_start_enable_alter_database_create_hive_first--true_: wait tenant gone
2025-11-14 07:06:14,563 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_tenant_gone: /Root/test_stop_start_enable_alter_database_create_hive_first--true_: tenant gone
2025-11-14 07:06:14,565 - DEBUG - ydb.tests.library.fixtures - ydb_database_ctx: destroy database /Root/test_stop_start_enable_alter_database_create_hive_first--true_: stop nodes
2025-11-14 07:06:36,572 - INFO - ydb.tests.library.harness.kikimr_runner - stop: Stopped node localhost:29509/2
2025-11-14 07:06:36,573 - DEBUG - ydb.tests.library.fixtures - ydb_database_ctx: destroy database /Root/test_stop_start_enable_alter_database_create_hive_first--true_: database down
2025-11-14 07:06:36,573 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - remove_database: /Root/test_stop_start_enable_alter_database_create_hive_first--true_
2025-11-14 07:06:36,573 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_send_op: /Root/test_stop_start_enable_alter_database_create_hive_first--true_: send console operation, token None
2025-11-14 07:06:36,575 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_send_op: /Root/test_stop_start_enable_alter_database_create_hive_first--true_: response from console: RemoveTenantResponse {
  Response {
    operation {
      ready: true
      status: NOT_FOUND
      issues {
        message: "Database \'/Root/test_stop_start_enable_alter_database_create_hive_first--true_\' doesn\'t exist"
        severity: 1
      }
    }
  }
}
Status {
  Code: NOT_FOUND
  Reason: "Database \'/Root/test_stop_start_enable_alter_database_create_hive_first--true_\' doesn\'t exist"
}

2025-11-14 07:06:36,575 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_op: /Root/test_stop_start_enable_alter_database_create_hive_first--true_: wait console operation done
2025-11-14 07:06:37,077 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_op: /Root/test_stop_start_enable_alter_database_create_hive_first--true_: console operation done
2025-11-14 07:06:37,077 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_tenant_gone: /Root/test_stop_start_enable_alter_database_create_hive_first--true_: wait tenant gone
2025-11-14 07:06:37,079 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_tenant_gone: /Root/test_stop_start_enable_alter_database_create_hive_first--true_: tenant gone
2025-11-14 07:06:37,079 - DEBUG - ydb.tests.library.fixtures - ydb_database_ctx: create database /Root/test_stop_start_enable_alter_database_create_hive_first--true_: create path and declare internals
2025-11-14 07:06:37,584 - DEBUG - ydb.tests.library.fixtures - ydb_database_ctx: create database /Root/test_stop_start_enable_alter_database_create_hive_first--true_: start nodes and construct internals
2025-11-14 07:06:37,584 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/rl7h/0030a0/ydb/apps/ydbd/ydbd
2025-11-14 07:06:37,585 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/1833
2025-11-14 07:06:37,585 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/21840
2025-11-14 07:06:37,585 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/62508
2025-11-14 07:06:37,586 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/1721
2025-11-14 07:06:37,586 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/22079
2025-11-14 07:06:37,586 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: CFG_DIR_PATH="/home/runner/.ya/build/build_root/rl7h/0030a0/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk12/testing_out_stuff/test_tenants.py.TestTenants.test_stop_start.enable_alter_database_create_hive_first--true/cluster/kikimr_configs"
2025-11-14 07:06:37,586 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: Final command: /home/runner/.ya/build/build_root/rl7h/0030a0/ydb/apps/ydbd/ydbd server --suppress-version-check --yaml-config=$CFG_DIR_PATH/config.yaml --node-broker=localhost:13394 --tenant=/Root/test_stop_start_enable_alter_database_create_hive_first--true_ --log-file-name=/home/runner/.ya/build/build_root/rl7h/0030a0/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk12/testing_out_stuff/test_tenants.py.TestTenants.test_stop_start.enable_alter_database_create_hive_first--true/cluster/slot_3/logfile__97i7res.log --grpc-port=1833 --mon-port=21840 --ic-port=62508
2025-11-14 07:06:37,587 - DEBUG - ya.test - execute: Executing '('/home/runner/.ya/build/build_root/rl7h/0030a0/ydb/apps/ydbd/ydbd', 'server', '--suppress-version-check', '--yaml-config=/home/runner/.ya/build/build_root/rl7h/0030a0/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk12/testing_out_stuff/test_tenants.py.TestTenants.test_stop_start.enable_alter_database_create_hive_first--true/cluster/kikimr_configs/config.yaml', '--node-broker=localhost:13394', '--tenant=/Root/test_stop_start_enable_alter_database_create_hive_first--true_', '--log-file-name=/home/runner/.ya/build/build_root/rl7h/0030a0/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk12/testing_out_stuff/test_tenants.py.TestTenants.test_stop_start.enable_alter_database_create_hive_first--true/cluster/slot_3/logfile__97i7res.log', '--grpc-port=1833', '--mon-port=21840', '--ic-port=62508')' in '/home/runner/.ya/build/build_root/rl7h/0030a0/ydb/tests/functional/tenants/test-results/py3test/testing_out_stuff/chunk12/testing_out_stuff/test_tenants.py.TestTenants.test_stop_start.enable_alter_database_create_hive_first--true/cluster/slot_3' (no wait)
2025-11-14 07:06:37,588 - DEBUG - ya.test - execute: Command pid: 2462502
2025-11-14 07:06:37,589 - INFO - ydb.tests.library.harness.kikimr_runner - start: Started node localhost:1833/3
2025-11-14 07:06:37,589 - DEBUG - ydb.tests.library.fixtures - ydb_database_ctx: create database /Root/test_stop_start_enable_alter_database_create_hive_first--true_: wait construction done
2025-11-14 07:06:39,592 - DEBUG - ydb.tests.library.fixtures - ydb_database_ctx: create database /Root/test_stop_start_enable_alter_database_create_hive_first--true_: database up
2025-11-14 07:06:39,592 - 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 07:06:39,594 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-11-14 07:06:39,594 - DEBUG - ydb.table.SessionPool - subscribe: Active session queue is empty, subscribe waiter for a session
2025-11-14 07:06:39,595 - 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 07:06:39,595 - DEBUG - ydb.table.SessionPool - subscribe: Subscribe waiter <Future at 0x7f0df8aed500 state=pending>
2025-11-14 07:06:39,597 - DEBUG - ydb.table.SessionPool - subscribe: Session pool is not large enough (active_count < size: 0 < 100). will create a new session.
2025-11-14 07:06:39,597 - DEBUG - ydb.table.SessionPool - _create: Created session <ydb.table.Session object at 0x7f0df8aedc80>
2025-11-14 07:06:39,598 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7f0df8aedc80>
2025-11-14 07:06:39,598 - 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 07:06:39,599 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database /Root/test_stop_start_enable_alter_database_create_hive_first--true_
2025-11-14 07:06:39,600 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, 9316c03e-fe6c-47bb-a1d9-dbe566f52921, localhost:13394): creating call state
2025-11-14 07:06:39,600 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, 9316c03e-fe6c-47bb-a1d9-dbe566f52921, localhost:13394): request = { database: "/Root/test_stop_start_enable_alter_database_create_hive_first--true_" }
2025-11-14 07:06:39,602 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, 9316c03e-fe6c-47bb-a1d9-dbe566f52921, localhost:13394): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Discovery.ListEndpointsResult] { endpoints { address: "ghrun-iuibjpfjoa.auto.internal" port: 1833 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 07:06:39,602 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Resolved endpoints for database /Root/test_stop_start_enable_alter_database_create_hive_first--true_: DiscoveryResult <self_location: 1, endpoints [<Endpoint ghrun-iuibjpfjoa.auto.internal:1833, location , ssl: False>]>
2025-11-14 07:06:39,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 07:06:39,605 - INFO - ydb.connection - close: Closing channel for endpoint localhost:13394
2025-11-14 07:06:39,605 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7f0df8aedc80>
2025-11-14 07:06:39,606 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, aebdbbc8-75d0-4a48-bd97-4bee9bfe20e5, ghrun-iuibjpfjoa.auto.internal:1833): creating call state
2025-11-14 07:06:39,606 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, aebdbbc8-75d0-4a48-bd97-4bee9bfe20e5, ghrun-iuibjpfjoa.auto.internal:1833): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-11-14 07:06:39,608 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, aebdbbc8-75d0-4a48-bd97-4bee9bfe20e5, ghrun-iuibjpfjoa.auto.internal:1833): on response callback started
2025-11-14 07:06:39,609 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, aebdbbc8-75d0-4a48-bd97-4bee9bfe20e5, ghrun-iuibjpfjoa.auto.internal:1833): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=50002&id=OGQyZGMyNzgtYjI5NzY2MzgtMmVjZjQxOS05YWQ3MmIzMg==" } } } }
2025-11-14 07:06:39,609 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7f0df8aedc80>
2025-11-14 07:06:39,609 - DEBUG - ydb.table.SessionPool - put: Replying to waiter with a session <ydb.table.Session object at 0x7f0df8aedc80>
2025-11-14 07:06:39,610 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, aebdbbc8-75d0-4a48-bd97-4bee9bfe20e5, ghrun-iuibjpfjoa.auto.internal:1833): on response callback success
2025-11-14 07:06:39,610 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteSchemeQuery, eedf1039-96b4-47a9-b15a-1e4810a727bf, ghrun-iuibjpfjoa.auto.internal:1833): creating call state
2025-11-14 07:06:39,611 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteSchemeQuery, eedf1039-96b4-47a9-b15a-1e4810a727bf, ghrun-iuibjpfjoa.auto.internal:1833): request = { session_id: "ydb://session/3?node_id=50002&id=OGQyZGMyNzgtYjI5NzY2MzgtMmVjZjQxOS05YWQ3MmIzMg==" yql_text: "\n                CREATE TABLE `table_2` (id utf8, PRIMARY KEY (id));\n            " operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-14 07:06:39,649 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteSchemeQuery, eedf1039-96b4-47a9-b15a-1e4810a727bf, ghrun-iuibjpfjoa.auto.internal:1833): response = { operation { ready: true status: SUCCESS } }
2025-11-14 07:06:39,649 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7f0df8aedc80>
2025-11-14 07:06:39,650 - DEBUG - ydb.tests.library.fixtures - ydb_database_ctx: destroy database /Root/test_stop_start_enable_alter_database_create_hive_first--true_: remove path and dismantle internals
2025-11-14 07:06:39,650 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - remove_database: /Root/test_stop_start_enable_alter_database_create_hive_first--true_
2025-11-14 07:06:39,650 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_send_op: /Root/test_stop_start_enable_alter_database_create_hive_first--true_: send console operation, token None
2025-11-14 07:06:39,653 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_send_op: /Root/test_stop_start_enable_alter_database_create_hive_first--true_: response from console: RemoveTenantResponse {
  Response {
    operation {
      id: "ydb://cmsrequest/5?tenant=/Root/test_stop_start_enable_alter_database_create_hive_first--true_&cmstid=72057594037936131&txid=1763103999650540&action=2"
    }
  }
}
Status {
  Code: STATUS_CODE_UNSPECIFIED
}

2025-11-14 07:06:39,654 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_op: /Root/test_stop_start_enable_alter_database_create_hive_first--true_: wait console operation done
2025-11-14 07:06:40,156 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_op: /Root/test_stop_start_enable_alter_database_create_hive_first--true_: console operation done
2025-11-14 07:06:40,156 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_tenant_gone: /Root/test_stop_start_enable_alter_database_create_hive_first--true_: wait tenant gone
2025-11-14 07:06:40,157 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_tenant_gone: /Root/test_stop_start_enable_alter_database_create_hive_first--true_: tenant gone
2025-11-14 07:06:40,157 - DEBUG - ydb.tests.library.fixtures - ydb_database_ctx: destroy database /Root/test_stop_start_enable_alter_database_create_hive_first--true_: stop nodes
2025-11-14 07:07:00,523 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-11-14 07:07:00,524 - 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 07:07:00,528 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database /Root/test_stop_start_enable_alter_database_create_hive_first--true_
2025-11-14 07:07:00,529 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, 60e12762-6598-4449-9e3b-b7dee9ebf8cb, localhost:13394): creating call state
2025-11-14 07:07:00,529 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, 60e12762-6598-4449-9e3b-b7dee9ebf8cb, localhost:13394): request = { database: "/Root/test_stop_start_enable_alter_database_create_hive_first--true_" }
2025-11-14 07:07:00,532 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, 60e12762-6598-4449-9e3b-b7dee9ebf8cb, localhost:13394): response = { operation { ready: true status: NOT_FOUND issues { message: "Requested database does not exist" issue_code: 200202 severity: 1 } } }
2025-11-14 07:07:00,532 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Failed to resolve endpoints for database /Root/test_stop_start_enable_alter_database_create_hive_first--true_. Endpoint: "localhost:13394". Error details:
 message: "Requested database does not exist" issue_code: 200202 severity: 1 (server_code: 400140)
2025-11-14 07:07:00,533 - INFO - ydb.connection - close: Closing channel for endpoint localhost:13394
2025-11-14 07:07:01,993 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-11-14 07:07:01,994 - 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 07:07:01,997 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database /Root/test_stop_start_enable_alter_database_create_hive_first--true_
2025-11-14 07:07:01,998 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, da6a9f5a-3449-433d-8fcb-e175bc32f890, localhost:13394): creating call state
2025-11-14 07:07:01,998 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, da6a9f5a-3449-433d-8fcb-e175bc32f890, localhost:13394): request = { database: "/Root/test_stop_start_enable_alter_database_create_hive_first--true_" }
2025-11-14 07:07:02,000 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, da6a9f5a-3449-433d-8fcb-e175bc32f890, localhost:13394): response = { operation { ready: true status: NOT_FOUND issues { message: "Requested database does not exist" issue_code: 200202 severity: 1 } } }
2025-11-14 07:07:02,001 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Failed to resolve endpoints for database /Root/test_stop_start_enable_alter_database_create_hive_first--true_. Endpoint: "localhost:13394". Error details:
 message: "Requested database does not exist" issue_code: 200202 severity: 1 (server_code: 400140)
2025-11-14 07:07:02,001 - INFO - ydb.connection - close: Closing channel for endpoint localhost:13394
2025-11-14 07:07:02,159 - INFO - ydb.tests.library.harness.kikimr_runner - stop: Stopped node localhost:1833/3
2025-11-14 07:07:02,159 - DEBUG - ydb.tests.library.fixtures - ydb_database_ctx: destroy database /Root/test_stop_start_enable_alter_database_create_hive_first--true_: database down
2025-11-14 07:07:02,159 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - remove_database: /Root/test_stop_start_enable_alter_database_create_hive_first--true_
2025-11-14 07:07:02,160 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_send_op: /Root/test_stop_start_enable_alter_database_create_hive_first--true_: send console operation, token None
2025-11-14 07:07:02,163 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_send_op: /Root/test_stop_start_enable_alter_database_create_hive_first--true_: response from console: RemoveTenantResponse {
  Response {
    operation {
      ready: true
      status: NOT_FOUND
      issues {
        message: "Database \'/Root/test_stop_start_enable_alter_database_create_hive_first--true_\' doesn\'t exist"
        severity: 1
      }
    }
  }
}
Status {
  Code: NOT_FOUND
  Reason: "Database \'/Root/test_stop_start_enable_alter_database_create_hive_first--true_\' doesn\'t exist"
}

2025-11-14 07:07:02,164 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_op: /Root/test_stop_start_enable_alter_database_create_hive_first--true_: wait console operation done
2025-11-14 07:07:02,666 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_op: /Root/test_stop_start_enable_alter_database_create_hive_first--true_: console operation done
2025-11-14 07:07:02,666 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_tenant_gone: /Root/test_stop_start_enable_alter_database_create_hive_first--true_: wait tenant gone
2025-11-14 07:07:02,667 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_tenant_gone: /Root/test_stop_start_enable_alter_database_create_hive_first--true_: tenant gone
2025-11-14 07:07:02,668 - DEBUG - ydb.tests.library.fixtures - ydb_database_ctx: create database /Root/test_stop_start_enable_alter_database_create_hive_first--true_: create path and declare internals
2025-11-14 07:07:03,261 - ERROR - ya.test - logreport: ydb/tests/functional/tenants/test_tenants.py:297: in test_stop_start
    with ydb_database_ctx(ydb_cluster, database_path):
contrib/tools/python3/Lib/contextlib.py:137: in __enter__
    return next(self.gen)
ydb/tests/library/fixtures/__init__.py:88: in ydb_database_ctx
    ydb_cluster.create_database(database_path, storage_pool_units_count=storage_pools, timeout_seconds=timeout_seconds, token=token)
ydb/tests/library/harness/kikimr_cluster_interface.py:217: in create_database
    raise RuntimeError('create_database failed: %s, %s' % (operation.status, ydb.issues._format_issues(operation.issues)))
E   RuntimeError: create_database failed: 400080, message: "Group fit error BoxId# 1 StoragePoolId# 5 Error# failed to allocate group: no group options PDisks# {[(1:1-S)]}" severity: 1
2025-11-14 07:07:03,263 - INFO - ya.test - pytest_runtest_teardown: Test teardown
2025-11-14 07:07:03,263 - DEBUG - ydb.table.SessionPool - stop: Requested session pool stop.
2025-11-14 07:07:03,263 - DEBUG - ydb.table.SessionPool - stop: Session pool is under stop, cancelling all in flight waiters.
2025-11-14 07:07:03,264 - DEBUG - ydb.table.SessionPool - _terminate_event: Terminated session pool.
2025-11-14 07:07:03,264 - DEBUG - ydb.table.SessionPool - stop: Destroying sessions in active queue
2025-11-14 07:07:03,265 - DEBUG - ydb.table.SessionPool - _destroy: Requested session destroy: <ydb.table.Session object at 0x7f0df8aedc80>, reason: session-pool-terminated
2025-11-14 07:07:03,265 - DEBUG - ydb.table.SessionPool - _destroy: Session <ydb.table.Session object at 0x7f0df8aedc80> is no longer active. Current active count 0.
2025-11-14 07:07:03,265 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, b960fa34-7b05-4839-baf4-8b70ea20fbe4, ghrun-iuibjpfjoa.auto.internal:1833): creating call state
2025-11-14 07:07:03,266 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, b960fa34-7b05-4839-baf4-8b70ea20fbe4, ghrun-iuibjpfjoa.auto.internal:1833): request = { session_id: "ydb://session/3?node_id=50002&id=OGQyZGMyNzgtYjI5NzY2MzgtMmVjZjQxOS05YWQ3MmIzMg==" operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-11-14 07:07:03,267 - DEBUG - ydb.table.SessionPool - _destroy: Sent delete on session <ydb.table.Session object at 0x7f0df8aedc80>
2025-11-14 07:07:03,267 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, b960fa34-7b05-4839-baf4-8b70ea20fbe4, ghrun-iuibjpfjoa.auto.internal:1833): on response callback started
2025-11-14 07:07:03,268 - DEBUG - ydb.table.SessionPool - stop: Destroyed active sessions
2025-11-14 07:07:03,268 - INFO - ydb.connection - _rpc_error_handler: RpcState(DeleteSession, b960fa34-7b05-4839-baf4-8b70ea20fbe4, ghrun-iuibjpfjoa.auto.internal:1833): received error, <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.UNAVAILABLE
	details = "connections to all backends failing; last error: UNKNOWN: ipv4:127.0.1.1:1833: Failed to connect to remote host: Connection refused"
	debug_error_string = "UNKNOWN:connections to all backends failing; last error: UNKNOWN: ipv4:127.0.1.1:1833: Failed to connect to remote host: Connection refused {grpc_status:14, created_time:"2025-11-14T07:07:03.266781372+00:00", file_line:153, file:"/home/runner/actions_runner/_work/ydb/ydb/contrib/libs/grpc/src/core/lib/transport/error_utils.cc"}"
>
2025-11-14 07:07:03,268 - DEBUG - ydb.table.SessionPool - stop: Requested session pool stop.
2025-11-14 07:07:03,269 - DEBUG - ydb.connection - _rpc_error_handler: RpcState(DeleteSession, b960fa34-7b05-4839-baf4-8b70ea20fbe4, ghrun-iuibjpfjoa.auto.internal:1833): unhandled rpc error, disconnecting channel
2025-11-14 07:07:03,269 - DEBUG - ydb.table.SessionPool - stop: Session pool is under stop, cancelling all in flight waiters.
2025-11-14 07:07:03,270 - DEBUG - ydb.table.SessionPool - _terminate_event: Terminated session pool.
2025-11-14 07:07:03,270 - INFO - ydb.connection - close: Closing channel for endpoint ghrun-iuibjpfjoa.auto.internal:1833
2025-11-14 07:07:03,271 - DEBUG - ydb.table.SessionPool - stop: Destroying sessions in active queue
2025-11-14 07:07:03,272 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-11-14 07:07:03,272 - DEBUG - ydb.table.SessionPool - _destroy: Requested session destroy: <ydb.table.Session object at 0x7f0df8a9b440>, reason: session-pool-terminated
2025-11-14 07:07:03,272 - 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 07:07:03,273 - DEBUG - ydb.table.SessionPool - _destroy: Session <ydb.table.Session object at 0x7f0df8a9b440> is no longer active. Current active count 0.
2025-11-14 07:07:03,275 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, 89069667-baea-4e06-a4f5-ebfd97a65369, ghrun-iuibjpfjoa.auto.internal:29509): creating call state
2025-11-14 07:07:03,276 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, 89069667-baea-4e06-a4f5-ebfd97a65369, ghrun-iuibjpfjoa.auto.internal:29509): request = { session_id: "ydb://session/3?node_id=50001&id=M2QwZmRjNzktNWU0YjE5MDEtOWUwMDY2Y2YtYTNjNDBhNzQ=" operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-11-14 07:07:03,278 - DEBUG - ydb.table.SessionPool - _destroy: Sent delete on session <ydb.table.Session object at 0x7f0df8a9b440>
2025-11-14 07:07:03,278 - DEBUG - ydb.table.SessionPool - stop: Destroyed active sessions
2025-11-14 07:07:03,279 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, 89069667-baea-4e06-a4f5-ebfd97a65369, ghrun-iuibjpfjoa.auto.internal:29509): on response callback started
2025-11-14 07:07:03,279 - DEBUG - ydb.table.SessionPool - stop: Requested session pool stop.
2025-11-14 07:07:03,280 - INFO - ydb.connection - _rpc_error_handler: RpcState(DeleteSession, 89069667-baea-4e06-a4f5-ebfd97a65369, ghrun-iuibjpfjoa.auto.internal:29509): received error, <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.UNAVAILABLE
	details = "connections to all backends failing; last error: UNKNOWN: ipv4:127.0.1.1:29509: Failed to connect to remote host: Connection refused"
	debug_error_string = "UNKNOWN:connections to all backends failing; last error: UNKNOWN: ipv4:127.0.1.1:29509: Failed to connect to remote host: Connection refused {file:"/home/runner/actions_runner/_work/ydb/ydb/contrib/libs/grpc/src/core/lib/transport/error_utils.cc", file_line:153, created_time:"2025-11-14T07:07:03.277818201+00:00", grpc_status:14}"
>
2025-11-14 07:07:03,280 - DEBUG - ydb.table.SessionPool - stop: Session pool is under stop, cancelling all in flight waiters.
2025-11-14 07:07:03,280 - DEBUG - ydb.table.SessionPool - _terminate_event: Terminated session pool.
2025-11-14 07:07:03,281 - DEBUG - ydb.connection - _rpc_error_handler: RpcState(DeleteSession, 89069667-baea-4e06-a4f5-ebfd97a65369, ghrun-iuibjpfjoa.auto.internal:29509): unhandled rpc error, disconnecting channel
2025-11-14 07:07:03,281 - DEBUG - ydb.table.SessionPool - stop: Destroying sessions in active queue
2025-11-14 07:07:03,282 - INFO - ydb.connection - close: Closing channel for endpoint ghrun-iuibjpfjoa.auto.internal:29509
2025-11-14 07:07:03,282 - DEBUG - ydb.table.SessionPool - _destroy: Requested session destroy: <ydb.table.Session object at 0x7f0df8b570d0>, reason: session-pool-terminated
2025-11-14 07:07:03,283 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-11-14 07:07:03,284 - DEBUG - ydb.table.SessionPool - _destroy: Session <ydb.table.Session object at 0x7f0df8b570d0> is no longer active. Current active count 0.
2025-11-14 07:07:03,284 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database /Root/test_stop_start_enable_alter_database_create_hive_first--true_
2025-11-14 07:07:03,285 - 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 07:07:03,285 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, c796b142-f7c0-46d6-b7eb-bec6288b1a21, ghrun-iuibjpfjoa.auto.internal:23497): creating call state
2025-11-14 07:07:03,286 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, 91386cd9-c9f1-4355-8dfd-9afbe3aa128e, localhost:13394): creating call state
2025-11-14 07:07:03,288 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, c796b142-f7c0-46d6-b7eb-bec6288b1a21, ghrun-iuibjpfjoa.auto.internal:23497): request = { session_id: "ydb://session/3?node_id=50000&id=NGFmY2RlNjktNGRkNmE5NWYtYzkxNDJhZS1jMzZjN2Y5" operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-11-14 07:07:03,289 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, 91386cd9-c9f1-4355-8dfd-9afbe3aa128e, localhost:13394): request = { database: "/Root/test_stop_start_enable_alter_database_create_hive_first--true_" }
2025-11-14 07:07:03,292 - DEBUG - ydb.table.SessionPool - _destroy: Sent delete on session <ydb.table.Session object at 0x7f0df8b570d0>
2025-11-14 07:07:03,292 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, c796b142-f7c0-46d6-b7eb-bec6288b1a21, ghrun-iuibjpfjoa.auto.internal:23497): on response callback started
2025-11-14 07:07:03,293 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, 91386cd9-c9f1-4355-8dfd-9afbe3aa128e, localhost:13394): response = { operation { ready: true status: NOT_FOUND issues { message: "Requested database does not exist" issue_code: 200202 severity: 1 } } }
2025-11-14 07:07:03,293 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database /Root/test_stop_start_enable_alter_database_create_hive_first--true_
2025-11-14 07:07:03,293 - DEBUG - ydb.table.SessionPool - stop: Destroyed active sessions
2025-11-14 07:07:03,294 - INFO - ydb.connection - _rpc_error_handler: RpcState(DeleteSession, c796b142-f7c0-46d6-b7eb-bec6288b1a21, ghrun-iuibjpfjoa.auto.internal:23497): received error, <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.UNAVAILABLE
	details = "connections to all backends failing; last error: UNKNOWN: ipv4:127.0.1.1:23497: Failed to connect to remote host: Connection refused"
	debug_error_string = "UNKNOWN:connections to all backends failing; last error: UNKNOWN: ipv4:127.0.1.1:23497: Failed to connect to remote host: Connection refused {grpc_status:14, created_time:"2025-11-14T07:07:03.290508001+00:00", file_line:153, file:"/home/runner/actions_runner/_work/ydb/ydb/contrib/libs/grpc/src/core/lib/transport/error_utils.cc"}"
>
2025-11-14 07:07:03,295 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Failed to resolve endpoints for database /Root/test_stop_start_enable_alter_database_create_hive_first--true_. Endpoint: "localhost:13394". Error details:
 message: "Requested database does not exist" issue_code: 200202 severity: 1 (server_code: 400140)
2025-11-14 07:07:03,296 - INFO - ydb.connection - close: Closing channel for endpoint localhost:13394
2025-11-14 07:07:03,296 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, 29a812b8-42d5-4b9c-8561-2b075847910a, localhost:13394): creating call state
2025-11-14 07:07:03,297 - DEBUG - ydb.connection - _rpc_error_handler: RpcState(DeleteSession, c796b142-f7c0-46d6-b7eb-bec6288b1a21, ghrun-iuibjpfjoa.auto.internal:23497): unhandled rpc error, disconnecting channel
2025-11-14 07:07:03,297 - INFO - ydb.connection - close: Closing channel for endpoint localhost:13394
2025-11-14 07:07:03,298 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, 29a812b8-42d5-4b9c-8561-2b075847910a, localhost:13394): request = { database: "/Root/test_stop_start_enable_alter_database_create_hive_first--true_" }
2025-11-14 07:07:03,298 - INFO - ydb.connection - close: Closing channel for endpoint ghrun-iuibjpfjoa.auto.internal:23497
2025-11-14 07:07:03,300 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-11-14 07:07:03,301 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, 29a812b8-42d5-4b9c-8561-2b075847910a, localhost:13394): response = { operation { ready: true status: NOT_FOUND issues { message: "Requested database does not exist" issue_code: 200202 severity: 1 } } }
2025-11-14 07:07:03,301 - 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 07:07:03,302 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Failed to resolve endpoints for database /Root/test_stop_start_enable_alter_database_create_hive_first--true_. Endpoint: "localhost:13394". Error details:
 message: "Requested database does not exist" issue_code: 200202 severity: 1 (server_code: 400140)
2025-11-14 07:07:03,304 - INFO - ydb.connection - close: Closing channel for endpoint localhost:13394
2025-11-14 07:07:03,305 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database /Root/test_stop_start_enable_alter_database_create_hive_first--true_
2025-11-14 07:07:03,306 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, 953bb14c-caea-478b-8d78-796affda1704, localhost:13394): creating call state
2025-11-14 07:07:03,311 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, 953bb14c-caea-478b-8d78-796affda1704, localhost:13394): request = { database: "/Root/test_stop_start_enable_alter_database_create_hive_first--true_" }
2025-11-14 07:07:03,313 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, 953bb14c-caea-478b-8d78-796affda1704, localhost:13394): response = { operation { ready: true status: NOT_FOUND issues { message: "Requested database does not exist" issue_code: 200202 severity: 1 } } }
2025-11-14 07:07:03,314 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Failed to resolve endpoints for database /Root/test_stop_start_enable_alter_database_create_hive_first--true_. Endpoint: "localhost:13394". Error details:
 message: "Requested database does not exist" issue_code: 200202 severity: 1 (server_code: 400140)
2025-11-14 07:07:03,315 - INFO - ydb.connection - close: Closing channel for endpoint localhost:13394
2025-11-14 07:07:03,486 - INFO - ydb.pool.Discovery - run: Successfully terminated discovery process
2025-11-14 07:07:03,487 - INFO - ydb.connection - close: Closing channel for endpoint localhost:13394
2025-11-14 07:07:03,495 - INFO - ydb.pool.Discovery - run: Successfully terminated discovery process
2025-11-14 07:07:03,495 - INFO - ydb.connection - close: Closing channel for endpoint localhost:13394
2025-11-14 07:07:03,508 - INFO - ydb.pool.Discovery - run: Successfully terminated discovery process
