I'm trying to find the bottleneck in my code - the function that consumes most of the time. But I don't understand how to interpret the nimprof report as it seems like it has duplicate entries.
In its default settings nimprof report included std and system functions, I altered it a little bit, excluding Nim std and system functions (I filter out the stack trace, excluding system functions).
It kinda works, but produces strange results containing the duplicates, I was using code example from Nim in Action, Profiling your code
The code playground:
import strutils, custom_nimprof
proc ab() =
echo("Found letter")
proc num() =
echo("Found number")
proc diff() =
echo("Found something else")
proc analyse(x: string) =
var i = 0
while i < x.len:
case x[i]
of Letters: ab()
of {'0' .. '9'}: num()
else: diff()
i.inc
for i in 0 .. 10000:
analyse("uyguhijkmnbdv44354gasuygiuiolknchyqudsayd12635uha")
It produces the following result (with excluded nim core functions):
writing profile_results.txt...
total executions of each stack trace:
Entry: 1/5 Calls: 67/125 = 53.60% [sum: 67; 67/125 = 53.60%]
/main.nim: analyse 125/125 = 100.00%
/main.nim: main 125/125 = 100.00%
Entry: 2/5 Calls: 38/125 = 30.40% [sum: 105; 105/125 = 84.00%]
/main.nim: ab 50/125 = 40.00%
/main.nim: analyse 125/125 = 100.00%
/main.nim: main 125/125 = 100.00%
Entry: 3/5 Calls: 12/125 = 9.60% [sum: 117; 117/125 = 93.60%]
/main.nim: ab 50/125 = 40.00%
/main.nim: analyse 125/125 = 100.00%
/main.nim: main 125/125 = 100.00%
Entry: 4/5 Calls: 5/125 = 4.00% [sum: 122; 122/125 = 97.60%]
/main.nim: num 8/125 = 6.40%
/main.nim: analyse 125/125 = 100.00%
/main.nim: main 125/125 = 100.00%
Entry: 5/5 Calls: 3/125 = 2.40% [sum: 125; 125/125 = 100.00%]
/main.nim: num 8/125 = 6.40%
/main.nim: analyse 125/125 = 100.00%
/main.nim: main 125/125 = 100.00%
You may notice that the call stack in entries 2/5 and 3/5 is the same. Why?
Aren't they supposed to be grouped together?