[Spce-user] Calls between subscribers are duplicated in the call list

Henk henkpls at hotmail.com
Wed Oct 19 11:21:09 EDT 2022


Hi Marco,

I can confirm that ngcp-sync-grants fixes the rate-o-mat problem.

As for the call list, I tested with high rates and it is displayed 
correctly, zero charge for the inbound call. But I think what caused my 
confusion, is that local inbound calls have a billing zone supplied 
where this field is normally empty.

So I've tested if the billing zone changes when I add an inbound rate 
and the wrong zone is displayed (with the right price). So it seems the 
real problem is that the zone for inbound calls is not displayed correctly.

Regards,

Henk Plessius

On 19-Oct-22 14:28, Marco Capetta via Spce-user wrote:
> Hi Henk,
>
> I spin up a new mr9.5.5 CE system like your.
> I cannot reproduce the kamailio crash on my side, but I'm glad to hear 
> that a "ngcp-update" fixed the issue.
>
> About the rate-o-mat problem we are aware of that and it is already 
> being internally addressed. The internal ticket numbers are TT#190250 
> and MT#55275.
> Please try to execute the command 'ngcp-sync-grants' and then restart 
> the rate-o-mat service and let us know if it solves the problem.
>
> About the original reported issue, I confirm what I reported in my 
> last email: in the subscribers' call list you get all the calls 
> received or done by that user.
> So in your case you should get on one user an entry as outgoing call 
> and on the other user an entry as incoming call.
> This is the expected behavior.
>
> About the call costs calculation you need to rely on the CDRs (so one 
> for each call) and not on the call-list of the subscribers.
>
>
> Regards
> Marco
>
>
>
>
>
> On 18/10/22 12:05, Henk wrote:
>>
>> Hi Marco,
>>
>> I started with the 9.5.5 VMWare image. Just added two subscribers to 
>> the first customer (#7 customer.test at spce.test). I registered two 
>> devices and made a call without succes. It seems the kamailio proxy 
>> crashed on INVITE with a memory dump:
>>
>> Oct 18 11:25:03 spce proxy[27230]: NOTICE: DEFAULT_ROUTE <script>: 
>> New request on proxy - M=INVITE 
>> R=«sip:1121234567 at test1654835032.example.org» 
>> F=«sip:c2 at test1654835032.example.org» 
>> T=«sip:1121234567 at test1654835032.example.org» IP=«10.0.1.212»:«6062» 
>> («127.0.0.1»:«5060») ID=«1991747540-6062-9 at BA.A.B.CBC» 
>> UA='Grandstream DP750 1.0.17.8' DESTIP=«127.0.0.1»:«5062»
>> Oct 18 11:25:03 spce proxy[27230]: NOTICE: DEFAULT_ROUTE <script>: 
>> Sending reply S=100 Trying M=INVITE fs='«127.0.0.1»:«5062»' 
>> du='«127.0.0.1»:«5060»' - 
>> R=«sip:1121234567 at test1654835032.example.org» 
>> ID=«1991747540-6062-9 at BA.A.B.CBC» UA='Grandstream DP750 1.0.17.8'
>> Oct 18 11:25:03 spce proxy[27230]: NOTICE: ROUTE_AUTH <script>: 
>> Authentication failed, no credentials - 
>> R=«sip:1121234567 at test1654835032.example.org» 
>> ID=«1991747540-6062-9 at BA.A.B.CBC» UA='Grandstream DP750 1.0.17.8' 
>> Auth=«<null>»
>> Oct 18 11:25:03 spce proxy[27230]: NOTICE: ROUTE_AUTH <script>: 
>> Sending reply S=407 fs='«127.0.0.1»:«5062»' du='«127.0.0.1»:«5060»' - 
>> ID=«1991747540-6062-9 at BA.A.B.CBC» UA='Grandstream DP750 1.0.17.8'
>> Oct 18 11:25:03 spce proxy[27230]: NOTICE: sl:filtered-ack <script>: 
>> New request on proxy - M=ACK 
>> R=«sip:1121234567 at test1654835032.example.org» 
>> F=«sip:c2 at test1654835032.example.org» 
>> T=«sip:1121234567 at test1654835032.example.org» IP=«<null>»:«<null>» 
>> («127.0.0.1»:«5060») ID=«1991747540-6062-9 at BA.A.B.CBC» UA='<null>' 
>> DESTIP=«127.0.0.1»:«5062»
>> Oct 18 11:25:03 spce proxy[27230]: NOTICE: DEFAULT_ROUTE <script>: 
>> New request on proxy - M=INVITE 
>> R=«sip:1121234567 at test1654835032.example.org» 
>> F=«sip:c2 at test1654835032.example.org» 
>> T=«sip:1121234567 at test1654835032.example.org» IP=«10.0.1.212»:«6062» 
>> («127.0.0.1»:«5060») ID=«1991747540-6062-9 at BA.A.B.CBC» 
>> UA='Grandstream DP750 1.0.17.8' DESTIP=«127.0.0.1»:«5062»
>> Oct 18 11:25:03 spce proxy[27230]: NOTICE: DEFAULT_ROUTE <script>: 
>> Sending reply S=100 Trying M=INVITE fs='«127.0.0.1»:«5062»' 
>> du='«127.0.0.1»:«5060»' - 
>> R=«sip:1121234567 at test1654835032.example.org» 
>> ID=«1991747540-6062-9 at BA.A.B.CBC» UA='Grandstream DP750 1.0.17.8'
>> Oct 18 11:25:03 spce proxy[27230]: NOTICE: ROUTE_FIND_CALLER 
>> <script>: Sending reply S=101 Connecting fs='«127.0.0.1»:«5062»' 
>> du='«127.0.0.1»:«5060»' - 
>> R=«sip:1121234567 at test1654835032.example.org» 
>> ID=«1991747540-6062-9 at BA.A.B.CBC» UA='Grandstream DP750 1.0.17.8'
>> Oct 18 11:25:03 spce proxy[27230]: NOTICE: ROUTE_DLG_MANAGE <script>: 
>> Dialog managed, lua_dlg_callid:[«1991747540-6062-9 at BA.A.B.CBC»] - 
>> R=«sip:1121234567 at test1654835032.example.org» 
>> ID=«1991747540-6062-9 at BA.A.B.CBC» UA='Grandstream DP750 1.0.17.8'
>> Oct 18 11:25:03 spce proxy[27230]: NOTICE: ROUTE_GET_CALLER_CLI 
>> <script>: User-Provided CLI '«c2»' taken from From-User - 
>> R=«sip:1121234567 at test1654835032.example.org» 
>> ID=«1991747540-6062-9 at BA.A.B.CBC» UA='Grandstream DP750 1.0.17.8'
>> Oct 18 11:25:03 spce proxy[27230]: NOTICE: ROUTE_CHECK_CLI_ALLOWED 
>> <script>: User-provided CLI '«c2»' rejected, using network-provided 
>> CLI '«1127654321»' - R=«sip:1121234567 at test1654835032.example.org» 
>> ID=«1991747540-6062-9 at BA.A.B.CBC» UA='Grandstream DP750 1.0.17.8'
>> Oct 18 11:25:03 spce proxy[27230]: NOTICE: ROUTE_INVITE <script>: 
>> Setting '«1127654321»@«test1654835032.example.org»' as initiating 
>> user-provided CLI - R=«sip:1121234567 at test1654835032.example.org» 
>> ID=«1991747540-6062-9 at BA.A.B.CBC» UA='Grandstream DP750 1.0.17.8'
>> Oct 18 11:25:03 spce proxy[27230]: NOTICE: ROUTE_INVITE <script>: 
>> Setting '«1127654321»@«test1654835032.example.org»' as initiating 
>> network-provided CLI - R=«sip:1121234567 at test1654835032.example.org» 
>> ID=«1991747540-6062-9 at BA.A.B.CBC» UA='Grandstream DP750 1.0.17.8'
>> Oct 18 11:25:03 spce proxy[27230]: NOTICE: ROUTE_FIND_CALLEE 
>> <script>: Callee was aliased with base '«1121234567»' - 
>> R=«sip:c1 at test1654835032.example.org» 
>> ID=«1991747540-6062-9 at BA.A.B.CBC» UA='Grandstream DP750 1.0.17.8'
>> Oct 18 11:25:03 spce proxy[27230]: NOTICE: ROUTE_FIND_CALLEE 
>> <script>: Callee is local, 
>> uuid='«e5eb8a53-d91a-4460-83b0-eb84cbc9240a»' - 
>> R=«sip:c1 at test1654835032.example.org» 
>> ID=«1991747540-6062-9 at BA.A.B.CBC» UA='Grandstream DP750 1.0.17.8'
>> Oct 18 11:25:03 spce proxy[27230]: NOTICE: ROUTE_ACC_CALLER <script>: 
>> Setting acc source-leg for uuid 
>> '«a889b68d-9999-42a4-b897-e5c4bdb102f5»': 
>> '«{"gpp":[null,null,null,null,null,null,null,null,null,null],"clir":0,"uuid":"a889b68d-9999-42a4-b897-e5c4bdb102f5","u":"c2","d":"test1654835032.example.org","cli":"1127654321","s_id":"","c_id":"","a_id":7,"pau":"","par":"","s":"call","ip":"10.0.1.212","t":1666085103.2204731,"lnp_p":"","cli_out":"1127654321","lnp_t":"","pai":"","div":"","last_hih":"","cid":"","u2u":"","lcr":0,"cc_quota":"","cc_sub":"1","cc_cust":"2"}»' 
>> - 
>> R=«sip:c1 at 77.160.100.40:61022;rinstance=38ecd83d4d88e500;transport=TCP» 
>> ID=«1991747540-6062-9 at BA.A.B.CBC» UA='Grandstream DP750 1.0.17.8'
>> Oct 18 11:25:03 spce proxy[27230]: NOTICE: ROUTE_ACC_CALLEE <script>: 
>> Setting acc destination-leg for uuid 
>> '«e5eb8a53-d91a-4460-83b0-eb84cbc9240a»': 
>> '«{"gpp":[null,null,null,null,null,null,null,null,null,null],"plu":0,"s_id":"","c_id":"","a_id":7,"dialed":"1121234567","uuid":"e5eb8a53-d91a-4460-83b0-eb84cbc9240a","u":"c1","d":"test1654835032.example.org","u_in":"1121234567","d_in":"test1654835032.example.org","lcr":0,"lnp_p":"","u_out":"c1","lnp_t":"","fci":"","cc_quota":"","cc_sub":"1","cc_cust":"2"}»' 
>> - 
>> R=«sip:c1 at 77.160.100.40:61022;rinstance=38ecd83d4d88e500;transport=TCP» 
>> ID=«1991747540-6062-9 at BA.A.B.CBC» UA='Grandstream DP750 1.0.17.8'
>> Oct 18 11:25:03 spce proxy[27230]: CRITICAL: 
>> ROUTE_REMOVE_TIMER_SUPP_REQ <core> [core/mem/q_malloc.c:133]: 
>> qm_debug_check_frag(): BUG: qm: fragm. 0x7f63d68230c0 (address 
>> 0x7f63d68230f8) end overwritten (c0c0c000, abcdefed)! Memory 
>> allocator was called from pv_headers: pvh_func.c:444. Fragment marked 
>> by pv_headers: pvh_func.c:391. Exec from core/mem/q_malloc.c:511.
>> Oct 18 11:25:03 spce proxy[27230]: NOTICE: 
>> ROUTE_REMOVE_TIMER_SUPP_REQ qm_status: qm_status(): (0x7f63d5980010):
>> Oct 18 11:25:03 spce proxy[27230]: NOTICE: 
>> ROUTE_REMOVE_TIMER_SUPP_REQ qm_status: qm_status(): heap size= 134217728
>> Oct 18 11:25:03 spce proxy[27230]: NOTICE: 
>> ROUTE_REMOVE_TIMER_SUPP_REQ qm_status: qm_status(): used= 26496208, 
>> used+overhead=33382264, free=100835464
>> Oct 18 11:25:03 spce proxy[27230]: NOTICE: 
>> ROUTE_REMOVE_TIMER_SUPP_REQ qm_status: qm_status(): max used 
>> (+overhead)= 33687296
>> Oct 18 11:25:03 spce proxy[27230]: NOTICE: 
>> ROUTE_REMOVE_TIMER_SUPP_REQ qm_status: qm_status(): dumping all 
>> alloc'ed. fragments:
>>
>> .....
>>
>> So I ran ngcp-update which fixed the issue, only now rate-o-mat crashes:
>> Oct 18 11:33:48 spce (info) ngcp-rate-o-mat[65715]: DBD::mysql::db do 
>> failed: Access denied; you need (at least one of) the SUPER, BINLOG 
>> ADMIN privilege(s) for this operation at /usr/sbin/ngcp-rate-o-mat 
>> line 288.
>> Oct 18 11:33:48 spce (info) ngcp-rate-o-mat[65715]: FATAL: error 
>> setting session binlog_format
>> Oct 18 11:33:48 spce (info) ngcp-rate-o-mat[65715]: INFO: Trying to 
>> connect to billing db...
>> Oct 18 11:34:09 spce (info) ngcp-rate-o-mat[66252]: DBD::mysql::db do 
>> failed: Access denied; you need (at least one of) the SUPER, BINLOG 
>> ADMIN privilege(s) for this operation at /usr/sbin/ngcp-rate-o-mat 
>> line 288.
>> Oct 18 11:34:09 spce (info) ngcp-rate-o-mat[66252]: FATAL: error 
>> setting session binlog_format
>> Oct 18 11:34:09 spce (info) ngcp-rate-o-mat[66252]: INFO: Trying to 
>> connect to billing db...
>> Oct 18 11:34:42 spce (info) ngcp-rate-o-mat[67355]: DBD::mysql::db do 
>> failed: Access denied; you need (at least one of) the SUPER, BINLOG 
>> ADMIN privilege(s) for this operation at /usr/sbin/ngcp-rate-o-mat 
>> line 288.
>> Oct 18 11:34:42 spce (info) ngcp-rate-o-mat[67355]: FATAL: error 
>> setting session binlog_format
>> Oct 18 11:34:42 spce (info) ngcp-rate-o-mat[67355]: INFO: Trying to 
>> connect to billing db...
>>
>> So, the image seems not very stable, but I was able to finish my test.
>> The call list for subscriber 1:
>>
>> Call List for c1 at test1654835032.example.org (1 12 1234567)
>> 115 1127654321    1121234567    0        cancel    2022-10-18 
>> 11:36:39.586    0:00:00 568301286-6062-11 at BA.A.B.CBC 0.00
>> 116    1121234567    1127654321    0        ok    2022-10-18 
>> 11:37:39.065    0:00:05.501    0.0    0.0    0.0    0.0 
>> DgOp_xBrhhPSWa5Df2TovQ..    0.00
>>
>> and for subscriber 2:
>>
>> Call List for c2 at test1654835032.example.org (1 12 7654321)
>> 115 1127654321    1121234567    0        cancel    2022-10-18 
>> 11:36:39.586    0:00:00 568301286-6062-11 at BA.A.B.CBC 0.00
>> 116    1121234567    1127654321    0        ok    2022-10-18 
>> 11:37:39.065    0:00:05.501    0.0    0.0    0.0    0.0 
>> DgOp_xBrhhPSWa5Df2TovQ..    0.00
>>
>> The relevant parts of the CDR record:
>> MariaDB [accounting]> select * from cdr where id=116\G;
>> *************************** 1. row ***************************
>>                                   id: 116
>>                          update_time: 2022-10-18 11:37:51
>>                       source_user_id: 
>> e5eb8a53-d91a-4460-83b0-eb84cbc9240a
>>                   source_provider_id: 1
>>        source_external_subscriber_id:
>>          source_external_contract_id:
>>                    source_account_id: 7
>>                          source_user: c1
>>                        source_domain: test1654835032.example.org
>>                           source_cli: 1121234567
>>                          source_clir: 0
>>                            source_ip: 10.0.1.10
>>
>>                      source_user_out: 1121234567
>>                  destination_user_id: 
>> a889b68d-9999-42a4-b897-e5c4bdb102f5
>>              destination_provider_id: 1
>>   destination_external_subscriber_id:
>>     destination_external_contract_id:
>>               destination_account_id: 7
>>                     destination_user: c2
>>                   destination_domain: test1654835032.example.org
>>              destination_user_dialed: 1127654321
>>                  destination_user_in: 1127654321
>>                destination_domain_in: test1654835032.example.org
>>
>>                 destination_user_out: c2
>>                       peer_auth_user:
>>                      peer_auth_realm:
>>                            call_type: call
>>                          call_status: ok
>>                            call_code: 200
>>                            init_time: 1666085853.906
>>                           start_time: 1666085859.065
>>                             duration: 5.501
>>                              call_id: DgOp_xBrhhPSWa5Df2TovQ..
>>
>> I hope this is enough to investigate, if you need any more logs just 
>> let me know.
>>
>> Regards,
>>
>> Henk Plessius
>>
>> On 17-Oct-22 17:23, Marco Capetta via Spce-user wrote:
>>> Hi Henk,
>>>
>>> Can you please detail a bit more?
>>> In the subscribers' call list you should get on one user an entry as 
>>> outgoing call and on the other user an entry as incoming call.
>>> If you check in the DB or in the exported records, how many CDRs do 
>>> you get in total for a single call?
>>>
>>> Thank you
>>> Regards
>>> Marco
>>>
>>>
>>> On 17/10/22 12:52, Henk wrote:
>>>> Hi all,
>>>>
>>>> I'm on mr9.5.4 and found that calls between subscribers from the 
>>>> same customer are appearing in both call lists, in my test the 
>>>> callee gets to see the record of the caller.
>>>>
>>>> The total cost for the callee in the CDR list will also not be 
>>>> correct, as the amount from the caller is added.
>>>>
>>>> Regards,
>>>>
>>>> Henk Plessius
>>>>
>>>>
>>>
>>>
>>
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.sipwise.com/pipermail/spce-user_lists.sipwise.com/attachments/20221019/f0fb7aa3/attachment-0001.html>


More information about the Spce-user mailing list