Hi,
We use landslide(from spirent) to test free5gc. And when we set “the PDU for every subscriber” to 5, the system raise an warn and erro like this:
[WARN][UPF][Util] Pool is empty
[ERROR][UPF][Util] bufPool64 is empty
[ERROR][UPF][Util] UTLT_Malloc fail
[ERROR][UPF][Util] Allocate new slot error
So we want to know the free5gc v3.0.4 support 1 subscriber with more than 1 PDU session or not ? If the answer is yes, where and how can we set the UPF ip pool ?
Thank you
Hi,
in short: I don’t know. However, until you will get a free5gc offical answer:
Have you checked the upfcfg.yaml file. There is a dnn_list with currently one entry. maybe you can add another one there. e.g.:
dnn_list:
I don’t know if this causes two PDU sessions on subscriber side as well. But maybe give it a try.
best,
Ralf
Thank you for your help!
Hello,
I have the same problem when I add more than 9DNN to the list and with time expire also the UPF have a segmentation fault.
. UPF VM1
ubuntu@PSA-UPF1:~/free5gc/NFs/upf/build$ sudo ./bin/free5gc-upfd
2021-10-22T22:15:31Z [INFO][UPF][Util] Config: /home/ubuntu/free5gc/NFs/upf/build/config/upfcfg.yaml
2021-10-22T22:15:31Z [INFO][UPF][Util] UPF config version [1.0.0]
2021-10-22T22:15:31Z [INFO][UPF][Util] Set log level: info
2021-10-22T22:15:31Z [INFO][UPF][Util] DNN routes added, main routing table:
2021-10-22T22:15:31Z [INFO][UPF][Util] DstIp Gateway Iface Priority RtProto Type
2021-10-22T22:15:31Z [INFO][UPF][Util] 192.168.56.0 /24 0.0.0.0 enp0s10 0 kernel unicast
2021-10-22T22:15:31Z [INFO][UPF][Util] 172.16.4.0 /24 0.0.0.0 enp0s9 0 kernel unicast
2021-10-22T22:15:31Z [INFO][UPF][Util] 172.16.3.0 /24 0.0.0.0 enp0s8 0 kernel unicast
2021-10-22T22:15:31Z [INFO][UPF][Util] 60.69.0.0 /24 0.0.0.0 upfgtp 0 static unicast
2021-10-22T22:15:31Z [INFO][UPF][Util] 60.68.0.0 /24 0.0.0.0 upfgtp 0 static unicast
2021-10-22T22:15:31Z [INFO][UPF][Util] 60.67.0.0 /24 0.0.0.0 upfgtp 0 static unicast
2021-10-22T22:15:31Z [INFO][UPF][Util] 60.66.0.0 /24 0.0.0.0 upfgtp 0 static unicast
2021-10-22T22:15:31Z [INFO][UPF][Util] 60.65.0.0 /24 0.0.0.0 upfgtp 0 static unicast
2021-10-22T22:15:31Z [INFO][UPF][Util] 60.64.0.0 /24 0.0.0.0 upfgtp 0 static unicast
2021-10-22T22:15:31Z [INFO][UPF][Util] 60.63.0.0 /24 0.0.0.0 upfgtp 0 static unicast
2021-10-22T22:15:31Z [INFO][UPF][Util] 60.62.0.0 /24 0.0.0.0 upfgtp 0 static unicast
2021-10-22T22:15:31Z [INFO][UPF][Util] 60.61.0.0 /24 0.0.0.0 upfgtp 0 static unicast
2021-10-22T22:15:31Z [INFO][UPF][Util] 60.60.0.0 /24 0.0.0.0 upfgtp 0 static unicast
2021-10-22T22:15:31Z [INFO][UPF][Util] 10.0.2.2 /32 0.0.0.0 enp0s3 100 dhcp unicast
2021-10-22T22:15:31Z [INFO][UPF][Util] 10.0.2.0 /24 0.0.0.0 enp0s3 0 kernel unicast
2021-10-22T22:15:31Z [INFO][UPF][Util] 0.0.0.0 /0 10.0.2.2 enp0s3 100 dhcp unicast
2021-10-22T22:15:40Z [INFO][UPF][Util] [PFCP] Handle PFCP association setup request
2021-10-22T22:15:40Z [INFO][UPF][Util] [PFCP] Association Setup Response
2021-10-22T22:17:51Z [INFO][UPF][Util] [PFCP] Handle PFCP session establishment request
2021-10-22T22:17:51Z [INFO][UPF][Util] [PFCP] Session Establishment Response
2021-10-22T22:17:51Z [INFO][UPF][Util] [PFCP] Handle PFCP session establishment request
2021-10-22T22:17:51Z [INFO][UPF][Util] [PFCP] Session Establishment Response
2021-10-22T22:17:51Z [INFO][UPF][Util] [PFCP] Handle PFCP session establishment request
2021-10-22T22:17:51Z [INFO][UPF][Util] [PFCP] Session Establishment Response
2021-10-22T22:17:51Z [INFO][UPF][Util] [PFCP] Handle PFCP session establishment request
2021-10-22T22:17:51Z [INFO][UPF][Util] [PFCP] Session Establishment Response
2021-10-22T22:17:52Z [INFO][UPF][Util] [PFCP] Handle PFCP session establishment request
2021-10-22T22:17:52Z [INFO][UPF][Util] [PFCP] Session Establishment Response
2021-10-22T22:17:52Z [INFO][UPF][Util] [PFCP] Handle PFCP session establishment request
2021-10-22T22:17:52Z [INFO][UPF][Util] [PFCP] Session Establishment Response
2021-10-22T22:17:52Z [INFO][UPF][Util] [PFCP] Handle PFCP session establishment request
2021-10-22T22:17:52Z [INFO][UPF][Util] [PFCP] Session Establishment Response
2021-10-22T22:17:52Z [INFO][UPF][Util] [PFCP] Handle PFCP session establishment request
2021-10-22T22:17:52Z [INFO][UPF][Util] [PFCP] Session Establishment Response
2021-10-22T22:17:52Z [INFO][UPF][Util] [PFCP] Handle PFCP session establishment request
2021-10-22T22:17:52Z [INFO][UPF][Util] [PFCP] Session Establishment Response
2021-10-22T22:17:52Z [INFO][UPF][Util] [PFCP] Handle PFCP session establishment request
2021-10-22T22:17:52Z [WARN][UPF][Util] Pool is empty
2021-10-22T22:17:52Z [ERRO][UPF][Util] bufPool64 is empty
2021-10-22T22:17:52Z [ERRO][UPF][Util] buffer block alloc error
2021-10-22T22:17:52Z [WARN][UPF][Util] Pool is empty
2021-10-22T22:17:52Z [ERRO][UPF][Util] bufPool64 is empty
2021-10-22T22:17:52Z [ERRO][UPF][Util] buffer block alloc error
2021-10-22T22:17:52Z [WARN][UPF][Util] Pool is empty
2021-10-22T22:17:52Z [ERRO][UPF][Util] bufPool64 is empty
2021-10-22T22:17:52Z [ERRO][UPF][Util] buffer block alloc error
2021-10-22T22:17:52Z [WARN][UPF][Util] Pool is empty
2021-10-22T22:17:52Z [ERRO][UPF][Util] bufPool64 is empty
2021-10-22T22:17:52Z [ERRO][UPF][Util] buffer block alloc error
2021-10-22T22:17:52Z [ERRO][UPF][Util] pfcpXact update TX error
2021-10-22T22:17:52Z [INFO][UPF][Util] [PFCP] Handle PFCP session modification request
2021-10-22T22:17:52Z [INFO][UPF][Util] [PFCP] Session Modification Response
2021-10-22T22:17:52Z [INFO][UPF][Util] [PFCP] Handle PFCP session modification request
2021-10-22T22:17:52Z [INFO][UPF][Util] [PFCP] Session Modification Response
2021-10-22T22:17:52Z [INFO][UPF][Util] [PFCP] Handle PFCP session modification request
2021-10-22T22:17:52Z [INFO][UPF][Util] [PFCP] Session Modification Response
2021-10-22T22:17:52Z [INFO][UPF][Util] [PFCP] Handle PFCP session modification request
2021-10-22T22:17:52Z [INFO][UPF][Util] [PFCP] Session Modification Response
2021-10-22T22:17:52Z [INFO][UPF][Util] [PFCP] Handle PFCP session modification request
2021-10-22T22:17:52Z [INFO][UPF][Util] [PFCP] Session Modification Response
2021-10-22T22:17:52Z [INFO][UPF][Util] [PFCP] Handle PFCP session modification request
2021-10-22T22:17:52Z [INFO][UPF][Util] [PFCP] Session Modification Response
2021-10-22T22:17:52Z [INFO][UPF][Util] [PFCP] Handle PFCP session modification request
2021-10-22T22:17:52Z [INFO][UPF][Util] [PFCP] Session Modification Response
2021-10-22T22:17:52Z [INFO][UPF][Util] [PFCP] Handle PFCP session modification request
2021-10-22T22:17:52Z [INFO][UPF][Util] [PFCP] Session Modification Response
2021-10-22T22:17:52Z [INFO][UPF][Util] [PFCP] Handle PFCP session modification request
2021-10-22T22:17:52Z [INFO][UPF][Util] [PFCP] Session Modification Response
2021-10-22T22:17:55Z [WARN][UPF][Util] Pool is empty
2021-10-22T22:17:55Z [ERRO][UPF][Util] bufPool64 is empty
2021-10-22T22:17:55Z [ERRO][UPF][Util] UTLT_Malloc fail
Segmentation fault
. free5gc VM2
d8ebdfd8830a/modify |
2021-10-22T22:17:52Z [INFO][LIB][PFCP] Remove Request Transaction [20]
2021-10-22T22:18:01Z [INFO][LIB][PFCP] Remove Request Transaction [11]
2021-10-22T22:18:07Z [INFO][AMF][NGAP][172.16.2.1:58932] Handle Uplink Nas Transport
2021-10-22T22:18:07Z [INFO][AMF][NGAP][172.16.2.1:58932][AMF_UE_NGAP_ID:1] Uplink NAS Transport (RAN UE NGAP ID: 1)
2021-10-22T22:18:07Z [INFO][AMF][GMM][AMF_UE_NGAP_ID:1][SUPI:imsi-208930000000017] Handle UL NAS Transport
2021-10-22T22:18:07Z [INFO][AMF][GMM][AMF_UE_NGAP_ID:1][SUPI:imsi-208930000000017] Transport 5GSM Message to SMF
2021-10-22T22:18:07Z [WARN][AMF][GMM][AMF_UE_NGAP_ID:1][SUPI:imsi-208930000000017] Duplicated PDU session ID[10]
2021-10-22T22:18:07Z [INFO][SMF][PduSess] Recieve Update SM Context Request
2021-10-22T22:18:07Z [INFO][SMF][PduSess] In HandlePDUSessionSMContextUpdate
2021-10-22T22:18:07Z [WARN][SMF][PduSess] SMContext[imsi-208930000000017-10] should be Active, but actual ModificationPending
2021-10-22T22:18:07Z [INFO][SMF][CTX] [SMF] Cause_REL_DUE_TO_DUPLICATE_SESSION_ID
2021-10-22T22:18:07Z [INFO][SMF][PduSess] Send PFCP Deletion from HandlePDUSessionSMContextUpdate
2021-10-22T22:18:16Z [INFO][LIB][PFCP] Remove Request Transaction [21]
. UE VM3
gnb
ubuntu@ue:~/UERANSIM$ build/nr-gnb -c config/free5gc-gnb.yaml
UERANSIM v3.2.3
[2021-10-22 22:16:09.162] [sctp] [info] Trying to establish SCTP connection… (172.16.2.100:38412)
[2021-10-22 22:16:09.185] [sctp] [info] SCTP connection established (172.16.2.100:38412)
[2021-10-22 22:16:09.185] [sctp] [debug] SCTP association setup ascId[3]
[2021-10-22 22:16:09.185] [ngap] [debug] Sending NG Setup Request
[2021-10-22 22:16:09.196] [ngap] [debug] NG Setup Response received
[2021-10-22 22:16:09.196] [ngap] [info] NG Setup procedure is successful
[2021-10-22 22:17:46.969] [rrc] [debug] UE[1] new signal detected
[2021-10-22 22:17:49.480] [rrc] [info] RRC Setup for UE[1]
[2021-10-22 22:17:49.481] [ngap] [debug] Initial NAS message received from UE[1]
[2021-10-22 22:17:49.683] [ngap] [debug] Initial Context Setup Request received
[2021-10-22 22:17:50.032] [ngap] [info] PDU session resource(s) setup for UE[1] count[1]
[2021-10-22 22:17:50.148] [ngap] [info] PDU session resource(s) setup for UE[1] count[1]
[2021-10-22 22:17:50.168] [ngap] [info] PDU session resource(s) setup for UE[1] count[1]
[2021-10-22 22:17:50.291] [ngap] [info] PDU session resource(s) setup for UE[1] count[1]
[2021-10-22 22:17:50.315] [ngap] [info] PDU session resource(s) setup for UE[1] count[1]
[2021-10-22 22:17:50.351] [ngap] [info] PDU session resource(s) setup for UE[1] count[1]
[2021-10-22 22:17:50.415] [ngap] [info] PDU session resource(s) setup for UE[1] count[1]
[2021-10-22 22:17:50.496] [ngap] [info] PDU session resource(s) setup for UE[1] count[1]
[2021-10-22 22:17:50.572] [ngap] [info] PDU session resource(s) setup for UE[1] count[1]
[2021-10-22 22:19:20.836] [rls] [debug] UE[1] signal lost
^Z
UE
ubuntu@ue:~/UERANSIM$ sudo build/nr-ue -c config/free5gc-ue2dnn.yaml
UERANSIM v3.2.3
[2021-10-22 22:17:46.971] [rrc] [debug] New signal detected for cell[1], total [1] cells in coverage
[2021-10-22 22:17:46.973] [nas] [info] UE switches to state [MM-DEREGISTERED/PLMN-SEARCH]
[2021-10-22 22:17:49.171] [nas] [error] PLMN selection failure, no cells in coverage
[2021-10-22 22:17:49.173] [nas] [info] Selected plmn[208/93]
[2021-10-22 22:17:49.470] [rrc] [info] Selected cell plmn[208/93] tac[1] category[SUITABLE]
[2021-10-22 22:17:49.471] [nas] [info] UE switches to state [MM-DEREGISTERED/PS]
[2021-10-22 22:17:49.472] [nas] [info] UE switches to state [MM-DEREGISTERED/NORMAL-SERVICE]
[2021-10-22 22:17:49.473] [nas] [debug] Initial registration required due to [MM-DEREG-NORMAL-SERVICE]
[2021-10-22 22:17:49.474] [nas] [debug] UAC access attempt is allowed for identity[0], category[MO_sig]
[2021-10-22 22:17:49.475] [nas] [debug] Sending Initial Registration
[2021-10-22 22:17:49.479] [rrc] [debug] Sending RRC Setup Request
[2021-10-22 22:17:49.480] [rrc] [info] RRC connection established
[2021-10-22 22:17:49.481] [rrc] [info] UE switches to state [RRC-CONNECTED]
[2021-10-22 22:17:49.481] [nas] [info] UE switches to state [MM-REGISTER-INITIATED]
[2021-10-22 22:17:49.482] [nas] [info] UE switches to state [CM-CONNECTED]
[2021-10-22 22:17:49.545] [nas] [debug] Authentication Request received
[2021-10-22 22:17:49.546] [nas] [debug] Sending Authentication Failure due to SQN out of range
[2021-10-22 22:17:49.579] [nas] [debug] Authentication Request received
[2021-10-22 22:17:49.595] [nas] [debug] Security Mode Command received
[2021-10-22 22:17:49.596] [nas] [debug] Selected integrity[2] ciphering[0]
[2021-10-22 22:17:49.684] [nas] [debug] Registration accept received
[2021-10-22 22:17:49.684] [nas] [info] UE switches to state [MM-REGISTERED/NORMAL-SERVICE]
[2021-10-22 22:17:49.685] [nas] [debug] Sending Registration Complete
[2021-10-22 22:17:49.685] [nas] [info] Initial Registration is successful
[2021-10-22 22:17:49.685] [nas] [debug] Sending PDU Session Establishment Request
[2021-10-22 22:17:49.685] [nas] [debug] UAC access attempt is allowed for identity[0], category[MO_sig]
[2021-10-22 22:17:49.685] [nas] [debug] Sending PDU Session Establishment Request
[2021-10-22 22:17:49.685] [nas] [debug] UAC access attempt is allowed for identity[0], category[MO_sig]
[2021-10-22 22:17:49.686] [nas] [debug] Sending PDU Session Establishment Request
[2021-10-22 22:17:49.686] [nas] [debug] UAC access attempt is allowed for identity[0], category[MO_sig]
[2021-10-22 22:17:49.687] [nas] [debug] Sending PDU Session Establishment Request
[2021-10-22 22:17:49.687] [nas] [debug] UAC access attempt is allowed for identity[0], category[MO_sig]
[2021-10-22 22:17:49.688] [nas] [debug] Sending PDU Session Establishment Request
[2021-10-22 22:17:49.688] [nas] [debug] UAC access attempt is allowed for identity[0], category[MO_sig]
[2021-10-22 22:17:49.689] [nas] [debug] Sending PDU Session Establishment Request
[2021-10-22 22:17:49.689] [nas] [debug] UAC access attempt is allowed for identity[0], category[MO_sig]
[2021-10-22 22:17:49.689] [nas] [debug] Sending PDU Session Establishment Request
[2021-10-22 22:17:49.690] [nas] [debug] UAC access attempt is allowed for identity[0], category[MO_sig]
[2021-10-22 22:17:49.690] [nas] [debug] Sending PDU Session Establishment Request
[2021-10-22 22:17:49.691] [nas] [debug] UAC access attempt is allowed for identity[0], category[MO_sig]
[2021-10-22 22:17:49.691] [nas] [debug] Sending PDU Session Establishment Request
[2021-10-22 22:17:49.691] [nas] [debug] UAC access attempt is allowed for identity[0], category[MO_sig]
[2021-10-22 22:17:49.691] [nas] [debug] Sending PDU Session Establishment Request
[2021-10-22 22:17:49.692] [nas] [debug] UAC access attempt is allowed for identity[0], category[MO_sig]
[2021-10-22 22:17:50.006] [nas] [debug] PDU Session Establishment Accept received
[2021-10-22 22:17:50.026] [nas] [info] PDU Session establishment is successful PSI[1]
[2021-10-22 22:17:50.063] [app] [info] Connection setup for PDU session[1] is successful, TUN interface[uesimtun0, 60.60.0.1] is up.
[2021-10-22 22:17:50.128] [nas] [debug] PDU Session Establishment Accept received
[2021-10-22 22:17:50.128] [nas] [info] PDU Session establishment is successful PSI[2]
[2021-10-22 22:17:50.169] [nas] [debug] PDU Session Establishment Accept received
[2021-10-22 22:17:50.174] [nas] [info] PDU Session establishment is successful PSI[3]
[2021-10-22 22:17:50.182] [app] [info] Connection setup for PDU session[2] is successful, TUN interface[uesimtun1, 60.61.0.1] is up.
[2021-10-22 22:17:50.257] [app] [info] Connection setup for PDU session[3] is successful, TUN interface[uesimtun2, 60.62.0.1] is up.
[2021-10-22 22:17:50.265] [nas] [debug] PDU Session Establishment Accept received
[2021-10-22 22:17:50.266] [nas] [info] PDU Session establishment is successful PSI[4]
[2021-10-22 22:17:50.310] [nas] [debug] PDU Session Establishment Accept received
[2021-10-22 22:17:50.313] [nas] [info] PDU Session establishment is successful PSI[5]
[2021-10-22 22:17:50.336] [app] [info] Connection setup for PDU session[4] is successful, TUN interface[uesimtun3, 60.63.0.1] is up.
[2021-10-22 22:17:50.351] [nas] [debug] PDU Session Establishment Accept received
[2021-10-22 22:17:50.351] [nas] [info] PDU Session establishment is successful PSI[6]
[2021-10-22 22:17:50.386] [app] [info] Connection setup for PDU session[5] is successful, TUN interface[uesimtun4, 60.64.0.1] is up.
[2021-10-22 22:17:50.416] [nas] [debug] PDU Session Establishment Accept received
[2021-10-22 22:17:50.416] [nas] [info] PDU Session establishment is successful PSI[7]
[2021-10-22 22:17:50.455] [app] [info] Connection setup for PDU session[6] is successful, TUN interface[uesimtun5, 60.65.0.1] is up.
[2021-10-22 22:17:50.496] [nas] [debug] PDU Session Establishment Accept received
[2021-10-22 22:17:50.497] [nas] [info] PDU Session establishment is successful PSI[8]
[2021-10-22 22:17:50.514] [app] [info] Connection setup for PDU session[7] is successful, TUN interface[uesimtun6, 60.66.0.1] is up.
[2021-10-22 22:17:50.573] [nas] [debug] PDU Session Establishment Accept received
[2021-10-22 22:17:50.573] [nas] [info] PDU Session establishment is successful PSI[9]
[2021-10-22 22:17:50.591] [app] [info] Connection setup for PDU session[8] is successful, TUN interface[uesimtun7, 60.67.0.1] is up.
[2021-10-22 22:17:50.677] [app] [info] Connection setup for PDU session[9] is successful, TUN interface[uesimtun8, 60.68.0.1] is up.
[2021-10-22 22:18:05.989] [nas] [warning] Retransmitting PDU Session Establishment Request due to T3580 expiry
[2021-10-22 22:18:05.990] [nas] [debug] UAC access attempt is allowed for identity[0], category[MO_sig]
[2021-10-22 22:18:22.005] [nas] [warning] Retransmitting PDU Session Establishment Request due to T3580 expiry
[2021-10-22 22:18:22.005] [nas] [debug] UAC access attempt is allowed for identity[0], category[MO_sig]
[2021-10-22 22:18:38.021] [nas] [warning] Retransmitting PDU Session Establishment Request due to T3580 expiry
[2021-10-22 22:18:38.021] [nas] [debug] UAC access attempt is allowed for identity[0], category[MO_sig]
[2021-10-22 22:18:54.037] [nas] [warning] Retransmitting PDU Session Establishment Request due to T3580 expiry
[2021-10-22 22:18:54.037] [nas] [debug] UAC access attempt is allowed for identity[0], category[MO_sig]
[2021-10-22 22:19:10.053] [nas] [error] PDU Session Establishment procedure failure, no response from the network after 5 attempts
[2021-10-22 22:19:10.053] [nas] [debug] Aborting SM procedure for PTI[10], PSI[10]
[2021-10-22 22:19:10.650] [nas] [debug] Sending PDU Session Establishment Request
[2021-10-22 22:19:10.650] [nas] [debug] UAC access attempt is allowed for identity[0], category[MO_sig]
^Z
Hi @tuweijian ,
You can try modified the size of buffer in /free5gc/NFs/upf/lib/utlt/src/utlt_buff.c. This error is because the buffer can’t afford too many PDU session or other UP resources, multiply it’s size may help. Below is the example, if still don’t work, let me know, thanks!
BRs,
Oneal Lee