Description

We have various commercial UE's connecting over an Amarisoft Callbox Classic eNB with Open5GS core network. This issue concerns different UE behaviour.

Name checking code introduced between Kamailio v5.6.4 and v5.7.1 (udomain.c lines 580 to 599) leads to rejection of the SUBSCRIBE request from a Huawei UE (user-agent: IM-client/OMA1.0 HW-Rto/V1.0). SUBSCRIBE requests from a OnePlus UE (user-agent: OnePlus_KB2003_RPIA.201005.001) are accepted.

We assume that the behaviour of the commercial-off-the-shelf UE's complies with the 3GPP standards; but we do not know to what extent. The following code, however, caused our Huawei UE's to lose VoLTE capability, after updating the Kamailio IMS from v5.6.4 to v5.7.1.

580                if ((contact_info->aor.len>0) && (needle_uri.user.len != 0)){
581                  if ((needle_uri.user.len != c->contact_user.len) ||
582                       (memcmp(needle_uri.user.s, c->contact_user.s, needle_uri.user.len) != 0)) {
583                                   LM_ERR("user name does not match - no match here...\n");
584                                   LM_DBG("found pcontact username [%d]: [%.*s]\n", i, c->contact_user.len, c->contact_user.s);
585                                   LM_DBG("incoming contact username: [%.*s]\n", needle_uri.user.len, needle_uri.user.s);
586                                   c = c->next;
587                                   continue;
588                   }
589                   if ((contact_info->aor.len >= 4) && (memcmp(contact_info->aor.s, c->aor.s, 4) != 0)) {   // do not mix up sip- and tel-URIs.
590                                LM_ERR("scheme does not match - no match here...\n");
591                                LM_DBG("found pcontact scheme [%d]: [%.*s]\n", i, 4, c->aor.s);
592                                LM_DBG("incoming contact scheme: [%.*s]\n", 4, contact_info->aor.s);
593                                c = c->next;
594                                continue;
595                   }
596                }
597                else{
598                    LM_DBG("No user name present - abort user name check\n");
599                }

The above code also does not consider the reverse_search flag (uses c=c->next instead of c = reverse_search? c->prev : c->next), so if reverse_search is set, the code's behaviour may be incorrect.

In the following pcap file, the Huawei's SIP REGISTER process starts at packet 2, 200 OK arriving in packet 41, with the P-Associated-URI sip:51194@ims.mnc001.mcc001.3gppnetwork.org. This UE sends SUBSCRIBE (packet 47) incorporating a new Contact: sip:51194@10.46.0.6:31896, presumably derived from the P-Associated-URI; but receives "403 Forbidden - You must register first with a S-CSCF".

The Oneplus sends SIP REGISTER at packet 56, receiving 200 OK at packet 83 with P-Associated-URI sip:51196@ims.mnc001.mcc001.3gppnetwork.org. But this UE's SUBSCRIBE (packet 84) incorporates the same Contact used in the REGISTER request: sip:c57d4262-e59d-4530-a0f4-b4faaa2fb1c6@10.46.0.8:5060, and 200 OK arrives at packet 92.

v571-pcscf-name-check-fail.zip

Debugging Data

None acquired

Log Messages

NB: log messages acquired prior to above pcap. The following extract shows failed name check (udomain.c lines 580 - 599) for username 51194, while 001010000051194 was registered:

Jul 18 12:15:31 corsa03 p-cscf[58090]: DEBUG: ims_registrar_pcscf [service_routes.c:210]: getContactP(): This is a request - using first via to find contact
Jul 18 12:15:31 corsa03 p-cscf[58090]: DEBUG: ims_registrar_pcscf [service_routes.c:218]: getContactP(): searching for contact with host:port:proto contact [1://10.46.0.6:31894]
Jul 18 12:15:31 corsa03 p-cscf[58090]: DEBUG: ims_usrloc_pcscf [udomain.c:459]: get_pcontact_from_cache(): Searching for contact with AOR [sip:51194@10.46.0.6:31894] in P-CSCF usrloc based on VIA [1://10.46.0.6:31894] Received [1://10.46.0.6:31409], Search flag is 0, reverse_search 0
Jul 18 12:15:31 corsa03 p-cscf[58090]: DEBUG: ims_usrloc_pcscf [udomain.c:469]: get_pcontact_from_cache(): Have an AOR to search for
Jul 18 12:15:31 corsa03 p-cscf[58090]: DEBUG: ims_usrloc_pcscf [udomain.c:474]: get_pcontact_from_cache(): checking for rinstance
Jul 18 12:15:31 corsa03 p-cscf[58090]: DEBUG: ims_usrloc_pcscf [usrloc.c:157]: get_aor_hash(): Returning hash: [1746035570]
Jul 18 12:15:31 corsa03 p-cscf[58090]: DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact_from_cache(): get_pcontact slot is [370]
Jul 18 12:15:31 corsa03 p-cscf[58090]: DEBUG: ims_usrloc_pcscf [udomain.c:513]: get_pcontact_from_cache(): comparing contact with aorhash [1746035570], aor [sip:001010000051194@10.46.0.6:5060]
Jul 18 12:15:31 corsa03 p-cscf[58090]: DEBUG: ims_usrloc_pcscf [udomain.c:514]: get_pcontact_from_cache():   contact host [10.46.0.6:5060]
Jul 18 12:15:31 corsa03 p-cscf[58090]: DEBUG: ims_usrloc_pcscf [udomain.c:515]: get_pcontact_from_cache(): contact received [2:10.46.0.6:5060]
Jul 18 12:15:31 corsa03 p-cscf[58090]: DEBUG: ims_usrloc_pcscf [udomain.c:522]: get_pcontact_from_cache(): mached a record by aorhash: 1746035570
Jul 18 12:15:31 corsa03 p-cscf[58090]: DEBUG: ims_usrloc_pcscf [udomain.c:513]: get_pcontact_from_cache(): comparing contact with aorhash [1746035570], aor [sip:001010000051194@10.46.0.6:31894]
Jul 18 12:15:31 corsa03 p-cscf[58090]: DEBUG: ims_usrloc_pcscf [udomain.c:514]: get_pcontact_from_cache():   contact host [10.46.0.6:31894]
Jul 18 12:15:31 corsa03 p-cscf[58090]: DEBUG: ims_usrloc_pcscf [udomain.c:515]: get_pcontact_from_cache(): contact received [2:10.46.0.6:31409]
Jul 18 12:15:31 corsa03 p-cscf[58090]: DEBUG: ims_usrloc_pcscf [udomain.c:522]: get_pcontact_from_cache(): mached a record by aorhash: 1746035570
Jul 18 12:15:31 corsa03 p-cscf[58090]: DEBUG: ims_usrloc_pcscf [udomain.c:541]: get_pcontact_from_cache(): matched contact ip address and port
Jul 18 12:15:31 corsa03 p-cscf[58090]: DEBUG: ims_usrloc_pcscf [udomain.c:569]: get_pcontact_from_cache(): found contact with URI [sip:001010000051194@10.46.0.6:31894]
Jul 18 12:15:31 corsa03 p-cscf[58090]: ERROR: ims_usrloc_pcscf [udomain.c:583]: get_pcontact_from_cache(): user name does not match - no match here...
Jul 18 12:15:31 corsa03 p-cscf[58090]: DEBUG: ims_usrloc_pcscf [udomain.c:584]: get_pcontact_from_cache(): found pcontact username [1]: [001010000051194]
Jul 18 12:15:31 corsa03 p-cscf[58090]: DEBUG: ims_usrloc_pcscf [udomain.c:585]: get_pcontact_from_cache(): incoming contact username: [51194]
Jul 18 12:15:31 corsa03 p-cscf[58090]: DEBUG: ims_usrloc_pcscf [udomain.c:643]: get_pcontact_from_cache(): contact not found in memory
Jul 18 12:15:31 corsa03 p-cscf[58090]: INFO: ims_registrar_pcscf [service_routes.c:277]: getContactP(): Contact not found based on Contact-header, trying IP/Port/Proto
Jul 18 12:15:31 corsa03 p-cscf[58090]: DEBUG: ims_usrloc_pcscf [udomain.c:459]: get_pcontact_from_cache(): Searching for contact with AOR [sip:51194@10.46.0.6:31894] in P-CSCF usrloc based on VIA [1://10.46.0.6:31894] Received [1://10.46.0.6:31409], Search flag is 1, reverse_search 0
Jul 18 12:15:31 corsa03 p-cscf[58090]: DEBUG: ims_usrloc_pcscf [udomain.c:469]: get_pcontact_from_cache(): Have an AOR to search for
Jul 18 12:15:31 corsa03 p-cscf[58090]: DEBUG: ims_usrloc_pcscf [udomain.c:474]: get_pcontact_from_cache(): checking for rinstance
Jul 18 12:15:31 corsa03 p-cscf[58090]: DEBUG: ims_usrloc_pcscf [usrloc.c:157]: get_aor_hash(): Returning hash: [1746035570]
Jul 18 12:15:31 corsa03 p-cscf[58090]: DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact_from_cache(): get_pcontact slot is [370]
Jul 18 12:15:31 corsa03 p-cscf[58090]: DEBUG: ims_usrloc_pcscf [udomain.c:513]: get_pcontact_from_cache(): comparing contact with aorhash [1746035570], aor [sip:001010000051194@10.46.0.6:5060]
Jul 18 12:15:31 corsa03 p-cscf[58090]: DEBUG: ims_usrloc_pcscf [udomain.c:514]: get_pcontact_from_cache():   contact host [10.46.0.6:5060]
Jul 18 12:15:31 corsa03 p-cscf[58090]: DEBUG: ims_usrloc_pcscf [udomain.c:515]: get_pcontact_from_cache(): contact received [2:10.46.0.6:5060]
Jul 18 12:15:31 corsa03 p-cscf[58090]: DEBUG: ims_usrloc_pcscf [udomain.c:522]: get_pcontact_from_cache(): mached a record by aorhash: 1746035570
Jul 18 12:15:31 corsa03 p-cscf[58090]: DEBUG: ims_usrloc_pcscf [udomain.c:546]: get_pcontact_from_cache(): continuing to match on received details
Jul 18 12:15:31 corsa03 p-cscf[58090]: DEBUG: ims_usrloc_pcscf [udomain.c:513]: get_pcontact_from_cache(): comparing contact with aorhash [1746035570], aor [sip:001010000051194@10.46.0.6:31894]
Jul 18 12:15:31 corsa03 p-cscf[58090]: DEBUG: ims_usrloc_pcscf [udomain.c:514]: get_pcontact_from_cache():   contact host [10.46.0.6:31894]
Jul 18 12:15:31 corsa03 p-cscf[58090]: DEBUG: ims_usrloc_pcscf [udomain.c:515]: get_pcontact_from_cache(): contact received [2:10.46.0.6:31409]
Jul 18 12:15:31 corsa03 p-cscf[58090]: DEBUG: ims_usrloc_pcscf [udomain.c:522]: get_pcontact_from_cache(): mached a record by aorhash: 1746035570
Jul 18 12:15:31 corsa03 p-cscf[58090]: DEBUG: ims_usrloc_pcscf [udomain.c:546]: get_pcontact_from_cache(): continuing to match on received details
Jul 18 12:15:31 corsa03 p-cscf[58090]: DEBUG: ims_usrloc_pcscf [udomain.c:569]: get_pcontact_from_cache(): found contact with URI [sip:001010000051194@10.46.0.6:31894]
Jul 18 12:15:31 corsa03 p-cscf[58090]: ERROR: ims_usrloc_pcscf [udomain.c:583]: get_pcontact_from_cache(): user name does not match - no match here...
Jul 18 12:15:31 corsa03 p-cscf[58090]: DEBUG: ims_usrloc_pcscf [udomain.c:584]: get_pcontact_from_cache(): found pcontact username [1]: [001010000051194]
Jul 18 12:15:31 corsa03 p-cscf[58090]: DEBUG: ims_usrloc_pcscf [udomain.c:585]: get_pcontact_from_cache(): incoming contact username: [51194]
Jul 18 12:15:31 corsa03 p-cscf[58090]: DEBUG: ims_usrloc_pcscf [udomain.c:643]: get_pcontact_from_cache(): contact not found in memory
Jul 18 12:15:31 corsa03 p-cscf[58090]: DEBUG: ims_registrar_pcscf [service_routes.c:282]: getContactP(): No entry in usrloc for 10.46.0.6:31409 (Proto 1) found!
Jul 18 12:15:31 corsa03 p-cscf[58090]: DEBUG: ims_registrar_pcscf [service_routes.c:319]: getContactP(): Asserted identity not set
Jul 18 12:15:31 corsa03 p-cscf[58090]: ERROR: *** cfgtrace:dbg_cfg_trace(): request_route=[MO] c=[/etc/kamailio/pcscf/route/mo.cfg] l=16 a=26 n=send_reply
Jul 18 12:15:31 corsa03 p-cscf[58090]: DEBUG: sl [sl.c:310]: send_reply(): reply in stateless mode (sl)
Jul 18 12:15:31 corsa03 p-cscf[58090]: DEBUG: <core> [core/receive.c:126]: sip_check_fline(): first line indicates a SIP reply
Jul 18 12:15:31 corsa03 p-cscf[58090]: ERROR: *** cfgtrace:dbg_cfg_trace(): request_route=[MO] c=[/etc/kamailio/pcscf/route/mo.cfg] l=17 a=2 n=exit
Jul 18 12:15:31 corsa03 p-cscf[58090]: DEBUG: <core> [core/receive.c:528]: receive_msg(): request-route executed in: 4219 usec
Jul 18 12:15:31 corsa03 p-cscf[58090]: DEBUG: <core> [core/usr_avp.c:637]: destroy_avp_list(): destroying list 0x7f043587bfc0

Possible Solutions

Commenting out udomain.c lines 580-599 allowed both UE's to complete their SUBSCRIBE's, and make VoLTE calls. In the following pcap, the Oneplus REGISTER's and SUBSCRIBE's over packets 1 to 37; the Huawei process occurs from packets 45 to 98.

v571-pcscf-name-check-skipped.zip

Additional Information

version: kamailio 5.7.1 (x86_64/linux)
flags: USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS, USE_RAW_SOCKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MMAP, PKG_MALLOC, MEM_JOIN_FREE, Q_MALLOC, F_MALLOC, TLSF_MALLOC, DBG_SR_MEMORY, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLOCKLIST, HAVE_RESOLV_RES, TLS_PTHREAD_MUTEX_SHARED
ADAPTIVE_WAIT_LOOPS 1024, MAX_RECV_BUFFER_SIZE 262144, MAX_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 8MB
poll method support: poll, epoll_lt, epoll_et, sigio_rt, select.
id: unknown
Linux corsa03 6.5.?-gentoo-x86_64 #2 SMP PREEMPT_DYNAMIC <not recorded> CEST 2023 x86_64 AMD EPYC 7513 32-Core Processor AuthenticAMD GNU/Linux


Reply to this email directly, view it on GitHub, or unsubscribe.
You are receiving this because you are subscribed to this thread.Message ID: <kamailio/kamailio/issues/3646@github.com>