[Users] loose_route goes strict - Stray colon in Record-Route

Further to below problem regarding BYEs not loose_routed. I see now that openser sends the invite with a wierd colon at the end of "127.0.0.1:" in record route. The same colon is of course also present in the BYEs which loop. Is it possible that OS gets confused by this when receiving the BYE ? What causes this - How can I work around this ? Thanks a lot for your help in the matter. I am using openser 1.0.1 Gerry Inivite sent by OS: INVITE sip:7336058@127.0.0.1:5061 SIP/2.0 Max-Forwards: 10 Record-Route: <sip:127.0.0.1:;r2=on;ftag=as58f53672;lr=on> Record-Route: <sip:101.101.101.101;r2=on;ftag=as58f53672;lr=on> Via: SIP/2.0/UDP 127.0.0.1:5060;branch=z9hG4bK39c3.dcf37ad6.0 Via: SIP/2.0/UDP 202.202.202.202:5060;branch=z9hG4bK2955936f From: "7654321" <sip:7654321@XXXXXXXXXXXX>;tag=as58f53672 To: <sip:7654321@XXXXXXXXXXXX> Contact: <sip:7654321@202.202.202.202> Call-ID: 5cdc877611378bf05dc78ef3035be7fb@xxxxxxxxxxxxxx CSeq: 103 INVITE User-Agent: Asterisk PBX Date: Thu, 29 Jun 2006 07:23:52 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER Content-Type: application/sdp Content-Length: 240 -----Original Message----- From: G.Jacobsen [mailto:g_jacobsen@yahoo.co.uk] Sent: Donnerstag, 29. Juni 2006 01:04 To: Devel@Openser. Org Subject: loose_route goes strict with BYEs Gentlemen, I have openser sitting on the same machine as another UA - openser is on port 5060 the other on 5061. BYEs by the UA are not loose_routed to the originating client - causing the BYEs to loop on openser with 513 message too big. I am not sure whether this is related - but a similar problem seems to have been touched here before - still cant find the solution. http://openser.org/pipermail/devel/2006-April/002540.html I have put all aliases with the port 5060 now - still doesnt help. If I read the debug correctly openser does strict routing on this line - why ? "rewrite_uri: Rewriting Request-URI with 'sip:111.111.111.111;r2=on;ftag=109880961431220;lr=on' " I would be most grateful if someone could explain which parameter causes the BYE to go strict. TIA Gerry Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: SIP Request: Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: method: <BYE> Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: uri: <sip:1234567@sip.somedomain.com:5060> Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: version: <SIP/2.0> Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: parse_headers: flags=2 Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: DEBUG: add_param: tag=109880961431220 Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: DEBUG:parse_to:end of header reached, state=29 Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: DEBUG: get_hdr_field: <To> [55]; uri=[sip:1234567@sip.somedomain.com:5060] Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: DEBUG: to body [<sip:1234567@sip.somedomain.com:5060>] Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: Found param type 235, <rport> = <n/a>; state=6 Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: Found param type 232, <branch> = <z9hG4bK719885386>; state=16 Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: end of header reached, state=5 Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: parse_headers: Via found, flags=2 Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: parse_headers: this is the first via Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: After parse_msg... Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: preparing to run routing scripts... Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: parse_headers: flags=100 Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: get_hdr_field: cseq <CSeq>: <2> <BYE> Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: DEBUG:maxfwd:is_maxfwd_present: value = 70 Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: DEBUG: add_param: tag=1957747793 Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: DEBUG:parse_to:end of header reached, state=29 Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: parse_headers: flags=200 Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: is_preloaded: No Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: grep_sock_info - checking if host==us: 14==9 && [sip.somedomain.com] == [127.0.0.1] Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: grep_sock_info - checking if port 5060 matches port 5060 Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: grep_sock_info - checking if host==us: 14==13 && [sip.somedomain.com] == [111.111.111.111] Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: grep_sock_info - checking if port 5060 matches port 5060 Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: grep_sock_info - checking if host==us: 14==9 && [sip.somedomain.com] == [127.0.0.1] Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: grep_sock_info - checking if port 5060 matches port 5060 Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: grep_sock_info - checking if host==us: 14==13 && [sip.somedomain.com] == [111.111.111.111] Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: grep_sock_info - checking if port 5060 matches port 5060 Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: grep_sock_info - checking if host==us: 9==9 && [127.0.0.1] == [127.0.0.1] Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: grep_sock_info - checking if port 5060 matches port 5060 Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: grep_sock_info - checking if host==us: 9==9 && [127.0.0.1] == [127.0.0.1] Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: DBG:rr:run_rr_callbacks: callback id 0 entered Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: DEBUG:uac:restore_from: getting 'vsf' Route param Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: DEBUG:uac:restore_from: Route param 'vsf' not found Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: after_strict: Next hop: 'sip:111.111.111.111;r2=on;ftag=109880961431220;lr=on' is loose router Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: parse_headers: flags=ffffffffffffffff Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: DEBUG: get_hdr_body : content_length=0 Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: found end of header Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: rewrite_uri: Rewriting Request-URI with 'sip:111.111.111.111;r2=on;ftag=109880961431220;lr=on' Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: after_strict: The last route URI: 'sip:111.111.111.111;r2=on;ftag=109880961431220;lr=on' Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: parse_headers: flags=ffffffffffffffff Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: parse_headers: flags=58 Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: rc_get_seqnbr: couldn't open sequence file /var/run/radius.seq: Permission denied Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: parse_headers: flags=58 Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: ACC: request accounted: method=BYE, i-uri=sip:1234567@sip.somedomain.com:5060, o-uri=sip:111.111.111.111;r2=on;ftag=109880961431220;lr=on, call_id=2BCF5051-F28C-4CCA-AE6B-D895607B668E(a)81.198.36.24, from=<sip:7654321@sip.somedomain.com:5060>;tag=1957747793, code=200 ok Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: DEBUG: t_newtran: msg id=2 , global msg id=1 , T on entrance=0xffffffff Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: parse_headers: flags=ffffffffffffffff Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: parse_headers: flags=78 Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: t_lookup_request: start searching: hash=51354, isACK=0 Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: DEBUG: RFC3261 transaction matching failed Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: DEBUG: t_lookup_request: no transaction found Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: DBG: trans=0x405797d8, callback type 1, id 0 entered Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: DEBUG: mk_proxy: doing DNS lookup... Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: check_via_address(127.0.0.1, 127.0.0.1, 0) Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: DEBUG: add_to_tail_of_timer[4]: 0x405798f4 Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19830]: SIP Request: Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: DEBUG: add_to_tail_of_timer[0]: 0x40579904 Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19830]: method: <BYE> Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: SER: new transaction fwd'ed Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19830]: uri: <sip:111.111.111.111;r2=on;ftag=109880961431220;lr=on> Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: DEBUG:destroy_avp_list: destroying list (nil) Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19830]: version: <SIP/2.0> Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19818]: receive_msg: cleaning up Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19830]: parse_headers: flags=2 Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19830]: DEBUG: add_param: tag=109880961431220 Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19830]: DEBUG:parse_to:end of header reached, state=29 Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19830]: DEBUG: get_hdr_field: <To> [55]; uri=[sip:1234567@sip.somedomain.com:5060] Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19830]: DEBUG: to body [<sip:1234567@sip.somedomain.com:5060>] Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19830]: Found param type 232, <branch> = <z9hG4bKa98c.f4c21e03.0>; state=16 Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19830]: end of header reached, state=5 Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19830]: parse_headers: Via found, flags=2 Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19830]: parse_headers: this is the first via Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19830]: After parse_msg... Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19830]: preparing to run routing scripts... Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19830]: parse_headers: flags=100 Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19830]: Found param type 235, <rport> = <5061>; state=6 Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19830]: Found param type 232, <branch> = <z9hG4bK719885386>; state=16 Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19830]: end of header reached, state=5 Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19830]: parse_headers: Via found, flags=100 Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19830]: parse_headers: this is the second via Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19830]: get_hdr_field: cseq <CSeq>: <2> <BYE> Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19830]: DEBUG:maxfwd:is_maxfwd_present: value = 69 Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19830]: DEBUG: add_param: tag=1957747793 Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19830]: DEBUG:parse_to:end of header reached, state=29 Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19830]: parse_headers: flags=200 Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19830]: DEBUG: get_hdr_body : content_length=0 Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19830]: found end of header Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19830]: find_first_route: No Route headers found Jun 29 00:32:16 gatesip1 /usr/local/sbin/openser[19830]: loose_route: There is no Route HF ___________________________________________________________ All new Yahoo! Mail "The new Interface is stunning in its simplicity and ease of use." - PC Magazine http://uk.docs.yahoo.com/nowyoucan.html