[SR-Users] No REGISTER sent to third party AS from scscf
Anthony Blandin
anthony.blandin at airnity.com
Thu Oct 20 12:25:03 CEST 2022
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 at 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 at 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 at ims.mnc081.mcc901.3gppnetwork.org<mailto:901810000000022 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at ims.mnc081.mcc901.3gppnetwork.org]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [impurecord.c:883]: compare_subscription(): new sip:901810000000022 at ims.mnc081.mcc901.3gppnetwork.org (53) vs. orig sip:901810000000022 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at ims.mnc081.mcc901.3gppnetwork.org] and contact:[sip:75bb2112-e5ef-47cc-ad1c-872ae629c493 at 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 at 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 at ims.mnc081.mcc901.3gppnetwork.org] and contact uri: [sip:75bb2112-e5ef-47cc-ad1c-872ae629c493 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at ims.mnc081.mcc901.3gppnetwork.org]
scscf1-airnity-slice-data-par 10(52) DEBUG: ims_usrloc_scscf [impurecord.c:883]: compare_subscription(): new sip:901810000000022 at ims.mnc081.mcc901.3gppnetwork.org (53) vs. orig sip:901810000000022 at 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 at 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 at 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 at 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 at 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 at ims.mnc081.mcc901.3gppnetwork.org] and contact:[sip:75bb2112-e5ef-47cc-ad1c-872ae629c493 at 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 at 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 at ims.mnc081.mcc901.3gppnetwork.org] and contact uri: [sip:75bb2112-e5ef-47cc-ad1c-872ae629c493 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.kamailio.org/pipermail/sr-users/attachments/20221020/a5985d74/attachment.htm>
More information about the sr-users
mailing list