[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