Skipping issue on PCH

[Sheik Yerbouti]

OK, I did some more testing and I've got some logs (putty included). I watched and skipped back and forth and stopped watching around 40 minutes. Next I resumed, it went to the right spot in the video, but the current time showed 00:00:00. I stopped again and resumed again. At that time the start time was negative: -04:36:36. I stopped again, and resumed again and mvpmcx2 crashed.

Martin, I hope these logs can help improve the skipping.

Chris

[mvallevand]

Chris it doesn't look like you increased the pre-resume delay? Maybe start with 750 and move up from there.

Martin

[bgowland]

I want both so try

Code:

sh -c /etc/mvpmc/startmeup &>/etc/mvpmc/foobar &

I had a look at this again and it seems the first '&' should be a '2' (according to my existing 'sh' line in npvr.cgi). I now have...

Code:

sh -c /etc/mvpmc/startmeup 2>/etc/mvpmc/mvpmcx2.log &

...and it has created the mvpmcx2.log file on my mvpmc share and successfully started npvr on the PCH. Just about to test and will zip and upload everything when I get a drop to the Recordings menu.

Cheers,
Brian

[mvallevand]

Hi Brian, the 2 is for stderr, I also want stdout so you need to add a second option > /etc/mvpmc/mvpmcx1.log

I thought ampersand would get both to one file but it is not supported on the PCH's version of busybox

Martin

[bgowland]

OK - I've got it now hopefully. The following successfully starts npvr on the PCH and creates both log files...

Code:

sh -c /etc/mvpmc/startmeup 2>/etc/mvpmc/mvpmcx2-stderr.log >/etc/mvpmc/mvpmcx2-stdout.log &

...I'll report back when I've got something.

[bgowland]

OK - true to form for a 1 hour programme where a drop back to Recordings seems to occur when skipping after about 40mins in when trying to get past adverts, it happened at 46mins 21secs (according to the OSD timeline).

Time in the MVP.log is...

Code:

2011-09-14 01:56:32.620    [DEBUG][3]    User pressed: Right

Hopefully I've got everything in the attached zip - the web.log had just rolled over so I've included the web.log.1 also in case it's needed.

Cheers,
Brian

[mvallevand]

Yes I see the demux stall and the Stop safety take over and this is where resume should work if you were to go right back in

I do see this in user logs and I can only really equate it to hitting next/prev extremely aggressively earlier in the session like this:

00:39:23 Received 534937600 request to seek to 1798 seconds 4013 duration
00:39:28 Received 563527680 request to seek to 1889 seconds 4013 duration
00:39:31 Received 591200256 request to seek to 1979 seconds 4013 duration
00:39:36 Received 620462080 request to seek to 2071 seconds 4013 duration
00:39:40 Received 603029504 request to seek to 2012 seconds 4013 duration
00:39:43 Received 592461824 request to seek to 1982 seconds 4013 duration
00:39:46 Received 607305728 request to seek to 2027 seconds 4013 duration
00:39:49 Received 598491136 request to seek to 1998 seconds 4013 duration

I suspect the sdk for the demux has memory bugs dealing with NPVR style navigation

Martin

[BrettB]

Hi Brian, the 2 is for stderr, I also want stdout so you need to add a second option > /etc/mvpmc/mvpmcx1.log

I thought ampersand would get both to one file but it is not supported on the PCH's version of busybox

Here's the syntax Martin gave me to use. I think that it gets everything he needs, since I frequently send him logs.

Code:

sh -c /etc/mvpmc/startmeup >/tmp/mvpmcx2.txt 2>&1 &

[bgowland]

I do see this in user logs and I can only really equate it to hitting next/prev extremely aggressively earlier in the session like this:

I find it interesting that you consider those 'requests to seek' as extremely aggressive. When I skip I press and wait for screen update to gauge whether I'm still in advert break or I've gone too far etc.

Looking at the timing for when I pressed the buttons on the remote, the gaps are 5s, 3s, 5s, 4s, 3s, 3s, 3s - a total of 7 in 26 seconds, is that aggressive? I'm mindful of the possibility that pressing a skip button repeatedly in the space of a couple of seconds may have a detrimental effect but that's counter-effective to me anyway as, like I said, I want to check after each button press to see if I've gone too far and need to skip back or if I need to skip forward again.

The crucial question, of course, is why this single press caused the Stop :confused: ...

00:56:35 Received 868155392 request to seek to 2870 seconds 4013 duration

[mvallevand]

Looking at the timing for when I pressed the buttons on the remote, the gaps are 5s, 3s, 5s, 4s, 3s, 3s, 3s - a total of 7 in 26 seconds, is that aggressive? I'm mindful of the

In the terms of the PCH agressive but certainly not crazy or extreme. I am simply explainly I see the most problem with the demux after this behaviour It takes about 2 seconds (or more) do do a seek given the delayed response of the network so that is 3, 1, 3, 2, 1, 1, 1 basically hitting the screen as soon as their is something perceptible that you don't like. With all of this there is still background buffering and streaming still going on that you aren't even aware of, so those ones are close to zero. I could likely tweak the demux buffer to reduce the risk, but there would be stuttering.

possibility that pressing a skip button repeatedly in the space of a couple of seconds may have a detrimental effect but that's counter-effective to me anyway as, like I said, I want to check after each button press to see if I've gone too far and need to skip back or if I need to skip forward again.

It's saying nothing about you, it is how this trick mode is being processed on the PCH and the fact that I know it can cause problems.

The crucial question, of course, is why this single press caused the Stop :confused: ...

Asked and answered already, the demux get stuck in the file and I force mvpmcx2 to stop so you can safely restart at the same point it got stuck

Code:

A pause in streaming in the web log is usually (the error is just streaming ending)
2011-09-14 01:56:32.745    [DEBUG][3]    RollingFile.Seek(868155392)
2011-09-14 01:56:32.745    [DEBUG][3]    about to read 200000 from location 868155392  (current length = 1196343264)
2011-09-14 01:56:32.761    [DEBUG][3]    about to read 200000 from location 868355392  (current length = 1196343264)
2011-09-14 01:56:36.414    [ERROR][3]    Unexpected error streaming file: System.Net.Sockets.SocketException: An existing connection was forcibly closed by the remote host

Confirmed with PTS in the client side not move showing the frozen demux

00:56:35 Received request to seek to 2870 seconds 4013 duration
time seek 2870
seeking to 2870 s, pos 666157056 position 47962446048 factor 3172507728809353632 Timing 868155392
Waited 0 00:56:35 OSD update took 0.1 seconds
00:56:35 Stuck at 0 63193 PTS 2781
00:56:36 Stuck at 1 63193 PTS 2781
00:56:37 Stuck at 2 63193 PTS 2781
00:56:38 Stuck at 3 63193 PTS 2781
Forced stop

I have some code to silently resume behind the scenes that should be triggered I was hoping to see why it didn't work. Again this is to get around what I consider a problem with the SDK and not your behaviour.

Martin