[#464] file logger

[elfenpiff]

Notes for Reviewer

Implements a simple file logger that does not use any additional crates and where we can add a simple C/C++ binding for it to be able to exchange loggers from different languages.

Pre-Review Checklist for the PR Author

1. Add sensible notes for the reviewer
2. PR title is short, expressive and meaningful
3. Relevant issues are linked in the References section
4. Every source code file has a copyright header with SPDX-License-Identifier: Apache-2.0 OR MIT
5. Branch follows the naming format (iox2-123-introduce-posix-ipc-example)
6. Commits messages are according to this guideline
   • Commit messages have the issue ID ([#123] Add posix ipc example)
   • Commit author matches Eclipse Contributor Agreement (and ECA is signed)
7. Tests follow the best practice for testing
8. Changelog updated in the unreleased section including API breaking changes
9. Assign PR to reviewer
10. All checks have passed (except task-list-completed)

Checklist for the PR Reviewer

• Commits are properly organized and messages are according to the guideline
• Unit tests have been written for new behavior
• Public API is documented
• PR title describes the changes

Post-review Checklist for the PR Author

1. All open points are addressed and tracked via issues

References

Relates to #464

[codecov]

Codecov Report

Attention: Patch coverage is 0% with 65 lines in your changes missing coverage. Please review.

Project coverage is 78.92%. Comparing base (51c619e) to head (fa4a525).
Report is 40 commits behind head on main.

Files with missing lines	Patch %	Lines
iceoryx2-bb/log/src/logger/file.rs	0.00%	65 Missing ⚠️

Additional details and impacted files

@@            Coverage Diff             @@
##             main     #465      +/-   ##
==========================================
- Coverage   79.14%   78.92%   -0.22%     
==========================================
  Files         196      197       +1     
  Lines       23538    23637      +99     
==========================================
+ Hits        18629    18656      +27     
- Misses       4909     4981      +72     

Files with missing lines	Coverage Δ
iceoryx2-bb/log/src/logger/file.rs	0.00% <0.00%> (ø)

... and 6 files with indirect coverage changes

[orecham]

Looks fine for me, will let @elBoberido comment on the Rust. Ping me if needed.

[xieyuschen]

Regards on the log level, currently i saw we use a static log level to do so. But if we have supported the file logger, I believe it's reasonable to spawn multiple loggers which writes to different files(such as errors.log and info.log, debug.log) in the future.

Probably it's nice to let the logger holds its own log level, it allows us spawn many file loggers with different level.

[elfenpiff]

But this would still be possible with this approach. You could create a custom MultiFileLogger which uses a log file for every log level.

[xieyuschen]

Just curious, why does the creation time of a logger matters for each piece of log here. Looks like it's not a useful information for each piece of log.

[elfenpiff]

• timestamp - useful when debugging many processes that log in many log files to have some kind of total order across these log files. But the UNIX time stamp does not really tell you if the thing occurred during the start of a program or after running for hours
• elapsed_time - Maybe a better name is needed. Useful when you have a bug that always occurs 10 seconds after starting the process (we already had some of them). Then you start investigating the logs that were created around 10 seconds after process startup.

So the elapsed_time relates somehow to the process startup time since the logger is the first thing that is created in a process.

[xieyuschen]

Useful when you have a bug that always occurs 10 seconds after starting the process (we already had some of them).

I see, it may help you to figure out the bugs before. But does the gap(500ms or less?) between starting process and logger creation matters for a fragile and weird bug?

[elfenpiff]

We are talking here about single-digit micro-seconds so I think it is fine. This will never be perfect but we try to provide as much insights as possible for the next developer that has to debug something.

[xieyuschen]

will sync_all cost a lot for every piece of messages? I have searched the forum mentioned it in this post. Hdyt?

B) Asking the OS to dump its in-memory ... . it can be a slow and expensive operation.
This operation is not required for data to become visible to other applications.

[elBoberido]

I guess the idea was to have the logs available when a crash occurs. Maybe this can be done via a crash handler. On the other side, AFAIK there are no logs in the hot path, so it should also not affect performance.

[xieyuschen]

AFAIK there are no logs in the hot path

Every log call will send a message and the write_buffer_to_file will call sync_all, it's in the hot path.
It's a bit different from previously the continuous log call will make the queue not empty so sync_all won't be triggered. PCMIIW

[elfenpiff]

This is why all of this is handled in a background thread. The hot path just uses the channel to move the log message out of the hot thread into the log thread.

[elfenpiff]

I think the worst case scenario is, when a crash happens and the logger didn't sync the file and therefore the final log messages are not written.

However, I also want to highlight that this does not need to be the final implementation. If we realize this becomes a bottleneck we can put on our thinking caps and try harder.

[xieyuschen]

LGTM, thanks for your clarify.