Fixed Verbosity System

[jClugstor]

Checklist

• Appropriate tests were added
• Any code changes were done in a way that does not break public API
• All documentation related to code changes were updated
• The new code follows the
  contributor guidelines, in particular the SciML Style Guide and
  COLPRAC.
• Any new documentation only uses public API

Additional context

using LinearSolve, BenchmarkTools
using SciMLLogging: Verbosity
n = 4
A = rand(n, n)
b1 = rand(n);
b2 = rand(n);
prob = LinearProblem(A, b1)

With this PR:

@btime solve(prob, verbose=false)
365.015 ns (11 allocations: 928 bytes)

using SciMLLogging: Verbosity
@btime solve(prob, verbose = LinearVerbosity(Verbosity.None()))
363.893 ns (12 allocations: 960 bytes)

@btime solve(prob, verbose=true)
 432.445 ns (15 allocations: 1.03 KiB)

@report_opt solve(prob, verbose = LinearVerbosity(Verbosity.None()))
No errors detected

@report_opt solve(prob, verbose = false)
No errors detected

@profview for i in 1:10000000 init(prob, verbose = false) end 

From the profile we can see that the constructor for LinearVerbosity doesn't even get called from __init, which should indicate that it got compiled out.

With current main (Bool verbosity system)

`@btime solve(prob, verbose=false)`
 `359.857 ns (11 allocations: 928 bytes)`

`@btime solve(prob, verbose=true)`
` 329.573 ns (11 allocations: 928 bytes)`

@profview for i in 1:10000000 init(prob, verbose = false) end 

[jClugstor]

@ChrisRackauckas

[jClugstor]

I rewrote SciMLLogging to get rid of the Moshi.jl dependency, and to make it easier to implement Verbosity "presets". I also rewrote the stuff in LinearVerbosity. This way has fewer dependencies, and is still able to compile out the logging code. Better yet, even if logging is enabled, if the code goes through an @SciMLMessage where the verbosity toggle is set to Verbosity.Silent() the it doesn't go through any of the SciMLLogging code because it gets compiled away, at least in the testing I've done so far. Which means that no time is wasted getting the verbosity type, checking if it's None, etc. anymore.

With this PR:

n = 4
A = rand(n, n)
b1 = rand(n);
b2 = rand(n);
prob = LinearProblem(A, b1)

@b solve(prob, verbose = false)
373.308 ns (12 allocs: 1008 bytes)

@b solve(prob, verbose = true )
364.000 ns (12 allocs: 1008 bytes)

@b solve(prob, verbose = LinearVerbosity()) 
378.214 ns (13 allocs: 1.000 KiB)

@b solve(prob)
378.121 ns (12 allocs: 1008 bytes)

verb = LinearVerbosity()

@b solve(prob, verbose = verb)
527.854 ns (13 allocs: 960 bytes)

opt = @report_opt solve(prob, LUFactorization(), verbose = LinearVerbosity())
No errors detected

opt = @report_opt solve(prob, LUFactorization(), verbose = LinearVerbosity(Verbosity.None()))
No errors detected

opt = @report_opt solve(prob, LUFactorization(), verbose = false)
No errors detected

cache = init(prob, LUFactorization())

@b solve!(cache) 
101.288 ns (1 allocs: 48 bytes)

A = [1.0 0 0 0
    0 1 0 0
    0 0 1 0
    0 0 0 0]
b = rand(4)
prob = LinearProblem(A, b)

verb = LinearVerbosity(default_lu_fallback = Verbosity.Silent())

cache = init(prob, verbose = verb)

@b solve!(cache)
104.880 ns (1 allocs: 48 bytes)

cache = init(prob, verbose=false)

@b solve!(cache)
104.812 ns (1 allocs: 48 bytes)

LinearSolve v3.40.1:

n = 4
A = rand(n, n)
b1 = rand(n);
b2 = rand(n);
prob = LinearProblem(A, b1)

@b solve(prob, verbose = false)
252.902 ns (11 allocs: 928 bytes)

@b solve(prob, verbose = true )
250.919 ns (11 allocs: 928 bytes)

A = [1.0 0 0 0
    0 1 0 0
    0 0 1 0
    0 0 0 0]
b = rand(4)
prob = LinearProblem(A, b)

cache = init(prob, verbose = false)

104.171 ns (1 allocs: 48 bytes)

So the creation of the LinearVerbosity adds a little bit of overhead to init, but once the cache is created, if there's no printing, there's no overhead.

[jClugstor]

Got rid of the Verbosity submodule in SciMLLogging, and cleaned up the names so there are no collisions with Logging.jl. Running simple benchmarks again to make sure nothing changed:

using LinearSolve, Chairmarks
using SciMLLogging
using JET
using Test

n = 4
A = rand(n, n)
b1 = rand(n);
b2 = rand(n);
prob = LinearProblem(A, b1)

@b solve(prob, verbose = false)
368.538 ns (12 allocs: 1.031 KiB)

@b solve(prob, verbose = true )
365.672 ns (12 allocs: 1.031 KiB)

@b solve(prob, verbose = LinearVerbosity()) 
367.880 ns (13 allocs: 1.047 KiB)

@b solve(prob)
361.778 ns (12 allocs: 1.031 KiB)

opt = @report_opt solve(prob, LUFactorization(), verbose = LinearVerbosity())
No errors detected

opt = @report_opt solve(prob, LUFactorization(), verbose = LinearVerbosity(SciMLLogging.None()))
No errors detected

opt = @report_opt solve(prob, LUFactorization(), verbose = false)
No errors detected

cache = init(prob, LUFactorization())

@b solve!(cache) 
103.779 ns (1 allocs: 48 bytes)

A = [1.0 0 0 0
    0 1 0 0
    0 0 1 0
    0 0 0 0]
b = rand(4)
prob = LinearProblem(A, b)

solve(
    prob,
    verbose=LinearVerbosity(default_lu_fallback=WarnLevel()))

@test_logs (:warn,
    "LU factorization failed, falling back to QR factorization. `A` is potentially rank-deficient.") solve(
    prob,
    verbose=LinearVerbosity(default_lu_fallback=WarnLevel()))
    
verb = LinearVerbosity(default_lu_fallback = Silent())

cache = init(prob, verbose = false)

@b solve!(cache)
105.875 ns (1 allocs: 48 bytes)

[jClugstor]

@ChrisRackauckas BLAS logging is in this now. In order to completely test I added the "BLIS Verbosity Integration Tests" testset https://github.com/SciML/LinearSolve.jl/pull/756/files#diff-89192f46443cdf6aec03225b86e08aa1554d15671259bf9cc9957a3e75d96851R323 which doesn't run on CI because blis_jll isn't available, but I ran those tests locally and made sure they pass and give the expected output.

[ChrisRackauckas]

Just don't load BLIS then.

[jClugstor]

I should just get rid of that testset?

[ChrisRackauckas]

If BLIS doesn't load then just don't use it. Also, it should not just test BLIS, the least used BLAS. You need to also cover MKL, AppleAccelerate, and OpenBLAS.

[jClugstor]

Ah yeah, I have it check if the extension is loaded and don't run the tests if it isn't.
Ok, I'll add those in as well.