VPNRemote Phone will not register

[Phoneguy15]

Setting up 9630G as VPNRemote phone.
I believe we have the VPN connection working since the tunnel is successfully set up and traffic is passing thru.
The endpoint just will not register.

In Monitor I can see the request from the source (IP Phone) 192.168.128 to the Destination (IPO) 192.168.0.231
I can also see the requested extension number for the login (132)
Then I see an Unregistration request from the IPO back out to the phone after a message of:

GK: Unregister endpoint DigiTrax_5061d01b20d56f75 for extension 132 reason 4

I have no idea what a "reason 4" is.


Here is the full monitor trace:


733331mS RasRx: v=IFace=LAN1, Src=192.168.1.128:49300, Dst=192.168.0.231:1719 peb=0
RasMessage = registrationRequest

733331mS H323Evt: Recv: RegistrationRequest 192.168.1.128; Endpoints registered: 0; Endpoints in registration: 1
733331mS H323Evt: e_H225_AliasAddress_dialedDigits alias
733331mS H323Evt: found number <132>
733332mS H323Evt: RRQ --- CallSigProtocol is H323AnnexL_P. Go for Avaya VPN phone
733332mS H323Evt: RRQ --- Treat this as a forced login, the phone was probably rebooted (same_cs_addr 1)
733332mS H323Evt: GK: Unregister endpoint DigiTrax_5061cfec69bc033b for extension 132 reason 4
733333mS H323Evt: RRQ --- Register extn 132 using product IP_Phone_VPN, version 3.105S
733335mS RasTx: v=Src=192.168.0.231:1719, Dst=192.168.1.128:49300 peb=0
RasMessage = registrationConfirm

736354mS RasRx: v=IFace=LAN1, Src=192.168.1.128:49300, Dst=192.168.0.231:1719 peb=0
RasMessage = registrationRequest

736354mS H323Evt: Recv: RegistrationRequest 192.168.1.128; Endpoints registered: 0; Endpoints in registration: 1
736354mS H323Evt: e_H225_AliasAddress_dialedDigits alias
736354mS H323Evt: found number <132>
736355mS H323Evt: RRQ --- CallSigProtocol is H323AnnexL_P. Go for Avaya VPN phone
736355mS H323Evt: RRQ --- Treat this as a forced login, the phone was probably rebooted (same_cs_addr 1)
736355mS H323Evt: GK: Unregister endpoint DigiTrax_5061cfef783f7f39 for extension 132 reason 4
736356mS H323Evt: RRQ --- Register extn 132 using product IP_Phone_VPN, version 3.105S
736358mS RasTx: v=Src=192.168.0.231:1719, Dst=192.168.1.128:49300 peb=0
RasMessage = registrationConfirm

745797mS H323Evt: IRCheckTimer: GRQ record deleted (user name=; extn-num=132)
745797mS H323Evt: IRCheckTimer: GRQ record deleted (user name=; extn-num=132)
745797mS H323Evt: IRCheckTimer: GRQ record deleted (user name=; extn-num=132)
745797mS H323Evt: IRCheckTimer: GRQ record deleted (user name=; extn-num=132)
745797mS H323Evt: IRCheckTimer: GRQ record deleted (user name=; extn-num=132)
755601mS RasRx: v=IFace=LAN1, Src=192.168.1.128:49302, Dst=192.168.0.231:1719 peb=0
RasMessage = gatekeeperRequest

755602mS H323Evt: Recv GRQ from c0a80180
755602mS H323Evt: e_H225_AliasAddress_dialedDigits alias
755602mS H323Evt: found number <132>
755603mS RasTx: v=Src=192.168.0.231:1719, Dst=192.168.1.128:49302 peb=0
RasMessage = gatekeeperConfirm

760946mS RasRx: v=IFace=LAN1, Src=192.168.1.128:49302, Dst=192.168.0.231:1719 peb=0
RasMessage = gatekeeperRequest

760946mS H323Evt: Recv GRQ from c0a80180
760947mS H323Evt: e_H225_AliasAddress_dialedDigits alias
760947mS H323Evt: found number <132>
760947mS RasTx: v=Src=192.168.0.231:1719, Dst=192.168.1.128:49302 peb=0
RasMessage = gatekeeperConfirm

765941mS RasRx: v=IFace=LAN1, Src=192.168.1.128:49302, Dst=192.168.0.231:1719 peb=0
RasMessage = gatekeeperRequest

765942mS H323Evt: Recv GRQ from c0a80180
765942mS H323Evt: e_H225_AliasAddress_dialedDigits alias
765942mS H323Evt: found number <132>
765943mS RasTx: v=Src=192.168.0.231:1719, Dst=192.168.1.128:49302 peb=0
RasMessage = gatekeeperConfirm

771368mS RasRx: v=IFace=LAN1, Src=75.76.73.218:34270, Dst=192.168.0.231:1719 peb=0
RasMessage = gatekeeperRequest

771368mS H323Evt: Recv GRQ from 4b4c49da
771368mS H323Evt: e_H225_AliasAddress_dialedDigits alias
771369mS H323Evt: found number <132>
771369mS RasTx: v=Src=192.168.0.231:1719, Dst=75.76.73.218:34270 peb=0
RasMessage = gatekeeperConfirm

771448mS RasRx: v=IFace=LAN1, Src=192.168.1.128:49303, Dst=192.168.0.231:1719 peb=0
RasMessage = registrationRequest

771448mS H323Evt: Recv: RegistrationRequest 192.168.1.128; Endpoints registered: 0; Endpoints in registration: 1
771448mS H323Evt: e_H225_AliasAddress_dialedDigits alias
771448mS H323Evt: found number <132>
771449mS H323Evt: RRQ --- CallSigProtocol is H323AnnexL_P. Go for Avaya VPN phone
771449mS H323Evt: RRQ --- Treat this as a forced login, the phone was probably rebooted (same_cs_addr 0)
771449mS H323Evt: GK: Unregister endpoint DigiTrax_5061cff24bf84030 for extension 132 reason 4
771450mS H323Evt: GK: Send URQ
771450mS RasTx: v=Src=192.168.0.231:1719, Dst=192.168.1.128:49300 peb=0
RasMessage = unregistrationRequest

771451mS H323Evt: RRQ --- Register extn 132 using product IP_Phone_VPN, version 3.105S
771452mS RasTx: v=Src=192.168.0.231:1719, Dst=192.168.1.128:49303 peb=0
RasMessage = registrationConfirm

774440mS RasRx: v=IFace=LAN1, Src=192.168.1.128:49303, Dst=192.168.0.231:1719 peb=0
RasMessage = registrationRequest

774440mS H323Evt: Recv: RegistrationRequest 192.168.1.128; Endpoints registered: 0; Endpoints in registration: 1
774440mS H323Evt: e_H225_AliasAddress_dialedDigits alias
774440mS H323Evt: found number <132>
774441mS H323Evt: RRQ --- CallSigProtocol is H323AnnexL_P. Go for Avaya VPN phone
774441mS H323Evt: RRQ --- Treat this as a forced login, the phone was probably rebooted (same_cs_addr 1)
774441mS H323Evt: GK: Unregister endpoint DigiTrax_5061d015164809a5 for extension 132 reason 4
774442mS H323Evt: RRQ --- Register extn 132 using product IP_Phone_VPN, version 3.105S
774444mS RasTx: v=Src=192.168.0.231:1719, Dst=192.168.1.128:49303 peb=0
RasMessage = registrationConfirm

777438mS RasRx: v=IFace=LAN1, Src=192.168.1.128:49303, Dst=192.168.0.231:1719 peb=0
RasMessage = registrationRequest

777439mS H323Evt: Recv: RegistrationRequest 192.168.1.128; Endpoints registered: 0; Endpoints in registration: 1
777439mS H323Evt: e_H225_AliasAddress_dialedDigits alias
777439mS H323Evt: found number <132>
777439mS H323Evt: RRQ --- CallSigProtocol is H323AnnexL_P. Go for Avaya VPN phone
777439mS H323Evt: RRQ --- Treat this as a forced login, the phone was probably rebooted (same_cs_addr 1)
777439mS H323Evt: GK: Unregister endpoint DigiTrax_5061d01816e3074d for extension 132 reason 4
777441mS H323Evt: RRQ --- Register extn 132 using product IP_Phone_VPN, version 3.105S
777442mS RasTx: v=Src=192.168.0.231:1719, Dst=192.168.1.128:49303 peb=0
RasMessage = registrationConfirm


********** SysMonitor v10.1 (43) [connected to 192.168.0.231 (DigiTrax)] **********
796678mS RasRx: v=IFace=LAN1, Src=192.168.1.128:49305, Dst=192.168.0.231:1719 peb=0
RasMessage = gatekeeperRequest

796678mS H323Evt: Recv GRQ from c0a80180
796679mS H323Evt: e_H225_AliasAddress_dialedDigits alias
796679mS H323Evt: found number <132>
796679mS RasTx: v=Src=192.168.0.231:1719, Dst=192.168.1.128:49305 peb=0
RasMessage = gatekeeperConfirm

802061mS RasRx: v=IFace=LAN1, Src=192.168.1.128:49305, Dst=192.168.0.231:1719 peb=0
RasMessage = gatekeeperRequest

802062mS H323Evt: Recv GRQ from c0a80180
802062mS H323Evt: e_H225_AliasAddress_dialedDigits alias
802062mS H323Evt: found number <132>
802062mS RasTx: v=Src=192.168.0.231:1719, Dst=192.168.1.128:49305 peb=0
RasMessage = gatekeeperConfirm

805797mS H323Evt: IRCheckTimer: GRQ record deleted (user name=; extn-num=132)
805797mS H323Evt: IRCheckTimer: GRQ record deleted (user name=; extn-num=132)
805797mS H323Evt: IRCheckTimer: GRQ record deleted (user name=; extn-num=132)
805797mS H323Evt: IRCheckTimer: GRQ record deleted (user name=; extn-num=132)
805797mS H323Evt: IRCheckTimer: GRQ record deleted (user name=; extn-num=132)
805797mS H323Evt: IRCheckTimer: GRQ record deleted (user name=; extn-num=132)
805798mS H323Evt: IRCheckTimer: GRQ record deleted (user name=; extn-num=132)
807065mS RasRx: v=IFace=LAN1, Src=192.168.1.128:49305, Dst=192.168.0.231:1719 peb=0
RasMessage = gatekeeperRequest

807066mS H323Evt: Recv GRQ from c0a80180
807066mS H323Evt: e_H225_AliasAddress_dialedDigits alias
807066mS H323Evt: found number <132>
807067mS RasTx: v=Src=192.168.0.231:1719, Dst=192.168.1.128:49305 peb=0
RasMessage = gatekeeperConfirm

812474mS RasRx: v=IFace=LAN1, Src=75.76.73.218:17770, Dst=192.168.0.231:1719 peb=0
RasMessage = gatekeeperRequest

812475mS H323Evt: Recv GRQ from 4b4c49da
812475mS H323Evt: e_H225_AliasAddress_dialedDigits alias
812475mS H323Evt: found number <132>
812475mS RasTx: v=Src=192.168.0.231:1719, Dst=75.76.73.218:17770 peb=0
RasMessage = gatekeeperConfirm

812542mS RasRx: v=IFace=LAN1, Src=192.168.1.128:49306, Dst=192.168.0.231:1719 peb=0
RasMessage = registrationRequest

812542mS H323Evt: Recv: RegistrationRequest 192.168.1.128; Endpoints registered: 0; Endpoints in registration: 1
812542mS H323Evt: e_H225_AliasAddress_dialedDigits alias
812542mS H323Evt: found number <132>
812543mS H323Evt: RRQ --- CallSigProtocol is H323AnnexL_P. Go for Avaya VPN phone
812543mS H323Evt: RRQ --- Treat this as a forced login, the phone was probably rebooted (same_cs_addr 0)
812543mS H323Evt: GK: Unregister endpoint DigiTrax_5061d01b20d56f75 for extension 132 reason 4
812544mS H323Evt: GK: Send URQ
812545mS RasTx: v=Src=192.168.0.231:1719, Dst=192.168.1.128:49303 peb=0
RasMessage = unregistrationRequest

812545mS H323Evt: RRQ --- Register extn 132 using product IP_Phone_VPN, version 3.105S
812546mS RasTx: v=Src=192.168.0.231:1719, Dst=192.168.1.128:49306 peb=0
RasMessage = registrationConfirm

815530mS RasRx: v=IFace=LAN1, Src=192.168.1.128:49306, Dst=192.168.0.231:1719 peb=0
RasMessage = registrationRequest

815530mS H323Evt: Recv: RegistrationRequest 192.168.1.128; Endpoints registered: 0; Endpoints in registration: 1
815530mS H323Evt: e_H225_AliasAddress_dialedDigits alias
815530mS H323Evt: found number <132>
815531mS H323Evt: RRQ --- CallSigProtocol is H323AnnexL_P. Go for Avaya VPN phone
815531mS H323Evt: RRQ --- Treat this as a forced login, the phone was probably rebooted (same_cs_addr 1)
815531mS H323Evt: GK: Unregister endpoint DigiTrax_5061d03e1b8718b1 for extension 132 reason 4
815532mS H323Evt: RRQ --- Register extn 132 using product IP_Phone_VPN, version 3.105S
815533mS RasTx: v=Src=192.168.0.231:1719, Dst=192.168.1.128:49306 peb=0
RasMessage = registrationConfirm

818558mS RasRx: v=IFace=LAN1, Src=192.168.1.128:49306, Dst=192.168.0.231:1719 peb=0
RasMessage = registrationRequest

818559mS H323Evt: Recv: RegistrationRequest 192.168.1.128; Endpoints registered: 0; Endpoints in registration: 1
818559mS H323Evt: e_H225_AliasAddress_dialedDigits alias
818559mS H323Evt: found number <132>
818560mS H323Evt: RRQ --- CallSigProtocol is H323AnnexL_P. Go for Avaya VPN phone
818560mS H323Evt: RRQ --- Treat this as a forced login, the phone was probably rebooted (same_cs_addr 1)
818560mS H323Evt: GK: Unregister endpoint DigiTrax_5061d0412a615683 for extension 132 reason 4
818561mS H323Evt: RRQ --- Register extn 132 using product IP_Phone_VPN, version 3.105S
818563mS RasTx: v=Src=192.168.0.231:1719, Dst=192.168.1.128:49306 peb=0
RasMessage = registrationConfirm


********** Warning: Logging to Screen Stopped **********




The system config is IP500v2 R8.1.43
I have available Avaya IP Endpoint licenses though I have not reserved any for this particular endpoint.
I have set both the user and the extension to "Enable Remote Worker" and "Allow Remote Extn".
I have also set a Login Code for the user under Telephony/Supervisor Settings

Any help would be appreciated.

 

[tlpeter]

When you use the phone as a VPN phone then remote worker should be disabled.
A VPN phone and a remote worker phone are different!


BAZINGA!

I'm not insane, my mother had me tested!

 

[BWB8771]

I'm getting the same "reason 4" issue, but my non-VPN phone is boot-cycling over and over. I am attempting to re-login at with my own extension. Since we're tight on endpoint licenses, I use my extension in the conference room, phone room, etc.

In this instance, I had logged into a small 4602SW IP phone. Curiously, on THIS phone, it correctly challenged me for a password (on the rest of the 4621/5621 phones, just pressing # again will let people login!). There's no intuitive way to log off that phone, so I just walked back to my office and have been attempting to login.

I *can* login, but the phone only works for about 20 seconds, and then reboots.

What other debugging (to include using Wireshark!) can I do to find out why this happens?

2013-01-11T11:20:14 150839962mS SNMPRxMsg: get-request PDU
2013-01-11T11:20:14 150839962mS SNMPRxMsg: Sending response PDU to 192.168.1.17:47971 from 192.168.42.1:161
2013-01-11T11:20:22 150847355mS H323Evt: Recv GRQ from c0a82a6b
2013-01-11T11:20:22 150847356mS H323Evt: e_H225_AliasAddress_dialedDigits alias
2013-01-11T11:20:22 150847356mS H323Evt: found number <203>
2013-01-11T11:20:22 150847374mS H323Evt: Recv: RegistrationRequest 192.168.42.107; Endpoints registered: 28; Endpoints in registration: 1
2013-01-11T11:20:22 150847374mS H323Evt: e_H225_AliasAddress_dialedDigits alias
2013-01-11T11:20:22 150847375mS H323Evt: found number <203>
2013-01-11T11:20:22 150847375mS H323Evt: RRQ --- CallSigProtocol is H323AnnexL_P. Go for Avaya 4600IP phone
2013-01-11T11:20:22 150847375mS H323Evt: RRQ --- Reject unforced-login as there is an EP registered with the same name/extension
2013-01-11T11:20:27 150852726mS H323Evt: Recv GRQ from c0a82a6b
2013-01-11T11:20:27 150852726mS H323Evt: e_H225_AliasAddress_dialedDigits alias
2013-01-11T11:20:27 150852726mS H323Evt: found number <203>
2013-01-11T11:20:27 150852744mS H323Evt: Recv: RegistrationRequest 192.168.42.107; Endpoints registered: 28; Endpoints in registration: 1
2013-01-11T11:20:27 150852745mS H323Evt: e_H225_AliasAddress_dialedDigits alias
2013-01-11T11:20:27 150852745mS H323Evt: found number <203>
2013-01-11T11:20:27 150852745mS H323Evt: RRQ --- CallSigProtocol is H323AnnexL_P. Go for Avaya 4600IP phone
2013-01-11T11:20:27 150852745mS H323Evt: [highlight #FCE94F]GK: Unregister endpoint FLDIC_50eff51a78570d28 for extension 203 reason 4[/highlight]
2013-01-11T11:20:27 150852746mS H323Evt: GK: Send URQ
2013-01-11T11:20:27 150852746mS H323Evt: RRQ --- Register extn 203 using product IP_Phone, version 2.9010


IP 500 8.1(63)
VMPro 8.1.9016
5610s