Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

trying to add logging for OCaml RPC calls #10196

Closed
wants to merge 1 commit into from
Closed

trying to add logging for OCaml RPC calls #10196

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
1 change: 1 addition & 0 deletions cli/src/semgrep/ocaml.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -93,6 +93,7 @@ def _parse_function_return(packet: str) -> Optional[out.FunctionReturn]:

def _call(call: out.FunctionCall, cls: Type[T]) -> Optional[T]:
semgrep_core_path = SemgrepCore.executable_path()
logger.debug(f"calling OCaml via rpc")
with subprocess.Popen(
[semgrep_core_path, "-rpc"],
stdin=subprocess.PIPE,
Expand Down
59 changes: 27 additions & 32 deletions src/core_scan/Core_scan.ml
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -22,7 +22,9 @@ module RP = Core_result
module In = Input_to_core_j
module OutJ = Semgrep_output_v1_j

let tags = Logs_.create_tags [ __MODULE__ ]
let src = Logs.Src.create "semgrep.core_scan"

module Log = (val Logs.src_log src : Logs.LOG)

(*****************************************************************************)
(* Purpose *)
Expand Down Expand Up @@ -457,8 +459,8 @@ let filter_files_with_too_many_matches_and_transform_as_timeout
offending_file_list
|> List_.map (fun file ->
(* logging useful info for rule writers *)
Logs.debug (fun m ->
m ~tags "too many matches on %s, generating exn for it" file);
Log.warn (fun m ->
m "too many matches on %s, generating exn for it" file);
let sorted_offending_rules =
let matches = List.assoc file per_files in
matches
Expand All @@ -479,9 +481,8 @@ let filter_files_with_too_many_matches_and_transform_as_timeout
| _ -> assert false
in
let (id, pat), cnt = biggest_offending_rule in
Logs.debug (fun m ->
m ~tags
"most offending rule: id = %s, matches = %d, pattern = %s"
Log.warn (fun m ->
m "most offending rule: id = %s, matches = %d, pattern = %s"
(Rule_ID.to_string id) cnt pat);

(* todo: we should maybe use a new error: TooManyMatches of int * string*)
Expand Down Expand Up @@ -566,8 +567,7 @@ let rules_from_rule_source (caps : < Cap.tmp >) (config : Core_scan_config.t) :
in
match rule_source with
| Some (Core_scan_config.Rule_file file) ->
Logs.debug (fun m ->
m ~tags "%s" (spf "Parsing %s:\n%s" !!file (UFile.read_file file)));
Log.debug (fun m -> m "Parsing %s:\n%s" !!file (UFile.read_file file));
Parse_rule.parse_and_filter_invalid_rules ~rewrite_rule_ids:None file
| Some (Core_scan_config.Rules rules) -> (rules, [])
| None ->
Expand Down Expand Up @@ -608,8 +608,8 @@ let iter_targets_and_get_matches_and_exn_to_errors (config : Core_scan_config.t)
|> map_targets config.ncores (fun (target : Target.t) ->
let internal_path = Target.internal_path target in
let origin = Target.origin target in
Logs.debug (fun m ->
m ~tags "Analyzing %s (contents in %s)" (Origin.to_string origin)
Log.info (fun m ->
m "Analyzing %s (contents in %s)" (Origin.to_string origin)
!!internal_path);
let (res, was_scanned), run_time =
Common.with_time (fun () ->
Expand Down Expand Up @@ -648,8 +648,8 @@ let iter_targets_and_get_matches_and_exn_to_errors (config : Core_scan_config.t)
* not testing -max_memory.
*)
if config.test then Gc.full_major ();
Logs.debug (fun m ->
m ~tags "done with %s (contents in %s)"
Log.info (fun m ->
m "done with %s (contents in %s)"
(Origin.to_string origin) !!internal_path);

(res, was_scanned))
Expand All @@ -665,18 +665,17 @@ let iter_targets_and_get_matches_and_exn_to_errors (config : Core_scan_config.t)
(match !Match_patterns.last_matched_rule with
| None -> ()
| Some rule ->
Logs.debug (fun m ->
m ~tags "critical exn while matching ruleid %s"
Log.warn (fun m ->
m "critical exn while matching ruleid %s"
(Rule_ID.to_string rule.id);
Logs.debug (fun m ->
m ~tags "full pattern is: %s"
rule.MR.pattern_string)));
Log.debug (fun m ->
m "full pattern is: %s" rule.MR.pattern_string)));
let loc = Tok.first_loc_of_file !!internal_path in
let errors =
match exn with
| Match_rules.File_timeout rule_ids ->
Logs.debug (fun m ->
m ~tags "Timeout on %s (contents in %s)"
Log.warn (fun m ->
m "Timeout on %s (contents in %s)"
(Origin.to_string origin) !!internal_path);
(* TODO what happened here is several rules
timed out while trying to scan a file.
Expand All @@ -693,8 +692,8 @@ let iter_targets_and_get_matches_and_exn_to_errors (config : Core_scan_config.t)
OutJ.Timeout)
|> E.ErrorSet.of_list
| Out_of_memory ->
Logs.warn (fun m ->
m ~tags "OutOfMemory on %s (contents in %s)"
Log.warn (fun m ->
m "OutOfMemory on %s (contents in %s)"
(Origin.to_string origin) !!internal_path);
E.ErrorSet.singleton
(E.mk_error !Rule.last_matched_rule loc ""
Expand Down Expand Up @@ -835,8 +834,7 @@ let targets_of_config (caps : < Cap.tmp >) (config : Core_scan_config.t) :
(* sanity checking *)
(* in deep mode we actually have a single root dir passed *)
if roots <> [] then
Logs.err (fun m ->
m ~tags "if you use -targets, you should not specify files");
Log.err (fun m -> m "if you use -targets, you should not specify files");
(* TODO: ugly, this is because the code path for -e/-f requires
* a language, even with a -target, see test_target_file.py
*)
Expand Down Expand Up @@ -1084,9 +1082,8 @@ let scan ?match_hook (caps : < Cap.tmp >) config
];

(* Let's go! *)
Logs.debug (fun m ->
m ~tags "processing %d files, skipping %d files" num_targets
num_skipped_targets);
Log.info (fun m ->
m "processing %d files, skipping %d files" num_targets num_skipped_targets);
let file_results, scanned_targets =
all_targets
|> iter_targets_and_get_matches_and_exn_to_errors config
Expand Down Expand Up @@ -1122,8 +1119,7 @@ let scan ?match_hook (caps : < Cap.tmp >) config
let num_errors = List.length res.errors in
Tracing.add_data_to_opt_span config.top_level_span
[ ("num_matches", `Int num_matches); ("num_errors", `Int num_errors) ];
Logs.debug (fun m ->
m ~tags "found %d matches, %d errors" num_matches num_errors);
Log.info (fun m -> m "found %d matches, %d errors" num_matches num_errors);

let processed_matches, new_errors, new_skipped =
filter_files_with_too_many_matches_and_transform_as_timeout
Expand All @@ -1140,8 +1136,8 @@ let scan ?match_hook (caps : < Cap.tmp >) config

(* Concatenate all the skipped targets *)
let skipped_targets = skipped @ new_skipped @ res.skipped_targets in
Logs.debug (fun m ->
m ~tags "there were %d skipped targets" (List.length skipped_targets));
Log.info (fun m ->
m "there were %d skipped targets" (List.length skipped_targets));
(* TODO: returning, or not skipped_targets does not seem to have any impact
* on our testsuite, weird. We need to add more tests. Maybe because
* both pysemgrep and osemgrep do their own skip targets management.
Expand Down Expand Up @@ -1170,6 +1166,5 @@ let scan_with_exn_handler (caps : < Cap.tmp >) (config : Core_scan_config.t) :
with
| exn when not !Flag_semgrep.fail_fast ->
let e = Exception.catch exn in
Logs.debug (fun m ->
m ~tags "Uncaught exception: %s" (Exception.to_string e));
Log.err (fun m -> m "Uncaught exception: %s" (Exception.to_string e));
Error (e, None)
1 change: 1 addition & 0 deletions src/rpc/RPC.ml
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -145,5 +145,6 @@ let handle_single_request caps () =
write_packet stdout res_str

let main caps =
Logs.info (fun m -> m "-> OCaml RPC in");
(* For now, just handle one request and then exit. *)
handle_single_request caps ()