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