@@ -2,7 +2,7 @@ use crate::config::processing_loop::ProcessingLoop;
22use crate :: sql:: { InlineTables , SqlQueryContext , SqlService } ;
33use crate :: table:: TableValue ;
44use crate :: util:: time_span:: warn_long;
5- use crate :: { metastore, CubeError } ;
5+ use crate :: { app_metrics , metastore, CubeError } ;
66use async_trait:: async_trait;
77use datafusion:: cube_ext;
88use hex:: ToHex ;
@@ -78,6 +78,9 @@ impl<W: io::Write + Send> AsyncMysqlShim<W> for Backend {
7878 }
7979 let _s = warn_long ( "sending query results" , Duration :: from_millis ( 100 ) ) ;
8080 let data_frame = res. unwrap ( ) ;
81+
82+ let data_frame_serialization_start_time = SystemTime :: now ( ) ;
83+
8184 let columns = data_frame
8285 . get_columns ( )
8386 . iter ( )
@@ -133,7 +136,15 @@ impl<W: io::Write + Send> AsyncMysqlShim<W> for Backend {
133136 rw. end_row ( ) ?;
134137 }
135138 rw. finish ( ) ?;
136- if start. elapsed ( ) . unwrap ( ) . as_millis ( ) > 200 && query. to_lowercase ( ) . starts_with ( "select" )
139+
140+ let end_time = SystemTime :: now ( ) ;
141+ app_metrics:: SQL_QUERY_DATA_FRAME_SERIALIZATION_TIME_US . report (
142+ end_time
143+ . duration_since ( data_frame_serialization_start_time) ?
144+ . as_micros ( ) as i64 ,
145+ ) ;
146+ if end_time. duration_since ( start) . unwrap ( ) . as_millis ( ) > 200
147+ && query. to_lowercase ( ) . starts_with ( "select" )
137148 {
138149 warn ! (
139150 "Slow Query SQL ({:?}):\n {}" ,
0 commit comments