[Serusers] Re: [Serdev] Bug? Inconsistent return of loose_route function
Alex Mack
amack at fhm.edu
Wed May 25 15:05:06 CEST 2005
Hi!
I've tested your changes, Cesc, but it didn't solve the issue with BYE
not getting through to the TLS'ed snom phone, my setup:
(84040) (84033)
Snom190 ------[NAT]------ SER ------[NAT]------ Grandstream
|----------TLS--------| |--------UDP-----------|
Problem still is: the BYE from GS to Snom never reaches the Snom. I
think it's related to connection reuse, or the lack of it.
How should this work in real life? Why are there 2 Record-Routes? What
does the "r2" parameter do?
Anyway, your patch did some changes, because loose_route DID return
FALSE for the BYE when it would have to be routed from UDP to TLS. This
has been fixed by applying your patch to modules/rr/loose.c. Now it
returns TRUE.
Here's the debug output for the lost BYE BEFORE the patch:
9(29936) SIP Request:
9(29936) method: <BYE>
9(29936) uri:
<sip:84040@*SNOM_PRIVIP*:2069;line=mq1lx8ld;transport=tls>
9(29936) version: <SIP/2.0>
9(29936) parse_headers: flags=1
9(29936) Found param type 232, <branch> = <z9hG4bK2010b4141608130c>;
state=16
9(29936) end of header reached, state=5
9(29936) parse_headers: Via found, flags=1
9(29936) parse_headers: this is the first via
9(29936) After parse_msg...
9(29936) preparing to run routing scripts...
9(29936) XLOG: xl_print_log: final buffer length 110
9(29936) time [Wed May 25 14:30:59 2005] method <BYE> r-uri
<sip:84040@*SNOM_PRIVIP*:2069;line=mq1lx8ld;transport=tls>
9(29936) parse_headers: flags=128
9(29936) DEBUG: add_param: tag=vff0lxwqz8
9(29936) end of header reached, state=29
9(29936) DEBUG: get_hdr_field: <To> [57]; uri=[sip:84040 at mydomain.org]
9(29936) DEBUG: to body ["LCN VoIP Tel 1" <sip:84040 at mydomain.org>]
9(29936) get_hdr_field: cseq <CSeq>: <10746> <BYE>
9(29936) DEBUG:maxfwd:is_maxfwd_present: value = 70
9(29936) check_via_address(*NAT_PUBIP*, *GS_PRIVIP*, 0)
9(29936) parse_headers: flags=64
9(29936) DEBUG: get_hdr_body : content_length=0
9(29936) found end of header
9(29936) ------> Request's source is NAT'ed!
9(29936) DEBUG: add_param: tag=cc5e1b5aad9ba0fc
9(29936) end of header reached, state=29
9(29936) parse_headers: flags=256
9(29936) is_preloaded: No
9(29936) grep_sock_info - checking if host==us: 13==14 &&
[*SNOM_PRIVIP*] == [*SER_PUBIP*]
9(29936) grep_sock_info - checking if port 5060 matches port 2069
9(29936) grep_sock_info - checking if host==us: 13==14 &&
[*SNOM_PRIVIP*] == [*SER_PUBIP*]
9(29936) grep_sock_info - checking if port 5060 matches port 2069
9(29936) grep_sock_info - checking if host==us: 13==14 &&
[*SNOM_PRIVIP*] == [*SER_PUBIP*]
9(29936) grep_sock_info - checking if port 5061 matches port 2069
9(29936) check_self: host != me
9(29936) grep_sock_info - checking if host==us: 14==14 &&
[*SER_PUBIP*] == [*SER_PUBIP*]
9(29936) grep_sock_info - checking if port 5060 matches port 5060
9(29936) after_loose: Topmost route URI:
'sip:*SER_PUBIP*;r2=on;ftag=vff0lxwqz8;lr' is me
9(29936) parse_headers: flags=256
9(29936) found end of header
9(29936) find_next_route: No next Route HF found
9(29936) after_loose: No next URI found
9(29936) XLOG: xl_print_log: final buffer length 43
9(29936) ------- NO Loose Routing for BYE detected!
9(29936) ----> Checking for outbound request...
9(29936) grep_sock_info - checking if host==us: 13==14 &&
[*SNOM_PRIVIP*] == [*SER_PUBIP*]
9(29936) grep_sock_info - checking if port 5060 matches port 2069
9(29936) grep_sock_info - checking if host==us: 13==14 &&
[*SNOM_PRIVIP*] == [*SER_PUBIP*]
9(29936) grep_sock_info - checking if port 5060 matches port 2069
9(29936) grep_sock_info - checking if host==us: 13==14 &&
[*SNOM_PRIVIP*] == [*SER_PUBIP*]
9(29936) grep_sock_info - checking if port 5061 matches port 2069
9(29936) check_self: host != me
9(29936) parse_headers: flags=-1
9(29936) XLOG: xl_print_log: final buffer length 599
9(29936) Message:
BYE sip:84040@*SNOM_PRIVIP*:2069;line=mq1lx8ld;transport=tls SIP/2.0
Via: SIP/2.0/UDP *GS_PRIVIP*;branch=z9hG4bK2010b4141608130c
Route: <sip:*SER_PUBIP*;r2=on;ftag=vff0lxwqz8;lr>
Route: <sip:*SER_PUBIP*:5061;transport=tls;r2=on;ftag=vff0lxwqz8;lr>
From: <sip:84033 at mydomain.org;user=phone>;tag=cc5e1b5aad9ba0fc
To: "LCN VoIP Tel 1" <sip:84040 at mydomain.org>;tag=vff0lxwqz8
Call-ID: 3c267025927c-qdq7eg6tg7wp at snom190
CSeq: 10746 BYE
User-Agent: Grandstream BT100 1.0.5.18
Max-Forwards: 69
Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE
Content-Length: 0
9(29936) XLOG: xl_print_log: final buffer length 18
9(29936) Forcing RTP Relay
9(29936) ERROR: force_rtp_proxy2: support for RTP proxy is disabled
9(29936) DEBUG: t_newtran: msg id=2 , global msg id=0 , T on
entrance=0xffffffff
9(29936) parse_headers: flags=-1
9(29936) parse_headers: flags=60
9(29936) t_lookup_request: start searching: hash=65420, isACK=0
9(29936) DEBUG: RFC3261 transaction matching failed
9(29936) DEBUG: t_lookup_request: no transaction found
9(29936) DEBUG: mk_proxy: doing DNS lookup...
9(29936) parse_headers: flags=2048
9(29936) check_via_address(*NAT_PUBIP*, *GS_PRIVIP*, 0)
9(29936) tcp_send: no open tcp connection found, opening new one
This is output AFTER changing loose.c:
9(30810) SIP Request:
9(30810) method: <BYE>
9(30810) uri:
<sip:84040@*SNOM_PRIVIP*:2072;line=mq1lx8ld;transport=tls>
9(30810) version: <SIP/2.0>
9(30810) parse_headers: flags=1
9(30810) Found param type 232, <branch> = <z9hG4bKa9c44e2971bc9cb0>;
state=16
9(30810) end of header reached, state=5
9(30810) parse_headers: Via found, flags=1
9(30810) parse_headers: this is the first via
9(30810) After parse_msg...
9(30810) preparing to run routing scripts...
9(30810) XLOG: xl_print_log: final buffer length 110
9(30810) time [Wed May 25 14:43:47 2005] method <BYE> r-uri
<sip:84040@*SNOM_PRIVIP*:2072;line=mq1lx8ld;transport=tls>
9(30810) parse_headers: flags=128
9(30810) DEBUG: add_param: tag=vvtpi0yrd1
9(30810) end of header reached, state=29
9(30810) DEBUG: get_hdr_field: <To> [57]; uri=[sip:84040 at mydomain.org]
9(30810) DEBUG: to body ["LCN VoIP Tel 1" <sip:84040 at mydomain.org>]
9(30810) get_hdr_field: cseq <CSeq>: <48894> <BYE>
9(30810) DEBUG:maxfwd:is_maxfwd_present: value = 70
9(30810) check_via_address(*NAT_PUBIP*, *GS_PRIVIP*, 0)
9(30810) parse_headers: flags=64
9(30810) DEBUG: get_hdr_body : content_length=0
9(30810) found end of header
9(30810) ------> Request's source is NAT'ed!
9(30810) DEBUG: add_param: tag=265f0cd77557dd43
9(30810) end of header reached, state=29
9(30810) parse_headers: flags=256
9(30810) is_preloaded: No
9(30810) grep_sock_info - checking if host==us: 13==14 &&
[*SNOM_PRIVIP*] == [*SER_PUBIP*]
9(30810) grep_sock_info - checking if port 5060 matches port 2072
9(30810) grep_sock_info - checking if host==us: 13==14 &&
[*SNOM_PRIVIP*] == [*SER_PUBIP*]
9(30810) grep_sock_info - checking if port 5060 matches port 2072
9(30810) grep_sock_info - checking if host==us: 13==14 &&
[*SNOM_PRIVIP*] == [*SER_PUBIP*]
9(30810) grep_sock_info - checking if port 5061 matches port 2072
9(30810) check_self: host != me
9(30810) grep_sock_info - checking if host==us: 14==14 &&
[*SER_PUBIP*] == [*SER_PUBIP*]
9(30810) grep_sock_info - checking if port 5060 matches port 5060
9(30810) after_loose: Topmost route URI:
'sip:*SER_PUBIP*;r2=on;ftag=vvtpi0yrd1;lr' is me
9(30810) parse_headers: flags=256
9(30810) found end of header
9(30810) find_next_route: No next Route HF found
9(30810) after_loose: No next URI found
9(30810) parse_headers: flags=-1
9(30810) XLOG: xl_print_log: final buffer length 40
9(30810) +++++++ Loose Routing for BYE detected!
9(30810) XLOG: xl_print_log: final buffer length 599
9(30810) Message:
BYE sip:84040@*SNOM_PRIVIP*:2072;line=mq1lx8ld;transport=tls SIP/2.0
Via: SIP/2.0/UDP *GS_PRIVIP*;branch=z9hG4bKa9c44e2971bc9cb0
Route: <sip:*SER_PUBIP*;r2=on;ftag=vvtpi0yrd1;lr>
Route: <sip:*SER_PUBIP*:5061;transport=tls;r2=on;ftag=vvtpi0yrd1;lr>
From: <sip:84033 at mydomain.org;user=phone>;tag=265f0cd77557dd43
To: "LCN VoIP Tel 1" <sip:84040 at mydomain.org>;tag=vvtpi0yrd1
Call-ID: 3c26701b186a-918969x4677v at snom190
CSeq: 48894 BYE
User-Agent: Grandstream BT100 1.0.5.18
Max-Forwards: 69
Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE
Content-Length: 0
9(30810) XLOG: xl_print_log: final buffer length 18
9(30810) Forcing RTP Relay
9(30810) ERROR: force_rtp_proxy2: support for RTP proxy is disabled
9(30810) DEBUG: t_newtran: msg id=2 , global msg id=0 , T on
entrance=0xffffffff
9(30810) parse_headers: flags=-1
9(30810) parse_headers: flags=60
9(30810) t_lookup_request: start searching: hash=59149, isACK=0
9(30810) DEBUG: RFC3261 transaction matching failed
9(30810) DEBUG: t_lookup_request: no transaction found
9(30810) DEBUG: mk_proxy: doing DNS lookup...
9(30810) parse_headers: flags=2048
9(30810) check_via_address(*NAT_PUBIP*, *GS_PRIVIP*, 0)
9(30810) tcp_send: no open tcp connection found, opening new one
I'd like to have that issue resolved, but I don't get where to start.
There're some options like force_tcp_alias() but the documentation of
those funtcions in the NEWS file is poor at best. Is there more
information somewhere?
Alex Mack
Cesc Santasusana schrieb:
>Hi,
>
>I found what i think is a bug in the return value of loose_route() ...
>bear with me because it is a rather long email.
>
>First, the scenario:
>
>phone1 ----- SER1 ----- SER2 ----- phone2
>
>p1 to s1 and p2 to s2 use UDP
>s1 to s2 uses tcp or tls
>
>The bug comes into place when there is a change of protocol in ser,
>from UDP into TCP or TLS.
>We do not use a preloaded route set from the phones.
>What ser does is it adds 2 route headers, using the r2 parameter.
>Route: <route1>, <route2>
>
>CASE A: --------------------------------------------
>In this scenario, say p1 places a call to p2, going through s1 and s2,
>creating the route set with the record-route.
>Now, let's say p2 generates the BYE message.
>When the BYE gets to s1, the last hop, in the config we do:
>if( loose_route () ) {
> t_relay();
>}
>But, and here is the inconsistency, loose_route (remember we are using
>TCP/TLS, so there are 2 routes in one header field) returns FALSE.
>
>CASE B: --------------------------------------------
>If this experiment is repeated using ALL UDP, the route headers when they
>get to s1 contain only one route, and the call to loose_route() returns .... TRUE!
>
>
>Unless the config file does not allow blind sip message relaying, both cases end
>up working ... the BYE gets to the final destination. But if the config file does not
>accept relaying ... the request-uri in the BYE is not taken as a local domain ... and
>thus the message is rejected ... (To Alex Mack: could this be the solution to your problem?
>the BYEs not reaching the phone? add some log output and check it ... )
>
>================================================================
>So, this is not consistent. Now, what is the solution?
>I think that both case A and B should return the same, but what, true or false?
>
>As I see it, the solution causing less trouble is that both return true. So, the last proxy
>considers this BYE as being loose_routed.
>For this ... change the code in:
>rr::loose_route.c:: static inline int after_loose(struct sip_msg* _m, int preloaded)
> .....
> if (enable_double_rr && is_2rr(&puri.params)) {
> ....
> if (res > 0) { /* No next route found */
> DBG("after_loose: No next URI found\n");
> return (preloaded ? NOT_RR_DRIVEN : RR_DRIVEN);
> or simply
> return (preloaded RR_DRIVEN);
>
>
>And now ... the other option is that both return false ... but this would make big changes.
>Correct me if i am wrong, but wouldn't this be the compliant solution?
>Considering that the r-uri is not part of the route set, when the last proxy processes
>all route headers and there are no more left, there is no loose routing done. The
>destination is taken from the r-uri, not the route set ... thus loose_route should return
>false.
>Or I am getting it all wrong? rfc and goal of loose_route() ?
>
>
>Regards,
>
>Cesc
>
>
>
>Unclassified
>
>
>
>
>
>
>
>
>
>
>
>_______________________________________________
>Serdev mailing list
>serdev at lists.iptel.org
>http://lists.iptel.org/mailman/listinfo/serdev
>
>
>
More information about the sr-users
mailing list