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 <j...@textplus.com > <mailto:j...@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 > <mico...@gmail.com <mailto:mico...@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 >> <http://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@sbc-gslb-test-1:~# netstat -putan | grep 56470 >> tcp 0 0 10.116.15.237:443 >> <http://10.116.15.237:443> 35.191.9.20:56470 >> <http://35.191.9.20:56470> ESTABLISHED 3920/kamailio >> root@sbc-gslb-test-1:~# >> >> >> Anyone? >> >> On Wed, Nov 20, 2019 at 9:26 AM Joel Serrano >> <j...@textplus.com <mailto:j...@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@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@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 >> <j...@textplus.com <mailto:j...@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 >> <ovoshl...@gmail.com <mailto:ovoshl...@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, >> <j...@textplus.com <mailto:j...@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.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 <http://1.1.1.1:1111> -> >> 2.2.2.2:443 <http://2.2.2.2:443> (EXT) >> 3.3.3.3:3333 <http://3.3.3.3:3333> (INT) -> >> 7.7.7.7:5060 <http://7.7.7.7:5060> (Kamailio) >> >> Transaction 2: ACK >> >> UAC 1.1.1.1:1112 <http://1.1.1.1:1112> -> >> 2.2.2.2:443 <http://2.2.2.2:443> (EXT) >> 4.4.4.4:4444 <http://4.4.4.4:4444> (INT) -> >> 7.7.7.7:5060 <http://7.7.7.7:5060> (Kamailio) >> >> Transaction 3: BYE >> >> Kam 7.7.7.7:5060 <http://7.7.7.7:5060> -> >> 3.3.3.3:3333 <http://3.3.3.3:3333> (INT) >> 2.2.2.2:443 <http://2.2.2.2:443> (EXT) >> -> 1.1.1.1:1111 <http://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 <http://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 >> <http://35.191.0.66:60271> would be the >> equivalent of 3.3.3.3:3333 >> <http://3.3.3.3:3333> >> and 104.175.176.242:28157 >> <http://104.175.176.242:28157> would be >> 1.1.1.1:1111 <http://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@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@lists.kamailio.org >> <mailto:sr-users@lists.kamailio.org> >> >> https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users >> >> _______________________________________________ >> Kamailio (SER) - Users Mailing List >> sr-users@lists.kamailio.org >> <mailto:sr-users@lists.kamailio.org> >> >> https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users >> >> >> _______________________________________________ >> Kamailio (SER) - Users Mailing List >> sr-users@lists.kamailio.org <mailto:sr-users@lists.kamailio.org> >> https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users > > -- > Daniel-Constantin Mierla -- www.asipto.com <http://www.asipto.com> > www.twitter.com/miconda <http://www.twitter.com/miconda> -- > www.linkedin.com/in/miconda <http://www.linkedin.com/in/miconda> > Kamailio World Conference - April 27-29, 2020, in Berlin -- > www.kamailioworld.com <http://www.kamailioworld.com> > -- Daniel-Constantin Mierla -- www.asipto.com www.twitter.com/miconda -- www.linkedin.com/in/miconda Kamailio World Conference - April 27-29, 2020, in Berlin -- www.kamailioworld.com
_______________________________________________ Kamailio (SER) - Users Mailing List sr-users@lists.kamailio.org https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users