Opened 5 years ago

Closed 3 years ago

#12397 closed Bug Report - General (Works for me)

All recordings could not be played

Reported by: ismota@… Owned by: JYA
Priority: minor Milestone: unknown
Component: MythTV - Video Playback Version: 0.27.4
Severity: medium Keywords:
Cc: pbennett@… Ticket locked: no

Description

After upgrading from 0.24 to 0.27 fixes all recording won't play. It happens older recordings and new ones too. About one of twenty recordings has this problem.

This is frontend error log: AFD: OpenFile? -- begin 2015-02-25 20:54:51.774049 I AFD: Buffer size: 32768 streamed 0 seekable 1 2015-02-25 20:54:53.209917 E AFD: Could not find codec parameters. file was "myth://192.168.1.98/1050_20150224165300.mpg". 2015-02-25 20:54:53.210034 E Couldn't open decoder for: myth://192.168.1.98/1050_20150224165300.mpg 2015-02-25 20:54:53.210064 E Player(0): Unable to open video file. 2015-02-25 20:54:53.210080 E playCtx: StartPlaying?() Failed to start player

Old 0.24 frontend played those files correctly. I am using VDPAU.

This bug is also tested in master with amd/intel/nvidia hardware and none of them plays those.

This is download link for non-working test file. It won't work in recordings or when copied to video library. https://www.dropbox.com/s/2hvwwffn3beacdk/1050_20150224165300.mpg?dl=0

If I run ffmpeg stream copy against file, it can be played after that.

Change History (19)

comment:1 Changed 5 years ago by blm-ubunet@…

The OPs attached recording plays in mythtv when frontend is started with "-O FFMPEGTS=1" override. It appears that without the override the stream codec probing fails. Possibly because is does not probe far/long enough.

The alternative code path (with override) uses different libav* function.

Assuming you are using DVB.. Do you have the backend recording setup "DVBWaitForSeqStart" set ? This stops your recordings having unusable junk at start.

comment:2 Changed 5 years ago by J.Pilk@…

... but not always. I get this with part-time DVB channels in the UK if the recording includes startup or closedown.

comment:3 Changed 5 years ago by ismota@…

Yes, I have "DVBWaitForSeqStart" set for all tuners. This seems to happen quite rarely now. I have found few old recordings that won't play, but not crossed any new ones in few weeks. Somehow player code has changed as 0.24 could play those recordings fine.

comment:4 Changed 3 years ago by brian@…

This is happening on 0.28 still/also.

Are there any plans to make the player more resilient to these files?

comment:5 Changed 3 years ago by Peter Bennett

I tested the sample on the latest 0.28 and it plays OK. I suspect it is a duplicate of #12787 which I fixed 2 months ago. Are you using a recent build of 0.28/fixes? If you are still having this on the latest 0.28/fixes can you give a sample that fails?

comment:6 Changed 3 years ago by Peter Bennett

Cc: pbennett@… added

comment:7 in reply to:  5 Changed 3 years ago by brian@…

Replying to pbennett:

I tested the sample on the latest 0.28 and it plays OK. I suspect it is a duplicate of #12787 which I fixed 2 months ago. Are you using a recent build of 0.28/fixes?

mythfrontend version: fixes/0.28 [v28.0-35-g812ec08] www.mythtv.org

If you are still having this on the latest 0.28/fixes

I'm just using what is available in F24. I don't build from source here. If something more recent is needed I will prod upstream.

can you give a sample that fails?

http://www.interlinx.bc.ca/~brian/12397.mpg is a 1MB sample. If it's not long enough let me know how many MBs you will need.

comment:8 Changed 3 years ago by J.Pilk@…

No problem playing that as a recording, as a video, and in vlc. I'm using a rebuild for el7 from essentially the same SRPM. How come it doesn't have a .ts suffix? mythffprobe -i sees it as mpegts. Has it been post-processed? Did you use the upload procedure quoted in #12787?

comment:9 Changed 3 years ago by Peter Bennett

The fix for #12787 is not in that commit (812ec08). The fix is two commits after that. See if you can get a later build from fixes/0.28.

I confirm the video sample you provided plays fine on latest 0.28/fixes.

Last edited 3 years ago by Peter Bennett (previous) (diff)

comment:10 Changed 3 years ago by J.Pilk@…

I don't see any sign of a newer build at rpmfusion. Brian, do you still see the problem when you try with your file as downloaded?

comment:11 in reply to:  10 Changed 3 years ago by brian@…

Replying to J.Pilk@…:

I don't see any sign of a newer build at rpmfusion.

Yeah. What I am using is their latest. They need to re-spin with the latest 0.28/fixes. Unlike Mythbuntu, they don't rebuild on every commit to 0.28/fixes. Unfortunately.

Brian, do you still see the problem when you try with your file as downloaded?

Yes, because the build I have from rpmfusion, which is their latest is not the latest 0.28/fixes with the fix in it. I have requested a newer build.

comment:12 Changed 3 years ago by J.Pilk@…

OK. As I said, that file plays for me in v28.0-35-g812ec08 and I asked if you had checked with a downloaded copy. I hope the new build works for you.

comment:13 in reply to:  12 Changed 3 years ago by brian@…

Replying to J.Pilk@…:

I asked if you had checked with a downloaded copy.

I must have not understood what you were asking there then. My apologies. Can you rephrase?

comment:14 Changed 3 years ago by J.Pilk@…

You have a recording that does not play. You uploaded a section of it, which I have downloaded and can play. Our myth versions are essentially identical. The cut > upload > download process might have caused the difference that we see, with the cut (unless by dd) being the most likely suspect. I expect the rpmfusion update will take some time, so I thought it would clarify things if you downloaded your sample from interlinx and saw if the problem was still there. Or just try it with the file that you uploaded.

I tested as a 'recording' by making a new short recording and overwriting its file content; as a 'video' by putting the file into the video SG and (menu key) scanning for changes.

comment:15 in reply to:  14 Changed 3 years ago by brian@…

Replying to J.Pilk@…:

You have a recording that does not play. You uploaded a section of it, which I have downloaded and can play. Our myth versions are essentially identical.

Oh. I thought somebody said my version didn't have a fix for #12787 which fixes the problem.

The cut > upload > download process might have caused the difference that we see, with the cut (unless by dd)

Yes, it was by dd. That's the only way (that I know of) to make sure you have exactly what I have.

being the most likely suspect. I expect the rpmfusion update will take some time,

If it does and it gets to a point where I can't wait any longer, I will just pull down their RPM spec file, grab the latest 0.28/fixes and roll my own. But I'm not at that point yet so I will let my patience take over here.

so I thought it would clarify things if you downloaded your sample from interlinx and saw if the problem was still there.

But it will be given that it's just a dd copy.

I'll update here when I have a new version to try.

Cheers!

comment:16 Changed 3 years ago by hobbes1069@…

Doing local builds now for testing prior to doing official builds on RPM Fusion.

comment:17 Changed 3 years ago by brian@…

I have upgraded to mythfrontend version: fixes/0.28 [v0.28-52-ge6a60f7] www.mythtv.org via rpmfusion and now I get a different error on the problem recording(s):

2016-09-25 08:17:48.486424 I  TV::TV(): Creating TV object
2016-09-25 08:17:48.644309 N  Suspending idle timer
2016-09-25 08:17:48.654901 I  TV::Init(): Created TvPlayWindow.
2016-09-25 08:17:48.739646 I  TV::HandleStateChange(): Attempting to change from None to WatchingPreRecorded
2016-09-25 08:17:49.067790 E  ALSA: snd_pcm_info_get_card: Operation not permitted
2016-09-25 08:17:49.168720 N  AudioPlayer: Enabling Audio
libva info: VA-API version 0.39.3
libva info: va_getDriverName() returns 0
libva info: Trying to open /usr/lib64/dri/i965_drv_video.so
libva info: Found init function __vaDriverInit_0_39
libva info: va_openDriver() returns 0
2016-09-25 08:17:49.643497 I  AFD: codec AC3 has 0 channels
2016-09-25 08:17:49.643712 I  AFD: Opened codec 0x28da2a0, id(AC3) type(Audio)
2016-09-25 08:17:49.653471 I  VAAPI: Version: 0.39
2016-09-25 08:17:49.653476 I  VAAPI: Driver : Intel i965 driver for Intel(R) Haswell Desktop - 1.7.2
2016-09-25 08:17:49.653488 I  VAAPI: Profile: MPEG2Simple Entrypoints: VLD EncSlice (UNSUPPORTED) 
2016-09-25 08:17:49.653493 I  VAAPI: Profile: MPEG2Main Entrypoints: VLD EncSlice (UNSUPPORTED) 
2016-09-25 08:17:49.653495 I  VAAPI: Profile: H264ConstrainedBase Entrypoints: VLD EncSlice (UNSUPPORTED) 
2016-09-25 08:17:49.653498 I  VAAPI: Profile: H264Main Entrypoints: VLD EncSlice (UNSUPPORTED) 
2016-09-25 08:17:49.653501 I  VAAPI: Profile: H264High Entrypoints: VLD EncSlice (UNSUPPORTED) 
2016-09-25 08:17:49.653504 I  VAAPI: Profile: Unknown Entrypoints: VLD EncSlice (UNSUPPORTED) 
2016-09-25 08:17:49.653507 I  VAAPI: Profile: H264StereoHigh Entrypoints: VLD EncSlice (UNSUPPORTED) 
2016-09-25 08:17:49.653509 I  VAAPI: Profile: VC1Simple Entrypoints: VLD 
2016-09-25 08:17:49.653511 I  VAAPI: Profile: VC1Main Entrypoints: VLD 
2016-09-25 08:17:49.653514 I  VAAPI: Profile: VC1Advanced Entrypoints: VLD 
2016-09-25 08:17:49.653517 I  VAAPI: Profile: None Entrypoints: VideoProc (UNSUPPORTED) 
2016-09-25 08:17:49.653519 I  VAAPI: Profile: Unknown Entrypoints: VLD 
2016-09-25 08:17:49.653903 I  AFD: Opened codec 0x28d9a00, id(MPEG2VIDEO) type(Video)
2016-09-25 08:17:49.653911 W  Enabling buffering optimisations for low bitrate stream.
2016-09-25 08:17:49.656731 N  AudioPlayer: Enabling Audio
libva info: VA-API version 0.39.3
libva info: va_getDriverName() returns 0
libva info: Trying to open /usr/lib64/dri/i965_drv_video.so
libva info: Found init function __vaDriverInit_0_39
libva info: va_openDriver() returns 0
2016-09-25 08:17:50.004106 I  GLVid: Using raw RGBA input textures.
2016-09-25 08:17:50.017405 I  OSD: Base theme size: 800x600
2016-09-25 08:17:50.017422 I  OSD: Scaling factors: 1.065x0.8
libpng warning: iCCP: known incorrect sRGB profile
libpng warning: iCCP: known incorrect sRGB profile
2016-09-25 08:17:50.129054 I  OSD: Base theme size: 800x600
2016-09-25 08:17:50.129063 I  OSD: Scaling factors: 1.065x0.8
2016-09-25 08:17:50.148005 I  Player(0): Video timing method: DRM
libva info: VA-API version 0.39.3
libva info: va_getDriverName() returns 0
libva info: Trying to open /usr/lib64/dri/i965_drv_video.so
libva info: Found init function __vaDriverInit_0_39
libva info: va_openDriver() returns 0
2016-09-25 08:17:50.164430 I  AFD: codec AC3 has 0 channels
2016-09-25 08:17:50.164697 I  AFD: Opened codec 0x7fbca00051e0, id(AC3) type(Audio)
2016-09-25 08:17:50.164712 I  AFD: codec AC3 has 0 channels
2016-09-25 08:17:50.164939 I  AFD: Opened codec 0x7fbca0005d20, id(AC3) type(Audio)
2016-09-25 08:17:50.167418 I  TV::StartPlayer(): Created player.
2016-09-25 08:17:50.167784 I  TV::HandleStateChange(): Changing from None to WatchingPreRecorded
2016-09-25 08:17:50.171652 I  TV::HandleStateChange(): Main UI disabled.
2016-09-25 08:17:50.171693 I  TV::StartTV(): Entering main playback loop.
2016-09-25 08:17:50.175395 I  AFD: Opened codec 0x7fbca0004940, id(MPEG2VIDEO) type(Video)
2016-09-25 08:17:50.175400 W  Enabling buffering optimisations for low bitrate stream.
2016-09-25 08:17:50.178457 I  AOBase: Opening audio device 'pulse' ch 2(2) sr 48000 sf 32 bit floating point reenc 0
2016-09-25 08:17:50.194885 N  VidOutGL: Deferring creation of OpenGL resources
2016-09-25 08:17:50.194890 E  VidOutGLVAAPI: CreateVAAPIContext called from non-UI thread
2016-09-25 08:17:50.194898 E  VidOutGLVAAPI: Failed to re-initialise video output.
2016-09-25 08:17:50.194902 E  Player(0): Failed to Reinitialize Video. Exiting..
2016-09-25 08:17:50.218175 I  ScreenSaverDBus: Successfully inhibited screensaver via org.freedesktop.ScreenSaver. cookie 1356482398. nom nom
2016-09-25 08:17:50.218497 W  ScreenSaverDBus: Failed to disable screensaver: Method "Inhibit" with signature "ss" on interface "org.gnome.SessionManager" doesn't exist

2016-09-25 08:17:50.218776 I  ScreenSaverX11Private: DPMS Deactivated 1
2016-09-25 08:17:50.457006 I  TV::HandleStateChange(): Attempting to change from WatchingPreRecorded to None
2016-09-25 08:17:50.557172 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:50.657283 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:50.757383 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:50.857502 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:50.957596 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:51.057691 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:51.157796 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:51.257879 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:51.358002 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:51.458119 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:51.558232 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:51.658328 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:51.758451 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:51.858537 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:51.958625 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:52.058722 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:52.158813 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:52.258913 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:52.359010 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:52.459134 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:52.559220 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:52.659321 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:52.759412 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:52.859513 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:52.959607 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:53.059719 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:53.159820 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:53.259931 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:53.360022 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:53.460116 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:53.560203 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:53.660311 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:53.760391 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:53.860495 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:53.960594 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:54.060682 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:54.160789 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:54.260873 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:54.360989 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:54.461069 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:54.561159 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:54.661263 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:54.761350 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:54.861470 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:54.961561 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:55.061657 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:55.161744 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:55.261846 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:55.361989 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:55.462092 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:55.562180 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:55.662290 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:55.762403 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:55.862516 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:55.962625 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:56.062726 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:56.162824 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:56.262911 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:56.363018 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:56.463109 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:56.563203 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:56.663299 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:56.763417 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:56.863500 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:56.963594 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:57.063681 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:57.163772 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:57.263887 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:57.363998 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:57.464089 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:57.564175 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:57.664311 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:57.764402 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:57.864512 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:57.964639 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:58.064752 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:58.164882 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:58.264996 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:58.365085 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:58.465175 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:58.565291 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:58.665400 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:58.765488 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:58.865586 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:58.965692 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:59.065790 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:59.165886 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:59.266002 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:59.366092 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:59.466183 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:59.566305 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:59.666407 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:59.766534 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:59.866665 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:17:59.966757 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:18:00.066858 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:18:00.166987 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:18:00.267092 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:18:00.367240 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:18:00.467341 W  Player(0): Waited 100ms for decoder to pause
2016-09-25 08:18:00.490396 I  TV::HandleStateChange(): Changing from WatchingPreRecorded to None
2016-09-25 08:18:00.490464 I  TV::StartTV(): Exiting main playback loop.
2016-09-25 08:18:00.490585 I  ScreenSaverDBus: Screensaver uninhibited via org.freedesktop.ScreenSaver
2016-09-25 08:18:00.490781 I  ScreenSaverX11Private: DPMS Reactivated 1
2016-09-25 08:18:00.503741 E  Preview: 1910: 
2016-09-25 08:18:00.518623 N  Resuming idle timer
2016-09-25 08:18:09.154852 I  TV::TV(): Creating TV object
2016-09-25 08:18:09.167371 N  Suspending idle timer
2016-09-25 08:18:09.170658 I  TV::Init(): Created TvPlayWindow.
2016-09-25 08:18:09.187107 I  TV::HandleStateChange(): Attempting to change from None to WatchingPreRecorded
libva info: VA-API version 0.39.3
libva info: va_getDriverName() returns 0
libva info: Trying to open /usr/lib64/dri/i965_drv_video.so
libva info: Found init function __vaDriverInit_0_39
libva info: va_openDriver() returns 0
2016-09-25 08:18:09.253610 E  ALSA: snd_pcm_info_get_card: Operation not permitted
2016-09-25 08:18:09.264870 N  AudioPlayer: Enabling Audio
2016-09-25 08:18:09.280850 I  AFD: codec AC3 has 0 channels
2016-09-25 08:18:09.281082 I  AFD: Opened codec 0x62a7b80, id(AC3) type(Audio)
2016-09-25 08:18:09.289819 I  AFD: Opened codec 0x489b520, id(MPEG2VIDEO) type(Video)
2016-09-25 08:18:09.289827 W  Enabling buffering optimisations for low bitrate stream.
2016-09-25 08:18:09.289844 N  AudioPlayer: Enabling Audio
libva info: VA-API version 0.39.3
libva info: va_getDriverName() returns 0
libva info: Trying to open /usr/lib64/dri/i965_drv_video.so
libva info: Found init function __vaDriverInit_0_39
libva info: va_openDriver() returns 0
2016-09-25 08:18:33.953655 I  GLVid: Using raw RGBA input textures.
2016-09-25 08:18:33.960397 I  OSD: Base theme size: 800x600
2016-09-25 08:18:33.960407 I  OSD: Scaling factors: 1.065x0.8
2016-09-25 08:18:33.980364 I  OSD: Base theme size: 800x600
2016-09-25 08:18:33.980375 I  OSD: Scaling factors: 1.065x0.8
libva info: VA-API version 0.39.3
libva info: va_getDriverName() returns 0
libva info: Trying to open /usr/lib64/dri/i965_drv_video.so
libva info: Found init function __vaDriverInit_0_39
libva info: va_openDriver() returns 0
2016-09-25 08:18:34.015160 I  Player(1): Video timing method: DRM
2016-09-25 08:18:34.031081 I  AFD: codec AC3 has 0 channels
2016-09-25 08:18:34.031336 I  AFD: Opened codec 0x7fbc80008860, id(AC3) type(Audio)
2016-09-25 08:18:34.031349 I  AFD: codec AC3 has 0 channels
2016-09-25 08:18:34.031561 I  AFD: Opened codec 0x7fbc8000a280, id(AC3) type(Audio)
2016-09-25 08:18:34.031864 I  TV::StartPlayer(): Created player.
2016-09-25 08:18:34.031897 I  TV::HandleStateChange(): Changing from None to WatchingPreRecorded
2016-09-25 08:18:34.035441 I  TV::HandleStateChange(): Main UI disabled.
2016-09-25 08:18:34.035486 I  TV::StartTV(): Entering main playback loop.
2016-09-25 08:18:34.040646 I  AFD: Opened codec 0x7fbc80007e60, id(MPEG2VIDEO) type(Video)
2016-09-25 08:18:34.040654 W  Enabling buffering optimisations for low bitrate stream.
2016-09-25 08:18:34.044408 E  Preview: 2618: 
2016-09-25 08:18:34.044423 E  Preview: 2680: 
2016-09-25 08:18:34.046534 I  ScreenSaverDBus: Successfully inhibited screensaver via org.freedesktop.ScreenSaver. cookie 963999393. nom nom
2016-09-25 08:18:34.046882 W  ScreenSaverDBus: Failed to disable screensaver: Method "Inhibit" with signature "ss" on interface "org.gnome.SessionManager" doesn't exist

2016-09-25 08:18:34.047084 I  ScreenSaverX11Private: DPMS Deactivated 1
2016-09-25 08:18:34.083271 I  AOBase: Opening audio device 'pulse' ch 2(2) sr 48000 sf 32 bit floating point reenc 0
2016-09-25 08:18:34.096580 N  VidOutGL: Deferring creation of OpenGL resources
2016-09-25 08:18:34.096586 E  VidOutGLVAAPI: CreateVAAPIContext called from non-UI thread
2016-09-25 08:18:34.096588 E  VidOutGLVAAPI: Failed to re-initialise video output.
2016-09-25 08:18:34.096592 E  Player(1): Failed to Reinitialize Video. Exiting..
2016-09-25 08:18:34.286112 I  TV::HandleStateChange(): Attempting to change from WatchingPreRecorded to None
2016-09-25 08:18:34.386252 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:34.486367 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:34.586464 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:34.686577 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:34.786694 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:34.886789 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:34.986878 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:35.086969 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:35.187075 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:35.287181 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:35.387270 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:35.487361 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:35.587472 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:35.687573 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:35.787673 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:35.887776 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:35.987883 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:36.087978 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:36.188089 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:36.288204 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:36.388296 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:36.488400 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:36.588500 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:36.688600 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:36.788714 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:36.888821 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:36.988912 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:37.088989 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:37.189080 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:37.289170 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:37.389291 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:37.489403 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:37.589498 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:37.690058 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:37.790165 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:37.890267 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:37.990387 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:38.090496 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:38.190643 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:38.290755 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:38.390870 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:38.490997 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:38.591092 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:38.691262 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:38.791396 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:38.891501 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:38.991590 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:39.091674 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:39.191784 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:39.291896 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:39.392013 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:39.492116 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:39.592273 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:39.692386 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:39.792485 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:39.892571 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:39.992657 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:40.092757 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:40.192872 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:40.292981 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:40.393085 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:40.493179 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:40.593278 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:40.693364 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:40.793478 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:40.893574 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:40.993662 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:41.093776 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:41.193865 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:41.293980 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:41.394064 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:41.494111 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:41.594213 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:41.694317 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:41.794406 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:41.894499 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:41.994586 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:42.094695 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:42.194823 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:42.294919 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:42.395018 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:42.495137 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:42.595223 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:42.695329 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:42.795436 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:42.895538 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:42.995646 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:43.095759 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:43.195861 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:43.295982 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:43.396068 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:43.496163 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:43.596253 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:43.696342 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:43.796457 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:43.896552 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:43.996673 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:44.096789 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:44.196874 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:44.296989 W  Player(1): Waited 100ms for decoder to pause
2016-09-25 08:18:44.361123 I  TV::HandleStateChange(): Changing from WatchingPreRecorded to None
2016-09-25 08:18:44.361177 I  TV::StartTV(): Exiting main playback loop.
2016-09-25 08:18:44.361261 I  ScreenSaverDBus: Screensaver uninhibited via org.freedesktop.ScreenSaver
2016-09-25 08:18:44.361374 I  ScreenSaverX11Private: DPMS Reactivated 1
2016-09-25 08:18:44.393644 N  Resuming idle timer
2016-09-25 08:18:44.824235 E  Preview: 1790: 
2016-09-25 08:19:06.022681 I  TV::TV(): Creating TV object
2016-09-25 08:19:06.034199 N  Suspending idle timer
2016-09-25 08:19:06.038718 I  TV::Init(): Created TvPlayWindow.
2016-09-25 08:19:06.054268 I  TV::HandleStateChange(): Attempting to change from None to WatchingPreRecorded
2016-09-25 08:19:06.193308 E  ALSA: snd_pcm_info_get_card: Operation not permitted
2016-09-25 08:19:06.203644 N  AudioPlayer: Enabling Audio
libva info: VA-API version 0.39.3
libva info: va_getDriverName() returns 0
libva info: Trying to open /usr/lib64/dri/i965_drv_video.so
libva info: Found init function __vaDriverInit_0_39
libva info: va_openDriver() returns 0
2016-09-25 08:19:06.317649 I  AFD: codec AAC has 2 channels
2016-09-25 08:19:06.318082 I  AFD: Opened codec 0x2551780, id(AAC) type(Audio)
2016-09-25 08:19:06.318092 I  AFD: codec VORBIS has 2 channels
2016-09-25 08:19:06.318670 I  AFD: Opened codec 0x10c13c0, id(VORBIS) type(Audio)
2016-09-25 08:19:06.326187 I  AFD: Opened codec 0x29b38e0, id(H264) type(Video)
2016-09-25 08:19:06.326236 I  AOBase: Opening audio device 'pulse' ch 2(2) sr 48000 sf 32 bit floating point reenc 0

libva info: VA-API version 0.39.3
libva info: va_getDriverName() returns 0
libva info: Trying to open /usr/lib64/dri/i965_drv_video.so
libva info: Found init function __vaDriverInit_0_39
libva info: va_openDriver() returns 0
2016-09-25 08:19:17.143192 I  GLVid: Using raw RGBA input textures.
2016-09-25 08:19:17.151406 I  OSD: Base theme size: 800x600
2016-09-25 08:19:17.151422 I  OSD: Scaling factors: 1.065x0.8
2016-09-25 08:19:17.178931 I  OSD: Base theme size: 800x600
2016-09-25 08:19:17.178939 I  OSD: Scaling factors: 1.065x0.8
2016-09-25 08:19:17.198161 I  Player(2): Video timing method: DRM
2016-09-25 08:19:17.214517 I  TV::StartPlayer(): Created player.
2016-09-25 08:19:17.214573 I  TV::HandleStateChange(): Changing from None to WatchingPreRecorded
2016-09-25 08:19:17.217765 I  TV::HandleStateChange(): Main UI disabled.
2016-09-25 08:19:17.217801 I  TV::StartTV(): Entering main playback loop.
2016-09-25 08:19:17.239768 I  ScreenSaverDBus: Successfully inhibited screensaver via org.freedesktop.ScreenSaver. cookie 465660088. nom nom
2016-09-25 08:19:17.246764 W  ScreenSaverDBus: Failed to disable screensaver: Method "Inhibit" with signature "ss" on interface "org.gnome.SessionManager" doesn't exist

2016-09-25 08:19:17.246971 I  ScreenSaverX11Private: DPMS Deactivated 1
2016-09-25 08:19:17.253462 I  OSD: Base theme size: 800x600
2016-09-25 08:19:17.253473 I  OSD: Scaling factors: 1.065x0.8
2016-09-25 08:19:29.765238 I  OSD: Base theme size: 800x600
2016-09-25 08:19:29.765248 I  OSD: Scaling factors: 1.065x0.8
2016-09-25 08:19:29.813747 I  ScreenSaverDBus: Screensaver uninhibited via org.freedesktop.ScreenSaver
2016-09-25 08:19:29.813839 I  ScreenSaverX11Private: DPMS Reactivated 1
2016-09-25 08:19:32.298154 I  TV::HandleStateChange(): Attempting to change from WatchingPreRecorded to None
2016-09-25 08:19:32.812335 I  TV::HandleStateChange(): Changing from WatchingPreRecorded to None
2016-09-25 08:19:32.812355 I  TV::StartTV(): Exiting main playback loop.
2016-09-25 08:19:32.829482 N  Resuming idle timer
2016-09-25 08:19:34.590846 E  Preview: 2624: 
2016-09-25 08:20:12.084364 E  Preview: 2625: 
2016-09-25 08:20:13.039564 E  Preview: 2617: 
2016-09-25 08:20:43.502078 E  Preview: 2700: 
2016-09-25 08:21:54.084863 E  Preview: 2536: 
2016-09-25 08:21:55.096506 E  Preview: 2596: 
2016-09-25 08:22:25.225219 E  Preview: 2586: 
2016-09-25 08:22:28.040396 E  Preview: 2577: 
2016-09-25 08:22:45.598417 E  Preview: 2569: 
2016-09-25 08:22:49.522100 E  Preview: 2561: 
2016-09-25 08:22:59.655847 E  Preview: 2550: 
2016-09-25 08:23:04.974782 E  Preview: 2548: 

Which you might think is just a general playback problem, but newer recordings continue to play back with no problem.

I'm happy to crank up some debug levels and provide more output to help resolve this.

comment:18 Changed 3 years ago by Peter Bennett

The original post was from ismota and referred to Playback Profile VDPAU. It looks like the latest post is using VAAPI. Can you try with a different playback profile (e.g. Normal, Slim, or OpenGL) to see if this is now a VAAPI issue. If you try OpenGL make sure the appearance, paint engine is also set to OpenGL.

comment:19 Changed 3 years ago by Peter Bennett

Resolution: Works for me
Status: newclosed
Note: See TracTickets for help on using tickets.