GPIO sysfs input lag.

[William Hermans]

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    

[William Hermans]

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.

--
For more options, visit http://beagleboard.org/discuss
---
You received this message because you are subscribed to the Google Groups "BeagleBoard" group.
To unsubscribe from this group and stop receiving emails from it, send an email to beagleboard+unsubscribe@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/beagleboard/5885cd25-64f8-4989-940a-35ba85365828%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[William Hermans]

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 . . .

[William Hermans]

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 ?

[William Hermans]

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.