0

I have some code that does a lot of work. It does enough work over enough time that we don't generally care about precise accuracy (i.e. to the millisecond), but being off by more than a minute would not be useful. We have a stored procedure that we call to log the start of a task, and the end of the task. Right now we have a lot of code that looks like this:

Logger.LogTaskStart(taskName); // do stuff Logger.LogTaskEnd(taskName); 

Where the two methods save the metadata, which is eventually persisted via the afore-mentioned stored procedure. We also have some places where we may sometimes log timing information, but not always b/c it is either too much noise, or it usually doesn't have a problem.

if (debug) Logger.LogTaskStart(taskName); // do stuff if (debug) Logger.LogTaskEnd(taskName); 

We've had issues where we inadvertently mismatch a start & end, or we only put one under a debug flag, etc. We've considered creating a pretty simple logger class that implements IDisposable to do it for us, such that we'd just do this (assume that the constructor starts the timer RAII style, and that Dispose stops it)

using (new Logger(taskName, debug)) { // Do stuff } 

As best as we can tell, this should just compile to approximately this:

Logger loggerThing = null; try { loggerThing = new Logger(taskName, debug); // Do stuff } finally { loggerThing?.Dispose(); } 

As such, it seems reasonably safe to use this for our larger tasks with enough granularity to be able to say "that ran a reasonable amount of time" or "that ran substantially faster/slower than normal". Are we right?

From some reading, I found the following articles, code samples, and SO Q&A. We clearly aren't the only people to have thought of this or something similar, but no-one seems to have ever given a clear and definitive answer to the question of "how timely can we assume Dispose will be called, and how reliable would timing results of that be?" Given the first post below, regarding how using is just syntactic sugar, we're inclined to think that is the case.

3
  • 1
    So clearly you have reasons not to trust the answer from question you've linked to... but why? What exactly is missing to clarify to you how Dispose is called by using? Commented Apr 12, 2019 at 22:27
  • 1
    What do you mean by timely? Dispose is going to be called at the end of the using block. Commented Apr 12, 2019 at 23:27
  • stackoverflow.com/q/14830534/17034 Commented Apr 13, 2019 at 5:03

1 Answer 1

1

The Dispose method is called immediately after the code in the using statement. To confirm this we can take a peek at the IL that is generated from a using statement:

The following simple example:

 class Program { static void Main() { using (new TestClass()) { Console.WriteLine("Do work"); } } } class TestClass : IDisposable { public void Dispose() { Console.WriteLine("disposed"); } } 

Produces the following IL.

Program.Main: IL_0000: nop IL_0001: newobj UserQuery+TestClass..ctor IL_0006: stloc.0 IL_0007: nop IL_0008: ldstr "Do work" IL_000D: call System.Console.WriteLine IL_0012: nop IL_0013: nop IL_0014: leave.s IL_0021 IL_0016: ldloc.0 IL_0017: brfalse.s IL_0020 IL_0019: ldloc.0 IL_001A: callvirt System.IDisposable.Dispose IL_001F: nop IL_0020: endfinally IL_0021: ret Program..ctor: IL_0000: ldarg.0 IL_0001: call System.Object..ctor IL_0006: nop IL_0007: ret TestClass.Dispose: IL_0000: nop IL_0001: ldstr "disposed" IL_0006: call System.Console.WriteLine IL_000B: nop IL_000C: ret TestClass..ctor: IL_0000: ldarg.0 IL_0001: call System.Object..ctor IL_0006: nop IL_0007: ret 

Here we can see the dispose method being called immediately after the code in the using statement.

Sign up to request clarification or add additional context in comments.

Comments

Start asking to get answers

Find the answer to your question by asking.

Ask question

Explore related questions

See similar questions with these tags.