Ceton Cablecard Firmware Upgrade Problem?

[signcarver]

In the past, none of my devices have had a problem with a provider issued firmware upgrade for the cablecards... a few weeks ago my provider (cox phoenix) started rolling out PKEY1.5.3_F.p.1301 and every day for a week I have been waking up to a message in WMC stating there is a firmware upgrade and the only response is OK, then there is another nonsense message

(I have to press OK about a dozen with various frequencies occasionally the video is frozen until I restart WMC)

I know some devices need to reboot after getting the upgrade so I have also tried that but I am still on PKEY1.5.3_F.p.0601 I checked my STBs and they did not originally upgrade either but slowly each of my devices have been getting the firmware and now the only one left is my main ceton USB tuner (I say this is main as it is dedicated to my main machine where others are shared)... In looking over the logs I see:

Code: Select all

Jan  1 08:52:26 ocur[21]: upnp: Event(octa[6]): UDCPMessage, "AwYAIgH//wAdASt/AQQABALvnP8aAEqpcf8aBBoa5P8aAAAAAP8="
Jan  1 08:55:02 ocur[21]: ocur: Upgrade Source: 1
Jan  1 08:55:02 ocur[21]: ocur: Download Time: 14400
Jan  1 08:55:02 ocur[21]: ocur: Timeout Type: 0
Jan  1 08:55:02 ocur[21]: ocur: Download Timeout Period: 14400
Jan  1 08:55:02 ocur[21]: ocur: User Notification Text: Preparing for CableCARD firmware upgrade...
Jan  1 08:55:02 ocur[21]: ocur: Received firmware request
Jan  1 08:55:02 ocur[21]: upnp: Event(cas[0]): CardStatus, "Firmware Upgrade"
Jan  1 08:55:02 ocur[21]: upnp: Event(cas[1]): CardStatus, "Firmware Upgrade"
Jan  1 08:55:02 ocur[21]: upnp: Event(cas[2]): CardStatus, "Firmware Upgrade"
Jan  1 08:55:02 ocur[21]: upnp: Event(cas[3]): CardStatus, "Firmware Upgrade"
Jan  1 08:55:02 ocur[21]: ocur: SetCardMessage = Preparing for CableCARD firmware upgrade...
Jan  1 08:55:02 ocur[21]: upnp: Event(cas[0]): CardMessage, "Preparing for CableCARD firmware upgrade..."
Jan  1 08:55:02 ocur[21]: upnp: Event(cas[1]): CardMessage, "Preparing for CableCARD firmware upgrade..."
Jan  1 08:55:02 ocur[21]: upnp: Event(cas[2]): CardMessage, "Preparing for CableCARD firmware upgrade..."
Jan  1 08:55:02 ocur[21]: upnp: Event(cas[3]): CardMessage, "Preparing for CableCARD firmware upgrade..."
Jan  1 08:55:02 ocur[21]: ocur: Found free tuner at instance 1
Jan  1 08:55:02 ocur[21]: ocur: Setting reserved stream 1
Jan  1 08:55:02 ocur[21]: ocur: Setting mpeg_enabled setting for 1
Jan  1 08:55:02 ocur[21]: ocur: Going ahead with firmware update
Jan  1 08:55:02 ocur[21]: ocur: Doing card firmware update
Jan  1 08:55:02 ocur[21]: ocur: Checking connections to instance 0
Jan  1 08:55:02 ocur[21]: ocur: Checking connections to instance 1
Jan  1 08:55:02 ocur[21]: ocur: Found free tuner at instance 1
Jan  1 08:55:02 ocur[21]: ocur: Setting reserved stream 1
Jan  1 08:55:02 ocur[21]: ocur: Setting reserved stream 1
Jan  1 08:55:02 ocur[21]: ocur: Firmware update can proceed
Jan  1 08:55:02 ocur[21]: libctn91xx: ERROR: type: "MCARD Reported Error" d7 origin: 00 control_byte: 00 seqno: 00
Jan  1 08:55:02 ocur[21]: ocur: Card reset
Jan  1 08:55:02 ocur[21]: ocur: Setting reserved stream -1
Jan  1 08:55:02 ocur[21]: ocur: Repairing mpeg_enabled setting for 1
Jan  1 08:55:02 ocur[21]: ocur: Card reset done
Jan  1 08:55:02 ocur[21]: ocur: SetCardMessage = (null)
Jan  1 08:55:02 ocur[21]: upnp: Event(cas[0]): CardMessage, ""
Jan  1 08:55:02 ocur[21]: upnp: Event(cas[1]): CardMessage, ""
Jan  1 08:55:02 ocur[21]: upnp: Event(cas[2]): CardMessage, ""
Jan  1 08:55:02 ocur[21]: upnp: Event(cas[3]): CardMessage, ""
Jan  1 08:55:02 ocur[21]: upnp: Event(cas[0]): CardStatus, "Inserted"
Jan  1 08:55:02 ocur[21]: upnp: Event(cas[1]): CardStatus, "Inserted"
Jan  1 08:55:02 ocur[21]: upnp: Event(cas[2]): CardStatus, "Inserted"
Jan  1 08:55:02 ocur[21]: upnp: Event(cas[3]): CardStatus, "Inserted"
Jan  1 08:55:03 ocur[21]: ocur: Upgrade Source: 1
Jan  1 08:55:03 ocur[21]: ocur: Download Time: 14400
Jan  1 08:55:03 ocur[21]: ocur: Timeout Type: 2
Jan  1 08:55:03 ocur[21]: ocur: Download Timeout Period: 14400
Jan  1 08:55:03 ocur[21]: ocur: User Notification Text: CableCARD upgrade in progress. SC[0x00000001]
Jan  1 08:55:03 ocur[21]: ocur: Received firmware request
Jan  1 08:55:03 ocur[21]: upnp: Event(cas[0]): CardStatus, "Firmware Upgrade"
Jan  1 08:55:03 ocur[21]: upnp: Event(cas[1]): CardStatus, "Firmware Upgrade"
Jan  1 08:55:03 ocur[21]: upnp: Event(cas[2]): CardStatus, "Firmware Upgrade"
Jan  1 08:55:03 ocur[21]: upnp: Event(cas[3]): CardStatus, "Firmware Upgrade"
Jan  1 08:55:03 ocur[21]: ocur: SetCardMessage = CableCARD upgrade in progress. SC[0x00000001]
Jan  1 08:55:03 ocur[21]: upnp: Event(cas[0]): CardMessage, "CableCARD upgrade in progress. SC[0x00000001]"
Jan  1 08:55:03 ocur[21]: upnp: Event(cas[1]): CardMessage, "CableCARD upgrade in progress. SC[0x00000001]"
Jan  1 08:55:03 ocur[21]: upnp: Event(cas[2]): CardMessage, "CableCARD upgrade in progress. SC[0x00000001]"
Jan  1 08:55:03 ocur[21]: upnp: Event(cas[3]): CardMessage, "CableCARD upgrade in progress. SC[0x00000001]"
Jan  1 08:55:03 ocur[21]: ocur: Found free tuner at instance 1
Jan  1 08:55:03 ocur[21]: ocur: Setting reserved stream 1
Jan  1 08:55:03 ocur[21]: ocur: Setting mpeg_enabled setting for 1
Jan  1 08:55:03 ocur[21]: ocur: Going ahead with firmware update
Jan  1 08:55:03 ocur[21]: ocur: Doing card firmware update
Jan  1 08:55:03 ocur[21]: ocur: Checking connections to instance 0
Jan  1 08:55:03 ocur[21]: ocur: Checking connections to instance 1
Jan  1 08:55:03 ocur[21]: ocur: Found free tuner at instance 1
Jan  1 08:55:03 ocur[21]: ocur: Setting reserved stream 1
Jan  1 08:55:03 ocur[21]: ocur: Setting reserved stream 1
Jan  1 08:55:03 ocur[21]: ocur: Firmware update can proceed
Jan  1 08:55:09 ocur[21]: upnp: Event(cas[0]): MMIMessage, "AQABADVodHRwOi8vMTkyLjE2OC4xODAuMTo4MC9nZXRfY2NfdXJsP1xDYWJsZUNBUkRcT29iRmRjAA=="
Jan  1 08:55:09 ocur[21]: ocur: Opening dialog 1 on 1 instances
Jan  1 08:55:09 ocur[21]: upnp: [192.168.180.2] Calling Action(cas[0]) NotifyMmiClose
Jan  1 08:55:09 ocur[21]: ocur: Sending close_mmi_cnf for dialog 1
Jan  1 08:55:09 ocur[21]: ocur: 0x6c3e8
Jan  1 08:55:09 ocur[21]: upnp: Event(cas[0]): MMIMessage, "AQAA"
Jan  1 08:55:09 ocur[21]: upnp: [192.168.180.2] Action(cas[0]) NotifyMmiClose success
Jan  1 08:55:16 ocur[21]: ocur: Disabled table monitor for instance 1
Jan  1 08:55:16 ocur[21]: ocur: [1] Locked: 1 Acc E: 0
Jan  1 08:55:16 ocur[21]: ocur: [1] Tune finished to freq 693000
Jan  1 08:55:16 ocur[21]: libctn91xx: Clearing pid filter on 5
Jan  1 08:55:16 ocur[21]: libcetontrif: WARNING: No outstanding tune req/rsp, ignoring cnf.
Jan  1 08:55:18 ocur[21]: upnp: [192.168.180.2] Calling Action(ua[0]) UserActivityDetected
Jan  1 08:55:18 ocur[21]: upnp: Event(octa[6]): UDCPMessage, "AwYAIgH//wAdASz/AQQABALvnP8KAEqpcf8aBBoa5P8aAAAAAP8="
Jan  1 08:55:18 ocur[21]: upnp: [192.168.180.2] Action(ua[0]) UserActivityDetected success
Jan  1 08:55:19 ocur[21]: upnp: Event(cas[0]): MMIMessage, "AQABADVodHRwOi8vMTkyLjE2OC4xODAuMTo4MC9nZXRfY2NfdXJsP1xDYWJsZUNBUkRcT29iRmRjAA=="
Jan  1 08:55:19 ocur[21]: ocur: Opening dialog 1 on 1 instances
Jan  1 08:55:19 ocur[21]: upnp: [192.168.180.2] Calling Action(cas[0]) NotifyMmiClose
Jan  1 08:55:19 ocur[21]: ocur: Sending close_mmi_cnf for dialog 1
Jan  1 08:55:19 ocur[21]: ocur: 0x6c3e8
Jan  1 08:55:19 ocur[21]: upnp: Event(cas[0]): MMIMessage, "AQAA"
Jan  1 08:55:19 ocur[21]: upnp: [192.168.180.2] Action(cas[0]) NotifyMmiClose success
Jan  1 08:55:21 ocur[21]: ocur: Disabled table monitor for instance 1
Jan  1 08:55:21 ocur[21]: ocur: [1] Locked: 1 Acc E: 0
Jan  1 08:55:21 ocur[21]: ocur: [1] Tune finished to freq 693000
Jan  1 08:55:21 ocur[21]: libctn91xx: Clearing pid filter on 5
Jan  1 08:55:21 ocur[21]: libcetontrif: WARNING: No outstanding tune req/rsp, ignoring cnf.
Jan  1 08:55:22 ocur[21]: upnp: Event(tuner[1]): PCRLock, "0"
Jan  1 08:55:26 ocur[21]: ocur: Disabled table monitor for instance 1
Jan  1 08:55:27 ocur[21]: ocur: [1] Locked: 0 Acc E: 0
Jan  1 08:55:27 ocur[21]: ocur: [1] Tune finished to freq 693000
Jan  1 08:55:27 ocur[21]: libctn91xx: Clearing pid filter on 5
Jan  1 08:55:27 ocur[21]: libcetontrif: WARNING: No outstanding tune req/rsp, ignoring cnf.
Jan  1 08:55:27 ocur[21]: upnp: Event(tuner[1]): PCRLock, "1"
Jan  1 08:55:28 ocur[21]: ocur: Disabled table monitor for instance 1
Jan  1 08:55:28 ocur[21]: ocur: [1] Locked: 1 Acc E: 0
Jan  1 08:55:28 ocur[21]: ocur: [1] Tune finished to freq 693000
Jan  1 08:55:28 ocur[21]: libctn91xx: Clearing pid filter on 5
Jan  1 08:55:28 ocur[21]: libcetontrif: WARNING: No outstanding tune req/rsp, ignoring cnf.
Jan  1 08:55:28 ocur[21]: upnp: Event(tuner[1]): PCRLock, "0"
Jan  1 08:55:29 ocur[21]: upnp: Event(cas[0]): MMIMessage, "AQABADhodHRwOi8vMTkyLjE2OC4xODAuMTo4MC9nZXRfY2NfdXJsP1xDYWJsZUNBUkRcQ3Z0U3RhdHVzAA=="
Jan  1 08:55:29 ocur[21]: ocur: Opening dialog 1 on 1 instances
Jan  1 08:55:29 ocur[21]: ocur: Disabled table monitor for instance 1
Jan  1 08:55:29 ocur[21]: ocur: [1] Locked: 0 Acc E: 0
Jan  1 08:55:29 ocur[21]: ocur: [1] Tune finished to freq 555000
Jan  1 08:55:29 ocur[21]: libctn91xx: Clearing pid filter on 5
Jan  1 08:55:29 ocur[21]: libcetontrif: WARNING: No outstanding tune req/rsp, ignoring cnf.
Jan  1 08:55:29 ocur[21]: upnp: Event(tuner[1]): PCRLock, "1"
Jan  1 08:55:29 ocur[21]: upnp: [192.168.180.2] Calling Action(cas[0]) NotifyMmiClose
Jan  1 08:55:29 ocur[21]: ocur: Sending close_mmi_cnf for dialog 1
Jan  1 08:55:29 ocur[21]: ocur: 0x6c3e8
Jan  1 08:55:29 ocur[21]: upnp: Event(cas[0]): MMIMessage, "AQAA"
Jan  1 08:55:29 ocur[21]: upnp: [192.168.180.2] Action(cas[0]) NotifyMmiClose success
Jan  1 08:55:30 ocur[21]: ocur: Disabled table monitor for instance 1
Jan  1 08:55:30 ocur[21]: ocur: [1] Locked: 1 Acc E: 0
Jan  1 08:55:30 ocur[21]: ocur: [1] Tune finished to freq 555000
Jan  1 08:55:30 ocur[21]: upnp: Event(tuner[1]): PCRLock, "0"
Jan  1 08:55:30 ocur[21]: libctn91xx: Clearing pid filter on 5
Jan  1 08:55:30 ocur[21]: libcetontrif: WARNING: No outstanding tune req/rsp, ignoring cnf.
Jan  1 08:55:31 ocur[21]: ocur: Disabled table monitor for instance 1
Jan  1 08:55:31 ocur[21]: ocur: [1] Locked: 0 Acc E: 0
Jan  1 08:55:31 ocur[21]: ocur: [1] Tune finished to freq 657000
Jan  1 08:55:31 ocur[21]: upnp: Event(tuner[1]): PCRLock, "1"

Sorry for the length but I thought I should show a couple of frequencies... I believe my problem might be the card with the libctn91xx: ERROR: type: "MCARD Reported Error" d7 origin: 00 control_byte: 00 seqno: 00 causing the update to not take... another possibility since I can see it try a dozen frequencies is that it stated there was an update but at the time it got that message, there was no update being transmitted and eventually times out

I am not too worried about it in that everything works and the main purpose of the update is for improved 6 tuner support which this device doesn't need, it may even be the fact that it is an older 800 Card and the new firmware isn't compatible... I probably wouldn't even ask if it wasn't for the week of waking up to those messages in the morning and the video sometimes freezing as a result... I personally haven't checked but was told my 6 ETH at another house did get the update properly... my 2 primes and 2 STBs here also got the update eventually... seemed to be 1 device a night. It hasn't happened the last 3 nights and nothing in my log since then has indicated they were even trying to push it out the last few days... I believe my device here is the only one on the latest beta firmware and was wondering if it might be a coincidence or if others have noticed problems... If it is a problem with the card, I probably won't even bother to try and get it fixed... I also haven't tried putting the card in a prime and see if it updates (probably moot since they no longer seem to be actively pushing it at night) but getting the cards re-paired seems like it could be too much of a hassle (though part of me would like to see how well they handle it).

[adam1991]

Look here in the Ceton forum for a recent thread about WOW cable trying to get hold of Ceton. In there is a source thread about how Cable Labs has updated the cableCARD spec, and this update is a result of that.

As your screenshots say, the TV service provider is trying to upgrade their cableCARD. It's not at all about the tuner your card is plugged into. Call your provider.

[mcewinter]

Well you could post a link. After all, it's your thread...

http://www.thegreenbutton.tv/forums/vie ... 288#p79288

[STC]

Is that an expletive message from the TV Service Provider? I had to double take...it's just missing the U

I suppose it would be about right anyway lol.

[erkotz]

The log you posted shows the CableCARD seizing an in-band tuner and tuning for an update, but is only about 30 seconds long. CableCARD firmware upgrades usually take 10-20 minutes because of how they are broadcast.

[erkotz]

Look here in the Ceton forum for a recent thread about WOW cable trying to get hold of Ceton. In there is a source thread about how Cable Labs has updated the cableCARD spec, and this update is a result of that.

As your screenshots say, the TV service provider is trying to upgrade their cableCARD. It's not at all about the tuner your card is plugged into. Call your provider.

That's not really why - CableCARDs regularly get firmware upgrades.

[3rob3]

Funny, I got the same message last night as well. I have never seen that before.

[kd6icz]

I got that message too a few weeks ago. I didn't get a chance to read it because the screen had dimmed and I hit the OK button to wake it up which cleared it..