2025-10-26 19:54:35.252 INFO  dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [default] dqrun.cpp:756: dqrun ABI version: 2.38.0
2025-10-26 19:54:35.339 INFO  dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [default] storage.cpp:177: FileStorage initialized in "/home/runner/.ya/build/build_root/70hy/0003ad/r3tmp/tmp23Lqch/", temporary dir: "/home/runner/.ya/build/build_root/70hy/0003ad/r3tmp/tmp23Lqch/1999589", files: 0, total size: 0
2025-10-26 19:54:35.343 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [YT] init.cpp:24: Entering YT API init
2025-10-26 19:54:35.343 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [YT] init.cpp:40: Using YT global prefix: //
2025-10-26 19:54:35.367 INFO  dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [generic] client.cpp:34: Connector endpoint: grpc://localhost:32779
2025-10-26 19:54:35.391 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [DQ] interconnect_helpers.cpp:120: Initializing local services
2025-10-26 19:54:35.391 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [DQ] interconnect_helpers.cpp:147: Initializing node table
2025-10-26 19:54:35.391 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [DQ] interconnect_helpers.cpp:177: IC Handshake set to 5.000000s
2025-10-26 19:54:35.391 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [DQ] interconnect_helpers.cpp:178: IC DeadPeer set to 30.000000s
2025-10-26 19:54:35.391 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [DQ] interconnect_helpers.cpp:179: IC CloseOnIdle set to 300.000000s
2025-10-26 19:54:35.391 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [DQ] interconnect_helpers.cpp:181: IC SendBufferDieLimitInMB set to 512
2025-10-26 19:54:35.391 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [DQ] interconnect_helpers.cpp:182: IC TotalInflightAmountOfData set to 0
2025-10-26 19:54:35.391 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [DQ] interconnect_helpers.cpp:183: IC MergePerPeerCounters set to 0
2025-10-26 19:54:35.391 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [DQ] interconnect_helpers.cpp:184: IC MergePerDataCenterCounters set to 0
2025-10-26 19:54:35.391 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [DQ] interconnect_helpers.cpp:185: IC TCPSocketBufferSize set to 16777216
2025-10-26 19:54:35.391 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [DQ] interconnect_helpers.cpp:187: IC PingPeriod set to 3.000000s
2025-10-26 19:54:35.391 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [DQ] interconnect_helpers.cpp:188: IC ForceConfirmPeriod set to 1.000000s
2025-10-26 19:54:35.391 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [DQ] interconnect_helpers.cpp:189: IC LostConnection set to 0.000000s
2025-10-26 19:54:35.392 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [DQ] interconnect_helpers.cpp:190: IC BatchPeriod set to 0.000000s
2025-10-26 19:54:35.392 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [DQ] interconnect_helpers.cpp:192: IC MessagePendingTimeout set to 5.000000s
2025-10-26 19:54:35.392 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [DQ] interconnect_helpers.cpp:194: IC MessagePendingSize set to 18446744073709551615
2025-10-26 19:54:35.392 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [DQ] interconnect_helpers.cpp:195: IC MaxSerializedEventSize set to 67108000
2025-10-26 19:54:35.392 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [DQ] interconnect_helpers.cpp:196: IC EnableExternalDataChannel set to 0
2025-10-26 19:54:35.392 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [DQ] interconnect_helpers.cpp:201: Initializing proxy actors
2025-10-26 19:54:35.392 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [DQ] interconnect_helpers.cpp:212: Start listener
2025-10-26 19:54:35.392 INFO  dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [DQ] interconnect_helpers.cpp:215: Start listener ::1:31337 socket: 11
2025-10-26 19:54:35.392 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [DQ] interconnect_helpers.cpp:228: Actor initialization complete
2025-10-26 19:54:35.428 INFO  dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [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
2025-10-26 19:54:35.433 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [DQ] service_node.cpp:33: Start GRPC Listener
Parse SQL...
Compile program...
2025-10-26 19:54:38.253 INFO  dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [generic] yql_generic_settings.cpp:38: GenericConfiguration::AddCluster: name = clickhouse_integration_test, kind = CLICKHOUSE, database name = primitive_types_nullable_NATIVE, database id = , endpoint = { host: "172.18.0.2" port: 9000 }, use tls = 0, protocol = NATIVE
Run program...
2025-10-26 19:54:38.256 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [DQ] yql_dq_provider.cpp:109: OpenSession dummy_op
2025-10-26 19:54:38.256 INFO  dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [DQ] yql_dq_gateway.cpp:565: {dummy_op} OpenSession
2025-10-26 19:54:38.257 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [DQ] yql_dq_provider.cpp:112: OpenSession dummy_op complete in 0
2025-10-26 19:54:38.259 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [core eval] yql_eval_expr.cpp:403: {dummy_op} EvaluateExpression - start
2025-10-26 19:54:38.261 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [core eval] yql_eval_expr.cpp:1165: {dummy_op} EvaluateExpression - finish
2025-10-26 19:54:38.263 INFO  dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [YT] yql_yt_io_discovery.cpp:227: {dummy_op} YtIODiscovery - finish, status: Ok
2025-10-26 19:54:38.265 DEBUG dqrun(pid=1999589, tid=0x00007FB940293640) [DQ] grpc_service.cpp:577: OpenSession for dummy_op runner
2025-10-26 19:54:38.266 INFO  dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [generic] yql_generic_load_meta.cpp:83: {dummy_op} Loading table meta for: `clickhouse_integration_test`.`tf0c24b99`
2025-10-26 19:54:38.267 INFO  dqrun(pid=1999589, tid=0x00007FB93C12B640) [DQ] yql_dq_gateway.cpp:593: {dummy_op} OpenSession OK
2025-10-26 19:54:38.278 INFO  dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [RESULT] yql_result_provider.cpp:1414: {dummy_op} RewriteIO
2025-10-26 19:54:38.283 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] type_ann_expr.cpp:44: {dummy_op} Execution of [TypeAnnotationTransformer::DoTransform] took 5.12ms
2025-10-26 19:54:38.284 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_constraint.cpp:3079: {dummy_op} Execution of [ConstraintTransformer::DoTransform] took 702us
2025-10-26 19:54:38.285 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] type_ann_expr.cpp:44: {dummy_op} Execution of [TypeAnnotationTransformer::DoTransform] took 6us
2025-10-26 19:54:38.285 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_constraint.cpp:3079: {dummy_op} Execution of [ConstraintTransformer::DoTransform] took 263us
2025-10-26 19:54:38.285 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] type_ann_expr.cpp:44: {dummy_op} Execution of [TypeAnnotationTransformer::DoTransform] took 5us
2025-10-26 19:54:38.286 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_constraint.cpp:3079: {dummy_op} Execution of [ConstraintTransformer::DoTransform] took 258us
2025-10-26 19:54:38.286 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_csee.cpp:598: {dummy_op} Execution of [UpdateCompletness] took 154us
2025-10-26 19:54:38.287 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_csee.cpp:611: {dummy_op} Execution of [EliminateCommonSubExpressions] took 687us
2025-10-26 19:54:38.289 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [core] yql_co_simple1.cpp:6127: {dummy_op} Expand SqlProject
2025-10-26 19:54:38.290 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] type_ann_expr.cpp:44: {dummy_op} Execution of [TypeAnnotationTransformer::DoTransform] took 569us
2025-10-26 19:54:38.290 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_constraint.cpp:3079: {dummy_op} Execution of [ConstraintTransformer::DoTransform] took 132us
2025-10-26 19:54:38.290 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] type_ann_expr.cpp:44: {dummy_op} Execution of [TypeAnnotationTransformer::DoTransform] took 4us
2025-10-26 19:54:38.291 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_constraint.cpp:3079: {dummy_op} Execution of [ConstraintTransformer::DoTransform] took 276us
2025-10-26 19:54:38.291 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_csee.cpp:598: {dummy_op} Execution of [UpdateCompletness] took 94us
2025-10-26 19:54:38.291 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_csee.cpp:611: {dummy_op} Execution of [EliminateCommonSubExpressions] took 200us
2025-10-26 19:54:38.291 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [core] yql_opt_utils.cpp:785: {dummy_op} Enumerate struct object for FlattenMembers
2025-10-26 19:54:38.293 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] type_ann_expr.cpp:44: {dummy_op} Execution of [TypeAnnotationTransformer::DoTransform] took 910us
2025-10-26 19:54:38.293 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_constraint.cpp:3079: {dummy_op} Execution of [ConstraintTransformer::DoTransform] took 208us
2025-10-26 19:54:38.294 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] type_ann_expr.cpp:44: {dummy_op} Execution of [TypeAnnotationTransformer::DoTransform] took 5us
2025-10-26 19:54:38.294 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_constraint.cpp:3079: {dummy_op} Execution of [ConstraintTransformer::DoTransform] took 486us
2025-10-26 19:54:38.295 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_csee.cpp:598: {dummy_op} Execution of [UpdateCompletness] took 215us
2025-10-26 19:54:38.295 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_csee.cpp:611: {dummy_op} Execution of [EliminateCommonSubExpressions] took 668us
2025-10-26 19:54:38.296 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [core] yql_co_simple1.cpp:1124: {dummy_op} CheckClonedStructure
2025-10-26 19:54:38.297 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] type_ann_expr.cpp:44: {dummy_op} Execution of [TypeAnnotationTransformer::DoTransform] took 247us
2025-10-26 19:54:38.297 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_constraint.cpp:3079: {dummy_op} Execution of [ConstraintTransformer::DoTransform] took 64us
2025-10-26 19:54:38.297 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] type_ann_expr.cpp:44: {dummy_op} Execution of [TypeAnnotationTransformer::DoTransform] took 5us
2025-10-26 19:54:38.297 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_constraint.cpp:3079: {dummy_op} Execution of [ConstraintTransformer::DoTransform] took 188us
2025-10-26 19:54:38.297 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_csee.cpp:598: {dummy_op} Execution of [UpdateCompletness] took 204us
2025-10-26 19:54:38.298 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_csee.cpp:611: {dummy_op} Execution of [EliminateCommonSubExpressions] took 180us
2025-10-26 19:54:38.298 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [core] yql_co_simple1.cpp:2016: {dummy_op} FlatMap with single arg AsList
2025-10-26 19:54:38.299 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] type_ann_expr.cpp:44: {dummy_op} Execution of [TypeAnnotationTransformer::DoTransform] took 226us
2025-10-26 19:54:38.299 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_constraint.cpp:3079: {dummy_op} Execution of [ConstraintTransformer::DoTransform] took 66us
2025-10-26 19:54:38.299 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] type_ann_expr.cpp:44: {dummy_op} Execution of [TypeAnnotationTransformer::DoTransform] took 6us
2025-10-26 19:54:38.299 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_constraint.cpp:3079: {dummy_op} Execution of [ConstraintTransformer::DoTransform] took 179us
2025-10-26 19:54:38.299 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_csee.cpp:598: {dummy_op} Execution of [UpdateCompletness] took 55us
2025-10-26 19:54:38.299 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_csee.cpp:611: {dummy_op} Execution of [EliminateCommonSubExpressions] took 178us
2025-10-26 19:54:38.300 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [core] yql_co_simple1.cpp:2028: {dummy_op} FlatMap with Just
2025-10-26 19:54:38.300 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] type_ann_expr.cpp:44: {dummy_op} Execution of [TypeAnnotationTransformer::DoTransform] took 106us
2025-10-26 19:54:38.300 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_constraint.cpp:3079: {dummy_op} Execution of [ConstraintTransformer::DoTransform] took 112us
2025-10-26 19:54:38.300 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_csee.cpp:598: {dummy_op} Execution of [UpdateCompletness] took 71us
2025-10-26 19:54:38.301 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_csee.cpp:611: {dummy_op} Execution of [EliminateCommonSubExpressions] took 155us
2025-10-26 19:54:38.303 INFO  dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [DQ] yql_dq_recapture.cpp:102: {dummy_op} DqsRecapture
2025-10-26 19:54:38.303 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [generic] yql_generic_datasource_type_ann.cpp:135: {dummy_op} struct column order0: _yql_block_length(Scalar<Uint64>), 1: col_01_boolean(Block<Bool?>), 2: col_02_int8(Block<Int8?>), 3: col_03_uint8(Block<Uint8?>), 4: col_04_int16(Block<Int16?>), 5: col_05_uint16(Block<Uint16?>), 6: col_06_int32(Block<Int32?>), 7: col_07_uint32(Block<Uint32?>), 8: col_08_int64(Block<Int64?>), 9: col_09_uint64(Block<Uint64?>), 10: col_10_float32(Block<Float?>), 11: col_11_float64(Block<Double?>), 12: col_12_string(Block<String?>), 13: col_13_fixed_string(Block<String?>), 14: col_14_date(Block<Date?>), 15: col_15_date32(Block<Date?>), 16: col_16_datetime(Block<Datetime?>), 17: col_17_datetime64(Block<Timestamp?>)
2025-10-26 19:54:38.304 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] type_ann_expr.cpp:44: {dummy_op} Execution of [TypeAnnotationTransformer::DoTransform] took 604us
2025-10-26 19:54:38.304 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_constraint.cpp:3079: {dummy_op} Execution of [ConstraintTransformer::DoTransform] took 242us
2025-10-26 19:54:38.304 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_csee.cpp:598: {dummy_op} Execution of [UpdateCompletness] took 139us
2025-10-26 19:54:38.305 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_csee.cpp:611: {dummy_op} Execution of [EliminateCommonSubExpressions] took 622us
2025-10-26 19:54:38.314 INFO  dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [generic] yql_optimize.cpp:135: {dummy_op} PhysicalOptimizer-TrimReadWorld
2025-10-26 19:54:38.315 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] type_ann_expr.cpp:44: {dummy_op} Execution of [TypeAnnotationTransformer::DoTransform] took 144us
2025-10-26 19:54:38.315 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_constraint.cpp:3079: {dummy_op} Execution of [ConstraintTransformer::DoTransform] took 98us
2025-10-26 19:54:38.315 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_csee.cpp:598: {dummy_op} Execution of [UpdateCompletness] took 113us
2025-10-26 19:54:38.315 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_csee.cpp:611: {dummy_op} Execution of [EliminateCommonSubExpressions] took 518us
2025-10-26 19:54:38.320 INFO  dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [DQ] yql_optimize.cpp:135: {dummy_op} DqsPhy-BuildStageWithSourceWrap
2025-10-26 19:54:38.322 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] type_ann_expr.cpp:44: {dummy_op} Execution of [TypeAnnotationTransformer::DoTransform] took 1.45ms
2025-10-26 19:54:38.322 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_constraint.cpp:3079: {dummy_op} Execution of [ConstraintTransformer::DoTransform] took 218us
2025-10-26 19:54:38.322 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] type_ann_expr.cpp:44: {dummy_op} Execution of [TypeAnnotationTransformer::DoTransform] took 5us
2025-10-26 19:54:38.323 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_constraint.cpp:3079: {dummy_op} Execution of [ConstraintTransformer::DoTransform] took 172us
2025-10-26 19:54:38.323 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] type_ann_expr.cpp:44: {dummy_op} Execution of [TypeAnnotationTransformer::DoTransform] took 5us
2025-10-26 19:54:38.324 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_constraint.cpp:3079: {dummy_op} Execution of [ConstraintTransformer::DoTransform] took 427us
2025-10-26 19:54:38.324 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_csee.cpp:598: {dummy_op} Execution of [UpdateCompletness] took 261us
2025-10-26 19:54:38.325 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_csee.cpp:611: {dummy_op} Execution of [EliminateCommonSubExpressions] took 849us
2025-10-26 19:54:38.334 INFO  dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [DQ] yql_optimize.cpp:135: {dummy_op} DqsPhy-BuildSortStage<false>
2025-10-26 19:54:38.336 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] type_ann_expr.cpp:44: {dummy_op} Execution of [TypeAnnotationTransformer::DoTransform] took 1.04ms
2025-10-26 19:54:38.336 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_constraint.cpp:3079: {dummy_op} Execution of [ConstraintTransformer::DoTransform] took 227us
2025-10-26 19:54:38.337 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] type_ann_expr.cpp:44: {dummy_op} Execution of [TypeAnnotationTransformer::DoTransform] took 5us
2025-10-26 19:54:38.337 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_constraint.cpp:3079: {dummy_op} Execution of [ConstraintTransformer::DoTransform] took 190us
2025-10-26 19:54:38.338 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] type_ann_expr.cpp:44: {dummy_op} Execution of [TypeAnnotationTransformer::DoTransform] took 5us
2025-10-26 19:54:38.338 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_constraint.cpp:3079: {dummy_op} Execution of [ConstraintTransformer::DoTransform] took 290us
2025-10-26 19:54:38.339 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] type_ann_expr.cpp:44: {dummy_op} Execution of [TypeAnnotationTransformer::DoTransform] took 4us
2025-10-26 19:54:38.339 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_constraint.cpp:3079: {dummy_op} Execution of [ConstraintTransformer::DoTransform] took 123us
2025-10-26 19:54:38.339 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_csee.cpp:598: {dummy_op} Execution of [UpdateCompletness] took 251us
2025-10-26 19:54:38.340 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_csee.cpp:611: {dummy_op} Execution of [EliminateCommonSubExpressions] took 827us
2025-10-26 19:54:38.354 INFO  dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [RESULT] yql_result_provider.cpp:769: {dummy_op} ResPull
2025-10-26 19:54:38.355 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] type_ann_expr.cpp:44: {dummy_op} Execution of [TypeAnnotationTransformer::DoTransform] took 351us
2025-10-26 19:54:38.355 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_constraint.cpp:3079: {dummy_op} Execution of [ConstraintTransformer::DoTransform] took 123us
2025-10-26 19:54:38.355 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] type_ann_expr.cpp:44: {dummy_op} Execution of [TypeAnnotationTransformer::DoTransform] took 5us
2025-10-26 19:54:38.356 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_constraint.cpp:3079: {dummy_op} Execution of [ConstraintTransformer::DoTransform] took 143us
2025-10-26 19:54:38.356 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_csee.cpp:598: {dummy_op} Execution of [UpdateCompletness] took 275us
2025-10-26 19:54:38.357 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_csee.cpp:611: {dummy_op} Execution of [EliminateCommonSubExpressions] took 829us
2025-10-26 19:54:38.368 INFO  dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [core exec] yql_execution.cpp:59: {dummy_op} Begin, root #199693
2025-10-26 19:54:38.368 INFO  dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [core exec] yql_execution.cpp:72: {dummy_op} Collect unused nodes for root #199693, status: Ok
2025-10-26 19:54:38.368 INFO  dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [core exec] yql_execution.cpp:577: {dummy_op} Node #199031<Configure!> finished execution
2025-10-26 19:54:38.369 INFO  dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [core exec] yql_execution.cpp:594: {dummy_op} Node #199031<Configure!> created 0 trackable nodes: 
2025-10-26 19:54:38.369 INFO  dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [core exec] yql_execution.cpp:577: {dummy_op} Node #199689<DqCnResult> finished execution
2025-10-26 19:54:38.369 INFO  dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [core exec] yql_execution.cpp:594: {dummy_op} Node #199689<DqCnResult> created 0 trackable nodes: 
2025-10-26 19:54:38.369 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [DQ] yql_dq_exectransformer.cpp:1247: {dummy_op/#199691/#199706} Executing Pull (UniqueId=199706)
2025-10-26 19:54:38.371 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] type_ann_expr.cpp:44: {dummy_op/#199691/#199706} Execution of [TypeAnnotationTransformer::DoTransform] took 57us
2025-10-26 19:54:38.371 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_constraint.cpp:3079: {dummy_op/#199691/#199706} Execution of [ConstraintTransformer::DoTransform] took 48us
2025-10-26 19:54:38.371 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_csee.cpp:598: {dummy_op/#199691/#199706} Execution of [UpdateCompletness] took 282us
2025-10-26 19:54:38.372 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_csee.cpp:611: {dummy_op/#199691/#199706} Execution of [EliminateCommonSubExpressionsForSubGraph] took 758us
2025-10-26 19:54:38.501 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] type_ann_expr.cpp:44: {dummy_op/#199691/#199706} Execution of [TypeAnnotationTransformer::DoTransform] took 1.3ms
2025-10-26 19:54:38.502 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_constraint.cpp:3079: {dummy_op/#199691/#199706} Execution of [ConstraintTransformer::DoTransform] took 268us
2025-10-26 19:54:38.502 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] type_ann_expr.cpp:44: {dummy_op/#199691/#199706} Execution of [TypeAnnotationTransformer::DoTransform] took 6us
2025-10-26 19:54:38.502 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_constraint.cpp:3079: {dummy_op/#199691/#199706} Execution of [ConstraintTransformer::DoTransform] took 340us
2025-10-26 19:54:38.502 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] type_ann_expr.cpp:44: {dummy_op/#199691/#199706} Execution of [TypeAnnotationTransformer::DoTransform] took 5us
2025-10-26 19:54:38.503 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_constraint.cpp:3079: {dummy_op/#199691/#199706} Execution of [ConstraintTransformer::DoTransform] took 127us
2025-10-26 19:54:38.503 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] type_ann_expr.cpp:44: {dummy_op/#199691/#199706} Execution of [TypeAnnotationTransformer::DoTransform] took 5us
2025-10-26 19:54:38.503 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_constraint.cpp:3079: {dummy_op/#199691/#199706} Execution of [ConstraintTransformer::DoTransform] took 117us
2025-10-26 19:54:38.503 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_csee.cpp:598: {dummy_op/#199691/#199706} Execution of [UpdateCompletness] took 272us
2025-10-26 19:54:38.504 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_csee.cpp:611: {dummy_op/#199691/#199706} Execution of [EliminateCommonSubExpressionsForSubGraph] took 869us
2025-10-26 19:54:38.513 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [core] yql_co_flow2.cpp:1012: {dummy_op/#199691/#199706} Drop FromFlow with ToFlow
2025-10-26 19:54:38.513 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [core] yql_co_flow2.cpp:1012: {dummy_op/#199691/#199706} Drop FromFlow with ToFlow
2025-10-26 19:54:38.514 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] type_ann_expr.cpp:44: {dummy_op/#199691/#199706} Execution of [TypeAnnotationTransformer::DoTransform] took 409us
2025-10-26 19:54:38.514 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_constraint.cpp:3079: {dummy_op/#199691/#199706} Execution of [ConstraintTransformer::DoTransform] took 106us
2025-10-26 19:54:38.514 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] type_ann_expr.cpp:44: {dummy_op/#199691/#199706} Execution of [TypeAnnotationTransformer::DoTransform] took 5us
2025-10-26 19:54:38.515 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_constraint.cpp:3079: {dummy_op/#199691/#199706} Execution of [ConstraintTransformer::DoTransform] took 121us
2025-10-26 19:54:38.515 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] type_ann_expr.cpp:44: {dummy_op/#199691/#199706} Execution of [TypeAnnotationTransformer::DoTransform] took 4us
2025-10-26 19:54:38.515 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_constraint.cpp:3079: {dummy_op/#199691/#199706} Execution of [ConstraintTransformer::DoTransform] took 96us
2025-10-26 19:54:38.515 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_csee.cpp:598: {dummy_op/#199691/#199706} Execution of [UpdateCompletness] took 262us
2025-10-26 19:54:38.516 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_csee.cpp:611: {dummy_op/#199691/#199706} Execution of [EliminateCommonSubExpressionsForSubGraph] took 725us
2025-10-26 19:54:38.522 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] type_ann_expr.cpp:44: {dummy_op/#199691/#199706} Execution of [TypeAnnotationTransformer::DoTransform] took 44us
2025-10-26 19:54:38.523 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_constraint.cpp:3079: {dummy_op/#199691/#199706} Execution of [ConstraintTransformer::DoTransform] took 46us
2025-10-26 19:54:38.523 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_csee.cpp:598: {dummy_op/#199691/#199706} Execution of [UpdateCompletness] took 243us
2025-10-26 19:54:38.524 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_csee.cpp:611: {dummy_op/#199691/#199706} Execution of [EliminateCommonSubExpressionsForSubGraph] took 729us
2025-10-26 19:54:38.524 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [core peephole] yql_opt_peephole_physical.cpp:4634: {dummy_op/#199691/#199706} Swap Sort with NarrowMap
2025-10-26 19:54:38.526 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] type_ann_expr.cpp:44: {dummy_op/#199691/#199706} Execution of [TypeAnnotationTransformer::DoTransform] took 1.05ms
2025-10-26 19:54:38.526 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_constraint.cpp:3079: {dummy_op/#199691/#199706} Execution of [ConstraintTransformer::DoTransform] took 156us
2025-10-26 19:54:38.527 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] type_ann_expr.cpp:44: {dummy_op/#199691/#199706} Execution of [TypeAnnotationTransformer::DoTransform] took 5us
2025-10-26 19:54:38.528 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_constraint.cpp:3079: {dummy_op/#199691/#199706} Execution of [ConstraintTransformer::DoTransform] took 1.33ms
2025-10-26 19:54:38.528 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_csee.cpp:598: {dummy_op/#199691/#199706} Execution of [UpdateCompletness] took 234us
2025-10-26 19:54:38.529 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_csee.cpp:611: {dummy_op/#199691/#199706} Execution of [EliminateCommonSubExpressionsForSubGraph] took 839us
2025-10-26 19:54:38.530 INFO  dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [core dq] yql_dq_exectransformer.cpp:376: {dummy_op/#199691/#199706} Setting block status for stage #199637 to Partial
2025-10-26 19:54:38.531 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] type_ann_expr.cpp:44: {dummy_op/#199691/#199706} Execution of [TypeAnnotationTransformer::DoTransform] took 321us
2025-10-26 19:54:38.531 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_constraint.cpp:3079: {dummy_op/#199691/#199706} Execution of [ConstraintTransformer::DoTransform] took 226us
2025-10-26 19:54:38.531 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_csee.cpp:598: {dummy_op/#199691/#199706} Execution of [UpdateCompletness] took 211us
2025-10-26 19:54:38.532 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_csee.cpp:611: {dummy_op/#199691/#199706} Execution of [EliminateCommonSubExpressionsForSubGraph] took 721us
2025-10-26 19:54:38.533 INFO  dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [core dq] yql_dq_exectransformer.cpp:376: {dummy_op/#199691/#199706} Setting block status for stage #199649 to None
2025-10-26 19:54:38.533 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] type_ann_expr.cpp:44: {dummy_op/#199691/#199706} Execution of [TypeAnnotationTransformer::DoTransform] took 234us
2025-10-26 19:54:38.533 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_constraint.cpp:3079: {dummy_op/#199691/#199706} Execution of [ConstraintTransformer::DoTransform] took 181us
2025-10-26 19:54:38.534 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_csee.cpp:598: {dummy_op/#199691/#199706} Execution of [UpdateCompletness] took 210us
2025-10-26 19:54:38.534 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_csee.cpp:611: {dummy_op/#199691/#199706} Execution of [EliminateCommonSubExpressionsForSubGraph] took 687us
2025-10-26 19:54:38.535 INFO  dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [core dq] yql_dq_exectransformer.cpp:376: {dummy_op/#199691/#199706} Setting block status for stage #199680 to None
2025-10-26 19:54:38.536 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] type_ann_expr.cpp:44: {dummy_op/#199691/#199706} Execution of [TypeAnnotationTransformer::DoTransform] took 159us
2025-10-26 19:54:38.536 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_constraint.cpp:3079: {dummy_op/#199691/#199706} Execution of [ConstraintTransformer::DoTransform] took 128us
2025-10-26 19:54:38.536 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_csee.cpp:598: {dummy_op/#199691/#199706} Execution of [UpdateCompletness] took 211us
2025-10-26 19:54:38.537 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [perf] yql_expr_csee.cpp:611: {dummy_op/#199691/#199706} Execution of [EliminateCommonSubExpressionsForSubGraph] took 710us
2025-10-26 19:54:38.539 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [DQ] execution_planner.cpp:152: {dummy_op/#199691/#199706} Execution Plan (
(let $1 '"clickhouse_integration_test")
(let $2 (DataSource '"generic" $1))
(let $3 '"col_13_fixed_string")
(let $4 '"col_17_datetime64")
(let $5 '('"col_01_boolean" '"col_02_int8" '"col_03_uint8" '"col_04_int16" '"col_05_uint16" '"col_06_int32" '"col_07_uint32" '"col_08_int64" '"col_09_uint64" '"col_10_float32" '"col_11_float64" '"col_12_string" $3 '"col_14_date" '"col_15_date32" '"col_16_datetime" $4))
(let $6 (Bool 'true))
(let $7 (GenSourceSettings $1 '"tf0c24b99" (SecureParam '"cluster:default_clickhouse_integration_test") $5 (lambda '($15) $6)))
(let $8 '('('"_logical_id" '199637) '('"_id" '"d0982fcf-2b666a28-11e2a8d7-a4c0bcb4") '('"_block_status" '"Partial")))
(let $9 (DqPhyStage '((DqSource $2 $7)) (lambda '($16) (block '(
  (let $17 (OptionalType (DataType 'String)))
  (let $18 (OptionalType (DataType 'Date)))
  (let $19 (StructType '('"col_01_boolean" (OptionalType (DataType 'Bool))) '('"col_02_int8" (OptionalType (DataType 'Int8))) '('"col_03_uint8" (OptionalType (DataType 'Uint8))) '('"col_04_int16" (OptionalType (DataType 'Int16))) '('"col_05_uint16" (OptionalType (DataType 'Uint16))) '('"col_06_int32" (OptionalType (DataType 'Int32))) '('"col_07_uint32" (OptionalType (DataType 'Uint32))) '('"col_08_int64" (OptionalType (DataType 'Int64))) '('"col_09_uint64" (OptionalType (DataType 'Uint64))) '('"col_10_float32" (OptionalType (DataType 'Float))) '('"col_11_float64" (OptionalType (DataType 'Double))) '('"col_12_string" $17) '($3 $17) '('"col_14_date" $18) '('"col_15_date32" $18) '('"col_16_datetime" (OptionalType (DataType 'Datetime))) '($4 (OptionalType (DataType 'Timestamp)))))
  (return (FromFlow (NarrowMap (WideSort (WideFromBlocks (DqSourceWideBlockWrap $16 $2 $19)) '('('0 $6))) (lambda '($20 $21 $22 $23 $24 $25 $26 $27 $28 $29 $30 $31 $32 $33 $34 $35 $36) (AsStruct '('"col_01_boolean" $20) '('"col_02_int8" $21) '('"col_03_uint8" $22) '('"col_04_int16" $23) '('"col_05_uint16" $24) '('"col_06_int32" $25) '('"col_07_uint32" $26) '('"col_08_int64" $27) '('"col_09_uint64" $28) '('"col_10_float32" $29) '('"col_11_float64" $30) '('"col_12_string" $31) '($3 $32) '('"col_14_date" $33) '('"col_15_date32" $34) '('"col_16_datetime" $35) '($4 $36))))))
))) $8))
(let $10 '('"_block_status" '"None"))
(let $11 '('('"_logical_id" '199649) '('"_id" '"a60b0a95-69ba5a67-8ebdc153-2f24fa22") $10))
(let $12 (DqPhyStage '((DqCnMerge (TDqOutput $9 '0) '('('"col_01_boolean" '"Asc")))) (lambda '($37) $37) $11))
(let $13 '('('"_logical_id" '199680) '('"_id" '"dc9d493b-46a1175a-7a3bf54b-fce3c967") $10))
(let $14 (DqPhyStage '((DqCnUnionAll (TDqOutput $12 '0))) (lambda '($38) $38) $13))
(return (DqCnResult (TDqOutput $14 '0) '()))
)

2025-10-26 19:54:38.541 INFO  dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [generic] yql_generic_dq_integration.cpp:126: {dummy_op/#199691/#199706} Filling source settings: cluster: clickhouse_integration_test, table: tf0c24b99, endpoint: host: "172.18.0.2" port: 9000
2025-10-26 19:54:38.552 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [DQ] yql_dq_gateway.cpp:382: {dummy_op} Send query of size 4436
2025-10-26 19:54:38.554 INFO  dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [core exec] yql_execution.cpp:466: {dummy_op} Register async execution for node #199691
2025-10-26 19:54:38.554 INFO  dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [core exec] yql_execution.cpp:87: {dummy_op} Finish, output #199693, status: Async
2025-10-26 19:54:38.555 DEBUG dqrun(pid=1999589, tid=0x00007FB95F3D4640) [DQ] grpc_service.cpp:353: {dummy_op} TServiceProxyActor::OnExecuteGraph
2025-10-26 19:54:38.560 DEBUG dqrun(pid=1999589, tid=0x00007FB95EBC5640) [DQ] graph_execution_events_actor.cpp:38: {dummy_op} OnEvent START
2025-10-26 19:54:38.560 DEBUG dqrun(pid=1999589, tid=0x00007FB95EBC5640) [DQ] graph_execution_events_actor.cpp:77: {dummy_op} OnStart
2025-10-26 19:54:38.560 DEBUG dqrun(pid=1999589, tid=0x00007FB95F3D4640) [DQ] actor_helpers.h:147: OnSync(): delayed messages 0
2025-10-26 19:54:38.560 DEBUG dqrun(pid=1999589, tid=0x00007FB95F3D4640) [DQ] grpc_service.cpp:393: {dummy_op} FinishBootstrap
2025-10-26 19:54:38.561 DEBUG dqrun(pid=1999589, tid=0x00007FB95F3D4640) [DQ] result_actor_base.h:117: {dummy_op} _AllResultsBytesLimit = 100000
2025-10-26 19:54:38.561 DEBUG dqrun(pid=1999589, tid=0x00007FB95F3D4640) [DQ] result_actor_base.h:118: {dummy_op} _RowsLimitPerWrite = 1000
2025-10-26 19:54:38.561 DEBUG dqrun(pid=1999589, tid=0x00007FB95F3D4640) [DQ] task_controller_impl.h:78: {dummy_op} _AllResultsBytesLimit = 100000
2025-10-26 19:54:38.561 DEBUG dqrun(pid=1999589, tid=0x00007FB95F3D4640) [DQ] task_controller_impl.h:81: {dummy_op} _RowsLimitPerWrite = 1000
2025-10-26 19:54:38.562 DEBUG dqrun(pid=1999589, tid=0x00007FB95F3D4640) [DQ] interconnect_helpers.cpp:40: 2025-10-26T19:54:38.561901Z :ActorLib INFO: SessionId: dummy_op 2025-10-26 19:54:38.561 INFO  dqrun(pid=1999589, tid=0x00007FB95EBC5640) [DQ] executer_actor.cpp:157: {dummy_op} Trying to allocate 3 workers [EnableComputeActor=1]

2025-10-26 19:54:38.563 DEBUG dqrun(pid=1999589, tid=0x00007FB95F3D4640) [DQ] local_worker_manager.cpp:316: {dummy_op} TLocalWorkerManager::TEvAllocateWorkersRequest 364406500229120
2025-10-26 19:54:38.563 DEBUG dqrun(pid=1999589, tid=0x00007FB95F3D4640) [DQ] local_worker_manager.cpp:376: {dummy_op} Create compute actor: async
2025-10-26 19:54:38.564 DEBUG dqrun(pid=1999589, tid=0x00007FB95F3D4640) [DQ] local_worker_manager.cpp:376: {dummy_op} Create compute actor: async
2025-10-26 19:54:38.564 DEBUG dqrun(pid=1999589, tid=0x00007FB95F3D4640) [DQ] local_worker_manager.cpp:376: {dummy_op} Create compute actor: async
2025-10-26 19:54:38.565 DEBUG dqrun(pid=1999589, tid=0x00007FB95EBC5640) [DQ] tasks_runner_local.cpp:267: {TODO/1} Build task: 1
2025-10-26 19:54:38.566 DEBUG dqrun(pid=1999589, tid=0x00007FB95AA5D640) [DQ] resource_allocator.cpp:141: {dummy_op/[1:7565621305754621436:8203]} TEvAllocateWorkersResponse 1
2025-10-26 19:54:38.566 DEBUG dqrun(pid=1999589, tid=0x00007FB95D8A5640) [DQ] tasks_runner_local.cpp:267: {TODO/2} Build task: 2
2025-10-26 19:54:38.567 DEBUG dqrun(pid=1999589, tid=0x00007FB95BD76640) [DQ] tasks_runner_local.cpp:267: {TODO/3} Build task: 3
2025-10-26 19:54:38.567 DEBUG dqrun(pid=1999589, tid=0x00007FB95AA5D640) [DQ] interconnect_helpers.cpp:40: 2025-10-26T19:54:38.567202Z :ActorLib INFO: SessionId: dummy_op 2025-10-26 19:54:38.567 INFO  dqrun(pid=1999589, tid=0x00007FB95F3D4640) [DQ] executer_actor.cpp:412: {dummy_op} 3 workers allocated

2025-10-26 19:54:38.567 DEBUG dqrun(pid=1999589, tid=0x00007FB95D8A5640) [DQ] tasks_runner_local.cpp:267: {TODO/2} task: 2, program size: 39, llvm: ``.
2025-10-26 19:54:38.568 DEBUG dqrun(pid=1999589, tid=0x00007FB95BD76640) [DQ] tasks_runner_local.cpp:267: {TODO/3} task: 3, program size: 39, llvm: ``.
2025-10-26 19:54:38.569 DEBUG dqrun(pid=1999589, tid=0x00007FB95EBC5640) [DQ] tasks_runner_local.cpp:267: {TODO/1} task: 1, program size: 191, llvm: ``.
2025-10-26 19:54:38.608 DEBUG dqrun(pid=1999589, tid=0x00007FB95BD76640) [DQ] tasks_runner_local.cpp:267: {TODO/3} Build task: 3 takes 41205 us
2025-10-26 19:54:38.608 DEBUG dqrun(pid=1999589, tid=0x00007FB95BD76640) [DQ] tasks_runner_local.cpp:267: {TODO/3} Prepare task: 3
2025-10-26 19:54:38.608 DEBUG dqrun(pid=1999589, tid=0x00007FB95BD76640) [DQ] tasks_runner_local.cpp:267: {TODO/3} Run task: 3, Prepare task: 3, takes 145 us
2025-10-26 19:54:38.609 DEBUG dqrun(pid=1999589, tid=0x00007FB95D8A5640) [DQ] tasks_runner_local.cpp:267: {TODO/2} Build task: 2 takes 42426 us
2025-10-26 19:54:38.609 DEBUG dqrun(pid=1999589, tid=0x00007FB95D8A5640) [DQ] tasks_runner_local.cpp:267: {TODO/2} Prepare task: 2
2025-10-26 19:54:38.609 DEBUG dqrun(pid=1999589, tid=0x00007FB95D8A5640) [DQ] tasks_runner_local.cpp:267: {TODO/2} Run task: 2, Prepare task: 2, takes 109 us
2025-10-26 19:54:38.609 DEBUG dqrun(pid=1999589, tid=0x00007FB95F3D4640) [DQ] tasks_runner_local.cpp:267: {TODO/3} Run task: 3, Run task: 3
2025-10-26 19:54:38.609 DEBUG dqrun(pid=1999589, tid=0x00007FB95BD76640) [DQ] tasks_runner_local.cpp:267: {TODO/2} Run task: 2, Run task: 2
2025-10-26 19:54:40.909 DEBUG dqrun(pid=1999589, tid=0x00007FB95EBC5640) [DQ] tasks_runner_local.cpp:267: {TODO/1} Build task: 1 takes 2344372 us
2025-10-26 19:54:40.909 DEBUG dqrun(pid=1999589, tid=0x00007FB95EBC5640) [DQ] tasks_runner_local.cpp:267: {TODO/1} Prepare task: 1
2025-10-26 19:54:40.910 DEBUG dqrun(pid=1999589, tid=0x00007FB95EBC5640) [DQ] tasks_runner_local.cpp:267: {TODO/1} Run task: 1, Prepare task: 1, takes 67 us
2025-10-26 19:54:40.910 INFO  dqrun(pid=1999589, tid=0x00007FB95EBC5640) [generic] yql_generic_read_actor.cpp:454: Creating read actor with params: kind=CLICKHOUSE, endpoint=host: "172.18.0.2" port: 9000, database=primitive_types_nullable_NATIVE, use_tls=0, protocol=NATIVE
2025-10-26 19:54:40.910 DEBUG dqrun(pid=1999589, tid=0x00007FB95EBC5640) [generic] yql_generic_read_actor.cpp:83: Start splits listing
2025-10-26 19:54:40.911 DEBUG dqrun(pid=1999589, tid=0x00007FB95EBC5640) [DQ] tasks_runner_local.cpp:267: {TODO/1} Run task: 1, Run task: 1
2025-10-26 19:54:40.913 DEBUG dqrun(pid=1999589, tid=0x00007FB95EBC5640) [generic] yql_generic_read_actor.cpp:147: Handle :: EvListSplitsFinished :: last message was reached, start data reading
2025-10-26 19:54:40.913 DEBUG dqrun(pid=1999589, tid=0x00007FB95EBC5640) [generic] yql_generic_read_actor.cpp:167: Start splits reading
2025-10-26 19:54:40.919 DEBUG dqrun(pid=1999589, tid=0x00007FB95EBC5640) [DQ] tasks_runner_local.cpp:267: {TODO/1} Run task: 1, Run task: 1
2025-10-26 19:54:40.919 DEBUG dqrun(pid=1999589, tid=0x00007FB95D8A5640) [DQ] tasks_runner_local.cpp:267: {TODO/2} Run task: 2, Run task: 2
2025-10-26 19:54:40.919 DEBUG dqrun(pid=1999589, tid=0x00007FB95EBC5640) [DQ] tasks_runner_local.cpp:267: {TODO/3} Run task: 3, Run task: 3
2025-10-26 19:54:40.926 DEBUG dqrun(pid=1999589, tid=0x00007FB95F3D4640) [DQ] tasks_runner_local.cpp:267: {TODO/1} Run task: 1, Run task: 1
2025-10-26 19:54:40.926 DEBUG dqrun(pid=1999589, tid=0x00007FB95F3D4640) [generic] yql_generic_read_actor.cpp:240: Handle :: EvReadSplitsFinished :: last message was reached, finish data reading
2025-10-26 19:54:40.926 DEBUG dqrun(pid=1999589, tid=0x00007FB95F3D4640) [DQ] tasks_runner_local.cpp:267: {TODO/1} Run task: 1, Run task: 1
2025-10-26 19:54:40.927 INFO  dqrun(pid=1999589, tid=0x00007FB95F3D4640) [generic] yql_generic_read_actor.cpp:335: GetAsyncInputData :: data reading finished
2025-10-26 19:54:40.927 DEBUG dqrun(pid=1999589, tid=0x00007FB95F3D4640) [DQ] tasks_runner_local.cpp:267: {TODO/1} Run task: 1, Run task: 1
2025-10-26 19:54:40.927 DEBUG dqrun(pid=1999589, tid=0x00007FB95F3D4640) [DQ] tasks_runner_local.cpp:267: {TODO/1} Run task: 1, task1, execution finished, finish consumers
2025-10-26 19:54:40.927 DEBUG dqrun(pid=1999589, tid=0x00007FB95F3D4640) [DQ] tasks_runner_local.cpp:267: {TODO/1} channelId: 1. Finish request
2025-10-26 19:54:40.927 DEBUG dqrun(pid=1999589, tid=0x00007FB95EBC5640) [DQ] tasks_runner_local.cpp:267: {TODO/2} Run task: 2, Run task: 2
2025-10-26 19:54:40.928 DEBUG dqrun(pid=1999589, tid=0x00007FB95F3D4640) [DQ] tasks_runner_local.cpp:267: {TODO/1} Run task: 1, Run task: 1
2025-10-26 19:54:40.928 DEBUG dqrun(pid=1999589, tid=0x00007FB95F3D4640) [DQ] tasks_runner_local.cpp:267: {TODO/1} Run task: 1, task1, execution finished, finish consumers
2025-10-26 19:54:40.928 DEBUG dqrun(pid=1999589, tid=0x00007FB95F3D4640) [DQ] tasks_runner_local.cpp:267: {TODO/1} channelId: 1. Finish request
2025-10-26 19:54:40.928 DEBUG dqrun(pid=1999589, tid=0x00007FB95EBC5640) [DQ] tasks_runner_local.cpp:267: {TODO/2} Run task: 2, task2, execution finished, finish consumers
2025-10-26 19:54:40.928 DEBUG dqrun(pid=1999589, tid=0x00007FB95EBC5640) [DQ] tasks_runner_local.cpp:267: {TODO/2} channelId: 2. Finish request
2025-10-26 19:54:40.928 INFO  dqrun(pid=1999589, tid=0x00007FB95F3D4640) [generic] yql_generic_read_actor.cpp:400: PassAway :: final ingress stats: bytes 221, rows 2, chunks 1
2025-10-26 19:54:40.928 DEBUG dqrun(pid=1999589, tid=0x00007FB95EBC5640) [DQ] tasks_runner_local.cpp:267: {TODO/3} Run task: 3, Run task: 3
2025-10-26 19:54:40.929 DEBUG dqrun(pid=1999589, tid=0x00007FB95EBC5640) [DQ] tasks_runner_local.cpp:267: {TODO/3} Run task: 3, task3, execution finished, finish consumers
2025-10-26 19:54:40.929 DEBUG dqrun(pid=1999589, tid=0x00007FB95EBC5640) [DQ] tasks_runner_local.cpp:267: {TODO/3} channelId: 3. Finish request
2025-10-26 19:54:40.929 DEBUG dqrun(pid=1999589, tid=0x00007FB95AA5D640) [DQ] tasks_runner_local.cpp:267: {TODO/2} Run task: 2, Run task: 2
2025-10-26 19:54:40.929 DEBUG dqrun(pid=1999589, tid=0x00007FB95AA5D640) [DQ] tasks_runner_local.cpp:267: {TODO/2} Run task: 2, task2, execution finished, finish consumers
2025-10-26 19:54:40.929 DEBUG dqrun(pid=1999589, tid=0x00007FB95AA5D640) [DQ] tasks_runner_local.cpp:267: {TODO/2} channelId: 2. Finish request
2025-10-26 19:54:40.930 DEBUG dqrun(pid=1999589, tid=0x00007FB95F3D4640) [DQ] tasks_runner_local.cpp:267: {TODO/3} Run task: 3, Run task: 3
2025-10-26 19:54:40.930 DEBUG dqrun(pid=1999589, tid=0x00007FB95F3D4640) [DQ] tasks_runner_local.cpp:267: {TODO/3} Run task: 3, task3, execution finished, finish consumers
2025-10-26 19:54:40.930 DEBUG dqrun(pid=1999589, tid=0x00007FB95F3D4640) [DQ] tasks_runner_local.cpp:267: {TODO/3} channelId: 3. Finish request
2025-10-26 19:54:40.933 DEBUG dqrun(pid=1999589, tid=0x00007FB95EBC5640) [DQ] grpc_service.cpp:211: {dummy_op} TServiceProxyActor::OnReturnResult 106
2025-10-26 19:54:40.933 DEBUG dqrun(pid=1999589, tid=0x00007FB95D8A5640) [DQ] resource_allocator.cpp:228: {dummy_op/[1:7565621305754621436:8203]} TEvFreeWorkersNotify 364406500229120
2025-10-26 19:54:40.933 DEBUG dqrun(pid=1999589, tid=0x00007FB95F3D4640) [DQ] local_worker_manager.cpp:416: TEvFreeWorkersNotify 364406500229120
2025-10-26 19:54:40.933 DEBUG dqrun(pid=1999589, tid=0x00007FB95D8A5640) [DQ] resource_allocator.cpp:228: {dummy_op/[1:7565621305754621436:8203]} TEvFreeWorkersNotify 364406500229120
2025-10-26 19:54:40.934 DEBUG dqrun(pid=1999589, tid=0x00007FB95F3D4640) [DQ] local_worker_manager.cpp:440: Free Group 364406500229120
2025-10-26 19:54:40.934 DEBUG dqrun(pid=1999589, tid=0x00007FB95D8A5640) [DQ] resource_allocator.cpp:228: {dummy_op/[1:7565621305754621436:8203]} TEvFreeWorkersNotify 364406500229120
2025-10-26 19:54:40.934 DEBUG dqrun(pid=1999589, tid=0x00007FB95F3D4640) [DQ] local_worker_manager.cpp:416: TEvFreeWorkersNotify 364406500229120
2025-10-26 19:54:40.934 DEBUG dqrun(pid=1999589, tid=0x00007FB95F3D4640) [DQ] local_worker_manager.cpp:440: Free Group 364406500229120
2025-10-26 19:54:40.934 DEBUG dqrun(pid=1999589, tid=0x00007FB95F3D4640) [DQ] local_worker_manager.cpp:416: TEvFreeWorkersNotify 364406500229120
2025-10-26 19:54:40.934 DEBUG dqrun(pid=1999589, tid=0x00007FB95F3D4640) [DQ] local_worker_manager.cpp:440: Free Group 364406500229120
2025-10-26 19:54:40.935 DEBUG dqrun(pid=1999589, tid=0x00007FB95F3D4640) [DQ] graph_execution_events_actor.cpp:38: {dummy_op} OnEvent SUCCESS
2025-10-26 19:54:40.935 DEBUG dqrun(pid=1999589, tid=0x00007FB95F3D4640) [DQ] graph_execution_events_actor.cpp:120: {dummy_op} OnSuccess
2025-10-26 19:54:40.935 DEBUG dqrun(pid=1999589, tid=0x00007FB95F3D4640) [DQ] actor_helpers.h:147: OnSync(): delayed messages 0
2025-10-26 19:54:40.936 DEBUG dqrun(pid=1999589, tid=0x00007FB95F3D4640) [DQ] grpc_service.cpp:333: {dummy_op} DoPassAway
2025-10-26 19:54:40.938 INFO  dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [core exec] yql_execution.cpp:133: {dummy_op} Completed async execution for node #199691
2025-10-26 19:54:40.938 INFO  dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [DQ] yql_dq_exectransformer.cpp:1463: {dummy_op} Execution Pull complete, duration: 2.568754s
2025-10-26 19:54:40.939 INFO  dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [core exec] yql_execution.cpp:153: {dummy_op} State is ExecutionComplete after apply async changes for node #199691
2025-10-26 19:54:40.939 INFO  dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [core exec] yql_execution.cpp:59: {dummy_op} Begin, root #199693
2025-10-26 19:54:40.939 INFO  dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [core exec] yql_execution.cpp:72: {dummy_op} Collect unused nodes for root #199693, status: Ok
2025-10-26 19:54:40.939 INFO  dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [core exec] yql_execution.cpp:577: {dummy_op} Node #199692<Commit!> finished execution
2025-10-26 19:54:40.939 INFO  dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [core exec] yql_execution.cpp:594: {dummy_op} Node #199692<Commit!> created 0 trackable nodes: 
2025-10-26 19:54:40.939 INFO  dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [core exec] yql_execution.cpp:577: {dummy_op} Node #199693<Commit!> finished execution
2025-10-26 19:54:40.939 INFO  dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [core exec] yql_execution.cpp:594: {dummy_op} Node #199693<Commit!> created 0 trackable nodes: 
2025-10-26 19:54:40.939 INFO  dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [core exec] yql_execution.cpp:87: {dummy_op} Finish, output #199693, status: Ok
2025-10-26 19:54:40.939 INFO  dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [core exec] yql_execution.cpp:93: {dummy_op} Creating finalizing transformer, output #199693
{
    "Detailed" = {
        "Operations" = [
            {
                "Id" = 10u;
                "Name" = "DqStage";
                "Streams" = {
                    "Program" = [
                        {
                            "Name" = "DqSourceWideBlockWrap"
                        };
                        {
                            "Name" = "WideFromBlocks"
                        };
                        {
                            "Name" = "NarrowMap"
                        };
                        {
                            "Name" = "Sort"
                        }
                    ]
                }
            };
            {
                "Id" = 8u;
                "Name" = "DqStage";
                "Streams" = {
                    "Program" = []
                };
                "DependsOn" = [
                    10u
                ]
            };
            {
                "Id" = 6u;
                "Name" = "DqStage";
                "Streams" = {
                    "Program" = []
                };
                "DependsOn" = [
                    8u
                ]
            };
            {
                "Id" = 3u;
                "Name" = "ResPull!";
                "DependsOn" = [
                    6u
                ]
            };
            {
                "Id" = 1u;
                "Name" = "Commit!";
                "DependsOn" = [
                    3u
                ]
            }
        ];
        "OperationRoot" = 1u;
        "Providers" = [];
        "OperationStats" = {
            "Commit!" = 1u;
            "DqStage" = 3u;
            "ResPull!" = 1u
        }
    };
    "Basic" = {
        "nodes" = [
            {
                "id" = 10u;
                "level" = 1u;
                "name" = "DqStage #10";
                "type" = "op"
            };
            {
                "id" = 8u;
                "level" = 2u;
                "name" = "DqStage #8";
                "type" = "op"
            };
            {
                "id" = 6u;
                "level" = 3u;
                "name" = "DqStage #6";
                "type" = "op"
            };
            {
                "id" = 3u;
                "level" = 4u;
                "name" = "ResPull!";
                "type" = "op"
            };
            {
                "id" = 1u;
                "level" = 5u;
                "name" = "Commit!";
                "type" = "op"
            }
        ];
        "links" = [
            {
                "source" = 10u;
                "target" = 8u
            };
            {
                "source" = 8u;
                "target" = 6u
            };
            {
                "source" = 6u;
                "target" = 3u
            };
            {
                "source" = 3u;
                "target" = 1u
            }
        ]
    }
}Getting results...

Done
2025-10-26 19:54:41.257 DEBUG dqrun(pid=1999589, tid=0x00007FB99A7E3C00) [DQ] yql_dq_provider.cpp:126: {dummy_op} CloseSession dummy_op
2025-10-26 19:54:41.259 DEBUG dqrun(pid=1999589, tid=0x00007FB93C12B640) [DQ] yql_dq_gateway.cpp:412: {dummy_op} Async close session OK
