Skip to content

Commit f58d8d3

Browse files
authored
CA-364194: use timespans for script timeouts (#6200)
This has two advantages: 1. Always non-negative: they represent absolute differences in time 2. Forces users to define the units of time, allowing to read the time in minutes, when appropriate Passed the toolstack's smoke and validation tests: Job 209833
2 parents d8ac4d9 + 87013f1 commit f58d8d3

File tree

14 files changed

+77
-51
lines changed

14 files changed

+77
-51
lines changed

ocaml/forkexecd/lib/dune

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -4,7 +4,9 @@
44
(wrapped false)
55
(libraries
66
astring
7+
clock
78
fd-send-recv
9+
mtime
810
rpclib.core
911
rpclib.json
1012
rpclib.xml

ocaml/forkexecd/lib/forkhelpers.ml

Lines changed: 12 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -315,8 +315,8 @@ let safe_close_and_exec ?tracing ?env stdin stdout stderr
315315
close_fds
316316

317317
let execute_command_get_output_inner ?tracing ?env ?stdin
318-
?(syslog_stdout = NoSyslogging) ?(redirect_stderr_to_stdout = false)
319-
?(timeout = -1.0) cmd args =
318+
?(syslog_stdout = NoSyslogging) ?(redirect_stderr_to_stdout = false) timeout
319+
cmd args =
320320
let to_close = ref [] in
321321
let close fd =
322322
if List.mem fd !to_close then (
@@ -354,8 +354,13 @@ let execute_command_get_output_inner ?tracing ?env ?stdin
354354
close wr
355355
)
356356
stdinandpipes ;
357-
if timeout > 0. then
358-
Unix.setsockopt_float sock Unix.SO_RCVTIMEO timeout ;
357+
( match timeout with
358+
| Some span ->
359+
let timeout = Clock.Timer.span_to_s span in
360+
Unix.setsockopt_float sock Unix.SO_RCVTIMEO timeout
361+
| None ->
362+
()
363+
) ;
359364
with_tracing ~tracing ~name:"Forkhelpers.waitpid" @@ fun _ ->
360365
try waitpid (sock, pid)
361366
with Unix.(Unix_error ((EAGAIN | EWOULDBLOCK), _, _)) ->
@@ -380,12 +385,12 @@ let execute_command_get_output_inner ?tracing ?env ?stdin
380385
let execute_command_get_output ?tracing ?env ?(syslog_stdout = NoSyslogging)
381386
?(redirect_stderr_to_stdout = false) ?timeout cmd args =
382387
with_tracing ~tracing ~name:__FUNCTION__ @@ fun tracing ->
383-
execute_command_get_output_inner ?tracing ?env ?stdin:None ?timeout
384-
~syslog_stdout ~redirect_stderr_to_stdout cmd args
388+
execute_command_get_output_inner ?tracing ?env ?stdin:None ~syslog_stdout
389+
~redirect_stderr_to_stdout timeout cmd args
385390

386391
let execute_command_get_output_send_stdin ?tracing ?env
387392
?(syslog_stdout = NoSyslogging) ?(redirect_stderr_to_stdout = false)
388393
?timeout cmd args stdin =
389394
with_tracing ~tracing ~name:__FUNCTION__ @@ fun tracing ->
390395
execute_command_get_output_inner ?tracing ?env ~stdin ~syslog_stdout
391-
~redirect_stderr_to_stdout ?timeout cmd args
396+
~redirect_stderr_to_stdout timeout cmd args

ocaml/forkexecd/lib/forkhelpers.mli

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -48,7 +48,7 @@ val execute_command_get_output :
4848
-> ?env:string array
4949
-> ?syslog_stdout:syslog_stdout
5050
-> ?redirect_stderr_to_stdout:bool
51-
-> ?timeout:float
51+
-> ?timeout:Mtime.Span.t
5252
-> string
5353
-> string list
5454
-> string * string
@@ -61,7 +61,7 @@ val execute_command_get_output_send_stdin :
6161
-> ?env:string array
6262
-> ?syslog_stdout:syslog_stdout
6363
-> ?redirect_stderr_to_stdout:bool
64-
-> ?timeout:float
64+
-> ?timeout:Mtime.Span.t
6565
-> string
6666
-> string list
6767
-> string

ocaml/forkexecd/test/dune

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,7 +1,7 @@
11
(executable
22
(modes exe)
33
(name fe_test)
4-
(libraries forkexec uuid xapi-stdext-unix fd-send-recv))
4+
(libraries fmt forkexec mtime clock mtime.clock.os uuid xapi-stdext-unix fd-send-recv))
55

66
(rule
77
(alias runtest)

ocaml/forkexecd/test/fe_test.ml

Lines changed: 26 additions & 18 deletions
Original file line numberDiff line numberDiff line change
@@ -115,12 +115,6 @@ let one fds x =
115115
:: string_of_int (fds - (x.max_extra - number_of_extra))
116116
:: shuffle cmdline_names
117117
in
118-
(* Printf.fprintf stderr "stdin = %s\n" (if x.stdin then "Some" else "None");
119-
Printf.fprintf stderr "stdout = %s\n" (if x.stdout then "Some" else "None");
120-
Printf.fprintf stderr "stderr = %s\n" (if x.stderr then "Some" else "None");
121-
List.iter (fun (uuid, _) -> Printf.fprintf stderr "uuid %s -> stdin\n" uuid) table;
122-
Printf.fprintf stderr "%s %s\n" exe (String.concat " " args);
123-
*)
124118
Forkhelpers.waitpid_fail_if_bad_exit
125119
(Forkhelpers.safe_close_and_exec
126120
(if x.stdin then Some fd else None)
@@ -129,26 +123,43 @@ let one fds x =
129123
table exe args
130124
)
131125

126+
type in_range = In_range | Longer | Shorter
127+
128+
let in_range ~e:leeway ~around span =
129+
let upper = Mtime.Span.add around leeway in
130+
if Clock.Timer.span_is_shorter ~than:around span then
131+
Shorter
132+
else if Clock.Timer.span_is_longer ~than:upper span then
133+
Longer
134+
else
135+
In_range
136+
132137
let test_delay () =
133-
let start = Unix.gettimeofday () in
138+
let start = Mtime_clock.counter () in
134139
let args = ["sleep"] in
135140
(* Need to have fractional part because some internal usage split integer
136141
and fractional and do computation.
137142
Better to have a high fractional part (> 0.5) to more probably exceed
138143
the unit.
139144
*)
140-
let timeout = 1.7 in
145+
let timeout = Mtime.Span.(1700 * ms) in
141146
try
142147
Forkhelpers.execute_command_get_output ~timeout exe args |> ignore ;
143148
fail "Failed to timeout"
144149
with
145-
| Forkhelpers.Subprocess_timeout ->
146-
let elapsed = Unix.gettimeofday () -. start in
147-
Printf.printf "Caught timeout exception after %f seconds\n%!" elapsed ;
148-
if elapsed < timeout then
149-
failwith "Process exited too soon" ;
150-
if elapsed > timeout +. 0.2 then
151-
failwith "Excessive time elapsed"
150+
| Forkhelpers.Subprocess_timeout -> (
151+
let elapsed = Mtime_clock.count start in
152+
Printf.printf "Caught timeout exception after %s seconds\n%!"
153+
Fmt.(to_to_string Mtime.Span.pp elapsed) ;
154+
155+
match in_range ~e:Mtime.Span.(200 * ms) ~around:timeout elapsed with
156+
| In_range ->
157+
()
158+
| Shorter ->
159+
failwith "Process exited too soon"
160+
| Longer ->
161+
failwith "Process took too long to exit"
162+
)
152163
| e ->
153164
fail "Failed with unexpected exception: %s" (Printexc.to_string e)
154165

@@ -289,9 +300,6 @@ let slave = function
289300
)
290301
fds ;
291302
(* Check that we have the expected number *)
292-
(*
293-
Printf.fprintf stderr "%s %d\n" total_fds (List.length present - 1)
294-
*)
295303
if total_fds <> List.length filtered then
296304
fail "Expected %d fds; /proc/self/fd has %d: %s" total_fds
297305
(List.length filtered) ls

ocaml/networkd/bin/dune

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -14,10 +14,11 @@
1414
(modes exe)
1515
(libraries
1616
astring
17-
17+
clock
1818
forkexec
1919
http_lib
2020
integers
21+
mtime
2122
netlink
2223
networklibs
2324
rpclib.core

ocaml/networkd/bin/networkd.ml

Lines changed: 8 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -105,8 +105,14 @@ let options =
105105
, "Path to the Unix command dracut"
106106
)
107107
; ( "dracut-timeout"
108-
, Arg.Set_float Network_utils.dracut_timeout
109-
, (fun () -> string_of_float !Network_utils.dracut_timeout)
108+
, Arg.Float
109+
(fun x ->
110+
let x = Float.to_int (x *. 1000.) in
111+
Network_utils.dracut_timeout := Mtime.Span.(x * ms)
112+
)
113+
, (fun () ->
114+
Float.to_string (Clock.Timer.span_to_s !Network_utils.dracut_timeout)
115+
)
110116
, "Default value for the dracut command timeout"
111117
)
112118
; ( "modinfo-cmd-path"

ocaml/networkd/lib/network_utils.ml

Lines changed: 5 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -67,7 +67,7 @@ let dracut = ref "/sbin/dracut"
6767

6868
let modinfo = ref "/sbin/modinfo"
6969

70-
let dracut_timeout = ref 180.0
70+
let dracut_timeout = ref Mtime.Span.(3 * min)
7171

7272
let fcoedriver = ref "/opt/xensource/libexec/fcoe_driver"
7373

@@ -128,7 +128,8 @@ let check_n_run ?(on_error = default_error_handler) ?(log = true) run_func
128128
| Forkhelpers.Spawn_internal_error (stderr, stdout, status) ->
129129
on_error script args stdout stderr status
130130

131-
let call_script ?(timeout = Some 60.0) ?on_error ?log script args =
131+
let call_script ?(timeout = Some Mtime.Span.(1 * min)) ?on_error ?log script
132+
args =
132133
let call_script_internal env script args =
133134
let out, _err =
134135
Forkhelpers.execute_command_get_output ~env ?timeout script args
@@ -1064,7 +1065,8 @@ end = struct
10641065
end
10651066

10661067
module Fcoe = struct
1067-
let call ?log args = call_script ?log ~timeout:(Some 10.0) !fcoedriver args
1068+
let call ?log args =
1069+
call_script ?log ~timeout:(Some Mtime.Span.(10 * s)) !fcoedriver args
10681070

10691071
let get_capabilities name =
10701072
match Sys.file_exists !fcoedriver with

ocaml/xapi/helpers.ml

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -71,7 +71,7 @@ let call_script ?(log_output = Always) ?env ?stdin ?timeout script args =
7171
| None ->
7272
"without a timeout"
7373
| Some t ->
74-
Printf.sprintf "with a timeout of %.3f seconds" t
74+
Fmt.str "with a timeout of %a" Mtime.Span.pp t
7575
in
7676
debug "about to call script %s: %s %s" timeout_msg script
7777
(String.concat " " (filter_args args)) ;

ocaml/xapi/static_vdis.ml

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -37,7 +37,9 @@ let permanent_vdi_attach ~__context ~vdi ~reason =
3737
)
3838
) ;
3939
ignore
40-
(Helpers.call_script ~timeout:60.0 !Xapi_globs.static_vdis
40+
(Helpers.call_script
41+
~timeout:Mtime.Span.(1 * min)
42+
!Xapi_globs.static_vdis
4143
["add"; Db.VDI.get_uuid ~__context ~self:vdi; reason]
4244
) ;
4345
(* VDI will be attached on next boot; attach it now too *)

ocaml/xapi/xapi_globs.ml

Lines changed: 8 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -994,7 +994,7 @@ let winbind_allow_kerberos_auth_fallback = ref false
994994

995995
let winbind_keep_configuration = ref false
996996

997-
let winbind_ldap_query_subject_timeout = ref 20.
997+
let winbind_ldap_query_subject_timeout = ref Mtime.Span.(20 * s)
998998

999999
let tdb_tool = ref "/usr/bin/tdbtool"
10001000

@@ -1146,7 +1146,13 @@ let xapi_globs_spec =
11461146
; ("local_yum_repo_port", Int local_yum_repo_port)
11471147
]
11481148

1149-
let xapi_globs_spec_with_descriptions = []
1149+
let xapi_globs_spec_with_descriptions =
1150+
[
1151+
( "winbind_ldap_query_subject_timeout"
1152+
, ShortDurationFromSeconds winbind_ldap_query_subject_timeout
1153+
, "Timeout to perform ldap query for subject information"
1154+
)
1155+
]
11501156

11511157
let option_of_xapi_globs_spec ?(description = None) (name, ty) =
11521158
let spec =
@@ -1467,11 +1473,6 @@ let other_options =
14671473
, "Whether to clear winbind configuration when join domain failed or leave \
14681474
domain"
14691475
)
1470-
; ( "winbind_ldap_query_subject_timeout"
1471-
, Arg.Set_float winbind_ldap_query_subject_timeout
1472-
, (fun () -> string_of_float !winbind_ldap_query_subject_timeout)
1473-
, "Timeout to perform ldap query for subject information"
1474-
)
14751476
; ( "hsts_max_age"
14761477
, Arg.Set_int hsts_max_age
14771478
, (fun () -> string_of_int !hsts_max_age)

ocaml/xenopsd/lib/dune

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -9,6 +9,7 @@
99
fd-send-recv
1010
fmt
1111
forkexec
12+
mtime
1213
re
1314
gzip
1415
zstd

ocaml/xenopsd/lib/xenopsd.ml

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -37,7 +37,7 @@ let vgpu_ready_timeout = ref 30.
3737

3838
let varstored_ready_timeout = ref 30.
3939

40-
let swtpm_ready_timeout = ref 60
40+
let swtpm_ready_timeout = ref Mtime.Span.(1 * min)
4141

4242
let use_upstream_qemu = ref false
4343

ocaml/xenopsd/xc/service.ml

Lines changed: 5 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -40,7 +40,7 @@ type t = {
4040
; exec_path: string
4141
; pid_filename: string
4242
; chroot: Chroot.t
43-
; timeout_seconds: int
43+
; timeout: Mtime.Span.t
4444
; args: string list
4545
; execute:
4646
path:string -> args:string list -> domid:Xenctrl.domid -> unit -> string
@@ -180,7 +180,7 @@ let start_and_wait_for_readyness ~task ~service =
180180

181181
Xenops_task.check_cancelling task ;
182182

183-
let amount = Mtime.Span.(service.timeout_seconds * s) in
183+
let amount = service.timeout in
184184
(* wait for pidfile to appear *)
185185
Result.iter_error raise_e (wait ~amount ~service_name:syslog_key) ;
186186

@@ -797,16 +797,14 @@ module Swtpm = struct
797797
swtpm-wrapper runs as a service and getting the exact error back is
798798
difficult. *)
799799
let needs_init = check_state_needs_init task vtpm_uuid in
800-
let timeout_seconds = !Xenopsd.swtpm_ready_timeout in
800+
let timeout = !Xenopsd.swtpm_ready_timeout in
801801
if needs_init then (
802802
debug "vTPM %s is empty, needs to be created" (Uuidm.to_string vtpm_uuid) ;
803803
let key = Printf.sprintf "%s-%d" (Filename.basename exec_path) domid in
804804
let _, _ =
805805
Forkhelpers.execute_command_get_output
806806
~syslog_stdout:(Forkhelpers.Syslog_WithKey key)
807-
~redirect_stderr_to_stdout:true
808-
~timeout:(float_of_int timeout_seconds)
809-
exec_path (args true)
807+
~redirect_stderr_to_stdout:true ~timeout exec_path (args true)
810808
in
811809
let state_file = Filename.concat tpm_root "tpm2-00.permall" in
812810
let state = Unixext.string_of_file state_file |> Base64.encode_exn in
@@ -825,7 +823,7 @@ module Swtpm = struct
825823
; chroot
826824
; args= args false
827825
; execute
828-
; timeout_seconds
826+
; timeout
829827
}
830828
in
831829

0 commit comments

Comments
 (0)