Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Rule information during integration testing #393

Draft
wants to merge 20 commits into
base: main
Choose a base branch
from

Conversation

Soph1514
Copy link
Contributor

Enable getting all the rules in order of their application to a an essence problem and store them in a file. When cargo test is run, in addition to getting the parsed, rewritten model and the solutions, a list of rules for each test case will be generated and tested against the expected file.

@Soph1514 Soph1514 self-assigned this Oct 30, 2024
@Soph1514 Soph1514 marked this pull request as draft October 30, 2024 18:40
@ozgurakgun
Copy link
Contributor

I think this prints the name of the rule only, and not the expression it was applied to.

See

log::trace!(target: "file", "Rule applicable: {:?}, to Expression: {:?}, resulting in: {:?}", rule, expression, red.new_expression);
and
log::trace!(target: "file", "Rule attempted but not applied: {:?}, to Expression: {:?}", rule, expression);
-- I think these are closer to the output we want. You will have to enable them through the log library though.

@niklasdewally
Copy link
Collaborator

niklasdewally commented Oct 31, 2024

LGTM! Just have a few comments below to provide context on how we use log:

  • I agree that we should use Rusts logging functionality where possible. This gives us lots of flexibility down the line over the format and chattiness of the information. If you use the default logger on trace level, this should already go both to a file and stderr.

  • Optional: You could create a seperate log target for the rule logger, so that you can make it show up separately to the other logs, saved in a different file, say "rule_engine" before logs so we know what subsystem it came from, etc.

    For example, you could use this to write rule application traces in particular to a certain tester file, but also allow rules to be output in the main logs as normal during normal execution.

  • Optional: Writing a simple macro, log_rule_app! to wrap the call to whatever underlying logging / writing you do might be good. This way, you can change how you format these in one place, and your actual logging lines should be easier to write. See the parser logging macros below.

  • Nit: Ideally we should log to stderr not stdout (eprintln! instead of println!). I know that we aren't yet consistent on this across the codebase though!

For example, here's how we log the parser:

macro_rules! parser_trace {
($($arg:tt)+) => {
log::trace!(target:"jsonparser",$($arg)+)
};
}
macro_rules! parser_debug {
($($arg:tt)+) => {
log::debug!(target:"jsonparser",$($arg)+)
};
}

parser_debug!("Trying to parse vec_op: {key} ...");
let mut args_parsed: Option<Vec<Option<Expression>>> = None;
if let Some(abs_lit_matrix) = value.pointer("/AbstractLiteral/AbsLitMatrix/1") {
parser_trace!("... containing a matrix of literals");

Builder::with_level("TRACE")
//Builder::new()
.with_target_writer("info", new_writer(stdout()))
.with_target_writer("file,jsonparser", new_writer(log_file))
.init();

@@ -347,9 +351,13 @@ fn apply_all_rules<'a>(
/// }
///
fn choose_rewrite(results: &[RuleResult]) -> Option<Reduction> {
if results.len() > 1 {
bug!("There should be only 1 rule that can be applied to an expression at a time");
Copy link
Contributor

Choose a reason for hiding this comment

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

looks good! if it actually happens we would probably also want to print the names of the rules etc.

Copy link
Contributor

Choose a reason for hiding this comment

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

also: let's see if it code coverage correctly ignores this line.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

This caused a lot of integration tests to fail, does that mean there is a problem with our rules or the if statement?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Of course! I will have it print to the console for now and once I figure out the logging will implement that there

Copy link
Contributor

Choose a reason for hiding this comment

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

oh I was just meaning string concatanation to make the message you pass to bug! more descriptive. I'll check the failing tests.

Copy link
Contributor

Choose a reason for hiding this comment

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

yep, we need that message to tell us a bit more :)

it looks like multiple rules were applicable all over the place. good if statement!

Copy link
Contributor

Choose a reason for hiding this comment

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

I suggest we separate the two changes, as they are orthogonal. adding tracing (which is what this PR started as) is one change, adding the if statement and working on its implications should be another PR.

@Soph1514
Copy link
Contributor Author

Soph1514 commented Nov 1, 2024

To enable the following line log::trace!(target: "file", "Rule applicable: {:?}, to Expression: {:?}, resulting in: {:?}", rule, expression, red.new_expression); do I need to create a new builder in the main function? Or work with generated_tests.rs since I want the logging and file creation to happen when cargo test is run.

@niklasdewally
Copy link
Collaborator

niklasdewally commented Nov 1, 2024

To enable the following line log::trace!(target: "file", "Rule applicable: {:?}, to Expression: {:?}, resulting in: {:?}", rule, expression, red.new_expression); do I need to create a new builder in the main function? Or work with generated_tests.rs since I want the logging and file creation to happen when cargo test is run.

The latter sounds right 👍

Note that tests run in parallel, so you might want to wrap your builder in a OnceLock: https://doc.rust-lang.org/std/sync/struct.OnceLock.html.

This guarantees that the variable is initialised exactly once.

@niklasdewally
Copy link
Collaborator

niklasdewally commented Nov 1, 2024

Lazylock now exists, which seems much simpler than Oncelock
https://doc.rust-lang.org/std/sync/struct.LazyLock.html

@ozgurakgun
Copy link
Contributor

We want a separate log file per integration test, that is checked like we checked the other 3 files (expected/output style). Keep that in mind as well when choosing a logging library.

@Soph1514
Copy link
Contributor Author

Soph1514 commented Nov 3, 2024

I have managed to capture the trace from rewrite_model to files for all integration tests but only when the function is called inside the tracing::subscriber scope which then means we do not have access to the model itself. I couldn't create a global subscriber because it says a global default trace dispatcher has already been set. Where are we creating a global one because I could not find it in the code?

generated_tests.rs

let (subscriber, _guard) = create_scoped_subscriber(path, essence_base);
    tracing::subscriber::with_default(subscriber, || {
        // Create a span for the trace
        let test_span = span!(target: "rule_engine", Level::TRACE, "test_span");
        let _enter = test_span.enter();
        trace!(target: "rule_engine", "hello");
    });

    let model = rewrite_model(&model, &rule_sets)?;
    if verbose {
        println!("Rewritten model: {:#?}", model)
    }

@Soph1514
Copy link
Contributor Author

Soph1514 commented Nov 3, 2024

This does not produce an error though, only when I use tracing::subscriber.set_global it panics and says that a global one already exists. I was just wondering where is the global one defined in our repo so I could maybe try adding mother target to it?

@niklasdewally
Copy link
Collaborator

Sorry, I deleted my message as I looked deeper into the library you used and it does seem like the right tool for the job!

@niklasdewally
Copy link
Collaborator

This does not produce an error though, only when I use tracing::subscriber.set_global it panics and says that a global one already exists. I was just wondering where is the global one defined in our repo so I could maybe try adding mother target to it?

Do we need a global logger? Does having the scoped ones as you've shown above work?

@Soph1514
Copy link
Contributor Author

Soph1514 commented Nov 3, 2024

This does not produce an error though, only when I use tracing::subscriber.set_global it panics and says that a global one already exists. I was just wondering where is the global one defined in our repo so I could maybe try adding mother target to it?

Do we need a global logger? Does having the scoped ones as you've shown above work?

It only works if I put the function call inside the brackets of tracing::subscriber which leads to many issues, like inability to use ? and the model being dropped after the scope ends. I tried wrapping the last 2 test stages into the subscriber but then the compiler complains about asserts. I am just not sure how to approach this and I did not want to mess with the already established code much. Perpahs the model can be initialised outside first somehow and made mutable?

@niklasdewally
Copy link
Collaborator

niklasdewally commented Nov 3, 2024

It only works if I put the function call inside the brackets of tracing::subscriber which leads to many issues, like inability to use ? and the model being dropped after the scope ends. I tried wrapping the last 2 test stages into the subscriber but then the compiler complains about asserts. I am just not sure how to approach this and I did not want to mess with the already established code much. Perpahs the model can be initialised outside first somehow and made mutable?

It might be easier to use the logger for the entire lifetime of the thread, instead of just for the rewrite model bit? integration_test wraps the test code with setup/teardown code; if you put the logger in there, it should last for the entire duration of the test. However, this would mean that we could only check the logs at the end of test, during the teardown stage; not sure if this is suitable in this case?

(I am also not too familiar with tracing, so there might be a technical reason why this wouldn't work)

@niklasdewally
Copy link
Collaborator

niklasdewally commented Nov 3, 2024

Perpahs the model can be initialised outside first somehow and made mutable

With closures the usual solution is to use smart pointers / Arc as so:

let model_ptr1 = Arc::new(my_model);
let model_ptr2 = model_ptr1.clone();

do_some_stuff(move ||{
  check_my_model(*model_ptr1)
})

do_some_more_stuff(*model_ptr2)

The above code makes 2 pointers for the model, then gives ownership of the first pointer to the inside of do_some_stuff, to do some stuff with.

The main code keeps ownership of the second pointer, allowing it to also access the model. Arc keeps the model from being dropped until all the pointers cease to exist.

@niklasdewally
Copy link
Collaborator

niklasdewally commented Nov 3, 2024

For mutability, you would need to add a RefCell or a Mutex inside the Arc (depending on how thread safe you want to be, or required to be by tracing).

This can be messy, so I will defer the giving of an example to stack overflow:(https://stackoverflow.com/questions/31373255/how-do-i-share-a-mutable-object-between-threads-using-arc):

fn main() {
    let shared_stats = Arc::new(Mutex::new(Stats));
    let threads = 5;
    for _ in 0..threads {
        let my_stats = shared_stats.clone();
        thread::spawn(move || {
            let mut shared = my_stats.lock().unwrap();
            shared.add_stats(&Stats);
        });
        // Note: Immediately joining, no multithreading happening!
        // THIS WAS A LIE, see below
    }

Copy link
Contributor

github-actions bot commented Nov 4, 2024

Code and Documentation Coverage Report

Documentation Coverage

Click to view documentation coverage for this PR
+-------------------------------------+------------+------------+------------+------------+
| File                                | Documented | Percentage |   Examples | Percentage |
+-------------------------------------+------------+------------+------------+------------+
| crates/conjure_macros/src/lib.rs    |          2 |      66.7% |          1 |      33.3% |
+-------------------------------------+------------+------------+------------+------------+
| Total                               |          2 |      66.7% |          1 |      33.3% |
+-------------------------------------+------------+------------+------------+------------+
+-------------------------------------+------------+------------+------------+------------+
| File                                | Documented | Percentage |   Examples | Percentage |
+-------------------------------------+------------+------------+------------+------------+
| ...m_compatability_macro/src/lib.rs |          2 |     100.0% |          1 |      50.0% |
+-------------------------------------+------------+------------+------------+------------+
| Total                               |          2 |     100.0% |          1 |      50.0% |
+-------------------------------------+------------+------------+------------+------------+
+-------------------------------------+------------+------------+------------+------------+
| File                                | Documented | Percentage |   Examples | Percentage |
+-------------------------------------+------------+------------+------------+------------+
| solvers/kissat/src/lib.rs           |          0 |       0.0% |          0 |       0.0% |
+-------------------------------------+------------+------------+------------+------------+
| Total                               |          0 |       0.0% |          0 |       0.0% |
+-------------------------------------+------------+------------+------------+------------+
+-------------------------------------+------------+------------+------------+------------+
| File                                | Documented | Percentage |   Examples | Percentage |
+-------------------------------------+------------+------------+------------+------------+
| solvers/minion/src/ast.rs           |         11 |      11.0% |          0 |       0.0% |
| solvers/minion/src/error.rs         |          8 |     100.0% |          0 |       0.0% |
| solvers/minion/src/lib.rs           |          1 |     100.0% |          1 |     100.0% |
| solvers/minion/src/run.rs           |          2 |     100.0% |          1 |     100.0% |
| solvers/minion/src/wrappers.rs      |          1 |     100.0% |          0 |       0.0% |
+-------------------------------------+------------+------------+------------+------------+
| Total                               |         23 |      20.5% |          2 |      11.8% |
+-------------------------------------+------------+------------+------------+------------+
+-------------------------------------+------------+------------+------------+------------+
| File                                | Documented | Percentage |   Examples | Percentage |
+-------------------------------------+------------+------------+------------+------------+
| ...onjure_core/src/ast/constants.rs |          0 |       0.0% |          0 |       0.0% |
| .../conjure_core/src/ast/domains.rs |          0 |       0.0% |          0 |       0.0% |
| ...jure_core/src/ast/expressions.rs |         26 |      96.3% |          0 |       0.0% |
| crates/conjure_core/src/ast/mod.rs  |          0 |       0.0% |          0 |       0.0% |
| ...ure_core/src/ast/symbol_table.rs |          0 |       0.0% |          0 |       0.0% |
| ...es/conjure_core/src/ast/types.rs |          0 |       0.0% |          0 |       0.0% |
| ...onjure_core/src/ast/variables.rs |          1 |      50.0% |          0 |       0.0% |
| crates/conjure_core/src/bug.rs      |          1 |      50.0% |          1 |      50.0% |
| crates/conjure_core/src/context.rs  |          0 |       0.0% |          0 |       0.0% |
| crates/conjure_core/src/error.rs    |          1 |      14.3% |          0 |       0.0% |
| crates/conjure_core/src/lib.rs      |          0 |       0.0% |          0 |       0.0% |
| crates/conjure_core/src/metadata.rs |          0 |       0.0% |          0 |       0.0% |
| crates/conjure_core/src/model.rs    |          2 |      12.5% |          0 |       0.0% |
| ...core/src/parse/example_models.rs |          2 |     100.0% |          0 |       0.0% |
| ...es/conjure_core/src/parse/mod.rs |          0 |       0.0% |          0 |       0.0% |
| ...re_core/src/parse/parse_model.rs |          0 |       0.0% |          0 |       0.0% |
| ...jure_core/src/rule_engine/mod.rs |          5 |      71.4% |          5 |      71.4% |
| ...src/rule_engine/resolve_rules.rs |          3 |     100.0% |          0 |       0.0% |
| ..._core/src/rule_engine/rewrite.rs |          2 |      66.7% |          0 |       0.0% |
| ...ure_core/src/rule_engine/rule.rs |          3 |      25.0% |          1 |     100.0% |
| ...core/src/rule_engine/rule_set.rs |          4 |     100.0% |          0 |       0.0% |
| ...njure_core/src/rules/constant.rs |          1 |     100.0% |          0 |       0.0% |
| ...es/conjure_core/src/rules/mod.rs |          1 |     100.0% |          0 |       0.0% |
| ...re/src/solver/adaptors/kissat.rs |          1 |     100.0% |          0 |       0.0% |
| ...re/src/solver/adaptors/minion.rs |          1 |     100.0% |          0 |       0.0% |
| ..._core/src/solver/adaptors/mod.rs |          1 |     100.0% |          0 |       0.0% |
| ...s/conjure_core/src/solver/mod.rs |         14 |      33.3% |          1 |       4.2% |
| ...ore/src/solver/model_modifier.rs |          7 |      70.0% |          0 |       0.0% |
| ...onjure_core/src/solver/states.rs |          7 |      63.6% |          0 |       0.0% |
| ...es/conjure_core/src/stats/mod.rs |          0 |       0.0% |          0 |       0.0% |
| ...core/src/stats/rewriter_stats.rs |          1 |      20.0% |          0 |       0.0% |
| ...e_core/src/stats/solver_stats.rs |          3 |      37.5% |          0 |       0.0% |
+-------------------------------------+------------+------------+------------+------------+
| Total                               |         87 |      41.4% |          8 |       9.9% |
+-------------------------------------+------------+------------+------------+------------+
+-------------------------------------+------------+------------+------------+------------+
| File                                | Documented | Percentage |   Examples | Percentage |
+-------------------------------------+------------+------------+------------+------------+
| conjure_oxide/src/find_conjure.rs   |          1 |      50.0% |          0 |       0.0% |
| conjure_oxide/src/lib.rs            |          0 |       0.0% |          0 |       0.0% |
| conjure_oxide/src/utils/conjure.rs  |          0 |       0.0% |          0 |       0.0% |
| conjure_oxide/src/utils/json.rs     |          2 |      66.7% |          0 |       0.0% |
| conjure_oxide/src/utils/misc.rs     |          0 |       0.0% |          0 |       0.0% |
| conjure_oxide/src/utils/mod.rs      |          0 |       0.0% |          0 |       0.0% |
| conjure_oxide/src/utils/testing.rs  |          0 |       0.0% |          0 |       0.0% |
+-------------------------------------+------------+------------+------------+------------+
| Total                               |          3 |      10.3% |          0 |       0.0% |
+-------------------------------------+------------+------------+------------+------------+
Click to view documentation coverage for main
+-------------------------------------+------------+------------+------------+------------+
| File                                | Documented | Percentage |   Examples | Percentage |
+-------------------------------------+------------+------------+------------+------------+
| crates/conjure_macros/src/lib.rs    |          2 |      66.7% |          1 |      33.3% |
+-------------------------------------+------------+------------+------------+------------+
| Total                               |          2 |      66.7% |          1 |      33.3% |
+-------------------------------------+------------+------------+------------+------------+
+-------------------------------------+------------+------------+------------+------------+
| File                                | Documented | Percentage |   Examples | Percentage |
+-------------------------------------+------------+------------+------------+------------+
| ...m_compatability_macro/src/lib.rs |          2 |     100.0% |          1 |      50.0% |
+-------------------------------------+------------+------------+------------+------------+
| Total                               |          2 |     100.0% |          1 |      50.0% |
+-------------------------------------+------------+------------+------------+------------+
+-------------------------------------+------------+------------+------------+------------+
| File                                | Documented | Percentage |   Examples | Percentage |
+-------------------------------------+------------+------------+------------+------------+
| solvers/minion/src/ast.rs           |         11 |      11.0% |          0 |       0.0% |
| solvers/minion/src/error.rs         |          8 |     100.0% |          0 |       0.0% |
| solvers/minion/src/lib.rs           |          1 |     100.0% |          1 |     100.0% |
| solvers/minion/src/run.rs           |          2 |     100.0% |          1 |     100.0% |
| solvers/minion/src/wrappers.rs      |          1 |     100.0% |          0 |       0.0% |
+-------------------------------------+------------+------------+------------+------------+
| Total                               |         23 |      20.5% |          2 |      11.8% |
+-------------------------------------+------------+------------+------------+------------+
+-------------------------------------+------------+------------+------------+------------+
| File                                | Documented | Percentage |   Examples | Percentage |
+-------------------------------------+------------+------------+------------+------------+
| ...onjure_core/src/ast/constants.rs |          0 |       0.0% |          0 |       0.0% |
| .../conjure_core/src/ast/domains.rs |          0 |       0.0% |          0 |       0.0% |
| ...jure_core/src/ast/expressions.rs |         26 |      96.3% |          0 |       0.0% |
| crates/conjure_core/src/ast/mod.rs  |          0 |       0.0% |          0 |       0.0% |
| ...ure_core/src/ast/symbol_table.rs |          0 |       0.0% |          0 |       0.0% |
| ...es/conjure_core/src/ast/types.rs |          0 |       0.0% |          0 |       0.0% |
| ...onjure_core/src/ast/variables.rs |          1 |      50.0% |          0 |       0.0% |
| crates/conjure_core/src/bug.rs      |          1 |      50.0% |          1 |      50.0% |
| crates/conjure_core/src/context.rs  |          0 |       0.0% |          0 |       0.0% |
| crates/conjure_core/src/error.rs    |          1 |      14.3% |          0 |       0.0% |
| crates/conjure_core/src/lib.rs      |          0 |       0.0% |          0 |       0.0% |
| crates/conjure_core/src/metadata.rs |          0 |       0.0% |          0 |       0.0% |
| crates/conjure_core/src/model.rs    |          2 |      12.5% |          0 |       0.0% |
| ...core/src/parse/example_models.rs |          2 |     100.0% |          0 |       0.0% |
| ...es/conjure_core/src/parse/mod.rs |          0 |       0.0% |          0 |       0.0% |
| ...re_core/src/parse/parse_model.rs |          0 |       0.0% |          0 |       0.0% |
| ...jure_core/src/rule_engine/mod.rs |          5 |      71.4% |          5 |      71.4% |
| ...src/rule_engine/resolve_rules.rs |          3 |     100.0% |          0 |       0.0% |
| ..._core/src/rule_engine/rewrite.rs |          2 |      66.7% |          0 |       0.0% |
| ...ure_core/src/rule_engine/rule.rs |          3 |      25.0% |          1 |     100.0% |
| ...core/src/rule_engine/rule_set.rs |          4 |     100.0% |          0 |       0.0% |
| ...njure_core/src/rules/constant.rs |          1 |     100.0% |          0 |       0.0% |
| ...es/conjure_core/src/rules/mod.rs |          1 |     100.0% |          0 |       0.0% |
| ...re/src/solver/adaptors/kissat.rs |          1 |     100.0% |          0 |       0.0% |
| ...re/src/solver/adaptors/minion.rs |          1 |     100.0% |          0 |       0.0% |
| ..._core/src/solver/adaptors/mod.rs |          1 |     100.0% |          0 |       0.0% |
| ...s/conjure_core/src/solver/mod.rs |         14 |      33.3% |          1 |       4.2% |
| ...ore/src/solver/model_modifier.rs |          7 |      70.0% |          0 |       0.0% |
| ...onjure_core/src/solver/states.rs |          7 |      63.6% |          0 |       0.0% |
| ...es/conjure_core/src/stats/mod.rs |          0 |       0.0% |          0 |       0.0% |
| ...core/src/stats/rewriter_stats.rs |          1 |      20.0% |          0 |       0.0% |
| ...e_core/src/stats/solver_stats.rs |          3 |      37.5% |          0 |       0.0% |
+-------------------------------------+------------+------------+------------+------------+
| Total                               |         87 |      41.4% |          8 |       9.9% |
+-------------------------------------+------------+------------+------------+------------+
+-------------------------------------+------------+------------+------------+------------+
| File                                | Documented | Percentage |   Examples | Percentage |
+-------------------------------------+------------+------------+------------+------------+
| conjure_oxide/src/find_conjure.rs   |          1 |      50.0% |          0 |       0.0% |
| conjure_oxide/src/lib.rs            |          0 |       0.0% |          0 |       0.0% |
| conjure_oxide/src/utils/conjure.rs  |          0 |       0.0% |          0 |       0.0% |
| conjure_oxide/src/utils/json.rs     |          2 |      66.7% |          0 |       0.0% |
| conjure_oxide/src/utils/misc.rs     |          0 |       0.0% |          0 |       0.0% |
| conjure_oxide/src/utils/mod.rs      |          0 |       0.0% |          0 |       0.0% |
| conjure_oxide/src/utils/testing.rs  |          0 |       0.0% |          0 |       0.0% |
+-------------------------------------+------------+------------+------------+------------+
| Total                               |          3 |      10.3% |          0 |       0.0% |
+-------------------------------------+------------+------------+------------+------------+
+-------------------------------------+------------+------------+------------+------------+
| File                                | Documented | Percentage |   Examples | Percentage |
+-------------------------------------+------------+------------+------------+------------+
| solvers/kissat/src/lib.rs           |          0 |       0.0% |          0 |       0.0% |
+-------------------------------------+------------+------------+------------+------------+
| Total                               |          0 |       0.0% |          0 |       0.0% |
+-------------------------------------+------------+------------+------------+------------+

Code Coverage Summary

This PR: Detailed Report

  lines......: 73.2% (3183 of 4349 lines)
  functions..: 45.8% (369 of 806 functions)
  branches...: no data found

Main: Detailed Report

  lines......: 73.1% (3175 of 4341 lines)
  functions..: 45.7% (368 of 805 functions)
  branches...: no data found

Coverage Main & PR Coverage Change

Lines coverage changed by 0.10% and covered lines changed by 8
Functions coverage changed by 0.10% and covered lines changed by 1
Branches... coverage: No comparison data available

@ozgurakgun
Copy link
Contributor

This is looking good so far.

Should we change the filenames to something like:

BASENAME.expected-rule-trace.txt
BASENAME.generated-rule-trace.txt

like the other 3 files?

We would then update the accept code paths as well.

@Soph1514
Copy link
Contributor Author

Soph1514 commented Nov 4, 2024

That would be my next step. Just wanted to make it work first:)

niklasdewally added a commit to niklasdewally/conjure-oxide that referenced this pull request Nov 4, 2024
- Replace `structured_logger` with `tracing-subscribers` for log output.
- Add stderr logging, configurable with the --verbose flag, and the
  RUST_LOG environment variable. The former changes the default log
  level to DEBUG and makes print format more verbose, the latter adjusts
  the log level.

Previously, we were using `log` to produce logs, and `structured_logger`
to put them in a file.

For debugging, I want configurable logging to stderr; however,
`structured_logger` does not allow different outputs to have different
formats or log levels.

We begin to use the `tracing` library as well as `log` for the rule
engine in PR conjure-cp#393 due to its better multi-threading support.
`trace_subscriber::fmt`, the `tracing` log writer used in this patch,
automatically intercepts `log` messages. Thus, the logger can now see
messages from both systems, instead of just `log`.

Long term I believe that `tracing` will be a better choice than `log`
and should be used everywhere; however, for now, supporting both in our
log output is sensible.
Copy link
Collaborator

@niklasdewally niklasdewally left a comment

Choose a reason for hiding this comment

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

Looks good so far, just a few comments.

Cloning this branch caused my git submodules to freakout and minion to fail the build, but this could just be me.

@@ -0,0 +1 @@
Event { fields: ValueSet { message: trace test, callsite: Identifier(0x557b0aba4020) }, metadata: Metadata { name: "event conjure_oxide/tests/generated_tests.rs:77", target: "rule_engine", level: Level(Trace), module_path: "generated_tests", location: conjure_oxide/tests/generated_tests.rs:77, fields: {message}, callsite: Identifier(0x557b0aba4020), kind: Kind(EVENT) }, parent: Current }
Copy link
Collaborator

Choose a reason for hiding this comment

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

callsite: ... might cause issues on different computers?

readme 2.md Outdated
Copy link
Collaborator

Choose a reason for hiding this comment

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

Delete this

@@ -310,10 +325,10 @@ fn assert_constants_leq_one(parent_expr: &Expression, exprs: &[Expression]) {
assert!(count <= 1, "assert_vector_operators_have_partially_evaluated: expression {} is not partially evaluated",parent_expr)
}

// using a custom formatter to ommit the span name in the log
struct CustomFormatter;
// using a custom formatter to omit the span name in the log
Copy link
Collaborator

Choose a reason for hiding this comment

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

Why do we need to do this ourselves instead of using builtin stuff, such as:

layer =    fmt::layer()
                .with_writer(non_blocking)
                .json()
                .with_current_span(false)
               .with_span_list(false)

or, via format:

let format = fmt::format().
       .with_current_span(false)
       .with_span_list(false)
      .json()

layer =   fmt::layer()
                .with_writer(non_blocking)
                .event_format(format),

(https://docs.rs/tracing-subscriber/0.3.18/tracing_subscriber/fmt/index.html#customizing-formatters)

Copy link
Collaborator

Choose a reason for hiding this comment

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

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

4 participants