pghs975uc
/
infer_clone
1
0
Fork 0
Code Issues Pull Requests Releases Wiki Activity

[logging] Introduce a function to call arbitrary function with subsequent logs written in an indended way.

Browse Source 
Summary:
The problem: you want to log "as much as possible" so you rarely need to
debug your stuff. But you are worried that logs will become not readable
because it will be hard to follow the logic of the program.

Solution: Indentation!

If everything what is happening inside the function is indended, it
won't hurt readability: the overall flow of the whole program will be
easy to comprehend.

Intended usage of this new helper: if the function is complex enough
that does something nontrivial inside (e.g. calls other complex
functions), wrap it in `d_with_indent` at top level.

This diff also uses this function in several top-level places of
Nullsafe. Follow up diffs will include more logging in nullsafe.

Example of log:
```
before:
  &bad -> [Field codetoanalyze.java.nullsafe_default.NullFieldAccess.nullableStatic (object: OptimisticFallback)] Nullable java.lang.Object*
  &codetoanalyze.java.nullsafe_default.NullFieldAccess_codetoanalyze.java.nullsafe_default.NullFieldAccess.nullableStatic -> [Field codetoanalyze.java.nullsafe_default.NullFieldAccess.nullableStatic (object: OptimisticFallback)] Nullable java.lang.Object*
  &this -> [this] StrictNonnull codetoanalyze.java.nullsafe_default.NullFieldAccess*

-----------------------------
Typecking instr: n$1=*&bad:java.lang.Object* [line 45]

Executing typecheck_expr:
  Expr: &bad

Result of typecheck_expr:
  Typ: java.lang.Object*; Nullability: Nullable
Executing convert_complex_exp_to_pvar:

Result of convert_complex_exp_to_pvar:
  Exp: &bad;
  Typestate:
    &bad -> [Field codetoanalyze.java.nullsafe_default.NullFieldAccess.nullableStatic (object: OptimisticFallback)] Nullable java.lang.Object*
    &codetoanalyze.java.nullsafe_default.NullFieldAccess_codetoanalyze.java.nullsafe_default.NullFieldAccess.nullableStatic -> [Field codetoanalyze.java.nullsafe_default.NullFieldAccess.nullableStatic (object: OptimisticFallback)] Nullable java.lang.Object*
    &this -> [this] StrictNonnull codetoanalyze.java.nullsafe_default.NullFieldAccess*

Executing typecheck_expr:
  Expr: &bad

Result of typecheck_expr:
  Typ: java.lang.Object*; Nullability: Nullable
Setting Nullable to Id n$1: Sil.Load
New state:
  n$1 -> [Field codetoanalyze.java.nullsafe_default.NullFieldAccess.nullableStatic (object: OptimisticFallback)] Nullable java.lang.Object*
  &bad -> [Field codetoanalyze.java.nullsafe_default.NullFieldAccess.nullableStatic (object: OptimisticFallback)] Nullable java.lang.Object*
  &codetoanalyze.java.nullsafe_default.NullFieldAccess_codetoanalyze.java.nullsafe_default.NullFieldAccess.nullableStatic -> [Field codetoanalyze.java.nullsafe_default.NullFieldAccess.nullableStatic (object: OptimisticFallback)] Nullable java.lang.Object*
  &this -> [this] StrictNonnull codetoanalyze.java.nullsafe_default.NullFieldAccess*

-----------------------------
Typecking instr: _=*n$1:java.lang.Object*(root java.lang.Object) [line 45]

Executing typecheck_expr:
  Expr: n$1

Result of typecheck_expr:
  Typ: java.lang.Object*; Nullability: Nullable
Executing convert_complex_exp_to_pvar:

Result of convert_complex_exp_to_pvar:
  Exp: &bad;
  Typestate:
    n$1 -> [Field codetoanalyze.java.nullsafe_default.NullFieldAccess.nullableStatic (object: OptimisticFallback)] Nullable java.lang.Object*
    &bad -> [Field codetoanalyze.java.nullsafe_default.NullFieldAccess.nullableStatic (object: OptimisticFallback)] Nullable java.lang.Object*
    &codetoanalyze.java.nullsafe_default.NullFieldAccess_codetoanalyze.java.nullsafe_default.NullFieldAccess.nullableStatic -> [Field codetoanalyze.java.nullsafe_default.NullFieldAccess.nullableStatic (object: OptimisticFallback)] Nullable java.lang.Object*
    &this -> [this] StrictNonnull codetoanalyze.java.nullsafe_default.NullFieldAccess*

Executing typecheck_expr:
  Expr: &bad

Result of typecheck_expr:
  Typ: java.lang.Object*; Nullability: Nullable
Setting Nullable to Id _: Sil.Load
New state:
  n$1 -> [Field codetoanalyze.java.nullsafe_default.NullFieldAccess.nullableStatic (object: OptimisticFallback)] Nullable java.lang.Object*
  _ -> [Field codetoanalyze.java.nullsafe_default.NullFieldAccess.nullableStatic (object: OptimisticFallback)] Nullable java.lang.Object*
  &bad -> [Field codetoanalyze.java.nullsafe_default.NullFieldAccess.nullableStatic (object: OptimisticFallback)] Nullable java.lang.Object*
  &codetoanalyze.java.nullsafe_default.NullFieldAccess_codetoanalyze.java.nullsafe_default.NullFieldAccess.nullableStatic -> [Field codetoanalyze.java.nullsafe_default.NullFieldAccess.nullableStatic (object: OptimisticFallback)] Nullable java.lang.Object*
  &this -> [this] StrictNonnull codetoanalyze.java.nullsafe_default.NullFieldAccess*

-----------------------------
Typecking instr: n$3=_fun_String Object.toString()(n$1:java.lang.Object*) virtual [line 45]

Executing typecheck_expr:
  Expr: n$1

Result of typecheck_expr:
  Typ: java.lang.Object*; Nullability: Nullable
Executing convert_complex_exp_to_pvar:

Result of convert_complex_exp_to_pvar:
  Exp: &bad;
  Typestate:
    n$1 -> [Field codetoanalyze.java.nullsafe_default.NullFieldAccess.nullableStatic (object: OptimisticFallback)] Nullable java.lang.Object*
    _ -> [Field codetoanalyze.java.nullsafe_default.NullFieldAccess.nullableStatic (object: OptimisticFallback)] Nullable java.lang.Object*
    &bad -> [Field codetoanalyze.java.nullsafe_default.NullFieldAccess.nullableStatic (object: OptimisticFallback)] Nullable java.lang.Object*
    &codetoanalyze.java.nullsafe_default.NullFieldAccess_codetoanalyze.java.nullsafe_default.NullFieldAccess.nullableStatic -> [Field codetoanalyze.java.nullsafe_default.NullFieldAccess.nullableStatic (object: OptimisticFallback)] Nullable java.lang.Object*
    &this -> [this] StrictNonnull codetoanalyze.java.nullsafe_default.NullFieldAccess*

Executing typecheck_expr:
  Expr: &bad

Result of typecheck_expr:
  Typ: java.lang.Object*; Nullability: Nullable
exp_rv_dexp: normal var n$1
find_normal_variable_load defining &bad
exp_lv_dexp: program var &bad
WARNING: ERADICATE_NULLABLE_DEREFERENCE `bad` is nullable and is not locally checked for null when calling `toString()`: field nullableStatic at line 44.
Setting ThirdPartyNonnull to Id n$3: typecheck_sil_call_function
New state:
  n$3 -> [Fun toString()] ThirdPartyNonnull java.lang.String*
  n$1 -> [Field codetoanalyze.java.nullsafe_default.NullFieldAccess.nullableStatic (object: OptimisticFallback)] Nullable java.lang.Object*
  _ -> [Field codetoanalyze.java.nullsafe_default.NullFieldAccess.nullableStatic (object: OptimisticFallback)] Nullable java.lang.Object*
  &bad -> [Field codetoanalyze.java.nullsafe_default.NullFieldAccess.nullableStatic (object: OptimisticFallback)] Nullable java.lang.Object*
  &codetoanalyze.java.nullsafe_default.NullFieldAccess_codetoanalyze.java.nullsafe_default.NullFieldAccess.nullableStatic -> [Field codetoanalyze.java.nullsafe_default.NullFieldAccess.nullableStatic (object: OptimisticFallback)] Nullable java.lang.Object*
  &this -> [this] StrictNonnull codetoanalyze.java.nullsafe_default.NullFieldAccess*

-----------------------------
Typecking instr: *&$irvar0:java.lang.String*=n$3 [line 45]

Executing typecheck_expr:
  Expr: &$irvar0

Result of typecheck_expr:
  Typ: void; Nullability: StrictNonnull
Executing convert_complex_exp_to_pvar:
  exp_rv_dexp: program var &$irvar0
  exp_lv_dexp: program var &$irvar0
  exp_rv_dexp: constant _fun_String Object.toString()
  exp_rv_dexp: normal var n$1
  find_normal_variable_load defining &bad
  exp_lv_dexp: program var &bad

Result of convert_complex_exp_to_pvar:
  Exp: &java.lang.Object.toString():java.lang.String(bad)V;
  Typestate:
    n$3 -> [Fun toString()] ThirdPartyNonnull java.lang.String*
    n$1 -> [Field codetoanalyze.java.nullsafe_default.NullFieldAccess.nullableStatic (object: OptimisticFallback)] Nullable java.lang.Object*
    _ -> [Field codetoanalyze.java.nullsafe_default.NullFieldAccess.nullableStatic (object: OptimisticFallback)] Nullable java.lang.Object*
    &bad -> [Field codetoanalyze.java.nullsafe_default.NullFieldAccess.nullableStatic (object: OptimisticFallback)] Nullable java.lang.Object*
    &codetoanalyze.java.nullsafe_default.NullFieldAccess_codetoanalyze.java.nullsafe_default.NullFieldAccess.nullableStatic -> [Field codetoanalyze.java.nullsafe_default.NullFieldAccess.nullableStatic (object: OptimisticFallback)] Nullable java.lang.Object*
    &this -> [this] StrictNonnull codetoanalyze.java.nullsafe_default.NullFieldAccess*

Executing typecheck_expr:
  Expr: n$3

Result of typecheck_expr:
  Typ: java.lang.String*; Nullability: ThirdPartyNonnull
Setting ThirdPartyNonnull to Pvar java.lang.Object.toString():java.lang.String(bad)V: Sil.Store: Exp.Lvar case
New state:
  n$3 -> [Fun toString()] ThirdPartyNonnull java.lang.String*
  n$1 -> [Field codetoanalyze.java.nullsafe_default.NullFieldAccess.nullableStatic (object: OptimisticFallback)] Nullable java.lang.Object*
  _ -> [Field codetoanalyze.java.nullsafe_default.NullFieldAccess.nullableStatic (object: OptimisticFallback)] Nullable java.lang.Object*
  &java.lang.Object.toString():java.lang.String(bad)V -> [Fun toString()] ThirdPartyNonnull java.lang.String*
  &bad -> [Field codetoanalyze.java.nullsafe_default.NullFieldAccess.nullableStatic (object: OptimisticFallback)] Nullable java.lang.Object*
  &codetoanalyze.java.nullsafe_default.NullFieldAccess_codetoanalyze.java.nullsafe_default.NullFieldAccess.nullableStatic -> [Field codetoanalyze.java.nullsafe_default.NullFieldAccess.nullableStatic (object: OptimisticFallback)] Nullable java.lang.Object*
  &this -> [this] StrictNonnull codetoanalyze.java.nullsafe_default.NullFieldAccess*

-----------------------------
Typecking instr: NULLIFY(&bad); [line 45]
```

Reviewed By: artempyanykh

Differential Revision: D20304424

fbshipit-source-id: 7fa3f459e
master
Mitya Lyubarskiy 5 years ago committed by Facebook Github Bot
parent 16ed8950e9
commit 59e17f59b8
5 changed files with 210 additions and 167 deletions
Show Stats Download Patch File Download Diff File

22
infer/src/base/Logging.ml
Unescape View File

@ -436,8 +436,26 @@ let d_indent indent =
d_str s d_str s
(** dump command to increase the indentation level *)
let d_increase_indent () = d_printf " @[" let d_increase_indent () = d_printf " @["
(** dump command to decrease the indentation level *)
let d_decrease_indent () = d_printf "@]" let d_decrease_indent () = d_printf "@]"
let d_call_with_indent_impl ~f =
d_increase_indent () ;
let result = f () in
d_decrease_indent () ;
d_ln () ;
(* Without a new line decreasing identation does not fully work *)
result
let d_with_indent ?pp_result ~name f =
if not Config.write_html then f ()
else (
d_printf "Executing %s:@\n" name ;
let result = d_call_with_indent_impl ~f in
(* Print result if needed *)
Option.iter pp_result ~f:(fun pp_result ->
d_printf "Result of %s:@\n" name ;
d_call_with_indent_impl ~f:(fun () -> d_printf "%a" pp_result result) ) ;
result )

16
infer/src/base/Logging.mli
Unescape View File

@ -129,7 +129,19 @@ val d_indent : int -> unit
(** dump an indentation *) (** dump an indentation *)
val d_increase_indent : unit -> unit val d_increase_indent : unit -> unit
(** dump command to increase the indentation level *) (** dump command to increase the indentation level. NOTE: most likely, you need [d_with_indent]
instead *)
val d_decrease_indent : unit -> unit val d_decrease_indent : unit -> unit
(** dump command to decrease the indentation level *) (** dump command to decrease the indentation level NOTE: most likely, you need [d_with_indent]
instead. *)
val d_with_indent : ?pp_result:(F.formatter -> 'a -> unit) -> name:string -> (unit -> 'a) -> 'a
(** Execute arbitrary function (the last argument) with a given [name] so that all logs written
inside (if any) are written with indentation.
[pp_result], if provided, will make the result of a call to be printed as well (useful for cases
when there are several places when the function returns).
NOTE: If you want to use it NOT at the very top level of a function, it is a code smell, and you
probably want to split your function into smaller ones. *)

25
infer/src/nullsafe/typeCheck.ml
Unescape View File

@ -112,6 +112,8 @@ type checks = {eradicate: bool; check_ret_type: check_return_type list}
(** Typecheck an expression. *) (** Typecheck an expression. *)
let rec typecheck_expr ~nullsafe_mode find_canonical_duplicate visited checks tenv node instr_ref let rec typecheck_expr ~nullsafe_mode find_canonical_duplicate visited checks tenv node instr_ref
(curr_pdesc : Procdesc.t) typestate e tr_default loc : TypeState.range = (curr_pdesc : Procdesc.t) typestate e tr_default loc : TypeState.range =
L.d_with_indent ~name:"typecheck_expr" ~pp_result:TypeState.pp_range (fun () ->
L.d_printfln "Expr: %a" Exp.pp e ;
match e with match e with
(* null literal or 0 *) (* null literal or 0 *)
| _ when Exp.is_null_literal e -> | _ when Exp.is_null_literal e ->
@ -138,8 +140,8 @@ let rec typecheck_expr ~nullsafe_mode find_canonical_duplicate visited checks te
| Exp.Lfield (exp, field_name, typ) -> | Exp.Lfield (exp, field_name, typ) ->
let _, _ = tr_default in let _, _ = tr_default in
let _, inferred_nullability = let _, inferred_nullability =
typecheck_expr ~nullsafe_mode find_canonical_duplicate visited checks tenv node instr_ref typecheck_expr ~nullsafe_mode find_canonical_duplicate visited checks tenv node
curr_pdesc typestate exp instr_ref curr_pdesc typestate exp
(* TODO(T54687014) optimistic default might be an unsoundness issue - investigate *) (* TODO(T54687014) optimistic default might be an unsoundness issue - investigate *)
(typ, InferredNullability.create TypeOrigin.OptimisticFallback) (typ, InferredNullability.create TypeOrigin.OptimisticFallback)
loc loc
@ -161,8 +163,8 @@ let rec typecheck_expr ~nullsafe_mode find_canonical_duplicate visited checks te
tr_new tr_new
| Exp.Lindex (array_exp, index_exp) -> | Exp.Lindex (array_exp, index_exp) ->
let _, inferred_nullability = let _, inferred_nullability =
typecheck_expr ~nullsafe_mode find_canonical_duplicate visited checks tenv node instr_ref typecheck_expr ~nullsafe_mode find_canonical_duplicate visited checks tenv node
curr_pdesc typestate array_exp tr_default loc instr_ref curr_pdesc typestate array_exp tr_default loc
in in
let index_desc = let index_desc =
match EradicateChecks.explain_expr tenv node index_exp with Some s -> s | None -> "?" match EradicateChecks.explain_expr tenv node index_exp with Some s -> s | None -> "?"
@ -175,7 +177,7 @@ let rec typecheck_expr ~nullsafe_mode find_canonical_duplicate visited checks te
let typ, _ = tr_default in let typ, _ = tr_default in
(typ, InferredNullability.create TypeOrigin.ArrayAccess) (typ, InferredNullability.create TypeOrigin.ArrayAccess)
| _ -> | _ ->
tr_default tr_default )
(* Handle the case where a field access X.f happens via a temporary variable $Txxx. (* Handle the case where a field access X.f happens via a temporary variable $Txxx.
@ -259,6 +261,10 @@ let update_typestate_fld ~is_assignment tenv access_loc typestate pvar object_or
let convert_complex_exp_to_pvar tenv idenv curr_pname let convert_complex_exp_to_pvar tenv idenv curr_pname
(curr_annotated_signature : AnnotatedSignature.t) ~node ~(original_node : Procdesc.Node.t) (curr_annotated_signature : AnnotatedSignature.t) ~node ~(original_node : Procdesc.Node.t)
~is_assignment exp_ typestate loc = ~is_assignment exp_ typestate loc =
L.d_with_indent ~name:"convert_complex_exp_to_pvar"
~pp_result:(fun f (exp, typestate) ->
F.fprintf f "Exp: %a;@\nTypestate: @\n%a" Exp.pp exp TypeState.pp typestate )
(fun () ->
let exp = let exp =
handle_field_access_via_temporary idenv curr_pname typestate (Idenv.expand_expr idenv exp_) handle_field_access_via_temporary idenv curr_pname typestate (Idenv.expand_expr idenv exp_)
in in
@ -274,8 +280,8 @@ let convert_complex_exp_to_pvar tenv idenv curr_pname
in in
match frontend_variable_assignment with match frontend_variable_assignment with
| Some (call_node, id) -> | Some (call_node, id) ->
( funcall_exp_to_original_pvar_exp tenv curr_pname typestate exp ~is_assignment ~call_node ( funcall_exp_to_original_pvar_exp tenv curr_pname typestate exp ~is_assignment
~node id ~call_node ~node id
, typestate ) , typestate )
| _ -> | _ ->
default ) default )
@ -341,7 +347,7 @@ let convert_complex_exp_to_pvar tenv idenv curr_pname
in in
res res
| _ -> | _ ->
default default )
let constructor_check_calls_this curr_pname calls_this pn = let constructor_check_calls_this curr_pname calls_this pn =
@ -395,6 +401,7 @@ let drop_unchecked_signature_params proc_attributes annotated_signature =
(* Apply a function to a pvar and its associated content if front-end generated. *) (* Apply a function to a pvar and its associated content if front-end generated. *)
let pvar_apply instr_ref idenv tenv curr_pname curr_annotated_signature loc handle_pvar typestate let pvar_apply instr_ref idenv tenv curr_pname curr_annotated_signature loc handle_pvar typestate
pvar node = pvar node =
L.d_with_indent ~name:"pvar_apply" ~pp_result:TypeState.pp (fun () ->
let typestate' = handle_pvar typestate pvar in let typestate' = handle_pvar typestate pvar in
let curr_node = TypeErr.InstrRef.get_node instr_ref in let curr_node = TypeErr.InstrRef.get_node instr_ref in
let frontent_variable_assignment = let frontent_variable_assignment =
@ -414,7 +421,7 @@ let pvar_apply instr_ref idenv tenv curr_pname curr_annotated_signature loc hand
| Exp.Lvar pvar', _ -> | Exp.Lvar pvar', _ ->
handle_pvar typestate' pvar' handle_pvar typestate' pvar'
| _ -> | _ ->
typestate' ) typestate' ) )
(* typecheck_expr with fewer parameters, using a common template for typestate range *) (* typecheck_expr with fewer parameters, using a common template for typestate range *)

4
infer/src/nullsafe/typeState.ml
Unescape View File

@ -19,6 +19,10 @@ end)
type range = Typ.t * InferredNullability.t [@@deriving compare] type range = Typ.t * InferredNullability.t [@@deriving compare]
let pp_range fmt (typ, nullability) =
F.fprintf fmt "Typ: %s; Nullability: %a" (Typ.to_string typ) InferredNullability.pp nullability
type t = range M.t [@@deriving compare] type t = range M.t [@@deriving compare]
let equal = [%compare.equal: t] let equal = [%compare.equal: t]

2
infer/src/nullsafe/typeState.mli
Unescape View File

@ -14,6 +14,8 @@ type t
type range = Typ.t * InferredNullability.t type range = Typ.t * InferredNullability.t
val pp_range : Format.formatter -> Typ.t * InferredNullability.t -> unit
val add_id : Ident.t -> range -> t -> descr:string -> t val add_id : Ident.t -> range -> t -> descr:string -> t
(** [descr] is for debug logs only *) (** [descr] is for debug logs only *)

Write Preview
Loading…
Cancel
Save