GC: enable logging to stderr when GC runs

[vilterp]

Useful to get a feel for how often GC is running and how much it's collecting.

GC.enable_logging()
# do some stuff
GC: pause 12.75ms. collected 5.130933MB. full recollect
GC: pause 56.41ms. collected 0.001632MB. incr
GC.enable_logging(false)

was split off from #42768

[KristofferC]

6 decimals for milliseconds is perhaps a bit excessive?

[vilterp]

Haha true. Truncated to 2 decimal points.

[vtjnash]

seems reasonable

[vilterp]

It appears that tester_linux32 failed, with an error in the Statistics package. Don't see a clear error message — possible flake?

[KristofferC]

Should be to stderr?

[vilterp]

Ah, I think my docstring was wrong and it already does print to stderr, since it uses jl_safe_printf:

julia/src/jl_uv.c

Line 624 in dc74954

if (write(STDERR_FILENO, buf, strlen(buf)) < 0) {

Updated the docstring.

[DilumAluthge]

Can you also edit the PR title to reflect whether this prints to stdout or stderr?

[vilterp]

Whoops, done.

[NHDaly]

LGTM :)

Can you plz add a very simple test that just enables the printing and then triggers a GC and then disables the printing? Thanks!

🎄 Merry christmas! 🎄

[vchuravy]

Also we should add docs for this.

[NHDaly]

@vchuravy Do you think docs and news? Or just docs?

[sefffal]

Instead (or in addition to) logging to STDERR, what about a way to register a callback that receives the same information?
I'm working on code that has a real time component and this PR would be a big help. But it's main interface is a GUI.
Ideally I would like to hook into this logging infrastructure and display e.g. a live plot showing GC pauses.

[vilterp]

@sefffal that would be cool, but I'm a little unsure how to do it… Since no Julia code can run during a GC pause (where the println is now) I guess we'd have to somehow queue up the callback to run after GC unpauses? Not quite sure how to do that at the moment; my knowledge of this codebase is pretty limited…

@NHDaly @vchuravy Julia contributor n00b question: where do I add docs and news? (besides the little docstring I put on the function?)

[vchuravy]

I think just docs suffice, I tend to find a place in the manual that makes sense, maybe https://docs.julialang.org/en/v1/manual/profile/#Memory-allocation-analysis or in the devdocs, but we sadly don't have a devdocs section for the GC, and then find the right section in https://github.com/JuliaLang/julia/tree/master/doc/src

News go here https://github.com/JuliaLang/julia/blob/master/NEWS.md

[vilterp]

Ok, added a bit of docs on this (and some headings) under the memory section of the profiling doc.

(hopefully we'll be able to add another heading for #42768 soon…)

[NHDaly]

For the News, i'd probably add it to one of these sections, at your discretion:

• https://github.com/JuliaLang/julia/blob/master/NEWS.md#compilerruntime-improvements
• https://github.com/JuliaLang/julia/blob/master/NEWS.md#tooling-improvements

It can just be a one-line blurb that links to this PR, following the structure of the others. Thanks @vilterp!

[NHDaly]

@vilterp This looks good to go, except for moving the function into the Base.GC module instead of Base.Experimental. Can you make that last change? Thanks! 👍

[vilterp]

done, and added a test.

[vilterp]

Thanks Valentin!