Groups > linux.debian.kernel > #63684 > unrolled thread

Bug#925334: vc4: CMA fills up and screen not updated anymore on raspi3

Started by	Fabian Pietsch <fabian-debian@canvon.de>
First post	2019-03-23 12:10 +0100
Last post	2019-04-03 15:30 +0200
Articles	5 — 2 participants

Back to article view | Back to linux.debian.kernel

  Bug#925334: vc4: CMA fills up and screen not updated anymore on raspi3 Fabian Pietsch <fabian-debian@canvon.de> - 2019-03-23 12:10 +0100
    Bug#925334: vc4: CMA fills up and screen not updated anymore on raspi3 Fabian Pietsch <fabian-debian@canvon.de> - 2019-03-27 15:40 +0100
      Bug#925334: vc4: CMA fills up and screen not updated anymore on raspi3 Romain Perier <romain.perier@gmail.com> - 2019-03-27 21:40 +0100
        Bug#925334: vc4: CMA fills up and screen not updated anymore on raspi3 Fabian Pietsch <fabian-debian@canvon.de> - 2019-04-03 12:40 +0200
          Bug#925334: vc4: CMA fills up and screen not updated anymore on raspi3 Fabian Pietsch <fabian-debian@canvon.de> - 2019-04-03 15:30 +0200

#63684 — Bug#925334: vc4: CMA fills up and screen not updated anymore on raspi3

From	Fabian Pietsch <fabian-debian@canvon.de>
Date	2019-03-23 12:10 +0100
Subject	Bug#925334: vc4: CMA fills up and screen not updated anymore on raspi3
Message-ID	<xEMHf-3Cj-1@gated-at.bofh.it>

Package: src:linux
Version: 4.19.16-1
Severity: important
Tags: upstream

Dear Maintainer,

(please also see the additional information in the footnotes below.)

When using the vc4 video driver with Xorg on the Raspberry Pi 3 [raspi3],
it seems to sooner or later fill up the CMA, leading to, e.g., this:

[  739.307920] [drm:vc4_bo_create [vc4]] *ERROR* Failed to allocate from CMA:
[  739.314932] [drm]                            V3D:  23468kb BOs (10)
[  739.321333] [drm]                     V3D shader:    144kb BOs (35)
[  739.327734] [drm]                           dumb:   8148kb BOs (4)

When additionally the following happens, the screen stops updating
until reboot [stops_updating]:

[  739.334049] vc4_v3d 3fc00000.v3d: Failed to allocate memory for tile binning: -12. You may need to enable CMA or give it more memory.

This happens with cma=64M, cma=128M and cma=256M, though 128M seems to
be the recommended size for vc4 use, according to comments in
package raspi3-firmware's /etc/default/raspi3-firmware.

ii  raspi3-firmware 1.20190215-1 arm64        Raspberry Pi 2 and 3 GPU firmware and bootloaders

With cma=128M, the error happens on a freshly booted, idle system
running lightdm, after perhaps 10m-30m, or can be provoked by
running a [screensaver].

A work-around is to force Xorg to use driver fbdev, which seems to work
even after the tile binning error which otherwise would have required
a reboot.


I also get a lot of, e.g.:

[  739.135918] alloc_contig_range: [37400, 38400) PFNs busy

I don't know if this is related or a different problem.


Please somehow make it possible (or even automatic) for the screen
update to continue without the need for a reboot. Fixes to CMA handling
so that the tile binning error doesn't even happen anymore would be
even better!

Regards, Fabian

(Please also see the footnotes below.)


[raspi3]
This machine was set up based on a Raspberry Pi 3 Debian buster preview
image, from https://wiki.debian.org/RaspberryPi3 ; it says
unofficial/unsupported, there, I hope this bug report still is ok
as, as far as I understand, the unmodified Debian buster arm64 kernel
seems to be used[1].

[1] Pulled in via apt from official mirror in sources.list:
    https://github.com/Debian/raspi3-image-spec/blob/master/raspi3.yaml#L72


[stops_updating] "Stops updating the screen" here means that the
Xorg tty graphical contents don't change anymore, except for the
mouse cursor. The mouse cursor can still be moved around, and even
changes form on, e.g., window borders, and I can resize the terminal
window up one line, and the cursor change on mouseover reflects
the change; just nothing changes to the non-mousecursor visual picture.

Also, tasking into console works fine, and tasking back into the Xorg
tty restores the previous visual picture, and tasking back into the
console again is also still possible. So no real "freeze" or hard crash,
here, except that, after the tile binning error in dmesg, the Xorg
tty graphical contents don't change (except for mouse cursor).


[screensaver] The error can be provoked by running the following
for some time:

  /usr/lib/xscreensaver/tessellimage -root -fill-screen

This leads to a slightly different pattern of dmesg messages, though.
The thing in common is that the screen stops updating, there, too,
when the tile binning error quoted above happens.

When provoked in this way, "grep ^CmaFree: /proc/meminfo" in a loop
said 25564 kB directly before a tile binning error message, 7160 kB
directly after, with values between 8000-10000 kB after, with
recovery to 81740 kB after exiting tessellimage. But the screen update
stays stopped.


Additional dmesg output:

[    0.000000] Booting Linux on physical CPU 0x0000000000 [0x410fd034]
[    0.000000] Linux version 4.19.0-2-arm64 (debian-kernel@lists.debian.org) (gcc version 8.2.0 (Debian 8.2.0-14)) #1 SMP Debian 4.19.16-1 (2019-01-17)
[    0.000000] Machine model: Raspberry Pi 3 Model B Rev 1.2
[...]
[    0.000000] cma: Reserved 128 MiB at 0x0000000033400000
[...]
[    0.000000] Memory: 780176K/970752K available (8700K kernel code, 1600K rwdata, 2788K rodata, 4864K init, 530K bss, 59504K reserved, 131072K cma-reserved)
[...]
[    0.000193] Console: colour dummy device 80x25
[    0.000682] console [tty0] enabled
[...]
[    0.141070] simple-framebuffer 3e887000.framebuffer: framebuffer at 0x3e887000, 0x373800 bytes, mapped to 0x(____ptrval____)
[    0.141106] simple-framebuffer 3e887000.framebuffer: format=r5g6b5, mode=1824x984x16, linelength=3648
[    0.162242] Console: switching to colour frame buffer device 228x61
[    0.182688] simple-framebuffer 3e887000.framebuffer: fb0: simplefb registered!
[...]
[    4.768075] raspberrypi-firmware soc:firmware: Attached to firmware from 2019-02-12 19:42
[...]
[   11.863850] vc4_hdmi 3f902000.hdmi: ASoC: Failed to create component debugfs directory
[   11.921037] vc4_hdmi 3f902000.hdmi: vc4-hdmi-hifi <-> 3f902000.hdmi mapping ok
[   11.945385] vc4_hdmi 3f902000.hdmi: ASoC: no DMI vendor name!
[   11.979202] vc4-drm soc:gpu: bound 3f902000.hdmi (ops vc4_hdmi_ops [vc4])
[   12.004926] vc4-drm soc:gpu: bound 3f806000.vec (ops vc4_vec_ops [vc4])
[   12.035507] vc4-drm soc:gpu: bound 3f004000.txp (ops vc4_txp_ops [vc4])
[   12.086726] vc4-drm soc:gpu: bound 3f400000.hvs (ops vc4_hvs_ops [vc4])
[   12.169266] vc4-drm soc:gpu: bound 3f206000.pixelvalve (ops vc4_crtc_ops [vc4])
[   12.186736] vc4-drm soc:gpu: bound 3f207000.pixelvalve (ops vc4_crtc_ops [vc4])
[   12.203918] vc4-drm soc:gpu: bound 3f807000.pixelvalve (ops vc4_crtc_ops [vc4])
[   12.248590] vc4-drm soc:gpu: bound 3fc00000.v3d (ops vc4_v3d_ops [vc4])
[   12.270202] checking generic (3e887000 373800) vs hw (0 ffffffffffffffff)
[   12.270219] fb: switching to vc4drmfb from simple
[   12.286291] Console: switching to colour dummy device 80x25
[   12.295210] [drm] Initialized vc4 0.0.0 20140616 for soc:gpu on minor 0
[   12.302047] [drm] Supports vblank timestamp caching Rev 2 (21.10.2013).
[   12.308858] [drm] Driver supports precise vblank timestamp query.
[   12.373775] Console: switching to colour frame buffer device 240x67
[   12.447976] vc4-drm soc:gpu: fb0: DRM emulated frame buffer device


Some excerpts from /var/log/Xorg.0.log:

[    17.868] (II) xfree86: Adding drm device (/dev/dri/card0)
[    17.886] (II) no primary bus or device found
[    17.886] 	falling back to /sys/devices/platform/soc/soc:gpu/drm/card0
[...]
[    18.011] (II) Loading /usr/lib/xorg/modules/drivers/modesetting_drv.so
[...]
[    18.101] (II) modeset(0): using drv /dev/dri/card0
[...]
[    20.654] (II) modeset(0): [DRI2] Setup complete
[    20.654] (II) modeset(0): [DRI2]   DRI driver: vc4
[    20.654] (II) modeset(0): [DRI2]   VDPAU driver: vc4


-- Package-specific info:
** Version:
Linux version 4.19.0-2-arm64 (debian-kernel@lists.debian.org) (gcc version 8.2.0 (Debian 8.2.0-14)) #1 SMP Debian 4.19.16-1 (2019-01-17)

** Command line:
bcm2708_fb.fbwidth=1824 bcm2708_fb.fbheight=984 bcm2708_fb.fbswap=1 dma.dmachans=0x7f35 bcm2709.boardrev=0xa02082 bcm2709.serial=[...] bcm2709.uart_clock=48000000 smsc95xx.macaddr=[...] vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000  console=tty0 console=ttyS1,115200 root=/dev/mmcblk0p2 rw elevator=deadline fsck.repair=yes net.ifnames=0 cma=128M rootwait

** Tainted: C (1024)
 * Module from drivers/staging has been loaded.

** Kernel log:
[  499.856555] alloc_contig_range: [37000, 38200) PFNs busy
[  499.863352] alloc_contig_range: [37000, 38300) PFNs busy
[  499.869842] alloc_contig_range: [37400, 38400) PFNs busy
[  559.875179] alloc_contig_range: 39 callbacks suppressed
[  559.875191] alloc_contig_range: [35700, 36700) PFNs busy
[  559.887274] alloc_contig_range: [36c00, 37c00) PFNs busy
[  559.893765] alloc_contig_range: [36c00, 37d00) PFNs busy
[  559.900465] alloc_contig_range: [36c00, 37e00) PFNs busy
[  559.907193] alloc_contig_range: [36c00, 37f00) PFNs busy
[  559.913667] alloc_contig_range: [37000, 38000) PFNs busy
[  559.920236] alloc_contig_range: [37000, 38100) PFNs busy
[  559.927035] alloc_contig_range: [37000, 38200) PFNs busy
[  559.933560] alloc_contig_range: [37000, 38300) PFNs busy
[  559.940087] alloc_contig_range: [37400, 38400) PFNs busy
[  619.945816] alloc_contig_range: 39 callbacks suppressed
[  619.945828] alloc_contig_range: [35700, 36700) PFNs busy
[  680.002416] alloc_contig_range: [35700, 36700) PFNs busy
[  680.009068] alloc_contig_range: [36c00, 37c00) PFNs busy
[  680.016136] alloc_contig_range: [36c00, 37d00) PFNs busy
[  680.022796] alloc_contig_range: [36c00, 37e00) PFNs busy
[  680.029539] alloc_contig_range: [36c00, 37f00) PFNs busy
[  680.036234] alloc_contig_range: [37000, 38000) PFNs busy
[  680.042956] alloc_contig_range: [37000, 38100) PFNs busy
[  680.049597] alloc_contig_range: [37000, 38200) PFNs busy
[  680.056322] alloc_contig_range: [37000, 38300) PFNs busy
[  680.063057] alloc_contig_range: [37400, 38400) PFNs busy
[  739.070013] alloc_contig_range: 39 callbacks suppressed
[  739.070022] alloc_contig_range: [35700, 36700) PFNs busy
[  739.082093] alloc_contig_range: [36c00, 37c00) PFNs busy
[  739.088787] alloc_contig_range: [36c00, 37d00) PFNs busy
[  739.095577] alloc_contig_range: [36c00, 37e00) PFNs busy
[  739.102204] alloc_contig_range: [36c00, 37f00) PFNs busy
[  739.109079] alloc_contig_range: [37000, 38000) PFNs busy
[  739.115811] alloc_contig_range: [37000, 38100) PFNs busy
[  739.122455] alloc_contig_range: [37000, 38200) PFNs busy
[  739.129163] alloc_contig_range: [37000, 38300) PFNs busy
[  739.135918] alloc_contig_range: [37400, 38400) PFNs busy
[  739.307920] [drm:vc4_bo_create [vc4]] *ERROR* Failed to allocate from CMA:
[  739.314932] [drm]                            V3D:  23468kb BOs (10)
[  739.321333] [drm]                     V3D shader:    144kb BOs (35)
[  739.327734] [drm]                           dumb:   8148kb BOs (4)
[  739.334049] vc4_v3d 3fc00000.v3d: Failed to allocate memory for tile binning: -12. You may need to enable CMA or give it more memory.
[ 2779.449085] alloc_contig_range: 164 callbacks suppressed
[ 2779.449094] alloc_contig_range: [334c4, 334c5) PFNs busy
[ 3139.868509] alloc_contig_range: [334cc, 334cd) PFNs busy
[ 3799.628926] alloc_contig_range: [33463, 33464) PFNs busy
[ 7699.127567] alloc_contig_range: [334c4, 334c5) PFNs busy
[ 7879.339150] alloc_contig_range: [334c4, 334c5) PFNs busy
[ 7939.408956] alloc_contig_range: [334c4, 334c5) PFNs busy
[ 8059.540487] alloc_contig_range: [33598, 3359b) PFNs busy
[ 8119.611432] alloc_contig_range: [334c4, 334c5) PFNs busy
[ 8419.954991] alloc_contig_range: [33598, 3359b) PFNs busy
[10099.896326] alloc_contig_range: [334c4, 334c5) PFNs busy
[10159.965596] alloc_contig_range: [334c4, 334c5) PFNs busy
[12499.678935] alloc_contig_range: [334da, 334db) PFNs busy
[12499.684911] alloc_contig_range: [334df, 334e0) PFNs busy
[12499.690877] alloc_contig_range: [334f6, 334f7) PFNs busy
[12739.956325] alloc_contig_range: [334da, 334db) PFNs busy
[12739.962453] alloc_contig_range: [334df, 334e0) PFNs busy
[12739.968356] alloc_contig_range: [334f6, 334f7) PFNs busy
[12739.974391] alloc_contig_range: [334ff, 33500) PFNs busy
[14600.107691] alloc_contig_range: [334db, 334dc) PFNs busy
[15259.872721] alloc_contig_range: [334db, 334dc) PFNs busy
[15319.944302] alloc_contig_range: [334db, 334dc) PFNs busy
[15440.090589] alloc_contig_range: [334db, 334dc) PFNs busy
[15500.155237] alloc_contig_range: [334db, 334dc) PFNs busy
[15559.222890] alloc_contig_range: [334db, 334dc) PFNs busy
[18920.093345] alloc_contig_range: [33462, 33463) PFNs busy
[19459.711617] alloc_contig_range: [33462, 33463) PFNs busy
[19639.918652] alloc_contig_range: [33462, 33463) PFNs busy
[22999.805126] alloc_contig_range: [334c2, 334c3) PFNs busy
[25099.228929] alloc_contig_range: [334c2, 334c3) PFNs busy
[25279.448616] alloc_contig_range: [334c2, 334c3) PFNs busy
[25279.454520] alloc_contig_range: [334cc, 334cd) PFNs busy
[26899.324100] alloc_contig_range: [334c2, 334c3) PFNs busy
[27799.364929] alloc_contig_range: [334db, 334dc) PFNs busy
[32119.349649] alloc_contig_range: [33594, 33597) PFNs busy
[32599.899617] alloc_contig_range: [33594, 33597) PFNs busy
[32899.242481] alloc_contig_range: [33594, 33597) PFNs busy
[34520.147440] alloc_contig_range: [334cd, 334ce) PFNs busy
[34699.355995] alloc_contig_range: [334cd, 334ce) PFNs busy
[34699.361890] alloc_contig_range: [334ce, 334cf) PFNs busy
[44179.322839] alloc_contig_range: [334c6, 334c8) PFNs busy
[44179.340656] alloc_contig_range: [334c2, 334c3) PFNs busy
[45019.306823] alloc_contig_range: [334c2, 334c3) PFNs busy
[45499.861134] alloc_contig_range: [334c2, 334c3) PFNs busy
[47540.239970] alloc_contig_range: [334c2, 334c3) PFNs busy
[47719.440460] alloc_contig_range: [334c2, 334c3) PFNs busy
[47839.579705] alloc_contig_range: [334c2, 334c3) PFNs busy
[48019.789629] alloc_contig_range: [334c2, 334c3) PFNs busy
[48079.859404] alloc_contig_range: [334c2, 334c3) PFNs busy
[51080.327733] alloc_contig_range: [334cc, 334cd) PFNs busy
[51139.390146] alloc_contig_range: [334cc, 334cd) PFNs busy
[51199.460320] alloc_contig_range: [334cc, 334cd) PFNs busy
[55639.751738] alloc_contig_range: [334da, 334db) PFNs busy
[56780.097567] alloc_contig_range: [33463, 33464) PFNs busy
[61100.175987] alloc_contig_range: [334c2, 334c3) PFNs busy
[61880.082259] alloc_contig_range: [334c2, 334c3) PFNs busy
[62120.364473] alloc_contig_range: [334d8, 334d9) PFNs busy
[62720.061227] alloc_contig_range: [334cc, 334cd) PFNs busy

** Model information
Device Tree model: Raspberry Pi 3 Model B Rev 1.2

** Loaded modules:
fuse
appletalk
psnap
llc
ip6t_REJECT
nf_reject_ipv6
nft_counter
ipt_REJECT
nf_reject_ipv4
xt_tcpudp
xt_comment
nft_compat
nf_tables
nfnetlink
nls_ascii
nls_cp437
vfat
fat
joydev
evdev
vc4
hid_microsoft
snd_soc_core
hid_generic
snd_pcm_dmaengine
snd_pcm
brcmfmac
snd_timer
brcmutil
smsc95xx
cfg80211
snd
usbnet
usbhid
mii
soundcore
hid
cec
rfkill
drm_kms_helper
drm
vchiq(C)
bcm2835_thermal
pwm_bcm2835
bcm2835_rng
rng_core
bcm2835_wdt
leds_gpio
ip_tables
x_tables
autofs4
ext4
crc16
mbcache
jbd2
crc32c_generic
fscrypto
ecb
aes_arm64
dwc2
udc_core
usbcore
sdhci_iproc
sdhci_pltfm
usb_common
sdhci
bcm2835
i2c_bcm2835
phy_generic

** PCI devices:
not available

** USB devices:
not available


-- System Information:
Debian Release: buster/sid
  APT prefers testing
  APT policy: (500, 'testing')
Architecture: arm64 (aarch64)

Kernel: Linux 4.19.0-2-arm64 (SMP w/4 CPU cores)
Kernel taint flags: TAINT_CRAP
Locale: LANG=en_GB.UTF-8, LC_CTYPE=en_GB.UTF-8 (charmap=UTF-8), LANGUAGE=en_GB.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /usr/bin/dash
Init: systemd (via /run/systemd/system)
LSM: AppArmor: enabled

Versions of packages linux-image-4.19.0-2-arm64 depends on:
ii  initramfs-tools [linux-initramfs-tool]  0.133
ii  kmod                                    26-1
ii  linux-base                              4.5

Versions of packages linux-image-4.19.0-2-arm64 recommends:
ii  apparmor             2.13.2-9
ii  firmware-linux-free  3.4
ii  irqbalance           1.5.0-3

Versions of packages linux-image-4.19.0-2-arm64 suggests:
pn  debian-kernel-handbook  <none>
ii  linux-doc-4.19          4.19.16-1

Versions of packages linux-image-4.19.0-2-arm64 is related to:
pn  firmware-amd-graphics     <none>
pn  firmware-atheros          <none>
pn  firmware-bnx2             <none>
pn  firmware-bnx2x            <none>
ii  firmware-brcm80211        20190114-1
pn  firmware-cavium           <none>
pn  firmware-intel-sound      <none>
pn  firmware-intelwimax       <none>
pn  firmware-ipw2x00          <none>
pn  firmware-ivtv             <none>
pn  firmware-iwlwifi          <none>
pn  firmware-libertas         <none>
pn  firmware-linux-nonfree    <none>
pn  firmware-misc-nonfree     <none>
pn  firmware-myricom          <none>
pn  firmware-netxen           <none>
pn  firmware-qlogic           <none>
pn  firmware-realtek          <none>
pn  firmware-samsung          <none>
pn  firmware-siano            <none>
pn  firmware-ti-connectivity  <none>
pn  xen-hypervisor            <none>

-- no debconf information

[toc] | [next] | [standalone]

#63702

From	Fabian Pietsch <fabian-debian@canvon.de>
Date	2019-03-27 15:40 +0100
Message-ID	<xGhSF-1fz-9@gated-at.bofh.it>
In reply to	#63684

Package: src:linux
Version: 4.19.28-2
Followup-For: Bug #925334

Dear Maintainer,

the bug is still present in the current version. It took a freshly
booted, idle system 3304 seconds for the bug to occur, though,
so this time rather an hour (than 10-30min as stated before).

After the bug has happened, I get the following information from sysfs:

| root@rpi3:/sys/bus/platform/drivers/vc4_v3d# for I in enabled status active_time suspended_time; do echo -n "$I=$(cat 3fc00000.v3d/power/runtime_$I) "; done; echo
| enabled=enabled status=error active_time=16800 suspended_time=55464216

And again:

| enabled=enabled status=error active_time=16800 suspended_time=55479160

So vc4_v3d which reported the error seems to be in status=error
and counts as suspended. Manual attempts to get it to resume again,
now that more cma is free again, failed, but there are probably ways
I don't know about.

"echo on > .../power/control" changed runtime_enabled=forbidden
(and echo auto > control changed it back to runtime_enabled=enabled),
but runtime_status remained at "error".

Regards, Fabian


-- System Information:
Debian Release: buster/sid
  APT prefers testing
  APT policy: (500, 'testing')
Architecture: arm64 (aarch64)

Kernel: Linux 4.19.0-4-arm64 (SMP w/4 CPU cores)
Kernel taint flags: TAINT_CRAP
Locale: LANG=en_GB.UTF-8, LC_CTYPE=en_GB.UTF-8 (charmap=UTF-8), LANGUAGE=en_GB.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /usr/bin/dash
Init: systemd (via /run/systemd/system)
LSM: AppArmor: enabled

[toc] | [prev] | [next] | [standalone]

#63705

From	Romain Perier <romain.perier@gmail.com>
Date	2019-03-27 21:40 +0100
Message-ID	<xGnv4-4G3-13@gated-at.bofh.it>
In reply to	#63702

[Multipart message — attachments visible in raw view] — view raw

On Wed, Mar 27, 2019 at 03:29:21PM +0100, Fabian Pietsch wrote:
> Package: src:linux
> Version: 4.19.28-2
> Followup-For: Bug #925334
> 
> Dear Maintainer,
> 
> the bug is still present in the current version. It took a freshly
> booted, idle system 3304 seconds for the bug to occur, though,
> so this time rather an hour (than 10-30min as stated before).
> 
> After the bug has happened, I get the following information from sysfs:
> 
> | root@rpi3:/sys/bus/platform/drivers/vc4_v3d# for I in enabled status active_time suspended_time; do echo -n "$I=$(cat 3fc00000.v3d/power/runtime_$I) "; done; echo
> | enabled=enabled status=error active_time=16800 suspended_time=55464216
> 
> And again:
> 
> | enabled=enabled status=error active_time=16800 suspended_time=55479160
> 
> So vc4_v3d which reported the error seems to be in status=error
> and counts as suspended. Manual attempts to get it to resume again,
> now that more cma is free again, failed, but there are probably ways
> I don't know about.
> 
> "echo on > .../power/control" changed runtime_enabled=forbidden
> (and echo auto > control changed it back to runtime_enabled=enabled),
> but runtime_status remained at "error".
> 
> Regards, Fabian
> 
> 
> -- System Information:
> Debian Release: buster/sid
>   APT prefers testing
>   APT policy: (500, 'testing')
> Architecture: arm64 (aarch64)
> 
> Kernel: Linux 4.19.0-4-arm64 (SMP w/4 CPU cores)
> Kernel taint flags: TAINT_CRAP
> Locale: LANG=en_GB.UTF-8, LC_CTYPE=en_GB.UTF-8 (charmap=UTF-8), LANGUAGE=en_GB.UTF-8 (charmap=UTF-8)
> Shell: /bin/sh linked to /usr/bin/dash
> Init: systemd (via /run/systemd/system)
> LSM: AppArmor: enabled

Hi,

As discussed on IRC, thanks for your bug report and for the refresh.

Could you test, two stuffs for me ? :

1. The VC4 driver seems to use runtime pm operations, could you try to
disable runtime suspend completly (there are kernel parameters for this
if I remember correctly) ?

2. Your kernel cmdline are... weird, could you try with minimalistic
kernel cmdline ? Only keep console= for logging to uart and/or to your
tty0 and keep your rootfs.


Thanks,
Romain

[toc] | [prev] | [next] | [standalone]

#63756

From	Fabian Pietsch <fabian-debian@canvon.de>
Date	2019-04-03 12:40 +0200
Message-ID	<xILtg-3gU-11@gated-at.bofh.it>
In reply to	#63705

Hi,

* Romain Perier (Wed, 27 Mar 2019 21:33:19 +0100):
> Return-Path: <romain.perier@gmail.com>
> Message-ID: <20190327203319.GA15993@debby.home>
> From: Romain Perier <romain.perier@gmail.com>
> Subject: Re: Bug#925334: vc4: CMA fills up and screen not updated anymore
>  on raspi3
> To: Fabian Pietsch <fabian-debian@canvon.de>, 925334@bugs.debian.org
> User-Agent: Mutt/1.10.1 (2018-07-13)
> 
> On Wed, Mar 27, 2019 at 03:29:21PM +0100, Fabian Pietsch wrote:

[...]

> > the bug is still present in the current version. It took a freshly
> > booted, idle system 3304 seconds for the bug to occur, though,
> > so this time rather an hour (than 10-30min as stated before).

[...]

> > So vc4_v3d which reported the error seems to be in status=error
> > and counts as suspended. Manual attempts to get it to resume again,
> > now that more cma is free again, failed, but there are probably ways
> > I don't know about.

[...]

> Could you test, two stuffs for me ? :
> 
> 1. The VC4 driver seems to use runtime pm operations, could you try to
> disable runtime suspend completly (there are kernel parameters for this
> if I remember correctly) ?

Didn't find anything useful to that regard in linux-doc Documentation/
and by googling. Could you please tell me how?

> 2. Your kernel cmdline are... weird, could you try with minimalistic
> kernel cmdline ? Only keep console= for logging to uart and/or to your
> tty0 and keep your rootfs.

The initial part until the two spaces seems to be auto-generated by the
firmware at boot, so I guess I can't change or suppress it; if it should
be possible, again, please tell me how.

My kernel cmdline as passed *to* the firmware is:

| fabian@rpi3:~$ cat /boot/firmware/cmdline.txt
| console=tty0 console=ttyS1,115200 root=/dev/mmcblk0p2 rw elevator=deadline fsck.repair=yes net.ifnames=0 cma=128M rootwait

This is just auto-generated by the raspi3-firmware package to which
you (Romain Perier) seem to be contributing.

As suggested, I tested more compact cmdline.txt, though:

| root=/dev/mmcblk0p2

| console=tty0 root=/dev/mmcblk0p2

| console=tty0 root=/dev/mmcblk0p2 cma=128M

With the first two, cma defaulted to 64M and already the lightdm login
screen stops updating after a few seconds to minutes. With the 3rd,
the bug initially didn't happen so I used X a bit, then logged out and
let the system fall idle; the bug then seems to have happened
9868 seconds after boot (according to dmesg --follow).

Regards, Fabian

-- 
Fabian "canvon" Pietsch - https://www.canvon.de/

[toc] | [prev] | [next] | [standalone]

#63757

From	Fabian Pietsch <fabian-debian@canvon.de>
Date	2019-04-03 15:30 +0200
Message-ID	<xIO7L-4UW-1@gated-at.bofh.it>
In reply to	#63756

Hi,


* Fabian Pietsch (Wed, 03 Apr 2019 12:30:01 +0200):
> As suggested, I tested more compact cmdline.txt, though:
> 
> | root=/dev/mmcblk0p2
> 
> | console=tty0 root=/dev/mmcblk0p2
> 
> | console=tty0 root=/dev/mmcblk0p2 cma=128M
> 
> With the first two, cma defaulted to 64M and already the lightdm login
> screen stops updating after a few seconds to minutes. With the 3rd,
> the bug initially didn't happen so I used X a bit, then logged out and
> let the system fall idle; the bug then seems to have happened
> 9868 seconds after boot (according to dmesg --follow).

Another round (system mostly idle except for manually renaming enx[...]
to eth0 after boot and restarting wicd, which came with lxde meta-package
to manage the networking, to get a correct system time via NTP)  ->
3960 seconds after boot (in dmesg). That seems to suggest to me that
the cmdline.txt built by raspi3-firmware was not the issue, here.
Still don't know whether it's possible or sensible to disable the
"weird" initial cmdline passed by the firmware, though.

In any case, the tile binning error ...

| kernel: vc4_v3d 3fc00000.v3d: Failed to allocate memory for tile binning: -12. You may need to enable CMA or give it more memory.

... together with a preceding, e.g., ...

| kernel: [drm:vc4_bo_create [vc4]] *ERROR* Failed to allocate from CMA:
| kernel: [drm]                            V3D:  23468kb BOs (10)
| kernel: [drm]                     V3D shader:    144kb BOs (35)
| kernel: [drm]                           dumb:   8148kb BOs (4)

... is usually surrounded (in journal) by nothing but many:

| kernel: alloc_contig_range: [36400, 37500) PFNs busy

What I'm trying to say is that there seems to be no log-noticeable
concurrent activity going on.  Watching the CMA use via /proc/meminfo
suggests that it's much more than half free, most of the time.
The tile binning error seems to be entirely random, at this point.


Looking at the source[1], vc4_allocate_bin_bo() seems to use a strategy
of successively allocating memory until it randomly finds a block that
fits certain requirements. Maybe randomly sometimes there is no such
block available, leading to it failing with -ENOMEM. It's not clear
to me, though, when and why the function is called, seemingly randomly
on an idle system. It reads to me as an initialization, not something
that is randomly repeated. (?)

[1] https://sources.debian.org/src/linux/4.19.28-2/drivers/gpu/drm/vc4/vc4_v3d.c/#L244


Again, it would be nice if the resulting device error state could
somehow be reset / the function retried with more/different CMA free
at a later point during the same boot. Perhaps that's already possible
(maybe even in a general way?) but I don't know how.

(Trying to unbind the driver (vc4_v3d) via sysfs led to a kernel oops
(IIRC paging fault?), and an attempt to bind it again was rejected
without any noticeable action.)


Regards, Fabian

-- 
Fabian "canvon" Pietsch - https://www.canvon.de/

[toc] | [prev] | [standalone]

csiph-web

Bug#925334: vc4: CMA fills up and screen not updated anymore on raspi3

Contents

#63684 — Bug#925334: vc4: CMA fills up and screen not updated anymore on raspi3

#63702

#63705

#63756

#63757