2025-12-09T03:43:38.871176Z :YQ_TEST_CONNECTION DEBUG: test_connection.cpp:142: Starting yandex query test connection. Actor id: [1:7581698830330991235:2070]
2025-12-09T03:43:38.871424Z :GRPC_SERVER NOTICE: grpc_request_proxy.cpp:380: Grpc request proxy started, nodeid# 1, serve as static node
2025-12-09T03:43:38.871479Z :GRPC_SERVER CRIT: grpc_request_proxy.cpp:440: Failed to deliver subscription request to config dispatcher
2025-12-09T03:43:38.871483Z :GRPC_SERVER NOTICE: grpc_request_proxy.cpp:380: Grpc request proxy started, nodeid# 1, serve as static node
2025-12-09T03:43:38.871501Z :GRPC_SERVER CRIT: grpc_request_proxy.cpp:440: Failed to deliver subscription request to config dispatcher
2025-12-09T03:43:38.871606Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: e89fdf35-d81f0194-91266a8b-851ce03f1, Host: ghrun-syjwtgwtdu, Tenant: /compute
2025-12-09T03:43:38.871730Z :YQ_RATE_LIMITER INFO: quoter_service.cpp:124: Bootstraping with config: { Enabled: true DataPlaneEnabled: true Database { Endpoint: "localhost:8635" Database: "local" TablePrefix: "RateLimiter_d0f7bd1b-d9e2-40b6-853d-4861bfa7c5a2" } Limiters { CoordinationNodePath: "rate_limiter" } }
2025-12-09T03:43:38.872124Z :FQ_QUOTA_PROXY INFO: quota_proxy.cpp:90: STARTED
2025-12-09T03:43:38.872156Z :FQ_LOG_UPDATER DEBUG: log.cpp:93: Updated YQL logs priority: 8
2025-12-09T03:43:38.872161Z :FQ_LOG_UPDATER CRIT: log.cpp:55: Failed to deliver subscription request to config dispatcher.
2025-12-09T03:43:38.872187Z :STREAMS_STORAGE_SERVICE INFO: storage_proxy.cpp:214: Bootstrap
2025-12-09T03:43:38.872189Z :STREAMS_STORAGE_SERVICE INFO: storage_proxy.cpp:217: Create sdk ydb connection
2025-12-09T03:43:38.872213Z :FQ_ROW_DISPATCHER DEBUG: row_dispatcher.cpp:544: RowDispatcher: Successfully bootstrapped row dispatcher, id [1:7581698830330991230:2065], tenant /compute
2025-12-09T03:43:38.872219Z :STREAMS_STORAGE_SERVICE INFO: storage_proxy.cpp:239: Successfully bootstrapped TStorageProxy [1:7581698830330991229:2064] with connection to localhost:8635:local
2025-12-09T03:43:38.872230Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7581698830330991230:2065]
2025-12-09T03:43:38.872232Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:329: Coordinator: Add new row dispatcher to map (state 1)
2025-12-09T03:43:38.872324Z :YQL_NODES_MANAGER INFO: nodes_manager.cpp:88: Bootstrap, InstanceId: 209bb6e0-4ad8b8b3-50ad61b7-dbc97a90
2025-12-09T03:43:38.872326Z :YQL_NODES_MANAGER DEBUG: nodes_manager.cpp:310: TNodesManagerActor::ResolveSelfAddress
2025-12-09T03:43:38.872394Z :FQ_ROW_DISPATCHER DEBUG: coordinator.cpp:293: Coordinator: Successfully bootstrapped coordinator, id [1:7581698830330991268:2086], NodesManagerId [0:4705493345362661702:78], rebalancing timeout 5.000000s
2025-12-09T03:43:38.872421Z :FQ_ROW_DISPATCHER DEBUG: leader_election.cpp:232: TLeaderElection [1:7581698830330991269:2087] Successfully bootstrapped, local coordinator id [1:7581698830330991268:2086], tenant id compute, local mode 0, coordination node path local/compute, endpoint localhost:8635
2025-12-09T03:43:38.872900Z :MEMORY_PROFILER NOTICE: monitor.cpp:332: Bootstrapped
2025-12-09T03:43:38.872953Z :FQ_ROW_DISPATCHER DEBUG: row_dispatcher.cpp:637: RowDispatcher: TEvCoordinatorChangesSubscribe from [1:7581698830330991268:2086]
2025-12-09T03:43:38.872992Z :SCHEME_BOARD_SUBSCRIBER NOTICE: subscriber.cpp:849: [main][1:7581698830330991250:2080][/Root] Set up state: owner# [1:7581698830330991207:2052], state# { Deleted: 1 Strong: 0 Version: <Invalid> DomainId: <Invalid> AbandonedSchemeShards: there are 0 elements }
2025-12-09T03:43:38.873003Z :SCHEME_BOARD_SUBSCRIBER NOTICE: subscriber.cpp:849: [main][1:7581698830330991251:2081][/compute] Set up state: owner# [1:7581698830330991207:2052], state# { Deleted: 1 Strong: 0 Version: <Invalid> DomainId: <Invalid> AbandonedSchemeShards: there are 0 elements }
2025-12-09T03:43:38.873008Z :GRPC_SERVER WARN: grpc_request_proxy.cpp:583: SchemeBoardDelete /Root Strong=0
2025-12-09T03:43:38.873010Z :GRPC_SERVER WARN: grpc_request_proxy.cpp:583: SchemeBoardDelete /compute Strong=0
2025-12-09T03:43:38.873280Z :FQ_QUOTA_SERVICE INFO: quota_manager.cpp:196: STARTED
2025-12-09T03:43:38.873291Z :SCHEME_BOARD_SUBSCRIBER NOTICE: subscriber.cpp:849: [main][1:7581698830330991253:2083][/compute] Set up state: owner# [1:7581698830330991208:2053], state# { Deleted: 1 Strong: 0 Version: <Invalid> DomainId: <Invalid> AbandonedSchemeShards: there are 0 elements }
2025-12-09T03:43:38.873303Z :GRPC_SERVER WARN: grpc_request_proxy.cpp:583: SchemeBoardDelete /compute Strong=0
2025-12-09T03:43:38.873347Z :SCHEME_BOARD_SUBSCRIBER NOTICE: subscriber.cpp:849: [main][1:7581698830330991252:2082][/Root] Set up state: owner# [1:7581698830330991208:2053], state# { Deleted: 1 Strong: 0 Version: <Invalid> DomainId: <Invalid> AbandonedSchemeShards: there are 0 elements }
2025-12-09T03:43:38.873356Z :GRPC_SERVER WARN: grpc_request_proxy.cpp:583: SchemeBoardDelete /Root Strong=0
2025-12-09T03:43:38.873884Z :YQL_NODES_MANAGER TRACE: nodes_manager.cpp:318: TNodesManagerActor::NodesHealthCheck
2025-12-09T03:43:38.874718Z :FQ_ROW_DISPATCHER DEBUG: schema.cpp:71: Run create coordination node "local/compute" actor
2025-12-09T03:43:38.874727Z :FQ_ROW_DISPATCHER DEBUG: schema.cpp:113: Call create coordination node "local/compute"
2025-12-09T03:43:38.874729Z :FQ_ROW_DISPATCHER DEBUG: schema.cpp:411: Call create coordination node "local/compute"
2025-12-09T03:43:38.883965Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-09T03:43:38.883978Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-09T03:43:38.885734Z :YQL_NODES_MANAGER TRACE: nodes_manager.cpp:389: Send NodeInfo with size: 0 to DynamicNameserver
2025-12-09T03:43:38.894477Z :FQ_ROW_DISPATCHER DEBUG: schema.cpp:155: Successfully created coordination node "local/compute"
2025-12-09T03:43:38.894500Z :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-09T03:43:38.894520Z :FQ_ROW_DISPATCHER DEBUG: leader_election.cpp:345: TLeaderElection [1:7581698830330991269:2087] Coordination node successfully created
2025-12-09T03:43:38.894523Z :FQ_ROW_DISPATCHER DEBUG: leader_election.cpp:323: TLeaderElection [1:7581698830330991269:2087] Start session
2025-12-09T03:43:38.896270Z :FQ_ROW_DISPATCHER DEBUG: leader_election.cpp:359: TLeaderElection [1:7581698830330991269:2087] Session successfully created
2025-12-09T03:43:38.900357Z :FQ_ROW_DISPATCHER DEBUG: leader_election.cpp:372: TLeaderElection [1:7581698830330991269:2087] Semaphore successfully created
2025-12-09T03:43:38.900368Z :FQ_ROW_DISPATCHER DEBUG: leader_election.cpp:304: TLeaderElection [1:7581698830330991269:2087] Try to acquire semaphore
2025-12-09T03:43:38.900493Z :FQ_ROW_DISPATCHER DEBUG: leader_election.cpp:420: TLeaderElection [1:7581698830330991269:2087] Describe semaphore
2025-12-09T03:43:38.902449Z :FQ_ROW_DISPATCHER DEBUG: leader_election.cpp:386: TLeaderElection [1:7581698830330991269:2087] Semaphore successfully acquired
2025-12-09T03:43:38.902562Z :FQ_ROW_DISPATCHER DEBUG: leader_election.cpp:469: TLeaderElection [1:7581698830330991269:2087] Semaphore successfully described: coordinator id [1:7581698830330991268:2086] generation 6
2025-12-09T03:43:38.902570Z :FQ_ROW_DISPATCHER INFO: leader_election.cpp:471: TLeaderElection [1:7581698830330991269:2087] Send TEvCoordinatorChanged to [1:7581698830330991230:2065], new coordinator id [1:7581698830330991268:2086], previous coordinator id [0:0:0]
2025-12-09T03:43:38.902596Z :FQ_ROW_DISPATCHER DEBUG: row_dispatcher.cpp:569: RowDispatcher: Coordinator changed, old leader (empty maybe), new [1:7581698830330991268:2086] generation 6
2025-12-09T03:43:38.902613Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [1:7581698830330991230:2065]
2025-12-09T03:43:38.902617Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7581698830330991230:2065]
2025-12-09T03:43:38.902620Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [1:7581698830330991230:2065]
2025-12-09T03:43:38.902631Z :FQ_ROW_DISPATCHER DEBUG: coordinator.cpp:440: Coordinator: New leader [1:7581698830330991268:2086], SelfId [1:7581698830330991268:2086]
2025-12-09T03:43:38.902634Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:633: RowDispatcher: NActors::TEvents::TEvPong
2025-12-09T03:43:39.869719Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: e89fdf35-d81f0194-91266a8b-851ce03f2, Host: ghrun-syjwtgwtdu, Tenant: /compute
2025-12-09T03:43:39.875366Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-09T03:43:39.875386Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-09T03:43:40.870170Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:627: RowDispatcher: Send ping to [1:7581698830330991268:2086]
2025-12-09T03:43:40.870188Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1174: RowDispatcher: TEvPrivate::TEvSendStatistic
2025-12-09T03:43:40.870202Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: e89fdf35-d81f0194-91266a8b-851ce03f3, Host: ghrun-syjwtgwtdu, Tenant: /compute
2025-12-09T03:43:40.870226Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [1:7581698830330991230:2065]
2025-12-09T03:43:40.870229Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7581698830330991230:2065]
2025-12-09T03:43:40.870231Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [1:7581698830330991230:2065]
2025-12-09T03:43:40.870540Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:633: RowDispatcher: NActors::TEvents::TEvPong
2025-12-09T03:43:40.874455Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-09T03:43:40.874469Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-09T03:43:41.870622Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: e89fdf35-d81f0194-91266a8b-851ce03f4, Host: ghrun-syjwtgwtdu, Tenant: /compute
2025-12-09T03:43:41.874442Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-09T03:43:41.874453Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-09T03:43:42.871028Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:627: RowDispatcher: Send ping to [1:7581698830330991268:2086]
2025-12-09T03:43:42.871038Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: e89fdf35-d81f0194-91266a8b-851ce03f5, Host: ghrun-syjwtgwtdu, Tenant: /compute
2025-12-09T03:43:42.871049Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1174: RowDispatcher: TEvPrivate::TEvSendStatistic
2025-12-09T03:43:42.871076Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [1:7581698830330991230:2065]
2025-12-09T03:43:42.871080Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7581698830330991230:2065]
2025-12-09T03:43:42.871085Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [1:7581698830330991230:2065]
2025-12-09T03:43:42.871091Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:633: RowDispatcher: NActors::TEvents::TEvPong
2025-12-09T03:43:42.874892Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-09T03:43:42.874903Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-09T03:43:43.869448Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:665: Coordinator: Change global state to Started (by timeout)
2025-12-09T03:43:43.869449Z :YQL_NODES_MANAGER TRACE: nodes_manager.cpp:318: TNodesManagerActor::NodesHealthCheck
2025-12-09T03:43:43.871480Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: e89fdf35-d81f0194-91266a8b-851ce03f6, Host: ghrun-syjwtgwtdu, Tenant: /compute
2025-12-09T03:43:43.874339Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-09T03:43:43.874349Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-09T03:43:43.877889Z :YQL_NODES_MANAGER TRACE: nodes_manager.cpp:389: Send NodeInfo with size: 0 to DynamicNameserver
2025-12-09T03:43:44.871905Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:627: RowDispatcher: Send ping to [1:7581698830330991268:2086]
2025-12-09T03:43:44.871912Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: e89fdf35-d81f0194-91266a8b-851ce03f7, Host: ghrun-syjwtgwtdu, Tenant: /compute
2025-12-09T03:43:44.871923Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1174: RowDispatcher: TEvPrivate::TEvSendStatistic
2025-12-09T03:43:44.871933Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [1:7581698830330991230:2065]
2025-12-09T03:43:44.871939Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7581698830330991230:2065]
2025-12-09T03:43:44.871941Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [1:7581698830330991230:2065]
2025-12-09T03:43:44.871958Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:633: RowDispatcher: NActors::TEvents::TEvPong
2025-12-09T03:43:44.875580Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-09T03:43:44.875595Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-09T03:43:45.872407Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: e89fdf35-d81f0194-91266a8b-851ce03f8, Host: ghrun-syjwtgwtdu, Tenant: /compute
2025-12-09T03:43:45.876933Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-09T03:43:45.876947Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-09T03:43:46.872848Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:627: RowDispatcher: Send ping to [1:7581698830330991268:2086]
2025-12-09T03:43:46.872859Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: e89fdf35-d81f0194-91266a8b-851ce03f9, Host: ghrun-syjwtgwtdu, Tenant: /compute
2025-12-09T03:43:46.872868Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1174: RowDispatcher: TEvPrivate::TEvSendStatistic
2025-12-09T03:43:46.872878Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [1:7581698830330991230:2065]
2025-12-09T03:43:46.872882Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7581698830330991230:2065]
2025-12-09T03:43:46.872885Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [1:7581698830330991230:2065]
2025-12-09T03:43:46.872903Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:633: RowDispatcher: NActors::TEvents::TEvPong
2025-12-09T03:43:46.876897Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-09T03:43:46.876919Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-09T03:43:47.873851Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: e89fdf35-d81f0194-91266a8b-851ce03f10, Host: ghrun-syjwtgwtdu, Tenant: /compute
2025-12-09T03:43:47.878158Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-09T03:43:47.878177Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-09T03:43:48.869642Z :FQ_ROW_DISPATCHER DEBUG: coordinator.cpp:599: Coordinator: Send TEvGetNodesRequest to NodesManager
2025-12-09T03:43:48.869648Z :YQL_NODES_MANAGER TRACE: nodes_manager.cpp:318: TNodesManagerActor::NodesHealthCheck
2025-12-09T03:43:48.869927Z :YQL_NODES_MANAGER TRACE: nodes_manager.cpp:300: Received TNodesManagerActor::TEvGetNodesRequest
2025-12-09T03:43:48.869949Z :FQ_ROW_DISPATCHER INFO: coordinator.cpp:690: Coordinator: Updated node info, node count: 1
2025-12-09T03:43:48.873717Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:627: RowDispatcher: Send ping to [1:7581698830330991268:2086]
2025-12-09T03:43:48.873735Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1174: RowDispatcher: TEvPrivate::TEvSendStatistic
2025-12-09T03:43:48.873752Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [1:7581698830330991230:2065]
2025-12-09T03:43:48.873757Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7581698830330991230:2065]
2025-12-09T03:43:48.873759Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [1:7581698830330991230:2065]
2025-12-09T03:43:48.873773Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:633: RowDispatcher: NActors::TEvents::TEvPong
2025-12-09T03:43:48.874780Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: e89fdf35-d81f0194-91266a8b-851ce03f11, Host: ghrun-syjwtgwtdu, Tenant: /compute
2025-12-09T03:43:48.877770Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-09T03:43:48.877781Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-09T03:43:48.877799Z :YQL_NODES_MANAGER TRACE: nodes_manager.cpp:389: Send NodeInfo with size: 0 to DynamicNameserver
2025-12-09T03:43:49.875194Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: e89fdf35-d81f0194-91266a8b-851ce03f12, Host: ghrun-syjwtgwtdu, Tenant: /compute
2025-12-09T03:43:49.878855Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-09T03:43:49.878872Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-09T03:43:50.874626Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:627: RowDispatcher: Send ping to [1:7581698830330991268:2086]
2025-12-09T03:43:50.874648Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1174: RowDispatcher: TEvPrivate::TEvSendStatistic
2025-12-09T03:43:50.874656Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [1:7581698830330991230:2065]
2025-12-09T03:43:50.874661Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7581698830330991230:2065]
2025-12-09T03:43:50.874664Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [1:7581698830330991230:2065]
2025-12-09T03:43:50.874673Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:633: RowDispatcher: NActors::TEvents::TEvPong
2025-12-09T03:43:50.875646Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: e89fdf35-d81f0194-91266a8b-851ce03f13, Host: ghrun-syjwtgwtdu, Tenant: /compute
2025-12-09T03:43:50.879509Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-09T03:43:50.879521Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-09T03:43:51.876117Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: e89fdf35-d81f0194-91266a8b-851ce03f14, Host: ghrun-syjwtgwtdu, Tenant: /compute
2025-12-09T03:43:51.879960Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-09T03:43:51.879973Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-09T03:43:52.875537Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:627: RowDispatcher: Send ping to [1:7581698830330991268:2086]
2025-12-09T03:43:52.875560Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1174: RowDispatcher: TEvPrivate::TEvSendStatistic
2025-12-09T03:43:52.875568Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [1:7581698830330991230:2065]
2025-12-09T03:43:52.875574Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7581698830330991230:2065]
2025-12-09T03:43:52.875577Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [1:7581698830330991230:2065]
2025-12-09T03:43:52.875586Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:633: RowDispatcher: NActors::TEvents::TEvPong
2025-12-09T03:43:52.876506Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: e89fdf35-d81f0194-91266a8b-851ce03f15, Host: ghrun-syjwtgwtdu, Tenant: /compute
2025-12-09T03:43:52.880389Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-09T03:43:52.880407Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-09T03:43:53.869826Z :YQL_NODES_MANAGER TRACE: nodes_manager.cpp:318: TNodesManagerActor::NodesHealthCheck
2025-12-09T03:43:53.876979Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: e89fdf35-d81f0194-91266a8b-851ce03f16, Host: ghrun-syjwtgwtdu, Tenant: /compute
2025-12-09T03:43:53.878319Z :YQL_NODES_MANAGER TRACE: nodes_manager.cpp:389: Send NodeInfo with size: 0 to DynamicNameserver
2025-12-09T03:43:53.879822Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-09T03:43:53.879832Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-09T03:43:54.876379Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:627: RowDispatcher: Send ping to [1:7581698830330991268:2086]
2025-12-09T03:43:54.876401Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1174: RowDispatcher: TEvPrivate::TEvSendStatistic
2025-12-09T03:43:54.876408Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [1:7581698830330991230:2065]
2025-12-09T03:43:54.876411Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7581698830330991230:2065]
2025-12-09T03:43:54.876413Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [1:7581698830330991230:2065]
2025-12-09T03:43:54.876422Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:633: RowDispatcher: NActors::TEvents::TEvPong
2025-12-09T03:43:54.877440Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: e89fdf35-d81f0194-91266a8b-851ce03f17, Host: ghrun-syjwtgwtdu, Tenant: /compute
2025-12-09T03:43:54.880975Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-09T03:43:54.880987Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-09T03:43:55.877883Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: e89fdf35-d81f0194-91266a8b-851ce03f18, Host: ghrun-syjwtgwtdu, Tenant: /compute
2025-12-09T03:43:55.881450Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-09T03:43:55.881459Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-09T03:43:56.877311Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:627: RowDispatcher: Send ping to [1:7581698830330991268:2086]
2025-12-09T03:43:56.877337Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1174: RowDispatcher: TEvPrivate::TEvSendStatistic
2025-12-09T03:43:56.877344Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [1:7581698830330991230:2065]
2025-12-09T03:43:56.877348Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7581698830330991230:2065]
2025-12-09T03:43:56.877351Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [1:7581698830330991230:2065]
2025-12-09T03:43:56.877360Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:633: RowDispatcher: NActors::TEvents::TEvPong
2025-12-09T03:43:56.878304Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: e89fdf35-d81f0194-91266a8b-851ce03f19, Host: ghrun-syjwtgwtdu, Tenant: /compute
2025-12-09T03:43:56.881512Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-09T03:43:56.881526Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-09T03:43:57.878789Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: e89fdf35-d81f0194-91266a8b-851ce03f20, Host: ghrun-syjwtgwtdu, Tenant: /compute
2025-12-09T03:43:57.888828Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-09T03:43:57.888842Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 1
2025-12-09T03:43:57.889084Z :FQ_PENDING_FETCHER DEBUG: pending_fetcher.cpp:361: NewTask: Scope: yandexcloud://my_folder Id: ptqudqgd4a50qp2jttl4 UserId: root@builtin AuthToken: **** (B6C6F477)
2025-12-09T03:43:57.889265Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: e89fdf35-d81f0194-91266a8b-851ce03f21, Host: ghrun-syjwtgwtdu, Tenant: /compute
2025-12-09T03:43:57.889274Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:375: QueryId: ptqudqgd4a50qp2jttl4 Start run actor. Compute state: RUNNING
2025-12-09T03:43:57.889278Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:469: QueryId: ptqudqgd4a50qp2jttl4 FillConnections
2025-12-09T03:43:57.889323Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:2333: QueryId: ptqudqgd4a50qp2jttl4 Run actors params: { QueryId: ptqudqgd4a50qp2jttl4 CloudId: mock_cloud UserId: root@builtin Owner: e89fdf35-d81f0194-91266a8b-851ce03f20 PreviousQueryRevision: 2 Connections: 1 Bindings: 0 AccountIdSignatures: 0 QueryType: STREAMING ExecuteMode: RUN ResultId: ptrudqgd3k6tcj3e80r4 StateLoadMode: FROM_LAST_CHECKPOINT StreamingDisposition: { from_last_checkpoint { } } Status: RUNNING DqGraphs: 1 DqGraphIndex: 0 Resource.TopicConsumers: 1 }
2025-12-09T03:43:57.889363Z :FQ_PINGER TRACE: pinger.cpp:171: QueryId: ptqudqgd4a50qp2jttl4, Owner: e89fdf35-d81f0194-91266a8b-851ce03f20 Start Pinger
2025-12-09T03:43:57.889405Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:911: QueryId: ptqudqgd4a50qp2jttl4 Overall dq tasks: 2
2025-12-09T03:43:57.889530Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:1598: QueryId: ptqudqgd4a50qp2jttl4 ResultWriter was NOT CREATED since ResultType is empty
2025-12-09T03:43:57.889553Z :FQ_PINGER TRACE: pinger.cpp:250: QueryId: ptqudqgd4a50qp2jttl4, Owner: e89fdf35-d81f0194-91266a8b-851ce03f20 Forward ping request: { resources { rate_limiter: READY compilation: READY topic_consumers_state: READY rate_limiter_path: "local/RateLimiter_d0f7bd1b-d9e2-40b6-853d-4861bfa7c5a2/rate_limiter" topic_consumers { database: "local" topic_path: "test_match_recognize[v1-kikimr0]_v1_input" consumer_name: "ptqudqgd4a50qp2jttl4" cluster_endpoint: "localhost:8635" token_name: "cluster:default_myyds" add_bearer_to_token: true } } }
2025-12-09T03:43:57.889560Z :FQ_PINGER TRACE: pinger.cpp:393: QueryId: ptqudqgd4a50qp2jttl4, Owner: e89fdf35-d81f0194-91266a8b-851ce03f20 Forward request Private::PingTask
2025-12-09T03:43:57.889600Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: ptqudqgd4a50qp2jttl4 2025-12-09 03:43:57.889 DEBUG ydbd(pid=1646206, tid=0x00007F1C1F1FC640) [DQ] task_controller_impl.h:86: _RowsLimitPerWrite = 0
2025-12-09T03:43:57.889648Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:1652: QueryId: ptqudqgd4a50qp2jttl4 Executer: [1:7581698911935370100:2279], Controller: [1:7581698911935370102:2281], ResultIdActor: [1:7581698911935370100:2279]
2025-12-09T03:43:57.889706Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: ptqudqgd4a50qp2jttl4 2025-12-09 03:43:57.889 DEBUG ydbd(pid=1646206, tid=0x00007F1C201FE640) [DQ] executer_actor.cpp:140: {ptqudqgd4a50qp2jttl4} TDqExecuter::OnGraph
2025-12-09T03:43:57.889734Z :YQL_PROXY INFO: log.cpp:64: SessionId: ptqudqgd4a50qp2jttl4 2025-12-09 03:43:57.889 INFO  ydbd(pid=1646206, tid=0x00007F1C201FE640) [DQ] executer_actor.cpp:157: {ptqudqgd4a50qp2jttl4} Trying to allocate 2 workers [EnableComputeActor=1]
2025-12-09T03:43:57.890820Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: ptqudqgd4a50qp2jttl4 2025-12-09 03:43:57.890 DEBUG ydbd(pid=1646206, tid=0x00007F1C201FE640) [DQ] executer_actor.cpp:247: {ptqudqgd4a50qp2jttl4} Dq timeouts are set to: 0.000000s (global), 600.000000s (workers allocation fail), 30.000000s (workers allocation warn) 
2025-12-09T03:43:57.891532Z :YQL_NODES_MANAGER DEBUG: nodes_manager.cpp:125: TEvAllocateWorkersResponse Nodes {
  ResourceId: 4294967297
  Worker {
    NodeId: 1
    Guid: "209bb6e0-4ad8b8b3-50ad61b7-dbc97a90,ghrun-syjwtgwtdu"
  }
  Worker {
    NodeId: 1
    Guid: "209bb6e0-4ad8b8b3-50ad61b7-dbc97a90,ghrun-syjwtgwtdu"
  }
}
2025-12-09T03:43:57.891674Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: e89fdf35-d81f0194-91266a8b-851ce03f 2025-12-09 03:43:57.891 DEBUG ydbd(pid=1646206, tid=0x00007F1C1F1FC640) [DQ] local_worker_manager.cpp:316: {ptqudqgd4a50qp2jttl4} TLocalWorkerManager::TEvAllocateWorkersRequest 562954248388609
2025-12-09T03:43:57.891703Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: e89fdf35-d81f0194-91266a8b-851ce03f 2025-12-09 03:43:57.891 DEBUG ydbd(pid=1646206, tid=0x00007F1C1F1FC640) [DQ] local_worker_manager.cpp:376: {ptqudqgd4a50qp2jttl4} Create compute actor: async
2025-12-09T03:43:57.891716Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-09T03:43:57.891723Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-09T03:43:57.898913Z :FQ_PINGER TRACE: pinger.cpp:338: QueryId: ptqudqgd4a50qp2jttl4, Owner: e89fdf35-d81f0194-91266a8b-851ce03f20 Ping response success: { expired_at { seconds: 1765251857 nanos: 893000000 } }
2025-12-09T03:43:57.898944Z :FQ_RUN_ACTOR TRACE: run_actor.cpp:861: QueryId: ptqudqgd4a50qp2jttl4 Forward ping response. Success: 1. Cookie: 0
2025-12-09T03:43:57.917659Z :KQP_COMPUTE DEBUG: dq_compute_actor_impl.h:144: SelfId: [1:7581698911935370104:2283], TxId: ptqudqgd4a50qp2jttl4, task: 2. Ctx: {}. Start compute actor [1:7581698911935370104:2283], task: 2
2025-12-09T03:43:57.917680Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: e89fdf35-d81f0194-91266a8b-851ce03f 2025-12-09 03:43:57.917 DEBUG ydbd(pid=1646206, tid=0x00007F1C1F1FC640) [DQ] local_worker_manager.cpp:316: {ptqudqgd4a50qp2jttl4} TLocalWorkerManager::TEvAllocateWorkersRequest 281479271677953
2025-12-09T03:43:57.917693Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: e89fdf35-d81f0194-91266a8b-851ce03f 2025-12-09 03:43:57.917 DEBUG ydbd(pid=1646206, tid=0x00007F1C1F1FC640) [DQ] local_worker_manager.cpp:376: {ptqudqgd4a50qp2jttl4} Create compute actor: async
2025-12-09T03:43:57.917701Z :KQP_COMPUTE DEBUG: dq_async_compute_actor.cpp:114: SelfId: [1:7581698911935370104:2283], TxId: ptqudqgd4a50qp2jttl4, task: 2. Ctx: {}. Use CPU quota: 1. Rate limiter resource: { "local/RateLimiter_d0f7bd1b-d9e2-40b6-853d-4861bfa7c5a2/rate_limiter", "mock_cloud/my_folder/ptqudqgd4a50qp2jttl4" }
2025-12-09T03:43:57.917761Z :KQP_COMPUTE DEBUG: dq_compute_actor_impl.h:144: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Start compute actor [1:7581698911935370107:2284], task: 1
2025-12-09T03:43:57.917781Z :KQP_COMPUTE DEBUG: dq_async_compute_actor.cpp:114: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Use CPU quota: 1. Rate limiter resource: { "local/RateLimiter_d0f7bd1b-d9e2-40b6-853d-4861bfa7c5a2/rate_limiter", "mock_cloud/my_folder/ptqudqgd4a50qp2jttl4" }
2025-12-09T03:43:57.917822Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: e89fdf35-d81f0194-91266a8b-851ce03f 2025-12-09 03:43:57.917 DEBUG ydbd(pid=1646206, tid=0x00007F1C1F1FC640) [DQ] tasks_runner_local.cpp:267: {TODO/1} Build task: 1
2025-12-09T03:43:57.917833Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: ptqudqgd4a50qp2jttl4 2025-12-09 03:43:57.917 DEBUG ydbd(pid=1646206, tid=0x00007F1C201FE640) [DQ] executer_actor.cpp:358: {ptqudqgd4a50qp2jttl4} TDqExecuter::TEvAllocateWorkersResponse
2025-12-09T03:43:57.917844Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: ptqudqgd4a50qp2jttl4 2025-12-09 03:43:57.917 DEBUG ydbd(pid=1646206, tid=0x00007F1C201FE640) [DQ] executer_actor.cpp:384: {ptqudqgd4a50qp2jttl4} Allocated resource 4294967297
2025-12-09T03:43:57.917891Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: ptqudqgd4a50qp2jttl4 2025-12-09 03:43:57.917 DEBUG ydbd(pid=1646206, tid=0x00007F1C201FE640) [DQ] executer_actor.cpp:401: {ptqudqgd4a50qp2jttl4} WorkerInfo: Id:209bb6e0-4ad8b8b3-50ad61b7-dbc97a90,ghrun-syjwtgwtdu,NodeId:1,StageId:214477
2025-12-09T03:43:57.917904Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: ptqudqgd4a50qp2jttl4 2025-12-09 03:43:57.917 DEBUG ydbd(pid=1646206, tid=0x00007F1C201FE640) [DQ] executer_actor.cpp:402: {ptqudqgd4a50qp2jttl4} TaskInfo: 0/1
2025-12-09T03:43:57.917911Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: ptqudqgd4a50qp2jttl4 2025-12-09 03:43:57.917 DEBUG ydbd(pid=1646206, tid=0x00007F1C201FE640) [DQ] executer_actor.cpp:404: {ptqudqgd4a50qp2jttl4}  ObjectId: 2ad8a0198ac871ab3cd73b3e9d43a8d7c87aa707, dq_vanilla_job.lite, 
2025-12-09T03:43:57.917932Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: ptqudqgd4a50qp2jttl4 2025-12-09 03:43:57.917 DEBUG ydbd(pid=1646206, tid=0x00007F1C201FE640) [DQ] executer_actor.cpp:401: {ptqudqgd4a50qp2jttl4} WorkerInfo: Id:209bb6e0-4ad8b8b3-50ad61b7-dbc97a90,ghrun-syjwtgwtdu,NodeId:1,StageId:214497
2025-12-09T03:43:57.917943Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: ptqudqgd4a50qp2jttl4 2025-12-09 03:43:57.917 DEBUG ydbd(pid=1646206, tid=0x00007F1C201FE640) [DQ] executer_actor.cpp:402: {ptqudqgd4a50qp2jttl4} TaskInfo: 1/2
2025-12-09T03:43:57.917950Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: ptqudqgd4a50qp2jttl4 2025-12-09 03:43:57.917 DEBUG ydbd(pid=1646206, tid=0x00007F1C201FE640) [DQ] executer_actor.cpp:404: {ptqudqgd4a50qp2jttl4}  ObjectId: 2ad8a0198ac871ab3cd73b3e9d43a8d7c87aa707, dq_vanilla_job.lite, 
2025-12-09T03:43:57.917960Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: e89fdf35-d81f0194-91266a8b-851ce03f 2025-12-09 03:43:57.917 DEBUG ydbd(pid=1646206, tid=0x00007F1C1F1FC640) [DQ] tasks_runner_local.cpp:267: {TODO/1} task: 1, program size: 68, llvm: ``.
2025-12-09T03:43:57.917962Z :YQL_PROXY INFO: log.cpp:64: SessionId: ptqudqgd4a50qp2jttl4 2025-12-09 03:43:57.917 INFO  ydbd(pid=1646206, tid=0x00007F1C201FE640) [DQ] executer_actor.cpp:415: {ptqudqgd4a50qp2jttl4} 2 workers allocated
2025-12-09T03:43:57.918084Z :YQL_PROXY TRACE: log.cpp:64: SessionId:  2025-12-09 03:43:57.918 TRACE ydbd(pid=1646206, tid=0x00007F1C201FE640) [DQ] task_controller_impl.h:271:  [1:7581698911935370102:2281] ExportStats Summary
2025-12-09T03:43:57.918120Z :YQL_PROXY DEBUG: log.cpp:64: SessionId:  2025-12-09 03:43:57.918 DEBUG ydbd(pid=1646206, tid=0x00007F1C201FE640) [DQ] task_controller_impl.h:526: Ready State: [1:7581698911935370102:2281]
2025-12-09T03:43:57.918131Z :YQL_PROXY DEBUG: log.cpp:64: SessionId:  2025-12-09 03:43:57.918 DEBUG ydbd(pid=1646206, tid=0x00007F1C201FE640) [DQ] task_controller_impl.h:537: Forward: [1:7581698911935370102:2281] to [1:7581698911935370101:2280]
2025-12-09T03:43:57.918157Z :STREAMS_CHECKPOINT_COORDINATOR DEBUG: checkpoint_coordinator.cpp:70: [ptqudqgd4a50qp2jttl4-0.2] TEvReadyState, streaming disposition { from_last_checkpoint { } }, state load mode FROM_LAST_CHECKPOINT, checkpointing period 1.000000s
2025-12-09T03:43:57.918175Z :STREAMS_CHECKPOINT_COORDINATOR DEBUG: checkpoint_coordinator.cpp:104: [ptqudqgd4a50qp2jttl4-0.2] AllActors count: 2, ActorsToTrigger count: 1, ActorsToNotify count: 2, ActorsToWaitFor count: 2
2025-12-09T03:43:57.918179Z :STREAMS_CHECKPOINT_COORDINATOR DEBUG: checkpoint_coordinator.cpp:114: [ptqudqgd4a50qp2jttl4-0.2] Send TEvRegisterCoordinatorRequest
2025-12-09T03:43:57.918186Z :STREAMS_STORAGE_SERVICE DEBUG: storage_proxy.cpp:261: [ptqudqgd4a50qp2jttl4-0.2] Got TEvRegisterCoordinatorRequest
2025-12-09T03:43:57.918188Z :STREAMS_STORAGE_SERVICE INFO: storage_proxy.cpp:243: StartInitialization, EnableSecureScriptExecutions: 0
2025-12-09T03:43:57.918980Z :STREAMS_STORAGE_SERVICE NOTICE: storage_proxy.cpp:585: Add to delayed
2025-12-09T03:43:57.927643Z :STREAMS_STORAGE_SERVICE INFO: storage_proxy.cpp:557: Checkpoint storage and state storage were successfully initted
2025-12-09T03:43:57.927663Z :STREAMS_STORAGE_SERVICE DEBUG: storage_proxy.cpp:261: [ptqudqgd4a50qp2jttl4-0.2] Got TEvRegisterCoordinatorRequest
2025-12-09T03:43:57.949317Z :STREAMS_STORAGE_SERVICE INFO: storage_proxy.cpp:279: [ptqudqgd4a50qp2jttl4-0.2] Graph registered
2025-12-09T03:43:57.949333Z :STREAMS_STORAGE_SERVICE DEBUG: storage_proxy.cpp:281: [ptqudqgd4a50qp2jttl4-0.2] Send TEvRegisterCoordinatorResponse
2025-12-09T03:43:57.949372Z :STREAMS_CHECKPOINT_COORDINATOR DEBUG: checkpoint_coordinator.cpp:131: [ptqudqgd4a50qp2jttl4-0.2] Got TEvRegisterCoordinatorResponse; issues: 
2025-12-09T03:43:57.949376Z :STREAMS_CHECKPOINT_COORDINATOR DEBUG: checkpoint_coordinator.cpp:140: [ptqudqgd4a50qp2jttl4-0.2] Successfully registered in storage
2025-12-09T03:43:57.949379Z :STREAMS_CHECKPOINT_COORDINATOR INFO: checkpoint_coordinator.cpp:141: [ptqudqgd4a50qp2jttl4-0.2] Send TEvNewCheckpointCoordinator to 2 actor(s)
2025-12-09T03:43:57.949390Z :STREAMS_CHECKPOINT_COORDINATOR INFO: checkpoint_coordinator.cpp:149: [ptqudqgd4a50qp2jttl4-0.2] Send TEvGetCheckpointsMetadataRequest; state load mode: FROM_LAST_CHECKPOINT; load graph: 0
2025-12-09T03:43:57.949413Z :STREAMS_STORAGE_SERVICE DEBUG: storage_proxy.cpp:434: [ptqudqgd4a50qp2jttl4-0] Got TEvGetCheckpointsMetadataRequest
2025-12-09T03:43:57.968240Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: e89fdf35-d81f0194-91266a8b-851ce03f 2025-12-09 03:43:57.968 DEBUG ydbd(pid=1646206, tid=0x00007F1C1F1FC640) [DQ] tasks_runner_local.cpp:267: {TODO/1} Build task: 1 takes 50384 us
2025-12-09T03:43:57.968262Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: e89fdf35-d81f0194-91266a8b-851ce03f 2025-12-09 03:43:57.968 DEBUG ydbd(pid=1646206, tid=0x00007F1C1F1FC640) [DQ] tasks_runner_local.cpp:267: {TODO/1} Prepare task: 1
2025-12-09T03:43:57.968296Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: e89fdf35-d81f0194-91266a8b-851ce03f 2025-12-09 03:43:57.968 DEBUG ydbd(pid=1646206, tid=0x00007F1C1F1FC640) [DQ] tasks_runner_local.cpp:267: {TODO/1} Prepare task: 1, takes 27 us
2025-12-09T03:43:57.968378Z :KQP_COMPUTE DEBUG: dq_compute_actor_checkpoints.cpp:197: [] Task: 1. Got TEvNewCheckpointCoordinator event: generation 2, actorId: [1:7581698911935370101:2280]
2025-12-09T03:43:57.968385Z :KQP_COMPUTE TRACE: dq_compute_actor_checkpoints.cpp:208: [] Task: 1. Assign checkpoint coordinator (generation = 2)
2025-12-09T03:43:57.968883Z :KQP_COMPUTE DEBUG: dq_compute_actor_impl.h:1360: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, 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\024ptqudqgd4a50qp2jttl4\032\016localhost:8635\"\027\n\025cluster:default_myyds*\005local0\002@\001b\002dtb\003strj&[\"OptionalType\";[\"DataType\";\"Uint64\"]]j&[\"OptionalType\";[\"DataType\";\"String\"]]\222\001\024ptcudqgd4adc711dm4t7\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-09T03:43:57.969171Z :KQP_COMPUTE DEBUG: dq_pq_read_actor_base.cpp:153: SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, 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-09T03:43:57.969219Z :YQL_PROXY TRACE: log.cpp:64: SessionId:  2025-12-09 03:43:57.969 TRACE ydbd(pid=1646206, tid=0x00007F1C1F1FC640) [DQ] task_controller_impl.h:160: [1:7581698911935370102:2281] EvState TaskId: 1 State: 2 PingCookie: 0 StatusCode: UNSPECIFIED
2025-12-09T03:43:57.969232Z :YQL_PROXY TRACE: log.cpp:64: SessionId:  2025-12-09 03:43:57.969 TRACE ydbd(pid=1646206, tid=0x00007F1C1F1FC640) [DQ] task_controller_impl.h:201:  [1:7581698911935370102:2281] Executing TaskId: 1
2025-12-09T03:43:57.988815Z :STREAMS_STORAGE_SERVICE DEBUG: storage_proxy.cpp:451: [ptqudqgd4a50qp2jttl4-0] Send TEvGetCheckpointsMetadataResponse
2025-12-09T03:43:57.988872Z :STREAMS_CHECKPOINT_COORDINATOR DEBUG: checkpoint_coordinator.cpp:186: [ptqudqgd4a50qp2jttl4-0.2] Got TEvGetCheckpointsMetadataResponse
2025-12-09T03:43:57.988880Z :STREAMS_CHECKPOINT_COORDINATOR INFO: checkpoint_coordinator.cpp:219: [ptqudqgd4a50qp2jttl4-0.2] Will restore from checkpoint 1:2
2025-12-09T03:43:57.989113Z :KQP_COMPUTE DEBUG: dq_compute_actor_checkpoints.cpp:265: [ptqudqgd4a50qp2jttl4-0] Task: 1. [Checkpoint 1.2] TEvRestoreFromCheckpoint, StateLoadPlan = { StateType: STATE_TYPE_OWN }
2025-12-09T03:43:57.989141Z :STREAMS_STORAGE_SERVICE DEBUG: storage_proxy.cpp:508: [ptqudqgd4a50qp2jttl4-0] [1:2] Got TEvGetTaskState: tasks {1}
2025-12-09T03:43:57.989148Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:519: [ptqudqgd4a50qp2jttl4-0] [1:2] GetState, tasks: 1
2025-12-09T03:43:58.046743Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:654: [ptqudqgd4a50qp2jttl4-0] [1:2] ListOfStates results:
2025-12-09T03:43:58.046774Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:675: [ptqudqgd4a50qp2jttl4-0] [1:2] taskId 1 checkpoint id: 1:2, rows count: 1
2025-12-09T03:43:58.046776Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:675: [ptqudqgd4a50qp2jttl4-0] [1:2] taskId 1 checkpoint id: 1:1, rows count: 1
2025-12-09T03:43:58.046785Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:901: [ptqudqgd4a50qp2jttl4-0] [1:2] SkipStatesInFuture, skip 0 checkpoints
2025-12-09T03:43:58.046842Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:796: [ptqudqgd4a50qp2jttl4-0] [1:2] SelectState: task_id 1, seq_no 2, blob_seq_num 0
2025-12-09T03:43:58.091855Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:410: [ptqudqgd4a50qp2jttl4-0] [1:2] DeserializeState, task id 1, blob size 135
2025-12-09T03:43:58.091901Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:960: [ptqudqgd4a50qp2jttl4-0] [1:2] ApplyIncrements
2025-12-09T03:43:58.092668Z :STREAMS_STORAGE_SERVICE DEBUG: storage_proxy.cpp:527: [ptqudqgd4a50qp2jttl4-0] [{ Id: 2 Generation: 1 }] Send TEvGetTaskStateResult: tasks: {1}
2025-12-09T03:43:58.092716Z :KQP_COMPUTE DEBUG: dq_compute_actor_checkpoints.cpp:336: [ptqudqgd4a50qp2jttl4-0] Task: 1. [Checkpoint 1.2] TEvGetTaskStateResult: restoring state
2025-12-09T03:43:58.092734Z :KQP_COMPUTE DEBUG: dq_compute_actor_impl.h:793: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Load state
2025-12-09T03:43:58.092824Z :KQP_COMPUTE DEBUG: dq_pq_read_actor_base.cpp:153: SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, 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-09T03:43:58.092848Z :KQP_COMPUTE DEBUG: dq_pq_read_actor_base.cpp:133: SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, task: 1. PQ source. SessionId: empty StartingMessageTs 2025-12-09T03:43:36.009000Z Restoring offset: {0@,4},
2025-12-09T03:43:58.092870Z :KQP_COMPUTE DEBUG: dq_compute_actor_checkpoints.cpp:362: [ptqudqgd4a50qp2jttl4-0] Task: 1. [Checkpoint 1.2] Checkpoint state restored
2025-12-09T03:43:58.092906Z :STREAMS_CHECKPOINT_COORDINATOR DEBUG: checkpoint_coordinator.cpp:297: [ptqudqgd4a50qp2jttl4-0.2] [1:2] Got TEvRestoreFromCheckpointResult; taskId: 1, checkpoint: 1:2, status: OK, issues: 
2025-12-09T03:43:58.092910Z :STREAMS_CHECKPOINT_COORDINATOR DEBUG: checkpoint_coordinator.cpp:320: [ptqudqgd4a50qp2jttl4-0.2] [1:2] Task state restored, need 1 more acks
2025-12-09T03:43:58.405767Z :KQP_COMPUTE DEBUG: dq_compute_actor_checkpoints.cpp:197: [] Task: 2. Got TEvNewCheckpointCoordinator event: generation 2, actorId: [1:7581698911935370101:2280]
2025-12-09T03:43:58.405781Z :KQP_COMPUTE TRACE: dq_compute_actor_checkpoints.cpp:208: [] Task: 2. Assign checkpoint coordinator (generation = 2)
2025-12-09T03:43:58.405823Z :KQP_COMPUTE DEBUG: dq_compute_actor_impl.h:1447: SelfId: [1:7581698911935370104:2283], TxId: ptqudqgd4a50qp2jttl4, 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\016localhost:8635\032\027\n\025cluster:default_myyds\"\005local0\0018\002" } } }
2025-12-09T03:43:58.405893Z :KQP_COMPUTE DEBUG: dq_compute_actor_checkpoints.cpp:265: [ptqudqgd4a50qp2jttl4-0] Task: 2. [Checkpoint 1.2] TEvRestoreFromCheckpoint, StateLoadPlan = { StateType: STATE_TYPE_OWN }
2025-12-09T03:43:58.405920Z :STREAMS_STORAGE_SERVICE DEBUG: storage_proxy.cpp:508: [ptqudqgd4a50qp2jttl4-0] [1:2] Got TEvGetTaskState: tasks {2}
2025-12-09T03:43:58.405930Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:519: [ptqudqgd4a50qp2jttl4-0] [1:2] GetState, tasks: 2
2025-12-09T03:43:58.405941Z :YQL_PROXY TRACE: log.cpp:64: SessionId:  2025-12-09 03:43:58.405 TRACE ydbd(pid=1646206, tid=0x00007F1C201FE640) [DQ] task_controller_impl.h:160: [1:7581698911935370102:2281] EvState TaskId: 2 State: 2 PingCookie: 0 StatusCode: UNSPECIFIED
2025-12-09T03:43:58.405953Z :YQL_PROXY TRACE: log.cpp:64: SessionId:  2025-12-09 03:43:58.405 TRACE ydbd(pid=1646206, tid=0x00007F1C201FE640) [DQ] task_controller_impl.h:201:  [1:7581698911935370102:2281] Executing TaskId: 2
2025-12-09T03:43:58.405975Z :YQL_PROXY DEBUG: log.cpp:64: SessionId:  2025-12-09 03:43:58.405 DEBUG ydbd(pid=1646206, tid=0x00007F1C201FE640) [DQ] task_controller_impl.h:561: Update channels
2025-12-09T03:43:58.406246Z :YQL_PROXY TRACE: log.cpp:64: SessionId:  2025-12-09 03:43:58.406 TRACE ydbd(pid=1646206, tid=0x00007F1C201FE640) [DQ] task_controller_impl.h:577: 1 Update { Id: 1 TransportVersion: DATA_TRANSPORT_UV_PICKLE_1_0 SrcTaskId: 1 DstTaskId: 2 SrcEndpoint { ActorId { RawX1: 7581698911935370107 RawX2: 4503603922340076 } } DstEndpoint { ActorId { RawX1: 7581698911935370104 RawX2: 4503603922340075 } } WatermarksMode: WATERMARKS_MODE_DISABLED SrcStageId: 214477 DstStageId: 214497 }
2025-12-09T03:43:58.406279Z :YQL_PROXY TRACE: log.cpp:64: SessionId:  2025-12-09 03:43:58.406 TRACE ydbd(pid=1646206, tid=0x00007F1C201FE640) [DQ] task_controller_impl.h:577: 2 Update { Id: 1 TransportVersion: DATA_TRANSPORT_UV_PICKLE_1_0 SrcTaskId: 1 DstTaskId: 2 SrcEndpoint { ActorId { RawX1: 7581698911935370107 RawX2: 4503603922340076 } } DstEndpoint { ActorId { RawX1: 7581698911935370104 RawX2: 4503603922340075 } } WatermarksMode: WATERMARKS_MODE_DISABLED SrcStageId: 214477 DstStageId: 214497 }
2025-12-09T03:43:58.406312Z :KQP_COMPUTE DEBUG: dq_compute_actor_impl.h:1064: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Received channels info: Update { Id: 1 TransportVersion: DATA_TRANSPORT_UV_PICKLE_1_0 SrcTaskId: 1 DstTaskId: 2 SrcEndpoint { ActorId { RawX1: 7581698911935370107 RawX2: 4503603922340076 } } DstEndpoint { ActorId { RawX1: 7581698911935370104 RawX2: 4503603922340075 } } WatermarksMode: WATERMARKS_MODE_DISABLED SrcStageId: 214477 DstStageId: 214497 }
2025-12-09T03:43:58.406320Z :KQP_COMPUTE DEBUG: dq_compute_actor_impl.h:1064: SelfId: [1:7581698911935370104:2283], TxId: ptqudqgd4a50qp2jttl4, task: 2. Ctx: {}. Received channels info: Update { Id: 1 TransportVersion: DATA_TRANSPORT_UV_PICKLE_1_0 SrcTaskId: 1 DstTaskId: 2 SrcEndpoint { ActorId { RawX1: 7581698911935370107 RawX2: 4503603922340076 } } DstEndpoint { ActorId { RawX1: 7581698911935370104 RawX2: 4503603922340075 } } WatermarksMode: WATERMARKS_MODE_DISABLED SrcStageId: 214477 DstStageId: 214497 }
2025-12-09T03:43:58.406322Z :KQP_COMPUTE DEBUG: dq_compute_actor_impl.h:1083: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Update output channelId: 1, peer: [1:7581698911935370104:2283]
2025-12-09T03:43:58.406324Z :KQP_COMPUTE DEBUG: dq_compute_actor_impl.h:1071: SelfId: [1:7581698911935370104:2283], TxId: ptqudqgd4a50qp2jttl4, task: 2. Ctx: {}. Update input channelId: 1, peer: [1:7581698911935370107:2284]
2025-12-09T03:43:58.408481Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:654: [ptqudqgd4a50qp2jttl4-0] [1:2] ListOfStates results:
2025-12-09T03:43:58.408507Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:675: [ptqudqgd4a50qp2jttl4-0] [1:2] taskId 2 checkpoint id: 1:2, rows count: 1
2025-12-09T03:43:58.408509Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:675: [ptqudqgd4a50qp2jttl4-0] [1:2] taskId 2 checkpoint id: 1:1, rows count: 1
2025-12-09T03:43:58.408516Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:901: [ptqudqgd4a50qp2jttl4-0] [1:2] SkipStatesInFuture, skip 0 checkpoints
2025-12-09T03:43:58.408548Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:796: [ptqudqgd4a50qp2jttl4-0] [1:2] SelectState: task_id 2, seq_no 2, blob_seq_num 0
2025-12-09T03:43:58.410569Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:410: [ptqudqgd4a50qp2jttl4-0] [1:2] DeserializeState, task id 2, blob size 260
2025-12-09T03:43:58.410587Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:960: [ptqudqgd4a50qp2jttl4-0] [1:2] ApplyIncrements
2025-12-09T03:43:58.410618Z :STREAMS_STORAGE_SERVICE DEBUG: storage_proxy.cpp:527: [ptqudqgd4a50qp2jttl4-0] [{ Id: 2 Generation: 1 }] Send TEvGetTaskStateResult: tasks: {2}
2025-12-09T03:43:58.410658Z :KQP_COMPUTE DEBUG: dq_compute_actor_checkpoints.cpp:336: [ptqudqgd4a50qp2jttl4-0] Task: 2. [Checkpoint 1.2] TEvGetTaskStateResult: restoring state
2025-12-09T03:43:58.410671Z :KQP_COMPUTE DEBUG: dq_compute_actor_impl.h:793: SelfId: [1:7581698911935370104:2283], TxId: ptqudqgd4a50qp2jttl4, task: 2. Ctx: {}. Load state
2025-12-09T03:43:58.410837Z :KQP_COMPUTE DEBUG: dq_pq_write_actor.cpp:268: SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, TaskId: 2, PQ sink. Load state: { SourceId: "163830dc-48eb33dc-75397bee-46f62dd7" }
2025-12-09T03:43:58.410849Z :KQP_COMPUTE DEBUG: dq_compute_actor_impl.h:821: SelfId: [1:7581698911935370104:2283], TxId: ptqudqgd4a50qp2jttl4, task: 2. Ctx: {}. State size: 174
2025-12-09T03:43:58.410888Z :KQP_COMPUTE DEBUG: dq_compute_actor_checkpoints.cpp:362: [ptqudqgd4a50qp2jttl4-0] Task: 2. [Checkpoint 1.2] Checkpoint state restored
2025-12-09T03:43:58.410911Z :STREAMS_CHECKPOINT_COORDINATOR DEBUG: checkpoint_coordinator.cpp:297: [ptqudqgd4a50qp2jttl4-0.2] [1:2] Got TEvRestoreFromCheckpointResult; taskId: 2, checkpoint: 1:2, status: OK, issues: 
2025-12-09T03:43:58.410923Z :STREAMS_CHECKPOINT_COORDINATOR DEBUG: checkpoint_coordinator.cpp:320: [ptqudqgd4a50qp2jttl4-0.2] [1:2] Task state restored, need 0 more acks
2025-12-09T03:43:58.410927Z :STREAMS_CHECKPOINT_COORDINATOR INFO: checkpoint_coordinator.cpp:445: [ptqudqgd4a50qp2jttl4-0.2] Send TEvRun to all actors
2025-12-09T03:43:58.410949Z :KQP_COMPUTE DEBUG: dq_compute_actor_impl.h:1164: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Got TEvRun from actor [1:7581698911935370101:2280]
2025-12-09T03:43:58.410949Z :KQP_COMPUTE DEBUG: dq_compute_actor_impl.h:1164: SelfId: [1:7581698911935370104:2283], TxId: ptqudqgd4a50qp2jttl4, task: 2. Ctx: {}. Got TEvRun from actor [1:7581698911935370101:2280]
2025-12-09T03:43:58.410957Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1483: SelfId: [1:7581698911935370104:2283], TxId: ptqudqgd4a50qp2jttl4, task: 2. Ctx: {}. Poll inputs
2025-12-09T03:43:58.410959Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1483: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Poll inputs
2025-12-09T03:43:58.410959Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1498: SelfId: [1:7581698911935370104:2283], TxId: ptqudqgd4a50qp2jttl4, task: 2. Ctx: {}. Poll sources
2025-12-09T03:43:58.410960Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1498: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Poll sources
2025-12-09T03:43:58.410961Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:698: SelfId: [1:7581698911935370104:2283], TxId: ptqudqgd4a50qp2jttl4, task: 2. Ctx: {}. DoExecuteImpl: 0
2025-12-09T03:43:58.410968Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:542: SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, task: 1. PQ source. SessionId: empty GetAsyncInputData freeSpace = 1
2025-12-09T03:43:58.410992Z :KQP_COMPUTE DEBUG: dq_pq_read_actor.cpp:648: SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, task: 1. PQ source. SessionId: empty PartitionsToRead: 0
2025-12-09T03:43:58.411028Z :YDB_SDK INFO: actor.cpp:37: 2025-12-09T03:43:58.411023Z :INFO: [local] [local] [9574d711-eea3e517-142b777c-ba3b4156] Starting read session
2025-12-09T03:43:58.411039Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-09T03:43:58.411037Z :DEBUG: [local] [local] [9574d711-eea3e517-142b777c-ba3b4156] Starting single session
2025-12-09T03:43:58.411080Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-09T03:43:58.411078Z :DEBUG: [local] [local] [9574d711-eea3e517-142b777c-ba3b4156] [] In Reconnect, ReadSizeBudget = 8388608, ReadSizeServerDelta = 0
2025-12-09T03:43:58.411088Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-09T03:43:58.411087Z :DEBUG: [local] [local] [9574d711-eea3e517-142b777c-ba3b4156] [] New values: ReadSizeBudget = 8388608, ReadSizeServerDelta = 0
2025-12-09T03:43:58.411093Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-09T03:43:58.411091Z :DEBUG: [local] [local] [9574d711-eea3e517-142b777c-ba3b4156] [] Reconnecting session to cluster  in 0.000000s
2025-12-09T03:43:58.411132Z :KQP_COMPUTE TRACE: dq_compute_memory_quota.h:97: TxId: ptqudqgd4a50qp2jttl4, task: 2. Peak memory usage: 2031616
2025-12-09T03:43:58.411149Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:493: SelfId: [1:7581698911935370104:2283], TxId: ptqudqgd4a50qp2jttl4, task: 2. Ctx: {}. update task runner stats
2025-12-09T03:43:58.411179Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:762: SelfId: [1:7581698911935370104:2283], TxId: ptqudqgd4a50qp2jttl4, task: 2. Ctx: {}. Resume execution, run status: PendingInput checkpoint: 0 watermark injected: (empty maybe)
2025-12-09T03:43:58.411189Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:406: SelfId: [1:7581698911935370104:2283], TxId: ptqudqgd4a50qp2jttl4, task: 2. Ctx: {}. ProcessOutputsState.Inflight: 0
2025-12-09T03:43:58.411194Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:573: SelfId: [1:7581698911935370104:2283], TxId: ptqudqgd4a50qp2jttl4, task: 2. Ctx: {}. About to drain sink 0. FreeSpace: 16777216, allowedOvercommit: 500000, toSend: 17277216
2025-12-09T03:43:58.411198Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:1107: SelfId: [1:7581698911935370104:2283], TxId: ptqudqgd4a50qp2jttl4, task: 2. Ctx: {}. Ask CPU quota: 488ms
2025-12-09T03:43:58.411216Z :KQP_COMPUTE TRACE: dq_pq_write_actor.cpp:195: SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, TaskId: 2, PQ sink. SendData. Batch: 0. Checkpoint: 0. Finished: 0
2025-12-09T03:43:58.411282Z :KQP_COMPUTE INFO: dq_pq_read_actor.cpp:315: SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, task: 1. PQ source. SessionId: 9574d711-eea3e517-142b777c-ba3b4156 CreateReadSession
2025-12-09T03:43:58.411290Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:1025: SelfId: [1:7581698911935370104:2283], TxId: ptqudqgd4a50qp2jttl4, task: 2. Ctx: {}. Sink 0: sent 0 bytes of data and 0 bytes of checkpoint barrier
2025-12-09T03:43:58.411292Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:1029: SelfId: [1:7581698911935370104:2283], TxId: ptqudqgd4a50qp2jttl4, task: 2. Ctx: {}. Drain sink 0. Free space decreased: 0, sent data from buffer: 0
2025-12-09T03:43:58.411293Z :KQP_COMPUTE TRACE: dq_compute_actor_async_input_helper.h:81: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Poll async input 0. Buffer free space: 1, read from async input: 0 bytes, 0 rows, finished: 0
2025-12-09T03:43:58.411299Z :KQP_COMPUTE TRACE: dq_compute_actor_channels.cpp:605: TxId: ptqudqgd4a50qp2jttl4, task: 2. no poll, channelId: 1, hasPeer: 1, finished: 0, retry: 0, lastSeqNo: 0, freeSpace: 1000000
2025-12-09T03:43:58.411307Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-09T03:43:58.411291Z :DEBUG: [local] [local] [9574d711-eea3e517-142b777c-ba3b4156] [] Successfully connected. Initializing session
2025-12-09T03:43:58.411310Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:844: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Send TEvContinueRun on OnAsyncInputPushFinished
2025-12-09T03:43:58.411334Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: e89fdf35-d81f0194-91266a8b-851ce03f 2025-12-09 03:43:58.411 DEBUG ydbd(pid=1646206, tid=0x00007F1C1F1FC640) [DQ] tasks_runner_local.cpp:267: {TODO/1} Run task: 1
2025-12-09T03:43:58.411407Z :KQP_COMPUTE TRACE: dq_compute_memory_quota.h:97: TxId: ptqudqgd4a50qp2jttl4, task: 1. Peak memory usage: 2031616
2025-12-09T03:43:58.411415Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:493: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. update task runner stats
2025-12-09T03:43:58.411430Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:762: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Resume execution, run status: PendingInput checkpoint: 0 watermark injected: (empty maybe)
2025-12-09T03:43:58.411432Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:406: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. ProcessOutputsState.Inflight: 0
2025-12-09T03:43:58.411435Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:534: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. About to drain channelId: 1, hasPeer: 1, peerState:(freeSpace:1000000;inFlightBytes:0;inFlightCount:0;)
2025-12-09T03:43:58.411437Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:1107: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Ask CPU quota: 52ms
2025-12-09T03:43:58.411980Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:1165: SelfId: [1:7581698911935370104:2283], TxId: ptqudqgd4a50qp2jttl4, task: 2. Ctx: {}. CPU quota delay: 0ms
2025-12-09T03:43:58.412033Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:1165: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. CPU quota delay: 0ms
2025-12-09T03:43:58.412337Z :YDB_SDK INFO: actor.cpp:37: 2025-12-09T03:43:58.412332Z :INFO: [local] [local] [9574d711-eea3e517-142b777c-ba3b4156] [] Got InitResponse. ReadSessionId: ptqudqgd4a50qp2jttl4_1_12_10015761972333514831_v1
2025-12-09T03:43:58.412348Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-09T03:43:58.412346Z :DEBUG: [local] [local] [9574d711-eea3e517-142b777c-ba3b4156] [] In ContinueReadingDataImpl, ReadSizeBudget = 8388608, ReadSizeServerDelta = 0
2025-12-09T03:43:58.412389Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-09T03:43:58.412387Z :DEBUG: [local] [local] [9574d711-eea3e517-142b777c-ba3b4156] [] After sending read request: ReadSizeBudget = 0, ReadSizeServerDelta = 8388608
2025-12-09T03:43:58.412654Z :YDB_SDK INFO: actor.cpp:37: 2025-12-09T03:43:58.412649Z :INFO: [local] OnFederationDiscovery fall back to single mode, database=local
2025-12-09T03:43:58.412777Z :YDB_SDK INFO: actor.cpp:37: [] [] Start federated write session to database '' (previous was <empty>) FederationState: { Status: SUCCESS SelfLocation: "" DbInfos: [ { path: "local" endpoint: "localhost:8635" status: AVAILABLE weight: 100 } ] ControlPlaneEndpoint: localhost:8635 }
2025-12-09T03:43:58.412821Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-09T03:43:58.412820Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, TaskId: 2, PQ sink. ]  SessionId []  MessageGroupId [163830dc-48eb33dc-75397bee-46f62dd7] Write session: try to update token
2025-12-09T03:43:58.413038Z :YDB_SDK INFO: actor.cpp:37: 2025-12-09T03:43:58.413035Z :INFO: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, TaskId: 2, PQ sink. ]  SessionId []  MessageGroupId [163830dc-48eb33dc-75397bee-46f62dd7] Start write session. Will connect to nodeId: 0
2025-12-09T03:43:58.413189Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-09T03:43:58.413183Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, TaskId: 2, PQ sink. ]  SessionId []  MessageGroupId [163830dc-48eb33dc-75397bee-46f62dd7] Write session: write to message_group: 163830dc-48eb33dc-75397bee-46f62dd7
2025-12-09T03:43:58.413218Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-09T03:43:58.413215Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, TaskId: 2, PQ sink. ]  SessionId []  MessageGroupId [163830dc-48eb33dc-75397bee-46f62dd7] Write session: send init request: init_request { path: "test_match_recognize[v1-kikimr0]_v1_output" producer_id: "163830dc-48eb33dc-75397bee-46f62dd7" message_group_id: "163830dc-48eb33dc-75397bee-46f62dd7" }
2025-12-09T03:43:58.413225Z :YDB_SDK TRACE: actor.cpp:37: 2025-12-09T03:43:58.413223Z :TRACE: [local] TRACE_EVENT InitRequest 
2025-12-09T03:43:58.413312Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-09T03:43:58.413309Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, TaskId: 2, PQ sink. ]  SessionId []  MessageGroupId [163830dc-48eb33dc-75397bee-46f62dd7] Write session: OnWriteDone gRpcStatusCode: 0
2025-12-09T03:43:58.413911Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:363: SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, task: 1. PQ source. SessionId: 9574d711-eea3e517-142b777c-ba3b4156 Source data ready
2025-12-09T03:43:58.413930Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1483: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Poll inputs
2025-12-09T03:43:58.413931Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1498: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Poll sources
2025-12-09T03:43:58.413936Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:542: SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, task: 1. PQ source. SessionId: 9574d711-eea3e517-142b777c-ba3b4156 GetAsyncInputData freeSpace = 1000000
2025-12-09T03:43:58.413948Z :KQP_COMPUTE DEBUG: dq_pq_read_actor.cpp:820: SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, task: 1. PQ source. SessionId: 9574d711-eea3e517-142b777c-ba3b4156 Key: 0@ StartPartitionSessionEvent received
2025-12-09T03:43:58.413950Z :KQP_COMPUTE DEBUG: dq_pq_read_actor.cpp:827: SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, task: 1. PQ source. SessionId: 9574d711-eea3e517-142b777c-ba3b4156 Key: 0@ Confirm StartPartitionSession with offset 4
2025-12-09T03:43:58.413960Z :YDB_SDK INFO: actor.cpp:37: 2025-12-09T03:43:58.413957Z :INFO: [local] [local] [9574d711-eea3e517-142b777c-ba3b4156] [] Confirm partition stream create. Partition stream id: 1. Cluster: "-". Topic: "test_match_recognize[v1-kikimr0]_v1_input". Partition: 0. Read offset: 4
2025-12-09T03:43:58.414064Z :KQP_COMPUTE TRACE: dq_compute_actor_async_input_helper.h:81: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Poll async input 0. Buffer free space: 1000000, read from async input: 0 bytes, 0 rows, finished: 0
2025-12-09T03:43:58.414085Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:363: SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, task: 1. PQ source. SessionId: 9574d711-eea3e517-142b777c-ba3b4156 Source data ready
2025-12-09T03:43:58.414089Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:844: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Send TEvContinueRun on OnAsyncInputPushFinished
2025-12-09T03:43:58.414145Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1483: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Poll inputs
2025-12-09T03:43:58.414149Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1498: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Poll sources
2025-12-09T03:43:58.414152Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:542: SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, task: 1. PQ source. SessionId: 9574d711-eea3e517-142b777c-ba3b4156 GetAsyncInputData freeSpace = 1000000
2025-12-09T03:43:58.414156Z :KQP_COMPUTE TRACE: dq_compute_actor_async_input_helper.h:81: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Poll async input 0. Buffer free space: 1000000, read from async input: 0 bytes, 0 rows, finished: 0
2025-12-09T03:43:58.414160Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:493: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. update task runner stats
2025-12-09T03:43:58.414183Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:762: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Resume execution, run status: PendingInput checkpoint: 0 watermark injected: (empty maybe)
2025-12-09T03:43:58.414191Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:406: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. ProcessOutputsState.Inflight: 0
2025-12-09T03:43:58.414195Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:534: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. About to drain channelId: 1, hasPeer: 1, peerState:(freeSpace:1000000;inFlightBytes:0;inFlightCount:0;)
2025-12-09T03:43:58.414198Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:844: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Send TEvContinueRun on OnAsyncInputPushFinished
2025-12-09T03:43:58.414220Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:493: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. update task runner stats
2025-12-09T03:43:58.414230Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:762: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Resume execution, run status: PendingInput checkpoint: 0 watermark injected: (empty maybe)
2025-12-09T03:43:58.414232Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:406: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. ProcessOutputsState.Inflight: 0
2025-12-09T03:43:58.414234Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:534: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. About to drain channelId: 1, hasPeer: 1, peerState:(freeSpace:1000000;inFlightBytes:0;inFlightCount:0;)
2025-12-09T03:43:58.414568Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-09T03:43:58.414564Z :DEBUG: [local] [local] [9574d711-eea3e517-142b777c-ba3b4156] [] Got ReadResponse, serverBytesSize = 87, now ReadSizeBudget = 0, ReadSizeServerDelta = 8388521
2025-12-09T03:43:58.414588Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-09T03:43:58.414586Z :DEBUG: [local] [local] [9574d711-eea3e517-142b777c-ba3b4156] [] In ContinueReadingDataImpl, ReadSizeBudget = 0, ReadSizeServerDelta = 8388521
2025-12-09T03:43:58.414618Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-09T03:43:58.414617Z :DEBUG: [local] Decompression task done. Partition/PartitionSessionId: 1 (4-4)
2025-12-09T03:43:58.414626Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-09T03:43:58.414625Z :DEBUG: [local] [local] [9574d711-eea3e517-142b777c-ba3b4156] [] Returning serverBytesSize = 87 to budget
2025-12-09T03:43:58.414639Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-09T03:43:58.414627Z :DEBUG: [local] [local] [9574d711-eea3e517-142b777c-ba3b4156] [] In ContinueReadingDataImpl, ReadSizeBudget = 87, ReadSizeServerDelta = 8388521
2025-12-09T03:43:58.414677Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-09T03:43:58.414676Z :DEBUG: [local] [local] [9574d711-eea3e517-142b777c-ba3b4156] [] After sending read request: ReadSizeBudget = 0, ReadSizeServerDelta = 8388608
2025-12-09T03:43:58.414713Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:363: SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, task: 1. PQ source. SessionId: 9574d711-eea3e517-142b777c-ba3b4156 Source data ready
2025-12-09T03:43:58.414717Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1483: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Poll inputs
2025-12-09T03:43:58.414718Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1498: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Poll sources
2025-12-09T03:43:58.414722Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:542: SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, task: 1. PQ source. SessionId: 9574d711-eea3e517-142b777c-ba3b4156 GetAsyncInputData freeSpace = 1000000
2025-12-09T03:43:58.414740Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-09T03:43:58.414737Z :DEBUG: [local] Take Data. Partition 0. Read: {0, 0} (4-4)
2025-12-09T03:43:58.414756Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-09T03:43:58.414754Z :DEBUG: [local] [local] [9574d711-eea3e517-142b777c-ba3b4156] [] The application data is transferred to the client. Number of messages 1, size 37 bytes
2025-12-09T03:43:58.414764Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-09T03:43:58.414763Z :DEBUG: [local] [local] [9574d711-eea3e517-142b777c-ba3b4156] [] Returning serverBytesSize = 0 to budget
2025-12-09T03:43:58.414785Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:761: SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, task: 1. PQ source. SessionId: 9574d711-eea3e517-142b777c-ba3b4156 Key: 0@ Data received: Message { Data: "{"dt": 1696849944100001, "str": "E" }" Information: { Offset: 4 ProducerId: "" SeqNo: 0 CreateTime: 2025-12-09T03:43:39.927000Z WriteTime: 2025-12-09T03:43:39.926000Z MessageGroupId: "" Meta: { } MessageMeta: { } } Partition session id: 1 Topic: "test_match_recognize[v1-kikimr0]_v1_input" Partition: 0 }
2025-12-09T03:43:58.414808Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:737: SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, task: 1. PQ source. SessionId: 9574d711-eea3e517-142b777c-ba3b4156 Return ready batch. DataCount = 1 Watermark = none Used space = 37
2025-12-09T03:43:58.414815Z :KQP_COMPUTE TRACE: dq_compute_actor_async_input_helper.h:81: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Poll async input 0. Buffer free space: 1000000, read from async input: 37 bytes, 1 rows, finished: 0
2025-12-09T03:43:58.414831Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:363: SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, task: 1. PQ source. SessionId: 9574d711-eea3e517-142b777c-ba3b4156 Source data ready
2025-12-09T03:43:58.414834Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:844: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Send TEvContinueRun on OnAsyncInputPushFinished
2025-12-09T03:43:58.414837Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1483: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Poll inputs
2025-12-09T03:43:58.414839Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1498: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Poll sources
2025-12-09T03:43:58.414841Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:542: SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, task: 1. PQ source. SessionId: 9574d711-eea3e517-142b777c-ba3b4156 GetAsyncInputData freeSpace = 999963
2025-12-09T03:43:58.414844Z :KQP_COMPUTE TRACE: dq_compute_actor_async_input_helper.h:81: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Poll async input 0. Buffer free space: 999963, read from async input: 0 bytes, 0 rows, finished: 0
2025-12-09T03:43:58.414970Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:844: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Send TEvContinueRun on OnAsyncInputPushFinished
2025-12-09T03:43:58.414980Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1483: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Poll inputs
2025-12-09T03:43:58.414982Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1498: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Poll sources
2025-12-09T03:43:58.414985Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:542: SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, task: 1. PQ source. SessionId: 9574d711-eea3e517-142b777c-ba3b4156 GetAsyncInputData freeSpace = 999963
2025-12-09T03:43:58.414987Z :KQP_COMPUTE TRACE: dq_compute_actor_async_input_helper.h:81: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Poll async input 0. Buffer free space: 999963, read from async input: 0 bytes, 0 rows, finished: 0
2025-12-09T03:43:58.414991Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:493: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. update task runner stats
2025-12-09T03:43:58.415002Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:762: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Resume execution, run status: PendingInput checkpoint: 0 watermark injected: (empty maybe)
2025-12-09T03:43:58.415009Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:406: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. ProcessOutputsState.Inflight: 0
2025-12-09T03:43:58.415013Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:534: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. About to drain channelId: 1, hasPeer: 1, peerState:(freeSpace:1000000;inFlightBytes:0;inFlightCount:0;)
2025-12-09T03:43:58.415016Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:844: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Send TEvContinueRun on OnAsyncInputPushFinished
2025-12-09T03:43:58.415053Z :KQP_COMPUTE TRACE: dq_compute_actor_channels.cpp:566: TxId: ptqudqgd4a50qp2jttl4, task: 1. SendChannelData, channelId: 1, peer: [1:7581698911935370104:2283], chunks: 1, bytes: 17, watermark: 0, checkpoint: 0, seqNo: 1, finished: 0
2025-12-09T03:43:58.415076Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:493: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. update task runner stats
2025-12-09T03:43:58.415088Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:762: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Resume execution, run status: PendingInput checkpoint: 0 watermark injected: (empty maybe)
2025-12-09T03:43:58.415089Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:406: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. ProcessOutputsState.Inflight: 0
2025-12-09T03:43:58.415092Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:534: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. About to drain channelId: 1, hasPeer: 1, peerState:(freeSpace:1000000;inFlightBytes:113;inFlightCount:1;)
2025-12-09T03:43:58.415095Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1483: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Poll inputs
2025-12-09T03:43:58.415096Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1498: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Poll sources
2025-12-09T03:43:58.415098Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:542: SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, task: 1. PQ source. SessionId: 9574d711-eea3e517-142b777c-ba3b4156 GetAsyncInputData freeSpace = 1000000
2025-12-09T03:43:58.415101Z :KQP_COMPUTE TRACE: dq_compute_actor_async_input_helper.h:81: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Poll async input 0. Buffer free space: 1000000, read from async input: 0 bytes, 0 rows, finished: 0
2025-12-09T03:43:58.415102Z :KQP_COMPUTE TRACE: dq_compute_actor_channels.cpp:129: TxId: ptqudqgd4a50qp2jttl4, task: 2. Received input for channelId: 1, seqNo: 1, size: 17, chunks: 1, watermark: 0, checkpoint: 0, finished: 0, from: [1:7581698911935370108:2284], expected seqNo: 1
2025-12-09T03:43:58.415106Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:611: SelfId: [1:7581698911935370104:2283], TxId: ptqudqgd4a50qp2jttl4, task: 2. Ctx: {}. took input
2025-12-09T03:43:58.415118Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:844: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Send TEvContinueRun on OnAsyncInputPushFinished
2025-12-09T03:43:58.415126Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:493: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. update task runner stats
2025-12-09T03:43:58.415127Z :DQ_TASK_RUNNER TRACE: task_runner_actor_local.cpp:356: SelfId: [1:7581698911935370106:2283], TxId: ptqudqgd4a50qp2jttl4, task: 2. No watermark 
2025-12-09T03:43:58.415131Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:965: SelfId: [1:7581698911935370104:2283], TxId: ptqudqgd4a50qp2jttl4, task: 2. Ctx: {}. Input data push finished. Cookie: 0 Watermark: (empty maybe) Ack: 1 TakeInputChannelDataRequests: 1
2025-12-09T03:43:58.415132Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:762: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Resume execution, run status: PendingInput checkpoint: 0 watermark injected: (empty maybe)
2025-12-09T03:43:58.415134Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:406: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. ProcessOutputsState.Inflight: 0
2025-12-09T03:43:58.415135Z :KQP_COMPUTE TRACE: dq_compute_actor_channels.cpp:738: TxId: ptqudqgd4a50qp2jttl4, task: 2. Sending channel data ack to channelId: 1, peer: [1:7581698911935370107:2284], from: [1:7581698911935370104:2283], freeSpace: 999983, seqNo: 1, finished: 0
2025-12-09T03:43:58.415137Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:534: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. About to drain channelId: 1, hasPeer: 1, peerState:(freeSpace:1000000;inFlightBytes:113;inFlightCount:1;)
2025-12-09T03:43:58.415139Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1483: SelfId: [1:7581698911935370104:2283], TxId: ptqudqgd4a50qp2jttl4, task: 2. Ctx: {}. Poll inputs
2025-12-09T03:43:58.415140Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1498: SelfId: [1:7581698911935370104:2283], TxId: ptqudqgd4a50qp2jttl4, task: 2. Ctx: {}. Poll sources
2025-12-09T03:43:58.415141Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:698: SelfId: [1:7581698911935370104:2283], TxId: ptqudqgd4a50qp2jttl4, task: 2. Ctx: {}. DoExecuteImpl: 0
2025-12-09T03:43:58.415142Z :KQP_COMPUTE TRACE: dq_compute_actor_channels.cpp:179: TxId: ptqudqgd4a50qp2jttl4, task: 1. Received channel data ack for channelId: 1, seqNo: 1, lastSentSeqNo: 1, freeSpace: 999983, early finish: 0
2025-12-09T03:43:58.415146Z :KQP_COMPUTE TRACE: dq_compute_actor_channels.cpp:207: TxId: ptqudqgd4a50qp2jttl4, task: 1. PeerState, peerState:(freeSpace:999983;inFlightBytes:0;inFlightCount:0;), sentSeqNo: 1, ackSeqNo: 1
2025-12-09T03:43:58.415148Z :KQP_COMPUTE TRACE: dq_compute_actor_channels.cpp:220: TxId: ptqudqgd4a50qp2jttl4, task: 1. Resume compute actor
2025-12-09T03:43:58.415162Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1483: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Poll inputs
2025-12-09T03:43:58.415163Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1498: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Poll sources
2025-12-09T03:43:58.415165Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: e89fdf35-d81f0194-91266a8b-851ce03f 2025-12-09 03:43:58.415 DEBUG ydbd(pid=1646206, tid=0x00007F1C1F1FC640) [DQ] tasks_runner_local.cpp:267: {TODO/2} Run task: 2
2025-12-09T03:43:58.415165Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:542: SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, task: 1. PQ source. SessionId: 9574d711-eea3e517-142b777c-ba3b4156 GetAsyncInputData freeSpace = 1000000
2025-12-09T03:43:58.415168Z :KQP_COMPUTE TRACE: dq_compute_actor_async_input_helper.h:81: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Poll async input 0. Buffer free space: 1000000, read from async input: 0 bytes, 0 rows, finished: 0
2025-12-09T03:43:58.415172Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:493: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. update task runner stats
2025-12-09T03:43:58.415177Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:762: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Resume execution, run status: PendingInput checkpoint: 0 watermark injected: (empty maybe)
2025-12-09T03:43:58.415179Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:406: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. ProcessOutputsState.Inflight: 0
2025-12-09T03:43:58.415181Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:534: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. About to drain channelId: 1, hasPeer: 1, peerState:(freeSpace:999983;inFlightBytes:0;inFlightCount:0;)
2025-12-09T03:43:58.415184Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:844: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Send TEvContinueRun on OnAsyncInputPushFinished
2025-12-09T03:43:58.415196Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:493: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. update task runner stats
2025-12-09T03:43:58.415201Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:762: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Resume execution, run status: PendingInput checkpoint: 0 watermark injected: (empty maybe)
2025-12-09T03:43:58.415202Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:406: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. ProcessOutputsState.Inflight: 0
2025-12-09T03:43:58.415205Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:534: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. About to drain channelId: 1, hasPeer: 1, peerState:(freeSpace:999983;inFlightBytes:0;inFlightCount:0;)
2025-12-09T03:43:58.415433Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:493: SelfId: [1:7581698911935370104:2283], TxId: ptqudqgd4a50qp2jttl4, task: 2. Ctx: {}. update task runner stats
2025-12-09T03:43:58.415460Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:762: SelfId: [1:7581698911935370104:2283], TxId: ptqudqgd4a50qp2jttl4, task: 2. Ctx: {}. Resume execution, run status: PendingInput checkpoint: 0 watermark injected: (empty maybe)
2025-12-09T03:43:58.415461Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:406: SelfId: [1:7581698911935370104:2283], TxId: ptqudqgd4a50qp2jttl4, task: 2. Ctx: {}. ProcessOutputsState.Inflight: 0
2025-12-09T03:43:58.415463Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:573: SelfId: [1:7581698911935370104:2283], TxId: ptqudqgd4a50qp2jttl4, task: 2. Ctx: {}. About to drain sink 0. FreeSpace: 16777216, allowedOvercommit: 500000, toSend: 17277216
2025-12-09T03:43:58.415471Z :KQP_COMPUTE TRACE: dq_pq_write_actor.cpp:195: SelfId: [1:7581698916230337409:2283], TxId: ptqudqgd4a50qp2jttl4, TaskId: 2, PQ sink. SendData. Batch: 1. Checkpoint: 0. Finished: 0
2025-12-09T03:43:58.415473Z :KQP_COMPUTE TRACE: dq_pq_write_actor.cpp:221: SelfId: [1:7581698916230337409:2283], TxId: ptqudqgd4a50qp2jttl4, 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-09T03:43:58.415488Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:1025: SelfId: [1:7581698911935370104:2283], TxId: ptqudqgd4a50qp2jttl4, task: 2. Ctx: {}. Sink 0: sent 95 bytes of data and 0 bytes of checkpoint barrier
2025-12-09T03:43:58.415490Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:1029: SelfId: [1:7581698911935370104:2283], TxId: ptqudqgd4a50qp2jttl4, task: 2. Ctx: {}. Drain sink 0. Free space decreased: 91, sent data from buffer: 95
2025-12-09T03:43:58.415493Z :KQP_COMPUTE TRACE: dq_compute_actor_channels.cpp:629: TxId: ptqudqgd4a50qp2jttl4, task: 2. do poll, channelId: 1, last freeSpace: 999983, current freeSpace: 1000000, seqNo: 1
2025-12-09T03:43:58.415495Z :KQP_COMPUTE TRACE: dq_compute_actor_channels.cpp:639: TxId: ptqudqgd4a50qp2jttl4, task: 2. Poll input channelId: 1, from: [1:7581698911935370107:2284], seqNo: 1, freeSpace: 1000000
2025-12-09T03:43:58.415498Z :KQP_COMPUTE TRACE: dq_compute_actor_channels.cpp:738: TxId: ptqudqgd4a50qp2jttl4, task: 2. Sending channel data ack to channelId: 1, peer: [1:7581698911935370107:2284], from: [1:7581698911935370104:2283], freeSpace: 1000000, seqNo: 1, finished: 0
2025-12-09T03:43:58.415511Z :KQP_COMPUTE TRACE: dq_compute_actor_channels.cpp:179: TxId: ptqudqgd4a50qp2jttl4, task: 1. Received channel data ack for channelId: 1, seqNo: 1, lastSentSeqNo: 1, freeSpace: 1000000, early finish: 0
2025-12-09T03:43:58.415513Z :KQP_COMPUTE TRACE: dq_compute_actor_channels.cpp:207: TxId: ptqudqgd4a50qp2jttl4, task: 1. PeerState, peerState:(freeSpace:1000000;inFlightBytes:0;inFlightCount:0;), sentSeqNo: 1, ackSeqNo: 1
2025-12-09T03:43:58.415514Z :KQP_COMPUTE TRACE: dq_compute_actor_channels.cpp:220: TxId: ptqudqgd4a50qp2jttl4, task: 1. Resume compute actor
2025-12-09T03:43:58.415517Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1483: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Poll inputs
2025-12-09T03:43:58.415519Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1498: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Poll sources
2025-12-09T03:43:58.415532Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:542: SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, task: 1. PQ source. SessionId: 9574d711-eea3e517-142b777c-ba3b4156 GetAsyncInputData freeSpace = 1000000
2025-12-09T03:43:58.415535Z :KQP_COMPUTE TRACE: dq_compute_actor_async_input_helper.h:81: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Poll async input 0. Buffer free space: 1000000, read from async input: 0 bytes, 0 rows, finished: 0
2025-12-09T03:43:58.415540Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:844: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Send TEvContinueRun on OnAsyncInputPushFinished
2025-12-09T03:43:58.415554Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: e89fdf35-d81f0194-91266a8b-851ce03f 2025-12-09 03:43:58.415 DEBUG ydbd(pid=1646206, tid=0x00007F1C1F1FC640) [DQ] tasks_runner_local.cpp:267: {TODO/1} Run task: 1
2025-12-09T03:43:58.415563Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:493: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. update task runner stats
2025-12-09T03:43:58.415572Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:762: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Resume execution, run status: PendingInput checkpoint: 0 watermark injected: (empty maybe)
2025-12-09T03:43:58.415574Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:406: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. ProcessOutputsState.Inflight: 0
2025-12-09T03:43:58.415576Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:534: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. About to drain channelId: 1, hasPeer: 1, peerState:(freeSpace:1000000;inFlightBytes:0;inFlightCount:0;)
2025-12-09T03:43:58.419324Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-09T03:43:58.419317Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, TaskId: 2, PQ sink. ]  SessionId []  MessageGroupId [163830dc-48eb33dc-75397bee-46f62dd7] Write session: OnReadDone gRpcStatusCode: 0
2025-12-09T03:43:58.419344Z :YDB_SDK INFO: actor.cpp:37: 2025-12-09T03:43:58.419342Z :INFO: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, TaskId: 2, PQ sink. ]  SessionId []  MessageGroupId [163830dc-48eb33dc-75397bee-46f62dd7] Counters: { Errors: 0 CurrentSessionLifetimeMs: 1765251838419 BytesWritten: 0 MessagesWritten: 0 BytesWrittenCompressed: 0 BytesInflightUncompressed: 0 BytesInflightCompressed: 0 BytesInflightTotal: 0 MessagesInflight: 0 }
2025-12-09T03:43:58.419360Z :YDB_SDK INFO: actor.cpp:37: 2025-12-09T03:43:58.419359Z :INFO: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, TaskId: 2, PQ sink. ]  SessionId []  MessageGroupId [163830dc-48eb33dc-75397bee-46f62dd7] Write session established. Init response: session_id: "163830dc-48eb33dc-75397bee-46f62dd7|2067c992-8dfb82ad-954cae33-d7d6ec73_0"
2025-12-09T03:43:58.419364Z :YDB_SDK TRACE: actor.cpp:37: 2025-12-09T03:43:58.419363Z :TRACE: [local] TRACE_EVENT InitResponse  partition_id=0 session_id=163830dc-48eb33dc-75397bee-46f62dd7|2067c992-8dfb82ad-954cae33-d7d6ec73_0
2025-12-09T03:43:58.419367Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-09T03:43:58.419366Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, TaskId: 2, PQ sink. ]  SessionId [163830dc-48eb33dc-75397bee-46f62dd7|2067c992-8dfb82ad-954cae33-d7d6ec73_0]  MessageGroupId [163830dc-48eb33dc-75397bee-46f62dd7] Write session: set DirectWriteToPartitionId 0
2025-12-09T03:43:58.419411Z :YDB_SDK INFO: actor.cpp:37: 2025-12-09T03:43:58.419410Z :INFO: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, TaskId: 2, PQ sink. ]  SessionId [163830dc-48eb33dc-75397bee-46f62dd7|2067c992-8dfb82ad-954cae33-d7d6ec73_0]  PartitionId [0]  Generation [0] Get partition location async, partition 0, delay 0.000000s
2025-12-09T03:43:58.419423Z :YDB_SDK TRACE: actor.cpp:37: 2025-12-09T03:43:58.419421Z :TRACE: [local] TRACE_EVENT DescribePartitionRequest  path=local/test_match_recognize[v1-kikimr0]_v1_output partition_id=0
2025-12-09T03:43:58.419458Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-09T03:43:58.419451Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, TaskId: 2, PQ sink. ]  SessionId [163830dc-48eb33dc-75397bee-46f62dd7|2067c992-8dfb82ad-954cae33-d7d6ec73_0]  PartitionId [0]  Generation [0]  Getting partition location, partition 0
2025-12-09T03:43:58.420376Z :YDB_SDK INFO: actor.cpp:37: 2025-12-09T03:43:58.420371Z :INFO: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, TaskId: 2, PQ sink. ]  SessionId [163830dc-48eb33dc-75397bee-46f62dd7|2067c992-8dfb82ad-954cae33-d7d6ec73_0]  PartitionId [0]  Generation [0] Got PartitionLocation response. Status SUCCESS, proto:
partition {
  active: true
  partition_location {
    node_id: 1
    generation: 1
  }
}

2025-12-09T03:43:58.420388Z :YDB_SDK TRACE: actor.cpp:37: 2025-12-09T03:43:58.420385Z :TRACE: [local] TRACE_EVENT DescribePartitionResponse  partition_id=0 active=1 pl_node_id=1 pl_generation=1
2025-12-09T03:43:58.420392Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-09T03:43:58.420391Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, TaskId: 2, PQ sink. ]  SessionId [163830dc-48eb33dc-75397bee-46f62dd7|2067c992-8dfb82ad-954cae33-d7d6ec73_0]  PartitionId [0]  Generation [0] GetPreferredEndpoint: partitionId 0, partitionNodeId 1 exists in the endpoint pool.
2025-12-09T03:43:58.420397Z :YDB_SDK TRACE: actor.cpp:37: 2025-12-09T03:43:58.420396Z :TRACE: [local] TRACE_EVENT PreferredPartitionLocation  Endpoint= NodeId=1 Generation=1
2025-12-09T03:43:58.420400Z :YDB_SDK INFO: actor.cpp:37: 2025-12-09T03:43:58.420399Z :INFO: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, TaskId: 2, PQ sink. ]  SessionId [163830dc-48eb33dc-75397bee-46f62dd7|2067c992-8dfb82ad-954cae33-d7d6ec73_0]  PartitionId [0]  Generation [1] Start write session. Will connect to nodeId: 1
2025-12-09T03:43:58.420589Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-09T03:43:58.420583Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, TaskId: 2, PQ sink. ]  SessionId [163830dc-48eb33dc-75397bee-46f62dd7|2067c992-8dfb82ad-954cae33-d7d6ec73_0]  PartitionId [0]  Generation [1] Write session: OnReadDone gRpcStatusCode: 1, Msg: CANCELLED, Details: , InternalError: 0
2025-12-09T03:43:58.420745Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-09T03:43:58.420741Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, TaskId: 2, PQ sink. ]  SessionId [163830dc-48eb33dc-75397bee-46f62dd7|2067c992-8dfb82ad-954cae33-d7d6ec73_0]  PartitionId [0]  Generation [1] Write session: direct write to partition: 0, generation 1
2025-12-09T03:43:58.420773Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-09T03:43:58.420771Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, TaskId: 2, PQ sink. ]  SessionId [163830dc-48eb33dc-75397bee-46f62dd7|2067c992-8dfb82ad-954cae33-d7d6ec73_0]  PartitionId [0]  Generation [1] Write session: send init request: init_request { path: "test_match_recognize[v1-kikimr0]_v1_output" producer_id: "163830dc-48eb33dc-75397bee-46f62dd7" partition_with_generation { generation: 1 } }
2025-12-09T03:43:58.420777Z :YDB_SDK TRACE: actor.cpp:37: 2025-12-09T03:43:58.420775Z :TRACE: [local] TRACE_EVENT InitRequest  pwg_partition_id=0 pwg_generation=1
2025-12-09T03:43:58.420861Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-09T03:43:58.420859Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, TaskId: 2, PQ sink. ]  SessionId [163830dc-48eb33dc-75397bee-46f62dd7|2067c992-8dfb82ad-954cae33-d7d6ec73_0]  PartitionId [0]  Generation [1] Write session: OnWriteDone gRpcStatusCode: 0
2025-12-09T03:43:58.425243Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-09T03:43:58.425238Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, TaskId: 2, PQ sink. ]  SessionId [163830dc-48eb33dc-75397bee-46f62dd7|2067c992-8dfb82ad-954cae33-d7d6ec73_0]  PartitionId [0]  Generation [1] Write session: OnReadDone gRpcStatusCode: 0
2025-12-09T03:43:58.425268Z :YDB_SDK INFO: actor.cpp:37: 2025-12-09T03:43:58.425265Z :INFO: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, TaskId: 2, PQ sink. ]  SessionId [163830dc-48eb33dc-75397bee-46f62dd7|2067c992-8dfb82ad-954cae33-d7d6ec73_0]  PartitionId [0]  Generation [1] Write session established. Init response: session_id: "163830dc-48eb33dc-75397bee-46f62dd7|855d4d3e-35c91bcd-ea938dcf-ab3d02d1_0"
2025-12-09T03:43:58.425274Z :YDB_SDK TRACE: actor.cpp:37: 2025-12-09T03:43:58.425271Z :TRACE: [local] TRACE_EVENT InitResponse  partition_id=0 session_id=163830dc-48eb33dc-75397bee-46f62dd7|855d4d3e-35c91bcd-ea938dcf-ab3d02d1_0
2025-12-09T03:43:58.425278Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-09T03:43:58.425276Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, TaskId: 2, PQ sink. ]  SessionId [163830dc-48eb33dc-75397bee-46f62dd7|855d4d3e-35c91bcd-ea938dcf-ab3d02d1_0]  PartitionId [0]  Generation [1] Write session: set DirectWriteToPartitionId 0
2025-12-09T03:43:58.425347Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-09T03:43:58.425319Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, TaskId: 2, PQ sink. ]  SessionId [163830dc-48eb33dc-75397bee-46f62dd7|855d4d3e-35c91bcd-ea938dcf-ab3d02d1_0]  PartitionId [0]  Generation [1] Write 1 messages with Id from 1 to 1
2025-12-09T03:43:58.425360Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-09T03:43:58.425359Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, TaskId: 2, PQ sink. ]  SessionId [163830dc-48eb33dc-75397bee-46f62dd7|855d4d3e-35c91bcd-ea938dcf-ab3d02d1_0]  PartitionId [0]  Generation [1] Write session: try to update token
2025-12-09T03:43:58.425369Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-09T03:43:58.425368Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, TaskId: 2, PQ sink. ]  SessionId [163830dc-48eb33dc-75397bee-46f62dd7|855d4d3e-35c91bcd-ea938dcf-ab3d02d1_0]  PartitionId [0]  Generation [1] Send 1 message(s) (0 left), first sequence number is 1
2025-12-09T03:43:58.426697Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-09T03:43:58.426693Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, TaskId: 2, PQ sink. ]  SessionId [163830dc-48eb33dc-75397bee-46f62dd7|855d4d3e-35c91bcd-ea938dcf-ab3d02d1_0]  PartitionId [0]  Generation [1] Write session: OnReadDone gRpcStatusCode: 0
2025-12-09T03:43:58.426733Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-09T03:43:58.426731Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, TaskId: 2, PQ sink. ]  SessionId [163830dc-48eb33dc-75397bee-46f62dd7|855d4d3e-35c91bcd-ea938dcf-ab3d02d1_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-09T03:43:58.426739Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-09T03:43:58.426738Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, TaskId: 2, PQ sink. ]  SessionId [163830dc-48eb33dc-75397bee-46f62dd7|855d4d3e-35c91bcd-ea938dcf-ab3d02d1_0]  PartitionId [0]  Generation [1] OnAck: seqNo=1, txId=?
2025-12-09T03:43:58.426742Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-09T03:43:58.426741Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, TaskId: 2, PQ sink. ]  SessionId [163830dc-48eb33dc-75397bee-46f62dd7|855d4d3e-35c91bcd-ea938dcf-ab3d02d1_0]  PartitionId [0]  Generation [1] Write session: acknoledged message 1
2025-12-09T03:43:58.426822Z :KQP_COMPUTE TRACE: dq_pq_write_actor.cpp:454: SelfId: [1:7581698916230337409:2283], TxId: ptqudqgd4a50qp2jttl4, TaskId: 2, PQ sink. Ack seq no 1
2025-12-09T03:43:58.870086Z :YQL_NODES_MANAGER TRACE: nodes_manager.cpp:318: TNodesManagerActor::NodesHealthCheck
2025-12-09T03:43:58.877135Z :YQL_NODES_MANAGER TRACE: nodes_manager.cpp:389: Send NodeInfo with size: 0 to DynamicNameserver
2025-12-09T03:43:58.878192Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:627: RowDispatcher: Send ping to [1:7581698830330991268:2086]
2025-12-09T03:43:58.878209Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1174: RowDispatcher: TEvPrivate::TEvSendStatistic
2025-12-09T03:43:58.878215Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [1:7581698830330991230:2065]
2025-12-09T03:43:58.878219Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7581698830330991230:2065]
2025-12-09T03:43:58.878221Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [1:7581698830330991230:2065]
2025-12-09T03:43:58.878231Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:633: RowDispatcher: NActors::TEvents::TEvPong
2025-12-09T03:43:58.879213Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: e89fdf35-d81f0194-91266a8b-851ce03f22, Host: ghrun-syjwtgwtdu, Tenant: /compute
2025-12-09T03:43:58.882187Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-09T03:43:58.882198Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-09T03:43:58.918225Z :YQL_PROXY TRACE: log.cpp:64: SessionId:  2025-12-09 03:43:58.918 TRACE ydbd(pid=1646206, tid=0x00007F1C201FE640) [DQ] task_controller_impl.h:271:  [1:7581698911935370102:2281] ExportStats Summary
2025-12-09T03:43:58.918402Z :FQ_PINGER TRACE: pinger.cpp:250: QueryId: ptqudqgd4a50qp2jttl4, Owner: e89fdf35-d81f0194-91266a8b-851ce03f20 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-09T03:43:58.918408Z :FQ_PINGER TRACE: pinger.cpp:393: QueryId: ptqudqgd4a50qp2jttl4, Owner: e89fdf35-d81f0194-91266a8b-851ce03f20 Forward request Private::PingTask
2025-12-09T03:43:58.928899Z :FQ_PINGER TRACE: pinger.cpp:338: QueryId: ptqudqgd4a50qp2jttl4, Owner: e89fdf35-d81f0194-91266a8b-851ce03f20 Ping response success: { action: ABORT expired_at { seconds: 1765251858 nanos: 924000000 } }
2025-12-09T03:43:58.928917Z :FQ_PINGER DEBUG: pinger.cpp:342: QueryId: ptqudqgd4a50qp2jttl4, Owner: e89fdf35-d81f0194-91266a8b-851ce03f20 Query action: ABORT
2025-12-09T03:43:58.928942Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:690: QueryId: ptqudqgd4a50qp2jttl4 New query action received: ABORT
2025-12-09T03:43:58.928948Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:1827: QueryId: ptqudqgd4a50qp2jttl4 Is about to finish query with status ABORTED_BY_USER
2025-12-09T03:43:58.928951Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:1820: QueryId: ptqudqgd4a50qp2jttl4 Write finalizing status: ABORTING_BY_USER
2025-12-09T03:43:58.928961Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:528: QueryId: ptqudqgd4a50qp2jttl4 Cancel running query
2025-12-09T03:43:58.928982Z :FQ_RUN_ACTOR TRACE: run_actor.cpp:880: QueryId: ptqudqgd4a50qp2jttl4 Forward ping response. Success: 1. Cookie: 6
2025-12-09T03:43:58.928991Z :FQ_PINGER TRACE: pinger.cpp:250: QueryId: ptqudqgd4a50qp2jttl4, Owner: e89fdf35-d81f0194-91266a8b-851ce03f20 Forward ping request: { status: ABORTING_BY_USER }
2025-12-09T03:43:58.928994Z :FQ_PINGER TRACE: pinger.cpp:393: QueryId: ptqudqgd4a50qp2jttl4, Owner: e89fdf35-d81f0194-91266a8b-851ce03f20 Forward request Private::PingTask
2025-12-09T03:43:58.929133Z :YQL_PROXY DEBUG: log.cpp:64: SessionId:  2025-12-09 03:43:58.928 DEBUG ydbd(pid=1646206, tid=0x00007F1C201FE640) [DQ] task_controller_impl.h:130: AbortExecution from [1:7581698911935370098:2277]:ABORTED { <main>: Error: ABORTED_BY_USER }
2025-12-09T03:43:58.929152Z :YQL_PROXY DEBUG: log.cpp:64: SessionId:  2025-12-09 03:43:58.929 DEBUG ydbd(pid=1646206, tid=0x00007F1C201FE640) [DQ] task_controller_impl.h:598: OnError { <main>: Error: ABORTED_BY_USER } ABORTED
2025-12-09T03:43:58.929214Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: ptqudqgd4a50qp2jttl4 2025-12-09 03:43:58.929 DEBUG ydbd(pid=1646206, tid=0x00007F1C201FE640) [DQ] executer_actor.cpp:304: {ptqudqgd4a50qp2jttl4} OnFailure, status=4, issues size=1, sender=[1:7581698911935370102:2281]
2025-12-09T03:43:58.929233Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: ptqudqgd4a50qp2jttl4 2025-12-09 03:43:58.929 DEBUG ydbd(pid=1646206, tid=0x00007F1C201FE640) [DQ] executer_actor.cpp:315: {ptqudqgd4a50qp2jttl4} Issues: <main>: Error: ABORTED_BY_USER

2025-12-09T03:43:58.929246Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: ptqudqgd4a50qp2jttl4 2025-12-09 03:43:58.929 DEBUG ydbd(pid=1646206, tid=0x00007F1C201FE640) [DQ] executer_actor.cpp:284: {ptqudqgd4a50qp2jttl4} Finish with status=4 issues=<main>: Error: ABORTED_BY_USER

2025-12-09T03:43:58.929297Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: ptqudqgd4a50qp2jttl4 2025-12-09 03:43:58.929 DEBUG ydbd(pid=1646206, tid=0x00007F1C201FE640) [DQ] executer_actor.cpp:341: {ptqudqgd4a50qp2jttl4} OnQueryResponse status=4 issuses_size=1
2025-12-09T03:43:58.929320Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:1396: QueryId: ptqudqgd4a50qp2jttl4 TEvQueryResponse received on finish
2025-12-09T03:43:58.929325Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:1233: QueryId: ptqudqgd4a50qp2jttl4 Query response CANCELLED. Result set index: 0. Issues count: 1. Rows count: 0
2025-12-09T03:43:58.929435Z :STREAMS_CHECKPOINT_COORDINATOR DEBUG: checkpoint_coordinator.cpp:657: [ptqudqgd4a50qp2jttl4-0.2] PassAway
2025-12-09T03:43:58.929470Z :KQP_COMPUTE ERROR: dq_compute_actor_impl.h:1205: SelfId: [1:7581698911935370107:2284], TxId: ptqudqgd4a50qp2jttl4, task: 1. Ctx: {}. Handle abort execution event from: [1:7581698830330991231:2066], status: UNAVAILABLE, reason: { <main>: Error: Aborted by LWM }
2025-12-09T03:43:58.929485Z :KQP_COMPUTE ERROR: dq_compute_actor_impl.h:1205: SelfId: [1:7581698911935370104:2283], TxId: ptqudqgd4a50qp2jttl4, task: 2. Ctx: {}. Handle abort execution event from: [1:7581698830330991231:2066], status: UNAVAILABLE, reason: { <main>: Error: Aborted by LWM }
2025-12-09T03:43:58.929510Z :KQP_COMPUTE DEBUG: dq_compute_actor_channels.cpp:494: TxId: ptqudqgd4a50qp2jttl4, task: 2. pass away
2025-12-09T03:43:58.929511Z :KQP_COMPUTE DEBUG: dq_compute_actor_channels.cpp:494: TxId: ptqudqgd4a50qp2jttl4, task: 1. pass away
2025-12-09T03:43:58.929531Z :YDB_SDK INFO: actor.cpp:37: 2025-12-09T03:43:58.929526Z :INFO: [local] [local] [9574d711-eea3e517-142b777c-ba3b4156] Closing read session. Close timeout: 0.000000s
2025-12-09T03:43:58.929546Z :YDB_SDK INFO: actor.cpp:37: 2025-12-09T03:43:58.929544Z :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-09T03:43:58.929558Z :YDB_SDK INFO: actor.cpp:37: 2025-12-09T03:43:58.929556Z :INFO: [local] [local] [9574d711-eea3e517-142b777c-ba3b4156] Counters: { Errors: 0 CurrentSessionLifetimeMs: 518 BytesRead: 37 MessagesRead: 1 BytesReadCompressed: 37 BytesInflightUncompressed: 0 BytesInflightCompressed: 0 BytesInflightTotal: 0 MessagesInflight: 0 }
2025-12-09T03:43:58.929573Z :YDB_SDK NOTICE: actor.cpp:37: 2025-12-09T03:43:58.929571Z :NOTICE: [local] [local] [9574d711-eea3e517-142b777c-ba3b4156] Aborting read session. Description: SessionClosed { Status: ABORTED Issues: "<main>: Error: Close with zero timeout " }
2025-12-09T03:43:58.929584Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-09T03:43:58.929582Z :DEBUG: [local] [local] [9574d711-eea3e517-142b777c-ba3b4156] [] Abort session to cluster
2025-12-09T03:43:58.929720Z :YDB_SDK INFO: actor.cpp:37: 2025-12-09T03:43:58.929718Z :INFO: [local] [local] [9574d711-eea3e517-142b777c-ba3b4156] Closing read session. Close timeout: 0.000000s
2025-12-09T03:43:58.929727Z :YDB_SDK INFO: actor.cpp:37: 2025-12-09T03:43:58.929726Z :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-09T03:43:58.929729Z :YDB_SDK INFO: actor.cpp:37: 2025-12-09T03:43:58.929728Z :INFO: [local] [local] [9574d711-eea3e517-142b777c-ba3b4156] Counters: { Errors: 0 CurrentSessionLifetimeMs: 518 BytesRead: 37 MessagesRead: 1 BytesReadCompressed: 37 BytesInflightUncompressed: 0 BytesInflightCompressed: 0 BytesInflightTotal: 0 MessagesInflight: 0 }
2025-12-09T03:43:58.929734Z :YDB_SDK NOTICE: actor.cpp:37: 2025-12-09T03:43:58.929733Z :NOTICE: [local] [local] [9574d711-eea3e517-142b777c-ba3b4156] Aborting read session. Description: SessionClosed { Status: ABORTED Issues: "<main>: Error: Aborted " }
2025-12-09T03:43:58.933545Z :YDB_SDK INFO: actor.cpp:37: 2025-12-09T03:43:58.933539Z :INFO: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, TaskId: 2, PQ sink. ]  SessionId [163830dc-48eb33dc-75397bee-46f62dd7|855d4d3e-35c91bcd-ea938dcf-ab3d02d1_0]  PartitionId [0]  Generation [1] Write session: close. Timeout 0.000000s
2025-12-09T03:43:58.933556Z :YDB_SDK INFO: actor.cpp:37: 2025-12-09T03:43:58.933555Z :INFO: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, TaskId: 2, PQ sink. ]  SessionId [163830dc-48eb33dc-75397bee-46f62dd7|855d4d3e-35c91bcd-ea938dcf-ab3d02d1_0]  PartitionId [0]  Generation [1] Write session will now close
2025-12-09T03:43:58.933568Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-09T03:43:58.933567Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, TaskId: 2, PQ sink. ]  SessionId [163830dc-48eb33dc-75397bee-46f62dd7|855d4d3e-35c91bcd-ea938dcf-ab3d02d1_0]  PartitionId [0]  Generation [1] Write session: aborting
2025-12-09T03:43:58.933762Z :YDB_SDK INFO: actor.cpp:37: 2025-12-09T03:43:58.933760Z :INFO: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, TaskId: 2, PQ sink. ]  SessionId [163830dc-48eb33dc-75397bee-46f62dd7|855d4d3e-35c91bcd-ea938dcf-ab3d02d1_0]  PartitionId [0]  Generation [1] Write session: gracefully shut down, all writes complete
2025-12-09T03:43:58.933783Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-09T03:43:58.933774Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, TaskId: 2, PQ sink. ]  SessionId [163830dc-48eb33dc-75397bee-46f62dd7|855d4d3e-35c91bcd-ea938dcf-ab3d02d1_0]  PartitionId [0]  Generation [1] Write session: OnReadDone gRpcStatusCode: 1, Msg: CANCELLED, Details: , InternalError: 0
2025-12-09T03:43:58.933803Z :YDB_SDK TRACE: actor.cpp:37: 2025-12-09T03:43:58.933801Z :TRACE: [local] TRACE_EVENT Error  status=CLIENT_CANCELLED
2025-12-09T03:43:58.933808Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-09T03:43:58.933807Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, TaskId: 2, PQ sink. ]  SessionId [163830dc-48eb33dc-75397bee-46f62dd7|855d4d3e-35c91bcd-ea938dcf-ab3d02d1_0]  PartitionId [0]  Generation [1] Write session is aborting and will not restart
2025-12-09T03:43:58.933822Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-09T03:43:58.933821Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudqgd4a50qp2jttl4, TaskId: 2, PQ sink. ]  SessionId [163830dc-48eb33dc-75397bee-46f62dd7|855d4d3e-35c91bcd-ea938dcf-ab3d02d1_0]  PartitionId [0]  Generation [1] Write session: destroy
2025-12-09T03:43:58.938049Z :FQ_PINGER TRACE: pinger.cpp:338: QueryId: ptqudqgd4a50qp2jttl4, Owner: e89fdf35-d81f0194-91266a8b-851ce03f20 Ping response success: { action: ABORT expired_at { seconds: 1765251858 nanos: 933000000 } }
2025-12-09T03:43:58.938062Z :FQ_PINGER DEBUG: pinger.cpp:342: QueryId: ptqudqgd4a50qp2jttl4, Owner: e89fdf35-d81f0194-91266a8b-851ce03f20 Query action: ABORT
2025-12-09T03:43:58.938089Z :FQ_RUN_ACTOR TRACE: run_actor.cpp:880: QueryId: ptqudqgd4a50qp2jttl4 Forward ping response. Success: 1. Cookie: 3
2025-12-09T03:43:58.938094Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:887: QueryId: ptqudqgd4a50qp2jttl4 Finalizing status is saved
2025-12-09T03:43:58.938131Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:1507: QueryId: ptqudqgd4a50qp2jttl4 Start rate limiter resource deleter
2025-12-09T03:43:58.938137Z :STREAMS DEBUG: read_rule_deleter.cpp:214: ptqudqgd4a50qp2jttl4: Create read rule deleter actor for `test_match_recognize[v1-kikimr0]_v1_input` [0]
2025-12-09T03:43:58.938158Z :STREAMS DEBUG: read_rule_deleter.cpp:106: ptqudqgd4a50qp2jttl4: Make request for read rule deletion for topic `test_match_recognize[v1-kikimr0]_v1_input` [0]
2025-12-09T03:43:58.973388Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:1498: QueryId: ptqudqgd4a50qp2jttl4 Rate limiter resource deletion finished. Success: 1. Issues: 
2025-12-09T03:43:58.973407Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:1919: QueryId: ptqudqgd4a50qp2jttl4 SendPingAndPassAway, FinalQueryStatus ABORTED_BY_USER
2025-12-09T03:43:58.973442Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:536: QueryId: ptqudqgd4a50qp2jttl4 PassAway
2025-12-09T03:43:58.973581Z :FQ_PINGER TRACE: pinger.cpp:250: QueryId: ptqudqgd4a50qp2jttl4, Owner: e89fdf35-d81f0194-91266a8b-851ce03f20 Forward ping request: { result_id { value: "ptrudqgd3k6tcj3e80r4" } status: ABORTED_BY_USER issues { message: "ABORTED_BY_USER" severity: 1 } statistics: "{\"Graph=0\":{\"Actor\":{\"ActorCreateTimeUs\":{\"sum\":\"52ms\",\"count\":2,\"avg\":\"26ms\",\"max\":\"26ms\",\"min\":\"26ms\"}},\"AllocateWorkersUs\":{\"sum\":\"27ms\",\"count\":1,\"avg\":\"27ms\",\"max\":\"27ms\",\"min\":\"27ms\"},\"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_d0f7bd1b-d9e2-40b6-853d-4861bfa7c5a2/rate_limiter" topic_consumers { database: "local" topic_path: "test_match_recognize[v1-kikimr0]_v1_input" consumer_name: "ptqudqgd4a50qp2jttl4" cluster_endpoint: "localhost:8635" token_name: "cluster:default_myyds" add_bearer_to_token: true } } finished_at { seconds: 1765251838 nanos: 928000000 } }
2025-12-09T03:43:58.973591Z :FQ_PINGER TRACE: pinger.cpp:393: QueryId: ptqudqgd4a50qp2jttl4, Owner: e89fdf35-d81f0194-91266a8b-851ce03f20 Forward request Private::PingTask
2025-12-09T03:43:59.033479Z :FQ_PINGER TRACE: pinger.cpp:338: QueryId: ptqudqgd4a50qp2jttl4, Owner: e89fdf35-d81f0194-91266a8b-851ce03f20 Ping response success: { action: ABORT }
2025-12-09T03:43:59.033510Z :FQ_PINGER DEBUG: pinger.cpp:379: QueryId: ptqudqgd4a50qp2jttl4, Owner: e89fdf35-d81f0194-91266a8b-851ce03f20 Query finished
2025-12-09T03:43:59.033514Z :FQ_PINGER TRACE: pinger.cpp:187: QueryId: ptqudqgd4a50qp2jttl4, Owner: e89fdf35-d81f0194-91266a8b-851ce03f20 Stop Pinger
2025-12-09T03:43:59.879678Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: e89fdf35-d81f0194-91266a8b-851ce03f23, Host: ghrun-syjwtgwtdu, Tenant: /compute
2025-12-09T03:43:59.884522Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-09T03:43:59.884553Z :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:27194: Failed to connect to remote host: Connection refused
<main>: Error: Grpc error response on endpoint ghrun-syjwtgwtdu.auto.internal:27194
2025-12-09T03:44:00.879112Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:627: RowDispatcher: Send ping to [1:7581698830330991268:2086]
2025-12-09T03:44:00.879133Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1174: RowDispatcher: TEvPrivate::TEvSendStatistic
2025-12-09T03:44:00.879142Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [1:7581698830330991230:2065]
2025-12-09T03:44:00.879146Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7581698830330991230:2065]
2025-12-09T03:44:00.879150Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [1:7581698830330991230:2065]
2025-12-09T03:44:00.879158Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:633: RowDispatcher: NActors::TEvents::TEvPong
2025-12-09T03:44:00.880133Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: e89fdf35-d81f0194-91266a8b-851ce03f24, Host: ghrun-syjwtgwtdu, Tenant: /compute
2025-12-09T03:44:00.884788Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-09T03:44:00.884811Z :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:27194: Failed to connect to remote host: Connection refused
<main>: Error: Grpc error response on endpoint ghrun-syjwtgwtdu.auto.internal:27194
2025-12-09T03:44:01.880551Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: e89fdf35-d81f0194-91266a8b-851ce03f25, Host: ghrun-syjwtgwtdu, Tenant: /compute
2025-12-09T03:44:01.885329Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-09T03:44:01.885348Z :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:27194: Failed to connect to remote host: Connection refused
<main>: Error: Grpc error response on endpoint ghrun-syjwtgwtdu.auto.internal:27194
