Dialup Reliability Improvement

General Discussion

Dialup Reliability Improvement

Postby millsb » Sat Oct 06, 2012 7:52 pm

Elsewhere on this forum there has been a number of posts recently about problems with the AltEPG dial-up service, and in particular dial-up via the 08450800300 number.

This article provides a bit of background to the problem and describes in detail a way to solve it.

Background
When TiVo makes a dial-up call, it establishes an internet connection over the phone line, and then uses HTTP messages to pass information to the AltEPG server and to retrieve programme data.
Occasionally an HTTP message may be lost before it gets to the server, or the response may be lost. The TiVo software sets a timeout on each message request. The timeout is typically between 3 and 5 minutes. If TiVo doesn't receive a response within in the time limit, it hangs up the phone line and the call is marked as failed. TiVo will then try again a few hours later.

With the 08450800300 number, almost all calls are currently failing due to timeouts. It is not clear what is causing this.

Way Forward
The problem is due in part to the fact that the TiVo software is not designed to retry in the event of a timeout. However experiments show that if the timeout interval is reduced and the software made to retry immediately on time-out, the second attempt usually succeeds. The solution described here is to modify the TiVo software so that it is able to re-try.

The TiVo programs that send and receive HTTP messages are as follows:
  • /tvbin/http_post - sends programme data status messages to the AltEPG server
  • /tvbin/tclient_post - sends TiVo configuration data messages to the AltEPG server
  • /tvbin/http_get - retrieves programme (slice) data from the AltEPG server
Each of these programs will be replaced by new version that implements an improved timeout/retry strategy.

1. /tvbin/http_post
This program uses a fixed 3 minute timeout. However its behaviour is fairly similar to /tvbin/tclient_post, which has a configurable timeout. It will therefore be replaced by a script which calls /tvbin/tclient_post.
We'll call this script /tvbin/http_post.bash. Unfortunately a subtle difference between http_post and tclient_post is that tclient_post expects a response whereas http_post does not. We'll therefore always get a time-out when using tclient_post in this way. We can ignore the timeout but it means we can't tell whether or not tclient_post has succeeded. We'll therefore always run this command twice to be on the safe side.

2. /tvbin/tclient_post
This program uses a timeout that can be set on the command line. With the current TiVo software it's set to 300 seconds. We'll reduce it to 5 seconds but will retry up to 10 times if we get a failure.

3. /tvbin/http_get
This program uses a default timeout of 300 seconds. Its function is similar to the 'wget' program which is provided as part of the AltEPG 1.0d build. wget has an in-built timeout and retry mechanism, so we'll replace http_get with wget. We'll wrap wget in a script (http_get.bash) so that it presents the same interface as http_get.

Testing
A package containing the updates has been prepared, but needs testing. If you are willing to participate in testing this package, please let me know. You'll need a TiVo configured for dialup and with AltEPG 1.0d installed.
millsb
AltEPG Team
AltEPG Team
 
Posts: 974
Joined: Sat Mar 05, 2011 11:16 am

Re: Dialup Reliability Improvement

Postby ByTheCringe » Sun Oct 07, 2012 6:32 am

Does this improvement apply also to the 0161 number? So far, no-one has diagnosed the problem with that number, but if a timeout has benn causing it, presumably this fix would be effective. Whilst nothing like as bad as the recent 0845 problem, the 0161 number problem is bad enough to disallow daily unattended downloads, because when it hangs, the phone line is still occupied. So only one or two downloads per week can be allowed. It would certainly be nice to be able to leave the phone line attached and get daily downloads.
ByTheCringe
TiVo lover
TiVo lover
 
Posts: 165
Joined: Fri May 06, 2011 1:52 pm

Re: Dialup Reliability Improvement

Postby millsb » Sun Oct 07, 2012 9:09 am

Yes, the improvement applies whatever route your TiVo uses for connecting to the server. I can't say whether it will fix the problem you're describing on the 0161 number, but it's certainly a scenario worth testing.
millsb
AltEPG Team
AltEPG Team
 
Posts: 974
Joined: Sat Mar 05, 2011 11:16 am

Re: Dialup Reliability Improvement

Postby ByTheCringe » Mon Oct 08, 2012 8:15 am

Thank'ee kindly, sir, that sounds promising.
ByTheCringe
TiVo lover
TiVo lover
 
Posts: 165
Joined: Fri May 06, 2011 1:52 pm

Re: Dialup Reliability Improvement

Postby The Larch » Tue Oct 09, 2012 10:26 pm

This sounds like a worthwhile improvement to make.

One thought - is there any reason why wget can't be used (with --post-data or --post-file) to replace http_post as well?

The only problem I see is that this won't help those (like my parents) with unmodified tivos. I suspect that covers quite a few of those still using dial-up. So here's hoping the source of the timeouts is found and fixed as well!

It's odd though, TCP ought to recover from lost packets. Is the problem that the dial-up connection suddenly stops routing altogether? I've had that problem with dial-up in the past, on Demon Internet. And as far as I know they never properly got to the bottom of it. :(
The Larch
Powering up...
Powering up...
 
Posts: 14
Joined: Tue Oct 09, 2012 10:05 pm

Re: Dialup Reliability Improvement

Postby millsb » Tue Oct 09, 2012 11:53 pm

The Larch wrote:One thought - is there any reason why wget can't be used (with --post-data or --post-file) to replace http_post as well?

Thanks for that - it's something I wasn't aware of. It may be a better solution than what I've managed to come up with. However I'd like to get the current solution tested before taking it any further.

The only problem I see is that this won't help those (like my parents) with unmodified tivos. I suspect that covers quite a few of those still using dial-up.

Sorry, you've got the wrong end of the stick. I believe the solution will work for unmodified TiVo's too. But to date I've only built an installation package for AltEPG1.0d. I'd like to get that tested before moving on to doing an installer for unmodified TiVos - that's quite a bit more work. Sadly no one has offered to do any testing yet. :cry:

So here's hoping the source of the timeouts is found and fixed as well!

It would be nice, but I've run out of ideas.

It's odd though, TCP ought to recover from lost packets. Is the problem that the dial-up connection suddenly stops routing altogether?

I don't know precisely what happens, but the problem is only intermittent, which is why the retry solution seems to overcome it.
millsb
AltEPG Team
AltEPG Team
 
Posts: 974
Joined: Sat Mar 05, 2011 11:16 am

Re: Dialup Reliability Improvement

Postby DX30 » Wed Oct 10, 2012 9:04 am

millsb wrote:Sadly no one has offered to do any testing yet. :cry:

I have a spare TiVo I can setup to do some dialup testing if you are still looking for volunteers.
DX30
Valued Contributor
Valued Contributor
 
Posts: 645
Joined: Thu May 19, 2011 2:36 pm

Re: Dialup Reliability Improvement

Postby millsb » Wed Oct 10, 2012 10:51 am

DX30 wrote:
millsb wrote:Sadly no one has offered to do any testing yet. :cry:

I have a spare TiVo I can setup to do some dialup testing if you are still looking for volunteers.


Thanks. As noted above TiVo needs altepg1.0d installed. The package you need to install is available for download from www.altepg.com/am (login, choose your tivo and pick 'Install Software', click the 'show test packages' checkbox, and choose timeout-retry_patch-2012-10-06

Suggest using the 0161 number to download and install the patch, then when that's confirmed as installed switch to 0845 number to check daily calls work OK.

Cheers
millsb
AltEPG Team
AltEPG Team
 
Posts: 974
Joined: Sat Mar 05, 2011 11:16 am

Re: Dialup Reliability Improvement

Postby The Larch » Wed Oct 10, 2012 10:03 pm

millsb wrote:Sorry, you've got the wrong end of the stick. I believe the solution will work for unmodified TiVo's too. But to date I've only built an installation package for AltEPG1.0d. I'd like to get that tested before moving on to doing an installer for unmodified TiVos - that's quite a bit more work.

Ah, sorry, I wasn't aware there was a way to actually make the changes to an unmodified tivo - I thought at the very least I'd have to pull the drive to enable shell access. Obviously I'm going to have to look in to this.

millsb wrote:Sadly no one has offered to do any testing yet. :cry:

I can try to talk my parents in to letting me test it, but I don't hold out much hope. They use it every day and live in abject fear of it ever dying. We've tried out several freeview recorders in the shop, and none of them seem particularly usable if you're blind.

It would be nice, but I've run out of ideas.

I feel your pain, it must be almost impossible to diagnose this sort of problem!
The Larch
Powering up...
Powering up...
 
Posts: 14
Joined: Tue Oct 09, 2012 10:05 pm

Re: Dialup Reliability Improvement

Postby DX30 » Thu Oct 11, 2012 2:47 pm

I hit some problems with the timeout-retry_patch-2012-10-06 package. From the tclient logs it looks like it is failing because /tvlib/http_post.bash isn't found as it is in tvbin.

I think I've put things back to normal by replacing CmdStr.itcl and TClient-lib.itcl with the standard versions - anything else I should do?

Let me know if you want me to give it another go.
DX30
Valued Contributor
Valued Contributor
 
Posts: 645
Joined: Thu May 19, 2011 2:36 pm

Re: Dialup Reliability Improvement

Postby millsb » Thu Oct 11, 2012 5:02 pm

Rats! I fixed that bug but failed to update the patch file. Can you try again?

Thanks
millsb
AltEPG Team
AltEPG Team
 
Posts: 974
Joined: Sat Mar 05, 2011 11:16 am

Re: Dialup Reliability Improvement

Postby DX30 » Thu Oct 11, 2012 5:54 pm

I installed the new package and tried it on serial-ppp first. I'm getting "Failed. Call interrupted". The tclient log file seems to show a problem with http_get.bash

Code: Select all
10/11:17:40:19: /tvbin/TClient:  Executing HTTP GET: /tvbin/http_get.bash -U http://127.0.0.1:8000/tivo-static/ukheadends/message-20000035.slice -D /var/packages -T 0230000601E875C -C 1349977137 -d
10/11:17:42:09: /tvbin/TClient:  http GET command failed: child process exited abnormally
10/11:17:42:09: /tvbin/TClient:  Download failure: 1


I'll try with dialup later but I assume this package shouldn't break non-dialup TiVo's?

Edit: dialup results differ, but fail with No dial tone (after Dialup, Answered, Connecting). The suspicious bit of the log file is

Code: Select all
10/11:18:13:59: /tvbin/TClient:  Executing HTTP command: /tvbin/http_post.bash /var/log/svclog http://127.0.0.1:8000/tivo-service/mlog.cgi OFF OFF ON
10/11:18:14:00: /tvbin/TClient:  about to do TCD411 Call
10/11:18:14:00: /tvbin/TClient:  Executing HTTP command (10): /tvbin/tclient_post 127.0.0.1:8000 /var/tmp/TCD411.send /var/tmp/TCD411.recv 5 ON
10/11:18:14:05: /tvbin/TClient:  http POST command failed:  timeout waiting to read
10/11:18:14:05: /tvbin/TClient:  Executing HTTP command (9): /tvbin/tclient_post 127.0.0.1:8000 /var/tmp/TCD411.send /var/tmp/TCD411.recv 5 ON
10/11:18:14:11: /tvbin/TClient:  http POST command failed:  timeout waiting to read
10/11:18:14:11: /tvbin/TClient:  Executing HTTP command (8): /tvbin/tclient_post 127.0.0.1:8000 /var/tmp/TCD411.send /var/tmp/TCD411.recv 5 ON
10/11:18:14:16: /tvbin/TClient:  http POST command failed:  timeout waiting to read
10/11:18:14:16: /tvbin/TClient:  Executing HTTP command (7): /tvbin/tclient_post 127.0.0.1:8000 /var/tmp/TCD411.send /var/tmp/TCD411.recv 5 ON
10/11:18:14:21: /tvbin/TClient:  http POST command failed:  timeout waiting to read
10/11:18:14:21: /tvbin/TClient:  Executing HTTP command (6): /tvbin/tclient_post 127.0.0.1:8000 /var/tmp/TCD411.send /var/tmp/TCD411.recv 5 ON
10/11:18:14:26: /tvbin/TClient:  http POST command failed:  timeout waiting to read
10/11:18:14:26: /tvbin/TClient:  Executing HTTP command (5): /tvbin/tclient_post 127.0.0.1:8000 /var/tmp/TCD411.send /var/tmp/TCD411.recv 5 ON
10/11:18:14:31: /tvbin/TClient:  http POST command failed:  timeout waiting to read
10/11:18:14:31: /tvbin/TClient:  Executing HTTP command (4): /tvbin/tclient_post 127.0.0.1:8000 /var/tmp/TCD411.send /var/tmp/TCD411.recv 5 ON
10/11:18:14:36: /tvbin/TClient:  http POST command failed:  connect failed, reason = Connection timed out
10/11:18:14:36: /tvbin/TClient:  Executing HTTP command (3): /tvbin/tclient_post 127.0.0.1:8000 /var/tmp/TCD411.send /var/tmp/TCD411.recv 5 ON
10/11:18:14:41: /tvbin/TClient:  http POST command failed:  connect failed, reason = Connection timed out
10/11:18:14:41: /tvbin/TClient:  Executing HTTP command (2): /tvbin/tclient_post 127.0.0.1:8000 /var/tmp/TCD411.send /var/tmp/TCD411.recv 5 ON
10/11:18:14:47: /tvbin/TClient:  http POST command failed:  connect failed, reason = Connection timed out
10/11:18:14:47: /tvbin/TClient:  Executing HTTP command (1): /tvbin/tclient_post 127.0.0.1:8000 /var/tmp/TCD411.send /var/tmp/TCD411.recv 5 ON
10/11:18:14:52: /tvbin/TClient:  http POST command failed:  connect failed, reason = Connection timed out
10/11:18:14:52: /tvbin/TClient:  doHttpCall returned: 0
10/11:18:14:52: /tvbin/TClient:  Connect/POST has failed, we've warned the user, set status to Failed
10/11:18:14:52: /tvbin/TClient:  failed connect - aborting


The whole tclient in case there are other clues
Code: Select all
10/11:18:06:17: /tvbin/TClient:  inside TClient
10/11:18:06:18: /tvbin/TClient:  No previously downloaded files remain in /var/packages
10/11:18:06:18: /tvbin/TClient:  TClient: invoking init w/argv=-t
10/11:18:06:18: /tvbin/TClient:  TClient: TClient-lib version altepg1.0d
10/11:18:06:18: /tvbin/TClient:  writing In Progress to LastCallStatus
10/11:18:06:18: /tvbin/TClient:  deferCall: special callWait prefix set - changing netcard config (won't call)
10/11:18:06:18: /tvbin/TClient:  calling changeNetcard with code=0 ip= gateway= netmask=
10/11:18:06:18: /tvbin/TClient:  changeNetcard: changing to 'Auto' (code=0)
10/11:18:06:20: /tvbin/TClient:  changeNetCard:nic set to Auto in /etc/oztivo.conf
10/11:18:06:20: /tvbin/TClient:  Calling event send 23 DATA_MESSAGES 0
10/11:18:06:20: /tvbin/TClient:  TClient init: 0
10/11:18:06:20: /tvbin/TClient:  dial config code: (005) found
10/11:18:06:20: /tvbin/TClient:  matched 005, returning value = 08450800300:127.0.0.1:8000::
10/11:18:06:20: /tvbin/TClient:  updateStatus: In Progress EX| 29 48
10/11:18:06:20: /tvbin/TClient:  writing In Progress to LastCallStatus
10/11:18:06:20: /tvbin/TClient:  SendDialupEvent 30 9 EX|29
10/11:18:06:20: /tvbin/TClient:  Host = 127.0.0.1
10/11:18:06:20: /tvbin/TClient:  Port = 8000
10/11:18:06:20: /tvbin/TClient:  Phone = 08450800300
10/11:18:06:20: /tvbin/TClient:  updateStatus: In Progress EX| 29 50
10/11:18:06:20: /tvbin/TClient:  SendDialupEvent 30 9 EX|29
10/11:18:06:20: /tvbin/TClient:  Network changed. Status => Failed, Phase => EX| 29 50
10/11:18:06:21: /tvbin/TClient:  updateStatus: In Progress EX| 29 11
10/11:18:06:21: /tvbin/TClient:  SendDialupEvent 30 9 EX|29
10/11:18:06:26: /tvbin/TClient:  updateStatus: Failed EX| 29 11
Saving 'EX|11' to result file
10/11:18:06:26: /tvbin/TClient:  writing Failed to LastCallStatus
10/11:18:06:26: /tvbin/TClient:  SendDialupEvent 30 9 EX|11
10/11:18:06:26: /tvbin/TClient:  TClient login: 1
10/11:18:06:26: /tvbin/TClient:  TClient backhaulDone: 0
10/11:18:09:54: /tvbin/TClient:  inside TClient
10/11:18:09:55: /tvbin/TClient:  No previously downloaded files remain in /var/packages
10/11:18:09:55: /tvbin/TClient:  TClient: invoking init w/argv=-backup
10/11:18:09:55: /tvbin/TClient:  TClient: TClient-lib version altepg1.0d
10/11:18:09:55: /tvbin/TClient:  writing In Progress to LastCallStatus
10/11:18:09:55: /tvbin/TClient:  deferCall: ',1234567,0721#' didnt match '^,#[0-9]$'
10/11:18:09:55: /tvbin/TClient:  ParseCallWait: diagnosticLevel = '1', deferralRule = '1234567,0721#', cwprefix = ''
10/11:18:09:55: /tvbin/TClient:  deferCall: not an automatic call, so OK, don't defer
10/11:18:09:55: /tvbin/TClient:  TClient init: 0
10/11:18:09:55: /tvbin/TClient:  dial config code: (005) found
10/11:18:09:55: /tvbin/TClient:  matched 005, returning value = 08450800300:127.0.0.1:8000::
10/11:18:09:55: /tvbin/TClient:  updateStatus: In Progress EX| 29 48
10/11:18:09:55: /tvbin/TClient:  writing In Progress to LastCallStatus
10/11:18:09:55: /tvbin/TClient:  SendDialupEvent 30 9 EX|29
10/11:18:09:55: /tvbin/TClient:  Host = 127.0.0.1
10/11:18:09:55: /tvbin/TClient:  Port = 8000
10/11:18:09:55: /tvbin/TClient:  Phone = 08450800300
10/11:18:09:55: /tvbin/TClient:  updateStatus: In Progress EX| 29 50
10/11:18:09:55: /tvbin/TClient:  SendDialupEvent 30 9 EX|29
10/11:18:09:55: /tvbin/TClient:  updateStatus: In Progress EX| 29 8
10/11:18:09:55: /tvbin/TClient:  SendDialupEvent 30 9 EX|29
retrying after errTmBackgroundHoldoff ...
retrying after errTmBackgroundHoldoff ...
10/11:18:10:01: /tvbin/TClient:  DataSets may not be enabled, could not find GenreVersion: DataSet GenreVersion does not exist.
10/11:18:10:01: /tvbin/TClient:  DataSets may not be enabled, could not find LogoVersion: DataSet LogoVersion does not exist.
10/11:18:10:01: /tvbin/TClient:  DataSets may not be enabled, could not find AffiliationVersion: DataSet AffiliationVersion does not exist.
10/11:18:10:01: /tvbin/TClient:  DataSets may not be enabled, could not find ShowcaseVersion: DataSet ShowcaseVersion does not exist.
10/11:18:10:01: /tvbin/TClient:  mrsigtype=5 mrconnector=7...
10/11:18:10:01: /tvbin/TClient:  mrsigtype=1 mrconnector=1...
10/11:18:10:02: /tvbin/TClient:  Using error search string: [Ee]xception([^/]| [^P]| P[^O]| PO[^S]| POS[^T])|[Aa]ssert|[B]acktrace|[Ss]egmentation|[K]ernel panic|[D]riveStatusError|[e]rrDbNoMemory
10/11:18:10:18: /tvbin/TClient:  encryptLog called with infile = /var/persist/thumbslog.log.gz outfile = /var/persist/thumbslog.log.gz.bfg keyname = BACKHAUL_THUMB
10/11:18:10:18: /tvbin/TClient:  EncryptLog Could not find /var/persist/thumbslog.log.gz
10/11:18:10:18: /tvbin/TClient:  encryptLog called with infile = /var/log/tivoLog.prv.gz outfile = /var/log/tivoLog.prv.gz.bfg keyname = BACKHAUL_PRIVATE
10/11:18:10:19: /tvbin/TClient:  bfkey = 0x0D28E3581ADAFB3AFB83BE889F707925
10/11:18:10:19: /tvbin/TClient:  Key value =
10/11:18:10:19: /tvbin/TClient:  EncryptLog could not super-encrypt the key because key was empty
10/11:18:10:19: /tvbin/TClient:  updateStatus: In Progress EX| 28 7
10/11:18:10:19: /tvbin/TClient:  SendDialupEvent 30 9 EX|28
10/11:18:10:19: /tvbin/TClient:  end of tidyup
10/11:18:10:19: /tvbin/TClient:  updateStatus: In Progress EX| 28 7
10/11:18:10:19: /tvbin/TClient:  SendDialupEvent 30 9 EX|28
10/11:18:10:19: /tvbin/TClient:  creating keyserver query
retrying after errTmBackgroundHoldoff ...
10/11:18:10:31: /tvbin/TClient:  setting up Ident Block
10/11:18:10:31: /tvbin/TClient:  found message 20000002 (localId = 428367), from 1
10/11:18:10:32: /tvbin/TClient:  returning messages: 20000002-4|
10/11:18:10:32: /tvbin/TClient:  getting current software
10/11:18:10:33: /tvbin/TClient:  found name = 2.5.5-01-1-023
10/11:18:10:34: /tvbin/TClient:  found name = ACTIVE
10/11:18:10:34: /tvbin/TClient:  Found 2.5.5-01-1 running
10/11:18:10:34: /tvbin/TClient:  getting current showcases
10/11:18:10:34: /tvbin/TClient:  getting locationID
10/11:18:10:35: /tvbin/TClient:  Current postalcode: 01000
10/11:18:10:35: /tvbin/TClient:  getting headendID
10/11:18:10:35: /tvbin/TClient:  getting headend ID List info
10/11:18:10:35
10/11:18:10:35: /tvbin/TClient:  working on headend: dbobj362
10/11:18:10:35: /tvbin/TClient:  Found TmsHeadendId = UK01005
10/11:18:10:35: /tvbin/TClient:  working on headend: dbobj478
10/11:18:10:35: /tvbin/TClient:  Found TmsHeadendId = UK01006
listOfHeadendsWithStations = {UK01005 {416834/-1 416836/-1 416837/-1 416838/-1 416839/-1 416840/-1 416841/-1 416842/-1 416843/-1 416844/-1 416845/-1 416846/-1 416847/-1 416848/-1 416849/-1 416850/-1 416851/-1 416852/-1 416853/-1 416854/-1 416855/-1 416856/-1 416857/-1 416858/-1 416859/-1 416860/-1 416861/-1 416862/-1 416863/-1 416864/-1 416865/-1 416866/-1 416867/-1 416868/-1 416869/-1 416870/-1 416871/-1 416872/-1 416873/-1 416874/-1 416875/-1 416876/-1 416872/-1 416877/-1 416878/-1 416879/-1 416880/-1 416881/-1 416882/-1 416883/-1 416884/-1 416886/-1 416887/-1 416888/-1 416890/-1 416891/-1 416892/-1 416894/-1 416895/-1 416896/-1 416897/-1 416898/-1 416900/-1 416901/-1 416902/-1 416903/-1 416904/-1 416905/-1 416906/-1 416907/-1 416908/-1 416912/-1 416914/-1 416915/-1 416919/-1 416921/-1 416922/-1 416923/-1 416924/-1 416925/-1 416926/-1 416927/-1 416928/-1 416929/-1 416930/-1 416931/-1 416932/-1 416933/-1 416934/-1 416935/-1 416938/-1 416939/-1 416952/-1 416956/-1 416957/-1 416958/-1 416959/-1 416960/-1 416961/-1 416962/-1 416963/-1 416964/-1 416965/-1 416966/-1 416974/-1 416975/-1 416976/-1 416977/-1 416979/-1 417053/-1 417129/-1 417163/-1 438529/-1 447870/-1 447871/-1}} {UK01006 416834/-1}
10/11:18:10:35: /tvbin/TClient:  Hole found in 416834 at 15624
10/11:18:10:35: /tvbin/TClient:  HOLE INFO: station=NoNag sId=7999999 lastDay=15624
10/11:18:10:35: /tvbin/TClient:  Station 416834 last day is 15623 (lastDay=15623)
10/11:18:10:35: /tvbin/TClient:  Station 416836 last day is 15632 (lastDay=15623)
10/11:18:10:35: /tvbin/TClient:  Station 416837 last day is 15632 (lastDay=15623)
10/11:18:10:35: /tvbin/TClient:  Station 416838 last day is 15632 (lastDay=15623)
10/11:18:10:35: /tvbin/TClient:  Station 416839 last day is 15632 (lastDay=15623)
10/11:18:10:35: /tvbin/TClient:  Station 416840 last day is 15632 (lastDay=15623)
10/11:18:10:35: /tvbin/TClient:  Station 416841 last day is 15632 (lastDay=15623)
10/11:18:10:36: /tvbin/TClient:  Station 416842 last day is 15632 (lastDay=15623)
10/11:18:10:36: /tvbin/TClient:  Station 416843 last day is 15632 (lastDay=15623)
10/11:18:10:36: /tvbin/TClient:  Station 416844 last day is 15632 (lastDay=15623)
10/11:18:10:36: /tvbin/TClient:  Station 416845 last day is 15632 (lastDay=15623)
10/11:18:10:36: /tvbin/TClient:  Station 416846 last day is 15632 (lastDay=15623)
10/11:18:10:36: /tvbin/TClient:  Station 416847 last day is 15632 (lastDay=15623)
10/11:18:10:37: /tvbin/TClient:  Station 416848 last day is 15632 (lastDay=15623)
10/11:18:10:37: /tvbin/TClient:  Station 416849 last day is 15632 (lastDay=15623)
10/11:18:10:37: /tvbin/TClient:  Station 416850 last day is 15632 (lastDay=15623)
10/11:18:10:37: /tvbin/TClient:  Station 416851 last day is 15632 (lastDay=15623)
10/11:18:10:38: /tvbin/TClient:  Station 416852 last day is 15632 (lastDay=15623)
10/11:18:10:38: /tvbin/TClient:  Station 416853 last day is 15632 (lastDay=15623)
10/11:18:10:38: /tvbin/TClient:  Station 416854 last day is 15632 (lastDay=15623)
10/11:18:10:38: /tvbin/TClient:  Station 416855 last day is 15632 (lastDay=15623)
10/11:18:10:38: /tvbin/TClient:  HOLE INFO: station=ITV1BS sId=7200297 lastDay=15624
10/11:18:10:38: /tvbin/TClient:  Station 416856 last day is 15623 (lastDay=15623)
10/11:18:10:38: /tvbin/TClient:  Station 416857 last day is 15632 (lastDay=15623)
10/11:18:10:38: /tvbin/TClient:  Station 416858 last day is 15632 (lastDay=15623)
10/11:18:10:38: /tvbin/TClient:  Station 416859 last day is 15632 (lastDay=15623)
10/11:18:10:38: /tvbin/TClient:  Station 416860 last day is 15632 (lastDay=15623)
10/11:18:10:38: /tvbin/TClient:  Station 416861 last day is 15632 (lastDay=15623)
10/11:18:10:38: /tvbin/TClient:  Station 416862 last day is 15632 (lastDay=15623)
10/11:18:10:38: /tvbin/TClient:  Station 416863 last day is 15632 (lastDay=15623)
10/11:18:10:38: /tvbin/TClient:  Station 416864 last day is 15632 (lastDay=15623)
10/11:18:10:38: /tvbin/TClient:  Station 416865 last day is 15632 (lastDay=15623)
10/11:18:10:39: /tvbin/TClient:  Station 416866 last day is 15632 (lastDay=15623)
10/11:18:10:39: /tvbin/TClient:  Station 416867 last day is 15632 (lastDay=15623)
10/11:18:10:39: /tvbin/TClient:  Station 416868 last day is 15632 (lastDay=15623)
10/11:18:10:39: /tvbin/TClient:  Station 416869 last day is 15632 (lastDay=15623)
10/11:18:10:39: /tvbin/TClient:  Station 416870 last day is 15632 (lastDay=15623)
10/11:18:10:39: /tvbin/TClient:  Station 416871 last day is 15632 (lastDay=15623)
10/11:18:10:39: /tvbin/TClient:  Station 416872 last day is 15632 (lastDay=15623)
10/11:18:10:39: /tvbin/TClient:  Station 416873 last day is 15632 (lastDay=15623)
10/11:18:10:39: /tvbin/TClient:  Station 416874 last day is 15632 (lastDay=15623)
10/11:18:10:39: /tvbin/TClient:  Station 416875 last day is 15632 (lastDay=15623)
10/11:18:10:39: /tvbin/TClient:  Station 416876 last day is 15632 (lastDay=15623)
10/11:18:10:39: /tvbin/TClient:  Station 416872 last day is 15632 (lastDay=15623)
10/11:18:10:39: /tvbin/TClient:  Station 416877 last day is 15632 (lastDay=15623)
10/11:18:10:39: /tvbin/TClient:  Station 416878 last day is 15632 (lastDay=15623)
10/11:18:10:40: /tvbin/TClient:  Station 416879 last day is 15632 (lastDay=15623)
10/11:18:10:40: /tvbin/TClient:  Station 416880 last day is 15632 (lastDay=15623)
10/11:18:10:40: /tvbin/TClient:  Station 416881 last day is 15632 (lastDay=15623)
10/11:18:10:40: /tvbin/TClient:  Station 416882 last day is 15632 (lastDay=15623)
10/11:18:10:40: /tvbin/TClient:  Station 416883 last day is 15632 (lastDay=15623)
10/11:18:10:40: /tvbin/TClient:  Station 416884 last day is 15632 (lastDay=15623)
10/11:18:10:40: /tvbin/TClient:  Station 416886 last day is 15629 (lastDay=15623)
10/11:18:10:40: /tvbin/TClient:  Station 416887 last day is 15632 (lastDay=15623)
10/11:18:10:40: /tvbin/TClient:  Station 416888 last day is 15632 (lastDay=15623)
10/11:18:10:40: /tvbin/TClient:  Statio
10/11:18:10:40: /tvbin/TClient:  Station 416890 last day is 15632 (lastDay=15623)
10/11:18:10:40: /tvbin/TClient:  Station 416891 last day is 15632 (lastDay=15623)
10/11:18:10:40: /tvbin/TClient:  Station 416892 last day is 15632 (lastDay=15623)
10/11:18:10:40: /tvbin/TClient:  Station 416894 last day is 15632 (lastDay=15623)
10/11:18:10:40: /tvbin/TClient:  Station 416895 last day is 15632 (lastDay=15623)
10/11:18:10:40: /tvbin/TClient:  Station 416896 last day is 15632 (lastDay=15623)
10/11:18:10:41: /tvbin/TClient:  Station 416897 last day is 15632 (lastDay=15623)
10/11:18:10:41: /tvbin/TClient:  Station 416898 last day is 15632 (lastDay=15623)
10/11:18:10:41: /tvbin/TClient:  Station 416900 last day is 15632 (lastDay=15623)
10/11:18:10:41: /tvbin/TClient:  Station 416901 last day is 15632 (lastDay=15623)
10/11:18:10:41: /tvbin/TClient:  Station 416902 last day is 15632 (lastDay=15623)
10/11:18:10:41: /tvbin/TClient:  Station 416903 last day is 15632 (lastDay=15623)
10/11:18:10:41: /tvbin/TClient:  Station 416904 last day is 15632 (lastDay=15623)
10/11:18:10:41: /tvbin/TClient:  Station 416905 last day is 15632 (lastDay=15623)
10/11:18:10:41: /tvbin/TClient:  Station 416906 last day is 15632 (lastDay=15623)
10/11:18:10:41: /tvbin/TClient:  Station 416907 last day is 15632 (lastDay=15623)
10/11:18:10:41: /tvbin/TClient:  Station 416908 last day is 15632 (lastDay=15623)
10/11:18:10:41: /tvbin/TClient:  Station 416912 last day is 15632 (lastDay=15623)
10/11:18:10:41: /tvbin/TClient:  Station 416914 last day is 15632 (lastDay=15623)
10/11:18:10:41: /tvbin/TClient:  Station 416915 last day is 15632 (lastDay=15623)
10/11:18:10:41: /tvbin/TClient:  Station 416919 last day is 15632 (lastDay=15623)
10/11:18:10:42: /tvbin/TClient:  Station 416921 last day is 15632 (lastDay=15623)
10/11:18:10:42: /tvbin/TClient:  Station 416922 last day is 15632 (lastDay=15623)
10/11:18:10:42: /tvbin/TClient:  Station 416923 last day is 15632 (lastDay=15623)
10/11:18:10:42: /tvbin/TClient:  Station 416924 last day is 15632 (lastDay=15623)
10/11:18:10:42: /tvbin/TClient:  Station 416925 last day is 15632 (lastDay=15623)
10/11:18:10:42: /tvbin/TClient:  Station 416926 last day is 15632 (lastDay=15623)
10/11:18:10:42: /tvbin/TClient:  Station 416927 last day is 15632 (lastDay=15623)
10/11:18:10:42: /tvbin/TClient:  Station 416928 last day is 15632 (lastDay=15623)
10/11:18:10:42: /tvbin/TClient:  Station 416929 last day is 15632 (lastDay=15623)
10/11:18:10:42: /tvbin/TClient:  Station 416930 last day is 15632 (lastDay=15623)
10/11:18:10:42: /tvbin/TClient:  Station 416931 last day is 15632 (lastDay=15623)
10/11:18:10:42: /tvbin/TClient:  Station 416932 last day is 15632 (lastDay=15623)
10/11:18:10:42: /tvbin/TClient:  Station 416933 last day is 15629 (lastDay=15623)
10/11:18:10:42: /tvbin/TClient:  Station 416934 last day is 15629 (lastDay=15623)
10/11:18:10:43: /tvbin/TClient:  Station 416935 last day is 15632 (lastDay=15623)
10/11:18:10:43: /tvbin/TClient:  Station 416938 last day is 15632 (lastDay=15623)
10/11:18:10:43: /tvbin/TClient:  Station 416939 last day is 15632 (lastDay=15623)
10/11:18:10:43: /tvbin/TClient:  Station 416952 last day is 15632 (lastDay=15623)
10/11:18:10:43: /tvbin/TClient:  Station 416956 last day is 15630 (lastDay=15623)
10/11:18:10:43: /tvbin/TClient:  Station 416957 last day is 15630 (lastDay=15623)
10/11:18:10:43: /tvbin/TClient:  Station 416958 last day is 15630 (lastDay=15623)
10/11:18:10:43: /tvbin/TClient:  Station 416959 last day is 15629 (lastDay=15623)
10/11:18:10:43: /tvbin/TClient:  Station 416960 last day is 15630 (lastDay=15623)
10/11:18:10:43: /tvbin/TClient:  Station 416961 last day is 15630 (lastDay=15623)
10/11:18:10:43: /tvbin/TClient:  Hole found in 416962 at 15624
10/11:18:10:43: /tvbin/TClient:  HOLE INFO: station=BBC5LX sId=7200062 lastDay=15624
10/11:18:10:43: /tvbin/TClient:  Station 416962 last day is 15623 (lastDay=15623)
10/11:18:10:43: /tvbin/TClient:  Station 416963 last day is 15630 (lastDay=15623)
10/11:18:10:43: /tvbin/TClient:  Station 416964 last day is 15630 (lastDay=15623)
10/11:18:10:43: /tvbin/TClient:  Station 416965 last day is 15630 (lastDay=15623)
10/11:18:10:43: /tvbin/TClient:  Station 416966 last day is 15630 (lastDay=15623)
10/11:18:10:43: /tvbin/TClient:  Station 416974 last day is 15630 (lastDay=15623)
10/11:18:10:44: /tvbin/TClient:  Station 416975 last day is 15629 (lastDay=15623)
10/11:18:10:44: /tvbin/TClient:  Station 416976 last day is 15630 (lastDay=15623)
10/11:18:10:44: /tvbin/TClient:  Station 416977 last day is 15629 (lastDay=15623)
10/11:18:10:44: /tvbin/TClient:  Station 416979 last day is 15629 (lastDay=15623)
10/11:18:10:44: /tvbin/TClient:  Station 417053 last day is 15632 (lastDay=15623)
10/11:18:10:44: /tvbin/TClient:  Station 417129 last day is 15632 (lastDay=15623)
10/11:18:10:44: /tvbin/TClient:  Station 417163 last day is 15632 (lastDay=15623)
10/11:18:10:44: /tvbin/TClient:  Station 438529 last day is 15632 (lastDay=15623)
10/11:18:10:44: /tvbin/TClient:  Station 447870 last day is 15632 (lastDay=15623)
10/11:18:10:44: /tvbin/TClient:  Station 447871 last day is 15632 (lastDay=15623)
10/11:18:10:44: /tvbin/TClient:  Last day of programming data for UK01005 is 15623
10/11:18:10:44: /tvbin/TClient:  retHeadStr = UK01005-15623|
10/11:18:10:44: /tvbin/TClient:  Hole found in 416834 at 15624
10/11:18:10:44: /tvbin/TClient:  HOLE INFO: station=NoNag sId=7999999 lastDay=15624
10/11:18:10:44: /tvbin/TClient:  Station 416834 last day is 15623 (lastDay=15623)
10/11:18:10:44: /tvbin/TClient:  Last day of programming data for UK01006 is 15623
10/11:18:10:44: /tvbin/TClient:  retHeadStr = UK01005-15623|UK01006-15623|
10/11:18:10:44: /tvbin/TClient:  setting up TCD411 block
10/11:18:10:44: /tvbin/TClient:  setting area code:
10/11:18:10:44: /tvbin/TClient:  getCurPhoneNum : dialinprefix = ''
10/11:18:10:44: /tvbin/TClient:  getCurPhoneNum : +dialinareacode = ''
10/11:18:10:44: /tvbin/TClient:  getCurPhoneNum : +dialinnum = ''
10/11:18:10:44: /tvbin/TClient: 
10/11:18:10:44: /tvbin/TClient:       Start TCD411 Request ==================
10/11:18:10:44: /tvbin/TClient:              areaCode:
10/11:18:10:44: /tv
10/11:18:10:44: /tvbin/TClient:                prefix: {}
10/11:18:10:44: /tvbin/TClient:        dialInAreaCode: {}
10/11:18:10:44: /tvbin/TClient:              curPhNum:
10/11:18:10:44: /tvbin/TClient:                objVer:
10/11:18:10:44: /tvbin/TClient:                 tcdId: 0230000601E875C
10/11:18:10:44: /tvbin/TClient:                callId: 1349978995
10/11:18:10:44: /tvbin/TClient:            dialPrefix:
10/11:18:10:44: /tvbin/TClient:         dialToneCheck:
10/11:18:10:44: /tvbin/TClient:         offHookDetect:
10/11:18:10:44: /tvbin/TClient:         tonePulseDial: P
10/11:18:10:44: /tvbin/TClient:        callWaitPrefix: ,1234567,0721#
10/11:18:10:44: /tvbin/TClient:          tollFreeAuth: 1
10/11:18:10:44: /tvbin/TClient:              callType: TS_SR_ACCEPTED
10/11:18:10:44: /tvbin/TClient:             swVerName: 2.5.5-01-1-023
10/11:18:10:44: /tvbin/TClient:         End TCD411 Request ==================
10/11:18:10:44: /tvbin/TClient: 
10/11:18:10:44: /tvbin/TClient:   Start Ident     =====================
10/11:18:10:44: /tvbin/TClient:              version: 3
10/11:18:10:44: /tvbin/TClient:             centerID: 0230000601E875C
10/11:18:10:44: /tvbin/TClient:           reasonCode: 1
10/11:18:10:44: /tvbin/TClient:         softwareDesc: 468089-51|468071-1|468073-1|468075-1|468077-1|468079-1|468081-1|468083-1|468085-1|468087-1|468090-1|468091-1|468092-1|468093-1|468094-1|468095-1|468096-1|468097-1|468098-1|468099-1|468100-1|468101-1|468102-1|468103-1|468104-1|468105-1|468106-1|468107-1|468108-1|468109-1|468110-1|468111-1|468112-1|468113-1|468114-1|468115-1|468116-1|468117-1|468118-1|468119-1|468120-1|468121-1|468122-1|468123-1|468124-1|468125-1|468127-1|468128-1|468129-1|468130-1|468131-1|468132-1|468133-1|468134-1|468135-1|468136-1|468137-1|468138-1|468139-1|24252-77|24264-362|387715-4|61464-40|24273-54|24294-76|427608-4|24306-72|24337-54|24352-638|24358-36|24380-12|
10/11:18:10:44: /tvbin/TClient:           locationID: 01000-30
10/11:18:10:44: /tvbin/TClient:       sequenceCookie: 12345678
10/11:18:10:44: /tvbin/TClient:            headendID: UK01005-15623|UK01006-15623|
10/11:18:10:44: /tvbin/TClient:         showcaseDesc: showcase0-0
10/11:18:10:44: /tvbin/TClient:        inventoryFile:
10/11:18:10:44: /tvbin/TClient:         waitingCount: 0
10/11:18:10:44: /tvbin/TClient:           dialConfig: 005
10/11:18:10:44: /tvbin/TClient:             confInfo: 08450800300:127.0.0.1:8000::
10/11:18:10:44: /tvbin/TClient:          messageDesc: 20000002-4|
10/11:18:10:44: /tvbin/TClient:          irdbVersion: 317
10/11:18:10:44: /tvbin/TClient:         genreVersion:
10/11:18:10:44: /tvbin/TClient:          logoVersion:
10/11:18:10:44: /tvbin/TClient:   affiliationVersion:
10/11:18:10:44: /tvbin/TClient:      showcaseVersion:
10/11:18:10:44: /tvbin/TClient:            swVerName: 2.5.5-01-1-023
10/11:18:10:44: /tvbin/TClient:  configParameterList: zip=01000,dar=,rcq=,tz=7,as=,tun=,suc=7
10/11:18:10:44: /tvbin/TClient:  sourceParameterList: st=5,con=7,drm=,ekr=,ccn=20034,brn=SONY,lin=1,irs=150;st=1,con=1,drm=,ekr=,ccn=,brn=,lin=16,irs=
10/11:18:10:44: /tvbin/TClient:              apgOnly:
10/11:18:10:44: /tvbin/TClient:           useChksums: TRUE
10/11:18:10:44: /tvbin/TClient:     premiumShowcases:
10/11:18:10:44: /tvbin/TClient:      captureRequests:
10/11:18:10:44: /tvbin/TClient:            menuItems:
10/11:18:10:44: /tvbin/TClient:        otherDataSets: HDGenre-4|RM_cleanTvShow-|
10/11:18:10:44: /tvbin/TClient:        rbBackgrounds:
10/11:18:10:44: /tvbin/TClient:        dataGroupList:
10/11:18:10:44: /tvbin/TClient:   lstAvalancheDnload: 0,0 0,0
10/11:18:10:44: /tvbin/TClient:        userInitiated: 1
10/11:18:10:44: /tvbin/TClient:  altEPGClientVersion: altepg1.0d
10/11:18:10:44: /tvbin/TClient:         nicInstalled: MODEM
10/11:18:10:44: /tvbin/TClient:                hdaId: S088J10YA15494
10/11:18:10:44: /tvbin/TClient:                hdbId: Unknown
10/11:18:10:44: /tvbin/TClient:             hdaModel: SAMSUNG SP2014N                         
10/11:18:10:44: /tvbin/TClient:             hdbModel:
10/11:18:10:44: /tvbin/TClient:  End Ident        =====================
10/11:18:10:44: /tvbin/TClient: 
10/11:18:10:44: /tvbin/TClient:  Logging camid.
10/11:18:10:44: /tvbin/TClient:  CAM_ID not found.
10/11:18:10:44: /tvbin/TClient:  Ird Id.
10/11:18:10:45: /tvbin/TClient:  useModem: dialPrefix not set, probing network...
10/11:18:10:45: /tvbin/TClient:  useModem: no network found  - using dialup modem
10/11:18:10:45: /tvbin/TClient:    toneOrPulse = 0
10/11:18:10:45: /tvbin/TClient:    dialPrefix = {}
10/11:18:10:45: /tvbin/TClient:    callWaitingPrefix == ,1234567,0721#
10/11:18:10:45: /tvbin/TClient:    realCallWaitingPrefix ==
10/11:18:10:45: /tvbin/TClient:    phoneNumber = 08450800300
10/11:18:10:45: /tvbin/TClient:    phoneAvailableDetection = 1
10/11:18:10:45: /tvbin/TClient:    dialToneDetection = 0
10/11:18:10:45: /tvbin/TClient:  Starting dial.expect with:
10/11:18:10:45: /tvbin/TClient:    toneOrPulse = T
10/11:18:10:45: /tvbin/TClient:    dialPrefix = {}
10/11:18:10:45: /tvbin/TClient:    callWaitingPrefix = ,1234567,0721#
10/11:18:10:45: /tvbin/TClient:    realCallWaitingPrefix ==
10/11:18:10:45: /tvbin/TClient:    phoneNumber = 08450800300
10/11:18:10:45: /tvbin/TClient:    phoneAvailableDetection = 0
10/11:18:10:45: /tvbin/TClient:    dialToneDetection = 1
10/11:18:10:45: /tvbin/TClient:    useV34 = 0
10/11:18:10:45: /tvbin/TClient:  updateStatus: In Progress CL| 30 24
10/11:18:10:45: /tvbin/TClient:  SendDialupEvent 30 9 CL|30
10/11:18:10:58: /tvbin/TClient:  Whole result is spawn /tvbin/modemtest -expect
ATZ
ATZ

OKChecking for modem type...

ATI3

P2109-V90

OK
Modem type is 2109
*****NEW***** modem
ATQ0

OK
ATS0=0

OK
AT+GCI=B4

OK
AT-STE=2

OK
ATW2S6=8S7=50S11=100%C0&D2+MS=V34

OK
ATW1X4

OK
AT-TTE=1500,200,500

OK
Current line voltage (in volts, of course!):
AT-TRV

48.97
OK
new modem...line status interrupt disabled
ATDT08450800300

NO DIALTONE
dialcode is:10
10/11:18:10:58: /tvbin/TClient:  PPP has failed, we've warned the user, set status to Failed
10/11:18:11:03: /tvbin/TClient:  updateStatus: F
10/11:18:11:03: /tvbin/TClient:  updateStatus: Failed CL| 30 24
Saving 'CL|10' to result file
10/11:18:11:03: /tvbin/TClient:  writing Failed to LastCallStatus
10/11:18:11:03: /tvbin/TClient:  SendDialupEvent 30 9 EX|10
10/11:18:11:03: /tvbin/TClient:  Creating Dialup Message...
10/11:18:11:03: /tvbin/TClient:  Calling event send 23 DATA_MESSAGES 0
10/11:18:11:03: /tvbin/TClient:  TClient login: 1
10/11:18:11:03: /tvbin/TClient:  TClient backhaulDone: 0
10/11:18:12:29: /tvbin/TClient:  inside TClient
10/11:18:12:30: /tvbin/TClient:  No previously downloaded files remain in /var/packages
10/11:18:12:30: /tvbin/TClient:  TClient: invoking init w/argv=
10/11:18:12:30: /tvbin/TClient:  TClient: TClient-lib version altepg1.0d
10/11:18:12:30: /tvbin/TClient:  writing In Progress to LastCallStatus
10/11:18:12:30: /tvbin/TClient:  deferCall: ',1234567,0721#' didnt match '^,#[0-9]$'
10/11:18:12:30: /tvbin/TClient:  ParseCallWait: diagnosticLevel = '1', deferralRule = '1234567,0721#', cwprefix = ''
10/11:18:12:30: /tvbin/TClient:  deferCall: not an automatic call, so OK, don't defer
10/11:18:12:30: /tvbin/TClient:  TClient init: 0
10/11:18:12:30: /tvbin/TClient:  dial config code: (005) found
10/11:18:12:30: /tvbin/TClient:  matched 005, returning value = 08450800300:127.0.0.1:8000::
10/11:18:12:30: /tvbin/TClient:  updateStatus: In Progress EX| 29 48
10/11:18:12:30: /tvbin/TClient:  writing In Progress to LastCallStatus
10/11:18:12:30: /tvbin/TClient:  SendDialupEvent 30 9 EX|29
10/11:18:12:30: /tvbin/TClient:  Host = 127.0.0.1
10/11:18:12:30: /tvbin/TClient:  Port = 8000
10/11:18:12:30: /tvbin/TClient:  Phone = 08450800300
10/11:18:12:30: /tvbin/TClient:  updateStatus: In Progress EX| 29 50
10/11:18:12:30: /tvbin/TClient:  SendDialupEvent 30 9 EX|29
10/11:18:12:30: /tvbin/TClient:  updateStatus: In Progress EX| 29 8
10/11:18:12:30: /tvbin/TClient:  SendDialupEvent 30 9 EX|29
retrying after errTmBackgroundHoldoff ...
retrying after errTmBackgroundHoldoff ...
10/11:18:12:36: /tvbin/TClient:  DataSets may not be enabled, could not find GenreVersion: DataSet GenreVersion does not exist.
10/11:18:12:36: /tvbin/TClient:  DataSets may not be enabled, could not find LogoVersion: DataSet LogoVersion does not exist.
10/11:18:12:37: /tvbin/TClient:  DataSets may not be enabled, could not find AffiliationVersion: DataSet AffiliationVersion does not exist.
10/11:18:12:37: /tvbin/TClient:  DataSets may not be enabled, could not find ShowcaseVersion: DataSet ShowcaseVersion does not exist.
10/11:18:12:37: /tvbin/TClient:  mrsigtype=5 mrconnector=7...
10/11:18:12:37: /tvbin/TClient:  mrsigtype=1 mrconnector=1...
10/11:18:12:38: /tvbin/TClient:  Using error search string: [Ee]xception([^/]| [^P]| P[^O]| PO[^S]| POS[^T])|[Aa]ssert|[B]acktrace|[Ss]egmentation|[K]ernel panic|[D]riveStatusError|[e]rrDbNoMemory
10/11:18:12:54: /tvbin/TClient:  encryptLog called with infile = /var/persist/thumbslog.log.gz outfile = /var/persist/thumbslog.log.gz.bfg keyname = BACKHAUL_THUMB
10/11:18:12:54: /tvbin/TClient:  EncryptLog Could not find /var/persist/thumbslog.log.gz
10/11:18:12:54: /tvbin/TClient:  encryptLog called with infile = /var/log/tivoLog.prv.gz outfile = /var/log/tivoLog.prv.gz.bfg keyname = BACKHAUL_PRIVATE
10/11:18:12:54: /tvbin/TClient:  bfkey = 0xFE149AE928CBD28BF22ABE7A6814F56D
10/11:18:12:54: /tvbin/TClient:  Key value =
10/11:18:12:54: /tvbin/TClient:  EncryptLog could not super-encrypt the key because key was empty
10/11:18:12:54: /tvbin/TClient:  updateStatus: In Progress EX| 28 7
10/11:18:12:54: /tvbin/TClient:  SendDialupEvent 30 9 EX|28
retrying after errTmBackgroundHoldoff ...
retrying after errTmBackgroundHoldoff ...
10/11:18:13:01: /tvbin/TClient:  end of tidyup
10/11:18:13:01: /tvbin/TClient:  updateStatus: In Progress EX| 28 7
10/11:18:13:01: /tvbin/TClient:  SendDialupEvent 30 9 EX|28
10/11:18:13:01: /tvbin/TClient:  creating keyserver query
10/11:18:13:10: /tvbin/TClient:  setting up Ident Block
10/11:18:13:10: /tvbin/TClient:  found message 20000002 (localId = 428367), from 1
10/11:18:13:13: /tvbin/TClient:  returning messages: 20000002-4|
10/11:18:13:13: /tvbin/TClient:  getting current software
10/11:18:13:13: /tvbin/TClient:  found name = 2.5.5-01-1-023
10/11:18:13:14: /tvbin/TClient:  found name = ACTIVE
10/11:18:13:15: /tvbin/TClient:  Found 2.5.5-01-1 running
10/11:18:13:15: /tvbin/TClient:  getting current showcases
10/11:18:13:15: /tvbin/TClient:  getting locationID
10/11:18:13:15: /tvbin/TClient:  Current postalcode: 01000
10/11:18:13:15: /tvbin/TClient:  getting headendID
10/11:18:13:15: /tvbin/TClient:  getting headend ID List info
10/11:18:13:15: /tvbin/TClient:  working on headend: dbobj363
10/11:18:13:15: /tvbin/TClient:  Found TmsHeadendId = UK01005
10/11:18:13:15: /tvbin/TClient:  working on headend: dbobj479
10/11:18:13:15: /tvbin/TClient:  Found TmsHeadendId = UK01006
listOfHeadendsWithStations = {UK01005 {416834/-1 416836/-1 416837/-1 416838/-1 416839/-1 416840/-1 416841/-1 416842/-1 416843/-1 416844/-1 416845/-1 416846/-1 416847/-1 416848/-1 416849/-1 416850/-1 416851/-1 416852/-1 416853/-1 416854/-1 416855/-1 416856/-1 416857/-1 416858/-1 416859/-1 416860/-1 416861/-1 416862/-1 416863/-1 416864/-1 416865/-1 416866/-1 416867/-1 416868/-1 416869/-1 416870/-1 416871/-1 416872/-1 416873/-1 416874/-1 416875/-1 416876/-1 416872/-1 416877/-1 416878/-1 416879/-1 416880/-1 416881/-1 416882/-1 416883/-1 416884/-1 416886/-1 416887/-1 416888/-1 416890/-1 416891/-1 416892/-1 416894/-1 416895/-1 416896/-1 416897/-1 416898/-1 416900/-1 416901/-1 416902/-1 416903/-1 416904/-1 416905/-1 416906/-1 416907/-1 416908/-1 416912/-1 416914/-1 416915/-1 416919/-1 416921/-1 416922/-1 416923/-1 416924/-1 416925/-1 416926/-1 416927/-1 416928/-1 416929/-1 416930/-1 416931/-1 416932/-1 416933/-1 416934/-1 416935/-1 416938/-1 416939/-1 416952/-1 416956/-1 416957/-1 416958/-1 416959/-1 416960/-1 416961/-1 416962/-1 416963/-1 416964/-1 416965/-1 416966/-1 416974/-1 416975/-1 416976/-1 416977/-1 416979/-1 417053/-1 417129/-1 417163/-1 438529/-1 447870/-1 447871/-1}} {UK01006 416834/-1}
10/11:18:13:15: /tvbin/TClient:  Hole found in 416834 at 15624
10/11:18:13:15: /tvbin/TClient:  HOLE INFO: stat
10/11:18:13:15: /tvbin/TClient:  HOLE INFO: station=NoNag sId=7999999 lastDay=15624
10/11:18:13:15: /tvbin/TClient:  Station 416834 last day is 15623 (lastDay=15623)
10/11:18:13:15: /tvbin/TClient:  Station 416836 last day is 15632 (lastDay=15623)
10/11:18:13:15: /tvbin/TClient:  Station 416837 last day is 15632 (lastDay=15623)
10/11:18:13:15: /tvbin/TClient:  Station 416838 last day is 15632 (lastDay=15623)
10/11:18:13:15: /tvbin/TClient:  Station 416839 last day is 15632 (lastDay=15623)
10/11:18:13:15: /tvbin/TClient:  Station 416840 last day is 15632 (lastDay=15623)
10/11:18:13:16: /tvbin/TClient:  Station 416841 last day is 15632 (lastDay=15623)
10/11:18:13:16: /tvbin/TClient:  Station 416842 last day is 15632 (lastDay=15623)
10/11:18:13:16: /tvbin/TClient:  Station 416843 last day is 15632 (lastDay=15623)
10/11:18:13:16: /tvbin/TClient:  Station 416844 last day is 15632 (lastDay=15623)
10/11:18:13:16: /tvbin/TClient:  Station 416845 last day is 15632 (lastDay=15623)
10/11:18:13:16: /tvbin/TClient:  Station 416846 last day is 15632 (lastDay=15623)
10/11:18:13:16: /tvbin/TClient:  Station 416847 last day is 15632 (lastDay=15623)
10/11:18:13:16: /tvbin/TClient:  Station 416848 last day is 15632 (lastDay=15623)
10/11:18:13:16: /tvbin/TClient:  Station 416849 last day is 15632 (lastDay=15623)
10/11:18:13:16: /tvbin/TClient:  Station 416850 last day is 15632 (lastDay=15623)
10/11:18:13:16: /tvbin/TClient:  Station 416851 last day is 15632 (lastDay=15623)
10/11:18:13:16: /tvbin/TClient:  Station 416852 last day is 15632 (lastDay=15623)
10/11:18:13:16: /tvbin/TClient:  Station 416853 last day is 15632 (lastDay=15623)
10/11:18:13:17: /tvbin/TClient:  Station 416854 last day is 15632 (lastDay=15623)
10/11:18:13:17: /tvbin/TClient:  Station 416855 last day is 15632 (lastDay=15623)
10/11:18:13:17: /tvbin/TClient:  HOLE INFO: station=ITV1BS sId=7200297 lastDay=15624
10/11:18:13:17: /tvbin/TClient:  Station 416856 last day is 15623 (lastDay=15623)
10/11:18:13:17: /tvbin/TClient:  Station 416857 last day is 15632 (lastDay=15623)
10/11:18:13:17: /tvbin/TClient:  Station 416858 last day is 15632 (lastDay=15623)
10/11:18:13:17: /tvbin/TClient:  Station 416859 last day is 15632 (lastDay=15623)
10/11:18:13:17: /tvbin/TClient:  Station 416860 last day is 15632 (lastDay=15623)
10/11:18:13:17: /tvbin/TClient:  Station 416861 last day is 15632 (lastDay=15623)
10/11:18:13:17: /tvbin/TClient:  Station 416862 last day is 15632 (lastDay=15623)
10/11:18:13:17: /tvbin/TClient:  Station 416863 last day is 15632 (lastDay=15623)
10/11:18:13:17: /tvbin/TClient:  Station 416864 last day is 15632 (lastDay=15623)
10/11:18:13:17: /tvbin/TClient:  Station 416865 last day is 15632 (lastDay=15623)
10/11:18:13:17: /tvbin/TClient:  Station 416866 last day is 15632 (lastDay=15623)
10/11:18:13:17: /tvbin/TClient:  Station 416867 last day is 15632 (lastDay=15623)
10/11:18:13:18: /tvbin/TClient:  Station 416868 last day is 15632 (lastDay=15623)
10/11:18:13:18: /tvbin/TClient:  Station 416869 last day is 15632 (lastDay=15623)
10/11:18:13:18: /tvbin/TClient:  Station 416870 last day is 15632 (lastDay=15623)
10/11:18:13:18: /tvbin/TClient:  Station 416871 last day is 15632 (lastDay=15623)
10/11:18:13:18: /tvbin/TClient:  Station 416872 last day is 15632 (lastDay=15623)
10/11:18:13:18: /tvbin/TClient:  Station 416873 last day is 15632 (lastDay=15623)
10/11:18:13:18: /tvbin/TClient:  Station 416874 last day is 15632 (lastDay=15623)
10/11:18:13:18: /tvbin/TClient:  Station 416875 last day is 15632 (lastDay=15623)
10/11:18:13:18: /tvbin/TClient:  Station 416876 last day is 15632 (lastDay=15623)
10/11:18:13:18: /tvbin/TClient:  Station 416872 last day is 15632 (lastDay=15623)
10/11:18:13:18: /tvbin/TClient:  Station 416877 last day is 15632 (lastDay=15623)
10/11:18:13:18: /tvbin/TClient:  Station 416878 last day is 15632 (lastDay=15623)
10/11:18:13:18: /tvbin/TClient:  Station 416879 last day is 15632 (lastDay=15623)
10/11:18:13:18: /tvbin/TClient:  Station 416880 last day is 15632 (lastDay=15623)
10/11:18:13:19: /tvbin/TClient:  Station 416881 last day is 15632 (lastDay=15623)
10/11:18:13:19: /tvbin/TClient:  Station 416882 last day is 15632 (lastDay=15623)
10/11:18:13:19: /tvbin/TClient:  Station 416883 last day is 15632 (lastDay=15623)
10/11:18:13:19: /tvbin/TClient:  Station 416884 last day is 15632 (lastDay=15623)
10/11:18:13:19: /tvbin/TClient:  Station 416886 last day is 15629 (lastDay=15623)
10/11:18:13:19: /tvbin/TClient:  Station 416887 last day is 15632 (lastDay=15623)
10/11:18:13:19: /tvbin/TClient:  Station 416888 last day is 15632 (lastDay=15623)
10/11:18:13:19: /tvbin/TClient:  Station 416890 last day is 15632 (lastDay=15623)
10/11:18:13:19: /tvbin/TClient:  Station 416891 last day is 15632 (lastDay=15623)
10/11:18:13:19: /tvbin/TClient:  Station 416892 last day is 15632 (lastDay=15623)
10/11:18:13:19: /tvbin/TClient:  Station 416894 last day is 15632 (lastDay=15623)
10/11:18:13:19: /tvbin/TClient:  Station 416895 last day is 15632 (lastDay=15623)
10/11:18:13:19: /tvbin/TClient:  Station 416896 last day is 15632 (lastDay=15623)
10/11:18:13:19: /tvbin/TClient:  Station 416897 last day is 15632 (lastDay=15623)
10/11:18:13:19: /tvbin/TClient:  Station 416898 last day is 15632 (lastDay=15623)
10/11:18:13:20: /tvbin/TClient:  Station 416900 last day is 15632 (lastDay=15623)
10/11:18:13:20: /tvbin/TClient:  Station 416901 last day is 15632 (lastDay=15623)
10/11:18:13:20: /tvbin/TClient:  Station 416902 last day is 15632 (lastDay=15623)
10/11:18:13:20: /tvbin/TClient:  Station 416903 last day is 15632 (lastDay=15623)
10/11:18:13:20: /tvbin/TClient:  Station 416904 last day is 15632 (lastDay=15623)
10/11:18:13:20: /tvbin/TClient:  Station 416905 last day is 15632 (lastDay=15623)
10/11:18:13:20: /tvbin/TClient:  Station 416906 last day is 15632 (lastDay=15623)
10/11:18:13:20: /tvbin/TClient:  Station 416907 last day is 15632 (lastDay=15623)
10/11:18:13:20: /tvbin/TClient:  Station 416908 last day is 15632 (lastDay=15623)
10/11:18:13:20: /tvbin/TClient:  Station 416912 last day is 15632 (lastDay=15623)
10/11:18:13:20: /tvbin/TClient:  Station 416914 last day is 15632 (lastDay=15623)
10/11:18:13:20: /tvbin/TClient:  Stat
10/11:18:13:20: /tvbin/TClient:  Station 416915 last day is 15632 (lastDay=15623)
10/11:18:13:20: /tvbin/TClient:  Station 416919 last day is 15632 (lastDay=15623)
10/11:18:13:20: /tvbin/TClient:  Station 416921 last day is 15632 (lastDay=15623)
10/11:18:13:20: /tvbin/TClient:  Station 416922 last day is 15632 (lastDay=15623)
10/11:18:13:21: /tvbin/TClient:  Station 416923 last day is 15632 (lastDay=15623)
10/11:18:13:21: /tvbin/TClient:  Station 416924 last day is 15632 (lastDay=15623)
10/11:18:13:21: /tvbin/TClient:  Station 416925 last day is 15632 (lastDay=15623)
10/11:18:13:21: /tvbin/TClient:  Station 416926 last day is 15632 (lastDay=15623)
10/11:18:13:21: /tvbin/TClient:  Station 416927 last day is 15632 (lastDay=15623)
10/11:18:13:21: /tvbin/TClient:  Station 416928 last day is 15632 (lastDay=15623)
10/11:18:13:21: /tvbin/TClient:  Station 416929 last day is 15632 (lastDay=15623)
10/11:18:13:21: /tvbin/TClient:  Station 416930 last day is 15632 (lastDay=15623)
10/11:18:13:21: /tvbin/TClient:  Station 416931 last day is 15632 (lastDay=15623)
10/11:18:13:21: /tvbin/TClient:  Station 416932 last day is 15632 (lastDay=15623)
10/11:18:13:21: /tvbin/TClient:  Station 416933 last day is 15629 (lastDay=15623)
10/11:18:13:21: /tvbin/TClient:  Station 416934 last day is 15629 (lastDay=15623)
10/11:18:13:21: /tvbin/TClient:  Station 416935 last day is 15632 (lastDay=15623)
10/11:18:13:21: /tvbin/TClient:  Station 416938 last day is 15632 (lastDay=15623)
10/11:18:13:21: /tvbin/TClient:  Station 416939 last day is 15632 (lastDay=15623)
10/11:18:13:22: /tvbin/TClient:  Station 416952 last day is 15632 (lastDay=15623)
10/11:18:13:22: /tvbin/TClient:  Station 416956 last day is 15630 (lastDay=15623)
10/11:18:13:22: /tvbin/TClient:  Station 416957 last day is 15630 (lastDay=15623)
10/11:18:13:22: /tvbin/TClient:  Station 416958 last day is 15630 (lastDay=15623)
10/11:18:13:22: /tvbin/TClient:  Station 416959 last day is 15629 (lastDay=15623)
10/11:18:13:22: /tvbin/TClient:  Station 416960 last day is 15630 (lastDay=15623)
10/11:18:13:22: /tvbin/TClient:  Station 416961 last day is 15630 (lastDay=15623)
10/11:18:13:22: /tvbin/TClient:  Hole found in 416962 at 15624
10/11:18:13:22: /tvbin/TClient:  HOLE INFO: station=BBC5LX sId=7200062 lastDay=15624
10/11:18:13:22: /tvbin/TClient:  Station 416962 last day is 15623 (lastDay=15623)
10/11:18:13:22: /tvbin/TClient:  Station 416963 last day is 15630 (lastDay=15623)
10/11:18:13:22: /tvbin/TClient:  Station 416964 last day is 15630 (lastDay=15623)
10/11:18:13:22: /tvbin/TClient:  Station 416965 last day is 15630 (lastDay=15623)
10/11:18:13:22: /tvbin/TClient:  Station 416966 last day is 15630 (lastDay=15623)
10/11:18:13:22: /tvbin/TClient:  Station 416974 last day is 15630 (lastDay=15623)
10/11:18:13:22: /tvbin/TClient:  Station 416975 last day is 15629 (lastDay=15623)
10/11:18:13:22: /tvbin/TClient:  Station 416976 last day is 15630 (lastDay=15623)
10/11:18:13:22: /tvbin/TClient:  Station 416977 last day is 15629 (lastDay=15623)
10/11:18:13:23: /tvbin/TClient:  Station 416979 last day is 15629 (lastDay=15623)
10/11:18:13:23: /tvbin/TClient:  Station 417053 last day is 15632 (lastDay=15623)
10/11:18:13:23: /tvbin/TClient:  Station 417129 last day is 15632 (lastDay=15623)
10/11:18:13:23: /tvbin/TClient:  Station 417163 last day is 15632 (lastDay=15623)
10/11:18:13:23: /tvbin/TClient:  Station 438529 last day is 15632 (lastDay=15623)
10/11:18:13:23: /tvbin/TClient:  Station 447870 last day is 15632 (lastDay=15623)
10/11:18:13:23: /tvbin/TClient:  Station 447871 last day is 15632 (lastDay=15623)
10/11:18:13:23: /tvbin/TClient:  Last day of programming data for UK01005 is 15623
10/11:18:13:23: /tvbin/TClient:  retHeadStr = UK01005-15623|
10/11:18:13:23: /tvbin/TClient:  Hole found in 416834 at 15624
10/11:18:13:23: /tvbin/TClient:  HOLE INFO: station=NoNag sId=7999999 lastDay=15624
10/11:18:13:23: /tvbin/TClient:  Station 416834 last day is 15623 (lastDay=15623)
10/11:18:13:23: /tvbin/TClient:  Last day of programming data for UK01006 is 15623
10/11:18:13:23: /tvbin/TClient:  retHeadStr = UK01005-15623|UK01006-15623|
10/11:18:13:23: /tvbin/TClient:  setting up TCD411 block
10/11:18:13:23: /tvbin/TClient:  setting area code:
10/11:18:13:23: /tvbin/TClient:  getCurPhoneNum : dialinprefix = ''
10/11:18:13:23: /tvbin/TClient:  getCurPhoneNum : +dialinareacode = ''
10/11:18:13:23: /tvbin/TClient:  getCurPhoneNum : +dialinnum = ''
10/11:18:13:23: /tvbin/TClient: 
10/11:18:13:23: /tvbin/TClient:       Start TCD411 Request ==================
10/11:18:13:23: /tvbin/TClient:              areaCode:
10/11:18:13:23: /tvbin/TClient:                prefix: {}
10/11:18:13:23: /tvbin/TClient:        dialInAreaCode: {}
10/11:18:13:23: /tvbin/TClient:              curPhNum:
10/11:18:13:23: /tvbin/TClient:                objVer:
10/11:18:13:23: /tvbin/TClient:                 tcdId: 0230000601E875C
10/11:18:13:23: /tvbin/TClient:                callId: 1349979150
10/11:18:13:23: /tvbin/TClient:            dialPrefix:
10/11:18:13:23: /tvbin/TClient:         dialToneCheck:
10/11:18:13:23: /tvbin/TClient:         offHookDetect:
10/11:18:13:23: /tvbin/TClient:         tonePulseDial: P
10/11:18:13:23: /tvbin/TClient:        callWaitPrefix: ,1234567,0721#
10/11:18:13:23: /tvbin/TClient:          tollFreeAuth: 1
10/11:18:13:23: /tvbin/TClient:              callType: TS_SR_ACCEPTED
10/11:18:13:23: /tvbin/TClient:             swVerName: 2.5.5-01-1-023
10/11:18:13:23: /tvbin/TClient:         End TCD411 Request ==================
10/11:18:13:23: /tvbin/TClient: 
10/11:18:13:23: /tvbin/TClient:   Start Ident     =====================
10/11:18:13:23: /tvbin/TClient:              version: 3
10/11:18:13:23: /tvbin/TClient:             centerID: 0230000601E875C
10/11:18:13:23: /tvbin/TClient:           reasonCode: 1
10/11:18:13:23: /tvbin/TClient:         softwareDesc: 468089-51|468071-1|468073-1|468075-1|468077-1|468079-1|468081-1|468083-1|468085-1|468087-1|468090-1|468091-1|468092-1|468093-1|468094-1|468095-1|468096-1|468097-1|468098-1|468099-1|468100-1|468101-1|468102-1|468103-1|468104-1|468105-1|468106-1|468107-1|468108-1|468109-1|468110-1|468111-1|468112-1|
10/11:18:13:23: /tvbin/TClient:         softwareDesc: 468089-51|468071-1|468073-1|468075-1|468077-1|468079-1|468081-1|468083-1|468085-1|468087-1|468090-1|468091-1|468092-1|468093-1|468094-1|468095-1|468096-1|468097-1|468098-1|468099-1|468100-1|468101-1|468102-1|468103-1|468104-1|468105-1|468106-1|468107-1|468108-1|468109-1|468110-1|468111-1|468112-1|468113-1|468114-1|468115-1|468116-1|468117-1|468118-1|468119-1|468120-1|468121-1|468122-1|468123-1|468124-1|468125-1|468127-1|468128-1|468129-1|468130-1|468131-1|468132-1|468133-1|468134-1|468135-1|468136-1|468137-1|468138-1|468139-1|24252-77|24264-362|387715-4|61464-40|24273-54|24294-76|427608-4|24306-72|24337-54|24352-638|24358-36|24380-12|
10/11:18:13:23: /tvbin/TClient:           locationID: 01000-30
10/11:18:13:23: /tvbin/TClient:       sequenceCookie: 12345678
10/11:18:13:23: /tvbin/TClient:            headendID: UK01005-15623|UK01006-15623|
10/11:18:13:23: /tvbin/TClient:         showcaseDesc: showcase0-0
10/11:18:13:23: /tvbin/TClient:        inventoryFile:
10/11:18:13:23: /tvbin/TClient:         waitingCount: 0
10/11:18:13:23: /tvbin/TClient:           dialConfig: 005
10/11:18:13:23: /tvbin/TClient:             confInfo: 08450800300:127.0.0.1:8000::
10/11:18:13:23: /tvbin/TClient:          messageDesc: 20000002-4|
10/11:18:13:23: /tvbin/TClient:          irdbVersion: 317
10/11:18:13:23: /tvbin/TClient:         genreVersion:
10/11:18:13:23: /tvbin/TClient:          logoVersion:
10/11:18:13:23: /tvbin/TClient:   affiliationVersion:
10/11:18:13:23: /tvbin/TClient:      showcaseVersion:
10/11:18:13:23: /tvbin/TClient:            swVerName: 2.5.5-01-1-023
10/11:18:13:23: /tvbin/TClient:  configParameterList: zip=01000,dar=,rcq=,tz=7,as=,tun=,suc=7
10/11:18:13:23: /tvbin/TClient:  sourceParameterList: st=5,con=7,drm=,ekr=,ccn=20034,brn=SONY,lin=1,irs=150;st=1,con=1,drm=,ekr=,ccn=,brn=,lin=16,irs=
10/11:18:13:23: /tvbin/TClient:              apgOnly:
10/11:18:13:23: /tvbin/TClient:           useChksums: TRUE
10/11:18:13:23: /tvbin/TClient:     premiumShowcases:
10/11:18:13:23: /tvbin/TClient:      captureRequests:
10/11:18:13:23: /tvbin/TClient:            menuItems:
10/11:18:13:23: /tvbin/TClient:        otherDataSets: HDGenre-4|RM_cleanTvShow-|
10/11:18:13:23: /tvbin/TClient:        rbBackgrounds:
10/11:18:13:23: /tvbin/TClient:        dataGroupList:
10/11:18:13:23: /tvbin/TClient:   lstAvalancheDnload: 0,0 0,0
10/11:18:13:23: /tvbin/TClient:        userInitiated: 1
10/11:18:13:23: /tvbin/TClient:  altEPGClientVersion: altepg1.0d
10/11:18:13:23: /tvbin/TClient:         nicInstalled: MODEM
10/11:18:13:23: /tvbin/TClient:                hdaId: S088J10YA15494
10/11:18:13:23: /tvbin/TClient:                hdbId: Unknown
10/11:18:13:23: /tvbin/TClient:             hdaModel: SAMSUNG SP2014N                         
10/11:18:13:23: /tvbin/TClient:             hdbModel:
10/11:18:13:23: /tvbin/TClient:  End Ident        =====================
10/11:18:13:23: /tvbin/TClient: 
10/11:18:13:23: /tvbin/TClient:  Logging camid.
10/11:18:13:23: /tvbin/TClient:  CAM_ID not found.
10/11:18:13:23: /tvbin/TClient:  Ird Id.
10/11:18:13:23: /tvbin/TClient:  useModem: dialPrefix not set, probing network...
10/11:18:13:23: /tvbin/TClient:  useModem: no network found  - using dialup modem
10/11:18:13:23: /tvbin/TClient:    toneOrPulse = 0
10/11:18:13:23: /tvbin/TClient:    dialPrefix = {}
10/11:18:13:23: /tvbin/TClient:    callWaitingPrefix == ,1234567,0721#
10/11:18:13:23: /tvbin/TClient:    realCallWaitingPrefix ==
10/11:18:13:23: /tvbin/TClient:    phoneNumber = 08450800300
10/11:18:13:23: /tvbin/TClient:    phoneAvailableDetection = 1
10/11:18:13:23: /tvbin/TClient:    dialToneDetection = 0
10/11:18:13:23: /tvbin/TClient:  Starting dial.expect with:
10/11:18:13:23: /tvbin/TClient:    toneOrPulse = T
10/11:18:13:23: /tvbin/TClient:    dialPrefix = {}
10/11:18:13:23: /tvbin/TClient:    callWaitingPrefix = ,1234567,0721#
10/11:18:13:23: /tvbin/TClient:    realCallWaitingPrefix ==
10/11:18:13:24: /tvbin/TClient:    phoneNumber = 08450800300
10/11:18:13:24: /tvbin/TClient:    phoneAvailableDetection = 0
10/11:18:13:24: /tvbin/TClient:    dialToneDetection = 1
10/11:18:13:24: /tvbin/TClient:    useV34 = 0
10/11:18:13:24: /tvbin/TClient:  updateStatus: In Progress CL| 30 24
10/11:18:13:24: /tvbin/TClient:  SendDialupEvent 30 9 CL|30
10/11:18:13:55: /tvbin/TClient:  Whole result is spawn /tvbin/modemtest -expect
ATZ
ATZ

OK
Checking for modem type...
ATI3

P2109-V90

OK
Modem type is 2109
*****NEW***** modem
ATQ0

OK
ATS0=0

OK
AT+GCI=B4

OK
AT-STE=2

OK
ATW2S6=8S7=50S11=100%C0&D2+MS=V34

OK
ATW1X4

OK
AT-TTE=1500,200,500

OK
Current line voltage (in volts, of course!):
AT-TRV

48.97
OK
new modem...line status interrupt disabled
ATDT08450800300

+MCR: V34

+MRR: 28800,33600

+ER: LAPM

CONNECT 57600
Sending a carriage return
Expecting ogin: or ame:


login:
login: Got ogin:
Sending 0230000601E875C.1349979150@tivo.net
Expecting sword:
0230000601E875C.1349979150@tivo.net
Password: Got sword:
Sending password
dialcode is:OK
10/11:18:13:55: /tvbin/TClient:  updateStatus: In Progress CL| 32 12
10/11:18:13:55: /tvbin/TClient:  SendDialupEvent 30 9 CL|32
10/11:18:13:55: /tvbin/TClient:  Starting pppd, code=OK
10/11:18:13:55: /tvbin/TClient:  updateStatus: In Progress ST| 33 13
10/11:18:13:55: /tvbin/TClient:  SendDialupEvent 30 9 ST|33
10/11:18:13:56: /tvbin/TClient:  waiting for PPP - 1
10/11:18:13:59: /tvbin/TClient:  updateStatus: In Progress ST| 33 14
10/11:18:13:59: /tvbin/TClient:  SendDialupEvent 30 9 ST|33
10/11:18:13:59: /tvbin/TClient:  About to connect to 127.0.0.1:8000
10/11:18:13:59: /tvbin/TClient:  Executing HTTP command: /tvbin/http_post.bash /var/log/svclog http://127.0.0.1:8000/tivo-service/mlog.cgi OFF OFF ON
10/11:18:14:00: /tvbin/TClient:  about to do TCD411 Call
10/11:18:14:00: /tvbin/TClient:  Executing HTTP command (10): /tvbin/tclient_post 127.0.0.1:8000 /var/tmp/TCD411.send /var/tmp/TCD411.recv 5 ON
10/11:18:14:05: /tvbin/TClient:  http POST command failed:  timeout waiting to read
10/11:18:14:05: /tvbin/TClient:  Executing HTTP command (9): /tvbin/tclient_post 127.0.0.1:8000 /var/tmp/TCD411.send /var/tmp/TCD411.recv 5 ON
10/11:18:14:11: /tvbin/TClient:  http POST command failed:  timeout waiting to read
10/11:18:14:11: /tvbin/TClient:  Executing HTTP command (8): /tvbin/tclient_post 127.0.0.1:8000 /var/tmp/TCD411.send /var/tmp/TCD411.recv 5 ON
10/11:18:14:16: /tvbin/TClient:  http POST command failed:  timeout waiti
10/11:18:14:16: /tvbin/TClient:  http POST command failed:  timeout waiting to read
10/11:18:14:16: /tvbin/TClient:  Executing HTTP command (7): /tvbin/tclient_post 127.0.0.1:8000 /var/tmp/TCD411.send /var/tmp/TCD411.recv 5 ON
10/11:18:14:21: /tvbin/TClient:  http POST command failed:  timeout waiting to read
10/11:18:14:21: /tvbin/TClient:  Executing HTTP command (6): /tvbin/tclient_post 127.0.0.1:8000 /var/tmp/TCD411.send /var/tmp/TCD411.recv 5 ON
10/11:18:14:26: /tvbin/TClient:  http POST command failed:  timeout waiting to read
10/11:18:14:26: /tvbin/TClient:  Executing HTTP command (5): /tvbin/tclient_post 127.0.0.1:8000 /var/tmp/TCD411.send /var/tmp/TCD411.recv 5 ON
10/11:18:14:31: /tvbin/TClient:  http POST command failed:  timeout waiting to read
10/11:18:14:31: /tvbin/TClient:  Executing HTTP command (4): /tvbin/tclient_post 127.0.0.1:8000 /var/tmp/TCD411.send /var/tmp/TCD411.recv 5 ON
10/11:18:14:36: /tvbin/TClient:  http POST command failed:  connect failed, reason = Connection timed out
10/11:18:14:36: /tvbin/TClient:  Executing HTTP command (3): /tvbin/tclient_post 127.0.0.1:8000 /var/tmp/TCD411.send /var/tmp/TCD411.recv 5 ON
10/11:18:14:41: /tvbin/TClient:  http POST command failed:  connect failed, reason = Connection timed out
10/11:18:14:41: /tvbin/TClient:  Executing HTTP command (2): /tvbin/tclient_post 127.0.0.1:8000 /var/tmp/TCD411.send /var/tmp/TCD411.recv 5 ON
10/11:18:14:47: /tvbin/TClient:  http POST command failed:  connect failed, reason = Connection timed out
10/11:18:14:47: /tvbin/TClient:  Executing HTTP command (1): /tvbin/tclient_post 127.0.0.1:8000 /var/tmp/TCD411.send /var/tmp/TCD411.recv 5 ON
10/11:18:14:52: /tvbin/TClient:  http POST command failed:  connect failed, reason = Connection timed out
10/11:18:14:52: /tvbin/TClient:  doHttpCall returned: 0
10/11:18:14:52: /tvbin/TClient:  Connect/POST has failed, we've warned the user, set status to Failed
10/11:18:14:52: /tvbin/TClient:  failed connect - aborting
10/11:18:14:52: /tvbin/TClient:  Will kill pppd
10/11:18:14:52: /tvbin/TClient:  Killing (pppd).
10/11:18:14:57: /tvbin/TClient:  updateStatus: Failed ST| 33 14
Saving 'ST|14' to result file
10/11:18:14:57: /tvbin/TClient:  writing Failed to LastCallStatus
10/11:18:14:57: /tvbin/TClient:  SendDialupEvent 30 9 EX|14
10/11:18:14:58: /tvbin/TClient:  Creating Dialup Message...
10/11:18:14:58: /tvbin/TClient:  Calling event send 23 DATA_MESSAGES 0
10/11:18:14:58: /tvbin/TClient:  TClient login: 1
10/11:18:14:58: /tvbin/TClient:  TClient backhaulDone: 0
10/11:18:16:08: /tvbin/TClient:  inside TClient
10/11:18:16:09: /tvbin/TClient:  No previously downloaded files remain in /var/packages
10/11:18:16:09: /tvbin/TClient:  TClient: invoking init w/argv=-t -backup
10/11:18:16:09: /tvbin/TClient:  TClient: TClient-lib version altepg1.0d
10/11:18:16:09: /tvbin/TClient:  writing In Progress to LastCallStatus
10/11:18:16:09: /tvbin/TClient:  deferCall: special callWait prefix set - changing netcard config (won't call)
10/11:18:16:09: /tvbin/TClient:  calling changeNetcard with code=2 ip= gateway= netmask=
10/11:18:16:09: /tvbin/TClient:  changeNetcard: changing to 'PPPonDSS' (code=2)
10/11:18:16:10: /tvbin/TClient:  changeNetCard:nic set to PPPonDSS in /etc/oztivo.conf
10/11:18:16:10: /tvbin/TClient:  Calling event send 23 DATA_MESSAGES 0
10/11:18:16:10: /tvbin/TClient:  TClient init: 0
10/11:18:16:10: /tvbin/TClient:  dial config code: (005) found
10/11:18:16:10: /tvbin/TClient:  matched 005, returning value = 08450800300:127.0.0.1:8000::
10/11:18:16:10: /tvbin/TClient:  updateStatus: In Progress EX| 29 48
10/11:18:16:10: /tvbin/TClient:  writing In Progress to LastCallStatus
10/11:18:16:10: /tvbin/TClient:  SendDialupEvent 30 9 EX|29
10/11:18:16:11: /tvbin/TClient:  Host = 127.0.0.1
10/11:18:16:11: /tvbin/TClient:  Port = 8000
10/11:18:16:11: /tvbin/TClient:  Phone = 08450800300
10/11:18:16:11: /tvbin/TClient:  updateStatus: In Progress EX| 29 50
10/11:18:16:11: /tvbin/TClient:  SendDialupEvent 30 9 EX|29
10/11:18:16:11: /tvbin/TClient:  Network changed. Status => Failed, Phase => EX| 29 50
10/11:18:16:11: /tvbin/TClient:  updateStatus: In Progress EX| 29 11
10/11:18:16:11: /tvbin/TClient:  SendDialupEvent 30 9 EX|29
10/11:18:16:16: /tvbin/TClient:  updateStatus: Failed EX| 29 11
Saving 'EX|11' to result file
10/11:18:16:16: /tvbin/TClient:  writing Failed to LastCallStatus
retrying after errTmBackgroundHoldoff ...
10/11:18:16:19: /tvbin/TClient:  writing Failed to LastCallStatus
10/11:18:16:19: /tvbin/TClient:  SendDialupEvent 30 9 EX|11
10/11:18:16:19: /tvbin/TClient:  TClient login: 1
10/11:18:16:19: /tvbin/TClient:  TClient backhaulDone: 0

DX30
Valued Contributor
Valued Contributor
 
Posts: 645
Joined: Thu May 19, 2011 2:36 pm

Re: Dialup Reliability Improvement

Postby millsb » Thu Oct 11, 2012 11:02 pm

Thanks for all that - lots of useful information there. I didn't expect the serial-ppp to behave so badly (I can see lots of failed attempts in the server logs), so I will take a look at that first.
For dialup it looks like you got a duff connection (two attempts - first one didn't even complete call set-up properly). I'd ask you to try that again but probably better if I get a better understanding of why serial-ppp isn't reliable before you do that.
millsb
AltEPG Team
AltEPG Team
 
Posts: 974
Joined: Sat Mar 05, 2011 11:16 am

Re: Dialup Reliability Improvement

Postby healeydave » Mon Oct 22, 2012 10:02 am

I have a customers TiVo here (in for upgrade) that has been on test for a week now.
Its bog standard AltEPG 1.0d with (no dial prefixes set) and has no NIC, so is using dial-up.
Its generally dialling in ok, but during this period, it has reported two daily call failures on the 0845 number.
Its automatically using both the 0845 and the 0161 numbers as options for connecting to AltEPG, so I assume that fact that the last calls have been successful and the guide is up-to-date that its attempted the 0161 and got through successfully.

Brian, is it worth me putting this patch on to get another unit testing it out?

I guess it might not be a good idea if the patch is having an adverse affect on DUN reliability but if thats only on serial-ppp and standard DUN connections are working better I could install before returning to the customer!
Keeping the dream alive.
healeydave
AltEPG Team
AltEPG Team
 
Posts: 921
Joined: Mon Mar 20, 2006 7:42 pm
Location: Worcester


Return to General

Who is online

Users browsing this forum: No registered users and 78 guests