Ceton Tuner recording problems

[Matt <matt@…>]

I am currently on my second Ceton tuner (first one was: infiniTV4 PCIe, current on is: infiniTV6 eth). Both tuners experienced the same problem. Randomly during recoding a TV show, the recording will stop. MythTV under status shows that the recording is still going, but the file size has stopped growing and if i go to watch the recording it will say that is is only like 8 minutes and it should be like 40 minutes at this time. Then when the recording is complete, it will turn yellow in the record list view.

I have been working with Centon Linux support about this problem and they are telling me that the problem is going from MythTV and not there tuner. Here is what i original submitted to them: I am currently using Ceton infiniTV 6 eth with MythTV running on Mythbuntu 12.04.4.

Cable Company: Wide Open West (W.O.W.)

system information: Intel(R) Core(TM) i5 CPU 650 @ 3.20GHz MemTotal?: 16425088 kB 3.8.0-36-generic #52~precise1-Ubuntu SMP x86_64 x86_64 x86_64 GNU/Linux

OS drive - (1) 500GB (Hitachi HTS727550A9E364) data drive - (7) 4 TB Western Digital RED (WDC WD40EFRX-68WT0N0) in a software raid 5 (mdadm) then made into logical volumn (LVM) /dev/mapper/vg_raid5-lv_mythtv 22T 11T 11T 50% /mythtv

The Ceton works about 95% of the time. I record about 30 shows a week. both 30 minute and 60 minute shows. Some times, maybe one (1) time a week or one (1) time every two (2) weeks the Ceton will randomly not record shows that I have defined in MythTV.

MythTV logs: Mar 10 19:58:42 mythbackend: mythbackend[5879]: E ProcessRequest? programinfo.cpp:2358 (GetPlaybackURL) ProgramInfo?(1208_20140310235900.mpg): GetPlaybackURL: '1208_20140310235900.mpg' should be local, but it can not be found. Mar 10 19:58:47 mythbackend: mythbackend[5879]: I TVRecEvent tv_rec.cpp:3602 (TuningCheckForHWChange) TVRec[1]: HW Tuner: 1->1 Mar 10 19:58:47 mythbackend: mythbackend[5879]: I CetonStreamHandler? recorders/iptvstreamhandler.cpp:122 (run) IPTVSH(::-1): run() Mar 10 19:58:47 mythbackend: mythbackend[5879]: N Scheduler autoexpire.cpp:264 (CalcParams?) AutoExpire?: CalcParams?(): Max required Free Space: 3.0 GB w/freq: 7 min Mar 10 19:58:47 mythbackend: mythbackend[5879]: I CetonStreamHandler? recorders/cetonrtsp.cpp:190 (Setup) CetonRTSP: Transport: RTP/AVP;unicast;client_port=38403-52087 Mar 10 19:58:47 mythbackend: mythbackend[5879]: E ProcessRequest? programinfo.cpp:2358 (GetPlaybackURL) ProgramInfo?(1208_20140310235900.mpg): GetPlaybackURL: '1208_20140310235900.mpg' should be local, but it can not be found. Mar 10 19:58:47 mythbackend: mythbackend[5879]: I Scheduler scheduler.cpp:2645 (HandleRecordingStatusChange?) Tuning recording: Bones:"The Source in the Sludge": channel 1208 on cardid 1, sourceid 1

MythTV will continue to record (or it thinks it is recording) until the schedule is complete. for today, 2014-03-10, 07:58 pm EST to 09:02 pm EST but it also shows that the record is 0 B in size.

Ceton has a utility to collect information about the server and their tuner. I can provide the logs from that if it would be helpful

[Matt <matt@…>]

Sorry i forgot to include there response:

It looks like at about 2:08AM UTC, MythTV (or something) re-tuned the tuner that was on 417 to channel 0 (nothing) 12911 Jan 30 01:46:16 ocur[21]: ocur: STT time Tue Mar 25 01:47:34 2014 UTC 12912 Jan 30 01:56:51 ocur[21]: ocur: [1] Attempting to SetChannel? (Channel=417 SourceId?=0 Mode=0) 12914 Jan 30 01:56:51 ocur[21]: ocur: [1] Program number set to 0, was 208 12915 Jan 30 01:56:51 ocur[21]: ocur: [1] Tune to 417 (mod=q256, freq=411000, program=417, std=9) 12916 Jan 30 01:56:51 ocur[21]: ocur: [1] Program number set to 417, was 0 12918 Jan 30 01:56:51 ocur[21]: ocur: [1] Locked: 1 Acc E: 0 12922 Jan 30 01:56:51 ocur[21]: ocur: [1] rtp setup for client 10.1.9.10:55164 12932 Jan 30 01:56:52 ocur[21]: ocur: [1] Tune finished to freq 411000 12933 Jan 30 01:56:52 ocur[21]: ocur: [1] Getting pmt for program 417 12936 Jan 30 01:56:52 ocur[21]: ocur: [1] Got pmt for program# 417 12937 Jan 30 01:56:52 ocur[21]: ocur: [1] Adding pid 0x1ffc 12938 Jan 30 01:56:52 ocur[21]: ocur: [1] Adding pid 0x0070 12939 Jan 30 01:56:52 ocur[21]: ocur: [1] Adding pid 0x0050 12940 Jan 30 01:56:52 ocur[21]: ocur: [1] Adding pid 0x00e0 12941 Jan 30 01:56:52 ocur[21]: ocur: [1] Adding pid 0x00d0 12942 Jan 30 01:56:52 ocur[21]: ocur: [1] Adding pid 0x00a0 12943 Jan 30 01:56:52 ocur[21]: ocur: [1] Adding pid 0x00c0 12944 Jan 30 01:56:52 ocur[21]: upnp: Event(tuner[1]): PCRLock, "1" 12947 Jan 30 01:56:52 ocur[21]: ocur: [1] Adding pid 0x0000 12948 Jan 30 01:56:52 ocur[21]: ocur: [1] Adding pid 0x00e1 12949 Jan 30 01:56:52 ocur[21]: ocur: [1] Adding pid 0x00ed 12950 Jan 30 01:56:52 ocur[21]: ocur: [1] Adding pid 0x00e2 12951 Jan 30 01:56:52 ocur[21]: ocur: [1] Adding pid 0x00e3 12952 Jan 30 01:56:52 ocur[21]: ocur: [1] Adding pid 0x00e4 12955 Jan 30 01:56:52 ocur[21]: ocur: [1] Channel is scrambled, expecting CCI 12956 Jan 30 01:56:52 ocur[21]: ocur: [1] Sending ca_pmt to CableCARD for program number 417 index 1 12977 Jan 30 01:56:53 ocur[21]: ocur: [1] CCI 00 arrived for program# 417 12979 Jan 30 01:56:54 ocur[21]: ocur: [1] rtp teardown for client 10.1.9.10:55164 12983 Jan 30 01:56:54 ocur[21]: ocur: [1] rtp setup for client 10.1.9.10:43661 13162 Jan 30 02:07:05 ocur[21]: ocur: [1] Attempting to SetChannel? (Channel=0 SourceId?=0 Mode=0) 13164 Jan 30 02:07:05 ocur[21]: ocur: [1] Program number set to 0, was 417 13165 Jan 30 02:07:05 ocur[21]: ocur: WARNING: [1] Channel 0 not found Around the same time, I see the tuner that was on channel 201 re-tuned to 203: 12911 Jan 30 01:46:16 ocur[21]: ocur: STT time Tue Mar 25 01:47:34 2014 UTC 12923 Jan 30 01:56:51 ocur[21]: ocur: [4] Attempting to SetChannel? (Channel=201 SourceId?=0 Mode=0) 12925 Jan 30 01:56:52 ocur[21]: ocur: [4] Program number set to 0, was 0 12926 Jan 30 01:56:52 ocur[21]: ocur: [4] Tune to 201 (mod=q256, freq=231000, program=201, std=9) 12927 Jan 30 01:56:52 ocur[21]: ocur: [4] Program number set to 201, was 0 12931 Jan 30 01:56:52 ocur[21]: ocur: [4] Locked: 1 Acc E: 0 12935 Jan 30 01:56:52 ocur[21]: ocur: [4] rtp setup for client 10.1.9.10:47912 12945 Jan 30 01:56:52 ocur[21]: ocur: [4] Tune finished to freq 231000 12946 Jan 30 01:56:52 ocur[21]: ocur: [4] Getting pmt for program 201 12957 Jan 30 01:56:52 ocur[21]: ocur: [4] Got pmt for program# 201 12958 Jan 30 01:56:52 ocur[21]: ocur: [4] Adding pid 0x1ffc 12959 Jan 30 01:56:52 ocur[21]: ocur: [4] Adding pid 0x1580 12960 Jan 30 01:56:52 ocur[21]: ocur: [4] Adding pid 0x1bc0 12961 Jan 30 01:56:52 ocur[21]: ocur: [4] Adding pid 0x1c30 12962 Jan 30 01:56:52 ocur[21]: upnp: Event(tuner[4]): PCRLock, "1" 12963 Jan 30 01:56:52 ocur[21]: ocur: [4] Adding pid 0x0000 12964 Jan 30 01:56:52 ocur[21]: ocur: [4] Adding pid 0x1bc1 12965 Jan 30 01:56:52 ocur[21]: ocur: [4] Adding pid 0x1bc2 12966 Jan 30 01:56:52 ocur[21]: ocur: [4] Adding pid 0x1bc3 12967 Jan 30 01:56:52 ocur[21]: ocur: [4] Adding pid 0x1bc4 12970 Jan 30 01:56:52 ocur[21]: ocur: [4] Channel is clear 12971 Jan 30 01:56:52 ocur[21]: ocur: [4] Sending ca_pmt to CableCARD for program number 201 index 2 12972 Jan 30 01:56:53 ocur[21]: ocur: [4] rtp teardown for client 10.1.9.10:47912 12976 Jan 30 01:56:53 ocur[21]: ocur: [4] rtp setup for client 10.1.9.10:39419 12978 Jan 30 01:56:54 ocur[21]: ocur: [4] CCI 00 arrived for program# 201 13137 Jan 30 02:05:04 ocur[21]: ocur: [4] Attempting to SetChannel? (Channel=203 SourceId?=0 Mode=0) 13139 Jan 30 02:05:04 ocur[21]: ocur: [4] Program number set to 0, was 201 My guess is this is either a MythTV configuration issue, or a MythTV bug.

[JYA]

Is this still an issue with post 0.27.1?

[Matt <matt@…>]

i am currently on:

mythpython --version

MythTV Python Bindings

local versions

bindings version: 0.27.-1.0 ttvdb version: 1.2.1 tmdb version: v0.7.0

external versions

lxml version: 2.3.2 MySQLdb version: 1.2.3.final.0

protocol versions

backend: 77 schema: 1317 music schema: 1018 netvision schema: 1007

and the problem is still happening

[JYA]

What has mythpython anything to do with this? It provides no useful information and has nothing to do with recordings

What does mythfrontend --version Outputs?

[Matt <matt@…>]

mythfrontend version

[Matt <matt@…>]

mythfrontend --version screen shot attached

[JYA]

Why a screenshot? Surely you can just paste the text like you did for mythpython

Regardless, you aren't running 0.27.1

Upgrade to the latest version

[Matt <matt@…>]

It has happened again after upgrading to 0.27.1

White Collar Neighborhood Watch 3x13 EP011775780043 2012-01-31 Fri Jun 27, 2014 (06:00 AM) 233 - USA Network HD

This recording is scheduled to start 1 minutes early and end 2 minutes late for a total of roughly 63 minutes. The recording is showing a length of 37:38 instead of 63 minutes. Should have started around 5:59:00 and ended around 7:02:00. So I have included the information from the mythbackend.log for that time window. another episode of "White Collar" is scheduled to start at 07:00 AM on the same channel with the with the same recording parameters. The 07:00 AM recording worked correctly

mythbackend.log Jun 27 05:58:00 prdmt01 mythbackend: mythbackend[14831]: I Scheduler mythdbcon.cpp:409 (PurgeIdleConnections?) New DB connection, total: 11 Jun 27 05:58:00 prdmt01 mythbackend: mythbackend[14831]: I Scheduler scheduler.cpp:2139 (HandleReschedule?) Reschedule requested for PLACE PrepareToRecord? Jun 27 05:58:01 prdmt01 mythbackend: mythbackend[14831]: I Scheduler scheduler.cpp:2252 (HandleReschedule?) Scheduled 246 items in 1.5 = 0.00 match + 0.00 check + 1.52 place Jun 27 05:58:30 prdmt01 mythbackend: mythbackend[14831]: I TVRecEvent tv_rec.cpp:1567 (HandlePendingRecordings?) TVRec[1]: ASK_RECORDING 1 28 0 0 Jun 27 06:24:28 prdmt01 mythbackend: mythbackend[14831]: N Expire autoexpire.cpp:264 (CalcParams?) AutoExpire?: CalcParams?(): Max required Free Space: 1.0 GB w/freq: 15 min Jun 27 06:24:28 prdmt01 mythbackend: mythbackend[14831]: I TVRecEvent tv_rec.cpp:1050 (HandleStateChange?) TVRec[1]: Changing from None to RecordingOnly? Jun 27 06:24:28 prdmt01 mythbackend: mythbackend[14831]: I TVRecEvent mythdbcon.cpp:409 (PurgeIdleConnections?) New DB connection, total: 11 Jun 27 06:24:28 prdmt01 mythbackend: mythbackend[14831]: I TVRecEvent tv_rec.cpp:3602 (TuningCheckForHWChange) TVRec[1]: HW Tuner: 1->1 Jun 27 06:24:28 prdmt01 mythbackend: mythbackend[14831]: I CetonStreamHandler? recorders/iptvstreamhandler.cpp:127 (run) IPTVSH(::-1): run() Jun 27 06:24:28 prdmt01 mythbackend: mythbackend[14831]: N Scheduler autoexpire.cpp:264 (CalcParams?) AutoExpire?: CalcParams?(): Max required Free Space: 3.0 GB w/freq: 14 min Jun 27 06:24:28 prdmt01 mythbackend: mythbackend[14831]: I Scheduler scheduler.cpp:2689 (HandleRecordingStatusChange?) Tuning recording: "White Collar":"Neighborhood Watch": channel 1233 on cardid 1, sourceid 1 Jun 27 06:24:28 prdmt01 mythbackend: mythbackend[14831]: I CetonStreamHandler? recorders/cetonrtsp.cpp:413 (Setup) CetonRTSP: Transport: RTP/AVP;unicast;client_port=59225-59226 Jun 27 06:24:29 prdmt01 mythbackend: mythbackend[14831]: E ProcessRequest? programinfo.cpp:2358 (GetPlaybackURL) ProgramInfo?(1233_20140627095900.mpg): GetPlaybackURL: '1233_20140627095900.mpg' should be local, but it can not be found. Jun 27 06:24:29 mythbackend: last message repeated 2 times Jun 27 06:24:29 prdmt01 mythbackend: mythbackend[14831]: N CetonStreamHandler? recorders/dtvsignalmonitor.cpp:367 (HandlePMT) DTVSigMon[1](10.1.9.12-RTP.0): PMT says program 233 is encrypted Jun 27 06:24:29 prdmt01 mythbackend: mythbackend[14831]: I CoreContext? scheduler.cpp:704 (UpdateRecStatus?) Updating status for "White Collar":"Neighborhood Watch" on cardid 1 (Tuning => Recording) Jun 27 06:24:30 prdmt01 mythbackend: mythbackend[14831]: I TVRecEvent tv_rec.cpp:4129 (TuningNewRecorder?) TVRec[1]: rec->GetPathname?(): '/mythtv/livetv/1233_20140627095900.mpg' Jun 27 06:24:30 prdmt01 mythbackend: mythbackend[14831]: E TVRecEvent recorders/recorderbase.cpp:206 (SetStrOption?) RecBase?[1](10.1.9.12-RTP.0): SetStrOption?(...recordingtype): Option not in profile. Jun 27 06:24:30 prdmt01 mythbackend: mythbackend[14831]: I CetonStreamHandler? recorders/iptvstreamhandler.cpp:127 (run) IPTVSH(::-1): run() Jun 27 06:24:30 prdmt01 mythbackend: mythbackend[14831]: I CetonStreamHandler? recorders/cetonrtsp.cpp:413 (Setup) CetonRTSP: Transport: RTP/AVP;unicast;client_port=41080-41081 Jun 27 06:24:31 prdmt01 mythbackend: mythbackend[14831]: I PreviewGeneratorQueue? mythdbcon.cpp:409 (PurgeIdleConnections?) New DB connection, total: 14 Jun 27 06:24:31 prdmt01 mythbackend: mythbackend[14831]: I ProcessRequest? mainserver.cpp:1436 (HandleAnnounce?) MainServer::ANN Monitor Jun 27 06:24:31 prdmt01 mythbackend: mythbackend[14831]: I ProcessRequest? mainserver.cpp:1438 (HandleAnnounce?) adding: prdmt01 as a client (events: 0) Jun 27 06:24:31 prdmt01 mythbackend: mythbackend[14831]: I ProcessRequest? mainserver.cpp:1436 (HandleAnnounce?) MainServer::ANN Monitor Jun 27 06:24:31 prdmt01 mythbackend: mythbackend[14831]: I ProcessRequest? mainserver.cpp:1438 (HandleAnnounce?) adding: prdmt01 as a client (events: 1) Jun 27 06:40:27 prdmt01 mythbackend: mythbackend[14831]: N Expire autoexpire.cpp:264 (CalcParams?) AutoExpire?: CalcParams?(): Max required Free Space: 3.0 GB w/freq: 14 min Jun 27 06:55:27 prdmt01 mythbackend: mythbackend[14831]: N Expire autoexpire.cpp:264 (CalcParams?) AutoExpire?: CalcParams?(): Max required Free Space: 3.0 GB w/freq: 14 min Jun 27 06:58:00 prdmt01 mythbackend: mythbackend[14831]: I Scheduler scheduler.cpp:2139 (HandleReschedule?) Reschedule requested for PLACE PrepareToRecord? Jun 27 06:58:01 prdmt01 mythbackend: mythbackend[14831]: I Scheduler scheduler.cpp:2252 (HandleReschedule?) Scheduled 246 items in 1.1 = 0.00 match + 0.00 check + 1.09 place Jun 27 06:58:30 prdmt01 mythbackend: mythbackend[14831]: I TVRecEvent tv_rec.cpp:1567 (HandlePendingRecordings?) TVRec[2]: ASK_RECORDING 2 29 0 0 Jun 27 06:59:00 prdmt01 mythbackend: mythbackend[14831]: I TVRecEvent tv_rec.cpp:1050 (HandleStateChange?) TVRec[2]: Changing from None to RecordingOnly? Jun 27 06:59:00 prdmt01 mythbackend: mythbackend[14831]: I TVRecEvent mythdbcon.cpp:409 (PurgeIdleConnections?) New DB connection, total: 14 Jun 27 06:59:00 prdmt01 mythbackend: mythbackend[14831]: I TVRecEvent tv_rec.cpp:3602 (TuningCheckForHWChange) TVRec[2]: HW Tuner: 2->2 Jun 27 06:59:00 prdmt01 mythbackend: mythbackend[14831]: I CetonStreamHandler? recorders/iptvstreamhandler.cpp:127 (run) IPTVSH(::-1): run() Jun 27 06:59:00 prdmt01 mythbackend: mythbackend[14831]: N Scheduler autoexpire.cpp:264 (CalcParams?) AutoExpire?: CalcParams?(): Max required Free Space: 3.0 GB w/freq: 7 min Jun 27 06:59:00 prdmt01 mythbackend: mythbackend[14831]: I Scheduler scheduler.cpp:2689 (HandleRecordingStatusChange?) Tuning recording: "White Collar":"Pulling Strings": channel 1233 on cardid 2, sourceid 1 Jun 27 06:59:00 prdmt01 mythbackend: mythbackend[14831]: I CetonStreamHandler? recorders/cetonrtsp.cpp:413 (Setup) CetonRTSP: Transport: RTP/AVP;unicast;client_port=42607-42608 Jun 27 06:59:00 prdmt01 mythbackend: mythbackend[14831]: E ProcessRequest? programinfo.cpp:2358 (GetPlaybackURL) ProgramInfo?(1233_20140627105900.mpg): GetPlaybackURL: '1233_20140627105900.mpg' should be local, but it can not be found. Jun 27 06:59:01 mythbackend: last message repeated 2 times Jun 27 06:59:01 prdmt01 mythbackend: mythbackend[14831]: N CetonStreamHandler? recorders/dtvsignalmonitor.cpp:367 (HandlePMT) DTVSigMon[2](10.1.9.12-RTP.1): PMT says program 233 is encrypted Jun 27 06:59:01 prdmt01 mythbackend: mythbackend[14831]: I CoreContext? scheduler.cpp:704 (UpdateRecStatus?) Updating status for "White Collar":"Pulling Strings" on cardid 2 (Tuning => Recording) Jun 27 06:59:01 prdmt01 mythbackend: mythbackend[14831]: I TVRecEvent tv_rec.cpp:4129 (TuningNewRecorder?) TVRec[2]: rec->GetPathname?(): '/mythtv/livetv/1233_20140627105900.mpg' Jun 27 06:59:01 prdmt01 mythbackend: mythbackend[14831]: E TVRecEvent recorders/recorderbase.cpp:206 (SetStrOption?) RecBase?[2](10.1.9.12-RTP.1): SetStrOption?(...recordingtype): Option not in profile. Jun 27 06:59:01 prdmt01 mythbackend: mythbackend[14831]: I CetonStreamHandler? recorders/iptvstreamhandler.cpp:127 (run) IPTVSH(::-1): run() Jun 27 06:59:01 prdmt01 mythbackend: mythbackend[14831]: I CetonStreamHandler? recorders/cetonrtsp.cpp:413 (Setup) CetonRTSP: Transport: RTP/AVP;unicast;client_port=54417-54418 Jun 27 06:59:04 prdmt01 mythbackend: mythbackend[14831]: I ProcessRequest? mainserver.cpp:1436 (HandleAnnounce?) MainServer::ANN Monitor Jun 27 06:59:04 prdmt01 mythbackend: mythbackend[14831]: I ProcessRequest? mainserver.cpp:1438 (HandleAnnounce?) adding: prdmt01 as a client (events: 0) Jun 27 06:59:04 prdmt01 mythbackend: mythbackend[14831]: I ProcessRequest? mainserver.cpp:1436 (HandleAnnounce?) MainServer::ANN Monitor Jun 27 06:59:04 prdmt01 mythbackend: mythbackend[14831]: I ProcessRequest? mainserver.cpp:1438 (HandleAnnounce?) adding: prdmt01 as a client (events: 1) Jun 27 07:02:00 prdmt01 mythbackend: mythbackend[14831]: I TVRecEvent tv_rec.cpp:1050 (HandleStateChange?) TVRec[1]: Changing from RecordingOnly? to None Jun 27 07:02:00 prdmt01 mythbackend: mythbackend[14831]: I TVRecEvent tv_rec.cpp:834 (FinishedRecording?) TVRec[1]: FinishedRecording?(1233_2014-06-27T09:59:00Z) damaged recq:<RecordingQuality? overall_score="0" key="1233_2014-06-27T09:59:00Z" countinuity_error_count="3" packet_count="18757969">#012 <Gap start="2014-06-27T10:00:00Z" end="2014-06-27T10:24:30Z" duration="1470" />#012</RecordingQuality?> Jun 27 07:02:00 prdmt01 mythbackend: mythbackend[14831]: E CoreContext? mainserver.cpp:963 (customEvent) MainServer?: PREVIEW_SUCCESS but no receivers. Jun 27 07:02:00 prdmt01 mythbackend: mythbackend[14831]: I CoreContext? scheduler.cpp:704 (UpdateRecStatus?) Updating status for "White Collar":"Neighborhood Watch" on cardid 1 (Recording => Recorded) Jun 27 07:02:00 prdmt01 mythbackend: mythbackend[14831]: I Scheduler scheduler.cpp:2139 (HandleReschedule?) Reschedule requested for CHECK -3 64 0 UpdateRecStatus2 | White Collar | Neighborhood Watch | Elizabeth's curiosity leads Peter and Neal to uncover a robbery plot. | EP011775780043 Jun 27 07:02:01 prdmt01 mythbackend: mythbackend[14831]: I Scheduler scheduler.cpp:2252 (HandleReschedule?) Scheduled 245 items in 0.7 = 0.00 match + 0.00 check + 0.73 place Jun 27 07:02:01 prdmt01 mythbackend: mythbackend[14831]: I ProcessRequest? mainserver.cpp:1436 (HandleAnnounce?) MainServer::ANN Monitor Jun 27 07:02:01 prdmt01 mythbackend: mythbackend[14831]: I ProcessRequest? mainserver.cpp:1438 (HandleAnnounce?) adding: prdmt01 as a client (events: 0) Jun 27 07:02:01 prdmt01 mythbackend: mythbackend[14831]: I ProcessRequest? mainserver.cpp:1436 (HandleAnnounce?) MainServer::ANN Monitor Jun 27 07:02:01 prdmt01 mythbackend: mythbackend[14831]: I ProcessRequest? mainserver.cpp:1438 (HandleAnnounce?) adding: prdmt01 as a client (events: 1) Jun 27 07:02:24 prdmt01 mythbackend: mythbackend[14831]: I Metadata_6389 jobqueue.cpp:2156 (DoMetadataLookupThread?) JobQueue?: Metadata Lookup Starting for "White Collar":"Neighborhood Watch" recorded from channel 1233 at 2014-06-27T09:59:00Z Jun 27 07:02:26 prdmt01 mythbackend: mythbackend[14831]: I ProcessRequest? mainserver.cpp:1436 (HandleAnnounce?) MainServer::ANN Monitor Jun 27 07:02:26 prdmt01 mythbackend: mythbackend[14831]: I ProcessRequest? mainserver.cpp:1438 (HandleAnnounce?) adding: prdmt01 as a client (events: 0) Jun 27 07:02:26 prdmt01 mythbackend: mythbackend[14831]: I ProcessRequest? mainserver.cpp:1436 (HandleAnnounce?) MainServer::ANN Monitor Jun 27 07:02:26 prdmt01 mythbackend: mythbackend[14831]: I ProcessRequest? mainserver.cpp:1438 (HandleAnnounce?) adding: prdmt01 as a client (events: 1) Jun 27 07:03:29 prdmt01 mythbackend: mythbackend[14831]: I Commflag_6391 jobqueue.cpp:2281 (DoFlagCommercialsThread?) JobQueue?: Commercial Detection Starting for "White Collar":"Neighborhood Watch" recorded from channel 1233 at 2014-06-27T09:59:00Z

mythbackend --version Please attach all output as a file in bug reports. MythTV Version : v0.27.1-16-gaa822f5 MythTV Branch : fixes/0.27 Network Protocol : 77 Library API : 0.27.20140520-1 QT Version : 4.8.1 Options compiled in:

linux profile use_hidesyms using_alsa using_oss using_pulse using_pulseoutput using_backend using_bindings_perl using_bindings_python using_bindings_php using_crystalhd using_dvb using_firewire using_frontend using_hdhomerun using_ceton using_hdpvr using_ivtv using_joystick_menu using_libcec using_libcrypto using_libdns_sd using_libfftw3 using_libxml2 using_lirc using_mheg using_opengl using_opengl_video using_qtwebkit using_qtscript using_qtdbus using_sdl using_taglib using_v4l2 using_x11 using_xrandr using_xv using_profiletype using_bindings_perl using_bindings_python using_bindings_php using_mythtranscode using_opengl using_vaapi using_vdpau using_ffmpeg_threads using_mheg using_libass using_libxml2

mythfrontend --version Please attach all output as a file in bug reports. MythTV Version : v0.27.1-16-gaa822f5 MythTV Branch : fixes/0.27 Network Protocol : 77 Library API : 0.27.20140520-1 QT Version : 4.8.1 Options compiled in:

linux profile use_hidesyms using_alsa using_oss using_pulse using_pulseoutput using_backend using_bindings_perl using_bindings_python using_bindings_php using_crystalhd using_dvb using_firewire using_frontend using_hdhomerun using_ceton using_hdpvr using_ivtv using_joystick_menu using_libcec using_libcrypto using_libdns_sd using_libfftw3 using_libxml2 using_lirc using_mheg using_opengl using_opengl_video using_qtwebkit using_qtscript using_qtdbus using_sdl using_taglib using_v4l2 using_x11 using_xrandr using_xv using_profiletype using_bindings_perl using_bindings_python using_bindings_php using_mythtranscode using_opengl using_vaapi using_vdpau using_ffmpeg_threads using_mheg using_libass using_libxml2

Please let me know what other information you need.

[Matt <matt@…>]

here is 2 more that failed

The Big Bang Theory The Jiminy Conjecture EP009311820045 2009-09-28 Sat Jun 28, 2014 (04:30 PM) 208 - WTTEDT (WTTE-DT)

This recording is scheduled to start 1 minutes early and end 1 minutes late for a total of roughly 32 minutes. Nothing recorded at all. Should have started around 16:29:00 and ended around 17:01:00. So I have included the information from the mythbackend.log for that time window.

mythbackend.log Jun 28 16:28:00 prdmt01 mythbackend: mythbackend[4574]: I Scheduler scheduler.cpp:2139 (HandleReschedule?) Reschedule requested for PLACE PrepareToRecord? Jun 28 16:28:00 prdmt01 mythbackend: mythbackend[4574]: I Scheduler scheduler.cpp:2252 (HandleReschedule?) Scheduled 256 items in 0.8 = 0.00 match + 0.00 check + 0.76 place Jun 28 16:28:30 prdmt01 mythbackend: mythbackend[4574]: I Scheduler mythdbcon.cpp:409 (PurgeIdleConnections?) New DB connection, total: 7 Jun 28 16:28:30 prdmt01 mythbackend: mythbackend[4574]: I TVRecEvent tv_rec.cpp:1567 (HandlePendingRecordings?) TVRec[1]: ASK_RECORDING 1 29 0 0 Jun 28 16:29:00 prdmt01 mythbackend: mythbackend[4574]: I TVRecEvent tv_rec.cpp:1050 (HandleStateChange?) TVRec[1]: Changing from None to RecordingOnly? Jun 28 16:29:00 prdmt01 mythbackend: mythbackend[4574]: I TVRecEvent tv_rec.cpp:3602 (TuningCheckForHWChange) TVRec[1]: HW Tuner: 1->1 Jun 28 16:29:00 prdmt01 mythbackend: mythbackend[4574]: I CetonStreamHandler? recorders/iptvstreamhandler.cpp:127 (run) IPTVSH(::-1): run() Jun 28 16:29:00 prdmt01 mythbackend: mythbackend[4574]: N Scheduler autoexpire.cpp:264 (CalcParams?) AutoExpire?: CalcParams?(): Max required Free Space: 3.0 GB w/freq: 14 min Jun 28 16:29:00 prdmt01 mythbackend: mythbackend[4574]: I Scheduler scheduler.cpp:2689 (HandleRecordingStatusChange?) Tuning recording: "The Big Bang Theory":"The Jiminy Conjecture": channel 1208 on cardid 1, sourceid 1 Jun 28 16:29:00 prdmt01 mythbackend: mythbackend[4574]: I CetonStreamHandler? recorders/cetonrtsp.cpp:413 (Setup) CetonRTSP: Transport: RTP/AVP;unicast;client_port=38001-38002 Jun 28 16:29:00 prdmt01 mythbackend: mythbackend[4574]: E ProcessRequest? programinfo.cpp:2358 (GetPlaybackURL) ProgramInfo?(1208_20140628202900.mpg): GetPlaybackURL: '1208_20140628202900.mpg' should be local, but it can not be found. Jun 28 16:30:03 mythbackend: last message repeated 2 times Jun 28 16:35:17 prdmt01 mythbackend: mythbackend[4574]: N Expire autoexpire.cpp:264 (CalcParams?) AutoExpire?: CalcParams?(): Max required Free Space: 3.0 GB w/freq: 14 min Jun 28 16:49:17 prdmt01 mythbackend: mythbackend[4574]: N Expire autoexpire.cpp:264 (CalcParams?) AutoExpire?: CalcParams?(): Max required Free Space: 3.0 GB w/freq: 14 min Jun 28 17:01:00 prdmt01 mythbackend: mythbackend[4574]: I CoreContext? scheduler.cpp:704 (UpdateRecStatus?) Updating status for "The Big Bang Theory":"The Jiminy Conjecture" on cardid 1 (Tuning => Recorder Failed) Jun 28 17:01:00 prdmt01 mythbackend: mythbackend[4574]: I Scheduler scheduler.cpp:2139 (HandleReschedule?) Reschedule requested for CHECK -9 1 0 UpdateRecStatus2 | The Big Bang Theory | The Jiminy Conjecture | Penny and Leonard try to recover from an awkward hookup; Howard and Sheldon make a high-stakes bet. | EP009311820045 Jun 28 17:01:00 prdmt01 mythbackend: mythbackend[4574]: I TVRecEvent tv_rec.cpp:1050 (HandleStateChange?) TVRec[1]: Changing from RecordingOnly? to None Jun 28 17:01:00 prdmt01 mythbackend: mythbackend[4574]: E ProcessRequest? programinfo.cpp:2358 (GetPlaybackURL) ProgramInfo?(1208_20140628202900.mpg): GetPlaybackURL: '1208_20140628202900.mpg' should be local, but it can not be found. Jun 28 17:01:01 prdmt01 mythbackend: mythbackend[4574]: I Scheduler scheduler.cpp:2252 (HandleReschedule?) Scheduled 255 items in 0.6 = 0.01 match + 0.03 check + 0.58 place

The Big Bang Theory The Electric Can Opener Fluctuation EP009311820044 2009-09-21 Sat Jun 28, 2014 (06:30 PM) 208 - WTTEDT (WTTE-DT)

This recording is scheduled to start 1 minutes early and end 1 minutes late for a total of roughly 32 minutes. Nothing recorded at all. Should have started around 18:29:00 and ended around 19:01:00. So I have included the information from the mythbackend.log for that time window.

mythbackend.log Jun 28 18:28:00 prdmt01 mythbackend: mythbackend[4574]: I Scheduler scheduler.cpp:2139 (HandleReschedule?) Reschedule requested for PLACE PrepareToRecord? Jun 28 18:28:01 prdmt01 mythbackend: mythbackend[4574]: I Scheduler scheduler.cpp:2252 (HandleReschedule?) Scheduled 255 items in 1.2 = 0.00 match + 0.00 check + 1.16 place Jun 28 18:28:30 prdmt01 mythbackend: mythbackend[4574]: I Scheduler mythdbcon.cpp:409 (PurgeIdleConnections?) New DB connection, total: 8 Jun 28 18:28:30 prdmt01 mythbackend: mythbackend[4574]: I TVRecEvent tv_rec.cpp:1567 (HandlePendingRecordings?) TVRec[1]: ASK_RECORDING 1 29 0 0 Jun 28 18:29:00 prdmt01 mythbackend: mythbackend[4574]: I TVRecEvent tv_rec.cpp:1050 (HandleStateChange?) TVRec[1]: Changing from None to RecordingOnly? Jun 28 18:29:00 prdmt01 mythbackend: mythbackend[4574]: I TVRecEvent mythdbcon.cpp:409 (PurgeIdleConnections?) New DB connection, total: 8 Jun 28 18:29:00 prdmt01 mythbackend: mythbackend[4574]: I TVRecEvent tv_rec.cpp:3602 (TuningCheckForHWChange) TVRec[1]: HW Tuner: 1->1 Jun 28 18:29:00 prdmt01 mythbackend: mythbackend[4574]: I CoreContext? mythdbcon.cpp:409 (PurgeIdleConnections?) New DB connection, total: 8 Jun 28 18:29:00 prdmt01 mythbackend: mythbackend[4574]: I CetonStreamHandler? recorders/iptvstreamhandler.cpp:127 (run) IPTVSH(::-1): run() Jun 28 18:29:00 prdmt01 mythbackend: mythbackend[4574]: N Scheduler autoexpire.cpp:264 (CalcParams?) AutoExpire?: CalcParams?(): Max required Free Space: 3.0 GB w/freq: 14 min Jun 28 18:29:00 prdmt01 mythbackend: mythbackend[4574]: I Scheduler scheduler.cpp:2689 (HandleRecordingStatusChange?) Tuning recording: "The Big Bang Theory":"The Electric Can Opener Fluctuation": channel 1208 on cardid 1, sourceid 1 Jun 28 18:29:00 prdmt01 mythbackend: mythbackend[4574]: I CetonStreamHandler? recorders/cetonrtsp.cpp:413 (Setup) CetonRTSP: Transport: RTP/AVP;unicast;client_port=44785-44786 Jun 28 18:29:00 prdmt01 mythbackend: mythbackend[4574]: E ProcessRequest? programinfo.cpp:2358 (GetPlaybackURL) ProgramInfo?(1208_20140628222900.mpg): GetPlaybackURL: '1208_20140628222900.mpg' should be local, but it can not be found. Jun 28 18:29:00 mythbackend: last message repeated 2 times Jun 28 18:29:00 prdmt01 mythbackend: mythbackend[4574]: I CoreContext? scheduler.cpp:704 (UpdateRecStatus?) Updating status for "The Big Bang Theory":"The Electric Can Opener Fluctuation" on cardid 1 (Tuning => Recording) Jun 28 18:29:00 prdmt01 mythbackend: mythbackend[4574]: I TVRecEvent tv_rec.cpp:4129 (TuningNewRecorder?) TVRec[1]: rec->GetPathname?(): '/mythtv/livetv/1208_20140628222900.mpg' Jun 28 18:29:00 prdmt01 mythbackend: mythbackend[4574]: E TVRecEvent recorders/recorderbase.cpp:206 (SetStrOption?) RecBase?[1](10.1.9.12-RTP.0): SetStrOption?(...recordingtype): Option not in profile. Jun 28 18:29:00 prdmt01 mythbackend: mythbackend[4574]: I CetonStreamHandler? recorders/iptvstreamhandler.cpp:127 (run) IPTVSH(::-1): run() Jun 28 18:29:01 prdmt01 mythbackend: mythbackend[4574]: I CetonStreamHandler? recorders/cetonrtsp.cpp:413 (Setup) CetonRTSP: Transport: RTP/AVP;unicast;client_port=55162-55163 Jun 28 18:37:17 prdmt01 mythbackend: mythbackend[4574]: N Expire autoexpire.cpp:264 (CalcParams?) AutoExpire?: CalcParams?(): Max required Free Space: 3.0 GB w/freq: 14 min Jun 28 18:51:17 prdmt01 mythbackend: mythbackend[4574]: N Expire autoexpire.cpp:264 (CalcParams?) AutoExpire?: CalcParams?(): Max required Free Space: 3.0 GB w/freq: 14 min Jun 28 19:01:00 prdmt01 mythbackend: mythbackend[4574]: I TVRecEvent tv_rec.cpp:1050 (HandleStateChange?) TVRec[1]: Changing from RecordingOnly? to None Jun 28 19:01:00 prdmt01 mythbackend: mythbackend[4574]: I TVRecEvent recordinginfo.cpp:1075 (FinishedRecording?) Finished recording The Big Bang Theory "The Electric Can Opener Fluctuation": channel 1208 Jun 28 19:01:00 prdmt01 mythbackend: mythbackend[4574]: I CoreContext? scheduler.cpp:704 (UpdateRecStatus?) Updating status for "The Big Bang Theory":"The Electric Can Opener Fluctuation" on cardid 1 (Recording => Recorded) Jun 28 19:01:00 prdmt01 mythbackend: mythbackend[4574]: I Scheduler scheduler.cpp:2139 (HandleReschedule?) Reschedule requested for CHECK -3 1 0 UpdateRecStatus2 | The Big Bang Theory | The Electric Can Opener Fluctuation | After tampering with Sheldon's Arctic-expedition data, the guys follow him back to Texas, which threatens Leonard's chances for romance with Penny. | EP009311820044 Jun 28 19:01:00 prdmt01 mythbackend: mythbackend[4574]: I PreviewGeneratorQueue? mythdbcon.cpp:409 (PurgeIdleConnections?) New DB connection, total: 8 Jun 28 19:01:00 prdmt01 mythbackend: mythbackend[4574]: I Scheduler scheduler.cpp:2252 (HandleReschedule?) Scheduled 254 items in 0.6 = 0.01 match + 0.01 check + 0.57 place Jun 28 19:01:01 prdmt01 mythbackend: mythbackend[4574]: I ProcessRequest? mainserver.cpp:1436 (HandleAnnounce?) MainServer::ANN Monitor Jun 28 19:01:01 prdmt01 mythbackend: mythbackend[4574]: I ProcessRequest? mainserver.cpp:1438 (HandleAnnounce?) adding: prdmt01 as a client (events: 0) Jun 28 19:01:01 prdmt01 mythbackend: mythbackend[4574]: I ProcessRequest? mainserver.cpp:1436 (HandleAnnounce?) MainServer::ANN Monitor Jun 28 19:01:01 prdmt01 mythbackend: mythbackend[4574]: I ProcessRequest? mainserver.cpp:1438 (HandleAnnounce?) adding: prdmt01 as a client (events: 1) Jun 28 19:01:02 prdmt01 mythbackend: mythbackend[4574]: E PreviewGenerator? previewgenerator.cpp:265 (Run) Preview: Encountered problems running '/usr/bin/mythpreviewgen' (128)

[mattlach@…]

I may have found a solution to this:

During initial setup I had to install the Ceton Windows utility on a few Windows machines in order to get everything to work. I theorized that the Ceton utility was responsible for switching the channel (as it does this during channel testing).

Just shutting down the Windows Ceton utility on the computers it is installed on did not help. I had to uninstall all Ceton software (including drivers) from all Windows machines on the local network. Since then I have not had a interrupted recording, though it hasn't been long enough to know for sure yet. (fingers crossed)

[Matt <matt@…>]

I did have the utility install on 1 windows machine to configure the device. I went into Control Panel -> Program and Features and uninstalled the Ceton Software. It asked to reboot the machine to complete the uninstall which I did at that time. You also said "including drivers" did you have to do anything else to remove the drivers?

[mattlach@…]

I think that takes care of it. I just installed anything related to Ceton and rebooted.

I had it installed on a couple of machines though, one Windows VM on my desktop (I run Linux) and on my HTPC which runs Windows 8.1.

The problem SEEMS to have gone a way now, but I will have to wait and see. It's too early to confirm yet.

I'm probably going to have to create a dedicated VM just for Ceton configuration that I only run when I absolutely need to.

[JYA]

you should report the issue upstream. It's not acceptable that they change the tuning in the background without the user being aware of it

[Matt <matt@…>]

I have notified Ceton Linux Support (from Ceton "We do not support Linux or MythTV. However, we have a team of engineers that may be able to help you with questions pertaining to Linux. You may e-mail them at linux@….") of your conclusion. I will let you know what there response is.

[mattlach@…]

Agreed, if we can confirm this is the issue, it is definitely a Ceton issue, and not a MythTV issue.

Right now I know that running the Ceton Utility DEFINITELY changes the tuning (and will thus interrupt anything the tuner is used for) and as I recall (but can not check as I removed it) the GUI warns you against this.

What is less clear is whether the drivers do something in the background or play with Windows Media Center, and it tries to steal some of the tuners in the background without telling the user.

If uninstalling the software works for the other Matt as well, then maybe this is something that should be reported to Ceton.

I am just hesitant to come to that conclusion and close this ticket quite yet, as I have not had enough time to do conclusive testing that my problem is - in fact - solved.

[Matt <matt@…>]

response from Ceton: "We are unaware of any reason that the Windows utility would cause issues with a separate Linux PC using the InfiniTV. Eric Kotz Ceton"

[mattlach@…]

Hmm. Well maybe it isn't the Ceton utility or drivers itself.

As I recall, the Ceton utility automatically sets up Windows Media Center (if installed) on the local machine. Maybe it is Windows Media Center causing the issues? (I should note, when I removed the Ceton utility, I also removed Windows Media Center from both machines using the add/remove windows features setting)

As I have said before, I haven't had enough time to test to see if the issue is solved, but I feel like if it weren't, I should have run into a few broken recordings by now. I ran into a bunch before removing the software from the two Windows machines that had it installed.

OP: Have you run into any more issues after uninstalling the Ceton utility?

[mattlach@…]

Hmm. Well maybe it isn't the Ceton utility or drivers itself.

As I recall, the Ceton utility automatically sets up Windows Media Center (if installed) on the local machine. Maybe it is Windows Media Center causing the issues? (I should note, when I removed the Ceton utility, I also removed Windows Media Center from both machines using the add/remove windows features setting)

As I have said before, I haven't had enough time to test to see if the issue is solved, but I feel like if it weren't, I should have run into a few broken recordings by now. I ran into a bunch before removing the software from the two Windows machines that had it installed.

OP: Have you run into any more issues after uninstalling the Ceton utility?

[JYA]

Replying to Matt <matt@…>:

response from Ceton: "We are unaware of any reason that the Windows utility would cause issues with a separate Linux PC using the InfiniTV. Eric Kotz Ceton"

You would hope that they are unaware of it :)

[mattlach@…]

Replying to jyavenard:

You would hope that they are unaware of it :)

Very true!

That being said, closed source software development is a very different environment, and known bugs aren't always published or even addressed in a timely manner, if deemed non-critical (which this might be, as they explicitly say Linux use is not supported) :p

[gigem]

Various, somewhat random, thoughts.

The Linux driver is not closed source. The firmware is, but the firmware for the vast majority of cards is too. In my few dealings with Ceton, they have been extremely helpful and cooperative.

You don't say what firmware and driver versions you are using. Make sure you have the latest or have very good reasons for not running the latest.

I seriously doubt that the Windows utility makes any difference of consequence.

If you suspect MythTV recorder issues, you need to run the backend with '-v record,channel' at a minimum.

My bets are on intermittent DRM changes or signal quality being the cause of the truncated recordings.

[mattlach@…]

Replying to gigem:

Various, somewhat random, thoughts.

The Linux driver is not closed source. The firmware is, but the firmware for the vast majority of cards is too. In my few dealings with Ceton, they have been extremely helpful and cooperative.

You don't say what firmware and driver versions you are using. Make sure you have the latest or have very good reasons for not running the latest.

I seriously doubt that the Windows utility makes any difference of consequence.

If you suspect MythTV recorder issues, you need to run the backend with '-v record,channel' at a minimum.

My bets are on intermittent DRM changes or signal quality being the cause of the truncated recordings.

Don't get me wrong here. Ceton seems like a good company and they make a solid product. I was just speaking in general about the realities of developing commercial software in an environment of multiple priorities. In my brief stint as a Software QA guy (which I hope to never do again :p ) I have seen this first hand.

I have not had a chance to look at my own logs, but the logs that OP posted clearly shows that something is coming in and changing the tuner channel to 0. This was the big hint to me, as this is exactly what the Ceton Windows utility does when you fire it up, as part of its checking for a functioning tuner and cable card process.

Where I suspect (but have not confirmed) the problem lies is in multiple networked hosts fighting over the same tuner.

Scenario:

MythTV is recording on tuner 0. Ceton's Windows configuration utility then goes through it's checking routine, and switches the channel to 0.

This is hardly a huge problem, as it should be up to the user to make sure they don't have multiple machines fighting over the same tuner, but what stood out to me was that this was happening even when the Ceton utility was not actively running, but for me the problem SEEMS to have gone away after uninstalling Cetons software and Windows Media Center from the other machines on the network.

Theory:

My working theory (which I have yet to confirm, and I am posting here hoping someone else will pick up and run with it, as I really don't have the time right now (I'm in the middle of both moving and switching jobs) is that the Ceton utility interrupts recordings by switching the channel to 0 during its testing sequence. Also, as part of running the setup, the Ceton utility configures Windows Media Center to use the tuner, adding an additional variable to the equation. After this, WMC may also be fighting with MythTV for the tuners, even when the Ceton utility is not actively running on Windows.

It's just a theory at this time, but it is based on my problem seemingly going away (it hasn't been long enough yet) after uninstalling Ceton software and WMC from my windows boxes.

It would be interesting to know how the handoff between tuners works when there are multiple hosts competing for tuners. There isn't by any chance a controlled system architecture document for all this is there? ;)

[Gary Buhrmaster <gary.buhrmaster@…>]

My bets

My WAG would include the possibility of interactions between multiple systems believing that they have control (the Alexander Haig problem).

Neither MythTV nor WMC share network tuners especially well (some systems/devices have locks, some do not). And by default WMC will tend to "own" all the devices it is configured with (a not unreasonable default for the average user). There are references to a configuration option in WMC to "disown" tuners to allow other systems to control them. One might want to look there, too, and disable WMC access to any Ceton device.

But a simple test case would be to turn the Windows computer off for a few weeks and see if the problem goes away. If getting rid of windows solves the problem, you have your answer.

[gigem]

If the problem was just with the infiniTV6 eth, yeah, my first guess would be interference from some other network device. However, the OP clearly stated the same problem existed with his original, infiniTV4 PCIe. For the same problem to exist in that case, he would have had to specifically configured his Linux host to bridge or route to the Ceton. If he really did that, it would help if he would confirm it. Of course, I could be too quick to assume the host was running Linux. If it was a Windows system already running WMC or Cetons demo code, then all bets are off.

[Matt <matt@…>]

Both the infiniTV4 PCIe and infiniTV6 eth were being used only with MythTV via Mythbuntu. While the infiniTV4 PCIe was in use there were no special routes defined for 192.168.200.1 (infiniTV4 PCIe IP Address) to allow external access to the PCIe tuner. The Ceton utility was installed on a Win7 Pro workstation that did have WMC but nothing was setup or configured in WMC. The original infiniTV4 PCIe was installed on a Win7 Pro workstation and WMC was configured to test the card when the cable company did the original setup of the cable card. After the test was complete that workstation was formatted and Mythbuntu was install on it. The problem does appear to be worse with the infiniTV6 eth tuner, it is happening almost daily. It happens on all different channels, the basic channels (ABC, NBC, CBS, FOX, CW) the cable channels (USA and TNT) and the premium channels (HBO). All of my recording are set to use the HD channels only, so I have no experience with problems on the SD channels. I do not believe that it has ever effect more then 1 of the 4 or 6 tuners at a time. There has been numerous occasions where multiple tuners have been recording and only 1 had a problem.

​http://cetoncorp.com/infinitv_support/linux_drivers/ "InfiniTV firmware Latest firmware is: Latest Firmware Image for PCIe and USB infiniTV (1.1.8.2) Latest Firmware Image for Ethernet infiniTV (13.5.6.132) Upload via the System tab on the device webpage"

from my tuner: Firmware Version: 13.5.6.132 Firmware Release Date: Friday, 03. May 2013 Firmware Install Date: Sept 14, 2009 Firmware Filename: ceton_monaco_prod_v1.IMAGE

[Matt <matt@…>]

Since removing the Ceton utility 6 shows have recorded without any problems, but that is not uncommon. I have gone a day or two (recording 2 to 8 shows each day) without a problem. Now if it goes the next 4 days without a problem (i have about 15 shows set to record each of the next 4 days, mostly 30 minutes shows) that would be uncommon.

[Matt <matt@…>]

I did have a problem today. A recording should have been 33 minutes and it was 29 minutes and 30 seconds.

mythbackend.log Jul 1 15:58:00 prdmt01 mythbackend: mythbackend[4574]: I Scheduler scheduler.cpp:2139 (HandleReschedule?) Reschedule requested for PLACE PrepareToRecord? Jul 1 15:58:00 prdmt01 mythbackend: mythbackend[4574]: I Scheduler scheduler.cpp:2252 (HandleReschedule?) Scheduled 306 items in 0.7 = 0.00 match + 0.00 check + 0.75 place Jul 1 15:58:30 prdmt01 mythbackend: mythbackend[4574]: I Scheduler mythdbcon.cpp:409 (PurgeIdleConnections?) New DB connection, total: 13 Jul 1 15:58:30 prdmt01 mythbackend: mythbackend[4574]: I TVRecEvent tv_rec.cpp:1567 (HandlePendingRecordings?) TVRec[1]: ASK_RECORDING 1 29 0 0 Jul 1 16:02:28 prdmt01 mythbackend: mythbackend[4574]: I CoreContext? mythdbcon.cpp:409 (PurgeIdleConnections?) New DB connection, total: 13 Jul 1 16:02:28 prdmt01 mythbackend: mythbackend[4574]: I TVRecEvent tv_rec.cpp:1050 (HandleStateChange?) TVRec[1]: Changing from None to RecordingOnly? Jul 1 16:02:28 prdmt01 mythbackend: mythbackend[4574]: I TVRecEvent mythdbcon.cpp:409 (PurgeIdleConnections?) New DB connection, total: 13 Jul 1 16:02:28 prdmt01 mythbackend: mythbackend[4574]: I TVRecEvent tv_rec.cpp:3602 (TuningCheckForHWChange) TVRec[1]: HW Tuner: 1->1 Jul 1 16:02:28 prdmt01 mythbackend: mythbackend[4574]: I CetonStreamHandler? recorders/iptvstreamhandler.cpp:127 (run) IPTVSH(::-1): run() Jul 1 16:02:28 prdmt01 mythbackend: mythbackend[4574]: N Scheduler autoexpire.cpp:264 (CalcParams?) AutoExpire?: CalcParams?(): Max required Free Space: 3.0 GB w/freq: 14 min Jul 1 16:02:28 prdmt01 mythbackend: mythbackend[4574]: I Scheduler scheduler.cpp:2689 (HandleRecordingStatusChange?) Tuning recording: "Boy Meets World":"Uncle Daddy": channel 1254 on cardid 1, sourceid 1 Jul 1 16:02:28 prdmt01 mythbackend: mythbackend[4574]: I CetonStreamHandler? recorders/cetonrtsp.cpp:413 (Setup) CetonRTSP: Transport: RTP/AVP;unicast;client_port=42640-42641 Jul 1 16:02:28 prdmt01 mythbackend: mythbackend[4574]: E ProcessRequest? programinfo.cpp:2358 (GetPlaybackURL) ProgramInfo?(1254_20140701195900.mpg): GetPlaybackURL: '1254_20140701195900.mpg' should be local, but it can not be found. Jul 1 16:02:29 mythbackend: last message repeated 2 times Jul 1 16:02:29 prdmt01 mythbackend: mythbackend[4574]: N CetonStreamHandler? recorders/dtvsignalmonitor.cpp:367 (HandlePMT) DTVSigMon[1](10.1.9.12-RTP.0): PMT says program 254 is encrypted Jul 1 16:02:29 prdmt01 mythbackend: mythbackend[4574]: I CoreContext? scheduler.cpp:704 (UpdateRecStatus?) Updating status for "Boy Meets World":"Uncle Daddy" on cardid 1 (Tuning => Recording) Jul 1 16:02:29 prdmt01 mythbackend: mythbackend[4574]: I TVRecEvent tv_rec.cpp:4129 (TuningNewRecorder?) TVRec[1]: rec->GetPathname?(): '/mythtv/livetv/1254_20140701195900.mpg' Jul 1 16:02:29 prdmt01 mythbackend: mythbackend[4574]: E TVRecEvent recorders/recorderbase.cpp:206 (SetStrOption?) RecBase?[1](10.1.9.12-RTP.0): SetStrOption?(...recordingtype): Option not in profile. Jul 1 16:02:29 prdmt01 mythbackend: mythbackend[4574]: I CetonStreamHandler? recorders/iptvstreamhandler.cpp:127 (run) IPTVSH(::-1): run() Jul 1 16:02:29 prdmt01 mythbackend: mythbackend[4574]: I CetonStreamHandler? recorders/cetonrtsp.cpp:413 (Setup) CetonRTSP: Transport: RTP/AVP;unicast;client_port=45698-45699 Jul 1 16:02:30 prdmt01 mythbackend: mythbackend[4574]: I PreviewGeneratorQueue? mythdbcon.cpp:409 (PurgeIdleConnections?) New DB connection, total: 16 Jul 1 16:02:31 prdmt01 mythbackend: mythbackend[4574]: I ProcessRequest? mainserver.cpp:1436 (HandleAnnounce?) MainServer::ANN Monitor Jul 1 16:02:31 prdmt01 mythbackend: mythbackend[4574]: I ProcessRequest? mainserver.cpp:1438 (HandleAnnounce?) adding: prdmt01 as a client (events: 0) Jul 1 16:02:31 prdmt01 mythbackend: mythbackend[4574]: I ProcessRequest? mainserver.cpp:1436 (HandleAnnounce?) MainServer::ANN Monitor Jul 1 16:02:31 prdmt01 mythbackend: mythbackend[4574]: I ProcessRequest? mainserver.cpp:1438 (HandleAnnounce?) adding: prdmt01 as a client (events: 1) Jul 1 16:05:27 prdmt01 mythbackend: mythbackend[4574]: N Expire autoexpire.cpp:264 (CalcParams?) AutoExpire?: CalcParams?(): Max required Free Space: 3.0 GB w/freq: 14 min Jul 1 16:19:27 prdmt01 mythbackend: mythbackend[4574]: N Expire autoexpire.cpp:264 (CalcParams?) AutoExpire?: CalcParams?(): Max required Free Space: 3.0 GB w/freq: 14 min Jul 1 16:28:00 prdmt01 mythbackend: mythbackend[4574]: I Scheduler scheduler.cpp:2139 (HandleReschedule?) Reschedule requested for PLACE PrepareToRecord? Jul 1 16:28:00 prdmt01 mythbackend: mythbackend[4574]: I Scheduler scheduler.cpp:2252 (HandleReschedule?) Scheduled 306 items in 0.7 = 0.00 match + 0.00 check + 0.73 place Jul 1 16:28:30 prdmt01 mythbackend: mythbackend[4574]: I TVRecEvent tv_rec.cpp:1567 (HandlePendingRecordings?) TVRec[2]: ASK_RECORDING 2 29 0 0 Jul 1 16:29:00 prdmt01 mythbackend: mythbackend[4574]: I TVRecEvent tv_rec.cpp:1050 (HandleStateChange?) TVRec[2]: Changing from None to RecordingOnly? Jul 1 16:29:00 prdmt01 mythbackend: mythbackend[4574]: I TVRecEvent mythdbcon.cpp:409 (PurgeIdleConnections?) New DB connection, total: 16 Jul 1 16:29:00 prdmt01 mythbackend: mythbackend[4574]: I TVRecEvent tv_rec.cpp:3602 (TuningCheckForHWChange) TVRec[2]: HW Tuner: 2->2 Jul 1 16:29:00 prdmt01 mythbackend: mythbackend[4574]: E ProcessRequest? programinfo.cpp:2358 (GetPlaybackURL) ProgramInfo?(1254_20140701202900.mpg): GetPlaybackURL: '1254_20140701202900.mpg' should be local, but it can not be found. Jul 1 16:29:00 prdmt01 mythbackend: mythbackend[4574]: E ProcessRequest? programinfo.cpp:2358 (GetPlaybackURL) ProgramInfo?(1254_20140701202900.mpg): GetPlaybackURL: '1254_20140701202900.mpg' should be local, but it can not be found. Jul 1 16:29:00 prdmt01 mythbackend: mythbackend[4574]: I CetonStreamHandler? recorders/iptvstreamhandler.cpp:127 (run) IPTVSH(::-1): run() Jul 1 16:29:00 prdmt01 mythbackend: mythbackend[4574]: N Scheduler autoexpire.cpp:264 (CalcParams?) AutoExpire?: CalcParams?(): Max required Free Space: 3.0 GB w/freq: 7 min Jul 1 16:29:00 prdmt01 mythbackend: mythbackend[4574]: I Scheduler scheduler.cpp:2689 (HandleRecordingStatusChange?) Tuning recording: "Boy Meets World":"Quiz Show": channel 1254 on cardid 2, sourceid 1 Jul 1 16:29:00 prdmt01 mythbackend: mythbackend[4574]: E ProcessRequest? programinfo.cpp:2358 (GetPlaybackURL) ProgramInfo?(1254_20140701202900.mpg): GetPlaybackURL: '1254_20140701202900.mpg' should be local, but it can not be found. Jul 1 16:29:00 prdmt01 mythbackend: mythbackend[4574]: I CetonStreamHandler? recorders/cetonrtsp.cpp:413 (Setup) CetonRTSP: Transport: RTP/AVP;unicast;client_port=34757-34758 Jul 1 16:29:02 prdmt01 mythbackend: mythbackend[4574]: N CetonStreamHandler? recorders/dtvsignalmonitor.cpp:367 (HandlePMT) DTVSigMon[2](10.1.9.12-RTP.1): PMT says program 254 is encrypted Jul 1 16:29:02 prdmt01 mythbackend: mythbackend[4574]: I CoreContext? scheduler.cpp:704 (UpdateRecStatus?) Updating status for "Boy Meets World":"Quiz Show" on cardid 2 (Tuning => Recording) Jul 1 16:29:02 prdmt01 mythbackend: mythbackend[4574]: I TVRecEvent tv_rec.cpp:4129 (TuningNewRecorder?) TVRec[2]: rec->GetPathname?(): '/mythtv/livetv/1254_20140701202900.mpg' Jul 1 16:29:02 prdmt01 mythbackend: mythbackend[4574]: E TVRecEvent recorders/recorderbase.cpp:206 (SetStrOption?) RecBase?[2](10.1.9.12-RTP.1): SetStrOption?(...recordingtype): Option not in profile. Jul 1 16:29:02 prdmt01 mythbackend: mythbackend[4574]: I CetonStreamHandler? recorders/iptvstreamhandler.cpp:127 (run) IPTVSH(::-1): run() Jul 1 16:29:02 prdmt01 mythbackend: mythbackend[4574]: I CetonStreamHandler? recorders/cetonrtsp.cpp:413 (Setup) CetonRTSP: Transport: RTP/AVP;unicast;client_port=50446-50447 Jul 1 16:29:04 prdmt01 mythbackend: mythbackend[4574]: I ProcessRequest? mainserver.cpp:1436 (HandleAnnounce?) MainServer::ANN Monitor Jul 1 16:29:04 prdmt01 mythbackend: mythbackend[4574]: I ProcessRequest? mainserver.cpp:1438 (HandleAnnounce?) adding: prdmt01 as a client (events: 0) Jul 1 16:29:04 prdmt01 mythbackend: mythbackend[4574]: I ProcessRequest? mainserver.cpp:1436 (HandleAnnounce?) MainServer::ANN Monitor Jul 1 16:29:04 prdmt01 mythbackend: mythbackend[4574]: I ProcessRequest? mainserver.cpp:1438 (HandleAnnounce?) adding: prdmt01 as a client (events: 1) Jul 1 16:32:01 prdmt01 mythbackend: mythbackend[4574]: I TVRecEvent tv_rec.cpp:1050 (HandleStateChange?) TVRec[1]: Changing from RecordingOnly? to None Jul 1 16:32:01 prdmt01 mythbackend: mythbackend[4574]: I TVRecEvent tv_rec.cpp:834 (FinishedRecording?) TVRec[1]: FinishedRecording?(1254_2014-07-01T19:59:00Z) damaged recq:<RecordingQuality? overall_score="0" key="1254_2014-07-01T19:59:00Z" countinuity_error_count="0" packet_count="16087395">#012 <Gap start="2014-07-01T20:00:00Z" end="2014-07-01T20:02:30Z" duration="150" />#012</RecordingQuality?> Jul 1 16:32:01 prdmt01 mythbackend: mythbackend[4574]: E CoreContext? mainserver.cpp:963 (customEvent) MainServer?: PREVIEW_SUCCESS but no receivers. Jul 1 16:32:01 prdmt01 mythbackend: mythbackend[4574]: I CoreContext? scheduler.cpp:704 (UpdateRecStatus?) Updating status for "Boy Meets World":"Uncle Daddy" on cardid 1 (Recording => Recorded) Jul 1 16:32:01 prdmt01 mythbackend: mythbackend[4574]: I Scheduler scheduler.cpp:2139 (HandleReschedule?) Reschedule requested for CHECK -3 226 0 UpdateRecStatus2 | Boy Meets World | Uncle Daddy | Eric begins dating a woman with a young child, prompting his friends and family to warn him about responsibility. | EP000838770086 Jul 1 16:32:01 prdmt01 mythbackend: mythbackend[4574]: I ProcessRequest? mainserver.cpp:1436 (HandleAnnounce?) MainServer::ANN Monitor Jul 1 16:32:01 prdmt01 mythbackend: mythbackend[4574]: I ProcessRequest? mainserver.cpp:1438 (HandleAnnounce?) adding: prdmt01 as a client (events: 0) Jul 1 16:32:01 prdmt01 mythbackend: mythbackend[4574]: I ProcessRequest? mainserver.cpp:1436 (HandleAnnounce?) MainServer::ANN Monitor Jul 1 16:32:01 prdmt01 mythbackend: mythbackend[4574]: I ProcessRequest? mainserver.cpp:1438 (HandleAnnounce?) adding: prdmt01 as a client (events: 1) Jul 1 16:32:02 prdmt01 mythbackend: mythbackend[4574]: I Scheduler scheduler.cpp:2252 (HandleReschedule?) Scheduled 305 items in 1.2 = 0.01 match + 0.00 check + 1.22 place Jul 1 16:32:29 prdmt01 mythbackend: mythbackend[4574]: I Metadata_6462 jobqueue.cpp:2156 (DoMetadataLookupThread?) JobQueue?: Metadata Lookup Starting for "Boy Meets World":"Uncle Daddy" recorded from channel 1254 at 2014-07-01T19:59:00Z Jul 1 16:32:29 prdmt01 mythbackend: mythbackend[4574]: I ProcessRequest? mainserver.cpp:1436 (HandleAnnounce?) MainServer::ANN Monitor Jul 1 16:32:29 prdmt01 mythbackend: mythbackend[4574]: I ProcessRequest? mainserver.cpp:1438 (HandleAnnounce?) adding: prdmt01 as a client (events: 0) Jul 1 16:32:29 prdmt01 mythbackend: mythbackend[4574]: I ProcessRequest? mainserver.cpp:1436 (HandleAnnounce?) MainServer::ANN Monitor Jul 1 16:32:29 prdmt01 mythbackend: mythbackend[4574]: I ProcessRequest? mainserver.cpp:1438 (HandleAnnounce?) adding: prdmt01 as a client (events: 1) Jul 1 16:32:30 prdmt01 mythbackend: mythbackend[4574]: I ProcessRequest? mainserver.cpp:1436 (HandleAnnounce?) MainServer::ANN Monitor Jul 1 16:32:30 prdmt01 mythbackend: mythbackend[4574]: I ProcessRequest? mainserver.cpp:1438 (HandleAnnounce?) adding: prdmt01 as a client (events: 0) Jul 1 16:32:30 prdmt01 mythbackend: mythbackend[4574]: I ProcessRequest? mainserver.cpp:1436 (HandleAnnounce?) MainServer::ANN Monitor Jul 1 16:32:30 prdmt01 mythbackend: mythbackend[4574]: I ProcessRequest? mainserver.cpp:1438 (HandleAnnounce?) adding: prdmt01 as a client (events: 1)

there was another recording that started at 16:29 (16:30 show but starts 1 minute early) on the same channel and it recorded without a problem.

[mattlach@…]

Replying to Matt <matt@…>:

I did have a problem today. A recording should have been 33 minutes and it was 29 minutes and 30 seconds.

mythbackend.log

there was another recording that started at 16:29 (16:30 show but starts 1 minute early) on the same channel and it recorded without a problem.

That is too bad. I thought we had this one solved. I still have not had an issue since removing the windows Ceton software.

[JYA]

Replying to mattlach@…:

That is too bad. I thought we had this one solved. I still have not had an issue since removing the windows Ceton software.

I think the difference is so little that it may be insignificant and may not show an actual issue

[JYA]

any updates?

[mattlach@…]

Well,

I am guessing my problem and the ops problem are different.

My problem disappeared completely after removing the Ceton software from all computers on the local network and never reappeared again.

This apparently did not solve his issues.

--Matt(2)

[Matt <matt@…>]

Still the same thing. If i have 15 recording 1 day at least 2 of them will stopped early.

I have noticed a few things.

It seems to happen at a similar day/time of the week. Like I have setup to record old episodes of shows. There is one show that plays 2 episodes Thursday mornings at like 0400 and 0500. At least one of them will fail every week but it is not always the same one. what i mean is, 1 week it will be the 0400 one the next week it will be the 0500 one.

the server was under an extreme load between 2300 and 0900 (the next morning). this is due to me transcoding the shows. i assumed the high load on the server might cause issues so i stopped the transcoding. It has been 6 weeks since i stop transcoding and it has not gotten any better.

last thing that I noticed. the recordings page in mythfrontend, the recorded programs and upcoming recordings in mythweb sometime take a long time to load and sometimes they never load at all. after checking a few things: load on the server, disk i/o, network i/o, and the database (mysql database is hosted on a different server then mythbackend). I noticed that there was a lot of table level locks on the database. every time now that mythfrontend recording pages is slow or never loads or mythweb's recorded programs / upcoming recordings is slow or never loads i check the database and every time there is locks there. if i kill the locks, mythfrontend or myweb will load instantly (like it normally does).

changes i have made: i run mythbuntu and was on 12.04.4. i upgrade to mythbuntu 14.04.1

my database server is a VMWare 5.5 VM running on CentOS 6.4.

upgrade my network connection on my VMWare ESXi 5.5 host from 4 1GB connections in a VMWare standard switch to 4 1GB connections in a VMWare distributed switch with LACP configured upgrade my storage network connection on my VMWare ESXi 5.5 host from 4 1GB connections in a VMWare standard switch to 4 1GB connections in a vmware distributed switch with LACP configured moved the VM from a datastore that was on local storage (1 sata hard drive) to a datastore that is NFS storage (8 sata hard drives connection to a PERC 6/i configured in RAID 1+0) being hosted by openmediavault.

today is just the second day since everything is running on the new configuration and as of now there has been no recordings that have stopped early.

[Stuart Auchterlonie]

Closing all old tickets in trac.

If your issue still persists, please open an issue in Github ​https://github.com/MythTV/mythtv/issues

and reference the existing trac ticket.