Skip to content

GC: enable logging to stderr when GC runs#43511

Merged
vchuravy merged 14 commits intoJuliaLang:masterfrom
vilterp:pv-gc-logging
Jan 4, 2022
Merged

GC: enable logging to stderr when GC runs#43511
vchuravy merged 14 commits intoJuliaLang:masterfrom
vilterp:pv-gc-logging

Conversation

@vilterp
Copy link
Copy Markdown
Contributor

@vilterp vilterp commented Dec 21, 2021 •
edited
Loading

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

@vilterp vilterp mentioned this pull request Dec 21, 2021
Merged
7 tasks
@DilumAluthge DilumAluthge requested a review from vtjnash December 21, 2021 20:37
@vilterp
don't print out num_alloc'd; it seems inaccurate
21b19e7 
and wasn't the most useful thing anyway
@KristofferC
Copy link
Copy Markdown
Member

KristofferC commented Dec 21, 2021

6 decimals for milliseconds is perhaps a bit excessive?

@vilterp
Copy link
Copy Markdown
Contributor Author

vilterp commented Dec 21, 2021

Haha true. Truncated to 2 decimal points.

vtjnash
vtjnash reviewed Dec 22, 2021
View reviewed changes
vtjnash
vtjnash reviewed Dec 22, 2021
View reviewed changes
vtjnash
vtjnash reviewed Dec 22, 2021
View reviewed changes
Copy link
Copy Markdown
Member

@vtjnash vtjnash left a comment

Choose a reason for hiding this comment

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

seems reasonable

@vilterp
Copy link
Copy Markdown
Contributor Author

vilterp commented Dec 22, 2021

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

IanButterworth
IanButterworth reviewed Dec 22, 2021
View reviewed changes
@KristofferC
Copy link
Copy Markdown
Member

KristofferC commented Dec 22, 2021

Should be to stderr?

@vilterp
Copy link
Copy Markdown
Contributor Author

vilterp commented Dec 22, 2021

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
Copy link
Copy Markdown
Member

DilumAluthge commented Dec 22, 2021

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

@vilterp vilterp changed the title GC: enable logging to stdout when GC runs GC: enable logging to stderr when GC runs Dec 23, 2021
@vilterp
Copy link
Copy Markdown
Contributor Author

vilterp commented Dec 23, 2021

Whoops, done.

NHDaly
NHDaly approved these changes Dec 25, 2021
View reviewed changes
Copy link
Copy Markdown
Member

@NHDaly NHDaly left a comment

Choose a reason for hiding this comment

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

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
Copy link
Copy Markdown
Member

vchuravy commented Dec 25, 2021

Also we should add docs for this.

@NHDaly NHDaly added needs docs Documentation for this change is required needs news A NEWS entry is required for this change labels Dec 26, 2021
@NHDaly
Copy link
Copy Markdown
Member

NHDaly commented Dec 26, 2021

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

@sefffal
Copy link
Copy Markdown

sefffal commented Dec 27, 2021

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
Copy link
Copy Markdown
Contributor Author

vilterp commented Jan 3, 2022 •
edited
Loading

@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
Copy link
Copy Markdown
Member

vchuravy commented Jan 3, 2022

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
Copy link
Copy Markdown
Contributor Author

vilterp commented Jan 3, 2022

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…)

vchuravy
vchuravy reviewed Jan 3, 2022
View reviewed changes
vilterp
vilterp commented Jan 3, 2022
View reviewed changes
NHDaly
NHDaly reviewed Jan 3, 2022
View reviewed changes
@NHDaly NHDaly removed the needs docs Documentation for this change is required label Jan 3, 2022
@NHDaly
Copy link
Copy Markdown
Member

NHDaly commented Jan 3, 2022

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

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

NHDaly
NHDaly reviewed Jan 4, 2022
View reviewed changes
@NHDaly
Copy link
Copy Markdown
Member

NHDaly commented Jan 4, 2022

@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
Copy link
Copy Markdown
Contributor Author

vilterp commented Jan 4, 2022

done, and added a test.

@vchuravy vchuravy added GC Garbage collector tooling and removed needs news A NEWS entry is required for this change labels Jan 4, 2022
@vchuravy vchuravy merged commit c61cd12 into JuliaLang:master Jan 4, 2022
@vchuravy vchuravy deleted the pv-gc-logging branch January 4, 2022 23:22
@vilterp
Copy link
Copy Markdown
Contributor Author

vilterp commented Jan 4, 2022

Thanks Valentin!

@vilterp vilterp mentioned this pull request Jan 23, 2022
Merged
6 tasks
LilithHafner pushed a commit to LilithHafner/julia that referenced this pull request Feb 22, 2022
@vilterp @NHDaly @LilithHafner
GC: enable logging to stderr when GC runs (JuliaLang#43511)
93b1c9a 
Co-authored-by: Nathan Daly <NHDaly@gmail.com>
LilithHafner pushed a commit to LilithHafner/julia that referenced this pull request Mar 8, 2022
@vilterp @NHDaly @LilithHafner
GC: enable logging to stderr when GC runs (JuliaLang#43511)
12e1dba 
Co-authored-by: Nathan Daly <NHDaly@gmail.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Reviewers

@NHDaly NHDaly NHDaly approved these changes

@IanButterworth IanButterworth IanButterworth left review comments

@vchuravy vchuravy vchuravy approved these changes

@vtjnash vtjnash vtjnash approved these changes

Assignees

No one assigned

Labels

GC Garbage collector tooling

Projects

None yet

Milestone

No milestone

Development

Successfully merging this pull request may close these issues.

8 participants

@vilterp @KristofferC @DilumAluthge @vchuravy @NHDaly @sefffal @vtjnash @IanButterworth