+- Kodi Community Forum (https://forum.kodi.tv)
+-- Forum: Support (https://forum.kodi.tv/forumdisplay.php?fid=33)
+--- Forum: PVR & Live TV Support (https://forum.kodi.tv/forumdisplay.php?fid=167)
+---- Forum: VDR (https://forum.kodi.tv/forumdisplay.php?fid=169)
+---- Thread: VNSI Kodi 17 Mac specific channel results in crash (/showthread.php?tid=317829)
Pages:
1
2
VNSI Kodi 17 Mac specific channel results in crash - sharky1337 - 2017-07-06
Hello ,
I'm trying to use vnsi plugin with kodi17 on my mac.
If a zap to a program called ZDF HD , Kodi does show one or two pictures from that channel sound work well but than the stream stops and kodi crashes.
Debug log got a lot of these errors.
root@tv-server:~# vdr -V
vdr (2.2.0/2.2.0) - The Video Disk Recorder
vnsiserver (1.5.2) - VDR-Network-Streaming-Interface (VNSI) Server
Quote:21:40:28.603 T:123145501323264 ERROR: ffmpeg[70000BDCB000]: [h264] Missing reference picture, default is 0
21:40:28.603 T:123145501323264 ERROR: ffmpeg[70000BDCB000]: [h264] decode_slice_header error
21:40:28.604 T:123145501323264 ERROR: ffmpeg[70000BDCB000]: [h264] hardware accelerator failed to decode picture
21:40:28.604 T:123145501323264 ERROR: Decode - avcodec_decode_video returned failure
21:40:28.604 T:123145501323264 DEBUG: CVideoPlayerVideo - video decoder returned error
21:40:28.808 T:123145501323264 ERROR: Decode - avcodec_decode_video returned failure
21:40:28.808 T:123145501323264 DEBUG: CVideoPlayerVideo - video decoder returned error
21:40:28.808 T:123145501323264 INFO: CVideoPlayerVideo - Stillframe detected, switching to forced 50.000000 fps
21:40:28.818 T:123145500786688 WARNING: VideoPlayer::Sync - stream player video does not start, flushing buffers
21:40:28.818 T:123145500786688 DEBUG: CVideoPlayer::FlushBuffers - flushing buffers
21:40:28.827 T:123145507225600 DEBUG: CDVDAudio::Flush - flush audio stream
21:40:28.827 T:123145507225600 DEBUG: CDVDAudio:ause - pausing audio stream
21:40:28.827 T:123145507225600 DEBUG: CVideoPlayerAudio - CDVDMsg::GENERAL_SYNCHRONIZE
21:40:28.827 T:123145501323264 DEBUG: CVideoPlayerVideo - CDVDMsg::GENERAL_SYNCHRONIZE
21:40:28.827 T:123145500786688 DEBUG: CVideoPlayer::SetCaching - caching state 2
21:40:28.827 T:123145500786688 DEBUG: CDVDClock::SetSpeedAdjust - adjusted:0.000000
21:40:28.836 T:123145501323264 INFO: CVideoPlayerVideo - Stillframe left, switching to normal playback
21:40:28.836 T:123145501323264 DEBUG: CVideoPlayerVideo::CalcDropRequirement - hurry: 0
21:40:28.838 T:123145507225600 DEBUG: CDVDAudio:
21:40:28.845 T:123145501323264 DEBUG: CDVDVideoCodecFFmpeg - Updated codec: ff-h264
21:40:28.854 T:123145501323264 INFO: CBitstreamConverter::Open annexb to bitstream init
21:40:28.854 T:123145500786688 DEBUG: CVideoPlayer::HandleMessages - player started 1
21:40:28.873 T:123145501323264 DEBUG: CDVDVideoCodecFFmpeg - Updated codec: ff-h264-vtb
21:40:28.878 T:123145501323264 DEBUG: CVideoPlayerVideo::CalcDropRequirement - hurry: 0
21:40:28.880 T:123145501323264 ERROR: ffmpeg[70000BDCB000]: [h264] co located POCs unavailable
Crashlog https://pastebin.com/s0jPPE0L
Anyone interested to dig deeper ?
RE: VNSI Kodi 17 Mac specific channel results in crash - FernetMenta - 2017-07-08
Did you try with hardware acceleration (videotoolbox) disabled?
RE: VNSI Kodi 17 Mac specific channel results in crash - sharky1337 - 2017-07-10
Thank you @FernetMenta . ZDF HD now works perfectly with VTB disabled , but there are other HD Channels which have similar problems for example VOX HD & n-tv HD . On these nothing changed at all. Still many interrupts while watching.
Code:
21:57:01.142 T:123145427927040 DEBUG: Initialize: using buffer size: 16384 (0.046440 ms)
21:57:01.142 T:123145427927040 DEBUG: CActiveAESink::OpenSink - DARWINOSX Initialized:
21:57:01.142 T:123145427927040 DEBUG: Output Device : Default
21:57:01.142 T:123145427927040 DEBUG: Sample Rate : 44100
21:57:01.143 T:123145427927040 DEBUG: Sample Format : AE_FMT_FLOAT
21:57:01.143 T:123145427927040 DEBUG: Channel Count : 2
21:57:01.143 T:123145427927040 DEBUG: Channel Layout: FL,FR
21:57:01.143 T:123145427927040 DEBUG: Frames : 512
21:57:01.143 T:123145427927040 DEBUG: Frame Size : 8
21:57:01.144 T:123145427390464 DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted
21:57:27.538 T:140736441635776 DEBUG: Previous line repeats 1 times.
21:57:27.538 T:140736441635776 DEBUG: ------ Window Init (Pointer.xml) ------
21:57:28.353 T:140736441635776 DEBUG: ProcessMouse: trying mouse action leftclick
21:57:28.353 T:140736441635776 DEBUG: Activating window ID: 10700
21:57:28.655 T:140736441635776 DEBUG: ------ Window Deinit (Home.xml) ------
21:57:28.669 T:140736441635776 DEBUG: ------ Window Init (MyPVRChannels.xml) ------
21:57:28.670 T:140736441635776 DEBUG: CGUIMediaWindow::GetDirectory (pvr://channels/tv/All channels/)
21:57:28.671 T:140736441635776 DEBUG: ParentPath = [pvr://channels/tv/All channels/]
21:57:28.671 T:140736441635776 DEBUG: CPVRDirectory::GetDirectory(pvr://channels/tv/All channels)
21:57:29.239 T:140736441635776 DEBUG: ------ Window Deinit (Pointer.xml) ------
21:57:30.483 T:123145423097856 DEBUG: Thread JobWorker 123145423097856 terminating (autodelete)
21:57:30.486 T:123145422561280 DEBUG: Thread JobWorker 123145422561280 terminating (autodelete)
21:57:28.353 T:140736441635776 DEBUG: ProcessMouse: trying mouse action leftclick
21:57:28.353 T:140736441635776 DEBUG: Activating window ID: 10700
21:57:28.655 T:140736441635776 DEBUG: ------ Window Deinit (Home.xml) ------
21:57:28.669 T:140736441635776 DEBUG: ------ Window Init (MyPVRChannels.xml) ------
21:57:28.670 T:140736441635776 DEBUG: CGUIMediaWindow::GetDirectory (pvr://channels/tv/All channels/)
21:57:28.671 T:140736441635776 DEBUG: ParentPath = [pvr://channels/tv/All channels/]
21:57:28.671 T:140736441635776 DEBUG: CPVRDirectory::GetDirectory(pvr://channels/tv/All channels)
21:57:29.239 T:140736441635776 DEBUG: ------ Window Deinit (Pointer.xml) ------
21:57:30.483 T:123145423097856 DEBUG: Thread JobWorker 123145423097856 terminating (autodelete)
21:57:30.486 T:123145422561280 DEBUG: Thread JobWorker 123145422561280 terminating (autodelete)
21:57:52.374 T:140736441635776 DEBUG: ------ Window Init (Pointer.xml) ------
21:57:53.374 T:140736441635776 DEBUG: ProcessMouse: trying mouse action wheeldown
21:57:55.321 T:140736441635776 DEBUG: Previous line repeats 3 times.
21:57:55.321 T:140736441635776 DEBUG: ProcessMouse: trying mouse action leftclick
21:57:55.365 T:140736441635776 DEBUG: Loading settings for pvr://channels/tv/All channels/pvr.vdr.vnsi_1317513966.pvr
21:57:55.366 T:140736441635776 DEBUG: CPlayerCoreFactory::GetPlayers(pvr://channels/tv/All channels/pvr.vdr.vnsi_1317513966.pvr)
21:57:55.366 T:140736441635776 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: system rules
21:57:55.366 T:140736441635776 DEBUG: CPlayerSelectionRule::GetPlayers: matches rule: system rules
21:57:55.366 T:140736441635776 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: mms/udp
21:57:55.366 T:140736441635776 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: lastfm/shout
21:57:55.366 T:140736441635776 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: rtmp
21:57:55.366 T:140736441635776 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: rtsp
21:57:55.366 T:140736441635776 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: streams
21:57:55.366 T:140736441635776 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: dvd
21:57:55.366 T:140736441635776 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: dvdimage
21:57:55.366 T:140736441635776 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: sdp/asf
21:57:55.366 T:140736441635776 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: nsv
21:57:55.366 T:140736441635776 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: radio
21:57:55.366 T:140736441635776 DEBUG: CPlayerCoreFactory::GetPlayers: matched 0 rules with players
21:57:55.366 T:140736441635776 DEBUG: CPlayerCoreFactory::GetPlayers: adding videodefaultplayer (VideoPlayer)
21:57:55.366 T:140736441635776 DEBUG: CPlayerCoreFactory::GetPlayers: for video=1, audio=0
21:57:55.366 T:140736441635776 DEBUG: CPlayerCoreFactory::GetPlayers: for video=1, audio=1
21:57:55.366 T:140736441635776 DEBUG: CPlayerCoreFactory::GetPlayers: added 1 players
21:57:55.367 T:140736441635776 DEBUG: Radio UECP (RDS) Processor - new CDVDRadioRDSData
21:57:55.367 T:140736441635776 NOTICE: VideoPlayer: Opening: pvr://channels/tv/All channels/pvr.vdr.vnsi_1317513966.pvr
21:57:55.367 T:140736441635776 WARNING: CDVDMessageQueue(player)::Put MSGQ_NOT_INITIALIZED
21:57:55.367 T:140736441635776 DEBUG: LinuxRendererGL: Cleaning up GL resources
21:57:55.367 T:140736441635776 DEBUG: CLinuxRendererGL::PreInit - precision of luminance 16 is 16
21:57:55.367 T:123145423097856 DEBUG: Thread VideoPlayer start, auto delete: false
21:57:55.367 T:123145423097856 NOTICE: Creating InputStream
21:57:55.367 T:123145423097856 DEBUG: PVRManager - OpenLiveStream - opening live stream on channel 'n-tv HD'
21:57:55.367 T:123145423097856 DEBUG: opening live stream for channel 'n-tv HD'
21:57:55.374 T:123145423097856 NOTICE: AddOnLog: VDR VNSI Client: Logged in at '1499716675+7200' to 'VDR-Network-Streaming-Interface (VNSI) Server' Version: '1.5.2' with protocol version '10'
21:57:55.374 T:123145423097856 DEBUG: AddOnLog: VDR VNSI Client: changing to channel 12
21:57:55.394 T:123145423097856 DEBUG: CDVDInputStreamPVRManager - Open - playback has started on filename pvr://channels/tv/All channels/pvr.vdr.vnsi_1317513966.pvr
21:57:55.394 T:123145423097856 DEBUG: CDVDInputStreamPVRManager::Open - stream opened: pvr://channels/tv/All channels/pvr.vdr.vnsi_1317513966.pvr
21:57:55.394 T:123145423097856 NOTICE: Creating Demuxer
21:57:55.394 T:123145423097856 DEBUG: OnPlayBackStarted: play state was 1, starting 1
21:57:55.394 T:123145423097856 DEBUG: CVideoPlayer::SetCaching - caching state 2
21:57:55.394 T:123145423097856 DEBUG: CDVDClock::SetSpeedAdjust - adjusted:0.000000
21:57:55.394 T:140736441635776 DEBUG: PlayFile: OpenFile succeed, play state 2
21:57:55.394 T:140736441635776 DEBUG: OnPlayBackStarted: play state was 2, starting 0
21:57:55.404 T:123145423634432 DEBUG: Thread JobWorker start, auto delete: true
21:57:55.404 T:123145423634432 DEBUG: CGUIInfoManager::SetCurrentMovie(pvr://channels/tv/All channels/pvr.vdr.vnsi_1317513966.pvr)
21:57:55.406 T:123145425780736 DEBUG: CAnnouncementManager - Announcement: OnPlay from xbmc
21:57:55.406 T:123145425780736 DEBUG: GOT ANNOUNCEMENT, type: 1, from xbmc, message OnPlay
21:57:57.390 T:123145423097856 DEBUG: CDVDDemuxClient::RequestStreams(): added/updated stream 36 with codec_id 94215
21:57:57.390 T:123145423097856 DEBUG: CDVDDemuxClient::RequestStreams(): added/updated stream 1279 with codec_id 28
21:57:57.390 T:123145423097856 DEBUG: CDVDDemuxClient::RequestStreams(): added/updated stream 1283 with codec_id 86019
21:57:57.390 T:123145423097856 DEBUG: CDVDDemuxClient::RequestStreams(): added/updated stream 1284 with codec_id 86019
21:57:57.390 T:123145423097856 NOTICE: Opening stream: 1279 source: 256
21:57:57.390 T:123145423097856 NOTICE: Creating video codec with codec id: 28
21:57:57.390 T:123145423097856 DEBUG: FactoryCodec - Video: - Opening
21:57:57.390 T:123145423097856 NOTICE: CDVDVideoCodecFFmpeg::Open() Using codec: H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10
21:57:57.390 T:123145423097856 DEBUG: CDVDVideoCodecFFmpeg - open frame threaded with 6 threads
21:57:57.390 T:123145423097856 DEBUG: CDVDVideoCodecFFmpeg - Updated codec: ff-h264
21:57:57.390 T:123145423097856 DEBUG: FactoryCodec - Video: ff-h264 - Opened
21:57:57.390 T:123145423097856 DEBUG: CVideoPlayerVideo::OpenStream - open stream with codec id: 28
21:57:57.390 T:123145423097856 NOTICE: Creating video thread
21:57:57.390 T:123145439809536 DEBUG: Thread VideoPlayerVideo start, auto delete: false
21:57:57.390 T:123145423097856 NOTICE: Opening stream: 1283 source: 256
21:57:57.390 T:123145439809536 NOTICE: running thread: video_thread
21:57:57.390 T:123145423097856 NOTICE: Finding audio codec for: 86019
21:57:57.391 T:123145423097856 DEBUG: FactoryCodec - Audio: FFmpeg - Opening
21:57:57.391 T:123145423097856 DEBUG: FactoryCodec - Audio: FFmpeg - Opened
21:57:57.391 T:123145423097856 NOTICE: Creating audio thread
21:57:57.391 T:123145440882688 DEBUG: Thread VideoPlayerAudio start, auto delete: false
21:57:57.391 T:123145423097856 NOTICE: Opening stream: 36 source: 256
21:57:57.391 T:123145440882688 NOTICE: running thread: CVideoPlayerAudio::Process()
21:57:57.391 T:123145423097856 NOTICE: waiting for teletext data thread to exit
21:57:57.391 T:123145440882688 DEBUG: CDVDAudio::Pause - pausing audio stream
21:57:57.391 T:123145423097856 NOTICE: Creating teletext data thread
21:57:57.391 T:123145441419264 DEBUG: Thread DVDTeletextData start, auto delete: false
21:57:57.391 T:123145441419264 NOTICE: running thread: CDVDTeletextData
21:57:57.414 T:123145423097856 DEBUG: CDVDDemuxClient::ParsePacket - {1279} profile changed from -99 to 100
21:57:57.414 T:123145423097856 DEBUG: CDVDDemuxClient::ParsePacket - {1279} level changed from -99 to 40
21:57:57.414 T:123145423097856 NOTICE: Opening stream: 1279 source: 256
21:57:57.414 T:123145423097856 NOTICE: Creating video codec with codec id: 28
21:57:57.414 T:123145423097856 DEBUG: FactoryCodec - Video: - Opening
21:57:57.414 T:123145423097856 NOTICE: CDVDVideoCodecFFmpeg::Open() Using codec: H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10
21:57:57.414 T:123145423097856 DEBUG: CDVDVideoCodecFFmpeg - open frame threaded with 6 threads
21:57:57.415 T:123145423097856 DEBUG: CDVDVideoCodecFFmpeg - Updated codec: ff-h264
21:57:57.415 T:123145423097856 DEBUG: FactoryCodec - Video: ff-h264 - Opened
21:57:57.415 T:123145423097856 NOTICE: Opening stream: 1283 source: 256
21:57:57.415 T:123145423097856 NOTICE: Opening stream: 36 source: 256
21:57:57.415 T:123145439809536 DEBUG: CVideoPlayerVideo::OpenStream - open stream with codec id: 28
21:57:57.415 T:123145439809536 DEBUG: CVideoPlayerVideo::CalcDropRequirement - hurry: 0
21:57:57.702 T:123145440882688 NOTICE: Creating audio stream (codec id: 86019, channels: 2, sample rate: 48000, no pass-through)
21:57:57.703 T:123145440882688 DEBUG: CVideoPlayerAudio:: synctype set to 1: resample
21:57:57.706 T:123145439809536 DEBUG: CVideoPlayerVideo::CalcDropRequirement - hurry: 0
21:57:57.731 T:123145427927040 DEBUG: Previous line repeats 3 times.
21:57:57.731 T:123145427927040 INFO: CActiveAESink::OpenSink - initialize sink
21:57:57.732 T:123145439809536 DEBUG: CVideoPlayerVideo::CalcDropRequirement - hurry: 0
21:57:57.778 T:123145439809536 DEBUG: Previous line repeats 2 times.
21:57:57.778 T:123145439809536 DEBUG: CRenderManager::Configure - change configuration. 1920x1080. display: 1920x1080. framerate: 25.00. format: YV12
21:57:57.787 T:140736441635776 DEBUG: DeleteRenderer - deleting renderer
21:57:57.787 T:140736441635776 DEBUG: LinuxRendererGL: Cleaning up GL resources
21:57:57.789 T:140736441635776 DEBUG: Previous line repeats 1 times.
21:57:57.789 T:140736441635776 DEBUG: CLinuxRendererGL::PreInit - precision of luminance 16 is 16
21:57:57.789 T:140736441635776 DEBUG: GL: Requested render method: 0
21:57:57.789 T:140736441635776 DEBUG: GL: BaseYUV2RGBGLSLShader: defines:
#define XBMC_texture_rectangle 0
#define XBMC_texture_rectangle_hack 0
#define XBMC_STRETCH 0
#define XBMC_YV12
21:57:57.789 T:140736441635776 NOTICE: GL: Selecting Single Pass YUV 2 RGB shader
21:57:57.790 T:140736441635776 DEBUG: GL: Vertex Shader compilation log:
21:57:57.790 T:140736441635776 DEBUG: GL: Vertex Shader compiled successfully
21:57:57.790 T:140736441635776 DEBUG: GL: Pixel Shader compilation log:
21:57:57.790 T:140736441635776 DEBUG: GL: Fragment Shader compiled successfully
21:57:57.791 T:140736441635776 DEBUG: GL: Vertex Shader compilation log:
21:57:57.791 T:140736441635776 DEBUG: GL: Vertex Shader compiled successfully
21:57:57.791 T:140736441635776 DEBUG: GL: Pixel Shader compilation log:
21:57:57.791 T:140736441635776 DEBUG: GL: Fragment Shader compiled successfully
21:57:57.792 T:140736441635776 NOTICE: GL: NPOT texture support detected
21:57:57.792 T:140736441635776 NOTICE: Using GL_TEXTURE_2D
21:57:57.792 T:140736441635776 DEBUG: CRenderManager::Configure - 4
21:57:57.794 T:140736441635776 DEBUG: GL: Requested render method: 0
21:57:57.794 T:140736441635776 DEBUG: GL: BaseYUV2RGBGLSLShader: defines:
#define XBMC_texture_rectangle 0
#define XBMC_texture_rectangle_hack 0
#define XBMC_STRETCH 0
#define XBMC_YV12
21:57:57.794 T:140736441635776 NOTICE: GL: Selecting Single Pass YUV 2 RGB shader
21:57:57.795 T:140736441635776 DEBUG: GL: Vertex Shader compilation log:
21:57:57.795 T:140736441635776 DEBUG: GL: Vertex Shader compiled successfully
21:57:57.795 T:140736441635776 DEBUG: GL: Pixel Shader compilation log:
21:57:57.795 T:140736441635776 DEBUG: GL: Fragment Shader compiled successfully
21:57:57.796 T:140736441635776 NOTICE: GL: NPOT texture support detected
21:57:57.868 T:123145423097856 DEBUG: CVideoPlayer::HandleMessages - player started 2
21:57:57.878 T:123145427927040 DEBUG: CCoreAudioStream::Close: Restoring original physical format for stream 0x002f. ([lpcm] Mixable Interleaved 2 Channel 32-bit Floating Point LE (44100Hz))
21:57:58.176 T:123145427927040 DEBUG: CCoreAudioStream::SetPhysicalFormat: Physical format for stream 0x002f. now active ([lpcm] Mixable Interleaved 2 Channel 32-bit Floating Point LE (44100Hz))
21:57:58.176 T:123145427927040 DEBUG: CCoreAudioStream::Close: Closed stream 0x002f.
21:57:58.177 T:123145427927040 DEBUG: CActiveAESink::OpenSink - trying to open device DARWINOSX:default
21:57:58.180 T:123145427927040 NOTICE: virtual bool CAESinkDARWINOSX::Initialize(AEAudioFormat &, std::string &): Opening default device Built-in Output
21:57:58.181 T:123145427927040 DEBUG: FindSuitableFormatForStream: Finding stream for format AE_FMT_FLOATP
21:57:58.181 T:123145427927040 DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 24-bit Signed Integer LE (96000Hz) rated 1106.000000
21:57:58.181 T:123145427927040 DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 24-bit Signed Integer LE (88200Hz) rated 670.500000
21:57:58.181 T:123145427927040 DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 24-bit Signed Integer LE (48000Hz) rated 1508.000000
21:57:58.181 T:123145427927040 DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 24-bit Signed Integer LE (44100Hz) rated 89.250000
21:57:58.181 T:123145427927040 DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 16-bit Signed Integer LE (96000Hz) rated 1105.000000
21:57:58.181 T:123145427927040 DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 16-bit Signed Integer LE (88200Hz) rated 669.500000
21:57:58.181 T:123145427927040 DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 16-bit Signed Integer LE (48000Hz) rated 1507.000000
21:57:58.181 T:123145427927040 DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 16-bit Signed Integer LE (44100Hz) rated 88.250000
21:57:58.181 T:123145427927040 DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 32-bit Floating Point LE (96000Hz) rated 1107.000000
21:57:58.181 T:123145427927040 DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 32-bit Floating Point LE (88200Hz) rated 671.500000
21:57:58.181 T:123145427927040 DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 32-bit Floating Point LE (48000Hz) rated 1509.000000
21:57:58.181 T:123145427927040 DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 32-bit Floating Point LE (44100Hz) rated 90.250000
21:57:58.181 T:123145427927040 DEBUG: Initialize: Selected stream[0] - id: 0x002F, Physical Format: [lpcm] Mixable Interleaved 2 Channel 32-bit Floating Point LE (48000Hz)
21:57:58.182 T:123145427927040 DEBUG: CCoreAudioDevice::SupportsMixing: Device mixing support : 'No'.
21:57:58.182 T:123145427927040 DEBUG: CCoreAudioStream::Open: Opened stream 0x002f.
21:57:58.182 T:123145427927040 DEBUG: Initialize: Previous Virtual Format: [lpcm] Mixable Interleaved 2 Channel 32-bit Floating Point LE (44100Hz)
21:57:58.182 T:123145427927040 DEBUG: Initialize: Previous Physical Format: [lpcm] Mixable Interleaved 2 Channel 32-bit Floating Point LE (44100Hz)
21:57:58.484 T:123145445175296 INFO: CCoreAudioStream::HardwareStreamListener: Hardware physical format changed to [lpcm] Mixable Interleaved 2 Channel 32-bit Floating Point LE (48000Hz)
21:57:58.484 T:123145445175296 INFO: CCoreAudioStream::HardwareStreamListener: Hardware virtual format changed to [lpcm] Mixable Interleaved 2 Channel 32-bit Floating Point LE (48000Hz)
21:57:58.487 T:123145427927040 DEBUG: CCoreAudioStream::SetPhysicalFormat: Physical format for stream 0x002f. now active ([lpcm] Mixable Interleaved 2 Channel 32-bit Floating Point LE (48000Hz))
21:57:58.491 T:123145427927040 DEBUG: Initialize: New Virtual Format: [lpcm] Mixable Interleaved 2 Channel 32-bit Floating Point LE (48000Hz)
21:57:58.491 T:123145427927040 DEBUG: Initialize: New Physical Format: [lpcm] Mixable Interleaved 2 Channel 32-bit Floating Point LE (48000Hz)
21:57:58.492 T:123145427927040 DEBUG: GetAEChannelMap Engine requests layout FL,FR
21:57:58.492 T:123145427927040 DEBUG: GetAEChannelMap trying to map to stereo layout: [Left] [Right]
21:57:58.492 T:123145427927040 DEBUG: GetAEChannelMap mapped channels to layout FL,FR
21:57:58.492 T:123145427927040 DEBUG: Initialize: using buffer size: 16384 (0.042667 ms)
21:57:58.492 T:123145427927040 DEBUG: CActiveAESink::OpenSink - DARWINOSX Initialized:
21:57:58.492 T:123145427927040 DEBUG: Output Device : Default
21:57:58.492 T:123145427927040 DEBUG: Sample Rate : 48000
21:57:58.492 T:123145427927040 DEBUG: Sample Format : AE_FMT_FLOAT
21:57:58.492 T:123145427927040 DEBUG: Channel Count : 2
21:57:58.492 T:123145427927040 DEBUG: Channel Layout: FL,FR
21:57:58.492 T:123145427927040 DEBUG: Frames : 512
21:57:58.492 T:123145427927040 DEBUG: Frame Size : 8
21:57:58.494 T:123145427390464 DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted
21:57:58.558 T:123145423097856 DEBUG: Previous line repeats 1 times.
21:57:58.558 T:123145423097856 DEBUG: CVideoPlayer::HandleMessages - player started 1
21:57:58.558 T:123145423097856 DEBUG: CVideoPlayer::SetCaching - caching state 3
21:57:58.558 T:123145423097856 DEBUG: CDVDClock::SetSpeedAdjust - adjusted:0.000000
21:57:58.558 T:123145423097856 DEBUG: CVideoPlayer::SetCaching - caching state 0
21:57:58.558 T:123145423097856 DEBUG: CDVDClock::SetSpeedAdjust - adjusted:0.000000
21:57:58.558 T:123145423097856 DEBUG: VideoPlayer::Sync - Audio - pts: 69783525756.000000, cache: 230520.844658, totalcache: 442666.679621
21:57:58.558 T:123145423097856 DEBUG: VideoPlayer::Sync - Video - pts: 69784381033.000000, cache: 50000.000000, totalcache: 100000.000000
21:57:58.558 T:123145440882688 DEBUG: CVideoPlayerAudio - CDVDMsg::GENERAL_RESYNC(69782683089.320374)
21:57:58.558 T:123145439809536 DEBUG: CVideoPlayerVideo - CDVDMsg::GENERAL_RESYNC(69782683089.320374)
21:57:58.558 T:123145440882688 DEBUG: CDVDAudio::Resume - resume audio stream
21:57:58.558 T:123145439809536 DEBUG: CVideoPlayerVideo::CalcDropRequirement - hurry: 1
21:57:58.559 T:123145427390464 DEBUG: ActiveAE - start sync of audio stream
21:57:58.559 T:123145439809536 DEBUG: CVideoPlayerVideo::CalcDropRequirement - hurry: 1
21:57:58.658 T:123145427390464 DEBUG: Previous line repeats 2 times.
21:57:58.658 T:123145427390464 DEBUG: ActiveAE::SyncStream - average error of 625.631049, start adjusting
21:57:59.119 T:123145439809536 WARNING: CRenderManager::WaitForBuffer - timeout waiting for buffer
21:57:59.293 T:123145427390464 DEBUG: ActiveAE::SyncStream - average error 15.833675, last average error: 625.631049
21:57:59.377 T:140736441635776 DEBUG: Keyboard: scancode: 0x35, sym: 0x001b, unicode: 0x001b, modifier: 0x0
21:57:59.405 T:123145427390464 DEBUG: ActiveAE::SyncStream - average error of -32.299154, start adjusting
21:57:59.405 T:123145427390464 DEBUG: ActiveAE::SyncStream - average error -22.299154 below threshold of 30.000000
21:57:59.425 T:140736441635776 DEBUG: OnKey: escape (0xf01b) pressed, action is PreviousMenu
21:57:59.425 T:140736441635776 DEBUG: CGUIWindowManager::PreviousWindow: Deactivate
21:57:59.426 T:140736441635776 DEBUG: ------ Window Deinit (Pointer.xml) ------
21:57:59.636 T:123145439809536 WARNING: CRenderManager::WaitForBuffer - timeout waiting for buffer
21:57:59.755 T:140736441635776 DEBUG: ------ Window Deinit (MyPVRChannels.xml) ------
21:57:59.756 T:140736441635776 DEBUG: CGUIWindowManager::PreviousWindow: Activate new
21:57:59.756 T:140736441635776 DEBUG: ------ Window Init (Home.xml) ------
21:57:59.757 T:140736441635776 DEBUG: CDirectoryProvider[addons://sources/video/]: refreshing..
21:57:59.757 T:140736441635776 DEBUG: CDirectoryProvider[addons://sources/audio/]: refreshing..
21:57:59.757 T:140736441635776 DEBUG: CDirectoryProvider[addons://sources/executable/]: refreshing..
21:57:59.757 T:140736441635776 DEBUG: CDirectoryProvider[addons://sources/image/]: refreshing..
21:57:59.757 T:140736441635776 DEBUG: CDirectoryProvider[pvr://channels/tv/*?view=lastplayed]: refreshing..
21:57:59.757 T:140736441635776 DEBUG: CDirectoryProvider[pvr://channels/radio/*?view=lastplayed]: refreshing..
21:57:59.757 T:123145446248448 DEBUG: Thread JobWorker start, auto delete: true
21:57:59.758 T:140736441635776 DEBUG: Keyboard: scancode: 0x35, sym: 0x001b, unicode: 0x0000, modifier: 0x0
21:57:59.760 T:140736441635776 DEBUG: ------ Window Init (Pointer.xml) ------
21:57:59.764 T:123145423634432 DEBUG: CPVRDirectory::GetDirectory(pvr://channels/tv/*?view=lastplayed)
21:57:59.766 T:123145446248448 DEBUG: CPVRDirectory::GetDirectory(pvr://channels/radio/*?view=lastplayed)
21:57:59.768 T:123145423634432 WARNING: CreateLoader - unsupported protocol(pvr) in pvr://channels/tv/All channels/pvr.vdr.vnsi_1317513966.tbn
21:57:59.768 T:123145423634432 WARNING: CreateLoader - unsupported protocol(pvr) in pvr://channels/tv/All channels/pvr.vdr.vnsi_118294079.tbn
21:57:59.768 T:123145423634432 WARNING: CreateLoader - unsupported protocol(pvr) in pvr://channels/tv/All channels/pvr.vdr.vnsi_1620961810.tbn
21:57:59.768 T:123145423634432 WARNING: CreateLoader - unsupported protocol(pvr) in pvr://channels/tv/All channels/pvr.vdr.vnsi_1055743585.tbn
21:57:59.768 T:123145423634432 WARNING: CreateLoader - unsupported protocol(pvr) in pvr://channels/tv/All channels/pvr.vdr.vnsi_1281493562.tbn
21:58:00.152 T:123145439809536 WARNING: CRenderManager::WaitForBuffer - timeout waiting for buffer
21:58:00.489 T:140736441635776 DEBUG: ProcessMouse: trying mouse action leftclick
21:58:00.489 T:140736441635776 DEBUG: Activating window ID: 12005
21:58:00.489 T:140736441635776 DEBUG: ------ Window Deinit (Home.xml) ------
21:58:00.489 T:140736441635776 DEBUG: ------ Window Init (VideoFullScreen.xml) ------
21:58:00.520 T:140736441635776 DEBUG: ------ Window Init (VideoOSD.xml) ------
21:58:00.523 T:140736441635776 ERROR: Control 602 in window 12901 has been asked to focus, but it can't
21:58:00.523 T:140736441635776 DEBUG: ------ Window Init (DialogSeekBar.xml) ------
21:58:00.523 T:140736441635776 DEBUG: ------ Window Init (Custom_1109_TopBarOverlay.xml) ------
21:58:00.554 T:140736441635776 ERROR: Control 602 in window 12901 has been asked to focus, but it can't
21:58:00.604 T:123145439809536 ERROR: Previous line repeats 2 times.
21:58:00.604 T:123145439809536 NOTICE: CDVDVideoCodecFFmpeg::CDropControl: calculated diff time: 47272
21:58:02.760 T:123145439809536 DEBUG: CPullupCorrection: detected pattern of length 1: 20000.00, frameduration: 20000.000000
21:58:08.756 T:140736441635776 DEBUG: ------ Window Deinit (Pointer.xml) ------
21:58:12.071 T:140736441635776 DEBUG: ------ Window Deinit (VideoOSD.xml) ------
21:58:12.087 T:140736441635776 DEBUG: ------ Window Deinit (DialogSeekBar.xml) ------
21:58:12.087 T:140736441635776 DEBUG: ------ Window Deinit (Custom_1109_TopBarOverlay.xml) ------
21:58:18.921 T:123145440882688 NOTICE: CVideoPlayerAudio::Process - stream stalled
21:58:19.122 T:123145423097856 DEBUG: CVideoPlayer::CheckContinuity - resync forward :2, prev:69804461033.000000, curr:69806061033.000000, diff:1560000.000000
21:58:19.122 T:123145423097856 DEBUG: Stream stalled, start buffering. Audio: 0 - Video: 11
21:58:19.122 T:123145423097856 DEBUG: CVideoPlayer::FlushBuffers - flushing buffers
21:58:19.131 T:123145440882688 DEBUG: CDVDAudio::Flush - flush audio stream
21:58:19.131 T:123145440882688 DEBUG: CDVDAudio::Pause - pausing audio stream
21:58:19.131 T:123145440882688 DEBUG: CVideoPlayerAudio - CDVDMsg::GENERAL_SYNCHRONIZE
21:58:19.131 T:123145439809536 DEBUG: CVideoPlayerVideo - CDVDMsg::GENERAL_SYNCHRONIZE
21:58:19.131 T:123145423097856 DEBUG: CVideoPlayer::SetCaching - caching state 2
21:58:19.131 T:123145423097856 DEBUG: CDVDClock::SetSpeedAdjust - adjusted:0.000000
21:58:19.142 T:123145440882688 DEBUG: CDVDAudio::Pause - pausing audio stream
21:58:19.147 T:123145439809536 INFO: CVideoPlayerVideo - Stillframe left, switching to normal playback
21:58:19.147 T:123145439809536 DEBUG: CVideoPlayerVideo::CalcDropRequirement - hurry: 0
21:58:19.256 T:123145423097856 DEBUG: Previous line repeats 2 times.
21:58:19.256 T:123145423097856 DEBUG: CVideoPlayer::HandleMessages - player started 1
21:58:19.256 T:123145439809536 DEBUG: CVideoPlayerVideo::CalcDropRequirement - hurry: 0
21:58:20.718 T:123145423097856 DEBUG: Previous line repeats 36 times.
21:58:20.718 T:123145423097856 DEBUG: CVideoPlayer::HandleMessages - player started 2
21:58:20.718 T:123145423097856 DEBUG: CVideoPlayer::SetCaching - caching state 3
21:58:20.718 T:123145423097856 DEBUG: CDVDClock::SetSpeedAdjust - adjusted:0.000000
21:58:20.718 T:123145423097856 DEBUG: CVideoPlayer::SetCaching - caching state 0
21:58:20.718 T:123145423097856 DEBUG: CDVDClock::SetSpeedAdjust - adjusted:0.000000
21:58:20.718 T:123145423097856 DEBUG: VideoPlayer::Sync - Audio - pts: 69805253756.000000, cache: 243139.460575, totalcache: 442666.679621
21:58:20.718 T:123145423097856 DEBUG: VideoPlayer::Sync - Video - pts: 69807421033.000000, cache: 50000.000000, totalcache: 100000.000000
21:58:20.718 T:123145440882688 DEBUG: CVideoPlayerAudio - CDVDMsg::GENERAL_RESYNC(69804411089.320374)
21:58:20.718 T:123145440882688 DEBUG: CDVDAudio::Resume - resume audio stream
21:58:20.719 T:123145439809536 DEBUG: CVideoPlayerVideo - CDVDMsg::GENERAL_RESYNC(69804411089.320374)
21:58:20.719 T:123145439809536 DEBUG: CVideoPlayerVideo::CalcDropRequirement - hurry: 1
21:58:20.722 T:123145427390464 DEBUG: ActiveAE - start sync of audio stream
21:58:20.830 T:123145427390464 DEBUG: ActiveAE::SyncStream - average error of 626.772998, start adjusting
21:58:21.236 T:123145439809536 WARNING: CRenderManager::WaitForBuffer - timeout waiting for buffer
21:58:21.470 T:123145427390464 DEBUG: ActiveAE::SyncStream - average error 24.735256, last average error: 626.772998
21:58:21.487 T:140736441635776 DEBUG: ------ Window Init (Pointer.xml) ------
21:58:21.503 T:140736441635776 DEBUG: ------ Window Init (VideoOSD.xml) ------
21:58:21.506 T:140736441635776 ERROR: Control 602 in window 12901 has been asked to focus, but it can't
21:58:21.507 T:140736441635776 DEBUG: ------ Window Init (DialogSeekBar.xml) ------
21:58:21.507 T:140736441635776 DEBUG: ------ Window Init (Custom_1109_TopBarOverlay.xml) ------
21:58:21.577 T:123145427390464 DEBUG: ActiveAE::SyncStream - average error of -24.745895, start adjusting
21:58:21.577 T:123145427390464 DEBUG: ActiveAE::SyncStream - average error -14.745895 below threshold of 30.000000
21:58:21.752 T:123145439809536 WARNING: CRenderManager::WaitForBuffer - timeout waiting for buffer
21:58:23.389 T:123145439809536 WARNING: Previous line repeats 3 times.
21:58:23.389 T:123145439809536 DEBUG: CVideoPlayerVideo::CalcDropRequirement - hurry: 1
21:58:26.194 T:123145439809536 DEBUG: CPullupCorrection: detected pattern of length 1: 20000.00, frameduration: 20000.000000
21:58:27.305 T:140736441635776 DEBUG: ------ Window Deinit (Pointer.xml) ------
21:58:28.289 T:140736441635776 DEBUG: ------ Window Init (Pointer.xml) ------
21:58:28.505 T:140736441635776 ERROR: Control 602 in window 12901 has been asked to focus, but it can't
21:58:29.255 T:140736441635776 ERROR: Previous line repeats 21 times.
21:58:29.255 T:140736441635776 DEBUG: ProcessMouse: trying mouse action leftclick
21:58:29.255 T:140736441635776 NOTICE: CVideoPlayer::CloseFile()
21:58:29.255 T:140736441635776 NOTICE: VideoPlayer: waiting for threads to exit
21:58:29.332 T:123145423097856 NOTICE: CVideoPlayer::OnExit()
21:58:29.332 T:123145423097856 NOTICE: Closing stream player 1
21:58:29.332 T:123145423097856 NOTICE: Waiting for audio thread to exit
21:58:29.353 T:123145440882688 NOTICE: thread end: CVideoPlayerAudio::OnExit()
21:58:29.353 T:123145440882688 DEBUG: Thread VideoPlayerAudio 123145440882688 terminating
21:58:29.353 T:123145423097856 NOTICE: Closing audio device
21:58:29.364 T:123145423097856 DEBUG: CDVDAudio::Flush - flush audio stream
21:58:29.364 T:123145427390464 DEBUG: CActiveAE::DiscardStream - audio stream deleted
21:58:29.364 T:123145427390464 DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted
21:58:29.364 T:123145423097856 DEBUG: Previous line repeats 2 times.
21:58:29.364 T:123145423097856 NOTICE: Deleting audio codec
21:58:29.364 T:123145427927040 INFO: CActiveAESink::OpenSink - initialize sink
21:58:29.364 T:123145423097856 NOTICE: Closing stream player 2
21:58:29.364 T:123145423097856 NOTICE: waiting for video thread to exit
21:58:29.406 T:123145445711872 WARNING: DARWINOSX: underflow (1600 vs 4096 bytes)
21:58:29.418 T:123145439809536 NOTICE: thread end: video_thread
21:58:29.418 T:123145439809536 DEBUG: Thread VideoPlayerVideo 123145439809536 terminating
21:58:29.418 T:123145423097856 NOTICE: deleting video codec
21:58:29.430 T:123145423097856 NOTICE: Closing stream player 4
21:58:29.430 T:123145423097856 NOTICE: waiting for teletext data thread to exit
21:58:29.430 T:123145441419264 ERROR: Got MSGQ_ABORT or MSGO_IS_ERROR return true (-1)
21:58:29.430 T:123145441419264 NOTICE: thread end: data_thread
21:58:29.430 T:123145441419264 DEBUG: Thread DVDTeletextData 123145441419264 terminating
21:58:29.434 T:123145446248448 DEBUG: DoWork - Saving file state for video item pvr://channels/tv/All channels/pvr.vdr.vnsi_1317513966.pvr
21:58:29.434 T:123145423097856 DEBUG: AddOnLog: VDR VNSI Client: closing demuxer
21:58:29.465 T:123145423097856 DEBUG: CDVDInputStreamPVRManager::Close - stream closed
21:58:29.465 T:123145423097856 DEBUG: OnPlayBackStopped: play state was 2, starting 0
21:58:29.465 T:123145423097856 DEBUG: Thread VideoPlayer 123145423097856 terminating
21:58:29.465 T:140736441635776 NOTICE: VideoPlayer: finished waiting
21:58:29.465 T:123145425780736 DEBUG: CAnnouncementManager - Announcement: OnStop from xbmc
21:58:29.465 T:140736441635776 DEBUG: DeleteRenderer - deleting renderer
21:58:29.465 T:140736441635776 DEBUG: LinuxRendererGL: Cleaning up GL resources
21:58:29.465 T:123145425780736 DEBUG: GOT ANNOUNCEMENT, type: 1, from xbmc, message OnStop
21:58:29.467 T:140736441635776 DEBUG: CGUIWindowManager::PreviousWindow: Deactivate
21:58:29.467 T:140736441635776 DEBUG: ------ Window Deinit (VideoOSD.xml) ------
21:58:29.467 T:140736441635776 DEBUG: ------ Window Deinit (VideoFullScreen.xml) ------
21:58:29.469 T:140736441635776 DEBUG: CGUIWindowManager::PreviousWindow: Activate new
21:58:29.469 T:140736441635776 DEBUG: ------ Window Init (Home.xml) ------
21:58:29.469 T:140736441635776 DEBUG: CDirectoryProvider[addons://sources/video/]: refreshing..
21:58:29.469 T:140736441635776 DEBUG: CDirectoryProvider[addons://sources/audio/]: refreshing..
21:58:29.469 T:140736441635776 DEBUG: CDirectoryProvider[addons://sources/executable/]: refreshing..
21:58:29.469 T:140736441635776 DEBUG: CDirectoryProvider[addons://sources/image/]: refreshing..
21:58:29.469 T:140736441635776 DEBUG: CDirectoryProvider[pvr://channels/tv/*?view=lastplayed]: refreshing..
21:58:29.469 T:140736441635776 DEBUG: CDirectoryProvider[pvr://channels/radio/*?view=lastplayed]: refreshing..
21:58:29.471 T:123145423097856 DEBUG: Thread JobWorker start, auto delete: true
21:58:29.471 T:140736441635776 ERROR: Control 803 in window 10000 has been asked to focus, but it can't
21:58:29.478 T:123145446248448 DEBUG: CPVRDirectory::GetDirectory(pvr://channels/tv/*?view=lastplayed)
21:58:29.481 T:123145423097856 DEBUG: CPVRDirectory::GetDirectory(pvr://channels/radio/*?view=lastplayed)
21:58:29.485 T:123145446248448 WARNING: CreateLoader - unsupported protocol(pvr) in pvr://channels/tv/All channels/pvr.vdr.vnsi_1317513966.tbn
21:58:29.485 T:123145446248448 WARNING: CreateLoader - unsupported protocol(pvr) in pvr://channels/tv/All channels/pvr.vdr.vnsi_118294079.tbn
21:58:29.485 T:123145446248448 WARNING: CreateLoader - unsupported protocol(pvr) in pvr://channels/tv/All channels/pvr.vdr.vnsi_1620961810.tbn
21:58:29.485 T:123145446248448 WARNING: CreateLoader - unsupported protocol(pvr) in pvr://channels/tv/All channels/pvr.vdr.vnsi_1055743585.tbn
21:58:29.486 T:123145446248448 WARNING: CreateLoader - unsupported protocol(pvr) in pvr://channels/tv/All channels/pvr.vdr.vnsi_1281493562.tbn
21:58:29.508 T:123145427927040 DEBUG: CCoreAudioStream::Close: Restoring original physical format for stream 0x002f. ([lpcm] Mixable Interleaved 2 Channel 32-bit Floating Point LE (44100Hz))
21:58:29.539 T:140736441635776 DEBUG: ------ Window Deinit (Pointer.xml) ------
21:58:29.541 T:140736441635776 NOTICE: CVideoPlayer::CloseFile()
21:58:29.541 T:140736441635776 NOTICE: VideoPlayer: waiting for threads to exit
21:58:29.541 T:140736441635776 NOTICE: VideoPlayer: finished waiting
21:58:29.541 T:140736441635776 NOTICE: CVideoPlayer::CloseFile()
21:58:29.541 T:140736441635776 NOTICE: VideoPlayer: waiting for threads to exit
21:58:29.541 T:140736441635776 NOTICE: VideoPlayer: finished waiting
21:58:29.544 T:140736441635776 DEBUG: Radio UECP (RDS) Processor - delete ~CDVDRadioRDSData
21:58:29.545 T:140736441635776 DEBUG: ------ Window Deinit (DialogSeekBar.xml) ------
21:58:29.556 T:140736441635776 DEBUG: ------ Window Deinit (Custom_1109_TopBarOverlay.xml) ------
21:58:29.907 T:123145427927040 DEBUG: CCoreAudioStream::SetPhysicalFormat: Physical format for stream 0x002f. now active ([lpcm] Mixable Interleaved 2 Channel 32-bit Floating Point LE (44100Hz))
21:58:29.907 T:123145427927040 DEBUG: CCoreAudioStream::Close: Closed stream 0x002f.
21:58:29.907 T:123145427927040 DEBUG: CActiveAESink::OpenSink - trying to open device DARWINOSX:default
21:58:29.908 T:123145427927040 NOTICE: virtual bool CAESinkDARWINOSX::Initialize(AEAudioFormat &, std::string &): Opening default device Built-in Output
21:58:29.909 T:123145427927040 DEBUG: FindSuitableFormatForStream: Finding stream for format AE_FMT_FLOAT
21:58:29.909 T:123145427927040 DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 24-bit Signed Integer LE (96000Hz) rated 929.129272
21:58:29.909 T:123145427927040 DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 24-bit Signed Integer LE (88200Hz) rated 1106.000000
21:58:29.909 T:123145427927040 DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 24-bit Signed Integer LE (48000Hz) rated 1419.564697
21:58:29.909 T:123145427927040 DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 24-bit Signed Integer LE (44100Hz) rated 1508.000000
21:58:29.909 T:123145427927040 DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 16-bit Signed Integer LE (96000Hz) rated 928.129272
21:58:29.909 T:123145427927040 DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 16-bit Signed Integer LE (88200Hz) rated 1105.000000
21:58:29.909 T:123145427927040 DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 16-bit Signed Integer LE (48000Hz) rated 1418.564697
21:58:29.909 T:123145427927040 DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 16-bit Signed Integer LE (44100Hz) rated 1507.000000
21:58:29.909 T:123145427927040 DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 32-bit Floating Point LE (96000Hz) rated 930.129272
21:58:29.909 T:123145427927040 DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 32-bit Floating Point LE (88200Hz) rated 1107.000000
21:58:29.909 T:123145427927040 DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 32-bit Floating Point LE (48000Hz) rated 1420.564697
21:58:29.909 T:123145427927040 DEBUG: FindSuitableFormatForStream: Physical Format: [lpcm] Mixable Interleaved 2 Channel 32-bit Floating Point LE (44100Hz) rated 1509.000000
21:58:29.909 T:123145427927040 DEBUG: Initialize: Selected stream[0] - id: 0x002F, Physical Format: [lpcm] Mixable Interleaved 2 Channel 32-bit Floating Point LE (44100Hz)
21:58:29.909 T:123145427927040 DEBUG: CCoreAudioDevice::SupportsMixing: Device mixing support : 'No'.
21:58:29.909 T:123145427927040 DEBUG: CCoreAudioStream::Open: Opened stream 0x002f.
21:58:29.909 T:123145427927040 DEBUG: Initialize: Previous Virtual Format: [lpcm] Mixable Interleaved 2 Channel 32-bit Floating Point LE (44100Hz)
21:58:29.909 T:123145427927040 DEBUG: Initialize: Previous Physical Format: [lpcm] Mixable Interleaved 2 Channel 32-bit Floating Point LE (44100Hz)
21:58:30.200 T:123145427927040 DEBUG: CCoreAudioStream::SetPhysicalFormat: Physical format for stream 0x002f. now active ([lpcm] Mixable Interleaved 2 Channel 32-bit Floating Point LE (44100Hz))
21:58:30.203 T:123145427927040 DEBUG: Initialize: New Virtual Format: [lpcm] Mixable Interleaved 2 Channel 32-bit Floating Point LE (44100Hz)
21:58:30.203 T:123145427927040 DEBUG: Initialize: New Physical Format: [lpcm] Mixable Interleaved 2 Channel 32-bit Floating Point LE (44100Hz)
21:58:30.204 T:123145427927040 DEBUG: GetAEChannelMap Engine requests layout FL,FR
21:58:30.204 T:123145427927040 DEBUG: GetAEChannelMap trying to map to stereo layout: [Left] [Right]
21:58:30.204 T:123145427927040 DEBUG: GetAEChannelMap mapped channels to layout FL,FR
21:58:30.204 T:123145427927040 DEBUG: Initialize: using buffer size: 16384 (0.046440 ms)
21:58:30.204 T:123145427927040 DEBUG: CActiveAESink::OpenSink - DARWINOSX Initialized:
21:58:30.204 T:123145427927040 DEBUG: Output Device : Default
21:58:30.204 T:123145427927040 DEBUG: Sample Rate : 44100
21:58:30.204 T:123145427927040 DEBUG: Sample Format : AE_FMT_FLOAT
21:58:30.204 T:123145427927040 DEBUG: Channel Count : 2
21:58:30.204 T:123145427927040 DEBUG: Channel Layout: FL,FR
21:58:30.204 T:123145427927040 DEBUG: Frames : 512
21:58:30.204 T:123145427927040 DEBUG: Frame Size : 8
21:58:30.205 T:123145427390464 DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deletedI can watch the same channel via http without issues , so it is related to the vnsi plugin ?
sharky@tv-server:~$ vdr -V
vdr (2.3.8/2.3.8) - The Video Disk Recorder
ddci2 (1.0.5) - External Digital Devices CI-Adapter
live (2.3.1) - Live Interactive VDR Environment
permashift (1.0.3) - Auto-buffer live TV
streamdev-server (0.6.1-git) - VDR Streaming Server
vnsiserver (1.5.2) - VDR-Network-Streaming-Interface (VNSI) Server
Updated my system to the latest dev version, but the same problem occur on vdr 2.2.0 .
RE: VNSI Kodi 17 Mac specific channel results in crash - FernetMenta - 2017-07-11
Can you try a nightly please.
Please post logs on pastebin (or similar) not directly here.
RE: VNSI Kodi 17 Mac specific channel results in crash - sharky1337 - 2017-07-13
Issue still occur with nightly
18.0-ALPHA1 Git:20170712-9b94915). Platform: OS X x86 64-bit
https://pastebin.com/2X5CfZrZ
RE: VNSI Kodi 17 Mac specific channel results in crash - FernetMenta - 2017-07-14
My guess is a weak network connectivity. How is you Mac and vdr server connected to the network?
RE: VNSI Kodi 17 Mac specific channel results in crash - FernetMenta - 2017-07-14
BTW: I don't obderve those issues on my Mac no matter what vdr channel. (vdr 2.3.7)
RE: VNSI Kodi 17 Mac specific channel results in crash - sharky1337 - 2017-07-14
I will check that, but normally than all other protocols should have glitches too and http runs smooth.
RE: VNSI Kodi 17 Mac specific channel results in crash - FernetMenta - 2017-07-14
(2017-07-14, 16:45)sharky1337 Wrote: I will check that, but normally than all other protocols should have glitches too and http runs smooth.
Nope, because live tv are realtime streams. That means that buffers won't fill once playback has been started. By changing playback speed slightly VideoPlayer holds level of demuxer queued above 5%, that is approximately 400ms. If you don't get packets in this timeframe, a/v streams stall.
RE: VNSI Kodi 17 Mac specific channel results in crash - sharky1337 - 2017-07-14
No , sorry I mean real live streams via http (streamdev ) works fine . Playback via kodi iptv plugin or vlc is super smooth. If I there were packet loss than we should see it on both protocols http and vnsi .
RE: VNSI Kodi 17 Mac specific channel results in crash - FernetMenta - 2017-07-15
hmm, this is from my Mac playing ZDF: https://pastebin.com/byzumbqk
Mac and vdr server are connected via wired LAN.
Do you use wireless? If so, can you test with cables?
RE: VNSI Kodi 17 Mac specific channel results in crash - sharky1337 - 2017-07-16
Hey ,
yes I tried both and now I'm only testing on the cable path, the wireless adapter disabled.
I don't know that much about how different plugins in vdr work together, but everytime the "hicup" occur this message show up in the vdr debug log.
Code:
Jul 14 22:22:39 tv-server vdr: [4042] VNSI: CAM error, try reset
Jul 14 22:22:39 tv-server vdr: [4042] VNSI: re-tuning...
Jul 14 22:22:39 tv-server vdr: [4042] VNSI: close video input ...
Jul 14 22:22:39 tv-server vdr: [4042] VNSI: activate live receiver: 0
Jul 14 22:22:39 tv-server vdr: [4042] CAM 1: unassigned from device 1
Jul 14 22:22:39 tv-server vdr: [4042] VNSI: Dummy receiver (0x7f56100049a0) deactivated
Jul 14 22:22:39 tv-server vdr: [4042] CAM 1/1: reusing MTD CAM slot
Jul 14 22:22:39 tv-server vdr: [4089] device 1 TS buffer thread ended (pid=4015, tid=4089)
Jul 14 22:22:39 tv-server vdr: [4088] buffer stats: 255492 (4%) used
Jul 14 22:22:39 tv-server vdr: [4088] device 1 receiver thread ended (pid=4015, tid=4088)
Jul 14 22:22:39 tv-server vdr: [4042] CAM 1: assigned to device 1
Jul 14 22:22:39 tv-server vdr: [4042] VNSI: Successfully found following device: 0xe3a050 (1) for receiving, priority=0
Jul 14 22:22:39 tv-server vdr: [4090] device 1 receiver thread started (pid=4015, tid=4090, prio=high)
Jul 14 22:22:39 tv-server vdr: [4091] device 1 TS buffer thread started (pid=4015, tid=4091, prio=high)
Jul 14 22:22:39 tv-server vdr: [4042] VNSI: Dummy receiver (0x7f56100049a0) activated
Jul 14 22:22:39 tv-server vdr: [4042] VNSI: activate live receiver: 1I'm using the ddci2 plugin for decrypting the channel , but I don't know if this messages is returned by vnsi or ddci
Jul 14 22:22:39 tv-server vdr: [4042] VNSI: CAM error, try reset
To troubelshoot this further, do I have to use gdp version of the plugins ?
RE: VNSI Kodi 17 Mac specific channel results in crash - FernetMenta - 2017-07-16
Jul 14 22:22:39 tv-server vdr: [4042] VNSI: CAM error, try reset
This means that vnsiserver got a scrambled (encrypted) PES packet from vdr at a time when the cam has already stated working. As a fist step I would try vdr 2.3.7
RE: VNSI Kodi 17 Mac specific channel results in crash - sharky1337 - 2017-07-16
I asked other people on vdr-portal and they would like to know why are you doing a retune if the Scrambed Bit is set in ts stream . Maybe you can join the following discussion.
http://www.vdr-portal.de/board18-vdr-hardware/board102-dvb-karten/101149-ci-unterstützung-für-cines2-mystique-satix-s2-dual-usw/index20.html
I think you know some german if you're from munich ;-)
RE: VNSI Kodi 17 Mac specific channel results in crash - FernetMenta - 2017-07-17
(2017-07-16, 21:32)sharky1337 Wrote: I asked other people on vdr-portal and they would like to know why are you doing a retune if the Scrambed Bit is set in ts stream . Maybe you can join the following discussion.
http://www.vdr-portal.de/board18-vdr-hardware/board102-dvb-karten/101149-ci-unterstützung-für-cines2-mystique-satix-s2-dual-usw/index20.html
I think you know some german if you're from munich ;-)
If the scramble bit is set, we have an error condition that not necessarely is recoverable. By retuning vnsiserver recovers from this error.
Sure, vnsiserver could be more fault tolerant by i.e. wait with reset for x errors in a row. This issue seems to be limited to ddci