xbmc-live shutters sometimes
#1
Hi all,
I don'y understand what is happening to my installation.
At the beggining it was working fine, but now it has gotten worse, but I can't recall when this happened.

For a while now, I get random shutter during playback of video, especially 720p and 1080p.

This happens now and then, like 3 or 4 times per movie.

When this happens, to return to smooth video playback I have to press PAUSE, wait one second, and then press PLAY again.
Then it's ok for sometime (5 or 10 or 60 minutes, it depends) and then the shuttering starts again.
And I can't reproduce the shuttering in the same point, meaning that if I play again the movie, the shuttering appears in a different position.

My system:
Intel E4300 - XBMC-Live 10.1
1GB RAM - nVidia GT8600

Anyone can help?

Here's the log file, but there is nothing strange during the playback of the movie, when the shuttering occurs.

Code:
21:42:13 T:3054598016 M:836005888  NOTICE: DVDPlayer: Opening: /duetera/Video/Movies - ITA/HDTV mkv (ITA)/Wall Street il denaro non dorme mai (2010).mkv
21:42:13 T:3054598016 M:836005888 WARNING: CDVDMessageQueue(player)::Put MSGQ_NOT_INITIALIZED
21:42:13 T:2663373680 M:836005888  NOTICE: Creating InputStream
21:42:13 T:2663373680 M:836005888  NOTICE: Creating Demuxer
21:42:13 T:2663373680 M:828002304  NOTICE: Opening video stream: 0 source: 256
21:42:13 T:2663373680 M:828002304  NOTICE: Creating video codec with codec id: 28
21:42:13 T:2663373680 M:828284928  NOTICE: CDVDVideoCodecFFmpeg::Open() Creating VDPAU(1280x544, 28)
21:42:13 T:2663373680 M:826949632  NOTICE: vdp_device = 0x00000001 vdp_st = 0x00000000
21:42:13 T:2663373680 M:826949632  NOTICE: VDPAU Decoder capabilities:
21:42:13 T:2663373680 M:826949632  NOTICE: name          level macbs width height
21:42:13 T:2663373680 M:826949632  NOTICE: ------------------------------------
21:42:13 T:2663373680 M:826949632  NOTICE: MPEG1             0  8192  2048  2048
21:42:13 T:2663373680 M:826949632  NOTICE: MPEG2_SIMPLE      3  8192  2048  2048
21:42:13 T:2663373680 M:826949632  NOTICE: MPEG2_MAIN        3  8192  2048  2048
21:42:13 T:2663373680 M:826949632  NOTICE: H264_MAIN        41  8192  2048  2048
21:42:13 T:2663373680 M:826949632  NOTICE: H264_HIGH        41  8192  2048  2048
21:42:13 T:2663373680 M:826949632  NOTICE: VC1_SIMPLE        1  8190  2048  2048
21:42:13 T:2663373680 M:826949632  NOTICE: VC1_MAIN          2  8190  2048  2048
21:42:13 T:2663373680 M:826949632  NOTICE: VC1_ADVANCED      4  8190  2048  2048
21:42:13 T:2663373680 M:826949632  NOTICE: ------------------------------------
21:42:13 T:2663373680 M:826949632  NOTICE: Mixer feature: VDP_VIDEO_MIXER_FEATURE_NOISE_REDUCTION
21:42:13 T:2663373680 M:826949632  NOTICE: Mixer feature: VDP_VIDEO_MIXER_FEATURE_SHARPNESS
21:42:13 T:2663373680 M:826949632  NOTICE: Mixer feature: VDP_VIDEO_MIXER_FEATURE_DEINTERLACE_TEMPORAL
21:42:13 T:2663373680 M:826949632  NOTICE: Mixer feature: VDP_VIDEO_MIXER_FEATURE_DEINTERLACE_TEMPORAL_SPATIAL
21:42:13 T:2663373680 M:826949632  NOTICE: Mixer feature: VDP_VIDEO_MIXER_FEATURE_INVERSE_TELECINE
21:42:13 T:2663373680 M:826568704  NOTICE: Creating 1280x544 pixmap
21:42:13 T:2663373680 M:824594432  NOTICE: CDVDVideoCodecFFmpeg::Open() Using codec: H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10 (VDPAU acceleration)
21:42:13 T:2663373680 M:824594432  NOTICE: Creating video thread
21:42:13 T:2663373680 M:824594432  NOTICE: Opening audio stream: 1 source: 256
21:42:13 T:2663373680 M:824594432  NOTICE: Finding audio codec for: 86021
21:42:13 T:2663373680 M:824594432  NOTICE: Creating audio thread
21:42:13 T:2663373680 M:824594432  NOTICE: Opening Subtitle stream: 4 source: 256
21:42:13 T:2711980912 M:824594432  NOTICE: running thread: CDVDPlayerAudio::Process()
21:42:13 T:2711980912 M:824180736  NOTICE: Creating audio device with codec id: 86021, channels: 2, sample rate: 48000, pass-through
21:42:13 T:2673863536 M:824180736  NOTICE: running thread: video_thread
21:42:13 T:2673863536 M:824688640  NOTICE:  (VDPAU) screenWidth:1280 vidWidth:1280
21:42:13 T:2673863536 M:824688640  NOTICE:  (VDPAU) screenHeight:544 vidHeight:544
21:42:13 T:2673863536 M:822767616  NOTICE:  (VDPAU) Total Output Surfaces Available: 4 of a max (tmp: 4 const: 4)
21:42:14 T:2673863536 M:822009856  NOTICE:  (VDPAU) Creating the video mixer
21:42:14 T:2673863536 M:821960704  NOTICE:  fps: 23.976025, pwidth: 1280, pheight: 544, dwidth: 1280, dheight: 544
21:42:14 T:2673863536 M:821960704  NOTICE: Display resolution ADJUST : default: 1920x1080 @ 24.00Hz (14)
21:42:14 T:3054598016 M:818188288  NOTICE: Using GL_TEXTURE_2D
21:42:14 T:3054598016 M:818188288  NOTICE: GL: Using VDPAU render method
21:42:14 T:3054598016 M:818188288  NOTICE: GL: NPOT texture support detected
21:42:14 T:3054598016 M:818188288  NOTICE: GL: Using GL_ARB_pixel_buffer_object
21:42:14 T:3054598016 M:816791552  NOTICE: Created m_glPixmapTexture (14)
21:50:14 T:3054598016 M:786165760 WARNING: CreateFile, successfuly opened </home/xbmc/.xbmc/addons/skin.night/720p/DialogSeekbar.xml> instead of </home/xbmc/.xbmc/addons/skin.night/720p/DialogSeekBar.xml>
23:52:11 T:2673863536 M:756908032 WARNING: CDVDMessageQueue(video)::Get - asked for new data packet, with nothing available
23:52:11 T:2711980912 M:755085312 WARNING: CALSADirectSound::GetSpace - get space failed. err: -32 (Broken pipe)
23:53:17 T:3054598016 M:756830208 WARNING: Previous line repeats 1 times.
23:53:17 T:3054598016 M:756830208  NOTICE: CDVDPlayer::CloseFile()
23:53:17 T:3054598016 M:756830208  NOTICE: DVDPlayer: waiting for threads to exit
23:53:17 T:2663373680 M:756830208  NOTICE: CDVDPlayer::OnExit()
23:53:17 T:2663373680 M:756830208  NOTICE: DVDPlayer: closing audio stream
23:53:17 T:2663373680 M:756830208  NOTICE: Closing audio stream
23:53:17 T:2663373680 M:756830208  NOTICE: Waiting for audio thread to exit
23:53:17 T:2711980912 M:756830208  NOTICE: thread end: CDVDPlayerAudio::OnExit()
23:53:17 T:2663373680 M:756957184  NOTICE: Closing audio device
23:53:17 T:2663373680 M:757137408  NOTICE: Deleting audio codec
23:53:17 T:2663373680 M:757137408  NOTICE: DVDPlayer: closing video stream
23:53:17 T:2663373680 M:757137408  NOTICE: Closing video stream
23:53:17 T:2663373680 M:757137408  NOTICE: waiting for video thread to exit
23:53:17 T:2673863536 M:757137408  NOTICE: thread end: video_thread
23:53:17 T:2663373680 M:757137408  NOTICE: deleting video codec
23:53:17 T:2663373680 M:757137408  NOTICE: DVDPlayer: closing subtitle stream
23:53:17 T:2663373680 M:757137408  NOTICE: Closing subtitle stream
23:53:17 T:2663373680 M:757137408  NOTICE: CDVDPlayer::OnExit() deleting demuxer
23:53:17 T:2663373680 M:761544704  NOTICE: CDVDPlayer::OnExit() deleting input stream
23:53:17 T:3054598016 M:763383808  NOTICE: DVDPlayer: finished waiting
23:53:17 T:3054598016 M:763383808  NOTICE:  (VDPAU) Close
23:53:17 T:3054598016 M:763383808  NOTICE:  (VDPAU) FiniVDPAUOutput
23:53:17 T:3054598016 M:786182144 WARNING: Skin has invalid include: control
23:53:17 T:3054598016 M:786227200 WARNING: Previous line repeats 26 times.
23:53:17 T:3054598016 M:786227200 WARNING: Skin has invalid include: recent_right_side
23:53:18 T:3054598016 M:785211392 WARNING: Previous line repeats 1 times.
23:53:18 T:3054598016 M:785211392  NOTICE: CDVDPlayer::CloseFile()
23:53:18 T:3054598016 M:785211392 WARNING: CDVDMessageQueue(player)::Put MSGQ_NOT_INITIALIZED
23:53:18 T:3054598016 M:785211392  NOTICE: DVDPlayer: waiting for threads to exit
23:53:18 T:3054598016 M:785211392  NOTICE: DVDPlayer: finished waiting

and here my xorg.conf
Code:
# nvidia-xconfig: X configuration file generated by nvidia-xconfig
# nvidia-xconfig:  version 1.0  (buildmeister@builder75)  Thu Apr 22 11:44:23 PDT 2010

Section "Monitor"
  Identifier    "DFP-0"
  HorizSync 15 - 100
  VertRefresh 22 - 110
  # CEA Format 16
  ModeLine "1920x1080_60_ste" 148.352 1920 2008 2052 2200 1080 1084 1089 1125 +hsync +vsync
  # CEA Format 31
  ModeLine "1920x1080_50_ste" 148.50 1920 2448 2492 2640 1080 1084 1089 1125 +hsync +vsync
  #Custom 23.976p
  ModeLine "1920x1080_24_ste" 74.059 1920 2558 2602 2718 1080 1084 1089 1137 +hsync +vsync
  Option   "enable" "true"
  Option   "Preferred Mode" "1920x1080_24_ste"
#  Option   "DPMS"
EndSection

Section "Device"
  Identifier "nvidia"
  Driver  "nvidia"
  Option  "ConnectedMonitor"    "DFP-0"
  Option  "NoLogo"              "true"
  Option  "DynamicTwinView"     "false"
  Option  "NoFlip"              "false"
  Option  "FlatPanelProperties" "Scaling = Native"
  Option  "ModeValidation"      "NoVesaModes, NoXServerModes"
  Option  "UseDisplayDevice"    "DFP-0"
  Option  "HWCursor"            "false"
  Option  "ExactModeTimingsDVI" "True"
  Option  "UseEDIDFreqs" "False"
EndSection

Section "Screen"
  Identifier      "screen"
  Device          "nvidia"
  Monitor         "DFP-0"
    SubSection    "Display"
    Depth         24
    Modes "1920x1080_50_ste" "1920x1080_24_ste" "1920x1080_60_ste"
  EndSubSection
EndSection

Section "Extensions"
  Option  "Composite"           "false"
EndSection
Reply
#2
hi all,
no replies?

Still getting this problem.

please, give me some help.
Reply
#3
Please turn on debug logging in XBMC and post the full log on pastebin.
Reply
#4
bobo1on1 Wrote:Please turn on debug logging in XBMC and post the full log on pastebin.

Hi bobo1on1,
thanks for your reply.
I managed finally to watch a full video with the debug log turned on.

Here is the result:
http://pastebin.com/cjWn14GF

The shutter happened at 21:31, 21:41, 21:43, 21:46, 22:51, 22:56, 23:00, etc.
These are the most recurrant errors:
DEBUG ERROR: CDVDPlayerAudio:: Discontinuity - was:xxxxxxxxxxxx
CPullupCorrection: pattern lost
WARNING: Decode - avcodec_decode_video didn't consume the full packet.

Here is a part of the log file during the video shutter:
Code:
22:56:51 T:2748308336 M:714186752    INFO: Scriptresult: Success
22:56:51 T:2748308336 M:714186752   DEBUG: xbp_dlopen loading python lib /usr/lib/xbmc/system/python/python24.zip/collections.so. flags: 2
22:56:51 T:2748308336 M:714240000   DEBUG: Loading: /home/xbmc/.xbmc/temp/collections.so
22:56:51 T:2748308336 M:714240000   DEBUG: RegisterExtensionLib, adding collections.so (0xaf29fd8)
22:56:51 T:2748308336 M:714240000   DEBUG: xbp_dlsym - load symbol initcollections
22:56:51 T:2748308336 M:714240000    INFO: Python script stopped
22:56:51 T:2748308336 M:714240000   DEBUG: Thread 2748308336 terminating
22:56:51 T:3053430656 M:714240000   DEBUG: python thread 3 destructed
22:56:51 T:3053430656 M:714240000   DEBUG: started alarm with name: nextaired
22:56:53 T:2758798192 M:713437184 WARNING: Decode - avcodec_decode_video didn't consume the full packet. size: 92611, consumed: 0
22:56:53 T:2758798192 M:710766592 WARNING: Decode - avcodec_decode_video didn't consume the full packet. size: 95055, consumed: 0
22:56:55 T:2758798192 M:705015808   DEBUG: CPullupCorrection: detected pattern of length 24: 42000.00 42000.00 41000.00 42000.00 42000.00 41000.00 42000.00 42000.00 41000.00 42000.00 42000.00 42000.00 41000.00 42000.00 42000.00 41000.00 42000.00 42000.00 42000.00 41000.00 42000.00 42000.00 41000.00 42000.00
22:57:01 T:3053430656 M:686784512    INFO: Python, unloading python24.dll because no scripts are running anymore
22:57:01 T:3053430656 M:686784512   DEBUG: UnloadExtensionLibs, clearing python extension libraries
22:57:01 T:3053430656 M:686784512   DEBUG: Unloading: strop.so
22:57:01 T:3053430656 M:686784512   DEBUG: Unloading: _socket.so
22:57:01 T:3053430656 M:686784512   DEBUG: Unloading: _ssl.so
22:57:01 T:3053430656 M:686784512   DEBUG: Unloading: time.so
22:57:01 T:3053430656 M:686784512   DEBUG: Unloading: collections.so
22:57:01 T:3053430656 M:686784512   DEBUG: Unloading: python24-i486-linux.so
22:57:05 T:3053430656 M:677359616   DEBUG: HttpApi Start command: SendKey  paras: SendKey; 61520
22:57:05 T:3053430656 M:677359616   DEBUG: OnKey: 61520 pressed, action is Play
22:57:05 T:3053430656 M:677359616   DEBUG: CAnnouncementManager - Announcement: PlaybackPaused from xbmc
22:57:05 T:3053430656 M:677359616   DEBUG: ------ Window Init (DialogSeekBar.xml) ------
22:57:53 T:3053430656 M:677388288   DEBUG: HttpApi Start command: SendKey  paras: SendKey; 61520
22:57:53 T:3053430656 M:677388288   DEBUG: OnKey: 61520 pressed, action is Play
22:57:53 T:3053430656 M:677388288   DEBUG: CAnnouncementManager - Announcement: PlaybackResumed from xbmc
22:57:53 T:2808241008 M:677388288   DEBUG: CDVDPlayerAudio:: Discontinuity - was:5010834524.217292, should be:5010837845.458724, error:3321.241432
22:57:53 T:3053430656 M:673873920   DEBUG: ------ Window Deinit (DialogSeekBar.xml) ------
22:59:27 T:2808241008 M:667541504   DEBUG: CDVDPlayerAudio:: Discontinuity - was:5105035631.276724, should be:5105045666.816399, error:10035.539675
23:01:00 T:2808241008 M:667791360   DEBUG: CDVDPlayerAudio:: Discontinuity - was:5198219420.119399, should be:5198229455.761556, error:10035.642156
23:02:33 T:2808241008 M:661377024   DEBUG: CDVDPlayerAudio:: Discontinuity - was:5291403558.780556, should be:5291413587.236669, error:10028.456112
23:04:07 T:2808241008 M:662126592   DEBUG: CDVDPlayerAudio:: Discontinuity - was:5384587279.097669, should be:5384597316.957643, error:10037.859974
23:04:26 T:2758798192 M:663003136   DEBUG: CPullupCorrection: pattern lost
23:04:28 T:2758798192 M:662249472   DEBUG: CPullupCorrection: detected pattern of length 24: 41000.00 42000.00 42000.00 41000.00 42000.00 42000.00 41000.00 42000.00 42000.00 42000.00 41000.00 42000.00 42000.00 41000.00 42000.00 42000.00 42000.00 41000.00 42000.00 42000.00 41000.00 42000.00 42000.00 42000.00
23:05:40 T:2808241008 M:658481152   DEBUG: CDVDPlayerAudio:: Discontinuity - was:5477771870.242642, should be:5477781898.384361, error:10028.141719
23:07:13 T:2808241008 M:650452992   DEBUG: CDVDPlayerAudio:: Discontinuity - was:5570955789.287361, should be:5570965814.387634, error:10025.100273
23:08:46 T:2808241008 M:663224320   DEBUG: CDVDPlayerAudio:: Discontinuity - was:5664140285.417634, should be:5664150322.395978, error:10036.978344
23:10:19 T:2808241008 M:663920640   DEBUG: CDVDPlayerAudio:: Discontinuity - was:5757323370.424978, should be:5757333395.667664, error:10025.242685
23:11:52 T:2808241008 M:663900160   DEBUG: CDVDPlayerAudio:: Discontinuity - was:5850507463.060663, should be:5850517501.183052, error:10038.122389
23:12:51 T:2758798192 M:663470080   DEBUG: CPullupCorrection: pattern lost
23:12:54 T:2758798192 M:663597056   DEBUG: CPullupCorrection: detected pattern of length 24: 41000.00 42000.00 42000.00 42000.00 41000.00 42000.00 42000.00 41000.00 42000.00 42000.00 41000.00 42000.00 42000.00 42000.00 41000.00 42000.00 42000.00 41000.00 42000.00 42000.00 42000.00 41000.00 42000.00 42000.00
23:13:26 T:2808241008 M:662618112   DEBUG: CDVDPlayerAudio:: Discontinuity - was:5943691503.665052, should be:5943701525.691642, error:10022.026589
23:14:59 T:2808241008 M:655941632   DEBUG: CDVDPlayerAudio:: Discontinuity - was:6036875559.037642, should be:6036885598.350617, error:10039.312976
23:16:32 T:2808241008 M:653590528   DEBUG: CDVDPlayerAudio:: Discontinuity - was:6130059916.181618, should be:6130069936.852329, error:10020.670712
23:17:47 T:3053430656 M:653111296   DEBUG: UDisks: DeviceChanged (/org/freedesktop/UDisks/devices/sdb)
23:17:47 T:3053430656 M:653111296   DEBUG: DBus: Creating message to org.freedesktop.UDisks on /org/freedesktop/UDisks/devices/sdb with interface org.freedesktop.DBus.Properties and method GetAll
23:17:47 T:3053430656 M:653111296   DEBUG: UDisks: DeviceChanged - DeviceUDI /org/freedesktop/UDisks/devices/sdb: IsFileSystem false HasFileSystem  IsSystemInternal true IsMounted false IsRemovable false IsPartition false IsOptical false
23:17:47 T:3053430656 M:653025280   DEBUG: UDisks: DeviceChanged (/org/freedesktop/UDisks/devices/sda)
23:17:47 T:3053430656 M:653025280   DEBUG: DBus: Creating message to org.freedesktop.UDisks on /org/freedesktop/UDisks/devices/sda with interface org.freedesktop.DBus.Properties and method GetAll
23:17:47 T:3053430656 M:653025280   DEBUG: UDisks: DeviceChanged - DeviceUDI /org/freedesktop/UDisks/devices/sda: IsFileSystem false HasFileSystem  IsSystemInternal true IsMounted false IsRemovable false IsPartition false IsOptical false
23:18:05 T:2808241008 M:653094912   DEBUG: CDVDPlayerAudio:: Discontinuity - was:6223244073.278329, should be:6223254100.190954, error:10026.912625
23:19:38 T:2808241008 M:643698688   DEBUG: CDVDPlayerAudio:: Discontinuity - was:6316428004.969954, should be:6316438047.210174, error:10042.240219
23:21:11 T:2808241008 M:643923968   DEBUG: CDVDPlayerAudio:: Discontinuity - was:6409611255.662173, should be:6409621273.900921, error:10018.238747

Can you help?

thanks a lot.
Reply
#5
If it happens on all videos, then it looks like the soundcard is playing the stream slightly too slow, this will cause a slowly drifting a/v sync error, which gets corrected if the sync error is more than 10 milliseconds.
Try turning on sync playback to display with the sync method set to resample.
Reply
#6
bobo1on1 Wrote:If it happens on all videos, then it looks like the soundcard is playing the stream slightly too slow, this will cause a slowly drifting a/v sync error, which gets corrected if the sync error is more than 10 milliseconds.
Try turning on sync playback to display with the sync method set to resample.

Hi,
Thanks for your quick reply.
will try and get back.

Thanks again.
Reply
#7
Thumbs Up 
Hi bobo1on1,
it seems that the trick solved the problem.

Thanks again.
Reply

Logout Mark Read Team Forum Stats Members Help
xbmc-live shutters sometimes0