### Author:  [@mcarland](https://community.particle.io/u/mcarland)
#### Post date: [March 17, 2016, 3:54pm UTC](https://community.particle.io/t/sporadic-value-from-micros/21167/1 "2016-03-17T15:54:08Z")
Hey everyone,
Just starting with a Photon. I am trying to measure pulse times via a low triggered interrupt. I think it’s a pretty simple handler.
I started getting occasional random errors, and began storing the micros() values into an array, so when I got a bad value I could print the timings. The bit errors come in different places, but each time it appears there is a reading with an extra 1ms, and the next delta is negative because the reading gets back on track. Time jumping ahead leads me to believe I’m not missing counts, and since it jumps backwards, not missing an interrupt.
Example 1:
```
Current Previous Delta
27062216 27062135 81
27062297 27062216 81
27062424 27062297 127
27062505 27062424 81
27062586 27062505 81
27062666 27062586 80
27062759 27062666 93
27062840 27062759 81
27062921 27062840 81
27064002 27062921 1081
27063083 27064002 -919
27063163 27063083 80
27063244 27063163 81
27063323 27063244 79
27063464 27063323 141
```
Example 2:
```
32194423 32194295 128
32194504 32194423 81
32194584 32194504 80
32194664 32194584 80
32194758 32194664 94
32194839 32194758 81
32194919 32194839 80
32196001 32194919 1082
32195083 32196001 -918
32195163 32195083 80
32195244 32195163 81
32195323 32195244 79
32195464 32195323 141
32195592 32195464 128
```
The measuredMicros[][] and bad\* variables are for debugging this issue.
```auto
volatile int intCount = 0;
volatile int badTemp = 0;
volatile int badRH = 0;
volatile int badSum = 0;
volatile int badCheck = 0;
volatile int measuredMicros[3][45];
void sensorInterrupt(void) {
static unsigned long lastMicros;
static unsigned int measuringTemp;
static unsigned int measuringRH;
static unsigned int checksum;
intCount++;
if (intCount == 1) {
// First interrupt is sensor ack
measuringTemp = 0;
measuringRH = 0;
checksum = 0;
return;
}
unsigned long currentMicros = micros();
if (intCount > 2) {
measuredMicros[0][intCount] = currentMicros;
measuredMicros[1][intCount] = lastMicros;
measuredMicros[2][intCount] = currentMicros - lastMicros;
int newBit = (currentMicros - lastMicros) < 100 ? 0x00 : 0x01;
if (intCount <= 18) {
measuringRH = (measuringRH << 1) | newBit;
} else if (intCount <= 34) {
measuringTemp = (measuringTemp << 1) | newBit;
} else {
checksum = (checksum << 1) | newBit;
}
if (intCount == 42) {
unsigned int sum = 0;
sum += measuringRH >> 8;
sum += measuringRH & 0x0ff;
sum += measuringTemp >> 8;
sum += measuringTemp & 0x0ff;
if ((sum & 0x0ff) == checksum) {
if (measuringTemp & 0x08000) {
lastTemp = -(measuringTemp & 0x7fff);
} else {
lastTemp = measuringTemp;
}
lastRH = measuringRH;
} else {
badTemp = measuringTemp;
badRH = measuringRH;
badSum = sum;
badCheck = checksum;
}
}
}
lastMicros = currentMicros;
}
```
Any suggestions?
Thanks.
---
### Author:  [@ScruffR](https://community.particle.io/u/ScruffR)
#### Post date: [March 18, 2016, 6:44am UTC](https://community.particle.io/t/sporadic-value-from-micros/21167/2 "2016-03-18T06:44:58Z")
How are you attaching the interrupt?
Since you see a 1ms glitch from time to time I could be that higher priority interrupts (e.g. WiFi communication) get in your way and cause some “out of order” execution due to queueing same priority interrupts.
Could you try to elevate the priority of your interrupt?
But this might still be something for @mdma to look at.
BTW: Try to have all your micros variables `unsigned long` and `volatile`.
---
### Author:  [@mdma](https://community.particle.io/u/mdma)
#### Post date: [March 18, 2016, 9:17am UTC](https://community.particle.io/t/sporadic-value-from-micros/21167/3 "2016-03-18T09:17:42Z")
I’ve been thinking about how `millis()` is implemented, and that it’s totally reliant upon the SysTick interrupt, which may be delayed/unsurped by a higher IRQ. Also, `millis()` isn’t ticked while the device is in stop-mode sleep.
>
---
### Author:  [@ScruffR](https://community.particle.io/u/ScruffR)
#### Post date: [March 18, 2016, 11:53am UTC](https://community.particle.io/t/sporadic-value-from-micros/21167/4 "2016-03-18T11:53:50Z")
But in this case it’s `micros()` that’s usually still doing its job even inside ISRs.
---
### Author:  [@mdma](https://community.particle.io/u/mdma)
#### Post date: [March 18, 2016, 1:34pm UTC](https://community.particle.io/t/sporadic-value-from-micros/21167/5 "2016-03-18T13:34:29Z")
Right, but micros is based on millis() indirectly so any problem with millis() will also affect micros.
---
### Author:  [@ScruffR](https://community.particle.io/u/ScruffR)
#### Post date: [March 18, 2016, 1:42pm UTC](https://community.particle.io/t/sporadic-value-from-micros/21167/6 "2016-03-18T13:42:10Z")
OK?
I would have thought it to be the other way round.
After all if `millis()` not get updated inside ISRs how would `micros()` do the magic of counting 1000th fractions of a frozen variable and get updated anyhow?
---
### Author:  [@mcarland](https://community.particle.io/u/mcarland)
#### Post date: [March 18, 2016, 1:44pm UTC](https://community.particle.io/t/sporadic-value-from-micros/21167/7 "2016-03-18T13:44:19Z")
Last night I had tried making the micros variables volatile, after reading an article on code reordering. It seemed to be working, even as I was convincing myself that wouldn’t explain the issue, but then more failures.
I have not tried changing the interrupt priority. I understand that tick interrupts could possibly be missed, but looking at the firmware code, I think that would only delay millis(), and in no case cause a jump forward, and then backwards by micros(). The only way I could see this happening is if the `GetSystem1UsTick()` call was out of order, but its variables are volatile.
I am attaching the interrupt as follows
```auto
void startRead(void) {
detachInterrupt(SENSOR_PIN);
intCount = 0;
lastTemp = -101;
lastRH = -101;
digitalWrite(SENSOR_PIN, LOW);
pinMode(SENSOR_PIN, OUTPUT);
delay(2); // Wait for sensor to detect start
noInterrupts();
pinMode(SENSOR_PIN, INPUT);
attachInterrupt(SENSOR_PIN, sensorInterrupt, FALLING);
interrupts();
}
```
Thanks everyone.
---
### Author:  [@mcarland](https://community.particle.io/u/mcarland)
#### Post date: [March 18, 2016, 1:58pm UTC](https://community.particle.io/t/sporadic-value-from-micros/21167/8 "2016-03-18T13:58:48Z")
Even if `millis()` is incorrect, `micros()` is based off the last DWT-\>CYCCNT value when `millis()` was calculated. So wouldn’t `micros()` still be correct?
---
### Author:  [@mcarland](https://community.particle.io/u/mcarland)
#### Post date: [March 22, 2016, 3:01am UTC](https://community.particle.io/t/sporadic-value-from-micros/21167/9 "2016-03-22T03:01:04Z")
I see it now. If my interrupt is higher priority, it could interrupt System1MsTick() between its two statements, which would cause me to be off 1ms.
I’m having a hard time finding the priority level of the SysTick interrupt, so I can set my interrupt to be a lower priority. Where could I find this information?
Thanks.
---
### Author:  [@mcarland](https://community.particle.io/u/mcarland)
#### Post date: [March 22, 2016, 2:09pm UTC](https://community.particle.io/t/sporadic-value-from-micros/21167/10 "2016-03-22T14:09:25Z")
I found
`#define SYSTICK_IRQ_PRIORITY 13`,
and registered my interrupt with priority 14
`attachInterrupt(SENSOR_PIN, sensorInterrupt, FALLING, SYSTICK_IRQ_PRIORITY + 1);`
Letting the code run for about 9 hours, which should have read the sensor about 32k times, I still had 8 readings where delta micros() jumped forward and then went negative to correct itself.
Should priority 14 have kept my code from interrupting the system timer? Any other ideas?
---
### Author:  [@ScruffR](https://community.particle.io/u/ScruffR)
#### Post date: [March 22, 2016, 2:51pm UTC](https://community.particle.io/t/sporadic-value-from-micros/21167/11 "2016-03-22T14:51:41Z")
Has this changed anything on the frequency of that glitch at all?
Since `micros()` returns a `uint32_t` it will have roled over 7 to 8 times during your 9 hours (once every 71 minutes).
While unsigned subtractions should not show this behaviour, this could well be a possible reason.
Have you printed the readings causing the error?
---
### Author:  [@mcarland](https://community.particle.io/u/mcarland)
#### Post date: [March 22, 2016, 3:23pm UTC](https://community.particle.io/t/sporadic-value-from-micros/21167/12 "2016-03-22T15:23:04Z")
It seems to be less frequent. However looking at the micros value where it happened previously, it does not appear to be when the value crosses the word boundary. From example 1 above, the values were:
```auto
27062921 0x19C F289
27064002 0x19C F6C2 (+1081)
27063083 0x19C F32B (-919)
```
The error was in the high byte of the low word, and isn’t a case of being caught incremented before the low byte was updated, F6 is larger than the target value of F3. I stopped logging the current micros value, but each second I am logging how many errors I have seen with a line like
`Temp: 21.5C Humidity: 36.8% badChecksums: 55 negativeMicros: 9`
If this only occurred at rollover, it should never happen with fewer than about 4260 samples (71 minutes \* 60). But I do see if more frequently than that.
```auto
Michaels-MacBook-Pro:~ mcarland$ egrep "Micros: [0-9]" mgc.out | sed -e "s/.*negativeMicros: \([0-9]\)/\1/" | uniq -c
7640 0
619 1
2766 2
1117 3
2650 4
4697 5
2799 6
9549 7
5443 8
1134 9
```
So it went as few as 619 seconds without error, and erred five times total under 71 minutes, not counting the last sample which wasn’t complete.
I am going to connect another Arduino as a waveform generator that I don’t have to trigger, and see if I can repeat this with a simpler case. I’ll also go back to logging the current micros value to see when it is happening.
---
### Author:  [@ScruffR](https://community.particle.io/u/ScruffR)
#### Post date: [March 22, 2016, 3:40pm UTC](https://community.particle.io/t/sporadic-value-from-micros/21167/13 "2016-03-22T15:40:29Z")
OK, this sounds different to what I understood from that
> [@mcarland](#):
>
> Letting the code run for about 9 hours, ... I still had 8 readings where delta micros() jumped forward and then went negative to correct itself.
Which made it appear likely, and since the code was changed since the previous data log, I couldn't tell any different 😉
---
### Author:  [@mcarland](https://community.particle.io/u/mcarland)
#### Post date: [March 22, 2016, 3:44pm UTC](https://community.particle.io/t/sporadic-value-from-micros/21167/14 "2016-03-22T15:44:24Z")
Yes, your suggestion made sense. I had to go back and look to see if your theory fit the data. Wish is was true, would be an easier thing to fix.
---
### Author:  [@ScruffR](https://community.particle.io/u/ScruffR)
#### Post date: [March 22, 2016, 3:45pm UTC](https://community.particle.io/t/sporadic-value-from-micros/21167/15 "2016-03-22T15:45:45Z")
Yup, too bad - so it’s still a puzzle that might need the insight and a possible solution of @mdma
---
### Author:  [@mcarland](https://community.particle.io/u/mcarland)
#### Post date: [March 22, 2016, 6:12pm UTC](https://community.particle.io/t/sporadic-value-from-micros/21167/16 "2016-03-22T18:12:59Z")
Ok, stripped down my code to an example. Removed the sensor I was reading, and used a Bus Pirate to put a 10kHz pulse on D1. Only thing connected is USB and GND/D1 to the Bus Pirate. Once per second (roughly) I attached the interrupt, and measure 40 pulses before disconnecting the interrupt. It went a while with no problem, but then had quite a few, sometimes more than one per minute, so I don’t think it was either counter doing a rollover.
@mdma, should setting the interrupt priority to SYSTICK\_IRQ\_PRIORITY + 1 take the millis counter issue out of the problem like I’m thinking?
```auto
negatives: 4
Read found negative delta micros():1313172
1313165105 1313165205 100
1313165205 1313165304 99
1313165304 1313165404 100
1313165404 1313165503 99
1313165503 1313165603 100
1313165603 1313165703 100
1313165703 1313165802 99
1313165802 1313165902 100
1313165902 1313167001 1099
1313167001 1313166098 -903
1313166098 1313166198 100
1313166198 1313166297 99
1313166297 1313166397 100
1313166397 1313166496 99
1313166496 1313166596 100
1313166596 1313166696 100
1313166696 1313166795 99
1313166795 1313166895 100
1313166895 1313166994 99
1313166994 1313167097 103
1313167097 1313167196 99
1313167196 1313167296 100
1313167296 1313167395 99
1313167395 1313167495 100
1313167495 1313167594 99
1313167594 1313167694 100
1313167694 1313167794 100
1313167794 1313167893 99
1313167893 1313167993 100
1313167993 1313168094 101
1313168094 1313168193 99
1313168193 1313168292 99
1313168292 1313168392 100
1313168392 1313168492 100
1313168492 1313168591 99
1313168591 1313168691 100
1313168691 1313168791 100
1313168791 1313168890 99
1313168890 1313168990 100
negatives: 5
negatives: 5
negatives: 5
negatives: 5
negatives: 5
negatives: 5
negatives: 5
negatives: 5
Read found negative delta micros():1322334
1322326711 1322326810 99
1322326810 1322326910 100
1322326910 1322327010 100
1322327010 1322327109 99
1322327109 1322327208 99
1322327208 1322327308 100
1322327308 1322327408 100
1322327408 1322327507 99
1322327507 1322327607 100
1322327607 1322327706 99
1322327706 1322327806 100
1322327806 1322327906 100
1322327906 1322328006 100
1322328006 1322328105 99
1322328105 1322328205 100
1322328205 1322328304 99
1322328304 1322328404 100
1322328404 1322328503 99
1322328503 1322328603 100
1322328603 1322328703 100
1322328703 1322328802 99
1322328802 1322328902 100
1322328902 1322330001 1099
1322330001 1322329102 -899
1322329102 1322329201 99
1322329201 1322329300 99
1322329300 1322329400 100
1322329400 1322329499 99
1322329499 1322329599 100
1322329599 1322329699 100
1322329699 1322329798 99
1322329798 1322329898 100
1322329898 1322329998 100
1322329998 1322330097 99
1322330097 1322330196 99
1322330196 1322330296 100
1322330296 1322330395 99
1322330395 1322330495 100
1322330495 1322330594 99
negatives: 6
negatives: 6
```
```auto
int SENSOR_PIN = D1;
volatile int intCount = 0;
volatile int negativeMicrosCount = 0;
volatile int negativeFound = 0;
volatile int readComplete = 0;
volatile int measuredMicros[40];
void sensorInterrupt(void) {
static volatile unsigned long lastMicros;
volatile unsigned long currentMicros = micros();
long microsDiff = currentMicros - lastMicros;
if (microsDiff < 0) {
negativeFound = 1;
negativeMicrosCount++;
}
intCount++;
if (microsDiff > 5000) {
intCount = 0;
}
lastMicros = currentMicros;
if (intCount < 40) {
measuredMicros[intCount] = currentMicros;
} else {
readComplete = 1;
}
}
void setup() {
Serial.begin(9600);
delay(1000);
pinMode(SENSOR_PIN, INPUT);
attachInterrupt(SENSOR_PIN, sensorInterrupt, FALLING, SYSTICK_IRQ_PRIORITY + 1);
}
void loop() {
while (1) {
if (readComplete) {
detachInterrupt(SENSOR_PIN);
if (negativeFound) {
negativeFound = 0;
Serial.print("Read found negative delta micros():");
Serial.print(millis());
for (int i = 1; i < 40; i++) {
Serial.print("\t");
Serial.print(measuredMicros[i-1]);
Serial.print("\t");
Serial.print(measuredMicros[i]);
Serial.print("\t");
Serial.print(measuredMicros[i] - measuredMicros[i-1]);
Serial.println();
}
} else {
Serial.print("negatives: ");
Serial.println(negativeMicrosCount);
}
readComplete = 0;
delay(1000);
attachInterrupt(SENSOR_PIN, sensorInterrupt, FALLING, SYSTICK_IRQ_PRIORITY + 1);
}
}
}
```
---
### Author:  [@mdma](https://community.particle.io/u/mdma)
#### Post date: [April 19, 2016, 1:35pm UTC](https://community.particle.io/t/sporadic-value-from-micros/21167/17 "2016-04-19T13:35:41Z")
Setting the priority will certainly remove one possible cause of delaying the systick interrupt, but presently the millis/micros code is not thread safe so an interrupt at just the right (wrong?) time can cause the data to be computed incorrectly.