aligungr / UERANSIM

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

nr-ue crashed after received pdu session establishment accept #561

Open myonlystarWang opened 1 year ago

myonlystarWang commented 1 year ago

Hi @aligungr I have met a nr-ue crash problem with a commercial 5GC. Initial registeration was successfull,but after received pdu session establishment accept nr-ue was crashed.Log is below:

root@user:~/UERANSIM/build# ./nr-ue -c ../config/open5gs-ue.yaml
UERANSIM v3.2.6
[2022-09-26 12:09:46.020] [nas] [info] UE switches to state [MM-DEREGISTERED/PLMN-SEARCH]
[2022-09-26 12:09:46.022] [rrc] [debug] New signal detected for cell[1], total [1] cells in coverage
[2022-09-26 12:09:46.022] [nas] [info] Selected plmn[460/00]
[2022-09-26 12:09:46.022] [rrc] [info] Selected cell plmn[460/00] tac[512000] category[SUITABLE]
[2022-09-26 12:09:46.022] [nas] [info] UE switches to state [MM-DEREGISTERED/PS]
[2022-09-26 12:09:46.022] [nas] [info] UE switches to state [MM-DEREGISTERED/NORMAL-SERVICE]
[2022-09-26 12:09:46.022] [nas] [debug] Initial registration required due to [MM-DEREG-NORMAL-SERVICE]
[2022-09-26 12:09:46.024] [nas] [debug] UAC access attempt is allowed for identity[0], category[MO_sig]
[2022-09-26 12:09:46.024] [nas] [debug] Sending Initial Registration
[2022-09-26 12:09:46.024] [nas] [info] UE switches to state [MM-REGISTER-INITIATED]
[2022-09-26 12:09:46.024] [rrc] [debug] Sending RRC Setup Request
[2022-09-26 12:09:46.024] [rrc] [info] RRC connection established
[2022-09-26 12:09:46.024] [rrc] [info] UE switches to state [RRC-CONNECTED]
[2022-09-26 12:09:46.024] [nas] [info] UE switches to state [CM-CONNECTED]
[2022-09-26 12:09:46.037] [nas] [debug] Authentication Request received
[2022-09-26 12:09:46.052] [nas] [debug] Security Mode Command received
[2022-09-26 12:09:46.052] [nas] [debug] Selected integrity[3] ciphering[0]
[2022-09-26 12:09:46.068] [nas] [debug] Registration accept received
[2022-09-26 12:09:46.068] [nas] [info] UE switches to state [MM-REGISTERED/NORMAL-SERVICE]
[2022-09-26 12:09:46.068] [nas] [debug] Sending Registration Complete
[2022-09-26 12:09:46.068] [nas] [info] Initial Registration is successful
[2022-09-26 12:09:46.068] [nas] [debug] Sending PDU Session Establishment Request
[2022-09-26 12:09:46.068] [nas] [debug] UAC access attempt is allowed for identity[0], category[MO_sig]
terminate called after throwing an instance of 'std::runtime_error'
  what():  Bad constructed NAS message
Aborted (core dumped)

The pcap file is here: 5g.zip

Maybe you can see what the problem is. Thank you.

myonlystarWang commented 1 year ago

Hi @aligungr , I have updated more info here, I use gdb and get the error calltrace as below:

(gdb) r -c ../config/open5gs-ue.yaml
Starting program: /home/user/UERANSIM-3.2.6/build/nr-ue -c ../config/open5gs-ue.yaml
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
UERANSIM v3.2.6
[New Thread 0x7ffff6e83700 (LWP 38485)]
[New Thread 0x7ffff6682700 (LWP 38486)]
[New Thread 0x7ffff5e81700 (LWP 38487)]
[2022-10-26 02:50:43.549] [nas] [info] UE switches to state [MM-DEREGISTERED/PLMN-SEARCH]
[New Thread 0x7ffff5680700 (LWP 38488)]
[New Thread 0x7ffff4e7f700 (LWP 38489)]
[New Thread 0x7fffe7fff700 (LWP 38490)]
[New Thread 0x7fffe77fe700 (LWP 38491)]
[2022-10-26 02:50:43.550] [rrc] [debug] New signal detected for cell[1], total [1] cells in coverage
[2022-10-26 02:50:43.551] [nas] [info] Selected plmn[460/01]
[2022-10-26 02:50:43.551] [rrc] [info] Selected cell plmn[460/01] tac[512000] category[SUITABLE]
[New Thread 0x7fffe6ffd700 (LWP 38492)]
[2022-10-26 02:50:43.551] [nas] [info] UE switches to state [MM-DEREGISTERED/PS]
[2022-10-26 02:50:43.551] [nas] [info] UE switches to state [MM-DEREGISTERED/NORMAL-SERVICE]
[2022-10-26 02:50:43.551] [nas] [debug] Initial registration required due to [MM-DEREG-NORMAL-SERVICE]
[2022-10-26 02:50:43.551] [nas] [debug] UAC access attempt is allowed for identity[0], category[MO_sig]
[2022-10-26 02:50:43.552] [nas] [debug] Sending Initial Registration
[2022-10-26 02:50:43.552] [nas] [info] UE switches to state [MM-REGISTER-INITIATED]
[2022-10-26 02:50:43.552] [rrc] [debug] Sending RRC Setup Request
[2022-10-26 02:50:43.553] [rrc] [info] RRC connection established
[2022-10-26 02:50:43.553] [rrc] [info] UE switches to state [RRC-CONNECTED]
[2022-10-26 02:50:43.553] [nas] [info] UE switches to state [CM-CONNECTED]
[2022-10-26 02:50:43.572] [nas] [debug] Authentication Request received
[2022-10-26 02:50:43.783] [nas] [debug] Security Mode Command received
[2022-10-26 02:50:43.783] [nas] [debug] Selected integrity[3] ciphering[0]
[2022-10-26 02:50:43.804] [nas] [debug] Registration accept received
[2022-10-26 02:50:43.804] [nas] [info] UE switches to state [MM-REGISTERED/NORMAL-SERVICE]
[2022-10-26 02:50:43.804] [nas] [debug] Sending Registration Complete
[2022-10-26 02:50:43.804] [nas] [info] Initial Registration is successful
[2022-10-26 02:50:43.805] [nas] [debug] Sending PDU Session Establishment Request
[2022-10-26 02:50:43.805] [nas] [debug] UAC access attempt is allowed for identity[0], category[MO_sig]
terminate called after throwing an instance of 'std::runtime_error'
  what():  Bad constructed NAS message

Thread 4 "nr-ue" received signal SIGABRT, Aborted.
[Switching to Thread 0x7ffff5e81700 (LWP 38487)]
__GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51
51      ../sysdeps/unix/sysv/linux/raise.c: No such file or directory.
(gdb) bt
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51
#1  0x00007ffff72627f1 in __GI_abort () at abort.c:79
#2  0x00007ffff78b7957 in ?? () from /usr/lib/x86_64-linux-gnu/libstdc++.so.6
#3  0x00007ffff78bdae6 in ?? () from /usr/lib/x86_64-linux-gnu/libstdc++.so.6
#4  0x00007ffff78bdb21 in std::terminate() () from /usr/lib/x86_64-linux-gnu/libstdc++.so.6
#5  0x00007ffff78bdd54 in __cxa_throw () from /usr/lib/x86_64-linux-gnu/libstdc++.so.6
#6  0x000055555568dd54 in nas::DecodeNasMessage(OctetView const&) ()
#7  0x0000555555649a1f in nr::ue::NasMm::receiveDlNasTransport(nas::DlNasTransport const&) ()
#8  0x0000555555626d05 in nr::ue::NasMm::receiveMmMessage(nas::PlainMmMessage const&) ()
#9  0x00005555556286a7 in nr::ue::NasMm::receiveNasMessage(nas::NasMessage const&) ()
#10 0x000055555563b680 in nr::ue::NasMm::handleRrcEvent(nr::ue::NmUeRrcToNas const&) ()
#11 0x00005555555fe60f in nr::ue::NasTask::onLoop() ()
#12 0x000055555570236c in std::thread::_State_impl<std::thread::_Invoker<std::tuple<NtsTask::start()::{lambda()#1}> > >::_M_run() ()
#13 0x00007ffff78e86df in ?? () from /usr/lib/x86_64-linux-gnu/libstdc++.so.6
#14 0x00007ffff7bbb6db in start_thread (arg=0x7ffff5e81700) at pthread_create.c:463
#15 0x00007ffff734361f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Hope this will help find the problem,thanks!