[SOLVED] Arduino's micros() method is taking over 500 cycles to execute on Nano 33 BLE Sense

I posted this question over on the Arduino forum first but my questions haven't been receiving much attention lately so here goes...

I worked pretty hard to make a simple sketch proving how slow the micros() method is on the Nano 33 BLE Sense:

#include "mbed.h"
#include "nrf_delay.h"
#include "nrf_gpio.h"

#define OUTPUT_PIN NRF_GPIO_PIN_MAP(1,11)

unsigned long startClock;
unsigned long stopClock;
unsigned long arithmeticMinuend = 4294967295;
unsigned long arithmeticSubtrahend = 2147483648;
unsigned long arithmeticDifference = 0;
unsigned long timeDifference1 = 0;
unsigned long timeDifference2 = 0;

//Assume 1 to 4 clock cycles (15.625 to 62.5 ns) is required for every...
//* call of micros();
//* subtraction of two unsigned longs.
//Therefore we should not be able to measure the time to execute either task by using the micros() - startClock technique, as...
//* micros() - startClock = 0 in either case.

void setup() {
  Serial.begin(115200);
  while (!Serial);

  nrf_gpio_cfg_output(OUTPUT_PIN);

  startClock = micros();
  stopClock = micros();
}

void loop() {
  timeDifference1 = microsecondsToSubtract2LongsOnce();
  timeDifference2 = microsecondsToSubtract2LongsTwice();
  Serial.print("timeDifference1 = ");
  Serial.print(timeDifference1);
  Serial.print(" us.\ntimeDifference2 = ");
  Serial.print(timeDifference2);
  Serial.println(" us.");
  
  microsecondsToSubtract2LongsOnceMeasuredWithScope();
  delay(100);
  microsecondsToSubtract2LongsTwiceMeasuredWithScope();
  delay(100);
  microsecondsToToggleOutputPinMeasuredWithScope();
  
  while(1) {
    
  }
}

//Prints 8 us:
unsigned long microsecondsToSubtract2LongsOnce() {
  startClock = micros();
  stopClock = micros();
  return stopClock - startClock;
}

//Prints 9 us:
unsigned long microsecondsToSubtract2LongsTwice() {
  startClock = micros();
  arithmeticDifference = arithmeticMinuend - arithmeticSubtrahend;
  stopClock = micros();
  return stopClock - startClock;
}

//Measured 18 us on scope:
void microsecondsToSubtract2LongsOnceMeasuredWithScope() {
  nrf_gpio_pin_toggle(OUTPUT_PIN);
  startClock = micros();
  stopClock = micros();
  nrf_gpio_pin_toggle(OUTPUT_PIN);
}

//Measured 18 us on scope:
void microsecondsToSubtract2LongsTwiceMeasuredWithScope() {
  nrf_gpio_pin_toggle(OUTPUT_PIN);
  startClock = micros();
  arithmeticDifference = arithmeticMinuend - arithmeticSubtrahend;
  stopClock = micros();
  nrf_gpio_pin_toggle(OUTPUT_PIN);
}

//Measured 500 ns on scope:
void microsecondsToToggleOutputPinMeasuredWithScope() {
  nrf_gpio_pin_toggle(OUTPUT_PIN);
  nrf_gpio_pin_toggle(OUTPUT_PIN);
}

I compare time measurements I made with oscilloscope to the ones I made using micros(). Doing the math we get that the # of clock cycles (CC) required for one micros() call = (0.5*(18000 - 500) ns)/15.625 ns = 560 CC!!!

Can someone give an example for measuring time on this board which doesn't require more than 10 CC???

From my reading, I think a faster (theoretically 1 CC) strategy would involve using the method nrf_drv_timer or the newer nrfx_timer (both strategies would require setting the timer to operate in counter mode), but I couldn't find a concrete example for use on my Arduino's NRF52840.

EDIT:

I also tried reducing time by using mbed's us_ticker but the timing results were exactly the same. Here is the code I used for that test:

#include "mbed.h"
#include "nrf_delay.h"
#include "nrf_gpio.h"

#define OUTPUT_PIN NRF_GPIO_PIN_MAP(1,11)

mbed::Timer timer;

uint32_t startClock;
uint32_t stopClock;
uint32_t arithmeticMinuend = 4294967295;
uint32_t arithmeticSubtrahend = 2147483648;
uint32_t arithmeticDifference = 0;
uint32_t timeDifference1 = 0;
uint32_t timeDifference2 = 0;

//Assume 1 to 4 clock cycles (15.625 to 62.5 ns) is required for every...
//* call of micros();
//* subtraction of two unsigned longs.
//Therefore we should not be able to measure the time to execute either task by using the micros() - startClock technique, as...
//* micros() - startClock = 0 in either case.

void setup() {
  Serial.begin(115200);
  while (!Serial);

  nrf_gpio_cfg_output(OUTPUT_PIN);
  timer.start();
  startClock = timer.read_us();
  stopClock = timer.read_us();
}

void loop() {
  timeDifference1 = microsecondsToSubtract2LongsOnce();
  timeDifference2 = microsecondsToSubtract2LongsTwice();
  Serial.print("timeDifference1 = ");
  Serial.print(timeDifference1);
  Serial.print(" us.\ntimeDifference2 = ");
  Serial.print(timeDifference2);
  Serial.println(" us.");
  
  microsecondsToSubtract2LongsOnceMeasuredWithScope();
  timer.stop();
  delay(100);
  timer.start();
  microsecondsToSubtract2LongsTwiceMeasuredWithScope();
  timer.stop();
  delay(100);
  timer.start();
  microsecondsToToggleOutputPinMeasuredWithScope();
  timer.stop();
  
  while(1) {
    
  }
}

//Prints 8 us:
unsigned long microsecondsToSubtract2LongsOnce() {
  startClock = timer.read_us();
  stopClock = timer.read_us();
  return stopClock - startClock;
}

//Prints 9 us:
unsigned long microsecondsToSubtract2LongsTwice() {
  startClock = timer.read_us();
  arithmeticDifference = arithmeticMinuend - arithmeticSubtrahend;
  stopClock = timer.read_us();
  return stopClock - startClock;
}

//Measured 18 us on scope:
void microsecondsToSubtract2LongsOnceMeasuredWithScope() {
  nrf_gpio_pin_toggle(OUTPUT_PIN);
  startClock = timer.read_us();
  stopClock = timer.read_us();
  nrf_gpio_pin_toggle(OUTPUT_PIN);
}

//Measured 18 us on scope:
void microsecondsToSubtract2LongsTwiceMeasuredWithScope() {
  nrf_gpio_pin_toggle(OUTPUT_PIN);
  startClock = timer.read_us();
  arithmeticDifference = arithmeticMinuend - arithmeticSubtrahend;
  stopClock = timer.read_us();
  nrf_gpio_pin_toggle(OUTPUT_PIN);
}

//Measured 500 ns on scope:
void microsecondsToToggleOutputPinMeasuredWithScope() {
  nrf_gpio_pin_toggle(OUTPUT_PIN);
  nrf_gpio_pin_toggle(OUTPUT_PIN);
}