Major bug, seems to be online video issue only (1 Viewer)

[Crackofdawn]

Hello, I have a very annoying problem I'm hoping someone can help with! When I try to play videos in OnlineVideos, there is a massive 'lag' time before the video starts loading - this lag time appears to be different based on the site I'm using, with sites like Break being the quickest and Yahoomusicvideos taking by far the longest. During the initial 'lag' time, it will show '0%' loaded (not 0.0%) and the Hard disk on my HTPC will be flashing nonstop and very loud as if a lot of data is being read/written. After awhile (as long as 60 seconds) it will change from 0% to 0.0% loaded, and then as long as 20 seconds after that it will suddenly go up very fast and start the video. Once the video starts playing the HD access goes away. This behavior only started sometime in the last few months - I've been using OnlineVideos since a loooong time ago (0.16 or something) without any issues, and I think this issue either popped up when installing OnlineVideos 1.0.0 or MediaPortal 1.2.0 with LAV Filters (before that I was only using FFDShow for everything). I can't say for sure when it actually started though. I'm currently on MP 1.2.3 and OV 1.2.0 with LAV Filters 0.50.2 and the issue is the same or worse.

Attached is a mediaportal debug run where I loaded, went straight to OnlineVideos, then to YahooMusicVideos, then clicked a video (the lag is by far the worst with Yahoo, takes up to 1 1/2 minutes to start a video, with the first 1 minute and 25 seconds at 0%. Other sites like break will go much faster but still take 10+ seconds to start a single video - even if the video is only 10 seconds long.

The main suspicious thing to me is in the MPUrlSourceSplitter.log file, immediately after it shows the LAV Filter loaded, there are hundreds of errors below that go for 45 seconds or so:

MPUrlSourceSplitter_Rtmp: RtmpLogCallback(): DECODING ERROR, IGNORING BYTES UNTIL NEXT KNOWN PATTERN!

Google doesn't seem to show anything about what this is but it seems to take up the majority of the time when OnlineVideos is 'hung' waiting to start streaming.

Side note: This only happens in OnlineVideos - if I play any local file in MovingPictures, My TV-Series, etc, it plays instantly with only minor hard drive access.

 

[offbyone]

It's not a bug, it's a feature!
Investigating your logs, it clearly shows problems with the RTMP data that is coming from Yahoo. Since 1.0 we are using our own filter for accessing this protocol, so there can be problems ofc.
The long delay should not happen on videos from YouTube for example. It all depends on a) what protocol is used to connect to the server and b) how good the metadata in the file is. You have to understand that the stream cannot start instant like moviews on your HDD - because it needs to be buffered a little at first.

 

[Crackofdawn]

Oh I definitely understand buffering has to occur, but it doesn't visibly start for almost 60 seconds while the HDD is going crazy. This didn't used to happen in older onlinevideos versions I guess because the filter is different? It happens with break.com too but not as bad. I have 30mbit Internet that will buffer the entire video from a web browser before that same video in onlinevideos even starts buffering :/ in older onlinevideos versions these same videos would buffer and start almost instantly.

Oh! I almost forgot! In the onlinevideos configuration where you can test each stream type when I click the "test" button next to each type the HDD goes crazy for 6+ seconds before the little video plays and it shows LAV Flters in the box - I assumed that was related to the same issue. It's the massive hard disk access that confuses me most.

 

[georgius]

It's not a bug, it's a feature!
Investigating your logs, it clearly shows problems with the RTMP data that is coming from Yahoo. Since 1.0 we are using our own filter for accessing this protocol, so there can be problems ofc.
The long delay should not happen on videos from YouTube for example. It all depends on a) what protocol is used to connect to the server and b) how good the metadata in the file is. You have to understand that the stream cannot start instant like moviews on your HDD - because it needs to be buffered a little at first.

RTMP protocol is not very well described. Sometimes remote server responds with extra data in stream which cause synchronization error in library.

Oh! I almost forgot! In the onlinevideos configuration where you can test each stream type when I click the "test" button next to each type the HDD goes crazy for 6+ seconds before the little video plays and it shows LAV Flters in the box - I assumed that was related to the same issue. It's the massive hard disk access that confuses me most.

Can you post logs for these cases?

 

[Crackofdawn]

Is there a way to log the media portal configuration program or onlinevideos configuration window? This test button isn't within media portal itself only the configuration program.

 

[offbyone]

The test from within Configuration will also use the same logfiles as MediaPortal (only Configuration.log instead of MediaPortal.log but all other files just the same).
BTW: I have seen people stating that disabling Microsoft Security Essenstials or other AntiVirus tools can help performance in starting streams.

 

[Crackofdawn]

Attached are the Configuration.log file and MPUrlSourceSplitter.log - I generated these by first setting MP to Debug logging, then running Configuration, then OnlineVideos configuration, then clicking 'test' on the codec page for the first couple entries. Each click of 'test' took 12+ seconds before the video showed up and started playing (12 seconds is an eternity in that case). You can see a couple snippets below for example in Configuration.log at 11:33:03 it takes almost 9 seconds between adding the MP Url Source Splitter to graph, and then adding LAV Video/Audio decoders to graph - so 9 seconds to load the MPURL Splitter (edit looks like its probably 9 seconds to load the LAV Filter not the MPUrlSplitter, not sure, but LAV Filter loads fine when I play local media via movingpictures etc)? What's up with that? Same from MPUrlSourceSplitter.log at 11:33:14-23, 9 seconds from closing MPUrlSourceSplitter_Http to starting the LAVSplitter. Doesn't make sense to me.

From Configuration.log
2012-04-29 11:33:03.058956 [Info.][Config Main(1)]: Added filter: MediaPortal Url Source Splitter to graph
2012-04-29 11:33:11.583444 [Info.][Config Main(1)]: Added filter: LAV Video Decoder to graph
2012-04-29 11:33:11.585444 [Info.][Config Main(1)]: Added filter: LAV Audio Decoder to graph

From MPUrlSourceSplitter.log
29-04-2012 11:33:14.214 [ fc8] [{3BA8E1B2-D3C5-4583-AB0F-0BF876419EDC}] [Info] MPUrlSourceSplitter_Http: CloseConnection(): End
29-04-2012 11:33:23.277 [ fb0] [{D1938045-FF4E-4DE3-ABDA-553D55B36A69}] [Info] LAVSplitter: SetPositionsInternal(): Start

 

[NTM]

Like offbyone said.
I had the same problem and uninstalling Microsoft Security Essentials solved it for me.
Try that if you have it installed.

 

[Crackofdawn]

I'm 99% sure I don't have any anti-virus installed on my HTPC - certainly no 3rd party antivirus and 99% sure no Security Essentials but I'll double check when I get home.

 

[georgius]

Like NTM and offbyone said. Something is consuming your CPU time. I compared times from your log and times are approx. 5 times slower than on my HTPC.