home
products
contribute
download
documentation
forum
Home
Forums
New posts
Search forums
What's new
New posts
All posts
Latest activity
Members
Registered members
Current visitors
Donate
Log in
Register
What's new
Search
Search
Search titles only
By:
New posts
Search forums
Search titles only
By:
Menu
Log in
Register
Navigation
Install the app
Install
More options
Contact us
Close Menu
Forums
MediaPortal 1
Support
Watch / Listen Media
Television (MyTV frontend and TV-Server)
Channel switching times increased with 1.4.0
Contact us
RSS
JavaScript is disabled. For a better experience, please enable JavaScript in your browser before proceeding.
You are using an out of date browser. It may not display this or other websites correctly.
You should upgrade or use an
alternative browser
.
Reply to thread
Message
<blockquote data-quote="mm1352000" data-source="post: 1020255" data-attributes="member: 82144"><p>Hello again Razorblade</p><p> </p><p></p><p>On the 12th I see:</p><p></p><p> </p><p>I don't see that entry on the 11th so either the server is still v1.3 at that stage, or something funky is going on if that is really the case.</p><p> </p><p> </p><p> </p><p></p><p>Sure. I mean, if you're convinced that you updated on the 7th and you have some 1.3 client + server logs around then by all means I'd be happy to take a look. That way I can cross-compare and see where the extra time is taken.</p><p> </p><p> </p><p> </p><p></p><p>It is when the TV Server has to actually send a tune request to the hardware and the client has to build or rebuild the player graph. You could consider it like a "worst case" channel change time (though it is not actually the absolute worst case).</p><p>On the server side, it is the difference between an 800 ms change and a 200 ms change.</p><p>On the client side it is harder to quantify, but you can compare for yourself.</p><p> </p><p>Here is the full tune for SAT.1:</p><p>[collapse]2013-08-12 19:16:20.010114 [Info.][MPMain(1)]: TVHome.ViewChannelAndCheck(): View channel=SAT.1</p><p>2013-08-12 19:16:20.652204 [Info.][MPMain(1)]: succeeded<img src="data:image/gif;base64,R0lGODlhAQABAIAAAAAAAP///yH5BAEAAAAALAAAAAABAAEAAAIBRAA7" class="smilie smilie--sprite smilie--sprite5" alt=":confused:" title="Confused :confused:" loading="lazy" data-shortname=":confused:" />ucceeded TvControl.VirtualCard</p><p>2013-08-12 19:16:20.656211 [Info.][MPMain(1)]: tvhome:startplay</p><p>2013-08-12 19:16:20.659216 [Info.][MPMain(1)]: tvhome:file<img src="data:image/gif;base64,R0lGODlhAQABAIAAAAAAAP///yH5BAEAAAAALAAAAAABAAEAAAIBRAA7" class="smilie smilie--sprite smilie--sprite8" alt=":D" title="Big Grin :D" loading="lazy" data-shortname=":D" />:\TV_Timeshift\live9-0.ts.tsbuffer</p><p>2013-08-12 19:16:20.663223 [Warn.][MPMain(1)]: tvhome:startplay. Phase 1 - 9 ms - Done method initialization</p><p>2013-08-12 19:16:20.665226 [Info.][MPMain(1)]: tvhome:startplay:rtsp://WHS-Box:554/stream9.0 - using rtsp mode:True</p><p>2013-08-12 19:16:20.669233 [Info.][MPMain(1)]: g_Player.Play(rtsp://WHS-Box:554/stream9.0 TV)</p><p>2013-08-12 19:16:20.881593 [Info.][MPMain(1)]: TSReaderPlayer play:rtsp://WHS-Box:554/stream9.0 radio:False</p><p>2013-08-12 19:16:20.882595 [Info.][MPMain(1)]: TSReaderPlayer: live tv</p><p>2013-08-12 19:16:20.883597 [Info.][MPMain(1)]: TSReaderPlayer: Enabling DX9 exclusive mode</p><p>2013-08-12 19:16:20.883597 [Info.][MPMain(1)]: TSReaderPlayer<img src="data:image/gif;base64,R0lGODlhAQABAIAAAAAAAP///yH5BAEAAAAALAAAAAABAAEAAAIBRAA7" class="smilie smilie--sprite smilie--sprite7" alt=":p" title="Stick Out Tongue :p" loading="lazy" data-shortname=":p" />lay rtsp://WHS-Box:554/stream9.0</p><p>2013-08-12 19:16:20.890609 [Info.][MPMain(1)]: TSReaderPlayer: GetInterfaces()</p><p>2013-08-12 19:16:20.907638 [Info.][MPMain(1)]: DirectShowUtils: First try to insert new audio renderer Default DirectSound Device</p><p>2013-08-12 19:16:20.993784 [Info.][MPMain(1)]: DirectShowUtils: Found audio renderer</p><p>2013-08-12 19:16:21.070915 [Info.][MPMain(1)]: TSReaderPlayer: Add TsReader to graph</p><p>2013-08-12 19:16:21.071916 [Info.][MPMain(1)]: TSReaderPlayer: Open file: rtsp://WHS-Box:554/stream9.0</p><p>2013-08-12 19:16:21.100966 [Info.][MPMain(1)]: TSReaderPlayer:OnRequestAudioChange()</p><p>2013-08-12 19:16:21.112986 [Info.][MPMain(1)]: TsReaderPlayer: AudioDualMonoMode switching not available. Audioswitcher filter not loaded</p><p>2013-08-12 19:16:21.113988 [Info.][MPMain(1)]: TsReaderPlayer: AudioDualMonoMode switching not available. Audioswitcher filter not loaded</p><p>2013-08-12 19:16:21.113988 [Info.][MPMain(1)]: TsReaderPlayer: AudioDualMonoMode switching not available. Audioswitcher filter not loaded</p><p>2013-08-12 19:16:21.114990 [Info.][MPMain(1)]: Audio stream: switching to preferred AC3 audio stream 1, based on LANG deu</p><p>2013-08-12 19:16:21.115991 [Info.][MPMain(1)]: TsReaderPlayer: AudioDualMonoMode switching not available. Audioswitcher filter not loaded</p><p>2013-08-12 19:16:21.819185 [Info.][MPMain(1)]: TsReaderPlayer: OnVideoFormatChanged - streamtype=MPEG2 resolution=720x576 aspect ratio=16:9 bitrate=15000000 isInterlaced=True</p><p>2013-08-12 19:16:21.827198 [Info.][MPMain(1)]: TSReaderPlayer: Add codecs</p><p>2013-08-12 19:16:22.085637 [Info.][MPMain(1)]: VMR9: added EVR Renderer to graph</p><p>2013-08-12 19:16:22.167776 [Info.][MPMain(1)]: Added filter: CyberLink Video Decoder (PDVD12) to graph</p><p>2013-08-12 19:16:22.176792 [Info.][MPMain(1)]: Added filter: MediaPortal DVBSub3 to graph</p><p>2013-08-12 19:16:22.322038 [Info.][MPMain(1)]: Added filter: LAV Audio Decoder to graph</p><p>2013-08-12 19:16:22.325043 [Info.][MPMain(1)]: TSReaderPlayer: Render TsReader outputs</p><p>2013-08-12 19:16:22.433227 [Info.][MPMain(1)]: TSReaderPlayer: Cleanup Captions</p><p>2013-08-12 19:16:22.485315 [Info.][MPMain(1)]: TSReaderPlayer: OnInitialized</p><p>2013-08-12 19:16:22.485315 [Info.][MPMain(1)]: TSReaderPlayer: position:0, duration:1,1</p><p>2013-08-12 19:16:22.486317 [Info.][MPMain(1)]: g_Player.OnStarted() rtsp://WHS-Box:554/stream9.0 media:TV</p><p>2013-08-12 19:16:22.538405 [Warn.][MPMain(1)]: tvhome:startplay. Phase 2 - 1872 ms - Done starting g_Player.Play()</p><p>2013-08-12 19:16:22.547421 [Info.][MPMain(1)]: tv home init<img src="data:image/gif;base64,R0lGODlhAQABAIAAAAAAAP///yH5BAEAAAAALAAAAAABAAEAAAIBRAA7" class="smilie smilie--sprite smilie--sprite5" alt=":confused:" title="Confused :confused:" loading="lazy" data-shortname=":confused:" />AT.1 done[/collapse]</p><p> </p><p>Note we can see it took roughly 650 ms to tune on the server side so we can guess the hardware had to tune. Then we use a bunch of time adding renderers, codecs and TsReader. All up, it is 2.5 seconds.</p><p> </p><p>Compare that with a change like this to VOX:</p><p>[collapse]2013-08-12 19:17:51.460316 [Info.][MPMain(1)]: TVHome.ViewChannelAndCheck(): View channel=VOX</p><p>2013-08-12 19:17:51.474340 [Info.][MPMain(1)]: TSReaderPlayer<img src="data:image/gif;base64,R0lGODlhAQABAIAAAAAAAP///yH5BAEAAAAALAAAAAABAAEAAAIBRAA7" class="smilie smilie--sprite smilie--sprite7" alt=":p" title="Stick Out Tongue :p" loading="lazy" data-shortname=":p" />ause graph</p><p>2013-08-12 19:17:51.499382 [Info.][MPMain(1)]: TSReaderPlayer: OnZapping :128</p><p>2013-08-12 19:17:51.681692 [Info.][MPMain(1)]: TSReaderPlayer: OnZapping :3</p><p>2013-08-12 19:17:51.682693 [Info.][MPMain(1)]: succeeded<img src="data:image/gif;base64,R0lGODlhAQABAIAAAAAAAP///yH5BAEAAAAALAAAAAABAAEAAAIBRAA7" class="smilie smilie--sprite smilie--sprite5" alt=":confused:" title="Confused :confused:" loading="lazy" data-shortname=":confused:" />ucceeded TvControl.VirtualCard</p><p>2013-08-12 19:17:51.682693 [Info.][MPMain(1)]: tvhome<img src="data:image/gif;base64,R0lGODlhAQABAIAAAAAAAP///yH5BAEAAAAALAAAAAABAAEAAAIBRAA7" class="smilie smilie--sprite smilie--sprite5" alt=":confused:" title="Confused :confused:" loading="lazy" data-shortname=":confused:" />eektoEnd(89,4697709/89,537),True,rtsp=True</p><p>2013-08-12 19:17:51.683695 [Info.][MPMain(1)]: TsReaderPlayer:seekabs:895370000 start:0 end:895370000</p><p>2013-08-12 19:17:51.839960 [Info.][MPMain(1)]: TsReaderPlayer: pos: 895370000 start:0 end:895370000</p><p>2013-08-12 19:17:51.839960 [Info.][MPMain(1)]: TsReaderPlayer seek done:0</p><p>2013-08-12 19:17:51.840962 [Info.][MPMain(1)]: TSReaderPlayer: current pos:89,537 dur:89,537</p><p>2013-08-12 19:17:51.840962 [Info.][MPMain(1)]: TSReaderPlayer:Continue graph</p><p>2013-08-12 19:17:52.049316 [Info.][MPMain(1)]: TSReaderPlayer:OnRequestAudioChange()</p><p>2013-08-12 19:17:52.053322 [Info.][MPMain(1)]: TsReaderPlayer: AudioDualMonoMode switching not available. Audioswitcher filter not loaded</p><p>2013-08-12 19:17:52.054324 [Info.][MPMain(1)]: TsReaderPlayer: AudioDualMonoMode switching not available. Audioswitcher filter not loaded</p><p>2013-08-12 19:17:52.054324 [Info.][MPMain(1)]: Audio stream: switching to preferred AC3/MPEG audio stream 0 (only 1 track avail.)</p><p>2013-08-12 19:17:52.056327 [Info.][MPMain(1)]: TsReaderPlayer: AudioDualMonoMode switching not available. Audioswitcher filter not loaded</p><p>2013-08-12 19:17:52.451999 [Info.][MPMain(1)]: Rerendering audio pin of tsreader filter.</p><p>2013-08-12 19:17:52.453001 [Info.][MPMain(1)]: Disconnecting all pins from filter LAV Audio Decoder</p><p>2013-08-12 19:17:52.454002 [Info.][MPMain(1)]: Disconnecting pin Output</p><p>2013-08-12 19:17:52.454002 [Info.][MPMain(1)]: Disconnecting all pins from filter Default DirectSound Device</p><p>2013-08-12 19:17:52.456006 [Info.][MPMain(1)]: Added filter: LAV Audio Decoder to graph</p><p>2013-08-12 19:17:52.695412 [Info.][MPMain(1)]: Reconfigure graph done[/collapse]</p><p> </p><p>It took approximately 200 ms for the server to do its thing, so we can tell the hardware did not have to tune.</p><p>Then the audio codec had to be reconfigured... but that is much faster than rebuilding the graph. All up, change time of 1.2 seconds or so.</p><p> </p><p>So, not all channel changes can be directly compared because the work required for MP to change the channel varies.</p><p> </p><p>mm</p></blockquote><p></p>
[QUOTE="mm1352000, post: 1020255, member: 82144"] Hello again Razorblade On the 12th I see: I don't see that entry on the 11th so either the server is still v1.3 at that stage, or something funky is going on if that is really the case. Sure. I mean, if you're convinced that you updated on the 7th and you have some 1.3 client + server logs around then by all means I'd be happy to take a look. That way I can cross-compare and see where the extra time is taken. It is when the TV Server has to actually send a tune request to the hardware and the client has to build or rebuild the player graph. You could consider it like a "worst case" channel change time (though it is not actually the absolute worst case). On the server side, it is the difference between an 800 ms change and a 200 ms change. On the client side it is harder to quantify, but you can compare for yourself. Here is the full tune for SAT.1: [collapse]2013-08-12 19:16:20.010114 [Info.][MPMain(1)]: TVHome.ViewChannelAndCheck(): View channel=SAT.1 2013-08-12 19:16:20.652204 [Info.][MPMain(1)]: succeeded:confused:ucceeded TvControl.VirtualCard 2013-08-12 19:16:20.656211 [Info.][MPMain(1)]: tvhome:startplay 2013-08-12 19:16:20.659216 [Info.][MPMain(1)]: tvhome:file:D:\TV_Timeshift\live9-0.ts.tsbuffer 2013-08-12 19:16:20.663223 [Warn.][MPMain(1)]: tvhome:startplay. Phase 1 - 9 ms - Done method initialization 2013-08-12 19:16:20.665226 [Info.][MPMain(1)]: tvhome:startplay:rtsp://WHS-Box:554/stream9.0 - using rtsp mode:True 2013-08-12 19:16:20.669233 [Info.][MPMain(1)]: g_Player.Play(rtsp://WHS-Box:554/stream9.0 TV) 2013-08-12 19:16:20.881593 [Info.][MPMain(1)]: TSReaderPlayer play:rtsp://WHS-Box:554/stream9.0 radio:False 2013-08-12 19:16:20.882595 [Info.][MPMain(1)]: TSReaderPlayer: live tv 2013-08-12 19:16:20.883597 [Info.][MPMain(1)]: TSReaderPlayer: Enabling DX9 exclusive mode 2013-08-12 19:16:20.883597 [Info.][MPMain(1)]: TSReaderPlayer:play rtsp://WHS-Box:554/stream9.0 2013-08-12 19:16:20.890609 [Info.][MPMain(1)]: TSReaderPlayer: GetInterfaces() 2013-08-12 19:16:20.907638 [Info.][MPMain(1)]: DirectShowUtils: First try to insert new audio renderer Default DirectSound Device 2013-08-12 19:16:20.993784 [Info.][MPMain(1)]: DirectShowUtils: Found audio renderer 2013-08-12 19:16:21.070915 [Info.][MPMain(1)]: TSReaderPlayer: Add TsReader to graph 2013-08-12 19:16:21.071916 [Info.][MPMain(1)]: TSReaderPlayer: Open file: rtsp://WHS-Box:554/stream9.0 2013-08-12 19:16:21.100966 [Info.][MPMain(1)]: TSReaderPlayer:OnRequestAudioChange() 2013-08-12 19:16:21.112986 [Info.][MPMain(1)]: TsReaderPlayer: AudioDualMonoMode switching not available. Audioswitcher filter not loaded 2013-08-12 19:16:21.113988 [Info.][MPMain(1)]: TsReaderPlayer: AudioDualMonoMode switching not available. Audioswitcher filter not loaded 2013-08-12 19:16:21.113988 [Info.][MPMain(1)]: TsReaderPlayer: AudioDualMonoMode switching not available. Audioswitcher filter not loaded 2013-08-12 19:16:21.114990 [Info.][MPMain(1)]: Audio stream: switching to preferred AC3 audio stream 1, based on LANG deu 2013-08-12 19:16:21.115991 [Info.][MPMain(1)]: TsReaderPlayer: AudioDualMonoMode switching not available. Audioswitcher filter not loaded 2013-08-12 19:16:21.819185 [Info.][MPMain(1)]: TsReaderPlayer: OnVideoFormatChanged - streamtype=MPEG2 resolution=720x576 aspect ratio=16:9 bitrate=15000000 isInterlaced=True 2013-08-12 19:16:21.827198 [Info.][MPMain(1)]: TSReaderPlayer: Add codecs 2013-08-12 19:16:22.085637 [Info.][MPMain(1)]: VMR9: added EVR Renderer to graph 2013-08-12 19:16:22.167776 [Info.][MPMain(1)]: Added filter: CyberLink Video Decoder (PDVD12) to graph 2013-08-12 19:16:22.176792 [Info.][MPMain(1)]: Added filter: MediaPortal DVBSub3 to graph 2013-08-12 19:16:22.322038 [Info.][MPMain(1)]: Added filter: LAV Audio Decoder to graph 2013-08-12 19:16:22.325043 [Info.][MPMain(1)]: TSReaderPlayer: Render TsReader outputs 2013-08-12 19:16:22.433227 [Info.][MPMain(1)]: TSReaderPlayer: Cleanup Captions 2013-08-12 19:16:22.485315 [Info.][MPMain(1)]: TSReaderPlayer: OnInitialized 2013-08-12 19:16:22.485315 [Info.][MPMain(1)]: TSReaderPlayer: position:0, duration:1,1 2013-08-12 19:16:22.486317 [Info.][MPMain(1)]: g_Player.OnStarted() rtsp://WHS-Box:554/stream9.0 media:TV 2013-08-12 19:16:22.538405 [Warn.][MPMain(1)]: tvhome:startplay. Phase 2 - 1872 ms - Done starting g_Player.Play() 2013-08-12 19:16:22.547421 [Info.][MPMain(1)]: tv home init:confused:AT.1 done[/collapse] Note we can see it took roughly 650 ms to tune on the server side so we can guess the hardware had to tune. Then we use a bunch of time adding renderers, codecs and TsReader. All up, it is 2.5 seconds. Compare that with a change like this to VOX: [collapse]2013-08-12 19:17:51.460316 [Info.][MPMain(1)]: TVHome.ViewChannelAndCheck(): View channel=VOX 2013-08-12 19:17:51.474340 [Info.][MPMain(1)]: TSReaderPlayer:pause graph 2013-08-12 19:17:51.499382 [Info.][MPMain(1)]: TSReaderPlayer: OnZapping :128 2013-08-12 19:17:51.681692 [Info.][MPMain(1)]: TSReaderPlayer: OnZapping :3 2013-08-12 19:17:51.682693 [Info.][MPMain(1)]: succeeded:confused:ucceeded TvControl.VirtualCard 2013-08-12 19:17:51.682693 [Info.][MPMain(1)]: tvhome:confused:eektoEnd(89,4697709/89,537),True,rtsp=True 2013-08-12 19:17:51.683695 [Info.][MPMain(1)]: TsReaderPlayer:seekabs:895370000 start:0 end:895370000 2013-08-12 19:17:51.839960 [Info.][MPMain(1)]: TsReaderPlayer: pos: 895370000 start:0 end:895370000 2013-08-12 19:17:51.839960 [Info.][MPMain(1)]: TsReaderPlayer seek done:0 2013-08-12 19:17:51.840962 [Info.][MPMain(1)]: TSReaderPlayer: current pos:89,537 dur:89,537 2013-08-12 19:17:51.840962 [Info.][MPMain(1)]: TSReaderPlayer:Continue graph 2013-08-12 19:17:52.049316 [Info.][MPMain(1)]: TSReaderPlayer:OnRequestAudioChange() 2013-08-12 19:17:52.053322 [Info.][MPMain(1)]: TsReaderPlayer: AudioDualMonoMode switching not available. Audioswitcher filter not loaded 2013-08-12 19:17:52.054324 [Info.][MPMain(1)]: TsReaderPlayer: AudioDualMonoMode switching not available. Audioswitcher filter not loaded 2013-08-12 19:17:52.054324 [Info.][MPMain(1)]: Audio stream: switching to preferred AC3/MPEG audio stream 0 (only 1 track avail.) 2013-08-12 19:17:52.056327 [Info.][MPMain(1)]: TsReaderPlayer: AudioDualMonoMode switching not available. Audioswitcher filter not loaded 2013-08-12 19:17:52.451999 [Info.][MPMain(1)]: Rerendering audio pin of tsreader filter. 2013-08-12 19:17:52.453001 [Info.][MPMain(1)]: Disconnecting all pins from filter LAV Audio Decoder 2013-08-12 19:17:52.454002 [Info.][MPMain(1)]: Disconnecting pin Output 2013-08-12 19:17:52.454002 [Info.][MPMain(1)]: Disconnecting all pins from filter Default DirectSound Device 2013-08-12 19:17:52.456006 [Info.][MPMain(1)]: Added filter: LAV Audio Decoder to graph 2013-08-12 19:17:52.695412 [Info.][MPMain(1)]: Reconfigure graph done[/collapse] It took approximately 200 ms for the server to do its thing, so we can tell the hardware did not have to tune. Then the audio codec had to be reconfigured... but that is much faster than rebuilding the graph. All up, change time of 1.2 seconds or so. So, not all channel changes can be directly compared because the work required for MP to change the channel varies. mm [/QUOTE]
Insert quotes…
Verification
Post reply
Forums
MediaPortal 1
Support
Watch / Listen Media
Television (MyTV frontend and TV-Server)
Channel switching times increased with 1.4.0
Contact us
RSS
Top
Bottom
