FusionPBX call drop problem

Daniel B · Dec 11, 2017

Hello everyone,

My name is Daniel and I'm coming to you with a problem with my new voip environment. Please excuse me if my predicament has been discussed already, but I did not find anything useful with search.

I have installed Fusionpbx on debian 9.3 and apart from some small issues everything went ok.
I have created extension for my voip phones, which are cisco 7911G.
The phones are running SIP firmware 8.5 and are also running without issues.
Now on to my problem: I can make and receive calls, everything works great, but at a minute and 30 seconds the call drops. To be more exact, the time is 100 seconds, split between the time it takes to answer and the talk time.
The error I'm seeing in the Call Details App, is Request_timer_expire, with SIP code Q850/102.
This pointed me to a NAT error, but my environment is only operating in the local LAN, and the only active SIP profile is the internal one.
I also tried increasing the timeouts on the cisco phones, but still no luck. Also tried changing settings in the SIP profile, but again no luck.
Somewhere there is a timer that is messing with me and I can't seem to find out where.
Did anyone else experience this problem, or can you point me in the right direction?

Thank you!

DigitalDaz · Dec 11, 2017

Post a siptrace of a call, it absolutely sounds like nat, you saying calls between extensions drop after 1:30??

Also, though you may get away with it, Freeswitch is not officially supported on Debian 9 yet though I expect this has nothing to do with your current issue.

To get a siptrace, in the fs_cli do a:

Code:

sofia global siptrace on

and make the call

Daniel B · Dec 12, 2017

Hello,

I thought about NAT as well after reading about the error, but the calls are done in an internal network segment. All the phones have an IP address from the same segment and while there is a router on the segment, it only acts as a dhcp server and an internet gateway. However, I don't have any rules towards an external provider.
Today I noticed something interesting, namely that you place the call, the other person answers, it lasts for 100 seconds with the initial ringing included in this time and then suddenly you can't hear anything, but on the screen it still shows connected.
I ran the command you gave me and this is what I could see in the Log Viewer after that (is there another place where I could see the log?):

4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:30:44.491267 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/212@172.16.8.73) State DESTROY going to sleep
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:30:44.491267 [DEBUG] switch_core_state_machine.c:181 sofia/internal/212@172.16.8.73 Standard DESTROY
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:30:44.491267 [DEBUG] mod_sofia.c:343 sofia/internal/212@172.16.8.73 SOFIA DESTROY
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:30:44.491267 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/212@172.16.8.73) State DESTROY
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:30:44.491267 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/212@172.16.8.73) Running State Change CS_DESTROY (Cur 0 Tot 12)
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:30:44.491267 [NOTICE] switch_core_session.c:1687 Close Channel sofia/internal/212@172.16.8.73 [CS_DESTROY]
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:30:44.491267 [NOTICE] switch_core_session.c:1683 Session 11 (sofia/internal/212@172.16.8.73) Ended
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:30:44.491267 [DEBUG] switch_core_session.c:1665 Session 11 (sofia/internal/212@172.16.8.73) Locked, Waiting on external entities
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:30:44.491267 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/212@172.16.8.73) State Change CS_REPORTING -> CS_DESTROY
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:30:44.491267 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/212@172.16.8.73) State REPORTING going to sleep
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:30:44.491267 [DEBUG] switch_core_state_machine.c:174 sofia/internal/212@172.16.8.73 Standard REPORTING, cause: RECOVERY_ON_TIMER_EXPIRE
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:30:44.391265 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/233@172.16.8.210:5060) State DESTROY going to sleep
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:30:44.391265 [DEBUG] switch_core_state_machine.c:181 sofia/internal/233@172.16.8.210:5060 Standard DESTROY
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:30:44.391265 [DEBUG] mod_sofia.c:343 sofia/internal/233@172.16.8.210:5060 SOFIA DESTROY
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:30:44.391265 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/233@172.16.8.210:5060) State DESTROY
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:30:44.391265 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/233@172.16.8.210:5060) Running State Change CS_DESTROY (Cur 1 Tot 12)
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:30:44.391265 [NOTICE] switch_core_session.c:1687 Close Channel sofia/internal/233@172.16.8.210:5060 [CS_DESTROY]
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:30:44.391265 [NOTICE] switch_core_session.c:1683 Session 12 (sofia/internal/233@172.16.8.210:5060) Ended
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:30:44.391265 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/212@172.16.8.73) State REPORTING
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:30:44.391265 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/212@172.16.8.73) Running State Change CS_REPORTING (Cur 2 Tot 12)
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:30:44.391265 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/212@172.16.8.73) State Change CS_HANGUP -> CS_REPORTING
4dc537cb-58c7-4dd0-9766-4a16385af8d8
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:30:44.391265 [DEBUG] switch_core_state_machine.c:783 Hangup Command with no Session lua(app.lua hangup):
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:30:44.391265 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/212@172.16.8.73) State HANGUP going to sleep
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:30:44.391265 [DEBUG] switch_core_state_machine.c:60 sofia/internal/212@172.16.8.73 Standard HANGUP, cause: RECOVERY_ON_TIMER_EXPIRE
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:30:44.391265 [DEBUG] mod_sofia.c:438 Channel sofia/internal/212@172.16.8.73 hanging up, cause: RECOVERY_ON_TIMER_EXPIRE
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:30:44.391265 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/212@172.16.8.73) State HANGUP
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:30:44.391265 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/212@172.16.8.73) Callstate Change ACTIVE -> HANGUP
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:30:44.391265 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/212@172.16.8.73) Running State Change CS_HANGUP (Cur 2 Tot 12)
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:30:44.391265 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/212@172.16.8.73) State EXECUTE going to sleep
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:30:44.391265 [DEBUG] switch_core_session.c:2815 sofia/internal/212@172.16.8.73 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:30:44.391265 [DEBUG] switch_ivr_bridge.c:1715 sofia/internal/212@172.16.8.73 skip receive message [UNBRIDGE] (channel is hungup already)
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:30:44.391265 [DEBUG] switch_core_session.c:1665 Session 12 (sofia/internal/233@172.16.8.210:5060) Locked, Waiting on external entities
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:30:44.391265 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/233@172.16.8.210:5060) State Change CS_REPORTING -> CS_DESTROY
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:30:44.391265 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/233@172.16.8.210:5060) State REPORTING going to sleep
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:30:44.391265 [DEBUG] switch_core_state_machine.c:174 sofia/internal/233@172.16.8.210:5060 Standard REPORTING, cause: NORMAL_CLEARING
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:30:44.391265 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/233@172.16.8.210:5060) State REPORTING
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:30:44.391265 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/233@172.16.8.210:5060) Running State Change CS_REPORTING (Cur 2 Tot 12)
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:30:44.391265 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/233@172.16.8.210:5060) State Change CS_HANGUP -> CS_REPORTING
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:30:44.391265 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/233@172.16.8.210:5060) State HANGUP going to sleep
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:30:44.391265 [DEBUG] switch_core_state_machine.c:60 sofia/internal/233@172.16.8.210:5060 Standard HANGUP, cause: NORMAL_CLEARING
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:30:44.391265 [DEBUG] mod_sofia.c:491 Sending BYE to sofia/internal/233@172.16.8.210:5060
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:30:44.391265 [DEBUG] mod_sofia.c:438 Channel sofia/internal/233@172.16.8.210:5060 hanging up, cause: NORMAL_CLEARING
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:30:44.391265 [DEBUG] mod_sofia.c:432 sofia/internal/233@172.16.8.210:5060 Overriding SIP cause 480 with 408 from the other leg
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:30:44.391265 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/233@172.16.8.210:5060) State HANGUP
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:30:44.391265 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/233@172.16.8.210:5060) Callstate Change ACTIVE -> HANGUP
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:30:44.391265 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/233@172.16.8.210:5060) Running State Change CS_HANGUP (Cur 2 Tot 12)
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:30:44.391265 [DEBUG] switch_core_state_machine.c:653 (sofia/internal/233@172.16.8.210:5060) State EXCHANGE_MEDIA going to sleep
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:30:44.391265 [NOTICE] switch_ivr_bridge.c:904 Hangup sofia/internal/233@172.16.8.210:5060 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:30:44.391265 [DEBUG] switch_ivr_bridge.c:787 BRIDGE THREAD DONE [sofia/internal/233@172.16.8.210:5060]
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:30:44.391265 [DEBUG] switch_ivr_bridge.c:706 sofia/internal/212@172.16.8.73 ending bridge by request from write function
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:30:44.371274 [DEBUG] switch_ivr_bridge.c:787 BRIDGE THREAD DONE [sofia/internal/212@172.16.8.73]
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:30:44.371274 [DEBUG] switch_ivr_bridge.c:712 sofia/internal/212@172.16.8.73 ending bridge by request from read function
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:30:44.371274 [DEBUG] mod_hash.c:297 Usage for 172.16.8.73_233 is now 0
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:30:44.371274 [NOTICE] sofia.c:8273 Hangup sofia/internal/212@172.16.8.73 [CS_EXECUTE] [RECOVERY_ON_TIMER_EXPIRE]
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:30:44.371274 [DEBUG] sofia.c:7084 Channel sofia/internal/212@172.16.8.73 entering state [terminating][408]
2017-12-12 13:30:29.671265 [WARNING] sofia_reg.c:1792 SIP auth challenge (REGISTER) on sofia profile 'internal' for [227@172.16.8.73] from ip 172.16.8.192
2017-12-12 13:30:29.431266 [WARNING] sofia_reg.c:1792 SIP auth challenge (REGISTER) on sofia profile 'internal' for [209@172.16.8.73] from ip 172.16.8.195
2017-12-12 13:30:29.371264 [WARNING] sofia_reg.c:1792 SIP auth challenge (REGISTER) on sofia profile 'internal' for [248@172.16.8.73] from ip 172.16.8.181
2017-12-12 13:30:29.311280 [WARNING] sofia_reg.c:1792 SIP auth challenge (REGISTER) on sofia profile 'internal' for [218@172.16.8.73] from ip 172.16.8.178
2017-12-12 13:30:28.951267 [WARNING] sofia_reg.c:1792 SIP auth challenge (REGISTER) on sofia profile 'internal' for [208@172.16.8.73] from ip 172.16.8.179
2017-12-12 13:30:28.871269 [WARNING] sofia_reg.c:1792 SIP auth challenge (REGISTER) on sofia profile 'internal' for [207@172.16.8.73] from ip 172.16.8.157
2017-12-12 13:30:28.511272 [WARNING] sofia_reg.c:1792 SIP auth challenge (REGISTER) on sofia profile 'internal' for [222@172.16.8.73] from ip 172.16.8.105
2017-12-12 13:30:28.271269 [WARNING] sofia_reg.c:1792 SIP auth challenge (REGISTER) on sofia profile 'internal' for [229@172.16.8.73] from ip 172.16.8.190
2017-12-12 13:30:28.051271 [WARNING] sofia_reg.c:1792 SIP auth challenge (REGISTER) on sofia profile 'internal' for [233@172.16.8.73] from ip 172.16.8.210
2017-12-12 13:30:27.491275 [WARNING] sofia_reg.c:1792 SIP auth challenge (REGISTER) on sofia profile 'internal' for [217@172.16.8.73] from ip 172.16.8.196
2017-12-12 13:30:27.251276 [WARNING] sofia_reg.c:1792 SIP auth challenge (REGISTER) on sofia profile 'internal' for [226@172.16.8.73] from ip 172.16.8.189
2017-12-12 13:30:27.211280 [WARNING] sofia_reg.c:1792 SIP auth challenge (REGISTER) on sofia profile 'internal' for [204@172.16.8.73] from ip 172.16.8.194
2017-12-12 13:30:27.131266 [WARNING] sofia_reg.c:1792 SIP auth challenge (REGISTER) on sofia profile 'internal' for [211@172.16.8.73] from ip 172.16.8.172
2017-12-12 13:30:27.071265 [WARNING] sofia_reg.c:1792 SIP auth challenge (REGISTER) on sofia profile 'internal' for [205@172.16.8.73] from ip 172.16.8.187
2017-12-12 13:30:27.011265 [WARNING] sofia_reg.c:1792 SIP auth challenge (REGISTER) on sofia profile 'internal' for [228@172.16.8.73] from ip 172.16.8.202
2017-12-12 13:30:26.971283 [WARNING] sofia_reg.c:1792 SIP auth challenge (REGISTER) on sofia profile 'internal' for [238@172.16.8.73] from ip 172.16.8.200
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:30:12.371274 [DEBUG] sofia.c:7084 Channel sofia/internal/212@172.16.8.73 entering state [calling][0]
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:17.931272 [DEBUG] switch_rtp.c:7271 Correct audio ip/port confirmed.
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:29:17.891268 [DEBUG] switch_rtp.c:7271 Correct audio ip/port confirmed.
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:29:17.851267 [DEBUG] sofia.c:7084 Channel sofia/internal/212@172.16.8.73 entering state [ready][200]
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:17.771276 [DEBUG] mod_sofia.c:631 SOFIA EXCHANGE_MEDIA
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:17.771276 [DEBUG] switch_core_state_machine.c:653 (sofia/internal/233@172.16.8.210:5060) State EXCHANGE_MEDIA
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:17.771276 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/233@172.16.8.210:5060) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 12)
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:17.771276 [DEBUG] switch_ivr_bridge.c:1614 (sofia/internal/233@172.16.8.210:5060) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:29:17.771276 [DEBUG] switch_ivr_originate.c:3705 Originate Resulted in Success: [sofia/internal/233@172.16.8.210:5060]
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:29:17.771276 [DEBUG] switch_ivr_originate.c:3705 Originate Resulted in Success: [sofia/internal/233@172.16.8.210:5060]
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:29:17.771276 [DEBUG] switch_channel.c:3773 (sofia/internal/212@172.16.8.73) Callstate Change RINGING -> ACTIVE
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:29:17.771276 [NOTICE] switch_ivr_originate.c:3647 Channel [sofia/internal/212@172.16.8.73] has been answered
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:29:17.771276 [DEBUG] sofia.c:7084 Channel sofia/internal/212@172.16.8.73 entering state [completed][200]
4dc537cb-58c7-4dd0-9766-4a16385af8d8
4dc537cb-58c7-4dd0-9766-4a16385af8d8 a=sendrecv
4dc537cb-58c7-4dd0-9766-4a16385af8d8 a=ptime:20
4dc537cb-58c7-4dd0-9766-4a16385af8d8 a=fmtp:101 0-16
4dc537cb-58c7-4dd0-9766-4a16385af8d8 a=rtpmap:101 telephone-event/8000
4dc537cb-58c7-4dd0-9766-4a16385af8d8 a=rtpmap:0 PCMU/8000
4dc537cb-58c7-4dd0-9766-4a16385af8d8 m=audio 23832 RTP/AVP 0 101
4dc537cb-58c7-4dd0-9766-4a16385af8d8 t=0 0
4dc537cb-58c7-4dd0-9766-4a16385af8d8 c=IN IP4 172.16.8.73
4dc537cb-58c7-4dd0-9766-4a16385af8d8 s=FreeSWITCH
4dc537cb-58c7-4dd0-9766-4a16385af8d8 o=FreeSWITCH 1513054325 1513054326 IN IP4 172.16.8.73
4dc537cb-58c7-4dd0-9766-4a16385af8d8 v=0
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:29:17.771276 [DEBUG] mod_sofia.c:850 Local SDP sofia/internal/212@172.16.8.73:
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:29:17.771276 [DEBUG] switch_core_media.c:7209 sofia/internal/212@172.16.8.73 Set rtp dtmf delay to 40
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:29:17.771276 [DEBUG] switch_core_media.c:7186 sofia/internal/212@172.16.8.73 Set 2833 dtmf receive payload to 101
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:29:17.771276 [DEBUG] switch_core_media.c:7179 sofia/internal/212@172.16.8.73 Set 2833 dtmf send payload to 101
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:29:17.771276 [DEBUG] switch_rtp.c:4111 Starting timer [soft] 160 bytes per 20ms
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:29:17.771276 [DEBUG] switch_core_media.c:6878 AUDIO RTP [sofia/internal/212@172.16.8.73] 172.16.8.73 port 23832 -> 172.16.8.188 port 32050 codec: 0 ms: 20
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:17.771276 [DEBUG] switch_channel.c:3773 (sofia/internal/233@172.16.8.210:5060) Callstate Change RINGING -> ACTIVE
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:17.771276 [NOTICE] sofia.c:8218 Channel [sofia/internal/233@172.16.8.210:5060] has been answered
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:17.771276 [DEBUG] switch_core_media.c:7209 sofia/internal/233@172.16.8.210:5060 Set rtp dtmf delay to 40
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:17.771276 [DEBUG] switch_core_media.c:7186 sofia/internal/233@172.16.8.210:5060 Set 2833 dtmf receive payload to 101
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:17.771276 [DEBUG] switch_core_media.c:7179 sofia/internal/233@172.16.8.210:5060 Set 2833 dtmf send payload to 101
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:17.771276 [DEBUG] switch_rtp.c:4111 Starting timer [soft] 160 bytes per 20ms
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:17.771276 [DEBUG] switch_core_media.c:6878 AUDIO RTP [sofia/internal/233@172.16.8.210:5060] 172.16.8.73 port 18412 -> 172.16.8.210 port 30126 codec: 0 ms: 20
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:17.771276 [DEBUG] switch_core_media.c:4767 sofia/internal/233@172.16.8.210:5060 Set 2833 dtmf send payload to 101 recv payload to 101
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:17.771276 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:17.771276 [DEBUG] switch_core_codec.c:111 sofia/internal/233@172.16.8.210:5060 Original read codec set to PCMU:0
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:17.771276 [DEBUG] switch_core_media.c:3061 Set Codec sofia/internal/233@172.16.8.210:5060 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:17.771276 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:17.771276 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:17.771276 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:17.771276 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:17.771276 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:17.771276 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:17.771276 [DEBUG] sofia.c:7084 Channel sofia/internal/233@172.16.8.210:5060 entering state [ready][200]
7068caf6-2538-44c4-8f58-3857bf445ba9
7068caf6-2538-44c4-8f58-3857bf445ba9 a=fmtp:101 0-15
7068caf6-2538-44c4-8f58-3857bf445ba9 a=rtpmap:101 telephone-event/8000
7068caf6-2538-44c4-8f58-3857bf445ba9 a=rtpmap:0 PCMU/8000
7068caf6-2538-44c4-8f58-3857bf445ba9 c=IN IP4 172.16.8.210
7068caf6-2538-44c4-8f58-3857bf445ba9 m=audio 30126 RTP/AVP 0 101
7068caf6-2538-44c4-8f58-3857bf445ba9 t=0 0
7068caf6-2538-44c4-8f58-3857bf445ba9 s=SIP Call
7068caf6-2538-44c4-8f58-3857bf445ba9 o=Cisco-SIPUA 18739 0 IN IP4 172.16.8.210
7068caf6-2538-44c4-8f58-3857bf445ba9 v=0
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:17.771276 [DEBUG] sofia.c:7094 Remote SDP:
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:17.771276 [DEBUG] sofia.c:7084 Channel sofia/internal/233@172.16.8.210:5060 entering state [completing][200]
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:29:12.231257 [NOTICE] switch_ivr_originate.c:525 Ring Ready sofia/internal/212@172.16.8.73!
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:29:12.231257 [DEBUG] sofia.c:7084 Channel sofia/internal/212@172.16.8.73 entering state [early][180]
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:29:12.211258 [NOTICE] mod_sofia.c:2273 Ring-Ready sofia/internal/212@172.16.8.73!
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:12.211258 [DEBUG] switch_channel.c:3346 (sofia/internal/233@172.16.8.210:5060) Callstate Change DOWN -> RINGING
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:12.211258 [NOTICE] sofia.c:7192 Ring-Ready sofia/internal/233@172.16.8.210:5060!
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:12.211258 [DEBUG] sofia.c:7084 Channel sofia/internal/233@172.16.8.210:5060 entering state [proceeding][180]
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:11.971257 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/233@172.16.8.210:5060) State CONSUME_MEDIA going to sleep
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:11.971257 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/233@172.16.8.210:5060) State CONSUME_MEDIA
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:11.971257 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/233@172.16.8.210:5060) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 12)
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:11.971257 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/233@172.16.8.210:5060) State ROUTING going to sleep
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:11.971257 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/233@172.16.8.210:5060) State Change CS_ROUTING -> CS_CONSUME_MEDIA
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:11.971257 [DEBUG] mod_sofia.c:143 sofia/internal/233@172.16.8.210:5060 SOFIA ROUTING
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:11.971257 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/233@172.16.8.210:5060) State ROUTING
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:11.971257 [DEBUG] sofia.c:7084 Channel sofia/internal/233@172.16.8.210:5060 entering state [calling][0]
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:11.971257 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/233@172.16.8.210:5060) Running State Change CS_ROUTING (Cur 2 Tot 12)
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:11.971257 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/233@172.16.8.210:5060) State INIT going to sleep
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:11.971257 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/233@172.16.8.210:5060) State Change CS_INIT -> CS_ROUTING
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:11.971257 [DEBUG] switch_core_state_machine.c:40 sofia/internal/233@172.16.8.210:5060 Standard INIT
7068caf6-2538-44c4-8f58-3857bf445ba9
7068caf6-2538-44c4-8f58-3857bf445ba9 a=sendrecv
7068caf6-2538-44c4-8f58-3857bf445ba9 a=ptime:20
7068caf6-2538-44c4-8f58-3857bf445ba9 a=rtpmap:13 CN/8000
7068caf6-2538-44c4-8f58-3857bf445ba9 a=fmtp:101 0-16
7068caf6-2538-44c4-8f58-3857bf445ba9 a=rtpmap:101 telephone-event/8000
7068caf6-2538-44c4-8f58-3857bf445ba9 a=rtpmap:3 GSM/8000
7068caf6-2538-44c4-8f58-3857bf445ba9 a=rtpmap:8 PCMA/8000
7068caf6-2538-44c4-8f58-3857bf445ba9 a=rtpmap:9 G722/8000
7068caf6-2538-44c4-8f58-3857bf445ba9 a=rtpmap:0 PCMU/8000
7068caf6-2538-44c4-8f58-3857bf445ba9 m=audio 18412 RTP/AVP 0 9 8 3 101 13
7068caf6-2538-44c4-8f58-3857bf445ba9 t=0 0
7068caf6-2538-44c4-8f58-3857bf445ba9 c=IN IP4 172.16.8.73
7068caf6-2538-44c4-8f58-3857bf445ba9 s=FreeSWITCH
7068caf6-2538-44c4-8f58-3857bf445ba9 o=FreeSWITCH 1513059739 1513059740 IN IP4 172.16.8.73
7068caf6-2538-44c4-8f58-3857bf445ba9 v=0
7068caf6-2538-44c4-8f58-3857bf445ba9 Local SDP:
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:11.971257 [DEBUG] sofia_glue.c:1295 sofia/internal/233@172.16.8.210:5060 sending invite version: 1.6.19 -36-7a77e0b 64bit
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:11.971257 [DEBUG] mod_sofia.c:90 sofia/internal/233@172.16.8.210:5060 SOFIA INIT
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:11.971257 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/233@172.16.8.210:5060) State INIT
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:11.971257 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/233@172.16.8.210:5060) Running State Change CS_INIT (Cur 2 Tot 12)
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:11.971257 [DEBUG] mod_sofia.c:4819 (sofia/internal/233@172.16.8.210:5060) State Change CS_NEW -> CS_INIT
7068caf6-2538-44c4-8f58-3857bf445ba9 2017-12-12 13:29:11.971257 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/233@172.16.8.210:5060 [7068caf6-2538-44c4-8f58-3857bf445ba9]
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:29:11.971257 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:29:11.971257 [DEBUG] switch_channel.c:1250 sofia/internal/212@172.16.8.73 EXPORTING[export_vars] [domain_name]=[172.16.8.73] to event
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:29:11.971257 [DEBUG] switch_channel.c:1250 sofia/internal/212@172.16.8.73 EXPORTING[export_vars] [origination_callee_id_name]=[233] to event
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:29:11.971257 [DEBUG] switch_channel.c:1250 sofia/internal/212@172.16.8.73 EXPORTING[export_vars] [dialed_extension]=[233] to event
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:29:11.971257 [DEBUG] switch_channel.c:1250 sofia/internal/212@172.16.8.73 EXPORTING[export_vars] [domain_name]=[172.16.8.73] to event
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:29:11.971257 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:29:11.971257 [DEBUG] switch_channel.c:1250 sofia/internal/212@172.16.8.73 EXPORTING[export_vars] [domain_name]=[172.16.8.73] to event
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:29:11.971257 [DEBUG] switch_channel.c:1250 sofia/internal/212@172.16.8.73 EXPORTING[export_vars] [origination_callee_id_name]=[233] to event
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:29:11.971257 [DEBUG] switch_channel.c:1250 sofia/internal/212@172.16.8.73 EXPORTING[export_vars] [dialed_extension]=[233] to event
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:29:11.971257 [DEBUG] switch_channel.c:1250 sofia/internal/212@172.16.8.73 EXPORTING[export_vars] [domain_name]=[172.16.8.73] to event
4dc537cb-58c7-4dd0-9766-4a16385af8d8 EXECUTE sofia/internal/212@172.16.8.73 bridge(user/233@172.16.8.73)
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:29:11.971257 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [domain_name]=[172.16.8.73]
4dc537cb-58c7-4dd0-9766-4a16385af8d8 EXECUTE sofia/internal/212@172.16.8.73 export(domain_name=172.16.8.73)
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:29:11.971257 [DEBUG] mod_dptools.c:1548 SET sofia/internal/212@172.16.8.73 [api_hangup_hook]=[lua app.lua hangup]
4dc537cb-58c7-4dd0-9766-4a16385af8d8 EXECUTE sofia/internal/212@172.16.8.73 set(api_hangup_hook=lua app.lua hangup)
4dc537cb-58c7-4dd0-9766-4a16385af8d8 EXECUTE sofia/internal/212@172.16.8.73 hash(insert/172.16.8.73-last_dial//4dc537cb-58c7-4dd0-9766-4a16385af8d8)
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:29:11.971257 [DEBUG] mod_dptools.c:1548 SET sofia/internal/212@172.16.8.73 [called_party_call_group]=[UNDEF]
4dc537cb-58c7-4dd0-9766-4a16385af8d8 EXECUTE sofia/internal/212@172.16.8.73 set(called_party_call_group=)
4dc537cb-58c7-4dd0-9766-4a16385af8d8 EXECUTE sofia/internal/212@172.16.8.73 hash(insert/172.16.8.73-last_dial_ext/233/4dc537cb-58c7-4dd0-9766-4a16385af8d8)
4dc537cb-58c7-4dd0-9766-4a16385af8d8 EXECUTE sofia/internal/212@172.16.8.73 hash(insert/172.16.8.73-call_return/233/212)
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:29:11.971257 [DEBUG] mod_dptools.c:1548 SET sofia/internal/212@172.16.8.73 [continue_on_fail]=[true]
4dc537cb-58c7-4dd0-9766-4a16385af8d8 EXECUTE sofia/internal/212@172.16.8.73 set(continue_on_fail=true)
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:29:11.971257 [DEBUG] mod_dptools.c:1548 SET sofia/internal/212@172.16.8.73 [hangup_after_bridge]=[true]
4dc537cb-58c7-4dd0-9766-4a16385af8d8 EXECUTE sofia/internal/212@172.16.8.73 set(hangup_after_bridge=true)
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:29:11.971257 [DEBUG] mod_hash.c:196 Usage for 172.16.8.73_233 is now 1/5
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:29:11.971257 [DEBUG] switch_limit.c:126 incr called: 172.16.8.73_233 max:5, interval:0
4dc537cb-58c7-4dd0-9766-4a16385af8d8 EXECUTE sofia/internal/212@172.16.8.73 limit(hash 172.16.8.73 233 5 error/user_busy)
4dc537cb-58c7-4dd0-9766-4a16385af8d8 EXECUTE sofia/internal/212@172.16.8.73 eval(not_secure)
4dc537cb-58c7-4dd0-9766-4a16385af8d8 EXECUTE sofia/internal/212@172.16.8.73 hash(insert/172.16.8.73-last_dial/212/233)
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:29:11.971257 [DEBUG] mod_dptools.c:1548 SET sofia/internal/212@172.16.8.73 [RFC2822_DATE]=[Tue, 12 Dec 2017 13:29:11 +0200]
4dc537cb-58c7-4dd0-9766-4a16385af8d8 EXECUTE sofia/internal/212@172.16.8.73 set(RFC2822_DATE=Tue, 12 Dec 2017 13:29:11 +0200)
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:29:11.971257 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [origination_callee_id_name]=[233]
4dc537cb-58c7-4dd0-9766-4a16385af8d8 EXECUTE sofia/internal/212@172.16.8.73 export(origination_callee_id_name=233)
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:29:11.971257 [DEBUG] mod_dptools.c:1548 SET sofia/internal/212@172.16.8.73 [call_direction]=[local]
4dc537cb-58c7-4dd0-9766-4a16385af8d8 EXECUTE sofia/internal/212@172.16.8.73 set(call_direction=local)
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:29:11.971257 [DEBUG] switch_core_state_machine.c:328 sofia/internal/212@172.16.8.73 Standard EXECUTE
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:29:11.971257 [DEBUG] mod_sofia.c:198 sofia/internal/212@172.16.8.73 SOFIA EXECUTE
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:29:11.971257 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/212@172.16.8.73) State EXECUTE
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:29:11.971257 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/212@172.16.8.73) Running State Change CS_EXECUTE (Cur 1 Tot 11)
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:29:11.971257 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/212@172.16.8.73) State ROUTING going to sleep
4dc537cb-58c7-4dd0-9766-4a16385af8d8 2017-12-12 13:29:11.971257 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/212@172.16.8.73) State Change CS_ROUTING -> CS_EXECUTE
4dc537cb-58c7-4dd0-9766-4a16385af8d8 Dialplan: sofia/internal/212@172.16.8.73 Action lua(app.lua voicemail)
4dc537cb-58c7-4dd0-9766-4a16385af8d8 Dialplan: sofia/internal/212@172.16.8.73 Action set(voicemail_profile=default)
4dc537cb-58c7-4dd0-9766-4a16385af8d8 Dialplan: sofia/internal/212@172.16.8.73 Action set(voicemail_id=${destination_number})
4dc537cb-58c7-4dd0-9766-4a16385af8d8 Dialplan: sofia/internal/212@172.16.8.73 Action set(voicemail_action=save)
4dc537cb-58c7-4dd0-9766-4a16385af8d8 Dialplan: sofia/internal/212@172.16.8.73 Action sleep(1000)
4dc537cb-58c7-4dd0-9766-4a16385af8d8 Dialplan: sofia/internal/212@172.16.8.73 Action answer()
4dc537cb-58c7-4dd0-9766-4a16385af8d8 Dialplan: sofia/internal/212@172.16.8.73 Regex (PASS) [voicemail] ${user_exists}(true) =~ /true/ break=on-false
4dc537cb-58c7-4dd0-9766-4a16385af8d8 Dialplan: sofia/internal/212@172.16.8.73 parsing [172.16.8.73->voicemail] continue=false
4dc537cb-58c7-4dd0-9766-4a16385af8d8 Dialplan: sofia/internal/212@172.16.8.73 Action lua(app.lua failure_handler)
4dc537cb-58c7-4dd0-9766-4a16385af8d8 Dialplan: sofia/internal/212@172.16.8.73 Action bridge(user/${destination_number}@${domain_name})
4dc537cb-58c7-4dd0-9766-4a16385af8d8 Dialplan: sofia/internal/212@172.16.8.73 Action export(domain_name=${domain_name})
4dc537cb-58c7-4dd0-9766-4a16385af8d8 Dialplan: sofia/internal/212@172.16.8.73 Action set(api_hangup_hook=lua app.lua hangup)
4dc537cb-58c7-4dd0-9766-4a16385af8d8 Dialplan: sofia/internal/212@172.16.8.73 Action hash(insert/${domain_name}-last_dial/${called_party_call_group}/${uuid})
4dc537cb-58c7-4dd0-9766-4a16385af8d8 Dialplan: sofia/internal/212@172.16.8.73 Action set(called_party_call_group=${user_data(${dialed_extension}@${domain_name} var call_group)})
4dc537cb-58c7-4dd0-9766-4a16385af8d8 Dialplan: sofia/internal/212@172.16.8.73 Action hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid})
4dc537cb-58c7-4dd0-9766-4a16385af8d8 Dialplan: sofia/internal/212@172.16.8.73 Action hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number})
4dc537cb-58c7-4dd0-9766-4a16385af8d8 Dialplan: sofia/internal/212@172.16.8.73 Action set(continue_on_fail=true)
4dc537cb-58c7-4dd0-9766-4a16385af8d8 Dialplan: sofia/internal/212@172.16.8.73 Action set(hangup_after_bridge=true)
4dc537cb-58c7-4dd0-9766-4a16385af8d8 Dialplan: sofia/internal/212@172.16.8.73 Regex (PASS) [local_extension] () =~ // break=on-false
4dc537cb-58c7-4dd0-9766-4a16385af8d8 Dialplan: sofia/internal/212@172.16.8.73 Action limit(hash ${domain_name} ${destination_number} ${limit_max} ${limit_destination})
3:29:11.971257 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [dialed_extension]=[233]

DigitalDaz · Dec 12, 2017

Catch the sip with ngrep

So ssh into the box

Code:

apt-get install ngrep
ngrep -deth0 port 5060 -W byline

Change the eth0 to whatever interface it is

Daniel B · Dec 12, 2017

Hello again,

Guess what, I had to move the workstation that fusionpbx is running on and I plugged the network cable into a different switch and now the problem seems resolved. I ran the commands you gave me and was expecting to get disconnected again, but the call lasted 5 minutes until I stopped it.
It's curious that the former switch is a gigabit one, with no management features.
I will continue to test with other calls.
Here is what you requested, perhaps you see something out of place:

#
U 172.16.8.188:49159 -> 172.16.8.73:5060
BYE sip:233@172.16.8.73:5060;transport=udp SIP/2.0.
Via: SIP/2.0/UDP 172.16.8.188:5060;branch=z9hG4bK423eeac8.
From: "IT" <sip:212@172.16.8.73>;tag=00070e36b3b0000519e923c6-f9b026cf.
To: <sip:233@172.16.8.73>;tag=UZmyeF9yNc03N.
Call-ID: 00070e36-b3b00005-0ab6b00c-914e7ab1@172.16.8.188.
Max-Forwards: 70.
Date: Tue, 12 Dec 2017 12:02:29 GMT.
CSeq: 103 BYE.
User-Agent: Cisco-CP7911G/8.5.3.
Content-Length: 0.
Proxy-Authorization: Digest username="212",realm="172.16.8.73",uri="sip:233@172.16.8.73:5060;transport=udp",response="39205e7553e1a29724e3b13832f373e8",nonce="fbe07e5f-5f8a-4fc7-b548-4c825869929e",cnonce="babdec15",qop=auth,nc=00000002,algorithm=MD5.
.

#
U 172.16.8.73:5060 -> 172.16.8.188:49159
BYE sip:212@172.16.8.188:5060;transport=udp SIP/2.0.
Via: SIP/2.0/UDP 172.16.8.73;rport;branch=z9hG4bKK605agSU0HK0g.
Max-Forwards: 70.
From: <sip:233@172.16.8.73>;tag=UZmyeF9yNc03N.
To: "IT" <sip:212@172.16.8.73>;tag=00070e36b3b0000519e923c6-f9b026cf.
Call-ID: 00070e36-b3b00005-0ab6b00c-914e7ab1@172.16.8.188.
CSeq: 116200411 BYE.
User-Agent: FreeSWITCH.
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE.
Supported: timer, path, replaces.
Reason: Q.850;cause=16;text="NORMAL_CLEARING".
Content-Length: 0.
.

#
U 172.16.8.73:5060 -> 172.16.8.188:5060
SIP/2.0 200 OK.
Via: SIP/2.0/UDP 172.16.8.188:5060;branch=z9hG4bK423eeac8.
From: "IT" <sip:212@172.16.8.73>;tag=00070e36b3b0000519e923c6-f9b026cf.
To: <sip:233@172.16.8.73>;tag=UZmyeF9yNc03N.
Call-ID: 00070e36-b3b00005-0ab6b00c-914e7ab1@172.16.8.188.
CSeq: 103 BYE.
Content-Length: 0.
.

^Cexit
9 received, 0 dropped
root@fusionpbx:/home/user1# clear
root@fusionpbx:/home/user1# ngrep -dens32 port 5060 -W byline
interface: ens32 (172.16.8.0/255.255.255.0)
filter: (ip or ip6) and ( port 5060 )
#
U 172.16.8.188:49159 -> 172.16.8.73:5060
INVITE sip:248@172.16.8.73 SIP/2.0.
Via: SIP/2.0/UDP 172.16.8.188:5060;branch=z9hG4bK8a1c3155.
From: "IT" <sip:212@172.16.8.73>;tag=00070e36b3b000066ee9c835-9b78f895.
To: <sip:248@172.16.8.73>.
Call-ID: 00070e36-b3b00006-1a5a8975-ec242cd5@172.16.8.188.
Max-Forwards: 70.
Date: Tue, 12 Dec 2017 12:03:23 GMT.
CSeq: 101 INVITE.
User-Agent: Cisco-CP7911G/8.5.3.
Contact: <sip:212@172.16.8.188:5060;transport=udp>.
Expires: 180.
Accept: application/sdp.
Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE.
Supported: replaces,join,norefersub.
Allow-Events: kpml,dialog.
Content-Length: 324.
Content-Type: application/sdp.
Content-Disposition: session;handling=optional.
.
v=0.
o=Cisco-SIPUA 27591 0 IN IP4 172.16.8.188.
s=SIP Call.
t=0 0.
m=audio 24522 RTP/AVP 0 8 18 116 101.
c=IN IP4 172.16.8.188.
a=rtpmap:0 PCMU/8000.
a=rtpmap:8 PCMA/8000.
a=rtpmap:18 G729/8000.
a=fmtp:18 annexb=no.
a=rtpmap:116 iLBC/8000.
a=fmtp:116 mode=20.
a=rtpmap:101 telephone-event/8000.
a=fmtp:101 0-15.
a=sendrecv.

#
U 172.16.8.73:5060 -> 172.16.8.188:5060
SIP/2.0 100 Trying.
Via: SIP/2.0/UDP 172.16.8.188:5060;branch=z9hG4bK8a1c3155.
From: "IT" <sip:212@172.16.8.73>;tag=00070e36b3b000066ee9c835-9b78f895.
To: <sip:248@172.16.8.73>.
Call-ID: 00070e36-b3b00006-1a5a8975-ec242cd5@172.16.8.188.
CSeq: 101 INVITE.
User-Agent: FreeSWITCH.
Content-Length: 0.
.

#
U 172.16.8.73:5060 -> 172.16.8.188:5060
SIP/2.0 407 Proxy Authentication Required.
Via: SIP/2.0/UDP 172.16.8.188:5060;branch=z9hG4bK8a1c3155.
From: "IT" <sip:212@172.16.8.73>;tag=00070e36b3b000066ee9c835-9b78f895.
To: <sip:248@172.16.8.73>;tag=yt08K0U9c72Ur.
Call-ID: 00070e36-b3b00006-1a5a8975-ec242cd5@172.16.8.188.
CSeq: 101 INVITE.
User-Agent: FreeSWITCH.
Accept: application/sdp.
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE.
Supported: timer, path, replaces.
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer.
Proxy-Authenticate: Digest realm="172.16.8.73", nonce="8ecce47a-d518-494e-882b-6fa4a420424e", algorithm=MD5, qop="auth".
Content-Length: 0.
.

#
U 172.16.8.188:49162 -> 172.16.8.73:5060
ACK sip:248@172.16.8.73 SIP/2.0.
Via: SIP/2.0/UDP 172.16.8.188:5060;branch=z9hG4bK8a1c3155.
From: "IT" <sip:212@172.16.8.73>;tag=00070e36b3b000066ee9c835-9b78f895.
To: <sip:248@172.16.8.73>;tag=yt08K0U9c72Ur.
Call-ID: 00070e36-b3b00006-1a5a8975-ec242cd5@172.16.8.188.
Date: Tue, 12 Dec 2017 12:03:23 GMT.
CSeq: 101 ACK.
Content-Length: 0.
.

#
U 172.16.8.188:49159 -> 172.16.8.73:5060
INVITE sip:248@172.16.8.73 SIP/2.0.
Via: SIP/2.0/UDP 172.16.8.188:5060;branch=z9hG4bKbf3cad15.
From: "IT" <sip:212@172.16.8.73>;tag=00070e36b3b000066ee9c835-9b78f895.
To: <sip:248@172.16.8.73>.
Call-ID: 00070e36-b3b00006-1a5a8975-ec242cd5@172.16.8.188.
Max-Forwards: 70.
Date: Tue, 12 Dec 2017 12:03:23 GMT.
CSeq: 102 INVITE.
User-Agent: Cisco-CP7911G/8.5.3.
Contact: <sip:212@172.16.8.188:5060;transport=udp>.
Proxy-Authorization: Digest username="212",realm="172.16.8.73",uri="sip:248@172.16.8.73",response="6dec1034d14a7b6cf9884d2807a23b22",nonce="8ecce47a-d518-494e-882b-6fa4a420424e",cnonce="6953b2f5",qop=auth,nc=00000001,algorithm=MD5.
Expires: 180.
Accept: application/sdp.
Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE.
Supported: replaces,join,norefersub.
Allow-Events: kpml,dialog.
Content-Length: 324.
Content-Type: application/sdp.
Content-Disposition: session;handling=optional.
.
v=0.
o=Cisco-SIPUA 27591 0 IN IP4 172.16.8.188.
s=SIP Call.
t=0 0.
m=audio 24522 RTP/AVP 0 8 18 116 101.
c=IN IP4 172.16.8.188.
a=rtpmap:0 PCMU/8000.
a=rtpmap:8 PCMA/8000.
a=rtpmap:18 G729/8000.
a=fmtp:18 annexb=no.
a=rtpmap:116 iLBC/8000.
a=fmtp:116 mode=20.
a=rtpmap:101 telephone-event/8000.
a=fmtp:101 0-15.
a=sendrecv.

#
U 172.16.8.73:5060 -> 172.16.8.188:5060
SIP/2.0 100 Trying.
Via: SIP/2.0/UDP 172.16.8.188:5060;branch=z9hG4bKbf3cad15.
From: "IT" <sip:212@172.16.8.73>;tag=00070e36b3b000066ee9c835-9b78f895.
To: <sip:248@172.16.8.73>.
Call-ID: 00070e36-b3b00006-1a5a8975-ec242cd5@172.16.8.188.
CSeq: 102 INVITE.
User-Agent: FreeSWITCH.
Content-Length: 0.
.

#
U 172.16.8.73:5060 -> 172.16.8.181:5060
INVITE sip:248@172.16.8.181:5060;transport=udp SIP/2.0.
Via: SIP/2.0/UDP 172.16.8.73;rport;branch=z9hG4bKmFtycBaZXt9jc.
Max-Forwards: 69.
From: "IT" <sip:212@172.16.8.73>;tag=0cKtQpXg7rF1F.
To: <sip:248@172.16.8.181:5060;transport=udp>.
Call-ID: 89c9a326-59c6-1236-21a3-000c29ef6549.
CSeq: 116200439 INVITE.
Contact: <sip:mod_sofia@172.16.8.73:5060>.
User-Agent: FreeSWITCH.
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE.
Supported: timer, path, replaces.
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer.
Content-Type: application/sdp.
Content-Disposition: session.
Content-Length: 313.
X-FS-Support: update_display,send_info.
Remote-Party-ID: "IT" <sip:212@172.16.8.73>;party=calling;screen=yes;privacy=off.
.
v=0.
o=FreeSWITCH 1513054712 1513054713 IN IP4 172.16.8.73.
s=FreeSWITCH.
c=IN IP4 172.16.8.73.
t=0 0.
m=audio 25492 RTP/AVP 0 9 8 3 101 13.
a=rtpmap:0 PCMU/8000.
a=rtpmap:9 G722/8000.
a=rtpmap:8 PCMA/8000.
a=rtpmap:3 GSM/8000.
a=rtpmap:101 telephone-event/8000.
a=fmtp:101 0-16.
a=rtpmap:13 CN/8000.
a=ptime:20.

#
U 172.16.8.181:49153 -> 172.16.8.73:5060
SIP/2.0 100 Trying.
Via: SIP/2.0/UDP 172.16.8.73;rport;branch=z9hG4bKmFtycBaZXt9jc.
From: "IT" <sip:212@172.16.8.73>;tag=0cKtQpXg7rF1F.
To: <sip:248@172.16.8.181:5060;transport=udp>.
Call-ID: 89c9a326-59c6-1236-21a3-000c29ef6549.
Date: Tue, 12 Dec 2017 12:03:23 GMT.
CSeq: 116200439 INVITE.
Server: Cisco-CP7911G/8.5.3.
Contact: <sip:248@172.16.8.181:5060;transport=udp>.
Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE.
Allow-Events: kpml,dialog.
Content-Length: 0.
.

#
U 172.16.8.181:49153 -> 172.16.8.73:5060
SIP/2.0 180 Ringing.
Via: SIP/2.0/UDP 172.16.8.73;rport;branch=z9hG4bKmFtycBaZXt9jc.
From: "IT" <sip:212@172.16.8.73>;tag=0cKtQpXg7rF1F.
To: <sip:248@172.16.8.181:5060;transport=udp>;tag=001bd4a02f03004b90864f7a-b554f079.
Call-ID: 89c9a326-59c6-1236-21a3-000c29ef6549.
Date: Tue, 12 Dec 2017 12:03:23 GMT.
CSeq: 116200439 INVITE.
Server: Cisco-CP7911G/8.5.3.
Contact: <sip:248@172.16.8.181:5060;transport=udp>.
Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE.
Allow-Events: kpml,dialog.
Content-Length: 0.
.

#
U 172.16.8.73:5060 -> 172.16.8.188:5060
SIP/2.0 180 Ringing.
Via: SIP/2.0/UDP 172.16.8.188:5060;branch=z9hG4bKbf3cad15.
From: "IT" <sip:212@172.16.8.73>;tag=00070e36b3b000066ee9c835-9b78f895.
To: <sip:248@172.16.8.73>;tag=Z3S1NUcDagSem.
Call-ID: 00070e36-b3b00006-1a5a8975-ec242cd5@172.16.8.188.
CSeq: 102 INVITE.
Contact: <sip:248@172.16.8.73:5060;transport=udp>.
User-Agent: FreeSWITCH.
Accept: application/sdp.
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE.
Supported: timer, path, replaces.
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer.
Content-Length: 0.
Remote-Party-ID: "248" <sip:248@172.16.8.73>;party=calling;privacy=off;screen=no.
.

#
U 172.16.8.181:49153 -> 172.16.8.73:5060
SIP/2.0 200 OK.
Via: SIP/2.0/UDP 172.16.8.73;rport;branch=z9hG4bKmFtycBaZXt9jc.
From: "IT" <sip:212@172.16.8.73>;tag=0cKtQpXg7rF1F.
To: <sip:248@172.16.8.181:5060;transport=udp>;tag=001bd4a02f03004b90864f7a-b554f079.
Call-ID: 89c9a326-59c6-1236-21a3-000c29ef6549.
Date: Tue, 12 Dec 2017 12:03:26 GMT.
CSeq: 116200439 INVITE.
Server: Cisco-CP7911G/8.5.3.
Contact: <sip:248@172.16.8.181:5060;transport=udp>.
Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE.
Supported: replaces,join,norefersub.
Allow-Events: kpml,dialog.
Content-Length: 205.
Content-Type: application/sdp.
Content-Disposition: session;handling=optional.
.
v=0.
o=Cisco-SIPUA 26952 0 IN IP4 172.16.8.181.
s=SIP Call.
t=0 0.
m=audio 18056 RTP/AVP 0 101.
c=IN IP4 172.16.8.181.
a=rtpmap:0 PCMU/8000.
a=rtpmap:101 telephone-event/8000.
a=fmtp:101 0-15.
a=sendrecv.

#
U 172.16.8.73:5060 -> 172.16.8.181:5060
ACK sip:248@172.16.8.181:5060;transport=udp SIP/2.0.
Via: SIP/2.0/UDP 172.16.8.73;rport;branch=z9hG4bKNrKQe6t2t3Z5Q.
Max-Forwards: 70.
From: "IT" <sip:212@172.16.8.73>;tag=0cKtQpXg7rF1F.
To: <sip:248@172.16.8.181:5060;transport=udp>;tag=001bd4a02f03004b90864f7a-b554f079.
Call-ID: 89c9a326-59c6-1236-21a3-000c29ef6549.
CSeq: 116200439 ACK.
Contact: <sip:mod_sofia@172.16.8.73:5060>.
Content-Length: 0.
.

#
U 172.16.8.73:5060 -> 172.16.8.188:5060
SIP/2.0 200 OK.
Via: SIP/2.0/UDP 172.16.8.188:5060;branch=z9hG4bKbf3cad15.
From: "IT" <sip:212@172.16.8.73>;tag=00070e36b3b000066ee9c835-9b78f895.
To: <sip:248@172.16.8.73>;tag=Z3S1NUcDagSem.
Call-ID: 00070e36-b3b00006-1a5a8975-ec242cd5@172.16.8.188.
CSeq: 102 INVITE.
Contact: <sip:248@172.16.8.73:5060;transport=udp>.
User-Agent: FreeSWITCH.
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE.
Supported: timer, path, replaces.
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer.
Session-Expires: 120;refresher=uas.
Content-Type: application/sdp.
Content-Disposition: session.
Content-Length: 218.
Remote-Party-ID: "248" <sip:248@172.16.8.73>;party=calling;privacy=off;screen=no.
.
v=0.
o=FreeSWITCH 1513050522 1513050523 IN IP4 172.16.8.73.
s=FreeSWITCH.
c=IN IP4 172.16.8.73.
t=0 0.
m=audio 29686 RTP/AVP 0 101.
a=rtpmap:0 PCMU/8000.
a=rtpmap:101 telephone-event/8000.
a=fmtp:101 0-16.
a=ptime:20.

#
U 172.16.8.188:49159 -> 172.16.8.73:5060
ACK sip:248@172.16.8.73:5060;transport=udp SIP/2.0.
Via: SIP/2.0/UDP 172.16.8.188:5060;branch=z9hG4bK5444a7b5.
From: "IT" <sip:212@172.16.8.73>;tag=00070e36b3b000066ee9c835-9b78f895.
To: <sip:248@172.16.8.73>;tag=Z3S1NUcDagSem.
Call-ID: 00070e36-b3b00006-1a5a8975-ec242cd5@172.16.8.188.
Max-Forwards: 70.
Date: Tue, 12 Dec 2017 12:03:26 GMT.
CSeq: 102 ACK.
User-Agent: Cisco-CP7911G/8.5.3.
Proxy-Authorization: Digest username="212",realm="172.16.8.73",uri="sip:248@172.16.8.73",response="6dec1034d14a7b6cf9884d2807a23b22",nonce="8ecce47a-d518-494e-882b-6fa4a420424e",cnonce="6953b2f5",qop=auth,nc=00000001,algorithm=MD5.
Content-Length: 0.
.

#
U 172.16.8.188:49159 -> 172.16.8.73:5060
BYE sip:248@172.16.8.73:5060;transport=udp SIP/2.0.
Via: SIP/2.0/UDP 172.16.8.188:5060;branch=z9hG4bK8d4d9827.
From: "IT" <sip:212@172.16.8.73>;tag=00070e36b3b000066ee9c835-9b78f895.
To: <sip:248@172.16.8.73>;tag=Z3S1NUcDagSem.
Call-ID: 00070e36-b3b00006-1a5a8975-ec242cd5@172.16.8.188.
Max-Forwards: 70.
Date: Tue, 12 Dec 2017 12:08:37 GMT.
CSeq: 103 BYE.
User-Agent: Cisco-CP7911G/8.5.3.
Content-Length: 0.
Proxy-Authorization: Digest username="212",realm="172.16.8.73",uri="sip:248@172.16.8.73:5060;transport=udp",response="953d050ffa6659b47ccc79213483a5bd",nonce="8ecce47a-d518-494e-882b-6fa4a420424e",cnonce="9990fcb9",qop=auth,nc=00000002,algorithm=MD5.
.

#
U 172.16.8.73:5060 -> 172.16.8.188:5060
SIP/2.0 200 OK.
Via: SIP/2.0/UDP 172.16.8.188:5060;branch=z9hG4bK8d4d9827.
From: "IT" <sip:212@172.16.8.73>;tag=00070e36b3b000066ee9c835-9b78f895.
To: <sip:248@172.16.8.73>;tag=Z3S1NUcDagSem.
Call-ID: 00070e36-b3b00006-1a5a8975-ec242cd5@172.16.8.188.
CSeq: 103 BYE.
User-Agent: FreeSWITCH.
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE.
Supported: timer, path, replaces.
Content-Length: 0.
.

#
U 172.16.8.73:5060 -> 172.16.8.181:5060
BYE sip:248@172.16.8.181:5060;transport=udp SIP/2.0.
Via: SIP/2.0/UDP 172.16.8.73;rport;branch=z9hG4bKp1cgg1B6QcprK.
Max-Forwards: 70.
From: "IT" <sip:212@172.16.8.73>;tag=0cKtQpXg7rF1F.
To: <sip:248@172.16.8.181:5060;transport=udp>;tag=001bd4a02f03004b90864f7a-b554f079.
Call-ID: 89c9a326-59c6-1236-21a3-000c29ef6549.
CSeq: 116200440 BYE.
User-Agent: FreeSWITCH.
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE.
Supported: timer, path, replaces.
Reason: Q.850;cause=16;text="NORMAL_CLEARING".
Content-Length: 0.
.

#
U 172.16.8.181:49153 -> 172.16.8.73:5060
SIP/2.0 200 OK.
Via: SIP/2.0/UDP 172.16.8.73;rport;branch=z9hG4bKp1cgg1B6QcprK.
From: "IT" <sip:212@172.16.8.73>;tag=0cKtQpXg7rF1F.
To: <sip:248@172.16.8.181:5060;transport=udp>;tag=001bd4a02f03004b90864f7a-b554f079.
Call-ID: 89c9a326-59c6-1236-21a3-000c29ef6549.
Date: Tue, 12 Dec 2017 12:08:37 GMT.
CSeq: 116200440 BYE.
Server: Cisco-CP7911G/8.5.3.
Content-Length: 0.
.

^Cexit
22 received, 0 dropped
root@fusionpbx:/home/user1#

Daniel B · Dec 12, 2017

So, apparently I spoke too soon. The problem happened once again. It only worked for half an hour maybe before it started again.
I ran the trace again like you said. Here is the output:

ngrep -dens32 port 5060 -W byline
interface: ens32 (172.16.8.0/255.255.255.0)
filter: (ip or ip6) and ( port 5060 )
#
U 172.16.8.188:49159 -> 172.16.8.73:5060
INVITE sip:248@172.16.8.73 SIP/2.0.
Via: SIP/2.0/UDP 172.16.8.188:5060;branch=z9hG4bKfb87b77f.
From: "IT" <sip:212@172.16.8.73>;tag=00070e36b3b00018d240b8dc-e1632e21.
To: <sip:248@172.16.8.73>.
Call-ID: 00070e36-b3b0000f-0f715d4a-e291ab93@172.16.8.188.
Max-Forwards: 70.
Date: Tue, 12 Dec 2017 17:59:01 GMT.
CSeq: 101 INVITE.
User-Agent: Cisco-CP7911G/8.5.3.
Contact: <sip:212@172.16.8.188:5060;transport=udp>.
Expires: 180.
Accept: application/sdp.
Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE.
Supported: replaces,join,norefersub.
Allow-Events: kpml,dialog.
Content-Length: 324.
Content-Type: application/sdp.
Content-Disposition: session;handling=optional.
.
v=0.
o=Cisco-SIPUA 26490 0 IN IP4 172.16.8.188.
s=SIP Call.
t=0 0.
m=audio 22952 RTP/AVP 0 8 18 116 101.
c=IN IP4 172.16.8.188.
a=rtpmap:0 PCMU/8000.
a=rtpmap:8 PCMA/8000.
a=rtpmap:18 G729/8000.
a=fmtp:18 annexb=no.
a=rtpmap:116 iLBC/8000.
a=fmtp:116 mode=20.
a=rtpmap:101 telephone-event/8000.
a=fmtp:101 0-15.
a=sendrecv.

#
U 172.16.8.73:5060 -> 172.16.8.188:5060
SIP/2.0 100 Trying.
Via: SIP/2.0/UDP 172.16.8.188:5060;branch=z9hG4bKfb87b77f.
From: "IT" <sip:212@172.16.8.73>;tag=00070e36b3b00018d240b8dc-e1632e21.
To: <sip:248@172.16.8.73>.
Call-ID: 00070e36-b3b0000f-0f715d4a-e291ab93@172.16.8.188.
CSeq: 101 INVITE.
User-Agent: FreeSWITCH.
Content-Length: 0.
.

#
U 172.16.8.73:5060 -> 172.16.8.188:5060
SIP/2.0 407 Proxy Authentication Required.
Via: SIP/2.0/UDP 172.16.8.188:5060;branch=z9hG4bKfb87b77f.
From: "IT" <sip:212@172.16.8.73>;tag=00070e36b3b00018d240b8dc-e1632e21.
To: <sip:248@172.16.8.73>;tag=K0UUZ6NtcBypH.
Call-ID: 00070e36-b3b0000f-0f715d4a-e291ab93@172.16.8.188.
CSeq: 101 INVITE.
User-Agent: FreeSWITCH.
Accept: application/sdp.
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE.
Supported: timer, path, replaces.
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer.
Proxy-Authenticate: Digest realm="172.16.8.73", nonce="76b06f63-6177-40fa-bf24-78f26226c616", algorithm=MD5, qop="auth".
Content-Length: 0.
.

#
U 172.16.8.188:49174 -> 172.16.8.73:5060
ACK sip:248@172.16.8.73 SIP/2.0.
Via: SIP/2.0/UDP 172.16.8.188:5060;branch=z9hG4bKfb87b77f.
From: "IT" <sip:212@172.16.8.73>;tag=00070e36b3b00018d240b8dc-e1632e21.
To: <sip:248@172.16.8.73>;tag=K0UUZ6NtcBypH.
Call-ID: 00070e36-b3b0000f-0f715d4a-e291ab93@172.16.8.188.
Date: Tue, 12 Dec 2017 17:59:01 GMT.
CSeq: 101 ACK.
Content-Length: 0.
.

#
U 172.16.8.188:49159 -> 172.16.8.73:5060
INVITE sip:248@172.16.8.73 SIP/2.0.
Via: SIP/2.0/UDP 172.16.8.188:5060;branch=z9hG4bK934dfecd.
From: "IT" <sip:212@172.16.8.73>;tag=00070e36b3b00018d240b8dc-e1632e21.
To: <sip:248@172.16.8.73>.
Call-ID: 00070e36-b3b0000f-0f715d4a-e291ab93@172.16.8.188.
Max-Forwards: 70.
Date: Tue, 12 Dec 2017 17:59:01 GMT.
CSeq: 102 INVITE.
User-Agent: Cisco-CP7911G/8.5.3.
Contact: <sip:212@172.16.8.188:5060;transport=udp>.
Proxy-Authorization: Digest username="212",realm="172.16.8.73",uri="sip:248@172.16.8.73",response="481a2d6cb327b5ee59d6b9a622c11abd",nonce="76b06f63-6177-40fa-bf24-78f26226c616",cnonce="726259d6",qop=auth,nc=00000001,algorithm=MD5.
Expires: 180.
Accept: application/sdp.
Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE.
Supported: replaces,join,norefersub.
Allow-Events: kpml,dialog.
Content-Length: 324.
Content-Type: application/sdp.
Content-Disposition: session;handling=optional.
.
v=0.
o=Cisco-SIPUA 26490 0 IN IP4 172.16.8.188.
s=SIP Call.
t=0 0.
m=audio 22952 RTP/AVP 0 8 18 116 101.
c=IN IP4 172.16.8.188.
a=rtpmap:0 PCMU/8000.
a=rtpmap:8 PCMA/8000.
a=rtpmap:18 G729/8000.
a=fmtp:18 annexb=no.
a=rtpmap:116 iLBC/8000.
a=fmtp:116 mode=20.
a=rtpmap:101 telephone-event/8000.
a=fmtp:101 0-15.
a=sendrecv.

#
U 172.16.8.73:5060 -> 172.16.8.188:5060
SIP/2.0 100 Trying.
Via: SIP/2.0/UDP 172.16.8.188:5060;branch=z9hG4bK934dfecd.
From: "IT" <sip:212@172.16.8.73>;tag=00070e36b3b00018d240b8dc-e1632e21.
To: <sip:248@172.16.8.73>.
Call-ID: 00070e36-b3b0000f-0f715d4a-e291ab93@172.16.8.188.
CSeq: 102 INVITE.
User-Agent: FreeSWITCH.
Content-Length: 0.
.

#
U 172.16.8.73:5060 -> 172.16.8.181:5060
INVITE sip:248@172.16.8.181:5060;transport=udp SIP/2.0.
Via: SIP/2.0/UDP 172.16.8.73;rport;branch=z9hG4bK84v789Np79FZp.
Max-Forwards: 69.
From: "IT" <sip:212@172.16.8.73>;tag=NjeD3vQ16vavr.
To: <sip:248@172.16.8.181:5060;transport=udp>.
Call-ID: 393233b8-59f8-1236-21a3-000c29ef6549.
CSeq: 116211109 INVITE.
Contact: <sip:mod_sofia@172.16.8.73:5060>.
User-Agent: FreeSWITCH.
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE.
Supported: timer, path, replaces.
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer.
Content-Type: application/sdp.
Content-Disposition: session.
Content-Length: 313.
X-FS-Support: update_display,send_info.
Remote-Party-ID: "IT" <sip:212@172.16.8.73>;party=calling;screen=yes;privacy=off.
.
v=0.
o=FreeSWITCH 1513075130 1513075131 IN IP4 172.16.8.73.
s=FreeSWITCH.
c=IN IP4 172.16.8.73.
t=0 0.
m=audio 26414 RTP/AVP 0 9 8 3 101 13.
a=rtpmap:0 PCMU/8000.
a=rtpmap:9 G722/8000.
a=rtpmap:8 PCMA/8000.
a=rtpmap:3 GSM/8000.
a=rtpmap:101 telephone-event/8000.
a=fmtp:101 0-16.
a=rtpmap:13 CN/8000.
a=ptime:20.

#
U 172.16.8.181:49153 -> 172.16.8.73:5060
SIP/2.0 100 Trying.
Via: SIP/2.0/UDP 172.16.8.73;rport;branch=z9hG4bK84v789Np79FZp.
From: "IT" <sip:212@172.16.8.73>;tag=NjeD3vQ16vavr.
To: <sip:248@172.16.8.181:5060;transport=udp>.
Call-ID: 393233b8-59f8-1236-21a3-000c29ef6549.
Date: Tue, 12 Dec 2017 17:59:02 GMT.
CSeq: 116211109 INVITE.
Server: Cisco-CP7911G/8.5.3.
Contact: <sip:248@172.16.8.181:5060;transport=udp>.
Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE.
Allow-Events: kpml,dialog.
Content-Length: 0.
.

#
U 172.16.8.181:49153 -> 172.16.8.73:5060
SIP/2.0 180 Ringing.
Via: SIP/2.0/UDP 172.16.8.73;rport;branch=z9hG4bK84v789Np79FZp.
From: "IT" <sip:212@172.16.8.73>;tag=NjeD3vQ16vavr.
To: <sip:248@172.16.8.181:5060;transport=udp>;tag=001bd4a02f03005bad1b9f66-6fd440e0.
Call-ID: 393233b8-59f8-1236-21a3-000c29ef6549.
Date: Tue, 12 Dec 2017 17:59:02 GMT.
CSeq: 116211109 INVITE.
Server: Cisco-CP7911G/8.5.3.
Contact: <sip:248@172.16.8.181:5060;transport=udp>.
Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE.
Allow-Events: kpml,dialog.
Content-Length: 0.
.

#
U 172.16.8.73:5060 -> 172.16.8.188:5060
SIP/2.0 180 Ringing.
Via: SIP/2.0/UDP 172.16.8.188:5060;branch=z9hG4bK934dfecd.
From: "IT" <sip:212@172.16.8.73>;tag=00070e36b3b00018d240b8dc-e1632e21.
To: <sip:248@172.16.8.73>;tag=m9mm116X9Km9c.
Call-ID: 00070e36-b3b0000f-0f715d4a-e291ab93@172.16.8.188.
CSeq: 102 INVITE.
Contact: <sip:248@172.16.8.73:5060;transport=udp>.
User-Agent: FreeSWITCH.
Accept: application/sdp.
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE.
Supported: timer, path, replaces.
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer.
Content-Length: 0.
Remote-Party-ID: "248" <sip:248@172.16.8.73>;party=calling;privacy=off;screen=no.
.

#
U 172.16.8.181:49153 -> 172.16.8.73:5060
SIP/2.0 200 OK.
Via: SIP/2.0/UDP 172.16.8.73;rport;branch=z9hG4bK84v789Np79FZp.
From: "IT" <sip:212@172.16.8.73>;tag=NjeD3vQ16vavr.
To: <sip:248@172.16.8.181:5060;transport=udp>;tag=001bd4a02f03005bad1b9f66-6fd440e0.
Call-ID: 393233b8-59f8-1236-21a3-000c29ef6549.
Date: Tue, 12 Dec 2017 17:59:04 GMT.
CSeq: 116211109 INVITE.
Server: Cisco-CP7911G/8.5.3.
Contact: <sip:248@172.16.8.181:5060;transport=udp>.
Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE.
Supported: replaces,join,norefersub.
Allow-Events: kpml,dialog.
Content-Length: 204.
Content-Type: application/sdp.
Content-Disposition: session;handling=optional.
.
v=0.
o=Cisco-SIPUA 4724 0 IN IP4 172.16.8.181.
s=SIP Call.
t=0 0.
m=audio 19548 RTP/AVP 0 101.
c=IN IP4 172.16.8.181.
a=rtpmap:0 PCMU/8000.
a=rtpmap:101 telephone-event/8000.
a=fmtp:101 0-15.
a=sendrecv.

#
U 172.16.8.73:5060 -> 172.16.8.181:5060
ACK sip:248@172.16.8.181:5060;transport=udp SIP/2.0.
Via: SIP/2.0/UDP 172.16.8.73;rport;branch=z9hG4bK9Dp0a56S4j6Hj.
Max-Forwards: 70.
From: "IT" <sip:212@172.16.8.73>;tag=NjeD3vQ16vavr.
To: <sip:248@172.16.8.181:5060;transport=udp>;tag=001bd4a02f03005bad1b9f66-6fd440e0.
Call-ID: 393233b8-59f8-1236-21a3-000c29ef6549.
CSeq: 116211109 ACK.
Contact: <sip:mod_sofia@172.16.8.73:5060>.
Content-Length: 0.
.

#
U 172.16.8.73:5060 -> 172.16.8.188:5060
SIP/2.0 200 OK.
Via: SIP/2.0/UDP 172.16.8.188:5060;branch=z9hG4bK934dfecd.
From: "IT" <sip:212@172.16.8.73>;tag=00070e36b3b00018d240b8dc-e1632e21.
To: <sip:248@172.16.8.73>;tag=m9mm116X9Km9c.
Call-ID: 00070e36-b3b0000f-0f715d4a-e291ab93@172.16.8.188.
CSeq: 102 INVITE.
Contact: <sip:248@172.16.8.73:5060;transport=udp>.
User-Agent: FreeSWITCH.
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE.
Supported: timer, path, replaces.
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer.
Session-Expires: 120;refresher=uas.
Content-Type: application/sdp.
Content-Disposition: session.
Content-Length: 218.
Remote-Party-ID: "248" <sip:248@172.16.8.73>;party=calling;privacy=off;screen=no.
.
v=0.
o=FreeSWITCH 1513081507 1513081508 IN IP4 172.16.8.73.
s=FreeSWITCH.
c=IN IP4 172.16.8.73.
t=0 0.
m=audio 20040 RTP/AVP 0 101.
a=rtpmap:0 PCMU/8000.
a=rtpmap:101 telephone-event/8000.
a=fmtp:101 0-16.
a=ptime:20.

#
U 172.16.8.188:49159 -> 172.16.8.73:5060
ACK sip:248@172.16.8.73:5060;transport=udp SIP/2.0.
Via: SIP/2.0/UDP 172.16.8.188:5060;branch=z9hG4bK74773cc6.
From: "IT" <sip:212@172.16.8.73>;tag=00070e36b3b00018d240b8dc-e1632e21.
To: <sip:248@172.16.8.73>;tag=m9mm116X9Km9c.
Call-ID: 00070e36-b3b0000f-0f715d4a-e291ab93@172.16.8.188.
Max-Forwards: 70.
Date: Tue, 12 Dec 2017 17:59:04 GMT.
CSeq: 102 ACK.
User-Agent: Cisco-CP7911G/8.5.3.
Proxy-Authorization: Digest username="212",realm="172.16.8.73",uri="sip:248@172.16.8.73",response="481a2d6cb327b5ee59d6b9a622c11abd",nonce="76b06f63-6177-40fa-bf24-78f26226c616",cnonce="726259d6",qop=auth,nc=00000001,algorithm=MD5.
Content-Length: 0.
.

#
U 172.16.8.73:5060 -> 172.16.8.188:49159
INVITE sip:212@172.16.8.188:5060;transport=udp SIP/2.0.
Via: SIP/2.0/UDP 172.16.8.73;rport;branch=z9hG4bKaQFSc0QX1Uv4D.
Max-Forwards: 70.
From: <sip:248@172.16.8.73>;tag=m9mm116X9Km9c.
To: "IT" <sip:212@172.16.8.73>;tag=00070e36b3b00018d240b8dc-e1632e21.
Call-ID: 00070e36-b3b0000f-0f715d4a-e291ab93@172.16.8.188.
CSeq: 116211142 INVITE.
Contact: <sip:248@172.16.8.73:5060;transport=udp>.
User-Agent: FreeSWITCH.
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE.
Supported: timer, path, replaces.
Session-Expires: 120;refresher=uac.
Min-SE: 120.
Content-Type: application/sdp.
Content-Disposition: session.
Content-Length: 218.
.
v=0.
o=FreeSWITCH 1513081507 1513081508 IN IP4 172.16.8.73.
s=FreeSWITCH.
c=IN IP4 172.16.8.73.
t=0 0.
m=audio 20040 RTP/AVP 0 101.
a=rtpmap:0 PCMU/8000.
a=rtpmap:101 telephone-event/8000.
a=fmtp:101 0-16.
a=ptime:20.

#
U 172.16.8.73:5060 -> 172.16.8.188:49159
INVITE sip:212@172.16.8.188:5060;transport=udp SIP/2.0.
Via: SIP/2.0/UDP 172.16.8.73;rport;branch=z9hG4bKaQFSc0QX1Uv4D.
Max-Forwards: 70.
From: <sip:248@172.16.8.73>;tag=m9mm116X9Km9c.
To: "IT" <sip:212@172.16.8.73>;tag=00070e36b3b00018d240b8dc-e1632e21.
Call-ID: 00070e36-b3b0000f-0f715d4a-e291ab93@172.16.8.188.
CSeq: 116211142 INVITE.
Contact: <sip:248@172.16.8.73:5060;transport=udp>.
User-Agent: FreeSWITCH.
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE.
Supported: timer, path, replaces.
Session-Expires: 120;refresher=uac.
Min-SE: 120.
Content-Type: application/sdp.
Content-Disposition: session.
Content-Length: 218.
.
v=0.
o=FreeSWITCH 1513081507 1513081508 IN IP4 172.16.8.73.
s=FreeSWITCH.
c=IN IP4 172.16.8.73.
t=0 0.
m=audio 20040 RTP/AVP 0 101.
a=rtpmap:0 PCMU/8000.
a=rtpmap:101 telephone-event/8000.
a=fmtp:101 0-16.
a=ptime:20.

#
U 172.16.8.73:5060 -> 172.16.8.188:49159
INVITE sip:212@172.16.8.188:5060;transport=udp SIP/2.0.
Via: SIP/2.0/UDP 172.16.8.73;rport;branch=z9hG4bKaQFSc0QX1Uv4D.
Max-Forwards: 70.
From: <sip:248@172.16.8.73>;tag=m9mm116X9Km9c.
To: "IT" <sip:212@172.16.8.73>;tag=00070e36b3b00018d240b8dc-e1632e21.
Call-ID: 00070e36-b3b0000f-0f715d4a-e291ab93@172.16.8.188.
CSeq: 116211142 INVITE.
Contact: <sip:248@172.16.8.73:5060;transport=udp>.
User-Agent: FreeSWITCH.
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE.
Supported: timer, path, replaces.
Session-Expires: 120;refresher=uac.
Min-SE: 120.
Content-Type: application/sdp.
Content-Disposition: session.
Content-Length: 218.
.
v=0.
o=FreeSWITCH 1513081507 1513081508 IN IP4 172.16.8.73.
s=FreeSWITCH.
c=IN IP4 172.16.8.73.
t=0 0.
m=audio 20040 RTP/AVP 0 101.
a=rtpmap:0 PCMU/8000.
a=rtpmap:101 telephone-event/8000.
a=fmtp:101 0-16.
a=ptime:20.

#
U 172.16.8.73:5060 -> 172.16.8.188:49159
INVITE sip:212@172.16.8.188:5060;transport=udp SIP/2.0.
Via: SIP/2.0/UDP 172.16.8.73;rport;branch=z9hG4bKaQFSc0QX1Uv4D.
Max-Forwards: 70.
From: <sip:248@172.16.8.73>;tag=m9mm116X9Km9c.
To: "IT" <sip:212@172.16.8.73>;tag=00070e36b3b00018d240b8dc-e1632e21.
Call-ID: 00070e36-b3b0000f-0f715d4a-e291ab93@172.16.8.188.
CSeq: 116211142 INVITE.
Contact: <sip:248@172.16.8.73:5060;transport=udp>.
User-Agent: FreeSWITCH.
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE.
Supported: timer, path, replaces.
Session-Expires: 120;refresher=uac.
Min-SE: 120.
Content-Type: application/sdp.
Content-Disposition: session.
Content-Length: 218.
.
v=0.
o=FreeSWITCH 1513081507 1513081508 IN IP4 172.16.8.73.
s=FreeSWITCH.
c=IN IP4 172.16.8.73.
t=0 0.
m=audio 20040 RTP/AVP 0 101.
a=rtpmap:0 PCMU/8000.
a=rtpmap:101 telephone-event/8000.
a=fmtp:101 0-16.
a=ptime:20.

#
U 172.16.8.73:5060 -> 172.16.8.188:49159
INVITE sip:212@172.16.8.188:5060;transport=udp SIP/2.0.
Via: SIP/2.0/UDP 172.16.8.73;rport;branch=z9hG4bKaQFSc0QX1Uv4D.
Max-Forwards: 70.
From: <sip:248@172.16.8.73>;tag=m9mm116X9Km9c.
To: "IT" <sip:212@172.16.8.73>;tag=00070e36b3b00018d240b8dc-e1632e21.
Call-ID: 00070e36-b3b0000f-0f715d4a-e291ab93@172.16.8.188.
CSeq: 116211142 INVITE.
Contact: <sip:248@172.16.8.73:5060;transport=udp>.
User-Agent: FreeSWITCH.
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE.
Supported: timer, path, replaces.
Session-Expires: 120;refresher=uac.
Min-SE: 120.
Content-Type: application/sdp.
Content-Disposition: session.
Content-Length: 218.
.
v=0.
o=FreeSWITCH 1513081507 1513081508 IN IP4 172.16.8.73.
s=FreeSWITCH.
c=IN IP4 172.16.8.73.
t=0 0.
m=audio 20040 RTP/AVP 0 101.
a=rtpmap:0 PCMU/8000.
a=rtpmap:101 telephone-event/8000.
a=fmtp:101 0-16.
a=ptime:20.

#
U 172.16.8.73:5060 -> 172.16.8.188:49159
INVITE sip:212@172.16.8.188:5060;transport=udp SIP/2.0.
Via: SIP/2.0/UDP 172.16.8.73;rport;branch=z9hG4bKaQFSc0QX1Uv4D.
Max-Forwards: 70.
From: <sip:248@172.16.8.73>;tag=m9mm116X9Km9c.
To: "IT" <sip:212@172.16.8.73>;tag=00070e36b3b00018d240b8dc-e1632e21.
Call-ID: 00070e36-b3b0000f-0f715d4a-e291ab93@172.16.8.188.
CSeq: 116211142 INVITE.
Contact: <sip:248@172.16.8.73:5060;transport=udp>.
User-Agent: FreeSWITCH.
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE.
Supported: timer, path, replaces.
Session-Expires: 120;refresher=uac.
Min-SE: 120.
Content-Type: application/sdp.
Content-Disposition: session.
Content-Length: 218.
.
v=0.
o=FreeSWITCH 1513081507 1513081508 IN IP4 172.16.8.73.
s=FreeSWITCH.
c=IN IP4 172.16.8.73.
t=0 0.
m=audio 20040 RTP/AVP 0 101.
a=rtpmap:0 PCMU/8000.
a=rtpmap:101 telephone-event/8000.
a=fmtp:101 0-16.
a=ptime:20.

#
U 172.16.8.73:5060 -> 172.16.8.188:49159
BYE sip:212@172.16.8.188:5060;transport=udp SIP/2.0.
Via: SIP/2.0/UDP 172.16.8.73;rport;branch=z9hG4bKB08HeU80y4jQS.
Max-Forwards: 70.
From: <sip:248@172.16.8.73>;tag=m9mm116X9Km9c.
To: "IT" <sip:212@172.16.8.73>;tag=00070e36b3b00018d240b8dc-e1632e21.
Call-ID: 00070e36-b3b0000f-0f715d4a-e291ab93@172.16.8.188.
CSeq: 116211143 BYE.
Contact: <sip:248@172.16.8.73:5060;transport=udp>.
User-Agent: FreeSWITCH.
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE.
Supported: timer, path, replaces.
Content-Length: 0.
.

#
U 172.16.8.73:5060 -> 172.16.8.181:5060
BYE sip:248@172.16.8.181:5060;transport=udp SIP/2.0.
Via: SIP/2.0/UDP 172.16.8.73;rport;branch=z9hG4bKc91agpS4UD99m.
Max-Forwards: 70.
From: "IT" <sip:212@172.16.8.73>;tag=NjeD3vQ16vavr.
To: <sip:248@172.16.8.181:5060;transport=udp>;tag=001bd4a02f03005bad1b9f66-6fd440e0.
Call-ID: 393233b8-59f8-1236-21a3-000c29ef6549.
CSeq: 116211110 BYE.
User-Agent: FreeSWITCH.
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE.
Supported: timer, path, replaces.
Reason: Q.850;cause=16;text="NORMAL_CLEARING".
Content-Length: 0.
.

#
U 172.16.8.181:49153 -> 172.16.8.73:5060
SIP/2.0 200 OK.
Via: SIP/2.0/UDP 172.16.8.73;rport;branch=z9hG4bKc91agpS4UD99m.
From: "IT" <sip:212@172.16.8.73>;tag=NjeD3vQ16vavr.
To: <sip:248@172.16.8.181:5060;transport=udp>;tag=001bd4a02f03005bad1b9f66-6fd440e0.
Call-ID: 393233b8-59f8-1236-21a3-000c29ef6549.
Date: Tue, 12 Dec 2017 18:00:39 GMT.
CSeq: 116211110 BYE.
Server: Cisco-CP7911G/8.5.3.
Content-Length: 0.
.

#
U 172.16.8.73:5060 -> 172.16.8.188:49159
BYE sip:212@172.16.8.188:5060;transport=udp SIP/2.0.
Via: SIP/2.0/UDP 172.16.8.73;rport;branch=z9hG4bKB08HeU80y4jQS.
Max-Forwards: 70.
From: <sip:248@172.16.8.73>;tag=m9mm116X9Km9c.
To: "IT" <sip:212@172.16.8.73>;tag=00070e36b3b00018d240b8dc-e1632e21.
Call-ID: 00070e36-b3b0000f-0f715d4a-e291ab93@172.16.8.188.
CSeq: 116211143 BYE.
Contact: <sip:248@172.16.8.73:5060;transport=udp>.
User-Agent: FreeSWITCH.
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE.
Supported: timer, path, replaces.
Content-Length: 0.
.

#
U 172.16.8.73:5060 -> 172.16.8.188:49159
BYE sip:212@172.16.8.188:5060;transport=udp SIP/2.0.
Via: SIP/2.0/UDP 172.16.8.73;rport;branch=z9hG4bKB08HeU80y4jQS.
Max-Forwards: 70.
From: <sip:248@172.16.8.73>;tag=m9mm116X9Km9c.
To: "IT" <sip:212@172.16.8.73>;tag=00070e36b3b00018d240b8dc-e1632e21.
Call-ID: 00070e36-b3b0000f-0f715d4a-e291ab93@172.16.8.188.
CSeq: 116211143 BYE.
Contact: <sip:248@172.16.8.73:5060;transport=udp>.
User-Agent: FreeSWITCH.
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE.
Supported: timer, path, replaces.
Content-Length: 0.
.

#
U 172.16.8.188:49159 -> 172.16.8.73:5060
BYE sip:248@172.16.8.73:5060;transport=udp SIP/2.0.
Via: SIP/2.0/UDP 172.16.8.188:5060;branch=z9hG4bK0a03d8b2.
From: "IT" <sip:212@172.16.8.73>;tag=00070e36b3b00018d240b8dc-e1632e21.
To: <sip:248@172.16.8.73>;tag=m9mm116X9Km9c.
Call-ID: 00070e36-b3b0000f-0f715d4a-e291ab93@172.16.8.188.
Max-Forwards: 70.
Date: Tue, 12 Dec 2017 18:00:46 GMT.
CSeq: 103 BYE.
User-Agent: Cisco-CP7911G/8.5.3.
Content-Length: 0.
Proxy-Authorization: Digest username="212",realm="172.16.8.73",uri="sip:248@172.16.8.73:5060;transport=udp",response="e71e6406ad9956266577af7ebfcfeeda",nonce="76b06f63-6177-40fa-bf24-78f26226c616",cnonce="033b0c36",qop=auth,nc=00000002,algorithm=MD5.
.

#
U 172.16.8.73:5060 -> 172.16.8.188:5060
SIP/2.0 481 Call Does Not Exist.
Via: SIP/2.0/UDP 172.16.8.188:5060;branch=z9hG4bK0a03d8b2.
From: "IT" <sip:212@172.16.8.73>;tag=00070e36b3b00018d240b8dc-e1632e21.
To: <sip:248@172.16.8.73>;tag=m9mm116X9Km9c.
Call-ID: 00070e36-b3b0000f-0f715d4a-e291ab93@172.16.8.188.
CSeq: 103 BYE.
User-Agent: FreeSWITCH.
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE.
Supported: timer, path, replaces.
Content-Length: 0.
.

#
U 172.16.8.73:5060 -> 172.16.8.188:49159
BYE sip:212@172.16.8.188:5060;transport=udp SIP/2.0.
Via: SIP/2.0/UDP 172.16.8.73;rport;branch=z9hG4bKB08HeU80y4jQS.
Max-Forwards: 70.
From: <sip:248@172.16.8.73>;tag=m9mm116X9Km9c.
To: "IT" <sip:212@172.16.8.73>;tag=00070e36b3b00018d240b8dc-e1632e21.
Call-ID: 00070e36-b3b0000f-0f715d4a-e291ab93@172.16.8.188.
CSeq: 116211143 BYE.
Contact: <sip:248@172.16.8.73:5060;transport=udp>.
User-Agent: FreeSWITCH.
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE.
Supported: timer, path, replaces.
Content-Length: 0.
.

#
U 172.16.8.73:5060 -> 172.16.8.188:49159
BYE sip:212@172.16.8.188:5060;transport=udp SIP/2.0.
Via: SIP/2.0/UDP 172.16.8.73;rport;branch=z9hG4bKB08HeU80y4jQS.
Max-Forwards: 70.
From: <sip:248@172.16.8.73>;tag=m9mm116X9Km9c.
To: "IT" <sip:212@172.16.8.73>;tag=00070e36b3b00018d240b8dc-e1632e21.
Call-ID: 00070e36-b3b0000f-0f715d4a-e291ab93@172.16.8.188.
CSeq: 116211143 BYE.
Contact: <sip:248@172.16.8.73:5060;transport=udp>.
User-Agent: FreeSWITCH.
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE.
Supported: timer, path, replaces.
Content-Length: 0.
.

#
U 172.16.8.73:5060 -> 172.16.8.188:49159
BYE sip:212@172.16.8.188:5060;transport=udp SIP/2.0.
Via: SIP/2.0/UDP 172.16.8.73;rport;branch=z9hG4bKB08HeU80y4jQS.
Max-Forwards: 70.
From: <sip:248@172.16.8.73>;tag=m9mm116X9Km9c.
To: "IT" <sip:212@172.16.8.73>;tag=00070e36b3b00018d240b8dc-e1632e21.
Call-ID: 00070e36-b3b0000f-0f715d4a-e291ab93@172.16.8.188.
CSeq: 116211143 BYE.
Contact: <sip:248@172.16.8.73:5060;transport=udp>.
User-Agent: FreeSWITCH.
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE.
Supported: timer, path, replaces.
Content-Length: 0.
.

^Cexit
34 received, 0 dropped
root@fusionpbx:/home/user1#

Adrian Fretwell · Dec 13, 2017

Just looking at this very briefly this morning, I can see that the contact header in the initial invite shows a different port to the actual port that signalling came from. These issues are often auto corrected by the aggressive NAT detection in the software, but your case it is clearly not being corrected because we see the 100 trying message being send to 172.16.8.188:5060 as specified in the contact header and not 172.16.8.188:49159 which is where the invite actually came from.

Further down in the trace we see:
U 172.16.8.181:49153 -> 172.16.8.73:5060
SIP/2.0 200 OK.

U 172.16.8.73:5060 -> 172.16.8.181:5060
ACK sip:248@172.16.8.181:5060;transport=udp SIP/2.0.

Here the ACK following the 200 OK is being sent to the wrong port. Generally if an ACK is not received following a 200 OK the call will be terminated when the relevant timers expire.

Hope this helps. A.

Daniel B · Dec 13, 2017

Hello Adrian,

I have looked in the config file of the phones and the SIP port is defined as 5060 and the media ports are between 16000 and 32000.
I also have 5060 in the internal profile in Fusionpbx.
You mean to tell me that the conversation should happen only on the 5060 port, on both sides?
I see nowhere I could configure things differently.
Also, which would be the relevant timer that causes the disconnection?

Thank you!

Adrian Fretwell · Dec 13, 2017

Daniel,
SIP signalling can be on whatever ports you configure it to be, it does not have to be solely on 5060. Simplistically and ignoring VIA headers, a SIP device will send reply messages to the address specified in the contact header, that is what the header is there for, but if the contact header is deemed useless, for example it contains the address of a non reachable network, then reply messages will be sent to the same IP address and port that the request message came from.

Irrespective of what you see set up in the device config, the facts, established from the SIP trace show that this device is sending from port 49153 but advertising that it wants to be contacted on 5060. I know you said this is just operating on a local LAN but this is typically what we see when the device is behind a NAT. The device will send from port 5060 on its internal IP address or whatever port is configured for SIP and then the NAT (router) will translate this port to 49153 on the external IP address.

I think the problem is with your device not Fusion. Some devices (phones) are more problematic that others, you may find everything works fine with Yealink phones.
A.

DigitalDaz · Dec 13, 2017

Adrian Fretwell said:
Just looking at this very briefly this morning, I can see that the contact header in the initial invite shows a different port to the actual port that signalling came from. These issues are often auto corrected by the aggressive NAT detection in the software, but your case it is clearly not being corrected because we see the 100 trying message being send to 172.16.8.188:5060 as specified in the contact header and not 172.16.8.188:49159 which is where the invite actually came from.

Further down in the trace we see:
U 172.16.8.181:49153 -> 172.16.8.73:5060
SIP/2.0 200 OK.

U 172.16.8.73:5060 -> 172.16.8.181:5060
ACK sip:248@172.16.8.181:5060;transport=udp SIP/2.0.

Here the ACK following the 200 OK is being sent to the wrong port. Generally if an ACK is not received following a 200 OK the call will be terminated when the relevant timers expire.

Hope this helps. A.

The ACK IS being sent to the right port.

The ACK should be sent to the URI specified in the Contact header of the 200OK which in this case is: 248@172.16.8.181:5060.

I think the problem here is that these Cisco where never designed to be used with anything other than callmanager. They also behave differently depending on the firmware and also unlike other firmwares some get worse with newer firmwares.

I have a nice colour touch screen 7965G that will never be anymore than a good paperweight.

The problem I see here is because of the use of session timers, Freeswitch then goes to reinvite:

U 172.16.8.73:5060 -> 172.16.8.188:49159
INVITE sip:212@172.16.8.188:5060;transport=udp SIP/2.0.
Via: SIP/2.0/UDP 172.16.8.73;rport;branch=z9hG4bKaQFSc0QX1Uv4D.
Max-Forwards: 70.
From: <sip:248@172.16.8.73>;tag=m9mm116X9Km9c.
To: "IT" <sip:212@172.16.8.73>;tag=00070e36b3b00018d240b8dc-e1632e21.
Call-ID: 00070e36-b3b0000f-0f715d4a-e291ab93@172.16.8.188.
CSeq: 116211142 INVITE.
Contact: <sip:248@172.16.8.73:5060;transport=udp>.
User-Agent: FreeSWITCH.
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE.
Supported: timer, path, replaces.
Session-Expires: 120;refresher=uac.
Min-SE: 120.
Content-Type: application/sdp.
Content-Disposition: session.
Content-Length: 218.

In any normal NATted phone this would work but the reINVITE should be going to 172.16.8.188:5060

We also see that freeswitch is sticking rport in the Via so it thinks there is NAT at play somewhere.

I would say that the first thing to do is disable session timers in the Cisco phones themselves, they are definitely not needed. I do not think though that this will do anything other than raise another issue later.

As well as disabling session timers, go into the GUI of FusionPBX and in advanced/sip profiles, inside the internal sip profile find a setting NDLB-force-rport.

Make this setting set to false, it is probably set to safe.

You will then probably have to flush memcache either in SIP status in the GUI or on the fs_cli command line with: memcache flush

Before you do this, could you, in the fs_cli, do a:

Code:

sofia status profile internal reg

And paste the output back here, change the settings anyway, I'm just very curious as to what FS is seeing

Adrian Fretwell · Dec 13, 2017

Daz, thanks for explaining that better than I did. Technically the ACK is being sent to the correct port, it's just that the information in the contact header appears to be wrong.

Phones that are NAT aware will put the external IP address and port into the contact header.

As a SIP trunk provider we perform various tests on the contact header like checking for the presence of RFC1918 / RFC6598 addresses, and checking the address/port in the contact header against source IP address/port where the signalling came from. If necessary we correct the contact header in the proxy so the ACK etc. do actually get sent to the right place. I hope that makes sense.

As for timers, I'm not exactly sure but I seem to remember reading an RFC, possibly 3261 that said that if a SIP device does not receive an ACK to its final 2xx reply then it has to disconnect the call by issuing a BYE message.

You can learn a lot about SIP by studying traces. Are you able to do a SIP trace using a NAT aware phone, like a Yealink (no I don't have shares in Yealink), so you can see the difference between the two - just an idea...

DigitalDaz · Dec 13, 2017

Sorry, I completely disagree, there is nothing wrong with the contact header, these ciscos are notorious for this behaviour.

The ack is absolutely getting back, its nothing to do with the ACK, its the reinvite being sent by Freeswitch that is wrong, moreover, I little deeper look and it seems the session timers have been enabled on the Freeswitch box, not the Ciscos.

U 172.16.8.73:5060 -> 172.16.8.188:49159
INVITE sip:212@172.16.8.188:5060;transport=udp SIP/2.0.
Via: SIP/2.0/UDP 172.16.8.73;rport;branch=z9hG4bKaQFSc0QX1Uv4D.
Max-Forwards: 70.
From: <sip:248@172.16.8.73>;tag=m9mm116X9Km9c.
To: "IT" <sip:212@172.16.8.73>;tag=00070e36b3b00018d240b8dc-e1632e21.
Call-ID: 00070e36-b3b0000f-0f715d4a-e291ab93@172.16.8.188.
CSeq: 116211142 INVITE.
Contact: <sip:248@172.16.8.73:5060;transport=udp>.
User-Agent: FreeSWITCH.
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE.
Supported: timer, path, replaces.
Session-Expires: 120;refresher=uac.
Min-SE: 120.
Content-Type: application/sdp.
Content-Disposition: session.
Content-Length: 218.

The reinvite is being sent to port 49159 rather than 5060, as a result of this the reinvite gets retransmitted and eventually freeswitch hangs it up on timer expired.

Daniel B · Dec 14, 2017

Hello,

Thank you for trying to help. I'm now at the computer again and I can do what you requested.
Daz,

Here is the output of the reg command:

Registrations:
=================================================================================================
Call-ID: 00070e36-baf50002-88887b38-4ff26840@172.16.8.187
User: 205@172.16.8.73
Contact: "" <sip:248@172.16.8.187:5060;transport=udp>
Agent: Cisco-CP7911G/8.5.3
Status: Registered(UDP)(unknown) EXP(2017-12-14 13:27:51) EXPSECS(1968)
Ping-Status: Reachable
Ping-Time: 0.00
Host: fusionpbx
IP: 172.16.8.187
Port: 49153
Auth-User: 205
Auth-Realm: 172.16.8.73
MWI-Account: 205@172.16.8.73

Call-ID: 001bd4a0-0f320002-41bc9326-9a49b031@172.16.8.172
User: 211@172.16.8.73
Contact: "" <sip:211@172.16.8.172:5060;transport=udp>
Agent: Cisco-CP7911G/8.5.3
Status: Registered(UDP)(unknown) EXP(2017-12-14 13:27:54) EXPSECS(1971)
Ping-Status: Reachable
Ping-Time: 0.00
Host: fusionpbx
IP: 172.16.8.172
Port: 49153
Auth-User: 211
Auth-Realm: 172.16.8.73
MWI-Account: 211@172.16.8.73

Call-ID: 001bd4a0-5f840002-62499bce-832878ed@172.16.8.200
User: 238@172.16.8.73
Contact: "" <sip:217@172.16.8.200:5060;transport=udp>
Agent: Cisco-CP7911G/8.5.3
Status: Registered(UDP)(unknown) EXP(2017-12-14 13:27:48) EXPSECS(1965)
Ping-Status: Reachable
Ping-Time: 0.00
Host: fusionpbx
IP: 172.16.8.200
Port: 49153
Auth-User: 238
Auth-Realm: 172.16.8.73
MWI-Account: 238@172.16.8.73

Call-ID: 00070e57-29bb0002-7928ff3e-8de79395@172.16.8.202
User: 228@172.16.8.73
Contact: "" <sip:228@172.16.8.202:5060;transport=udp>
Agent: Cisco-CP7911G/8.5.3
Status: Registered(UDP)(unknown) EXP(2017-12-14 13:27:48) EXPSECS(1965)
Ping-Status: Reachable
Ping-Time: 0.00
Host: fusionpbx
IP: 172.16.8.202
Port: 49153
Auth-User: 228
Auth-Realm: 172.16.8.73
MWI-Account: 228@172.16.8.73

Call-ID: 002290bc-08450002-dc5816f0-f01fedca@172.16.8.194
User: 204@172.16.8.73
Contact: "" <sip:204@172.16.8.194:5060;transport=udp>
Agent: Cisco-CP7911G/8.5.3
Status: Registered(UDP)(unknown) EXP(2017-12-14 13:27:56) EXPSECS(1973)
Ping-Status: Reachable
Ping-Time: 0.00
Host: fusionpbx
IP: 172.16.8.194
Port: 49153
Auth-User: 204
Auth-Realm: 172.16.8.73
MWI-Account: 204@172.16.8.73

Call-ID: 00070e57-2e630002-97924da8-33e4c394@172.16.8.189
User: 226@172.16.8.73
Contact: "" <sip:226@172.16.8.189:5060;transport=udp>
Agent: Cisco-CP7911G/8.5.3
Status: Registered(UDP)(unknown) EXP(2017-12-14 13:27:49) EXPSECS(1966)
Ping-Status: Reachable
Ping-Time: 0.00
Host: fusionpbx
IP: 172.16.8.189
Port: 49153
Auth-User: 226
Auth-Realm: 172.16.8.73
MWI-Account: 226@172.16.8.73

Call-ID: 00070e36-bccf0002-6e421ec0-0777fb06@172.16.8.196
User: 217@172.16.8.73
Contact: "" <sip:217@172.16.8.196:5060;transport=udp>
Agent: Cisco-CP7911G/8.5.3
Status: Registered(UDP)(unknown) EXP(2017-12-14 13:27:56) EXPSECS(1973)
Ping-Status: Reachable
Ping-Time: 0.00
Host: fusionpbx
IP: 172.16.8.196
Port: 49153
Auth-User: 217
Auth-Realm: 172.16.8.73
MWI-Account: 217@172.16.8.73

Call-ID: 00070e36-10560002-1e16cb86-8d8e7a29@172.16.8.190
User: 229@172.16.8.73
Contact: "" <sip:229@172.16.8.190:5060;transport=udp>
Agent: Cisco-CP7911G/8.5.3
Status: Registered(UDP)(unknown) EXP(2017-12-14 13:27:56) EXPSECS(1973)
Ping-Status: Reachable
Ping-Time: 0.00
Host: fusionpbx
IP: 172.16.8.190
Port: 49153
Auth-User: 229
Auth-Realm: 172.16.8.73
MWI-Account: 229@172.16.8.73

Call-ID: 00070e36-b3b00003-485af738-981409a6@172.16.8.188
User: 212@172.16.8.73
Contact: "" <sip:212@172.16.8.188:5060;transport=udp>
Agent: Cisco-CP7911G/8.5.3
Status: Registered(UDP)(unknown) EXP(2017-12-14 13:26:12) EXPSECS(1869)
Ping-Status: Reachable
Ping-Time: 0.00
Host: fusionpbx
IP: 172.16.8.188
Port: 49159
Auth-User: 212
Auth-Realm: 172.16.8.73
MWI-Account: 212@172.16.8.73

Call-ID: 001e4a0b-ae870002-be910360-d8e4d86e@172.16.8.105
User: 222@172.16.8.73
Contact: "" <sip:222@172.16.8.105:5060;transport=udp>
Agent: Cisco-CP7911G/8.5.3
Status: Registered(UDP)(unknown) EXP(2017-12-14 13:27:55) EXPSECS(1972)
Ping-Status: Reachable
Ping-Time: 0.00
Host: fusionpbx
IP: 172.16.8.105
Port: 49153
Auth-User: 222
Auth-Realm: 172.16.8.73
MWI-Account: 222@172.16.8.73

Call-ID: 00070e57-33f50002-3195b4a8-fc479d14@172.16.8.157
User: 207@172.16.8.73
Contact: "" <sip:207@172.16.8.157:5060;transport=udp>
Agent: Cisco-CP7911G/8.5.3
Status: Registered(UDP)(unknown) EXP(2017-12-14 13:27:54) EXPSECS(1971)
Ping-Status: Reachable
Ping-Time: 0.00
Host: fusionpbx
IP: 172.16.8.157
Port: 49153
Auth-User: 207
Auth-Realm: 172.16.8.73
MWI-Account: 207@172.16.8.73

Call-ID: 001bd4a0-5fa10002-65d5c538-10ded55c@172.16.8.179
User: 208@172.16.8.73
Contact: "" <sip:208@172.16.8.179:5060;transport=udp>
Agent: Cisco-CP7911G/8.5.3
Status: Registered(UDP)(unknown) EXP(2017-12-14 13:27:56) EXPSECS(1973)
Ping-Status: Reachable
Ping-Time: 0.00
Host: fusionpbx
IP: 172.16.8.179
Port: 49153
Auth-User: 208
Auth-Realm: 172.16.8.73
MWI-Account: 208@172.16.8.73

Call-ID: 001bd4a0-5f540002-52919d4e-85070fad@172.16.8.178
User: 218@172.16.8.73
Contact: "" <sip:218@172.16.8.178:5060;transport=udp>
Agent: Cisco-CP7911G/8.5.3
Status: Registered(UDP)(unknown) EXP(2017-12-14 13:27:56) EXPSECS(1973)
Ping-Status: Reachable
Ping-Time: 0.00
Host: fusionpbx
IP: 172.16.8.178
Port: 49153
Auth-User: 218
Auth-Realm: 172.16.8.73
MWI-Account: 218@172.16.8.73

Call-ID: 001bd4a0-2f030002-53991006-9529ce89@172.16.8.181
User: 248@172.16.8.73
Contact: "" <sip:248@172.16.8.181:5060;transport=udp>
Agent: Cisco-CP7911G/8.5.3
Status: Registered(UDP)(unknown) EXP(2017-12-14 13:27:58) EXPSECS(1975)
Ping-Status: Reachable
Ping-Time: 0.00
Host: fusionpbx
IP: 172.16.8.181
Port: 49153
Auth-User: 248
Auth-Realm: 172.16.8.73
MWI-Account: 248@172.16.8.73

Call-ID: 00070e36-bc330002-da32695e-06df1665@172.16.8.195
User: 209@172.16.8.73
Contact: "" <sip:209@172.16.8.195:5060;transport=udp>
Agent: Cisco-CP7911G/8.5.3
Status: Registered(UDP)(unknown) EXP(2017-12-14 13:27:56) EXPSECS(1973)
Ping-Status: Reachable
Ping-Time: 0.00
Host: fusionpbx
IP: 172.16.8.195
Port: 49153
Auth-User: 209
Auth-Realm: 172.16.8.73
MWI-Account: 209@172.16.8.73

Call-ID: 00070e36-bd520002-97059e26-c10fff71@172.16.8.192
User: 227@172.16.8.73
Contact: "" <sip:227@172.16.8.192:5060;transport=udp>
Agent: Cisco-CP7911G/8.5.3
Status: Registered(UDP)(unknown) EXP(2017-12-14 13:27:55) EXPSECS(1972)
Ping-Status: Reachable
Ping-Time: 0.00
Host: fusionpbx
IP: 172.16.8.192
Port: 49153
Auth-User: 227
Auth-Realm: 172.16.8.73
MWI-Account: 227@172.16.8.73

Call-ID: 001f6c80-e40a0002-a6fdc638-08e70f80@172.16.8.124
User: 234@172.16.8.73
Contact: "" <sip:234@172.16.8.124:5060;transport=udp>
Agent: Cisco-CP7911G/8.5.3
Status: Registered(UDP)(unknown) EXP(2017-12-14 13:04:24) EXPSECS(561)
Ping-Status: Reachable
Ping-Time: 0.00
Host: fusionpbx
IP: 172.16.8.124
Port: 49166
Auth-User: 234
Auth-Realm: 172.16.8.73
MWI-Account: 234@172.16.8.73

Total items returned: 17
=================================================================================================

You are right about the NDLB-force-rport setting, it is set to safe. I will set it to false and get back to you.
Do you want me to post the cisco phone config here? Will it help with anything?
I tried increasing 2 timers on the cisco before I posted this thread, but no luck.
I will test now with the NDLB setting to false and get back to you.

EDIT: I forgot to mention that the phones are all on the same network, so no NAT

Thank you again for your help!

KR!

Adrian Fretwell · Dec 14, 2017

Sorry Chaps, I don't want to get in the way of your further diagnostics, but just for my sanity, are we saying that these Cisco devices listen on 5060 but send SIP messages out on a variety of different ports?

DigitalDaz · Dec 14, 2017

In your sip profiles, have you changed session-timeout ??

DigitalDaz · Dec 14, 2017

Adrian Fretwell said:
Sorry Chaps, I don't want to get in the way of your further diagnostics, but just for my sanity, are we saying that these Cisco devices listen on 5060 but send SIP messages out on a variety of different ports?

Yes indeed

Also it depends on the firmware, newer ones can be worse.

They will send from a random port and absolutely refuse to accept traffic on the port they sent from, instead only talking on the port set in the contact header. This trashes everything we would normally handle with a simple rport type scenario on a WAN.

DigitalDaz · Dec 14, 2017

@Adrian Fretwell:

Most consumer VOIP services, including providers that support Cisco 79x0 model phones, will not work with 79x1 phones without intervention on the provider side. Because the 79x1 phones send SIP messages from arbitrary high number UDP ports (e.g. 49000+) the symmetric NAT approach used by Asterisk (nat=yes) and most VOIP providers does not work with these phones. The 79x1 will transmit ICMP unreachable messages back to SIP proxies that attempt to respond to SIP registration using symmetric NAT (you will see inbound SIP messages from the proxy with a high number UDP port destination, assuming your router works with symmetric NAT).

The 79x1 behavior is RFC compliant, just incompatibly non-standard. Cisco support reports that this the use of random high number ports to send SIP messages is a "security enhancement" compared with Cisco's other/older products.

Daniel B · Dec 14, 2017

So, I changed the NDLB setting but still no go. Is it ok is I just disable the session timer on Fusionpbx?

DigitalDaz · Dec 14, 2017

Yes, there shouldn't be any session timers by default on the PBX

Daniel B · Dec 14, 2017

Hey Daz,

The session_timeout variable in the internal profile is false already. Are there any other timers I should look at?

FusionPBX call drop problem

New Member

Administrator

New Member

Administrator

New Member

New Member

Well-Known Member

New Member

Well-Known Member

Administrator

Well-Known Member

Administrator

New Member

Well-Known Member

Administrator

Administrator

Administrator

New Member

Administrator

New Member