[LIVE] Intermittent hang while watching movies.
#1
Since the last time I rebuilt the system, I haven't had any issues I would consider major, until now. I'm using XBMC built on top of Ubuntu Server on an ECS H55H-I with an i3-550 CPU and 4GB of ram. All of my media is connected through an NFS mount and when watching video, iptraf typically has a datarate of 12-20mbps.

I watched the first episode of Stargate Universe and I had several instances of playback pausing for several seconds, then resuming. After the 2nd or 3rd time, I turned on debugging and did a tail on the log file.

At 20:23:27, it experienced a hiccup, playback paused and at 20:23:48, playback resumed. I haven't had a problem for weeks, and I don't know why it's having problems now.

Quote:20:22:41 T:2819619696 M:3577217024 NOTICE: 'TRAKT: Title: Stargate Universe,2009,01,01'
20:22:49 T:2310380400 M:3590795264 DEBUG: CDVDPlayerAudio:: Discontinuity - was:5080496945.111931, should be:5080506969.880324, error:10024.768393
20:22:53 T:3045541744 M:3590717440 DEBUG: UPower: Recieved an unkown signal DeviceChanged
20:22:56 T:2819619696 M:3589652480 NOTICE: 'TRAKT: Video found playing'
20:22:56 T:2819619696 M:3589652480 NOTICE: 'TRAKT: Percentage of progress: 0.965517241379'
20:22:56 T:2819619696 M:3589652480 NOTICE: 'TRAKT: continuing to send check'
20:22:57 T:2819619696 M:3590647808 NOTICE: 'TRAKT: Found TV Show'
20:22:57 T:2819619696 M:3590647808 NOTICE: 'TRAKT: Title: Stargate Universe,2009,01,01'
20:23:12 T:2819619696 M:3588722688 NOTICE: 'TRAKT: Video found playing'
20:23:12 T:2819619696 M:3588722688 NOTICE: 'TRAKT: Percentage of progress: 0.977011494253'
20:23:12 T:2819619696 M:3588722688 NOTICE: 'TRAKT: continuing to send check'
20:23:13 T:2819619696 M:3587960832 NOTICE: 'TRAKT: Found TV Show'
20:23:13 T:2819619696 M:3587960832 NOTICE: 'TRAKT: Title: Stargate Universe,2009,01,01'
20:23:23 T:3045541744 M:3599450112 DEBUG: UPower: Recieved an unkown signal DeviceChanged
20:23:27 T:2310380400 M:3599450112 WARNING: CDVDMessageQueue(audio)::Get - asked for new data packet, with nothing available
20:23:27 T:2320870256 M:3603513344 WARNING: CDVDMessageQueue(video)::Get - asked for new data packet, with nothing available
20:23:28 T:2320870256 M:3603513344 INFO: CDVDPlayerVideo - Stillframe detected, switching to forced 23.976025 fps
20:23:28 T:2320870256 M:3603513344 DEBUG: CPullupCorrection: pattern lost
20:23:28 T:2819619696 M:3603386368 NOTICE: 'TRAKT: Video found playing'
20:23:28 T:2819619696 M:3603386368 NOTICE: 'TRAKT: Percentage of progress: 0.977011494253'
20:23:28 T:2819619696 M:3603386368 NOTICE: 'TRAKT: continuing to send check'
20:23:29 T:2819619696 M:3603484672 NOTICE: 'TRAKT: Video is currently paused'
20:23:30 T:2320870256 M:3603484672 DEBUG: CPullupCorrection: detected pattern of length 1: 41708.33
20:23:44 T:2819619696 M:3603492864 NOTICE: 'TRAKT: Video found playing'
20:23:44 T:2819619696 M:3603492864 NOTICE: 'TRAKT: Percentage of progress: 0.977011494253'
20:23:44 T:2819619696 M:3603492864 NOTICE: 'TRAKT: continuing to send check'
20:23:45 T:2819619696 M:3603492864 NOTICE: 'TRAKT: Video is currently paused'
20:23:48 T:2622479216 M:3606921216 DEBUG: CDVDPlayer::SetCaching - caching state 1
20:23:48 T:2310380400 M:3606921216 ERROR: Pause - pcm_pause, alsa error: -77 - File descriptor in bad state
20:23:48 T:2310380400 M:3606921216 WARNING: CALSADirectSound::CALSADirectSound - device is not able to pause playback, will flush and prefix with 0 frames
20:23:48 T:3045541744 M:3606921216 DEBUG: ------ Window Init (DialogSeekBar.xml) ------
20:23:48 T:2572573552 M:3606921216 DEBUG: thread start, auto delete: 1
20:23:48 T:2622479216 M:3606581248 DEBUG: CDVDPlayer::HandleMessages - player started 1
20:23:48 T:2622479216 M:3606581248 DEBUG: CDVDPlayer::HandleMessages - player started 2
20:23:48 T:2572573552 M:3599314944 DEBUG: GetImageHash - unable to stat url /home/xbmc/Ryoken/Television/Stargate Universe//clearart.png
20:23:48 T:2572573552 M:3599314944 DEBUG: GetImageHash - unable to stat url /home/xbmc/Ryoken/Television/Stargate Universe/../clearart.png
20:23:49 T:2622479216 M:3592880128 DEBUG: CDVDPlayer::SetCaching - caching state 0
20:23:49 T:2320870256 M:3592880128 INFO: CDVDPlayerVideo - Stillframe left, switching to normal playback
20:23:49 T:2310380400 M:3592880128 DEBUG: CDVDPlayerAudio:: Discontinuity - was:5139958705.715324, should be:5119210678.727145, error:-20748026.988179
20:23:49 T:2320870256 M:3592753152 DEBUG: CPullupCorrection: pattern lost
20:23:49 T:3045541744 M:3592372224 DEBUG: ------ Window Deinit (DialogSeekBar.xml) ------
Reply
#2
I fixed some UPower configuration problems while watching episode 2, then watched the logs again. I'm generating fewer lines this time around, but still pausing problems.

Quote:21:04:16 T:2547395440 M:3604779008 WARNING: CDVDMessageQueue(audio)::Get - asked for new data packet, with nothing available
21:04:16 T:2557885296 M:3611127808 WARNING: CDVDMessageQueue(video)::Get - asked for new data packet, with nothing available
21:04:17 T:2557885296 M:3611254784 INFO: CDVDPlayerVideo - Stillframe detected, switching to forced 23.976025 fps
21:04:17 T:2557885296 M:3611254784 DEBUG: CPullupCorrection: pattern lost
21:04:19 T:2557885296 M:3611262976 DEBUG: CPullupCorrection: detected pattern of length 1: 41708.33
21:04:23 T:3045541744 M:3611262976 DEBUG: UPower: Recieved an unkown signal DeviceChanged
21:04:37 T:2630921072 M:3611402240 DEBUG: CDVDPlayer::SetCaching - caching state 1
21:04:37 T:2547395440 M:3611402240 WARNING: CALSADirectSound::CALSADirectSound - device is not able to pause playback, will flush and prefix with 0 frames
21:04:37 T:2630921072 M:3611402240 DEBUG: CDVDPlayer::HandleMessages - player started 1
21:04:37 T:2630921072 M:3611402240 DEBUG: CDVDPlayer::HandleMessages - player started 2
21:04:37 T:3045541744 M:3611406336 DEBUG: ------ Window Init (DialogSeekBar.xml) ------
21:04:37 T:2341849968 M:3611488256 DEBUG: thread start, auto delete: 1
21:04:38 T:2630921072 M:3605991424 DEBUG: CDVDPlayer::SetCaching - caching state 0
21:04:38 T:2557885296 M:3605991424 INFO: CDVDPlayerVideo - Stillframe left, switching to normal playback
21:04:38 T:2547395440 M:3605991424 DEBUG: CDVDPlayerAudio:: Discontinuity - was:1640562692.946303, should be:1619541342.587814, error:-21021350.358490
21:04:38 T:2341849968 M:3605737472 DEBUG: GetImageHash - unable to stat url /home/xbmc/Ryoken/Television/Stargate Universe//clearart.png
21:04:38 T:2341849968 M:3605737472 DEBUG: GetImageHash - unable to stat url /home/xbmc/Ryoken/Television/Stargate Universe/../clearart.png
Reply
#3
I'm experiencing the problem on videos that have not had the problem before. I know I can't be the only one having this problem. I've found people on Boxee forums experiencing the same problem. When the problem happens, network traffic drops way down, 35-40kbps.

http://forums.boxee.tv/showthread.php?t=47239
https://github.com/pipelka/vdr-plugin-xvdr/issues/17
Reply

Logout Mark Read Team Forum Stats Members Help
[LIVE] Intermittent hang while watching movies.0