Skip to content

Conversation

@IanButterworth
Copy link
Member

@IanButterworth IanButterworth commented Aug 28, 2025

Highlights compilation that's happening during the profiling period, which is otherwise just indicated by non-specific profile hits.

i.e. hitting ctrl-T on macOS just after starting Pkg.update()

load: 4.66  cmd: julia 29738 running 14.25u 0.90s

======================================================================================
Information request received. A stacktrace will print followed by a 1.0 second profile.
--trace-compile is enabled during profile collection.
======================================================================================

signal (29): Information request: 29
__psynch_cvwait at /usr/lib/system/libsystem_kernel.dylib (unknown line)
unknown function (ip: 0x0) at (unknown file)
_ZNK4llvm17RegisterClassInfo16computePSetLimitEj at /Users/ian/Documents/GitHub/julia/usr/lib/libLLVM.dylib (unknown line)
_ZN4llvm17ScheduleDAGMILive15initRegPressureEv at /Users/ian/Documents/GitHub/julia/usr/lib/libLLVM.dylib (unknown line)
_ZN4llvm17ScheduleDAGMILive8scheduleEv at /Users/ian/Documents/GitHub/julia/usr/lib/libLLVM.dylib (unknown line)
_ZN12_GLOBAL__N_120MachineSchedulerBase15scheduleRegionsERN4llvm17ScheduleDAGInstrsEb at /Users/ian/Documents/GitHub/julia/usr/lib/libLLVM.dylib (unknown line)
_ZN12_GLOBAL__N_116MachineScheduler20runOnMachineFunctionERN4llvm15MachineFunctionE at /Users/ian/Documents/GitHub/julia/usr/lib/libLLVM.dylib (unknown line)
_ZN4llvm19MachineFunctionPass13runOnFunctionERNS_8FunctionE at /Users/ian/Documents/GitHub/julia/usr/lib/libLLVM.dylib (unknown line)
_ZN4llvm13FPPassManager13runOnFunctionERNS_8FunctionE at /Users/ian/Documents/GitHub/julia/usr/lib/libLLVM.dylib (unknown line)
_ZN4llvm13FPPassManager11runOnModuleERNS_6ModuleE at /Users/ian/Documents/GitHub/julia/usr/lib/libLLVM.dylib (unknown line)
_ZN4llvm6legacy15PassManagerImpl3runERNS_6ModuleE at /Users/ian/Documents/GitHub/julia/usr/lib/libLLVM.dylib (unknown line)
_ZN4llvm3orc14SimpleCompilerclERNS_6ModuleE at /Users/ian/Documents/GitHub/julia/usr/lib/libLLVM.dylib (unknown line)
#=  225.2 ms =# precompile(Tuple{typeof(Core.kwcall), NamedTuple{(:io,), Tuple{Base.IOContext{IO}}}, typeof(Pkg.Registry.update)})
operator() at /Users/ian/Documents/GitHub/julia/src/jitlayers.cpp:1612
addModule at /Users/ian/Documents/GitHub/julia/src/jitlayers.cpp:2093
jl_compile_codeinst_now at /Users/ian/Documents/GitHub/julia/src/jitlayers.cpp:682
jl_compile_codeinst_impl at /Users/ian/Documents/GitHub/julia/src/jitlayers.cpp:873
jl_compile_method_internal at /Users/ian/Documents/GitHub/julia/src/gf.c:3535
_jl_invoke at /Users/ian/Documents/GitHub/julia/src/gf.c:3993 [inlined]
ijl_apply_generic at /Users/ian/Documents/GitHub/julia/src/gf.c:4198
#update_registries#162 at /Users/ian/Documents/GitHub/julia/usr/share/julia/stdlib/v1.13/Pkg/src/Operations.jl:1713
update_registries at /Users/ian/Documents/GitHub/julia/usr/share/julia/stdlib/v1.13/Pkg/src/Operations.jl:1710 [inlined]
#up#165 at /Users/ian/Documents/GitHub/julia/usr/share/julia/stdlib/v1.13/Pkg/src/API.jl:421
up at /Users/ian/Documents/GitHub/julia/usr/share/julia/stdlib/v1.13/Pkg/src/API.jl:406
unknown function (ip: 0x125c440ef) at (unknown file)
#up#48 at /Users/ian/Documents/GitHub/julia/usr/share/julia/stdlib/v1.13/Pkg/src/API.jl:168
unknown function (ip: 0x125c0c4b7) at (unknown file)
up at /Users/ian/Documents/GitHub/julia/usr/share/julia/stdlib/v1.13/Pkg/src/API.jl:157
jfptr_up_44121 at /Users/ian/Documents/GitHub/julia/usr/share/julia/compiled/v1.13/Pkg/tUTdb_L0OKt.dylib (unknown line)
do_cmd at /Users/ian/Documents/GitHub/julia/usr/share/julia/stdlib/v1.13/Pkg/src/REPLMode/REPLMode.jl:422
do_cmds at /Users/ian/Documents/GitHub/julia/usr/share/julia/stdlib/v1.13/Pkg/src/REPLMode/REPLMode.jl:406
jfptr_do_cmds_44950 at /Users/ian/Documents/GitHub/julia/usr/share/julia/compiled/v1.13/Pkg/tUTdb_L0OKt.dylib (unknown line)
do_cmds at /Users/ian/Documents/GitHub/julia/usr/share/julia/stdlib/v1.13/Pkg/ext/REPLExt/REPLExt.jl:118
on_done at /Users/ian/Documents/GitHub/julia/usr/share/julia/stdlib/v1.13/Pkg/ext/REPLExt/REPLExt.jl:132
jfptr_on_done_2682 at /Users/ian/Documents/GitHub/julia/usr/share/julia/compiled/v1.13/REPLExt/c9i2p_L0OKt.dylib (unknown line)
jl_apply at /Users/ian/Documents/GitHub/julia/src/julia.h:2382 [inlined]
jl_f_invoke_in_world at /Users/ian/Documents/GitHub/julia/src/builtins.c:902
#invokelatest_gr#233 at ./reflection.jl:1333 [inlined]
invokelatest_gr at ./reflection.jl:1327 [inlined]
#create_mode##0 at /Users/ian/Documents/GitHub/julia/usr/share/julia/stdlib/v1.13/Pkg/ext/REPLExt/REPLExt.jl:156
unknown function (ip: 0x125bfc163) at (unknown file)
jl_apply at /Users/ian/Documents/GitHub/julia/src/julia.h:2382 [inlined]
jl_f_invokelatest at /Users/ian/Documents/GitHub/julia/src/builtins.c:883
run_interface at /Users/ian/Documents/GitHub/julia/usr/share/julia/stdlib/v1.13/REPL/src/LineEdit.jl:2854
run_frontend at /Users/ian/Documents/GitHub/julia/usr/share/julia/stdlib/v1.13/REPL/src/REPL.jl:1697
#61 at /Users/ian/Documents/GitHub/julia/usr/share/julia/stdlib/v1.13/REPL/src/REPL.jl:678
jfptr_YY.61_17068 at /Users/ian/Documents/GitHub/julia/usr/share/julia/compiled/v1.13/REPL/u0gqU_L0OKt.dylib (unknown line)
jl_apply at /Users/ian/Documents/GitHub/julia/src/julia.h:2382 [inlined]
start_task at /Users/ian/Documents/GitHub/julia/src/task.c:1253
unknown function (ip: 0x0) at (unknown file)

#=   34.0 ms =# precompile(Tuple{Base.Experimental.var"#sync_end##0#sync_end##1"{Base.Channel{Any}, Task}})
#=   27.7 ms =# precompile(Tuple{Downloads.Curl.var"#socket_callback##6#socket_callback##7"{Int32, FileWatching.FDWatcher, Downloads.Curl.Multi}})
#=    4.8 ms =# precompile(Tuple{Base.var"#702#703"{Base.Process}})
#=    4.8 ms =# precompile(Tuple{typeof(Base.lock), Base.TTY})
    Updating registry at `~/.julia/registries/HolyLabRegistry`
#=    6.1 ms =# precompile(Tuple{typeof(Base.unlock), Base.TTY})
    Updating git-repo `git@github.com:HolyLab/HolyLabRegistry`
#=    3.7 ms =# precompile(Tuple{typeof(Base.merge), NamedTuple{(:payload,), Tuple{Base.Dict{Symbol, Any}}}, NamedTuple{(:transfer_progress, :credentials), Tuple{Ptr{Nothing}, Ptr{Nothing}}}})
#=    7.0 ms =# precompile(Tuple{typeof(Core.kwcall), NamedTuple{(:payload, :transfer_progress, :credentials), Tuple{Base.Dict{Symbol, Any}, Ptr{Nothing}, Ptr{Nothing}}}, Type{LibGit2.RemoteCallbacks}})

==============================================================
Profile collected. A report will print at the next yield point
Disabling --trace-compile
==============================================================

┌ Warning: There were no samples collected in one or more groups.
│ This may be due to idle threads, or you may need to run your
│ program longer (perhaps by running it multiple times),
│ or adjust the delay between samples with `Profile.init()`.
└ @ Profile ~/Documents/GitHub/julia/usr/share/julia/stdlib/v1.13/Profile/src/Profile.jl:1362
Overhead ╎ [+additional indent] Count File:Line  Function
=========================================================
Thread 1 (interactive)
 Task 0x000000010f3f92d0 Total snapshots: 364. Utilization: 100%
   ╎204 @REPL/src/REPL.jl:678  (::REPL.var"#61#62"{REPL.LineEditREPL, REPL.REPLBackendRef})()
   ╎ 204 @REPL/src/REPL.jl:1697  run_frontend(repl::REPL.LineEditREPL, backend::REPL.REPLBackendRef)
   ╎  204 @REPL/src/LineEdit.jl:2854  run_interface(terminal::REPL.Terminals.TextTerminal, m::REPL.LineEdit.ModalInterface, s::R…
   ╎   204 @Pkg/ext/REPLExt/REPLExt.jl:156  (::REPLExt.var"#create_mode##0#create_mode##1"{REPL.LineEditREPL})(s::REPL.LineEdit.…
   ╎    204 @Base/reflection.jl:1327  invokelatest_gr
   ╎     204 @Base/reflection.jl:1333  #invokelatest_gr#233
   ╎    ╎ 204 @Pkg/ext/REPLExt/REPLExt.jl:132  on_done(s::REPL.LineEdit.MIState, buf::IOBuffer, ok::Bool, repl::REPL.LineEditREP…
   ╎    ╎  204 @Pkg/ext/REPLExt/REPLExt.jl:118  do_cmds(repl::REPL.LineEditREPL, commands::String)
...

@IanButterworth IanButterworth changed the title Enable --trace-compile=stderr --trace-compile-timing during SIGUSR1/SIGINFO1 profiling Enable --trace-compile during SIGUSR1/SIGINFO1 profiling Aug 28, 2025
@nsajko nsajko added the observability metrics, timing, understandability, reflection, logging, ... label Aug 29, 2025
@IanButterworth IanButterworth added the merge me PR is reviewed. Merge when all tests are passing label Aug 29, 2025
@IanButterworth IanButterworth merged commit 8052b91 into JuliaLang:master Aug 30, 2025
9 checks passed
@IanButterworth IanButterworth deleted the ib/peek_trace_compile branch August 30, 2025 14:36
@DilumAluthge DilumAluthge removed the merge me PR is reviewed. Merge when all tests are passing label Aug 30, 2025
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

observability metrics, timing, understandability, reflection, logging, ... profiler

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants