2018-11-27 10:20:09.187910 [DEBUG] switch_core_state_machine.c:603 (sofia/default/8527@178.128.241.78) State NEW 2018-11-27 10:20:09.187910 [DEBUG] sofia.c:2334 detaching session 0474050e-f22e-11e8-a3e1-4334abcd501c 2018-11-27 10:20:09.287900 [DEBUG] sofia.c:7084 Channel sofia/default/746434@202.142.114.240:54942 entering state [completing][200] 2018-11-27 10:20:09.287900 [DEBUG] sofia.c:7094 Remote SDP: v=0 o=- 2 2 IN IP4 172.18.5.124 s=CounterPath X-Lite 3.0 c=IN IP4 172.18.5.124 t=0 0 m=audio 17480 RTP/AVP 0 101 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 2018-11-27 10:20:09.287900 [DEBUG] sofia.c:7084 Channel sofia/default/746434@202.142.114.240:54942 entering state [ready][200] 2018-11-27 10:20:09.287900 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2018-11-27 10:20:09.287900 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match 2018-11-27 10:20:09.287900 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000 2018-11-27 10:20:09.287900 [DEBUG] switch_core_media.c:3061 Set Codec sofia/default/746434@202.142.114.240:54942 PCMU/8000 20 ms 160 samples 64000 bits 1 channels 2018-11-27 10:20:09.287900 [DEBUG] switch_core_codec.c:111 sofia/default/746434@202.142.114.240:54942 Original read codec set to PCMU:0 2018-11-27 10:20:09.287900 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000 2018-11-27 10:20:09.287900 [DEBUG] switch_core_media.c:4767 sofia/default/746434@202.142.114.240:54942 Set 2833 dtmf send payload to 101 recv payload to 101 2018-11-27 10:20:09.287900 [DEBUG] switch_core_media.c:6878 AUDIO RTP [sofia/default/746434@202.142.114.240:54942] 178.128.241.78 port 24206 -> 172.18.5.124 port 17480 codec: 0 ms: 20 2018-11-27 10:20:09.287900 [DEBUG] switch_rtp.c:4159 Not using a timer 2018-11-27 10:20:09.287900 [DEBUG] switch_core_media.c:7180 sofia/default/746434@202.142.114.240:54942 Set 2833 dtmf send payload to 101 2018-11-27 10:20:09.287900 [DEBUG] switch_core_media.c:7187 sofia/default/746434@202.142.114.240:54942 Set 2833 dtmf receive payload to 101 2018-11-27 10:20:09.287900 [DEBUG] switch_core_media.c:7210 sofia/default/746434@202.142.114.240:54942 Set rtp dtmf delay to 40 2018-11-27 10:20:09.287900 [NOTICE] sofia.c:8218 Channel [sofia/default/746434@202.142.114.240:54942] has been answered 2018-11-27 10:20:09.287900 [DEBUG] switch_channel.c:3773 (sofia/default/746434@202.142.114.240:54942) Callstate Change RINGING -> ACTIVE 2018-11-27 10:20:09.307880 [DEBUG] switch_core_media.c:6878 AUDIO RTP [sofia/default/16617480240@104.222.96.119:5060] 178.128.241.78 port 28092 -> 104.222.96.119 port 7932 codec: 0 ms: 20 2018-11-27 10:20:09.307880 [DEBUG] switch_rtp.c:4159 Not using a timer 2018-11-27 10:20:09.307880 [DEBUG] switch_core_media.c:7180 sofia/default/16617480240@104.222.96.119:5060 Set 2833 dtmf send payload to 101 2018-11-27 10:20:09.307880 [DEBUG] switch_core_media.c:7187 sofia/default/16617480240@104.222.96.119:5060 Set 2833 dtmf receive payload to 101 2018-11-27 10:20:09.307880 [DEBUG] switch_core_media.c:7210 sofia/default/16617480240@104.222.96.119:5060 Set rtp dtmf delay to 40 2018-11-27 10:20:09.307880 [DEBUG] mod_sofia.c:850 Local SDP sofia/default/16617480240@104.222.96.119:5060: v=0 o=FreeSWITCH 1543285917 1543285918 IN IP4 178.128.241.78 s=FreeSWITCH c=IN IP4 178.128.241.78 t=0 0 m=audio 28092 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv 2018-11-27 10:20:09.307880 [NOTICE] switch_ivr_originate.c:3647 Channel [sofia/default/16617480240@104.222.96.119:5060] has been answered 2018-11-27 10:20:09.307880 [DEBUG] switch_channel.c:3773 (sofia/default/16617480240@104.222.96.119:5060) Callstate Change RINGING -> ACTIVE 2018-11-27 10:20:09.307880 [DEBUG] switch_ivr_originate.c:3705 Originate Resulted in Success: [sofia/default/746434@202.142.114.240:54942] 2018-11-27 10:20:09.307880 [DEBUG] switch_ivr_bridge.c:1614 (sofia/default/746434@202.142.114.240:54942) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA 2018-11-27 10:20:09.307880 [DEBUG] switch_core_state_machine.c:584 (sofia/default/746434@202.142.114.240:54942) Running State Change CS_EXCHANGE_MEDIA (Cur 4 Tot 38) 2018-11-27 10:20:09.307880 [DEBUG] switch_core_state_machine.c:653 (sofia/default/746434@202.142.114.240:54942) State EXCHANGE_MEDIA 2018-11-27 10:20:09.307880 [DEBUG] mod_sofia.c:631 SOFIA EXCHANGE_MEDIA 2018-11-27 10:20:09.307880 [DEBUG] sofia.c:7084 Channel sofia/default/16617480240@104.222.96.119:5060 entering state [completed][200] 2018-11-27 10:20:09.487898 [DEBUG] sofia.c:7084 Channel sofia/default/16617480240@104.222.96.119:5060 entering state [ready][200] 2018-11-27 10:20:09.527880 [INFO] switch_rtp.c:7268 Auto Changing audio port from 172.18.5.124:17480 to 202.142.114.240:19081 2018-11-27 10:20:09.847913 [DEBUG] switch_rtp.c:7308 Correct audio ip/port confirmed. 2018-11-27 10:20:11.787888 [WARNING] switch_core_state_machine.c:687 00028b8a-f22e-11e8-a3a2-4334abcd501c sofia/default/85018@178.128.241.78 Abandoned 2018-11-27 10:20:11.787888 [NOTICE] switch_core_state_machine.c:690 Hangup sofia/default/85018@178.128.241.78 [CS_NEW] [WRONG_CALL_STATE] 2018-11-27 10:20:11.787888 [DEBUG] switch_core_state_machine.c:584 (sofia/default/85018@178.128.241.78) Running State Change CS_HANGUP (Cur 4 Tot 38) 2018-11-27 10:20:11.787888 [DEBUG] switch_core_state_machine.c:850 (sofia/default/85018@178.128.241.78) Callstate Change DOWN -> HANGUP 2018-11-27 10:20:11.787888 [DEBUG] switch_core_state_machine.c:852 (sofia/default/85018@178.128.241.78) State HANGUP 2018-11-27 10:20:11.787888 [DEBUG] mod_sofia.c:438 Channel sofia/default/85018@178.128.241.78 hanging up, cause: WRONG_CALL_STATE 2018-11-27 10:20:11.787888 [DEBUG] switch_core_state_machine.c:60 sofia/default/85018@178.128.241.78 Standard HANGUP, cause: WRONG_CALL_STATE 2018-11-27 10:20:11.787888 [DEBUG] switch_core_state_machine.c:852 (sofia/default/85018@178.128.241.78) State HANGUP going to sleep 2018-11-27 10:20:11.787888 [DEBUG] switch_core_state_machine.c:619 (sofia/default/85018@178.128.241.78) State Change CS_HANGUP -> CS_REPORTING 2018-11-27 10:20:11.787888 [DEBUG] switch_core_state_machine.c:584 (sofia/default/85018@178.128.241.78) Running State Change CS_REPORTING (Cur 4 Tot 38) 2018-11-27 10:20:11.787888 [DEBUG] switch_core_state_machine.c:938 (sofia/default/85018@178.128.241.78) State REPORTING 2018-11-27 10:20:11.787888 [DEBUG] switch_core_state_machine.c:174 sofia/default/85018@178.128.241.78 Standard REPORTING, cause: WRONG_CALL_STATE 2018-11-27 10:20:11.787888 [DEBUG] switch_core_state_machine.c:938 (sofia/default/85018@178.128.241.78) State REPORTING going to sleep 2018-11-27 10:20:11.787888 [DEBUG] switch_core_state_machine.c:610 (sofia/default/85018@178.128.241.78) State Change CS_REPORTING -> CS_DESTROY 2018-11-27 10:20:11.787888 [DEBUG] switch_core_session.c:1665 Session 35 (sofia/default/85018@178.128.241.78) Locked, Waiting on external entities 2018-11-27 10:20:11.787888 [NOTICE] switch_core_session.c:1683 Session 35 (sofia/default/85018@178.128.241.78) Ended 2018-11-27 10:20:11.787888 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/85018@178.128.241.78 [CS_DESTROY] 2018-11-27 10:20:11.787888 [DEBUG] switch_core_state_machine.c:741 (sofia/default/85018@178.128.241.78) Running State Change CS_DESTROY (Cur 3 Tot 38) 2018-11-27 10:20:11.787888 [DEBUG] switch_core_state_machine.c:751 (sofia/default/85018@178.128.241.78) State DESTROY 2018-11-27 10:20:11.787888 [DEBUG] mod_sofia.c:343 sofia/default/85018@178.128.241.78 SOFIA DESTROY 2018-11-27 10:20:11.787888 [DEBUG] switch_core_state_machine.c:181 sofia/default/85018@178.128.241.78 Standard DESTROY 2018-11-27 10:20:11.787888 [DEBUG] switch_core_state_machine.c:751 (sofia/default/85018@178.128.241.78) State DESTROY going to sleep 2018-11-27 10:20:17.307878 [NOTICE] switch_channel.c:1104 New Channel sofia/default/74460@178.128.241.78 [094c6184-f22e-11e8-a3e4-4334abcd501c] 2018-11-27 10:20:17.307878 [DEBUG] switch_core_state_machine.c:584 (sofia/default/74460@178.128.241.78) Running State Change CS_NEW (Cur 4 Tot 39) 2018-11-27 10:20:17.307878 [DEBUG] sofia.c:9873 sofia/default/74460@178.128.241.78 receiving invite from 158.69.126.203:56392 version: 1.6.20 64bit 2018-11-27 10:20:17.307878 [DEBUG] sofia.c:10044 IP 158.69.126.203 Rejected by acl "default". Falling back to Digest auth. 2018-11-27 10:20:17.307878 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'default' for [000441492550028@178.128.241.78] from ip 158.69.126.203 2018-11-27 10:20:17.307878 [DEBUG] switch_core_state_machine.c:603 (sofia/default/74460@178.128.241.78) State NEW 2018-11-27 10:20:17.307878 [DEBUG] sofia.c:2334 detaching session 094c6184-f22e-11e8-a3e4-4334abcd501c 2018-11-27 10:20:19.247926 [WARNING] switch_core_state_machine.c:687 0474050e-f22e-11e8-a3e1-4334abcd501c sofia/default/8527@178.128.241.78 Abandoned 2018-11-27 10:20:19.247926 [NOTICE] switch_core_state_machine.c:690 Hangup sofia/default/8527@178.128.241.78 [CS_NEW] [WRONG_CALL_STATE] 2018-11-27 10:20:19.247926 [DEBUG] switch_core_state_machine.c:584 (sofia/default/8527@178.128.241.78) Running State Change CS_HANGUP (Cur 4 Tot 39) 2018-11-27 10:20:19.247926 [DEBUG] switch_core_state_machine.c:850 (sofia/default/8527@178.128.241.78) Callstate Change DOWN -> HANGUP 2018-11-27 10:20:19.247926 [DEBUG] switch_core_state_machine.c:852 (sofia/default/8527@178.128.241.78) State HANGUP 2018-11-27 10:20:19.247926 [DEBUG] mod_sofia.c:438 Channel sofia/default/8527@178.128.241.78 hanging up, cause: WRONG_CALL_STATE 2018-11-27 10:20:19.247926 [DEBUG] switch_core_state_machine.c:60 sofia/default/8527@178.128.241.78 Standard HANGUP, cause: WRONG_CALL_STATE 2018-11-27 10:20:19.247926 [DEBUG] switch_core_state_machine.c:852 (sofia/default/8527@178.128.241.78) State HANGUP going to sleep 2018-11-27 10:20:19.247926 [DEBUG] switch_core_state_machine.c:619 (sofia/default/8527@178.128.241.78) State Change CS_HANGUP -> CS_REPORTING 2018-11-27 10:20:19.247926 [DEBUG] switch_core_state_machine.c:584 (sofia/default/8527@178.128.241.78) Running State Change CS_REPORTING (Cur 4 Tot 39) 2018-11-27 10:20:19.247926 [DEBUG] switch_core_state_machine.c:938 (sofia/default/8527@178.128.241.78) State REPORTING 2018-11-27 10:20:19.247926 [DEBUG] switch_core_state_machine.c:174 sofia/default/8527@178.128.241.78 Standard REPORTING, cause: WRONG_CALL_STATE 2018-11-27 10:20:19.247926 [DEBUG] switch_core_state_machine.c:938 (sofia/default/8527@178.128.241.78) State REPORTING going to sleep 2018-11-27 10:20:19.247926 [DEBUG] switch_core_state_machine.c:610 (sofia/default/8527@178.128.241.78) State Change CS_REPORTING -> CS_DESTROY 2018-11-27 10:20:19.247926 [DEBUG] switch_core_session.c:1665 Session 38 (sofia/default/8527@178.128.241.78) Locked, Waiting on external entities 2018-11-27 10:20:19.247926 [NOTICE] switch_core_session.c:1683 Session 38 (sofia/default/8527@178.128.241.78) Ended 2018-11-27 10:20:19.247926 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/8527@178.128.241.78 [CS_DESTROY] 2018-11-27 10:20:19.247926 [DEBUG] switch_core_state_machine.c:741 (sofia/default/8527@178.128.241.78) Running State Change CS_DESTROY (Cur 3 Tot 39) 2018-11-27 10:20:19.247926 [DEBUG] switch_core_state_machine.c:751 (sofia/default/8527@178.128.241.78) State DESTROY 2018-11-27 10:20:19.247926 [DEBUG] mod_sofia.c:343 sofia/default/8527@178.128.241.78 SOFIA DESTROY 2018-11-27 10:20:19.247926 [DEBUG] switch_core_state_machine.c:181 sofia/default/8527@178.128.241.78 Standard DESTROY 2018-11-27 10:20:19.247926 [DEBUG] switch_core_state_machine.c:751 (sofia/default/8527@178.128.241.78) State DESTROY going to sleep