Jan  1 01:05:04 tau syslog.info syslogd started: BusyBox v1.15.3
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.000)[app:dbg]HIO: port 17 <ReadyAfterInit/hangup> msg <Offhook><0>
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.001)[app:dbg]Port: 17:  ReadyAfterInit -> Release (No errors)
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.001)[app:dbg]HIO: offhook TDM port '17' port enabled 1
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.002)[app:dbg]HIO: offhook TDM port '17' direction unknown -> outgoing
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.003)[app:dbg]port 17: offhook state: hangup
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.003)[app:dbg]regex ID 17: dial reset
Jan  1 01:05:12 tau user.info tau: 2.14.0.284|(12.004)[app:info]port 17: from state 'hangup' to state 'hangdown'
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.005)[app:dbg]Port: 17: Chan 17: current state is INITIAL
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.005)[app:dbg]Port 17: chan: 17 check vapi queue ('free') at vapi_create_chan:1333
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.006)[app:dbg]Port 17: chan: 17: set vapi queue MSP to 'busy' with 'create' at vapi_create_chan:1354
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.006)[app:dbg]VQ Port 17 = MSP :        'create' =
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.007)[app:dbg]vapi: create: Create TDM 17
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.008)[app:dbg]Chan 17: INITIAL -> CREATING
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.009)[app:dbg]Port 17: chan: 17 check vapi queue ('busy''create') at __cmd_engine:428
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.010)[app:dbg]Port: 17: Chan 17: current state is CREATING
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.011)[app:dbg]Port 17: chan: 17 check vapi queue ('busy''create') at vapi_start_tone_chan:1837
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.012)[app:dbg]Port 17 chan 17 put cmd 'start_tone',cur 'create' to queue at (vapi_start_tone_chan:1842)
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.012)[app:dbg]VQ Port 17 = MSP :        'create' =
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.013)[app:dbg]VQ Port 17 + 00  :    'start_tone'/   tone<21>,Tdm + <-get_ptr 
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.013)[app:dbg]Port 17: chan: 17 check vapi queue ('busy''create') at __cmd_engine:428
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.014)[app:dbg]voip_lock: set voip lock
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.015)[app:dbg]pbx -[msg_fxs_state]-> group
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.016)[app:dbg]dump_port_calls() port 17:
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.016)[app:dbg]Q:NONE
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.017)[app:dbg]H:((nil),0x00000000,(nil),0) W:((nil),0x00000000,(nil)) N:((nil),0x00000000,(nil)) C:((nil),0x00000000,(nil))
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.018)[app:dbg]HIO: port 17 <Release/hangdown> msg <State><16>
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.018)[app:dbg]Port: 17:  Release -> Talk (No errors)
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.083)[app:dbg]ITC: [msg_fxs_state] -> group
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.084)[app:dbg][SG] Port 17: new state is hangdown
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.096)[app:dbg]vapi_cb_req(): Conn 17 CALLBACK msg (level = 0x0; result = 0x0; req_id = 0x   0; len = 0)
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.097)[app:dbg]vapi: chan: 17 Callback request = 0x   0
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.098)[app:dbg]vapi: chan 17: voip DTMF SET
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.100)[app:dbg]Port 17: chan: 17 check vapi queue ('busy''create') at vapi_cb_chan:4418
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.102)[app:dbg]vapi_cb_req(): Conn 17 CALLBACK msg (level = 0x0; result = 0x0; req_id = 0x  61; len = 12)
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.103)[app:dbg]vapi: chan: 17 Callback request = 0x  61
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.104)[app:dbg]vapi: create: Set TDM 17 SSRC to 0x14f1d538
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.105)[app:dbg]Chan 17: CREATING -> CREATED
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.105)[app:dbg]vapi: create: TDM 17 Done
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.106)[app:dbg]Port 17: chan: 17 check vapi queue ('busy''create') at vapi_cb_chan:4424
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.107)[app:dbg]Port 17: chan: 17: set vapi queue MSP to 'free' with  at vapi_cb_chan:4425
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.107)[app:dbg]VQ Port 17 + 00  :    'start_tone'/   tone<21>,Tdm + <-get_ptr 
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.108)[app:dbg]Port 17: chan: 17 check vapi queue ('free') at vapi_next_ops:3782
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.109)[app:dbg]Port 17 get cmd 'start_tone' from queue at (vapi_next_ops:3799)
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.109)[app:dbg]Port: 17: Chan 17: current state is CREATED
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.110)[app:dbg]Port 17: chan: 17 check vapi queue ('free') at vapi_start_tone_chan:1837
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.111)[app:dbg]Port 17: chan: 17: set vapi queue MSP to 'busy' with 'start_tone' at vapi_start_tone_chan:1858
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.111)[app:dbg]VQ Port 17 = MSP :    'start_tone' =
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.112)[app:dbg]Conn 17, Set custom tone config: tone_high: 425Hz, tone_low: 0Hz
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.112)[app:dbg]Conn 17, Set custom tone config: tone_t_on1: 1000ms, tone_t_off1: 0ms, tone_t_on2: 0ms, tone_t_off2: 0ms
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.114)[app:dbg]chan 17 start tone, id=21, direction=TDM
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.115)[app:dbg]Port 17: chan: 17 check vapi queue ('busy''start_tone') at vapi_next_ops:3927
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.118)[app:dbg]vapi_cb_req(): Conn 17 CALLBACK msg (level = 0x0; result = 0x0; req_id = 0x E20; len = 12)
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.120)[app:dbg]vapi: chan: 17 Callback request = 0x E20
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.121)[app:dbg]Conn 17: Start tone - Successfull
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.122)[app:dbg]Port 17: chan: 17 check vapi queue ('busy''start_tone') at vapi_cb_chan:4424
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.122)[app:dbg]Port 17: chan: 17: set vapi queue MSP to 'free' with  at vapi_cb_chan:4425
Jan  1 01:05:12 tau user.debug tau: 2.14.0.284|(12.123)[app:dbg]Port 17: chan: 17 check vapi queue ('free') at vapi_next_ops:3782
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.073)[app:dbg]HIO: port 17 <Talk/hangdown> msg <Pre Onhook><2>
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.074)[app:dbg]HIO: preonhook TDM port '17', port enabled 1
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.074)[app:dbg]Port: 17: Chan 17: current state is CREATED
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.075)[app:dbg]Port 17: chan: 17 check vapi queue ('free') at vapi_stop_tone_chan:1982
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.075)[app:dbg]Port 17: chan: 17: set vapi queue MSP to 'busy' with 'stop_tone' at vapi_stop_tone_chan:2003
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.076)[app:dbg]VQ Port 17 = MSP :     'stop_tone' =
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.077)[app:dbg]chan 17 stop tone
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.078)[app:dbg]Port 17: chan: 17 check vapi queue ('busy''stop_tone') at __cmd_engine:428
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.080)[app:dbg]vapi_cb_req(): Conn 17 CALLBACK msg (level = 0x0; result = 0x0; req_id = 0x E21; len = 0)
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.081)[app:dbg]vapi: chan: 17 Callback request = 0x E21
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.082)[app:dbg]Conn 17: Stop tone - Successfull
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.082)[app:dbg]Port 17: chan: 17 check vapi queue ('busy''stop_tone') at vapi_cb_chan:4424
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.083)[app:dbg]Port 17: chan: 17: set vapi queue MSP to 'free' with  at vapi_cb_chan:4425
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.084)[app:dbg]Port 17: chan: 17 check vapi queue ('free') at vapi_next_ops:3782
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.086)[app:dbg]vapi: generic event, code 2 <Tone Generation completed>, conn 17
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.637)[app:dbg]HIO: port 17 <Talk/hangdown> msg <Onhook><1>
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.638)[app:dbg]HIO: onhook TDM port '17', port enabled 1
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.639)[app:dbg]port 17: onhook state: hangdown
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.640)[app:dbg]regex ID 17: dial reset
Jan  1 01:05:16 tau user.info tau: 2.14.0.284|(16.640)[app:info]port 17: from state 'hangdown' to state 'hangup'
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.641)[app:dbg]Port: 17: Chan 17: current state is CREATED
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.642)[app:dbg]Port 17: chan: 17 check vapi queue ('free') at vapi_stop_tone_chan:1982
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.642)[app:dbg]Port 17: chan: 17: set vapi queue MSP to 'busy' with 'stop_tone' at vapi_stop_tone_chan:2003
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.643)[app:dbg]VQ Port 17 = MSP :     'stop_tone' =
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.644)[app:dbg]chan 17 stop tone
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.645)[app:dbg]Port 17: chan: 17 check vapi queue ('busy''stop_tone') at __cmd_engine:428
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.646)[app:dbg]port 17: reset
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.646)[app:dbg]dump_port_calls() port 17:
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.647)[app:dbg]Q:NONE
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.647)[app:dbg]H:((nil),0x00000000,(nil),0) W:((nil),0x00000000,(nil)) N:((nil),0x00000000,(nil)) C:((nil),0x00000000,(nil))
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.648)[app:dbg]Port: 17: Chan 17: current state is CREATED
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.649)[app:dbg]Port 17: chan: 17 check vapi queue ('busy''stop_tone') at vapi_destroy_chan:1486
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.649)[app:dbg]Clear vapi queue of Port 17
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.650)[app:dbg]Port 17: clear VPL
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.651)[app:dbg]Port 17: vpl is empty
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.651)[app:dbg]Port 17: vpl is empty
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.652)[app:dbg]Port 17 chan 17 put cmd 'destroy',cur 'stop_tone' to queue at (vapi_destroy_chan:1494)
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.653)[app:dbg]VQ Port 17 = MSP :     'stop_tone' =
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.653)[app:dbg]VQ Port 17 + 00  :       'destroy'/         <none> + <-get_ptr 
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.654)[app:dbg]Port 17: chan: 17 check vapi queue ('busy''stop_tone') at __cmd_engine:428
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.655)[app:dbg]voip_lock: remove voip lock
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.655)[app:dbg]pbx -[msg_fxs_state]-> group
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.656)[app:dbg]dump_port_calls() port 17:
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.657)[app:dbg]Q:NONE
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.657)[app:dbg]H:((nil),0x00000000,(nil),0) W:((nil),0x00000000,(nil)) N:((nil),0x00000000,(nil)) C:((nil),0x00000000,(nil))
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.658)[app:dbg]HIO: port 17 <Talk/hangup> msg <State><16>
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.659)[app:dbg]Port: 17:  Talk -> ReadyAfterInit (No errors)
Jan  1 01:05:16 tau user.info tau: 2.14.0.284|(16.659)[app:info]port 17: from state 'hangup' to state 'hangup'
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.665)[app:dbg]ITC: [msg_fxs_state] -> group
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.665)[app:dbg][SG] Port 17: new state is hangup
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.667)[app:dbg]vapi_cb_req(): Conn 17 CALLBACK msg (level = 0x0; result = 0x0; req_id = 0x E21; len = 0)
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.668)[app:dbg]vapi: chan: 17 Callback request = 0x E21
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.669)[app:dbg]Conn 17: Stop tone - Successfull
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.670)[app:dbg]Port 17: chan: 17 check vapi queue ('busy''stop_tone') at vapi_cb_chan:4424
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.670)[app:dbg]Port 17: chan: 17: set vapi queue MSP to 'free' with  at vapi_cb_chan:4425
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.671)[app:dbg]VQ Port 17 + 00  :       'destroy'/         <none> + <-get_ptr 
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.672)[app:dbg]Port 17: chan: 17 check vapi queue ('free') at vapi_next_ops:3782
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.672)[app:dbg]Port 17 get cmd 'destroy' from queue at (vapi_next_ops:3799)
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.673)[app:dbg]Port: 17: Chan 17: current state is CREATED
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.673)[app:dbg]Port 17: chan: 17 check vapi queue ('free') at vapi_destroy_chan:1486
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.674)[app:dbg]Port 17: chan: 17: set vapi queue MSP to 'busy' with 'destroy' at vapi_destroy_chan:1509
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.675)[app:dbg]VQ Port 17 = MSP :       'destroy' =
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.675)[app:dbg]Chan 17: CREATED -> DESTROYING
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.676)[app:dbg]vapi: destroy: Destroy mediaforks on TDM 17
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.677)[app:dbg]vapi: destroy: TDM 17 get statistic
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.678)[app:dbg]Port 17: chan: 17 check vapi queue ('busy''destroy') at vapi_next_ops:3927
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.680)[app:dbg]vapi_cb_req(): Conn 17 CALLBACK msg (level = 0x0; result = 0x0; req_id = 0x 15E; len = 208)
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.681)[app:dbg]vapi: chan: 17 Callback request = 0x 15E
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.682)[app:dbg]port 17: (chan 17) get port STATISTIC
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.683)[app:dbg]port 17: Rx_pack = 0
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.683)[app:dbg]port 17: Rx_oct  = 0
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.684)[app:dbg]port 17: Lost_pack  = 0
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.684)[app:dbg]port 17: Tx_pack = 0
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.685)[app:dbg]port 17: Tx_oct  = 0
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.686)[app:dbg]port 17: peak_jiter = 0
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.686)[app:dbg]vapi: destroy: TDM 17 Destroy
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.688)[app:dbg]Port 17: chan: 17 check vapi queue ('busy''destroy') at vapi_cb_chan:4418
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.695)[app:dbg]vapi_cb_req(): Conn 17 CALLBACK msg (level = 0x0; result = 0x0; req_id = 0x 103; len = 0)
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.696)[app:dbg]vapi: chan: 17 Callback request = 0x 103
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.697)[app:dbg]vapi: destroy: reset and turn off RTCP timers
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.698)[app:dbg]Chan 17: DESTROYING -> INITIAL
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.698)[app:dbg]vapi: destroy: Done (port 17) - TDM-just actions
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.699)[app:dbg]Port 17: chan: 17 check vapi queue ('busy''destroy') at vapi_cb_chan:4424
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.700)[app:dbg]Port 17: chan: 17: set vapi queue MSP to 'free' with  at vapi_cb_chan:4425
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.700)[app:dbg]Port 17: chan: 17 check vapi queue ('free') at vapi_next_ops:3782
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.759)[app:dbg]HIO: port 18 <ReadyAfterInit/hangup> msg <State><16>
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.760)[app:dbg]HIO: port 19 <ReadyAfterInit/hangup> msg <State><16>
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.767)[app:dbg]HIO: port 16 <ReadyAfterInit/hangup> msg <State><16>
Jan  1 01:05:16 tau user.debug tau: 2.14.0.284|(16.768)[app:dbg]HIO: port 17 <ReadyAfterInit/hangup> msg <State><16>
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.368)[app:dbg]HIO: port 17 <ReadyAfterInit/hangup> msg <Offhook><0>
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.369)[app:dbg]Port: 17:  ReadyAfterInit -> Release (No errors)
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.370)[app:dbg]HIO: offhook TDM port '17' port enabled 1
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.370)[app:dbg]HIO: offhook TDM port '17' direction unknown -> outgoing
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.371)[app:dbg]port 17: offhook state: hangup
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.371)[app:dbg]regex ID 17: dial reset
Jan  1 01:05:46 tau user.info tau: 2.14.0.284|(46.372)[app:info]port 17: from state 'hangup' to state 'hangdown'
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.373)[app:dbg]Port: 17: Chan 17: current state is INITIAL
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.373)[app:dbg]Port 17: chan: 17 check vapi queue ('free') at vapi_create_chan:1333
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.374)[app:dbg]Port 17: chan: 17: set vapi queue MSP to 'busy' with 'create' at vapi_create_chan:1354
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.375)[app:dbg]VQ Port 17 = MSP :        'create' =
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.375)[app:dbg]vapi: create: Create TDM 17
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.376)[app:dbg]Chan 17: INITIAL -> CREATING
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.377)[app:dbg]Port 17: chan: 17 check vapi queue ('busy''create') at __cmd_engine:428
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.378)[app:dbg]Port: 17: Chan 17: current state is CREATING
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.379)[app:dbg]Port 17: chan: 17 check vapi queue ('busy''create') at vapi_start_tone_chan:1837
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.380)[app:dbg]Port 17 chan 17 put cmd 'start_tone',cur 'create' to queue at (vapi_start_tone_chan:1842)
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.380)[app:dbg]VQ Port 17 = MSP :        'create' =
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.381)[app:dbg]VQ Port 17 + 01  :    'start_tone'/   tone<21>,Tdm + <-get_ptr 
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.382)[app:dbg]Port 17: chan: 17 check vapi queue ('busy''create') at __cmd_engine:428
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.382)[app:dbg]voip_lock: set voip lock
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.383)[app:dbg]pbx -[msg_fxs_state]-> group
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.384)[app:dbg]dump_port_calls() port 17:
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.384)[app:dbg]Q:NONE
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.385)[app:dbg]H:((nil),0x00000000,(nil),0) W:((nil),0x00000000,(nil)) N:((nil),0x00000000,(nil)) C:((nil),0x00000000,(nil))
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.386)[app:dbg]HIO: port 17 <Release/hangdown> msg <State><16>
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.386)[app:dbg]Port: 17:  Release -> Talk (No errors)
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.388)[app:dbg]ITC: [msg_fxs_state] -> group
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.389)[app:dbg][SG] Port 17: new state is hangdown
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.395)[app:dbg]vapi_cb_req(): Conn 17 CALLBACK msg (level = 0x0; result = 0x0; req_id = 0x   0; len = 0)
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.396)[app:dbg]vapi: chan: 17 Callback request = 0x   0
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.396)[app:dbg]vapi: chan 17: voip DTMF SET
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.398)[app:dbg]Port 17: chan: 17 check vapi queue ('busy''create') at vapi_cb_chan:4418
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.400)[app:dbg]vapi_cb_req(): Conn 17 CALLBACK msg (level = 0x0; result = 0x0; req_id = 0x  61; len = 12)
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.401)[app:dbg]vapi: chan: 17 Callback request = 0x  61
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.401)[app:dbg]vapi: create: Set TDM 17 SSRC to 0x14ae3b58
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.402)[app:dbg]Chan 17: CREATING -> CREATED
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.403)[app:dbg]vapi: create: TDM 17 Done
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.403)[app:dbg]Port 17: chan: 17 check vapi queue ('busy''create') at vapi_cb_chan:4424
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.404)[app:dbg]Port 17: chan: 17: set vapi queue MSP to 'free' with  at vapi_cb_chan:4425
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.405)[app:dbg]VQ Port 17 + 01  :    'start_tone'/   tone<21>,Tdm + <-get_ptr 
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.405)[app:dbg]Port 17: chan: 17 check vapi queue ('free') at vapi_next_ops:3782
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.406)[app:dbg]Port 17 get cmd 'start_tone' from queue at (vapi_next_ops:3799)
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.406)[app:dbg]Port: 17: Chan 17: current state is CREATED
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.407)[app:dbg]Port 17: chan: 17 check vapi queue ('free') at vapi_start_tone_chan:1837
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.408)[app:dbg]Port 17: chan: 17: set vapi queue MSP to 'busy' with 'start_tone' at vapi_start_tone_chan:1858
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.408)[app:dbg]VQ Port 17 = MSP :    'start_tone' =
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.409)[app:dbg]Conn 17, Set custom tone config: tone_high: 425Hz, tone_low: 0Hz
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.410)[app:dbg]Conn 17, Set custom tone config: tone_t_on1: 1000ms, tone_t_off1: 0ms, tone_t_on2: 0ms, tone_t_off2: 0ms
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.411)[app:dbg]chan 17 start tone, id=21, direction=TDM
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.412)[app:dbg]Port 17: chan: 17 check vapi queue ('busy''start_tone') at vapi_next_ops:3927
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.414)[app:dbg]vapi_cb_req(): Conn 17 CALLBACK msg (level = 0x0; result = 0x0; req_id = 0x E20; len = 12)
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.415)[app:dbg]vapi: chan: 17 Callback request = 0x E20
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.415)[app:dbg]Conn 17: Start tone - Successfull
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.416)[app:dbg]Port 17: chan: 17 check vapi queue ('busy''start_tone') at vapi_cb_chan:4424
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.417)[app:dbg]Port 17: chan: 17: set vapi queue MSP to 'free' with  at vapi_cb_chan:4425
Jan  1 01:05:46 tau user.debug tau: 2.14.0.284|(46.417)[app:dbg]Port 17: chan: 17 check vapi queue ('free') at vapi_next_ops:3782
Jan  1 01:05:48 tau user.debug tau: 2.14.0.284|(48.530)[app:dbg]HIO: port 17 <Talk/hangdown> msg <Pre Onhook><2>
Jan  1 01:05:48 tau user.debug tau: 2.14.0.284|(48.531)[app:dbg]HIO: preonhook TDM port '17', port enabled 1
Jan  1 01:05:48 tau user.debug tau: 2.14.0.284|(48.531)[app:dbg]Port: 17: Chan 17: current state is CREATED
Jan  1 01:05:48 tau user.debug tau: 2.14.0.284|(48.532)[app:dbg]Port 17: chan: 17 check vapi queue ('free') at vapi_stop_tone_chan:1982
Jan  1 01:05:48 tau user.debug tau: 2.14.0.284|(48.533)[app:dbg]Port 17: chan: 17: set vapi queue MSP to 'busy' with 'stop_tone' at vapi_stop_tone_chan:2003
Jan  1 01:05:48 tau user.debug tau: 2.14.0.284|(48.533)[app:dbg]VQ Port 17 = MSP :     'stop_tone' =
Jan  1 01:05:48 tau user.debug tau: 2.14.0.284|(48.534)[app:dbg]chan 17 stop tone
Jan  1 01:05:48 tau user.debug tau: 2.14.0.284|(48.535)[app:dbg]Port 17: chan: 17 check vapi queue ('busy''stop_tone') at __cmd_engine:428
Jan  1 01:05:48 tau user.debug tau: 2.14.0.284|(48.538)[app:dbg]vapi_cb_req(): Conn 17 CALLBACK msg (level = 0x0; result = 0x0; req_id = 0x E21; len = 0)
Jan  1 01:05:48 tau user.debug tau: 2.14.0.284|(48.540)[app:dbg]vapi: chan: 17 Callback request = 0x E21
Jan  1 01:05:48 tau user.debug tau: 2.14.0.284|(48.541)[app:dbg]Conn 17: Stop tone - Successfull
Jan  1 01:05:48 tau user.debug tau: 2.14.0.284|(48.541)[app:dbg]Port 17: chan: 17 check vapi queue ('busy''stop_tone') at vapi_cb_chan:4424
Jan  1 01:05:48 tau user.debug tau: 2.14.0.284|(48.542)[app:dbg]Port 17: chan: 17: set vapi queue MSP to 'free' with  at vapi_cb_chan:4425
Jan  1 01:05:48 tau user.debug tau: 2.14.0.284|(48.543)[app:dbg]Port 17: chan: 17 check vapi queue ('free') at vapi_next_ops:3782
Jan  1 01:05:48 tau user.debug tau: 2.14.0.284|(48.547)[app:dbg]vapi: generic event, code 2 <Tone Generation completed>, conn 17
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.136)[app:dbg]HIO: port 17 <Talk/hangdown> msg <Onhook><1>
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.136)[app:dbg]HIO: onhook TDM port '17', port enabled 1
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.137)[app:dbg]port 17: onhook state: hangdown
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.138)[app:dbg]regex ID 17: dial reset
Jan  1 01:05:49 tau user.info tau: 2.14.0.284|(49.139)[app:info]port 17: from state 'hangdown' to state 'hangup'
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.139)[app:dbg]Port: 17: Chan 17: current state is CREATED
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.140)[app:dbg]Port 17: chan: 17 check vapi queue ('free') at vapi_stop_tone_chan:1982
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.141)[app:dbg]Port 17: chan: 17: set vapi queue MSP to 'busy' with 'stop_tone' at vapi_stop_tone_chan:2003
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.141)[app:dbg]VQ Port 17 = MSP :     'stop_tone' =
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.142)[app:dbg]chan 17 stop tone
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.143)[app:dbg]Port 17: chan: 17 check vapi queue ('busy''stop_tone') at __cmd_engine:428
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.144)[app:dbg]port 17: reset
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.144)[app:dbg]dump_port_calls() port 17:
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.145)[app:dbg]Q:NONE
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.146)[app:dbg]H:((nil),0x00000000,(nil),0) W:((nil),0x00000000,(nil)) N:((nil),0x00000000,(nil)) C:((nil),0x00000000,(nil))
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.146)[app:dbg]Port: 17: Chan 17: current state is CREATED
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.147)[app:dbg]Port 17: chan: 17 check vapi queue ('busy''stop_tone') at vapi_destroy_chan:1486
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.148)[app:dbg]Clear vapi queue of Port 17
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.148)[app:dbg]Port 17: clear VPL
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.149)[app:dbg]Port 17: vpl is empty
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.149)[app:dbg]Port 17: vpl is empty
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.150)[app:dbg]Port 17 chan 17 put cmd 'destroy',cur 'stop_tone' to queue at (vapi_destroy_chan:1494)
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.151)[app:dbg]VQ Port 17 = MSP :     'stop_tone' =
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.151)[app:dbg]VQ Port 17 + 00  :       'destroy'/         <none> + <-get_ptr 
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.152)[app:dbg]Port 17: chan: 17 check vapi queue ('busy''stop_tone') at __cmd_engine:428
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.153)[app:dbg]voip_lock: remove voip lock
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.154)[app:dbg]pbx -[msg_fxs_state]-> group
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.154)[app:dbg]dump_port_calls() port 17:
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.155)[app:dbg]Q:NONE
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.155)[app:dbg]H:((nil),0x00000000,(nil),0) W:((nil),0x00000000,(nil)) N:((nil),0x00000000,(nil)) C:((nil),0x00000000,(nil))
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.156)[app:dbg]HIO: port 17 <Talk/hangup> msg <State><16>
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.157)[app:dbg]Port: 17:  Talk -> ReadyAfterInit (No errors)
Jan  1 01:05:49 tau user.info tau: 2.14.0.284|(49.157)[app:info]port 17: from state 'hangup' to state 'hangup'
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.162)[app:dbg]ITC: [msg_fxs_state] -> group
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.163)[app:dbg][SG] Port 17: new state is hangup
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.165)[app:dbg]vapi_cb_req(): Conn 17 CALLBACK msg (level = 0x0; result = 0x0; req_id = 0x E21; len = 0)
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.166)[app:dbg]vapi: chan: 17 Callback request = 0x E21
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.166)[app:dbg]Conn 17: Stop tone - Successfull
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.167)[app:dbg]Port 17: chan: 17 check vapi queue ('busy''stop_tone') at vapi_cb_chan:4424
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.168)[app:dbg]Port 17: chan: 17: set vapi queue MSP to 'free' with  at vapi_cb_chan:4425
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.168)[app:dbg]VQ Port 17 + 00  :       'destroy'/         <none> + <-get_ptr 
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.169)[app:dbg]Port 17: chan: 17 check vapi queue ('free') at vapi_next_ops:3782
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.170)[app:dbg]Port 17 get cmd 'destroy' from queue at (vapi_next_ops:3799)
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.170)[app:dbg]Port: 17: Chan 17: current state is CREATED
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.171)[app:dbg]Port 17: chan: 17 check vapi queue ('free') at vapi_destroy_chan:1486
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.172)[app:dbg]Port 17: chan: 17: set vapi queue MSP to 'busy' with 'destroy' at vapi_destroy_chan:1509
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.172)[app:dbg]VQ Port 17 = MSP :       'destroy' =
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.173)[app:dbg]Chan 17: CREATED -> DESTROYING
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.173)[app:dbg]vapi: destroy: Destroy mediaforks on TDM 17
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.174)[app:dbg]vapi: destroy: TDM 17 get statistic
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.175)[app:dbg]Port 17: chan: 17 check vapi queue ('busy''destroy') at vapi_next_ops:3927
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.177)[app:dbg]vapi_cb_req(): Conn 17 CALLBACK msg (level = 0x0; result = 0x0; req_id = 0x 15E; len = 208)
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.179)[app:dbg]vapi: chan: 17 Callback request = 0x 15E
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.179)[app:dbg]port 17: (chan 17) get port STATISTIC
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.180)[app:dbg]port 17: Rx_pack = 0
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.181)[app:dbg]port 17: Rx_oct  = 0
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.181)[app:dbg]port 17: Lost_pack  = 0
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.182)[app:dbg]port 17: Tx_pack = 0
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.182)[app:dbg]port 17: Tx_oct  = 0
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.183)[app:dbg]port 17: peak_jiter = 0
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.184)[app:dbg]vapi: destroy: TDM 17 Destroy
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.185)[app:dbg]Port 17: chan: 17 check vapi queue ('busy''destroy') at vapi_cb_chan:4418
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.192)[app:dbg]vapi_cb_req(): Conn 17 CALLBACK msg (level = 0x0; result = 0x0; req_id = 0x 103; len = 0)
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.193)[app:dbg]vapi: chan: 17 Callback request = 0x 103
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.194)[app:dbg]vapi: destroy: reset and turn off RTCP timers
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.194)[app:dbg]Chan 17: DESTROYING -> INITIAL
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.195)[app:dbg]vapi: destroy: Done (port 17) - TDM-just actions
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.196)[app:dbg]Port 17: chan: 17 check vapi queue ('busy''destroy') at vapi_cb_chan:4424
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.196)[app:dbg]Port 17: chan: 17: set vapi queue MSP to 'free' with  at vapi_cb_chan:4425
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.197)[app:dbg]Port 17: chan: 17 check vapi queue ('free') at vapi_next_ops:3782
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.251)[app:dbg]HIO: port 18 <ReadyAfterInit/hangup> msg <State><16>
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.252)[app:dbg]HIO: port 19 <ReadyAfterInit/hangup> msg <State><16>
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.259)[app:dbg]HIO: port 16 <ReadyAfterInit/hangup> msg <State><16>
Jan  1 01:05:49 tau user.debug tau: 2.14.0.284|(49.260)[app:dbg]HIO: port 17 <ReadyAfterInit/hangup> msg <State><16>