Daily call fails

[miketivo]

Hi all

Wondering if you could point me in the right direction, one of my tivo's has a turbonet card is all set up and working however the daily calls regualrly fail 9 out of 10 times, yet when I make a test call all is fine each time, yet when I force a daily call this fails maybe 4 out 5 times, tivo even managed to run out of guide data before I noticed this was going on.

Tivo seems to dial in ok over the network but has trouble and stalls on the 'connecting' phase and fails????

Any help or suggestions greatly appreciated.

[macella]

Yes, I am having a similar issue. Internet call. Test call is fine. Then you force a daily call and it fails. Working perfectly until Sunday/Monday.

Error is "number not available"

Soft reboot from menu did not seem to work, but a hard reboot by removing the cable seems to have done the job. Will monitor over next couple of days.

[macella]

so, I still get a lot of failed daily calls. Sometimes have to try 5+ times to get it to download. Below is my TClient log from the last failed call.

Interestingly it seems to read the 'header' from the EPG server, then fall over......

Any ideas??

Code: Select all

07/03:22:50:55: /tvbin/TClient:  SendDialupEvent 30 9 ST|33
07/03:22:50:55: /tvbin/TClient:  About to connect to 194.1.151.205:80
07/03:22:50:55: /tvbin/TClient:  Executing HTTP command: /tvbin/http_post /var/log/svclog http://194.1.151.205:80/tivo-service/mlog.cgi OFF OFF ON
07/03:22:50:56: /tvbin/TClient:  about to do TCD411 Call
07/03:22:50:56: /tvbin/TClient:  Executing HTTP command: /tvbin/tclient_post 194.1.151.205:80 /var/tmp/TCD411.send /var/tmp/TCD411.recv 300 ON
07/03:22:50:56: /tvbin/TClient:  doHttpCall returned: 1
07/03:22:50:56: /tvbin/TClient:  reading HTTP header...
07/03:22:50:56: /tvbin/TClient:  HTTP header: HTTP/1.1 200 OK
07/03:22:50:56: /tvbin/TClient:  HTTP header: Date: Tue, 03 Jul 2012 22:50:56 GMT
07/03:22:50:56: /tvbin/TClient:  HTTP header: Server: Apache/2.2.14 (Ubuntu)
07/03:22:50:56: /tvbin/TClient:  HTTP header: Vary: Accept-Encoding
07/03:22:50:56: /tvbin/TClient:  HTTP header: Connection: close
07/03:22:50:56: /tvbin/TClient:  HTTP header: Content-Type: text/plain; charset=ISO-8859-1
07/03:22:50:56: /tvbin/TClient:  Got end of Header
07/03:22:50:56: /tvbin/TClient:  TCD411RespCli::readBlock returned: 1
07/03:22:50:56: /tvbin/TClient: 
07/03:22:50:56: /tvbin/TClient:     Start TCD411Resp =====================
07/03:22:50:56: /tvbin/TClient:              errMsg:
07/03:22:50:56: /tvbin/TClient:         areaCodeObj: OK
07/03:22:50:56: /tvbin/TClient:        tollFreeAuth: 0
07/03:22:50:56: /tvbin/TClient:         tollFreeNum: 0
07/03:22:50:56: /tvbin/TClient:       End TCD411Resp =====================

07/03:22:50:57: /tvbin/TClient:  about to do HServer Call
07/03:22:50:57: /tvbin/TClient:  Executing HTTP command: /tvbin/tclient_post 194.1.151.205:80 /var/tmp/HServer.send /var/tmp/HServer.recv 300 ON
07/03:22:51:57: /tvbin/TClient:  doHttpCall returned: 1
07/03:22:51:57: /tvbin/TClient:  reading HTTP header...
07/03:22:51:57: /tvbin/TClient:  Got end of File
07/03:22:51:57: /tvbin/TClient:  Expected field ERR_MSG not found, got:
07/03:22:51:57: /tvbin/TClient:  SvrResp::readBlock returned: 0
07/03:22:51:57: /tvbin/TClient:  Connect/POST has failed, we've warned the user, set status to Failed
07/03:22:51:57: /tvbin/TClient:  failed connect - aborting
07/03:22:51:57: /tvbin/TClient:  Will kill pppd
07/03:22:52:02: /tvbin/TClient:  updateStatus: Failed ST| 33 14
Saving 'ST|14' to result file
07/03:22:52:02: /tvbin/TClient:  writing Failed to LastCallStatus
07/03:22:52:03: /tvbin/TClient:  SendDialupEvent 30 9 EX|14
07/03:22:52:03: /tvbin/TClient:  TClient login: 1
07/03:22:52:03: /tvbin/TClient:  TClient backhaulDone: 0
bash-2.02# ~

[millsb]

Interestingly it seems to read the 'header' from the EPG server, then fall over......

What you're seeing there is some kind of network timeout. In this particular case the HServer call at 07/03:22:50:57 times out 60 seconds later, so TiVo sees this as an null response. This would appear to be something in the network chain actively invoking a timeout: TiVo will timeout if it doesn't get a response after 5 minutes (that's what the "300" parameter means), but it's not TiVo timing out in this case.

I've looked in the server logs and this call never reached the server, so the timeout is happening at some intermediate point. What is the configuration of your connection to the internet? Is there a proxy or similar that could be misbehaving?

To test this further you can kick off that http_post command from the telnet (bash) prompt, ie:

Code: Select all

/tvbin/tclient_post 194.1.151.205:80 /var/tmp/HServer.send /var/tmp/HServer.recv 300 ON


Which is a lot quicker than firing off a daily call from the UI.

[asfafa]

Sorry to hijack this thread for myself, but the Daily Call on my TiVo has been failing since Saturday with similar messages in the tclient.log:

Code: Select all

07/24:13:27:39: /tvbin/TClient:  about to do HServer Call
07/24:13:27:39: /tvbin/TClient:  Executing HTTP command: /tvbin/tclient_post 194.1.151.205:80 /var/tmp/HServer.send /var/tmp/HServer.recv 300 ON
07/24:13:28:39: /tvbin/TClient:  doHttpCall returned: 1
07/24:13:28:39: /tvbin/TClient:  reading HTTP header...
07/24:13:28:39: /tvbin/TClient:  Got end of File
07/24:13:28:39: /tvbin/TClient:  Expected field ERR_MSG not found, got:
07/24:13:28:39: /tvbin/TClient:  SvrResp::readBlock returned: 0
07/24:13:28:40: /tvbin/TClient:  Connect/POST has failed, we've warned the user, set status to Failed
07/24:13:28:40: /tvbin/TClient:  failed connect - aborting
07/24:13:28:40: /tvbin/TClient:  Will kill pppd
07/24:13:28:45: /tvbin/TClient:  updateStatus: Failed ST| 33 14
Saving 'ST|14' to result file
07/24:13:28:45: /tvbin/TClient:  writing Failed to LastCallStatus
07/24:13:28:45: /tvbin/TClient:  SendDialupEvent 30 9 EX|14
07/24:13:28:46: /tvbin/TClient:  TClient login: 1
07/24:13:28:46: /tvbin/TClient:  TClient backhaulDone: 0


Making a Test Call is fine.

If I run the tclient_post command on the command line, I get:

Code: Select all

Tue Jul 24 13:33:22 2012: /tvbin/tclient_post invoked
 connecting to 194.1.151.205:80
 read 2502 bytes from file
writing 2502 bytes to socket
socket 5 ready for writing
wrote 2502 bytes to socket
 EOF read from file
 select-ing for header
data ready on socket 5
EOF read on connection
Tue Jul 24 13:34:22 2012: /tvbin/tclient_post finished


Also, I checked my account on altepg.com and can see the same error over the past few days:

Code: Select all

cd_driveid   Mon Jul 23 08:05:00 2012   Mon Jul 23 08:07:07 2012   HDA=S1VSJ90B503555 HDB=Unknown
tclient_result   Mon Jul 23 08:05:00 2012   Mon Jul 23 08:08:14 2012   STATUS=Failed
ird_id   Tue Jul 24 07:16:19 2012   Tue Jul 24 07:18:22 2012   ID=531F51EE


Any ideas? I haven't made any changes to the setup other than a new router a few weeks back.

Thanks in advance

Paul

[asfafa]

So after about 10 attempts, the daily call was finally successful. I'm still puzzled as to why it is failing so many times though.

[millsb]

It sounds like there's something wrong in your home network such as two devices with the same IP address or two devices with the same MAC address. There are no connection errors logged at the server for your IP address so in the cases where it's failing it looks like the requests aren't getting out of your network.

Are you running an AltEPG image or a pre-AltEPG image reconfigured to work with the AltEPG service?

[asfafa]

I'm running a pre-AltEPG image running AltEPG service.

Since I have a relatively new router (Billion 7800n), I think I will play around with the DHCP server settings, and see if excluding the 192.168.1.200 address helps...