Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.810[app:dbg]vapi: chan 7: connection STATISTIC
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.810[app:dbg]vapi: chan 7: Rx_pack = 0
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.810[app:dbg]vapi: chan 7: Rx_oct  = 0
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.810[app:dbg]vapi: chan 7: Lost_pack  = 0
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.810[app:dbg]vapi: chan 7: Tx_pack = 0
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.810[app:dbg]vapi: chan 7: Tx_oct  = 0
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.810[app:dbg]vapi: chan 7: peak_jiter = 0
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.810[app:dbg]SLIC 7: Common port statistic
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.810[app:dbg]SLIC 7: Rx_pack = 3021
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.810[app:dbg]SLIC 7: Rx_oct  = 96672
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.810[app:dbg]SLIC 7: Lost_pack  = 33
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.810[app:dbg]SLIC 7: Tx_pack = 3067
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.810[app:dbg]SLIC 7: Tx_oct  = 97632
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.810[app:dbg]SLIC 7: peak_jiter = 0
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.810[app:dbg]SLIC 7: reset call 0x0205000D (active)
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.810[app:dbg]CMD_SET_VOICE: port = 7
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.810[app:dbg]Port 7: check vapi queue ('busy''start_tone') at vapi_start_stop_chan:1667
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.810[app:dbg]Port 7 put cmd 'set voice',cur 'start_tone' to queue at (vapi_start_stop_chan:1674)
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.810[app:dbg]VQ Conn 7 = MSP :    'start_tone' =
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.810[app:dbg]VQ Conn 7 + 01  :     'set voice'  + <-get_ptr 
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.810[app:dbg]incom_calls_set_media_started() call 0x0205000D, group 0, task <group> media stopped
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.810[app:dbg]incom_calls_rem() rem call 0x0205000D, group 0, task <group> from list
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.810[app:dbg]dump_port_calls() SLIC 7:
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.810[app:dbg]Q:NONE
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.810[app:dbg]H:((nil),0x00000000,(nil),0) W:((nil),0x00000000,(nil)) N:((nil),0x00000000,(nil)) H2:((nil),0x00000000,(nil))
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.820[app:dbg]vapi_cb_req: 7 0 result 0x00000000 requid 0x00000923
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.820[app:dbg]ITC: [msg_fxs_state] -> group
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.820[app:dbg]-----[GM] self_fxs_state()
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.820[app:dbg]Port 7: new state is busy
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.820[app:dbg]vapi_proc_event: VAPI_CB
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.820[app:dbg]vapi_cb_chan: chan 7 reqest_id 0x00000923 result 0x00000000
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.820[app:dbg]Conn 7: Start tone - Successfull
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.820[app:dbg]Port 7: check vapi queue ('busy''start_tone') at vapi_next_ops:2614
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.820[app:dbg]Port 7 get cmd 'set voice' from queue at (vapi_next_ops:2633)
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.820[app:dbg]Port 7: check vapi queue ('free') at vapi_start_stop_chan:1667
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.820[app:dbg]Chan 7: current state is CREATED
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.820[app:dbg]vapi: Conn 7. start_stop voice chan, TX stop, RX stop
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.820[app:dbg]Port 7: set vapi queue MSP to 'busy' with 'set voice' at vapi_start_stop_chan:1710
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.820[app:dbg]VQ Conn 7 = MSP :     'set voice' =
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.820[app:dbg]vapi_cb_req: 7 0 result 0x00000000 requid 0x00000401
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.820[app:dbg]vapi_proc_event: VAPI_CB
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.820[app:dbg]vapi_cb_chan: chan 7 reqest_id 0x00000401 result 0x00000000
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.820[app:dbg]vapi: conn 7. RTCP disabled
Sep 25 09:42:46 TAU-8 user.notice syslog: 09:42:46.820[sip]nua(0x334000): event i_terminated 200 Session Terminated
Sep 25 09:42:46 TAU-8 user.notice syslog: 09:42:46.820[sip]nua(0x334000): recv signal r_destroy
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.820[app:dbg]vapi_cb_req: 7 0 result 0x00000000 requid 0x000004ff
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.820[app:dbg]vapi_proc_event: VAPI_CB
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.820[app:dbg]vapi_cb_chan: chan 7 reqest_id 0x000004ff result 0x00000000
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.820[app:dbg]Conn 7: Set voice mode successeful
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.820[app:dbg]Stop all medias on chan 7
Sep 25 09:42:46 TAU-8 user.debug syslog: 09:42:46.820[app:dbg]Port 7: check vapi queue ('busy''set voice') at vapi_next_ops:2614
Sep 25 09:42:47 TAU-8 user.debug syslog: 09:42:47.120[app:dbg]slic7. Event 8.
Sep 25 09:42:47 TAU-8 user.debug syslog: 09:42:47.120[app:dbg]slic 7. Pre-On-hook event
Sep 25 09:42:47 TAU-8 user.debug syslog: 09:42:47.120[app:dbg]HIO: preonhook TDM port '7', port enabled 1
Sep 25 09:42:47 TAU-8 user.debug syslog: 09:42:47.120[app:dbg]CMD_STOP_TONE: port = 7
Sep 25 09:42:47 TAU-8 user.debug syslog: 09:42:47.120[app:dbg]Port 7: check vapi queue ('free') at vapi_stop_tone_chan:1518
Sep 25 09:42:47 TAU-8 user.debug syslog: 09:42:47.120[app:dbg]Chan 7: current state is CREATED
Sep 25 09:42:47 TAU-8 user.debug syslog: 09:42:47.120[app:dbg]Port 7: set vapi queue MSP to 'busy' with 'stop_tone' at vapi_stop_tone_chan:1564
Sep 25 09:42:47 TAU-8 user.debug syslog: 09:42:47.120[app:dbg]VQ Conn 7 = MSP :     'stop_tone' =
Sep 25 09:42:47 TAU-8 user.debug syslog: 09:42:47.120[app:dbg]chan 7 stop tone
Sep 25 09:42:47 TAU-8 user.debug syslog: 09:42:47.120[app:dbg]vapi_cb_req: 7 0 result 0x00000000 requid 0x00000924
Sep 25 09:42:47 TAU-8 user.debug syslog: 09:42:47.120[app:dbg]vapi_proc_event: VAPI_CB
Sep 25 09:42:47 TAU-8 user.debug syslog: 09:42:47.120[app:dbg]vapi_cb_chan: chan 7 reqest_id 0x00000924 result 0x00000000
Sep 25 09:42:47 TAU-8 user.debug syslog: 09:42:47.120[app:dbg]Conn 7: Stop tone - Successfull
Sep 25 09:42:47 TAU-8 user.debug syslog: 09:42:47.120[app:dbg]Port 7: check vapi queue ('busy''stop_tone') at vapi_next_ops:2614
Sep 25 09:42:47 TAU-8 user.debug syslog: 09:42:47.120[app:dbg]vapi: generic event, code 2 <Tone Generation completed>, conn 7
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.110[app:dbg]slic7. Event 1.
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.110[app:dbg]slic 7. On-hook event
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.110[app:dbg]Set port 7 led to state 'LED_OFF'
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.110[app:dbg]HIO: onhook TDM port '7', port enabled 1
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.110[app:dbg]SLIC 7 (12): onhook state: busy
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.110[app:dbg]regex ID 7: dial reset
Sep 25 09:42:48 TAU-8 user.info syslog: 09:42:48.110[app:info]SLIC 7: from state 'busy' to state 'hangup'
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.110[app:dbg]CMD_STOP_TONE: port = 7
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.110[app:dbg]Port 7: check vapi queue ('free') at vapi_stop_tone_chan:1518
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.110[app:dbg]Chan 7: current state is CREATED
Sep 25 09:42:48 TAU-8 user.err syslog: 09:42:48.110[app:ERR]chan 7: no generated tones!
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.110[app:dbg]vapi_chan.c:1554: conn 7 peek cmd 'no event' from queue
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.110[app:dbg]Port 7: check vapi queue ('free') at __cmd_engine:342
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.110[app:dbg]Port 7: check vapi queue ('free') at vapi_next_ops:2614
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.110[app:dbg]SLIC 7: reset
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.110[app:dbg]dump_port_calls() SLIC 7:
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.110[app:dbg]Q:NONE
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.110[app:dbg]H:((nil),0x00000000,(nil),0) W:((nil),0x00000000,(nil)) N:((nil),0x00000000,(nil)) H2:((nil),0x00000000,(nil))
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.110[app:dbg]free_final_mx: final_mx was NULL for SLIC 7
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.110[app:dbg]CMD_DESTROY_CONN: port = 7
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.110[app:dbg]Port 7: check vapi queue ('free') at vapi_destroy_chan:906
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.110[app:dbg]Destroying connection 7...
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.110[app:dbg]Chan 7: current state is CREATED
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.110[app:dbg]Port 7: set vapi queue MSP to 'busy' with 'destroy' at vapi_destroy_chan:932
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.110[app:dbg]VQ Conn 7 = MSP :       'destroy' =
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.110[app:dbg]Chan 7: CREATED -> DESTROYING
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.110[app:dbg]CMD_DESTROY_IPONLY_CONN: port = 7
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.110[app:dbg]Port 7: check vapi queue ('busy''destroy') at vapi_destroy_chan:906
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.110[app:dbg]Clear vapi queue of Port 7/chan 15
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.110[app:dbg]Port 7 put cmd 'destroy',cur 'destroy' to queue at (vapi_destroy_chan:913)
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.110[app:dbg]VQ Conn 15 = MSP :       'destroy' =
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.110[app:dbg]VQ Conn 15 + 00  :       'destroy' (hold) + <-get_ptr 
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.110[app:dbg]Port 7: user port 1, old state hangup, new state 
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.110[app:dbg]Set port 7 led to state 'LED_OFF'
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.110[app:dbg]pbx -[msg_fxs_state]-> group
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.110[app:dbg]dump_port_calls() SLIC 7:
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.110[app:dbg]Q:NONE
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.110[app:dbg]H:((nil),0x00000000,(nil),0) W:((nil),0x00000000,(nil)) N:((nil),0x00000000,(nil)) H2:((nil),0x00000000,(nil))
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.110[app:dbg]Set port 7 led to state 'LED_OFF'
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.110[app:dbg]vapi_cb_req: 7 0 result 0x00000000 requid 0x0000014c
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.110[app:dbg]ITC: [msg_fxs_state] -> group
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.110[app:dbg]-----[GM] self_fxs_state()
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.110[app:dbg]Port 7: new state is hangup
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.120[app:dbg]vapi_proc_event: VAPI_CB
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.120[app:dbg]vapi_cb_chan: chan 7 reqest_id 0x0000014c result 0x00000000
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.120[app:dbg]vapi_cb_req: 7 0 result 0x00000000 requid 0x00000103
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.120[app:dbg]vapi_proc_event: VAPI_CB
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.120[app:dbg]vapi_cb_chan: chan 7 reqest_id 0x00000103 result 0x00000000
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.120[app:dbg]Conn 7 destroyed
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.120[app:dbg]Chan 7: DESTROYING -> INITIAL
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.120[app:dbg]Port 7: check vapi queue ('busy''destroy') at vapi_next_ops:2614
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.120[app:dbg]Port 7 get cmd 'destroy' from queue at (vapi_next_ops:2633)
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.120[app:dbg]Port 7: check vapi queue ('free') at vapi_destroy_chan:906
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.120[app:dbg]Destroying connection 15...
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.120[app:dbg]Chan 15: current state is INITIAL
Sep 25 09:42:48 TAU-8 user.err syslog: 09:42:48.120[app:ERR]vapi_destroy_chan() chan 15: current state initial: duplicate destroying connection!
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.120[app:dbg]Port 7: check vapi queue ('free') at vapi_next_ops:2776
Sep 25 09:42:48 TAU-8 user.debug syslog: 09:42:48.120[app:dbg]Port 7: check vapi queue ('free') at vapi_next_ops:2614