Logging Overhaul

[patmuk]

Changes

Please list issues fixed by this PR here, using format "Fixes #the-issue-number".

Checklist

• An issue to be fixed by this PR is listed above.
• New tests are added to ensure new features are working. Please refer to this page to see how to add a test.
• ./frb_internal precommit --mode slow (or fast) is run (it internal runs code generator, does auto formatting, etc).
• If this PR adds/changes features, documentations (in the ./website folder) are updated.
• CI is passing. Please refer to this page to see how to solve a failed CI.

Remark for PR creator

• ./frb_internal --help shows utilities for development.
• If fzyzcjy does not reply for a few days, maybe he just did not see it, so please ping him.

[patmuk]

@fzyzcjy I cleaned up the branch ... that is, I needed to create a new branch. As I could not swap the branch from the old PR (#2303) I created this new one.

Will close the old one if this (macro) approach is working :)

[patmuk]

I solved the dependency issue, but I have a code generation issue now:

In the macro code, in frb_rust/src/log_2_dart.rs I get:

  --> /Users/patmuk/code/own/oss/frb/flutter_rust_bridge_fork_pat/frb_rust/src/log_2_dart.rs:81:17
   |
81 |             use frb_generated::StreamSink;
   |                 ^^^^^^^^^^^^^ use of undeclared crate or module `frb_generated`

Clearly, in this code I have not generated code. But I need to refer to the StreamSink, which should be generated ...

Do you have an advice how to progress?

1. I could copy the generated code for the StreamSink to the macro as well - but this way we are close (back?) to the non-macro way in PR Logging overhaul #2303
2. I could probably inject it as a parameter of the macro ... but then the StreamSink needs to be defined in the users project - not a very clean solution
3. statically calling code generation?

I am sure you have a better idea :) It is a bit cat-and-mouse: The logger code should be generated (actually integrated), but it needs the StreamSink to be generated to work ...

As for solving the log dependency:
For using log::info!() in the user's rust code, he needs to use flutter_rust_bridge::log_2_dart::log; (with no modification on the cargo.toml, or use log;, but then importing the crate in the cargo.toml. While the latter can be done when creating a project the first time (in the cargo.toml template you pointed me to), it is a breaking change that needs to be migrated for users with existing projects.

Nevertheless, I want to leave this decision open until I see if use flutter_rust_bridge::log_2_dart is needed anyways - maybe to solve the problem above.

[fzyzcjy]

In the macro code

Standard Rust would need crate::frb_generated::... to find the frb_geneated.rs

[patmuk]

Standard Rust would need crate::frb_generated::... to find the frb_geneated.rs

The problem is, that there is no struct StreamSink declared yet. It is generated later.

error[E0432]: unresolved import `crate::frb_generated`
 --> /Users/patmuk/code/own/oss/frb/flutter_rust_bridge_fork_pat/frb_rust/src/log_2_dart.rs:4:12
  |
4 | use crate::frb_generated::StreamSink;
  |            ^^^^^^^^^^^^^ could not find `frb_generated` in the crate root
error[E0412]: cannot find type `StreamSink` in this scope
  --> /Users/patmuk/code/own/oss/frb/flutter_rust_bridge_fork_pat/frb_rust/src/log_2_dart.rs:87:30
   |
87 |                 stream_sink: StreamSink<Log2DartLogRecord>,
   |                              ^^^^^^^^^^ not found in this scope
   |
  ::: /Users/patmuk/code/own/oss/frb/flutter_rust_bridge_fork_pat/frb_rust/src/misc/user_utils.rs:10:5
   |
10 |     setup_logging!();
   |     ---------------- in this macro invocation
   |
   = note: this error originates in the macro `setup_logging` (in Nightly builds, run with -Z macro-backtrace for more info)
error[E0412]: cannot find type `StreamSink` in this scope
  --> /Users/patmuk/code/own/oss/frb/flutter_rust_bridge_fork_pat/frb_rust/src/log_2_dart.rs:92:29
   |
92 |                 log_stream: StreamSink<Log2DartLogRecord>,
   |                             ^^^^^^^^^^ not found in this scope
   |
  ::: /Users/patmuk/code/own/oss/frb/flutter_rust_bridge_fork_pat/frb_rust/src/misc/user_utils.rs:10:5
   |
10 |     setup_logging!();
   |     ---------------- in this macro invocation
   |
   = note: this error originates in the macro `setup_logging` (in Nightly builds, run with -Z macro-backtrace for more info)
Some errors have detailed explanations: E0412, E0432.
For more information about an error, try `rustc --explain E0412`.

[fzyzcjy]

A deeper review, but mainly are nits :)

[fzyzcjy]

todo(fzyzcjy): optimize the doc

(you don't need to do anything - this note is for me)

[patmuk]

Okay. Note that I rewrote the docs after making the logging better to use. Feel free to change it anywhere you like :)

[fzyzcjy]

looks like logger initialization indeed has multiple things. maybe we can separate them. for example:

1. setup rust logging, such that whenever rust log::info!("hi"), it is forwarded to dart logging log.info("hi"). in this function, we do not configure any dart logging outputs / min levels etc.
2. another separate thing: configure a (default) Logger.root.level and Logger.root.onRecord.

[patmuk]

I changed the API, so that the configuration is simpler.

These settings need to happen at the same time.
The problem is this code:

    pub fn initialize_log2dart(log_stream: crate::frb_generated::StreamSink<Log2DartLogRecord>, max_log_level: u16) {
      log::set_boxed_logger(Box::new(FRBLogger {
        stream_sink: log_stream,
      }))
      .map(|()| log::set_max_level(from_u16(max_log_level)))
      .expect("initialize_log2dart is called only once!");
(...)

Because I move the FRBLogger into log:: I cannot change the log level subsequentially anymore.
In between I had a version where one could set this and the logging function later in the program execution - but while I was struggling with lifetimes I thought that a user might never need to change these later in a program.

If it is just to make the function smaller and easier to read: Sure, we can split it up. But eventually it needs to be called at once.

[fzyzcjy]

But eventually it needs to be called at once.

By default yes. But users should be free to customize etc.

Suppose a simple example: User may like to have Rust log forward to Dart, but at the same time, he or she already setup the dart logging (e.g. his own Logger.root.level, his own Logger.root.onRecord, let's say he sends it to Sentry instead of printing for some reason). Then he should not call our 2nd function.

[fzyzcjy]

I cannot change the log level subsequentially anymore.

What about

pub fn another_function_that_freely_changes_log_level(){
  log::set_max_level(TRACE)
}

seems we can change the level

[patmuk]

Ok, I will look into it. I forgot why I wasn't able to change it after the initialization ... maybe it was a temporary limitation during refactoring ...

But let's first refactor where the code will be generated to, do unit tests - and then I will enable setting the log level after initialization.

As for your example, a user could create another logger for Sentry, that inherits from the FRB created root logger and change anything he likes there.

But in general, I think if a user changes something using this logging implementation, it should always apply to both sides, rust and dart. That way it is least surprising :)

[fzyzcjy]

todo(fzyzcjy): review this core file again after it is modified

[patmuk]

Now I am thinking if it wouldn't have been better to implement logging from the other side around: Send Dart logs to rust.
That way we might not need macros, as from the Dart code it would just call the rust log function ... I could implement that in addition, have the user configure the direction he likes.

For me personally it would depend how to handle logging configuration best - I here I lack the experience. I mean, would it be better to have log outputs configured via rust (using opinionated_logger, thus one logger for codegen and prod, OSLogger and Android crates, ... maybe some fancy Network logging ...) or better in the Flutter ecosystem (maybe better integrated in the mobile OSs, into firebase crashlytics, etc.).

For now I am undecided and would first gather some experience. I understood that in your product you forward the rust logs to dart as well, right?
Nevertheless, I think dart->rust would be very easy to implement (in fact easier than what I did ... duh).

[fzyzcjy]

Send Dart logs to rust

Hmm, if the user is "using Rust for e.g. computation-heavy work for the Flutter app", then I guess he or she will have already setup the Dart logging system before adding frb or Rust code, and thus "send rust logs to dart" would be a good default choice.

My personal choice for my app is also send Rust log to Dart.

That way we might not need macros

I guess it still needs macros (for complex scenarios at least)

[patmuk]

Send Dart logs to rust

(...) I guess he or she will have already setup the Dart logging system before (...)

True.

My personal choice for my app is also send Rust log to Dart.

Thanks for sharing.

That way we might not need macros

I guess it still needs macros (for complex scenarios at least)

True - at least the rust calls to be called by the Dart logging function (if Dart -> rust) need to be wired ... so the macro is a must.

I am currently simplifying the usage a bit. If you like you can already have a look - but I will extend the macro with the same optional parameters as the dart function init_logger so that less code is needed :)

[patmuk]

I finished the improvements - feel free to review this PR!

[patmuk]

Oh, I overlooked that you did already a review! Working through your comments now!

[patmuk]

I finished working through your review. Many thanks!

Now only until tests are to-be-done.
I am contemplating to implement a Dart-to-Rust option as well, while I have this fresh in mind. I would do so by splitting up the macro (internally) and giving it a 4th parameter, on which dependence different code parts are inserted, so either rust logs are forwarded via a stream to dart (current implementation) or dart logs are processed by dart calling the rust log function.

Sounds easy, but is probably not needed, as discussed before ...

For now I will hold still until we resolved the above discussions.

The bloating of the minimal.rs is a bad think, would be good if we find a way to put the logging code into frb_generated or similar.

[fzyzcjy]

Great and you are welcome!

Dart-to-Rust option

I guess we can add this option in doc only and mention "if you want it, create an issue and discuss your scenarios". I personally think this will not be very frequently needed, thus we can save time efforts not implementing it, but I can be totally wrong!

The bloating of the minimal.rs is a bad think, would be good if we find a way to put the logging code into frb_generated or similar.

Totally agree (see my reply above)

[patmuk]

I did not implement any tests

No worries, we can do it last. Yes just do things in pure_dart. Probably add a few lines mimicking e.g.

flutter_rust_bridge/frb_example/pure_dart/test/api/misc_no_twin_example_a_test.dart

Line 10 in 4f5cf68

test('ItemContainerSolutionOneTwinNormal', () async {

I looked into it, but it is not so easy to understand ... it would help, if you can give me a kick-start here: If you could implement a test for the default settings, meaning implementing a test that calls enable_frb_logging!() on the rust side and executes a log::info!('whatever rust') from Rust and a FRBLogger.getLogger(whatever dart) from Dart, that would be great!

Based on that I can do all the other scenarios.

As for asserting the test result, if it is too complicated to assert what has been written to the console we can set a custom log function that writes into a variable instead.

[fzyzcjy]

(just happen to see this, thus this isolated nit)

[fzyzcjy]

nit: thinking about what an end user sees. feel free to discuss!

In main.dart

Nothing. There is no line related to logging setup.

In minimal.rs

i.e. what should be the code in minimal.rs, which can either by our default template, or by telling users to migrate to

choice 1

flutter_rust_bridge::setup_default_logging!();

#[frb(init)]
pub fn init_app() {
    flutter_rust_bridge::setup_default_user_utils();
}

choice 2

flutter_rust_bridge::setup_default_user_utilities!();

(the name is explicitly a bit different to avoid making a macro and a function same name to confuse users. the current hacky proposed name looks not good... feel free to propose a better name!)

where setup_default_user_utils's definition is, "call setup_default_logging + that fn init_app".
and we still allow customizations. For example, suppose one wants to remove logging, but keep others, then he or she can remove setup_default_user_utils, and copy-paste the fn initapp or whatever he likes.

pros: less confusing to users (in choice 1, users may think "why logging is not user utils?")

pros: less verbose (in choice 1, user may think "oh so many lines")

cons: a bit less explicit. (but users can click that macro to see what is going on, so maybe acceptable)

I personally prefer choice 2, what do you think?

[patmuk]

I agree with choice 2 as well :) probably there will be more supporting tools in future - and then it would get very (too) verbose. So hiding that all behind something like setup_default_(...) sounds very good to me :)

I am quite confident, the I can rewrite the code so that the customizing can be done any time ... from setting the log level to a custom log function.

I think this would work from both sides - meaning one could call a Rust function set_custom_log_fn from minimal.rs or main.dart. So my next question is not very relevant, but: We are assuming a user would do the logging configuration preferably from Dart, right?

Thus, for setting the log level one needs to use the Dart logging package's definition (which I find quite unusual ...), even when setting it from Rust. I could easily change this though, I was aiming for consistency.

As for the custom log function, if set from Dart it shall be Dart code, if set from Rust Rust code. I think we can change this as well, but that requires a bit more effort. But probably this is a good default.

So, to summarize, I think it would be best if:

1. logging gets automatically initialized with defaults, triggered as part of RustLib.init()
2. A user would disable this by not having the log feature active
3. thus, there is no visible code in neither main.dart, nor minimal.rs
4. issuing log statements works as usual in the respective language (Logger().info('from Dart), log::info(from Rust) - this should already work :)
5. Customizing the log level can be done from both, Dart or Rust code
6. the generated code ends up in frb_generated.rs/dart and not minimal.rs

For (6.), I wasn't able to get it there - the StreamSink was never processed. I tried calling the macro in frb_rust/src/for_generated/boilerplate.rs, frb_rust/src/misc/user_utils.rs, etc. Probably you see right away what needs to be fixed :)

[fzyzcjy]

probably there will be more supporting tools in future

Totally agree. Choice 1 will require user to migrate again at that time which is not optimal.

Agree 1-6! Except minor details:

A user would disable this by not having the log feature active

I guess by simply copy-paste content in setup_default_user_utilities and remove the one about logging.
Using feature for this, personally speaking, may be a little bit overkill, and a bit less flexible.

Customizing the log level can be done from both, Dart or Rust code

Yes, for simplicity (of our implementation), users can use Rust and Dart's native mechanism to set logging level respectively.

the generated code ends up in frb_generated.rs/dart and not minimal.rs

I will handle that

[patmuk]

A user would disable this by not having the log feature active

I guess by simply copy-paste content in setup_default_user_utilities and remove the one about logging. Using feature for this, personally speaking, may be a little bit overkill, and a bit less flexible.

Yes, true, that would be a way as well. I was referring to the already existing feature flag 'log' - I used #[cfg(feature = "log")] wherever it made sense :)

Customizing the log level can be done from both, Dart or Rust code

Yes, for simplicity (of our implementation), users can use Rust and Dart's native mechanism to set logging level respectively.

Oh yes, we can just use the usual functions for setting the log level - will do that.

the generated code ends up in frb_generated.rs/dart and not minimal.rs

I will handle that

Ah, great , thanks :)

[fzyzcjy]

That flag was there because I wanted frb_rust to have minimal dependency if a user wants it. It accidentally also controls that existing behavior...

[patmuk]

Good idea :) Ah, ok. If this flag is needed always for the existing behavior (mandatory parts?) I would suggest to remove it from these and repurpose it for this logging implementation. Probably users have used it for that. I actually assume that probably nobody deactivated it ... as this is not so straight-forward in Rust.

[fzyzcjy]

btw, maybe we can add a few lines in codegen to sanity check, if we find the string setup_default_user_utils, maybe we just log::warn!("Please migrate to new default user utils, see some_url_link_here for details") in codegen.

[patmuk]

I think that would be great!