@time can't handle top-level-only expressions

[gitfoxi]

I don't really care that this doesn't work.

julia> @time using DataFrames
ERROR: unsupported or misplaced expression using

But it could

julia> @time eval(parse("using DataFrames"))
elapsed time: 5.558196165 seconds (64795540 bytes allocated)

Also, does anyone think the bytes allocated means something?

julia> function fib(n)
        n < 2 && return n
        return fib(n-1) + fib(n-2)
       end
fib (generic function with 1 method)

julia> @time fib(40)
elapsed time: 1.244510557 seconds (33068 bytes allocated)
102334155

julia> @time fib(40)
elapsed time: 1.102346687 seconds (64 bytes allocated)
102334155

Wow. Only 64 bytes allocated that is efficient.

[StefanKarpinski]

Macro syntax is space sensitive. You can also write @time(using DataFrames).

The bytes allocated means how many bytes were allocated while evaluating the expression, including code generation. Why would fib need to allocate more than the return value?

[JeffBezanson]

The bytes allocated doesn't distinguish bytes allocated by the user code from bytes allocated during compilation. The 64 bytes in the last case is probably allocation of a couple boxes to shuttle the result to the REPL and such.

using is one of the top-level-only expressions, which does make it hard to handle. In general, a case like this would be quite perverse (you wouldn't time, say, a type definition), but it just so happens that using is very slow and so an important thing to time.

[StefanKarpinski]

Is there any way we can turn off the gc_bytes incrementing while doing code gen?

[JeffBezanson]

We probably could, but by the principle of generally preferring transparency the effort might not be worth it. We'd have to go through the code and save the gc counter before every bit we consider off limits, then reset it. You will also get strange results like 0 bytes allocated for code that generates code --- sometimes compilation is logically part of the user program.

[JeffBezanson]

Of course I don't mean 0 bytes literally, just an artificially low number.

[StefanKarpinski]

Yeah, it's probably better the way it is. People just need to understand that sometimes running something generates code, which takes up both time and memory. Since we can't avoid the time taken by code generation, it would almost be more confusing to not report the bytes allocated. This way the @time output gives two hints that compilation is occurring vs. not occurring: the amount of time and the number of bytes.

[JeffBezanson]

Yes, I think that's exactly how Tim and I felt about it when he first added the bytes counter.

[simonster]

You can @time require("DataFrames"), which seems fine since nearly all of the time it takes to do using DataFrames is in loading the code.

[quinnj]

Hmmm....is there something we should do for @time using DataFrames? Maybe throw an error suggesting to do require? The gc issue here is superseded by #7119.

[KristofferC]

This now seems to work:

julia> @time using Tokenize
  0.014877 seconds (26.78 k allocations: 1.450 MB)