[cisco-voip] SRST 9.1 and 6961 with latest firmware

Anthony Kouloglou akoul at dataways.gr
Thu Jan 2 10:27:23 EST 2014


Here are the console logs,
i realy can't see anything.
Can you?
wan outage at 08:54
srst registration at 08:57

BR
Anthony

Στις 2/1/2014 5:22 μμ, ο/η Brian Meade (brmeade) έγραψε:
>
> Anthony,
>
> It’s possible the DNS timeout is causing additional delay. Console log 
> should show that though.
>
> Thanks,
>
> Brian Meade
>
> *From:*Anthony Kouloglou [mailto:akoul at dataways.gr]
> *Sent:* Thursday, January 02, 2014 10:21 AM
> *To:* Brian Meade (brmeade); cisco-voip at puck-nether.net
> *Subject:* Re: [cisco-voip] SRST 9.1 and 6961 with latest firmware
>
> Brian,
> i cannot see anything suspicious at the log.
> I am using dns name for ccms and it is sure that when the wan is out, 
> dns is not accessible.
> Could this be the reason?
>
> BR
> Anthony
>
> Στις 2/1/2014 5:13 μμ, ο/η Brian Meade (brmeade) έγραψε:
>
>     Anthony,
>
>     Take a look at the console logs to see if anything is causing a delay.
>
>     The SRST option will never display any sort of status indication
>     as the phone doesn’t maintain a backup registration with the SRST
>     router.  It just fails over to that option if all the CM’s are down.
>
>     Brian
>
>     *From:*Anthony Kouloglou [mailto:akoul at dataways.gr]
>     *Sent:* Thursday, January 02, 2014 10:05 AM
>     *To:* Brian Meade (brmeade); cisco-voip at puck-nether.net
>     <mailto:cisco-voip at puck-nether.net>
>     *Subject:* Re: [cisco-voip] SRST 9.1 and 6961 with latest firmware
>
>     Well,
>     i have upgraded to 9.4.1.3 and it worked!
>     But i have to wait almost 2 and a half minutes! I thought with the
>     default settings for keepelives, in 90 seconds it should register!
>     I have never waited more than 2 minutes...
>     Sorry for that :-[
>     At the web page though, the 3rd option (srst) displays only the IP
>     of the srst with no indication if it is ok or not.
>
>     BR
>     Anthony
>
>     Στις 2/1/2014 3:32 μμ, ο/η Anthony Kouloglou έγραψε:
>
>         Hi Brian,
>         i have dowloaded the xml file for the 9.1.1sr1 phoneload.
>         There it is clearly stated the name of the SRST and it's IP
>         address.
>         The srst does not show on the phone's web page but it gets
>         registered to it when there is a WAN outage.
>         I will upgrade and see the xml file and the packet/console
>         logs for 9.4.1.
>         Just one last question: must the srst be shown as srst in
>         parenthesis () when everything is ok?
>         for example, primary and secondary ccms are always shown as
>         (active) and (standby).
>
>         BR
>         Anthony
>
>         Anthony,
>
>             The phone console logs and a packet capture on the phone
>             side will probably help with determining why the phone
>             isn’t registering with the SRST router.
>
>             On the old firmware, there was a bug where the SRST
>             address didn’t properly show up.  Having trouble finding
>             it though.
>
>             Brian
>
>             *From:*cisco-voip
>             [mailto:cisco-voip-bounces at puck.nether.net] *On Behalf Of
>             *Anthony Kouloglou
>             *Sent:* Wednesday, January 01, 2014 11:26 AM
>             *To:* cisco-voip at puck-nether.net
>             <mailto:cisco-voip at puck-nether.net>
>             *Subject:* [cisco-voip] SRST 9.1 and 6961 with latest firmware
>
>             Hi all,
>             i wish you a happy new year!
>             I have an 6961, running the latest 9.4.1 firmware which
>             registers on CUCM 9.1.
>             It is at a remote site which has an 881v where
>             call-manager-fallback is configured (SRST 9.1)
>             Although it gets the srst as a third option after the
>             Publisher and subscriber, when the wan connection to the
>             main site is off, it does not even try to get registered!
>             (i have debugged ephone registration)
>             I have downgraded to 9.3 and 9.2 and still nothing.
>             Finally, when i downgraded to 9.1.1sr1 it started to get
>             register to the SRST.
>             Funny thing is that web page of the phone does not report
>             the srst after the 2 ccms!
>             Any ideas would be appreciated!
>
>             BR
>             Anthony
>

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://puck.nether.net/pipermail/cisco-voip/attachments/20140102/e74ff924/attachment.html>
-------------- next part --------------
Adding 24168 symbols for standalone.


]]]]]]]]]]]]]]]]]]]]]]]]]]]]]]]]]]]]]]]]
]]]]]]]]]]]]]]]]]]]]]]]]]]]]]]]]]]]]]]]
]]]]]]]]]]]]]]]]]]]]]]]]]]]]]]]]]]]]]]
]]]]]]]]]]] ]]]] ]]]]]]]]]] ]] ]]]] (R)
] ]]]]]]]]] ]]]]]] ]]]]]]]] ]] ]]]]
]] ]]]]]]] ]]]]]]]] ]]]]]] ] ]] ]]]]
]]] ]]]]] ] ]]] ] ]]]] ]]] ]]]]]]]]] ]]]] ]] ]]]] ]] ]]]]]
]]]] ]]] ]] ] ]]] ]] ]]]]] ]]]]]] ]] ]]]]]]] ]]]] ]] ]]]]
]]]]] ] ]]]] ]]]]] ]]]]]]]] ]]]] ]] ]]]] ]]]]]]] ]]]]
]]]]]] ]]]]] ]]]]]] ] ]]]]] ]]]] ]] ]]]] ]]]]]]]] ]]]]
]]]]]]] ]]]]] ] ]]]]]] ] ]]] ]]]] ]] ]]]] ]]]] ]]]] ]]]]
]]]]]]]] ]]]]] ]]] ]]]]]]] ] ]]]]]]] ]]]] ]]]] ]]]] ]]]]]
]]]]]]]]]]]]]]]]]]]]]]]]]]]]]]
]]]]]]]]]]]]]]]]]]]]]]]]]]]]] Development System
]]]]]]]]]]]]]]]]]]]]]]]]]]]]
]]]]]]]]]]]]]]]]]]]]]]]]]]] VxWorks 6.2
]]]]]]]]]]]]]]]]]]]]]]]]]] KERNEL: WIND version 2.8
]]]]]]]]]]]]]]]]]]]]]]]]] Copyright Wind River Systems, Inc., 1984-2005

CPU: TI TNETV1050 Communication Processor. Processor #0.
Memory Size: 0x2000000. BSP version 8.6.0.3.
Created: Nov 5 2013, 14:54:15
ED&R Policy Mode: deployed

========================================================
Board : TI TNETV1050 Communication Processor
SOC : Titan, ChipId: 0x7, Version: 2
Cache : Write-Back, Write-Allocate
PSP Version : 8.6.0.3
Type : BasePSP 8.6.0.3
PSPWIZ Version : 0.6
MIPS freq : 162500000 Hz,
System Freq : 100000000 Hz,
VBUS freq : 81250000 Hz
BasePSP mode : Routing
========================================================
Unable to delete route.

> WEB componment starting ...
> CFGTREE creating ...
CFGTREE creates finish.
> L2PROTO reg to cfgmgr ...
> NETWORK reg to cfgmgr ...
cfgmgr_init : CFGMGR: Creating...
SSH: stop ssh server success!(sshd_start)
sntp_restore_time(712) : didn't get time information last time uptime: 1days,02:05:58
00:00:00:01.192 - E/DLM: Cannot alloc mem for internal msg (1)
06:50:31, 01/01/2014 : DLM: Cannot alloc mem for internal msg (1)
00:00:00:01.192 - E/DLM: Cannot alloc mem for internal msg (1)
06:50:31, 01/01/2014 : DLM: Cannot alloc mem for internal msg (1)
00:00:00:01.192 - E/DLM: Cannot alloc mem for internal msg (2)
06:50:31, 01/01/2014 : DLM: Cannot alloc mem for internal msg (2)
06:50:31, 01/01/2014 : system boot up (SCCP 9.4.1.3)
cdpInit: init ok.
00:00:00:01.996 - E/cfgmgrEventToMMI(4262): winAppPost error: -1
ed75752 GLCD: bpp:8, X:396, Y:162 paletteSz:512
uglTitanModeSet 486:pGenDriver->fbAddress b54e7330
appCreate: autoBootLevel=2
MXP environment is created.
About to create Idle Task
About to create Measurement Task
Idle Measurement Tasks created
Panic button enabled
Heartbeat started
Creating Golden Gateway application...
TNETV1050 Communication Processor Revision: PG3.1
DSP core type (TITAN)
dimhw_HALT_DSP - No TDM config needed
check_file_crc : /DSP/DSP69xx.12-4-122-02-121029.zz ffs_check_crc success
Retrieving DSP image
Source: Flash file system, file: /DSP/DSP69xx.12-4-122-02-121029.zz

unzip 7-ZIP file successful
purchd_start(). ok.

*******************************************************************
** **
** VOIP IPP firmware SCCP 9.4.1.3 **
** **
** compiled on Nov 5 2013 at 14:54:07 **
** **
** **
*******************************************************************



VxWorks login: 00:00:00:02.088 - E/> MMI: Creating Browser ...
00:00:00:03.396 - E/Network: nw_create() ipstack_mode=2
06:50:34, 01/01/2014 : Network: nw_create() ipstack_mode=2
00:00:00:03.396 - E/Network: ndimhw_HALT_DSP - No TDM config needed
w_create() max_conn=50, max_fd=150
06:50:34, 01/01/2014 : Network: nw_create() max_conn=50, max_fd=150
00:00:00:03.396 - E/Following features compiled out of the build:
00:00:00:03.396 - E/ DIM_DNLD_PAGED_BOOT
00:00:00:03.396 - E/ DIM_DNLD_DIRECT
00:00:00:03.398 - E/ DIM_DNLD_MSG
00:00:00:03.398 - E/ DIM_CHAN_IF
00:00:00:03.398 - E/ DIM_RTCP_IF
00:00:00:03.398 - E/ DIM_SIG_IF
00:00:00:03.398 - E/ DIM_AUDIO_IF
00:00:00:03.398 - E/ DIM_LOMGR_CHN_FIFO
00:00:00:03.398 - E/ PROTO_AAL2
00:00:00:03.398 - E/ PROTO_CLRDT
00:00:00:03.398 - E/ PROTO_MODEM
00:00:00:03.398 - E/ DIM_3PROC
00:00:00:03.398 - E/ DIM_DETAILED_SPY
00:00:00:03.398 - E/ DIM_HI_PRIORITY_MSGS
00:00:00:03.398 - E/Following features not defined in build and have been enabled
00:00:00:03.398 - E/by default; REVIEW to remove potential unnecessary code:
00:00:00:03.398 - E/ All features are accounted for!!!
00:00:00:03.404 - E/ROOT: Hardware ringer :FALSE
06:50:34, 01/01/2014 : ROOT: Hardware ringer :FALSE
00:00:00:03.410 - E/CMM: cmm_create(). num_tcids=4. max_rtp_term=4
00:00:00:03.414 - E/ROOT: CMM created
00:00:00:03.420 - E/TSTN> tMVX_TSTN creating...
00:00:00:03.422 - E/SAPP : initializing sockets
00:00:00:03.422 - E/SAPP : initializing calls
00:00:00:03.434 - E/SAPP : initializing sccp
00:00:00:03.434 - E/SAPP : initialized
00:00:00:03.440 - E/TSTN> tMVX_TSTN created.
00:00:00:03.442 - E/CUVA> tMVX_CUVA created.
00:00:00:03.444 - E/NMM: Build contains Only TUIU
00:00:00:03.464 - E/DSPALLOC: AER instance 1, max_tail = 60 ms, usage = ( HS HeS GL_HS
GL_HeS )
06:50:34, 01/01/2014 : DSPALLOC: AER instance 1, max_tail = 60 ms, usage = ( HS HeS GL_
S GL_HeS )
00:00:00:03.464 - E/DSPALLOC: AER instance 0, max_tail = 200 ms, usage = ( HS HeS HF G
_HS GL_HeS )
06:50:34, 01/01/2014 : DSPALLOC: AER instance 0, max_tail = 200 ms, usage = ( HS HeS HF
GL_HS GL_HeS )
FlashEraseBlo
ck(b0790000,b07affff).cdpTxTask 2782 port[sw]: 0 2 (2233)
.00:00:00:03.472 - E/SIP: SIP: Init OK
00:00:00:03.472 - E/TCP : SNET task started ...
00:00:00:03.472 - E/SCCP : SCCP task started...
00:00:00:03.472 - E/CUVA> 'acuva_init_sock()'. initializing...
00:00:00:03.472 - E/CUVA> 'acuva_init_sock()'. non-block CUVA sock-port(13:4224), initial
zed.
00:00:00:03.550 - E/DIM: 0:*,Writing 0x6a001400 @ 0x100
00:00:00:03.764 - E/DSPA: DSP 0,Image 0:Download done!
00:00:00:03.764 - E/NMM: DSP Download OK
00:00:00:03.766 - E/NMM: 0, Set Channel State UNCONFIGURED Done (SUCCESS)
00:00:00:03.814 - E/NMM: 1, Set Channel State UNCONFIGURED Done (SUCCESS)
00:00:00:03.814 - E/NMM: 0, Channel Config Done (SUCCESS)
00:00:00:03.846 - E/NMM: 0, Set Channel State NORMAL Done (SUCCESS)
00:00:00:03.864 - E/NMM: 2, Set Channel State UNCONFIGURED Done (SUCCESS)
00:00:00:03.864 - E/NMM: 1, Channel Config Done (SUCCESS)
00:00:00:03.914 - E/NMM: 3, Set Channel State UNCONFIGURED Done (SUCCESS)
00:00:00:03.958 - E/NMM: 1, Set Channel State NORMAL Done (SUCCESS)
00:00:00:03.958 - E/NMM: 2, Channel Config Done (SUCCESS)
00:00:00:04.036 - E/NMM: 2, Set Channel State NORMAL Done (SUCCESS)
00:00:00:04.036 - E/NMM: 3, Channel Config Done (SUCCESS)
00:00:00:04.114 - E/NMM: 3, Set Channel State NORMAL Done (SUCCESS)
cdpTxTask 2782 port[sw]: 0 1 (2733)
lldp: init OK

rwxrwxrwx 0:0 a: -1 i:0 Jan 1, 2014 6:50:36am 223 Chirp1.raw

rwxrwxrwx 0:0 a: -1 i:0 Jan 1, 2014 6:50:36am 502 Chirp2.raw
xml_config_keymap(1652): -----
deck: stemplate
card: template
href: #stemplate?template
xml_config_keymap(1657): -----
cdpTxTask 2782 port[sw]: 0 0 (3233)

The DUT in DHCP Bind state.....
default 10.0.0.33 done
06:51:17, 01/01/2014 : SEPf029295a9946 Get ip from DHCP server : 10.0.0.36
EW: ew_client_task_create fail, either domain is null or invalid!
06:51:20, 01/01/2014 : CTLSEPF029295A9946.tlv updating
download percent : 0% download percent : 0% download percent : 0% download percent : 0% 0
:51:20, 01/01/2014 : CTLSEPF029295A9946.tlv not found in 213.140.133.68
06:51:20, 01/01/2014 : ITLSEPF029295A9946.tlv updating
download percent : 0% download percent : 0% download percent : 53% download percent : 100
download percent : 100% download percent : 100% 06:51:20, 01/01/2014 : ITLSEPF029295A994
.tlv (HTTP)

rwxrwxrwx 0:0 a: -1 i:0 Jan 1, 2014 6:51:20am 2442 VC_ITLSEPF029295A9946.tlv
06:51:20, 01/01/2014 : ITLSEPF029295A9946.tlv updated successfully
Process Trust File /CFG/VC_ITLSEPF029295A9946.tlv from 213.140.133.68 successfully
06:51:20, 01/01/2014 : ITL installed
download percent : 0% download percent : 0% download percent : 33% download percent : 66%
download percent : 99% download percent : 100% download percent : 100% download percent :
100% 06:51:20, 01/01/2014 : SEPF029295A9946.cnf.xml.sgn (HTTP)
Authenticating configuration file SEPF029295A9946.cnf.xml.sgn successfully
06:51:20, 01/01/2014 : Authenticating configuration file SEPF029295A9946.cnf.xml.sgn succ
ssfully
ERR [RTSOL] rtsold.c:1113: Router Solicitation is not running
network_stop_ipv6(3391) : dhcp6cStop fail
06:51:20, 01/01/2014 : Loads name : SCCP69xx.9-4-1-3.loads
06:51:22, 01/01/2014 : CTLSEPF029295A9946.tlv updating
download percent : 0% download percent : 0% download percent : 0% download percent : 0% 0
:51:22, 01/01/2014 : CTLSEPF029295A9946.tlv not found in 213.140.133.68
06:51:22, 01/01/2014 : ITLSEPF029295A9946.tlv updating
download percent : 0% download percent : 0% download percent : 53% download percent : 100
download percent : 100% download percent : 100% 06:51:22, 01/01/2014 : ITLSEPF029295A994
.tlv (HTTP)

rwxrwxrwx 0:0 a: -1 i:0 Jan 1, 2014 6:51:22am 2442 VC_ITLSEPF029295A9946.tlv
06:51:22, 01/01/2014 : ITLSEPF029295A9946.tlv updated successfully
Process Trust File /CFG/VC_ITLSEPF029295A9946.tlv from 213.140.133.68 successfully
06:51:22, 01/01/2014 : ITL installed
download percent : 0% download percent : 33% download percent : 99% download percent : 10
% download percent : 100% download percent : 100% 06:51:22, 01/01/2014 : SEPF029295A9946.
nf.xml.sgn (HTTP)
Authenticating configuration file SEPF029295A9946.cnf.xml.sgn successfully
06:51:22, 01/01/2014 : Authenticating configuration file SEPF029295A9946.cnf.xml.sgn succ
ssfully
06:51:22, 01/01/2014 : Loads name : SCCP69xx.9-4-1-3.loads
Authenticating SCCP69xx.9-4-1-3.loads file successfully.
06:51:27, 01/01/2014 : DNS Query [cma] : Successs
06:51:27, 01/01/2014 : DNS Query [cmb] : Successs
download percent : 0% download percent : 0% download percent : 6% download percent : 18%
ownload percent : 33% download percent : 36% download percent : 39% download percent : 51
download percent : 57% download percent : 75% download percent : 84% download percent :
3% download percent : 100% download percent : 100% download percent : 100% 06:51:34, 01/0
/2014 : tzdatacsv.csv.sgn (HTTP)
Authenticating configuration file tzdatacsv.csv.sgn successfully

rwxrwxrwx 0:0 a: -1 i:0 Jan 1, 2014 6:51:34am 9470 tzdatacsv.csv
00:00:01:04.002 - E/AMMU: Checking Protocol: Device=SCCP. Config=SCCP
00:00:01:04.406 - E/ACCU: SCCP REG OK[(0,0), (-1,0)]
00:00:01:04.426 - E/ACCU: SCCP REG OK[(0,0), (-1,0)]
00:00:01:04.494 - E/ACCU: SCCP REG OK[(0,0), (1,0)]

rwxrwxrwx 0:0 a: -1 i:0 Jan 2, 2014 8:49:48am 2230 local

rwxrwxrwx 0:0 a: -1 i:0 Jan 2, 2014 8:49:50am 6683 config

Copying files to flash... Complete.
..00:00:01:22.092 - E/Idle/Max KIPS: 5535 / 160823 --- MIPs avail: 5.54 CPU Idle:
.44%
00:00:07:22.642 - E/ACCU: SCCP REG OK[(0,0), (-1,0)]
00:00:07:28.358 - E/ACCU: SCCP REG OK[(-1,0), (-1,0)]
00:00:07:28.360 - E/ACCU: SCCP REG FAIL

rwxrwxrwx 0:0 a: -1 i:0 Jan 2, 2014 8:56:12am 2232 local

rwxrwxrwx 0:0 a: -1 i:0 Jan 2, 2014 8:56:14am 6683 config

Copying files to flash... Complete.
..00:00:09:17.678 - E/ACCU: SCCP REG OK[(2,0), (-1,0)]
00:00:09:17.686 - E/ACCU: SCCP REG OK[(2,0), (-1,0)]
xml_config_keymap(1652): -----
deck: sCMEtemplate
card: template
href: #sCMEtemplate?template
xml_config_keymap(1657): -----

rwxrwxrwx 0:0 a: -1 i:0 Jan 2, 2014 8:57:24am 2232 local

rwxrwxrwx 0:0 a: -1 i:0 Jan 2, 2014 8:57:26am 6683 config

Copying files to flash... Complete.
..00:00:09:35.004 - E/Idle/Max KIPS: 0 / 160823 --- MIPs avail: 0.00 CPU Idle:
.00%
00:00:13:19.058 - E/ACCU: SCCP REG OK[(2,0), (0,0)]

rwxrwxrwx 0:0 a: -1 i:0 Jan 2, 2014 9:01:24am 2234 local

rwxrwxrwx 0:0 a: -1 i:0 Jan 2, 2014 9:01:26am 6683 config

Copying files to flash... Complete.
..00:00:15:19.118 - E/ACCU: SCCP REG OK[(-1,0), (0,0)]
00:00:15:19.120 - E/ACCU: SCCP REG FAIL
00:00:15:19.582 - E/ACCU: SCCP REG OK[(0,0), (2,0)]
00:00:15:19.594 - E/ACCU: SCCP REG OK[(0,0), (2,0)]
xml_config_keymap(1652): -----
deck: stemplate
card: template
href: #stemplate?template
xml_config_keymap(1657): -----
09:03:51, 01/02/2014 : CTLSEPF029295A9946.tlv updating
download percent : 0% 00:00:15:20.620 - E/ACCU: SCCP REG OK[(0,0), (1,0)]
download percent : 0% download percent : 0% download percent : 0% 09:03:51, 01/02/2014 :
TLSEPF029295A9946.tlv not found in 213.140.133.68
09:03:51, 01/02/2014 : ITLSEPF029295A9946.tlv updating
download percent : 0% download percent : 0% download percent : 53% download percent : 100
download percent : 100% download percent : 100% 09:03:52, 01/02/2014 : ITLSEPF029295A994
.tlv (HTTP)

rwxrwxrwx 0:0 a: -1 i:0 Jan 2, 2014 9:03:52am 2442 VC_ITLSEPF029295A9946.tlv
09:03:52, 01/02/2014 : ITLSEPF029295A9946.tlv updated successfully
Process Trust File /CFG/VC_ITLSEPF029295A9946.tlv from 213.140.133.68 successfully
09:03:52, 01/02/2014 : ITL installed
download percent : 0% download percent : 0% download percent : 33% download percent : 66%
download percent : 99% download percent : 100% download percent : 100% download percent :
100% 09:03:52, 01/02/2014 : SEPF029295A9946.cnf.xml.sgn (HTTP)
Authenticating configuration file SEPF029295A9946.cnf.xml.sgn successfully
09:03:52, 01/02/2014 : Authenticating configuration file SEPF029295A9946.cnf.xml.sgn succ
ssfully
09:03:52, 01/02/2014 : Loads name : SCCP69xx.9-4-1-3.loads
Authenticating SCCP69xx.9-4-1-3.loads file successfully.

rwxrwxrwx 0:0 a: -1 i:0 Jan 2, 2014 9:04:04am 2230 local

rwxrwxrwx 0:0 a: -1 i:0 Jan 2, 2014 9:04:08am 6683 config

Copying files to flash... Complete.
.00:00:15:37.884 - E/Idle/Max KIPS: 0 / 160823 --- MIPs avail: 0.00 CPU Idle: 0
00%
.


More information about the cisco-voip mailing list