I2C long delay between register write and requestFrom

The program below executing on an Argon takes 100 milliseconds or more to execute the fetchData function . The same code takes about 250 microseconds on a PJRC Teensy 4. I can’t see what I’m doing doing wrong with the Particle. But what is happening is that “something” is causing a huge delay between the writing of the sensor register address to read from and the reading of the 13 bytes of sensor data.
This is with a newly flashed DeviceOS 2.1.0 and up to date Particle Workbench. Osciloscope pictures clearly show the interrupt pin staying high for the very long periods with the Argon because “something” is taking control from the I2C I/O between the write to set the register address and the multibyte read.
The following pictures show the overall latency (from top to bottom traces are interrupt pin, I2C clock and I2C data), the “leading edge” of the 100-150 millisecond latency and the “trailing edge” of the interrupt service latency. Are there rules involving requestFrom that I’m not honoring or what? I could not get clues from the Particle doc for this function.



/*
 * Project x
 * Description: interrupt problem test case
 *   It is taking the Argon 400 times longer to service an
 *   interrupt than expected. On the Argon the interrupt
 *   service takes 100-175 milliseconds. On a PJRC Teensy 4.0
 *   this same code takes the expected time to service 
 *   the interrupt.
 * Date: 7/9/2021
 */

#include <Wire.h>

#ifdef PARTICLE
SYSTEM_MODE(MANUAL);
#endif

static volatile uint32_t interrupt_count;

typedef enum {
  FXOS8700_STATUS           = 0x00,
  FXOS8700_WHOAMI           = 0x0D,
  FXOS8700_XYZ_DATA_CFG     = 0x0E,
  FXOS8700_CTRL_REG1        = 0x2A,
  FXOS8700_CTRL_REG2        = 0x2B,
  FXOS8700_CTRL_REG3        = 0x2C,
  FXOS8700_CTRL_REG4        = 0x2D,
  FXOS8700_CTRL_REG5        = 0x2E,
  FXOS8700_M_CTRL_REG1      = 0x5B,
  FXOS8700_M_CTRL_REG2      = 0x5C,
} FXOS8700_REGISTERS;

#define FXOS8700_ID (0xC7)
static const uint8_t SENSOR_ADDRESS = 0x1e;

void write8(byte reg, byte value) {
  Wire.beginTransmission(SENSOR_ADDRESS);
  Wire.write((uint8_t)reg);
  Wire.write((uint8_t)value);
  Wire.endTransmission();
}

byte read8(byte reg) {
  byte value;

  Wire.beginTransmission((byte)SENSOR_ADDRESS);
  Wire.write((uint8_t)reg);
  if (Wire.endTransmission(false) != 0) return 0;
  Wire.requestFrom((byte)SENSOR_ADDRESS, (byte)1);
  value = Wire.read();

  return value;
}

void fetchData() {
  interrupt_count += 1;

  // B U G. This is taking 100-175milliseconds instead of
  // 320 microseconds as if the clock is pathologically slow.
  // This takes the expected time on a PJRC Teensy 4.0.

  Wire.beginTransmission(SENSOR_ADDRESS);
  Wire.write(FXOS8700_STATUS | 0x80);
  Wire.endTransmission();
  Wire.requestFrom((uint8_t) SENSOR_ADDRESS, (uint8_t) 13);

  for (int i=0; i < 13; i++) {
    Wire.read();
  }
}

void setup() {
  pinMode(2, INPUT);
  Wire.begin();

  // 2.5 microseconds per bit or 320usec for 16 bytes

#ifdef PARTICLE
  Wire.setSpeed(CLOCK_SPEED_400KHZ);
#else
  Wire.setClock(CLOCK_SPEED_400KHZ);
#endif

  // Initialize Serial I/O
  Serial.begin(9600);

  /* Make sure we have the correct chip ID since this checks
      for correct address and that the IC is properly connected */
  uint8_t id = read8(FXOS8700_WHOAMI);
  if (id != FXOS8700_ID) {
    Serial.println("chip id does not match: hanging");
    while(1) {
    }
  }
  write8(FXOS8700_M_CTRL_REG2, 0x40);
  delay(1);
  write8(FXOS8700_M_CTRL_REG2, 0x00);
  delay(1);
  /* END RESET */
#endif

  /* Set to standby mode (required to make changes to this register) */
  write8(FXOS8700_CTRL_REG1, 0);
  // interrupt polarity active hith
  write8(FXOS8700_CTRL_REG3, 2);
  // interrupt enabled for data ready
  write8(FXOS8700_CTRL_REG4, 1);
  // interrupt routed to INT1
  write8(FXOS8700_CTRL_REG5, 1);
  /* Configure the magnetometer */
  /* Hybrid Mode, Over Sampling Rate = 16 */
  write8(FXOS8700_M_CTRL_REG1, 0x1F);
  /* Jump to reg 0x33 after reading 0x06 */
  write8(FXOS8700_M_CTRL_REG2, 0x20);
  // Make active and set rate
  write8(FXOS8700_CTRL_REG1, 0x39);

  // Attach interrupt to MPU pin
  attachInterrupt(digitalPinToInterrupt(2), fetchData, RISING);
}

void loop() {
  delay(1000);
  Serial.println(interrupt_count);
}

Hi there!

Because “MANUAL” is the chosen mode you need to place extra code in the loop() to process system background processing and network management. Try adding Particle.process() at the end of loop():

void loop() {
  delay(1000);
  Serial.println(interrupt_count);
  Particle.process(); //need this for MANUAL mode
}

https://docs.particle.io/cards/firmware/system-modes/manual-mode/

Also, add SYSTEM_THREAD(ENABLED) statement above your setup():

SYSTEM_THREAD(ENABLED);

void setup() {
...

https://docs.particle.io/cards/firmware/system-thread/system-thread/

Hope this helps you.

Unfortunately this doesn’t help. The behavior of the interrupt handler is completely independent of the loop() code and just runs over and over by itself. But thanks.

I should mention one more thing that is the same fetchData() code, when executed at the non-interrupt level, works fine at a couple hundred samples per second (polling the data ready status of the sensor chip). It’s only within the interrupt handler that the code appears to go to the thread scheduler or who knows what instead of returning from requestFrom (assuming that’s the source of the delay: I didn’t think to trace this with gdb but assume Particle will be familiar with that code and possible scenarios to explain this. I also should mention that multiple sensor chips were tested: this isn’t a defect in a particular instance of the chip.

In setup(), try adding this statement above your attach interrupt statement:

  detachInterrupt(digitalPinToInterrupt(2)); //remove all low-level interrupts for this pin, if they exist    https://gammon.com.au/interrupts

  // Attach interrupt to MPU pin
  attachInterrupt(digitalPinToInterrupt(2), fetchData, RISING);
}

see if that helps.

If it were me, I would change the ISR (fetchData) to set a volatile flag only. Then, return to loop() and there, call a different routine to execute your Wire. statements.

Also, I would remove the delay(1000) statement from loop() and use a millis() counter instead:

void loop() {
  //delay(1000);
 static uint32_t last_interrupt_count = 0;
 if (last_interrupt_count != interrupt_count) {//interrupt fired
  last_interrupt_count = interrupt_count;
  interruptFired_DoStuff();
 }
 static uint32_t tmsSecondDelay = 0;
 if (millis() - tmsSecondDelay >= 1000) {       
  tmsSecondDelay  = millis();
  Serial.println(interrupt_count);
 }
 Particle.process(); //need this for MANUAL mode
}

The detachInterrupt call has no effect.

@petesoper, you might want to try to specify a (higher) priority for the interrupt using attachInterrupt(pin, function, mode, priority); where:

  • priority (optional): the priority of this interrupt. Default priority is 13. Lower values increase the priority of the interrupt.

What’s the interrupt rate from the sensor?

Thanks. Tried high priority early on. The sample rate as programmed is about 1.4 per secondt. The huge delay is fixed: it isn’t about the rate but limits the sample rate to the 6.25/sec choice.

The write of the register address is getting a NAK after the 100+ milliseconds. Something is fouling up I2C I/O in the interrupt handler. If fetchData is called from inside loop() the endTransmission does not return a NAK status.

I would do the I2C from a worker thread and not an ISR. While I2C is not expressly prohibited from an ISR, I’m not convinced it will work properly. And, apparently, it doesn’t. Among other things, there is a mutex lock surrounding the various calls internally. Except since you can’t mutex lock from an ISR, there’s actually a check that skips locking when in an ISR. While this prevents the system from deadlocking, I’m not convinced it wouldn’t cause other issues. Plus, if you ever need to use I2C from the loop thread that would definitely cause problems without the lock.

1 Like

It certainly doesn’t work properly. That’s clear at this point. I can only hope SPI I/O within an ISR will be a different story. Thanks for the feedback.

1 Like

@petesoper you are absolutely right
It’s a bug 100%
I have similar issue.
The workaround for me was downloading to 1.5.0

I got curious and traced the Wire.endTransmission() to hal_i2c_end_transmission that uses a WAIT_TIMED macro that calls os_thread_yield() with a comment wishing that call could be eliminated. So we both wish for that now. The os_thread_yield() appears to do a taskYIELD that I assume does a system call or software interrupt or something to get into the scheduler but that somehow leads to the timeout causing the NAK return. I can’t back up to OS rev 1.5: client dependent on 2.1.0, but luckily the sensor operates with SPI (in theory: I haven’t gotten it past WHOAMI although I can clearly see what looks like a totally valid SPI transaction with the logic analyzer. I know about the “floating SA1” protocol for this sensor putting itself into SPI mode). The $USD 64k question is whether I can function with an indeterminate number of milliseconds waking a thread up from the ISR while the app functionality is sorted and SPI communication is made to work.

Anyway, thanks to all for the feedback!