Apr 12 00:52:14 UC100 user.notice freeswitch[2015]: recv 793 bytes from udp/[192.168.30.1]:5060(local:192.168.30.15:5060) at 00:52:14.438700:    ------------------------------------------------------------------------
Apr 12 00:52:14 UC100 user.notice freeswitch[2015]:    REGISTER sip:192.168.30.15:5060 SIP/2.0
Apr 12 00:52:14 UC100 user.notice freeswitch[2015]:    Via: SIP/2.0/UDP 192.168.30.1:5060;branch=z9hG4bK1377461299
Apr 12 00:52:14 UC100 user.notice freeswitch[2015]:    From: "200" <sip:200@192.168.30.15:5060>;tag=3699345532
Apr 12 00:52:14 UC100 user.notice freeswitch[2015]:    To: "200" <sip:200@192.168.30.15:5060>
Apr 12 00:52:14 UC100 user.notice freeswitch[2015]:    Call-ID: 0_526858704@192.168.89.243
Apr 12 00:52:14 UC100 user.notice freeswitch[2015]:    CSeq: 146 REGISTER
Apr 12 00:52:14 UC100 user.notice freeswitch[2015]:    Contact: <sip:200@192.168.30.1:5060>
Apr 12 00:52:14 UC100 user.notice freeswitch[2015]:    Authorization: Digest username="200", realm="UC100", nonce="087fc05e-eca2-4b5f-9c2f-51d65260a634", uri="sip:192.168.30.15:5060", response="9e647eace8cb41f60f0a046ab6979be9", algorithm=MD5, cnonce="0a4f113b", qop=au
Apr 12 00:52:14 UC100 user.notice freeswitch[2015]:    Allow: INVITE, INFO, PRACK, ACK, BYE, CANCEL, OPTIONS, NOTIFY, REGISTER, SUBSCRIBE, REFER, PUBLISH, UPDATE, MESSAGE
Apr 12 00:52:14 UC100 user.notice freeswitch[2015]:    Max-Forwards: 70
Apr 12 00:52:14 UC100 user.notice freeswitch[2015]:    User-Agent: Yealink SIP-T21P_E2 52.84.0.15
Apr 12 00:52:14 UC100 user.notice freeswitch[2015]:    Expires: 3600
Apr 12 00:52:14 UC100 user.notice freeswitch[2015]:    Allow-Events: talk,hold,conference,refer,check-sync
Apr 12 00:52:14 UC100 user.notice freeswitch[2015]:    Content-Length: 0
Apr 12 00:52:14 UC100 user.notice freeswitch[2015]:    ------------------------------------------------------------------------
Apr 12 00:52:14 UC100 user.notice freeswitch[2015]: send 559 bytes to udp/[192.168.30.1]:5060(local:192.168.30.15:5060) at 00:52:14.501640:    ------------------------------------------------------------------------
Apr 12 00:52:14 UC100 user.notice freeswitch[2015]:    SIP/2.0 200 OK
Apr 12 00:52:14 UC100 user.notice freeswitch[2015]:    Via: SIP/2.0/UDP 192.168.30.1:5060;branch=z9hG4bK1377461299
Apr 12 00:52:14 UC100 user.notice freeswitch[2015]:    From: "200" <sip:200@192.168.30.15:5060>;tag=3699345532
Apr 12 00:52:14 UC100 user.notice freeswitch[2015]:    To: "200" <sip:200@192.168.30.15:5060>;tag=gHv16emc8eNmH
Apr 12 00:52:14 UC100 user.notice freeswitch[2015]:    Call-ID: 0_526858704@192.168.89.243
Apr 12 00:52:14 UC100 user.notice freeswitch[2015]:    CSeq: 146 REGISTER
Apr 12 00:52:14 UC100 user.notice freeswitch[2015]:    Contact: <sip:200@192.168.30.1:5060>;expires=30
Apr 12 00:52:14 UC100 user.notice freeswitch[2015]:    Date: Tue, 12 Apr 2022 00:52:14 GMT
Apr 12 00:52:14 UC100 user.notice freeswitch[2015]:    User-Agent: UC100/2.53.4.16 2019-01-17 20:11:39 CST +0800
Apr 12 00:52:14 UC100 user.notice freeswitch[2015]:    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, SUBSCRIBE, PUBLISH
Apr 12 00:52:14 UC100 user.notice freeswitch[2015]:    Supported: timer, path, replaces
Apr 12 00:52:14 UC100 user.notice freeswitch[2015]:    Content-Length: 0
Apr 12 00:52:14 UC100 user.notice freeswitch[2015]:    ------------------------------------------------------------------------
Apr 12 00:52:15 UC100 user.debug freeswitch[2015]: slot 0 chn 0 detect RING !!!.
Apr 12 00:52:15 UC100 user.info freeswitch[2015]: channel(slot:0 port:0) is offhook.
Apr 12 00:52:15 UC100 user.debug freeswitch[2015]: [s1c1][0:0] create fxso event enum_id:5, data_len:0, spanid = 0 !
Apr 12 00:52:15 UC100 user.debug freeswitch[2015]: ftdm_queue_dequeue(fchan->event_queue)
Apr 12 00:52:15 UC100 user.debug freeswitch[2015]: ftdm_queue_dequeue(span->event_queue)
Apr 12 00:52:15 UC100 user.debug freeswitch[2015]: [s1c1][0:0] received fxso event enum_id:5, data_len:0!
Apr 12 00:52:15 UC100 user.debug freeswitch[2015]: fio_channel_process_event
Apr 12 00:52:15 UC100 user.debug freeswitch[2015]: [s1c1][0:0] Received event [RING_START] in state [DOWN]
Apr 12 00:52:15 UC100 user.debug freeswitch[2015]: [s1c1][0:0] flags:a, max_dialstr:30, wait_dialtone_timeout:10000, polarity_delay:600, digit_timeout:4000, hotline:
Apr 12 00:52:15 UC100 user.debug freeswitch[2015]: [s1c1][0:0] Changed state from DOWN to GET_CALLERID
Apr 12 00:52:15 UC100 user.info freeswitch[2015]: recv ring spi packet!
Apr 12 00:52:15 UC100 user.debug freeswitch[2015]: slot:0 spi_chn:0 recv INTE_SRC spi packets, value:1.
Apr 12 00:52:15 UC100 user.debug freeswitch[2015]: [0 0]recv LINE_VOLT_STAT spi packet, voltage:30, current:0!
Apr 12 00:52:15 UC100 user.debug freeswitch[2015]: [s1c1][0:0] flags:a, max_dialstr:30, wait_dialtone_timeout:10000, polarity_delay:600, digit_timeout:4000, hotline:
Apr 12 00:52:15 UC100 user.debug freeswitch[2015]: [s1c1][0:0] ANALOG CHANNEL thread starting.
Apr 12 00:52:15 UC100 user.debug freeswitch[2015]: dsp channel is 0, span = 0, channel= 0, chan number = 2!
Apr 12 00:52:15 UC100 user.info freeswitch[2015]: dsp:0,chan;0, offhook open
Apr 12 00:52:15 UC100 user.notice syslog: PCM_BUILD        = 7620 Dec 19 2018 14:04:56
Apr 12 00:52:15 UC100 user.notice syslog: PCM_SEG_CHN      = 1
Apr 12 00:52:15 UC100 user.notice syslog: PCM_SEG_MS       = 10
Apr 12 00:52:15 UC100 user.notice syslog: PCM_SEG_SAMPLES  = 80
Apr 12 00:52:15 UC100 user.notice syslog: PCM_SEG_NUM      = 256
Apr 12 00:52:15 UC100 user.notice syslog: PCM_TX_MAX_GAP   = 3
Apr 12 00:52:15 UC100 user.notice syslog: PCM_RX_MAX_GAP   = 2
Apr 12 00:52:15 UC100 user.notice syslog: PCM_PKT_LENGTH   = 160
Apr 12 00:52:15 UC100 user.notice syslog: PCM_SYS_TICK_HZ  = 100
Apr 12 00:52:15 UC100 user.debug freeswitch[2015]: [s1c1][0:0] create socket ip:192.168.11.1 port:8000.
Apr 12 00:52:15 UC100 user.debug freeswitch[2015]: [s1c1][0:0] meida remote ip:192.168.11.1 remote port:8000 local ip:192.168.11.1 local port:5174.
Apr 12 00:52:15 UC100 user.debug freeswitch[2015]: [s1c1][0:0] dsp open channel successly!
Apr 12 00:52:15 UC100 user.debug freeswitch[2015]: [s1c1][0:0] Initialized DTMF detection
Apr 12 00:52:15 UC100 user.debug freeswitch[2015]: [s1c1][0:0] Completed state change from DOWN to GET_CALLERID in 28 ms
Apr 12 00:52:15 UC100 user.debug freeswitch[2015]: [s1c1][0:0] Executing state handler on 1:1 for GET_CALLERID
Apr 12 00:52:15 UC100 user.notice syslog: chan:0    RX seg dma: * first_sync, dma_chan:0, loopback_chan:0, pcm_mode:2, length:160 
Apr 12 00:52:15 UC100 user.notice syslog: chan:0    TX seg dma: * first_sync, dma_chan:0, loopback_chan:0, pcm_mode:2, length:160 
Apr 12 00:52:15 UC100 user.debug freeswitch[2015]: dsp channel is 0, span = 0, chan number = 2 enable cid detect!
Apr 12 00:52:15 UC100 user.debug freeswitch[2015]: [s1c1][0:0] fxo enable callerid detect successly.
Apr 12 00:52:15 UC100 user.info freeswitch[2015]: slot:0 port:0 detect ring again.
Apr 12 00:52:15 UC100 user.debug freeswitch[2015]: slot:0 spi_chn:0 recv INTE_SRC spi packets, value:1.
Apr 12 00:52:15 UC100 user.debug freeswitch[2015]: [0 0]recv LINE_VOLT_STAT spi packet, voltage:63, current:0!
Apr 12 00:52:15 UC100 user.info freeswitch[2015]: slot:0 port:0 detect ring again.
Apr 12 00:52:15 UC100 user.debug freeswitch[2015]: slot:0 spi_chn:0 recv INTE_SRC spi packets, value:1.
Apr 12 00:52:15 UC100 user.debug freeswitch[2015]: [0 0]recv LINE_VOLT_STAT spi packet, voltage:7, current:0!
Apr 12 00:52:16 UC100 user.info freeswitch[2015]: slot:0 port:0 detect ring again.
Apr 12 00:52:16 UC100 user.debug freeswitch[2015]: slot:0 spi_chn:0 recv INTE_SRC spi packets, value:1.
Apr 12 00:52:16 UC100 user.debug freeswitch[2015]: [0 0]recv LINE_VOLT_STAT spi packet, voltage:19, current:0!
Apr 12 00:52:16 UC100 user.debug syslog: Web created thread: 6828
Apr 12 00:52:16 UC100 user.debug syslog: Web buried thread: 6719
Apr 12 00:52:16 UC100 user.info freeswitch[2015]: slot:0 port:0 detect ring again.
Apr 12 00:52:16 UC100 user.debug freeswitch[2015]: slot:0 spi_chn:0 recv INTE_SRC spi packets, value:1.
Apr 12 00:52:16 UC100 user.debug freeswitch[2015]: [0 0]recv LINE_VOLT_STAT spi packet, voltage:57, current:0!
Apr 12 00:52:16 UC100 user.info freeswitch[2015]: slot:0 port:0 detect ring again.
Apr 12 00:52:16 UC100 user.debug freeswitch[2015]: slot:0 spi_chn:0 recv INTE_SRC spi packets, value:1.
Apr 12 00:52:16 UC100 user.debug freeswitch[2015]: [0 0]recv LINE_VOLT_STAT spi packet, voltage:45, current:0!
Apr 12 00:52:17 UC100 user.info freeswitch[2015]: Clock synchronized to system time.
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: [s1c1][0:0] fxso recv DSP_EVENT_CALLERID_DETECTED_EVENT event, dsp event id:20!
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: [s1c1][0:0] fxo recv callerid, msg_type:4, msg_length:19!
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: [s1c1][0:0] fxo recv callerid(cid_number:[03217169974], cid_name:[], cid_date:[04120603])!
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: [s1c1][0:0] fxso recv dsp event,slot:0, channelId = 0, event = 20!
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: [s1c1][0:0] fxso recv DSP_EVENT_CALLERID_DETECTED_EVENT event, dsp event id:20!
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: [s1c1][0:0] fxo recv callerid(cid_number:[03217169974], cid_name:[], cid_date:[04120603])!
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: [s1c1][0:0] create fxso event enum_id:13, data_len:114, spanid = 0 !
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: ftdm_queue_dequeue(fchan->event_queue)
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: ftdm_queue_dequeue(span->event_queue)
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: [s1c1][0:0] received fxso event enum_id:13, data_len:114!
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: [s1c1][0:0] fxo recv callerid(cid_number:[03217169974], cid_name:[], cid_date:[04120603])!
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: dsp channel is 0, span = 0, chan number = 2 disable cid detect!
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: [s1c1][0:0] fxo disable callerid detect successly.
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: fio_channel_process_event
Apr 12 00:52:17 UC100 user.notice freeswitch[2015]: [s1c1][0:0] ftdm_queue_dequeue error.
Apr 12 00:52:17 UC100 user.notice freeswitch[2015]: [s1c1][0:0] ftdm_queue_dequeue error.
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: dsp channel is 0, span = 0, channel= 0, chan number = 2!
Apr 12 00:52:17 UC100 user.info freeswitch[2015]: dsp:0,chan;0, offhook open
Apr 12 00:52:17 UC100 user.notice syslog: PCM_BUILD        = 7620 Dec 19 2018 14:04:56
Apr 12 00:52:17 UC100 user.notice syslog: PCM_SEG_CHN      = 1
Apr 12 00:52:17 UC100 user.notice syslog: PCM_SEG_MS       = 10
Apr 12 00:52:17 UC100 user.notice syslog: PCM_SEG_SAMPLES  = 80
Apr 12 00:52:17 UC100 user.notice syslog: PCM_SEG_NUM      = 256
Apr 12 00:52:17 UC100 user.notice syslog: PCM_TX_MAX_GAP   = 3
Apr 12 00:52:17 UC100 user.notice syslog: PCM_RX_MAX_GAP   = 2
Apr 12 00:52:17 UC100 user.notice syslog: PCM_PKT_LENGTH   = 160
Apr 12 00:52:17 UC100 user.notice syslog: PCM_SYS_TICK_HZ  = 100
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: [s1c1][0:0] create socket ip:192.168.11.1 port:8000.
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: [s1c1][0:0] meida remote ip:192.168.11.1 remote port:8000 local ip:192.168.11.1 local port:5176.
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: [s1c1][0:0] Changed state from GET_CALLERID to RING
Apr 12 00:52:17 UC100 user.notice syslog: chan:0    RX seg dma: * first_sync, dma_chan:0, loopback_chan:0, pcm_mode:2, length:160 
Apr 12 00:52:17 UC100 user.notice syslog: chan:0    TX seg dma: * first_sync, dma_chan:0, loopback_chan:0, pcm_mode:2, length:160 
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: [s1c1][0:0] Completed state change from GET_CALLERID to RING in 20 ms
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: [s1c1][0:0] Executing state handler on 1:1 for RING
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: got FXO sig 1:1 [START]
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: [s1c1][0:0] set default codec PCMA 20ms
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: Connect inbound channel FreeTDM/1:1/ 
Apr 12 00:52:17 UC100 user.notice freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 New Channel FreeTDM/1:1/  [20707da2-685b-45f5-9286-5bdda7254e77]
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 (FreeTDM/1:1/ ) State Change CS_NEW -> CS_INIT
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Send signal FreeTDM/1:1/  [BREAK]
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 (FreeTDM/1:1/ ) Running State Change CS_INIT
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 (FreeTDM/1:1/ ) State INIT
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 (FreeTDM/1:1/ ) State Change CS_INIT -> CS_ROUTING
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Send signal FreeTDM/1:1/  [BREAK]
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 (FreeTDM/1:1/ ) State INIT going to sleep
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 (FreeTDM/1:1/ ) Running State Change CS_ROUTING
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 (FreeTDM/1:1/ ) Callstate Change DOWN -> RINGING
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 (FreeTDM/1:1/ ) State ROUTING
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: FreeTDM/1:1/  CHANNEL ROUTING
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: [s1c1][0:0] Indicating PROCEED in state RING
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 FreeTDM/1:1/  Standard ROUTING
Apr 12 00:52:17 UC100 user.info freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Processing 03217169974 <03217169974>->  in context public
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Dialplan: FreeTDM/1:1/  parsing [public->unloop] continue=true
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Dialplan: FreeTDM/1:1/  Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Dialplan: FreeTDM/1:1/  Action ring_ready() 
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Dialplan: FreeTDM/1:1/  Action lua(set_chan_name_by_uci_cfg.lua) 
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Dialplan: FreeTDM/1:1/  Action lua(set_base_param.lua) 
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Dialplan: FreeTDM/1:1/  Regex (FAIL) [unloop] chan_name(FreeTDM/1:1/ ) =~ /^sofia// break=on-false
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Dialplan: FreeTDM/1:1/  parsing [public->factory test] continue=false
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Dialplan: FreeTDM/1:1/  Regex (PASS) [factory test] chan_name(FreeTDM/1:1/ ) =~ /^FreeTDM\/1:1\// break=on-false
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Dialplan: FreeTDM/1:1/  Regex (FAIL) [factory test] destination_number( ) =~ /\*100\*100\*000/ break=on-false
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Dialplan: FreeTDM/1:1/  parsing [public->featurecode service] continue=false
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Dialplan: FreeTDM/1:1/  Regex (FAIL) [featurecode service] chan_name(FreeTDM/1:1/ ) =~ /^sofia/user/ break=on-false
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Dialplan: FreeTDM/1:1/  parsing [public->speed dial check] continue=true
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Dialplan: FreeTDM/1:1/  Regex (FAIL) [speed dial check] chan_name(FreeTDM/1:1/ ) =~ /Not Config/ break=on-false
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Dialplan: FreeTDM/1:1/  parsing [public->Call Filter] continue=true
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Dialplan: FreeTDM/1:1/  Regex (PASS) [Call Filter] chan_name(FreeTDM/1:1/ ) =~ /^sofia/user|^FreeTDM/ break=on-false
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Dialplan: FreeTDM/1:1/  Action lua(call_filter.lua out) 
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Dialplan: FreeTDM/1:1/  parsing [public->DID match check] continue=true
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Dialplan: FreeTDM/1:1/  Regex (FAIL) [DID match check] ${destination_number}( ) =~ /^([0-9a-zA-Z+*#]+)$/ break=on-false
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Dialplan: FreeTDM/1:1/  parsing [public->DID] continue=false
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Dialplan: FreeTDM/1:1/  Regex (FAIL) [DID] ${did_destination}() =~ /^\d+$/ break=on-false
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Dialplan: FreeTDM/1:1/  parsing [public->local_extension] continue=false
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 |--- Dialplan: Processing recursive conditions level:1 [local_extension_recur_1] require-nested=TRUE
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 |--- Dialplan: FreeTDM/1:1/  Regex (FAIL) [local_extension_recur_1] ${destination_number}( ) =~ /^205[*#]{0,1}$|^2001[*#]{0,1}$|^201[*#]{0,1}$|^208[*#]{0,1}$|^100[*#]{0,1}$|^207[*#
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Dialplan: FreeTDM/1:1/  parsing [public->extension_to_gsm_fxo] continue=false
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Dialplan: FreeTDM/1:1/  Regex (FAIL) [extension_to_gsm_fxo] ${destination_number}( ) =~ /^8000[*#]{0,1}$|^8001[*#]{0,1}$/ break=on-false
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Dialplan: FreeTDM/1:1/  parsing [public->intercept-default] continue=false
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Dialplan: FreeTDM/1:1/  Regex (PASS) [intercept-default] chan_name(FreeTDM/1:1/ ) =~ /^FreeTDM|^sofia/user/ break=on-false
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Dialplan: FreeTDM/1:1/  Regex (FAIL) [intercept-default] destination_number( ) =~ /^\*\*$|^\*\*\d+$/ break=on-false
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Dialplan: FreeTDM/1:1/  parsing [public->29] continue=false
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Dialplan: FreeTDM/1:1/  Regex (PASS) [29] ${last_matched_route}() =~ /^(?!29)/ break=on-false
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Dialplan: FreeTDM/1:1/  Regex (PASS) [29] chan_name(FreeTDM/1:1/ ) =~ /^FreeTDM/1:1|^FreeTDM/1:2/ break=on-false
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Dialplan: FreeTDM/1:1/  Action set(last_matched_route=29) 
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Dialplan: FreeTDM/1:1/  Action set(my_dst_number=${destination_number}) 
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Dialplan: FreeTDM/1:1/  Action lua(extension_service.lua 2000) 
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 (FreeTDM/1:1/ ) State Change CS_ROUTING -> CS_EXECUTE
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Send signal FreeTDM/1:1/  [BREAK]
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 (FreeTDM/1:1/ ) State ROUTING going to sleep
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 (FreeTDM/1:1/ ) Running State Change CS_EXECUTE
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 (FreeTDM/1:1/ ) State EXECUTE
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: FreeTDM/1:1/  CHANNEL EXECUTE
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 FreeTDM/1:1/  Standard EXECUTE
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 EXECUTE FreeTDM/1:1/  ring_ready()
Apr 12 00:52:17 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 26, file:src/switch_core_session.c!
Apr 12 00:52:17 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 7, file:FreeTDM/1:1/ !
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Send signal FreeTDM/1:1/  [BREAK]
Apr 12 00:52:17 UC100 user.notice freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Ring Ready FreeTDM/1:1/ !
Apr 12 00:52:17 UC100 user.notice freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Ring-Ready FreeTDM/1:1/ !
Apr 12 00:52:17 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 45, file:FreeTDM/1:1/ !
Apr 12 00:52:17 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 27, file:src/switch_core_session.c!
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 EXECUTE FreeTDM/1:1/  lua(set_chan_name_by_uci_cfg.lua)
Apr 12 00:52:17 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 26, file:src/switch_core_session.c!
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 FreeTDM/1:1/  destroy/unlink session from object
Apr 12 00:52:17 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 27, file:src/switch_core_session.c!
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 EXECUTE FreeTDM/1:1/  lua(set_base_param.lua)
Apr 12 00:52:17 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 26, file:src/switch_core_session.c!
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 FreeTDM/1:1/  destroy/unlink session from object
Apr 12 00:52:17 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 27, file:src/switch_core_session.c!
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 EXECUTE FreeTDM/1:1/  lua(call_filter.lua out)
Apr 12 00:52:17 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 26, file:src/switch_core_session.c!
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 FreeTDM/1:1/  destroy/unlink session from object
Apr 12 00:52:17 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 27, file:src/switch_core_session.c!
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 EXECUTE FreeTDM/1:1/  set(last_matched_route=29)
Apr 12 00:52:17 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 26, file:src/switch_core_session.c!
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 FreeTDM/1:1/  SET [last_matched_route]=[29]
Apr 12 00:52:17 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 27, file:src/switch_core_session.c!
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 EXECUTE FreeTDM/1:1/  set(my_dst_number= )
Apr 12 00:52:17 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 26, file:src/switch_core_session.c!
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 FreeTDM/1:1/  SET [my_dst_number]=[ ]
Apr 12 00:52:17 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 27, file:src/switch_core_session.c!
Apr 12 00:52:17 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 EXECUTE FreeTDM/1:1/  lua(extension_service.lua 2000)
Apr 12 00:52:17 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 26, file:src/switch_core_session.c!
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 EXECUTE FreeTDM/1:1/  unset(did_destination)
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 26, file:src/switch_core_session.c!
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 UNSET [did_destination]
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 27, file:src/switch_core_session.c!
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 EXECUTE FreeTDM/1:1/  export(progress_timeout=55)
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 26, file:src/switch_core_session.c!
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 EXPORT (export_vars) [progress_timeout]=[55]
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 27, file:src/switch_core_session.c!
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 EXECUTE FreeTDM/1:1/  export(originate_timeout=55)
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 26, file:src/switch_core_session.c!
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 EXPORT (export_vars) [originate_timeout]=[55]
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 27, file:src/switch_core_session.c!
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 EXECUTE FreeTDM/1:1/  export(force_transfer_context=public)
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 26, file:src/switch_core_session.c!
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 EXPORT (export_vars) [force_transfer_context]=[public]
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 27, file:src/switch_core_session.c!
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 EXECUTE FreeTDM/1:1/  export(sip_redirect_context=public)
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 26, file:src/switch_core_session.c!
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 EXPORT (export_vars) [sip_redirect_context]=[public]
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 27, file:src/switch_core_session.c!
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 EXECUTE FreeTDM/1:1/  bind_meta_app(1 b is execute_extension::blind_transfer XML transfer)
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 26, file:src/switch_core_session.c!
Apr 12 00:52:18 UC100 user.info freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Bound B-Leg: *1 execute_extension::blind_transfer XML transfer
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 27, file:src/switch_core_session.c!
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 EXECUTE FreeTDM/1:1/  bind_meta_app(2 b ib execute_extension::att_xfer XML transfer)
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 26, file:src/switch_core_session.c!
Apr 12 00:52:18 UC100 user.info freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Bound B-Leg: *2 execute_extension::att_xfer XML transfer
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 27, file:src/switch_core_session.c!
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 FreeTDM/1:1/  set pstn->sip fax param...
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 EXECUTE FreeTDM/1:1/  export(fax_enable_t38_request=true)
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 26, file:src/switch_core_session.c!
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 EXPORT (export_vars) [fax_enable_t38_request]=[true]
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 27, file:src/switch_core_session.c!
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 EXECUTE FreeTDM/1:1/  export(sip_execute_on_image=myfax_fax_start t38 self)
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 26, file:src/switch_core_session.c!
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 EXPORT (export_vars) [sip_execute_on_image]=[myfax_fax_start t38 self]
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 27, file:src/switch_core_session.c!
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 EXECUTE FreeTDM/1:1/  export(fax_enable_t30_request=true)
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 26, file:src/switch_core_session.c!
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 EXPORT (export_vars) [fax_enable_t30_request]=[true]
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 27, file:src/switch_core_session.c!
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 EXECUTE FreeTDM/1:1/  export(sip_execute_on_t30=myfax_fax_start t30 self)
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 26, file:src/switch_core_session.c!
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 EXPORT (export_vars) [sip_execute_on_t30]=[myfax_fax_start t30 self]
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 27, file:src/switch_core_session.c!
Apr 12 00:52:18 UC100 user.info freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 FreeTDM/1:1/   -> user/2000 set called codec to G723@30i,G729@20i,PCMA@20i,PCMU@20i,
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 EXECUTE FreeTDM/1:1/  export(nolocal:absolute_codec_string=G723@30i,G729@20i,PCMA@20i,PCMU@20i,)
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 26, file:src/switch_core_session.c!
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 EXPORT (export_vars) (REMOTE ONLY) [absolute_codec_string]=[G723@30i,G729@20i,PCMA@20i,PCMU@20i,]
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 27, file:src/switch_core_session.c!
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 EXECUTE FreeTDM/1:1/  export(nolocal:bridge_generate_comfort_noise=true)
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 26, file:src/switch_core_session.c!
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 EXPORT (export_vars) (REMOTE ONLY) [bridge_generate_comfort_noise]=[true]
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 27, file:src/switch_core_session.c!
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 EXECUTE FreeTDM/1:1/  export(nolocal:rtp_auto_adjust_threshold=1)
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 26, file:src/switch_core_session.c!
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 EXPORT (export_vars) (REMOTE ONLY) [rtp_auto_adjust_threshold]=[1]
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 27, file:src/switch_core_session.c!
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 EXECUTE FreeTDM/1:1/  export(nolocal:sip_contact_user=03217169974)
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 26, file:src/switch_core_session.c!
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 EXPORT (export_vars) (REMOTE ONLY) [sip_contact_user]=[03217169974]
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 27, file:src/switch_core_session.c!
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 EXECUTE FreeTDM/1:1/  limit(hash sip_ext 2000 2 !USER_BUSY)
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 26, file:src/switch_core_session.c!
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 incr called: sip_ext_2000 max:2, interval:0
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Usage for sip_ext_2000 is now 1/2
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 27, file:src/switch_core_session.c!
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 EXECUTE FreeTDM/1:1/  bridge(user/2000)
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]: [s1c1][0:0] mod_freetdm receive message, id = 26, file:src/switch_core_session.c!
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 FreeTDM/1:1/  EXPORTING[export_vars] [progress_timeout]=[55] to event
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 FreeTDM/1:1/  EXPORTING[export_vars] [originate_timeout]=[55] to event
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 FreeTDM/1:1/  EXPORTING[export_vars] [force_transfer_context]=[public] to event
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 FreeTDM/1:1/  EXPORTING[export_vars] [sip_redirect_context]=[public] to event
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 FreeTDM/1:1/  EXPORTING[export_vars] [fax_enable_t38_request]=[true] to event
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 FreeTDM/1:1/  EXPORTING[export_vars] [sip_execute_on_image]=[myfax_fax_start t38 self] to event
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 FreeTDM/1:1/  EXPORTING[export_vars] [fax_enable_t30_request]=[true] to event
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 FreeTDM/1:1/  EXPORTING[export_vars] [sip_execute_on_t30]=[myfax_fax_start t30 self] to event
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 FreeTDM/1:1/  EXPORTING[export_vars] [absolute_codec_string]=[G723@30i,G729@20i,PCMA@20i,PCMU@20i,] to event
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 FreeTDM/1:1/  EXPORTING[export_vars] [bridge_generate_comfort_noise]=[true] to event
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 FreeTDM/1:1/  EXPORTING[export_vars] [rtp_auto_adjust_threshold]=[1] to event
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 FreeTDM/1:1/  EXPORTING[export_vars] [sip_contact_user]=[03217169974] to event
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Parsing global variables
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 FreeTDM/1:1/  EXPORTING[export_vars] [progress_timeout]=[55] to event
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 FreeTDM/1:1/  EXPORTING[export_vars] [originate_timeout]=[55] to event
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 FreeTDM/1:1/  EXPORTING[export_vars] [force_transfer_context]=[public] to event
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 FreeTDM/1:1/  EXPORTING[export_vars] [sip_redirect_context]=[public] to event
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 FreeTDM/1:1/  EXPORTING[export_vars] [fax_enable_t38_request]=[true] to event
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 FreeTDM/1:1/  EXPORTING[export_vars] [sip_execute_on_image]=[myfax_fax_start t38 self] to event
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 FreeTDM/1:1/  EXPORTING[export_vars] [fax_enable_t30_request]=[true] to event
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 FreeTDM/1:1/  EXPORTING[export_vars] [sip_execute_on_t30]=[myfax_fax_start t30 self] to event
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 FreeTDM/1:1/  EXPORTING[export_vars] [absolute_codec_string]=[G723@30i,G729@20i,PCMA@20i,PCMU@20i,] to event
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 FreeTDM/1:1/  EXPORTING[export_vars] [bridge_generate_comfort_noise]=[true] to event
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 FreeTDM/1:1/  EXPORTING[export_vars] [rtp_auto_adjust_threshold]=[1] to event
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 FreeTDM/1:1/  EXPORTING[export_vars] [sip_contact_user]=[03217169974] to event
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Parsing global variables
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: Parsing variable [sip_invite_domain]=[UC100]
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: Parsing variable [presence_id]=[2000@UC100]
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]: cb5bd758-0e1e-47ac-867d-8bbe30b5287d New Channel sofia/user/s@192.168.30.1:61418 [cb5bd758-0e1e-47ac-867d-8bbe30b5287d]
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: cb5bd758-0e1e-47ac-867d-8bbe30b5287d (sofia/user/s@192.168.30.1:61418) State Change CS_NEW -> CS_INIT
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: cb5bd758-0e1e-47ac-867d-8bbe30b5287d Send signal sofia/user/s@192.168.30.1:61418 [BREAK]
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: cb5bd758-0e1e-47ac-867d-8bbe30b5287d (sofia/user/s@192.168.30.1:61418) Running State Change CS_INIT
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: cb5bd758-0e1e-47ac-867d-8bbe30b5287d (sofia/user/s@192.168.30.1:61418) State INIT
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: cb5bd758-0e1e-47ac-867d-8bbe30b5287d sofia/user/s@192.168.30.1:61418 SOFIA INIT
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: cb5bd758-0e1e-47ac-867d-8bbe30b5287d sofia/user/s@192.168.30.1:61418 sending invite version: 1.4.12  32bit Local SDP: v=0 o=UC100 1649708588 1649708589 IN IP4 192.168.30.15 s=UC100 c=IN IP4 192.168.30.15 t=0 0 m=audio
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: cb5bd758-0e1e-47ac-867d-8bbe30b5287d sofia/user/s@192.168.30.1:61418 Standard INIT
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: cb5bd758-0e1e-47ac-867d-8bbe30b5287d (sofia/user/s@192.168.30.1:61418) State Change CS_INIT -> CS_ROUTING
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: cb5bd758-0e1e-47ac-867d-8bbe30b5287d Send signal sofia/user/s@192.168.30.1:61418 [BREAK]
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]: send 1143 bytes to udp/[192.168.30.1]:61418(local:192.168.30.15:5060) at 00:52:18.410540:    ------------------------------------------------------------------------
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    INVITE sip:s@192.168.30.1:61418;line=dstghmt SIP/2.0
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    Via: SIP/2.0/UDP 192.168.30.15:5060;rport;branch=z9hG4bKmc8D3Naj64UQQ
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    Max-Forwards: 70
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: cb5bd758-0e1e-47ac-867d-8bbe30b5287d (sofia/user/s@192.168.30.1:61418) State INIT going to sleep
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    From: "03217169974" <sip:03217169974@UC100>;tag=HtNt894F5QB7c
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    To: <sip:s@192.168.30.1:61418;line=dstghmt>
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    Call-ID: a4f8aff8-349d-123b-21a3-f8a03d59cdf2
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    CSeq: 50308577 INVITE
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    Contact: <sip:03217169974@192.168.30.15:5060>
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    User-Agent: UC100/2.53.4.16 2019-01-17 20:11:39 CST +0800
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, SUBSCRIBE, PUBLISH
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    Supported: timer, path, replaces
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    Allow-Events: talk, hold, conference, dialog, presence, as-feature-event, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    Content-Type: application/sdp
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    Content-Disposition: session
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    Content-Length: 277
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    X-FS-Support: update_display,send_info
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    v=0
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    o=UC100 1649708588 1649708589 IN IP4 192.168.30.15
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    s=UC100
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    c=IN IP4 192.168.30.15
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    t=0 0
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    m=audio 16150 RTP/AVP 4 18 8 0 101 13
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    a=rtpmap:4 G723/8000
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    a=rtpmap:18 G729/8000
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    a=rtpmap:8 PCMA/8000
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    a=rtpmap:0 PCMU/8000
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    a=rtpmap:101 telephone-event/8000
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    a=fmtp:101 0-16
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    ------------------------------------------------------------------------
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: cb5bd758-0e1e-47ac-867d-8bbe30b5287d Send signal sofia/user/s@192.168.30.1:61418 [BREAK]
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]: recv 514 bytes from udp/[192.168.30.1]:61418(local:192.168.30.15:5060) at 00:52:18.440860:    ------------------------------------------------------------------------
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    SIP/2.0 401 Unauthorized
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    Via: SIP/2.0/UDP 192.168.30.15:5060;rport=5060;received=192.168.30.15;branch=z9hG4bKmc8D3Naj64UQQ
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    Call-ID: a4f8aff8-349d-123b-21a3-f8a03d59cdf2
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    From: "03217169974" <sip:03217169974@UC100>;tag=HtNt894F5QB7c
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    To: <sip:s@192.168.30.1:61418;line=dstghmt>;tag=z9hG4bKmc8D3Naj64UQQ
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    CSeq: 50308577 INVITE
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    WWW-Authenticate: Digest realm="asterisk",nonce="1649725402/844e9391578267587173bb6000ee3553",opaque="354efa5b175e7eec",algorithm=md5,qop="auth"
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    Server: VitalPBX
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    Content-Length:  0
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    ------------------------------------------------------------------------
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: cb5bd758-0e1e-47ac-867d-8bbe30b5287d (sofia/user/s@192.168.30.1:61418) Running State Change CS_ROUTING
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]: send 361 bytes to udp/[192.168.30.1]:61418(local:192.168.30.15:5060) at 00:52:18.465060:    ------------------------------------------------------------------------
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    ACK sip:s@192.168.30.1:61418;line=dstghmt SIP/2.0
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    Via: SIP/2.0/UDP 192.168.30.15:5060;rport;branch=z9hG4bKmc8D3Naj64UQQ
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    Max-Forwards: 70
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    From: "03217169974" <sip:03217169974@UC100>;tag=HtNt894F5QB7c
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    To: <sip:s@192.168.30.1:61418;line=dstghmt>;tag=z9hG4bKmc8D3Naj64UQQ
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    Call-ID: a4f8aff8-349d-123b-21a3-f8a03d59cdf2
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    CSeq: 50308577 ACK
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    Content-Length: 0
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]:    ------------------------------------------------------------------------
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: cb5bd758-0e1e-47ac-867d-8bbe30b5287d Send signal sofia/user/s@192.168.30.1:61418 [BREAK]
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: cb5bd758-0e1e-47ac-867d-8bbe30b5287d Channel sofia/user/s@192.168.30.1:61418 entering state [calling][0]
Apr 12 00:52:18 UC100 user.err freeswitch[2015]: cb5bd758-0e1e-47ac-867d-8bbe30b5287d Cannot locate any authentication credentials to complete an authentication request for realm '"asterisk"'
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]: cb5bd758-0e1e-47ac-867d-8bbe30b5287d Hangup sofia/user/s@192.168.30.1:61418 [CS_ROUTING] [MANDATORY_IE_MISSING]
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: cb5bd758-0e1e-47ac-867d-8bbe30b5287d Send signal sofia/user/s@192.168.30.1:61418 [KILL]
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Originate Resulted in Error Cause: 96 [MANDATORY_IE_MISSING]
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: cb5bd758-0e1e-47ac-867d-8bbe30b5287d Send signal sofia/user/s@192.168.30.1:61418 [BREAK]
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: cb5bd758-0e1e-47ac-867d-8bbe30b5287d (sofia/user/s@192.168.30.1:61418) State ROUTING
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Cannot create outgoing channel of type [user] cause: [MANDATORY_IE_MISSING]
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: cb5bd758-0e1e-47ac-867d-8bbe30b5287d sofia/user/s@192.168.30.1:61418 SOFIA ROUTING
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: cb5bd758-0e1e-47ac-867d-8bbe30b5287d (sofia/user/s@192.168.30.1:61418) State ROUTING going to sleep
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Originate Resulted in Error Cause: 96 [MANDATORY_IE_MISSING]
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: cb5bd758-0e1e-47ac-867d-8bbe30b5287d (sofia/user/s@192.168.30.1:61418) Running State Change CS_HANGUP
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: cb5bd758-0e1e-47ac-867d-8bbe30b5287d (sofia/user/s@192.168.30.1:61418) Callstate Change DOWN -> HANGUP
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: cb5bd758-0e1e-47ac-867d-8bbe30b5287d (sofia/user/s@192.168.30.1:61418) State HANGUP
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: cb5bd758-0e1e-47ac-867d-8bbe30b5287d Channel sofia/user/s@192.168.30.1:61418 hanging up, cause: MANDATORY_IE_MISSING
Apr 12 00:52:18 UC100 user.info freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Originate Failed.  Cause: MANDATORY_IE_MISSING
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Hangup FreeTDM/1:1/  [CS_EXECUTE] [MANDATORY_IE_MISSING]
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Send signal FreeTDM/1:1/  [KILL]
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Usage for sip_ext_2000 is now 0
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Send signal FreeTDM/1:1/  [BREAK]
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 FreeTDM/1:1/  skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 FreeTDM/1:1/  ZOMBIE EXEC hash(delete/callgroup/U-2000)
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 EXECUTE FreeTDM/1:1/  hash(delete/callgroup/U-2000)
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 FreeTDM/1:1/  skip receive message [APPLICATION_EXEC] (channel is hungup already)
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 FreeTDM/1:1/  skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 FreeTDM/1:1/  destroy/unlink session from object
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 FreeTDM/1:1/  skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 (FreeTDM/1:1/ ) State EXECUTE going to sleep
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 (FreeTDM/1:1/ ) Running State Change CS_HANGUP
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 (FreeTDM/1:1/ ) Callstate Change RINGING -> HANGUP
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 (FreeTDM/1:1/ ) State HANGUP
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: [1:1] FreeTDM/1:1/  CHANNEL HANGUP ENTER
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]: [s1c1][0:0] ftdm_queue_dequeue error.
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]: [s1c1][0:0] ftdm_queue_dequeue error.
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: dsp channel is 0, span = 0, channel= 0, chan number = 2!
Apr 12 00:52:18 UC100 user.info freeswitch[2015]: dsp:0,chan;0, offhook open
Apr 12 00:52:18 UC100 user.notice syslog: PCM_BUILD        = 7620 Dec 19 2018 14:04:56
Apr 12 00:52:18 UC100 user.notice syslog: PCM_SEG_CHN      = 1
Apr 12 00:52:18 UC100 user.notice syslog: PCM_SEG_MS       = 10
Apr 12 00:52:18 UC100 user.notice syslog: PCM_SEG_SAMPLES  = 80
Apr 12 00:52:18 UC100 user.notice syslog: PCM_SEG_NUM      = 256
Apr 12 00:52:18 UC100 user.notice syslog: PCM_TX_MAX_GAP   = 3
Apr 12 00:52:18 UC100 user.notice syslog: PCM_RX_MAX_GAP   = 2
Apr 12 00:52:18 UC100 user.notice syslog: PCM_PKT_LENGTH   = 160
Apr 12 00:52:18 UC100 user.notice syslog: PCM_SYS_TICK_HZ  = 100
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: cb5bd758-0e1e-47ac-867d-8bbe30b5287d Sending CANCEL to sofia/user/s@192.168.30.1:61418
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: [s1c1][0:0] create socket ip:192.168.11.1 port:8000.
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: [s1c1][0:0] meida remote ip:192.168.11.1 remote port:8000 local ip:192.168.11.1 local port:5178.
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: cb5bd758-0e1e-47ac-867d-8bbe30b5287d sofia/user/s@192.168.30.1:61418 Standard HANGUP, cause: MANDATORY_IE_MISSING
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: [s1c1][0:0] Changed state from RING to HANGUP
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: cb5bd758-0e1e-47ac-867d-8bbe30b5287d (sofia/user/s@192.168.30.1:61418) State HANGUP going to sleep
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: cb5bd758-0e1e-47ac-867d-8bbe30b5287d (sofia/user/s@192.168.30.1:61418) State Change CS_HANGUP -> CS_REPORTING
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: cb5bd758-0e1e-47ac-867d-8bbe30b5287d Send signal sofia/user/s@192.168.30.1:61418 [BREAK]
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: [s1c1][0:0] Completed state change from RING to HANGUP in 9 ms
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: [s1c1][0:0] Executing state handler on 1:1 for HANGUP
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: slot 0 port 0 off hook.
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: cb5bd758-0e1e-47ac-867d-8bbe30b5287d (sofia/user/s@192.168.30.1:61418) Running State Change CS_REPORTING
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: cb5bd758-0e1e-47ac-867d-8bbe30b5287d (sofia/user/s@192.168.30.1:61418) State REPORTING
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: cb5bd758-0e1e-47ac-867d-8bbe30b5287d sofia/user/s@192.168.30.1:61418 Standard REPORTING, cause: MANDATORY_IE_MISSING
Apr 12 00:52:18 UC100 user.notice syslog: chan:0    RX seg dma: * first_sync, dma_chan:0, loopback_chan:0, pcm_mode:2, length:160 
Apr 12 00:52:18 UC100 user.notice syslog: chan:0    TX seg dma: * first_sync, dma_chan:0, loopback_chan:0, pcm_mode:2, length:160 
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: cb5bd758-0e1e-47ac-867d-8bbe30b5287d (sofia/user/s@192.168.30.1:61418) State REPORTING going to sleep
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: cb5bd758-0e1e-47ac-867d-8bbe30b5287d (sofia/user/s@192.168.30.1:61418) State Change CS_REPORTING -> CS_DESTROY
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: cb5bd758-0e1e-47ac-867d-8bbe30b5287d Send signal sofia/user/s@192.168.30.1:61418 [BREAK]
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: cb5bd758-0e1e-47ac-867d-8bbe30b5287d Session 30 (sofia/user/s@192.168.30.1:61418) Locked, Waiting on external entities
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]: cb5bd758-0e1e-47ac-867d-8bbe30b5287d Session 30 (sofia/user/s@192.168.30.1:61418) Ended
Apr 12 00:52:18 UC100 user.notice freeswitch[2015]: cb5bd758-0e1e-47ac-867d-8bbe30b5287d Close Channel sofia/user/s@192.168.30.1:61418 [CS_DESTROY]
Apr 12 00:52:18 UC100 user.info freeswitch[2015]: slot:0, port:0 offhook successly(write reg 5 value 1(0x1))!
Apr 12 00:52:18 UC100 user.info freeswitch[2015]: [s1c1][0:0] the channel state is not down, current state:HANGUP.
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: [s1c1][0:0] Channel is now offhook
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: [1:1] FreeTDM/1:1/  CHANNEL HANGUP EXIT
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 FreeTDM/1:1/  Standard HANGUP, cause: MANDATORY_IE_MISSING
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 (FreeTDM/1:1/ ) State HANGUP going to sleep
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 (FreeTDM/1:1/ ) State Change CS_HANGUP -> CS_REPORTING
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Send signal FreeTDM/1:1/  [BREAK]
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 (FreeTDM/1:1/ ) Running State Change CS_REPORTING
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: [0 0]recv LINE_VOLT_STAT spi packet, voltage:45, current:23!
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 (FreeTDM/1:1/ ) State REPORTING
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: cb5bd758-0e1e-47ac-867d-8bbe30b5287d (sofia/user/s@192.168.30.1:61418) Running State Change CS_DESTROY
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: (FreeTDM/1:1/ ) insert_vars= (caller_id_number,destination_number,source_chan_name,dest_chan_name,start_epoch,answer_epoch,end_epoch,duration,billsec,progressmsec,progress_mediamsec,hangup_cause,created_time,uuid,bleg
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: The current number of CDR db is [523].
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: cb5bd758-0e1e-47ac-867d-8bbe30b5287d (sofia/user/s@192.168.30.1:61418) State DESTROY
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: Writing SQL to DB: INSERT INTO cdr (caller_id_number,destination_number,source_chan_name,dest_chan_name,start_epoch,answer_epoch,end_epoch,duration,billsec,progressmsec,progress_mediamsec,hangup_cause,created_time,uui
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: cb5bd758-0e1e-47ac-867d-8bbe30b5287d sofia/user/s@192.168.30.1:61418 SOFIA DESTROY
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: cb5bd758-0e1e-47ac-867d-8bbe30b5287d sofia/user/s@192.168.30.1:61418 Standard DESTROY
Apr 12 00:52:18 UC100 user.debug freeswitch[2015]: cb5bd758-0e1e-47ac-867d-8bbe30b5287d (sofia/user/s@192.168.30.1:61418) State DESTROY going to sleep
Apr 12 00:52:19 UC100 user.debug freeswitch[2015]: (FreeTDM/1:1/ ) Last_hangup_cause = (MANDATORY_IE_MISSING)
Apr 12 00:52:19 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 FreeTDM/1:1/  Standard REPORTING, cause: MANDATORY_IE_MISSING
Apr 12 00:52:19 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 (FreeTDM/1:1/ ) State REPORTING going to sleep
Apr 12 00:52:19 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 (FreeTDM/1:1/ ) State Change CS_REPORTING -> CS_DESTROY
Apr 12 00:52:19 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Send signal FreeTDM/1:1/  [BREAK]
Apr 12 00:52:19 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Session 29 (FreeTDM/1:1/ ) Locked, Waiting on external entities
Apr 12 00:52:19 UC100 user.notice freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Session 29 (FreeTDM/1:1/ ) Ended
Apr 12 00:52:19 UC100 user.notice freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 Close Channel FreeTDM/1:1/  [CS_DESTROY]
Apr 12 00:52:19 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 (FreeTDM/1:1/ ) Running State Change CS_DESTROY
Apr 12 00:52:19 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 (FreeTDM/1:1/ ) State DESTROY
Apr 12 00:52:19 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 FreeTDM/1:1/  Standard DESTROY
Apr 12 00:52:19 UC100 user.debug freeswitch[2015]: 20707da2-685b-45f5-9286-5bdda7254e77 (FreeTDM/1:1/ ) State DESTROY going to sleep
Apr 12 00:52:19 UC100 user.debug freeswitch[2015]: slot:0 spi_chn:0 recv INTE_SRC spi packets, value:1.
Apr 12 00:52:19 UC100 user.debug freeswitch[2015]: slot 0 chn 0 poloriry !!!.
Apr 12 00:52:19 UC100 user.debug freeswitch[2015]: [0 0]recv LINE_VOLT_STAT spi packet, voltage:7, current:26!
Apr 12 00:52:19 UC100 user.debug freeswitch[2015]: [s1c1][0:0] Changed state from HANGUP to DOWN
Apr 12 00:52:19 UC100 user.debug freeswitch[2015]: [s1c1][0:0] Completed state change from HANGUP to DOWN in 18 ms
Apr 12 00:52:19 UC100 user.debug freeswitch[2015]: [s1c1][0:0] Executing state handler on 1:1 for DOWN
Apr 12 00:52:19 UC100 user.debug freeswitch[2015]: [s1c1][0:0] Ignoring SIGEVENT_STOP since user already requested hangup
Apr 12 00:52:19 UC100 user.debug freeswitch[2015]: [s1c1][0:0] Going onhook
Apr 12 00:52:19 UC100 user.debug freeswitch[2015]: slot 0 port 0 on hook.
Apr 12 00:52:19 UC100 user.notice freeswitch[2015]: recv 409 bytes from udp/[192.168.30.1]:61418(local:192.168.30.15:5060) at 00:52:19.984460:    ------------------------------------------------------------------------
Apr 12 00:52:19 UC100 user.notice freeswitch[2015]:    OPTIONS sip:192.168.30.15:5060 SIP/2.0
Apr 12 00:52:19 UC100 user.notice freeswitch[2015]:    Via: SIP/2.0/UDP 192.168.30.1:61418;rport;branch=z9hG4bKPj2fea2267-e95f-439d-8819-7af4cc6b078c
Apr 12 00:52:19 UC100 user.notice freeswitch[2015]:    From: <sip:2000@192.168.30.1:61418>;tag=accc3708-e2a9-462a-9961-a0c516a8b795
Apr 12 00:52:19 UC100 user.notice freeswitch[2015]:    To: <sip:192.168.30.15>
Apr 12 00:52:19 UC100 user.notice freeswitch[2015]:    Contact: <sip:2000@192.168.30.1:61418>
Apr 12 00:52:19 UC100 user.notice freeswitch[2015]:    Call-ID: 1115c321-8cf9-4f71-b401-e4c0aa1e50b6
Apr 12 00:52:19 UC100 user.notice freeswitch[2015]:    CSeq: 41543 OPTIONS
Apr 12 00:52:19 UC100 user.notice freeswitch[2015]:    Max-Forwards: 70
Apr 12 00:52:19 UC100 user.notice freeswitch[2015]:    User-Agent: VitalPBX
Apr 12 00:52:19 UC100 user.notice freeswitch[2015]:    Content-Length:  0
Apr 12 00:52:19 UC100 user.notice freeswitch[2015]:    ------------------------------------------------------------------------
Apr 12 00:52:19 UC100 user.notice freeswitch[2015]: send 757 bytes to udp/[192.168.30.1]:61418(local:192.168.30.15:5060) at 00:52:19.996520:    ------------------------------------------------------------------------
Apr 12 00:52:19 UC100 user.notice freeswitch[2015]:    SIP/2.0 200 OK
Apr 12 00:52:19 UC100 user.notice freeswitch[2015]:    Via: SIP/2.0/UDP 192.168.30.1:61418;rport=61418;branch=z9hG4bKPj2fea2267-e95f-439d-8819-7af4cc6b078c
Apr 12 00:52:20 UC100 user.notice freeswitch[2015]:    From: <sip:2000@192.168.30.1:61418>;tag=accc3708-e2a9-462a-9961-a0c516a8b795
Apr 12 00:52:20 UC100 user.notice freeswitch[2015]:    To: <sip:192.168.30.15>;tag=j3eKa5NK201Sr
Apr 12 00:52:20 UC100 user.notice freeswitch[2015]:    Call-ID: 1115c321-8cf9-4f71-b401-e4c0aa1e50b6
Apr 12 00:52:20 UC100 user.notice freeswitch[2015]:    CSeq: 41543 OPTIONS
Apr 12 00:52:20 UC100 user.notice freeswitch[2015]:    Contact: <sip:192.168.30.15>
Apr 12 00:52:20 UC100 user.notice freeswitch[2015]:    User-Agent: UC100/2.53.4.16 2019-01-17 20:11:39 CST +0800
Apr 12 00:52:20 UC100 user.notice freeswitch[2015]:    Accept: application/sdp
Apr 12 00:52:20 UC100 user.notice freeswitch[2015]:    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, SUBSCRIBE, PUBLISH
Apr 12 00:52:20 UC100 user.notice freeswitch[2015]:    Supported: timer, path, replaces
Apr 12 00:52:20 UC100 user.notice freeswitch[2015]:    Allow-Events: talk, hold, conference, dialog, presence, as-feature-event, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Apr 12 00:52:20 UC100 user.notice freeswitch[2015]:    Content-Length: 0
Apr 12 00:52:20 UC100 user.notice freeswitch[2015]:    ------------------------------------------------------------------------
Apr 12 00:52:20 UC100 user.info freeswitch[2015]: slot:0, port:0 onhook successly(write reg 5 value 0(0))!
Apr 12 00:52:20 UC100 user.notice freeswitch[2015]: [s1c1][0:0] ftdm_queue_dequeue error.
Apr 12 00:52:20 UC100 user.notice freeswitch[2015]: [s1c1][0:0] ftdm_queue_dequeue error.
Apr 12 00:52:20 UC100 user.debug freeswitch[2015]: [s1c1][0:0] close socket(6).
Apr 12 00:52:20 UC100 user.debug freeswitch[2015]: [s1c1][0:0] DTMF debug is already disabled
Apr 12 00:52:20 UC100 user.debug freeswitch[2015]: [s1c1][0:0] No need to disable input dump
Apr 12 00:52:20 UC100 user.debug freeswitch[2015]: [s1c1][0:0] No need to disable output dump
Apr 12 00:52:20 UC100 user.debug freeswitch[2015]: [s1c1][0:0] channel done
Apr 12 00:52:20 UC100 user.debug freeswitch[2015]: [s1c1][0:0] ANALOG CHANNEL 1:1 thread ended.
Apr 12 00:52:20 UC100 user.debug freeswitch[2015]: [0 0]recv LINE_VOLT_STAT spi packet, voltage:47, current:0!