upf icon indicating copy to clipboard operation
upf copied to clipboard
verified publisher icon omec-project

free5GC SMF + BESS UPF: appQERLookupFail

Open yoursunny opened this issue 11 months ago • 7 comments

I'm trying the combination of free5GC Control Plane and BESS UPF, but I cannot get downlink traffic to work.

BESS UPF configuration

upf1.json 
{
  "access": {
    "ifname": "n3"
  },
  "core": {
    "ifname": "n6"
  },
  "cpiface": {
    "peers": [
    ]
  },
  "ddp": false,
  "enable_gtpu_path_monitoring": false,
  "enable_hbTimer": false,
  "enable_ntf": false,
  "enable_p4rt": false,
  "gtppsc": true,
  "hwcksum": false,
  "log_level": "debug",
  "max_req_retries": 5,
  "measure_flow": false,
  "measure_upf": true,
  "mode": "af_packet",
  "p4rtciface": {
  },
  "qci_qos_config": [
  ],
  "read_timeout": 4294967295,
  "resp_timeout": "2s",
  "table_sizes": {
    "appQERLookup": 200000,
    "farLookup": 150000,
    "flowMeasure": 200000,
    "pdrLookup": 50000,
    "sessionQERLookup": 100000
  },
  "workers": 2
}

The qci_qos_config array is empty. If I kept this array with the content from the template, results are the same.

PFCP packet trace

2.pcapng.gz

The PFCP Session Establishment Request is in frame 76:


Packet Forwarding Control Protocol
    Flags: 0x23, Message Priority (MP), SEID (S)
    Message Type: PFCP Session Establishment Request (50)
    Length: 330
    SEID: 0x0000000000000000
    Sequence Number: 5
    .... .... .... .... 0000 .... = Message Priority: 0
    .... 0000 = Spare: 0
    Node ID : IPv4 address: 172.25.194.17
    F-SEID : SEID: 0x0000000000000001, IPv4 172.25.194.17
    Create PDR : [Grouped IE]: PDR ID: 1
        IE Type: Create PDR (1)
        IE Length: 87
        PDR ID : 1
        Precedence : 255
        PDI : [Grouped IE]
        Outer Header Removal : GTP-U/UDP/IPv4
        FAR ID : Dynamic by CP 1
        QER ID : Dynamic by CP 2
        QER ID : Dynamic by CP 1
    Create PDR : [Grouped IE]: PDR ID: 2
        IE Type: Create PDR (1)
        IE Length: 69
        PDR ID : 2
        Precedence : 255
        PDI : [Grouped IE]
        FAR ID : Dynamic by CP 2
        QER ID : Dynamic by CP 2
        QER ID : Dynamic by CP 1
    Create FAR : [Grouped IE]: FAR ID: Dynamic by CP 1
    Create FAR : [Grouped IE]: FAR ID: Dynamic by CP 2
    Create QER : [Grouped IE]: QER ID: Dynamic by CP 2
        IE Type: Create QER (7)
        IE Length: 18
        QER ID : Dynamic by CP 2
        Gate Status : 
        QFI : 
            IE Type: QFI (124)
            IE Length: 1
            00.. .... = Spare: 0
            ..00 0001 = QFI: 0x01
    Create QER : [Grouped IE]: QER ID: Dynamic by CP 1
        IE Type: Create QER (7)
        IE Length: 32
        QER ID : Dynamic by CP 1
        Gate Status : 
        MBR : 
            IE Type: MBR (26)
            IE Length: 10
            UL MBR: 1200000
            DL MBR: 1600000
        QFI : 
            IE Type: QFI (124)
            IE Length: 1
            00.. .... = Spare: 0
            ..00 0001 = QFI: 0x01
    PDN Type : IPv4
    [Response In: 79]

Notably, both PDRs are linked to two QERs, but only the second QER carries MBR fields.

UPF logs

upf1.log.gz

Relevant section here:

2024-12-27T19:58:51.501Z  ERROR  pfcpiface/parse_qer.go:69  could not read MBRUL  {"component": "UPF", "category": "Pfcp"}
2024-12-27T19:58:51.501Z  ERROR  pfcpiface/parse_qer.go:74  could not read MBRDL  {"component": "UPF", "category": "Pfcp"}
2024-12-27T19:58:51.501Z  ERROR  pfcpiface/parse_qer.go:79  could not read GBRUL  {"component": "UPF", "category": "Pfcp"}
2024-12-27T19:58:51.501Z  ERROR  pfcpiface/parse_qer.go:84  could not read GBRDL  {"component": "UPF", "category": "Pfcp"}
2024-12-27T19:58:51.501Z  ERROR  pfcpiface/parse_qer.go:79  could not read GBRUL  {"component": "UPF", "category": "Pfcp"}
2024-12-27T19:58:51.501Z  ERROR  pfcpiface/parse_qer.go:84  could not read GBRDL  {"component": "UPF", "category": "Pfcp"}
2024-12-27T19:58:51.501Z  INFO  pfcpiface/session_qer.go:126  session QER found. QER ID: 1  {"component": "UPF", "category": "Pfcp"}
2024-12-27T19:58:51.501Z  INFO  pfcpiface/session_qer.go:126  session QER found. QER ID: 1  {"component": "UPF", "category": "Pfcp"}
2024-12-27T19:58:51.501Z  DEBUG  pfcpiface/bess.go:152  add PDR(id=1, F-SEID=747136693117216301, srcIface=1, tunnelIPv4Dst=172.25.195.5/ffffffff, tunnelTEID=2/ffffffff, ueAddress=10.1.0.1, applicationFilter=ApplicationFilter(srcIP=10.1.0.1/ffffffff, dstIP=0.0.0.0/0, proto=0/0, srcPort={0-0}, dstPort={0-0}), precedence=255, F-SEID IP=2887369233, counterID=0, farID=1, qerIDs=[2 1], needDecap=1, allocIPFlag=false)  {"component": "UPF", "category": "BESS"}
2024-12-27T19:58:51.501Z  DEBUG  pfcpiface/bess.go:152  add PDR(id=2, F-SEID=747136693117216301, srcIface=2, tunnelIPv4Dst=0.0.0.0/0, tunnelTEID=0/0, ueAddress=10.1.0.1, applicationFilter=ApplicationFilter(srcIP=0.0.0.0/0, dstIP=10.1.0.1/ffffffff, proto=0/0, srcPort={0-0}, dstPort={0-0}), precedence=255, F-SEID IP=2887369233, counterID=0, farID=2, qerIDs=[2 1], needDecap=0, allocIPFlag=false)  {"component": "UPF", "category": "BESS"}
2024-12-27T19:58:51.501Z  DEBUG  pfcpiface/bess.go:165  add FAR(id=1, F-SEID=747136693117216301, F-SEID IPv4=172.25.194.17, dstInterface=1, tunnelType=0, tunnelIPv4Src=172.25.193.5, tunnelIPv4Dst=0.0.0.0, tunnelTEID=0, tunnelSrcPort=0, sendEndMarker=false, drops=false, forwards=true, buffers=false)  {"component": "UPF", "category": "BESS"}
2024-12-27T19:58:51.501Z  DEBUG  pfcpiface/bess.go:165  add FAR(id=2, F-SEID=747136693117216301, F-SEID IPv4=172.25.194.17, dstInterface=0, tunnelType=0, tunnelIPv4Src=172.25.195.5, tunnelIPv4Dst=0.0.0.0, tunnelTEID=0, tunnelSrcPort=0, sendEndMarker=false, drops=false, forwards=true, buffers=false)  {"component": "UPF", "category": "BESS"}
2024-12-27T19:58:51.501Z  DEBUG  pfcpiface/bess.go:178  add QER(id=2, F-SEID=747136693117216301, F-SEID IP=2887369233, QFI=1, uplinkMBR=0, downlinkMBR=0, uplinkGBR=0, downlinkGBR=0, type=application, uplinkStatus=0, downlinkStatus=0)  {"component": "UPF", "category": "BESS"}
2024-12-27T19:58:51.501Z  DEBUG  pfcpiface/bess.go:178  add QER(id=1, F-SEID=747136693117216301, F-SEID IP=2887369233, QFI=1, uplinkMBR=1200000, downlinkMBR=1600000, uplinkGBR=0, downlinkGBR=0, type=session, uplinkStatus=0, downlinkStatus=0)  {"component": "UPF", "category": "BESS"}
2024-12-27T19:58:51.501Z  DEBUG  pfcpiface/bess.go:994  number of config for qfi/qci: 1 using default burst size  {"component": "UPF", "category": "BESS"}
2024-12-27T19:58:51.501Z  DEBUG  pfcpiface/bess.go:884  PDR rules [{srcPort:0 srcMask:0 dstPort:0 dstMask:0}]  {"component": "UPF", "category": "BESS"}
2024-12-27T19:58:51.501Z  DEBUG  pfcpiface/bess.go:884  PDR rules [{srcPort:0 srcMask:0 dstPort:0 dstMask:0}]  {"component": "UPF", "category": "BESS"}
2024-12-27T19:58:51.501Z  DEBUG  pfcpiface/bess.go:994  number of config for qfi/qci: 1 using default burst size  {"component": "UPF", "category": "BESS"}
2024-12-27T19:58:51.502Z  DEBUG  pfcpiface/bess.go:1433  qerlookup resp:   {"component": "UPF", "category": "BESS"}
2024-12-27T19:58:51.502Z  DEBUG  pfcpiface/bess.go:1027  number of config for qfi/qci: 1 using default burst size  {"component": "UPF", "category": "BESS"}
2024-12-27T19:58:51.521Z  DEBUG  pfcpiface/bess.go:856  pdrlookup resp:   {"component": "UPF", "category": "BESS"}
2024-12-27T19:58:51.530Z  DEBUG  pfcpiface/bess.go:856  pdrlookup resp:   {"component": "UPF", "category": "BESS"}
2024-12-27T19:58:51.538Z  DEBUG  pfcpiface/bess.go:1166  farlookup resp:   {"component": "UPF", "category": "BESS"}
2024-12-27T19:58:51.547Z  DEBUG  pfcpiface/bess.go:1166  farlookup resp:   {"component": "UPF", "category": "BESS"}
2024-12-27T19:58:51.556Z  DEBUG  pfcpiface/bess.go:1433  qerlookup resp:   {"component": "UPF", "category": "BESS"}
2024-12-27T19:58:51.556Z  DEBUG  pfcpiface/bess.go:1027  number of config for qfi/qci: 1 using default burst size  {"component": "UPF", "category": "BESS"}
2024-12-27T19:58:51.566Z  DEBUG  pfcpiface/bess.go:1433  qerlookup resp:   {"component": "UPF", "category": "BESS"}
2024-12-27T19:58:51.574Z  DEBUG  pfcpiface/bess.go:1433  qerlookup resp:   {"component": "UPF", "category": "BESS"}
2024-12-27T19:58:51.575Z  DEBUG  pfcpiface/local_store.go:44  saved PFCP sessions to local store  {"component": "UPF", "category": "Pfcp", "session": "PDRs=[PDR(id=1, F-SEID=747136693117216301, srcIface=1, tunnelIPv4Dst=172.25.195.5/ffffffff, tunnelTEID=2/ffffffff, ueAddress=10.1.0.1, applicationFilter=ApplicationFilter(srcIP=10.1.0.1/ffffffff, dstIP=0.0.0.0/0, proto=0/0, srcPort={0-0}, dstPort={0-0}), precedence=255, F-SEID IP=2887369233, counterID=0, farID=1, qerIDs=[2 1], needDecap=1, allocIPFlag=false) PDR(id=2, F-SEID=747136693117216301, srcIface=2, tunnelIPv4Dst=0.0.0.0/0, tunnelTEID=0/0, ueAddress=10.1.0.1, applicationFilter=ApplicationFilter(srcIP=0.0.0.0/0, dstIP=10.1.0.1/ffffffff, proto=0/0, srcPort={0-0}, dstPort={0-0}), precedence=255, F-SEID IP=2887369233, counterID=0, farID=2, qerIDs=[2 1], needDecap=0, allocIPFlag=false)], FARs=[FAR(id=1, F-SEID=747136693117216301, F-SEID IPv4=172.25.194.17, dstInterface=1, tunnelType=0, tunnelIPv4Src=172.25.193.5, tunnelIPv4Dst=0.0.0.0, tunnelTEID=0, tunnelSrcPort=0, sendEndMarker=false, drops=false, forwards=true, buffers=false) FAR(id=2, F-SEID=747136693117216301, F-SEID IPv4=172.25.194.17, dstInterface=0, tunnelType=0, tunnelIPv4Src=172.25.195.5, tunnelIPv4Dst=0.0.0.0, tunnelTEID=0, tunnelSrcPort=0, sendEndMarker=false, drops=false, forwards=true, buffers=false)], QERs=[QER(id=2, F-SEID=747136693117216301, F-SEID IP=2887369233, QFI=1, uplinkMBR=0, downlinkMBR=0, uplinkGBR=0, downlinkGBR=0, type=application, uplinkStatus=0, downlinkStatus=0) QER(id=1, F-SEID=747136693117216301, F-SEID IP=2887369233, QFI=1, uplinkMBR=1200000, downlinkMBR=1600000, uplinkGBR=0, downlinkGBR=0, type=session, uplinkStatus=0, downlinkStatus=0)]"}
2024-12-27T19:58:51.575Z  INFO  pfcpiface/session_pdr.go:30  add PDRs with UPF alloc IPs to Establishment response  {"component": "UPF", "category": "Pfcp"}
2024-12-27T19:58:51.575Z  INFO  pfcpiface/session_pdr.go:31  PDRs: [PDR(id=1, F-SEID=747136693117216301, srcIface=1, tunnelIPv4Dst=172.25.195.5/ffffffff, tunnelTEID=2/ffffffff, ueAddress=10.1.0.1, applicationFilter=ApplicationFilter(srcIP=10.1.0.1/ffffffff, dstIP=0.0.0.0/0, proto=0/0, srcPort={0-0}, dstPort={0-0}), precedence=255, F-SEID IP=2887369233, counterID=0, farID=1, qerIDs=[2 1], needDecap=1, allocIPFlag=false) PDR(id=2, F-SEID=747136693117216301, srcIface=2, tunnelIPv4Dst=0.0.0.0/0, tunnelTEID=0/0, ueAddress=10.1.0.1, applicationFilter=ApplicationFilter(srcIP=0.0.0.0/0, dstIP=10.1.0.1/ffffffff, proto=0/0, srcPort={0-0}, dstPort={0-0}), precedence=255, F-SEID IP=2887369233, counterID=0, farID=2, qerIDs=[2 1], needDecap=0, allocIPFlag=false)]  {"component": "UPF", "category": "Pfcp"}
2024-12-27T19:58:51.575Z  INFO  pfcpiface/session_pdr.go:33  pdrID: 1  {"component": "UPF", "category": "Pfcp"}
2024-12-27T19:58:51.575Z  INFO  pfcpiface/session_pdr.go:33  pdrID: 2  {"component": "UPF", "category": "Pfcp"}
2024-12-27T19:58:51.575Z  DEBUG  pfcpiface/messages.go:118  successfully processed Session Establishment Request, from 172.25.194.17:8805, nodeID: 172.25.194.17  {"component": "UPF", "category": "Pfcp"}
2024-12-27T19:58:51.575Z  DEBUG  pfcpiface/messages.go:153  sent Session Establishment Response to 172.25.194.17:8805  {"component": "UPF", "category": "Pfcp"}

Notably, QER with ID=2 is classified as ApplicationQos level, while QER with ID=1 is classified as SessionQos level.

Traffic and UPF Behavior

I transmitted 10000 ICMP ping packets from the Data Network to the UE. BESS Pipeline webpage indicates that all these packets are dropped at appQERLookupFail sink.

2024-12-27 15 04 32

I'm unable to determine why the QER lookup is failing.

yoursunny avatar Dec 27 '24 20:12 yoursunny

Thanks @yoursunny for trying out UPF. I shall take a closer look at it and will update you

ajaythakurintel avatar Dec 27 '24 23:12 ajaythakurintel

@yoursunny - Could you please with following

  1. Why free5gc control plane is linking same 2 QERs with both the PDRs?
  2. Why only one of the QER has QoS Rates and not the other one?
  3. Are you referring to those 10004 QER failure?
  4. Did you use the free5gc with UPF successfully in the past?

thakurajayL avatar Dec 30 '24 21:12 thakurajayL

Why free5gc control plane is linking same 2 QERs with both the PDRs?

I do not know, but the PFCP spec does permit multiple QERs linked to a PDR.

Why only one of the QER has QoS Rates and not the other one?

I do not know, but the PFCP spec does permit some QERs having QoS rates and some QERs not having QoS rates.

Are you referring to those 10004 QER failure?

Yes, I am concerned about appQERLookupFail outcome, which occurred 10004 times in the screenshot.

Did you use the free5gc with UPF successfully in the past?

This is my first time trying this combination.

yoursunny avatar Dec 31 '24 01:12 yoursunny

printf insertion

I inserted two print statements to the code, to reveal the cause of the QER lookup failure.

In upf/pfcpiface/bess.go processQER function, I changed the ModuleCommand call to:

	req := pb.CommandRequest{
		Name: qosTableName,
		Cmd:  methods[method],
		Arg:  any,
	}
	logger.BessLog.Errorln("processQER", req.String())
	resp, err := b.client.ModuleCommand(ctx, &req)

In Dockerfile, I inserted a step just before build bess:

RUN <<EOF
  set -eux
  sed -i '/keys\[j\].u64_arr\[i\]/ a\\printf("QoS::ProcessBatch %d %zu %016lx\\n", j, i, keys[j].u64_arr[i]);' core/modules/qos.cc
EOF

This in turn modifies bess/core/modules/qos.cc Qos::processBatch function, to print the lookup key after its preparation.

pfcpiface log

2024-12-31T17:51:21.009Z	INFO	pfcpiface/session_qer.go:126	session QER found. QER ID: 1	{"component": "UPF", "category": "Pfcp"}
2024-12-31T17:51:21.009Z	INFO	pfcpiface/session_qer.go:126	session QER found. QER ID: 1	{"component": "UPF", "category": "Pfcp"}
2024-12-31T17:51:21.009Z	DEBUG	pfcpiface/bess.go:152	add PDR(id=1, F-SEID=7313368347187895487, srcIface=1, tunnelIPv4Dst=172.25.195.5/ffffffff, tunnelTEID=2/ffffffff, ueAddress=10.1.0.1, applicationFilter=ApplicationFilter(srcIP=10.1.0.1/ffffffff, dstIP=0.0.0.0/0, proto=0/0, srcPort={0-0}, dstPort={0-0}), precedence=255, F-SEID IP=2887369233, counterID=0, farID=1, qerIDs=[2 1], needDecap=1, allocIPFlag=false)	{"component": "UPF", "category": "BESS"}
2024-12-31T17:51:21.009Z	DEBUG	pfcpiface/bess.go:152	add PDR(id=2, F-SEID=7313368347187895487, srcIface=2, tunnelIPv4Dst=0.0.0.0/0, tunnelTEID=0/0, ueAddress=10.1.0.1, applicationFilter=ApplicationFilter(srcIP=0.0.0.0/0, dstIP=10.1.0.1/ffffffff, proto=0/0, srcPort={0-0}, dstPort={0-0}), precedence=255, F-SEID IP=2887369233, counterID=0, farID=2, qerIDs=[2 1], needDecap=0, allocIPFlag=false)	{"component": "UPF", "category": "BESS"}
2024-12-31T17:51:21.009Z	DEBUG	pfcpiface/bess.go:165	add FAR(id=1, F-SEID=7313368347187895487, F-SEID IPv4=172.25.194.17, dstInterface=1, tunnelType=0, tunnelIPv4Src=172.25.193.5, tunnelIPv4Dst=0.0.0.0, tunnelTEID=0, tunnelSrcPort=0, sendEndMarker=false, drops=false, forwards=true, buffers=false)	{"component": "UPF", "category": "BESS"}
2024-12-31T17:51:21.009Z	DEBUG	pfcpiface/bess.go:165	add FAR(id=2, F-SEID=7313368347187895487, F-SEID IPv4=172.25.194.17, dstInterface=0, tunnelType=0, tunnelIPv4Src=172.25.195.5, tunnelIPv4Dst=0.0.0.0, tunnelTEID=0, tunnelSrcPort=0, sendEndMarker=false, drops=false, forwards=true, buffers=false)	{"component": "UPF", "category": "BESS"}
2024-12-31T17:51:21.009Z	DEBUG	pfcpiface/bess.go:178	add QER(id=2, F-SEID=7313368347187895487, F-SEID IP=2887369233, QFI=1, uplinkMBR=0, downlinkMBR=0, uplinkGBR=0, downlinkGBR=0, type=application, uplinkStatus=0, downlinkStatus=0)	{"component": "UPF", "category": "BESS"}
2024-12-31T17:51:21.009Z	DEBUG	pfcpiface/bess.go:178	add QER(id=1, F-SEID=7313368347187895487, F-SEID IP=2887369233, QFI=1, uplinkMBR=1200000, downlinkMBR=1600000, uplinkGBR=0, downlinkGBR=0, type=session, uplinkStatus=0, downlinkStatus=0)	{"component": "UPF", "category": "BESS"}
2024-12-31T17:51:21.009Z	DEBUG	pfcpiface/bess.go:994	number of config for qfi/qci: 1 using default burst size	{"component": "UPF", "category": "BESS"}
2024-12-31T17:51:21.009Z	DEBUG	pfcpiface/bess.go:884	PDR rules [{srcPort:0 srcMask:0 dstPort:0 dstMask:0}]	{"component": "UPF", "category": "BESS"}
2024-12-31T17:51:21.010Z	ERROR	pfcpiface/bess.go:1437	processQER name:"sessionQERLookup"  cmd:"add"  arg:{[type.googleapis.com/bess.pb.QosCommandAddArg]:{cir:1  pir:150000000  cbs:48448  pbs:1500000  ebs:1500000  fields:{value_int:1}  fields:{value_int:7313368347187895487}}}	{"component": "UPF", "category": "BESS"}
2024-12-31T17:51:21.010Z	DEBUG	pfcpiface/bess.go:884	PDR rules [{srcPort:0 srcMask:0 dstPort:0 dstMask:0}]	{"component": "UPF", "category": "BESS"}
2024-12-31T17:51:21.010Z	DEBUG	pfcpiface/bess.go:994	number of config for qfi/qci: 1 using default burst size	{"component": "UPF", "category": "BESS"}
2024-12-31T17:51:21.010Z	ERROR	pfcpiface/bess.go:1437	processQER name:"appQERLookup"  cmd:"add"  arg:{[type.googleapis.com/bess.pb.QosCommandAddArg]:{gate:6  cbs:48448  pbs:48448  ebs:48448  fields:{value_int:1}  fields:{value_int:2}  fields:{value_int:7313368347187895487}  values:{value_int:1}}}	{"component": "UPF", "category": "BESS"}
2024-12-31T17:51:21.011Z	DEBUG	pfcpiface/bess.go:856	pdrlookup resp: 	{"component": "UPF", "category": "BESS"}
2024-12-31T17:51:21.019Z	DEBUG	pfcpiface/bess.go:1440	qerlookup resp: 	{"component": "UPF", "category": "BESS"}
2024-12-31T17:51:21.019Z	DEBUG	pfcpiface/bess.go:1027	number of config for qfi/qci: 1 using default burst size	{"component": "UPF", "category": "BESS"}
2024-12-31T17:51:21.019Z	ERROR	pfcpiface/bess.go:1437	processQER name:"sessionQERLookup"  cmd:"add"  arg:{[type.googleapis.com/bess.pb.QosCommandAddArg]:{cir:1  pir:200000000  cbs:48448  pbs:2000000  ebs:2000000  fields:{value_int:2}  fields:{value_int:7313368347187895487}}}	{"component": "UPF", "category": "BESS"}
2024-12-31T17:51:21.028Z	DEBUG	pfcpiface/bess.go:856	pdrlookup resp: 	{"component": "UPF", "category": "BESS"}
2024-12-31T17:51:21.038Z	DEBUG	pfcpiface/bess.go:1166	farlookup resp: 	{"component": "UPF", "category": "BESS"}
2024-12-31T17:51:21.048Z	DEBUG	pfcpiface/bess.go:1166	farlookup resp: 	{"component": "UPF", "category": "BESS"}
2024-12-31T17:51:21.056Z	DEBUG	pfcpiface/bess.go:1440	qerlookup resp: 	{"component": "UPF", "category": "BESS"}
2024-12-31T17:51:21.056Z	DEBUG	pfcpiface/bess.go:1027	number of config for qfi/qci: 1 using default burst size	{"component": "UPF", "category": "BESS"}
2024-12-31T17:51:21.057Z	ERROR	pfcpiface/bess.go:1437	processQER name:"appQERLookup"  cmd:"add"  arg:{[type.googleapis.com/bess.pb.QosCommandAddArg]:{gate:6  cbs:48448  pbs:48448  ebs:48448  fields:{value_int:2}  fields:{value_int:2}  fields:{value_int:7313368347187895487}  values:{value_int:1}}}	{"component": "UPF", "category": "BESS"}
2024-12-31T17:51:21.065Z	DEBUG	pfcpiface/bess.go:1440	qerlookup resp: 	{"component": "UPF", "category": "BESS"}
2024-12-31T17:51:21.074Z	DEBUG	pfcpiface/bess.go:1440	qerlookup resp: 	{"component": "UPF", "category": "BESS"}

BESS log

QoS::ProcessBatch 0 0 8db85cbfffff0102
QoS::ProcessBatch 0 1 00000002c119acff
QoS::ProcessBatch 0 0 ffffff0000000002
QoS::ProcessBatch 0 1 00000002c119acff
QoS::ProcessBatch 0 0 b85cbf0000000002
QoS::ProcessBatch 0 1 000000657e4dc38d
QoS::ProcessBatch 0 0 8db85cbfffff0102
QoS::ProcessBatch 0 1 00000002c119acff
QoS::ProcessBatch 0 0 ffffff0000000002
QoS::ProcessBatch 0 1 00000002c119acff
QoS::ProcessBatch 0 0 b85cbf0000000002
QoS::ProcessBatch 0 1 000000657e4dc38d
QoS::ProcessBatch 0 0 8db85cbfbb010602

Observation

The ModuleCommand call for appQERLookup in downlink direction has this parameter:

name: "appQERLookup"
cmd: "add"
arg: {
  [type.googleapis.com/bess.pb.QosCommandAddArg]: {
    gate: 6
    cbs: 48448
    pbs: 48448
    ebs: 48448
    fields: { value_int: 2 } # srcIface=core
    fields: { value_int: 2 } # qerID=2
    fields: { value_int: 7313368347187895487 } # fseID=0x657e4dc38db85cbf
    values: { value_int: 1 } # QFI=1
  }
}

Looking for the F-SEID on BESS side, we can find two occurrences of this pattern:

QoS::ProcessBatch 0 0 b85cbf0000000002
QoS::ProcessBatch 0 1 000000657e4dc38d

Decoding these fields according to up4.bess:

src_iface: 0x02
qer_id: 0x00000000
fseid: 0x657e4dc38db85cbf

Thus, the lookup failure is caused by BESS not knowing the QER ID while constructing the key.

yoursunny avatar Dec 31 '24 18:12 yoursunny

This issue has been stale for 120 days and will be closed in 15 days. Comment to keep it open.

github-actions[bot] avatar May 01 '25 00:05 github-actions[bot]

https://blog.benwinding.com/github-stale-bots/

yoursunny avatar May 01 '25 00:05 yoursunny

This issue has been stale for 120 days and will be closed in 15 days. Comment to keep it open.

github-actions[bot] avatar Aug 30 '25 00:08 github-actions[bot]