[SR-Users] Missing ACC record in case of canceled call forking
Marco Capetta
mcapetta at sipwise.com
Tue Sep 11 13:39:42 CEST 2018
Hi Daniel,
with the latest patch it works fine. The ACC record has code 486 and
status Busy.
I'm not sure if in this case it would be better to report 487/Cancel or
486/Busy in the ACC, but in any case the record has been created.
Thank you very much for your help
Regards
Marco
On 09/10/2018 07:48 PM, Daniel-Constantin Mierla wrote:
>
> Hello,
>
> pushed another commit:
>
> -
> https://github.com/kamailio/kamailio/commit/35dec4c20d78f49ba242229c877894d70c94705c
>
> Give it a try and let's see the results.
>
> Cheers,
> Daniel
>
>
> On 10.09.18 16:08, Marco Capetta wrote:
>> Hello,
>>
>> the issue seems still there.
>> Please find attached the new log with debug 3.
>>
>> Thanks
>> Marco
>>
>>
>> On 09/10/2018 03:14 PM, Daniel-Constantin Mierla wrote:
>>>
>>> Hello,
>>>
>>> can you try with:
>>>
>>> https://github.com/kamailio/kamailio/commit/5b223a2e8a92f351b8eab756f5256fda7645ff21
>>>
>>> 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 at 10.50.16.134:5063 ID=1125655181 at 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 at 10.50.16.134:5063 ID=1125655181 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 10.50.3.130
>>>>>> F=sip:43993004 at 10.50.3.130 T=sip:43993003 at 10.50.3.130
>>>>>> IP=127.0.0.1:5060 (127.0.0.1:5060) ID=1125655181 at 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 at 10.50.3.130 ID=1125655181 at 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 at 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 at 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 at 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 at 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 at 10.50.16.134:5063
>>>>>> ID=1125655181 at 10.50.3.130 UA='YATE/5.4.0'
>>>>>> Sep 10 10:33:33 sp1 proxy[7627]: NOTICE: <script>: Final reply -
>>>>>> R=sip:43993003 at 10.50.16.134:5063 ID=1125655181 at 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 at 10.50.3.130 T=sip:43993003 at 10.50.3.130
>>>>>> IP=127.0.0.1:5060 (127.0.0.1:5060) ID=1125655181 at 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 at 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 at 10.50.3.130
>>>>>> F=sip:43993004 at 10.50.3.130 T=sip:43993003 at 10.50.3.130
>>>>>> IP=127.0.0.1:5060 (127.0.0.1:5060) ID=1125655181 at 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 at 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 at 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 at 10.50.3.130
>>>>>> F=sip:43993004 at 10.50.3.130 T=sip:43993003 at 10.50.3.130
>>>>>> IP=127.0.0.1:5060 (127.0.0.1:5060) ID=1929423861 at 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 at 10.50.3.130 ID=1929423861 at 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 at 10.50.3.130 T=sip:43993003 at 10.50.3.130
>>>>>> IP=127.0.0.1:5060 (127.0.0.1:5060) ID=1929423861 at 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 at 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 at 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 at 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 at 10.50.16.134:5063
>>>>>> ID=1929423861 at 10.50.3.130 UA='YATE/5.4.0'
>>>>>> Sep 10 10:35:43 sp1 proxy[7627]: NOTICE: <script>: Final reply -
>>>>>> R=sip:43993003 at 10.50.16.134:5063 ID=1929423861 at 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 at 10.50.3.130
>>>>>> F=sip:43993004 at 10.50.3.130 T=sip:43993003 at 10.50.3.130
>>>>>> IP=127.0.0.1:5060 (127.0.0.1:5060) ID=1929423861 at 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/f21554c6befaddbc82016d5d498e11ab3720c404
>>>>>>>
>>>>>>> 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 at 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 at 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 at sipwise.com <mailto:mcapetta at 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 at sipwise.com <mailto:mcapetta at 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 at sipwise.com <mailto:mcapetta at 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 at sipwise.com <mailto:mcapetta at 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 at sipwise.com <mailto:mcapetta at 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
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.kamailio.org/pipermail/sr-users/attachments/20180911/51ed05ea/attachment.html>
More information about the sr-users
mailing list