Remove old SRST entry

Unanswered Question
Jan 2nd, 2014
User Badges:

I am having problems with my Cisco CME. I have a handful off 7925 and 7921 phones. They are randomly just switching themselves off and it is not hardware related (the problem has happened to almost all the phones at random times).



I have setup debugging on my CME and full debugging on the phones themselves. None of the log files reveal anything, the phones just die without logging anything and the CME only see's the KeepAlives drop before reporting a abnormal deregistration.



The only real pattern I can see is that the phones log some SRST messages exactly 5 seconds before the phone dies. The phones do log these messages every 30 odd seconds so it could be a coincidence but it is the only thing I have to go off right now.



The thing is my CME is not even configured for SRST, but the phones still show a SRST server under CallManger2. I know that we used to have CUCM before my time here, but it was replaced by CME for some reason I dont know. The IP address showing up under CallManager2 though is the IP address of my main switch which does nothing apart from layer 3 routing.



How can I remove the old SRST record from the phones to rule out this as being some sort of bug which is crashing my phones? I have looked at the .cnf.xml files and they only list my CME, there is no SRST record in the config.



Here are the related IP addresses,


Phone from testing: 192.168.3.119

CME - 192.168.3.4

Old CUCM - 192.168.3.10

Layer 3 switch - 192.168.3.1



Here is my show telephone-service all,


CONFIG (Version=8.6)

=====================

Version 8.6

Max phoneload sccp version 17

Max dspfarm sccp version 18

Cisco Unified Communications Manager Express

For on-line documentation please see:

http://www.cisco.com/en/US/products/sw/voicesw/ps4625/tsd_products_support_series_home.html


protocol mode default

ip source-address 192.168.3.4 port 2000

ip qos dscp:

ef (the MS 6 bits, 46, in ToS, 0xB8) for media

cs3 (the MS 6 bits, 24, in ToS, 0x60) for signal

af41 (the MS 6 bits, 34, in ToS, 0x88) for video

default (the MS 6 bits, 0, in ToS, 0x0) for serviceservice directed-pickup

no auto-reg-ephone

load 7921 CP7921G-1.4.2

load 7925 CP7925G-1.4.2

load 7931 SCCP31.9-1-1SR1S

load 7975 SCCP75.9-1-1SR1S

max-ephones 70

max-dn 100

max-conferences 12 gain -6

dspfarm units 0

dspfarm transcode sessions 0

conference software

privacy

no privacy-on-hold

hunt-group report delay 1 hours

hunt-group logout DND

max-redirect 10

cnf-file location: flash:

cnf-file option: PER-PHONE

network-locale[0] US   (This is the default network locale for this box)

network-locale[1] US

network-locale[2] US

network-locale[3] US

network-locale[4] US

user-locale[0] US    (This is the default user locale for this box)

user-locale[1] US

user-locale[2] US

user-locale[3] US

user-locale[4] US

srst mode auto-provision is OFF

srst ephone template is 0

srst dn template is 0

srst dn line-mode single

phone service g722CodecSupport 2

phone service webAccess 0

phone service phoneBookWebAccess 1

phone service videoCapability 1

phone service ThumbButton1 PTTH2

phone service displayOnWhenIncomingCall 1

phone service daysBacklightNotActive 1,2,3,4,5,6,7

phone service backlightOnTime 07:30

phone service backlightOnDuration 10:00

phone service backlightIdleTimeout 00:01

phone service daysDisplayNotActive 1,2,3,4,5,6,7

phone service displayOnTime 07:30

phone service displayOnDuration 10:00

phone service displayIdleTimeout 00:01

time-format 24

date-format dd-mm-yy

timezone 44 Tokyo Standard Time

secondary-dialtone 9

transfer-pattern .T

keepalive 40 auxiliary 30

timeout interdigit 10

timeout busy 10

timeout ringing 180

timeout transfer-recall 0

timeout ringin-callerid 8

timeout night-service-bell 12

caller-id name-only: enable

system message *****************

web admin system name ********************************

web admin customer name ***************

edit DN through Web:  enabled.

edit TIME through web:  enabled.

background save interval 10 minutes

Log (table parameters):

     max-size: 150

     retain-timer: 15

create cnf-files version-stamp Jan 01 2002 00:00:00

transfer-system full-consult

transfer-digit-collect new-call

local directory service: enabled.

Extension-assigner tag-type ephone-tag.




Here are the last bit of logging from the phone before it dies,

2014-01-02 19:30:20:0460 CP-7925G user.info SCCP: <-|ActiveKeepAlive

2014-01-02 19:30:20:0470 CP-7925G user.info SCCP: |->KAAck[1785]

2014-01-02 19:30:21:0360 CP-7925G authpriv.debug AUD: timedPendSignal timedout sec: 1388672927 usec 266173 

2014-01-02 19:30:23:0030 CP-7925G authpriv.debug AUD: timedPendSignal timedout sec: 1388672928 usec 922973 

2014-01-02 19:30:24:0030 CP-7925G user.info SCCP: SK_GetTcpConnection: Select error (-47) for 17 with time=11

2014-01-02 19:30:24:0040 CP-7925G user.debug SCCP: sk_security_LookServerTrusteList(192.168.3.1:SRST)...

2014-01-02 19:30:24:0050 CP-7925G user.debug secd: appLoop: DO RD, fd 6 (reqS)

2014-01-02 19:30:24:0060 CP-7925G user.notice secd: BEGIN SEC REQ:

2014-01-02 19:30:24:0070 CP-7925G user.notice secd:    req-type     : 4 (LOOKUP_SRVR)

2014-01-02 19:30:24:0080 CP-7925G user.notice secd:    req-id       : 5505904 (pid:336/seq:880) 

2014-01-02 19:30:24:0090 CP-7925G user.notice secd:    clnt-pid     : 336 

2014-01-02 19:30:24:0100 CP-7925G user.notice secd:    max-sec      : 120 (timeout)

2014-01-02 19:30:24:0110 CP-7925G user.notice secd:   LOOKUP REQ:

2014-01-02 19:30:24:0130 CP-7925G user.notice secd:    srvr name     : 192.168.3.1

2014-01-02 19:30:24:0130 CP-7925G user.notice secd:    srvr type     : 3 (SRST)

2014-01-02 19:30:24:0150 CP-7925G user.notice secd:   REQ DUMP (84 b):

2014-01-02 19:30:24:0160 CP-7925G user.notice secd:  * 04 00 00 00 70 03 54 00 50 01 00 00 78 00 00 00  [....p.T.P...x...]

2014-01-02 19:30:24:0170 CP-7925G user.notice secd:  * 03 00 00 00 31 30 2E 32 31 34 2E 33 2E 31 00 00  [....192.168.3.1..]

2014-01-02 19:30:24:0190 CP-7925G user.notice secd:  * 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  [................]

2014-01-02 19:30:24:0200 CP-7925G user.notice secd:  * 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  [................]

2014-01-02 19:30:24:0210 CP-7925G user.notice secd:  * 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  [................]

2014-01-02 19:30:24:0220 CP-7925G user.notice secd:  * 00 00 00 00                                      [....]

2014-01-02 19:30:24:0230 CP-7925G user.notice secd: END SEC REQ

2014-01-02 19:30:24:0240 CP-7925G user.debug secd: appLoop: rd ok, fd 6 (reqS)

2014-01-02 19:30:24:0250 CP-7925G user.debug secd: setFds: chk rd, fd 10 (sslserver)

2014-01-02 19:30:24:0260 CP-7925G user.debug secd: setFds: chk rd, fd 7 (prxy)

2014-01-02 19:30:24:0270 CP-7925G user.debug secd: setFds: chk rd, fd 6 (reqS)

2014-01-02 19:30:24:0280 CP-7925G user.debug secd: setFds: chk rd, fd 5 (cmd)

2014-01-02 19:30:24:0300 CP-7925G user.debug secd: setFds: monitor, rd 4 wr 0

2014-01-02 19:30:24:0300 CP-7925G user.debug secd: setTimeOut: tmo 119s:936ms

2014-01-02 19:30:24:0320 CP-7925G user.warn secd: WARN:lookupSRST: no CTL, treat SRST as non-secure

2014-01-02 19:30:24:0330 CP-7925G user.notice secd: BEGIN SEC REP:

2014-01-02 19:30:24:0340 CP-7925G user.notice secd:    req-type     : 4 (LOOKUP_SRVR)

2014-01-02 19:30:24:0350 CP-7925G user.notice secd:    req-id       : 5505904 (pid:336/seq:880) 

2014-01-02 19:30:24:0360 CP-7925G user.notice secd:    status       : 0 (OK) 

2014-01-02 19:30:24:0370 CP-7925G user.notice secd:    errcode      : 0 (NONE)

2014-01-02 19:30:24:0380 CP-7925G user.notice secd:    sub-errcode  : 0 (N/A)

2014-01-02 19:30:24:0390 CP-7925G user.notice secd:    err-desc     : <>

2014-01-02 19:30:24:0400 CP-7925G user.notice secd:   LOOKUP REP:

2014-01-02 19:30:24:0400 CP-7925G user.notice secd:    srvr name     : 192.168.3.1

2014-01-02 19:30:24:0410 CP-7925G user.notice secd:    srvr type     : 3 (SRST)

2014-01-02 19:30:24:0420 CP-7925G user.notice secd:    lookup result : 10 (NONSECURE)

2014-01-02 19:30:24:0430 CP-7925G user.notice secd:   REP DUMP (156 b):

2014-01-02 19:30:24:0450 CP-7925G user.notice secd:  * 04 00 00 00 70 03 54 00 00 00 00 00 00 00 00 00  [....p.T.........]

2014-01-02 19:30:24:0460 CP-7925G user.notice secd:  * 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  [................]

2014-01-02 19:30:24:0470 CP-7925G user.notice secd:  * 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  [................]

2014-01-02 19:30:24:0480 CP-7925G user.notice secd:  * 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  [................]

2014-01-02 19:30:24:0500 CP-7925G user.notice secd:  * 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  [................]

2014-01-02 19:30:24:0510 CP-7925G user.notice secd:  * 00 00 00 00 03 00 00 00 31 30 2E 32 31 34 2E 33  [........192.168.3]

2014-01-02 19:30:24:0520 CP-7925G authpriv.debug AUD: timedPendSignal timedout sec: 1388672930 usec 420633 

2014-01-02 19:30:24:0540 CP-7925G user.notice secd:  * 2E 31 00 00 00 00 00 00 00 00 00 00 00 00 00 00  [.1..............]

2014-01-02 19:30:24:0550 CP-7925G user.notice secd:  * 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  [................]

2014-01-02 19:30:24:0560 CP-7925G user.notice secd:  * 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  [................]

2014-01-02 19:30:24:0570 CP-7925G user.notice secd:  * 00 00 00 00 00 00 00 00 0A 00 00 00              [............]

2014-01-02 19:30:24:0580 CP-7925G user.notice secd: END SEC REP

2014-01-02 19:30:24:0600 CP-7925G user.debug secd: appLoop: DO RD, fd 5 (cmd)

2014-01-02 19:30:24:0610 CP-7925G user.debug secd: appLoop: rd ok, fd 5 (cmd)

2014-01-02 19:30:24:0640 CP-7925G user.debug secd: setFds: chk rd, fd 10 (sslserver)

2014-01-02 19:30:24:0650 CP-7925G user.debug SCCP: Server 192.168.3.1 exists in Certificate Trust list....

2014-01-02 19:30:24:0660 CP-7925G user.debug secd: setFds: chk rd, fd 7 (prxy)

2014-01-02 19:30:24:0670 CP-7925G user.debug secd: setFds: chk rd, fd 6 (reqS)

2014-01-02 19:30:24:0680 CP-7925G user.debug secd: setFds: chk rd, fd 5 (cmd)

2014-01-02 19:30:24:0690 CP-7925G user.debug secd: setFds: monitor, rd 4 wr 0

2014-01-02 19:30:24:0700 CP-7925G user.debug secd: setTimeOut: block

2014-01-02 19:30:26:0060 CP-7925G authpriv.debug AUD: timedPendSignal timedout sec: 1388672931 usec 966710 

2014-01-02 19:30:27:0940 CP-7925G authpriv.debug AUD: timedPendSignal timedout sec: 1388672933 usec 847467 

2014-01-02 19:30:28:0890 CP-7925G user.warn kernel: WLAN_DRVR: 2633.795: Starting cont scan, RSSI = -77

2014-01-02 19:30:28:0900 CP-7925G user.warn kernel: WLAN_DRVR: 2633.811: Restarting continuous scans

2014-01-02 19:30:29:0870 CP-7925G authpriv.debug AUD: timedPendSignal timedout sec: 1388672935 usec 727870

<PHONE DIES HERE>




Here is the log from CME,

Jan  2 19:30:19.800 EST: ephone-2 If GigabitEthernet0/1.3 ETHERNET 192.168.3.119 via ARP

Jan  2 19:30:19.800 EST: ephone-2[1/32][SEP0023AAAAAAAA]:Keepalive socket[32] SEP0023AAAAAAAA

Jan  2 19:30:22.908 EST: Cannot find device entry on socket fd 19 for message 0

Jan  2 19:30:30.736 EST: Cannot find device entry on socket fd 14 for message 0

Jan  2 19:30:34.081 EST: %C3800_ENVM-3-MFAIL_OFF: There is more than one failure with the Power System 2 or this Power System has been turned off.

Jan  2 19:30:36.413 EST: Cannot find device entry on socket fd 17 for message 0

Jan  2 19:30:39.861 EST: VOICE REGISTER POOL-7 has unregistered. Name:SEP000000000338  IP:192.168.3.248  DeviceType:Phon

Jan  2 19:30:42.149 EST: ephone-2[1/32][SEP0023AAAAAAAA]:SkinnyCheckPendingCallBackPhone scan 6 lines

Jan  2 19:30:42.969 EST: Cannot find device entry on socket fd 19 for message 0

Jan  2 19:30:43.149 EST: KeepAlive PROBE on socket [32] ephone-2 ephone  address= 192.168.3.119

Jan  2 19:30:50.149 EST: ephone-2[1/32][SEP0023AAAAAAAA]:Keepalive TIMEOUT on socket [32] ephone-2 SEP0023AAAAAAAA

Jan  2 19:30:50.149 EST: ephone-2[1/32][SEP0023AAAAAAAA]:DisAssociate: Closed socket 32 while REGISTERED

Jan  2 19:30:50.149 EST: ephone-2[1/32][SEP0023AAAAAAAA]: DN out-of-service for DN 58 chan 1

Jan  2 19:30:50.149 EST: SkinnyGetCallState for DN 58 chan 1 IDLE

Jan  2 19:30:50.149 EST: called DN -1 chan 1, calling DN -1 chan 1 phone -1 s2s:0

Jan  2 19:30:50.149 EST: ephone-2[1/32][SEP0023AAAAAAAA]: DN out-of-service for DN 58 chan 2

Jan  2 19:30:50.149 EST: SkinnyGetCallState for DN 58 chan 2 IDLE

Jan  2 19:30:50.149 EST: called DN -1 chan 1, calling DN -1 chan 1 phone 2 incoming s2s:0

Jan  2 19:30:50.149 EST: Bring down DN 58 chan 1 (541) with the following traceback

Jan  2 19:30:50.149 EST: -Traceback= 60585138z 60587E70z 605BF56Cz 605C4DF0z 605C5D98z 604FD790z

Jan  2 19:30:50.149 EST: Skinny DN 58 chan 1 state change to DOWN

Jan  2 19:30:50.149 EST: Bring down DN 58 chan 2 (541) with the following traceback

Jan  2 19:30:50.153 EST: -Traceback= 60585138z 60587E70z 605BF56Cz 605C4DF0z 605C5D98z 604FD790z

Jan  2 19:30:50.153 EST: Skinny DN 58 chan 2 state change to DOWN

Jan  2 19:30:50.153 EST: SkinnySetCTILineStatus: phone 1 dn 58 line status 0 line_removed 0

Jan  2 19:30:50.153 EST: ephone-2[1/32][SEP0023AAAAAAAA]:skinny_delete_socket [32]

Jan  2 19:30:50.153 EST: %IPPHONE-6-UNREGISTER_ABNORMAL: ephone-2:SEP0023AAAAAAAA IP:192.168.3.119 Socket:32 DeviceType:Phone has unregistered abnormally.

  • 1
  • 2
  • 3
  • 4
  • 5
Overall Rating: 0 (0 ratings)
Loading.
Hermanus Janse ... Mon, 01/06/2014 - 02:32
User Badges:
  • Silver, 250 points or more

have you tried to factory reset the phones or do a erase all config ?

Fredrik Ringertz Mon, 01/06/2014 - 22:34
User Badges:

I have done a full factory reset on the phones and that made no difference, it picks up the old SRST entry as soon as it has registered the phone with CME. I can't do a full reset on the router itself because it is our main router so it is in use...

Hermanus Janse ... Mon, 01/06/2014 - 22:40
User Badges:
  • Silver, 250 points or more

Have you tried

no srst mode auto-provision is OFF

no srst ephone template is 0

no srst dn template is 0

no srst dn line-mode single


then no create cnf-files and the create cnf-files again?


Factory reset the phone again.

Fredrik Ringertz Tue, 01/07/2014 - 03:09
User Badges:

I have tried all the "no srst"s before, and I just tried the no cnf-files and then recreated them. No luck unfortunately. I also downloaded the cnf for the phone I am using for testing with tftp and confirmed it has not got any mention of this 192.168.3.1 IP in it.

Actions

This Discussion