Not logged in. · Lost password · Register
Forum: Bugs RSS
Player stalls after a few seconds of playing
Praetorian #1
Member since Oct 2007 · 2 posts
Group memberships: Members
Show profile · Link to this post
Subject: Player stalls after a few seconds of playing
I have tried using the player on two systems, and the one system stops playing the movie after a few seconds.  The movie is HD and is recorded at 15mbit.  I have the mythtv server and two clients plugged into the same gigabit switch and all are running at gigabit.  One of the clients (a desktop machine with p4 3.6 and 2gigs ram) play the movie no problem. The other client is a dell E1705 with centrino 1.6 duo and 1g ram and x1400 video.  The dell is the one with the problem.  I moved one of the mpegs to the machine via file xfer and it plays fine with another player.  So the laptop should be able to play it across the net connection.  Any ideas? thanks.
Girkers #2
Member since Sep 2007 · 29 posts · Location: Brisbane, Queensland, Australia
Group memberships: Members
Show profile · Link to this post
Have at look in your directory where the software is located and there is a file there called log.txt This should give you a good indication of what is going. Post the relevant section in here to let the programmer help you out.
Praetorian #3
Member since Oct 2007 · 2 posts
Group memberships: Members
Show profile · Link to this post
Subject: Log File info
09:07:44 Main: MythTv Player v. 0.4.1, compiled: Aug  6 2007
09:07:44 Config: Config file parsed in 63ms
09:07:44 Main: Starting GUI thread
09:07:44 Main: Starting SDL loop and waiting for it to init
09:07:44 SDL_Loop: Initing SDL with YUV_HWACCEL=1
09:07:44 SDL_Loop: SDL Inited
09:07:44 Main: Initing decoder
09:07:44 Demuxer: Registering all formats
09:07:44 Main: Starting controller
09:07:44 MPControl: State change: Connecting -> Connecting
09:07:44 MPControl: Connecting to MythBackend
09:07:44 MPControl: Connecting to Backend
09:07:44 MythServer: Connected to server with protocol version 31
09:07:44 MythServer: Connected to server with protocol version 31
09:07:44 MPControl: Sending GUI events
09:07:44 MPControl: Initing videorender
09:07:44 VideoRender: Fonts
09:07:44 MythBackendEventListener: Started
09:07:44 VideoRender: System resolution is 1024x768
09:07:44 VideoRender: Releaseing existing overlay
09:07:44 VideoRender: Setting mode: 512x288 in 0 bpp. Position 29,-5
09:07:44 VideoRender: Clearing screen
09:07:44 VideoRender: Creating YUV-overlay 704x576
09:07:44 VideoRender: Overlay is in hardware
09:07:45 MPControl: videoRender start
09:07:45 MPControl: State change: Connecting -> Stopped
09:07:45 MPControl: New state: Stopped
09:07:45 VideoRender: Run
09:07:45 MPControl: Starting event loop
09:07:45 MPControl: Command: RequestProgramListUpdate
09:07:45 MPControl: Getting programlist
09:07:45 MythServer: Buffer is to small. Expanding it from 1000 to 5577
09:07:45 ProgramList: Constructor
09:07:45 ProgramList: Parsing programInfo.
09:07:45 ProgramList: 9 recordings detected.
09:07:45 MPControl: Getting MythBackend Status
09:07:45 MythLive: DiskSpace. Total: 637.97 GB, Used: 71.82 GB, Free: 566.15 GB
09:07:45 MythLive: Recorders: 1, Free: 0
09:07:45 MythLive: Load: 0.10,0.17,0.09
09:07:45 MythLive: Uptime: 34 days, 3:36
09:07:45 MythLive: Memory: 2022 (140 free). Virtual Memory: 1983 (1983 free)
09:07:49 MPControl: Command: Open
09:07:49 MPControl: Stopping decoding
09:07:49 MPControl: State change: Stopped -> Stopped
09:07:49 MPControl: State change: Stopped -> Opening
09:07:49 MPControl: New state: Opening
09:07:49 MPControl: Opening file 'myth://127.0.0.1:6543/1091_20071024210000.mpg'
09:07:49 MPControl: Recording found at host 172.16.0.210, port 6543
09:07:49 MythLive: Querying Bookmark
09:07:49 MythLive: Querying Commercial breaks
09:07:49 MythCommercialMarks: Parsing 12 commercial marks
09:07:49 MythCommercialMarks: Start mark: 0 = 0s
09:07:49 MythCommercialMarks: End   mark: 121 = 4s
09:07:49 MythCommercialMarks: Start mark: 12067 = 482s
09:07:49 MythCommercialMarks: End   mark: 17561 = 702s
09:07:49 MythCommercialMarks: Start mark: 33376 = 1335s
09:07:49 MythCommercialMarks: End   mark: 39867 = 1594s
09:07:49 MythCommercialMarks: Start mark: 51903 = 2076s
09:07:49 MythCommercialMarks: End   mark: 57606 = 2304s
09:07:49 MythCommercialMarks: Start mark: 80379 = 3215s
09:07:49 MythCommercialMarks: End   mark: 89089 = 3563s
09:07:49 MythCommercialMarks: Start mark: 103416 = 4136s
09:07:49 MythCommercialMarks: End   mark: 107733 = 4309s
09:07:50 MPControl: Opening stream: 'myth://127.0.0.1:6543/1091_20071024210000.mpg'
09:07:50 ThreadedStreamBuffer: Opening Stream
09:07:50 ThreadedStreamBuffer: Starting thread
09:07:50 MPControl: Waiting for streambuffer to open
09:07:50 ThreadedStreamBuffer: Thread started
09:07:50 MythServer: Connected to server with protocol version 31
09:07:50 MythServer: Connected to server with protocol version 31
09:07:50 MythStream: File opened. nr: 35, size 7239559084
09:07:50 ThreadedStreamBuffer: Stream opened
09:07:50 MPControl: Stream openened succecully
09:07:51 ThreadedStreamBuffer: Seeking from end -1. Returning filesize 7239559083
09:07:51 ThreadedStreamBuffer: Seeking is a 'tell'. Simply returning position: 4292608
09:07:51 Demuxer: Demuxer is 'MPEG2 transport stream format'(mpegts)
09:07:51 Demuxer: Duration: 3597007ms, 0:59:57
09:07:51 Demuxer: Start time: 30499656ms, 8:28:19
09:07:51 Demuxer: Filesize: 6.74 GB
09:07:51 Demuxer: Bitrate: 15 Mbit/s
09:07:51 Demuxer: Preparing codecs
09:07:51 Demuxer: Stream [0], Type='Video', Codec='MPEG2VIDEO'(id=2)
09:07:51 Demuxer: Stream [1], Type='Audio', Codec='AC3'(id=86020)
09:07:51 VideoDecoder: Codec is 'MPEG2VIDEO'(id: 2) at 1920x1080
09:07:51 VideoDecoder: Codec opened
09:07:51 VideoRender: Allocating pictures
09:07:51 VideoRender: Releaseing existing overlay
09:07:51 VideoRender: Setting mode: 960x540 in 0 bpp. Position 29,-5
09:07:52 VideoRender: Clearing screen
09:07:52 VideoRender: Creating YUV-overlay 1920x1080
09:07:52 VideoRender: Overlay is in hardware
09:07:52 AudioDecoder: Codec is 'AC3' (id: 86020)
09:07:52 AudioDecoder: Codec opened, freq: 48000
09:07:52 AudioDecoder:         Channels: 6
09:07:52 AudioDecoder:         Bits/sample: 0
09:07:52 AudioDecoder: Only playing the first 2 channels!
09:07:52 AudioRender: SDL_Audio already initialized
09:07:52 AudioRender: Initializing Audio
09:07:52 AudioRender: chan: 2, freq: 48000
09:07:52 AudioRender: buffer is 4096 bytes, or 85 ms
09:07:52 AudioRender: Opening SDL audio device
09:07:52 AudioRender: chan: 2, freq: 48000
09:07:52 AudioRender: buffer is 4096 bytes, or 85 ms
09:07:52 Demuxer: Audio. Start time: 2744969ms, 0:45:44
09:07:52 Demuxer: Audio. Num: 1, Den: 90000
09:07:52 Demuxer: Video. Start time: 2745012ms, 0:45:45
09:07:52 Demuxer: Video. Num: 1, Den: 90000
09:07:52 Demuxer: Video: FrameRate: 30000/1001
09:07:52 Demuxer: Packet. Stream[1] pts: -308385411111, dts: -308385411111, frame: 0, start_time: 30499656044
09:07:52 Demuxer: Done finding time 1
09:07:52 MPControl: Starting decoding
09:07:52 AudioDecoder: Start
09:07:52 VideoDecoder: start
09:07:52 VideoDecoder: Pause
09:07:52 VideoRender: Pause
09:07:52 VideoDecoder: Pause detected
09:07:52 VideoRender: paused
09:07:52 AudioRender: Pause
09:07:52 Demuxer: Seeking to 0:01:21 (frame 2454), currrent time is 0:00:00
09:07:52 ThreadedStreamBuffer: Seeking from end -1. Returning filesize 7239559083
09:07:52 ThreadedStreamBuffer: Seeking is a 'tell'. Simply returning position: 98304
09:07:53 Demuxer: av_seek_frame completed
09:07:53 MPControl: State change: Opening -> PreBuffering
09:07:53 MPControl: Changing to stateBuffering
09:07:53 AudioRender: Pause
09:07:53 VideoRender: Pause
09:07:53 VideoDecoder: Pause stopped
09:07:53 Demuxer: Packet. Stream[0] pts: -30499656055, dts: 81856066, frame: 0, start_time: 2744969045
09:07:53 MPControl: Changing to stateBuffering: Done
09:07:53 MPControl: New state: PreBuffering
09:07:53 MythLive: Setting Bookmark
09:07:53 AudioDecoder: Large difference in current pts and new pts recieved from packet: -81920 ms.
09:07:53 MPControl: State change: PreBuffering -> Playing
09:07:53 MPControl: Changing to statePlaying
09:07:53 VideoDecoder: Resume
09:07:53 VideoRender: Resume
09:07:53 VideoRender: de-paused
09:07:53 AudioRender: Resume
09:07:53 AudioRender: Resume
09:07:53 VideoDecoder: Resume
09:07:53 VideoRender: Resume
09:07:53 MPControl: Changing to statePlaying: Done
09:07:53 MPControl: New state: Playing
09:07:59 AudioDecoder: Not enough audio in buffer :(. Setting beenInTrouble flag.
09:07:59 MPControl: State change: Playing -> ReBuffering
09:07:59 MPControl: Changing to stateBuffering
09:07:59 AudioRender: Pause
09:07:59 VideoRender: Pause
09:07:59 VideoRender: paused
09:07:59 MPControl: Changing to stateBuffering: Done
09:07:59 MPControl: New state: ReBuffering


After that it just sits there with the frame frozen.

Thanks for any ideas or testing that I can do to help fix this.
gdbaldw #4
Member since Jan 2008 · 2 posts
Group memberships: Members
Show profile · Link to this post
I have the exact same issue while playing any recording from SA4200HD STB. - 100MB LAN, MythTV 0.20.2, Debian.  Any solutions found?

<snip from my log file>
12:25:56 Demuxer: Demuxer is 'MPEG2 transport stream format'(mpegts)
12:25:56 Demuxer: Duration: 0ms, Unknown
12:25:56 Demuxer: Start time: 6801913ms, 1:53:21
12:25:56 Demuxer: Filesize: 150 MB
12:25:56 Demuxer: Bitrate: 0.00 Kbit/s
12:25:56 Demuxer: Preparing codecs
12:25:56 Demuxer: Stream [0], Type='Video', Codec='MPEG2VIDEO'(id=2)
12:25:56 Demuxer: Stream [1], Type='Audio', Codec='AC3'(id=86020)
12:25:56 Demuxer: Video stream 0
12:25:56 Demuxer: Audio stream 1
...
12:25:56 AudioRender: chan: 2, freq: 48000
12:25:56 AudioRender: buffer is 4096 bytes, or 85 ms
12:25:56 Demuxer: Audio. Start time: 612172ms, 0:10:12
12:25:56 Demuxer: Audio. Num: 1, Den: 90000
12:25:56 Demuxer: Video. Start time: 612211ms, 0:10:12
12:25:56 Demuxer: Video. Num: 1, Den: 90000
12:25:56 Demuxer: Video: FrameRate: 30000/1001
12:25:56 Demuxer: Reading Packet
12:25:56 ThreadedStreamBuffer: Read 32768
12:25:56 ThreadedStreamBuffer: Reading from ringBuffer
12:25:56 ThreadedStreamBuffer: Read done 32768
12:25:56 Demuxer: Packet. Stream[1] pts: -68773113633, dts: -68773113633, frame: 0, start_time: 6801913744
12:25:56 Demuxer: Done finding time 1
12:25:56 MPControl: Starting decoding
12:25:56 MPControl: State change: Opening -> PreBuffering
12:25:56 MPControl: Changing to stateBuffering
12:25:56 MythSocket: Receiving 5 bytes
12:25:56 MythStream: Receiving binary data, 32768
12:25:56 MythStream: read(), done. Returned 32768
12:25:56 ThreadedStreamBuffer: stream->read, 32768
12:25:56 ThreadedStreamBuffer: ringbuffer->write
12:25:56 ThreadedStreamBuffer: ringbuffer->written
12:25:56 ThreadedStreamBuffer: stream->read
12:25:56 MythStream: Read() 32768 bytes
12:25:56 MythStream: Requesting Block
12:25:56 MythSocket: Sending command
12:25:56 MythSocket: Sending command with 3
12:25:56 MythSocket: cmd: '49      QUERY_FILETRANSFER 27[]:[]REQUEST_BLOCK[]:[]32768'
12:25:56 MythSocket: Returned from send 57
12:25:56 MythSocket: Receiving answer
12:25:56 AudioDecoder: Start
12:25:56 AudioDecoder: Frame
12:25:56 AudioDecoder: Frame end
12:25:56 AudioDecoder: Waiting for event
12:25:56 VideoDecoder: start
12:25:56 Demuxer: Frame
12:25:56 AudioDecoder: Waiting for event, End
12:25:56 VideoDecoder: Frame
12:25:56 AudioRender: Pause
12:25:56 Demuxer: Audio Packet
12:25:56 AudioDecoder: Frame end
12:25:56 VideoDecoder: Frame end
12:25:56 VideoRender: Pause
12:25:56 AudioDecoder: Frame
12:25:56 AudioDecoder: Frame end
12:25:56 MPControl: Changing to stateBuffering: Done
12:25:56 AudioDecoder: Waiting for event
12:25:56 VideoRender: Waiting for event, done
12:25:56 MPControl: New state: PreBuffering
12:25:56 VideoRender: paused
12:25:56 AudioDecoder: Waiting for event, End
12:25:56 AudioDecoder: Frame end
12:25:56 AudioDecoder: Frame
12:25:56 AudioDecoder: Frame end
12:25:56 AudioDecoder: Frame
12:25:56 AudioDecoder: Frame end
12:25:56 AudioDecoder: Waiting for event
12:25:56 Demuxer: Frame end
12:25:56 Demuxer: Frame
12:25:56 Demuxer: Reading Packet
12:25:56 Demuxer: Packet. Stream[1] pts: 31988, dts: 31988, frame: 1, start_time: 612333518
12:25:56 Demuxer: Audio Packet
12:25:56 AudioDecoder: Waiting for event, End
12:25:56 AudioDecoder: Frame end
12:25:56 AudioDecoder: Frame
12:25:56 AudioDecoder: Frame end
12:25:56 AudioDecoder: Frame
12:25:56 AudioDecoder: Frame end
12:25:56 AudioDecoder: Waiting for event
12:25:56 Demuxer: Frame end
12:25:56 Demuxer: Frame
12:25:56 Demuxer: Reading Packet
12:25:56 Demuxer: Packet. Stream[1] pts: 63988, dts: 63988, frame: 2, start_time: 612333518
12:25:56 Demuxer: Audio Packet
12:25:56 AudioDecoder: Waiting for event, End
12:25:56 AudioDecoder: Frame end
12:25:56 AudioDecoder: Frame
12:25:56 AudioDecoder: Frame end
12:25:56 AudioDecoder: Frame
12:25:56 AudioDecoder: Frame end
12:25:56 AudioDecoder: Waiting for event
12:25:56 Demuxer: Frame end
12:25:56 Demuxer: Frame
12:25:56 Demuxer: Reading Packet
12:25:56 Demuxer: Packet. Stream[0] pts: -1352300, dts: -1469088, frame: 0, start_time: 612333518
12:25:56 Demuxer: Video Packet
12:25:56 MPControl: Event Handled
12:25:56 MPControl: New event
12:25:56 MPControl: Command: Timer
12:25:56 Demuxer: GetPlayerStatus
12:25:56 Demuxer: GetPlayerStatus, Done
12:25:56 ThreadedStreamBuffer: Size 158158196. Pos: 32768
12:25:56 MythSocket: Receiving 5 bytes
12:25:56 VideoDecoder: Frame end
12:25:56 Demuxer: Frame end
12:25:56 VideoDecoder: Frame
12:25:56 MythStream: Receiving binary data, 32768
12:25:56 Demuxer: Frame
12:25:56 VideoDecoder: avcodec_decode
12:25:56 MythStream: read(), done. Returned 32768
12:25:56 MPControl: handle timer, end
12:25:56 Demuxer: Reading Packet
12:25:56 MPControl: Event Handled
12:25:56 ThreadedStreamBuffer: stream->read, 32768
12:25:56 Demuxer: Packet. Stream[1] pts: 95988, dts: 95988, frame: 3, start_time: 612333518
12:25:56 ThreadedStreamBuffer: ringbuffer->write
12:25:56 Demuxer: Audio Packet
12:25:56 ThreadedStreamBuffer: ringbuffer->written
12:25:56 ThreadedStreamBuffer: stream->read
12:25:56 Demuxer: Frame end
12:25:56 AudioDecoder: Waiting for event, End
12:25:56 MythStream: Read() 32768 bytes
12:25:56 Demuxer: Frame
12:25:56 AudioDecoder: Frame end
12:25:56 MythStream: Requesting Block
12:25:56 Demuxer: Reading Packet
12:25:56 AudioDecoder: Frame
12:25:56 MythSocket: Sending command
12:25:56 Demuxer: Packet. Stream[0] pts: -1435722, dts: -1435722, frame: 0, start_time: 612333518
12:25:56 MythSocket: Sending command with 3
12:25:56 Demuxer: Video Packet
12:25:56 MythSocket: cmd: '49      QUERY_FILETRANSFER 27[]:[]REQUEST_BLOCK[]:[]32768'
12:25:56 Demuxer: Frame end
12:25:56 AudioDecoder: Frame end
12:25:56 MythSocket: Returned from send 57
12:25:56 Demuxer: Frame
12:25:56 AudioDecoder: Frame
12:25:56 MythSocket: Receiving answer
12:25:56 Demuxer: Reading Packet
12:25:56 AudioDecoder: Frame end
12:25:56 AudioDecoder: Waiting for event
12:25:56 Demuxer: Packet. Stream[0] pts: -1402355, dts: -1402355, frame: 0, start_time: 612333518
12:25:56 Demuxer: Video Packet
12:25:56 Demuxer: Frame end
12:25:56 Demuxer: Frame
12:25:56 Demuxer: Reading Packet
12:25:56 Demuxer: Packet. Stream[1] pts: -1792011, dts: -1792011, frame: 0, start_time: 612333518
12:25:56 Demuxer: Audio Packet
12:25:56 Demuxer: Frame end
12:25:56 AudioDecoder: Waiting for event, End
12:25:56 Demuxer: Frame
12:25:56 AudioDecoder: Frame end
12:25:56 Demuxer: Reading Packet
12:25:56 AudioDecoder: Frame
12:25:56 ThreadedStreamBuffer: Read 32768
12:25:56 ThreadedStreamBuffer: Reading from ringBuffer
12:25:56 ThreadedStreamBuffer: Read done 32768
12:25:56 Demuxer: Packet. Stream[0] pts: -1252200, dts: -1352300, frame: 0, start_time: 612333518
12:25:56 Demuxer: Video Packet
12:25:56 Demuxer: Frame end
12:25:56 AudioDecoder: Large difference in current pts and new pts recieved from packet: 1919 ms.
...
12:26:21 MPControl: New event
12:26:21 MPControl: Command: Timer
12:26:21 Demuxer: GetPlayerStatus
12:26:21 Demuxer: GetPlayerStatus, Done
12:26:21 ThreadedStreamBuffer: Size 158158196. Pos: 158158196
12:26:21 MPControl: State change: ReBuffering -> Playing
12:26:21 MPControl: Changing to statePlaying
12:26:21 VideoDecoder: Resume
12:26:21 Demuxer: Waiting for event, Done
12:26:21 VideoRender: Resume
12:26:21 VideoDecoder: Frame end
12:26:21 VideoDecoder: Frame
12:26:21 VideoRender: de-paused
12:26:21 Demuxer: Frame end
12:26:21 AudioRender: Resume
12:26:21 AudioDecoder: Waiting for event, End
12:26:21 VideoDecoder: Frame end
12:26:21 VideoRender: Still waiting for first frame
12:26:21 AudioRender: Resume
12:26:21 AudioDecoder: Frame end
...
12:26:21 MythSocket: cmd: '49      QUERY_FILETRANSFER 27[]:[]REQUEST_BLOCK[]:[]32768'
12:26:21 MythSocket: Returned from send 57
12:26:21 MythSocket: Receiving answer
12:26:21 AudioDecoder: Stopped
12:26:21 Demuxer: Closing ffmpeg file
12:26:21 ThreadedStreamBuffer: Stream close, requested
12:26:21 ThreadedStreamBuffer: Destructing
12:26:21 MythSocket: Receiving 1 bytes
12:26:21 MythStream: 0 bytes, received
12:26:21 ThreadedStreamBuffer: stream->read, 0
12:26:21 ThreadedStreamBuffer: Closing stream
12:26:21 MythSocket: Sending command with 2
12:26:21 MythSocket: cmd: '30      QUERY_FILETRANSFER 27[]:[]DONE'
12:26:21 MythSocket: Returned from send 38
12:26:21 MythStream: MythStream: closed at 158158196, length 158158196
12:26:21 MythSocket: Disconnected
12:26:21 MythSocket: Disconnected
12:26:21 ThreadedStreamBuffer: Destructing blockBuffer
12:26:21 ThreadedStreamBuffer: Deleting stream
12:26:21 Demuxer: Stopped
12:26:21 MPControl: State change: Playing -> Stopped
12:26:21 MPControl: New state: Stopped
12:26:21 MPControl: handle timer, end
12:26:21 MPControl: Event Handled
12:26:21 MPControl: New event
12:26:21 MPControl: Command: Timer
12:26:21 MPControl: handle timer, end
12:26:21 MPControl: Event Handled
12:26:21 MPControl: New event
12:26:21 MPControl: Command: Timer
gdbaldw #5
Member since Jan 2008 · 2 posts
Group memberships: Members
Show profile · Link to this post
I really want this to work for me, and am attempting to isolate the issue.

Using 100Mbps ethernet; files stream without errors (but with commercials) using VLC.  I've implemented Samba, turned off streamBuffer, and tested both live and recorded video.  In each case, the log files show that the audio buffer is not full.  An example level 4 log file is attached below:

02:33:53 MPControl: State change: Stopped -> Stopped
02:33:53 MPControl: State change: Stopped -> Opening
02:33:53 MPControl: New state: Opening
02:33:53 MPControl: Opening file '/var/lib/mythtv//3013_20080122143338.mpg'
02:33:53 MPControl: Recording is a liveTv recording.
02:33:53 MPControl: Recording found at host '192.168.0.109:6543'
02:33:53 MPControl: Opening stream: '//btcserver/mythtv/3013_20080122143338.mpg'
02:33:53 ThreadedStreamBuffer: Opening Stream
02:33:53 ThreadedStreamBuffer: Requesting thread to start
02:33:53 MPControl: Waiting for streambuffer to open
02:33:53 ThreadedStreamBuffer: Thread started
02:33:53 ThreadedStreamBuffer: Stream opened
02:33:53 MPControl: Stream openened succecully
02:33:53 Demuxer: Demuxer is 'MPEG2 transport stream format'(mpegts)
02:33:53 Demuxer: Duration: 3095ms, 0:00:03
02:33:53 Demuxer: Start time: 94756778ms, 2:19:16
02:33:53 Demuxer: Filesize: 1 MB
02:33:53 Demuxer: Bitrate: 3.1 Mbit/s
02:33:53 Demuxer: Preparing codecs
02:33:53 Demuxer: Stream [0], Type='Video', Codec='MPEG2VIDEO'(id=2)
02:33:53 Demuxer: Stream [1], Type='Audio', Codec='AC3'(id=86020)
02:33:53 VideoDecoder: Codec is 'MPEG2VIDEO'(id: 2) at 704x480
02:33:53 VideoDecoder: Codec opened
02:33:53 VideoRender: Allocating pictures
02:33:53 VideoRender: Releasing existing overlay
02:33:53 VideoRender: Setting mode: 426x240 in 0 bpp. Position 365,327
02:33:54 VideoRender: Clearing screen
02:33:54 VideoRender: Creating YUV-overlay 704x480
02:33:54 VideoRender: Overlay is in hardware: 1
02:33:54 VideoRender: setMode() done
02:33:54 AudioDecoder: Codec is 'AC3' (id: 86020)
02:33:54 AudioDecoder: Codec opened, freq: 48000
02:33:54 AudioDecoder:         Channels: 1
02:33:54 AudioDecoder:         Bits/sample: 0
02:33:54 AudioRender: Initializing Audio
02:33:54 AudioRender: chan: 1, freq: 48000
02:33:54 AudioRender: buffer is 4096 bytes, or 85 ms
02:33:54 AudioRender: Opening SDL audio device
02:33:54 AudioRender: chan: 1, freq: 48000
02:33:54 AudioRender: buffer is 4096 bytes, or 85 ms
02:33:54 Demuxer: Audio. Start time: 8528110ms, 2:22:08
02:33:54 Demuxer: Audio. Num: 1, Den: 90000
02:33:54 Demuxer: Video. Start time: 8528163ms, 2:22:08
02:33:54 Demuxer: Video. Num: 1, Den: 90000
02:33:54 Demuxer: Video: FrameRate: 30000/1001
02:33:54 Demuxer: Packet. Stream[1] pts: -958094394366, dts: -958094394366, frame: 0, start_time: 94756778344
02:33:54 Demuxer: Done finding time 1
02:33:54 MPControl: Starting decoding
02:33:54 MPControl: State change: Opening -> PreBuffering
02:33:54 MPControl: Changing to stateBuffering
02:33:54 AudioDecoder: Start
02:33:54 VideoDecoder: start
02:33:54 AudioRender: Pause
02:33:54 AudioDecoder: Large difference in current pts and new pts recieved from packet: 947 ms.
02:33:54 VideoRender: Pause
02:33:54 MPControl: Changing to stateBuffering: Done
02:33:54 MPControl: New state: PreBuffering
02:33:54 AudioDecoder: Large difference in current pts and new pts recieved from packet: 1983 ms.
02:33:54 MPControl: State change: PreBuffering -> Playing
02:33:54 MPControl: Changing to statePlaying
02:33:54 VideoDecoder: Resume
02:33:54 VideoRender: Resume
02:33:54 VideoRender: de-paused
02:33:54 AudioRender: Resume
02:33:54 AudioRender: Resume
02:33:54 VideoDecoder: Resume
02:33:54 VideoRender: Resume
02:33:54 MPControl: Changing to statePlaying: Done
02:33:54 MPControl: New state: Playing
02:33:57 AudioDecoder: Not enough audio in buffer :(. Setting beenInTrouble flag.
02:33:57 MPControl: Audiodecoder was in trouble. As stream is eof we stop demuxer.
02:33:57 MPControl: End of stream detected
02:33:57 MPControl: You are watching livetv. Checking if there is a program in the programchain
02:33:57 MPControl: No program found. stopping stream
02:33:57 GUI: Current Recorder 0
02:33:57 Demuxer: Stopping thread
02:33:57 Demuxer: Stopping
02:33:57 Demuxer: Flushing
02:33:57 Demuxer: Stopping videoDecoder
02:33:57 VideoDecoder: Stopping thread
02:33:57 VideoRender: Pause
02:33:57 VideoDecoder: Stopped
02:33:57 VideoDecoder: Flushing
02:33:57 VideoRender: paused
02:33:57 VideoDecoder: Closing codec
02:33:57 Demuxer: Stopping audioDecoder
02:33:57 AudioDecoder: Stopping
02:33:57 AudioDecoder: Closing codec
02:33:57 AudioRender: Pausing audio
02:33:57 AudioRender: Closing audio
02:33:57 AudioDecoder: Stopped
02:33:57 Demuxer: Closing ffmpeg file
02:33:57 Demuxer: Stopped
02:33:57 MPControl: State change: Playing -> Stopped
02:33:57 MPControl: New state: Stopped
02:33:57 MPControl: Command: RequestRecorderList
02:33:57 MPControl: Updating status of recorders
02:33:57 MPControl: Getting MythBackend Status
02:33:57 MythLive: DiskSpace. Total: 331.96 GB, Used: 227.82 GB, Free: 104.13 GB
02:33:57 MythLive: Recorders: 1, Free: 1
02:33:57 MythLive: Load: 0.19,0.07,0.14
02:33:57 MythLive: Uptime: -27800 days, -2 hours, 0 mins, and -3 seconds
02:33:57 MythLive: Memory: 4019 (433 free). Virtual Memory: 255 (255 free)
Avatar
Kuroneko #6
Member since Jan 2007 · 40 posts · Location: Pittsburgh, PA, USA
Group memberships: Members
Show profile · Link to this post
I'm not sure why I didn't notice this before, but have you tried the newest versions?

http://www.sudu.dk/mythtvplayer/forum/thread/83

or

http://www.sudu.dk/mythtvplayer/files/0.6/MythTvPlayer0.5.…

?
rcstanley #7
Member since Oct 2008 · 1 post
Group memberships: Members
Show profile · Link to this post
Subject: I think HD is the key
I think I have the same problem too.  I only have the problem with HD recordings, just digital programs do not have this problem.  (I see the problem in the latest experimental build too.  Also, livetv has the same problem, Hd channels freeze after a second or two.)  I am running it on an eee 900ha.

Here's my baseless suspicion, with the HD recordings, the buffer gets used up too fast, and it never recovers (hence the "rebuffering").
Lomion (Moderator) #8
Member since Jan 2009 · 40 posts · Location: Vienna, Austria
Group memberships: Global Moderators, Members
Show profile · Link to this post
Bug solved:
Problem occured when no AudioPacket has been rendered before the VideoQueue was filled up (VideoRender was waiting for m_currentTimeDiff but Demuxer did not sync AudioDecoder with VideoRender)


Index: Demuxer.cpp
===================================================================
--- Demuxer.cpp (revision 201)
+++ Demuxer.cpp (working copy)
@@ -595,6 +595,9 @@
        PlayerStatus ps;
        LOG_DEBUG4("GetPlayerStatus");

+           //Bug-fix: http://www.sudu.dk/mythtvplayer/forum/thread/97
+    //Use this trigger to avoid a deadlock when no AudioPacket has been rendered before the VideoQueue was filled up (VideoRender was waiting for m_currentTimeDiff but Demuxer did not sync AudioDecoder with VideoRender)
+       vd->setTimestampDiff(ad->getTimestampDiff());
+
        memset(&ps,0,sizeof(ps));
     ps.length=getLength();
        ps.currentPosition=getCurrentPosition();
Lomion (Moderator) #9
Member since Jan 2009 · 40 posts · Location: Vienna, Austria
Group memberships: Global Moderators, Members
Show profile · Link to this post
Verify it with this build: http://www.freedrive.com/file/900243
jtumblin #10
Member since Dec 2009 · 1 post
Group memberships: Members
Show profile · Link to this post
Subject: Freezing and prebuffering
Every 8 Seconds I enter a prebuffering freeze and then a restart and a freeze here is my log



02:07:21 Main: MythTv Player v. 0.7.0 - Revision 236, compiled: Oct 29 2009
02:07:21 Config: Config file parsed in 5ms
02:07:21 Main: Locale is: English_United States.1252
02:07:21 Main: Starting GUI thread
02:07:21 Main: Starting SDL loop and waiting for it to init
02:07:21 SDL_Loop: Initing SDL with YUV_HWACCEL=1
02:07:21 SDL_Loop: SDL Inited
02:07:21 Main: Initing decoder
02:07:21 Demuxer: Registering all formats
02:07:21 Main: Starting controller
02:07:21 MPControl: State change: Connecting -> Connecting
02:07:21 MPControl: Connecting to MythBackend
02:07:21 MythSocket: Connected to server with protocol version 50
02:07:21 MythSocket: Connected to server with protocol version 50
02:07:21 MPControl: Sending Initial GUI events
02:07:21 MPControl: State change: Connecting -> Initializing
02:07:21 MPControl: New state: Initializing
02:07:21 MythLive: Detected 1 recorder(s)
02:07:21 MythLive: Querying list of pending recordings
02:07:21 MythLive: Has conflicts: 0
02:07:21 ProgramList: Parsing programInfo - 35 recordings detected.
02:07:21 ProgramList: Expected stride 46, while it is actually 47. Using the real stride
02:07:21 MythScheduler: Next recording on recorder 0 is 'October Sky' in -1 hours, -7 mins, and -21 seconds  with status '-4'
02:07:21 MythLive: Querying recording schedules
02:07:21 ProgramList: Parsing programInfo - 20 recordings detected.
02:07:21 ProgramList: Expected stride 46, while it is actually 47. Using the real stride
02:07:21 MythBackendEventListener: Starting listen loop
02:07:21 MPControl: Enabling LiveTv
02:07:21 MythLive: Probing recorder information.
02:07:21 MythLive: Detected recorder 1
02:07:21 MythLive: Building list of channels
02:07:21 MythRecorder: Building list of channels for recorder 1
02:07:21 MythRecorder:  - Added channel 'RAI' (1058)
02:07:21 MythRecorder:  - Added channel 'BRAVO' (1057)
02:07:21 MythRecorder:  - Added channel 'SPIKETV' (1055)
02:07:21 MythRecorder:  - Added channel 'BET' (1054)
02:07:22 MythRecorder:  - Added channel 'CSNNE' (1052)
02:07:22 MythRecorder:  - Added channel 'NESN' (1051)
02:07:22 MythRecorder:  - Added channel 'ESPN2' (1050)
02:07:22 MythRecorder:  - Added channel 'ESPN' (1049)
02:07:22 MythRecorder:  - Added channel 'VERSUS' (1048)
02:07:22 MythRecorder:  - Added channel 'TWC' (1047)
02:07:22 MythRecorder:  - Added channel 'CNBC' (1046)
02:07:22 MythRecorder:  - Added channel 'CNN' (1045)
02:07:22 MythRecorder:  - Added channel 'CSPAN' (1044)
02:07:22 MythRecorder:  - Added channel 'HLN' (1043)
02:07:22 MythRecorder:  - Added channel 'FNC' (1041)
02:07:22 MythRecorder:  - Added channel 'FOOD' (1040)
02:07:22 MythRecorder:  - Added channel 'DSC' (1039)
02:07:22 MythRecorder:  - Added channel 'TLC' (1038)
02:07:22 MythRecorder:  - Added channel 'AETV' (1037)
02:07:22 MythRecorder:  - Added channel 'LIFE' (1036)
02:07:22 MythRecorder:  - Added channel 'USA' (1035)
02:07:23 MythRecorder:  - Added channel 'E' (1034)
02:07:23 MythRecorder:  - Added channel 'TNT' (1033)
02:07:23 MythRecorder:  - Added channel 'HGTV' (1032)
02:07:23 MythRecorder:  - Added channel 'TBS' (1031)
02:07:23 MythRecorder:  - Added channel 'FX' (1030)
02:07:23 MythRecorder:  - Added channel 'VH1' (1029)
02:07:23 MythRecorder:  - Added channel 'MTV' (1028)
02:07:23 MythRecorder:  - Added channel 'ABCF' (1026)
02:07:23 MythRecorder:  - Added channel 'NIK' (1025)
02:07:23 MythRecorder:  - Added channel 'DISN' (1024)
02:07:23 MythRecorder:  - Added channel 'WYDN' (1023)
02:07:23 MythRecorder:  - Added channel 'WUTF' (1021)
02:07:23 MythRecorder:  - Added channel 'WMFP' (1020)
02:07:23 MythRecorder:  - Added channel 'WNEU' (1019)
02:07:23 MythRecorder:  - Added channel 'WZMY' (1018)
02:07:23 MythRecorder:  - Added channel 'WUNI' (1017)
02:07:24 MythRecorder:  - Added channel 'GOAC016' (1016)
02:07:24 MythRecorder:  - Added channel 'EDAC015' (1015)
02:07:24 MythRecorder:  - Added channel 'WSBK' (1014)
02:07:24 MythRecorder:  - Added channel 'WFXT' (1013)
02:07:24 MythRecorder:  - Added channel 'WLVI' (1012)
02:07:24 MythRecorder:  - Added channel 'WENH' (1011)
02:07:24 MythRecorder:  - Added channel 'WGBX' (1010)
02:07:24 MythRecorder:  - Added channel 'WBPX' (1009)
02:07:24 MythRecorder:  - Added channel 'HSN' (1008)
02:07:24 MythRecorder:  - Added channel 'WHDH' (1007)
02:07:24 MythRecorder:  - Added channel 'NECN' (1006)
02:07:24 MythRecorder:  - Added channel 'WCVB' (1005)
02:07:24 MythRecorder:  - Added channel 'WBZ' (1004)
02:07:24 MythRecorder:  - Added channel 'WGBH' (1002)
02:07:24 MythRecorder:  - Added channel 'WWDP' (1095)
02:07:25 MythRecorder:  - Added channel 'QVC' (1071)
02:07:25 MythRecorder:  - Added channel 'GOLF' (1069)
02:07:25 MythRecorder:  - Added channel 'CSPAN2' (1068)
02:07:25 MythRecorder:  - Added channel 'LOOR067' (1096)
02:07:25 MythRecorder:  - Added channel 'HISTORY' (1066)
02:07:25 MythRecorder:  - Added channel 'TVLAND' (1064)
02:07:25 MythRecorder:  - Added channel 'APL' (1063)
02:07:25 MythRecorder:  - Added channel 'SYFY' (1062)
02:07:25 MythRecorder:  - Added channel 'COMEDY' (1061)
02:07:25 MythRecorder:  - Added channel 'TOON' (1060)
02:07:25 MythRecorder:  - Added channel 'AMC' (1059)
02:07:25 MythChannel: Finalizing list. Creating subchannels
02:07:25 MythLive: Merging channels with existing list of channels
02:07:25 MythLive: List of channels completed
02:07:25 MythLive: Querying list of pending recordings
02:07:25 MythLive: Has conflicts: 0
02:07:25 ProgramList: Parsing programInfo - 35 recordings detected.
02:07:25 ProgramList: Expected stride 46, while it is actually 47. Using the real stride
02:07:25 MythScheduler: Next recording on recorder 0 is 'October Sky' in -1 hours, -7 mins, and -25 seconds  with status '-4'
02:07:25 MythScheduler: Next recording on recorder 1 is 'City Goverment BOA or CC' in 4 hours, 52 mins, and 35 seconds  with status '-1'
02:07:25 MPControl: Updating status of recorders
02:07:25 MPControl: Initing videorender
02:07:25 VideoRender: System resolution is 1440x900
02:07:25 VideoRender: Releasing existing overlay
02:07:25 VideoRender: Setting mode: 512x288 in 0 bpp. Position 853,83
02:07:26 VideoRender: Clearing screen
02:07:26 VideoRender: Creating YUV-overlay 704x576
02:07:26 VideoRender: Overlay is in hardware: 1
02:07:26 VideoRender: setMode() done
02:07:26 MPControl: videoRender start
02:07:26 MPControl: State change: Initializing -> Stopped
02:07:26 VideoRender: Run
02:07:26 MPControl: New state: Stopped
02:07:26 MPControl: Starting event loop
02:07:26 MPControl: Command: RequestProgramListUpdate
02:07:26 MPControl: Getting programlist
02:07:26 ProgramList: Parsing programInfo - 6 recordings detected.
02:07:26 ProgramList: Expected stride 46, while it is actually 47. Using the real stride
02:07:26 MPControl: Getting MythBackend Status
02:07:26 MythLive: DiskSpace. Total: 2746.74 GB, Used: 1851.14 GB, Free: 895.60 GB
02:07:26 MythLive: Recorders: 1, Free: 1
02:07:26 MythLive: Load: 0.26,0.40,1.44
02:07:26 MythLive: Uptime: -3 days, -7 hours, -32 mins, and -21 seconds
02:07:26 MythLive: Memory: 1897 (105 free). Virtual Memory: 3807 (3806 free)
02:07:26 MPControl: Setting deinterlazing
02:07:26 MythLive: We might need to update guide data for channels. Checking all channels.
02:07:31 MPControl: Command: Open
02:07:31 MPControl: Stopping decoding
02:07:31 GUI: Current Recorder 0
02:07:31 MPControl: State change: Stopped -> Stopped
02:07:31 MPControl: Opening file '1059_20091207130000.mpg'
02:07:31 MPControl: Recording is an ordinary recording.
02:07:31 MPControl: Recording found at host '127.0.0.1:16543'
02:07:31 MythLive: Querying Bookmark
02:07:31 MPControl: State change: Stopped -> Opening
02:07:31 MPControl: New state: Opening
02:07:31 MPControl: Opening stream: '1059_20091207130000.mpg'
02:07:31 ThreadedStreamBuffer: Opening stream that does not change in size
02:07:31 MythStream: Opening stream that does not change in size
02:07:31 MythSocket: Connected to server with protocol version 50
02:07:31 MythSocket: Connected to server with protocol version 50
02:07:31 MythStream: File opened. nr: 31, size 2025934888
02:07:31 ThreadedStreamBuffer: Requesting thread to start
02:07:31 MPControl: Waiting for streambuffer to open
02:07:31 ThreadedStreamBuffer: Thread started
02:07:31 MPControl: Stream openened succecully
02:07:31 MPControl: Opening recording
02:07:41 ThreadedStreamBuffer: Seek Unknown: 0
02:07:41 ThreadedStreamBuffer: Unkown whence
02:07:41 ThreadedStreamBuffer: Returned -1
02:07:41 ThreadedStreamBuffer: Seek End: -1
02:07:41 ThreadedStreamBuffer: Waiting for last seek to finish
02:07:41 ThreadedStreamBuffer: Doing seek
02:07:41 ThreadedStreamBuffer: Returned 2025934887
02:07:41 ThreadedStreamBuffer: Seek Set: 2129920
02:07:41 ThreadedStreamBuffer: Waiting for last seek to finish
02:07:42 MythStream: Seek Set: 2025934887
02:07:42 MythStream: Returned 2025934887
02:07:42 ThreadedStreamBuffer: Doing seek
02:07:42 ThreadedStreamBuffer: Returned 2129920
02:07:42 MythStream: Bounding read to 1 bytes. Pos: 2025934887
02:07:42 ThreadedStreamBuffer: Seek Set: 0
02:07:42 ThreadedStreamBuffer: Waiting for last seek to finish
02:07:42 MythStream: Seek Set: 2129920
02:07:42 MythStream: Returned 2129920
02:07:42 ThreadedStreamBuffer: Doing seek
02:07:42 ThreadedStreamBuffer: Returned 0
02:07:42 ThreadedStreamBuffer: Seek Set: 2025684888
02:07:42 ThreadedStreamBuffer: Waiting for last seek to finish
02:07:42 MythStream: Seek Set: 0
02:07:42 MythStream: Returned 0
02:07:42 ThreadedStreamBuffer: Doing seek
02:07:42 ThreadedStreamBuffer: Returned 2025684888
02:07:42 MythStream: Seek Set: 2025684888
02:07:42 MythStream: Returned 2025684888
02:07:43 MythStream: Bounding read to 20624 bytes. Pos: 2025914264
02:07:43 Threaded
Close Smaller – Larger + Reply to this post:
Verification code: VeriCode Please note the verification code from the picture into the text field next to it.
Smileys: :-) ;-) :-D :-p :blush: :cool: :rolleyes: :huh: :-/ <_< :-( :'( :#: :scared: 8-( :nuts: :-O
Special characters:
Go to forum
This board is powered by the Unclassified NewsBoard software, 20100516-dev, © 2003-10 by Yves Goergen
Page created in 1.8 s (1.5 s) · 97 database queries in 1.2 s
Current time: 2010-09-08, 06:46:27 (UTC +01:00)