

Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.012[app:dbg]Reloading config...
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.030[app:dbg]Error: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.035[app:dbg]Error: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.035[app:dbg]Getting option 'authentication' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.036[app:dbg]Founded value: 1
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.036[app:dbg]Getting option 'enablesip' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.037[app:dbg]Founded value: 1
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.037[app:dbg]Getting option 'registration' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.037[app:dbg]Founded value: 1
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.038[app:dbg]Getting option 'proxyip' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.038[app:dbg]Founded value: 192.168.254.253:5060
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.039[app:dbg]Getting option 'registrarip' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.039[app:dbg]Founded value: 192.168.254.253:5060
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.040[app:dbg]Getting option 'registration_rsrv1' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.040[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.040[app:dbg]Getting option 'proxyip_rsrv1' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.040[app:dbg]Getting option 'registrarip_rsrv1' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.040[app:dbg]Getting option 'registration_rsrv2' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.040[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.040[app:dbg]Getting option 'proxyip_rsrv2' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.041[app:dbg]Getting option 'registrarip_rsrv2' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.041[app:dbg]Getting option 'registration_rsrv3' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.041[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.041[app:dbg]Getting option 'proxyip_rsrv3' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.041[app:dbg]Getting option 'registrarip_rsrv3' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.041[app:dbg]Getting option 'registration_rsrv4' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.041[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.041[app:dbg]Getting option 'proxyip_rsrv4' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.041[app:dbg]Getting option 'registrarip_rsrv4' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.041[app:dbg]Getting option 'rsrv_keepalive_time' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.042[app:dbg]Founded value: 35
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.042[app:dbg]Getting option 'rsrv_check_method' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.042[app:dbg]Founded value: invite
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.042[app:dbg]Getting option 'rsrv_mode' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.042[app:dbg]Founded value: homing
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.042[app:dbg]Getting option 'outbound' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.042[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.042[app:dbg]Getting option 'dial_timeout' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.042[app:dbg]Founded value: 30
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.042[app:dbg]Getting option 'ringback' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.043[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.043[app:dbg]Getting option 'early_media' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.043[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.043[app:dbg]Getting option 'domain_to_reg' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.043[app:dbg]Founded value: 1
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.043[app:dbg]Getting option 'display_to_reg' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.043[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.043[app:dbg]Getting option 'domain' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.043[app:dbg]Founded value: tagnet.tagnet.cc
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.043[app:dbg]Getting option 'expires' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.044[app:dbg]Founded value: 300
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.044[app:dbg]Getting option 'username' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.044[app:dbg]Getting option 'password' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.044[app:dbg]Getting option 'cw_ring' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.044[app:dbg]Getting option 'reduce_sdp_media_count' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.044[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.044[app:dbg]Getting option 'rri' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.044[app:dbg]Founded value: 60
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.044[app:dbg]Getting option 'option_100rel' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.045[app:dbg]Founded value: supported
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.045[app:dbg]Getting option 'keep_alive_mode' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.045[app:dbg]Founded value: off
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.045[app:dbg]Getting option 'keep_alive_interval' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.045[app:dbg]Getting option 'conference_mode' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.045[app:dbg]Founded value: local
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.045[app:dbg]Getting option 'conference_server' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.045[app:dbg]Founded value: conf
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.045[app:dbg]Getting option 'ims_mode' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.045[app:dbg]Founded value: off
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.046[app:dbg]Getting option 'xcap_calltransfer_name' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.046[app:dbg]Founded value: explicit-call-transfer
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.046[app:dbg]Getting option 'use_alertinfo_header' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.046[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.046[app:dbg]Getting option 'ruri_check_user_only' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.046[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.046[app:dbg]Getting option 'xcap_callhold_name' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.046[app:dbg]Founded value: call-hold
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.046[app:dbg]Getting option 'xcap_cw_name' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.046[app:dbg]Founded value: call-waiting
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.047[app:dbg]Getting option 'xcap_conference_name' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.047[app:dbg]Founded value: three-party-conference
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.047[app:dbg]Getting option 'xcap_hotline_name' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.047[app:dbg]Founded value: hot-line-service
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.047[app:dbg]Getting option 'timer_enable' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.047[app:dbg]Founded value: 1
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.047[app:dbg]Getting option 'timer_minse' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.047[app:dbg]Founded value: 120
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.047[app:dbg]Getting option 'timer_session_expires' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.047[app:dbg]Founded value: 1800
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.048[app:dbg]Getting option 'g711u' in section 'codecs'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.048[app:dbg]Founded value: -1
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.048[app:dbg]Getting option 'g711a' in section 'codecs'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.048[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.048[app:dbg]Getting option 'g723' in section 'codecs'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.048[app:dbg]Founded value: -1
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.048[app:dbg]Getting option 'g729x' in section 'codecs'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.048[app:dbg]Founded value: -1
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.048[app:dbg]Getting option 'g729a' in section 'codecs'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.048[app:dbg]Founded value: -1
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.049[app:dbg]Getting option 'g729b' in section 'codecs'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.049[app:dbg]Founded value: -1
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.049[app:dbg]Getting option 'pt_auto_adjustment' in section 'codecs'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.049[app:dbg]Getting option 'g711pte' in section 'codecs'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.049[app:dbg]Founded value: 20
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.049[app:dbg]Getting option 'dtmftransfer' in section 'codecs'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.049[app:dbg]Founded value: rfc2833
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.049[app:dbg]Getting option 'flashtransfer' in section 'codecs'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.049[app:dbg]Founded value: rfc2833
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.049[app:dbg]Getting option 'silence_sensitivity' in section 'codecs'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.070[app:dbg]Getting option 'faxdirection' in section 'codecs'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.070[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.070[app:dbg]Getting option 'faxtransfer1' in section 'codecs'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.070[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.070[app:dbg]Getting option 'faxtransfer2' in section 'codecs'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.070[app:dbg]Founded value: 3
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.070[app:dbg]Getting option 'faxtransfer3' in section 'codecs'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.071[app:dbg]Founded value: 3
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.071[app:dbg]Getting option 'enable_in_t38' in section 'codecs'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.071[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.071[app:dbg]Getting option 'modem' in section 'codecs'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.071[app:dbg]Founded value: 2
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.071[app:dbg]Getting option 'payload' in section 'codecs'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.071[app:dbg]Founded value: 101
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.071[app:dbg]Getting option 'silencedetector' in section 'codecs'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.071[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.071[app:dbg]Getting option 'echocanceler' in section 'codecs'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.071[app:dbg]Founded value: 1
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.072[app:dbg]Getting option 'rtcp' in section 'codecs'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.072[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.072[app:dbg]Getting option 'rtcp_timer' in section 'codecs'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.072[app:dbg]Getting option 'rtcp_count' in section 'codecs'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.072[app:dbg]Getting option 't38maxdatagram' in section 'codecs'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.072[app:dbg]Getting option 't38bitrate' in section 'codecs'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.072[app:dbg]Getting option 't38udpfec' in section 'codecs'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.072[app:dbg]Getting option 'flash_mime' in section 'codecs'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.072[app:dbg]Founded value: hookflash
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.072[app:dbg]Getting option 'dtmf_mime' in section 'codecs'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.073[app:dbg]Founded value: dtmf-relay
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.073[app:dbg]Getting option 'nse_payload' in section 'codecs'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.073[app:dbg]Getting option 'rfc3264_pt_common' in section 'codecs'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.073[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.073[app:dbg]Error: 3
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.073[app:dbg]Error: 3
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.074[app:dbg]Error: 3
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.074[app:dbg]Error: 3
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.074[app:dbg]Error: 3
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.074[app:dbg]Error: 3
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.075[app:dbg]Error: 3
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.100[app:dbg]Error: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.101[app:dbg]Getting regex 0 expression string
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.101[app:dbg]Getting option 'expression' in section 'regexp'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.101[app:dbg]Founded value: S3, L30 (1xx S0 | 5xx S0 | [2349]xxxxx S0 | xxx. )
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.101[app:dbg]end parsing
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.101[app:dbg]routes 4, common L/S <30>/<3>
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.101[app:dbg]0x326200/0x258800:<XXX.> : <> L=<> S=<> 
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.101[app:dbg]0x258800/0x324800:<[2349]XXXXX> : <> L=<> S=<0> 
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.101[app:dbg]0x324800/0x325a00:<5XX> : <> L=<> S=<0> 
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.102[app:dbg]0x325a00/   (nil):<1XX> : <> L=<> S=<0> 
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.102[app:dbg]unload regexpr dialplan
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.102[app:dbg]cur route 3:
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.102[app:dbg]got timers: 30/3
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.102[app:dbg]prefix is: XXX.
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.102[app:dbg]  subs count 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.102[app:dbg]cur route 2:
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.102[app:dbg]got timers: 30/0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.102[app:dbg]prefix is: [2349]XXXXX
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.102[app:dbg]  subs count 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.103[app:dbg]0: [
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.103[app:dbg]cur route 1:
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.103[app:dbg]got timers: 30/0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.103[app:dbg]prefix is: 5XX
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.103[app:dbg]  subs count 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.103[app:dbg]cur route 0:
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.103[app:dbg]got timers: 30/0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.103[app:dbg]prefix is: 1XX
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.103[app:dbg]  subs count 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.103[app:dbg]0: L 30, S 0 ||0| psi 0:
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.104[app:dbg]#0110: 0x0002 / 00 00 00 00:  {  0,  0}, [  ,   ,   :0]
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.104[app:dbg]#0111: 0x03FF / 00 00 00 00:  {  0,  0}, [  ,   ,   :0]
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.104[app:dbg]#0112: 0x03FF / 00 00 00 00:  {  0,  0}, [  ,   ,   :0]
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.104[app:dbg]1: L 30, S 0 ||0| psi 0:
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.104[app:dbg]#0110: 0x0020 / 00 00 00 00:  {  0,  0}, [  ,   ,   :0]
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.104[app:dbg]#0111: 0x03FF / 00 00 00 00:  {  0,  0}, [  ,   ,   :0]
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.104[app:dbg]#0112: 0x03FF / 00 00 00 00:  {  0,  0}, [  ,   ,   :0]
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.105[app:dbg]2: L 30, S 0 ||0| psi 0:
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.105[app:dbg]#0110: 0x021C / 00 00 00 00:  {  0,  0}, [  ,   ,   :0]
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.105[app:dbg]#0111: 0x03FF / 00 00 00 00:  {  0,  0}, [  ,   ,   :0]
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.105[app:dbg]#0112: 0x03FF / 00 00 00 00:  {  0,  0}, [  ,   ,   :0]
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.105[app:dbg]#0113: 0x03FF / 00 00 00 00:  {  0,  0}, [  ,   ,   :0]
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.105[app:dbg]#0114: 0x03FF / 00 00 00 00:  {  0,  0}, [  ,   ,   :0]
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.105[app:dbg]#0115: 0x03FF / 00 00 00 00:  {  0,  0}, [  ,   ,   :0]
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.105[app:dbg]3: L 30, S 3 ||0| psi 0:
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.106[app:dbg]#0110: 0x03FF / 00 00 00 00:  {  0,  0}, [  ,   ,   :0]
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.106[app:dbg]#0111: 0x03FF / 00 00 00 00:  {  0,  0}, [  ,   ,   :0]
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.106[app:dbg]#0112: 0x03FF / 08 00 00 FF: r{  0,255}, [  ,   ,   :0]
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.106[app:dbg]regexp0 load ok
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.106[app:dbg]Error: 3
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.106[app:dbg]Error: 3
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.107[app:dbg]Error: 3
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.107[app:dbg]Error: 3
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.107[app:dbg]Error: 3
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.107[app:dbg]Error: 3
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.108[app:dbg]Error: 3
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.109[app:dbg]Reading common sip conf...
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.109[app:dbg]Getting option 'stun_server' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.109[app:dbg]Getting option 'public_ip' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.109[app:dbg]No public IP
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.109[app:dbg]IP from net config 192.168.3.5
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.109[app:dbg]IP from net config 192.168.3.5
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.109[app:dbg]IP from net config 192.168.3.5
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.109[app:dbg]IP from net config 192.168.3.5
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.130[app:dbg]IP from net config 192.168.3.5
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.130[app:dbg]IP from net config 192.168.3.5
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.130[app:dbg]IP from net config 192.168.3.5
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.130[app:dbg]IP from net config 192.168.3.5
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.130[app:dbg]Getting option 'stun_enable' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.130[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.130[app:dbg]Getting option 'stun_interval' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.131[app:dbg]Getting option 'invite_init_t' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.131[app:dbg]Getting option 'invite_total_t' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.131[app:dbg]Getting option 'not_use_naptr' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.131[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.131[app:dbg]Getting option 'not_use_srv' in section 'sip'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.131[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.131[app:dbg]Reading general conf...
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.131[app:dbg]Getting option 'use_uni' in section 'general'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.131[app:dbg]Getting option 'unit_prefix' in section 'general'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.131[app:dbg]Getting option 'device_name' in section 'general'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.132[app:dbg]Getting option 'voip_history_size' in section 'general'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.132[app:dbg]Founded value: 100
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.132[app:dbg]Getting option 'use_fxs_profile' in section 'general'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.132[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.132[app:dbg]Reading qos conf...
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.132[app:dbg]Getting option 'tcpportmin' in section 'qos'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.132[app:dbg]Getting option 'tcpportmax' in section 'qos'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.132[app:dbg]Getting option 'udpportmin' in section 'qos'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.132[app:dbg]Founded value: 23000
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.132[app:dbg]Getting option 'udpportmax' in section 'qos'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.132[app:dbg]Founded value: 26000
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.133[app:dbg]Getting option 'rtph323min' in section 'qos'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.133[app:dbg]Getting option 'rtph323max' in section 'qos'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.133[app:dbg]Getting option 'rtp_tos' in section 'qos'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.133[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.133[app:dbg]Getting option 'sig_tos' in section 'qos'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.133[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.133[app:dbg]RTP ports: 23000...26000
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.133[app:dbg]Reading fxs1 conf to 2...
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.133[app:dbg]Getting option 'phone' in section 'fxs1'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.134[app:dbg]Founded value: 501
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.134[app:dbg]Getting option 'representative_number' in section 'fxs1'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.134[app:dbg]Getting option 'alt_number' in section 'fxs1'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.134[app:dbg]Getting option 'use_altnumber_as_private' in section 'fxs1'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.134[app:dbg]Getting option 'use_alt_number' in section 'fxs1'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.134[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.134[app:dbg]Getting option 'username' in section 'fxs1'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.134[app:dbg]Founded value: 501
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.134[app:dbg]Getting option 'auth_name' in section 'fxs1'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.134[app:dbg]Founded value: 501
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.135[app:dbg]Getting option 'auth_pass_encrypted' in section 'fxs1'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.135[app:dbg]Founded value: 406634305873446C
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.135[app:dbg]Getting option 'category' in section 'fxs1'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.135[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.135[app:dbg]Getting option 'cpc_rus' in section 'fxs1'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.135[app:dbg]Getting option 'payphone' in section 'fxs1'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.135[app:dbg]Founded value: off
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.135[app:dbg]Getting option 'calltransfer' in section 'fxs1'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.135[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.136[app:dbg]Getting option 'callwaiting' in section 'fxs1'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.136[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.136[app:dbg]Getting option 'hotline' in section 'fxs1'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.136[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.136[app:dbg]Getting option 'hottimeout' in section 'fxs1'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.136[app:dbg]Getting option 'hotnumber' in section 'fxs1'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.136[app:dbg]Getting option 'directnumber' in section 'fxs1'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.136[app:dbg]Getting option 'ct_unconditional' in section 'fxs1'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.136[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.136[app:dbg]Getting option 'cfu_number' in section 'fxs1'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.137[app:dbg]Getting option 'ct_busy' in section 'fxs1'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.137[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.137[app:dbg]Getting option 'cfb_number' in section 'fxs1'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.137[app:dbg]Getting option 'ct_noanswer' in section 'fxs1'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.137[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.137[app:dbg]Getting option 'ct_timeout' in section 'fxs1'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.137[app:dbg]Getting option 'cfna_number' in section 'fxs1'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.137[app:dbg]Getting option 'clir' in section 'fxs1'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.137[app:dbg]Getting option 'stop_dial' in section 'fxs1'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.137[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.138[app:dbg]Getting option 'disabled' in section 'fxs1'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.138[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.138[app:dbg]uci_load_fxs: disabled = 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.138[app:dbg]Getting option 'pickupgroup' in section 'fxs1'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.138[app:dbg]Getting option 'pickup_enable' in section 'fxs1'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.138[app:dbg]Getting option 'dnd_enable' in section 'fxs1'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.138[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.138[app:dbg]Getting option 'sip_profile_id' in section 'fxs1'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.138[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.138[app:dbg]Getting option 'fxs_profile_id' in section 'fxs1'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.139[app:dbg]Getting option 'sipport' in section 'fxs1'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.139[app:dbg]Founded value: 5060
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.139[app:dbg]Getting option 'minflash' in section 'fxs1'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.139[app:dbg]Founded value: 200
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.139[app:dbg]Getting option 'minpulse' in section 'fxs1'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.140[app:dbg]Founded value: 100
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.160[app:dbg]Getting option 'interdigit' in section 'fxs1'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.160[app:dbg]Founded value: 200
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.160[app:dbg]Getting option 'minonhooktime' in section 'fxs1'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.160[app:dbg]Founded value: 500
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.161[app:dbg]Getting option 'gainr' in section 'fxs1'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.161[app:dbg]Founded value: -130
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.161[app:dbg]Getting option 'gaint' in section 'fxs1'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.161[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.161[app:dbg]Getting option 'payphone' in section 'fxs1'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.161[app:dbg]Founded value: off
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.161[app:dbg]Getting option 'caller_id' in section 'fxs1'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.161[app:dbg]Founded value: bell
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.161[app:dbg]Getting option 'hangup_timeout' in section 'fxs1'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.161[app:dbg]Getting option 'rb_timeout' in section 'fxs1'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.162[app:dbg]Getting option 'busy_timeout' in section 'fxs1'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.162[app:dbg]Reading fxs2 conf to 3...
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.162[app:dbg]Getting option 'phone' in section 'fxs2'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.162[app:dbg]Founded value: 502
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.162[app:dbg]Getting option 'representative_number' in section 'fxs2'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.162[app:dbg]Getting option 'alt_number' in section 'fxs2'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.162[app:dbg]Getting option 'use_altnumber_as_private' in section 'fxs2'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.162[app:dbg]Getting option 'use_alt_number' in section 'fxs2'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.162[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.163[app:dbg]Getting option 'username' in section 'fxs2'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.163[app:dbg]Founded value: 502
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.163[app:dbg]Getting option 'auth_name' in section 'fxs2'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.163[app:dbg]Founded value: 502
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.163[app:dbg]Getting option 'auth_pass_encrypted' in section 'fxs2'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.163[app:dbg]Founded value: 72305C4B6331603F
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.163[app:dbg]Getting option 'category' in section 'fxs2'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.163[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.163[app:dbg]Getting option 'cpc_rus' in section 'fxs2'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.164[app:dbg]Getting option 'payphone' in section 'fxs2'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.164[app:dbg]Founded value: off
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.164[app:dbg]Getting option 'calltransfer' in section 'fxs2'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.164[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.164[app:dbg]Getting option 'callwaiting' in section 'fxs2'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.164[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.164[app:dbg]Getting option 'hotline' in section 'fxs2'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.164[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.164[app:dbg]Getting option 'hottimeout' in section 'fxs2'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.164[app:dbg]Getting option 'hotnumber' in section 'fxs2'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.165[app:dbg]Getting option 'directnumber' in section 'fxs2'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.165[app:dbg]Getting option 'ct_unconditional' in section 'fxs2'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.165[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.165[app:dbg]Getting option 'cfu_number' in section 'fxs2'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.165[app:dbg]Getting option 'ct_busy' in section 'fxs2'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.165[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.165[app:dbg]Getting option 'cfb_number' in section 'fxs2'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.165[app:dbg]Getting option 'ct_noanswer' in section 'fxs2'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.165[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.165[app:dbg]Getting option 'ct_timeout' in section 'fxs2'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.166[app:dbg]Getting option 'cfna_number' in section 'fxs2'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.166[app:dbg]Getting option 'clir' in section 'fxs2'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.166[app:dbg]Getting option 'stop_dial' in section 'fxs2'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.166[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.166[app:dbg]Getting option 'disabled' in section 'fxs2'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.166[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.166[app:dbg]uci_load_fxs: disabled = 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.166[app:dbg]Getting option 'pickupgroup' in section 'fxs2'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.166[app:dbg]Getting option 'pickup_enable' in section 'fxs2'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.166[app:dbg]Getting option 'dnd_enable' in section 'fxs2'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.167[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.167[app:dbg]Getting option 'sip_profile_id' in section 'fxs2'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.167[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.167[app:dbg]Getting option 'fxs_profile_id' in section 'fxs2'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.167[app:dbg]Getting option 'sipport' in section 'fxs2'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.167[app:dbg]Founded value: 5060
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.167[app:dbg]Getting option 'minflash' in section 'fxs2'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.167[app:dbg]Founded value: 200
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.167[app:dbg]Getting option 'minpulse' in section 'fxs2'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.168[app:dbg]Founded value: 100
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.168[app:dbg]Getting option 'interdigit' in section 'fxs2'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.168[app:dbg]Founded value: 200
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.168[app:dbg]Getting option 'minonhooktime' in section 'fxs2'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.168[app:dbg]Founded value: 500
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.168[app:dbg]Getting option 'gainr' in section 'fxs2'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.168[app:dbg]Founded value: -130
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.168[app:dbg]Getting option 'gaint' in section 'fxs2'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.168[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.168[app:dbg]Getting option 'payphone' in section 'fxs2'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.169[app:dbg]Founded value: off
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.169[app:dbg]Getting option 'caller_id' in section 'fxs2'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.169[app:dbg]Founded value: bell
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.169[app:dbg]Getting option 'hangup_timeout' in section 'fxs2'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.169[app:dbg]Getting option 'rb_timeout' in section 'fxs2'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.169[app:dbg]Getting option 'busy_timeout' in section 'fxs2'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.169[app:dbg]Reading fxs3 conf to 0...
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.169[app:dbg]Getting option 'phone' in section 'fxs3'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.169[app:dbg]Founded value: 504
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.170[app:dbg]Getting option 'representative_number' in section 'fxs3'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.190[app:dbg]Getting option 'alt_number' in section 'fxs3'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.190[app:dbg]Getting option 'use_altnumber_as_private' in section 'fxs3'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.190[app:dbg]Getting option 'use_alt_number' in section 'fxs3'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.190[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.191[app:dbg]Getting option 'username' in section 'fxs3'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.191[app:dbg]Founded value: 504
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.191[app:dbg]Getting option 'auth_name' in section 'fxs3'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.191[app:dbg]Founded value: 504
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.191[app:dbg]Getting option 'auth_pass_encrypted' in section 'fxs3'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.191[app:dbg]Founded value: 577C3335477F4766
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.191[app:dbg]Getting option 'category' in section 'fxs3'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.191[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.191[app:dbg]Getting option 'cpc_rus' in section 'fxs3'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.192[app:dbg]Getting option 'payphone' in section 'fxs3'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.192[app:dbg]Founded value: off
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.192[app:dbg]Getting option 'calltransfer' in section 'fxs3'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.192[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.192[app:dbg]Getting option 'callwaiting' in section 'fxs3'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.192[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.192[app:dbg]Getting option 'hotline' in section 'fxs3'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.192[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.192[app:dbg]Getting option 'hottimeout' in section 'fxs3'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.192[app:dbg]Getting option 'hotnumber' in section 'fxs3'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.193[app:dbg]Getting option 'directnumber' in section 'fxs3'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.193[app:dbg]Getting option 'ct_unconditional' in section 'fxs3'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.193[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.193[app:dbg]Getting option 'cfu_number' in section 'fxs3'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.193[app:dbg]Getting option 'ct_busy' in section 'fxs3'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.193[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.193[app:dbg]Getting option 'cfb_number' in section 'fxs3'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.193[app:dbg]Getting option 'ct_noanswer' in section 'fxs3'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.193[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.193[app:dbg]Getting option 'ct_timeout' in section 'fxs3'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.194[app:dbg]Getting option 'cfna_number' in section 'fxs3'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.194[app:dbg]Getting option 'clir' in section 'fxs3'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.194[app:dbg]Getting option 'stop_dial' in section 'fxs3'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.194[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.194[app:dbg]Getting option 'disabled' in section 'fxs3'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.194[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.194[app:dbg]uci_load_fxs: disabled = 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.194[app:dbg]Getting option 'pickupgroup' in section 'fxs3'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.194[app:dbg]Getting option 'pickup_enable' in section 'fxs3'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.194[app:dbg]Getting option 'dnd_enable' in section 'fxs3'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.195[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.195[app:dbg]Getting option 'sip_profile_id' in section 'fxs3'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.195[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.195[app:dbg]Getting option 'fxs_profile_id' in section 'fxs3'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.195[app:dbg]Getting option 'sipport' in section 'fxs3'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.195[app:dbg]Founded value: 5060
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.195[app:dbg]Getting option 'minflash' in section 'fxs3'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.195[app:dbg]Founded value: 200
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.195[app:dbg]Getting option 'minpulse' in section 'fxs3'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.196[app:dbg]Founded value: 100
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.196[app:dbg]Getting option 'interdigit' in section 'fxs3'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.196[app:dbg]Founded value: 200
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.196[app:dbg]Getting option 'minonhooktime' in section 'fxs3'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.196[app:dbg]Founded value: 500
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.196[app:dbg]Getting option 'gainr' in section 'fxs3'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.196[app:dbg]Founded value: -130
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.196[app:dbg]Getting option 'gaint' in section 'fxs3'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.196[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.196[app:dbg]Getting option 'payphone' in section 'fxs3'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.197[app:dbg]Founded value: off
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.197[app:dbg]Getting option 'caller_id' in section 'fxs3'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.197[app:dbg]Founded value: bell
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.197[app:dbg]Getting option 'hangup_timeout' in section 'fxs3'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.197[app:dbg]Getting option 'rb_timeout' in section 'fxs3'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.197[app:dbg]Getting option 'busy_timeout' in section 'fxs3'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.197[app:dbg]Reading fxs4 conf to 1...
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.197[app:dbg]Getting option 'phone' in section 'fxs4'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.197[app:dbg]Founded value: 599
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.198[app:dbg]Getting option 'representative_number' in section 'fxs4'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.198[app:dbg]Getting option 'alt_number' in section 'fxs4'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.198[app:dbg]Getting option 'use_altnumber_as_private' in section 'fxs4'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.198[app:dbg]Getting option 'use_alt_number' in section 'fxs4'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.198[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.198[app:dbg]Getting option 'username' in section 'fxs4'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.198[app:dbg]Founded value: 599
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.198[app:dbg]Getting option 'auth_name' in section 'fxs4'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.198[app:dbg]Founded value: 599
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.198[app:dbg]Getting option 'auth_pass_encrypted' in section 'fxs4'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.199[app:dbg]Founded value: 59703635577D597E
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.199[app:dbg]Getting option 'category' in section 'fxs4'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.199[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.199[app:dbg]Getting option 'cpc_rus' in section 'fxs4'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.199[app:dbg]Getting option 'payphone' in section 'fxs4'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.199[app:dbg]Founded value: off
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.199[app:dbg]Getting option 'calltransfer' in section 'fxs4'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.199[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.199[app:dbg]Getting option 'callwaiting' in section 'fxs4'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.200[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.220[app:dbg]Getting option 'hotline' in section 'fxs4'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.220[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.220[app:dbg]Getting option 'hottimeout' in section 'fxs4'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.220[app:dbg]Getting option 'hotnumber' in section 'fxs4'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.220[app:dbg]Getting option 'directnumber' in section 'fxs4'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.220[app:dbg]Getting option 'ct_unconditional' in section 'fxs4'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.221[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.221[app:dbg]Getting option 'cfu_number' in section 'fxs4'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.221[app:dbg]Getting option 'ct_busy' in section 'fxs4'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.221[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.221[app:dbg]Getting option 'cfb_number' in section 'fxs4'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.221[app:dbg]Getting option 'ct_noanswer' in section 'fxs4'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.221[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.221[app:dbg]Getting option 'ct_timeout' in section 'fxs4'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.221[app:dbg]Getting option 'cfna_number' in section 'fxs4'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.221[app:dbg]Getting option 'clir' in section 'fxs4'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.222[app:dbg]Getting option 'stop_dial' in section 'fxs4'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.222[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.222[app:dbg]Getting option 'disabled' in section 'fxs4'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.222[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.222[app:dbg]uci_load_fxs: disabled = 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.222[app:dbg]Getting option 'pickupgroup' in section 'fxs4'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.222[app:dbg]Getting option 'pickup_enable' in section 'fxs4'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.222[app:dbg]Getting option 'dnd_enable' in section 'fxs4'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.222[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.222[app:dbg]Getting option 'sip_profile_id' in section 'fxs4'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.223[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.223[app:dbg]Getting option 'fxs_profile_id' in section 'fxs4'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.223[app:dbg]Getting option 'sipport' in section 'fxs4'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.223[app:dbg]Founded value: 5060
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.223[app:dbg]Getting option 'minflash' in section 'fxs4'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.223[app:dbg]Founded value: 200
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.223[app:dbg]Getting option 'minpulse' in section 'fxs4'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.223[app:dbg]Founded value: 100
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.223[app:dbg]Getting option 'interdigit' in section 'fxs4'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.224[app:dbg]Founded value: 200
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.224[app:dbg]Getting option 'minonhooktime' in section 'fxs4'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.224[app:dbg]Founded value: 500
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.224[app:dbg]Getting option 'gainr' in section 'fxs4'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.224[app:dbg]Founded value: -130
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.224[app:dbg]Getting option 'gaint' in section 'fxs4'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.224[app:dbg]Founded value: 0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.224[app:dbg]Getting option 'payphone' in section 'fxs4'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.224[app:dbg]Founded value: off
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.224[app:dbg]Getting option 'caller_id' in section 'fxs4'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.224[app:dbg]Founded value: bell
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.225[app:dbg]Getting option 'hangup_timeout' in section 'fxs4'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.225[app:dbg]Getting option 'rb_timeout' in section 'fxs4'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.225[app:dbg]Getting option 'busy_timeout' in section 'fxs4'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.225[app:dbg]Getting option 'cfu_prefix' in section 'supp_services'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.225[app:dbg]Getting option 'cfb_prefix' in section 'supp_services'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.225[app:dbg]Getting option 'cfna_prefix' in section 'supp_services'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.225[app:dbg]Getting option 'call_pickup_prefix' in section 'supp_services'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.225[app:dbg]Getting option 'hot_number_prefix' in section 'supp_services'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.226[app:dbg]Getting option 'callwaiting_prefix' in section 'supp_services'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.226[app:dbg]Getting option 'dnd_prefix' in section 'supp_services'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.253[app:dbg]Getting option 'network_mode' in section 'common_settings'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.253[app:dbg]Founded value: basic
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.253[app:dbg]Getting option 'connection' in section 'basic'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.253[app:dbg]Founded value: wired
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.254[app:dbg]Getting option 'bridge_mode' in section 'basic'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.254[app:dbg]Founded value: 1
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.254[app:dbg]Getting option 'wan_protocol' in section 'basic'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.254[app:dbg]Founded value: Static
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.254[app:dbg]net_config_init: Signalling interface br0
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.254[app:dbg]net: init: local IP: 192.168.3.5
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.254[app:dbg]net: init: local MAC: a8:f9:4b:03:8b:47
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.255[app:dbg]Signalling IP is 192.168.3.5
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.255[app:dbg]net: init: local IP: 192.168.3.5
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.255[app:dbg]net: init: local MAC: a8:f9:4b:03:8b:47
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.255[app:dbg]RTP IP is 192.168.3.5
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.284[app:dbg]Getting option 'reserved_ip' in section 'qos'
Jan  1 06:02:34 192.168.3.5 syslog: 06:02:34.284[app:dbg]Founded value: 192.168.253.1
Jan  1 06:03:05 192.168.3.5 syslog: 06:03:05.940[app:dbg]got nua_r_register : 200(Ok)
Jan  1 06:03:05 192.168.3.5 syslog: 06:03:05.940[app:dbg]sip: endpoint 2: REGISTER: 200 Ok
Jan  1 06:03:05 192.168.3.5 syslog: 06:03:05.940[app:dbg]Port 2: user port 0, old state hangup, new state 
Jan  1 06:03:05 192.168.3.5 syslog: 06:03:05.940[app:dbg]sip: endpoint 2: successfully registered
Jan  1 06:03:08 192.168.3.5 syslog: 06:03:08.957[app:dbg]got nua_r_register : 200(Ok)
Jan  1 06:03:08 192.168.3.5 syslog: 06:03:08.957[app:dbg]sip: endpoint 0: REGISTER: 200 Ok
Jan  1 06:03:08 192.168.3.5 syslog: 06:03:08.957[app:dbg]Port 0: user port 2, old state hangup, new state 
Jan  1 06:03:08 192.168.3.5 syslog: 06:03:08.958[app:dbg]sip: endpoint 0: successfully registered
Jan  1 06:03:26 192.168.3.5 syslog: 06:03:26.110[app:dbg]got nua_r_register : 200(Ok)
Jan  1 06:03:26 192.168.3.5 syslog: 06:03:26.110[app:dbg]sip: endpoint 1: REGISTER: 200 Ok
Jan  1 06:03:26 192.168.3.5 syslog: 06:03:26.110[app:dbg]Port 1: user port 3, old state hangup, new state 
Jan  1 06:03:26 192.168.3.5 syslog: 06:03:26.110[app:dbg]sip: endpoint 1: successfully registered
Jan  1 06:03:26 192.168.3.5 syslog: 06:03:26.124[app:dbg]got nua_r_register : 200(Ok)
Jan  1 06:03:26 192.168.3.5 syslog: 06:03:26.124[app:dbg]sip: endpoint 3: REGISTER: 200 Ok
Jan  1 06:03:26 192.168.3.5 syslog: 06:03:26.125[app:dbg]Port 3: user port 1, old state hangup, new state 
Jan  1 06:03:26 192.168.3.5 syslog: 06:03:26.125[app:dbg]sip: endpoint 3: successfully registered
Jan  1 06:04:05 192.168.3.5 syslog: 06:04:05.470[app:dbg]slic1. Event 2.
Jan  1 06:04:05 192.168.3.5 syslog: 06:04:05.470[app:dbg]slic 1. Off-hook event
Jan  1 06:04:05 192.168.3.5 syslog: 06:04:05.470[app:dbg]Set port 1 led to state 'LED_ON'
Jan  1 06:04:05 192.168.3.5 syslog: 06:04:05.470[app:dbg]HIO: offhook TDM port '1' port enabled 1
Jan  1 06:04:05 192.168.3.5 syslog: 06:04:05.470[app:dbg]HIO: offhook TDM port '1' direction unknown -> outgoing
Jan  1 06:04:05 192.168.3.5 syslog: 06:04:05.470[app:dbg]SLIC 1 (599): offhook state: hangup
Jan  1 06:04:05 192.168.3.5 syslog: 06:04:05.470[app:dbg]regex ID 1: dial reset
Jan  1 06:04:05 192.168.3.5 syslog: 06:04:05.551[app:dbg]vapi: Dev 0. Init TDM bus
Jan  1 06:04:05 192.168.3.5 syslog: 06:04:05.590[app:dbg]IFNAME: br0
Jan  1 06:04:05 192.168.3.5 syslog: 06:04:05.591[app:dbg]Configure EMAC 1 for interface br0
Jan  1 06:04:05 192.168.3.5 syslog: 06:04:05.591[app:dbg]vapi: Dev 0. Init Eth addr: <00:11:22:33:44:55>
Jan  1 06:04:05 192.168.3.5 syslog: 06:04:05.600[app:dbg]Setting Eth config
Jan  1 06:04:05 192.168.3.5 syslog: 06:04:05.610[app:dbg]vapi: Dev 0. Init IP addr: <192.168.253.2>
Jan  1 06:04:05 192.168.3.5 syslog: 06:04:05.640[app:dbg]vapi: Master Dev. Set Hairpin Mode: Ok
Jan  1 06:04:05 192.168.3.5 syslog: 06:04:05.650[app:dbg]vapi: Master Dev. Type 'M83263'
Jan  1 06:04:05 192.168.3.5 syslog: 06:04:05.660[app:dbg]vapi: Master Dev. ARM CODE VERSION:   <Test_v601_13_78771_1>
Jan  1 06:04:05 192.168.3.5 syslog: 06:04:05.980[app:dbg]CMD_CREATE_CONN: port = 1
Jan  1 06:04:05 192.168.3.5 syslog: 06:04:05.980[app:dbg]Port 1: check vapi queue ('free') at vapi_create_chan:573
Jan  1 06:04:05 192.168.3.5 syslog: 06:04:05.981[app:dbg]Chan 1: current state is INITIAL
Jan  1 06:04:05 192.168.3.5 syslog: 06:04:05.981[app:dbg]Port 1: set vapi queue MSP to 'busy' with 'create' at vapi_create_chan:599
Jan  1 06:04:05 192.168.3.5 syslog: 06:04:05.981[app:dbg]VQ Conn 1 = MSP :        'create' =
Jan  1 06:04:05 192.168.3.5 syslog: 06:04:05.981[app:dbg]Creating connection 1....
Jan  1 06:04:05 192.168.3.5 syslog: 06:04:05.981[app:dbg]Chan 1: INITIAL -> CREATING
Jan  1 06:04:05 192.168.3.5 syslog: 06:04:05.990[app:dbg]Created succefuly 1....
Jan  1 06:04:05 192.168.3.5 syslog: 06:04:05.990[app:dbg]CMD_CREATE_CONN: port = 1
Jan  1 06:04:05 192.168.3.5 syslog: 06:04:05.990[app:dbg]Port 1: check vapi queue ('busy''create') at vapi_create_chan:573
Jan  1 06:04:05 192.168.3.5 syslog: 06:04:05.990[app:dbg]Port 1 put cmd 'create',cur 'create' to queue at (vapi_create_chan:579)
Jan  1 06:04:05 192.168.3.5 syslog: 06:04:05.991[app:dbg]VQ Conn 1 = MSP :        'create' =
Jan  1 06:04:05 192.168.3.5 syslog: 06:04:05.991[app:dbg]VQ Conn 1 + 02  :        'create'  + <-get_ptr 
Jan  1 06:04:05 192.168.3.5 syslog: 06:04:05.991[app:dbg]port_start_tone(1 21 0 0)
Jan  1 06:04:05 192.168.3.5 syslog: 06:04:05.991[app:dbg]CMD_START_TONE: port = 1
Jan  1 06:04:05 192.168.3.5 syslog: 06:04:05.991[app:dbg]Port 1: check vapi queue ('busy''create') at vapi_start_tone_chan:1263
Jan  1 06:04:05 192.168.3.5 syslog: 06:04:05.991[app:dbg]Port 1 put cmd 'start_tone',cur 'create' to queue at (vapi_start_tone_chan:1273)
Jan  1 06:04:05 192.168.3.5 syslog: 06:04:05.991[app:dbg]VQ Conn 1 = MSP :        'create' =
Jan  1 06:04:05 192.168.3.5 syslog: 06:04:05.991[app:dbg]VQ Conn 1 + 02  :        'create'  + <-get_ptr 
Jan  1 06:04:05 192.168.3.5 syslog: 06:04:05.991[app:dbg]VQ Conn 1 + 03  :    'start_tone'  +  
Jan  1 06:04:05 192.168.3.5 syslog: 06:04:05.992[app:dbg]Port 1: user port 3, old state hangdown, new state 
Jan  1 06:04:05 192.168.3.5 syslog: 06:04:05.992[app:dbg]Set port 1 led to state 'LED_ON'
Jan  1 06:04:05 192.168.3.5 syslog: 06:04:05.992[app:dbg]pbx -[msg_fxs_state]-> group
Jan  1 06:04:05 192.168.3.5 syslog: 06:04:05.992[app:dbg]dump_port_calls() SLIC 1:
Jan  1 06:04:05 192.168.3.5 syslog: 06:04:05.992[app:dbg]Q:NONE
Jan  1 06:04:05 192.168.3.5 syslog: 06:04:05.992[app:dbg]H:((nil),0x00000000,(nil),0) W:((nil),0x00000000,(nil)) N:((nil),0x00000000,(nil)) H2:((nil),0x00000000,(nil))
Jan  1 06:04:05 192.168.3.5 syslog: 06:04:05.997[app:dbg]ITC: [msg_fxs_state] -> group
Jan  1 06:04:05 192.168.3.5 syslog: 06:04:05.997[app:dbg]-----[GM] self_fxs_state()
Jan  1 06:04:05 192.168.3.5 syslog: 06:04:05.997[app:dbg]Port 1: new state is hangdown
Jan  1 06:04:06 192.168.3.5 syslog: 06:04:06.011[app:dbg]vapi_cb_req: 1 0 result 0x00000000 requid 0x0000004f
Jan  1 06:04:06 192.168.3.5 syslog: 06:04:06.012[app:dbg]vapi_proc_event: VAPI_CB
Jan  1 06:04:06 192.168.3.5 syslog: 06:04:06.012[app:dbg]vapi_cb_chan: chan 1 reqest_id 0x0000004f result 0x00000000
Jan  1 06:04:06 192.168.3.5 syslog: 06:04:06.021[app:dbg]vapi_cb_req: 1 0 result 0x00000000 requid 0x00000000
Jan  1 06:04:06 192.168.3.5 syslog: 06:04:06.030[app:dbg]vapi_proc_event: VAPI_CB
Jan  1 06:04:06 192.168.3.5 syslog: 06:04:06.030[app:dbg]vapi_cb_chan: chan 1 reqest_id 0x00000000 result 0x00000000
Jan  1 06:04:06 192.168.3.5 syslog: 06:04:06.030[app:dbg]vapi: Conn 1 - << CREATED >>
Jan  1 06:04:06 192.168.3.5 syslog: 06:04:06.030[app:dbg]vapi: Conn 1 - fix DTMF detector
Jan  1 06:04:06 192.168.3.5 syslog: 06:04:06.032[app:dbg]vapi_cb_req: 1 0 result 0x00000000 requid 0x00000049
Jan  1 06:04:06 192.168.3.5 syslog: 06:04:06.040[app:dbg]vapi_proc_event: VAPI_CB
Jan  1 06:04:06 192.168.3.5 syslog: 06:04:06.040[app:dbg]vapi_cb_chan: chan 1 reqest_id 0x00000049 result 0x00000000
Jan  1 06:04:06 192.168.3.5 syslog: 06:04:06.040[app:dbg]vapi: Conn 1 - fix CNG generator
Jan  1 06:04:06 192.168.3.5 syslog: 06:04:06.046[app:dbg]vapi_cb_req: 1 0 result 0x00000000 requid 0x0000004c
Jan  1 06:04:06 192.168.3.5 syslog: 06:04:06.050[app:dbg]vapi_proc_event: VAPI_CB
Jan  1 06:04:06 192.168.3.5 syslog: 06:04:06.050[app:dbg]vapi_cb_chan: chan 1 reqest_id 0x0000004c result 0x00000000
Jan  1 06:04:06 192.168.3.5 syslog: 06:04:06.050[app:dbg]vapi: Conn 1 - caller id Set param
Jan  1 06:04:06 192.168.3.5 syslog: 06:04:06.050[app:dbg]vapi: chan '1' set param Caller ID
Jan  1 06:04:06 192.168.3.5 syslog: 06:04:06.052[app:dbg]vapi_cb_req: 1 0 result 0x00000000 requid 0x0000000c
Jan  1 06:04:06 192.168.3.5 syslog: 06:04:06.060[app:dbg]vapi_proc_event: VAPI_CB
Jan  1 06:04:06 192.168.3.5 syslog: 06:04:06.060[app:dbg]vapi_cb_chan: chan 1 reqest_id 0x0000000c result 0x00000000
Jan  1 06:04:06 192.168.3.5 syslog: 06:04:06.060[app:dbg]vapi: Conn 1 - enable ind ptime and pt
Jan  1 06:04:06 192.168.3.5 syslog: 06:04:06.065[app:dbg]vapi_cb_req: 1 0 result 0x00000000 requid 0x0000004a
Jan  1 06:04:06 192.168.3.5 syslog: 06:04:06.070[app:dbg]vapi_proc_event: VAPI_CB
Jan  1 06:04:06 192.168.3.5 syslog: 06:04:06.070[app:dbg]vapi_cb_chan: chan 1 reqest_id 0x0000004a result 0x00000000
Jan  1 06:04:06 192.168.3.5 syslog: 06:04:06.070[app:dbg]Chan 1: CREATING -> CREATED
Jan  1 06:04:06 192.168.3.5 syslog: 06:04:06.070[app:dbg]Port 1: check vapi queue ('busy''create') at vapi_next_ops:2408
Jan  1 06:04:06 192.168.3.5 syslog: 06:04:06.070[app:dbg]Port 1 get cmd 'create' from queue at (vapi_next_ops:2427)
Jan  1 06:04:06 192.168.3.5 syslog: 06:04:06.070[app:dbg]VQ Conn 1 + 03  :    'start_tone'  + <-get_ptr 
Jan  1 06:04:06 192.168.3.5 syslog: 06:04:06.071[app:dbg]Port 1: check vapi queue ('free') at vapi_create_chan:573
Jan  1 06:04:06 192.168.3.5 syslog: 06:04:06.071[app:dbg]Chan 1: current state is CREATED
Jan  1 06:04:06 192.168.3.5 syslog: 06:04:06.071[app:dbg]chan 1: no need to create - already exists
Jan  1 06:04:06 192.168.3.5 syslog: 06:04:06.071[app:dbg]Port 1: check vapi queue ('free') at vapi_next_ops:2570
Jan  1 06:04:06 192.168.3.5 syslog: 06:04:06.071[app:dbg]Port 1: check vapi queue ('free') at vapi_next_ops:2408
Jan  1 06:04:06 192.168.3.5 syslog: 06:04:06.071[app:dbg]Port 1 get cmd 'start_tone' from queue at (vapi_next_ops:2427)
Jan  1 06:04:06 192.168.3.5 syslog: 06:04:06.071[app:dbg]Port 1: check vapi queue ('free') at vapi_start_tone_chan:1263
Jan  1 06:04:06 192.168.3.5 syslog: 06:04:06.071[app:dbg]Chan 1: current state is CREATED
Jan  1 06:04:06 192.168.3.5 syslog: 06:04:06.071[app:dbg]Port 1: set vapi queue MSP to 'busy' with 'start_tone' at vapi_start_tone_chan:1300
Jan  1 06:04:06 192.168.3.5 syslog: 06:04:06.071[app:dbg]VQ Conn 1 = MSP :    'start_tone' =
Jan  1 06:04:06 192.168.3.5 syslog: 06:04:06.076[app:dbg]chan 1 start tone, id=21, direction=TDM
Jan  1 06:04:06 192.168.3.5 syslog: 06:04:06.077[app:dbg]vapi_cb_req: 1 0 result 0x00000000 requid 0x00000922
Jan  1 06:04:06 192.168.3.5 syslog: 06:04:06.080[app:dbg]vapi_proc_event: VAPI_CB
Jan  1 06:04:06 192.168.3.5 syslog: 06:04:06.080[app:dbg]vapi_cb_chan: chan 1 reqest_id 0x00000922 result 0x00000000
Jan  1 06:04:06 192.168.3.5 syslog: 06:04:06.080[app:dbg]Conn 1: Start tone - Successfull
Jan  1 06:04:06 192.168.3.5 syslog: 06:04:06.080[app:dbg]Port 1: check vapi queue ('busy''start_tone') at vapi_next_ops:2408
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.330[app:dbg]vapi_proc_event: eVAPI_TONE_DETECT_EVENT
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.330[app:dbg]vapi: tone detect: Conn 1. Change signal <DTMF digit 0> (duration 3290 ms) -> <DTMF digit 8> (level 0 dBov)
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.340[app:dbg]hio: port 1: digit 8 (code 0x18), tone
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.340[app:dbg]CMD_STOP_TONE: port = 1
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.340[app:dbg]Port 1: check vapi queue ('free') at vapi_stop_tone_chan:1353
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.340[app:dbg]Chan 1: current state is CREATED
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.340[app:dbg]Port 1: set vapi queue MSP to 'busy' with 'stop_tone' at vapi_stop_tone_chan:1399
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.340[app:dbg]VQ Conn 1 = MSP :     'stop_tone' =
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.341[app:dbg]chan 1 stop tone
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.341[app:dbg]Port 1: user port 3, old state dial, new state 
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.341[app:dbg]Set port 1 led to state 'LED_ON'
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.341[app:dbg]pbx -[msg_fxs_state]-> group
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.342[app:dbg]check item 0: 0x03FF/00000000,0 : <8>
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.342[app:dbg]regex_match_item: check route 0x312c08 repeat off rf 0, rt 0, crt 0, digit '8' mask 0x3FF
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.342[app:dbg]<cur match>: dial <8>r 0, dt 0, sub 0 {0,0}
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.342[app:dbg]check item 1: 0x03FF/00000000,0 : <F>
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.342[app:dbg]check 'cant dial more' within cycle: item 0, crt 0, {0,0}
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.342[app:dbg]MATCH: fulldialed 0, can`t dial more 0, dialtone 0
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.342[app:dbg]check item 0: 0x021C/00000000,0 : <8>
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.342[app:dbg]regex_match_item: check route 0x312ab0 repeat off rf 0, rt 0, crt 0, digit '8' mask 0x21C
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.343[app:dbg]regex_match_item: digit '8' not in mask[0] 0x021C
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.343[app:dbg]<whole not match>: dial <8>r 0, dt 0, sub 0 {0,0}
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.343[app:dbg]match fail
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.343[app:dbg]check item 0: 0x0020/00000000,0 : <8>
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.343[app:dbg]regex_match_item: check route 0x312958 repeat off rf 0, rt 0, crt 0, digit '8' mask 0x20
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.343[app:dbg]regex_match_item: digit '8' not in mask[0] 0x0020
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.343[app:dbg]<whole not match>: dial <8>r 0, dt 0, sub 0 {0,0}
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.343[app:dbg]match fail
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.343[app:dbg]check item 0: 0x0002/00000000,0 : <8>
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.344[app:dbg]regex_match_item: check route 0x312800 repeat off rf 0, rt 0, crt 0, digit '8' mask 0x02
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.344[app:dbg]regex_match_item: digit '8' not in mask[0] 0x0002
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.344[app:dbg]<whole not match>: dial <8>r 0, dt 0, sub 0 {0,0}
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.344[app:dbg]match fail
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.344[app:dbg]01: [3,]
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.344[app:dbg]port_process_digit() regex route 0x312c08, final 0, dt 0
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.344[app:dbg]port 1: dial candidates
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.344[app:dbg]regex ID 1, route 3: L 30 en, S 3 dis
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.350[app:dbg]ITC: [msg_fxs_state] -> group
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.350[app:dbg]-----[GM] self_fxs_state()
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.350[app:dbg]Port 1: new state is dial
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.351[app:dbg]vapi_cb_req: 1 0 result 0x00000000 requid 0x00000923
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.351[app:dbg]vapi_proc_event: VAPI_CB
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.351[app:dbg]vapi_cb_chan: chan 1 reqest_id 0x00000923 result 0x00000000
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.351[app:dbg]Conn 1: Stop tone - Successfull
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.351[app:dbg]Port 1: check vapi queue ('busy''stop_tone') at vapi_next_ops:2408
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.360[app:dbg]vapi: generic event, code 2 <Tone Generation completed>, conn 1
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.430[app:dbg]vapi_proc_event: eVAPI_TONE_DETECT_EVENT
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.430[app:dbg]vapi: tone detect: Conn 1. End of signal <DTMF digit 8>, duration 100 ms
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.527[app:dbg]got nua_r_register : 200(Ok)
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.527[app:dbg]sip: endpoint 2: REGISTER: 200 Ok
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.528[app:dbg]Port 2: user port 0, old state hangup, new state 
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.528[app:dbg]sip: endpoint 2: successfully registered
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.563[app:dbg]vapi_proc_event: eVAPI_TONE_DETECT_EVENT
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.563[app:dbg]vapi: tone detect: Conn 1. Detect signal <DTMF digit 3> (level 8 dBov)
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.570[app:dbg]hio: port 1: digit 3 (code 0x13), tone
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.570[app:dbg]check item 0: 0x03FF/00000000,0 : <8>
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.570[app:dbg]regex_match_item: check route 0x312c08 repeat off rf 0, rt 0, crt 0, digit '8' mask 0x3FF
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.570[app:dbg]<cur match>: dial <8>r 0, dt 0, sub 0 {0,0}
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.570[app:dbg]check item 1: 0x03FF/00000000,0 : <3>
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.570[app:dbg]regex_match_item: check route 0x312c08 repeat off rf 0, rt 0, crt 0, digit '3' mask 0x3FF
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.571[app:dbg]<cur match>: dial <3>r 0, dt 0, sub 0 {0,0}
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.571[app:dbg]check item 2: 0x03FF/080000FF,0 : <F>
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.571[app:dbg]check 'cant dial more' within cycle: item 1, crt 0, {0,0}
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.571[app:dbg]MATCH: fulldialed 1, can`t dial more 0, dialtone 0
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.571[app:dbg]01: [3,]
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.571[app:dbg]port_process_digit() regex route 0x312c08, final 1, dt 0
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.571[app:dbg]port 1: process final route
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.670[app:dbg]vapi_proc_event: eVAPI_TONE_DETECT_EVENT
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.670[app:dbg]vapi: tone detect: Conn 1. End of signal <DTMF digit 3>, duration 110 ms
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.804[app:dbg]vapi_proc_event: eVAPI_TONE_DETECT_EVENT
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.804[app:dbg]vapi: tone detect: Conn 1. Detect signal <DTMF digit 4> (level 8 dBov)
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.811[app:dbg]hio: port 1: digit 4 (code 0x14), tone
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.811[app:dbg]check item 0: 0x03FF/00000000,0 : <8>
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.811[app:dbg]regex_match_item: check route 0x312c08 repeat off rf 0, rt 0, crt 0, digit '8' mask 0x3FF
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.811[app:dbg]<cur match>: dial <8>r 0, dt 0, sub 0 {0,0}
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.812[app:dbg]check item 1: 0x03FF/00000000,0 : <3>
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.812[app:dbg]regex_match_item: check route 0x312c08 repeat off rf 0, rt 0, crt 0, digit '3' mask 0x3FF
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.812[app:dbg]<cur match>: dial <3>r 0, dt 0, sub 0 {0,0}
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.812[app:dbg]check item 2: 0x03FF/080000FF,0 : <4>
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.812[app:dbg]regex_match_item: check route 0x312c08 repeat on rf 0, rt 255(inf), crt 0, digit '4' mask 0x3FF
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.812[app:dbg]<cur match>: dial <4>r 1, dt 0, sub 0 r{0,255(inf)}
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.812[app:dbg]match ok: rf 0, crt 1, rt 255
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.812[app:dbg]end of items - test dial ended
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.812[app:dbg]check 'cant dial more' out of the cycle: item 2, crt 1, r{0,255(inf)}
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.813[app:dbg]MATCH: fulldialed 1, can`t dial more 0, dialtone 0
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.813[app:dbg]01: [3,]
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.813[app:dbg]port_process_digit() regex route 0x312c08, final 1, dt 0
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.813[app:dbg]port 1: process final route
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.910[app:dbg]vapi_proc_event: eVAPI_TONE_DETECT_EVENT
Jan  1 06:04:09 192.168.3.5 syslog: 06:04:09.910[app:dbg]vapi: tone detect: Conn 1. End of signal <DTMF digit 4>, duration 110 ms
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.040[app:dbg]port 1: regex per sec timeout
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.045[app:dbg]vapi_proc_event: eVAPI_TONE_DETECT_EVENT
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.045[app:dbg]vapi: tone detect: Conn 1. Detect signal <DTMF digit 3> (level 8 dBov)
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.050[app:dbg]hio: port 1: digit 3 (code 0x13), tone
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.050[app:dbg]check item 0: 0x03FF/00000000,0 : <8>
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.050[app:dbg]regex_match_item: check route 0x312c08 repeat off rf 0, rt 0, crt 0, digit '8' mask 0x3FF
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.050[app:dbg]<cur match>: dial <8>r 0, dt 0, sub 0 {0,0}
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.050[app:dbg]check item 1: 0x03FF/00000000,0 : <3>
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.050[app:dbg]regex_match_item: check route 0x312c08 repeat off rf 0, rt 0, crt 0, digit '3' mask 0x3FF
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.051[app:dbg]<cur match>: dial <3>r 0, dt 0, sub 0 {0,0}
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.051[app:dbg]check item 2: 0x03FF/080000FF,0 : <4>
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.051[app:dbg]regex_match_item: check route 0x312c08 repeat on rf 0, rt 255(inf), crt 0, digit '4' mask 0x3FF
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.051[app:dbg]<cur match>: dial <4>r 1, dt 0, sub 0 r{0,255(inf)}
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.051[app:dbg]match ok: rf 0, crt 1, rt 255
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.051[app:dbg]check item 2: 0x03FF/080000FF,1 : <3>
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.051[app:dbg]regex_match_item: check route 0x312c08 repeat on rf 0, rt 255(inf), crt 1, digit '3' mask 0x3FF
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.051[app:dbg]<cur match>: dial <3>r 2, dt 0, sub 0 r{0,255(inf)}
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.052[app:dbg]match ok: rf 0, crt 2, rt 255
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.052[app:dbg]end of items - test dial ended
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.052[app:dbg]check 'cant dial more' out of the cycle: item 2, crt 2, r{0,255(inf)}
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.052[app:dbg]MATCH: fulldialed 1, can`t dial more 0, dialtone 0
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.052[app:dbg]01: [3,]
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.052[app:dbg]port_process_digit() regex route 0x312c08, final 1, dt 0
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.052[app:dbg]port 1: process final route
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.150[app:dbg]vapi_proc_event: eVAPI_TONE_DETECT_EVENT
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.150[app:dbg]vapi: tone detect: Conn 1. End of signal <DTMF digit 3>, duration 110 ms
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.285[app:dbg]vapi_proc_event: eVAPI_TONE_DETECT_EVENT
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.285[app:dbg]vapi: tone detect: Conn 1. Detect signal <DTMF digit 3> (level 8 dBov)
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.290[app:dbg]hio: port 1: digit 3 (code 0x13), tone
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.290[app:dbg]check item 0: 0x03FF/00000000,0 : <8>
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.290[app:dbg]regex_match_item: check route 0x312c08 repeat off rf 0, rt 0, crt 0, digit '8' mask 0x3FF
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.290[app:dbg]<cur match>: dial <8>r 0, dt 0, sub 0 {0,0}
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.290[app:dbg]check item 1: 0x03FF/00000000,0 : <3>
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.291[app:dbg]regex_match_item: check route 0x312c08 repeat off rf 0, rt 0, crt 0, digit '3' mask 0x3FF
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.291[app:dbg]<cur match>: dial <3>r 0, dt 0, sub 0 {0,0}
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.291[app:dbg]check item 2: 0x03FF/080000FF,0 : <4>
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.291[app:dbg]regex_match_item: check route 0x312c08 repeat on rf 0, rt 255(inf), crt 0, digit '4' mask 0x3FF
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.291[app:dbg]<cur match>: dial <4>r 1, dt 0, sub 0 r{0,255(inf)}
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.291[app:dbg]match ok: rf 0, crt 1, rt 255
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.291[app:dbg]check item 2: 0x03FF/080000FF,1 : <3>
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.291[app:dbg]regex_match_item: check route 0x312c08 repeat on rf 0, rt 255(inf), crt 1, digit '3' mask 0x3FF
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.291[app:dbg]<cur match>: dial <3>r 2, dt 0, sub 0 r{0,255(inf)}
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.292[app:dbg]match ok: rf 0, crt 2, rt 255
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.292[app:dbg]check item 2: 0x03FF/080000FF,2 : <3>
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.292[app:dbg]regex_match_item: check route 0x312c08 repeat on rf 0, rt 255(inf), crt 2, digit '3' mask 0x3FF
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.292[app:dbg]<cur match>: dial <3>r 3, dt 0, sub 0 r{0,255(inf)}
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.292[app:dbg]match ok: rf 0, crt 3, rt 255
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.292[app:dbg]end of items - test dial ended
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.292[app:dbg]check 'cant dial more' out of the cycle: item 2, crt 3, r{0,255(inf)}
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.292[app:dbg]MATCH: fulldialed 1, can`t dial more 0, dialtone 0
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.292[app:dbg]01: [3,]
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.292[app:dbg]port_process_digit() regex route 0x312c08, final 1, dt 0
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.293[app:dbg]port 1: process final route
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.390[app:dbg]vapi_proc_event: eVAPI_TONE_DETECT_EVENT
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.390[app:dbg]vapi: tone detect: Conn 1. End of signal <DTMF digit 3>, duration 110 ms
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.525[app:dbg]vapi_proc_event: eVAPI_TONE_DETECT_EVENT
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.525[app:dbg]vapi: tone detect: Conn 1. Detect signal <DTMF digit 7> (level 8 dBov)
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.530[app:dbg]hio: port 1: digit 7 (code 0x17), tone
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.530[app:dbg]check item 0: 0x03FF/00000000,0 : <8>
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.530[app:dbg]regex_match_item: check route 0x312c08 repeat off rf 0, rt 0, crt 0, digit '8' mask 0x3FF
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.530[app:dbg]<cur match>: dial <8>r 0, dt 0, sub 0 {0,0}
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.530[app:dbg]check item 1: 0x03FF/00000000,0 : <3>
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.530[app:dbg]regex_match_item: check route 0x312c08 repeat off rf 0, rt 0, crt 0, digit '3' mask 0x3FF
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.531[app:dbg]<cur match>: dial <3>r 0, dt 0, sub 0 {0,0}
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.531[app:dbg]check item 2: 0x03FF/080000FF,0 : <4>
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.531[app:dbg]regex_match_item: check route 0x312c08 repeat on rf 0, rt 255(inf), crt 0, digit '4' mask 0x3FF
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.531[app:dbg]<cur match>: dial <4>r 1, dt 0, sub 0 r{0,255(inf)}
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.531[app:dbg]match ok: rf 0, crt 1, rt 255
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.531[app:dbg]check item 2: 0x03FF/080000FF,1 : <3>
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.531[app:dbg]regex_match_item: check route 0x312c08 repeat on rf 0, rt 255(inf), crt 1, digit '3' mask 0x3FF
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.531[app:dbg]<cur match>: dial <3>r 2, dt 0, sub 0 r{0,255(inf)}
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.532[app:dbg]match ok: rf 0, crt 2, rt 255
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.532[app:dbg]check item 2: 0x03FF/080000FF,2 : <3>
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.532[app:dbg]regex_match_item: check route 0x312c08 repeat on rf 0, rt 255(inf), crt 2, digit '3' mask 0x3FF
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.532[app:dbg]<cur match>: dial <3>r 3, dt 0, sub 0 r{0,255(inf)}
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.532[app:dbg]match ok: rf 0, crt 3, rt 255
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.532[app:dbg]check item 2: 0x03FF/080000FF,3 : <7>
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.532[app:dbg]regex_match_item: check route 0x312c08 repeat on rf 0, rt 255(inf), crt 3, digit '7' mask 0x3FF
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.532[app:dbg]<cur match>: dial <7>r 4, dt 0, sub 0 r{0,255(inf)}
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.532[app:dbg]match ok: rf 0, crt 4, rt 255
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.533[app:dbg]end of items - test dial ended
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.533[app:dbg]check 'cant dial more' out of the cycle: item 2, crt 4, r{0,255(inf)}
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.533[app:dbg]MATCH: fulldialed 1, can`t dial more 0, dialtone 0
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.533[app:dbg]01: [3,]
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.533[app:dbg]port_process_digit() regex route 0x312c08, final 1, dt 0
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.533[app:dbg]port 1: process final route
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.630[app:dbg]vapi_proc_event: eVAPI_TONE_DETECT_EVENT
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.630[app:dbg]vapi: tone detect: Conn 1. End of signal <DTMF digit 7>, duration 110 ms
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.765[app:dbg]vapi_proc_event: eVAPI_TONE_DETECT_EVENT
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.765[app:dbg]vapi: tone detect: Conn 1. Detect signal <DTMF digit 6> (level 8 dBov)
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.770[app:dbg]hio: port 1: digit 6 (code 0x16), tone
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.770[app:dbg]check item 0: 0x03FF/00000000,0 : <8>
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.770[app:dbg]regex_match_item: check route 0x312c08 repeat off rf 0, rt 0, crt 0, digit '8' mask 0x3FF
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.770[app:dbg]<cur match>: dial <8>r 0, dt 0, sub 0 {0,0}
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.770[app:dbg]check item 1: 0x03FF/00000000,0 : <3>
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.770[app:dbg]regex_match_item: check route 0x312c08 repeat off rf 0, rt 0, crt 0, digit '3' mask 0x3FF
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.771[app:dbg]<cur match>: dial <3>r 0, dt 0, sub 0 {0,0}
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.771[app:dbg]check item 2: 0x03FF/080000FF,0 : <4>
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.771[app:dbg]regex_match_item: check route 0x312c08 repeat on rf 0, rt 255(inf), crt 0, digit '4' mask 0x3FF
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.771[app:dbg]<cur match>: dial <4>r 1, dt 0, sub 0 r{0,255(inf)}
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.771[app:dbg]match ok: rf 0, crt 1, rt 255
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.771[app:dbg]check item 2: 0x03FF/080000FF,1 : <3>
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.771[app:dbg]regex_match_item: check route 0x312c08 repeat on rf 0, rt 255(inf), crt 1, digit '3' mask 0x3FF
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.771[app:dbg]<cur match>: dial <3>r 2, dt 0, sub 0 r{0,255(inf)}
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.772[app:dbg]match ok: rf 0, crt 2, rt 255
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.772[app:dbg]check item 2: 0x03FF/080000FF,2 : <3>
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.772[app:dbg]regex_match_item: check route 0x312c08 repeat on rf 0, rt 255(inf), crt 2, digit '3' mask 0x3FF
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.772[app:dbg]<cur match>: dial <3>r 3, dt 0, sub 0 r{0,255(inf)}
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.772[app:dbg]match ok: rf 0, crt 3, rt 255
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.772[app:dbg]check item 2: 0x03FF/080000FF,3 : <7>
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.772[app:dbg]regex_match_item: check route 0x312c08 repeat on rf 0, rt 255(inf), crt 3, digit '7' mask 0x3FF
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.772[app:dbg]<cur match>: dial <7>r 4, dt 0, sub 0 r{0,255(inf)}
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.772[app:dbg]match ok: rf 0, crt 4, rt 255
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.773[app:dbg]check item 2: 0x03FF/080000FF,4 : <6>
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.773[app:dbg]regex_match_item: check route 0x312c08 repeat on rf 0, rt 255(inf), crt 4, digit '6' mask 0x3FF
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.773[app:dbg]<cur match>: dial <6>r 5, dt 0, sub 0 r{0,255(inf)}
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.773[app:dbg]match ok: rf 0, crt 5, rt 255
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.773[app:dbg]end of items - test dial ended
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.773[app:dbg]check 'cant dial more' out of the cycle: item 2, crt 5, r{0,255(inf)}
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.773[app:dbg]MATCH: fulldialed 1, can`t dial more 0, dialtone 0
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.773[app:dbg]01: [3,]
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.773[app:dbg]port_process_digit() regex route 0x312c08, final 1, dt 0
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.773[app:dbg]port 1: process final route
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.870[app:dbg]vapi_proc_event: eVAPI_TONE_DETECT_EVENT
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:10.870[app:dbg]vapi: tone detect: Conn 1. End of signal <DTMF digit 6>, duration 110 ms
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:11.005[app:dbg]vapi_proc_event: eVAPI_TONE_DETECT_EVENT
Jan  1 06:04:10 192.168.3.5 syslog: 06:04:11.005[app:dbg]vapi: tone detect: Conn 1. Detect signal <DTMF digit 4> (level 8 dBov)
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.010[app:dbg]hio: port 1: digit 4 (code 0x14), tone
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.010[app:dbg]check item 0: 0x03FF/00000000,0 : <8>
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.010[app:dbg]regex_match_item: check route 0x312c08 repeat off rf 0, rt 0, crt 0, digit '8' mask 0x3FF
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.010[app:dbg]<cur match>: dial <8>r 0, dt 0, sub 0 {0,0}
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.010[app:dbg]check item 1: 0x03FF/00000000,0 : <3>
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.010[app:dbg]regex_match_item: check route 0x312c08 repeat off rf 0, rt 0, crt 0, digit '3' mask 0x3FF
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.011[app:dbg]<cur match>: dial <3>r 0, dt 0, sub 0 {0,0}
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.011[app:dbg]check item 2: 0x03FF/080000FF,0 : <4>
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.011[app:dbg]regex_match_item: check route 0x312c08 repeat on rf 0, rt 255(inf), crt 0, digit '4' mask 0x3FF
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.011[app:dbg]<cur match>: dial <4>r 1, dt 0, sub 0 r{0,255(inf)}
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.011[app:dbg]match ok: rf 0, crt 1, rt 255
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.011[app:dbg]check item 2: 0x03FF/080000FF,1 : <3>
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.011[app:dbg]regex_match_item: check route 0x312c08 repeat on rf 0, rt 255(inf), crt 1, digit '3' mask 0x3FF
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.011[app:dbg]<cur match>: dial <3>r 2, dt 0, sub 0 r{0,255(inf)}
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.012[app:dbg]match ok: rf 0, crt 2, rt 255
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.012[app:dbg]check item 2: 0x03FF/080000FF,2 : <3>
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.012[app:dbg]regex_match_item: check route 0x312c08 repeat on rf 0, rt 255(inf), crt 2, digit '3' mask 0x3FF
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.012[app:dbg]<cur match>: dial <3>r 3, dt 0, sub 0 r{0,255(inf)}
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.012[app:dbg]match ok: rf 0, crt 3, rt 255
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.012[app:dbg]check item 2: 0x03FF/080000FF,3 : <7>
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.012[app:dbg]regex_match_item: check route 0x312c08 repeat on rf 0, rt 255(inf), crt 3, digit '7' mask 0x3FF
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.012[app:dbg]<cur match>: dial <7>r 4, dt 0, sub 0 r{0,255(inf)}
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.012[app:dbg]match ok: rf 0, crt 4, rt 255
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.013[app:dbg]check item 2: 0x03FF/080000FF,4 : <6>
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.013[app:dbg]regex_match_item: check route 0x312c08 repeat on rf 0, rt 255(inf), crt 4, digit '6' mask 0x3FF
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.013[app:dbg]<cur match>: dial <6>r 5, dt 0, sub 0 r{0,255(inf)}
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.013[app:dbg]match ok: rf 0, crt 5, rt 255
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.013[app:dbg]check item 2: 0x03FF/080000FF,5 : <4>
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.013[app:dbg]regex_match_item: check route 0x312c08 repeat on rf 0, rt 255(inf), crt 5, digit '4' mask 0x3FF
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.013[app:dbg]<cur match>: dial <4>r 6, dt 0, sub 0 r{0,255(inf)}
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.013[app:dbg]match ok: rf 0, crt 6, rt 255
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.013[app:dbg]end of items - test dial ended
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.013[app:dbg]check 'cant dial more' out of the cycle: item 2, crt 6, r{0,255(inf)}
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.014[app:dbg]MATCH: fulldialed 1, can`t dial more 0, dialtone 0
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.014[app:dbg]01: [3,]
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.014[app:dbg]port_process_digit() regex route 0x312c08, final 1, dt 0
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.014[app:dbg]port 1: process final route
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.020[app:dbg]port 1: regex per sec timeout
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.110[app:dbg]vapi_proc_event: eVAPI_TONE_DETECT_EVENT
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.110[app:dbg]vapi: tone detect: Conn 1. End of signal <DTMF digit 4>, duration 115 ms
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.245[app:dbg]vapi_proc_event: eVAPI_TONE_DETECT_EVENT
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.245[app:dbg]vapi: tone detect: Conn 1. Detect signal <DTMF digit 0> (level 8 dBov)
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.250[app:dbg]hio: port 1: digit 0 (code 0x10), tone
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.250[app:dbg]check item 0: 0x03FF/00000000,0 : <8>
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.250[app:dbg]regex_match_item: check route 0x312c08 repeat off rf 0, rt 0, crt 0, digit '8' mask 0x3FF
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.250[app:dbg]<cur match>: dial <8>r 0, dt 0, sub 0 {0,0}
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.250[app:dbg]check item 1: 0x03FF/00000000,0 : <3>
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.250[app:dbg]regex_match_item: check route 0x312c08 repeat off rf 0, rt 0, crt 0, digit '3' mask 0x3FF
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.251[app:dbg]<cur match>: dial <3>r 0, dt 0, sub 0 {0,0}
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.251[app:dbg]check item 2: 0x03FF/080000FF,0 : <4>
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.251[app:dbg]regex_match_item: check route 0x312c08 repeat on rf 0, rt 255(inf), crt 0, digit '4' mask 0x3FF
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.251[app:dbg]<cur match>: dial <4>r 1, dt 0, sub 0 r{0,255(inf)}
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.251[app:dbg]match ok: rf 0, crt 1, rt 255
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.251[app:dbg]check item 2: 0x03FF/080000FF,1 : <3>
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.251[app:dbg]regex_match_item: check route 0x312c08 repeat on rf 0, rt 255(inf), crt 1, digit '3' mask 0x3FF
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.251[app:dbg]<cur match>: dial <3>r 2, dt 0, sub 0 r{0,255(inf)}
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.252[app:dbg]match ok: rf 0, crt 2, rt 255
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.252[app:dbg]check item 2: 0x03FF/080000FF,2 : <3>
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.252[app:dbg]regex_match_item: check route 0x312c08 repeat on rf 0, rt 255(inf), crt 2, digit '3' mask 0x3FF
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.252[app:dbg]<cur match>: dial <3>r 3, dt 0, sub 0 r{0,255(inf)}
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.252[app:dbg]match ok: rf 0, crt 3, rt 255
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.252[app:dbg]check item 2: 0x03FF/080000FF,3 : <7>
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.252[app:dbg]regex_match_item: check route 0x312c08 repeat on rf 0, rt 255(inf), crt 3, digit '7' mask 0x3FF
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.252[app:dbg]<cur match>: dial <7>r 4, dt 0, sub 0 r{0,255(inf)}
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.252[app:dbg]match ok: rf 0, crt 4, rt 255
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.253[app:dbg]check item 2: 0x03FF/080000FF,4 : <6>
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.253[app:dbg]regex_match_item: check route 0x312c08 repeat on rf 0, rt 255(inf), crt 4, digit '6' mask 0x3FF
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.253[app:dbg]<cur match>: dial <6>r 5, dt 0, sub 0 r{0,255(inf)}
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.253[app:dbg]match ok: rf 0, crt 5, rt 255
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.253[app:dbg]check item 2: 0x03FF/080000FF,5 : <4>
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.253[app:dbg]regex_match_item: check route 0x312c08 repeat on rf 0, rt 255(inf), crt 5, digit '4' mask 0x3FF
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.253[app:dbg]<cur match>: dial <4>r 6, dt 0, sub 0 r{0,255(inf)}
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.253[app:dbg]match ok: rf 0, crt 6, rt 255
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.253[app:dbg]check item 2: 0x03FF/080000FF,6 : <0>
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.254[app:dbg]regex_match_item: check route 0x312c08 repeat on rf 0, rt 255(inf), crt 6, digit '0' mask 0x3FF
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.254[app:dbg]<cur match>: dial <0>r 7, dt 0, sub 0 r{0,255(inf)}
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.254[app:dbg]match ok: rf 0, crt 7, rt 255
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.254[app:dbg]end of items - test dial ended
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.254[app:dbg]check 'cant dial more' out of the cycle: item 2, crt 7, r{0,255(inf)}
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.254[app:dbg]MATCH: fulldialed 1, can`t dial more 0, dialtone 0
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.254[app:dbg]01: [3,]
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.254[app:dbg]port_process_digit() regex route 0x312c08, final 1, dt 0
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.254[app:dbg]port 1: process final route
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.350[app:dbg]vapi_proc_event: eVAPI_TONE_DETECT_EVENT
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.350[app:dbg]vapi: tone detect: Conn 1. End of signal <DTMF digit 0>, duration 110 ms
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.485[app:dbg]vapi_proc_event: eVAPI_TONE_DETECT_EVENT
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.485[app:dbg]vapi: tone detect: Conn 1. Detect signal <DTMF digit 6> (level 8 dBov)
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.490[app:dbg]hio: port 1: digit 6 (code 0x16), tone
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.490[app:dbg]check item 0: 0x03FF/00000000,0 : <8>
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.490[app:dbg]regex_match_item: check route 0x312c08 repeat off rf 0, rt 0, crt 0, digit '8' mask 0x3FF
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.490[app:dbg]<cur match>: dial <8>r 0, dt 0, sub 0 {0,0}
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.490[app:dbg]check item 1: 0x03FF/00000000,0 : <3>
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.490[app:dbg]regex_match_item: check route 0x312c08 repeat off rf 0, rt 0, crt 0, digit '3' mask 0x3FF
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.491[app:dbg]<cur match>: dial <3>r 0, dt 0, sub 0 {0,0}
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.491[app:dbg]check item 2: 0x03FF/080000FF,0 : <4>
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.491[app:dbg]regex_match_item: check route 0x312c08 repeat on rf 0, rt 255(inf), crt 0, digit '4' mask 0x3FF
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.491[app:dbg]<cur match>: dial <4>r 1, dt 0, sub 0 r{0,255(inf)}
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.491[app:dbg]match ok: rf 0, crt 1, rt 255
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.491[app:dbg]check item 2: 0x03FF/080000FF,1 : <3>
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.491[app:dbg]regex_match_item: check route 0x312c08 repeat on rf 0, rt 255(inf), crt 1, digit '3' mask 0x3FF
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.491[app:dbg]<cur match>: dial <3>r 2, dt 0, sub 0 r{0,255(inf)}
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.492[app:dbg]match ok: rf 0, crt 2, rt 255
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.492[app:dbg]check item 2: 0x03FF/080000FF,2 : <3>
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.492[app:dbg]regex_match_item: check route 0x312c08 repeat on rf 0, rt 255(inf), crt 2, digit '3' mask 0x3FF
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.492[app:dbg]<cur match>: dial <3>r 3, dt 0, sub 0 r{0,255(inf)}
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.492[app:dbg]match ok: rf 0, crt 3, rt 255
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.492[app:dbg]check item 2: 0x03FF/080000FF,3 : <7>
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.492[app:dbg]regex_match_item: check route 0x312c08 repeat on rf 0, rt 255(inf), crt 3, digit '7' mask 0x3FF
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.492[app:dbg]<cur match>: dial <7>r 4, dt 0, sub 0 r{0,255(inf)}
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.492[app:dbg]match ok: rf 0, crt 4, rt 255
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.492[app:dbg]check item 2: 0x03FF/080000FF,4 : <6>
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.493[app:dbg]regex_match_item: check route 0x312c08 repeat on rf 0, rt 255(inf), crt 4, digit '6' mask 0x3FF
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.493[app:dbg]<cur match>: dial <6>r 5, dt 0, sub 0 r{0,255(inf)}
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.493[app:dbg]match ok: rf 0, crt 5, rt 255
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.493[app:dbg]check item 2: 0x03FF/080000FF,5 : <4>
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.493[app:dbg]regex_match_item: check route 0x312c08 repeat on rf 0, rt 255(inf), crt 5, digit '4' mask 0x3FF
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.493[app:dbg]<cur match>: dial <4>r 6, dt 0, sub 0 r{0,255(inf)}
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.493[app:dbg]match ok: rf 0, crt 6, rt 255
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.493[app:dbg]check item 2: 0x03FF/080000FF,6 : <0>
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.494[app:dbg]regex_match_item: check route 0x312c08 repeat on rf 0, rt 255(inf), crt 6, digit '0' mask 0x3FF
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.494[app:dbg]<cur match>: dial <0>r 7, dt 0, sub 0 r{0,255(inf)}
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.494[app:dbg]match ok: rf 0, crt 7, rt 255
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.494[app:dbg]check item 2: 0x03FF/080000FF,7 : <6>
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.494[app:dbg]regex_match_item: check route 0x312c08 repeat on rf 0, rt 255(inf), crt 7, digit '6' mask 0x3FF
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.494[app:dbg]<cur match>: dial <6>r 8, dt 0, sub 0 r{0,255(inf)}
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.494[app:dbg]match ok: rf 0, crt 8, rt 255
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.494[app:dbg]end of items - test dial ended
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.494[app:dbg]check 'cant dial more' out of the cycle: item 2, crt 8, r{0,255(inf)}
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.494[app:dbg]MATCH: fulldialed 1, can`t dial more 0, dialtone 0
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.495[app:dbg]01: [3,]
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.495[app:dbg]port_process_digit() regex route 0x312c08, final 1, dt 0
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.495[app:dbg]port 1: process final route
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.590[app:dbg]vapi_proc_event: eVAPI_TONE_DETECT_EVENT
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.590[app:dbg]vapi: tone detect: Conn 1. End of signal <DTMF digit 6>, duration 110 ms
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.705[app:dbg]vapi_proc_event: eVAPI_TONE_DETECT_EVENT
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.705[app:dbg]vapi: tone detect: Conn 1. Detect signal <DTMF digit 2> (level 8 dBov)
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.710[app:dbg]hio: port 1: digit 2 (code 0x12), tone
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.710[app:dbg]check item 0: 0x03FF/00000000,0 : <8>
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.710[app:dbg]regex_match_item: check route 0x312c08 repeat off rf 0, rt 0, crt 0, digit '8' mask 0x3FF
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.710[app:dbg]<cur match>: dial <8>r 0, dt 0, sub 0 {0,0}
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.710[app:dbg]check item 1: 0x03FF/00000000,0 : <3>
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.710[app:dbg]regex_match_item: check route 0x312c08 repeat off rf 0, rt 0, crt 0, digit '3' mask 0x3FF
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.711[app:dbg]<cur match>: dial <3>r 0, dt 0, sub 0 {0,0}
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.711[app:dbg]check item 2: 0x03FF/080000FF,0 : <4>
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.711[app:dbg]regex_match_item: check route 0x312c08 repeat on rf 0, rt 255(inf), crt 0, digit '4' mask 0x3FF
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.711[app:dbg]<cur match>: dial <4>r 1, dt 0, sub 0 r{0,255(inf)}
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.711[app:dbg]match ok: rf 0, crt 1, rt 255
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.711[app:dbg]check item 2: 0x03FF/080000FF,1 : <3>
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.711[app:dbg]regex_match_item: check route 0x312c08 repeat on rf 0, rt 255(inf), crt 1, digit '3' mask 0x3FF
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.711[app:dbg]<cur match>: dial <3>r 2, dt 0, sub 0 r{0,255(inf)}
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.712[app:dbg]match ok: rf 0, crt 2, rt 255
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.712[app:dbg]check item 2: 0x03FF/080000FF,2 : <3>
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.712[app:dbg]regex_match_item: check route 0x312c08 repeat on rf 0, rt 255(inf), crt 2, digit '3' mask 0x3FF
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.712[app:dbg]<cur match>: dial <3>r 3, dt 0, sub 0 r{0,255(inf)}
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.712[app:dbg]match ok: rf 0, crt 3, rt 255
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.712[app:dbg]check item 2: 0x03FF/080000FF,3 : <7>
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.712[app:dbg]regex_match_item: check route 0x312c08 repeat on rf 0, rt 255(inf), crt 3, digit '7' mask 0x3FF
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.712[app:dbg]<cur match>: dial <7>r 4, dt 0, sub 0 r{0,255(inf)}
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.712[app:dbg]match ok: rf 0, crt 4, rt 255
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.713[app:dbg]check item 2: 0x03FF/080000FF,4 : <6>
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.713[app:dbg]regex_match_item: check route 0x312c08 repeat on rf 0, rt 255(inf), crt 4, digit '6' mask 0x3FF
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.713[app:dbg]<cur match>: dial <6>r 5, dt 0, sub 0 r{0,255(inf)}
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.713[app:dbg]match ok: rf 0, crt 5, rt 255
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.713[app:dbg]check item 2: 0x03FF/080000FF,5 : <4>
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.713[app:dbg]regex_match_item: check route 0x312c08 repeat on rf 0, rt 255(inf), crt 5, digit '4' mask 0x3FF
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.713[app:dbg]<cur match>: dial <4>r 6, dt 0, sub 0 r{0,255(inf)}
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.713[app:dbg]match ok: rf 0, crt 6, rt 255
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.713[app:dbg]check item 2: 0x03FF/080000FF,6 : <0>
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.714[app:dbg]regex_match_item: check route 0x312c08 repeat on rf 0, rt 255(inf), crt 6, digit '0' mask 0x3FF
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.714[app:dbg]<cur match>: dial <0>r 7, dt 0, sub 0 r{0,255(inf)}
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.714[app:dbg]match ok: rf 0, crt 7, rt 255
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.714[app:dbg]check item 2: 0x03FF/080000FF,7 : <6>
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.714[app:dbg]regex_match_item: check route 0x312c08 repeat on rf 0, rt 255(inf), crt 7, digit '6' mask 0x3FF
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.714[app:dbg]<cur match>: dial <6>r 8, dt 0, sub 0 r{0,255(inf)}
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.714[app:dbg]match ok: rf 0, crt 8, rt 255
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.714[app:dbg]check item 2: 0x03FF/080000FF,8 : <2>
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.714[app:dbg]regex_match_item: check route 0x312c08 repeat on rf 0, rt 255(inf), crt 8, digit '2' mask 0x3FF
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.715[app:dbg]<cur match>: dial <2>r 9, dt 0, sub 0 r{0,255(inf)}
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.715[app:dbg]match ok: rf 0, crt 9, rt 255
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.715[app:dbg]end of items - test dial ended
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.715[app:dbg]check 'cant dial more' out of the cycle: item 2, crt 9, r{0,255(inf)}
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.715[app:dbg]MATCH: fulldialed 1, can`t dial more 0, dialtone 0
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.715[app:dbg]01: [3,]
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.715[app:dbg]port_process_digit() regex route 0x312c08, final 1, dt 0
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.715[app:dbg]port 1: process final route
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.810[app:dbg]vapi_proc_event: eVAPI_TONE_DETECT_EVENT
Jan  1 06:04:11 192.168.3.5 syslog: 06:04:11.810[app:dbg]vapi: tone detect: Conn 1. End of signal <DTMF digit 2>, duration 110 ms
Jan  1 06:04:12 192.168.3.5 syslog: 06:04:12.030[app:dbg]port 1: regex per sec timeout
Jan  1 06:04:13 192.168.3.5 syslog: 06:04:13.020[app:dbg]port 1: regex per sec timeout
Jan  1 06:04:13 192.168.3.5 syslog: 06:04:13.350[app:dbg]vapi_proc_event: eVAPI_TONE_DETECT_EVENT
Jan  1 06:04:13 192.168.3.5 syslog: 06:04:13.350[app:dbg]vapi: tone detect: Conn 1. Detect signal <T.30 CNG start detected (fax calling tone)> (level 8 dBov)
Jan  1 06:04:13 192.168.3.5 syslog: 06:04:13.745[app:dbg]vapi_proc_event: eVAPI_TONE_DETECT_EVENT
Jan  1 06:04:13 192.168.3.5 syslog: 06:04:13.745[app:dbg]vapi: tone detect: Conn 1. End of signal <T.30 CNG start detected (fax calling tone)>, duration 500 ms
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.020[app:dbg]port 1: regex per sec timeout
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.020[app:dbg]SLIC 1: final action
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.020[app:dbg]pbx: allocating memory for new call
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.020[app:dbg]pbx: created new outgoing call for SLIC 1
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.020[app:dbg]self_call_create (4187): created
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.020[app:dbg]free_final_mx: final_mx was NULL for SLIC 1
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.020[app:dbg]SLIC 1: -> calling to sip//83433764062
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.021[app:dbg]ext: 0
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.021[app:dbg]pbx -[msg_call]-> sip
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.021[app:dbg]CMD_STOP_TONE: port = 1
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.021[app:dbg]Port 1: check vapi queue ('free') at vapi_stop_tone_chan:1353
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.021[app:dbg]Chan 1: current state is CREATED
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.021[app:dbg]vapi_chan.c:1389: conn 1 peek cmd 'no event' from queue
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.021[app:dbg]Port 1: check vapi queue ('free') at __cmd_engine:302
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.021[app:dbg]Port 1: check vapi queue ('free') at vapi_next_ops:2408
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.022[app:dbg]Port 1: user port 3, old state calling, new state 
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.022[app:dbg]Set port 1 led to state 'LED_ON'
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.022[app:dbg]pbx -[msg_fxs_state]-> group
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.022[app:dbg]regex ID 1: dial reset
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.023[app:dbg]ITC: [msg_call] -> sip
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.023[app:dbg]sip: outgoing call 00010001 from endpoint 1 to 83433764062@(null)
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.023[app:dbg]available RTP ports: 23000...26000
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.023[app:dbg]selected port for current call: 23004
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.023[app:dbg]sip_params_create() normal - using cur proxy [192.168.254.253:5060] if proxy call
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.023[app:dbg]stun_get_public_ip(port = 8000)
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.023[app:dbg]stun_get_public_ip: Always using local IP
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.023[app:dbg]sip: to host is <(null)> - should not have port; to user is <83433764062>, use proxy - yes
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.024[app:dbg]sip_params_create() send to is <sip:83433764062@192.168.254.253:5060>, <not outbound>
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.024[app:dbg]sip_params_create() target,request url is <sip:83433764062@tagnet.tagnet.cc>
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.024[app:dbg]sip: call 00010001: sip  INVITE from sip:599@tagnet.tagnet.cc to sip:83433764062@tagnet.tagnet.cc
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.024[app:dbg]sip: call 00010001: targeturl is <sip:83433764062@tagnet.tagnet.cc>
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.024[app:dbg]build contact field with To-Host '192.168.254.253:5060'
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.024[app:dbg]stun_get_public_ip(port = 5060)
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.025[app:dbg]stun_get_public_ip: Always using local IP
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.025[app:dbg]stun_get_public_ip(port = 23004)
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.025[app:dbg]stun_get_public_ip: Always using local IP
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.025[app:dbg]sdp_codecs_init() init call sdp (offer)
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.026[app:dbg]sdp_codecs_dump() ssup present off, ecan absent on, rfc present 101, nse absent 0, ptime present 20
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.026[app:dbg]sdp_codecs_dump() G723: none
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.026[app:dbg]sdp_codecs_dump() G711A:
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.026[app:dbg]sdp_codecs_dump() PT 8, vbd absent off
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.026[app:dbg]sdp_codecs_dump() G711U: none
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.026[app:dbg]sdp_codecs_g711a_add_to_media_attrs() g711a: have one at last
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.026[app:dbg]sdp_codecs_rfc2833_add_to_media_attrs() present, pt 101
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.026[app:dbg]sdp_codecs_nse_add_to_media_attrs() absent, pt 0
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.026[app:dbg]sdp_codecs_ptime_add_to_attrs() ptime present 20
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.027[app:dbg]sdp_codecs_ecan_add_to_attrs() ecan absent on
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.027[app:dbg]sdp_codecs_ssup_add_to_attrs() ssup present off
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.027[app:dbg]sdp_tail:  8 101#012a=rtpmap:8 PCMA/8000#012a=rtpmap:101 telephone-event/8000#012a=fmtp:101 0-16#012a=ptime:20#012a=silenceSupp:off - - - -
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.027[app:dbg]make_sdp: SDP: s=Session SDP#012m=audio 23004 RTP/AVP 8 101#012a=rtpmap:8 PCMA/8000#012a=rtpmap:101 telephone-event/8000#012a=fmtp:101 0-16#012a=ptime:20#012a=silenceSupp:off - - - -
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.027[app:dbg]sip: get_support_params: profile 0 supported: 'timer, 100rel, replaces'
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.027[app:dbg]ITC: [msg_fxs_state] -> group
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.028[app:dbg]-----[GM] self_fxs_state()
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.028[app:dbg]Port 1: new state is calling
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.030[app:dbg]got nua_r_set_params : 200(OK)
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.030[app:dbg]NO SIP IN nua_r_set_params == 200 : OK
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.047[app:dbg]got nua_i_state : 0(INVITE sent)
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.047[app:dbg]NO SIP IN nua_i_state == 0 : INVITE sent
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.047[app:dbg]self_i_state(): call state 2: os : local sdp : sdp_init no_oc
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.047[app:dbg]sip: call 00010001: SDP offer sent
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.047[app:dbg]self_create_local_media() 0: add rtpmap 8
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.048[app:dbg]self_create_local_media() 1: add rtpmap 101
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.048[app:dbg]sip: call 00010001: media stream 0, creating proposed audio channel, local RTP 192.168.3.5:23004, rtpmaps cnt: 2
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.048[app:dbg]sip: call 00010001: local SDP offer copy
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.061[app:dbg]got nua_r_invite : 100(Trying)
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.061[app:dbg]sip: call 00010001: INVITE: 100 Trying
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.061[app:dbg]Contact/Record-route on answer to INVITE: sip:83433764062@192.168.254.253:5060
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.061[app:dbg]Setup new proxy addr for call; sip:83433764062@192.168.254.253:5060
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.062[app:dbg]call 00065537 got 100/Trying - set received_1xx
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.062[app:dbg]got nua_r_set_params : 200(OK)
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.062[app:dbg]NO SIP IN nua_r_set_params == 200 : OK
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.427[app:dbg]got nua_r_invite : 183(Progress)
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.427[app:dbg]sip: call 00010001: INVITE: 183 Progress
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.427[app:dbg]Contact/Record-route on answer to INVITE: sip:83433764062@192.168.254.253:5060
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.428[app:dbg]Setup new proxy addr for call; sip:83433764062@192.168.254.253:5060
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.428[app:dbg]call 00065537 got 183/Progress - set received_1xx
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.428[app:dbg]sip: call 00010001: ringing back
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.428[app:dbg]attr: name: ptime value: 20
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.429[app:dbg]sdp_codecs_set_ptime() ptime present : 20
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.429[app:dbg]attr: name: silenceSupp value: off - - - -
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.429[app:dbg]sip: call 00010001: 183 ringing with SDP descr
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.429[app:dbg]sip -[msg_free]-> pbx
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.429[app:dbg]sip: call 00010001: current status (183)
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.429[app:dbg]ITC: [msg_free] -> pbx
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.429[app:dbg]SLIC 1: peer ringing
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.429[app:dbg]SLIC 1: -> ringback (0)
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.433[app:dbg]got nua_i_state : 183(Progress)
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.434[app:dbg]NO SIP IN nua_i_state == 183 : Progress
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.434[app:dbg]self_i_state(): call state 3: ar : remote sdp : sdp_sent have_oc
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.434[app:dbg]sip: call 00010001: SDP answer received
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.434[app:dbg]sip: call 00010001: calltype 1, mode_codec 0, codec 0
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.434[app:dbg]sip: call 00010001: SDP answer received
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.434[app:dbg]self_destroy_current_media() nothing to destroy
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.434[app:dbg]sdp_codecs_get_rfc2833: present=1 pt=101
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.434[app:dbg]sdp_codecs_set_rfc2833() present pt 101 remote fmtp 0-15, local fmtp 0-15
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.435[app:dbg]self_start_media: 1. handle call id 0x00010001, call id 0x00010001
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.435[app:dbg]sip: set options: call 00010001: media stream 0: 192.168.3.5:23004 -> 192.168.254.253:17170: MFPT 0 <drop>
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.435[app:dbg]self_itc_codec(): payload 8
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.435[app:dbg]sip_set_rxtx_opts(): check rtpm <PCMA>:8
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.435[app:dbg]sip_set_rxtx_opts(): check offered 0: 8
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.435[app:dbg]self_itc_codec(): payload 8
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.435[app:dbg]Supported codec[0]: <G.711A>:8, vbd off, vad off, ecan on
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.435[app:dbg]validate_ptime() codec G.711A, ptime 20, check_bigger 1, present 1
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.435[app:dbg]validate_ptime() using 20
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.436[app:dbg]sdp_codecs_set_ptime() ptime present : 20
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.436[app:dbg]sip_set_rxtx_opts(): check rtpm <telephone-event>:101
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.436[app:dbg]sip_set_rxtx_opts(): check offered 0: 8
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.436[app:dbg]sip_set_rxtx_opts(): check offered 1: 101
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.436[app:dbg]self_itc_codec(): payload 101
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.436[app:dbg]validate_ptime() codec G.711A, ptime 20, check_bigger 1, present 1
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.436[app:dbg]validate_ptime() using 20
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.436[app:dbg]sdp_codecs_set_ptime() ptime present : 20
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.436[app:dbg]sdp_codecs_get_rfc2833: present=1 pt=101
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.436[app:dbg]validate_ptime() codec G.711A, ptime 20, check_bigger 1, present 1
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.437[app:dbg]validate_ptime() using 20
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.437[app:dbg]sdp_codecs_set_ptime() ptime present : 20
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.437[app:dbg]self_start_media: 2. handle call id 0x00010001, call id 0x00010001
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.437[app:dbg]sip -[msg_set_media]-> pbx
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.430[app:dbg]CMD_STOP_TONE: port = 1
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.440[app:dbg]Port 1: check vapi queue ('free') at vapi_stop_tone_chan:1353
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.440[app:dbg]Chan 1: current state is CREATED
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.440[app:dbg]vapi_chan.c:1389: conn 1 peek cmd 'no event' from queue
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.440[app:dbg]Port 1: check vapi queue ('free') at __cmd_engine:302
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.440[app:dbg]Port 1: check vapi queue ('free') at vapi_next_ops:2408
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.441[app:dbg]Port 1: user port 3, old state ringback, new state 
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.441[app:dbg]Set port 1 led to state 'LED_ON'
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.441[app:dbg]pbx -[msg_fxs_state]-> group
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.441[app:dbg]ITC: [msg_fxs_state] -> group
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.442[app:dbg]-----[GM] self_fxs_state()
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.442[app:dbg]Port 1: new state is ringback
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.442[app:dbg]got nua_r_set_params : 200(OK)
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.442[app:dbg]NO SIP IN nua_r_set_params == 200 : OK
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.443[app:dbg]got nua_r_set_params : 200(OK)
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.443[app:dbg]NO SIP IN nua_r_set_params == 200 : OK
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.450[app:dbg]ITC: [msg_set_media] -> pbx
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.450[app:dbg]self_on_set_media: call id 0x00010001 tx/rx 1/1
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.450[app:dbg]dump_port_calls() SLIC 1:
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.450[app:dbg]Q:(0x31e800,0x00010001,(nil))
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.450[app:dbg]H:((nil),0x00000000,(nil),0) W:((nil),0x00000000,(nil)) N:((nil),0x00000000,(nil)) H2:((nil),0x00000000,(nil))
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.450[app:dbg]SLIC 1: TX start / RX start: 192.168.3.5:23004->192.168.254.253:17170, <G.711A:8>
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.451[app:dbg]SLIC 1: send only 0 vad 0 g723_hr 1 vbd 0, ecan 1 rfc2833 pt 101, NSE pt 0, MFPT 0
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.451[app:dbg]self_set_media_start(): set ptime to 20
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.451[app:dbg]port_set_ip_param
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.451[app:dbg]set media param for '1', 192.168.3.5:23004, mode=local, random 6
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.451[app:dbg]port_set_ip_param
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.451[app:dbg]set media param for '1', 192.168.254.253:17170, mode=remote, random 6
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.451[app:dbg]CMD_CREATE_CONN: port = 1
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.451[app:dbg]Port 1: check vapi queue ('free') at vapi_create_chan:573
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.451[app:dbg]Chan 1: current state is CREATED
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.451[app:dbg]chan 1: no need to create - already exists
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.452[app:dbg]Port 1: check vapi queue ('free') at __cmd_engine:302
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.452[app:dbg]Port 1: check vapi queue ('free') at vapi_next_ops:2408
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.452[app:dbg]SLIC 1: starting media (G.711A) 192.168.3.5:23004 -> 192.168.254.253:17170
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.452[app:dbg]port 1: start voice - first time
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.452[app:dbg]port_start_voice() chan 01: remote IP <192.168.254.253> (arp query 0 times)
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.452[app:dbg]chan 1: get mac succesfull, repeat 0 times
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.452[app:dbg]CMD_START_VOICE: port = 1
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.452[app:dbg]vapi_set_chan_param: chan=1 hold=0 deactivate=0
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.452[app:dbg]Port 1: check vapi queue ('free') at vapi_set_chan_param:2015
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.452[app:dbg]Chan 1: current state is CREATED
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.453[app:dbg]Port 1: set vapi queue MSP to 'busy' with 'start voice' at vapi_set_chan_param:2036
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.453[app:dbg]VQ Conn 1 = MSP :   'start voice' =
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.453[app:dbg]Conn 1 Eth src=a8:f9:4b:03:8b:47, dst=00:00:00:00:00:00
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.453[app:dbg]Conn 1 IP src=192.168.3.5:23004, dst=192.168.254.253:17170
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.453[app:dbg]CHECK REQID: 0x00000502(Conn 1)
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.453[app:dbg]vapi: Conn 1. Disable - Ok
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.454[app:dbg]vapi_cb_req: 1 0 result 0x00000000 requid 0x00000502
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.460[app:dbg]vapi_proc_event: VAPI_CB
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.460[app:dbg]vapi_cb_chan: chan 1 reqest_id 0x00000502 result 0x00000000
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.460[app:dbg]VOIP_DISABLE: chan = 1
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.460[app:dbg]vapi_cb_setchan: chan 1 deactivate 0
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.460[app:dbg]vapi: create: TDM channel 1 Set SSRC to 1C55245D
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.460[app:dbg]vapi: Conn 1. Set src/dst eth mac - Ok
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.461[app:dbg]Reserved IP: 192.168.253.1
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.461[app:dbg]vapi_cb_setchan: ch1. msp_ip = 192.168.253.2
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.461[app:dbg]IP PARAMS: 1FDA8C0 30004 2FDA8C0 30004
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.461[app:dbg]vapi: Conn 1. Set src/dst ip addr - ok
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.462[app:dbg]Create RX-TX media for SLIC 1(sendonly: 0, rtcp: 0)
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.465[app:dbg]vapi_cb_req: 1 0 result 0x00000000 requid 0x00000508
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.470[app:dbg]vapi_proc_event: VAPI_CB
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.470[app:dbg]vapi_cb_chan: chan 1 reqest_id 0x00000508 result 0x00000000
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.470[app:dbg]VOIP_SET_IP: chan = 1
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.470[app:dbg]vapi_cb_setchan: chan 1 deactivate 0
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.470[app:dbg]chan 1. vapi_cb_setchan: configure ecan on
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.470[app:dbg]vapi_passthru_echocan_cb() NLP, DCRF enabled, session 0, on 1, value 0x8007
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.471[app:dbg]vapi_cb_req: 1 0 result 0x00000000 requid 0x00000547
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.480[app:dbg]vapi_proc_event: VAPI_CB
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.480[app:dbg]vapi_cb_chan: chan 1 reqest_id 0x00000547 result 0x00000000
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.480[app:dbg]VOIP_SSRC_FILT: chan = 1
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.480[app:dbg]vapi_cb_setchan: chan 1 deactivate 0
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.480[app:dbg]chan 1. vapi_cb_setchan: VOIP_SSRC_FILT
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.480[app:dbg]vapi_cb_setchan: ch1. msp_ip = 192.168.253.2
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.481[app:dbg]RTCP IP PARAMS: 1FDA8C0 30005 2FDA8C0 30005
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.485[app:dbg]vapi_cb_req: 1 0 result 0x00000000 requid 0x0000052b
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.490[app:dbg]vapi_proc_event: VAPI_CB
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.490[app:dbg]vapi_cb_chan: chan 1 reqest_id 0x0000052b result 0x00000000
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.490[app:dbg]VOIP_SET_IP2: chan = 1
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.490[app:dbg]vapi_cb_setchan: chan 1 deactivate 0
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.490[app:dbg]chan 1. vapi_cb_setchan: VOIP_SET_PT
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.491[app:dbg]for chan <1> set codec type = 5 'G711A'
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.492[app:dbg]vapi_cb_req: 1 0 result 0x00000000 requid 0x0000054e
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.500[app:dbg]vapi_proc_event: VAPI_CB
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.500[app:dbg]vapi_cb_chan: chan 1 reqest_id 0x0000054e result 0x00000000
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.500[app:dbg]UNKNOWN_CMD: chan = 1
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.500[app:dbg]vapi_cb_setchan: chan 1 deactivate 0
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.500[app:dbg]chan 1. vapi_cb_setchan: VOIP_SET_CODEC
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.500[app:dbg]set_packet_interval = 20
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.500[app:dbg]vapi: Conn 1. Set 'Packet interval' 20
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.501[app:dbg]chan 1. vapi_cb_setchan: VOIP_SET_PACKET
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.501[app:dbg]SET TX PT: 101
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.501[app:dbg]vapi_cb_req: 1 0 result 0x00000000 requid 0x00000510
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.510[app:dbg]vapi_proc_event: VAPI_CB
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.510[app:dbg]vapi_cb_chan: chan 1 reqest_id 0x00000510 result 0x00000000
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.510[app:dbg]VOIP_SET_PACKET2: chan = 1
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.510[app:dbg]vapi_cb_setchan: chan 1 deactivate 0
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.510[app:dbg]chan 1. vapi_cb_setchan: VOIP_SET_PACKET2
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.510[app:dbg]SET RX PT: 101
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.511[app:dbg]vapi_cb_req: 1 0 result 0x00000000 requid 0x00000513
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.520[app:dbg]vapi_proc_event: VAPI_CB
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.520[app:dbg]vapi_cb_chan: chan 1 reqest_id 0x00000513 result 0x00000000
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.520[app:dbg]VOIP_SET_DTMFOPT: chan = 1
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.520[app:dbg]vapi_cb_setchan: chan 1 deactivate 0
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.520[app:dbg]vapi: Chan 1 set chach (packet mode)
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.520[app:dbg]chan 1. vapi_cb_setchan: VOIP_SET_DTMFOPT dtmf 1, pt 101
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.521[app:dbg]Enable RFC2833 events
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.521[app:dbg]Set RFC2833 PT: 101(01A6, 65FF)
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.521[app:dbg]chan 1. vapi_cb_setchan: VOIP_SET_DTMFOPT2
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.521[app:dbg]chan 1. vapi_cb_setchan: VOIP_SET_PT2
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.521[app:dbg]vapi: Conn 1. Enable RTP indication
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.521[app:dbg]chan 1. vapi_cb_setchan: VOIP_ENABLE_RTP_IND
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.521[app:dbg]chan 1: set jitter buffer options
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.521[app:dbg]chan 1. vapi_cb_setchan: VOIP_SET_INDCTL
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.521[app:dbg]chan 1. vapi_cb_setchan: VOIP_SET_JBOPT
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.521[app:dbg]vapi: Conn 1. Set tone ctl options
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.522[app:dbg]chan 1. vapi_cb_setchan: VOIP_SET_VLAN
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.522[app:dbg]VAD: 0 CNG: 0 PTE: 20
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.526[app:dbg]vapi_cb_req: 1 0 result 0x00000000 requid 0x00000516
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.530[app:dbg]vapi_proc_event: VAPI_CB
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.530[app:dbg]vapi_cb_chan: chan 1 reqest_id 0x00000516 result 0x00000000
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.530[app:dbg]VOIP_SET_VCEOPT: chan = 1
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.530[app:dbg]vapi_cb_setchan: chan 1 deactivate 0
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.530[app:dbg]chan 1. vapi_cb_setchan: VOIP_SET_VCEOPT
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.532[app:dbg]vapi_cb_req: 1 0 result 0x00000000 requid 0x00000518
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.540[app:dbg]vapi_proc_event: VAPI_CB
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.540[app:dbg]vapi_cb_chan: chan 1 reqest_id 0x00000518 result 0x00000000
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.540[app:dbg]VOIP_SET_VOICE: chan = 1
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.540[app:dbg]vapi_cb_setchan: chan 1 deactivate 0
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.540[app:dbg]vapi_cb_setchan() Conn 1: set eActive state ok
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.540[app:dbg]Port 1: check vapi queue ('busy''start voice') at vapi_next_ops:2408
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.741[app:dbg]vapi_proc_event: eVAPI_UNDEFINED_EVENT
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.741[app:dbg]vapi: Conn 1. event 'RTP Monitor Ind': Start RTP stream , PT 0x0008 'PCM-A', silence 0
Jan  1 06:04:14 192.168.3.5 syslog: 06:04:14.750[app:dbg]vapi: generic event, code 5 <SSRC change>, conn 10
Jan  1 06:04:16 192.168.3.5 syslog: 06:04:16.304[app:dbg]vapi_proc_event: eVAPI_UNDEFINED_EVENT
Jan  1 06:04:16 192.168.3.5 syslog: 06:04:16.304[app:dbg]vapi: event Fax CNG detected (timestamp 58006)
Jan  1 06:04:16 192.168.3.5 syslog: 06:04:16.845[app:dbg]vapi_proc_event: eVAPI_TONE_DETECT_EVENT
Jan  1 06:04:16 192.168.3.5 syslog: 06:04:16.845[app:dbg]vapi: tone detect: Conn 1. Detect signal <T.30 CNG start detected (fax calling tone)> (level 20 dBov)
Jan  1 06:04:17 192.168.3.5 syslog: 06:04:17.250[app:dbg]vapi_proc_event: eVAPI_TONE_DETECT_EVENT
Jan  1 06:04:17 192.168.3.5 syslog: 06:04:17.250[app:dbg]vapi: tone detect: Conn 1. End of signal <T.30 CNG start detected (fax calling tone)>, duration 500 ms
Jan  1 06:04:19 192.168.3.5 syslog: 06:04:19.785[app:dbg]vapi_proc_event: eVAPI_UNDEFINED_EVENT
Jan  1 06:04:19 192.168.3.5 syslog: 06:04:19.785[app:dbg]vapi: event Fax CNG detected (timestamp 85846)
Jan  1 06:04:20 192.168.3.5 syslog: 06:04:20.345[app:dbg]vapi_proc_event: eVAPI_TONE_DETECT_EVENT
Jan  1 06:04:20 192.168.3.5 syslog: 06:04:20.345[app:dbg]vapi: tone detect: Conn 1. Detect signal <T.30 CNG start detected (fax calling tone)> (level 20 dBov)
Jan  1 06:04:20 192.168.3.5 syslog: 06:04:20.750[app:dbg]vapi_proc_event: eVAPI_TONE_DETECT_EVENT
Jan  1 06:04:20 192.168.3.5 syslog: 06:04:20.750[app:dbg]vapi: tone detect: Conn 1. End of signal <T.30 CNG start detected (fax calling tone)>, duration 500 ms
Jan  1 06:04:21 192.168.3.5 syslog: 06:04:21.630[app:dbg]got nua_r_register : 200(Ok)
Jan  1 06:04:21 192.168.3.5 syslog: 06:04:21.630[app:dbg]sip: endpoint 0: REGISTER: 200 Ok
Jan  1 06:04:21 192.168.3.5 syslog: 06:04:21.630[app:dbg]Port 0: user port 2, old state hangup, new state 
Jan  1 06:04:21 192.168.3.5 syslog: 06:04:21.631[app:dbg]sip: endpoint 0: successfully registered
Jan  1 06:04:23 192.168.3.5 syslog: 06:04:23.285[app:dbg]vapi_proc_event: eVAPI_UNDEFINED_EVENT
Jan  1 06:04:23 192.168.3.5 syslog: 06:04:23.285[app:dbg]vapi: event Fax CNG detected (timestamp 113846)
Jan  1 06:04:23 192.168.3.5 syslog: 06:04:23.845[app:dbg]vapi_proc_event: eVAPI_TONE_DETECT_EVENT
Jan  1 06:04:23 192.168.3.5 syslog: 06:04:23.845[app:dbg]vapi: tone detect: Conn 1. Detect signal <T.30 CNG start detected (fax calling tone)> (level 20 dBov)
Jan  1 06:04:24 192.168.3.5 syslog: 06:04:24.250[app:dbg]vapi_proc_event: eVAPI_TONE_DETECT_EVENT
Jan  1 06:04:24 192.168.3.5 syslog: 06:04:24.250[app:dbg]vapi: tone detect: Conn 1. End of signal <T.30 CNG start detected (fax calling tone)>, duration 500 ms
Jan  1 06:04:26 192.168.3.5 syslog: 06:04:26.785[app:dbg]vapi_proc_event: eVAPI_UNDEFINED_EVENT
Jan  1 06:04:26 192.168.3.5 syslog: 06:04:26.785[app:dbg]vapi: event Fax CNG detected (timestamp 141846)
Jan  1 06:04:27 192.168.3.5 syslog: 06:04:27.345[app:dbg]vapi_proc_event: eVAPI_TONE_DETECT_EVENT
Jan  1 06:04:27 192.168.3.5 syslog: 06:04:27.345[app:dbg]vapi: tone detect: Conn 1. Detect signal <T.30 CNG start detected (fax calling tone)> (level 20 dBov)
Jan  1 06:04:27 192.168.3.5 syslog: 06:04:27.750[app:dbg]vapi_proc_event: eVAPI_TONE_DETECT_EVENT
Jan  1 06:04:27 192.168.3.5 syslog: 06:04:27.750[app:dbg]vapi: tone detect: Conn 1. End of signal <T.30 CNG start detected (fax calling tone)>, duration 500 ms
Jan  1 06:04:30 192.168.3.5 syslog: 06:04:30.285[app:dbg]vapi_proc_event: eVAPI_UNDEFINED_EVENT
Jan  1 06:04:30 192.168.3.5 syslog: 06:04:30.285[app:dbg]vapi: event Fax CNG detected (timestamp 169846)
Jan  1 06:04:30 192.168.3.5 syslog: 06:04:30.845[app:dbg]vapi_proc_event: eVAPI_TONE_DETECT_EVENT
Jan  1 06:04:30 192.168.3.5 syslog: 06:04:30.845[app:dbg]vapi: tone detect: Conn 1. Detect signal <T.30 CNG start detected (fax calling tone)> (level 20 dBov)
Jan  1 06:04:31 192.168.3.5 syslog: 06:04:31.250[app:dbg]vapi_proc_event: eVAPI_TONE_DETECT_EVENT
Jan  1 06:04:31 192.168.3.5 syslog: 06:04:31.250[app:dbg]vapi: tone detect: Conn 1. End of signal <T.30 CNG start detected (fax calling tone)>, duration 500 ms
Jan  1 06:04:33 192.168.3.5 syslog: 06:04:33.785[app:dbg]vapi_proc_event: eVAPI_UNDEFINED_EVENT
Jan  1 06:04:33 192.168.3.5 syslog: 06:04:33.785[app:dbg]vapi: event Fax CNG detected (timestamp 197846)
Jan  1 06:04:34 192.168.3.5 syslog: 06:04:34.345[app:dbg]vapi_proc_event: eVAPI_TONE_DETECT_EVENT
Jan  1 06:04:34 192.168.3.5 syslog: 06:04:34.345[app:dbg]vapi: tone detect: Conn 1. Detect signal <T.30 CNG start detected (fax calling tone)> (level 20 dBov)
Jan  1 06:04:34 192.168.3.5 syslog: 06:04:34.750[app:dbg]vapi_proc_event: eVAPI_TONE_DETECT_EVENT
Jan  1 06:04:34 192.168.3.5 syslog: 06:04:34.750[app:dbg]vapi: tone detect: Conn 1. End of signal <T.30 CNG start detected (fax calling tone)>, duration 500 ms
Jan  1 06:04:37 192.168.3.5 syslog: 06:04:37.285[app:dbg]vapi_proc_event: eVAPI_UNDEFINED_EVENT
Jan  1 06:04:37 192.168.3.5 syslog: 06:04:37.285[app:dbg]vapi: event Fax CNG detected (timestamp 225846)
Jan  1 06:04:37 192.168.3.5 syslog: 06:04:37.845[app:dbg]vapi_proc_event: eVAPI_TONE_DETECT_EVENT
Jan  1 06:04:37 192.168.3.5 syslog: 06:04:37.845[app:dbg]vapi: tone detect: Conn 1. Detect signal <T.30 CNG start detected (fax calling tone)> (level 20 dBov)
Jan  1 06:04:38 192.168.3.5 syslog: 06:04:38.250[app:dbg]vapi_proc_event: eVAPI_TONE_DETECT_EVENT
Jan  1 06:04:38 192.168.3.5 syslog: 06:04:38.250[app:dbg]vapi: tone detect: Conn 1. End of signal <T.30 CNG start detected (fax calling tone)>, duration 500 ms
Jan  1 06:04:38 192.168.3.5 syslog: 06:04:38.797[app:dbg]got nua_r_register : 200(Ok)
Jan  1 06:04:38 192.168.3.5 syslog: 06:04:38.797[app:dbg]sip: endpoint 3: REGISTER: 200 Ok
Jan  1 06:04:38 192.168.3.5 syslog: 06:04:38.797[app:dbg]Port 3: user port 1, old state hangup, new state 
Jan  1 06:04:38 192.168.3.5 syslog: 06:04:38.798[app:dbg]sip: endpoint 3: successfully registered
Jan  1 06:04:40 192.168.3.5 syslog: 06:04:40.785[app:dbg]vapi_proc_event: eVAPI_UNDEFINED_EVENT
Jan  1 06:04:40 192.168.3.5 syslog: 06:04:40.785[app:dbg]vapi: event Fax CNG detected (timestamp 253846)
Jan  1 06:04:41 192.168.3.5 syslog: 06:04:41.345[app:dbg]vapi_proc_event: eVAPI_TONE_DETECT_EVENT
Jan  1 06:04:41 192.168.3.5 syslog: 06:04:41.345[app:dbg]vapi: tone detect: Conn 1. Detect signal <T.30 CNG start detected (fax calling tone)> (level 20 dBov)
Jan  1 06:04:41 192.168.3.5 syslog: 06:04:41.750[app:dbg]vapi_proc_event: eVAPI_TONE_DETECT_EVENT
Jan  1 06:04:41 192.168.3.5 syslog: 06:04:41.750[app:dbg]vapi: tone detect: Conn 1. End of signal <T.30 CNG start detected (fax calling tone)>, duration 500 ms
Jan  1 06:04:43 192.168.3.5 syslog: 06:04:43.282[app:dbg]got nua_r_invite : 200(OK)
Jan  1 06:04:43 192.168.3.5 syslog: 06:04:43.282[app:dbg]sip: call 00010001: INVITE: 200 OK
Jan  1 06:04:43 192.168.3.5 syslog: 06:04:43.282[app:dbg]sip: call 00010001: current status (200)
Jan  1 06:04:43 192.168.3.5 syslog: 06:04:43.283[app:dbg]got nua_i_state : 200(OK)
Jan  1 06:04:43 192.168.3.5 syslog: 06:04:43.283[app:dbg]NO SIP IN nua_i_state == 200 : OK
Jan  1 06:04:43 192.168.3.5 syslog: 06:04:43.284[app:dbg]self_i_state(): call state 4: : : sdp_init have_oc
Jan  1 06:04:43 192.168.3.5 syslog: 06:04:43.284[app:dbg]sip: call 00010001: call answered
Jan  1 06:04:43 192.168.3.5 syslog: 06:04:43.284[app:dbg]sip -[msg_answer]-> pbx
Jan  1 06:04:43 192.168.3.5 syslog: 06:04:43.284[app:dbg]sip: call 00010001: ACK to sip:83433764062@tagnet.tagnet.cc
Jan  1 06:04:43 192.168.3.5 syslog: 06:04:43.286[app:dbg]got nua_r_set_params : 200(OK)
Jan  1 06:04:43 192.168.3.5 syslog: 06:04:43.286[app:dbg]NO SIP IN nua_r_set_params == 200 : OK
Jan  1 06:04:43 192.168.3.5 syslog: 06:04:43.297[app:dbg]got nua_i_state : 200(ACK sent)
Jan  1 06:04:43 192.168.3.5 syslog: 06:04:43.297[app:dbg]NO SIP IN nua_i_state == 200 : ACK sent
Jan  1 06:04:43 192.168.3.5 syslog: 06:04:43.297[app:dbg]self_i_state(): call state 8: : : sdp_init have_oc
Jan  1 06:04:43 192.168.3.5 syslog: 06:04:43.298[app:dbg]sip: call 00010001: ACK from sip:599@tagnet.tagnet.cc
Jan  1 06:04:43 192.168.3.5 syslog: 06:04:43.299[app:dbg]got nua_i_active : 200(Call active)
Jan  1 06:04:43 192.168.3.5 syslog: 06:04:43.299[app:dbg]NO SIP IN nua_i_active == 200 : Call active
Jan  1 06:04:43 192.168.3.5 syslog: 06:04:43.290[app:dbg]ITC: [msg_answer] -> pbx
Jan  1 06:04:43 192.168.3.5 syslog: 06:04:43.300[app:dbg]SLIC 1: peer answered
Jan  1 06:04:43 192.168.3.5 syslog: 06:04:43.300[app:dbg]CMD_STOP_TONE: port = 1
Jan  1 06:04:43 192.168.3.5 syslog: 06:04:43.300[app:dbg]Port 1: check vapi queue ('busy''get statistic') at vapi_stop_tone_chan:1353
Jan  1 06:04:43 192.168.3.5 syslog: 06:04:43.300[app:dbg]Port 1 put cmd 'stop_tone',cur 'get statistic' to queue at (vapi_stop_tone_chan:1359)
Jan  1 06:04:43 192.168.3.5 syslog: 06:04:43.300[app:dbg]VQ Conn 1 + 04  :     'stop_tone'  + <-get_ptr 
Jan  1 06:04:43 192.168.3.5 syslog: 06:04:43.301[app:dbg]Port 1: user port 3, old state talking, new state 
Jan  1 06:04:43 192.168.3.5 syslog: 06:04:43.301[app:dbg]Set port 1 led to state 'LED_ON'
Jan  1 06:04:43 192.168.3.5 syslog: 06:04:43.301[app:dbg]pbx -[msg_fxs_state]-> group
Jan  1 06:04:43 192.168.3.5 syslog: 06:04:43.301[app:dbg]Port 1 get cmd 'stop_tone' from queue at (vapi_next_ops:2427)
Jan  1 06:04:43 192.168.3.5 syslog: 06:04:43.301[app:dbg]Port 1: check vapi queue ('free') at vapi_stop_tone_chan:1353
Jan  1 06:04:43 192.168.3.5 syslog: 06:04:43.302[app:dbg]Chan 1: current state is CREATED
Jan  1 06:04:43 192.168.3.5 syslog: 06:04:43.302[app:dbg]vapi_chan.c:1389: conn 1 peek cmd 'no event' from queue
Jan  1 06:04:43 192.168.3.5 syslog: 06:04:43.302[app:dbg]Port 1: check vapi queue ('free') at vapi_next_ops:2570
Jan  1 06:04:43 192.168.3.5 syslog: 06:04:43.302[app:dbg]Port 1: check vapi queue ('free') at vapi_next_ops:2408
Jan  1 06:04:43 192.168.3.5 syslog: 06:04:43.302[app:dbg]ITC: [msg_fxs_state] -> group
Jan  1 06:04:43 192.168.3.5 syslog: 06:04:43.303[app:dbg]-----[GM] self_fxs_state()
Jan  1 06:04:43 192.168.3.5 syslog: 06:04:43.303[app:dbg]Port 1: new state is talking
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.285[app:dbg]vapi_proc_event: eVAPI_UNDEFINED_EVENT
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.285[app:dbg]vapi: event Fax CNG detected (timestamp 281846)
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.290[app:dbg]Switch to FAX transfer with G.711A
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.290[app:dbg]pbx -[msg_mode]-> sip
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.290[app:dbg]ITC: [msg_mode] -> sip
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.290[app:dbg]sip: call 00010001: endpoint 1 need to change session to fax, G.711A
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.291[app:dbg]sdp_codecs_init() init call sdp (offer)
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.291[app:dbg]new media list:
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.291[app:dbg]Media 0: 0
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.291[app:dbg]Media 1: 0
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.291[app:dbg]Media 2: 0
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.291[app:dbg]Media 3: 0
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.291[app:dbg]Media 4: 0
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.291[app:dbg]new media list(fixed):
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.291[app:dbg]Media 0: 2
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.291[app:dbg]Media 1: 0
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.292[app:dbg]Media 2: 0
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.292[app:dbg]Media 3: 0
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.292[app:dbg]Media 4: 0
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.292[app:dbg]sdp_codecs_set_ssup() ssup present 1 ssup no
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.292[app:dbg]sdp_codecs_set_ecan() ecan present, on, dir fb, type -
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.292[app:dbg]sdp_codecs_g711_item_set_vbd() pt 8 vbd absent on
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.292[app:dbg]sdp_codecs_g711a_add_to_media_attrs() g711a: have one at last
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.292[app:dbg]sdp_codecs_rfc2833_add_to_media_attrs() present, pt 101
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.293[app:dbg]sdp_codecs_ptime_add_to_attrs() ptime present 20
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.293[app:dbg]sdp_codecs_ssup_add_to_attrs() ssup present off
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.293[app:dbg]sdp_codecs_ecan_add_to_attrs() ecan present on
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.293[app:dbg]put active audio media: m=audio 23004 RTP/AVP 8 101#012a=rtpmap:8 PCMA/8000#012a=rtpmap:101 telephone-event/8000#012a=fmtp:101 0-16#012a=ptime:20#012a=silenceSupp:off - - - -#012a=ecan:fb on -
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.294[app:dbg]sip: call 00010001: re-INVITE to sip:83433764062@tagnet.tagnet.cc
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.294[app:dbg]BUF: s=Session SDP#012m=audio 23004 RTP/AVP 8 101#012a=rtpmap:8 PCMA/8000#012a=rtpmap:101 telephone-event/8000#012a=fmtp:101 0-16#012a=ptime:20#012a=silenceSupp:off - - - -#012a=ecan:fb on -
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.294[app:dbg]sip: get_support_params: profile 0 supported: 'timer, 100rel, replaces'
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.312[app:dbg]got nua_i_state : 0(INVITE sent)
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.313[app:dbg]NO SIP IN nua_i_state == 0 : INVITE sent
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.313[app:dbg]self_i_state(): call state 2: os : local sdp : sdp_init have_oc
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.313[app:dbg]sip: call 00010001: SDP offer sent
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.313[app:dbg]self_create_local_media() 0: add rtpmap 8
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.313[app:dbg]self_create_local_media() 1: add rtpmap 101
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.313[app:dbg]sip: call 00010001: media stream 0, creating proposed audio channel, local RTP 192.168.3.5:23004, rtpmaps cnt: 2
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.313[app:dbg]sip: call 00010001: local SDP offer copy
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.316[app:dbg]got nua_r_invite : 100(Trying)
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.316[app:dbg]sip: call 00010001: INVITE: 100 Trying
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.316[app:dbg]call 00065537 got 100/Trying - set received_1xx
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.420[app:dbg]got nua_r_invite : 200(OK)
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.420[app:dbg]sip: call 00010001: INVITE: 200 OK
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.420[app:dbg]sip: call 00010001: current status (200)
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.431[app:dbg]got nua_i_state : 200(OK)
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.431[app:dbg]NO SIP IN nua_i_state == 200 : OK
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.431[app:dbg]self_i_state(): call state 8: ar : remote sdp : sdp_sent have_oc
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.432[app:dbg]sip: call 00010001: SDP answer received
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.432[app:dbg]sip: call 00010001: calltype 3, mode_codec 1, codec 1
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.432[app:dbg]sip: call 00010001: switch G.711A -> G.711A
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.432[app:dbg]sip: call 00010001: SDP answer received <change mode voice->voice! (reconfig)>
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.432[app:dbg]sip: call 00010001: destroying channel of media stream 0
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.432[app:dbg]call 0x00010001 (ep 1) :: TX stop, RX stop, <reconfigure> (self_destroy_current_media)
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.432[app:dbg]sip -[msg_set_media]-> pbx
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.432[app:dbg]sdp_codecs_get_rfc2833: present=1 pt=101
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.433[app:dbg]sdp_codecs_set_rfc2833() present pt 101 remote fmtp 0-15, local fmtp 0-15
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.433[app:dbg]self_start_media: 1. handle call id 0x00010001, call id 0x00010001
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.433[app:dbg]sip: set options: call 00010001: media stream 0: 192.168.3.5:23004 -> 192.168.254.253:17170: MFPT 1 <reconfigure>
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.433[app:dbg]self_itc_codec(): payload 8
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.433[app:dbg]sip_set_rxtx_opts(): check rtpm <PCMA>:8
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.433[app:dbg]sip_set_rxtx_opts(): check offered 0: 8
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.433[app:dbg]self_itc_codec(): payload 8
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.433[app:dbg]Supported codec[0]: <G.711A>:8, vbd on, vad off, ecan off
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.433[app:dbg]validate_ptime() codec G.711A, ptime 20, check_bigger 1, present 1
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.434[app:dbg]validate_ptime() using 20
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.434[app:dbg]sdp_codecs_set_ptime() ptime present : 20
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.434[app:dbg]sip_set_rxtx_opts(): check rtpm <telephone-event>:101
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.434[app:dbg]sip_set_rxtx_opts(): check offered 0: 8
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.434[app:dbg]sip_set_rxtx_opts(): check offered 1: 101
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.434[app:dbg]self_itc_codec(): payload 101
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.434[app:dbg]validate_ptime() codec G.711A, ptime 20, check_bigger 1, present 1
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.434[app:dbg]validate_ptime() using 20
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.434[app:dbg]sdp_codecs_set_ptime() ptime present : 20
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.434[app:dbg]sdp_codecs_get_rfc2833: present=1 pt=101
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.435[app:dbg]validate_ptime() codec G.711A, ptime 20, check_bigger 1, present 1
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.435[app:dbg]validate_ptime() using 20
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.435[app:dbg]sdp_codecs_set_ptime() ptime present : 20
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.435[app:dbg]self_start_media: 2. handle call id 0x00010001, call id 0x00010001
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.435[app:dbg]sip -[msg_set_media]-> pbx
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.435[app:dbg]sip: call 00010001: ACK from sip:599@tagnet.tagnet.cc
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.435[app:dbg]ITC: [msg_set_media] -> pbx
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.435[app:dbg]self_on_set_media: call id 0x00010001 tx/rx 0/0
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.436[app:dbg]dump_port_calls() SLIC 1:
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.436[app:dbg]Q:(0x31e800,0x00010001,(nil))
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.436[app:dbg]H:((nil),0x00000000,(nil),0) W:((nil),0x00000000,(nil)) N:((nil),0x00000000,(nil)) H2:((nil),0x00000000,(nil))
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.436[app:dbg]SLIC 1: TX stop / RX stop
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.436[app:dbg]SLIC 1: send only 0
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.436[app:dbg]CMD_SET_VOICE: port = 1
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.436[app:dbg]Port 1: check vapi queue ('free') at vapi_start_stop_chan:1502
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.436[app:dbg]Chan 1: current state is CREATED
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.436[app:dbg]vapi: Conn 1. start_stop voice chan, TX stop, RX stop
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.436[app:dbg]Port 1: set vapi queue MSP to 'busy' with 'set voice' at vapi_start_stop_chan:1545
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.437[app:dbg]VQ Conn 1 = MSP :     'set voice' =
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.437[app:dbg]vapi_cb_req: 1 0 result 0x00000000 requid 0x00000401
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.438[app:dbg]got nua_i_active : 200(Call active)
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.438[app:dbg]NO SIP IN nua_i_active == 200 : Call active
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.439[app:dbg]got nua_r_set_params : 200(OK)
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.439[app:dbg]NO SIP IN nua_r_set_params == 200 : OK
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.440[app:dbg]ITC: [msg_set_media] -> pbx
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.440[app:dbg]self_on_set_media: call id 0x00010001 tx/rx 1/1
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.440[app:dbg]dump_port_calls() SLIC 1:
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.440[app:dbg]Q:(0x31e800,0x00010001,(nil))
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.440[app:dbg]H:((nil),0x00000000,(nil),0) W:((nil),0x00000000,(nil)) N:((nil),0x00000000,(nil)) H2:((nil),0x00000000,(nil))
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.441[app:dbg]SLIC 1: TX start / RX start: 192.168.3.5:23004->192.168.254.253:17170, <G.711A:8>
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.441[app:dbg]SLIC 1: send only 0 vad 0 g723_hr 1 vbd 1, ecan 0 rfc2833 pt 101, NSE pt 0, MFPT 1
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.441[app:dbg]self_set_media_start(): set ptime to 20
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.441[app:dbg]port_set_ip_param
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.441[app:dbg]set media param for '1', 192.168.3.5:23004, mode=local, random 44
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.441[app:dbg]port_set_ip_param
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.441[app:dbg]set media param for '1', 192.168.254.253:17170, mode=remote, random 44
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.441[app:dbg]CMD_CREATE_CONN: port = 1
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.441[app:dbg]Port 1: check vapi queue ('busy''set voice') at vapi_create_chan:573
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.442[app:dbg]Port 1 put cmd 'create',cur 'set voice' to queue at (vapi_create_chan:579)
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.442[app:dbg]VQ Conn 1 = MSP :     'set voice' =
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.442[app:dbg]VQ Conn 1 + 05  :        'create'  + <-get_ptr 
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.442[app:dbg]SLIC 1: starting media (G.711A) 192.168.3.5:23004 -> 192.168.254.253:17170
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.442[app:dbg]port 1: start voice - first time
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.442[app:dbg]port_start_voice() chan 01: remote IP <192.168.254.253> (arp query 0 times)
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.442[app:dbg]chan 1: get mac succesfull, repeat 0 times
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.442[app:dbg]CMD_START_VOICE: port = 1
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.442[app:dbg]vapi_set_chan_param: chan=1 hold=0 deactivate=0
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.442[app:dbg]Port 1: check vapi queue ('busy''set voice') at vapi_set_chan_param:2015
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.443[app:dbg]Port 1 put cmd 'start voice',cur 'set voice' to queue at (vapi_set_chan_param:2024)
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.443[app:dbg]VQ Conn 1 = MSP :     'set voice' =
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.443[app:dbg]VQ Conn 1 + 05  :        'create'  + <-get_ptr 
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.443[app:dbg]VQ Conn 1 + 06  :   'start voice'  +  
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.443[app:dbg]vapi_proc_event: VAPI_CB
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.443[app:dbg]vapi_cb_chan: chan 1 reqest_id 0x00000401 result 0x00000000
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.443[app:dbg]vapi: conn 1. RTCP disabled
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.445[app:dbg]vapi_cb_req: 1 0 result 0x00000000 requid 0x000004ff
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.450[app:dbg]vapi_proc_event: VAPI_CB
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.450[app:dbg]vapi_cb_chan: chan 1 reqest_id 0x000004ff result 0x00000000
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.450[app:dbg]Conn 1: Set voice mode successeful
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.450[app:dbg]Stop all medias on chan 1
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.450[app:dbg]Port 1: check vapi queue ('busy''set voice') at vapi_next_ops:2408
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.450[app:dbg]Port 1 get cmd 'create' from queue at (vapi_next_ops:2427)
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.451[app:dbg]VQ Conn 1 + 06  :   'start voice'  + <-get_ptr 
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.451[app:dbg]Port 1: check vapi queue ('free') at vapi_create_chan:573
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.451[app:dbg]Chan 1: current state is CREATED
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.451[app:dbg]chan 1: no need to create - already exists
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.451[app:dbg]Port 1: check vapi queue ('free') at vapi_next_ops:2570
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.451[app:dbg]Port 1: check vapi queue ('free') at vapi_next_ops:2408
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.451[app:dbg]Port 1 get cmd 'start voice' from queue at (vapi_next_ops:2427)
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.451[app:dbg]vapi_set_chan_param: chan=1 hold=0 deactivate=0
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.451[app:dbg]Port 1: check vapi queue ('free') at vapi_set_chan_param:2015
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.451[app:dbg]Chan 1: current state is CREATED
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.452[app:dbg]Port 1: set vapi queue MSP to 'busy' with 'start voice' at vapi_set_chan_param:2036
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.452[app:dbg]VQ Conn 1 = MSP :   'start voice' =
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.452[app:dbg]Conn 1 Eth src=a8:f9:4b:03:8b:47, dst=00:00:00:00:00:00
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.452[app:dbg]Conn 1 IP src=192.168.3.5:23004, dst=192.168.254.253:17170
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.452[app:dbg]CHECK REQID: 0x00000582(Conn 1)
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.452[app:dbg]vapi: Conn 1. Disable - Ok
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.453[app:dbg]Mute all RX-TX medias on SLIC 1
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.453[app:dbg]Mute media on chan 1[mute 1]
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.453[app:dbg]vapi_cb_req: 1 0 result 0x00000000 requid 0x00000582
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.460[app:dbg]vapi_proc_event: VAPI_CB
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.460[app:dbg]vapi_cb_chan: chan 1 reqest_id 0x00000582 result 0x00000000
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.460[app:dbg]UNKNOWN_CMD: chan = 1
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.460[app:dbg]vapi_cb_setchan: chan 1 deactivate 0
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.460[app:dbg]vapi: create: TDM channel 1 Set SSRC to 76FAE5A2
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.461[app:dbg]vapi: Conn 1. Set src/dst eth mac - Ok
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.461[app:dbg]Reserved IP: 192.168.253.1
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.461[app:dbg]vapi_cb_setchan: ch1. msp_ip = 192.168.253.2
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.461[app:dbg]IP PARAMS: 1FDA8C0 30004 2FDA8C0 30004
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.461[app:dbg]vapi: Conn 1. Set src/dst ip addr - ok
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.462[app:dbg]Create RX-TX media for SLIC 1(sendonly: 0, rtcp: 0)
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.462[app:dbg]Can't bind - try to clear binding call from prev connection
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.462[app:dbg]Delete all RX-TX with RTP port = 23004
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.462[app:dbg]Clear media from SLIC 1
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.465[app:dbg]vapi_cb_req: 1 0 result 0x00000000 requid 0x00000588
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.470[app:dbg]VQ Conn 1 = MSP :   'start voice' =
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.470[app:dbg]vapi_proc_event: VAPI_CB
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.470[app:dbg]vapi_cb_chan: chan 1 reqest_id 0x00000588 result 0x00000000
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.470[app:dbg]UNKNOWN_CMD: chan = 1
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.470[app:dbg]vapi_cb_setchan: chan 1 deactivate 0
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.471[app:dbg]chan 1. vapi_cb_setchan: configure ecan off
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.471[app:dbg]vapi_passthru_echocan_cb() NLP, DCRF enabled, session 0, on 0, value 0x0000
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.472[app:dbg]vapi_cb_req: 1 0 result 0x00000000 requid 0x000005c7
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.480[app:dbg]vapi_proc_event: VAPI_CB
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.480[app:dbg]vapi_cb_chan: chan 1 reqest_id 0x000005c7 result 0x00000000
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.480[app:dbg]UNKNOWN_CMD: chan = 1
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.480[app:dbg]vapi_cb_setchan: chan 1 deactivate 0
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.480[app:dbg]chan 1. vapi_cb_setchan: VOIP_SSRC_FILT
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.480[app:dbg]vapi_cb_setchan: ch1. msp_ip = 192.168.253.2
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.481[app:dbg]RTCP IP PARAMS: 1FDA8C0 30005 2FDA8C0 30005
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.482[app:dbg]vapi_cb_req: 1 0 result 0x00000000 requid 0x000005ab
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.490[app:dbg]vapi_proc_event: VAPI_CB
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.490[app:dbg]vapi_cb_chan: chan 1 reqest_id 0x000005ab result 0x00000000
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.490[app:dbg]UNKNOWN_CMD: chan = 1
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.490[app:dbg]vapi_cb_setchan: chan 1 deactivate 0
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.490[app:dbg]chan 1. vapi_cb_setchan: VOIP_SET_PT
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.491[app:dbg]for chan <1> set codec type = 5 'G711A'
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.492[app:dbg]vapi_cb_req: 1 0 result 0x00000000 requid 0x000005ce
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.500[app:dbg]vapi_proc_event: VAPI_CB
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.500[app:dbg]vapi_cb_chan: chan 1 reqest_id 0x000005ce result 0x00000000
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.500[app:dbg]UNKNOWN_CMD: chan = 1
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.500[app:dbg]vapi_cb_setchan: chan 1 deactivate 0
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.500[app:dbg]chan 1. vapi_cb_setchan: VOIP_SET_CODEC
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.500[app:dbg]set_packet_interval = 20
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.501[app:dbg]vapi: Conn 1. Set 'Packet interval' 20
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.501[app:dbg]chan 1. vapi_cb_setchan: VOIP_SET_PACKET
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.501[app:dbg]SET TX PT: 101
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.511[app:dbg]vapi_cb_req: 1 0 result 0x00000000 requid 0x00000590
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.520[app:dbg]vapi: generic event, code 5 <SSRC change>, conn 10
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.530[app:dbg]vapi_proc_event: VAPI_CB
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.530[app:dbg]vapi_cb_chan: chan 1 reqest_id 0x00000590 result 0x00000000
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.530[app:dbg]UNKNOWN_CMD: chan = 1
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.530[app:dbg]vapi_cb_setchan: chan 1 deactivate 0
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.530[app:dbg]chan 1. vapi_cb_setchan: VOIP_SET_PACKET2
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.530[app:dbg]SET RX PT: 101
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.533[app:dbg]vapi_cb_req: 1 0 result 0x00000000 requid 0x00000593
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.540[app:dbg]vapi_proc_event: VAPI_CB
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.540[app:dbg]vapi_cb_chan: chan 1 reqest_id 0x00000593 result 0x00000000
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.540[app:dbg]UNKNOWN_CMD: chan = 1
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.540[app:dbg]vapi_cb_setchan: chan 1 deactivate 0
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.540[app:dbg]vapi: Chan 1 set chach (packet mode)
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.540[app:dbg]chan 1. vapi_cb_setchan: VOIP_SET_DTMFOPT dtmf 1, pt 101
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.541[app:dbg]Enable RFC2833 events
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.541[app:dbg]Set RFC2833 PT: 101(01A6, 65FF)
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.541[app:dbg]chan 1. vapi_cb_setchan: VOIP_SET_DTMFOPT2
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.541[app:dbg]chan 1. vapi_cb_setchan: VOIP_SET_PT2
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.541[app:dbg]vapi: Conn 1. Enable RTP indication
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.541[app:dbg]chan 1. vapi_cb_setchan: VOIP_ENABLE_RTP_IND
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.541[app:dbg]chan 1: set jitter buffer options
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.541[app:dbg]chan 1. vapi_cb_setchan: VOIP_SET_INDCTL
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.541[app:dbg]chan 1. vapi_cb_setchan: VOIP_SET_JBOPT
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.541[app:dbg]vapi: Conn 1. Set tone ctl options
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.541[app:dbg]chan 1. vapi_cb_setchan: VOIP_SET_VLAN
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.542[app:dbg]VAD: 0 CNG: 0 PTE: 20
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.547[app:dbg]vapi_cb_req: 1 0 result 0x00000000 requid 0x00000516
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.550[app:dbg]vapi_proc_event: VAPI_CB
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.550[app:dbg]vapi_cb_chan: chan 1 reqest_id 0x00000516 result 0x00000000
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.550[app:dbg]VOIP_SET_VCEOPT: chan = 1
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.550[app:dbg]vapi_cb_setchan: chan 1 deactivate 0
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.550[app:dbg]chan 1. vapi_cb_setchan: VOIP_SET_VCEOPT
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.553[app:dbg]vapi_cb_req: 1 0 result 0x00000000 requid 0x00000518
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.560[app:dbg]vapi_proc_event: VAPI_CB
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.560[app:dbg]vapi_cb_chan: chan 1 reqest_id 0x00000518 result 0x00000000
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.561[app:dbg]VOIP_SET_VOICE: chan = 1
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.561[app:dbg]vapi_cb_setchan: chan 1 deactivate 0
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.561[app:dbg]vapi_cb_setchan() Conn 1: set eActive state ok
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.561[app:dbg]Port 1: check vapi queue ('busy''start voice') at vapi_next_ops:2408
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.580[app:dbg]vapi_proc_event: eVAPI_UNDEFINED_EVENT
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.580[app:dbg]vapi: Conn 1. event 'RTP Monitor Ind': Start RTP stream , PT 0x0008 'PCM-A', silence 0
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.844[app:dbg]vapi_proc_event: eVAPI_TONE_DETECT_EVENT
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.844[app:dbg]vapi: tone detect: Conn 1. Detect signal <T.30 CNG start detected (fax calling tone)> (level 20 dBov)
Jan  1 06:04:44 192.168.3.5 syslog: 06:04:44.850[app:dbg]We do not process that event
Jan  1 06:04:45 192.168.3.5 syslog: 06:04:45.250[app:dbg]vapi_proc_event: eVAPI_TONE_DETECT_EVENT
Jan  1 06:04:45 192.168.3.5 syslog: 06:04:45.250[app:dbg]vapi: tone detect: Conn 1. End of signal <T.30 CNG start detected (fax calling tone)>, duration 500 ms
Jan  1 06:04:46 192.168.3.5 syslog: 06:04:46.870[app:dbg]got nua_r_register : 200(Ok)
Jan  1 06:04:46 192.168.3.5 syslog: 06:04:46.870[app:dbg]sip: endpoint 1: REGISTER: 200 Ok
Jan  1 06:04:46 192.168.3.5 syslog: 06:04:46.870[app:dbg]Port 1: user port 3, old state talking, new state 
Jan  1 06:04:46 192.168.3.5 syslog: 06:04:46.871[app:dbg]sip: endpoint 1: successfully registered
Jan  1 06:04:47 192.168.3.5 syslog: 06:04:47.785[app:dbg]vapi_proc_event: eVAPI_UNDEFINED_EVENT
Jan  1 06:04:47 192.168.3.5 syslog: 06:04:47.785[app:dbg]vapi: event Fax CNG detected (timestamp 309686)
Jan  1 06:04:47 192.168.3.5 syslog: 06:04:47.790[app:dbg]FAX transfer already is on
Jan  1 06:04:47 192.168.3.5 syslog: 06:04:47.970[app:dbg]slic1. Event 8.
Jan  1 06:04:47 192.168.3.5 syslog: 06:04:47.970[app:dbg]slic 1. Pre-On-hook event
Jan  1 06:04:47 192.168.3.5 syslog: 06:04:47.970[app:dbg]HIO: preonhook TDM port '1', port enabled 1
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.480[app:dbg]slic1. Event 1.
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.480[app:dbg]slic 1. On-hook event
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.480[app:dbg]Set port 1 led to state 'LED_OFF'
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.480[app:dbg]HIO: onhook TDM port '1', port enabled 1
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.480[app:dbg]SLIC 1 (599): onhook state: talking
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.480[app:dbg]regex ID 1: dial reset
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.480[app:dbg]pbx -[msg_clear]-> sip
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.481[app:dbg]CMD_STOP_TONE: port = 1
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.481[app:dbg]Port 1: check vapi queue ('free') at vapi_stop_tone_chan:1353
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.481[app:dbg]Chan 1: current state is CREATED
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.481[app:dbg]vapi_chan.c:1389: conn 1 peek cmd 'no event' from queue
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.481[app:dbg]Port 1: check vapi queue ('free') at __cmd_engine:302
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.481[app:dbg]Port 1: check vapi queue ('free') at vapi_next_ops:2408
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.481[app:dbg]SLIC 1: reset
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.481[app:dbg]dump_port_calls() SLIC 1:
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.481[app:dbg]Q:(0x31e800,0x00010001,(nil))
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.482[app:dbg]H:((nil),0x00000000,(nil),0) W:((nil),0x00000000,(nil)) N:((nil),0x00000000,(nil)) H2:((nil),0x00000000,(nil))
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.482[app:dbg]vapi: chan 1: connection STATISTIC
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.482[app:dbg]vapi: chan 1: Rx_pack = 1636
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.482[app:dbg]vapi: chan 1: Rx_oct  = 281392
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.482[app:dbg]vapi: chan 1: Lost_pack  = 0
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.482[app:dbg]vapi: chan 1: Tx_pack = 1639
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.482[app:dbg]vapi: chan 1: Tx_oct  = 281908
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.482[app:dbg]vapi: chan 1: peak_jiter = 8
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.482[app:dbg]SLIC 1: Common port statistic
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.482[app:dbg]SLIC 1: Rx_pack = 3324
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.483[app:dbg]SLIC 1: Rx_oct  = 571728
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.483[app:dbg]SLIC 1: Lost_pack  = 0
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.483[app:dbg]SLIC 1: Tx_pack = 3328
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.483[app:dbg]SLIC 1: Tx_oct  = 572416
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.483[app:dbg]SLIC 1: peak_jiter = 8
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.483[app:dbg]SLIC 1: reset call 0x00010001 (active)
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.483[app:dbg]CMD_SET_VOICE: port = 1
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.483[app:dbg]Port 1: check vapi queue ('free') at vapi_start_stop_chan:1502
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.483[app:dbg]Chan 1: current state is CREATED
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.483[app:dbg]vapi: Conn 1. start_stop voice chan, TX stop, RX stop
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.483[app:dbg]Port 1: set vapi queue MSP to 'busy' with 'set voice' at vapi_start_stop_chan:1545
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.484[app:dbg]VQ Conn 1 = MSP :     'set voice' =
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.484[app:dbg]free_final_mx: final_mx was NULL for SLIC 1
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.484[app:dbg]CMD_DESTROY_CONN: port = 1
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.484[app:dbg]Port 1: check vapi queue ('busy''set voice') at vapi_destroy_chan:769
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.485[app:dbg]Clear vapi queue of Port 1/chan 1
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.485[app:dbg]Port 1 put cmd 'destroy',cur 'set voice' to queue at (vapi_destroy_chan:776)
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.485[app:dbg]VQ Conn 1 = MSP :     'set voice' =
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.485[app:dbg]VQ Conn 1 + 00  :       'destroy'  + <-get_ptr 
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.485[app:dbg]CMD_DESTROY_IPONLY_CONN: port = 1
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.485[app:dbg]Port 1: check vapi queue ('busy''set voice') at vapi_destroy_chan:769
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.485[app:dbg]Clear vapi queue of Port 1/chan 5
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.485[app:dbg]Port 1 put cmd 'destroy',cur 'set voice' to queue at (vapi_destroy_chan:776)
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.485[app:dbg]VQ Conn 5 = MSP :     'set voice' =
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.486[app:dbg]VQ Conn 5 + 00  :       'destroy'  + <-get_ptr 
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.486[app:dbg]VQ Conn 5 + 01  :       'destroy' (hold) +  
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.486[app:dbg]Port 1: user port 3, old state hangup, new state 
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.486[app:dbg]Set port 1 led to state 'LED_OFF'
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.486[app:dbg]pbx -[msg_fxs_state]-> group
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.487[app:dbg]dump_port_calls() SLIC 1:
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.487[app:dbg]Q:NONE
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.487[app:dbg]H:((nil),0x00000000,(nil),0) W:((nil),0x00000000,(nil)) N:((nil),0x00000000,(nil)) H2:((nil),0x00000000,(nil))
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.487[app:dbg]Set port 1 led to state 'LED_OFF'
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.487[app:dbg]ITC: [msg_clear] -> sip
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.487[app:dbg]call 00010001,flags(00000049): endpoint 1 cleared
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.487[app:dbg]sip: call 00010001: BYE to sip:83433764062@tagnet.tagnet.cc
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.488[app:dbg]vapi_cb_req: 1 0 result 0x00000000 requid 0x00000401
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.488[app:dbg]ITC: [msg_fxs_state] -> group
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.489[app:dbg]-----[GM] self_fxs_state()
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.489[app:dbg]Port 1: new state is hangup
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.490[app:dbg]vapi_proc_event: VAPI_CB
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.490[app:dbg]vapi_cb_chan: chan 1 reqest_id 0x00000401 result 0x00000000
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.490[app:dbg]vapi: conn 1. RTCP disabled
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.491[app:dbg]Delete all RX-TX medias from SLIC 1
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.507[app:dbg]got nua_r_bye : 200(OK)
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.507[app:dbg]sip: call 00010001: BYE/INFO: 200 OK
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.507[app:dbg]got nua_i_state : 200(to BYE)
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.507[app:dbg]NO SIP IN nua_i_state == 200 : to BYE
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.507[app:dbg]self_i_state(): call state 10: : : sdp_init have_oc
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.507[app:dbg]sip: call 00010001: terminated
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.508[app:dbg]self_callstate_terminated: call id = 00010001 need_exchange_at_answer = 0
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.511[app:dbg]Delete all RX-TX medias from SLIC 5
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.511[app:dbg]vapi_cb_req: 1 0 result 0x00000000 requid 0x000004ff
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.520[app:dbg]vapi_proc_event: VAPI_CB
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.520[app:dbg]vapi_cb_chan: chan 1 reqest_id 0x000004ff result 0x00000000
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.520[app:dbg]Conn 1: Set voice mode successeful
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.520[app:dbg]Stop all medias on chan 1
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.520[app:dbg]Port 1: check vapi queue ('busy''set voice') at vapi_next_ops:2408
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.520[app:dbg]Port 1 get cmd 'destroy' from queue at (vapi_next_ops:2427)
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.521[app:dbg]VQ Conn 1 + 01  :       'destroy' (hold) + <-get_ptr 
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.521[app:dbg]Port 1: check vapi queue ('free') at vapi_destroy_chan:769
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.521[app:dbg]Destroying connection 1...
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.521[app:dbg]Chan 1: current state is CREATED
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.521[app:dbg]Port 1: set vapi queue MSP to 'busy' with 'destroy' at vapi_destroy_chan:795
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.521[app:dbg]VQ Conn 1 = MSP :       'destroy' =
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.521[app:dbg]VQ Conn 1 + 01  :       'destroy' (hold) + <-get_ptr 
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.521[app:dbg]Chan 1: CREATED -> DESTROYING
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.522[app:dbg]Mute all RX-TX medias on SLIC 1
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.522[app:dbg]Delete all RX-TX medias from SLIC 1
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.524[app:dbg]vapi_cb_req: 1 0 result 0x00000000 requid 0x0000014b
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.530[app:dbg]vapi_proc_event: VAPI_CB
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.530[app:dbg]vapi_cb_chan: chan 1 reqest_id 0x0000014b result 0x00000000
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.532[app:dbg]vapi_cb_req: 1 0 result 0x00000000 requid 0x00000103
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.540[app:dbg]vapi_proc_event: VAPI_CB
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.540[app:dbg]vapi_cb_chan: chan 1 reqest_id 0x00000103 result 0x00000000
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.540[app:dbg]Conn 1 destroyed
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.540[app:dbg]Chan 1: DESTROYING -> INITIAL
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.540[app:dbg]Port 1: check vapi queue ('busy''destroy') at vapi_next_ops:2408
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.540[app:dbg]Port 1 get cmd 'destroy' from queue at (vapi_next_ops:2427)
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.541[app:dbg]Port 1: check vapi queue ('free') at vapi_destroy_chan:769
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.541[app:dbg]Destroying connection 5...
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.541[app:dbg]Chan 5: current state is INITIAL
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.541[app:dbg]Port 1: check vapi queue ('free') at vapi_next_ops:2570
Jan  1 06:04:48 192.168.3.5 syslog: 06:04:48.541[app:dbg]Port 1: check vapi queue ('free') at vapi_next_ops:2408

