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

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

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

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/5b223a2e8a92f351b8eab756f5256fd… > > 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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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/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 <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(a)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(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 <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(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 <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(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 <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(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