Sunshine icon indicating copy to clipboard operation
Sunshine copied to clipboard

Include milliseconds in logging timestamps

Open ns6089 opened this issue 1 year ago • 3 comments

Description

Include milliseconds in logging timestamps and improve formatting while at it. Should now give better idea how long individual steps take (shader compilation, encoder probing, etc).

Screenshot

Before

[2024:08:04:22:33:15]: Info: Sunshine version: 0.0.0.f8b0be1e

After

[2024-08-04 22:33:15.623] Info: Sunshine version: 0.0.0.f8b0be1e

Issues Fixed or Closed

Type of Change

  • [ ] Bug fix (non-breaking change which fixes an issue)
  • [x] New feature (non-breaking change which adds functionality)
  • [ ] Breaking change (fix or feature that would cause existing functionality to not work as expected)
  • [ ] Dependency update (updates to dependencies)
  • [ ] Documentation update (changes to documentation)
  • [ ] Repository update (changes to repository files, e.g. .github/...)

Checklist

  • [x] My code follows the style guidelines of this project
  • [x] I have performed a self-review of my own code
  • [x] I have commented my code, particularly in hard-to-understand areas
  • [x] I have added or updated the in code docstring/documentation-blocks for new or existing methods/components

ns6089 avatar Aug 04 '24 20:08 ns6089

If we're going to adjust the logging format, can we improve the readability a little more?

I'm not an expert on boost logging, but can we do something like this?

2024-08-04 22:33:15.623 - INFO :: <module/file that called the message... or the thread> : <the message>

ReenigneArcher avatar Aug 04 '24 22:08 ReenigneArcher

It's possible, but in my opinion we shouldn't.

It will

  • add quite a bit of informational bloat
  • break message alignment
  • be entirely useless for users
  • be not very useful for us (copy-pasting and searching the codebase for message keywords is near instantaneous and hasn't failed me once for sunshine)

So yeah. Small changes that objectively improve the situation (conventional date separating symbols, removing needless ':') I can do. Large subjective changes, I'd rather not.

ns6089 avatar Aug 05 '24 07:08 ns6089

I agree with your points, I was just thinking it would allow us to not have to search and we could go directly the point in the code... I guess it's not incredibly value added, unless the message is from outside of Sunshine's codebase.

I would like the log format to be like this though if you could.

2024-08-04 22:33:15.623 - INFO :: <the message>

ReenigneArcher avatar Aug 05 '24 13:08 ReenigneArcher

I would like the log format to be like this though if you could. 2024-08-04 22:33:15.623 - INFO :: <the message>

No strong opinion on this, but I don't want it to be traced to my commit since I have nothing to do with the decision.

I've updated this PR leaving only the timestamp change. The rest can be done outside without any deep c++ knowledge. https://github.com/ns6089/Sunshine/blob/4dc34b0e670cbad5577cd2bce8d83b2a5e9a833a/src/logging.cpp#L77-L92 https://github.com/ns6089/Sunshine/blob/4dc34b0e670cbad5577cd2bce8d83b2a5e9a833a/src/logging.cpp#L103 https://github.com/ns6089/Sunshine/blob/4dc34b0e670cbad5577cd2bce8d83b2a5e9a833a/src_assets/common/assets/web/index.html#L145

ns6089 avatar Aug 08 '24 06:08 ns6089

Codecov Report

All modified and coverable lines are covered by tests :white_check_mark:

Project coverage is 9.68%. Comparing base (04df80f) to head (5ba5065). Report is 138 commits behind head on master.

Additional details and impacted files
@@            Coverage Diff            @@
##           master   #2963      +/-   ##
=========================================
+ Coverage    9.67%   9.68%   +0.01%     
=========================================
  Files          97      97              
  Lines       17526   17528       +2     
  Branches     8199    8200       +1     
=========================================
+ Hits         1696    1698       +2     
+ Misses      13052   12993      -59     
- Partials     2778    2837      +59     
Flag Coverage Δ
Linux 7.19% <85.71%> (+0.01%) :arrow_up:
Windows 5.11% <100.00%> (+0.01%) :arrow_up:
macOS-12 10.37% <71.42%> (+0.03%) :arrow_up:
macOS-13 10.26% <71.42%> (+0.02%) :arrow_up:
macOS-14 10.58% <71.42%> (+0.02%) :arrow_up:

Flags with carried forward coverage won't be shown. Click here to find out more.

Files with missing lines Coverage Δ
src/logging.cpp 81.30% <100.00%> (+0.35%) :arrow_up:

... and 26 files with indirect coverage changes

codecov[bot] avatar Aug 08 '24 13:08 codecov[bot]

Added an #include statement. It should fix failing builds on some platforms (hopefully).

ns6089 avatar Aug 08 '24 13:08 ns6089