jonsequitur / Its.Log

Get information out of your code at runtime to send it to log files, perf counters, consoles, services, sensors. Maximum flexibility and maintainability, minimum code.
Other
13 stars 10 forks source link

Clean up Confirm abstraction #19

Open jzabroski opened 9 years ago

jzabroski commented 9 years ago
  1. Func value = null, but null is really a marker value to be coerced to true. This signature should be re-written using an Option type aka Nullable for reference types. Not quite the same thing semantically as Maybe, because we are trying to explicitly capture the fact we can handle a None case for the user.
  2. The whole idea of requireConfirm is kind of messy. The documentation says "Writes out buffered entries in a log activity that was entered with requireConfirm set to true." So I have a couple of observations here. First, why should calling this method depend on a flag set at the Log.Enter level? This is sort of like what some researchers call Type State - the methods that are allowed to be called depend on the state of the type instance. We can mimic Type State in .NET by essentially making the Log class parametric - Log where T is a LogType. This may also result in better JIT code, since the overload doesn't exist and the final could would generate two separate IL execution blocks for each generic type.
  3. The idea of buffering entries needs to be more carefully thought through - I think it could result in deadlocks or at least dirty reads. Perhaps a Confirm and ConfirmWrite abstraction.
  4. I can see you are recording elapsed time at each Confirm checkpoint, but how do I output that elapsed time? This would be really helpful for our Performance Engineers to read our logs. More of a question, which may lead to more clean up :)
  5. [Edit: Digging deeper, I see that private void StartTiming() is what actually controls the stop watch. (I am not sure why this is necessary?)]

    I think you are probably already on this thought pattern already - I see the comment "// TODO: (LogActivity) generalize extensions that are triggered on boundary enter" which suggests each extension basically has an AOP cut-point that you can weave "advice" extensions into.

    This final list falls under "dealing with multiple Confirmed entries and flushing multiple entries in thread-safe ways".

    1. Perhaps not the best place to ask this, but why does Complete() null out the entry.Message if the LogActivity falls out of scope (e.g., using statement)? I don't think entry should be stateful like this.
    2. I don't see what the variable "confirmed" is for - it seems to be set but never used. It doesn't (Seem to) make sense in the presence of multiple confirm entries.
    3. Similarly, I don't see why you set requireConfirmed = false before the buffer is emptied. Isn't it possible for the buffer to add messages if the LogActivity is accessed from multiple threads?
    4. The ConfirmationList is hard-coded to stop at 100 - see Formatter.ListExpansionLimit = 100; - so this essentially means I can have at most 100 calls to Confirm actually logged. A simple test for this would be to use Its.Log and take each of the C# examples from http://www.99-bottles-of-beer.net/ and change the value to > 100 for # of beer bottles. This would also test Its.Log's output is correct across many different C# language features. You would simply find/replace Console.WriteLine(s) with Log.Write(() => s)
    jonsequitur commented 9 years ago

    I'll address a few of these here. I also opened a chat at https://gitter.im/jonsequitur/Its.Log for more open-ended design discussion because I think a lot of these questions will require some dialog and digestion before being actionable. Another thing that might be useful is example code for interface change suggestions. Its.Log has been around for over 5 years with no compatibility breaking changes, and sometimes it shows its age, but I'm happy to start sketching a v2 that incorporates new use cases and language features.

    Item 1. In general, LogActivity.Confirm is doing double-duty for the sake of terseness. One is a signal that says "I only care about logging from this code block if a particular thing happens." The other is an optional way to supply parameters to be output in the final log entry (rather than generating multiple log entries, which is what LogActivity.Trace does. This is a tradeoff, for sure, for terseness over clearly separated intentions. Its.Log often leans this way because we want logging code to stay out of the way as much as is possible.

    Item 3. Not sure I see the deadlock concern, or at least where it might occur inside Its.Log's boundaries. The dirty reads issue is interesting because it's actually part of the intent of the design (again for terseness) to be able to capture changing state via closures, e.g. the following allows me to write out the state of an instance twice:

    using (Log.Enter(() => new { request } )
    {
        // ...
    }

    Also, the expectation is that these buffers are very short-lived.

    Item 4. The emitted LogEntry has an ElapsedMilliseconds property that will be non-null when the LogEntry was emitted from a LogActivity (e.g. Log.Enter, LogActivity.Trace, or LogActivity.Exit.) It's also stamped into the output of the confirmations on exit.

    Item i. This is a historical implementation detail. Certain information has to be shared across log entries emitted by the LogActivity and this was one way to do it. It can certainly be improved.

    Item ii. Fixed: https://github.com/jonsequitur/Its.Log/commit/93a390aa05c5dd18db9e55f17743e9c7d25d18f5

    Item iii: Once a LogActivity is confirmed, log entries are emitted immediately on subsequent calls. What you're seeing here is the implementation detail enabling that.

    Item iv: This class can potentially be made public, allowing this setting to be changed. I'd also be fine with making this setting higher and letting the exit entry grow as a result if someone wants to call Confirm that many times. (Also, it's worth noting that Confirm calls within a loop update the confirmed value rather than appending to the confirmation list.)

    jzabroski commented 9 years ago

    Thanks for your thoughtful reply. I am starting to get a feel for your thought process on things.

    jzabroski commented 9 years ago

    Item 1. RE: But I don't think that terseness should be at the expense of type safety and clear interface semantics. Coercing null to true is not a clear type signature. Basically, this: Option<Func> value is clearer than this: Func value = null For an example of an Option type, see https://github.com/jzabroski/language-ext/blob/master/LanguageExt.Core/Option.cs - the root of this idea came from the language ML, where it is impossible to construct a nullable reference type (because null.Foo() is not allowed by the compiler, since you cannot call a method on something that doesn't have a value, and so you instead "lift" the null to an Option type which can dispatch on a None case via ML-style pattern matching).

    I think you also responded to Item 2 in Item 1, so:

    The idea of Trace emitting iteratively and incrementally vs. Confirm holding a buffer makes sense. I plan to take this discussion in a different direction on gitter, though - I think its clear this doesn't make sense in the current version of Its.Log and would be more for planning future features. I'll get around to discussing this after my work's sprint closes - we have 13 customers going live in the next 2 months.