2025-12-12T12:27:34.918040Z :YQ_TEST_CONNECTION DEBUG: test_connection.cpp:142: Starting yandex query test connection. Actor id: [1:7582947103614901222:2070]
2025-12-12T12:27:34.918233Z :GRPC_SERVER NOTICE: grpc_request_proxy.cpp:380: Grpc request proxy started, nodeid# 1, serve as static node
2025-12-12T12:27:34.918278Z :GRPC_SERVER CRIT: grpc_request_proxy.cpp:440: Failed to deliver subscription request to config dispatcher
2025-12-12T12:27:34.918282Z :GRPC_SERVER NOTICE: grpc_request_proxy.cpp:380: Grpc request proxy started, nodeid# 1, serve as static node
2025-12-12T12:27:34.918297Z :GRPC_SERVER CRIT: grpc_request_proxy.cpp:440: Failed to deliver subscription request to config dispatcher
2025-12-12T12:27:34.918479Z :YQ_RATE_LIMITER INFO: quoter_service.cpp:124: Bootstraping with config: { Enabled: true DataPlaneEnabled: true Database { Endpoint: "localhost:25827" Database: "local" TablePrefix: "RateLimiter_1fb303ed-ed93-4034-ace4-b066e21a3ab1" } Limiters { CoordinationNodePath: "rate_limiter" } }
2025-12-12T12:27:34.918490Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 8f71b000-7466b0e9-41997d65-a6f433e61, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:34.918979Z :FQ_QUOTA_PROXY INFO: quota_proxy.cpp:90: STARTED
2025-12-12T12:27:34.919021Z :FQ_LOG_UPDATER DEBUG: log.cpp:93: Updated YQL logs priority: 8
2025-12-12T12:27:34.919026Z :FQ_LOG_UPDATER CRIT: log.cpp:55: Failed to deliver subscription request to config dispatcher.
2025-12-12T12:27:34.919067Z :STREAMS_STORAGE_SERVICE INFO: storage_proxy.cpp:214: Bootstrap
2025-12-12T12:27:34.919069Z :STREAMS_STORAGE_SERVICE INFO: storage_proxy.cpp:217: Create sdk ydb connection
2025-12-12T12:27:34.919197Z :STREAMS_STORAGE_SERVICE INFO: storage_proxy.cpp:239: Successfully bootstrapped TStorageProxy [1:7582947103614901216:2064] with connection to localhost:25827:local
2025-12-12T12:27:34.919206Z :FQ_ROW_DISPATCHER DEBUG: row_dispatcher.cpp:544: RowDispatcher: Successfully bootstrapped row dispatcher, id [1:7582947103614901217:2065], tenant /compute
2025-12-12T12:27:34.919217Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7582947103614901217:2065]
2025-12-12T12:27:34.919219Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:329: Coordinator: Add new row dispatcher to map (state 1)
2025-12-12T12:27:34.919243Z :FQ_QUOTA_SERVICE INFO: quota_manager.cpp:196: STARTED
2025-12-12T12:27:34.919307Z :YQL_NODES_MANAGER INFO: nodes_manager.cpp:88: Bootstrap, InstanceId: cbea4aea-4b282d6f-f20607bb-2fc73250
2025-12-12T12:27:34.919309Z :YQL_NODES_MANAGER DEBUG: nodes_manager.cpp:310: TNodesManagerActor::ResolveSelfAddress
2025-12-12T12:27:34.919382Z :FQ_ROW_DISPATCHER DEBUG: coordinator.cpp:293: Coordinator: Successfully bootstrapped coordinator, id [1:7582947103614901262:2093], NodesManagerId [0:4705493345362661702:78], rebalancing timeout 5.000000s
2025-12-12T12:27:34.919407Z :FQ_ROW_DISPATCHER DEBUG: leader_election.cpp:232: TLeaderElection [1:7582947103614901265:2096] Successfully bootstrapped, local coordinator id [1:7582947103614901262:2093], tenant id compute, local mode 0, coordination node path local/compute, endpoint localhost:25827
2025-12-12T12:27:34.919765Z :SCHEME_BOARD_SUBSCRIBER NOTICE: subscriber.cpp:849: [main][1:7582947103614901238:2081][/compute] Set up state: owner# [1:7582947103614901194:2052], state# { Deleted: 1 Strong: 0 Version: <Invalid> DomainId: <Invalid> AbandonedSchemeShards: there are 0 elements }
2025-12-12T12:27:34.919780Z :SCHEME_BOARD_SUBSCRIBER NOTICE: subscriber.cpp:849: [main][1:7582947103614901240:2083][/compute] Set up state: owner# [1:7582947103614901195:2053], state# { Deleted: 1 Strong: 0 Version: <Invalid> DomainId: <Invalid> AbandonedSchemeShards: there are 0 elements }
2025-12-12T12:27:34.919785Z :MEMORY_PROFILER NOTICE: monitor.cpp:332: Bootstrapped
2025-12-12T12:27:34.919787Z :GRPC_SERVER WARN: grpc_request_proxy.cpp:583: SchemeBoardDelete /compute Strong=0
2025-12-12T12:27:34.919789Z :GRPC_SERVER WARN: grpc_request_proxy.cpp:583: SchemeBoardDelete /compute Strong=0
2025-12-12T12:27:34.919869Z :FQ_ROW_DISPATCHER DEBUG: row_dispatcher.cpp:637: RowDispatcher: TEvCoordinatorChangesSubscribe from [1:7582947103614901262:2093]
2025-12-12T12:27:34.919876Z :SCHEME_BOARD_SUBSCRIBER NOTICE: subscriber.cpp:849: [main][1:7582947103614901239:2082][/Root] Set up state: owner# [1:7582947103614901195:2053], state# { Deleted: 1 Strong: 0 Version: <Invalid> DomainId: <Invalid> AbandonedSchemeShards: there are 0 elements }
2025-12-12T12:27:34.919878Z :SCHEME_BOARD_SUBSCRIBER NOTICE: subscriber.cpp:849: [main][1:7582947103614901237:2080][/Root] Set up state: owner# [1:7582947103614901194:2052], state# { Deleted: 1 Strong: 0 Version: <Invalid> DomainId: <Invalid> AbandonedSchemeShards: there are 0 elements }
2025-12-12T12:27:34.919882Z :GRPC_SERVER WARN: grpc_request_proxy.cpp:583: SchemeBoardDelete /Root Strong=0
2025-12-12T12:27:34.919884Z :GRPC_SERVER WARN: grpc_request_proxy.cpp:583: SchemeBoardDelete /Root Strong=0
2025-12-12T12:27:34.920166Z :YQL_NODES_MANAGER TRACE: nodes_manager.cpp:318: TNodesManagerActor::NodesHealthCheck
2025-12-12T12:27:34.921222Z :FQ_ROW_DISPATCHER DEBUG: schema.cpp:71: Run create coordination node "local/compute" actor
2025-12-12T12:27:34.921230Z :FQ_ROW_DISPATCHER DEBUG: schema.cpp:113: Call create coordination node "local/compute"
2025-12-12T12:27:34.921232Z :FQ_ROW_DISPATCHER DEBUG: schema.cpp:411: Call create coordination node "local/compute"
2025-12-12T12:27:34.929021Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:34.929044Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:34.932348Z :YQL_NODES_MANAGER TRACE: nodes_manager.cpp:389: Send NodeInfo with size: 0 to DynamicNameserver
2025-12-12T12:27:34.933776Z :FQ_ROW_DISPATCHER DEBUG: schema.cpp:155: Successfully created coordination node "local/compute"
2025-12-12T12:27:34.933793Z :FQ_ROW_DISPATCHER DEBUG: schema.cpp:122: Reply for create coordination node "local/compute": { <main>: Error: Check failed: path: '/local/compute', error: path exist, request accepts it (id: [OwnerId: 72057594046678944, LocalPathId: 19], type: EPathTypeKesus, state: EPathStateNoChanges), source_location: ydb/core/tx/schemeshard/schemeshard__operation_create_kesus.cpp:339 }
2025-12-12T12:27:34.933807Z :FQ_ROW_DISPATCHER DEBUG: leader_election.cpp:345: TLeaderElection [1:7582947103614901265:2096] Coordination node successfully created
2025-12-12T12:27:34.933810Z :FQ_ROW_DISPATCHER DEBUG: leader_election.cpp:323: TLeaderElection [1:7582947103614901265:2096] Start session
2025-12-12T12:27:34.935598Z :FQ_ROW_DISPATCHER DEBUG: leader_election.cpp:359: TLeaderElection [1:7582947103614901265:2096] Session successfully created
2025-12-12T12:27:34.937413Z :FQ_ROW_DISPATCHER DEBUG: leader_election.cpp:372: TLeaderElection [1:7582947103614901265:2096] Semaphore successfully created
2025-12-12T12:27:34.937422Z :FQ_ROW_DISPATCHER DEBUG: leader_election.cpp:304: TLeaderElection [1:7582947103614901265:2096] Try to acquire semaphore
2025-12-12T12:27:34.937544Z :FQ_ROW_DISPATCHER DEBUG: leader_election.cpp:420: TLeaderElection [1:7582947103614901265:2096] Describe semaphore
2025-12-12T12:27:34.939511Z :FQ_ROW_DISPATCHER DEBUG: leader_election.cpp:386: TLeaderElection [1:7582947103614901265:2096] Semaphore successfully acquired
2025-12-12T12:27:34.939583Z :FQ_ROW_DISPATCHER DEBUG: leader_election.cpp:469: TLeaderElection [1:7582947103614901265:2096] Semaphore successfully described: coordinator id [1:7582947103614901262:2093] generation 8
2025-12-12T12:27:34.939597Z :FQ_ROW_DISPATCHER INFO: leader_election.cpp:471: TLeaderElection [1:7582947103614901265:2096] Send TEvCoordinatorChanged to [1:7582947103614901217:2065], new coordinator id [1:7582947103614901262:2093], previous coordinator id [0:0:0]
2025-12-12T12:27:34.939620Z :FQ_ROW_DISPATCHER DEBUG: row_dispatcher.cpp:569: RowDispatcher: Coordinator changed, old leader (empty maybe), new [1:7582947103614901262:2093] generation 8
2025-12-12T12:27:34.939630Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [1:7582947103614901217:2065]
2025-12-12T12:27:34.939633Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7582947103614901217:2065]
2025-12-12T12:27:34.939637Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [1:7582947103614901217:2065]
2025-12-12T12:27:34.939646Z :FQ_ROW_DISPATCHER DEBUG: coordinator.cpp:440: Coordinator: New leader [1:7582947103614901262:2093], SelfId [1:7582947103614901262:2093]
2025-12-12T12:27:34.939649Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:633: RowDispatcher: NActors::TEvents::TEvPong
2025-12-12T12:27:35.917038Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 8f71b000-7466b0e9-41997d65-a6f433e62, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:35.920766Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:35.920775Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:36.916438Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:627: RowDispatcher: Send ping to [1:7582947103614901262:2093]
2025-12-12T12:27:36.916459Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1174: RowDispatcher: TEvPrivate::TEvSendStatistic
2025-12-12T12:27:36.916467Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [1:7582947103614901217:2065]
2025-12-12T12:27:36.916470Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7582947103614901217:2065]
2025-12-12T12:27:36.916473Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [1:7582947103614901217:2065]
2025-12-12T12:27:36.916481Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:633: RowDispatcher: NActors::TEvents::TEvPong
2025-12-12T12:27:36.917467Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 8f71b000-7466b0e9-41997d65-a6f433e63, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:36.921545Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:36.921556Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:37.917918Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 8f71b000-7466b0e9-41997d65-a6f433e64, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:37.921736Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:37.921747Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:38.917321Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:627: RowDispatcher: Send ping to [1:7582947103614901262:2093]
2025-12-12T12:27:38.917342Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1174: RowDispatcher: TEvPrivate::TEvSendStatistic
2025-12-12T12:27:38.917353Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [1:7582947103614901217:2065]
2025-12-12T12:27:38.917358Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7582947103614901217:2065]
2025-12-12T12:27:38.917361Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [1:7582947103614901217:2065]
2025-12-12T12:27:38.917372Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:633: RowDispatcher: NActors::TEvents::TEvPong
2025-12-12T12:27:38.918354Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 8f71b000-7466b0e9-41997d65-a6f433e65, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:38.922093Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:38.922104Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:39.916769Z :YQL_NODES_MANAGER TRACE: nodes_manager.cpp:318: TNodesManagerActor::NodesHealthCheck
2025-12-12T12:27:39.916781Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:665: Coordinator: Change global state to Started (by timeout)
2025-12-12T12:27:39.918838Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 8f71b000-7466b0e9-41997d65-a6f433e66, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:39.923216Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:39.923227Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:39.927636Z :YQL_NODES_MANAGER TRACE: nodes_manager.cpp:389: Send NodeInfo with size: 0 to DynamicNameserver
2025-12-12T12:27:40.918238Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:627: RowDispatcher: Send ping to [1:7582947103614901262:2093]
2025-12-12T12:27:40.918257Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1174: RowDispatcher: TEvPrivate::TEvSendStatistic
2025-12-12T12:27:40.918263Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [1:7582947103614901217:2065]
2025-12-12T12:27:40.918266Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7582947103614901217:2065]
2025-12-12T12:27:40.918269Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [1:7582947103614901217:2065]
2025-12-12T12:27:40.918279Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:633: RowDispatcher: NActors::TEvents::TEvPong
2025-12-12T12:27:40.919257Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 8f71b000-7466b0e9-41997d65-a6f433e67, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:40.923107Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:40.923119Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:41.919675Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 8f71b000-7466b0e9-41997d65-a6f433e68, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:41.925434Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:41.925448Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:42.919135Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:627: RowDispatcher: Send ping to [1:7582947103614901262:2093]
2025-12-12T12:27:42.919160Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1174: RowDispatcher: TEvPrivate::TEvSendStatistic
2025-12-12T12:27:42.919167Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [1:7582947103614901217:2065]
2025-12-12T12:27:42.919171Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7582947103614901217:2065]
2025-12-12T12:27:42.919174Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [1:7582947103614901217:2065]
2025-12-12T12:27:42.919184Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:633: RowDispatcher: NActors::TEvents::TEvPong
2025-12-12T12:27:42.920147Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 8f71b000-7466b0e9-41997d65-a6f433e69, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:42.924846Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:42.924853Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:43.920620Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 8f71b000-7466b0e9-41997d65-a6f433e610, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:43.925507Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:43.925522Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:44.916947Z :FQ_ROW_DISPATCHER DEBUG: coordinator.cpp:599: Coordinator: Send TEvGetNodesRequest to NodesManager
2025-12-12T12:27:44.916970Z :YQL_NODES_MANAGER TRACE: nodes_manager.cpp:318: TNodesManagerActor::NodesHealthCheck
2025-12-12T12:27:44.917198Z :YQL_NODES_MANAGER TRACE: nodes_manager.cpp:300: Received TNodesManagerActor::TEvGetNodesRequest
2025-12-12T12:27:44.917214Z :FQ_ROW_DISPATCHER INFO: coordinator.cpp:690: Coordinator: Updated node info, node count: 1
2025-12-12T12:27:44.920020Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:627: RowDispatcher: Send ping to [1:7582947103614901262:2093]
2025-12-12T12:27:44.920035Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1174: RowDispatcher: TEvPrivate::TEvSendStatistic
2025-12-12T12:27:44.920040Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [1:7582947103614901217:2065]
2025-12-12T12:27:44.920043Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7582947103614901217:2065]
2025-12-12T12:27:44.920046Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [1:7582947103614901217:2065]
2025-12-12T12:27:44.920054Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:633: RowDispatcher: NActors::TEvents::TEvPong
2025-12-12T12:27:44.921038Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 8f71b000-7466b0e9-41997d65-a6f433e611, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:44.924659Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:44.924669Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:44.925062Z :YQL_NODES_MANAGER TRACE: nodes_manager.cpp:389: Send NodeInfo with size: 0 to DynamicNameserver
2025-12-12T12:27:45.921535Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 8f71b000-7466b0e9-41997d65-a6f433e612, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:45.927083Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:45.927095Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:46.920935Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:627: RowDispatcher: Send ping to [1:7582947103614901262:2093]
2025-12-12T12:27:46.920959Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1174: RowDispatcher: TEvPrivate::TEvSendStatistic
2025-12-12T12:27:46.920966Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [1:7582947103614901217:2065]
2025-12-12T12:27:46.920970Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7582947103614901217:2065]
2025-12-12T12:27:46.920972Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [1:7582947103614901217:2065]
2025-12-12T12:27:46.920984Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:633: RowDispatcher: NActors::TEvents::TEvPong
2025-12-12T12:27:46.921959Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 8f71b000-7466b0e9-41997d65-a6f433e613, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:46.929059Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:46.929076Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:47.922405Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 8f71b000-7466b0e9-41997d65-a6f433e614, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:47.927142Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:47.927157Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:48.921829Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:627: RowDispatcher: Send ping to [1:7582947103614901262:2093]
2025-12-12T12:27:48.921869Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1174: RowDispatcher: TEvPrivate::TEvSendStatistic
2025-12-12T12:27:48.921878Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [1:7582947103614901217:2065]
2025-12-12T12:27:48.921882Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7582947103614901217:2065]
2025-12-12T12:27:48.921885Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [1:7582947103614901217:2065]
2025-12-12T12:27:48.921897Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:633: RowDispatcher: NActors::TEvents::TEvPong
2025-12-12T12:27:48.922875Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 8f71b000-7466b0e9-41997d65-a6f433e615, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:48.927212Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:48.927232Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:49.917160Z :YQL_NODES_MANAGER TRACE: nodes_manager.cpp:318: TNodesManagerActor::NodesHealthCheck
2025-12-12T12:27:49.923346Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 8f71b000-7466b0e9-41997d65-a6f433e616, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:49.927185Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:49.927207Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:49.927484Z :YQL_NODES_MANAGER TRACE: nodes_manager.cpp:389: Send NodeInfo with size: 0 to DynamicNameserver
2025-12-12T12:27:50.922666Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:627: RowDispatcher: Send ping to [1:7582947103614901262:2093]
2025-12-12T12:27:50.922683Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1174: RowDispatcher: TEvPrivate::TEvSendStatistic
2025-12-12T12:27:50.922689Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [1:7582947103614901217:2065]
2025-12-12T12:27:50.922694Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7582947103614901217:2065]
2025-12-12T12:27:50.922697Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [1:7582947103614901217:2065]
2025-12-12T12:27:50.922707Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:633: RowDispatcher: NActors::TEvents::TEvPong
2025-12-12T12:27:50.923756Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 8f71b000-7466b0e9-41997d65-a6f433e617, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:50.934770Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:50.934782Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:51.924235Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 8f71b000-7466b0e9-41997d65-a6f433e618, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:51.931925Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:51.931938Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:52.923607Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:627: RowDispatcher: Send ping to [1:7582947103614901262:2093]
2025-12-12T12:27:52.923632Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1174: RowDispatcher: TEvPrivate::TEvSendStatistic
2025-12-12T12:27:52.923638Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [1:7582947103614901217:2065]
2025-12-12T12:27:52.923641Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7582947103614901217:2065]
2025-12-12T12:27:52.923644Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [1:7582947103614901217:2065]
2025-12-12T12:27:52.923653Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:633: RowDispatcher: NActors::TEvents::TEvPong
2025-12-12T12:27:52.925118Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 8f71b000-7466b0e9-41997d65-a6f433e619, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:52.933065Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:52.933076Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:53.925654Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 8f71b000-7466b0e9-41997d65-a6f433e620, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:53.975257Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:53.975270Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 1
2025-12-12T12:27:53.975483Z :FQ_PENDING_FETCHER DEBUG: pending_fetcher.cpp:361: NewTask: Scope: yandexcloud://my_folder Id: ptqudq7uem53kjjhdml0 UserId: root@builtin AuthToken: **** (B6C6F477)
2025-12-12T12:27:53.975638Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 8f71b000-7466b0e9-41997d65-a6f433e621, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:53.975896Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:375: QueryId: ptqudq7uem53kjjhdml0 Start run actor. Compute state: RUNNING
2025-12-12T12:27:53.975898Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:469: QueryId: ptqudq7uem53kjjhdml0 FillConnections
2025-12-12T12:27:53.975930Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:2333: QueryId: ptqudq7uem53kjjhdml0 Run actors params: { QueryId: ptqudq7uem53kjjhdml0 CloudId: mock_cloud UserId: root@builtin Owner: 8f71b000-7466b0e9-41997d65-a6f433e620 PreviousQueryRevision: 2 Connections: 1 Bindings: 0 AccountIdSignatures: 0 QueryType: STREAMING ExecuteMode: RUN ResultId: ptrudq7ue01e8skng8d6 StateLoadMode: FROM_LAST_CHECKPOINT StreamingDisposition: { from_last_checkpoint { } } Status: RUNNING DqGraphs: 1 DqGraphIndex: 0 Resource.TopicConsumers: 1 }
2025-12-12T12:27:53.975990Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:911: QueryId: ptqudq7uem53kjjhdml0 Overall dq tasks: 2
2025-12-12T12:27:53.976127Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:1598: QueryId: ptqudq7uem53kjjhdml0 ResultWriter was NOT CREATED since ResultType is empty
2025-12-12T12:27:53.976198Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: ptqudq7uem53kjjhdml0 2025-12-12 12:27:53.976 DEBUG ydbd(pid=1214775, tid=0x00007F4DE262D640) [DQ] task_controller_impl.h:86: _RowsLimitPerWrite = 0
2025-12-12T12:27:53.976246Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:1652: QueryId: ptqudq7uem53kjjhdml0 Executer: [1:7582947185219280079:2271], Controller: [1:7582947185219280081:2273], ResultIdActor: [1:7582947185219280079:2271]
2025-12-12T12:27:53.976261Z :FQ_PINGER TRACE: pinger.cpp:171: QueryId: ptqudq7uem53kjjhdml0, Owner: 8f71b000-7466b0e9-41997d65-a6f433e620 Start Pinger
2025-12-12T12:27:53.976397Z :FQ_PINGER TRACE: pinger.cpp:250: QueryId: ptqudq7uem53kjjhdml0, Owner: 8f71b000-7466b0e9-41997d65-a6f433e620 Forward ping request: { resources { rate_limiter: READY compilation: READY topic_consumers_state: READY rate_limiter_path: "local/RateLimiter_1fb303ed-ed93-4034-ace4-b066e21a3ab1/rate_limiter" topic_consumers { database: "local" topic_path: "test_time_order_recoverer[v1-kikimr0]_v1_input" consumer_name: "ptqudq7uem53kjjhdml0" cluster_endpoint: "localhost:25827" token_name: "cluster:default_myyds" add_bearer_to_token: true } } }
2025-12-12T12:27:53.976400Z :FQ_PINGER TRACE: pinger.cpp:393: QueryId: ptqudq7uem53kjjhdml0, Owner: 8f71b000-7466b0e9-41997d65-a6f433e620 Forward request Private::PingTask
2025-12-12T12:27:53.976583Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: ptqudq7uem53kjjhdml0 2025-12-12 12:27:53.976 DEBUG ydbd(pid=1214775, tid=0x00007F4DE262D640) [DQ] executer_actor.cpp:140: {ptqudq7uem53kjjhdml0} TDqExecuter::OnGraph
2025-12-12T12:27:53.976597Z :YQL_PROXY INFO: log.cpp:64: SessionId: ptqudq7uem53kjjhdml0 2025-12-12 12:27:53.976 INFO  ydbd(pid=1214775, tid=0x00007F4DE262D640) [DQ] executer_actor.cpp:157: {ptqudq7uem53kjjhdml0} Trying to allocate 2 workers [EnableComputeActor=1]
2025-12-12T12:27:53.977594Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: ptqudq7uem53kjjhdml0 2025-12-12 12:27:53.977 DEBUG ydbd(pid=1214775, tid=0x00007F4DE262D640) [DQ] executer_actor.cpp:247: {ptqudq7uem53kjjhdml0} Dq timeouts are set to: 0.000000s (global), 600.000000s (workers allocation fail), 30.000000s (workers allocation warn) 
2025-12-12T12:27:53.978200Z :YQL_NODES_MANAGER DEBUG: nodes_manager.cpp:125: TEvAllocateWorkersResponse Nodes {
  ResourceId: 4294967297
  Worker {
    NodeId: 1
    Guid: "cbea4aea-4b282d6f-f20607bb-2fc73250,ghrun-fhkyrtz6p4"
  }
  Worker {
    NodeId: 1
    Guid: "cbea4aea-4b282d6f-f20607bb-2fc73250,ghrun-fhkyrtz6p4"
  }
}
2025-12-12T12:27:53.987308Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:53.987317Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:54.012067Z :FQ_PINGER TRACE: pinger.cpp:338: QueryId: ptqudq7uem53kjjhdml0, Owner: 8f71b000-7466b0e9-41997d65-a6f433e620 Ping response success: { expired_at { seconds: 1765542493 nanos: 991000000 } }
2025-12-12T12:27:54.012129Z :FQ_RUN_ACTOR TRACE: run_actor.cpp:861: QueryId: ptqudq7uem53kjjhdml0 Forward ping response. Success: 1. Cookie: 0
2025-12-12T12:27:54.043660Z :KQP_COMPUTE DEBUG: dq_compute_actor_impl.h:144: SelfId: [1:7582947189514247379:2275], TxId: ptqudq7uem53kjjhdml0, task: 2. Ctx: {}. Start compute actor [1:7582947189514247379:2275], task: 2
2025-12-12T12:27:54.043709Z :KQP_COMPUTE DEBUG: dq_async_compute_actor.cpp:114: SelfId: [1:7582947189514247379:2275], TxId: ptqudq7uem53kjjhdml0, task: 2. Ctx: {}. Use CPU quota: 1. Rate limiter resource: { "local/RateLimiter_1fb303ed-ed93-4034-ace4-b066e21a3ab1/rate_limiter", "mock_cloud/my_folder/ptqudq7uem53kjjhdml0" }
2025-12-12T12:27:54.043789Z :KQP_COMPUTE DEBUG: dq_compute_actor_impl.h:144: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Start compute actor [1:7582947189514247382:2276], task: 1
2025-12-12T12:27:54.043813Z :KQP_COMPUTE DEBUG: dq_async_compute_actor.cpp:114: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Use CPU quota: 1. Rate limiter resource: { "local/RateLimiter_1fb303ed-ed93-4034-ace4-b066e21a3ab1/rate_limiter", "mock_cloud/my_folder/ptqudq7uem53kjjhdml0" }
2025-12-12T12:27:54.043836Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: ptqudq7uem53kjjhdml0 2025-12-12 12:27:54.043 DEBUG ydbd(pid=1214775, tid=0x00007F4DDFE28640) [DQ] executer_actor.cpp:358: {ptqudq7uem53kjjhdml0} TDqExecuter::TEvAllocateWorkersResponse
2025-12-12T12:27:54.043846Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: ptqudq7uem53kjjhdml0 2025-12-12 12:27:54.043 DEBUG ydbd(pid=1214775, tid=0x00007F4DDFE28640) [DQ] executer_actor.cpp:384: {ptqudq7uem53kjjhdml0} Allocated resource 4294967297
2025-12-12T12:27:54.043880Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: 8f71b000-7466b0e9-41997d65-a6f433e6 2025-12-12 12:27:54.043 DEBUG ydbd(pid=1214775, tid=0x00007F4DE162B640) [DQ] tasks_runner_local.cpp:267: {TODO/2} Build task: 2
2025-12-12T12:27:54.043890Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: ptqudq7uem53kjjhdml0 2025-12-12 12:27:54.043 DEBUG ydbd(pid=1214775, tid=0x00007F4DDFE28640) [DQ] executer_actor.cpp:401: {ptqudq7uem53kjjhdml0} WorkerInfo: Id:cbea4aea-4b282d6f-f20607bb-2fc73250,ghrun-fhkyrtz6p4,NodeId:1,StageId:204663
2025-12-12T12:27:54.043911Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: ptqudq7uem53kjjhdml0 2025-12-12 12:27:54.043 DEBUG ydbd(pid=1214775, tid=0x00007F4DDFE28640) [DQ] executer_actor.cpp:402: {ptqudq7uem53kjjhdml0} TaskInfo: 0/1
2025-12-12T12:27:54.043923Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: ptqudq7uem53kjjhdml0 2025-12-12 12:27:54.043 DEBUG ydbd(pid=1214775, tid=0x00007F4DDFE28640) [DQ] executer_actor.cpp:404: {ptqudq7uem53kjjhdml0}  ObjectId: 88a034dc314301cb1522a933e690a4c49a7591e8, dq_vanilla_job.lite, 
2025-12-12T12:27:54.043945Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: ptqudq7uem53kjjhdml0 2025-12-12 12:27:54.043 DEBUG ydbd(pid=1214775, tid=0x00007F4DDFE28640) [DQ] executer_actor.cpp:401: {ptqudq7uem53kjjhdml0} WorkerInfo: Id:cbea4aea-4b282d6f-f20607bb-2fc73250,ghrun-fhkyrtz6p4,NodeId:1,StageId:204683
2025-12-12T12:27:54.043956Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: ptqudq7uem53kjjhdml0 2025-12-12 12:27:54.043 DEBUG ydbd(pid=1214775, tid=0x00007F4DDFE28640) [DQ] executer_actor.cpp:402: {ptqudq7uem53kjjhdml0} TaskInfo: 1/2
2025-12-12T12:27:54.043961Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: ptqudq7uem53kjjhdml0 2025-12-12 12:27:54.043 DEBUG ydbd(pid=1214775, tid=0x00007F4DDFE28640) [DQ] executer_actor.cpp:404: {ptqudq7uem53kjjhdml0}  ObjectId: 88a034dc314301cb1522a933e690a4c49a7591e8, dq_vanilla_job.lite, 
2025-12-12T12:27:54.043987Z :YQL_PROXY INFO: log.cpp:64: SessionId: ptqudq7uem53kjjhdml0 2025-12-12 12:27:54.043 INFO  ydbd(pid=1214775, tid=0x00007F4DDFE28640) [DQ] executer_actor.cpp:415: {ptqudq7uem53kjjhdml0} 2 workers allocated
2025-12-12T12:27:54.044100Z :YQL_PROXY TRACE: log.cpp:64: SessionId:  2025-12-12 12:27:54.044 TRACE ydbd(pid=1214775, tid=0x00007F4DDFE28640) [DQ] task_controller_impl.h:271:  [1:7582947185219280081:2273] ExportStats Summary
2025-12-12T12:27:54.044105Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: 8f71b000-7466b0e9-41997d65-a6f433e6 2025-12-12 12:27:54.044 DEBUG ydbd(pid=1214775, tid=0x00007F4DE162B640) [DQ] tasks_runner_local.cpp:267: {TODO/2} task: 2, program size: 420, llvm: ``.
2025-12-12T12:27:54.044132Z :YQL_PROXY DEBUG: log.cpp:64: SessionId:  2025-12-12 12:27:54.044 DEBUG ydbd(pid=1214775, tid=0x00007F4DDFE28640) [DQ] task_controller_impl.h:526: Ready State: [1:7582947185219280081:2273]
2025-12-12T12:27:54.044144Z :YQL_PROXY DEBUG: log.cpp:64: SessionId:  2025-12-12 12:27:54.044 DEBUG ydbd(pid=1214775, tid=0x00007F4DDFE28640) [DQ] task_controller_impl.h:537: Forward: [1:7582947185219280081:2273] to [1:7582947185219280080:2272]
2025-12-12T12:27:54.044186Z :STREAMS_CHECKPOINT_COORDINATOR DEBUG: checkpoint_coordinator.cpp:70: [ptqudq7uem53kjjhdml0-0.2] TEvReadyState, streaming disposition { from_last_checkpoint { } }, state load mode FROM_LAST_CHECKPOINT, checkpointing period 1.000000s
2025-12-12T12:27:54.044203Z :STREAMS_CHECKPOINT_COORDINATOR DEBUG: checkpoint_coordinator.cpp:104: [ptqudq7uem53kjjhdml0-0.2] AllActors count: 2, ActorsToTrigger count: 1, ActorsToNotify count: 2, ActorsToWaitFor count: 2
2025-12-12T12:27:54.044204Z :STREAMS_CHECKPOINT_COORDINATOR DEBUG: checkpoint_coordinator.cpp:114: [ptqudq7uem53kjjhdml0-0.2] Send TEvRegisterCoordinatorRequest
2025-12-12T12:27:54.044212Z :STREAMS_STORAGE_SERVICE DEBUG: storage_proxy.cpp:261: [ptqudq7uem53kjjhdml0-0.2] Got TEvRegisterCoordinatorRequest
2025-12-12T12:27:54.044214Z :STREAMS_STORAGE_SERVICE INFO: storage_proxy.cpp:243: StartInitialization, EnableSecureScriptExecutions: 0
2025-12-12T12:27:54.047699Z :STREAMS_STORAGE_SERVICE NOTICE: storage_proxy.cpp:585: Add to delayed
2025-12-12T12:27:54.059924Z :STREAMS_STORAGE_SERVICE INFO: storage_proxy.cpp:557: Checkpoint storage and state storage were successfully initted
2025-12-12T12:27:54.059955Z :STREAMS_STORAGE_SERVICE DEBUG: storage_proxy.cpp:261: [ptqudq7uem53kjjhdml0-0.2] Got TEvRegisterCoordinatorRequest
2025-12-12T12:27:54.083859Z :STREAMS_STORAGE_SERVICE INFO: storage_proxy.cpp:279: [ptqudq7uem53kjjhdml0-0.2] Graph registered
2025-12-12T12:27:54.083879Z :STREAMS_STORAGE_SERVICE DEBUG: storage_proxy.cpp:281: [ptqudq7uem53kjjhdml0-0.2] Send TEvRegisterCoordinatorResponse
2025-12-12T12:27:54.083914Z :STREAMS_CHECKPOINT_COORDINATOR DEBUG: checkpoint_coordinator.cpp:131: [ptqudq7uem53kjjhdml0-0.2] Got TEvRegisterCoordinatorResponse; issues: 
2025-12-12T12:27:54.083918Z :STREAMS_CHECKPOINT_COORDINATOR DEBUG: checkpoint_coordinator.cpp:140: [ptqudq7uem53kjjhdml0-0.2] Successfully registered in storage
2025-12-12T12:27:54.083923Z :STREAMS_CHECKPOINT_COORDINATOR INFO: checkpoint_coordinator.cpp:141: [ptqudq7uem53kjjhdml0-0.2] Send TEvNewCheckpointCoordinator to 2 actor(s)
2025-12-12T12:27:54.083933Z :STREAMS_CHECKPOINT_COORDINATOR INFO: checkpoint_coordinator.cpp:149: [ptqudq7uem53kjjhdml0-0.2] Send TEvGetCheckpointsMetadataRequest; state load mode: FROM_LAST_CHECKPOINT; load graph: 0
2025-12-12T12:27:54.083943Z :STREAMS_STORAGE_SERVICE DEBUG: storage_proxy.cpp:434: [ptqudq7uem53kjjhdml0-0] Got TEvGetCheckpointsMetadataRequest
2025-12-12T12:27:54.108310Z :KQP_COMPUTE DEBUG: dq_compute_actor_checkpoints.cpp:197: [] Task: 1. Got TEvNewCheckpointCoordinator event: generation 2, actorId: [1:7582947185219280080:2272]
2025-12-12T12:27:54.108325Z :KQP_COMPUTE TRACE: dq_compute_actor_checkpoints.cpp:208: [] Task: 1. Assign checkpoint coordinator (generation = 2)
2025-12-12T12:27:54.109073Z :KQP_COMPUTE DEBUG: dq_compute_actor_impl.h:1360: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Create source for input 0 { Source { Type: "PqSource" Settings { type_url: "type.googleapis.com/NYql.NPq.NProto.TDqPqTopicSource" value: "\n.test_time_order_recoverer[v1-kikimr0]_v1_input\022\024ptqudq7uem53kjjhdml0\032\017localhost:25827\"\027\n\025cluster:default_myyds*\005local0\002@\001b\002dtj&[\"OptionalType\";[\"DataType\";\"Uint64\"]]\222\001\024ptcudq7uemfqqjepn05j\232\001\rjson_each_row\242\001>[\"StructType\";[[\"dt\";[\"OptionalType\";[\"DataType\";\"Uint64\"]]]]]\262\001\002\022\000\272\001\026\n\010cloud_id\022\nmock_cloud\272\001 \n\005scope\022\027yandexcloud://my_folder" } WatermarksMode: WATERMARKS_MODE_DISABLED } }
2025-12-12T12:27:54.109433Z :KQP_COMPUTE DEBUG: dq_pq_read_actor_base.cpp:153: SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, task: 1. PQ source. SessionId: empty Watermarks enabled: 0 granularity: 0.000000s late arrival delay: 0.000000s idle: 0 idle timeout: 0.000000s
2025-12-12T12:27:54.109491Z :YQL_PROXY TRACE: log.cpp:64: SessionId:  2025-12-12 12:27:54.109 TRACE ydbd(pid=1214775, tid=0x00007F4DE262D640) [DQ] task_controller_impl.h:160: [1:7582947185219280081:2273] EvState TaskId: 1 State: 2 PingCookie: 0 StatusCode: UNSPECIFIED
2025-12-12T12:27:54.109507Z :YQL_PROXY TRACE: log.cpp:64: SessionId:  2025-12-12 12:27:54.109 TRACE ydbd(pid=1214775, tid=0x00007F4DE262D640) [DQ] task_controller_impl.h:201:  [1:7582947185219280081:2273] Executing TaskId: 1
2025-12-12T12:27:54.152204Z :STREAMS_STORAGE_SERVICE DEBUG: storage_proxy.cpp:451: [ptqudq7uem53kjjhdml0-0] Send TEvGetCheckpointsMetadataResponse
2025-12-12T12:27:54.152410Z :STREAMS_CHECKPOINT_COORDINATOR DEBUG: checkpoint_coordinator.cpp:186: [ptqudq7uem53kjjhdml0-0.2] Got TEvGetCheckpointsMetadataResponse
2025-12-12T12:27:54.152422Z :STREAMS_CHECKPOINT_COORDINATOR INFO: checkpoint_coordinator.cpp:219: [ptqudq7uem53kjjhdml0-0.2] Will restore from checkpoint 1:2
2025-12-12T12:27:54.152673Z :KQP_COMPUTE DEBUG: dq_compute_actor_checkpoints.cpp:265: [ptqudq7uem53kjjhdml0-0] Task: 1. [Checkpoint 1.2] TEvRestoreFromCheckpoint, StateLoadPlan = { StateType: STATE_TYPE_OWN }
2025-12-12T12:27:54.152698Z :STREAMS_STORAGE_SERVICE DEBUG: storage_proxy.cpp:508: [ptqudq7uem53kjjhdml0-0] [1:2] Got TEvGetTaskState: tasks {1}
2025-12-12T12:27:54.152706Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:519: [ptqudq7uem53kjjhdml0-0] [1:2] GetState, tasks: 1
2025-12-12T12:27:54.199812Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: 8f71b000-7466b0e9-41997d65-a6f433e6 2025-12-12 12:27:54.199 DEBUG ydbd(pid=1214775, tid=0x00007F4DE162B640) [DQ] tasks_runner_local.cpp:267: {TODO/2} Build task: 2 takes 155890 us
2025-12-12T12:27:54.199837Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: 8f71b000-7466b0e9-41997d65-a6f433e6 2025-12-12 12:27:54.199 DEBUG ydbd(pid=1214775, tid=0x00007F4DE162B640) [DQ] tasks_runner_local.cpp:267: {TODO/2} Prepare task: 2
2025-12-12T12:27:54.199866Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: 8f71b000-7466b0e9-41997d65-a6f433e6 2025-12-12 12:27:54.199 DEBUG ydbd(pid=1214775, tid=0x00007F4DE162B640) [DQ] tasks_runner_local.cpp:267: {TODO/2} Prepare task: 2, takes 21 us
2025-12-12T12:27:54.199946Z :KQP_COMPUTE DEBUG: dq_compute_actor_checkpoints.cpp:197: [] Task: 2. Got TEvNewCheckpointCoordinator event: generation 2, actorId: [1:7582947185219280080:2272]
2025-12-12T12:27:54.199948Z :KQP_COMPUTE TRACE: dq_compute_actor_checkpoints.cpp:208: [] Task: 2. Assign checkpoint coordinator (generation = 2)
2025-12-12T12:27:54.199996Z :KQP_COMPUTE DEBUG: dq_compute_actor_impl.h:1447: SelfId: [1:7582947189514247379:2275], TxId: ptqudq7uem53kjjhdml0, task: 2. Ctx: {}. Create sink for output 0 { Sink { Type: "PqSink" Settings { type_url: "type.googleapis.com/NYql.NPq.NProto.TDqPqTopicSink" value: "\n/test_time_order_recoverer[v1-kikimr0]_v1_output\022\017localhost:25827\032\027\n\025cluster:default_myyds\"\005local0\0018\002" } } }
2025-12-12T12:27:54.200065Z :KQP_COMPUTE DEBUG: dq_compute_actor_checkpoints.cpp:265: [ptqudq7uem53kjjhdml0-0] Task: 2. [Checkpoint 1.2] TEvRestoreFromCheckpoint, StateLoadPlan = { StateType: STATE_TYPE_OWN }
2025-12-12T12:27:54.200093Z :STREAMS_STORAGE_SERVICE DEBUG: storage_proxy.cpp:508: [ptqudq7uem53kjjhdml0-0] [1:2] Got TEvGetTaskState: tasks {2}
2025-12-12T12:27:54.200099Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:519: [ptqudq7uem53kjjhdml0-0] [1:2] GetState, tasks: 2
2025-12-12T12:27:54.200137Z :YQL_PROXY TRACE: log.cpp:64: SessionId:  2025-12-12 12:27:54.200 TRACE ydbd(pid=1214775, tid=0x00007F4DE262D640) [DQ] task_controller_impl.h:160: [1:7582947185219280081:2273] EvState TaskId: 2 State: 2 PingCookie: 0 StatusCode: UNSPECIFIED
2025-12-12T12:27:54.200155Z :YQL_PROXY TRACE: log.cpp:64: SessionId:  2025-12-12 12:27:54.200 TRACE ydbd(pid=1214775, tid=0x00007F4DE262D640) [DQ] task_controller_impl.h:201:  [1:7582947185219280081:2273] Executing TaskId: 2
2025-12-12T12:27:54.200182Z :YQL_PROXY DEBUG: log.cpp:64: SessionId:  2025-12-12 12:27:54.200 DEBUG ydbd(pid=1214775, tid=0x00007F4DE262D640) [DQ] task_controller_impl.h:561: Update channels
2025-12-12T12:27:54.201059Z :YQL_PROXY TRACE: log.cpp:64: SessionId:  2025-12-12 12:27:54.200 TRACE ydbd(pid=1214775, tid=0x00007F4DE262D640) [DQ] task_controller_impl.h:577: 1 Update { Id: 1 TransportVersion: DATA_TRANSPORT_UV_PICKLE_1_0 SrcTaskId: 1 DstTaskId: 2 SrcEndpoint { ActorId { RawX1: 7582947189514247382 RawX2: 4503603922340068 } } DstEndpoint { ActorId { RawX1: 7582947189514247379 RawX2: 4503603922340067 } } WatermarksMode: WATERMARKS_MODE_DISABLED SrcStageId: 204663 DstStageId: 204683 }
2025-12-12T12:27:54.201102Z :YQL_PROXY TRACE: log.cpp:64: SessionId:  2025-12-12 12:27:54.201 TRACE ydbd(pid=1214775, tid=0x00007F4DE262D640) [DQ] task_controller_impl.h:577: 2 Update { Id: 1 TransportVersion: DATA_TRANSPORT_UV_PICKLE_1_0 SrcTaskId: 1 DstTaskId: 2 SrcEndpoint { ActorId { RawX1: 7582947189514247382 RawX2: 4503603922340068 } } DstEndpoint { ActorId { RawX1: 7582947189514247379 RawX2: 4503603922340067 } } WatermarksMode: WATERMARKS_MODE_DISABLED SrcStageId: 204663 DstStageId: 204683 }
2025-12-12T12:27:54.201154Z :KQP_COMPUTE DEBUG: dq_compute_actor_impl.h:1064: SelfId: [1:7582947189514247379:2275], TxId: ptqudq7uem53kjjhdml0, task: 2. Ctx: {}. Received channels info: Update { Id: 1 TransportVersion: DATA_TRANSPORT_UV_PICKLE_1_0 SrcTaskId: 1 DstTaskId: 2 SrcEndpoint { ActorId { RawX1: 7582947189514247382 RawX2: 4503603922340068 } } DstEndpoint { ActorId { RawX1: 7582947189514247379 RawX2: 4503603922340067 } } WatermarksMode: WATERMARKS_MODE_DISABLED SrcStageId: 204663 DstStageId: 204683 }
2025-12-12T12:27:54.201141Z :KQP_COMPUTE DEBUG: dq_compute_actor_impl.h:1064: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Received channels info: Update { Id: 1 TransportVersion: DATA_TRANSPORT_UV_PICKLE_1_0 SrcTaskId: 1 DstTaskId: 2 SrcEndpoint { ActorId { RawX1: 7582947189514247382 RawX2: 4503603922340068 } } DstEndpoint { ActorId { RawX1: 7582947189514247379 RawX2: 4503603922340067 } } WatermarksMode: WATERMARKS_MODE_DISABLED SrcStageId: 204663 DstStageId: 204683 }
2025-12-12T12:27:54.201159Z :KQP_COMPUTE DEBUG: dq_compute_actor_impl.h:1071: SelfId: [1:7582947189514247379:2275], TxId: ptqudq7uem53kjjhdml0, task: 2. Ctx: {}. Update input channelId: 1, peer: [1:7582947189514247382:2276]
2025-12-12T12:27:54.201161Z :KQP_COMPUTE DEBUG: dq_compute_actor_impl.h:1083: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Update output channelId: 1, peer: [1:7582947189514247379:2275]
2025-12-12T12:27:54.243380Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:654: [ptqudq7uem53kjjhdml0-0] [1:2] ListOfStates results:
2025-12-12T12:27:54.243413Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:675: [ptqudq7uem53kjjhdml0-0] [1:2] taskId 1 checkpoint id: 1:2, rows count: 1
2025-12-12T12:27:54.243416Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:675: [ptqudq7uem53kjjhdml0-0] [1:2] taskId 1 checkpoint id: 1:1, rows count: 1
2025-12-12T12:27:54.243426Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:901: [ptqudq7uem53kjjhdml0-0] [1:2] SkipStatesInFuture, skip 0 checkpoints
2025-12-12T12:27:54.243497Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:654: [ptqudq7uem53kjjhdml0-0] [1:2] ListOfStates results:
2025-12-12T12:27:54.243507Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:675: [ptqudq7uem53kjjhdml0-0] [1:2] taskId 2 checkpoint id: 1:2, rows count: 1
2025-12-12T12:27:54.243510Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:675: [ptqudq7uem53kjjhdml0-0] [1:2] taskId 2 checkpoint id: 1:1, rows count: 1
2025-12-12T12:27:54.243515Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:901: [ptqudq7uem53kjjhdml0-0] [1:2] SkipStatesInFuture, skip 0 checkpoints
2025-12-12T12:27:54.243545Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:796: [ptqudq7uem53kjjhdml0-0] [1:2] SelectState: task_id 1, seq_no 2, blob_seq_num 0
2025-12-12T12:27:54.243846Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:796: [ptqudq7uem53kjjhdml0-0] [1:2] SelectState: task_id 2, seq_no 2, blob_seq_num 0
2025-12-12T12:27:54.300783Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:410: [ptqudq7uem53kjjhdml0-0] [1:2] DeserializeState, task id 2, blob size 155
2025-12-12T12:27:54.300816Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:960: [ptqudq7uem53kjjhdml0-0] [1:2] ApplyIncrements
2025-12-12T12:27:54.300921Z :STREAMS_STORAGE_SERVICE DEBUG: storage_proxy.cpp:527: [ptqudq7uem53kjjhdml0-0] [{ Id: 2 Generation: 1 }] Send TEvGetTaskStateResult: tasks: {2}
2025-12-12T12:27:54.300980Z :KQP_COMPUTE DEBUG: dq_compute_actor_checkpoints.cpp:336: [ptqudq7uem53kjjhdml0-0] Task: 2. [Checkpoint 1.2] TEvGetTaskStateResult: restoring state
2025-12-12T12:27:54.300993Z :KQP_COMPUTE DEBUG: dq_compute_actor_impl.h:793: SelfId: [1:7582947189514247379:2275], TxId: ptqudq7uem53kjjhdml0, task: 2. Ctx: {}. Load state
2025-12-12T12:27:54.301010Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:410: [ptqudq7uem53kjjhdml0-0] [1:2] DeserializeState, task id 1, blob size 140
2025-12-12T12:27:54.301019Z :STREAMS_STORAGE_SERVICE DEBUG: ydb_state_storage.cpp:960: [ptqudq7uem53kjjhdml0-0] [1:2] ApplyIncrements
2025-12-12T12:27:54.301027Z :STREAMS_STORAGE_SERVICE DEBUG: storage_proxy.cpp:527: [ptqudq7uem53kjjhdml0-0] [{ Id: 2 Generation: 1 }] Send TEvGetTaskStateResult: tasks: {1}
2025-12-12T12:27:54.301169Z :KQP_COMPUTE DEBUG: dq_pq_write_actor.cpp:268: SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. Load state: { SourceId: "1199ee69-34530df5-a04a40c8-c42e672a" }
2025-12-12T12:27:54.301179Z :KQP_COMPUTE DEBUG: dq_compute_actor_impl.h:821: SelfId: [1:7582947189514247379:2275], TxId: ptqudq7uem53kjjhdml0, task: 2. Ctx: {}. State size: 69
2025-12-12T12:27:54.301217Z :KQP_COMPUTE DEBUG: dq_compute_actor_checkpoints.cpp:362: [ptqudq7uem53kjjhdml0-0] Task: 2. [Checkpoint 1.2] Checkpoint state restored
2025-12-12T12:27:54.301230Z :KQP_COMPUTE DEBUG: dq_compute_actor_checkpoints.cpp:336: [ptqudq7uem53kjjhdml0-0] Task: 1. [Checkpoint 1.2] TEvGetTaskStateResult: restoring state
2025-12-12T12:27:54.301236Z :KQP_COMPUTE DEBUG: dq_compute_actor_impl.h:793: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Load state
2025-12-12T12:27:54.301246Z :KQP_COMPUTE DEBUG: dq_pq_read_actor_base.cpp:153: SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, task: 1. PQ source. SessionId: empty Watermarks enabled: 0 granularity: 0.000000s late arrival delay: 0.000000s idle: 0 idle timeout: 0.000000s
2025-12-12T12:27:54.301260Z :KQP_COMPUTE DEBUG: dq_pq_read_actor_base.cpp:133: SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, task: 1. PQ source. SessionId: empty StartingMessageTs 2025-12-12T12:27:31.970000Z Restoring offset: {0@,2},
2025-12-12T12:27:54.301269Z :KQP_COMPUTE DEBUG: dq_compute_actor_checkpoints.cpp:362: [ptqudq7uem53kjjhdml0-0] Task: 1. [Checkpoint 1.2] Checkpoint state restored
2025-12-12T12:27:54.301289Z :STREAMS_CHECKPOINT_COORDINATOR DEBUG: checkpoint_coordinator.cpp:297: [ptqudq7uem53kjjhdml0-0.2] [1:2] Got TEvRestoreFromCheckpointResult; taskId: 2, checkpoint: 1:2, status: OK, issues: 
2025-12-12T12:27:54.301296Z :STREAMS_CHECKPOINT_COORDINATOR DEBUG: checkpoint_coordinator.cpp:320: [ptqudq7uem53kjjhdml0-0.2] [1:2] Task state restored, need 1 more acks
2025-12-12T12:27:54.301299Z :STREAMS_CHECKPOINT_COORDINATOR DEBUG: checkpoint_coordinator.cpp:297: [ptqudq7uem53kjjhdml0-0.2] [1:2] Got TEvRestoreFromCheckpointResult; taskId: 1, checkpoint: 1:2, status: OK, issues: 
2025-12-12T12:27:54.301301Z :STREAMS_CHECKPOINT_COORDINATOR DEBUG: checkpoint_coordinator.cpp:320: [ptqudq7uem53kjjhdml0-0.2] [1:2] Task state restored, need 0 more acks
2025-12-12T12:27:54.301305Z :STREAMS_CHECKPOINT_COORDINATOR INFO: checkpoint_coordinator.cpp:445: [ptqudq7uem53kjjhdml0-0.2] Send TEvRun to all actors
2025-12-12T12:27:54.301310Z :KQP_COMPUTE DEBUG: dq_compute_actor_impl.h:1164: SelfId: [1:7582947189514247379:2275], TxId: ptqudq7uem53kjjhdml0, task: 2. Ctx: {}. Got TEvRun from actor [1:7582947185219280080:2272]
2025-12-12T12:27:54.301317Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1483: SelfId: [1:7582947189514247379:2275], TxId: ptqudq7uem53kjjhdml0, task: 2. Ctx: {}. Poll inputs
2025-12-12T12:27:54.301318Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1498: SelfId: [1:7582947189514247379:2275], TxId: ptqudq7uem53kjjhdml0, task: 2. Ctx: {}. Poll sources
2025-12-12T12:27:54.301320Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:698: SelfId: [1:7582947189514247379:2275], TxId: ptqudq7uem53kjjhdml0, task: 2. Ctx: {}. DoExecuteImpl: 0
2025-12-12T12:27:54.301456Z :KQP_COMPUTE TRACE: dq_compute_memory_quota.h:97: TxId: ptqudq7uem53kjjhdml0, task: 2. Peak memory usage: 2031616
2025-12-12T12:27:54.301470Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:493: SelfId: [1:7582947189514247379:2275], TxId: ptqudq7uem53kjjhdml0, task: 2. Ctx: {}. update task runner stats
2025-12-12T12:27:54.301489Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:762: SelfId: [1:7582947189514247379:2275], TxId: ptqudq7uem53kjjhdml0, task: 2. Ctx: {}. Resume execution, run status: PendingInput checkpoint: 0 watermark injected: (empty maybe)
2025-12-12T12:27:54.301496Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:406: SelfId: [1:7582947189514247379:2275], TxId: ptqudq7uem53kjjhdml0, task: 2. Ctx: {}. ProcessOutputsState.Inflight: 0
2025-12-12T12:27:54.301500Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:573: SelfId: [1:7582947189514247379:2275], TxId: ptqudq7uem53kjjhdml0, task: 2. Ctx: {}. About to drain sink 0. FreeSpace: 16777216, allowedOvercommit: 500000, toSend: 17277216
2025-12-12T12:27:54.301503Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:1107: SelfId: [1:7582947189514247379:2275], TxId: ptqudq7uem53kjjhdml0, task: 2. Ctx: {}. Ask CPU quota: 156ms
2025-12-12T12:27:54.301513Z :KQP_COMPUTE TRACE: dq_pq_write_actor.cpp:195: SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. SendData. Batch: 0. Checkpoint: 0. Finished: 0
2025-12-12T12:27:54.301603Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:1025: SelfId: [1:7582947189514247379:2275], TxId: ptqudq7uem53kjjhdml0, task: 2. Ctx: {}. Sink 0: sent 0 bytes of data and 0 bytes of checkpoint barrier
2025-12-12T12:27:54.301606Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:1029: SelfId: [1:7582947189514247379:2275], TxId: ptqudq7uem53kjjhdml0, task: 2. Ctx: {}. Drain sink 0. Free space decreased: 0, sent data from buffer: 0
2025-12-12T12:27:54.301611Z :KQP_COMPUTE TRACE: dq_compute_actor_channels.cpp:605: TxId: ptqudq7uem53kjjhdml0, task: 2. no poll, channelId: 1, hasPeer: 1, finished: 0, retry: 0, lastSeqNo: 0, freeSpace: 1000000
2025-12-12T12:27:54.301620Z :KQP_COMPUTE DEBUG: dq_compute_actor_impl.h:1164: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Got TEvRun from actor [1:7582947185219280080:2272]
2025-12-12T12:27:54.301625Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1483: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Poll inputs
2025-12-12T12:27:54.301626Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1498: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Poll sources
2025-12-12T12:27:54.301630Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:542: SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, task: 1. PQ source. SessionId: empty GetAsyncInputData freeSpace = 1
2025-12-12T12:27:54.301651Z :KQP_COMPUTE DEBUG: dq_pq_read_actor.cpp:648: SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, task: 1. PQ source. SessionId: empty PartitionsToRead: 0
2025-12-12T12:27:54.301671Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:54.301668Z :INFO: [local] [local] [e6693091-4ecea588-216e7a65-e6408507] Starting read session
2025-12-12T12:27:54.301676Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.301674Z :DEBUG: [local] [local] [e6693091-4ecea588-216e7a65-e6408507] Starting single session
2025-12-12T12:27:54.301698Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.301696Z :DEBUG: [local] [local] [e6693091-4ecea588-216e7a65-e6408507] [] In Reconnect, ReadSizeBudget = 8388608, ReadSizeServerDelta = 0
2025-12-12T12:27:54.301701Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.301700Z :DEBUG: [local] [local] [e6693091-4ecea588-216e7a65-e6408507] [] New values: ReadSizeBudget = 8388608, ReadSizeServerDelta = 0
2025-12-12T12:27:54.301705Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.301704Z :DEBUG: [local] [local] [e6693091-4ecea588-216e7a65-e6408507] [] Reconnecting session to cluster  in 0.000000s
2025-12-12T12:27:54.301932Z :KQP_COMPUTE INFO: dq_pq_read_actor.cpp:315: SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, task: 1. PQ source. SessionId: e6693091-4ecea588-216e7a65-e6408507 CreateReadSession
2025-12-12T12:27:54.301945Z :KQP_COMPUTE TRACE: dq_compute_actor_async_input_helper.h:81: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Poll async input 0. Buffer free space: 1, read from async input: 0 bytes, 0 rows, finished: 0
2025-12-12T12:27:54.301960Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.301946Z :DEBUG: [local] [local] [e6693091-4ecea588-216e7a65-e6408507] [] Successfully connected. Initializing session
2025-12-12T12:27:54.301966Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:844: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Send TEvContinueRun on OnAsyncInputPushFinished
2025-12-12T12:27:54.302062Z :KQP_COMPUTE TRACE: dq_compute_memory_quota.h:97: TxId: ptqudq7uem53kjjhdml0, task: 1. Peak memory usage: 2031616
2025-12-12T12:27:54.302075Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:493: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. update task runner stats
2025-12-12T12:27:54.302090Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:762: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Resume execution, run status: PendingInput checkpoint: 0 watermark injected: (empty maybe)
2025-12-12T12:27:54.302092Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:406: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. ProcessOutputsState.Inflight: 0
2025-12-12T12:27:54.302096Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:534: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. About to drain channelId: 1, hasPeer: 1, peerState:(freeSpace:1000000;inFlightBytes:0;inFlightCount:0;)
2025-12-12T12:27:54.302098Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:1107: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Ask CPU quota: 66ms
2025-12-12T12:27:54.303629Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:54.303619Z :INFO: [local] OnFederationDiscovery fall back to single mode, database=local
2025-12-12T12:27:54.303828Z :YDB_SDK INFO: actor.cpp:37: [] [] Start federated write session to database '' (previous was <empty>) FederationState: { Status: SUCCESS SelfLocation: "" DbInfos: [ { path: "local" endpoint: "localhost:25827" status: AVAILABLE weight: 100 } ] ControlPlaneEndpoint: localhost:25827 }
2025-12-12T12:27:54.303898Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.303895Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId []  MessageGroupId [1199ee69-34530df5-a04a40c8-c42e672a] Write session: try to update token
2025-12-12T12:27:54.304149Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:54.304145Z :INFO: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId []  MessageGroupId [1199ee69-34530df5-a04a40c8-c42e672a] Start write session. Will connect to nodeId: 0
2025-12-12T12:27:54.304626Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.304620Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId []  MessageGroupId [1199ee69-34530df5-a04a40c8-c42e672a] Write session: write to message_group: 1199ee69-34530df5-a04a40c8-c42e672a
2025-12-12T12:27:54.304652Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.304649Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId []  MessageGroupId [1199ee69-34530df5-a04a40c8-c42e672a] Write session: send init request: init_request { path: "test_time_order_recoverer[v1-kikimr0]_v1_output" producer_id: "1199ee69-34530df5-a04a40c8-c42e672a" message_group_id: "1199ee69-34530df5-a04a40c8-c42e672a" }
2025-12-12T12:27:54.304655Z :YDB_SDK TRACE: actor.cpp:37: 2025-12-12T12:27:54.304654Z :TRACE: [local] TRACE_EVENT InitRequest 
2025-12-12T12:27:54.304745Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:54.304742Z :INFO: [local] [local] [e6693091-4ecea588-216e7a65-e6408507] [] Got InitResponse. ReadSessionId: ptqudq7uem53kjjhdml0_1_15_10263605297662524468_v1
2025-12-12T12:27:54.304751Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.304749Z :DEBUG: [local] [local] [e6693091-4ecea588-216e7a65-e6408507] [] In ContinueReadingDataImpl, ReadSizeBudget = 8388608, ReadSizeServerDelta = 0
2025-12-12T12:27:54.304786Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.304784Z :DEBUG: [local] [local] [e6693091-4ecea588-216e7a65-e6408507] [] After sending read request: ReadSizeBudget = 0, ReadSizeServerDelta = 8388608
2025-12-12T12:27:54.304878Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.304875Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId []  MessageGroupId [1199ee69-34530df5-a04a40c8-c42e672a] Write session: OnWriteDone gRpcStatusCode: 0
2025-12-12T12:27:54.305163Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:363: SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, task: 1. PQ source. SessionId: e6693091-4ecea588-216e7a65-e6408507 Source data ready
2025-12-12T12:27:54.305189Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1483: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Poll inputs
2025-12-12T12:27:54.305192Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1498: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Poll sources
2025-12-12T12:27:54.305199Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:542: SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, task: 1. PQ source. SessionId: e6693091-4ecea588-216e7a65-e6408507 GetAsyncInputData freeSpace = 1000000
2025-12-12T12:27:54.305214Z :KQP_COMPUTE DEBUG: dq_pq_read_actor.cpp:820: SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, task: 1. PQ source. SessionId: e6693091-4ecea588-216e7a65-e6408507 Key: 0@ StartPartitionSessionEvent received
2025-12-12T12:27:54.305217Z :KQP_COMPUTE DEBUG: dq_pq_read_actor.cpp:827: SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, task: 1. PQ source. SessionId: e6693091-4ecea588-216e7a65-e6408507 Key: 0@ Confirm StartPartitionSession with offset 2
2025-12-12T12:27:54.305227Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:54.305224Z :INFO: [local] [local] [e6693091-4ecea588-216e7a65-e6408507] [] Confirm partition stream create. Partition stream id: 1. Cluster: "-". Topic: "test_time_order_recoverer[v1-kikimr0]_v1_input". Partition: 0. Read offset: 2
2025-12-12T12:27:54.305293Z :KQP_COMPUTE TRACE: dq_compute_actor_async_input_helper.h:81: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Poll async input 0. Buffer free space: 1000000, read from async input: 0 bytes, 0 rows, finished: 0
2025-12-12T12:27:54.305310Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:363: SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, task: 1. PQ source. SessionId: e6693091-4ecea588-216e7a65-e6408507 Source data ready
2025-12-12T12:27:54.305314Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:844: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Send TEvContinueRun on OnAsyncInputPushFinished
2025-12-12T12:27:54.305319Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1483: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Poll inputs
2025-12-12T12:27:54.305320Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1498: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Poll sources
2025-12-12T12:27:54.305323Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:542: SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, task: 1. PQ source. SessionId: e6693091-4ecea588-216e7a65-e6408507 GetAsyncInputData freeSpace = 1000000
2025-12-12T12:27:54.305327Z :KQP_COMPUTE TRACE: dq_compute_actor_async_input_helper.h:81: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Poll async input 0. Buffer free space: 1000000, read from async input: 0 bytes, 0 rows, finished: 0
2025-12-12T12:27:54.305329Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:844: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Send TEvContinueRun on OnAsyncInputPushFinished
2025-12-12T12:27:54.305360Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:1165: SelfId: [1:7582947189514247379:2275], TxId: ptqudq7uem53kjjhdml0, task: 2. Ctx: {}. CPU quota delay: 3ms
2025-12-12T12:27:54.305363Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:1165: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. CPU quota delay: 3ms
2025-12-12T12:27:54.305401Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: 8f71b000-7466b0e9-41997d65-a6f433e6 2025-12-12 12:27:54.305 DEBUG ydbd(pid=1214775, tid=0x00007F4DE162B640) [DQ] tasks_runner_local.cpp:267: {TODO/1} Run task: 1
2025-12-12T12:27:54.305430Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:493: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. update task runner stats
2025-12-12T12:27:54.305465Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:762: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Resume execution, run status: PendingInput checkpoint: 0 watermark injected: (empty maybe)
2025-12-12T12:27:54.305468Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:406: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. ProcessOutputsState.Inflight: 0
2025-12-12T12:27:54.305475Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:534: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. About to drain channelId: 1, hasPeer: 1, peerState:(freeSpace:1000000;inFlightBytes:0;inFlightCount:0;)
2025-12-12T12:27:54.306267Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.306261Z :DEBUG: [local] [local] [e6693091-4ecea588-216e7a65-e6408507] [] Got ReadResponse, serverBytesSize = 256, now ReadSizeBudget = 0, ReadSizeServerDelta = 8388352
2025-12-12T12:27:54.306293Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.306291Z :DEBUG: [local] [local] [e6693091-4ecea588-216e7a65-e6408507] [] In ContinueReadingDataImpl, ReadSizeBudget = 0, ReadSizeServerDelta = 8388352
2025-12-12T12:27:54.306348Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.306346Z :DEBUG: [local] Decompression task done. Partition/PartitionSessionId: 1 (2-6)
2025-12-12T12:27:54.306353Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.306351Z :DEBUG: [local] [local] [e6693091-4ecea588-216e7a65-e6408507] [] Returning serverBytesSize = 256 to budget
2025-12-12T12:27:54.306356Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.306354Z :DEBUG: [local] [local] [e6693091-4ecea588-216e7a65-e6408507] [] In ContinueReadingDataImpl, ReadSizeBudget = 256, ReadSizeServerDelta = 8388352
2025-12-12T12:27:54.306385Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.306384Z :DEBUG: [local] [local] [e6693091-4ecea588-216e7a65-e6408507] [] After sending read request: ReadSizeBudget = 0, ReadSizeServerDelta = 8388608
2025-12-12T12:27:54.306563Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:363: SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, task: 1. PQ source. SessionId: e6693091-4ecea588-216e7a65-e6408507 Source data ready
2025-12-12T12:27:54.306578Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1483: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Poll inputs
2025-12-12T12:27:54.306580Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1498: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Poll sources
2025-12-12T12:27:54.306585Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:542: SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, task: 1. PQ source. SessionId: e6693091-4ecea588-216e7a65-e6408507 GetAsyncInputData freeSpace = 1000000
2025-12-12T12:27:54.306600Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.306597Z :DEBUG: [local] Take Data. Partition 0. Read: {0, 0} (2-2)
2025-12-12T12:27:54.306605Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.306604Z :DEBUG: [local] Take Data. Partition 0. Read: {0, 1} (3-3)
2025-12-12T12:27:54.306611Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.306610Z :DEBUG: [local] Take Data. Partition 0. Read: {0, 2} (4-4)
2025-12-12T12:27:54.306615Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.306614Z :DEBUG: [local] Take Data. Partition 0. Read: {0, 3} (5-5)
2025-12-12T12:27:54.306622Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.306620Z :DEBUG: [local] Take Data. Partition 0. Read: {0, 4} (6-6)
2025-12-12T12:27:54.306630Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.306628Z :DEBUG: [local] [local] [e6693091-4ecea588-216e7a65-e6408507] [] The application data is transferred to the client. Number of messages 5, size 115 bytes
2025-12-12T12:27:54.306638Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.306634Z :DEBUG: [local] [local] [e6693091-4ecea588-216e7a65-e6408507] [] Returning serverBytesSize = 0 to budget
2025-12-12T12:27:54.306656Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:761: SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, task: 1. PQ source. SessionId: e6693091-4ecea588-216e7a65-e6408507 Key: 0@ Data received: Message { Data: "{"dt":1696849942800000}" Information: { Offset: 2 ProducerId: "" SeqNo: 0 CreateTime: 2025-12-12T12:27:35.964000Z WriteTime: 2025-12-12T12:27:35.963000Z MessageGroupId: "" Meta: { } MessageMeta: { } } Partition session id: 1 Topic: "test_time_order_recoverer[v1-kikimr0]_v1_input" Partition: 0 }
2025-12-12T12:27:54.306669Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:761: SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, task: 1. PQ source. SessionId: e6693091-4ecea588-216e7a65-e6408507 Key: 0@ Data received: Message { Data: "{"dt":1696849943200003}" Information: { Offset: 3 ProducerId: "" SeqNo: 0 CreateTime: 2025-12-12T12:27:35.964000Z WriteTime: 2025-12-12T12:27:35.963000Z MessageGroupId: "" Meta: { } MessageMeta: { } } Partition session id: 1 Topic: "test_time_order_recoverer[v1-kikimr0]_v1_input" Partition: 0 }
2025-12-12T12:27:54.306672Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:761: SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, task: 1. PQ source. SessionId: e6693091-4ecea588-216e7a65-e6408507 Key: 0@ Data received: Message { Data: "{"dt":1696849943300003}" Information: { Offset: 4 ProducerId: "" SeqNo: 0 CreateTime: 2025-12-12T12:27:35.964000Z WriteTime: 2025-12-12T12:27:35.963000Z MessageGroupId: "" Meta: { } MessageMeta: { } } Partition session id: 1 Topic: "test_time_order_recoverer[v1-kikimr0]_v1_input" Partition: 0 }
2025-12-12T12:27:54.306677Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:761: SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, task: 1. PQ source. SessionId: e6693091-4ecea588-216e7a65-e6408507 Key: 0@ Data received: Message { Data: "{"dt":1696849943600003}" Information: { Offset: 5 ProducerId: "" SeqNo: 0 CreateTime: 2025-12-12T12:27:35.964000Z WriteTime: 2025-12-12T12:27:35.963000Z MessageGroupId: "" Meta: { } MessageMeta: { } } Partition session id: 1 Topic: "test_time_order_recoverer[v1-kikimr0]_v1_input" Partition: 0 }
2025-12-12T12:27:54.306681Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:761: SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, task: 1. PQ source. SessionId: e6693091-4ecea588-216e7a65-e6408507 Key: 0@ Data received: Message { Data: "{"dt":1696849943900003}" Information: { Offset: 6 ProducerId: "" SeqNo: 0 CreateTime: 2025-12-12T12:27:35.964000Z WriteTime: 2025-12-12T12:27:35.963000Z MessageGroupId: "" Meta: { } MessageMeta: { } } Partition session id: 1 Topic: "test_time_order_recoverer[v1-kikimr0]_v1_input" Partition: 0 }
2025-12-12T12:27:54.306695Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:737: SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, task: 1. PQ source. SessionId: e6693091-4ecea588-216e7a65-e6408507 Return ready batch. DataCount = 5 Watermark = none Used space = 115
2025-12-12T12:27:54.306698Z :KQP_COMPUTE TRACE: dq_compute_actor_async_input_helper.h:81: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Poll async input 0. Buffer free space: 1000000, read from async input: 115 bytes, 5 rows, finished: 0
2025-12-12T12:27:54.306719Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:363: SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, task: 1. PQ source. SessionId: e6693091-4ecea588-216e7a65-e6408507 Source data ready
2025-12-12T12:27:54.306722Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:844: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Send TEvContinueRun on OnAsyncInputPushFinished
2025-12-12T12:27:54.306726Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1483: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Poll inputs
2025-12-12T12:27:54.306727Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1498: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Poll sources
2025-12-12T12:27:54.306729Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:542: SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, task: 1. PQ source. SessionId: e6693091-4ecea588-216e7a65-e6408507 GetAsyncInputData freeSpace = 999885
2025-12-12T12:27:54.306732Z :KQP_COMPUTE TRACE: dq_compute_actor_async_input_helper.h:81: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Poll async input 0. Buffer free space: 999885, read from async input: 0 bytes, 0 rows, finished: 0
2025-12-12T12:27:54.306898Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:844: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Send TEvContinueRun on OnAsyncInputPushFinished
2025-12-12T12:27:54.306901Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1483: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Poll inputs
2025-12-12T12:27:54.306902Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1498: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Poll sources
2025-12-12T12:27:54.306904Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:542: SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, task: 1. PQ source. SessionId: e6693091-4ecea588-216e7a65-e6408507 GetAsyncInputData freeSpace = 999885
2025-12-12T12:27:54.306907Z :KQP_COMPUTE TRACE: dq_compute_actor_async_input_helper.h:81: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Poll async input 0. Buffer free space: 999885, read from async input: 0 bytes, 0 rows, finished: 0
2025-12-12T12:27:54.306911Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:493: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. update task runner stats
2025-12-12T12:27:54.306936Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:762: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Resume execution, run status: PendingInput checkpoint: 0 watermark injected: (empty maybe)
2025-12-12T12:27:54.306938Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:406: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. ProcessOutputsState.Inflight: 0
2025-12-12T12:27:54.306944Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:534: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. About to drain channelId: 1, hasPeer: 1, peerState:(freeSpace:1000000;inFlightBytes:0;inFlightCount:0;)
2025-12-12T12:27:54.306948Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:844: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Send TEvContinueRun on OnAsyncInputPushFinished
2025-12-12T12:27:54.306990Z :KQP_COMPUTE TRACE: dq_compute_actor_channels.cpp:566: TxId: ptqudq7uem53kjjhdml0, task: 1. SendChannelData, channelId: 1, peer: [1:7582947189514247379:2275], chunks: 5, bytes: 51, watermark: 0, checkpoint: 0, seqNo: 1, finished: 0
2025-12-12T12:27:54.307034Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:493: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. update task runner stats
2025-12-12T12:27:54.307043Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:762: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Resume execution, run status: PendingInput checkpoint: 0 watermark injected: (empty maybe)
2025-12-12T12:27:54.307045Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:406: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. ProcessOutputsState.Inflight: 0
2025-12-12T12:27:54.307048Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:534: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. About to drain channelId: 1, hasPeer: 1, peerState:(freeSpace:1000000;inFlightBytes:147;inFlightCount:1;)
2025-12-12T12:27:54.307052Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1483: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Poll inputs
2025-12-12T12:27:54.307054Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1498: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Poll sources
2025-12-12T12:27:54.307057Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:542: SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, task: 1. PQ source. SessionId: e6693091-4ecea588-216e7a65-e6408507 GetAsyncInputData freeSpace = 1000000
2025-12-12T12:27:54.307057Z :KQP_COMPUTE TRACE: dq_compute_actor_channels.cpp:129: TxId: ptqudq7uem53kjjhdml0, task: 2. Received input for channelId: 1, seqNo: 1, size: 51, chunks: 5, watermark: 0, checkpoint: 0, finished: 0, from: [1:7582947189514247383:2276], expected seqNo: 1
2025-12-12T12:27:54.307061Z :KQP_COMPUTE TRACE: dq_compute_actor_async_input_helper.h:81: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Poll async input 0. Buffer free space: 1000000, read from async input: 0 bytes, 0 rows, finished: 0
2025-12-12T12:27:54.307063Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:611: SelfId: [1:7582947189514247379:2275], TxId: ptqudq7uem53kjjhdml0, task: 2. Ctx: {}. took input
2025-12-12T12:27:54.307078Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:844: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Send TEvContinueRun on OnAsyncInputPushFinished
2025-12-12T12:27:54.307081Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:493: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. update task runner stats
2025-12-12T12:27:54.307085Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:762: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Resume execution, run status: PendingInput checkpoint: 0 watermark injected: (empty maybe)
2025-12-12T12:27:54.307086Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:406: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. ProcessOutputsState.Inflight: 0
2025-12-12T12:27:54.307089Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:534: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. About to drain channelId: 1, hasPeer: 1, peerState:(freeSpace:1000000;inFlightBytes:147;inFlightCount:1;)
2025-12-12T12:27:54.307100Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:493: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. update task runner stats
2025-12-12T12:27:54.307104Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:762: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Resume execution, run status: PendingInput checkpoint: 0 watermark injected: (empty maybe)
2025-12-12T12:27:54.307105Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:406: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. ProcessOutputsState.Inflight: 0
2025-12-12T12:27:54.307108Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:534: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. About to drain channelId: 1, hasPeer: 1, peerState:(freeSpace:1000000;inFlightBytes:147;inFlightCount:1;)
2025-12-12T12:27:54.307183Z :DQ_TASK_RUNNER TRACE: task_runner_actor_local.cpp:356: SelfId: [1:7582947189514247381:2275], TxId: ptqudq7uem53kjjhdml0, task: 2. No watermark 
2025-12-12T12:27:54.307190Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:965: SelfId: [1:7582947189514247379:2275], TxId: ptqudq7uem53kjjhdml0, task: 2. Ctx: {}. Input data push finished. Cookie: 0 Watermark: (empty maybe) Ack: 1 TakeInputChannelDataRequests: 1
2025-12-12T12:27:54.307194Z :KQP_COMPUTE TRACE: dq_compute_actor_channels.cpp:738: TxId: ptqudq7uem53kjjhdml0, task: 2. Sending channel data ack to channelId: 1, peer: [1:7582947189514247382:2276], from: [1:7582947189514247379:2275], freeSpace: 999949, seqNo: 1, finished: 0
2025-12-12T12:27:54.307208Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1483: SelfId: [1:7582947189514247379:2275], TxId: ptqudq7uem53kjjhdml0, task: 2. Ctx: {}. Poll inputs
2025-12-12T12:27:54.307211Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1498: SelfId: [1:7582947189514247379:2275], TxId: ptqudq7uem53kjjhdml0, task: 2. Ctx: {}. Poll sources
2025-12-12T12:27:54.307213Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:698: SelfId: [1:7582947189514247379:2275], TxId: ptqudq7uem53kjjhdml0, task: 2. Ctx: {}. DoExecuteImpl: 0
2025-12-12T12:27:54.307417Z :KQP_COMPUTE TRACE: dq_compute_actor_channels.cpp:179: TxId: ptqudq7uem53kjjhdml0, task: 1. Received channel data ack for channelId: 1, seqNo: 1, lastSentSeqNo: 1, freeSpace: 999949, early finish: 0
2025-12-12T12:27:54.307426Z :KQP_COMPUTE TRACE: dq_compute_actor_channels.cpp:207: TxId: ptqudq7uem53kjjhdml0, task: 1. PeerState, peerState:(freeSpace:999949;inFlightBytes:0;inFlightCount:0;), sentSeqNo: 1, ackSeqNo: 1
2025-12-12T12:27:54.307427Z :KQP_COMPUTE TRACE: dq_compute_actor_channels.cpp:220: TxId: ptqudq7uem53kjjhdml0, task: 1. Resume compute actor
2025-12-12T12:27:54.307434Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1483: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Poll inputs
2025-12-12T12:27:54.307436Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1498: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Poll sources
2025-12-12T12:27:54.307440Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:542: SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, task: 1. PQ source. SessionId: e6693091-4ecea588-216e7a65-e6408507 GetAsyncInputData freeSpace = 1000000
2025-12-12T12:27:54.307444Z :KQP_COMPUTE TRACE: dq_compute_actor_async_input_helper.h:81: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Poll async input 0. Buffer free space: 1000000, read from async input: 0 bytes, 0 rows, finished: 0
2025-12-12T12:27:54.307448Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:844: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Send TEvContinueRun on OnAsyncInputPushFinished
2025-12-12T12:27:54.307469Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: 8f71b000-7466b0e9-41997d65-a6f433e6 2025-12-12 12:27:54.307 DEBUG ydbd(pid=1214775, tid=0x00007F4DE162B640) [DQ] tasks_runner_local.cpp:267: {TODO/1} Run task: 1
2025-12-12T12:27:54.307480Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:493: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. update task runner stats
2025-12-12T12:27:54.307490Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:762: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Resume execution, run status: PendingInput checkpoint: 0 watermark injected: (empty maybe)
2025-12-12T12:27:54.307491Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:406: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. ProcessOutputsState.Inflight: 0
2025-12-12T12:27:54.307495Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:534: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. About to drain channelId: 1, hasPeer: 1, peerState:(freeSpace:999949;inFlightBytes:0;inFlightCount:0;)
2025-12-12T12:27:54.307593Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:493: SelfId: [1:7582947189514247379:2275], TxId: ptqudq7uem53kjjhdml0, task: 2. Ctx: {}. update task runner stats
2025-12-12T12:27:54.307629Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:762: SelfId: [1:7582947189514247379:2275], TxId: ptqudq7uem53kjjhdml0, task: 2. Ctx: {}. Resume execution, run status: PendingInput checkpoint: 0 watermark injected: (empty maybe)
2025-12-12T12:27:54.307636Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:406: SelfId: [1:7582947189514247379:2275], TxId: ptqudq7uem53kjjhdml0, task: 2. Ctx: {}. ProcessOutputsState.Inflight: 0
2025-12-12T12:27:54.307640Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:573: SelfId: [1:7582947189514247379:2275], TxId: ptqudq7uem53kjjhdml0, task: 2. Ctx: {}. About to drain sink 0. FreeSpace: 16777216, allowedOvercommit: 500000, toSend: 17277216
2025-12-12T12:27:54.307652Z :KQP_COMPUTE TRACE: dq_pq_write_actor.cpp:195: SelfId: [1:7582947189514247388:2275], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. SendData. Batch: 3. Checkpoint: 0. Finished: 0
2025-12-12T12:27:54.307660Z :KQP_COMPUTE TRACE: dq_pq_write_actor.cpp:221: SelfId: [1:7582947189514247388:2275], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. Received data for sending: {"dt":1696849942000001}
2025-12-12T12:27:54.307663Z :KQP_COMPUTE TRACE: dq_pq_write_actor.cpp:221: SelfId: [1:7582947189514247388:2275], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. Received data for sending: {"dt":1696849942400002}
2025-12-12T12:27:54.307664Z :KQP_COMPUTE TRACE: dq_pq_write_actor.cpp:221: SelfId: [1:7582947189514247388:2275], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. Received data for sending: {"dt":1696849942800000}
2025-12-12T12:27:54.307692Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:1025: SelfId: [1:7582947189514247379:2275], TxId: ptqudq7uem53kjjhdml0, task: 2. Ctx: {}. Sink 0: sent 81 bytes of data and 0 bytes of checkpoint barrier
2025-12-12T12:27:54.307699Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:1029: SelfId: [1:7582947189514247379:2275], TxId: ptqudq7uem53kjjhdml0, task: 2. Ctx: {}. Drain sink 0. Free space decreased: 69, sent data from buffer: 81
2025-12-12T12:27:54.307705Z :KQP_COMPUTE TRACE: dq_compute_actor_channels.cpp:629: TxId: ptqudq7uem53kjjhdml0, task: 2. do poll, channelId: 1, last freeSpace: 999949, current freeSpace: 1000000, seqNo: 1
2025-12-12T12:27:54.307708Z :KQP_COMPUTE TRACE: dq_compute_actor_channels.cpp:639: TxId: ptqudq7uem53kjjhdml0, task: 2. Poll input channelId: 1, from: [1:7582947189514247382:2276], seqNo: 1, freeSpace: 1000000
2025-12-12T12:27:54.307711Z :KQP_COMPUTE TRACE: dq_compute_actor_channels.cpp:738: TxId: ptqudq7uem53kjjhdml0, task: 2. Sending channel data ack to channelId: 1, peer: [1:7582947189514247382:2276], from: [1:7582947189514247379:2275], freeSpace: 1000000, seqNo: 1, finished: 0
2025-12-12T12:27:54.307729Z :KQP_COMPUTE TRACE: dq_compute_actor_channels.cpp:179: TxId: ptqudq7uem53kjjhdml0, task: 1. Received channel data ack for channelId: 1, seqNo: 1, lastSentSeqNo: 1, freeSpace: 1000000, early finish: 0
2025-12-12T12:27:54.307736Z :KQP_COMPUTE TRACE: dq_compute_actor_channels.cpp:207: TxId: ptqudq7uem53kjjhdml0, task: 1. PeerState, peerState:(freeSpace:1000000;inFlightBytes:0;inFlightCount:0;), sentSeqNo: 1, ackSeqNo: 1
2025-12-12T12:27:54.307737Z :KQP_COMPUTE TRACE: dq_compute_actor_channels.cpp:220: TxId: ptqudq7uem53kjjhdml0, task: 1. Resume compute actor
2025-12-12T12:27:54.307741Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1483: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Poll inputs
2025-12-12T12:27:54.307743Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:1498: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Poll sources
2025-12-12T12:27:54.307749Z :KQP_COMPUTE TRACE: dq_pq_read_actor.cpp:542: SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, task: 1. PQ source. SessionId: e6693091-4ecea588-216e7a65-e6408507 GetAsyncInputData freeSpace = 1000000
2025-12-12T12:27:54.307754Z :KQP_COMPUTE TRACE: dq_compute_actor_async_input_helper.h:81: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Poll async input 0. Buffer free space: 1000000, read from async input: 0 bytes, 0 rows, finished: 0
2025-12-12T12:27:54.307762Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:844: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Send TEvContinueRun on OnAsyncInputPushFinished
2025-12-12T12:27:54.307787Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:493: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. update task runner stats
2025-12-12T12:27:54.307801Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:762: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Resume execution, run status: PendingInput checkpoint: 0 watermark injected: (empty maybe)
2025-12-12T12:27:54.307805Z :KQP_COMPUTE TRACE: dq_compute_actor_impl.h:406: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. ProcessOutputsState.Inflight: 0
2025-12-12T12:27:54.307808Z :KQP_COMPUTE TRACE: dq_async_compute_actor.cpp:534: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. About to drain channelId: 1, hasPeer: 1, peerState:(freeSpace:1000000;inFlightBytes:0;inFlightCount:0;)
2025-12-12T12:27:54.321477Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.321466Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId []  MessageGroupId [1199ee69-34530df5-a04a40c8-c42e672a] Write session: OnReadDone gRpcStatusCode: 0
2025-12-12T12:27:54.321502Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:54.321498Z :INFO: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId []  MessageGroupId [1199ee69-34530df5-a04a40c8-c42e672a] Counters: { Errors: 0 CurrentSessionLifetimeMs: 1765542474321 BytesWritten: 0 MessagesWritten: 0 BytesWrittenCompressed: 0 BytesInflightUncompressed: 0 BytesInflightCompressed: 0 BytesInflightTotal: 0 MessagesInflight: 0 }
2025-12-12T12:27:54.321523Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:54.321521Z :INFO: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId []  MessageGroupId [1199ee69-34530df5-a04a40c8-c42e672a] Write session established. Init response: session_id: "1199ee69-34530df5-a04a40c8-c42e672a|b3f74c4-4a7a9bf9-b1fabb1c-c778b1b1_0"
2025-12-12T12:27:54.321528Z :YDB_SDK TRACE: actor.cpp:37: 2025-12-12T12:27:54.321526Z :TRACE: [local] TRACE_EVENT InitResponse  partition_id=0 session_id=1199ee69-34530df5-a04a40c8-c42e672a|b3f74c4-4a7a9bf9-b1fabb1c-c778b1b1_0
2025-12-12T12:27:54.321533Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.321530Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId [1199ee69-34530df5-a04a40c8-c42e672a|b3f74c4-4a7a9bf9-b1fabb1c-c778b1b1_0]  MessageGroupId [1199ee69-34530df5-a04a40c8-c42e672a] Write session: set DirectWriteToPartitionId 0
2025-12-12T12:27:54.321599Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:54.321596Z :INFO: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId [1199ee69-34530df5-a04a40c8-c42e672a|b3f74c4-4a7a9bf9-b1fabb1c-c778b1b1_0]  PartitionId [0]  Generation [0] Get partition location async, partition 0, delay 0.000000s
2025-12-12T12:27:54.321611Z :YDB_SDK TRACE: actor.cpp:37: 2025-12-12T12:27:54.321609Z :TRACE: [local] TRACE_EVENT DescribePartitionRequest  path=local/test_time_order_recoverer[v1-kikimr0]_v1_output partition_id=0
2025-12-12T12:27:54.323336Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.323321Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId [1199ee69-34530df5-a04a40c8-c42e672a|b3f74c4-4a7a9bf9-b1fabb1c-c778b1b1_0]  PartitionId [0]  Generation [0]  Getting partition location, partition 0
2025-12-12T12:27:54.325550Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:54.325539Z :INFO: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId [1199ee69-34530df5-a04a40c8-c42e672a|b3f74c4-4a7a9bf9-b1fabb1c-c778b1b1_0]  PartitionId [0]  Generation [0] Got PartitionLocation response. Status SUCCESS, proto:
partition {
  active: true
  partition_location {
    node_id: 1
    generation: 1
  }
}

2025-12-12T12:27:54.325563Z :YDB_SDK TRACE: actor.cpp:37: 2025-12-12T12:27:54.325558Z :TRACE: [local] TRACE_EVENT DescribePartitionResponse  partition_id=0 active=1 pl_node_id=1 pl_generation=1
2025-12-12T12:27:54.325573Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.325571Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId [1199ee69-34530df5-a04a40c8-c42e672a|b3f74c4-4a7a9bf9-b1fabb1c-c778b1b1_0]  PartitionId [0]  Generation [0] GetPreferredEndpoint: partitionId 0, partitionNodeId 1 exists in the endpoint pool.
2025-12-12T12:27:54.325582Z :YDB_SDK TRACE: actor.cpp:37: 2025-12-12T12:27:54.325580Z :TRACE: [local] TRACE_EVENT PreferredPartitionLocation  Endpoint= NodeId=1 Generation=1
2025-12-12T12:27:54.325587Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:54.325585Z :INFO: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId [1199ee69-34530df5-a04a40c8-c42e672a|b3f74c4-4a7a9bf9-b1fabb1c-c778b1b1_0]  PartitionId [0]  Generation [1] Start write session. Will connect to nodeId: 1
2025-12-12T12:27:54.330284Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.330272Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId [1199ee69-34530df5-a04a40c8-c42e672a|b3f74c4-4a7a9bf9-b1fabb1c-c778b1b1_0]  PartitionId [0]  Generation [1] Write session: OnReadDone gRpcStatusCode: 1, Msg: CANCELLED, Details: , InternalError: 0
2025-12-12T12:27:54.330468Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.330464Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId [1199ee69-34530df5-a04a40c8-c42e672a|b3f74c4-4a7a9bf9-b1fabb1c-c778b1b1_0]  PartitionId [0]  Generation [1] Write session: direct write to partition: 0, generation 1
2025-12-12T12:27:54.330496Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.330492Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId [1199ee69-34530df5-a04a40c8-c42e672a|b3f74c4-4a7a9bf9-b1fabb1c-c778b1b1_0]  PartitionId [0]  Generation [1] Write session: send init request: init_request { path: "test_time_order_recoverer[v1-kikimr0]_v1_output" producer_id: "1199ee69-34530df5-a04a40c8-c42e672a" partition_with_generation { generation: 1 } }
2025-12-12T12:27:54.330501Z :YDB_SDK TRACE: actor.cpp:37: 2025-12-12T12:27:54.330499Z :TRACE: [local] TRACE_EVENT InitRequest  pwg_partition_id=0 pwg_generation=1
2025-12-12T12:27:54.330651Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.330649Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId [1199ee69-34530df5-a04a40c8-c42e672a|b3f74c4-4a7a9bf9-b1fabb1c-c778b1b1_0]  PartitionId [0]  Generation [1] Write session: OnWriteDone gRpcStatusCode: 0
2025-12-12T12:27:54.343574Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.343559Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId [1199ee69-34530df5-a04a40c8-c42e672a|b3f74c4-4a7a9bf9-b1fabb1c-c778b1b1_0]  PartitionId [0]  Generation [1] Write session: OnReadDone gRpcStatusCode: 0
2025-12-12T12:27:54.343628Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:54.343624Z :INFO: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId [1199ee69-34530df5-a04a40c8-c42e672a|b3f74c4-4a7a9bf9-b1fabb1c-c778b1b1_0]  PartitionId [0]  Generation [1] Write session established. Init response: session_id: "1199ee69-34530df5-a04a40c8-c42e672a|d7f3d2b1-7468cb1a-e3a0da9-6c2f087a_0"
2025-12-12T12:27:54.343636Z :YDB_SDK TRACE: actor.cpp:37: 2025-12-12T12:27:54.343633Z :TRACE: [local] TRACE_EVENT InitResponse  partition_id=0 session_id=1199ee69-34530df5-a04a40c8-c42e672a|d7f3d2b1-7468cb1a-e3a0da9-6c2f087a_0
2025-12-12T12:27:54.343641Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.343639Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId [1199ee69-34530df5-a04a40c8-c42e672a|d7f3d2b1-7468cb1a-e3a0da9-6c2f087a_0]  PartitionId [0]  Generation [1] Write session: set DirectWriteToPartitionId 0
2025-12-12T12:27:54.343743Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.343715Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId [1199ee69-34530df5-a04a40c8-c42e672a|d7f3d2b1-7468cb1a-e3a0da9-6c2f087a_0]  PartitionId [0]  Generation [1] Write 1 messages with Id from 1 to 1
2025-12-12T12:27:54.343767Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.343765Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId [1199ee69-34530df5-a04a40c8-c42e672a|d7f3d2b1-7468cb1a-e3a0da9-6c2f087a_0]  PartitionId [0]  Generation [1] Write session: try to update token
2025-12-12T12:27:54.343775Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.343772Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId [1199ee69-34530df5-a04a40c8-c42e672a|d7f3d2b1-7468cb1a-e3a0da9-6c2f087a_0]  PartitionId [0]  Generation [1] Send 1 message(s) (0 left), first sequence number is 1
2025-12-12T12:27:54.343900Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.343898Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId [1199ee69-34530df5-a04a40c8-c42e672a|d7f3d2b1-7468cb1a-e3a0da9-6c2f087a_0]  PartitionId [0]  Generation [1] Write 1 messages with Id from 2 to 2
2025-12-12T12:27:54.343908Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.343907Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId [1199ee69-34530df5-a04a40c8-c42e672a|d7f3d2b1-7468cb1a-e3a0da9-6c2f087a_0]  PartitionId [0]  Generation [1] Write session: try to update token
2025-12-12T12:27:54.343913Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.343911Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId [1199ee69-34530df5-a04a40c8-c42e672a|d7f3d2b1-7468cb1a-e3a0da9-6c2f087a_0]  PartitionId [0]  Generation [1] Send 1 message(s) (0 left), first sequence number is 2
2025-12-12T12:27:54.343922Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.343920Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId [1199ee69-34530df5-a04a40c8-c42e672a|d7f3d2b1-7468cb1a-e3a0da9-6c2f087a_0]  PartitionId [0]  Generation [1] Write 1 messages with Id from 3 to 3
2025-12-12T12:27:54.343927Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.343925Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId [1199ee69-34530df5-a04a40c8-c42e672a|d7f3d2b1-7468cb1a-e3a0da9-6c2f087a_0]  PartitionId [0]  Generation [1] Write session: try to update token
2025-12-12T12:27:54.343930Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.343928Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId [1199ee69-34530df5-a04a40c8-c42e672a|d7f3d2b1-7468cb1a-e3a0da9-6c2f087a_0]  PartitionId [0]  Generation [1] Send 1 message(s) (0 left), first sequence number is 3
2025-12-12T12:27:54.346264Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.346254Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId [1199ee69-34530df5-a04a40c8-c42e672a|d7f3d2b1-7468cb1a-e3a0da9-6c2f087a_0]  PartitionId [0]  Generation [1] Write session: OnReadDone gRpcStatusCode: 0
2025-12-12T12:27:54.346320Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.346318Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId [1199ee69-34530df5-a04a40c8-c42e672a|d7f3d2b1-7468cb1a-e3a0da9-6c2f087a_0]  PartitionId [0]  Generation [1] Write session got write response: acks { seq_no: 1 written { } } write_statistics { persisting_time { nanos: 3000000 } min_queue_wait_time { } max_queue_wait_time { } partition_quota_wait_time { } topic_quota_wait_time { } }
2025-12-12T12:27:54.346327Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.346325Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId [1199ee69-34530df5-a04a40c8-c42e672a|d7f3d2b1-7468cb1a-e3a0da9-6c2f087a_0]  PartitionId [0]  Generation [1] OnAck: seqNo=1, txId=?
2025-12-12T12:27:54.346331Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.346330Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId [1199ee69-34530df5-a04a40c8-c42e672a|d7f3d2b1-7468cb1a-e3a0da9-6c2f087a_0]  PartitionId [0]  Generation [1] Write session: acknoledged message 1
2025-12-12T12:27:54.346560Z :KQP_COMPUTE TRACE: dq_pq_write_actor.cpp:454: SelfId: [1:7582947189514247388:2275], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. Ack seq no 1
2025-12-12T12:27:54.349805Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.349795Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId [1199ee69-34530df5-a04a40c8-c42e672a|d7f3d2b1-7468cb1a-e3a0da9-6c2f087a_0]  PartitionId [0]  Generation [1] Write session: OnReadDone gRpcStatusCode: 0
2025-12-12T12:27:54.349861Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.349858Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId [1199ee69-34530df5-a04a40c8-c42e672a|d7f3d2b1-7468cb1a-e3a0da9-6c2f087a_0]  PartitionId [0]  Generation [1] Write session got write response: acks { seq_no: 2 written { offset: 1 } } write_statistics { persisting_time { nanos: 4000000 } min_queue_wait_time { } max_queue_wait_time { } partition_quota_wait_time { } topic_quota_wait_time { } }
2025-12-12T12:27:54.349866Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.349864Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId [1199ee69-34530df5-a04a40c8-c42e672a|d7f3d2b1-7468cb1a-e3a0da9-6c2f087a_0]  PartitionId [0]  Generation [1] OnAck: seqNo=2, txId=?
2025-12-12T12:27:54.349871Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.349870Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId [1199ee69-34530df5-a04a40c8-c42e672a|d7f3d2b1-7468cb1a-e3a0da9-6c2f087a_0]  PartitionId [0]  Generation [1] Write session: acknoledged message 2
2025-12-12T12:27:54.349929Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.349926Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId [1199ee69-34530df5-a04a40c8-c42e672a|d7f3d2b1-7468cb1a-e3a0da9-6c2f087a_0]  PartitionId [0]  Generation [1] Write session: OnReadDone gRpcStatusCode: 0
2025-12-12T12:27:54.349942Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.349940Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId [1199ee69-34530df5-a04a40c8-c42e672a|d7f3d2b1-7468cb1a-e3a0da9-6c2f087a_0]  PartitionId [0]  Generation [1] Write session got write response: acks { seq_no: 3 written { offset: 2 } } write_statistics { persisting_time { nanos: 4000000 } min_queue_wait_time { } max_queue_wait_time { } partition_quota_wait_time { } topic_quota_wait_time { } }
2025-12-12T12:27:54.349947Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.349944Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId [1199ee69-34530df5-a04a40c8-c42e672a|d7f3d2b1-7468cb1a-e3a0da9-6c2f087a_0]  PartitionId [0]  Generation [1] OnAck: seqNo=3, txId=?
2025-12-12T12:27:54.349950Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:54.349949Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId [1199ee69-34530df5-a04a40c8-c42e672a|d7f3d2b1-7468cb1a-e3a0da9-6c2f087a_0]  PartitionId [0]  Generation [1] Write session: acknoledged message 3
2025-12-12T12:27:54.350042Z :KQP_COMPUTE TRACE: dq_pq_write_actor.cpp:454: SelfId: [1:7582947189514247388:2275], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. Ack seq no 2
2025-12-12T12:27:54.350045Z :KQP_COMPUTE TRACE: dq_pq_write_actor.cpp:454: SelfId: [1:7582947189514247388:2275], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. Ack seq no 3
2025-12-12T12:27:54.917349Z :YQL_NODES_MANAGER TRACE: nodes_manager.cpp:318: TNodesManagerActor::NodesHealthCheck
2025-12-12T12:27:54.924509Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:627: RowDispatcher: Send ping to [1:7582947103614901262:2093]
2025-12-12T12:27:54.924527Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1174: RowDispatcher: TEvPrivate::TEvSendStatistic
2025-12-12T12:27:54.924546Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [1:7582947103614901217:2065]
2025-12-12T12:27:54.924552Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7582947103614901217:2065]
2025-12-12T12:27:54.924555Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [1:7582947103614901217:2065]
2025-12-12T12:27:54.924563Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:633: RowDispatcher: NActors::TEvents::TEvPong
2025-12-12T12:27:54.925503Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 8f71b000-7466b0e9-41997d65-a6f433e622, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:54.929181Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:54.929191Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:54.931196Z :YQL_NODES_MANAGER TRACE: nodes_manager.cpp:389: Send NodeInfo with size: 0 to DynamicNameserver
2025-12-12T12:27:55.044384Z :YQL_PROXY TRACE: log.cpp:64: SessionId:  2025-12-12 12:27:55.044 TRACE ydbd(pid=1214775, tid=0x00007F4DE262D640) [DQ] task_controller_impl.h:271:  [1:7582947185219280081:2273] ExportStats Summary
2025-12-12T12:27:55.044585Z :FQ_PINGER TRACE: pinger.cpp:250: QueryId: ptqudq7uem53kjjhdml0, Owner: 8f71b000-7466b0e9-41997d65-a6f433e620 Forward ping request: { statistics: "{\"Graph=0\":{\"TaskRunner\":{\"Stage=204663\":{\"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=204683\":{\"CpuTimeUs\":{\"sum\":\"0.00s\",\"count\":1,\"avg\":\"0.00s\",\"max\":\"0.00s\",\"min\":\"0.00s\"},\"Tasks\":{\"sum\":1,\"count\":1,\"avg\":1,\"max\":1,\"min\":1}},\"Stage=Total\":{\"CpuTimeUs\":{\"sum\":\"0.00s\",\"count\":2,\"avg\":\"0.00s\",\"max\":\"0.00s\",\"min\":\"0.00s\"},\"Tasks\":{\"sum\":2,\"count\":2,\"avg\":1,\"max\":1,\"min\":1}}}}}" }
2025-12-12T12:27:55.044593Z :FQ_PINGER TRACE: pinger.cpp:393: QueryId: ptqudq7uem53kjjhdml0, Owner: 8f71b000-7466b0e9-41997d65-a6f433e620 Forward request Private::PingTask
2025-12-12T12:27:55.057584Z :FQ_PINGER TRACE: pinger.cpp:338: QueryId: ptqudq7uem53kjjhdml0, Owner: 8f71b000-7466b0e9-41997d65-a6f433e620 Ping response success: { action: ABORT expired_at { seconds: 1765542495 nanos: 51000000 } }
2025-12-12T12:27:55.057595Z :FQ_PINGER DEBUG: pinger.cpp:342: QueryId: ptqudq7uem53kjjhdml0, Owner: 8f71b000-7466b0e9-41997d65-a6f433e620 Query action: ABORT
2025-12-12T12:27:55.057625Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:690: QueryId: ptqudq7uem53kjjhdml0 New query action received: ABORT
2025-12-12T12:27:55.057631Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:1827: QueryId: ptqudq7uem53kjjhdml0 Is about to finish query with status ABORTED_BY_USER
2025-12-12T12:27:55.057633Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:1820: QueryId: ptqudq7uem53kjjhdml0 Write finalizing status: ABORTING_BY_USER
2025-12-12T12:27:55.057645Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:528: QueryId: ptqudq7uem53kjjhdml0 Cancel running query
2025-12-12T12:27:55.057658Z :FQ_PINGER TRACE: pinger.cpp:250: QueryId: ptqudq7uem53kjjhdml0, Owner: 8f71b000-7466b0e9-41997d65-a6f433e620 Forward ping request: { status: ABORTING_BY_USER }
2025-12-12T12:27:55.057673Z :FQ_PINGER TRACE: pinger.cpp:393: QueryId: ptqudq7uem53kjjhdml0, Owner: 8f71b000-7466b0e9-41997d65-a6f433e620 Forward request Private::PingTask
2025-12-12T12:27:55.057682Z :FQ_RUN_ACTOR TRACE: run_actor.cpp:880: QueryId: ptqudq7uem53kjjhdml0 Forward ping response. Success: 1. Cookie: 6
2025-12-12T12:27:55.057808Z :YQL_PROXY DEBUG: log.cpp:64: SessionId:  2025-12-12 12:27:55.057 DEBUG ydbd(pid=1214775, tid=0x00007F4DDFE28640) [DQ] task_controller_impl.h:130: AbortExecution from [1:7582947185219280077:2269]:ABORTED { <main>: Error: ABORTED_BY_USER }
2025-12-12T12:27:55.057829Z :YQL_PROXY DEBUG: log.cpp:64: SessionId:  2025-12-12 12:27:55.057 DEBUG ydbd(pid=1214775, tid=0x00007F4DDFE28640) [DQ] task_controller_impl.h:598: OnError { <main>: Error: ABORTED_BY_USER } ABORTED
2025-12-12T12:27:55.057890Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: ptqudq7uem53kjjhdml0 2025-12-12 12:27:55.057 DEBUG ydbd(pid=1214775, tid=0x00007F4DDFE28640) [DQ] executer_actor.cpp:304: {ptqudq7uem53kjjhdml0} OnFailure, status=4, issues size=1, sender=[1:7582947185219280081:2273]
2025-12-12T12:27:55.057907Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: ptqudq7uem53kjjhdml0 2025-12-12 12:27:55.057 DEBUG ydbd(pid=1214775, tid=0x00007F4DDFE28640) [DQ] executer_actor.cpp:315: {ptqudq7uem53kjjhdml0} Issues: <main>: Error: ABORTED_BY_USER

2025-12-12T12:27:55.057914Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: ptqudq7uem53kjjhdml0 2025-12-12 12:27:55.057 DEBUG ydbd(pid=1214775, tid=0x00007F4DDFE28640) [DQ] executer_actor.cpp:284: {ptqudq7uem53kjjhdml0} Finish with status=4 issues=<main>: Error: ABORTED_BY_USER

2025-12-12T12:27:55.058015Z :YQL_PROXY DEBUG: log.cpp:64: SessionId: ptqudq7uem53kjjhdml0 2025-12-12 12:27:55.057 DEBUG ydbd(pid=1214775, tid=0x00007F4DE262D640) [DQ] executer_actor.cpp:341: {ptqudq7uem53kjjhdml0} OnQueryResponse status=4 issuses_size=1
2025-12-12T12:27:55.058041Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:1396: QueryId: ptqudq7uem53kjjhdml0 TEvQueryResponse received on finish
2025-12-12T12:27:55.058047Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:1233: QueryId: ptqudq7uem53kjjhdml0 Query response CANCELLED. Result set index: 0. Issues count: 1. Rows count: 0
2025-12-12T12:27:55.058151Z :KQP_COMPUTE ERROR: dq_compute_actor_impl.h:1205: SelfId: [1:7582947189514247382:2276], TxId: ptqudq7uem53kjjhdml0, task: 1. Ctx: {}. Handle abort execution event from: [1:7582947103614901218:2066], status: UNAVAILABLE, reason: { <main>: Error: Aborted by LWM }
2025-12-12T12:27:55.058187Z :KQP_COMPUTE ERROR: dq_compute_actor_impl.h:1205: SelfId: [1:7582947189514247379:2275], TxId: ptqudq7uem53kjjhdml0, task: 2. Ctx: {}. Handle abort execution event from: [1:7582947103614901218:2066], status: UNAVAILABLE, reason: { <main>: Error: Aborted by LWM }
2025-12-12T12:27:55.058200Z :STREAMS_CHECKPOINT_COORDINATOR DEBUG: checkpoint_coordinator.cpp:657: [ptqudq7uem53kjjhdml0-0.2] PassAway
2025-12-12T12:27:55.058201Z :KQP_COMPUTE DEBUG: dq_compute_actor_channels.cpp:494: TxId: ptqudq7uem53kjjhdml0, task: 1. pass away
2025-12-12T12:27:55.058218Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:55.058215Z :INFO: [local] [local] [e6693091-4ecea588-216e7a65-e6408507] Closing read session. Close timeout: 0.000000s
2025-12-12T12:27:55.058224Z :KQP_COMPUTE DEBUG: dq_compute_actor_channels.cpp:494: TxId: ptqudq7uem53kjjhdml0, task: 2. pass away
2025-12-12T12:27:55.058232Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:55.058231Z :INFO: [local] Read/commit by partition streams (cluster:topic:partition:stream-id:read-offset:committed-offset): -:test_time_order_recoverer[v1-kikimr0]_v1_input:0:1:6:2
2025-12-12T12:27:55.058238Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:55.058237Z :INFO: [local] [local] [e6693091-4ecea588-216e7a65-e6408507] Counters: { Errors: 0 CurrentSessionLifetimeMs: 756 BytesRead: 115 MessagesRead: 5 BytesReadCompressed: 115 BytesInflightUncompressed: 0 BytesInflightCompressed: 0 BytesInflightTotal: 0 MessagesInflight: 0 }
2025-12-12T12:27:55.058259Z :YDB_SDK NOTICE: actor.cpp:37: 2025-12-12T12:27:55.058257Z :NOTICE: [local] [local] [e6693091-4ecea588-216e7a65-e6408507] Aborting read session. Description: SessionClosed { Status: ABORTED Issues: "<main>: Error: Close with zero timeout " }
2025-12-12T12:27:55.058265Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:55.058264Z :DEBUG: [local] [local] [e6693091-4ecea588-216e7a65-e6408507] [] Abort session to cluster
2025-12-12T12:27:55.058621Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:55.058617Z :INFO: [local] [local] [e6693091-4ecea588-216e7a65-e6408507] Closing read session. Close timeout: 0.000000s
2025-12-12T12:27:55.058634Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:55.058633Z :INFO: [local] Read/commit by partition streams (cluster:topic:partition:stream-id:read-offset:committed-offset): -:test_time_order_recoverer[v1-kikimr0]_v1_input:0:1:6:2
2025-12-12T12:27:55.058638Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:55.058637Z :INFO: [local] [local] [e6693091-4ecea588-216e7a65-e6408507] Counters: { Errors: 0 CurrentSessionLifetimeMs: 756 BytesRead: 115 MessagesRead: 5 BytesReadCompressed: 115 BytesInflightUncompressed: 0 BytesInflightCompressed: 0 BytesInflightTotal: 0 MessagesInflight: 0 }
2025-12-12T12:27:55.058647Z :YDB_SDK NOTICE: actor.cpp:37: 2025-12-12T12:27:55.058645Z :NOTICE: [local] [local] [e6693091-4ecea588-216e7a65-e6408507] Aborting read session. Description: SessionClosed { Status: ABORTED Issues: "<main>: Error: Aborted " }
2025-12-12T12:27:55.059891Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:55.059885Z :INFO: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId [1199ee69-34530df5-a04a40c8-c42e672a|d7f3d2b1-7468cb1a-e3a0da9-6c2f087a_0]  PartitionId [0]  Generation [1] Write session: close. Timeout 0.000000s
2025-12-12T12:27:55.059906Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:55.059904Z :INFO: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId [1199ee69-34530df5-a04a40c8-c42e672a|d7f3d2b1-7468cb1a-e3a0da9-6c2f087a_0]  PartitionId [0]  Generation [1] Write session will now close
2025-12-12T12:27:55.059928Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:55.059926Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId [1199ee69-34530df5-a04a40c8-c42e672a|d7f3d2b1-7468cb1a-e3a0da9-6c2f087a_0]  PartitionId [0]  Generation [1] Write session: aborting
2025-12-12T12:27:55.060043Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:55.060041Z :INFO: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId [1199ee69-34530df5-a04a40c8-c42e672a|d7f3d2b1-7468cb1a-e3a0da9-6c2f087a_0]  PartitionId [0]  Generation [1] Write session: gracefully shut down, all writes complete
2025-12-12T12:27:55.060052Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:55.060051Z :DEBUG: [local]  TraceId [SelfId: [0:0:0], TxId: ptqudq7uem53kjjhdml0, TaskId: 2, PQ sink. ]  SessionId [1199ee69-34530df5-a04a40c8-c42e672a|d7f3d2b1-7468cb1a-e3a0da9-6c2f087a_0]  PartitionId [0]  Generation [1] Write session: destroy
2025-12-12T12:27:55.070291Z :FQ_PINGER TRACE: pinger.cpp:338: QueryId: ptqudq7uem53kjjhdml0, Owner: 8f71b000-7466b0e9-41997d65-a6f433e620 Ping response success: { action: ABORT expired_at { seconds: 1765542495 nanos: 62000000 } }
2025-12-12T12:27:55.070315Z :FQ_PINGER DEBUG: pinger.cpp:342: QueryId: ptqudq7uem53kjjhdml0, Owner: 8f71b000-7466b0e9-41997d65-a6f433e620 Query action: ABORT
2025-12-12T12:27:55.070341Z :FQ_RUN_ACTOR TRACE: run_actor.cpp:880: QueryId: ptqudq7uem53kjjhdml0 Forward ping response. Success: 1. Cookie: 3
2025-12-12T12:27:55.070343Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:887: QueryId: ptqudq7uem53kjjhdml0 Finalizing status is saved
2025-12-12T12:27:55.070389Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:1507: QueryId: ptqudq7uem53kjjhdml0 Start rate limiter resource deleter
2025-12-12T12:27:55.070418Z :STREAMS DEBUG: read_rule_deleter.cpp:214: ptqudq7uem53kjjhdml0: Create read rule deleter actor for `test_time_order_recoverer[v1-kikimr0]_v1_input` [0]
2025-12-12T12:27:55.070469Z :STREAMS DEBUG: read_rule_deleter.cpp:106: ptqudq7uem53kjjhdml0: Make request for read rule deletion for topic `test_time_order_recoverer[v1-kikimr0]_v1_input` [0]
2025-12-12T12:27:55.115046Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:1498: QueryId: ptqudq7uem53kjjhdml0 Rate limiter resource deletion finished. Success: 1. Issues: 
2025-12-12T12:27:55.115063Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:1919: QueryId: ptqudq7uem53kjjhdml0 SendPingAndPassAway, FinalQueryStatus ABORTED_BY_USER
2025-12-12T12:27:55.115092Z :FQ_RUN_ACTOR DEBUG: run_actor.cpp:536: QueryId: ptqudq7uem53kjjhdml0 PassAway
2025-12-12T12:27:55.115267Z :FQ_PINGER TRACE: pinger.cpp:250: QueryId: ptqudq7uem53kjjhdml0, Owner: 8f71b000-7466b0e9-41997d65-a6f433e620 Forward ping request: { result_id { value: "ptrudq7ue01e8skng8d6" } status: ABORTED_BY_USER issues { message: "ABORTED_BY_USER" severity: 1 } statistics: "{\"Graph=0\":{\"Actor\":{\"ActorCreateTimeUs\":{\"sum\":\"0.13s\",\"count\":2,\"avg\":\"65ms\",\"max\":\"65ms\",\"min\":\"65ms\"}},\"AllocateWorkersUs\":{\"sum\":\"66ms\",\"count\":1,\"avg\":\"66ms\",\"max\":\"66ms\",\"min\":\"66ms\"},\"ExecutionTimeUs\":{\"sum\":\"1.01s\",\"count\":1,\"avg\":\"1.01s\",\"max\":\"1.01s\",\"min\":\"1.01s\"},\"TaskRunner\":{\"Stage=204663\":{\"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=204683\":{\"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_1fb303ed-ed93-4034-ace4-b066e21a3ab1/rate_limiter" topic_consumers { database: "local" topic_path: "test_time_order_recoverer[v1-kikimr0]_v1_input" consumer_name: "ptqudq7uem53kjjhdml0" cluster_endpoint: "localhost:25827" token_name: "cluster:default_myyds" add_bearer_to_token: true } } finished_at { seconds: 1765542475 nanos: 57000000 } }
2025-12-12T12:27:55.115275Z :FQ_PINGER TRACE: pinger.cpp:393: QueryId: ptqudq7uem53kjjhdml0, Owner: 8f71b000-7466b0e9-41997d65-a6f433e620 Forward request Private::PingTask
2025-12-12T12:27:55.211898Z :FQ_PINGER TRACE: pinger.cpp:338: QueryId: ptqudq7uem53kjjhdml0, Owner: 8f71b000-7466b0e9-41997d65-a6f433e620 Ping response success: { action: ABORT }
2025-12-12T12:27:55.211922Z :FQ_PINGER DEBUG: pinger.cpp:379: QueryId: ptqudq7uem53kjjhdml0, Owner: 8f71b000-7466b0e9-41997d65-a6f433e620 Query finished
2025-12-12T12:27:55.211924Z :FQ_PINGER TRACE: pinger.cpp:187: QueryId: ptqudq7uem53kjjhdml0, Owner: 8f71b000-7466b0e9-41997d65-a6f433e620 Stop Pinger
2025-12-12T12:27:55.926003Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 8f71b000-7466b0e9-41997d65-a6f433e623, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:55.931624Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:55.931644Z :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:23850: Failed to connect to remote host: Connection refused
<main>: Error: Grpc error response on endpoint ghrun-fhkyrtz6p4.auto.internal:23850
2025-12-12T12:27:56.925396Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:627: RowDispatcher: Send ping to [1:7582947103614901262:2093]
2025-12-12T12:27:56.925417Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1174: RowDispatcher: TEvPrivate::TEvSendStatistic
2025-12-12T12:27:56.925425Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [1:7582947103614901217:2065]
2025-12-12T12:27:56.925428Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7582947103614901217:2065]
2025-12-12T12:27:56.925430Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [1:7582947103614901217:2065]
2025-12-12T12:27:56.925439Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:633: RowDispatcher: NActors::TEvents::TEvPong
2025-12-12T12:27:56.926438Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 8f71b000-7466b0e9-41997d65-a6f433e624, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:56.931449Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:56.931475Z :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:23850: Failed to connect to remote host: Connection refused
<main>: Error: Grpc error response on endpoint ghrun-fhkyrtz6p4.auto.internal:23850
2025-12-12T12:27:57.926885Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 8f71b000-7466b0e9-41997d65-a6f433e625, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:57.937889Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:57.937909Z :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:23850: Failed to connect to remote host: Connection refused
<main>: Error: Grpc error response on endpoint ghrun-fhkyrtz6p4.auto.internal:23850
2025-12-12T12:27:58.926295Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:627: RowDispatcher: Send ping to [1:7582947103614901262:2093]
2025-12-12T12:27:58.926314Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1174: RowDispatcher: TEvPrivate::TEvSendStatistic
2025-12-12T12:27:58.926327Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [1:7582947103614901217:2065]
2025-12-12T12:27:58.926332Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7582947103614901217:2065]
2025-12-12T12:27:58.926335Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [1:7582947103614901217:2065]
2025-12-12T12:27:58.926347Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:633: RowDispatcher: NActors::TEvents::TEvPong
2025-12-12T12:27:58.927317Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 8f71b000-7466b0e9-41997d65-a6f433e626, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:58.932485Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:58.932503Z :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:23850: Failed to connect to remote host: Connection refused
<main>: Error: Grpc error response on endpoint ghrun-fhkyrtz6p4.auto.internal:23850
2025-12-12T12:27:59.917539Z :YQL_NODES_MANAGER TRACE: nodes_manager.cpp:318: TNodesManagerActor::NodesHealthCheck
2025-12-12T12:27:59.923734Z :YQL_NODES_MANAGER ERROR: nodes_manager.cpp:395: ydb/core/fq/libs/actors/nodes_manager.cpp:353: TRANSPORT_UNAVAILABLE
<main>: Error: GRpc error: (14): connections to all backends failing; last error: UNKNOWN: ipv4:127.0.1.1:23850: Failed to connect to remote host: Connection refused
<main>: Error: Grpc error response on endpoint ghrun-fhkyrtz6p4.auto.internal:23850
2025-12-12T12:27:59.927774Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 8f71b000-7466b0e9-41997d65-a6f433e627, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:59.932305Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:59.932325Z :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:23850: Failed to connect to remote host: Connection refused
<main>: Error: Grpc error response on endpoint ghrun-fhkyrtz6p4.auto.internal:23850
2025-12-12T12:28:00.927192Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:627: RowDispatcher: Send ping to [1:7582947103614901262:2093]
2025-12-12T12:28:00.927212Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1174: RowDispatcher: TEvPrivate::TEvSendStatistic
2025-12-12T12:28:00.927219Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [1:7582947103614901217:2065]
2025-12-12T12:28:00.927222Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7582947103614901217:2065]
2025-12-12T12:28:00.927225Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [1:7582947103614901217:2065]
2025-12-12T12:28:00.927235Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:633: RowDispatcher: NActors::TEvents::TEvPong
2025-12-12T12:28:00.928212Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 8f71b000-7466b0e9-41997d65-a6f433e628, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:28:00.939337Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:28:00.939357Z :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:23850: Failed to connect to remote host: Connection refused
<main>: Error: Grpc error response on endpoint ghrun-fhkyrtz6p4.auto.internal:23850
2025-12-12T12:28:01.928648Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 8f71b000-7466b0e9-41997d65-a6f433e629, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:28:01.933958Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:28:01.933978Z :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:23850: Failed to connect to remote host: Connection refused
<main>: Error: Grpc error response on endpoint ghrun-fhkyrtz6p4.auto.internal:23850
