[PATCH] drm/vkms: Don't warn hrtimer_forward_now failure.

[Tetsuo Handa]

On 2020/05/26 0:21, Daniel Vetter wrote:
> On Mon, May 25, 2020 at 11:38:49PM +0900, Tetsuo Handa wrote:
>> Commit 3a0709928b172a41 ("drm/vkms: Add vblank events simulated by
>> hrtimers") introduced ret_overrun variable. And that variable was an
>> unused-but-set-variable until commit 09ef09b4ab95dc40 ("drm/vkms:
>> WARN when hrtimer_forward_now fails") added WARN_ON(ret_overrun != 1).
>>
>> Now, syzbot is hitting this WARN_ON() using a simple reproducer that
>> does open("/dev/dri/card1") followed by ioctl(DRM_IOCTL_WAIT_VBLANK),
>> and a debug printk() patch says that syzbot is getting
>>
>>    output->vblank_hrtimer.base->get_time()=93531904774 (which is uptime)
>>    output->period_ns=0
>>    ret_overrun=216994
>>
>> . I can't understand what "verify the hrtimer_forward_now return" in
>> that commit wants to say. hrtimer_forward_now() must return, and the
>> return value of hrtimer_forward_now() is not a boolean. Why comparing
>> with 1 ? Anyway, this failure is not something that worth crashing the
>> system. Let's remove the ret_overrun variable and WARN_ON() test.
> 
> Uh we're not crashing the system, it's a warning backtrace.

syzbot uses panic_on_warn=1, and this bug is currently the 8th top crasher.

> 
> And we've spent a few months hunting the races here, so just removing that
> check isn't really a good idea. The correct thing to do is figure out why
> we're hitting this. It could be that we're having a missing check
> somewhere, or missing initialization, and that's what syzbot is hitting.
> Removing this check here just papers over the bug.

Here is a reproducer which syzbot is using.

----------
#include <sys/types.h>
#include <sys/stat.h>
#include <fcntl.h>
#include <sys/ioctl.h>
#include <drm/drm.h>

int main(int argc, char *argv[])
{
	union drm_wait_vblank arg;
	int fd = open("/dev/dri/card1", O_RDONLY);

	arg.request.type = 0;
	arg.request.sequence = 0xffff;
	arg.request.signal = 0x21;
	ioctl(fd, DRM_IOCTL_WAIT_VBLANK, &arg);
	return 0;
}
----------

Debug printk() patch shows that hrtimer_forward_now() can return larger than 1.
What is the reason you are expecting hrtimer_forward_now() to always return 1 ?

> 
> If the vkms driver is loaded, and there's nothing else going on, then what
> I expect to happen is that this virtual hw is entirely off. And in that
> case, the vblank ioctl should be rejected outright. So there's definitely
> something fishy going on to begin with.
> 
> If otoh the virtual hw is somehow on (maybe fbcon gets loaded, no idea),
> then the vblank wait shouldn't just blow up like this.
> -Daniel
> 
>>
>> Link: https://syzkaller.appspot.com/bug?id=0ba17d70d062b2595e1f061231474800f076c7cb
>> Signed-off-by: Tetsuo Handa <penguin-kernel at I-love.SAKURA.ne.jp>
>> Reported-by: syzbot+0871b14ca2e2fb64f6e3 at syzkaller.appspotmail.com
>> Fixes: 09ef09b4ab95dc40 ("drm/vkms: WARN when hrtimer_forward_now fails")
>> ---
>>  drivers/gpu/drm/vkms/vkms_crtc.c | 5 +----
>>  1 file changed, 1 insertion(+), 4 deletions(-)
>>
>> diff --git a/drivers/gpu/drm/vkms/vkms_crtc.c b/drivers/gpu/drm/vkms/vkms_crtc.c
>> index ac85e17428f8..cc1811ce6092 100644
>> --- a/drivers/gpu/drm/vkms/vkms_crtc.c
>> +++ b/drivers/gpu/drm/vkms/vkms_crtc.c
>> @@ -13,12 +13,9 @@ static enum hrtimer_restart vkms_vblank_simulate(struct hrtimer *timer)
>>  						  vblank_hrtimer);
>>  	struct drm_crtc *crtc = &output->crtc;
>>  	struct vkms_crtc_state *state;
>> -	u64 ret_overrun;
>>  	bool ret;
>>  
>> -	ret_overrun = hrtimer_forward_now(&output->vblank_hrtimer,
>> -					  output->period_ns);
>> -	WARN_ON(ret_overrun != 1);
>> +	hrtimer_forward_now(&output->vblank_hrtimer, output->period_ns);
>>  
>>  	spin_lock(&output->lock);
>>  	ret = drm_crtc_handle_vblank(crtc);
>> -- 
>> 2.18.2
>>
>