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

Federico Cabiddu federico.cabiddu at gmail.com
Thu Nov 5 11:40:24 CET 2020


Good to know that you solved it :)
Why did you have to set "append_branches" to 0? Which was the behaviour
when enabling it?

Cheers,

Federico

On Tue, Nov 3, 2020 at 6:51 PM Jurijs Ivolga <jurijs.ivolga at gmail.com>
wrote:

> Hi Federico,
>
> First of all, thank you a lot for helping me. This means a lot to me!!!!
> This is true open source spirit!!!
>
> So indeed I had messed up config and I was saving transactions incorrectly
> and that why you saw 2 call IDs.
>
> I updated my config and now I do save transactions correctly and it works!
> I would like to add that I needed to update Registrar settings too:
>
> modparam("registrar", "append_branches", 0) -- this was messing with my
> config too. I needed to disable it to make it work.
>
> Thank you again!!!!
>
> Jurijs
>
>
> On Tue, Nov 3, 2020 at 12:55 PM Federico Cabiddu <
> federico.cabiddu at gmail.com> wrote:
>
>> Hi Jurijs,
>> I had a look at the logs but they are confusing: looks like there are two
>> calls (transactions) stored by tsilo and the ts_append is called only for
>> one.
>> In the logs you sent:
>> 1) row 19: an INVITE comes with callid
>> 9741c821-93b2-1239-0599-024233fefdc7
>> 2) row 60: since there is no contact the transaction is
>> suspended (transaction hash:id=9467:1575872173)
>> 3) row 132: a REGISTER is received from the user for which the
>> transaction was suspended
>> 4) row 193 onward: the transaction 9467:1575872173 is resumed, the INVITE
>> is sent out and the transaction stored by tsilo
>> 5) row 262: another REGISTER from the same instance (same sip.instance
>> and received) is received
>> 6) ts_append is called but the transaction hash:id is 16864:783220347 and
>> the callid is 3ed4a6c3051ea46b50487a0d1b5b25ec at 10.10.0.0: when has this
>> transaction been stored? I couldn't find anywhere in the logs
>> Which version of kamailio are you using?
>> Are you setting the "use_domain" tsilo parameter?
>> First I'd suggest trying to call ts_store specifying the r-uri, as you do
>> for ts_append.
>> Then could you please retry the scenario being sure that there is only
>> one transaction stored?
>> Thank you,
>>
>> Federico
>>
>>
>>
>>
>> On Sat, Oct 31, 2020 at 5:16 PM Jurijs Ivolga <jurijs.ivolga at gmail.com>
>> wrote:
>>
>>> Hi,
>>>
>>> Any ideas regarding "t_append_branches(): failure to add branches (-1)"?
>>>
>>> Is there a way somehow to dump what ts_append handover towards tm? I
>>> think if I would be able to see this I will be able to understand what is
>>> wrong. I tried tm:local-request and failure route and branch route, but
>>> these routes are not executed when this error happens.
>>>
>>> Maybe the issue is that the TLS connection is established between
>>> Kamailio and UAC what is in front my Register and this Register kamailio
>>> just tries to connect directly towards UAC and it fails? At least this is
>>> my idea why this might fail.
>>>
>>> Jurijs
>>>
>>>
>>> On Thu, Oct 29, 2020 at 8:38 AM Jurijs Ivolga <jurijs.ivolga at gmail.com>
>>> wrote:
>>>
>>>> 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 at 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 at 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 at 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 at 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 at voipstaging.onoffapp.net");
>>>>                                 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 at gmail.com> 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 at gmail.com> 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 at 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 at 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 at 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 at 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 at 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 at 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 at gmail.com> 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 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
>>>>>>> Funding: https://www.paypal.me/dcmierla
>>>>>>>
>>>>>>> _______________________________________________
>>>>>> 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 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 List
> sr-users at lists.kamailio.org
> https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.kamailio.org/pipermail/sr-users/attachments/20201105/c951d04c/attachment.htm>


More information about the sr-users mailing list