TV-Server Version: 1.0.0.21149
MediaPortal Version: 1.0.0.21149
MediaPortal Skin: Blue3
Windows Version: Win XP MCE SP3
CPU Type: Intel P4 Nw 2.2 GHz
HDD: 1: Seagate 200 GB, 2: WD 250 GB, 3: WD 250 GB
Memory: 512 MB + 2x 256 MB PC-2700
Motherboard: Gigabyte 8PE667U
Video Card: ATI Radeon 9800 Pro w. 128 MB RAM
Video Card Driver: Catalyst v8.12
Sound Card: Creative Soundblaster Audigy 2 ZS
Sound Card AC3:
Sound Card Driver: 6.0.1.1361
1. TV Card: Hauppauge PVR 500 MCE
1. TV Card Type: Dual analogue tuners
1. TV Card Driver: 2.0.48.25037
2. TV Card:
2. TV Card Type:
2. TV Card Driver:
3. TV Card:
3. TV Card Type:
3. TV Card Driver:
4. TV Card:
4. TV Card Type:
4. TV Card Driver:
MPEG2 Video Codec: MPV Decoder Filter
MPEG2 Audio Codec: MPA Decoder Filter
h.264 Video Codec: ffdshow Video Decoder
Satelite/CableTV Provider:
HTPC Case: Old Piece of Trash™
Cooling: Zalman CNPS7000A-AlCu & VF1000 LED & NB47J
Power Supply: Nexus NX-3000 (300W)
Remote:
TV:
TV - HTPC Connection:
I am new to MediaPortal, so I need some help troubleshooting an issue that has annoyed me since I first tried out my new TV-watching-experience. I have come across several threads describing much the same problem, but most have been reduced to guesses without any reports of a real solution - I hope this will be different.
My channel change times are very long - usually in excess of 5 seconds. I have tried to break down the problem by looking at log files, but I have no idea what times are to be expected and what all the stuff that is going on in the log file is all about let alone how to resolve the problems that I have identified. It would be great if somebody could point to exactly which parts of the logs show excessive times and what I can do to counter the particular problems that they may represent.
To start things off I have grabbed an example from a log generated during one of my recent sessions - a generic channel switch. This can be found in attatched old_logs.zip. Another set of logs made with the MediaPortal Debug mode is also attatched for further elaboration.
mediaportal.log says button press was registered at 02:39:30.791438
vmr9.log says presentation started again at 02:39:36.025
This is a total of ~5.234 secs, which corresponds pretty well with the times i generally experience on changing channel. So I had an in-depth look at it:
Two things especially bother me about this: The events at 02:39:30.978938 and 02:39:33.838313. Each last 2.59375 secs and 1.546875 - without them the total change time would be ~1.093 secs which, to me, would be better than the expected total of 1-2 secs. So I am really interested in what is hiding behind those events and times.
For greater detail I took a look at the tv.log file - it held no record for the initial "Navigator:ZapPrevious" time consumption, so I am guessing that is client-side and registered in a log I could not find. However it did give a better idea of what was going on with the "TSReaderPlayer
ause graph".
(I refrained from pasting my tv.log snippet here - would take up too much room
The tv.log represents a time frame of 1.671875 - only some 30% of the total channel change time. However there are also a few times that seem out of the ordinary. In particular the following three lines seemed to use up a lot of time. However I have no clue whether this is normal and what can be done to improve those times.
02:39:33.994563 0.171875 card: user: mediaportal:1:0 tune tv
portsNyhederne Freq:0 Channel:89 Country
enmark Tuner:Cable Video:Tuner
02:39:34.713313 0.40625 card: WaitForTimeShiftFile - waiting _eventAudio & _eventVideo
02:39:35.150813 0.21875 card: WaitForTimeShiftFile - video and audio are seen after 0,421875 seconds
The three together make up 0.796875 secs which is just short of half of the total time represented in the tv.log
I am guessing that the vmr9.log shows that the MediaPortal client shuts down the display of the video stream while the server is changing the channel. When
compared to the other log files it seems the presentation is stopped while the MediaPlayer.log reports the "TSReaderPlayer
ause graph" and the tv.log reports
that it is happening just before the "Controller: StartTimeShifting TV 2 15" is happening, which does not seem to coincide with any of the big time consumers in
the tv.log. It is difficult for me to assess whether this means something without a bit more insight into how this works
tv.log end 02:39:35.400813
MediaPortal.log end 02:39:35.478938 +0.078125
vmr9.log end 02:39:36.025 +0.546062
I am wondering what is going on during the time that passes while the tv.log and MediaPortal.log is done reporting and I am waiting to see the picture on my
screen as I am guessing the vmr9.log reports more than half a second later
Codecs does not seem to be a problem - I have changed between several different sets and channel change times doesn't really get lower.
I have also experimented with placement and setup of timeshift files, which also seemed to have no direct effect on the problem.
Can anybody explain to me what is going on?
MediaPortal Version: 1.0.0.21149
MediaPortal Skin: Blue3
Windows Version: Win XP MCE SP3
CPU Type: Intel P4 Nw 2.2 GHz
HDD: 1: Seagate 200 GB, 2: WD 250 GB, 3: WD 250 GB
Memory: 512 MB + 2x 256 MB PC-2700
Motherboard: Gigabyte 8PE667U
Video Card: ATI Radeon 9800 Pro w. 128 MB RAM
Video Card Driver: Catalyst v8.12
Sound Card: Creative Soundblaster Audigy 2 ZS
Sound Card AC3:
Sound Card Driver: 6.0.1.1361
1. TV Card: Hauppauge PVR 500 MCE
1. TV Card Type: Dual analogue tuners
1. TV Card Driver: 2.0.48.25037
2. TV Card:
2. TV Card Type:
2. TV Card Driver:
3. TV Card:
3. TV Card Type:
3. TV Card Driver:
4. TV Card:
4. TV Card Type:
4. TV Card Driver:
MPEG2 Video Codec: MPV Decoder Filter
MPEG2 Audio Codec: MPA Decoder Filter
h.264 Video Codec: ffdshow Video Decoder
Satelite/CableTV Provider:
HTPC Case: Old Piece of Trash™
Cooling: Zalman CNPS7000A-AlCu & VF1000 LED & NB47J
Power Supply: Nexus NX-3000 (300W)
Remote:
TV:
TV - HTPC Connection:
I am new to MediaPortal, so I need some help troubleshooting an issue that has annoyed me since I first tried out my new TV-watching-experience. I have come across several threads describing much the same problem, but most have been reduced to guesses without any reports of a real solution - I hope this will be different.
My channel change times are very long - usually in excess of 5 seconds. I have tried to break down the problem by looking at log files, but I have no idea what times are to be expected and what all the stuff that is going on in the log file is all about let alone how to resolve the problems that I have identified. It would be great if somebody could point to exactly which parts of the logs show excessive times and what I can do to counter the particular problems that they may represent.
To start things off I have grabbed an example from a log generated during one of my recent sessions - a generic channel switch. This can be found in attatched old_logs.zip. Another set of logs made with the MediaPortal Debug mode is also attatched for further elaboration.
mediaportal.log says button press was registered at 02:39:30.791438
vmr9.log says presentation started again at 02:39:36.025
This is a total of ~5.234 secs, which corresponds pretty well with the times i generally experience on changing channel. So I had an in-depth look at it:
Code:
** MediaPortal.log snippet begin **
2009-02-10 02:39:30.791438 [Info.][MPMain]: TVHome:OnPreviousChannel()
[COLOR="Red"]2009-02-10 02:39:30.978938 [Info.][MPMain]: Navigator:ZapPrevious TV 2 Zulu->TV 2[/COLOR]
2009-02-10 02:39:33.572688 [Info.][MPMain]: Channel change:TV 2
2009-02-10 02:39:33.572688 [Info.][MPMain]: TVHome.ViewChannelAndCheck(): View channel=TV 2
[COLOR="Red"]2009-02-10 02:39:33.838313 [Info.][MPMain]: TSReaderPlayer:Pause graph[/COLOR]
2009-02-10 02:39:35.385188 [Info.][MPMain]: tvhome:SeektoEnd(True, rtsp=False
2009-02-10 02:39:35.400813 [Info.][MPMain]: TsReaderPlayer:seekabs:648070000 start:2980000 end:648070000
2009-02-10 02:39:35.478938 [Info.][MPMain]: TsReaderPlayer seek done:0
2009-02-10 02:39:35.478938 [Info.][MPMain]: TSReaderPlayer: current pos:64,509 dur:64,509
2009-02-10 02:39:35.478938 [Info.][MPMain]: TSReaderPlayer:Continue graph
2009-02-10 02:39:35.478938 [Info.][MPMain]: succeeded:Succeeded TvControl.VirtualCard
** MediaPortal.log snippet end **
Two things especially bother me about this: The events at 02:39:30.978938 and 02:39:33.838313. Each last 2.59375 secs and 1.546875 - without them the total change time would be ~1.093 secs which, to me, would be better than the expected total of 1-2 secs. So I am really interested in what is hiding behind those events and times.
For greater detail I took a look at the tv.log file - it held no record for the initial "Navigator:ZapPrevious" time consumption, so I am guessing that is client-side and registered in a log I could not find. However it did give a better idea of what was going on with the "TSReaderPlayer
(I refrained from pasting my tv.log snippet here - would take up too much room
The tv.log represents a time frame of 1.671875 - only some 30% of the total channel change time. However there are also a few times that seem out of the ordinary. In particular the following three lines seemed to use up a lot of time. However I have no clue whether this is normal and what can be done to improve those times.
02:39:33.994563 0.171875 card: user: mediaportal:1:0 tune tv
02:39:34.713313 0.40625 card: WaitForTimeShiftFile - waiting _eventAudio & _eventVideo
02:39:35.150813 0.21875 card: WaitForTimeShiftFile - video and audio are seen after 0,421875 seconds
The three together make up 0.796875 secs which is just short of half of the total time represented in the tv.log
Code:
** vmr9.log snippet begin **
10-02-2009 02:39:33.869 [a74]vmr9:StopPresenting()
10-02-2009 02:39:36.025 [69c]vmr9:StartPresenting()
** vmr9.log snippet end **
I am guessing that the vmr9.log shows that the MediaPortal client shuts down the display of the video stream while the server is changing the channel. When
compared to the other log files it seems the presentation is stopped while the MediaPlayer.log reports the "TSReaderPlayer
that it is happening just before the "Controller: StartTimeShifting TV 2 15" is happening, which does not seem to coincide with any of the big time consumers in
the tv.log. It is difficult for me to assess whether this means something without a bit more insight into how this works
tv.log end 02:39:35.400813
MediaPortal.log end 02:39:35.478938 +0.078125
vmr9.log end 02:39:36.025 +0.546062
I am wondering what is going on during the time that passes while the tv.log and MediaPortal.log is done reporting and I am waiting to see the picture on my
screen as I am guessing the vmr9.log reports more than half a second later
Codecs does not seem to be a problem - I have changed between several different sets and channel change times doesn't really get lower.
I have also experimented with placement and setup of timeshift files, which also seemed to have no direct effect on the problem.
Can anybody explain to me what is going on?