jperkin / node-rpio

Raspberry Pi GPIO library for node.js
859 stars 126 forks source link

Issues with timing on poll #160

Open JesperNaarttijarvi opened 2 years ago

JesperNaarttijarvi commented 2 years ago

We're trying to go away from a dependent rich library, pigpio-client to RPIO for our Wiegand readers but are facing some problems with the polls. Below is a snapshot of the current code and old code. Also, output from both codes. We seem to have a problem getting reads on low inputs. Both programs are running under the same circumstances and trying to read a card. What are we doing incorrectly?

Code is quite simple, we register two listeners, one for RX and one for TX, and listen to the callbacks.

EDIT: removed unnecessary code for readablility. New code:

const rpio = require('rpio');
const start = new Date().getTime()

 wiegand.addWiegandListener = () => {
    wiegand.cbArgs.resetBinary = wiegand.resetBinary
    rpio.open(wiegand.tx, rpio.INPUT, rpio.PULL_UP);
    rpio.open(wiegand.rx, rpio.INPUT, rpio.PULL_UP);

    const cb = (pin) => {
      const level = rpio.read(pin)
      wiegand.wieCallback(pin, level)
    }

    rpio.poll(wiegand.tx, cb, rpio.POLL_LOW)
    rpio.poll(wiegand.rx, cb, rpio.POLL_LOW)
  }

  wiegand.watchPin = (pin, timeout) => {
    const localCb = () => {
      if (wiegand === undefined) {
        return
      }
      const level = rpio.read(pin)
      if (wiegand.level[pinNum] === level) {
        wiegand.wieCallback(pin, 3, null)
      }
    }
    let pinNum = 0
    if (pin === wiegand.rx) pinNum = 1

    if (wiegand.watching[pinNum]) {
      return
    }

    wiegand.watching[pinNum] = true
    wiegand.interval[pinNum] = setInterval(localCb, timeout);
  }

OLD CODE SNAPSHOT

  wiegand.addWiegandListener = () => {
    wiegand.cbArgs.resetBinary = wiegand.resetBinary

    const tx = wiegand.pigpio.gpio(wiegand.tx);
    const rx = wiegand.pigpio.gpio(wiegand.rx);

    tx.modeSet('input');
    rx.modeSet('input');

   // gpio.pullUpDown(pud, cb) pud=2: set pullup resistor, pud=1: set pulldown resistor, pud=0: clear resistor setting.
    tx.pullUpDown(2)
    rx.pullUpDown(2)

    tx.notify(wiegand.wieCallback.bind(null, wiegand.tx))
    rx.notify(wiegand.wieCallback.bind(null, wiegand.rx))
  }

  wiegand.watchPin = (pin, timeout) => {
    const localCallback = () => {
      if (wiegand === undefined) {
        return
      }
      gpio.read((_, level) => {
        if (wiegand.level[pinNum] === level) {
          wiegand.wieCallback(pin, 3, null)
        }
      })
    }
    let pinNum = 0
    if (pin === wiegand.rx) pinNum = 1

    if (wiegand.watching[pinNum]) {
      return
    }

    wiegand.watching[pinNum] = true

    const gpio = wiegand.pigpio.gpio(pin);

    wiegand.interval[pinNum] = setInterval(localCallback, timeout);
  }

COMMON CODE:

  wiegand.wieCallback = (pin, level, tick) => {
    if (wiegand === null) return
    console.group('wieCallback')
    console.log(`Pin: ${pin}, Level: ${level}`)
    console.log('TICK', tick)
    console.log('SINCE START', new Date().getTime() - start)
    console.groupEnd()

    let pinNum = 0
    if (pin === wiegand.rx) pinNum = 1

    wiegand.level[pinNum] = level

    //Accumulate bits until both gpios 0 and 1 timeout.

    // a falling edge indicates a new bit
    if (level === 0) {
      // First bit, start logging
      if (wiegand.inCode === undefined) {
        wiegand.bits = 1
        wiegand.num = 0

        wiegand.inCode = 1
        wiegand.watchPin(wiegand.tx, wiegand.pinTimeout)
        wiegand.watchPin(wiegand.rx, wiegand.pinTimeout)

      } else {
        wiegand.bits++
        wiegand.num <<= 1
      }

      if (pin === wiegand.tx) { // timeout gpio 14
        wiegand.txTimedout = false
      } else {
        wiegand.rxTimedout = false  // timeout gpio 15
        wiegand.num |= 1
      }

    } else if (level === 3) {
      if (wiegand.inCode !== undefined) {
        if (pin === wiegand.tx) { // timeout gpio 14
          wiegand.txTimedout = true
        } else {
          wiegand.rxTimedout = true // timeout gpio 15
        }

        if (wiegand.rxTimedout && wiegand.txTimedout) { // both gpios timed out
          wiegand.cbArgs.wiegand = wiegand
          if (wiegand.isFunction(wiegand.cb)) {
            wiegand.cb(wiegand.num, wiegand.bits, wiegand.cbArgs)
          }
        }
      }
    }
  }

  wiegand.addWiegandListener()

Output RPIO:

wieCallback Pin: 14, Level: 1 TICK undefined SINCE START 39 wieCallback Pin: 15, Level: 1 TICK undefined SINCE START 41 wieCallback Pin: 14, Level: 1 TICK undefined SINCE START 2140 wieCallback Pin: 14, Level: 1 TICK undefined SINCE START 2142 wieCallback Pin: 15, Level: 1 TICK undefined SINCE START 2146 wieCallback Pin: 14, Level: 1 TICK undefined SINCE START 2148 wieCallback Pin: 15, Level: 1 TICK undefined SINCE START 2149 wieCallback Pin: 14, Level: 1 TICK undefined SINCE START 2151 wieCallback Pin: 15, Level: 1 TICK undefined SINCE START 2152 wieCallback Pin: 14, Level: 1 TICK undefined SINCE START 2154 wieCallback Pin: 15, Level: 1 TICK undefined SINCE START 2155 wieCallback Pin: 14, Level: 1 TICK undefined SINCE START 2156 wieCallback Pin: 15, Level: 1 TICK undefined SINCE START 2157 wieCallback Pin: 14, Level: 1 TICK undefined SINCE START 2159 wieCallback Pin: 15, Level: 0 TICK undefined SINCE START 2160 wieCallback Pin: 14, Level: 1 TICK undefined SINCE START 2163 wieCallback Pin: 15, Level: 0 TICK undefined SINCE START 2164 wieCallback Pin: 14, Level: 1 TICK undefined SINCE START 2166 wieCallback Pin: 15, Level: 1 TICK undefined SINCE START 2167 wieCallback Pin: 15, Level: 1 TICK undefined SINCE START 2168 wieCallback Pin: 14, Level: 1 TICK undefined SINCE START 2170 wieCallback Pin: 15, Level: 1 TICK undefined SINCE START 2171 wieCallback Pin: 14, Level: 1 TICK undefined SINCE START 2174 wieCallback Pin: 14, Level: 3 TICK null SINCE START 2214 wieCallback Pin: 15, Level: 3 TICK null SINCE START 2217 checker [INFO] (0): new card: 3 | bits: 2 checker [INFO] (1): user not found for Card: 3 wieCallback Pin: 14, Level: 1 TICK undefined SINCE START 5576 wieCallback Pin: 14, Level: 1 TICK undefined SINCE START 5578 wieCallback Pin: 15, Level: 1 TICK undefined SINCE START 5581 wieCallback Pin: 14, Level: 1 TICK undefined SINCE START 5583 wieCallback Pin: 15, Level: 1 TICK undefined SINCE START 5585 wieCallback Pin: 14, Level: 1 TICK undefined SINCE START 5588 wieCallback Pin: 15, Level: 1 TICK undefined SINCE START 5590 wieCallback Pin: 14, Level: 1 TICK undefined SINCE START 5592 wieCallback Pin: 15, Level: 1 TICK undefined SINCE START 5594 wieCallback Pin: 14, Level: 1 TICK undefined SINCE START 5597 wieCallback Pin: 15, Level: 1 TICK undefined SINCE START 5599 wieCallback Pin: 14, Level: 1 TICK undefined SINCE START 5601 wieCallback Pin: 15, Level: 1 TICK undefined SINCE START 5603 wieCallback Pin: 14, Level: 1 TICK undefined SINCE START 5606 wieCallback Pin: 15, Level: 1 TICK undefined SINCE START 5608 wieCallback Pin: 14, Level: 1 TICK undefined SINCE START 9007 wieCallback Pin: 14, Level: 1 TICK undefined SINCE START 9009 wieCallback Pin: 15, Level: 1 TICK undefined SINCE START 9012 wieCallback Pin: 14, Level: 1 TICK undefined SINCE START 9013 wieCallback Pin: 15, Level: 1 TICK undefined SINCE START 9015 wieCallback Pin: 14, Level: 1 TICK undefined SINCE START 9016 wieCallback Pin: 15, Level: 1 TICK undefined SINCE START 9018 wieCallback Pin: 14, Level: 1 TICK undefined SINCE START 9020 wieCallback Pin: 15, Level: 1 TICK undefined SINCE START 9021 wieCallback Pin: 14, Level: 1 TICK undefined SINCE START 9023 wieCallback Pin: 15, Level: 1 TICK undefined SINCE START 9024 wieCallback Pin: 14, Level: 1 TICK undefined SINCE START 9026 wieCallback Pin: 15, Level: 1 TICK undefined SINCE START 9027 wieCallback Pin: 14, Level: 1 TICK undefined SINCE START 9029 wieCallback Pin: 15, Level: 1 TICK undefined SINCE START 9030 wieCallback Pin: 14, Level: 1 TICK undefined SINCE START 9031 wieCallback Pin: 15, Level: 1 TICK undefined SINCE START 9033 wieCallback Pin: 14, Level: 1 TICK undefined SINCE START 9034 wieCallback Pin: 15, Level: 1 TICK undefined SINCE START 9036 wieCallback Pin: 14, Level: 0 TICK undefined SINCE START 9037 wieCallback Pin: 15, Level: 1 TICK undefined SINCE START 9039 wieCallback Pin: 14, Level: 1 TICK undefined SINCE START 9041 wieCallback Pin: 14, Level: 3 TICK null SINCE START 9089 wieCallback Pin: 15, Level: 3 TICK null SINCE START 9091 checker [INFO] (2): new card: 0 | bits: 1 checker [INFO] (3): OK USER for Card: 0 reader [INFO] (0): Door was unlocked, leaving it. */

Output pigpio: /* wieCallback Pin: 14, Level: 0 TICK 375151076 SINCE START 1574 wieCallback Pin: 14, Level: 1 TICK 375151161 SINCE START 1579 wieCallback Pin: 15, Level: 0 TICK 375152076 SINCE START 1582 wieCallback Pin: 15, Level: 1 TICK 375152167 SINCE START 1584 wieCallback Pin: 14, Level: 0 TICK 375153081 SINCE START 1587 wieCallback Pin: 14, Level: 1 TICK 375153167 SINCE START 1591 wieCallback Pin: 14, Level: 0 TICK 375154086 SINCE START 1592 wieCallback Pin: 14, Level: 1 TICK 375154171 SINCE START 1593 wieCallback Pin: 15, Level: 0 TICK 375155091 SINCE START 1595 wieCallback Pin: 15, Level: 1 TICK 375155176 SINCE START 1596 wieCallback Pin: 14, Level: 0 TICK 375156091 SINCE START 1597 wieCallback Pin: 14, Level: 1 TICK 375156181 SINCE START 1598 wieCallback Pin: 15, Level: 0 TICK 375157096 SINCE START 1601 wieCallback Pin: 15, Level: 1 TICK 375157181 SINCE START 1602 wieCallback Pin: 14, Level: 0 TICK 375158102 SINCE START 1603 wieCallback Pin: 14, Level: 1 TICK 375158187 SINCE START 1604 wieCallback Pin: 14, Level: 0 TICK 375159106 SINCE START 1605 wieCallback Pin: 14, Level: 1 TICK 375159191 SINCE START 1606 wieCallback Pin: 14, Level: 0 TICK 375160107 SINCE START 1607 wieCallback Pin: 14, Level: 1 TICK 375160197 SINCE START 1608 wieCallback Pin: 14, Level: 0 TICK 375161111 SINCE START 1610 wieCallback Pin: 14, Level: 1 TICK 375161196 SINCE START 1612 wieCallback Pin: 15, Level: 0 TICK 375162116 SINCE START 1613 wieCallback Pin: 15, Level: 1 TICK 375162201 SINCE START 1614 wieCallback Pin: 14, Level: 0 TICK 375163122 SINCE START 1620 wieCallback Pin: 14, Level: 1 TICK 375163202 SINCE START 1621 wieCallback Pin: 15, Level: 0 TICK 375164121 SINCE START 1622 wieCallback Pin: 15, Level: 1 TICK 375164206 SINCE START 1623 wieCallback Pin: 15, Level: 0 TICK 375165127 SINCE START 1624 wieCallback Pin: 15, Level: 1 TICK 375165212 SINCE START 1625 wieCallback Pin: 15, Level: 0 TICK 375166131 SINCE START 1626 wieCallback Pin: 15, Level: 1 TICK 375166216 SINCE START 1627 wieCallback Pin: 14, Level: 0 TICK 375167136 SINCE START 1629 wieCallback Pin: 14, Level: 1 TICK 375167221 SINCE START 1630 wieCallback Pin: 14, Level: 0 TICK 375168137 SINCE START 1631 wieCallback Pin: 14, Level: 1 TICK 375168222 SINCE START 1632 wieCallback Pin: 14, Level: 0 TICK 375169141 SINCE START 1634 wieCallback Pin: 14, Level: 1 TICK 375169226 SINCE START 1635 wieCallback Pin: 15, Level: 0 TICK 375170146 SINCE START 1636 wieCallback Pin: 15, Level: 1 TICK 375170232 SINCE START 1637 wieCallback Pin: 15, Level: 0 TICK 375171146 SINCE START 1644 wieCallback Pin: 15, Level: 1 TICK 375171238 SINCE START 1645 wieCallback Pin: 15, Level: 0 TICK 375172151 SINCE START 1646 wieCallback Pin: 15, Level: 1 TICK 375172236 SINCE START 1646 wieCallback Pin: 14, Level: 0 TICK 375173157 SINCE START 1647 wieCallback Pin: 14, Level: 1 TICK 375173242 SINCE START 1648 wieCallback Pin: 14, Level: 0 TICK 375174162 SINCE START 1648 wieCallback Pin: 14, Level: 1 TICK 375174246 SINCE START 1649 wieCallback Pin: 15, Level: 0 TICK 375175168 SINCE START 1650 wieCallback Pin: 15, Level: 1 TICK 375175247 SINCE START 1650 wieCallback Pin: 15, Level: 0 TICK 375176167 SINCE START 1651 wieCallback Pin: 15, Level: 1 TICK 375176251 SINCE START 1652 wieCallback Pin: 14, Level: 0 TICK 375177172 SINCE START 1652 wieCallback Pin: 14, Level: 1 TICK 375177256 SINCE START 1653 wieCallback Pin: 15, Level: 0 TICK 375178177 SINCE START 1654 wieCallback Pin: 15, Level: 1 TICK 375178262 SINCE START 1654 wieCallback Pin: 15, Level: 0 TICK 375179176 SINCE START 1655 wieCallback Pin: 15, Level: 1 TICK 375179261 SINCE START 1656 wieCallback Pin: 15, Level: 0 TICK 375180181 SINCE START 1656 wieCallback Pin: 15, Level: 1 TICK 375180266 SINCE START 1657 wieCallback Pin: 14, Level: 0 TICK 375181186 SINCE START 1658 wieCallback Pin: 14, Level: 1 TICK 375181271 SINCE START 1659 wieCallback Pin: 14, Level: 0 TICK 375182191 SINCE START 1660 wieCallback Pin: 14, Level: 1 TICK 375182276 SINCE START 1661 wieCallback Pin: 14, Level: 3 TICK null SINCE START 1665 wieCallback Pin: 15, Level: 3 TICK null SINCE START 1667 checker [INFO] (0): new card: 1243028700 | bits: 32 checker [INFO] (1): user not found for Card: 1243028700 wieCallback Pin: 14, Level: 0 TICK 378584400 SINCE START 5004 wieCallback Pin: 14, Level: 1 TICK 378584485 SINCE START 5007 wieCallback Pin: 15, Level: 0 TICK 378585400 SINCE START 5010 wieCallback Pin: 15, Level: 1 TICK 378585485 SINCE START 5012 wieCallback Pin: 14, Level: 0 TICK 378586405 SINCE START 5013 wieCallback Pin: 14, Level: 1 TICK 378586490 SINCE START 5015 wieCallback Pin: 14, Level: 0 TICK 378587410 SINCE START 5017 wieCallback Pin: 14, Level: 1 TICK 378587495 SINCE START 5018 wieCallback Pin: 15, Level: 0 TICK 378588410 SINCE START 5020 wieCallback Pin: 15, Level: 1 TICK 378588500 SINCE START 5021 wieCallback Pin: 14, Level: 0 TICK 378589415 SINCE START 5023 wieCallback Pin: 14, Level: 1 TICK 378589500 SINCE START 5024 wieCallback Pin: 15, Level: 0 TICK 378590420 SINCE START 5026 wieCallback Pin: 15, Level: 1 TICK 378590505 SINCE START 5027 wieCallback Pin: 14, Level: 0 TICK 378591425 SINCE START 5030 wieCallback Pin: 14, Level: 1 TICK 378591510 SINCE START 5031 wieCallback Pin: 14, Level: 0 TICK 378592430 SINCE START 5033 wieCallback Pin: 14, Level: 1 TICK 378592515 SINCE START 5034 wieCallback Pin: 14, Level: 0 TICK 378593430 SINCE START 5035 wieCallback Pin: 14, Level: 1 TICK 378593515 SINCE START 5037 wieCallback Pin: 14, Level: 0 TICK 378594435 SINCE START 5038 wieCallback Pin: 14, Level: 1 TICK 378594520 SINCE START 5039 wieCallback Pin: 15, Level: 0 TICK 378595440 SINCE START 5041 wieCallback Pin: 15, Level: 1 TICK 378595525 SINCE START 5042 wieCallback Pin: 14, Level: 0 TICK 378596440 SINCE START 5043 wieCallback Pin: 14, Level: 1 TICK 378596525 SINCE START 5045 wieCallback Pin: 15, Level: 0 TICK 378597445 SINCE START 5046 wieCallback Pin: 15, Level: 1 TICK 378597530 SINCE START 5047 wieCallback Pin: 15, Level: 0 TICK 378598450 SINCE START 5049 wieCallback Pin: 15, Level: 1 TICK 378598535 SINCE START 5050 wieCallback Pin: 15, Level: 0 TICK 378599455 SINCE START 5051 wieCallback Pin: 15, Level: 1 TICK 378599541 SINCE START 5053 wieCallback Pin: 14, Level: 0 TICK 378600460 SINCE START 5054 wieCallback Pin: 14, Level: 1 TICK 378600540 SINCE START 5055 wieCallback Pin: 14, Level: 0 TICK 378601460 SINCE START 5057 wieCallback Pin: 14, Level: 1 TICK 378601545 SINCE START 5058 wieCallback Pin: 14, Level: 0 TICK 378602465 SINCE START 5059 wieCallback Pin: 14, Level: 1 TICK 378602550 SINCE START 5061 wieCallback Pin: 15, Level: 0 TICK 378603470 SINCE START 5062 wieCallback Pin: 15, Level: 1 TICK 378603555 SINCE START 5063 wieCallback Pin: 15, Level: 0 TICK 378604470 SINCE START 5065 wieCallback Pin: 15, Level: 1 TICK 378604560 SINCE START 5066 wieCallback Pin: 15, Level: 0 TICK 378605475 SINCE START 5067 wieCallback Pin: 15, Level: 1 TICK 378605560 SINCE START 5069 wieCallback Pin: 14, Level: 0 TICK 378606480 SINCE START 5072 wieCallback Pin: 14, Level: 1 TICK 378606565 SINCE START 5074 wieCallback Pin: 14, Level: 0 TICK 378607485 SINCE START 5075 wieCallback Pin: 14, Level: 1 TICK 378607570 SINCE START 5076 wieCallback Pin: 15, Level: 0 TICK 378608485 SINCE START 5078 wieCallback Pin: 15, Level: 1 TICK 378608575 SINCE START 5079 wieCallback Pin: 15, Level: 0 TICK 378609490 SINCE START 5080 wieCallback Pin: 15, Level: 1 TICK 378609575 SINCE START 5082 wieCallback Pin: 14, Level: 0 TICK 378610495 SINCE START 5083 wieCallback Pin: 14, Level: 1 TICK 378610580 SINCE START 5084 wieCallback Pin: 14, Level: 3 TICK null SINCE START 5087 wieCallback Pin: 15, Level: 0 TICK 378611500 SINCE START 5089 wieCallback Pin: 15, Level: 1 TICK 378611585 SINCE START 5091 wieCallback Pin: 15, Level: 0 TICK 378612500 SINCE START 5092 wieCallback Pin: 15, Level: 1 TICK 378612590 SINCE START 5093 wieCallback Pin: 15, Level: 0 TICK 378613505 SINCE START 5095 wieCallback Pin: 15, Level: 1 TICK 378613590 SINCE START 5096 wieCallback Pin: 14, Level: 0 TICK 378614510 SINCE START 5097 wieCallback Pin: 14, Level: 1 TICK 378614597 SINCE START 5099 wieCallback Pin: 14, Level: 0 TICK 378615510 SINCE START 5100 wieCallback Pin: 14, Level: 1 TICK 378615600 SINCE START 5101 wieCallback Pin: 15, Level: 3 TICK null SINCE START 5104 wieCallback Pin: 14, Level: 3 TICK null SINCE START 5122 checker [INFO] (2): new card: 1243028700 | bits: 32 checker [INFO] (3): user not found for Card: 1243028700

*/

fishbone1 commented 5 months ago

I also have issues implementing a receiver for Wiegand messages with this library.

I identified two problems:

1: Sometimes we receive too many bits. I don't know how this could happen at all. My assumption is that the library's C code clears the event flag too quickly after reading it in function gpio_event_poll

    if ((rval = bcm2835_gpio_eds_multi(mask))) {
        bcm2835_gpio_set_eds_multi(rval);
    }

So maybe the same event is read again. Or the the Wiegand interface's sent signal is somehow unstable and contains multiple falling edges. For me, it makes more sense to clear the flag after my poll callback has been called. I patched my version of node-rpio to call bcm2835_gpio_set_eds_multi after the callback calls:

function event_poll()
{
    var active = bindcall(binding.gpio_event_poll, event_mask);

    for (gpiopin in event_pins) {
        if (active & (1 << gpiopin)) {
            module.exports.emit('pin' + gpiopin);
        }
    }

        // Patch here:
    bindcall(binding.gpio_clear_poll_event_flag, active);
}

I had to export the C function in rpio.cc:

NAN_MODULE_INIT(setup)
{
    NAN_EXPORT(target, gpio_clear_poll_event_flag);
//...

NAN_METHOD(gpio_clear_poll_event_flag)
{
    ASSERT_ARGC1(IS_U32);

    uint32_t mask = FROM_U32(0);

    bcm2835_gpio_set_eds_multi(mask);
}

and recompile it:

npm install node-gyp
cd node_modules/rpio
../.bin/node-gyp rebuild
cd ../..

and the result is a huge improvement.

Problem 2 is that some bits are missing sometimes, but surprisingly it happens not that often as problem 1. The reason is probably that JS is too slow. If I see your time measurements, then the callbacks sometimes take more than 3ms. This means that two signals have been sent in the meantime.

JS is probably not a good environment for such tasks. An idea to fix this is to move the polling code completely to C (maybe in a separate thread) and call a JS callback from there.

fishbone1 commented 5 months ago

I came to the conclusion that the node-rpio module and the bcm2835 C-library on which it's based, simply just don't fit for this case. You need a library / module that relies on GPIO interrupts. This module not only doesn't use interrupts, it requires you to disable them at all.

This article makes it even more clear.

I ported everything to C and have similar issues, even though it's much faster. You have to ensure exact timing in order not to miss bits or receive extra bits. I need 1ms delay between polling which leads to noticable increase of CPU load.