Re: [SR-Users] tsilo - failure to add branches (-1)

Hi Federico, Indeed I had a messed up config at that point. I cleaned it up, but still had the same problem. Full log in attachment. Here is some part of it: 45(51) DEBUG: {1 21 REGISTER 6z~FzexPro} tsilo [ts_append.c:72]: > ts_append(): transaction 16864:783220347 found for > sip:1443452187102-0af7c6035717-0001@voipstaging.myappapp.net, going > to append branches > 45(51) DEBUG: {1 21 REGISTER 6z~FzexPro} tm [t_lookup.c:1612]: > t_lookup_ident_filter(): transaction found > 45(51) DEBUG: {1 21 REGISTER 6z~FzexPro} registrar [lookup.c:306]: > lookup_helper(): contact for [1443452187102-0af7c6035717-0001] found by > address > 45(51) DEBUG: {1 21 REGISTER 6z~FzexPro} tm [t_append_branches.c:77]: > t_append_branches(): transaction 16864:783220347 in status 180 > 45(51) DEBUG: {1 21 REGISTER 6z~FzexPro} tm [t_append_branches.c:99]: > t_append_branches(): Call 3ed4a6c3051ea46b50487a0d1b5b25ec(a)10.10.0.0: > 1 (0) outgoing branches > 45(51) DEBUG: {1 21 REGISTER 6z~FzexPro} tm [t_append_branches.c:163]: > t_append_branches(): Call 3ed4a6c3051ea46b50487a0d1b5b25ec(a)10.10.0.0: > 1 (0) outgoing branches after clear_branches() > 45(51) ERROR: {1 21 REGISTER 6z~FzexPro} tm [t_append_branches.c:172]: *t_append_branches(): > failure to add branches (-1)* > 45(51) INFO: {1 21 REGISTER 6z~FzexPro} <script>: tsilo appending > branch sip:1443452187102-0af7c6035717-0001@voipstaging.myappapp.net > Here Kamailio snippets of config: ........................................................... route[CONTINUE] { if (!is_method("REGISTER")) return; $var(pjoin) = 0; lock("$tU"); $var(pjoin) = $sht(pmap=>join::$tU); $var(pstored) = $sht(pmap=>stored::$tU); xlog("L_INFO", "===== Stored 1 not stored 0 $var(pstored) [$sht(pmap=>stored::$tU)] \n"); $sht(pmap=>join::$tU) = $null; unlock("$tU"); if($var(pjoin)==0) { if ($var(pstored)) { if($expires(min)>0) { ts_append("location", "sip:$ tU(a)voipstaging.onoffapp.net&quot;)uot;); xlog("L_INFO","tsilo appending branch $tu \n"); } } return; } $var(id_index) = $(var(pjoin){s.select,0,:}{s.int}); $var(id_label) = $(var(pjoin){s.select,1,:}{s.int}); xlog("L_INFO", "===== resuming suspended trasaction [$var(id_index):$var(id_label)] $tU ($var(pjoin)) \n"); t_continue("$var(id_index)", "$var(id_label)", "LOCATION"); } ........................................................... if (is_method("INVITE")) { ts_store(); $sht(pmap=>stored::$rU) = 1; xlog("L_ERR" ,"stored transaction [$T(id_index):$T(id_label)] $fU => $rU\n"); } ........................................................... Jurijs On Wed, Oct 28, 2020 at 9:09 AM Federico Cabiddu < federico.cabiddu(a)gmail.com&gt; wrote: > Hi Jurijs, > I had a look at the logs and there is something strange: I see the > ts_append logs before the registrar module ones (the save function). > Are you sure you are calling ts_append after calling save()? > > Cheers, > > Federico > > On Tue, Oct 27, 2020 at 10:26 AM Jurijs Ivolga < > jurijs.ivolga(a)gmail.com&gt; wrote: > >> Hi Daniel-Constantin, >> >> Debug log is intachment. Do you see any hints? >> >> I think this is relative part: >> >> 2020-10-27T08:24:36.198Z,"79(85) DEBUG: {1 21 REGISTER G~qt15Oz7~} >>> tsilo [ts_append.c:72]: ts_append(): transaction 21280:984985415 found for >>> sip:1443452187102-0af7c6035717-0001@voipstaging.myapp.net, going to >>> append branches" >>> 2020-10-27T08:24:36.198Z,79(85) DEBUG: {1 21 REGISTER G~qt15Oz7~} >>> registrar [lookup.c:306]: lookup_helper(): contact for >>> [1443452187102-0af7c6035717-0001] found by address >>> 2020-10-27T08:24:36.198Z,79(85) DEBUG: {1 21 REGISTER G~qt15Oz7~} tm >>> [t_lookup.c:1612]: t_lookup_ident_filter(): transaction found >>> 2020-10-27T08:24:36.199Z,79(85) DEBUG: {1 21 REGISTER G~qt15Oz7~} tm >>> [t_append_branches.c:77]: t_append_branches(): transaction 21280:984985415 >>> in status 180 >>> 2020-10-27T08:24:36.199Z,79(85) DEBUG: {1 21 REGISTER G~qt15Oz7~} tm >>> [t_append_branches.c:99]: t_append_branches(): Call >>> 88cc06a544ba41a8aee5035c437baabf(a)0.0.0.0: 1 (0) outgoing branches >>> 2020-10-27T08:24:36.205Z,79(85) DEBUG: {1 21 REGISTER G~qt15Oz7~} tm >>> [t_append_branches.c:163]: t_append_branches(): Call >>> 88cc06a544ba41a8aee5035c437baabf(a)0.0.0.0: 1 (0) outgoing branches >>> after clear_branches() >>> 2020-10-27T08:24:36.206Z,"79(85) DEBUG: {1 21 REGISTER G~qt15Oz7~} >>> tsilo [ts_append.c:72]: ts_append(): transaction 38832:1600293484 found for >>> sip:1443452187102-0af7c6035717-0001@voipstaging.myapp.net, going to >>> append branches" >>> 2020-10-27T08:24:36.206Z,79(85) ERROR: {1 21 REGISTER G~qt15Oz7~} tm >>> [t_append_branches.c:172]:* t_append_branches(): failure to add >>> branches (-1)* >>> 2020-10-27T08:24:36.207Z,79(85) DEBUG: {1 21 REGISTER G~qt15Oz7~} >>> registrar [lookup.c:306]: lookup_helper(): contact for >>> [1443452187102-0af7c6035717-0001] found by address >>> 2020-10-27T08:24:36.207Z,79(85) DEBUG: {1 21 REGISTER G~qt15Oz7~} tm >>> [t_append_branches.c:77]: t_append_branches(): transaction 38832:1600293484 >>> in status 180 >>> 2020-10-27T08:24:36.207Z,79(85) DEBUG: {1 21 REGISTER G~qt15Oz7~} tm >>> [t_lookup.c:1612]: t_lookup_ident_filter(): transaction found >>> 2020-10-27T08:24:36.208Z,79(85) ERROR: {1 21 REGISTER G~qt15Oz7~} tm >>> [t_append_branches.c:172]: t_append_branches(): failure to add branches (-1) >>> 2020-10-27T08:24:36.208Z,79(85) DEBUG: {1 21 REGISTER G~qt15Oz7~} tm >>> [t_append_branches.c:99]: t_append_branches(): Call >>> aac9c351-92d0-1239-0599-024233fefdc7: 2 (0) outgoing branches >>> 2020-10-27T08:24:36.208Z,79(85) DEBUG: {1 21 REGISTER G~qt15Oz7~} tm >>> [t_append_branches.c:163]: t_append_branches(): Call >>> aac9c351-92d0-1239-0599-024233fefdc7: 2 (0) outgoing branches after >>> clear_branches() >>> 2020-10-27T08:24:36.209Z,79(85) INFO: {1 21 REGISTER G~qt15Oz7~} >>> <script>: tsilo appending branch >>> sip:1443452187102-0af7c6035717-0001@voipstaging.myapp.net >>> 2020-10-27T08:24:36.217Z,79(85) DEBUG: {1 21 REGISTER G~qt15Oz7~} >>> <core> [core/strutils.c:215]: unescape_user(): unescaped string is >>> <sip:192.168.173.107:55982;transport=tls> >>> 2020-10-27T08:24:36.218Z,79(85) DEBUG: {1 21 REGISTER G~qt15Oz7~} >>> registrar [path.c:116]: build_path_vector(): path is <<sip: >>> ingress1dev.myapp.net;lr;received=sip:192.168.173.107:55982 >>> %3Btransport%3Dtls>> >>> 2020-10-27T08:24:36.218Z,79(85) DEBUG: {1 21 REGISTER G~qt15Oz7~} >>> registrar [path.c:108]: build_path_vector(): received is >>> <sip:192.168.173.107:55982;transport=tls> >>> 2020-10-27T08:24:36.218Z,79(85) DEBUG: {1 21 REGISTER G~qt15Oz7~} >>> registrar [save.c:314]: pack_ci(): set >>> instance[<urn:uuid:2a56856a-fae5-00f6-8f3b-2d9283f533be>] >>> 2020-10-27T08:24:36.219Z,79(85) DEBUG: {1 21 REGISTER G~qt15Oz7~} >>> <core> [sruid.c:182]: sruid_next(): new sruid is [uloc-5f97d8f4-55-1] (1 / >>> 18) >>> 2020-10-27T08:24:36.219Z,79(85) DEBUG: {1 21 REGISTER G~qt15Oz7~} >>> registrar [save.c:410]: pack_ci(): generated ruid is: uloc-5f97d8f4-55-1 >>> 2020-10-27T08:24:36.220Z,79(85) DEBUG: {1 21 REGISTER G~qt15Oz7~} >>> registrar [save.c:410]: pack_ci(): generated ruid is: uloc-5f97d8f4-55-2 >>> 2020-10-27T08:24:36.220Z,79(85) DEBUG: {1 21 REGISTER G~qt15Oz7~} >>> <core> [sruid.c:182]: sruid_next(): new sruid is [uloc-5f97d8f4-55-2] (2 / >>> 18) >>> 2020-10-27T08:24:36.220Z,"79(85) DEBUG: {1 21 REGISTER G~qt15Oz7~} >>> registrar [reply.c:377]: build_contact(): created Contact HF: Contact: >>> <sip:1443452187102-0af7c6035717-0001@192.168.173.107:55982 >>> ;transport=tls>;q=1;expires=120;received=""sip:192.168.173.107:55982 >>> ;transport=tls"";+sip.instance=""<urn:uuid:2a56856a-fae5-00f6-8f3b-2d9283f533be>""" >>> 2020-10-27T08:24:36.227Z,79(85) DEBUG: {1 21 REGISTER G~qt15Oz7~} >>> cfgutils [cfgutils.c:724]: cfg_lock_helper(): cfg_lock mode 0 on 54 >>> (1443452187102-0af7c6035717-0001) >>> 2020-10-27T08:24:36.228Z,79(85) DEBUG: {1 21 REGISTER G~qt15Oz7~} >>> htable [ht_var.c:89]: pv_set_ht_cell(): set value for >>> $sht(pmap=>join::1443452187102-0af7c6035717-0001) >>> 2020-10-27T08:24:36.228Z,79(85) DEBUG: {1 21 REGISTER G~qt15Oz7~} >>> cfgutils [cfgutils.c:724]: cfg_lock_helper(): cfg_lock mode 1 on 54 >>> (1443452187102-0af7c6035717-0001) >>> 2020-10-27T08:24:36.228Z,79(85) DEBUG: {1 21 REGISTER G~qt15Oz7~} >>> <core> [core/receive.c:437]: receive_msg(): request-route executed in: 2293 >>> usec >>> >> >> Jurijs >> >> >> On Tue, Oct 27, 2020 at 10:20 AM Daniel-Constantin Mierla < >> miconda(a)gmail.com&gt; wrote: >> >>> Hello, >>> >>> if you get it always, then run with debug=3 and send all the debug >>> messages here, there should be more hints about why a branch is not added. >>> >>> Cheers, >>> Daniel >>> On 27.10.20 08:40, Jurijs Ivolga wrote: >>> >>> Hi, >>> >>> I have several Kamailio proxies - loadbalancer which is used as TLS >>> offload and Authorization server and behind registrar servers. >>> >>> In this case I can't make tsilo work on the registrar server. >>> >>> I'm always getting: "tm [t_append_branches.c:172]: >>> t_append_branches(): failure to add branches (-1)" >>> >>> If I use just one Kamailio which is used as Authorization and >>> Registrar server then tsilo works as expected. >>> >>> Looks like kamailio where I run ts_append tries to connect to UAC >>> directly and not through Loadbalancer. >>> >>> Any ideas? How can I troubleshoot this? >>> >>> Thank you! >>> >>> Jurijs >>> >>> _______________________________________________ >>> Kamailio (SER) - Users Mailing Listsr-users@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 >>> Funding: https://www.paypal.me/dcmierla >>> >>> _______________________________________________ >> Kamailio (SER) - Users Mailing List >> sr-users(a)lists.kamailio.org >> https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users >> > _______________________________________________ > Kamailio (SER) - Users Mailing List > sr-users(a)lists.kamailio.org > https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users > _______________________________________________