ticks_diff not behaving

General discussions and questions abound development of code with MicroPython that is not hardware specific.
Target audience: MicroPython Users.
Post Reply
User avatar
devnull
Posts: 473
Joined: Sat Jan 07, 2017 1:52 am
Location: Singapore / Cornwall
Contact:

ticks_diff not behaving

Post by devnull » Mon Feb 20, 2017 2:05 pm

Here's the output from a function that prints values every 5 seconds, it uses ticks_diff() to calculate secs, mins and hours.

As you can see, it suddenly jumps from 679.43 secs to 4979.68 secs just 5 seconds later:

Code: Select all

secs: 668.86 |mins: 11.15 |hrs: 0.19 |ma: 43.53 |ma/hr: 234.28 |ma/day: 5622.73 |hrs/bat: 11.52
secs: 674.15 |mins: 11.24 |hrs: 0.19 |ma: 43.87 |ma/hr: 234.26 |ma/day: 5622.41 |hrs/bat: 11.53
secs: 679.43 |mins: 11.32 |hrs: 0.19 |ma: 44.21 |ma/hr: 234.25 |ma/day: 5622.09 |hrs/bat: 11.53
secs: 4979.68 |mins: 82.99 |hrs: 1.38 |ma: 44.55 |ma/hr: 32.21 |ma/day: 773.01 |hrs/bat: 83.83
secs: 4984.97 |mins: 83.08 |hrs: 1.38 |ma: 44.89 |ma/hr: 32.42 |ma/day: 778.10 |hrs/bat: 83.28
secs: 4990.25 |mins: 83.17 |hrs: 1.39 |ma: 45.24 |ma/hr: 32.63 |ma/day: 783.19 |hrs/bat: 82.74
This is the method that calculates secs:

Code: Select all

def pincb(pin):
  global data
  if(data['startms']==0):
    data['startms'] = ticks_ms()
    return
  data['count']+=1
  data['secs'] = ticks_diff(ticks_ms(),data['startms']) / 1000
  
It looks like ticks_diff() is not catching the overflow correctly ??

I am using the latest firmware, device is ESP8266.

User avatar
devnull
Posts: 473
Joined: Sat Jan 07, 2017 1:52 am
Location: Singapore / Cornwall
Contact:

Re: ticks_diff not behaving

Post by devnull » Tue Feb 21, 2017 1:45 pm

Turns out that the cause of this is the interrupt routine pincb().

I had to change saving the values in the interrupt so that it does not save to dictionary items.

Once I did this everything behaved as expected.

User avatar
pythoncoder
Posts: 5956
Joined: Fri Jul 18, 2014 8:01 am
Location: UK
Contact:

MicroPython bug?

Post by pythoncoder » Tue Feb 21, 2017 4:23 pm

This could be a MicroPython bug. What does the team think?
Peter Hinch
Index to my micropython libraries.

User avatar
marfis
Posts: 215
Joined: Fri Oct 31, 2014 10:29 am
Location: Zurich / Switzerland

Re: ticks_diff not behaving

Post by marfis » Wed Feb 22, 2017 9:07 pm

can't really explain it but just to note a couple of things:

ticks_diff should return invalid values if the difference is higher than 2**29-1 (as described in the docs). From what I see in the repo this value is the same for all platforms (`MICROPY_PY_UTIME_TICKS_PERIOD`) and works as expected on the REPL:

Code: Select all

>>> ticks_diff(2**27,0)  #ok
134217728
>>> ticks_diff(2**28,0)  #ok
268435456
>>> ticks_diff(2**29-1,0) # ok
536870911
>>> ticks_diff(2**29,0) # wraps around
-536870912
The intention is to calculate efficiently a time difference from a timer value that wraps around. I wouldn't use it for larger values. Better sum up the differences from the last saved timestamp.

I don't know why your code misbehaves at 679sec though (=679430 ticks doesn't fall into a power of 2 border either..). But it will result in an invalid value after 149 hours (2**29 msec).

User avatar
pythoncoder
Posts: 5956
Joined: Fri Jul 18, 2014 8:01 am
Location: UK
Contact:

Re: ticks_diff not behaving

Post by pythoncoder » Thu Feb 23, 2017 6:31 am

In the light of @devnull's comments I wondered if there was a MicroPython bug related to an interrupt handler storing data in a dict. As far as I can see there is not. The following script is running fine on a Pyboard.

Code: Select all

import pyb
from utime import ticks_diff, ticks_us, sleep
data = {'time' : ticks_us(), 'count' : 0, 'fail' : False}
def cb(t):
    now = ticks_us()
    old = data['time']
    if ticks_diff(now, old) > 20000:
        print('Fail: ', now, old)
        data['fail'] = True
    data['time'] = now
    data['count'] += 1

tim = pyb.Timer(1)
tim.init(freq=100)
tim.callback(cb)
while not data['fail']:
    print(data['count'])
    sleep(1)
Peter Hinch
Index to my micropython libraries.

User avatar
Roberthh
Posts: 3667
Joined: Sat May 09, 2015 4:13 pm
Location: Rhineland, Europe

Re: ticks_diff not behaving

Post by Roberthh » Thu Feb 23, 2017 10:08 am

On 8266 I had my problems with the timer callbacks, as these are not real interrupts. Theses callbacks can be interrupted with another timer callback or other interrupts. my callback function was not really more complicate than @nulldev's one. Finally I solved my problem with setting a flag, preventing nested timer callbacks. So it would be interesting to try this flag method. I do not know what the other code is doing here, which may interrupt the timer callback. So trying it with just that callback function may not tell a lot.

From what I understand, @damien's proposed scheduler method would support locking out nested calls.

Post Reply