[OpenSIPS-Users] topology_hiding Record-Route
Bogdan-Andrei Iancu
bogdan at opensips.org
Wed Aug 10 21:58:18 CEST 2011
Hi Pavel,
Thanks for the logs - please apply the attached patch and let me know if
this solved your problem.
Regards,
Bogdan
On 08/08/2011 11:59 PM, Pavel Eremin wrote:
> 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
>>>
>>
>>
>
>
--
Bogdan-Andrei Iancu
OpenSIPS eBootcamp - 19th of September 2011
OpenSIPS solutions and "know-how"
-------------- next part --------------
A non-text attachment was scrubbed...
Name: dialog.patch
Type: text/x-patch
Size: 890 bytes
Desc: not available
URL: <http://lists.opensips.org/pipermail/users/attachments/20110810/5fe264b0/attachment.bin>
More information about the Users
mailing list