2025-12-12T12:27:07.323921Z :YQ_TEST_CONNECTION DEBUG: test_connection.cpp:142: Starting yandex query test connection. Actor id: [1:7582946985661012434:2070]
2025-12-12T12:27:07.324187Z :GRPC_SERVER NOTICE: grpc_request_proxy.cpp:380: Grpc request proxy started, nodeid# 1, serve as static node
2025-12-12T12:27:07.324253Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 6ca58679-69617f0a-85bc5868-8fd3dbeb1, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:07.324259Z :GRPC_SERVER CRIT: grpc_request_proxy.cpp:440: Failed to deliver subscription request to config dispatcher
2025-12-12T12:27:07.324269Z :GRPC_SERVER NOTICE: grpc_request_proxy.cpp:380: Grpc request proxy started, nodeid# 1, serve as static node
2025-12-12T12:27:07.324288Z :GRPC_SERVER CRIT: grpc_request_proxy.cpp:440: Failed to deliver subscription request to config dispatcher
2025-12-12T12:27:07.324689Z :YQ_RATE_LIMITER INFO: quoter_service.cpp:124: Bootstraping with config: { Enabled: true DataPlaneEnabled: true Database { Endpoint: "localhost:25827" Database: "local" TablePrefix: "RateLimiter_5958a75f-5918-4b93-a01c-15191f6a0817" } Limiters { CoordinationNodePath: "rate_limiter" } }
2025-12-12T12:27:07.325572Z :FQ_QUOTA_PROXY INFO: quota_proxy.cpp:90: STARTED
2025-12-12T12:27:07.325607Z :FQ_LOG_UPDATER DEBUG: log.cpp:93: Updated YQL logs priority: 8
2025-12-12T12:27:07.325612Z :FQ_LOG_UPDATER CRIT: log.cpp:55: Failed to deliver subscription request to config dispatcher.
2025-12-12T12:27:07.325650Z :STREAMS_STORAGE_SERVICE INFO: storage_proxy.cpp:214: Bootstrap
2025-12-12T12:27:07.325653Z :STREAMS_STORAGE_SERVICE INFO: storage_proxy.cpp:217: Create sdk ydb connection
2025-12-12T12:27:07.325824Z :FQ_QUOTA_SERVICE INFO: quota_manager.cpp:196: STARTED
2025-12-12T12:27:07.325844Z :FQ_ROW_DISPATCHER DEBUG: row_dispatcher.cpp:544: RowDispatcher: Successfully bootstrapped row dispatcher, id [1:7582946985661012429:2065], tenant /compute
2025-12-12T12:27:07.325855Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7582946985661012429:2065]
2025-12-12T12:27:07.325857Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:329: Coordinator: Add new row dispatcher to map (state 1)
2025-12-12T12:27:07.325965Z :FQ_ROW_DISPATCHER DEBUG: coordinator.cpp:293: Coordinator: Successfully bootstrapped coordinator, id [1:7582946985661012477:2096], NodesManagerId [0:4705493345362661702:78], rebalancing timeout 5.000000s
2025-12-12T12:27:07.326497Z :FQ_ROW_DISPATCHER DEBUG: leader_election.cpp:232: TLeaderElection [1:7582946985661012478:2097] Successfully bootstrapped, local coordinator id [1:7582946985661012477:2096], tenant id compute, local mode 0, coordination node path local/compute, endpoint localhost:25827
2025-12-12T12:27:07.326610Z :YQL_NODES_MANAGER INFO: nodes_manager.cpp:88: Bootstrap, InstanceId: 2eabb9a9-45cdb6aa-2b652fa2-6a73f108
2025-12-12T12:27:07.326613Z :YQL_NODES_MANAGER DEBUG: nodes_manager.cpp:310: TNodesManagerActor::ResolveSelfAddress
2025-12-12T12:27:07.326636Z :FQ_ROW_DISPATCHER DEBUG: row_dispatcher.cpp:637: RowDispatcher: TEvCoordinatorChangesSubscribe from [1:7582946985661012477:2096]
2025-12-12T12:27:07.327856Z :SCHEME_BOARD_SUBSCRIBER NOTICE: subscriber.cpp:849: [main][1:7582946985661012450:2081][/Root] Set up state: owner# [1:7582946985661012406:2052], state# { Deleted: 1 Strong: 0 Version: <Invalid> DomainId: <Invalid> AbandonedSchemeShards: there are 0 elements }
2025-12-12T12:27:07.327866Z :SCHEME_BOARD_SUBSCRIBER NOTICE: subscriber.cpp:849: [main][1:7582946985661012451:2082][/compute] Set up state: owner# [1:7582946985661012406:2052], state# { Deleted: 1 Strong: 0 Version: <Invalid> DomainId: <Invalid> AbandonedSchemeShards: there are 0 elements }
2025-12-12T12:27:07.327871Z :SCHEME_BOARD_SUBSCRIBER NOTICE: subscriber.cpp:849: [main][1:7582946985661012453:2084][/compute] Set up state: owner# [1:7582946985661012407:2053], state# { Deleted: 1 Strong: 0 Version: <Invalid> DomainId: <Invalid> AbandonedSchemeShards: there are 0 elements }
2025-12-12T12:27:07.327877Z :SCHEME_BOARD_SUBSCRIBER NOTICE: subscriber.cpp:849: [main][1:7582946985661012452:2083][/Root] Set up state: owner# [1:7582946985661012407:2053], state# { Deleted: 1 Strong: 0 Version: <Invalid> DomainId: <Invalid> AbandonedSchemeShards: there are 0 elements }
2025-12-12T12:27:07.327882Z :GRPC_SERVER WARN: grpc_request_proxy.cpp:583: SchemeBoardDelete /Root Strong=0
2025-12-12T12:27:07.327884Z :GRPC_SERVER WARN: grpc_request_proxy.cpp:583: SchemeBoardDelete /compute Strong=0
2025-12-12T12:27:07.327885Z :GRPC_SERVER WARN: grpc_request_proxy.cpp:583: SchemeBoardDelete /compute Strong=0
2025-12-12T12:27:07.327887Z :GRPC_SERVER WARN: grpc_request_proxy.cpp:583: SchemeBoardDelete /Root Strong=0
2025-12-12T12:27:07.328656Z :MEMORY_PROFILER NOTICE: monitor.cpp:332: Bootstrapped
2025-12-12T12:27:07.328802Z :STREAMS_STORAGE_SERVICE INFO: storage_proxy.cpp:239: Successfully bootstrapped TStorageProxy [1:7582946985661012428:2064] with connection to localhost:25827:local
2025-12-12T12:27:07.329562Z :YQL_NODES_MANAGER TRACE: nodes_manager.cpp:318: TNodesManagerActor::NodesHealthCheck
2025-12-12T12:27:07.331225Z :FQ_ROW_DISPATCHER DEBUG: schema.cpp:71: Run create coordination node "local/compute" actor
2025-12-12T12:27:07.331228Z :FQ_ROW_DISPATCHER DEBUG: schema.cpp:113: Call create coordination node "local/compute"
2025-12-12T12:27:07.331231Z :FQ_ROW_DISPATCHER DEBUG: schema.cpp:411: Call create coordination node "local/compute"
2025-12-12T12:27:07.352479Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:07.352495Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:07.356616Z :FQ_ROW_DISPATCHER DEBUG: schema.cpp:155: Successfully created coordination node "local/compute"
2025-12-12T12:27:07.356646Z :FQ_ROW_DISPATCHER DEBUG: schema.cpp:122: Reply for create coordination node "local/compute": { <main>: Error: Check failed: path: '/local/compute', error: path exist, request accepts it (id: [OwnerId: 72057594046678944, LocalPathId: 19], type: EPathTypeKesus, state: EPathStateNoChanges), source_location: ydb/core/tx/schemeshard/schemeshard__operation_create_kesus.cpp:339 }
2025-12-12T12:27:07.356662Z :FQ_ROW_DISPATCHER DEBUG: leader_election.cpp:345: TLeaderElection [1:7582946985661012478:2097] Coordination node successfully created
2025-12-12T12:27:07.356666Z :FQ_ROW_DISPATCHER DEBUG: leader_election.cpp:323: TLeaderElection [1:7582946985661012478:2097] Start session
2025-12-12T12:27:07.362776Z :YQL_NODES_MANAGER TRACE: nodes_manager.cpp:389: Send NodeInfo with size: 0 to DynamicNameserver
2025-12-12T12:27:07.364975Z :FQ_ROW_DISPATCHER DEBUG: leader_election.cpp:359: TLeaderElection [1:7582946985661012478:2097] Session successfully created
2025-12-12T12:27:07.374983Z :FQ_ROW_DISPATCHER DEBUG: leader_election.cpp:372: TLeaderElection [1:7582946985661012478:2097] Semaphore successfully created
2025-12-12T12:27:07.375014Z :FQ_ROW_DISPATCHER DEBUG: leader_election.cpp:304: TLeaderElection [1:7582946985661012478:2097] Try to acquire semaphore
2025-12-12T12:27:07.375096Z :FQ_ROW_DISPATCHER DEBUG: leader_election.cpp:420: TLeaderElection [1:7582946985661012478:2097] Describe semaphore
2025-12-12T12:27:07.382895Z :FQ_ROW_DISPATCHER DEBUG: leader_election.cpp:386: TLeaderElection [1:7582946985661012478:2097] Semaphore successfully acquired
2025-12-12T12:27:07.382942Z :FQ_ROW_DISPATCHER DEBUG: leader_election.cpp:469: TLeaderElection [1:7582946985661012478:2097] Semaphore successfully described: coordinator id [1:7582946985661012477:2096] generation 6
2025-12-12T12:27:07.382947Z :FQ_ROW_DISPATCHER INFO: leader_election.cpp:471: TLeaderElection [1:7582946985661012478:2097] Send TEvCoordinatorChanged to [1:7582946985661012429:2065], new coordinator id [1:7582946985661012477:2096], previous coordinator id [0:0:0]
2025-12-12T12:27:07.382965Z :FQ_ROW_DISPATCHER DEBUG: row_dispatcher.cpp:569: RowDispatcher: Coordinator changed, old leader (empty maybe), new [1:7582946985661012477:2096] generation 6
2025-12-12T12:27:07.382974Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [1:7582946985661012429:2065]
2025-12-12T12:27:07.382978Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7582946985661012429:2065]
2025-12-12T12:27:07.382982Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [1:7582946985661012429:2065]
2025-12-12T12:27:07.382988Z :FQ_ROW_DISPATCHER DEBUG: coordinator.cpp:440: Coordinator: New leader [1:7582946985661012477:2096], SelfId [1:7582946985661012477:2096]
2025-12-12T12:27:07.382991Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:633: RowDispatcher: NActors::TEvents::TEvPong
2025-12-12T12:27:08.323040Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 6ca58679-69617f0a-85bc5868-8fd3dbeb2, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:08.331199Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:08.331216Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:09.321839Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:627: RowDispatcher: Send ping to [1:7582946985661012477:2096]
2025-12-12T12:27:09.321859Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1174: RowDispatcher: TEvPrivate::TEvSendStatistic
2025-12-12T12:27:09.321879Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [1:7582946985661012429:2065]
2025-12-12T12:27:09.321883Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7582946985661012429:2065]
2025-12-12T12:27:09.321886Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [1:7582946985661012429:2065]
2025-12-12T12:27:09.321893Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:633: RowDispatcher: NActors::TEvents::TEvPong
2025-12-12T12:27:09.322842Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 6ca58679-69617f0a-85bc5868-8fd3dbeb3, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:09.331247Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:09.331264Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:10.323302Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 6ca58679-69617f0a-85bc5868-8fd3dbeb4, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:10.332963Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:10.332981Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:11.322721Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:627: RowDispatcher: Send ping to [1:7582946985661012477:2096]
2025-12-12T12:27:11.322747Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1174: RowDispatcher: TEvPrivate::TEvSendStatistic
2025-12-12T12:27:11.322757Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [1:7582946985661012429:2065]
2025-12-12T12:27:11.322761Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7582946985661012429:2065]
2025-12-12T12:27:11.322764Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [1:7582946985661012429:2065]
2025-12-12T12:27:11.322778Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:633: RowDispatcher: NActors::TEvents::TEvPong
2025-12-12T12:27:11.323737Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 6ca58679-69617f0a-85bc5868-8fd3dbeb5, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:11.331821Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:11.331837Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:12.322130Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:665: Coordinator: Change global state to Started (by timeout)
2025-12-12T12:27:12.324155Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 6ca58679-69617f0a-85bc5868-8fd3dbeb6, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:12.329314Z :YQL_NODES_MANAGER TRACE: nodes_manager.cpp:318: TNodesManagerActor::NodesHealthCheck
2025-12-12T12:27:12.331426Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:12.331443Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:12.341297Z :YQL_NODES_MANAGER TRACE: nodes_manager.cpp:389: Send NodeInfo with size: 0 to DynamicNameserver
2025-12-12T12:27:13.323657Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:627: RowDispatcher: Send ping to [1:7582946985661012477:2096]
2025-12-12T12:27:13.323678Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1174: RowDispatcher: TEvPrivate::TEvSendStatistic
2025-12-12T12:27:13.323685Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [1:7582946985661012429:2065]
2025-12-12T12:27:13.323689Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7582946985661012429:2065]
2025-12-12T12:27:13.323693Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [1:7582946985661012429:2065]
2025-12-12T12:27:13.323704Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:633: RowDispatcher: NActors::TEvents::TEvPong
2025-12-12T12:27:13.324632Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 6ca58679-69617f0a-85bc5868-8fd3dbeb7, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:13.339096Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:13.339109Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:14.325076Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 6ca58679-69617f0a-85bc5868-8fd3dbeb8, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:14.330762Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:14.330776Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:15.324491Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:627: RowDispatcher: Send ping to [1:7582946985661012477:2096]
2025-12-12T12:27:15.324514Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1174: RowDispatcher: TEvPrivate::TEvSendStatistic
2025-12-12T12:27:15.324522Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [1:7582946985661012429:2065]
2025-12-12T12:27:15.324528Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7582946985661012429:2065]
2025-12-12T12:27:15.324531Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [1:7582946985661012429:2065]
2025-12-12T12:27:15.324544Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:633: RowDispatcher: NActors::TEvents::TEvPong
2025-12-12T12:27:15.325545Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 6ca58679-69617f0a-85bc5868-8fd3dbeb9, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:15.329118Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:15.329135Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:16.325985Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 6ca58679-69617f0a-85bc5868-8fd3dbeb10, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:16.331829Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:16.331841Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:17.322346Z :FQ_ROW_DISPATCHER DEBUG: coordinator.cpp:599: Coordinator: Send TEvGetNodesRequest to NodesManager
2025-12-12T12:27:17.322375Z :YQL_NODES_MANAGER TRACE: nodes_manager.cpp:300: Received TNodesManagerActor::TEvGetNodesRequest
2025-12-12T12:27:17.322387Z :FQ_ROW_DISPATCHER INFO: coordinator.cpp:690: Coordinator: Updated node info, node count: 1
2025-12-12T12:27:17.325382Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:627: RowDispatcher: Send ping to [1:7582946985661012477:2096]
2025-12-12T12:27:17.325398Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1174: RowDispatcher: TEvPrivate::TEvSendStatistic
2025-12-12T12:27:17.325405Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [1:7582946985661012429:2065]
2025-12-12T12:27:17.325410Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7582946985661012429:2065]
2025-12-12T12:27:17.325412Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [1:7582946985661012429:2065]
2025-12-12T12:27:17.325422Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:633: RowDispatcher: NActors::TEvents::TEvPong
2025-12-12T12:27:17.326433Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 6ca58679-69617f0a-85bc5868-8fd3dbeb11, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:17.329539Z :YQL_NODES_MANAGER TRACE: nodes_manager.cpp:318: TNodesManagerActor::NodesHealthCheck
2025-12-12T12:27:17.330149Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:17.330162Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:17.338837Z :YQL_NODES_MANAGER TRACE: nodes_manager.cpp:389: Send NodeInfo with size: 0 to DynamicNameserver
2025-12-12T12:27:18.330187Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 6ca58679-69617f0a-85bc5868-8fd3dbeb12, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:18.334272Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:18.334299Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:19.326299Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:627: RowDispatcher: Send ping to [1:7582946985661012477:2096]
2025-12-12T12:27:19.326318Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1174: RowDispatcher: TEvPrivate::TEvSendStatistic
2025-12-12T12:27:19.326324Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [1:7582946985661012429:2065]
2025-12-12T12:27:19.326328Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7582946985661012429:2065]
2025-12-12T12:27:19.326341Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [1:7582946985661012429:2065]
2025-12-12T12:27:19.326352Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:633: RowDispatcher: NActors::TEvents::TEvPong
2025-12-12T12:27:19.330387Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 6ca58679-69617f0a-85bc5868-8fd3dbeb13, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:19.334237Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:19.334251Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:20.330830Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 6ca58679-69617f0a-85bc5868-8fd3dbeb14, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:20.334581Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:20.334591Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:21.327159Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:627: RowDispatcher: Send ping to [1:7582946985661012477:2096]
2025-12-12T12:27:21.327188Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1174: RowDispatcher: TEvPrivate::TEvSendStatistic
2025-12-12T12:27:21.327198Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [1:7582946985661012429:2065]
2025-12-12T12:27:21.327202Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7582946985661012429:2065]
2025-12-12T12:27:21.327205Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [1:7582946985661012429:2065]
2025-12-12T12:27:21.327221Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:633: RowDispatcher: NActors::TEvents::TEvPong
2025-12-12T12:27:21.331328Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 6ca58679-69617f0a-85bc5868-8fd3dbeb15, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:21.335386Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:21.335402Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:22.329695Z :YQL_NODES_MANAGER TRACE: nodes_manager.cpp:318: TNodesManagerActor::NodesHealthCheck
2025-12-12T12:27:22.334158Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 6ca58679-69617f0a-85bc5868-8fd3dbeb16, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:22.347185Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:22.347195Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:22.347212Z :YQL_NODES_MANAGER TRACE: nodes_manager.cpp:389: Send NodeInfo with size: 0 to DynamicNameserver
2025-12-12T12:27:23.328092Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:627: RowDispatcher: Send ping to [1:7582946985661012477:2096]
2025-12-12T12:27:23.328112Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1174: RowDispatcher: TEvPrivate::TEvSendStatistic
2025-12-12T12:27:23.328118Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [1:7582946985661012429:2065]
2025-12-12T12:27:23.328121Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7582946985661012429:2065]
2025-12-12T12:27:23.328124Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [1:7582946985661012429:2065]
2025-12-12T12:27:23.328133Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:633: RowDispatcher: NActors::TEvents::TEvPong
2025-12-12T12:27:23.335250Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 6ca58679-69617f0a-85bc5868-8fd3dbeb17, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:23.358270Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:23.358283Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 1
2025-12-12T12:27:23.358502Z :FQ_PENDING_FETCHER DEBUG: pending_fetcher.cpp:361: NewTask: Scope: yandexcloud://my_folder Id: ptqudq7ufj3un8ovpbv9 UserId: root@builtin AuthToken: **** (B6C6F477)
2025-12-12T12:27:23.358657Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 6ca58679-69617f0a-85bc5868-8fd3dbeb18, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:23.358661Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:375: QueryId: ptqudq7ufj3un8ovpbv9 Start run actor. Compute state: RUNNING
2025-12-12T12:27:23.358664Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:469: QueryId: ptqudq7ufj3un8ovpbv9 FillConnections
2025-12-12T12:27:23.358702Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:2333: QueryId: ptqudq7ufj3un8ovpbv9 Run actors params: { QueryId: ptqudq7ufj3un8ovpbv9 CloudId: mock_cloud UserId: root@builtin Owner: 6ca58679-69617f0a-85bc5868-8fd3dbeb17 PreviousQueryRevision: 2 Connections: 1 Bindings: 0 AccountIdSignatures: 0 QueryType: STREAMING ExecuteMode: RUN ResultId: ptrudq7uet7plgdf9k5a StateLoadMode: FROM_LAST_CHECKPOINT StreamingDisposition: { from_last_checkpoint { } } Status: RUNNING DqGraphs: 1 DqGraphIndex: 0 Resource.TopicConsumers: 1 }
2025-12-12T12:27:23.358728Z :FQ_PINGER TRACE: pinger.cpp:171: QueryId: ptqudq7ufj3un8ovpbv9, Owner: 6ca58679-69617f0a-85bc5868-8fd3dbeb17 Start Pinger
2025-12-12T12:27:23.358770Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:911: QueryId: ptqudq7ufj3un8ovpbv9 Overall dq tasks: 2
2025-12-12T12:27:23.358915Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:1598: QueryId: ptqudq7ufj3un8ovpbv9 ResultWriter was NOT CREATED since ResultType is empty
2025-12-12T12:27:23.358974Z :FQ_PINGER TRACE: pinger.cpp:250: QueryId: ptqudq7ufj3un8ovpbv9, Owner: 6ca58679-69617f0a-85bc5868-8fd3dbeb17 Forward ping request: { resources { rate_limiter: READY compilation: READY topic_consumers_state: READY rate_limiter_path: "local/RateLimiter_5958a75f-5918-4b93-a01c-15191f6a0817/rate_limiter" topic_consumers { database: "local" topic_path: "test_match_recognize[v1-kikimr0]_v1_input" consumer_name: "ptqudq7ufj3un8ovpbv9" cluster_endpoint: "localhost:25827" token_name: "cluster:default_myyds" add_bearer_to_token: true } } }
2025-12-12T12:27:23.358978Z :FQ_PINGER TRACE: pinger.cpp:393: QueryId: ptqudq7ufj3un8ovpbv9, Owner: 6ca58679-69617f0a-85bc5868-8fd3dbeb17 Forward request Private::PingTask
2025-12-12T12:27:23.358996Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: ptqudq7ufj3un8ovpbv9 2025-12-12 12:27:23.358 DEBUG ydbd(pid=1196126, tid=0x00007F90FCD0D640) [DQ] task_controller_impl.h:86: _RowsLimitPerWrite = 0
2025-12-12T12:27:23.359054Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:1652: QueryId: ptqudq7ufj3un8ovpbv9 Executer: [1:7582947054380489379:2247], Controller: [1:7582947054380489381:2249], ResultIdActor: [1:7582947054380489379:2247]
2025-12-12T12:27:23.359088Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: ptqudq7ufj3un8ovpbv9 2025-12-12 12:27:23.359 DEBUG ydbd(pid=1196126, tid=0x00007F90FCD0D640) [DQ] executer_actor.cpp:140: {ptqudq7ufj3un8ovpbv9} TDqExecuter::OnGraph
2025-12-12T12:27:23.359100Z :YQL_PROXY INFO: log.cpp:64: SessionId: ptqudq7ufj3un8ovpbv9 2025-12-12 12:27:23.359 INFO  ydbd(pid=1196126, tid=0x00007F90FCD0D640) [DQ] executer_actor.cpp:157: {ptqudq7ufj3un8ovpbv9} Trying to allocate 2 workers [EnableComputeActor=1]
2025-12-12T12:27:23.360111Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: ptqudq7ufj3un8ovpbv9 2025-12-12 12:27:23.360 DEBUG ydbd(pid=1196126, tid=0x00007F90FCD0D640) [DQ] executer_actor.cpp:247: {ptqudq7ufj3un8ovpbv9} Dq timeouts are set to: 0.000000s (global), 600.000000s (workers allocation fail), 30.000000s (workers allocation warn) 
2025-12-12T12:27:23.360767Z :YQL_NODES_MANAGER DEBUG: nodes_manager.cpp:125: TEvAllocateWorkersResponse Nodes {
  ResourceId: 4294967297
  Worker {
    NodeId: 1
    Guid: "2eabb9a9-45cdb6aa-2b652fa2-6a73f108,ghrun-fhkyrtz6p4"
  }
  Worker {
    NodeId: 1
    Guid: "2eabb9a9-45cdb6aa-2b652fa2-6a73f108,ghrun-fhkyrtz6p4"
  }
}
2025-12-12T12:27:23.360923Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: 6ca58679-69617f0a-85bc5868-8fd3dbeb 2025-12-12 12:27:23.360 DEBUG ydbd(pid=1196126, tid=0x00007F90FCD0D640) [DQ] local_worker_manager.cpp:316: {ptqudq7ufj3un8ovpbv9} TLocalWorkerManager::TEvAllocateWorkersRequest 562954248388609
2025-12-12T12:27:23.360939Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: 6ca58679-69617f0a-85bc5868-8fd3dbeb 2025-12-12 12:27:23.360 DEBUG ydbd(pid=1196126, tid=0x00007F90FCD0D640) [DQ] local_worker_manager.cpp:376: {ptqudq7ufj3un8ovpbv9} Create compute actor: async
2025-12-12T12:27:23.362968Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:23.362972Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:23.372408Z :FQ_PINGER TRACE: pinger.cpp:338: QueryId: ptqudq7ufj3un8ovpbv9, Owner: 6ca58679-69617f0a-85bc5868-8fd3dbeb17 Ping response success: { expired_at { seconds: 1765542463 nanos: 365000000 } }
2025-12-12T12:27:23.372457Z :FQ_RUN_ACTOR TRACE: run_actor.cpp:861: QueryId: ptqudq7ufj3un8ovpbv9 Forward ping response. Success: 1. Cookie: 0
2025-12-12T12:27:23.395124Z :KQP_COMPUTE DEBUG: dq_compute_actor_impl.h:144: SelfId: [1:7582947054380489383:2251], TxId: ptqudq7ufj3un8ovpbv9, task: 2. Ctx: {}. Start compute actor [1:7582947054380489383:2251], task: 2
2025-12-12T12:27:23.395142Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: 6ca58679-69617f0a-85bc5868-8fd3dbeb 2025-12-12 12:27:23.395 DEBUG ydbd(pid=1196126, tid=0x00007F90FCD0D640) [DQ] local_worker_manager.cpp:316: {ptqudq7ufj3un8ovpbv9} TLocalWorkerManager::TEvAllocateWorkersRequest 281479271677953
2025-12-12T12:27:23.395159Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: 6ca58679-69617f0a-85bc5868-8fd3dbeb 2025-12-12 12:27:23.395 DEBUG ydbd(pid=1196126, tid=0x00007F90FCD0D640) [DQ] local_worker_manager.cpp:376: {ptqudq7ufj3un8ovpbv9} Create compute actor: async
2025-12-12T12:27:23.395163Z :KQP_COMPUTE DEBUG: dq_async_compute_actor.cpp:114: SelfId: [1:7582947054380489383:2251], TxId: ptqudq7ufj3un8ovpbv9, task: 2. Ctx: {}. Use CPU quota: 1. Rate limiter resource: { "local/RateLimiter_5958a75f-5918-4b93-a01c-15191f6a0817/rate_limiter", "mock_cloud/my_folder/ptqudq7ufj3un8ovpbv9" }
2025-12-12T12:27:23.395249Z :KQP_COMPUTE DEBUG: dq_compute_actor_impl.h:144: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Start compute actor [1:7582947054380489386:2252], task: 1
2025-12-12T12:27:23.395272Z :KQP_COMPUTE DEBUG: dq_async_compute_actor.cpp:114: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Use CPU quota: 1. Rate limiter resource: { "local/RateLimiter_5958a75f-5918-4b93-a01c-15191f6a0817/rate_limiter", "mock_cloud/my_folder/ptqudq7ufj3un8ovpbv9" }
2025-12-12T12:27:23.395313Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: ptqudq7ufj3un8ovpbv9 2025-12-12 12:27:23.395 DEBUG ydbd(pid=1196126, tid=0x00007F90FBD0B640) [DQ] executer_actor.cpp:358: {ptqudq7ufj3un8ovpbv9} TDqExecuter::TEvAllocateWorkersResponse
2025-12-12T12:27:23.395326Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: 6ca58679-69617f0a-85bc5868-8fd3dbeb 2025-12-12 12:27:23.395 DEBUG ydbd(pid=1196126, tid=0x00007F90FCD0D640) [DQ] tasks_runner_local.cpp:267: {TODO/1} Build task: 1
2025-12-12T12:27:23.395333Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: ptqudq7ufj3un8ovpbv9 2025-12-12 12:27:23.395 DEBUG ydbd(pid=1196126, tid=0x00007F90FBD0B640) [DQ] executer_actor.cpp:384: {ptqudq7ufj3un8ovpbv9} Allocated resource 4294967297
2025-12-12T12:27:23.395394Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: ptqudq7ufj3un8ovpbv9 2025-12-12 12:27:23.395 DEBUG ydbd(pid=1196126, tid=0x00007F90FBD0B640) [DQ] executer_actor.cpp:401: {ptqudq7ufj3un8ovpbv9} WorkerInfo: Id:2eabb9a9-45cdb6aa-2b652fa2-6a73f108,ghrun-fhkyrtz6p4,NodeId:1,StageId:214477
2025-12-12T12:27:23.395418Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: ptqudq7ufj3un8ovpbv9 2025-12-12 12:27:23.395 DEBUG ydbd(pid=1196126, tid=0x00007F90FBD0B640) [DQ] executer_actor.cpp:402: {ptqudq7ufj3un8ovpbv9} TaskInfo: 0/1
2025-12-12T12:27:23.395426Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: ptqudq7ufj3un8ovpbv9 2025-12-12 12:27:23.395 DEBUG ydbd(pid=1196126, tid=0x00007F90FBD0B640) [DQ] executer_actor.cpp:404: {ptqudq7ufj3un8ovpbv9}  ObjectId: 88a034dc314301cb1522a933e690a4c49a7591e8, dq_vanilla_job.lite, 
2025-12-12T12:27:23.395449Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: ptqudq7ufj3un8ovpbv9 2025-12-12 12:27:23.395 DEBUG ydbd(pid=1196126, tid=0x00007F90FBD0B640) [DQ] executer_actor.cpp:401: {ptqudq7ufj3un8ovpbv9} WorkerInfo: Id:2eabb9a9-45cdb6aa-2b652fa2-6a73f108,ghrun-fhkyrtz6p4,NodeId:1,StageId:214497
2025-12-12T12:27:23.395455Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: 6ca58679-69617f0a-85bc5868-8fd3dbeb 2025-12-12 12:27:23.395 DEBUG ydbd(pid=1196126, tid=0x00007F90FCD0D640) [DQ] tasks_runner_local.cpp:267: {TODO/1} task: 1, program size: 68, llvm: ``.
2025-12-12T12:27:23.395457Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: ptqudq7ufj3un8ovpbv9 2025-12-12 12:27:23.395 DEBUG ydbd(pid=1196126, tid=0x00007F90FBD0B640) [DQ] executer_actor.cpp:402: {ptqudq7ufj3un8ovpbv9} TaskInfo: 1/2
2025-12-12T12:27:23.395463Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: ptqudq7ufj3un8ovpbv9 2025-12-12 12:27:23.395 DEBUG ydbd(pid=1196126, tid=0x00007F90FBD0B640) [DQ] executer_actor.cpp:404: {ptqudq7ufj3un8ovpbv9}  ObjectId: 88a034dc314301cb1522a933e690a4c49a7591e8, dq_vanilla_job.lite, 
2025-12-12T12:27:23.395476Z :YQL_PROXY INFO: log.cpp:64: SessionId: ptqudq7ufj3un8ovpbv9 2025-12-12 12:27:23.395 INFO  ydbd(pid=1196126, tid=0x00007F90FBD0B640) [DQ] executer_actor.cpp:415: {ptqudq7ufj3un8ovpbv9} 2 workers allocated
2025-12-12T12:27:23.395597Z :YQL_PROXY TRACE: log.cpp:64: SessionId:  2025-12-12 12:27:23.395 TRACE ydbd(pid=1196126, tid=0x00007F90FBD0B640) [DQ] task_controller_impl.h:271:  [1:7582947054380489381:2249] ExportStats Summary
2025-12-12T12:27:23.395634Z :YQL_PROXY DEBUG: log.cpp:64: SessionId:  2025-12-12 12:27:23.395 DEBUG ydbd(pid=1196126, tid=0x00007F90FBD0B640) [DQ] task_controller_impl.h:526: Ready State: [1:7582947054380489381:2249]
2025-12-12T12:27:23.395647Z :YQL_PROXY DEBUG: log.cpp:64: SessionId:  2025-12-12 12:27:23.395 DEBUG ydbd(pid=1196126, tid=0x00007F90FBD0B640) [DQ] task_controller_impl.h:537: Forward: [1:7582947054380489381:2249] to [1:7582947054380489380:2248]
2025-12-12T12:27:23.395677Z :STREAMS_CHECKPOINT_COORDINATOR DEBUG: checkpoint_coordinator.cpp:70: [ptqudq7ufj3un8ovpbv9-0.2] TEvReadyState, streaming disposition { from_last_checkpoint { } }, state load mode FROM_LAST_CHECKPOINT, checkpointing period 1.000000s
2025-12-12T12:27:23.395693Z :STREAMS_CHECKPOINT_COORDINATOR DEBUG: checkpoint_coordinator.cpp:104: [ptqudq7ufj3un8ovpbv9-0.2] AllActors count: 2, ActorsToTrigger count: 1, ActorsToNotify count: 2, ActorsToWaitFor count: 2
2025-12-12T12:27:23.395695Z :STREAMS_CHECKPOINT_COORDINATOR DEBUG: checkpoint_coordinator.cpp:114: [ptqudq7ufj3un8ovpbv9-0.2] Send TEvRegisterCoordinatorRequest
2025-12-12T12:27:23.395702Z :STREAMS_STORAGE_SERVICE DEBUG: storage_proxy.cpp:261: [ptqudq7ufj3un8ovpbv9-0.2] Got TEvRegisterCoordinatorRequest
2025-12-12T12:27:23.395704Z :STREAMS_STORAGE_SERVICE INFO: storage_proxy.cpp:243: StartInitialization, EnableSecureScriptExecutions: 0
2025-12-12T12:27:23.396493Z :STREAMS_STORAGE_SERVICE NOTICE: storage_proxy.cpp:585: Add to delayed
2025-12-12T12:27:23.408053Z :STREAMS_STORAGE_SERVICE INFO: storage_proxy.cpp:557: Checkpoint storage and state storage were successfully initted
2025-12-12T12:27:23.408084Z :STREAMS_STORAGE_SERVICE DEBUG: storage_proxy.cpp:261: [ptqudq7ufj3un8ovpbv9-0.2] Got TEvRegisterCoordinatorRequest
2025-12-12T12:27:23.431157Z :STREAMS_STORAGE_SERVICE INFO: storage_proxy.cpp:279: [ptqudq7ufj3un8ovpbv9-0.2] Graph registered
2025-12-12T12:27:23.431168Z :STREAMS_STORAGE_SERVICE DEBUG: storage_proxy.cpp:281: [ptqudq7ufj3un8ovpbv9-0.2] Send TEvRegisterCoordinatorResponse
2025-12-12T12:27:23.431227Z :STREAMS_CHECKPOINT_COORDINATOR DEBUG: checkpoint_coordinator.cpp:131: [ptqudq7ufj3un8ovpbv9-0.2] Got TEvRegisterCoordinatorResponse; issues: 
2025-12-12T12:27:23.431231Z :STREAMS_CHECKPOINT_COORDINATOR DEBUG: checkpoint_coordinator.cpp:140: [ptqudq7ufj3un8ovpbv9-0.2] Successfully registered in storage
2025-12-12T12:27:23.431235Z :STREAMS_CHECKPOINT_COORDINATOR INFO: checkpoint_coordinator.cpp:141: [ptqudq7ufj3un8ovpbv9-0.2] Send TEvNewCheckpointCoordinator to 2 actor(s)
2025-12-12T12:27:23.431243Z :STREAMS_CHECKPOINT_COORDINATOR INFO: checkpoint_coordinator.cpp:149: [ptqudq7ufj3un8ovpbv9-0.2] Send TEvGetCheckpointsMetadataRequest; state load mode: FROM_LAST_CHECKPOINT; load graph: 0
2025-12-12T12:27:23.431253Z :STREAMS_STORAGE_SERVICE DEBUG: storage_proxy.cpp:434: [ptqudq7ufj3un8ovpbv9-0] Got TEvGetCheckpointsMetadataRequest
2025-12-12T12:27:23.450888Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: 6ca58679-69617f0a-85bc5868-8fd3dbeb 2025-12-12 12:27:23.450 DEBUG ydbd(pid=1196126, tid=0x00007F90FCD0D640) [DQ] tasks_runner_local.cpp:267: {TODO/1} Build task: 1 takes 55527 us
2025-12-12T12:27:23.450914Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: 6ca58679-69617f0a-85bc5868-8fd3dbeb 2025-12-12 12:27:23.450 DEBUG ydbd(pid=1196126, tid=0x00007F90FCD0D640) [DQ] tasks_runner_local.cpp:267: {TODO/1} Prepare task: 1
2025-12-12T12:27:23.450939Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: 6ca58679-69617f0a-85bc5868-8fd3dbeb 2025-12-12 12:27:23.450 DEBUG ydbd(pid=1196126, tid=0x00007F90FCD0D640) [DQ] tasks_runner_local.cpp:267: {TODO/1} Prepare task: 1, takes 16 us
2025-12-12T12:27:23.451080Z :KQP_COMPUTE DEBUG: dq_compute_actor_checkpoints.cpp:197: [] Task: 1. Got TEvNewCheckpointCoordinator event: generation 2, actorId: [1:7582947054380489380:2248]
2025-12-12T12:27:23.451086Z :KQP_COMPUTE TRACE: dq_compute_actor_checkpoints.cpp:208: [] Task: 1. Assign checkpoint coordinator (generation = 2)
2025-12-12T12:27:23.451786Z :KQP_COMPUTE DEBUG: dq_compute_actor_impl.h:1360: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Create source for input 0 { Source { Type: "PqSource" Settings { type_url: "type.googleapis.com/NYql.NPq.NProto.TDqPqTopicSource" value: "\n)test_match_recognize[v1-kikimr0]_v1_input\022\024ptqudq7ufj3un8ovpbv9\032\017localhost:25827\"\027\n\025cluster:default_myyds*\005local0\002@\001b\002dtb\003strj&[\"OptionalType\";[\"DataType\";\"Uint64\"]]j&[\"OptionalType\";[\"DataType\";\"String\"]]\222\001\024ptcudq7ufjfufnmne5eb\232\001\rjson_each_row\242\001m[\"StructType\";[[\"dt\";[\"OptionalType\";[\"DataType\";\"Uint64\"]]];[\"str\";[\"OptionalType\";[\"DataType\";\"String\"]]]]]\262\001\002\022\000\272\001\026\n\010cloud_id\022\nmock_cloud\272\001 \n\005scope\022\027yandexcloud://my_folder" } WatermarksMode: WATERMARKS_MODE_DISABLED } }
2025-12-12T12:27:23.452139Z :KQP_COMPUTE DEBUG: dq_pq_read_actor_base.cpp:153: SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, task: 1. PQ source. SessionId: empty Watermarks enabled: 0 granularity: 0.000000s late arrival delay: 0.000000s idle: 0 idle timeout: 0.000000s
2025-12-12T12:27:23.452186Z :YQL_PROXY TRACE: log.cpp:64: SessionId:  2025-12-12 12:27:23.452 TRACE ydbd(pid=1196126, tid=0x00007F90FCD0D640) [DQ] task_controller_impl.h:160: [1:7582947054380489381:2249] EvState TaskId: 1 State: 2 PingCookie: 0 StatusCode: UNSPECIFIED
2025-12-12T12:27:23.452197Z :YQL_PROXY TRACE: log.cpp:64: SessionId:  2025-12-12 12:27:23.452 TRACE ydbd(pid=1196126, tid=0x00007F90FCD0D640) [DQ] task_controller_impl.h:201:  [1:7582947054380489381:2249] Executing TaskId: 1
2025-12-12T12:27:23.505590Z :STREAMS_STORAGE_SERVICE DEBUG: storage_proxy.cpp:451: [ptqudq7ufj3un8ovpbv9-0] Send TEvGetCheckpointsMetadataResponse
2025-12-12T12:27:23.505662Z :STREAMS_CHECKPOINT_COORDINATOR DEBUG: checkpoint_coordinator.cpp:186: [ptqudq7ufj3un8ovpbv9-0.2] Got TEvGetCheckpointsMetadataResponse
2025-12-12T12:27:23.505674Z :STREAMS_CHECKPOINT_COORDINATOR INFO: checkpoint_coordinator.cpp:219: [ptqudq7ufj3un8ovpbv9-0.2] Will restore from checkpoint 1:2
2025-12-12T12:27:23.505866Z :KQP_COMPUTE DEBUG: dq_compute_actor_checkpoints.cpp:265: [ptqudq7ufj3un8ovpbv9-0] Task: 1. [Checkpoint 1.2] TEvRestoreFromCheckpoint, StateLoadPlan = { StateType: STATE_TYPE_OWN }
2025-12-12T12:27:23.505888Z :STREAMS_STORAGE_SERVICE DEBUG: storage_proxy.cpp:508: [ptqudq7ufj3un8ovpbv9-0] [1:2] Got TEvGetTaskState: tasks {1}
2025-12-12T12:27:23.505893Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:519: [ptqudq7ufj3un8ovpbv9-0] [1:2] GetState, tasks: 1
2025-12-12T12:27:23.581610Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:654: [ptqudq7ufj3un8ovpbv9-0] [1:2] ListOfStates results:
2025-12-12T12:27:23.581630Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:675: [ptqudq7ufj3un8ovpbv9-0] [1:2] taskId 1 checkpoint id: 1:2, rows count: 1
2025-12-12T12:27:23.581633Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:675: [ptqudq7ufj3un8ovpbv9-0] [1:2] taskId 1 checkpoint id: 1:1, rows count: 1
2025-12-12T12:27:23.581640Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:901: [ptqudq7ufj3un8ovpbv9-0] [1:2] SkipStatesInFuture, skip 0 checkpoints
2025-12-12T12:27:23.581697Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:796: [ptqudq7ufj3un8ovpbv9-0] [1:2] SelectState: task_id 1, seq_no 2, blob_seq_num 0
2025-12-12T12:27:23.630255Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:410: [ptqudq7ufj3un8ovpbv9-0] [1:2] DeserializeState, task id 1, blob size 136
2025-12-12T12:27:23.630282Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:960: [ptqudq7ufj3un8ovpbv9-0] [1:2] ApplyIncrements
2025-12-12T12:27:23.630927Z :STREAMS_STORAGE_SERVICE DEBUG: storage_proxy.cpp:527: [ptqudq7ufj3un8ovpbv9-0] [{ Id: 2 Generation: 1 }] Send TEvGetTaskStateResult: tasks: {1}
2025-12-12T12:27:23.630968Z :KQP_COMPUTE DEBUG: dq_compute_actor_checkpoints.cpp:336: [ptqudq7ufj3un8ovpbv9-0] Task: 1. [Checkpoint 1.2] TEvGetTaskStateResult: restoring state
2025-12-12T12:27:23.630973Z :KQP_COMPUTE DEBUG: dq_compute_actor_impl.h:793: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Load state
2025-12-12T12:27:23.630985Z :KQP_COMPUTE DEBUG: dq_pq_read_actor_base.cpp:153: SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, task: 1. PQ source. SessionId: empty Watermarks enabled: 0 granularity: 0.000000s late arrival delay: 0.000000s idle: 0 idle timeout: 0.000000s
2025-12-12T12:27:23.631011Z :KQP_COMPUTE DEBUG: dq_pq_read_actor_base.cpp:133: SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, task: 1. PQ source. SessionId: empty StartingMessageTs 2025-12-12T12:27:01.926000Z Restoring offset: {0@,4},
2025-12-12T12:27:23.631026Z :KQP_COMPUTE DEBUG: dq_compute_actor_checkpoints.cpp:362: [ptqudq7ufj3un8ovpbv9-0] Task: 1. [Checkpoint 1.2] Checkpoint state restored
2025-12-12T12:27:23.631050Z :STREAMS_CHECKPOINT_COORDINATOR DEBUG: checkpoint_coordinator.cpp:297: [ptqudq7ufj3un8ovpbv9-0.2] [1:2] Got TEvRestoreFromCheckpointResult; taskId: 1, checkpoint: 1:2, status: OK, issues: 
2025-12-12T12:27:23.631053Z :STREAMS_CHECKPOINT_COORDINATOR DEBUG: checkpoint_coordinator.cpp:320: [ptqudq7ufj3un8ovpbv9-0.2] [1:2] Task state restored, need 1 more acks
2025-12-12T12:27:24.012480Z :KQP_COMPUTE DEBUG: dq_compute_actor_checkpoints.cpp:197: [] Task: 2. Got TEvNewCheckpointCoordinator event: generation 2, actorId: [1:7582947054380489380:2248]
2025-12-12T12:27:24.012491Z :KQP_COMPUTE TRACE: dq_compute_actor_checkpoints.cpp:208: [] Task: 2. Assign checkpoint coordinator (generation = 2)
2025-12-12T12:27:24.012525Z :KQP_COMPUTE DEBUG: dq_compute_actor_impl.h:1447: SelfId: [1:7582947054380489383:2251], TxId: ptqudq7ufj3un8ovpbv9, task: 2. Ctx: {}. Create sink for output 0 { Sink { Type: "PqSink" Settings { type_url: "type.googleapis.com/NYql.NPq.NProto.TDqPqTopicSink" value: "\n*test_match_recognize[v1-kikimr0]_v1_output\022\017localhost:25827\032\027\n\025cluster:default_myyds\"\005local0\0018\002" } } }
2025-12-12T12:27:24.012592Z :KQP_COMPUTE DEBUG: dq_compute_actor_checkpoints.cpp:265: [ptqudq7ufj3un8ovpbv9-0] Task: 2. [Checkpoint 1.2] TEvRestoreFromCheckpoint, StateLoadPlan = { StateType: STATE_TYPE_OWN }
2025-12-12T12:27:24.012616Z :STREAMS_STORAGE_SERVICE DEBUG: storage_proxy.cpp:508: [ptqudq7ufj3un8ovpbv9-0] [1:2] Got TEvGetTaskState: tasks {2}
2025-12-12T12:27:24.012619Z :YQL_PROXY TRACE: log.cpp:64: SessionId:  2025-12-12 12:27:24.012 TRACE ydbd(pid=1196126, tid=0x00007F90FDD0F640) [DQ] task_controller_impl.h:160: [1:7582947054380489381:2249] EvState TaskId: 2 State: 2 PingCookie: 0 StatusCode: UNSPECIFIED
2025-12-12T12:27:24.012624Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:519: [ptqudq7ufj3un8ovpbv9-0] [1:2] GetState, tasks: 2
2025-12-12T12:27:24.012627Z :YQL_PROXY TRACE: log.cpp:64: SessionId:  2025-12-12 12:27:24.012 TRACE ydbd(pid=1196126, tid=0x00007F90FDD0F640) [DQ] task_controller_impl.h:201:  [1:7582947054380489381:2249] Executing TaskId: 2
2025-12-12T12:27:24.012638Z :YQL_PROXY DEBUG: log.cpp:64: SessionId:  2025-12-12 12:27:24.012 DEBUG ydbd(pid=1196126, tid=0x00007F90FDD0F640) [DQ] task_controller_impl.h:561: Update channels
2025-12-12T12:27:24.012787Z :YQL_PROXY TRACE: log.cpp:64: SessionId:  2025-12-12 12:27:24.012 TRACE ydbd(pid=1196126, tid=0x00007F90FDD0F640) [DQ] task_controller_impl.h:577: 1 Update { Id: 1 TransportVersion: DATA_TRANSPORT_UV_PICKLE_1_0 SrcTaskId: 1 DstTaskId: 2 SrcEndpoint { ActorId { RawX1: 7582947054380489386 RawX2: 4503603922340044 } } DstEndpoint { ActorId { RawX1: 7582947054380489383 RawX2: 4503603922340043 } } WatermarksMode: WATERMARKS_MODE_DISABLED SrcStageId: 214477 DstStageId: 214497 }
2025-12-12T12:27:24.012813Z :YQL_PROXY TRACE: log.cpp:64: SessionId:  2025-12-12 12:27:24.012 TRACE ydbd(pid=1196126, tid=0x00007F90FDD0F640) [DQ] task_controller_impl.h:577: 2 Update { Id: 1 TransportVersion: DATA_TRANSPORT_UV_PICKLE_1_0 SrcTaskId: 1 DstTaskId: 2 SrcEndpoint { ActorId { RawX1: 7582947054380489386 RawX2: 4503603922340044 } } DstEndpoint { ActorId { RawX1: 7582947054380489383 RawX2: 4503603922340043 } } WatermarksMode: WATERMARKS_MODE_DISABLED SrcStageId: 214477 DstStageId: 214497 }
2025-12-12T12:27:24.012828Z :KQP_COMPUTE DEBUG: dq_compute_actor_impl.h:1064: SelfId: [1:7582947054380489383:2251], TxId: ptqudq7ufj3un8ovpbv9, task: 2. Ctx: {}. Received channels info: Update { Id: 1 TransportVersion: DATA_TRANSPORT_UV_PICKLE_1_0 SrcTaskId: 1 DstTaskId: 2 SrcEndpoint { ActorId { RawX1: 7582947054380489386 RawX2: 4503603922340044 } } DstEndpoint { ActorId { RawX1: 7582947054380489383 RawX2: 4503603922340043 } } WatermarksMode: WATERMARKS_MODE_DISABLED SrcStageId: 214477 DstStageId: 214497 }
2025-12-12T12:27:24.012831Z :KQP_COMPUTE DEBUG: dq_compute_actor_impl.h:1071: SelfId: [1:7582947054380489383:2251], TxId: ptqudq7ufj3un8ovpbv9, task: 2. Ctx: {}. Update input channelId: 1, peer: [1:7582947054380489386:2252]
2025-12-12T12:27:24.012850Z :KQP_COMPUTE DEBUG: dq_compute_actor_impl.h:1064: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Received channels info: Update { Id: 1 TransportVersion: DATA_TRANSPORT_UV_PICKLE_1_0 SrcTaskId: 1 DstTaskId: 2 SrcEndpoint { ActorId { RawX1: 7582947054380489386 RawX2: 4503603922340044 } } DstEndpoint { ActorId { RawX1: 7582947054380489383 RawX2: 4503603922340043 } } WatermarksMode: WATERMARKS_MODE_DISABLED SrcStageId: 214477 DstStageId: 214497 }
2025-12-12T12:27:24.012855Z :KQP_COMPUTE DEBUG: dq_compute_actor_impl.h:1083: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Update output channelId: 1, peer: [1:7582947054380489383:2251]
2025-12-12T12:27:24.015393Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:654: [ptqudq7ufj3un8ovpbv9-0] [1:2] ListOfStates results:
2025-12-12T12:27:24.015414Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:675: [ptqudq7ufj3un8ovpbv9-0] [1:2] taskId 2 checkpoint id: 1:2, rows count: 1
2025-12-12T12:27:24.015417Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:675: [ptqudq7ufj3un8ovpbv9-0] [1:2] taskId 2 checkpoint id: 1:1, rows count: 1
2025-12-12T12:27:24.015422Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:901: [ptqudq7ufj3un8ovpbv9-0] [1:2] SkipStatesInFuture, skip 0 checkpoints
2025-12-12T12:27:24.015457Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:796: [ptqudq7ufj3un8ovpbv9-0] [1:2] SelectState: task_id 2, seq_no 2, blob_seq_num 0
2025-12-12T12:27:24.017999Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:410: [ptqudq7ufj3un8ovpbv9-0] [1:2] DeserializeState, task id 2, blob size 260
2025-12-12T12:27:24.018019Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:960: [ptqudq7ufj3un8ovpbv9-0] [1:2] ApplyIncrements
2025-12-12T12:27:24.018046Z :STREAMS_STORAGE_SERVICE DEBUG: storage_proxy.cpp:527: [ptqudq7ufj3un8ovpbv9-0] [{ Id: 2 Generation: 1 }] Send TEvGetTaskStateResult: tasks: {2}
2025-12-12T12:27:24.018090Z :KQP_COMPUTE DEBUG: dq_compute_actor_checkpoints.cpp:336: [ptqudq7ufj3un8ovpbv9-0] Task: 2. [Checkpoint 1.2] TEvGetTaskStateResult: restoring state
2025-12-12T12:27:24.018101Z :KQP_COMPUTE DEBUG: dq_compute_actor_impl.h:793: SelfId: [1:7582947054380489383:2251], TxId: ptqudq7ufj3un8ovpbv9, task: 2. Ctx: {}. Load state
2025-12-12T12:27:24.018241Z :KQP_COMPUTE DEBUG: dq_pq_write_actor.cpp:268: SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, TaskId: 2, PQ sink. Load state: { SourceId: "f3827dbf-645f1af1-c71cdbc2-d3d1bc9b" }
2025-12-12T12:27:24.018250Z :KQP_COMPUTE DEBUG: dq_compute_actor_impl.h:821: SelfId: [1:7582947054380489383:2251], TxId: ptqudq7ufj3un8ovpbv9, task: 2. Ctx: {}. State size: 174
2025-12-12T12:27:24.018279Z :KQP_COMPUTE DEBUG: dq_compute_actor_checkpoints.cpp:362: [ptqudq7ufj3un8ovpbv9-0] Task: 2. [Checkpoint 1.2] Checkpoint state restored
2025-12-12T12:27:24.018293Z :STREAMS_CHECKPOINT_COORDINATOR DEBUG: checkpoint_coordinator.cpp:297: [ptqudq7ufj3un8ovpbv9-0.2] [1:2] Got TEvRestoreFromCheckpointResult; taskId: 2, checkpoint: 1:2, status: OK, issues: 
2025-12-12T12:27:24.018300Z :STREAMS_CHECKPOINT_COORDINATOR DEBUG: checkpoint_coordinator.cpp:320: [ptqudq7ufj3un8ovpbv9-0.2] [1:2] Task state restored, need 0 more acks
2025-12-12T12:27:24.018303Z :STREAMS_CHECKPOINT_COORDINATOR INFO: checkpoint_coordinator.cpp:445: [ptqudq7ufj3un8ovpbv9-0.2] Send TEvRun to all actors
2025-12-12T12:27:24.018316Z :KQP_COMPUTE DEBUG: dq_compute_actor_impl.h:1164: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Got TEvRun from actor [1:7582947054380489380:2248]
2025-12-12T12:27:24.018330Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1483: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Poll inputs
2025-12-12T12:27:24.018332Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1498: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Poll sources
2025-12-12T12:27:24.018337Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:542: SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, task: 1. PQ source. SessionId: empty GetAsyncInputData freeSpace = 1
2025-12-12T12:27:24.018354Z :KQP_COMPUTE DEBUG: dq_pq_read_actor.cpp:648: SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, task: 1. PQ source. SessionId: empty PartitionsToRead: 0
2025-12-12T12:27:24.018377Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:24.018373Z :INFO: [local] [local] [9eab0b4f-69624c9e-112d9715-75e4ec27] Starting read session
2025-12-12T12:27:24.018382Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:24.018380Z :DEBUG: [local] [local] [9eab0b4f-69624c9e-112d9715-75e4ec27] Starting single session
2025-12-12T12:27:24.018408Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:24.018406Z :DEBUG: [local] [local] [9eab0b4f-69624c9e-112d9715-75e4ec27] [] In Reconnect, ReadSizeBudget = 8388608, ReadSizeServerDelta = 0
2025-12-12T12:27:24.018416Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:24.018414Z :DEBUG: [local] [local] [9eab0b4f-69624c9e-112d9715-75e4ec27] [] New values: ReadSizeBudget = 8388608, ReadSizeServerDelta = 0
2025-12-12T12:27:24.018419Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:24.018418Z :DEBUG: [local] [local] [9eab0b4f-69624c9e-112d9715-75e4ec27] [] Reconnecting session to cluster  in 0.000000s
2025-12-12T12:27:24.018438Z :KQP_COMPUTE DEBUG: dq_compute_actor_impl.h:1164: SelfId: [1:7582947054380489383:2251], TxId: ptqudq7ufj3un8ovpbv9, task: 2. Ctx: {}. Got TEvRun from actor [1:7582947054380489380:2248]
2025-12-12T12:27:24.018556Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1483: SelfId: [1:7582947054380489383:2251], TxId: ptqudq7ufj3un8ovpbv9, task: 2. Ctx: {}. Poll inputs
2025-12-12T12:27:24.018570Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1498: SelfId: [1:7582947054380489383:2251], TxId: ptqudq7ufj3un8ovpbv9, task: 2. Ctx: {}. Poll sources
2025-12-12T12:27:24.018572Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:698: SelfId: [1:7582947054380489383:2251], TxId: ptqudq7ufj3un8ovpbv9, task: 2. Ctx: {}. DoExecuteImpl: 0
2025-12-12T12:27:24.018574Z :KQP_COMPUTE INFO: dq_pq_read_actor.cpp:315: SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, task: 1. PQ source. SessionId: 9eab0b4f-69624c9e-112d9715-75e4ec27 CreateReadSession
2025-12-12T12:27:24.018581Z :KQP_COMPUTE TRACE: dq_compute_actor_async_input_helper.h:81: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Poll async input 0. Buffer free space: 1, read from async input: 0 bytes, 0 rows, finished: 0
2025-12-12T12:27:24.018600Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:844: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Send TEvContinueRun on OnAsyncInputPushFinished
2025-12-12T12:27:24.018613Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:24.018599Z :DEBUG: [local] [local] [9eab0b4f-69624c9e-112d9715-75e4ec27] [] Successfully connected. Initializing session
2025-12-12T12:27:24.018703Z :KQP_COMPUTE TRACE: dq_compute_memory_quota.h:97: TxId: ptqudq7ufj3un8ovpbv9, task: 1. Peak memory usage: 2031616
2025-12-12T12:27:24.018715Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:493: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. update task runner stats
2025-12-12T12:27:24.018733Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:762: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Resume execution, run status: PendingInput checkpoint: 0 watermark injected: (empty maybe)
2025-12-12T12:27:24.018741Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:406: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. ProcessOutputsState.Inflight: 0
2025-12-12T12:27:24.018745Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:534: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. About to drain channelId: 1, hasPeer: 1, peerState:(freeSpace:1000000;inFlightBytes:0;inFlightCount:0;)
2025-12-12T12:27:24.018748Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:1107: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Ask CPU quota: 57ms
2025-12-12T12:27:24.018847Z :KQP_COMPUTE TRACE: dq_compute_memory_quota.h:97: TxId: ptqudq7ufj3un8ovpbv9, task: 2. Peak memory usage: 2031616
2025-12-12T12:27:24.018873Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:493: SelfId: [1:7582947054380489383:2251], TxId: ptqudq7ufj3un8ovpbv9, task: 2. Ctx: {}. update task runner stats
2025-12-12T12:27:24.018899Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:762: SelfId: [1:7582947054380489383:2251], TxId: ptqudq7ufj3un8ovpbv9, task: 2. Ctx: {}. Resume execution, run status: PendingInput checkpoint: 0 watermark injected: (empty maybe)
2025-12-12T12:27:24.018906Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:406: SelfId: [1:7582947054380489383:2251], TxId: ptqudq7ufj3un8ovpbv9, task: 2. Ctx: {}. ProcessOutputsState.Inflight: 0
2025-12-12T12:27:24.018910Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:573: SelfId: [1:7582947054380489383:2251], TxId: ptqudq7ufj3un8ovpbv9, task: 2. Ctx: {}. About to drain sink 0. FreeSpace: 16777216, allowedOvercommit: 500000, toSend: 17277216
2025-12-12T12:27:24.018912Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:1107: SelfId: [1:7582947054380489383:2251], TxId: ptqudq7ufj3un8ovpbv9, task: 2. Ctx: {}. Ask CPU quota: 617ms
2025-12-12T12:27:24.018929Z :KQP_COMPUTE TRACE: dq_pq_write_actor.cpp:195: SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, TaskId: 2, PQ sink. SendData. Batch: 0. Checkpoint: 0. Finished: 0
2025-12-12T12:27:24.019030Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:1025: SelfId: [1:7582947054380489383:2251], TxId: ptqudq7ufj3un8ovpbv9, task: 2. Ctx: {}. Sink 0: sent 0 bytes of data and 0 bytes of checkpoint barrier
2025-12-12T12:27:24.019039Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:1029: SelfId: [1:7582947054380489383:2251], TxId: ptqudq7ufj3un8ovpbv9, task: 2. Ctx: {}. Drain sink 0. Free space decreased: 0, sent data from buffer: 0
2025-12-12T12:27:24.019045Z :KQP_COMPUTE TRACE: dq_compute_actor_channels.cpp:605: TxId: ptqudq7ufj3un8ovpbv9, task: 2. no poll, channelId: 1, hasPeer: 1, finished: 0, retry: 0, lastSeqNo: 0, freeSpace: 1000000
2025-12-12T12:27:24.019857Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:1165: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. CPU quota delay: 1ms
2025-12-12T12:27:24.020426Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:1165: SelfId: [1:7582947054380489383:2251], TxId: ptqudq7ufj3un8ovpbv9, task: 2. Ctx: {}. CPU quota delay: 1ms
2025-12-12T12:27:24.023196Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:24.023189Z :INFO: [local] OnFederationDiscovery fall back to single mode, database=local
2025-12-12T12:27:24.023346Z :YDB_SDK INFO: actor.cpp:37: [] [] Start federated write session to database '' (previous was <empty>) FederationState: { Status: SUCCESS SelfLocation: "" DbInfos: [ { path: "local" endpoint: "localhost:25827" status: AVAILABLE weight: 100 } ] ControlPlaneEndpoint: localhost:25827 }
2025-12-12T12:27:24.023399Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:24.023396Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, TaskId: 2, PQ sink. ]  SessionId []  MessageGroupId [f3827dbf-645f1af1-c71cdbc2-d3d1bc9b] Write session: try to update token
2025-12-12T12:27:24.023702Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:24.023699Z :INFO: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, TaskId: 2, PQ sink. ]  SessionId []  MessageGroupId [f3827dbf-645f1af1-c71cdbc2-d3d1bc9b] Start write session. Will connect to nodeId: 0
2025-12-12T12:27:24.024326Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:24.024319Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, TaskId: 2, PQ sink. ]  SessionId []  MessageGroupId [f3827dbf-645f1af1-c71cdbc2-d3d1bc9b] Write session: write to message_group: f3827dbf-645f1af1-c71cdbc2-d3d1bc9b
2025-12-12T12:27:24.024359Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:24.024357Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, TaskId: 2, PQ sink. ]  SessionId []  MessageGroupId [f3827dbf-645f1af1-c71cdbc2-d3d1bc9b] Write session: send init request: init_request { path: "test_match_recognize[v1-kikimr0]_v1_output" producer_id: "f3827dbf-645f1af1-c71cdbc2-d3d1bc9b" message_group_id: "f3827dbf-645f1af1-c71cdbc2-d3d1bc9b" }
2025-12-12T12:27:24.024363Z :YDB_SDK TRACE: actor.cpp:37: 2025-12-12T12:27:24.024361Z :TRACE: [local] TRACE_EVENT InitRequest 
2025-12-12T12:27:24.024450Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:24.024448Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, TaskId: 2, PQ sink. ]  SessionId []  MessageGroupId [f3827dbf-645f1af1-c71cdbc2-d3d1bc9b] Write session: OnWriteDone gRpcStatusCode: 0
2025-12-12T12:27:24.026209Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:24.026202Z :INFO: [local] [local] [9eab0b4f-69624c9e-112d9715-75e4ec27] [] Got InitResponse. ReadSessionId: ptqudq7ufj3un8ovpbv9_1_12_13263724620272791061_v1
2025-12-12T12:27:24.026220Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:24.026218Z :DEBUG: [local] [local] [9eab0b4f-69624c9e-112d9715-75e4ec27] [] In ContinueReadingDataImpl, ReadSizeBudget = 8388608, ReadSizeServerDelta = 0
2025-12-12T12:27:24.026291Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:24.026289Z :DEBUG: [local] [local] [9eab0b4f-69624c9e-112d9715-75e4ec27] [] After sending read request: ReadSizeBudget = 0, ReadSizeServerDelta = 8388608
2025-12-12T12:27:24.029533Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:363: SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, task: 1. PQ source. SessionId: 9eab0b4f-69624c9e-112d9715-75e4ec27 Source data ready
2025-12-12T12:27:24.029563Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1483: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Poll inputs
2025-12-12T12:27:24.029566Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1498: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Poll sources
2025-12-12T12:27:24.029573Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:542: SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, task: 1. PQ source. SessionId: 9eab0b4f-69624c9e-112d9715-75e4ec27 GetAsyncInputData freeSpace = 1000000
2025-12-12T12:27:24.029589Z :KQP_COMPUTE DEBUG: dq_pq_read_actor.cpp:820: SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, task: 1. PQ source. SessionId: 9eab0b4f-69624c9e-112d9715-75e4ec27 Key: 0@ StartPartitionSessionEvent received
2025-12-12T12:27:24.029592Z :KQP_COMPUTE DEBUG: dq_pq_read_actor.cpp:827: SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, task: 1. PQ source. SessionId: 9eab0b4f-69624c9e-112d9715-75e4ec27 Key: 0@ Confirm StartPartitionSession with offset 4
2025-12-12T12:27:24.029604Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:24.029601Z :INFO: [local] [local] [9eab0b4f-69624c9e-112d9715-75e4ec27] [] Confirm partition stream create. Partition stream id: 1. Cluster: "-". Topic: "test_match_recognize[v1-kikimr0]_v1_input". Partition: 0. Read offset: 4
2025-12-12T12:27:24.029704Z :KQP_COMPUTE TRACE: dq_compute_actor_async_input_helper.h:81: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Poll async input 0. Buffer free space: 1000000, read from async input: 0 bytes, 0 rows, finished: 0
2025-12-12T12:27:24.029719Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:363: SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, task: 1. PQ source. SessionId: 9eab0b4f-69624c9e-112d9715-75e4ec27 Source data ready
2025-12-12T12:27:24.029722Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:844: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Send TEvContinueRun on OnAsyncInputPushFinished
2025-12-12T12:27:24.029775Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1483: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Poll inputs
2025-12-12T12:27:24.029776Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1498: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Poll sources
2025-12-12T12:27:24.029780Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:542: SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, task: 1. PQ source. SessionId: 9eab0b4f-69624c9e-112d9715-75e4ec27 GetAsyncInputData freeSpace = 1000000
2025-12-12T12:27:24.029784Z :KQP_COMPUTE TRACE: dq_compute_actor_async_input_helper.h:81: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Poll async input 0. Buffer free space: 1000000, read from async input: 0 bytes, 0 rows, finished: 0
2025-12-12T12:27:24.029788Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:493: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. update task runner stats
2025-12-12T12:27:24.029819Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:762: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Resume execution, run status: PendingInput checkpoint: 0 watermark injected: (empty maybe)
2025-12-12T12:27:24.029821Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:406: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. ProcessOutputsState.Inflight: 0
2025-12-12T12:27:24.029827Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:534: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. About to drain channelId: 1, hasPeer: 1, peerState:(freeSpace:1000000;inFlightBytes:0;inFlightCount:0;)
2025-12-12T12:27:24.029831Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:844: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Send TEvContinueRun on OnAsyncInputPushFinished
2025-12-12T12:27:24.029863Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:493: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. update task runner stats
2025-12-12T12:27:24.029869Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:762: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Resume execution, run status: PendingInput checkpoint: 0 watermark injected: (empty maybe)
2025-12-12T12:27:24.029871Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:406: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. ProcessOutputsState.Inflight: 0
2025-12-12T12:27:24.029874Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:534: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. About to drain channelId: 1, hasPeer: 1, peerState:(freeSpace:1000000;inFlightBytes:0;inFlightCount:0;)
2025-12-12T12:27:24.034443Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:24.034435Z :DEBUG: [local] [local] [9eab0b4f-69624c9e-112d9715-75e4ec27] [] Got ReadResponse, serverBytesSize = 87, now ReadSizeBudget = 0, ReadSizeServerDelta = 8388521
2025-12-12T12:27:24.034473Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:24.034471Z :DEBUG: [local] [local] [9eab0b4f-69624c9e-112d9715-75e4ec27] [] In ContinueReadingDataImpl, ReadSizeBudget = 0, ReadSizeServerDelta = 8388521
2025-12-12T12:27:24.034518Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:24.034516Z :DEBUG: [local] Decompression task done. Partition/PartitionSessionId: 1 (4-4)
2025-12-12T12:27:24.034523Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:24.034522Z :DEBUG: [local] [local] [9eab0b4f-69624c9e-112d9715-75e4ec27] [] Returning serverBytesSize = 87 to budget
2025-12-12T12:27:24.034527Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:24.034525Z :DEBUG: [local] [local] [9eab0b4f-69624c9e-112d9715-75e4ec27] [] In ContinueReadingDataImpl, ReadSizeBudget = 87, ReadSizeServerDelta = 8388521
2025-12-12T12:27:24.034557Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:24.034555Z :DEBUG: [local] [local] [9eab0b4f-69624c9e-112d9715-75e4ec27] [] After sending read request: ReadSizeBudget = 0, ReadSizeServerDelta = 8388608
2025-12-12T12:27:24.035172Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:363: SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, task: 1. PQ source. SessionId: 9eab0b4f-69624c9e-112d9715-75e4ec27 Source data ready
2025-12-12T12:27:24.035200Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1483: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Poll inputs
2025-12-12T12:27:24.035202Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1498: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Poll sources
2025-12-12T12:27:24.035208Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:542: SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, task: 1. PQ source. SessionId: 9eab0b4f-69624c9e-112d9715-75e4ec27 GetAsyncInputData freeSpace = 1000000
2025-12-12T12:27:24.035226Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:24.035223Z :DEBUG: [local] Take Data. Partition 0. Read: {0, 0} (4-4)
2025-12-12T12:27:24.035237Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:24.035235Z :DEBUG: [local] [local] [9eab0b4f-69624c9e-112d9715-75e4ec27] [] The application data is transferred to the client. Number of messages 1, size 37 bytes
2025-12-12T12:27:24.035244Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:24.035242Z :DEBUG: [local] [local] [9eab0b4f-69624c9e-112d9715-75e4ec27] [] Returning serverBytesSize = 0 to budget
2025-12-12T12:27:24.035261Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:761: SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, task: 1. PQ source. SessionId: 9eab0b4f-69624c9e-112d9715-75e4ec27 Key: 0@ Data received: Message { Data: "{"dt": 1696849944100001, "str": "E" }" Information: { Offset: 4 ProducerId: "" SeqNo: 0 CreateTime: 2025-12-12T12:27:08.408000Z WriteTime: 2025-12-12T12:27:08.408000Z MessageGroupId: "" Meta: { } MessageMeta: { } } Partition session id: 1 Topic: "test_match_recognize[v1-kikimr0]_v1_input" Partition: 0 }
2025-12-12T12:27:24.035278Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:737: SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, task: 1. PQ source. SessionId: 9eab0b4f-69624c9e-112d9715-75e4ec27 Return ready batch. DataCount = 1 Watermark = none Used space = 37
2025-12-12T12:27:24.035287Z :KQP_COMPUTE TRACE: dq_compute_actor_async_input_helper.h:81: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Poll async input 0. Buffer free space: 1000000, read from async input: 37 bytes, 1 rows, finished: 0
2025-12-12T12:27:24.035312Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:363: SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, task: 1. PQ source. SessionId: 9eab0b4f-69624c9e-112d9715-75e4ec27 Source data ready
2025-12-12T12:27:24.035315Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:844: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Send TEvContinueRun on OnAsyncInputPushFinished
2025-12-12T12:27:24.035320Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1483: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Poll inputs
2025-12-12T12:27:24.035321Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1498: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Poll sources
2025-12-12T12:27:24.035324Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:542: SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, task: 1. PQ source. SessionId: 9eab0b4f-69624c9e-112d9715-75e4ec27 GetAsyncInputData freeSpace = 999963
2025-12-12T12:27:24.035327Z :KQP_COMPUTE TRACE: dq_compute_actor_async_input_helper.h:81: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Poll async input 0. Buffer free space: 999963, read from async input: 0 bytes, 0 rows, finished: 0
2025-12-12T12:27:24.035488Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:844: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Send TEvContinueRun on OnAsyncInputPushFinished
2025-12-12T12:27:24.035491Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1483: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Poll inputs
2025-12-12T12:27:24.035492Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1498: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Poll sources
2025-12-12T12:27:24.035495Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:542: SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, task: 1. PQ source. SessionId: 9eab0b4f-69624c9e-112d9715-75e4ec27 GetAsyncInputData freeSpace = 999963
2025-12-12T12:27:24.035497Z :KQP_COMPUTE TRACE: dq_compute_actor_async_input_helper.h:81: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Poll async input 0. Buffer free space: 999963, read from async input: 0 bytes, 0 rows, finished: 0
2025-12-12T12:27:24.035501Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:493: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. update task runner stats
2025-12-12T12:27:24.035526Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:762: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Resume execution, run status: PendingInput checkpoint: 0 watermark injected: (empty maybe)
2025-12-12T12:27:24.035528Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:406: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. ProcessOutputsState.Inflight: 0
2025-12-12T12:27:24.035534Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:534: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. About to drain channelId: 1, hasPeer: 1, peerState:(freeSpace:1000000;inFlightBytes:0;inFlightCount:0;)
2025-12-12T12:27:24.035538Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:844: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Send TEvContinueRun on OnAsyncInputPushFinished
2025-12-12T12:27:24.035969Z :KQP_COMPUTE TRACE: dq_compute_actor_channels.cpp:566: TxId: ptqudq7ufj3un8ovpbv9, task: 1. SendChannelData, channelId: 1, peer: [1:7582947054380489383:2251], chunks: 1, bytes: 17, watermark: 0, checkpoint: 0, seqNo: 1, finished: 0
2025-12-12T12:27:24.035984Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:493: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. update task runner stats
2025-12-12T12:27:24.035994Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:762: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Resume execution, run status: PendingInput checkpoint: 0 watermark injected: (empty maybe)
2025-12-12T12:27:24.035996Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:406: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. ProcessOutputsState.Inflight: 0
2025-12-12T12:27:24.035998Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:534: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. About to drain channelId: 1, hasPeer: 1, peerState:(freeSpace:1000000;inFlightBytes:113;inFlightCount:1;)
2025-12-12T12:27:24.036001Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1483: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Poll inputs
2025-12-12T12:27:24.036003Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1498: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Poll sources
2025-12-12T12:27:24.036006Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:542: SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, task: 1. PQ source. SessionId: 9eab0b4f-69624c9e-112d9715-75e4ec27 GetAsyncInputData freeSpace = 1000000
2025-12-12T12:27:24.036009Z :KQP_COMPUTE TRACE: dq_compute_actor_async_input_helper.h:81: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Poll async input 0. Buffer free space: 1000000, read from async input: 0 bytes, 0 rows, finished: 0
2025-12-12T12:27:24.036026Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:844: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Send TEvContinueRun on OnAsyncInputPushFinished
2025-12-12T12:27:24.036030Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:493: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. update task runner stats
2025-12-12T12:27:24.036036Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:762: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Resume execution, run status: PendingInput checkpoint: 0 watermark injected: (empty maybe)
2025-12-12T12:27:24.036037Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:406: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. ProcessOutputsState.Inflight: 0
2025-12-12T12:27:24.036041Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:534: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. About to drain channelId: 1, hasPeer: 1, peerState:(freeSpace:1000000;inFlightBytes:113;inFlightCount:1;)
2025-12-12T12:27:24.036055Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:493: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. update task runner stats
2025-12-12T12:27:24.036061Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:762: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Resume execution, run status: PendingInput checkpoint: 0 watermark injected: (empty maybe)
2025-12-12T12:27:24.036063Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:406: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. ProcessOutputsState.Inflight: 0
2025-12-12T12:27:24.036066Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:534: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. About to drain channelId: 1, hasPeer: 1, peerState:(freeSpace:1000000;inFlightBytes:113;inFlightCount:1;)
2025-12-12T12:27:24.036081Z :KQP_COMPUTE TRACE: dq_compute_actor_channels.cpp:129: TxId: ptqudq7ufj3un8ovpbv9, task: 2. Received input for channelId: 1, seqNo: 1, size: 17, chunks: 1, watermark: 0, checkpoint: 0, finished: 0, from: [1:7582947054380489387:2252], expected seqNo: 1
2025-12-12T12:27:24.036084Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:611: SelfId: [1:7582947054380489383:2251], TxId: ptqudq7ufj3un8ovpbv9, task: 2. Ctx: {}. took input
2025-12-12T12:27:24.036101Z :DQ_TASK_RUNNER TRACE: task_runner_actor_local.cpp:356: SelfId: [1:7582947054380489385:2251], TxId: ptqudq7ufj3un8ovpbv9, task: 2. No watermark 
2025-12-12T12:27:24.036106Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:965: SelfId: [1:7582947054380489383:2251], TxId: ptqudq7ufj3un8ovpbv9, task: 2. Ctx: {}. Input data push finished. Cookie: 0 Watermark: (empty maybe) Ack: 1 TakeInputChannelDataRequests: 1
2025-12-12T12:27:24.036109Z :KQP_COMPUTE TRACE: dq_compute_actor_channels.cpp:738: TxId: ptqudq7ufj3un8ovpbv9, task: 2. Sending channel data ack to channelId: 1, peer: [1:7582947054380489386:2252], from: [1:7582947054380489383:2251], freeSpace: 999983, seqNo: 1, finished: 0
2025-12-12T12:27:24.036121Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1483: SelfId: [1:7582947054380489383:2251], TxId: ptqudq7ufj3un8ovpbv9, task: 2. Ctx: {}. Poll inputs
2025-12-12T12:27:24.036122Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1498: SelfId: [1:7582947054380489383:2251], TxId: ptqudq7ufj3un8ovpbv9, task: 2. Ctx: {}. Poll sources
2025-12-12T12:27:24.036123Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:698: SelfId: [1:7582947054380489383:2251], TxId: ptqudq7ufj3un8ovpbv9, task: 2. Ctx: {}. DoExecuteImpl: 0
2025-12-12T12:27:24.036484Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:493: SelfId: [1:7582947054380489383:2251], TxId: ptqudq7ufj3un8ovpbv9, task: 2. Ctx: {}. update task runner stats
2025-12-12T12:27:24.036502Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:762: SelfId: [1:7582947054380489383:2251], TxId: ptqudq7ufj3un8ovpbv9, task: 2. Ctx: {}. Resume execution, run status: PendingInput checkpoint: 0 watermark injected: (empty maybe)
2025-12-12T12:27:24.036504Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:406: SelfId: [1:7582947054380489383:2251], TxId: ptqudq7ufj3un8ovpbv9, task: 2. Ctx: {}. ProcessOutputsState.Inflight: 0
2025-12-12T12:27:24.036507Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:573: SelfId: [1:7582947054380489383:2251], TxId: ptqudq7ufj3un8ovpbv9, task: 2. Ctx: {}. About to drain sink 0. FreeSpace: 16777216, allowedOvercommit: 500000, toSend: 17277216
2025-12-12T12:27:24.036515Z :KQP_COMPUTE TRACE: dq_pq_write_actor.cpp:195: SelfId: [1:7582947058675456688:2251], TxId: ptqudq7ufj3un8ovpbv9, TaskId: 2, PQ sink. SendData. Batch: 1. Checkpoint: 0. Finished: 0
2025-12-12T12:27:24.036518Z :KQP_COMPUTE TRACE: dq_pq_write_actor.cpp:221: SelfId: [1:7582947058675456688:2251], TxId: ptqudq7ufj3un8ovpbv9, TaskId: 2, PQ sink. Received data for sending: {"a_str":"A","b_str":"B","c_str":"C","dt_begin":1696849942000001,"dt_end":1696849943000001}
2025-12-12T12:27:24.036539Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:1025: SelfId: [1:7582947054380489383:2251], TxId: ptqudq7ufj3un8ovpbv9, task: 2. Ctx: {}. Sink 0: sent 95 bytes of data and 0 bytes of checkpoint barrier
2025-12-12T12:27:24.036541Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:1029: SelfId: [1:7582947054380489383:2251], TxId: ptqudq7ufj3un8ovpbv9, task: 2. Ctx: {}. Drain sink 0. Free space decreased: 91, sent data from buffer: 95
2025-12-12T12:27:24.036546Z :KQP_COMPUTE TRACE: dq_compute_actor_channels.cpp:629: TxId: ptqudq7ufj3un8ovpbv9, task: 2. do poll, channelId: 1, last freeSpace: 999983, current freeSpace: 1000000, seqNo: 1
2025-12-12T12:27:24.036549Z :KQP_COMPUTE TRACE: dq_compute_actor_channels.cpp:639: TxId: ptqudq7ufj3un8ovpbv9, task: 2. Poll input channelId: 1, from: [1:7582947054380489386:2252], seqNo: 1, freeSpace: 1000000
2025-12-12T12:27:24.036552Z :KQP_COMPUTE TRACE: dq_compute_actor_channels.cpp:738: TxId: ptqudq7ufj3un8ovpbv9, task: 2. Sending channel data ack to channelId: 1, peer: [1:7582947054380489386:2252], from: [1:7582947054380489383:2251], freeSpace: 1000000, seqNo: 1, finished: 0
2025-12-12T12:27:24.036561Z :KQP_COMPUTE TRACE: dq_compute_actor_channels.cpp:179: TxId: ptqudq7ufj3un8ovpbv9, task: 1. Received channel data ack for channelId: 1, seqNo: 1, lastSentSeqNo: 1, freeSpace: 999983, early finish: 0
2025-12-12T12:27:24.036566Z :KQP_COMPUTE TRACE: dq_compute_actor_channels.cpp:207: TxId: ptqudq7ufj3un8ovpbv9, task: 1. PeerState, peerState:(freeSpace:999983;inFlightBytes:0;inFlightCount:0;), sentSeqNo: 1, ackSeqNo: 1
2025-12-12T12:27:24.036567Z :KQP_COMPUTE TRACE: dq_compute_actor_channels.cpp:220: TxId: ptqudq7ufj3un8ovpbv9, task: 1. Resume compute actor
2025-12-12T12:27:24.036571Z :KQP_COMPUTE TRACE: dq_compute_actor_channels.cpp:179: TxId: ptqudq7ufj3un8ovpbv9, task: 1. Received channel data ack for channelId: 1, seqNo: 1, lastSentSeqNo: 1, freeSpace: 1000000, early finish: 0
2025-12-12T12:27:24.036574Z :KQP_COMPUTE TRACE: dq_compute_actor_channels.cpp:207: TxId: ptqudq7ufj3un8ovpbv9, task: 1. PeerState, peerState:(freeSpace:1000000;inFlightBytes:0;inFlightCount:0;), sentSeqNo: 1, ackSeqNo: 1
2025-12-12T12:27:24.036575Z :KQP_COMPUTE TRACE: dq_compute_actor_channels.cpp:220: TxId: ptqudq7ufj3un8ovpbv9, task: 1. Resume compute actor
2025-12-12T12:27:24.036578Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1483: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Poll inputs
2025-12-12T12:27:24.036579Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1498: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Poll sources
2025-12-12T12:27:24.036583Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:542: SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, task: 1. PQ source. SessionId: 9eab0b4f-69624c9e-112d9715-75e4ec27 GetAsyncInputData freeSpace = 1000000
2025-12-12T12:27:24.036586Z :KQP_COMPUTE TRACE: dq_compute_actor_async_input_helper.h:81: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Poll async input 0. Buffer free space: 1000000, read from async input: 0 bytes, 0 rows, finished: 0
2025-12-12T12:27:24.036591Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:844: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Send TEvContinueRun on OnAsyncInputPushFinished
2025-12-12T12:27:24.036612Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:493: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. update task runner stats
2025-12-12T12:27:24.036623Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:762: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Resume execution, run status: PendingInput checkpoint: 0 watermark injected: (empty maybe)
2025-12-12T12:27:24.036624Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:406: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. ProcessOutputsState.Inflight: 0
2025-12-12T12:27:24.036628Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:534: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. About to drain channelId: 1, hasPeer: 1, peerState:(freeSpace:1000000;inFlightBytes:0;inFlightCount:0;)
2025-12-12T12:27:24.044284Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:24.044276Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, TaskId: 2, PQ sink. ]  SessionId []  MessageGroupId [f3827dbf-645f1af1-c71cdbc2-d3d1bc9b] Write session: OnReadDone gRpcStatusCode: 0
2025-12-12T12:27:24.044307Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:24.044304Z :INFO: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, TaskId: 2, PQ sink. ]  SessionId []  MessageGroupId [f3827dbf-645f1af1-c71cdbc2-d3d1bc9b] Counters: { Errors: 0 CurrentSessionLifetimeMs: 1765542444044 BytesWritten: 0 MessagesWritten: 0 BytesWrittenCompressed: 0 BytesInflightUncompressed: 0 BytesInflightCompressed: 0 BytesInflightTotal: 0 MessagesInflight: 0 }
2025-12-12T12:27:24.044326Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:24.044324Z :INFO: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, TaskId: 2, PQ sink. ]  SessionId []  MessageGroupId [f3827dbf-645f1af1-c71cdbc2-d3d1bc9b] Write session established. Init response: session_id: "f3827dbf-645f1af1-c71cdbc2-d3d1bc9b|61e53ea9-e07eaf45-eb26711b-5a166363_0"
2025-12-12T12:27:24.044333Z :YDB_SDK TRACE: actor.cpp:37: 2025-12-12T12:27:24.044330Z :TRACE: [local] TRACE_EVENT InitResponse  partition_id=0 session_id=f3827dbf-645f1af1-c71cdbc2-d3d1bc9b|61e53ea9-e07eaf45-eb26711b-5a166363_0
2025-12-12T12:27:24.044338Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:24.044336Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, TaskId: 2, PQ sink. ]  SessionId [f3827dbf-645f1af1-c71cdbc2-d3d1bc9b|61e53ea9-e07eaf45-eb26711b-5a166363_0]  MessageGroupId [f3827dbf-645f1af1-c71cdbc2-d3d1bc9b] Write session: set DirectWriteToPartitionId 0
2025-12-12T12:27:24.044398Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:24.044395Z :INFO: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, TaskId: 2, PQ sink. ]  SessionId [f3827dbf-645f1af1-c71cdbc2-d3d1bc9b|61e53ea9-e07eaf45-eb26711b-5a166363_0]  PartitionId [0]  Generation [0] Get partition location async, partition 0, delay 0.000000s
2025-12-12T12:27:24.044412Z :YDB_SDK TRACE: actor.cpp:37: 2025-12-12T12:27:24.044410Z :TRACE: [local] TRACE_EVENT DescribePartitionRequest  path=local/test_match_recognize[v1-kikimr0]_v1_output partition_id=0
2025-12-12T12:27:24.044478Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:24.044475Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, TaskId: 2, PQ sink. ]  SessionId [f3827dbf-645f1af1-c71cdbc2-d3d1bc9b|61e53ea9-e07eaf45-eb26711b-5a166363_0]  PartitionId [0]  Generation [0]  Getting partition location, partition 0
2025-12-12T12:27:24.053276Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:24.053266Z :INFO: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, TaskId: 2, PQ sink. ]  SessionId [f3827dbf-645f1af1-c71cdbc2-d3d1bc9b|61e53ea9-e07eaf45-eb26711b-5a166363_0]  PartitionId [0]  Generation [0] Got PartitionLocation response. Status SUCCESS, proto:
partition {
  active: true
  partition_location {
    node_id: 1
    generation: 1
  }
}

2025-12-12T12:27:24.053301Z :YDB_SDK TRACE: actor.cpp:37: 2025-12-12T12:27:24.053288Z :TRACE: [local] TRACE_EVENT DescribePartitionResponse  partition_id=0 active=1 pl_node_id=1 pl_generation=1
2025-12-12T12:27:24.053308Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:24.053306Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, TaskId: 2, PQ sink. ]  SessionId [f3827dbf-645f1af1-c71cdbc2-d3d1bc9b|61e53ea9-e07eaf45-eb26711b-5a166363_0]  PartitionId [0]  Generation [0] GetPreferredEndpoint: partitionId 0, partitionNodeId 1 exists in the endpoint pool.
2025-12-12T12:27:24.053314Z :YDB_SDK TRACE: actor.cpp:37: 2025-12-12T12:27:24.053312Z :TRACE: [local] TRACE_EVENT PreferredPartitionLocation  Endpoint= NodeId=1 Generation=1
2025-12-12T12:27:24.053320Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:24.053316Z :INFO: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, TaskId: 2, PQ sink. ]  SessionId [f3827dbf-645f1af1-c71cdbc2-d3d1bc9b|61e53ea9-e07eaf45-eb26711b-5a166363_0]  PartitionId [0]  Generation [1] Start write session. Will connect to nodeId: 1
2025-12-12T12:27:24.054008Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:24.054003Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, TaskId: 2, PQ sink. ]  SessionId [f3827dbf-645f1af1-c71cdbc2-d3d1bc9b|61e53ea9-e07eaf45-eb26711b-5a166363_0]  PartitionId [0]  Generation [1] Write session: direct write to partition: 0, generation 1
2025-12-12T12:27:24.054036Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:24.054035Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, TaskId: 2, PQ sink. ]  SessionId [f3827dbf-645f1af1-c71cdbc2-d3d1bc9b|61e53ea9-e07eaf45-eb26711b-5a166363_0]  PartitionId [0]  Generation [1] Write session: send init request: init_request { path: "test_match_recognize[v1-kikimr0]_v1_output" producer_id: "f3827dbf-645f1af1-c71cdbc2-d3d1bc9b" partition_with_generation { generation: 1 } }
2025-12-12T12:27:24.054040Z :YDB_SDK TRACE: actor.cpp:37: 2025-12-12T12:27:24.054038Z :TRACE: [local] TRACE_EVENT InitRequest  pwg_partition_id=0 pwg_generation=1
2025-12-12T12:27:24.054116Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:24.054115Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, TaskId: 2, PQ sink. ]  SessionId [f3827dbf-645f1af1-c71cdbc2-d3d1bc9b|61e53ea9-e07eaf45-eb26711b-5a166363_0]  PartitionId [0]  Generation [1] Write session: OnReadDone gRpcStatusCode: 1, Msg: CANCELLED, Details: , InternalError: 0
2025-12-12T12:27:24.054173Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:24.054171Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, TaskId: 2, PQ sink. ]  SessionId [f3827dbf-645f1af1-c71cdbc2-d3d1bc9b|61e53ea9-e07eaf45-eb26711b-5a166363_0]  PartitionId [0]  Generation [1] Write session: OnWriteDone gRpcStatusCode: 0
2025-12-12T12:27:24.069209Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:24.069200Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, TaskId: 2, PQ sink. ]  SessionId [f3827dbf-645f1af1-c71cdbc2-d3d1bc9b|61e53ea9-e07eaf45-eb26711b-5a166363_0]  PartitionId [0]  Generation [1] Write session: OnReadDone gRpcStatusCode: 0
2025-12-12T12:27:24.069238Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:24.069235Z :INFO: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, TaskId: 2, PQ sink. ]  SessionId [f3827dbf-645f1af1-c71cdbc2-d3d1bc9b|61e53ea9-e07eaf45-eb26711b-5a166363_0]  PartitionId [0]  Generation [1] Write session established. Init response: session_id: "f3827dbf-645f1af1-c71cdbc2-d3d1bc9b|14cfb307-b9a23113-c5d002d9-20ab0e3_0"
2025-12-12T12:27:24.069244Z :YDB_SDK TRACE: actor.cpp:37: 2025-12-12T12:27:24.069242Z :TRACE: [local] TRACE_EVENT InitResponse  partition_id=0 session_id=f3827dbf-645f1af1-c71cdbc2-d3d1bc9b|14cfb307-b9a23113-c5d002d9-20ab0e3_0
2025-12-12T12:27:24.069248Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:24.069246Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, TaskId: 2, PQ sink. ]  SessionId [f3827dbf-645f1af1-c71cdbc2-d3d1bc9b|14cfb307-b9a23113-c5d002d9-20ab0e3_0]  PartitionId [0]  Generation [1] Write session: set DirectWriteToPartitionId 0
2025-12-12T12:27:24.071133Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:24.071114Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, TaskId: 2, PQ sink. ]  SessionId [f3827dbf-645f1af1-c71cdbc2-d3d1bc9b|14cfb307-b9a23113-c5d002d9-20ab0e3_0]  PartitionId [0]  Generation [1] Write 1 messages with Id from 1 to 1
2025-12-12T12:27:24.071162Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:24.071160Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, TaskId: 2, PQ sink. ]  SessionId [f3827dbf-645f1af1-c71cdbc2-d3d1bc9b|14cfb307-b9a23113-c5d002d9-20ab0e3_0]  PartitionId [0]  Generation [1] Write session: try to update token
2025-12-12T12:27:24.071167Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:24.071165Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, TaskId: 2, PQ sink. ]  SessionId [f3827dbf-645f1af1-c71cdbc2-d3d1bc9b|14cfb307-b9a23113-c5d002d9-20ab0e3_0]  PartitionId [0]  Generation [1] Send 1 message(s) (0 left), first sequence number is 1
2025-12-12T12:27:24.073372Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:24.073366Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, TaskId: 2, PQ sink. ]  SessionId [f3827dbf-645f1af1-c71cdbc2-d3d1bc9b|14cfb307-b9a23113-c5d002d9-20ab0e3_0]  PartitionId [0]  Generation [1] Write session: OnReadDone gRpcStatusCode: 0
2025-12-12T12:27:24.073413Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:24.073409Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, TaskId: 2, PQ sink. ]  SessionId [f3827dbf-645f1af1-c71cdbc2-d3d1bc9b|14cfb307-b9a23113-c5d002d9-20ab0e3_0]  PartitionId [0]  Generation [1] Write session got write response: acks { seq_no: 1 written { } } write_statistics { persisting_time { nanos: 1000000 } min_queue_wait_time { } max_queue_wait_time { } partition_quota_wait_time { } topic_quota_wait_time { } }
2025-12-12T12:27:24.073418Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:24.073416Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, TaskId: 2, PQ sink. ]  SessionId [f3827dbf-645f1af1-c71cdbc2-d3d1bc9b|14cfb307-b9a23113-c5d002d9-20ab0e3_0]  PartitionId [0]  Generation [1] OnAck: seqNo=1, txId=?
2025-12-12T12:27:24.073421Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:24.073420Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, TaskId: 2, PQ sink. ]  SessionId [f3827dbf-645f1af1-c71cdbc2-d3d1bc9b|14cfb307-b9a23113-c5d002d9-20ab0e3_0]  PartitionId [0]  Generation [1] Write session: acknoledged message 1
2025-12-12T12:27:24.073530Z :KQP_COMPUTE TRACE: dq_pq_write_actor.cpp:454: SelfId: [1:7582947058675456688:2251], TxId: ptqudq7ufj3un8ovpbv9, TaskId: 2, PQ sink. Ack seq no 1
2025-12-12T12:27:24.335751Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 6ca58679-69617f0a-85bc5868-8fd3dbeb19, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:24.351079Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:24.351090Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:24.396231Z :YQL_PROXY TRACE: log.cpp:64: SessionId:  2025-12-12 12:27:24.396 TRACE ydbd(pid=1196126, tid=0x00007F90FDD0F640) [DQ] task_controller_impl.h:271:  [1:7582947054380489381:2249] ExportStats Summary
2025-12-12T12:27:24.396496Z :FQ_PINGER TRACE: pinger.cpp:250: QueryId: ptqudq7ufj3un8ovpbv9, Owner: 6ca58679-69617f0a-85bc5868-8fd3dbeb17 Forward ping request: { statistics: "{\"Graph=0\":{\"TaskRunner\":{\"Stage=214477\":{\"CpuTimeUs\":{\"sum\":\"0.00s\",\"count\":1,\"avg\":\"0.00s\",\"max\":\"0.00s\",\"min\":\"0.00s\"},\"Tasks\":{\"sum\":1,\"count\":1,\"avg\":1,\"max\":1,\"min\":1}},\"Stage=214497\":{\"CpuTimeUs\":{\"sum\":\"0.00s\",\"count\":1,\"avg\":\"0.00s\",\"max\":\"0.00s\",\"min\":\"0.00s\"},\"Tasks\":{\"sum\":1,\"count\":1,\"avg\":1,\"max\":1,\"min\":1}},\"Stage=Total\":{\"CpuTimeUs\":{\"sum\":\"0.00s\",\"count\":2,\"avg\":\"0.00s\",\"max\":\"0.00s\",\"min\":\"0.00s\"},\"Tasks\":{\"sum\":2,\"count\":2,\"avg\":1,\"max\":1,\"min\":1}}}}}" }
2025-12-12T12:27:24.396503Z :FQ_PINGER TRACE: pinger.cpp:393: QueryId: ptqudq7ufj3un8ovpbv9, Owner: 6ca58679-69617f0a-85bc5868-8fd3dbeb17 Forward request Private::PingTask
2025-12-12T12:27:24.409856Z :FQ_PINGER TRACE: pinger.cpp:338: QueryId: ptqudq7ufj3un8ovpbv9, Owner: 6ca58679-69617f0a-85bc5868-8fd3dbeb17 Ping response success: { action: ABORT expired_at { seconds: 1765542464 nanos: 403000000 } }
2025-12-12T12:27:24.409871Z :FQ_PINGER DEBUG: pinger.cpp:342: QueryId: ptqudq7ufj3un8ovpbv9, Owner: 6ca58679-69617f0a-85bc5868-8fd3dbeb17 Query action: ABORT
2025-12-12T12:27:24.409918Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:690: QueryId: ptqudq7ufj3un8ovpbv9 New query action received: ABORT
2025-12-12T12:27:24.409922Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:1827: QueryId: ptqudq7ufj3un8ovpbv9 Is about to finish query with status ABORTED_BY_USER
2025-12-12T12:27:24.409925Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:1820: QueryId: ptqudq7ufj3un8ovpbv9 Write finalizing status: ABORTING_BY_USER
2025-12-12T12:27:24.409948Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:528: QueryId: ptqudq7ufj3un8ovpbv9 Cancel running query
2025-12-12T12:27:24.409962Z :FQ_RUN_ACTOR TRACE: run_actor.cpp:880: QueryId: ptqudq7ufj3un8ovpbv9 Forward ping response. Success: 1. Cookie: 6
2025-12-12T12:27:24.409987Z :FQ_PINGER TRACE: pinger.cpp:250: QueryId: ptqudq7ufj3un8ovpbv9, Owner: 6ca58679-69617f0a-85bc5868-8fd3dbeb17 Forward ping request: { status: ABORTING_BY_USER }
2025-12-12T12:27:24.409995Z :FQ_PINGER TRACE: pinger.cpp:393: QueryId: ptqudq7ufj3un8ovpbv9, Owner: 6ca58679-69617f0a-85bc5868-8fd3dbeb17 Forward request Private::PingTask
2025-12-12T12:27:24.410141Z :YQL_PROXY DEBUG: log.cpp:64: SessionId:  2025-12-12 12:27:24.409 DEBUG ydbd(pid=1196126, tid=0x00007F90FBD0B640) [DQ] task_controller_impl.h:130: AbortExecution from [1:7582947054380489377:2245]:ABORTED { <main>: Error: ABORTED_BY_USER }
2025-12-12T12:27:24.410156Z :YQL_PROXY DEBUG: log.cpp:64: SessionId:  2025-12-12 12:27:24.410 DEBUG ydbd(pid=1196126, tid=0x00007F90FBD0B640) [DQ] task_controller_impl.h:598: OnError { <main>: Error: ABORTED_BY_USER } ABORTED
2025-12-12T12:27:24.410246Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: ptqudq7ufj3un8ovpbv9 2025-12-12 12:27:24.410 DEBUG ydbd(pid=1196126, tid=0x00007F90FDD0F640) [DQ] executer_actor.cpp:304: {ptqudq7ufj3un8ovpbv9} OnFailure, status=4, issues size=1, sender=[1:7582947054380489381:2249]
2025-12-12T12:27:24.410276Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: ptqudq7ufj3un8ovpbv9 2025-12-12 12:27:24.410 DEBUG ydbd(pid=1196126, tid=0x00007F90FDD0F640) [DQ] executer_actor.cpp:315: {ptqudq7ufj3un8ovpbv9} Issues: <main>: Error: ABORTED_BY_USER

2025-12-12T12:27:24.410284Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: ptqudq7ufj3un8ovpbv9 2025-12-12 12:27:24.410 DEBUG ydbd(pid=1196126, tid=0x00007F90FDD0F640) [DQ] executer_actor.cpp:284: {ptqudq7ufj3un8ovpbv9} Finish with status=4 issues=<main>: Error: ABORTED_BY_USER

2025-12-12T12:27:24.410352Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: ptqudq7ufj3un8ovpbv9 2025-12-12 12:27:24.410 DEBUG ydbd(pid=1196126, tid=0x00007F90FDD0F640) [DQ] executer_actor.cpp:341: {ptqudq7ufj3un8ovpbv9} OnQueryResponse status=4 issuses_size=1
2025-12-12T12:27:24.410374Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:1396: QueryId: ptqudq7ufj3un8ovpbv9 TEvQueryResponse received on finish
2025-12-12T12:27:24.410380Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:1233: QueryId: ptqudq7ufj3un8ovpbv9 Query response CANCELLED. Result set index: 0. Issues count: 1. Rows count: 0
2025-12-12T12:27:24.410494Z :KQP_COMPUTE ERROR: dq_compute_actor_impl.h:1205: SelfId: [1:7582947054380489386:2252], TxId: ptqudq7ufj3un8ovpbv9, task: 1. Ctx: {}. Handle abort execution event from: [1:7582946985661012430:2066], status: UNAVAILABLE, reason: { <main>: Error: Aborted by LWM }
2025-12-12T12:27:24.410529Z :KQP_COMPUTE ERROR: dq_compute_actor_impl.h:1205: SelfId: [1:7582947054380489383:2251], TxId: ptqudq7ufj3un8ovpbv9, task: 2. Ctx: {}. Handle abort execution event from: [1:7582946985661012430:2066], status: UNAVAILABLE, reason: { <main>: Error: Aborted by LWM }
2025-12-12T12:27:24.410538Z :KQP_COMPUTE DEBUG: dq_compute_actor_channels.cpp:494: TxId: ptqudq7ufj3un8ovpbv9, task: 1. pass away
2025-12-12T12:27:24.410555Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:24.410551Z :INFO: [local] [local] [9eab0b4f-69624c9e-112d9715-75e4ec27] Closing read session. Close timeout: 0.000000s
2025-12-12T12:27:24.410557Z :KQP_COMPUTE DEBUG: dq_compute_actor_channels.cpp:494: TxId: ptqudq7ufj3un8ovpbv9, task: 2. pass away
2025-12-12T12:27:24.410564Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:24.410562Z :INFO: [local] Read/commit by partition streams (cluster:topic:partition:stream-id:read-offset:committed-offset): -:test_match_recognize[v1-kikimr0]_v1_input:0:1:4:4
2025-12-12T12:27:24.410566Z :STREAMS_CHECKPOINT_COORDINATOR DEBUG: checkpoint_coordinator.cpp:657: [ptqudq7ufj3un8ovpbv9-0.2] PassAway
2025-12-12T12:27:24.410571Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:24.410570Z :INFO: [local] [local] [9eab0b4f-69624c9e-112d9715-75e4ec27] Counters: { Errors: 0 CurrentSessionLifetimeMs: 392 BytesRead: 37 MessagesRead: 1 BytesReadCompressed: 37 BytesInflightUncompressed: 0 BytesInflightCompressed: 0 BytesInflightTotal: 0 MessagesInflight: 0 }
2025-12-12T12:27:24.410583Z :YDB_SDK NOTICE: actor.cpp:37: 2025-12-12T12:27:24.410581Z :NOTICE: [local] [local] [9eab0b4f-69624c9e-112d9715-75e4ec27] Aborting read session. Description: SessionClosed { Status: ABORTED Issues: "<main>: Error: Close with zero timeout " }
2025-12-12T12:27:24.410590Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:24.410588Z :DEBUG: [local] [local] [9eab0b4f-69624c9e-112d9715-75e4ec27] [] Abort session to cluster
2025-12-12T12:27:24.410712Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:24.410710Z :INFO: [local] [local] [9eab0b4f-69624c9e-112d9715-75e4ec27] Closing read session. Close timeout: 0.000000s
2025-12-12T12:27:24.410716Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:24.410714Z :INFO: [local] Read/commit by partition streams (cluster:topic:partition:stream-id:read-offset:committed-offset): -:test_match_recognize[v1-kikimr0]_v1_input:0:1:4:4
2025-12-12T12:27:24.410720Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:24.410718Z :INFO: [local] [local] [9eab0b4f-69624c9e-112d9715-75e4ec27] Counters: { Errors: 0 CurrentSessionLifetimeMs: 392 BytesRead: 37 MessagesRead: 1 BytesReadCompressed: 37 BytesInflightUncompressed: 0 BytesInflightCompressed: 0 BytesInflightTotal: 0 MessagesInflight: 0 }
2025-12-12T12:27:24.410726Z :YDB_SDK NOTICE: actor.cpp:37: 2025-12-12T12:27:24.410724Z :NOTICE: [local] [local] [9eab0b4f-69624c9e-112d9715-75e4ec27] Aborting read session. Description: SessionClosed { Status: ABORTED Issues: "<main>: Error: Aborted " }
2025-12-12T12:27:24.416878Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:24.416871Z :INFO: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, TaskId: 2, PQ sink. ]  SessionId [f3827dbf-645f1af1-c71cdbc2-d3d1bc9b|14cfb307-b9a23113-c5d002d9-20ab0e3_0]  PartitionId [0]  Generation [1] Write session: close. Timeout 0.000000s
2025-12-12T12:27:24.416899Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:24.416897Z :INFO: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, TaskId: 2, PQ sink. ]  SessionId [f3827dbf-645f1af1-c71cdbc2-d3d1bc9b|14cfb307-b9a23113-c5d002d9-20ab0e3_0]  PartitionId [0]  Generation [1] Write session will now close
2025-12-12T12:27:24.416914Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:24.416913Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, TaskId: 2, PQ sink. ]  SessionId [f3827dbf-645f1af1-c71cdbc2-d3d1bc9b|14cfb307-b9a23113-c5d002d9-20ab0e3_0]  PartitionId [0]  Generation [1] Write session: aborting
2025-12-12T12:27:24.417061Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:24.417058Z :INFO: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, TaskId: 2, PQ sink. ]  SessionId [f3827dbf-645f1af1-c71cdbc2-d3d1bc9b|14cfb307-b9a23113-c5d002d9-20ab0e3_0]  PartitionId [0]  Generation [1] Write session: gracefully shut down, all writes complete
2025-12-12T12:27:24.417066Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:24.417065Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7ufj3un8ovpbv9, TaskId: 2, PQ sink. ]  SessionId [f3827dbf-645f1af1-c71cdbc2-d3d1bc9b|14cfb307-b9a23113-c5d002d9-20ab0e3_0]  PartitionId [0]  Generation [1] Write session: destroy
2025-12-12T12:27:24.430447Z :FQ_PINGER TRACE: pinger.cpp:338: QueryId: ptqudq7ufj3un8ovpbv9, Owner: 6ca58679-69617f0a-85bc5868-8fd3dbeb17 Ping response success: { action: ABORT expired_at { seconds: 1765542464 nanos: 419000000 } }
2025-12-12T12:27:24.430469Z :FQ_PINGER DEBUG: pinger.cpp:342: QueryId: ptqudq7ufj3un8ovpbv9, Owner: 6ca58679-69617f0a-85bc5868-8fd3dbeb17 Query action: ABORT
2025-12-12T12:27:24.430504Z :FQ_RUN_ACTOR TRACE: run_actor.cpp:880: QueryId: ptqudq7ufj3un8ovpbv9 Forward ping response. Success: 1. Cookie: 3
2025-12-12T12:27:24.430508Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:887: QueryId: ptqudq7ufj3un8ovpbv9 Finalizing status is saved
2025-12-12T12:27:24.430552Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:1507: QueryId: ptqudq7ufj3un8ovpbv9 Start rate limiter resource deleter
2025-12-12T12:27:24.430574Z :STREAMS DEBUG: read_rule_deleter.cpp:214: ptqudq7ufj3un8ovpbv9: Create read rule deleter actor for `test_match_recognize[v1-kikimr0]_v1_input` [0]
2025-12-12T12:27:24.430603Z :STREAMS DEBUG: read_rule_deleter.cpp:106: ptqudq7ufj3un8ovpbv9: Make request for read rule deletion for topic `test_match_recognize[v1-kikimr0]_v1_input` [0]
2025-12-12T12:27:24.474354Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:1498: QueryId: ptqudq7ufj3un8ovpbv9 Rate limiter resource deletion finished. Success: 1. Issues: 
2025-12-12T12:27:24.474367Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:1919: QueryId: ptqudq7ufj3un8ovpbv9 SendPingAndPassAway, FinalQueryStatus ABORTED_BY_USER
2025-12-12T12:27:24.474392Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:536: QueryId: ptqudq7ufj3un8ovpbv9 PassAway
2025-12-12T12:27:24.474496Z :FQ_PINGER TRACE: pinger.cpp:250: QueryId: ptqudq7ufj3un8ovpbv9, Owner: 6ca58679-69617f0a-85bc5868-8fd3dbeb17 Forward ping request: { result_id { value: "ptrudq7uet7plgdf9k5a" } status: ABORTED_BY_USER issues { message: "ABORTED_BY_USER" severity: 1 } statistics: "{\"Graph=0\":{\"Actor\":{\"ActorCreateTimeUs\":{\"sum\":\"68ms\",\"count\":2,\"avg\":\"34ms\",\"max\":\"34ms\",\"min\":\"34ms\"}},\"AllocateWorkersUs\":{\"sum\":\"35ms\",\"count\":1,\"avg\":\"35ms\",\"max\":\"35ms\",\"min\":\"35ms\"},\"ExecutionTimeUs\":{\"sum\":\"1.01s\",\"count\":1,\"avg\":\"1.01s\",\"max\":\"1.01s\",\"min\":\"1.01s\"},\"TaskRunner\":{\"Stage=214477\":{\"CpuTimeUs\":{\"sum\":\"0.00s\",\"count\":1,\"avg\":\"0.00s\",\"max\":\"0.00s\",\"min\":\"0.00s\"},\"Tasks\":{\"sum\":1,\"count\":1,\"avg\":1,\"max\":1,\"min\":1}},\"Stage=214497\":{\"CpuTimeUs\":{\"sum\":\"0.00s\",\"count\":1,\"avg\":\"0.00s\",\"max\":\"0.00s\",\"min\":\"0.00s\"},\"Tasks\":{\"sum\":1,\"count\":1,\"avg\":1,\"max\":1,\"min\":1}},\"Stage=Total\":{\"CpuTimeUs\":{\"sum\":\"0.00s\",\"count\":2,\"avg\":\"0.00s\",\"max\":\"0.00s\",\"min\":\"0.00s\"},\"Tasks\":{\"sum\":2,\"count\":2,\"avg\":1,\"max\":1,\"min\":1}}},\"UniqueWorkers\":{\"sum\":1,\"count\":1,\"avg\":1,\"max\":1,\"min\":1}}}" resources { rate_limiter: READY compilation: READY topic_consumers_state: READY rate_limiter_path: "local/RateLimiter_5958a75f-5918-4b93-a01c-15191f6a0817/rate_limiter" topic_consumers { database: "local" topic_path: "test_match_recognize[v1-kikimr0]_v1_input" consumer_name: "ptqudq7ufj3un8ovpbv9" cluster_endpoint: "localhost:25827" token_name: "cluster:default_myyds" add_bearer_to_token: true } } finished_at { seconds: 1765542444 nanos: 409000000 } }
2025-12-12T12:27:24.474524Z :FQ_PINGER TRACE: pinger.cpp:393: QueryId: ptqudq7ufj3un8ovpbv9, Owner: 6ca58679-69617f0a-85bc5868-8fd3dbeb17 Forward request Private::PingTask
2025-12-12T12:27:24.587883Z :FQ_PINGER TRACE: pinger.cpp:338: QueryId: ptqudq7ufj3un8ovpbv9, Owner: 6ca58679-69617f0a-85bc5868-8fd3dbeb17 Ping response success: { action: ABORT }
2025-12-12T12:27:24.587920Z :FQ_PINGER DEBUG: pinger.cpp:379: QueryId: ptqudq7ufj3un8ovpbv9, Owner: 6ca58679-69617f0a-85bc5868-8fd3dbeb17 Query finished
2025-12-12T12:27:24.587924Z :FQ_PINGER TRACE: pinger.cpp:187: QueryId: ptqudq7ufj3un8ovpbv9, Owner: 6ca58679-69617f0a-85bc5868-8fd3dbeb17 Stop Pinger
2025-12-12T12:27:25.329001Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:627: RowDispatcher: Send ping to [1:7582946985661012477:2096]
2025-12-12T12:27:25.329033Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1174: RowDispatcher: TEvPrivate::TEvSendStatistic
2025-12-12T12:27:25.329043Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [1:7582946985661012429:2065]
2025-12-12T12:27:25.329047Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7582946985661012429:2065]
2025-12-12T12:27:25.329050Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [1:7582946985661012429:2065]
2025-12-12T12:27:25.329059Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:633: RowDispatcher: NActors::TEvents::TEvPong
2025-12-12T12:27:25.336175Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 6ca58679-69617f0a-85bc5868-8fd3dbeb20, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:25.351250Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:25.351275Z :FQ_PENDING_FETCHER ERROR: pending_fetcher.cpp:259: Error with GetTask: <main>: Error: GRpc error: (14): connections to all backends failing; last error: UNKNOWN: ipv4:127.0.1.1:7555: Failed to connect to remote host: Connection refused
<main>: Error: Grpc error response on endpoint ghrun-fhkyrtz6p4.auto.internal:7555
2025-12-12T12:27:26.336627Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 6ca58679-69617f0a-85bc5868-8fd3dbeb21, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:26.342668Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:26.342695Z :FQ_PENDING_FETCHER ERROR: pending_fetcher.cpp:259: Error with GetTask: <main>: Error: GRpc error: (14): connections to all backends failing; last error: UNKNOWN: ipv4:127.0.1.1:7555: Failed to connect to remote host: Connection refused
<main>: Error: Grpc error response on endpoint ghrun-fhkyrtz6p4.auto.internal:7555
2025-12-12T12:27:27.329919Z :YQL_NODES_MANAGER TRACE: nodes_manager.cpp:318: TNodesManagerActor::NodesHealthCheck
2025-12-12T12:27:27.330228Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:627: RowDispatcher: Send ping to [1:7582946985661012477:2096]
2025-12-12T12:27:27.330239Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1174: RowDispatcher: TEvPrivate::TEvSendStatistic
2025-12-12T12:27:27.330247Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [1:7582946985661012429:2065]
2025-12-12T12:27:27.330250Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7582946985661012429:2065]
2025-12-12T12:27:27.330254Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [1:7582946985661012429:2065]
2025-12-12T12:27:27.330260Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:633: RowDispatcher: NActors::TEvents::TEvPong
2025-12-12T12:27:27.335396Z :YQL_NODES_MANAGER ERROR: nodes_manager.cpp:395: ydb/core/fq/libs/actors/nodes_manager.cpp:353: TRANSPORT_UNAVAILABLE
<main>: Error: GRpc error: (14): connections to all backends failing; last error: UNKNOWN: ipv4:127.0.1.1:7555: Failed to connect to remote host: Connection refused
<main>: Error: Grpc error response on endpoint ghrun-fhkyrtz6p4.auto.internal:7555
2025-12-12T12:27:27.337116Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 6ca58679-69617f0a-85bc5868-8fd3dbeb22, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:27.350523Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:27.350549Z :FQ_PENDING_FETCHER ERROR: pending_fetcher.cpp:259: Error with GetTask: <main>: Error: GRpc error: (14): connections to all backends failing; last error: UNKNOWN: ipv4:127.0.1.1:7555: Failed to connect to remote host: Connection refused
<main>: Error: Grpc error response on endpoint ghrun-fhkyrtz6p4.auto.internal:7555
