Bug#742896: Blank screen on all videos with VDPAU and nVidia card (xbmc)

Sun Oct 19 18:51:57 UTC 2014

Hi Wojciech,

2014-10-19 14:22 GMT+02:00 Wojciech Kuranowski <wojciech at kuranowski.pl>:
> On 14 October 2014 00:02, Bálint Réczey <balint at balintreczey.hu> wrote:
>> Hi,
>>
>> 2014-10-13 23:46 GMT+02:00 Wojciech Kuranowski <wojciech at kuranowski.pl>:
>>> Yes, VDPAU acceleration fails with the latest package. But it's a bit
>>> better than before, because I have one example of working movie which
>>> was not working with previous libav based xbmc packages. All other
>>> tested movies fails with VDPAU. But everything works fine with ffmpeg
>>> based xbmc.
>>>
>>> This is my card:
>>> 01:00.0 VGA compatible controller: NVIDIA Corporation GK107 [GeForce
>>> GTX 650] (rev a1)
>>>
>>> Driver:
>>> nvidia-vdpau-driver:amd64            340.46-1
>>>
>>> How can I help?
>> I suspect some codecs work but others don't. Please collect xbmc logs
>> while playing the working and not working files and attach them to the
>> bug.
>
> It's strange. I have tried to play sample videos attached by Sergej
> Wildemann. And they sometimes work but not always. It's random. I have
> attached logs for both cases.
Thank you for the logs they are very useful.

The symptom and the logs suggest that it it a threading problem (T is
the thread id):
bad:
...
14:09:30 T:139908127639296  NOTICE: CDVDVideoCodecFFmpeg::GetFormat -
Creating VDPAU(1280x720)
14:09:30 T:139908119246592  NOTICE: running thread: CDVDPlayerAudio::Process()
14:09:30 T:139908119246592   DEBUG: CDVDPlayerAudio -
CDVDMsg::GENERAL_RESYNC(5000.000000, 1)
14:09:30 T:139908119246592  NOTICE: Creating audio stream (codec id:
86019, channels: 6, sample rate: 48000, no pass-through)
14:09:30 T:139908589209344    INFO: CActiveAESink::OpenSink - initialize sink
14:09:30 T:139908589209344   DEBUG: CActiveAESink::OpenSink - trying
to open device ALSA:@
14:09:30 T:139908589209344   DEBUG: CAESinkALSA::GetChannelLayout -
Input Channel Count: 2 Output Channel Count: 2
14:09:30 T:139908589209344   DEBUG: CAESinkALSA::GetChannelLayout -
Requested Layout: FL,FR
14:09:30 T:139908589209344   DEBUG: CAESinkALSA::GetChannelLayout -
Got Layout: FL,FR
14:09:30 T:139908589209344    INFO: CAESinkALSA::Initialize -
Attempting to open device "@"
14:09:30 T:139908119246592   DEBUG: CDVDPlayerAudio:: synctype set to
0: clock feedback
14:09:30 T:139908127639296  NOTICE: VDPAU::CreateContext - creating
decoder context
14:09:30 T:139908589209344    INFO: CAESinkALSA::Initialize - Opened
device "sysdefault"
14:09:30 T:139908589209344    INFO: CAESinkALSA::InitializeHW - Your
hardware does not support AE_FMT_FLOAT, trying other formats
...
14:09:30 T:139908127639296   DEBUG: CVDPAU::SetWidthHeight Setting
OutWidth: 870 OutHeight: 489
14:09:30 T:139908127639296  NOTICE:  (VDPAU) screenWidth:870
vidWidth:1280 surfaceWidth:1280
14:09:30 T:139908127639296  NOTICE:  (VDPAU) screenHeight:489
vidHeight:720 surfaceHeight:720
14:09:30 T:139907351705344  NOTICE: Thread Vdpau Output start, auto
delete: false
14:09:30 T:139907351705344  NOTICE: COutput::OnStartup: Output Thread created
14:09:30 T:139907351705344  NOTICE: VDPAU::COutput::CreateGlxContext -
created context
14:09:30 T:139907351705344  NOTICE: VDPAU::COutput: vdpau gl interop initialized
14:09:30 T:139907343312640  NOTICE: Thread Vdpau Mixer start, auto delete: false
14:09:30 T:139907343312640  NOTICE: CMixer::OnStartup: Output Thread created
14:09:30 T:139907343312640  NOTICE:  (VDPAU) Creating the video mixer
14:09:30 T:139907351705344  NOTICE: VDPAU::COutput::InitBufferPool -
Output Surface created
14:09:30 T:139908127639296  NOTICE: Previous line repeats 3 times.
14:09:30 T:139908127639296   DEBUG: CDVDPlayerVideo -
CDVDMsg::GENERAL_RESYNC(208000.000000, 0)
14:09:30 T:139908127639296   DEBUG: CDVDPlayerVideo - video decoder
returned error
14:09:30 T:139909238515776   DEBUG: Previous line repeats 53 times.
14:09:30 T:139909238515776   DEBUG: LogindUPowerSyscall - Received
unknown signal NameAcquired
14:09:30 T:139908127639296   DEBUG: CDVDPlayerVideo - video decoder
returned error
14:09:31 T:139908127639296   DEBUG: Previous line repeats 163 times.
14:09:31 T:139908127639296 WARNING: CDVDMessageQueue(video)::Get -
asked for new data packet, with nothing available
...

good:
...
14:17:40 T:139776842725120    INFO: CDVDPlayerVideo - Stillframe left,
switching to normal playback
14:17:40 T:139776842725120  NOTICE: CDVDVideoCodecFFmpeg::GetFormat -
Creating VDPAU(1280x720)
14:17:40 T:139776842725120  NOTICE: VDPAU::CreateContext - creating
decoder context
14:17:40 T:139777614022720  NOTICE: WebServer: Started the webserver
14:17:40 T:139777614022720  NOTICE: starting upnp server
14:17:40 T:139776867903232   DEBUG: CZeroconfAvahi::doPublishService
identifier: servers.webserver type: _http._tcp name:XBMC (home)
port:8123
14:17:40 T:139776867903232   DEBUG: CZeroconfAvahi::doPublishService:
client not running, queued for publishing
14:17:40 T:139776867903232   DEBUG: CZeroconfAvahi::doPublishService
identifier: servers.jsonrpc-http type: _xbmc-jsonrpc-h._tcp name:XBMC
(home) port:8123
...
14:17:40 T:139776054740736  NOTICE: CMixer::OnStartup: Output Thread created
14:17:40 T:139776054740736  NOTICE:  (VDPAU) Creating the video mixer
14:17:40 T:139776063133440  NOTICE: VDPAU::COutput::InitBufferPool -
Output Surface created
14:17:40 T:139776842725120  NOTICE: Previous line repeats 3 times.
14:17:40 T:139776842725120   DEBUG: CDVDPlayerVideo -
CDVDMsg::GENERAL_RESYNC(208000.000000, 0)
14:17:40 T:139776063133440  NOTICE: VDPAU::COutput::InitBufferPool -
Output Surface created
14:17:40 T:139776063133440  NOTICE: Previous line repeats 2 times.
14:17:40 T:139776063133440  NOTICE: VDPAU::COutput registered output surfaces
14:17:40 T:139776842725120  NOTICE: Previous line repeats 6 times.
14:17:40 T:139776842725120  NOTICE:  fps: 23.976024, pwidth: 870,
pheight: 489, dwidth: 1280, dheight: 720
14:17:40 T:139776842725120   DEBUG: OutputPicture - change
configuration. 870x489. framerate: 23.98. format: VDPAU
14:17:40 T:139776842725120  NOTICE: Display resolution DESKTOP :
1920x1200@ 59.95 - Full Screen (16)
14:17:40 T:139776842725120   DEBUG: CXBMCRenderManager::Configure - 3
14:17:40 T:139777614022720   DEBUG: Activating window ID: 12005
14:17:40 T:139777614022720   DEBUG: ------ Window Deinit (Home.xml) ------

I will ask Libav upstream about possible threading issues.

Cheers,
Balint