[SR-Users] tsilo - failure to add branches (-1)
Jurijs Ivolga
jurijs.ivolga at gmail.com
Tue Nov 3 18:46:52 CET 2020
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
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.kamailio.org/pipermail/sr-users/attachments/20201103/9757dd53/attachment.htm>
More information about the sr-users
mailing list