Given function entry and exit events with timestamps, print the time spent in each function when it exits. How do you separate total time from self time, and handle recursion?

29.2.7 · L3 · Interview

Reported at: Uber

Predict first

What does the stack-based report print?

struct Event { let name: String; let isStart: Bool; let time: Int }
func report(_ events: [Event]) {
    var stack: [(name: String, start: Int, child: Int)] = []
    for e in events {
        if e.isStart { stack.append((e.name, e.time, 0)); continue }
        guard let top = stack.popLast(), top.name == e.name else { print("bad log at t=\(e.time)"); return }
        let total = e.time - top.start
        print("\(e.name): \(total) total, \(total - top.child) self")
        if !stack.isEmpty { stack[stack.count - 1].child += total }       // the parent does not own this time
    }
}
report([Event(name: "f", isStart: true, time: 0), Event(name: "g", isStart: true, time: 2),
        Event(name: "g", isStart: false, time: 5), Event(name: "h", isStart: true, time: 5),
        Event(name: "h", isStart: false, time: 6), Event(name: "f", isStart: false, time: 9)])
print("--- recursion")
report([Event(name: "f", isStart: true, time: 0), Event(name: "f", isStart: true, time: 1),
        Event(name: "f", isStart: false, time: 2), Event(name: "f", isStart: false, time: 4)])
print("--- mismatched")
report([Event(name: "f", isStart: true, time: 0), Event(name: "g", isStart: false, time: 1)])
  • g: 3 total, 3 self / h: 1 total, 1 self / f: 9 total, 5 self / then f: 1 total, 1 self / f: 4 total, 3 self / then bad log at t=1
  • f: 9 total, 9 self for the first log
  • it crashes on the mismatched log

Mental model. A stopwatch for each nested task: when an inner task finishes, its time is added to what the outer one has to subtract from its own.

The events form a properly nested structure, so use a stack. On entry push the function name, its start time and a child total of 0. On exit pop the top: its name must match the event (otherwise the log is corrupt, so report it), its total time is exit - start, and its self time is total minus the time its children took. Then add the total to the new top’s child, because the parent did not spend that time itself. For the first log, f calls g (3) and h (1) over 9 time units, so f’s self time is 5. O(n) time, O(depth) memory.

Recursion works because each call gets its own stack frame record, so the inner f (1 total) and the outer f (4 total, 3 self) are reported separately; do not key times by name alone or you will double count. Say what you do on bad input: an exit with no matching entry, or a mismatched name, which the check reports as bad log. This is the model of a real profiler such as Instruments’ time profile or os_signpost intervals. Reported at Uber (anonymous, unverified).

Children are subtracted from the parent’s self time, each recursive call is separate, and a mismatched exit is reported rather than crashing.

Common traps

  • Keying elapsed time by function name. Recursive calls overwrite each other.
  • Charging child time to the parent’s self time, which counts the same seconds twice.

They might follow up with

  • What if events arrive out of order across threads? Keep one stack per thread id and sort or merge by timestamp.
  • How would you print a flame-graph-style summary? Aggregate self time by call path instead of by function name.

Related questions

  • 29.2.6 Recursively walk a folder tree to count files and bytes. Compare your own recursion with…
  • 29.2.8 Given two people’s busy intervals and working hours, find the time when both are free. How is it the…
  • 29.1.2 Merge overlapping intervals: [[1,3],[8,10],[2,6],[15,18]] becomes [[1,6],[8,10],[15,18]]. How do you do it…

← Recursively walk a folder tree to count files and bytes. Compare your…   Given two people’s busy intervals and working hours, find the time… →