# \[ANN\] OwnTime - Gives alternate view of profiling data. Seeking feedback

**URL:** <https://discourse.julialang.org/t/ann-owntime-gives-alternate-view-of-profiling-data-seeking-feedback/34095>\
**Category:** Package Announcements\
**Tags:** profiling\
**Created:** [February 2, 2020, 10:23pm UTC](https://discourse.julialang.org/t/ann-owntime-gives-alternate-view-of-profiling-data-seeking-feedback/34095 "2020-02-02T22:23:16Z")\
**Posts on this page:** 8\
**Page:** 1

<div class="post-metadata">

**Author:** ![DevJac](https://avatars.discourse-cdn.com/v4/letter/d/50afbb/32.png) [@DevJac](https://discourse.julialang.org/u/DevJac)\
**Post date:** [February 2, 2020, 10:23pm UTC](https://discourse.julialang.org/t/ann-owntime-gives-alternate-view-of-profiling-data-seeking-feedback/34095/1 "2020-02-02T22:23:16Z")

</div>

> **[GitHub - DevJac/OwnTime.jl: A Julia profiling package that provides an "own...](https://github.com/DevJac/OwnTime.jl)**
>
> A Julia profiling package that provides an "own time" and "total time" view of profiling data - GitHub - DevJac/OwnTime.jl: A Julia profiling package that provides an "own ...

I am accustomed to seeing profiling data in tools like “py-spy” with “Own Time” and “Total Time” views. Julia doesn’t have this (?), so I wrote my own code for it and have made it into a package. The README explains how it works.

I’m seeking feedback and half expecting someone to tell me this was already possible with Profile or some other package. 🙂

(On that note, it does look like Profile in the standard library has been adding code to provide a similar view. This was my impression when reviewing Profile’s code on master at least.)

One of my main pain points is that it takes a loooong time to do the “lookups” that turn the pointers from Julia’s profile buffer into StackFrames. It can take several minutes on my laptop. Profile in the standard library doesn’t seem to have this problem and I’ve been meaning to look into why.

Also, I want to say that I’m quite happy with how profiling in Julia works, and pleased that it allowed me to create this library so easily.

---

<div class="post-metadata">

**Author:** ![juliohm](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/juliohm/32/215266_2.png) [@juliohm](https://discourse.julialang.org/u/juliohm)\
**Post date:** [February 2, 2020, 11:57pm UTC](https://discourse.julialang.org/t/ann-owntime-gives-alternate-view-of-profiling-data-seeking-feedback/34095/2 "2020-02-02T23:57:55Z")

</div>

Related packages for reference:

- [GitHub - timholy/ProfileView.jl: Visualization of Julia profiling data](https://github.com/timholy/ProfileView.jl)
- [GitHub - KristofferC/TimerOutputs.jl: Formatted output of timed sections in Julia](https://github.com/KristofferC/TimerOutputs.jl)

---

<div class="post-metadata">

**Author:** ![tim.holy](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/tim.holy/32/52_2.png) [@tim.holy](https://discourse.julialang.org/u/tim.holy)\
**Post date:** [February 3, 2020, 2:03am UTC](https://discourse.julialang.org/t/ann-owntime-gives-alternate-view-of-profiling-data-seeking-feedback/34095/3 "2020-02-03T02:03:40Z")

</div>

On master you can do pretty much the same thing with `Profile.print(format=:flat, sortedby=:overhead)`, but indeed earlier Julia versions do not have this capability. So this is a nice addition.

You’re correct that instruction pointer lookup is _insanely_ slow. Make sure you’re not doing redundant work, for instance use `Dict(ip=>Profile.lookup(ip) for ip in unique(data))` so that you look up each pointer only once.

---

<div class="post-metadata">

**Author:** ![DevJac](https://avatars.discourse-cdn.com/v4/letter/d/50afbb/32.png) [@DevJac](https://discourse.julialang.org/u/DevJac)\
**Post date:** [February 3, 2020, 2:28am UTC](https://discourse.julialang.org/t/ann-owntime-gives-alternate-view-of-profiling-data-seeking-feedback/34095/4 "2020-02-03T02:28:44Z")

</div>

@tim.holy

Thank you very much for the tip. I was not doing that, but I will. I also never knew about the `unique` function, which looks very handy.

Will Profile in the standard library ever provide a way to filter StackFrames like I’ve done? I’d be willing to work on it if you think it’s a good idea?

---

<div class="post-metadata">

**Author:** ![tim.holy](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/tim.holy/32/52_2.png) [@tim.holy](https://discourse.julialang.org/u/tim.holy)\
**Post date:** [February 3, 2020, 2:38am UTC](https://discourse.julialang.org/t/ann-owntime-gives-alternate-view-of-profiling-data-seeking-feedback/34095/5 "2020-02-03T02:38:32Z")

</div>

Your filtering looks nice, and I don’t know of anyone working on that in Profile or anywhere else. As long as one doesn’t break backward compatibility, new features in the standard library are welcome. Since `Profile.print` doesn’t currently take a function argument I’d guess there’s a good chance you might be able to pull this off, though you’d have to consider what to do for `tree` format printing.

I might also CC @jameson to see if he has any thoughts.

---

<div class="post-metadata">

**Author:** ![jlchan](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/jlchan/32/10958_2.png) [@jlchan](https://discourse.julialang.org/u/jlchan)\
**Post date:** [February 9, 2020, 2:12pm UTC](https://discourse.julialang.org/t/ann-owntime-gives-alternate-view-of-profiling-data-seeking-feedback/34095/6 "2020-02-09T14:12:18Z")

</div>

I like the idea of this package, especially filtering the stack frames. I’m having some trouble reproducing the example, however. Profiling and using owntime() (with and without filters) in Juno gives me

```julia
julia> owntime()
 [1] 3% => eval(::Module, ::Any) at boot.jl:330
 [2] 2% => _fast at reduce.jl:462 [inlined]
 [3] 1% => Type at boot.jl:408 [inlined]

julia> owntime(stackframe_filter=filecontains("demo_mycode.jl"))
 [1] 2% => myfunc() at demo_mycode.jl:3
 [2] 1% => myfunc() at demo_mycode.jl:2

```

Should I expect this sort of output?

---

<div class="post-metadata">

**Author:** ![DevJac](https://avatars.discourse-cdn.com/v4/letter/d/50afbb/32.png) [@DevJac](https://discourse.julialang.org/u/DevJac)\
**Post date:** [February 9, 2020, 7:44pm UTC](https://discourse.julialang.org/t/ann-owntime-gives-alternate-view-of-profiling-data-seeking-feedback/34095/7 "2020-02-09T19:44:02Z")

</div>

Maybe. Try looking at your profiling data with other tools as well to see what’s going on. You can still use the tree view in the standard libraries Profile package, for example. That should show you where time is being spent.

I would guess you didn’t “warm up” your function, and that the JIT is using most of the time. Try calling the function several times in a loop and profile that.

---

<div class="post-metadata">

**Author:** ![jlchan](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/jlchan/32/10958_2.png) [@jlchan](https://discourse.julialang.org/u/jlchan)\
**Post date:** [February 9, 2020, 8:41pm UTC](https://discourse.julialang.org/t/ann-owntime-gives-alternate-view-of-profiling-data-seeking-feedback/34095/8 "2020-02-09T20:41:03Z")

</div>

I did warm up the function, but I think I figured it out - the Juno REPL behaves slightly differently from the regular REPL. I get more reasonable results if I run it the standard REPL.