Page 7 of 10 FirstFirst ... 56789 ... LastLast
Results 61 to 70 of 95

Thread: Failed. Service Unavailable Part 2

  1. #61

    Another one...

    My Tivo started failing on data d/l on Wednesday. I read this thread and then decided to just shift to the Orac emulator port 8000, reboot the Tivo and leave it. I checked and it had done a guide data d/l in the middle of the day today and reports success. I did nothing except shift from Ed's to Orac and reboot Tivo.

  2. #62
    Heres the tclient log - part1-

    Aug 26 15:10:21 (none) tcphonehome[119]: TCphonehome active
    Aug 26 15:10:21 (none) tcphonehome[122]: cleaning /Setup
    Aug 26 15:10:21 (none) tcphonehome[122]: Fetching /SwSystemACTIVE/Name
    Aug 26 15:10:21 (none) tcphonehome[122]: Last Call Status Was: 'Failed' (size 6)
    Aug 26 15:10:21 (none) tcphonehome[122]: Last Call Status Will Be: Failed
    Aug 26 15:10:21 (none) tcphonehome[122]: setCallStatus called with: Failed state 0
    Aug 26 15:10:21 (none) tcphonehome[122]: LastCallAttempt at 1125066194
    Aug 26 15:10:21 (none) tcphonehome[122]: setting call status to: Failed
    Aug 26 15:10:21 (none) tcphonehome[122]: setting call in progress to 0 (second successCount)
    Aug 26 15:10:21 (none) tcphonehome[122]: Setting callActive to 0
    Aug 26 15:10:21 (none) tcphonehome[122]: PhoneHome: statusValue = <0>, getResult = <0>
    Aug 26 15:10:21 (none) tcphonehome[122]: /State/Avalanche LastStatus was <0> and getResult was <0>, changing to unknown
    Aug 26 15:10:21 (none) tcphonehome[122]: finished cleaning /Setup
    Aug 26 15:10:21 (none) tcphonehome[122]: About to execute: /sbin/ifconfig eth0 2>&1
    Aug 26 15:10:21 (none) tcphonehome[122]: Command Output: eth0 Link encap:Ethernet HWaddr 00:0B:AD:69:C6:67
    Aug 26 15:10:21 (none) tcphonehome[122]: Command Output: inet addr:0.0.0.0 Bcast:255.255.255.255 Mask:0.0.0.0
    Aug 26 15:10:21 (none) tcphonehome[122]: Command Output: UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1
    Aug 26 15:10:21 (none) tcphonehome[122]: Command Output: RX packets:0 errors:0 dropped:0 overruns:0 frame:0
    Aug 26 15:10:21 (none) tcphonehome[122]: Command Output: TX packets:0 errors:0 dropped:0 overruns:0 carrier:0 coll:0
    Aug 26 15:10:21 (none) tcphonehome[122]: Command Output: Interrupt:29
    Aug 26 15:10:21 (none) tcphonehome[122]: Command Output:
    Aug 26 15:10:21 (none) tcphonehome[122]: Command succeeded
    Aug 26 15:10:21 (none) tcphonehome[122]: NOT Using debug ethernet
    Aug 26 15:10:21 (none) tcphonehome[122]: Error statting file /var/log/http: No such file or directory (errno=2)
    Aug 26 15:10:21 (none) tcphonehome[122]: Error statting file /var/log/Ohttp: No such file or directory (errno=2)
    Aug 26 15:10:21 (none) tcphonehome[122]: Timesync is within the past 5 days... all is well
    Aug 26 15:10:21 (none) tcphonehome[122]: ReschedCall: reason = 7, secSinceLast = 0, numFails = 0
    Aug 26 15:10:21 (none) tcphonehome[122]: Schedule call after failure
    Aug 26 15:10:21 (none) tcphonehome[122]: setting next attempt at 1125071181 (Fri Aug 26 15:46:21 2005 )
    Aug 26 15:10:21 (none) tcphonehome[122]: ReschedCall(7, 0) in 36 min
    Aug 26 15:10:21 (none) PhoneAction[122]: PhoneAction 2 register complete timeout 2160
    Aug 26 15:10:21 (none) PhoneAction[122]: Register Complete: Next call should happen at Fri Aug 26 15:46:21 2005
    Aug 26 15:10:21 (none) tcphonehome[122]: called getTZ
    Aug 26 15:10:21 (none) WatchdogAction[122]: WatchdogAction register complete
    Aug 26 15:11:29 (none) tcphonehome[122]: Setting MCP PhoneHome action: RUNNING
    Aug 26 15:11:29 (none) tcphonehome[122]: pCommMempool empty
    Aug 26 15:11:29 (none) tcphonehome[122]: useBackupTollFree is 1
    Aug 26 15:11:29 (none) tcphonehome[122]: phonehome: received message. type = 30 subtype = 2
    Aug 26 15:11:29 (none) tcphonehome[122]: creating CommGlobals
    Aug 26 15:11:37 (none) tcphonehome[122]: created CommGlobals
    Aug 26 15:11:37 (none) tcphonehome[122]: PerformCall, subtype=2 forceTollFree=1 automated=0
    Aug 26 15:11:37 (none) tcphonehome[122]: setCallStatus called with: In Progress state 1
    Aug 26 15:11:37 (none) tcphonehome[122]: LastCallAttempt at 1125069089
    Aug 26 15:11:37 (none) tcphonehome[122]: setting call status to: In Progress
    Aug 26 15:11:37 (none) tcphonehome[122]: setting call in progress to 1 (second successCount)
    Aug 26 15:11:37 (none) tcphonehome[122]: Setting callActive to 1
    Aug 26 15:11:37 (none) tcphonehome[122]: setting call attempt
    Aug 26 15:11:37 (none) tcphonehome[122]: Error statting file /var/log/http: No such file or directory (errno=2)
    Aug 26 15:11:37 (none) tcphonehome[122]: Error statting file /var/log/Ohttp: No such file or directory (errno=2)
    Aug 26 15:11:37 (none) tcphonehome[122]: Calling TClient
    Aug 26 15:11:37 (none) comm[122]: CallStatusReporter: Phase: Select_Phone, Status In Progress
    Aug 26 15:11:37 (none) comm[122]: CallStatusReporter: sending message "EX|29"
    Aug 26 15:11:37 (none) comm[122]: CallService: preprocessing call.
    Aug 26 15:11:37 (none) comm[122]: CallStatusReporter: Phase: Prepare_Call, Status In Progress
    Aug 26 15:11:37 (none) comm[122]: CallStatusReporter: sending message "EX|29"
    Aug 26 15:11:45 (none) comm[122]: LogMgr: start writing to GzPacker(/var/tmp/syslog.gz)
    Aug 26 15:11:45 (none) comm[122]: skipping filter line itself!
    Aug 26 15:11:58 (none) last message repeated 8490 times
    Aug 26 15:11:58 (none) comm[122]: LogMgr: end writing to GzPacker(/var/tmp/syslog.gz)
    Aug 26 15:11:58 (none) comm[122]: Starting Private Logs processing; send event to MW
    Aug 26 15:11:58 (none) comm[122]: waiting for logs to divert...
    Aug 26 15:11:58 (none) comm[121]: Received the LOGMGR WAIT event
    Aug 26 15:11:58 (none) comm[122]: logs diverted.
    Aug 26 15:11:58 (none) comm[122]: Do actual private logs processing
    Aug 26 15:11:59 (none) comm[122]: Error getting demographic info: No Tuner Count
    Aug 26 15:11:59 (none) comm[122]: CmdProc: wrote /var/persist/thumbslog.log.gz
    Aug 26 15:11:59 (none) comm[122]: encryptFile: infile = /var/persist/thumbslog.log.gz outfile = /var/persist/thumbslog.log.gz.bfg keyname = BACKHAUL_THUMB
    Aug 26 15:11:59 (none) comm[122]: About to execute: /tvbin/genkey 128 1 2>&1
    Aug 26 15:12:00 (none) comm[122]: Command succeeded
    Aug 26 15:12:00 (none) comm[122]: EncryptLog: key was empty for BACKHAUL_THUMB
    Aug 26 15:12:04 (none) comm[122]: CmdProc: wrote /var/log/tivoLog.prv.gz
    Aug 26 15:12:04 (none) comm[122]: encryptFile: infile = /var/log/tivoLog.prv.gz outfile = /var/log/tivoLog.prv.gz.bfg keyname = BACKHAUL_PRIVATE
    Aug 26 15:12:04 (none) comm[122]: About to execute: /tvbin/genkey 128 1 2>&1
    Aug 26 15:12:04 (none) comm[122]: Command succeeded
    Aug 26 15:12:04 (none) comm[122]: EncryptLog: key was empty for BACKHAUL_PRIVATE
    Aug 26 15:12:04 (none) comm[122]: Done with actual private logs processing
    Aug 26 15:12:04 (none) comm[122]: About to execute: /tvbin/crypto -gsn 2>&1
    Aug 26 15:12:05 (none) comm[122]: Command succeeded
    Aug 26 15:12:05 (none) comm[122]: About to execute: /tvbin/crypto -gsv 2>&1
    Aug 26 15:12:06 (none) comm[122]: Command succeeded
    Aug 26 15:12:07 (none) comm[122]: About to execute: /tvbin/crypto -x -gek 2>&1
    Aug 26 15:12:13 (none) comm[122]: Command succeeded
    Aug 26 15:12:13 (none) comm[122]: SvcLogRqst: open(/var/log/svclog.tmp)ed (tmpfd = 19)
    Aug 26 15:12:13 (none) comm[122]: SvcLogRqst: open(/var/log/svclog.upload)ed (uploadfd = 20)
    Aug 26 15:12:13 (none) comm[122]: SvcLogRqst: final (351 bytes)::read() (status = 0)
    Aug 26 15:12:13 (none) comm[122]: SvcLogRqst: unlink(/var/log/svclog.tmp)ed (status = 0)
    Aug 26 15:12:13 (none) comm[122]: SvcLogRqst: rename failed (/var/log/commlog probably doesn't exist) skipping
    Aug 26 15:12:13 (none) comm[122]: Start TCD411 Request ==================
    Aug 26 15:12:13 (none) comm[122]: areaCode: 002
    Aug 26 15:12:13 (none) comm[122]: prefix: %2C%23401
    Aug 26 15:12:13 (none) comm[122]: dialInAreaCode:
    Aug 26 15:12:13 (none) comm[122]: curPhNum:
    Aug 26 15:12:13 (none) comm[122]: objVer:
    Aug 26 15:12:13 (none) comm[122]: tcdId: 0020000202190EF
    Aug 26 15:12:13 (none) comm[122]: callId: 1125069097
    Aug 26 15:12:13 (none) comm[122]: dialPrefix: %2C%23401
    Aug 26 15:12:13 (none) comm[122]: dialToneCheck: 0
    Aug 26 15:12:13 (none) comm[122]: offHookDetect: 0
    Aug 26 15:12:13 (none) comm[122]: tonePulseDial: T
    Aug 26 15:12:13 (none) comm[122]: callWaitPrefix:
    Aug 26 15:12:13 (none) comm[122]: tollFreeAuth: 1
    Aug 26 15:12:13 (none) comm[122]: callType: TS_SR_ACCEPTED
    Aug 26 15:12:13 (none) comm[122]: swVerName: 3.0-01-1-000
    Aug 26 15:12:13 (none) comm[122]: End TCD411 Request ==================
    Aug 26 15:12:13 (none) comm[122]: sigType=st=2 connector=con=1...
    Aug 26 15:12:13 (none) comm[122]: Error getting the Avalanche Disk Directories: errNmNameNotFound
    Aug 26 15:12:13 (none) comm[122]: Start Ident ==================
    Aug 26 15:12:13 (none) comm[122]: version: 3
    Aug 26 15:12:13 (none) comm[122]: centerID: 0020000202190EF
    Aug 26 15:12:13 (none) comm[122]: reasonCode: 6
    Aug 26 15:12:13 (none) comm[122]: softwareDesc: 6406306-51|6406288-1|6406290-1|6406292-1|6406294-1|6406296-1|6406298-1|6406300-1|6406302-1|6406304-1|6406307-1|6406308-1|6406309-1|6406310-1|6406311-1|6406312-1|6406313-1|6406314-1|6406315-1|6406316-1|6406317-1|6406318-1|6406319-1|6406
    Aug 26 15:12:13 (none) comm[122]: 320-1|6406321-1|6406322-1|6406323-1|6406324-1|6406325-1|6406326-1|6406327-1|6406328-1|6406329-1|6406330-1|6406331-1|6406332-1|6406333-1|6406334-1|6406335-1|6406336-1|6406337-1|6406338-1|6406339-1|6406340-1|6406341-1|6406342-1|6406343-1|6406344-1|6406345-1|
    Aug 26 15:12:13 (none) comm[122]: 6406346-1|6406347-1|6406348-1|6406349-1|6406350-1|6406351-1|6406352-1|6406353-1|6406354-1|6406355-1|411986-104|412025-19|412046-11|412086-19|412107-19|412149-71|412202-19|412214-6|

  3. #63
    tclient log - part 2 - and segment from tclient as attachment

    Aug 26 15:12:13 (none) comm[122]: locationID: 02113-27
    Aug 26 15:12:13 (none) comm[122]: sequenceCookie: 12345678
    Aug 26 15:12:13 (none) comm[122]: headendID:
    Aug 26 15:12:13 (none) comm[122]: headendHisto:
    Aug 26 15:12:13 (none) comm[122]: headendWorst:
    Aug 26 15:12:13 (none) comm[122]: showcaseDesc: showcase0-0
    Aug 26 15:12:13 (none) comm[122]: inventoryFile:
    Aug 26 15:12:13 (none) comm[122]: waitingCount: 0
    Aug 26 15:12:13 (none) comm[122]: confInfo: :202.36.218.218:8888::::
    Aug 26 15:12:13 (none) comm[122]: dialConfig: 127
    Aug 26 15:12:13 (none) comm[122]: messageDesc:
    Aug 26 15:12:13 (none) comm[122]: irdbVersion:
    Aug 26 15:12:13 (none) comm[122]: genreVersion:
    Aug 26 15:12:13 (none) comm[122]: logoVersion:
    Aug 26 15:12:13 (none) comm[122]: affiliationVersion:
    Aug 26 15:12:13 (none) comm[122]: showcaseVersion:
    Aug 26 15:12:13 (none) comm[122]: demoMode:
    Aug 26 15:12:13 (none) comm[122]: swVerName: 3.0-01-1-000
    Aug 26 15:12:13 (none) comm[122]: apgOnly:
    Aug 26 15:12:13 (none) comm[122]: useChksums: TRUE
    Aug 26 15:12:13 (none) comm[122]: premiumShowcases:
    Aug 26 15:12:13 (none) comm[122]: captureRequests:
    Aug 26 15:12:13 (none) comm[122]: menuItems:
    Aug 26 15:12:13 (none) comm[122]: collabData:
    Aug 26 15:12:13 (none) comm[122]: signedFiles:
    Aug 26 15:12:13 (none) comm[122]: otherDatasets:
    Aug 26 15:12:13 (none) comm[122]: rbBackgrounds:
    Aug 26 15:12:13 (none) comm[122]: dataGroupList:
    Aug 26 15:12:13 (none) comm[122]: lastAvalDownload: 0,0 0,0
    Aug 26 15:12:13 (none) comm[122]: userInitiated: 1
    Aug 26 15:12:13 (none) comm[122]: mfsTotalApp: 785168
    Aug 26 15:12:13 (none) comm[122]: mfsAvailApp: 763888
    Aug 26 15:12:13 (none) comm[122]: mfsTotalMedia: 388595712
    Aug 26 15:12:13 (none) comm[122]: mfsAvailMedia: 66271232
    Aug 26 15:12:13 (none) comm[122]: clipsTotalSize: 10000000
    Aug 26 15:12:13 (none) comm[122]: clipsAvailSize: 9948800
    Aug 26 15:12:13 (none) comm[122]: rbTotalSize: 0
    Aug 26 15:12:13 (none) comm[122]: rbAvailSize: 0
    Aug 26 15:12:13 (none) comm[122]: tcdId: 0020000202190EF
    Aug 26 15:12:13 (none) comm[122]: callId: 1125069097
    Aug 26 15:12:13 (none) comm[122]: sourceParameterList: st=2,con=1,drm=,ekr=1,ccn=,brn=,lin=
    Aug 26 15:12:13 (none) comm[122]: configParameterList: zip=02113,dar=0,rcq=40,tz=1,as=1,tun=,suc=0,sta=3, exp=0
    Aug 26 15:12:13 (none) comm[122]: iceboxinfo:
    Aug 26 15:12:13 (none) comm[122]: timeStamp: ...
    Aug 26 15:12:13 (none) comm[122]: End Ident ==================
    Aug 26 15:12:13 (none) comm[122]: CallService: Start err 0
    Aug 26 15:12:13 (none) comm[122]: CAM_ID not found.
    Aug 26 15:12:14 (none) comm[122]: CallStatusReporter: Phase: Dial, Status In Progress
    Aug 26 15:12:14 (none) comm[122]: CallStatusReporter: sending message "CL|30"
    Aug 26 15:12:14 (none) comm[122]: Backdoor code 4, enable calls via broadband
    Aug 26 15:12:14 (none) comm[122]: Using Ethernet. Not starting modem/pppd.
    Aug 26 15:12:14 (none) comm[122]: CallStatusReporter: Phase: Start_Auth, Status In Progress
    Aug 26 15:12:20 (none) comm[122]: CallStatusReporter: sending message "ST|33"
    Aug 26 15:12:41 (none) comm[122]: CommUtil: connection to host 202.36.218.218, port 8888, err 0x50005
    Aug 26 15:12:41 (none) comm[122]: tmk tcp connect failed, reason = Operation now in progress
    Aug 26 15:12:41 (none) comm[122]: drainGetPostQ: doXfer failed err=327685 (0x50005)
    Aug 26 15:12:41 (none) comm[122]: NetAgent: drainPostQ failed, err = 0x50005
    Aug 26 15:12:41 (none) comm[122]: CallService: NetAgent Process err 327685
    Aug 26 15:12:41 (none) comm[122]: CallService: NetAgent failed, status 0x50005
    Aug 26 15:12:41 (none) comm[122]: CallService: EndCall start
    Aug 26 15:12:43 (none) comm[122]: CallStatusReporter: Turning off-hook LED off
    Aug 26 15:12:43 (none) comm[122]: Recover private logs
    Aug 26 15:12:43 (none) comm[122]: Opening old private log files
    Aug 26 15:12:43 (none) comm[122]: Reverting private logs
    Aug 26 15:12:43 (none) tcphonehome[122]: CallService return status 0x50005
    Aug 26 15:12:49 (none) comm[122]: CallStatusReporter: Phase: Start_Auth, Status Failed
    Aug 26 15:12:49 (none) comm[122]: CallStatusReporter: sending message "EX|14"
    Aug 26 15:12:49 (none) tcphonehome[122]: TClient failed: EX|14
    Aug 26 15:12:49 (none) tcphonehome[122]: Sending dialup event, subtype 8, msg EX|14
    Aug 26 15:12:49 (none) tcphonehome[122]: setCallStatus called with: Failed state 0
    Aug 26 15:12:59 (none) tcphonehome[122]: LastCallAttempt at 1125069097
    Aug 26 15:12:59 (none) tcphonehome[122]: setting call status to: Failed
    Aug 26 15:12:59 (none) tcphonehome[122]: setting call in progress to 0 (second successCount)
    Aug 26 15:12:59 (none) tcphonehome[122]: Setting callActive to 0
    Aug 26 15:12:59 (none) comm[122]: CallStatusReporter: sending data changed event 20
    Aug 26 15:12:59 (none) tcphonehome[122]: destroying CommGlobals!
    Aug 26 15:12:59 (none) tcphonehome[122]: pCommMempool empty
    Aug 26 15:12:59 (none) tcphonehome[122]: Setting MCP PhoneHome action: ENABLED
    Attached Images Attached Images

  4. #64
    Join Date
    Apr 2004
    Location
    Auckland
    Posts
    32

    Tried port 8888

    Quote Originally Posted by DJC
    Excellent, I'm keen to see the result of this.
    Tried it, and sorry, it still says "Failed. Service unavailable."

    It does spend a long time with the "Connection ..." message (this is in tivoweb, obviously).

    I updated tclient.conf; it's not using emuProxy.


    Code:
    [TiVo [p0] ~]# tail -n 15 /etc/tclient.conf
    #
    000:
    # Dennis' Emulator
    126::66.23.218.193:80:::
    # This is for the server emulator on minnie. Trouble if your ISP blocks HTTP .9
    #127::131.244.9.101:80:::
    
    # This uses emuProxy2 to avoid problems with transparent proxy. Thanks Tim!
    #127::127.0.0.1:8000:::
    
    # Matt for NZ
    #127::64.151.65.200:80:::
    #127::210.48.107.133:8000:::
    127::202.36.218.218:8888:::
    Would any logfiles be helpful? Or is there a glaring error in my config above? ;-)

    Cheers
    Matt

  5. #65
    Join Date
    Apr 2004
    Location
    Wellington
    Posts
    224

  6. #66
    Thanks, that sorted my problem

  7. #67
    Join Date
    Aug 2004
    Location
    The Mainland
    Posts
    542
    Quote Originally Posted by wbeasley
    Thanks, that sorted my problem
    .. huh? so after all that you never managed to move off the original emulator?
    1 x Philips TiVo Series 1, Cachecard, 1 x 1TB SATA (with recent TradeMe sourced adaptor), Mk II Pal Tuner Mod, NZ Emulator, Previously Dual A/V Source, Now Pay Satellite
    2 x TiVo HD, Freeview, HNP, 2TB (WD-AV) jmfs upgraded
    1 x Thomson UK TiVo, Cachecard, 200GB, Testing Work

  8. #68
    I tried the test one you set up first
    127::202.36.218.218:8888:::

    then the dev emulator 127::210.48.107.133:8000:::
    (i don't have logos installed)

    then 127::64.151.65.200:80::: and no problems.
    (all these with guided setup)

    My image is 3.0 version 1

    Thanks for your time trying to resolve the issue it was really appreciated.
    I will switch to 127::210.48.107.133:8000::: on sunday and see if i can upload data now that guided setup has completed.

  9. #69
    Join Date
    Aug 2004
    Location
    The Mainland
    Posts
    542
    Peter: is there a hack that needs to be applied to the emulator for this to work.... or are you talking about the code of emuProxy2 ? cheers/DJC

    Quote Originally Posted by petestrash
    If the emuproxy2 was working properly the 2nd 'HTTP Header' line should be 1.1 and not 1.0 still. It's ok for the 'Uploading Header' line to show 1.0.

    Perhaps the hack has not been implemented on the NZ server.

    Peter.
    1 x Philips TiVo Series 1, Cachecard, 1 x 1TB SATA (with recent TradeMe sourced adaptor), Mk II Pal Tuner Mod, NZ Emulator, Previously Dual A/V Source, Now Pay Satellite
    2 x TiVo HD, Freeview, HNP, 2TB (WD-AV) jmfs upgraded
    1 x Thomson UK TiVo, Cachecard, 200GB, Testing Work

  10. #70
    Join Date
    Apr 2004
    Location
    Perth, Western Australia
    Posts
    3,037
    Quote Originally Posted by DJC
    Peter: is there a hack that needs to be applied to the emulator for this to work.... or are you talking about the code of emuProxy2 ? cheers/DJC
    I have not played with emulators since emuProxy2 has been used.

    But from my understanding and the comments associated with its use EmuProxy2 works with a hack in the emulator to accept the header "TivoURLBase" which is the base url to give back to the Tivo when specifying data paths.

    For the specific changes to the emulator you would be best asking Warren or Ed.

    Peter.
    Please search this forum and our Website for your TiVo questions before starting a new thread. Thanks!

Similar Threads

  1. Failed. Service unavailable
    By MelissaH in forum TV Guide Issues
    Replies: 51
    Last Post: 10-06-2009, 06:20 PM
  2. Failed: Service unavailable
    By SteveP in forum TV Guide Issues
    Replies: 7
    Last Post: 15-04-2009, 01:00 AM
  3. Failed. Service unavailable
    By kiltannen in forum New Zealand TV Guide Issues
    Replies: 1
    Last Post: 17-12-2008, 09:01 PM
  4. Failed. Service unavailable
    By vex in forum TV Guide Issues
    Replies: 42
    Last Post: 14-10-2008, 11:42 PM
  5. Failed. Service unavailable
    By RalphMesiti in forum Question and Answer Forum
    Replies: 20
    Last Post: 24-05-2006, 03:26 PM

Bookmarks

Posting Permissions

  • You may not post new threads
  • You may not post replies
  • You may not post attachments
  • You may not edit your posts
  •