on raspberry Pi Zero W performance of read/write 15-30x slower after running application 2nd time.,about mattjlewis/diozero

Comments (17)

JohnMTu commented on May 25, 2024

update:
i was testing also other libraries and noticed this:

If i use code above, and then run code using only pi4j-core-1.2.jar (without diozero), then such code is slow (There were 100000 flips in 7384ms).
But if i run same pi4j-core-1.2.jar (without diozero) again, it's 3x faster: (There were 100000 flips in 2206ms)
Hence i tried to run after code from original ticket. It was also fast.

From that i have a feeling, that cleanup done by pi4j-core-1.2.jar is somehow better.
This is what i used there:

GpioPinDigitalInput inPin = gpio.provisionDigitalInputPin(RaspiBcmPin.GPIO_03, "myName3", PinPullResistance.OFF);

inPin.setShutdownOptions(true, PinState.LOW, PinPullResistance.OFF);

GpioPinDigitalOutput outPin = gpio.provisionDigitalOutputPin(RaspiBcmPin.GPIO_02, PinState.LOW);

outPin.setShutdownOptions(true, PinState.LOW, PinPullResistance.OFF);

from diozero.

mattjlewis commented on May 25, 2024

Could you try with the latest 0.12 snapshot build please. I've switched to pi4j-1.2 in the latest build - I suspect the different behaviour is due to pi4j 1.1 but it would be good to validate.

Could you also try with the following provider combinations:

No providers, just include tinylog and diozero-core on the classpath (should be slowest)
The diozero mmap provider (diozero-provider-mmap) (should be the fastest)

I've just pushed to the snapshot repository.

Thanks Matt,

from diozero.

JohnMTu commented on May 25, 2024

so compiled it myself (on windows and had to skip tests, as they were failing).
And tried with
sudo java -Dpi4j.linking=dynamic -cp .:diozero-core-0.12-SNAPSHOT.jar:tinylog-1.3.4.jar:diozero-provider-wiringpi-0.12-SNAPSHOT.jar sk.jamicom.smart.garaz.trials.GpioSwitchSpeed_DioZeroTest

but didn't solve my problem.
With this version there is "constant" performance, independently if i run it after fresh rPI boot, or if i stop it and run again. And that performance seems to be ~2x better, than 2nd run with v0.11 ... but still order of magnitude slower, when compared to 1st run with 0.11.

So overall it's worse for me.

from diozero.

JohnMTu commented on May 25, 2024

here is my whole test suite. Last two are without diozero, instead pi4j directly and my own simple sysFs impl.

Test code was (and similar for non dio-zero)

        System.out.println("Init test, inPin="+inPin+", outPin="+outPin);
        try (
                LED outPin = new LED(this.outPin);
                Button inPin = new Button(this.inPin, GpioPullUpDown.NONE);
        ){
            long flips = -10000; // warm up
            boolean expectedValue = false;
            outPin.setOn(expectedValue);

            System.out.println("Warming up test");
            long start = System.currentTimeMillis();
            long reads = 0;

            while (true) {
                long now = System.currentTimeMillis();
                if (flips == 0) {
                    System.out.println("Starting measurement");
                    start = System.currentTimeMillis();
                    reads = 0;
                }
                if (now > start + 1000) {
                    System.out.println("There were "+flips+" flips and "+reads+" reads in "+(now-start)+"ms");
                    break;
                }
                for (int i=0; i<1000; i++) { // loop 1000 times to avoid calling System.currentTimeMillis too often
                    reads++;
                    if (inPin.getValue() == expectedValue) {
                        flips++;
                        expectedValue = !expectedValue;
                        outPin.setOn(expectedValue);
                    }
                }
            }
        } finally {
//            DeviceFactoryHelper.getNativeDeviceFactory().close();
        }```

results:

DIO no-provider
There were 12000 flips and 12000 reads in 1080ms

DIO no-provider-12-SNAPSHOT
There were 11000 flips and 11000 reads in 1004ms

DIO MMAP
There were 52000 flips and 52000 reads in 1008ms

DIO MMAP-12-SNAPSHOT
There were 47000 flips and 47000 reads in 1003ms

DIO PI4j
There were 60000 flips and 60000 reads in 1009ms

DIO WiringPi
There were 1085000 flips and 1085000 reads in 1001ms

DIO WiringPi-12-SNAPSHOT
There were 1125000 flips and 1125000 reads in 1001ms

DIO PigPio
There were 625000 flips and 625000 reads in 1001ms

pi4j
There were 54000 flips and 54000 reads in 1014ms

sysFs
There were 32000 flips and 32000 reads in 1011ms

from diozero.

JohnMTu commented on May 25, 2024

but problem remains. If i don't run cleanup from native pi4j library, then running e.g. twice a DIO WiringPi leads to 698000 followed by 33000
for wiringPi-12-SNAPSHOT it's only 62000 followed by 59000

(10%-20% is error of measurement, as i tried it only once and usually i see like a milion instead of 700k for the first wiringPi-0.11)

from diozero.

JohnMTu commented on May 25, 2024

hence using cleanup from pi4j followed by v0.11 wiring pi is unbeatable ... 2x faster than pigPio and at least 10x faster than all others (including MMAP)

from diozero.

mattjlewis commented on May 25, 2024

Please take a look at GpioPerfTest in diozero-sampleapps. Running on my Pi3B with the wiringPi provider I see hardly any variation in execution times.

pi@leonard:~/diozero$ sudo java -Dpi4j.linking=dynamic -cp tinylog-1.3.6.jar:diozero-core-0.12-SNAPSHOT.jar:diozero-provider-wiringpi-0.12-SNAPSHOT.jar:diozero-sampleapps-0.12-SNAPSHOT.jar:pi4j-core.jar com.diozero.sampleapps.GpioPerfTest 12 1000000
20:55:26.832 [main] INFO com.diozero.internal.provider.wiringpi.WiringPiDeviceFactory.setHardwarePwmFrequency - setHardwarePwmFrequency(100) - range=1024, divisor=187
20:55:27.483 [main] INFO com.diozero.sampleapps.GpioPerfTest.test - Duration for 1000000 iterations: 0.4149s
20:55:27.880 [main] INFO com.diozero.sampleapps.GpioPerfTest.test - Duration for 1000000 iterations: 0.3948s
20:55:28.282 [main] INFO com.diozero.sampleapps.GpioPerfTest.test - Duration for 1000000 iterations: 0.4000s
20:55:28.684 [main] INFO com.diozero.sampleapps.GpioPerfTest.test - Duration for 1000000 iterations: 0.3987s
20:55:29.076 [main] INFO com.diozero.sampleapps.GpioPerfTest.test - Duration for 1000000 iterations: 0.3900s
pi@leonard:~/diozero$ sudo java -Dpi4j.linking=dynamic -cp tinylog-1.3.6.jar:diozero-core-0.12-SNAPSHOT.jar:diozero-provider-wiringpi-0.12-SNAPSHOT.jar:diozero-sampleapps-0.12-SNAPSHOT.jar:pi4j-core.jar com.diozero.sampleapps.GpioPerfTest 12 1000000
20:55:51.601 [main] INFO com.diozero.internal.provider.wiringpi.WiringPiDeviceFactory.setHardwarePwmFrequency - setHardwarePwmFrequency(100) - range=1024, divisor=187
20:55:52.252 [main] INFO com.diozero.sampleapps.GpioPerfTest.test - Duration for 1000000 iterations: 0.4113s
20:55:52.646 [main] INFO com.diozero.sampleapps.GpioPerfTest.test - Duration for 1000000 iterations: 0.3919s
20:55:53.037 [main] INFO com.diozero.sampleapps.GpioPerfTest.test - Duration for 1000000 iterations: 0.3883s
20:55:53.439 [main] INFO com.diozero.sampleapps.GpioPerfTest.test - Duration for 1000000 iterations: 0.3988s
20:55:53.833 [main] INFO com.diozero.sampleapps.GpioPerfTest.test - Duration for 1000000 iterations: 0.3911s
pi@leonard:~/diozero$ sudo java -Dpi4j.linking=dynamic -cp tinylog-1.3.6.jar:diozero-core-0.12-SNAPSHOT.jar:diozero-provider-wiringpi-0.12-SNAPSHOT.jar:diozero-sampleapps-0.12-SNAPSHOT.jar:pi4j-core.jar com.diozero.sampleapps.GpioPerfTest 12 1000000
20:55:57.893 [main] INFO com.diozero.internal.provider.wiringpi.WiringPiDeviceFactory.setHardwarePwmFrequency - setHardwarePwmFrequency(100) - range=1024, divisor=187
20:55:58.555 [main] INFO com.diozero.sampleapps.GpioPerfTest.test - Duration for 1000000 iterations: 0.4199s
20:55:58.949 [main] INFO com.diozero.sampleapps.GpioPerfTest.test - Duration for 1000000 iterations: 0.3913s
20:55:59.345 [main] INFO com.diozero.sampleapps.GpioPerfTest.test - Duration for 1000000 iterations: 0.3940s
20:55:59.740 [main] INFO com.diozero.sampleapps.GpioPerfTest.test - Duration for 1000000 iterations: 0.3917s
20:56:00.166 [main] INFO com.diozero.sampleapps.GpioPerfTest.test - Duration for 1000000 iterations: 0.4231s

Running with the mmap provider is almost twice as fast:

pi@leonard:~/diozero$ sudo java -Dpi4j.linking=dynamic -cp tinylog-1.3.6.jar:diozero-core-0.12-SNAPSHOT.jar:diozero-provider-mmap-0.12-SNAPSHOT.jar:diozero-sampleapps-0.12-SNAPSHOT.jar com.diozero.sampleapps.GpioPerfTest 12 1000000
20:59:05.302 [main] INFO com.diozero.sampleapps.GpioPerfTest.test - Duration for 1000000 iterations: 0.2655s
20:59:05.552 [main] INFO com.diozero.sampleapps.GpioPerfTest.test - Duration for 1000000 iterations: 0.2354s
20:59:05.789 [main] INFO com.diozero.sampleapps.GpioPerfTest.test - Duration for 1000000 iterations: 0.2347s
20:59:06.028 [main] INFO com.diozero.sampleapps.GpioPerfTest.test - Duration for 1000000 iterations: 0.2359s
20:59:06.265 [main] INFO com.diozero.sampleapps.GpioPerfTest.test - Duration for 1000000 iterations: 0.2350s
pi@leonard:~/diozero$ sudo java -Dpi4j.linking=dynamic -cp tinylog-1.3.6.jar:diozero-core-0.12-SNAPSHOT.jar:diozero-provider-mmap-0.12-SNAPSHOT.jar:diozero-sampleapps-0.12-SNAPSHOT.jar com.diozero.sampleapps.GpioPerfTest 12 1000000
20:59:11.115 [main] INFO com.diozero.sampleapps.GpioPerfTest.test - Duration for 1000000 iterations: 0.2635s
20:59:11.364 [main] INFO com.diozero.sampleapps.GpioPerfTest.test - Duration for 1000000 iterations: 0.2328s
20:59:11.599 [main] INFO com.diozero.sampleapps.GpioPerfTest.test - Duration for 1000000 iterations: 0.2332s
20:59:11.834 [main] INFO com.diozero.sampleapps.GpioPerfTest.test - Duration for 1000000 iterations: 0.2338s
20:59:12.069 [main] INFO com.diozero.sampleapps.GpioPerfTest.test - Duration for 1000000 iterations: 0.2331s
pi@leonard:~/diozero$ sudo java -Dpi4j.linking=dynamic -cp tinylog-1.3.6.jar:diozero-core-0.12-SNAPSHOT.jar:diozero-provider-mmap-0.12-SNAPSHOT.jar:diozero-sampleapps-0.12-SNAPSHOT.jar com.diozero.sampleapps.GpioPerfTest 12 1000000
20:59:15.534 [main] INFO com.diozero.sampleapps.GpioPerfTest.test - Duration for 1000000 iterations: 0.2705s
20:59:15.802 [main] INFO com.diozero.sampleapps.GpioPerfTest.test - Duration for 1000000 iterations: 0.2546s
20:59:16.051 [main] INFO com.diozero.sampleapps.GpioPerfTest.test - Duration for 1000000 iterations: 0.2469s
20:59:16.289 [main] INFO com.diozero.sampleapps.GpioPerfTest.test - Duration for 1000000 iterations: 0.2362s
20:59:16.527 [main] INFO com.diozero.sampleapps.GpioPerfTest.test - Duration for 1000000 iterations: 0.2364s

from diozero.

mattjlewis commented on May 25, 2024

Pi4j is half the speed of wiringPi. Again no difference between runs.

pi@leonard:~/diozero$ sudo java -Dpi4j.linking=dynamic -cp tinylog-1.3.6.jar:diozero-core-0.12-SNAPSHOT.jar:diozero-provider-pi4j-0.12-SNAPSHOT.jar:diozero-sampleapps-0.12-SNAPSHOT.jar:pi4j-core.jar com.diozero.sampleapps.GpioPerfTest 12 1000000
21:05:01.895 [main] INFO com.diozero.internal.provider.pi4j.Pi4jDeviceFactory.setHardwarePwmFrequency - setHardwarePwmFrequency(100) - range=1024, divisor=187
21:05:03.244 [main] INFO com.diozero.sampleapps.GpioPerfTest.test - Duration for 1000000 iterations: 1.0502s
21:05:04.311 [main] INFO com.diozero.sampleapps.GpioPerfTest.test - Duration for 1000000 iterations: 1.0643s
21:05:05.361 [main] INFO com.diozero.sampleapps.GpioPerfTest.test - Duration for 1000000 iterations: 1.0479s
21:05:06.413 [main] INFO com.diozero.sampleapps.GpioPerfTest.test - Duration for 1000000 iterations: 1.0493s
21:05:07.483 [main] INFO com.diozero.sampleapps.GpioPerfTest.test - Duration for 1000000 iterations: 1.0676s
pi@leonard:~/diozero$ sudo java -Dpi4j.linking=dynamic -cp tinylog-1.3.6.jar:diozero-core-0.12-SNAPSHOT.jar:diozero-provider-pi4j-0.12-SNAPSHOT.jar:diozero-sampleapps-0.12-SNAPSHOT.jar:pi4j-core.jar com.diozero.sampleapps.GpioPerfTest 12 1000000
21:05:11.065 [main] INFO com.diozero.internal.provider.pi4j.Pi4jDeviceFactory.setHardwarePwmFrequency - setHardwarePwmFrequency(100) - range=1024, divisor=187
21:05:12.415 [main] INFO com.diozero.sampleapps.GpioPerfTest.test - Duration for 1000000 iterations: 1.0483s
21:05:13.477 [main] INFO com.diozero.sampleapps.GpioPerfTest.test - Duration for 1000000 iterations: 1.0595s
21:05:14.522 [main] INFO com.diozero.sampleapps.GpioPerfTest.test - Duration for 1000000 iterations: 1.0438s
21:05:15.565 [main] INFO com.diozero.sampleapps.GpioPerfTest.test - Duration for 1000000 iterations: 1.0412s
21:05:16.607 [main] INFO com.diozero.sampleapps.GpioPerfTest.test - Duration for 1000000 iterations: 1.0407s
pi@leonard:~/diozero$ sudo java -Dpi4j.linking=dynamic -cp tinylog-1.3.6.jar:diozero-core-0.12-SNAPSHOT.jar:diozero-provider-pi4j-0.12-SNAPSHOT.jar:diozero-sampleapps-0.12-SNAPSHOT.jar:pi4j-core.jar com.diozero.sampleapps.GpioPerfTest 12 1000000
21:05:19.875 [main] INFO com.diozero.internal.provider.pi4j.Pi4jDeviceFactory.setHardwarePwmFrequency - setHardwarePwmFrequency(100) - range=1024, divisor=187
21:05:21.269 [main] INFO com.diozero.sampleapps.GpioPerfTest.test - Duration for 1000000 iterations: 1.0923s
21:05:22.368 [main] INFO com.diozero.sampleapps.GpioPerfTest.test - Duration for 1000000 iterations: 1.0973s
21:05:23.468 [main] INFO com.diozero.sampleapps.GpioPerfTest.test - Duration for 1000000 iterations: 1.0982s
21:05:24.564 [main] INFO com.diozero.sampleapps.GpioPerfTest.test - Duration for 1000000 iterations: 1.0934s
21:05:25.661 [main] INFO com.diozero.sampleapps.GpioPerfTest.test - Duration for 1000000 iterations: 1.0956s

from diozero.

JohnMTu commented on May 25, 2024

your tests are different, as you do set true, set false in one iteration.
I do Set value, read value.

i'll try my tests on rPI 3B+

from diozero.

JohnMTu commented on May 25, 2024

on rpi3b+ is MMAP order of magnitude faster and is the fastest now. Also many others are faster - the slowest ones are like 2-3x faster. Wiring pi is having similar performance. See all results:

DIO no-provider
There were 55000 flips and 55000 reads in 1008ms

DIO no-provider-12-SNAPSHOT
There were 60000 flips and 60000 reads in 1009ms

DIO MMAP
There were 1346017 flips and 1347000 reads in 1001ms

DIO MMAP-12-SNAPSHOT
There were 1492720 flips and 1493000 reads in 1001ms

DIO PI4j
There were 155000 flips and 155000 reads in 1003ms

DIO WiringPi
There were 972999 flips and 973000 reads in 1001ms

DIO WiringPi-12-SNAPSHOT
There were 1088998 flips and 1089000 reads in 1001ms

DIO PigPio
There were 771999 flips and 772000 reads in 1001ms

pi4j
There were 165000 flips and 165000 reads in 1004ms

sysFs
There were 60000 flips and 60000 reads in 1005ms

from diozero.

mattjlewis commented on May 25, 2024

I wrote a very simple read test to see if there is any performance difference between runs (see GpioReadPerfTest in sample apps). Again, no difference in times between runs:

pi@leonard:~/diozero$ sudo java -Dpi4j.linking=dynamic -cp tinylog-1.3.6.jar:diozero-core-0.12-SNAPSHOT.jar:diozero-provider-pi4j-0.12-SNAPSHOT.jar:diozero-sampleapps-0.12-SNAPSHOT.jar:pi4j-core.jar com.diozero.sampleapps.GpioReadPerfTest 12 1000000
21:17:51.034 [main] INFO com.diozero.internal.provider.pi4j.Pi4jDeviceFactory.setHardwarePwmFrequency - setHardwarePwmFrequency(100) - range=1024, divisor=187
21:17:54.424 [main] INFO com.diozero.sampleapps.GpioReadPerfTest.test - Duration for 1000000 iterations: 2.9841s
21:17:57.298 [main] INFO com.diozero.sampleapps.GpioReadPerfTest.test - Duration for 1000000 iterations: 2.8721s
21:18:00.215 [main] INFO com.diozero.sampleapps.GpioReadPerfTest.test - Duration for 1000000 iterations: 2.9143s
21:18:03.079 [main] INFO com.diozero.sampleapps.GpioReadPerfTest.test - Duration for 1000000 iterations: 2.8606s
21:18:06.030 [main] INFO com.diozero.sampleapps.GpioReadPerfTest.test - Duration for 1000000 iterations: 2.9489s
pi@leonard:~/diozero$ sudo java -Dpi4j.linking=dynamic -cp tinylog-1.3.6.jar:diozero-core-0.12-SNAPSHOT.jar:diozero-provider-pi4j-0.12-SNAPSHOT.jar:diozero-sampleapps-0.12-SNAPSHOT.jar:pi4j-core.jar com.diozero.sampleapps.GpioReadPerfTest 12 1000000
21:18:09.911 [main] INFO com.diozero.internal.provider.pi4j.Pi4jDeviceFactory.setHardwarePwmFrequency - setHardwarePwmFrequency(100) - range=1024, divisor=187
21:18:13.302 [main] INFO com.diozero.sampleapps.GpioReadPerfTest.test - Duration for 1000000 iterations: 2.9787s
21:18:16.302 [main] INFO com.diozero.sampleapps.GpioReadPerfTest.test - Duration for 1000000 iterations: 2.9972s
21:18:19.295 [main] INFO com.diozero.sampleapps.GpioReadPerfTest.test - Duration for 1000000 iterations: 2.9909s
21:18:22.236 [main] INFO com.diozero.sampleapps.GpioReadPerfTest.test - Duration for 1000000 iterations: 2.9380s
21:18:25.122 [main] INFO com.diozero.sampleapps.GpioReadPerfTest.test - Duration for 1000000 iterations: 2.8841s

from diozero.

mattjlewis commented on May 25, 2024

I'm still confused as to what the problem is exactly. I see absolutely no variation between runs at all, admittedly I'm not actually connecting pins together. Note I previously have verified my performance tests using a digital scope.

from diozero.

JohnMTu commented on May 25, 2024

good that you mentioned. I tried as well or that rPI3B+.

On rPI3B+ there are no difference between runs even if i don't run cleanup from pi4j
... but on rPi zero W there is huge difference.... wondering why.

both are running raspbian buster, in both i installed native libs using
apt-get update
sudo apt-get install pigpio wiringpi

and both are having same java
openjdk version "1.8.0_212"
OpenJDK Runtime Environment (build 1.8.0_212-8u212-b01-1+rpi1-b01)
OpenJDK Client VM (build 25.212-b01, mixed mode)

But for me, it's not an issue anymore, as I was onlydeveloping on Zero W, while it will be deployed on 3B+ where seems to be no issue with subsequent runs.

from diozero.

JohnMTu commented on May 25, 2024

updated initial problem description with:
update: seems issue exists on R PI Zero W, but not exists on R Pi 3B and R Pi 3B+

from diozero.

mattjlewis commented on May 25, 2024

Excellent :-) I do have a Pi Zero W kicking around somewhere, I will try at some point.

from diozero.

JohnMTu commented on May 25, 2024

yup, maybe try to figure out, what's the difference in cleanup code when is diozero used and when is pi4j used, as only the later one seems to do cleanup well enough for Rpi Zero W.

Thanks for support. Good night.

from diozero.

mattjlewis commented on May 25, 2024

Closing this issue - I've not been able to reproduce on my RPi Zero.

from diozero.

on raspberry Pi Zero W performance of read/write 15-30x slower after running application 2nd time. about diozero HOT 17 CLOSED

Comments (17)

Related Issues (20)

Recommend Projects

React

Vue.js

Typescript

TensorFlow

Django

Laravel

D3

Recommend Topics

javascript

web

server

Machine learning

Visualization

Game

Recommend Org

Facebook

Microsoft

Google

Alibaba

D3

Tencent