2025-10-14T14:22:41.856921Z node 10 :METADATA_PROVIDER WARN: log.cpp:841: fline=table_exists.cpp:54;actor=TTableExistsActor;event=undelivered;self_id=[10:7561082742420749699:2078];send_to=[0:7307199536658146131:7762515];
2025-10-14T14:22:41.857004Z node 10 :METADATA_PROVIDER ERROR: log.cpp:841: fline=accessor_snapshot_base.cpp:71;action=cannot detect path existence;path=//Root/.metadata/initialization/migrations;error=scheme_cache_undelivered_message;
test_client.cpp: SetPath # /home/runner/.ya/build/build_root/8izf/0012f0/r3tmp/tmpc32eMG/pdisk_1.dat
2025-10-14T14:22:41.900868Z node 10 :KQP_PROXY WARN: kqp_finalize_script_service.cpp:135: [ScriptExecutions] [TKqpFinalizeScriptService] Failed to check script execution tables existence, scheme status: LookupError, path: Root/.metadata/script_executions
2025-10-14T14:22:41.910247Z node 12 :BS_NODE WARN: {NWDC01@distconf.cpp:397} StateFunc too long Type# 268639248 Duration# 0.005517s
2025-10-14T14:22:42.074324Z node 10 :IMPORT WARN: schemeshard_import.cpp:307: Table profiles were not loaded
2025-10-14T14:22:42.095478Z node 10 :HIVE WARN: node_info.cpp:25: HIVE#72057594037968897 Node(10, (0,0,0,0)) VolatileState: Unknown -> Disconnected
2025-10-14T14:22:42.095578Z node 10 :HIVE WARN: node_info.cpp:25: HIVE#72057594037968897 Node(10, (0,0,0,0)) VolatileState: Disconnected -> Connecting
2025-10-14T14:22:42.104812Z node 10 :HIVE WARN: node_info.cpp:25: HIVE#72057594037968897 Node(10, (0,0,0,0)) VolatileState: Connecting -> Connected
TServer::EnableGrpc on GrpcPort 22210, node 10
2025-10-14T14:22:42.163145Z node 10 :KQP_PROXY WARN: kqp_finalize_script_service.cpp:135: [ScriptExecutions] [TKqpFinalizeScriptService] Failed to check script execution tables existence, scheme status: PathErrorUnknown, path: Root/.metadata/script_executions
2025-10-14T14:22:42.196380Z node 10 :NET_CLASSIFIER WARN: net_classifier.cpp:190: distributable config is empty, broken or outdated, will use file: (empty maybe)
2025-10-14T14:22:42.196414Z node 10 :NET_CLASSIFIER WARN: net_classifier.cpp:196: will try to initialize from file: (empty maybe)
2025-10-14T14:22:42.196442Z node 10 :NET_CLASSIFIER WARN: net_classifier.cpp:204: failed to initialize from file: (empty maybe)
2025-10-14T14:22:42.196616Z node 10 :NET_CLASSIFIER ERROR: net_classifier.cpp:228: got bad distributable configuration
TClient is connected to server localhost:15847
WaitRootIsUp 'Root'...
TClient::Ls request: Root
TClient::Ls response: Status: 1
StatusCode: SUCCESS
SchemeStatus: 0
PathDescription {
  Self {
    Name: "Root"
    PathId: 1
    SchemeshardId: 72057594046644480
    PathType: EPathTypeDir
    CreateFinished: true
    CreateTxId: 1
    CreateStep: 0
    ParentPathId: 1
    PathState: EPathStateNoChanges
    Owner: "root@builtin"
    ACL: ""
    EffectiveACL: ""
    PathVersion: 2
    PathSubType: EPathSubTypeEmpty
    Version {
      GeneralVersion: 2
      ACLVersion: 0
      EffectiveACLVersion: 0
      UserAttrsVersion: 1
      ChildrenVersion: 1
      SubDomainVersion: 0
      SecurityStateVersion: 0
    }
    ChildrenExist: false
  }
  Children {
    Name: ".sys"
    PathId: 18446744073709551615
    SchemeshardId: 72057594046644480
    PathType: EPathTypeDir
    CreateFinished: true
    CreateTxId: 0
    CreateStep: 0
    ParentPathId: 18446744073709551615
  }
  DomainDescription {
    SchemeShardId_Depricated: 72057594046644480
    PathId_Depricated: 1
    ProcessingParams {
      Version: 0
      Pl...
(TRUNCATED)
WaitRootIsUp 'Root' success.
2025-10-14T14:22:42.526041Z node 10 :FLAT_TX_SCHEMESHARD WARN: schemeshard__operation.cpp:183: Operation part proposed ok, but propose itself is undo unsafe, suboperation type: ESchemeOpAlterSubDomain, opId: 281474976710657:0, at schemeshard:  72057594046644480, first GetDB called at:  (GetDB first called at /home/runner/actions_runner/_work/ydb/ydb/ydb/core/tx/schemeshard/schemeshard__operation_alter_subdomain.cpp:311)
waiting...
2025-10-14T14:22:42.881446Z node 10 :TX_CONVEYOR ERROR: log.cpp:841: fline=service.h:53;problem=unexpected event for task executor;ev_type=NActors::TEvents::TEvWakeup;
2025-10-14T14:22:45.473388Z node 10 :FLAT_TX_SCHEMESHARD WARN: schemeshard__operation.cpp:183: Operation part proposed ok, but propose itself is undo unsafe, suboperation type: ESchemeOpCreateTable, opId: 281474976710658:0, at schemeshard:  72057594046644480, first GetDB called at:  (GetDB first called at /home/runner/actions_runner/_work/ydb/ydb/ydb/core/tx/schemeshard/schemeshard__operation_create_table.cpp:684)
2025-10-14T14:22:45.504546Z node 10 :TX_DATASHARD INFO: datashard.cpp:373: TDataShard::OnActivateExecutor: tablet 72075186224037888 actor [10:7561082759600619940:2322]
2025-10-14T14:22:45.504828Z node 10 :TX_DATASHARD DEBUG: datashard__init.cpp:661: TxInitSchema.Execute
2025-10-14T14:22:45.520564Z node 10 :TX_DATASHARD DEBUG: datashard__init.cpp:727: TxInitSchema.Complete
2025-10-14T14:22:45.520670Z node 10 :TX_DATASHARD DEBUG: datashard__init.cpp:50: TDataShard::TTxInit::Execute
2025-10-14T14:22:45.522508Z node 10 :TX_DATASHARD DEBUG: datashard.cpp:1323: LoadChangeRecords: QueueSize: 0, at tablet: 72075186224037888
2025-10-14T14:22:45.522565Z node 10 :TX_DATASHARD DEBUG: datashard.cpp:1379: LoadLockChangeRecords at tablet: 72075186224037888
2025-10-14T14:22:45.522606Z node 10 :TX_DATASHARD DEBUG: datashard.cpp:1428: LoadChangeRecordCommits at tablet: 72075186224037888
2025-10-14T14:22:45.522975Z node 10 :TX_DATASHARD DEBUG: datashard__init.cpp:94: TDataShard::TTxInit::Complete
2025-10-14T14:22:45.523043Z node 10 :TX_DATASHARD DEBUG: datashard__init.cpp:102: TDataShard::TTxInitRestored::Execute
2025-10-14T14:22:45.523077Z node 10 :TX_DATASHARD DEBUG: datashard__init.cpp:142: DataShard 72075186224037888 persisting started state actor id [10:7561082759600619964:2322] in generation 1
2025-10-14T14:22:45.532514Z node 10 :TX_DATASHARD DEBUG: datashard__init.cpp:151: TDataShard::TTxInitRestored::Complete
2025-10-14T14:22:45.532564Z node 10 :TX_DATASHARD INFO: datashard.cpp:417: Switched to work state WaitScheme tabletId 72075186224037888
2025-10-14T14:22:45.532649Z node 10 :TX_DATASHARD DEBUG: datashard.cpp:457: 72075186224037888 not sending time cast registration request in state WaitScheme: missing processing params
2025-10-14T14:22:45.532700Z node 10 :TX_DATASHARD DEBUG: datashard.cpp:1258: Change sender created: at tablet: 72075186224037888, actorId: [10:7561082759600619967:2323]
2025-10-14T14:22:45.532726Z node 10 :TX_DATASHARD DEBUG: datashard.cpp:1263: Trying to activate change sender: at tablet: 72075186224037888
2025-10-14T14:22:45.532739Z node 10 :TX_DATASHARD INFO: datashard.cpp:1280: Cannot activate change sender: at tablet: 72075186224037888, state: WaitScheme
2025-10-14T14:22:45.532756Z node 10 :TX_DATASHARD DEBUG: cdc_stream_heartbeat.cpp:87: [CdcStreamHeartbeat] Emit heartbeats: at tablet# 72075186224037888
2025-10-14T14:22:45.532904Z node 10 :TX_DATASHARD DEBUG: datashard__cleanup_in_rs.cpp:96: TTxCheckInReadSets::Execute at 72075186224037888
2025-10-14T14:22:45.532997Z node 10 :TX_DATASHARD DEBUG: datashard__cleanup_in_rs.cpp:139: TTxCheckInReadSets::Complete found 0 read sets to remove in 72075186224037888
2025-10-14T14:22:45.533053Z node 10 :TX_DATASHARD DEBUG: datashard.cpp:3721: Server connected at leader tablet# 72075186224037888, clientId# [10:7561082759600619930:2656], serverId# [10:7561082759600619937:2661], sessionId# [0:0:0]
2025-10-14T14:22:45.533082Z node 10 :TX_DATASHARD DEBUG: datashard__progress_tx.cpp:16: TTxProgressTransaction::Execute at 72075186224037888
2025-10-14T14:22:45.533097Z node 10 :TX_DATASHARD DEBUG: datashard_pipeline.cpp:272: GetNextActiveOp at 72075186224037888 active 0 active planned 0 immediate 0 planned 0
2025-10-14T14:22:45.533115Z node 10 :TX_DATASHARD INFO: datashard__progress_tx.cpp:48: No tx to execute at 72075186224037888 TxInFly 0
2025-10-14T14:22:45.533137Z node 10 :TX_DATASHARD DEBUG: datashard__progress_tx.cpp:119: TTxProgressTransaction::Complete at 72075186224037888
2025-10-14T14:22:45.533762Z node 10 :TX_DATASHARD DEBUG: datashard__propose_tx_base.cpp:33: TTxProposeTransactionBase::Execute at 72075186224037888
2025-10-14T14:22:45.534038Z node 10 :TX_DATASHARD DEBUG: check_scheme_tx_unit.cpp:133: Propose scheme transaction at tablet 72075186224037888 txId 281474976710658 ssId 72057594046644480 seqNo 2:1
2025-10-14T14:22:45.534145Z node 10 :TX_DATASHARD DEBUG: check_scheme_tx_unit.cpp:221: Prepared scheme transaction txId 281474976710658 at tablet 72075186224037888
2025-10-14T14:22:45.536855Z node 10 :TX_DATASHARD DEBUG: datashard_subdomain_path_id.cpp:129: Discovered subdomain [OwnerId: 72057594046644480, LocalPathId: 1] state, outOfSpace = 0 at datashard 72075186224037888
2025-10-14T14:22:45.537769Z node 10 :TX_DATASHARD DEBUG: datashard__propose_tx_base.cpp:152: TTxProposeTransactionBase::Complete at 72075186224037888
2025-10-14T14:22:45.537847Z node 10 :TX_DATASHARD DEBUG: datashard.cpp:467: 72075186224037888 not sending time cast registration request in state WaitScheme
2025-10-14T14:22:45.545066Z node 10 :TX_DATASHARD DEBUG: datashard.cpp:3721: Server connected at leader tablet# 72075186224037888, clientId# [10:7561082759600619989:2698], serverId# [10:7561082759600619990:2699], sessionId# [0:0:0]
2025-10-14T14:22:45.555358Z node 10 :TX_DATASHARD DEBUG: datashard__plan_step.cpp:69: Planned transaction txId 281474976710658 at step 1760451765590 at tablet 72075186224037888 { Transactions { TxId: 281474976710658 AckTo { RawX1: 0 RawX2: 0 } } Step: 1760451765590 MediatorID: 72057594046382081 TabletID: 72075186224037888 }
2025-10-14T14:22:45.555400Z node 10 :TX_DATASHARD DEBUG: cdc_stream_heartbeat.cpp:87: [CdcStreamHeartbeat] Emit heartbeats: at tablet# 72075186224037888
2025-10-14T14:22:45.555560Z node 10 :TX_DATASHARD DEBUG: datashard_subdomain_path_id.cpp:129: Discovered subdomain [OwnerId: 72057594046644480, LocalPathId: 1] state, outOfSpace = 0 at datashard 72075186224037888
2025-10-14T14:22:45.555636Z node 10 :TX_DATASHARD DEBUG: datashard__progress_tx.cpp:16: TTxProgressTransaction::Execute at 72075186224037888
2025-10-14T14:22:45.555658Z node 10 :TX_DATASHARD DEBUG: datashard_pipeline.cpp:272: GetNextActiveOp at 72075186224037888 active 0 active planned 0 immediate 0 planned 1
2025-10-14T14:22:45.555688Z node 10 :TX_DATASHARD DEBUG: datashard_pipeline.cpp:333: Found ready operation [1760451765590:281474976710658] in PlanQueue unit at 72075186224037888
2025-10-14T14:22:45.555951Z node 10 :TX_DATASHARD DEBUG: datashard_pipeline.cpp:634: LoadTxDetails at 72075186224037888 loaded tx from db 1760451765590:281474976710658 keys extracted: 0
2025-10-14T14:22:45.556089Z node 10 :TX_DATASHARD DEBUG: datashard_pipeline.cpp:272: GetNextActiveOp at 72075186224037888 (dry run) active 1 active planned 1 immediate 0 planned 1
2025-10-14T14:22:45.556215Z node 10 :TX_DATASHARD DEBUG: datashard__progress_tx.cpp:16: TTxProgressTransaction::Execute at 72075186224037888
2025-10-14T14:22:45.556273Z node 10 :TX_DATASHARD INFO: create_table_unit.cpp:69: Trying to CREATE TABLE at 72075186224037888 tableId# [OwnerId: 72057594046644480, LocalPathId: 2] schema version# 1
2025-10-14T14:22:45.557474Z node 10 :TX_DATASHARD INFO: datashard.cpp:475: Send registration request to time cast Ready tabletId 72075186224037888 mediators count is 1 coordinators count is 1 buckets per mediator 2
2025-10-14T14:22:45.557928Z node 10 :TX_DATASHARD DEBUG: datashard_pipeline.cpp:272: GetNextActiveOp at 72075186224037888 (dry run) active 0 active planned 0 immediate 0 planned 0
2025-10-14T14:22:45.559179Z node 10 :TX_DATASHARD DEBUG: datashard.cpp:3753: Got TEvMediatorTimecast::TEvRegisterTabletResult at 72075186224037888 time 1760451765589
2025-10-14T14:22:45.559197Z node 10 :TX_DATASHARD DEBUG: cdc_stream_heartbeat.cpp:87: [CdcStreamHeartbeat] Emit heartbeats: at tablet# 72075186224037888
2025-10-14T14:22:45.561010Z node 10 :TX_DATASHARD DEBUG: datashard__plan_step.cpp:98: Sending '{TEvPlanStepAccepted TabletId# 72075186224037888 step# 1760451765590}
2025-10-14T14:22:45.561069Z node 10 :TX_DATASHARD DEBUG: datashard__progress_tx.cpp:119: TTxProgressTransaction::Complete at 72075186224037888
2025-10-14T14:22:45.561276Z node 10 :TX_DATASHARD DEBUG: datashard.cpp:3771: Got TEvMediatorTimecast::TEvSubscribeReadStepResult at 72075186224037888 coordinator 72057594046316545 last step 0 next step 1760451765597
2025-10-14T14:22:45.561320Z node 10 :TX_DATASHARD DEBUG: datashard__progress_tx.cpp:119: TTxProgressTransaction::Complete at 72075186224037888
2025-10-14T14:22:45.561337Z node 10 :TX_DATASHARD DEBUG: datashard.cpp:1263: Trying to activate change sender: at tablet: 72075186224037888
2025-10-14T14:22:45.561367Z node 10 :TX_DATASHARD INFO: datashard.cpp:1301: Change sender activated: at tablet: 72075186224037888
2025-10-14T14:22:45.561405Z node 10 :TX_DATASHARD DEBUG: datashard.cpp:809: Complete [1760451765590 : 281474976710658] from 72075186224037888 at tablet 72075186224037888 send result to client [10:7561082742420750013:2198], exec latency: 1 ms, propose latency: 5 ms
2025-10-14T14:22:45.561429Z node 10 :TX_DATASHARD INFO: datashard.cpp:1598: 72075186224037888 Sending notify to schemeshard 72057594046644480 txId 281474976710658 state Ready TxInFly 0
2025-10-14T14:22:45.561455Z node 10 :TX_DATASHARD DEBUG: cdc_stream_heartbeat.cpp:87: [CdcStreamHeartbeat] Emit heartbeats: at tablet# 72075186224037888
2025-10-14T14:22:45.564868Z node 10 :TX_DATASHARD DEBUG: datashard.cpp:2964: Handle TEvSchemaChangedResult 281474976710658  datashard 72075186224037888 state Ready
2025-10-14T14:22:45.564914Z node 10 :TX_DATASHARD DEBUG: datashard__schema_changed.cpp:22: 72075186224037888 Got TEvSchemaChangedResult from SS at 72075186224037888
2025-10-14T14:22:45.591581Z node 10 :TX_DATASHARD DEBUG: datashard.cpp:3721: Server connected at leader tablet# 72075186224037888, clientId# [10:7561082759600620041:2740], serverId# [10:7561082759600620042:2741], sessionId# [0:0:0]
2025-10-14T14:22:45.591692Z node 10 :TX_DATASHARD INFO: datashard__op_rows.cpp:26: TTxDirectBase(36) Execute: at tablet# 72075186224037888
2025-10-14T14:22:45.597430Z node 10 :TX_DATASHARD INFO: datashard__op_rows.cpp:80: TTxDirectBase(36) Complete: at tablet# 72075186224037888
2025-10-14T14:22:45.597470Z node 10 :TX_DATASHARD DEBUG: cdc_stream_heartbeat.cpp:87: [CdcStreamHeartbeat] Emit heartbeats: at tablet# 72075186224037888
SUCCESS
Upsert done: 0.028822s
2025-10-14T14:22:46.112999Z node 10 :KQP_EXECUTER ERROR: kqp_planner.cpp:123: TxId: 281474976710659. Ctx: { TraceId: 01k7hhm9bjcjh6agdf800x4jk3, Database: , SessionId: ydb://session/3?node_id=10&id=ZWMxNTIyMS1mYjBhODAyYi04ODhjMmU5Ni1mNTQ5ZThiYg==, PoolId: , DatabaseId: /Root}. Database not set, use /Root
SUCCESS
count returned 100 rows
Negative (format is not CSV): SCHEME_ERROR
Negative (format is not CSV): BAD_REQUEST
Negative (less columns): BAD_REQUEST
Negative (reordered columns): BAD_REQUEST
2025-10-14T14:22:46.331267Z node 10 :TX_DATASHARD INFO: datashard__op_rows.cpp:26: TTxDirectBase(36) Execute: at tablet# 72075186224037888
2025-10-14T14:22:46.336981Z node 10 :TX_DATASHARD INFO: datashard__op_rows.cpp:80: TTxDirectBase(36) Complete: at tablet# 72075186224037888
2025-10-14T14:22:46.337003Z node 10 :TX_DATASHARD DEBUG: cdc_stream_heartbeat.cpp:87: [CdcStreamHeartbeat] Emit heartbeats: at tablet# 72075186224037888
Reordered columns (with header): SUCCESS
