herlesupreeth / Kamailio_IMS_Config

Fixed version of Kamailio IMS configuration files for basic calling
45 stars 36 forks source link

No registration with ims-communicator: 403 Authentitication Failed #16

Closed Dgeka25594 closed 2 years ago

Dgeka25594 commented 2 years ago

Hi, herlesupreeth! I would be grateful if you can help me, I broke my head solving this problem. Immediately apologize for my English.

I am setting up Kamailio IMS on VirtualBox: FHоSS 192.168.56.110 PCSCF 192.168.56.112 ICSCF 192.168.56.113 SCSCF 192.168.56.109 Instead of UE, I use ims-communicator (https://sourceforge.net/projects/imscommunicator.berlios/), the authentification algorithm I use AKAv1-MD5. User profiles are standard, Bob. I answer:

CDATA[SIP/2.0 403 Authentication Failed
Call-ID: 4d2dec8ff4bd3e0b2135ce28491c7773@10.2.16.7
CSeq: 2 REGISTER
Via: SIP/2.0/UDP 10.2.16.7:5060;rport=5060;branch=z9hG4bK96f147b25a0d531964930fa3bb733041
From: "bob" <sip:bob@ims.local>;tag=1140338296
To: "bob" <sip:bob@ims.local>;tag=184e029c10d1260618967590dddeffe9.4729ef90
Server: Kamailio S-CSCF
Content-Length: 0

I don't understand the error from the CSCSCF logs, the user status is written to HSS as AUTH-PENDING.

Nov 11 11:53:35 scscf /usr/sbin/kamailio[29124]: DEBUG: ims_dialog [dlg_handlers.c:1923]: print_all_dlgs(): ********************
Nov 11 11:53:35 scscf /usr/sbin/kamailio[29124]: DEBUG: ims_dialog [dlg_handlers.c:1924]: print_all_dlgs(): printing 4096 dialogs
Nov 11 11:53:35 scscf /usr/sbin/kamailio[29124]: DEBUG: ims_dialog [dlg_handlers.c:1934]: print_all_dlgs(): ********************
Nov 11 11:53:35 scscf /usr/sbin/kamailio[29124]: DEBUG: ims_auth [authorize.c:187]: reg_await_timer(): Looking for expired/useless at 31955412
Nov 11 11:53:35 scscf /usr/sbin/kamailio[29124]: DEBUG: ims_auth [authorize.c:192]: reg_await_timer(): Slot  509 <bob@ims.local>
Nov 11 11:53:35 scscf /usr/sbin/kamailio[29124]: DEBUG: ims_auth [authorize.c:232]: reg_await_timer(): [DONE] Looking for expired/useless at 31955412
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29121]: NOTICE: <script>: SCSCF: REGISTER sip:scscf.ims.local:6060 (sip:bob@ims.local (192.168.56.113:4060) to sip:bob@ims.local, 4d2dec8ff4bd3e0b2135ce28491c7773@10.2.16.7)
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29121]: ERROR: <script>: ALGORITHM IS [] and User-Agent is [IMS-Communicator 070518]
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29121]: DEBUG: ims_auth [authorize.c:728]: authenticate(): Running authenticate, is_proxy_auth=0
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29121]: DEBUG: ims_auth [authorize.c:748]: authenticate(): Checking if REGISTER is authorized for realm [ims.local]...
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29121]: DEBUG: ims_auth [utils.c:168]: get_nonce_response(): Calling find_credentials with realm [ims.local]
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29121]: DEBUG: ims_auth [utils.c:57]: ims_find_credentials(): Searching credentials in realm [ims.local]
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29121]: DEBUG: ims_auth [utils.c:92]: ims_find_credentials(): *hook = 0x7f5222a529c8
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29121]: DEBUG: ims_auth [utils.c:103]: ims_find_credentials(): Credential parsed successfully
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29121]: DEBUG: ims_auth [utils.c:106]: ims_find_credentials(): Comparing realm <ims.local> and <ims.local>
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29121]: DEBUG: ims_auth [utils.c:195]: get_nonce_response(): Found nonce response
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29121]: DEBUG: ims_auth [authorize.c:786]: authenticate(): Nonce or response missing: nonce len [0], response16 len[0]
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29121]: DEBUG: ims_auth [authorize.c:293]: challenge(): Looking for route block [REG_MAR_REPLY]
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29121]: INFO: ims_auth [cxdx_mar.c:79]: create_return_code(): created AVP successfully : [maa_return_code] - [-2]
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29121]: DEBUG: ims_auth [authorize.c:317]: challenge(): Need to challenge for realm [ims.local]
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29121]: DEBUG: ims_auth [authorize.c:324]: challenge(): Checking if REGISTER is authorized for realm [ims.local]...
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29121]: DEBUG: ims_auth [authorize.c:1448]: get_auth_userdata(): Searching auth_userdata for IMPU sip:bob@ims.local (Hash 509)
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29121]: DEBUG: ims_auth [authorize.c:1457]: get_auth_userdata(): Found auth_userdata
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29121]: DEBUG: ims_auth [authorize.c:460]: challenge(): Suspending SIP TM transaction
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29121]: DEBUG: ims_auth [authorize.c:1528]: multimedia_auth_request(): Sending MAR
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29121]: DEBUG: ims_auth [cxdx_mar.c:549]: cxdx_send_mar(): Successfully sent async diameter
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29135]: INFO: ims_auth [cxdx_avp.c:137]: cxdx_get_avp(): cxdx_get_experimental_result_code: Failed finding avp (avp_code = 297, vendor_id = 0)
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29135]: DEBUG: ims_auth [authorize.c:1305]: new_auth_vector(): new auth-vector with ck [fbba17f90da5816dcf5e7462d7db772b] with status 0
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29135]: DEBUG: ims_auth [authorize.c:1559]: pack_challenge(): setting QOP str used is [, qop="auth,auth-int"]
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29135]: DEBUG: ims_auth [authorize.c:1561]: pack_challenge(): QOP str used is [, qop="auth,auth-int"]
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29135]: DEBUG: ims_auth [authorize.c:1448]: get_auth_userdata(): Searching auth_userdata for IMPU sip:bob@ims.local (Hash 509)
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29135]: DEBUG: ims_auth [authorize.c:1457]: get_auth_userdata(): Found auth_userdata
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29135]: DEBUG: ims_auth [authorize.c:1681]: add_auth_vector(): Adding auth_vector (status 1) for IMPU sip:bob@ims.local / IMPI bob@ims.local (Hash 509)
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29135]: DEBUG: ims_auth [cxdx_mar.c:464]: async_cdp_callback(): DBG:UAR Async CDP callback: ... Done resuming transaction
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29135]: INFO: ims_auth [cxdx_mar.c:79]: create_return_code(): created AVP successfully : [maa_return_code] - [1]
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29135]: ERROR: tm [t_suspend.c:192]: t_continue_helper(): active transaction not found
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29135]: DEBUG: ims_auth [cxdx_mar.c:87]: free_saved_transaction_data(): Freeing saved transaction data: async
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29123]: NOTICE: <script>: SCSCF: REGISTER sip:scscf.ims.local:6060 (sip:bob@ims.local (192.168.56.113:4060) to sip:bob@ims.local, 4d2dec8ff4bd3e0b2135ce28491c7773@10.2.16.7)
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29123]: ERROR: <script>: ALGORITHM IS [AKAv1-MD5] and User-Agent is [IMS-Communicator 070518]
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29123]: DEBUG: ims_auth [authorize.c:728]: authenticate(): Running authenticate, is_proxy_auth=0
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29123]: DEBUG: ims_auth [authorize.c:748]: authenticate(): Checking if REGISTER is authorized for realm [ims.local]...
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29123]: DEBUG: ims_auth [utils.c:168]: get_nonce_response(): Calling find_credentials with realm [ims.local]
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29123]: DEBUG: ims_auth [utils.c:57]: ims_find_credentials(): Searching credentials in realm [ims.local]
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29123]: DEBUG: ims_auth [utils.c:92]: ims_find_credentials(): *hook = 0x7f5222a524b0
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29123]: DEBUG: ims_auth [utils.c:103]: ims_find_credentials(): Credential parsed successfully
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29123]: DEBUG: ims_auth [utils.c:106]: ims_find_credentials(): Comparing realm <ims.local> and <ims.local>
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29123]: DEBUG: ims_auth [utils.c:195]: get_nonce_response(): Found nonce response
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29123]: DEBUG: ims_auth [authorize.c:797]: authenticate(): look for an already used vector for bob@ims.local
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29123]: DEBUG: ims_auth [authorize.c:1448]: get_auth_userdata(): Searching auth_userdata for IMPU sip:bob@ims.local (Hash 509)
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29123]: DEBUG: ims_auth [authorize.c:1457]: get_auth_userdata(): Found auth_userdata
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29123]: DEBUG: ims_auth [authorize.c:1064]: get_auth_vector(): looping through AV status is 1 and were looking for 3
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29123]: DEBUG: ims_auth [authorize.c:806]: authenticate(): Looking for auth vector based on IMPI: [bob@ims.local] and IMPU: [sip:bob@ims.local]
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29123]: DEBUG: ims_auth [authorize.c:1448]: get_auth_userdata(): Searching auth_userdata for IMPU sip:bob@ims.local (Hash 509)
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29123]: DEBUG: ims_auth [authorize.c:1457]: get_auth_userdata(): Found auth_userdata
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29123]: DEBUG: ims_auth [authorize.c:822]: authenticate(): look for a fresh vector for bob@ims.local
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29123]: DEBUG: ims_auth [authorize.c:1448]: get_auth_userdata(): Searching auth_userdata for IMPU sip:bob@ims.local (Hash 509)
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29123]: DEBUG: ims_auth [authorize.c:1457]: get_auth_userdata(): Found auth_userdata
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29123]: DEBUG: ims_auth [authorize.c:1064]: get_auth_vector(): looping through AV status is 1 and were looking for 1
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29123]: DEBUG: ims_auth [authorize.c:1066]: get_auth_vector(): Found result
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29123]: INFO: ims_auth [authorize.c:827]: authenticate(): uri=sip:ims.local nonce=nq6VQejc01kRr/pZzewvtjrz0Gjm9QAAd/YHxdoaIE0= response=2999b70a35ed80ac7dd988d325510ad9 qop= nc= cnonce= hbody=
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29123]: DEBUG: ims_auth [rfc2617.c:135]: calc_response(): calc_response(_ha1=ba56eddf524a884714bc561c4cdfbc13, _nonce=nq6VQejc01kRr/pZzewvtjrz0Gjm9QAAd/YHxdoaIE0=, _nc=,_cnonce=, _qop=, _auth_int=0,_method=REGISTER,_uri=sip:ims.local,_hentity=)
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29123]: DEBUG: ims_auth [rfc2617.c:185]: calc_response(): H(A1) = ba56eddf524a884714bc561c4cdfbc13, H(A2) = 2160f61155151141448c74e2c08b234f, rspauth = 9d0d2dfc1c89de76a8ec45081954b249
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29123]: INFO: ims_auth [authorize.c:882]: authenticate(): UE said: 2999b70a35ed80ac7dd988d325510ad9 and we expect 9d0d2dfc1c89de76a8ec45081954b249 ha1 ba56eddf524a884714bc561c4cdfbc13 (REGISTER)
Nov 11 11:53:36 scscf /usr/sbin/kamailio[29123]: DEBUG: ims_auth [authorize.c:987]: authenticate(): UE said: 2999b70a35ed80ac7dd988d325510ad9, but we expect 9d0d2dfc1c89de76a8ec45081954b249 : authenticate(b64) is [nq6VQejc01kRr/pZzewvtjrz0Gjm9QAAd/YHxdoaIE0=], authenticate(hex) is [9eae9541e8dcd35911affa59cdec2fb63af3d068e6f5000077f607c5da1a204d], authorise is [16] [7575ef8ec0b9746a]
Nov 11 11:53:45 scscf /usr/sbin/kamailio[29124]: DEBUG: ims_dialog [dlg_handlers.c:1923]: print_all_dlgs(): ********************
Nov 11 11:53:45 scscf /usr/sbin/kamailio[29124]: DEBUG: ims_dialog [dlg_handlers.c:1924]: print_all_dlgs(): printing 4096 dialogs
Nov 11 11:53:45 scscf /usr/sbin/kamailio[29124]: DEBUG: ims_dialog [dlg_handlers.c:1934]: print_all_dlgs(): ********************
Nov 11 11:53:45 scscf /usr/sbin/kamailio[29124]: DEBUG: ims_auth [authorize.c:187]: reg_await_timer(): Looking for expired/useless at 31955422
Nov 11 11:53:45 scscf /usr/sbin/kamailio[29124]: DEBUG: ims_auth [authorize.c:192]: reg_await_timer(): Slot  509 <bob@ims.local>
Nov 11 11:53:45 scscf /usr/sbin/kamailio[29124]: DEBUG: ims_auth [authorize.c:197]: reg_await_timer(): .. AV    1 - 2 Exp 31955474  0x7f521b70b650
Nov 11 11:53:45 scscf /usr/sbin/kamailio[29124]: DEBUG: ims_auth [authorize.c:203]: reg_await_timer(): ... dropping av 1 - 2
Nov 11 11:53:45 scscf /usr/sbin/kamailio[29124]: DEBUG: ims_auth [authorize.c:232]: reg_await_timer(): [DONE] Looking for expired/useless at 31955422
Nov 11 11:53:55 scscf /usr/sbin/kamailio[29124]: DEBUG: ims_dialog [dlg_handlers.c:1923]: print_all_dlgs(): ********************
Nov 11 11:53:55 scscf /usr/sbin/kamailio[29124]: DEBUG: ims_dialog [dlg_handlers.c:1924]: print_all_dlgs(): printing 4096 dialogs
Nov 11 11:53:55 scscf /usr/sbin/kamailio[29124]: DEBUG: ims_dialog [dlg_handlers.c:1934]: print_all_dlgs(): ********************
Nov 11 11:53:55 scscf /usr/sbin/kamailio[29124]: DEBUG: ims_auth [authorize.c:187]: reg_await_timer(): Looking for expired/useless at 31955432
Nov 11 11:53:55 scscf /usr/sbin/kamailio[29124]: DEBUG: ims_auth [authorize.c:192]: reg_await_timer(): Slot  509 <bob@ims.local>
Nov 11 11:53:55 scscf /usr/sbin/kamailio[29124]: DEBUG: ims_auth [authorize.c:232]: reg_await_timer(): [DONE] Looking for expired/useless at 31955432
Nov 11 11:54:05 scscf /usr/sbin/kamailio[29124]: DEBUG: ims_dialog [dlg_handlers.c:1923]: print_all_dlgs(): ********************

The dump shows that after the second REGISTER comes Status: 403 Authentitication Failed. The dump shows that ims-communicator is sending the second REGISTER with the authentification algorithm AKAv1-MD5. In scscf.cfg I have included AKAv1-MD5.

I found errors in the PCSCF log, No security parameters found, but I assume they are due to the fact that the client is without IPSEC and does not interfere with the request further.

Nov 11 11:53:36 pcscf /usr/sbin/kamailio[114408]: ERROR: <script>: REGISTER (sip:bob@ims.local (10.2.16.7:5060) to sip:bob@ims.local, 4d2dec8ff4bd3e0b2135ce28491c7773@10.2.16.7)
Nov 11 11:53:36 pcscf /usr/sbin/kamailio[114408]: INFO: rr [rr_mod.c:515]: pv_get_route_uri_f(): No route header present.
Nov 11 11:53:36 pcscf /usr/sbin/kamailio[114408]: INFO: ims_registrar_pcscf [sec_agree.c:264]: cscf_get_security(): No security parameters found
Nov 11 11:53:36 pcscf /usr/sbin/kamailio[114408]: INFO: ims_registrar_pcscf [sec_agree.c:296]: cscf_get_security_verify(): No security-verify parameters found
Nov 11 11:53:36 pcscf /usr/sbin/kamailio[114414]: ERROR: ims_ipsec_pcscf [cmd.c:673]: ipsec_create(): No security parameters found in contact
Nov 11 11:53:36 pcscf /usr/sbin/kamailio[114417]: ERROR: <script>: REGISTER (sip:bob@ims.local (10.2.16.7:5060) to sip:bob@ims.local, 4d2dec8ff4bd3e0b2135ce28491c7773@10.2.16.7)
Nov 11 11:53:36 pcscf /usr/sbin/kamailio[114417]: INFO: rr [rr_mod.c:515]: pv_get_route_uri_f(): No route header present.
Nov 11 11:53:36 pcscf /usr/sbin/kamailio[114417]: INFO: ims_registrar_pcscf [sec_agree.c:264]: cscf_get_security(): No security parameters found
Nov 11 11:53:36 pcscf /usr/sbin/kamailio[114417]: INFO: ims_registrar_pcscf [sec_agree.c:296]: cscf_get_security_verify(): No security-verify parameters found

I cannot determine the source of the problem. dumps.zip

Dumps, log and config are attache icscf.zip pcscf.zip scscf.zip hss.zip

Dgeka25594 commented 2 years ago

I rebuilt Kamailio (on VMachine) and the difference was in the configs compared to the IMS_Kamailio template. Now there is such an error on the PCSCF:

 3(141510) NOTICE: <script>: PCSCF: REGISTER sip:ims.mnc001.mcc001.3gppnetwork.org (sip:bob@ims.mnc001.mcc001.3gppnetwork.org (10.2.16.7:5060) to sip:bob@ims.mnc001.mcc001.3gppnetwork.org, 2e1cf44b667071def5332be769f348d1@10.2.16.7)
 3(141510) INFO: rr [rr_mod.c:515]: pv_get_route_uri_f(): No route header present.
 3(141510) NOTICE: <script>: PCSCF REGISTER:
 Destination URI: <null>
 Request URI: sip:ims.mnc001.mcc001.3gppnetwork.org
 3(141510) INFO: rr [rr_mod.c:515]: pv_get_route_uri_f(): No route header present.
 3(141510) NOTICE: <script>: Source IP and Port: (10.2.16.7:5060)
 Route-URI:
 3(141510) NOTICE: <script>: Received IP and Port: (192.168.56.117:5060)
 3(141510) NOTICE: <script>: Contact header: <sip:bob@10.2.16.7:5060>
 3(141510) INFO: ims_registrar_pcscf [sec_agree.c:264]: cscf_get_security(): No security parameters found
 3(141510) INFO: ims_registrar_pcscf [sec_agree.c:296]: cscf_get_security_verify(): No security-verify parameters found
 3(141510) ERROR: cdp [routing.c:274]: get_routing_peer(): get_routing_peer(): No connected DefaultRoute peer found for app_id 16777236 and vendor id 10415.
 3(141510) ERROR: cdp [diameter_comm.c:142]: AAASendMessage(): AAASendMessage(): Can't find a suitable connected peer in the routing table.
 3(141510) ERROR: ims_qos [ims_qos_mod.c:1414]: w_rx_aar_register(): Failed to send AAR
 3(141510) ERROR: ims_qos [ims_qos_mod.c:1458]: w_rx_aar_register(): Error trying to send AAR
 3(141510) WARNING: tm [t_lookup.c:1504]: t_unref(): script writer didn't release transaction

So I understand the problem with the Kamailio routes. But why was it not a problem with my configs.

Dgeka25594 commented 2 years ago

The problem was solved by other clients Boghe https://boghe-ims-client.software.informer.com/1.0/