The softphone works fine but the ATA device no

Hello people, from almost two weeks, I’m trying to figure out what happen with asterisk because if I connect a softphone to any extension, example 1004 it works fine, but when I replace with an ATA device (GrandStream 487) it do not works anymore.

I have asterisk/freepbx inside a lxc container with the ip 10.0.8.115 so I set a NAT to communicate with the external ip 191.9.82.189, I use the port 5086 instead 5060.

The GrandStream and even the softphone is in 190.22.84.117 and because it is behind a router I placed it on DMZ.
The IP assigned by the router to the grandstream is 192.168.1.4.

Please let me share the log perhaps you can find something that I wasn’t able:

[2014-09-02 04:02:35] NOTICE[5387] chan_sip.c: Peer '1004' is now UNREACHABLE! Last qualify: 198
[2014-09-02 04:02:35] DEBUG[5387] chan_sip.c: Destroying SIP dialog [email protected]:5086
[2014-09-02 04:02:35] VERBOSE[5387] chan_sip.c: Really destroying SIP dialog '[email protected]:5086' Method: OPTIONS
[2014-09-02 04:02:35] DEBUG[5362] devicestate.c: No provider found, checking channel drivers for SIP - 1004
[2014-09-02 04:02:35] DEBUG[5362] chan_sip.c: Checking device state for peer 1004
[2014-09-02 04:02:35] DEBUG[5362] devicestate.c: Changing state for SIP/1004 - state 5 (Unavailable)
[2014-09-02 04:02:35] DEBUG[5362] devicestate.c: device 'SIP/1004' state '5'
[2014-09-02 04:02:35] DEBUG[5364] devicestate.c: Checking if I can find provider for "Custom" - number: DND1004
[2014-09-02 04:02:35] DEBUG[5364] devicestate.c: Checking provider Custom with Custom
[2014-09-02 04:02:35] DEBUG[5397] app_queue.c: Device 'SIP/1004' changed to state '5' (Unavailable) but we don't care because they're not a member of any queue.
[2014-09-02 04:02:35] DEBUG[5364] db.c: Unable to find key 'DND1004' in family 'CustomDevstate'
[2014-09-02 04:02:35] DEBUG[5364] app_queue.c: Extension '1004@ext-local' changed to state '5' (Unavailable)
[2014-09-02 04:02:44] DEBUG[16659] manager.c: Running action 'Login'
[2014-09-02 04:02:45] DEBUG[5387] chan_sip.c: Allocating new SIP dialog for [email protected]:5086 - OPTIONS (No RTP)
[2014-09-02 04:02:45] DEBUG[5387] acl.c: For destination '190.22.84.117', our source address is '10.0.8.115'.
[2014-09-02 04:02:45] DEBUG[5387] chan_sip.c: Target address 190.22.84.117:17942 is not local, substituting externaddr
[2014-09-02 04:02:45] DEBUG[5387] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 191.9.82.129:5086
[2014-09-02 04:02:45] DEBUG[5387] chan_sip.c: SIP call-id changed from '[email protected]:5086' to '[email protected]:5086'
[2014-09-02 04:02:45] DEBUG[5387] chan_sip.c: Initializing initreq for method OPTIONS - callid [email protected]:5086
[2014-09-02 04:02:45] DEBUG[5387] chan_sip.c: Header 0 [ 42]: OPTIONS sip:[email protected]:17942 SIP/2.0
[2014-09-02 04:02:45] DEBUG[5387] chan_sip.c: Header 1 [ 64]: Via: SIP/2.0/UDP 191.9.82.129:5086;branch=z9hG4bK77acd6d9;rport
[2014-09-02 04:02:45] DEBUG[5387] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70
[2014-09-02 04:02:45] DEBUG[5387] chan_sip.c: Header 3 [ 63]: From: "Unknown" <sip:[email protected]:5086>;tag=as11f391d7
[2014-09-02 04:02:45] DEBUG[5387] chan_sip.c: Header 4 [ 32]: To: <sip:[email protected]:17942>
[2014-09-02 04:02:45] DEBUG[5387] chan_sip.c: Header 5 [ 41]: Contact: <sip:[email protected]:5086>
[2014-09-02 04:02:45] DEBUG[5387] chan_sip.c: Header 6 [ 60]: Call-ID: [email protected]:5086
[2014-09-02 04:02:45] DEBUG[5387] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS
[2014-09-02 04:02:45] DEBUG[5387] chan_sip.c: Header 8 [ 34]: User-Agent: FPBX-12.0.1rc5(11.7.0)
[2014-09-02 04:02:45] DEBUG[5387] chan_sip.c: Header 9 [ 35]: Date: Tue, 02 Sep 2014 07:02:45 GMT
[2014-09-02 04:02:45] DEBUG[5387] chan_sip.c: Header 10 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
[2014-09-02 04:02:45] DEBUG[5387] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer
[2014-09-02 04:02:45] VERBOSE[5387] chan_sip.c: Reliably Transmitting (NAT) to 190.22.84.117:17942:
[2014-09-02 04:02:45] DEBUG[5387] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #229586
[2014-09-02 04:02:45] DEBUG[5387] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 190.22.84.117:17942
[2014-09-02 04:02:46] DEBUG[5387] chan_sip.c: SIP TIMER: Not rescheduling id #229586:OPTIONS (Method 3) (No timer T1)
[2014-09-02 04:02:46] VERBOSE[5387] chan_sip.c: Retransmitting #1 (NAT) to 190.22.84.117:17942:
[2014-09-02 04:02:46] DEBUG[5387] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 190.22.84.117:17942
[2014-09-02 04:02:47] DEBUG[5387] chan_sip.c: SIP TIMER: Not rescheduling id #229586:OPTIONS (Method 3) (No timer T1)
[2014-09-02 04:02:47] VERBOSE[5387] chan_sip.c: Retransmitting #2 (NAT) to 190.22.84.117:17942:
[2014-09-02 04:02:47] DEBUG[5387] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 190.22.84.117:17942
[2014-09-02 04:02:48] DEBUG[5387] chan_sip.c: SIP TIMER: Not rescheduling id #229586:OPTIONS (Method 3) (No timer T1)
[2014-09-02 04:02:48] VERBOSE[5387] chan_sip.c: Retransmitting #3 (NAT) to 190.22.84.117:17942:
[2014-09-02 04:02:48] DEBUG[5387] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 190.22.84.117:17942
[2014-09-02 04:02:49] DEBUG[5387] chan_sip.c: SIP TIMER: Not rescheduling id #229586:OPTIONS (Method 3) (No timer T1)
[2014-09-02 04:02:49] VERBOSE[5387] chan_sip.c: Retransmitting #4 (NAT) to 190.22.84.117:17942:
[2014-09-02 04:02:49] DEBUG[5387] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 190.22.84.117:17942
[2014-09-02 04:02:49] DEBUG[5387] chan_sip.c: Destroying SIP dialog [email protected]:5086
[2014-09-02 04:02:49] VERBOSE[5387] chan_sip.c: Really destroying SIP dialog '[email protected]:5086' Method: OPTIONS
[2014-09-02 04:02:55] DEBUG[5387] chan_sip.c: Auto destroying SIP dialog '[email protected]'
[2014-09-02 04:02:55] DEBUG[5387] chan_sip.c: Destroying SIP dialog [email protected]
[2014-09-02 04:02:55] VERBOSE[5387] chan_sip.c: Really destroying SIP dialog '[email protected]' Method: REGISTER

Any suggestion is really appreciate.

Thanks.

Hello,

Did you found any solution on this? I have almost the same issue. Softphones (like Zoiper) works fine, Cisco 8821 becoming UNREACHABLE right after its registration try.

Thanks for your time

I’d start by getting a packet trace, and try to capture the sip registration transaction. It would help to see a trace of both the softphone, and the ata for comparison.
You can do this from the asterisk command line with:

freepbxCLI> pjsip set logger host ip_of_device
or
freepbx
CLI> sip set debug ip ip_of_device

Or, if there’s too much activity flying by from your acli, you can capture the traffic to a file and view it in a program like wireshark.
https://wiki.sangoma.com/display/PPS/Capture+TCPDumps

Typically, you can start the capture and restart the ata/softphone to force a registration, then kill the capture. If you share the output here, let us know the ip of the pbx, ip of the ata, and ip of the softphone so we know we’re looking at the right transaction if an ip wasn’t specified.

Hello,

Thanks for your quick response to our issue. Please find attached the pcap pcaps.tgz (11.9 KB)
files you mentioned (one from the Zoiper softphone which works fine, and three more captured from 8821 with the issue) . Also below there is the debug output from asterisk with the registration witch becoming unreachable. Please take a look into them and let me know if you can notice something weird. My 8821 ip is: 192.168.4.2 Ext: 231 and Freepbx is: 192.168.0.78

P/S: Softphone and/or Cisco SPA525g2 are working fine through 192.168.4.0/24 subnet :(((

Once again thanks for your time

<--- SIP read from UDP:192.168.4.2:5060 --->
REGISTER sip:192.168.0.78 SIP/2.0
Via: SIP/2.0/UDP 192.168.4.2:5060;branch=z9hG4bK61d5819b
From: <sip:[email protected]>;tag=7018a717c7460e380143e597-0e915b76
To: <sip:[email protected]>
Call-ID: [email protected]
Max-Forwards: 70
Session-ID: a1dc650e00105000a0007018a717c746;remote=00000000000000000000000000000000
Date: Tue, 31 Mar 2020 11:22:27 GMT
CSeq: 1238 REGISTER
User-Agent: Cisco-CP8821/11.0.5
Contact: <sip:[email protected]:5060;user=phone;transport=udp>;+sip.instance="<urn:uuid:00000000-0000-0000-0000-7018a717c746>";+u.sip!devicename.ccm.cisco.com="SEP7018A717C746";+u.sip!model.ccm.cisco.com="36216"
Supported: replaces,join,sdp-anat,norefersub,resource-priority,extended-refer,X-cisco-callinfo,X-cisco-serviceuri,X-cisco-escapecodes,X-cisco-service-control,X-cisco-srtp-fallback,X-cisco-monrec,X-cisco-config,X-cisco-sis-7.0.0,X-cisco-xsi-8.5.1
Content-Length: 0
Reason: SIP;cause=200;text="cisco-alarm:14 Name=SEP7018A717C746 ActiveLoad=sip8821.11-0-5SR2-2.loads InactiveLoad=sip8821.11-0-4-14.loads Last=cm-closed-tcp"
Expires: 3600

<------------->
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header  0 [ 33]: REGISTER sip:192.168.0.78 SIP/2.0
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header  1 [ 56]: Via: SIP/2.0/UDP 192.168.4.2:5060;branch=z9hG4bK61d5819b
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header  2 [ 66]: From: <sip:[email protected]>;tag=7018a717c7460e380143e597-0e915b76
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header  3 [ 26]: To: <sip:[email protected]>
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header  4 [ 56]: Call-ID: [email protected]
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header  5 [ 16]: Max-Forwards: 70
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header  6 [ 84]: Session-ID: a1dc650e00105000a0007018a717c746;remote=00000000000000000000000000000000
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header  7 [ 35]: Date: Tue, 31 Mar 2020 11:22:27 GMT
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header  8 [ 19]: CSeq: 1238 REGISTER
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header  9 [ 31]: User-Agent: Cisco-CP8821/11.0.5
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header 10 [209]: Contact: <sip:[email protected]:5060;user=phone;transport=udp>;+sip.instance="<urn:uuid:00000000-0000-0000-0000-7018a717c746>";+u.sip!devicename.ccm.cisco.com="SEP7018A717C746";+u.sip!model.ccm.cisco.com="36216"
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header 11 [245]: Supported: replaces,join,sdp-anat,norefersub,resource-priority,extended-refer,X-cisco-callinfo,X-cisco-serviceuri,X-cisco-escapecodes,X-cisco-service-control,X-cisco-srtp-fallback,X-cisco-monrec,X-cisco-config,X-cisco-sis-7.0.0,X-cisco-xsi-8.5.1
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header 12 [ 17]: Content-Length: 0
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header 13 [157]: Reason: SIP;cause=200;text="cisco-alarm:14 Name=SEP7018A717C746 ActiveLoad=sip8821.11-0-5SR2-2.loads InactiveLoad=sip8821.11-0-4-14.loads Last=cm-closed-tcp"
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header 14 [ 13]: Expires: 3600
[2020-03-31 14:22:25] VERBOSE[1660] chan_sip.c: --- (15 headers 0 lines) ---
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c: = Looking for  Call ID: [email protected] (Checking From) --From tag 7018a717c7460e380143e597-0e915b76 --To-tag
[2020-03-31 14:22:25] DEBUG[1660] acl.c: For destination '192.168.4.2', our source address is '192.168.0.78'.
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c: Setting AST_TRANSPORT_UDP with address 192.168.0.78:5060
[2020-03-31 14:22:25] DEBUG[1660] netsock2.c: Splitting '192.168.4.2:5060' into...
[2020-03-31 14:22:25] DEBUG[1660] netsock2.c: ...host '192.168.4.2' and port '5060'.
[2020-03-31 14:22:25] VERBOSE[1660] chan_sip.c: Sending to 192.168.4.2:5060 (NAT)
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c: Allocating new SIP dialog for [email protected] - REGISTER (No RTP)
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c: Initializing initreq for method REGISTER - callid [email protected]
[2020-03-31 14:22:25] DEBUG[1660] netsock2.c: Splitting '192.168.4.2:5060' into...
[2020-03-31 14:22:25] DEBUG[1660] netsock2.c: ...host '192.168.4.2' and port '5060'.
[2020-03-31 14:22:25] VERBOSE[1660] chan_sip.c: Sending to 192.168.4.2:5060 (NAT)
[2020-03-31 14:22:25] DEBUG[1660] netsock2.c: Splitting '192.168.0.78' into...
[2020-03-31 14:22:25] DEBUG[1660] netsock2.c: ...host '192.168.0.78' and port ''.
[2020-03-31 14:22:25] VERBOSE[1660] chan_sip.c:
<--- Transmitting (NAT) to 192.168.4.2:5060 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 192.168.4.2:5060;branch=z9hG4bK61d5819b;received=192.168.4.2;rport=5060
From: <sip:[email protected]>;tag=7018a717c7460e380143e597-0e915b76
To: <sip:[email protected]>;tag=as60c39ffb
Call-ID: [email protected]
CSeq: 1238 REGISTER
Server: FPBX-14.0.13.26(13.29.2)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces
WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="5ab2eece"
Content-Length: 0


<------------>
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 192.168.4.2:5060
[2020-03-31 14:22:25] VERBOSE[1660] chan_sip.c: Scheduling destruction of SIP dialog '[email protected]' in 32000 ms (Method: REGISTER)
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c: Destroying SIP dialog [email protected]
[2020-03-31 14:22:25] VERBOSE[1660] chan_sip.c: Really destroying SIP dialog '[email protected]' Method: REFER
[2020-03-31 14:22:25] VERBOSE[1660] chan_sip.c:
<--- SIP read from UDP:192.168.4.2:5060 --->
REFER sip:192.168.0.78 SIP/2.0
Via: SIP/2.0/UDP 192.168.4.2:5060;branch=z9hG4bK4c77981f
From: "231" <sip:[email protected]>;tag=7018a717c7460e37068afc71-4f49bbd5
To: <sip:192.168.0.78>
Call-ID: [email protected]
Session-ID: a1dc650e00105000a0007018a717c746;remote=00000000000000000000000000000000
Date: Tue, 31 Mar 2020 11:22:27 GMT
CSeq: 1000 REFER
User-Agent: Cisco-CP8821/11.0.5
Expires: 10
Max-Forwards: 70
Contact: <sip:[email protected]:5060;transport=udp>;+u.sip!devicename.ccm.cisco.com="SEP7018A717C746"
Require: norefersub
Referred-By: "231" <sip:[email protected]>
Refer-To: cid:[email protected]
Content-Id: <[email protected]>
Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE
Content-Length: 506
Content-Type: application/x-cisco-alarm+xml
Content-Disposition: session;handling=required

<?xml version="1.0" encoding="UTF-8"?>
<x-cisco-alarm>
<Alarm Name="DeviceTLInfo">
<ParameterList>
<String name="DeviceName">SEP7018A717C746</String>
<String name="IPv4Address">192.168.1.5</String>
<String name="IPv6Address"></String>
<String name="CTL_Signature">Not Installed</String>
<String name="CTL_TFTP_Server">N/A</String>
<String name="ITL_Signature">Not Installed</String>
<String name="ITL_TFTP_Server">N/A</String>
<String name="StatusCode">6</String>
</ParameterList>
</Alarm>
</x-cisco-alarm>
<------------->
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header  0 [ 30]: REFER sip:192.168.0.78 SIP/2.0
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header  1 [ 56]: Via: SIP/2.0/UDP 192.168.4.2:5060;branch=z9hG4bK4c77981f
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header  2 [ 71]: From: "231" <sip:[email protected]>;tag=7018a717c7460e37068afc71-4f49bbd5
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header  3 [ 22]: To: <sip:192.168.0.78>
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header  4 [ 56]: Call-ID: [email protected]
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header  5 [ 84]: Session-ID: a1dc650e00105000a0007018a717c746;remote=00000000000000000000000000000000
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header  6 [ 35]: Date: Tue, 31 Mar 2020 11:22:27 GMT
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header  7 [ 16]: CSeq: 1000 REFER
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header  8 [ 31]: User-Agent: Cisco-CP8821/11.0.5
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header  9 [ 11]: Expires: 10
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header 10 [ 16]: Max-Forwards: 70
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header 11 [ 99]: Contact: <sip:[email protected]:5060;transport=udp>;+u.sip!devicename.ccm.cisco.com="SEP7018A717C746"
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header 12 [ 19]: Require: norefersub
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header 13 [ 40]: Referred-By: "231" <sip:[email protected]>
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header 14 [ 34]: Refer-To: cid:[email protected]
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header 15 [ 34]: Content-Id: <[email protected]>
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header 16 [ 75]: Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header 17 [ 19]: Content-Length: 506
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header 18 [ 43]: Content-Type: application/x-cisco-alarm+xml
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header 19 [ 46]: Content-Disposition: session;handling=required
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header 20 [  0]:
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:    Body  0 [ 38]: <?xml version="1.0" encoding="UTF-8"?>
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:    Body  1 [ 15]: <x-cisco-alarm>
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:    Body  2 [ 27]: <Alarm Name="DeviceTLInfo">
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:    Body  3 [ 15]: <ParameterList>
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:    Body  4 [ 50]: <String name="DeviceName">SEP7018A717C746</String>
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:    Body  5 [ 47]: <String name="IPv4Address">192.168.1.5</String>
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:    Body  6 [ 36]: <String name="IPv6Address"></String>
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:    Body  7 [ 51]: <String name="CTL_Signature">Not Installed</String>
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:    Body  8 [ 43]: <String name="CTL_TFTP_Server">N/A</String>
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:    Body  9 [ 51]: <String name="ITL_Signature">Not Installed</String>
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:    Body 10 [ 43]: <String name="ITL_TFTP_Server">N/A</String>
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:    Body 11 [ 36]: <String name="StatusCode">6</String>
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:    Body 12 [ 16]: </ParameterList>
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:    Body 13 [  8]: </Alarm>
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:    Body 14 [ 16]: </x-cisco-alarm>
[2020-03-31 14:22:25] VERBOSE[1660] chan_sip.c: --- (20 headers 15 lines) ---
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c: = Looking for  Call ID: [email protected] (Checking From) --From tag 7018a717c7460e37068afc71-4f49bbd5 --To-tag
[2020-03-31 14:22:25] DEBUG[1660] acl.c: For destination '192.168.4.2', our source address is '192.168.0.78'.
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c: Setting AST_TRANSPORT_UDP with address 192.168.0.78:5060
[2020-03-31 14:22:25] DEBUG[1660] netsock2.c: Splitting '192.168.4.2:5060' into...
[2020-03-31 14:22:25] DEBUG[1660] netsock2.c: ...host '192.168.4.2' and port '5060'.
[2020-03-31 14:22:25] VERBOSE[1660] chan_sip.c: Sending to 192.168.4.2:5060 (NAT)
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c: Allocating new SIP dialog for [email protected] - REFER (No RTP)
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c: **** Received REFER (9) - Command in SIP REFER
[2020-03-31 14:22:25] VERBOSE[1660] chan_sip.c: Call [email protected] got a SIP call transfer from caller: (REFER)!
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c: Call [email protected]: Declined REFER, outside of dialog...
[2020-03-31 14:22:25] VERBOSE[1660] chan_sip.c:
<--- Transmitting (NAT) to 192.168.4.2:5060 --->
SIP/2.0 603 Declined (No dialog)
Via: SIP/2.0/UDP 192.168.4.2:5060;branch=z9hG4bK4c77981f;received=192.168.4.2;rport=5060
From: "231" <sip:[email protected]>;tag=7018a717c7460e37068afc71-4f49bbd5
To: <sip:192.168.0.78>;tag=as6c71e095
Call-ID: [email protected]
CSeq: 1000 REFER
Server: FPBX-14.0.13.26(13.29.2)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces
Content-Length: 0


<------------>
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c: Trying to put 'SIP/2.0 603' onto UDP socket destined for 192.168.4.2:5060
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c: Setting SIP_ALREADYGONE on dialog [email protected]
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c: Destroying SIP dialog [email protected]
[2020-03-31 14:22:25] VERBOSE[1660] chan_sip.c: Really destroying SIP dialog '[email protected]' Method: REFER

[2020-03-31 14:22:25] VERBOSE[1660] chan_sip.c:
<--- SIP read from UDP:192.168.4.2:5060 --->
REGISTER sip:192.168.0.78 SIP/2.0
Via: SIP/2.0/UDP 192.168.4.2:5060;branch=z9hG4bK24de7a54
From: <sip:[email protected]>;tag=7018a717c7460e380143e597-0e915b76
To: <sip:[email protected]>
Call-ID: [email protected]
Max-Forwards: 70
Session-ID: a1dc650e00105000a0007018a717c746;remote=00000000000000000000000000000000
Date: Tue, 31 Mar 2020 11:22:27 GMT
CSeq: 1239 REGISTER
User-Agent: Cisco-CP8821/11.0.5
Contact: <sip:[email protected]:5060;user=phone;transport=udp>;+sip.instance="<urn:uuid:00000000-0000-0000-0000-7018a717c746>";+u.sip!devicename.ccm.cisco.com="SEP7018A717C746";+u.sip!model.ccm.cisco.com="36216"
Authorization: Digest username="231",realm="asterisk",uri="sip:192.168.0.78",response="f765b896027a0911580bfbeaef77331a",nonce="5ab2eece",algorithm=MD5
Supported: replaces,join,sdp-anat,norefersub,resource-priority,extended-refer,X-cisco-callinfo,X-cisco-serviceuri,X-cisco-escapecodes,X-cisco-service-control,X-cisco-srtp-fallback,X-cisco-monrec,X-cisco-config,X-cisco-sis-7.0.0,X-cisco-xsi-8.5.1
Content-Length: 0
Reason: SIP;cause=200;text="cisco-alarm:14 Name=SEP7018A717C746 ActiveLoad=sip8821.11-0-5SR2-2.loads InactiveLoad=sip8821.11-0-4-14.loads Last=cm-closed-tcp"
Expires: 3600

<------------->
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header  0 [ 33]: REGISTER sip:192.168.0.78 SIP/2.0
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header  1 [ 56]: Via: SIP/2.0/UDP 192.168.4.2:5060;branch=z9hG4bK24de7a54
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header  2 [ 66]: From: <sip:[email protected]>;tag=7018a717c7460e380143e597-0e915b76
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header  3 [ 26]: To: <sip:[email protected]>
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header  4 [ 56]: Call-ID: [email protected]
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header  5 [ 16]: Max-Forwards: 70
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header  6 [ 84]: Session-ID: a1dc650e00105000a0007018a717c746;remote=00000000000000000000000000000000
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header  7 [ 35]: Date: Tue, 31 Mar 2020 11:22:27 GMT
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header  8 [ 19]: CSeq: 1239 REGISTER
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header  9 [ 31]: User-Agent: Cisco-CP8821/11.0.5
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header 10 [209]: Contact: <sip:[email protected]:5060;user=phone;transport=udp>;+sip.instance="<urn:uuid:00000000-0000-0000-0000-7018a717c746>";+u.sip!devicename.ccm.cisco.com="SEP7018A717C746";+u.sip!model.ccm.cisco.com="36216"
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header 11 [151]: Authorization: Digest username="231",realm="asterisk",uri="sip:192.168.0.78",response="f765b896027a0911580bfbeaef77331a",nonce="5ab2eece",algorithm=MD5
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header 12 [245]: Supported: replaces,join,sdp-anat,norefersub,resource-priority,extended-refer,X-cisco-callinfo,X-cisco-serviceuri,X-cisco-escapecodes,X-cisco-service-control,X-cisco-srtp-fallback,X-cisco-monrec,X-cisco-config,X-cisco-sis-7.0.0,X-cisco-xsi-8.5.1
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header 13 [ 17]: Content-Length: 0
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header 14 [157]: Reason: SIP;cause=200;text="cisco-alarm:14 Name=SEP7018A717C746 ActiveLoad=sip8821.11-0-5SR2-2.loads InactiveLoad=sip8821.11-0-4-14.loads Last=cm-closed-tcp"
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header 15 [ 13]: Expires: 3600
[2020-03-31 14:22:25] VERBOSE[1660] chan_sip.c: --- (16 headers 0 lines) ---
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c: = Looking for  Call ID: [email protected] (Checking From) --From tag 7018a717c7460e380143e597-0e915b76 --To-tag
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c: Initializing initreq for method REGISTER - callid [email protected]
[2020-03-31 14:22:25] DEBUG[1660] netsock2.c: Splitting '192.168.4.2:5060' into...
[2020-03-31 14:22:25] DEBUG[1660] netsock2.c: ...host '192.168.4.2' and port '5060'.
[2020-03-31 14:22:25] VERBOSE[1660] chan_sip.c: Sending to 192.168.4.2:5060 (NAT)
[2020-03-31 14:22:25] DEBUG[1660] netsock2.c: Splitting '192.168.0.78' into...
[2020-03-31 14:22:25] DEBUG[1660] netsock2.c: ...host '192.168.0.78' and port ''.
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c: Store REGISTER's src-IP:port for call routing.
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c: build_path: do not use Path headers
[2020-03-31 14:22:25] VERBOSE[1660] chan_sip.c: Registered SIP '231' at 192.168.4.2:5060
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c: Allocating new SIP dialog for [email protected]:5060 - OPTIONS (No RTP)
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c: OBPROXY: Not applying OBproxy to this call
[2020-03-31 14:22:25] DEBUG[1660] acl.c: For destination '192.168.4.2', our source address is '192.168.0.78'.
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c: Setting AST_TRANSPORT_UDP with address 192.168.0.78:5060
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c: SIP call-id changed from '[email protected]:5060' to '[email protected]:5060'
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c: Initializing initreq for method OPTIONS - callid [email protected]:5060
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header  0 [ 65]: OPTIONS sip:[email protected]:5060;user=phone;transport=udp SIP/2.0
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header  1 [ 63]: Via: SIP/2.0/UDP 192.168.0.78:5060;branch=z9hG4bK3aed04a5;rport
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header  2 [ 16]: Max-Forwards: 70
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header  3 [ 57]: From: "Unknown" <sip:[email protected]>;tag=as6f8b8f89
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header  4 [ 55]: To: <sip:[email protected]:5060;user=phone;transport=udp>
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header  5 [ 40]: Contact: <sip:[email protected]:5060>
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header  6 [ 59]: Call-ID: [email protected]:5060
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header  7 [ 17]: CSeq: 102 OPTIONS
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header  8 [ 36]: User-Agent: FPBX-14.0.13.26(13.29.2)
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header  9 [ 35]: Date: Tue, 31 Mar 2020 11:22:25 GMT
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header 10 [ 90]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c:  Header 11 [ 26]: Supported: replaces, timer
[2020-03-31 14:22:25] VERBOSE[1660] chan_sip.c: Reliably Transmitting (NAT) to 192.168.4.2:5060:
OPTIONS sip:[email protected]:5060;user=phone;transport=udp SIP/2.0
Via: SIP/2.0/UDP 192.168.0.78:5060;branch=z9hG4bK3aed04a5;rport
Max-Forwards: 70
From: "Unknown" <sip:[email protected]>;tag=as6f8b8f89
To: <sip:[email protected]:5060;user=phone;transport=udp>
Contact: <sip:[email protected]:5060>
Call-ID: [email protected]:5060
CSeq: 102 OPTIONS
User-Agent: FPBX-14.0.13.26(13.29.2)
Date: Tue, 31 Mar 2020 11:22:25 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Length: 0


---
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id  #84
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 192.168.4.2:5060
[2020-03-31 14:22:25] VERBOSE[1660] chan_sip.c:
<--- Transmitting (NAT) to 192.168.4.2:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.4.2:5060;branch=z9hG4bK24de7a54;received=192.168.4.2;rport=5060
From: <sip:[email protected]>;tag=7018a717c7460e380143e597-0e915b76
To: <sip:[email protected]>;tag=as60c39ffb
Call-ID: [email protected]
CSeq: 1239 REGISTER
Server: FPBX-14.0.13.26(13.29.2)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces
Expires: 300
Contact: <sip:[email protected]:5060;user=phone;transport=udp>;expires=300
Date: Tue, 31 Mar 2020 11:22:25 GMT
Content-Length: 0


<------------>
[2020-03-31 14:22:25] DEBUG[1660] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.4.2:5060
[2020-03-31 14:22:25] DEBUG[1576] devicestate.c: No provider found, checking channel drivers for SIP - 231
[2020-03-31 14:22:25] DEBUG[1576] chan_sip.c: Checking device state for peer 231
[2020-03-31 14:22:25] DEBUG[1576] devicestate.c: Changing state for SIP/231 - state 1 (Not in use)
[2020-03-31 14:22:25] DEBUG[1685] app_queue.c: Device 'SIP/231' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[2020-03-31 14:22:25] VERBOSE[1660] chan_sip.c: Scheduling destruction of SIP dialog '[email protected]' in 32000 ms (Method: REGISTER)

[2020-03-31 14:22:26] DEBUG[1660] chan_sip.c: SIP TIMER: Not rescheduling id #84:OPTIONS (Method 3) (No timer T1)
[2020-03-31 14:22:26] VERBOSE[1660] chan_sip.c: Retransmitting #1 (NAT) to 192.168.4.2:5060:
OPTIONS sip:[email protected]:5060;user=phone;transport=udp SIP/2.0
Via: SIP/2.0/UDP 192.168.0.78:5060;branch=z9hG4bK3aed04a5;rport
Max-Forwards: 70
From: "Unknown" <sip:[email protected]>;tag=as6f8b8f89
To: <sip:[email protected]:5060;user=phone;transport=udp>
Contact: <sip:[email protected]:5060>
Call-ID: [email protected]:5060
CSeq: 102 OPTIONS
User-Agent: FPBX-14.0.13.26(13.29.2)
Date: Tue, 31 Mar 2020 11:22:25 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Length: 0


---
[2020-03-31 14:22:26] DEBUG[1660] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 192.168.4.2:5060

[2020-03-31 14:22:27] DEBUG[1660] chan_sip.c: SIP TIMER: Not rescheduling id #84:OPTIONS (Method 3) (No timer T1)
[2020-03-31 14:22:27] VERBOSE[1660] chan_sip.c: Retransmitting #2 (NAT) to 192.168.4.2:5060:
OPTIONS sip:[email protected]:5060;user=phone;transport=udp SIP/2.0
Via: SIP/2.0/UDP 192.168.0.78:5060;branch=z9hG4bK3aed04a5;rport
Max-Forwards: 70
From: "Unknown" <sip:[email protected]>;tag=as6f8b8f89
To: <sip:[email protected]:5060;user=phone;transport=udp>
Contact: <sip:[email protected]:5060>
Call-ID: [email protected]:5060
CSeq: 102 OPTIONS
User-Agent: FPBX-14.0.13.26(13.29.2)
Date: Tue, 31 Mar 2020 11:22:25 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Length: 0


---
[2020-03-31 14:22:27] DEBUG[1660] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 192.168.4.2:5060

[2020-03-31 14:22:28] DEBUG[1660] chan_sip.c: SIP TIMER: Not rescheduling id #84:OPTIONS (Method 3) (No timer T1)
[2020-03-31 14:22:28] VERBOSE[1660] chan_sip.c: Retransmitting #3 (NAT) to 192.168.4.2:5060:
OPTIONS sip:[email protected]:5060;user=phone;transport=udp SIP/2.0
Via: SIP/2.0/UDP 192.168.0.78:5060;branch=z9hG4bK3aed04a5;rport
Max-Forwards: 70
From: "Unknown" <sip:[email protected]>;tag=as6f8b8f89
To: <sip:[email protected]:5060;user=phone;transport=udp>
Contact: <sip:[email protected]:5060>
Call-ID: [email protected]:5060
CSeq: 102 OPTIONS
User-Agent: FPBX-14.0.13.26(13.29.2)
Date: Tue, 31 Mar 2020 11:22:25 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Length: 0


---
[2020-03-31 14:22:28] DEBUG[1660] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 192.168.4.2:5060

[2020-03-31 14:22:29] VERBOSE[1660] chan_sip.c: Retransmitting #4 (NAT) to 192.168.4.2:5060:
OPTIONS sip:[email protected]:5060;user=phone;transport=udp SIP/2.0
Via: SIP/2.0/UDP 192.168.0.78:5060;branch=z9hG4bK3aed04a5;rport
Max-Forwards: 70
From: "Unknown" <sip:[email protected]>;tag=as6f8b8f89
To: <sip:[email protected]:5060;user=phone;transport=udp>
Contact: <sip:[email protected]:5060>
Call-ID: [email protected]:5060
CSeq: 102 OPTIONS
User-Agent: FPBX-14.0.13.26(13.29.2)
Date: Tue, 31 Mar 2020 11:22:25 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Length: 0


---
[2020-03-31 14:22:29] DEBUG[1660] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 192.168.4.2:5060
[2020-03-31 14:22:29] NOTICE[1660] chan_sip.c: Peer '231' is now UNREACHABLE!  Last qualify: 0
[2020-03-31 14:22:29] DEBUG[1576] devicestate.c: No provider found, checking channel drivers for SIP - 231
[2020-03-31 14:22:29] DEBUG[1576] chan_sip.c: Checking device state for peer 231
[2020-03-31 14:22:29] DEBUG[1576] devicestate.c: Changing state for SIP/231 - state 5 (Unavailable)
[2020-03-31 14:22:29] DEBUG[1685] app_queue.c: Device 'SIP/231' changed to state '5' (Unavailable) but we don't care because they're not a member of any queue.
[2020-03-31 14:22:29] DEBUG[1660] chan_sip.c: Destroying SIP dialog [email protected]:5060
[2020-03-31 14:22:29] VERBOSE[1660] chan_sip.c: Really destroying SIP dialog '[email protected]:5060' Method: OPTIONS

P/S: Softphone and/or Cisco SPA525g2 are working fine through 192.168.4.0/24 subnet :(((

Can you explain that a bit more? It might help to add something to Local Networks in Settings->Asterisk SIP Settings depending on what’s going on.

It’s definitely strange that the registration handshake looks successful. Based on that, this might not be the issue, but I noticed that port 5061 being used in the zoiper traffic. For example the Request-Line in the REGISTER packets. Is it possible that the cisco needs to have a port specified somewhere?

Can you explain that a bit more? It might help to add something to Local Networks in Settings->Asterisk SIP Settings depending on what’s going on.

Local network (192.168.0.0/24) already had about five(5) SPA525g2 that they are working flawlessly. In my Asterisk Sip Settings I already declared my three subnets (192.168.0.0/24, 192.168.1.0/24, 192.168.4.0/24). This issue happens only on 8821 and on 192.168.4.0/24 !!!

It’s definitely strange that the registration handshake looks successful.

That’s true but right after the successful registration, client becoming UNREACHABLE unexpectedly.

Is it possible that the cisco needs to have a port specified somewhere?

According to Cisco documentation, I don’t think so. But even if it needs any additional port, there is no firewall in my Asterisk server. And subnets are completely opened between them. So 8821 has no barrier in communication i think…

Try firing up sngrep and filtering on ‘Source’ being 192.168.4.2 (for extension 231)

Try firing up sngrep and filtering on ‘Source’ being 192.168.4.2 (for extension 231)

Is what am currently using with tcpdump. But I really cannot understand where the issue could be…

sip 603 Decline

The destination does not wish to participate in the call, or cannot do so, and additionally the destination knows there are no alternative destinations (such as a voicemail server) willing to accept the call.

Unfortunately thats as far as the view from the network can go, find a good recipe for the particular ATA

According to Cisco documentation, I don’t think so. But even if it needs any additional port, there is no firewall in my Asterisk server. And subnets are completely opened between them. So 8821 has no barrier in communication i think…
Is a port included in the registration server option? For example, if you only have the PBX IP set, can you add something like “:5060” or “:5061”, so it would be like “192.168.0.78:5060”? It may not matter, and the device just defaults to 5060 if a port isn’t included, but it could be worth looking at. By the way, is any sort of TLS enabled on the PBX?

It’s good you have some phones of the same model that are working. When looking at the 8821’s settings, have you compared it to one of the working ones? And are they all running the same firmware? Maybe there’s a difference there. Also, look for any notable differences in /etc/asterisk/sip_additional.conf when comparing extension 231 vs one that’s working with an SPA from another network… I know 231 is working for zoiper, but it’s still worth looking at. It really does seem network related for now though.

Also, it could help to see a packet capture of a working SPA from another network. That way, it’s more of a direct comparison when looking at this captures from the non working one.

As for the three 8821 captures you included, were they just 3 separate registrations? I noticed the 3rd one had a lot instances of “Fragmented IP Protocol”. I’m not sure what that’s all about, maybe insignificant.

Definitely should be a network issue because the same device (8821) connected through 192.168.1.0/24 subnet is working fine. So as you mentioned, I captured 8821 communication from the working subnet for comparing. If you have a chance, please take a look and let me know

pcaps2.tgz (102.2 KB)

Once again million thanks for your time

Unfortunately, nothing stood out from the comparison. Looking at the 603 responses to the REFERs as dicko mentioned, do you know why those are being sent? I see a lot being sent within a short time on the bad phone’s trace. I also see some on the working phone, so they might be normal, but it would help to know what those are about.

Looking back at one of the REFER packet in your acli output from an earlier post:

REFER sip:192.168.0.78 SIP/2.0
Via: SIP/2.0/UDP 192.168.4.2:5060;branch=z9hG4bK4c77981f
From: "231" <sip:[email protected]>;tag=7018a717c7460e37068afc71-4f49bbd5
To: <sip:192.168.0.78>
Call-ID: [email protected]
Session-ID: a1dc650e00105000a0007018a717c746;remote=00000000000000000000000000000000
Date: Tue, 31 Mar 2020 11:22:27 GMT
CSeq: 1000 REFER
User-Agent: Cisco-CP8821/11.0.5
Expires: 10
Max-Forwards: 70
Contact: <sip:[email protected]:5060;transport=udp>;+u.sip!devicename.ccm.cisco.com="SEP7018A717C746"
Require: norefersub
Referred-By: "231" <sip:[email protected]>
Refer-To: cid:[email protected]
Content-Id: <[email protected]>
Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE
Content-Length: 506
Content-Type: application/x-cisco-alarm+xml
Content-Disposition: session;handling=required

<?xml version="1.0" encoding="UTF-8"?>
<x-cisco-alarm>
<Alarm Name="DeviceTLInfo">
<ParameterList>
<String name="DeviceName">SEP7018A717C746</String>
<String name="IPv4Address">192.168.1.5</String>
<String name="IPv6Address"></String>
<String name="CTL_Signature">Not Installed</String>
<String name="CTL_TFTP_Server">N/A</String>
<String name="ITL_Signature">Not Installed</String>
<String name="ITL_TFTP_Server">N/A</String>
<String name="StatusCode">6</String>
</ParameterList>
</Alarm>
</x-cisco-alarm>
<------------->

In the xml at the bottom includes. does that make sense?

<String name="DeviceName">SEP7018A717C746</String>
<String name="IPv4Address">192.168.1.5</String>

Also, if you look at the Message Body on a REFER from the working phone pcap, I see:

<String name="DeviceName">SEP7018A717C746</String>
<String name="IPv4Address">192.168.1.5/24</String>
<String name="IPv4DefaultGateway">192.168.1.1</String>

All the REFERs from the failing phone’s captures don’t include the “/24” after the ip address, our the IPv4DefaultGateway line. I’m just grasping at straws at this point, but knowing more about those REFERs would be helpful.

Thanks again for your time. I have no idea about these REFERs and additional xml included. Probably are used by Cisco Call Manager. I don’t think that could make sense in our setup. Unfortunately the documentation regarding this phone configured out of Cisco Call Manager is so limited even if it is the top of the line in cisco wireless voip catalog. :((((((

BTW, the working subnets 192.168.0.0/24 and 192.168.1.0/24 are driven by Cisco routers. The non working one 192.168.4.0/24 is a Teltonika LTE. Both are connected though the same DMVPN (IPsec/GRE). I am braking my head to find any possible reason from the Teltonika router side, but seems completely transparent…

See also my ne!twork diagram… Everything is working fine everywhere EXEMPT the very right 8821 :(((

Have you looked for any SIP settings on the Teltonika? I’m seeing something about “Helpers” in some documentation, but no idea if it’s relevant here. Usually enabling these type of features will lead to problems, but if they’re available and disabled, they could be worth looking into.

Yes I have checked this even before I write on this thread. Nat helpers contains H323 and SIP ALG option that are disabled in my router.

BTW, I may didn’t solve the problem yet, but I’m sniffing what may cause all this. Both of my routers are connected together through a DMVPN. The C887VA (pictured above in the center) is the HUB, and the left and the right are SPOKES. All three had VLANs configured with BGP routings and the telephony is based on VLAN1 in all three routers. The main problem should be that VLAN is L2 and DMVPN is L3 so you can’t pass VLANs over WAN unless there are L2 WAN (like MPLS etc). My HUB and my left SPOKE are Cisco IOS based and seems they are collaborating flawlessly, but my right side SPOKE (with 192.168.4.0/24 subnet) still facing issues.

Another problem i discovered last weekend was that my right SPOKE was not able to access port 80 (http) on every server (in this network) which is connected through a trunk Ethernet port. With other words, native http protocol cannot passed correctly to my right SPOKE if it is coming from a server which uses more than one VLAN !!! This new discovered issue happen only on port 80. All other ports seems to be fine (ssh, telnet etc)

Any thought???

Finally I found a solution… I went to Chan SIP Settings and turned “Enable TCP” to Yes. So asterisk can get registrations over TCP as well. Then turned my 8821 to register over TCP (instead of UDP by default) and the problem disappeared. Most probably this strange issue caused by SIP retransmission errors though UDP.

Thanks all for your time

1 Like

That’s great news. Thanks for the detailed update.

1 Like

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