gistfile1.txt

Mar  9 16:44:22 alpha /usr/local/sbin/opensips[24044]: DBG:core:tcp_read_req: Using the global ( per process ) buff
Mar  9 16:44:22 alpha /usr/local/sbin/opensips[24044]: DBG:core:tcp_handle_req: content-length= 0
Mar  9 16:44:22 alpha /usr/local/sbin/opensips[24044]: DBG:core:async_tsend_stream: Async succesful write from first try on 0x7fb14df006c0
Mar  9 16:44:22 alpha /usr/local/sbin/opensips[24044]: DBG:core:tcp_read_req: tcp_read_req end
Mar  9 16:44:26 alpha /usr/local/sbin/opensips[24041]: DBG:core:parse_msg: SIP Request:
Mar  9 16:44:26 alpha /usr/local/sbin/opensips[24041]: DBG:core:parse_msg:  method:  <REGISTER>
Mar  9 16:44:26 alpha /usr/local/sbin/opensips[24041]: DBG:core:parse_msg:  uri:     <sip:104.236.248.128:5060>
Mar  9 16:44:26 alpha /usr/local/sbin/opensips[24041]: DBG:core:parse_msg:  version: <SIP/2.0>
Mar  9 16:44:26 alpha /usr/local/sbin/opensips[24041]: DBG:core:parse_headers: flags=2
Mar  9 16:44:26 alpha /usr/local/sbin/opensips[24041]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK4848713aa2967d1954fe061a>; state=6
Mar  9 16:44:26 alpha /usr/local/sbin/opensips[24041]: DBG:core:parse_via_param: found param type 235, <rport> = <n/a>; state=17
Mar  9 16:44:26 alpha /usr/local/sbin/opensips[24041]: DBG:core:parse_via: end of header reached, state=5
Mar  9 16:44:26 alpha /usr/local/sbin/opensips[24041]: DBG:core:parse_headers: via found, flags=2
Mar  9 16:44:26 alpha /usr/local/sbin/opensips[24041]: DBG:core:parse_headers: this is the first via
Mar  9 16:44:26 alpha /usr/local/sbin/opensips[24041]: DBG:core:receive_msg: After parse_msg...
Mar  9 16:44:26 alpha /usr/local/sbin/opensips[24041]: DBG:core:receive_msg: preparing to run routing scripts...
Mar  9 16:44:26 alpha /usr/local/sbin/opensips[24041]: DBG:pike:mark_node: search on branch 195 (top=0x7fb14def7228)
Mar  9 16:44:26 alpha /usr/local/sbin/opensips[24041]: DBG:pike:mark_node: only first 1 were matched!
Mar  9 16:44:26 alpha /usr/local/sbin/opensips[24041]: DBG:pike:pike_check_req: src IP [195.154.52.219],node=0x7fb14def7228; hits=[1,1],[0,0] node_flags=2 func_flags=8
Mar  9 16:44:26 alpha /usr/local/sbin/opensips[24041]: DBG:core:destroy_avp_list: destroying list (nil)
Mar  9 16:44:26 alpha /usr/local/sbin/opensips[24041]: DBG:core:receive_msg: cleaning up
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24041]: DBG:core:parse_msg: SIP Request:
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24041]: DBG:core:parse_msg:  method:  <REGISTER>
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24041]: DBG:core:parse_msg:  uri:     <sip:104.236.248.128:5060>
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24041]: DBG:core:parse_msg:  version: <SIP/2.0>
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24041]: DBG:core:parse_headers: flags=2
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24041]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK5134513aa36dfd2354fe061d>; state=6
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24041]: DBG:core:parse_via_param: found param type 235, <rport> = <n/a>; state=17
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24041]: DBG:core:parse_via: end of header reached, state=5
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24041]: DBG:core:parse_headers: via found, flags=2
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24041]: DBG:core:parse_headers: this is the first via
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24041]: DBG:core:receive_msg: After parse_msg...
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24041]: DBG:core:receive_msg: preparing to run routing scripts...
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24041]: DBG:pike:mark_node: search on branch 195 (top=0x7fb14def7228)
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24041]: DBG:pike:mark_node: only first 1 were matched!
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24041]: DBG:pike:pike_check_req: src IP [195.154.52.219],node=0x7fb14def7228; hits=[1,2],[0,0] node_flags=2 func_flags=8
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24041]: DBG:core:destroy_avp_list: destroying list (nil)
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24041]: DBG:core:receive_msg: cleaning up
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24042]: DBG:proto_ws:ws_process: Using the global ( per process ) buff
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24042]: DBG:proto_ws:ws_process: We're releasing the connection in state 0
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24042]: DBG:core:parse_msg: SIP Request:
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24042]: DBG:core:parse_msg:  method:  <INVITE>
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24042]: DBG:core:parse_msg:  uri:     <sip:test@alpha.uphreak.com>
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24042]: DBG:core:parse_msg:  version: <SIP/2.0>
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24042]: DBG:core:parse_headers: flags=2
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24042]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK1099966>; state=16
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24042]: DBG:core:parse_via: end of header reached, state=5
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24042]: DBG:core:parse_headers: via found, flags=2
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24042]: DBG:core:parse_headers: this is the first via
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24042]: DBG:core:receive_msg: After parse_msg...
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24042]: DBG:core:receive_msg: preparing to run routing scripts...
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24042]: DBG:pike:mark_node: search on branch 50 (top=0x7fb14def7178)
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24042]: DBG:pike:mark_node: only first 1 were matched!
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24042]: DBG:pike:pike_check_req: src IP [50.198.204.238],node=0x7fb14def7178; hits=[0,1],[0,0] node_flags=2 func_flags=8
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24042]: DBG:core:parse_headers: flags=100
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24042]: DBG:maxfwd:is_maxfwd_present: value = 70
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24042]: DBG:core:parse_headers: flags=ffffffffffffffff
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24042]: DBG:core:parse_to: end of header reached, state=10
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24042]: DBG:core:parse_to: display={}, ruri={sip:test@alpha.uphreak.com}
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24042]: DBG:core:get_hdr_field: <To> [30]; uri=[sip:test@alpha.uphreak.com]
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24042]: DBG:core:get_hdr_field: to body [<sip:test@alpha.uphreak.com>
]
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24042]: DBG:core:get_hdr_field: cseq <CSeq>: <4801> <INVITE>
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24042]: DBG:core:get_hdr_field: content_length=2267
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24042]: DBG:core:get_hdr_field: found end of header
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24042]: DBG:core:check_ip_address: params 50.198.204.238, da2pe5ujl2ik.invalid, 0
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24042]: route                     : 4801: INVITE: received request from uac behind nat
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24042]: DBG:core:parse_headers: flags=ffffffffffffffff
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24042]: DBG:core:parse_headers: flags=ffffffffffffffff
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24042]: DBG:core:decode_mime_type: Decoding MIME type for:[application/sdp]
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24042]: DBG:core:parse_headers: flags=40
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24042]: DBG:core:parse_to_param: tag=6dc84blqe4
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24042]: DBG:core:parse_to: end of header reached, state=29
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24042]: DBG:core:parse_to: display={"test2"}, ruri={sip:test2@alpha.uphreak.com}
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24042]: DBG:core:parse_headers: flags=ffffffffffffffff
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24042]: DBG:rtpengine:check_content_type: type <application/sdp> found valid
Mar  9 16:44:30 alpha /usr/local/sbin/opensips[24042]: DBG:rtpengine:rtpe_function_call: proxy reply: d3:sdp796:v=0
o=Mozilla-SIPUA-36.0 24884 0 IN IP4 104.236.248.128
s=SIP Call
t=0 0
m=audio 53130 RTP/AVP 109 9 0 8 101
c=IN IP4 104.236.248.128
a=rtpmap:109 opus/48000/2
a=ptime:20
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendrecv
a=rtcp:53131
a=rtcp-mux
m=video 53158 RTP/AVP 120 126 97
c=IN IP4 104.236.248.128
a=rtpmap:120 VP8/90000
a=rtpmap:126 H264/90000
a=fmtp:126 profile-level-id=42e01f;packetization-mode=1
a=rtpmap:97 H264/90000
a=fmtp:97 profile-level-id=42e01f
a=rtcp-fb:120 nack
a=rtcp-fb:120 nack pli
a=rtcp-fb:120 ccm fir
a=rtcp-fb:126 nack
a=rtcp-fb:126 nack pli
a=rtcp-fb:126 ccm fir
a=rtcp-fb:97 nack
a=rtcp-fb:97 nack pli
a=rtcp-fb:97 ccm fir
a=sendrecv
a=rtcp:53159
a=rtcp-mux
6:result2:oke
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: route                     : 4801: INVITE: rtpengine offer
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:uri:has_totag: no totag
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: route[initial_requests]   : 4801: INVITE: received initial request to sip:test@alpha.uphreak.com
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:core:parse_headers: flags=200
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:rr:find_first_route: No Route headers found
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:rr:loose_route: There is no Route HF
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:dialog:build_new_dlg: new dialog 0x7fb14defc550 (c=qbip3g2fv51iq6ckc0oi,f=sip:test2@alpha.uphreak.com,t=sip:test@alpha.uphreak.com,ft=6dc84blqe4) on hash 1478
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:core:parse_headers: flags=ffffffffffffffff
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:dialog:init_leg_info: route_set , contact sip:1nu1qtbf@50.198.204.238:33499;transport=ws;ob, cseq 4801 and bind_addr ws:104.236.248.128:8080
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:dialog:dlg_add_leg_info: set leg 0 for 0x7fb14defc550: tag=<6dc84blqe4> rcseq=<0>
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:dialog:link_dlg: ref dlg 0x7fb14defc550 with 3 -> 3 in h_entry 0x7fb14decbe88 - 1478
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:rr:add_rr_param: adding (;did=6c5.c08a8a21) 2
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: route[initial_requests]   : 4801: INVITE: fU=test2 fd=alpha.uphreak.com rU=test
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:db_mysql:mysql_raise_event: MySQL status has not changed: connected
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:core:db_new_result: allocate 48 bytes for result set at 0x7fb1560b0860
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:db_mysql:db_mysql_get_columns: 2 columns returned from the query
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:core:db_allocate_columns: allocate 56 bytes for result columns at 0x7fb1560ad740
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7fb1560ad750)[0]=[username]
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7fb1560ad760)[1]=[domain]
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:db_mysql:db_mysql_convert_rows: no rows returned from the query
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:alias_db:alias_db_query: no alias found for R-URI
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:core:db_free_columns: freeing result columns at 0x7fb1560ad740
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:core:db_free_rows: freeing 0 rows
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:core:db_free_result: freeing result set at 0x7fb1560b0860
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:core:comp_scriptvar: int 20 : 0 / 1
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:core:comp_scriptvar: int 20 : 0 / 0
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:avpops:ops_dbquery_avps: query [select tran_strip, tran_prefix, tran_user, tran_domain, tran_add_header from translations where (from_username='test2' or from_username IS NULL) and from_domain='alpha.uphreak.com' and ('test' regexp match_regex or match_regex IS NULL) order by tran_priority limit 1]
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:db_mysql:mysql_raise_event: MySQL status has not changed: connected
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:core:db_new_result: allocate 48 bytes for result set at 0x7fb1560b0860
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:db_mysql:db_mysql_get_columns: 5 columns returned from the query
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:core:db_allocate_columns: allocate 140 bytes for result columns at 0x7fb1560c1160
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7fb1560c1188)[0]=[tran_strip]
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:db_mysql:db_mysql_get_columns: use DB_INT result type
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7fb1560c1198)[1]=[tran_prefix]
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7fb1560c11a8)[2]=[tran_user]
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7fb1560c11b8)[3]=[tran_domain]
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7fb1560c11c8)[4]=[tran_add_header]
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:db_mysql:db_mysql_convert_rows: no rows returned from the query
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:avpops:db_query_avp: no result after query
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:avpops:db_close_query: close avp query
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:core:db_free_columns: freeing result columns at 0x7fb1560c1160
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:core:db_free_rows: freeing 0 rows
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:core:db_free_result: freeing result set at 0x7fb1560b0860
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:db_mysql:mysql_raise_event: MySQL status has not changed: connected
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:core:db_new_result: allocate 48 bytes for result set at 0x7fb1560b0860
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:db_mysql:db_mysql_get_columns: 2 columns returned from the query
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:core:db_allocate_columns: allocate 56 bytes for result columns at 0x7fb1560ad740
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7fb1560ad750)[0]=[domain]
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7fb1560ad760)[1]=[attrs]
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:core:db_allocate_rows: allocate 80 bytes for result rows and values at 0x7fb1560c0ee0
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:db_mysql:db_mysql_str2val: converting STRING [alpha.uphreak.com]
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:db_mysql:db_mysql_str2val: converting STRING [auth]
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:domain:is_domain_local_pvar: Realm 'alpha.uphreak.com' is local
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:core:db_free_columns: freeing result columns at 0x7fb1560ad740
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:core:db_free_rows: freeing 1 rows
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:core:db_free_row: freeing row values at 0x7fb1560c0ef0
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:core:db_free_rows: freeing rows at 0x7fb1560c0ee0
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:core:db_free_result: freeing result set at 0x7fb1560b0860
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:registrar:lookup: found a complete match
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:registrar:lookup: setting as ruri <sip:test@10.1.10.25:53060;transport=tcp;registering_acc=alpha_uphreak_com>
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:registrar:lookup: looking for branches
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: route[initial_requests]   : 4801: INVITE: found registration for sip:test@alpha.uphreak.com
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:tm:t_newtran: transaction on entrance=0xffffffffffffffff
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:core:parse_headers: flags=ffffffffffffffff
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:core:parse_headers: flags=78
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:tm:t_lookup_request: start searching: hash=6721, isACK=0
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:tm:matching_3261: RFC3261 transaction matching failed
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:tm:t_lookup_request: no transaction found
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:tm:run_reqin_callbacks: trans=0x7fb14def8170, callback type 1, id 0 entered
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:dialog:dlg_onreq: t hash_index = 6721, t label = 107269241
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:core:parse_headers: flags=ffffffffffffffff
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:core:_shm_resize: resize(0) called
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:core:tcp_conn_get: con found in state 0
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:core:tcp_conn_get: tcp connection found (0x7fb14def6ff8) already in this process ( 7 ) , fd = 25
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:proto_ws:proto_ws_send: sending via fd 25...
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:proto_ws:proto_ws_send: after write: c= 0x7fb14def6ff8 n=335 fd=25
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:proto_ws:proto_ws_send: buf=
SIP/2.0 100 Giving a try
Via: SIP/2.0/WS da2pe5ujl2ik.invalid;received=50.198.204.238;rport=33499;branch=z9hG4bK1099966
To: <sip:test@alpha.uphreak.com>
From: "test2" <sip:test2@alpha.uphreak.com>;tag=6dc84blqe4
Call-ID: qbip3g2fv51iq6ckc0oi
CSeq: 4801 INVITE
Server: OpenSIPS (2.1.1dev (x86_64/linux))
Content-Length: 0
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:tm:_reply_light: reply sent out. buf=0x7fb1560c12a0: SIP/2.0 1..., shmem=0x7fb14df00168: SIP/2.0 1
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:tm:_reply_light: finished
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:core:_shm_resize: resize(0) called
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:core:mk_proxy: doing DNS lookup...
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:core:parse_headers: flags=2000
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:core:parse_headers: flags=2000
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:core:parse_headers: flags=ffffffffffffffff
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:core:clen_builder: content-length: 796 (796)
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:core:build_req_buf_from_sip_req: id added: <;i=1>, rcv proto=5
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:core:tcp_conn_get: con found in state 0
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:core:tcp_conn_get: tcp connection found (0x7fb14defcda0), acquiring fd
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:core:tcp_conn_get: c= 0x7fb14defcda0, n=16, Usock=23
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24050]: DBG:core:handle_worker: read response= 7fb14defcda0, 1, fd -1 from 7 (24042)
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:core:tcp_conn_get: after receive_fd: c= 0x7fb14defcda0 n=8 fd=26
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:core:proto_tcp_send: sending via fd 26...
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:core:async_tsend_stream: Async succesful write from first try on 0x7fb14defcda0
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:core:proto_tcp_send: after write: c= 0x7fb14defcda0 n=1612 fd=26
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:tm:insert_timer_unsafe: [0]: 0x7fb14def83c0 (465)
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:tm:t_relay_to: new transaction fwd'ed
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:tm:t_unref: UNREF_UNSAFE: [0x7fb14def8170] after is 0
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:dialog:unref_dlg: unref dlg 0x7fb14defc550 with 1 -> 2 in entry 0x7fb14decbe88
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:core:destroy_avp_list: destroying list (nil)
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:core:receive_msg: cleaning up
Mar  9 16:44:31 alpha /usr/local/sbin/opensips[24042]: DBG:proto_ws:ws_process: ws_read end