Skip to content

free5GC SMF + BESS UPF: appQERLookupFail #873

Open
@yoursunny

Description

@yoursunny

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.

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions