Hi all,
I am still looking for some help to debug why S-CSCF send BYE to caller and callee after a call was connected. from wireshark, I just saw S-CSCF send BYE to both caller and callee. That matched the S-CSCF debug output. But the question is why S-CSCF delete contact and send BYE to a active call? There was no timer expire or something like that in the log... Anyone can help?
Thanks,
--Charles
19(24) DEBUG: <core> [core/mem/q_malloc.c:519]: qm_free(): freeing frag. 0x7fb09413e6d0 alloc'ed from cdp: diameter_msg.c: AAATranslateMessage(484)
19(24) DEBUG: tm [t_lookup.c:1618]: t_lookup_ident(): transaction found
19(24) DEBUG: <core> [core/mem/q_malloc.c:367]: qm_malloc(): qm_malloc(0x7fb093db6000, 6872) called from core: core/sip_msg_clone.c: sip_msg_shm_clone(496)
19(24) DEBUG: <core> [core/mem/q_malloc.c:412]: qm_malloc(): qm_malloc(0x7fb093db6000, 6872) returns address 0x7fb09414d450 frag. 0x7fb09414d418 (size=6872) on 1 -th hit
19(24) ERROR: *** cfgtrace:failure_route=[REG_SAR_REPLY] c=[/etc/kamailio/kamailio.cfg] l=767 a=26 n=xlog
19(24) DEBUG: <script>: saa_return code is 1
19(24) ERROR: *** cfgtrace:failure_route=[REG_SAR_REPLY] c=[/etc/kamailio/kamailio.cfg] l=769 a=26 n=xlog
19(24) DEBUG: <script>: saa_return code (for scscf_save on register) is 1
19(24) ERROR: *** cfgtrace:failure_route=[REG_SAR_REPLY] c=[/etc/kamailio/kamailio.cfg] l=783 a=21 n=switch
19(24) ERROR: *** cfgtrace:failure_route=[REG_SAR_REPLY] c=[/etc/kamailio/kamailio.cfg] l=772 a=26 n=xlog
19(24) DEBUG: <script>: SAR success - 200 response sent from module
19(24) ERROR: *** cfgtrace:failure_route=[REG_SAR_REPLY] c=[/etc/kamailio/kamailio.cfg] l=773 a=2 n=exit
19(24) DEBUG: <core> [core/mem/q_malloc.c:475]: qm_free(): qm_free(0x7fb093db6000, 0x7fb09414d450), called from tm: t_reply.c: free_faked_req(948)
19(24) DEBUG: <core> [core/mem/q_malloc.c:519]: qm_free(): freeing frag. 0x7fb09414d418 alloc'ed from core: core/sip_msg_clone.c: sip_msg_shm_clone(496)
19(24) DEBUG: <core> [core/mem/q_malloc.c:475]: qm_free(): qm_free(0x7fb093db6000, 0x7fb09413e978), called from ims_registrar_scscf: cxdx_sar.c: free_saved_transaction_data(94)
19(24) DEBUG: <core> [core/mem/q_malloc.c:519]: qm_free(): freeing frag. 0x7fb09413e940 alloc'ed from ims_registrar_scscf: save.c: save(1414)
19(24) DEBUG: <core> [core/mem/q_malloc.c:475]: qm_free(): qm_free(0x7fb093db6000, 0x7fb09413e0b0), called from ims_registrar_scscf: reply.c: free_contact_buf(830)
19(24) DEBUG: <core> [core/mem/q_malloc.c:519]: qm_free(): freeing frag. 0x7fb09413e078 alloc'ed from ims_registrar_scscf: reply.c: build_contact(443)
19(24) DEBUG: <core> [core/mem/q_malloc.c:475]: qm_free(): qm_free(0x7fb093db6000, 0x7fb094145218), called from ims_registrar_scscf: reply.c: free_contact_buf(835)
19(24) DEBUG: <core> [core/mem/q_malloc.c:519]: qm_free(): freeing frag. 0x7fb0941451e0 alloc'ed from ims_registrar_scscf: reply.c: build_contact(435)
19(24) DEBUG: <core> [core/mem/q_malloc.c:475]: qm_free(): qm_free(0x7fb093db6000, 0x7fb094147dc0), called from ims_registrar_scscf: cxdx_sar.c: free_saved_transaction_data(98)
19(24) DEBUG: <core> [core/mem/q_malloc.c:519]: qm_free(): freeing frag. 0x7fb094147d88 alloc'ed from ims_registrar_scscf: save.c: save(1396)
19(24) DEBUG: <core> [core/mem/q_malloc.c:475]: qm_free(): qm_free(0x7fb093db6000, 0x7fb09415b4c8), called from cdp: transaction.c: cdp_free_trans(182)
19(24) DEBUG: <core> [core/mem/q_malloc.c:519]: qm_free(): freeing frag. 0x7fb09415b490 alloc'ed from cdp: transaction.c: cdp_add_trans(110)
19(24) DEBUG: <core> [core/mem/q_malloc.c:475]: qm_free(): qm_free(0x7fb093db6000, 0x7fb0941442a0), called from cdp: transaction.c: cdp_free_trans(183)
19(24) DEBUG: <core> [core/mem/q_malloc.c:519]: qm_free(): freeing frag. 0x7fb094144268 alloc'ed from cdp: transaction.c: cdp_add_trans(105)
13(18) DEBUG: ims_usrloc_scscf [ims_usrloc_scscf_mod.c:481]: timer(): Syncing cache
13(18) DEBUG: ims_usrloc_scscf [udomain.c:291]: mem_timer_udomain(): *** mem_timer_udomain - checking contacts - START ***
13(18) DEBUG: ims_usrloc_scscf [udomain.c:301]: mem_timer_udomain(): We have a [3gpp=0] contact in the new contact list in slot 95 = [sip:bob@ims.mnc001.mnc001.3gppnetwork.org] (sip:bob@192.168.164.248:50448;rinstance=989f943bd5098a11;transport=UDP) which expires in -60.000000 seconds and has a ref count of 0 (state: Contact with delayed delete)
13(18) DEBUG: ims_usrloc_scscf [udomain.c:309]: mem_timer_udomain(): contact in state CONTACT_DELATED_DELETE is about to be deleted13(18) DEBUG: ims_usrloc_scscf [udomain.c:301]: mem_timer_udomain(): We have a [3gpp=0] contact in the new contact list in slot 464 = [sip:alice@ims.mnc001.mnc001.3gppnetwork.org] (sip:alice@192.168.164.203:44640;rinstance=e35e9704884c3208;transport=UDP) which expires in 50.000000 seconds and has a ref count of 1 (state: Contact valid)
13(18) DEBUG: ims_usrloc_scscf [udomain.c:301]: mem_timer_udomain(): We have a [3gpp=0] contact in the new contact list in slot 478 = [sip:bob@ims.mnc001.mnc001.3gppnetwork.org] (sip:bob@192.168.164.248:50448;rinstance=9e742618a5f6bcae;transport=UDP) which expires in 56.000000 seconds and has a ref count of 1 (state: Contact valid)
13(18) DEBUG: ims_usrloc_scscf [udomain.c:353]: mem_timer_udomain(): *** mem_timer_udomain - checking contacts - FINISHED ***
13(18) DEBUG: ims_usrloc_scscf [udomain.c:359]: mem_timer_udomain(): *** mem_timer_udomain - checking IMPUs - START ***
13(18) DEBUG: ims_usrloc_scscf [impurecord.c:372]: process_impurecord(): Checking validity of IMPU: <sip:alice@ims.mnc001.mnc001.3gppnetwork.org> registration subscriptions
13(18) DEBUG: ims_usrloc_scscf [impurecord.c:404]: process_impurecord(): Public Identity sip:alice@ims.mnc001.mnc001.3gppnetwork.org, Barred: [0], State: [registered], contacts [1], 3gppcontacts [0]
13(18) DEBUG: ims_usrloc_scscf [impurecord.c:441]: process_impurecord(): Contact #0 - sip:alice@192.168.164.203:44640;rinstance=e35e9704884c3208;transport=UDP, Ref [1] (expires in 50 seconds) (State: 0)
13(18) DEBUG: ims_usrloc_scscf [impurecord.c:372]: process_impurecord(): Checking validity of IMPU: <sip:bob@ims.mnc001.mnc001.3gppnetwork.org> registration subscriptions
13(18) DEBUG: ims_usrloc_scscf [impurecord.c:404]: process_impurecord(): Public Identity sip:bob@ims.mnc001.mnc001.3gppnetwork.org, Barred: [0], State: [registered], contacts [1], 3gppcontacts [0]
3(18) DEBUG: ims_usrloc_scscf [impurecord.c:441]: process_impurecord(): Contact #0 - sip:bob@192.168.164.248:50448;rinstance=9e742618a5f6bcae;transport=UDP, Ref [1] (expires in 56 seconds) (State: 0)
3(18) DEBUG: ims_usrloc_scscf [udomain.c:384]: mem_timer_udomain(): *** mem_timer_udomain - checking IMPUs - FINISHED ***
3(18) DEBUG: ims_usrloc_scscf [udomain.c:406]: mem_timer_udomain(): deleting contact [sip:bob@ims.mnc001.mnc001.3gppnetwork.org]
13(18) DEBUG: ims_usrloc_scscf [impurecord.c:598]: delete_scontact(): Deleting contact: [sip:bob@192.168.164.248:50448;rinstance=989f943bd5098a11;transport=UDP]
13(18) DEBUG: ims_usrloc_scscf [usrloc_db.c:370]: db_delete_ucontact(): Deleting ucontact [sip:bob@192.168.164.248:50448;rinstance=989f943bd5098a11;transport=UDP]
13(18) DEBUG: ims_usrloc_scscf [impurecord.c:310]: mem_delete_ucontact(): Checking if dialog_data is there and needs to be torn down
13(18) DEBUG: ims_usrloc_scscf [impurecord.c:314]: mem_delete_ucontact(): first dialog is not 0
13(18) DEBUG: ims_usrloc_scscf [impurecord.c:317]: mem_delete_ucontact(): Going to tear down dialog with info h_entry [1694] h_id [3889]
13(18) DEBUG: ims_dialog [dlg_hash.c:887]: lookup_dlg(): ref dlg 0x7fb09414ce40 with 1 -> 3
13(18) DEBUG: ims_dialog [dlg_hash.c:889]: lookup_dlg(): dialog id=3889 found on entry 1694
13(18) DEBUG: ims_dialog [dlg_hash.c:1066]: unref_dlg(): unref dlg 0x7fb09414ce40 with 1 -> 2
13(18) DEBUG: ims_dialog [dlg_req_within.c:379]: dlg_terminate(): terminating confirmed dialog
13(18) DEBUG: <core> [core/mem/q_malloc.c:367]: qm_malloc(): qm_malloc(0x7fb09b5ae010, 18) called from ims_dialog: dlg_req_within.c: build_extra_hdr(229)
13(18) DEBUG: <core> [core/mem/q_malloc.c:412]: qm_malloc(): qm_malloc(0x7fb09b5ae010, 24) returns address 0x7fb09b640c30 frag. 0x7fb09b640bf8 (size=64) on 1 -th hit
13(18) DEBUG: <core> [core/mem/q_malloc.c:367]: qm_malloc(): qm_malloc(0x7fb09b5ae010, 248) called from ims_dialog: dlg_req_within.c: build_dlg_t(81)
13(18) DEBUG: <core> [core/mem/q_malloc.c:412]: qm_malloc(): qm_malloc(0x7fb09b5ae010, 248) returns address 0x7fb09b74b100 frag. 0x7fb09b74b0c8 (size=248) on 1 -th hit
13(18) DEBUG: <core> [core/mem/q_malloc.c:367]: qm_malloc(): qm_malloc(0x7fb09b5ae010, 72) called from core: core/parser/parse_rr.c: do_parse_rr_body(68)
13(18) DEBUG: <core> [core/mem/q_malloc.c:412]: qm_malloc(): qm_malloc(0x7fb09b5ae010, 72) returns address 0x7fb09b74b048 frag. 0x7fb09b74b010 (size=80) on 1 -th hit
13(18) DEBUG: ims_dialog [dlg_req_within.c:272]: send_bye(): sending BYE to caller
13(18) DEBUG: ims_dialog [dlg_hash.c:1047]: ref_dlg(): ref dlg 0x7fb09414ce40 with 1 -> 3
CONFIDENTIALITY NOTICE: This email and any attachments are for the sole use of the intended recipient and may contain material that is proprietary, confidential, privileged or otherwise legally protected or restricted under applicable government laws. Any review, disclosure, distributing or other use without expressed permission of the sender is strictly prohibited. If you are not the intended recipient, please contact the sender and delete all copies without reading, printing, or saving.
