IP Phones keep unregistering and rebooting themselves

[tkauf]

We have an IP500 that has 3 IP Phones and 7 VPNremote phones. The IP phones are at a remote location which is connected via a site to site VPN tunnel (using Cisco ASA 5505 at both ends)

The VPN phones are located at people's homes and are creating a tunnel with the ASA 5505

We are having an issue where random phones will have their keep-alive time out, unregister themselves and then reboot. The phone states "Resetting on URQ" and then reboots. Then the phone will reconnect and then can stay connected for 1-2 minutes and then reboot itself again.

This has started happening around 2 weeks ago and has happened to different phones at different locations with both IP & VPNremote phones.

We have been also seeing random dropout of calls and also "System Incompatibilty" messages that come up as well.

While witnessing this occur many times, I have checked the status of the VPN tunnels and they are all fine. In addition, you can ping the IP of the phone just fine from the voicemail PC without losing 1 packet or seeing latency.

Below is sysmon trace of what occured when this happened.
Has anyone had this problem before? Thanks.

420298583mS H323Evt: Keep-alive time-out on 1210 (keep_alive_count 0)
420298583mS H323Evt: GK: Unregister endpoint TEL IP500 RNJ_497ee9c53a3d686f for extension 1210
420298583mS CMExtnEvt: IP Test 1: ExtnFault now 1
420298584mS CMExtnTx: v=1210, p1=8010
CMReleaseComp
Line: type=IPLine 250 Call: lid=261 id=298 in=1
Cause=16, Normal call clearing
420298585mS H323Evt: GK: Send URQ
420298585mS RasTx: v=Src=192.168.0.20:1719, Dst=172.16.23.53:49300 peb=0
RasMessage = unregistrationRequest

420298586mS H323Evt: v=0 stacknum=250 State, new=ReleaseReq, old=Present id=298
420298587mS H323Tx: 1289 dst=172.16.23.53:5584
H323 Pcol=08(Q931) Reflen=2 ref=0001(Local)
Message Type = ReleaseComplete

420331666mS H323Evt: Recv GRQ from ac101735
420331666mS H323Evt: e_H225_AliasAddress_dialedDigits alias
420331667mS H323Evt: found number <1210>
420331667mS RasTx: v=Src=192.168.0.20:1719, Dst=172.16.23.53:49300 peb=0
RasMessage = gatekeeperConfirm

420331718mS RasRx: v=IFace=LAN1, Src=172.16.23.53:49300, Dst=192.168.0.20:1719 peb=0
RasMessage = registrationRequest

420331719mS H323Evt: Recv: RegistrationRequest ac101735; Endpoints registered: 9; Endpoints in registration: 1
420331719mS H323Evt: e_H225_AliasAddress_dialedDigits alias
420331719mS H323Evt: found number <1210>
420331719mS H323Evt: RRQ --- CallSigProtocol is H323AnnexL_P. Go for Avaya VPN phone
420331720mS H323Evt: RRQ --- Register extn 1210 using product IP_Phone_VPN, version 2.300
420331721mS RasTx: v=Src=192.168.0.20:1719, Dst=172.16.23.53:49300 peb=0
RasMessage = registrationConfirm

420331975mS H323Rx: 1291 src=172.16.23.53:3356
H323 Pcol=08(Q931) Reflen=2 ref=0001(Remote)
Message Type = Setup
ForwardLCParameters EAAI:[G711_ULAW64K (frames=10)] H2250 SID=01:
ReverseLCParameters EAAI:[G711_ULAW64K (frames=60)] H2250 SID=01: RTP=172.16.23.53(52292) , RTCP=172.16.23.53(52293) ,
ForwardLCParameters EAAI:[G711_ALAW64K (frames=10)] H2250 SID=01:
ReverseLCParameters EAAI:[G711_ALAW64K (frames=60)] H2250 SID=01: RTP=172.16.23.53(52292) , RTCP=172.16.23.53(52293) ,
ForwardLCParameters EAAI:[G729_AWB (frames=1)] H2250 SID=01:
ReverseLCParameters EAAI:[G729_AWB (frames=6)] H2250 SID=01: RTP=172.16.23.53(52292) , RTCP=172.16.23.53(52293) ,
ForwardLCParameters EAAI:[G729_A (frames=1)] H2250 SID=01:
ReverseLCParameters EAAI:[G729_A (frames=6)] H2250 SID=01: RTP=172.16.23.53(52292) , RTCP=172.16.23.53(52293) ,
ForwardLCParameters EAAI:[G729_WB (frames=1)] H2250 SID=01:
ReverseLCParameters EAAI:[G729_WB (frames=6)] H2250 SID=01: RTP=172.16.23.53(52292) , RTCP=172.16.23.53(52293) ,
ForwardLCParameters H2250 SID=01:
ReverseLCParameters H2250 SID=01: RTP=172.16.23.53(52292) , RTCP=172.16.23.53(52293) ,
ForwardLCParameters EAAI:[G711_ULAW64K (frames=10)] H2250 SID=01:
ReverseLCParameters EAAI:[G711_ULAW64K (frames=60)] H2250 SID=01: RTP=172.16.23.53(52292) , RTCP=172.16.23.53(52293) ,
ForwardLCParameters EAAI:[G711_ALAW64K (frames=10)] H2250 SID=01:
ReverseLCParameters EAAI:[G711_ALAW64K (frames=60)] H2250 SID=01: RTP=172.16.23.53(52292) , RTCP=172.16.23.53(52293) ,
ForwardLCParameters EAAI:[G729_AWB (frames=1)] H2250 SID=01:
ReverseLCParameters EAAI:[G729_AWB (frames=6)] H2250 SID=01: RTP=172.16.23.53(52292) , RTCP=172.16.23.53(52293) ,
ForwardLCParameters EAAI:[G729_A (frames=1)] H2250 SID=01:
ReverseLCParameters EAAI:[G729_A (frames=6)] H2250 SID=01: RTP=172.16.23.53(52292) , RTCP=172.16.23.53(52293) ,
ForwardLCParameters EAAI:[G729_WB (frames=1)] H2250 SID=01:
ReverseLCParameters EAAI:[G729_WB (frames=6)] H2250 SID=01: RTP=172.16.23.53(52292) , RTCP=172.16.23.53(52293) ,
ForwardLCParameters H2250 SID=01:
ReverseLCParameters H2250 SID=01: RTP=172.16.23.53(52292) , RTCP=172.16.23.53(52293) ,
ForwardLCParameters [G711_ULAW64K (frames=10)] H2250 SID=01:
ReverseLCParameters [G711_ULAW64K (frames=60)] H2250 SID=01: RTP=172.16.23.53(52292) , RTCP=172.16.23.53(52293) ,
ForwardLCParameters [G711_ALAW64K (frames=10)] H2250 SID=01:
ReverseLCParameters [G711_ALAW64K (frames=60)] H2250 SID=01: RTP=172.16.23.53(52292) , RTCP=172.16.23.53(52293) ,
ForwardLCParameters [G729_AWB (frames=1)] H2250 SID=01:
ReverseLCParameters [G729_AWB (frames=6)] H2250 SID=01: RTP=172.16.23.53(52292) , RTCP=172.16.23.53(52293) ,
ForwardLCParameters [G729_A (frames=1)] H2250 SID=01:
ReverseLCParameters [G729_A (frames=6)] H2250 SID=01: RTP=172.16.23.53(52292) , RTCP=172.16.23.53(52293) ,
ForwardLCParameters [G729_WB (frames=1)] H2250 SID=01:
ReverseLCParameters [G729_WB (frames=6)] H2250 SID=01: RTP=172.16.23.53(52292) , RTCP=172.16.23.53(52293) ,
ForwardLCParameters H2250 SID=01:
ReverseLCParameters H2250 SID=01: RTP=172.16.23.53(52292) , RTCP=172.16.23.53(52293) ,

420331976mS H323Evt: v=0 stacknum=250 State, new=NullState, old=NullState id=-1
420331976mS H323Evt: v=0 stacknum=250 State, new=Present, old=NullState id=300
420331986mS CMExtnTx: v=1210, p1=8010
CMProceeding
Line: type=IPLine 250 Call: lid=261 id=300 in=1
420331987mS CMExtnTx: v=1210, p1=8010
CMConnect
Line: type=IPLine 250 Call: lid=261 id=300 in=1
IE CMIEFastStartInfoData (6)
420331987mS CcmsTx: v=6099
0000 07 38 11 20 a2 a0 0b .8. ...
420331988mS H323Evt: v=0 stacknum=250 State, new=ICProceeding, old=Present id=300
420331988mS H323Tx: 1291 dst=172.16.23.53:3356
H323 Pcol=08(Q931) Reflen=2 ref=0001(Local)
Message Type = CallProceeding

 

[superikey]

Note:

Tzvi forgot to mention the following.

IP400 Running 4.2.11
DS 16 For Local Users at the Site
Voicemail Pro on Windows 2003 Server PC
Avaya My_Ip_Tel.... TFTP Server


Isaac Braca
Avaya ACA - IP Office
CTO / ICCS & Co., LLC.


ICCS, Your Premier IT & Telecom Partner, is a New York City Based Avaya SMB Expert Business Partner and IT Consulting Firm.

Visit and Post on my Blog:

http://ipofficeexpert.blogspot.com/

 

[johnnybrian]

Just had this exact issue today on a 1808 phone on a 500 with 4.2(14) and newest firmware on the phone. Tried logging in as another user, and then the phone was fine. Deleted the original user from the PBX, added him again with the same number/details, and havent heard any complaints in 2 hours now..strange....

 

[Bas1234]

Have a look here;

http://www.tek-tips.com/viewthread.cfm?qid=1530181&page=9

___________________________________________
It works! Now if only I could remember what I did...
___________________________________________

 

[HairySupportMonkey]

Ok - im now well versed in ASA5505 and IP handsets.

1) Turn off all the h323 inspection maps (formally "fixups")
2) Turn off h323 TCP time outs in your Global time out options.
3) Deregister phones using the Options menu --> Log Off
4) Delete users on switch.
5) recreate base extensions and user profiles (if required)

should be stable after that.

Also, Try without hot desking (agent login / out) and see if more stable.