[mythtv-users] nouveau video faster than audio

Eyal Lebedinsky eyal at eyal.emu.id.au
Thu Jan 2 22:35:17 UTC 2014


On 01/03/14 09:29, Eyal Lebedinsky wrote:
>
>
> On 01/03/14 08:02, HP-mini wrote:
>> On Thu, 2014-01-02 at 20:44 +1300, Nick Rout wrote:
>>> On Thu, Jan 2, 2014 at 12:34 PM, Eyal Lebedinsky <eyal at eyal.emu.id.au> wrote:
>>>>
>>>> I am using "High Quality". I then tried VDPAU (needed to install firmware)
>>>> and video was even *faster*. OpenGL was faster again...
>>>>
>>>> If all fails then I will go back to the nvidia binaries, but I really hoped
>>>> the open source driver will start being useful.
>>>
>>>
>>> All else has failed.
>>
>> Does this match?
>> What video/GPU h/w?
>> http://code.mythtv.org/trac/ticket/11729
>
> Good find, I did not see this one. Reads very much like my case. With vdpau the video goes
> at about twice the speed, and the A/V Sync rises to over 600 before dropping very low,
> when the video gets to "normal" speed for a fraction of a second and then returns to very
> high speed.
>
> Without vdpau the video is stable at the wrong speed, e.g. Video=50Hz, FPS=60Hz. Again, when
> A/V Sync gets to over 600 it drops away, FPS goes to 50Hz then immediately rises to 60Hz.
>
> So it is not always twice the speed. A 50Hz Video runs at 60Hz, but using vdpau it runs at 110Hz
> (very variable, between 100 and 120Hz).
>
> One thing to add: mythfrontend often hangs on exit and "needs killing".
>
> I also see very many of these messages logged:
>
> Jan  3 09:02:56 e4 /etc/gdm/Xsession[1369]: 2014-01-03 09:02:56.001076 I  Player(0): FPS:   59.93 Mean: 16687 Std.Dev:  3099 CPUs: 0j 1j 23j 17j
> Jan  3 09:02:56 e4 /etc/gdm/Xsession[1369]: 2014-01-03 09:02:56.835764 I  Player(0): FPS:   59.93 Mean: 16687 Std.Dev:  3110 CPUs: 1j 1j 23j 18j
> Jan  3 09:02:57 e4 /etc/gdm/Xsession[1369]: 2014-01-03 09:02:57.670296 I  Player(0): FPS:   59.94 Mean: 16684 Std.Dev:  3106 CPUs: 5j 2j 19j 15j
> Jan  3 09:02:58 e4 /etc/gdm/Xsession[1369]: 2014-01-03 09:02:58.504970 I  Player(0): FPS:   59.92 Mean: 16687 Std.Dev:  3148 CPUs: 8j 12j 14j 11j
> Jan  3 09:02:59 e4 /etc/gdm/Xsession[1369]: 2014-01-03 09:02:59.339723 I  Player(0): FPS:   59.92 Mean: 16688 Std.Dev:  3118 CPUs: 23j 4j 8j 5j
> Jan  3 09:03:00 e4 /etc/gdm/Xsession[1369]: 2014-01-03 09:03:00.174362 I  Player(0): FPS:   59.93 Mean: 16687 Std.Dev:  3164 CPUs: 23j 4j 7j 5j
> Jan  3 09:03:01 e4 /etc/gdm/Xsession[1369]: 2014-01-03 09:03:00.993506 I  Player(0): FPS:   61.06 Mean: 16377 Std.Dev:  3792 CPUs: 20j 10j 9j 6j
> Jan  3 09:03:01 e4 /etc/gdm/Xsession[1369]: 2014-01-03 09:03:01.843700 I  Player(0): FPS:   58.83 Mean: 16997 Std.Dev:  3783 CPUs: 26j 1j 8j 4j
> Jan  3 09:03:02 e4 /etc/gdm/Xsession[1369]: 2014-01-03 09:03:02.678376 I  Player(0): FPS:   59.92 Mean: 16687 Std.Dev:  3149 CPUs: 20j 5j 7j 8j
> Jan  3 09:03:03 e4 /etc/gdm/Xsession[1369]: 2014-01-03 09:03:03.512997 I  Player(0): FPS:   59.93 Mean: 16686 Std.Dev:  3129 CPUs: 19j 6j 8j 4j
> Jan  3 09:03:04 e4 /etc/gdm/Xsession[1369]: 2014-01-03 09:03:04.347820 I  Player(0): FPS:   59.91 Mean: 16690 Std.Dev:  3109 CPUs: 18j 6j 13j 6j
> Jan  3 09:03:05 e4 /etc/gdm/Xsession[1369]: 2014-01-03 09:03:05.182461 I  Player(0): FPS:   59.93 Mean: 16686 Std.Dev:  3144 CPUs: 0j 0j 17j 18j
> Jan  3 09:03:06 e4 /etc/gdm/Xsession[1369]: 2014-01-03 09:03:06.016753 I  Player(0): FPS:   59.95 Mean: 16679 Std.Dev:  3137 CPUs: 1j 1j 23j 16j
> Jan  3 09:03:06 e4 /etc/gdm/Xsession[1369]: 2014-01-03 09:03:06.851863 I  Player(0): FPS:   59.89 Mean: 16696 Std.Dev:  3111 CPUs: 2j 1j 23j 17j
> Jan  3 09:03:07 e4 /etc/gdm/Xsession[1369]: 2014-01-03 09:03:07.686692 I  Player(0): FPS:   59.91 Mean: 16690 Std.Dev:  3120 CPUs: 2j 0j 20j 14j
> Jan  3 09:03:08 e4 /etc/gdm/Xsession[1369]: 2014-01-03 09:03:08.521074 I  Player(0): FPS:   59.95 Mean: 16681 Std.Dev:  3088 CPUs: 1j 1j 15j 20j
> Jan  3 09:03:09 e4 /etc/gdm/Xsession[1369]: 2014-01-03 09:03:09.355972 I  Player(0): FPS:   59.91 Mean: 16692 Std.Dev:  5546 CPUs: 4j 1j 23j 13j
> Jan  3 09:03:10 e4 /etc/gdm/Xsession[1369]: 2014-01-03 09:03:10.190355 I  Player(0): FPS:   59.94 Mean: 16682 Std.Dev:  4913 CPUs: 6j 1j 17j 13j
> Jan  3 09:03:10 e4 /etc/gdm/Xsession[1369]: 2014-01-03 09:03:10.474812 I  Player(0): FPS:  175.95 Mean:  5683 Std.Dev:  9288 CPUs: 38j 24j 21j 20j
> Jan  3 09:03:10 e4 /etc/gdm/Xsession[1369]: 2014-01-03 09:03:10.651857 I  Player(0): FPS:  282.84 Mean:  3535 Std.Dev:  1677 CPUs: 100j 6j 6j 12j
> Jan  3 09:03:10 e4 /etc/gdm/Xsession[1369]: 2014-01-03 09:03:10.808028 I  Player(0): FPS:  320.62 Mean:  3118 Std.Dev:  1310 CPUs: 33j 65j 33j 12j
> Jan  3 09:03:10 e4 /etc/gdm/Xsession[1369]: 2014-01-03 09:03:10.988271 I  Player(0): FPS:  277.83 Mean:  3599 Std.Dev:  2098 CPUs: 17j 17j 100j 29j
> Jan  3 09:03:11 e4 /etc/gdm/Xsession[1369]: 2014-01-03 09:03:11.161234 I  Player(0): FPS:  289.45 Mean:  3454 Std.Dev:  1838 CPUs: 6j 0j 100j 19j
> Jan  3 09:03:11 e4 /etc/gdm/Xsession[1369]: 2014-01-03 09:03:11.319495 I  Player(0): FPS:  316.37 Mean:  3160 Std.Dev:  1703 CPUs: 0j 100j 19j 6j
> Jan  3 09:03:11 e4 /etc/gdm/Xsession[1369]: 2014-01-03 09:03:11.452541 I  Player(0): FPS:  376.51 Mean:  2655 Std.Dev:  1552 CPUs: 7j 100j 0j 14j
> Jan  3 09:03:11 e4 /etc/gdm/Xsession[1369]: 2014-01-03 09:03:11.592611 I  Player(0): FPS:  357.67 Mean:  2795 Std.Dev:  1806 CPUs: 0j 100j 15j 8j
> Jan  3 09:03:11 e4 /etc/gdm/Xsession[1369]: 2014-01-03 09:03:11.727276 I  Player(0): FPS:  372.00 Mean:  2688 Std.Dev:  1227 CPUs: 0j 100j 15j 14j
> Jan  3 09:03:12 e4 /etc/gdm/Xsession[1369]: 2014-01-03 09:03:11.941537 N  Player(0): Waited 103ms for video buffers AAAAAAAAAAAAAAAAAAAUUUUUUUUUuuLP
> Jan  3 09:03:12 e4 /etc/gdm/Xsession[1369]: 2014-01-03 09:03:11.971147 I  Player(0): FPS:  205.25 Mean:  4872 Std.Dev: 15135 CPUs: 0j 100j 4j 8j
> Jan  3 09:03:12 e4 /etc/gdm/Xsession[1369]: 2014-01-03 09:03:12.116512 I  Player(0): FPS:  344.56 Mean:  2902 Std.Dev:  1621 CPUs: 7j 100j 27j 7j
> Jan  3 09:03:12 e4 /etc/gdm/Xsession[1369]: 2014-01-03 09:03:12.263511 I  Player(0): FPS:  340.65 Mean:  2935 Std.Dev:  1444 CPUs: 0j 100j 13j 7j
> Jan  3 09:03:12 e4 /etc/gdm/Xsession[1369]: 2014-01-03 09:03:12.410151 I  Player(0): FPS:  341.51 Mean:  2928 Std.Dev:  1582 CPUs: 21j 100j 7j 7j
> Jan  3 09:03:12 e4 /etc/gdm/Xsession[1369]: 2014-01-03 09:03:12.561050 I  Player(0): FPS:  331.86 Mean:  3013 Std.Dev:   783 CPUs: 25j 100j 7j 0j
> Jan  3 09:03:12 e4 /etc/gdm/Xsession[1369]: 2014-01-03 09:03:12.701665 I  Player(0): FPS:  356.19 Mean:  2807 Std.Dev:  1662 CPUs: 21j 100j 0j 0j
> Jan  3 09:03:12 e4 /etc/gdm/Xsession[1369]: 2014-01-03 09:03:12.837635 I  Player(0): FPS:  368.40 Mean:  2714 Std.Dev:  1439 CPUs: 17j 100j 8j 0j
> Jan  3 09:03:13 e4 /etc/gdm/Xsession[1369]: 2014-01-03 09:03:12.975858 I  Player(0): FPS:  362.34 Mean:  2759 Std.Dev:  1372 CPUs: 21j 100j 0j 0j
> Jan  3 09:03:13 e4 /etc/gdm/Xsession[1369]: 2014-01-03 09:03:13.126233 I  Player(0): FPS:  333.02 Mean:  3002 Std.Dev:  1761 CPUs: 20j 100j 6j 12j
> Jan  3 09:03:13 e4 /etc/gdm/Xsession[1369]: 2014-01-03 09:03:13.308415 I  Player(0): FPS:  274.85 Mean:  3638 Std.Dev:  1101 CPUs: 16j 100j 0j 0j
> Jan  3 09:03:13 e4 /etc/gdm/Xsession[1369]: 2014-01-03 09:03:13.494249 I  Player(0): FPS:  269.42 Mean:  3711 Std.Dev:  1490 CPUs: 5j 100j 19j 11j
> Jan  3 09:03:13 e4 /etc/gdm/Xsession[1369]: 2014-01-03 09:03:13.676611 I  Player(0): FPS:  274.57 Mean:  3642 Std.Dev:  1319 CPUs: 0j 100j 6j 11j
>
> I get the impression that the video, at times, plays as fast as it can get data rather than
> keep to a desired FPS.
>
> cheers

I should also say that often (probably when it hangs) I get the following problem after which
I need to reboot the machine:

Jan  2 09:06:13 e4 kernel: [329065.170007] nouveau E[Xorg[10687]] failed to idle channel 0xcccc0000 [Xorg[10687]]
Jan  2 09:06:13 e4 kernel: [329065.172141] nouveau E[     PFB][0000:01:00.0] trapped read at 0x002001e020 on channel 0x0001fb23 [unknown] SEMAPHORE_BG/PFIFO_READ/00 reason: PAGE_NOT_PRESENT
Jan  2 09:06:13 e4 kernel: [329065.182673] nouveau E[  PGRAPH][0000:01:00.0] TRAP_M2MF NOTIFY
Jan  2 09:06:13 e4 kernel: [329065.183658] nouveau E[  PGRAPH][0000:01:00.0] TRAP_M2MF 00304041 00004360 00000000 06000432
Jan  2 09:06:13 e4 kernel: [329065.183658] nouveau E[  PGRAPH][0000:01:00.0]  TRAP
Jan  2 09:06:13 e4 kernel: [329065.183658] nouveau E[  PGRAPH][0000:01:00.0] ch 2 [0x001fb23000 Xorg[10687]] subc 0 class 0x5039 mthd 0x023c data 0x00000000
Jan  2 09:06:13 e4 kernel: [329065.183658] nouveau E[     PFB][0000:01:00.0] trapped write at 0x002001e010 on channel 0x0001fb23 [Xorg[10687]] PGRAPH/DISPATCH/M2M_NOTIFY reason: PAGE_NOT_PRESENT
Jan  2 09:06:13 e4 kernel: [329065.222272] nouveau E[  PGRAPH][0000:01:00.0] TRAP_M2MF IN
Jan  2 09:06:13 e4 kernel: [329065.223258] nouveau E[  PGRAPH][0000:01:00.0] TRAP_M2MF 00320151 00000240 00000000 04000000
Jan  2 09:06:13 e4 kernel: [329065.223258] nouveau E[  PGRAPH][0000:01:00.0]  TRAP
Jan  2 09:06:13 e4 kernel: [329065.223258] nouveau E[  PGRAPH][0000:01:00.0] ch 2 [0x001fb23000 Xorg[10687]] subc 0 class 0x5039 mthd 0x0328 data 0x00000000
Jan  2 09:06:13 e4 kernel: [329065.223258] nouveau E[     PFB][0000:01:00.0] trapped write at 0x002001e020 on channel 0x0001fb23 [unknown] PFIFO/PFIFO_READ/SEMAPHORE reason: PAGE_NOT_PRESENT
Jan  2 09:06:13 e4 kernel: [329065.267454] nouveau E[   PFIFO][0000:01:00.0] CACHE_ERROR - ch 2 [Xorg[10687]] subc 1 mthd 0x0068 data 0x11111111
Jan  2 09:06:13 e4 kernel: [329065.268425] nouveau E[     PFB][0000:01:00.0] trapped read at 0x002001e024 on channel 0x0001fb23 [unknown] PFIFO/PFIFO_READ/SEMAPHORE reason: PAGE_NOT_PRESENT
Jan  2 09:06:13 e4 kernel: [329065.289336] nouveau E[     PFB][0000:01:00.0] trapped write at 0x002001a024 on channel 0x0001fb23 [unknown] PFIFO/PFIFO_READ/SEMAPHORE reason: NULL_DMAOBJ
Jan  2 09:06:13 e4 kernel: [329065.304309] nouveau E[  PGRAPH][0000:01:00.0] TRAP_M2MF NOTIFY
Jan  2 09:06:13 e4 kernel: [329065.305295] nouveau E[  PGRAPH][0000:01:00.0] TRAP_M2MF 00304041 00004360 00000000 06000432
Jan  2 09:06:13 e4 kernel: [329065.305295] nouveau E[  PGRAPH][0000:01:00.0]  TRAP
Jan  2 09:06:13 e4 kernel: [329065.305295] nouveau E[  PGRAPH][0000:01:00.0] ch 2 [0x001fb23000 Xorg[10687]] subc 0 class 0x5039 mthd 0x0328 data 0x00000000
Jan  2 09:06:13 e4 kernel: [329065.305295] nouveau E[     PFB][0000:01:00.0] trapped write at 0x002001e010 on channel 0x0001fb23 [Xorg[10687]] PGRAPH/DISPATCH/M2M_NOTIFY reason: PAGE_NOT_PRESENT
Jan  2 09:06:13 e4 kernel: [329065.361944] nouveau E[  PGRAPH][0000:01:00.0] TRAP_M2MF NOTIFY
Jan  2 09:06:13 e4 kernel: [329065.362924] nouveau E[  PGRAPH][0000:01:00.0] TRAP_M2MF 00304041 00004360 00000000 06000432
Jan  2 09:06:13 e4 kernel: [329065.362924] nouveau E[  PGRAPH][0000:01:00.0]  TRAP
Jan  2 09:06:13 e4 kernel: [329065.362924] nouveau E[  PGRAPH][0000:01:00.0] ch 2 [0x001fb23000 Xorg[10687]] subc 0 class 0x5039 mthd 0x0328 data 0x00000000
Jan  2 09:06:14 e4 /etc/gdm/Xsession[20209]: xfce4-session: Fatal IO error 11 (Resource temporarily unavailable) on X server :0.
Jan  2 09:06:14 e4 /etc/gdm/Xsession[20209]: xfwm4: Fatal IO error 11 (Resource temporarily unavailable) on X server :0.0.
Jan  2 09:06:14 e4 /etc/gdm/Xsession[20209]: xfce4-panel: Fatal IO error 4 (Interrupted system call) on X server :0.
Jan  2 09:06:15 e4 gdm[933]: Child process 10687 was already dead.
Jan  2 09:06:15 e4 gdm[933]: GLib-GObject: g_object_ref: assertion `object->ref_count > 0' failed
Jan  2 09:06:15 e4 gdm[933]: GLib-GObject: g_object_unref: assertion `object->ref_count > 0' failed
Jan  2 09:06:15 e4 /etc/gdm/Xsession[20209]: wrapper: Fatal IO error 104 (Connection reset by peer) on X server :0.0.
Jan  2 09:06:15 e4 /etc/gdm/Xsession[20209]: xfdesktop: Fatal IO error 104 (Connection reset by peer) on X server :0.0.
Jan  2 09:06:15 e4 /etc/gdm/Xsession[20209]: firefox: Fatal IO error 11 (Resource temporarily unavailable) on X server :0.0.
Jan  2 09:06:15 e4 /etc/gdm/Xsession[20209]: orage: Fatal IO error 11 (Resource temporarily unavailable) on X server :0.0.
Jan  2 09:06:15 e4 /etc/gdm/Xsession[20209]: wrapper: Fatal IO error 104 (Connection reset by peer) on X server :0.0.
Jan  2 09:06:15 e4 /etc/gdm/Xsession[20209]: thunderbird: Fatal IO error 11 (Resource temporarily unavailable) on X server :0.0.
Jan  2 09:06:15 e4 /etc/gdm/Xsession[20209]: XIO:  fatal IO error 11 (Resource temporarily unavailable) on X server ":0.0"
Jan  2 09:06:15 e4 /etc/gdm/Xsession[20209]: after 46708 requests (46708 known processed) with 0 events remaining.
Jan  2 09:06:15 e4 /etc/gdm/Xsession[20209]: XIO:  fatal IO error 11 (Resource temporarily unavailable) on X server ":0.0"
Jan  2 09:06:15 e4 /etc/gdm/Xsession[20209]: after 31332 requests (31332 known processed) with 0 events remaining.
Jan  2 09:06:15 e4 /etc/gdm/Xsession[20209]: Thunar: Fatal IO error 11 (Resource temporarily unavailable) on X server :0.0.
Jan  2 09:06:15 e4 /etc/gdm/Xsession[20209]: xterm: fatal IO error 11 (Resource temporarily unavailable) or KillClient on X server ":0.0"
Jan  2 09:06:15 e4 /etc/gdm/Xsession[20209]: xterm: fatal IO error 11 (Resource temporarily unavailable) or KillClient on X server ":0"
Jan  2 09:06:15 e4 /etc/gdm/Xsession[20209]: xterm: fatal IO error 11 (Resource temporarily unavailable) or KillClient on X server ":0"
Jan  2 09:06:15 e4 /etc/gdm/Xsession[20209]: xterm: fatal IO error 11 (Resource temporarily unavailable) or KillClient on X server ":0"
Jan  2 09:06:15 e4 /etc/gdm/Xsession[20209]: xterm: fatal IO error 11 (Resource temporarily unavailable) or KillClient on X server ":0"
Jan  2 09:06:15 e4 /etc/gdm/Xsession[20209]: xterm: fatal IO error 11 (Resource temporarily unavailable) or KillClient on X server ":0"

... and so on, then the system locks and a reboot followes...

cheers

-- 
Eyal Lebedinsky	(eyal at eyal.emu.id.au)


More information about the mythtv-users mailing list