[1.3.0.0] YT Videos frequently don't start on first attempt (2 Viewers)

[infinite.loop]

I have the problem that YT videos very frequently won't start on the first attempt to play them.

1. select the video
2. "okay"
3. it buffers
4. then MP just sits there and waits for a timeout
5. then a dialog window shows up, telling me that playback was not possible
6. try again
7. it buffers
8. playback starts

@offbyoneany clue why this happens?

Spoiler

[11-27 12:34:38,233] [OVInit      ] [INFO ] Using language 'de'
[11-27 12:34:38,416] [OVInit      ] [DEBUG] Translating skin
[11-27 12:34:38,516] [OVInit      ] [INFO ] Thumbnails will be stored in \\mainframe\htpc\Configurations\General\Thumbs\OnlineVideos\ with a maximum age of 30 days.
[11-27 12:34:39,385] [OVInit      ] [INFO ] Loaded 87 sites from OnlineVideoSites.xml
[11-27 12:34:39,617] [OVInit      ] [DEBUG] Looking for SiteUtils in Assembly: OnlineVideos (Version: 1.3.0.2261, LastWriteTime: 2012-07-18 10:20:16)
[11-27 12:34:39,680] [OVInit      ] [DEBUG] Looking for SiteUtils in Assembly: OnlineVideos.Sites.apondman (Version: 1.0.2.2385, LastWriteTime: 2012-10-08 22:05:46)
[11-27 12:34:39,690] [OVInit      ] [DEBUG] Looking for SiteUtils in Assembly: OnlineVideos.Sites.brownard (Version: 1.0.0.0, LastWriteTime: 2012-11-26 22:33:01)
[11-27 12:34:39,696] [OVInit      ] [DEBUG] Looking for SiteUtils in Assembly: OnlineVideos.Sites.corporategadfly (Version: 1.0.0.15, LastWriteTime: 2012-07-18 19:31:57)
[11-27 12:34:39,703] [OVInit      ] [DEBUG] Looking for SiteUtils in Assembly: OnlineVideos.Sites.diebagger (Version: 1.0.0.0, LastWriteTime: 2012-07-18 19:52:37)
[11-27 12:34:39,737] [OVInit      ] [DEBUG] Looking for SiteUtils in Assembly: OnlineVideos.Sites.doskabouter (Version: 1.0.0.0, LastWriteTime: 2012-11-26 22:33:01)
[11-27 12:34:39,777] [OVInit      ] [DEBUG] Looking for SiteUtils in Assembly: OnlineVideos.Sites.hioctane (Version: 1.0.0.0, LastWriteTime: 2012-09-01 16:15:30)
[11-27 12:34:39,789] [OVInit      ] [DEBUG] Looking for SiteUtils in Assembly: OnlineVideos.Sites.offbyone (Version: 1.0.0.0, LastWriteTime: 2012-11-09 16:49:28)
[11-27 12:34:39,957] [OVInit      ] [DEBUG] Looking for SiteUtils in Assembly: OnlineVideos.Sites.pilehave (Version: 1.0.0.0, LastWriteTime: 2012-07-18 19:31:57)
[11-27 12:34:39,963] [OVInit      ] [DEBUG] Looking for SiteUtils in Assembly: OnlineVideos.Sites.rick164 (Version: 1.0.0.0, LastWriteTime: 2012-11-20 22:34:25)
[11-27 12:34:39,968] [OVInit      ] [DEBUG] Looking for SiteUtils in Assembly: OnlineVideos.Sites.SilentException (Version: 1.0.0.0, LastWriteTime: 2012-07-18 19:31:57)
[11-27 12:34:39,975] [OVInit      ] [DEBUG] Looking for SiteUtils in Assembly: OnlineVideos.Sites.SK_CZ (Version: 1.2.0.11, LastWriteTime: 2012-07-18 19:31:57)
[11-27 12:34:39,986] [OVInit      ] [DEBUG] Looking for SiteUtils in Assembly: OnlineVideos.Sites.titof (Version: 1.0.0.0, LastWriteTime: 2012-07-18 19:31:57)
[11-27 12:34:40,300] [OVInit      ] [WARN ] HardwareInfo - could not set Configuration Value: nextPageRegExUrlDecoding. Error: Der angeforderte Wert "true" konnte nicht gefunden werden.
[11-27 12:34:40,326] [OVInit      ] [WARN ] SiteUtil with name: TurboNick not found!
[11-27 12:34:40,363] [OVInit      ] [DEBUG] Loading script files
[11-27 12:34:40,376] [OVInit      ] [INFO ] Created 75 SiteUtils
[11-27 12:34:40,515] [OVLatest    ] [INFO ] LatestVideosManager getting new data from SiteUtils.
[11-27 12:34:45,601] [OVLatest    ] [INFO ] LatestVideosManager found 3 videos from 1 SiteUtils.
[11-27 12:35:28,614] [OVLoad      ] [INFO ] Checking 1365 thumbnails for age.
[11-27 12:35:31,528] [OVLoad      ] [INFO ] Deleted 1 thumbnails.
[11-27 12:35:32,062] [MPMain      ] [INFO ] Called with LoadParameter: 'site:YouTube|return:Locked'
[11-27 12:35:32,163] [MPMain      ] [INFO ] DoPageLoad with CurrentState 'categories', PreviousWindowId '35'
[11-27 12:35:32,180] [OnlineVideos] [INFO ] Looking for dynamic categories for site 'YouTube'
[11-27 12:35:32,286] [OnlineVideos] [INFO ] Found 32 dynamic categories for site 'YouTube'
[11-27 12:35:32,458] [MPMain      ] [INFO ] restoring search category...
[11-27 12:35:32,468] [MPMain      ] [INFO ] Search category restored to Alle
[11-27 12:35:54,356] [OnlineVideos] [INFO ] Searching for ganganam style in all categories
[11-27 12:35:55,594] [MPMain      ] [INFO ] restoring search category...
[11-27 12:35:55,605] [MPMain      ] [INFO ] Search category restored to Alle
[11-27 12:36:00,354] [OnlineVideos] [DEBUG] GetWebData-GET: 'http://youtube.com/get_video_info?video_id=9bZkp7q19f0&has_verified=1'
[11-27 12:36:02,819] [MPMain      ] [INFO ] Preparing graph for playback of 'http://o-o---preferred---sn-4g57ln7y---v3---lscache1.c.youtube.com/videoplayback?upn=5uBaTtGr3Hk&sparams=cp%2Cgcr%2Cid%2Cip%2Cipbits%2Citag%2Cratebypass%2Csource%2Cupn%2Cexpire&fexp=912307%2C906435%2C916623%2C922401%2C920704%2C912806%2C927201%2C925706%2C922403%2C913546%2C913556%2C916805%2C920201%2C911116%2C901451&ms=au&expire=1354040361&itag=22&ipbits=8&gcr=at&sver=3&ratebypass=yes&mt=1354016110&ip=80.92.116.241&mv=m&source=youtube&key=yt1&cp=U0hUSVBPTl9LS0NONF9ISVJEOndrSW9DcHA0dXFO&id=f5b664a7bab5f5fd&signature=C231C6FE6C1E856423CCA8DD39FB56523B3A06EB.21ABA8A3CB5B5994BA412885C795E351ADD938C5&ext=.mp4'
[11-27 12:36:03,759] [OnlineVideos] [INFO ] Start prebuffering ...
[11-27 12:36:04,337] [OnlineVideos] [DEBUG] Buffering: 975/90895 KB (1%)
[11-27 12:36:04,899] [OVGraph    ] [DEBUG] BufferFile : Rendering unconnected output pins of source filter ...
[11-27 12:36:04,899] [OnlineVideos] [DEBUG] Buffering: 1886/90895 KB (2%)
[11-27 12:36:04,924] [OVGraph    ] [INFO ] found H264 video on output pin
[11-27 12:36:05,172] [OnlineVideos] [DEBUG] Buffering: 2897/90895 KB (3%)
[11-27 12:36:05,233] [OVGraph    ] [DEBUG] BufferFile : Playback Ready.
[11-27 12:36:05,279] [OnlineVideos] [INFO ] Prebuffering finished.
[11-27 12:36:05,387] [MPMain      ] [INFO ] OnlineVideosPlayer: Play 'http://o-o---preferred---sn-4g57ln7y---v3---lscache1.c.youtube.com/videoplayback?upn=5uBaTtGr3Hk&sparams=cp%2Cgcr%2Cid%2Cip%2Cipbits%2Citag%2Cratebypass%2Csource%2Cupn%2Cexpire&fexp=912307%2C906435%2C916623%2C922401%2C920704%2C912806%2C927201%2C925706%2C922403%2C913546%2C913556%2C916805%2C920201%2C911116%2C901451&ms=au&expire=1354040361&itag=22&ipbits=8&gcr=at&sver=3&ratebypass=yes&mt=1354016110&ip=80.92.116.241&mv=m&source=youtube&key=yt1&cp=U0hUSVBPTl9LS0NONF9ISVJEOndrSW9DcHA0dXFO&id=f5b664a7bab5f5fd&signature=C231C6FE6C1E856423CCA8DD39FB56523B3A06EB.21ABA8A3CB5B5994BA412885C795E351ADD938C5&ext=.mp4'
[11-27 12:36:05,537] [MPMain      ] [DEBUG] MediaPortal Url Source Splitter --> LAV Video Decoder --> Enhanced Video Renderer
[11-27 12:36:05,691] [MPMain      ] [DEBUG] MediaPortal Url Source Splitter --> LAV Audio Decoder --> MediaPortal - Audio Renderer
[11-27 12:36:26,233] [MPMain      ] [WARN ] OnlineVideosPlayer: Unable to play with reason: IMediaControl.GetState after 20 seconds: 0x00040237 - 'Statusübergang wurde nicht abgeschlossen.'
[11-27 12:36:30,259] [OnlineVideos] [DEBUG] GetWebData-GET (cached): 'http://youtube.com/get_video_info?video_id=9bZkp7q19f0&has_verified=1'
[11-27 12:36:32,142] [MPMain      ] [INFO ] Preparing graph for playback of 'http://o-o---preferred---sn-4g57ln7y---v3---lscache1.c.youtube.com/videoplayback?upn=5uBaTtGr3Hk&sparams=cp%2Cgcr%2Cid%2Cip%2Cipbits%2Citag%2Cratebypass%2Csource%2Cupn%2Cexpire&fexp=912307%2C906435%2C916623%2C922401%2C920704%2C912806%2C927201%2C925706%2C922403%2C913546%2C913556%2C916805%2C920201%2C911116%2C901451&ms=au&expire=1354040361&itag=22&ipbits=8&gcr=at&sver=3&ratebypass=yes&mt=1354016110&ip=80.92.116.241&mv=m&source=youtube&key=yt1&cp=U0hUSVBPTl9LS0NONF9ISVJEOndrSW9DcHA0dXFO&id=f5b664a7bab5f5fd&signature=C231C6FE6C1E856423CCA8DD39FB56523B3A06EB.21ABA8A3CB5B5994BA412885C795E351ADD938C5&ext=.mp4'
[11-27 12:36:32,482] [OnlineVideos] [INFO ] Start prebuffering ...
[11-27 12:36:33,162] [OnlineVideos] [DEBUG] Buffering: 1020/90895 KB (1%)
[11-27 12:36:33,423] [OnlineVideos] [DEBUG] Buffering: 2000/90895 KB (2%)
[11-27 12:36:33,483] [OVGraph    ] [DEBUG] BufferFile : Rendering unconnected output pins of source filter ...
[11-27 12:36:33,493] [OVGraph    ] [INFO ] found H264 video on output pin
[11-27 12:36:33,588] [OVGraph    ] [DEBUG] BufferFile : Playback Ready.
[11-27 12:36:33,633] [OnlineVideos] [INFO ] Prebuffering finished.
[11-27 12:36:33,708] [MPMain      ] [INFO ] OnlineVideosPlayer: Play 'http://o-o---preferred---sn-4g57ln7y---v3---lscache1.c.youtube.com/videoplayback?upn=5uBaTtGr3Hk&sparams=cp%2Cgcr%2Cid%2Cip%2Cipbits%2Citag%2Cratebypass%2Csource%2Cupn%2Cexpire&fexp=912307%2C906435%2C916623%2C922401%2C920704%2C912806%2C927201%2C925706%2C922403%2C913546%2C913556%2C916805%2C920201%2C911116%2C901451&ms=au&expire=1354040361&itag=22&ipbits=8&gcr=at&sver=3&ratebypass=yes&mt=1354016110&ip=80.92.116.241&mv=m&source=youtube&key=yt1&cp=U0hUSVBPTl9LS0NONF9ISVJEOndrSW9DcHA0dXFO&id=f5b664a7bab5f5fd&signature=C231C6FE6C1E856423CCA8DD39FB56523B3A06EB.21ABA8A3CB5B5994BA412885C795E351ADD938C5&ext=.mp4'
[11-27 12:36:33,840] [MPMain      ] [DEBUG] MediaPortal Url Source Splitter --> LAV Video Decoder --> Enhanced Video Renderer
[11-27 12:36:34,000] [MPMain      ] [DEBUG] MediaPortal Url Source Splitter --> LAV Audio Decoder --> MediaPortal - Audio Renderer
[11-27 12:36:35,573] [MPMain      ] [INFO ] OnlineVideosPlayer: Duration 252,17 sec
[11-27 12:36:37,758] [OVPlaying  ] [INFO ] Setting Video Properties for 'PSY - GANGNAM STYLE (강남스타일) M/V (1280x720 | mp4 (22))'
[11-27 12:39:46,722] [MPMain      ] [INFO ] OnlineVideosPlayer: Stop
[11-27 12:39:47,111] [MPMain      ] [INFO ] DoPageLoad with CurrentState 'videos', PreviousWindowId '4758'
[11-27 12:39:47,268] [MPMain      ] [INFO ] restoring search category...
[11-27 12:39:47,282] [MPMain      ] [INFO ] Search category restored to Alle

 

[offbyone]

No real clue, but this line:
OnlineVideosPlayer: Unable to play with reason: IMediaControl.GetState after 20 seconds: 0x00040237 - 'Statusübergang wurde nicht abgeschlossen.'
is telling that somehow your directshow graph is not in a playing state. But why is out of my knowledge.

 

[infinite.loop]

I never had this issue until I started using MP 1.3.0Alpha/LAVF and 1.3.0.0 on the live system.

There are no playback issues inside MyTV/Videos/TvSeries/MovingPictures with a lot of different formats and codecs.
Thats why this puzzles me.

 

[georgius]

Attach MPUrlSourceSplitter.log (or complete MP logs), maybe it's filter issue.

 

[infinite.loop]

Attach MPUrlSourceSplitter.log (or complete MP logs), maybe it's filter issue.

Here they are.

First YT video I played worked, 2nd failed.

 

[tourettes]

HRESULT: 0x00040237 (262711)
Name: VFW_S_STATE_INTERMEDIATE
Description: The state transition has not completed.

Some of the filters aren't behaving nicely and is telling to the graph that it needs to buffer data. If you are using MPAR then try without it.

 

[infinite.loop]

HRESULT: 0x00040237 (262711)
Name: VFW_S_STATE_INTERMEDIATE
Description: The state transition has not completed.

Some of the filters aren't behaving nicely and is telling to the graph that it needs to buffer data. If you are using MPAR then try without it.

Yeah I am using MPAR. Does OV take the filter settings from the videos section?

 

[tourettes]

HRESULT: 0x00040237 (262711)
Name: VFW_S_STATE_INTERMEDIATE
Description: The state transition has not completed.

Some of the filters aren't behaving nicely and is telling to the graph that it needs to buffer data. If you are using MPAR then try without it.

Yeah I am using MPAR. Does OV take the filter settings from the videos section?

As far as I remember it just renders the graph with OS defaults - but t has been long time since I have heard that so I could be wrong (and hopefully I am ).

 

[georgius]

Does OV take the filter settings from the videos section?

Yes. From OV 1.1.0 are codecs get from videos section.

In filter log is nothing, so try another renderer as MPAR.

 

[infinite.loop]

Seems you were right about mpar causing this.

Just played 50 videos (1280x720 mp4) on YouTube, and all played nicely.
This also fixed an other issue I had, where the video was paused after the buffering finished.

@tourettes any ideas?
Cant life without mpar enabled in videos