Hello,
ok, thanks for testing, I will backport to 5.1 ...
Cheers, Daniel
On 12.09.18 09:50, Marco Capetta wrote:
Hello,
yes, a "486 Busy Here" message is sent back to the caller as final reply.
Thanks
Cheers Marco
On 09/11/2018 05:20 PM, Daniel-Constantin Mierla wrote:
Hello,
Can you look on the wire and see what reply code is sent to caller? That should be accounted.
Cheers, Daniel
On 11 Sep 2018 1:39 pm, "Marco Capetta" <mcapetta@sipwise.com mailto:mcapetta@sipwise.com> wrote:
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 >> http://127.0.0.1:5062' du='127.0.0.1:5080 >> http://127.0.0.1:5080' - R=sip:43993003@10.50.16.134:5063 >> mailto:R=sip:43993003@10.50.16.134:5063 >> ID=1125655181@10.50.3.130 >> mailto:ID=1125655181@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 >> http://127.0.0.1:5062' du='127.0.0.1:5080 >> http://127.0.0.1:5080' - R=sip:43993003@10.50.16.134:5063 >> mailto:R=sip:43993003@10.50.16.134:5063 >> ID=1125655181@10.50.3.130 >> mailto:ID=1125655181@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 >> http://10.50.3.126:35901 (127.0.0.1:5080 >> http://127.0.0.1:5080) ID=1125655181@10.50.3.130 >> mailto:ID=1125655181@10.50.3.130 UA='<null>' >> DESTIP=127.0.0.1:5062 http://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 >> http://10.50.3.126:35901 (127.0.0.1:5080 >> http://127.0.0.1:5080) ID=1125655181@10.50.3.130 >> mailto:ID=1125655181@10.50.3.130 UA='<null>' >> DESTIP=127.0.0.1:5062 http://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 >> http://10.50.3.126:35901 (127.0.0.1:5080 >> http://127.0.0.1:5080) ID=1125655181@10.50.3.130 >> mailto:ID=1125655181@10.50.3.130 UA='<null>' >> DESTIP=127.0.0.1:5062 http://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 >> http://127.0.0.1:5062' du='127.0.0.1 >> http://127.0.0.1:<null>' - ID=1125655181@10.50.3.130 >> mailto:ID=1125655181@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 >> http://10.50.3.126:35901 (127.0.0.1:5080 >> http://127.0.0.1:5080) ID=1125655181@10.50.3.130 >> mailto:ID=1125655181@10.50.3.130 UA='Yealink SIP-T32G >> 32.70.1.33' DESTIP=127.0.0.1:5062 http://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 >> http://127.0.0.1:5062' du='127.0.0.1 >> http://127.0.0.1:<null>' - ID=1125655181@10.50.3.130 >> mailto:ID=1125655181@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 >> mailto:R=sip:43993003@10.50.3.130 >> F=sip:43993004@10.50.3.130 >> mailto:F=sip:43993004@10.50.3.130 >> T=sip:43993003@10.50.3.130 >> mailto:T=sip:43993003@10.50.3.130 IP=127.0.0.1:5060 >> http://127.0.0.1:5060 (127.0.0.1:5060 >> http://127.0.0.1:5060) ID=1125655181@10.50.3.130 >> mailto:ID=1125655181@10.50.3.130 UA='<null>' >> DESTIP=127.0.0.1:5062 http://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 >> http://127.0.0.1:5062' du='127.0.0.1:5060 >> http://127.0.0.1:5060' - R=sip:43993003@10.50.3.130 >> mailto:R=sip:43993003@10.50.3.130 >> ID=1125655181@10.50.3.130 >> mailto:ID=1125655181@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 http://10.50.3.126:35901 >> (127.0.0.1:5080 http://127.0.0.1:5080) >> ID=1125655181@10.50.3.130 >> mailto:ID=1125655181@10.50.3.130 UA='<null>' >> DESTIP=127.0.0.1:5062 http://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 >> http://127.0.0.1:5062' du='127.0.0.1 >> http://127.0.0.1:<null>' - ID=1125655181@10.50.3.130 >> mailto:ID=1125655181@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 http://10.50.3.126:35901 >> (127.0.0.1:5080 http://127.0.0.1:5080) >> ID=1125655181@10.50.3.130 >> mailto:ID=1125655181@10.50.3.130 UA='<null>' >> DESTIP=127.0.0.1:5062 http://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 >> http://127.0.0.1:5062' du='127.0.0.1 >> http://127.0.0.1:<null>' - ID=1125655181@10.50.3.130 >> mailto:ID=1125655181@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 >> mailto:R=sip:43993003@10.50.16.134:5063 >> ID=1125655181@10.50.3.130 >> mailto:ID=1125655181@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 >> mailto:R=sip:43993003@10.50.16.134:5063 >> ID=1125655181@10.50.3.130 >> mailto:ID=1125655181@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 >> mailto:F=sip:43993004@10.50.3.130 >> T=sip:43993003@10.50.3.130 >> mailto:T=sip:43993003@10.50.3.130 IP=127.0.0.1:5060 >> http://127.0.0.1:5060 (127.0.0.1:5060 >> http://127.0.0.1:5060) ID=1125655181@10.50.3.130 >> mailto:ID=1125655181@10.50.3.130 UA='YATE/5.4.0' >> DESTIP=127.0.0.1:5062 http://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 >> http://127.0.0.1:5062' du='127.0.0.1:5060 >> http://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@10.50.3.130 >> mailto:ID=1125655181@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 >> mailto:R=sip:43993003@10.50.3.130 >> F=sip:43993004@10.50.3.130 >> mailto:F=sip:43993004@10.50.3.130 >> T=sip:43993003@10.50.3.130 >> mailto:T=sip:43993003@10.50.3.130 IP=127.0.0.1:5060 >> http://127.0.0.1:5060 (127.0.0.1:5060 >> http://127.0.0.1:5060) ID=1125655181@10.50.3.130 >> mailto:ID=1125655181@10.50.3.130 UA='<null>' >> DESTIP=127.0.0.1:5062 http://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 >> http://10.50.3.126:35901 (127.0.0.1:5080 >> http://127.0.0.1:5080) ID=1929423861@10.50.3.130 >> mailto:ID=1929423861@10.50.3.130 UA='Yealink SIP-T32G >> 32.70.1.33' DESTIP=127.0.0.1:5062 http://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 >> http://127.0.0.1:5062' du='127.0.0.1 >> http://127.0.0.1:<null>' - ID=1929423861@10.50.3.130 >> mailto:ID=1929423861@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 >> mailto:R=sip:43993003@10.50.3.130 >> F=sip:43993004@10.50.3.130 >> mailto:F=sip:43993004@10.50.3.130 >> T=sip:43993003@10.50.3.130 >> mailto:T=sip:43993003@10.50.3.130 IP=127.0.0.1:5060 >> http://127.0.0.1:5060 (127.0.0.1:5060 >> http://127.0.0.1:5060) ID=1929423861@10.50.3.130 >> mailto:ID=1929423861@10.50.3.130 UA='<null>' >> DESTIP=127.0.0.1:5062 http://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 >> http://127.0.0.1:5062' du='127.0.0.1:5060 >> http://127.0.0.1:5060' - R=sip:43993003@10.50.3.130 >> mailto:R=sip:43993003@10.50.3.130 >> ID=1929423861@10.50.3.130 >> mailto:ID=1929423861@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 >> mailto:F=sip:43993004@10.50.3.130 >> T=sip:43993003@10.50.3.130 >> mailto:T=sip:43993003@10.50.3.130 IP=127.0.0.1:5060 >> http://127.0.0.1:5060 (127.0.0.1:5060 >> http://127.0.0.1:5060) ID=1929423861@10.50.3.130 >> mailto:ID=1929423861@10.50.3.130 UA='YATE/5.4.0' >> DESTIP=127.0.0.1:5062 http://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 >> http://127.0.0.1:5062' du='127.0.0.1:5060 >> http://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@10.50.3.130 >> mailto:ID=1929423861@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 http://10.50.3.126:35901 >> (127.0.0.1:5080 http://127.0.0.1:5080) >> ID=1929423861@10.50.3.130 >> mailto:ID=1929423861@10.50.3.130 UA='<null>' >> DESTIP=127.0.0.1:5062 http://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 >> http://127.0.0.1:5062' du='127.0.0.1 >> http://127.0.0.1:<null>' - ID=1929423861@10.50.3.130 >> mailto:ID=1929423861@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 >> mailto:R=sip:43993003@10.50.16.134:5063 >> ID=1929423861@10.50.3.130 >> mailto:ID=1929423861@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 >> mailto:R=sip:43993003@10.50.16.134:5063 >> ID=1929423861@10.50.3.130 >> mailto:ID=1929423861@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 >> mailto:R=sip:43993003@10.50.3.130 >> F=sip:43993004@10.50.3.130 >> mailto:F=sip:43993004@10.50.3.130 >> T=sip:43993003@10.50.3.130 >> mailto:T=sip:43993003@10.50.3.130 IP=127.0.0.1:5060 >> http://127.0.0.1:5060 (127.0.0.1:5060 >> http://127.0.0.1:5060) ID=1929423861@10.50.3.130 >> mailto:ID=1929423861@10.50.3.130 UA='<null>' >> DESTIP=127.0.0.1:5062 http://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/f21554c6befaddbc82016d5d498e11ab... >>> >>> 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@X.X.X.X mailto:121700311@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@lists.kamailio.org >>>>>> mailto:sr-users@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@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 http://www.asipto.com >>> www.twitter.com/miconda http://www.twitter.com/miconda -- www.linkedin.com/in/miconda >>> http://www.linkedin.com/in/miconda >>> Kamailio World Conference -- www.kamailioworld.com http://www.kamailioworld.com >>> Kamailio Advanced Training, Nov 12-14, 2018, in Berlin -- www.asipto.com http://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@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 http://www.asipto.com > www.twitter.com/miconda http://www.twitter.com/miconda -- www.linkedin.com/in/miconda http://www.linkedin.com/in/miconda > Kamailio World Conference -- www.kamailioworld.com http://www.kamailioworld.com > Kamailio Advanced Training, Nov 12-14, 2018, in Berlin -- www.asipto.com http://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@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 <http://www.asipto.com> www.twitter.com/miconda <http://www.twitter.com/miconda> -- www.linkedin.com/in/miconda <http://www.linkedin.com/in/miconda> Kamailio World Conference -- www.kamailioworld.com <http://www.kamailioworld.com> Kamailio Advanced Training, Nov 12-14, 2018, in Berlin -- www.asipto.com <http://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@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 <http://www.asipto.com> www.twitter.com/miconda <http://www.twitter.com/miconda> -- www.linkedin.com/in/miconda <http://www.linkedin.com/in/miconda> Kamailio World Conference -- www.kamailioworld.com <http://www.kamailioworld.com> Kamailio Advanced Training, Nov 12-14, 2018, in Berlin -- www.asipto.com <http://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@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-- *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@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