Reworked `check_timing` to provide a structured error report
As per title:
check_timingnow provides a list ofSimpleNamespaceerror descriptions, e.g.namespace(block=2, event='block', field='duration', error_type='BLOCK_DURATION_MISMATCH', value=0.00102, duration=0.001)- The default signature for
check_timingremains the same to not break existing code. It will now just print the namespace objects instead the error messages. - The error report can be pretty-printed with the
print_error_reportfunction provide incheck_timing.py. check_timingnow accepts an additional argumentprint_errors=Trueto directly print the error report if there are errors.Sequence.writenow performs acheck_timingcheck by default (can be disabled withcheck_timing=False) and warns if any errors are found.- The "TotalDuration" sequence definition calculation is now moved to
Sequence.write - Added a unit test for the new
check_timing - Fixed
check_timingto not assumerf_raster_time == adc_raster_time(#191).
In addition, the final commit in this series adds functionality to trace where sequence blocks and events were first created, which I believe helps a lot with identifying where the timing errors originate:
- This can be enabled/disabled with
pp.enable_trace(depth=1)andpp.disable_trace(). It is disabled by default. - When traces are available, the
check_timingerror report will automatically include them. - All gradient, RF, and ADC events now include a
event.tracefield if tracing is enabled. This is the call stack (up to the specified depth) from where the event was created.
Some smaller changes included in this PR:
- Added warnings for RF and ADC delays smaller than the respective dead time, to make users aware that this is automatically increased to the dead time.
- Removed trailing whitespace in some files
- Corrected
system == Nonechecks tosystem is Noneand added proper optional type hints for system (Union[Opts, None]).
Queries:
- In this printing of the new timing report I added some colours to distinguish the events, errors, and (optional) trace. It can be disabled in
print_error_reportby providingcolored=False. But I wonder what others think, is this desired, and if so, are the colours nice, does it work in all terminals (or at least not break anything), etc.? Try:
import pypulseq as pp
system = pp.Opts(adc_dead_time=10e-6)
pp.enable_trace()
seq = pp.Sequence(system)
adc = pp.make_adc(num_samples=123, duration=1e-3) # <- system not specified
seq.add_block(adc)
seq.check_timing(print_errors=True)
- In
check_timingthere was a check whether gradients ramped down to zero in the last block. I removed this check because it does not belong in a timing check. Question is, where should it go? Also, it literally only checked the last block, all other gradient checks occur inadd_block. - Do you like the event tracing changes? It adds some extra code in all
make_*functions.
- I think colors look great, and make it much easier to track what is going on. Colors worked on my terminal, at least.
- Is this check even useful? Correct me if I'm wrong, but a proper check would have to look ahead for every block where gradient does not end with 0, and check if next block has a gradient with initial point that does not violate slew rate requirements, right? Having mismatched or non-ramped down gradients only at the last block sounds like a fringe case to me. Maybe I am missing something.
- Traces are definitely useful. TBH, without traces, especially for a large sequence, it is super hard to find the error by the block number.
Also there is a trivial conflict occured due to merging of the other PR.
2. Is this check even useful? Correct me if I'm wrong, but a proper check would have to look ahead for every block where gradient does not end with 0, and check if next block has a gradient with initial point that does not violate slew rate requirements, right? Having mismatched or non-ramped down gradients only at the last block sounds like a fringe case to me. Maybe I am missing something.
set_block does the check for any consecutive blocks added. The only block that is not checked this way is the last one. It is definitely a rare case, but one that could be checked. Sequence.write would be a possible place to just do it automatically.
In that case, adding it to write seems reasonable. It is late to warn, but better than not warning at all, I guess.
I added the gradient check to Sequence.write. In addition, I found out about a number of bugs in the gradient continuity checks that I fixed, and added unit tests for the situations I could think of.
A note for some future improvements: With the tracing information, runtime errors in set_block could also report the origin of the offending events (the block origin is already reported by the exception itself).
I'll fix the merge conflict once we're happy with the PR as a whole.
I finally tested your changes and like it a lot. I (and my linter) did some further cleanups and I also adjusted the test_report() function to print the timing errors in a bit more structured way. It will print the total number of timing errors and then list up to 20 errors. The timing check report is now at the bottom of the report and each (of the up to 20) error will now be on a new line for better readability. Looks for example like this:
Number of blocks: 1280
Number of events:
RF: 256
Gx: 768
...
Max absolute gradient: 1793183 Hz/m == 42.12 mT/m
Max absolute slew rate: 9.4378e+09 Hz/m/s == 221.67 T/m/s
Event timing check failed with 512 errors in total.
Details of the first up to 20 timing errors:
namespace(block=4, event='block', field='duration', value=0.0033330000000000005, value_rounded=0.00333, error=3.000000000000398e-06, raster='block_duration_raster', error_type='RASTER')
namespace(block=4, event='adc', field='dwell', value=1.2785156250000001e-05, value_rounded=1.28e-05, error=-1.4843749999998243e-08, raster='adc_raster_time', error_type='RASTER')
namespace(block=9, event='block', field='duration', value=0.0033330000000000005, value_rounded=0.00333, error=3.000000000000398e-06, raster='block_duration_raster', error_type='RASTER')
namespace(block=9, event='adc', field='dwell', value=1.2785156250000001e-05, value_rounded=1.28e-05, error=-1.4843749999998243e-08, raster='adc_raster_time', error_type='RASTER')
namespace(block=14, event='block', field='duration', value=0.0033330000000000005, value_rounded=0.00333, error=3.000000000000398e-06, raster='block_duration_raster', error_type='RASTER')
namespace(block=14, event='adc', field='dwell', value=1.2785156250000001e-05, value_rounded=1.28e-05, error=-1.4843749999998243e-08, raster='adc_raster_time', error_type='RASTER')
namespace(block=19, event='block', field='duration', value=0.0033330000000000005, value_rounded=0.00333, error=3.000000000000398e-06, raster='block_duration_raster', error_type='RASTER')
namespace(block=19, event='adc', field='dwell', value=1.2785156250000001e-05, value_rounded=1.28e-05, error=-1.4843749999998243e-08, raster='adc_raster_time', error_type='RASTER')
namespace(block=24, event='block', field='duration', value=0.0033330000000000005, value_rounded=0.00333, error=3.000000000000398e-06, raster='block_duration_raster', error_type='RASTER')
namespace(block=24, event='adc', field='dwell', value=1.2785156250000001e-05, value_rounded=1.28e-05, error=-1.4843749999998243e-08, raster='adc_raster_time', error_type='RASTER')
namespace(block=29, event='block', field='duration', value=0.0033330000000000005, value_rounded=0.00333, error=3.000000000000398e-06, raster='block_duration_raster', error_type='RASTER')
namespace(block=29, event='adc', field='dwell', value=1.2785156250000001e-05, value_rounded=1.28e-05, error=-1.4843749999998243e-08, raster='adc_raster_time', error_type='RASTER')
namespace(block=34, event='block', field='duration', value=0.0033330000000000005, value_rounded=0.00333, error=3.000000000000398e-06, raster='block_duration_raster', error_type='RASTER')
namespace(block=34, event='adc', field='dwell', value=1.2785156250000001e-05, value_rounded=1.28e-05, error=-1.4843749999998243e-08, raster='adc_raster_time', error_type='RASTER')
namespace(block=39, event='block', field='duration', value=0.0033330000000000005, value_rounded=0.00333, error=3.000000000000398e-06, raster='block_duration_raster', error_type='RASTER')
namespace(block=39, event='adc', field='dwell', value=1.2785156250000001e-05, value_rounded=1.28e-05, error=-1.4843749999998243e-08, raster='adc_raster_time', error_type='RASTER')
namespace(block=44, event='block', field='duration', value=0.0033330000000000005, value_rounded=0.00333, error=3.000000000000398e-06, raster='block_duration_raster', error_type='RASTER')
namespace(block=44, event='adc', field='dwell', value=1.2785156250000001e-05, value_rounded=1.28e-05, error=-1.4843749999998243e-08, raster='adc_raster_time', error_type='RASTER')
namespace(block=49, event='block', field='duration', value=0.0033330000000000005, value_rounded=0.00333, error=3.000000000000398e-06, raster='block_duration_raster', error_type='RASTER')
namespace(block=49, event='adc', field='dwell', value=1.2785156250000001e-05, value_rounded=1.28e-05, error=-1.4843749999998243e-08, raster='adc_raster_time', error_type='RASTER')
I also realized that we use a mixture of single quotes and double quotes in all our code, with less appearance of single quotes compared to double quotes. This is why I changed all single quotes to double quotes in the files I touched (although I personally prefer single quotes). I would suggest to introduce RUFF as a linter and formatter for PyPulseq. We can use a very basic config in the beginning that just checks for correct order of imports, single/double quotes, white spaces, line endings etc.
I will create another PR for this.
let me know if you want to review this again @FrankZijlstra & @btasdelen
Changes look good to me. And agreed on the formatting, I also prefer single quotes (hence all the single quotes in my code), but most importantly it should be consistent.