Login at Kodi Home

Mirar · 2014-08-19, 22:35

I have a problem with surround. The rear channels and subwoofer are mixed up.

* Not doing passthrough.
* The problem is only with XBMC. Playing in mplayer and everything is fine.
* Output is HDMI over a nVidia card over pulseaudio in default settings (I want to keep running pulseaudio)
* Problem exist in both 13.2 beta 1 and 14.0 alpha (nightly)
* Problem exist both for ac3 and wmv
* Sample rate or methods or hardware acceleration or 5.1 or 7.1 changes nothing

So my conclusion is that somewhere inside XBMC the channels are processed and output into the wrong channels.

My question is:

How do I debug this problem?
Where and how do XBMC do it's channel mapping?
Is there a settings file somewhere or anything like that?

**fritsch** · 2014-08-20, 08:08

post a Debug Log ...

Mirar · 2014-08-20, 10:02

(2014-08-20, 08:08)fritsch Wrote: post a Debug Log ...

Thank you. With this, I can determine that:

Code:
51:09 T:140438571353856   DEBUG: CActiveAESink::OpenSink - PULSE Initialized:

51:09 T:140438571353856   DEBUG:   Output Device : Default

51:09 T:140438571353856   DEBUG:   Sample Rate   : 192000

51:09 T:140438571353856   DEBUG:   Sample Format : AE_FMT_FLOAT

51:09 T:140438571353856   DEBUG:   Channel Count : 6

51:09 T:140438571353856   DEBUG:   Channel Layout: FL,FR,FC,BL,BR,LFE

51:09 T:140438571353856   DEBUG:   Frames        : 9600

51:09 T:140438571353856   DEBUG:   Frame Samples : 57600

51:09 T:140438571353856   DEBUG:   Frame Size    : 24

that doesn't seem to match the output from speaker-test, which uses the correct channels:

Code:
- Front Left

- Front Right

- Rear Left

- Rear Right

- Center

- LFE

However, the center channel is correct from XBMC to the speaker, but LFE is wrong.
LFE/rear left/rear right are mixed up from XBMC to the speakers. I'm even more confused now.

Relevant parts of the debug log:

Code:
51:08 T:140438876489664   DEBUG: OnKey: return (0xf00d) pressed, action is Select

51:08 T:140438876489664   DEBUG: OnPlayMedia /mnt/media/unsorted/wmv-surroundtest_720p.wmv

51:08 T:140438876489664   DEBUG: CAnnouncementManager - Announcement: OnClear from xbmc

51:08 T:140438876489664   DEBUG: GOT ANNOUNCEMENT, type: 2, from xbmc, message OnClear

51:08 T:140438876489664   DEBUG: GetMovieId (/mnt/media/unsorted/wmv-surroundtest_720p.wmv), query = select idMovie from movie where idFile=12275

51:08 T:140438876489664   DEBUG: GetEpisodeId (/mnt/media/unsorted/wmv-surroundtest_720p.wmv), query = select idEpisode from episode where idFile=12275

51:08 T:140438876489664   DEBUG: GetMusicVideoId (/mnt/media/unsorted/wmv-surroundtest_720p.wmv), query = select idMVideo from musicvideo where idFile=12275

51:08 T:140438876489664   DEBUG: CAnnouncementManager - Announcement: OnAdd from xbmc

51:08 T:140438876489664   DEBUG: GOT ANNOUNCEMENT, type: 2, from xbmc, message OnAdd

51:08 T:140438876489664   DEBUG: Loading settings for /mnt/media/unsorted/wmv-surroundtest_720p.wmv

51:08 T:140438876489664   DEBUG: CPlayerCoreFactory::GetPlayers(/mnt/media/unsorted/wmv-surroundtest_720p.wmv)

51:08 T:140438876489664   DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: system rules

51:08 T:140438876489664   DEBUG: CPlayerSelectionRule::GetPlayers: matches rule: system rules

51:08 T:140438876489664   DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: rtv

51:08 T:140438876489664   DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: hdhomerun/myth/mms/udp

51:08 T:140438876489664   DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: lastfm/shout

51:08 T:140438876489664   DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: rtmp

51:08 T:140438876489664   DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: rtsp

51:08 T:140438876489664   DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: streams

51:08 T:140438876489664   DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: dvd

51:08 T:140438876489664   DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: dvdimage

51:08 T:140438876489664   DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: sdp/asf

51:08 T:140438876489664   DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: nsv

51:08 T:140438876489664   DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: radio

51:08 T:140438876489664   DEBUG: CPlayerCoreFactory::GetPlayers: matched 0 rules with players

51:08 T:140438876489664   DEBUG: CPlayerCoreFactory::GetPlayers: adding videodefaultplayer (1)

51:08 T:140438876489664   DEBUG: CPlayerCoreFactory::GetPlayers: for video=1, audio=0

51:08 T:140438876489664   DEBUG: CPlayerCoreFactory::GetPlayers: for video=1, audio=1

51:08 T:140438876489664   DEBUG: CPlayerCoreFactory::GetPlayers: adding player: DVDPlayer (1)

51:08 T:140438876489664   DEBUG: CPlayerCoreFactory::GetPlayers: added 1 players

51:08 T:140438876489664  NOTICE: DVDPlayer: Opening: /mnt/media/unsorted/wmv-surroundtest_720p.wmv

51:08 T:140438876489664 WARNING: CDVDMessageQueue(player)::Put MSGQ_NOT_INITIALIZED

51:08 T:140438876489664   DEBUG: CRenderManager::UpdateDisplayLatency - Latency set to 0 msec

51:08 T:140438876489664   DEBUG: LinuxRendererGL: Cleaning up GL resources

51:08 T:140438876489664   DEBUG: CLinuxRendererGL::PreInit - precision of luminance 16 is 16

51:08 T:140438526441216  NOTICE: Thread DVDPlayer start, auto delete: false

51:08 T:140438526441216  NOTICE: Creating InputStream

51:08 T:140438526441216   DEBUG: ScanForExternalSubtitles: Searching for subtitles...

51:08 T:140438526441216   DEBUG: ScanForExternalSubtitles: END (total time: 1 ms)

51:08 T:140438526441216  NOTICE: Creating Demuxer

51:08 T:140438526441216   DEBUG: Open - probing detected format [asf]

51:08 T:140438526441216   DEBUG: Open - avformat_find_stream_info starting

51:08 T:140438526441216   DEBUG: ffmpeg[647B3700]: [asf] parser not found for codec wmapro, packets or times may be invalid.

51:09 T:140438526441216   DEBUG: Previous line repeats 1 times.

51:09 T:140438526441216   DEBUG: Open - av_find_stream_info finished

51:09 T:140438526441216    INFO: ffmpeg[647B3700]: Input #0, asf, from '/mnt/media/unsorted/wmv-surroundtest_720p.wmv':

51:09 T:140438526441216    INFO: ffmpeg[647B3700]:   Metadata:

51:09 T:140438526441216    INFO: ffmpeg[647B3700]:     WMFSDKNeeded    : 0.0.0.0000

51:09 T:140438526441216    INFO: ffmpeg[647B3700]:     DeviceConformanceTemplate: MP@HL

51:09 T:140438526441216    INFO: ffmpeg[647B3700]:     WM/WMADRCPeakReference: 31838

51:09 T:140438526441216    INFO: ffmpeg[647B3700]:     WM/WMADRCPeakTarget: 31838

51:09 T:140438526441216    INFO: ffmpeg[647B3700]:     WM/WMADRCAverageReference: 4878

51:09 T:140438526441216    INFO: ffmpeg[647B3700]:     WM/WMADRCAverageTarget: 4878

51:09 T:140438526441216    INFO: ffmpeg[647B3700]:     WMFSDKVersion   : 9.00.00.2980

51:09 T:140438526441216    INFO: ffmpeg[647B3700]:     IsVBR           : 0

51:09 T:140438526441216    INFO: ffmpeg[647B3700]:   Duration: 00:00:08.50, start: 0.000000, bitrate: 4948 kb/s

51:09 T:140438526441216    INFO: ffmpeg[647B3700]:     Stream #0:0(eng): Audio: wmapro (b[1][0][0] / 0x0162), 48000 Hz, 5.1, fltp, 384 kb/s

51:09 T:140438526441216    INFO: ffmpeg[647B3700]:     Stream #0:1(eng): Video: wmv3 (Main) (WMV3 / 0x33564D57), yuv420p, 1280x720, 5000 kb/s, 24 tbr, 1k tbn, 1k tbc

51:09 T:140438526441216   DEBUG: CDVDDemuxFFmpeg::AddStream(0, ...) -> 0

51:09 T:140438526441216   DEBUG: CDVDDemuxFFmpeg::AddStream(1, ...) -> 1

51:09 T:140438526441216  NOTICE: Opening stream: 1 source: 256

51:09 T:140438526441216  NOTICE: Creating video codec with codec id: 72

51:09 T:140438526441216   DEBUG: CDVDFactoryCodec: compiled in hardware support: CrystalHD:yes AMCodec:no MediaCodec:no OpenMax:no libstagefright:no VDPAU:yes VAAPI:yes

51:09 T:140438526441216   DEBUG: FactoryCodec - Video:  - Opening

51:09 T:140438526441216  NOTICE: CDVDVideoCodecFFmpeg::Open() Using codec: Windows Media Video 9

51:09 T:140438526441216  NOTICE: CDVDVideoCodecFFmpeg::GetFormat - Creating VDPAU(1280x720)

51:09 T:140438526441216  NOTICE: VDPAU::CreateContext - creating decoder context

51:09 T:140438526441216  NOTICE: vdp_device = 0x00000001 vdp_st = 0x00000000

51:09 T:140438526441216  NOTICE: VDPAU Decoder capabilities:

51:09 T:140438526441216  NOTICE: name          level macbs width height

51:09 T:140438526441216  NOTICE: ------------------------------------

51:09 T:140438526441216  NOTICE: MPEG1             0 65536  4032  4048

51:09 T:140438526441216  NOTICE: MPEG2_SIMPLE      3 65536  4032  4048

51:09 T:140438526441216  NOTICE: MPEG2_MAIN        3 65536  4032  4048

51:09 T:140438526441216  NOTICE: H264_MAIN        41 65536  4032  4080

51:09 T:140438526441216  NOTICE: H264_HIGH        41 65536  4032  4080

51:09 T:140438526441216  NOTICE: VC1_SIMPLE        1  8190  2048  2048

51:09 T:140438526441216  NOTICE: VC1_MAIN          2  8190  2048  2048

51:09 T:140438526441216  NOTICE: VC1_ADVANCED      4  8190  2048  2048

51:09 T:140438526441216  NOTICE: MPEG4_PART2_ASP   5  8192  2048  2048

51:09 T:140438526441216  NOTICE: ------------------------------------

51:09 T:140438526441216  NOTICE: Mixer feature: VDP_VIDEO_MIXER_FEATURE_NOISE_REDUCTION

51:09 T:140438526441216  NOTICE: Mixer feature: VDP_VIDEO_MIXER_FEATURE_SHARPNESS

51:09 T:140438526441216  NOTICE: Mixer feature: VDP_VIDEO_MIXER_FEATURE_DEINTERLACE_TEMPORAL

51:09 T:140438526441216  NOTICE: Mixer feature: VDP_VIDEO_MIXER_FEATURE_DEINTERLACE_TEMPORAL_SPATIAL

51:09 T:140438526441216  NOTICE: Mixer feature: VDP_VIDEO_MIXER_FEATURE_INVERSE_TELECINE

51:09 T:140438526441216  NOTICE: Mixer feature: VDP_VIDEO_MIXER_FEATURE_HIGH_QUALITY_SCALING_L1

51:09 T:140438526441216  NOTICE: CDVDVideoCodecFFmpeg::GetFormat - Creating VDPAU(1280x720)

51:09 T:140438526441216  NOTICE:  (VDPAU) Close

51:09 T:140438526441216   DEBUG: FactoryCodec - Video: ff-wmv3-vdpau - Opened

51:09 T:140438526441216  NOTICE: Creating video thread

51:09 T:140438488422144  NOTICE: Thread DVDPlayerVideo start, auto delete: false

51:09 T:140438488422144  NOTICE: running thread: video_thread

51:09 T:140438526441216  NOTICE: Opening stream: 0 source: 256

51:09 T:140438526441216  NOTICE: Finding audio codec for: 86054

51:09 T:140438526441216   DEBUG: FactoryCodec - Audio: passthrough - Opening

51:09 T:140438526441216   DEBUG: FactoryCodec - Audio: passthrough - Failed

51:09 T:140438526441216   DEBUG: FactoryCodec - Audio: FFmpeg - Opening

51:09 T:140438526441216   DEBUG: FactoryCodec - Audio: FFmpeg - Opened

51:09 T:140438526441216  NOTICE: Creating audio thread

51:09 T:140438473975552  NOTICE: Thread DVDPlayerAudio start, auto delete: false

51:09 T:140438473975552  NOTICE: running thread: CDVDPlayerAudio::Process()

51:09 T:140438488422144   DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_SYNCHRONIZE

51:09 T:140438473975552   DEBUG: CDVDPlayerAudio - CDVDMsg::GENERAL_SYNCHRONIZE

51:09 T:140438526441216   DEBUG: ReadEditDecisionLists - Checking for edit decision lists (EDL) on local drive or remote share for: /mnt/media/unsorted/wmv-surroundtest_720p.wmv

51:09 T:140438526441216   DEBUG: OnPlayBackStarted : play state was 1, starting 1

51:09 T:140438526441216   DEBUG: CDVDPlayer::SetCaching - caching state 3

51:09 T:140438876489664   DEBUG: PlayFile : OpenFile succeed, play state 2

51:09 T:140438876489664   DEBUG: OnPlayBackStarted : play state was 2, starting 0

51:09 T:140438488422144    INFO: CDVDPlayerVideo - Stillframe left, switching to normal playback

51:09 T:140438488422144  NOTICE: CDVDVideoCodecFFmpeg::GetFormat - Creating VDPAU(1280x720)

51:09 T:140438473975552  NOTICE: Creating audio stream (codec id: 86054, channels: 6, sample rate: 48000, no pass-through)

51:09 T:140438473975552   DEBUG: CDVDPlayerAudio:: synctype set to 0: clock feedback

51:09 T:140438508410624    INFO: CActiveAE::ApplySettings - Forcing samplerate to 192000

51:09 T:140438526441216   DEBUG: CDVDPlayer::SetCaching - caching state 0

51:09 T:140438571353856    INFO: CActiveAESink::OpenSink - initialize sink

51:09 T:140438876489664   DEBUG: CGUIInfoManager::SetCurrentMovie(/mnt/media/unsorted/wmv-surroundtest_720p.wmv)

51:09 T:140438876489664   DEBUG: GetMovieId (/mnt/media/unsorted/wmv-surroundtest_720p.wmv), query = select idMovie from movie where idFile=12275

51:09 T:140438876489664   DEBUG: GetEpisodeId (/mnt/media/unsorted/wmv-surroundtest_720p.wmv), query = select idEpisode from episode where idFile=12275

51:09 T:140438876489664   DEBUG: GetMusicVideoId (/mnt/media/unsorted/wmv-surroundtest_720p.wmv), query = select idMVideo from musicvideo where idFile=12275

51:09 T:140438876489664   DEBUG: CAnnouncementManager - Announcement: OnPlay from xbmc

51:09 T:140438876489664   DEBUG: GOT ANNOUNCEMENT, type: 1, from xbmc, message OnPlay

51:09 T:140438488422144  NOTICE:  (VDPAU) Close

51:09 T:140438488422144   DEBUG: CVDPAU::SetWidthHeight Setting OutWidth: 1280 OutHeight: 720

51:09 T:140438488422144  NOTICE:  (VDPAU) screenWidth:1280 vidWidth:1280 surfaceWidth:1280

51:09 T:140438488422144  NOTICE:  (VDPAU) screenHeight:720 vidHeight:720 surfaceHeight:720

51:09 T:140438571353856   DEBUG: CActiveAESink::OpenSink - trying to open device PULSE:Default

51:09 T:140438571353856   DEBUG: PulseAudio: Context authorizing

51:09 T:140438571353856   DEBUG: PulseAudio: Context setting name

51:09 T:140438571353856   DEBUG: PulseAudio: Context ready

51:09 T:140438571353856   DEBUG: PULSE does not support format: AE_FMT_FLOATP - will fallback to AE_FMT_FLOAT

51:09 T:140438571353856   DEBUG: PulseAudio: Stream ready

51:09 T:140438571353856   DEBUG: Restored Stream value to 0.898579

51:09 T:140438571353856   DEBUG: CAnnouncementManager - Announcement: OnVolumeChanged from xbmc

51:09 T:140438571353856   DEBUG: GOT ANNOUNCEMENT, type: 64, from xbmc, message OnVolumeChanged

51:09 T:140438571353856  NOTICE: PulseAudio: Opened device Default in pcm mode with Buffersize 185 ms

51:09 T:140438571353856   DEBUG: CActiveAESink::OpenSink - PULSE Initialized:

51:09 T:140438571353856   DEBUG:   Output Device : Default

51:09 T:140438571353856   DEBUG:   Sample Rate   : 192000

51:09 T:140438571353856   DEBUG:   Sample Format : AE_FMT_FLOAT

51:09 T:140438571353856   DEBUG:   Channel Count : 6

51:09 T:140438571353856   DEBUG:   Channel Layout: FL,FR,FC,BL,BR,LFE

51:09 T:140438571353856   DEBUG:   Frames        : 9600

51:09 T:140438571353856   DEBUG:   Frame Samples : 57600

51:09 T:140438571353856   DEBUG:   Frame Size    : 24

51:09 T:140438508410624   DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted

51:09 T:140438473975552   DEBUG: CDVDPlayerAudio - CDVDMsg::GENERAL_DELAY(129000.000000)

51:09 T:140438526441216   DEBUG: CDVDPlayer::HandleMessages - player started 1

51:09 T:140437369120512  NOTICE: Thread Vdpau Output start, auto delete: false

51:09 T:140437369120512  NOTICE: COutput::OnStartup: Output Thread created

51:09 T:140437369120512  NOTICE: VDPAU::COutput::CreateGlxContext - created context

51:09 T:140437369120512  NOTICE: VDPAU::COutput: vdpau gl interop initialized

51:09 T:140437109077760  NOTICE: Thread Vdpau Mixer start, auto delete: false

51:09 T:140437109077760  NOTICE: CMixer::OnStartup: Output Thread created

51:09 T:140437109077760  NOTICE:  (VDPAU) Creating the video mixer

51:09 T:140437369120512  NOTICE: VDPAU::COutput::InitBufferPool - Output Surface created

51:09 T:140438488422144  NOTICE: Previous line repeats 3 times.

51:09 T:140438488422144   DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_RESYNC(41000.000000, 1)

51:09 T:140437369120512  NOTICE: VDPAU::COutput::InitBufferPool - Output Surface created

51:09 T:140438473975552   DEBUG: CDVDPlayerAudio - CDVDMsg::GENERAL_RESYNC(170000.000000, 1)

51:09 T:140438473975552   DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError1 - was:-48790.376210, should be:-48789.180210, error:1.196000

51:09 T:140437369120512  NOTICE: VDPAU::COutput::InitBufferPool - Output Surface created

51:09 T:140437369120512  NOTICE: Previous line repeats 1 times.

51:09 T:140437369120512  NOTICE: VDPAU::COutput registered output surfaces

51:09 T:140438488422144  NOTICE:  fps: 24.000000, pwidth: 1280, pheight: 720, dwidth: 1280, dheight: 720

51:09 T:140438488422144   DEBUG: OutputPicture - change configuration. 1280x720. framerate: 24.00. format: VDPAU

51:09 T:140438488422144  NOTICE: Display resolution DESKTOP : 1920x1080@ 60.00 - Full Screen (16)

51:09 T:140438488422144   DEBUG: CXBMCRenderManager::Configure - 3

51:09 T:140437369120512  NOTICE: VDPAU::COutput registered output surfaces

51:09 T:140438876489664  NOTICE: Previous line repeats 1 times.

51:09 T:140438876489664   DEBUG: Activating window ID: 12005

51:09 T:140438876489664   DEBUG: ------ Window Deinit (MyVideoNav.xml) ------

51:09 T:140438876489664   DEBUG: ------ Window Init (VideoFullScreen.xml) ------

51:09 T:140438876489664  NOTICE: Using GL_TEXTURE_2D

51:09 T:140438876489664  NOTICE: GL: Using VDPAU render method

51:09 T:140438876489664  NOTICE: GL: NPOT texture support detected

51:09 T:140438876489664  NOTICE: GL: Using GL_ARB_pixel_buffer_object

51:09 T:140438876489664 WARNING: CLinuxRendererGL::UpdateVideoFilter - choosen scaling method 4, is not supported by renderer

51:09 T:140438876489664   DEBUG: GL: Vertex Shader compilation log:

51:09 T:140438876489664   DEBUG: GL: Vertex Shader compiled successfully

51:09 T:140438876489664   DEBUG: GL: Pixel Shader compilation log:

51:09 T:140438876489664   DEBUG: GL: Fragment Shader compiled successfully

51:09 T:140438526441216   DEBUG: CDVDPlayer::HandleMessages - player started 2

51:09 T:140437369120512  NOTICE: VDPAU::COutput registered output surfaces

51:13 T:140438473975552  NOTICE: Previous line repeats 3 times.

51:13 T:140438473975552   DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:4066199.923790, should be:4051586.849328, error:-14613.074463

51:14 T:140438488422144   DEBUG: CPullupCorrection: detected pattern of length 1: 41666.67, frameduration: 41666.666667

51:16 T:140438141040384   DEBUG: Thread JobWorker 140438141040384 terminating (autodelete)

51:16 T:140437377513216   DEBUG: Thread JobWorker 140437377513216 terminating (autodelete)

51:16 T:140438157825792   DEBUG: Thread JobWorker 140438157825792 terminating (autodelete)

51:16 T:140437325612800   DEBUG: Thread JobWorker 140437325612800 terminating (autodelete)

51:17 T:140438473975552   DEBUG: CDVDPlayerAudio - CDVDMsg::GENERAL_EOF

51:17 T:140438473975552 WARNING: CDVDMessageQueue(audio)::Get - asked for new data packet, with nothing available

51:17 T:140438488422144 WARNING: CDVDMessageQueue(video)::Get - asked for new data packet, with nothing available

51:17 T:140438526441216  NOTICE: CDVDPlayer::OnExit()

51:17 T:140438526441216  NOTICE: DVDPlayer: eof, waiting for queues to empty

51:17 T:140438526441216  NOTICE: Closing stream player 1

51:17 T:140438526441216  NOTICE: CDVDMessageQueue(audio)::WaitUntilEmpty

51:17 T:140438473975552   DEBUG: CDVDPlayerAudio - CDVDMsg::GENERAL_SYNCHRONIZE

51:17 T:140438526441216  NOTICE: Waiting for audio thread to exit

51:17 T:140438473975552   DEBUG: CDVDPlayerAudio::Process - Abort received, exiting thread

51:17 T:140438473975552  NOTICE: thread end: CDVDPlayerAudio::OnExit()

51:17 T:140438473975552   DEBUG: Thread DVDPlayerAudio 140438473975552 terminating

51:17 T:140438526441216  NOTICE: Closing audio device

51:17 T:140438526441216  NOTICE: Deleting audio codec

51:17 T:140438508410624   DEBUG: CActiveAE::DiscardStream - audio stream deleted

51:17 T:140438526441216  NOTICE: Closing stream player 2

51:17 T:140438526441216  NOTICE: CDVDMessageQueue(video)::WaitUntilEmpty

51:17 T:140438508410624   DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted

51:17 T:140438488422144   DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_SYNCHRONIZE

51:17 T:140438488422144   ERROR: Got MSGQ_ABORT or MSGO_IS_ERROR return true

51:17 T:140438526441216  NOTICE: waiting for video thread to exit

51:17 T:140438488422144  NOTICE: thread end: video_thread

51:17 T:140438488422144   DEBUG: Thread DVDPlayerVideo 140438488422144 terminating

51:17 T:140438526441216  NOTICE: deleting video codec

51:17 T:140438526441216  NOTICE: CVDPAU::Release pre-cleanup

51:17 T:140437109077760  NOTICE: CMixer::OnExit: Output Thread terminated

51:17 T:140437109077760   DEBUG: Thread Vdpau Mixer 140437109077760 terminating

51:17 T:140437369120512   DEBUG: VDPAU::PreCleanup - released output surface

51:17 T:140438526441216   DEBUG: Previous line repeats 5 times.

51:17 T:140438526441216   DEBUG: OnPlayBackEnded : play state was 2, starting 0

51:17 T:140438526441216   DEBUG: CAnnouncementManager - Announcement: OnStop from xbmc

51:17 T:140438526441216   DEBUG: GOT ANNOUNCEMENT, type: 1, from xbmc, message OnStop

51:17 T:140438526441216   DEBUG: Thread DVDPlayer 140438526441216 terminating

51:17 T:140438876489664   DEBUG: CGUIWindowManager::PreviousWindow: Deactivate

51:17 T:140438876489664   DEBUG: ------ Window Deinit (VideoFullScreen.xml) ------

51:17 T:140438876489664   DEBUG: CGUIWindowManager::PreviousWindow: Activate new

51:17 T:140438876489664   DEBUG: ------ Window Init (MyVideoNav.xml) ------

51:17 T:140438876489664   DEBUG: CGUIMediaWindow::GetDirectory (/mnt/media/unsorted/)

51:17 T:140438876489664   DEBUG:   ParentPath = [/mnt/media/unsorted/]

51:17 T:140438876489664   DEBUG: RunQuery took 0 ms for 57 items query: SELECT  files.strFilename, files.playCount,  bookmark.timeInSeconds, bookmark.totalTimeInSeconds FROM files  LEFT JOIN bookmark ON    files.idFile = bookmark.idFile AND bookmark.type = 1  WHERE files.idPath=358

51:18 T:140438526441216  NOTICE: Thread BackgroundLoader start, auto delete: false

51:18 T:140437109077760  NOTICE: Thread JobWorker start, auto delete: true

51:18 T:140437109077760   DEBUG: DoWork - Saving file state for video item /mnt/media/unsorted/wmv-surroundtest_720p.wmv

51:18 T:140437109077760   DEBUG: DoWork - Marking video item /mnt/media/unsorted/wmv-surroundtest_720p.wmv as watched

51:18 T:140437109077760   DEBUG: Mysql execute: update files set playCount=4,lastPlayed='2014-08-20 09:51:18' where idFile=12275

**fritsch** · 2014-08-20, 10:08

Speaker-test is using Alsa while xbmc is using pulse. The file gives BR BL to the engine.

**fritsch** · 2014-08-20, 10:53

I cannot see more about your output devices, as you have cut the relevant part in the logfile ...

PulseAudio uses an annotated mapping. E.g. if SR is requested from the engine it returns: https://github.com/xbmc/xbmc/blob/e5de23...E.cpp#L272

and so on. This is all saved in a channel map that the pulse audio server will read again: https://github.com/xbmc/xbmc/blob/e5de23...E.cpp#L319

Post a complete Debug Log please - so that I can see the device enumeration correctly.

**fritsch** · 2014-08-20, 11:06

What about this sample: https://dl.dropboxusercontent.com/u/5572...20Test.avi <- post a complete Debug Log with that one please.

**fritsch** · 2014-08-20, 11:09

Also make a screenshot of pavucontrol while playing that sample - It should name the different speakers correctly

Mirar · 2014-08-20, 11:35

Sorry about that, I didn't see that part before. This is the startup part of the debug log (I did a restart while downloading) that should match above:

Code:
31:54 T:140729638733760  NOTICE: special://profile/ is mapped to: special://masterprofile/

31:54 T:140729638733760  NOTICE: -----------------------------------------------------------------------

31:54 T:140729638733760  NOTICE: Starting XBMC (14.0-ALPHA1 Git:a891415). Platform: Linux x86 64-bit

31:54 T:140729638733760  NOTICE: Using Release XBMC x64 build

31:54 T:140729638733760  NOTICE: XBMC compiled Jul 17 2014 by GCC 4.8.1 for Linux x86 64-bit version 3.11.10 (199434)

31:54 T:140729638733760  NOTICE: Running on Ubuntu 13.10, kernel: Linux x86 64-bit version 3.11.0-12-generic

31:54 T:140729638733760  NOTICE: FFmpeg statically linked, version: 2.2.4-xbmc-2.2-Helix-alpha2

31:54 T:140729638733760  NOTICE: Host CPU: Intel(R) Core(TM) i7-2600K CPU @ 3.40GHz, 8 cores available

31:54 T:140729638733760  NOTICE: special://xbmc/ is mapped to: /usr/share/xbmc

31:54 T:140729638733760  NOTICE: special://xbmcbin/ is mapped to: /usr/lib/xbmc

31:54 T:140729638733760  NOTICE: special://masterprofile/ is mapped to: /home/xbmc/.xbmc/userdata

31:54 T:140729638733760  NOTICE: special://home/ is mapped to: /home/xbmc/.xbmc

31:54 T:140729638733760  NOTICE: special://temp/ is mapped to: /home/xbmc/.xbmc/temp

31:54 T:140729638733760  NOTICE: The executable running is: /usr/lib/xbmc/xbmc.bin

31:54 T:140729638733760  NOTICE: Local hostname: iris

31:54 T:140729638733760  NOTICE: Log File is located: /home/xbmc/.xbmc/temp/xbmc.log

31:54 T:140729638733760  NOTICE: -----------------------------------------------------------------------

31:54 T:140729638733760  NOTICE: load settings...

31:54 T:140729638733760  NOTICE: Found 1 Lists of Devices

31:54 T:140729638733760  NOTICE: Enumerated PULSE devices:

31:54 T:140729638733760  NOTICE:     Device 1

31:54 T:140729638733760  NOTICE:         m_deviceName      : Default

31:54 T:140729638733760  NOTICE:         m_displayName     : Default

31:54 T:140729638733760  NOTICE:         m_displayNameExtra: Default Output Device (PULSEAUDIO)

31:54 T:140729638733760  NOTICE:         m_deviceType      : AE_DEVTYPE_PCM

31:54 T:140729638733760  NOTICE:         m_channels        : FL,FR

31:54 T:140729638733760  NOTICE:         m_sampleRates     : 5512,8000,11025,16000,22050,32000,44100,48000,64000,88200,96000,176400,192000,384000

31:54 T:140729638733760  NOTICE:         m_dataFormats     : AE_FMT_U8,AE_FMT_S16NE,AE_FMT_S24NE3,AE_FMT_S24NE4,AE_FMT_S32NE,AE_FMT_FLOAT

31:54 T:140729638733760  NOTICE:     Device 2

31:54 T:140729638733760  NOTICE:         m_deviceName      : alsa_output.pci-0000_01_00.1.hdmi-surround

31:54 T:140729638733760  NOTICE:         m_displayName     : GF119 HDMI Audio Controller Digital Surround 5.1 (HDMI)

31:54 T:140729638733760  NOTICE:         m_displayNameExtra: HDMI / DisplayPort (PULSEAUDIO)

31:54 T:140729638733760  NOTICE:         m_deviceType      : AE_DEVTYPE_PCM

31:54 T:140729638733760  NOTICE:         m_channels        : FL,FR,BL,BR,FC,LFE

31:54 T:140729638733760  NOTICE:         m_sampleRates     : 5512,8000,11025,16000,22050,32000,44100,48000,64000,88200,96000,176400,192000,384000

31:54 T:140729638733760  NOTICE:         m_dataFormats     : AE_FMT_U8,AE_FMT_S16NE,AE_FMT_S24NE3,AE_FMT_S24NE4,AE_FMT_S32NE,AE_FMT_FLOAT

31:54 T:140729638733760  NOTICE: No settings file to load (special://xbmc/system/advancedsettings.xml)

31:54 T:140729638733760  NOTICE: Loaded settings file from special://profile/advancedsettings.xml

31:54 T:140729638733760  NOTICE: Contents of special://profile/advancedsettings.xml are...

                                            <advancedsettings>

                                              <videodatabase>

and backing to 13.1 and playing your sample (actually my original test file but I got tired of the ratatatat after the 50th round):

Code:
25:54 T:140413276940224  NOTICE: special://profile/ is mapped to: special://masterprofile/

25:54 T:140413276940224  NOTICE: -----------------------------------------------------------------------

25:54 T:140413276940224  NOTICE: Starting XBMC (13.1 Git:f2acae7). Platform: x86 Linux 64-bit

25:54 T:140413276940224  NOTICE: Using Release XBMC x64 build, compiled Jun  6 2014 by GCC 4.8.1 for x86 Linux 64-bit 3.11.10

25:54 T:140413276940224  NOTICE: Running on Linux 64-bit (Ubuntu 13.10, 3.11.0-12-generic x86_64)

25:54 T:140413276940224  NOTICE: Host CPU: Intel(R) Core(TM) i7-2600K CPU @ 3.40GHz, 8 cores available

25:54 T:140413276940224  NOTICE: special://xbmc/ is mapped to: /usr/share/xbmc

25:54 T:140413276940224  NOTICE: special://xbmcbin/ is mapped to: /usr/lib/xbmc

25:54 T:140413276940224  NOTICE: special://masterprofile/ is mapped to: /home/xbmc/.xbmc/userdata

25:54 T:140413276940224  NOTICE: special://home/ is mapped to: /home/xbmc/.xbmc

25:54 T:140413276940224  NOTICE: special://temp/ is mapped to: /home/xbmc/.xbmc/temp

25:54 T:140413276940224  NOTICE: The executable running is: /usr/lib/xbmc/xbmc.bin

25:54 T:140413276940224  NOTICE: Local hostname: iris

25:54 T:140413276940224  NOTICE: Log File is located: /home/xbmc/.xbmc/temp/xbmc.log

25:54 T:140413276940224  NOTICE: -----------------------------------------------------------------------

25:54 T:140413276940224  NOTICE: load settings...

25:54 T:140413276940224  NOTICE: Found 1 Lists of Devices

25:54 T:140413276940224  NOTICE: Enumerated PULSE devices:

25:54 T:140413276940224  NOTICE:     Device 1

25:54 T:140413276940224  NOTICE:         m_deviceName      : Default

25:54 T:140413276940224  NOTICE:         m_displayName     : Default

25:54 T:140413276940224  NOTICE:         m_displayNameExtra: Default Output Device (PULSEAUDIO)

25:54 T:140413276940224  NOTICE:         m_deviceType      : AE_DEVTYPE_PCM

25:54 T:140413276940224  NOTICE:         m_channels        : FL,FR

25:54 T:140413276940224  NOTICE:         m_sampleRates     : 5512,8000,11025,16000,22050,32000,44100,48000,64000,88200,96000,176400,192000,384000

25:54 T:140413276940224  NOTICE:         m_dataFormats     : AE_FMT_U8,AE_FMT_S16LE,AE_FMT_S16BE,AE_FMT_S16NE,AE_FMT_S24LE3,AE_FMT_S24BE3,AE_FMT_S24NE3,AE_FMT_S24LE4,AE_FMT_S24BE4,AE_FMT_S24NE4,AE_FMT_S32BE,AE_FMT_S32LE,AE_FMT_S32NE,AE_FMT_FLOAT

25:54 T:140413276940224  NOTICE:     Device 2

25:54 T:140413276940224  NOTICE:         m_deviceName      : alsa_output.pci-0000_01_00.1.hdmi-surround

25:54 T:140413276940224  NOTICE:         m_displayName     : GF119 HDMI Audio Controller Digital Surround 5.1 (HDMI)

25:54 T:140413276940224  NOTICE:         m_displayNameExtra: HDMI / DisplayPort (PULSEAUDIO)

25:54 T:140413276940224  NOTICE:         m_deviceType      : AE_DEVTYPE_PCM

25:54 T:140413276940224  NOTICE:         m_channels        : FL,FR,BL,BR,FC,LFE

25:54 T:140413276940224  NOTICE:         m_sampleRates     : 5512,8000,11025,16000,22050,32000,44100,48000,64000,88200,96000,176400,192000,384000

25:54 T:140413276940224  NOTICE:         m_dataFormats     : AE_FMT_U8,AE_FMT_S16LE,AE_FMT_S16BE,AE_FMT_S16NE,AE_FMT_S24LE3,AE_FMT_S24BE3,AE_FMT_S24NE3,AE_FMT_S24LE4,AE_FMT_S24BE4,AE_FMT_S24NE4,AE_FMT_S32BE,AE_FMT_S32LE,AE_FMT_S32NE,AE_FMT_FLOAT

25:54 T:140413276940224  NOTICE: No settings file to load (special://xbmc/system/advancedsettings.xml)

[...]

25:54 T:140412971804416   DEBUG: CAnnouncementManager - Announcement: OnVolumeChanged from xbmc

25:54 T:140412971804416   DEBUG: CActiveAESink::OpenSink - PULSE Initialized:

25:54 T:140412971804416   DEBUG:   Output Device : Default

25:54 T:140412971804416   DEBUG:   Sample Rate   : 192000

25:54 T:140412971804416   DEBUG:   Sample Format : AE_FMT_FLOAT

25:54 T:140412971804416   DEBUG:   Channel Count : 6

25:54 T:140412971804416   DEBUG:   Channel Layout: FL,FR,FC,BL,BR,LFE

25:54 T:140412971804416   DEBUG:   Frames        : 9600

25:54 T:140412971804416   DEBUG:   Frame Samples : 57600

25:54 T:140412971804416   DEBUG:   Frame Size    : 24

25:54 T:140413276940224  NOTICE: Running database version Addons16

25:54 T:140413276940224   DEBUG: SECTION:LoadDLL(special://xbmcbin/system/libcpluff-x86_64-linux.so)

I wasn't allowed to post the entire log (too big for the message and I can't spot any way of attaching it), so it's here.

**fritsch** · 2014-08-20, 11:37

Please switch the device to: alsa_output.pci-0000_01_00.1.hdmi-surround - same issue?

Also please provide the pavucontrol screenshot when playing that sample.

Mirar · (This post was last modified: 2014-08-20, 11:42 by Mirar.)

Screenshots Playback and Output tabs.

Quote:Also please provide the pavucontrol screenshot when playing that sample.

I was still working on it, you're too fast Wink

**fritsch** · (This post was last modified: 2014-08-20, 11:45 by fritsch.)

Yeah that's what I have expected. pavucontrol shows perfectly fine what xbmc is doing. The routing from PA to your output device seems to go wrong.
Btw: DTS, AC3 won't work in passthrough mode if pulse is set to 6 channels, see also the wiki.

**fritsch** · 2014-08-20, 11:47

Do you have something special in your default.pa? E.g. disabling of remapping?

Mirar · 2014-08-20, 11:59

(2014-08-20, 11:37)fritsch Wrote: Please switch the device to: alsa_output.pci-0000_01_00.1.hdmi-surround - same issue?
Also please provide the pavucontrol screenshot when playing that sample.

From the device switch forward (continuing the log from before):
xbmc.debug2.log

screenshot

debug log from restart to play

**fritsch** · (This post was last modified: 2014-08-20, 12:00 by fritsch.)

Here, this is a dump patch to fixate the channel layout, when doing 5.1 surround: http://paste.ubuntu.com/8096622/

Please provide the older information I asked for, too. Normally. Pulse should get the mask, e.g. the channel names correctly and map them to whatever it has to map. This is what you see in pavucontrol all the channels are named correctly. So something is put out wrongly, e.g. mapping disabled perhaps?

**fritsch** · 2014-08-20, 12:07

Also post your /etc/pulse/default.pa please