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@mydomain.org] 9(29936) DEBUG: to body ["LCN VoIP Tel 1" sip:84040@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@mydomain.org;user=phone;tag=cc5e1b5aad9ba0fc To: "LCN VoIP Tel 1" sip:84040@mydomain.org;tag=vff0lxwqz8 Call-ID: 3c267025927c-qdq7eg6tg7wp@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@mydomain.org] 9(30810) DEBUG: to body ["LCN VoIP Tel 1" sip:84040@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@mydomain.org;user=phone;tag=265f0cd77557dd43 To: "LCN VoIP Tel 1" sip:84040@mydomain.org;tag=vvtpi0yrd1 Call-ID: 3c26701b186a-918969x4677v@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@lists.iptel.org http://lists.iptel.org/mailman/listinfo/serdev