[OpenSIPS-Users] topology_hiding Record-Route

Pavel Eremin pavel at eremina.net
Tue Aug 9 06:59:46 CEST 2011


Bogdan, here is debug 6 when i recieve 180 Message. 11.11.11.11 - A,  
22.22.22.22 - B (opensips with Topologu_hiding), 33.33.33.33 - C

Aug  8 09:42:36 opensips ./opensips[20030]: incoming reply
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:core:parse_msg: SIP Reply   
(status):
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:core:parse_msg:  version:  
<SIP/2.0>
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:core:parse_msg:  status:   
<180>
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:core:parse_msg:  reason:   
<Ringing>
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:core:parse_headers: flags=2
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:core:parse_via_param:  
found param type 232, <branch> = <z9hG4bK8d86.1649d5a2.0>; state=16
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:core:parse_via: end of  
header reached, state=5
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:core:parse_headers: via  
found, flags=2
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:core:parse_headers: this  
is the first via
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:core:receive_msg: After  
parse_msg...
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:core:forward_reply: found  
module tm, passing reply to it
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:tm:t_check:  
start=0xffffffffffffffff
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:core:parse_headers:  
flags=22
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:core:parse_to_param:  
tag=1c416124843
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:core:parse_to: end of  
header reached, state=29
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:core:parse_to: display={},  
ruri={sip:79128923945 at 22.22.22.22;user=phone}
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:core:get_hdr_field: <To>  
[58]; uri=[sip:79128923945 at 22.22.22.22;user=phone]
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:core:get_hdr_field: to  
body [<sip:79128923945 at 22.22.22.22;user=phone>]
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:core:get_hdr_field: cseq  
<CSeq>: <1> <INVITE>
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:core:parse_headers: flags=8
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:tm:t_reply_matching: hash  
26840 label 710775905 branch 0
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:tm:t_reply_matching:  
REF_UNSAFE:[0x7f4a74c66480] after is 1
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:tm:t_reply_matching: reply  
matched (T=0x7f4a74c66480)!
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:tm:run_trans_callbacks:  
trans=0x7f4a74c66480, callback type 2, id 5 entered
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:core:parse_headers:  
flags=2000
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:core:get_hdr_field:  
content_length=0
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:tm:run_trans_callbacks:  
trans=0x7f4a74c66480, callback type 2, id 3 entered
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:core:parse_to_param:  
tag=2925795659-3759225282-335606691-1600804190
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:core:parse_to: end of  
header reached, state=29
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:core:parse_to: display={},  
ruri={sip:73512453023 at 11.11.11.11}
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:core:parse_headers:  
flags=40
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:siptrace:trace_onreply_in:  
storing info 7...
Aug  9 09:42:36 opensips ./opensips[20031]:  
DBG:db_postgres:db_postgres_val2str: PQescapeStringConn: in: 44 chars,  
out: 44 chars
Aug  9 09:42:36 opensips ./opensips[20031]:  
DBG:db_postgres:db_postgres_val2str: PQescapeStringConn: in: 6 chars, out:  
6 chars
Aug  9 09:42:36 opensips ./opensips[20031]:  
DBG:db_postgres:db_postgres_val2str: PQescapeStringConn: in: 3 chars, out:  
3 chars
Aug  9 09:42:36 opensips ./opensips[20031]:  
DBG:db_postgres:db_postgres_val2str: PQescapeStringConn: in: 20 chars,  
out: 20 chars
Aug  9 09:42:36 opensips ./opensips[20031]:  
DBG:db_postgres:db_postgres_val2str: PQescapeStringConn: in: 20 chars,  
out: 20 chars
Aug  9 09:42:36 opensips ./opensips[20031]:  
DBG:db_postgres:db_postgres_val2str: PQescapeStringConn: in: 2 chars, out:  
2 chars
Aug  9 09:42:36 opensips ./opensips[20031]:  
DBG:db_postgres:db_postgres_val2str: PQescapeStringConn: in: 42 chars,  
out: 42 chars
Aug  9 09:42:36 opensips ./opensips[20031]:  
DBG:db_postgres:db_postgres_val2str: PQescapeStringConn: in: 0 chars, out:  
0 chars
Aug  9 09:42:36 opensips ./opensips[20031]:  
DBG:db_postgres:db_postgres_submit_query: 0x7dadc8 PQsendQuery
(insert into sip_trace  
(msg,callid,method,status,fromip,toip,time_stamp,direction,fromtag,traced_user  
)
values ('SIP/2.0 180 Ringing\\015\\012Via: SIP/2.0/UDP  
22.22.22.22;branch=z9hG4bK8d86.1649d5a2.0\\015\\012
From:  
<sip:73512453023 at 11.11.11.11>;tag=2925795659-3759225282-335606691-1600804190\\015\\012
To: <sip:79128923945 at 22.22.22.22;user=phone>;tag=1c416124843\\015\\012
Call-ID: 4b196530c23911e0a3f300145e556a5f at 11.11.11.11\\015\\012CSeq: 1  
INVITE\\015\\012
Contact: <sip:1037 at media.sipproxy.xz:5060;transport=udp>\\015\\012
Supported: em,timer,replaces,path,early-session,resource-priority\\015\\012
Allow:  
REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE\\015\\012
Server: Audiocodes-Sip-Gateway-/v.5.80A.039.005\\015\\012Content-Length:  
0\\015\\012
Record-Route:  
<sip:33.33.33.33;lr;ftag=2925795659-3759225282-335606691-1600804190;did=1a.9b364f41>
\\015\\012\\015\\012','4b196530c23911e0a3f300145e556a5f at 11.11.11.11','INVITE','180','udp:33.33.33.33:5060','udp:22.22.22.22:5060','2011-08-09  
09:42:36','in','2925795659-3759225282-335606691-1600804190',''))
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:core:db_new_result:  
allocate 48 bytes for result set at 0x7dc168
Aug  9 09:42:36 opensips ./opensips[20031]:  
DBG:db_postgres:db_postgres_store_result: 0x7dadc8  
PQresultStatus(PGRES_COMMAND_OK) PQgetResult(0x25b3bc0)
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:db_postgres:free_query:  
PQclear(0x25b3bc0) result set
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:core:db_free_rows: freeing  
0 rows
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:core:db_free_result:  
freeing result set at 0x7dc168
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:tm:run_trans_callbacks:  
trans=0x7f4a74c66480, callback type 2, id 1 entered
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:dialog:dlg_th_onreply:  
start
Aug  9 09:42:36 opensips ./opensips[20031]:  
DBG:dialog:dlg_replace_contact: Replaced contact with  
[<sip:22.22.22.22:5060;did=1a8.a01b9366>]
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:dialog:dlg_th_onreply:  
peer_leg = 0
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:dialog:dlg_th_onreply:  
Added Via headers [Via: SIP/2.0/UDP  
11.11.11.11:5061;rport;branch=z9hG4bK-2257328459-3759225282-335606691-1600804190#015#012]  
leg=0x7f4a74c65b08
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:tm:t_check:  
end=0x7f4a74c66480
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:tm:reply_received: org.  
status uas=100, uac[0]=100 local=0 is_invite=1)
Aug  9 09:42:36 opensips ./opensips[20031]: incoming reply
Aug  9 09:42:36 opensips ./opensips[20031]:  
DBG:tm:t_should_relay_response: T_code=100, new_code=180
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:tm:relay_reply: branch=0,  
save=0, relay=0
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:tm:run_trans_callbacks:  
trans=0x7f4a74c66480, callback type 8, id 0 entered
Aug  9 09:42:36 opensips ./opensips[20031]:  
DBG:dialog:push_reply_in_dialog: 0x7f4a74c60318 totag in rpl is  
<1c416124843> (11)
Aug  9 09:42:36 opensips ./opensips[20031]:  
DBG:dialog:push_reply_in_dialog: new branch with tag <1c416124843>
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:dialog:init_leg_info:  
route_set , contact , cseq 1 and bind_addr udp:22.22.22.22:5060
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:dialog:dlg_add_leg_info:  
set leg 1 for 0x7f4a74c60318: tag=<1c416124843> rcseq=<1>
Aug  9 09:42:36 opensips ./opensips[20031]:  
DBG:core:build_res_buf_from_sip_res:  old size: 677, new size: 712
Aug  9 09:42:36 opensips ./opensips[20031]:  
DBG:core:build_res_buf_from_sip_res: copied size: orig:350, new: 385,  
rest: 327 msg=#012SIP/2.0 180 Ringing#015#012Via: SIP/2.0/UDP  
11.11.11.11:5061;rport;branch=z9hG4bK-2257328459-3759225282-335606691-1600804190#015#012From:  
<sip:73512453023 at 11.11.11.11>;tag=2925795659-3759225282-335606691-1600804190#015#012To:  
<sip:79128923945 at 22.22.22.22;user=phone>;tag=1c416124843#015#012Call-ID:  
4b196530c23911e0a3f300145e556a5f at 11.11.11.11#015#012CSeq: 1  
INVITE#015#012Contact:  
<sip:22.22.22.22:5060;did=1a8.a01b9366>#015#012Supported:  
em,timer,replaces,path,early-session,resource-priority#015#012Allow:  
REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE#015#012Server:  
Audiocodes-Sip-Gateway-/v.5.80A.039.005#015#012Content-Length:  
0#015#012Record-Route:  
<sip:33.33.33.33;lr;ftag=2925795659-3759225282-335606691-1600804190;did=1a.9b364f41>#015#012#015#012
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:tm:run_trans_callbacks:  
trans=0x7f4a74c66480, callback type 64, id 0 entered
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:dialog:next_state_dlg:  
dialog 0x7f4a74c60318 changed from state 1 to state 2, due event 2
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:tm:relay_reply: sent  
buf=0x7de5f8: SIP/2.0 1..., shmem=0x7f4a74c736b0: SIP/2.0 1
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:tm:run_trans_callbacks:  
trans=0x7f4a74c66480, callback type 128, id 5 entered
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:core:parse_headers:  
flags=2000
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:tm:run_trans_callbacks:  
trans=0x7f4a74c66480, callback type 128, id 4 entered
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:core:parse_headers:  
flags=40
Aug  9 09:42:36 opensips ./opensips[20031]:  
DBG:siptrace:trace_onreply_out: dest [udp:11.11.11.11:5061]
Aug  9 09:42:36 opensips ./opensips[20031]:  
DBG:siptrace:trace_onreply_out: storing info 10...
Aug  9 09:42:36 opensips ./opensips[20031]:  
DBG:db_postgres:db_postgres_val2str: PQescapeStringConn: in: 44 chars,  
out: 44 chars
Aug  9 09:42:36 opensips ./opensips[20031]:  
DBG:db_postgres:db_postgres_val2str: PQescapeStringConn: in: 6 chars, out:  
6 chars
Aug  9 09:42:36 opensips ./opensips[20031]:  
DBG:db_postgres:db_postgres_val2str: PQescapeStringConn: in: 3 chars, out:  
3 chars
Aug  9 09:42:36 opensips ./opensips[20031]:  
DBG:db_postgres:db_postgres_val2str: PQescapeStringConn: in: 20 chars,  
out: 20 chars
Aug  9 09:42:36 opensips ./opensips[20031]:  
DBG:db_postgres:db_postgres_val2str: PQescapeStringConn: in: 20 chars,  
out: 20 chars
Aug  9 09:42:36 opensips ./opensips[20031]:  
DBG:db_postgres:db_postgres_val2str: PQescapeStringConn: in: 3 chars, out:  
3 chars
Aug  9 09:42:36 opensips ./opensips[20031]:  
DBG:db_postgres:db_postgres_val2str: PQescapeStringConn: in: 42 chars,  
out: 42 chars
Aug  9 09:42:36 opensips ./opensips[20031]:  
DBG:db_postgres:db_postgres_val2str: PQescapeStringConn: in: 0 chars, out:  
0 chars
Aug  9 09:42:36 opensips ./opensips[20031]:  
DBG:db_postgres:db_postgres_submit_query: 0x7dadc8 PQsendQuery(insert into
sip_trace  
(msg,callid,method,status,fromip,toip,time_stamp,direction,fromtag,traced_user  
) values
('SIP/2.0 180 Ringing\\015\\012Via: SIP/2.0/UDP 11.11.11.11:5061;rport;
branch=z9hG4bK-2257328459-3759225282-335606691-1600804190\\015\\012
From:  
<sip:73512453023 at 11.11.11.11>;tag=2925795659-3759225282-335606691-1600804190\\015\\012To:  
<sip:79128923945 at 22.22.22.22;us
er=phone>;tag=1c416124843\\015\\012Call-ID:  
4b196530c23911e0a3f300145e556a5f at 11.11.11.11\\015\\012CSeq: 1  
INVITE\\015\\012
Contact: <sip:22.22.22.22:5060;did=1a8.a01b9366>\\015\\012Supported:  
em,timer,replaces,path,early-session,resource-priority\\01
5\\012Allow:  
REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE\\015\\012
Server: Audiocodes-Sip-Gateway-/v.5.80A.039.005\\015\\012Content-Length:  
0\\015\\012
Record-Route:  
<sip:33.33.33.33;lr;ftag=2925795659-3759225282-335606691-1600804190;did=1a.9b364f41>\\015\\012\\015\\012',
'4b196530c23911e0a3f300145e556a5f at 11.11.11.11','INVITE','180','udp:22.22.22.22:5060','udp:11.11.11.11:5061',
'2011-08-09  
09:42:36','out','2925795659-3759225282-335606691-1600804190',''))
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:core:db_new_result:  
allocate 48 bytes for result set at 0x7dc168
Aug  9 09:42:36 opensips ./opensips[20031]:  
DBG:db_postgres:db_postgres_store_result: 0x7dadc8  
PQresultStatus(PGRES_COMMAND_OK) PQgetResult(0x25b3bc0)
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:db_postgres:free_query:  
PQclear(0x25b3bc0) result set
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:core:db_free_rows: freeing  
0 rows
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:core:db_free_result:  
freeing result set at 0x7dc168
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:tm:set_timer: relative  
timeout is 120
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:tm:insert_timer_unsafe:  
[1]: 0x7f4a74c666d0 (87872)
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:tm:t_unref: UNREF_UNSAFE:  
[0x7f4a74c66480] after is 0
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:core:destroy_avp_list:  
destroying list (nil)
Aug  9 09:42:36 opensips ./opensips[20031]: DBG:core:receive_msg: cleaning  
up



On Tue, 09 Aug 2011 01:35:19 +0600, Bogdan-Andrei Iancu  
<bogdan at opensips.org> wrote:

> HI Pavel,
>
> My first guess is that the 180 somehow does no match the  
> transaction....If you can reproduce the case, could you run a call with  
> debug=6 and post the opensips log ?
>
> Regards,
> Bogdan
>
> On 08/08/2011 08:24 AM, Pavel Eremin wrote:
>> Hi!
>>
>> iF i use topology_hiding in initial request then initial 'INVITE' are
>> good. There are no Record-Route or Via(except myself) header exist. But  
>> in
>> 180 and 183 SIP messages Record-Route is present.
>>
>> Topology_hiding must delete RR header 180 and 183 in messages too, Does  
>> it?
>>
>> Some scheme like sip_trace. I need to hide C sip-proxy. B is
>> topology_hiding opensips. A - some client.
>>
>> A -> initial -> B
>> C <- initial <- B
>> B -> 100 try -> A
>> C -> 180 Ring -> B
>> A <- 180 Ring <- B (RR present with C ip) ???
>> C -> 200 OK -> B
>> A <- 200 OK <- B  (no RR present)
>> ... ACK Exchange and Buy
>>
>
>


-- 
Using Opera's revolutionary email client: http://www.opera.com/mail/



More information about the Users mailing list