Why is my timer erratic?

[rhubarbdog]

I have the following code

Code: Select all

import pyb
import time

timer = pyb.Timer(12, freq = 900)
start = time.ticks_us()

def timer_cb(t):
  global start
  
  diff = time.ticks_diff(time.ticks_us(), start)
  # buffer diff
  
timer.callback(timer_cb)
time.sleep(5)
timer.callback(None)

# print buffer

Most of my differences are correct 1111 micro seconds. But 0.22% are at a higher frequency 9kHz
Why is my timer triggering after 111 micro seconds?

[dhylands]

Your code says freq=900 which 0.9 kHz, not 9kHz

[rhubarbdog]

I know 99.7% results are at 900Hz, where as the 0.22% are at 9kHz

[jickster]

Try with different frequencies


Sent from my iPad using Tapatalk Pro

[rhubarbdog]

It seems ok at 1.6 kHz

[Roberthh]

Actually you do not see the timer, but the time stamp stored to your buffer in the call back function. If that 'get & store' in the callback is delayed for some reasons, e.g. a higher priority interrupt, then the time distance to the next callback will be shorter.

[rhubarbdog]

Yes I've seen that where 2 adjacent times are + - delta. And then times go back in sync.

But in this case there is many with period 1111 and just an occasional singleton with period of 111

[pythoncoder]

I can't see how the code quoted can produce the results you describe: start is only initialised once so diff should increase monotonically. Somewhere your code must be resetting it. I suggest you post the entire code so we can review it.
[EDIT]
The following code run on a Pyboard V1.0 does not replicate your result

Code: Select all

import pyb
import time
import micropython
micropython.alloc_emergency_exception_buf(100)

timer = pyb.Timer(12, freq = 900)
start = None
mindiff = 100000
count = 0

def fail(diff):
  print('fail', diff)

def timer_cb(t):
  global start, count, mindiff
  count += 1
  if start is None:
    start = time.ticks_us()
    return

  diff = time.ticks_diff(time.ticks_us(), start)
  mindiff = min(mindiff, diff)
  start = time.ticks_us()
  if diff < 1000:
    micropython.schedule(fail, diff)
  
timer.callback(timer_cb)
time.sleep(5)
timer.callback(None)

print('Iterations:', count, 'min diff:', mindiff)

Outcome:

Code: Select all

Iterations: 4499 min diff: 1084

[rhubarbdog]

Yes i've tried your code @pythoncoder and can't get the problem to occour. Even with a run time of 5 minutes.
As you'll see my initial code is a myth but represents the problem. What i'm doing is measuring analog pins and transmitting them over UART to a second pyboard. The second pyboard writes this info to disk and I analysis the data by converting it to a csv file. When the data set is small enough.

Code: Select all

# file data_logger.py
import pyb
import time
import array
import ustruct
# These 2 are for performace and consistency. use of
# .enable_irq() and disable.irq() take longer but improve
# consistency
import gc
import machine

import micropython
micropython.alloc_emergency_exception_buf(200)

SHORT_CHAR = 'h'
HEADER_FORMAT = '<ii' + SHORT_CHAR
SIZE_OF_HEADER = ustruct.calcsize(HEADER_FORMAT)
SHORT_FORMAT = '<' + SHORT_CHAR
SIZE_OF_SHORT = ustruct.calcsize(SHORT_FORMAT)
SIZE_OF_INT = ustruct.calcsize('<i')
BUFFER_SIZE = const(1024)
BAUD = const(112500)
BITS = const(8)

class logger_Tx():
    def __init__(self, uart, sensor_pins, timer, freq):
        self.data_points = len(sensor_pins)
        self.buffer_ = bytearray(((self.data_points - 1) * SIZE_OF_SHORT)\
                                 + SIZE_OF_HEADER)
        
        self.timer = pyb.Timer(timer, freq = freq)

        self.sensors = []
        for sp in sensor_pins:
            self.sensors.append(pyb.ADC(sp))

        self.uart = pyb.UART(uart, BAUD, BITS, parity = None, stop =1,\
                             flow = 0, timeout_char = 0)

    def begin(self):
        gc.disable()
        self.check = 0
        self.start = time.ticks_us()
        self.timer.counter(0)
        self.timer.callback(self.transmit)

    def end(self):
        self.timer.callback(None)
        gc.enable()

    def timed(self):
        gc.disable()
        self.check = 0
        self.start = time.ticks_us()
        self.transmit(None)
        end = time.ticks_us()
        gc.enable()

        return  time.ticks_diff(end, self.start)
    
    @micropython.native
    def transmit(self, timer):
        machine.disable_irq()
        
        self.check += 1
        ustruct.pack_into(HEADER_FORMAT, self.buffer_, 0, self.check,\
                         time.ticks_diff(time.ticks_us(), self.start),
                         self.sensors[0].read())

        index = SIZE_OF_HEADER

        for s in range(1, self.data_points):
            ustruct.pack_into(SHORT_FORMAT, self.buffer_, index,\
                              self.sensors[s].read())
            index += SIZE_OF_SHORT

        self.uart.write(self.buffer_)
        
        machine.enable_irq()

Here's a main.py to run the logger.
It's sampling pin X1 at 900Hz

Code: Select all

import pyb
import data_logger

log = data_logger.logger_Tx(6 ,('X1', ), 12, 900)
switch = pyb.Switch()
yellow = pyb.LED(3)

def main():
    # press and release USR switch
    while not switch.value():
        pass
    while switch.value():
        pass

    # press USR switch to halt
    log.begin()
    yellow.on()
    while not switch.value():
        pyb.delay(1000)
    log.end()
    yellow.off()

if __name__ == '__main__':
    main()

Thanks for looking at this.
Although it doesn't happen at 1.6Khz i get a lot more transmission errors.

[rhubarbdog]

Here's the coresponding receiver

Code: Select all

#  file data_logger.py
import pyb
import time
import array
import ustruct
# These 2 are for performace and consistency. use of
# .enable_irq() and disable.irq() take longer but improve
# consistency
import gc
import machine

import micropython
micropython.alloc_emergency_exception_buf(200)

SHORT_CHAR = 'h'
HEADER_FORMAT = '<ii' + SHORT_CHAR
SIZE_OF_HEADER = ustruct.calcsize(HEADER_FORMAT)
SHORT_FORMAT = '<' + SHORT_CHAR
SIZE_OF_SHORT = ustruct.calcsize(SHORT_FORMAT)
SIZE_OF_INT = ustruct.calcsize('<i')
BUFFER_SIZE = const(1024)
BAUD = const(112500)
BITS = const(8)

class logger_Rx():
    def __init__(self, uart, data_points, file_name, write_LED = None):
        self.uart = pyb.UART(uart, BAUD, BITS, parity = None, stop =1,\
                             flow = 0, timeout_char = 0,\
                             read_buf_len = BUFFER_SIZE * SIZE_OF_INT)
        self.data_points = data_points + 2
        self.format_ = HEADER_FORMAT
        if data_points > 1:
            self.format_ += (SHORT_CHAR * (data_points - 1))
        self.size_of_format = ustruct.calcsize(self.format_)
        self.file_ = open(file_name, 'wb')
        self.buffer_ = array.array('i', [0 for _ in range(BUFFER_SIZE)])
        self.data = b''
        self.index = 0 
        self.switch = pyb.Switch()
        self.error = False
        self.LED = write_LED

    def begin(self):
        gc.enable()
        while not self.switch.value():
            amount = self.uart.any()
            if amount > 0:
                self.data += self.uart.read(amount)
                
            while len(self.data) >= self.size_of_format:
                numbers = ustruct.unpack(self.format_,\
                                         self.data[:self.size_of_format])

                if self.index + self.data_points < BUFFER_SIZE:
                    for n in numbers:
                        self.buffer_[self.index] = n
                        self.index += 1
                else:
                    delta = BUFFER_SIZE - self.index
                    for d in range(delta):
                        self.buffer_[self.index] = numbers[d]
                        self.index += 1

                    if self.LED:
                        self.LED.on()
                    self.file_.write(self.buffer_)
                    if self.LED:
                        self.LED.off()
                    self.index = 0
                    for n in numbers[delta:]:
                        self.buffer_[self.index] = n
                        self.index += 1

                self.data = self.data[self.size_of_format:]

    def end(self, wait_ms = 0):
        if self.error:
            return None
        
        if wait_ms > 0:
            time.sleep_ms(wait_ms)

        amount = self.uart.any() 
        if amount > 0:
            self.data += self.uart.read(amount)

        while len(self.data) >= self.size_of_format:
            numbers = ustruct.unpack(self.format_,\
                                     self.data[:self.size_of_format])
            if self.index + self.data_points < BUFFER_SIZE:
                for n in numbers:
                    self.buffer_[self.index] = n
                    self.index += 1
            else:
                delta = BUFFER_SIZE - self.index
                for d in range(delta):
                    self.buffer_[self.index + d] = numbers[d]

                self.file_.write(self.buffer_)
                self.index = 0
                for n in numbers[delta:]:
                    self.buffer_[self.index] = n
                    self.index += 1

            self.data = self.data[self.size_of_format:]

        if self.index > 0:
            self.file_.write(self.buffer_[:self.index])

        if len(self.data) > 0:
            self.error = True

        self.file_.close()

and here's a main.py to run it

Code: Select all

import pyb
import data_logger

def main():
    log = data_logger.logger_Rx(6, 1, '/sd/data-set.bin', pyb.LED(4))

    pyb.LED(3).on()
    log.begin()
    log.end(5000)
    pyb.LED(3).off()

if __name__ == '__main__':
    main()

I have just run a measure and transmit for 8 minutes and got 900 results with a period of 111 micro secods. when I swapped pyboards around there were 800 of a short period, but it may have been a shorter run time i'm not monitoring the duration of experiment accurately.