@@ -247,33 +247,62 @@ impl<T: 'static + AsLogicalPlan> ExecutionPlan for DistributedQueryExec<T> {
247247
248248 let session_config = context. session_config ( ) . clone ( ) ;
249249
250- let stream = futures:: stream:: once (
251- execute_query (
252- self . scheduler_url . clone ( ) ,
253- self . session_id . clone ( ) ,
254- query,
255- self . config . default_grpc_client_max_message_size ( ) ,
256- GrpcClientConfig :: from ( & self . config ) ,
257- Arc :: new ( self . metrics . clone ( ) ) ,
258- partition,
259- session_config,
250+ if session_config. ballista_config ( ) . client_pull ( ) {
251+ let stream = futures:: stream:: once (
252+ execute_query_pull (
253+ self . scheduler_url . clone ( ) ,
254+ self . session_id . clone ( ) ,
255+ query,
256+ self . config . default_grpc_client_max_message_size ( ) ,
257+ GrpcClientConfig :: from ( & self . config ) ,
258+ Arc :: new ( self . metrics . clone ( ) ) ,
259+ partition,
260+ session_config,
261+ )
262+ . map_err ( |e| ArrowError :: ExternalError ( Box :: new ( e) ) ) ,
260263 )
261- . map_err ( |e| ArrowError :: ExternalError ( Box :: new ( e) ) ) ,
262- )
263- . try_flatten ( )
264- . inspect ( move |batch| {
265- metric_total_bytes. add (
266- batch
267- . as_ref ( )
268- . map ( |b| b. get_array_memory_size ( ) )
269- . unwrap_or ( 0 ) ,
270- ) ;
271-
272- metric_row_count. add ( batch. as_ref ( ) . map ( |b| b. num_rows ( ) ) . unwrap_or ( 0 ) ) ;
273- } ) ;
274-
275- let schema = self . schema ( ) ;
276- Ok ( Box :: pin ( RecordBatchStreamAdapter :: new ( schema, stream) ) )
264+ . try_flatten ( )
265+ . inspect ( move |batch| {
266+ metric_total_bytes. add (
267+ batch
268+ . as_ref ( )
269+ . map ( |b| b. get_array_memory_size ( ) )
270+ . unwrap_or ( 0 ) ,
271+ ) ;
272+
273+ metric_row_count. add ( batch. as_ref ( ) . map ( |b| b. num_rows ( ) ) . unwrap_or ( 0 ) ) ;
274+ } ) ;
275+
276+ let schema = self . schema ( ) ;
277+ Ok ( Box :: pin ( RecordBatchStreamAdapter :: new ( schema, stream) ) )
278+ } else {
279+ let stream = futures:: stream:: once (
280+ execute_query_push (
281+ self . scheduler_url . clone ( ) ,
282+ query,
283+ self . config . default_grpc_client_max_message_size ( ) ,
284+ GrpcClientConfig :: from ( & self . config ) ,
285+ Arc :: new ( self . metrics . clone ( ) ) ,
286+ partition,
287+ session_config,
288+ )
289+ . map_err ( |e| ArrowError :: ExternalError ( Box :: new ( e) ) ) ,
290+ )
291+ . try_flatten ( )
292+ . inspect ( move |batch| {
293+ metric_total_bytes. add (
294+ batch
295+ . as_ref ( )
296+ . map ( |b| b. get_array_memory_size ( ) )
297+ . unwrap_or ( 0 ) ,
298+ ) ;
299+
300+ metric_row_count. add ( batch. as_ref ( ) . map ( |b| b. num_rows ( ) ) . unwrap_or ( 0 ) ) ;
301+ } ) ;
302+
303+ let schema = self . schema ( ) ;
304+ Ok ( Box :: pin ( RecordBatchStreamAdapter :: new ( schema, stream) ) )
305+ }
277306 }
278307
279308 fn statistics ( & self ) -> Result < Statistics > {
@@ -288,8 +317,11 @@ impl<T: 'static + AsLogicalPlan> ExecutionPlan for DistributedQueryExec<T> {
288317 }
289318}
290319
320+ /// Client will periodically invoke scheduler to check
321+ /// job status. There is preconfigured wait period between
322+ /// pulls, which increases query latency.
291323#[ allow( clippy:: too_many_arguments) ]
292- async fn execute_query (
324+ async fn execute_query_pull (
293325 scheduler_url : String ,
294326 session_id : String ,
295327 query : ExecuteQueryParams ,
@@ -453,6 +485,160 @@ async fn execute_query(
453485 } ;
454486 }
455487}
488+ /// After job is scheduled client waits
489+ /// for job updates, which are streamed back
490+ /// from server to client
491+ #[ allow( clippy:: too_many_arguments) ]
492+ async fn execute_query_push (
493+ scheduler_url : String ,
494+ query : ExecuteQueryParams ,
495+ max_message_size : usize ,
496+ grpc_config : GrpcClientConfig ,
497+ metrics : Arc < ExecutionPlanMetricsSet > ,
498+ partition : usize ,
499+ session_config : SessionConfig ,
500+ ) -> Result < impl Stream < Item = Result < RecordBatch > > + Send > {
501+ let grpc_interceptor = session_config. ballista_grpc_interceptor ( ) ;
502+ let customize_endpoint =
503+ session_config. ballista_override_create_grpc_client_endpoint ( ) ;
504+ let use_tls = session_config. ballista_use_tls ( ) ;
505+
506+ // Capture query submission time for total_query_time_ms
507+ let query_start_time = std:: time:: Instant :: now ( ) ;
508+
509+ info ! ( "Connecting to Ballista scheduler at {scheduler_url}" ) ;
510+ // TODO reuse the scheduler to avoid connecting to the Ballista scheduler again and again
511+ let mut endpoint =
512+ create_grpc_client_endpoint ( scheduler_url. clone ( ) , Some ( & grpc_config) )
513+ . map_err ( |e| DataFusionError :: Execution ( format ! ( "{e:?}" ) ) ) ?;
514+
515+ if let Some ( ref customize) = customize_endpoint {
516+ endpoint = customize
517+ . configure_endpoint ( endpoint)
518+ . map_err ( |e| DataFusionError :: Execution ( format ! ( "{e:?}" ) ) ) ?;
519+ }
520+
521+ let connection = endpoint
522+ . connect ( )
523+ . await
524+ . map_err ( |e| DataFusionError :: Execution ( format ! ( "{e:?}" ) ) ) ?;
525+
526+ let mut scheduler = SchedulerGrpcClient :: with_interceptor (
527+ connection,
528+ grpc_interceptor. as_ref ( ) . clone ( ) ,
529+ )
530+ . max_encoding_message_size ( max_message_size)
531+ . max_decoding_message_size ( max_message_size) ;
532+
533+ let mut query_status_stream = scheduler
534+ . execute_query_push ( query)
535+ . await
536+ . map_err ( |e| DataFusionError :: Execution ( format ! ( "{e:?}" ) ) ) ?
537+ . into_inner ( ) ;
538+
539+ let mut prev_status: Option < job_status:: Status > = None ;
540+
541+ loop {
542+ let item = query_status_stream
543+ . next ( )
544+ . await
545+ . ok_or ( DataFusionError :: Execution (
546+ "Stream closed without job completing" . to_string ( ) ,
547+ ) ) ?
548+ . map_err ( |e| DataFusionError :: Execution ( e. to_string ( ) ) ) ?;
549+
550+ let GetJobStatusResult {
551+ status,
552+ flight_proxy,
553+ } = item;
554+ let job_id = status
555+ . as_ref ( )
556+ . map ( |s| s. job_id . to_owned ( ) )
557+ . unwrap_or ( "unknown_job_id" . to_string ( ) ) ; // should not happen
558+ let status = status. and_then ( |s| s. status ) ;
559+ let has_status_change = prev_status != status;
560+ match status {
561+ None => {
562+ if has_status_change {
563+ info ! ( "Job {job_id} is in initialization ..." ) ;
564+ }
565+ prev_status = status;
566+ }
567+ Some ( job_status:: Status :: Queued ( _) ) => {
568+ if has_status_change {
569+ info ! ( "Job {job_id} is queued..." ) ;
570+ }
571+ prev_status = status;
572+ }
573+ Some ( job_status:: Status :: Running ( _) ) => {
574+ if has_status_change {
575+ info ! ( "Job {job_id} is running..." ) ;
576+ }
577+ prev_status = status;
578+ }
579+ Some ( job_status:: Status :: Failed ( err) ) => {
580+ let msg = format ! ( "Job {} failed: {}" , job_id, err. error) ;
581+ error ! ( "{msg}" ) ;
582+ break Err ( DataFusionError :: Execution ( msg) ) ;
583+ }
584+ Some ( job_status:: Status :: Successful ( SuccessfulJob {
585+ queued_at,
586+ started_at,
587+ ended_at,
588+ partition_location,
589+ ..
590+ } ) ) => {
591+ // Calculate job execution time (server-side execution)
592+ let job_execution_ms = ended_at. saturating_sub ( started_at) ;
593+ let duration = Duration :: from_millis ( job_execution_ms) ;
594+
595+ info ! ( "Job {job_id} finished executing in {duration:?} " ) ;
596+
597+ // Calculate scheduling time (server-side queue time)
598+ // This includes network latency and actual queue time
599+ let scheduling_ms = started_at. saturating_sub ( queued_at) ;
600+
601+ // Calculate total query time (end-to-end from client perspective)
602+ let total_elapsed = query_start_time. elapsed ( ) ;
603+ let total_ms = total_elapsed. as_millis ( ) ;
604+
605+ // Set timing metrics
606+ let metric_job_execution = MetricBuilder :: new ( & metrics)
607+ . gauge ( "job_execution_time_ms" , partition) ;
608+ metric_job_execution. set ( job_execution_ms as usize ) ;
609+
610+ let metric_scheduling =
611+ MetricBuilder :: new ( & metrics) . gauge ( "job_scheduling_in_ms" , partition) ;
612+ metric_scheduling. set ( scheduling_ms as usize ) ;
613+
614+ let metric_total_time =
615+ MetricBuilder :: new ( & metrics) . gauge ( "total_query_time_ms" , partition) ;
616+ metric_total_time. set ( total_ms as usize ) ;
617+
618+ // Note: data_transfer_time_ms is not set here because partition fetching
619+ // happens lazily when the stream is consumed, not during execute_query.
620+ // This could be added in a future enhancement by wrapping the stream.
621+
622+ let streams = partition_location. into_iter ( ) . map ( move |partition| {
623+ let f = fetch_partition (
624+ partition,
625+ max_message_size,
626+ true ,
627+ scheduler_url. clone ( ) ,
628+ flight_proxy. clone ( ) ,
629+ customize_endpoint. clone ( ) ,
630+ use_tls,
631+ )
632+ . map_err ( |e| ArrowError :: ExternalError ( Box :: new ( e) ) ) ;
633+
634+ futures:: stream:: once ( f) . try_flatten ( )
635+ } ) ;
636+
637+ break Ok ( futures:: stream:: iter ( streams) . flatten ( ) ) ;
638+ }
639+ } ;
640+ }
641+ }
456642
457643fn get_client_host_port (
458644 executor_metadata : & ExecutorMetadata ,
0 commit comments