[cisco-voip] 79X1's over VPN fail to register after upgrade from 6.1(2) to 7.1(2a)

Mon Jul 27 15:41:44 EDT 2009

Upgrade over the weekend to 7.1(2a).  79X1's were registered fine prior to
the upgrade but now do not.  79X1's on the local network register fine and I
brought one of mine from home to the office that wasn't work and it came up
fine.  The phone gets the correct UCM IPs but just cycles between them. Any
ideas?

Here is an excerpt from the console logs:

NOT 20:01:39.076161 DHCP6: sockTos = 0x60
WRN 20:01:39.114337 SECD: WARN:getCTLInfo: ** phone has no CTL
WRN 20:01:39.121390 SECD: WARN:getCTLInfo: ** phone has no CTL
NOT 20:01:39.136470 DNS: SIGHUP received...
NOT 20:01:39.148990 CDP-D: catchipcfg:getdhcpinfo IP:ae04565
domain:cna.comchngVal:1
NOT 20:01:39.156534 CDP-D: set pc vvlan access --> 26
NOT 20:01:39.181990 tftpClient: request server 0 ---> 10.12.144.55
ERR 20:01:39.183451 RTSOLD: opvvlan:4095->4095 advvlan:4096->4096
ERR 20:01:39.192628 RTSOLD: LINK -> LINK
NOT 20:01:39.217298 tftpClient: request server 1 ---> 10.18.144.55
NOT 20:01:39.238829 tftpClient: request server 0 ---> 10.12.144.55
NOT 20:01:39.244675 ESP: server 0 = 10.12.144.55
NOT 20:01:39.268742 tftpClient: request server 1 ---> 10.18.144.55
NOT 20:01:39.272352 ESP: server 1 = 10.18.144.55
NOT 20:01:39.287405 tftpClient: request server6 0 ---> ::
NOT 20:01:39.295180 ESP: server 2 = ::
NOT 20:01:39.337945 tftpClient: request server6 1 ---> ::
NOT 20:01:39.339561 ESP: server 3 = ::
NOT 20:01:39.388554 tftpClient: request server6 0 ---> ::
NOT 20:01:39.398619 tftpClient: request server6 1 ---> ::
WRN 20:02:38.907566 JVM: Startup Module Loader|cip.sccp.dj:? - [CmgrSm 0]
Locked out: 3 retries...
WRN 20:02:39.197123 JVM: Startup Module Loader|cip.sccp.ck:? - Read
exception: java.io.EOFException
Close(d) Connection ...
ERR 20:02:39.206966 JVM: 8:02:39p|java.io.EOFException
at java.io.DataInputStream.readInt()I(Unknown Source)
at cip.io.i.readInt()I(Unknown Source)
at cip.sccp.av.a()Lcip/sccp/br;(Unknown Source)
at cip.sccp.ck.e()V(Unknown Source)
at cip.sys.l.run()V(Unknown Source)
at java.lang.Thread.startup(Z)V(Unknown Source)
NOT 20:12:29.361204 SYSMSG: pid 26 (/bin/sh) Normal Exit, status = 127
INF 20:12:29.361276           runtime = 962.830 secs

INF 20:12:29.361316          user cpu = 0.036605859 secs

INF 20:12:29.361356        system cpu = 0.245709561 secs

INF 20:12:29.361391    child user cpu = 0.007422818 secs

INF 20:12:29.361424     child sys cpu = 0.097004205 secs

INF 20:12:29.361470    sys interrupts = 7.370375323 secs for 99901
interrupts

INF 20:12:29.361511 total cpu = 0.387242443 secs ( 0% utilization )

INF 20:12:29.386959 dropbear[19]:ssh_getpwnam: Found Config entry for
caa9387
INF 20:12:29.388478 dropbear[19]:exit after auth (caa9387): Exited normally
WRN 20:13:39.945089 JVM: Startup Module Loader|cip.sccp.ck:? - Read
exception: java.io.EOFException
Close(d) Connection ...
ERR 20:13:39.954260 JVM: 8:13:39p|java.io.EOFException
at java.io.DataInputStream.readInt()I(Unknown Source)
at cip.io.i.readInt()I(Unknown Source)
at cip.sccp.av.a()Lcip/sccp/br;(Unknown Source)
at cip.sccp.ck.e()V(Unknown Source)
at cip.sys.l.run()V(Unknown Source)
at java.lang.Thread.startup(Z)V(Unknown Source)
NOT 20:13:39.956874 JVM: Startup Module Loader|cip.cfg.r:? - Requesting
CONFIG file from TFTP Service(1)
ERR 20:13:40.125435 JVM: tftpClient SEP0017E0355A73.cnf.xml
/usr/ram/SEP0017E0355A73.cnf.xml 350001 1
NOT 20:13:40.135791 tftpClient: tftp request rcv'd from /usr/tmp/tftp,
srcFile = SEP0017E0355A73.cnf.xml, dstFile =
/usr/ram/SEP0017E0355A73.cnf.xml max size = 350001
NOT 20:13:40.139797 tftpClient: auth server - tftpList[0] =
::ffff:10.12.144.55
NOT 20:13:40.141499 tftpClient: look up server - 0
WRN 20:13:40.144707 SECD: WARN:lookupCTL: ** no CTL, assume TFTP NONSECURE
NOT 20:13:40.148403 tftpClient: secVal = 0xa
NOT 20:13:40.149365 tftpClient: ::ffff:10.12.144.55 is a NONsecure server
NOT 20:13:40.150285 tftpClient: look up server - 1
WRN 20:13:40.153169 SECD: WARN:lookupCTL: ** no CTL, assume TFTP NONSECURE
NOT 20:13:40.156651 tftpClient: secVal = 0xa
NOT 20:13:40.157615 tftpClient: ::ffff:10.18.144.55 is a NONsecure server
NOT 20:13:40.158489 tftpClient: temp retval = SRVR_NONSECURE, keep looking
NOT 20:13:40.159276 tftpClient: temp retval = SRVR_NONSECURE, keep looking
NOT 20:13:40.174582 tftpClient: retval = 10
NOT 20:13:40.175470 tftpClient: Secure file requested
NOT 20:13:40.176241 tftpClient: Non secure file approved  --
SEP0017E0355A73.cnf.xml
NOT 20:13:40.196857 TFTP: [4]:Requesting SEP0017E0355A73.cnf.xml from
10.12.144.55 with size limit of 350001
NOT 20:13:40.393255 TFTP: [4]:Finished --> rcvd 7563 bytes
WRN 20:13:40.407561 SECD: WARN:lookupCTL: ** no CTL, assume TFTP NONSECURE
NOT 20:13:41.353500 JVM: Startup Module Loader|cip.cfg.r:? - Config
handleTftpResponse, status=0 for file=ram/SEP0017E0355A73.cnf.xml
WRN 20:13:41.354907 JVM: Startup Module Loader|cip.xml.ao:parse - Encoding
Updated to UTF-8
WRN 20:13:41.356353 JVM: Startup Module Loader|cip.xml.ao:  - XML Parser
Warning: Unknown element 'name' in element '/device/devicePool' (line=12)
WRN 20:13:41.357825 JVM: Startup Module Loader|cip.xml.ao:  - XML Parser
Warning: Unknown element 'name' in element
'/device/devicePool/dateTimeSetting' (line=14)
WRN 20:13:41.359317 JVM: Startup Module Loader|cip.xml.ao:  - XML Parser
Warning: Unknown element 'name' in element
'/device/devicePool/callManagerGroup' (line=25)
WRN 20:13:41.360894 JVM: Startup Module Loader|cip.xml.ao:  - XML Parser
Warning: Unknown element 'tftpDefault' in element
'/device/devicePool/callManagerGroup' (line=26)
WRN 20:13:41.362493 JVM: Startup Module Loader|cip.xml.ao:  - XML Parser
Warning: Unknown element 'mgcpPorts' in element
'/device/devicePool/callManagerGroup/members/member/callManager/ports'
(line=36)
WRN 20:13:41.364018 JVM: Startup Module Loader|cip.xml.ao:  - XML Parser
Warning: Unknown element 'mgcpPorts' in element
'/device/devicePool/callManagerGroup/members/member/callManager/ports'
(line=52)
WRN 20:13:41.365519 JVM: Startup Module Loader|cip.xml.ao:  - XML Parser
Warning: Unknown element 'name' in element '/device/devicePool/srstInfo'
(line=63)
WRN 20:13:41.366996 JVM: Startup Module Loader|cip.xml.ao:  - XML Parser
Warning: Unknown element 'userModifiable' in element
'/device/devicePool/srstInfo' (line=65)
WRN 20:13:41.368482 JVM: Startup Module Loader|cip.xml.ao:  - XML Parser
Warning: Unknown element 'mlppDomainId' in element '/device/devicePool'
(line=80)
WRN 20:13:41.369955 JVM: Startup Module Loader|cip.xml.ao:  - XML Parser
Warning: Unknown element 'mlppIndicationStatus' in element
'/device/devicePool' (line=81)
NOT 20:13:41.414256 INETD: Set IP mode 1
NOT 20:13:41.414567 INETD: Requestted IP mode is same as current mode
NOT 20:13:41.385080 SECD: clearTFTPList: cleared all TFTP entries
WRN 20:13:41.372191 JVM: Startup Module Loader|cip.xml.ao:  - XML Parser
Warning: Unknown element 'preemption' in element '/device/devicePool'
(line=82)
WRN 20:13:41.373645 JVM: Startup Module Loader|cip.xml.ao:  - XML Parser
Warning: Unknown element 'uid' in element '/device/networkLocaleInfo'
(line=105)
WRN 20:13:41.375075 JVM: Startup Module Loader|cip.xml.ao:  - XML Parser
Warning: Unknown element 'mobility' in element '/device' (line=139)
NOT 20:13:41.493244 CDP-D: cdpSetRepeater 11
NOT 20:13:41.533714 PAE: SIGIPCFG received...
NOT 20:13:41.535334 ESP: send ADMIN, logging = 1, shell = 0, ipconfig = 1
DBG 20:13:41.756967 LCD: Turn OFF backlight
DBG 20:13:41.758629 LCD: Turn ON backlight
NOT 20:13:42.820564 SECD: setSecMode: sec mode set to NONE (was NONE)
NOT 20:13:44.243252 SECD: clearSRSTList: cleared all SRST entries
WRN 20:13:44.669480 SECD: WARN:cancelCapfOp: CAPF not in use, user cancel
ignored
NOT 20:13:44.670616 SECD: clearCapfList: CAPF table cleared
ERR 20:13:44.679849 SECD: EROR:addCapfEntry: phone has no CTL, can't use
CAPF
NOT 20:13:44.724153 JVM: Startup Module Loader|cip.cfg.r:? - CUCM in config
file: #0 XmlCallAgentObject: IPv4-name=[10.18.144.51] IPv6-name=[] port=2000
priority=0
NOT 20:13:44.726296 JVM: Startup Module Loader|cip.cfg.r:? - CUCM in config
file: #1 XmlCallAgentObject: IPv4-name=[10.12.144.51] IPv6-name=[] port=2000
priority=1
NOT 20:13:44.728382 JVM: Startup Module Loader|cip.cfg.r:? - CUCM in config
file: #2 XmlCallAgentObject: IPv4-name=[] IPv6-name=[] port=0 priority=32767
NOT 20:13:44.734306 JVM: Startup Module Loader|cip.cfg.r:? - CUCM in config
file: #3 XmlCallAgentObject: IPv4-name=[] IPv6-name=[] port=0 priority=32767
NOT 20:13:44.736422 JVM: Startup Module Loader|cip.cfg.r:? - CUCM in config
file: #4 XmlCallAgentObject: IPv4-name=[] IPv6-name=[] port=0 priority=32767
ERR 20:13:44.740819 JVM: Startup Module Loader|cip.sec.CapfProperty:? -
Failed to resolve Capf Ipv6 Address with hostname
NOT 20:13:44.744217 JVM: Startup Module Loader|cip.cfg.r:? - Config
processConfigNoError() result code=CONFIG_FILE_NO_CHANGE
NOT 20:13:44.748010 SECD: setSecMode: sec mode set to NONE (was NONE)
INF 20:13:44.857746 no buffer to recve, force EHOSTDOWN
NOT 20:13:45.094557 JVM: Startup Module Loader - Deletion of file
Successful/usr/ram/SEP0017E0355A73.cnf.xml
NOT 20:13:45.096648 JVM: Startup Module Loader|cip.cfg.r:? - DELETE
ConfigFile:(ram/SEP0017E0355A73.cnf.xml)WAS SUCCESSFUL
NOT 20:13:45.098720 JVM: Startup Module Loader|cip.cfg.ConfigManager:? -
ConfigManager PropertyChanged: device.config.io.dscp.config
WRN 20:13:45.169477 SECD: WARN:lookupCTL: ** no CTL, assume UCM NONSECURE
WRN 20:13:45.343917 SECD: WARN:lookupSRST: no CTL, treat SRST as non-secure
NOT 20:13:45.896475 DHCP6: sockTos = 0x60

Thanks

Mike
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://puck.nether.net/pipermail/cisco-voip/attachments/20090727/a8cc2c8d/attachment.html>