TiVo won't download guide data

Printable View

26-06-2004, 04:48 PM
peterd

TiVo won't download guide data

My TiVo can ping the guide data server, and the server is specified correctly in the config file. However, when I force TiVo to "make daily call now", I get the error message "Failed. Service unavailable".

Here is the log. Any ideas?

Jun 26 18:40:11 (none) tcphonehome[111]: Setting MCP PhoneHome action: RUNNING
Jun 26 18:40:11 (none) tcphonehome[111]: pCommMempool empty
Jun 26 18:40:11 (none) tcphonehome[111]: useBackupTollFree is 0
Jun 26 18:40:11 (none) tcphonehome[111]: phonehome: received message. type = 30 subtype = 3
Jun 26 18:40:11 (none) tcphonehome[111]: creating CommGlobals
Jun 26 18:40:11 (none) tcphonehome[111]: created CommGlobals
Jun 26 18:40:11 (none) tcphonehome[111]: PerformCall, subtype=3 forceTollFree=0 automated=0
Jun 26 18:40:11 (none) tcphonehome[111]: setCallStatus called with: In Progress state 1
Jun 26 18:40:11 (none) tcphonehome[111]: LastCallAttempt at 1088274714
Jun 26 18:40:11 (none) tcphonehome[111]: setting call status to: In Progress
Jun 26 18:40:11 (none) tcphonehome[111]: setting call in progress to 1 (second successCount)
Jun 26 18:40:11 (none) tcphonehome[111]: Setting callActive to 1
Jun 26 18:40:11 (none) tcphonehome[111]: setting call attempt
Jun 26 18:40:11 (none) tcphonehome[111]: Error statting file /var/log/http: No such file or directory (errno=2)
Jun 26 18:40:11 (none) tcphonehome[111]: Error statting file /var/log/Omessages: No such file or directory (errno=2)
Jun 26 18:40:11 (none) tcphonehome[111]: Error statting file /var/log/Okernel: No such file or directory (errno=2)
Jun 26 18:40:11 (none) tcphonehome[111]: Error statting file /var/log/Otverr: No such file or directory (errno=2)
Jun 26 18:40:11 (none) tcphonehome[111]: Error statting file /var/log/Okdebug: No such file or directory (errno=2)
Jun 26 18:40:11 (none) tcphonehome[111]: Error statting file /var/log/Otvdebuglog: No such file or directory (errno=2)
Jun 26 18:40:11 (none) tcphonehome[111]: Error statting file /var/log/Otvlog: No such file or directory (errno=2)
Jun 26 18:40:11 (none) tcphonehome[111]: Error statting file /var/log/Otclient: No such file or directory (errno=2)
Jun 26 18:40:11 (none) tcphonehome[111]: Error statting file /var/log/Otcdebuglog: No such file or directory (errno=2)
Jun 26 18:40:11 (none) tcphonehome[111]: Error statting file /var/log/Ohttp: No such file or directory (errno=2)
Jun 26 18:40:11 (none) tcphonehome[111]: Calling TClient
Jun 26 18:40:11 (none) comm[111]: CallStatusReporter: Phase: Select_Phone, Status In Progress
Jun 26 18:40:11 (none) comm[111]: CallStatusReporter: sending message "EX|29"
Jun 26 18:40:12 (none) comm[111]: CallService: preprocessing call.
Jun 26 18:40:12 (none) comm[111]: CallStatusReporter: Phase: Prepare_Call, Status In Progress
Jun 26 18:40:12 (none) comm[111]: CallStatusReporter: sending message "EX|29"
Jun 26 18:40:12 (none) comm[111]: SvcLogRqst: open(/var/log/svclog.tmp)ed (tmpfd = 25)
Jun 26 18:40:12 (none) comm[111]: SvcLogRqst: open(/var/log/svclog.upload)ed (uploadfd = 26)
Jun 26 18:40:12 (none) comm[111]: SvcLogRqst: final (357 bytes)::read() (status = 0)
Jun 26 18:40:12 (none) comm[111]: SvcLogRqst: unlink(/var/log/svclog.tmp)ed (status = 0)
Jun 26 18:40:12 (none) comm[111]: Start Ident ==================
Jun 26 18:40:12 (none) comm[111]: version: 3
Jun 26 18:40:12 (none) comm[111]: centerID: 0020000203D4C2E
Jun 26 18:40:12 (none) comm[111]: reasonCode: 4
Jun 26 18:40:12 (none) comm[111]: softwareDesc: NONE
Jun 26 18:40:12 (none) comm[111]: locationID: NONE
Jun 26 18:40:12 (none) comm[111]: sequenceCookie: NONE
Jun 26 18:40:12 (none) comm[111]: headendID: NONE
Jun 26 18:40:12 (none) comm[111]: headendHisto:
Jun 26 18:40:12 (none) comm[111]: headendWorst:
Jun 26 18:40:12 (none) comm[111]: showcaseDesc: NONE
Jun 26 18:40:12 (none) comm[111]: inventoryFile:
Jun 26 18:40:12 (none) comm[111]: waitingCount:
Jun 26 18:40:12 (none) comm[111]: confInfo:
Jun 26 18:40:12 (none) comm[111]: dialConfig:
Jun 26 18:40:12 (none) comm[111]: messageDesc:
Jun 26 18:40:12 (none) comm[111]: irdbVersion:
Jun 26 18:40:12 (none) comm[111]: genreVersion:
Jun 26 18:40:12 (none) comm[111]: logoVersion:
Jun 26 18:40:12 (none) comm[111]: affiliationVersion:
Jun 26 18:40:12 (none) comm[111]: showcaseVersion:
Jun 26 18:40:12 (none) comm[111]: demoMode:
Jun 26 18:40:12 (none) comm[111]: swVerName: 3.0-01-1-000
Jun 26 18:40:12 (none) comm[111]: apgOnly:
Jun 26 18:40:12 (none) comm[111]: useChksums: TRUE
Jun 26 18:40:12 (none) comm[111]: premiumShowcases:
Jun 26 18:40:12 (none) comm[111]: captureRequests:
Jun 26 18:40:12 (none) comm[111]: menuItems:
Jun 26 18:40:12 (none) comm[111]: collabData:
Jun 26 18:40:12 (none) comm[111]: signedFiles:
Jun 26 18:40:12 (none) comm[111]: otherDatasets:
Jun 26 18:40:12 (none) comm[111]: rbBackgrounds:
Jun 26 18:40:12 (none) comm[111]: dataGroupList:
Jun 26 18:40:12 (none) comm[111]: lastAvalDownload:
Jun 26 18:40:12 (none) comm[111]: userInitiated:
Jun 26 18:40:12 (none) comm[111]: mfsTotalApp:
Jun 26 18:40:12 (none) comm[111]: mfsAvailApp:
Jun 26 18:40:12 (none) comm[111]: mfsTotalMedia:
Jun 26 18:40:12 (none) comm[111]: mfsAvailMedia:
Jun 26 18:40:12 (none) comm[111]: clipsTotalSize:
Jun 26 18:40:12 (none) comm[111]: clipsAvailSize:
Jun 26 18:40:12 (none) comm[111]: rbTotalSize:
Jun 26 18:40:12 (none) comm[111]: rbAvailSize:
Jun 26 18:40:12 (none) comm[111]: tcdId: 0020000203D4C2E
Jun 26 18:40:12 (none) comm[111]: callId: 1088275211
Jun 26 18:40:12 (none) comm[111]: sourceParameterList:
Jun 26 18:40:12 (none) comm[111]: configParameterList:
Jun 26 18:40:12 (none) comm[111]: iceboxinfo:
Jun 26 18:40:12 (none) comm[111]: timeStamp: ...
Jun 26 18:40:12 (none) comm[111]: End Ident ==================
Jun 26 18:40:12 (none) comm[111]: CallService: Start err 0
Jun 26 18:40:12 (none) comm[111]: CAM_ID not found.
Jun 26 18:40:12 (none) comm[111]: CallStatusReporter: Phase: Dial, Status In Progress
26-06-2004, 04:49 PM
peterd

Jun 26 18:40:12 (none) comm[111]: CallStatusReporter: sending message "CL|30"
Jun 26 18:40:12 (none) comm[111]: Backdoor code 4, enable calls via broadband
Jun 26 18:40:12 (none) comm[111]: Using Ethernet. Not starting modem/pppd.
Jun 26 18:40:12 (none) comm[111]: CallStatusReporter: Phase: Start_Auth, Status In Progress
Jun 26 18:40:12 (none) comm[111]: CallStatusReporter: sending message "ST|33"
Jun 26 18:40:12 (none) comm[111]: CommUtil: connection to host 66.238.88.163, port 80, err 0x0
Jun 26 18:40:12 (none) comm[111]: Uploading HTTP Header for modLog of /var/log/svclog: POST /tivo-service/mlog.cgi HTTP/1.0^M Content-Length: 357^M ^M
Jun 26 18:40:12 (none) comm[111]: read HTTP Header: HTTP/1.0 200 OK^M Date: Sat, 26 Jun 2004 06:41:54 GMT^M Content-Type: text/plain; charset=ISO-8859-1^M Server: Apache/1.3.31 (Unix) (Gentoo/Linux) PHP/4.3.6 mod_gzip/1.3.26.1a^M Via: 1.1 nc2 (NetCache NetApp/5.5R4), 1.1 nc1-acld (NetCache Ne
Jun 26 18:40:12 (none) comm[111]: tApp/5.5D2)^M X-Cache: MISS from fender^M Connection: close
Jun 26 18:40:12 (none) comm[111]: SvcLogRqst::verify: enter
Jun 26 18:40:12 (none) comm[111]: SvcLogRqst::verify: unlink(/var/log/svclog.upload)ed (status = 0)
Jun 26 18:40:12 (none) comm[111]: CommUtil: connection to host 66.238.88.163, port 80, err 0x0
Jun 26 18:40:12 (none) comm[111]: read 1027 bytes of upload data for HServerRqst
Jun 26 18:40:13 (none) comm[111]: HServerRqst::evaluate starting
Jun 26 18:40:13 (none) comm[111]: HTTP header: HTTP/1.0 411 Length Required^M
Jun 26 18:40:13 (none) comm[111]: HTTP header: Server: squid/2.5.STABLE4^M
Jun 26 18:40:13 (none) comm[111]: HTTP header: Mime-Version: 1.0^M
Jun 26 18:40:13 (none) comm[111]: HTTP header: Date: Sat, 26 Jun 2004 06:41:17 GMT^M
Jun 26 18:40:13 (none) comm[111]: HTTP header: Content-Type: text/html^M
Jun 26 18:40:13 (none) comm[111]: HTTP header: Content-Length: 2239^M
Jun 26 18:40:13 (none) comm[111]: HTTP header: Expires: Sat, 26 Jun 2004 06:41:17 GMT^M
Jun 26 18:40:13 (none) comm[111]: HTTP header: X-Squid-Error: ERR_INVALID_REQ 0^M
Jun 26 18:40:13 (none) comm[111]: HTTP header: X-Cache: MISS from fender^M
Jun 26 18:40:13 (none) comm[111]: HTTP header: Connection: close^M
Jun 26 18:40:13 (none) comm[111]: HTTP header: ^M
Jun 26 18:40:13 (none) comm[111]: Required Parameter ERR_MSG not present
Jun 26 18:40:13 (none) comm[111]: Required Parameter VERSION not present
Jun 26 18:40:13 (none) comm[111]: Required Parameter CODE not present
Jun 26 18:40:13 (none) comm[111]: Required Parameter SW_LIST not present
Jun 26 18:40:13 (none) comm[111]: Required Parameter BACK_CH_PRV not present
Jun 26 18:40:13 (none) comm[111]: Required Parameter BACK_CH_PUB not present
Jun 26 18:40:13 (none) comm[111]: Required Parameter BACK_CH_LOG not present
Jun 26 18:40:13 (none) comm[111]: Required Parameter TIME_SVC not present
Jun 26 18:40:13 (none) comm[111]: Required Parameter SEQ_COOKIE not present
Jun 26 18:40:13 (none) comm[111]: Required Parameter INV_FILE not present
Jun 26 18:40:13 (none) comm[111]: Required Parameter NO_PRV_BACKHAUL not present
Jun 26 18:40:13 (none) comm[111]: Required Parameter SERVICE_STATE not present
Jun 26 18:40:13 (none) comm[111]: Required Parameter STATE_EXPIRE not present
Jun 26 18:40:13 (none) comm[111]: Required Parameter SW_SYSTEM_NAME not present
Jun 26 18:40:13 (none) comm[111]: HServerRqst: readBlock failed, err = 0xffff
Jun 26 18:40:13 (none) comm[111]: NetAgent: drainEvalQ failed, err = 0xffff
Jun 26 18:40:13 (none) comm[111]: CallService: NetAgent Process err 65535
Jun 26 18:40:13 (none) comm[111]: CallService: NetAgent failed, status 0xffff
Jun 26 18:40:13 (none) comm[111]: CallService: EndCall start
Jun 26 18:40:15 (none) comm[111]: CallStatusReporter: Turning off-hook LED off
Jun 26 18:40:15 (none) tcphonehome[111]: CallService return status 0xffff
Jun 26 18:40:15 (none) comm[111]: CallStatusReporter: Phase: Start_Auth, Status Failed
Jun 26 18:40:15 (none) comm[111]: CallStatusReporter: sending message "EX|14"
Jun 26 18:40:15 (none) tcphonehome[111]: TClient failed: EX|14
Jun 26 18:40:15 (none) tcphonehome[111]: Sending dialup event, subtype 8, msg EX|14
Jun 26 18:40:15 (none) tcphonehome[111]: setCallStatus called with: Failed state 0
Jun 26 18:40:20 (none) tcphonehome[111]: LastCallAttempt at 1088275211
Jun 26 18:40:20 (none) tcphonehome[111]: setting call status to: Failed
Jun 26 18:40:20 (none) tcphonehome[111]: setting call in progress to 0 (second successCount)
Jun 26 18:40:20 (none) tcphonehome[111]: Setting callActive to 0
Jun 26 18:40:20 (none) comm[111]: CallStatusReporter: sending data changed event 20
Jun 26 18:40:20 (none) tcphonehome[111]: destroying CommGlobals!
Jun 26 18:40:20 (none) tcphonehome[111]: pCommMempool empty
Jun 26 18:40:20 (none) tcphonehome[111]: Setting MCP PhoneHome action: ENABLED
27-06-2004, 09:45 AM
peterd

I solved this issue.

If anyone else has this problem, try turning off your proxy.