Measure short amounts of time with micros()

[MORA99 9]

Tested on CC3200.

 

I am trying to see how long a pin is held in one state, the time will be pretty short at most 100us.

 

So I tried with micros() before and after, but didnt get good results, then I tried timing a simple pinmode and digitalwrite, that gave a negative or very large value...

 

So I boiled it down to this example

while(1)
{
  unsigned long i = micros();
  delayMicroseconds(100);
  unsigned long p = micros();  
  unsigned long o = p-i;
  Serial.print("Tooki : ");  Serial.println(i);
  Serial.print("Tookp : ");  Serial.println(p);
  Serial.print("Tooko : ");  Serial.println(o);  
  
  i = micros();
  delayMicroseconds(1000);
  p = micros();  
  o = p-i;
  Serial.print("Tooki : ");  Serial.println(i);
  Serial.print("Tookp : ");  Serial.println(p);
  Serial.print("Tooko : ");  Serial.println(o);  

Serial.println();Serial.println();Serial.println();

delay(1000);  
  
}

I have made a time machine

Tooki : 112690699
Tookp : 112690597
Tooko : 4294967194
Tooki : 112693032
Tookp : 112694699
Tooko : 1667

The numbers are stable, the funny part is that i-p is about 100, but p is set to micros() after the sleep of 100micro seconds so it should be lower than i.

If I increase the sleep to 1000(1 mili second if I am not mistaken), then it works correctly

Tooki : 4064995
Tookp : 4065995
Tooko : 1000
Tooki : 4067298
Tookp : 4068995
Tooko : 1697

This is tested in a while loop at the end of the setup function.

 

I have searched for similar issues but they seemed to relate to using the function in interrupts, if thers another thread on the subject already, please send me in the right direction.

[chicken 630]

Internally micros() relies on timer interrupts to update the microsecond count a few times every millisecond or so. delayMicroseconds() uses loops, basically counting clock cycles. So it might happen, that either the timer interrupt did not happen or interferes at the very moment you try to read micros(), which for short periods can lead to the funny results you observe.

 

To more reliably measure pulse lengths, there's the pulseIn() command, which measures pulse lengths by counting clock cycles.

 

PS: Looking at the pulseIn source code, I think there's still room for improvement. I also uses loops (clock cycles) to measure time and will understate the pulse length when there are interrupts during measurement. Might be an interesting exercise to refactor it to use a timer instead.

[bobnova 59]

If you have the time/energy for it your best bet is probably to set up a timer to do your timing for you. At that point you'll know exactly what its operating parameters are and it won't throw as many surprises at you as delayMicroseconds() and micros() will.

[MORA99 9]

I will try pulsein, I am using it for reading a dht sensor, so I dont need super accurate numbers, most of the time I just need to differentiate between 30us and 70us.

Originally the code I ported from avr 8bit was just using sleeps, but I changed it to use DigitalRead which seems to be slow enough to offset the sleeps, I tried to measure the time it takes for digitalread when I ran into the micros() running backwards

[igor 163]

Another way to measure time between events is described here.

 

http://forum.stellarisiti.com/topic/1908-execution-time-the-easy-way

 

Examples given are for Tiva and for ARM CMSIS library.

It relies on particular hardware on the Cortex Mx processors.  I do not know for sure whether the CC3200 has the requisite hardware.

You may also need to find the appropriate CMSIS header file for the CC3200.

 

If the processor supports this, it can be handy for profiling.

(Can calculate time between different places in clock cycles.)

[MORA99 9]

Hmm, the pulsein didnt help, so to check if it could even detect the changes I added a outpin that will be toggled on each change, and it works fine.

int8_t dht_getdata(unsigned char pin, short *temperature, short *humidity) {
pinMode(3, OUTPUT);
	uint8_t bits[5];
	uint8_t i,j = 0;

	memset(bits, 0, sizeof(bits));
/*
	//reset port
	pinMode(pin, OUTPUT);
	digitalWrite(pin, HIGH);
	delay(100);
*/
	//send request

	pinMode(pin, OUTPUT);
	digitalWrite(pin, LOW);
	#if DHT_TYPE == DHT_DHT11
	delay(18);
	#elif DHT_TYPE == DHT_DHT22
	delayMicroseconds(500);
	#endif

	pinMode(pin, INPUT);
	digitalWrite(pin, HIGH);

	delayMicroseconds(40);

	//check start condition 1
	if(digitalRead(pin)==HIGH) {
		return -1;
	}
	delayMicroseconds(80);
	//check start condition 2
	if(digitalRead(pin)==LOW) {
		return -2;
	}
//	delayMicroseconds(40);

      uint32_t res[5*8];
      //Sensor init ok, now read 5 bytes ...
      for (j=0; j<5*8; j++)
      {
        res[j] = pulseIn(pin, HIGH, 1000);
        digitalWrite(3, !digitalRead(3));
      }
      
      for (j=0; j<5*8; j++)
      {
        Serial.print(j);Serial.print(" : ");Serial.println(res[j]);      
      }
      

And it toggles the pin just fine (screenshot of capture attached, green is the output pin being toggled, yellow is the signal I am trying to measure).

 

Output on serial console

0 : 4294967269
1 : 4294967269
2 : 4294967269
3 : 4294967269
4 : 4294967270
5 : 4294967270
6 : 4294967270
7 : 4294967224
8 : 1927
9 : 4294967223
10 : 4294967223
11 : 4294967223
12 : 4294967270
13 : 4294967223
14 : 4294967223
15 : 4294967223
16 : 4294967269
17 : 4294967270
18 : 4294967269
19 : 4294967270
20 : 4294967269
21 : 4294967269
22 : 4294967268
23 : 4294967271
24 : 4294967224
25 : 4294967222
26 : 4294967269
27 : 4294967222
28 : 4294967223
29 : 4294967269
30 : 4294967270
31 : 4294967223
32 : 4294967223
33 : 4294967223
34 : 4294967269
35 : 4294967222
36 : 4294967270
37 : 4294967271
38 : 4294967270
39 : 4294967224

I will keep digging for a solution

Maybe these functions dont play well with the 80mhz cpu.

[MORA99 9]

So pulseIn in cc3200 uses micros, which was my problem to start with, so same issue.

I made fresh sketch to try and isolate micros problem()

 

Test micro sleeps...
for (uint16_t i=500; i<16000; i=i+500)
{
  a = micros();
  delayMicroseconds(16000);
  b = micros();
  c=b-a;
  Serial.println(i);
  Serial.print("A: ");Serial.println(a);
  Serial.print("B: ");Serial.println(;
  Serial.print("C: ");Serial.println(c);  
}

 

All of those sleeps are between 1000 and 1800us acording to the cpu, but about 3ms acording to my logic analyser.

At the very least they should be different, and getting longer for each loop.

 

 

 

 

Trying to find out where these timers come from ...

unsigned long micros(void)
{
	return (milliseconds * 1000) + (SysTickValueGet() / (F_CPU/1000000));
}

So miliseconds times 1000, plus system tics, devided by cpu devided by 1million to get cycles per us

 

SysTickValueGet() - systick.c
unsigned long SysTickValueGet(void)
{
    //
    // Return the current value of the SysTick counter.
    //
    return(HWREG(NVIC_ST_CURRENT));
}

./cores/cc3200/inc/hw_nvic.h:#define NVIC_ST_CURRENT         0xE000E018  // SysTick Current Value Register

 

Page 58 in CC3200 datasheet:

SysTick (see Section 3.2.1) Provides a simple, 24-bit clear-on-write, decrementing, wrap-on-zero counter with a flexible control mechanism.

 

'decrementing' hmm, flashback to my original time machine where the delay was roughly correct, but the timer values were odd.

 

void loop()
{
Serial.println(SysTickValueGet());
delay(100); 
}

24bits in dec = 16 777 215, every 100ms I get roughly the same number, not sure what that says.

79461, 79465, 79475, 79480, 79452, 79453, 79453, 79461, 79465

 

  unsigned long test[1000];
  for (uint16_t i=0; i<1000; i++)
    test[i]=SysTickValueGet();
    
  for (uint16_t i=0; i<1000; i++)
  {
    Serial.print(i);Serial.print(" > ");Serial.println(test[i]);
  }  

170 > 27606

171 > 27554

172 > 27503

173 > 27452

174 > 27401

175 > 27349

176 > 27298

177 > 27247

178 > 27196

179 > 27144

180 > 27093

181 > 27042

182 > 26991

183 > 26939

184 > 26888

185 > 26837

186 > 26786

187 > 26734

188 > 26683

 

Aha, so there is the 24bit timer, if it ticks 80million times a second it overflows 4 times a second.

But it counts down not up, so back to pulseIn.

 

hardware/cc3200/cores/cc3200/wiring_pulse.c

    // wait for the pulse to start
    while (MAP_GPIOPinRead(portBase, bit) != stateMask)
        if (numloops++ == maxloops)
            return 0;

    // wait for the pulse to stop
    unsigned long start = micros();

    while (MAP_GPIOPinRead(portBase, bit) == stateMask) {
        if (numloops++ == maxloops)
            return 0;
    }
    unsigned long end = micros();
    unsigned long result = end - start;

That assumes that micros counts up, but with current code micros counts down untill it reaches milisecond boundary.

So I made a copy of pulseIn and changed the line     unsigned long result = end - start; to      unsigned long result = start - end;

 

Then setup my logic analyser to make a simple 50% PWM signal with 20us pulses to the CC3200 and ran this test program

  for (uint16_t i=0; i<1000; i++)
    Serial.println(pulseinn(3,HIGH,100000));

20

19

21

20

4294965317

20

20

19

20

19

20

20

20

20

21

20

21

 

Most of the time timing is correct +/-1us, and then a huge wrong reading.

4 294 965 317 which is close to the max value of my unsigned long, which means end was higher than start, so the timer probaly overflowed there.

 

 

[igor 163]

pulseIn is (as you note) pretty crude, 

on the Stellaris and Tiva processors the Timers are capable of measuring time between edges on a signal.

See for instance http://forum.stellarisiti.com/topic/1923-energia-library-timer-based-non-blocking-pulsein-equivalent

I have not studied the timers on the CC3200, but they might have similar capabilities.

[igor 163]

@@MORA99 I think you are saying there is an error in the implementation of micros()  (That it counts halfway backwards).  At least looking at the code that is what it looks like to me.

That error also appears to apply to delayMicroseconds, and pulseIn also has problems because it uses micros().

 

This error appears to apply to the Stellaris/Tiva platform, as well as the CC3200.

 

In the previous release of Energia, micros and delayMicroseconds were handled by a Timer which was programmed to count up.  

I would guess that the conversion to use SysTimer did not take account for the fact that SysTimer counts down.

(Interestingly the driverlib documentation does not bother to mention which way the SysTimer counts.  It really should specify, rather than making one look it up in the device datasheet, or find out by experiment.)

 

The example code in this issue https://github.com/energia/Energia/issues/154

looks like it may deal with the fact that SysTimer counts down.

 

See also:

https://github.com/energia/Energia/issues/400

 

 

@@energia - Since there are already a couple of issues dealing with micros(), plus this discussion thread, I wasn't quite sure what the tidiest way to bring this to the attention of the developers.  Hope this suffices.

[MORA99 9]

Yes I think the problem is energia developer didnt take into account CC3200 counts down on its tick counter, dont know about other boards yet.

 

The micros routine may be able to be adjusted to return correct values, then pulseIn should work also.

The datasheet said it could be reset by writing, so if the ms interrupt resets the tick counter, then 24bits - currentValue is the number of us since last reset, and since theres only 1000us in a ms, it wont get around to overflow.

 

But 80.000.000 / 16.777.215 is exactly 4, so it will reset on its own every 250ms, but thats only for cc3200 running at 80mhz, theres a ethernet board running at 120mhz too, and all the regular boards at <20mhz.

[spirilis 1,265]

Ah krud, that's a common mistake with SysTick too I think (made this same goof with a TivaWare application I wrote a while ago). Will have to take a close look later.

 

Sent from my Galaxy Note II with Tapatalk 4

[MORA99 9]

void loop()
{
Serial.println(SysTickValueGet());
delay(100); 
}

24bits in dec = 16 777 215, every 100ms I get roughly the same number, not sure what that says.

79461, 79465, 79475, 79480, 79452, 79453, 79453, 79461, 79465

So it seems sysTick are being reset to 80000 when crossing a milisecond (number of cycles in a ms) and then decrements.

So a rough fix to micros

return (milliseconds * 1000) + (((F_CPU/1000)-SysTickValueGet()) / (F_CPU/1000000));

The timings are not perfect, maybe due to interrupts, but out of 10000 tests, I only had 1 totally off reading, the rest was within +/-5us, with about 90% of them being +/- 1us.

void delayMicroseconds(unsigned int us)
{
	volatile unsigned long elapsedTime;
	unsigned long startTime = SysTickValueGet();

	do{
		elapsedTime = startTime - SysTickValueGet();
	} while(elapsedTime <= us * (F_CPU/1000000));
}

Oddly enough this function seems to take into account that the systick value is decrementing.

Since SysTickValueGet is being reset to 80000 on each ms, if the current counter is less than the delay time requested it will be inacurate.

Reference says to use delay if delaying more than a few 1000us, and max is 16k, so its edge case to have it being too low.

  digitalWrite(3, HIGH);
  delayMicroseconds(20);
  digitalWrite(3, LOW);
  delayMicroseconds(20);  

gives 22-24us ticks, so looks good.

[chicken 630]

To avoid glitches, you could try to disable interrupts while you read milliseconds and call SysTickValueGet().

 

As for the delayMicroseconds(), I've the feeling that this will misbehave when called shortly before systick rolls over:

 

starttime = 1

elapsedtime = 1 - systick = a very large unsigned integer

elapsedtime almost certainly larger than us * MHz, so while loop will terminate prematurely

 

This could work:

 

do{
  currentTime = sysTickValueGet();
  if(currenttime > startTime) startTime += 80000; // or whatever the reset value is
  elapsedTime = startTime - systick;
} while(elapsedTime <= us * (F_CPU/1000000));

 

In addition I think it will get stuck with input > 1000 microseconds, which is really bad. This could be fixed with the following code at the beginning of the method:

 

if(us >= 1000)
{
  delay(us/1000);
  us = us % 1000;
}

 

With that solution I'd still be worried about race conditions where we miss a few systicks for large values of us. Maybe an overall refactoring would be better:

- retrieve start time using micros()

- calculate end time

- compare current reading of micros() to end time

 

When calculating/comparing, make sure to consider possible rollover when the integer is full. See this thread:

http://forum.43oh.com/topic/3867-strange-millis-behaviour/?p=35084

[MORA99 9]

For my original needs a few us is plenty precise, I have about 30us difference between the 2 signals I need to differenciate, the one way off reading will just get scrapped in CRC, but in general the big one should be avoided somehow.

 

With the original delayMicroseconds it does not get stuck with values larger than 1000, but you always get about 1ms sleep if you ask for more than 1000us.

for (uint16_t i=0; i<16000; i+=250)
{  
  delayMicroseconds(i);
  digitalWrite(3, HIGH);
  delayMicroseconds(i);
  digitalWrite(3, LOW);
}

Capture attached, except for some variation at the start where i is less than 1000, all of them are 1ms.

 

Every ms the tick gets reset to 80k, so if I ask for 5000us sleep at say 70k

Then when the tick gets reset, its (~0-70000) - 80000 placed in an unsigned long and compared to us * ticks_per_us which will obviously be true, since the long will be near its highest value.

 

We could call micros in the loop, but not sure if its too much overhead, or we could replicate the micros function in the delay one to get the correct sleep.

 

 

[update] Just tested my dht reader using original pulseIn but with changed micros and it worked

[igor 163]

So it seems sysTick are being reset to 80000 when crossing a milisecond (number of cycles in a ms) and then decrements.

So a rough fix to micros

return (milliseconds * 1000) + (((F_CPU/1000)-SysTickValueGet()) / (F_CPU/1000000));

The timings are not perfect, maybe due to interrupts, but out of 10000 tests, I only had 1 totally off reading, the rest was within +/-5us, with about 90% of them being +/- 1us.

 

 

 

The micros() that gompf suggested in the Energia issue (same issue I mentioned above) might help prevent totally off reading.

unsigned long micros()
{
register uint32_t ms, cycle_cnt;
do {
  ms = milliseconds ;
  cycle_cnt = SysTickValueGet();
} while (ms != milliseconds );
return (ms * 1000) + ((F_CPU/1000) - cycle_cnt) / (F_CPU/1000000);
}

I have not tested it, etc., but it looks like it should handle the rollover condition better.