Friday, 6 May 2016

7800 Series Phones Not Prompting For MRA Domain & User Credentials

I've seen this happen a few times after upgrading from 7800 series firmware 10.3.1 to the latest 11.0.1 firmware (which introduced official MRA support). Phones that could previously connect endlessly loop between "registering" & "not registered", they never prompt for the domain to resolve the _collab-edge._tls SRV record, nor do they attempt to resolve a cached domain either.
Correct behaviour is if DHCP option 150 isn't present or the TFTP server is unreachable, the phone tries to resolve the host name of the CUCM servers in its cached configuration file, if this also fails then the phone should determine that it should use MRA instead. Looking at the status messages on the phone confirms that the phone never gets beyond the lack of TFTP or CUCM connectivity:

[12:22:54,29/04/16] TFTP Error : SEPF09E636E5656.cnf.xml.sgn
[12:22:54,29/04/16] DNS Unknown IPv4 Host CUCM2.somewhere.com
[12:22:54,29/04/16] DNS Unknown IPv4 Host CUCM1.somewhere.com
[12:22:57,29/04/16] TFTP Error : SK93886772-e459-a46f-ff8d-e15df16797e8.xml.sgn
[12:22:58,29/04/16] Configuring IP
[12:23:03,29/04/16] No IPv4 TFTP Server
[12:23:03,29/04/16] Trust List Update Failed
[12:23:04,29/04/16] TFTP Error : SEPF09E636E5656.cnf.xml.sgn
[12:23:04,29/04/16] DNS Unknown IPv4 Host CUCM2.somewhere.com
[12:23:04,29/04/16] DNS Unknown IPv4 Host CUCM1.somewhere.com

Looking at the console logs on the phone also shows that the phone fails to connect to TFTP or resolve the server names but thinks it's not in Collaboration Edge mode:

1102 ERR Apr 29 12:23:27.529537 JAVA-CFG : config_process_ccm_properties : No valid IPv4 TFTP server configured
1103 NOT Apr 29 12:23:27.529953 JAVA-ccm0=CUCM2.somewhere.com ccm1=CUCM1.somewhere.com  ccm2= sip_port_0=5060 sip_port_1=5060 sip_port_2=5060 length=0
1104 NOT Apr 29 12:23:27.530006 JAVA-ccm0=CUCM2.somewhere.com ccm1=CUCM1.somewhere.com  ccm2= sec_sip_port_0=5061 sec_sip_port_1=5061 sec_sip_port_2=5061 length=0
1105 NOT Apr 29 12:23:27.530341 JAVA-ccm0_v6= ccm1_v6=  ccm2_v6= lenght=0
1106 NOT Apr 29 12:23:27.530382 JAVA-ip_mode is IPv4
1107 NOT Apr 29 12:23:27.530614 JAVA-config_process_ccm_properties: is in Edge mode = FALSE
1108 NOT Apr 29 12:23:27.597478 dgetserver(9651)-dgetserver.RESULT [_0_  [PASS] No error     ]
1109 NOT Apr 29 12:23:27.606755 downd-SOCKET accept errno=4 "Interrupted system call"
1110 INF Apr 29 12:23:27.630973 dnsmasq[2033]: query[A] CUCM1.somewhere.com from 127.0.0.1
1111 INF Apr 29 12:23:27.631110 dnsmasq[2033]: cached CUCM1.somewhere.com is NXDOMAIN-IPv4
1112 INF Apr 29 12:23:27.632905 dnsmasq[2033]: query[A] CUCM1.somewhere.com from 127.0.0.1
1113 INF Apr 29 12:23:27.633020 dnsmasq[2033]: cached CUCM1.somewhere.com is NXDOMAIN-IPv4
1114 ERR Apr 29 12:23:27.631788 JAVA-dnsGetHostByName :lookup CUCM1.somewhere.com failed.
1115 INF Apr 29 12:23:27.634020 dnsmasq[2033]: query[A] CUCM2.somewhere.com from 127.0.0.1
1116 INF Apr 29 12:23:27.634110 dnsmasq[2033]: cached CUCM2.somewhere.com is NXDOMAIN-IPv4
1117 INF Apr 29 12:23:27.634374 dnsmasq[2033]: query[A] CUCM2.somewhere.com from 127.0.0.1
1118 INF Apr 29 12:23:27.634565 dnsmasq[2033]: cached CUCM2.somewhere.com is NXDOMAIN-IPv4
1119 ERR Apr 29 12:23:27.634845 JAVA-dnsGetHostByName :lookup CUCM2.somewhere.com failed.

Eventually I stumbled across Admin Settings > Reset Settings > Service Name fixing the problem. Not exactly a clearly described setting, nor does it explain why the phone isn't getting as far as prompting for a domain, if it had cached an incorrect one I'd expect to see it trying to resolve the _collab-edge._tls SRV record for the incorrect domain.