Re: [PATCH] drm/mgag200: Flush the cache to improve latency

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



On 06/11/2023 11:46, Jocelyn Falempe wrote:
On 23/10/2023 10:30, Jocelyn Falempe wrote:
On 20/10/2023 14:06, Thomas Zimmermann wrote:
(cc'ing lkml for feedback)

Hi Jocelyn

Am 19.10.23 um 15:55 schrieb Jocelyn Falempe:
We found a regression in v5.10 on real-time server, using the
rt-kernel and the mgag200 driver. It's some really specialized
workload, with <10us latency expectation on isolated core.
After the v5.10, the real time tasks missed their <10us latency
when something prints on the screen (fbcon or printk)

I'd like to hear the opinion of the RT-devs on this patch. Because AFAIK we never did such a workaround in other drivers. And AFAIK printk is a PITA anyway.

Most other drivers uses DMA, which means this workaround can't apply to them.


IMHO if that RT system cannot handle differences in framebuffer caching, it's under-powered. It's just a matter of time until something else changes and the problem returns. And (honest question) as it's an x86-64, how do they handle System Management Mode?

I think it's not a big news, that the Matrox G200 from 1999 is under-powered. I was also a bit surprised that flushing the cache would have such effect on latency. The tests we are doing can run 24h with the workaround, without any interrupt taking more than 10us. Without the workaround, every ~30s the interrupt failed its 10us target.



The regression has been bisected to 2 commits:
0b34d58b6c32 ("drm/mgag200: Enable caching for SHMEM pages")
4862ffaec523 ("drm/mgag200: Move vmap out of commit tail")

The first one changed the system memory framebuffer from Write-Combine
to the default caching.
Before the second commit, the mgag200 driver used to unmap the
framebuffer after each frame, which implicitly does a cache flush.
Both regressions are fixed by the following patch, which forces a
cache flush after each frame, reverting to almost v5.9 behavior.

With that second commit, we essentially never unmap an active framebuffer console. But with commit

359c6649cd9a ("drm/gem: Implement shadow-plane {begin, end}_fb_access with vmap")

we now again unmap the console framebuffer after the pageflip happened.

So how does the latest kernel behave wrt to the problem?

The regression was found when upgrading the server from v5.4 to v5.14, so we didn't test with later kernels. We will test with v6.3 (which should have 359c6649cd9a ) and see what it gives.

I don't have a clear explanation, but testing with v6.3, and forcing the Write Combine, doesn't fix the latency issue. So forcing the cache flush is still needed.

Also, on some systems, they use "isolated cpu" to handle RT task, but with a standard kernel (so without the CONFIG_PREEMPT_RT).
So I'm wondering if we can use a kernel module parameter for this,
so that users that wants to achieve low latency, can opt-in ?

something like mgag200.force_cache_flush=1 or mgag200.low_latency=1 ?

Hi,

I have now access to a server that reproduce the issue, and I was able to test different workarounds.

So it is definitely related to the "Write Combine" mode of the mga internal RAM. If I comment the two lines to enable wc: https://elixir.bootlin.com/linux/latest/source/drivers/gpu/drm/mgag200/mgag200_drv.c#L150, then the latency is <10us (but the performances are worse, from 20ms to 87ms to draw a full frame).

I also tried to flush the vram using:
drm_clflush_virt_range(mdev->vram + clip->y1 * fb->pitches[0], drm_rect_height(clip) * fb->pitches[0]);
And that lower the latency to ~20us, but it's not enough.

I tried "sfence" which I though would flush the WC buffers of the CPU, but that has no effect in practice.

I think I can send a new patch, to not map the VRAM as Write Combine, either if CONFIG_PREEMPT_RT is set or if a module parameter is set.
What do you think is the best approach ?



My tests setup:

I either flood the console with "cat /dev/urandom | base64" from the BMC, or write to fb0 with "while true; do dd if=/dev/urandom of=/dev/fb0 ; done"

then I run:

cd /sys/kernel/debug/tracing
echo 0 > tracing_on
echo 950000 > hwlat_detector/width
echo hwlat > current_tracer
echo 10 > tracing_thresh
echo 1 > tracing_on
sleep 300
cat trace
echo 0 > tracing_on
echo nop > current_tracer


Test Results:

V6.6 (~40us latency)

# tracer: hwlat
#
# entries-in-buffer/entries-written: 6/6   #P:56
#
#                                _-----=> irqs-off/BH-disabled
#                               / _----=> need-resched
#                              | / _---=> hardirq/softirq
#                              || / _--=> preempt-depth
#                              ||| / _-=> migrate-disable
#                              |||| /     delay
#           TASK-PID     CPU#  |||||  TIMESTAMP  FUNCTION
#              | |         |   |||||     |         |
<...>-8795 [001] dn... 613.749741: #1 inner/outer(us): 41/41 ts:1702045267.016266287 count:9976 <...>-8804 [000] dn... 675.201727: #2 inner/outer(us): 40/40 ts:1702045328.469859973 count:6506 <...>-8804 [000] dn... 731.435258: #3 inner/outer(us): 40/41 ts:1702045384.704861049 count:9578 <...>-8804 [000] d.... 787.684533: #4 inner/outer(us): 41/41 ts:1702045440.955603974 count:22591 <...>-8804 [000] d.... 844.303041: #5 inner/outer(us): 41/41 ts:1702045497.575594006 count:33324 <...>-8804 [000] d.... 900.494844: #6 inner/outer(us): 40/40 ts:1702045553.768864888 count:1924


V6.6 + clfush mdev->vram (~20us latency)

# tracer: hwlat
#
# entries-in-buffer/entries-written: 3/3   #P:56
#
#                                _-----=> irqs-off/BH-disabled
#                               / _----=> need-resched
#                              | / _---=> hardirq/softirq
#                              || / _--=> preempt-depth
#                              ||| / _-=> migrate-disable
#                              |||| /     delay
#           TASK-PID     CPU#  |||||  TIMESTAMP  FUNCTION
#              | |         |   |||||     |         |
<...>-8983 [001] d.... 534.595415: #1 inner/outer(us): 21/20 ts:1702024432.844243126 count:3018 <...>-8983 [000] dn... 758.560453: #2 inner/outer(us): 21/21 ts:1702024656.824367474 count:22238 <...>-8983 [000] dn... 815.117057: #3 inner/outer(us): 21/21 ts:1702024713.373220580 count:26455


V6.6 + no Write Combine for VRAM (<10us latency)

# tracer: hwlat
#
# entries-in-buffer/entries-written: 0/0   #P:56
#
#                                _-----=> irqs-off/BH-disabled
#                               / _----=> need-resched
#                              | / _---=> hardirq/softirq
#                              || / _--=> preempt-depth
#                              ||| / _-=> migrate-disable
#                              |||| /     delay
#           TASK-PID     CPU#  |||||  TIMESTAMP  FUNCTION
#              | |         |   |||||     |         |


Best regards,

--

Jocelyn




[Index of Archives]     [Linux DRI Users]     [Linux Intel Graphics]     [Linux USB Devel]     [Video for Linux]     [Linux Audio Users]     [Yosemite News]     [Linux Kernel]     [Linux SCSI]     [XFree86]     [Linux USB Devel]     [Video for Linux]     [Linux Audio Users]     [Linux Kernel]     [Linux SCSI]     [XFree86]
  Powered by Linux