Testing help needed for Myth 0.25 support

Reset the git repository as per above but no change. Is anyone else able to skip adverts?

This was the same file and location played after the latest change. Any suggestions?

23:17:39 T:140614185027328 DEBUG: CheckAutoSceneSkip - Clock in commercial break [00:47:13.520 - 00:48:21.920]: 00:47:13.541. Automatically skipping to end of commercial break (only done once per break)
23:17:39 T:140614185027328 DEBUG: demuxer seek to: 2901921
23:17:39 T:140614185027328 DEBUG: Seek - seek to pos 0, whence 16
23:17:39 T:140614185027328 DEBUG: Seek - seek to pos 0, whence 0
23:17:39 T:140614185027328 DEBUG: Seek - seek to pos 3203005632, whence 0
23:17:39 T:140614185027328 DEBUG: Seek - seek to pos 3203003564, whence 0
23:17:39 T:140614539102080 DEBUG: ------ Window Init (DialogSeekBar.xml) ------
23:17:39 T:140614539102080 DEBUG: Alloc resources: 0.06ms (0.00 ms skin load)
23:17:39 T:140614185027328 DEBUG: Seek - seek to pos 3202999428, whence 0
23:17:39 T:140614185027328 DEBUG: Seek - seek to pos 2145847040, whence 0
23:17:39 T:140614185027328 DEBUG: Seek - seek to pos 2172014196, whence 0
23:17:39 T:140614185027328 DEBUG: Seek - seek to pos 2171509980, whence 0
23:17:39 T:140614185027328 DEBUG: Seek - seek to pos 2171230800, whence 0
23:17:39 T:140614185027328 DEBUG: Seek - seek to pos 2171331944, whence 0
23:17:39 T:140614185027328 DEBUG: Seek - seek to pos 2171372928, whence 0
23:17:39 T:140614185027328 DEBUG: Seek - seek to pos 2171349804, whence 0
23:17:39 T:140614185027328 DEBUG: Seek - seek to pos 2171347360, whence 0
23:17:39 T:140614185027328 DEBUG: Seek - seek to pos 2171347172, whence 0
23:17:39 T:140614185027328 DEBUG: SeekTime - seek ended up on time 2901835
23:17:39 T:140614185027328 DEBUG: demuxer seek to: 2901921, success
23:17:42 T:140614539102080 DEBUG: ------ Window Deinit (DialogSeekBar.xml) ------
23:17:47 T:140613731215104 WARNING: CDVDMessageQueue(audio)::Get - asked for new data packet, with nothing available
23:17:47 T:140613731215104 DEBUG: CDVDAudio::Drain - adding 1232 bytes of silence, buffer size: 2608, chunk size: 3840
23:17:57 T:140614176634624 DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_SYNCHRONIZE
23:17:57 T:140614176634624 DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_RESYNC(2902120000.000002, 1)
23:17:57 T:140614176634624 WARNING: CDVDMessageQueue(video)::Get - asked for new data packet, with nothing available
23:17:57 T:140614176634624 DEBUG: CPullupCorrection: pattern lost on diff 68519999.999997
23:17:57 T:140614185027328 DEBUG: CDVDPlayer::HandleMessages - player started 2
23:17:57 T:140614185027328 DEBUG: CDVDPlayer::SetCaching - caching state 2
23:17:57 T:140614185027328 DEBUG: CDVDPlayer::SetCaching - caching state 3
23:17:57 T:140614185027328 DEBUG: CDVDPlayer::HandleMessages - player started 2
23:17:57 T:140614176634624 INFO: CDVDPlayerVideo - Stillframe detected, switching to forced 25.000000 fps
23:18:02 T:140614176634624 DEBUG: CPullupCorrection: detected pattern of length 1: 40000.00, frameduration: 40000.000000
23:18:04 T:140614539102080 DEBUG: ------ Window Init (VideoOSD.xml) ------
23:18:04 T:140614539102080 INFO: Loading skin file: VideoOSD.xml
23:18:04 T:140614539102080 DEBUG: Load VideoOSD.xml: 1.71ms
23:18:04 T:140614539102080 DEBUG: Alloc resources: 2.41ms (1.77 ms skin load)
23:18:04 T:140614539102080 DEBUG: ------ Window Init (Pointer.xml) ------
23:18:15 T:140614539102080 DEBUG: SDLKeyboard: scancode: 25, sym: 0132, unicode: 0000, modifier: 0
23:18:15 T:140614539102080 DEBUG: OnKey: leftctrl (f0d0) pressed, action is
23:18:15 T:140614539102080 DEBUG: SDLKeyboard: scancode: 40, sym: 0134, unicode: 0000, modifier: 40
23:18:15 T:140614539102080 DEBUG: OnKey: ctrl-leftalt (1f0d4) pressed, action is
23:18:15 T:140614539102080 DEBUG: ------ Window Deinit (Pointer.xml) ------
23:18:15 T:140614539102080 DEBUG: ------ Window Init (Pointer.xml) ------
23:18:20 T:140614539102080 DEBUG: ------ Window Deinit (Pointer.xml) ------
23:18:20 T:140614539102080 DEBUG: ------ Window Deinit (VideoOSD.xml) ------

I tested this yesterday and it worked great! I pulled before the rebase though - the last commit I picked up from you was "Testing: copy the control verison to the connection version as it was hard-coded to 8."

I'm on ubuntu 12.04 (precise), x86-64. Here's what I tested:
- lists of recordings/channels look right
- watching recordings (with commercial skip) worked
- watching live tv worked

Hopefully that's a useful data point. Thanks for implementing this!

Is it possible to disable commercial skipping?

@rwats2011nz, can you please create a ticket at http://trac.xbmc.org/ for the problem with seeking and attach a full debug log file there. Does the problem also exists when skipping normally?

The errors that you are seeing in the logs are the same as the errors some others have experienced when I was going through the forum a couple of nights ago. I'm not sure what has changed in XBMC dvdplayer that might affect that. It's possible there could be a bug in the Myth related seeking that only gets triggered in certain circumstances.

The problem only seems to affect some people. The large number of Seek attempts and large seek numbers looks suspicious.

There is no way to disable commercial skipping through configuration. If you want I can send you a patch to disable it through a small code change.

Latest test. We watched the start of a recording it got to the first commericial and then dropped out. We were getting lots of jitter too..

Log here: http://pastebin.com/0F6aP1pc

@rdoac, yeah that's a nasty looking log file. All the discontinuities and Seek statements will be causing a bit of havoc. If possible can you try playback of that same recording via SMB or off the local disc if XBMC and MythTV are on the same machine. For other users that worked which means it is definitely related to the transmission of data via the myth:// protocol.

Please raise a trac ticket and attach that log file. The discontinuities looks like the main cause of problems.

I'll open a ticket later today and add these log entries. I'd definitely like the patch to disable commerical skipping as well as its kind of impacting the WAF at the moment...

Thank you!

@rwats2011nz, http://s3.teirney.net/xbmc/patches/turn-...skip.patch

@rwats2011nz, not sure if seeking and playback has been fine with tsp42's PVR Addon for you prior to updating to Myth 0.25. I noticed one difference in the file transfer area in tsp42's version of libcmyth. I've just pushed another update to my repository that should match the FileTransfer mode in tsp42's PVR Addon. No idea if it will improve anything for you but it's worth a shot to try and narrow down the area that might be different (assuming seeking was working for you with the Addon).

No luck with the latest git pull. Still stalls on auto commercial skip.

Skipping manually 30 second or 10 minutes seems to be working fine. In the log below I stepped forward just before the auto skip kicks in..

21:48:54 T:139891074570112 DEBUG: SDLKeyboard: scancode: 72, sym: 0113, unicode: 0000, modifier: 0
21:48:54 T:139891074570112 DEBUG: OnKey: right (f083) pressed, action is StepForward
21:48:54 T:139890720495360 DEBUG: CDVDPlayer::SetCaching - caching state 2
21:48:54 T:139890720495360 DEBUG: demuxer seek to: 2829726
21:48:54 T:139890720495360 DEBUG: Seek - seek to pos 0, whence 16
21:48:54 T:139890720495360 DEBUG: Seek - seek to pos 0, whence 0
21:48:54 T:139890720495360 DEBUG: Seek - seek to pos 3203005632, whence 0
21:48:54 T:139890720495360 DEBUG: Seek - seek to pos 3203003564, whence 0
21:48:54 T:139890720495360 DEBUG: Seek - seek to pos 3202999428, whence 0
21:48:54 T:139890720495360 DEBUG: Seek - seek to pos 2092457484, whence 0
21:48:54 T:139890720495360 DEBUG: Seek - seek to pos 2116570364, whence 0
21:48:54 T:139890720495360 DEBUG: Seek - seek to pos 2117817556, whence 0
21:48:54 T:139890720495360 DEBUG: Seek - seek to pos 2117566012, whence 0
21:48:54 T:139890720495360 DEBUG: Seek - seek to pos 2117663960, whence 0
21:48:54 T:139890720495360 DEBUG: Seek - seek to pos 2117620720, whence 0
21:48:54 T:139890720495360 DEBUG: Seek - seek to pos 2117604364, whence 0
21:48:54 T:139890720495360 DEBUG: SeekTime - seek ended up on time 2829879
21:48:54 T:139890720495360 DEBUG: demuxer seek to: 2829726, success
21:48:54 T:139891074570112 DEBUG: CAnnouncementManager - Announcement: OnSeek from xbmc
21:48:54 T:139891074570112 DEBUG: GOT ANNOUNCEMENT, type: 1, from xbmc, message OnSeek
21:48:54 T:139890272483072 DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_SYNCHRONIZE
21:48:54 T:139890479068928 DEBUG: CDVDPlayerAudio - CDVDMsg::GENERAL_SYNCHRONIZE
21:48:54 T:139890272483072 DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_RESYNC(2829879999.999998, 1)
21:48:54 T:139890272483072 INFO: CDVDPlayerVideo - Stillframe left, switching to normal playback
21:48:54 T:139890479068928 DEBUG: CDVDPlayerAudio - CDVDMsg::GENERAL_RESYNC(2829629755.555558, 0)
21:48:54 T:139890720495360 DEBUG: CDVDPlayer::HandleMessages - player started 1
21:48:54 T:139890720495360 DEBUG: CDVDPlayer::HandleMessages - player started 2
21:48:54 T:139890720495360 DEBUG: CDVDPlayer::SetCaching - caching state 0
21:48:54 T:139890479068928 DEBUG: CDVDPlayerAudio:: Discontinuity - was:2829882174.639997, should be:2829618856.998270, error:-263317.6417
21:48:54 T:139890479068928 WARNING: CDVDMessageQueue(audio)::Get - asked for new data packet, with nothing available
21:48:54 T:139890720495360 DEBUG: CheckAutoSceneSkip - Clock in commercial break [00:47:13.520 - 00:48:21.920]: 00:47:13.541. Automaticallkipping to end of commercial break (only done once per break)
21:48:54 T:139890720495360 DEBUG: demuxer seek to: 2901921
21:48:54 T:139890720495360 DEBUG: Seek - seek to pos 0, whence 16
21:48:54 T:139890720495360 DEBUG: Seek - seek to pos 0, whence 0
21:48:54 T:139890720495360 DEBUG: Seek - seek to pos 3203005632, whence 0
21:48:54 T:139890720495360 DEBUG: Seek - seek to pos 3203003564, whence 0
21:48:54 T:139890720495360 DEBUG: Seek - seek to pos 3202999428, whence 0
21:48:54 T:139890720495360 DEBUG: Seek - seek to pos 2145847040, whence 0
21:48:54 T:139890720495360 DEBUG: Seek - seek to pos 2172014196, whence 0
21:48:54 T:139890720495360 DEBUG: Seek - seek to pos 2171509980, whence 0
21:48:54 T:139890720495360 DEBUG: Seek - seek to pos 2171230800, whence 0
21:48:54 T:139890720495360 DEBUG: Seek - seek to pos 2171331944, whence 0
21:48:54 T:139890720495360 DEBUG: Seek - seek to pos 2171372928, whence 0
21:48:54 T:139890720495360 DEBUG: Seek - seek to pos 2171349804, whence 0
21:48:54 T:139890720495360 DEBUG: Seek - seek to pos 2171347360, whence 0
21:48:54 T:139890720495360 DEBUG: Seek - seek to pos 2171347172, whence 0
21:48:54 T:139890720495360 DEBUG: SeekTime - seek ended up on time 2901835
21:48:54 T:139890720495360 DEBUG: demuxer seek to: 2901921, success
21:48:54 T:139890440267520 DEBUG: Thread Jobworker 139890440267520 terminating (autodelete)
21:48:55 T:139890479068928 DEBUG: CDVDPlayerAudio:: Discontinuity - was:2830627769.098269, should be:2830596971.508523, error:-30797.58974
21:48:56 T:139890479068928 DEBUG: CDVDPlayerAudio:: Discontinuity - was:2831606402.996522, should be:2831637050.531973, error:30647.535451
21:48:56 T:139891074570112 DEBUG: ------ Window Deinit (DialogSeekBar.xml) ------
21:48:57 T:139890479068928 WARNING: CDVDMessageQueue(audio)::Get - asked for new data packet, with nothing available
21:48:58 T:139890479068928 DEBUG: CDVDAudio::Drain - adding 1336 bytes of silence, buffer size: 2504, chunk size: 3840
21:49:08 T:139890272483072 DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_SYNCHRONIZE
21:49:08 T:139890272483072 DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_RESYNC(2902120000.000002, 1)
21:49:08 T:139890272483072 WARNING: CDVDMessageQueue(video)::Get - asked for new data packet, with nothing available
21:49:08 T:139890720495360 DEBUG: CDVDPlayer::SetCaching - caching state 2
21:49:08 T:139890720495360 DEBUG: CDVDPlayer::SetCaching - caching state 3
21:49:08 T:139890720495360 DEBUG: CDVDPlayer::HandleMessages - player started 2
21:49:08 T:139890272483072 DEBUG: Previous line repeats 1 times.
21:49:08 T:139890272483072 INFO: CDVDPlayerVideo - Stillframe detected, switching to forced 25.000000 fps
21:49:13 T:139890272483072 DEBUG: CPullupCorrection: detected pattern of length 1: 40000.00, frameduration: 40000.000000
21:49:18 T:139891074570112 DEBUG: ------ Window Init (VideoOSD.xml) ------
21:49:18 T:139891074570112 INFO: Loading skin file: VideoOSD.xml
21:49:18 T:139891074570112 DEBUG: Load VideoOSD.xml: 11.06ms
21:49:18 T:139891074570112 DEBUG: Alloc resources: 31.64ms (11.13 ms skin load)
21:49:18 T:139891074570112 WARNING: JpegIO: Error 55: Not a JPEG file: starts with 0x%02x 0x%02x
21:49:18 T:139891074570112 DEBUG: ------ Window Init (Pointer.xml) ------
21:49:24 T:139891074570112 DEBUG: ------ Window Deinit (Pointer.xml) ------
21:49:25 T:139891074570112 DEBUG: ------ Window Deinit (VideoOSD.xml) ------
21:49:35 T:139891074570112 DEBUG: SDLKeyboard: scancode: 25, sym: 0132, unicode: 0000, modifier: 0
21:49:35 T:139891074570112 DEBUG: OnKey: leftctrl (f0d0) pressed, action is
21:49:35 T:139891074570112 DEBUG: SDLKeyboard: scancode: 40, sym: 0134, unicode: 0000, modifier: 40
21:49:35 T:139891074570112 DEBUG: OnKey: ctrl-leftalt (1f0d4) pressed, action is
21:53:24 T:139891074570112 INFO: CheckIdle - closing idle connection to MythTV backend: mythtvserver
21:53:28 T:139891074570112 INFO: CheckIdle - closing idle connection to MythTV backend: 192.168.1.2