timholy / SnoopCompile.jl

Provide insights about latency (TTFX) for Julia packages
https://timholy.github.io/SnoopCompile.jl/dev/
Other
309 stars 48 forks source link

Handle printing in `@precompile_all_calls` #308

Closed carstenbauer closed 1 year ago

carstenbauer commented 1 year ago

I recently added a @precompile_all_calls block to ThreadPinning.jl which contains typical calls that I want to be precompiled. One of them was (it's not there anymore) threadinfo() which essentially only prints things (specifically the system topology + where Julia threads are currently running). While this seemed fine at first, I noticed that when the package precompilation is triggered by using ThreadPinning instead of the (arguably more common) ] add ThreadPinning (or ] precompile) I would now see the printing output of the snoop-precompile block. I find this to be somewhat annoying which is why I dropped the threadinfo() call. However, this seems to be a general issue that might be worth a fix.

A straightforward solution to the issue would be to redirect all printing by the snoop-precompile block to /dev/null or similar. I guess the question then is whether there are cases where one actually wants to see the printing output. (I can't think of any but what do I know 😄).

ronisbr commented 1 year ago

I also have this problem with PrettyTables. I am trying to solve by redirecting stdout.

FedeClaudi commented 1 year ago

Hi folks,

I've experienced something similar in Term.jl, my solution:

 originalSTDOUT = stdout
 (outRead, outWrite) = redirect_stdout()

 @precompile_setup begin
    @precompile_all_calls begin
        # do your thing, with prints
    end
end

close(outRead)
redirect_stdout(originalSTDOUT)

nothing gets printed out

carstenbauer commented 1 year ago

Yes, that's the obvious workaround. The question is whether something like this should be the default, potentially with an opt-out option.

FedeClaudi commented 1 year ago

Apparently the approach before seems to cause problems for some users, anyone experienced something like this before?

timholy commented 1 year ago

Can't you just

@precompile_setup begin
    junkio = IOBuffer()      # or perhaps better, use `devnull`?
    @precompile_all_calls begin
        ...
        do_some_printing(junkio, args...)
        ...
    end
end

?

carstenbauer commented 1 year ago

Maybe I misunderstand, but this would assume that every function that does some printing down the road takes an io as the first argument. That's unrealistic I think.

timholy commented 1 year ago

With Julia's multiple dispatch you can of course define

myprintingfunction(io::IO, args...) = ...                                              # the "real" definition
myprintingfunction(args...) = myprintingfunction(stdout, args...)    # the convenience definition

That's basically good practice anyway, as it greatly improves the flexibility of what you can do with myprintingfunction.

But in the end, eliminating spurious output isn't a requirement, it's a nice-to-have. If you want to be able to eliminate the output, then accept an io as the first argument? Otherwise live with the consequences?

This is something up to the individual package developer, it's not going to become something SnoopPrecompile does automatically for you. As you say, there's no sane way to guarantee that will work.

carstenbauer commented 1 year ago

A thought: Precompilation triggered by, say, ] precompile doesn't show output from snoop precompile blocks. Precompilation triggered by using XY does. What's different for the former? Maybe we can exploit the same technique? (Maybe not)

carstenbauer commented 1 year ago

FWIW, I wouldn't call it "spurious output". People use println, @info, etc. in functions that do computations. I don't think that's "spurious output" (it only is in the context of this issue).

timholy commented 1 year ago

Precompilation triggered by, say, ] precompile doesn't show output from snoop precompile blocks. Precompilation triggered by using XY does. What's different for the former? Maybe we can exploit the same technique? (Maybe not)

I don't think we'd want that by default: if precompilation fails, we'd like to be able to see stacktraces. But it's easy to do, just pass devnull to Base.compilecache:

help?> Base.compilecache
  Base.compilecache(module::PkgId)

  Creates a precompiled cache file for a module and all of its dependencies. This can be used to reduce package load
  times. Cache files are stored in DEPOT_PATH[1]/compiled. See Module initialization and precompilation for important
  notes.

julia> methods(Base.compilecache)
# 7 methods for generic function "compilecache" from Base:
 [1] compilecache(pkg::Base.PkgId)
     @ loading.jl:2002
 [2] compilecache(pkg::Base.PkgId, internal_stderr::IO)
     @ loading.jl:2002
 [3] compilecache(pkg::Base.PkgId, internal_stderr::IO, internal_stdout::IO)
     @ loading.jl:2002
 [4] compilecache(pkg::Base.PkgId, path::String)
     @ loading.jl:2011
 [5] compilecache(pkg::Base.PkgId, path::String, internal_stderr::IO)
     @ loading.jl:2011
 [6] compilecache(pkg::Base.PkgId, path::String, internal_stderr::IO, internal_stdout::IO)
     @ loading.jl:2011
 [7] compilecache(pkg::Base.PkgId, path::String, internal_stderr::IO, internal_stdout::IO, keep_loaded_modules::Bool)
     @ loading.jl:2011
timholy commented 1 year ago

This issue is broader than printing, by the way. When ImageView precompiles, various windows pop up and then disappear. I guess I've gotten used to this, so I don't think of it as a big deal, but I can understand why you don't want the output. But at present I don't see a generic solution that this package can implement.

timholy commented 1 year ago

I don't think there's anything to be done here.