Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Framebuffer : Vblank timeout #9

Closed
Miouyouyou opened this issue Jul 22, 2018 · 24 comments
Closed

Framebuffer : Vblank timeout #9

Miouyouyou opened this issue Jul 22, 2018 · 24 comments

Comments

@Miouyouyou
Copy link
Owner

On some configurations, the framebuffer fails to initialize the screen correctly.

It seems that the problem started to occur since some 4.16-rcX version.
In such events, the system boots fine and X11 starts without issues.

So it's highly probable that this is a framebuffer related issue.

[    1.277829] WARNING: CPU: 2 PID: 102 at drivers/gpu/drm/drm_atomic_helper.c:1349 drm_atomic_helper_wait_for_vblanks+0x1c8/0x1e0
[    1.277831] [CRTC:30:crtc-0] vblank wait timed out
[    1.277833] Modules linked in:
[    1.277840] CPU: 2 PID: 102 Comm: kworker/2:4 Not tainted 4.16.0-RockMyy-16Bits-Edition #1
[    1.277842] Hardware name: Rockchip (Device Tree)
[    1.277848] Workqueue: events deferred_probe_work_func
[    1.277860] [<c010f664>] (unwind_backtrace) from [<c010b7d4>] (show_stack+0x10/0x14)
[    1.277868] [<c010b7d4>] (show_stack) from [<c0c711c4>] (dump_stack+0x70/0x8c)
[    1.277875] [<c0c711c4>] (dump_stack) from [<c011f278>] (__warn+0xdc/0xfc)
[    1.277881] [<c011f278>] (__warn) from [<c011f2cc>] (warn_slowpath_fmt+0x34/0x44)
[    1.277887] [<c011f2cc>] (warn_slowpath_fmt) from [<c070b318>] (drm_atomic_helper_wait_for_vblanks+0x1c8/0x1e0)
[    1.277894] [<c070b318>] (drm_atomic_helper_wait_for_vblanks) from [<c070cc80>] (drm_atomic_helper_commit_tail_rpm+0x48/0x58)
[    1.277900] [<c070cc80>] (drm_atomic_helper_commit_tail_rpm) from [<c070cb04>] (commit_tail+0x40/0x6c)
[    1.277904] [<c070cb04>] (commit_tail) from [<c070cc2c>] (drm_atomic_helper_commit+0xf4/0x100)
[    1.277910] [<c070cc2c>] (drm_atomic_helper_commit) from [<c070ed50>] (restore_fbdev_mode_atomic+0x7c/0x1b4)
[    1.277917] [<c070ed50>] (restore_fbdev_mode_atomic) from [<c07115a8>] (drm_fb_helper_restore_fbdev_mode_unlocked+0x48/0x7c)
[    1.277923] [<c07115a8>] (drm_fb_helper_restore_fbdev_mode_unlocked) from [<c0711628>] (drm_fb_helper_set_par+0x4c/0x5c)
[    1.277929] [<c0711628>] (drm_fb_helper_set_par) from [<c06a8eec>] (fbcon_init+0x2cc/0x45c)
[    1.277937] [<c06a8eec>] (fbcon_init) from [<c06df5d8>] (visual_init+0xc0/0x110)
[    1.277943] [<c06df5d8>] (visual_init) from [<c06e0db4>] (do_bind_con_driver+0x258/0x2d4)
[    1.277947] [<c06e0db4>] (do_bind_con_driver) from [<c06e1188>] (do_take_over_console+0x158/0x19c)
[    1.277952] [<c06e1188>] (do_take_over_console) from [<c06a90cc>] (do_fbcon_takeover+0x50/0xc0)
[    1.277958] [<c06a90cc>] (do_fbcon_takeover) from [<c013c7a4>] (notifier_call_chain+0x44/0x68)
[    1.277964] [<c013c7a4>] (notifier_call_chain) from [<c013ca20>] (__blocking_notifier_call_chain+0x40/0x58)
[    1.277970] [<c013ca20>] (__blocking_notifier_call_chain) from [<c013ca4c>] (blocking_notifier_call_chain+0x14/0x1c)
[    1.277977] [<c013ca4c>] (blocking_notifier_call_chain) from [<c06a1a88>] (register_framebuffer+0x5c/0x268)
[    1.277984] [<c06a1a88>] (register_framebuffer) from [<c0711278>] (__drm_fb_helper_initial_config_and_unlock+0x2b0/0x344)
[    1.277991] [<c0711278>] (__drm_fb_helper_initial_config_and_unlock) from [<c073a268>] (rockchip_drm_fbdev_init+0xa0/0x104)
[    1.277996] [<c073a268>] (rockchip_drm_fbdev_init) from [<c0735d88>] (rockchip_drm_bind+0x158/0x1cc)
[    1.278002] [<c0735d88>] (rockchip_drm_bind) from [<c0749a70>] (try_to_bring_up_master+0x68/0x158)
[    1.278008] [<c0749a70>] (try_to_bring_up_master) from [<c0749d88>] (component_master_add_with_match+0xa8/0xe0)
[    1.278014] [<c0749d88>] (component_master_add_with_match) from [<c0735fb0>] (rockchip_drm_platform_probe+0x1b4/0x204)
[    1.278019] [<c0735fb0>] (rockchip_drm_platform_probe) from [<c07505a8>] (platform_drv_probe+0x50/0x9c)
[    1.278025] [<c07505a8>] (platform_drv_probe) from [<c074ebc4>] (driver_probe_device+0x240/0x308)
[    1.278029] [<c074ebc4>] (driver_probe_device) from [<c074d410>] (bus_for_each_drv+0x84/0x8c)
[    1.278034] [<c074d410>] (bus_for_each_drv) from [<c074e8f8>] (__device_attach+0x98/0x100)
[    1.278039] [<c074e8f8>] (__device_attach) from [<c074deb8>] (bus_probe_device+0x28/0x80)
[    1.278043] [<c074deb8>] (bus_probe_device) from [<c074e3e4>] (deferred_probe_work_func+0x108/0x120)
[    1.278050] [<c074e3e4>] (deferred_probe_work_func) from [<c01360e0>] (process_one_work+0x220/0x468)
[    1.278056] [<c01360e0>] (process_one_work) from [<c0136354>] (process_scheduled_works+0x2c/0x30)
[    1.278061] [<c0136354>] (process_scheduled_works) from [<c0137090>] (worker_thread+0x2b8/0x3e8)
[    1.278066] [<c0137090>] (worker_thread) from [<c013b1dc>] (kthread+0x130/0x148)
[    1.278071] [<c013b1dc>] (kthread) from [<c01010e8>] (ret_from_fork+0x14/0x2c)
[    1.278074] Exception stack(0xed8a1fb0 to 0xed8a1ff8)
[    1.278077] 1fa0:                                     00000000 00000000 00000000 00000000
[    1.278081] 1fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[    1.278084] 1fe0: 00000000 00000000 00000000 00000000 00000013 00000000
[    1.278087] ---[ end trace 0d44f5a5d5fde61d ]---
@samsonluk
Copy link

Start working on compilation of 4.16-rc4...

@samsonluk
Copy link

Prompting kernel config questions this time... Restart script after

$ cp tmp/RockMyy-0dfd08eeb9ca1ece37b083e22c494afd5f4a379c/config/v4.16/config-latest .config
$ cp .config linux

@samsonluk
Copy link

PASSED! No vblank timeout dmesg_4.16-rc4-RockMyy-16Bits-Edition.log

@Miouyouyou
Copy link
Owner Author

Miouyouyou commented Jul 23, 2018

Alright...

My guess is that it could be either this change :
https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/drivers/gpu/drm?h=v4.16&id=b24791fe00f8b089d5b10cb7bcc4e1ae88b4831b
or this change
https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/drivers/gpu/drm?h=v4.16&id=5a9f698feb11b198f17b2acebbfe0e2716a3beed

Both were introduced with the kernel 4.16-rc7.

One way to test one of the patches, without the other, would be to :

  • Set the script to download and compile a 4.16-rc7 kernel
  • Test the result
  • If that fails :
    • From the script folder, type :
cd linux
wget https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/patch/drivers/gpu/drm?id=b24791fe00f8b089d5b10cb7bcc4e1ae88b4831b -O GetFB.patch
git apply -R ./GetFB.patch
  • Re-execute the script and retest the compilation result.
  • If the Vblank timeout still occurs, try :
cd linux
wget https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/patch/drivers/gpu/drm?id=5a9f698feb11b198f17b2acebbfe0e2716a3beed -O DRMAST.patch
git apply -R DRMAST.patch
  • Re-execute the script and retest the compilation result.

If that still fails... It will be time for some "printk" debugging.

@samsonluk
Copy link

Ok, start compile 4.16-rc7

@samsonluk
Copy link

samsonluk commented Jul 24, 2018

With both changes:

Linux tinkerboard 4.16.0-rc7-RockMyy-16Bits-Edition #1 SMP PREEMPT Mon Jul 23 15:45:32 UTC 2018 armv7l
dmesg | grep vblank
[    1.112528] [drm] Supports vblank timestamp caching Rev 2 (21.10.2013).
[    1.112531] [drm] No driver support for vblank timestamp query.
[    1.287346] WARNING: CPU: 0 PID: 102 at drivers/gpu/drm/drm_atomic_helper.c:1349 drm_atomic_helper_wait_for_vblanks+0x1c8/0x1e0
[    1.287348] [CRTC:30:crtc-0] vblank wait timed out
[    1.287404] [<c011f2ec>] (warn_slowpath_fmt) from [<c070b2f8>] (drm_atomic_helper_wait_for_vblanks+0x1c8/0x1e0)
[    1.287411] [<c070b2f8>] (drm_atomic_helper_wait_for_vblanks) from [<c070cc60>] (drm_atomic_helper_commit_tail_rpm+0x48/0x58)

git apply -R ./GetFB.patch

dmesg | grep vblank
[    1.113467] [drm] Supports vblank timestamp caching Rev 2 (21.10.2013).
[    1.113469] [drm] No driver support for vblank timestamp query.
[    1.288810] WARNING: CPU: 0 PID: 101 at drivers/gpu/drm/drm_atomic_helper.c:1349 drm_atomic_helper_wait_for_vblanks+0x1c8/0x1e0
[    1.288851] [CRTC:30:crtc-0] vblank wait timed out
[    1.288909] [<c011f2ec>] (warn_slowpath_fmt) from [<c070b2f8>] (drm_atomic_helper_wait_for_vblanks+0x1c8/0x1e0)
[    1.288915] [<c070b2f8>] (drm_atomic_helper_wait_for_vblanks) from [<c070cc60>] (drm_atomic_helper_commit_tail_rpm+0x48/0x58)

git apply -R ./DRMAST.patch
error: drivers/gpu/drm/ast/ast_tables.h: No such file or directory

Oh, should have backup linux/ before git apply...

@Miouyouyou
Copy link
Owner Author

You can do git checkout -- . to revert non commited changes.

I'm surprised you don't have this file, since it's still present in the latest 4.18-rc.
Be sure to apply the patch from the linux directory, else the patch will fail.

Anyway, we're sure that it's between the rc4 and rc7. So if you're good for a last compilation, try the -rc6. If the problem doesn't occur with the -rc6, that it's clearly in between.
In this case, keep the linux/ of the rc6 and rc7`, we'll need it, since we'll have to add some "printk" to the code, in order to understand how things are initialised in both trees and pinpoint the differences.

@samsonluk
Copy link

Oops, stupid me! I actually execute the wget/git apply in the wrong machine...

Anyway, saved linux/ of rc7

git apply -R ./DRMAST.patch

dmesg | grep vblank
[    1.111755] [drm] Supports vblank timestamp caching Rev 2 (21.10.2013).
[    1.111758] [drm] No driver support for vblank timestamp query.
[    1.284329] WARNING: CPU: 3 PID: 102 at drivers/gpu/drm/drm_atomic_helper.c:1349 drm_atomic_helper_wait_for_vblanks+0x1c8/0x1e0
[    1.284331] [CRTC:30:crtc-0] vblank wait timed out
[    1.284388] [<c011f2ec>] (warn_slowpath_fmt) from [<c070b2f8>] (drm_atomic_helper_wait_for_vblanks+0x1c8/0x1e0)
[    1.284395] [<c070b2f8>] (drm_atomic_helper_wait_for_vblanks) from [<c070cc60>] (drm_atomic_helper_commit_tail_rpm+0x48/0x58)

So not rc7. Go for -rc6 now...

@samsonluk
Copy link

samsonluk commented Jul 24, 2018

rc6 PASSED!

Linux tinkerboard 4.16.0-rc6-RockMyy-16Bits-Edition #1 SMP PREEMPT Tue Jul 24 08:27:54 UTC 2018 armv7l GNU/Linux
root@tinkerboard:~#
root@tinkerboard:~# dmesg | grep vblank
[    1.112326] [drm] Supports vblank timestamp caching Rev 2 (21.10.2013).
[    1.112328] [drm] No driver support for vblank timestamp query.

I have both linux/ ready:
drwxr-xr-x 27 root root 4096 Jul 24 10:03 linux_4.16-rc6
drwxr-xr-x 25 root root 4096 Jul 24 07:18 linux_4.16-rc7

@Miouyouyou
Copy link
Owner Author

Here's the patch that should apply to both. This will pollute the logs so get the logs quickly.

From aef02775f33ba10090388316648e1206f45e74fc Mon Sep 17 00:00:00 2001
From: "Miouyouyou (Myy)" <myy@miouyouyou.fr>
Date: Tue, 24 Jul 2018 21:18:17 +0200
Subject: [PATCH] Let's pollute the logs

To get some informations about CRTC.
Not really working at the moment.
Most informations are bogus.

Signed-off-by: Miouyouyou (Myy) <myy@miouyouyou.fr>
---
 drivers/gpu/drm/drm_atomic_helper.c | 17 +++++++++++++++++
 1 file changed, 17 insertions(+)

diff --git a/drivers/gpu/drm/drm_atomic_helper.c b/drivers/gpu/drm/drm_atomic_helper.c
index ae3cbfe9e..37f1fc62a 100644
--- a/drivers/gpu/drm/drm_atomic_helper.c
+++ b/drivers/gpu/drm/drm_atomic_helper.c
@@ -1345,6 +1345,23 @@ drm_atomic_helper_wait_for_vblanks(struct drm_device *dev,
                                        drm_crtc_vblank_count(crtc),
                                msecs_to_jiffies(50));
 
+               dev_warn(dev->dev, "(Myy)\n"
+                       "\tCRTC[%i] (%d : %s)\n"
+                       "\tOld state last vblank Count : %llu\n"
+                       "\tCRTC Vblank_count           : %llu\n"
+                       "\tWait Event Timeout Ret      :  %d\n"
+                       "\tCRTC Interrupt enabled      ?  %d\n"
+                       "\tCRTC Interrupt number       :  %d\n"
+                       "\tCRTC Device                 :  %p\n"
+                       "\tArgument Device             :  %p\n",
+                       i, crtc->base.id, crtc->name,
+                       old_state->crtcs[i].last_vblank_count,
+                       drm_crtc_vblank_count(crtc),
+                       ret,
+                       (crtc->dev ? crtc->dev->irq_enabled : 0),
+                       (crtc->dev ? crtc->dev->irq : 0),
+                       crtc->dev, dev);
+
                WARN(!ret, "[CRTC:%d:%s] vblank wait timed out\n",
                     crtc->base.id, crtc->name);
 
-- 
2.16.4

Once you're done with the patch, try to the following :

cd linux_4.16-rc7
wget https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/patch/?id=3215b9d57a2c75c4305a3956ca303d7004485200 -O Clocks.patch
git apply -R Clocks.patch

And see how it goes.

@Miouyouyou
Copy link
Owner Author

Note that this patch should be applied to both kernels and tested on both, in order to see if there's any difference between them.

The last commands only target the rc7.

@samsonluk
Copy link

samsonluk commented Jul 25, 2018

What's wrong? linux/ is a clone of linux_4.16-rc6

root@91d81f86bc53:/usr/src/linux# git am a.patch
Applying: Let's pollute the logs
error: patch failed: drivers/gpu/drm/drm_atomic_helper.c:1345
error: drivers/gpu/drm/drm_atomic_helper.c: patch does not apply
Patch failed at 0001 Let's pollute the logs
The copy of the patch that failed is found in: .git/rebase-apply/patch
When you have resolved this problem, run "git am --continue".
If you prefer to skip this patch, run "git am --skip" instead.
To restore the original branch and stop patching, run "git am --abort".

@samsonluk
Copy link

Resolved:

root@91d81f86bc53:/usr/src/linux# git am --ignore-whitespace --ignore-space-change a.patch
Applying: Let's pollute the logs

@samsonluk
Copy link

this is linux_4.16-rc7 after "Applying: Let's pollute the logs" patch:

root@91d81f86bc53:/usr/src/linux# git apply -R Clocks.patch
error: patch failed: drivers/clk/clk-aspeed.c:259
error: drivers/clk/clk-aspeed.c: patch does not apply
root@91d81f86bc53:/usr/src/linux# git apply -v -R Clocks.patch
Checking patch drivers/clk/sunxi-ng/ccu-sun6i-a31.c...
Checking patch drivers/clk/imx/clk-imx51-imx53.c...
Checking patch drivers/clk/ti/clkctrl.c...
Checking patch drivers/clk/ti/clk-33xx.c...
Checking patch drivers/clk/ti/clk-43xx.c...
Checking patch drivers/clk/clk.c...
Hunk #1 succeeded at 2311 (offset -2 lines).
Checking patch drivers/clk/clk.c...
Hunk #1 succeeded at 2969 (offset -2 lines).
Hunk #2 succeeded at 3002 (offset -2 lines).
Checking patch drivers/clk/clk.c...
Checking patch drivers/clk/hisilicon/clk-hi3660-stub.c...
Checking patch drivers/clk/qcom/apcs-msm8916.c...
Checking patch drivers/clk/clk-aspeed.c...
error: while searching for:
{
        struct aspeed_clk_gate *gate = to_aspeed_clk_gate(hw);
        u32 clk = BIT(gate->clock_idx);
        u32 enval = (gate->flags & CLK_GATE_SET_TO_DISABLE) ? 0 : clk;
        u32 reg;

        regmap_read(gate->map, ASPEED_CLK_STOP_CTRL, &reg);

        return ((reg & clk) == enval) ? 1 : 0;
}

static const struct clk_ops aspeed_clk_gate_ops = {

error: patch failed: drivers/clk/clk-aspeed.c:259
error: drivers/clk/clk-aspeed.c: patch does not apply
Checking patch drivers/clk/clk-aspeed.c...
Checking patch drivers/clk/bcm/clk-bcm2835.c...
Checking patch drivers/clk/bcm/clk-bcm2835.c...
root@91d81f86bc53:/usr/src/linux#

@Miouyouyou
Copy link
Owner Author

Which version does /usr/src/linux links to ?
This is the latest patch affecting drivers/clk/clk-aspeed.c for the 4.16-rc7, so I don't know why it does not apply... I'll try to prepare a tarball if needed.

@samsonluk
Copy link

It is 4.16-rc7, I even deleted linux/ and restarted the script again from scratch:

root@91d81f86bc53:/usr/src# more GetPatchAndCompileKernel_4.16-rc7.sh
export ARCH=arm
export CROSS_COMPILE=

export KERNEL_GIT_URL='git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git'

export KERNEL_SERIES=v4.16
export KERNEL_BRANCH=v4.16-rc7
export LOCALVERSION=-RockMyy-16Bits-Edition
export MALI_VERSION=r19p0-01rel0
export MALI_BASE_URL=https://developer.arm.com/-/media/Files/downloads/mali-drivers/kernel/mali-midgard-gpu

Note: checking out '3eb2ce825ea1ad89d20f7a3b5780df850e4be274'.

@Miouyouyou
Copy link
Owner Author

Well, let's try it like that than :

wget https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/patch/drivers/clk/clk-aspeed.c?id=8a53fc511c5ec81347b981b438f68c3dde421608 -O clk.patch
git apply -R clk.patch

I'm just wondering if some Clock patches generated issues with the HDMI detection.

@samsonluk
Copy link

@Miouyouyou
Copy link
Owner Author

Hmm, I guess I messed up the vblank count display.
In the first case, it seems to be at 0 (2**32 overflowing at 0)
In the second case, it seems to be at -46, if it's a 32 bits value...

I'll try to modify my script so that you can pull the kernel sources at one specific commit...

It seems like a very subtle bug. If you remove the timestamps of both dmesg logs and you cut them before the first "Myy" log and do a diff, both logs are almost identical.
Some pointers addresses change, but that's due to the recompilation process and various sources change, but these addresses don't seem null or completely off (like 0xffffffff).

That some tricky bug...

Could you test a compilation by doing like this :

mv linux{,.bak}
wget https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/snapshot/linux-3215b9d57a2c75c4305a3956ca303d7004485200.tar.gz -O linux.tgz
tar zxvf linux.tgz
mv linux-3215* linux
cd linux
git init .
git add .
git commit -m "My wonderful kernel"
cd ..

And then run the usual script.

@samsonluk
Copy link

FYI, Nodepad++ for Windows can compare the logs without cutting time stamp.

I will try that out tomorrow...

@samsonluk
Copy link

Done
dmesg

@Miouyouyou
Copy link
Owner Author

Was the screen plugged-in during the boot sequence ? I'm reading this, in your last log :

[    1.114972] [drm] Cannot find any crtc or sizes

@samsonluk
Copy link

Oops. switched off

@Miouyouyou
Copy link
Owner Author

If you still have these issues, feel free to reopen this ticket. Meanwhile, I'm closing it due to no activity.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

2 participants