# Slow compilation, i think, not sure how to debug

**URL:** <https://discourse.julialang.org/t/slow-compilation-i-think-not-sure-how-to-debug/39741>\
**Category:** New to Julia\
**Created:** [May 19, 2020, 5:40am UTC](https://discourse.julialang.org/t/slow-compilation-i-think-not-sure-how-to-debug/39741 "2020-05-19T05:40:48Z")\
**Posts on this page:** 16\
**Page:** 1

<div class="post-metadata">

**Author:** ![purplishrock](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/purplishrock/32/13451_2.png) [@purplishrock](https://discourse.julialang.org/u/purplishrock)\
**Post date:** [May 19, 2020, 5:40am UTC](https://discourse.julialang.org/t/slow-compilation-i-think-not-sure-how-to-debug/39741/1 "2020-05-19T05:40:48Z")

</div>

I have a very simple program, on the order of 50 lines, which uses CSV to read a 2 entry-per-line, 448 line CSV file.  
i have put @time on the using statements and they are normal (oh why oh why is PyPlot 8s ?!)  
total time, about 11s.

the program does not appear to start to run for at least another 10-15s. i can’t provide the program because work, blah, blah, blah. i’m hoping to create a separate copy of what it’s doing so i can post. so i thought for sure it was a compilation issue, but then i stuck an @time on the CSV.File statement and it came back about 8.5s which seemed in possible. So i ran the CSV.File by hand in the repl and it came back at 0.2s, which is what you would expect.

So now i can’t figure out if the @time in the program is correct and there’s just some other weird run-time issue, or if @time is returning a bogus number.

regardless i’m waiting 30-35s for a 50 line program to read a 448 line CSV file and perform some _really_ simple math on the contents.

I was hoping to get some help on how to start to debug this. My plan right now is to start distributing a lot of @time calls to see if it’s more run-time vs compilation.

Is there some (relatively simple) way to get metrics on what the compiler is doing ?

it’s a very weird situation. I’ve waited this long for some programs but they were considerably more complicated and pulled in a LOT of other modules. This one is ridiculously simple and taking a really long time.

---

<div class="post-metadata">

**Author:** ![Oscar\_Smith](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/oscar_smith/32/25343_2.png) [@Oscar\_Smith](https://discourse.julialang.org/u/Oscar_Smith)\
**Post date:** [May 19, 2020, 5:43am UTC](https://discourse.julialang.org/t/slow-compilation-i-think-not-sure-how-to-debug/39741/2 "2020-05-19T05:43:35Z")

</div>

What version of Julia are you using? Recent ones have improved lot in these areas.

---

<div class="post-metadata">

**Author:** ![purplishrock](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/purplishrock/32/13451_2.png) [@purplishrock](https://discourse.julialang.org/u/purplishrock)\
**Post date:** [May 19, 2020, 5:47am UTC](https://discourse.julialang.org/t/slow-compilation-i-think-not-sure-how-to-debug/39741/3 "2020-05-19T05:47:32Z")

</div>

aargh, I should know better than to post a question like this without the version.

I’m using 1.4.1

i’m using 1.3.1 at home. i’ll try and get the code onto my home machine and see what 1.3.1 does with it.

---

<div class="post-metadata">

**Author:** ![mauro3](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/mauro3/32/292_2.png) [@mauro3](https://discourse.julialang.org/u/mauro3)\
**Post date:** [May 19, 2020, 6:37am UTC](https://discourse.julialang.org/t/slow-compilation-i-think-not-sure-how-to-debug/39741/4 "2020-05-19T06:37:37Z")

</div>

This might be long compile times of CSV.jl. Have you tried using `readdlm` of `DelimitedFiles`? That should be a lot faster, at least for small files, as DelimitedFiles is part of the standard library and thus fully compiled (and not just precompiled).

---

<div class="post-metadata">

**Author:** ![bernhard](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/bernhard/32/2619_2.png) [@bernhard](https://discourse.julialang.org/u/bernhard)\
**Post date:** [May 19, 2020, 7:05am UTC](https://discourse.julialang.org/t/slow-compilation-i-think-not-sure-how-to-debug/39741/5 "2020-05-19T07:05:38Z")

</div>

I think this is the (pre?)compilation time of CSV.jl which is always rather slow on first usage.

Is it possible for you to (re) use a existing julia session to circumvent this?

For reference, it takes me 15.7 seconds to read a 116719 row file (43 columns) for the first time. Second time is 2.78 seconds

---

<div class="post-metadata">

**Author:** ![purplishrock](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/purplishrock/32/13451_2.png) [@purplishrock](https://discourse.julialang.org/u/purplishrock)\
**Post date:** [May 19, 2020, 5:32pm UTC](https://discourse.julialang.org/t/slow-compilation-i-think-not-sure-how-to-debug/39741/6 "2020-05-19T17:32:02Z")

</div>

wow, absolutely crazy results.  
Everything is being run twice.

Using CSV

> $ time julia pulse.jl data/pulse\_20200514\_234617.csv  
> real 1m39.590s  
> user 0m0.015s  
> sys 0m0.093s

This run still has the “using CSV” statement in it, but I am using a simple reader to read the file, i.e. CSV is NOT being used to read the file. This shows that there is still something very wrong even with the CSV.File function, as the run time drops about 27 s.

> $ time julia pulse.jl data/pulse\_20200514\_234617.csv
> 
> real 1m12.716s  
> user 0m0.015s  
> sys 0m0.077s

remove “using CSV”, but I left in “using DataFrames”. -40 seconds. ouch.

> $ time julia pulse.jl data/pulse\_20200514\_234617.csv
> 
> real 0m31.559s  
> user 0m0.031s  
> sys 0m0.061s

and finally. i get rid of both “using CSV” and “using DataFrames”, since i’m only using DataFrames because i couldn’t figure out how to make CSV give me an array. lol.

> time julia pulse.jl data/pulse\_20200514\_234617.csv
> 
> real 0m21.711s  
> user 0m0.000s  
> sys 0m0.140s

CSV is effectively unusable for me ☹

DataFrames isn’t so great either, but the good news is that my routines that use DataFrames is processing DB accesses and doing a fair amount of work and so the overhead is not as obvious.

I’ll try out DelimitedFiles. Didn’t even know it existed.

Thanks for your help.

---

<div class="post-metadata">

**Author:** ![purplishrock](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/purplishrock/32/13451_2.png) [@purplishrock](https://discourse.julialang.org/u/purplishrock)\
**Post date:** [May 19, 2020, 7:36pm UTC](https://discourse.julialang.org/t/slow-compilation-i-think-not-sure-how-to-debug/39741/7 "2020-05-19T19:36:41Z")

</div>

With DelimitedFiles, I’m still at about 23s

Then, i can’t remember for the life of me where i saw it, but I remembered that you could set the optimization level, so I “downgraded” my optimization

julia -O0 …

and this took another 6 seconds off, i’m assuming because it’s not trying so hard to optimize.

I posted this question to hopefully learn some techniques. For example even though CSV was, sadly, a culprit, i had to figure it out by not using it.

I’m still interested in knowing if there is a way to get any statistics as to where the compiler is spending it’s time, at a basic level.

---

<div class="post-metadata">

**Author:** ![mauro3](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/mauro3/32/292_2.png) [@mauro3](https://discourse.julialang.org/u/mauro3)\
**Post date:** [May 19, 2020, 8:01pm UTC](https://discourse.julialang.org/t/slow-compilation-i-think-not-sure-how-to-debug/39741/8 "2020-05-19T20:01:17Z")

</div>

I cannot reproduce the long load times of DelimitedFiles:

```julia
@show fl = download("https://people.sc.fsu.edu/~jburkardt/data/csv/airtravel.csv")

@time using DelimitedFiles # 0.000452 seconds (690 allocations: 37.062 KiB)

@time d,h = readdlm(fl, ',', header=true) # 1.163442 seconds (2.12 M allocations: 105.665 MiB, 1.47% gc time)
@time d,h = readdlm(fl, ',', header=true) # 0.000198 seconds (75 allocations: 44.297 KiB)

@show h
@show d

```

Although, 1s is still too long.

I think this might be because all tests for DelimitedFiles seem to use some sort of IOBuffer and not a file-path string:

> <https://github.com/JuliaLang/julia/blob/84d7e67aa82f3a3348a84a5a5659e03e2ebd6bcf/stdlib/DelimitedFiles/test/runtests.jl>

Thus the automated precompile-script does not pick up to compile the file-path method.

---

<div class="post-metadata">

**Author:** ![purplishrock](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/purplishrock/32/13451_2.png) [@purplishrock](https://discourse.julialang.org/u/purplishrock)\
**Post date:** [May 19, 2020, 8:52pm UTC](https://discourse.julialang.org/t/slow-compilation-i-think-not-sure-how-to-debug/39741/9 "2020-05-19T20:52:33Z")

</div>

I may have mislead you. The _overall_ compile/runtime of my program is long, but definitely not a fault of delimited files.

DelimitedFiles is loading in 3ms, lol, and the file read only takes 0.2s.

My program is now taking approximately 18s, total , to run.

1. 3s of julia startup time, i.e. the time where i see nothing
2. 7.2s for “using PyPlot”
3. 1.2s for ALL of the other “using ModuleName”
4. 0.23s for file read.
5. 7s - ?

However what I have noticed, is that there is another noticeable delay from the time all the using statements are complete to the start of the program. I’m thinking that must be more compilation time for the body of my program itself.

Also, I am using ArgParse, and i’ve become suspicious that it is contributing to the overhead, maybe compilation of the line arguments processing machinery ?

I would like to point out something that is very familiar to Julia users. Processing 1 file takes my program about 18s, but processing 36 files (I do it in a loop inside the program - don’t have to re-run it) takes only 2s more, i.e. 20s.

---

<div class="post-metadata">

**Author:** ![mauro3](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/mauro3/32/292_2.png) [@mauro3](https://discourse.julialang.org/u/mauro3)\
**Post date:** [May 19, 2020, 8:58pm UTC](https://discourse.julialang.org/t/slow-compilation-i-think-not-sure-how-to-debug/39741/10 "2020-05-19T20:58:30Z")

</div>

> [@purplishrock](#):
>
> However what I have noticed, is that there is another noticeable delay from the time all the using statements are complete to the start of the program.

Yes, methods still will need to be compiled for a set of arguments. This incurs further delays after `using`, often of comparable size.

Yes, Argparse was slow the last time I used it (a few years ago). Just posted today:

> [@Precompile a script?](https://discourse.julialang.org/t/precompile-a-script/5364/7):
>
> I don’t know if you’re still having this issue, but I just created a new argument parsing module that might help with that somewhat. [GitHub - zachmatson/ArgMacros.jl: Fast, flexible, macro-based, Julia package for parsing command line arguments.](https://github.com/zachmatson/ArgMacros.jl) Still in the middle of the three-day waiting period for adding Julia packages to the registry but can be added from GitHub still right now.

maybe better?

---

<div class="post-metadata">

**Author:** ![tbeason](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/tbeason/32/15898_2.png) [@tbeason](https://discourse.julialang.org/u/tbeason)\
**Post date:** [May 19, 2020, 9:11pm UTC](https://discourse.julialang.org/t/slow-compilation-i-think-not-sure-how-to-debug/39741/11 "2020-05-19T21:11:36Z")

</div>

Comment out everything to do with plotting and run it and report back.

---

<div class="post-metadata">

**Author:** ![zachmatson](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/zachmatson/32/9397_2.png) [@zachmatson](https://discourse.julialang.org/u/zachmatson)\
**Post date:** [May 19, 2020, 9:13pm UTC](https://discourse.julialang.org/t/slow-compilation-i-think-not-sure-how-to-debug/39741/12 "2020-05-19T21:13:07Z")

</div>

This is a pretty big pain point for me with Julia right now, I think some pretty comprehensive work around being able to write scripts with quick startup in Julia needs to be done still, like compilation not always extending to all of the methods called by the methods that do get compiled. Using `-O0` as a Julia argument made a pretty noticeable impact on some scripts I was working on too so that’s a very good find…

---

<div class="post-metadata">

**Author:** ![purplishrock](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/purplishrock/32/13451_2.png) [@purplishrock](https://discourse.julialang.org/u/purplishrock)\
**Post date:** [May 19, 2020, 10:21pm UTC](https://discourse.julialang.org/t/slow-compilation-i-think-not-sure-how-to-debug/39741/13 "2020-05-19T22:21:47Z")

</div>

I thought i had, however the “using PyPlot” was still in there and when i commented it out i found that i had missed commenting out the plot line. So the “using PyPlot” and errant plot() statement were worth about 8s, 7s for the “using PyPlot” + 1s for the plot, so that reduced my run time down to about 9s.

And now for the interesting part, as @mauro3, alluded to regarding ArgParse…

> time julia args.jl test1  
> 0.392707 seconds (46.13 k allocations: 3.572 MiB)  
> Dict{String,Any}(“filenames” =\> [“test1”],“graph” =\> false)
> 
> real 0m7.928s  
> user 0m0.031s  
> sys 0m0.078s

That’s right, 8s to do **nothing** but process command line args… ouch.

Well that explains a lot. I think that i have ArgParse in a LOT of scripts. Never occurred to me to check it.

So without ArgParse the script is at about 4s.

---

<div class="post-metadata">

**Author:** ![zachmatson](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/zachmatson/32/9397_2.png) [@zachmatson](https://discourse.julialang.org/u/zachmatson)\
**Post date:** [May 19, 2020, 10:52pm UTC](https://discourse.julialang.org/t/slow-compilation-i-think-not-sure-how-to-debug/39741/14 "2020-05-19T22:52:44Z")

</div>

Not sure if the [ArgMacros](https://github.com/zachmatson/ArgMacros.jl) module that was linked above works for your use case but wrote it basically because of this kind of speed issue. Might help with this.

---

<div class="post-metadata">

**Author:** ![purplishrock](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/purplishrock/32/13451_2.png) [@purplishrock](https://discourse.julialang.org/u/purplishrock)\
**Post date:** [May 19, 2020, 11:26pm UTC](https://discourse.julialang.org/t/slow-compilation-i-think-not-sure-how-to-debug/39741/15 "2020-05-19T23:26:17Z")

</div>

yes, thanks for that ! i will definitely try it out.

---

<div class="post-metadata">

**Author:** ![PeterSimon](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/petersimon/32/25193_2.png) [@PeterSimon](https://discourse.julialang.org/u/PeterSimon)\
**Post date:** [May 20, 2020, 1:14am UTC](https://discourse.julialang.org/t/slow-compilation-i-think-not-sure-how-to-debug/39741/16 "2020-05-20T01:14:38Z")

</div>

You might want to also check out [argparse2](https://github.com/kmsquire/ArgParse2.jl), which was written to address the speed issues of other existing argument parsing solutions.