Teensy 3.1 time measurements

Status
Not open for further replies.

BobQ

Member
This thread is related to previous threads
Sub micro timing and
Teensyduino access to counting cpu cycles

I've been using the teensy 3.1 to measure an external time interval. I use a very stable 100 Hz signal applied to 2 pins, one for the rising edge and one for the falling edge. The program counts cpu cycles to measure the time. The teensy runs at 48 MHz and the interval is 5 msec, 240000 cpu cycles. I measure an average of 239975 in my test. I use the average value to see how much each measurement differs from the average. I first ran the program below with the test for "test <-5 || test > 5" commented out and collected about 2000 data points. Then I re-ran it with the test for about 200000 total data points. I used 2 separate tests to reduce the number of data points that got recorded. Of the 200000 total points, about 1200 got recorded. I combined the results, scaling the second set to account for the longer run. The frequency distribution is in the table below. I realize it's probably hard to follow.

Most of the data is/are very close to the average. I noticed that one group of measurements is far removed from the others. In 200000 measurements, nothing falls between -25 cpu cycles and -100 cpu cycles from the average. The table shows 2 for the range -103 to -135. That is actually 1 from the run of 2000 and 100 from the run of 200000 (scaled by 0.01, 2000/200000). 100 cpu cycles is about 2 usec.

Maybe more than one thing is going on.
I don't know how to adjust the priority of my 2 interrupts. That might tighten the distribution of the points between 17 and -25 in the table. I expect some jitter due to the asynchronous signal.
Is something else causing the infrequent (100 in 200000 measurements) errors of about 100 cpu cycles?

Thanks,
Bob


bucket total
17 0.01
15 0.04
13 0.14
11 1.6
9 3.08
7 9.06
6 0.02
5 27
3 478
1 846
-1 382
-3 204
-5 0
-7 0.11
-9 0.11
-11 0.07
-13 0.06
-15 0.11
-17 0.1
-19 0.07
-20 0.07
-21 0.16
-22 0.09
-23 1.09
-24 0.05
-25 0.09

nothing between -26 and -102

-103 to -135 2





Code:
/*
Teensy 3.1, Arduino 1.61 and Teensyduino 1.21
*/
const int pin2 = 2;
const int pin3 = 3;
unsigned long longCount = 0;
long test;
volatile int riseFlag = 0;
volatile int fallFlag = 0;
unsigned long pulseWidth = 0;
unsigned long fallEdge = 0;
unsigned long riseEdge = 0;

void setup() {
  ARM_DEMCR |= ARM_DEMCR_TRCENA;
  ARM_DWT_CTRL |= ARM_DWT_CTRL_CYCCNTENA;
  pinMode(pin2, INPUT);
  pinMode(pin3, INPUT);
  Serial.begin(9600);
  attachInterrupt(pin2, fall_ISR, FALLING); // set flag high on falling edge
  attachInterrupt(pin3, rise_ISR, RISING); // set flag high on rising edge

}

void loop() {
  longCount++;
  fallFlag = 0;
  while (!fallFlag) { // wait for falling edge
  }
  fallEdge = ARM_DWT_CYCCNT;
  riseFlag = 0;
  while (!riseFlag) {
  }
  riseEdge = ARM_DWT_CYCCNT;
  pulseWidth = riseEdge - fallEdge;
  test = pulseWidth - 239975;  // 24000 based on 100 Hz, 50% and 48 MHz.  239975 average of 450 readings
  if (test < -5 || test > 5) {  // span of -5 to 5 in 450 readings not counting exceptions
  Serial.print(longCount);
  Serial.print("  ");
  Serial.print(test);
  Serial.print("  ");
  Serial.println(pulseWidth);
  }
  delay(100);
}     
//-------------------------------------
void fall_ISR() {
  fallFlag = 1;
}

//-------------------------------------
void rise_ISR() {
  riseFlag = 1;
}
 
@BobQ: see NVIC_SET_PRIORITY
also: why not obtain the rise/falledge in the isr? I think it would be better then setting a flag, then waiting until the main program picks it up and only then obtaining the time.
 
The ISR can change the hardware interrupt sensing to the rising/falling opposite of what it was at the current interrupt. Then dismiss the interrupt and the hardware will interrupt on the newly chosen edge.

Some MCUs have an "either" rising/falling interrupt cause choice.

You don't want to spin-loop in an ISR waiting for the other edge.
 
@stevech, I think you are adressing my comment. I was not suggesting to move the spin loop to the isr, just wait for the isr to be triggered and just store the cycle counter.You still have to set a flag, to the spin loop the main program.
 
I think you could use a PORT event and let it trigger a DMA transfer from ARM_DWT_CYCCNT to your memory variable.

This needs three steps

* Setup the PORTx_PINn control register to generate events on both rising and falling edge
* Configure a DMAMUX to send the event to a DMA channel
* Configure the DMA to capture one word per event and move the destination address 4 bytes for
every event while keeping the source address fixed, set up the count two 2 and generate an interrupt
or simply poll for flags on the DMA channel.
* Enable the DMA channel and event requests.

This is a bit of work to get all the little bits right, but should give a sampling that is independent of
all interrupts. I dont think there is a single library that will do this for you.

UPDATE - This will not work, since the ARM_DWT memory area can only be accesed by the Cortex-M4 core
and not from the DMA bus master. So the cycle count can be read from a program running on the CPU but not
from DMA.
 
Last edited:
The following sketch reads a PPS input from GPS on pin 12. It uses PIT0 and DMA.


Code:
/* Example with input on pin PORTC_PIN7 */

/* Pin 13 has the LED on Teensy 3.0 */
int led = 13;

/*******************************************************

DMA definitions

********************************************************/

#define DMAMUX0_CHCFG(n)          *(volatile uint8_t  *)(0x40021000+n)

struct DMA_TCD_REG {
    volatile void * volatile SADDR; 		//0x40009000 // TCD Source Address
    volatile int16_t      SOFF; 			//0x40009004  // TCD Signed Source Address Offset
    volatile uint16_t     ATTR;  		//0x40009006 // TCD Transfer Attributes
    union {
    volatile uint32_t     NBYTES_MLNO; 	//0x40009008 // TCD Minor Byte Count (Minor Loop Disabled)
    volatile uint32_t     NBYTES_MLOFFNO; //0x40009008 // TCD Signed Minor Loop Offset (Minor Loop Enabled and Offset Disabled)
    volatile uint32_t     NBYTES_MLOFFYES; //0x40009008 // TCD Signed Minor Loop Offset (Minor Loop and Offset Enabled)
    };
    volatile int32_t      SLAST; 		//0x4000900C  // TCD Last Source Address Adjustment
    volatile void * volatile DADDR; 		//0x40009010 // TCD Destination Address
    volatile int16_t      DOFF; 			//0x40009014  // TCD Signed Destination Address Offset
    union {
    volatile uint16_t     CITER_ELINKYES; //0x40009016 // TCD Current Minor Loop Link, Major Loop Count, Channel Linking Enabled
    volatile uint16_t     CITER_ELINKNO; //0x40009016 // ??
    };
    volatile int32_t      DLASTSGA; 		//0x40009018  // TCD Last Destination Address Adjustment/Scatter Gather Address
    volatile uint16_t     CSR; 			//0x4000901C // TCD Control and Status
    union {
    volatile uint16_t     BITER_ELINKYES; //0x4000901E // TCD Beginning Minor Loop Link, Major Loop Count, Channel Linking Enabled
    volatile uint16_t     BITER_ELINKNO; //0x4000901E // TCD Beginning Minor Loop Link, Major Loop Count, Channel Linking Disabled
    };
} ;


/*******************************************************

DMA from PIT_CVAL0 to memory on port pin event, one major loop transfers 
the timer count to two consecutive words in eventTimes array using two events
from the port pin.

********************************************************/

DMA_TCD_REG * TCD0 = (DMA_TCD_REG *)0x40009000;

uint32_t eventTimes[2];

void initDMA(struct DMA_TCD_REG * dma_tcd) {
  /* Grab channel number from TCD address */
  int dma_channel = (((uint32_t)dma_tcd)>>5)&0xF;

  /* Enable DMAMUX and DMA clock domains */
  SIM_SCGC6 |= SIM_SCGC6_DMAMUX;
  SIM_SCGC7 |= SIM_SCGC7_DMA;
  
  /* Disable the DMAMUX for this channel */
  DMAMUX0_CHCFG(dma_channel) = DMAMUX_DISABLE;

  /* Transfer 4 bytes per request */
  dma_tcd->SADDR = (void *)&PIT_CVAL0;
  dma_tcd->SOFF = 0;
  dma_tcd->DADDR = eventTimes; // &GPIOD_PSOR;
  dma_tcd->DOFF = 4;
  dma_tcd->ATTR = DMA_TCD_ATTR_SSIZE(DMA_TCD_ATTR_SIZE_32BIT) | DMA_TCD_ATTR_DSIZE(DMA_TCD_ATTR_SIZE_32BIT);
  dma_tcd->NBYTES_MLNO = 4;
  
  /* Major loop is two iterations, restore destination address */
  dma_tcd->SLAST = 0;
  dma_tcd->DLASTSGA = -8;
  dma_tcd->BITER_ELINKNO = 2;
  dma_tcd->CITER_ELINKNO = 2;

  dma_tcd->CSR = 0;
  /* Disable minor loop mapping */
  DMA_CR = 0;
  /* Enable channel requests */
  DMA_SERQ = dma_channel;
  /* Enable the DMAMUX */
  DMAMUX0_CHCFG(dma_channel) = DMAMUX_ENABLE | DMAMUX_SOURCE_PORTC;

}


void setup() {
  Serial.begin(115200);
  delay(2000);
  SIM_SCGC6 |= SIM_SCGC6_PIT;
  PIT_MCR = 0;
  PIT_LDVAL0 = 0xFFFFFFFF; /* 32 bit freerunning */
  PIT_TCTRL0 = 1;        /* Enable without interrupts */
  pinMode(led,OUTPUT);
  PORTC_PCR7 = PORT_PCR_MUX(1);
  /* Wait for end of PPS pulse */
  while (!(GPIOC_PDIR&(1<<7))) ;
  while (GPIOC_PDIR&(1<<7)) ;
  initDMA(TCD0);
  PORTC_PCR7 = PORT_PCR_IRQC(3) | PORT_PCR_MUX(1);
      Serial.print("CITER ");Serial.println(TCD0->CITER_ELINKNO);
      Serial.print("CSR   ");Serial.println(TCD0->CSR,HEX);
      Serial.print("GPIOC_PDIR ");Serial.println(GPIOC_PDIR,BIN);
      Serial.println("*******************");
}

uint32_t lastPulse;
void loop() {
  uint32_t count, intervall;
  if (Serial.available()) {
    char c=Serial.read();
    if (c=='p') {
      Serial.println(DMA_ERQ,HEX);
      Serial.print("F_BUS ");Serial.println((uint32_t)F_BUS);
      Serial.print("MCM_PLASC ");Serial.println((uint32_t)MCM_PLASC,HEX);
      Serial.print("MCM_PLAMC ");Serial.println((uint32_t)MCM_PLAMC,HEX);
      Serial.print("DMA_ES ");Serial.println((uint32_t)DMA_ES,HEX);
      Serial.print("SADDR ");Serial.println((uint32_t)TCD0->SADDR,HEX);
      Serial.print("SOFF  ");Serial.println((int32_t)TCD0->SOFF);
      Serial.print("DADDR ");Serial.println((uint32_t)TCD0->DADDR,HEX);
      Serial.print("DOFF  ");Serial.println((int32_t)TCD0->DOFF);
      Serial.print("CSR   ");Serial.println((uint32_t)TCD0->CSR,HEX);
      Serial.print("CITER ");Serial.println(TCD0->CITER_ELINKNO);
      Serial.print("CSR   ");Serial.println(TCD0->CSR,HEX);
      Serial.print("GPIOC_PDOR ");Serial.println(GPIOC_PDOR,BIN);
      Serial.print("GPIOC_PDIR ");Serial.println(GPIOC_PDIR,BIN);
      Serial.print("PIT_CVAL0  ");Serial.println((uint32_t)PIT_CVAL0,HEX);
      Serial.print("&eventTime ");Serial.println((uint32_t)eventTimes,HEX);
      Serial.print("eventTime0 ");Serial.println(eventTimes[0]);
      Serial.print("eventTime1 ");Serial.println(eventTimes[1]);      
    }
  }
  digitalWrite(led,GPIOC_PDIR&(1<<7));
  if ((TCD0->CSR&DMA_TCD_CSR_DONE)) {
    /* Clear the DONE flag */
    TCD0->CSR = 0;
    count = eventTimes[0]-eventTimes[1];
    intervall = lastPulse-eventTimes[0];
    lastPulse = eventTimes[0];
    Serial.println(count);
    Serial.println(intervall);
    Serial.println((double)intervall/48.0);
  }
}
 
Thanks for the comments. I tested 2. Some of the others are over my head but I'll look at them some more.

FreqMeasure works very well. With a 100 Hz input I measured values of 479992-3 with no exceptions for over 3 hours run time.

I changed the code to capture the cpu cycle count in the ISR and to use a single ISR, see below. The average count increased from 239975 to 239994. That's closer to the nominal 240000 (100 Hz, 50% duty cycle). I still see about the same close in distribution plus the occasional reading about 100 cpu cycles slow. The table shows the results for a run of about 200000 readings.

I noticed that rev 1.23 of teensyduino changes the priority of the Systick interrupt and I might try compiling with that.

I'll keep working on it. The performance is already much better than using pulseIn, especially if I average. The "off" readings are spaced out so averaging will work well.

Bucket Count
<-103 25
-28 2
-26 11
-24 12
-8 2
-6 12
-4 443
-2 31100
-1 100
0 194900
2 200
4 284
6 811
8 31
10 137
12 5
14 4


Code:
/*
Teensy 3.1, Arduino 1.61 and Teensyduino 1.21
*/
const int pin2 = 2;
unsigned long longCount = 0;
long test;
volatile unsigned long timeStamp = 0;
unsigned long pulseWidth = 0;
unsigned long fallEdge = 0;
unsigned long riseEdge = 0;
int val_p2 = 0;

void setup() {
  ARM_DEMCR |= ARM_DEMCR_TRCENA;
  ARM_DWT_CTRL |= ARM_DWT_CTRL_CYCCNTENA;
  pinMode(pin2, INPUT);
  Serial.begin(9600);
  attachInterrupt(pin2, pw_ISR, CHANGE); // set flag on change
}

void loop() {
  longCount++;
  fallEdge = 0;
  riseEdge = 0;
  while (fallEdge == 0 || riseEdge == 0) { //wait for both edges
    timeStamp = 0;
    while (timeStamp == 0) { // wait for an edge
    }
    val_p2 = digitalRead(pin2);
    if (val_p2 == LOW) {  // low edge first
      fallEdge = timeStamp;
    }
    if (val_p2 == HIGH && fallEdge != 0) { // low to high AND previous high to low
      riseEdge = timeStamp;
    }
  }

  pulseWidth = riseEdge - fallEdge;
  test = pulseWidth - 239994;  // 24000 based on 100 Hz, 50% and 48 MHz. 239994 average this test
  if (test < -2 || test > 2) {  // most readings 0, -2
    Serial.print(longCount);
    Serial.print("  ");
    Serial.print(test);
    Serial.print("  ");
    Serial.println(pulseWidth);
  }
  delay(100);
}
//-------------------------------------
void pw_ISR() {
  timeStamp = ARM_DWT_CYCCNT;
}
 
239994 is about 25 ppm away from the nominal value. lthough a tiny bit larger then what i am typically seeing, this can just be your crystal offset.
 
There's an old message about reducing IntervalTimer jitter. I don't have the link handy right now... But the basic ideas are priority(0) and FASTRUN for the function, so it executes from RAM to avoid the Flash memory cache.

Also, are you sure the 100 Hz waveform is better than 25 ppm accurate?
 
Not sure how this might help the discussion - but I got to alter some code. It might offer a baseline for seeing noise in the system, if it is valid at all. It shouldn't print much, unless there is a larger than 2 error.

Using the above code merged with a Timer interrupt driven Blink sketch I made - at 48MHz CPU I came up with this - requiring a wire between pins #2 and #4 and no external source.

Generally it runs with no difference outside +/- 2, and when it does it prints. It will run fine thousands of times - then fail in bunches of ~30. Last run 123 failures over +/-2 out of 18,888, then fine and up to 27,211 it accumulated 169 failures. Looking at those results the failures are at longCount==1k, 9k, 18k, 27k, the next batch at 35k, 44k, 52k. And when it fails they are average -50 cycles [rarely over and often -100 or -200]

When I put on FASTRUN - I wasn't sure it helped, some runs seemed worse. Last run with FASTRUN has breaks on similar boundaries [@400, 9k, 17k, 26k, 35k, 43k, 52k], but 17% fewer, though of similar magnitude.

Extra code in my blinkLED ISR also seemed to make things change, but not always.

More stats and counts easily possible and finding the cause of the 9,000 run cycle error might be telling.

Code:
/*
Teensy 3.1, Arduino 1.61 and Teensyduino 1.21
https://forum.pjrc.com/threads/28509-Teensy-3-1-time-measurements
*/
const int pin2 = 2;
unsigned long longCount = 0;
long test;
long lasttest = 0;
volatile unsigned long timeStamp = 0;
unsigned long pulseWidth = 0;
unsigned long fallEdge = 0;
unsigned long riseEdge = 0;
int val_p2 = 0;


#include <TimerOne.h>
long unsigned MicrosVal = 5000;

#define qBlink() (digitalWriteFast(LED_BUILTIN, !digitalReadFast(LED_BUILTIN) ))
#define q4Blink() (digitalWriteFast(4, !digitalReadFast(4) ))

void setup(void)
{
  ARM_DEMCR |= ARM_DEMCR_TRCENA;
  ARM_DWT_CTRL |= ARM_DWT_CTRL_CYCCNTENA;
  pinMode(pin2, INPUT);
  Serial.begin(9600);
  attachInterrupt(pin2, pw_ISR, CHANGE); // set flag on change

  pinMode(LED_BUILTIN, OUTPUT);
  pinMode(4, OUTPUT);
  Timer1.initialize(MicrosVal);
  Timer1.attachInterrupt(blinkLED); // blinkLED to run every 0.15 seconds
  Serial.begin(9600);
  while (!Serial && (millis () < 5000)) ;
  Serial.print(test);

}


void loop() {
  longCount++;
  fallEdge = 0;
  riseEdge = 0;
  while (fallEdge == 0 || riseEdge == 0) { //wait for both edges
    timeStamp = 0;
    while (timeStamp == 0) { // wait for an edge
//      yield();
    }
    val_p2 = digitalRead(pin2);
    if (val_p2 == LOW) {  // low edge first
      fallEdge = timeStamp;
    }
    if (val_p2 == HIGH && fallEdge != 0) { // low to high AND previous high to low
      riseEdge = timeStamp;
    }
  }

  pulseWidth = riseEdge - fallEdge;
  test = pulseWidth - 239998;  // 24000 based on 100 Hz, 50% and 48 MHz. 239994 average this test
  if ((test < -2 || test > 2) && test != lasttest) {  // most readings 0, -2
    lasttest = test;
    Serial.print(longCount);
    Serial.print("  ");
    Serial.print(test);
    Serial.print("  ");
    Serial.println(pulseWidth);
  }
//  delay(1);
}
//-------------------------------------
FASTRUN 
void pw_ISR() {
  timeStamp = ARM_DWT_CYCCNT;
}

FASTRUN 
void blinkLED(void)
{
  q4Blink();
//  qBlink();
}
 
I got back to the msg #13 code and made this edit (added the two bold lines) and it improved my results - maximizing the time to the first 'tested' change. Depending on how fast the next 'pin change' was, I assume it was causing a race to the answer to discriminate the edges on the next change - error rate dropped by 80%. [48 errors in 60k samples instead of 234], and the average margin of the error is under 5 ticks, instead of over 100, but still see some 117-160:

Code:
  riseEdge = 0;
[B]  timeStamp = 0;
  while (timeStamp == 0) ; // Throw away next edge[/B]
  while (fallEdge == 0 || riseEdge == 0) { //wait for both edges
    timeStamp = 0;
    while (timeStamp == 0) { // wait for an edge

Before this change the above code was seeing runs of 10-20 grouped Pulse Misses. I am still seeing some tests out of range by 117 to 262 cycles, but they no longer are grouping every ~9K hits on the longcount.

544 over +/-2 in 845,402 trials, and grouped errors are max 5, 2 is more common, and single errors dominate those.

There is something here eating response time on %0.064 of the tests against internal interrupt timer pin change, typically small sometimes %0.065+ of expected value (156 cycle error).
 
There is something here eating response time on %0.064 of the tests against internal interrupt timer pin change

Maybe the USB interrupt?

Try adding NVIC_SET_PRIORITY(IRQ_PORTD, 0), since pin 2 is on the port D interrupt vector.

Also, use Teensyduino 1.23. The Systick timer priority was changed, so you can use the highest priority without interference.
 
PAUL:: Quick update - I think you found part of it - seems like another 35% drop in errors. Also The pulse measure went from 239998 average to 240000, most reported errors end up -4, but more were +4, so the common variance is +/-3 but prior code was at +/-2 so just moving the mid-point is enough change.

I haven't gone to 1.23 yet. I still see error groups 'runs' of 2-3-4 long, most errors are short ticks, the only extreme ticks are 8% of the errors at +104 to +214

Since I'm using a timer interrupt to toggle pin 4 - I should maybe track the accuracy of that in parallel to show compounded errors.

NOTE: Per Msg#14, Still need to SKIP that next CHANGE on loop entry to allow time to get the PULSE right, taking that off was better but still doubled the errors.

Had this PORT chart changed/been updated for the T_3.1 or T_LC?

https://forum.pjrc.com/threads/17532-Tutorial-on-digital-I-O-ATMega-PIN-PORT-DDR-D-B-registers-vs-ARM-GPIO_PDIR-_PDOR?p=30625&viewfull=1#post30625

Quick view of BEFORE and AFTER stats:

Quick before snip BEFORE the NVIC PRI change, shows 95 errors up to 131897 tests::
ERROR GROUP #=2 >> total out of range #=91
130603 -108 239890
130723 -176 239822
131897 -8 239990_8

Current AFTER test - shows 70 errors up to 131589 tests::
ERROR GROUP #=2 >> total out of range #=63
127198 -3 239997_-4
131589 110 240110_-4_-6_-4_-6
 
Looks like it's still only for Teensy 3.0 and 3.1.

Teensy-LC differs on pins 3-4 and 24-26. Of course, LC doesn't have 27-33. All the other pins have identical mapping between Teensy LC and 3.1.
 
I still think it would be interesting if someone elese tries out the code (#8) that uses port triggers to DMA the PIT value to memory variable.
This bypasses interrups altogether, there are some delays in setting up DMA transactions but with little other DMA activity they should be constant/predictable.
 
mlu: without hardware - but a 3.1 and simple wire - I went with my timer blink code that uses two interrupts. I'll add a tick count to the timer interrupt to see if it shows variance, and repost my code. Glad Paul read my code - it improved helped, and now I need to get 1.23beta too.
 
No hardware needed, the GPS PPS is only one possible input, you can use an on chip generated square wave, like PWM with
pin to pin connection, that should work perfect. But in general a setup like this would be used with some hardware generating
signal you would want to measure.

My main point is that DMA latency is less than IRQ, at least if no big hungry DMA engines like audio output is running.
 
Paul: Similar results using TD_1.23b1 installed over my 1.6.3 IDE on Win 7.

{ NOTE: it compiled and ran no issues under 1.23b1 }

Still seeing groups of 2,3,4. Ticks outside +/-2 May be down 10% from 223 out of range to only 199 on test of 340,046 trials

Distribution and range of error info as I print it doesn't show it varied much.

I started looking at the Tick count timing on my Timer Interrupt code - that then toggles the port to trigger the change, and I am seeing variability in the timing there that would account for some error.
 
Tracking ticks on the TIMER BLINK interrupt didn't interfere with or worsen the PULSE interrupt behavior. In fact I think it is showing something on the larger variations. There are ones like these two where one error in the BLINK rolls into the PULSE, and the one that follows the BLINK was on the mark, but the PULSE slipped.

longCount=167941 PulseErr=244 MeasuredPulse=240244 (ticks at blink INT)240244
longCount=169655 PulseErr=116 MeasuredPulse=240116 (ticks at blink INT)240000

I also see ones like these suggesting the BLINK was slipped 101 ticks, but the PULSE ends up coming in off by 4.

longCount=28589 PulseErr=-4 MeasuredPulse=239996 (ticks at blink INT)240101

I have also started computing/printing the GOOD RUNS ## between error batches - and it seems there may be some period to it. [ The one I first saw as a 9K multiple. ]

So far it just shows that there are ticks going somewhere, at some time holding up interrupts.
 
Paul does this output below suggest anything to you? Does this seem to show some similarity to the OP getting periodic odd readings? Is it bothersome enough to worry over? 38 to 260 tick recurring delay out of 48,000,000?

As I wrote the msg #22 I had an idea to also print millis and micros, and when I did I see the pattern below when the larger variations appear. The values printed appear after a long run of timed signals inside the "pulseWidth - 240000" +/- 2 tick window, they are printed when one steps outside that window, and the prior last 'outside +/- 2' was more than 2,000 'test cycles' prior. In these cases the value noted "LONG GOOD LONG COUNT #=4381" shows how many ran inside +/- 2 ticks - in this case 4,381 iterations.

NOTE: Nothing prints to USB when there are no errors and the L.G.L.C is adding up, it may be possible the USB printing on seeing an error creates the 'group' response cluster, but when I started the group counting - I was doing that with only 4-5 char prints per instance , and now printing a ~60 char full line has not overtly changed that (similar groups and same overall error 6%).
View attachment InterruptsTimeMeasure.ino

The pattern is in the last 4 (5) digits of MICROS "???4580" - the pattern only breaks when MICROS rolls over, then the pattern returns around "???7283" - and again "???9987"

Looking at the count it is a near multiple of the 4K figure - but seeing the micros locked inside +/- 2 says something regular is happening. Once this break in the +/- 2 rhythm happens there are from 1 to 6 similar breaks in the next 10 to 30 iterations - then it goes back to being stable between these events.

Note: I see a total of 310 iterations testing outside +/- 2 and this cycle has run 506,542 iterations :: This still comes to the 0.0611% total larger error I was seeing last I looked, and 9% of those are shown below as the largest errors.

Code:
LONG GOOD LONG COUNT #=4381   micros  #=109834580  millis #=109834
LONG GOOD LONG COUNT #=4375   micros  #=197374580  millis #=197374
LONG GOOD LONG COUNT #=4200   micros  #=284974580  millis #=284974
LONG GOOD LONG COUNT #=4362   micros  #=372414580  millis #=372414
LONG GOOD LONG COUNT #=4373   micros  #=459974580  millis #=459974
LONG GOOD LONG COUNT #=2057   micros  #=501414578  millis #=501414
LONG GOOD LONG COUNT #=2316   micros  #=547734579  millis #=547734
LONG GOOD LONG COUNT #=4374   micros  #=635314580  millis #=635314
LONG GOOD LONG COUNT #=4365   micros  #=722794580  millis #=722794
LONG GOOD LONG COUNT #=2991   micros  #=810494580  millis #=810494
LONG GOOD LONG COUNT #=2625   micros  #=863114579  millis #=863114
LONG GOOD LONG COUNT #=4367   micros  #=985674580  millis #=985674
LONG GOOD LONG COUNT #=4375   micros #=1073494579  millis #=1073494
LONG GOOD LONG COUNT #=4364   micros #=1160874580  millis #=1160874
LONG GOOD LONG COUNT #=8727   micros #=1335594579  millis #=1335594
LONG GOOD LONG COUNT #=3487   micros #=1422254580  millis #=1422254
LONG GOOD LONG COUNT #=3223   micros #=1486974578  millis #=1486974
LONG GOOD LONG COUNT #=4349   micros #=1596254579  millis #=1596254
LONG GOOD LONG COUNT #=4353   micros #=1683334578  millis #=1683334
LONG GOOD LONG COUNT #=4345   micros #=1770234579  millis #=1770234
LONG GOOD LONG COUNT #=4345   micros #=1857134580  millis #=1857134
LONG GOOD LONG COUNT #=4350   micros #=1944274580  millis #=1944274
LONG GOOD LONG COUNT #=4350   micros #=2031554578  millis #=2031554
LONG GOOD LONG COUNT #=4353   micros #=2118614579  millis #=2118614
LONG GOOD LONG COUNT #=13114  micros #=2380894580  millis #=2380894
LONG GOOD LONG COUNT #=4325   micros #=2467554580  millis #=2467554
LONG GOOD LONG COUNT #=4320   micros #=2554014580  millis #=2554014
LONG GOOD LONG COUNT #=8618   micros #=2726454580  millis #=2726454
LONG GOOD LONG COUNT #=12851  micros #=2983674581  millis #=2983674
LONG GOOD LONG COUNT #=4277   micros #=3069214580  millis #=3069214
LONG GOOD LONG COUNT #=8533   micros #=3240154580  millis #=3240154
LONG GOOD LONG COUNT #=8550   micros #=3411154578  millis #=3411154
LONG GOOD LONG COUNT #=4261   micros #=3496394580  millis #=3496394
LONG GOOD LONG COUNT #=4253   micros #=3581614580  millis #=3581614
LONG GOOD LONG COUNT #=4263   micros #=3666974580  millis #=3666974
LONG GOOD LONG COUNT #=4260   micros #=3752334579  millis #=3752334
LONG GOOD LONG COUNT #=4531   micros #=3842974582  millis #=3842974
LONG GOOD LONG COUNT #=3992   micros #=3922814579  millis #=3922814
LONG GOOD LONG COUNT #=4255   micros #=4008034580  millis #=4008034
LONG GOOD LONG COUNT #=4265   micros #=4093354578  millis #=4093354
LONG GOOD LONG COUNT #=4250   micros #=4178354580  millis #=4178354
LONG GOOD LONG COUNT #=2928   micros #=4263634579  millis #=4263634

LONG GOOD LONG COUNT #=4260    micros  #=53867283  millis #=4348834
LONG GOOD LONG COUNT #=4250    micros #=138927284  millis #=4433894
LONG GOOD LONG COUNT #=4255    micros #=224207284  millis #=4519174
LONG GOOD LONG COUNT #=12781   micros #=479907284  millis #=4774874
LONG GOOD LONG COUNT #=3804    micros #=556187282  millis #=4851154
LONG GOOD LONG COUNT #=4373    micros #=654327284  millis #=4949294
LONG GOOD LONG COUNT #=3638    micros #=727407282  millis #=5022374
LONG GOOD LONG COUNT #=4379    micros #=829987284  millis #=5124954
LONG GOOD LONG COUNT #=4386    micros #=917987282  millis #=5212954
LONG GOOD LONG COUNT #=4375   micros #=1005487284  millis #=5300454
LONG GOOD LONG COUNT #=4388   micros #=1093247282  millis #=5388214
LONG GOOD LONG COUNT #=4372   micros #=1180707283  millis #=5475674
LONG GOOD LONG COUNT #=4365  micros #=1268027284  millis #=5562994
LONG GOOD LONG COUNT #=8734  micros #=1442907284  millis #=5737874
LONG GOOD LONG COUNT #=4135  micros #=1530187284  millis #=5825154
LONG GOOD LONG COUNT #=2398  micros #=1578307282  millis #=5873274
LONG GOOD LONG COUNT #=4355  micros #=1704967284  millis #=5999934
LONG GOOD LONG COUNT #=4372  micros #=1792407284  millis #=6087374
LONG GOOD LONG COUNT #=4371  micros #=1879947284  millis #=6174914
LONG GOOD LONG COUNT #=4858  micros #=1977367282  millis #=6272334
LONG GOOD LONG COUNT #=3890  micros #=2055167284  millis #=6350134
LONG GOOD LONG COUNT #=8765  micros #=2230687284  millis #=6525654
LONG GOOD LONG COUNT #=3864  micros #=2318527284  millis #=6613494
LONG GOOD LONG COUNT #=8767  micros #=2493907282  millis #=6788874
LONG GOOD LONG COUNT #=4366  micros #=2581267284  millis #=6876234
LONG GOOD LONG COUNT #=3439  micros #=2668927284  millis #=6963894
LONG GOOD LONG COUNT #=4366  micros #=2756487283  millis #=7051454
LONG GOOD LONG COUNT #=4366  micros #=2843987284  millis #=7138954
LONG GOOD LONG COUNT #=4363  micros #=2931287284  millis #=7226254
LONG GOOD LONG COUNT #=4361  micros #=3018627283  millis #=7313594
LONG GOOD LONG COUNT #=4365  micros #=3105927284  millis #=7400894
LONG GOOD LONG COUNT #=4371  micros #=3193387284  millis #=7488354
LONG GOOD LONG COUNT #=4369  micros #=3280927284  millis #=7575894
LONG GOOD LONG COUNT #=4376  micros #=3368647282  millis #=7663614
LONG GOOD LONG COUNT #=4373  micros #=3456147283  millis #=7751114
LONG GOOD LONG COUNT #=4368  micros #=3543567284  millis #=7838534
LONG GOOD LONG COUNT #=4380  micros #=3631287283  millis #=7926254
LONG GOOD LONG COUNT #=4365  micros #=3718607284  millis #=8013574
LONG GOOD LONG COUNT #=4369  micros #=3806127284  millis #=8101094
LONG GOOD LONG COUNT #=4363  micros #=3893627284  millis #=8188594
LONG GOOD LONG COUNT #=2499  micros #=3943807286  millis #=8238774
LONG GOOD LONG COUNT #=4362  micros #=4068707284  millis #=8363674
LONG GOOD LONG COUNT #=4385  micros #=4156487283  millis #=8451454
LONG GOOD LONG COUNT #=4364  micros #=4243887284  millis #=8538854

LONG GOOD LONG COUNT #=4376     micros #=36519987  millis #=8626454
LONG GOOD LONG COUNT #=4366   micros #=123919988  millis #=8713854
LONG GOOD LONG COUNT #=4371   micros #=211419988  millis #=8801354
LONG GOOD LONG COUNT #=4370   micros #=298979987  millis #=8888914
LONG GOOD LONG COUNT #=4360   micros #=386339988  millis #=8976274
LONG GOOD LONG COUNT #=4365   micros #=473839988  millis #=9063774
LONG GOOD LONG COUNT #=4377   micros #=561439988  millis #=9151374
LONG GOOD LONG COUNT #=4376   micros #=648999988  millis #=9238934
LONG GOOD LONG COUNT #=4380   micros #=736639986  millis #=9326574
LONG GOOD LONG COUNT #=8754   micros #=911739986  millis #=9501674
LONG GOOD LONG COUNT #=4381   micros #=999399986  millis #=9589334
LONG GOOD LONG COUNT #=4364  micros #=1086679988  millis #=9676614
LONG GOOD LONG COUNT #=4365  micros #=1174199988  millis #=9764134
LONG GOOD LONG COUNT #=4376  micros #=1261819988  millis #=9851754


These are the 29 iterations [first line value is the iteration #] shown with the largest tick misses [second value on line] from the 310 - error is between -262 and -38. The values "ll:" or "nn:" are '0' if they hit the target 240000. Sometimes the difference in those values IS the amount in error shown by the second value and those are the BLINK_interrupt error, the third value is that measured as the PulseWidth, if the error isn't in the BLINK ll/nn values then it came from timing on the CHANGE detect interrupt for the PULSE measure (the first 3 instances of this are in BOLD).
Code:
[B]9901  -262  239738 ll:240001 nn:0 >> total out of range #=9[/B]
10021  -38  239962 ll:240038 nn:239996 >> total out of range #=10
[B]18593  108  240108 ll:0 nn:0 >> total out of range #=13
22971  108  240108 ll:0 nn:0 >> total out of range #=15[/B]
25043  -112  239888 ll:240112 nn:239999 >> total out of range #=22
37506  82  240082 ll:240082 nn:240001 >> total out of range #=31
43128  82  240082 ll:240082 nn:240001 >> total out of range #=36
49256  108  240108 ll:0 nn:0 >> total out of range #=42
58016  108  240108 ll:0 nn:0 >> total out of range #=53
67598  -46  239954 ll:240046 nn:239999 >> total out of range #=60
74321  -42  239958 ll:240042 nn:239999 >> total out of range #=65
74361  -170  239830 ll:240172 nn:239999 >> total out of range #=66
92829  108  240108 ll:0 nn:0 >> total out of range #=74
127673  108  240108 ll:0 nn:0 >> total out of range #=91
153433  108  240108 ll:0 nn:0 >> total out of range #=99
210226  260  240260 ll:240260 nn:240001 >> total out of range #=125
221667  108  240108 ll:0 nn:0 >> total out of range #=129
242530  -258  239742 ll:0 nn:0 >> total out of range #=140
247437  108  240108 ll:0 nn:0 >> total out of range #=142
251091  -212  239788 ll:240212 nn:239999 >> total out of range #=150
287095  106  240106 ll:240106 nn:239990 >> total out of range #=175
291230  108  240108 ll:0 nn:0 >> total out of range #=176
313589  -78  239922 ll:240078 nn:239999 >> total out of range #=192
326783  112  240112 ll:240112 nn:240001 >> total out of range #=199
344728  -116  239884 ll:240116 nn:239999 >> total out of range #=210
400651  108  240108 ll:0 nn:0 >> total out of range #=241
411911  52  240052 ll:240052 nn:240001 >> total out of range #=253
418156  108  240108 ll:0 nn:0 >> total out of range #=257
496932  108  240108 ll:0 nn:0 >> total out of range #=30
 
I have to admit I have not read the thread...

The Teensy has the ability to capture the count of a timer at the time a pinchange occurs. Do you use this feature ?
This reading is independed of any software issues.
 
Status
Not open for further replies.
Back
Top