5/04-12:23:53,863 Sending command: api status
5/04-12:23:53,869 reply: UP 0 years, 78 days, 0 hours, 11 minutes, 55 seconds, 940 milliseconds, 498 microseconds
5/04-12:23:53,869 FreeSWITCH (Version 1.10.1  64bit) is ready
5/04-12:23:53,870 90 session(s) since startup
5/04-12:23:53,870 0 session(s) - peak 2, last 5min 0 
5/04-12:23:53,870 0 session(s) per Sec out of max 30, peak 1, last 5min 0 
5/04-12:23:53,870 1000 session(s) max
5/04-12:23:53,870 min idle cpu 0.00/99.21
5/04-12:23:53,871 fs uptime: 6739915 seconds
5/04-12:23:53,875 Sending command: api global_setvar call_debug=true
5/04-12:23:53,875 log 7
5/04-12:23:53,875 Sending command: api version short
5/04-12:23:53,876 reply: +OK
5/04-12:23:53,876 LogData started with api global_setvar call_debug=true
5/04-12:23:53,876 log 7
5/04-12:23:53,880 reply: 1.10.1
5/04-12:23:53,881 Sending command: api sofia status
5/04-12:23:53,884 reply:                      Name	   Type	                                      Data	State
5/04-12:23:53,885 =================================================================================================
5/04-12:23:53,885                 david-tld	profile	          sip:mod_sofia@192.168.20.13:5080	RUNNING (0)
5/04-12:23:53,885         david-tld::tld003	gateway	                 sip:22@192.168.40.10:5060	REGED
5/04-12:23:53,885 =================================================================================================
5/04-12:23:53,885 1 profile 0 aliases
5/04-12:23:53,886 REGED detected, setting registrationErrorShown to false
5/04-12:23:53,886 Leaving main function
5/04-12:23:53,886 Sending command: api global_getvar conf_dir
5/04-12:23:53,890 reply: C:/David/tld/code/voip2/Conf
5/04-12:23:53,891 Sending command: api global_getvar force_local_ip_v4
5/04-12:23:53,895 reply: -ERR no reply
5/04-12:23:53,896 Sending command: api global_setvar rx003=true
5/04-12:23:53,901 reply: +OK
5/04-12:23:53,902 Sending command: api global_getvar freetld
5/04-12:23:53,907 reply: 003
5/04-12:23:53,908 starting rxThread
5/04-12:24:46,920 Sending command: api create_uuid
5/04-12:24:46,921 reply: 57fcc4bb-8343-4040-9c41-43200cd0509c
5/04-12:24:46,921 filter: name=Unique-ID, value=57fcc4bb-8343-4040-9c41-43200cd0509cSending command: api originate {origination_uuid='57fcc4bb-8343-4040-9c41-43200cd0509c',ignore_early_media=true,fax_verbose=false,fax_use_ecm=true,fax_disable_v17=false,fax_enable_t38=false,fax_enable_t38_request=false,fax_ident='+49 6104 497422'}sofia/gateway/tld003/006314141923830 &txfax('C:\David\archive\user\100D8000\out\M007E052.001')
5/04-12:24:46,938 2021-05-04 12:24:46.915062 [DEBUG] switch_ivr_originate.c:2212 Parsing global variables
5/04-12:24:46,938 2021-05-04 12:24:46.915062 [NOTICE] switch_channel.c:1118 New Channel sofia/david-tld/006314141923830 [57fcc4bb-8343-4040-9c41-43200cd0509c]
5/04-12:24:46,938 2021-05-04 12:24:46.915062 [DEBUG] mod_sofia.c:5096 (sofia/david-tld/006314141923830) State Change CS_NEW -> CS_INIT
5/04-12:24:46,938 2021-05-04 12:24:46.915062 [DEBUG] switch_core_session.c:641 sofia/david-tld/006314141923830 set UUID=57fcc4bb-8343-4040-9c41-43200cd0509c
5/04-12:24:46,939 2021-05-04 12:24:46.915062 [DEBUG] switch_core_state_machine.c:585 (sofia/david-tld/006314141923830) Running State Change CS_INIT (Cur 1 Tot 91)
5/04-12:24:46,939 2021-05-04 12:24:46.915062 [DEBUG] switch_core_state_machine.c:628 (sofia/david-tld/006314141923830) State INIT
5/04-12:24:46,939 2021-05-04 12:24:46.915062 [DEBUG] mod_sofia.c:93 sofia/david-tld/006314141923830 SOFIA INIT
5/04-12:24:46,939 2021-05-04 12:24:46.915062 [DEBUG] sofia_glue.c:1618 sofia/david-tld/006314141923830 sending invite version: 1.10.1  64bit
5/04-12:24:46,939 Local SDP:
5/04-12:24:46,939 v=0

5/04-12:24:46,939 o=FreeSWITCH 1620098318 1620098319 IN IP4 192.168.20.13

5/04-12:24:46,939 s=FreeSWITCH

5/04-12:24:46,939 c=IN IP4 192.168.20.13

5/04-12:24:46,939 t=0 0

5/04-12:24:46,939 m=audio 25568 RTP/AVP 9 0 8 101 13

5/04-12:24:46,940 a=rtpmap:9 G722/8000

5/04-12:24:46,940 a=rtpmap:0 PCMU/8000

5/04-12:24:46,940 a=rtpmap:8 PCMA/8000

5/04-12:24:46,940 a=rtpmap:101 telephone-event/8000

5/04-12:24:46,940 a=fmtp:101 0-16

5/04-12:24:46,940 a=rtpmap:13 CN/8000

5/04-12:24:46,940 a=ptime:20

5/04-12:24:46,940 a=sendrecv

5/04-12:24:46,940 m=video 27210 RTP/AVP 102

5/04-12:24:46,940 b=AS:1024

5/04-12:24:46,940 a=rtpmap:102 VP8/90000

5/04-12:24:46,940 a=sendrecv

5/04-12:24:46,940 a=rtcp-fb:102 ccm fir

5/04-12:24:46,940 a=rtcp-fb:102 ccm tmmbr

5/04-12:24:46,941 a=rtcp-fb:102 nack

5/04-12:24:46,941 a=rtcp-fb:102 nack pli

5/04-12:24:46,941 2021-05-04 12:24:46.915062 [DEBUG] switch_core_state_machine.c:40 sofia/david-tld/006314141923830 Standard INIT
5/04-12:24:46,941 2021-05-04 12:24:46.915062 [DEBUG] switch_core_state_machine.c:48 (sofia/david-tld/006314141923830) State Change CS_INIT -> CS_ROUTING
5/04-12:24:46,941 2021-05-04 12:24:46.915062 [DEBUG] switch_core_state_machine.c:628 (sofia/david-tld/006314141923830) State INIT going to sleep
5/04-12:24:46,941 2021-05-04 12:24:46.915062 [DEBUG] switch_core_state_machine.c:585 (sofia/david-tld/006314141923830) Running State Change CS_ROUTING (Cur 1 Tot 91)
5/04-12:24:46,941 2021-05-04 12:24:46.915062 [DEBUG] sofia.c:7290 Channel sofia/david-tld/006314141923830 entering state [calling][0]
5/04-12:24:46,941 2021-05-04 12:24:46.915062 [DEBUG] switch_core_state_machine.c:644 (sofia/david-tld/006314141923830) State ROUTING
5/04-12:24:46,942 2021-05-04 12:24:46.915062 [DEBUG] mod_sofia.c:154 sofia/david-tld/006314141923830 SOFIA ROUTING
5/04-12:24:46,942 2021-05-04 12:24:46.915062 [DEBUG] switch_ivr_originate.c:67 (sofia/david-tld/006314141923830) State Change CS_ROUTING -> CS_CONSUME_MEDIA
5/04-12:24:46,942 2021-05-04 12:24:46.915062 [DEBUG] switch_core_state_machine.c:644 (sofia/david-tld/006314141923830) State ROUTING going to sleep
5/04-12:24:46,942 2021-05-04 12:24:46.915062 [DEBUG] switch_core_state_machine.c:585 (sofia/david-tld/006314141923830) Running State Change CS_CONSUME_MEDIA (Cur 1 Tot 91)
5/04-12:24:46,942 2021-05-04 12:24:46.915062 [DEBUG] switch_core_state_machine.c:663 (sofia/david-tld/006314141923830) State CONSUME_MEDIA
5/04-12:24:46,942 2021-05-04 12:24:46.915062 [DEBUG] switch_core_state_machine.c:663 (sofia/david-tld/006314141923830) State CONSUME_MEDIA going to sleep
5/04-12:25:18,927 2021-05-04 12:25:18.915262 [DEBUG] sofia.c:7290 Channel sofia/david-tld/006314141923830 entering state [terminated][408]
5/04-12:25:18,927 2021-05-04 12:25:18.915262 [NOTICE] sofia.c:8523 Hangup sofia/david-tld/006314141923830 [CS_CONSUME_MEDIA] [RECOVERY_ON_TIMER_EXPIRE]
5/04-12:25:18,927 2021-05-04 12:25:18.915262 [DEBUG] switch_core_state_machine.c:585 (sofia/david-tld/006314141923830) Running State Change CS_HANGUP (Cur 1 Tot 91)
5/04-12:25:18,927 2021-05-04 12:25:18.915262 [DEBUG] switch_core_state_machine.c:848 (sofia/david-tld/006314141923830) Callstate Change DOWN -> HANGUP
5/04-12:25:18,927 2021-05-04 12:25:18.915262 [DEBUG] switch_core_state_machine.c:850 (sofia/david-tld/006314141923830) State HANGUP
5/04-12:25:18,928 2021-05-04 12:25:18.915262 [DEBUG] mod_sofia.c:460 Channel sofia/david-tld/006314141923830 hanging up, cause: RECOVERY_ON_TIMER_EXPIRE
5/04-12:25:18,929 2021-05-04 12:25:18.915262 [DEBUG] switch_core_state_machine.c:60 sofia/david-tld/006314141923830 Standard HANGUP, cause: RECOVERY_ON_TIMER_EXPIRE
5/04-12:25:18,929 reply: -ERR RECOVERY_ON_TIMER_EXPIRE
5/04-12:25:18,930 2021-05-04 12:25:18.915262 [DEBUG] switch_core_state_machine.c:850 (sofia/david-tld/006314141923830) State HANGUP going to sleep
5/04-12:25:18,930 2021-05-04 12:25:18.915262 [DEBUG] switch_core_state_machine.c:620 (sofia/david-tld/006314141923830) State Change CS_HANGUP -> CS_REPORTING
5/04-12:25:18,930 2021-05-04 12:25:18.915262 [DEBUG] switch_core_state_machine.c:585 (sofia/david-tld/006314141923830) Running State Change CS_REPORTING (Cur 1 Tot 91)
5/04-12:25:18,930 2021-05-04 12:25:18.915262 [DEBUG] switch_core_state_machine.c:936 (sofia/david-tld/006314141923830) State REPORTING
5/04-12:25:18,930 2021-05-04 12:25:18.915262 [DEBUG] switch_core_state_machine.c:174 sofia/david-tld/006314141923830 Standard REPORTING, cause: RECOVERY_ON_TIMER_EXPIRE
5/04-12:25:18,931 2021-05-04 12:25:18.915262 [DEBUG] switch_core_state_machine.c:936 (sofia/david-tld/006314141923830) State REPORTING going to sleep
5/04-12:25:18,931 2021-05-04 12:25:18.915262 [DEBUG] switch_core_state_machine.c:611 (sofia/david-tld/006314141923830) State Change CS_REPORTING -> CS_DESTROY
5/04-12:25:18,931 2021-05-04 12:25:18.915262 [DEBUG] switch_core_session.c:1726 Session 91 (sofia/david-tld/006314141923830) Locked, Waiting on external entities
5/04-12:25:18,931 2021-05-04 12:25:18.925263 [DEBUG] switch_ivr_originate.c:3949 Originate Resulted in Error Cause: 102 [RECOVERY_ON_TIMER_EXPIRE]
5/04-12:25:18,931 2021-05-04 12:25:18.925263 [NOTICE] switch_core_session.c:1744 Session 91 (sofia/david-tld/006314141923830) Ended
5/04-12:25:18,931 2021-05-04 12:25:18.925263 [NOTICE] switch_core_session.c:1748 Close Channel sofia/david-tld/006314141923830 [CS_DESTROY]
5/04-12:25:18,931 2021-05-04 12:25:18.925263 [DEBUG] switch_core_state_machine.c:739 (sofia/david-tld/006314141923830) Running State Change CS_DESTROY (Cur 0 Tot 91)
5/04-12:25:18,931 2021-05-04 12:25:18.925263 [DEBUG] switch_core_state_machine.c:749 (sofia/david-tld/006314141923830) State DESTROY
5/04-12:25:18,932 2021-05-04 12:25:18.925263 [DEBUG] mod_sofia.c:365 sofia/david-tld/006314141923830 SOFIA DESTROY
5/04-12:25:18,932 2021-05-04 12:25:18.925263 [DEBUG] switch_core_state_machine.c:181 sofia/david-tld/006314141923830 Standard DESTROY
5/04-12:25:18,932 2021-05-04 12:25:18.925263 [DEBUG] switch_core_state_machine.c:749 (sofia/david-tld/006314141923830) State DESTROY going to sleep
5/04-12:29:44,041 Sending command: api create_uuid
5/04-12:29:44,042 reply: 6b3a2411-7d28-40ed-9d9b-a0b2b4866d87
5/04-12:29:44,043 filter: name=Unique-ID, value=6b3a2411-7d28-40ed-9d9b-a0b2b4866d87Sending command: api originate {origination_uuid='6b3a2411-7d28-40ed-9d9b-a0b2b4866d87',ignore_early_media=true,fax_verbose=false,fax_use_ecm=true,fax_disable_v17=false,fax_enable_t38=false,fax_enable_t38_request=false,fax_ident='+49 6104 497422'}sofia/gateway/tld003/0072198650255 &txfax('C:\David\archive\user\100D8000\out\M007E053.001')
5/04-12:29:44,049 2021-05-04 12:29:44.035772 [DEBUG] switch_ivr_originate.c:2212 Parsing global variables
5/04-12:29:44,049 2021-05-04 12:29:44.035772 [NOTICE] switch_channel.c:1118 New Channel sofia/david-tld/0072198650255 [6b3a2411-7d28-40ed-9d9b-a0b2b4866d87]
5/04-12:29:44,049 2021-05-04 12:29:44.035772 [DEBUG] mod_sofia.c:5096 (sofia/david-tld/0072198650255) State Change CS_NEW -> CS_INIT
5/04-12:29:44,049 2021-05-04 12:29:44.035772 [DEBUG] switch_core_session.c:641 sofia/david-tld/0072198650255 set UUID=6b3a2411-7d28-40ed-9d9b-a0b2b4866d87
5/04-12:29:44,050 2021-05-04 12:29:44.035772 [DEBUG] switch_core_state_machine.c:585 (sofia/david-tld/0072198650255) Running State Change CS_INIT (Cur 1 Tot 92)
5/04-12:29:44,050 2021-05-04 12:29:44.035772 [DEBUG] switch_core_state_machine.c:628 (sofia/david-tld/0072198650255) State INIT
5/04-12:29:44,050 2021-05-04 12:29:44.035772 [DEBUG] mod_sofia.c:93 sofia/david-tld/0072198650255 SOFIA INIT
5/04-12:29:44,050 2021-05-04 12:29:44.035772 [DEBUG] sofia_glue.c:1618 sofia/david-tld/0072198650255 sending invite version: 1.10.1  64bit
5/04-12:29:44,051 Local SDP:
5/04-12:29:44,051 v=0

5/04-12:29:44,051 o=FreeSWITCH 1620105762 1620105763 IN IP4 192.168.20.13

5/04-12:29:44,051 s=FreeSWITCH

5/04-12:29:44,051 c=IN IP4 192.168.20.13

5/04-12:29:44,051 t=0 0

5/04-12:29:44,051 m=audio 18422 RTP/AVP 9 0 8 101 13

5/04-12:29:44,051 a=rtpmap:9 G722/8000

5/04-12:29:44,052 a=rtpmap:0 PCMU/8000

5/04-12:29:44,052 a=rtpmap:8 PCMA/8000

5/04-12:29:44,052 a=rtpmap:101 telephone-event/8000

5/04-12:29:44,052 a=fmtp:101 0-16

5/04-12:29:44,052 a=rtpmap:13 CN/8000

5/04-12:29:44,052 a=ptime:20

5/04-12:29:44,052 a=sendrecv

5/04-12:29:44,053 m=video 20074 RTP/AVP 102

5/04-12:29:44,053 b=AS:1024

5/04-12:29:44,053 a=rtpmap:102 VP8/90000

5/04-12:29:44,053 a=sendrecv

5/04-12:29:44,053 a=rtcp-fb:102 ccm fir

5/04-12:29:44,054 a=rtcp-fb:102 ccm tmmbr

5/04-12:29:44,054 a=rtcp-fb:102 nack

5/04-12:29:44,054 a=rtcp-fb:102 nack pli

5/04-12:29:44,054 2021-05-04 12:29:44.045773 [DEBUG] switch_core_state_machine.c:40 sofia/david-tld/0072198650255 Standard INIT
5/04-12:29:44,054 2021-05-04 12:29:44.045773 [DEBUG] switch_core_state_machine.c:48 (sofia/david-tld/0072198650255) State Change CS_INIT -> CS_ROUTING
5/04-12:29:44,054 2021-05-04 12:29:44.045773 [DEBUG] switch_core_state_machine.c:628 (sofia/david-tld/0072198650255) State INIT going to sleep
5/04-12:29:44,055 2021-05-04 12:29:44.045773 [DEBUG] switch_core_state_machine.c:585 (sofia/david-tld/0072198650255) Running State Change CS_ROUTING (Cur 1 Tot 92)
5/04-12:29:44,055 2021-05-04 12:29:44.045773 [DEBUG] sofia.c:7290 Channel sofia/david-tld/0072198650255 entering state [calling][0]
5/04-12:29:44,055 2021-05-04 12:29:44.045773 [DEBUG] switch_core_state_machine.c:644 (sofia/david-tld/0072198650255) State ROUTING
5/04-12:29:44,055 2021-05-04 12:29:44.045773 [DEBUG] mod_sofia.c:154 sofia/david-tld/0072198650255 SOFIA ROUTING
5/04-12:29:44,055 2021-05-04 12:29:44.045773 [DEBUG] switch_ivr_originate.c:67 (sofia/david-tld/0072198650255) State Change CS_ROUTING -> CS_CONSUME_MEDIA
5/04-12:29:44,055 2021-05-04 12:29:44.045773 [DEBUG] switch_core_state_machine.c:644 (sofia/david-tld/0072198650255) State ROUTING going to sleep
5/04-12:29:44,055 2021-05-04 12:29:44.045773 [DEBUG] switch_core_state_machine.c:585 (sofia/david-tld/0072198650255) Running State Change CS_CONSUME_MEDIA (Cur 1 Tot 92)
5/04-12:29:44,056 2021-05-04 12:29:44.045773 [DEBUG] switch_core_state_machine.c:663 (sofia/david-tld/0072198650255) State CONSUME_MEDIA
5/04-12:29:44,056 2021-05-04 12:29:44.045773 [DEBUG] switch_core_state_machine.c:663 (sofia/david-tld/0072198650255) State CONSUME_MEDIA going to sleep
5/04-12:30:16,056 reply: -ERR RECOVERY_ON_TIMER_EXPIRE
5/04-12:30:16,064 2021-05-04 12:30:16.045972 [DEBUG] sofia.c:7290 Channel sofia/david-tld/0072198650255 entering state [terminated][408]
5/04-12:30:16,064 2021-05-04 12:30:16.045972 [NOTICE] sofia.c:8523 Hangup sofia/david-tld/0072198650255 [CS_CONSUME_MEDIA] [RECOVERY_ON_TIMER_EXPIRE]
5/04-12:30:16,064 2021-05-04 12:30:16.045972 [DEBUG] switch_core_state_machine.c:585 (sofia/david-tld/0072198650255) Running State Change CS_HANGUP (Cur 1 Tot 92)
5/04-12:30:16,064 2021-05-04 12:30:16.045972 [DEBUG] switch_core_state_machine.c:848 (sofia/david-tld/0072198650255) Callstate Change DOWN -> HANGUP
5/04-12:30:16,064 2021-05-04 12:30:16.045972 [DEBUG] switch_core_state_machine.c:850 (sofia/david-tld/0072198650255) State HANGUP
5/04-12:30:16,064 2021-05-04 12:30:16.045972 [DEBUG] mod_sofia.c:460 Channel sofia/david-tld/0072198650255 hanging up, cause: RECOVERY_ON_TIMER_EXPIRE
5/04-12:30:16,064 2021-05-04 12:30:16.045972 [DEBUG] switch_core_state_machine.c:60 sofia/david-tld/0072198650255 Standard HANGUP, cause: RECOVERY_ON_TIMER_EXPIRE
5/04-12:30:16,064 2021-05-04 12:30:16.045972 [DEBUG] switch_core_state_machine.c:850 (sofia/david-tld/0072198650255) State HANGUP going to sleep
5/04-12:30:16,065 2021-05-04 12:30:16.045972 [DEBUG] switch_core_state_machine.c:620 (sofia/david-tld/0072198650255) State Change CS_HANGUP -> CS_REPORTING
5/04-12:30:16,065 2021-05-04 12:30:16.045972 [DEBUG] switch_core_state_machine.c:585 (sofia/david-tld/0072198650255) Running State Change CS_REPORTING (Cur 1 Tot 92)
5/04-12:30:16,065 2021-05-04 12:30:16.045972 [DEBUG] switch_core_state_machine.c:936 (sofia/david-tld/0072198650255) State REPORTING
5/04-12:30:16,065 2021-05-04 12:30:16.045972 [DEBUG] switch_core_state_machine.c:174 sofia/david-tld/0072198650255 Standard REPORTING, cause: RECOVERY_ON_TIMER_EXPIRE
5/04-12:30:16,065 2021-05-04 12:30:16.045972 [DEBUG] switch_core_state_machine.c:936 (sofia/david-tld/0072198650255) State REPORTING going to sleep
5/04-12:30:16,065 2021-05-04 12:30:16.045972 [DEBUG] switch_core_state_machine.c:611 (sofia/david-tld/0072198650255) State Change CS_REPORTING -> CS_DESTROY
5/04-12:30:16,065 2021-05-04 12:30:16.045972 [DEBUG] switch_core_session.c:1726 Session 92 (sofia/david-tld/0072198650255) Locked, Waiting on external entities
5/04-12:30:16,065 2021-05-04 12:30:16.055973 [DEBUG] switch_ivr_originate.c:3949 Originate Resulted in Error Cause: 102 [RECOVERY_ON_TIMER_EXPIRE]
5/04-12:30:16,065 2021-05-04 12:30:16.055973 [NOTICE] switch_core_session.c:1744 Session 92 (sofia/david-tld/0072198650255) Ended
5/04-12:30:16,066 2021-05-04 12:30:16.055973 [NOTICE] switch_core_session.c:1748 Close Channel sofia/david-tld/0072198650255 [CS_DESTROY]
5/04-12:30:16,066 2021-05-04 12:30:16.055973 [DEBUG] switch_core_state_machine.c:739 (sofia/david-tld/0072198650255) Running State Change CS_DESTROY (Cur 0 Tot 92)
5/04-12:30:16,066 2021-05-04 12:30:16.055973 [DEBUG] switch_core_state_machine.c:749 (sofia/david-tld/0072198650255) State DESTROY
5/04-12:30:16,066 2021-05-04 12:30:16.055973 [DEBUG] mod_sofia.c:365 sofia/david-tld/0072198650255 SOFIA DESTROY
5/04-12:30:16,066 2021-05-04 12:30:16.055973 [DEBUG] switch_core_state_machine.c:181 sofia/david-tld/0072198650255 Standard DESTROY
5/04-12:30:16,066 2021-05-04 12:30:16.055973 [DEBUG] switch_core_state_machine.c:749 (sofia/david-tld/0072198650255) State DESTROY going to sleep
5/04-12:31:17,067 Sending command: api create_uuid
5/04-12:31:17,068 reply: ce7c8fa3-9b36-4abb-9a27-48a1a3ccaa82
5/04-12:31:17,068 filter: name=Unique-ID, value=ce7c8fa3-9b36-4abb-9a27-48a1a3ccaa82Sending command: api originate {origination_uuid='ce7c8fa3-9b36-4abb-9a27-48a1a3ccaa82',ignore_early_media=true,fax_verbose=false,fax_use_ecm=true,fax_disable_v17=false,fax_enable_t38=false,fax_enable_t38_request=false,fax_ident='+49 6104 497422'}sofia/gateway/tld003/006314141923830 &txfax('C:\David\archive\user\100D8000\out\M007E052.001')
5/04-12:31:17,081 2021-05-04 12:31:17.065074 [DEBUG] switch_ivr_originate.c:2212 Parsing global variables
5/04-12:31:17,081 2021-05-04 12:31:17.065074 [NOTICE] switch_channel.c:1118 New Channel sofia/david-tld/006314141923830 [ce7c8fa3-9b36-4abb-9a27-48a1a3ccaa82]
5/04-12:31:17,081 2021-05-04 12:31:17.065074 [DEBUG] mod_sofia.c:5096 (sofia/david-tld/006314141923830) State Change CS_NEW -> CS_INIT
5/04-12:31:17,081 2021-05-04 12:31:17.065074 [DEBUG] switch_core_session.c:641 sofia/david-tld/006314141923830 set UUID=ce7c8fa3-9b36-4abb-9a27-48a1a3ccaa82
5/04-12:31:17,081 2021-05-04 12:31:17.065074 [DEBUG] switch_core_state_machine.c:585 (sofia/david-tld/006314141923830) Running State Change CS_INIT (Cur 1 Tot 93)
5/04-12:31:17,082 2021-05-04 12:31:17.065074 [DEBUG] switch_core_state_machine.c:628 (sofia/david-tld/006314141923830) State INIT
5/04-12:31:17,082 2021-05-04 12:31:17.065074 [DEBUG] mod_sofia.c:93 sofia/david-tld/006314141923830 SOFIA INIT
5/04-12:31:17,082 2021-05-04 12:31:17.065074 [DEBUG] sofia_glue.c:1618 sofia/david-tld/006314141923830 sending invite version: 1.10.1  64bit
5/04-12:31:17,082 Local SDP:
5/04-12:31:17,082 v=0

5/04-12:31:17,082 o=FreeSWITCH 1620104457 1620104458 IN IP4 192.168.20.13

5/04-12:31:17,082 s=FreeSWITCH

5/04-12:31:17,082 c=IN IP4 192.168.20.13

5/04-12:31:17,082 t=0 0

5/04-12:31:17,083 m=audio 19820 RTP/AVP 9 0 8 101 13

5/04-12:31:17,083 a=rtpmap:9 G722/8000

5/04-12:31:17,083 a=rtpmap:0 PCMU/8000

5/04-12:31:17,083 a=rtpmap:8 PCMA/8000

5/04-12:31:17,083 a=rtpmap:101 telephone-event/8000

5/04-12:31:17,083 a=fmtp:101 0-16

5/04-12:31:17,083 a=rtpmap:13 CN/8000

5/04-12:31:17,083 a=ptime:20

5/04-12:31:17,083 a=sendrecv

5/04-12:31:17,083 m=video 21472 RTP/AVP 102

5/04-12:31:17,083 b=AS:1024

5/04-12:31:17,084 a=rtpmap:102 VP8/90000

5/04-12:31:17,084 a=sendrecv

5/04-12:31:17,084 a=rtcp-fb:102 ccm fir

5/04-12:31:17,084 a=rtcp-fb:102 ccm tmmbr

5/04-12:31:17,084 a=rtcp-fb:102 nack

5/04-12:31:17,084 a=rtcp-fb:102 nack pli

5/04-12:31:17,084 2021-05-04 12:31:17.065074 [DEBUG] switch_core_state_machine.c:40 sofia/david-tld/006314141923830 Standard INIT
5/04-12:31:17,084 2021-05-04 12:31:17.065074 [DEBUG] switch_core_state_machine.c:48 (sofia/david-tld/006314141923830) State Change CS_INIT -> CS_ROUTING
5/04-12:31:17,084 2021-05-04 12:31:17.065074 [DEBUG] switch_core_state_machine.c:628 (sofia/david-tld/006314141923830) State INIT going to sleep
5/04-12:31:17,084 2021-05-04 12:31:17.065074 [DEBUG] switch_core_state_machine.c:585 (sofia/david-tld/006314141923830) Running State Change CS_ROUTING (Cur 1 Tot 93)
5/04-12:31:17,085 2021-05-04 12:31:17.065074 [DEBUG] sofia.c:7290 Channel sofia/david-tld/006314141923830 entering state [calling][0]
5/04-12:31:17,085 2021-05-04 12:31:17.065074 [DEBUG] switch_core_state_machine.c:644 (sofia/david-tld/006314141923830) State ROUTING
5/04-12:31:17,085 2021-05-04 12:31:17.065074 [DEBUG] mod_sofia.c:154 sofia/david-tld/006314141923830 SOFIA ROUTING
5/04-12:31:17,085 2021-05-04 12:31:17.065074 [DEBUG] switch_ivr_originate.c:67 (sofia/david-tld/006314141923830) State Change CS_ROUTING -> CS_CONSUME_MEDIA
5/04-12:31:17,085 2021-05-04 12:31:17.065074 [DEBUG] switch_core_state_machine.c:644 (sofia/david-tld/006314141923830) State ROUTING going to sleep
5/04-12:31:17,085 2021-05-04 12:31:17.065074 [DEBUG] switch_core_state_machine.c:585 (sofia/david-tld/006314141923830) Running State Change CS_CONSUME_MEDIA (Cur 1 Tot 93)
5/04-12:31:17,085 2021-05-04 12:31:17.065074 [DEBUG] switch_core_state_machine.c:663 (sofia/david-tld/006314141923830) State CONSUME_MEDIA
5/04-12:31:17,085 2021-05-04 12:31:17.065074 [DEBUG] switch_core_state_machine.c:663 (sofia/david-tld/006314141923830) State CONSUME_MEDIA going to sleep
5/04-12:31:49,085 reply: -ERR RECOVERY_ON_TIMER_EXPIRE
5/04-12:31:49,086 2021-05-04 12:31:49.065273 [DEBUG] sofia.c:7290 Channel sofia/david-tld/006314141923830 entering state [terminated][408]
5/04-12:31:49,086 2021-05-04 12:31:49.065273 [NOTICE] sofia.c:8523 Hangup sofia/david-tld/006314141923830 [CS_CONSUME_MEDIA] [RECOVERY_ON_TIMER_EXPIRE]
5/04-12:31:49,086 2021-05-04 12:31:49.065273 [DEBUG] switch_core_state_machine.c:585 (sofia/david-tld/006314141923830) Running State Change CS_HANGUP (Cur 1 Tot 93)
5/04-12:31:49,086 2021-05-04 12:31:49.065273 [DEBUG] switch_core_state_machine.c:848 (sofia/david-tld/006314141923830) Callstate Change DOWN -> HANGUP
5/04-12:31:49,087 2021-05-04 12:31:49.065273 [DEBUG] switch_core_state_machine.c:850 (sofia/david-tld/006314141923830) State HANGUP
5/04-12:31:49,087 2021-05-04 12:31:49.065273 [DEBUG] mod_sofia.c:460 Channel sofia/david-tld/006314141923830 hanging up, cause: RECOVERY_ON_TIMER_EXPIRE
5/04-12:31:49,087 2021-05-04 12:31:49.065273 [DEBUG] switch_core_state_machine.c:60 sofia/david-tld/006314141923830 Standard HANGUP, cause: RECOVERY_ON_TIMER_EXPIRE
5/04-12:31:49,087 2021-05-04 12:31:49.065273 [DEBUG] switch_core_state_machine.c:850 (sofia/david-tld/006314141923830) State HANGUP going to sleep
5/04-12:31:49,087 2021-05-04 12:31:49.065273 [DEBUG] switch_core_state_machine.c:620 (sofia/david-tld/006314141923830) State Change CS_HANGUP -> CS_REPORTING
5/04-12:31:49,087 2021-05-04 12:31:49.065273 [DEBUG] switch_core_state_machine.c:585 (sofia/david-tld/006314141923830) Running State Change CS_REPORTING (Cur 1 Tot 93)
5/04-12:31:49,087 2021-05-04 12:31:49.065273 [DEBUG] switch_core_state_machine.c:936 (sofia/david-tld/006314141923830) State REPORTING
5/04-12:31:49,087 2021-05-04 12:31:49.065273 [DEBUG] switch_core_state_machine.c:174 sofia/david-tld/006314141923830 Standard REPORTING, cause: RECOVERY_ON_TIMER_EXPIRE
5/04-12:31:49,088 2021-05-04 12:31:49.065273 [DEBUG] switch_core_state_machine.c:936 (sofia/david-tld/006314141923830) State REPORTING going to sleep
5/04-12:31:49,088 2021-05-04 12:31:49.065273 [DEBUG] switch_core_state_machine.c:611 (sofia/david-tld/006314141923830) State Change CS_REPORTING -> CS_DESTROY
5/04-12:31:49,088 2021-05-04 12:31:49.065273 [DEBUG] switch_core_session.c:1726 Session 93 (sofia/david-tld/006314141923830) Locked, Waiting on external entities
5/04-12:31:49,088 2021-05-04 12:31:49.075274 [DEBUG] switch_ivr_originate.c:3949 Originate Resulted in Error Cause: 102 [RECOVERY_ON_TIMER_EXPIRE]
5/04-12:31:49,088 2021-05-04 12:31:49.075274 [NOTICE] switch_core_session.c:1744 Session 93 (sofia/david-tld/006314141923830) Ended
5/04-12:31:49,088 2021-05-04 12:31:49.075274 [NOTICE] switch_core_session.c:1748 Close Channel sofia/david-tld/006314141923830 [CS_DESTROY]
5/04-12:31:49,089 2021-05-04 12:31:49.075274 [DEBUG] switch_core_state_machine.c:739 (sofia/david-tld/006314141923830) Running State Change CS_DESTROY (Cur 0 Tot 93)
5/04-12:31:49,089 2021-05-04 12:31:49.075274 [DEBUG] switch_core_state_machine.c:749 (sofia/david-tld/006314141923830) State DESTROY
5/04-12:31:49,089 2021-05-04 12:31:49.075274 [DEBUG] mod_sofia.c:365 sofia/david-tld/006314141923830 SOFIA DESTROY
5/04-12:31:49,089 2021-05-04 12:31:49.075274 [DEBUG] switch_core_state_machine.c:181 sofia/david-tld/006314141923830 Standard DESTROY
5/04-12:31:49,089 2021-05-04 12:31:49.075274 [DEBUG] switch_core_state_machine.c:749 (sofia/david-tld/006314141923830) State DESTROY going to sleep
5/04-12:34:06,481 Entering onExit(), ProgState.Ende=0
5/04-12:34:06,482 Leaving onExit()
5/04-12:34:06,483 Disconnected. on ESL_FAIL
5/04-12:34:06,483 LogData ended