[scheduler] Add wall time to ExecutionDuration

Summary: Add the wall time to the ExecutionDuration. If this is not included we are not considering off-cpu time.

Reviewed By: ngorogiannis

Differential Revision: D20099667

fbshipit-source-id: 49dbfd739

infer/src/backend/BackendStats.ml

@@ -195,7 +195,10 @@ let log_to_scuba stats =
         ~duration_ms:(ExecutionDuration.sys_time field_value |> secs_to_ms)
     ; LogEntry.mk_time
         ~label:("backend_stats." ^ Field.name field ^ "_user")
-        ~duration_ms:(ExecutionDuration.user_time field_value |> secs_to_ms) ]
+        ~duration_ms:(ExecutionDuration.user_time field_value |> secs_to_ms)
+    ; LogEntry.mk_time
+        ~label:("backend_stats." ^ Field.name field ^ "_wall")
+        ~duration_ms:(ExecutionDuration.wall_time field_value |> secs_to_ms) ]
   in
   let entries =
     Fields.to_list ~summary_file_try_load:create_counter ~summary_read_from_disk:create_counter

infer/src/backend/ExecutionDuration.ml

@@ -30,34 +30,43 @@ module Duration = struct
   let secs d = d.time +. d.comp
 end
 
-type t = {utime: Duration.t; stime: Duration.t}
+type t = {user: Duration.t; sys: Duration.t; wall: Mtime.Span.t}
+
+type counter = {process_times: Unix.process_times; wall_time: Mtime_clock.counter}
 
 type 'a evaluation_result = {result: 'a; execution_duration: t}
 
-let zero = {utime= Duration.zero; stime= Duration.zero}
+let zero = {user= Duration.zero; sys= Duration.zero; wall= Mtime.Span.zero}
 
-let since (from : Unix.process_times) =
+let since {process_times; wall_time} =
   let now = Unix.times () in
-  { utime= Duration.since from.tms_utime ~now:now.tms_utime
-  ; stime= Duration.since from.tms_stime ~now:now.tms_stime }
+  { user= Duration.since process_times.tms_utime ~now:now.tms_utime
+  ; sys= Duration.since process_times.tms_stime ~now:now.tms_stime
+  ; wall= Mtime_clock.count wall_time }
 
 
 let add exe_d1 exe_d2 =
-  {utime= Duration.add exe_d1.utime exe_d2.utime; stime= Duration.add exe_d1.stime exe_d2.stime}
+  { user= Duration.add exe_d1.user exe_d2.user
+  ; sys= Duration.add exe_d1.sys exe_d2.sys
+  ; wall= Mtime.Span.add exe_d1.wall exe_d2.wall }
+
 
+let add_duration_since exe_duration from = add exe_duration (since from)
 
-let add_duration_since exe_duration (from : Unix.process_times) = add exe_duration (since from)
+let user_time exe_duration = Duration.secs exe_duration.user
 
-let user_time exe_duration = Duration.secs exe_duration.utime
+let sys_time exe_duration = Duration.secs exe_duration.sys
 
-let sys_time exe_duration = Duration.secs exe_duration.stime
+let wall_time exe_duration = Mtime.Span.to_s exe_duration.wall
 
 let pp ~field fmt exe_duration =
-  F.fprintf fmt "%s_utime= %.8f@;%s_stime= %.8f" field (user_time exe_duration) field
-    (sys_time exe_duration)
+  F.fprintf fmt "%s_user= %.8f@;%s_sys= %.8f@;%s_wall= %.8f" field (user_time exe_duration) field
+    (sys_time exe_duration) field (wall_time exe_duration)
+
 
+let counter () = {process_times= Unix.times (); wall_time= Mtime_clock.counter ()}
 
 let timed_evaluate ~f =
-  let start_time = Unix.times () in
+  let start = counter () in
   let result = f () in
-  {result; execution_duration= since start_time}
+  {result; execution_duration= since start}

infer/src/backend/ExecutionDuration.mli

@@ -9,13 +9,17 @@ open! IStd
 
 type t
 
+type counter
+
 type 'a evaluation_result = {result: 'a; execution_duration: t}
 
 val zero : t
 
-val since : Unix.process_times -> t
+val counter : unit -> counter
+
+val since : counter -> t
 
-val add_duration_since : t -> Unix.process_times -> t
+val add_duration_since : t -> counter -> t
 
 val add : t -> t -> t
 
@@ -23,6 +27,8 @@ val user_time : t -> float
 
 val sys_time : t -> float
 
+val wall_time : t -> float
+
 val pp : field:string -> Format.formatter -> t -> unit
 
 val timed_evaluate : f:(unit -> 'a) -> 'a evaluation_result

infer/src/backend/RestartScheduler.ml

@@ -54,15 +54,16 @@ let if_restart_scheduler f =
 
 
 type locked_proc =
-  {pname: Procname.t; start: Unix.process_times; mutable callees_useful: ExecutionDuration.t}
+  {pname: Procname.t; start: ExecutionDuration.counter; mutable callees_useful: ExecutionDuration.t}
 
 let locked_procs = Stack.create ()
 
 let record_locked_proc (pname : Procname.t) =
-  Stack.push locked_procs {pname; start= Unix.times (); callees_useful= ExecutionDuration.zero}
+  Stack.push locked_procs
+    {pname; start= ExecutionDuration.counter (); callees_useful= ExecutionDuration.zero}
 
 
-let add_to_useful_time (from : Unix.process_times) =
+let add_to_useful_time from =
   BackendStats.add_to_restart_scheduler_useful_time (ExecutionDuration.since from)
 
 
@@ -70,7 +71,7 @@ let add_to_useful_exe_duration exe_duration =
   BackendStats.add_to_restart_scheduler_useful_time exe_duration
 
 
-let add_to_total_time (from : Unix.process_times) =
+let add_to_total_time from =
   BackendStats.add_to_restart_scheduler_total_time (ExecutionDuration.since from)