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@22.22.22.22;user=phone}
Aug 9 09:42:36 opensips ./opensips[20031]: DBG:core:get_hdr_field:
<To> [58]; uri=[sip:79128923945@22.22.22.22;user=phone]
Aug 9 09:42:36 opensips ./opensips[20031]: DBG:core:get_hdr_field: to
body [<sip:79128923945@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@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@11.11.11.11>;tag=2925795659-3759225282-335606691-1600804190\\015\\012
To: <sip:79128923945@22.22.22.22;user=phone>;tag=1c416124843\\015\\012
Call-ID: 4b196530c23911e0a3f300145e556a5f@11.11.11.11\\015\\012CSeq: 1
INVITE\\015\\012
Contact: <sip:1...@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@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@11.11.11.11>;tag=2925795659-3759225282-335606691-1600804190#015#012To:
<sip:79128923945@22.22.22.22;user=phone>;tag=1c416124843#015#012Call-ID:
4b196530c23911e0a3f300145e556a5f@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@11.11.11.11>;tag=2925795659-3759225282-335606691-1600804190\\015\\012To:
<sip:79128923945@22.22.22.22;us
er=phone>;tag=1c416124843\\015\\012Call-ID:
4b196530c23911e0a3f300145e556a5f@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@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
<bog...@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"
Index: modules/dialog/dlg_tophiding.c
===================================================================
--- modules/dialog/dlg_tophiding.c (revision 8223)
+++ modules/dialog/dlg_tophiding.c (working copy)
@@ -213,6 +213,13 @@
struct dlg_leg* leg;
LM_DBG("start\n");
+
+ /* parse all headers to be sure that all RR and Contact hdrs are found */
+ if (parse_headers(rpl, HDR_EOH_T, 0)< 0) {
+ LM_ERR("Failed to parse reply\n");
+ return -1;
+ }
+
/* replace contact */
if(dlg_replace_contact(rpl, dlg) < 0) {
LM_ERR("Failed to replace contact\n");
@@ -460,6 +467,12 @@
/* add route headers */
fix_route_dialog(req, dlg);
+ /* replace contact*/
+ if(dlg_replace_contact(req, dlg) < 0) {
+ LM_ERR("Failed to replace contact\n");
+ return -1;
+ }
+
/* register tm callback for response in */
ref_dlg( dlg , 1);
if ( d_tmb.register_tmcb( req, 0, TMCB_RESPONSE_IN,
_______________________________________________
Users mailing list
Users@lists.opensips.org
http://lists.opensips.org/cgi-bin/mailman/listinfo/users
