dqrun ABI version: 2.44.0 2025-12-06 03:05:46.465 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [default] storage.cpp:189: FileStorage initialized in "/home/runner/.ya/build/build_root/o4ua/005281/r3tmp/tmpbAx9Qq/", temporary dir: "/home/runner/.ya/build/build_root/o4ua/005281/r3tmp/tmpbAx9Qq/3243516", locks dir:"/home/runner/.ya/build/build_root/o4ua/005281/r3tmp/tmpbAx9Qq/locks", files: 0, total size: 0 2025-12-06 03:05:46.473 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [generic] client.cpp:436: Connector[default] endpoint: grpcs://connector.yqv2-dev.cloud.yandex.net:50051 2025-12-06 03:05:46.488 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [http gw] yql_dns_gateway.h:85: Filled DNS resolution table based on provided configuration 2025-12-06 03:05:46.489 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [http gw] yql_dns_gateway.h:126: Started DNS table update 2025-12-06 03:05:46.493 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [DQ] interconnect_helpers.cpp:215: Start listener ::1:31337 socket: 18 2025-12-06 03:05:46.519 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [DQ] service_node.cpp:126: Starting GRPC on 31338 GRpc memory quota was set but disabled due to issues with grpc quoter, to enable it use EnableGRpcMemoryQuota option Parse SQL... Compile program... 2025-12-06 03:05:46.648 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [generic] yql_generic_settings.cpp:61: GenericConfiguration::AddCluster: name = ydb_dev, kind = YDB, database name = , database id = etnejle6hb72cdr6aqps, endpoint = { }, use tls = 1, protocol = NATIVE Run program... 2025-12-06 03:05:46.651 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [DQ] yql_dq_gateway.cpp:605: {dummy_op} OpenSession 2025-12-06 03:05:46.654 INFO dqrun(pid=3243516, tid=0x00007F5F7F5FD640) [DQ] yql_dq_gateway.cpp:633: {dummy_op} OpenSession OK 2025-12-06 03:05:46.656 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [YT] yql_yt_io_discovery.cpp:303: {dummy_op} YtIODiscovery - finish, status: Ok 2025-12-06 03:05:46.657 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [S3] yql_s3_listing_strategy.cpp:1018: {dummy_op} [TLoggingS3ListingStrategy] Going to list request [TS3Lister] TListingRequest{.url=file://./tpc/,.Prefix=h/1/part/,.Pattern=h/1/part/*,.PatternType=Wildcard,.Credentials=TS3Credentials{.ServiceAccountAuth=1,.AwsUserPwd=,.AwsSigV4=}} with options TS3ListingOptions{.IsPartitionedDataset=0,.IsConcurrentListing=0} 2025-12-06 03:05:46.658 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [S3] yql_s3_listing_strategy.cpp:236: {dummy_op} [TCompositeS3ListingStrategy] Strategy successfully listed paths. Returning result: 30 objects, 0 path prefixes 2025-12-06 03:05:46.658 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [S3] yql_s3_listing_strategy.cpp:1026: {dummy_op} [TLoggingS3ListingStrategy] Listing took 0.000001s and ended with 30 entries 2025-12-06 03:05:46.658 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [S3] yql_s3_listing_strategy.cpp:1018: {dummy_op} [TLoggingS3ListingStrategy] Going to list request [TS3Lister] TListingRequest{.url=file://./tpc/,.Prefix=h/1/lineitem/,.Pattern=h/1/lineitem/*,.PatternType=Wildcard,.Credentials=TS3Credentials{.ServiceAccountAuth=1,.AwsUserPwd=,.AwsSigV4=}} with options TS3ListingOptions{.IsPartitionedDataset=0,.IsConcurrentListing=0} 2025-12-06 03:05:46.659 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [S3] yql_s3_listing_strategy.cpp:236: {dummy_op} [TCompositeS3ListingStrategy] Strategy successfully listed paths. Returning result: 30 objects, 0 path prefixes 2025-12-06 03:05:46.659 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [S3] yql_s3_listing_strategy.cpp:1026: {dummy_op} [TLoggingS3ListingStrategy] Listing took 0.000000s and ended with 30 entries 2025-12-06 03:05:46.660 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [S3] yql_s3_io_discovery.cpp:395: {dummy_op} Pattern h/1/lineitem/* has 30 items with total size 188300741 2025-12-06 03:05:46.660 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [S3] yql_s3_io_discovery.cpp:395: {dummy_op} Pattern h/1/part/* has 30 items with total size 6089692 2025-12-06 03:05:46.662 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [YT] yql_yt_io_discovery.cpp:303: {dummy_op} YtIODiscovery - finish, status: Ok 2025-12-06 03:05:46.665 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [RESULT] yql_result_provider.cpp:1415: {dummy_op} RewriteIO 2025-12-06 03:05:46.687 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [RESULT] yql_result_provider.cpp:1154: {dummy_op} Setting result column order: [(revenue->revenue)] 2025-12-06 03:05:46.744 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [S3] yql_s3_dq_integration.cpp:252: {dummy_op} Wrap S3ReadObject! with token: cluster:default_yq-tpc-local 2025-12-06 03:05:46.745 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [S3] yql_s3_dq_integration.cpp:252: {dummy_op} Wrap S3ReadObject! with token: cluster:default_yq-tpc-local 2025-12-06 03:05:46.746 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [DQ] yql_dq_recapture.cpp:111: {dummy_op} DqsRecapture 2025-12-06 03:05:46.752 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [S3] yql_s3_logical_opt.cpp:628: {dummy_op} ExtractMembers over DqSource with S3ParseSettings 2025-12-06 03:05:46.753 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [S3] yql_optimize.cpp:131: {dummy_op} LogicalOptimizer-ExtractMembersOverDqSource 2025-12-06 03:05:46.753 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [S3] yql_s3_logical_opt.cpp:628: {dummy_op} ExtractMembers over DqSource with S3ParseSettings 2025-12-06 03:05:46.753 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [S3] yql_optimize.cpp:131: {dummy_op} LogicalOptimizer-ExtractMembersOverDqSource 2025-12-06 03:05:46.760 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [S3] yql_s3_logical_opt.cpp:434: {dummy_op} Will read from S3 60 files with total size 194390433 bytes 2025-12-06 03:05:46.763 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [S3] yql_optimize.cpp:131: {dummy_op} PhysicalOptimizer-TrimReadWorld 2025-12-06 03:05:46.768 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [S3] yql_s3_logical_opt.cpp:434: {dummy_op} Will read from S3 60 files with total size 194390433 bytes 2025-12-06 03:05:46.769 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [S3] yql_optimize.cpp:131: {dummy_op} PhysicalOptimizer-TrimReadWorld 2025-12-06 03:05:46.772 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [S3] yql_s3_logical_opt.cpp:434: {dummy_op} Will read from S3 60 files with total size 194390433 bytes 2025-12-06 03:05:46.773 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [DQ] yql_optimize.cpp:131: {dummy_op} DqsPhy-BuildStageWithSourceWrap 2025-12-06 03:05:46.773 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [DQ] yql_optimize.cpp:131: {dummy_op} DqsPhy-BuildStageWithSourceWrap 2025-12-06 03:05:46.779 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [DQ] yql_optimize.cpp:131: {dummy_op} DqsLogical-RewriteEquiJoin 2025-12-06 03:05:46.786 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [DQ] yql_optimize.cpp:131: {dummy_op} DqsPhy-BuildFlatmapStage 2025-12-06 03:05:46.786 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [DQ] yql_optimize.cpp:131: {dummy_op} DqsPhy-BuildFlatmapStage 2025-12-06 03:05:46.792 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [DQ] yql_optimize.cpp:131: {dummy_op} DqsPhy-BuildJoin 2025-12-06 03:05:46.799 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [DQ] yql_optimize.cpp:131: {dummy_op} DqsPhy-PushExtractMembersToStage 2025-12-06 03:05:46.809 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [DQ] yql_optimize.cpp:131: {dummy_op} DqsPhy-BuildFlatmapStage 2025-12-06 03:05:46.815 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [DQ] yql_optimize.cpp:131: {dummy_op} DqsLogical-RewriteAggregate 2025-12-06 03:05:46.819 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [DQ] yql_optimize.cpp:131: {dummy_op} DqsLogical-RewriteAggregate 2025-12-06 03:05:46.822 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [DQ] yql_optimize.cpp:131: {dummy_op} DqsLogical-RewriteAggregate 2025-12-06 03:05:46.832 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [DQ] yql_optimize.cpp:131: {dummy_op} DqsPhy-PushCombineToStage 2025-12-06 03:05:46.837 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [DQ] yql_optimize.cpp:131: {dummy_op} DqsLogical-RewriteAggregate 2025-12-06 03:05:46.841 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [DQ] yql_optimize.cpp:131: {dummy_op} DqsLogical-RewriteAggregate 2025-12-06 03:05:46.850 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [DQ] yql_optimize.cpp:131: {dummy_op} DqsPhy-BuildShuffleStage 2025-12-06 03:05:46.855 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [DQ] yql_optimize.cpp:131: {dummy_op} DqsPhy-BuildScalarPrecompute 2025-12-06 03:05:46.865 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [DQ] yql_optimize.cpp:131: {dummy_op} DqsPhy-BuildPrecompute 2025-12-06 03:05:46.869 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [DQ] yql_optimize.cpp:131: {dummy_op} DqsPhy-BuildAggregationResultStage 2025-12-06 03:05:46.879 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [RESULT] yql_result_provider.cpp:771: {dummy_op} ResPull 2025-12-06 03:05:46.889 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [core] yql_linear_checker.cpp:210: {dummy_op} Scanned 0 static linear types 2025-12-06 03:05:46.890 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [core exec] yql_execution.cpp:61: {dummy_op} Begin, root #216303 2025-12-06 03:05:46.890 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [core exec] yql_execution.cpp:74: {dummy_op} Collect unused nodes for root #216303, status: Ok 2025-12-06 03:05:46.890 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [core exec] yql_execution.cpp:630: {dummy_op} Node #209736 finished execution 2025-12-06 03:05:46.890 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [core exec] yql_execution.cpp:647: {dummy_op} Node #209736 created 0 trackable nodes: 2025-12-06 03:05:46.890 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [core exec] yql_execution.cpp:630: {dummy_op} Node #216291 finished execution 2025-12-06 03:05:46.890 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [core exec] yql_execution.cpp:647: {dummy_op} Node #216291 created 0 trackable nodes: 2025-12-06 03:05:46.897 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [core dq] dq_opt_build.cpp:482: {dummy_op/#216301/#216313/DqPhyPrecompute(#216274)} Enabled wide channels for stage with logical id = 214081 2025-12-06 03:05:46.898 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [core dq] dq_opt_build.cpp:482: {dummy_op/#216301/#216313/DqPhyPrecompute(#216274)} Enabled wide channels for stage with logical id = 214118 2025-12-06 03:05:46.901 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [core dq] dq_opt_build.cpp:482: {dummy_op/#216301/#216313/DqPhyPrecompute(#216274)} Enabled wide channels for stage with logical id = 215511 2025-12-06 03:05:46.972 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [core dq] yql_dq_exectransformer.cpp:379: {dummy_op/#216301/#216313/DqPhyPrecompute(#216274)} Setting block status for stage #214081 to Partial 2025-12-06 03:05:46.972 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [core dq] yql_dq_exectransformer.cpp:379: {dummy_op/#216301/#216313/DqPhyPrecompute(#216274)} Setting block status for stage #214118 to Partial 2025-12-06 03:05:46.973 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [core dq] yql_dq_exectransformer.cpp:379: {dummy_op/#216301/#216313/DqPhyPrecompute(#216274)} Setting block status for stage #215511 to None 2025-12-06 03:05:46.974 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [core dq] yql_dq_exectransformer.cpp:379: {dummy_op/#216301/#216313/DqPhyPrecompute(#216274)} Setting block status for stage #216080 to None 2025-12-06 03:05:46.990 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [core exec] yql_execution.cpp:519: {dummy_op} Register async execution for node #216301 2025-12-06 03:05:46.990 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [core exec] yql_execution.cpp:89: {dummy_op} Finish, output #216303, status: Async 2025-12-06 03:05:46.994 INFO dqrun(pid=3243516, tid=0x00007F5FAA133640) [DQ] executer_actor.cpp:157: {dummy_op} Trying to allocate 4 workers [EnableComputeActor=1] 2025-12-06 03:05:46.996 INFO dqrun(pid=3243516, tid=0x00007F5FAAC38640) [DQ] executer_actor.cpp:415: {dummy_op} 4 workers allocated 2025-12-06 03:05:53.870 INFO dqrun(pid=3243516, tid=0x00007F5F7F5FD640) [DQ] yql_dq_exectransformer.cpp:2042: {dummy_op/#216301/#216313/DqPhyPrecompute(#216274)} Execution precomputes complete, duration: 6.978743s 2025-12-06 03:05:53.870 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [core exec] yql_execution.cpp:135: {dummy_op} Completed async execution for node #216301 2025-12-06 03:05:53.870 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [core exec] yql_execution.cpp:155: {dummy_op} State is ExecutionRequired after apply async changes for node #216301 2025-12-06 03:05:53.870 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [core exec] yql_execution.cpp:61: {dummy_op} Begin, root #216303 2025-12-06 03:05:53.870 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [core exec] yql_execution.cpp:74: {dummy_op} Collect unused nodes for root #216303, status: Ok 2025-12-06 03:05:53.875 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [core dq] dq_opt_build.cpp:482: {dummy_op/#216301/#220113} Enabled wide channels for stage with logical id = 216193 2025-12-06 03:05:53.882 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [core dq] yql_dq_exectransformer.cpp:379: {dummy_op/#216301/#220113} Setting block status for stage #216193 to None 2025-12-06 03:05:53.883 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [core dq] yql_dq_exectransformer.cpp:379: {dummy_op/#216301/#220113} Setting block status for stage #216282 to None 2025-12-06 03:05:53.885 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [core exec] yql_execution.cpp:519: {dummy_op} Register async execution for node #216301 2025-12-06 03:05:53.885 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [core exec] yql_execution.cpp:89: {dummy_op} Finish, output #216303, status: Async 2025-12-06 03:05:53.886 INFO dqrun(pid=3243516, tid=0x00007F5FAAC38640) [DQ] executer_actor.cpp:157: {dummy_op} Trying to allocate 2 workers [EnableComputeActor=1] 2025-12-06 03:05:53.887 INFO dqrun(pid=3243516, tid=0x00007F5FA8024640) [DQ] executer_actor.cpp:415: {dummy_op} 2 workers allocated 2025-12-06 03:05:54.041 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [core exec] yql_execution.cpp:135: {dummy_op} Completed async execution for node #216301 2025-12-06 03:05:54.041 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [DQ] yql_dq_exectransformer.cpp:1526: {dummy_op} Execution Pull complete, duration: 0.170937s 2025-12-06 03:05:54.041 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [core exec] yql_execution.cpp:155: {dummy_op} State is ExecutionComplete after apply async changes for node #216301 2025-12-06 03:05:54.042 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [core exec] yql_execution.cpp:61: {dummy_op} Begin, root #216303 2025-12-06 03:05:54.042 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [core exec] yql_execution.cpp:74: {dummy_op} Collect unused nodes for root #216303, status: Ok 2025-12-06 03:05:54.042 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [core exec] yql_execution.cpp:630: {dummy_op} Node #216302 finished execution 2025-12-06 03:05:54.042 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [core exec] yql_execution.cpp:647: {dummy_op} Node #216302 created 0 trackable nodes: 2025-12-06 03:05:54.042 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [core exec] yql_execution.cpp:630: {dummy_op} Node #216303 finished execution 2025-12-06 03:05:54.042 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [core exec] yql_execution.cpp:647: {dummy_op} Node #216303 created 0 trackable nodes: 2025-12-06 03:05:54.042 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [core exec] yql_execution.cpp:89: {dummy_op} Finish, output #216303, status: Ok 2025-12-06 03:05:54.042 INFO dqrun(pid=3243516, tid=0x00007F5FC9405380) [core exec] yql_execution.cpp:95: {dummy_op} Creating finalizing transformer, output #216303 Getting results... Done