<div dir="ltr">Hi Daniel, <div><br></div><div>I have advertise as:</div><div><br></div><div>listen=tcp:<a href="http://10.116.15.237:443">10.116.15.237:443</a> advertise <a href="http://sbc01.stg.gii.me:443">sbc01.stg.gii.me:443</a><br></div><div><br></div><div>(normally it would be tls, I switched to tcp so I could get unencrypted traffic in tcpdump for you)</div><div><br></div><div>Record-route is done as:</div><div><br></div><div> # Dispatch requests<br> if (is_method("INVITE")) {<br> $avp(caller_conid) = $conid;<br> record_route();<br> route(DISPATCH);<br> exit;<br> }<br></div><div><br></div><div>(route DISPATCH basically does dispatcher lookup and t_relay)</div><div><br></div><div>And this is the log for the BYE that doesn't work:</div><div><br></div><div>"message":" DEBUG: <core> [core\/udp_server.c:498]: udp_rcv_loop(): received on udp socket: (106\/100\/907) [[BYE sip:linphone@104.175.176.242:43750;alias=130.211.3.12~53883~2;transport=tcp SIP\/2.0 0D 0A Via: SIP\/2.]]"}<br>"message":" DEBUG: <core> [core\/parser\/msg_parser.c:610]: parse_msg(): SIP Request:"}<br>"message":" DEBUG: <core> [core\/parser\/msg_parser.c:612]: parse_msg(): method: <BYE>"}<br>"message":" DEBUG: <core> [core\/parser\/msg_parser.c:614]: parse_msg(): uri: <sip:linphone@104.175.176.242:43750;alias=130.211.3.12~53883~2;transport=tcp>"}<br>"message":" DEBUG: <core> [core\/parser\/msg_parser.c:616]: parse_msg(): version: <SIP\/2.0>"}<br>"message":" DEBUG: <core> [core\/parser\/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK4eda.30b29b519ea0cbd688ceb8071e271f7d.0>; state=16"}<br>"message":" DEBUG: <core> [core\/parser\/parse_via.c:2639]: parse_via(): end of header reached, state=5"}<br>"message":" DEBUG: <core> [core\/parser\/msg_parser.c:498]: parse_headers(): Via found, flags=2"}<br>"message":" DEBUG: <core> [core\/parser\/msg_parser.c:500]: parse_headers(): this is the first via"}<br>"message":" DEBUG: <core> [core\/parser\/parse_via.c:1303]: parse_via_param(): Found param type 234, <received> = <35.226.32.33>; state=6"}<br>"message":" DEBUG: <core> [core\/parser\/parse_via.c:1303]: parse_via_param(): Found param type 235, <rport> = <6061>; state=6"}<br>"message":" DEBUG: <core> [core\/parser\/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bKy0gFgvHcajHtm>; state=16"}<br>"message":" DEBUG: <core> [core\/parser\/parse_via.c:2639]: parse_via(): end of header reached, state=5"}<br>"message":" DEBUG: <core> [core\/parser\/msg_parser.c:498]: parse_headers(): Via found, flags=78"}<br>"message":" DEBUG: <core> [core\/parser\/msg_parser.c:511]: parse_headers(): this is the second via"}<br>"message":" DEBUG: <core> [core\/parser\/parse_addr_spec.c:185]: parse_to_param(): add param: tag=DU0ehPULu"}<br>"message":" DEBUG: <core> [core\/parser\/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29"}<br>"message":" DEBUG: <core> [core\/parser\/msg_parser.c:171]: get_hdr_field(): <To> [82]; uri=[<a href="mailto:sip%3A8bd2a0aba14541789bb7269800646458@app.nextplus.me">sip:8bd2a0aba14541789bb7269800646458@app.nextplus.me</a>]"}<br>"message":" DEBUG: <core> [core\/parser\/msg_parser.c:174]: get_hdr_field(): to body [\"Joel Test\" <<a href="mailto:sip%3A8bd2a0aba14541789bb7269800646458@app.nextplus.me">sip:8bd2a0aba14541789bb7269800646458@app.nextplus.me</a>>], to tag [DU0ehPULu]"}<br>"message":" DEBUG: <core> [core\/parser\/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <12626897> <BYE>"}<br>"message":" DEBUG: <core> [core\/receive.c:320]: receive_msg(): --- received sip message - request - call-id: [nsWZzKWRld] - cseq: [12626897 BYE]"}<br>"message":" DEBUG: <core> [core\/parser\/msg_parser.c:185]: get_hdr_field(): content_length=0"}<br>"message":" DEBUG: <core> [core\/parser\/msg_parser.c:89]: get_hdr_field(): found end of header"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core> [core\/receive.c:380]: receive_msg(): preparing to run routing scripts..."}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core> [core\/socket_info.c:628]: grep_sock_info(): checking if host==us: 12==13 && [198.1.54.228] == [10.116.15.237]"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core> [core\/socket_info.c:646]: grep_sock_info(): checking advertise if host==us: 12==12 && [198.1.54.228] == [34.70.182.24]"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core> [core\/socket_info.c:628]: grep_sock_info(): checking if host==us: 12==13 && [198.1.54.228] == [10.116.15.237]"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core> [core\/socket_info.c:628]: grep_sock_info(): checking if host==us: 12==13 && [198.1.54.228] == [10.116.15.237]"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core> [core\/socket_info.c:646]: grep_sock_info(): checking advertise if host==us: 12==16 && [198.1.54.228] == [<a href="http://sbc01.stg.gii.me">sbc01.stg.gii.me</a>]"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core> [core\/socket_info.c:628]: grep_sock_info(): checking if host==us: 12==13 && [198.1.54.228] == [10.116.15.237]"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core> [core\/forward.c:413]: check_self(): host != me"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} maxfwd [mf_funcs.c:74]: is_maxfwd_present(): value = 69 "}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity.c:247]: check_ruri_sip_version(): check_ruri_sip_version entered"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity.c:270]: check_ruri_sip_version(): check_ruri_sip_version passed"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity.c:277]: check_ruri_scheme(): check_ruri_scheme entered"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity.c:297]: check_ruri_scheme(): check_ruri_scheme passed"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity.c:305]: check_required_headers(): check_required_headers entered"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity.c:313]: check_required_headers(): check_required_headers passed"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity.c:479]: check_cseq_method(): check_cseq_method entered"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity.c:512]: check_cseq_method(): check_cseq_method passed"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity.c:521]: check_cseq_value(): check_cseq_value entered"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity.c:549]: check_cseq_value(): check_cseq_value passed"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity.c:558]: check_cl(): check_cl entered"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity.c:583]: check_cl(): check_cl passed"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity.c:595]: check_expires_value(): check_expires_value entered"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity.c:632]: check_expires_value(): no expires header found"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity.c:732]: check_parse_uris(): check_parse_uris entered"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity.c:736]: check_parse_uris(): parsing ruri"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity.c:750]: check_parse_uris(): looking up From header"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity.c:764]: check_parse_uris(): parsing From header"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core> [core\/parser\/parse_addr_spec.c:185]: parse_to_param(): add param: tag=QZQSQQegvc5Zr"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core> [core\/parser\/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity.c:790]: check_parse_uris(): parsing From URI"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity.c:808]: check_parse_uris(): looking up To header"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity.c:830]: check_parse_uris(): check_parse_uris(): parsing To URI"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity.c:875]: check_parse_uris(): check_parse_uris passed"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity_mod.c:254]: w_sanity_check(): sanity checks result: 1"}<br>"message":" NOTICE: {1 12626897 BYE nsWZzKWRld} <script>: JOEL TEST New request - M=BYE UAC-IP=<a href="http://198.1.54.228:5060">198.1.54.228:5060</a> LB-IP=<null>:<null> CONID=<null> TCP-CONID=<null> UA='FS textPlus Voice' ID=nsWZzKWRld"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core> [core\/msg_translator.c:161]: check_via_address(): (198.1.54.228, 198.1.54.228, 0)"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} siputils [checks.c:123]: has_totag(): totag found"}<br>"message":" NOTICE: {1 12626897 BYE nsWZzKWRld} <script>: In-dialog request from COPS - M=BYE R=sip:linphone@104.175.176.242:43750;alias=130.211.3.12~53883~2;transport=tcp ID=nsWZzKWRld"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} rr [loose.c:90]: is_preloaded(): is_preloaded: No"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core> [core\/socket_info.c:628]: grep_sock_info(): checking if host==us: 15==13 && [104.175.176.242] == [10.116.15.237]"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core> [core\/socket_info.c:635]: grep_sock_info(): checking if port 5070 (advertise 5070) matches port 43750"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core> [core\/socket_info.c:628]: grep_sock_info(): checking if host==us: 15==13 && [104.175.176.242] == [10.116.15.237]"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core> [core\/socket_info.c:635]: grep_sock_info(): checking if port 5080 (advertise 0) matches port 43750"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core> [core\/socket_info.c:628]: grep_sock_info(): checking if host==us: 15==13 && [104.175.176.242] == [10.116.15.237]"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core> [core\/socket_info.c:635]: grep_sock_info(): checking if port 443 (advertise 443) matches port 43750"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core> [core\/socket_info.c:628]: grep_sock_info(): checking if host==us: 15==13 && [104.175.176.242] == [10.116.15.237]"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core> [core\/socket_info.c:635]: grep_sock_info(): checking if port 80 (advertise 0) matches port 43750"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core> [core\/forward.c:413]: check_self(): host != me"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core> [core\/socket_info.c:628]: grep_sock_info(): checking if host==us: 12==13 && [34.70.182.24] == [10.116.15.237]"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core> [core\/socket_info.c:635]: grep_sock_info(): checking if port 5070 (advertise 5070) matches port 5070"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core> [core\/socket_info.c:646]: grep_sock_info(): checking advertise if host==us: 12==12 && [34.70.182.24] == [34.70.182.24]"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} rr [loose.c:811]: after_loose(): Topmost route URI: 'sip:34.70.182.24:5070;r2=on;lr=on;ftag=DU0ehPULu;did=bfc.e45;nat=yes' is me"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core> [core\/socket_info.c:628]: grep_sock_info(): checking if host==us: 16==13 && [<a href="http://sbc01.stg.gii.me">sbc01.stg.gii.me</a>] == [10.116.15.237]"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core> [core\/socket_info.c:635]: grep_sock_info(): checking if port 443 (advertise 443) matches port 443"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core> [core\/socket_info.c:646]: grep_sock_info(): checking advertise if host==us: 16==16 && [<a href="http://sbc01.stg.gii.me">sbc01.stg.gii.me</a>] == [<a href="http://sbc01.stg.gii.me">sbc01.stg.gii.me</a>]"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core> [core\/parser\/msg_parser.c:89]: get_hdr_field(): found end of header"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} rr [loose.c:181]: find_next_route(): No next Route HF found"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} rr [loose.c:875]: after_loose(): no next URI found"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} rr [rr_cb.c:94]: run_rr_callbacks(): callback id 0 entered with <r2=on;lr=on;ftag=DU0ehPULu;did=bfc.e45;nat=yes>"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} dialog [dlg_handlers.c:1306]: dlg_onroute(): route param is 'bfc.e45' (len=7)"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} dialog [dlg_hash.c:784]: dlg_lookup(): ref dlg 0x7f56979d4660 with 1 -> 3"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} dialog [dlg_hash.c:786]: dlg_lookup(): dialog id=1358 found on entry 3323"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} dialog [dlg_profile.c:536]: set_current_dialog(): setting current dialog [3323:1358]"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} dialog [dlg_hash.c:1228]: next_state_dlg(): dialog 0x7f56979d4660 changed from state 4 to state 5, due event 7 (ref 3)"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} dialog [dlg_hash.c:1009]: dlg_ref_helper(): ref op on 0x7f56979d4660 with 1 from dlg_handlers.c:1430"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} dialog [dlg_hash.c:1013]: dlg_ref_helper(): ref dlg 0x7f56979d4660 with 1 -> 4"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} dialog [dlg_handlers.c:1441]: dlg_onroute(): BYE successfully processed"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} dialog [dlg_hash.c:1029]: dlg_unref_helper(): unref op on 0x7f56979d4660 with 2 from dlg_handlers.c:1465"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} dialog [dlg_hash.c:1033]: dlg_unref_helper(): unref dlg 0x7f56979d4660 with 2 -> 2"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} dialog [dlg_hash.c:1029]: dlg_unref_helper(): unref op on 0x7f56979d4660 with 1 from dlg_hash.c:1047"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} dialog [dlg_hash.c:1033]: dlg_unref_helper(): unref dlg 0x7f56979d4660 with 1 -> 1"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} nathelper [nathelper.c:1144]: handle_ruri_alias(): setting dst_uri to <sip:130.211.3.12:53883;transport=tcp>"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} nathelper [nathelper.c:1166]: handle_ruri_alias(): rewriting r-uri to <sip:linphone@104.175.176.242:43750;transport=tcp>"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} tm [t_lookup.c:1328]: t_newtran(): msg (0x7f569f9211e0) id=394\/10865 global id=393\/10865 T start=0xffffffffffffffff"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} tm [t_lookup.c:497]: t_lookup_request(): start searching: hash=44516, isACK=0"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} tm [t_lookup.c:455]: matching_3261(): RFC3261 transaction matching failed - via branch [z9hG4bK4eda.30b29b519ea0cbd688ceb8071e271f7d.0]"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} tm [t_lookup.c:675]: t_lookup_request(): no transaction found"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} tm [t_hooks.c:336]: run_reqin_callbacks_internal(): trans=0x7f56979d6558, callback type 1, id 0 entered"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core> [core\/crypto\/md5utils.c:67]: MD5StringArray(): MD5 calculated: 7fe00a28920a3325330971908f8c5b0e"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} siputils [checks.c:123]: has_totag(): totag found"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} rr [loose.c:1095]: check_route_param(): route params checking against [;r2=on;lr=on;ftag=DU0ehPULu;did=bfc.e45;nat=yes] (orig: [r2=on;lr=on;ftag=DU0ehPULu;did=bfc.e45;nat=yes])"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} rr [loose.c:1101]: check_route_param(): params are <;r2=on;lr=on;ftag=DU0ehPULu;did=bfc.e45;nat=yes>"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} siputils [checks.c:123]: has_totag(): totag found"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core> [core\/msg_translator.c:161]: check_via_address(): (198.1.54.228, 198.1.54.228, 0)"}<br>"message":" ERROR: {1 12626897 BYE nsWZzKWRld} tm [..\/..\/core\/forward.h:261]: msg_send_buffer(): tcp_send failed"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} tm [t_fwd.c:1537]: t_send_branch(): send to <a href="http://130.211.3.12:53883">130.211.3.12:53883</a> (2) failed"}<br>"message":" WARNING: {1 12626897 BYE nsWZzKWRld} tm [t_fwd.c:1557]: t_send_branch(): sending request on branch 0 failed"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} tm [t_funcs.c:336]: t_relay_to(): t_forward_nonack returned error -1 (-477)"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} tm [t_funcs.c:354]: t_relay_to(): -477 error reply generation delayed "}<br>"message":" ERROR: {1 12626897 BYE nsWZzKWRld} <script>: Could not forward request - M=BYE R=sip:linphone@104.175.176.242:43750;transport=tcp ID=nsWZzKWRld"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core> [core\/msg_translator.c:161]: check_via_address(): (198.1.54.228, 198.1.54.228, 0)"}<br>"message":" ERROR: {1 12626897 BYE nsWZzKWRld} sl [sl_funcs.c:392]: sl_reply_error(): stateless error reply used: I'm terribly sorry, server error occurred (1\/SL)"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core> [core\/receive.c:438]: receive_msg(): request-route executed in: 1051 usec"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} dialog [dlg_hash.c:784]: dlg_lookup(): ref dlg 0x7f56979d4660 with 1 -> 2"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} dialog [dlg_hash.c:786]: dlg_lookup(): dialog id=1358 found on entry 3323"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} dialog [dlg_hash.c:1029]: dlg_unref_helper(): unref op on 0x7f56979d4660 with 1 from dlg_hash.c:1047"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} dialog [dlg_hash.c:1033]: dlg_unref_helper(): unref dlg 0x7f56979d4660 with 1 -> 1"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} tm [t_lookup.c:1493]: t_unref(): delayed error reply generation(-477)"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core> [core\/msg_translator.c:161]: check_via_address(): (198.1.54.228, 198.1.54.228, 0)"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} tm [t_reply.c:1667]: cleanup_uac_timers(): RETR\/FR timers reset"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} tm [t_hooks.c:252]: run_trans_callbacks_internal(): DBG: trans=0x7f56979d6558, callback type 512, id 0 entered"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} dialog [dlg_hash.c:784]: dlg_lookup(): ref dlg 0x7f56979d4660 with 1 -> 2"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} dialog [dlg_hash.c:786]: dlg_lookup(): dialog id=1358 found on entry 3323"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} dialog [dlg_hash.c:1029]: dlg_unref_helper(): unref op on 0x7f56979d4660 with 1 from dlg_hash.c:1047"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} dialog [dlg_hash.c:1033]: dlg_unref_helper(): unref dlg 0x7f56979d4660 with 1 -> 1"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} tm [t_reply.c:610]: _reply_light(): reply sent out. buf=0x7f569f91ed70: SIP\/2.0 477 Unfortun..., shmem=0x7f56979d1520: SIP\/2.0 477 Unfortun"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} tm [t_reply.c:621]: _reply_light(): finished"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core> [core\/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core> [core\/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core> [core\/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core> [core\/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core> [core\/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core> [core\/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core> [core\/xavp.c:517]: xavp_destroy_list(): destroying xavp list (nil)"}<br>"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core> [core\/receive.c:529]: receive_msg(): cleaning up"}<br>"message":" DEBUG: <core> [core\/io_wait.h:599]: io_watch_del(): DBG: io_watch_del (0x562f315c32a0, 6, -1, 0x10) fd_no=3 called"}<br>"message":" DEBUG: <core> [core\/tcp_read.c:1680]: release_tcpconn(): releasing con 0x7f56979e0ad8, state 1, fd=6, id=6 ([104.175.176.242]:43750 -> [104.175.176.242]:443)"}<br>"message":" DEBUG: <core> [core\/tcp_read.c:1684]: release_tcpconn(): extra_data (nil)"}<br>"message":" DEBUG: <core> [core\/io_wait.h:599]: io_watch_del(): DBG: io_watch_del (0x562f315c32a0, 9, -1, 0x10) fd_no=2 called"}<br>"message":" DEBUG: <core> [core\/tcp_read.c:1680]: release_tcpconn(): releasing con 0x7f56979f0e78, state 1, fd=9, id=7 ([104.175.176.242]:44043 -> [104.175.176.242]:443)"}<br>"message":" DEBUG: <core> [core\/tcp_read.c:1684]: release_tcpconn(): extra_data (nil)"}<br>"message":" DEBUG: <core> [core\/tcp_main.c:3625]: handle_tcp_child(): reader response= 7f56979e0ad8, 1 from 0 "}<br>"message":" DEBUG: <core> [core\/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0x562f31567820, 24, 2, 0x7f56979e0ad8), fd_no=15"}<br>"message":" DEBUG: <core> [core\/tcp_main.c:3752]: handle_tcp_child(): CONN_RELEASE 0x7f56979e0ad8 refcnt= 1"}<br>"message":" DEBUG: <core> [core\/tcp_main.c:3625]: handle_tcp_child(): reader response= 7f56979f0e78, 1 from 0 "}<br>"message":" DEBUG: <core> [core\/io_wait.h:377]: io_watch_add(): DBG: io_watch_add(0x562f31567820, 26, 2, 0x7f56979f0e78), fd_no=16"}<br>"message":" DEBUG: <core> [core\/tcp_main.c:3752]: handle_tcp_child(): CONN_RELEASE 0x7f56979f0e78 refcnt= 1"}<br></div><div><br></div><div>Not sure what I can be doing wrong!</div><div><br></div><div>IP information to help you understand the packet capture:</div><div><br></div><div>UAC: 104.175.176.242</div><div>LB (UAC side): <a href="http://35.186.235.62:443">35.186.235.62:443</a> or <a href="http://sbc01stg.gii.me:443">sbc01stg.gii.me:443</a></div><div>LB (Kam side can be many, for this example it's <a href="http://130.211.3.12:53883">130.211.3.12:53883</a>)</div><div>PSTN GW: 198.1.54.228</div><div><br></div><div>Thanks for your help on this.</div><div><br></div><div>Best, </div><div>Joel.</div></div><br><div class="gmail_quote"><div dir="ltr" class="gmail_attr">On Fri, Nov 22, 2019 at 1:02 AM Daniel-Constantin Mierla <<a href="mailto:miconda@gmail.com">miconda@gmail.com</a>> wrote:<br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">
<div>
<p>Hello,</p>
<p>how do you set the record-route? Do you have advertised address
for the socket receiving TCP/HAproxy loadbalancer connections?</p>
<p>Can you give all the debug messages when processing the BYE that
doesn't go through?</p>
<p>Cheers,<br>
Daniel<br>
</p>
<div>On 21.11.19 19:44, Joel Serrano wrote:<br>
</div>
<blockquote type="cite">
<div dir="ltr">Hi Daniel,
<div><br>
</div>
<div>I sent you (privately) 2 pcaps. Please let me know if you
need anything else.</div>
<div><br>
</div>
<div>My current TCP params are:</div>
<div><br>
</div>
<div>disable_tcp=no<br>
tcp_children=1<br>
tcp_max_connections=12288<br>
tcp_rd_buf_size=65536<br>
tcp_conn_wq_max=131072<br>
tcp_keepalive=yes<br>
tcp_crlf_ping=yes<br>
tcp_keepcnt=3<br>
tcp_keepidle=30<br>
tcp_keepintvl=30<br>
tcp_connection_lifetime=3610<br>
tcp_accept_no_cl=yes<br>
tcp_accept_haproxy=yes<br>
tcp_no_connect=yes<br>
</div>
<div><br>
</div>
<div>Thanks, </div>
<div>Joel.</div>
</div>
<br>
<div class="gmail_quote">
<div dir="ltr" class="gmail_attr">On Thu, Nov 21, 2019 at 7:50
AM Joel Serrano <<a href="mailto:joel@textplus.com" target="_blank">joel@textplus.com</a>> wrote:<br>
</div>
<blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">
<div>
<div dir="auto">I don’t, but I’ll repeat the test with
tcpdump active! I’ll report back shortly</div>
</div>
<div><br>
<div class="gmail_quote">
<div dir="ltr" class="gmail_attr">On Thu, Nov 21, 2019 at
03:50 Daniel-Constantin Mierla <<a href="mailto:miconda@gmail.com" target="_blank">miconda@gmail.com</a>>
wrote:<br>
</div>
<blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">
<div>
<p>Hello,</p>
<p>do you have the pcap with the sip traffic for this
case?</p>
<p>Cheers,<br>
Daniel<br>
</p>
</div>
<div>
<div>On 20.11.19 19:45, Joel Serrano wrote:<br>
</div>
<blockquote type="cite">
<div dir="ltr">Hello,
<div><br>
</div>
<div>I added to the config file:</div>
<div><br>
</div>
<div>tcp_no_connect=yes<br>
</div>
<div><br>
</div>
<div>And with that param, the same test results in
a different behavior, but still not working:</div>
<div><br>
</div>
<div>"message":" DEBUG: {1 12583750 BYE
RVXZVMHKop} <core>
[core\/msg_translator.c:161]:
check_via_address(): (198.1.54.228,
198.1.54.228, 0)"}<br>
<font color="#ff0000">"message":" ERROR: {1
12583750 BYE RVXZVMHKop} tm
[..\/..\/core\/forward.h:292]:
msg_send_buffer(): tcp_send failed"}<br>
"message":" DEBUG: {1 12583750 BYE RVXZVMHKop}
tm [t_fwd.c:1537]: t_send_branch(): send to <a href="http://35.191.9.20:56470" target="_blank">35.191.9.20:56470</a>
(3) failed"}</font><br>
"message":" WARNING: {1 12583750 BYE RVXZVMHKop}
tm [t_fwd.c:1557]: t_send_branch(): sending
request on branch 0 failed"}<br>
"message":" DEBUG: {1 12583750 BYE RVXZVMHKop}
tm [t_funcs.c:336]: t_relay_to():
t_forward_nonack returned error -1 (-477)"}<br>
"message":" DEBUG: {1 12583750 BYE RVXZVMHKop}
tm [t_funcs.c:354]: t_relay_to(): -477 error
reply generation delayed "}<br>
</div>
<div><br>
</div>
<div>Although, netstats says the connection is
active:</div>
<div><br>
</div>
<div>root@sbc-gslb-test-1:~# netstat -putan | grep
56470<br>
tcp 0 0 <a href="http://10.116.15.237:443" target="_blank">10.116.15.237:443</a>
<a href="http://35.191.9.20:56470" target="_blank">35.191.9.20:56470</a>
ESTABLISHED 3920/kamailio<br>
root@sbc-gslb-test-1:~#<br>
</div>
<div><br>
</div>
<div><br>
</div>
<div>Anyone?</div>
</div>
<br>
<div class="gmail_quote">
<div dir="ltr" class="gmail_attr">On Wed, Nov 20,
2019 at 9:26 AM Joel Serrano <<a href="mailto:joel@textplus.com" target="_blank">joel@textplus.com</a>>
wrote:<br>
</div>
<blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">
<div dir="ltr">Bumping this thread up!
<div><br>
</div>
<div>I did some more tests trying to narrow
down the problem and this is what I
found...:</div>
<div><br>
</div>
<div>On the INVITE, I add the TCP connection
information I want to save (for later
reuse). Snippets:</div>
<div><br>
</div>
<div>...(found this in
the misc/examples/pkg/sip-router-oob.cfg,
but I haven't noticed any changes to the
headers or anything)...</div>
<div><br>
</div>
<div> # Force response to received
connection<br>
force_rport();<br>
if (proto==TCP || proto == TLS) {<br>
force_tcp_alias();<br>
xlog("L_NOTICE", "force_tcp_alias()
done");<br>
}<br>
</div>
<div>...</div>
<div><br>
</div>
<div>...(I also have this)...</div>
<div><br>
</div>
<div> if (is_first_hop()) {<br>
xlog("L_NOTICE", "Adding LB info to
contact - M=$rm ID=$ci\n");<br>
add_contact_alias("$tcp(c_si)",
"$tcp(c_sp)", "tls");<br>
}<br>
</div>
<div>...</div>
<div><br>
</div>
<div>Which effectively makes the contact look
like:</div>
<div><br>
</div>
<div><a><sip:linphone@104.175.176.242:50312;alias=35.191.9.21~50705~3;transport=tls></a><br>
</div>
<div><br>
</div>
<div>..180..</div>
<div>..200 OK..</div>
<div>..ACK..</div>
<div><br>
</div>
<div>Then, callee ends the call (so the
BYE comes from callee to caller), when I run
handle_ruri_alias() I see in the logs that
the everything is handled correctly:</div>
<div><br>
</div>
<div>"message":" DEBUG: {1 12543376 BYE
QQy-qagkcB} nathelper [nathelper.c:1144]:
handle_ruri_alias(): setting dst_uri to <a><sip:35.191.9.21:50705;transport=tls></a>"}<br>
"message":" DEBUG: {1 12543376 BYE
QQy-qagkcB} nathelper [nathelper.c:1166]:
handle_ruri_alias(): rewriting r-uri to <a><sip:linphone@104.175.176.242:50312;transport=tls></a>"}</div>
<div><br>
</div>
<div>But then, Kamalio won't reuse the
existing TCP connection and tries to create
a new one:</div>
<div><br>
"message":" DEBUG: {1 12543376 BYE
QQy-qagkcB} tm [t_lookup.c:1328]:
t_newtran(): msg (0x7f85883b14c8)
id=27\/1974 global id=25\/1974 T
start=0xffffffffffffffff"}<br>
"message":" DEBUG: {1 12543376 BYE
QQy-qagkcB} tm [t_lookup.c:497]:
t_lookup_request(): start searching:
hash=63128, isACK=0"}<br>
"message":" DEBUG: {1 12543376 BYE
QQy-qagkcB} tm [t_lookup.c:455]:
matching_3261(): RFC3261 transaction
matching failed - via branch
[z9hG4bK896f.dc04734743b0f0997f39c4fff07c0fbb.0]"}<br>
"message":" DEBUG: {1 12543376 BYE
QQy-qagkcB} tm [t_lookup.c:675]:
t_lookup_request(): no transaction found"}<br>
"message":" DEBUG: {1 12543376 BYE
QQy-qagkcB} tm [t_hooks.c:336]:
run_reqin_callbacks_internal():
trans=0x7f8583b17208, callback type 1, id 0
entered"}<br>
"message":" DEBUG: {1 12543376 BYE
QQy-qagkcB} <core>
[core\/crypto\/md5utils.c:67]:
MD5StringArray(): MD5 calculated:
71c229aff3c0b4f6e9e77c4990b74e5e"}<br>
"message":" DEBUG: {1 12543376 BYE
QQy-qagkcB} siputils [checks.c:123]:
has_totag(): totag found"}<br>
"message":" DEBUG: {1 12543376 BYE
QQy-qagkcB} rr [loose.c:1095]:
check_route_param(): route params checking
against
[;r2=on;lr=on;ftag=tAsjXhyIX;did=7d1.e6a2;nat=yes]
(orig:
[r2=on;lr=on;ftag=tAsjXhyIX;did=7d1.e6a2;nat=yes])"}<br>
"message":" DEBUG: {1 12543376 BYE
QQy-qagkcB} rr [loose.c:1101]:
check_route_param(): params are
<;r2=on;lr=on;ftag=tAsjXhyIX;did=7d1.e6a2;nat=yes>"}<br>
"message":" DEBUG: {1 12543376 BYE
QQy-qagkcB} siputils [checks.c:123]:
has_totag(): totag found"}<br>
"message":" DEBUG: {1 12543376 BYE
QQy-qagkcB} <core>
[core\/msg_translator.c:161]:
check_via_address(): (198.1.54.228,
198.1.54.228, 0)"}<br>
<font color="#ff0000">"message":" DEBUG: {1
12543376 BYE QQy-qagkcB} <core>
[core\/tcp_main.c:2060]: tcp_send(): no
open tcp connection found, opening new
one"}<br>
"message":" DEBUG: {1 12543376 BYE
QQy-qagkcB} <core>
[core\/ip_addr.c:229]: print_ip():
tcpconn_new: new tcp connection:
35.191.9.21"}<br>
"message":" DEBUG: {1 12543376 BYE
QQy-qagkcB} <core>
[core\/tcp_main.c:1242]: tcpconn_new(): on
port 50705, type 3"}</font><br>
"message":" DEBUG: {1 12543376 BYE
QQy-qagkcB} <core>
[core\/tcp_main.c:1561]: tcpconn_add():
hashes: 337:3545:0, 3"}<br>
</div>
<div><br>
</div>
<div>Am I still missing anything?</div>
<div><br>
</div>
<div>Is this a bug and I should open a GH
issue?</div>
<div><br>
</div>
<div>Any suggestions/comments/ideas are very
welcome!</div>
<div><br>
</div>
<div>Thanks, </div>
<div>Joel.</div>
<div><br>
</div>
</div>
<br>
<div class="gmail_quote">
<div dir="ltr" class="gmail_attr">On Fri, Nov
1, 2019 at 11:46 AM Joel Serrano <<a href="mailto:joel@textplus.com" target="_blank">joel@textplus.com</a>>
wrote:<br>
</div>
<blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">
<div dir="ltr">Hi Yuriy,
<div><br>
</div>
<div>Thanks for your suggestion, I've
tried tcp_accept_aliases=yes in config
and I added force_tcp_alias() in the
request route, but I haven't seen any
changes.</div>
<div><br>
</div>
<div>All the VIA headers look exactly the
same, and I still get this in the logs:</div>
<div><br>
</div>
<div>"message":" DEBUG: {1 11762916 BYE
d2T9-YOxYk} <core>
[core\/tcp_main.c:2060]: tcp_send(): no
open tcp connection found, opening new
one"}<br>
</div>
<div><br>
</div>
<div><br>
</div>
<div>The docs say: </div>
<div><br>
</div>
<div>"f<span style="color:rgb(51,51,51);font-family:Arial,sans-serif;font-size:14px">orce_tcp_alias(port)</span></div>
<p style="margin:0px 0px 1.4em;padding:0px;color:rgb(51,51,51);font-family:Arial,sans-serif;font-size:14px">adds
a tcp port alias for the current
connection (if tcp). Useful if you want
to send all the trafic to port_alias
through the same connection this request
came from [it could help for firewall or
nat traversal]. With no parameters adds
the port from the message via as the
alias. When the “aliased” connection is
closed (e.g. it's idle for too much
time), all the port aliases are
removed."</p>
<p style="margin:0px 0px 1.4em;padding:0px;color:rgb(51,51,51);font-family:Arial,sans-serif;font-size:14px">I
tried also using force_tcp_alias(5353)
as an example, just to see if I find
"5353" added to any headers, but no
luck, it wasn't added anywhere..</p>
<p style="margin:0px 0px 1.4em;padding:0px;color:rgb(51,51,51);font-family:Arial,sans-serif;font-size:14px"><br>
</p>
<p style="margin:0px 0px 1.4em;padding:0px;color:rgb(51,51,51);font-family:Arial,sans-serif;font-size:14px">Any
other suggestions? Am I missing
something?</p>
<p style="margin:0px 0px 1.4em;padding:0px;color:rgb(51,51,51);font-family:Arial,sans-serif;font-size:14px"><br>
</p>
<p style="margin:0px 0px 1.4em;padding:0px;color:rgb(51,51,51);font-family:Arial,sans-serif;font-size:14px">Thanks, </p>
<p style="margin:0px 0px 1.4em;padding:0px;color:rgb(51,51,51);font-family:Arial,sans-serif;font-size:14px">Joel.</p>
</div>
<br>
<div class="gmail_quote">
<div dir="ltr" class="gmail_attr">On Thu,
Oct 31, 2019 at 10:53 PM Yuriy
Gorlichenko <<a href="mailto:ovoshlook@gmail.com" target="_blank">ovoshlook@gmail.com</a>>
wrote:<br>
</div>
<blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">
<div dir="auto">You have to use
<div dir="auto">tcp_accept_aliases=yes</div>
<div dir="auto">But this is not enough
as this param will be triggered by
function</div>
<div dir="auto">force_tcp_alias() you
need to use in the route for request
( for example record_route or
subroutes) </div>
<div dir="auto">It will add param
paramname=<portnum> (I Don't
remember specific name) </div>
<div dir="auto">to Via header that
will be used for all dialog requests
belongs one being affected</div>
<div dir="auto"><br>
</div>
</div>
<br>
<div class="gmail_quote">
<div dir="ltr" class="gmail_attr">On
Fri, 1 Nov 2019, 00:52 Joel Serrano,
<<a href="mailto:joel@textplus.com" rel="noreferrer" target="_blank">joel@textplus.com</a>>
wrote:<br>
</div>
<blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">
<div dir="ltr">Hello, <br>
<div><br>
</div>
<div>I'm setting up a Kamailio
instance behind a TCP load
balancer (with proxy protocol
and NAT routing: meaning Kam
stays in the flow all the time).</div>
<div><br>
</div>
<div>I've managed to get working
almost everything we need for
our service, except for one
thing, and that is for Kam to
use existing connections for
subsequent transactions:</div>
<div><br>
</div>
<div>Following this example:</div>
<div><br>
</div>
<div>
<div><br>
</div>
<div>
<div><img src="https://mail.google.com/mail/?ui=2&ik=4cb8059f98&attid=0.1&th=16e257fd109e4e49&view=fimg&rm=16e257fd109e4e49&sz=w1600-h1000&attbid=ANGjdJ-91VHFzKV4hniupoRVBXwam-q5S4OzAdN4gy3xbdsMj4mq4jMHzqZAiNWCoW81L4r2mg7JSPiju8xWuIJzzKXfQ4TM-pAK-XcezfHICxM9RjHRbirzKBr1mdM&disp=emb&realattid=ii_k2fbh1u00&zw" alt="image.png" width="542" height="270"></div>
</div>
</div>
<div><br>
</div>
<div><br>
</div>
<div>EXT & INT represent the
external and internal interface
of a LB between the UAC and
Kamailio, using TLS on both legs
and proxy protocol.</div>
<div><br>
</div>
<div>Transaction 1: INVITE, 100,
180, 183, 200 OK</div>
<div><br>
</div>
<div>UAC <a href="http://1.1.1.1:1111" rel="noreferrer noreferrer" target="_blank">1.1.1.1:1111</a>
-> <a href="http://2.2.2.2:443" rel="noreferrer noreferrer" target="_blank">2.2.2.2:443</a>
(EXT) <a href="http://3.3.3.3:3333" rel="noreferrer noreferrer" target="_blank">3.3.3.3:3333</a>
(INT) -> <a href="http://7.7.7.7:5060" rel="noreferrer noreferrer" target="_blank">7.7.7.7:5060</a>
(Kamailio) </div>
<div><br>
</div>
<div>Transaction 2: ACK</div>
<div><br>
</div>
<div>
<div>UAC <a href="http://1.1.1.1:1112" rel="noreferrer noreferrer" target="_blank">1.1.1.1:1112</a>
-> <a href="http://2.2.2.2:443" rel="noreferrer noreferrer" target="_blank">2.2.2.2:443</a>
(EXT) <a href="http://4.4.4.4:4444" rel="noreferrer noreferrer" target="_blank">4.4.4.4:4444</a>
(INT) -> <a href="http://7.7.7.7:5060" rel="noreferrer noreferrer" target="_blank">7.7.7.7:5060</a>
(Kamailio) </div>
</div>
<div><br>
</div>
<div>Transaction 3: BYE</div>
<div><br>
</div>
<div>Kam <a href="http://7.7.7.7:5060" rel="noreferrer noreferrer" target="_blank">7.7.7.7:5060</a>
-> <a href="http://3.3.3.3:3333" rel="noreferrer noreferrer" target="_blank">3.3.3.3:3333</a>
(INT) <a href="http://2.2.2.2:443" rel="noreferrer noreferrer" target="_blank">2.2.2.2:443</a>
(EXT) -> <a href="http://1.1.1.1:1111" rel="noreferrer noreferrer" target="_blank">1.1.1.1:1111</a>
UAC</div>
<div><br>
</div>
<div>
<div><br>
</div>
</div>
<div><br>
</div>
<div>My problem is with
Transaction 3. In this case the
BYE is originated by the callee,
and Kam has to send it to the
caller. As the TCP load balancer
is between Kam and the UAC, Kam
has to send it to the LB so then
the LB can forward it back to
the UAC. This works well for
msgs that belong to the same
transaction (INVITE, 100, 180,
183, 200 OK) but it fails when
they don't belong to the same
transaction.</div>
<div><br>
</div>
<div>Thanks to the newly added
$tcp(c_si) and $tcp(c_sp)
pseudovars, I can save the
internal IP:Port of the LB, so I
can send stuff later to it, my
problem is that Kam doesn't seem
to allow this?</div>
<div><br>
</div>
<div>On the original INVITE, I use
the following to save where I
have to reach the UAC:</div>
<div><br>
</div>
<div>add_contact_alias("$tcp(c_si)",
"$tcp(c_sp)", "tls");<br>
</div>
<div><br>
</div>
<div>Then, handle_ruri_alias()
will take care of setting $du to
the correct (internal LB)
IP:Port so I can reach the UAC,
this works.</div>
<div><br>
</div>
<div>My problem is that Kamailio
doesn't identify that there is a
valid existing TLS connection
still up (from the INVITE), and
tries to create a new one (and
this obviously doesn't gives all
sorts of problems).</div>
<div><br>
</div>
<div>So when I run
handle_ruri_alias(), and $du is
set to <a href="http://3.3.3.3:3333" rel="noreferrer noreferrer" target="_blank">3.3.3.3:3333</a>
(from the example above),
instead of using the existing
connection, Kamailio tries to
create a new one.</div>
<div><br>
</div>
<div>I have a log statement right
before with the result of
tcp_conid_state(1) (the connid
is 1 for this connection) and
the $rc is 1 (Connection is OK),
but when I tell Kamailio it has
to use it I get this in the
logs:</div>
<div><br>
</div>
<div>DEBUG: {1 11726467 BYE
gqR1qqNK8B} <core>
[core\/tcp_main.c:2060]:
tcp_send(): no open tcp
connection found, opening new
one"}<br>
</div>
<div><br>
</div>
<div>And then the problems
begin...</div>
<div><br>
</div>
<div><br>
</div>
<div>I have tried playing around
with:</div>
<div><br>
</div>
<div>tcp_reuse_port<br>
</div>
<div>tcp_connection_match</div>
<div><br>
</div>
<div>But no luck..!</div>
<div><br>
</div>
<div>I also thought it could be a
problem of the connection being
created on one worker, and a
different worker handling BYE
transaction, so tested with
children=1 and tcp_children=1,
but still same problem.</div>
<div><br>
</div>
<div>A more detailed log:</div>
<div><br>
</div>
<div>In blue my log statement
checking for the status of conid
"1", in red Kam not being able
to find it, although it exists
(as validated
by tcp_conid_state(), and even
in netstat I can see the
connection established). In this
log, <a href="http://35.191.0.66:60271" rel="noreferrer noreferrer" target="_blank">35.191.0.66:60271</a>
would be the equivalent of <a href="http://3.3.3.3:3333" rel="noreferrer noreferrer" target="_blank">3.3.3.3:3333</a>
and <a href="http://104.175.176.242:28157" rel="noreferrer noreferrer" target="_blank">104.175.176.242:28157</a>
would be <a href="http://1.1.1.1:1111" rel="noreferrer noreferrer" target="_blank">1.1.1.1:1111</a>
from the example above.</div>
<div><br>
</div>
<div>...<br>
<font color="#0000ff">"message":"
DEBUG: {1 11727734 BYE
5-LX4GdI9X} <core>
[core\/tcp_main.c:1657]:
_tcpconn_find(): found
connection by id: 1"}<br>
"message":" NOTICE: {1
11727734 BYE 5-LX4GdI9X}
<script>: JOEL TEST New
request - M=BYE TCP STATUS:1
ID=5-LX4GdI9X"}</font><br>
...<br>
"message":" DEBUG: {1 11727734
BYE 5-LX4GdI9X} nathelper
[nathelper.c:1144]:
handle_ruri_alias(): setting
dst_uri to <a><sip:35.191.0.66:60271;transport=tls></a>"}<br>
"message":" DEBUG: {1 11727734
BYE 5-LX4GdI9X} nathelper
[nathelper.c:1166]:
handle_ruri_alias(): rewriting
r-uri to <a><sip:linphone@104.175.176.242:28157;transport=tls></a>"}<br>
"message":" DEBUG: {1 11727734
BYE 5-LX4GdI9X} tm
[t_lookup.c:1328]: t_newtran():
msg (0x7f3c884259d0)
id=534\/18664 global
id=532\/18664 T
start=0xffffffffffffffff"}<br>
"message":" DEBUG: {1 11727734
BYE 5-LX4GdI9X} tm
[t_lookup.c:497]:
t_lookup_request(): start
searching: hash=63496, isACK=0"}<br>
"message":" DEBUG: {1 11727734
BYE 5-LX4GdI9X} tm
[t_lookup.c:455]:
matching_3261(): RFC3261
transaction matching failed -
via branch
[z9hG4bK808f.eee2444f92a02cb33e1b7a21f20bc6bb.0]"}<br>
"message":" DEBUG: {1 11727734
BYE 5-LX4GdI9X} tm
[t_lookup.c:675]:
t_lookup_request(): no
transaction found"}<br>
"message":" DEBUG: {1 11727734
BYE 5-LX4GdI9X} tm
[t_hooks.c:336]:
run_reqin_callbacks_internal():
trans=0x7f3c83b8c598, callback
type 1, id 0 entered"}<br>
"message":" DEBUG: {1 11727734
BYE 5-LX4GdI9X} <core>
[core\/crypto\/md5utils.c:67]:
MD5StringArray(): MD5
calculated:
3071029feb05962b26b53a9664a14210"}<br>
"message":" DEBUG: {1 11727734
BYE 5-LX4GdI9X} siputils
[checks.c:123]: has_totag():
totag found"}<br>
"message":" DEBUG: {1 11727734
BYE 5-LX4GdI9X} rr
[loose.c:1095]:
check_route_param(): route
params checking against
[;r2=on;lr=on;ftag=Eb~TbdfTA;did=cab.01e2;nat=yes]
(orig:
[r2=on;lr=on;ftag=Eb~TbdfTA;did=cab.01e2;nat=yes])"}<br>
"message":" DEBUG: {1 11727734
BYE 5-LX4GdI9X} rr
[loose.c:1101]:
check_route_param(): params are
<;r2=on;lr=on;ftag=Eb~TbdfTA;did=cab.01e2;nat=yes>"}<br>
"message":" DEBUG: {1 11727734
BYE 5-LX4GdI9X} siputils
[checks.c:123]: has_totag():
totag found"}<br>
"message":" DEBUG: {1 11727734
BYE 5-LX4GdI9X} <core>
[core\/msg_translator.c:161]:
check_via_address():
(198.1.54.228, 198.1.54.228,
0)"}<br>
<font color="#ff0000">"message":"
DEBUG: {1 11727734 BYE
5-LX4GdI9X} <core>
[core\/tcp_main.c:2060]:
tcp_send(): no open tcp
connection found, opening new
one"}<br>
</font>"message":" DEBUG: {1
11727734 BYE 5-LX4GdI9X}
<core>
[core\/ip_addr.c:229]:
print_ip(): tcpconn_new: new tcp
connection: 35.191.0.66"}<br>
"message":" DEBUG: {1 11727734
BYE 5-LX4GdI9X} <core>
[core\/tcp_main.c:1242]:
tcpconn_new(): on port 60271,
type 3"}<br>
"message":" DEBUG: {1 11727734
BYE 5-LX4GdI9X} <core>
[core\/tcp_main.c:1561]:
tcpconn_add(): hashes:
1446:2350:0, 5"}<br>
"message":" DEBUG: {1 11727734
BYE 5-LX4GdI9X} tls
[tls_server.c:199]:
tls_complete_init(): completing
tls connection initialization"}<br>
...<br>
</div>
<div><br>
</div>
<div><br>
</div>
<div>So time to seek help from the
community, any
suggestions/ideas/comments?
Sorry if all this sounds
confusing, I've tried my best to
put in text the whole scenario
in and "understandable" way... </div>
<div><br>
</div>
<div>Is this even doable?</div>
<div><br>
</div>
<div>Thanks, </div>
<div>Joel.</div>
<div><br>
</div>
<div><br>
</div>
<div><br>
</div>
<div><br>
</div>
<div><br>
</div>
<div><br>
</div>
<div><br>
</div>
</div>
_______________________________________________<br>
Kamailio (SER) - Users Mailing List<br>
<a href="mailto:sr-users@lists.kamailio.org" rel="noreferrer noreferrer" target="_blank">sr-users@lists.kamailio.org</a><br>
<a href="https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users" rel="noreferrer noreferrer
noreferrer" target="_blank">https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users</a><br>
</blockquote>
</div>
_______________________________________________<br>
Kamailio (SER) - Users Mailing List<br>
<a href="mailto:sr-users@lists.kamailio.org" target="_blank">sr-users@lists.kamailio.org</a><br>
<a href="https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users" rel="noreferrer" target="_blank">https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users</a><br>
</blockquote>
</div>
</blockquote>
</div>
</blockquote>
</div>
<br>
<fieldset></fieldset>
<pre>_______________________________________________
Kamailio (SER) - Users Mailing List
<a href="mailto:sr-users@lists.kamailio.org" target="_blank">sr-users@lists.kamailio.org</a>
<a href="https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users" target="_blank">https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users</a>
</pre>
</blockquote>
<pre cols="72">--
Daniel-Constantin Mierla -- <a href="http://www.asipto.com" target="_blank">www.asipto.com</a>
<a href="http://www.twitter.com/miconda" target="_blank">www.twitter.com/miconda</a> -- <a href="http://www.linkedin.com/in/miconda" target="_blank">www.linkedin.com/in/miconda</a>
Kamailio World Conference - April 27-29, 2020, in Berlin -- <a href="http://www.kamailioworld.com" target="_blank">www.kamailioworld.com</a></pre>
</div>
</blockquote>
</div>
</div>
</blockquote>
</div>
</blockquote>
<pre cols="72">--
Daniel-Constantin Mierla -- <a href="http://www.asipto.com" target="_blank">www.asipto.com</a>
<a href="http://www.twitter.com/miconda" target="_blank">www.twitter.com/miconda</a> -- <a href="http://www.linkedin.com/in/miconda" target="_blank">www.linkedin.com/in/miconda</a>
Kamailio World Conference - April 27-29, 2020, in Berlin -- <a href="http://www.kamailioworld.com" target="_blank">www.kamailioworld.com</a></pre>
</div>
</blockquote></div>