Enforcing use of the safe macro when logging

src/linting/extended_checks.jl

@@ -55,7 +55,7 @@
     !is_there_any_star_marker && return x == y
 
     contains(x, "QQQ") && contains(y, "QQQ") &&
         throw(BothCannotHaveStarException("Cannot both $x and $y have a star marker"))
     if contains(x, "QQQ")
         reg_exp = Regex(replace(x, "QQQ" => ".*"))
         return !isnothing(match(reg_exp, y))
@@ -212,6 +212,7 @@
 struct NonFrontShapeAPIUsage_Extension <: ViolationExtendedRule end
 struct InterpolationInSafeLog_Extension <: RecommendationExtendedRule end
 struct UseOfStaticThreads <: ViolationExtendedRule end
+struct LogStatementsMustBeSafe <: ViolationExtendedRule end
 
 
 const all_extended_rule_types = Ref{Any}(
@@ -268,7 +269,7 @@
 
 function get_recommendation(msg_prefix)
     m = retrieve_full_msg_from_prefix(msg_prefix)
     m in keys(is_recommendation) || return nothing
     return is_recommendation[m]
 end
 
@@ -310,8 +311,9 @@
     return generic_check(T, x, template_code, "`$(keyword)` should be used with extreme caution.")
 end
 
+# IT IS NECESSARY TO CALL THIS FUNCTION IN A CHECK FUNCTION THAT DOES NOT USE GENERIC_CHECK
 function check_for_recommendation(T::DataType, msg::String)
     @assert supertype(T) in [RecommendationExtendedRule, ViolationExtendedRule]
     b = supertype(T) == RecommendationExtendedRule
     get!(is_recommendation, msg, b)
     return nothing
@@ -343,7 +345,7 @@
 
 function check(t::NThreads_Extention, x::EXPR, markers::Dict{Symbol,String})
     # Threads.nthreads() must not be used in a const field, but it is allowed elsewhere
     haskey(markers, :const) || return
     generic_check(t, x, "Threads.nthreads()", "`Threads.nthreads()` should not be used in a constant variable.")
 end
 
@@ -397,11 +399,11 @@
 check(t::Ptr_Extension, x::EXPR) = generic_check(t, x, "Ptr{hole_variable}(hole_variable)")
 
 function check(t::ArrayWithNoType_Extension, x::EXPR, markers::Dict{Symbol,String})
     haskey(markers, :filename) || return
     contains(markers[:filename], "src/Compiler") || return
 
     haskey(markers, :macrocall) && markers[:macrocall] == "@match" && return
     haskey(markers, :macrocall) && markers[:macrocall] == "@matchrule" && return
 
     generic_check(t, x, "[]", "Need a specific Array type to be provided.")
 end
@@ -441,7 +443,7 @@
 end
 
 function check(t::Unsafe_Extension, x::EXPR, markers::Dict{Symbol,String})
     haskey(markers, :function) || return
     isnothing(match(r"_unsafe_.*", markers[:function])) || return
     isnothing(match(r"unsafe_.*", markers[:function])) || return
 
@@ -538,7 +540,7 @@
 end
 
 function check(t::RelPathAPIUsage_Extension, x::EXPR, markers::Dict{Symbol,String})
     haskey(markers, :filename) || return
     contains(markers[:filename], "src/Compiler/Front") || return
 
     generic_check(t, x, "hole_variable::RelPath", "Usage of type `RelPath` is not allowed in this context.")
@@ -550,7 +552,7 @@
 end
 
 function check(t::NonFrontShapeAPIUsage_Extension, x::EXPR, markers::Dict{Symbol,String})
     haskey(markers, :filename) || return
     # In the front-end and in FFI, we are allowed to refer to `Shape`
     contains(markers[:filename], "src/FrontCompiler") && return
     contains(markers[:filename], "src/FFI") && return
@@ -578,3 +580,53 @@
     generic_check(t, x, "@threads :static hole_variable_star", msg)
     generic_check(t, x, "Threads.@threads :static hole_variable_star", msg)
 end
+
+function all_arguments_are_safe(x::EXPR)
+    is_safe_macro_call(y) =
+        y.head == :macrocall && y.args[1].head == :IDENTIFIER && y.args[1].val == "@safe"
+
+    for arg in x.args[2:end]
+        # This is safe
+        if is_safe_macro_call(arg) ||
+            arg.head == :NOTHING
+
+            continue
+        elseif arg.head isa CSTParser.EXPR && arg.head.head == :OPERATOR && arg.head.val == "=" &&
+            is_safe_macro_call(arg.args[2])
+
+            continue
+        else
+            # @info x arg
+            # isdefined(Main, :Infiltrator) && Main.infiltrate(@__MODULE__, Base.@locals, @__FILE__, @__LINE__)
+            return false
+        end
+    end
+    return true
+end
+
+function check(t::LogStatementsMustBeSafe, x::EXPR)
+    msg = "Unsafe logging statement. You must enclose variables and strings with @safe(...)."
+    check_for_recommendation(LogStatementsMustBeSafe, msg)
+
+    # @info and its friends
+    if x.head == :macrocall && x.args[1].head == :IDENTIFIER && startswith(x.args[1].val, "@info")
+        all_arguments_are_safe(x) || seterror!(x, msg)
+    end
+
+    # @debug and its friends
+    if x.head == :macrocall && x.args[1].head == :IDENTIFIER && startswith(x.args[1].val, "@debug")
+        all_arguments_are_safe(x) || seterror!(x, msg)
+    end
+
+    # @error and its friends
+    if x.head == :macrocall && x.args[1].head == :IDENTIFIER && startswith(x.args[1].val, "@error")
+        all_arguments_are_safe(x) || seterror!(x, msg)
+    end
+
+    # @warn and its friends
+    if x.head == :macrocall && x.args[1].head == :IDENTIFIER && startswith(x.args[1].val, "@warn")
+        # isdefined(Main, :Infiltrator) && Main.infiltrate(@__MODULE__, Base.@locals, @__FILE__, @__LINE__)
+        all_arguments_are_safe(x) || seterror!(x, msg)
+    end
+end
+

test/rai_rules_tests.jl

@@ -1807,31 +1807,31 @@ end
     # ERRORS
     source_with_error = raw"""
     function f(conf)
-        @info "($conf.container.baseurl)"
+        @INFO "($conf.container.baseurl)"
     end
     """
 
     source_with_error2 = raw"""
     function f(conf)
-        @info "$conf.container.baseurl"
+        @INFO "$conf.container.baseurl"
     end
     """
 
     source_with_error3 = raw"""
     function f(conf)
-        @info "this string contains an error $conf.container.baseurl indeed!"
+        @INFO "this string contains an error $conf.container.baseurl indeed!"
     end
     """
 
     source_with_error4 = raw"""
     function f(conf)
-        @info "this string contains an error $conf .container.baseurl indeed!"
+        @INFO "this string contains an error $conf .container.baseurl indeed!"
     end
     """
 
     source_with_error5 = raw"""
     function f(engine_name)
-        @info "Issuing delete request for engine $engine_name..."
+        @INFO "Issuing delete request for engine $engine_name..."
     end
     """
 
@@ -1862,13 +1862,13 @@ end
     # NO ERROR
     source_without_error = raw"""
     function f(conf)
-        @info "$(conf.container.baseurl)"
+        @INFO "$(conf.container.baseurl)"
     end
     """
 
     source_without_error2 = raw"""
     function f(conf)
-        @info "this string contains an error $(conf.container.baseurl) indeed!"
+        @INFO "this string contains an error $(conf.container.baseurl) indeed!"
     end
     """
 
@@ -1958,35 +1958,35 @@ end
     )
 end
 
-@testset "Check on @warnv_safe_to_log" begin
-    source = raw"""
-    function pm_check_mutable_pages(bytes::Int)
-        pm = PAGER_MONITOR
-
-        max_pages = (@atomic pm.mutable_pages_running_max)
-        max_bytes = (@atomic pm.mutable_bytes_running_max)
-        if max_bytes >= bytes
-            @warnv_safe_to_log 0 "[Pager] Too many mutable pages \
-                detected: $max_pages pages weighting $max_bytes bytes"
-
-            @ensure @warnv_safe_to_log 2 "[Pager] Too many mutable pages \
-                detected: $max_pages pages weighting $max_bytes bytes"
-
-            @ensure @warnv_safe_to_log 0 "no interpolation"
-
-            mutable_report = pm_generate_mutable_pages_report!()
-            if !isnothing(mutable_report)
-                @warnv_safe_to_log 0 mutable_report
-            end
-            return false
-        end
-
-        return true
-    end
-    """
-    @test lint_test(source, "Line 7, column 9: Safe warning log has interpolation.")
-    @test lint_test(source, "Line 10, column 17: Safe warning log has interpolation.")
-end
+# @testset "Check on @warnv_safe_to_log" begin
+#     source = raw"""
+#     function pm_check_mutable_pages(bytes::Int)
+#         pm = PAGER_MONITOR
+
+#         max_pages = (@atomic pm.mutable_pages_running_max)
+#         max_bytes = (@atomic pm.mutable_bytes_running_max)
+#         if max_bytes >= bytes
+#             @warnv_safe_to_log 0 "[Pager] Too many mutable pages \
+#                 detected: $max_pages pages weighting $max_bytes bytes"
+
+#             @ensure @warnv_safe_to_log 2 "[Pager] Too many mutable pages \
+#                 detected: $max_pages pages weighting $max_bytes bytes"
+
+#             @ensure @warnv_safe_to_log 0 "no interpolation"
+
+#             mutable_report = pm_generate_mutable_pages_report!()
+#             if !isnothing(mutable_report)
+#                 @warnv_safe_to_log 0 mutable_report
+#             end
+#             return false
+#         end
+
+#         return true
+#     end
+#     """
+#     @test lint_test(source, "Line 7, column 9: Safe warning log has interpolation.")
+#     @test lint_test(source, "Line 10, column 17: Safe warning log has interpolation.")
+# end
 
 @testset "Use of static threads" begin
     source = raw"""
@@ -2007,3 +2007,29 @@ end
     @test lint_test(source, "Line 2, column 5: Use `Threads.@threads :dynamic` instead of `Threads.@threads :static`.")
     @test lint_test(source, "Line 6, column 5: Use `Threads.@threads :dynamic` instead of `Threads.@threads :static`.")
 end
+
+@testset "Unsafe logging" begin
+    source = raw"""
+    function f()
+        @warnv "Unsafe logging $(x)"
+        @warnv @safe("Unsafe logging") job
+        @warnv @safe("Unsafe logging") my_value=job
+        @warnv @safe("Unsafe logging") my_value=@safe(job) my_value2=job
+        @warnv @safe("Unsafe logging") my_value=@safe(job) my_value=@safe(job2) my_value=@safe(job3) "$(x)"
+        @warnv @safe("Unsafe logging") my_value=@safe(job) my_value=@safe(job2) my_value=@safe(job3) "$(x)"
+        @debug_connection @safe("Unsafe logging") my_value=@safe(job) my_value=@safe(job2) my_value=@safe(job3) "$(x)"
+        @warn_with_current_exceptions_safe_to_log @safe("Unsafe logging") my_value=@safe(job) my_value=@safe(job2) my_value=@safe(job3) "$(x)"
+        @warnv "Unsafe logging"
+        @warnv "Unsafe logging" my_value=@safe(job)
+        @warnv "Unsafe logging" my_value=@safe(job) my_value=@safe(job2)
+        @warnv "Unsafe logging" my_value=@safe(job) my_value=@safe(job2) my_value=@safe(job3)
+
+        @warnv @safe("Safe logging $(x)")
+        @warnv @safe("Safe logging")
+    end
+    """
+    @test count_lint_errors(source) == 12
+    for line in 2:count_lint_errors(source) + 1
+        @test lint_test(source, "Line $(line), column 5: Unsafe logging statement. You must enclose variables and strings with @safe(...).")
+    end
+end

test/static_lint_tests.jl

@@ -1816,7 +1816,7 @@ end
         return nothing
     end
     """)
-    @test isempty(StaticLint.collect_hints(cst, server))
+    @test !isempty(StaticLint.collect_hints(cst, server))
 end
 
 @testset "aliased import: #974" begin