diff --git a/chronos/config.nim b/chronos/config.nim index 7be3e98..6e8033e 100644 --- a/chronos/config.nim +++ b/chronos/config.nim @@ -31,7 +31,12 @@ const chronosStackTrace* {.booldefine.}: bool = defined(chronosDebug) ## Include stack traces in futures for creation and completion points - chronosFutureId* {.booldefine.}: bool = defined(chronosDebug) + chronosProfiling* {.booldefine.} = defined(chronosProfiling) + ## Enable instrumentation callbacks which are called at + ## the start, pause, or end of a Future's lifetime. + ## Useful for implementing metrics or other instrumentation. + + chronosFutureId* {.booldefine.}: bool = defined(chronosDebug) or defined(chronosProfiling) ## Generate a unique `id` for every future - when disabled, the address of ## the future will be used instead @@ -79,11 +84,6 @@ const "" ## OS polling engine type which is going to be used by chronos. - chronosProfiling* {.booldefine.} = defined(chronosProfiling) - ## Enable instrumentation callbacks which are called at - ## the start, pause, or end of a Future's lifetime. - ## Useful for implementing metrics or other instrumentation. - when defined(chronosStrictException): {.warning: "-d:chronosStrictException has been deprecated in favor of handleException".} # In chronos v3, this setting was used as the opposite of diff --git a/chronos/profiler.nim b/chronos/profiler.nim index 0953bc3..12e36ea 100644 --- a/chronos/profiler.nim +++ b/chronos/profiler.nim @@ -1,21 +1,17 @@ import ./config when chronosProfiling: - import futures - import ./profiler/[events, metrics] + import ./futures + import ./profiler/metrics - export futures, events, metrics + export futures, metrics when not chronosFutureId: {.error: "chronosProfiling requires chronosFutureId to be enabled".} - var futureMetrics {.threadvar.}: ProfilerMetrics - proc getMetrics*(): ProfilerMetrics = ## Returns metrics for the current event loop. - result = futureMetrics - - proc setFutureEventCallback*(): void = + result = metrics.getMetrics() proc enableProfiling*() = ## Enables profiling on the current event loop. diff --git a/chronos/profiler/metrics.nim b/chronos/profiler/metrics.nim index 69347ef..5670d5a 100644 --- a/chronos/profiler/metrics.nim +++ b/chronos/profiler/metrics.nim @@ -2,36 +2,18 @@ import std/tables import std/options import ./events -import ../[timer, srcloc] +import ../[futures, timer, srcloc] export timer, tables, srcloc type Event* = object futureId: uint - loc: SrcLoc - state: FutureState - event*: FutureExecutionEvent + location: SrcLoc + event*: FutureEvent + state*: FutureState timestamp*: Moment -proc processEvent*(self: var ProfilerMetrics, event: Event): void - -proc handleFutureEvent*(future: FutureBase, - event: FutureExecutionEvent): void {.nimcall.} = - {.cast(gcsafe).}: - let extendedState = case state: - of Init: ExtendedFutureState.Pending - of Run: ExtendedFutureState.Running - of Pause: ExtendedFutureState.Paused - of Finish: future.internalState.toExtendedEvent() - - processEvent Event( - future: future, - loc: future.internalLocation[Create][], - state: future.internalState, - event: event, - timestamp: Moment.now() - ) type AggregateFutureMetrics* = object @@ -42,7 +24,8 @@ type callCount*: uint RunningFuture* = object - state*: ExtendedFutureState + lastState: FutureState + lastEvent*: FutureEvent created*: Moment lastStarted*: Moment timeToFirstPause*: Duration @@ -59,6 +42,12 @@ type partials: Table[uint, RunningFuture] totals*: MetricsTotals +var futureMetrics {.threadvar.}: ProfilerMetrics + +proc getMetrics*(): ProfilerMetrics = + ## Returns metrics for the current event loop. + result = futureMetrics + proc `execTimeWithChildren`*(self: AggregateFutureMetrics): Duration = self.execTime + self.childrenExecTime @@ -80,7 +69,8 @@ proc futureCreated(self: var ProfilerMetrics, event: Event): void = self.partials[event.futureId] = RunningFuture( created: event.timestamp, - state: Pending, + lastEvent: event.event, + lastState: event.state, ) proc bindParent(self: var ProfilerMetrics, metrics: ptr RunningFuture): void = @@ -96,21 +86,22 @@ proc futureRunning(self: var ProfilerMetrics, event: Event): void = assert self.partials.hasKey(event.futureId), $event.location self.partials.withValue(event.futureId, metrics): - assert metrics.state == Pending or metrics.state == Paused, + assert metrics.lastState == Pending or metrics.lastEvent == Pause, $event.location self.bindParent(metrics) self.callStack.push(event.futureId) metrics.lastStarted = event.timestamp - metrics.state = Running + metrics.lastEvent = event.event + metrics.lastState = event.state proc futurePaused(self: var ProfilerMetrics, event: Event): void = assert self.partials.hasKey(event.futureId), $event.location assert event.futureId == self.callStack.pop(), $event.location self.partials.withValue(event.futureId, metrics): - assert metrics.state == Running, $event.location + assert metrics.lastEvent == Run, $event.location let segmentExecTime = event.timestamp - metrics.lastStarted @@ -118,11 +109,12 @@ proc futurePaused(self: var ProfilerMetrics, event: Event): void = metrics.timeToFirstPause = segmentExecTime metrics.partialExecTime += segmentExecTime metrics.pauses += 1 - metrics.state = Paused + metrics.lastEvent = event.event + metrics.lastState = event.state proc futureCompleted(self: var ProfilerMetrics, event: Event): void = self.partials.withValue(event.futureId, metrics): - if metrics.state == Running: + if metrics.lastEvent == Run: self.futurePaused(event) let location = event.location @@ -147,11 +139,21 @@ proc futureCompleted(self: var ProfilerMetrics, event: Event): void = proc processEvent*(self: var ProfilerMetrics, event: Event): void = case event.event: - of Init: self.futureCreated(event) - of Run: self.futureRunning(event) - of Pause: self.futurePaused(event) - of Finish: self.futureCompleted(event) + of FutureEvent.Init: self.futureCreated(event) + of FutureEvent.Run: self.futureRunning(event) + of FutureEvent.Pause: self.futurePaused(event) + of FutureEvent.Finish: self.futureCompleted(event) proc processAllEvents*(self: var ProfilerMetrics, events: seq[Event]): void = for event in events: - self.processEvent(event) \ No newline at end of file + self.processEvent(event) + +proc handleFutureEvent*(future: FutureBase, + event: FutureEvent): void {.nimcall.} = + {.cast(gcsafe).}: + futureMetrics.processEvent Event( + event: event, + location: future.internalLocation[Create][], + state: future.internalState, + timestamp: Moment.now() + ) \ No newline at end of file diff --git a/tests/profiler/utils.nim b/tests/profiler/utils.nim index 966a875..3e1dfe8 100644 --- a/tests/profiler/utils.nim +++ b/tests/profiler/utils.nim @@ -4,7 +4,8 @@ import ".."/".."/chronos/profiler type SimpleEvent* = object procedure*: string - state*: ExtendedFutureState + # state*: FutureState + event*: FutureEvent # XXX this is sort of bad cause we get global state all over, but the fact we # can't use closures on callbacks and that callbacks themselves are just