Page 1 of 2 12 LastLast
Results 1 to 10 of 14

Thread: Failed. Service unavailable

  1. #1
    Join Date
    Jun 2005
    Location
    Auckland
    Posts
    43

    Failed. Service unavailable

    Friday the 15th was the last time my Tivo was able to get guide data from the emulator.

    I have forced the call with "forcedailycall.tcl" but it fails with

    Failed. Service unavailable

    Aug 15 18:54:13 (none) comm[162]: CallService: Start err 0
    Aug 15 18:54:13 (none) comm[162]: CAM_ID not found.
    Aug 15 18:54:13 (none) comm[162]: CallStatusReporter: Phase: Dial, Status In Progress
    Aug 15 18:54:13 (none) comm[162]: CallStatusReporter: sending message "CL|30"
    Aug 15 18:54:13 (none) comm[162]: Backdoor code 4, enable calls via broadband
    Aug 15 18:54:13 (none) comm[162]: Using Ethernet. Not starting modem/pppd.
    Aug 15 18:54:13 (none) comm[162]: CallStatusReporter: Phase: Start_Auth, Status In Progress
    Aug 15 18:54:13 (none) comm[162]: CallStatusReporter: sending message "ST|33"
    Aug 15 18:54:14 (none) comm[162]: CommUtil: connection to host 64.151.65.200, port 80, err 0x0
    Aug 15 18:54:14 (none) comm[162]: Uploading HTTP Header for modLog of /var/log/svclog: POST /tivo-service/mlog.cgi HTTP/1.0^M Content-Length: 358^M ^M
    Aug 15 18:54:17 (none) comm[162]: read HTTP Header: HTTP/1.0 200 OK^M Date: Mon, 15 Aug 2005 06:54:15 GMT^M Server: Apache/1.3.33 (Unix) (Gentoo/Linux) PHP/4.3.11 mod_gzip/1.3.26.1a^M Content-Type: text/plain; ch****t=ISO-8859-1^M X-Cache: MISS from cache1.qsi.net.nz^M Connection: close
    Aug 15 18:54:17 (none) comm[162]: SvcLogRqst::verify: enter
    Aug 15 18:54:17 (none) comm[162]: SvcLogRqst::verify: unlink(/var/log/svclog.upload)ed (status = 0)
    Aug 15 18:54:17 (none) comm[162]: couldn't stat input file, reason = No such file or directory
    Aug 15 18:54:17 (none) comm[162]: NetAgent::doXfer: open failed on Rqst : No such file or directory
    Aug 15 18:54:17 (none) comm[162]: drainGetPostQ: doXfer failed err=65535 (0xffff)
    Aug 15 18:54:17 (none) comm[162]: Xfer Performance Log says errors are Ok!
    Aug 15 18:54:17 (none) comm[162]: CommUtil: connection to host 64.151.65.200, port 80, err 0x0
    Aug 15 18:54:17 (none) comm[162]: read 384 bytes of upload data for FourOneOneRqst
    Aug 15 18:54:18 (none) comm[162]: CommUtil: connection to host 64.151.65.200, port 80, err 0x0
    Aug 15 18:54:18 (none) comm[162]: read 2002 bytes of upload data for HServerRqst
    Aug 15 18:54:18 (none) comm[162]: HTTP header: HTTP/1.0 200 OK^M
    Aug 15 18:54:18 (none) comm[162]: HTTP header: Date: Mon, 15 Aug 2005 06:54:15 GMT^M
    Aug 15 18:54:18 (none) comm[162]: HTTP header: Server: Apache/1.3.33 (Unix) (Gentoo/Linux) PHP/4.3.11 mod_gzip/1.3.26.1a^M
    Aug 15 18:54:18 (none) comm[162]: HTTP header: Content-Type: text/plain; ch****t=ISO-8859-1^M
    Aug 15 18:54:18 (none) comm[162]: HTTP header: X-Cache: MISS from cache1.qsi.net.nz^M
    Aug 15 18:54:18 (none) comm[162]: HTTP header: Connection: close^M
    Aug 15 18:54:18 (none) comm[162]: HTTP header: ^M
    Aug 15 18:54:18 (none) comm[162]: Start TCD411Resp =====================
    Aug 15 18:54:18 (none) comm[162]: errMsg:
    Aug 15 18:54:18 (none) comm[162]: areaCodeObj: OK
    Aug 15 18:54:18 (none) comm[162]: tollFreeAuth: 0
    Aug 15 18:54:18 (none) comm[162]: tollFreeNum:
    Aug 15 18:54:18 (none) comm[162]: End TCD411Resp =====================
    Aug 15 18:54:18 (none) comm[162]: current AreaCode object is OK
    Aug 15 18:54:18 (none) comm[162]: HServerRqst::evaluate starting
    Aug 15 18:54:18 (none) comm[162]: HTTP header: HTTP/1.0 411 Length Required^M
    Aug 15 18:54:18 (none) comm[162]: HTTP header: Server: squid/2.5.STABLE3^M
    Aug 15 18:54:18 (none) comm[162]: HTTP header: Mime-Version: 1.0^M
    Aug 15 18:54:18 (none) comm[162]: HTTP header: Date: Mon, 15 Aug 2005 06:54:16 GMT^M
    Aug 15 18:54:18 (none) comm[162]: HTTP header: Content-Type: text/html^M
    Aug 15 18:54:18 (none) comm[162]: HTTP header: Content-Length: 3263^M
    Aug 15 18:54:18 (none) comm[162]: HTTP header: Expires: Mon, 15 Aug 2005 06:54:16 GMT^M
    Aug 15 18:54:18 (none) comm[162]: HTTP header: X-Squid-Error: ERR_INVALID_REQ 0^M
    Aug 15 18:54:18 (none) comm[162]: HTTP header: X-Cache: MISS from cache1.qsi.net.nz^M
    Aug 15 18:54:18 (none) comm[162]: HTTP header: Connection: close^M
    Aug 15 18:54:18 (none) comm[162]: HTTP header: ^M
    Aug 15 18:54:18 (none) comm[162]: Required Parameter ERR_MSG not present
    Aug 15 18:54:18 (none) comm[162]: Required Parameter VERSION not present
    Aug 15 18:54:18 (none) comm[162]: Required Parameter CODE not present
    Aug 15 18:54:18 (none) comm[162]: Required Parameter SW_LIST not present
    Aug 15 18:54:18 (none) comm[162]: Required Parameter BACK_CH_PRV not present
    Aug 15 18:54:18 (none) comm[162]: Required Parameter BACK_CH_PUB not present
    Aug 15 18:54:18 (none) comm[162]: Required Parameter BACK_CH_LOG not present
    Aug 15 18:54:18 (none) comm[162]: Required Parameter TIME_SVC not present
    Aug 15 18:54:18 (none) comm[162]: Required Parameter SEQ_COOKIE not present
    Aug 15 18:54:18 (none) comm[162]: Required Parameter INV_FILE not present
    Aug 15 18:54:18 (none) comm[162]: Required Parameter NO_PRV_BACKHAUL not present
    Aug 15 18:54:18 (none) comm[162]: Required Parameter SERVICE_STATE not present
    Aug 15 18:54:18 (none) comm[162]: Required Parameter STATE_EXPIRE not present
    Aug 15 18:54:18 (none) comm[162]: Required Parameter SW_SYSTEM_NAME not present
    Aug 15 18:54:18 (none) comm[162]: HServerRqst: readBlock failed, err = 0xffff
    Aug 15 18:54:18 (none) comm[162]: NetAgent: drainEvalQ failed, err = 0xffff
    Aug 15 18:54:18 (none) comm[162]: CallService: NetAgent Process err 65535
    Aug 15 18:54:18 (none) comm[162]: CallService: NetAgent failed, status 0xffff
    Aug 15 18:54:18 (none) comm[162]: CallService: EndCall start
    Aug 15 18:54:20 (none) comm[162]: CallStatusReporter: Turning off-hook LED off
    Aug 15 18:54:21 (none) comm[162]: Recover private logs
    Aug 15 18:54:21 (none) comm[162]: Opening old private log files
    Aug 15 18:54:21 (none) comm[162]: Reverting private logs
    Aug 15 18:54:21 (none) comm[162]: Cleanup: GetAddDiskBasedDirectories returned <70001> "0x70001"...skipping cleanup
    Aug 15 18:54:21 (none) tcphonehome[162]: CallService return status 0xffff
    Aug 15 18:54:21 (none) tcphonehome[162]: GetPostalCodeVersion - /PostalCode/02113 ServerVersion=27
    Aug 15 18:54:21 (none) tcphonehome[162]: debug: sumServerVersion=27
    Aug 15 18:54:21 (none) comm[162]: CallStatusReporter: Phase: Start_Auth, Status Failed
    Aug 15 18:54:21 (none) comm[162]: CallStatusReporter: sending message "EX|14"
    Aug 15 18:54:21 (none) tcphonehome[162]: TClient failed: EX|14
    Aug 15 18:54:21 (none) tcphonehome[162]: Sending dialup event, subtype 8, msg EX|14
    Aug 15 18:54:21 (none) tcphonehome[162]: setCallStatus called with: Failed state 0
    Aug 15 18:54:21 (none) tcphonehome[162]: LastCallAttempt at 1124132019
    Aug 15 18:54:21 (none) tcphonehome[162]: setting call status to: Failed
    Aug 15 18:54:25 (none) tcphonehome[162]: setting call in progress to 0 (second successCount)
    Aug 15 18:54:25 (none) tcphonehome[162]: Setting callActive to 0
    Aug 15 18:54:25 (none) comm[162]: CallStatusReporter: sending data changed event 20
    Aug 15 18:54:25 (none) tcphonehome[162]: destroying CommGlobals!
    Aug 15 18:54:25 (none) tcphonehome[162]: pCommMempool empty
    Aug 15 18:54:35 (none) tcphonehome[162]: Setting MCP PhoneHome action: ENABLED

  2. #2
    Join Date
    Aug 2004
    Location
    The Mainland
    Posts
    542
    Has your isp changed their proxy recently?

    Does your oztivo image run emuProxy?
    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

  3. #3
    Join Date
    Jun 2005
    Location
    Auckland
    Posts
    43
    On Friday I changed from xtra to Quicksilver as my broadband provider

    http://forums.oztivo.net/showthread....ighlight=proxy

    Peterd - solved this issue by turning off his proxy.

    I don't run a proxy or does he mean turn off proxy on the Tivo??
    Last edited by sadrake; 16-08-2005 at 06:33 AM. Reason: More info found

  4. #4
    Join Date
    Jun 2005
    Location
    Auckland
    Posts
    43
    Quote Originally Posted by DJC
    Has your isp changed their proxy recently?

    Does your oztivo image run emuProxy?
    Im using the 1.4 image, is the emuProxy setting in tclient.conf?

    I havent changed the emuProxy setting from what came with the image if that helps - should i turn it off?

    edit- just found

    http://minnie.tuhs.org/twiki/bin/vie...entProxyServer

    Should I setup the emuProxy to solve my problem?
    Last edited by sadrake; 16-08-2005 at 07:36 AM.

  5. #5
    Join Date
    Aug 2004
    Location
    The Mainland
    Posts
    542
    Ok, so the problem obviously coincides with the change of ISP.

    Looks to me like squid (proxy) does not like the tivo request.

    Check your tclient file, if you are NOT using emuProxy it will have the emulator ip for 127.

    If you are using emuProxy, it will look like this 127::127.0.0.1:8000:::

    if you are not using it, I suggest installing/trying it, apparently it is designed to 'linearise' the http request stream to be more compatible...

    A suggestion at least
    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

  6. #6
    Join Date
    Jun 2005
    Location
    Auckland
    Posts
    43
    Thanks DJC

    I'll give the emuproxy a go tonight, sounds like it may solve my issue, I have asked if Quicksilver can exclude 64.151.65.200 from caching on the proxy also but wont hold my breath.

  7. #7
    Join Date
    Jun 2005
    Location
    Auckland
    Posts
    43

    emuProxy IP address question.

    Question To get this to work for NZ in the instructions for editing rc.sysinit I would have to add the IP address for the New Zealand emulator.


    Edit /etc/rc.d/rc.sysinit.author, Append the line:
    /hack/bin/emuProxy2 &

    Change to:
    /hack/bin/emuProxy2 -s 64.151.65.200 &

    This is so it would point to the New Zealand emulator and not the hardcoded Aussie one.

    The reason I ask as I looked in emuProxy2.c it has the server IP hardcoded as 131.244.9.101 and in New Zealand we are using 64.151.65.200.
    Last edited by sadrake; 16-08-2005 at 08:27 AM.

  8. #8
    Join Date
    Apr 2004
    Location
    Perth, Western Australia
    Posts
    3,037
    Just thought I'd drop a note in here for people searching the threads.

    Whenever you see 'HTTP header: HTTP/1.0' in tclient that usually means the ISP's transparent proxy is not handling the tivo correctly.

    A successful tclient will list 'HTTP Header: HTTP/1.1'.

    As sadrake has done, the best solution is to ask your ISP to exclude the emulator IP from the transparent proxy service (or fix the proxy). New Zealand IP 64.151.65.200 or Australia IP 131.244.9.101

    If you are using OzTiVo image r1.4 you 'should' be able to use emuproxy2 for the NZ emulator if it is setup to use it, just by changing the IP in /etc/rc.d/rc.sysinit.author

    Code:
    Emu Proxy
    # A tool for cleaning up the HTTP output by the Tivo in order to pass through
    # transparent proxies, etc.
    # Works in conjunction with a small hack to the emulator to accept the header
    # "TivoURLBase" which is the base url to give back to the Tivo when specifying
    # data paths.
    # Runs by default and is dependent on the
    # 127::127.0.0.1:8000:::
    # entry in tclient.conf
    # IF YOU COMMENT THIS OUT SO IT DOESN'T RUN, YOU MUST EDIT THE "127" entry
    # in /etc/tclient.conf to reflect the IP and port of the emulator you are using
    # There is a backup of the original here: /etc/tclient.conf-oztivo
    # Usage: %s [-d] [-h] [-l localport] [-L listenAddr] [-s serverip]
    #   [-p serverport]
    emuProxy2 -s 64.151.65.200 &
    Haven't tried it myself though, since I'm in Australia.

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

  9. #9
    Join Date
    Jun 2005
    Location
    Auckland
    Posts
    43
    As I expected the ISP wont exclude the IP from the proxy's cache.

    Will let you know how using the emuproxy goes tonight - fingers crossed.

  10. #10
    Join Date
    Jun 2005
    Location
    Auckland
    Posts
    43


    The ISP's proxy still does not like it. as long as everything is configured correctly to use it...

    rc.d.author
    # Usage: %s [-d] [-h] [-l localport] [-L listenAddr] [-s serverip]
    # [-p serverport]
    emuProxy2 -s 64.151.65.200 &


    tclient.conf
    #
    # This is the default port, it's values come from Addr.itcl not here
    #
    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::64.151.65.200:80:::

    # This uses emuProxy2 to avoid problems with transparent proxy. Thanks Tim!
    127::127.0.0.1:8000:::

    tclient log file....

    Aug 16 17:54:15 (none) comm[157]: CallService: Start err 0
    Aug 16 17:54:15 (none) comm[157]: CAM_ID not found.
    Aug 16 17:54:15 (none) comm[157]: CallStatusReporter: Phase: Dial, Status In Progress
    Aug 16 17:54:15 (none) comm[157]: CallStatusReporter: sending message "CL|30"
    Aug 16 17:54:16 (none) comm[157]: Backdoor code 4, enable calls via broadband
    Aug 16 17:54:16 (none) comm[157]: Using Ethernet. Not starting modem/pppd.
    Aug 16 17:54:16 (none) comm[157]: CallStatusReporter: Phase: Start_Auth, Status In Progress
    Aug 16 17:54:16 (none) comm[157]: CallStatusReporter: sending message "ST|33"
    Aug 16 17:54:16 (none) comm[157]: CommUtil: connection to host 127.0.0.1, port 8000, err 0x0
    Aug 16 17:54:16 (none) comm[157]: Uploading HTTP Header for modLog of /var/log/svclog: POST /tivo-service/mlog.cgi HTTP/1.0^M Content-Length: 358^M ^M
    Aug 16 17:54:16 (none) comm[157]: read HTTP Header: HTTP/1.0 200 OK^M Date: Tue, 16 Aug 2005 05:54:07 GMT^M Server: Apache/2.0.53^M Content-Type: text/plain; ch****t=ISO-8859-1^M X-Cache: MISS from cache1.qsi.net.nz^M Connection: close
    Aug 16 17:54:16 (none) comm[157]: SvcLogRqst::verify: enter
    Aug 16 17:54:16 (none) comm[157]: SvcLogRqst::verify: unlink(/var/log/svclog.upload)ed (status = 0)
    Aug 16 17:54:17 (none) comm[157]: couldn't stat input file, reason = No such file or directory
    Aug 16 17:54:17 (none) comm[157]: NetAgent::doXfer: open failed on Rqst : No such file or directory
    Aug 16 17:54:17 (none) comm[157]: drainGetPostQ: doXfer failed err=65535 (0xffff)
    Aug 16 17:54:17 (none) comm[157]: Xfer Performance Log says errors are Ok!
    Aug 16 17:54:17 (none) comm[157]: CommUtil: connection to host 127.0.0.1, port 8000, err 0x0
    Aug 16 17:54:17 (none) comm[157]: read 384 bytes of upload data for FourOneOneRqst
    Aug 16 17:54:18 (none) comm[157]: CommUtil: connection to host 127.0.0.1, port 8000, err 0x0
    Aug 16 17:54:18 (none) comm[157]: read 2000 bytes of upload data for HServerRqst
    Aug 16 17:54:18 (none) comm[157]: HTTP header: HTTP/1.0 200 OK^M
    Aug 16 17:54:18 (none) comm[157]: HTTP header: Date: Tue, 16 Aug 2005 05:54:08 GMT^M
    Aug 16 17:54:18 (none) comm[157]: HTTP header: Server: Apache/2.0.53^M
    Aug 16 17:54:18 (none) comm[157]: HTTP header: Content-Type: text/plain; ch****t=ISO-8859-1^M
    Aug 16 17:54:18 (none) comm[157]: HTTP header: X-Cache: MISS from cache1.qsi.net.nz^M
    Aug 16 17:54:18 (none) comm[157]: HTTP header: Connection: close^M
    Aug 16 17:54:18 (none) comm[157]: HTTP header: ^M
    Aug 16 17:54:18 (none) comm[157]: Start TCD411Resp =====================
    Aug 16 17:54:18 (none) comm[157]: errMsg:
    Aug 16 17:54:18 (none) comm[157]: areaCodeObj: &http://127.0.0.1:8000/tivo-static/headends/AC-002-v1.slice|
    Aug 16 17:54:18 (none) comm[157]: tollFreeAuth: 0
    Aug 16 17:54:18 (none) comm[157]: tollFreeNum: 0
    Aug 16 17:54:18 (none) comm[157]: End TCD411Resp =====================
    Aug 16 17:54:18 (none) comm[157]: HServerRqst::evaluate starting
    Aug 16 17:54:18 (none) comm[157]: HTTP header: HTTP/1.0 411 Length Required^M
    Aug 16 17:54:18 (none) comm[157]: HTTP header: Server: squid/2.5.STABLE3^M
    Aug 16 17:54:18 (none) comm[157]: HTTP header: Mime-Version: 1.0^M
    Aug 16 17:54:18 (none) comm[157]: HTTP header: Date: Tue, 16 Aug 2005 05:54:15 GMT^M
    Aug 16 17:54:18 (none) comm[157]: HTTP header: Content-Type: text/html^M
    Aug 16 17:54:18 (none) comm[157]: HTTP header: Content-Length: 3319^M
    Aug 16 17:54:18 (none) comm[157]: HTTP header: Expires: Tue, 16 Aug 2005 05:54:15 GMT^M
    Aug 16 17:54:18 (none) comm[157]: HTTP header: X-Squid-Error: ERR_INVALID_REQ 0^M
    Aug 16 17:54:18 (none) comm[157]: HTTP header: X-Cache: MISS from cache1.qsi.net.nz^M
    Aug 16 17:54:18 (none) comm[157]: HTTP header: Connection: close^M
    Aug 16 17:54:18 (none) comm[157]: HTTP header: ^M
    Aug 16 17:54:18 (none) comm[157]: Required Parameter ERR_MSG not present
    Aug 16 17:54:18 (none) comm[157]: Required Parameter VERSION not present
    Aug 16 17:54:18 (none) comm[157]: Required Parameter CODE not present
    Aug 16 17:54:18 (none) comm[157]: Required Parameter SW_LIST not present
    Aug 16 17:54:18 (none) comm[157]: Required Parameter BACK_CH_PRV not present
    Aug 16 17:54:18 (none) comm[157]: Required Parameter BACK_CH_PUB not present
    Aug 16 17:54:18 (none) comm[157]: Required Parameter BACK_CH_LOG not present
    Aug 16 17:54:18 (none) comm[157]: Required Parameter TIME_SVC not present
    Aug 16 17:54:18 (none) comm[157]: Required Parameter SEQ_COOKIE not present
    Aug 16 17:54:18 (none) comm[157]: Required Parameter INV_FILE not present
    Aug 16 17:54:18 (none) comm[157]: Required Parameter NO_PRV_BACKHAUL not present
    Aug 16 17:54:18 (none) comm[157]: Required Parameter SERVICE_STATE not present
    Aug 16 17:54:18 (none) comm[157]: Required Parameter STATE_EXPIRE not present
    Aug 16 17:54:18 (none) comm[157]: Required Parameter SW_SYSTEM_NAME not present
    Aug 16 17:54:18 (none) comm[157]: HServerRqst: readBlock failed, err = 0xffff
    Aug 16 17:54:18 (none) comm[157]: NetAgent: drainEvalQ failed, err = 0xffff
    Aug 16 17:54:18 (none) comm[157]: CallService: NetAgent Process err 65535
    Aug 16 17:54:18 (none) comm[157]: CallService: NetAgent failed, status 0xffff
    Aug 16 17:54:18 (none) comm[157]: CallService: EndCall start

Similar Threads

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