[SR-Users] Re-use TCP connections on different transactions

Joel Serrano joel at textplus.com
Fri Nov 22 19:25:48 CET 2019


Hi Daniel,

I have advertise as:

listen=tcp:10.116.15.237:443 advertise sbc01.stg.gii.me:443

(normally it would be tls, I switched to tcp so I could get unencrypted
traffic in tcpdump for you)

Record-route is done as:

    # Dispatch requests
    if (is_method("INVITE")) {
        $avp(caller_conid) = $conid;
        record_route();
        route(DISPATCH);
        exit;
    }

(route DISPATCH basically does dispatcher lookup and t_relay)

And this is the log for the BYE that doesn't work:

"message":" DEBUG: <core> [core\/udp_server.c:498]: udp_rcv_loop():
received on udp socket: (106\/100\/907) [[BYE
sip:linphone at 104.175.176.242:43750;alias=130.211.3.12~53883~2;transport=tcp
SIP\/2.0 0D  0A Via: SIP\/2.]]"}
"message":" DEBUG: <core> [core\/parser\/msg_parser.c:610]: parse_msg():
SIP Request:"}
"message":" DEBUG: <core> [core\/parser\/msg_parser.c:612]: parse_msg():
 method:  <BYE>"}
"message":" DEBUG: <core> [core\/parser\/msg_parser.c:614]: parse_msg():
 uri:     <sip:linphone at 104.175.176.242:43750
;alias=130.211.3.12~53883~2;transport=tcp>"}
"message":" DEBUG: <core> [core\/parser\/msg_parser.c:616]: parse_msg():
 version: <SIP\/2.0>"}
"message":" DEBUG: <core> [core\/parser\/parse_via.c:1303]:
parse_via_param(): Found param type 232, <branch> =
<z9hG4bK4eda.30b29b519ea0cbd688ceb8071e271f7d.0>; state=16"}
"message":" DEBUG: <core> [core\/parser\/parse_via.c:2639]: parse_via():
end of header reached, state=5"}
"message":" DEBUG: <core> [core\/parser\/msg_parser.c:498]:
parse_headers(): Via found, flags=2"}
"message":" DEBUG: <core> [core\/parser\/msg_parser.c:500]:
parse_headers(): this is the first via"}
"message":" DEBUG: <core> [core\/parser\/parse_via.c:1303]:
parse_via_param(): Found param type 234, <received> = <35.226.32.33>;
state=6"}
"message":" DEBUG: <core> [core\/parser\/parse_via.c:1303]:
parse_via_param(): Found param type 235, <rport> = <6061>; state=6"}
"message":" DEBUG: <core> [core\/parser\/parse_via.c:1303]:
parse_via_param(): Found param type 232, <branch> = <z9hG4bKy0gFgvHcajHtm>;
state=16"}
"message":" DEBUG: <core> [core\/parser\/parse_via.c:2639]: parse_via():
end of header reached, state=5"}
"message":" DEBUG: <core> [core\/parser\/msg_parser.c:498]:
parse_headers(): Via found, flags=78"}
"message":" DEBUG: <core> [core\/parser\/msg_parser.c:511]:
parse_headers(): this is the second via"}
"message":" DEBUG: <core> [core\/parser\/parse_addr_spec.c:185]:
parse_to_param(): add param: tag=DU0ehPULu"}
"message":" DEBUG: <core> [core\/parser\/parse_addr_spec.c:864]:
parse_addr_spec(): end of header reached, state=29"}
"message":" DEBUG: <core> [core\/parser\/msg_parser.c:171]:
get_hdr_field(): <To> [82]; uri=[
sip:8bd2a0aba14541789bb7269800646458 at app.nextplus.me]"}
"message":" DEBUG: <core> [core\/parser\/msg_parser.c:174]:
get_hdr_field(): to body [\"Joel Test\" <
sip:8bd2a0aba14541789bb7269800646458 at app.nextplus.me>], to tag [DU0ehPULu]"}
"message":" DEBUG: <core> [core\/parser\/msg_parser.c:152]:
get_hdr_field(): cseq <CSeq>: <12626897> <BYE>"}
"message":" DEBUG: <core> [core\/receive.c:320]: receive_msg(): ---
received sip message - request - call-id: [nsWZzKWRld] - cseq: [12626897
BYE]"}
"message":" DEBUG: <core> [core\/parser\/msg_parser.c:185]:
get_hdr_field(): content_length=0"}
"message":" DEBUG: <core> [core\/parser\/msg_parser.c:89]: get_hdr_field():
found end of header"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core>
[core\/receive.c:380]: receive_msg(): preparing to run routing scripts..."}
"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]"}
"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]"}
"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]"}
"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]"}
"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] == [sbc01.stg.gii.me]"}
"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]"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core>
[core\/forward.c:413]: check_self(): host != me"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} maxfwd [mf_funcs.c:74]:
is_maxfwd_present(): value = 69 "}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity.c:247]:
check_ruri_sip_version(): check_ruri_sip_version entered"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity.c:270]:
check_ruri_sip_version(): check_ruri_sip_version passed"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity.c:277]:
check_ruri_scheme(): check_ruri_scheme entered"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity.c:297]:
check_ruri_scheme(): check_ruri_scheme passed"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity.c:305]:
check_required_headers(): check_required_headers entered"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity.c:313]:
check_required_headers(): check_required_headers passed"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity.c:479]:
check_cseq_method(): check_cseq_method entered"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity.c:512]:
check_cseq_method(): check_cseq_method passed"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity.c:521]:
check_cseq_value(): check_cseq_value entered"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity.c:549]:
check_cseq_value(): check_cseq_value passed"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity.c:558]:
check_cl(): check_cl entered"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity.c:583]:
check_cl(): check_cl passed"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity.c:595]:
check_expires_value(): check_expires_value entered"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity.c:632]:
check_expires_value(): no expires header found"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity.c:732]:
check_parse_uris(): check_parse_uris entered"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity.c:736]:
check_parse_uris(): parsing ruri"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity.c:750]:
check_parse_uris(): looking up From header"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity.c:764]:
check_parse_uris(): parsing From header"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core>
[core\/parser\/parse_addr_spec.c:185]: parse_to_param(): add param:
tag=QZQSQQegvc5Zr"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core>
[core\/parser\/parse_addr_spec.c:864]: parse_addr_spec(): end of header
reached, state=29"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity.c:790]:
check_parse_uris(): parsing From URI"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity.c:808]:
check_parse_uris(): looking up To header"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity.c:830]:
check_parse_uris(): check_parse_uris(): parsing To URI"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity.c:875]:
check_parse_uris(): check_parse_uris passed"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} sanity [sanity_mod.c:254]:
w_sanity_check(): sanity checks result: 1"}
"message":" NOTICE: {1 12626897 BYE nsWZzKWRld} <script>: JOEL TEST New
request - M=BYE UAC-IP=198.1.54.228:5060 LB-IP=<null>:<null> CONID=<null>
TCP-CONID=<null> UA='FS textPlus Voice' ID=nsWZzKWRld"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core>
[core\/msg_translator.c:161]: check_via_address(): (198.1.54.228,
198.1.54.228, 0)"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} siputils [checks.c:123]:
has_totag(): totag found"}
"message":" NOTICE: {1 12626897 BYE nsWZzKWRld} <script>: In-dialog request
from COPS - M=BYE
R=sip:linphone at 104.175.176.242:43750;alias=130.211.3.12~53883~2;transport=tcp
ID=nsWZzKWRld"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} rr [loose.c:90]:
is_preloaded(): is_preloaded: No"}
"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]"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core>
[core\/socket_info.c:635]: grep_sock_info(): checking if port 5070
(advertise 5070) matches port 43750"}
"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]"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core>
[core\/socket_info.c:635]: grep_sock_info(): checking if port 5080
(advertise 0) matches port 43750"}
"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]"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core>
[core\/socket_info.c:635]: grep_sock_info(): checking if port 443
(advertise 443) matches port 43750"}
"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]"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core>
[core\/socket_info.c:635]: grep_sock_info(): checking if port 80 (advertise
0) matches port 43750"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core>
[core\/forward.c:413]: check_self(): host != me"}
"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]"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core>
[core\/socket_info.c:635]: grep_sock_info(): checking if port 5070
(advertise 5070) matches port 5070"}
"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]"}
"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"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core>
[core\/socket_info.c:628]: grep_sock_info(): checking if host==us: 16==13
&& [sbc01.stg.gii.me] == [10.116.15.237]"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core>
[core\/socket_info.c:635]: grep_sock_info(): checking if port 443
(advertise 443) matches port 443"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core>
[core\/socket_info.c:646]: grep_sock_info(): checking advertise if
host==us: 16==16 && [sbc01.stg.gii.me] == [sbc01.stg.gii.me]"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core>
[core\/parser\/msg_parser.c:89]: get_hdr_field(): found end of header"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} rr [loose.c:181]:
find_next_route(): No next Route HF found"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} rr [loose.c:875]:
after_loose(): no next URI found"}
"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>"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} dialog
[dlg_handlers.c:1306]: dlg_onroute(): route param is 'bfc.e45' (len=7)"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} dialog [dlg_hash.c:784]:
dlg_lookup(): ref dlg 0x7f56979d4660 with 1 -> 3"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} dialog [dlg_hash.c:786]:
dlg_lookup(): dialog id=1358 found on entry 3323"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} dialog [dlg_profile.c:536]:
set_current_dialog(): setting current dialog [3323:1358]"}
"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)"}
"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"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} dialog [dlg_hash.c:1013]:
dlg_ref_helper(): ref dlg 0x7f56979d4660 with 1 -> 4"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} dialog
[dlg_handlers.c:1441]: dlg_onroute(): BYE successfully processed"}
"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"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} dialog [dlg_hash.c:1033]:
dlg_unref_helper(): unref dlg 0x7f56979d4660 with 2 -> 2"}
"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"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} dialog [dlg_hash.c:1033]:
dlg_unref_helper(): unref dlg 0x7f56979d4660 with 1 -> 1"}
"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>"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} nathelper
[nathelper.c:1166]: handle_ruri_alias(): rewriting r-uri to
<sip:linphone at 104.175.176.242:43750;transport=tcp>"}
"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"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} tm [t_lookup.c:497]:
t_lookup_request(): start searching: hash=44516, isACK=0"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} tm [t_lookup.c:455]:
matching_3261(): RFC3261 transaction matching failed - via branch
[z9hG4bK4eda.30b29b519ea0cbd688ceb8071e271f7d.0]"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} tm [t_lookup.c:675]:
t_lookup_request(): no transaction found"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} tm [t_hooks.c:336]:
run_reqin_callbacks_internal(): trans=0x7f56979d6558, callback type 1, id 0
entered"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core>
[core\/crypto\/md5utils.c:67]: MD5StringArray(): MD5 calculated:
7fe00a28920a3325330971908f8c5b0e"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} siputils [checks.c:123]:
has_totag(): totag found"}
"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])"}
"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>"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} siputils [checks.c:123]:
has_totag(): totag found"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core>
[core\/msg_translator.c:161]: check_via_address(): (198.1.54.228,
198.1.54.228, 0)"}
"message":" ERROR: {1 12626897 BYE nsWZzKWRld} tm
[..\/..\/core\/forward.h:261]: msg_send_buffer(): tcp_send failed"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} tm [t_fwd.c:1537]:
t_send_branch(): send to 130.211.3.12:53883 (2) failed"}
"message":" WARNING: {1 12626897 BYE nsWZzKWRld} tm [t_fwd.c:1557]:
t_send_branch(): sending request on branch 0 failed"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} tm [t_funcs.c:336]:
t_relay_to(): t_forward_nonack returned error -1 (-477)"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} tm [t_funcs.c:354]:
t_relay_to(): -477 error reply generation delayed "}
"message":" ERROR: {1 12626897 BYE nsWZzKWRld} <script>: Could not forward
request - M=BYE R=sip:linphone at 104.175.176.242:43750;transport=tcp
ID=nsWZzKWRld"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core>
[core\/msg_translator.c:161]: check_via_address(): (198.1.54.228,
198.1.54.228, 0)"}
"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)"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core>
[core\/receive.c:438]: receive_msg(): request-route executed in: 1051 usec"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} dialog [dlg_hash.c:784]:
dlg_lookup(): ref dlg 0x7f56979d4660 with 1 -> 2"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} dialog [dlg_hash.c:786]:
dlg_lookup(): dialog id=1358 found on entry 3323"}
"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"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} dialog [dlg_hash.c:1033]:
dlg_unref_helper(): unref dlg 0x7f56979d4660 with 1 -> 1"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} tm [t_lookup.c:1493]:
t_unref(): delayed error reply generation(-477)"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core>
[core\/msg_translator.c:161]: check_via_address(): (198.1.54.228,
198.1.54.228, 0)"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} tm [t_reply.c:1667]:
cleanup_uac_timers(): RETR\/FR timers reset"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} tm [t_hooks.c:252]:
run_trans_callbacks_internal(): DBG: trans=0x7f56979d6558, callback type
512, id 0 entered"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} dialog [dlg_hash.c:784]:
dlg_lookup(): ref dlg 0x7f56979d4660 with 1 -> 2"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} dialog [dlg_hash.c:786]:
dlg_lookup(): dialog id=1358 found on entry 3323"}
"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"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} dialog [dlg_hash.c:1033]:
dlg_unref_helper(): unref dlg 0x7f56979d4660 with 1 -> 1"}
"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"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} tm [t_reply.c:621]:
_reply_light(): finished"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core>
[core\/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core>
[core\/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core>
[core\/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core>
[core\/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core>
[core\/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core>
[core\/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core> [core\/xavp.c:517]:
xavp_destroy_list(): destroying xavp list (nil)"}
"message":" DEBUG: {1 12626897 BYE nsWZzKWRld} <core>
[core\/receive.c:529]: receive_msg(): cleaning up"}
"message":" DEBUG: <core> [core\/io_wait.h:599]: io_watch_del(): DBG:
io_watch_del (0x562f315c32a0, 6, -1, 0x10) fd_no=3 called"}
"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)"}
"message":" DEBUG: <core> [core\/tcp_read.c:1684]: release_tcpconn():
extra_data (nil)"}
"message":" DEBUG: <core> [core\/io_wait.h:599]: io_watch_del(): DBG:
io_watch_del (0x562f315c32a0, 9, -1, 0x10) fd_no=2 called"}
"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)"}
"message":" DEBUG: <core> [core\/tcp_read.c:1684]: release_tcpconn():
extra_data (nil)"}
"message":" DEBUG: <core> [core\/tcp_main.c:3625]: handle_tcp_child():
reader response= 7f56979e0ad8, 1 from 0 "}
"message":" DEBUG: <core> [core\/io_wait.h:377]: io_watch_add(): DBG:
io_watch_add(0x562f31567820, 24, 2, 0x7f56979e0ad8), fd_no=15"}
"message":" DEBUG: <core> [core\/tcp_main.c:3752]: handle_tcp_child():
CONN_RELEASE  0x7f56979e0ad8 refcnt= 1"}
"message":" DEBUG: <core> [core\/tcp_main.c:3625]: handle_tcp_child():
reader response= 7f56979f0e78, 1 from 0 "}
"message":" DEBUG: <core> [core\/io_wait.h:377]: io_watch_add(): DBG:
io_watch_add(0x562f31567820, 26, 2, 0x7f56979f0e78), fd_no=16"}
"message":" DEBUG: <core> [core\/tcp_main.c:3752]: handle_tcp_child():
CONN_RELEASE  0x7f56979f0e78 refcnt= 1"}

Not sure what I can be doing wrong!

IP information to help you understand the packet capture:

UAC: 104.175.176.242
LB (UAC side): 35.186.235.62:443 or sbc01stg.gii.me:443
LB (Kam side can be many, for this example it's 130.211.3.12:53883)
PSTN GW: 198.1.54.228

Thanks for your help on this.

Best,
Joel.

On Fri, Nov 22, 2019 at 1:02 AM Daniel-Constantin Mierla <miconda at gmail.com>
wrote:

> Hello,
>
> how do you set the record-route? Do you have advertised address for the
> socket receiving TCP/HAproxy loadbalancer connections?
>
> Can you give all the debug messages when processing the BYE that doesn't
> go through?
>
> Cheers,
> Daniel
> On 21.11.19 19:44, Joel Serrano wrote:
>
> Hi Daniel,
>
> I sent you (privately) 2 pcaps. Please let me know if you need anything
> else.
>
> My current TCP params are:
>
> disable_tcp=no
> tcp_children=1
> tcp_max_connections=12288
> tcp_rd_buf_size=65536
> tcp_conn_wq_max=131072
> tcp_keepalive=yes
> tcp_crlf_ping=yes
> tcp_keepcnt=3
> tcp_keepidle=30
> tcp_keepintvl=30
> tcp_connection_lifetime=3610
> tcp_accept_no_cl=yes
> tcp_accept_haproxy=yes
> tcp_no_connect=yes
>
> Thanks,
> Joel.
>
> On Thu, Nov 21, 2019 at 7:50 AM Joel Serrano <joel at textplus.com> wrote:
>
>> I don’t, but I’ll repeat the test with tcpdump active! I’ll report back
>> shortly
>>
>> On Thu, Nov 21, 2019 at 03:50 Daniel-Constantin Mierla <miconda at gmail.com>
>> wrote:
>>
>>> Hello,
>>>
>>> do you have the pcap with the sip traffic for this case?
>>>
>>> Cheers,
>>> Daniel
>>> On 20.11.19 19:45, Joel Serrano wrote:
>>>
>>> Hello,
>>>
>>> I added to the config file:
>>>
>>> tcp_no_connect=yes
>>>
>>> And with that param, the same test results in a different behavior, but
>>> still not working:
>>>
>>> "message":" DEBUG: {1 12583750 BYE RVXZVMHKop} <core>
>>> [core\/msg_translator.c:161]: check_via_address(): (198.1.54.228,
>>> 198.1.54.228, 0)"}
>>> "message":" ERROR: {1 12583750 BYE RVXZVMHKop} tm
>>> [..\/..\/core\/forward.h:292]: msg_send_buffer(): tcp_send failed"}
>>> "message":" DEBUG: {1 12583750 BYE RVXZVMHKop} tm [t_fwd.c:1537]:
>>> t_send_branch(): send to 35.191.9.20:56470 (3) failed"}
>>> "message":" WARNING: {1 12583750 BYE RVXZVMHKop} tm [t_fwd.c:1557]:
>>> t_send_branch(): sending request on branch 0 failed"}
>>> "message":" DEBUG: {1 12583750 BYE RVXZVMHKop} tm [t_funcs.c:336]:
>>> t_relay_to(): t_forward_nonack returned error -1 (-477)"}
>>> "message":" DEBUG: {1 12583750 BYE RVXZVMHKop} tm [t_funcs.c:354]:
>>> t_relay_to(): -477 error reply generation delayed "}
>>>
>>> Although, netstats says the connection is active:
>>>
>>> root at sbc-gslb-test-1:~# netstat -putan | grep 56470
>>> tcp        0      0 10.116.15.237:443       35.191.9.20:56470
>>> ESTABLISHED 3920/kamailio
>>> root at sbc-gslb-test-1:~#
>>>
>>>
>>> Anyone?
>>>
>>> On Wed, Nov 20, 2019 at 9:26 AM Joel Serrano <joel at textplus.com> wrote:
>>>
>>>> Bumping this thread up!
>>>>
>>>> I did some more tests trying to narrow down the problem and this is
>>>> what I found...:
>>>>
>>>> On the INVITE, I add the TCP connection information I want to save (for
>>>> later reuse). Snippets:
>>>>
>>>> ...(found this in the misc/examples/pkg/sip-router-oob.cfg, but I
>>>> haven't noticed any changes to the headers or anything)...
>>>>
>>>>     # Force response to received connection
>>>>     force_rport();
>>>>     if (proto==TCP || proto == TLS) {
>>>>         force_tcp_alias();
>>>>         xlog("L_NOTICE", "force_tcp_alias() done");
>>>>     }
>>>> ...
>>>>
>>>> ...(I also have this)...
>>>>
>>>>     if (is_first_hop()) {
>>>>         xlog("L_NOTICE", "Adding LB info to contact - M=$rm ID=$ci\n");
>>>>         add_contact_alias("$tcp(c_si)", "$tcp(c_sp)", "tls");
>>>>     }
>>>> ...
>>>>
>>>> Which effectively makes the contact look like:
>>>>
>>>>
>>>> <sip:linphone at 104.175.176.242:50312;alias=35.191.9.21~50705~3;transport=tls>
>>>>
>>>> ..180..
>>>> ..200 OK..
>>>> ..ACK..
>>>>
>>>> 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:
>>>>
>>>> "message":" DEBUG: {1 12543376 BYE QQy-qagkcB} nathelper
>>>> [nathelper.c:1144]: handle_ruri_alias(): setting dst_uri to
>>>> <sip:35.191.9.21:50705;transport=tls>"}
>>>> "message":" DEBUG: {1 12543376 BYE QQy-qagkcB} nathelper
>>>> [nathelper.c:1166]: handle_ruri_alias(): rewriting r-uri to
>>>> <sip:linphone at 104.175.176.242:50312;transport=tls>"}
>>>>
>>>> But then, Kamalio won't reuse the existing TCP connection and tries to
>>>> create a new one:
>>>>
>>>> "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"}
>>>> "message":" DEBUG: {1 12543376 BYE QQy-qagkcB} tm [t_lookup.c:497]:
>>>> t_lookup_request(): start searching: hash=63128, isACK=0"}
>>>> "message":" DEBUG: {1 12543376 BYE QQy-qagkcB} tm [t_lookup.c:455]:
>>>> matching_3261(): RFC3261 transaction matching failed - via branch
>>>> [z9hG4bK896f.dc04734743b0f0997f39c4fff07c0fbb.0]"}
>>>> "message":" DEBUG: {1 12543376 BYE QQy-qagkcB} tm [t_lookup.c:675]:
>>>> t_lookup_request(): no transaction found"}
>>>> "message":" DEBUG: {1 12543376 BYE QQy-qagkcB} tm [t_hooks.c:336]:
>>>> run_reqin_callbacks_internal(): trans=0x7f8583b17208, callback type 1, id 0
>>>> entered"}
>>>> "message":" DEBUG: {1 12543376 BYE QQy-qagkcB} <core>
>>>> [core\/crypto\/md5utils.c:67]: MD5StringArray(): MD5 calculated:
>>>> 71c229aff3c0b4f6e9e77c4990b74e5e"}
>>>> "message":" DEBUG: {1 12543376 BYE QQy-qagkcB} siputils [checks.c:123]:
>>>> has_totag(): totag found"}
>>>> "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])"}
>>>> "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>"}
>>>> "message":" DEBUG: {1 12543376 BYE QQy-qagkcB} siputils [checks.c:123]:
>>>> has_totag(): totag found"}
>>>> "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)"}
>>>> "message":" DEBUG: {1 12543376 BYE QQy-qagkcB} <core>
>>>> [core\/tcp_main.c:2060]: tcp_send(): no open tcp connection found, opening
>>>> new one"}
>>>> "message":" DEBUG: {1 12543376 BYE QQy-qagkcB} <core>
>>>> [core\/ip_addr.c:229]: print_ip(): tcpconn_new: new tcp connection:
>>>> 35.191.9.21"}
>>>> "message":" DEBUG: {1 12543376 BYE QQy-qagkcB} <core>
>>>> [core\/tcp_main.c:1242]: tcpconn_new(): on port 50705, type 3"}
>>>> "message":" DEBUG: {1 12543376 BYE QQy-qagkcB} <core>
>>>> [core\/tcp_main.c:1561]: tcpconn_add(): hashes: 337:3545:0, 3"}
>>>>
>>>> Am I still missing anything?
>>>>
>>>> Is this a bug and I should open a GH issue?
>>>>
>>>> Any suggestions/comments/ideas are very welcome!
>>>>
>>>> Thanks,
>>>> Joel.
>>>>
>>>>
>>>> On Fri, Nov 1, 2019 at 11:46 AM Joel Serrano <joel at textplus.com> wrote:
>>>>
>>>>> Hi Yuriy,
>>>>>
>>>>> 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.
>>>>>
>>>>> All the VIA headers look exactly the same, and I still get this in the
>>>>> logs:
>>>>>
>>>>> "message":" DEBUG: {1 11762916 BYE d2T9-YOxYk} <core>
>>>>> [core\/tcp_main.c:2060]: tcp_send(): no open tcp connection found, opening
>>>>> new one"}
>>>>>
>>>>>
>>>>> The docs say:
>>>>>
>>>>> "force_tcp_alias(port)
>>>>>
>>>>> 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."
>>>>>
>>>>> 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..
>>>>>
>>>>>
>>>>> Any other suggestions? Am I missing something?
>>>>>
>>>>>
>>>>> Thanks,
>>>>>
>>>>> Joel.
>>>>>
>>>>> On Thu, Oct 31, 2019 at 10:53 PM Yuriy Gorlichenko <
>>>>> ovoshlook at gmail.com> wrote:
>>>>>
>>>>>> You have to use
>>>>>> tcp_accept_aliases=yes
>>>>>> But this is not enough as this param will be triggered by function
>>>>>> force_tcp_alias() you need to use in the route for request ( for
>>>>>> example record_route or subroutes)
>>>>>> It will add param paramname=<portnum> (I Don't remember specific
>>>>>> name)
>>>>>> to Via header that will be used for all dialog requests belongs one
>>>>>> being affected
>>>>>>
>>>>>>
>>>>>> On Fri, 1 Nov 2019, 00:52 Joel Serrano, <joel at textplus.com> wrote:
>>>>>>
>>>>>>> Hello,
>>>>>>>
>>>>>>> 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).
>>>>>>>
>>>>>>> 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:
>>>>>>>
>>>>>>> Following this example:
>>>>>>>
>>>>>>>
>>>>>>> [image: image.png]
>>>>>>>
>>>>>>>
>>>>>>> EXT & INT represent the external and internal interface of a LB
>>>>>>> between the UAC and Kamailio, using TLS on both legs and proxy protocol.
>>>>>>>
>>>>>>> Transaction 1: INVITE, 100, 180, 183, 200 OK
>>>>>>>
>>>>>>> UAC 1.1.1.1:1111 -> 2.2.2.2:443 (EXT) 3.3.3.3:3333 (INT) ->
>>>>>>> 7.7.7.7:5060 (Kamailio)
>>>>>>>
>>>>>>> Transaction 2: ACK
>>>>>>>
>>>>>>> UAC 1.1.1.1:1112 -> 2.2.2.2:443 (EXT) 4.4.4.4:4444 (INT) ->
>>>>>>> 7.7.7.7:5060 (Kamailio)
>>>>>>>
>>>>>>> Transaction 3: BYE
>>>>>>>
>>>>>>> Kam 7.7.7.7:5060 -> 3.3.3.3:3333 (INT) 2.2.2.2:443 (EXT) ->
>>>>>>> 1.1.1.1:1111 UAC
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>> 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.
>>>>>>>
>>>>>>> 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?
>>>>>>>
>>>>>>> On the original INVITE, I use the following to save where I have to
>>>>>>> reach the UAC:
>>>>>>>
>>>>>>> add_contact_alias("$tcp(c_si)", "$tcp(c_sp)", "tls");
>>>>>>>
>>>>>>> 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.
>>>>>>>
>>>>>>> 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).
>>>>>>>
>>>>>>> So when I run handle_ruri_alias(), and $du is set to 3.3.3.3:3333
>>>>>>> (from the example above), instead of using the existing connection,
>>>>>>> Kamailio tries to create a new one.
>>>>>>>
>>>>>>> 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:
>>>>>>>
>>>>>>> DEBUG: {1 11726467 BYE gqR1qqNK8B} <core> [core\/tcp_main.c:2060]:
>>>>>>> tcp_send(): no open tcp connection found, opening new one"}
>>>>>>>
>>>>>>> And then the problems begin...
>>>>>>>
>>>>>>>
>>>>>>> I have tried playing around with:
>>>>>>>
>>>>>>> tcp_reuse_port
>>>>>>> tcp_connection_match
>>>>>>>
>>>>>>> But no luck..!
>>>>>>>
>>>>>>> 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.
>>>>>>>
>>>>>>> A more detailed log:
>>>>>>>
>>>>>>> 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, 35.191.0.66:60271 would be the
>>>>>>> equivalent of 3.3.3.3:3333 and 104.175.176.242:28157 would be
>>>>>>> 1.1.1.1:1111 from the example above.
>>>>>>>
>>>>>>> ...
>>>>>>> "message":" DEBUG: {1 11727734 BYE 5-LX4GdI9X} <core>
>>>>>>> [core\/tcp_main.c:1657]: _tcpconn_find(): found connection by id: 1"}
>>>>>>> "message":" NOTICE: {1 11727734 BYE 5-LX4GdI9X} <script>: JOEL TEST
>>>>>>> New request - M=BYE TCP STATUS:1 ID=5-LX4GdI9X"}
>>>>>>> ...
>>>>>>> "message":" DEBUG: {1 11727734 BYE 5-LX4GdI9X} nathelper
>>>>>>> [nathelper.c:1144]: handle_ruri_alias(): setting dst_uri to
>>>>>>> <sip:35.191.0.66:60271;transport=tls>"}
>>>>>>> "message":" DEBUG: {1 11727734 BYE 5-LX4GdI9X} nathelper
>>>>>>> [nathelper.c:1166]: handle_ruri_alias(): rewriting r-uri to
>>>>>>> <sip:linphone at 104.175.176.242:28157;transport=tls>"}
>>>>>>> "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"}
>>>>>>> "message":" DEBUG: {1 11727734 BYE 5-LX4GdI9X} tm [t_lookup.c:497]:
>>>>>>> t_lookup_request(): start searching: hash=63496, isACK=0"}
>>>>>>> "message":" DEBUG: {1 11727734 BYE 5-LX4GdI9X} tm [t_lookup.c:455]:
>>>>>>> matching_3261(): RFC3261 transaction matching failed - via branch
>>>>>>> [z9hG4bK808f.eee2444f92a02cb33e1b7a21f20bc6bb.0]"}
>>>>>>> "message":" DEBUG: {1 11727734 BYE 5-LX4GdI9X} tm [t_lookup.c:675]:
>>>>>>> t_lookup_request(): no transaction found"}
>>>>>>> "message":" DEBUG: {1 11727734 BYE 5-LX4GdI9X} tm [t_hooks.c:336]:
>>>>>>> run_reqin_callbacks_internal(): trans=0x7f3c83b8c598, callback type 1, id 0
>>>>>>> entered"}
>>>>>>> "message":" DEBUG: {1 11727734 BYE 5-LX4GdI9X} <core>
>>>>>>> [core\/crypto\/md5utils.c:67]: MD5StringArray(): MD5 calculated:
>>>>>>> 3071029feb05962b26b53a9664a14210"}
>>>>>>> "message":" DEBUG: {1 11727734 BYE 5-LX4GdI9X} siputils
>>>>>>> [checks.c:123]: has_totag(): totag found"}
>>>>>>> "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])"}
>>>>>>> "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>"}
>>>>>>> "message":" DEBUG: {1 11727734 BYE 5-LX4GdI9X} siputils
>>>>>>> [checks.c:123]: has_totag(): totag found"}
>>>>>>> "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)"}
>>>>>>> "message":" DEBUG: {1 11727734 BYE 5-LX4GdI9X} <core>
>>>>>>> [core\/tcp_main.c:2060]: tcp_send(): no open tcp connection found, opening
>>>>>>> new one"}
>>>>>>> "message":" DEBUG: {1 11727734 BYE 5-LX4GdI9X} <core>
>>>>>>> [core\/ip_addr.c:229]: print_ip(): tcpconn_new: new tcp connection:
>>>>>>> 35.191.0.66"}
>>>>>>> "message":" DEBUG: {1 11727734 BYE 5-LX4GdI9X} <core>
>>>>>>> [core\/tcp_main.c:1242]: tcpconn_new(): on port 60271, type 3"}
>>>>>>> "message":" DEBUG: {1 11727734 BYE 5-LX4GdI9X} <core>
>>>>>>> [core\/tcp_main.c:1561]: tcpconn_add(): hashes: 1446:2350:0, 5"}
>>>>>>> "message":" DEBUG: {1 11727734 BYE 5-LX4GdI9X} tls
>>>>>>> [tls_server.c:199]: tls_complete_init(): completing tls connection
>>>>>>> initialization"}
>>>>>>> ...
>>>>>>>
>>>>>>>
>>>>>>> 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...
>>>>>>>
>>>>>>> Is this even doable?
>>>>>>>
>>>>>>> Thanks,
>>>>>>> Joel.
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>> _______________________________________________
>>>>>>> Kamailio (SER) - Users Mailing List
>>>>>>> sr-users at lists.kamailio.org
>>>>>>> https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users
>>>>>>>
>>>>>> _______________________________________________
>>>>>> Kamailio (SER) - Users Mailing List
>>>>>> sr-users at lists.kamailio.org
>>>>>> https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users
>>>>>>
>>>>>
>>> _______________________________________________
>>> Kamailio (SER) - Users Mailing Listsr-users at lists.kamailio.orghttps://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users
>>>
>>> --
>>> Daniel-Constantin Mierla -- www.asipto.comwww.twitter.com/miconda -- www.linkedin.com/in/miconda
>>> Kamailio World Conference - April 27-29, 2020, in Berlin -- www.kamailioworld.com
>>>
>>> --
> Daniel-Constantin Mierla -- www.asipto.comwww.twitter.com/miconda -- www.linkedin.com/in/miconda
> Kamailio World Conference - April 27-29, 2020, in Berlin -- www.kamailioworld.com
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.kamailio.org/pipermail/sr-users/attachments/20191122/6b96da82/attachment.html>


More information about the sr-users mailing list