SciMLLogging Integration

[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

I'm experimenting with using a ScopedValue to hold the NonlinearVerbosity object. There are a couple of reasons for this. Unlike LinearSolve, presently none of the caches have a verbose field that can hold the verbosity specifier. We could add these fields, but then only functions that explicitly depend on the cache can use the verbosity settings. Alternatively, we could thread the verbosity through every function that should be able to use it. Currently, many of the utility functions in NonlinearSolve don't explicitly depend on the cache, but do include warning messages, and we need to use the verbosity system in these functions if we want to be able to turn the warnings off while still having them available if needed. It seems unreasonable to have every function that might be used have to have the verbosity or the cache as one of it's arguments.

From what I can tell it seems like ScopedValues might be good for this, apparently avoiding some of the performance issues of normal globals. For now I have a global ScopedValue const nonlinear_verbose = ScopedValue{Union{NonlinearVerbosity{true}, NonlinearVerbosity{false}}}(). Then __init and solve! are called in the context of the @with macro, where nonlinear_verbose is set to the value of the verbose keyword. This allows any function that's called by __init or solve! to use the verbosity settings from the verbose keyword, without having to explicitly depend on either the verbosity object or the nonlinear cache.

I think my biggest concern here would be the performance of accessing the ScopedValue with nonlinear_verbose[], since that will need to be done in any place the @SciMLMessage macro would be used, which could be in parts of the code that is run very often.

I've been doing some profiling and some benchmarking and I do see a slowdown in some cases, but it's hard to tell if it's related to using ScopedValues or if it's other changes related to the verbosity system.

@oscardssmith do you have a sense of whether this is a good idea or not? If there are going to be really obvious performance issues then it's probably not worth it to do this

[jClugstor]

After profiling some more it looks like accessing the ScopedValue is pretty expensive:

the getindex on the left takes even more time than the actual solve, more than doubling the actual time of the solve. That's dissapointing, it could have been nice :(

[oscardssmith]

That's a lot more expensive than I would expect. Might be worth filing a bug.

[oscardssmith]

do we have a new profile of this to confirm it's cheap?

[jClugstor]

Which part? I abandoned the ScopedValues idea because of the performance and am just putting the verbosity inside of the caches for now.

I'm working on profiling a couple of examples of the system working right now.

[jClugstor]

SciMLLogging just needs a couple of changes to make it more type stable (SciML/SciMLLogging.jl#33) but with that when the relevant message toggle is set to Silent no code from SciMLLogging is run.

@profview for i in 1:10000000 
    solve(
    int_prob,
    ITP(), verbose=NonlinearVerbosity(non_enclosing_interval=SciMLLogging.Silent()))
end 

[jClugstor]

This is at a point where if I use SciML/LinearSolve.jl#756 all tests pass, and we can pass in a LinearVerbosity to the NonlinearVerbosity, and it will use that LinearVerbosity.

I made it so that the Standard preset for NonlinearVerbosity sets LinearVerbosity to Minimal.

Also there are a couple of other verbosity settings, all described by the docstring for NonlinearVerbosity.

There are a couple of warnings left that are not under a @SciMLMessage. We'll have to figure out how to get the NonlinearVerbosity available to those spots if we want to use SciMLLogging with those. It might be better to figure that out later.