2025-12-12T12:27:29.625135Z :GRPC_SERVER NOTICE: grpc_request_proxy.cpp:380: Grpc request proxy started, nodeid# 1, serve as static node
2025-12-12T12:27:29.625207Z :GRPC_SERVER CRIT: grpc_request_proxy.cpp:440: Failed to deliver subscription request to config dispatcher
2025-12-12T12:27:29.625213Z :GRPC_SERVER NOTICE: grpc_request_proxy.cpp:380: Grpc request proxy started, nodeid# 1, serve as static node
2025-12-12T12:27:29.625233Z :GRPC_SERVER CRIT: grpc_request_proxy.cpp:440: Failed to deliver subscription request to config dispatcher
2025-12-12T12:27:29.625868Z :STREAMS_STORAGE_SERVICE INFO: storage_proxy.cpp:214: Bootstrap
2025-12-12T12:27:29.625872Z :STREAMS_STORAGE_SERVICE INFO: storage_proxy.cpp:217: Create sdk ydb connection
2025-12-12T12:27:29.625955Z :STREAMS_STORAGE_SERVICE INFO: storage_proxy.cpp:239: Successfully bootstrapped TStorageProxy [1:7582947081859914881:2062] with connection to localhost:9655:local
2025-12-12T12:27:29.625968Z :FQ_ROW_DISPATCHER DEBUG: row_dispatcher.cpp:544: RowDispatcher: Successfully bootstrapped row dispatcher, id [1:7582947081859914882:2063], tenant /compute
2025-12-12T12:27:29.625982Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7582947081859914882:2063]
2025-12-12T12:27:29.625983Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:329: Coordinator: Add new row dispatcher to map (state 1)
2025-12-12T12:27:29.626098Z :YQL_NODES_MANAGER INFO: nodes_manager.cpp:88: Bootstrap, InstanceId: 45fb0e81-463ed951-c23c0a9b-b885eab8
2025-12-12T12:27:29.626099Z :YQL_NODES_MANAGER DEBUG: nodes_manager.cpp:310: TNodesManagerActor::ResolveSelfAddress
2025-12-12T12:27:29.626131Z :FQ_QUOTA_PROXY INFO: quota_proxy.cpp:90: STARTED
2025-12-12T12:27:29.626157Z :FQ_LOG_UPDATER DEBUG: log.cpp:93: Updated YQL logs priority: 8
2025-12-12T12:27:29.626160Z :FQ_LOG_UPDATER CRIT: log.cpp:55: Failed to deliver subscription request to config dispatcher.
2025-12-12T12:27:29.626192Z :YQ_RATE_LIMITER INFO: quoter_service.cpp:124: Bootstraping with config: { Enabled: true DataPlaneEnabled: true Database { Endpoint: "localhost:9655" Database: "local" TablePrefix: "RateLimiter_e0c8d7ba-1543-4913-8d1e-1a9eb9bae724" } Limiters { CoordinationNodePath: "rate_limiter" } }
2025-12-12T12:27:29.626291Z :FQ_ROW_DISPATCHER DEBUG: coordinator.cpp:293: Coordinator: Successfully bootstrapped coordinator, id [1:7582947081859914922:2082], NodesManagerId [0:4705493345362661702:78], rebalancing timeout 5.000000s
2025-12-12T12:27:29.626301Z :FQ_ROW_DISPATCHER DEBUG: leader_election.cpp:232: TLeaderElection [1:7582947081859914923:2083] Successfully bootstrapped, local coordinator id [1:7582947081859914922:2082], tenant id compute, local mode 0, coordination node path local/compute, endpoint localhost:9655
2025-12-12T12:27:29.627206Z :FQ_QUOTA_SERVICE INFO: quota_manager.cpp:196: STARTED
2025-12-12T12:27:29.627294Z :YQ_TEST_CONNECTION DEBUG: test_connection.cpp:142: Starting yandex query test connection. Actor id: [1:7582947081859914887:2068]
2025-12-12T12:27:29.627332Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 4c7b4b3e-d9d2d511-76304cae-9b3741581, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:29.627352Z :FQ_ROW_DISPATCHER DEBUG: row_dispatcher.cpp:637: RowDispatcher: TEvCoordinatorChangesSubscribe from [1:7582947081859914922:2082]
2025-12-12T12:27:29.627978Z :YQL_NODES_MANAGER TRACE: nodes_manager.cpp:318: TNodesManagerActor::NodesHealthCheck
2025-12-12T12:27:29.631518Z :FQ_ROW_DISPATCHER DEBUG: schema.cpp:71: Run create coordination node "local/compute" actor
2025-12-12T12:27:29.631528Z :FQ_ROW_DISPATCHER DEBUG: schema.cpp:113: Call create coordination node "local/compute"
2025-12-12T12:27:29.631530Z :FQ_ROW_DISPATCHER DEBUG: schema.cpp:411: Call create coordination node "local/compute"
2025-12-12T12:27:29.639077Z :MEMORY_PROFILER NOTICE: monitor.cpp:332: Bootstrapped
2025-12-12T12:27:29.655769Z :SCHEME_BOARD_SUBSCRIBER NOTICE: subscriber.cpp:849: [main][1:7582947081859914904:2080][/compute] Set up state: owner# [1:7582947081859914862:2053], state# { Deleted: 1 Strong: 0 Version: <Invalid> DomainId: <Invalid> AbandonedSchemeShards: there are 0 elements }
2025-12-12T12:27:29.655798Z :GRPC_SERVER WARN: grpc_request_proxy.cpp:583: SchemeBoardDelete /compute Strong=0
2025-12-12T12:27:29.655831Z :SCHEME_BOARD_SUBSCRIBER NOTICE: subscriber.cpp:849: [main][1:7582947081859914902:2078][/compute] Set up state: owner# [1:7582947081859914861:2052], state# { Deleted: 1 Strong: 0 Version: <Invalid> DomainId: <Invalid> AbandonedSchemeShards: there are 0 elements }
2025-12-12T12:27:29.655842Z :SCHEME_BOARD_SUBSCRIBER NOTICE: subscriber.cpp:849: [main][1:7582947081859914901:2077][/Root] Set up state: owner# [1:7582947081859914861:2052], state# { Deleted: 1 Strong: 0 Version: <Invalid> DomainId: <Invalid> AbandonedSchemeShards: there are 0 elements }
2025-12-12T12:27:29.655851Z :SCHEME_BOARD_SUBSCRIBER NOTICE: subscriber.cpp:849: [main][1:7582947081859914903:2079][/Root] Set up state: owner# [1:7582947081859914862:2053], state# { Deleted: 1 Strong: 0 Version: <Invalid> DomainId: <Invalid> AbandonedSchemeShards: there are 0 elements }
2025-12-12T12:27:29.655862Z :GRPC_SERVER WARN: grpc_request_proxy.cpp:583: SchemeBoardDelete /compute Strong=0
2025-12-12T12:27:29.655863Z :GRPC_SERVER WARN: grpc_request_proxy.cpp:583: SchemeBoardDelete /Root Strong=0
2025-12-12T12:27:29.655899Z :GRPC_SERVER WARN: grpc_request_proxy.cpp:583: SchemeBoardDelete /Root Strong=0
2025-12-12T12:27:29.667703Z :FQ_ROW_DISPATCHER DEBUG: schema.cpp:155: Successfully created coordination node "local/compute"
2025-12-12T12:27:29.667728Z :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:29.667737Z :FQ_ROW_DISPATCHER DEBUG: leader_election.cpp:345: TLeaderElection [1:7582947081859914923:2083] Coordination node successfully created
2025-12-12T12:27:29.667741Z :FQ_ROW_DISPATCHER DEBUG: leader_election.cpp:323: TLeaderElection [1:7582947081859914923:2083] Start session
2025-12-12T12:27:29.671151Z :FQ_ROW_DISPATCHER DEBUG: leader_election.cpp:359: TLeaderElection [1:7582947081859914923:2083] Session successfully created
2025-12-12T12:27:29.683042Z :FQ_ROW_DISPATCHER DEBUG: leader_election.cpp:372: TLeaderElection [1:7582947081859914923:2083] Semaphore successfully created
2025-12-12T12:27:29.683056Z :FQ_ROW_DISPATCHER DEBUG: leader_election.cpp:304: TLeaderElection [1:7582947081859914923:2083] Try to acquire semaphore
2025-12-12T12:27:29.683169Z :FQ_ROW_DISPATCHER DEBUG: leader_election.cpp:420: TLeaderElection [1:7582947081859914923:2083] Describe semaphore
2025-12-12T12:27:29.687490Z :FQ_ROW_DISPATCHER DEBUG: leader_election.cpp:386: TLeaderElection [1:7582947081859914923:2083] Semaphore successfully acquired
2025-12-12T12:27:29.690266Z :FQ_ROW_DISPATCHER DEBUG: leader_election.cpp:469: TLeaderElection [1:7582947081859914923:2083] Semaphore successfully described: coordinator id [1:7582947081859914922:2082] generation 4
2025-12-12T12:27:29.690281Z :FQ_ROW_DISPATCHER INFO: leader_election.cpp:471: TLeaderElection [1:7582947081859914923:2083] Send TEvCoordinatorChanged to [1:7582947081859914882:2063], new coordinator id [1:7582947081859914922:2082], previous coordinator id [0:0:0]
2025-12-12T12:27:29.690301Z :FQ_ROW_DISPATCHER DEBUG: row_dispatcher.cpp:569: RowDispatcher: Coordinator changed, old leader (empty maybe), new [1:7582947081859914922:2082] generation 4
2025-12-12T12:27:29.690315Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [1:7582947081859914882:2063]
2025-12-12T12:27:29.690318Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7582947081859914882:2063]
2025-12-12T12:27:29.690320Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [1:7582947081859914882:2063]
2025-12-12T12:27:29.690327Z :FQ_ROW_DISPATCHER DEBUG: coordinator.cpp:440: Coordinator: New leader [1:7582947081859914922:2082], SelfId [1:7582947081859914922:2082]
2025-12-12T12:27:29.690330Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:633: RowDispatcher: NActors::TEvents::TEvPong
2025-12-12T12:27:29.723097Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:29.723114Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:29.723141Z :YQL_NODES_MANAGER TRACE: nodes_manager.cpp:389: Send NodeInfo with size: 0 to DynamicNameserver
2025-12-12T12:27:30.382280Z :INTERCONNECT ERROR: interconnect_nameserver_dynamic.cpp:62:  ICN06 Unknown nodeId: 2
2025-12-12T12:27:30.623110Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 4c7b4b3e-d9d2d511-76304cae-9b3741582, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:30.627268Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:30.627282Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:30.835652Z :INTERCONNECT ERROR: interconnect_nameserver_dynamic.cpp:62:  ICN06 Unknown nodeId: 2
2025-12-12T12:27:30.835672Z :INTERCONNECT ERROR: interconnect_nameserver_dynamic.cpp:62:  ICN06 Unknown nodeId: 3
2025-12-12T12:27:31.098843Z :INTERCONNECT ERROR: interconnect_nameserver_dynamic.cpp:62:  ICN06 Unknown nodeId: 3
2025-12-12T12:27:31.539162Z :INTERCONNECT ERROR: interconnect_nameserver_dynamic.cpp:62:  ICN06 Unknown nodeId: 3
2025-12-12T12:27:31.623125Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:627: RowDispatcher: Send ping to [1:7582947081859914922:2082]
2025-12-12T12:27:31.623157Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1174: RowDispatcher: TEvPrivate::TEvSendStatistic
2025-12-12T12:27:31.623167Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [1:7582947081859914882:2063]
2025-12-12T12:27:31.623175Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7582947081859914882:2063]
2025-12-12T12:27:31.623178Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [1:7582947081859914882:2063]
2025-12-12T12:27:31.623196Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:633: RowDispatcher: NActors::TEvents::TEvPong
2025-12-12T12:27:31.624143Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 4c7b4b3e-d9d2d511-76304cae-9b3741583, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:31.627115Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:31.627127Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:31.934418Z :INTERCONNECT ERROR: interconnect_nameserver_dynamic.cpp:62:  ICN06 Unknown nodeId: 2
2025-12-12T12:27:32.624623Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 4c7b4b3e-d9d2d511-76304cae-9b3741584, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:32.628156Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:32.628183Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:32.701404Z :INTERCONNECT ERROR: interconnect_nameserver_dynamic.cpp:62:  ICN06 Unknown nodeId: 3
2025-12-12T12:27:33.135563Z :INTERCONNECT ERROR: interconnect_nameserver_dynamic.cpp:62:  ICN06 Unknown nodeId: 2
2025-12-12T12:27:33.624026Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:627: RowDispatcher: Send ping to [1:7582947081859914922:2082]
2025-12-12T12:27:33.624049Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1174: RowDispatcher: TEvPrivate::TEvSendStatistic
2025-12-12T12:27:33.624057Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [1:7582947081859914882:2063]
2025-12-12T12:27:33.624060Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7582947081859914882:2063]
2025-12-12T12:27:33.624062Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [1:7582947081859914882:2063]
2025-12-12T12:27:33.624071Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:633: RowDispatcher: NActors::TEvents::TEvPong
2025-12-12T12:27:33.625065Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 4c7b4b3e-d9d2d511-76304cae-9b3741585, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:33.627878Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:33.627891Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:34.183126Z :INTERCONNECT ERROR: interconnect_nameserver_dynamic.cpp:62:  ICN06 Unknown nodeId: 3
2025-12-12T12:27:34.183152Z :INTERCONNECT ERROR: interconnect_nameserver_dynamic.cpp:62:  ICN06 Unknown nodeId: 2
2025-12-12T12:27:34.623491Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:665: Coordinator: Change global state to Started (by timeout)
2025-12-12T12:27:34.623494Z :YQL_NODES_MANAGER TRACE: nodes_manager.cpp:318: TNodesManagerActor::NodesHealthCheck
2025-12-12T12:27:34.625497Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 4c7b4b3e-d9d2d511-76304cae-9b3741586, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:34.630816Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:34.630827Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:34.636937Z :YQL_NODES_MANAGER TRACE: nodes_manager.cpp:389: Send NodeInfo with size: 2 to DynamicNameserver
2025-12-12T12:27:34.779306Z :INTERCONNECT WARN: interconnect_handshake.cpp:501: Handshake [1:7582947103334751584:2063] [node 3] ICH09 Neither CompatibilityInfo nor VersionTag of the peer can be validated, accepting by default
2025-12-12T12:27:34.779657Z :INTERCONNECT WARN: interconnect_handshake.cpp:501: Handshake [1:7582947103334751586:2064] [node 2] ICH09 Neither CompatibilityInfo nor VersionTag of the peer can be validated, accepting by default
2025-12-12T12:27:35.184669Z :FQ_ROW_DISPATCHER INFO: coordinator.cpp:507: Coordinator: TEvCoordinatorRequest from [2:7582947089337657689:2150], test_filter_missing_fields_input, partIds: 0
2025-12-12T12:27:35.184704Z :FQ_ROW_DISPATCHER DEBUG: coordinator.cpp:562: Coordinator: Send TEvCoordinatorResult to [2:7582947089337657689:2150]
2025-12-12T12:27:35.184722Z :FQ_ROW_DISPATCHER DEBUG: coordinator.cpp:392: Coordinator: EvNodeConnected 2
2025-12-12T12:27:35.185613Z :FQ_ROW_DISPATCHER DEBUG: row_dispatcher.cpp:853: RowDispatcher: Received TEvStartSession from [2:7582947089337657689:2150], read group ptcudq7uemfchldv1md0, topicPath test_filter_missing_fields_input part id 0 query id ptqudq7uem2o5or4krva cookie 1
2025-12-12T12:27:35.185647Z :FQ_ROW_DISPATCHER DEBUG: row_dispatcher.cpp:892: RowDispatcher: Create new session: read group ptcudq7uemfchldv1md0 topic test_filter_missing_fields_input part id 0
2025-12-12T12:27:35.185703Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1052: RowDispatcher: TEvTryConnect to node id 2
2025-12-12T12:27:35.185741Z :FQ_ROW_DISPATCHER DEBUG: topic_session.cpp:443: TopicSession [1:7582947107629718895:2150] Bootstrap test_filter_missing_fields_input/0, Timeout 5.000000s sec
2025-12-12T12:27:35.185756Z :FQ_ROW_DISPATCHER INFO: topic_session.cpp:799: TopicSession [1:7582947107629718895:2150] New client: read actor id [2:7582947089337657689:2150], predicate: (`data@data` IS NULL), watermark expr: , offset: (empty maybe)
2025-12-12T12:27:35.185774Z :FQ_ROW_DISPATCHER DEBUG: row_dispatcher.cpp:587: RowDispatcher: EvNodeConnected, node id 2
2025-12-12T12:27:35.185804Z :FQ_ROW_DISPATCHER DEBUG: format_handler.cpp:440: TTopicFormatHandler [json_each_row]: Add client with id [2:7582947089337657689:2150]
2025-12-12T12:27:35.219557Z :FQ_ROW_DISPATCHER DEBUG: format_handler.cpp:559: TTopicFormatHandler [json_each_row]: UpdateParser to new schema with size 2
2025-12-12T12:27:35.220549Z :FQ_ROW_DISPATCHER INFO: json_parser.cpp:355: TJsonParser: Simdjson active implementation icelake (Intel/AMD AVX512), error skip mode: 0
2025-12-12T12:27:35.220607Z :FQ_ROW_DISPATCHER DEBUG: format_handler.cpp:570: TTopicFormatHandler [json_each_row]: Parser was created on schema with 2 columns
2025-12-12T12:27:35.220624Z :FQ_ROW_DISPATCHER DEBUG: purecalc_filter.cpp:461: GenerateSql: Generated sql:

            PRAGMA config.flags("LLVM", "OFF");
            SELECT COALESCE((`data@data` IS NULL), FALSE) AS _filter, _offset FROM Input;
        
2025-12-12T12:27:35.220642Z :FQ_ROW_DISPATCHER TRACE: filters_set.cpp:116: TTopicFilters: Create program with client id [2:7582947089337657689:2150]
2025-12-12T12:27:35.220646Z :FQ_ROW_DISPATCHER TRACE: filters_set.cpp:123: TTopicFilters: Create purecalc program for query '
            PRAGMA config.flags("LLVM", "OFF");
            SELECT COALESCE((`data@data` IS NULL), FALSE) AS _filter, _offset FROM Input;
        ' (client id: [2:7582947089337657689:2150])
2025-12-12T12:27:35.220654Z :FQ_ROW_DISPATCHER TRACE: purecalc_filter.cpp:341: TProgramCompileHandler: Send compile request with id 1
2025-12-12T12:27:35.220670Z :FQ_ROW_DISPATCHER TRACE: topic_session.cpp:952: TopicSession [1:7582947107629718895:2150] SendStatistics
2025-12-12T12:27:35.220680Z :FQ_ROW_DISPATCHER TRACE: compile_service.cpp:131: TPurecalcCompileService: Add to compile queue request with id 1 from [1:7582947107629718896:2150]
2025-12-12T12:27:35.220704Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1234: RowDispatcher: TEvSessionStatistic from [1:7582947107629718895:2150]
2025-12-12T12:27:35.562229Z :FQ_ROW_DISPATCHER TRACE: compile_service.cpp:52: TPurecalcCompileActor [1:7582947107629718896:2150] [id 1]: Started compile request
2025-12-12T12:27:35.610188Z :FQ_ROW_DISPATCHER TRACE: compile_service.cpp:70: TPurecalcCompileActor [1:7582947107629718896:2150] [id 1]: Compilation completed for request
2025-12-12T12:27:35.610231Z :FQ_ROW_DISPATCHER TRACE: filters_set.cpp:57: TTopicFilters: Got compile response for request with id 1
2025-12-12T12:27:35.610240Z :FQ_ROW_DISPATCHER TRACE: purecalc_filter.cpp:370: TProgramCompileHandler: Program compilation finished
2025-12-12T12:27:35.610240Z :FQ_ROW_DISPATCHER TRACE: compile_service.cpp:151: TPurecalcCompileService: Compile finished for request with id 1 from [1:7582947107629718896:2150]
2025-12-12T12:27:35.610254Z :FQ_ROW_DISPATCHER TRACE: filters_set.cpp:110: TTopicFilters: Start program with client id [2:7582947089337657689:2150]
2025-12-12T12:27:35.624887Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:627: RowDispatcher: Send ping to [1:7582947081859914922:2082]
2025-12-12T12:27:35.624915Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1174: RowDispatcher: TEvPrivate::TEvSendStatistic
2025-12-12T12:27:35.624934Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [1:7582947081859914882:2063]
2025-12-12T12:27:35.624949Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7582947081859914882:2063]
2025-12-12T12:27:35.624952Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [1:7582947081859914882:2063]
2025-12-12T12:27:35.624964Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:633: RowDispatcher: NActors::TEvents::TEvPong
2025-12-12T12:27:35.625930Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 4c7b4b3e-d9d2d511-76304cae-9b3741587, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:35.628110Z :FQ_QUOTA_SERVICE DEBUG: quota_manager.cpp:230: IC Peers[2]: [2, 3]
2025-12-12T12:27:35.629128Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:35.629134Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:36.103144Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [2:7582947085042690188:2063]
2025-12-12T12:27:36.103162Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [2:7582947085042690188:2063]
2025-12-12T12:27:36.103165Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:329: Coordinator: Add new row dispatcher to map (state 0)
2025-12-12T12:27:36.103168Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:334: Coordinator: Schedule TEvRebalancing
2025-12-12T12:27:36.103171Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [2:7582947085042690188:2063]
2025-12-12T12:27:36.604314Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [3:7582947085532780485:2063]
2025-12-12T12:27:36.604337Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [3:7582947085532780485:2063]
2025-12-12T12:27:36.604340Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:329: Coordinator: Add new row dispatcher to map (state 0)
2025-12-12T12:27:36.604344Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [3:7582947085532780485:2063]
2025-12-12T12:27:36.604364Z :FQ_ROW_DISPATCHER DEBUG: coordinator.cpp:392: Coordinator: EvNodeConnected 3
2025-12-12T12:27:36.626431Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 4c7b4b3e-d9d2d511-76304cae-9b3741588, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:36.632476Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:36.632501Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:37.186590Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:962: RowDispatcher: Received TEvHeartbeat from [2:7582947089337657689:2150], part id 0 query id ptqudq7uem2o5or4krva
2025-12-12T12:27:37.187583Z :FQ_ROW_DISPATCHER TRACE: topic_session.cpp:952: TopicSession [1:7582947107629718895:2150] SendStatistics
2025-12-12T12:27:37.187612Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1234: RowDispatcher: TEvSessionStatistic from [1:7582947107629718895:2150]
2025-12-12T12:27:37.625811Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:627: RowDispatcher: Send ping to [1:7582947081859914922:2082]
2025-12-12T12:27:37.625835Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1174: RowDispatcher: TEvPrivate::TEvSendStatistic
2025-12-12T12:27:37.625856Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [1:7582947081859914882:2063]
2025-12-12T12:27:37.625861Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7582947081859914882:2063]
2025-12-12T12:27:37.625864Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [1:7582947081859914882:2063]
2025-12-12T12:27:37.625884Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:633: RowDispatcher: NActors::TEvents::TEvPong
2025-12-12T12:27:37.626837Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 4c7b4b3e-d9d2d511-76304cae-9b3741589, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:37.629915Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:37.629926Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:38.104151Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [2:7582947085042690188:2063]
2025-12-12T12:27:38.104167Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [2:7582947085042690188:2063]
2025-12-12T12:27:38.104170Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [2:7582947085042690188:2063]
2025-12-12T12:27:38.605243Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [3:7582947085532780485:2063]
2025-12-12T12:27:38.605260Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [3:7582947085532780485:2063]
2025-12-12T12:27:38.605263Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [3:7582947085532780485:2063]
2025-12-12T12:27:38.627301Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 4c7b4b3e-d9d2d511-76304cae-9b37415810, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:38.630107Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:38.630119Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:39.188430Z :FQ_ROW_DISPATCHER TRACE: topic_session.cpp:952: TopicSession [1:7582947107629718895:2150] SendStatistics
2025-12-12T12:27:39.188436Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1067: RowDispatcher: Send TEvHeartbeat to [2:7582947089337657689:2150] query id ptqudq7uem2o5or4krva
2025-12-12T12:27:39.188457Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1234: RowDispatcher: TEvSessionStatistic from [1:7582947107629718895:2150]
2025-12-12T12:27:39.189444Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:962: RowDispatcher: Received TEvHeartbeat from [2:7582947089337657689:2150], part id 0 query id ptqudq7uem2o5or4krva
2025-12-12T12:27:39.622600Z :FQ_ROW_DISPATCHER DEBUG: coordinator.cpp:599: Coordinator: Send TEvGetNodesRequest to NodesManager
2025-12-12T12:27:39.622634Z :YQL_NODES_MANAGER TRACE: nodes_manager.cpp:300: Received TNodesManagerActor::TEvGetNodesRequest
2025-12-12T12:27:39.622643Z :FQ_ROW_DISPATCHER INFO: coordinator.cpp:690: Coordinator: Updated node info, node count: 3
2025-12-12T12:27:39.625263Z :YQL_NODES_MANAGER TRACE: nodes_manager.cpp:318: TNodesManagerActor::NodesHealthCheck
2025-12-12T12:27:39.626699Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:627: RowDispatcher: Send ping to [1:7582947081859914922:2082]
2025-12-12T12:27:39.626716Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1174: RowDispatcher: TEvPrivate::TEvSendStatistic
2025-12-12T12:27:39.626733Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [1:7582947081859914882:2063]
2025-12-12T12:27:39.626738Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7582947081859914882:2063]
2025-12-12T12:27:39.626741Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [1:7582947081859914882:2063]
2025-12-12T12:27:39.626755Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:633: RowDispatcher: NActors::TEvents::TEvPong
2025-12-12T12:27:39.627755Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 4c7b4b3e-d9d2d511-76304cae-9b37415811, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:39.636564Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:39.636585Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:39.641732Z :YQL_NODES_MANAGER TRACE: nodes_manager.cpp:389: Send NodeInfo with size: 2 to DynamicNameserver
2025-12-12T12:27:40.104812Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [2:7582947085042690188:2063]
2025-12-12T12:27:40.104833Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [2:7582947085042690188:2063]
2025-12-12T12:27:40.104837Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [2:7582947085042690188:2063]
2025-12-12T12:27:40.607231Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [3:7582947085532780485:2063]
2025-12-12T12:27:40.607251Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [3:7582947085532780485:2063]
2025-12-12T12:27:40.607258Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [3:7582947085532780485:2063]
2025-12-12T12:27:40.609819Z :FQ_ROW_DISPATCHER INFO: topic_session.cpp:516: TopicSession [1:7582947107629718895:2150] Create topic session, Path test_filter_missing_fields_input/0, StartingMessageTimestamp 2025-12-12T12:27:31.540000Z, BufferSize 16000000, GetConsumerMode Without
2025-12-12T12:27:40.609870Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:40.609865Z :INFO: [local] [local] [cac0108f-3a36a4d9-10074534-b33d2d27] Starting read session
2025-12-12T12:27:40.609876Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:40.609873Z :DEBUG: [local] [local] [cac0108f-3a36a4d9-10074534-b33d2d27] Starting single session
2025-12-12T12:27:40.609922Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:40.609920Z :DEBUG: [local] [local] [cac0108f-3a36a4d9-10074534-b33d2d27] [] In Reconnect, ReadSizeBudget = 8000000, ReadSizeServerDelta = 0
2025-12-12T12:27:40.609931Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:40.609930Z :DEBUG: [local] [local] [cac0108f-3a36a4d9-10074534-b33d2d27] [] New values: ReadSizeBudget = 8000000, ReadSizeServerDelta = 0
2025-12-12T12:27:40.609936Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:40.609934Z :DEBUG: [local] [local] [cac0108f-3a36a4d9-10074534-b33d2d27] [] Reconnecting session to cluster  in 0.000000s
2025-12-12T12:27:40.610495Z :FQ_ROW_DISPATCHER TRACE: topic_session.cpp:466: TopicSession [1:7582947107629718895:2150] SubscribeOnNextEvent
2025-12-12T12:27:40.619948Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:40.619930Z :DEBUG: [local] [local] [cac0108f-3a36a4d9-10074534-b33d2d27] [] Successfully connected. Initializing session
2025-12-12T12:27:40.623821Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:40.623809Z :INFO: [local] [local] [cac0108f-3a36a4d9-10074534-b33d2d27] [] Got InitResponse. ReadSessionId: _1_6_7213565857369862411_v1
2025-12-12T12:27:40.623838Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:40.623835Z :DEBUG: [local] [local] [cac0108f-3a36a4d9-10074534-b33d2d27] [] In ContinueReadingDataImpl, ReadSizeBudget = 8000000, ReadSizeServerDelta = 0
2025-12-12T12:27:40.623920Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:40.623917Z :DEBUG: [local] [local] [cac0108f-3a36a4d9-10074534-b33d2d27] [] After sending read request: ReadSizeBudget = 0, ReadSizeServerDelta = 8000000
2025-12-12T12:27:40.627324Z :FQ_ROW_DISPATCHER TRACE: topic_session.cpp:559: TopicSession [1:7582947107629718895:2150] TEvPqEventsReady
2025-12-12T12:27:40.627345Z :FQ_ROW_DISPATCHER DEBUG: topic_session.cpp:677: TopicSession [1:7582947107629718895:2150] StartPartitionSessionEvent received
2025-12-12T12:27:40.627350Z :FQ_ROW_DISPATCHER DEBUG: topic_session.cpp:685: TopicSession [1:7582947107629718895:2150] Confirm StartPartitionSession with offset (NULL)
2025-12-12T12:27:40.627364Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:40.627360Z :INFO: [local] [local] [cac0108f-3a36a4d9-10074534-b33d2d27] [] Confirm partition stream create. Partition stream id: 1. Cluster: "-". Topic: "test_filter_missing_fields_input". Partition: 0. Read offset: (NULL)
2025-12-12T12:27:40.627420Z :FQ_ROW_DISPATCHER TRACE: topic_session.cpp:466: TopicSession [1:7582947107629718895:2150] SubscribeOnNextEvent
2025-12-12T12:27:40.628405Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 4c7b4b3e-d9d2d511-76304cae-9b37415812, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:40.631199Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:40.631190Z :DEBUG: [local] [local] [cac0108f-3a36a4d9-10074534-b33d2d27] [] Got ReadResponse, serverBytesSize = 320, now ReadSizeBudget = 0, ReadSizeServerDelta = 7999680
2025-12-12T12:27:40.631235Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:40.631233Z :DEBUG: [local] [local] [cac0108f-3a36a4d9-10074534-b33d2d27] [] In ContinueReadingDataImpl, ReadSizeBudget = 0, ReadSizeServerDelta = 7999680
2025-12-12T12:27:40.631298Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:40.631296Z :DEBUG: [local] Decompression task done. Partition/PartitionSessionId: 1 (0-3)
2025-12-12T12:27:40.631305Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:40.631302Z :DEBUG: [local] [local] [cac0108f-3a36a4d9-10074534-b33d2d27] [] Returning serverBytesSize = 320 to budget
2025-12-12T12:27:40.631308Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:40.631306Z :DEBUG: [local] [local] [cac0108f-3a36a4d9-10074534-b33d2d27] [] In ContinueReadingDataImpl, ReadSizeBudget = 320, ReadSizeServerDelta = 7999680
2025-12-12T12:27:40.631347Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:40.631346Z :DEBUG: [local] [local] [cac0108f-3a36a4d9-10074534-b33d2d27] [] After sending read request: ReadSizeBudget = 0, ReadSizeServerDelta = 8000000
2025-12-12T12:27:40.631461Z :FQ_ROW_DISPATCHER TRACE: topic_session.cpp:559: TopicSession [1:7582947107629718895:2150] TEvPqEventsReady
2025-12-12T12:27:40.631487Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:40.631484Z :DEBUG: [local] Take Data. Partition 0. Read: {0, 0} (0-0)
2025-12-12T12:27:40.631495Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:40.631494Z :DEBUG: [local] Take Data. Partition 0. Read: {1, 0} (1-1)
2025-12-12T12:27:40.631500Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:40.631499Z :DEBUG: [local] Take Data. Partition 0. Read: {1, 1} (2-2)
2025-12-12T12:27:40.631505Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:40.631503Z :DEBUG: [local] Take Data. Partition 0. Read: {1, 2} (3-3)
2025-12-12T12:27:40.631514Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:40.631512Z :DEBUG: [local] [local] [cac0108f-3a36a4d9-10074534-b33d2d27] [] The application data is transferred to the client. Number of messages 4, size 185 bytes
2025-12-12T12:27:40.631520Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:40.631517Z :DEBUG: [local] [local] [cac0108f-3a36a4d9-10074534-b33d2d27] [] Returning serverBytesSize = 0 to budget
2025-12-12T12:27:40.631538Z :FQ_ROW_DISPATCHER TRACE: topic_session.cpp:654: TopicSession [1:7582947107629718895:2150] Data received: Message { Data: "{"time": 101, "event": "event1"}" Information: { Offset: 0 ProducerId: "" SeqNo: 0 CreateTime: 2025-12-12T12:27:36.549000Z WriteTime: 2025-12-12T12:27:36.549000Z MessageGroupId: "" Meta: { } MessageMeta: { } } Partition session id: 1 Topic: "test_filter_missing_fields_input" Partition: 0 }
2025-12-12T12:27:40.631544Z :FQ_ROW_DISPATCHER TRACE: topic_session.cpp:654: TopicSession [1:7582947107629718895:2150] Data received: Message { Data: "{"time": 102, "data@data": null, "event": "event2"}" Information: { Offset: 1 ProducerId: "" SeqNo: 0 CreateTime: 2025-12-12T12:27:36.549000Z WriteTime: 2025-12-12T12:27:36.555000Z MessageGroupId: "" Meta: { } MessageMeta: { } } Partition session id: 1 Topic: "test_filter_missing_fields_input" Partition: 0 }
2025-12-12T12:27:40.631547Z :FQ_ROW_DISPATCHER TRACE: topic_session.cpp:654: TopicSession [1:7582947107629718895:2150] Data received: Message { Data: "{"time": 103, "data@data": "", "event": "event2"}" Information: { Offset: 2 ProducerId: "" SeqNo: 0 CreateTime: 2025-12-12T12:27:36.549000Z WriteTime: 2025-12-12T12:27:36.555000Z MessageGroupId: "" Meta: { } MessageMeta: { } } Partition session id: 1 Topic: "test_filter_missing_fields_input" Partition: 0 }
2025-12-12T12:27:40.631550Z :FQ_ROW_DISPATCHER TRACE: topic_session.cpp:654: TopicSession [1:7582947107629718895:2150] Data received: Message { Data: "{"time": 104, "data@data": "null", "event": "event2"}" Information: { Offset: 3 ProducerId: "" SeqNo: 0 CreateTime: 2025-12-12T12:27:36.549000Z WriteTime: 2025-12-12T12:27:36.555000Z MessageGroupId: "" Meta: { } MessageMeta: { } } Partition session id: 1 Topic: "test_filter_missing_fields_input" Partition: 0 }
2025-12-12T12:27:40.631552Z :FQ_ROW_DISPATCHER TRACE: topic_session.cpp:707: TopicSession [1:7582947107629718895:2150] SendToParsing, messages: 4
2025-12-12T12:27:40.631555Z :FQ_ROW_DISPATCHER TRACE: format_handler.cpp:417: TTopicFormatHandler [json_each_row]: Send 4 messages to parser
2025-12-12T12:27:40.631559Z :FQ_ROW_DISPATCHER TRACE: json_parser.cpp:388: TJsonParser: Add 4 messages to parse
2025-12-12T12:27:40.631658Z :FQ_ROW_DISPATCHER TRACE: json_parser.cpp:454: TJsonParser: Do parsing, first offset: 0, values:
{"time": 101, "event": "event1"}{"time": 102, "data@data": null, "event": "event2"}{"time": 103, "data@data": "", "event": "event2"}{"time": 104, "data@data": "null", "event": "event2"}                                                                
2025-12-12T12:27:40.631661Z :FQ_ROW_DISPATCHER TRACE: json_parser.cpp:590: TJsonParser: Init parser, skipped 0, outputRowId 0 size 249
2025-12-12T12:27:40.631694Z :FQ_ROW_DISPATCHER TRACE: format_handler.cpp:77: TTopicFormatHandler [json_each_row]: TParserHandler: Got parsed data, number rows: 4
2025-12-12T12:27:40.631697Z :FQ_ROW_DISPATCHER TRACE: format_handler.cpp:614: TTopicFormatHandler [json_each_row]: Send 4 messages to programs, first offset: 0, last offset: 3
2025-12-12T12:27:40.631701Z :FQ_ROW_DISPATCHER TRACE: filters_set.cpp:34: TTopicFilters: ProcessData for 1 clients, number rows: 4
2025-12-12T12:27:40.631707Z :FQ_ROW_DISPATCHER TRACE: filters_set.cpp:223: TTopicFilters: Pass 4 rows to purecalc filter (client id: [2:7582947089337657689:2150])
2025-12-12T12:27:40.631711Z :FQ_ROW_DISPATCHER TRACE: purecalc_filter.cpp:408: TProgramRunHandler: ProcessData for 4 rows
2025-12-12T12:27:40.631764Z :FQ_ROW_DISPATCHER TRACE: format_handler.cpp:292: TTopicFormatHandler [json_each_row]: TClientHandler [2:7582947089337657689:2150]: OnBatchFinish, offset: 0, number rows: 1, row size: 17, watermark: (empty maybe)
2025-12-12T12:27:40.631766Z :FQ_ROW_DISPATCHER TRACE: topic_session.cpp:198: TopicSession [1:7582947107629718895:2150] AddDataToClient to [2:7582947089337657689:2150], offset: 0, number rows: 1, row size: 17, watermark: (empty maybe)
2025-12-12T12:27:40.631768Z :FQ_ROW_DISPATCHER TRACE: topic_session.cpp:936: TopicSession [1:7582947107629718895:2150] Send TEvNewDataArrived to [2:7582947089337657689:2150]
2025-12-12T12:27:40.631786Z :FQ_ROW_DISPATCHER TRACE: format_handler.cpp:292: TTopicFormatHandler [json_each_row]: TClientHandler [2:7582947089337657689:2150]: OnBatchFinish, offset: 1, number rows: 1, row size: 9, watermark: (empty maybe)
2025-12-12T12:27:40.631788Z :FQ_ROW_DISPATCHER TRACE: topic_session.cpp:198: TopicSession [1:7582947107629718895:2150] AddDataToClient to [2:7582947089337657689:2150], offset: 1, number rows: 1, row size: 9, watermark: (empty maybe)
2025-12-12T12:27:40.631797Z :FQ_ROW_DISPATCHER TRACE: format_handler.cpp:622: TTopicFormatHandler [json_each_row]: Commit client [2:7582947089337657689:2150] offset 3
2025-12-12T12:27:40.631800Z :FQ_ROW_DISPATCHER TRACE: topic_session.cpp:210: TopicSession [1:7582947107629718895:2150] UpdateClientOffset for [2:7582947089337657689:2150], new offset: 3
2025-12-12T12:27:40.631808Z :FQ_ROW_DISPATCHER TRACE: topic_session.cpp:466: TopicSession [1:7582947107629718895:2150] SubscribeOnNextEvent
2025-12-12T12:27:40.631810Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1081: RowDispatcher: Forward TEvNewDataArrived from [1:7582947107629718895:2150] to [2:7582947089337657689:2150] query id ptqudq7uem2o5or4krva
2025-12-12T12:27:40.634087Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:940: RowDispatcher: Received TEvGetNextBatch from [2:7582947089337657689:2150] part id 0 query id ptqudq7uem2o5or4krva
2025-12-12T12:27:40.634118Z :FQ_ROW_DISPATCHER TRACE: topic_session.cpp:588: TopicSession [1:7582947107629718895:2150] TEvGetNextBatch from [2:7582947089337657689:2150]
2025-12-12T12:27:40.634127Z :FQ_ROW_DISPATCHER TRACE: format_handler.cpp:324: TTopicFormatHandler [json_each_row]: TClientHandler [2:7582947089337657689:2150]: FinishPacking, batch size: 26, number rows: 2
2025-12-12T12:27:40.634139Z :FQ_ROW_DISPATCHER TRACE: format_handler.cpp:174: TTopicFormatHandler [json_each_row]: TClientHandler [2:7582947089337657689:2150]: ExtractClientData, number batches: 1
2025-12-12T12:27:40.634147Z :FQ_ROW_DISPATCHER TRACE: topic_session.cpp:764: TopicSession [1:7582947107629718895:2150] SendData to [2:7582947089337657689:2150], batch size 1
2025-12-12T12:27:40.634163Z :FQ_ROW_DISPATCHER TRACE: topic_session.cpp:457: TopicSession [1:7582947107629718895:2150] Skip SubscribeOnNextEvent, has ReadSession: true, IsWaitingEvents: 1
2025-12-12T12:27:40.634169Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1100: RowDispatcher: Forward TEvMessageBatch from [1:7582947107629718895:2150] to [2:7582947089337657689:2150] query id ptqudq7uem2o5or4krva
2025-12-12T12:27:40.635972Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:40.635986Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:41.103319Z :FQ_ROW_DISPATCHER DEBUG: coordinator.cpp:608: Coordinator: Rebalancing...
2025-12-12T12:27:41.103343Z :FQ_ROW_DISPATCHER DEBUG: coordinator.cpp:615: Coordinator: Current state (rebalancing):
2025-12-12T12:27:41.103349Z :FQ_ROW_DISPATCHER DEBUG: coordinator.cpp:617: Coordinator:   node 1 ([1:7582947081859914882:2063]) state Started connected 1 partitions count 1
2025-12-12T12:27:41.103353Z :FQ_ROW_DISPATCHER DEBUG: coordinator.cpp:617: Coordinator:   node 2 ([2:7582947085042690188:2063]) state Initializing connected 1 partitions count 0
2025-12-12T12:27:41.103355Z :FQ_ROW_DISPATCHER DEBUG: coordinator.cpp:617: Coordinator:   node 3 ([3:7582947085532780485:2063]) state Initializing connected 1 partitions count 0
2025-12-12T12:27:41.103357Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:648: Coordinator: Send TEvCoordinatorDistributionReset to [2:7582947089337657689:2150]
2025-12-12T12:27:41.103376Z :FQ_ROW_DISPATCHER DEBUG: coordinator.cpp:615: Coordinator: Current state (after rebalancing):
2025-12-12T12:27:41.103378Z :FQ_ROW_DISPATCHER DEBUG: coordinator.cpp:617: Coordinator:   node 1 ([1:7582947081859914882:2063]) state Started connected 1 partitions count 0
2025-12-12T12:27:41.103379Z :FQ_ROW_DISPATCHER DEBUG: coordinator.cpp:617: Coordinator:   node 2 ([2:7582947085042690188:2063]) state Started connected 1 partitions count 0
2025-12-12T12:27:41.103381Z :FQ_ROW_DISPATCHER DEBUG: coordinator.cpp:617: Coordinator:   node 3 ([3:7582947085532780485:2063]) state Started connected 1 partitions count 0
2025-12-12T12:27:41.189382Z :FQ_ROW_DISPATCHER TRACE: topic_session.cpp:952: TopicSession [1:7582947107629718895:2150] SendStatistics
2025-12-12T12:27:41.189429Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1234: RowDispatcher: TEvSessionStatistic from [1:7582947107629718895:2150]
2025-12-12T12:27:41.298676Z :FQ_ROW_DISPATCHER DEBUG: row_dispatcher.cpp:1001: RowDispatcher: Received TEvStopSession from [2:7582947089337657689:2150] topic test_filter_missing_fields_input query id ptqudq7uem2o5or4krva
2025-12-12T12:27:41.298698Z :FQ_ROW_DISPATCHER DEBUG: row_dispatcher.cpp:1016: RowDispatcher: DeleteConsumer, readActorId [2:7582947089337657689:2150] query id ptqudq7uem2o5or4krva, partitions size 1
2025-12-12T12:27:41.298721Z :FQ_ROW_DISPATCHER DEBUG: row_dispatcher.cpp:1036: RowDispatcher: Session is not used, sent TEvPoisonPill to [1:7582947107629718895:2150]
2025-12-12T12:27:41.298735Z :FQ_ROW_DISPATCHER DEBUG: topic_session.cpp:831: TopicSession [1:7582947107629718895:2150] TEvStopSession from [2:7582947089337657689:2150] topicPath test_filter_missing_fields_input clients count 1
2025-12-12T12:27:41.298742Z :FQ_ROW_DISPATCHER DEBUG: format_handler.cpp:477: TTopicFormatHandler [json_each_row]: Remove client with id [2:7582947089337657689:2150]
2025-12-12T12:27:41.298746Z :FQ_ROW_DISPATCHER TRACE: filters_set.cpp:94: TTopicFilters: Remove program with client id [2:7582947089337657689:2150]
2025-12-12T12:27:41.298914Z :FQ_ROW_DISPATCHER DEBUG: format_handler.cpp:559: TTopicFormatHandler [json_each_row]: UpdateParser to new schema with size 0
2025-12-12T12:27:41.298924Z :FQ_ROW_DISPATCHER INFO: format_handler.cpp:584: TTopicFormatHandler [json_each_row]: No columns to parse, reset parser
2025-12-12T12:27:41.298963Z :FQ_ROW_DISPATCHER DEBUG: topic_session.cpp:924: TopicSession [1:7582947107629718895:2150] Close read session
2025-12-12T12:27:41.298980Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:41.298976Z :INFO: [local] [local] [cac0108f-3a36a4d9-10074534-b33d2d27] Closing read session. Close timeout: 0.000000s
2025-12-12T12:27:41.299012Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:41.298996Z :INFO: [local] Read/commit by partition streams (cluster:topic:partition:stream-id:read-offset:committed-offset): -:test_filter_missing_fields_input:0:1:3:0
2025-12-12T12:27:41.299020Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:41.299019Z :INFO: [local] [local] [cac0108f-3a36a4d9-10074534-b33d2d27] Counters: { Errors: 0 CurrentSessionLifetimeMs: 689 BytesRead: 185 MessagesRead: 4 BytesReadCompressed: 185 BytesInflightUncompressed: 0 BytesInflightCompressed: 0 BytesInflightTotal: 0 MessagesInflight: 0 }
2025-12-12T12:27:41.299036Z :YDB_SDK NOTICE: actor.cpp:37: 2025-12-12T12:27:41.299034Z :NOTICE: [local] [local] [cac0108f-3a36a4d9-10074534-b33d2d27] Aborting read session. Description: SessionClosed { Status: ABORTED Issues: "<main>: Error: Close with zero timeout " }
2025-12-12T12:27:41.299043Z :YDB_SDK DEBUG: actor.cpp:37: 2025-12-12T12:27:41.299041Z :DEBUG: [local] [local] [cac0108f-3a36a4d9-10074534-b33d2d27] [] Abort session to cluster
2025-12-12T12:27:41.299227Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:41.299223Z :INFO: [local] [local] [cac0108f-3a36a4d9-10074534-b33d2d27] Closing read session. Close timeout: 0.000000s
2025-12-12T12:27:41.299239Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:41.299238Z :INFO: [local] Read/commit by partition streams (cluster:topic:partition:stream-id:read-offset:committed-offset): -:test_filter_missing_fields_input:0:1:3:0
2025-12-12T12:27:41.299245Z :YDB_SDK INFO: actor.cpp:37: 2025-12-12T12:27:41.299243Z :INFO: [local] [local] [cac0108f-3a36a4d9-10074534-b33d2d27] Counters: { Errors: 0 CurrentSessionLifetimeMs: 689 BytesRead: 185 MessagesRead: 4 BytesReadCompressed: 185 BytesInflightUncompressed: 0 BytesInflightCompressed: 0 BytesInflightTotal: 0 MessagesInflight: 0 }
2025-12-12T12:27:41.299269Z :YDB_SDK NOTICE: actor.cpp:37: 2025-12-12T12:27:41.299267Z :NOTICE: [local] [local] [cac0108f-3a36a4d9-10074534-b33d2d27] Aborting read session. Description: SessionClosed { Status: ABORTED Issues: "<main>: Error: Aborted " }
2025-12-12T12:27:41.299300Z :FQ_ROW_DISPATCHER TRACE: topic_session.cpp:457: TopicSession [1:7582947107629718895:2150] Skip SubscribeOnNextEvent, has ReadSession: false, IsWaitingEvents: 1
2025-12-12T12:27:41.299326Z :FQ_ROW_DISPATCHER DEBUG: topic_session.cpp:449: TopicSession [1:7582947107629718895:2150] PassAway
2025-12-12T12:27:41.627607Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:627: RowDispatcher: Send ping to [1:7582947081859914922:2082]
2025-12-12T12:27:41.627635Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1174: RowDispatcher: TEvPrivate::TEvSendStatistic
2025-12-12T12:27:41.627647Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [1:7582947081859914882:2063]
2025-12-12T12:27:41.627651Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7582947081859914882:2063]
2025-12-12T12:27:41.627654Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [1:7582947081859914882:2063]
2025-12-12T12:27:41.627669Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:633: RowDispatcher: NActors::TEvents::TEvPong
2025-12-12T12:27:41.628654Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 4c7b4b3e-d9d2d511-76304cae-9b37415813, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:41.631845Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:41.631858Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:266: Tasks count: 0
2025-12-12T12:27:42.106108Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [2:7582947085042690188:2063]
2025-12-12T12:27:42.106124Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [2:7582947085042690188:2063]
2025-12-12T12:27:42.106128Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [2:7582947085042690188:2063]
2025-12-12T12:27:42.607155Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [3:7582947085532780485:2063]
2025-12-12T12:27:42.607174Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [3:7582947085532780485:2063]
2025-12-12T12:27:42.607177Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [3:7582947085532780485:2063]
2025-12-12T12:27:42.629094Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 4c7b4b3e-d9d2d511-76304cae-9b37415814, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:42.633443Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:42.633462Z :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:62394: Failed to connect to remote host: Connection refused
<main>: Error: Grpc error response on endpoint ghrun-fhkyrtz6p4.auto.internal:62394
2025-12-12T12:27:43.190242Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1059: RowDispatcher: No consumer with EventQueueId = 0
2025-12-12T12:27:43.628507Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:627: RowDispatcher: Send ping to [1:7582947081859914922:2082]
2025-12-12T12:27:43.628532Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1174: RowDispatcher: TEvPrivate::TEvSendStatistic
2025-12-12T12:27:43.628540Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [1:7582947081859914882:2063]
2025-12-12T12:27:43.628544Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [1:7582947081859914882:2063]
2025-12-12T12:27:43.628547Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [1:7582947081859914882:2063]
2025-12-12T12:27:43.628556Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:633: RowDispatcher: NActors::TEvents::TEvPong
2025-12-12T12:27:43.629541Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 4c7b4b3e-d9d2d511-76304cae-9b37415815, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:43.638041Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:43.638072Z :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:62394: Failed to connect to remote host: Connection refused
<main>: Error: Grpc error response on endpoint ghrun-fhkyrtz6p4.auto.internal:62394
2025-12-12T12:27:44.106743Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:356: Coordinator: TEvPing received, [2:7582947085042690188:2063]
2025-12-12T12:27:44.106759Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:299: Coordinator: UpdateKnownRowDispatchers [2:7582947085042690188:2063]
2025-12-12T12:27:44.106763Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:359: Coordinator: Send TEvPong to [2:7582947085042690188:2063]
2025-12-12T12:27:44.569781Z :INTERCONNECT_NETWORK NOTICE: interconnect_tcp_input_session.cpp:712: [1 <-> 3] connection closed by peer
2025-12-12T12:27:44.570027Z :FQ_ROW_DISPATCHER DEBUG: coordinator.cpp:398: Coordinator: TEvNodeDisconnected, node id 3
2025-12-12T12:27:44.570038Z :FQ_ROW_DISPATCHER TRACE: coordinator.cpp:408: Coordinator: Schedule TEvRebalancing
2025-12-12T12:27:44.570621Z :INTERCONNECT_NETWORK NOTICE: interconnect_handshake.cpp:1262: [1 <-> 3] network-related error occured on handshake: outgoing handshake Peer# ghrun-fhkyrtz6p4(127.0.1.1:63718) Couldn't connect to any resolved address
2025-12-12T12:27:44.571087Z :FQ_ROW_DISPATCHER DEBUG: coordinator.cpp:398: Coordinator: TEvNodeDisconnected, node id 2
2025-12-12T12:27:44.571090Z :FQ_ROW_DISPATCHER DEBUG: row_dispatcher.cpp:597: RowDispatcher: TEvNodeDisconnected, node id 2
2025-12-12T12:27:44.571589Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1052: RowDispatcher: TEvTryConnect to node id 2
2025-12-12T12:27:44.571641Z :FQ_ROW_DISPATCHER DEBUG: row_dispatcher.cpp:597: RowDispatcher: TEvNodeDisconnected, node id 2
2025-12-12T12:27:44.624942Z :YQL_NODES_MANAGER TRACE: nodes_manager.cpp:318: TNodesManagerActor::NodesHealthCheck
2025-12-12T12:27:44.629969Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:329: Request Private::GetTask, Owner: 4c7b4b3e-d9d2d511-76304cae-9b37415816, Host: ghrun-fhkyrtz6p4, Tenant: /compute
2025-12-12T12:27:44.630094Z :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:62394: Failed to connect to remote host: Connection refused
<main>: Error: Grpc error response on endpoint ghrun-fhkyrtz6p4.auto.internal:62394
2025-12-12T12:27:44.634410Z :FQ_PENDING_FETCHER TRACE: pending_fetcher.cpp:254: Got GetTask response from PrivateApi
2025-12-12T12:27:44.634431Z :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:62394: Failed to connect to remote host: Connection refused
<main>: Error: Grpc error response on endpoint ghrun-fhkyrtz6p4.auto.internal:62394
2025-12-12T12:27:44.666831Z :FQ_ROW_DISPATCHER TRACE: row_dispatcher.cpp:1052: RowDispatcher: TEvTryConnect to node id 2
2025-12-12T12:27:44.666878Z :FQ_ROW_DISPATCHER DEBUG: row_dispatcher.cpp:597: RowDispatcher: TEvNodeDisconnected, node id 2
