[SR-Users] tsilo - failure to add branches (-1)
Federico Cabiddu
federico.cabiddu at gmail.com
Tue Nov 3 11:46:49 CET 2020
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
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.kamailio.org/pipermail/sr-users/attachments/20201103/3ff9686f/attachment.htm>
More information about the sr-users
mailing list