12:16:39.182[sip]   a=fmtp:96 0-15
12:16:39.182[sip]   a=sdpmangled:yes
12:16:39.182[sip]   ------------------------------------------------------------------------
12:16:39.182[sip]send 887 bytes to udp/[81.88.86.11]:5060 at 00:03:05.980000:
12:16:39.182[sip]   ------------------------------------------------------------------------
12:16:39.182[sip]   SIP/2.0 200 OK
12:16:39.182[sip]   Via: SIP/2.0/UDP 81.88.86.11:5060;branch=z9hG4bK9c6c.006bcc72.0
12:16:39.182[sip]   From: "79161209471"<sip:79161209471@mangosip.ru>;tag=091c0e45
12:16:39.182[sip]   To: <sip:user2@peggisu.mangosip.ru>;tag=3Qa410grtt40F
12:16:39.182[sip]   Call-ID: MTUzM2VlY2NhNDJlMjIyMGNkYTNmMjY2OWRjMTI2YWM.
12:16:39.182[sip]   CSeq: 2 UPDATE
12:16:39.182[sip]   Contact: <sip:user2@10.30.0.200:5077>
12:16:39.182[sip]   User-Agent: TAU-8.IP/2.0.0 SN/VI33001750 sofia-sip/1.12.10
12:16:39.192[sip]   Accept: application/sdp
12:16:39.192[sip]   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, INFO
12:16:39.192[sip]   Supported: timer, 100rel, replaces
12:16:39.192[sip]   Session-Expires: 1800;refresher=uas
12:16:39.192[sip]   Min-SE: 120
12:16:39.192[sip]   Content-Type: application/sdp
12:16:39.192[sip]   Content-Disposition: session
12:16:39.192[sip]   Content-Length: 225
12:16:39.192[sip]
12:16:39.192[sip]   v=0
12:16:39.192[sip]   o=- 1687452806008840352 5468881676689828319 IN IP4 10.30.0.200
12:16:39.192[sip]   s=Session SDP
12:16:39.192[sip]   c=IN IP4 10.30.0.200
12:16:39.192[sip]   t=0 0
12:16:39.192[sip]   m=audio 23000 RTP/AVP 8 96
12:16:39.192[sip]   a=rtpmap:8 PCMA/8000
12:16:39.192[sip]   a=rtpmap:96 telephone-event/8000
12:16:39.192[sip]   a=fmtp:96 0-15
12:16:39.192[sip]   a=ptime:20
12:16:39.192[sip]   ------------------------------------------------------------------------
12:16:39.192[app:dbg]got nua_i_update : 200(OK)
12:16:39.192[app:dbg]got nua_i_state : 200(OK)
12:16:39.192[app:dbg]NO SIP IN nua_i_state == 200 : OK
12:16:39.192[app:dbg]self_i_state(): call state 8: or as : local sdp remote sdp : sdp_init have_oc
12:16:39.192[app:dbg]sip: call 02070000: SDP offer received
12:16:39.192[app:dbg]sdp_codecs_init() init call sdp (offer)
12:16:39.192[app:dbg]sdp_codecs_set_ssup() ssup present 0 ssup yes
12:16:39.192[app:dbg]sdp_codecs_set_rfc2833() present pt 96 remote fmtp 0-15, local fmtp 0-15
12:16:39.192[app:dbg]attr: name: sdpmangled value: yes
12:16:39.192[app:dbg]sip: call 02070000: media stream 0, creating proposed audio channel, remote RTP 81.88.86.87:22800
12:16:39.192[app:dbg]sip: call 02070000: select audio media
12:16:39.192[app:dbg]G711A: PT 8
12:16:39.192[app:dbg]sip: call 02070000: remote SDP offer copy
12:16:39.192[app:dbg]sip: call 02070000: SDP answer sent for the first invite
12:16:39.192[app:dbg]sip: call 02070000: destroying channel of media stream 0
12:16:39.192[app:dbg]call 0x02070000 (ep 7) :: TX stop, RX stop, <stop> (self_destroy_current_media)
12:16:39.192[app:dbg]sip -[msg_set_media]-> pbx
12:16:39.192[app:dbg]self_start_media: 1. handle call id 0x02070000, call id 0x02070000
12:16:39.192[app:dbg]sip: set options: call 02070000: media stream 0: 10.30.0.200:23000 -> 81.88.86.87:22800: MFPT 0 <drop>
12:16:39.192[app:dbg]self_itc_codec(): payload 8
12:16:39.192[app:dbg]self_itc_codec(): payload 8
12:16:39.192[app:dbg]Supported codec[0]: <G.711A>:8, vbd off, vad on, ecan on
12:16:39.202[app:dbg]sdp_codecs_get_rfc2833: present=1 pt=96
12:16:39.202[app:dbg]validate_ptime() codec G.711A, ptime 20, check_bigger 1, present 1
12:16:39.202[app:dbg]validate_ptime() using 20
12:16:39.202[app:dbg]sdp_codecs_set_ptime() ptime present : 20
12:16:39.202[app:dbg]self_start_media: 2. handle call id 0x02070000, call id 0x02070000
12:16:39.202[app:dbg]sip -[msg_set_media]-> pbx
12:16:39.202[app:dbg]sip: call 02070000: local SDP offer copy
12:16:39.202[app:dbg]sip: call 02070000: ACK from sip:79161209471@mangosip.ru
12:16:39.202[app:dbg]sip: call 02070000: ACK from sip:79161209471@mangosip.ru
12:16:39.202[app:dbg]got nua_i_active : 200(Call active)
12:16:39.202[app:dbg]NO SIP IN nua_i_active == 200 : Call active
12:16:39.202[app:dbg]ITC: [msg_set_media] -> pbx
12:16:39.212[app:dbg]self_on_set_media: call id 0x02070000 tx/rx 0/0
12:16:39.212[app:dbg]dump_port_calls() SLIC 7:
12:16:39.212[app:dbg]Q:(0x310c00,0x02070000,(nil))
12:16:39.212[app:dbg]H:((nil),0x00000000,(nil),0) W:((nil),0x00000000,(nil)) N:((nil),0x00000000,(nil)) H2:((nil),0x00000000,(nil))
12:16:39.212[app:dbg]SLIC 7: TX stop / RX stop
12:16:39.212[app:dbg]SLIC 7: send only 0
12:16:39.212[app:dbg]incom_calls_set_media_started() call 0x02070000, group -1, task <sip> media stopped
12:16:39.212[app:dbg]CMD_SET_VOICE: port = 7
12:16:39.212[app:dbg]Port 7: check vapi queue ('free') at vapi_start_stop_chan:1623
12:16:39.212[app:dbg]Chan 7: current state is CREATED
12:16:39.212[app:dbg]vapi: Conn 7. start_stop voice chan, TX stop, RX stop
12:16:39.212[app:dbg]Port 7: set vapi queue MSP to 'busy' with 'set voice' at vapi_start_stop_chan:1666
12:16:39.212[app:dbg]VQ Conn 7 = MSP :     'set voice' =
12:16:39.212[app:dbg]vapi_cb_req: 7 0 result 0x00000000 requid 0x00000401
12:16:39.222[app:dbg]ITC: [msg_set_media] -> pbx
12:16:39.222[app:dbg]self_on_set_media: call id 0x02070000 tx/rx 1/1
12:16:39.222[app:dbg]dump_port_calls() SLIC 7:
12:16:39.222[app:dbg]Q:(0x310c00,0x02070000,(nil))
12:16:39.222[app:dbg]H:((nil),0x00000000,(nil),0) W:((nil),0x00000000,(nil)) N:((nil),0x00000000,(nil)) H2:((nil),0x00000000,(nil))
12:16:39.222[app:dbg]SLIC 7: TX start / RX start: 10.30.0.200:23000->81.88.86.87:22800, <G.711A:8>
12:16:39.222[app:dbg]SLIC 7: send only 0 vad 1 g723_hr 1 vbd 0, ecan 1 rfc2833 pt 96, NSE pt 0, MFPT 0
12:16:39.222[app:dbg]incom_calls_set_media_started() call 0x02070000, group -1, task <sip> media started
12:16:39.222[app:dbg]self_set_media_start(): set ptime to 20
12:16:39.222[app:dbg]port_set_ip_param
12:16:39.222[app:dbg]set media param for '7', 10.30.0.200:23000, mode=local, random 26
12:16:39.222[app:dbg]port_set_ip_param
12:16:39.222[app:dbg]set media param for '7', 81.88.86.87:22800, mode=remote, random 26
12:16:39.222[app:dbg]CMD_CREATE_CONN: port = 7
12:16:39.222[app:dbg]Port 7: check vapi queue ('busy''set voice') at vapi_create_chan:694
12:16:39.222[app:dbg]Port 7 put cmd 'create',cur 'set voice' to queue at (vapi_create_chan:700)
12:16:39.222[app:dbg]VQ Conn 7 = MSP :     'set voice' =
12:16:39.222[app:dbg]VQ Conn 7 + 00  :        'create'  + <-get_ptr
12:16:39.222[app:dbg]SLIC 7: starting media (G.711A) 10.30.0.200:23000 -> 81.88.86.87:22800
12:16:39.222[app:dbg]port 7: start voice - first time
12:16:39.222[app:dbg]port_start_voice() chan 07: remote IP <81.88.86.87> (arp query 0 times)
12:16:39.222[app:dbg]chan 7: get mac succesfull, repeat 0 times
12:16:39.222[app:dbg]CMD_START_VOICE: port = 7
12:16:39.222[app:dbg]vapi_set_chan_param: chan=7 hold=0 deactivate=0
12:16:39.222[app:dbg]Port 7: check vapi queue ('busy''set voice') at vapi_set_chan_param:2136
12:16:39.222[app:dbg]Port 7 put cmd 'start voice',cur 'set voice' to queue at (vapi_set_chan_param:2148)
12:16:39.222[app:dbg]VQ Conn 7 = MSP :     'set voice' =
12:16:39.222[app:dbg]VQ Conn 7 + 00  :        'create'  + <-get_ptr
12:16:39.222[app:dbg]VQ Conn 7 + 01  :   'start voice'  +
12:16:39.222[app:dbg]vapi_proc_event: VAPI_CB
12:16:39.222[app:dbg]vapi_cb_chan: chan 7 reqest_id 0x00000401 result 0x00000000
12:16:39.222[app:dbg]vapi: conn 7. RTCP disabled
12:16:39.222[app:dbg]vapi_cb_req: 7 0 result 0x00000000 requid 0x000004ff
12:16:39.232[app:dbg]vapi_proc_event: VAPI_CB
12:16:39.232[app:dbg]vapi_cb_chan: chan 7 reqest_id 0x000004ff result 0x00000000
12:16:39.232[app:dbg]Conn 7: Set voice mode successeful
12:16:39.232[app:dbg]Stop all medias on chan 7
12:16:39.232[app:dbg]Port 7: check vapi queue ('busy''set voice') at vapi_next_ops:2532
12:16:39.232[app:dbg]Port 7 get cmd 'create' from queue at (vapi_next_ops:2551)
12:16:39.232[app:dbg]VQ Conn 7 + 01  :   'start voice'  + <-get_ptr
12:16:39.232[app:dbg]Port 7: check vapi queue ('free') at vapi_create_chan:694
12:16:39.232[app:dbg]Chan 7: current state is CREATED
12:16:39.232[app:dbg]chan 7: no need to create - already exists
12:16:39.232[app:dbg]Port 7: check vapi queue ('free') at vapi_next_ops:2694
12:16:39.232[app:dbg]Port 7: check vapi queue ('free') at vapi_next_ops:2532
12:16:39.232[app:dbg]Port 7 get cmd 'start voice' from queue at (vapi_next_ops:2551)
12:16:39.232[app:dbg]vapi_set_chan_param: chan=7 hold=0 deactivate=0
12:16:39.232[app:dbg]Port 7: check vapi queue ('free') at vapi_set_chan_param:2136
12:16:39.232[app:dbg]Chan 7: current state is CREATED
12:16:39.232[app:dbg]Port 7: set vapi queue MSP to 'busy' with 'start voice' at vapi_set_chan_param:2160
12:16:39.232[app:dbg]VQ Conn 7 = MSP :   'start voice' =
12:16:39.232[app:dbg]Conn 7 Eth src=a8:f9:4b:08:e2:fa, dst=00:00:00:00:00:00
12:16:39.232[app:dbg]Conn 7 IP src=10.30.0.200:23000, dst=81.88.86.87:22800
12:16:39.232[app:dbg]CHECK REQID: 0x00000502(Conn 7)
12:16:39.232[app:dbg]vapi: Conn 7. Disable - Ok
12:16:39.232[app:dbg]Mute all RX-TX medias on SLIC 7
12:16:39.232[app:dbg]Mute media on chan 7[mute 1]
12:16:39.232[app:dbg]vapi_cb_req: 7 0 result 0x00000000 requid 0x00000502
12:16:39.242[app:dbg]vapi_proc_event: VAPI_CB
12:16:39.242[app:dbg]vapi_cb_chan: chan 7 reqest_id 0x00000502 result 0x00000000
12:16:39.242[app:dbg]VOIP_DISABLE: chan = 7
12:16:39.242[app:dbg]vapi_cb_setchan: chan 7 deactivate 0
12:16:39.242[app:dbg]vapi: create: TDM channel 7 Set SSRC to 528F55B9
12:16:39.242[app:dbg]vapi: Conn 7. Set src/dst eth mac - Ok
12:16:39.242[app:dbg]Reserved IP: 192.168.253.1
12:16:39.242[app:dbg]vapi_cb_setchan: ch7. msp_ip = 192.168.253.2
12:16:39.242[app:dbg]IP PARAMS: 1FDA8C0 30000 2FDA8C0 30000
12:16:39.242[app:dbg]vapi: Conn 7. Set src/dst ip addr - ok
12:16:39.242[app:dbg]Create RX-TX media for SLIC 7(sendonly: 0, rtcp: 0)
12:16:39.242[app:dbg]Can't bind - try to clear binding call from prev connection
12:16:39.242[app:dbg]Delete all RX-TX with RTP port = 23000
12:16:39.242[app:dbg]Clear media from SLIC 7
12:16:39.242[app:dbg]vapi_cb_req: 7 0 result 0x00000000 requid 0x00000508
12:16:39.252[app:dbg]vapi_proc_event: VAPI_CB
12:16:39.252[app:dbg]vapi_cb_chan: chan 7 reqest_id 0x00000508 result 0x00000000
12:16:39.252[app:dbg]VOIP_SET_IP: chan = 7
12:16:39.252[app:dbg]vapi_cb_setchan: chan 7 deactivate 0
12:16:39.252[app:dbg]chan 7. vapi_cb_setchan: configure ecan on
12:16:39.252[app:dbg]vapi_passthru_echocan_cb() NLP, DCRF enabled, session 0, on 1, value 0x8007
12:16:39.252[app:dbg]vapi_cb_req: 7 0 result 0x00000000 requid 0x00000547
12:16:39.262[app:dbg]vapi_proc_event: VAPI_CB
12:16:39.262[app:dbg]vapi_cb_chan: chan 7 reqest_id 0x00000547 result 0x00000000
12:16:39.262[app:dbg]VOIP_SSRC_FILT: chan = 7
12:16:39.262[app:dbg]vapi_cb_setchan: chan 7 deactivate 0
12:16:39.262[app:dbg]chan 7. vapi_cb_setchan: VOIP_SSRC_FILT
12:16:39.262[app:dbg]vapi_cb_setchan: ch7. msp_ip = 192.168.253.2
12:16:39.262[app:dbg]RTCP IP PARAMS: 1FDA8C0 30001 2FDA8C0 30001
12:16:39.262[app:dbg]vapi_cb_req: 7 0 result 0x00000000 requid 0x0000052b
12:16:39.272[app:dbg]vapi_proc_event: VAPI_CB
12:16:39.272[app:dbg]vapi_cb_chan: chan 7 reqest_id 0x0000052b result 0x00000000
12:16:39.272[app:dbg]VOIP_SET_IP2: chan = 7
12:16:39.272[app:dbg]vapi_cb_setchan: chan 7 deactivate 0
12:16:39.272[app:dbg]chan 7. vapi_cb_setchan: VOIP_SET_PT
12:16:39.272[app:dbg]for chan <7> set codec type = 5 'G711A'
12:16:39.272[app:dbg]vapi_cb_req: 7 0 result 0x00000000 requid 0x0000054e
12:16:39.282[app:dbg]vapi_proc_event: VAPI_CB
12:16:39.282[app:dbg]vapi_cb_chan: chan 7 reqest_id 0x0000054e result 0x00000000
12:16:39.282[app:dbg]UNKNOWN_CMD: chan = 7
12:16:39.282[app:dbg]vapi_cb_setchan: chan 7 deactivate 0
12:16:39.282[app:dbg]chan 7. vapi_cb_setchan: VOIP_SET_CODEC
12:16:39.282[app:dbg]set_packet_interval = 20
12:16:39.282[app:dbg]vapi: Conn 7. Set 'Packet interval' 20
12:16:39.282[app:dbg]chan 7. vapi_cb_setchan: VOIP_SET_PACKET
12:16:39.282[app:dbg]SET TX PT: 96
12:16:39.282[app:dbg]vapi_cb_req: 7 0 result 0x00000000 requid 0x00000510
12:16:39.292[app:dbg]vapi_proc_event: VAPI_CB
12:16:39.292[app:dbg]vapi_cb_chan: chan 7 reqest_id 0x00000510 result 0x00000000
12:16:39.292[app:dbg]VOIP_SET_PACKET2: chan = 7
12:16:39.292[app:dbg]vapi_cb_setchan: chan 7 deactivate 0
12:16:39.292[app:dbg]chan 7. vapi_cb_setchan: VOIP_SET_PACKET2
12:16:39.292[app:dbg]SET RX PT: 96
12:16:39.292[app:dbg]vapi_cb_req: 7 0 result 0x00000000 requid 0x00000513
12:16:39.302[app:dbg]vapi: generic event, code 5 <SSRC change>, conn 0
12:16:39.312[app:dbg]vapi_proc_event: VAPI_CB
12:16:39.312[app:dbg]vapi_cb_chan: chan 7 reqest_id 0x00000513 result 0x00000000
12:16:39.312[app:dbg]VOIP_SET_DTMFOPT: chan = 7
12:16:39.312[app:dbg]vapi_cb_setchan: chan 7 deactivate 0
12:16:39.312[app:dbg]vapi: Chan 7 set chach (packet mode)
12:16:39.312[app:dbg]chan 7. vapi_cb_setchan: VOIP_SET_DTMFOPT dtmf 1, pt 96
12:16:39.312[app:dbg]Enable RFC2833 events
12:16:39.312[app:dbg]Set RFC2833 PT: 96(01A6, 60FF)
12:16:39.312[app:dbg]chan 7. vapi_cb_setchan: VOIP_SET_DTMFOPT2
12:16:39.312[app:dbg]chan 7. vapi_cb_setchan: VOIP_SET_PT2
12:16:39.312[app:dbg]vapi: Conn 7. Enable RTP indication
12:16:39.312[app:dbg]chan 7. vapi_cb_setchan: VOIP_ENABLE_RTP_IND
12:16:39.312[app:dbg]chan 7: set jitter buffer options
12:16:39.312[app:dbg]chan 7. vapi_cb_setchan: VOIP_SET_INDCTL
12:16:39.312[app:dbg]chan 7. vapi_cb_setchan: VOIP_SET_JBOPT
12:16:39.312[app:dbg]vapi: Conn 7. Set tone ctl options
12:16:39.312[app:dbg]chan 7. vapi_cb_setchan: VOIP_SET_VLAN
12:16:39.312[app:dbg]VAD: 1 CNG: 1 PTE: 20
12:16:39.312[app:dbg]vapi_cb_req: 7 0 result 0x00000000 requid 0x00000516
12:16:39.322[app:dbg]vapi_proc_event: VAPI_CB
12:16:39.322[app:dbg]vapi_cb_chan: chan 7 reqest_id 0x00000516 result 0x00000000
12:16:39.322[app:dbg]VOIP_SET_VCEOPT: chan = 7
12:16:39.322[app:dbg]vapi_cb_setchan: chan 7 deactivate 0
12:16:39.322[app:dbg]chan 7. vapi_cb_setchan: VOIP_SET_VCEOPT
12:16:39.322[app:dbg]vapi_cb_req: 7 0 result 0x00000000 requid 0x00000518
12:16:39.332[app:dbg]vapi_proc_event: VAPI_CB
12:16:39.332[app:dbg]vapi_cb_chan: chan 7 reqest_id 0x00000518 result 0x00000000
12:16:39.332[app:dbg]VOIP_SET_VOICE: chan = 7
12:16:39.332[app:dbg]vapi_cb_setchan: chan 7 deactivate 0
12:16:39.332[app:dbg]vapi_cb_setchan() Conn 7: set eActive state ok
12:16:39.332[app:dbg]Port 7: check vapi queue ('busy''start voice') at vapi_next_ops:2532
12:16:39.342[app:dbg]vapi_proc_event: eVAPI_UNDEFINED_EVENT
12:16:39.342[app:dbg]vapi: Conn 7. event 'RTP Monitor Ind': Start RTP stream , PT 0x0008 'PCM-A', silence 0
12:16:40.132[sip]recv 269 bytes from udp/[81.88.86.11]:5060 at 00:03:06.930000:
12:16:40.132[sip]   ------------------------------------------------------------------------
12:16:40.132[sip]   OPTIONS sip:*.*.*.*:5077 SIP/2.0
12:16:40.132[sip]   Via: SIP/2.0/UDP 81.88.86.11:5060;branch=z9hG4bK5475137
12:16:40.132[sip]   From: sip:nat_pinger@mangosip.ru;tag=bc2936c3
12:16:40.132[sip]   To: sip:*.*.*.*:5077
12:16:40.132[sip]   Call-ID: 5cbefec2-98ca3e76-9a37@81.88.86.11
12:16:40.132[sip]   CSeq: 1 OPTIONS
12:16:40.132[sip]   Max-Forwards: 70
12:16:40.132[sip]   Content-Length: 0
12:16:40.132[sip]
12:16:40.132[sip]   ------------------------------------------------------------------------
12:16:40.132[app:dbg]got nua_i_options : 100(Trying)
12:16:40.132[app:dbg]NO CALL IN nua_i_options == 100 : Trying
12:16:40.132[app:dbg]sdp_codecs_init() init call sdp (offer)
12:16:40.132[app:dbg]sdp_codecs_dump() ssup present on, ecan absent on, rfc present 101, nse absent 0, ptime present 20
12:16:40.132[app:dbg]sdp_codecs_dump() G723: none
12:16:40.132[app:dbg]sdp_codecs_dump() G711A:
12:16:40.132[app:dbg]sdp_codecs_dump() PT 8, vbd absent off
12:16:40.132[app:dbg]sdp_codecs_dump() G711U:
12:16:40.132[app:dbg]sdp_codecs_dump() PT 0, vbd absent off
12:16:40.132[app:dbg]sdp_codecs_g711a_add_to_media_attrs() g711a: have one at last
12:16:40.132[app:dbg]sdp_codecs_g711u_add_to_media_attrs() g711u: have one at last
12:16:40.132[app:dbg]sdp_codecs_rfc2833_add_to_media_attrs() present, pt 101
12:16:40.132[app:dbg]sdp_codecs_nse_add_to_media_attrs() absent, pt 0
12:16:40.132[app:dbg]sdp_codecs_ptime_add_to_attrs() ptime present 20
12:16:40.132[app:dbg]sdp_codecs_ecan_add_to_attrs() ecan absent on
12:16:40.132[app:dbg]sdp_codecs_ssup_add_to_attrs() ssup present on
12:16:40.132[app:dbg]sdp_tail:  8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=silenceSupp:on - - - -
12:16:40.132[app:dbg]make_sdp: SDP: s=Session SDP
m=audio 0 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=silenceSupp:on - - - -
12:16:40.132[app:dbg]== current tester cb ==self_i_outbound=============================
12:16:40.132[sip]send 826 bytes to udp/[81.88.86.11]:5060 at 00:03:06.930000:
12:16:40.132[sip]   ------------------------------------------------------------------------
12:16:40.132[sip]   SIP/2.0 200 OK
12:16:40.132[sip]   Via: SIP/2.0/UDP 81.88.86.11:5060;branch=z9hG4bK5475137
12:16:40.132[sip]   From: sip:nat_pinger@mangosip.ru;tag=bc2936c3
12:16:40.142[sip]   To: <sip:*.*.*.*:5077>;tag=59vN5pjZmcH6p
12:16:40.142[sip]   Call-ID: 5cbefec2-98ca3e76-9a37@81.88.86.11
12:16:40.142[sip]   CSeq: 1 OPTIONS
12:16:40.142[sip]   Contact: <sip:user2@10.30.0.200:5077>
12:16:40.142[sip]   User-Agent: TAU-8.IP/2.0.0 SN/VI33001750 sofia-sip/1.12.10
12:16:40.142[sip]   Accept: application/sdp
12:16:40.142[sip]   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, INFO
12:16:40.142[sip]   Supported: timer, 100rel, replaces
12:16:40.142[sip]   Content-Type: application/sdp
12:16:40.142[sip]   Content-Length: 286
12:16:40.142[sip]
12:16:40.142[sip]   v=0
12:16:40.142[sip]   o=- 7690257898720939935 8574190216738495423 IN IP4 10.30.0.200
12:16:40.142[sip]   s=Session SDP
12:16:40.142[sip]   c=IN IP4 10.30.0.200
12:16:40.142[sip]   t=0 0
12:16:40.142[sip]   m=audio 0 RTP/AVP 8 0 101
12:16:40.142[sip]   a=rtpmap:8 PCMA/8000
12:16:40.142[sip]   a=rtpmap:0 PCMU/8000
12:16:40.142[sip]   a=rtpmap:101 telephone-event/8000
12:16:40.142[sip]   a=fmtp:101 0-16
12:16:40.142[sip]   a=inactive
12:16:40.142[sip]   a=ptime:20
12:16:40.142[sip]   a=silenceSupp:on - - - -
12:16:40.142[sip]   ------------------------------------------------------------------------
12:16:41.142[sip]recv 269 bytes from udp/[81.88.86.11]:5060 at 00:03:07.940000:
12:16:41.142[sip]   ------------------------------------------------------------------------
12:16:41.142[sip]   OPTIONS sip:*.*.*.*:5077 SIP/2.0
12:16:41.142[sip]   Via: SIP/2.0/UDP 81.88.86.11:5060;branch=z9hG4bK2320075
12:16:41.142[sip]   From: sip:nat_pinger@mangosip.ru;tag=6a1716c3
12:16:41.142[sip]   To: sip:*.*.*.*:5077
12:16:41.142[sip]   Call-ID: 5cbefec2-46b81e76-aa37@81.88.86.11
12:16:41.142[sip]   CSeq: 1 OPTIONS
12:16:41.142[sip]   Max-Forwards: 70
12:16:41.142[sip]   Content-Length: 0
12:16:41.142[sip]
12:16:41.142[sip]   ------------------------------------------------------------------------
12:16:41.152[app:dbg]got nua_i_options : 100(Trying)
12:16:41.152[app:dbg]NO CALL IN nua_i_options == 100 : Trying
12:16:41.152[app:dbg]sdp_codecs_init() init call sdp (offer)
12:16:41.152[app:dbg]sdp_codecs_dump() ssup present on, ecan absent on, rfc present 101, nse absent 0, ptime present 20
12:16:41.152[app:dbg]sdp_codecs_dump() G723: none
12:16:41.152[app:dbg]sdp_codecs_dump() G711A:
12:16:41.152[app:dbg]sdp_codecs_dump() PT 8, vbd absent off
12:16:41.152[app:dbg]sdp_codecs_dump() G711U:
12:16:41.152[app:dbg]sdp_codecs_dump() PT 0, vbd absent off
12:16:41.152[app:dbg]sdp_codecs_g711a_add_to_media_attrs() g711a: have one at last
12:16:41.152[app:dbg]sdp_codecs_g711u_add_to_media_attrs() g711u: have one at last
12:16:41.152[app:dbg]sdp_codecs_rfc2833_add_to_media_attrs() present, pt 101
12:16:41.152[app:dbg]sdp_codecs_nse_add_to_media_attrs() absent, pt 0
12:16:41.152[app:dbg]sdp_codecs_ptime_add_to_attrs() ptime present 20
12:16:41.152[app:dbg]sdp_codecs_ecan_add_to_attrs() ecan absent on
12:16:41.152[app:dbg]sdp_codecs_ssup_add_to_attrs() ssup present on
12:16:41.152[app:dbg]sdp_tail:  8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=silenceSupp:on - - - -
12:16:41.152[app:dbg]make_sdp: SDP: s=Session SDP
m=audio 0 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=silenceSupp:on - - - -
12:16:41.152[app:dbg]== current tester cb ==self_i_outbound=============================
12:16:41.152[sip]recv 269 bytes from udp/[81.88.86.11]:5060 at 00:03:07.940000:
12:16:41.152[sip]   ------------------------------------------------------------------------
12:16:41.152[sip]   OPTIONS sip:*.*.*.*:5077 SIP/2.0
12:16:41.152[sip]   Via: SIP/2.0/UDP 81.88.86.11:5060;branch=z9hG4bK9778583
12:16:41.152[sip]   From: sip:nat_pinger@mangosip.ru;tag=3c1716c3
12:16:41.152[sip]   To: sip:*.*.*.*:5077
12:16:41.152[sip]   Call-ID: 5cbefec2-18b81e76-aa37@81.88.86.11
12:16:41.152[sip]   CSeq: 1 OPTIONS
12:16:41.152[sip]   Max-Forwards: 70
12:16:41.152[sip]   Content-Length: 0
12:16:41.152[sip]
12:16:41.152[sip]   ------------------------------------------------------------------------
12:16:41.152[app:dbg]got nua_i_options : 100(Trying)
12:16:41.152[app:dbg]NO CALL IN nua_i_options == 100 : Trying
12:16:41.152[app:dbg]sdp_codecs_init() init call sdp (offer)
12:16:41.152[app:dbg]sdp_codecs_dump() ssup present on, ecan absent on, rfc present 101, nse absent 0, ptime present 20
12:16:41.162[app:dbg]sdp_codecs_dump() G723: none
12:16:41.162[app:dbg]sdp_codecs_dump() G711A:
12:16:41.162[app:dbg]sdp_codecs_dump() PT 8, vbd absent off
12:16:41.162[app:dbg]sdp_codecs_dump() G711U:
12:16:41.162[app:dbg]sdp_codecs_dump() PT 0, vbd absent off
12:16:41.162[app:dbg]sdp_codecs_g711a_add_to_media_attrs() g711a: have one at last
12:16:41.162[app:dbg]sdp_codecs_g711u_add_to_media_attrs() g711u: have one at last
12:16:41.162[app:dbg]sdp_codecs_rfc2833_add_to_media_attrs() present, pt 101
12:16:41.162[app:dbg]sdp_codecs_nse_add_to_media_attrs() absent, pt 0
12:16:41.162[app:dbg]sdp_codecs_ptime_add_to_attrs() ptime present 20
12:16:41.162[app:dbg]sdp_codecs_ecan_add_to_attrs() ecan absent on
12:16:41.162[app:dbg]sdp_codecs_ssup_add_to_attrs() ssup present on
12:16:41.162[app:dbg]sdp_tail:  8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=silenceSupp:on - - - -
12:16:41.162[app:dbg]make_sdp: SDP: s=Session SDP
m=audio 0 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=silenceSupp:on - - - -
12:16:41.162[app:dbg]== current tester cb ==self_i_outbound=============================
12:16:41.162[sip]send 825 bytes to udp/[81.88.86.11]:5060 at 00:03:07.960000:
12:16:41.162[sip]   ------------------------------------------------------------------------
12:16:41.162[sip]   SIP/2.0 200 OK
12:16:41.162[sip]   Via: SIP/2.0/UDP 81.88.86.11:5060;branch=z9hG4bK2320075
12:16:41.162[sip]   From: sip:nat_pinger@mangosip.ru;tag=6a1716c3
12:16:41.162[sip]   To: <sip:*.*.*.*:5077>;tag=6jpe7H32HN7rj
12:16:41.162[sip]   Call-ID: 5cbefec2-46b81e76-aa37@81.88.86.11
12:16:41.162[sip]   CSeq: 1 OPTIONS
12:16:41.162[sip]   Contact: <sip:user2@10.30.0.200:5077>
12:16:41.162[sip]   User-Agent: TAU-8.IP/2.0.0 SN/VI33001750 sofia-sip/1.12.10
12:16:41.162[sip]   Accept: application/sdp
12:16:41.162[sip]   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, INFO
12:16:41.162[sip]   Supported: timer, 100rel, replaces
12:16:41.162[sip]   Content-Type: application/sdp
12:16:41.162[sip]   Content-Length: 285
12:16:41.162[sip]
12:16:41.162[sip]   v=0
12:16:41.172[sip]   o=- 152970231580160577 7376096017057770867 IN IP4 10.30.0.200
12:16:41.172[sip]   s=Session SDP
12:16:41.172[sip]   c=IN IP4 10.30.0.200
12:16:41.172[sip]   t=0 0
12:16:41.172[sip]   m=audio 0 RTP/AVP 8 0 101
12:16:41.172[sip]   a=rtpmap:8 PCMA/8000
12:16:41.172[sip]   a=rtpmap:0 PCMU/8000
12:16:41.172[sip]   a=rtpmap:101 telephone-event/8000
12:16:41.172[sip]   a=fmtp:101 0-16
12:16:41.172[sip]   a=inactive
12:16:41.172[sip]   a=ptime:20
12:16:41.172[sip]   a=silenceSupp:on - - - -
12:16:41.172[sip]   ------------------------------------------------------------------------
12:16:41.172[sip]send 825 bytes to udp/[81.88.86.11]:5060 at 00:03:07.970000:
12:16:41.172[sip]   ------------------------------------------------------------------------
12:16:41.172[sip]   SIP/2.0 200 OK
12:16:41.172[sip]   Via: SIP/2.0/UDP 81.88.86.11:5060;branch=z9hG4bK9778583
12:16:41.172[sip]   From: sip:nat_pinger@mangosip.ru;tag=3c1716c3
12:16:41.172[sip]   To: <sip:*.*.*.*:5077>;tag=7UF78cm6eyXBe
12:16:41.172[sip]   Call-ID: 5cbefec2-18b81e76-aa37@81.88.86.11
12:16:41.172[sip]   CSeq: 1 OPTIONS
12:16:41.172[sip]   Contact: <sip:user2@10.30.0.200:5077>
12:16:41.172[sip]   User-Agent: TAU-8.IP/2.0.0 SN/VI33001750 sofia-sip/1.12.10
12:16:41.172[sip]   Accept: application/sdp
12:16:41.172[sip]   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, INFO
12:16:41.172[sip]   Supported: timer, 100rel, replaces
12:16:41.172[sip]   Content-Type: application/sdp
12:16:41.172[sip]   Content-Length: 285
12:16:41.182[sip]
12:16:41.182[sip]   v=0
12:16:41.182[sip]   o=- 2831905037428511232 395830600753473325 IN IP4 10.30.0.200
12:16:41.182[sip]   s=Session SDP
12:16:41.182[sip]   c=IN IP4 10.30.0.200
12:16:41.182[sip]   t=0 0
12:16:41.182[sip]   m=audio 0 RTP/AVP 8 0 101
12:16:41.182[sip]   a=rtpmap:8 PCMA/8000
12:16:41.182[sip]   a=rtpmap:0 PCMU/8000
12:16:41.182[sip]   a=rtpmap:101 telephone-event/8000
12:16:41.182[sip]   a=fmtp:101 0-16
12:16:41.182[sip]   a=inactive
12:16:41.182[sip]   a=ptime:20
12:16:41.182[sip]   a=silenceSupp:on - - - -
12:16:41.182[sip]   ------------------------------------------------------------------------
12:16:41.282[app:dbg]slic7. Event 8.
12:16:41.282[app:dbg]slic 7. Pre-On-hook event
12:16:41.282[app:dbg]HIO: preonhook TDM port '7', port enabled 1
12:16:41.282[app:dbg]CMD_STOP_TONE: port = 7
12:16:41.282[app:dbg]Port 7: check vapi queue ('free') at vapi_stop_tone_chan:1474
12:16:41.282[app:dbg]Chan 7: current state is CREATED
12:16:41.282[app:dbg]vapi_chan.c:1510: conn 7 peek cmd 'no event' from queue
12:16:41.282[app:dbg]Port 7: check vapi queue ('free') at __cmd_engine:320
12:16:41.282[app:dbg]Port 7: check vapi queue ('free') at vapi_next_ops:2532
12:16:41.762[app:dbg]slic7. Event 1.
12:16:41.762[app:dbg]slic 7. On-hook event
12:16:41.762[app:dbg]Set port 7 led to state 'LED_OFF'
12:16:41.762[app:dbg]HIO: onhook TDM port '7', port enabled 1
12:16:41.762[app:dbg]SLIC 7 (user2): onhook state: talking
12:16:41.762[app:dbg]regex ID 7: dial reset
12:16:41.762[app:dbg]pbx -[msg_clear]-> sip
12:16:41.762[app:dbg]ITC: [msg_clear] -> sip
12:16:41.762[app:dbg]call 02070000,flags(00000048): endpoint 7 cleared
12:16:41.762[app:dbg]sip: call 02070000: BYE to sip:user2@peggisu.mangosip.ru
12:16:41.762[sip]send 695 bytes to udp/[81.88.86.11]:5060 at 00:03:08.560000:
12:16:41.762[sip]   ------------------------------------------------------------------------
12:16:41.762[sip]   BYE sip:79161209471@81.88.86.11;did=596.8dbbf837 SIP/2.0
12:16:41.762[sip]   Via: SIP/2.0/UDP 10.30.0.200:5077;rport;branch=z9hG4bKS5j5y7y7gNXSQ
12:16:41.762[sip]   Max-Forwards: 70
12:16:41.762[sip]   From: <sip:user2@peggisu.mangosip.ru>;tag=3Qa410grtt40F
12:16:41.762[sip]   To: "79161209471" <sip:79161209471@mangosip.ru>;tag=091c0e45
12:16:41.762[sip]   Call-ID: MTUzM2VlY2NhNDJlMjIyMGNkYTNmMjY2OWRjMTI2YWM.
12:16:41.762[sip]   CSeq: 94 BYE
12:16:41.762[sip]   Contact: <sip:user2@10.30.0.200:5077>
12:16:41.762[sip]   User-Agent: TAU-8.IP/2.0.0 SN/VI33001750 sofia-sip/1.12.10
12:16:41.762[sip]   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, INFO
12:16:41.762[sip]   Supported: timer, 100rel, replaces
12:16:41.762[sip]   Reason: Q.850;cause=16;text="Normal call clearing"
12:16:41.762[sip]   Content-Length: 0
12:16:41.762[sip]   P-RTP-Stat: PS=16, OS=2752, PR=21, OR=3612, PL=0, JI=9
12:16:41.762[sip]
12:16:41.762[sip]   ------------------------------------------------------------------------
12:16:41.782[sip]recv 455 bytes from udp/[81.88.86.11]:5060 at 00:03:08.580000:
12:16:41.782[sip]   ------------------------------------------------------------------------
12:16:41.782[sip]   SIP/2.0 200 OK
12:16:41.782[sip]   Via: SIP/2.0/UDP 10.30.0.200:5077;received=*.*.*.*;rport=5077;branch=z9hG4bKS5j5y7y7gNXSQ
12:16:41.782[sip]   Contact: <sip:79161209471@81.88.86.11;did=596.8dbbf837>
12:16:41.782[sip]   To: "79161209471"<sip:79161209471@mangosip.ru>;tag=091c0e45
12:16:41.782[sip]   From: <sip:user2@peggisu.mangosip.ru>;tag=3Qa410grtt40F
12:16:41.782[sip]   Call-ID: MTUzM2VlY2NhNDJlMjIyMGNkYTNmMjY2OWRjMTI2YWM.
12:16:41.782[sip]   CSeq: 94 BYE
12:16:41.782[sip]   User-Agent: Softswitch2
12:16:41.782[sip]   Content-Length: 0
12:16:41.782[sip]   x-comm-id: 261:382213143
12:16:41.782[sip]   x-comm-context: 1701253372
12:16:41.782[sip]
12:16:41.782[sip]   ------------------------------------------------------------------------
12:16:41.782[app:dbg]got nua_r_bye : 200(OK)
12:16:41.782[app:dbg]sip: call 02070000: BYE/INFO: 200 OK
12:16:41.782[app:dbg]got nua_i_state : 200(to BYE)
12:16:41.782[app:dbg]NO SIP IN nua_i_state == 200 : to BYE
12:16:41.792[app:dbg]CMD_STOP_TONE: port = 7
12:16:41.792[app:dbg]Port 7: check vapi queue ('free') at vapi_stop_tone_chan:1474
12:16:41.792[app:dbg]Chan 7: current state is CREATED
12:16:41.792[app:dbg]vapi_chan.c:1510: conn 7 peek cmd 'no event' from queue
12:16:41.792[app:dbg]Port 7: check vapi queue ('free') at __cmd_engine:320
12:16:41.792[app:dbg]Port 7: check vapi queue ('free') at vapi_next_ops:2532
12:16:41.792[app:dbg]SLIC 7: reset
12:16:41.792[app:dbg]dump_port_calls() SLIC 7:
12:16:41.792[app:dbg]Q:(0x310c00,0x02070000,(nil))
12:16:41.792[app:dbg]H:((nil),0x00000000,(nil),0) W:((nil),0x00000000,(nil)) N:((nil),0x00000000,(nil)) H2:((nil),0x00000000,(nil))
12:16:41.792[app:dbg]vapi: chan 7: connection STATISTIC
12:16:41.792[app:dbg]vapi: chan 7: Rx_pack = 75
12:16:41.792[app:dbg]vapi: chan 7: Rx_oct  = 12900
12:16:41.792[app:dbg]vapi: chan 7: Lost_pack  = 0
12:16:41.792[app:dbg]vapi: chan 7: Tx_pack = 60
12:16:41.792[app:dbg]vapi: chan 7: Tx_oct  = 10002
12:16:41.792[app:dbg]vapi: chan 7: peak_jiter = 9
12:16:41.792[app:dbg]SLIC 7: Common port statistic
12:16:41.792[app:dbg]SLIC 7: Rx_pack = 75
12:16:41.792[app:dbg]SLIC 7: Rx_oct  = 12900
12:16:41.792[app:dbg]SLIC 7: Lost_pack  = 0
12:16:41.792[app:dbg]SLIC 7: Tx_pack = 60
12:16:41.792[app:dbg]SLIC 7: Tx_oct  = 10002
12:16:41.792[app:dbg]SLIC 7: peak_jiter = 9
12:16:41.792[app:dbg]SLIC 7: reset call 0x02070000 (active)
12:16:41.792[app:dbg]CMD_SET_VOICE: port = 7
12:16:41.792[app:dbg]Port 7: check vapi queue ('free') at vapi_start_stop_chan:1623
12:16:41.792[app:dbg]Chan 7: current state is CREATED
12:16:41.792[app:dbg]vapi: Conn 7. start_stop voice chan, TX stop, RX stop
12:16:41.792[app:dbg]Port 7: set vapi queue MSP to 'busy' with 'set voice' at vapi_start_stop_chan:1666
12:16:41.792[app:dbg]VQ Conn 7 = MSP :     'set voice' =
12:16:41.792[app:dbg]self_i_state(): call state 10: : : sdp_init have_oc
12:16:41.792[app:dbg]sip: call 02070000: terminated
12:16:41.792[app:dbg]self_callstate_terminated: call id = 02070000 need_exchange_at_answer = 0
12:16:41.802[app:dbg]incom_calls_set_media_started() call 0x02070000, group -1, task <sip> media stopped
12:16:41.802[app:dbg]vapi_cb_req: 7 0 result 0x00000000 requid 0x00000401
12:16:41.822[app:dbg]incom_calls_rem() rem call 0x02070000, group -1, task <sip> from list
12:16:41.822[app:dbg]free_final_mx: final_mx was NULL for SLIC 7
12:16:41.822[app:dbg]CMD_DESTROY_CONN: port = 7
12:16:41.822[app:dbg]Port 7: check vapi queue ('busy''set voice') at vapi_destroy_chan:890
12:16:41.822[app:dbg]Clear vapi queue of Port 7/chan 7
12:16:41.822[app:dbg]Port 7 put cmd 'destroy',cur 'set voice' to queue at (vapi_destroy_chan:897)
12:16:41.822[app:dbg]VQ Conn 7 = MSP :     'set voice' =
12:16:41.822[app:dbg]VQ Conn 7 + 00  :       'destroy'  + <-get_ptr
12:16:41.822[app:dbg]CMD_DESTROY_IPONLY_CONN: port = 7
12:16:41.822[app:dbg]Port 7: check vapi queue ('busy''set voice') at vapi_destroy_chan:890
12:16:41.822[app:dbg]Clear vapi queue of Port 7/chan 15
12:16:41.822[app:dbg]Port 7 put cmd 'destroy',cur 'set voice' to queue at (vapi_destroy_chan:897)
12:16:41.822[app:dbg]VQ Conn 15 = MSP :     'set voice' =
12:16:41.822[app:dbg]VQ Conn 15 + 00  :       'destroy'  + <-get_ptr
12:16:41.822[app:dbg]VQ Conn 15 + 01  :       'destroy' (hold) +
12:16:41.822[app:dbg]Port 7: user port 1, old state hangup, new state
12:16:41.822[app:dbg]Set port 7 led to state 'LED_OFF'
12:16:41.822[app:dbg]pbx -[msg_fxs_state]-> group
12:16:41.822[app:dbg]Delete all RX-TX medias from SLIC 7
12:16:41.822[app:dbg]ITC: [msg_fxs_state] -> group
12:16:41.822[app:dbg]-----[GM] self_fxs_state()
12:16:41.822[app:dbg]Port 7: new state is hangup
12:16:41.832[app:dbg]Delete all RX-TX medias from SLIC 15
12:16:41.842[app:dbg]dump_port_calls() SLIC 7:
12:16:41.842[app:dbg]Q:NONE
12:16:41.842[app:dbg]H:((nil),0x00000000,(nil),0) W:((nil),0x00000000,(nil)) N:((nil),0x00000000,(nil)) H2:((nil),0x00000000,(nil))
12:16:41.842[app:dbg]Set port 7 led to state 'LED_OFF'
12:16:41.852[app:dbg]vapi_proc_event: VAPI_CB
12:16:41.852[app:dbg]vapi_cb_chan: chan 7 reqest_id 0x00000401 result 0x00000000
12:16:41.852[app:dbg]vapi: conn 7. RTCP disabled
12:16:41.852[app:dbg]vapi_cb_req: 7 0 result 0x00000000 requid 0x000004ff
12:16:41.862[app:dbg]vapi_proc_event: VAPI_CB
12:16:41.862[app:dbg]vapi_cb_chan: chan 7 reqest_id 0x000004ff result 0x00000000
12:16:41.862[app:dbg]Conn 7: Set voice mode successeful
12:16:41.862[app:dbg]Stop all medias on chan 7
12:16:41.862[app:dbg]Port 7: check vapi queue ('busy''set voice') at vapi_next_ops:2532
12:16:41.862[app:dbg]Port 7 get cmd 'destroy' from queue at (vapi_next_ops:2551)
12:16:41.862[app:dbg]VQ Conn 7 + 01  :       'destroy' (hold) + <-get_ptr
12:16:41.862[app:dbg]Port 7: check vapi queue ('free') at vapi_destroy_chan:890
12:16:41.862[app:dbg]Destroying connection 7...
12:16:41.862[app:dbg]Chan 7: current state is CREATED
12:16:41.862[app:dbg]Port 7: set vapi queue MSP to 'busy' with 'destroy' at vapi_destroy_chan:916
12:16:41.862[app:dbg]VQ Conn 7 = MSP :       'destroy' =
12:16:41.862[app:dbg]VQ Conn 7 + 01  :       'destroy' (hold) + <-get_ptr
12:16:41.862[app:dbg]Chan 7: CREATED -> DESTROYING
12:16:41.862[app:dbg]Mute all RX-TX medias on SLIC 7
12:16:41.862[app:dbg]vapi_cb_req: 7 0 result 0x00000000 requid 0x0000014b
12:16:41.872[app:dbg]Delete all RX-TX medias from SLIC 7
12:16:41.872[app:dbg]vapi_proc_event: VAPI_CB
12:16:41.872[app:dbg]vapi_cb_chan: chan 7 reqest_id 0x0000014b result 0x00000000
12:16:41.872[app:dbg]vapi_cb_req: 7 0 result 0x00000000 requid 0x00000103
12:16:41.882[app:dbg]vapi_proc_event: VAPI_CB
12:16:41.882[app:dbg]vapi_cb_chan: chan 7 reqest_id 0x00000103 result 0x00000000
12:16:41.882[app:dbg]Conn 7 destroyed
12:16:41.882[app:dbg]Chan 7: DESTROYING -> INITIAL
12:16:41.882[app:dbg]Port 7: check vapi queue ('busy''destroy') at vapi_next_ops:2532
12:16:41.882[app:dbg]Port 7 get cmd 'destroy' from queue at (vapi_next_ops:2551)
12:16:41.882[app:dbg]Port 7: check vapi queue ('free') at vapi_destroy_chan:890
12:16:41.882[app:dbg]Destroying connection 15...
12:16:41.882[app:dbg]Chan 15: current state is INITIAL
12:16:41.882[app:dbg]Port 7: check vapi queue ('free') at vapi_next_ops:2694
12:16:41.882[app:dbg]Port 7: check vapi queue ('free') at vapi_next_ops:2532
12:16:41.912[app:dbg]slic7. Event 2.
12:16:41.912[app:dbg]slic 7. Off-hook event
12:16:41.912[app:dbg]Set port 7 led to state 'LED_ON'
12:16:41.912[app:dbg]HIO: offhook TDM port '7' port enabled 1
12:16:41.912[app:dbg]HIO: offhook TDM port '7' direction unknown -> outgoing
12:16:41.912[app:dbg]SLIC 7 (user2): offhook state: hangup
12:16:41.912[app:dbg]regex ID 7: dial reset
12:16:41.912[app:dbg]CMD_CREATE_CONN: port = 7
12:16:41.912[app:dbg]Port 7: check vapi queue ('free') at vapi_create_chan:694
12:16:41.912[app:dbg]Chan 7: current state is INITIAL
12:16:41.912[app:dbg]Port 7: set vapi queue MSP to 'busy' with 'create' at vapi_create_chan:720
12:16:41.912[app:dbg]VQ Conn 7 = MSP :        'create' =
12:16:41.912[app:dbg]Creating connection 7....
12:16:41.912[app:dbg]Chan 7: INITIAL -> CREATING
12:16:41.912[app:dbg]Created succefuly 7....
12:16:41.912[app:dbg]CMD_CREATE_CONN: port = 7
12:16:41.912[app:dbg]Port 7: check vapi queue ('busy''create') at vapi_create_chan:694
12:16:41.912[app:dbg]Port 7 put cmd 'create',cur 'create' to queue at (vapi_create_chan:700)
12:16:41.912[app:dbg]VQ Conn 7 = MSP :        'create' =
12:16:41.912[app:dbg]VQ Conn 7 + 02  :        'create'  + <-get_ptr
12:16:41.912[app:dbg]port_start_tone(7 21 0 0)
12:16:41.912[app:dbg]CMD_START_TONE: port = 7
12:16:41.912[app:dbg]Port 7: check vapi queue ('busy''create') at vapi_start_tone_chan:1384
12:16:41.912[app:dbg]Port 7 put cmd 'start_tone',cur 'create' to queue at (vapi_start_tone_chan:1394)
12:16:41.912[app:dbg]VQ Conn 7 = MSP :        'create' =
12:16:41.912[app:dbg]VQ Conn 7 + 02  :        'create'  + <-get_ptr
12:16:41.912[app:dbg]VQ Conn 7 + 03  :    'start_tone'  +
12:16:41.912[app:dbg]Port 7: user port 1, old state hangdown, new state
12:16:41.912[app:dbg]Set port 7 led to state 'LED_ON'
12:16:41.912[app:dbg]pbx -[msg_fxs_state]-> group
12:16:41.912[app:dbg]ITC: [msg_fxs_state] -> group
12:16:41.912[app:dbg]-----[GM] self_fxs_state()
12:16:41.912[app:dbg]Port 7: new state is hangdown
12:16:41.912[app:dbg]vapi_cb_req: 7 0 result 0x00000000 requid 0x0000004f
12:16:41.932[app:dbg]dump_port_calls() SLIC 7:
12:16:41.932[app:dbg]Q:NONE
12:16:41.932[app:dbg]H:((nil),0x00000000,(nil),0) W:((nil),0x00000000,(nil)) N:((nil),0x00000000,(nil)) H2:((nil),0x00000000,(nil))
12:16:41.942[app:dbg]vapi_proc_event: VAPI_CB
12:16:41.942[app:dbg]vapi_cb_chan: chan 7 reqest_id 0x0000004f result 0x00000000
12:16:41.942[app:dbg]vapi_cb_req: 7 0 result 0x00000000 requid 0x00000000
12:16:41.952[app:dbg]vapi_proc_event: VAPI_CB
12:16:41.952[app:dbg]vapi_cb_chan: chan 7 reqest_id 0x00000000 result 0x00000000
12:16:41.952[app:dbg]vapi: Conn 7 - << CREATED >>
12:16:41.952[app:dbg]vapi: Conn 7 - fix DTMF detector
12:16:41.952[app:dbg]vapi_cb_req: 7 0 result 0x00000000 requid 0x00000049
12:16:41.962[app:dbg]vapi_proc_event: VAPI_CB
12:16:41.962[app:dbg]vapi_cb_chan: chan 7 reqest_id 0x00000049 result 0x00000000
12:16:41.962[app:dbg]vapi: Conn 7 - fix CNG generator
12:16:41.962[app:dbg]vapi_cb_req: 7 0 result 0x00000000 requid 0x0000004c
12:16:41.972[app:dbg]vapi_proc_event: VAPI_CB
12:16:41.972[app:dbg]vapi_cb_chan: chan 7 reqest_id 0x0000004c result 0x00000000
12:16:41.972[app:dbg]vapi: Conn 7 - caller id Set param
12:16:41.972[app:dbg]vapi: chan '7' set param Caller ID
12:16:41.972[app:dbg]vapi_cb_req: 7 0 result 0x00000000 requid 0x0000000c
12:16:41.982[app:dbg]vapi_proc_event: VAPI_CB
12:16:41.982[app:dbg]vapi_cb_chan: chan 7 reqest_id 0x0000000c result 0x00000000
12:16:41.982[app:dbg]vapi: Conn 7 - enable ind ptime and pt
12:16:41.982[app:dbg]vapi_cb_req: 7 0 result 0x00000000 requid 0x0000004a
12:16:41.992[app:dbg]vapi_proc_event: VAPI_CB
12:16:41.992[app:dbg]vapi_cb_chan: chan 7 reqest_id 0x0000004a result 0x00000000
12:16:41.992[app:dbg]Chan 7: CREATING -> CREATED
12:16:41.992[app:dbg]Port 7: check vapi queue ('busy''create') at vapi_next_ops:2532
12:16:41.992[app:dbg]Port 7 get cmd 'create' from queue at (vapi_next_ops:2551)
12:16:41.992[app:dbg]VQ Conn 7 + 03  :    'start_tone'  + <-get_ptr
12:16:41.992[app:dbg]Port 7: check vapi queue ('free') at vapi_create_chan:694
12:16:41.992[app:dbg]Chan 7: current state is CREATED
12:16:41.992[app:dbg]chan 7: no need to create - already exists
12:16:41.992[app:dbg]Port 7: check vapi queue ('free') at vapi_next_ops:2694
12:16:41.992[app:dbg]Port 7: check vapi queue ('free') at vapi_next_ops:2532
12:16:41.992[app:dbg]Port 7 get cmd 'start_tone' from queue at (vapi_next_ops:2551)
12:16:41.992[app:dbg]Port 7: check vapi queue ('free') at vapi_start_tone_chan:1384
12:16:41.992[app:dbg]Chan 7: current state is CREATED
12:16:41.992[app:dbg]Port 7: set vapi queue MSP to 'busy' with 'start_tone' at vapi_start_tone_chan:1421
12:16:41.992[app:dbg]VQ Conn 7 = MSP :    'start_tone' =
12:16:41.992[app:dbg]chan 7 start tone, id=21, direction=TDM
12:16:41.992[app:dbg]vapi_cb_req: 7 0 result 0x00000000 requid 0x00000922
12:16:42.002[app:dbg]vapi_proc_event: VAPI_CB
12:16:42.002[app:dbg]vapi_cb_chan: chan 7 reqest_id 0x00000922 result 0x00000000
12:16:42.002[app:dbg]Conn 7: Start tone - Successfull
12:16:42.002[app:dbg]Port 7: check vapi queue ('busy''start_tone') at vapi_next_ops:2532
12:16:42.162[sip]recv 269 bytes from udp/[81.88.86.11]:5060 at 00:03:08.960000:
12:16:42.162[sip]   ------------------------------------------------------------------------
12:16:42.162[sip]   OPTIONS sip:*.*.*.*:5077 SIP/2.0
12:16:42.162[sip]   Via: SIP/2.0/UDP 81.88.86.11:5060;branch=z9hG4bK8791763
12:16:42.162[sip]   From: sip:nat_pinger@mangosip.ru;tag=e14906c3
12:16:42.162[sip]   To: sip:*.*.*.*:5077
12:16:42.162[sip]   Call-ID: 5cbefec2-cdda0e76-ba37@81.88.86.11
12:16:42.162[sip]   CSeq: 1 OPTIONS
12:16:42.162[sip]   Max-Forwards: 70
12:16:42.162[sip]   Content-Length: 0
12:16:42.162[sip]
12:16:42.162[sip]   ------------------------------------------------------------------------
12:16:42.162[app:dbg]got nua_i_options : 100(Trying)
12:16:42.172[app:dbg]NO CALL IN nua_i_options == 100 : Trying
12:16:42.172[app:dbg]sdp_codecs_init() init call sdp (offer)
12:16:42.172[app:dbg]sdp_codecs_dump() ssup present on, ecan absent on, rfc present 101, nse absent 0, ptime present 20
12:16:42.172[app:dbg]sdp_codecs_dump() G723: none
12:16:42.172[app:dbg]sdp_codecs_dump() G711A:
12:16:42.172[app:dbg]sdp_codecs_dump() PT 8, vbd absent off
12:16:42.172[app:dbg]sdp_codecs_dump() G711U:
12:16:42.172[app:dbg]sdp_codecs_dump() PT 0, vbd absent off
12:16:42.172[app:dbg]sdp_codecs_g711a_add_to_media_attrs() g711a: have one at last
12:16:42.172[app:dbg]sdp_codecs_g711u_add_to_media_attrs() g711u: have one at last
12:16:42.172[app:dbg]sdp_codecs_rfc2833_add_to_media_attrs() present, pt 101
12:16:42.172[app:dbg]sdp_codecs_nse_add_to_media_attrs() absent, pt 0
12:16:42.172[app:dbg]sdp_codecs_ptime_add_to_attrs() ptime present 20
12:16:42.172[app:dbg]sdp_codecs_ecan_add_to_attrs() ecan absent on
12:16:42.172[app:dbg]sdp_codecs_ssup_add_to_attrs() ssup present on
12:16:42.172[app:dbg]sdp_tail:  8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=silenceSupp:on - - - -
12:16:42.172[app:dbg]make_sdp: SDP: s=Session SDP
m=audio 0 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=silenceSupp:on - - - -
12:16:42.172[sip]send 826 bytes to udp/[81.88.86.11]:5060 at 00:03:08.970000:
12:16:42.172[sip]   ------------------------------------------------------------------------
12:16:42.172[sip]   SIP/2.0 200 OK
12:16:42.172[sip]   Via: SIP/2.0/UDP 81.88.86.11:5060;branch=z9hG4bK8791763
12:16:42.172[sip]   From: sip:nat_pinger@mangosip.ru;tag=e14906c3
12:16:42.172[sip]   To: <sip:*.*.*.*:5077>;tag=848Za849B7KyS
12:16:42.172[sip]   Call-ID: 5cbefec2-cdda0e76-ba37@81.88.86.11
12:16:42.172[sip]   CSeq: 1 OPTIONS
12:16:42.172[sip]   Contact: <sip:user2@10.30.0.200:5077>
12:16:42.172[sip]   User-Agent: TAU-8.IP/2.0.0 SN/VI33001750 sofia-sip/1.12.10
12:16:42.172[sip]   Accept: application/sdp
12:16:42.172[sip]   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, INFO
12:16:42.172[sip]   Supported: timer, 100rel, replaces
12:16:42.172[sip]   Content-Type: application/sdp
12:16:42.172[sip]   Content-Length: 286
12:16:42.172[sip]
12:16:42.172[sip]   v=0
12:16:42.172[sip]   o=- 2666397015357999886 1787629409887564453 IN IP4 10.30.0.200
12:16:42.172[sip]   s=Session SDP
12:16:42.172[sip]   c=IN IP4 10.30.0.200
12:16:42.172[sip]   t=0 0
12:16:42.172[sip]   m=audio 0 RTP/AVP 8 0 101
12:16:42.172[sip]   a=rtpmap:8 PCMA/8000
12:16:42.182[app:dbg]== current tester cb ==self_i_outbound=============================
12:16:42.172[sip]   a=rtpmap:0 PCMU/8000
12:16:42.182[sip]   a=rtpmap:101 telephone-event/8000
12:16:42.182[sip]   a=fmtp:101 0-16
12:16:42.182[sip]   a=inactive
12:16:42.182[sip]   a=ptime:20
12:16:42.182[sip]   a=silenceSupp:on - - - -
12:16:42.182[sip]   ------------------------------------------------------------------------
12:16:43.122[sip]recv 269 bytes from udp/[81.88.86.11]:5060 at 00:03:09.920000:
12:16:43.122[sip]   ------------------------------------------------------------------------
12:16:43.122[sip]   OPTIONS sip:*.*.*.*:5077 SIP/2.0
12:16:43.122[sip]   Via: SIP/2.0/UDP 81.88.86.11:5060;branch=z9hG4bK4670673
12:16:43.122[sip]   From: sip:nat_pinger@mangosip.ru;tag=44c016c3
12:16:43.122[sip]   To: sip:*.*.*.*:5077
12:16:43.122[sip]   Call-ID: 5cbefec2-20621e76-ca37@81.88.86.11
12:16:43.122[sip]   CSeq: 1 OPTIONS
12:16:43.122[sip]   Max-Forwards: 70
12:16:43.122[sip]   Content-Length: 0
12:16:43.122[sip]
12:16:43.122[sip]   ------------------------------------------------------------------------
12:16:43.122[app:dbg]got nua_i_options : 100(Trying)
12:16:43.122[app:dbg]NO CALL IN nua_i_options == 100 : Trying
12:16:43.122[app:dbg]sdp_codecs_init() init call sdp (offer)
12:16:43.122[app:dbg]sdp_codecs_dump() ssup present on, ecan absent on, rfc present 101, nse absent 0, ptime present 20
12:16:43.122[app:dbg]sdp_codecs_dump() G723: none
12:16:43.122[app:dbg]sdp_codecs_dump() G711A:
12:16:43.122[app:dbg]sdp_codecs_dump() PT 8, vbd absent off
12:16:43.122[app:dbg]sdp_codecs_dump() G711U:
12:16:43.122[app:dbg]sdp_codecs_dump() PT 0, vbd absent off
12:16:43.122[app:dbg]sdp_codecs_g711a_add_to_media_attrs() g711a: have one at last
12:16:43.122[app:dbg]sdp_codecs_g711u_add_to_media_attrs() g711u: have one at last
12:16:43.122[app:dbg]sdp_codecs_rfc2833_add_to_media_attrs() present, pt 101
12:16:43.122[app:dbg]sdp_codecs_nse_add_to_media_attrs() absent, pt 0
12:16:43.122[app:dbg]sdp_codecs_ptime_add_to_attrs() ptime present 20
12:16:43.122[app:dbg]sdp_codecs_ecan_add_to_attrs() ecan absent on
12:16:43.122[app:dbg]sdp_codecs_ssup_add_to_attrs() ssup present on
12:16:43.122[app:dbg]sdp_tail:  8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=silenceSupp:on - - - -
12:16:43.122[app:dbg]make_sdp: SDP: s=Session SDP
m=audio 0 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=silenceSupp:on - - - -
12:16:43.122[app:dbg]== current tester cb ==self_i_outbound=============================
12:16:43.122[sip]send 826 bytes to udp/[81.88.86.11]:5060 at 00:03:09.920000:
12:16:43.122[sip]   ------------------------------------------------------------------------
12:16:43.122[sip]   SIP/2.0 200 OK
12:16:43.132[sip]   Via: SIP/2.0/UDP 81.88.86.11:5060;branch=z9hG4bK4670673
12:16:43.132[sip]   From: sip:nat_pinger@mangosip.ru;tag=44c016c3
12:16:43.132[sip]   To: <sip:*.*.*.*:5077>;tag=9D2rc3ND9FaHN
12:16:43.132[sip]   Call-ID: 5cbefec2-20621e76-ca37@81.88.86.11
12:16:43.132[sip]   CSeq: 1 OPTIONS
12:16:43.132[sip]   Contact: <sip:user2@10.30.0.200:5077>
12:16:43.132[sip]   User-Agent: TAU-8.IP/2.0.0 SN/VI33001750 sofia-sip/1.12.10
12:16:43.132[sip]   Accept: application/sdp
12:16:43.132[sip]   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, INFO
12:16:43.132[sip]   Supported: timer, 100rel, replaces
12:16:43.132[sip]   Content-Type: application/sdp
12:16:43.132[sip]   Content-Length: 286
12:16:43.132[sip]
12:16:43.132[sip]   v=0
12:16:43.132[sip]   o=- 3387204167348236626 6831868266035900535 IN IP4 10.30.0.200
12:16:43.132[sip]   s=Session SDP
12:16:43.132[sip]   c=IN IP4 10.30.0.200
12:16:43.132[sip]   t=0 0
12:16:43.132[sip]   m=audio 0 RTP/AVP 8 0 101
12:16:43.132[sip]   a=rtpmap:8 PCMA/8000
12:16:43.132[sip]   a=rtpmap:0 PCMU/8000
12:16:43.132[sip]   a=rtpmap:101 telephone-event/8000
12:16:43.132[sip]   a=fmtp:101 0-16
12:16:43.132[sip]   a=inactive
12:16:43.132[sip]   a=ptime:20
12:16:43.132[sip]   a=silenceSupp:on - - - -
12:16:43.132[sip]   ------------------------------------------------------------------------
12:16:43.142[sip]recv 269 bytes from udp/[81.88.86.11]:5060 at 00:03:09.940000:
12:16:43.142[sip]   ------------------------------------------------------------------------
12:16:43.142[sip]   OPTIONS sip:*.*.*.*:5077 SIP/2.0
12:16:43.142[sip]   Via: SIP/2.0/UDP 81.88.86.11:5060;branch=z9hG4bK8443510
12:16:43.142[sip]   From: sip:nat_pinger@mangosip.ru;tag=6dd026c3
12:16:43.142[sip]   To: sip:*.*.*.*:5077
12:16:43.142[sip]   Call-ID: 5cbefec2-49722e76-ca37@81.88.86.11
12:16:43.142[sip]   CSeq: 1 OPTIONS
12:16:43.142[sip]   Max-Forwards: 70
12:16:43.142[sip]   Content-Length: 0
12:16:43.142[sip]
12:16:43.142[sip]   ------------------------------------------------------------------------
12:16:43.142[app:dbg]got nua_i_options : 100(Trying)
12:16:43.142[app:dbg]NO CALL IN nua_i_options == 100 : Trying
12:16:43.142[app:dbg]sdp_codecs_init() init call sdp (offer)
12:16:43.142[app:dbg]sdp_codecs_dump() ssup present on, ecan absent on, rfc present 101, nse absent 0, ptime present 20
12:16:43.142[app:dbg]sdp_codecs_dump() G723: none
12:16:43.142[app:dbg]sdp_codecs_dump() G711A:
12:16:43.142[app:dbg]sdp_codecs_dump() PT 8, vbd absent off
12:16:43.142[app:dbg]sdp_codecs_dump() G711U:
12:16:43.142[app:dbg]sdp_codecs_dump() PT 0, vbd absent off
12:16:43.142[app:dbg]sdp_codecs_g711a_add_to_media_attrs() g711a: have one at last
12:16:43.142[app:dbg]sdp_codecs_g711u_add_to_media_attrs() g711u: have one at last
12:16:43.142[app:dbg]sdp_codecs_rfc2833_add_to_media_attrs() present, pt 101
12:16:43.142[app:dbg]sdp_codecs_nse_add_to_media_attrs() absent, pt 0
12:16:43.142[app:dbg]sdp_codecs_ptime_add_to_attrs() ptime present 20
12:16:43.142[app:dbg]sdp_codecs_ecan_add_to_attrs() ecan absent on
12:16:43.142[app:dbg]sdp_codecs_ssup_add_to_attrs() ssup present on
12:16:43.142[app:dbg]sdp_tail:  8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=silenceSupp:on - - - -
12:16:43.152[app:dbg]make_sdp: SDP: s=Session SDP
m=audio 0 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=silenceSupp:on - - - -
12:16:43.152[sip]send 825 bytes to udp/[81.88.86.11]:5060 at 00:03:09.950000:
12:16:43.152[sip]   ------------------------------------------------------------------------
12:16:43.152[sip]   SIP/2.0 200 OK
12:16:43.152[sip]   Via: SIP/2.0/UDP 81.88.86.11:5060;branch=z9hG4bK8443510
12:16:43.152[sip]   From: sip:nat_pinger@mangosip.ru;tag=6dd026c3
12:16:43.152[sip]   To: <sip:*.*.*.*:5077>;tag=aQUHey6g6r03g
12:16:43.152[sip]   Call-ID: 5cbefec2-49722e76-ca37@81.88.86.11
12:16:43.152[sip]   CSeq: 1 OPTIONS
12:16:43.152[sip]   Contact: <sip:user2@10.30.0.200:5077>
12:16:43.152[sip]   User-Agent: TAU-8.IP/2.0.0 SN/VI33001750 sofia-sip/1.12.10
12:16:43.152[sip]   Accept: application/sdp
12:16:43.152[sip]   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, INFO
12:16:43.152[sip]   Supported: timer, 100rel, replaces
12:16:43.152[sip]   Content-Type: application/sdp
12:16:43.152[sip]   Content-Length: 285
12:16:43.162[sip]
12:16:43.162[sip]   v=0
12:16:43.162[sip]   o=- 7462252220015956767 139212025073461277 IN IP4 10.30.0.200
12:16:43.162[sip]   s=Session SDP
12:16:43.162[sip]   c=IN IP4 10.30.0.200
12:16:43.162[sip]   t=0 0
12:16:43.162[sip]   m=audio 0 RTP/AVP 8 0 101
12:16:43.162[sip]   a=rtpmap:8 PCMA/8000
12:16:43.162[sip]   a=rtpmap:0 PCMU/8000
12:16:43.162[sip]   a=rtpmap:101 telephone-event/8000
12:16:43.162[sip]   a=fmtp:101 0-16
12:16:43.162[sip]   a=inactive
12:16:43.162[sip]   a=ptime:20
12:16:43.162[sip]   a=silenceSupp:on - - - -
12:16:43.162[sip]   ------------------------------------------------------------------------
12:16:43.172[app:dbg]== current tester cb ==self_i_outbound=============================
12:16:44.642[app:dbg]slic7. Event 8.
12:16:44.642[app:dbg]slic 7. Pre-On-hook event
12:16:44.642[app:dbg]HIO: preonhook TDM port '7', port enabled 1
12:16:44.642[app:dbg]CMD_STOP_TONE: port = 7
12:16:44.642[app:dbg]Port 7: check vapi queue ('free') at vapi_stop_tone_chan:1474
12:16:44.642[app:dbg]Chan 7: current state is CREATED
12:16:44.642[app:dbg]Port 7: set vapi queue MSP to 'busy' with 'stop_tone' at vapi_stop_tone_chan:1520
12:16:44.642[app:dbg]VQ Conn 7 = MSP :     'stop_tone' =
12:16:44.642[app:dbg]chan 7 stop tone
12:16:44.642[app:dbg]vapi_cb_req: 7 0 result 0x00000000 requid 0x00000923
12:16:44.652[app:dbg]vapi_proc_event: VAPI_CB
12:16:44.652[app:dbg]vapi_cb_chan: chan 7 reqest_id 0x00000923 result 0x00000000
12:16:44.652[app:dbg]Conn 7: Stop tone - Successfull
12:16:44.652[app:dbg]Port 7: check vapi queue ('busy''stop_tone') at vapi_next_ops:2532
12:16:44.662[app:dbg]vapi: generic event, code 2 <Tone Generation completed>, conn 7
12:16:44.902[app:dbg]slic7. Event 4.
12:16:44.902[app:dbg]hio: port 7: digit 1 (code 0x1), pulse
12:16:44.902[app:dbg]CMD_STOP_TONE: port = 7
12:16:44.902[app:dbg]Port 7: check vapi queue ('free') at vapi_stop_tone_chan:1474
12:16:44.902[app:dbg]Chan 7: current state is CREATED
12:16:44.902[app:dbg]vapi_chan.c:1510: conn 7 peek cmd 'no event' from queue
12:16:44.902[app:dbg]Port 7: check vapi queue ('free') at __cmd_engine:320
12:16:44.902[app:dbg]Port 7: check vapi queue ('free') at vapi_next_ops:2532
12:16:44.902[app:dbg]Port 7: user port 1, old state dial, new state
12:16:44.902[app:dbg]Set port 7 led to state 'LED_ON'
12:16:44.902[app:dbg]pbx -[msg_fxs_state]-> group
12:16:44.902[app:dbg]ITC: [msg_fxs_state] -> group
12:16:44.902[app:dbg]-----[GM] self_fxs_state()
12:16:44.902[app:dbg]Port 7: new state is dial
12:16:44.922[app:dbg]first !* and !# - can`t be dvo
12:16:44.922[app:dbg]check item 0: 0x0FFF/080000FF,0 : <1>
12:16:44.922[app:dbg]regex_match_item: check route 0x31bc00 repeat on rf 0, rt 255(inf), crt 0, digit '1' mask 0xFFF
12:16:44.922[app:dbg]<cur match>: dial <1>r 1, dt 0, sub 0 r{0,255(inf)}
12:16:44.922[app:dbg]match ok: rf 0, crt 1, rt 255
12:16:44.922[app:dbg]end of items - test dial ended
12:16:44.922[app:dbg]check 'cant dial more' out of the cycle: item 0, crt 1, r{0,255(inf)}
12:16:44.922[app:dbg]MATCH: fulldialed 1, can`t dial more 0, dialtone 0 fullmatch 1
12:16:44.922[app:dbg]07: [0,]
12:16:44.922[app:dbg]port_process_digit() regex route 0x31bc00, final 1, dt 0
12:16:44.922[app:dbg]port 7: process final route
12:16:45.022[app:dbg]port 7: regex per sec timeout
12:16:45.552[app:dbg]slic7. Event 8.
12:16:45.552[app:dbg]slic 7. Pre-On-hook event
12:16:45.552[app:dbg]HIO: preonhook TDM port '7', port enabled 1
12:16:46.012[app:dbg]port 7: regex per sec timeout
12:16:46.152[sip]recv 269 bytes from udp/[81.88.86.11]:5060 at 00:03:12.950000:
12:16:46.162[sip]   ------------------------------------------------------------------------
12:16:46.162[sip]   OPTIONS sip:*.*.*.*:5077 SIP/2.0
12:16:46.162[sip]   Via: SIP/2.0/UDP 81.88.86.11:5060;branch=z9hG4bK1376759
12:16:46.162[sip]   From: sip:nat_pinger@mangosip.ru;tag=0b1816c3
12:16:46.162[sip]   To: sip:*.*.*.*:5077
12:16:46.162[sip]   Call-ID: 5cbefec2-e6b91e76-fa37@81.88.86.11
12:16:46.162[sip]   CSeq: 1 OPTIONS
12:16:46.162[sip]   Max-Forwards: 70
12:16:46.162[sip]   Content-Length: 0
12:16:46.162[sip]
12:16:46.162[sip]   ------------------------------------------------------------------------
12:16:46.162[app:dbg]got nua_i_options : 100(Trying)
12:16:46.162[app:dbg]NO CALL IN nua_i_options == 100 : Trying
12:16:46.162[app:dbg]sdp_codecs_init() init call sdp (offer)
12:16:46.162[app:dbg]sdp_codecs_dump() ssup present on, ecan absent on, rfc present 101, nse absent 0, ptime present 20
12:16:46.162[app:dbg]sdp_codecs_dump() G723: none
12:16:46.162[app:dbg]sdp_codecs_dump() G711A:
12:16:46.162[app:dbg]sdp_codecs_dump() PT 8, vbd absent off
12:16:46.162[app:dbg]sdp_codecs_dump() G711U:
12:16:46.162[app:dbg]sdp_codecs_dump() PT 0, vbd absent off
12:16:46.162[app:dbg]sdp_codecs_g711a_add_to_media_attrs() g711a: have one at last
12:16:46.162[app:dbg]sdp_codecs_g711u_add_to_media_attrs() g711u: have one at last
12:16:46.162[app:dbg]sdp_codecs_rfc2833_add_to_media_attrs() present, pt 101
12:16:46.162[app:dbg]sdp_codecs_nse_add_to_media_attrs() absent, pt 0
12:16:46.162[app:dbg]sdp_codecs_ptime_add_to_attrs() ptime present 20
12:16:46.162[app:dbg]sdp_codecs_ecan_add_to_attrs() ecan absent on
12:16:46.162[app:dbg]sdp_codecs_ssup_add_to_attrs() ssup present on
12:16:46.162[app:dbg]sdp_tail:  8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=silenceSupp:on - - - -
12:16:46.162[app:dbg]make_sdp: SDP: s=Session SDP
m=audio 0 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=silenceSupp:on - - - -
12:16:46.162[app:dbg]== current tester cb ==self_i_outbound=============================
12:16:46.162[sip]send 826 bytes to udp/[81.88.86.11]:5060 at 00:03:12.960000:
12:16:46.162[sip]   ------------------------------------------------------------------------
12:16:46.162[sip]   SIP/2.0 200 OK
12:16:46.162[sip]   Via: SIP/2.0/UDP 81.88.86.11:5060;branch=z9hG4bK1376759
12:16:46.162[sip]   From: sip:nat_pinger@mangosip.ru;tag=0b1816c3
12:16:46.162[sip]   To: <sip:*.*.*.*:5077>;tag=B0magSQm31ppc
12:16:46.172[sip]   Call-ID: 5cbefec2-e6b91e76-fa37@81.88.86.11
12:16:46.172[sip]   CSeq: 1 OPTIONS
12:16:46.172[sip]   Contact: <sip:user2@10.30.0.200:5077>
12:16:46.172[sip]   User-Agent: TAU-8.IP/2.0.0 SN/VI33001750 sofia-sip/1.12.10
12:16:46.172[sip]   Accept: application/sdp
12:16:46.172[sip]   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, INFO
12:16:46.172[sip]   Supported: timer, 100rel, replaces
12:16:46.172[sip]   Content-Type: application/sdp
12:16:46.172[sip]   Content-Length: 286
12:16:46.172[sip]
12:16:46.172[sip]   v=0
12:16:46.172[sip]   o=- 8016939106233783400 7638601906568674206 IN IP4 10.30.0.200
12:16:46.172[sip]   s=Session SDP
12:16:46.172[sip]   c=IN IP4 10.30.0.200
12:16:46.172[sip]   t=0 0
12:16:46.172[sip]   m=audio 0 RTP/AVP 8 0 101
12:16:46.172[sip]   a=rtpmap:8 PCMA/8000
12:16:46.172[sip]   a=rtpmap:0 PCMU/8000
12:16:46.172[sip]   a=rtpmap:101 telephone-event/8000
12:16:46.172[sip]   a=fmtp:101 0-16
12:16:46.172[sip]   a=inactive
12:16:46.172[sip]   a=ptime:20
12:16:46.172[sip]   a=silenceSupp:on - - - -
12:16:46.172[sip]   ------------------------------------------------------------------------
12:16:46.692[app:dbg]slic7. Event 4.
12:16:46.692[app:dbg]hio: port 7: digit 0 (code 0xA), pulse
12:16:46.692[app:dbg]check item 0: 0x0FFF/080000FF,0 : <1>
12:16:46.692[app:dbg]regex_match_item: check route 0x31bc00 repeat on rf 0, rt 255(inf), crt 0, digit '1' mask 0xFFF
12:16:46.692[app:dbg]<cur match>: dial <1>r 1, dt 0, sub 0 r{0,255(inf)}
12:16:46.692[app:dbg]match ok: rf 0, crt 1, rt 255
12:16:46.692[app:dbg]check item 0: 0x0FFF/080000FF,1 : <0>
12:16:46.692[app:dbg]regex_match_item: check route 0x31bc00 repeat on rf 0, rt 255(inf), crt 1, digit '0' mask 0xFFF
12:16:46.692[app:dbg]<cur match>: dial <0>r 2, dt 0, sub 0 r{0,255(inf)}
12:16:46.692[app:dbg]match ok: rf 0, crt 2, rt 255
12:16:46.692[app:dbg]end of items - test dial ended
12:16:46.692[app:dbg]check 'cant dial more' out of the cycle: item 0, crt 2, r{0,255(inf)}
12:16:46.692[app:dbg]MATCH: fulldialed 1, can`t dial more 0, dialtone 0 fullmatch 1
12:16:46.692[app:dbg]07: [0,]
12:16:46.692[app:dbg]port_process_digit() regex route 0x31bc00, final 1, dt 0
12:16:46.692[app:dbg]port 7: process final route
12:16:47.032[app:dbg]port 7: regex per sec timeout
12:16:47.292[app:dbg]slic7. Event 8.
12:16:47.292[app:dbg]slic 7. Pre-On-hook event
12:16:47.292[app:dbg]HIO: preonhook TDM port '7', port enabled 1
12:16:47.802[app:dbg]slic7. Event 1.
12:16:47.802[app:dbg]slic 7. On-hook event
12:16:47.802[app:dbg]Set port 7 led to state 'LED_OFF'
12:16:47.802[app:dbg]HIO: onhook TDM port '7', port enabled 1
12:16:47.802[app:dbg]SLIC 7 (user2): onhook state: dial
12:16:47.802[app:dbg]regex ID 7: dial reset
12:16:47.812[app:dbg]CMD_STOP_TONE: port = 7
12:16:47.812[app:dbg]Port 7: check vapi queue ('free') at vapi_stop_tone_chan:1474
12:16:47.822[app:dbg]Chan 7: current state is CREATED
12:16:47.822[app:dbg]vapi_chan.c:1510: conn 7 peek cmd 'no event' from queue
12:16:47.822[app:dbg]Port 7: check vapi queue ('free') at __cmd_engine:320
12:16:47.822[app:dbg]Port 7: check vapi queue ('free') at vapi_next_ops:2532
12:16:47.822[app:dbg]SLIC 7: reset
12:16:47.822[app:dbg]dump_port_calls() SLIC 7:
12:16:47.822[app:dbg]Q:NONE
12:16:47.822[app:dbg]H:((nil),0x00000000,(nil),0) W:((nil),0x00000000,(nil)) N:((nil),0x00000000,(nil)) H2:((nil),0x00000000,(nil))
12:16:47.822[app:dbg]Delete all RX-TX medias from SLIC 7
12:16:47.822[app:dbg]free_final_mx: final_mx was NULL for SLIC 7
12:16:47.822[app:dbg]CMD_DESTROY_CONN: port = 7
12:16:47.822[app:dbg]Port 7: check vapi queue ('free') at vapi_destroy_chan:890
12:16:47.822[app:dbg]Destroying connection 7...
12:16:47.822[app:dbg]Chan 7: current state is CREATED
12:16:47.822[app:dbg]Port 7: set vapi queue MSP to 'busy' with 'destroy' at vapi_destroy_chan:916
12:16:47.822[app:dbg]VQ Conn 7 = MSP :       'destroy' =
12:16:47.822[app:dbg]Chan 7: CREATED -> DESTROYING
12:16:47.822[app:dbg]vapi_cb_req: 7 0 result 0x00000000 requid 0x0000014b
12:16:47.822[app:dbg]CMD_DESTROY_IPONLY_CONN: port = 7
12:16:47.822[app:dbg]Port 7: check vapi queue ('busy''destroy') at vapi_destroy_chan:890
12:16:47.822[app:dbg]Clear vapi queue of Port 7/chan 15
12:16:47.822[app:dbg]Port 7 put cmd 'destroy',cur 'destroy' to queue at (vapi_destroy_chan:897)
12:16:47.822[app:dbg]VQ Conn 15 = MSP :       'destroy' =
12:16:47.822[app:dbg]VQ Conn 15 + 00  :       'destroy' (hold) + <-get_ptr
12:16:47.822[app:dbg]Port 7: user port 1, old state hangup, new state
12:16:47.822[app:dbg]Set port 7 led to state 'LED_OFF'
12:16:47.822[app:dbg]pbx -[msg_fxs_state]-> group
12:16:47.822[app:dbg]ITC: [msg_fxs_state] -> group
12:16:47.822[app:dbg]-----[GM] self_fxs_state()
12:16:47.822[app:dbg]Port 7: new state is hangup
12:16:47.832[app:dbg]Delete all RX-TX medias from SLIC 15
12:16:47.842[app:dbg]Delete all RX-TX medias from SLIC 7
12:16:47.842[app:dbg]dump_port_calls() SLIC 7:
12:16:47.842[app:dbg]Q:NONE
12:16:47.842[app:dbg]H:((nil),0x00000000,(nil),0) W:((nil),0x00000000,(nil)) N:((nil),0x00000000,(nil)) H2:((nil),0x00000000,(nil))
12:16:47.842[app:dbg]Set port 7 led to state 'LED_OFF'
12:16:47.852[app:dbg]vapi_proc_event: VAPI_CB
12:16:47.852[app:dbg]vapi_cb_chan: chan 7 reqest_id 0x0000014b result 0x00000000
12:16:47.852[app:dbg]vapi_cb_req: 7 0 result 0x00000000 requid 0x00000103
12:16:47.862[app:dbg]vapi_proc_event: VAPI_CB
12:16:47.862[app:dbg]vapi_cb_chan: chan 7 reqest_id 0x00000103 result 0x00000000
12:16:47.862[app:dbg]Conn 7 destroyed
12:16:47.862[app:dbg]Chan 7: DESTROYING -> INITIAL
12:16:47.862[app:dbg]Port 7: check vapi queue ('busy''destroy') at vapi_next_ops:2532
12:16:47.862[app:dbg]Port 7 get cmd 'destroy' from queue at (vapi_next_ops:2551)
12:16:47.862[app:dbg]Port 7: check vapi queue ('free') at vapi_destroy_chan:890
12:16:47.862[app:dbg]Destroying connection 15...
12:16:47.862[app:dbg]Chan 15: current state is INITIAL
12:16:47.862[app:dbg]Port 7: check vapi queue ('free') at vapi_next_ops:2694
12:16:47.862[app:dbg]Port 7: check vapi queue ('free') at vapi_next_ops:2532
12:16:48.442[sip]recv 269 bytes from udp/[81.88.86.11]:5060 at 00:03:15.240000:
12:16:48.442[sip]   ------------------------------------------------------------------------
12:16:48.442[sip]   OPTIONS sip:*.*.*.*:5077 SIP/2.0
12:16:48.442[sip]   Via: SIP/2.0/UDP 81.88.86.11:5060;branch=z9hG4bK1230368
12:16:48.442[sip]   From: sip:nat_pinger@mangosip.ru;tag=cec116c3
12:16:48.442[sip]   To: sip:*.*.*.*:5077
12:16:48.442[sip]   Call-ID: 5cbefec2-aa631e76-1b37@81.88.86.11
12:16:48.442[sip]   CSeq: 1 OPTIONS
12:16:48.442[sip]   Max-Forwards: 70
12:16:48.442[sip]   Content-Length: 0
12:16:48.442[sip]
12:16:48.442[sip]   ------------------------------------------------------------------------
12:16:48.442[app:dbg]got nua_i_options : 100(Trying)
12:16:48.442[app:dbg]NO CALL IN nua_i_options == 100 : Trying
12:16:48.442[app:dbg]sdp_codecs_init() init call sdp (offer)
12:16:48.442[app:dbg]sdp_codecs_dump() ssup present on, ecan absent on, rfc present 101, nse absent 0, ptime present 20
12:16:48.442[app:dbg]sdp_codecs_dump() G723: none
12:16:48.442[app:dbg]sdp_codecs_dump() G711A:
12:16:48.442[app:dbg]sdp_codecs_dump() PT 8, vbd absent off
12:16:48.442[app:dbg]sdp_codecs_dump() G711U:
12:16:48.442[app:dbg]sdp_codecs_dump() PT 0, vbd absent off
12:16:48.442[app:dbg]sdp_codecs_g711a_add_to_media_attrs() g711a: have one at last
12:16:48.442[app:dbg]sdp_codecs_g711u_add_to_media_attrs() g711u: have one at last
12:16:48.452[app:dbg]sdp_codecs_rfc2833_add_to_media_attrs() present, pt 101
12:16:48.452[app:dbg]sdp_codecs_nse_add_to_media_attrs() absent, pt 0
12:16:48.452[app:dbg]sdp_codecs_ptime_add_to_attrs() ptime present 20
12:16:48.452[app:dbg]sdp_codecs_ecan_add_to_attrs() ecan absent on
12:16:48.452[app:dbg]sdp_codecs_ssup_add_to_attrs() ssup present on
12:16:48.452[app:dbg]sdp_tail:  8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=silenceSupp:on - - - -
12:16:48.452[app:dbg]make_sdp: SDP: s=Session SDP
m=audio 0 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=silenceSupp:on - - - -
12:16:48.452[sip]send 826 bytes to udp/[81.88.86.11]:5060 at 00:03:15.250000:
12:16:48.452[sip]   ------------------------------------------------------------------------
12:16:48.452[sip]   SIP/2.0 200 OK
12:16:48.452[sip]   Via: SIP/2.0/UDP 81.88.86.11:5060;branch=z9hG4bK1230368
12:16:48.452[sip]   From: sip:nat_pinger@mangosip.ru;tag=cec116c3
12:16:48.452[sip]   To: <sip:*.*.*.*:5077>;tag=c9D3Hm8Q0aD9Q
12:16:48.452[sip]   Call-ID: 5cbefec2-aa631e76-1b37@81.88.86.11
12:16:48.452[sip]   CSeq: 1 OPTIONS
12:16:48.452[sip]   Contact: <sip:user2@10.30.0.200:5077>
12:16:48.452[sip]   User-Agent: TAU-8.IP/2.0.0 SN/VI33001750 sofia-sip/1.12.10
12:16:48.452[sip]   Accept: application/sdp
12:16:48.452[sip]   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, INFO
12:16:48.452[sip]   Supported: timer, 100rel, replaces
12:16:48.452[sip]   Content-Type: application/sdp
12:16:48.452[sip]   Content-Length: 286
12:16:48.452[sip]
12:16:48.452[sip]   v=0
12:16:48.452[sip]   o=- 7867394425838625331 4719905753172221698 IN IP4 10.30.0.200
12:16:48.452[sip]   s=Session SDP
12:16:48.452[sip]   c=IN IP4 10.30.0.200
12:16:48.452[sip]   t=0 0
12:16:48.452[sip]   m=audio 0 RTP/AVP 8 0 101
12:16:48.452[sip]   a=rtpmap:8 PCMA/8000
12:16:48.452[sip]   a=rtpmap:0 PCMU/8000
12:16:48.452[sip]   a=rtpmap:101 telephone-event/8000
12:16:48.452[sip]   a=fmtp:101 0-16
12:16:48.452[sip]   a=inactive
12:16:48.452[sip]   a=ptime:20
12:16:48.452[sip]   a=silenceSupp:on - - - -
12:16:48.462[app:dbg]== current tester cb ==self_i_outbound=============================
12:16:48.452[sip]   ------------------------------------------------------------------------
12:16:50.452[sip]recv 269 bytes from udp/[81.88.86.11]:5060 at 00:03:17.250000:
12:16:50.452[sip]   ------------------------------------------------------------------------
12:16:50.452[sip]   OPTIONS sip:*.*.*.*:5077 SIP/2.0
12:16:50.452[sip]   Via: SIP/2.0/UDP 81.88.86.11:5060;branch=z9hG4bK8728309
12:16:50.452[sip]   From: sip:nat_pinger@mangosip.ru;tag=b24b36c3
12:16:50.452[sip]   To: sip:*.*.*.*:5077
12:16:50.452[sip]   Call-ID: 5cbefec2-9edc3e76-3b37@81.88.86.11
12:16:50.452[sip]   CSeq: 1 OPTIONS
12:16:50.452[sip]   Max-Forwards: 70
12:16:50.452[sip]   Content-Length: 0
12:16:50.452[sip]
12:16:50.452[sip]   ------------------------------------------------------------------------
12:16:50.452[app:dbg]got nua_i_options : 100(Trying)
12:16:50.452[app:dbg]NO CALL IN nua_i_options == 100 : Trying
12:16:50.452[app:dbg]sdp_codecs_init() init call sdp (offer)
12:16:50.452[app:dbg]sdp_codecs_dump() ssup present on, ecan absent on, rfc present 101, nse absent 0, ptime present 20
12:16:50.452[app:dbg]sdp_codecs_dump() G723: none
12:16:50.452[app:dbg]sdp_codecs_dump() G711A:
12:16:50.452[app:dbg]sdp_codecs_dump() PT 8, vbd absent off
12:16:50.452[app:dbg]sdp_codecs_dump() G711U:
12:16:50.452[app:dbg]sdp_codecs_dump() PT 0, vbd absent off
12:16:50.452[app:dbg]sdp_codecs_g711a_add_to_media_attrs() g711a: have one at last
12:16:50.452[app:dbg]sdp_codecs_g711u_add_to_media_attrs() g711u: have one at last
12:16:50.452[app:dbg]sdp_codecs_rfc2833_add_to_media_attrs() present, pt 101
12:16:50.452[app:dbg]sdp_codecs_nse_add_to_media_attrs() absent, pt 0
12:16:50.452[app:dbg]sdp_codecs_ptime_add_to_attrs() ptime present 20
12:16:50.452[app:dbg]sdp_codecs_ecan_add_to_attrs() ecan absent on
12:16:50.452[app:dbg]sdp_codecs_ssup_add_to_attrs() ssup present on
12:16:50.452[app:dbg]sdp_tail:  8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=silenceSupp:on - - - -
12:16:50.452[app:dbg]make_sdp: SDP: s=Session SDP
m=audio 0 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=silenceSupp:on - - - -
12:16:50.452[app:dbg]== current tester cb ==self_i_outbound=============================
12:16:50.452[sip]send 826 bytes to udp/[81.88.86.11]:5060 at 00:03:17.250000:
12:16:50.452[sip]   ------------------------------------------------------------------------
12:16:50.452[sip]   SIP/2.0 200 OK
12:16:50.452[sip]   Via: SIP/2.0/UDP 81.88.86.11:5060;branch=z9hG4bK8728309
12:16:50.462[sip]   From: sip:nat_pinger@mangosip.ru;tag=b24b36c3
12:16:50.462[sip]   To: <sip:*.*.*.*:5077>;tag=Dj7UKFSUXK3UK
12:16:50.462[sip]   Call-ID: 5cbefec2-9edc3e76-3b37@81.88.86.11
12:16:50.462[sip]   CSeq: 1 OPTIONS
12:16:50.462[sip]   Contact: <sip:user2@10.30.0.200:5077>
12:16:50.462[sip]   User-Agent: TAU-8.IP/2.0.0 SN/VI33001750 sofia-sip/1.12.10
12:16:50.462[sip]   Accept: application/sdp
12:16:50.462[sip]   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, INFO
12:16:50.462[sip]   Supported: timer, 100rel, replaces
12:16:50.462[sip]   Content-Type: application/sdp
12:16:50.462[sip]   Content-Length: 286
12:16:50.462[sip]
12:16:50.462[sip]   v=0
12:16:50.462[sip]   o=- 7998805510838753481 7521849072479662708 IN IP4 10.30.0.200
12:16:50.462[sip]   s=Session SDP
12:16:50.462[sip]   c=IN IP4 10.30.0.200
12:16:50.462[sip]   t=0 0
12:16:50.462[sip]   m=audio 0 RTP/AVP 8 0 101
12:16:50.462[sip]   a=rtpmap:8 PCMA/8000
12:16:50.462[sip]   a=rtpmap:0 PCMU/8000
12:16:50.462[sip]   a=rtpmap:101 telephone-event/8000
12:16:50.462[sip]   a=fmtp:101 0-16
12:16:50.462[sip]   a=inactive
12:16:50.462[sip]   a=ptime:20
12:16:50.462[sip]   a=silenceSupp:on - - - -
12:16:50.462[sip]   ------------------------------------------------------------------------
12:16:51.452[sip]recv 269 bytes from udp/[81.88.86.11]:5060 at 00:03:18.250000:
12:16:51.452[sip]   ------------------------------------------------------------------------
12:16:51.452[sip]   OPTIONS sip:*.*.*.*:5077 SIP/2.0
12:16:51.452[sip]   Via: SIP/2.0/UDP 81.88.86.11:5060;branch=z9hG4bK3468114
12:16:51.452[sip]   From: sip:nat_pinger@mangosip.ru;tag=313916c3
12:16:51.452[sip]   To: sip:*.*.*.*:5077
12:16:51.452[sip]   Call-ID: 5cbefec2-1dca1e76-4b37@81.88.86.11
12:16:51.452[sip]   CSeq: 1 OPTIONS
12:16:51.452[sip]   Max-Forwards: 70
12:16:51.452[sip]   Content-Length: 0
12:16:51.452[sip]
12:16:51.452[sip]   ------------------------------------------------------------------------
12:16:51.452[app:dbg]got nua_i_options : 100(Trying)
12:16:51.452[app:dbg]NO CALL IN nua_i_options == 100 : Trying
12:16:51.452[app:dbg]sdp_codecs_init() init call sdp (offer)
12:16:51.452[app:dbg]sdp_codecs_dump() ssup present on, ecan absent on, rfc present 101, nse absent 0, ptime present 20
12:16:51.452[app:dbg]sdp_codecs_dump() G723: none
12:16:51.452[app:dbg]sdp_codecs_dump() G711A:
12:16:51.452[app:dbg]sdp_codecs_dump() PT 8, vbd absent off
12:16:51.452[app:dbg]sdp_codecs_dump() G711U:
12:16:51.452[app:dbg]sdp_codecs_dump() PT 0, vbd absent off
12:16:51.452[app:dbg]sdp_codecs_g711a_add_to_media_attrs() g711a: have one at last
12:16:51.452[app:dbg]sdp_codecs_g711u_add_to_media_attrs() g711u: have one at last
12:16:51.452[app:dbg]sdp_codecs_rfc2833_add_to_media_attrs() present, pt 101
12:16:51.452[app:dbg]sdp_codecs_nse_add_to_media_attrs() absent, pt 0
12:16:51.452[app:dbg]sdp_codecs_ptime_add_to_attrs() ptime present 20
12:16:51.452[app:dbg]sdp_codecs_ecan_add_to_attrs() ecan absent on
12:16:51.452[app:dbg]sdp_codecs_ssup_add_to_attrs() ssup present on
12:16:51.452[app:dbg]sdp_tail:  8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=silenceSupp:on - - - -
12:16:51.462[app:dbg]make_sdp: SDP: s=Session SDP
m=audio 0 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=silenceSupp:on - - - -
12:16:51.462[app:dbg]== current tester cb ==self_i_outbound=============================
12:16:51.472[sip]recv 269 bytes from udp/[81.88.86.11]:5060 at 00:03:18.260000:
12:16:51.472[sip]   ------------------------------------------------------------------------
12:16:51.472[sip]   OPTIONS sip:*.*.*.*:5077 SIP/2.0
12:16:51.472[sip]   Via: SIP/2.0/UDP 81.88.86.11:5060;branch=z9hG4bK4355086
12:16:51.472[sip]   From: sip:nat_pinger@mangosip.ru;tag=e23916c3
12:16:51.472[sip]   To: sip:*.*.*.*:5077
12:16:51.472[sip]   Call-ID: 5cbefec2-ceca1e76-4b37@81.88.86.11
12:16:51.472[sip]   CSeq: 1 OPTIONS
12:16:51.472[sip]   Max-Forwards: 70
12:16:51.472[sip]   Content-Length: 0
12:16:51.472[sip]
12:16:51.472[sip]   ------------------------------------------------------------------------
12:16:51.472[sip]send 826 bytes to udp/[81.88.86.11]:5060 at 00:03:18.270000:
12:16:51.472[sip]   ------------------------------------------------------------------------
12:16:51.472[sip]   SIP/2.0 200 OK
12:16:51.472[sip]   Via: SIP/2.0/UDP 81.88.86.11:5060;branch=z9hG4bK3468114
12:16:51.472[sip]   From: sip:nat_pinger@mangosip.ru;tag=313916c3
12:16:51.472[sip]   To: <sip:*.*.*.*:5077>;tag=eU0mNaaZtvSeF
12:16:51.472[sip]   Call-ID: 5cbefec2-1dca1e76-4b37@81.88.86.11
12:16:51.472[sip]   CSeq: 1 OPTIONS
12:16:51.472[sip]   Contact: <sip:user2@10.30.0.200:5077>
12:16:51.472[sip]   User-Agent: TAU-8.IP/2.0.0 SN/VI33001750 sofia-sip/1.12.10
12:16:51.472[sip]   Accept: application/sdp
12:16:51.472[sip]   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, INFO
12:16:51.472[sip]   Supported: timer, 100rel, replaces
12:16:51.472[sip]   Content-Type: application/sdp
12:16:51.472[sip]   Content-Length: 286
12:16:51.472[sip]
12:16:51.472[sip]   v=0
12:16:51.472[sip]   o=- 5303805482187915663 2630883210607567449 IN IP4 10.30.0.200
12:16:51.472[sip]   s=Session SDP
12:16:51.472[sip]   c=IN IP4 10.30.0.200
12:16:51.472[sip]   t=0 0
12:16:51.472[sip]   m=audio 0 RTP/AVP 8 0 101
12:16:51.472[sip]   a=rtpmap:8 PCMA/8000
12:16:51.472[sip]   a=rtpmap:0 PCMU/8000
12:16:51.472[sip]   a=rtpmap:101 telephone-event/8000
12:16:51.472[sip]   a=fmtp:101 0-16
12:16:51.472[sip]   a=inactive
12:16:51.472[sip]   a=ptime:20
12:16:51.472[sip]   a=silenceSupp:on - - - -
12:16:51.472[sip]   ------------------------------------------------------------------------
12:16:51.482[app:dbg]got nua_i_options : 100(Trying)
12:16:51.482[app:dbg]NO CALL IN nua_i_options == 100 : Trying
12:16:51.492[app:dbg]sdp_codecs_init() init call sdp (offer)
12:16:51.492[app:dbg]sdp_codecs_dump() ssup present on, ecan absent on, rfc present 101, nse absent 0, ptime present 20
12:16:51.492[app:dbg]sdp_codecs_dump() G723: none
12:16:51.492[app:dbg]sdp_codecs_dump() G711A:
12:16:51.492[app:dbg]sdp_codecs_dump() PT 8, vbd absent off
12:16:51.492[app:dbg]sdp_codecs_dump() G711U:
12:16:51.492[app:dbg]sdp_codecs_dump() PT 0, vbd absent off
12:16:51.492[app:dbg]sdp_codecs_g711a_add_to_media_attrs() g711a: have one at last
12:16:51.492[app:dbg]sdp_codecs_g711u_add_to_media_attrs() g711u: have one at last
12:16:51.492[app:dbg]sdp_codecs_rfc2833_add_to_media_attrs() present, pt 101
12:16:51.492[app:dbg]sdp_codecs_nse_add_to_media_attrs() absent, pt 0
12:16:51.492[app:dbg]sdp_codecs_ptime_add_to_attrs() ptime present 20
12:16:51.492[app:dbg]sdp_codecs_ecan_add_to_attrs() ecan absent on
12:16:51.492[app:dbg]sdp_codecs_ssup_add_to_attrs() ssup present on
12:16:51.492[app:dbg]sdp_tail:  8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=silenceSupp:on - - - -
12:16:51.492[app:dbg]make_sdp: SDP: s=Session SDP
m=audio 0 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=silenceSupp:on - - - -
12:16:51.492[app:dbg]== current tester cb ==self_i_outbound=============================
12:16:51.492[sip]send 826 bytes to udp/[81.88.86.11]:5060 at 00:03:18.290000:
12:16:51.492[sip]   ------------------------------------------------------------------------
12:16:51.492[sip]   SIP/2.0 200 OK
12:16:51.492[sip]   Via: SIP/2.0/UDP 81.88.86.11:5060;branch=z9hG4bK4355086
12:16:51.492[sip]   From: sip:nat_pinger@mangosip.ru;tag=e23916c3
12:16:51.492[sip]   To: <sip:*.*.*.*:5077>;tag=F4SDQ5t2Q5F1a
12:16:51.492[sip]   Call-ID: 5cbefec2-ceca1e76-4b37@81.88.86.11
12:16:51.492[sip]   CSeq: 1 OPTIONS
12:16:51.492[sip]   Contact: <sip:user2@10.30.0.200:5077>
12:16:51.492[sip]   User-Agent: TAU-8.IP/2.0.0 SN/VI33001750 sofia-sip/1.12.10
12:16:51.492[sip]   Accept: application/sdp
12:16:51.492[sip]   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, INFO
12:16:51.492[sip]   Supported: timer, 100rel, replaces
12:16:51.492[sip]   Content-Type: application/sdp
12:16:51.492[sip]   Content-Length: 286
12:16:51.492[sip]
12:16:51.492[sip]   v=0
12:16:51.492[sip]   o=- 4292107757789293298 2522152414924810544 IN IP4 10.30.0.200
12:16:51.492[sip]   s=Session SDP
12:16:51.492[sip]   c=IN IP4 10.30.0.200
12:16:51.502[sip]   t=0 0
12:16:51.502[sip]   m=audio 0 RTP/AVP 8 0 101
12:16:51.502[sip]   a=rtpmap:8 PCMA/8000
12:16:51.502[sip]   a=rtpmap:0 PCMU/8000
12:16:51.502[sip]   a=rtpmap:101 telephone-event/8000
12:16:51.502[sip]   a=fmtp:101 0-16
12:16:51.502[sip]   a=inactive
12:16:51.502[sip]   a=ptime:20
12:16:51.502[sip]   a=silenceSupp:on - - - -
12:16:51.502[sip]   ------------------------------------------------------------------------
12:16:52.442[sip]recv 269 bytes from udp/[81.88.86.11]:5060 at 00:03:19.240000:
12:16:52.442[sip]   ------------------------------------------------------------------------
12:16:52.442[sip]   OPTIONS sip:*.*.*.*:5077 SIP/2.0
12:16:52.442[sip]   Via: SIP/2.0/UDP 81.88.86.11:5060;branch=z9hG4bK4222954
12:16:52.442[sip]   From: sip:nat_pinger@mangosip.ru;tag=a24b06c3
12:16:52.442[sip]   To: sip:*.*.*.*:5077
12:16:52.442[sip]   Call-ID: 5cbefec2-8edc0e76-5b37@81.88.86.11
12:16:52.442[sip]   CSeq: 1 OPTIONS
12:16:52.442[sip]   Max-Forwards: 70
12:16:52.442[sip]   Content-Length: 0
12:16:52.442[sip]
12:16:52.442[sip]   ------------------------------------------------------------------------
12:16:52.442[app:dbg]got nua_i_options : 100(Trying)
12:16:52.442[app:dbg]NO CALL IN nua_i_options == 100 : Trying
12:16:52.442[app:dbg]sdp_codecs_init() init call sdp (offer)
12:16:52.442[app:dbg]sdp_codecs_dump() ssup present on, ecan absent on, rfc present 101, nse absent 0, ptime present 20
12:16:52.442[app:dbg]sdp_codecs_dump() G723: none
12:16:52.442[app:dbg]sdp_codecs_dump() G711A:
12:16:52.442[app:dbg]sdp_codecs_dump() PT 8, vbd absent off
12:16:52.442[app:dbg]sdp_codecs_dump() G711U:
12:16:52.442[app:dbg]sdp_codecs_dump() PT 0, vbd absent off
12:16:52.442[app:dbg]sdp_codecs_g711a_add_to_media_attrs() g711a: have one at last
12:16:52.442[app:dbg]sdp_codecs_g711u_add_to_media_attrs() g711u: have one at last
12:16:52.442[app:dbg]sdp_codecs_rfc2833_add_to_media_attrs() present, pt 101
12:16:52.442[app:dbg]sdp_codecs_nse_add_to_media_attrs() absent, pt 0
12:16:52.442[app:dbg]sdp_codecs_ptime_add_to_attrs() ptime present 20
12:16:52.442[app:dbg]sdp_codecs_ecan_add_to_attrs() ecan absent on
12:16:52.442[app:dbg]sdp_codecs_ssup_add_to_attrs() ssup present on
12:16:52.442[app:dbg]sdp_tail:  8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=silenceSupp:on - - - -
12:16:52.442[app:dbg]make_sdp: SDP: s=Session SDP
m=audio 0 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=silenceSupp:on - - - -
12:16:52.442[app:dbg]== current tester cb ==self_i_outbound=============================
12:16:52.452[sip]send 826 bytes to udp/[81.88.86.11]:5060 at 00:03:19.250000:
12:16:52.452[sip]   ------------------------------------------------------------------------
12:16:52.452[sip]   SIP/2.0 200 OK
12:16:52.452[sip]   Via: SIP/2.0/UDP 81.88.86.11:5060;branch=z9hG4bK4222954
12:16:52.452[sip]   From: sip:nat_pinger@mangosip.ru;tag=a24b06c3
12:16:52.452[sip]   To: <sip:*.*.*.*:5077>;tag=gDK6r0B6me6Kp
12:16:52.452[sip]   Call-ID: 5cbefec2-8edc0e76-5b37@81.88.86.11
12:16:52.452[sip]   CSeq: 1 OPTIONS
12:16:52.452[sip]   Contact: <sip:user2@10.30.0.200:5077>
12:16:52.452[sip]   User-Agent: TAU-8.IP/2.0.0 SN/VI33001750 sofia-sip/1.12.10
12:16:52.452[sip]   Accept: application/sdp
12:16:52.452[sip]   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, INFO
12:16:52.452[sip]   Supported: timer, 100rel, replaces
12:16:52.452[sip]   Content-Type: application/sdp
12:16:52.452[sip]   Content-Length: 286
12:16:52.452[sip]
12:16:52.452[sip]   v=0
12:16:52.452[sip]   o=- 6676294929797075679 2782066939675283735 IN IP4 10.30.0.200
12:16:52.452[sip]   s=Session SDP
12:16:52.452[sip]   c=IN IP4 10.30.0.200
12:16:52.452[sip]   t=0 0
12:16:52.452[sip]   m=audio 0 RTP/AVP 8 0 101
12:16:52.452[sip]   a=rtpmap:8 PCMA/8000
12:16:52.452[sip]   a=rtpmap:0 PCMU/8000
12:16:52.452[sip]   a=rtpmap:101 telephone-event/8000
12:16:52.452[sip]   a=fmtp:101 0-16
12:16:52.452[sip]   a=inactive
12:16:52.452[sip]   a=ptime:20
12:16:52.452[sip]   a=silenceSupp:on - - - -
12:16:52.452[sip]   ------------------------------------------------------------------------
12:16:53.442[sip]recv 269 bytes from udp/[81.88.86.11]:5060 at 00:03:20.240000:
12:16:53.442[sip]   ------------------------------------------------------------------------
12:16:53.442[sip]   OPTIONS sip:*.*.*.*:5077 SIP/2.0
12:16:53.442[sip]   Via: SIP/2.0/UDP 81.88.86.11:5060;branch=z9hG4bK6726081
12:16:53.442[sip]   From: sip:nat_pinger@mangosip.ru;tag=a4d216c3
12:16:53.442[sip]   To: sip:*.*.*.*:5077
12:16:53.442[sip]   Call-ID: 5cbefec2-80741e76-6b37@81.88.86.11
12:16:53.442[sip]   CSeq: 1 OPTIONS
12:16:53.442[sip]   Max-Forwards: 70
12:16:53.442[sip]   Content-Length: 0
12:16:53.452[sip]
12:16:53.452[sip]   ------------------------------------------------------------------------
12:16:53.452[app:dbg]got nua_i_options : 100(Trying)
12:16:53.452[app:dbg]NO CALL IN nua_i_options == 100 : Trying
12:16:53.452[app:dbg]sdp_codecs_init() init call sdp (offer)
12:16:53.452[app:dbg]sdp_codecs_dump() ssup present on, ecan absent on, rfc present 101, nse absent 0, ptime present 20
12:16:53.452[app:dbg]sdp_codecs_dump() G723: none
12:16:53.452[app:dbg]sdp_codecs_dump() G711A:
12:16:53.452[app:dbg]sdp_codecs_dump() PT 8, vbd absent off
12:16:53.452[app:dbg]sdp_codecs_dump() G711U:
12:16:53.452[app:dbg]sdp_codecs_dump() PT 0, vbd absent off
12:16:53.452[app:dbg]sdp_codecs_g711a_add_to_media_attrs() g711a: have one at last
12:16:53.452[app:dbg]sdp_codecs_g711u_add_to_media_attrs() g711u: have one at last
12:16:53.452[app:dbg]sdp_codecs_rfc2833_add_to_media_attrs() present, pt 101
12:16:53.452[app:dbg]sdp_codecs_nse_add_to_media_attrs() absent, pt 0
12:16:53.452[app:dbg]sdp_codecs_ptime_add_to_attrs() ptime present 20
12:16:53.452[app:dbg]sdp_codecs_ecan_add_to_attrs() ecan absent on
12:16:53.452[app:dbg]sdp_codecs_ssup_add_to_attrs() ssup present on
12:16:53.452[app:dbg]sdp_tail:  8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=silenceSupp:on - - - -
12:16:53.452[app:dbg]make_sdp: SDP: s=Session SDP
m=audio 0 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=silenceSupp:on - - - -
12:16:53.452[app:dbg]== current tester cb ==self_i_outbound=============================
12:16:53.462[sip]send 826 bytes to udp/[81.88.86.11]:5060 at 00:03:20.260000:
12:16:53.462[sip]   ------------------------------------------------------------------------
12:16:53.462[sip]   SIP/2.0 200 OK
12:16:53.462[sip]   Via: SIP/2.0/UDP 81.88.86.11:5060;branch=z9hG4bK6726081
12:16:53.462[sip]   From: sip:nat_pinger@mangosip.ru;tag=a4d216c3
12:16:53.462[sip]   To: <sip:*.*.*.*:5077>;tag=HpcZtUv9HQv6H
12:16:53.462[sip]   Call-ID: 5cbefec2-80741e76-6b37@81.88.86.11
12:16:53.462[sip]   CSeq: 1 OPTIONS
12:16:53.462[sip]   Contact: <sip:user2@10.30.0.200:5077>
12:16:53.462[sip]   User-Agent: TAU-8.IP/2.0.0 SN/VI33001750 sofia-sip/1.12.10
12:16:53.462[sip]   Accept: application/sdp
12:16:53.462[sip]   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, INFO
12:16:53.462[sip]   Supported: timer, 100rel, replaces
12:16:53.462[sip]   Content-Type: application/sdp
12:16:53.462[sip]   Content-Length: 286
12:16:53.462[sip]
12:16:53.462[sip]   v=0
12:16:53.462[sip]   o=- 5497691458935283793 5621502767524372886 IN IP4 10.30.0.200
12:16:53.462[sip]   s=Session SDP
12:16:53.462[sip]   c=IN IP4 10.30.0.200
12:16:53.462[sip]   t=0 0
12:16:53.462[sip]   m=audio 0 RTP/AVP 8 0 101
12:16:53.462[sip]   a=rtpmap:8 PCMA/8000
12:16:53.462[sip]   a=rtpmap:0 PCMU/8000
12:16:53.462[sip]   a=rtpmap:101 telephone-event/8000
12:16:53.462[sip]   a=fmtp:101 0-16
12:16:53.462[sip]   a=inactive
12:16:53.462[sip]   a=ptime:20
12:16:53.462[sip]   a=silenceSupp:on - - - -
12:16:53.462[sip]   ------------------------------------------------------------------------
12:16:53.462[sip]recv 269 bytes from udp/[81.88.86.11]:5060 at 00:03:20.260000:
12:16:53.462[sip]   ------------------------------------------------------------------------
12:16:53.462[sip]   OPTIONS sip:*.*.*.*:5077 SIP/2.0
12:16:53.462[sip]   Via: SIP/2.0/UDP 81.88.86.11:5060;branch=z9hG4bK9460302
12:16:53.462[sip]   From: sip:nat_pinger@mangosip.ru;tag=bde226c3
12:16:53.462[sip]   To: sip:*.*.*.*:5077
12:16:53.462[sip]   Call-ID: 5cbefec2-99842e76-6b37@81.88.86.11
12:16:53.462[sip]   CSeq: 1 OPTIONS
12:16:53.462[sip]   Max-Forwards: 70
12:16:53.462[sip]   Content-Length: 0
12:16:53.462[sip]
12:16:53.462[sip]   ------------------------------------------------------------------------
12:16:53.472[app:dbg]got nua_i_options : 100(Trying)
12:16:53.472[app:dbg]NO CALL IN nua_i_options == 100 : Trying
12:16:53.472[app:dbg]sdp_codecs_init() init call sdp (offer)
12:16:53.472[app:dbg]sdp_codecs_dump() ssup present on, ecan absent on, rfc present 101, nse absent 0, ptime present 20
12:16:53.472[app:dbg]sdp_codecs_dump() G723: none
12:16:53.472[app:dbg]sdp_codecs_dump() G711A:
12:16:53.472[app:dbg]sdp_codecs_dump() PT 8, vbd absent off
12:16:53.472[app:dbg]sdp_codecs_dump() G711U:
12:16:53.472[app:dbg]sdp_codecs_dump() PT 0, vbd absent off
12:16:53.472[app:dbg]sdp_codecs_g711a_add_to_media_attrs() g711a: have one at last
12:16:53.472[app:dbg]sdp_codecs_g711u_add_to_media_attrs() g711u: have one at last
12:16:53.472[app:dbg]sdp_codecs_rfc2833_add_to_media_attrs() present, pt 101
12:16:53.472[app:dbg]sdp_codecs_nse_add_to_media_attrs() absent, pt 0
12:16:53.472[app:dbg]sdp_codecs_ptime_add_to_attrs() ptime present 20
12:16:53.472[app:dbg]sdp_codecs_ecan_add_to_attrs() ecan absent on
12:16:53.472[app:dbg]sdp_codecs_ssup_add_to_attrs() ssup present on
12:16:53.472[app:dbg]sdp_tail:  8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=silenceSupp:on - - - -
12:16:53.472[app:dbg]make_sdp: SDP: s=Session SDP
m=audio 0 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=silenceSupp:on - - - -
12:16:53.472[app:dbg]== current tester cb ==self_i_outbound=============================
12:16:53.472[sip]send 825 bytes to udp/[81.88.86.11]:5060 at 00:03:20.270000:
12:16:53.472[sip]   ------------------------------------------------------------------------
12:16:53.472[sip]   SIP/2.0 200 OK
12:16:53.472[sip]   Via: SIP/2.0/UDP 81.88.86.11:5060;branch=z9hG4bK9460302
12:16:53.472[sip]   From: sip:nat_pinger@mangosip.ru;tag=bde226c3
12:16:53.472[sip]   To: <sip:*.*.*.*:5077>;tag=jZ5QvpDDF0jSD
12:16:53.472[sip]   Call-ID: 5cbefec2-99842e76-6b37@81.88.86.11
12:16:53.472[sip]   CSeq: 1 OPTIONS
12:16:53.482[sip]   Contact: <sip:user2@10.30.0.200:5077>
12:16:53.482[sip]   User-Agent: TAU-8.IP/2.0.0 SN/VI33001750 sofia-sip/1.12.10
12:16:53.482[sip]   Accept: application/sdp
12:16:53.482[sip]   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, INFO
12:16:53.482[sip]   Supported: timer, 100rel, replaces
12:16:53.482[sip]   Content-Type: application/sdp
12:16:53.482[sip]   Content-Length: 285
12:16:53.482[sip]
12:16:53.482[sip]   v=0
12:16:53.482[sip]   o=- 376985650347636009 1695268644832446781 IN IP4 10.30.0.200
12:16:53.482[sip]   s=Session SDP
12:16:53.482[sip]   c=IN IP4 10.30.0.200
12:16:53.482[sip]   t=0 0
12:16:53.482[sip]   m=audio 0 RTP/AVP 8 0 101
12:16:53.482[sip]   a=rtpmap:8 PCMA/8000
12:16:53.482[sip]   a=rtpmap:0 PCMU/8000
12:16:53.482[sip]   a=rtpmap:101 telephone-event/8000
12:16:53.482[sip]   a=fmtp:101 0-16
12:16:53.482[sip]   a=inactive
12:16:53.482[sip]   a=ptime:20
12:16:53.482[sip]   a=silenceSupp:on - - - -
12:16:53.482[sip]   ------------------------------------------------------------------------
12:16:56.452[sip]recv 269 bytes from udp/[81.88.86.11]:5060 at 00:03:23.250000:
12:16:56.452[sip]   ------------------------------------------------------------------------
12:16:56.452[sip]   OPTIONS sip:*.*.*.*:5077 SIP/2.0
12:16:56.452[sip]   Via: SIP/2.0/UDP 81.88.86.11:5060;branch=z9hG4bK9321678
12:16:56.452[sip]   From: sip:nat_pinger@mangosip.ru;tag=2c3a16c3
12:16:56.452[sip]   To: sip:*.*.*.*:5077
12:16:56.452[sip]   Call-ID: 5cbefec2-08db1e76-9b37@81.88.86.11
12:16:56.452[sip]   CSeq: 1 OPTIONS
12:16:56.452[sip]   Max-Forwards: 70
12:16:56.452[sip]   Content-Length: 0
12:16:56.452[sip]
12:16:56.462[sip]   ------------------------------------------------------------------------
12:16:56.462[app:dbg]got nua_i_options : 100(Trying)
12:16:56.462[app:dbg]NO CALL IN nua_i_options == 100 : Trying
12:16:56.462[app:dbg]sdp_codecs_init() init call sdp (offer)
12:16:56.462[app:dbg]sdp_codecs_dump() ssup present on, ecan absent on, rfc present 101, nse absent 0, ptime present 20
12:16:56.462[app:dbg]sdp_codecs_dump() G723: none
12:16:56.462[app:dbg]sdp_codecs_dump() G711A:
12:16:56.462[app:dbg]sdp_codecs_dump() PT 8, vbd absent off
12:16:56.462[app:dbg]sdp_codecs_dump() G711U:
12:16:56.462[app:dbg]sdp_codecs_dump() PT 0, vbd absent off
12:16:56.462[app:dbg]sdp_codecs_g711a_add_to_media_attrs() g711a: have one at last
12:16:56.462[app:dbg]sdp_codecs_g711u_add_to_media_attrs() g711u: have one at last
12:16:56.462[app:dbg]sdp_codecs_rfc2833_add_to_media_attrs() present, pt 101
12:16:56.462[app:dbg]sdp_codecs_nse_add_to_media_attrs() absent, pt 0
12:16:56.462[app:dbg]sdp_codecs_ptime_add_to_attrs() ptime present 20
12:16:56.462[app:dbg]sdp_codecs_ecan_add_to_attrs() ecan absent on
12:16:56.462[app:dbg]sdp_codecs_ssup_add_to_attrs() ssup present on
12:16:56.462[app:dbg]sdp_tail:  8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=silenceSupp:on - - - -
12:16:56.462[app:dbg]make_sdp: SDP: s=Session SDP
m=audio 0 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=silenceSupp:on - - - -
12:16:56.462[app:dbg]== current tester cb ==self_i_outbound=============================
12:16:56.462[sip]send 826 bytes to udp/[81.88.86.11]:5060 at 00:03:23.260000:
12:16:56.462[sip]   ------------------------------------------------------------------------
12:16:56.462[sip]   SIP/2.0 200 OK
12:16:56.462[sip]   Via: SIP/2.0/UDP 81.88.86.11:5060;branch=z9hG4bK9321678
12:16:56.462[sip]   From: sip:nat_pinger@mangosip.ru;tag=2c3a16c3
12:16:56.462[sip]   To: <sip:*.*.*.*:5077>;tag=K8ygyHygc98BS
12:16:56.462[sip]   Call-ID: 5cbefec2-08db1e76-9b37@81.88.86.11
12:16:56.462[sip]   CSeq: 1 OPTIONS
12:16:56.462[sip]   Contact: <sip:user2@10.30.0.200:5077>
12:16:56.462[sip]   User-Agent: TAU-8.IP/2.0.0 SN/VI33001750 sofia-sip/1.12.10
12:16:56.462[sip]   Accept: application/sdp
12:16:56.462[sip]   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, INFO
12:16:56.472[sip]   Supported: timer, 100rel, replaces
12:16:56.472[sip]   Content-Type: application/sdp
12:16:56.472[sip]   Content-Length: 286
12:16:56.472[sip]
12:16:56.472[sip]   v=0
12:16:56.472[sip]   o=- 3009978081366863697 4248877039842125327 IN IP4 10.30.0.200
12:16:56.472[sip]   s=Session SDP
12:16:56.472[sip]   c=IN IP4 10.30.0.200
12:16:56.472[sip]   t=0 0
12:16:56.472[sip]   m=audio 0 RTP/AVP 8 0 101
12:16:56.472[sip]   a=rtpmap:8 PCMA/8000
12:16:56.472[sip]   a=rtpmap:0 PCMU/8000
12:16:56.472[sip]   a=rtpmap:101 telephone-event/8000
12:16:56.472[sip]   a=fmtp:101 0-16
12:16:56.472[sip]   a=inactive
12:16:56.472[sip]   a=ptime:20
12:16:56.472[sip]   a=silenceSupp:on - - - -
12:16:56.472[sip]   ------------------------------------------------------------------------
12:16:58.472[sip]recv 269 bytes from udp/[81.88.86.11]:5060 at 00:03:25.270000:
12:16:58.472[sip]   ------------------------------------------------------------------------
12:16:58.472[sip]   OPTIONS sip:*.*.*.*:5077 SIP/2.0
12:16:58.472[sip]   Via: SIP/2.0/UDP 81.88.86.11:5060;branch=z9hG4bK3372421
12:16:58.472[sip]   From: sip:nat_pinger@mangosip.ru;tag=33e316c3
12:16:58.472[sip]   To: sip:*.*.*.*:5077
12:16:58.472[sip]   Call-ID: 5cbefec2-1f751e76-bb37@81.88.86.11
12:16:58.472[sip]   CSeq: 1 OPTIONS
12:16:58.472[sip]   Max-Forwards: 70
12:16:58.472[sip]   Content-Length: 0
12:16:58.472[sip]
12:16:58.472[sip]   ------------------------------------------------------------------------
12:16:58.472[app:dbg]got nua_i_options : 100(Trying)
12:16:58.472[app:dbg]NO CALL IN nua_i_options == 100 : Trying
12:16:58.472[app:dbg]sdp_codecs_init() init call sdp (offer)
12:16:58.472[app:dbg]sdp_codecs_dump() ssup present on, ecan absent on, rfc present 101, nse absent 0, ptime present 20
12:16:58.472[app:dbg]sdp_codecs_dump() G723: none
12:16:58.472[app:dbg]sdp_codecs_dump() G711A:
12:16:58.472[app:dbg]sdp_codecs_dump() PT 8, vbd absent off
12:16:58.472[app:dbg]sdp_codecs_dump() G711U:
12:16:58.472[app:dbg]sdp_codecs_dump() PT 0, vbd absent off
12:16:58.472[app:dbg]sdp_codecs_g711a_add_to_media_attrs() g711a: have one at last
12:16:58.472[app:dbg]sdp_codecs_g711u_add_to_media_attrs() g711u: have one at last
12:16:58.472[app:dbg]sdp_codecs_rfc2833_add_to_media_attrs() present, pt 101
12:16:58.472[app:dbg]sdp_codecs_nse_add_to_media_attrs() absent, pt 0
12:16:58.472[app:dbg]sdp_codecs_ptime_add_to_attrs() ptime present 20
12:16:58.472[app:dbg]sdp_codecs_ecan_add_to_attrs() ecan absent on
12:16:58.472[app:dbg]sdp_codecs_ssup_add_to_attrs() ssup present on
12:16:58.472[app:dbg]sdp_tail:  8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=silenceSupp:on - - - -
12:16:58.472[app:dbg]make_sdp: SDP: s=Session SDP
m=audio 0 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=silenceSupp:on - - - -
12:16:58.472[app:dbg]== current tester cb ==self_i_outbound=============================
12:16:58.482[sip]send 826 bytes to udp/[81.88.86.11]:5060 at 00:03:25.280000:
12:16:58.492[sip]   ------------------------------------------------------------------------
12:16:58.492[sip]   SIP/2.0 200 OK
12:16:58.492[sip]   Via: SIP/2.0/UDP 81.88.86.11:5060;branch=z9hG4bK3372421
12:16:58.492[sip]   From: sip:nat_pinger@mangosip.ru;tag=33e316c3
12:16:58.492[sip]   To: <sip:*.*.*.*:5077>;tag=mHr9ZcFm9HZym
12:16:58.492[sip]   Call-ID: 5cbefec2-1f751e76-bb37@81.88.86.11
12:16:58.492[sip]   CSeq: 1 OPTIONS
12:16:58.492[sip]   Contact: <sip:user2@10.30.0.200:5077>
12:16:58.492[sip]   User-Agent: TAU-8.IP/2.0.0 SN/VI33001750 sofia-sip/1.12.10
12:16:58.492[sip]   Accept: application/sdp
12:16:58.492[sip]   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, INFO
12:16:58.492[sip]   Supported: timer, 100rel, replaces
12:16:58.492[sip]   Content-Type: application/sdp
12:16:58.492[sip]   Content-Length: 286
12:16:58.492[sip]
12:16:58.492[sip]   v=0
12:16:58.492[sip]   o=- 8467328964831884927 1136579713287105405 IN IP4 10.30.0.200
12:16:58.492[sip]   s=Session SDP
12:16:58.492[sip]   c=IN IP4 10.30.0.200
12:16:58.492[sip]   t=0 0
12:16:58.492[sip]   m=audio 0 RTP/AVP 8 0 101
12:16:58.492[sip]   a=rtpmap:8 PCMA/8000
12:16:58.492[sip]   a=rtpmap:0 PCMU/8000
12:16:58.492[sip]   a=rtpmap:101 telephone-event/8000
12:16:58.492[sip]   a=fmtp:101 0-16
12:16:58.492[sip]   a=inactive
12:16:58.492[sip]   a=ptime:20
12:16:58.492[sip]   a=silenceSupp:on - - - -
12:16:58.492[sip]   ------------------------------------------------------------------------
