Profile identities #1473
Profile identities #1473
Conversation
chriseth
force-pushed
the
profile_identities
branch
from
67044e0
to
cefbe70
Compare
| /// The event log is a list of (event, <ID>, time) tuples. | ||
| static EVENT_LOG: RefCell<Vec<(Event, usize, Instant)>> = const { RefCell::new(Vec::new()) }; | ||
| /// The event log is a list of events. | ||
| static EVENT_LOG: RefCell<Vec<Event>> = const { RefCell::new(Vec::new()) }; |
There was a problem hiding this comment.
Maybe we rename this to EVENT_LOG_BY_MACHINE?
There was a problem hiding this comment.
Actually, same goes for a few names in this file that are specific to the by-machine profiling, like NAME_TO_ID, record_start, record_end, reset_and_print_profile_summary, ...
|
|
||
| use crate::witgen::FixedData; | ||
|
|
||
| pub static UNUSED_IDENTITY_ID: u64 = u64::MAX; |
There was a problem hiding this comment.
| pub static UNUSED_IDENTITY_ID: u64 = u64::MAX; | |
| pub static NO_IDENTITY_ID: u64 = u64::MAX; |
Maybe this?
| let updates = match updates { | ||
| Ok(updates) => updates, | ||
| Err(e) => { | ||
| record_end_identity(identity.id); | ||
| return Err(e); | ||
| } | ||
| }; |
There was a problem hiding this comment.
Hmm, should we wrap this function instead? I can imagining somebody to put a question mark in the future and then the log is inconsistent.
There was a problem hiding this comment.
Ah nooo ^^
I debugged the error I mentioned in the other comment, and it's actually not because of that but because there is an record_end_identity(identity.id); missing before the return in 256...
| record_start_identity(profiling::PROCESS_PROVER_QUERIES_ID); | ||
| progress |= self.processor.process_queries(row_index).map_err(|e| { | ||
| record_end_identity(profiling::PROCESS_PROVER_QUERIES_ID); | ||
| vec![e] | ||
| })?; | ||
| record_end_identity(profiling::PROCESS_PROVER_QUERIES_ID); |
There was a problem hiding this comment.
This should be inside the Processor, no? It is also used by block machines, so then we wouldn't measure it here?
| record_end_identity(profiling::UNUSED_IDENTITY_ID); | ||
| profiling::reset_and_print_profile_summary_identity(self.fixed_data); | ||
| record_start_identity(profiling::UNUSED_IDENTITY_ID); |
There was a problem hiding this comment.
Unfortunately, this breaks if there is more than one VM:
$ RUST_LOG=debug cargo run pil test_data/asm/vm_to_vm.asm -o output -f
...
[00:00:00 (ETA: 00:00:00)] ████████████████████ 100% - Starting... Finalizing VM: Main Machine
Transposing 256 rows with 19 columns...
Finalizing remaining rows...
Needed to finalize 256 / 256 rows.
Done transposing.
Finalizing VM: Secondary machine 0: main_vm (Vm)
Found loop with period 1 starting at row 100
== Identities processing profile (7464 events)
thread 'main' panicked at executor/src/witgen/machines/profiling.rs:158:17:
Unexpected recursive call!
There was a problem hiding this comment.
Ok, would you think it's a good fix to add a boolean flag to just output the partial profile summary (and then temporarily closing all open calls) and do not reset?
There was a problem hiding this comment.
Turns out the error was something else: https://github.com/powdr-labs/powdr/pull/1473/files#r1657169269
I still think it's a bit confusing, and at least we should add a debug log here which machine reached the loop and that all future profiling logs will not include any events before this point. As far as I understand, what happens now in vm_to_vm.asm is:
- Profiling starts
- Main machine reaches the loop -> profiling printed & reseted
Generator::run()finishes the loop and returns- We call
take_witness_col_valueson the secondary machines, which includes the secondary VM. This invokes the VM processor and immediately finds a loop -> profiling printed & reseted - Then, we call
reset_and_print_profile_summary_identityinWitnessGenerator::generate()
Not sure this is what we want! I think it would be cleanest to get 3 profiles:
- Main machine reaches the loop
Generator::run()returns- All the
take_witness_col_valueshave completed (this is probably the least important)
No description provided.