public void Stopwatch_WhenMultipleOperations_ThenElapsedIncrements() { using (var trace = new TraceListenerScope()) { var usable = // Stopwatch usable starts counting the moment somebody calls Use(). from stopwatch in Usable.Stopwatch() from outer in Usable.Using(() => new TraceSourceScope("outer")) // Snapshot elapsed to know how long it took to instantiate outer. let elapsedOuter = stopwatch.Elapsed from inner in new TraceSourceScope("inner") // Snapshot elapsed to know how long it took to instantiate inner. let elapsedInner = stopwatch.Elapsed - elapsedOuter // Snapshot elapsed to know how long it took for the entire operation. let elapsedTotal = stopwatch.Elapsed // Return computed value together with all the timing information. select new { Value = string.Join('/', outer.Operation, inner.Operation, "value").Trace(), ElapsedOuter = elapsedOuter, ElapsedInner = elapsedInner, ElapsedTotal = elapsedTotal, }; var expectedTrace = new string[] { "Enter: outer", " Enter: inner", " Value: outer/inner/value", " Leave: inner", "Leave: outer", }; Assert.Equal(new string[0], trace.ToLines()); var value = usable.Value(); Assert.Equal("outer/inner/value", value.Value); Assert.True(value.ElapsedOuter < value.ElapsedTotal); Assert.True(value.ElapsedInner < value.ElapsedTotal); Assert.Equal(expectedTrace, trace.ToLines()); } Assert.Equal(0, Trace.IndentLevel); }