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