Hi Alberto,
Thanks for your answer.
I installed the last Kamailio release and it solves my issue.
Regards
Anthony
From: sr-users <sr-users-bounces@lists.kamailio.org>
On Behalf Of Alberto Diez
Sent: Monday, 24 October 2022 09:54
To: sr-users@lists.kamailio.org
Subject: Re: [SR-Users] No REGISTER sent to third party AS from scscf
Vous ne recevez pas souvent de courriers de la part de
alberto-lists@mobileplots.com.
Découvrez pourquoi cela est important |
Hi Anthony,
In a system I have 3rd party registrations work, so I was curious what happens in your case. My conclusion is that you have a version of the code prior to this patches here below:
https://github.com/kamailio/kamailio/commit/2067f110336244826b183a649cb987fac94ffe1c
https://github.com/kamailio/kamailio/commit/89421e184a8b47557dcfc6c348d60dde347a9417
You need those patches, actually just update the modules you use to the latest because I am not sure of all the dependencies and the tm module...
If you do have those patches your log makes no sense to me :D.
Here explained:
The S-CSCF in the file save.c line 1474 calls t_suspend from the TM module which sets the transaction to suspended (we are on the reply to the REGISTER here). When it receives the Successful Diameter answer for the SAR then it tries to recover that transaction
calling t_continue_skip_timer from the TM module (line 289 in file cxdx_sar.c), this one calls t_continue_helper (tm/t_suspend.c ) which ends up calling t_lookup_ident_filter ... this function is from 2019, before it was only t_lookup_ident which doesn't
exist anymore and calls t_lookup_ident_filter.
Best regards
alberto
El 20/10/2022 a las 12:25, Anthony Blandin escribió:
Hello,
Here are the logs. It seems that after the save("PRE_REG_SAR_REPLY","location") function, the route PRE_REG_SAR_REPLY is not applied.
scscf1-airnity-slice-data-par 3(45) ERROR: <script>: Not REGISTERED
scscf1-airnity-slice-data-par 3(45) DEBUG: ims_registrar_scscf [save.c:1269]: save(): Looking for route block [PRE_REG_SAR_REPLY]
scscf1-airnity-slice-data-par 3(45) DEBUG: ims_registrar_scscf [save.c:1326]: save(): preparing for SAR assignment for new REGISTRATION sip:901810000000022@ims.mnc081.mcc901.3gppnetwork.org
scscf1-airnity-slice-data-par 3(45) DEBUG: tm [t_lookup.c:1328]: t_newtran(): msg (0x7f77335df348) id=3/45 global id=3/45 T start=(nil)
scscf1-airnity-slice-data-par 3(45) DEBUG: tm [t_lookup.c:497]: t_lookup_request(): start searching: hash=5727, isACK=0
scscf1-airnity-slice-data-par 3(45) DEBUG: tm [t_lookup.c:455]: matching_3261(): RFC3261 transaction matching failed - via branch [z9hG4bKf561.0ec3b0f8ee4f189c6053ab447b478699.0]
scscf1-airnity-slice-data-par 3(45) DEBUG: tm [t_lookup.c:675]: t_lookup_request(): no transaction found
scscf1-airnity-slice-data-par 3(45) DEBUG: tm [t_hooks.c:336]: run_reqin_callbacks_internal(): trans=0x7f772c08aad0, callback type 1, id 0 entered
scscf1-airnity-slice-data-par 3(45) INFO: ims_registrar_scscf [cxdx_sar.c:84]: create_return_code(): created AVP successfully : [saa_return_code] - [-2]
scscf1-airnity-slice-data-par 3(45) DEBUG: ims_registrar_scscf [save.c:1430]: save(): Suspending SIP TM transaction with index [0] and label [0]
scscf1-airnity-slice-data-par 3(45) DEBUG: cdp [session.c:284]: cdp_add_session(): adding a session with id scscf.ims.mnc081.mcc901.3gppnetwork.org;3181552081;2
scscf1-airnity-slice-data-par 3(45) DEBUG: tm [t_lookup.c:1034]: t_check_msg(): msg (0x7f77335df348) id=3/45 global id=3/45 T start=0x7f772c08aad0
scscf1-airnity-slice-data-par 3(45) DEBUG: tm [t_lookup.c:1109]: t_check_msg(): T (0x7f772c08aad0) already found for msg (0x7f77335df348)!
scscf1-airnity-slice-data-par 3(45) DEBUG: cdp [session.c:305]: cdp_get_session(): called get session with id scscf.ims.mnc081.mcc901.3gppnetwork.org;3181552081;2 and hash 12
scscf1-airnity-slice-data-par 3(45) DEBUG: cdp [session.c:314]: cdp_get_session(): no session found
scscf1-airnity-slice-data-par 3(45) DEBUG: cdp [routing.c:202]: get_routing_peer(): getting diameter routing peer for realm: [ims.mnc081.mcc901.3gppnetwork.org]
scscf1-airnity-slice-data-par 3(45) DEBUG: cdp [routing.c:271]: get_routing_peer(): no routing peer found, trying default route
scscf1-airnity-slice-data-par 3(45) DEBUG: cdp [routing.c:128]: get_first_connected_route(): The peer dra2_slice_par01.epc.mnc081.mcc901.3gppnetwork.org state is opened
scscf1-airnity-slice-data-par 3(45) DEBUG: cdp [routing.c:83]: peer_handles_application(): Checking if peer dra2_slice_par01.epc.mnc081.mcc901.3gppnetwork.org handles application 16777216 for vendord 10415
scscf1-airnity-slice-data-par 3(45) DEBUG: cdp [routing.c:131]: get_first_connected_route(): The peer dra2_slice_par01.epc.mnc081.mcc901.3gppnetwork.org matches - will forward there
scscf1-airnity-slice-data-par 3(45) DEBUG: cdp [routing.c:128]: get_first_connected_route(): The peer dra1_slice_par01.epc.mnc081.mcc901.3gppnetwork.org state is opened
scscf1-airnity-slice-data-par 3(45) DEBUG: cdp [routing.c:83]: peer_handles_application(): Checking if peer dra1_slice_par01.epc.mnc081.mcc901.3gppnetwork.org handles application 16777216 for vendord 10415
scscf1-airnity-slice-data-par 3(45) DEBUG: cdp [routing.c:131]: get_first_connected_route(): The peer dra1_slice_par01.epc.mnc081.mcc901.3gppnetwork.org matches - will forward there
scscf1-airnity-slice-data-par 3(45) DEBUG: cdp [routing.c:149]: get_first_connected_route(): peer [dra2_slice_par01.epc.mnc081.mcc901.3gppnetwork.org] was last used @ 1666163272179072
scscf1-airnity-slice-data-par 3(45) DEBUG: cdp [routing.c:152]: get_first_connected_route(): Peer [dra1_slice_par01.epc.mnc081.mcc901.3gppnetwork.org] was last used at [0]
scscf1-airnity-slice-data-par 3(45) DEBUG: cdp [routing.c:162]: get_first_connected_route(): chosen peer [dra1_slice_par01.epc.mnc081.mcc901.3gppnetwork.org]
scscf1-airnity-slice-data-par 3(45) DEBUG: cdp [diameter_comm.c:145]: AAASendMessage(): Found diameter peer [dra1_slice_par01.epc.mnc081.mcc901.3gppnetwork.org] from routing table
scscf1-airnity-slice-data-par 3(45) DEBUG: cdp [peerstatemachine.c:89]: sm_process(): sm_process(): Peer dra1_slice_par01.epc.mnc081.mcc901.3gppnetwork.org State I_Open Event Send_Message
scscf1-airnity-slice-data-par 3(45) DEBUG: cdp [peerstatemachine.c:1158]: Snd_Message(): Snd_Message called to peer [dra1_slice_par01.epc.mnc081.mcc901.3gppnetwork.org] for request with code 301
scscf1-airnity-slice-data-par 3(45) DEBUG: cdp [session.c:305]: cdp_get_session(): called get session with id scscf.ims.mnc081.mcc901.3gppnetwork.org;3181552081;2 and hash 12
scscf1-airnity-slice-data-par 3(45) DEBUG: cdp [session.c:314]: cdp_get_session(): no session found
scscf1-airnity-slice-data-par 3(45) DEBUG: cdp [diameter_msg.c:81]: AAABuildMsgBuffer(): AAABuildMsgBuffer(): len=528
scscf1-airnity-slice-data-par 3(45) DEBUG: cdp [receiver.c:1013]: peer_send_msg(): peer_send_msg(): Pipe push [0x7f772c085e10]
scscf1-airnity-slice-data-par 26(68) DEBUG: cdp [receiver.c:756]: receive_loop(): select_recv(): There is something on the send pipe
scscf1-airnity-slice-data-par 26(68) DEBUG: cdp [receiver.c:769]: receive_loop(): select_recv(): Send pipe says [0x7f772c085e10] 8
scscf1-airnity-slice-data-par 26(68) DEBUG: cdp [diameter_msg.c:410]: AAAFreeMessage(): AAAFreeMessage: Freeing message (0x7f772c085e10) 301
scscf1-airnity-slice-data-par 26(68) DEBUG: cdp [receiver.c:575]: do_receive(): receive_loop(): [dra1_slice_par01.epc.mnc081.mcc901.3gppnetwork.org] Recv Version 1 Length 1980
scscf1-airnity-slice-data-par 26(68) DEBUG: cdp [receiver.c:1104]: receive_message(): receive_message(): [dra1_slice_par01.epc.mnc081.mcc901.3gppnetwork.org] Recv msg 301
scscf1-airnity-slice-data-par 26(68) DEBUG: cdp [peerstatemachine.c:89]: sm_process(): sm_process(): Peer dra1_slice_par01.epc.mnc081.mcc901.3gppnetwork.org State I_Open Event I_Rcv_Message
scscf1-airnity-slice-data-par 26(68) DEBUG: cdp [session.c:305]: cdp_get_session(): called get session with id scscf.ims.mnc081.mcc901.3gppnetwork.org;3181552081;2 and hash 12
scscf1-airnity-slice-data-par 26(68) DEBUG: cdp [session.c:314]: cdp_get_session(): no session found
scscf1-airnity-slice-data-par 10(52) DEBUG: cdp [worker.c:343]: worker_process(): worker_process(): [1] got task Q(2/2)
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [cxdx_sar.c:142]: async_cdp_callback(): There is transaction data this must have been called from save or assign server unreg10(52) DEBUG: tm [t_lookup.c:1611]: t_lookup_ident_filter(): transaction found
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [cxdx_sar.c:189]: async_cdp_callback(): callid for found transaction is [1578740844_1601297404@192.168.101.3]
scscf1-airnity-slice-data-par 10(52) INFO: ims_registrar_scscf [cxdx_avp.c:138]: cxdx_get_avp(): cxdx_get_experimental_result_code: Failed finding avp
scscf1-airnity-slice-data-par 10(52) INFO: ims_registrar_scscf [cxdx_avp.c:138]: cxdx_get_avp(): cxdx_get_charging_info: Failed finding avp
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [cxdx_sar.c:214]: async_cdp_callback(): received AAA success for SAR - SAA
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [cxdx_sar.c:233]: async_cdp_callback(): Parsing user data string from SAA
scscf1-airnity-slice-data-par 10(52) ERROR: ims_registrar_scscf [userdata_parser.c:935]: parse_user_data(): sum is 151162 calculated len 1667 xml.l 166710(52) DEBUG: ims_registrar_scscf [userdata_parser.c:760]: parse_service_profile(): child name is [PublicIdentity]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [userdata_parser.c:760]: parse_service_profile(): child name is [PublicIdentity]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [userdata_parser.c:760]: parse_service_profile(): child name is [PublicIdentity]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [userdata_parser.c:760]: parse_service_profile(): child name is [InitialFilterCriteria]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [userdata_parser.c:760]: parse_service_profile(): child name is [InitialFilterCriteria]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [userdata_parser.c:1022]: print_user_data(): IMSSubscription:
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [userdata_parser.c:1025]: print_user_data(): Private Identity: 901810000000022@ims.mnc081.mcc901.3gppnetwork.org
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [userdata_parser.c:1027]: print_user_data(): Service Profile:
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [userdata_parser.c:1029]: print_user_data(): Public Identity: Barring [1] sip:901810000000022@ims.mnc081.mcc901.3gppnetwork.org
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [userdata_parser.c:1029]: print_user_data(): Public Identity: Barring [0] sip:+883390000010022@ims.mnc081.mcc901.3gppnetwork.org
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [userdata_parser.c:1029]: print_user_data(): Public Identity: Barring [0] tel:+883390000010022
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [userdata_parser.c:1035]: print_user_data(): Filter Criteria: Priority [1]ProfilePartInd [-1]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [userdata_parser.c:1040]: print_user_data(): Trigger Point: CNF [X] (_|_)&(_|_)
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [userdata_parser.c:1045]: print_user_data(): SPT: Grp[1] NOT[ ] RegType[0]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [userdata_parser.c:1057]: print_user_data(): Method == <REGISTER>
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [userdata_parser.c:1083]: print_user_data(): AS: sip:ip-sm-gw.ims.mnc081.mcc901.3gppnetwork.org Handling [1] SrvInfo: <>
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [userdata_parser.c:1035]: print_user_data(): Filter Criteria: Priority [2]ProfilePartInd [-1]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [userdata_parser.c:1040]: print_user_data(): Trigger Point: CNF [ ] (_&_)|(_&_)
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [userdata_parser.c:1045]: print_user_data(): SPT: Grp[0] NOT[ ] RegType[0]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [userdata_parser.c:1057]: print_user_data(): Method == <MESSAGE>
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [userdata_parser.c:1045]: print_user_data(): SPT: Grp[0] NOT[ ] RegType[0]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [userdata_parser.c:1062]: print_user_data(): Hdr(Content-Type(11)) == <application/vnd.3gpp.sms>
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [userdata_parser.c:1045]: print_user_data(): SPT: Grp[0] NOT[ ] RegType[0]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [userdata_parser.c:1070]: print_user_data(): SessionCase [0]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [userdata_parser.c:1083]: print_user_data(): AS: sip:ip-sm-gw.ims.mnc081.mcc901.3gppnetwork.org:5060 Handling [1] SrvInfo: <>
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [cxdx_sar.c:240]: async_cdp_callback(): Successfully parse user data XML setting ref to 1 (we are referencing it)
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [save.c:790]: update_contacts(): updating contacts in REGISTRATION state
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [impurecord.c:943]: update_impurecord(): No subscription yet for [901810000000022@ims.mnc081.mcc901.3gppnetwork.org]... adding
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [impurecord.c:1274]: ref_subscription_unsafe(): Reffing subscription [901810000000022@ims.mnc081.mcc901.3gppnetwork.org] - was [1]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [impurecord.c:971]: update_impurecord(): No existing impu record for sip:901810000000022@ims.mnc081.mcc901.3gppnetwork.org.... creating new one
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [impurecord.c:1274]: ref_subscription_unsafe(): Reffing subscription [901810000000022@ims.mnc081.mcc901.3gppnetwork.org] - was [2]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [udomain.c:238]: mem_insert_impurecord(): inserted new impurecord into memory [sip:901810000000022@ims.mnc081.mcc901.3gppnetwork.org]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [ul_callback.h:119]: run_ul_callbacks(): impurecord=0x7f772c08f280, contact=(nil), callback type 256/256, id 0 entered
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [usrloc_cb.c:53]: ul_impu_inserted(): Received notification of UL IMPU insert for IMPU sip:901810000000022@ims.mnc081.mcc901.3gppnetwork.org
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [usrloc_cb.c:55]: ul_impu_inserted(): Registering for callbacks on this IMPU for contact insert, update, delete or expire to send notifications if there are any subscriptions
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [ul_callback.c:168]: register_ulcb(): installing callback for SCSCF IMPU record with type [1024]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [ul_callback.c:168]: register_ulcb(): installing callback for SCSCF IMPU record with type [30720]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [usrloc_cb.c:59]: ul_impu_inserted(): Selectively asking for expire or no contact delete callbacks only on the anchor of the implicit set so that we only send one SAR per implicit set
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [impurecord.c:1285]: unref_subscription_unsafe(): un-reffing subscription [901810000000022@ims.mnc081.mcc901.3gppnetwork.org] - was [3]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [save.c:519]: update_contacts_helper(): updating the contacts for IMPU sip:901810000000022@ims.mnc081.mcc901.3gppnetwork.org
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [save.c:137]: calc_contact_expires(): Calculated expires for contact is 600000
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [save.c:545]: update_contacts_helper(): Need to update contact: sip:75bb2112-e5ef-47cc-ad1c-872ae629c493@192.168.101.3:43715;alias=192.168.101.3~44457~2: q_value [-1],sos: [0],expires [600000]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [save.c:550]: update_contacts_helper(): packing contact information
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [save.c:556]: update_contacts_helper(): adding/updating contact based on prior existence
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [impurecord.c:748]: get_scontact(): looking for contact [sip:75bb2112-e5ef-47cc-ad1c-872ae629c493@192.168.101.3:43715;alias=192.168.101.3~44457~2] in slot 230
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [save.c:562]: update_contacts_helper(): inserting new contact
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [impurecord.c:562]: insert_scontact(): INSERTing ucontact in usrloc module
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [ucontact.c:118]: new_ucontact(): Checking param [+g.3gpp.accesstype]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [ucontact.c:118]: new_ucontact(): Checking param [+sip.instance]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [ucontact.c:118]: new_ucontact(): Checking param [audio]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [ucontact.c:118]: new_ucontact(): Checking param [+g.3gpp.smsip]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [ucontact.c:118]: new_ucontact(): Checking param [+g.3gpp.icsi-ref]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [ucontact.c:173]: new_ucontact(): generating hash based on [sip:75bb2112-e5ef-47cc-ad1c-872ae629c493@192.168.101.3:43715;alias=192.168.101.3~44457~2]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [impurecord.c:280]: mem_insert_scontact(): Created new contact in memory with AOR: [sip:75bb2112-e5ef-47cc-ad1c-872ae629c493@192.168.101.3:43715;alias=192.168.101.3~44457~2] and hash [230]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [udomain.c:843]: ref_contact_unsafe(): incrementing ref count on contact [sip:75bb2112-e5ef-47cc-ad1c-872ae629c493@192.168.101.3:43715;alias=192.168.101.3~44457~2], was 1
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [impurecord.c:1226]: link_contact_to_impu(): number of contacts for IMPU [sip:901810000000022@ims.mnc081.mcc901.3gppnetwork.org] is 1
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [udomain.c:852]: unref_contact_unsafe(): decrementing ref count on contact [sip:75bb2112-e5ef-47cc-ad1c-872ae629c493@192.168.101.3:43715;alias=192.168.101.3~44457~2], was 2
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [ul_callback.h:119]: run_ul_callbacks(): impurecord=0x7f772c08f280, contact=0x7f772c08f690, callback type 1024/1024, id 0 entered
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [usrloc_cb.c:88]: ul_contact_changed(): Received notification of type 1024 on contact Address sip:75bb2112-e5ef-47cc-ad1c-872ae629c493@192.168.101.3:43715;alias=192.168.101.3~44457~2
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [usrloc_cb.c:91]: ul_contact_changed(): There are no subscriptions for this IMPU therefore breaking out now as nothing to do
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [udomain.c:792]: get_subscription(): found an existing subscription for IMPI [901810000000022@ims.mnc081.mcc901.3gppnetwork.org]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [impurecord.c:1274]: ref_subscription_unsafe(): Reffing subscription [901810000000022@ims.mnc081.mcc901.3gppnetwork.org] - was [2]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [impurecord.c:878]: compare_subscription(): Comparing subscription for IMPI [901810000000022@ims.mnc081.mcc901.3gppnetwork.org]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [impurecord.c:883]: compare_subscription(): new sip:901810000000022@ims.mnc081.mcc901.3gppnetwork.org (53) vs. orig sip:901810000000022@ims.mnc081.mcc901.3gppnetwork.org (53)
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [impurecord.c:971]: update_impurecord(): No existing impu record for sip:+883390000010022@ims.mnc081.mcc901.3gppnetwork.org.... creating new one
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [impurecord.c:1274]: ref_subscription_unsafe(): Reffing subscription [901810000000022@ims.mnc081.mcc901.3gppnetwork.org] - was [3]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [udomain.c:238]: mem_insert_impurecord(): inserted new impurecord into memory [sip:+883390000010022@ims.mnc081.mcc901.3gppnetwork.org]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [ul_callback.h:119]: run_ul_callbacks(): impurecord=0x7f772c090410, contact=(nil), callback type 256/256, id 0 entered
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [usrloc_cb.c:53]: ul_impu_inserted(): Received notification of UL IMPU insert for IMPU sip:+883390000010022@ims.mnc081.mcc901.3gppnetwork.org
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [usrloc_cb.c:55]: ul_impu_inserted(): Registering for callbacks on this IMPU for contact insert, update, delete or expire to send notifications if there are any subscriptions
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [ul_callback.c:168]: register_ulcb(): installing callback for SCSCF IMPU record with type [1024]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [ul_callback.c:168]: register_ulcb(): installing callback for SCSCF IMPU record with type [30720]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [usrloc_cb.c:59]: ul_impu_inserted(): Selectively asking for expire or no contact delete callbacks only on the anchor of the implicit set so that we only send one SAR per implicit set
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [ul_callback.c:168]: register_ulcb(): installing callback for SCSCF IMPU record with type [80]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [impurecord.c:1285]: unref_subscription_unsafe(): un-reffing subscription [901810000000022@ims.mnc081.mcc901.3gppnetwork.org] - was [4]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [save.c:519]: update_contacts_helper(): updating the contacts for IMPU sip:+883390000010022@ims.mnc081.mcc901.3gppnetwork.org
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [save.c:137]: calc_contact_expires(): Calculated expires for contact is 600000
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [save.c:545]: update_contacts_helper(): Need to update contact: sip:75bb2112-e5ef-47cc-ad1c-872ae629c493@192.168.101.3:43715;alias=192.168.101.3~44457~2: q_value [-1],sos: [0],expires [600000]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [save.c:550]: update_contacts_helper(): packing contact information
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [save.c:556]: update_contacts_helper(): adding/updating contact based on prior existence
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [impurecord.c:748]: get_scontact(): looking for contact [sip:75bb2112-e5ef-47cc-ad1c-872ae629c493@192.168.101.3:43715;alias=192.168.101.3~44457~2] in slot 230
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [impurecord.c:774]: get_scontact(): have partially found a contact
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [impurecord.c:783]: get_scontact(): contact found p=[0x7f772c08f690], aor:[sip:901810000000022@ims.mnc081.mcc901.3gppnetwork.org] and contact:[sip:75bb2112-e5ef-47cc-ad1c-872ae629c493@192.168.101.3:43715;alias=192.168.101.3~44457~2], state [0]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [udomain.c:843]: ref_contact_unsafe(): incrementing ref count on contact [sip:75bb2112-e5ef-47cc-ad1c-872ae629c493@192.168.101.3:43715;alias=192.168.101.3~44457~2], was 1
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [save.c:570]: update_contacts_helper(): Contact already exists - updating - it's currently in state [0]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [ucontact.c:423]: update_scontact(): Updating contact aor: [sip:901810000000022@ims.mnc081.mcc901.3gppnetwork.org] and contact uri: [sip:75bb2112-e5ef-47cc-ad1c-872ae629c493@192.168.101.3:43715;alias=192.168.101.3~44457~2]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [ucontact.c:351]: mem_update_ucontact(): Setting contact expires to 1666763272 which is in 600000 seconds time
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [udomain.c:843]: ref_contact_unsafe(): incrementing ref count on contact [sip:75bb2112-e5ef-47cc-ad1c-872ae629c493@192.168.101.3:43715;alias=192.168.101.3~44457~2], was 2
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [impurecord.c:1226]: link_contact_to_impu(): number of contacts for IMPU [sip:+883390000010022@ims.mnc081.mcc901.3gppnetwork.org] is 1
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [ucontact.c:439]: update_scontact(): exists callback for type= UL_CONTACT_UPDATE
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [ul_callback.h:119]: run_ul_callbacks(): impurecord=0x7f772c090410, contact=0x7f772c08f690, callback type 2048/30720, id 1 entered
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [usrloc_cb.c:88]: ul_contact_changed(): Received notification of type 2048 on contact Address sip:75bb2112-e5ef-47cc-ad1c-872ae629c493@192.168.101.3:43715;alias=192.168.101.3~44457~2
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [usrloc_cb.c:91]: ul_contact_changed(): There are no subscriptions for this IMPU therefore breaking out now as nothing to do
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [udomain.c:852]: unref_contact_unsafe(): decrementing ref count on contact [sip:75bb2112-e5ef-47cc-ad1c-872ae629c493@192.168.101.3:43715;alias=192.168.101.3~44457~2], was 3
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [udomain.c:792]: get_subscription(): found an existing subscription for IMPI [901810000000022@ims.mnc081.mcc901.3gppnetwork.org]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [impurecord.c:1274]: ref_subscription_unsafe(): Reffing subscription [901810000000022@ims.mnc081.mcc901.3gppnetwork.org] - was [3]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [impurecord.c:878]: compare_subscription(): Comparing subscription for IMPI [901810000000022@ims.mnc081.mcc901.3gppnetwork.org]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [impurecord.c:883]: compare_subscription(): new sip:901810000000022@ims.mnc081.mcc901.3gppnetwork.org (53) vs. orig sip:901810000000022@ims.mnc081.mcc901.3gppnetwork.org (53)
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [impurecord.c:971]: update_impurecord(): No existing impu record for tel:+883390000010022.... creating new one
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [impurecord.c:1274]: ref_subscription_unsafe(): Reffing subscription [901810000000022@ims.mnc081.mcc901.3gppnetwork.org] - was [4]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [udomain.c:238]: mem_insert_impurecord(): inserted new impurecord into memory [tel:+883390000010022]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [ul_callback.h:119]: run_ul_callbacks(): impurecord=0x7f772c090928, contact=(nil), callback type 256/256, id 0 entered
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [usrloc_cb.c:53]: ul_impu_inserted(): Received notification of UL IMPU insert for IMPU tel:+883390000010022
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [usrloc_cb.c:55]: ul_impu_inserted(): Registering for callbacks on this IMPU for contact insert, update, delete or expire to send notifications if there are any subscriptions
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [ul_callback.c:168]: register_ulcb(): installing callback for SCSCF IMPU record with type [1024]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [ul_callback.c:168]: register_ulcb(): installing callback for SCSCF IMPU record with type [30720]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [usrloc_cb.c:59]: ul_impu_inserted(): Selectively asking for expire or no contact delete callbacks only on the anchor of the implicit set so that we only send one SAR per implicit set
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [impurecord.c:1285]: unref_subscription_unsafe(): un-reffing subscription [901810000000022@ims.mnc081.mcc901.3gppnetwork.org] - was [5]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [save.c:519]: update_contacts_helper(): updating the contacts for IMPU tel:+883390000010022
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [save.c:137]: calc_contact_expires(): Calculated expires for contact is 600000
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [save.c:545]: update_contacts_helper(): Need to update contact: sip:75bb2112-e5ef-47cc-ad1c-872ae629c493@192.168.101.3:43715;alias=192.168.101.3~44457~2: q_value [-1],sos: [0],expires [600000]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [save.c:550]: update_contacts_helper(): packing contact information
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [save.c:556]: update_contacts_helper(): adding/updating contact based on prior existence
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [impurecord.c:748]: get_scontact(): looking for contact [sip:75bb2112-e5ef-47cc-ad1c-872ae629c493@192.168.101.3:43715;alias=192.168.101.3~44457~2] in slot 230
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [impurecord.c:774]: get_scontact(): have partially found a contact
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [impurecord.c:783]: get_scontact(): contact found p=[0x7f772c08f690], aor:[sip:901810000000022@ims.mnc081.mcc901.3gppnetwork.org] and contact:[sip:75bb2112-e5ef-47cc-ad1c-872ae629c493@192.168.101.3:43715;alias=192.168.101.3~44457~2], state [0]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [udomain.c:843]: ref_contact_unsafe(): incrementing ref count on contact [sip:75bb2112-e5ef-47cc-ad1c-872ae629c493@192.168.101.3:43715;alias=192.168.101.3~44457~2], was 2
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [save.c:570]: update_contacts_helper(): Contact already exists - updating - it's currently in state [0]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [ucontact.c:423]: update_scontact(): Updating contact aor: [sip:901810000000022@ims.mnc081.mcc901.3gppnetwork.org] and contact uri: [sip:75bb2112-e5ef-47cc-ad1c-872ae629c493@192.168.101.3:43715;alias=192.168.101.3~44457~2]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [ucontact.c:351]: mem_update_ucontact(): Setting contact expires to 1666763272 which is in 600000 seconds time
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [udomain.c:843]: ref_contact_unsafe(): incrementing ref count on contact [sip:75bb2112-e5ef-47cc-ad1c-872ae629c493@192.168.101.3:43715;alias=192.168.101.3~44457~2], was 3
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [impurecord.c:1226]: link_contact_to_impu(): number of contacts for IMPU [tel:+883390000010022] is 1
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [ucontact.c:439]: update_scontact(): exists callback for type= UL_CONTACT_UPDATE
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [ul_callback.h:119]: run_ul_callbacks(): impurecord=0x7f772c090928, contact=0x7f772c08f690, callback type 2048/30720, id 1 entered
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [usrloc_cb.c:88]: ul_contact_changed(): Received notification of type 2048 on contact Address sip:75bb2112-e5ef-47cc-ad1c-872ae629c493@192.168.101.3:43715;alias=192.168.101.3~44457~2
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [usrloc_cb.c:91]: ul_contact_changed(): There are no subscriptions for this IMPU therefore breaking out now as nothing to do
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [udomain.c:852]: unref_contact_unsafe(): decrementing ref count on contact [sip:75bb2112-e5ef-47cc-ad1c-872ae629c493@192.168.101.3:43715;alias=192.168.101.3~44457~2], was 4
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [reply.c:541]: build_contact(): created Contact HF: Contact: sip:75bb2112-e5ef-47cc-ad1c-872ae629c493@192.168.101.3:43715;alias=192.168.101.3~44457~2;expires=540000;+g.3gpp.accesstype="cellular2";+sip.instance="<urn:gsma:imei:86210804-091779-0>";audio;+g.3gpp.smsip;+g.3gpp.icsi-ref="urn%3Aurn-7%3A3gpp-service.ims.icsi.mmtel"
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [reply.c:584]: build_p_associated_uri(): Building P-Associated-URI
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [reply.c:633]: build_p_associated_uri(): Created P-Associated-URI HF P-Associated-URI: sip:+883390000010022@ims.mnc081.mcc901.3gppnetwork.org, tel:+883390000010022
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [registrar_notify.c:451]: event_reg(): Sending Reg event notifies
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [registrar_notify.c:452]: event_reg(): Switching on event type: 7
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [udomain.c:690]: get_impus_from_subscription_as_string(): getting IMPU subscription set
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [udomain.c:706]: get_impus_from_subscription_as_string(): Got Record sip:901810000000022@ims.mnc081.mcc901.3gppnetwork.org (53)
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [udomain.c:706]: get_impus_from_subscription_as_string(): Got Record sip:+883390000010022@ims.mnc081.mcc901.3gppnetwork.org (54)
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [udomain.c:706]: get_impus_from_subscription_as_string(): Got Record tel:+883390000010022 (20)
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [udomain.c:722]: get_impus_from_subscription_as_string(): num of records returned is 2 and we need 74 bytes
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [registrar_notify.c:523]: event_reg(): About to create notification
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [registrar_notify.c:1415]: create_notifications(): Creating notification
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [registrar_notify.c:1418]: create_notifications(): r_passed and c_passed are valid and presentity uri and watcher_contact is 0 - this must be a ul callback no need to lock domain
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [cxdx_sar.c:259]: async_cdp_callback(): Updated contacts: Contact: sip:75bb2112-e5ef-47cc-ad1c-872ae629c493@192.168.101.3:43715;alias=192.168.101.3~44457~2;expires=540000;+g.3gpp.accesstype="cellular2";+sip.instance="<urn:gsma:imei:86210804-091779-0>";audio;+g.3gpp.smsip;+g.3gpp.icsi-ref="urn%3Aurn-7%3A3gpp-service.ims.icsi.mmtel"
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [reply.c:648]: reg_send_reply_transactional(): Contacts: Contact: sip:75bb2112-e5ef-47cc-ad1c-872ae629c493@192.168.101.3:43715;alias=192.168.101.3~44457~2;expires=540000;+g.3gpp.accesstype="cellular2";+sip.instance="<urn:gsma:imei:86210804-091779-0>";audio;+g.3gpp.smsip;+g.3gpp.icsi-ref="urn%3Aurn-7%3A3gpp-service.ims.icsi.mmtel"
scscf1-airnity-slice-data-par 10(52) DEBUG: tm [t_reply.c:1667]: cleanup_uac_timers(): RETR/FR timers reset
scscf1-airnity-slice-data-par 10(52) DEBUG: tm [t_reply.c:610]: _reply_light(): reply sent out. buf=0x7f77335e2030: SIP/2.0 200 OK
scscf1-airnity-slice-data-par From..., shmem=0x7f772c090fa0: SIP/2.0 200 OK
scscf1-airnity-slice-data-par From
scscf1-airnity-slice-data-par 10(52) DEBUG: tm [t_reply.c:621]: _reply_light(): finished
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_registrar_scscf [cxdx_sar.c:272]: async_cdp_callback(): DBG:SAR Async CDP callback: ... Done resuming transaction
scscf1-airnity-slice-data-par 10(52) INFO: ims_registrar_scscf [cxdx_sar.c:84]: create_return_code(): created AVP successfully : [saa_return_code] - [1]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [impurecord.c:1285]: unref_subscription_unsafe(): un-reffing subscription [901810000000022@ims.mnc081.mcc901.3gppnetwork.org] - was [4]
scscf1-airnity-slice-data-par 10(52) DEBUG: cdp [diameter_msg.c:410]: AAAFreeMessage(): AAAFreeMessage: Freeing message (0x7f772c089f50) 301
scscf1-airnity-slice-data-par 10(52) DEBUG: tm [t_lookup.c:1603]: t_lookup_ident_filter(): transaction in terminated phase - skipping
scscf1-airnity-slice-data-par 10(52) WARNING: tm [t_suspend.c:192]: t_continue_helper(): active transaction not found
Could you help me on this issue?
Regards,
Anthony
From: Anthony Blandin
Sent: Wednesday, 19 October 2022 15:15
To: sr-users@lists.kamailio.org
Subject: No REGISTER sent to third party AS from scscf
Hi Community,
I am using scscf from Kamailio and I need that scscf sent a REGISTER to a third party AS during the registration phase.
When scscf received a new registration, no REGISTER is sent to the AS.
SAR-SAA is well processed but only 200 OK is sent for the REGISTER to the pcscf.
REGISTER is well sent to the AS only for Re-Registration or De-registration.
Do you have any idea to handle this case?
Regards
Anthony
__________________________________________________________Kamailio - Users Mailing List - Non Commercial Discussionssr-users@lists.kamailio.orgImportant: keep the mailing list in the recipients, do not reply only to the sender!Edit mailing list options or unsubscribe:https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users