Investigate slowness of unit tests

[rtuck99]

Following on from #1215
There are still a number of unit tests that seem to be slowing down unit test execution. This seems to be related to exceptions that are raised during successful execution of a test, and these seem to cause a delay. The reason why these exceptions cause the delay is unknown.

e.g. in test_given_no_tip_found_ever_when_get_tip_into_view_then_smargon_moved_positive_and_exception_thrown() a number of exceptions similar to the following are thrown and they each cause ~0.7s of delay:

[2024-03-05 13:50:21,235] ophyd status ERROR: An error was raised on a background thread while running the callback <bound method PinTipDetect.log_tips_and_statistics of FakePinTipDetect(prefix='BL03S-DI-OAV-01:MXSC:', name='oav_mxsc_pin_tip', parent='oav_mxsc', read_attrs=['tip_x', 'tip_y', 'triggered_tip', 'validity_timeout', 'settle_time_s'], configuration_attrs=[])>(StableSubscriptionStatus(device=oav_mxsc_pin_tip_tip_x, done=True, success=True)).
Traceback (most recent call last):
  File "/scratch/ws/hyperion/.venv/lib/python3.10/site-packages/ophyd/status.py", line 269, in _run_callbacks
    cb(self)
  File "/scratch/ws/dodal/src/dodal/devices/areadetector/plugins/MXSC.py", line 56, in log_tips_and_statistics
    median, standard_deviation = statistics_of_positions(self.tip_positions)
  File "/scratch/ws/dodal/src/dodal/devices/areadetector/plugins/MXSC.py", line 27, in statistics_of_positions
    x_coords, y_coords = np.array(positions).T
ValueError: not enough values to unpack (expected 2, got 0)
[2024-03-05 13:50:21,989] Hyperion pin_tip_centring_plan INFO: Pin tip found at (-1, -1)

It would be good if we could speed up the slow tests by eliminating the exceptions, ideally we would also want to:

• Making it easier to identify when this is happening to prevent further occurrences
• Figure out why this slows down the tests and remove the slowdown.

In investigating the latter, one possible avenue may be to temporarily re-instate the exceptions in the optimise_attenuation test and run the profiler against it (may need to tweak the timeout so that the exceptions happen before the test completes), possibly that may make the cause more obvious.

[DominicOram]

I think this is due to logging, on my machine:

• Running with as on main is 136.21s
• Running with no logging is 37.38s
• Running with logging but not the debug log on error is 47.13s

This fits with the issue being whenever there is an exception as this is when the debug logs get flushed. I suggest we turn off logging by default in the tests and only turn on for the tests that are testing logging logic?

[DominicOram]

Solution is to:

• Turn off ophyd debug logs in all tests
• Have a command line option to turn off all logging, this defaults to not logging locally and logging in CI

[DominicOram]

Will take ~0.5 days

[DominicOram]

Turn off ophyd debug logs in all tests

Interestingly this didn't give us much of a speed up. I guess enough debug logs are produced in general that the buffer becomes reasonably full part way through the tests anyway