BCM270X_DT: mz61581: Revert to spi-bcm2708

[notro]

The MZ61581 display does not work with spi-bcm2835 and software chip selects. It works before the commit: spi: bcm2835: transform native-cs to gpio-cs on first spi_setup

Revert to spi-bcm2708 until the cause has been detected and the issue resolved.

Also increase reliability by adding a patch for missing display controller reset.
This fbtft patch is now in linux-next and will probably land in 4.3.

[popcornmix]

Okay with me. @pelwell ?

Ideally we would like to drop spi-bcm2708 (and other drivers that have an upstream alternative that appears fully functional), but I guess that won't happen for a while (perhaps rpi-4.2.y kernel tree?)

[notro]

I can inform the manufacturer of the display that spi-bcm2708 probably will be removed the next time the Linux version is bumped on the official Pi kernel. That will give them some time to find out why it doesn't work with software controlled chip select.

[pelwell]

From what I remember, the upstream spi-bcm2835 doesn't have the auto-conversion patch. If the default is to always use cs-gpio in the dtb, and I'm not saying it should be, then there will need to be a way to defeat that with an overlay.

[notro]

@msperl Can spi-bcm2835 still be used with hw chip selects? Also with DMA?

[msperl]

As explained there are situations when the CS gets asserted/de-asserted for short periods (a few usec) of time when the control register is written to.
So any of those speed-optimizations will not work (as they will touch the register while the transfer is still in progress) - same with DMA.
That is why that auto-conversion from native to gpio-CS was put in place until CS-gpios gets added to the device tree...

Does the issue also happen when the dt already sets up pins 8 and 7 correctly as output and the spi driver node contains "CS-gpios = <&gpio 8>, <&gpio 7>;"?

[notro]

Does the issue also happen when the dt already sets up pins 8 and 7 correctly as output and the spi driver node contains "CS-gpios = <&gpio 8>, <&gpio 7>;"?

Yes. I tried that when I was trying to understand the spi cs gpio code.

[msperl]

If I had such a device then I could look into the why comparing the behavior on the bus using a logic-analyzer...

Maybe it is related to a pull-up issue in the hw?

The only difference I have seen is that the Native gpio has slightly less time between CS and clock-start.

So nothing else comes to my mind that could explain this except maybe a different interpretation of a spi-transfer sequence with regards to chip-selects in the framework compared to the 2708 driver.

Another thing: running at slower clocks solves the issue by chance?

[msperl]

Out of curiosity: why not use a "downgrade to spi-bcm2708" device-tree overlay for this specific device?

But obviously we also need to understand the issue and figure out why it does not work...

[pelwell]

Have you read this Pull Request? 8-)

[notro]

The only difference I have seen is that the Native gpio has slightly less time between CS and clock-start.

Ok, that's a place to start, adding a small delay after the gpio set in spi_set_cs().
I will try that when I'm done with some firmware API patches I'm working on. Thanks.
The display has a CPLD in front of the display controller, enabling it to max out the SPI bus at 128MHz.

Another thing: running at slower clocks solves the issue by chance?

No it doesn't.

Out of curiosity: why not use a "downgrade to spi-bcm2708" device-tree overlay for this specific device?

This PR does that :-)

[msperl]

As said: if you can have a look at the clocks and CS with a logic-analyzer then look into what is the difference on the bus-level (I can do this at up to 200MHz sample-rates if someone borrows me that device)...

But as said: I actually guess that the implementation behavior is slightly different for the drivers with regards to cs_change and the corresponding delays (actually between spi-bcm2835 and the spi-framework standard implementation)

[msperl]

One thing: is there any data that you read back from the device or can I also run this "blind" (similar to the st7739r I own).
Because then I can look at the SPI bus without a device attached and compare the waveforms...

[notro]

None of the FBTFT drivers rely on anything read back. I think that only one driver tries to read the device code if possible.

[msperl]

One idea: maybe the switching the gpio 7/8 to output does not remove the internal pull-up which would shift the low level up higher than with the alt2 mode (which would also control the gpio pull-ups I assume) - the cpld may run 1.8v internally but may be 3v3 tolerant, so with low guaranteed to say 0.2 vcc that would mean 0.3v as low limit and with the pull-up we may not get to that level.

So the test could be:

• Configure gpios 7/8 as output in the device tree and disable pull-ups.
• configure gpio-CS in spi.

If it works that way then we know it is the pull-ups and you got your way around it (and then I would be actually be surprised that the gpio code allows to change to output without disabling pull-ups).

[notro]

Neither the DT change, nor adding delay around CS helped. Also tried going down to 4MHz.

For reference, this is what I tried (tested ok on a rpi-display).
I also tried without changing pull.

diff --git a/arch/arm/boot/dts/bcm2708-rpi-b-plus.dts b/arch/arm/boot/dts/bcm2708-rpi-b-plus.dts
index 3ad2e0d..8faea0c 100644
--- a/arch/arm/boot/dts/bcm2708-rpi-b-plus.dts
+++ b/arch/arm/boot/dts/bcm2708-rpi-b-plus.dts
@@ -10,7 +10,8 @@
 &gpio {
        spi0_pins: spi0_pins {
                brcm,pins = <7 8 9 10 11>;
-               brcm,function = <4>; /* alt0 */
+               brcm,function = <1 1 4 4 4>; /* out out alt0 alt0 alt0 */
+               brcm,pull = <0 0 1 1 1>; /* none none down down down */
        };

        i2c0_pins: i2c0 {
@@ -46,6 +47,8 @@
        pinctrl-names = "default";
        pinctrl-0 = <&spi0_pins>;

+       cs-gpios = <&gpio 8 1>, <&gpio 7 1>;
+
        spidev@0{
                compatible = "spidev";
                reg = <0>;      /* CE0 */
diff --git a/drivers/spi/spi.c b/drivers/spi/spi.c
index 50910d8..7d579a0 100644
--- a/drivers/spi/spi.c
+++ b/drivers/spi/spi.c
@@ -464,8 +464,11 @@ static void spi_set_cs(struct spi_device *spi, bool enable)
        if (spi->mode & SPI_CS_HIGH)
                enable = !enable;

-       if (spi->cs_gpio >= 0)
+       if (spi->cs_gpio >= 0) {
+udelay(10);
                gpio_set_value(spi->cs_gpio, !enable);
+udelay(10);
+       }
        else if (spi->master->set_cs)
                spi->master->set_cs(spi, !enable);
 }

Thanks for the suggestions.
I can ask the manufacturer if he can send you a display. Will you look at it with your analyzer if he does?

[msperl]

I would try to figure it out...
But I will try first to run the device "blind" when I get back to my analyzer (as soon as it gets a bit cooler - maybe Sunday or Monday...)

[msperl]

I will share my findings with you and you can compare the measurements yourself as well...

[msperl]

Now that I run the logic-analyzer I see that you use:

                                spi-cpha;
                                spi-cpol;

And then the transfer on this changes the initial settings...
So the SPI clock and out level only get set during the first transfer....

Would it be possible to set the first transfer to a dummy command and see if it works then?

I would guess that just running:

rmmod fb_s6d02a1; insmod fb_s6d02a1

would also do the trick...

If it works then, then it is actually a bug in the spi-framework... (in that case I will explain why later - essentially something that has bitten me/us with CS-polarity before)

[msperl]

Please make sure that you only test with a single spi-device!
So do not load the driver for the touch display for this test!

[notro]

Reloading the module revealed a bug in fbtft which results in using a pointer to free'd memory. I thought I had fixed that issue. I need to build a kernel.

[msperl]

To summarize the issue - as I see it:
The problem is that with CS-gpio set the chip-select gets asserted before the spi-mode is set up.
This results CS being asserted and only then the clock is set up for the requested polarity.
This is not an issue as long as we always run in mode 0 (which is set by default) or as long as all devices use the same spi mode and the first transfer is "ignored".

That is why I was asking if setting up a single dummy transfer solves the issue.

Why does this not happen with native-CS? The reason is that in that case the polarities and chip-selects are set at the same time when writing the CS register.

As for a fix it will require a patch, that moves the setup of polarity to master->prepare_master to set polarity prior to setting gpio-CS.

[msperl]

@notro: sent you a (yet unverified) patch that should solve the polarity issue by moving the polarity settings to run before the chip-select not after.

The patch applies cleanly against upstream (4.2-rc3), but there may be a reject if you apply it against the foundation kernel because of handle_err does not exist in 4.0

[msperl]

Now I have checked and I believe that the problem should be solved by the patch!
Here the first transfer:

Failing when SCK changes the polarity WHILE CS is asserted:

Working eith SCK changing polarity while CS is NOT asserted:

Please tell me that it works as expected with a real device and I will upstream it...

[msperl]

Sent the patch upstream - when it gets accepted I will create a merge request

[notro]

Spot on Martin!

Your patch solved the problem as did reloading the driver (I had to apply the patch by hand on rpi-4.0.y).

I tried enabling DMA, but I only got polling transfers. When I disabled polling, I got DMA transfers for pixel data.
However the throughput is not as good as the old spi dma driver:

spi-bcm2835:
[   90.238356] fb_s6d02a1 spi0.0: Display update: 8482 kB/s (35.367 ms), fps=14 (70.009 ms)

spi-bcm2708:
[   56.904256] fb_s6d02a1 spi0.0: Display update: 12273 kB/s (24.443 ms), fps=19 (50.048 ms)

Ref: https://github.com/notro/fbtft/wiki/Performance#mz61581-pi-ext

[notro]

Just a note: If you try the performance output on any other than rpi-4.0.y, you need to use debug=35, because of a fbtft reset patch recently applied there. If not you get a white display.

[msperl]

I can try to run the same performance tests as you to see where/when we waste time with the logic-analyzer (especially the gaps)...

One note: please try to use a bigger DMA buffer than 4k - 32k for example should work and compare it then... (I guess the spi framework mapping of pages is quite expensive and then dmaengine on top - the original dma driver did not have that but did everything on its own)

[msperl]

As a note: when cleaning you run 51.3us between each 4k transfer with the default settings and 29.3us are spent with cs high. so there is still some interrupts (double maybe?) that run unneccesarily and stall the flow... (see my comment to your upstream patch)

And we run 0.358s for a full screen update at 8MHz.

[notro]

32k still gives me polling transfers. unsigned long overflows in the equation:

[    9.239777] bcm2835_spi_transfer_one: xfer_time_us= 32768 * 9 * 1000000 / 125000000 = 22

Removing polling, 32k gives comparable values:

[    8.648498] graphics fb1: fb_s6d02a1 frame buffer, 480x320, 300 KiB video memory, 32 KiB DMA buffer memory, fps=33, spi0.0 at 128 MHz

[   75.739626] fb_s6d02a1 spi0.0: Display update: 11314 kB/s (26.514 ms), fps=19 (50.385 ms)

fps=50:

[    8.717523] graphics fb1: fb_s6d02a1 frame buffer, 480x320, 300 KiB video memory, 32 KiB DMA buffer memory, fps=50, spi0.0 at 128 MHz

[   94.849416] fb_s6d02a1 spi0.0: Display update: 11406 kB/s (26.300 ms), fps=25 (39.996 ms)

The fps parameter is a misnomer but fps=50 translates to a HZ/fps=2 jiffies delay between updates.

What upstream patch are you referring to?

[msperl]

So we need to fix the calculation as well (at least make xfer_time_us long long)

[msperl]

Here the calculation patch (spaces instead of tabs, so does not apply cleanly)

diff --git a/drivers/spi/spi-bcm2835.c b/drivers/spi/spi-bcm2835.c
index c9357bb..e7874a6 100644
--- a/drivers/spi/spi-bcm2835.c
+++ b/drivers/spi/spi-bcm2835.c
@@ -480,7 +480,7 @@ static int bcm2835_spi_transfer_one_poll(struct spi_master *
                                         struct spi_device *spi,
                                         struct spi_transfer *tfr,
                                         u32 cs,
-                                        unsigned long xfer_time_us)
+                                        unsigned long long xfer_time_us)
 {
        struct bcm2835_spi *bs = spi_master_get_devdata(master);
        unsigned long timeout;
@@ -531,7 +531,8 @@ static int bcm2835_spi_transfer_one(struct spi_master *maste
 {
        struct bcm2835_spi *bs = spi_master_get_devdata(master);
        unsigned long spi_hz, clk_hz, cdiv;
-       unsigned long spi_used_hz, xfer_time_us;
+       unsigned long spi_used_hz;
+       unsigned long long xfer_time_us;
        u32 cs = bcm2835_rd(bs, BCM2835_SPI_CS);

        /* set clock */
@@ -573,9 +574,10 @@ static int bcm2835_spi_transfer_one(struct spi_master *mast
        bs->rx_len = tfr->len;

        /* calculate the estimated time in us the transfer runs */
-       xfer_time_us = tfr->len
+       xfer_time_us = (unsigned long long)tfr->len
                * 9 /* clocks/byte - SPI-HW waits 1 clock after each byte */
-               * 1000000 / spi_used_hz;
+               * 1000000;
+       do_div(xfer_time_us, spi_used_hz);

        /* for short requests run polling*/
        if (xfer_time_us <= BCM2835_SPI_POLLING_LIMIT_US)

That should fix the polling issue...

[msperl]

set out a patch for this for upstream as well...

[popcornmix]

I'm not sure xfer_time_us needs to be long long. 32-bit unsigned can handle over an hour.
I think you just need the cast in the calculation.
There is a big divide in the calculation so result is not going to be > 32-bits.

[msperl]

the bigger problem is that if I cast and cast back then we get issues with the 64/64 bit divide is not in eapi...
hence long long all the way and do_div();
No feedback on those 2 patches for upstream yet - and I would only merge when merged upstream...

[msperl]

@notro: as for speed: there does not seem to be a difference between 120MHz and 25MHz - at least from your dmesg reporting:

[  165.813848] graphics fb1: fb_s6d02a1 frame buffer, 480x320, 300 KiB video memory, 32 KiB DMA buffer memory, fps=33, spi0.0 at 25 MHz
[  123.074458] graphics fb1: fb_s6d02a1 frame buffer, 480x320, 300 KiB video memory, 32 KiB DMA buffer memory, fps=33, spi0.0 at 120 MHz

I will have a look at the output lines with the logic-analyzer to see where the "delay" can get found,
but I guess it may be related to interrupt latencies, and as we run interrupts for tx and rx-DMA while we only request rx-dma as an irq source that is some unnecessary overhead introduced by the dmaengine implementation - the original dma driver did not trigger tx-dma, so it may be faster because of that

[notro]

The fps numbers are used confusingly in fbtft. It first started out as a way to say how often the display should be updated. So the fps DT property and module argument is reflected in the fps value reported when the driver loads: fps=33. This is the default value.

Later when displays with bigger resolutions came along, fbtft couldn't always keep up with the value asked for, so I added a debug option to measure the real fps. This fps value is printed to the log for each frame sent to the display when debug=32, or for this particular display debug=35 has to be used because of a bug (fixed in rpi-4.0.y) in fbtft.

https://github.com/notro/fbtft/wiki/FPS was written to try and clear up this confusion, but this has not been done in the code.

[msperl]

here now some timings:

• dmesg:

[   74.699015] spi spi0.1: setting up native-CS1 as GPIO 7
[   74.699871] ads7846 spi0.1: touchscreen, irq 484
[   74.700501] input: ADS7846 Touchscreen as /devices/platform/soc/3f204000.spi/spi_master/spi0/spi0.1/input/input0
[   74.735725] fbtft: module is from the staging directory, the quality is unknown, you have been warned.
[   74.739504] fb_s6d02a1: module is from the staging directory, the quality is unknown, you have been warned.
[   74.743648] spi spi0.0: setting up native-CS0 as GPIO 8
[   74.744022] fbtft_of_value: width = 320
[   74.744043] fbtft_of_value: height = 480
[   74.744058] fbtft_of_value: buswidth = 8
[   74.744074] fbtft_of_value: debug = 3
[   74.744087] fbtft_of_value: rotate = 270
[   74.744101] fbtft_of_value: fps = 30
[   74.744114] fbtft_of_value: txbuflen = 32768
[   74.744977] fb_s6d02a1 spi0.0: fbtft_request_one_gpio: 'reset-gpios' = GPIO15
[   74.745033] fb_s6d02a1 spi0.0: fbtft_request_one_gpio: 'dc-gpios' = GPIO25
[   74.745124] fb_s6d02a1 spi0.0: fbtft_request_one_gpio: 'led-gpios' = GPIO18
[   74.745267] fb_s6d02a1 spi0.0: fbtft_verify_gpios()
[   74.745286] fb_s6d02a1 spi0.0: fbtft_init_display_dt()
[   74.745304] fb_s6d02a1 spi0.0: fbtft_reset()
[   74.865525] fb_s6d02a1 spi0.0: init: write_register: B0 00
[   74.865597] fb_s6d02a1 spi0.0: init: write_register: 11
[   74.865621] fb_s6d02a1 spi0.0: init: msleep(255)
[   75.131132] fb_s6d02a1 spi0.0: init: write_register: B3 02 00 00 00
[   75.131192] fb_s6d02a1 spi0.0: init: write_register: C0 13 3B 00 02 00 01 00 43
[   75.131234] fb_s6d02a1 spi0.0: init: write_register: C1 08 16 08 08
[   75.131271] fb_s6d02a1 spi0.0: init: write_register: C4 11 07 03 03
[   75.131308] fb_s6d02a1 spi0.0: init: write_register: C6 00
[   75.131355] fb_s6d02a1 spi0.0: init: write_register: C8 03 03 13 5C 03 07 14 08 00 21 08 14 07 53 0C 13 03 03 21 00
[   75.131395] fb_s6d02a1 spi0.0: init: write_register: 35 00
[   75.131426] fb_s6d02a1 spi0.0: init: write_register: 36 A0
[   75.131456] fb_s6d02a1 spi0.0: init: write_register: 3A 55
[   75.131487] fb_s6d02a1 spi0.0: init: write_register: 44 00 01
[   75.131521] fb_s6d02a1 spi0.0: init: write_register: D0 07 07 1D 03
[   75.131559] fb_s6d02a1 spi0.0: init: write_register: D1 03 30 10
[   75.131597] fb_s6d02a1 spi0.0: init: write_register: D2 03 14 04
[   75.131627] fb_s6d02a1 spi0.0: init: write_register: 29
[   75.131650] fb_s6d02a1 spi0.0: init: write_register: 2C
[   75.131673] fb_s6d02a1 spi0.0: set_var()
[   75.173576] fb_s6d02a1 spi0.0: Display update: 7167 kB/s (41.850 ms), fps=0 (0.000 ms)
[   75.173595] fb_s6d02a1 spi0.0: fbtft_register_backlight()
[   75.174103] graphics fb1: fb_s6d02a1 frame buffer, 480x320, 300 KiB video memory, 32 KiB DMA buffer memory, fps=33, spi0.0 at 120 MHz
[   75.174122] fb_s6d02a1 spi0.0: fbtft_backlight_update_status: polarity=0, power=0, fb_blank=0

• /etc/interrupts:

           CPU0       CPU1       CPU2       CPU3
 16:          0          0          0          0   ARMCTRL  16  bcm2708_fb dma
 24:         96          0          0          0   ARMCTRL  24  DMA IRQ
 25:       1407          0          0          0   ARMCTRL  25  DMA IRQ
 26:         10          0          0          0   ARMCTRL  26  DMA IRQ
 27:         10          0          0          0   ARMCTRL  27  DMA IRQ
 32:      34186          0          0          0   ARMCTRL  32  dwc_otg, dwc_otg_pcd, dwc_otg_hcd:usb1
 49:          0          0          0          0   ARMCTRL  49  3f200000.gpio:bank0
 50:          0          0          0          0   ARMCTRL  50  3f200000.gpio:bank1
 65:         20          0          0          0   ARMCTRL  65  3f00b880.mailbox
 66:          2          0          0          0   ARMCTRL  66  VCHIQ doorbell
 75:          1          0          0          0   ARMCTRL  75
 80:          0          0          0          0   ARMCTRL  80  3f204000.spi
 83:          6          0          0          0   ARMCTRL  83  uart-pl011
 84:       3321          0          0          0   ARMCTRL  84  mmc0
 99:       2183       2219       1315       1881   ARMCTRL  99  arch_timer
484:          0          0          0          0  pinctrl-bcm2835   4  ads7846
FIQ:              usb_fiq
IPI0:          0          0          0          0  CPU wakeup interrupts
IPI1:          0          0          0          0  Timer broadcast interrupts
IPI2:       2980       3009       2612       3528  Rescheduling interrupts
IPI3:         12         12         14         16  Function call interrupts
IPI4:          1          3          3          2  Single function call interrupts
IPI5:          0          0          0          0  CPU stop interrupts
IPI6:          0          0          0          0  IRQ work interrupts
IPI7:          0          0          0          0  completion interrupts
Err:          0

• so:
  • 10 RX-DMA-IRQ
  • 10 TX-DMA-IRQ
  • 0 SPI-IRQ
• basic pattern:
  
• 41531 us for the 10 32k Transfers (CS-Start to CS-end)
• measurement for "gaps" between 32kb transfers:
  • Graph:3
    
  • 249us from clock end to clock start (B1-D2)
  • 30us from clock end to CS-deassert (B1-C1)
  • 212us from CS-deassert to CS-assert (C1-D1)
  • 7us from CS-asset to CS (D1-D2)
• a full Transfer of 32k takes:
  • 4194us clock running
  • 4453us from start clock to start clock
  • so an overhead of 259us or 6%
• when sampling at 500MHz I got 62.5MHz clock

So I came to the conclusion that I need to configure at 125MHz and see if the clock then works as expected.

So with 125MHz I get now the expected 125MHz clock rate as well, but the fps is still fixed to 33.
But here some more measurements:

• 32k transfers take now:
  • 2097us clock running
  • 2476us from start clock to start clock
  • so an overhead of 379us or 16%

All this would not indicate that we run faster, but maybe that reporting can not do better estimation of the FPS.
If I run mplayer with BigBuckBunny I get the following pattern for updates:

• 
• 23374us for the transfer itself (first CS down to last CS up)
• 50000us between first CS-down and next first CS-down

This means we could fit another full screen update in between, which would bring us to 25ms or 40fps, but that means that this will be about as high as we can go - the big question is: how much other overhead do we have before we can run any updates.

Hope this gives you some insight into what the driver is actually doing...

[notro]

[   75.174103] graphics fb1: fb_s6d02a1 frame buffer, 480x320, 300 KiB video memory, 32 KiB DMA buffer memory, fps=33, spi0.0 at 120 MHz

The fps=33 here is not the measured frame rate. It's a misnomer that really means: we have a delay of HZ/fps=100/33=3 jiffies from the time of the first page touched in videomem until the update kernel thread is woken.
We will get this 33 fps rate if the time to update the display is smaller that what we have with our current display. A 176x220 display would have yielded this framerate for instance.

I tried fps=100 (1 jiffy delay) but got the same measured 25 fps as with fps=50 (2 jiffies).
So this display needs 2 jiffies to get the videomem dirty pages in order between updates.

This is how fbtft works:

• Userspace writes to videomemory
• fbdev deferred io collects page writes and schedules a thread to wake up in HZ/fps jiffies.
• fbtft is woken and turns the changed pages into a start and end line on the display.
• This part of video memory is broken up into txbuflen chunks
• Because the Pi is little endian and the controller interface is big endian, each rgb565 pixel is byte swapped (hence the need for a tx buffer). This is a fixed time between each SPI transfer.

Now SPI takes the buffer, allocates a rx buffer, dma maps buffers and sends them to dma engine.
I don't know how much time is spent on the rx buffer part.

Looking at your numbers I wonder why the overhead goes from 259us to 379us when the speed is doubled. Shouldn't these numbers be more or less the same?

Ideally, fbtft should have dynamically switched to a continous update mode when it detects that all of videomem is updated several times in a row. This could have shaved off the 2 jiffies delay.

I tried increasing txbuflen to 64k, but that gave me some USB errors, and a lousy measured framerate:

[    8.828145] graphics fb1: fb_s6d02a1 frame buffer, 480x320, 300 KiB video memory, 64 KiB DMA buffer memory, fps=50, spi0.0 at 128 MHz

[   66.592321] fb_s6d02a1 spi0.0: Display update: 2506 kB/s (119.647 ms), fps=0 (-628294215.249 ms)
[   66.733336] fb_s6d02a1 spi0.0: Display update: 2485 kB/s (120.690 ms), fps=7 (140.097 ms)
[   66.882983] fb_s6d02a1 spi0.0: Display update: 2299 kB/s (130.443 ms), fps=7 (139.891 ms)
[   67.029706] fb_s6d02a1 spi0.0: Display update: 2359 kB/s (127.151 ms), fps=6 (150.011 ms)
[   67.163600] fb_s6d02a1 spi0.0: Display update: 2494 kB/s (120.249 ms), fps=7 (140.793 ms)
[   67.311376] Transfer to device 4 endpoint 0x1 frame 1657 failed - FIQ reported NYET. Data may have been lost.
[   67.314969] fb_s6d02a1 spi0.0: Display update: 2265 kB/s (132.411 ms), fps=7 (139.203 ms)
[   67.450592] fb_s6d02a1 spi0.0: Display update: 2541 kB/s (118.009 ms), fps=6 (150.010 ms)
[   67.465342] fb_s6d02a1 spi0.0: Display update: 9901 kB/s (2.083 ms), fps=7 (130.686 ms)
[   67.602961] fb_s6d02a1 spi0.0: Display update: 2493 kB/s (120.309 ms), fps=51 (19.392 ms)
[   67.750837] fb_s6d02a1 spi0.0: Display update: 2337 kB/s (128.272 ms), fps=7 (139.910 ms)
[   67.886339] fb_s6d02a1 spi0.0: Display update: 2437 kB/s (123.042 ms), fps=7 (140.730 ms)
[   68.033103] fb_s6d02a1 spi0.0: Display update: 2298 kB/s (130.469 ms), fps=7 (139.334 ms)

Really nice to have access to an analyzer like this. Much easier to make descisions with access to hard facts. I have returned to working on fbtft now, especially the io path, so this is a helpful walkthrough for me.

[msperl]

@notro: Why does it vary?

I have only taken a single example to show the "situation" and did not go over it taking 10s of 100s of samples.

Well, there are lots of factors here - some of them have to do with scheduling and also I know that the first time a code-path is used it is about 70% slower - this has to do with the code being in the different CPU caches - the more often it runs the quicker. So whenever a "thread" is switched CPU everything is slower as it needs to fill the caches...

If you want I can run some more samples and I can send you a link to download the data - the SW itself you can get from the producer of the logic analyzer and you can read the files and analyze them...

But I guess that this is better happening in a different discussion or offline.

[msperl]

note that the patch for the "time estimate" has been accepted already.
the "bugfix" for alternate modes is still pending - you may want to acknowledge it or send "tested-by" to help maybe...

[notro]

Thanks, no need to run more samples. I don't know much about cpu caches and process/thread switching time. Have you tried running the queue with realtime priority (rt=true), what's your experience with that?

[msperl]

Rt does not make a huge difference any longer on a multi-CPU system.

Also the designs of running the spi message pump inline for spi_sync calls when there is no activity makes this somewhat redundant - you would need to run the calling thread with rt priority to make it work.