pypulseq icon indicating copy to clipboard operation
pypulseq copied to clipboard

Reworked `check_timing` to provide a structured error report

Open FrankZijlstra opened this issue 1 year ago • 5 comments

As per title:

  • check_timing now provides a list of SimpleNamespace error 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_timing remains 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_report function provide in check_timing.py.
  • check_timing now accepts an additional argument print_errors=True to directly print the error report if there are errors.
  • Sequence.write now performs a check_timing check by default (can be disabled with check_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_timing to not assume rf_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) and pp.disable_trace(). It is disabled by default.
  • When traces are available, the check_timing error report will automatically include them.
  • All gradient, RF, and ADC events now include a event.trace field 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 == None checks to system is None and 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_report by providing colored=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)

image

  • In check_timing there 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 in add_block.
  • Do you like the event tracing changes? It adds some extra code in all make_* functions.

FrankZijlstra avatar Sep 02 '24 15:09 FrankZijlstra

  1. I think colors look great, and make it much easier to track what is going on. Colors worked on my terminal, at least.
  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.
  3. Traces are definitely useful. TBH, without traces, especially for a large sequence, it is super hard to find the error by the block number.

btasdelen avatar Sep 03 '24 16:09 btasdelen

Also there is a trivial conflict occured due to merging of the other PR.

btasdelen avatar Sep 03 '24 16:09 btasdelen

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.

FrankZijlstra avatar Sep 03 '24 16:09 FrankZijlstra

In that case, adding it to write seems reasonable. It is late to warn, but better than not warning at all, I guess.

btasdelen avatar Sep 03 '24 19:09 btasdelen

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.

FrankZijlstra avatar Sep 05 '24 11:09 FrankZijlstra

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

schuenke avatar Nov 01 '24 07:11 schuenke

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.

FrankZijlstra avatar Nov 01 '24 15:11 FrankZijlstra