VoIP Phones will not register

jbj92 · July 8, 2022, 4:35pm

Hello all,

I currently have a pbx server on v16.0.19. This is a sangoma appliance with FreePBX installed. This server does not have a SIP trunk, but uses a DAHDI trunk.

I have analog phones that are connected to audiocodes. I can get the extensions on the audiocodes to register fine and calling works on these phones no problems.

I am trying to get a polycom ip650 & ip321 to register to the pbx but I am having no luck.

What is weird is that the phone acts like it is going to join, but does not. In my experience with the polycoms, when they are doing their provisioning upon a factory reset, they will come up and get their config. Once they get the config, the phone reboots one more time and then registers. The phone is getting some config, rebooting, but then can not register. In the gui of the phone, it shows that the line has the extension I am trying to configure. It also takes the admin password given from the pbx, it does not take the default polycom admin password of 456 so it is getting SOMETHING from the freepbx.

I have been trying with http provisioning and could not get that going so I tried ftp provisioning. Here are the ftp logs from the last attempt to register the ip321.

Fri Jul 8 11:24:12 2022 [pid 1092] CONNECT: Client “10.124.254.36”
Fri Jul 8 11:24:12 2022 [pid 1091] [asterisk] OK LOGIN: Client “10.124.254.36”
Fri Jul 8 11:24:20 2022 [pid 1177] CONNECT: Client “10.124.254.36”
Fri Jul 8 11:24:20 2022 [pid 1176] [asterisk] OK LOGIN: Client “10.124.254.36”
Fri Jul 8 11:24:20 2022 [pid 1178] [asterisk] FAIL UPLOAD: Client “10.124.254.36”, “/tftpboot/0004f2c3a1f7-app.log”, 0.00Kbyte/sec
Fri Jul 8 11:24:22 2022 [pid 1186] CONNECT: Client “10.124.254.36”
Fri Jul 8 11:24:22 2022 [pid 1185] [asterisk] OK LOGIN: Client “10.124.254.36”
Fri Jul 8 11:24:22 2022 [pid 1187] [asterisk] OK DOWNLOAD: Client “10.124.254.36”, “/tftpboot/0004f2c3a1f7.cfg”, 473 bytes, 342.67Kbyte/sec
Fri Jul 8 11:24:22 2022 [pid 1191] CONNECT: Client “10.124.254.36”
Fri Jul 8 11:24:22 2022 [pid 1190] [asterisk] OK LOGIN: Client “10.124.254.36”
Fri Jul 8 11:24:22 2022 [pid 1192] [asterisk] FAIL DOWNLOAD: Client “10.124.254.36”, “/tftpboot/customfw/polycom/2345-12360-001.sip.ld”, 113312 bytes, 11407.86Kbyte/sec
Fri Jul 8 11:24:23 2022 [pid 1187] [asterisk] OK DOWNLOAD: Client “10.124.254.36”, “/tftpboot/0004f2c3a1f7-features.cfg”, 32234 bytes, 243.71Kbyte/sec
Fri Jul 8 11:24:23 2022 [pid 1187] [asterisk] OK DOWNLOAD: Client “10.124.254.36”, “/tftpboot/0004f2c3a1f7-8888.cfg”, 3908 bytes, 1765.22Kbyte/sec
Fri Jul 8 11:24:23 2022 [pid 1187] [asterisk] OK DOWNLOAD: Client “10.124.254.36”, “/tftpboot/0004f2c3a1f7-sip-interop.cfg”, 23581 bytes, 716.32Kbyte/sec
Fri Jul 8 11:24:24 2022 [pid 1202] CONNECT: Client “10.124.254.36”
Fri Jul 8 11:24:24 2022 [pid 1201] [asterisk] OK LOGIN: Client “10.124.254.36”
Fri Jul 8 11:24:24 2022 [pid 1207] CONNECT: Client “10.124.254.36”
Fri Jul 8 11:24:24 2022 [pid 1204] [asterisk] OK LOGIN: Client “10.124.254.36”
Fri Jul 8 11:24:56 2022 [pid 1337] CONNECT: Client “10.124.254.36”
Fri Jul 8 11:24:56 2022 [pid 1336] [asterisk] OK LOGIN: Client “10.124.254.36”
Fri Jul 8 11:24:56 2022 [pid 1338] [asterisk] OK DOWNLOAD: Client “10.124.254.36”, “/tftpboot/0004f2c3a1f7.cfg”, 473 bytes, 282.34Kbyte/sec
Fri Jul 8 11:24:56 2022 [pid 1342] CONNECT: Client “10.124.254.36”
Fri Jul 8 11:24:56 2022 [pid 1341] [asterisk] OK LOGIN: Client “10.124.254.36”
Fri Jul 8 11:24:56 2022 [pid 1347] [asterisk] FAIL DOWNLOAD: Client “10.124.254.36”, “/tftpboot/customfw/polycom/2345-12360-001.sip.ld”, 113312 bytes, 11513.50Kbyte/sec
Fri Jul 8 11:24:56 2022 [pid 1349] CONNECT: Client “10.124.254.36”
Fri Jul 8 11:24:56 2022 [pid 1348] [asterisk] OK LOGIN: Client “10.124.254.36”
Fri Jul 8 11:24:56 2022 [pid 1338] [asterisk] OK DOWNLOAD: Client “10.124.254.36”, “/tftpboot/0004f2c3a1f7-features.cfg”, 32234 bytes, 283.93Kbyte/sec
Fri Jul 8 11:24:57 2022 [pid 1338] [asterisk] OK DOWNLOAD: Client “10.124.254.36”, “/tftpboot/0004f2c3a1f7-8888.cfg”, 3908 bytes, 1846.35Kbyte/sec
Fri Jul 8 11:24:57 2022 [pid 1350] [asterisk] FAIL UPLOAD: Client “10.124.254.36”, “/tftpboot/0004f2c3a1f7-app.log”, 0.00Kbyte/sec
Fri Jul 8 11:24:57 2022 [pid 1338] [asterisk] OK DOWNLOAD: Client “10.124.254.36”, “/tftpboot/0004f2c3a1f7-sip-interop.cfg”, 23581 bytes, 266.31Kbyte/sec
Fri Jul 8 11:24:58 2022 [pid 1357] CONNECT: Client “10.124.254.36”
Fri Jul 8 11:24:58 2022 [pid 1356] [asterisk] OK LOGIN: Client “10.124.254.36”
Fri Jul 8 11:24:58 2022 [pid 1360] CONNECT: Client “10.124.254.36”
Fri Jul 8 11:24:58 2022 [pid 1359] [asterisk] OK LOGIN: Client “10.124.254.36”
Fri Jul 8 11:24:59 2022 [pid 1366] CONNECT: Client “10.124.254.36”
Fri Jul 8 11:24:59 2022 [pid 1365] [asterisk] OK LOGIN: Client “10.124.254.36”
Fri Jul 8 11:24:59 2022 [pid 1369] CONNECT: Client “10.124.254.36”
Fri Jul 8 11:24:59 2022 [pid 1368] [asterisk] OK LOGIN: Client “10.124.254.36”
Fri Jul 8 11:24:59 2022 [pid 1372] CONNECT: Client “10.124.254.36”
Fri Jul 8 11:24:59 2022 [pid 1371] [asterisk] OK LOGIN: Client “10.124.254.36”
Fri Jul 8 11:24:59 2022 [pid 1338] [asterisk] OK DOWNLOAD: Client “10.124.254.36”, “/tftpboot/0004f2c3a1f7.cfg”, 473 bytes, 328.76Kbyte/sec
Fri Jul 8 11:24:59 2022 [pid 1376] CONNECT: Client “10.124.254.36”
Fri Jul 8 11:24:59 2022 [pid 1373] [asterisk] FAIL UPLOAD: Client “10.124.254.36”, “/tftpboot/0004f2c3a1f7-app.log”, 0.00Kbyte/sec
Fri Jul 8 11:24:59 2022 [pid 1375] [asterisk] OK LOGIN: Client “10.124.254.36”
Fri Jul 8 11:24:59 2022 [pid 1377] [asterisk] FAIL DOWNLOAD: Client “10.124.254.36”, “/tftpboot/customfw/polycom/2345-12360-001.sip.ld”, 113312 bytes, 10355.25Kbyte/sec
Fri Jul 8 11:25:00 2022 [pid 1338] [asterisk] OK DOWNLOAD: Client “10.124.254.36”, “/tftpboot/0004f2c3a1f7-features.cfg”, 32234 bytes, 246.70Kbyte/sec
Fri Jul 8 11:25:00 2022 [pid 1338] [asterisk] OK DOWNLOAD: Client “10.124.254.36”, “/tftpboot/0004f2c3a1f7-8888.cfg”, 3908 bytes, 1770.13Kbyte/sec
Fri Jul 8 11:25:01 2022 [pid 1338] [asterisk] OK DOWNLOAD: Client “10.124.254.36”, “/tftpboot/0004f2c3a1f7-sip-interop.cfg”, 23581 bytes, 309.62Kbyte/sec
Fri Jul 8 11:25:01 2022 [pid 1384] CONNECT: Client “10.124.254.36”
Fri Jul 8 11:25:01 2022 [pid 1383] [asterisk] OK LOGIN: Client “10.124.254.36”
Fri Jul 8 11:25:01 2022 [pid 1387] CONNECT: Client “10.124.254.36”
Fri Jul 8 11:25:01 2022 [pid 1386] [asterisk] OK LOGIN: Client “10.124.254.36”
Fri Jul 8 11:25:01 2022 [pid 1390] CONNECT: Client “10.124.254.36”
Fri Jul 8 11:25:01 2022 [pid 1389] [asterisk] OK LOGIN: Client “10.124.254.36”
Fri Jul 8 11:25:01 2022 [pid 1391] [asterisk] FAIL UPLOAD: Client “10.124.254.36”, “/tftpboot/0004f2c3a1f7-app.log”, 0.00Kbyte/sec
Fri Jul 8 11:25:04 2022 [pid 1434] CONNECT: Client “10.124.254.36”
Fri Jul 8 11:25:04 2022 [pid 1433] [asterisk] OK LOGIN: Client “10.124.254.36”
Fri Jul 8 11:25:04 2022 [pid 1435] [asterisk] FAIL UPLOAD: Client “10.124.254.36”, “/tftpboot/0004f2c3a1f7-app.log”, 0.00Kbyte/sec
Fri Jul 8 11:25:30 2022 [pid 1615] CONNECT: Client “10.124.254.36”
Fri Jul 8 11:25:30 2022 [pid 1614] [asterisk] OK LOGIN: Client “10.124.254.36”
Fri Jul 8 11:25:30 2022 [pid 1617] [asterisk] OK DOWNLOAD: Client “10.124.254.36”, “/tftpboot/0004f2c3a1f7.cfg”, 473 bytes, 273.32Kbyte/sec
Fri Jul 8 11:25:30 2022 [pid 1619] CONNECT: Client “10.124.254.36”
Fri Jul 8 11:25:30 2022 [pid 1618] [asterisk] OK LOGIN: Client “10.124.254.36”
Fri Jul 8 11:25:30 2022 [pid 1620] [asterisk] FAIL DOWNLOAD: Client “10.124.254.36”, “/tftpboot/customfw/polycom/2345-12360-001.sip.ld”, 113312 bytes, 11643.12Kbyte/sec
Fri Jul 8 11:25:31 2022 [pid 1617] [asterisk] OK DOWNLOAD: Client “10.124.254.36”, “/tftpboot/0004f2c3a1f7-features.cfg”, 32234 bytes, 286.96Kbyte/sec
Fri Jul 8 11:25:31 2022 [pid 1617] [asterisk] OK DOWNLOAD: Client “10.124.254.36”, “/tftpboot/0004f2c3a1f7-8888.cfg”, 3908 bytes, 1748.24Kbyte/sec
Fri Jul 8 11:25:31 2022 [pid 1617] [asterisk] OK DOWNLOAD: Client “10.124.254.36”, “/tftpboot/0004f2c3a1f7-sip-interop.cfg”, 23581 bytes, 286.02Kbyte/sec
Fri Jul 8 11:25:32 2022 [pid 1649] CONNECT: Client “10.124.254.36”
Fri Jul 8 11:25:32 2022 [pid 1648] [asterisk] OK LOGIN: Client “10.124.254.36”
Fri Jul 8 11:25:32 2022 [pid 1653] CONNECT: Client “10.124.254.36”
Fri Jul 8 11:25:32 2022 [pid 1652] [asterisk] OK LOGIN: Client “10.124.254.36”
Fri Jul 8 11:25:32 2022 [pid 1663] CONNECT: Client “10.124.254.36”
Fri Jul 8 11:25:32 2022 [pid 1662] [asterisk] OK LOGIN: Client “10.124.254.36”
Fri Jul 8 11:25:32 2022 [pid 1666] CONNECT: Client “10.124.254.36”
Fri Jul 8 11:25:32 2022 [pid 1665] [asterisk] OK LOGIN: Client “10.124.254.36”
Fri Jul 8 11:25:32 2022 [pid 1617] [asterisk] OK DOWNLOAD: Client “10.124.254.36”, “/tftpboot/0004f2c3a1f7.cfg”, 473 bytes, 326.67Kbyte/sec
Fri Jul 8 11:25:33 2022 [pid 1669] CONNECT: Client “10.124.254.36”
Fri Jul 8 11:25:33 2022 [pid 1668] [asterisk] OK LOGIN: Client “10.124.254.36”
Fri Jul 8 11:25:33 2022 [pid 1671] [asterisk] FAIL DOWNLOAD: Client “10.124.254.36”, “/tftpboot/customfw/polycom/2345-12360-001.sip.ld”, 113312 bytes, 11623.56Kbyte/sec
Fri Jul 8 11:25:33 2022 [pid 1617] [asterisk] OK DOWNLOAD: Client “10.124.254.36”, “/tftpboot/0004f2c3a1f7-features.cfg”, 32234 bytes, 292.36Kbyte/sec
Fri Jul 8 11:25:33 2022 [pid 1617] [asterisk] OK DOWNLOAD: Client “10.124.254.36”, “/tftpboot/0004f2c3a1f7-8888.cfg”, 3908 bytes, 1773.42Kbyte/sec
Fri Jul 8 11:25:34 2022 [pid 1617] [asterisk] OK DOWNLOAD: Client “10.124.254.36”, “/tftpboot/0004f2c3a1f7-sip-interop.cfg”, 23581 bytes, 306.81Kbyte/sec
Fri Jul 8 11:25:34 2022 [pid 1692] CONNECT: Client “10.124.254.36”
Fri Jul 8 11:25:34 2022 [pid 1691] [asterisk] OK LOGIN: Client “10.124.254.36”
Fri Jul 8 11:25:34 2022 [pid 1695] CONNECT: Client “10.124.254.36”
Fri Jul 8 11:25:34 2022 [pid 1694] [asterisk] OK LOGIN: Client “10.124.254.36”
Fri Jul 8 11:26:15 2022 [pid 1938] CONNECT: Client “10.124.254.36”
Fri Jul 8 11:26:15 2022 [pid 1937] [asterisk] OK LOGIN: Client “10.124.254.36”
Fri Jul 8 11:26:25 2022 [pid 1968] CONNECT: Client “10.124.254.36”
Fri Jul 8 11:26:25 2022 [pid 1967] [asterisk] OK LOGIN: Client “10.124.254.36”

Here are the logs from the phone itself.

000007.236|log ||03|---------- Initial log entry ----------
000007.238|so ||03|Platform: Model=SoundPoint IP 321, Assembly=2345-12360-001 Rev=C Region=
000007.238|so ||03|Platform: Interface eth0 MAC=0004f2c3a1f7
000007.238|so ||03|Platform: BootBlock=3.0.2.0024 (12360-001) 30-Nov-10 14:56
000007.238|so ||03|Platform: Updater=5.0.15.0741 05-Feb-20 20:04
000007.238|so ||03|Application, main: Label=SIP, Version=Mink 4.0.15.1009 07-Feb-20 12:56
000007.238|so ||03|Application, main: P/N=3150-11530-409
000007.238|rdisk||03|RAM disk created, size: 4,194,304 bytes
000007.240|ocsp ||03|O.C.S.P. Enabled = 0
000007.242|tls ||03|Initial log entry. Current logging level 4
000007.304|pmt ||03|Initial log entry. Current logging level 4
000007.306|wdog ||03|Initial log entry. Current logging level 4
000007.306|ethf ||03|Initial log entry. Current logging level 4
000007.306|hw ||03|Initial log entry. Current logging level 4
000007.306|ares ||03|Initial log entry. Current logging level 4
000007.306|dns ||03|Initial log entry. Current logging level 4
000007.306|cfg ||03|Initial log entry. Current logging level 4
000007.308|dot1x||03|Initial log entry. Current logging level 4
000007.314|cfg |5|03|RT|Error installing DHCP event hook.
000007.374|lic ||03|Initial log entry. Current logging level 4
000007.374|lic |4|03|cfgCfsFlashKeyScratchLoad: key is blank
000007.420|curl ||03|Initial log entry. Current logging level 4
000007.420|utilm||03|Initial log entry. Current logging level 4
000007.420|copy ||03|Initial log entry. Current logging level 4
000007.420|rtos ||03|Initial log entry. Current logging level 4
000007.422|sec ||03|Initial log entry. Current logging level 4
000007.426|so ||03|Configuration files: 0004f2c3a1f7-features.cfg, 0004f2c3a1f7-8888.cfg, 0004f2c3a1f7-sip-interop.cfg
000007.474|log ||03|Log render level set to 1
000007.538|srtp ||03|Initial log entry. Current logging level 4
000007.542|res ||03|Initial log entry. Current logging level 4
000007.544|httpa||03|Initial log entry. Current logging level 4
000007.544|lldp ||03|Initial log entry. Current logging level 4
000007.544|cdp ||03|Initial log entry. Current logging level 4
000007.546|sys ||03|Initial log entry. Current logging level 4
000007.612|ssps ||03|Initial log entry. Current logging level 4
000007.614|so ||03|soCodecConfig: Explicitly Adding codecG722 for PTT
000010.046|so ||03|System Info Reports:
000010.046|so ||03| CPU is TNETV1057/C55x, rev 2 running at 87.500MHz with memory at 87.500MHz.
000010.046|so ||03| Board is identified as PolycomSoundPointIP-SPIP_321.
000010.046|so ||03| DRAM_LO: 0x94000000. DRAM_SIZE: 32 MB
000010.046|so ||03| Clocks are VBUSP: 87.500MHz, VBUS: 75.000MHz, USB: 25.000MHz, LCD: 87.500MHz, DSP: 87.500MHz.
000010.046|so ||03| NOR flash detected is 9
000010.046|key ||03|Initial log entry. Current logging level 4
000010.052|httpd||03|Initial log entry. Current logging level 4
000010.054|poll ||03|Initial log entry. Current logging level 4
000010.054|push ||03|Initial log entry. Current logging level 4
000010.054|poll ||03|Initial log entry. Current logging level 4
000010.054|poll ||03|Initial log entry. Current logging level 4
000010.054|poll ||03|Initial log entry. Current logging level 4
000010.054|poll ||03|Initial log entry. Current logging level 4
000010.056|poll ||03|Initial log entry. Current logging level 4
000010.056|ht ||03|Initial log entry. Current logging level 4
000010.056|dbuf ||03|Initial log entry. Current logging level 4
000010.060|ssps ||03|Application, comp. 1: Label=PolyDSP Titan Mem1 FS4, Version=6.1.1.0010 11-Jul-12 19:00
000010.060|ssps ||03|Application, comp. 1: P/N=3150-11580-611.
000010.060|pps ||03|Initial log entry. Current logging level 4
000010.060|sip ||03|Initial log entry. Current logging level 4
000010.062|ptt ||03|Initial log entry. Current logging level 4
000010.362|so ||03|Using TCP IP Media Port, configured initial RTP port 2222
000010.390|sshc ||03|Initial log entry. Current logging level 4
000010.396|cmp ||03|Initial log entry. Current logging level 4
000010.396|wmgr ||03|Initial log entry. Current logging level 4
000010.406|slog ||03|Initial log entry. Current logging level 3
000010.598|app1 ||03|Initial log entry. Current logging level 4
000010.600|app1 |4|03|Default StatusBar is disabled
000010.602|app1 |4|03|mb.main.home parameter is empty
000010.606|mb ||03|Initial log entry. Current logging level 4
000010.684|ldap ||03|Initial log entry. Current logging level 4
000010.684|ldap |4|03|cDynamicData::cDynamicData:cDynamicData:Failed
000010.712|efk ||03|Initial log entry. Current logging level 4
000010.770|app1 |4|03|[AppUserLoginC::Init]:flushing user cache file failed
000011.362|utilm|4|03|uBLFCompressed: File /ffs0/local/local-directory_xml.zzz does not exist or is empty
000019.146|cfg ||03|RT|cfgRtNetInterfaceUpdate: Network not initialized
000022.658|cfg ||03|RT| Phone IP address is 10.124.254.36.
000022.660|cfg ||03|RT| Subnet mask is 255.255.255.0.
000022.660|cfg ||03|RT| Gateway address is 10.124.254.1.
000022.660|cfg ||03|RT| DNS server is 10.1.0.10.
000022.660|cfg ||03|RT| DNS alternate server is 10.1.0.11.
000022.660|cfg ||03|RT| Time server is XX.XX.XX.XX
000022.664|dns ||03|DNS resolver servers are ‘10.1.0.10’ ‘10.1.0.11’
000022.664|dns ||03|DNS resolver search domain is ‘’
000022.666|cfg ||03|RT|Primary IP changed to 10.124.254.36 subnet mask 255.255.255.0
000022.666|cfg ||03|RT|cfgRtNetInterfaceUpdate: bfeng – calling network status callback
000022.666|cfg ||03|RT|cfgRtNetInterfaceUpdate: bfeng – calling network status callback
000022.668|cfg ||03|RT| Phone IP address is 10.124.254.36.
000022.668|cfg ||03|RT| Subnet mask is 255.255.255.0.
000022.668|cfg ||03|RT| Gateway address is 10.124.254.1.
000022.668|cfg ||03|RT| DNS server is 10.1.0.10.
000022.668|cfg ||03|RT| DNS alternate server is 10.1.0.11.
000022.670|cfg ||03|RT| Time server is XX.XX.XX.XX
000022.702|sys ||03|0x95869280 (tDhcpcStateTask): arp_check: No reply, addr not used
000022.742|so ||03|Network initialized. Starting network tasks.
000022.742|log ||03|Install file upload callback for ‘so’

000022.780|sip ||03|Fast Boot Measurement Point: Ready for Call, uptime: 22.780 sec.
000022.800|app1 |5|03|Corporate directory instance does not exists.
000023.104|cfg ||03|Prov|Starting to update polycom/2/2345-12360-001.sip.ld
0708172457|log |4|03|UtilLogC::uploadFifoLog: upload error. protocol 0 result = -1
0708172458|cfg |4|03|Prov|Provisioning failed due to curl error code:78 and respCode:550
0708172458|cfg |4|03|Prov|Provisioning failed due to curl error code:78 and respCode:550
0708172458|cfg ||03|Prm|0004f2c3a1f7-features.cfg: Value 500 for configuration parameter dir.local.contacts.maxNum is too large, using 99, the maximum allowed
0708172459|app1 |4|03|[AppHybridC::procCfgParamChange] unexpected element param Id=(39)
0708172459|so ||03|soCodecConfig: Explicitly Adding codecG722 for PTT
0708172459|sip ||03|SipUserRemove 0
0708172459|dns |4|03|doDnsLookupForList: given NULL hostname in task tPktProSys
0708172459|sip |4|03|doDnsListLookup(udp): doDnsSrvLookupForARecordList ‘10.124. 254.3’ found no records
0708172459|sip |4|03|Registration failed User: 8888, Error Code:480 Temporarily not available
0708172459|cfg ||03|RT| Phone IP address is 10.124.254.36.
0708172459|cfg ||03|RT| Subnet mask is 255.255.255.0.
0708172459|cfg ||03|RT| Gateway address is 10.124.254.1.
0708172459|cfg ||03|RT| DNS server is 10.1.0.10.
0708172459|cfg ||03|RT| DNS alternate server is 10.1.0.11.
0708172459|cfg ||03|RT| GMT offset is -21600 seconds.
0708172459|so |4|03|Core Audio: Instruction 1 chord 0 of sound effect Message waiting not found
0708172459|so |4|03|Core Audio: Instruction 2 chord 0 of sound effect Message waiting not found
0708172459|so |4|03|Core Audio: Instruction 3 chord 0 of sound effect Message waiting not found
0708172459|cfg ||03|Prm|Restarting because of parameter change
0708172459|app1 |6|03|Manual Restart
0708172459|cfg ||03|Prov|Setting device parameters from configuration files.
0708172459|cfg ||03|Prov|Finished updating configuration
0708172459|utilm|4|03|uBLFCompressed: File /ffs0/local/local-directory_xml.zzz does not exist or is empty
0708172459|utilm|4|03|uBLFCompressed: File /ffs0/local/local-directory_xml.zzz does not exist or is empty
0708172500|cfg ||03|Prov|Starting to update polycom/2/2345-12360-001.sip.ld
0708172500|log |4|03|UtilLogC::uploadFifoLog: upload error. protocol 0 result = -1
0708112501|dns |4|03|doDnsLookupForList: given NULL hostname in task tSntpGet
0708112501|cfg |4|03|Prov|Provisioning failed due to curl error code:78 and respCode:550
0708112501|cfg |4|03|Prov|Provisioning failed due to curl error code:78 and respCode:550
0708112501|cfg ||03|Prov|Setting device parameters from configuration files.
0708112501|cfg ||03|Prov|Finished updating configuration
0708112501|so ||03|SoNcasC::procMsg: Client service shutdown complete
0708112501|log |4|03|UtilLogC::uploadFifoLog: upload error. protocol 0 result = -1
0708112501|wdog ||03|Watchdog Expired: tSupObjs
000007.368|log ||03|---------- Initial log entry ----------
000007.368|so ||03|Platform: Model=SoundPoint IP 321, Assembly=2345-12360-001 Rev=C Region=
000007.368|so ||03|Platform: Interface eth0 MAC=0004f2c3a1f7
000007.368|so ||03|Platform: BootBlock=3.0.2.0024 (12360-001) 30-Nov-10 14:56
000007.370|so ||03|Platform: Updater=5.0.15.0741 05-Feb-20 20:04
000007.370|so ||03|Application, main: Label=SIP, Version=Mink 4.0.15.1009 07-Feb-20 12:56
000007.370|so ||03|Application, main: P/N=3150-11530-409
000007.370|rdisk||03|RAM disk created, size: 4,194,304 bytes
000007.370|ocsp ||03|O.C.S.P. Enabled = 0
000007.372|tls ||03|Initial log entry. Current logging level 4
000007.434|pmt ||03|Initial log entry. Current logging level 4
000007.436|wdog ||03|Initial log entry. Current logging level 4
000007.438|ethf ||03|Initial log entry. Current logging level 4
000007.438|hw ||03|Initial log entry. Current logging level 4
000007.438|ares ||03|Initial log entry. Current logging level 4
000007.438|dns ||03|Initial log entry. Current logging level 4
000007.438|cfg ||03|Initial log entry. Current logging level 4
000007.440|dot1x||03|Initial log entry. Current logging level 4
000007.444|cfg |5|03|RT|Error installing DHCP event hook.
000007.506|lic ||03|Initial log entry. Current logging level 4
000007.506|lic |4|03|cfgCfsFlashKeyScratchLoad: key is blank
000007.550|curl ||03|Initial log entry. Current logging level 4
000007.550|utilm||03|Initial log entry. Current logging level 4
000007.550|copy ||03|Initial log entry. Current logging level 4
000007.550|rtos ||03|Initial log entry. Current logging level 4
000007.552|sec ||03|Initial log entry. Current logging level 4
000007.580|so ||03|Configuration files: 0004f2c3a1f7-features.cfg, 0004f2c3a1f7-8888.cfg, 0004f2c3a1f7-sip-interop.cfg
000007.580|so ||03|Configuration file “0004f2c3a1f7-features.cfg” SHA1 digest: 0D779A19AFDA7A1921E8DA307F8807220CF207C5
000007.580|so ||03|Configuration file “0004f2c3a1f7-8888.cfg” SHA1 digest: AE2806029187D85E56667A1B2281151025718229
000007.580|so ||03|Configuration file “0004f2c3a1f7-sip-interop.cfg” SHA1 digest: C1568D3AFCBB9E328069917420C35529DC3FF79F
000007.580|cfg |4|03|Prm|Configuration file(s) statistics: 1 parameter values were used but were out of range. 27 were invalid and ignored.
000007.630|log ||03|Log render level set to 1
000007.760|srtp ||03|Initial log entry. Current logging level 4
000007.762|res ||03|Initial log entry. Current logging level 4
000007.766|httpa||03|Initial log entry. Current logging level 4
000007.766|lldp ||03|Initial log entry. Current logging level 4
000007.766|cdp ||03|Initial log entry. Current logging level 4
000007.768|sys ||03|Initial log entry. Current logging level 4
000007.834|ssps ||03|Initial log entry. Current logging level 4
000007.836|so ||03|soCodecConfig: Explicitly Adding codecG722 for PTT
000010.268|so ||03|System Info Reports:
000010.268|so ||03| CPU is TNETV1057/C55x, rev 2 running at 87.500MHz with memory at 87.500MHz.
000010.268|so ||03| Board is identified as PolycomSoundPointIP-SPIP_321.
000010.268|so ||03| DRAM_LO: 0x94000000. DRAM_SIZE: 32 MB
000010.268|so ||03| Clocks are VBUSP: 87.500MHz, VBUS: 75.000MHz, USB: 25.000MHz, LCD: 87.500MHz, DSP: 87.500MHz.
000010.268|so ||03| NOR flash detected is 9
000010.268|key ||03|Initial log entry. Current logging level 4
000010.274|httpd||03|Initial log entry. Current logging level 4
000010.276|poll ||03|Initial log entry. Current logging level 4
000010.276|push ||03|Initial log entry. Current logging level 4
000010.276|poll ||03|Initial log entry. Current logging level 4
000010.276|poll ||03|Initial log entry. Current logging level 4
000010.276|poll ||03|Initial log entry. Current logging level 4
000010.278|poll ||03|Initial log entry. Current logging level 4
000010.278|poll ||03|Initial log entry. Current logging level 4
000010.278|ht ||03|Initial log entry. Current logging level 4
000010.278|dbuf ||03|Initial log entry. Current logging level 4
000010.282|ssps ||03|Application, comp. 1: Label=PolyDSP Titan Mem1 FS4, Version=6.1.1.0010 11-Jul-12 19:00
000010.282|ssps ||03|Application, comp. 1: P/N=3150-11580-611.
000010.282|pps ||03|Initial log entry. Current logging level 4
000010.282|sip ||03|Initial log entry. Current logging level 4
000010.284|ptt ||03|Initial log entry. Current logging level 4
000010.388|so |4|03|Core Audio: Instruction 1 chord 0 of sound effect Message waiting not found
000010.388|so |4|03|Core Audio: Instruction 2 chord 0 of sound effect Message waiting not found
000010.388|so |4|03|Core Audio: Instruction 3 chord 0 of sound effect Message waiting not found
000010.436|so |4|03|Core Audio: Instruction 1 chord 0 of sound effect Message waiting not found
000010.436|so |4|03|Core Audio: Instruction 2 chord 0 of sound effect Message waiting not found
000010.436|so |4|03|Core Audio: Instruction 3 chord 0 of sound effect Message waiting not found
000010.576|so ||03|Using TCP IP Media Port, configured initial RTP port 2222
000010.614|sshc ||03|Initial log entry. Current logging level 4
000010.618|cmp ||03|Initial log entry. Current logging level 4
000010.618|wmgr ||03|Initial log entry. Current logging level 4
000010.632|slog ||03|Initial log entry. Current logging level 3
000010.822|app1 ||03|Initial log entry. Current logging level 4
000010.822|app1 |4|03|Default StatusBar is disabled
000010.826|app1 |4|03|mb.main.home parameter is empty
000010.830|mb ||03|Initial log entry. Current logging level 4
000010.918|ldap ||03|Initial log entry. Current logging level 4
000010.918|ldap |4|03|cDynamicData::cDynamicData:cDynamicData:Failed
000010.946|efk ||03|Initial log entry. Current logging level 4
000011.044|app1 |4|03|[AppUserLoginC::Init]:flushing user cache file failed
000011.558|utilm|4|03|uBLFCompressed: File /ffs0/local/local-directory_xml.zzz does not exist or is empty
000019.146|cfg ||03|RT|cfgRtNetInterfaceUpdate: Network not initialized
000021.664|cfg ||03|RT| Phone IP address is 10.124.254.36.
000021.666|cfg ||03|RT| Subnet mask is 255.255.255.0.
000021.666|cfg ||03|RT| Gateway address is 10.124.254.1.
000021.666|cfg ||03|RT| DNS server is 10.1.0.10.
000021.666|cfg ||03|RT| DNS alternate server is 10.1.0.11.
000021.666|cfg ||03|RT| GMT offset is -21600 seconds.
000021.668|dns ||03|DNS resolver servers are ‘10.1.0.10’ ‘10.1.0.11’
000021.670|dns ||03|DNS resolver search domain is ‘’
000021.672|cfg ||03|RT|Primary IP changed to 10.124.254.36 subnet mask 255.255.255.0
000021.672|cfg ||03|RT|cfgRtNetInterfaceUpdate: bfeng – calling network status callback
000021.672|cfg ||03|RT|cfgRtNetInterfaceUpdate: bfeng – calling network status callback
000021.674|cfg ||03|RT| Phone IP address is 10.124.254.36.
000021.674|cfg ||03|RT| Subnet mask is 255.255.255.0.
000021.674|cfg ||03|RT| Gateway address is 10.124.254.1.
000021.674|cfg ||03|RT| DNS server is 10.1.0.10.
000021.674|cfg ||03|RT| DNS alternate server is 10.1.0.11.
000021.674|cfg ||03|RT| GMT offset is -21600 seconds.
000021.706|sys ||03|0x958648d0 (tDhcpcStateTask): arp_check: No reply, addr not used
000021.742|so ||03|Network initialized. Starting network tasks.
000021.742|log ||03|Install file upload callback for ‘so’

000021.790|app1 |5|03|Corporate directory instance does not exists.
000021.862|dns |4|03|doDnsLookupForList: given NULL hostname in task tPktProSys
000021.862|sip |4|03|doDnsListLookup(udp): doDnsSrvLookupForARecordList ‘10.124. 254.3’ found no records
000021.864|sip |4|03|Registration failed User: 8888, Error Code:480 Temporarily not available
000021.876|sip ||03|Fast Boot Measurement Point: Ready for Call, uptime: 21.876 sec.
000022.192|cfg ||03|Prov|Starting to update polycom/2/2345-12360-001.sip.ld
000022.208|dns |4|03|doDnsLookupForList: given NULL hostname in task tSntpGet
0708112532|cfg |4|03|Prov|Provisioning failed due to curl error code:78 and respCode:550
0708112532|cfg |4|03|Prov|Provisioning failed due to curl error code:78 and respCode:550
0708112532|cfg ||03|Prm|0004f2c3a1f7-features.cfg: Value 500 for configuration parameter dir.local.contacts.maxNum is too large, using 99, the maximum allowed
0708112532|cfg ||03|Prov|Setting device parameters from configuration files.
0708112532|cfg ||03|Prov|Finished updating configuration
0708112532|utilm|4|03|uBLFCompressed: File /ffs0/local/local-directory_xml.zzz does not exist or is empty
0708112532|utilm|4|03|uBLFCompressed: File /ffs0/local/local-directory_xml.zzz does not exist or is empty
0708112532|cfg ||03|Prov|Starting to update polycom/2/2345-12360-001.sip.ld
0708112533|cfg |4|03|Prov|Provisioning failed due to curl error code:78 and respCode:550
0708112533|cfg |4|03|Prov|Provisioning failed due to curl error code:78 and respCode:550
0708112534|cfg ||03|Prov|Setting device parameters from configuration files.
0708112534|cfg ||03|Prov|Finished updating configuration
0708112606|sip |4|03|doDnsListLookup(udp): doDnsSrvLookupForARecordList ‘10.124. 254.3’ found no records
0708112606|sip |4|03|Registration failed User: 8888, Error Code:480 Temporarily not available
0708112614|cfg |4|03|Web|[cfgSaProcessRequestC] Failed to download language file from provisioning server, request path Website_dictionary_language_en-us.xml
0708112614|utilm|4|03|uBLFCompressed: File /ffs0/languages/Website_dictionary_language_en-us.xml.zzz does not exist or is empty
0708112614|cfg |4|03|Web|[cfgSaProcessRequestC] Website_dictionary_language_en-us.xml Language file doesn’t exist in cache
0708112614|cfg |4|03|Web|[cfgSaProcessRequestC] Website_dictionary_language_en-us.xml Language file doesn’t exist in phone flash

Any help would be greatly appreciated.

Stewart1 · July 8, 2022, 5:32pm

This may be an artifact of the Polycom logging or of the forum, but if the server address you entered into the phone really does have a space before the 254, that could explain your issue.

I don’t know when (if ever) Asterisk would send a 480 response to REGISTER. Does anything appear in the Asterisk log when the phone attempts to register?

jbj92 · July 8, 2022, 5:40pm

Thank you for your response Stewart. I don’t know why that space is showing up before the 254. I will look into that.

As far as the asterisk log, are you referring to /var/log/asterisk/full?

Stewart1 · July 8, 2022, 5:42pm

Yes, At the Asterisk command prompt, type
pjsip set logger on
or
sip set debug on
according to extension type, then paste the relevant section of the log at pastebin.freepbx.org and post the link here.

jbj92 · July 8, 2022, 5:44pm

Nothing comes up in /var/log/asterisk/full when I am attempting to register. I have been attempting to register while having two sessions up. One session with ‘tail -f /var/log/vsftpd.log’ and one with ‘tail -f /var/log/asterisk/full’.

I get no output regarding phone registration in the full log. I see what I showed earlier in the vsftpd.log. I’ll run the pjsip set logger now.

jbj92 · July 8, 2022, 5:58pm

I just factory reset the phone with pjsip set logger on.

Like last time, I see output in vsftpd.log but I still don’t see anything even with pjsip set logger. I have the output and I did not find the address of the phone I am working with which is 10.124.254.36. There is quite a lot of output, would you still like me to post that?

Yeah, I have 21,000 lines of output and the phone’s address is nowhere to be found in this output.

rsmithuk · July 8, 2022, 6:20pm

If you’re not seeing registration attempts there is either an issue with the config or possibly a firewall issue.

The phone log shows that it’s pulling the config files OK but failing to register. It’s either trying to register against the wrong IP or like I say the firewall is blocking.

Can you try disabling the firewall temporarily?

jbj92 · July 8, 2022, 6:30pm

Stewart saw something earlier where there was a space in the IP of the address the phone is trying to register. It actually did have a space in endpoint manager global settings. I removed the space, rebooted the pbx, factory reset the phone and am still not getting registration. I will disable the firewall and try that now.

jbj92 · July 8, 2022, 6:35pm

Phone still did not register after disabling the firewall.

jbj92 · July 8, 2022, 6:38pm

I did a packet capture on my attempt before disabling the firewall. I didn’t see any sip packets coming from the phone to the pbx.

jbj92 · July 8, 2022, 6:43pm

I currently have three polycoms on the same network that are on the audiocodes that are working. In my last packet capture, when I filter for sip packets, I only see the audiocodes talking to the pbx server. I don’t see any of the polycom’s ips talking to the server via sip. Two of them have extesion mappings so they should be talking via sip, correct?

rsmithuk · July 8, 2022, 6:52pm

Yes I would expect to see SIP packets from the phones.

Have you logged in to any of the phones to check the config i.e Username/Password etc. is in the phone?

jbj92 · July 8, 2022, 6:59pm

I looked at the logs of the phone again and saw that it still was looking for 10.124. 254.3, it still had the space in front of 254. I double checked pbx to make sure that it was correct everywhere. I factory reset the phone and it is now reachable. I think the issue was that it was trying to get to 10.124. 254.3 instead of 10.124.254.3.

jbj92 · July 8, 2022, 7:10pm

Thanks for your help Stewart, this ended up being the issue.

jbj92 · July 8, 2022, 7:10pm

Thank you for your help Richard, I appreciate it.

lgaetz · July 8, 2022, 7:19pm

If you make any changes to system config, in this case EPM Global Settings, then you must rebuild the phone config and then reprovision the phones. I suspect that after fixing the error in global settings the phone config files were not rebuilt prior to the phone being re-provisioned.

system · July 15, 2022, 7:20pm

This topic was automatically closed 7 days after the last reply. New replies are no longer allowed.