If still a problem, send again all the logs with debug=3.
Cheers,
Daniel
On 10.09.18 13:55, Marco Capetta wrote:
Hi Daniel,
sorry for the misunderstanding.
Attached to the mail you can find the full log of the affected call
with debug level 3 as requested.
Thank you again
Cheers,
Marco
On 09/10/2018 12:29 PM, Daniel-Constantin Mierla wrote:
>
> Hello,
>
> I need **all the logs**, not only those from acc module and
> script, but all the modules and core.
>
> Add also:
>
> log_prefix="{$mt $hdr(CSeq) $ci} "
>
> to be able to match log message with the request time.
>
> And again, send the logs only for the case that fails.
>
> Cheers,
> Daniel
>
> On 10.09.18 10:57, Marco Capetta wrote:
>> Hi Daniel,
>>
>> I applied your patch to our kamailio v5.1.4 because this is the
>> current version we are using.
>>
>>
>> This is the log + debug of the call when the two INVITEs are
>> leaving kamailio.
>> This part is common for both the call cases:
>>
>> Sep 10 10:33:21 sp1 proxy[7627]: NOTICE: <script>: Request
>> leaving server, M=INVITE fs='127.0.0.1:5062' du='127.0.0.1:5080'
>> - R=sip:43993003@10.50.16.134:5063 ID=1125655181(a)10.50.3.130
>> UA='YATE/5.4.0'
>> Sep 10 10:33:21 sp1 proxy[7627]: NOTICE: <script>: Request
>> leaving server, M=INVITE fs='127.0.0.1:5062' du='127.0.0.1:5080'
>> - R=sip:43993003@10.50.16.134:5063 ID=1125655181(a)10.50.3.130
>> UA='YATE/5.4.0'
>> Sep 10 10:33:21 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:684]:
>> tmcb_func(): acc callback called for t(0x7f7ac12b4220) event type
>> 2, reply code 100
>> Sep 10 10:33:21 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:414]:
>> should_acc_reply(): probing acc state - code: 100 flags: 0x802a
>> Sep 10 10:33:21 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:443]:
>> should_acc_reply(): early media acc is off
>> Sep 10 10:33:21 sp1 proxy[7627]: NOTICE: <script>: NAT-Reply -
>> S=100 - Trying M=INVITE IP=10.50.3.126:35901 (127.0.0.1:5080)
>> ID=1125655181(a)10.50.3.130 UA='<null>' DESTIP=127.0.0.1:5062
>> Sep 10 10:33:21 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:684]:
>> tmcb_func(): acc callback called for t(0x7f7ac12b4220) event type
>> 2, reply code 100
>> Sep 10 10:33:21 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:414]:
>> should_acc_reply(): probing acc state - code: 100 flags: 0x802a
>> Sep 10 10:33:21 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:443]:
>> should_acc_reply(): early media acc is off
>> Sep 10 10:33:21 sp1 proxy[7627]: NOTICE: <script>: NAT-Reply -
>> S=100 - Trying M=INVITE IP=10.50.3.126:35901 (127.0.0.1:5080)
>> ID=1125655181(a)10.50.3.130 UA='<null>' DESTIP=127.0.0.1:5062
>> Sep 10 10:33:21 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:684]:
>> tmcb_func(): acc callback called for t(0x7f7ac12b4220) event type
>> 2, reply code 180
>> Sep 10 10:33:21 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:414]:
>> should_acc_reply(): probing acc state - code: 180 flags: 0x802a
>> Sep 10 10:33:21 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:443]:
>> should_acc_reply(): early media acc is off
>> Sep 10 10:33:21 sp1 proxy[7627]: NOTICE: <script>: NAT-Reply -
>> S=180 - Ringing M=INVITE IP=10.50.3.126:35901 (127.0.0.1:5080)
>> ID=1125655181(a)10.50.3.130 UA='<null>' DESTIP=127.0.0.1:5062
>> Sep 10 10:33:21 sp1 proxy[7627]: NOTICE: <script>: Sending reply
>> S=180 M=INVITE fs='127.0.0.1:5062' du='127.0.0.1:<null>' -
>> ID=1125655181(a)10.50.3.130 UA='<null>'
>> Sep 10 10:33:21 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:684]:
>> tmcb_func(): acc callback called for t(0x7f7ac12b4220) event type
>> 512, reply code 180
>> Sep 10 10:33:21 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:414]:
>> should_acc_reply(): probing acc state - code: 180 flags: 0x802a
>> Sep 10 10:33:21 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:443]:
>> should_acc_reply(): early media acc is off
>> Sep 10 10:33:22 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:684]:
>> tmcb_func(): acc callback called for t(0x7f7ac12b4220) event type
>> 2, reply code 180
>> Sep 10 10:33:22 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:414]:
>> should_acc_reply(): probing acc state - code: 180 flags: 0x802a
>> Sep 10 10:33:22 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:443]:
>> should_acc_reply(): early media acc is off
>> Sep 10 10:33:22 sp1 proxy[7627]: NOTICE: <script>: NAT-Reply -
>> S=180 - Ringing M=INVITE IP=10.50.3.126:35901 (127.0.0.1:5080)
>> ID=1125655181(a)10.50.3.130 UA='Yealink SIP-T32G 32.70.1.33'
>> DESTIP=127.0.0.1:5062
>> Sep 10 10:33:22 sp1 proxy[7627]: NOTICE: <script>: Sending reply
>> S=180 M=INVITE fs='127.0.0.1:5062' du='127.0.0.1:<null>' -
>> ID=1125655181(a)10.50.3.130 UA='Yealink SIP-T32G 32.70.1.33'
>> Sep 10 10:33:22 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:684]:
>> tmcb_func(): acc callback called for t(0x7f7ac12b4220) event type
>> 512, reply code 180
>> Sep 10 10:33:22 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:414]:
>> should_acc_reply(): probing acc state - code: 180 flags: 0x802a
>> Sep 10 10:33:22 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:443]:
>> should_acc_reply(): early media acc is off
>>
>>
>>
>> In CASE 1, this is the log + debug printed when the call is
>> canceled from the caller:
>>
>> Sep 10 10:33:33 sp1 proxy[7627]: NOTICE: <script>: New request on
>> proxy - M=CANCEL R=sip:43993003@10.50.3.130
>> F=sip:43993004@10.50.3.130 T=sip:43993003@10.50.3.130
>> IP=127.0.0.1:5060 (127.0.0.1:5060) ID=1125655181(a)10.50.3.130
>> UA='<null>' DESTIP=127.0.0.1:5062
>> Sep 10 10:33:33 sp1 proxy[7627]: NOTICE: <script>: Sending reply
>> S=100 Trying fs='127.0.0.1:5062' du='127.0.0.1:5060' -
>> R=sip:43993003@10.50.3.130 ID=1125655181(a)10.50.3.130 UA='<null>'
>> Sep 10 10:33:33 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:684]:
>> tmcb_func(): acc callback called for t(0x7f7ac12c3318) event type
>> 512, reply code 200
>> Sep 10 10:33:33 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:414]:
>> should_acc_reply(): probing acc state - code: 200 flags: 0x0
>> Sep 10 10:33:33 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:436]:
>> should_acc_reply(): acc is off
>> Sep 10 10:33:33 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:684]:
>> tmcb_func(): acc callback called for t(0x7f7ac12b4220) event type
>> 2, reply code 200
>> Sep 10 10:33:33 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:414]:
>> should_acc_reply(): probing acc state - code: 200 flags: 0x802a
>> Sep 10 10:33:33 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:447]:
>> should_acc_reply(): acc is on
>> Sep 10 10:33:33 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:684]:
>> tmcb_func(): acc callback called for t(0x7f7ac12b4220) event type
>> 2, reply code 487
>> Sep 10 10:33:33 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:414]:
>> should_acc_reply(): probing acc state - code: 487 flags: 0x802a
>> Sep 10 10:33:33 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:431]:
>> should_acc_reply(): failed acc is on
>> Sep 10 10:33:33 sp1 proxy[7627]: NOTICE: <script>: NAT-Reply -
>> S=487 - Request terminated M=INVITE IP=10.50.3.126:35901
>> (127.0.0.1:5080) ID=1125655181(a)10.50.3.130 UA='<null>'
>> DESTIP=127.0.0.1:5062
>> Sep 10 10:33:33 sp1 proxy[7627]: NOTICE: <script>: Sending reply
>> S=487 M=INVITE fs='127.0.0.1:5062' du='127.0.0.1:<null>' -
>> ID=1125655181(a)10.50.3.130 UA='<null>'
>> Sep 10 10:33:33 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:684]:
>> tmcb_func(): acc callback called for t(0x7f7ac12b4220) event type
>> 2, reply code 200
>> Sep 10 10:33:33 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:414]:
>> should_acc_reply(): probing acc state - code: 200 flags: 0x802a
>> Sep 10 10:33:33 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:447]:
>> should_acc_reply(): acc is on
>> Sep 10 10:33:33 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:684]:
>> tmcb_func(): acc callback called for t(0x7f7ac12b4220) event type
>> 2, reply code 487
>> Sep 10 10:33:33 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:414]:
>> should_acc_reply(): probing acc state - code: 487 flags: 0x802a
>> Sep 10 10:33:33 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:431]:
>> should_acc_reply(): failed acc is on
>> Sep 10 10:33:33 sp1 proxy[7627]: NOTICE: <script>: NAT-Reply -
>> S=487 - Request terminated M=INVITE IP=10.50.3.126:35901
>> (127.0.0.1:5080) ID=1125655181(a)10.50.3.130 UA='<null>'
>> DESTIP=127.0.0.1:5062
>> Sep 10 10:33:33 sp1 proxy[7627]: NOTICE: <script>: Sending reply
>> S=487 M=INVITE fs='127.0.0.1:5062' du='127.0.0.1:<null>' -
>> ID=1125655181(a)10.50.3.130 UA='<null>'
>> Sep 10 10:33:33 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:684]:
>> tmcb_func(): acc callback called for t(0x7f7ac12b4220) event type
>> 128, reply code 487
>> Sep 10 10:33:33 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:477]:
>> on_missed(): preparing to report the record
>> Sep 10 10:33:33 sp1 proxy[7627]: NOTICE: <script>: Failure route
>> for local call, code='487' - R=sip:43993003@10.50.16.134:5063
>> ID=1125655181(a)10.50.3.130 UA='YATE/5.4.0'
>> Sep 10 10:33:33 sp1 proxy[7627]: NOTICE: <script>: Final reply -
>> R=sip:43993003@10.50.16.134:5063 ID=1125655181(a)10.50.3.130
>> UA='YATE/5.4.0'
>> Sep 10 10:33:33 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:684]:
>> tmcb_func(): acc callback called for t(0x7f7ac12b4220) event type
>> 512, reply code 487
>> Sep 10 10:33:33 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:414]:
>> should_acc_reply(): probing acc state - code: 487 flags: 0x802a
>> Sep 10 10:33:33 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:431]:
>> should_acc_reply(): failed acc is on
>> Sep 10 10:33:33 sp1 proxy[7627]: DEBUG: acc [acc_extra.h:63]:
>> free_strar_mem(): Freeing memory, type is 2, message_index 8,
>> index i 0
>> Sep 10 10:33:33 sp1 proxy[7627]: DEBUG: acc [acc_extra.h:63]:
>> free_strar_mem(): Freeing memory, type is 2, message_index 8,
>> index i 1
>> Sep 10 10:33:33 sp1 proxy[7627]: DEBUG: acc [acc_extra.h:63]:
>> free_strar_mem(): Freeing memory, type is 2, message_index 8,
>> index i 2
>> Sep 10 10:33:33 sp1 proxy[7627]: DEBUG: acc [acc_extra.h:63]:
>> free_strar_mem(): Freeing memory, type is 2, message_index 8,
>> index i 3
>> Sep 10 10:33:33 sp1 proxy[7627]: DEBUG: acc [acc_extra.h:63]:
>> free_strar_mem(): Freeing memory, type is 2, message_index 8,
>> index i 4
>> Sep 10 10:33:33 sp1 proxy[7627]: NOTICE: <script>: New request on
>> proxy - M=BYE
>>
R=sip:127.0.0.1:5062;lr=on;ftag=1714653723;did=2cc.ee71;ice_caller=strip;ice_callee=strip;aset=50;rtpprx=yes;vsf=bUViZ2VDb2dwTTNFYU5lTDRmbVVtRWJn
>> F=sip:43993004@10.50.3.130 T=sip:43993003@10.50.3.130
>> IP=127.0.0.1:5060 (127.0.0.1:5060) ID=1125655181(a)10.50.3.130
>> UA='YATE/5.4.0' DESTIP=127.0.0.1:5062
>> Sep 10 10:33:33 sp1 proxy[7627]: NOTICE: <script>: Sending reply
>> S=100 Trying fs='127.0.0.1:5062' du='127.0.0.1:5060' -
>>
R=sip:127.0.0.1:5062;lr=on;ftag=1714653723;did=2cc.ee71;ice_caller=strip;ice_callee=strip;aset=50;rtpprx=yes;vsf=bUViZ2VDb2dwTTNFYU5lTDRmbVVtRWJn
>> ID=1125655181(a)10.50.3.130 UA='YATE/5.4.0'
>> Sep 10 10:33:33 sp1 proxy[7627]: NOTICE: <script>: New request on
>> proxy - M=ACK R=sip:43993003@10.50.3.130
>> F=sip:43993004@10.50.3.130 T=sip:43993003@10.50.3.130
>> IP=127.0.0.1:5060 (127.0.0.1:5060) ID=1125655181(a)10.50.3.130
>> UA='<null>' DESTIP=127.0.0.1:5062
>>
>>
>>
>> In CASE 2, this is the log + debug printed when the call is
>> rejected from one of the callee and then canceled from the caller:
>>
>> Sep 10 10:35:35 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:684]:
>> tmcb_func(): acc callback called for t(0x7f7ac12bbec0) event type
>> 2, reply code 486
>> Sep 10 10:35:35 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:414]:
>> should_acc_reply(): probing acc state - code: 486 flags: 0x802a
>> Sep 10 10:35:35 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:431]:
>> should_acc_reply(): failed acc is on
>> Sep 10 10:35:35 sp1 proxy[7627]: NOTICE: <script>: NAT-Reply -
>> S=486 - Busy Here M=INVITE IP=10.50.3.126:35901 (127.0.0.1:5080)
>> ID=1929423861(a)10.50.3.130 UA='Yealink SIP-T32G 32.70.1.33'
>> DESTIP=127.0.0.1:5062
>> Sep 10 10:35:35 sp1 proxy[7627]: NOTICE: <script>: Sending reply
>> S=486 M=INVITE fs='127.0.0.1:5062' du='127.0.0.1:<null>' -
>> ID=1929423861(a)10.50.3.130 UA='Yealink SIP-T32G 32.70.1.33'
>>
>> Sep 10 10:35:43 sp1 proxy[7627]: NOTICE: <script>: New request on
>> proxy - M=CANCEL R=sip:43993003@10.50.3.130
>> F=sip:43993004@10.50.3.130 T=sip:43993003@10.50.3.130
>> IP=127.0.0.1:5060 (127.0.0.1:5060) ID=1929423861(a)10.50.3.130
>> UA='<null>' DESTIP=127.0.0.1:5062
>> Sep 10 10:35:43 sp1 proxy[7627]: NOTICE: <script>: Sending reply
>> S=100 Trying fs='127.0.0.1:5062' du='127.0.0.1:5060' -
>> R=sip:43993003@10.50.3.130 ID=1929423861(a)10.50.3.130 UA='<null>'
>> Sep 10 10:35:43 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:684]:
>> tmcb_func(): acc callback called for t(0x7f7ac12c6b30) event type
>> 512, reply code 200
>> Sep 10 10:35:43 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:414]:
>> should_acc_reply(): probing acc state - code: 200 flags: 0x0
>> Sep 10 10:35:43 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:436]:
>> should_acc_reply(): acc is off
>> Sep 10 10:35:43 sp1 proxy[7627]: NOTICE: <script>: New request on
>> proxy - M=BYE
>>
R=sip:127.0.0.1:5062;lr=on;ftag=1174240048;did=7bd.7c3;ice_caller=strip;ice_callee=strip;aset=50;rtpprx=yes;vsf=bUViZ2VDb2dwTTNFYU5lTDRmbVVtRWJn
>> F=sip:43993004@10.50.3.130 T=sip:43993003@10.50.3.130
>> IP=127.0.0.1:5060 (127.0.0.1:5060) ID=1929423861(a)10.50.3.130
>> UA='YATE/5.4.0' DESTIP=127.0.0.1:5062
>> Sep 10 10:35:43 sp1 proxy[7627]: NOTICE: <script>: Sending reply
>> S=100 Trying fs='127.0.0.1:5062' du='127.0.0.1:5060' -
>>
R=sip:127.0.0.1:5062;lr=on;ftag=1174240048;did=7bd.7c3;ice_caller=strip;ice_callee=strip;aset=50;rtpprx=yes;vsf=bUViZ2VDb2dwTTNFYU5lTDRmbVVtRWJn
>> ID=1929423861(a)10.50.3.130 UA='YATE/5.4.0'
>> Sep 10 10:35:43 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:684]:
>> tmcb_func(): acc callback called for t(0x7f7ac12bbec0) event type
>> 2, reply code 200
>> Sep 10 10:35:43 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:414]:
>> should_acc_reply(): probing acc state - code: 200 flags: 0x802a
>> Sep 10 10:35:43 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:447]:
>> should_acc_reply(): acc is on
>> Sep 10 10:35:43 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:684]:
>> tmcb_func(): acc callback called for t(0x7f7ac12bbec0) event type
>> 2, reply code 487
>> Sep 10 10:35:43 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:414]:
>> should_acc_reply(): probing acc state - code: 487 flags: 0x802a
>> Sep 10 10:35:43 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:431]:
>> should_acc_reply(): failed acc is on
>> Sep 10 10:35:43 sp1 proxy[7627]: NOTICE: <script>: NAT-Reply -
>> S=487 - Request terminated M=INVITE IP=10.50.3.126:35901
>> (127.0.0.1:5080) ID=1929423861(a)10.50.3.130 UA='<null>'
>> DESTIP=127.0.0.1:5062
>> Sep 10 10:35:43 sp1 proxy[7627]: NOTICE: <script>: Sending reply
>> S=487 M=INVITE fs='127.0.0.1:5062' du='127.0.0.1:<null>' -
>> ID=1929423861(a)10.50.3.130 UA='<null>'
>> Sep 10 10:35:43 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:684]:
>> tmcb_func(): acc callback called for t(0x7f7ac12bbec0) event type
>> 128, reply code 486
>> Sep 10 10:35:43 sp1 proxy[7627]: DEBUG: acc [acc_logic.c:477]:
>> on_missed(): preparing to report the record
>> Sep 10 10:35:43 sp1 proxy[7627]: NOTICE: <script>: Failure route
>> for local call, code='486' - R=sip:43993003@10.50.16.134:5063
>> ID=1929423861(a)10.50.3.130 UA='YATE/5.4.0'
>> Sep 10 10:35:43 sp1 proxy[7627]: NOTICE: <script>: Final reply -
>> R=sip:43993003@10.50.16.134:5063 ID=1929423861(a)10.50.3.130
>> UA='YATE/5.4.0'
>> Sep 10 10:35:43 sp1 proxy[7627]: NOTICE: <script>: New request on
>> proxy - M=ACK R=sip:43993003@10.50.3.130
>> F=sip:43993004@10.50.3.130 T=sip:43993003@10.50.3.130
>> IP=127.0.0.1:5060 (127.0.0.1:5060) ID=1929423861(a)10.50.3.130
>> UA='<null>' DESTIP=127.0.0.1:5062
>>
>>
>> Thank you
>> Marco
>>
>>
>>
>> On 09/10/2018 09:21 AM, Daniel-Constantin Mierla wrote:
>>>
>>> Hello,
>>>
>>> I pushed a patch to print more debug messages when testing if
>>> accounting should be done or not:
>>>
>>> -
>>>
https://github.com/kamailio/kamailio/commit/f21554c6befaddbc82016d5d498e11a…
>>>
>>> Can you test with it and send me all debug messages for the
>>> respective transaction in the case that doesn't work?
>>>
>>> Cheers,
>>> Daniel
>>>
>>>
>>> On 04.09.18 14:03, Marco Capetta wrote:
>>>> Hello,
>>>>
>>>> Yes Flag 3 is set at the very beginning when we start handling
>>>> the received INVITE message.
>>>> I checked and it is still active in both the branches of the
>>>> outgoing INVITEs.
>>>>
>>>>
>>>>
>>>> In the 1st case the following ACC is generated:
>>>> id: 311
>>>> method: INVITE
>>>> from_tag:
>>>> to_tag:
>>>> callid: 121700311(a)X.X.X.X
>>>> sip_code: 487
>>>> sip_reason: Request terminated
>>>> time: 2018-09-04 11:55:24
>>>> time_hires: 1536054924.342
>>>>
>>>>
>>>>
>>>> I missed to say in my previous email that in kamailio ACC
>>>> configuration we have also:
>>>> modparam("acc", "acc_prepare_always", 1)
>>>>
>>>>
>>>> Thanks
>>>> Marco
>>>>
>>>>
>>>>
>>>> On 09/04/2018 11:39 AM, Daniel-Constantin Mierla wrote:
>>>>> Hello,
>>>>>
>>>>> is flag 3 set for the INVITE transaction?
>>>>>
>>>>> In the 1st case, is the CANCEL accounted or the INVITE transaction or
both?
>>>>>
>>>>> Cheers,
>>>>> Daniel
>>>>>
>>>>>
>>>>> On 04.09.18 11:18, Marco Capetta wrote:
>>>>>> HiAll,
>>>>>>
>>>>>> As additional step I tested the scenario with kamailio v5.1.5 but
the
>>>>>> problem seems still there.
>>>>>>
>>>>>> Best regards.
>>>>>> Marco
>>>>>>
>>>>>>
>>>>>> On 08/28/2018 03:10 PM, Marco Capetta wrote:
>>>>>>> Hi All,
>>>>>>>
>>>>>>> I'm facing a strange problem of missing ACC record in
case of
>>>>>>> parallel call forking.
>>>>>>>
>>>>>>> The scenario is the following:
>>>>>>> - A subscriber with 1 device registered
>>>>>>> - B subscriber with 2 device registered (B1 and B2)
>>>>>>>
>>>>>>> CASE 1:
>>>>>>> - A calls B
>>>>>>> - B1 and B2 start ringing
>>>>>>> - A hangups the call before B1 or B2 answers
>>>>>>> Kamailio generates an ACC record.
>>>>>>>
>>>>>>> CASE 2:
>>>>>>> - A calls B
>>>>>>> - B1 and B2 start ringing
>>>>>>> - B1 rejects the call sending back a 486
>>>>>>> - B2 is still ringing
>>>>>>> - A hangups the call before B2 answers
>>>>>>> Kamailio DOESN'T generate an ACC record.
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>> We have Kamailio v5.1.4 with TM module enabled.
>>>>>>>
>>>>>>> ACC configuration is the following:
>>>>>>> modparam("acc", "early_media", 0)
>>>>>>> modparam("acc", "report_ack", 0)
>>>>>>> modparam("acc", "report_cancels", 1)
>>>>>>> modparam("acc", "detect_direction",
1)
>>>>>>> modparam("acc", "db_flag", 1)
>>>>>>> modparam("acc", "db_missed_flag", 2)
>>>>>>> modparam("acc",
"failed_transaction_flag", 3)
>>>>>>>
>>>>>>>
>>>>>>> I increased debug level of TM and ACC modules and I added
some debug
>>>>>>> lines as well.
>>>>>>> The difference between the two calls is that, after the
CANCEL sent
>>>>>>> by A is processed by Kamailio, in CASE 1 I have the following
lines:
>>>>>>> Aug 28 14:21:11 spce proxy[13188]: DEBUG: tm
[t_hooks.c:258]:
>>>>>>> run_trans_callbacks_internal(): DBG: trans=0x7f5a88049198,
callback
>>>>>>> type 512, id 0 entered
>>>>>>> Aug 28 14:21:11 spce proxy[13188]: DEBUG: acc
[acc_logic.c:670]:
>>>>>>> tmcb_func(): acc callback called for t(0x7f5a88049198) event
type
>>>>>>> 512, reply code 487
>>>>>>> Aug 28 14:21:11 spce proxy[13188]: DEBUG: acc
[acc_extra.h:63]:
>>>>>>> free_strar_mem(): Freeing memory, type is 2, message_index 8,
index i 0
>>>>>>> Aug 28 14:21:11 spce proxy[13188]: DEBUG: acc
[acc_extra.h:63]:
>>>>>>> free_strar_mem(): Freeing memory, type is 2, message_index 8,
index i 1
>>>>>>> Aug 28 14:21:11 spce proxy[13188]: DEBUG: acc
[acc_extra.h:63]:
>>>>>>> free_strar_mem(): Freeing memory, type is 2, message_index 8,
index i 2
>>>>>>> Aug 28 14:21:11 spce proxy[13188]: DEBUG: acc
[acc_extra.h:63]:
>>>>>>> free_strar_mem(): Freeing memory, type is 2, message_index 8,
index i 3
>>>>>>> Aug 28 14:21:11 spce proxy[13188]: DEBUG: acc
[acc_extra.h:63]:
>>>>>>> free_strar_mem(): Freeing memory, type is 2, message_index 8,
index i 4
>>>>>>>
>>>>>>> Those debug lines are not printed for CASE 2.
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>> Is there any configuration I'm missing or is it a bug?
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>> Thank you very much for your support.
>>>>>>> Marco
>>>>>>>
>>>>>> _______________________________________________
>>>>>> Kamailio (SER) - Users Mailing List
>>>>>> sr-users(a)lists.kamailio.org
>>>>>>
https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users
>>>>
>>>> --
>>>> *Marco Capetta *
>>>> Operations Engineer
>>>>
>>>> Sipwise GmbH <http://www.sipwise.com> , Campus 21/Europaring F15
>>>> AT-2345 Brunn am Gebirge
>>>>
>>>> Phone: +43(0)1 301 2044 <tel:+4313012044>
>>>> Email: mcapetta(a)sipwise.com <mailto:mcapetta@sipwise.com>
>>>> Website:
www.sipwise.com <http://www.sipwise.com>
>>>>
>>>> Particulars according Austrian Companies Code paragraph 14
>>>> "Sipwise GmbH" - Europaring F15 - 2345 Brunn am Gebirge
>>>> FN:305595f, Commercial Court Vienna, ATU64002206
>>>>
>>>
>>> --
>>> Daniel-Constantin Mierla --www.asipto.com
>>>
www.twitter.com/miconda --www.linkedin.com/in/miconda
>>> Kamailio World Conference --www.kamailioworld.com
>>> Kamailio Advanced Training, Nov 12-14, 2018, in Berlin --www.asipto.com
>>
>> --
>> *Marco Capetta *
>> Operations Engineer
>>
>> Sipwise GmbH <http://www.sipwise.com> , Campus 21/Europaring F15
>> AT-2345 Brunn am Gebirge
>>
>> Phone: +43(0)1 301 2044 <tel:+4313012044>
>> Email: mcapetta(a)sipwise.com <mailto:mcapetta@sipwise.com>
>> Website:
www.sipwise.com <http://www.sipwise.com>
>>
>> Particulars according Austrian Companies Code paragraph 14
>> "Sipwise GmbH" - Europaring F15 - 2345 Brunn am Gebirge
>> FN:305595f, Commercial Court Vienna, ATU64002206
>>
>
> --
> Daniel-Constantin Mierla --www.asipto.com
>
www.twitter.com/miconda --www.linkedin.com/in/miconda
> Kamailio World Conference --www.kamailioworld.com
> Kamailio Advanced Training, Nov 12-14, 2018, in Berlin --www.asipto.com
--
*Marco Capetta *
Operations Engineer
Sipwise GmbH <http://www.sipwise.com> , Campus 21/Europaring F15
AT-2345 Brunn am Gebirge
Phone: +43(0)1 301 2044 <tel:+4313012044>
Email: mcapetta(a)sipwise.com <mailto:mcapetta@sipwise.com>
Website:
www.sipwise.com <http://www.sipwise.com>
Particulars according Austrian Companies Code paragraph 14
"Sipwise GmbH" - Europaring F15 - 2345 Brunn am Gebirge
FN:305595f, Commercial Court Vienna, ATU64002206
--www.linkedin.com/in/miconda
Kamailio World Conference --www.kamailioworld.com
Kamailio Advanced Training, Nov 12-14, 2018, in Berlin --www.asipto.com