Gadfly first-plot profiling results #1275
Comments
|
there's also PackageCompiler. i'm close to merging instructions as to how to use it with Gadfly. |
|
My hunch is that this line is contributing a lot: I believe |
|
Here's another view into Gadfly: function plot_min()
# function render_prepare
@time datas = Gadfly.Data(x=1:10, y=rand(10), xend=1:10, yend=zeros(10))
@time scales=Dict{Symbol,Gadfly.ScaleElement}(:x=>Scale.x_continuous(), :y=>Scale.y_continuous())
@time aes = Scale.apply_scales(collect(values(scales)), datas)
@time coord = Coord.cartesian()
@time stats = Gadfly.StatisticElement[Stat.xticks(), Stat.yticks()]
@time Stat.apply_statistics(stats, scales, coord, aes[1])
# function render_prepared
@time plot_context = Coord.apply_coordinate(coord, aes, scales)
@time layer_themes = [Theme(default_color="green"), Theme(default_color="orange")]
@time geom_ctxs = render.([Geom.point(), Geom.hair()], layer_themes, aes)
@time guide_ctxs = render.([Guide.xticks(), Guide.yticks()], [Theme()], aes)
@time compose!(plot_context, (context(), geom_ctxs...))
@time tbl = Guide.layout_guides(plot_context, coord, Theme(), [x[1] for x in guide_ctxs]...)
@time p = compose!(context(), tbl)
@time draw(PNG(), p)
@time draw(SVG(), p)
return nothing
endjulia> plot_min()
0.000017 seconds (7 allocations: 1.266 KiB)
0.056249 seconds (18.63 k allocations: 970.111 KiB, 39.13% gc time)
0.420187 seconds (364.51 k allocations: 20.095 MiB)
0.000002 seconds (3 allocations: 352 bytes)
0.000000 seconds (3 allocations: 224 bytes)
1.856495 seconds (1.21 M allocations: 62.480 MiB, 2.68% gc time)
0.230436 seconds (184.17 k allocations: 9.604 MiB, 6.87% gc time)
0.763589 seconds (48.97 k allocations: 2.429 MiB)
4.916489 seconds (6.29 M allocations: 325.060 MiB, 5.63% gc time)
3.684096 seconds (3.50 M allocations: 176.035 MiB, 3.75% gc time)
0.009549 seconds (1.78 k allocations: 92.083 KiB)
1.432211 seconds (974.65 k allocations: 50.617 MiB, 2.53% gc time)
0.000000 seconds (2 allocations: 176 bytes)
11.263422 seconds (11.94 M allocations: 615.439 MiB, 4.89% gc time)
5.497432 seconds (8.27 M allocations: 419.332 MiB, 3.10% gc time) |
|
I got a marginal speedup (5%-10%) in first-plot compile by going in and removing the splatting from a lot of internal methods. I'll pretty that up into a PR soon. To be honest, I thought the benefit there would be bigger based on what I was seeing in the profiling results. The next thing I'm gonna try is seeing if I can change some of the internal structs that don't have concretely typed fields to have strictly concrete fields; might see a speedup there I think. |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
I got curious about "time to first plot" and did some profiling to see
where most of the problem was coming from. I thought it might be
useful to share the results here for other's reference so that you
don't have to figure out the proper incantations of
Profileyourself. The approximate recipe for reproducing this is:
Here's the results of the profiling in tree-view:
The big thing that jumped out to me from this is that during the
"first plot", over 75% of time (this plot took roughly 50 seconds to
finish) is spent in Gadfly versus only ~25% spent in Compose. So it
isn't actually drawing the plot that's taking long precompile times
but all the work Gadfly does in the various
renderfunctions beforesending to Compose. So that's the place to start investigating.
For contrast, here's the profile dump for subsequent calls to
plot:It's the reverse of the first-plot situation: almost 70% of time is
spent in Compose with relatively little in Gadfly.
When I get a chance, I'll probably do a bit more digging on this
subject, but like I said, I thought this might be useful or spark some
thoughts for others in the meantime. It's unclear to me how much of
this first-call latency can be mitigated by package developers, but
it's probably worth a shot.
The text was updated successfully, but these errors were encountered: