Linux-2.6.31-rc4 - shut the annoying "failed to acquire vblank..."

Linux-2.6.31-rc4 - shut the annoying "failed to acquire vblank..."

[Paul Rolland]

Hello,

I sent a mail long ago about this message :
tux kernel: [drm:drm_wait_vblank] *ERROR* failed to acquire vblank counter,
-22 showing up more than 10 times per second, but was told that I had some
old userspace apps running... As I was using an old FC8, I forgot about it.

But I'm now running a quite recent FC11, pure 64bit machine, and when I run
a vanilla kernel, I have this message showing again and again.

I propose to apply the following patch :

--- drm_irq.c.orig      2009-07-26 21:36:20.000000000 +0200
+++ drm_irq.c   2009-07-26 21:36:34.000000000 +0200
@@ -566,7 +566,7 @@
 
        ret = drm_vblank_get(dev, crtc);
        if (ret) {
-               DRM_ERROR("failed to acquire vblank counter, %d\n", ret);
+               DRM_DEBUG("failed to acquire vblank counter, %d\n", ret);
                return ret;
        }
        seq = drm_vblank_count(dev, crtc);

to shut the message. This is at least what I do on my machine to have it
running quietly.

Anyway, if anyone care to explain why we have this "error", I'd be glad to
learn about it. 
And if anyone wants me to test some patches, I'll be glad to.

Regards,
Paul


-- 
Paul Rolland                                E-Mail : rol(at)witbe.net
CTO - Witbe.net SA                          Tel. +33 (0)1 47 67 77 77
Les Collines de l'Arche                     Fax. +33 (0)1 47 67 77 99
F-92057 Paris La Defense                    RIPE : PR12-RIPE

Please no HTML, I'm not a browser - Pas d'HTML, je ne suis pas un
navigateur "Some people dream of success... while others wake up and work
hard at it" 

"I worry about my child and the Internet all the time, even though she's
too young to have logged on yet. Here's what I worry about. I worry that 10
or 15 years from now, she will come to me and say 'Daddy, where were you
when they took freedom of the press away from the Internet?'"
--Mike Godwin, Electronic Frontier Foundation 

Re: Linux-2.6.31-rc4 - shut the annoying "failed to acquire vblank..."

[Frans Pop]

> I sent a mail long ago about this message :
> tux kernel: [drm:drm_wait_vblank] *ERROR* failed to acquire vblank
> counter, -22 showing up more than 10 times per second, but was told
> that I had some old userspace apps running... As I was using an old
> FC8, I forgot about it.

The message does not only show with old applications, it also shows:
- every time I suspend my notebook
- every time I start a second X session to log in as a different user

I agree that the message is very annoying and would be glad to be rid of 
it, especially as the only comment from the maintainers so far has been 
to just ignore it.
IMHO, If it is "ignoreable", then it is also "suppressable".

Thanks for your patch. I think I'll add it to my local branch too.

Cheers,
FJP

Re: Linux-2.6.31-rc4 - shut the annoying "failed to acquire vblank..."

[Paul Rolland]

Hi Frans,

On Tue, 28 Jul 2009 12:44:12 +0200
Frans Pop <elendil@planet.nl> wrote:

> > I sent a mail long ago about this message :
> > tux kernel: [drm:drm_wait_vblank] *ERROR* failed to acquire vblank
> > counter, -22 showing up more than 10 times per second, but was told
> > that I had some old userspace apps running... As I was using an old
> > FC8, I forgot about it.
> 
> The message does not only show with old applications, it also shows:
> - every time I suspend my notebook
> - every time I start a second X session to log in as a different user
Well, with the so-called "old apps", it's 20 times per second, as long as
the app is running, which really makes it painful, because it causes all
the logs to show off quickly :(
 
> I agree that the message is very annoying and would be glad to be rid of 
> it, especially as the only comment from the maintainers so far has been 
> to just ignore it.
Well, I'd really like some feedback from the maintainer... because if no
one cares, I agree it should be removed.

> IMHO, If it is "ignoreable", then it is also "suppressable".
Seconded, unless someone is using it to try to fix the problem ?
 
Paul

Re: Linux-2.6.31-rc4 - shut the annoying "failed to acquire vblank..."

[Jesse Barnes]

On Tue, 28 Jul 2009 14:53:59 +0200
Paul Rolland <rol@as2917.net> wrote:

> Hi Frans,
> 
> On Tue, 28 Jul 2009 12:44:12 +0200
> Frans Pop <elendil@planet.nl> wrote:
> 
> > > I sent a mail long ago about this message :
> > > tux kernel: [drm:drm_wait_vblank] *ERROR* failed to acquire vblank
> > > counter, -22 showing up more than 10 times per second, but was
> > > told that I had some old userspace apps running... As I was using
> > > an old FC8, I forgot about it.
> > 
> > The message does not only show with old applications, it also shows:
> > - every time I suspend my notebook
> > - every time I start a second X session to log in as a different
> > user
> Well, with the so-called "old apps", it's 20 times per second, as
> long as the app is running, which really makes it painful, because it
> causes all the logs to show off quickly :(
>  
> > I agree that the message is very annoying and would be glad to be
> > rid of it, especially as the only comment from the maintainers so
> > far has been to just ignore it.
> Well, I'd really like some feedback from the maintainer... because if
> no one cares, I agree it should be removed.
> 
> > IMHO, If it is "ignoreable", then it is also "suppressable".
> Seconded, unless someone is using it to try to fix the problem ?

It indicates a userland problem, and yes we shouldn't print that
message.  I've also posted a patch to quiet it a few times, but Dave
hasn't picked it up yet.  Feel free to send it straight to Linus with
my Reviewed-by if you want.

-- 
Jesse Barnes, Intel Open Source Technology Center

Re: Linux-2.6.31-rc4 - shut the annoying "failed to acquire vblank..."

[Paul Rolland]

Hi Jesse,

On Tue, 28 Jul 2009 09:23:19 -0700
Jesse Barnes <jbarnes@virtuousgeek.org> wrote:

> It indicates a userland problem, and yes we shouldn't print that
> message.  I've also posted a patch to quiet it a few times, but Dave
> hasn't picked it up yet.  Feel free to send it straight to Linus with
> my Reviewed-by if you want.
> 

Thx, will do that tomorrow morning, after making it compliant with Linux
rules for patch submission ;)

Rgds,
Paul

Re: Linux-2.6.31-rc4 - shut the annoying "failed to acquire vblank..."

[Paul Rolland]

[-- Attachment #1: Type: text/plain, Size: 3337 bytes --]

Hi Linus,

On Tue, 28 Jul 2009 09:23:19 -0700
Jesse Barnes <jbarnes@virtuousgeek.org> wrote:

> On Tue, 28 Jul 2009 14:53:59 +0200
> Paul Rolland <rol@as2917.net> wrote:
> 
> > Hi Frans,
> > 
> > On Tue, 28 Jul 2009 12:44:12 +0200
> > Frans Pop <elendil@planet.nl> wrote:
> > 
> > > > I sent a mail long ago about this message :
> > > > tux kernel: [drm:drm_wait_vblank] *ERROR* failed to acquire vblank
> > > > counter, -22 showing up more than 10 times per second, but was
> > > > told that I had some old userspace apps running... As I was using
> > > > an old FC8, I forgot about it.
> > > 
> > > The message does not only show with old applications, it also shows:
> > > - every time I suspend my notebook
> > > - every time I start a second X session to log in as a different
> > > user
> > Well, with the so-called "old apps", it's 20 times per second, as
> > long as the app is running, which really makes it painful, because it
> > causes all the logs to show off quickly :(
> >  
> > > I agree that the message is very annoying and would be glad to be
> > > rid of it, especially as the only comment from the maintainers so
> > > far has been to just ignore it.
> > Well, I'd really like some feedback from the maintainer... because if
> > no one cares, I agree it should be removed.
> > 
> > > IMHO, If it is "ignoreable", then it is also "suppressable".
> > Seconded, unless someone is using it to try to fix the problem ?
> 
> It indicates a userland problem, and yes we shouldn't print that
> message.  I've also posted a patch to quiet it a few times, but Dave
> hasn't picked it up yet.  Feel free to send it straight to Linus with
> my Reviewed-by if you want.

Could you please apply the included patch ?

Some applications/hardware combinations are triggering the message "failed to 
acquire vblank counter" to be issued up to 20 times a second, which makes it 
both useless and dangerous, as this may hide other important messages.
This changes makes it only appear when people are debugging.

Signed-off-by: Paul Rolland <rol@as2917.net>
Reviewed-by: Jesse Barnes <jbarnes@virtuousgeek.org>

--- linux-2.6.31-rc4/drivers/gpu/drm/drm_irq.c.orig	2009-07-26 21:36:20.000000000 +0200
+++ linux-2.6.31-rc4/drivers/gpu/drm/drm_irq.c	2009-07-26 21:36:34.000000000 +0200
@@ -566,7 +566,7 @@ int drm_wait_vblank(struct drm_device *d
 
 	ret = drm_vblank_get(dev, crtc);
 	if (ret) {
-		DRM_ERROR("failed to acquire vblank counter, %d\n", ret);
+		DRM_DEBUG("failed to acquire vblank counter, %d\n", ret);
 		return ret;
 	}
 	seq = drm_vblank_count(dev, crtc);



-- 
Paul Rolland                                E-Mail : rol(at)witbe.net
CTO - Witbe.net SA                          Tel. +33 (0)1 47 67 77 77
Les Collines de l'Arche                     Fax. +33 (0)1 47 67 77 99
F-92057 Paris La Defense                    RIPE : PR12-RIPE

Please no HTML, I'm not a browser - Pas d'HTML, je ne suis pas un
navigateur "Some people dream of success... while others wake up and work
hard at it" 

"I worry about my child and the Internet all the time, even though she's
too young to have logged on yet. Here's what I worry about. I worry that 10
or 15 years from now, she will come to me and say 'Daddy, where were you
when they took freedom of the press away from the Internet?'"
--Mike Godwin, Electronic Frontier Foundation 

[-- Attachment #2: drm.patch --]
[-- Type: text/x-patch, Size: 460 bytes --]

--- linux-2.6.31-rc4/drivers/gpu/drm/drm_irq.c.orig	2009-07-26 21:36:20.000000000 +0200
+++ linux-2.6.31-rc4/drivers/gpu/drm/drm_irq.c	2009-07-26 21:36:34.000000000 +0200
@@ -566,7 +566,7 @@ int drm_wait_vblank(struct drm_device *d
 
 	ret = drm_vblank_get(dev, crtc);
 	if (ret) {
-		DRM_ERROR("failed to acquire vblank counter, %d\n", ret);
+		DRM_DEBUG("failed to acquire vblank counter, %d\n", ret);
 		return ret;
 	}
 	seq = drm_vblank_count(dev, crtc);

Re: Linux-2.6.31-rc4 - shut the annoying "failed to acquire vblank..."

[Frans Pop]

Paul Rolland wrote:
> Some applications/hardware combinations are triggering the message
> "failed to acquire vblank counter" to be issued up to 20 times a second,
> which makes it both useless and dangerous, as this may hide other
> important messages. This changes makes it only appear when people are
> debugging. 
> 
> Signed-off-by: Paul Rolland <rol@as2917.net>
> Reviewed-by: Jesse Barnes <jbarnes@virtuousgeek.org>
> 
> --- linux-2.6.31-rc4/drivers/gpu/drm/drm_irq.c.orig     2009-07-26 21:36:20.000000000 +0200
> +++ linux-2.6.31-rc4/drivers/gpu/drm/drm_irq.c  2009-07-26 21:36:34.000000000 +0200
> @@ -566,7 +566,7 @@ int drm_wait_vblank(struct drm_device *d
> 
> ret = drm_vblank_get(dev, crtc);
> 	if (ret) {
> -		DRM_ERROR("failed to acquire vblank counter, %d\n", ret);
> +		DRM_DEBUG("failed to acquire vblank counter, %d\n", ret);
> 		return ret;
> 	}
> 	seq = drm_vblank_count(dev, crtc);

Actually, I just see that I get a different, but related error on suspend
and when opening/closing a second X session:
   *ERROR* trying to get vblank count for disabled pipe 0/1

Would it make sense to add the following to this patch:

diff --git a/drivers/gpu/drm/i915/i915_irq.c b/drivers/gpu/drm/i915/i915_irq.c
index 7ba23a6..d8b86ed 100644
--- a/drivers/gpu/drm/i915/i915_irq.c
+++ b/drivers/gpu/drm/i915/i915_irq.c
@@ -190,7 +190,7 @@ u32 i915_get_vblank_counter(struct drm_device *dev, int pipe)
 	low_frame = pipe ? PIPEBFRAMEPIXEL : PIPEAFRAMEPIXEL;
 
 	if (!i915_pipe_enabled(dev, pipe)) {
-		DRM_ERROR("trying to get vblank count for disabled pipe %d\n", pipe);
+		DRM_DEBUG("trying to get vblank count for disabled pipe %d\n", pipe);
 		return 0;
 	}
 
@@ -219,7 +219,7 @@ u32 gm45_get_vblank_counter(struct drm_device *dev, int pipe)
 	int reg = pipe ? PIPEB_FRMCOUNT_GM45 : PIPEA_FRMCOUNT_GM45;
 
 	if (!i915_pipe_enabled(dev, pipe)) {
-		DRM_ERROR("trying to get vblank count for disabled pipe %d\n", pipe);
+		DRM_DEBUG("trying to get vblank count for disabled pipe %d\n", pipe);
 		return 0;
 	}
 

Re: Linux-2.6.31-rc4 - shut the annoying "failed to acquire vblank..."

[Jesse Barnes]

On Thu, 30 Jul 2009 13:06:50 +0200
Frans Pop <elendil@planet.nl> wrote:

> Paul Rolland wrote:
> > Some applications/hardware combinations are triggering the message
> > "failed to acquire vblank counter" to be issued up to 20 times a
> > second, which makes it both useless and dangerous, as this may hide
> > other important messages. This changes makes it only appear when
> > people are debugging. 
> > 
> > Signed-off-by: Paul Rolland <rol@as2917.net>
> > Reviewed-by: Jesse Barnes <jbarnes@virtuousgeek.org>
> > 
> > --- linux-2.6.31-rc4/drivers/gpu/drm/drm_irq.c.orig     2009-07-26
> > 21:36:20.000000000 +0200 +++
> > linux-2.6.31-rc4/drivers/gpu/drm/drm_irq.c  2009-07-26
> > 21:36:34.000000000 +0200 @@ -566,7 +566,7 @@ int
> > drm_wait_vblank(struct drm_device *d
> > 
> > ret = drm_vblank_get(dev, crtc);
> > 	if (ret) {
> > -		DRM_ERROR("failed to acquire vblank counter,
> > %d\n", ret);
> > +		DRM_DEBUG("failed to acquire vblank counter,
> > %d\n", ret); return ret;
> > 	}
> > 	seq = drm_vblank_count(dev, crtc);
> 
> Actually, I just see that I get a different, but related error on
> suspend and when opening/closing a second X session:
>    *ERROR* trying to get vblank count for disabled pipe 0/1
> 
> Would it make sense to add the following to this patch:

Yes, that would be a good second patch (I also sent this one a few
times but it keeps getting lost).  If you want to send it to Linus more
formally, you can add my reviewed-by.

Thanks,
-- 
Jesse Barnes, Intel Open Source Technology Center