crystal-lang / crystal

The Crystal Programming Language
https://crystal-lang.org
Apache License 2.0
19.21k stars 1.61k forks source link

Add `Crystal::Tracing` for runtime tracing #14659

Closed ysbaddaden closed 2 weeks ago

ysbaddaden commented 1 month ago

Implements tracing of the garbage collector and the scheduler as per #14618

Tracing is enabled by compiling with -Dtracing then individual tracing must be enabled at runtime with the CRYSTAL_TRACE environment variable that is a comma separated list of sections to enable, for example:

The traces are printed to the standard error by default, but this can be changed at runtime with the CRYSTAL_TRACE_FILE environment variable. For example trace.log. You can also redirect the standard error to a file (e.g. 2> trace.log on UNIX shell).

Technical note: tracing happens before the stdlib is initialized, so the implementation must rely on some LibC methods directly (i.e. read environment variable, write to file descriptor) and can't use the core/stdlib abstractions.

Note: the Thread#current_thread? commit could be extracted into a distinct PR. Done: #14660

straight-shoota commented 1 month ago

the Thread#current_thread? commit could be extracted into a distinct PR.

Then let's do that, please 🙏

ysbaddaden commented 3 weeks ago

@straight-shoota following your review, I made the following changes:

  1. I replaced the Crystal.trace macro with a couple def methods (one that yield and one that don't), which led to:

    • the operation arg is now always a String :+1:
    • the method still yields twice, but this is no longer injecting the code twice, so it should be fine?
  2. I replaced the LibC.WideCharToMultiByte call with a pure Crystal alternative that leverages String.each_utf16_char(slice, &) and loops to avoid a buffer overflow and splitting a multibyte char across multiple prints.

ysbaddaden commented 3 weeks ago

Thanks @straight-shoota. I applied all your suggestions!

ysbaddaden commented 3 weeks ago

I noticed that one macro used constant.downcase while the other used lowerscore in a completely different place, so I grouped the logic into the Tracing::Section enum as a couple methods: .from_id(slice) and #to_id (instead of #id) and now both are using lowerscore.