# Need advice: tracing function calls non-invasively
**URL:** https://discourse.julialang.org/t/need-advice-tracing-function-calls-non-invasively/97584
**Category:** General Usage
**Tags:** question
**Created:** [April 17, 2023, 7:06pm UTC](https://discourse.julialang.org/t/need-advice-tracing-function-calls-non-invasively/97584 "2023-04-17T19:06:18Z")
**Posts on this page:** 8
**Page:** 1
### Author:  [@sumiya11](https://discourse.julialang.org/u/sumiya11)
#### Post date: [April 17, 2023, 7:06pm UTC](https://discourse.julialang.org/t/need-advice-tracing-function-calls-non-invasively/97584/1 "2023-04-17T19:06:18Z")
Hi everyone !
I want to record statistics about calls of some functions – the number of calls, runtime, etc. – without modifying the function code (or the code in the function parent module).
I have the following prototype (see example in readme):
[sumiya11/TraceIt.jl: Trace function calls with no overhead (github.com)](https://github.com/sumiya11/TraceIt.jl)
It does something like this:
```julia
using TraceIt
@trace Base.sum; @trace Base.log
reduce(log, map(sum, [[1, 2, 3], [4, 5], [6]]))
printtrace() # mostly compilation time
Func. ╲ Stat. │ called mem, b gctime, s time, s time, %
──────────────┼──────────────────────────────────────────────
sum │ 3 12272 0.0 0.0102889 54.94 %
log │ 2 138281 0.0 0.0084373 45.06 %
──────────────┼──────────────────────────────────────────────
Σ │ 5 150553 0.0 0.0187262 100.0 %
```
Internally, `@trace Foo.foo` does
```julia
primary_world = Base.get_world_counter()
@eval Foo function foo(x)
#= record statistics globally =#
@info "foo is now traced!"
return Base.invoke_in_world($primary_world, foo, x)
end
```
As I understand, this is not ideal. Tracing the functions that are nested will become complicated, and `Base.invoke_in_world` itself has overhead. (also, I realize that `@eval` inside of a macro is a bad idea; please bear with me :^D)
Is there a way to implement such tracing that could be better ?
Thank you !
–Alex
---
### Author:  [@SteffenPL](https://discourse.julialang.org/u/SteffenPL)
#### Post date: [April 18, 2023, 11:34am UTC](https://discourse.julialang.org/t/need-advice-tracing-function-calls-non-invasively/97584/2 "2023-04-18T11:34:19Z")
Is it important that you get the exact numbers of function calls?
Otherwise, a sampling profiler could do the job, e.g.
[https://www.julia-vscode.org/docs/dev/userguide/profiler/](https://www.julia-vscode.org/docs/dev/userguide/profiler/)
Since Julia 1.8 that includes also information about GC, dynamic dispatch etc.
* * *
Maybe you could use Revise and [GitHub - timholy/CodeTracking.jl: It's editing-time, do you know where your methods are?](https://github.com/timholy/CodeTracking.jl)
With the `@code_expr` you could get the expression for a particular method and then you can modify the method to define your own variant which does the tracing. That way you avoid using different worlds.
(Anyway, nice prototype 🙂 )
---
### Author:  [@Tomas\_Pevny](https://discourse.julialang.org/u/Tomas_Pevny)
#### Post date: [April 18, 2023, 2:46pm UTC](https://discourse.julialang.org/t/need-advice-tracing-function-calls-non-invasively/97584/3 "2023-04-18T14:46:11Z")
I have created a thing called “logging profiler” as a toy example when teaching generated functions. It is implemented here [GitHub - pevnak/LoggingProfiler.jl: A profiler that logs beggning and and of each function](https://github.com/pevnak/LoggingProfiler.jl), but I have touch it for a while and not sure about the state. If it is what you are looking for, I will be happy to help you to make this work. What stopped me to finish the project was that I did not know, how to deal with multi-threadding properly.
---
### Author:  [@goerz](https://discourse.julialang.org/u/goerz)
#### Post date: [April 18, 2023, 4:03pm UTC](https://discourse.julialang.org/t/need-advice-tracing-function-calls-non-invasively/97584/4 "2023-04-18T16:03:26Z")
There’s [GitHub - carstenbauer/TimerOutputsTracked](https://github.com/carstenbauer/TimerOutputsTracked)
---
### Author:  [@sumiya11](https://discourse.julialang.org/u/sumiya11)
#### Post date: [April 18, 2023, 5:06pm UTC](https://discourse.julialang.org/t/need-advice-tracing-function-calls-non-invasively/97584/5 "2023-04-18T17:06:05Z")
> Is it important that you get the exact numbers of function calls?
I think so. In the future potentially I’d like to also record information about function input values, samplifing profiling won’t be suitable.
Yeah, generating the expression for a method from scratch can be an option, thanks for the idea. `CodeTracking.@code_expr` is neat !
---
### Author:  [@sumiya11](https://discourse.julialang.org/u/sumiya11)
#### Post date: [April 18, 2023, 6:11pm UTC](https://discourse.julialang.org/t/need-advice-tracing-function-calls-non-invasively/97584/6 "2023-04-18T18:11:12Z")
thanks for the suggestions @Tomas_Pevny, @goerz !
`TimerOutputsTracked` is very cool. Though something seems broken on my example:
```julia
julia> using TimerOutputsTracked
julia> TimerOutputsTracked.track([Base.sum, Base.log])
julia> f() = reduce(log, map(sum, [[1, 2, 3], [4, 5], [6]]))
f (generic function with 1 method)
julia> @timetracked f()
8.783266944837743
julia> timings_tracked()
────────────────────────────────────────────────────────────────────
Time Allocations
─────────────────────── ────────────────────────
Tot / % measured: 5.80s / 0.0% 16.1MiB / 0.0%
Section ncalls time %tot avg alloc %tot avg
────────────────────────────────────────────────────────────────────
────────────────────────────────────────────────────────────────────
```
* * *
I’ll check out `LoggingProfiler.jl`, thanks for the pointer
---
### Author:  [@sumiya11](https://discourse.julialang.org/u/sumiya11)
#### Post date: [April 18, 2023, 6:22pm UTC](https://discourse.julialang.org/t/need-advice-tracing-function-calls-non-invasively/97584/7 "2023-04-18T18:22:46Z")
Once I understand how these solutions work internally, would be interesting to compare their runtime overhead for tracking a small function
---
### Author:  [@Tomas\_Pevny](https://discourse.julialang.org/u/Tomas_Pevny)
#### Post date: [April 18, 2023, 8:52pm UTC](https://discourse.julialang.org/t/need-advice-tracing-function-calls-non-invasively/97584/8 "2023-04-18T20:52:41Z")
They are based on the same principle. The lecture which explains mechanism behind logging profiler is [Lecture · Scientific Programming in Julia](https://juliateachingctu.github.io/Scientific-Programming-in-Julia/dev/lecture_09/lecture/)
Sorry for being brief, i am on ipad