I posted this to the SNOM forums, but there’s very little activity there, especially by SNOM staff. So I’m coming to this forum because you guys are awesome.
I’ve been forced to try the 8.7.4.8 beta firmware on my Snom 870 because an update of our Snom Visions to 1.2.5 (from 1.1.8) broke our 870’s on 8.7.3.19/8.7.3.25 (previous and current stable releases), and Vision 1.3.6 beta wouldn’t pair with the latest “stable” release (8.7.3.25). I’m on FreePBX 2.9.0.12. Now every call (extension or outside call) results in a disconnect after exactly 6 seconds.
The update did fix the initial issue (the 870s would get stuck in reboot loops or hang randomly), but now it disconnects after 6 seconds, every call. Incoming calls are fine (so far), not disconnecting for >1 minute (that’s all I tested for). This extension was working just fine before the update. I tried rebooting the 870 and the FreePBX box, no dice. Luckily I only did the update on one 870/Vision pair.
Here’s the log from the phone for one disconnected call:
21/10/2013 19:16:07 [NOTICE] LID: CAudioSpirit::SetVolume: 26214 of 8 Ohm speaker
21/10/2013 19:16:11 [NOTICE] SIP: getInternalSdpFmts: Skipped Codec g723 is not supported for ptime of 20
21/10/2013 19:16:11 [WARN ] SIP: process_registrar_packet: 401 needs 128 bit nonce
21/10/2013 19:16:11 [NOTICE] SIP: process auth: Match challenge for user=201, realm=asterisk
21/10/2013 19:16:12 [NOTICE] LID: CAudioSpirit::SetVolume: 26214 of 8 Ohm speaker
21/10/2013 19:16:15 [CRITIC] SIP: Process timer without requiring timer
21/10/2013 19:16:15 [NOTICE] SIP: RTP: set_destination RP6 adr:19096=71.XXX.XXX.XXX
21/10/2013 19:16:15 [NOTICE] LID: CAudioSpirit::SetVolume: 26214 of 8 Ohm speaker
21/10/2013 19:16:21 [NOTICE] SIP: RTP: set_destination RP6 adr=
21/10/2013 19:16:23 [NOTICE] PHN: Fetching URL: snom://mb_exit
Here’s the log from a call to the non-working 870 from working 870:
21/10/2013 19:50:48 [NOTICE] LID: CAudioSpirit::SetVolume: 43690 of 8 Ohm speaker
21/10/2013 19:50:49 [NOTICE] LID: CAudioSpirit::SetVolume: 39321 of 8 Ohm speaker
21/10/2013 19:50:53 [NOTICE] PHN: SDP: Skipped Codec G723 is not supported for 20 ms packets
21/10/2013 19:50:53 [WARN ] PHN: SIP: process_registrar_packet: 401 needs 128 bit nonce
21/10/2013 19:50:53 [NOTICE] PHN: SIP: process auth:Match challenge for user=202, realm=asterisk
21/10/2013 19:50:53 [NOTICE] GUI: Sending post request http://192.168.1.225:80/ExtensionGuiModule/actionUrlListener?local=202%40192.168.1.150&remote=201&active_url=202%40192.168.1.150&active_user=202&active_host=192.168.1.150&csta_id=9&action=outgoing_call&led_nr=&led_freq=&led_color=
21/10/2013 19:50:53 [NOTICE] PHN: Fetching URL: http://192.168.1.225:80/ExtensionGuiModule/actionUrlListener?local=202%40192.168.1.150&remote=201&active_url=202%40192.168.1.150&active_user=202&active_host=192.168.1.150&csta_id=9&action=outgoing_call&led_nr=&led_freq=&led_color=
21/10/2013 19:50:53 [NOTICE] LID: CAudioSpirit::SetVolume: 39321 of 8 Ohm speaker
21/10/2013 19:50:58 [CRITIC] PHN: SIP: Process timer without requiring timer
21/10/2013 19:50:58 [NOTICE] PHN: RTP: set_destination RP29 adr:13006=71.XXX.XXX.XXX
21/10/2013 19:50:58 [NOTICE] GUI: Sending post request http://192.168.1.225:80/ExtensionGuiModule/actionUrlListener?local=202%40192.168.1.150&remote=201&active_url=202%40192.168.1.150&active_user=202&active_host=192.168.1.150&csta_id=9&action=connected&led_nr=&led_freq=&led_color=
21/10/2013 19:50:58 [NOTICE] PHN: Fetching URL: http://192.168.1.225:80/ExtensionGuiModule/actionUrlListener?local=202%40192.168.1.150&remote=201&active_url=202%40192.168.1.150&active_user=202&active_host=192.168.1.150&csta_id=9&action=connected&led_nr=&led_freq=&led_color=
21/10/2013 19:50:58 [NOTICE] LID: CAudioSpirit::SetVolume: 39321 of 8 Ohm speaker
21/10/2013 19:51:15 [NOTICE] LID: CAudioSpirit::SetVolume: 65535 of 8 Ohm speaker
21/10/2013 19:51:16 [NOTICE] GUI: Sending post request http://192.168.1.225:80/ExtensionGuiModule/actionUrlListener?local=202%40192.168.1.150&remote=201&active_url=202%40192.168.1.150&active_user=202&active_host=192.168.1.150&csta_id=9&action=disconnected&led_nr=&led_freq=&led_color=
21/10/2013 19:51:16 [NOTICE] PHN: Fetching URL: http://192.168.1.225:80/ExtensionGuiModule/actionUrlListener?local=202%40192.168.1.150&remote=201&active_url=202%40192.168.1.150&active_user=202&active_host=192.168.1.150&csta_id=9&action=disconnected&led_nr=&led_freq=&led_color=
21/10/2013 19:51:16 [NOTICE] LID: CAudioSpirit::SetVolume: 39321 of 8 Ohm speaker
I have no experience reading these logs, but the only thing that occurs to me is that in the bad phone’s log, I see two RTP RP6 destination adr’s 6 seconds apart, one to my WAN IP address, the other to blank:
21/10/2013 19:16:15 [NOTICE] SIP: RTP: set_destination RP6 adr:19096=71.XXX.XXX.XXX
21/10/2013 19:16:21 [NOTICE] SIP: RTP: set_destination RP6 adr=
Whereas on the working phone, there’s only one RTP destination set to RP29
21/10/2013 19:50:58 [NOTICE] PHN: RTP: set_destination RP29 adr:13006=71.XXX.XXX.XXX
Could this be the problem? Am I way off? My port forwards cover the 10000-20000 range. I compared settings - every single setting - on this 870 that disconnects with another 870 that is on 8.7.3.19 that is working, and there are no differences that I can see at all. I’ve had similar disconnects when I had port forwarding issues on another installation, but it’s just this one 870 that’s having disconnection issues. I’m pulling out my hair.
Any help would be greatly appreciated.
David