Re: [SR-Users] No REGISTER sent to third party AS from scscf

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(a)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<mailto: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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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