GPIO sysfs input lag.

Something odd I’m just now noticing is that GPI on the beaglewbone seems to have some lag.

What I’m doing:We have a cape with 6 channels PWM, 6 pins input, and several pins output. In order to test the PWM circuitry on our capes, I’m configuring these pins as GPO’s, and we have a test header that ties the PWM pins to the input pins. All this is configured via an overlay file, and it is all correct. Additionally, we have LEDs on each channel PWM on these headers for visual inspection. The LEDs light up correctly when the PWM pins( again configured as GPO’s for the purpose of this test ) are high.

However, when setting these pins high, then reading back the value from the PWM pins, and input pins, The input pins lag behind a great deal. Code:

`
#include <unistd.h>
#include <sys/stat.h>
#include <fcntl.h>
#include <stdio.h>
#include <errno.h>
#include <stdlib.h>

#define HIGH 1
#define LOW 0

#define PWM1 2
#define PWM2 3
#define PWM3 50
#define PWM4 22
#define PWM5 51
#define PWM6 23

#define Z1IN 44
#define Z2IN 45
#define Z3IN 46
#define Z4IN 47
#define Z5IN 48
#define Z6IN 49

void set_pin(int pin_num, int value)
{
char gpio_path[40] = {0};
char str_value[2] = {0};

sprintf(str_value, “%d”, value);
sprintf(gpio_path, “/sys/class/gpio/gpio%d/value”, pin_num);

int fd = open(gpio_path, O_WRONLY);
if(fd == -1){
perror(gpio_path);
exit(1);
}

int nread = write(fd, str_value, 1);
if( nread < 0){
perror(“write()”);
exit(1);
}

close(fd);
}

int get_pin(int pin_num)
{
char gpio_path[40] = {0};
char str_value[2] = {0};

sprintf(gpio_path, “/sys/class/gpio/gpio%d/value”, pin_num);

int fd = open(gpio_path, O_RDONLY);
if(fd == -1){
perror(gpio_path);
exit(1);
}

read(fd, str_value, sizeof(str_value - 1));

close(fd);

return strtol(str_value, NULL, 10);
}

int main()
{

set_pin(PWM1, LOW);
set_pin(PWM2, LOW);
set_pin(PWM3, LOW);
set_pin(PWM4, LOW);
set_pin(PWM5, LOW);
set_pin(PWM6, LOW);
sleep(1);
printf(“PWM1: %i Z1IN: %i \n”, get_pin(PWM1), get_pin(Z1IN));
printf(“PWM2: %i Z2IN: %i \n”, get_pin(PWM2), get_pin(Z2IN));
printf(“PWM3: %i Z3IN: %i \n”, get_pin(PWM3), get_pin(Z3IN));
printf(“PWM4: %i Z4IN: %i \n”, get_pin(PWM4), get_pin(Z4IN));
printf(“PWM5: %i Z5IN: %i \n”, get_pin(PWM5), get_pin(Z5IN));
printf(“PWM6: %i Z6IN: %i \n”, get_pin(PWM6), get_pin(Z6IN));

printf("\n");

/***********************************************************/
set_pin(PWM1, HIGH);
set_pin(PWM2, HIGH);
set_pin(PWM3, HIGH);
set_pin(PWM4, HIGH);
set_pin(PWM5, HIGH);
set_pin(PWM6, HIGH);
sleep(1);
printf(“PWM1: %i Z1IN: %i \n”, get_pin(PWM1), get_pin(Z1IN));
printf(“PWM2: %i Z2IN: %i \n”, get_pin(PWM2), get_pin(Z2IN));
printf(“PWM3: %i Z3IN: %i \n”, get_pin(PWM3), get_pin(Z3IN));
printf(“PWM4: %i Z4IN: %i \n”, get_pin(PWM4), get_pin(Z4IN));
printf(“PWM5: %i Z5IN: %i \n”, get_pin(PWM5), get_pin(Z5IN));
printf(“PWM6: %i Z6IN: %i \n”, get_pin(PWM6), get_pin(Z6IN));

return 0;
}
`

As anyone can see, really simple straight forward code. The sleep shown in the code is required at this value, and if lowered, the input pins will be set correctly, but will read wrong. So here’s the output as it stands.

root@wgd:~/dl-i2c-test# nano read_zonein.c
root@wgd:~/dl-i2c-test# gcc -Wall -o read_zonein read_zonein.c
root@wgd:~/dl-i2c-test# ./read_zonein
PWM1: 0 Z1IN: 1
PWM2: 0 Z2IN: 1
PWM3: 0 Z3IN: 1
PWM4: 0 Z4IN: 1
PWM5: 0 Z5IN: 1
PWM6: 0 Z6IN: 1

PWM1: 1 Z1IN: 0
PWM2: 1 Z2IN: 0
PWM3: 1 Z3IN: 0
PWM4: 1 Z4IN: 0
PWM5: 1 Z5IN: 0
PWM6: 1 Z6IN: 0

But change the sleep() value to .5( 500 ms ) . . .
root@wgd:~/dl-i2c-test# nano read_zonein.c
root@wgd:~/dl-i2c-test# gcc -Wall -o read_zonein read_zonein.c
root@wgd:~/dl-i2c-test# ./read_zonein
PWM1: 0 Z1IN: 1
PWM2: 0 Z2IN: 1
PWM3: 0 Z3IN: 1
PWM4: 0 Z4IN: 1
PWM5: 0 Z5IN: 1
PWM6: 0 Z6IN: 1

PWM1: 1 Z1IN: 1
PWM2: 1 Z2IN: 1
PWM3: 1 Z3IN: 0
PWM4: 1 Z4IN: 0
PWM5: 1 Z5IN: 0
PWM6: 1 Z6IN: 0

Change the sleep value to .2(200 ms ), and the executed code gets all kinds of squirely. e.g. very inconsistent.

Does anyone know what’s going on here ?
root@wgd:~/dl-i2c-test# uname -r
4.4.55-ti-r94
root@wgd:~/dl-i2c-test# free
total used free shared buffers cached
Mem: 499308 64736 434572 1456 5792 32348
-/+ buffers/cache: 26596 472712
Swap: 0 0 0
root@wgd:~/dl-i2c-test# uptime
15:57:39 up 2:33, 1 user, load average: 0.00, 0.01, 0.00
root@wgd:~/dl-i2c-test# cat /etc/dogtag
BeagleBoard.org Debian Image 2017-04-02

Even for a non RT kernel this seems ridiculously slow

Just to show this is not exactly related to syscalls() ( printf() ) between userspace / kernelspace:
root@wgd:~/dl-i2c-test# ./read_zonein > test.txt
root@wgd:~/dl-i2c-test# cat test.txt
PWM1: 0 Z1IN: 1
PWM2: 0 Z2IN: 1
PWM3: 0 Z3IN: 1
PWM4: 0 Z4IN: 1
PWM5: 0 Z5IN: 1
PWM6: 0 Z6IN: 1

PWM1: 1 Z1IN: 1
PWM2: 1 Z2IN: 1
PWM3: 1 Z3IN: 1
PWM4: 1 Z4IN: 1
PWM5: 1 Z5IN: 1
PWM6: 1 Z6IN: 1

Perhaps the read()'s and write()'s are too much for the system to handle ? But this did not used to be the case. Used to be one could at least make 50-100 calls of this nature per second, before seeing any system slow down. The above is with a sleep value of 200ms, and we can see that the inputs have not caught up with the output in the second half of the test.

Sure seems to indicate there is a bug in the gpio driver somewhere . . . it does not get any faster than this, and yes, the sleep()s are required AGAIN.
root@wgd:~/dl-i2c-test# nano tst.c
root@wgd:~/dl-i2c-test# gcc -Wall -o tst tst.c
root@wgd:~/dl-i2c-test# ./tst
PWM1 1 Z1IN 0
PWM2 1 Z2IN 0
PWM3 1 Z3IN 0
PWM4 1 Z4IN 0
PWM5 1 Z5IN 0
PWM6 1 Z6IN 0

PWM1 0 Z1IN 1
PWM2 0 Z2IN 1
PWM3 0 Z3IN 1
PWM4 0 Z4IN 1
PWM5 0 Z5IN 1
PWM6 0 Z6IN 1

Code:

`
#include <stdio.h>
#include <stdlib.h>
#include <stdint.h>
#include <unistd.h>
#include <sys/mman.h>
#include <sys/types.h>
#include <sys/stat.h>
#include <errno.h>
#include <fcntl.h>

#define GPIO0 (0x44E07000)
#define GPIO1 (0x4804C000)
#define GPIO2 (0x481AC000)
#define GPIO3 (0x481AE000)
#define GPIO_SIZE (0x2000)

#define GPIO_DATAOUT (0x13C)
#define GPIO_DATAIN (0x138)

#define PWM1 (1<<2) /gpio_0/
#define PWM2 (1<<3) /gpio_0/
#define PWM3 (1<<18) /gpio_1/
#define PWM4 (1<<22) /gpio_0/
#define PWM5 (1<<19) /gpio_1/
#define PWM6 (1<<23) /gpio_0/

#define Z1IN (1<<12) /gpio_1/
#define Z2IN (1<<13) /gpio_1/
#define Z3IN (1<<14) /gpio_1/
#define Z4IN (1<<15) /gpio_1/
#define Z5IN (1<<16) /gpio_1/
#define Z6IN (1<<17) /gpio_1/

int main(int argc, char *argv[])
{
void *gpio_addr;
unsigned int *gpio0_out;
unsigned int *gpio1_out, *gpio1_in;

int fd = open("/dev/mem", O_RDWR);

gpio_addr = mmap(0, GPIO_SIZE, PROT_READ | PROT_WRITE, MAP_SHARED, fd, GPIO0);
gpio0_out = gpio_addr + GPIO_DATAOUT;

gpio_addr = mmap(0, GPIO_SIZE, PROT_READ | PROT_WRITE, MAP_SHARED, fd, GPIO1);
gpio1_out = gpio_addr + GPIO_DATAOUT;
gpio1_in = gpio_addr + GPIO_DATAIN;

close(fd);

*gpio0_out |= PWM1 + PWM2 + PWM4 + PWM6;
*gpio1_out |= PWM3 + PWM5;
sleep(1);
printf(“PWM1 %u Z1IN %u\n”, !! (*gpio0_out & PWM1), !!(*gpio1_in & Z1IN));
printf(“PWM2 %u Z2IN %u\n”, !! (*gpio0_out & PWM2), !!(*gpio1_in & Z2IN));
printf(“PWM3 %u Z3IN %u\n”, !! (*gpio1_out & PWM3), !!(*gpio1_in & Z3IN));
printf(“PWM4 %u Z4IN %u\n”, !! (*gpio0_out & PWM4), !!(*gpio1_in & Z4IN));
printf(“PWM5 %u Z5IN %u\n”, !! (*gpio1_out & PWM5), !!(*gpio1_in & Z5IN));
printf(“PWM6 %u Z6IN %u\n”, !! (*gpio0_out & PWM6), !!(*gpio1_in & Z6IN));
printf("\n");
*gpio0_out &= ~(PWM1 + PWM2 + PWM4 + PWM6);
*gpio1_out &= ~(PWM3 + PWM5);
sleep(1);
printf(“PWM1 %u Z1IN %u\n”, !! (*gpio0_out & PWM1), !!(*gpio1_in & Z1IN));
printf(“PWM2 %u Z2IN %u\n”, !! (*gpio0_out & PWM2), !!(*gpio1_in & Z2IN));
printf(“PWM3 %u Z3IN %u\n”, !! (*gpio1_out & PWM3), !!(*gpio1_in & Z3IN));
printf(“PWM4 %u Z4IN %u\n”, !! (*gpio0_out & PWM4), !!(*gpio1_in & Z4IN));
printf(“PWM5 %u Z5IN %u\n”, !! (*gpio1_out & PWM5), !!(*gpio1_in & Z5IN));
printf(“PWM6 %u Z6IN %u\n”, !! (*gpio0_out & PWM6), !!(*gpio1_in & Z6IN));

return 0;
}
`

sleep()'s again at .2(200ms)
root@wgd:~/dl-i2c-test# nano tst.c
root@wgd:~/dl-i2c-test# gcc -Wall -o tst tst.c
root@wgd:~/dl-i2c-test# ./tst
PWM1 1 Z1IN 1
PWM2 1 Z2IN 0
PWM3 1 Z3IN 0
PWM4 1 Z4IN 0
PWM5 1 Z5IN 0
PWM6 1 Z6IN 0

PWM1 0 Z1IN 0
PWM2 0 Z2IN 1
PWM3 0 Z3IN 1
PWM4 0 Z4IN 1
PWM5 0 Z5IN 1
PWM6 0 Z6IN 1

Output to a file:
root@wgd:~/dl-i2c-test# ./tst >test.txt
root@wgd:~/dl-i2c-test# cat test.txt
PWM1 1 Z1IN 1
PWM2 1 Z2IN 1
PWM3 1 Z3IN 1
PWM4 1 Z4IN 1
PWM5 1 Z5IN 1
PWM6 1 Z6IN 1

PWM1 0 Z1IN 1
PWM2 0 Z2IN 1
PWM3 0 Z3IN 1
PWM4 0 Z4IN 1
PWM5 0 Z5IN 1
PWM6 0 Z6IN 1

Something’s not right guys, and I’m pretty sure it’s not me . . .

So, same kernel but RT PREEMPT enabled. The only code that’s changed:

sleep(.2); printf("PWM1 %u Z1IN %u\n", !!(*gpio0_out & PWM1), !!(*gpio1_in & Z1IN)); printf("PWM2 %u Z2IN %u\n", !!(*gpio0_out & PWM2), !!(*gpio1_in & Z2IN)); printf("PWM3 %u Z3IN %u\n", !!(*gpio1_out & PWM3), !!(*gpio1_in & Z3IN)); printf("PWM4 %u Z4IN %u\n", !!(*gpio0_out & PWM4), !!(*gpio1_in & Z4IN)); printf("PWM5 %u Z5IN %u\n", !!(*gpio1_out & PWM5), !!(*gpio1_in & Z5IN)); printf("PWM6 %u Z6IN %u\n", !!(*gpio0_out & PWM6), !!(*gpio1_in & Z6IN)); printf("\n"); *gpio0_out &= ~(PWM1 + PWM2 + PWM4 + PWM6); *gpio1_out &= ~(PWM3 + PWM5); sleep(.2); printf("PWM1 %u Z1IN %u\n", !!(*gpio0_out & PWM1), !!(*gpio1_in & Z1IN)); printf("PWM2 %u Z2IN %u\n", !!(*gpio0_out & PWM2), !!(*gpio1_in & Z2IN)); printf("PWM3 %u Z3IN %u\n", !!(*gpio1_out & PWM3), !!(*gpio1_in & Z3IN)); printf("PWM4 %u Z4IN %u\n", !!(*gpio0_out & PWM4), !!(*gpio1_in & Z4IN)); printf("PWM5 %u Z5IN %u\n", !!(*gpio1_out & PWM5), !!(*gpio1_in & Z5IN)); printf("PWM6 %u Z6IN %u\n", !!(*gpio0_out & PWM6), !!(*gpio1_in & Z6IN));

sleep(.2);

For those of you who do not know what !! is. Think of it as a double NOT being used as a shorthand for a ternary conditional check. Anyway. . .
root@wgd:~/dl-i2c-test# nano tst.c
root@wgd:~/dl-i2c-test# gcc -Wall -o tst tst.c
root@wgd:~/dl-i2c-test# ./tst
PWM1 1 Z1IN 1
PWM2 1 Z2IN 0
PWM3 1 Z3IN 0
PWM4 1 Z4IN 0
PWM5 1 Z5IN 0
PWM6 1 Z6IN 0

PWM1 0 Z1IN 0
PWM2 0 Z2IN 1
PWM3 0 Z3IN 1
PWM4 0 Z4IN 1
PWM5 0 Z5IN 1
PWM6 0 Z6IN 1

root@wgd:~/dl-i2c-test# uname -r
4.4.55-ti-rt-r94

So what seems to be happening to me is this: There is a lazy check somewhere in the kernel, or kernel module code for the gpio driver(s) when changing the state of an input pin. Of course that’s an assumption. After thinking about this for a long time last night, This could be one of many things. Possibly even more than one thing. It could possibly even be something else slowing down the input pin updating. I am using a DS18B20 1-wire temperature sensor, which since 1-wire is technically power, ground, and a GPIO data pin . . . Maybe 1-wire could potentially be interfering or slowing down the systems GPI’s ? That’s a pretty “thin” guess, but I suppose possible ?

Ok, so I have identified the problem. GPI on the beaglebone is comparatively slow to GPO when changing state, but it’s no where near as bad as I thought. The actual “cutoff” for GPI changes to take effect are somewhere between 500, and 1000 uSec. Or between .5, and 1 millisecond. I tested all the way down to 10uS, and the first GPI of each half of the test was inverted to what it should have been for a correct reading. e.g. maybe slew speed could correct that ?

Now what the actual problem was: sleep() was not functioning in tenths of a second as it should be. In effect, anything less than “1” was working like sleep(0); Perhaps I need to install a package to get this functionality, but according to what I’ve read in the past, this shouldn’t be the case. Maybe I’m remembering incorrectly. So, I instead switched to usleep()

usleep(500);
root@wgd:~/dl-i2c-test# nano tst.c
root@wgd:~/dl-i2c-test# gcc -Wall -o tst tst.c
root@wgd:~/dl-i2c-test# ./tst
PWM1 1 Z1IN 1
PWM2 1 Z2IN 0
PWM3 1 Z3IN 0
PWM4 1 Z4IN 0
PWM5 1 Z5IN 0
PWM6 1 Z6IN 0

PWM1 0 Z1IN 1
PWM2 0 Z2IN 1
PWM3 0 Z3IN 1
PWM4 0 Z4IN 1
PWM5 0 Z5IN 1
PWM6 0 Z6IN 1

usleep(1000);
root@wgd:~/dl-i2c-test# nano tst.c
root@wgd:~/dl-i2c-test# gcc -Wall -o tst tst.c
root@wgd:~/dl-i2c-test# ./tst
PWM1 1 Z1IN 0
PWM2 1 Z2IN 0
PWM3 1 Z3IN 0
PWM4 1 Z4IN 0
PWM5 1 Z5IN 0
PWM6 1 Z6IN 0

PWM1 0 Z1IN 1
PWM2 0 Z2IN 1
PWM3 0 Z3IN 1
PWM4 0 Z4IN 1
PWM5 0 Z5IN 1
PWM6 0 Z6IN 1

At this point, I got tired of “hunting and packing”, so did not look any further.