3e3581fd-2908-4b9d-aa67-d4851f08d2f3 EXECUTE [depth=0] sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061 export(hostname=sip7) 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:52:26.992620 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [hostname]=[sip7] 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 EXECUTE [depth=0] sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061 set(rtp_payload_number=101) 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:52:26.992620 [DEBUG] mod_dptools.c:1672 SET sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061 [rtp_payload_number]=[101] 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 EXECUTE [depth=0] sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061 set(zrtp_secure_media=false) 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:52:26.992620 [DEBUG] mod_dptools.c:1672 SET sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061 [zrtp_secure_media]=[false] 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 EXECUTE [depth=0] sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061 answer() 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:52:26.992620 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1] 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:52:26.992620 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1] 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:52:26.992620 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:52:26.992620 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:52:26.992620 [DEBUG] switch_core_media.c:5649 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:52:26.992620 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [G729:96:8000:20:0:1]/[PCMU:0:8000:20:64000:1] 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:52:26.992620 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [G729:96:8000:20:0:1]/[PCMA:8:8000:20:64000:1] 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:52:26.992620 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [G729:97:8000:20:0:1]/[PCMU:0:8000:20:64000:1] 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:52:26.992620 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [G729:97:8000:20:0:1]/[PCMA:8:8000:20:64000:1] 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:52:26.992620 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:52:26.992620 [DEBUG] switch_core_media.c:5649 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:52:26.992620 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:52:26.992620 [DEBUG] switch_core_media.c:5510 Set telephone-event payload to 101@8000 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:52:26.992620 [DEBUG] switch_core_media.c:3839 Set Codec sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061 PCMA/8000 20 ms 160 samples 64000 bits 1 channels 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:52:26.992620 [DEBUG] switch_core_codec.c:111 sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061 Original read codec set to PCMA:8 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:52:26.992620 [DEBUG] switch_core_media.c:5853 Set telephone-event payload to 101@8000 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:52:26.992620 [DEBUG] switch_core_media.c:5911 sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061 Set 2833 dtmf send payload to 101 recv payload to 101 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:52:26.992620 [DEBUG] switch_core_media.c:8663 AUDIO RTP [sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061] 172.104.229.98 port 31840 -> 185.23.172.32 port 36114 codec: 8 ms: 20 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:52:26.992620 [DEBUG] switch_rtp.c:4472 Not using a timer 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:52:26.992620 [DEBUG] switch_core_media.c:8977 sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061 Set 2833 dtmf send payload to 101 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:52:26.992620 [DEBUG] switch_core_media.c:8984 sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061 Set 2833 dtmf receive payload to 101 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:52:26.992620 [DEBUG] switch_core_media.c:9007 sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061 Set rtp dtmf delay to 40 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:52:26.992620 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061! 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:52:26.992620 [DEBUG] switch_channel.c:3565 (sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061) Callstate Change RINGING -> EARLY 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:52:26.992620 [DEBUG] switch_core_media.c:8645 Audio params are unchanged for sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061. 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:52:26.992620 [DEBUG] mod_sofia.c:898 Local SDP sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061: 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 v=0 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 o=FreeSWITCH 1629244906 1629244907 IN IP4 172.104.229.98 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 s=FreeSWITCH 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 c=IN IP4 172.104.229.98 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 t=0 0 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 m=audio 31840 RTP/AVP 8 101 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 a=rtpmap:8 PCMA/8000 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 a=rtpmap:101 telephone-event/8000 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 a=fmtp:101 0-16 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 a=ptime:20 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 a=sendrecv 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:52:26.992620 [DEBUG] sofia.c:7326 Channel sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061 entering state [completed][200] 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:52:26.992620 [NOTICE] mod_dptools.c:1406 Channel [sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061] has been answered 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:52:26.992620 [DEBUG] switch_channel.c:3865 (sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061) Callstate Change EARLY -> ACTIVE 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 EXECUTE [depth=0] sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061 bind_digit_action(default,*,exec:transfer,ivr_7636_class) 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 EXECUTE [depth=0] sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061 ivr(7636_class) 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:52:26.992620 [DEBUG] switch_ivr_menu.c:486 Executing IVR menu 7636_class 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:52:26.992620 [DEBUG] switch_ivr_play_say.c:1488 Codec Activated L16@8000hz 1 channels 20ms 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:52:27.052590 [DEBUG] sofia.c:7326 Channel sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061 entering state [ready][200] 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:52:27.392605 [DEBUG] switch_rtp.c:7759 Correct audio ip/port confirmed. 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:52:37.572611 [DEBUG] switch_rtp.c:8004 RTP RECV DTMF 3:2080 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:52:37.572611 [DEBUG] mod_dptools.c:132 sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061 Digit NOT match binding [3] 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:52:37.572611 [INFO] switch_channel.c:522 RECV DTMF 3:2000 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:52:37.572611 [DEBUG] switch_channel.c:618 sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061 Queue dtmf 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 digit=3 ms=250 samples=2000 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:52:37.572611 [DEBUG] switch_ivr_play_say.c:1933 done playing file file_string:///usr/share/freeswitch/sounds/hotlines/7636_2021/00.mp3 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:52:37.572611 [DEBUG] switch_ivr_menu.c:378 waiting for 1/2 digits t/o 2500 **2.5 second timeout but the caller waits through 2.5 minutes of no messages** 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:55:13.052594 [NOTICE] sofia.c:1089 Hangup sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061 [CS_EXECUTE] [NORMAL_CLEARING] 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:55:13.052594 [DEBUG] switch_ivr_menu.c:425 digits 3 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:55:13.052594 [DEBUG] switch_ivr_menu.c:580 IVR action on menu 7636_class matched 3 param 7636_class_3_require_pin 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:55:13.052594 [DEBUG] switch_ivr_menu.c:584 switch_ivr_menu_execute todo=[1] 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:55:13.052594 [DEBUG] switch_ivr_menu.c:486 Executing IVR menu 7636_class_3_require_pin 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:55:13.052594 [DEBUG] switch_ivr_menu.c:676 exit-sound voicemail/vm-goodbye.wav 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:55:13.052594 [DEBUG] switch_core_session.c:2905 sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:55:13.052594 [DEBUG] switch_core_state_machine.c:651 (sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061) State EXECUTE going to sleep 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:55:13.052594 [DEBUG] switch_core_state_machine.c:585 (sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061) Running State Change CS_HANGUP (Cur 21 Tot 677307) 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:55:13.052594 [DEBUG] switch_core_state_machine.c:848 (sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061) Callstate Change ACTIVE -> HANGUP 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:55:13.052594 [DEBUG] switch_core_state_machine.c:850 (sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061) State HANGUP 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:55:13.052594 [DEBUG] mod_sofia.c:453 Channel sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061 hanging up, cause: NORMAL_CLEARING 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:55:13.052594 [DEBUG] switch_core_state_machine.c:60 sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061 Standard HANGUP, cause: NORMAL_CLEARING 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:55:13.052594 [DEBUG] switch_core_state_machine.c:850 (sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061) State HANGUP going to sleep 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:55:13.052594 [DEBUG] switch_core_state_machine.c:620 (sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061) State Change CS_HANGUP -> CS_REPORTING 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:55:13.052594 [DEBUG] switch_core_state_machine.c:585 (sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061) Running State Change CS_REPORTING (Cur 21 Tot 677307) 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:55:13.052594 [DEBUG] switch_core_state_machine.c:936 (sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061) State REPORTING 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:55:13.272594 [DEBUG] switch_core_state_machine.c:174 sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061 Standard REPORTING, cause: NORMAL_CLEARING 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:55:13.272594 [DEBUG] switch_core_state_machine.c:936 (sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061) State REPORTING going to sleep 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:55:13.272594 [DEBUG] switch_core_state_machine.c:611 (sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061) State Change CS_REPORTING -> CS_DESTROY 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:55:13.272594 [DEBUG] switch_core_session.c:1726 Session 677294 (sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061) Locked, Waiting on external entities 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:55:13.272594 [NOTICE] switch_core_session.c:1744 Session 677294 (sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061) Ended 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:55:13.272594 [NOTICE] switch_core_session.c:1748 Close Channel sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061 [CS_DESTROY] 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:55:13.272594 [DEBUG] switch_core_state_machine.c:739 (sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061) Running State Change CS_DESTROY (Cur 20 Tot 677307) 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:55:13.272594 [DEBUG] switch_core_state_machine.c:749 (sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061) State DESTROY 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:55:13.272594 [DEBUG] mod_sofia.c:364 sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061 SOFIA DESTROY 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:55:13.272594 [DEBUG] switch_core_state_machine.c:181 sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061 Standard DESTROY 3e3581fd-2908-4b9d-aa67-d4851f08d2f3 2021-08-18 08:55:13.272594 [DEBUG] switch_core_state_machine.c:749 (sofia/external/$ERROR-CALLER@$REMOTE-MEDIA:5061) State DESTROY going to sleep