Debug logging in context #674
Conversation
jvican
added
enhancement
cli
ergonomics
|
@jvican Yeah, definately. I just wanted to push this out to get some feedback. Also I'm new to bloop, so please review to make sure all logs are tied to the right context. |
|
|
||
| object Timer { | ||
| @inline def timed[T](logger: Logger, prefix: Option[String] = None)(op: => T): T = { | ||
| val start = System.nanoTime() | ||
| try op | ||
| finally { | ||
| val elapsed = (System.nanoTime() - start).toDouble / 1e6 | ||
| logger.debug(s"Elapsed ${prefix.map(s => s"($s)").getOrElse("")}: $elapsed ms") | ||
| logger.debugInContext(s"Elapsed ${prefix.map(s => s"($s)").getOrElse("")}: $elapsed ms")(LogContext.All) |
There was a problem hiding this comment.
We may want to take the log context as an optional parameter like prefix, defaulting on LogContext.All if none is provided.
There was a problem hiding this comment.
The problem is, we can't change the Logger interface. I've played around with implicit shadowing technique and it works for simple scenarios (I've presented POC to @tues on slack), but again, we've got cases where we have nested loggers, where we'd have to resolve to reflection to call the underlaying loggers "non-shadowed" (original) method. Also, its a bit hacky - I'm not sure you'd want that kind of solution in the library.
There was a problem hiding this comment.
I have force pushed a solution to this problem. The solution requires to know how the rules for ambiguous overloads work, but after some plumbing here and there I've managed to replace debugInContext by debug. I've also intentionally removed the default parameters for the implicit because I want the use of debug to be as explicit as possible and if developers of bloop call debug in a place where there's no implicit log context, they have to pass it manually.
I've also added a test case to make sure it works. Check it out, please. /cc @tues
| } | ||
|
|
||
| object LogContext { | ||
|
|
There was a problem hiding this comment.
Let's remove this new line 😄
The solution required to do this change without modifying sbt.testing.Logger's interface relies on the linearization order and the check for ambiguous overloads. Typically, if two methods are defined in an interface and they have the same public interface, except that one takes an implicit and the other one doesn't, the compiler fails with an ambiguous overload error when one of the methods is used (e.g. `logger.debug(msg)` refers to `logger.debug(msg)(implicit ctx)` or `logger.debug(msg)`?). To fix this problem, we override the version that doesn't take a parameter in a super class of `BloopLogger`, which is the common logging interface across bloop and is implemented by many different types of bloop loggers. Then, we add two abstract methods that must be implemented by subclasses: 1. An implementation of a `private[logging] def printDebug`, which is used by the overridden simple `debug` in `BaseSbtLogger`. 2. An implementation of the long debug method that we want the compiler to select for every use of `logger.debug(msg)`. This trick helps us remove `debugInContext` and simplify the logger API. From now on, everyone will be forced to use `debug` and provide a context if there is not an implicit one.
We didn't run this before, but now we add a way to test that all the commands in the doc generator are correctly parsed by bloop.
A debug filter can be selected by the user by typing `--debug $FILTER` in the command-line bloop tool. Users can now select several debug filters. They are called debug filters instead of log contexts because the latter name can be misleading. A log context is currently only used for debugging purposes, so it's better to keep its semantics as precise as possible. This commit also makes `--debug` enable verbose debugging automatically, which before required the user to pass `--verbose` to see the logs.
|
I've just added another commits to:
|
|
@jvican good job, I'm glad you've worked around the API issue. I'm really curious about the solution - I've spent a better part of one evening trying to figure it out 👍 I'll try to find some time for review soon. |
|
@ioleo The solution is not obvious, so I'm planning to write a blog post about it. If @tues cannot review today, I'll probably merge this PR right away because I'm blocked by it to implement some BSP features, but I would still love that someone goes through the diff and let me know their feedback -- I would be happy to follow up with another PR addressing it. |
|
@ioleo I wrote a blog post describing the technique I used for the design of the overloaded debug https://jvican.github.io/post/implicit-parameter-overload/ I haven’t yet tweeted about it but feel free to proof read it and let me know if I can improve something. |
|
I'm gonna go ahead and merge this 😄 I'm happy to address feedback on a follow-up PR. |
|
@jvican sure 👍, sorry I'm just loaded with work currently, had no time to look into it, but I will eventually get back to you |
Supersedes #638, implements #333.