search

aligungr / UERANSIM

Open source 5G UE and RAN (gNodeB) implementation.
GNU General Public License v3.0
791 stars 323 forks source link

authen failure due to SQN out of range resulted from UERANSIM test of oai-cn5g #320

Open auandrew opened 3 years ago

auandrew commented 3 years ago

Hello Forum & @aligungr,

Like issue #284, I've been trying to use ueransim to test oai-cn5g. The crash in #284 which I also experienced is no more with the latest ueransim code & oai-cn5g's latest code on branch quectel for AMF and branch develop for SMF.

However, I run into a new authentication issue in which the UE side complains about SQN being out of range, as follows.

Has anyone seen this before? @aligungr & Team, please help to take a look. Its debugs & pcap are in the attachment herewith.

Thanks in advance, Andrew

Creating nr_ue ... done
Attaching to nr_ue
nr_ue    | root@60066cb61c6a:/UERANSIM/build# UERANSIM v3.1.9
nr_ue    | [2021-05-13 17:23:11.224] [nas] [info] UE switches to state [MM-DEREGISTERED/PLMN-SEARCH]
nr_ue    | [2021-05-13 17:23:11.226] [rls] [debug] Coverage change detected. [1] cell entered, [0] cell exited
nr_ue    | [2021-05-13 17:23:11.226] [nas] [info] Serving cell determined [UERANSIM-gnb-208-95-1]
nr_ue    | [2021-05-13 17:23:11.226] [nas] [info] UE switches to state [MM-DEREGISTERED/NORMAL-SERVICE]
nr_ue    | [2021-05-13 17:23:11.226] [nas] [debug] Sending Initial Registration
nr_ue    | [2021-05-13 17:23:11.226] [nas] [info] UE switches to state [MM-REGISTER-INITIATED/NA]
nr_ue    | [2021-05-13 17:23:11.226] [rrc] [debug] Sending RRC Setup Request
nr_ue    | [2021-05-13 17:23:11.226] [rrc] [info] RRC connection established
nr_ue    | [2021-05-13 17:23:11.226] [nas] [info] UE switches to state [CM-CONNECTED]
nr_ue    | [2021-05-13 17:23:11.241] [nas] [debug] Sending Authentication Failure due to SQN out of range   <<<<<<<<<<<
nr_ue    | [2021-05-13 17:23:11.252] [nas] [debug] Sending Authentication Failure due to SQN out of range   <<<<<<<<<<<
nr_ue    | [2021-05-13 17:23:11.262] [nas] [debug] Sending Authentication Failure due to SQN out of range   <<<<<<<<<<<
nr_ue    | [2021-05-13 17:23:11.271] [nas] [error] Network failing the authentication check
nr_ue    | [2021-05-13 17:23:11.271] [nas] [info] Performing local release of NAS connection
nr_ue    | [2021-05-13 17:23:11.271] [nas] [info] UE switches to state [CM-IDLE]
nr_ue    | [2021-05-13 17:23:11.271] [nas] [info] UE switches to state [MM-DEREGISTERED/NA]
nr_ue    | [2021-05-13 17:23:11.271] [nas] [info] UE switches to state [5U2-NOT-UPDATED]
nr_ue    | [2021-05-13 17:23:11.271] [nas] [info] UE switches to state [MM-DEREGISTERED/ATTEMPTING-REGISTRATION]
nr_ue    | [2021-05-13 17:23:27.240] [nas] [debug] NAS timer[3520] expired [1]
nr_ue    | [2021-05-13 17:23:27.240] [nas] [error] Network failing the authentication check
nr_ue    | [2021-05-13 17:23:27.240] [nas] [info] Performing local release of NAS connection

SQN-issue.zip

aligungr commented 3 years ago

Hello @auandrew

Please add following two lines to the ue/nas/mm/auth.cpp, line 483

     // Verify that the received sequence number SQN is in the correct range
     if (!m_usim->m_sqnMng->checkSqn(receivedSQN))
+    {
+        m_logger->debug("Received SQN [%s]", receivedSQN.toHexString().c_str());
+        m_logger->debug("SQN-MS [%s]", m_usim->m_sqnMng->getSqn().toHexString().c_str());
+
         return EAutnValidationRes::SYNCHRONISATION_FAILURE;
+    }

This won't fix the problem, but we will be able to see SQN values. In this way we can deduce the cause of the issue.

Regards

auandrew commented 3 years ago

Hello @aligungr ,

Thanks for your suggestion. I've re-tested with your provided patch. The entire set of debug logs & pcap is in the attached zip file herewith.

The additional debug lines showed up are as follows which hopefully can reveal the problem's root cause:

nr_ue    | [2021-05-14 09:38:30.435] [nas] [info] UE switches to state [CM-CONNECTED]
nr_ue    | [2021-05-14 09:38:30.455] [nas] [debug] Received SQN [8E868201931F]
nr_ue    | [2021-05-14 09:38:30.455] [nas] [debug] SQN-MS [000000000000]
nr_ue    | [2021-05-14 09:38:30.455] [nas] [debug] Sending Authentication Failure due to SQN out of range
nr_ue    | [2021-05-14 09:38:30.468] [nas] [debug] Received SQN [7AB92CCC0D1D]
nr_ue    | [2021-05-14 09:38:30.468] [nas] [debug] SQN-MS [000000000000]
nr_ue    | [2021-05-14 09:38:30.468] [nas] [debug] Sending Authentication Failure due to SQN out of range
nr_ue    | [2021-05-14 09:38:30.485] [nas] [debug] Received SQN [8E088D905F10]
nr_ue    | [2021-05-14 09:38:30.485] [nas] [debug] SQN-MS [000000000000]
nr_ue    | [2021-05-14 09:38:30.485] [nas] [debug] Sending Authentication Failure due to SQN out of range
nr_ue    | [2021-05-14 09:38:30.503] [nas] [debug] Received SQN [69DF9413EC00]
nr_ue    | [2021-05-14 09:38:30.503] [nas] [debug] SQN-MS [000000000000]
nr_ue    | [2021-05-14 09:38:30.503] [nas] [error] Network failing the authentication check

SQN-issue-wdebug.zip

aligungr commented 3 years ago

@auandrew

Thanks for the new information.

Now it seems like there is a bug in OAI-CN side.

In case of a synchronization failure, the UDM must derive SQN-MS from received AUTS correctly and synchronize its own SQN value with the UE's SQN.

Regards

jssidhu94 commented 3 years ago

Hi,

Any update on this, because I am facing the same issue.

UERANSIM v3.1.9
[2021-05-18 15:23:07.766] [nas] [info] UE switches to state [MM-DEREGISTERED/PLMN-SEARCH]
[2021-05-18 15:23:07.768] [rls] [debug] Coverage change detected. [1] cell entered, [0] cell exited
[2021-05-18 15:23:07.768] [nas] [info] Serving cell determined [UERANSIM-gnb-208-95-1]
[2021-05-18 15:23:07.768] [nas] [info] UE switches to state [MM-DEREGISTERED/NORMAL-SERVICE]
[2021-05-18 15:23:07.768] [nas] [debug] Sending Initial Registration
[2021-05-18 15:23:07.768] [nas] [info] UE switches to state [MM-REGISTER-INITIATED/NA]
[2021-05-18 15:23:07.768] [rrc] [debug] Sending RRC Setup Request
[2021-05-18 15:23:07.775] [rrc] [info] RRC connection established
[2021-05-18 15:23:07.776] [nas] [info] UE switches to state [CM-CONNECTED]
[2021-05-18 15:23:07.817] [nas] [debug] Sending Authentication Failure due to SQN out of range
[2021-05-18 15:23:07.858] [nas] [debug] Sending Authentication Failure due to SQN out of range
[2021-05-18 15:23:07.896] [nas] [debug] Sending Authentication Failure due to SQN out of range
[2021-05-18 15:23:07.935] [nas] [error] Network failing the authentication check
[2021-05-18 15:23:07.935] [nas] [info] Performing local release of NAS connection
[2021-05-18 15:23:07.935] [nas] [info] UE switches to state [CM-IDLE]
[2021-05-18 15:23:07.935] [nas] [info] UE switches to state [MM-DEREGISTERED/NA]
[2021-05-18 15:23:07.935] [nas] [info] UE switches to state [5U2-NOT-UPDATED]
[2021-05-18 15:23:07.935] [nas] [info] UE switches to state [MM-DEREGISTERED/ATTEMPTING-REGISTRATION]
[2021-05-18 15:23:23.782] [nas] [debug] NAS timer[3520] expired [1]
[2021-05-18 15:23:23.782] [nas] [error] Network failing the authentication check
[2021-05-18 15:23:23.782] [nas] [info] Performing local release of NAS connection

Regards

aligungr commented 3 years ago

I'd like to inform the community about a temporary workaround.

You can go to ue/nas/usim/sqn_mng.cpp line 51, and comment out the controls.

Replace the following:

if (seq - getSeqMs() > m_wrappingDelta)
    return false;
if (seq <= getSeqFromSqn(m_sqnArr[ind]))
    return false;

with

//if (seq - getSeqMs() > m_wrappingDelta)
//    return false;
//if (seq <= getSeqFromSqn(m_sqnArr[ind]))
//    return false;

This is just a temporary solution for the people who has this issue, but of course I don't recommend this patch.

auandrew commented 3 years ago

Thank you @aligungr . I have this issue reported at the oai-cn5g forums, as follows:

infinitydon commented 3 years ago

@auandrew, @aligungr - I have just tested oai-5gc with ueransim 3.1.9 and am not running into any issues currently:

UERANSIM v3.1.9
[2021-05-23 05:09:04.919] [nas] [info] UE switches to state [MM-DEREGISTERED/PLMN-SEARCH]
[2021-05-23 05:09:04.920] [rls] [debug] Coverage change detected. [1] cell entered, [0] cell exited
[2021-05-23 05:09:04.920] [nas] [info] Serving cell determined [UERANSIM-gnb-208-95-1]
[2021-05-23 05:09:04.920] [nas] [info] UE switches to state [MM-DEREGISTERED/NORMAL-SERVICE]
[2021-05-23 05:09:04.920] [nas] [debug] Sending Initial Registration
[2021-05-23 05:09:04.920] [nas] [info] UE switches to state [MM-REGISTER-INITIATED/NA]
[2021-05-23 05:09:04.921] [rrc] [debug] Sending RRC Setup Request
[2021-05-23 05:09:04.921] [rrc] [info] RRC connection established
[2021-05-23 05:09:04.922] [nas] [info] UE switches to state [CM-CONNECTED]
[2021-05-23 05:09:05.075] [nas] [debug] Security Mode Command received
[2021-05-23 05:09:05.075] [nas] [debug] Selected integrity[1] ciphering[1]
[2021-05-23 05:09:05.108] [nas] [debug] Registration accept received
[2021-05-23 05:09:05.108] [nas] [info] UE switches to state [MM-REGISTERED/NORMAL-SERVICE]
[2021-05-23 05:09:05.108] [nas] [info] Initial Registration is successful
[2021-05-23 05:09:05.109] [nas] [info] Initial PDU sessions are establishing [1#]
[2021-05-23 05:09:05.109] [nas] [debug] Sending PDU Session Establishment Request
[2021-05-23 05:09:05.545] [nas] [debug] PDU Session Establishment Accept received
[2021-05-23 05:09:05.549] [nas] [info] PDU Session establishment is successful PSI[1]
[2021-05-23 05:09:05.625] [app] [info] Connection setup for PDU session[1] is successful, TUN interface[uesimtun0, 12.1.1.2] is up.

AMF logs:

image

Most likely this seems to a configuration somewhere.

auandrew commented 3 years ago

Hi @infinitydon , thanks for your info. On which oai-cn5g branch and how up-to-date on it are you?

infinitydon commented 3 years ago

As stated in the other issue #284:

AMF - quectel SMF - develop

if you are using a more recent version than what I stated above, you can let me know, I can test my setup using that.

The reason I did not use a recent version is because the oai-cn5g Dev said they will incorporate the changes in later versions

infinitydon commented 3 years ago

@auandrew - I decided to try with the latest commit in those branches I mentioned above but I did not run into the SQN errors.

The commits I used are:

AMF - quectel ----- 5ba47f73 SMF - develop----- 2a0dd9c8

aligungr commented 3 years ago

@infinitydon Then, probably SQN syncronization works as expected in CN side.

For @auandrew and other people who encounter this error; my suggestion is please double check your configurations. Especially OP/OPc mode and other parameters in UE side.

@infinitydon I'd be glad if you can share your config files.

infinitydon commented 3 years ago

Below are the configs I used, the only major difference is that I used a configuration file directly for the AMF instead of environment variable configuration option because I could not modify the NAS integrity and ciphering parameters.

oai-smf-config.txt oai-upf-config.txt oai-amf-config.txt

infinitydon commented 3 years ago

@aligungr @auandrew - I took the liberty to try the setup in docker-compose, you can check the repo below for the implementation:

https://bitbucket.org/infinitydon/oai-5g-docker-compose/src/main/

I have tested this and seems to work, let me know if you run into any issues.

N.B - You need to exec into the ueransim container manually to start the gnb and ue.

aligungr commented 3 years ago

Thanks for the docket compose @infinitydon. This will be helpful for the people.

Also, perhaps I should put the sample config files in our repository to reduce the configuration related errors. Are your oai-ue.yaml and oai-gnb.yaml files use default values for oia? If so, I might directly put them to our configs folder.

auandrew commented 3 years ago

Hello @infinitydon & @aligungr , thanks for making your sample configs available. Now I see there a difference from my use that I use environment variable config options rather than explicitly modified config files as what @infinitydon did. Let me check for further differences there to find out more exactly!

infinitydon commented 3 years ago

@aligungr - Yes I am using the default values.

aligungr commented 3 years ago

@infinitydon I'm putting a link to your repository in our Wiki page, FYI.

p1-bmu commented 3 years ago

Hi all, @aligungr,

I am going through a similar issue, and find the verification logic in UERANSIM not entirely perfect: In validateAutn(), you check the SQN value provided by the network, before verifying the MAC value. I think it would be better to decrypt the SQN from the network, use it to verify the MAC, and as soon as the MAC is verified only, then check the value of the SQN for synchronization purpose with the local value.

With the current logic, it may happen that UERANSIM accepts a dummy (i.e. mis-decrypted) SQN from the network while there is indeed a broader issue with a failing authentication. I don't have any easy patch as you compute a whole calculateMilenage() function in a different place, while I would like to call only its F1 part, or F2/F3/F4 part independently, in order to implement the aforementioned verification logic. Any ideas ?

Thanks anyway for this excellent software.

radhikamathuria commented 3 years ago

Hi @aligungr

I am facing the same issue, i.e. an Authentication failure due to SQN out of range. The version of UERANSIM I am using is 3.2.4. Is there any workaround to this?

I made the changes in auth.cpp, but I am unable to even see the SQN values. Adding the following results for your reference:

[2021-10-31 22:59:10.233] [nas] [info] UE switches to state [MM-DEREGISTERED/PS] [2021-10-31 22:59:10.234] [nas] [info] UE switches to state [5U2-NOT-UPDATED] [2021-10-31 22:59:10.234] [nas] [info] Performing local release of NAS connection [2021-10-31 22:59:10.234] [nas] [info] UE switches to state [MM-DEREGISTERED/ATTEMPTING-REGISTRATION] [2021-10-31 22:59:10.234] [nas] [debug] NAS timer[3520] expired [1] [2021-10-31 22:59:10.235] [nas] [error] Network failing the authentication check [2021-10-31 22:59:10.235] [nas] [info] Performing local release of NAS connection [2021-10-31 22:59:10.235] [rrc] [info] UE switches to state [RRC-IDLE] [2021-10-31 22:59:10.235] [nas] [info] UE switches to state [CM-IDLE] [2021-10-31 22:59:10.235] [rrc] [info] UE switches to state [RRC-IDLE] [2021-10-31 22:59:20.263] [nas] [debug] NAS timer[3511] expired [1] [2021-10-31 22:59:20.263] [nas] [debug] Initial registration required due to [T3511-EXPIRY-IN-ATT-REG] [2021-10-31 22:59:20.264] [nas] [debug] UAC access attempt is allowed for identity[0], category[MO_sig] [2021-10-31 22:59:20.264] [nas] [debug] Sending Initial Registration [2021-10-31 22:59:20.265] [nas] [info] UE switches to state [MM-REGISTER-INITIATED] [2021-10-31 22:59:20.265] [rrc] [debug] Sending RRC Setup Request [2021-10-31 22:59:20.268] [rrc] [info] RRC connection established [2021-10-31 22:59:20.268] [rrc] [info] UE switches to state [RRC-CONNECTED] [2021-10-31 22:59:20.268] [nas] [info] UE switches to state [CM-CONNECTED] [2021-10-31 22:59:20.286] [nas] [debug] Authentication Request received [2021-10-31 22:59:20.286] [nas] [debug] Sending Authentication Failure due to SQN out of range

PS: I am using free5GC.

Aharonez commented 2 years ago

Hello @radhikamathuria, have you solved it? I am using Free5gc as well and encountered the same issue.

pragyasharmaa commented 8 months ago

I am facing the same issue in free5gc