diff --git a/infer/man/man1/infer-full.txt b/infer/man/man1/infer-full.txt index de82b25cb..fffc4ea98 100644 --- a/infer/man/man1/infer-full.txt +++ b/infer/man/man1/infer-full.txt @@ -1568,6 +1568,10 @@ INTERNAL OPTIONS Reset the list of folders containing linters definitions to be empty (see linters-def-folder). + --scuba-logging + Activates: (direct) logging to scuba (Conversely: + --no-scuba-logging) + --seconds-per-iteration float Set the number of seconds per iteration (see --iterations) diff --git a/infer/src/backend/InferAnalyze.ml b/infer/src/backend/InferAnalyze.ml index c92af5e61..1e3ec1512 100644 --- a/infer/src/backend/InferAnalyze.ml +++ b/infer/src/backend/InferAnalyze.ml @@ -85,6 +85,7 @@ let main ~changed_files = if result then incr n_source_files_to_analyze ; result in + ScubaEventLogging.log_count ~name:"source_files_to_analyze" ~value:!n_source_files_to_analyze ; let source_files_to_analyze = SourceFiles.get_all ~filter () in L.progress "Found %d%s source file%s to analyze in %s@." !n_source_files_to_analyze ( if Config.reactive_mode || Option.is_some changed_files then diff --git a/infer/src/base/Config.ml b/infer/src/base/Config.ml index 438f6bba6..73b370758 100644 --- a/infer/src/base/Config.ml +++ b/infer/src/base/Config.ml @@ -2012,6 +2012,8 @@ and select = "Select bug number $(i,N). If omitted, prompt for input." +and scuba_logging = CLOpt.mk_bool ~long:"scuba-logging" "(direct) logging to scuba " + and siof_safe_methods = CLOpt.mk_string_list ~long:"siof-safe-methods" ~in_help:InferCommand.[(Analyze, manual_siof)] @@ -2988,6 +2990,8 @@ and seconds_per_iteration = !seconds_per_iteration and select = !select +and scuba_logging = !scuba_logging + and show_buckets = !print_buckets and siof = !siof diff --git a/infer/src/base/Config.mli b/infer/src/base/Config.mli index 12b154e33..836a9258b 100644 --- a/infer/src/base/Config.mli +++ b/infer/src/base/Config.mli @@ -598,6 +598,8 @@ val rest : string list val results_dir : string +val scuba_logging : bool + val seconds_per_iteration : float option val select : int option diff --git a/infer/src/deadcode/Makefile b/infer/src/deadcode/Makefile index 44fd6cd14..ce7c54b19 100644 --- a/infer/src/deadcode/Makefile +++ b/infer/src/deadcode/Makefile @@ -46,7 +46,7 @@ depend: ocamldep -native \ -I IR -I absint -I atd -I backend -I base -I biabduction -I bufferoverrun -I checkers \ -I clang -I concurrency -I facebook -I integration -I istd -I java \ - -I labs -I nullsafe -I pulse -I quandary -I topl -I unit -I unit/clang -I deadcode \ + -I labs -I nullsafe -I pulse -I scuba -I quandary -I topl -I unit -I unit/clang -I deadcode \ $(ml_src_files) > deadcode/.depend # circular dependency... not sure how to fix properly diff --git a/infer/src/dune.in b/infer/src/dune.in index 2ec802c3a..dc6b26133 100644 --- a/infer/src/dune.in +++ b/infer/src/dune.in @@ -24,6 +24,7 @@ let source_dirs = ; "nullsafe" ; "pulse" ; "quandary" + ; "scuba" ; "topl" ; "unit" ] ) diff --git a/infer/src/infer.ml b/infer/src/infer.ml index a83e97ceb..b91e7cccb 100644 --- a/infer/src/infer.ml +++ b/infer/src/infer.ml @@ -22,6 +22,8 @@ let run driver_mode = run_epilogue () +let run driver_mode = ScubaEventLogging.execute_with_time_logging "run" (fun () -> run driver_mode) + let setup () = ( match Config.command with | Analyze -> diff --git a/infer/src/integration/Driver.ml b/infer/src/integration/Driver.ml index 527f70260..292adad7e 100644 --- a/infer/src/integration/Driver.ml +++ b/infer/src/integration/Driver.ml @@ -305,6 +305,10 @@ let capture ~changed_files mode = PerfEvent.(log (fun logger -> log_end_event logger ())) +let capture ~changed_files mode = + ScubaEventLogging.execute_with_time_logging "capture" (fun () -> capture ~changed_files mode) + + let execute_analyze ~changed_files = register_perf_stats_report PerfStats.TotalBackend ; InferAnalyze.main ~changed_files ; @@ -407,6 +411,11 @@ let analyze_and_report ?suppress_console_report ~changed_files mode = if should_report && Config.report then report ?suppress_console:suppress_console_report () +let analyze_and_report ?suppress_console_report ~changed_files mode = + ScubaEventLogging.execute_with_time_logging "analyze_and_report" (fun () -> + analyze_and_report ?suppress_console_report ~changed_files mode ) + + (** as the Config.fail_on_bug flag mandates, exit with error when an issue is reported *) let fail_on_issue_epilogue () = let issues_json = @@ -549,6 +558,10 @@ let run_prologue mode = () +let run_prologue mode = + ScubaEventLogging.execute_with_time_logging "run_prologue" (fun () -> run_prologue mode) + + let run_epilogue () = if CLOpt.is_originator then ( if Config.developer_mode then StatsAggregator.generate_files () ; @@ -558,6 +571,8 @@ let run_epilogue () = () +let run_epilogue () = ScubaEventLogging.execute_with_time_logging "run_epilogue" run_epilogue + let read_config_changed_files () = match Config.changed_files_index with | None -> diff --git a/infer/src/opensource/Scribe.ml b/infer/src/opensource/Scribe.ml new file mode 100644 index 000000000..b03a0a646 --- /dev/null +++ b/infer/src/opensource/Scribe.ml @@ -0,0 +1,12 @@ +(* + * Copyright (c) 2019-present, Facebook, Inc. + * + * This source code is licensed under the MIT license found in the + * LICENSE file in the root directory of this source tree. + *) + +open! IStd + +type category = InferEvents + +let log _ _ = () diff --git a/infer/src/opensource/Scribe.mli b/infer/src/opensource/Scribe.mli new file mode 100644 index 000000000..2087dff1c --- /dev/null +++ b/infer/src/opensource/Scribe.mli @@ -0,0 +1,12 @@ +(* + * Copyright (c) 2019-present, Facebook, Inc. + * + * This source code is licensed under the MIT license found in the + * LICENSE file in the root directory of this source tree. + *) + +open! IStd + +type category = InferEvents + +val log : category -> string list -> unit diff --git a/infer/src/scuba/Scuba.ml b/infer/src/scuba/Scuba.ml new file mode 100644 index 000000000..d1994a820 --- /dev/null +++ b/infer/src/scuba/Scuba.ml @@ -0,0 +1,59 @@ +(* + * Copyright (c) 2019-present, Facebook, Inc. + * + * This source code is licensed under the MIT license found in the + * LICENSE file in the root directory of this source tree. + *) + +(* FB-ONLY *) + +open! IStd +module SMap = Map.Make (String) + +type table = InferEvents + +type sample = + { int_section: int SMap.t (** All integer type fields and their values *) + ; normal_section: string SMap.t + (** All string (normal in Scuba terminology) type fields and their values *) } + +let new_sample ~time = + let time = match time with Some time -> time | None -> int_of_float (Unix.time ()) in + { (* time is a single mandatory field in scuba. without it, + scuba disregards all samples *) + int_section= SMap.singleton "time" time + ; normal_section= SMap.empty } + + +let add_int ~name ~value sample = + let int_section = SMap.set sample.int_section ~key:name ~data:value in + {sample with int_section} + + +let add_normal ~name ~value sample = + let normal_section = SMap.set sample.normal_section ~key:name ~data:value in + {sample with normal_section} + + +let sample_to_json sample = + let map_to_assoc value_to_json key_value_map = + let pairs = SMap.to_alist key_value_map in + let assocs = List.map pairs ~f:(fun (name, data) -> (name, value_to_json data)) in + `Assoc assocs + in + let ints_to_assoc = map_to_assoc (fun data -> `Int data) in + let normals_to_assoc = map_to_assoc (fun data -> `String data) in + `Assoc + [("int", ints_to_assoc sample.int_section); ("normal", normals_to_assoc sample.normal_section)] + + +let sample_to_json_string sample = sample |> sample_to_json |> Yojson.Basic.to_string + +let table_to_scribe_category = function InferEvents -> Scribe.InferEvents + +let log table samples = + let category = table_to_scribe_category table in + Scribe.log category (List.map samples ~f:sample_to_json_string) + + +let log = if Config.scuba_logging then log else fun _ _ -> () diff --git a/infer/src/scuba/Scuba.mli b/infer/src/scuba/Scuba.mli new file mode 100644 index 000000000..551acc558 --- /dev/null +++ b/infer/src/scuba/Scuba.mli @@ -0,0 +1,45 @@ +(* + * Copyright (c) 2019-present, Facebook, Inc. + * + * This source code is licensed under the MIT license found in the + * LICENSE file in the root directory of this source tree. + *) + +open! IStd + +(* FB-ONLY *) + +(** + Low-level Scuba logging functionality. + Provides functionality to log anything to any scuba table. + (Note that Scuba is a schema-free storage, so it won't require any changes). + Don't use this module directly for logging to tables with known structure. + Use high-level functions that are aware of the table structure. + *) + +(** A scuba table *) +type table = InferEvents + +(** A sample to be added to Scuba *) +type sample + +val new_sample : time:int option -> sample +(** Create an empty sample with given creation timestamp. If time is not specified, + corresponds to current timestamp. *) + +val add_int : name:string -> value:int -> sample -> sample +(** + Set a new integer field and its value to the sample. + Overwrites if a field with this name was already set. + *) + +val add_normal : name:string -> value:string -> sample -> sample +(** + Set a new string (normal in Scuba terminology) field and its value to the sample. + Overwrites if a field with this name was already set. + *) + +val log : table -> sample list -> unit +(** + The main function. Log a collection of samples to the given table. + *) diff --git a/infer/src/scuba/ScubaEventLogging.ml b/infer/src/scuba/ScubaEventLogging.ml new file mode 100644 index 000000000..d751f28e1 --- /dev/null +++ b/infer/src/scuba/ScubaEventLogging.ml @@ -0,0 +1,59 @@ +(* + * Copyright (c) 2019-present, Facebook, Inc. + * + * This source code is licensed under the MIT license found in the + * LICENSE file in the root directory of this source tree. + *) +(* FB-ONLY *) + +(* + * Utilities to log in "infer_events" key-value scuba table. + *) +open! IStd + +let hostname = Unix.gethostname () + +let maybe_add_normal ~name ~value sample = + match value with None -> sample | Some value -> Scuba.add_normal ~name ~value sample + + +let set_common_fields sample = + let open Scuba in + sample + |> add_int ~name:"pid" ~value:(ProcessPoolState.get_pid () |> Pid.to_int) + |> add_int ~name:"is_main_process" ~value:(Bool.to_int CommandLineOption.is_originator) + |> add_normal ~name:"hostname" ~value:hostname + |> maybe_add_normal ~name:"job_id" ~value:Config.job_id + |> add_normal ~name:"command" ~value:(InferCommand.to_string Config.command) + |> add_normal ~name:"infer_commit" ~value:Version.commit + + +let create_sample ~event_name ~value = + Scuba.new_sample ~time:None |> set_common_fields + |> Scuba.add_normal ~name:"event" ~value:event_name + |> Scuba.add_int ~name:"value" ~value + + +type event_type = Count | Time + +let string_of_event_type = function Count -> "count" | Time -> "time" + +let log event_type ~event_suffix ~value = + let event_name = string_of_event_type event_type ^ "." ^ event_suffix in + let sample = create_sample ~event_name ~value in + Scuba.log Scuba.InferEvents [sample] + + +(* If scuba logging is disabled, we would not log anyway, but let's not even try + to create samples to save perf *) +let log = if Config.scuba_logging then log else fun _ ~event_suffix:_ ~value:_ -> () + +let log_count ~name ~value = log Count ~event_suffix:name ~value + +let log_time ~name ~duration_ms = log Time ~event_suffix:name ~value:duration_ms + +let execute_with_time_logging name f = + let start_time = Mtime_clock.counter () in + let ret_val = f () in + let duration_ms = Mtime_clock.count start_time |> Mtime.Span.to_ms |> int_of_float in + log_time ~name ~duration_ms ; ret_val diff --git a/infer/src/scuba/ScubaEventLogging.mli b/infer/src/scuba/ScubaEventLogging.mli new file mode 100644 index 000000000..1fe894640 --- /dev/null +++ b/infer/src/scuba/ScubaEventLogging.mli @@ -0,0 +1,32 @@ +(* + * Copyright (c) 2019-present, Facebook, Inc. + * + * This source code is licensed under the MIT license found in the + * LICENSE file in the root directory of this source tree. + *) + +open! IStd + +(* FB-ONLY *) + +(** + Functionality for logging into "infer_events" Scuba table. + The table is organized in form of key-value pairs. + Two most important fields are "event" and "value". + Other fields in the table correspond to things common for this particular + run of Infer. + *) + +val log_count : name:string -> value:int -> unit +(** Log anything that can be counted. Events will be prefixed with "count." *) + +val execute_with_time_logging : string -> (unit -> 'a) -> 'a +(** + A helper to log execution time of a particular function. + Use this to measure a performance of a given function. + Example: + {| + let f a b = + let f a b = ScubaEventLogging.execute_with_time_logging "f" (fun () -> f a b) + |} + *)