Skip to content

Measure compile time only when using time macros#38885

Merged
Keno merged 1 commit intoJuliaLang:masterfrom
IanButterworth:ib/compile_time_only_when_timing
Dec 15, 2020
Merged

Measure compile time only when using time macros#38885
Keno merged 1 commit intoJuliaLang:masterfrom
IanButterworth:ib/compile_time_only_when_timing

Conversation

@IanButterworth
Copy link
Copy Markdown
Member

@IanButterworth IanButterworth commented Dec 15, 2020

It turns out calling jl_hrtime on some BSD CI setups can be a lot more expensive than other platforms, which makes the overhead significant (#38877)

This changes to only grab the compile time measurement when called from @time and @timev macros.

@musm musm added the backport 1.6 Change should be backported to release-1.6 label Dec 15, 2020
@DilumAluthge DilumAluthge requested a review from Keno December 15, 2020 04:11
@IanButterworth
Copy link
Copy Markdown
Member Author

IanButterworth commented Dec 15, 2020

I missed a few jl_hrtime's. Just about to push

@IanButterworth IanButterworth force-pushed the ib/compile_time_only_when_timing branch from 0b6762f to 86c7b65 Compare December 15, 2020 04:37
@IanButterworth IanButterworth force-pushed the ib/compile_time_only_when_timing branch from 86c7b65 to faa20f5 Compare December 15, 2020 04:40
@IanButterworth IanButterworth mentioned this pull request Dec 15, 2020
Closed
@Keno
Copy link
Copy Markdown
Member

Keno commented Dec 15, 2020

Can confirm this fixes the freebsd slowness, thanks!

@Keno Keno merged commit fa6077e into JuliaLang:master Dec 15, 2020
@IanButterworth IanButterworth deleted the ib/compile_time_only_when_timing branch December 15, 2020 19:40
ericphanson
ericphanson reviewed Dec 16, 2020
View reviewed changes
Copy link
Copy Markdown
Contributor

@ericphanson ericphanson left a comment •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Should this be in a try-finally block? To me it looks like if the expression you’re timing throws, then jl_measure_compile_time gets left at 1.

(edit: referring to https://github.com/ianshmean/julia/blob/faa20f5cce1f9be2d453caf362e3744804d27b42/base/timing.jl#L201-L205 and the same for @timev, somehow my review didn't land at the right place).

@IanButterworth IanButterworth mentioned this pull request Dec 17, 2020
Merged
@IanButterworth
Copy link
Copy Markdown
Member Author

IanButterworth commented Dec 17, 2020

@ericphanson yes! Thanks for catching that. Fix here #38915

KristofferC pushed a commit that referenced this pull request Dec 17, 2020
@IanButterworth @KristofferC
measure compile time only when using time macros (fix #38877) (#38885)
64838d2 
(cherry picked from commit fa6077e)
@KristofferC KristofferC mentioned this pull request Dec 17, 2020
Merged
53 tasks
@KristofferC KristofferC removed the backport 1.6 Change should be backported to release-1.6 label Dec 19, 2020
staticfloat pushed a commit that referenced this pull request Jan 15, 2021
@IanButterworth @staticfloat
measure compile time only when using time macros (fix #38877) (#38885)
8d561f3 
(cherry picked from commit fa6077e)
ElOceanografo pushed a commit to ElOceanografo/julia that referenced this pull request May 4, 2021
@IanButterworth @ElOceanografo
measure compile time only when using time macros (fix JuliaLang#38877) (
f42fb99 
JuliaLang#38885)
@NHDaly NHDaly mentioned this pull request Aug 1, 2021
Merged
NHDaly added a commit to NHDaly/julia that referenced this pull request Aug 18, 2021
@NHDaly
Make jl_cumulative_compile_time_ns global (and reentrant).
619dec8 
Now, multiple tasks (on the same or different Threads) can start and stop compilation
time measurement, without interrupting each other.

* Makes jl_cumulative_compile_time_ns into a global, atomic variable.

Instead of keeping per-task compilation time, this change keeps a
global counter of compilation time, protected with atomic mutations.

Fixes JuliaLang#41739

```julia
julia> include("./compilation-task-migration-17-example.jl")
start thread: 2
end thread: 2
  5.185706 seconds (3.53 M allocations: 2.570 GiB, 7.34% gc time, 15.57% compilation time)

julia> include("./compilation-task-migration-17-example.jl")
start thread: 3
WARNING: replacing module M.
end thread: 1
  4.110316 seconds (18.23 k allocations: 2.391 GiB, 5.67% gc time, 0.24% compilation time)
```

Compilation time measurement originally added in: JuliaLang#38885

Problems addressed:
- This fixes JuliaLang#41739, meaning it fixes compilation time reporting in 1.7 after task migration was enabled.
- It also fixes the race condition that existed previously, even on 1.6, where multiple Tasks on the thread measuring `@time` could break the measurement, as identified in (JuliaLang#41271 (comment)).
  - It fixes reentrant `@time` by making the `enable` flag a _counter,_ instead of a boolean.
  - It fixes `@time` called from multiple threads by making that flag thread-safe (via atomics).
@NHDaly NHDaly mentioned this pull request Aug 18, 2021
Merged
NHDaly added a commit to NHDaly/julia that referenced this pull request Aug 23, 2021
@NHDaly
Make jl_cumulative_compile_time_ns global (and reentrant).
b4ca196 
Now, multiple tasks (on the same or different Threads) can start and stop compilation
time measurement, without interrupting each other.

* Makes jl_cumulative_compile_time_ns into a global, atomic variable.

Instead of keeping per-task compilation time, this change keeps a
global counter of compilation time, protected with atomic mutations.

Fixes JuliaLang#41739

```julia
julia> include("./compilation-task-migration-17-example.jl")
start thread: 2
end thread: 2
  5.185706 seconds (3.53 M allocations: 2.570 GiB, 7.34% gc time, 15.57% compilation time)

julia> include("./compilation-task-migration-17-example.jl")
start thread: 3
WARNING: replacing module M.
end thread: 1
  4.110316 seconds (18.23 k allocations: 2.391 GiB, 5.67% gc time, 0.24% compilation time)
```

Compilation time measurement originally added in: JuliaLang#38885

Problems addressed:
- This fixes JuliaLang#41739, meaning it fixes compilation time reporting in 1.7 after task migration was enabled.
- It also fixes the race condition that existed previously, even on 1.6, where multiple Tasks on the thread measuring `@time` could break the measurement, as identified in (JuliaLang#41271 (comment)).
  - It fixes reentrant `@time` by making the `enable` flag a _counter,_ instead of a boolean.
  - It fixes `@time` called from multiple threads by making that flag thread-safe (via atomics).
KristofferC pushed a commit that referenced this pull request Aug 27, 2021
@NHDaly @KristofferC
Make jl_cumulative_compile_time_ns global (and reentrant).
f34e241 
Now, multiple tasks (on the same or different Threads) can start and stop compilation
time measurement, without interrupting each other.

* Makes jl_cumulative_compile_time_ns into a global, atomic variable.

Instead of keeping per-task compilation time, this change keeps a
global counter of compilation time, protected with atomic mutations.

Fixes #41739

```julia
julia> include("./compilation-task-migration-17-example.jl")
start thread: 2
end thread: 2
  5.185706 seconds (3.53 M allocations: 2.570 GiB, 7.34% gc time, 15.57% compilation time)

julia> include("./compilation-task-migration-17-example.jl")
start thread: 3
WARNING: replacing module M.
end thread: 1
  4.110316 seconds (18.23 k allocations: 2.391 GiB, 5.67% gc time, 0.24% compilation time)
```

Compilation time measurement originally added in: #38885

Problems addressed:
- This fixes #41739, meaning it fixes compilation time reporting in 1.7 after task migration was enabled.
- It also fixes the race condition that existed previously, even on 1.6, where multiple Tasks on the thread measuring `@time` could break the measurement, as identified in (#41271 (comment)).
  - It fixes reentrant `@time` by making the `enable` flag a _counter,_ instead of a boolean.
  - It fixes `@time` called from multiple threads by making that flag thread-safe (via atomics).

(cherry picked from commit b4ca196)
janrous-rai pushed a commit to janrous-rai/julia that referenced this pull request Oct 28, 2021
@NHDaly @janrous-rai
Make jl_cumulative_compile_time_ns global (and reentrant).
a39a08f 
Now, multiple tasks (on the same or different Threads) can start and stop compilation
time measurement, without interrupting each other.

* Makes jl_cumulative_compile_time_ns into a global, atomic variable.

Instead of keeping per-task compilation time, this change keeps a
global counter of compilation time, protected with atomic mutations.

Fixes JuliaLang#41739

```julia
julia> include("./compilation-task-migration-17-example.jl")
start thread: 2
end thread: 2
  5.185706 seconds (3.53 M allocations: 2.570 GiB, 7.34% gc time, 15.57% compilation time)

julia> include("./compilation-task-migration-17-example.jl")
start thread: 3
WARNING: replacing module M.
end thread: 1
  4.110316 seconds (18.23 k allocations: 2.391 GiB, 5.67% gc time, 0.24% compilation time)
```

Compilation time measurement originally added in: JuliaLang#38885

Problems addressed:
- This fixes JuliaLang#41739, meaning it fixes compilation time reporting in 1.7 after task migration was enabled.
- It also fixes the race condition that existed previously, even on 1.6, where multiple Tasks on the thread measuring `@time` could break the measurement, as identified in (JuliaLang#41271 (comment)).
  - It fixes reentrant `@time` by making the `enable` flag a _counter,_ instead of a boolean.
  - It fixes `@time` called from multiple threads by making that flag thread-safe (via atomics).
LilithHafner pushed a commit to LilithHafner/julia that referenced this pull request Feb 22, 2022
@NHDaly @LilithHafner
Make jl_cumulative_compile_time_ns global (and reentrant).
4be5c79 
Now, multiple tasks (on the same or different Threads) can start and stop compilation
time measurement, without interrupting each other.

* Makes jl_cumulative_compile_time_ns into a global, atomic variable.

Instead of keeping per-task compilation time, this change keeps a
global counter of compilation time, protected with atomic mutations.

Fixes JuliaLang#41739

```julia
julia> include("./compilation-task-migration-17-example.jl")
start thread: 2
end thread: 2
  5.185706 seconds (3.53 M allocations: 2.570 GiB, 7.34% gc time, 15.57% compilation time)

julia> include("./compilation-task-migration-17-example.jl")
start thread: 3
WARNING: replacing module M.
end thread: 1
  4.110316 seconds (18.23 k allocations: 2.391 GiB, 5.67% gc time, 0.24% compilation time)
```

Compilation time measurement originally added in: JuliaLang#38885

Problems addressed:
- This fixes JuliaLang#41739, meaning it fixes compilation time reporting in 1.7 after task migration was enabled.
- It also fixes the race condition that existed previously, even on 1.6, where multiple Tasks on the thread measuring `@time` could break the measurement, as identified in (JuliaLang#41271 (comment)).
  - It fixes reentrant `@time` by making the `enable` flag a _counter,_ instead of a boolean.
  - It fixes `@time` called from multiple threads by making that flag thread-safe (via atomics).
LilithHafner pushed a commit to LilithHafner/julia that referenced this pull request Mar 8, 2022
@NHDaly @LilithHafner
Make jl_cumulative_compile_time_ns global (and reentrant).
946cfa6 
Now, multiple tasks (on the same or different Threads) can start and stop compilation
time measurement, without interrupting each other.

* Makes jl_cumulative_compile_time_ns into a global, atomic variable.

Instead of keeping per-task compilation time, this change keeps a
global counter of compilation time, protected with atomic mutations.

Fixes JuliaLang#41739

```julia
julia> include("./compilation-task-migration-17-example.jl")
start thread: 2
end thread: 2
  5.185706 seconds (3.53 M allocations: 2.570 GiB, 7.34% gc time, 15.57% compilation time)

julia> include("./compilation-task-migration-17-example.jl")
start thread: 3
WARNING: replacing module M.
end thread: 1
  4.110316 seconds (18.23 k allocations: 2.391 GiB, 5.67% gc time, 0.24% compilation time)
```

Compilation time measurement originally added in: JuliaLang#38885

Problems addressed:
- This fixes JuliaLang#41739, meaning it fixes compilation time reporting in 1.7 after task migration was enabled.
- It also fixes the race condition that existed previously, even on 1.6, where multiple Tasks on the thread measuring `@time` could break the measurement, as identified in (JuliaLang#41271 (comment)).
  - It fixes reentrant `@time` by making the `enable` flag a _counter,_ instead of a boolean.
  - It fixes `@time` called from multiple threads by making that flag thread-safe (via atomics).
staticfloat pushed a commit that referenced this pull request Dec 23, 2022
@IanButterworth @staticfloat
measure compile time only when using time macros (fix #38877) (#38885)
2872446 
(cherry picked from commit fa6077e)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Reviewers

@JeffBezanson JeffBezanson JeffBezanson approved these changes

@Keno Keno Awaiting requested review from Keno

+1 more reviewer

@ericphanson ericphanson ericphanson left review comments

Reviewers whose approvals may not affect merge requirements

Assignees

No one assigned

Labels

None yet

Projects

None yet

Milestone

No milestone

Development

Successfully merging this pull request may close these issues.

6 participants

@IanButterworth @Keno @JeffBezanson @ericphanson @KristofferC @musm