[mythtv-users] Strange Audio Problem 0.25

jr jraymyth at gmail.com
Wed Jun 13 00:01:54 UTC 2012


On Tue, Jun 12, 2012 at 4:23 PM, Jean-Yves Avenard <jyavenard at gmail.com> wrote:
> On 13 June 2012 03:40, jr <jraymyth at gmail.com> wrote:
>
>> So I went to make a recording and played it.  The video was clear, but
>> no audio was emitted.  The recording does have sound when played
>> through VLC.  I figure that its a config problem, but of what?  ALSA
>> is clearly working with the HDMI port.  MythTV is communicating with
>> ALSA, in the setup at the least.  I don't mind digging in...but where
>> do I dig?
>
> mythfrontend -v audio,playback
>
> start playback of the file giving you an issue, post the output of the console
> _______________________________________________
> mythtv-users mailing list
> mythtv-users at mythtv.org
> http://www.mythtv.org/mailman/listinfo/mythtv-users

****From start of play to end of play***

2012-06-12 19:58:10.846712 I  TV: Creating TV object
2012-06-12 19:58:10.850216 I  TV: Finished creating TV object
2012-06-12 19:58:10.850225 I  TV: StartTV() -- begin
2012-06-12 19:58:10.850289 N  Resuming idle timer
2012-06-12 19:58:10.850308 N  Suspending idle timer
2012-06-12 19:58:10.850315 I  TV: Init -- begin
2012-06-12 19:58:10.851858 I  TV: Created TvPlayWindow.
2012-06-12 19:58:10.851924 I  TV: DrawUnusedRects() -- begin
2012-06-12 19:58:10.851932 I  TV: DrawUnusedRects() -- end
2012-06-12 19:58:10.853835 I  TV: Init -- end
2012-06-12 19:58:10.854256 I  TV: tv->Playback() -- begin
2012-06-12 19:58:10.856518 I  TV: HandleStateChange(0) -- begin
2012-06-12 19:58:10.856531 I  TV: Attempting to change from None to
WatchingPreRecorded
2012-06-12 19:58:10.856831 I
FileRingBuf(/var/lib/mythtv/recordings/1081_20120612111100.mpg):
OpenFile(/var/lib/mythtv/recordings/1081_20120612111100.mpg, 2000 ms)
2012-06-12 19:58:10.857012 I  TV: StartPlayer(0, WatchingPreRecorded,
main) -- begin
2012-06-12 19:58:10.857024 I  TV: Elapsed time since TV constructor
was called: 11 ms
2012-06-12 19:58:10.931924 I  Pulse: PulseAudio not running
2012-06-12 19:58:10.933170 I  ALSA: OpenDevice hdmi:CARD=NVidia,DEV=1
2012-06-12 19:58:10.941666 I  AOS: Sample rate 32000 is supported
2012-06-12 19:58:10.941681 I  AOS: Sample rate 44100 is supported
2012-06-12 19:58:10.941689 I  AOS: Sample rate 48000 is supported
2012-06-12 19:58:10.941697 I  AOS: Format signed 16 bit is supported
2012-06-12 19:58:10.941703 I  AOS: Format signed 24 bit MSB is supported
2012-06-12 19:58:10.941708 I  AOS: Format signed 32 bit is supported
2012-06-12 19:58:10.941716 I  AOS: 2 channel(s) are supported
2012-06-12 19:58:10.941836 I  ALSA: Successfully retrieved ELD data
2012-06-12 19:58:10.941849 I  ELDUTILS: Detected monitor VW246 at
connection type HDMI
2012-06-12 19:58:10.941856 I  ELDUTILS: available speakers: FL/FR
2012-06-12 19:58:10.941862 I  ELDUTILS: max LPCM channels = 2
2012-06-12 19:58:10.941867 I  ELDUTILS: max channels = 2
2012-06-12 19:58:10.941872 I  ELDUTILS: supported codecs = LPCM
2012-06-12 19:58:10.941892 I  ELDUTILS: supports coding type LPCM:
channels = 2, rates = 32000 44100 48000, bits = 16 20 24
2012-06-12 19:58:10.968411 I  AOS: may be AC3 or DTS capable
2012-06-12 19:58:10.968422 I  AOS: 6 channel(s) are supported
2012-06-12 19:58:10.968445 N  AudioPlayer: Enabling Audio
2012-06-12 19:58:10.969275 I  AFD: Buffer size: 32768, streamed 0
2012-06-12 19:58:10.989637 I  AFD: Stream #0, has id 0x245 codec id
MPEG2VIDEO, type Video, bitrate 15498400 at 0x53a5c40
2012-06-12 19:58:10.990629 I  VDP: Accepting: cmp(> 0 0) dec(vdpau)
cpus(1) skiploop(disabled) rend(vdpau) osd(vdpau) osdfade(enabled)
deint(vdpauadvanceddoublerate,vdpauadvanced) filt()
2012-06-12 19:58:10.990645 I  VDP: LoadBestPreferences(2048x2048, 0)
2012-06-12 19:58:10.990667 I  VDP: LoadBestPreferences(2048x2048, 60)
2012-06-12 19:58:10.990682 I  VDP: LoadBestPreferences(1280x720, 60)
2012-06-12 19:58:10.990707 I  AFD: Using 1 CPUs for decoding
2012-06-12 19:58:10.990716 I  AFD: InitVideoCodec() 0x5011920
id(MPEG2VIDEO) type (Video).
2012-06-12 19:58:10.990752 I  AFD: Selected FPS is 59.9401 (avg 59.96
codec 59.9401 container 90000 estimated 59.9401)
2012-06-12 19:58:10.990764 I  Player(1): SetFrameInterval ps:1 scan:3
2012-06-12 19:58:10.990783 I  Player(1): detectInterlace(Detect Scan,
Interlaced Scan, 59.9401, 720) ->Progressive Scan
2012-06-12 19:58:10.990805 I  AFD: Using vdpau for video decoding
2012-06-12 19:58:10.990811 I  AFD: Looking for decoder for MPEG2VIDEO
2012-06-12 19:58:10.990832 I  AFD: Opened codec 0x5011920,
id(MPEG2VIDEO) type(Video)
2012-06-12 19:58:10.990845 I  AFD: Stream #1, has id 0x246 codec id
AC3, type Audio, bitrate 448000 at 0x1bdf120
2012-06-12 19:58:10.990853 I  AFD: codec AC3 has 2 channels
2012-06-12 19:58:10.990858 I  AFD: Looking for decoder for AC3
2012-06-12 19:58:10.991222 I  AFD: Opened codec 0x1b83460, id(AC3) type(Audio)
2012-06-12 19:58:10.991249 I  AFD: Audio Track #1, with type 0 is A/V
stream #1 and has 2 channels in the English language(6647399).
2012-06-12 19:58:10.991261 I  AFD: Stream #2, has id 0x247 codec id
AC3, type Audio, bitrate 192000 at 0x53a6130
2012-06-12 19:58:10.991268 I  AFD: codec AC3 has 2 channels
2012-06-12 19:58:10.991272 I  AFD: Looking for decoder for AC3
2012-06-12 19:58:10.991610 I  AFD: Opened codec 0x466b7d0, id(AC3) type(Audio)
2012-06-12 19:58:10.991631 I  AFD: Audio Track #2, with type 0 is A/V
stream #2 and has 2 channels in the Spanish; Castilian
language(7565409).
2012-06-12 19:58:10.991643 I  AFD: Trying to select default track
2012-06-12 19:58:10.991648 I  AFD: Trying to select audio track (w/lang)
2012-06-12 19:58:10.991668 I  AFD: Selected track 1: English AC3 2ch
(A/V Stream #1)
2012-06-12 19:58:10.991677 I  AFD: Initializing audio parms from audio track #1
2012-06-12 19:58:10.991698 I  AFD: Audio format changed
			from id(NONE)     -1Hz -1ch -1bps     (profile 0) to id( AC3)
48000Hz  2ch 16bps  pt (profile 0)
2012-06-12 19:58:10.991712 I  AO: Setting AC3 passthrough
2012-06-12 19:58:10.992518 I  SPDIFEncoder: Creating spdif encoder (for AC3)
2012-06-12 19:58:10.992524 I  AO: Killing AudioOutputDSP
2012-06-12 19:58:10.992535 I  AO: Original codec was AC3, signed 16
bit, 48 kHz, 2 channels
2012-06-12 19:58:10.992551 I  AO: enc(0), passthru(1), features
(AC3,DTS) configured_channels(2), 2 channels supported(1)
max_channels(2)
2012-06-12 19:58:10.992564 I  AO: Opening audio device
'hdmi:CARD=NVidia,DEV=1' ch 2(2) sr 48000 sf signed 16 bit reenc 0
2012-06-12 19:58:10.992573 I  ALSA: OpenDevice
hdmi:CARD=NVidia,DEV=1,AES0=6,AES1=0x82,AES2=0x00,AES3=0x01 for
passthrough
2012-06-12 19:58:11.001427 I  ALSA: SetParameters(format=2,
channels=2, rate=48000, buffer_time=500000, period_time=4)
2012-06-12 19:58:11.001473 I  ALSA: Buffer size range from 64 to 16384
2012-06-12 19:58:11.001480 I  ALSA: Period size range from 32 to 8192
2012-06-12 19:58:11.001496 I  ALSA: Requested 500000us got 341333 buffer time
2012-06-12 19:58:11.001596 I  ALSA: Hardware audio buffer cur: 64
need: 128 max allowed: 32768
2012-06-12 19:58:11.001618 E  ALSA: Setting hardware audio buffer size to 128
2012-06-12 19:58:11.009507 E  ALSA: Error opening
/proc/asound/card1/pcm7p/sub0/prealloc: Permission denied.
2012-06-12 19:58:11.009521 E  ALSA: Try to manually increase audio
buffer with: echo 128 | sudo tee
/proc/asound/card1/pcm7p/sub0/prealloc
2012-06-12 19:58:11.009535 E  ALSA: Unable to sufficiently increase
ALSA hardware buffer size - underruns are likely
2012-06-12 19:58:11.009543 I  ALSA: OpenDevice
hdmi:CARD=NVidia,DEV=1,AES0=6,AES1=0x82,AES2=0x00,AES3=0x01 for
passthrough
2012-06-12 19:58:11.017697 I  ALSA: SetParameters(format=2,
channels=2, rate=48000, buffer_time=500000, period_time=4)
2012-06-12 19:58:11.017742 I  ALSA: Buffer size range from 64 to 16384
2012-06-12 19:58:11.017749 I  ALSA: Period size range from 32 to 8192
2012-06-12 19:58:11.017762 I  ALSA: Buffer time = 341333 us
2012-06-12 19:58:11.017773 I  ALSA: Period time = 4 periods
2012-06-12 19:58:11.113425 I  ALSA: Buffer size = 16384 | Period size = 4096
2012-06-12 19:58:11.209466 I  AO: Audio fragment size: 8192
2012-06-12 19:58:11.209488 I  AO: Audio Stretch Factor: 1
2012-06-12 19:58:11.209539 I  AO: Ending Reconfigure()
2012-06-12 19:58:11.209560 I  Dec: Selected track #1 in the Unknown language(0)
2012-06-12 19:58:11.209573 I  Dec: Resyncing position map.
posmapStarted = 0 livetv(0) watchingRec(0)
2012-06-12 19:58:11.209668 I  AO: kickoffOutputAudioLoop: pid = 7589
2012-06-12 19:58:11.209690 I  AO: OutputAudioLoop: Play Event
2012-06-12 19:58:11.210307 I  Dec: Position map filled from DB to: 2352
2012-06-12 19:58:11.210325 I  Dec: SyncPositionMap prerecorded, from
DB: 99 entries
2012-06-12 19:58:11.210334 I  Dec: SyncPositionMap, new totframes:
2352, new length: 39, posMap size: 99
2012-06-12 19:58:11.452268 I  AFD: Position map found
2012-06-12 19:58:11.452286 I  AFD: Successfully opened decoder for
file: "/var/lib/mythtv/recordings/1081_20120612111100.mpg". novideo(0)
2012-06-12 19:58:11.455305 I  VideoOutput: Allowed renderers: vdpau
2012-06-12 19:58:11.455323 I  VideoOutput: Allowed renderers (filt:
vdpau): vdpau
2012-06-12 19:58:11.456082 I  VDP: Accepting: cmp(> 0 0) dec(vdpau)
cpus(1) skiploop(disabled) rend(vdpau) osd(vdpau) osdfade(enabled)
deint(vdpauadvanceddoublerate,vdpauadvanced) filt()
2012-06-12 19:58:11.456097 I  VDP: LoadBestPreferences(2048x2048, 0)
2012-06-12 19:58:11.456119 I  VDP: LoadBestPreferences(2048x2048, 60)
2012-06-12 19:58:11.456134 I  VDP: LoadBestPreferences(1280x720, 60)
2012-06-12 19:58:11.456148 I  VideoOutput: Preferred renderer: vdpau
2012-06-12 19:58:11.456158 I  VideoOutput: Trying video renderer: 'vdpau'
2012-06-12 19:58:11.457750 I  VDP: Accepting: cmp(> 0 0) dec(vdpau)
cpus(1) skiploop(disabled) rend(vdpau) osd(vdpau) osdfade(enabled)
deint(vdpauadvanceddoublerate,vdpauadvanced) filt()
2012-06-12 19:58:11.457764 I  VDP: LoadBestPreferences(2048x2048, 0)
2012-06-12 19:58:11.457783 I  VDP: LoadBestPreferences(2048x2048, 60)
2012-06-12 19:58:11.457808 I  VideoOutWindow::SetPIPState. pip_state: 0]
2012-06-12 19:58:11.457818 I  VDP: LoadBestPreferences(2048x2048, 59.9401)
2012-06-12 19:58:11.457830 I  Clearing OpenGL painter cache.
2012-06-12 19:58:11.465814 I  Display Rect  left: 0, top: 0, width:
1920, height: 1080, aspect: 1.33333
2012-06-12 19:58:11.465832 I  Video Rect    left: 0, top: 0, width:
1280, height: 720, aspect: 1.33333
2012-06-12 19:58:11.465843 I  VDP: LoadBestPreferences(1280x720, 59.9401)
2012-06-12 19:58:11.465869 I  Display Rect  left: 0, top: 0, width:
1920, height: 1080, aspect: 1.33333
2012-06-12 19:58:11.465880 I  Video Rect    left: 0, top: 0, width:
1280, height: 720, aspect: 1.33333
2012-06-12 19:58:11.465886 I  VDP: SetVideoRenderer(vdpau)
2012-06-12 19:58:11.465895 I  VDP: SetVideoRender(vdpau) == GetVideoRenderer()
2012-06-12 19:58:11.466492 I  VideoOutput: Pixel dimensions: Screen
1920x1080, window 1920x1080
2012-06-12 19:58:11.466507 I  VideoOutput: Actual display dimensions:
530x301 mm  Aspect: 1.7608
2012-06-12 19:58:11.466517 I  VideoOutput: Estimated window
dimensions: 530x301 mm  Aspect: 1.7608
2012-06-12 19:58:11.513756 I  VDPAU: Created 2 output surfaces.
2012-06-12 19:58:11.513788 I  VDPAU: Set colorkey to 0x20202
2012-06-12 19:58:11.513798 I  VDPAU: Created VDPAU render device 1920x1080
2012-06-12 19:58:11.513811 I  VidOutVDPAU: Created VDPAU osd (1920x1080)
2012-06-12 19:58:11.528376 I  ColourSpace: PictureAttributes:
Brightness, Contrast, Colour, Hue, Studio Levels,
2012-06-12 19:58:11.528401 I  Display Rect  left: 240, top: 0, width:
1440, height: 1080, aspect: 1.77778
2012-06-12 19:58:11.528410 I  Video Rect    left: 0, top: 0, width:
1280, height: 720, aspect: 1.33333
2012-06-12 19:58:11.528414 I  VidOutVDPAU: Created VDPAU context (GPU decode)
2012-06-12 19:58:11.528431 I  Over/underscan. V: 0, H: 0
2012-06-12 19:58:11.528440 I  Display Rect  left: 240, top: 0, width:
1440, height: 1080, aspect: 1.77778
2012-06-12 19:58:11.528447 I  Video Rect    left: 0, top: 0, width:
1280, height: 720, aspect: 1.33333
2012-06-12 19:58:11.528455 N  Player(1): Forcing decode extra audio
option on (Video method requires it).
2012-06-12 19:58:11.528464 I  Player(1): LoadFilters(''..) -> 0x0
2012-06-12 19:58:11.529488 I  Player(1): Decoder thread starting.
2012-06-12 19:58:11.533116 I  OSD: Loaded window osd_message
2012-06-12 19:58:11.536427 I  OSD: Loaded window osd_input
2012-06-12 19:58:11.544386 I  OSD: Loaded window program_info
2012-06-12 19:58:11.548394 I  OSD: Loaded window browse_info
2012-06-12 19:58:11.552160 I  OSD: Loaded window osd_status
2012-06-12 19:58:11.555726 I  OSD: Loaded window osd_program_editor
2012-06-12 19:58:11.560749 I  OSD: Loaded window osd_debug
2012-06-12 19:58:11.560760 I  OSD: Loaded OSD: size 1920x1080 offset 0+0
2012-06-12 19:58:11.560792 I  OSD: Created window aa_OSD_SUBTITLES
2012-06-12 19:58:11.560810 I  Player(1): ClearAfterSeek(0)
2012-06-12 19:58:11.561532 I  VDP: GetFilteredDeint() : vdpau ->
'vdpauadvanceddoublerate'
2012-06-12 19:58:11.561779 I  AO: OutputAudioLoop: Play Event
2012-06-12 19:58:11.561927 I  VidOutVDPAU: Enabled deinterlacing.
2012-06-12 19:58:11.561948 I  VSYNC: DRMVideoSync: Could not open
device /dev/dri/card0, No such file or directory
2012-06-12 19:58:11.561962 E  VSYNC: RTCVideoSync: Could not open /dev/rtc:
			eno: Permission denied (13)
2012-06-12 19:58:11.561968 E  Player(1): Video sync method can't
support double framerate (refresh rate too low for 2x deint)
2012-06-12 19:58:11.562287 I  VDP: GetFilteredDeint(vdpauadvanced) :
vdpau -> 'vdpauadvanced'
2012-06-12 19:58:11.562572 I  VidOutVDPAU: Enabled deinterlacing.
2012-06-12 19:58:11.562991 I  Player(1): Video timing method: USleep
with busy wait
2012-06-12 19:58:11.563003 I  Player(1): Display Refresh Rate: 59.999
Video Frame Rate: 59.941
2012-06-12 19:58:11.563008 I  Player(1): SetFrameInterval ps:1 scan:1
2012-06-12 19:58:11.563295 I  playCtx: StartPlaying(): took 0 ms to
start player.
2012-06-12 19:58:11.563315 I  TV: Created player.
2012-06-12 19:58:11.563332 I  TV: StartPlayer(0, WatchingPreRecorded,
main) -- end ok
2012-06-12 19:58:11.565782 I  TV: Changing from None to WatchingPreRecorded
2012-06-12 19:58:11.568586 I  TV: DrawUnusedRects() -- begin
2012-06-12 19:58:11.568595 I  TV: DrawUnusedRects() -- end
2012-06-12 19:58:11.568677 I  TV: Main UI disabled.
2012-06-12 19:58:11.568685 I  TV: HandleStateChange(0) -- end
2012-06-12 19:58:11.568689 I  TV: tv->Playback() -- end
2012-06-12 19:58:11.568693 I  TV: Entering main playback loop.
2012-06-12 19:58:11.571708 I  Player(1): Waiting for video buffers...
2012-06-12 19:58:11.571736 I  VidOutVDPAU: Created VDPAU decoder (2 ref frames)
2012-06-12 19:58:11.574525 I  Player(1): Video Aspect ratio changed
from 1.33333 to 1.77778
2012-06-12 19:58:11.574543 I  Display Rect  left: 0, top: 0, width:
1920, height: 1080, aspect: 1.77778
2012-06-12 19:58:11.574551 I  Video Rect    left: 0, top: 0, width:
1280, height: 720, aspect: 1.77778
2012-06-12 19:58:11.574559 I  Player(1): progressive frame seen after
2 interlaced frames
2012-06-12 19:58:11.576636 I  VDPAU: Added 2 output surfaces (total 4, max 4)
2012-06-12 19:58:11.588963 I  AFD: EIA-708 caption service #1 is in
the Undetermined language.
2012-06-12 19:58:11.588978 I  Dec: Selected track #1 in the
Undetermined language(7695972)
2012-06-12 19:58:11.632076 I  Player(1): Disabled deinterlacing
2012-06-12 19:58:11.862474 I  AFD: EIA-708 caption service #1 is in
the Undetermined language.
2012-06-12 19:58:11.862489 I  AFD: EIA-608 caption service #1 is in
the Undetermined language.
2012-06-12 19:58:11.878541 I  Dec: Selected track #1 in the
Undetermined language(7695972)
2012-06-12 19:58:13.046085 I  TV: SetActive(0,w/o OSD) 0 -> 0 -- begin
2012-06-12 19:58:13.046112 I  TV: SetActive(0,w/o OSD) 0 -> 0 -- end
2012-06-12 19:58:13.063657 I  TV: HandleStateChange(0) -- begin
2012-06-12 19:58:13.063673 I  TV: Attempting to change from
WatchingPreRecorded to None
2012-06-12 19:58:13.063688 I  TV: StopStuff() for player ctx 0 -- begin
2012-06-12 19:58:13.063698 I  TV: SetActive(0,w/o OSD) 0 -> 0 -- begin
2012-06-12 19:58:13.063712 I  TV: SetActive(0,w/o OSD) 0 -> 0 -- end
2012-06-12 19:58:13.063720 I  Player(1): StopPlaying - begin
2012-06-12 19:58:13.075193 I  Player(1): Decoder thread exiting.
2012-06-12 19:58:13.075295 I  Player(1): Exited decoder loop.
2012-06-12 19:58:13.075992 I  VidOutVDPAU: DiscardFrames(1)
2012-06-12 19:58:13.076029 I  VideoBuffers::DiscardFrames(1): AUUUUUUUUUUuuL
2012-06-12 19:58:13.076054 I  VideoBuffers::DiscardFrames(1):
AAAAAAAAAAAAAA -- done
2012-06-12 19:58:13.076070 I  VidOutVDPAU: DiscardFrames() 3:
AAAAAAAAAAAAAA -- done()
2012-06-12 19:58:13.077283 I  VDPAU Painter: Clearing VDPAU painter cache.
2012-06-12 19:58:13.116862 I  AO: Killing AudioOutputDSP
2012-06-12 19:58:13.122869 I  AO: OutputAudioLoop: Stop Event
2012-06-12 19:58:13.122889 I  AO: kickoffOutputAudioLoop exiting
2012-06-12 19:58:13.132409 I  Player(1): StopPlaying - end
2012-06-12 19:58:13.132422 I  TV: StopStuff(): stopping ring buffer
2012-06-12 19:58:13.132448 I  TV: StopStuff(): stopping player
2012-06-12 19:58:13.132460 I  TV: StopStuff() -- end
2012-06-12 19:58:13.132474 I  TV: Changing from WatchingPreRecorded to None
2012-06-12 19:58:13.132487 I  TV: HandleStateChange(0) -- end
2012-06-12 19:58:13.132500 I  TV: Exiting main playback loop.
2012-06-12 19:58:13.132507 I  TV: StartTV -- process events 2 begin
2012-06-12 19:58:13.132773 I  TV: StartTV -- process events 2 end
2012-06-12 19:58:13.132788 I  TV::~TV() -- begin
2012-06-12 19:58:13.143397 I  TV::~TV() -- lock
2012-06-12 19:58:13.143496 I  Player(1): StopPlaying - begin
2012-06-12 19:58:13.143512 I  Player(1): Exited decoder loop.
2012-06-12 19:58:13.143520 I  Player(1): StopPlaying - end
2012-06-12 19:58:13.145942 I  TV::~TV() -- end
2012-06-12 19:58:13.146486 N  Suspending idle timer
2012-06-12 19:58:13.146494 I  TV: StartTV -- end


More information about the mythtv-users mailing list