"Adjust display refresh rate" & "Sync playback" not working together anymore
#1
Hi.

I've been using XBMC on an iMac 2010 (Yosemite) plugged to a 1080p TV through HDMI for about one year, and was fully satisfied with the following settings :

• Adjust display refresh rate to match video : On start/stop ;
• Sync playback to display : On (A/V sync method : Video clock (resample audio)).

> The first one allowed me to adjust refresh of my TV when playing 23.976fps or 24fps files, avoiding the juddering 3:2 pulldown of 50/60Hz refresh ;
> The second one allowed me to force audio to keep synced with video on 23.976fps files, as Mac OSX cannot handle 23.976 and displays 24fps instead. With this setting, I was free from the annoying frame skip occuring every 41 seconds or so.

I stucked to XBMC 13.2 even since the release of Kodi, because when using Kodi, the refresh rate was not forced to 24 anymore : I could see frame skips, and pressing O on the keyboard showed me a refresh rate of 60 despite the "Adjust display" setting being on (same bug as the one reported here : http://forum.kodi.tv/showthread.php?tid=...st_1893799 ). It was not a problem for me to use a previous version as long as it worked fine.

Problem is, yesterday I watched a 23.976 movie, and saw some frame skips. I pressed O, and saw that even XBMC 13.2 did'nt manage to force 24Hz refresh anymore.

I thought of a problem certainly due to a recent Yosemite update, and decided to give Kodi 14.2 a try. There, I discovered that these two settings (adjust rate & sync playback) could not work together anymore : as soon as I launch a movie with these settings, Kodi crashes.

I have tried the same settings on a different Mac (MacBook Air 2011 Yosemite), same result.

I have tried to play a bit with advancedsettings.xml, and discovered that Kodi fails when trying to adjust refresh rate on 23.976, 24 and 25.

The followings settings cause a crash when launching a 23.976 video :

Code:
<video>
    <adjustrefreshrate>
        <override>
            <fps>23.976</fps>
            <refresh>23.976</refresh>
        </override>
    </adjustrefreshrate>
</video>
Code:
<video>
    <adjustrefreshrate>
        <override>
            <fps>23.976</fps>
            <refresh>24</refresh>
        </override>
    </adjustrefreshrate>
</video>
Code:
<video>
    <adjustrefreshrate>
        <override>
            <fps>23.976</fps>
            <refresh>25</refresh>
        </override>
    </adjustrefreshrate>
</video>

While the following setting works but with jerky playback (and audio pitched up more than 4%, which is logical)

Code:
<video>
    <adjustrefreshrate>
        <override>
            <fps>23.976</fps>
            <refresh>50</refresh>
        </override>
    </adjustrefreshrate>
</video>

And the following setting works but imply a 3:2 pulldown judder (the reason why I needed the "Adjust" & "Sync" settings...) :

Code:
<video>
    <adjustrefreshrate>
        <override>
            <fps>23.976</fps>
            <refresh>60</refresh>
        </override>
    </adjustrefreshrate>
</video>

When I try this setting (telling Kodi to chose the first refresh rate possible in the range), it displays a 50Hz refresh (with jerky playback and pitched audio mentionned above) :

Code:
<video>
    <adjustrefreshrate>
        <override>
            <fps>23.976</fps>
            <refreshmin>22.0</refreshmin>
            <refreshmax>51.0</refreshmax>
        </override>
    </adjustrefreshrate>
</video>

What I understand is that there is a conflict between Kodi and OSX about the ability to force a refresh rate of the TV under 50Hz.

I have not found anything about a Yosemite update that breaks refresh rate handling under 50Hz, though.

Anyone in the same case ?… Please, help…
Reply
#2
try the latest nightly:

http://mirrors.xbmc.org/nightlies/osx/x86_64/

should solve your problem.
Reply
#3
Thank you for your answer.
I've just tried today's nightly, with empty advancedsettings, crashes when I try to read a 23.976 file… (freezes, I have to force quit)
Do I paste my log file ?
Reply
#4
you can post a log file but i think something is wrong inside your kodi settings, playback of a 23.976 file shouldn't crash or freeze your system.

what i would do is:

disable your tv out or better pull the hdmi cable out for testing purpose and retry.

If that doesn't work delete your guisettings.xml file (backup first) and restart the latest nightly kodi.
Reply
#5
Ok, some new elements.

I deleted every files related to XBMC and Kodi on my Mac (I have a backup of my video database elsewhere), and proceeded to a clean install of the latest nightly.

1/
With the HDMI cable unplugged to test directly on the iMac's screen :

a/
"Adjust display refresh rate" Off
"Sync playback to display" Off
Result :
Image
Framerate is continually oscillating between 23.81 and 24.04.

b/
"Adjust display refresh rate" On start/stop
"Sync playback to display" Off
Result :
Image
No difference with above result.

c/
"Adjust display refresh rate" On start/stop
"Sync playback to display" On
Result :
Image
While I should have a stable 24Hz refresh rate (OSX handling of 23.976, the behaviour I was used to in XBMC 13.2), I have a native 60Hz refresh, and the video playback is really choppy.

d/
"Adjust display refresh rate" Off
"Sync playback to display" On
Result :
Image
No difference with above result.

2/
With the HDMI cable plugged to my TV to test on my TV screen (Video output : Full Screen #2 ; Audio output : HDMI) :

a/
"Adjust display refresh rate" Off
"Sync playback to display" Off
Result :
Image
Stable 24fps framerate, but clearly visible 3:2 judder.

b/
"Adjust display refresh rate" On start/stop
"Sync playback to display" Off
Result :
Image
Framerate is continually oscillating between 23.41 and 24.39, visible judder every ≈ 41 seconds (23.976 / 24 OSX bug).

c/
"Adjust display refresh rate" On start/stop
"Sync playback to display" On
Result :
Freeze ! I have to force quit Kodi. Here are the lines of log file after the moment I launched the video :
Code:
11:19:01 T:140735142662912   DEBUG: ------ Window Deinit (Pointer.xml) ------
11:19:01 T:140735142662912   DEBUG: ProcessMouse: trying mouse action leftclick
11:19:01 T:140735142662912   DEBUG: OnPlayMedia /Volumes/IOMEGA 500Go (noir)/Elysium.mkv
11:19:01 T:140735142662912   DEBUG: GetMovieId (/Volumes/IOMEGA 500Go (noir)/Elysium.mkv), query = select idMovie from movie where idFile=26
11:19:01 T:140735142662912   DEBUG: GetEpisodeId (/Volumes/IOMEGA 500Go (noir)/Elysium.mkv), query = select idEpisode from episode where idFile=26
11:19:01 T:140735142662912   DEBUG: GetMusicVideoId (/Volumes/IOMEGA 500Go (noir)/Elysium.mkv), query = select idMVideo from musicvideo where idFile=26
11:19:01 T:140735142662912   DEBUG: CAnnouncementManager - Announcement: OnAdd from xbmc
11:19:01 T:140735142662912   DEBUG: GOT ANNOUNCEMENT, type: 2, from xbmc, message OnAdd
11:19:01 T:140735142662912   DEBUG: Loading settings for /Volumes/IOMEGA 500Go (noir)/Elysium.mkv
11:19:01 T:140735142662912   DEBUG: CPlayerCoreFactory::GetPlayers(/Volumes/IOMEGA 500Go (noir)/Elysium.mkv)
11:19:01 T:140735142662912   DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: system rules
11:19:01 T:140735142662912   DEBUG: CPlayerSelectionRule::GetPlayers: matches rule: system rules
11:19:01 T:140735142662912   DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: hdhomerun/mms/udp
11:19:01 T:140735142662912   DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: lastfm/shout
11:19:01 T:140735142662912   DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: rtmp
11:19:01 T:140735142662912   DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: rtsp
11:19:01 T:140735142662912   DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: streams
11:19:01 T:140735142662912   DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: dvd
11:19:01 T:140735142662912   DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: dvdimage
11:19:01 T:140735142662912   DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: sdp/asf
11:19:01 T:140735142662912   DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: nsv
11:19:01 T:140735142662912   DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: radio
11:19:01 T:140735142662912   DEBUG: CPlayerCoreFactory::GetPlayers: matched 0 rules with players
11:19:01 T:140735142662912   DEBUG: CPlayerCoreFactory::GetPlayers: adding videodefaultplayer (1)
11:19:01 T:140735142662912   DEBUG: CPlayerCoreFactory::GetPlayers: for video=1, audio=0
11:19:01 T:140735142662912   DEBUG: CPlayerCoreFactory::GetPlayers: for video=1, audio=1
11:19:01 T:140735142662912   DEBUG: CPlayerCoreFactory::GetPlayers: adding player: DVDPlayer (1)
11:19:01 T:140735142662912   DEBUG: CPlayerCoreFactory::GetPlayers: added 1 players
11:19:01 T:140735142662912  NOTICE: DVDPlayer: Opening: /Volumes/IOMEGA 500Go (noir)/Elysium.mkv
11:19:01 T:140735142662912 WARNING: CDVDMessageQueue(player)::Put MSGQ_NOT_INITIALIZED
11:19:01 T:140735142662912   DEBUG: CRenderManager::UpdateDisplayLatency - Latency set to 0 msec
11:19:01 T:140735142662912   DEBUG: LinuxRendererGL: Cleaning up GL resources
11:19:01 T:140735142662912   DEBUG: CLinuxRendererGL::PreInit - precision of luminance 16 is 16
11:19:01 T:4529127424  NOTICE: Thread DVDPlayer start, auto delete: false
11:19:01 T:4529127424  NOTICE: Creating InputStream
11:19:01 T:4529127424   DEBUG: ScanForExternalSubtitles: Searching for subtitles...
11:19:01 T:4529127424   DEBUG: ScanForExternalSubtitles: END (total time: 1 ms)
11:19:01 T:4529127424  NOTICE: Creating Demuxer
11:19:01 T:4529127424   DEBUG: Open - probing detected format [matroska,webm]
11:19:01 T:4529127424   DEBUG: Open - avformat_find_stream_info starting
11:19:01 T:4529127424   DEBUG: Open - av_find_stream_info finished
11:19:01 T:4529127424  NOTICE: Opening stream: 0 source: 256
11:19:01 T:4529127424  NOTICE: Creating video codec with codec id: 28
11:19:01 T:4529127424   DEBUG: CDVDFactoryCodec: compiled in hardware support: VDADecoder:yes VideoToolBoxDecoder:no AMCodec:no MediaCodec:no OpenMax:no libstagefright:no iMXVPU:no MMAL:no
11:19:01 T:4529127424   DEBUG: FactoryCodec - Video:  - Opening
11:19:01 T:4529127424  NOTICE: CDVDVideoCodecFFmpeg::Open() Using codec: H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10
11:19:01 T:4529127424   DEBUG: FactoryCodec - Video: ff-h264 - Opened
11:19:01 T:4529127424  NOTICE: Creating video thread
11:19:01 T:4567359488  NOTICE: Thread RefClock start, auto delete: false
11:19:01 T:4529127424  NOTICE: Opening stream: 1 source: 256
11:19:01 T:4644147200  NOTICE: Thread DVDPlayerVideo start, auto delete: false
11:19:01 T:4567359488   DEBUG: CVideoSyncOsx::Setup setting up OSX
11:19:01 T:4529127424  NOTICE: Finding audio codec for: 86020
11:19:01 T:4644147200  NOTICE: running thread: video_thread
11:19:01 T:4567359488   DEBUG: CVideoSyncOsx::InitDisplayLink setting up displaylink
11:19:01 T:4529127424   DEBUG: FactoryCodec - Audio: passthrough - Opening
11:19:01 T:4529127424   DEBUG: FactoryCodec - Audio: passthrough - Failed
11:19:01 T:4529127424   DEBUG: FactoryCodec - Audio: FFmpeg - Opening
11:19:01 T:4529127424   DEBUG: FactoryCodec - Audio: FFmpeg - Opened
11:19:01 T:4529127424  NOTICE: Creating audio thread
11:19:01 T:4666212352  NOTICE: Thread DVDPlayerAudio start, auto delete: false
11:19:01 T:4529127424  NOTICE: Opening stream: 3 source: 256
11:19:01 T:4644147200   DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_SYNCHRONIZE
11:19:01 T:4666212352  NOTICE: running thread: CDVDPlayerAudio::Process()
11:19:01 T:4529127424   DEBUG: FactoryCodec - Overlay: Text Subtitle Decoder - Opening
11:19:01 T:4666212352   DEBUG: CDVDPlayerAudio - CDVDMsg::GENERAL_SYNCHRONIZE
11:19:01 T:4529127424   DEBUG: FactoryCodec - Overlay: Text Subtitle Decoder - Opened
11:19:01 T:4567359488   DEBUG: CVideoSyncOsx::GetFps Detected refreshrate: 50.000000 hertz
11:19:01 T:4567359488   DEBUG: CVideoReferenceClock: Detected refreshrate: 50.000 hertz
11:19:01 T:4529127424   DEBUG: ReadEditDecisionLists - Checking for edit decision lists (EDL) on local drive or remote share for: /Volumes/IOMEGA 500Go (noir)/Elysium.mkv
11:19:01 T:4644147200   DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_SYNCHRONIZE
11:19:01 T:4529127424   DEBUG: OnPlayBackStarted: play state was 1, starting 1
11:19:01 T:4666212352   DEBUG: CDVDPlayerAudio - CDVDMsg::GENERAL_SYNCHRONIZE
11:19:01 T:4529127424   DEBUG: CDVDPlayer::SetCaching - caching state 3
11:19:01 T:140735142662912   DEBUG: PlayFile: OpenFile succeed, play state 2
11:19:01 T:4644147200    INFO: CDVDPlayerVideo - Stillframe left, switching to normal playback
11:19:01 T:140735142662912   DEBUG: OnPlayBackStarted: play state was 2, starting 0
11:19:01 T:4666212352  NOTICE: Creating audio stream (codec id: 86020, channels: 6, sample rate: 48000, no pass-through)
11:19:01 T:4644147200   DEBUG: CDVDPlayerVideo::CalcDropRequirement - hurry: 0
11:19:01 T:4666212352   DEBUG: CDVDPlayerAudio:: synctype set to 2: resample
11:19:01 T:4528590848    INFO: CActiveAESink::OpenSink - initialize sink
11:19:01 T:4528590848   DEBUG: CActiveAESink::OpenSink - trying to open device DARWINOSX:HDMI:stream0
11:19:01 T:4528590848  NOTICE: Initialize pseudo device - requesting stream 0
11:19:01 T:4528590848   DEBUG: FindSuitableFormatForStream: Finding stream for format AE_FMT_FLOATP
11:19:01 T:4528590848   DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 24-bit Signed Integer LE (192000Hz) rated 1104.000000
11:19:01 T:4528590848   DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 24-bit Signed Integer LE (96000Hz) rated 1106.000000
11:19:01 T:4528590848   DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 24-bit Signed Integer LE (48000Hz) rated 1508.000000
11:19:01 T:4528590848   DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 24-bit Signed Integer LE (44100Hz) rated 89.250000
11:19:01 T:4528590848   DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 24-bit Signed Integer LE (32000Hz) rated 341.333344
11:19:01 T:4528590848   DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 20-bit Signed Integer LE (192000Hz) rated 1103.000000
11:19:01 T:4528590848   DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 20-bit Signed Integer LE (96000Hz) rated 1105.000000
11:19:01 T:4528590848   DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 20-bit Signed Integer LE (48000Hz) rated 1507.000000
11:19:01 T:4528590848   DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 20-bit Signed Integer LE (44100Hz) rated 88.250000
11:19:01 T:4528590848   DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 20-bit Signed Integer LE (32000Hz) rated 340.333344
11:19:01 T:4528590848   DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 16-bit Signed Integer LE (192000Hz) rated 1103.000000
11:19:01 T:4528590848   DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 16-bit Signed Integer LE (96000Hz) rated 1105.000000
11:19:01 T:4644147200   ERROR: VDA::CDecoder - Failed to init VDA decoder: -12473
11:19:01 T:4528590848   DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 16-bit Signed Integer LE (48000Hz) rated 1507.000000
11:19:01 T:4528590848   DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 16-bit Signed Integer LE (44100Hz) rated 88.250000
11:19:01 T:4528590848   DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 16-bit Signed Integer LE (32000Hz) rated 340.333344
11:19:01 T:4528590848   DEBUG: FindSuitableFormatForStream: Physical Format: [cac3] AC-3/DTS for S/PDIF LE (48000Hz) rated 0.000000
11:19:01 T:4528590848   DEBUG: FindSuitableFormatForStream: Physical Format: [cac3] AC-3/DTS for S/PDIF LE (44100Hz) rated 0.000000
11:19:01 T:4528590848   DEBUG: Initialize: Selected stream[0] - id: 0x0047, Physical Format: [lpcm] Mixable Interleaved 2 Channel 24-bit Signed Integer LE (48000Hz)
11:19:01 T:4528590848   DEBUG: CCoreAudioDevice::SupportsMixing: Device mixing support : 'No'.
11:19:01 T:4644147200  NOTICE: CDVDVideoCodecFFmpeg::Open() Using codec: H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10
11:19:01 T:4528590848   DEBUG: CCoreAudioStream::Open: Opened stream 0x0047.
11:19:01 T:4644147200   DEBUG: CDVDVideoCodecFFmpeg - open frame threaded with 4 threads
11:19:01 T:4528590848   DEBUG: Initialize: Previous Virtual Format: [lpcm] Mixable Interleaved 2 Channel 32-bit Floating Point LE (48000Hz)
11:19:01 T:4528590848   DEBUG: Initialize: Previous Physical Format: [lpcm] Mixable Interleaved 2 Channel 24-bit Signed Integer LE (48000Hz)
11:19:01 T:4644147200   DEBUG: CDVDPlayerVideo::CalcDropRequirement - hurry: 0
11:19:01 T:4644147200   DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_RESYNC(167000.000000, 0)
11:19:01 T:4644147200   DEBUG: CDVDPlayerVideo::CalcDropRequirement - hurry: 0
11:19:01 T:140735142662912   DEBUG: Previous line repeats 1 times.
11:19:01 T:140735142662912   DEBUG: ------ Window Init (Pointer.xml) ------
11:19:01 T:4528590848   DEBUG: CCoreAudioStream::SetPhysicalFormat: Physical format for stream 0x0047. now active ([lpcm] Mixable Interleaved 2 Channel 24-bit Signed Integer LE (48000Hz))
11:19:01 T:4644147200   DEBUG: CDVDPlayerVideo::CalcDropRequirement - hurry: 0
11:19:01 T:4528590848   DEBUG: Initialize: New Virtual Format: [lpcm] Mixable Interleaved 2 Channel 32-bit Floating Point LE (48000Hz)
11:19:01 T:4528590848   DEBUG: Initialize: New Physical Format: [lpcm] Mixable Interleaved 2 Channel 24-bit Signed Integer LE (48000Hz)
11:19:01 T:4528590848   DEBUG: GetAEChannelMap Engine requests layout FL,FR
11:19:01 T:4528590848   DEBUG: GetAEChannelMap trying to map to stereo layout: [Left] [Right]
11:19:01 T:4528590848   DEBUG: GetAEChannelMap mapped channels to layout FL,FR
11:19:01 T:4644147200   DEBUG: CDVDPlayerVideo::CalcDropRequirement - hurry: 0
11:19:01 T:140735142662912   DEBUG: Previous line repeats 1 times.
11:19:01 T:140735142662912   DEBUG: CGUIInfoManager::SetCurrentMovie(/Volumes/IOMEGA 500Go (noir)/Elysium.mkv)
11:19:01 T:4529127424   DEBUG: CDVDPlayer::SetCaching - caching state 0
11:19:01 T:4644147200  NOTICE:  fps: 23.976024, pwidth: 1920, pheight: 800, dwidth: 1920, dheight: 800
11:19:01 T:4644147200   DEBUG: OutputPicture - change configuration. 1920x800. framerate: 23.98. format: YV12
11:19:01 T:4644147200  NOTICE: Display resolution ADJUST : 1920x1080 @ 24.00 (37) (weight: 0.001)
11:19:01 T:4644147200   DEBUG: CXBMCRenderManager::Configure - 3
11:19:01 T:4644147200   DEBUG: CVideoReferenceClock: Clock speed 104.270833%
11:19:01 T:4528590848   DEBUG: Initialize: using buffer size: 16384 (0.042667 ms)
11:19:01 T:140735142662912   DEBUG: GetMovieId (/Volumes/IOMEGA 500Go (noir)/Elysium.mkv), query = select idMovie from movie where idFile=26
11:19:01 T:140735142662912   DEBUG: GetEpisodeId (/Volumes/IOMEGA 500Go (noir)/Elysium.mkv), query = select idEpisode from episode where idFile=26
11:19:01 T:4528590848   DEBUG: CActiveAESink::OpenSink - DARWINOSX Initialized:
11:19:01 T:140735142662912   DEBUG: GetMusicVideoId (/Volumes/IOMEGA 500Go (noir)/Elysium.mkv), query = select idMVideo from musicvideo where idFile=26
11:19:01 T:4528590848   DEBUG:   Output Device : HDMI
11:19:01 T:4528590848   DEBUG:   Sample Rate   : 48000
11:19:01 T:4528590848   DEBUG:   Sample Format : AE_FMT_FLOAT
11:19:01 T:4528590848   DEBUG:   Channel Count : 2
11:19:01 T:4528590848   DEBUG:   Channel Layout: FL,FR
11:19:01 T:4528590848   DEBUG:   Frames        : 512
11:19:01 T:4528590848   DEBUG:   Frame Samples : 1024
11:19:01 T:4528590848   DEBUG:   Frame Size    : 8
11:19:01 T:140735142662912   DEBUG: CAnnouncementManager - Announcement: OnPlay from xbmc
11:19:01 T:140735142662912   DEBUG: GOT ANNOUNCEMENT, type: 1, from xbmc, message OnPlay
11:19:01 T:4528054272   DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted
11:19:01 T:140735142662912   DEBUG: Activating window ID: 12005
11:19:01 T:4666212352   DEBUG: CDVDPlayerAudio - CDVDMsg::GENERAL_RESYNC(10000.000000, 1)
11:19:01 T:4528054272   DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted
11:19:01 T:140735142662912   DEBUG: ------ Window Deinit (MyVideoNav.xml) ------
11:19:01 T:4529127424   DEBUG: CDVDPlayer::HandleMessages - player started 1
11:19:01 T:4666212352  NOTICE: CDVDPlayerAudio::OutputPacket skipping a packets of duration 10
11:19:02 T:4666212352  NOTICE: Previous line repeats 1 times.
11:19:02 T:4666212352   DEBUG: CDVDPlayerAudio::HandleSyncError - average error -7845.552904 below threshold of 50000.000000
11:19:02 T:140735142662912    INFO: GL: Maximum texture width: 8192
11:19:02 T:140735142662912   DEBUG: GetMode looking for suitable mode with 1920 x 1080 @ 24.000000 Hz on display 1
11:19:02 T:140735142662912   DEBUG: GetMode found a match!
11:19:02 T:140735142662912   DEBUG: CWinSystemOSX::DisplayReconfigured with flags 1
11:19:02 T:140735142662912   DEBUG: CWinSystemOSX::AnnounceOnLostDevice
11:19:02 T:4644147200   DEBUG: CDVDPlayerVideo::CalcDropRequirement - hurry: 0
11:19:02 T:4529127424   DEBUG: CDVDPlayer::HandleMessages - player started 2
11:19:02 T:4644147200   DEBUG: CDVDPlayerVideo::CalcDropRequirement - hurry: 0
11:19:02 T:4528590848   DEBUG: Previous line repeats 2 times.
11:19:02 T:4528590848   DEBUG: CCoreAudioStream::Close: Restoring original physical format for stream 0x0047. ([lpcm] Mixable Interleaved 2 Channel 24-bit Signed Integer LE (48000Hz))
11:19:02 T:4528590848   DEBUG: CCoreAudioStream::SetPhysicalFormat: Physical format for stream 0x0047. now active ([lpcm] Mixable Interleaved 2 Channel 24-bit Signed Integer LE (48000Hz))
11:19:02 T:4528590848   DEBUG: CCoreAudioStream::Close: Closed stream 0x0047.
11:19:02 T:140735142662912   DEBUG: CWinSystemOSX::DisplayReconfigured with flags 1
11:19:02 T:4700635136  NOTICE: Thread Timer start, auto delete: false
11:19:02 T:4644147200   DEBUG: CDVDPlayerVideo::CalcDropRequirement - hurry: 0
11:19:03 T:140735142662912   DEBUG: Previous line repeats 24 times.
11:19:03 T:140735142662912   DEBUG: CWinSystemOSX::DisplayReconfigured with flags 8
11:19:03 T:140735142662912   DEBUG: CWinSystemOSX::AnnounceOnResetDevice
11:19:03 T:140735142662912   DEBUG: CWinSystemOSX::DisplayReconfigured with flags 0
11:19:03 T:140735142662912   DEBUG: CWinSystemOSX::AnnounceOnResetDevice
11:19:03 T:4700635136   DEBUG: Thread Timer 4700635136 terminating
11:19:03 T:4528054272   DEBUG: CActiveAE - display reset event
11:19:03 T:4528590848    INFO: CActiveAESink::OpenSink - initialize sink
11:19:03 T:4528590848   DEBUG: CActiveAESink::OpenSink - trying to open device DARWINOSX:HDMI:stream0
11:19:03 T:4528590848  NOTICE: Initialize pseudo device - requesting stream 0
11:19:03 T:4528590848   DEBUG: FindSuitableFormatForStream: Finding stream for format AE_FMT_FLOATP
11:19:03 T:4528590848   DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 24-bit Signed Integer LE (192000Hz) rated 1104.000000
11:19:03 T:4528590848   DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 24-bit Signed Integer LE (96000Hz) rated 1106.000000
11:19:03 T:4528590848   DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 24-bit Signed Integer LE (48000Hz) rated 1508.000000
11:19:03 T:4528590848   DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 24-bit Signed Integer LE (44100Hz) rated 89.250000
11:19:03 T:4528590848   DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 24-bit Signed Integer LE (32000Hz) rated 341.333344
11:19:03 T:4528590848   DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 20-bit Signed Integer LE (192000Hz) rated 1103.000000
11:19:03 T:4528590848   DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 20-bit Signed Integer LE (96000Hz) rated 1105.000000
11:19:03 T:4644147200   DEBUG: CDVDPlayerVideo::CalcDropRequirement - hurry: 0
11:19:03 T:4528590848   DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 20-bit Signed Integer LE (48000Hz) rated 1507.000000
11:19:03 T:4528590848   DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 20-bit Signed Integer LE (44100Hz) rated 88.250000
11:19:03 T:4528590848   DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 20-bit Signed Integer LE (32000Hz) rated 340.333344
11:19:03 T:4528590848   DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 16-bit Signed Integer LE (192000Hz) rated 1103.000000
11:19:03 T:4528590848   DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 16-bit Signed Integer LE (96000Hz) rated 1105.000000
11:19:03 T:4528590848   DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 16-bit Signed Integer LE (48000Hz) rated 1507.000000
11:19:03 T:4528590848   DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 16-bit Signed Integer LE (44100Hz) rated 88.250000
11:19:03 T:4528590848   DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 16-bit Signed Integer LE (32000Hz) rated 340.333344
11:19:03 T:4528590848   DEBUG: FindSuitableFormatForStream: Physical Format: [cac3] AC-3/DTS for S/PDIF LE (48000Hz) rated 0.000000
11:19:03 T:4528590848   DEBUG: FindSuitableFormatForStream: Physical Format: [cac3] AC-3/DTS for S/PDIF LE (44100Hz) rated 0.000000
11:19:03 T:4528590848   DEBUG: Initialize: Selected stream[0] - id: 0x0047, Physical Format: [lpcm] Mixable Interleaved 2 Channel 24-bit Signed Integer LE (48000Hz)
11:19:03 T:4528590848   DEBUG: CCoreAudioDevice::SupportsMixing: Device mixing support : 'No'.
11:19:03 T:4528590848   DEBUG: CCoreAudioStream::Open: Opened stream 0x0047.
11:19:03 T:4528590848   DEBUG: Initialize: Previous Virtual Format: [lpcm] Mixable Interleaved 2 Channel 32-bit Floating Point LE (48000Hz)
11:19:03 T:4528590848   DEBUG: Initialize: Previous Physical Format: [lpcm] Mixable Interleaved 2 Channel 24-bit Signed Integer LE (48000Hz)
11:19:03 T:4567359488   DEBUG: CVideoSyncOsx::Cleanup cleaning up OSX
11:19:03 T:4567359488   DEBUG: CVideoSyncOsx::Setup setting up OSX
11:19:03 T:4567359488   DEBUG: CVideoSyncOsx::InitDisplayLink setting up displaylink
11:19:03 T:4567359488   DEBUG: CVideoSyncOsx::GetFps Detected refreshrate: 24.000000 hertz
11:19:03 T:4567359488   DEBUG: CVideoReferenceClock: Detected refreshrate: 24.000 hertz
11:19:03 T:4528590848   DEBUG: CCoreAudioStream::SetPhysicalFormat: Physical format for stream 0x0047. now active ([lpcm] Mixable Interleaved 2 Channel 24-bit Signed Integer LE (48000Hz))
11:19:03 T:4528590848   DEBUG: Initialize: New Virtual Format: [lpcm] Mixable Interleaved 2 Channel 32-bit Floating Point LE (48000Hz)
11:19:03 T:4528590848   DEBUG: Initialize: New Physical Format: [lpcm] Mixable Interleaved 2 Channel 24-bit Signed Integer LE (48000Hz)
11:19:03 T:4528590848   DEBUG: GetAEChannelMap Engine requests layout FL,FR
11:19:03 T:4528590848   DEBUG: GetAEChannelMap trying to map to stereo layout: [Left] [Right]
11:19:03 T:4528590848   DEBUG: GetAEChannelMap mapped channels to layout FL,FR
11:19:03 T:4528590848   DEBUG: Initialize: using buffer size: 16384 (0.042667 ms)
11:19:03 T:4528590848   DEBUG: CActiveAESink::OpenSink - DARWINOSX Initialized:
11:19:03 T:4528590848   DEBUG:   Output Device : HDMI
11:19:03 T:4528590848   DEBUG:   Sample Rate   : 48000
11:19:03 T:4528590848   DEBUG:   Sample Format : AE_FMT_FLOAT
11:19:03 T:4528590848   DEBUG:   Channel Count : 2
11:19:03 T:4528590848   DEBUG:   Channel Layout: FL,FR
11:19:03 T:4528590848   DEBUG:   Frames        : 512
11:19:03 T:4528590848   DEBUG:   Frame Samples : 1024
11:19:03 T:4528590848   DEBUG:   Frame Size    : 8
11:19:03 T:4528054272   DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted
11:19:03 T:140735142662912    INFO: GL: Maximum texture width: 8192
11:19:03 T:140735142662912    INFO: Previous line repeats 1 times.
11:19:03 T:140735142662912   DEBUG: CRenderManager::UpdateDisplayLatency - Latency set to 0 msec
11:19:03 T:140735142662912   DEBUG: ------ Window Init (VideoFullScreen.xml) ------
11:19:03 T:140735142662912    INFO: Loading skin file: VideoFullScreen.xml, load type: KEEP_IN_MEMORY
11:19:03 T:140735142662912   DEBUG: Load VideoFullScreen.xml: 9.52ms
11:19:03 T:140735142662912   DEBUG: Alloc resources: 9.75ms  (9.70 ms skin load)
11:19:03 T:140735142662912  NOTICE: Using GL_TEXTURE_2D
11:19:03 T:140735142662912   DEBUG: GL: Requested render method: 0
11:19:03 T:140735142662912   DEBUG: GL: BaseYUV2RGBGLSLShader: defines:
                                            #define XBMC_texture_rectangle 0
                                            #define XBMC_texture_rectangle_hack 0
                                            #define XBMC_STRETCH 0
                                            #define XBMC_YV12
11:19:03 T:140735142662912  NOTICE: GL: Selecting Single Pass YUV 2 RGB shader
11:19:03 T:140735142662912   DEBUG: GL: Vertex Shader compilation log:
11:19:03 T:140735142662912   DEBUG: GL: Vertex Shader compiled successfully
11:19:03 T:140735142662912   DEBUG: GL: Pixel Shader compilation log:
11:19:03 T:140735142662912   DEBUG: GL: Fragment Shader compiled successfully
11:19:03 T:140735142662912   DEBUG: GL: Vertex Shader compilation log:
11:19:03 T:140735142662912   DEBUG: GL: Vertex Shader compiled successfully
11:19:03 T:140735142662912   DEBUG: GL: Pixel Shader compilation log:
11:19:03 T:140735142662912   DEBUG: GL: Fragment Shader compiled successfully
11:19:03 T:140735142662912  NOTICE: GL: NPOT texture support detected
11:19:03 T:140735142662912  NOTICE: GL: Using GL_ARB_pixel_buffer_object
11:19:03 T:4644147200   DEBUG: CDVDPlayerVideo::CalcDropRequirement - hurry: 1
11:19:03 T:4644147200   DEBUG: CVideoReferenceClock: Clock speed 100.100000%
11:19:03 T:4644147200   DEBUG: CDVDPlayerVideo::CalcDropRequirement - hurry: 1
11:19:04 T:4644147200   DEBUG: Previous line repeats 5 times.
11:19:04 T:4644147200 WARNING: CRenderManager::WaitForBuffer - timeout waiting for buffer
11:19:07 T:4666212352 WARNING: Previous line repeats 2 times.
11:19:07 T:4666212352   DEBUG: CDVDPlayerAudio::HandleSyncError - average error 2185375.880730 above threshold of 200000.000000
11:19:07 T:4666212352  NOTICE: CDVDPlayerAudio::OutputPacket duplicate 9 packets of duration 10
11:19:12 T:4620296192  NOTICE: Previous line repeats 47 times.
11:19:12 T:4620296192   DEBUG: Thread JobWorker 4620296192 terminating (autodelete)
11:19:12 T:4619759616   DEBUG: Thread JobWorker 4619759616 terminating (autodelete)
11:19:12 T:4666212352  NOTICE: CDVDPlayerAudio::OutputPacket duplicate 9 packets of duration 10

d/
"Adjust display refresh rate" Off
"Sync playback to display" On
Result :
Image
A framerate of 30, and a refresh rate of 50 Huh Playback is choppy, and acceleration is quite visible.

When plugged to my TV (the everyday configuration I need), only results a and b make sense for me in regards with the settings, but one implies 3:2 pulldown judder, and the other implies the ≈ 41 seconds frame skip due to OSX bad handling of 23.976fps. (These annoyances were the reason why I needed XBMC, and was satisfied with the 13.2 before my configuration begun to f*ck up…)

The only setting that would deal with both these annoyances are "Adjust display refresh rate" (to have my TV refresh rate to 24), and "Sync playback to display" (to keep audio synced with video when video is sped up from 23.976 to 24 by OSX). And these settings together make my Kodi freeze…

Is it possible that it comes from a recent Yosemite update ? Any user with an equivalent configuration who faces the same problem ?
Reply
#6
Please post the full debug log (wiki) to pastebin.com and put the link in here. Also what are your audio settings in Kodi?
AppleTV4/iPhone/iPod/iPad: HowTo find debug logs and everything else which the devs like so much: click here
HowTo setup NFS for Kodi: NFS (wiki)
HowTo configure avahi (zeroconf): Avahi_Zeroconf (wiki)
READ THE IOS FAQ!: iOS FAQ (wiki)
Reply
#7
Thank you for your answer.

Here is the link to the debug log file : http://pastebin.com/W4R3GxAk (case 2/ c/ that results in a freeze)

I use the HDMI audio output, which is plugged into my TV (audio passes through the TV, and is output by toslink to a DAC).
Reply
#8
It may be another thing entirely but your description reminded me of what I experienced. I immediately thought of it because of the two screens and the crash with 23,976hz files.
I posted about it here a couple of weeks ago.
If you have the time and the files, try 50p and 60i video, they behave differently on my system

I also use 2 ch over HDMI, but I do use passthrough (AC3 and DTS)
Edit: Oh, and I always use "adjust" and "sync" and didn't even check without, as for the reasons you mentioned both are a must on OSX.
Reply
#9
I really wonder how it should resample audio when you have passthrough enabled. Does disable passthrough make a change? Also we are on to something which might be related to your problem - will post a test build once the approach is clear...
AppleTV4/iPhone/iPod/iPad: HowTo find debug logs and everything else which the devs like so much: click here
HowTo setup NFS for Kodi: NFS (wiki)
HowTo configure avahi (zeroconf): Avahi_Zeroconf (wiki)
READ THE IOS FAQ!: iOS FAQ (wiki)
Reply
#10
Precision : I have not enabled audio passthrough in Kodi, digital audio is sent (resampled if option checked) via HDMI. The passthrough is on my TV side, which does not process the digital signal but outputs it instead via toslink (to an externat DAC plugged to my stereo amplifier).

I hope the something you're on will eventually fix my problem, when do you think this will be available on nightly ?
Reply
#11
please try

http://mirrors.kodi.tv/test-builds/osx/x...x86_64.dmg

and report back
AppleTV4/iPhone/iPod/iPad: HowTo find debug logs and everything else which the devs like so much: click here
HowTo setup NFS for Kodi: NFS (wiki)
HowTo configure avahi (zeroconf): Avahi_Zeroconf (wiki)
READ THE IOS FAQ!: iOS FAQ (wiki)
Reply
#12
Thank you Memphiz. Smile

The fix seems to be effective, no freeze when launching, the "O-key" info are quite good (refresh 24, speed +0.100%, framerate constantly oscillating between 23.41 and 24.39 though, is that normal ?)

I think I saw some skips on the first test I ran (those of the OSX 24Hz bug), but not on the two following, and I know tired eyes can play some tricks…
Here is the debug log of one "clear" test, if it is of any use for you : http://pastebin.com/f40VtgqV
I always launch the beginning of Elysium to test frame skips and judder, as there are several minutes of travelling sequences (one of the few qualities of this movie Big Grin ), but I'll take a couple of days to test this build out with different files. I'll post my conclusions here.

Let me know if this fix is merged to a future nightly, so I can test it also.
Reply
#13
Smile 
I've had the exact same experience as what cybergrunge described in his original post, including having to stay on 13.2 to keep sync working. I reported it in this thread, but the developers seemed to think it was a hardware/firmware problem. I'd just like to say that the test build fixed it for me too Smile
"The television screen is the retina of the mind's eye. Therefore, the television screen is part of the physical structure of the brain. Therefore, whatever appears on the television screen emerges as raw experience for those who watch it. Therefore, television is reality, and reality is less than television." (Videodrome (1983), David Cronenberg)
Reply
#14
Quote:framerate constantly oscillating between 23.41 and 24.39

just ignore this silly value. I tried to remove it but there was too much protest from people who did not even know what this value is about.
Reply
#15
fixed for me as well, thank you Memphiz!

(2015-05-15, 23:55)Memphiz Wrote: I really wonder how it should resample audio when you have passthrough enabled.

I have no clue, but it works.
Way back, I think in version 12 or so I heard a little sound clipping every couple of seconds as if the bitstream needed to drop frames to keep in sync. That made total sense to me as I had "drop/dupe" selected. It also did when I selected "resample", which also made sense because if I understand correctly it should revert to "drop/dupe" for passthrough anyway. But it's been good for a long while now.
I would also love to know how it works, but for the most part I am pretty happy it does.
Reply

Logout Mark Read Team Forum Stats Members Help
"Adjust display refresh rate" & "Sync playback" not working together anymore0