How to use @profile in Pluto?

[gdalle]

When I profile my own functions in Pluto, I often end up with three external methods (task_done_hook, wait and pop_task from task.jl in Base) taking most of the CPU time. See the example below, taken from my course material.

From what I understand, it could be linked to multiprocessing, more precisely the fact that Pluto launches each notebook on a separate worker (see #300). Is there a workaround to get precise profiling without the multiprocessing stuff?

[gdalle]

I found a workaround that doesn't act on the profiling itself but on the generated FlameGraph. It selects the subtree of the FlameGraph where the code is actually run, and discards the time spent waiting on the designated worker. I think it may work as long as the code we profile doesn't use Pluto itself.

using AbstractTrees, FlameGraphs

function select_pluto_subgraph(g)
    for n in PreOrderDFS(g)
        if (
            endswith(string(n.data.sf.file), "PlutoRunner.jl") &&
            endswith(string(n.data.sf.func), "run_inside_trycatch")
        )
            return n
        end
    end
end

From there, if we want to profile a function myfunc, all we have to do is run

using Profile, ProfileSVG

Profile.clear()
@profile f(args...)
ProfileSVG.view(select_pluto_subgraph(flamegraph()))

@fonsp does this look right to you? Would it be interesting to wrap this in a macro, say @plutoprofile? Would it belong in Pluto itself or rather in a mini-package outside?

[VarLad]

This looks awesome! Thanks for putting in the work!

[gdalle]

See https://github.com/gdalle/PlutoProfile.jl

[fonsp]

Thanks for pointing this out and for investigating the issue!

Note the difference: Multiprocessing (using Distributed, different OS process for each notebook) is not the same as multitasking (@async), which is again different from multithreading (running tasks in parallel within the same process).

But they are related: We use multiprocessing to manage different notebook processing, which (I believe) spawns tasks on the notebook process to execute actions in, including code execution. We do not use multithreading in the notebook process (I think).

[gdalle]

I must say I wasn't aware of the subtle difference with tasks, but today I learned!

[fonsp]

It surprises me that internal Pluto code is showing up in the profile. We use eval in boot.jl:360 to execute your code, but your code is doing the profile. So the profile is somehow going "up the call stack". Strange!

[gdalle]

I don't think it is so surprising. Since @profile works by periodically sampling backtraces during the call, there is no reason why it wouldn't go all the way up, right?

[fonsp]

Right, that explains it! Maybe this could be fixed in the profiling package: it can check the depth from which it is called, and discard everything below from the profile. This would get rid of the extra frames and fix your issue.