Channelchange issues, debug logs

[KRA]

Lots of times when changing channels it fails, sometimes I only get sound, but the most common problem is where xbmc just says buffering, and never start to play. Also as you can see from logs, tuning is rather slow, don't know if you can read anything from the logs but I hope so.

I've made some debug logs from xbmc, please note I'm using build from 1.3 api, so if changes has been made regarding this issue at later stage please ignore.

First log: I tune SD channel, works, change to other SD channel, xbmc stuck in buffering
http://dl.dropbox.com/u/35064639/xbmc-sd...fering.txt

another log: First tune HD channel, ok - then change to other HD channel, ok - change to SD channel only get sound
http://dl.dropbox.com/u/35064639/xbmc-hd...unonly.log

another log: First tune HD channel, ok, then change to other HD channel, ok, - change to SD channel, ok - Change to SD channel, stuck in buffering.
http://dl.dropbox.com/u/35064639/xbmc-hd...fering.txt

[sub]

Can you reproduce the issue, then zip and attach the xbmc.log, along with the web.log and nrecord.log?

[sub]

I have seen this a few times myself. I'm pretty sure it's an xbmc issue, because I know I was delivery the full channel transport stream, which included video, yet it only gave me audio.

[KRA]

I'm sure the problem is at xbmc side, I know on other pvr plugins they added delay option probably because of tuning problems. Don't know if that is related to how your plugins works though. I'll try to make log of all 3.

[KRA]

here are the 3 log files, I restarted xbmc in debug mode, and restarted NPVR service then reproduce the problem.

http://dl.dropbox.com/u/35064639/logs.zip

[sub]

In the log you went from 'TV3' to 'MAX'. So TV3 was fine, then what happened with MAX? Was it audio only, or something else?

[KRA]

oh, forgot, no this was the stuck in buffering 0%

tv3 was fine, then change to max and it gets stuck at buffering 0%

[sub]

From the point of view of the nextpvr addon log lines in xbmc.log, there isn't any obvious sign of problems. From the web.log I can see it's starting delivering data to xbmc about second after the channel change.

Unfortunately I'm no expert in reading the rest of the xbmc log messages. I suspect the answer is probably in the first 20-30 lines after the "Creating Demuxer" log message, where there is alot of messages from ffmpeg about the streams that it found, and opening the decoders etc. After the channel change, this area of the logs contains these messages:

18:41:47 T:2861591408 NOTICE: CDVDVideoCodecFFmpeg::Open() Using codec: MPEG-2 video
18:41:47 T:2861591408 DEBUG: FactoryCodec - Video: ff-mpeg2video - Opened
18:41:47 T:2853198704 ERROR: CDVDPlayerVideo::OpenStream - Invalid framerate 90000, using forced 25fps and just trust timestamps

You'd probably need to reproduce the same issue a few times to see if this same type of error in the logs each time you get the buffering issue.

The audio only problem would probably be slightly different, but you'd probably need to track it down the same way to find common log messages when it happens.

[KRA]

I did the test with HD channels (previous 2 are SD), changing between 2 channels, and I got the buffering issue, but cannot find the same invalid framerate error in the log. I stopped the stream when it was buffering, then I also try a SD channel next (TV3) and I got the only sound issue, still not the invalid framerate error.

http://dl.dropbox.com/u/35064639/xbmc1.log

[toricred]

Not sure this matters, but this is happening on a Windows client as well. I don't have access to the XBMC logs quite yet, but I'll post them later if you need them.