search

joan2937 / pigpio

pigpio is a C library for the Raspberry which allows control of the General Purpose Input Outputs (GPIO).
The Unlicense
1.45k stars 409 forks source link

wave_send_repeat() does double the delay time of pulses #331

Open hayguen opened 4 years ago

hayguen commented 4 years ago

Hello, i'm recording a bunch of pulses and re-playing them quite similar to the example http://abyz.me.uk/rpi/pigpio/python.html#wave_add_generic

my application records the remote control's signal for a power switch (or any other 433 MHZ OOK device) .. and replays the recorded signal later, e.g. to allow sort of home automization. see https://github.com/hayguen/rc433_rpi and https://github.com/hayguen/rc433_rpi/blob/master/tx_csv.py

using python3 and wave_send_repeat() failed to control the power switch at first attempt. i thought, that the timing is not accurate enough, that i've written https://github.com/hayguen/rc433_rpi/blob/master/tx_csv_pigpio.c this worked - even using busy loops.

now, having recorded the transmitted signal of tx_csv.py with an RTLSDR, i realized that all pulse delays were doubled on air! thus, halving all delay values (see ~line 50 in tx_csv.py) does work and switch the power.

i've tested with Raspberry Pi 3B+ and the latest Raspbian (2020-02-14) with the pigpio package containing version 71 and latest github master with version v74.

later (next days), i could test with a Raspberry Pi 1 and a 4B.

i tried to have a look into the sources .. but i could not understand. i'm missing an explanation how gpioWaveTxSend() works with DMA stuff. Especially how is DMA utilized to produce the delays?

however, if / when there's a bugfix, how can i determine in python if i should halve the delays - or not?

kind regards, hayati

joan2937 commented 4 years ago

Could you please prepare a short Python script which demonstrates this problem?

E.g. a script which is meant to generate pulses of 100 µs but actually results in pulses of 200 µs.

hayguen commented 4 years ago

try following script .. and connect RXPIN with TXPIN:

#!/usr/bin/env python3

import sys
import time
import pigpio
import numpy as np

# connect these two pins for testing
TXPIN = 17
RXPIN = 27
# transmit / expect pin/level change every DELAYUS us
DELAYUS = 200
SLEEP_SECS = 0.2   # wait/sleep while transmitting

bufused = 0
bufmax = 64   # rec max 32 pin changes
bufLevel = np.zeros( bufmax, dtype = np.dtype('uint8') )
bufTime  = np.zeros( bufmax, dtype = np.dtype('uint32') )

def cbf(gpio, level, tick):
    global bufused, bufmax, bufTime, bufLevel
    # just save incoming data, to be as fast as possible
    if RXPIN == gpio and bufused < bufmax:
        bufTime[bufused] = tick
        bufLevel[bufused] = level
        bufused = bufused + 1

p = pigpio.pi()
print("pigpio version: ", p.get_pigpio_version())

p.set_mode(TXPIN, pigpio.OUTPUT)
p.write(TXPIN, 0)
p.set_mode(RXPIN, pigpio.INPUT)
p.set_pull_up_down(RXPIN, pigpio.PUD_DOWN)
cb = p.callback(RXPIN, pigpio.EITHER_EDGE, cbf)

pulseTrain=[]
pinMask = 1 << TXPIN
for k in range(10):
  pulseTrain.append(pigpio.pulse(pinMask, 0, DELAYUS))
  pulseTrain.append(pigpio.pulse(0, pinMask, DELAYUS))

p.wave_clear() # clear any existing waveforms
p.wave_add_generic(pulseTrain)
pT = p.wave_create()
# => same result for wave_send_repeat() or wave_send_once()
print("transmitting ..")
p.wave_send_repeat(pT)
#p.wave_send_once(pT)
time.sleep(0.2)
p.wave_tx_stop() # stop waveform
print(".. stopped")

p.wave_clear()
time.sleep(SLEEP_SECS)
p.write(TXPIN, 0)

for k in range(1, bufused):
  deltaT = 0
  if k > 0:
    deltaT = pigpio.tickDiff(bufTime[k-1], bufTime[k])
  newLevel = bufLevel[k]
  print("{}: measured delta {} us, level {} => delay factor {}".format(k, deltaT, newLevel, deltaT / DELAYUS))

i get following output with 400 us between each pin change, where it should be DELAYUS = 200 us:

pi@raspberrypi:~/rc433_rpi $ ./testDelay.py
pigpio version:  74
transmitting ..
.. stopped
1: measured delta 400 us, level 0 => delay factor 2.0
2: measured delta 400 us, level 1 => delay factor 2.0
3: measured delta 400 us, level 0 => delay factor 2.0
4: measured delta 400 us, level 1 => delay factor 2.0
5: measured delta 400 us, level 0 => delay factor 2.0
6: measured delta 400 us, level 1 => delay factor 2.0
7: measured delta 400 us, level 0 => delay factor 2.0
8: measured delta 400 us, level 1 => delay factor 2.0
9: measured delta 400 us, level 0 => delay factor 2.0
10: measured delta 400 us, level 1 => delay factor 2.0
11: measured delta 400 us, level 0 => delay factor 2.0

by the way: the receive timings are really accurate, i had not expected.

hayguen commented 4 years ago

above (doubled delay) result was on Raspberry Pi 3B+ with latest Raspbian.

for completeness, here it's pinout chip infos:

Revision           : a020d3
SoC                : BCM2837
RAM                : 1024Mb
Storage            : MicroSD
USB ports          : 4 (excluding power)
Ethernet ports     : 1
Wi-fi              : True
Bluetooth          : True
Camera ports (CSI) : 1
Display ports (DSI): 1

same SD-card on Raspberry Pi 1B (of a friend) produced quite similar results, doubling the delay:

only the measured delay jittered up to 5 us - think, that is quite ok. here the chip info of pinout:

Revision           : 000f
SoC                : BCM2835
RAM                : 512Mb
Storage            : SD
USB ports          : 2 (excluding power)
Ethernet ports     : 1
Wi-fi              : False
Bluetooth          : False
Camera ports (CSI) : 1
Display ports (DSI): 1

Interestingly on a Raspberry Pi 4B with following pinout infos:

Revision           : b03111
SoC                : BCM2711
RAM                : 2048Mb
Storage            : MicroSD
USB ports          : 4 (excluding power)
Ethernet ports     : 1
Wi-fi              : True
Bluetooth          : True
Camera ports (CSI) : 1
Display ports (DSI): 1

there is NO error:

pigpio version:  74
transmitting ..
.. stopped
1: measured delta 200 us, level 0 => delay factor 1.0
2: measured delta 200 us, level 1 => delay factor 1.0
3: measured delta 200 us, level 0 => delay factor 1.0
4: measured delta 200 us, level 1 => delay factor 1.0
5: measured delta 200 us, level 0 => delay factor 1.0
6: measured delta 200 us, level 1 => delay factor 1.0
7: measured delta 200 us, level 0 => delay factor 1.0
8: measured delta 200 us, level 1 => delay factor 1.0
9: measured delta 200 us, level 0 => delay factor 1.0
10: measured delta 200 us, level 1 => delay factor 1.0
11: measured delta 200 us, level 0 => delay factor 1.0
joan2937 commented 4 years ago

Unfortunately it works as expected on my Pi3B+.

./issue.py 
pigpio version:  74
transmitting ..
.. stopped
1: measured delta 200 us, level 0 => delay factor 1.0
2: measured delta 200 us, level 1 => delay factor 1.0
3: measured delta 200 us, level 0 => delay factor 1.0
4: measured delta 200 us, level 1 => delay factor 1.0
5: measured delta 200 us, level 0 => delay factor 1.0
6: measured delta 200 us, level 1 => delay factor 1.0
7: measured delta 200 us, level 0 => delay factor 1.0
8: measured delta 200 us, level 1 => delay factor 1.0
9: measured delta 200 us, level 0 => delay factor 1.0
10: measured delta 200 us, level 1 => delay factor 1.0
11: measured delta 200 us, level 0 => delay factor 1.0
12: measured delta 200 us, level 1 => delay factor 1.0
13: measured delta 200 us, level 0 => delay factor 1.0
14: measured delta 200 us, level 1 => delay factor 1.0
...
Hardware    : BCM2835
Revision    : a020d3
Serial      : 0000000066a17c79
Model       : Raspberry Pi 3 Model B Plus Rev 1.3
guymcswain commented 4 years ago

Interesting. Have you looked at the signal with oscilloscope and is it clean? I'm curious as to why you set the pulldown.

joan2937 commented 4 years ago

There is a timing problem on some Pis which has never been tracked down. This may be another example of the same problem.

guymcswain commented 4 years ago

@joan2937 , is the timing issue you're referring to the one associated with have a monitor/display attached? I seem to recall something of that nature.

hayguen commented 4 years ago

from cat /proc/cpuinfo i get exactly same as you:

Hardware        : BCM2835
Revision        : a020d3
Serial          : 00000000ee3a9c68
Model           : Raspberry Pi 3 Model B Plus Rev 1.3

changing to PUD_OFF gives same doubled delay on my Pi 3B+.

i don't have an oscilloscope here at home :-( i could try on one more Pi 3B+ .. but i would like to remind, that i have the doubled delay also on a Pi 1.

any idea, how we could track this down? how can i assist?

hayguen commented 4 years ago

@joan2937 , is the timing issue you're referring to the one associated with have a monitor/display attached? I seem to recall something of that nature.

i have doubled delay on Pi 3B+ with display connected (working with screen/keyboard) but also when working headless over ssh: same double delay.

previous test on Pi 4B was headless. would need to look for a display adapter ..

joan2937 commented 4 years ago

@guymcswain That sounds right. It was never resolved. Nobody ever discovered a pattern as to which Pis were affected or why.

hayguen commented 4 years ago

tested on the another Pi 3B+: timing looks GOOD, delay factor is 1.

it's exactly same model (pinout command is in package python3-gpiozero !?!):

Revision           : a020d3
SoC                : BCM2837
RAM                : 1024Mb

cat /proc/cpuinfo delivers:

Hardware        : BCM2835
Revision        : a020d3
Serial          : 000000001fd6c90c
Model           : Raspberry Pi 3 Model B Plus Rev 1.3
joan2937 commented 4 years ago

@hayguen Were you using the same SD card and PSU on the working and non-working Pi3B+ ?

hayguen commented 4 years ago

2nd Pi 3B+: it was/still is different SD-card. PSU was just same model .. and now is exactly same PSU device. WiFi is configured on this SD card. always getting good results with this one.

now changed the SD-card for 2nd Pi 3B+ .. and have to connect Ethernet: whoooo. now i get the doubled delay!!!

removed Ethernet, configured WiFi on 2nd Pi 3B+: again: doubled delay.

guymcswain commented 4 years ago

@hayguen , prior to your initial testing, did you run the pigpio's test suite - x_pigpio.c et al? If not, can you run them and report the results.

joan2937 commented 4 years ago

Okay. I have downloaded and burnt the image.

My initial tests seem to be seeing the same as you, i.e. the waveforms are twice as long as expected.

For my test I did the following after logging in to the image.

sudo pigpiod
pigs m 4 w
pigs wvag 16 0 100 0 16 100
pigs wvcre
pigs wvtxr 0

That should have resulted in a continuous square wave of 100µs on and 100µs off.

Instead I see a square wave of 200µs on and 200µs off (using piscope).

It's good that we can replicate the problem.

That said I am busy at the moment and need to prioritise tasks needed for @guymcswain so can't be sure when I will be able to investigate.

hayguen commented 4 years ago

@hayguen , prior to your initial testing, did you run the pigpio's test suite - x_pigpio.c et al? If not, can you run them and report the results.

i had not executed the test suite before - even wasn't aware of it. here results of x_pigpio:

TEST  5.4  FAILED got 25 (callback: 50)
TEST  5.11 FAILED got 10 (wave tx busy, serial read: 0)

this happended 3 times on gpio25. then, i changed the pin to gpio8 and gpio7: same results

joan2937 commented 4 years ago

@hayguen Could you start the pigpio daemon with the -t0 option and see if that works okay.

sudo pigpiod -t0

hayguen commented 4 years ago

some more tests / insight:

setting hdmi_safe=1 in /boot/config.txt

activating the comment in /boot/config.txt, thus removing hdmi_safe

before having played with hdmi_safe

by default hdmi_safe was commented in /boot/config.txt and the error occured independent of display connected - or not

hayguen commented 4 years ago

@hayguen Could you start the pigpio daemon with the -t0 option and see if that works okay.

sudo pigpiod -t0

that is quite quite interesting!

-t value, clock peripheral, 0=PWM 1=PCM, default PCM hmmm, now i remember, that i also played with the audio setting with sudo raspi-config usually, i set 'force 3.5mm jack' .. what might have provoked the error

hayguen commented 4 years ago

let me ask, what are the implications for using PWM or PCM clock? on what criterions, to make a choice as end user or even programmer, regarding pigpio as a black box? think, we need some more documentation on this.

setting audio to 'always 3.5mm' with sudo raspi-config, i get the delay error with display connected - or not, when starting gpiod without any options.

i'd suggest:

  1. change the gpiod default clock to PWM, if it does not break something?!
  2. print a warning, when setting PCM clock, that it could interfere with soundcard's 3.5mm output
joan2937 commented 4 years ago

http://abyz.me.uk/rpi/pigpio/faq.html#Sound_isnt_working

guymcswain commented 4 years ago

@hayguen , pigpio has a wide user base and has been in existence for several years so changing default config is out of the question. But I could see value in coming up with a test that could determine if the alternate clock peripheral should be used. Since you have invested some time on this issue would you be interested in supporting the development of such a test?

I should add that there is already documentation in place. Selecting the alternate as default will create the need to document the cases that break under that scenario. This is why I suggest a test.

hayguen commented 4 years ago

Yes, I'd like to help.

hayguen commented 4 years ago

http://abyz.me.uk/rpi/pigpio/faq.html#Sound_isnt_working

let me notice, that i had no speakers connected at any time

guymcswain commented 4 years ago

Off the top of my head, using the C library one could generate pulses for timing measurement and switch between the two clock sources. If you want to help I'll accept a PR. Maybe it could be a part of x_pigpio.c

hayguen commented 4 years ago

x_pigpio requires that pin GPIO25 is unconnected or open. Suppose, this is why the tests are not automatically executed with every build / make.

the (python) test program (from above) requires having connected 2 pins.

however, both test programs have the problem, that they are executed only once in lifetime and usually not again. thus, end users would not realize the problem :-( in addition, we know, that the problem depends on sound output configuration and/or connection of display, what might change over time - possibly even at runtime!?

i would prefer something, to run at every start of pigpiod - without any requirements. can we check the audio output configuration somehow? can we check the clock settings somehow? what piece of OS kernel / sound driver does reconfigure the PCM clock? however, can someone point me to some reference documentation? give me a starting point?

guymcswain commented 4 years ago

Just looking for something simple that users can run when the question comes up. I don't want to support anything complex nor try to protect against anything a user might do to his system.

joan2937 commented 4 years ago

Perhaps something like the following. It should print 1.00 for no problem

#!/usr/bin/env python

import time
import pigpio

GPIO=4
MICROS=1000

pi = pigpio.pi()
if not pi.connected:
   exit()

pi.set_mode(GPIO, pigpio.OUTPUT)

pi.wave_add_generic(
   [pigpio.pulse(1<<GPIO,       0, MICROS), 
    pigpio.pulse(      0, 1<<GPIO, MICROS)])
wid = pi.wave_create()
if wid >= 0:
   start = time.time()
   pi.wave_chain([255, 0, wid, 255, 1, 200, 0]) # send wave 200 times
   while pi.wave_tx_busy():
      time.sleep(0.001)
   duration = time.time() - start
   pi.wave_delete(wid)
pi.stop()

EXPECTED_SECS = 400.0 * MICROS / 1000000.0

ratio = duration / EXPECTED_SECS

print("{:.2f}".format(ratio))
guymcswain commented 4 years ago

@joan2937 , yes this is along the line I'm thinking about. However, if the result is negative, can the test verify success when the alternate clock is selected. I don't think that can be done via pigpiod client

hayguen commented 4 years ago

i had a similar idea, but did go one step further: it looks, there is no need to write to any pin, making it possible to test the clock even inside pigpiod.

following script works fine, to detect the erroneous timing - or not, tested on Pi3B+ with different sound settings and different display connections:

#!/usr/bin/env python3
import time
import pigpio

DELAYUS = 500

p = pigpio.pi()
print("pigpio version: ", p.get_pigpio_version())

pulseTrain=[ pigpio.pulse(0, 0, DELAYUS), pulseTrain.append(pigpio.pulse(0, 0, DELAYUS) ]

p.wave_clear()
p.wave_add_generic(pulseTrain)
pT = p.wave_create()

p.wave_send_once(pT)
t1 = p.get_current_tick()
while p.wave_tx_busy():
  pass
t2 = p.get_current_tick()

p.wave_clear()
deltaT = pigpio.tickDiff(t1, t2)
ratio = deltaT / (2*DELAYUS)
print("passed time: {} us, expected {} us => ratio {}".format(deltaT, 2*DELAYUS, ratio))

increasing the test duration (above, only 1 ms), the determined ratio gets more accurate. i'm just unsure for the busy loop and what the multitasking OS will do .. with a higher test duration and accepting some inaccuracy, we could use normal sleeps, similar to Joan's variant.

it also looks, that timing does only change on (re)boot - and happily not at runtime. having 'auto' setting for sound, booting with display has good timing, which stays good when removing the display. but no idea, what sound output did meanwhile .. however.

i'm working on a C version testing both clocks .. and want to test on Pi 1. you can await test results and C version this evening or tomorrow.

hayguen commented 4 years ago

here's the standalone test program:

#include <stdio.h>
#include <stdlib.h>
#include <string.h>

#include <pigpio.h>

#define DELAY_US 25000

int main(int argc, char *argv[])
{
  gpioPulse_t pulse[2];
  uint32_t t0, t1, diffTick, expectedDelta;
  int k, ret, wave_id, testClock;
  float ratio;
  unsigned cfgMicros, cfgPeripheral;

  testClock = -1;  /* -1: test both configurations; 0: test PWM; 1: test PCM */

  if ( 1 < argc ) {
    if (!strcmp(argv[1], "pcm"))
      testClock = 1;
    else if (!strcmp(argv[1], "pwm"))
      testClock = 0;
    else
      testClock = atoi(argv[1]);
    if (testClock)
      testClock = 1;
  }

  for ( cfgPeripheral = 0; cfgPeripheral < 2; ++cfgPeripheral ) {
    if ( !( testClock == -1 || testClock == cfgPeripheral ) )
      continue;

    cfgMicros = 5;
    fprintf(stdout, "testing %s clock\n", (cfgPeripheral ? "PCM" : "PWM") );

    gpioCfgClock(cfgMicros, cfgPeripheral, 0);
    if (gpioInitialise() < 0)
    {
      fprintf(stderr, "pigpio initialisation failed.\n");
      return (cfgPeripheral+1)*10;
    }

    for ( k = 0; k < 2; ++k ) {
      pulse[k].gpioOn = 0;
      pulse[k].gpioOff = 0;
      pulse[k].usDelay = DELAY_US;
    }

    ret = gpioWaveAddNew();
    if (ret) {
      fprintf(stderr, "error at gpioWaveAddNew()\n");
      return 1;
    }
    ret = gpioWaveAddGeneric(2, pulse);
    if (ret != 2) {
      fprintf(stderr, "error at gpioWaveAddGeneric()\n");
      return 2;
    }
    wave_id = gpioWaveCreate();
    if (wave_id < 0) {
      fprintf(stderr, "error at gpioWaveCreate()\n");
      return 3;
    }

    ret = gpioWaveTxSend(wave_id, PI_WAVE_MODE_ONE_SHOT );
    t0 = gpioTick();
    if (ret <= 0) {
      fprintf(stderr, "error at gpioWaveTxSend()\n");
      return 4;
    }

    while ( gpioWaveTxBusy() ) {
      gpioDelay(500);
    }
    t1 = gpioTick();

    /*gpioWaveTxStop();*/
    gpioWaveClear();
    gpioTerminate();

    diffTick = t1 - t0;
    expectedDelta = DELAY_US + DELAY_US;
    ratio = (float)(diffTick) / (float)(expectedDelta);

    fprintf(stdout, "  delta = %u, expected = %u, ratio = %f\n", diffTick, expectedDelta, ratio);
    if ( 0.8F <= ratio && ratio <= 1.5F )
      fprintf(stdout, "  clock is OK\n");
    else if ( 1.8F <= ratio && ratio <= 2.2F )
      fprintf(stdout, "  clock is at half speed. all delays are doubled!\n");
    else
      fprintf(stdout, "  clock is corrupt!\n");
  }

  return 0;
}

i've extended the test duration to 50 ms per clock. time reports ~ 550 ms on Raspi 1, with the PCM clock doubling the duration. here the full output:

# time build/test_delay
testing PWM clock
  delta = 50281, expected = 50000, ratio = 1.005620
  clock is OK
testing PCM clock
  delta = 100270, expected = 50000, ratio = 2.005400
  clock is at half speed. all delays are doubled!

real    0m0,551s
user    0m0,075s
sys     0m0,302s

one more info:

i'll prepare a pull request ..

hayguen commented 4 years ago

see pull request https://github.com/joan2937/pigpio/pull/332