From 8f17c7e6b56b49cda380b046c236ced07f70e2b0 Mon Sep 17 00:00:00 2001 From: Guillaume Belanger Date: Fri, 15 Nov 2024 14:59:51 -0500 Subject: [PATCH] feat: add f-teid allocation support Signed-off-by: Guillaume Belanger --- .github/workflows/{master.yml => main.yml} | 10 +- .github/workflows/push.yml | 14 +- .gitignore | 1 + .wordlist.txt | 1 + Dockerfile | 8 +- VERSION | 2 +- cmd/p4info_code_gen/p4info_code_gen.go | 9 +- cmd/pfcpiface/main.go | 22 +- conf/upf.jsonc | 2 +- go.mod | 24 ++- go.sum | 45 ++-- logger/logger.go | 63 ++++++ pfcpiface/bess.go | 180 ++++++++-------- pfcpiface/config.go | 8 +- pfcpiface/config_test.go | 4 +- pfcpiface/conn.go | 22 +- pfcpiface/fteid.go | 75 +++++++ pfcpiface/fteid_test.go | 39 ++++ pfcpiface/grpcsim.go | 8 +- pfcpiface/ip_pool.go | 10 +- pfcpiface/local_store.go | 20 +- pfcpiface/messages.go | 18 +- pfcpiface/messages_conn.go | 26 +-- pfcpiface/messages_session.go | 53 +++-- pfcpiface/node.go | 36 ++-- pfcpiface/p4rt_translator.go | 98 +++------ pfcpiface/p4rtc.go | 95 ++++----- pfcpiface/parse_far.go | 12 +- pfcpiface/parse_pdr.go | 66 +++--- pfcpiface/parse_qer.go | 18 +- pfcpiface/parse_sdf.go | 21 +- pfcpiface/parse_sdf_test.go | 4 +- pfcpiface/pfcpiface.go | 12 +- pfcpiface/session_far.go | 8 +- pfcpiface/session_pdr.go | 33 +-- pfcpiface/session_qer.go | 10 +- pfcpiface/sessions.go | 5 +- pfcpiface/telemetry.go | 9 +- pfcpiface/up4.go | 236 +++++++-------------- pfcpiface/upf.go | 22 +- pfcpiface/utils.go | 14 +- pfcpiface/utils_test.go | 25 +++ pfcpiface/web_service.go | 20 +- pkg/fake_bess/fake_bess.go | 3 +- pkg/fake_bess/fake_bess_service.go | 45 ++-- ptf/Dockerfile | 2 +- test/integration/basic_test.go | 13 +- test/integration/conf.go | 8 +- test/integration/framework.go | 21 +- test/integration/providers/docker.go | 19 +- 50 files changed, 804 insertions(+), 715 deletions(-) rename .github/workflows/{master.yml => main.yml} (95%) create mode 100644 logger/logger.go create mode 100644 pfcpiface/fteid.go create mode 100644 pfcpiface/fteid_test.go diff --git a/.github/workflows/master.yml b/.github/workflows/main.yml similarity index 95% rename from .github/workflows/master.yml rename to .github/workflows/main.yml index c6336a859..d71841931 100644 --- a/.github/workflows/master.yml +++ b/.github/workflows/main.yml @@ -2,15 +2,15 @@ # Copyright 2023 Canonical Ltd. # Copyright 2024 Intel Corporation -name: Master workflow +name: Main workflow on: pull_request: branches: - - master + - main push: branches: - - master + - main jobs: build: @@ -55,7 +55,7 @@ jobs: go-version-file: 'go.mod' - name: golangci-lint - uses: golangci/golangci-lint-action@v6.1.0 + uses: golangci/golangci-lint-action@v6.1.1 with: version: latest args: -v --config ./.golangci.yml @@ -84,7 +84,7 @@ jobs: - uses: actions/checkout@v4 - name: Check Spelling - uses: rojopolis/spellcheck-github-actions@0.40.0 + uses: rojopolis/spellcheck-github-actions@0.45.0 with: config_path: .spellcheck.yml task_name: Markdown diff --git a/.github/workflows/push.yml b/.github/workflows/push.yml index 3a5e2dca6..8562fb6e0 100644 --- a/.github/workflows/push.yml +++ b/.github/workflows/push.yml @@ -5,7 +5,7 @@ name: GitHub release and Docker images on: push: branches: - - master + - main tags: - v* @@ -32,9 +32,9 @@ jobs: username: ${{ secrets.AETHER_REGISTRY_USERNAME }} password: ${{ secrets.AETHER_REGISTRY_PASSWORD }} - - name: Build and push "master-latest" Docker image + - name: Build and push "main-latest" Docker image env: - DOCKER_TAG: master-latest + DOCKER_TAG: main-latest CPU: haswell run: | docker pull ${DOCKER_REGISTRY}${DOCKER_REPOSITORY}upf-epc-bess:$DOCKER_TAG @@ -42,9 +42,9 @@ jobs: CPU=$CPU make docker-build make docker-push - - name: Build and push "master-GIT_SHA" Docker image + - name: Build and push "main-GIT_SHA" Docker image env: - DOCKER_TAG: master-${{ env.GIT_SHA_SHORT }} + DOCKER_TAG: main-${{ env.GIT_SHA_SHORT }} run: | make docker-build make docker-push @@ -174,13 +174,13 @@ jobs: echo "Updated version: $NEW_VERSION" - name: Create Pull Request - uses: peter-evans/create-pull-request@v6 + uses: peter-evans/create-pull-request@v7 with: token: ${{ secrets.GH_OMEC_PAT }} commit-message: Update version committer: github-actions[bot] <41898282+github-actions[bot]@users.noreply.github.com> author: ${{ github.actor }} <${{ github.actor_id }}+${{ github.actor }}@users.noreply.github.com> - signoff: false + signoff: true branch: version-update delete-branch: true title: Update version diff --git a/.gitignore b/.gitignore index 0a329d182..e69a82825 100644 --- a/.gitignore +++ b/.gitignore @@ -6,6 +6,7 @@ .coverage/ *.pyc *.swp +*.log output dpdk-devbind.py dpdk-hugepages.py diff --git a/.wordlist.txt b/.wordlist.txt index 46f50c53c..107e1cdb9 100644 --- a/.wordlist.txt +++ b/.wordlist.txt @@ -123,6 +123,7 @@ sudo tc TCP tcpdump +TEID TRex UDP UE diff --git a/Dockerfile b/Dockerfile index ae2a9b31c..4612c270e 100644 --- a/Dockerfile +++ b/Dockerfile @@ -5,7 +5,7 @@ # Stage bess-build: fetch BESS dependencies & pre-reqs FROM registry.aetherproject.org/sdcore/bess_build:latest AS bess-build ARG CPU=native -ARG BESS_COMMIT=master +ARG BESS_COMMIT=main ENV PLUGINS_DIR=plugins ARG MAKEFLAGS ENV PKG_CONFIG_PATH=/usr/lib64/pkgconfig @@ -102,7 +102,7 @@ WORKDIR /opt/bess/bessctl ENTRYPOINT ["bessd", "-f"] # Stage build bess golang pb -FROM golang:1.22.5 AS protoc-gen +FROM golang:1.23.3-bookworm AS protoc-gen RUN go install github.com/golang/protobuf/protoc-gen-go@latest FROM bess-build AS go-pb @@ -120,7 +120,7 @@ RUN mkdir /bess_pb && \ --python_out=plugins=grpc:/bess_pb \ --grpc_python_out=/bess_pb -FROM golang:1.22.5 AS pfcpiface-build +FROM golang:1.23.3-bookworm AS pfcpiface-build ARG GOFLAGS WORKDIR /pfcpiface @@ -134,7 +134,7 @@ COPY . /pfcpiface RUN CGO_ENABLED=0 go build $GOFLAGS -o /bin/pfcpiface ./cmd/pfcpiface # Stage pfcpiface: runtime image of pfcpiface toward SMF/SPGW-C -FROM alpine:3.20.2 AS pfcpiface +FROM alpine:3.20.3 AS pfcpiface COPY conf /opt/bess/bessctl/conf COPY --from=pfcpiface-build /bin/pfcpiface /bin ENTRYPOINT [ "/bin/pfcpiface" ] diff --git a/VERSION b/VERSION index f9f73cc57..227cea215 100644 --- a/VERSION +++ b/VERSION @@ -1 +1 @@ -1.4.2-dev +2.0.0 diff --git a/cmd/p4info_code_gen/p4info_code_gen.go b/cmd/p4info_code_gen/p4info_code_gen.go index c5d11e4de..a2a835535 100644 --- a/cmd/p4info_code_gen/p4info_code_gen.go +++ b/cmd/p4info_code_gen/p4info_code_gen.go @@ -13,8 +13,7 @@ import ( "github.com/ettle/strcase" "github.com/golang/protobuf/proto" - - log "github.com/sirupsen/logrus" + "github.com/omec-project/upf-epc/logger" p4ConfigV1 "github.com/p4lang/p4runtime/go/p4/config/v1" ) @@ -261,7 +260,7 @@ func generateConstants(p4info *p4ConfigV1.P4Info) string { name := eName + "_" + member.GetName() enumVal, err := getUint32FromByteArray(member.GetValue()) if err != nil { - log.Errorln(name, err) + logger.P4Log.Errorln(name, err) } else { constBuilder.WriteString(emitEntityConstantUint32(enumVarPrefix, name, enumVal)) } @@ -348,10 +347,10 @@ func main() { result := sb.String() if *outputPath == "-" { - fmt.Println(result) + logger.P4Log.Infoln(result) } else { if err := os.WriteFile(*outputPath, []byte(result), 0644); err != nil { - panic(fmt.Sprintf("Error while creating File: %v", err)) + logger.P4Log.Panicf("Error while creating File: %v", err) } } } diff --git a/cmd/pfcpiface/main.go b/cmd/pfcpiface/main.go index 1cb2bfc10..c6f9c11a9 100644 --- a/cmd/pfcpiface/main.go +++ b/cmd/pfcpiface/main.go @@ -7,22 +7,15 @@ package main import ( "flag" + "github.com/omec-project/upf-epc/logger" "github.com/omec-project/upf-epc/pfcpiface" - log "github.com/sirupsen/logrus" + "go.uber.org/zap/zapcore" ) var ( configPath = flag.String("config", "upf.jsonc", "path to upf config") ) -func init() { - // Set up logger - log.SetReportCaller(true) - log.SetFormatter(&log.TextFormatter{ - FullTimestamp: true, - }) -} - func main() { // cmdline args flag.Parse() @@ -30,12 +23,17 @@ func main() { // Read and parse json startup file. conf, err := pfcpiface.LoadConfigFile(*configPath) if err != nil { - log.Fatalln("Error reading conf file:", err) + logger.InitLog.Fatalln("error reading conf file:", err) } - log.SetLevel(conf.LogLevel) + lvl, errLevel := zapcore.ParseLevel(conf.LogLevel.String()) + if errLevel != nil { + logger.InitLog.Errorln("can not parse input level") + } + logger.InitLog.Infoln("setting log level to:", lvl) + logger.SetLogLevel(lvl) - log.Infof("%+v", conf) + logger.InitLog.Infof("%+v", conf) pfcpi := pfcpiface.NewPFCPIface(conf) diff --git a/conf/upf.jsonc b/conf/upf.jsonc index f33268971..2818d2087 100644 --- a/conf/upf.jsonc +++ b/conf/upf.jsonc @@ -25,7 +25,7 @@ "farLookup": 150000 }, - // [Optional] Set the log level to one of \"panic\", \"fatal\", \"error\", \"warning\", \"info\", \"debug\", \"trace\" + // [Optional] Set the log level to one of "panic", "fatal", "error", "warn", "info", "debug" "log_level": "info", // Use the sim block to enable simulation using either Source module or via il_trafficgen diff --git a/go.mod b/go.mod index bb3e8da36..bac5f63cc 100644 --- a/go.mod +++ b/go.mod @@ -1,33 +1,33 @@ module github.com/omec-project/upf-epc -go 1.21 +go 1.23 require ( github.com/Showmax/go-fqdn v1.0.0 github.com/antoninbas/p4runtime-go-client v0.0.0-20220204221603-49eba9f248c1 github.com/deckarep/golang-set v1.8.0 - github.com/docker/docker v26.1.4+incompatible + github.com/docker/docker v26.1.5+incompatible github.com/docker/go-connections v0.4.0 - github.com/ettle/strcase v0.1.1 + github.com/ettle/strcase v0.2.0 github.com/golang/protobuf v1.5.4 github.com/google/gopacket v1.1.19 github.com/grpc-ecosystem/go-grpc-middleware v1.3.0 github.com/libp2p/go-reuseport v0.1.0 - github.com/omec-project/pfcpsim v0.1.0 + github.com/omec-project/pfcpsim v1.2.0 github.com/p4lang/p4runtime v1.3.0 github.com/prometheus/client_golang v1.11.1 - github.com/sirupsen/logrus v1.9.3 github.com/stretchr/testify v1.9.0 - github.com/wmnsk/go-pfcp v0.0.14 + github.com/wmnsk/go-pfcp v0.0.24 + go.uber.org/zap v1.27.0 google.golang.org/genproto v0.0.0-20230410155749-daa745c078e1 - google.golang.org/grpc v1.64.1 + google.golang.org/grpc v1.67.0 google.golang.org/protobuf v1.34.2 ) require ( github.com/Microsoft/go-winio v0.5.2 // indirect github.com/beorn7/perks v1.0.1 // indirect - github.com/cespare/xxhash/v2 v2.2.0 // indirect + github.com/cespare/xxhash/v2 v2.3.0 // indirect github.com/containerd/log v0.1.0 // indirect github.com/davecgh/go-spew v1.1.1 // indirect github.com/distribution/reference v0.6.0 // indirect @@ -48,15 +48,17 @@ require ( github.com/prometheus/client_model v0.2.0 // indirect github.com/prometheus/common v0.26.0 // indirect github.com/prometheus/procfs v0.6.0 // indirect + github.com/sirupsen/logrus v1.9.3 // indirect go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp v0.53.0 // indirect go.opentelemetry.io/otel v1.28.0 // indirect go.opentelemetry.io/otel/exporters/otlp/otlptrace/otlptracehttp v1.28.0 // indirect go.opentelemetry.io/otel/metric v1.28.0 // indirect go.opentelemetry.io/otel/sdk v1.28.0 // indirect go.opentelemetry.io/otel/trace v1.28.0 // indirect - golang.org/x/net v0.26.0 // indirect - golang.org/x/sys v0.21.0 // indirect - golang.org/x/text v0.16.0 // indirect + go.uber.org/multierr v1.10.0 // indirect + golang.org/x/net v0.28.0 // indirect + golang.org/x/sys v0.24.0 // indirect + golang.org/x/text v0.17.0 // indirect golang.org/x/time v0.0.0-20211116232009-f0f3c7e86c11 // indirect gopkg.in/yaml.v3 v3.0.1 // indirect gotest.tools/v3 v3.1.0 // indirect diff --git a/go.sum b/go.sum index e0a880dd1..023291809 100644 --- a/go.sum +++ b/go.sum @@ -22,8 +22,8 @@ github.com/cenkalti/backoff/v4 v4.3.0 h1:MyRJ/UdXutAwSAT+s3wNd7MfTIcy71VQueUuFK3 github.com/cenkalti/backoff/v4 v4.3.0/go.mod h1:Y3VNntkOUPxTVeUxJ/G5vcM//AlwfmyYozVcomhLiZE= github.com/census-instrumentation/opencensus-proto v0.2.1/go.mod h1:f6KPmirojxKA12rnyqOA5BBL4O983OfeGPqjHWSTneU= github.com/cespare/xxhash/v2 v2.1.1/go.mod h1:VGX0DQ3Q6kWi7AoAeZDth3/j3BFtOZR5XLFGgcrjCOs= -github.com/cespare/xxhash/v2 v2.2.0 h1:DC2CZ1Ep5Y4k3ZQ899DldepgrayRUGE6BBZ/cd9Cj44= -github.com/cespare/xxhash/v2 v2.2.0/go.mod h1:VGX0DQ3Q6kWi7AoAeZDth3/j3BFtOZR5XLFGgcrjCOs= +github.com/cespare/xxhash/v2 v2.3.0 h1:UL815xU9SqsFlibzuggzjXhog7bL6oX9BbNZnL2UFvs= +github.com/cespare/xxhash/v2 v2.3.0/go.mod h1:VGX0DQ3Q6kWi7AoAeZDth3/j3BFtOZR5XLFGgcrjCOs= github.com/client9/misspell v0.3.4/go.mod h1:qj6jICC3Q7zFZvVWo7KLAzC3yx5G7kyvSDkc90ppPyw= github.com/cncf/udpa/go v0.0.0-20191209042840-269d4d468f6f/go.mod h1:M8M6+tZqaGXZJjfX53e64911xZQV5JYwmTeXPW+k8Sc= github.com/containerd/log v0.1.0 h1:TCJt7ioM2cr/tfR8GPbGf9/VRAX8D2B4PjzCpfX540I= @@ -36,8 +36,8 @@ github.com/deckarep/golang-set v1.8.0 h1:sk9/l/KqpunDwP7pSjUg0keiOOLEnOBHzykLrsP github.com/deckarep/golang-set v1.8.0/go.mod h1:5nI87KwE7wgsBU1F4GKAw2Qod7p5kyS383rP6+o6qqo= github.com/distribution/reference v0.6.0 h1:0IXCQ5g4/QMHHkarYzh5l+u8T3t73zM5QvfrDyIgxBk= github.com/distribution/reference v0.6.0/go.mod h1:BbU0aIcezP1/5jX/8MP0YiH4SdvB5Y4f/wlDRiLyi3E= -github.com/docker/docker v26.1.4+incompatible h1:vuTpXDuoga+Z38m1OZHzl7NKisKWaWlhjQk7IDPSLsU= -github.com/docker/docker v26.1.4+incompatible/go.mod h1:eEKB0N0r5NX/I1kEveEz05bcu8tLC/8azJZsviup8Sk= +github.com/docker/docker v26.1.5+incompatible h1:NEAxTwEjxV6VbBMBoGG3zPqbiJosIApZjxlbrG9q3/g= +github.com/docker/docker v26.1.5+incompatible/go.mod h1:eEKB0N0r5NX/I1kEveEz05bcu8tLC/8azJZsviup8Sk= github.com/docker/go-connections v0.4.0 h1:El9xVISelRB7BuFusrZozjnkIM5YnzCViNKohAFqRJQ= github.com/docker/go-connections v0.4.0/go.mod h1:Gbd7IOopHjR8Iph03tsViu4nIes5XhDvyHbTtUxmeec= github.com/docker/go-units v0.4.0 h1:3uh0PgVws3nIA0Q+MwDC8yjEPf9zjRfZZWXZYDct3Tw= @@ -46,8 +46,8 @@ github.com/envoyproxy/go-control-plane v0.9.0/go.mod h1:YTl/9mNaCwkRvm6d1a2C3ymF github.com/envoyproxy/go-control-plane v0.9.1-0.20191026205805-5f8ba28d4473/go.mod h1:YTl/9mNaCwkRvm6d1a2C3ymFceY/DCBVvsKhRF0iEA4= github.com/envoyproxy/go-control-plane v0.9.4/go.mod h1:6rpuAdCZL397s3pYoYcLgu1mIlRU8Am5FuJP05cCM98= github.com/envoyproxy/protoc-gen-validate v0.1.0/go.mod h1:iSmxcyjqTsJpI2R4NaDN7+kN2VEUnK/pcBlmesArF7c= -github.com/ettle/strcase v0.1.1 h1:htFueZyVeE1XNnMEfbqp5r67qAN/4r6ya1ysq8Q+Zcw= -github.com/ettle/strcase v0.1.1/go.mod h1:hzDLsPC7/lwKyBOywSHEP89nt2pDgdy+No1NBA9o9VY= +github.com/ettle/strcase v0.2.0 h1:fGNiVF21fHXpX1niBgk0aROov1LagYsOwV/xqKDKR/Q= +github.com/ettle/strcase v0.2.0/go.mod h1:DajmHElDSaX76ITe3/VHVyMin4LWSJN5Z909Wp+ED1A= github.com/felixge/httpsnoop v1.0.4 h1:NFTV2Zj1bL4mc9sqWACXbQFVBBg2W3GPvqp8/ESS2Wg= github.com/felixge/httpsnoop v1.0.4/go.mod h1:m8KPJKqk1gH5J9DgRY2ASl2lWCfGKXixSwevea8zH2U= github.com/go-kit/kit v0.8.0/go.mod h1:xBxKIO96dXMWWy0MnWVtmwkA9/13aqxPnvrjFYMA2as= @@ -132,8 +132,8 @@ github.com/morikuni/aec v1.0.0 h1:nP9CBfwrvYnBRgY6qfDQkygYDmYwOilePFkwzv4dU8A= github.com/morikuni/aec v1.0.0/go.mod h1:BbKIizmSmc5MMPqRYbxO4ZU0S0+P200+tUnFx7PXmsc= github.com/mwitkow/go-conntrack v0.0.0-20161129095857-cc309e4a2223/go.mod h1:qRWi+5nqEBWmkhHvq77mSJWrCKwh8bxhgT7d/eI7P4U= github.com/mwitkow/go-conntrack v0.0.0-20190716064945-2f068394615f/go.mod h1:qRWi+5nqEBWmkhHvq77mSJWrCKwh8bxhgT7d/eI7P4U= -github.com/omec-project/pfcpsim v0.1.0 h1:bVns5jF9bZvleejQNNHBvzvA/PtQTBxUE0YnLS4XyXE= -github.com/omec-project/pfcpsim v0.1.0/go.mod h1:ELaB0bjuNv7TEWN0Nx+HX4yQx0uevmdw/3GM+Kny7Ko= +github.com/omec-project/pfcpsim v1.2.0 h1:LxF+xePPQi6olzLNwKNH62g2Le3tPpllbqcalTHiLJQ= +github.com/omec-project/pfcpsim v1.2.0/go.mod h1:rn5FqLRxNJBK9pJP5dDdBVzsYpNWXanQfVa1wbCXRLY= github.com/opencontainers/go-digest v1.0.0 h1:apOUWs51W5PlhuyGyz9FCeeBIOUDA/6nW8Oi/yOhh5U= github.com/opencontainers/go-digest v1.0.0/go.mod h1:0JzlMkj0TRzQZfJkVvzbP0HBR3IKzErnv2BNG4W4MAM= github.com/opencontainers/image-spec v1.0.2 h1:9yCKha/T5XdGtO0q9Q9a6T5NUCsTn/DrBg0D7ufOcFM= @@ -141,8 +141,6 @@ github.com/opencontainers/image-spec v1.0.2/go.mod h1:BtxoFyWECRxE4U/7sNtV5W15zM github.com/opentracing/opentracing-go v1.1.0/go.mod h1:UkNAQd3GIcIGf0SeVgPpRdFStlNbqXla1AfSYxPUl2o= github.com/p4lang/p4runtime v1.3.0 h1:3fUhHj0JtsGcL2Bh0uxpACdBJBDqpZyLgj93tqKzoJY= github.com/p4lang/p4runtime v1.3.0/go.mod h1:voPsRsgz/TDEhcaFvBxfMbI++hSKR/QGJusJveEs9Jg= -github.com/pascaldekloe/goe v0.1.0 h1:cBOtyMzM9HTpWjXfbbunk26uA6nG3a8n06Wieeh0MwY= -github.com/pascaldekloe/goe v0.1.0/go.mod h1:lzWF7FIEvWOWxwDKqyGYQf6ZUaNfKdP144TG7ZOy1lc= github.com/pkg/errors v0.8.0/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0= github.com/pkg/errors v0.8.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0= github.com/pkg/errors v0.9.1 h1:FEBLx1zS214owpjy7qsBeixbURkuhQAwrK5UwLGTwt4= @@ -181,12 +179,11 @@ github.com/stretchr/objx v0.1.1/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+ github.com/stretchr/testify v1.2.2/go.mod h1:a8OnRcib4nhh0OaRAV+Yts87kKdq0PP7pXfy6kDkUVs= github.com/stretchr/testify v1.3.0/go.mod h1:M5WIy9Dh21IEIfnGCwXGc5bZfKNJtfHm1UVUgZn+9EI= github.com/stretchr/testify v1.4.0/go.mod h1:j7eGeouHqKxXV5pUuKE4zz7dFj8WfuZ+81PSLYec5m4= -github.com/stretchr/testify v1.5.1/go.mod h1:5W2xD1RspED5o8YsWQXVCued0rvSQ+mT+I5cxcmMvtA= github.com/stretchr/testify v1.7.0/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg= github.com/stretchr/testify v1.9.0 h1:HtqpIVDClZ4nwg75+f6Lvsy/wHu+3BoSGCbBAcpTsTg= github.com/stretchr/testify v1.9.0/go.mod h1:r2ic/lqez/lEtzL7wO/rwa5dbSLXVDPFyf8C91i36aY= -github.com/wmnsk/go-pfcp v0.0.14 h1:PMX7zKZYHaRM8qgjle45a/yis4q9hOAwRTfBMt+o7U4= -github.com/wmnsk/go-pfcp v0.0.14/go.mod h1:QKYWo1Wac4hc1Ut1YeaPKxcYUf8oHBZyqODJC6VAPBI= +github.com/wmnsk/go-pfcp v0.0.24 h1:sv4F3U/IphsPUMXMkTJW877CRvXZ1sF5onWHGBvxx/A= +github.com/wmnsk/go-pfcp v0.0.24/go.mod h1:8EUVvOzlz25wkUs9D8STNAs5zGyIo5xEUpHQOUZ/iSg= github.com/yuin/goldmark v1.1.27/go.mod h1:3hX8gzYuyVAZsxl0MRgGTJEmQBFcNTphYh9decYSb74= github.com/yuin/goldmark v1.2.1/go.mod h1:3hX8gzYuyVAZsxl0MRgGTJEmQBFcNTphYh9decYSb74= go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp v0.53.0 h1:4K4tsIXefpVJtvA/8srF4V4y0akAoPHkIslgAkjixJA= @@ -206,8 +203,14 @@ go.opentelemetry.io/otel/trace v1.28.0/go.mod h1:jPyXzNPg6da9+38HEwElrQiHlVMTnVf go.opentelemetry.io/proto/otlp v1.3.1 h1:TrMUixzpM0yuc/znrFTP9MMRh8trP93mkCiDVeXrui0= go.opentelemetry.io/proto/otlp v1.3.1/go.mod h1:0X1WI4de4ZsLrrJNLAQbFeLCm3T7yBkR0XqQ7niQU+8= go.uber.org/atomic v1.4.0/go.mod h1:gD2HeocX3+yG+ygLZcrzQJaqmWj9AIm7n08wl/qW/PE= +go.uber.org/goleak v1.3.0 h1:2K3zAYmnTNqV73imy9J1T3WC+gmCePx2hEGkimedGto= +go.uber.org/goleak v1.3.0/go.mod h1:CoHD4mav9JJNrW/WLlf7HGZPjdw8EucARQHekz1X6bE= go.uber.org/multierr v1.1.0/go.mod h1:wR5kodmAFQ0UK8QlbwjlSNy0Z68gJhDJUG5sjR94q/0= +go.uber.org/multierr v1.10.0 h1:S0h4aNzvfcFsC3dRF1jLoaov7oRaKqRGC/pUEJ2yvPQ= +go.uber.org/multierr v1.10.0/go.mod h1:20+QtiLqy0Nd6FdQB9TLXag12DsQkrbs3htMFfDN80Y= go.uber.org/zap v1.10.0/go.mod h1:vwi/ZaCAaUcBkycHslxD9B2zi4UTXhF60s6SWpuDF0Q= +go.uber.org/zap v1.27.0 h1:aJMhYGrd5QSmlpLMr2MftRKl7t8J8PTZPA732ud/XR8= +go.uber.org/zap v1.27.0/go.mod h1:GB2qFLM7cTU87MWRP2mPIjqfIDnGu+VIO4V/SdhGo2E= golang.org/x/crypto v0.0.0-20180904163835-0709b304e793/go.mod h1:6SG95UA2DQfeDnfUPMdvaQW0Q7yPrPDi9nlGo2tz2b4= golang.org/x/crypto v0.0.0-20190308221718-c2843e01d9a2/go.mod h1:djNgcEr1/C05ACkg1iLfiJU5Ep61QUkGW8qpdssI0+w= golang.org/x/crypto v0.0.0-20191011191535-87dc89f01550/go.mod h1:yigFU9vqHzYiE8UmvKecakEJjdnWj3jj499lnFckfCI= @@ -232,8 +235,8 @@ golang.org/x/net v0.0.0-20190620200207-3b0461eec859/go.mod h1:z5CRVTTTmAJ677TzLL golang.org/x/net v0.0.0-20200226121028-0de0cce0169b/go.mod h1:z5CRVTTTmAJ677TzLLGU+0bjPO0LkuOLi4/5GtJWs/s= golang.org/x/net v0.0.0-20200625001655-4c5254603344/go.mod h1:/O7V0waA8r7cgGh81Ro3o1hOxt32SMVPicZroKQ2sZA= golang.org/x/net v0.0.0-20201021035429-f5854403a974/go.mod h1:sp8m0HH+o8qH0wwXwYZr8TS3Oi6o0r6Gce1SSxlDquU= -golang.org/x/net v0.26.0 h1:soB7SVo0PWrY4vPW/+ay0jKDNScG2X9wFeYlXIvJsOQ= -golang.org/x/net v0.26.0/go.mod h1:5YKkiSynbBIh3p6iOc/vibscux0x38BZDkn8sCUPxHE= +golang.org/x/net v0.28.0 h1:a9JDOJc5GMUJ0+UDqmLT86WiEy7iWyIhz8gz8E4e5hE= +golang.org/x/net v0.28.0/go.mod h1:yqtgsTWOOnlGLG9GFRrK3++bGOUEkNBoHZc8MEDWPNg= golang.org/x/oauth2 v0.0.0-20180821212333-d2e6202438be/go.mod h1:N/0e6XlmueqKjAGxoOufVs8QHGRruUQn6yWY3a++T0U= golang.org/x/oauth2 v0.0.0-20190226205417-e64efc72b421/go.mod h1:gOpvHmFTYa4IltrdGE7lF6nIHvwfUNPOp7c8zoXwtLw= golang.org/x/sync v0.0.0-20180314180146-1d60e4601c6f/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM= @@ -261,13 +264,13 @@ golang.org/x/sys v0.0.0-20210124154548-22da62e12c0c/go.mod h1:h1NjWce9XRLGQEsW7w golang.org/x/sys v0.0.0-20210603081109-ebe580a85c40/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.0.0-20210616094352-59db8d763f22/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.0.0-20220715151400-c0bba94af5f8/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= -golang.org/x/sys v0.21.0 h1:rF+pYz3DAGSQAxAu1CbC7catZg4ebC4UIeIhKxBZvws= -golang.org/x/sys v0.21.0/go.mod h1:/VUhepiaJMQUp4+oa/7Zr1D23ma6VTLIYjOOTFZPUcA= +golang.org/x/sys v0.24.0 h1:Twjiwq9dn6R1fQcyiK+wQyHWfaz/BJB+YIpzU/Cv3Xg= +golang.org/x/sys v0.24.0/go.mod h1:/VUhepiaJMQUp4+oa/7Zr1D23ma6VTLIYjOOTFZPUcA= golang.org/x/text v0.3.0/go.mod h1:NqM8EUOU14njkJ3fqMW+pc6Ldnwhi/IjpwHt7yyuwOQ= golang.org/x/text v0.3.2/go.mod h1:bEr9sfX3Q8Zfm5fL9x+3itogRgK3+ptLWKqgva+5dAk= golang.org/x/text v0.3.3/go.mod h1:5Zoc/QRtKVWzQhOtBMvqHzDpF6irO9z98xDceosuGiQ= -golang.org/x/text v0.16.0 h1:a94ExnEXNtEwYLGJSIUxnWoxoRz/ZcCsV63ROupILh4= -golang.org/x/text v0.16.0/go.mod h1:GhwF1Be+LQoKShO3cGOHzqOgRrGaYc9AvblQOmPVHnI= +golang.org/x/text v0.17.0 h1:XtiM5bkSOt+ewxlOE/aE/AKEHibwj/6gvWMl9Rsh0Qc= +golang.org/x/text v0.17.0/go.mod h1:BuEKDfySbSR4drPmRPG/7iBdf8hvFMuRexcpahXilzY= golang.org/x/time v0.0.0-20211116232009-f0f3c7e86c11 h1:GZokNIeuVkl3aZHJchRrr13WCsols02MLUcz1U9is6M= golang.org/x/time v0.0.0-20211116232009-f0f3c7e86c11/go.mod h1:tRJNPiyCQ0inRvYxbN9jk5I+vvW/OXSQhTDSoE431IQ= golang.org/x/tools v0.0.0-20180917221912-90fa682c2a6e/go.mod h1:n7NCudcB/nEzxVGmLbDWY5pfWTLqBcC2KZ6jyYvM4mQ= @@ -299,8 +302,8 @@ google.golang.org/grpc v1.25.1/go.mod h1:c3i+UQWmh7LiEpx4sFZnkU36qjEYZ0imhYfXVyQ google.golang.org/grpc v1.27.0/go.mod h1:qbnxyOmOxrQa7FizSgH+ReBfzJrCY1pSN7KXBS8abTk= google.golang.org/grpc v1.28.1/go.mod h1:rpkK4SK4GF4Ach/+MFLZUBavHOvF2JJB5uozKKal+60= google.golang.org/grpc v1.29.1/go.mod h1:itym6AZVZYACWQqET3MqgPpjcuV5QH3BxFS3IjizoKk= -google.golang.org/grpc v1.64.1 h1:LKtvyfbX3UGVPFcGqJ9ItpVWW6oN/2XqTxfAnwRRXiA= -google.golang.org/grpc v1.64.1/go.mod h1:hiQF4LFZelK2WKaP6W0L92zGHtiQdZxk8CrSdvyjeP0= +google.golang.org/grpc v1.67.0 h1:IdH9y6PF5MPSdAntIcpjQ+tXO41pcQsfZV2RxtQgVcw= +google.golang.org/grpc v1.67.0/go.mod h1:1gLDyUQU7CTLJI90u3nXZ9ekeghjeM7pTDZlqFNg2AA= google.golang.org/protobuf v0.0.0-20200109180630-ec00e32a8dfd/go.mod h1:DFci5gLYBciE7Vtevhsrf46CRTquxDuWsQurQQe4oz8= google.golang.org/protobuf v0.0.0-20200221191635-4d8936d0db64/go.mod h1:kwYJMbMJ01Woi6D6+Kah6886xMZcty6N08ah7+eCXa0= google.golang.org/protobuf v0.0.0-20200228230310-ab0ca4ff8a60/go.mod h1:cfTl7dwQJ+fmap5saPgwCLgHXTUD7jkjRqWcaiX5VyM= diff --git a/logger/logger.go b/logger/logger.go new file mode 100644 index 000000000..cc09fefd5 --- /dev/null +++ b/logger/logger.go @@ -0,0 +1,63 @@ +// SPDX-FileCopyrightText: 2024 Intel Corporation +// +// SPDX-License-Identifier: Apache-2.0 + +package logger + +import ( + "go.uber.org/zap" + "go.uber.org/zap/zapcore" +) + +var ( + log *zap.Logger + BessLog *zap.SugaredLogger + DockerLog *zap.SugaredLogger + InitLog *zap.SugaredLogger + P4Log *zap.SugaredLogger + PfcpLog *zap.SugaredLogger + atomicLevel zap.AtomicLevel +) + +func init() { + atomicLevel = zap.NewAtomicLevelAt(zap.InfoLevel) + config := zap.Config{ + Level: atomicLevel, + Development: false, + Encoding: "console", + EncoderConfig: zap.NewProductionEncoderConfig(), + OutputPaths: []string{"stdout"}, + ErrorOutputPaths: []string{"stderr"}, + } + + config.EncoderConfig.TimeKey = "timestamp" + config.EncoderConfig.EncodeTime = zapcore.ISO8601TimeEncoder + config.EncoderConfig.LevelKey = "level" + config.EncoderConfig.EncodeLevel = zapcore.CapitalLevelEncoder + config.EncoderConfig.CallerKey = "caller" + config.EncoderConfig.EncodeCaller = zapcore.ShortCallerEncoder + config.EncoderConfig.MessageKey = "message" + config.EncoderConfig.StacktraceKey = "" + + var err error + log, err = config.Build() + if err != nil { + panic(err) + } + + BessLog = log.Sugar().With("component", "UPF", "category", "BESS") + DockerLog = log.Sugar().With("component", "UPF", "category", "Docker") + InitLog = log.Sugar().With("component", "UPF", "category", "Init") + P4Log = log.Sugar().With("component", "UPF", "category", "P4") + PfcpLog = log.Sugar().With("component", "UPF", "category", "Pfcp") +} + +func GetLogger() *zap.Logger { + return log +} + +// SetLogLevel: set the log level (panic|fatal|error|warn|info|debug) +func SetLogLevel(level zapcore.Level) { + InitLog.Infoln("set log level:", level) + atomicLevel.SetLevel(level) +} diff --git a/pfcpiface/bess.go b/pfcpiface/bess.go index b532679de..191f4304c 100644 --- a/pfcpiface/bess.go +++ b/pfcpiface/bess.go @@ -16,9 +16,9 @@ import ( "google.golang.org/grpc/credentials/insecure" + "github.com/omec-project/upf-epc/logger" pb "github.com/omec-project/upf-epc/pfcpiface/bess_pb" "github.com/prometheus/client_golang/prometheus" - log "github.com/sirupsen/logrus" "github.com/wmnsk/go-pfcp/ie" "google.golang.org/grpc" "google.golang.org/protobuf/types/known/anypb" @@ -117,7 +117,7 @@ func (b *bess) AddSliceInfo(sliceInfo *SliceInfo) error { rc := b.GRPCJoin(1, Timeout, done) if !rc { - log.Errorln("Unable to make GRPC calls") + logger.BessLog.Errorln("unable to make GRPC calls") } return nil @@ -149,7 +149,7 @@ func (b *bess) SendMsgToUPF( done := make(chan bool) for _, pdr := range pdrs { - log.Traceln(method, pdr) + logger.BessLog.Debugln(method, pdr) switch method { case upfMsgTypeAdd: @@ -162,7 +162,7 @@ func (b *bess) SendMsgToUPF( } for _, far := range fars { - log.Traceln(method, far) + logger.BessLog.Debugln(method, far) switch method { case upfMsgTypeAdd: @@ -175,7 +175,7 @@ func (b *bess) SendMsgToUPF( } for _, qer := range qers { - log.Traceln(method, qer) + logger.BessLog.Debugln(method, qer) switch method { case upfMsgTypeAdd: @@ -189,14 +189,14 @@ func (b *bess) SendMsgToUPF( rc := b.GRPCJoin(calls, Timeout, done) if !rc { - log.Println("Unable to make GRPC calls") + logger.BessLog.Errorln("unable to make GRPC calls") } return cause } func (b *bess) Exit() { - log.Println("Exit function Bess") + logger.BessLog.Infoln("exit function Bess") b.conn.Close() } @@ -207,7 +207,7 @@ func (b *bess) measureUpf(ifName string, f *pb.MeasureCommandGetSummaryArg) *pb. any, err := anypb.New(f) if err != nil { - log.Println("Error marshalling the rule", f, err) + logger.BessLog.Errorln("error marshalling the rule", f, err) return nil } @@ -219,7 +219,7 @@ func (b *bess) measureUpf(ifName string, f *pb.MeasureCommandGetSummaryArg) *pb. Arg: any, }) if err != nil { - log.Println("Error calling get_summary on module", modName(), err) + logger.BessLog.Errorln("error calling get_summary on module", modName(), err) return nil } @@ -227,7 +227,7 @@ func (b *bess) measureUpf(ifName string, f *pb.MeasureCommandGetSummaryArg) *pb. err = modRes.GetData().UnmarshalTo(&res) if err != nil { - log.Println("Error unmarshalling the response", modName(), err) + logger.BessLog.Errorln("error unmarshalling the response", modName(), err) return nil } @@ -242,12 +242,12 @@ func (b *bess) getPortStats(ifname string) *pb.GetPortStatsResponse { res, err := b.client.GetPortStats(ctx, req) if err != nil { - log.Println("Error calling GetPortStats", ifname, err) + logger.BessLog.Errorln("error calling GetPortStats", ifname, err) return nil } if res.GetError() != nil { - log.Println("Error calling GetPortStats", ifname, err, res.GetError().Errmsg) + logger.BessLog.Errorln("error calling GetPortStats", ifname, err, res.GetError().Errmsg) return nil } @@ -349,7 +349,7 @@ func (b *bess) SummaryLatencyJitter(uc *upfCollector, ch chan<- prometheus.Metri func (b *bess) SummaryGtpuLatency(uc *upfCollector, ch chan<- prometheus.Metric) { gtpuPathStatsResp := b.readGtpuPathMonitoringStats(GtpuPathMonitoringMeasure, true) if gtpuPathStatsResp == nil { - log.Errorln(GtpuPathMonitoringMeasure, " read failed!") + logger.BessLog.Errorln(GtpuPathMonitoringMeasure, "read failed") return } @@ -389,7 +389,7 @@ func (b *bess) flipFlowMeasurementBufferFlag(ctx context.Context, module string) any, err := anypb.New(req) if err != nil { - log.Errorln("Error marshalling request", req, err) + logger.BessLog.Errorln("error marshalling request", req, err) return } @@ -402,17 +402,17 @@ func (b *bess) flipFlowMeasurementBufferFlag(ctx context.Context, module string) ) if err != nil { - log.Errorln(module, "read failed!:", err) + logger.BessLog.Errorln(module, "read failed:", err) return } if resp.GetError() != nil { - log.Errorln(module, "error reading flow stats:", resp.GetError().Errmsg) + logger.BessLog.Errorln(module, "error reading flow stats:", resp.GetError().Errmsg) return } if err = resp.Data.UnmarshalTo(&flip); err != nil { - log.Errorln(err) + logger.BessLog.Errorln(err) return } @@ -431,7 +431,7 @@ func (b *bess) readFlowMeasurement( any, err := anypb.New(req) if err != nil { - log.Errorln("Error marshalling request", req, err) + logger.BessLog.Errorln("error marshalling request", req, err) return } @@ -444,17 +444,17 @@ func (b *bess) readFlowMeasurement( ) if err != nil { - log.Errorln(module, "read failed!:", err) + logger.BessLog.Errorln(module, "read failed:", err) return } if resp.GetError() != nil { - log.Errorln(module, "error reading flow stats:", resp.GetError().Errmsg) + logger.BessLog.Errorln(module, "error reading flow stats:", resp.GetError().Errmsg) return } if err = resp.Data.UnmarshalTo(&stats); err != nil { - log.Errorln(err, resp) + logger.BessLog.Errorln(err, resp) return } @@ -469,7 +469,7 @@ func (b *bess) readGtpuPathMonitoringStats( any, err := anypb.New(req) if err != nil { - log.Errorln("Error marshalling request", req, err) + logger.BessLog.Errorln("error marshalling request", req, err) return nil } @@ -484,12 +484,12 @@ func (b *bess) readGtpuPathMonitoringStats( ) if err != nil { - log.Errorln(module, "read failed!:", err) + logger.BessLog.Errorln(module, "read failed:", err) return nil } if resp.GetError() != nil { - log.Errorln(module, "error reading gptu path monitoring stats:", resp.GetError().Errmsg) + logger.BessLog.Errorln(module, "error reading gptu path monitoring stats:", resp.GetError().Errmsg) return nil } @@ -497,7 +497,7 @@ func (b *bess) readGtpuPathMonitoringStats( err = resp.Data.UnmarshalTo(&res) if err != nil { - log.Errorln(err, resp) + logger.BessLog.Errorln(err, resp) return nil } @@ -512,7 +512,7 @@ func (b *bess) SessionStats(pc *PfcpNodeCollector, ch chan<- prometheus.Metric) // Flips the buffer flag, automatically waits for in-flight packets to drain. flip, err := b.flipFlowMeasurementBufferFlag(ctx, PreQosFlowMeasure) if err != nil { - log.Errorln(PreQosFlowMeasure, " read failed!:", err) + logger.BessLog.Errorln(PreQosFlowMeasure, "read failed:", err) return } @@ -521,19 +521,19 @@ func (b *bess) SessionStats(pc *PfcpNodeCollector, ch chan<- prometheus.Metric) // Read stats from the now inactive side, and clear if needed. qosStatsInResp, err := b.readFlowMeasurement(ctx, PreQosFlowMeasure, flip.OldFlag, true, q) if err != nil { - log.Errorln(PreQosFlowMeasure, " read failed!:", err) + logger.BessLog.Errorln(PreQosFlowMeasure, "read failed:", err) return } postDlQosStatsResp, err := b.readFlowMeasurement(ctx, PostDlQosFlowMeasure, flip.OldFlag, true, q) if err != nil { - log.Errorln(PostDlQosFlowMeasure, " read failed!:", err) + logger.BessLog.Errorln(PostDlQosFlowMeasure, "read failed:", err) return } postUlQosStatsResp, err := b.readFlowMeasurement(ctx, PostUlQosFlowMeasure, flip.OldFlag, true, q) if err != nil { - log.Errorln(PostUlQosFlowMeasure, " read failed!:", err) + logger.BessLog.Errorln(PostUlQosFlowMeasure, "read failed:", err) return } @@ -551,7 +551,7 @@ func (b *bess) SessionStats(pc *PfcpNodeCollector, ch chan<- prometheus.Metric) }) if con == nil { - log.Warnln("No active PFCP connection, UE IP lookup disabled") + logger.BessLog.Warnln("no active PFCP connection, UE IP lookup disabled") } // Prepare session stats. @@ -569,7 +569,7 @@ func (b *bess) SessionStats(pc *PfcpNodeCollector, ch chan<- prometheus.Metric) } if pre == nil { - log.Infof("Found no pre QoS statistics for PDR %v FSEID %v", post.Pdr, post.Fseid) + logger.BessLog.Infof("found no pre QoS statistics for PDR %v FSEID %v", post.Pdr, post.Fseid) continue } @@ -580,7 +580,7 @@ func (b *bess) SessionStats(pc *PfcpNodeCollector, ch chan<- prometheus.Metric) if con != nil { session, ok := con.store.GetSession(pre.Fseid) if !ok { - log.Errorln("Invalid or unknown FSEID", pre.Fseid) + logger.BessLog.Errorln("invalid or unknown FSEID", pre.Fseid) continue } @@ -588,7 +588,7 @@ func (b *bess) SessionStats(pc *PfcpNodeCollector, ch chan<- prometheus.Metric) for _, p := range session.pdrs { if p.IsUplink() && p.ueAddress > 0 { ueIpString = int2ip(p.ueAddress).String() - log.Traceln(p.fseID, " -> ", ueIpString) + logger.BessLog.Debugln(p.fseID, " -> ", ueIpString) break } @@ -658,7 +658,7 @@ func (b *bess) endMarkerSendLoop(endMarkerChan chan []byte) { for outPacket := range endMarkerChan { _, err := b.endMarkerSocket.Write(outPacket) if err != nil { - log.Println("end marker write failed") + logger.BessLog.Errorln("end marker write failed") } } } @@ -713,13 +713,13 @@ func (b *bess) clearState() { ctx, cancel := context.WithTimeout(context.Background(), Timeout) defer cancel() - log.Debug("Clearing all the state in BESS") + logger.BessLog.Debugln("clearing all the state in BESS") clearWildcardCmd := &pb.WildcardMatchCommandClearArg{} anyWildcardClear, err := anypb.New(clearWildcardCmd) if err != nil { - log.Errorf("Error marshalling the rule %v: %v", clearWildcardCmd, err) + logger.BessLog.Errorf("error marshalling the rule %v: %v", clearWildcardCmd, err) return } @@ -729,7 +729,7 @@ func (b *bess) clearState() { anyExactClear, err := anypb.New(clearExactCmd) if err != nil { - log.Errorf("Error marshalling the rule %v: %v", anyExactClear, err) + logger.BessLog.Errorf("error marshalling the rule %v: %v", anyExactClear, err) return } @@ -741,7 +741,7 @@ func (b *bess) clearState() { var anyGtpuPathMonitoringClear *anypb.Any anyGtpuPathMonitoringClear, err = anypb.New(clearGtpuPathMonitoringCmd) if err != nil { - log.Errorf("Error marshalling the rule %v: %v", anyGtpuPathMonitoringClear, err) + logger.BessLog.Errorf("error marshalling the rule %v: %v", anyGtpuPathMonitoringClear, err) return } @@ -752,16 +752,16 @@ func (b *bess) clearState() { var anyQoSClear *anypb.Any anyQoSClear, err = anypb.New(clearQoSCmd) if err != nil { - log.Errorf("Error marshalling the rule %v: %v", anyQoSClear, err) + logger.BessLog.Errorf("error marshalling the rule %v: %v", anyQoSClear, err) return } if err = b.processQER(ctx, anyQoSClear, upfMsgTypeClear, AppQerLookup); err != nil { - log.Errorf("Failed to clear %v", AppQerLookup) + logger.BessLog.Errorf("failed to clear %v", AppQerLookup) } if err = b.processQER(ctx, anyQoSClear, upfMsgTypeClear, SessQerLookup); err != nil { - log.Errorf("Failed to clear %v", SessQerLookup) + logger.BessLog.Errorf("failed to clear %v", SessQerLookup) } } @@ -770,17 +770,17 @@ func (b *bess) clearState() { func (b *bess) SetUpfInfo(u *upf, conf *Conf) { var err error - log.Println("SetUpfInfo bess") + logger.BessLog.Errorln("SetUpfInfo bess") b.readQciQosMap(conf) // get bess grpc client - log.Println("bessIP ", *bessIP) + logger.BessLog.Errorln("bessIP", *bessIP) b.endMarkerChan = make(chan []byte, 1024) - b.conn, err = grpc.Dial(*bessIP, grpc.WithTransportCredentials(insecure.NewCredentials())) + b.conn, err = grpc.NewClient(*bessIP, grpc.WithTransportCredentials(insecure.NewCredentials())) if err != nil { - log.Fatalln("did not connect:", err) + logger.BessLog.Fatalln("did not connect:", err) } b.client = pb.NewBESSControlClient(b.conn) @@ -795,7 +795,7 @@ func (b *bess) SetUpfInfo(u *upf, conf *Conf) { b.notifyBessSocket, err = net.Dial("unixpacket", notifySockAddr) if err != nil { - log.Println("dial error:", err) + logger.BessLog.Errorln("dial error:", err) return } @@ -810,11 +810,11 @@ func (b *bess) SetUpfInfo(u *upf, conf *Conf) { b.endMarkerSocket, err = net.Dial("unixpacket", pfcpCommAddr) if err != nil { - log.Println("dial error:", err) + logger.BessLog.Errorln("dial error:", err) return } - log.Println("Starting end marker loop") + logger.BessLog.Infoln("Starting end marker loop") go b.endMarkerSendLoop(b.endMarkerChan) } @@ -830,7 +830,7 @@ func (b *bess) SetUpfInfo(u *upf, conf *Conf) { rc := b.GRPCJoin(1, Timeout, done) if !rc { - log.Errorln("Unable to make GRPC calls") + logger.BessLog.Errorln("unable to make GRPC calls") } } @@ -841,7 +841,7 @@ func (b *bess) SetUpfInfo(u *upf, conf *Conf) { func (b *bess) processPDR(ctx context.Context, any *anypb.Any, method upfMsgType) { if method != upfMsgTypeAdd && method != upfMsgTypeDel && method != upfMsgTypeClear { - log.Println("Invalid method name: ", method) + logger.BessLog.Infoln("invalid method name:", method) return } @@ -853,10 +853,10 @@ func (b *bess) processPDR(ctx context.Context, any *anypb.Any, method upfMsgType Arg: any, }) - log.Traceln("pdrlookup resp : ", resp) + logger.BessLog.Debugf("pdrlookup resp: %v", resp) if err != nil || resp.GetError() != nil { - log.Errorf("pdrLookup method failed with resp: %v, err: %v\n", resp, err) + logger.BessLog.Errorf("pdrLookup method failed with resp: %v, err: %v", resp, err) } } @@ -877,11 +877,11 @@ func (b *bess) addPDR(ctx context.Context, done chan<- bool, p pdr) { // Translate port ranges into ternary rule(s) and insert them one-by-one. portRules, err := CreatePortRangeCartesianProduct(p.appFilter.srcPortRange, p.appFilter.dstPortRange) if err != nil { - log.Errorln(err) + logger.BessLog.Errorln(err) return } - log.Tracef("PDR rules %+v", portRules) + logger.BessLog.Debugf("PDR rules %+v", portRules) for _, r := range portRules { f := &pb.WildcardMatchCommandAddArg{ @@ -918,7 +918,7 @@ func (b *bess) addPDR(ctx context.Context, done chan<- bool, p pdr) { any, err = anypb.New(f) if err != nil { - log.Println("Error marshalling the rule", f, err) + logger.BessLog.Infoln("error marshalling the rule", f, err) return } @@ -938,7 +938,7 @@ func (b *bess) delPDR(ctx context.Context, done chan<- bool, p pdr) { // Translate port ranges into ternary rule(s) and insert them one-by-one. portRules, err := CreatePortRangeCartesianProduct(p.appFilter.srcPortRange, p.appFilter.dstPortRange) if err != nil { - log.Errorln(err) + logger.BessLog.Errorln(err) return } @@ -968,7 +968,7 @@ func (b *bess) delPDR(ctx context.Context, done chan<- bool, p pdr) { any, err = anypb.New(f) if err != nil { - log.Errorln("Error marshalling the rule", f, err) + logger.BessLog.Errorln("error marshalling the rule", f, err) return } @@ -991,7 +991,7 @@ func (b *bess) addQER(ctx context.Context, done chan<- bool, qer qer) { // Lookup QCI from QFI, else try default QCI. qosVal, ok := b.qciQosMap[qer.qfi] if !ok { - log.Debug("No config for qfi/qci : ", qer.qfi, ". Using default burst size.") + logger.BessLog.Debugf("number of config for qfi/qci: %v using default burst size", qer.qfi) qosVal = b.qciQosMap[0] } @@ -1024,7 +1024,7 @@ func (b *bess) addQER(ctx context.Context, done chan<- bool, qer qer) { // Lookup QCI from QFI, else try default QCI. qosVal, ok = b.qciQosMap[qer.qfi] if !ok { - log.Debug("No config for qfi/qci : ", qer.qfi, ". Using default burst size.") + logger.BessLog.Debugf("number of config for qfi/qci: %v using default burst size", qer.qfi) qosVal = b.qciQosMap[0] } @@ -1082,7 +1082,7 @@ func (b *bess) addApplicationQER(ctx context.Context, gate uint64, srcIface uint any, err = anypb.New(q) if err != nil { - log.Errorln("Error marshalling the rule", q, err) + logger.BessLog.Errorln("error marshalling the rule", q, err) return } @@ -1090,7 +1090,7 @@ func (b *bess) addApplicationQER(ctx context.Context, gate uint64, srcIface uint err = b.processQER(ctx, any, upfMsgTypeAdd, qosTableName) if err != nil { - log.Errorln("process QER failed for appQERLookup add operation") + logger.BessLog.Errorln("process QER failed for appQERLookup add operation") } } @@ -1137,7 +1137,7 @@ func (b *bess) delApplicationQER( any, err = anypb.New(q) if err != nil { - log.Println("Error marshalling the rule", q, err) + logger.BessLog.Infoln("error marshalling the rule", q, err) return } @@ -1145,13 +1145,13 @@ func (b *bess) delApplicationQER( err = b.processQER(ctx, any, upfMsgTypeDel, qosTableName) if err != nil { - log.Errorln("process QER failed for appQERLookup del operation") + logger.BessLog.Errorln("process QER failed for appQERLookup del operation") } } func (b *bess) processFAR(ctx context.Context, any *anypb.Any, method upfMsgType) { if method != upfMsgTypeAdd && method != upfMsgTypeDel && method != upfMsgTypeClear { - log.Println("Invalid method name: ", method) + logger.BessLog.Errorln("invalid method name:", method) return } @@ -1163,16 +1163,16 @@ func (b *bess) processFAR(ctx context.Context, any *anypb.Any, method upfMsgType Arg: any, }) - log.Traceln("farlookup resp : ", resp) + logger.BessLog.Debugf("farlookup resp: %v", resp) if err != nil || resp.GetError() != nil { - log.Errorf("farLookup method failed with resp: %v, err: %v\n", resp, err) + logger.BessLog.Errorf("farLookup method failed with resp: %v, err: %v", resp, err) } } func (b *bess) processGtpuPathMonitoring(ctx context.Context, any *anypb.Any, method upfMsgType) { if method != upfMsgTypeAdd && method != upfMsgTypeDel && method != upfMsgTypeClear { - log.Println("Invalid method name: ", method) + logger.BessLog.Errorln("invalid method name:", method) return } @@ -1184,10 +1184,10 @@ func (b *bess) processGtpuPathMonitoring(ctx context.Context, any *anypb.Any, me Arg: any, }) - log.Traceln("gtpuPathMonitoring resp: ", resp) + logger.BessLog.Debugf("gtpuPathMonitoring resp: %v", resp) if err != nil || resp.GetError() != nil { - log.Errorf("gtpuPathMonitoring method failed with resp: %v, err: %v\n", resp, err) + logger.BessLog.Errorf("gtpuPathMonitoring method failed with resp: %v, err: %v", resp, err) } } @@ -1236,7 +1236,7 @@ func (b *bess) addFAR(ctx context.Context, done chan<- bool, far far) { any, err = anypb.New(f) if err != nil { - log.Println("Error marshalling the rule", f, err) + logger.BessLog.Infoln("error marshalling the rule", f, err) return } @@ -1249,7 +1249,7 @@ func (b *bess) addFAR(ctx context.Context, done chan<- bool, far far) { any, err = anypb.New(g) if err != nil { - log.Println("Error marshalling data", g, err) + logger.BessLog.Infoln("error marshalling data", g, err) return } @@ -1276,7 +1276,7 @@ func (b *bess) delFAR(ctx context.Context, done chan<- bool, far far) { any, err = anypb.New(f) if err != nil { - log.Println("Error marshalling the rule", f, err) + logger.BessLog.Infoln("error marshalling the rule", f, err) return } @@ -1289,12 +1289,12 @@ func (b *bess) delFAR(ctx context.Context, done chan<- bool, far far) { any, err = anypb.New(g) if err != nil { - log.Println("Error marshalling data", g, err) + logger.BessLog.Infoln("error marshalling data", g, err) return } - } - b.processGtpuPathMonitoring(ctx, any, upfMsgTypeDel) + b.processGtpuPathMonitoring(ctx, any, upfMsgTypeDel) + } done <- true }() @@ -1302,7 +1302,7 @@ func (b *bess) delFAR(ctx context.Context, done chan<- bool, far far) { func (b *bess) processSliceMeter(ctx context.Context, any *anypb.Any, method upfMsgType) { if method != upfMsgTypeAdd && method != upfMsgTypeDel && method != upfMsgTypeClear { - log.Errorln("Invalid method name: ", method) + logger.BessLog.Errorln("invalid method name:", method) return } @@ -1316,7 +1316,7 @@ func (b *bess) processSliceMeter(ctx context.Context, any *anypb.Any, method upf }, ) if err != nil { - log.Errorln("sliceMeter method failed!:", err) + logger.BessLog.Errorln("sliceMeter method failed:", err) } } @@ -1347,8 +1347,7 @@ func (b *bess) addSliceMeter(ctx context.Context, done chan<- bool, meterConfig ebs = 0 // Unused } - log.Traceln("uplink slice : cir: ", cir, ", pir: ", pir, - ", cbs: ", cbs, ", pbs: ", pbs) + logger.BessLog.Debugln("uplink slice: cir:", cir, ", pir:", pir, ", cbs:", cbs, ", pbs:", pbs) q := &pb.QosCommandAddArg{ Gate: gate, @@ -1366,7 +1365,7 @@ func (b *bess) addSliceMeter(ctx context.Context, done chan<- bool, meterConfig any, err = anypb.New(q) if err != nil { - log.Errorln("Error marshalling the rule", q, err) + logger.BessLog.Errorln("error marshalling the rule", q, err) return } @@ -1391,8 +1390,7 @@ func (b *bess) addSliceMeter(ctx context.Context, done chan<- bool, meterConfig ebs = 0 // Unused } - log.Traceln("downlink slice : cir: ", cir, ", pir: ", pir, - ", cbs: ", cbs, ", pbs: ", pbs) + logger.BessLog.Debugln("downlink slice: cir:", cir, ", pir:", pir, ", cbs:", cbs, ", pbs:", pbs) // TODO: packet deduction should take GTPU extension header into account q = &pb.QosCommandAddArg{ Gate: gate, @@ -1410,7 +1408,7 @@ func (b *bess) addSliceMeter(ctx context.Context, done chan<- bool, meterConfig any, err = anypb.New(q) if err != nil { - log.Errorln("Error marshalling the rule", q, err) + logger.BessLog.Errorln("error marshalling the rule", q, err) return } @@ -1432,10 +1430,10 @@ func (b *bess) processQER(ctx context.Context, any *anypb.Any, method upfMsgType Arg: any, }) - log.Traceln("qerlookup resp : ", resp) + logger.BessLog.Debugf("qerlookup resp: %v", resp) if err != nil || resp.GetError() != nil { - log.Errorf("%v for qer %v failed with resp: %v, error: %v", qosTableName, methods[method], resp, err) + logger.BessLog.Errorf("%v for qer %v failed with resp: %v, error: %v", qosTableName, methods[method], resp, err) return err } @@ -1465,7 +1463,7 @@ func (b *bess) addSessionQER(ctx context.Context, gate uint64, srcIface uint8, any, err = anypb.New(q) if err != nil { - log.Errorln("Error marshalling the rule", q, err) + logger.BessLog.Errorln("error marshalling the rule", q, err) return } @@ -1473,7 +1471,7 @@ func (b *bess) addSessionQER(ctx context.Context, gate uint64, srcIface uint8, err = b.processQER(ctx, any, upfMsgTypeAdd, qosTableName) if err != nil { - log.Errorln("process QER failed for sessionQERLookup add operation") + logger.BessLog.Errorln("process QER failed for sessionQERLookup add operation") } } @@ -1492,7 +1490,7 @@ func (b *bess) delSessionQER(ctx context.Context, srcIface uint8, qer qer) { any, err = anypb.New(q) if err != nil { - log.Println("Error marshalling the rule", q, err) + logger.BessLog.Errorln("error marshalling the rule", q, err) return } @@ -1500,7 +1498,7 @@ func (b *bess) delSessionQER(ctx context.Context, srcIface uint8, qer qer) { err = b.processQER(ctx, any, upfMsgTypeDel, qosTableName) if err != nil { - log.Errorln("process QER failed for sessionQERLookup del operation") + logger.BessLog.Errorln("process QER failed for sessionQERLookup del operation") } } @@ -1511,7 +1509,7 @@ func (b *bess) GRPCJoin(calls int, timeout time.Duration, done chan bool) bool { select { case ok := <-done: if !ok { - log.Println("Error making GRPC calls") + logger.BessLog.Errorln("error making GRPC calls") return false } @@ -1520,7 +1518,7 @@ func (b *bess) GRPCJoin(calls int, timeout time.Duration, done chan bool) bool { return true } case <-boom: - log.Println("Timed out adding entries") + logger.BessLog.Infoln("timed out adding entries") return false } } diff --git a/pfcpiface/config.go b/pfcpiface/config.go index 7fa9db482..0b8868d37 100644 --- a/pfcpiface/config.go +++ b/pfcpiface/config.go @@ -5,7 +5,8 @@ package pfcpiface import ( "github.com/omec-project/upf-epc/internal/p4constants" - log "github.com/sirupsen/logrus" + "go.uber.org/zap" + "go.uber.org/zap/zapcore" "net" "time" @@ -40,13 +41,14 @@ type Conf struct { EnableEndMarker bool `json:"enable_end_marker"` NotifySockAddr string `json:"notify_sockaddr"` EndMarkerSockAddr string `json:"endmarker_sockaddr"` - LogLevel log.Level `json:"log_level"` + LogLevel zapcore.Level `json:"log_level"` QciQosConfig []QciQosConfig `json:"qci_qos_config"` SliceMeterConfig SliceMeterConfig `json:"slice_rate_limit_config"` MaxReqRetries uint8 `json:"max_req_retries"` RespTimeout string `json:"resp_timeout"` EnableHBTimer bool `json:"enable_hbTimer"` HeartBeatInterval string `json:"heart_beat_interval"` + N4Addr string `json:"n4_addr"` } // QciQosConfig : Qos configured attributes. @@ -191,7 +193,7 @@ func LoadConfigFile(filepath string) (Conf, error) { jsonData := removeComments(string(jsoncFile)) var conf Conf - conf.LogLevel = log.InfoLevel + conf.LogLevel = zap.InfoLevel conf.P4rtcIface.DefaultTC = uint8(p4constants.EnumTrafficClassElastic) err = json.Unmarshal([]byte(jsonData), &conf) diff --git a/pfcpiface/config_test.go b/pfcpiface/config_test.go index 9f9e8d114..61c30aaa6 100644 --- a/pfcpiface/config_test.go +++ b/pfcpiface/config_test.go @@ -8,7 +8,7 @@ import ( "os" "testing" - log "github.com/sirupsen/logrus" + "go.uber.org/zap" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" @@ -78,7 +78,7 @@ func TestLoadConfigFile(t *testing.T) { conf, err := LoadConfigFile(confPath) require.NoError(t, err) - require.Equal(t, conf.LogLevel, log.InfoLevel) + require.Equal(t, conf.LogLevel, zap.InfoLevel) }) t.Run("all sample configs must be valid", func(t *testing.T) { diff --git a/pfcpiface/conn.go b/pfcpiface/conn.go index 83b8dd5cb..4153fe563 100644 --- a/pfcpiface/conn.go +++ b/pfcpiface/conn.go @@ -12,9 +12,9 @@ import ( "time" reuse "github.com/libp2p/go-reuseport" - log "github.com/sirupsen/logrus" "github.com/wmnsk/go-pfcp/ie" + "github.com/omec-project/upf-epc/logger" "github.com/omec-project/upf-epc/pfcpiface/metrics" ) @@ -79,23 +79,21 @@ func (pConn *PFCPConn) startHeartBeatMonitor() { hbCtx, hbCancel := context.WithCancel(pConn.ctx) pConn.hbCtxCancel = hbCancel - log.WithFields(log.Fields{ - "interval": pConn.upf.hbInterval, - }).Infoln("Starting Heartbeat timer") + logger.PfcpLog.With("interval", pConn.upf.hbInterval).Infoln("starting Heartbeat timer") heartBeatExpiryTimer := time.NewTicker(pConn.upf.hbInterval) for { select { case <-hbCtx.Done(): - log.Infoln("Cancel HeartBeat Timer", pConn.RemoteAddr().String()) + logger.PfcpLog.Infoln("cancel HeartBeat Timer", pConn.RemoteAddr().String()) heartBeatExpiryTimer.Stop() return case <-pConn.hbReset: heartBeatExpiryTimer.Reset(pConn.upf.hbInterval) case <-heartBeatExpiryTimer.C: - log.Traceln("HeartBeat Interval Timer Expired", pConn.RemoteAddr().String()) + logger.PfcpLog.Debugln("HeartBeat Interval Timer Expired", pConn.RemoteAddr().String()) r := pConn.getHeartBeatRequest() @@ -112,7 +110,7 @@ func (pConn *PFCPConn) startHeartBeatMonitor() { func (node *PFCPNode) NewPFCPConn(lAddr, rAddr string, buf []byte) *PFCPConn { conn, err := reuse.Dial("udp", lAddr, rAddr) if err != nil { - log.Errorln("dial socket failed", err) + logger.PfcpLog.Errorln("dial socket failed", err) } ts := recoveryTS{ @@ -120,7 +118,7 @@ func (node *PFCPNode) NewPFCPConn(lAddr, rAddr string, buf []byte) *PFCPConn { } // TODO: Get SEID range from PFCPNode for this PFCPConn - log.Infoln("Created PFCPConn from:", conn.LocalAddr(), "to:", conn.RemoteAddr()) + logger.PfcpLog.Infoln("created PFCPConn from:", conn.LocalAddr(), "to:", conn.RemoteAddr()) rng := rand.New(rand.NewSource(time.Now().UnixNano())) // #nosec G404 @@ -189,13 +187,13 @@ func (pConn *PFCPConn) Serve() { for { err := pConn.SetReadDeadline(time.Now().Add(pConn.upf.readTimeout)) if err != nil { - log.Errorf("failed to set read timeout: %v", err) + logger.PfcpLog.Errorf("failed to set read timeout: %v", err) } n, err := pConn.Read(recvBuf) if err != nil { if netErr, ok := err.(net.Error); ok && netErr.Timeout() { - log.Infof("Read timeout for connection %v<->%v, is the SMF still alive?", + logger.PfcpLog.Infof("read timeout for connection %v<->%v, is the SMF still alive?", pConn.LocalAddr(), pConn.RemoteAddr()) connTimeout <- struct{}{} @@ -251,11 +249,11 @@ func (pConn *PFCPConn) Shutdown() { err := pConn.Close() if err != nil { - log.Error("Failed to close PFCP connection..") + logger.PfcpLog.Errorln("failed to close PFCP connection") return } - log.Infoln("Shutdown complete for", rAddr) + logger.PfcpLog.Infoln("shutdown complete for", rAddr) } func (pConn *PFCPConn) getSeqNum() uint32 { diff --git a/pfcpiface/fteid.go b/pfcpiface/fteid.go new file mode 100644 index 000000000..8d8c49d44 --- /dev/null +++ b/pfcpiface/fteid.go @@ -0,0 +1,75 @@ +// SPDX-License-Identifier: Apache-2.0 +// Copyright 2024 Canonical Ltd. + +package pfcpiface + +import ( + "errors" + "math" + "sync" +) + +const ( + minValue = 1 + maxValue = math.MaxUint32 +) + +type FTEIDGenerator struct { + lock sync.Mutex + offset uint32 + usedMap map[uint32]bool +} + +func NewFTEIDGenerator() *FTEIDGenerator { + return &FTEIDGenerator{ + offset: 0, + usedMap: make(map[uint32]bool), + } +} + +// Allocate and return an id in range [minValue, maxValue] +func (idGenerator *FTEIDGenerator) Allocate() (uint32, error) { + idGenerator.lock.Lock() + defer idGenerator.lock.Unlock() + + offsetBegin := idGenerator.offset + for { + if _, ok := idGenerator.usedMap[idGenerator.offset]; ok { + idGenerator.updateOffset() + + if idGenerator.offset == offsetBegin { + return 0, errors.New("no available value range to allocate id") + } + } else { + break + } + } + idGenerator.usedMap[idGenerator.offset] = true + id := idGenerator.offset + minValue + idGenerator.updateOffset() + return id, nil +} + +func (idGenerator *FTEIDGenerator) FreeID(id uint32) { + if id < minValue { + return + } + idGenerator.lock.Lock() + defer idGenerator.lock.Unlock() + delete(idGenerator.usedMap, id-minValue) +} + +func (idGenerator *FTEIDGenerator) IsAllocated(id uint32) bool { + if id < minValue { + return false + } + idGenerator.lock.Lock() + defer idGenerator.lock.Unlock() + _, ok := idGenerator.usedMap[id-minValue] + return ok +} + +func (idGenerator *FTEIDGenerator) updateOffset() { + idGenerator.offset++ + idGenerator.offset = idGenerator.offset % maxValue +} diff --git a/pfcpiface/fteid_test.go b/pfcpiface/fteid_test.go new file mode 100644 index 000000000..d663948db --- /dev/null +++ b/pfcpiface/fteid_test.go @@ -0,0 +1,39 @@ +// SPDX-License-Identifier: Apache-2.0 +// Copyright 2024 Canonical Ltd. + +package pfcpiface_test + +import ( + "testing" + + "github.com/omec-project/upf-epc/pfcpiface" +) + +func TestFTEIDAllocate(t *testing.T) { + fteidGenerator := pfcpiface.NewFTEIDGenerator() + + fteid, err := fteidGenerator.Allocate() + if err != nil { + t.Errorf("FTEID allocation failed: %v", err) + } + if fteid < 1 { + t.Errorf("FTEID allocation failed, value is too small: %v", fteid) + } + if !fteidGenerator.IsAllocated(fteid) { + t.Errorf("FTEID was not allocated") + } +} + +func TestFTEIDFree(t *testing.T) { + fteidGenerator := pfcpiface.NewFTEIDGenerator() + fteid, err := fteidGenerator.Allocate() + if err != nil { + t.Errorf("FTEID allocation failed: %v", err) + } + + fteidGenerator.FreeID(fteid) + + if fteidGenerator.IsAllocated(fteid) { + t.Errorf("FTEID was not freed") + } +} diff --git a/pfcpiface/grpcsim.go b/pfcpiface/grpcsim.go index e6c52cedd..260d656d3 100644 --- a/pfcpiface/grpcsim.go +++ b/pfcpiface/grpcsim.go @@ -6,7 +6,7 @@ package pfcpiface import ( "time" - log "github.com/sirupsen/logrus" + "github.com/omec-project/upf-epc/logger" "github.com/wmnsk/go-pfcp/ie" ) @@ -69,7 +69,7 @@ func (s simMode) enable() bool { } func (u *upf) sim(mode simMode, s *SimModeInfo) { - log.Infoln(simulate.String(), "sessions:", s.MaxSessions) + logger.PfcpLog.Infoln(simulate.String(), "sessions:", s.MaxSessions) start := time.Now() ueip := s.StartUEIP @@ -268,9 +268,9 @@ func (u *upf) sim(mode simMode, s *SimModeInfo) { } else if mode.delete() { u.SendMsgToUPF(upfMsgTypeDel, allRules, PacketForwardingRules{}) } else { - log.Fatalln("Unsupported method", mode) + logger.PfcpLog.Fatalln("unsupported method", mode) } } - log.Infoln("Sessions/s:", float64(s.MaxSessions)/time.Since(start).Seconds()) + logger.PfcpLog.Infoln("sessions/s:", float64(s.MaxSessions)/time.Since(start).Seconds()) } diff --git a/pfcpiface/ip_pool.go b/pfcpiface/ip_pool.go index 639d19dee..c3c065a5f 100644 --- a/pfcpiface/ip_pool.go +++ b/pfcpiface/ip_pool.go @@ -9,7 +9,7 @@ import ( "strings" "sync" - log "github.com/sirupsen/logrus" + "github.com/omec-project/upf-epc/logger" ) type IPPool struct { @@ -54,7 +54,7 @@ func (i *IPPool) LookupOrAllocIP(seid uint64) (net.IP, error) { // Try to find an exiting session and return the allocated IP. ip, found := i.inventory[seid] if found { - log.Traceln("Found existing session", seid, "IP", ip) + logger.PfcpLog.Debugln("found existing session", seid, "IP", ip) return ip, nil } @@ -66,7 +66,7 @@ func (i *IPPool) LookupOrAllocIP(seid uint64) (net.IP, error) { ip = i.freePool[0] i.freePool = i.freePool[1:] // Slice off the element once it is dequeued. i.inventory[seid] = ip - log.Traceln("Allocated new session", seid, "IP", ip) + logger.PfcpLog.Debugln("allocated new session", seid, "IP", ip) ipVal := make(net.IP, len(ip)) copy(ipVal, ip) @@ -80,13 +80,13 @@ func (i *IPPool) DeallocIP(seid uint64) error { ip, ok := i.inventory[seid] if !ok { - log.Warnln("Attempt to dealloc non-existent session", seid) + logger.PfcpLog.Warnln("attempt to dealloc non-existent session", seid) return ErrInvalidArgumentWithReason("seid", seid, "can't dealloc non-existent session") } delete(i.inventory, seid) i.freePool = append(i.freePool, ip) // Simply append to enqueue. - log.Traceln("Deallocated session ", seid, "IP", ip) + logger.PfcpLog.Debugln("deallocated session", seid, "IP", ip) return nil } diff --git a/pfcpiface/local_store.go b/pfcpiface/local_store.go index 8bf78f29c..be9ab0f75 100644 --- a/pfcpiface/local_store.go +++ b/pfcpiface/local_store.go @@ -6,7 +6,7 @@ package pfcpiface import ( "sync" - log "github.com/sirupsen/logrus" + "github.com/omec-project/upf-epc/logger" ) type InMemoryStore struct { @@ -29,9 +29,7 @@ func (i *InMemoryStore) GetAllSessions() []PFCPSession { return true }) - log.WithFields(log.Fields{ - "sessions": sessions, - }).Trace("Got all PFCP sessions from local store") + logger.PfcpLog.With("sessions", sessions).Debugln("got all PFCP sessions from local store") return sessions } @@ -43,9 +41,7 @@ func (i *InMemoryStore) PutSession(session PFCPSession) error { i.sessions.Store(session.localSEID, session) - log.WithFields(log.Fields{ - "session": session, - }).Trace("Saved PFCP sessions to local store") + logger.PfcpLog.With("session", session).Debugln("saved PFCP sessions to local store") return nil } @@ -53,9 +49,7 @@ func (i *InMemoryStore) PutSession(session PFCPSession) error { func (i *InMemoryStore) DeleteSession(fseid uint64) error { i.sessions.Delete(fseid) - log.WithFields(log.Fields{ - "F-SEID": fseid, - }).Trace("PFCP session removed from local store") + logger.PfcpLog.With("F-SEID", fseid).Debugln("PFCP session removed from local store") return nil } @@ -66,7 +60,7 @@ func (i *InMemoryStore) DeleteAllSessions() bool { return true }) - log.Trace("All PFCP sessions removed from local store") + logger.P4Log.Debugln("all PFCP sessions removed from local store") return true } @@ -82,9 +76,7 @@ func (i *InMemoryStore) GetSession(fseid uint64) (PFCPSession, bool) { return PFCPSession{}, false } - log.WithFields(log.Fields{ - "session": session, - }).Trace("Got PFCP session from local store") + logger.PfcpLog.With("session", session).Debugln("Got PFCP session from local store") return session, ok } diff --git a/pfcpiface/messages.go b/pfcpiface/messages.go index 91f84e7d7..c526c9840 100644 --- a/pfcpiface/messages.go +++ b/pfcpiface/messages.go @@ -7,9 +7,9 @@ import ( "errors" "time" - log "github.com/sirupsen/logrus" "github.com/wmnsk/go-pfcp/message" + "github.com/omec-project/upf-epc/logger" "github.com/omec-project/upf-epc/pfcpiface/metrics" ) @@ -63,7 +63,7 @@ func (pConn *PFCPConn) HandlePFCPMsg(buf []byte) { msg, err := message.Parse(buf) if err != nil { - log.Errorln("Ignoring undecodable message: ", buf, " error: ", err) + logger.PfcpLog.Errorf("ignoring undecodable message: %v, error: %v", buf, err) return } @@ -104,7 +104,7 @@ func (pConn *PFCPConn) HandlePFCPMsg(buf []byte) { pConn.handleIncomingResponse(msg) default: - log.Errorln("Message type: ", msgType, " is currently not supported") + logger.PfcpLog.Errorf("message type: %s is not currently supported", msgType) return } @@ -112,10 +112,10 @@ func (pConn *PFCPConn) HandlePFCPMsg(buf []byte) { // Check for errors in handling the message if err != nil { m.Finish(nodeID, "Failure") - log.Errorln("Error handling PFCP message type", msgType, "from:", addr, "nodeID:", nodeID, err) + logger.PfcpLog.Errorf("error handling PFCP message type %s, from: %s, nodeID: %s, error: %v", msgType, addr, nodeID, err) } else { m.Finish(nodeID, "Success") - log.Traceln("Successfully processed", msgType, "from", addr, "nodeID:", nodeID) + logger.PfcpLog.Debugf("successfully processed %s, from %s, nodeID: %s", msgType, addr, nodeID) } pConn.SaveMessages(m) @@ -137,20 +137,20 @@ func (pConn *PFCPConn) SendPFCPMsg(msg message.Message) { if err := msg.MarshalTo(out); err != nil { m.Finish(nodeID, "Failure") - log.Errorln("Failed to marshal", msgType, "for", addr, err) + logger.PfcpLog.Errorf("failed to marshal %s for %s, error: %v", msgType, addr, err) return } if _, err := pConn.Write(out); err != nil { m.Finish(nodeID, "Failure") - log.Errorln("Failed to transmit", msgType, "to", addr, err) + logger.PfcpLog.Errorf("failed to transmit %v to %s, error %v", msgType, addr, err) return } m.Finish(nodeID, "Success") - log.Traceln("Sent", msgType, "to", addr) + logger.PfcpLog.Debugf("sent %v to %s", msgType, addr) } func (pConn *PFCPConn) sendPFCPRequestMessage(r *Request) (message.Message, bool) { @@ -161,7 +161,7 @@ func (pConn *PFCPConn) sendPFCPRequestMessage(r *Request) (message.Message, bool for { if reply, rc := r.GetResponse(pConn.shutdown, pConn.upf.respTimeout); rc { - log.Traceln("Request Timeout, retriesLeft:", retriesLeft) + logger.PfcpLog.Debugln("request timeout, retries left:", retriesLeft) if retriesLeft > 0 { pConn.SendPFCPMsg(r.msg) diff --git a/pfcpiface/messages_conn.go b/pfcpiface/messages_conn.go index 02f8d46d9..ebed1366f 100644 --- a/pfcpiface/messages_conn.go +++ b/pfcpiface/messages_conn.go @@ -6,7 +6,7 @@ package pfcpiface import ( "errors" - log "github.com/sirupsen/logrus" + "github.com/omec-project/upf-epc/logger" "github.com/wmnsk/go-pfcp/ie" "github.com/wmnsk/go-pfcp/message" ) @@ -27,7 +27,7 @@ func (pConn *PFCPConn) sendAssociationRequest() { if reply != nil { err := pConn.handleAssociationSetupResponse(reply) if err != nil { - log.Errorln("Handling of Assoc Setup Response Failed ", pConn.RemoteAddr()) + logger.PfcpLog.Errorln("handling of Assoc Setup Response Failed", pConn.RemoteAddr()) pConn.Shutdown() return @@ -67,7 +67,7 @@ func (pConn *PFCPConn) handleHeartbeatRequest(msg message.Message) (message.Mess // timer reset default: // channel full, log warning and ignore - log.Warn("failed to reset heartbeat timer") + logger.PfcpLog.Warnln("failed to reset heartbeat timer") } } @@ -96,7 +96,7 @@ func (pConn *PFCPConn) associationIEs() []*ie.IE { flags := uint8(0x41) if len(upf.dnn) != 0 { - log.Infoln("Association Setup with DNN:", upf.dnn) + logger.PfcpLog.Infoln("association Setup with DNN:", upf.dnn) // add ASSONI flag to set network instance. flags = uint8(0x61) } @@ -107,6 +107,8 @@ func (pConn *PFCPConn) associationIEs() []*ie.IE { setUeipFeature(features...) } + setFTUPFeature(features...) + if upf.enableEndMarker { setEndMarkerFeature(features...) } @@ -154,19 +156,19 @@ func (pConn *PFCPConn) handleAssociationSetupRequest(msg message.Message) (messa if pConn.ts.remote.IsZero() { pConn.ts.remote = ts - log.Infoln("Association Setup Request from", addr, + logger.PfcpLog.Infoln("association Setup Request from", addr, "with recovery timestamp:", ts) } else if ts.After(pConn.ts.remote) { old := pConn.ts.remote pConn.ts.remote = ts - log.Warnln("Association Setup Request from", addr, + logger.PfcpLog.Warnln("association Setup Request from", addr, "with newer recovery timestamp:", ts, "older:", old) } pConn.nodeID.remote = nodeID asres.Cause = ie.NewCause(ie.CauseRequestAccepted) - log.Infoln("Association setup done between nodes", + logger.PfcpLog.Infoln("association setup done between nodes", "local:", pConn.nodeID.local, "remote:", pConn.nodeID.remote) return asres, nil @@ -186,7 +188,7 @@ func (pConn *PFCPConn) handleAssociationSetupResponse(msg message.Message) error } if cause != ie.CauseRequestAccepted { - log.Errorln("Association Setup Response from", addr, + logger.PfcpLog.Errorln("association Setup Response from", addr, "with Cause:", cause) return errReqRejected } @@ -203,17 +205,17 @@ func (pConn *PFCPConn) handleAssociationSetupResponse(msg message.Message) error if pConn.ts.remote.IsZero() { pConn.ts.remote = ts - log.Infoln("Association Setup Response from", addr, + logger.PfcpLog.Infoln("association Setup Response from", addr, "with recovery timestamp:", ts) } else if ts.After(pConn.ts.remote) { old := pConn.ts.remote pConn.ts.remote = ts - log.Warnln("Association Setup Response from", addr, + logger.PfcpLog.Warnln("association Setup Response from", addr, "with newer recovery timestamp:", ts, "older:", old) } pConn.nodeID.remote = nodeID - log.Infoln("Association setup done between nodes", + logger.PfcpLog.Infoln("association setup done between nodes", "local:", pConn.nodeID.local, "remote:", pConn.nodeID.remote) return nil @@ -289,7 +291,7 @@ func (pConn *PFCPConn) handlePFDMgmtRequest(msg message.Message) (message.Messag } pConn.appPFDs[id] = applicationPFD - log.Traceln("Flow descriptions for AppID", id, ":", applicationPFD.flowDescs) + logger.PfcpLog.Debugf("flow descriptions for AppID %v: %v", id, applicationPFD.flowDescs) } // Build response message diff --git a/pfcpiface/messages_session.go b/pfcpiface/messages_session.go index 79ecba38d..f5344f15f 100644 --- a/pfcpiface/messages_session.go +++ b/pfcpiface/messages_session.go @@ -8,7 +8,7 @@ import ( "net" "strings" - log "github.com/sirupsen/logrus" + "github.com/omec-project/upf-epc/logger" "github.com/wmnsk/go-pfcp/ie" "github.com/wmnsk/go-pfcp/message" ) @@ -71,8 +71,8 @@ func (pConn *PFCPConn) handleSessionEstablishmentRequest(msg message.Message) (m } if strings.Compare(nodeID, pConn.nodeID.remote) != 0 { - log.Warnln("Association not found for Establishment request", - "with nodeID: ", nodeID, ", Association NodeID: ", pConn.nodeID.remote) + logger.PfcpLog.Warnln("association not found for Establishment request", + "with nodeID:", nodeID, ", association NodeID:", pConn.nodeID.remote) return errProcessReply(ErrAssocNotFound, ie.CauseNoEstablishedPFCPAssociation) } @@ -92,6 +92,18 @@ func (pConn *PFCPConn) handleSessionEstablishmentRequest(msg message.Message) (m return errProcessReply(err, ie.CauseRequestRejected) } + if p.UPAllocateFteid { + var fteid uint32 + fteid, err = pConn.upf.fteidGenerator.Allocate() + if err != nil { + return errProcessReply(err, ie.CauseNoResourcesAvailable) + } + p.tunnelTEID = fteid + p.tunnelTEIDMask = 0xFFFFFFFF + p.tunnelIP4Dst = ip2int(upf.accessIP) + p.tunnelIP4DstMask = 0xFFFFFFFF + } + p.fseidIP = fseidIP session.CreatePDR(p) addPDRs = append(addPDRs, p) @@ -142,7 +154,7 @@ func (pConn *PFCPConn) handleSessionEstablishmentRequest(msg message.Message) (m err = pConn.store.PutSession(session) if err != nil { - log.Errorf("Failed to put PFCP session to store: %v", err) + logger.PfcpLog.Errorf("failed to put PFCP session to store: %v", err) } var localFSEID *ie.IE @@ -164,8 +176,7 @@ func (pConn *PFCPConn) handleSessionEstablishmentRequest(msg message.Message) (m ie.NewCause(ie.CauseRequestAccepted), /* accept it blindly for the time being */ localFSEID, ) - - addPdrInfo(seres, &session) + addPdrInfo(seres, addPDRs) return seres, nil } @@ -181,7 +192,7 @@ func (pConn *PFCPConn) handleSessionModificationRequest(msg message.Message) (me var remoteSEID uint64 sendError := func(err error) (message.Message, error) { - log.Errorln(err) + logger.PfcpLog.Errorln(err) smres := message.NewSessionModificationResponse(0, /* MO?? <-- what's this */ 0, /* FO <-- what's this? */ @@ -209,7 +220,7 @@ func (pConn *PFCPConn) handleSessionModificationRequest(msg message.Message) (me session.remoteSEID = fseid.SEID fseidIP = ip2int(fseid.IPv4Address) - log.Traceln("Updated FSEID from session modification request") + logger.PfcpLog.Debugln("updated FSEID from session modification request") } } @@ -231,6 +242,7 @@ func (pConn *PFCPConn) handleSessionModificationRequest(msg message.Message) (me session.CreatePDR(p) addPDRs = append(addPDRs, p) } + logger.PfcpLog.Debugln("PDRs added:", addPDRs) for _, cFAR := range smreq.CreateFAR { var f far @@ -270,7 +282,7 @@ func (pConn *PFCPConn) handleSessionModificationRequest(msg message.Message) (me err = session.UpdatePDR(p) if err != nil { - log.Errorln("session PDR update failed ", err) + logger.PfcpLog.Errorln("session PDR update failed", err) continue } @@ -291,7 +303,7 @@ func (pConn *PFCPConn) handleSessionModificationRequest(msg message.Message) (me err = session.UpdateFAR(&f, &endMarkerList) if err != nil { - log.Errorln("session PDR update failed ", err) + logger.PfcpLog.Errorln("session PDR update failed", err) continue } @@ -312,7 +324,7 @@ func (pConn *PFCPConn) handleSessionModificationRequest(msg message.Message) (me err = session.UpdateQER(q) if err != nil { - log.Errorln("session QER update failed ", err) + logger.PfcpLog.Errorln("session QER update failed", err) continue } @@ -339,7 +351,7 @@ func (pConn *PFCPConn) handleSessionModificationRequest(msg message.Message) (me if upf.enableEndMarker { err := upf.SendEndMarkers(&endMarkerList) if err != nil { - log.Errorln("Sending End Markers Failed : ", err) + logger.PfcpLog.Errorln("sending End Markers Failed:", err) } } @@ -402,7 +414,7 @@ func (pConn *PFCPConn) handleSessionModificationRequest(msg message.Message) (me err := pConn.store.PutSession(session) if err != nil { - log.Errorf("Failed to put PFCP session to store: %v", err) + logger.PfcpLog.Errorf("failed to put PFCP session to store: %v", err) } // Build response message @@ -472,7 +484,7 @@ func (pConn *PFCPConn) handleSessionDeletionRequest(msg message.Message) (messag func (pConn *PFCPConn) handleDigestReport(fseid uint64) { session, ok := pConn.store.GetSession(fseid) if !ok { - log.Warnln("No session found for fseid : ", fseid) + logger.PfcpLog.Warnln("no session found for fseid:", fseid) return } @@ -503,14 +515,14 @@ func (pConn *PFCPConn) handleDigestReport(fseid uint64) { for _, far := range session.fars { if far.farID == farID { if far.applyAction&ActionNotify == 0 { - log.Errorln("packet received for forwarding far. discard") + logger.PfcpLog.Errorln("packet received for forwarding far. discard") return } } } if pdrID == 0 { - log.Errorln("No Pdr found for downlink") + logger.PfcpLog.Errorln("no Pdr found for downlink") return } @@ -518,10 +530,7 @@ func (pConn *PFCPConn) handleDigestReport(fseid uint64) { srreq.DownlinkDataReport = ie.NewDownlinkDataReport( ie.NewPDRID(uint16(pdrID))) - log.WithFields(log.Fields{ - "F-SEID": fseid, - "PDR ID": pdrID, - }).Debug("Sending Downlink Data Report") + logger.PfcpLog.With("F-SEID", fseid, "PDR ID", pdrID).Debugln("sending Downlink Data Report") pConn.SendPFCPMsg(srreq) } @@ -539,7 +548,7 @@ func (pConn *PFCPConn) handleSessionReportResponse(msg message.Message) error { return nil } - log.Warnln("session req not accepted seq : ", srres.SequenceNumber) + logger.PfcpLog.Warnln("session req not accepted seq:", srres.SequenceNumber) seid := srres.SEID() @@ -549,7 +558,7 @@ func (pConn *PFCPConn) handleSessionReportResponse(msg message.Message) error { return errProcess(ErrNotFoundWithParam("PFCP session context", "SEID", seid)) } - log.Warnln("context not found, deleting session locally") + logger.PfcpLog.Warnln("context not found, deleting session locally") pConn.RemoveSession(sessItem) diff --git a/pfcpiface/node.go b/pfcpiface/node.go index 75f522ea3..11a2b6ade 100644 --- a/pfcpiface/node.go +++ b/pfcpiface/node.go @@ -10,8 +10,8 @@ import ( "sync" reuse "github.com/libp2p/go-reuseport" - log "github.com/sirupsen/logrus" + "github.com/omec-project/upf-epc/logger" "github.com/omec-project/upf-epc/pfcpiface/metrics" ) @@ -35,14 +35,15 @@ type PFCPNode struct { // NewPFCPNode create a new PFCPNode listening on local address. func NewPFCPNode(upf *upf) *PFCPNode { - conn, err := reuse.ListenPacket("udp", ":"+PFCPPort) + conn, err := reuse.ListenPacket("udp", + upf.n4addr+":"+PFCPPort) if err != nil { - log.Fatalln("ListenUDP failed", err) + logger.PfcpLog.Fatalln("listen UDP failed", err) } metrics, err := metrics.NewPrometheusService() if err != nil { - log.Fatalln("prom metrics service init failed", err) + logger.PfcpLog.Fatalln("prom metrics service init failed", err) } ctx, cancel := context.WithCancel(context.Background()) @@ -62,17 +63,14 @@ func (node *PFCPNode) tryConnectToN4Peers(lAddrStr string) { for _, peer := range node.upf.peers { conn, err := net.Dial("udp", peer+":"+PFCPPort) if err != nil { - log.Warnln("Failed to establish PFCP connection to peer ", peer) + logger.PfcpLog.Warnln("failed to establish PFCP connection to peer", peer) continue } remoteAddr := conn.RemoteAddr().(*net.UDPAddr) n4DstIP := remoteAddr.IP - log.WithFields(log.Fields{ - "SPGWC/SMF host": peer, - "CP node": n4DstIP.String(), - }).Info("Establishing PFCP Conn with CP node") + logger.PfcpLog.Infof("Establishing PFCP Conn with CP node. SPGWC/SMF host: %s, CP node: %s", peer, n4DstIP.String()) pfcpConn := node.NewPFCPConn(lAddrStr, n4DstIP.String()+":"+PFCPPort, nil) if pfcpConn != nil { @@ -83,7 +81,7 @@ func (node *PFCPNode) tryConnectToN4Peers(lAddrStr string) { func (node *PFCPNode) handleNewPeers() { lAddrStr := node.LocalAddr().String() - log.Infoln("listening for new PFCP connections on", lAddrStr) + logger.PfcpLog.Infoln("listening for new PFCP connections on", lAddrStr) node.tryConnectToN4Peers(lAddrStr) @@ -103,7 +101,7 @@ func (node *PFCPNode) handleNewPeers() { _, ok := node.pConns.Load(rAddrStr) if ok { - log.Warnln("Drop packet for existing PFCPconn received from", rAddrStr) + logger.PfcpLog.Warnln("drop packet for existing PFCPconn received from", rAddrStr) continue } @@ -128,15 +126,15 @@ func (node *PFCPNode) Serve() { }) case rAddr := <-node.pConnDone: node.pConns.Delete(rAddr) - log.Infoln("Removed connection to", rAddr) + logger.PfcpLog.Infoln("removed connection to", rAddr) case <-node.ctx.Done(): shutdown = true - log.Infoln("Shutting down PFCP node") + logger.PfcpLog.Infoln("shutting down PFCP node") err := node.Close() if err != nil { - log.Errorln("Error closing PFCPNode conn", err) + logger.PfcpLog.Errorln("error closing PFCPNode conn", err) } // Clear out the remaining pconn completions @@ -150,7 +148,7 @@ func (node *PFCPNode) Serve() { break clearLoop } node.pConns.Delete(rAddr) - log.Infoln("Removed connection to", rAddr) + logger.PfcpLog.Infoln("removed connection to", rAddr) } default: // nothing to read from channel @@ -161,12 +159,12 @@ func (node *PFCPNode) Serve() { if len(node.pConnDone) > 0 { for rAddr := range node.pConnDone { node.pConns.Delete(rAddr) - log.Infoln("Removed connection to", rAddr) + logger.PfcpLog.Infoln("removed connection to", rAddr) } } close(node.pConnDone) - log.Infoln("Done waiting for PFCPConn completions") + logger.PfcpLog.Infoln("done waiting for PFCPConn completions") node.upf.Exit() } @@ -180,12 +178,12 @@ func (node *PFCPNode) Stop() { if err := node.metrics.Stop(); err != nil { // TODO: propagate error upwards - log.Errorln(err) + logger.PfcpLog.Errorln(err) } } // Done waits for Shutdown() to complete func (node *PFCPNode) Done() { <-node.done - log.Infoln("Shutdown complete") + logger.PfcpLog.Infoln("shutdown complete") } diff --git a/pfcpiface/p4rt_translator.go b/pfcpiface/p4rt_translator.go index 2bf33ed36..2b4f35d13 100644 --- a/pfcpiface/p4rt_translator.go +++ b/pfcpiface/p4rt_translator.go @@ -11,9 +11,9 @@ import ( "net" "github.com/omec-project/upf-epc/internal/p4constants" + "github.com/omec-project/upf-epc/logger" p4ConfigV1 "github.com/p4lang/p4runtime/go/p4/config/v1" p4 "github.com/p4lang/p4runtime/go/p4/v1" - log "github.com/sirupsen/logrus" "github.com/wmnsk/go-pfcp/ie" ) @@ -105,7 +105,7 @@ func convertValueToBinary(value interface{}) ([]byte, error) { return b, nil default: - log.Debugf("Type %T", t) + logger.P4Log.Debugf("type %T", t) return nil, ErrOperationFailedWithParam("convert type to byte array", "type", t) } } @@ -217,11 +217,8 @@ func (t *P4rtTranslator) withExactMatchField(entry *p4.TableEntry, name string, } func (t *P4rtTranslator) withLPMField(entry *p4.TableEntry, name string, value uint32, prefixLen uint8) error { - lpmFieldLog := log.WithFields(log.Fields{ - "entry": entry.String(), - "field name": name, - }) - lpmFieldLog.Trace("Adding LPM match field to the entry") + lpmFieldLog := logger.P4Log.With("entry", entry.String(), "field name", name) + lpmFieldLog.Debugln("adding LPM match field to the entry") if entry.TableId == 0 { return ErrInvalidArgumentWithReason("entry.TableId", entry.TableId, "no table ID for entry defined, set table ID before adding match fields") @@ -259,11 +256,8 @@ func (t *P4rtTranslator) withLPMField(entry *p4.TableEntry, name string, value u } func (t *P4rtTranslator) withRangeMatchField(entry *p4.TableEntry, name string, low interface{}, high interface{}) error { - rangeFieldLog := log.WithFields(log.Fields{ - "entry": entry.String(), - "field name": name, - }) - rangeFieldLog.Trace("Adding range match field to the entry") + rangeFieldLog := logger.P4Log.With("entry", entry.String(), "field name", name) + rangeFieldLog.Debugln("adding range match field to the entry") if entry.TableId == 0 { return ErrInvalidArgumentWithReason("entry.TableId", entry.TableId, "no table ID for entry defined, set table ID before adding match fields") @@ -306,11 +300,8 @@ func (t *P4rtTranslator) withRangeMatchField(entry *p4.TableEntry, name string, } func (t *P4rtTranslator) withTernaryMatchField(entry *p4.TableEntry, name string, value interface{}, mask interface{}) error { - ternaryFieldLog := log.WithFields(log.Fields{ - "entry": entry.String(), - "field name": name, - }) - ternaryFieldLog.Trace("Adding ternary match field to the entry") + ternaryFieldLog := logger.P4Log.With("entry", entry.String(), "field name", name) + ternaryFieldLog.Debugln("adding ternary match field to the entry") if entry.TableId == 0 { return ErrInvalidArgumentWithReason("entry.TableId", entry.TableId, "no table name for entry defined, set table name before adding match fields") @@ -327,7 +318,7 @@ func (t *P4rtTranslator) withTernaryMatchField(entry *p4.TableEntry, name string } if len(byteVal) != len(byteMask) { - ternaryFieldLog.Trace("value and mask length mismatch") + ternaryFieldLog.Debugln("value and mask length mismatch") return ErrOperationFailedWithParam("value and mask length mismatch for ternary field", "field", name) } @@ -483,10 +474,8 @@ func (t *P4rtTranslator) BuildInterfaceTableEntry(ipNet *net.IPNet, sliceID uint } func (t *P4rtTranslator) BuildApplicationsTableEntry(pdr pdr, sliceID uint8, internalAppID uint8) (*p4.TableEntry, error) { - applicationsBuilderLog := log.WithFields(log.Fields{ - "pdr": pdr, - }) - applicationsBuilderLog.Trace("Building P4rt table entry for applications table") + applicationsBuilderLog := logger.P4Log.With("pdr", pdr) + applicationsBuilderLog.Debugln("building P4rt table entry for applications table") entry := &p4.TableEntry{ TableId: p4constants.TablePreQosPipeApplications, @@ -544,18 +533,15 @@ func (t *P4rtTranslator) BuildApplicationsTableEntry(pdr pdr, sliceID uint8, int Type: &p4.TableAction_Action{Action: action}, } - applicationsBuilderLog = applicationsBuilderLog.WithField("entry", entry) - applicationsBuilderLog.Trace("Built P4rt table entry for applications table") + applicationsBuilderLog = applicationsBuilderLog.With("entry", entry) + applicationsBuilderLog.Debugln("built P4rt table entry for applications table") return entry, nil } func (t *P4rtTranslator) buildUplinkSessionsEntry(pdr pdr, sessMeterIdx uint32) (*p4.TableEntry, error) { - uplinkBuilderLog := log.WithFields(log.Fields{ - "pdr": pdr, - "sessionMeterIndex": sessMeterIdx, - }) - uplinkBuilderLog.Trace("Building P4rt table entry for sessions_uplink table") + uplinkBuilderLog := logger.P4Log.With("pdr", pdr, "sessionMeterIndex", sessMeterIdx) + uplinkBuilderLog.Debugln("building P4rt table entry for sessions_uplink table") entry := &p4.TableEntry{ TableId: p4constants.TablePreQosPipeSessionsUplink, @@ -582,19 +568,14 @@ func (t *P4rtTranslator) buildUplinkSessionsEntry(pdr pdr, sessMeterIdx uint32) Type: &p4.TableAction_Action{Action: action}, } - uplinkBuilderLog.WithField("entry", entry).Trace("Built P4rt table entry for sessions_uplink table") + uplinkBuilderLog.With("entry", entry).Debugln("built P4rt table entry for sessions_uplink table") return entry, nil } func (t *P4rtTranslator) buildDownlinkSessionsEntry(pdr pdr, sessMeterIdx uint32, tunnelPeerID uint8, needsBuffering bool) (*p4.TableEntry, error) { - builderLog := log.WithFields(log.Fields{ - "pdr": pdr, - "sessionMeterIndex": sessMeterIdx, - "tunnelPeerID": tunnelPeerID, - "needsBuffering": needsBuffering, - }) - builderLog.Trace("Building P4rt table entry for sessions_downlink table") + builderLog := logger.P4Log.With("pdr", pdr, "sessionMeterIndex", sessMeterIdx, "tunnelPeerID", tunnelPeerID, "needsBuffering", needsBuffering) + builderLog.Debugln("building P4rt table entry for sessions_downlink table") entry := &p4.TableEntry{ TableId: p4constants.TablePreQosPipeSessionsDownlink, @@ -627,7 +608,7 @@ func (t *P4rtTranslator) buildDownlinkSessionsEntry(pdr pdr, sessMeterIdx uint32 Type: &p4.TableAction_Action{Action: action}, } - builderLog.WithField("entry", entry).Trace("Built P4rt table entry for sessions_downlink table") + builderLog.With("entry", entry).Debugln("built P4rt table entry for sessions_downlink table") return entry, nil } @@ -644,12 +625,8 @@ func (t *P4rtTranslator) BuildSessionsTableEntry(pdr pdr, sessionMeter meter, tu } func (t *P4rtTranslator) buildUplinkTerminationsEntry(pdr pdr, appMeterIdx uint32, shouldDrop bool, internalAppID uint8, tc uint8, relatedQER qer) (*p4.TableEntry, error) { - builderLog := log.WithFields(log.Fields{ - "pdr": pdr, - "appMeterIndex": appMeterIdx, - "tc": tc, - }) - builderLog.Debug("Building P4rt table entry for UP4 terminations_uplink table") + builderLog := logger.P4Log.With("pdr", pdr, "appMeterIndex", appMeterIdx, "tc", tc) + builderLog.Debugln("building P4rt table entry for UP4 terminations_uplink table") entry := &p4.TableEntry{ TableId: p4constants.TablePreQosPipeTerminationsUplink, @@ -695,20 +672,15 @@ func (t *P4rtTranslator) buildUplinkTerminationsEntry(pdr pdr, appMeterIdx uint3 Type: &p4.TableAction_Action{Action: action}, } - builderLog.WithField("entry", entry).Debug("Built P4rt table entry for terminations_uplink table") + builderLog.With("entry", entry).Debugln("built P4rt table entry for terminations_uplink table") return entry, nil } func (t *P4rtTranslator) buildDownlinkTerminationsEntry(pdr pdr, appMeterIdx uint32, relatedFAR far, internalAppID uint8, qfi uint8, tc uint8, relatedQER qer) (*p4.TableEntry, error) { - builderLog := log.WithFields(log.Fields{ - "pdr": pdr, - "appMeterIndex": appMeterIdx, - "tc": tc, - "related-far": relatedFAR, - }) - builderLog.Debug("Building P4rt table entry for UP4 terminations_downlink table") + builderLog := logger.P4Log.With("pdr", pdr, "appMeterIndex", appMeterIdx, "tc", tc, "related-far", relatedFAR) + builderLog.Debugln("building P4rt table entry for UP4 terminations_downlink table") entry := &p4.TableEntry{ TableId: p4constants.TablePreQosPipeTerminationsDownlink, @@ -763,7 +735,7 @@ func (t *P4rtTranslator) buildDownlinkTerminationsEntry(pdr pdr, appMeterIdx uin Type: &p4.TableAction_Action{Action: action}, } - builderLog.WithField("entry", entry).Debug("Built P4rt table entry for terminations_downlink table") + builderLog.With("entry", entry).Debugln("built P4rt table entry for terminations_downlink table") return entry, nil } @@ -780,11 +752,8 @@ func (t *P4rtTranslator) BuildTerminationsTableEntry(pdr pdr, appMeter meter, re } func (t *P4rtTranslator) BuildGTPTunnelPeerTableEntry(tunnelPeerID uint8, tunnelParams tunnelParams) (*p4.TableEntry, error) { - builderLog := log.WithFields(log.Fields{ - "tunnelPeerID": tunnelPeerID, - "tunnel-params": tunnelParams, - }) - builderLog.Trace("Building P4rt table entry for GTP Tunnel Peers table") + builderLog := logger.P4Log.With("tunnelPeerID", tunnelPeerID, "tunnel-params", tunnelParams) + builderLog.Debugln("building P4rt table entry for GTP Tunnel Peers table") entry := &p4.TableEntry{ TableId: p4constants.TablePreQosPipeTunnelPeers, @@ -814,7 +783,7 @@ func (t *P4rtTranslator) BuildGTPTunnelPeerTableEntry(tunnelPeerID uint8, tunnel return nil, err } - builderLog.WithField("entry", entry).Debug("Built P4rt table entry for GTP Tunnel Peers table") + builderLog.With("entry", entry).Debugln("built P4rt table entry for GTP Tunnel Peers table") return entry, nil } @@ -822,11 +791,8 @@ func (t *P4rtTranslator) BuildGTPTunnelPeerTableEntry(tunnelPeerID uint8, tunnel func (t *P4rtTranslator) BuildMeterEntry(meterID uint32, cellID uint32, config *p4.MeterConfig) *p4.MeterEntry { meterName := p4constants.GetMeterIDToNameMap()[meterID] - builderLog := log.WithFields(log.Fields{ - "Meter": meterName, - "Cell ID": cellID, - }) - builderLog.Trace("Building Meter entry") + builderLog := logger.P4Log.With("Meter", meterName, "Cell ID", cellID) + builderLog.Debugln("building Meter entry") entry := &p4.MeterEntry{ MeterId: meterID, @@ -834,8 +800,8 @@ func (t *P4rtTranslator) BuildMeterEntry(meterID uint32, cellID uint32, config * Config: config, } - builderLog = builderLog.WithField("meter-entry", entry) - builderLog.Debug("Meter entry built successfully") + builderLog = builderLog.With("meter-entry", entry) + builderLog.Debugln("meter entry built successfully") return entry } diff --git a/pfcpiface/p4rtc.go b/pfcpiface/p4rtc.go index 4cb9e8622..1112adb87 100644 --- a/pfcpiface/p4rtc.go +++ b/pfcpiface/p4rtc.go @@ -21,9 +21,9 @@ import ( // as also P4Runtime stubs are based on the deprecated proto. "github.com/golang/protobuf/proto" grpcRetry "github.com/grpc-ecosystem/go-grpc-middleware/retry" + "github.com/omec-project/upf-epc/logger" p4ConfigV1 "github.com/p4lang/p4runtime/go/p4/config/v1" p4 "github.com/p4lang/p4runtime/go/p4/v1" - log "github.com/sirupsen/logrus" "google.golang.org/genproto/googleapis/rpc/code" "google.golang.org/grpc" ) @@ -158,7 +158,7 @@ func (c *P4rtClient) Init() (err error) { grpcRetry.WithMax(3), grpcRetry.WithPerRetryTimeout(1*time.Second)) if err != nil { - log.Println("stream channel error: ", err) + logger.P4Log.Errorln("stream channel error:", err) return } @@ -166,23 +166,23 @@ func (c *P4rtClient) Init() (err error) { for { res, err := c.stream.Recv() if err != nil { - log.Println("stream recv error: ", err) + logger.P4Log.Errorln("stream recv error:", err) return } else if arb := res.GetArbitration(); arb != nil { if code.Code(arb.Status.Code) == code.Code_OK { - log.Println("client is master") + logger.P4Log.Infoln("client is master") } else { - log.Println("client is not master") + logger.P4Log.Infoln("client is not master") } } else if dig := res.GetDigest(); dig != nil { c.digests <- dig } else { - log.Println("stream recv: ", res) + logger.P4Log.Infoln("stream recv:", res) } } }() - log.Println("exited from recv thread.") + logger.P4Log.Infoln("exited from recv thread") return } @@ -193,13 +193,7 @@ func (c *P4rtClient) GetNextDigestData() []byte { for _, p4d := range nextDigest.GetData() { if bitstring := p4d.GetBitstring(); bitstring != nil { - log.WithFields(log.Fields{ - "device-id": c.deviceID, - "conn": c.conn.Target(), - "digest length": len(bitstring), - "data": bitstring, - }).Trace("Received Digest") - + logger.P4Log.With("device-id", c.deviceID, "conn", c.conn.Target(), "digest length", len(bitstring), "data", bitstring).Debugln("received digest") return bitstring } } @@ -209,25 +203,25 @@ func (c *P4rtClient) GetNextDigestData() []byte { // ReadCounterEntry .. Read counter Entry. func (c *P4rtClient) ReadCounterEntry(entry *p4.CounterEntry) (*p4.ReadResponse, error) { - log.Traceln("Read Counter Entry ", entry.CounterId) + logger.P4Log.Debugln("read counter entry", entry.CounterId) entity := &p4.Entity{ Entity: &p4.Entity_CounterEntry{CounterEntry: entry}, } - log.Traceln(proto.MarshalTextString(entity)) + logger.P4Log.Debugln(proto.MarshalTextString(entity)) return c.ReadReq(entity) } // ReadTableEntry ... Read table Entry. func (c *P4rtClient) ReadTableEntry(entry *p4.TableEntry) (*p4.ReadResponse, error) { - log.Println("Read Table Entry for Table ", entry.TableId) + logger.P4Log.Infoln("read Table Entry for Table", entry.TableId) entity := &p4.Entity{ Entity: &p4.Entity_TableEntry{TableEntry: entry}, } - log.Traceln(proto.MarshalTextString(entity)) + logger.P4Log.Debugln(proto.MarshalTextString(entity)) return c.ReadReq(entity) } @@ -239,13 +233,13 @@ func (c *P4rtClient) ReadReqEntities(entities []*p4.Entity) (*p4.ReadResponse, e DeviceId: c.deviceID, Entities: entities, } - log.Traceln(proto.MarshalTextString(req)) + logger.P4Log.Debugln(proto.MarshalTextString(req)) readClient, err := c.client.Read(context.Background(), req) if err == nil { readRes, err = readClient.Recv() if err == nil { - log.Traceln(proto.MarshalTextString(readRes)) + logger.P4Log.Debugln(proto.MarshalTextString(readRes)) return readRes, nil } } @@ -264,13 +258,13 @@ func (c *P4rtClient) ReadReq(entity *p4.Entity) (*p4.ReadResponse, error) { 2*time.Second) defer cancel() - log.Traceln(proto.MarshalTextString(&req)) + logger.P4Log.Debugln(proto.MarshalTextString(&req)) readClient, err := c.client.Read(ctx, &req) if err == nil { readRes, err = readClient.Recv() if err == nil { - log.Traceln(proto.MarshalTextString(readRes)) + logger.P4Log.Debugln(proto.MarshalTextString(readRes)) return readRes, nil } } @@ -279,7 +273,7 @@ func (c *P4rtClient) ReadReq(entity *p4.Entity) (*p4.ReadResponse, error) { } func (c *P4rtClient) ClearTable(tableID uint32) error { - log.Traceln("Clearing P4 table: ", tableID) + logger.P4Log.Debugln("clearing P4 table:", tableID) entry := &p4.TableEntry{ TableId: tableID, @@ -306,9 +300,7 @@ func (c *P4rtClient) ClearTable(tableID uint32) error { } func (c *P4rtClient) ClearTables(tableIDs []uint32) error { - log.WithFields(log.Fields{ - "table IDs": tableIDs, - }).Traceln("Clearing P4 tables") + logger.P4Log.With("table IDs", tableIDs).Debugln("clearing P4 tables") updates := []*p4.Update{} @@ -339,7 +331,7 @@ func (c *P4rtClient) ClearTables(tableIDs []uint32) error { // InsertTableEntry .. Insert table Entry. func (c *P4rtClient) InsertTableEntry(entry *p4.TableEntry, funcType uint8) error { - log.Println("Insert Table Entry for Table ", entry.TableId) + logger.P4Log.Infoln("insert Table Entry for Table", entry.TableId) var updateType p4.Update_Type if funcType == FunctionTypeUpdate { @@ -357,7 +349,7 @@ func (c *P4rtClient) InsertTableEntry(entry *p4.TableEntry, funcType uint8) erro }, } - log.Traceln(proto.MarshalTextString(update)) + logger.P4Log.Debugln(proto.MarshalTextString(update)) return c.WriteReq(update) } @@ -372,7 +364,7 @@ func (c *P4rtClient) ApplyTableEntries(methodType p4.Update_Type, entries ...*p4 Entity: &p4.Entity_TableEntry{TableEntry: entry}, }, } - log.Traceln("Writing table entry: ", proto.MarshalTextString(update)) + logger.P4Log.Debugln("writing table entry:", proto.MarshalTextString(update)) updates = append(updates, update) } @@ -390,7 +382,7 @@ func (c *P4rtClient) ApplyMeterEntries(methodType p4.Update_Type, entries ...*p4 Entity: &p4.Entity_MeterEntry{MeterEntry: entry}, }, } - log.Traceln("Writing meter entry: ", proto.MarshalTextString(update)) + logger.P4Log.Debugln("writing meter entry:", proto.MarshalTextString(update)) updates = append(updates, update) } @@ -419,7 +411,7 @@ func (c *P4rtClient) WriteBatchReq(updates []*p4.Update) error { req.Updates = append(req.Updates, updates...) - log.Traceln(proto.MarshalTextString(req)) + logger.P4Log.Debugln(proto.MarshalTextString(req)) _, err := c.client.Write(context.Background(), req) @@ -428,15 +420,12 @@ func (c *P4rtClient) WriteBatchReq(updates []*p4.Update) error { // GetForwardingPipelineConfig ... Get Pipeline config from switch. func (c *P4rtClient) GetForwardingPipelineConfig() (err error) { - getLog := log.WithFields(log.Fields{ - "device ID": c.deviceID, - "conn": c.conn.Target(), - }) - getLog.Info("Getting ForwardingPipelineConfig from P4Rt device") + getLog := logger.P4Log.With("device ID", c.deviceID, "conn", c.conn.Target()) + getLog.Infoln("getting ForwardingPipelineConfig from P4Rt device") pipeline, err := GetPipelineConfig(c.client, c.deviceID) if err != nil { - getLog.Println("set pipeline config error ", err) + getLog.Errorln("set pipeline config error", err) return } @@ -463,7 +452,7 @@ func GetPipelineConfig(client p4.P4RuntimeClient, deviceID uint64) (*p4.GetForwa configRes, err := client.GetForwardingPipelineConfig(context.Background(), req) if err != nil { - log.Println("get forwarding pipeline returned error ", err) + logger.P4Log.Errorln("get forwarding pipeline returned error", err) return nil, err } @@ -472,11 +461,11 @@ func GetPipelineConfig(client p4.P4RuntimeClient, deviceID uint64) (*p4.GetForwa // SetForwardingPipelineConfig .. func (c *P4rtClient) SetForwardingPipelineConfig(p4InfoPath, deviceConfigPath string) (err error) { - log.Println("P4 Info: ", p4InfoPath) + logger.P4Log.Infoln("P4 Info: ", p4InfoPath) p4infoBytes, err := os.ReadFile(p4InfoPath) if err != nil { - log.Println("Read p4info file error ", err) + logger.P4Log.Errorln("read p4info file error", err) return } @@ -484,7 +473,7 @@ func (c *P4rtClient) SetForwardingPipelineConfig(p4InfoPath, deviceConfigPath st err = proto.UnmarshalText(string(p4infoBytes), p4Info) if err != nil { - log.Println("Unmarshal test failed for p4info ", err) + logger.P4Log.Errorln("unmarshal test failed for p4info", err) return } @@ -492,7 +481,7 @@ func (c *P4rtClient) SetForwardingPipelineConfig(p4InfoPath, deviceConfigPath st deviceConfig, err := LoadDeviceConfig(deviceConfigPath) if err != nil { - log.Println("bmv2 json read failed ", err) + logger.P4Log.Errorln("bmv2 json read failed", err) return } @@ -502,7 +491,7 @@ func (c *P4rtClient) SetForwardingPipelineConfig(p4InfoPath, deviceConfigPath st err = SetPipelineConfig(c.client, c.deviceID, &c.electionID, &pipeline) if err != nil { - log.Println("set pipeline config error ", err) + logger.P4Log.Errorln("set pipeline config error", err) return } @@ -521,7 +510,7 @@ func SetPipelineConfig(client p4.P4RuntimeClient, deviceID uint64, electionID *p _, err := client.SetForwardingPipelineConfig(context.Background(), req) if err != nil { - log.Println("set forwarding pipeline returned error ", err) + logger.P4Log.Errorln("set forwarding pipeline returned error", err) } return err @@ -530,11 +519,11 @@ func SetPipelineConfig(client p4.P4RuntimeClient, deviceID uint64, electionID *p // GetConnection ... Get Grpc connection. func GetConnection(host string) (conn *grpc.ClientConn, err error) { /* get connection */ - log.Println("Get connection.") + logger.P4Log.Infoln("get connection") - conn, err = grpc.Dial(host, grpc.WithTransportCredentials(insecure.NewCredentials())) + conn, err = grpc.NewClient(host, grpc.WithTransportCredentials(insecure.NewCredentials())) if err != nil { - log.Println("grpc dial err: ", err) + logger.P4Log.Errorln("grpc dial err:", err) return nil, err } @@ -543,7 +532,7 @@ func GetConnection(host string) (conn *grpc.ClientConn, err error) { // LoadDeviceConfig : Load Device config. func LoadDeviceConfig(deviceConfigPath string) (P4DeviceConfig, error) { - log.Println("BMv2 JSON: ", deviceConfigPath) + logger.P4Log.Infoln("BMv2 JSON:", deviceConfigPath) deviceConfig, err := os.Open(deviceConfigPath) if err != nil { @@ -568,11 +557,11 @@ func LoadDeviceConfig(deviceConfigPath string) (P4DeviceConfig, error) { // CreateChannel ... Create p4runtime client channel. func CreateChannel(host string, deviceID uint64) (*P4rtClient, error) { - log.Println("create channel") + logger.P4Log.Infoln("create channel") conn, err := GetConnection(host) if err != nil { - log.Println("grpc connection failed") + logger.P4Log.Errorln("grpc connection failed") return nil, err } @@ -585,7 +574,7 @@ func CreateChannel(host string, deviceID uint64) (*P4rtClient, error) { err = client.Init() if err != nil { - log.Println("client Init error: ", err) + logger.P4Log.Errorln("client Init error:", err) return nil, err } @@ -593,14 +582,14 @@ func CreateChannel(host string, deviceID uint64) (*P4rtClient, error) { if client.stream != nil { err = client.stream.CloseSend() if err != nil { - log.Errorf("Failed to close P4Rt stream with %v: %v", client.conn.Target(), err) + logger.P4Log.Errorf("failed to close P4Rt stream with %v: %v", client.conn.Target(), err) } } } err = client.SetMastership(TimeBasedElectionId()) if err != nil { - log.Error("Set Mastership error: ", err) + logger.P4Log.Errorln("set Mastership error:", err) closeStreamOnError() return nil, err diff --git a/pfcpiface/parse_far.go b/pfcpiface/parse_far.go index 7701107e1..d746e3ded 100644 --- a/pfcpiface/parse_far.go +++ b/pfcpiface/parse_far.go @@ -6,7 +6,7 @@ package pfcpiface import ( "fmt" - log "github.com/sirupsen/logrus" + "github.com/omec-project/upf-epc/logger" "github.com/wmnsk/go-pfcp/ie" ) @@ -80,11 +80,11 @@ func (f *far) parseFAR(farIE *ie.IE, fseid uint64, upf *upf, op operation) error return err } - if action == 0 { + if action[0] == 0 { return ErrInvalidArgument("FAR Action", action) } - f.applyAction = action + f.applyAction = action[0] var fwdIEs []*ie.IE @@ -115,7 +115,7 @@ func (f *far) parseFAR(farIE *ie.IE, fseid uint64, upf *upf, op operation) error ohcFields, err = fwdIE.OuterHeaderCreation() if err != nil { - log.Println("Unable to parse OuterHeaderCreationFields!") + logger.PfcpLog.Errorln("unable to parse OuterHeaderCreationFields") continue } @@ -128,7 +128,7 @@ func (f *far) parseFAR(farIE *ie.IE, fseid uint64, upf *upf, op operation) error f.dstIntf, err = fwdIE.DestinationInterface() if err != nil { - log.Println("Unable to parse DestinationInterface field") + logger.PfcpLog.Errorln("unable to parse DestinationInterface field") continue } @@ -142,7 +142,7 @@ func (f *far) parseFAR(farIE *ie.IE, fseid uint64, upf *upf, op operation) error smReqFlags, err := fwdIE.PFCPSMReqFlags() if err != nil { - log.Println("Unable to parse PFCPSMReqFlags!") + logger.PfcpLog.Errorln("unable to parse PFCPSMReqFlags") continue } diff --git a/pfcpiface/parse_pdr.go b/pfcpiface/parse_pdr.go index 0040d8010..e665d8a1a 100644 --- a/pfcpiface/parse_pdr.go +++ b/pfcpiface/parse_pdr.go @@ -10,7 +10,7 @@ import ( "math" "net" - log "github.com/sirupsen/logrus" + "github.com/omec-project/upf-epc/logger" "github.com/wmnsk/go-pfcp/ie" ) @@ -269,10 +269,11 @@ type applicationFilter struct { } type pdr struct { - srcIface uint8 - tunnelIP4Dst uint32 - tunnelTEID uint32 - ueAddress uint32 + UPAllocateFteid bool + srcIface uint8 + tunnelIP4Dst uint32 + tunnelTEID uint32 + ueAddress uint32 srcIfaceMask uint8 tunnelIP4DstMask uint32 @@ -338,15 +339,15 @@ func (p *pdr) parseUEAddressIE(ueAddrIE *ie.IE, ippool *IPPool) error { if needAllocIP(ueIPaddr) { /* alloc IPV6 if CHV6 is enabled : TBD */ - log.Infof("UPF should alloc UE IP for SEID %v. CHV4 flag set", p.fseID) + logger.PfcpLog.Infof("UPF should alloc UE IP for SEID %v. CHV4 flag set", p.fseID) ueIP4, err = ippool.LookupOrAllocIP(p.fseID) if err != nil { - log.Errorln("failed to allocate UE IP") + logger.PfcpLog.Errorln("failed to allocate UE IP") return err } - log.Traceln("Found or allocated new IP", ueIP4, "from pool", ippool) + logger.PfcpLog.Debugln("found or allocated new IP", ueIP4, "from pool", ippool) p.allocIPFlag = true } else { @@ -390,13 +391,15 @@ func (p *pdr) parseFTEID(teidIE *ie.IE) error { } teid := fteid.TEID - tunnelIPv4Address := fteid.IPv4Address - - if teid != 0 { - p.tunnelTEID = teid - p.tunnelTEIDMask = 0xFFFFFFFF - p.tunnelIP4Dst = ip2int(tunnelIPv4Address) - p.tunnelIP4DstMask = 0xFFFFFFFF + if fteid.HasCh() { + p.UPAllocateFteid = true + } else { + if teid != 0 { + p.tunnelTEID = teid + p.tunnelTEIDMask = 0xFFFFFFFF + p.tunnelIP4Dst = ip2int(fteid.IPv4Address) + p.tunnelIP4DstMask = 0xFFFFFFFF + } } return nil @@ -414,14 +417,11 @@ func (p *pdr) parseApplicationID(ie *ie.IE, appPFDs map[string]appPFD) error { } if appID != apfd.appID { - log.Fatalln("Mismatch in App ID", appID, apfd.appID) + logger.PfcpLog.Fatalln("mismatch in App ID", appID, apfd.appID) } for _, flowDesc := range apfd.flowDescs { - logger := log.WithFields(log.Fields{ - "Application ID": apfd.appID, - "Flow Description": flowDesc, - }) + logger := logger.PfcpLog.With("Application ID", apfd.appID, "Flow Description", flowDesc) logger.Debug("Parsing flow description of Application ID IE") ipf, err := parseFlowDesc(flowDesc, int2ip(p.ueAddress).String()) @@ -463,9 +463,7 @@ func (p *pdr) parseSDFFilter(ie *ie.IE) error { return ErrOperationFailedWithReason("parse SDF Filter", "empty filter description") } - log.WithFields(log.Fields{ - "Flow Description": flowDesc, - }).Debug("Parsing Flow Description from SDF Filter") + logger.PfcpLog.With("Flow Description", flowDesc).Debugln("parsing Flow Description from SDF Filter") ipf, err := parseFlowDesc(flowDesc, int2ip(p.ueAddress).String()) if err != nil { @@ -516,17 +514,17 @@ func (p *pdr) parsePDI(pdiIEs []*ie.IE, appPFDs map[string]appPFD, ippool *IPPoo switch pdiIE.Type { case ie.UEIPAddress: if err := p.parseUEAddressIE(pdiIE, ippool); err != nil { - log.Errorf("Failed to parse UE Address IE: %v", err) + logger.PfcpLog.Errorf("failed to parse UE Address IE: %v", err) return err } case ie.SourceInterface: if err := p.parseSourceInterfaceIE(pdiIE); err != nil { - log.Errorf("Failed to parse Source Interface IE: %v", err) + logger.PfcpLog.Errorf("failed to parse Source Interface IE: %v", err) return err } case ie.FTEID: if err := p.parseFTEID(pdiIE); err != nil { - log.Errorf("Failed to parse F-TEID IE: %v", err) + logger.PfcpLog.Errorf("failed to parse F-TEID IE: %v", err) return err } } @@ -547,12 +545,12 @@ func (p *pdr) parsePDI(pdiIEs []*ie.IE, appPFDs map[string]appPFD, ippool *IPPoo switch ie2.Type { case ie.ApplicationID: if err := p.parseApplicationID(ie2, appPFDs); err != nil { - log.Errorf("Failed to parse Application ID IE: %v", err) + logger.PfcpLog.Errorf("failed to parse Application ID IE: %v", err) return err } case ie.SDFFilter: if err := p.parseSDFFilter(ie2); err != nil { - log.Errorf("Failed to parse SDF Filter IE: %v", err) + logger.PfcpLog.Errorf("failed to parse SDF Filter IE: %v", err) return err } } @@ -569,19 +567,19 @@ func (p *pdr) parsePDR(ie1 *ie.IE, seid uint64, appPFDs map[string]appPFD, ippoo pdrID, err := ie1.PDRID() if err != nil { - log.Println("Could not read PDR ID!") + logger.PfcpLog.Errorln("could not read PDR ID!") return err } precedence, err := ie1.Precedence() if err != nil { - log.Println("Could not read Precedence!") + logger.PfcpLog.Errorln("could not read Precedence!") return err } pdi, err := ie1.PDI() if err != nil { - log.Println("Could not read PDI!") + logger.PfcpLog.Errorln("could not read PDI!") return err } @@ -597,7 +595,7 @@ func (p *pdr) parsePDR(ie1 *ie.IE, seid uint64, appPFDs map[string]appPFD, ippoo farID, err := ie1.FARID() if err != nil { - log.Println("Could not read FAR ID!") + logger.PfcpLog.Errorln("could not read FAR ID!") return err } @@ -625,7 +623,7 @@ func (p *pdr) parsePDR(ie1 *ie.IE, seid uint64, appPFDs map[string]appPFD, ippoo if x.Type == ie.QERID { qerID, errRead := x.QERID() if errRead != nil { - log.Errorln("qerID read failed") + logger.PfcpLog.Errorln("qerID read failed") continue } else { p.qerIDList = append(p.qerIDList, qerID) @@ -634,7 +632,7 @@ func (p *pdr) parsePDR(ie1 *ie.IE, seid uint64, appPFDs map[string]appPFD, ippoo } /*qerID, err := ie1.QERID() if err != nil { - log.Println("Could not read QER ID!") + logger.PfcpLog.Errorln("could not read QER ID!") }*/ p.precedence = precedence diff --git a/pfcpiface/parse_qer.go b/pfcpiface/parse_qer.go index ddfe97c84..96fe9e735 100644 --- a/pfcpiface/parse_qer.go +++ b/pfcpiface/parse_qer.go @@ -6,7 +6,7 @@ package pfcpiface import ( "fmt" - log "github.com/sirupsen/logrus" + "github.com/omec-project/upf-epc/logger" "github.com/wmnsk/go-pfcp/ie" ) @@ -45,43 +45,43 @@ func (q qer) String() string { func (q *qer) parseQER(ie1 *ie.IE, seid uint64) error { qerID, err := ie1.QERID() if err != nil { - log.Println("Could not read QER ID!") + logger.PfcpLog.Errorln("could not read QER ID") return err } qfi, err := ie1.QFI() if err != nil { - log.Println("Could not read QFI!") + logger.PfcpLog.Errorln("could not read QFI") } gsUL, err := ie1.GateStatusUL() if err != nil { - log.Println("Could not read Gate status uplink!") + logger.PfcpLog.Errorln("could not read Gate status uplink") } gsDL, err := ie1.GateStatusDL() if err != nil { - log.Println("Could not read Gate status downlink!") + logger.PfcpLog.Errorln("could not read Gate status downlink") } mbrUL, err := ie1.MBRUL() if err != nil { - log.Println("Could not read MBRUL!") + logger.PfcpLog.Errorln("could not read MBRUL") } mbrDL, err := ie1.MBRDL() if err != nil { - log.Println("Could not read MBRDL!") + logger.PfcpLog.Errorln("could not read MBRDL") } gbrUL, err := ie1.GBRUL() if err != nil { - log.Println("Could not read GBRUL!") + logger.PfcpLog.Errorln("could not read GBRUL") } gbrDL, err := ie1.GBRDL() if err != nil { - log.Println("Could not read GBRDL!") + logger.PfcpLog.Errorln("could not read GBRDL") } q.qerID = qerID diff --git a/pfcpiface/parse_sdf.go b/pfcpiface/parse_sdf.go index 687a11c28..117e6eddf 100644 --- a/pfcpiface/parse_sdf.go +++ b/pfcpiface/parse_sdf.go @@ -11,7 +11,7 @@ import ( "strconv" "strings" - log "github.com/sirupsen/logrus" + "github.com/omec-project/upf-epc/logger" ) const ( @@ -96,11 +96,8 @@ func (ipf *ipFilterRule) String() string { } func parseFlowDesc(flowDesc, ueIP string) (*ipFilterRule, error) { - parseLog := log.WithFields(log.Fields{ - "flow-description": flowDesc, - "ue-address": ueIP, - }) - parseLog.Debug("Parsing flow description") + parseLog := logger.PfcpLog.With("flow-description", flowDesc, "ue-address", ueIP) + parseLog.Debugln("parsing flow description") ipf := newIpFilterRule() @@ -146,7 +143,7 @@ func parseFlowDesc(flowDesc, ueIP string) (*ipFilterRule, error) { err := ipf.src.parseNet(fields[i]) if err != nil { - parseLog.Error(err) + parseLog.Errorln(err) return nil, err } @@ -155,7 +152,7 @@ func parseFlowDesc(flowDesc, ueIP string) (*ipFilterRule, error) { err = ipf.src.parsePort(fields[i]) if err != nil { - parseLog.Error("src port parse failed ", err) + parseLog.Errorln("src port parse failed", err) return nil, err } } @@ -165,7 +162,7 @@ func parseFlowDesc(flowDesc, ueIP string) (*ipFilterRule, error) { err := ipf.dst.parseNet(fields[i]) if err != nil { - parseLog.Error(err) + parseLog.Errorln(err) return nil, err } @@ -174,15 +171,15 @@ func parseFlowDesc(flowDesc, ueIP string) (*ipFilterRule, error) { err = ipf.dst.parsePort(fields[i]) if err != nil { - parseLog.Error("dst port parse failed ", err) + parseLog.Errorln("dst port parse failed", err) return nil, err } } } } - parseLog = parseLog.WithField("ip-filter", ipf) - parseLog.Debug("Flow description parsed successfully") + parseLog = parseLog.With("ip-filter", ipf) + parseLog.Debugln("flow description parsed successfully") return ipf, nil } diff --git a/pfcpiface/parse_sdf_test.go b/pfcpiface/parse_sdf_test.go index 422265b8d..b787419cc 100644 --- a/pfcpiface/parse_sdf_test.go +++ b/pfcpiface/parse_sdf_test.go @@ -4,7 +4,7 @@ package pfcpiface import ( - log "github.com/sirupsen/logrus" + "github.com/omec-project/upf-epc/logger" "github.com/stretchr/testify/require" "net" @@ -14,7 +14,7 @@ import ( func mustParseCIDRNet(s string) *net.IPNet { _, ipNet, err := net.ParseCIDR(s) if err != nil { - log.Fatal(err) + logger.PfcpLog.Fatal(err) } return ipNet diff --git a/pfcpiface/pfcpiface.go b/pfcpiface/pfcpiface.go index a7147c808..dcc9a16d9 100644 --- a/pfcpiface/pfcpiface.go +++ b/pfcpiface/pfcpiface.go @@ -14,7 +14,7 @@ import ( "syscall" "time" - log "github.com/sirupsen/logrus" + "github.com/omec-project/upf-epc/logger" ) var ( @@ -78,7 +78,7 @@ func (p *PFCPIface) mustInit() { p.uc, p.nc, err = setupProm(httpMux, p.upf, p.node) if err != nil { - log.Fatalln("setupProm failed", err) + logger.PfcpLog.Fatalln("setupProm failed", err) } // Note: due to error with golangci-lint ("Error: G112: Potential Slowloris Attack @@ -100,10 +100,10 @@ func (p *PFCPIface) Run() { go func() { if err := p.httpSrv.ListenAndServe(); err != nil && !errors.Is(err, http.ErrServerClosed) { - log.Fatalln("http server failed", err) + logger.PfcpLog.Fatalln("http server failed", err) } - log.Infoln("http server closed") + logger.PfcpLog.Infoln("http server closed") }() sig := make(chan os.Signal, 1) @@ -112,7 +112,7 @@ func (p *PFCPIface) Run() { go func() { oscall := <-sig - log.Infof("System call received: %+v", oscall) + logger.PfcpLog.Infof("system call received: %+v", oscall) p.Stop() }() @@ -131,7 +131,7 @@ func (p *PFCPIface) Stop() { }() if err := p.httpSrv.Shutdown(ctxHttpShutdown); err != nil { - log.Errorln("Failed to shutdown http: ", err) + logger.PfcpLog.Errorln("failed to shutdown http:", err) } p.node.Stop() diff --git a/pfcpiface/session_far.go b/pfcpiface/session_far.go index a166fb21a..45991e6f9 100644 --- a/pfcpiface/session_far.go +++ b/pfcpiface/session_far.go @@ -8,7 +8,7 @@ import ( "github.com/google/gopacket" "github.com/google/gopacket/layers" - log "github.com/sirupsen/logrus" + "github.com/omec-project/upf-epc/logger" ) // CreateFAR appends far to existing list of FARs in the session. @@ -18,7 +18,7 @@ func (s *PFCPSession) CreateFAR(f far) { func addEndMarker(farItem far, endMarkerList *[][]byte) { // This time lets fill out some information - log.Println("Adding end Marker for farID : ", farItem.farID) + logger.PfcpLog.Infoln("adding end marker for farID:", farItem.farID) options := gopacket.SerializeOptions{ ComputeChecksums: true, @@ -44,7 +44,7 @@ func addEndMarker(farItem far, endMarkerList *[][]byte) { err := udpLayer.SetNetworkLayerForChecksum(ipLayer) if err != nil { - log.Println("set checksum for UDP layer in endmarker failed") + logger.PfcpLog.Errorln("set checksum for UDP layer in endmarker failed") return } @@ -66,7 +66,7 @@ func addEndMarker(farItem far, endMarkerList *[][]byte) { outgoingPacket := buffer.Bytes() *endMarkerList = append(*endMarkerList, outgoingPacket) } else { - log.Println("go packet serialize failed : ", err) + logger.PfcpLog.Errorln("go packet serialize failed:", err) } } diff --git a/pfcpiface/session_pdr.go b/pfcpiface/session_pdr.go index 0d13d1f93..1b2b80a9b 100644 --- a/pfcpiface/session_pdr.go +++ b/pfcpiface/session_pdr.go @@ -6,43 +6,46 @@ package pfcpiface import ( "net" - log "github.com/sirupsen/logrus" + "github.com/omec-project/upf-epc/logger" "github.com/wmnsk/go-pfcp/ie" "github.com/wmnsk/go-pfcp/message" ) // Release allocated IPs. func releaseAllocatedIPs(ippool *IPPool, session *PFCPSession) error { - log.Println("release allocated IP") + logger.PfcpLog.Infoln("release allocated IP") // Check if we allocated an UE IP for this session and delete it. for _, pdr := range session.pdrs { if (pdr.allocIPFlag) && (pdr.srcIface == core) { var ueIP net.IP = int2ip(pdr.ueAddress) - - log.Traceln("Releasing IP", ueIP, " of session", session.localSEID) - + logger.PfcpLog.Debugf("Releasing IP %s of session %d", ueIP.String(), session.localSEID) return ippool.DeallocIP(session.localSEID) } } - return nil } -func addPdrInfo(msg *message.SessionEstablishmentResponse, - session *PFCPSession) { - log.Println("Add PDRs with UPF alloc IPs to Establishment response") - - for _, pdr := range session.pdrs { +func addPdrInfo(msg *message.SessionEstablishmentResponse, pdrs []pdr) { + logger.PfcpLog.Infoln("add PDRs with UPF alloc IPs to Establishment response") + logger.PfcpLog.Infoln("PDRs:", pdrs) + for _, pdr := range pdrs { + logger.PfcpLog.Infoln("pdrID:", pdr.pdrID) + if pdr.UPAllocateFteid { + logger.PfcpLog.Infoln("adding PDR with tunnel TEID:", pdr.tunnelTEID) + msg.CreatedPDR = append(msg.CreatedPDR, + ie.NewCreatedPDR( + ie.NewPDRID(uint16(pdr.pdrID)), + ie.NewFTEID(0x01, pdr.tunnelTEID, int2ip(pdr.tunnelIP4Dst), nil, 0), + )) + } if (pdr.allocIPFlag) && (pdr.srcIface == core) { - log.Println("pdrID : ", pdr.pdrID) - + logger.PfcpLog.Debugln("pdrID:", pdr.pdrID) var ( flags uint8 = 0x02 ueIP net.IP = int2ip(pdr.ueAddress) ) - - log.Println("ueIP : ", ueIP.String()) + logger.PfcpLog.Debugln("ueIP:", ueIP.String()) msg.CreatedPDR = append(msg.CreatedPDR, ie.NewCreatedPDR( ie.NewPDRID(uint16(pdr.pdrID)), diff --git a/pfcpiface/session_qer.go b/pfcpiface/session_qer.go index 1ceac6059..f6dd4c76f 100644 --- a/pfcpiface/session_qer.go +++ b/pfcpiface/session_qer.go @@ -4,7 +4,7 @@ package pfcpiface import ( - log "github.com/sirupsen/logrus" + "github.com/omec-project/upf-epc/logger" ) type QosLevel uint8 @@ -75,7 +75,7 @@ func (s *PFCPSession) MarkSessionQer(qers []qer) { // If PDRS have one QER and all PDRs point to same QER, then consider it as application qer. // If number of QERS is 2 or more, then search for session QER if (len(sessQerIDList) < 1) || (len(qers) < 2) { - log.Infoln("need atleast 1 QER in PDR or 2 QERs in session to mark session QER.") + logger.PfcpLog.Infoln("need atleast 1 QER in PDR or 2 QERs in session to mark session QER") return } @@ -105,13 +105,13 @@ func (s *PFCPSession) MarkSessionQer(qers []qer) { ) if len(sessQerIDList) > 3 { - log.Warnln("Qer ID list size above 3. Not supported.") + logger.PfcpLog.Warnln("qer id list size above 3 is not supported") } for idx, qer := range qers { if contains(sessQerIDList, qer.qerID) { if qer.ulGbr > 0 || qer.dlGbr > 0 { - log.Infoln("Do not consider qer with non zero gbr value for session qer") + logger.InitLog.Infoln("do not consider qer with non zero gbr value for session qer") continue } @@ -123,7 +123,7 @@ func (s *PFCPSession) MarkSessionQer(qers []qer) { } } - log.Infoln("session QER found. QER ID : ", sessQerID) + logger.PfcpLog.Infoln("session QER found. QER ID:", sessQerID) qers[sessionIdx].qosLevel = SessionQos diff --git a/pfcpiface/sessions.go b/pfcpiface/sessions.go index 233e373ce..f5e820b07 100644 --- a/pfcpiface/sessions.go +++ b/pfcpiface/sessions.go @@ -6,8 +6,7 @@ package pfcpiface import ( "fmt" - log "github.com/sirupsen/logrus" - + "github.com/omec-project/upf-epc/logger" "github.com/omec-project/upf-epc/pfcpiface/metrics" ) @@ -65,6 +64,6 @@ func (pConn *PFCPConn) RemoveSession(session PFCPSession) { pConn.SaveSessions(session.metrics) if err := pConn.store.DeleteSession(session.localSEID); err != nil { - log.Errorf("Failed to delete PFCP session from store: %v", err) + logger.PfcpLog.Errorf("failed to delete PFCP session from store: %v", err) } } diff --git a/pfcpiface/telemetry.go b/pfcpiface/telemetry.go index 79262ed65..d06133858 100644 --- a/pfcpiface/telemetry.go +++ b/pfcpiface/telemetry.go @@ -6,8 +6,7 @@ package pfcpiface import ( "net/http" - log "github.com/sirupsen/logrus" - + "github.com/omec-project/upf-epc/logger" "github.com/prometheus/client_golang/prometheus" "github.com/prometheus/client_golang/prometheus/promhttp" ) @@ -168,7 +167,7 @@ func (col PfcpNodeCollector) Collect(ch chan<- prometheus.Metric) { if col.node.upf.enableFlowMeasure { err := col.node.upf.SessionStats(&col, ch) if err != nil { - log.Errorln(err) + logger.PfcpLog.Errorln(err) return } } @@ -192,10 +191,10 @@ func setupProm(mux *http.ServeMux, upf *upf, node *PFCPNode) (*upfCollector, *Pf func clearProm(uc *upfCollector, nc *PfcpNodeCollector) { if ok := prometheus.Unregister(uc); !ok { - log.Warnln("Failed to unregister upfCollector") + logger.PfcpLog.Warnln("failed to unregister upfCollector") } if ok := prometheus.Unregister(nc); !ok { - log.Warnln("Failed to unregister PfcpNodeCollector") + logger.PfcpLog.Warnln("failed to unregister PfcpNodeCollector") } } diff --git a/pfcpiface/up4.go b/pfcpiface/up4.go index 374895637..2a37deea6 100644 --- a/pfcpiface/up4.go +++ b/pfcpiface/up4.go @@ -20,8 +20,8 @@ import ( p4 "github.com/p4lang/p4runtime/go/p4/v1" set "github.com/deckarep/golang-set" + "github.com/omec-project/upf-epc/logger" "github.com/prometheus/client_golang/prometheus" - log "github.com/sirupsen/logrus" "github.com/wmnsk/go-pfcp/ie" ) @@ -185,7 +185,7 @@ func (up4 *UP4) AddSliceInfo(sliceInfo *SliceInfo) error { // configure the meter with the largest slice MBR between UL and DL. err := up4.tryConnect() if err != nil { - log.Error("UP4 server not connected") + logger.PfcpLog.Error("UP4 server not connected") return ErrOperationFailedWithReason("addSliceInfo", "data plane is not connected") } @@ -211,9 +211,7 @@ func (up4 *UP4) AddSliceInfo(sliceInfo *SliceInfo) error { } sliceMeterEntry := up4.p4RtTranslator.BuildMeterEntry(p4constants.MeterPreQosPipeSliceTcMeter, uint32(meterCellId), &meterConfig) - log.WithFields(log.Fields{ - "Slice meter entry": sliceMeterEntry, - }).Debug("Installing slice P4 Meter entry") + logger.PfcpLog.With("Slice meter entry", sliceMeterEntry).Debugln("installing slice P4 Meter entry") err = up4.p4client.ApplyMeterEntries(p4.Update_MODIFY, sliceMeterEntry) @@ -246,16 +244,11 @@ func (up4 *UP4) initCounter(counterID uint8, name string, counterSize uint64) { up4.counters[counterID].counterIDsPool.Add(i) } - log.WithFields(log.Fields{ - "counterID": counterID, - "name": name, - "max-size": counterSize, - "UP4 counter ID": counterID, - }).Debug("Counter initialized successfully") + logger.PfcpLog.With("counterID", counterID, "name", name, "max-size", counterSize, "UP4 counter ID", counterID).Debugln("counter initialized successfully") } func (up4 *UP4) releaseCounterID(p4counterID uint8, val uint64) { - log.Println("delete counter val ", val) + logger.PfcpLog.Infoln("delete counter val", val) up4.counters[p4counterID].counterIDsPool.Add(val) } @@ -276,15 +269,12 @@ func (up4 *UP4) allocateCounterID(p4counterID uint8) (uint64, error) { } func (up4 *UP4) Exit() { - log.Println("Exit function P4rtc") + logger.PfcpLog.Infoln("exit function P4rtc") } func (up4 *UP4) setupChannel() error { - setupLog := log.WithFields(log.Fields{ - "P4Runtime server address": up4.host, - "DeviceID": up4.deviceID, - }) - setupLog.Debug("Trying to setup P4Rt channel") + setupLog := logger.PfcpLog.With("P4Runtime server address", up4.host, "DeviceID", up4.deviceID) + setupLog.Debugln("trying to setup P4Rt channel") client, err := CreateChannel(up4.host, up4.deviceID) if err != nil { @@ -296,13 +286,13 @@ func (up4 *UP4) setupChannel() error { up4.p4RtTranslator = newP4RtTranslator(up4.p4client.P4Info) - setupLog.Debug("P4Rt channel created") + setupLog.Debugln("P4Rt channel created") return nil } func (up4 *UP4) initAllCounters() { - log.Debug("Initializing counters for UP4") + logger.PfcpLog.Debugln("initializing counters for UP4") counters := []uint32{ p4constants.CounterPreQosPipePreQosCounter, @@ -314,7 +304,7 @@ func (up4 *UP4) initAllCounters() { counterSize, err := up4.p4RtTranslator.getCounterSizeByID(counterID) if err != nil { - log.Error(err) + logger.PfcpLog.Errorln(err) } switch counterID { @@ -327,7 +317,7 @@ func (up4 *UP4) initAllCounters() { } func (up4 *UP4) initMetersPools() { - log.Debug("Initializing P4 Meters pools for UP4") + logger.PfcpLog.Debugln("initializing P4 Meters pools for UP4") meters := []uint32{ p4constants.MeterPreQosPipeAppMeter, @@ -339,7 +329,7 @@ func (up4 *UP4) initMetersPools() { meterSize, err := up4.p4RtTranslator.getMeterSizeByID(meterID) if err != nil { - log.Errorf("Could not find meter size of %v", meterName) + logger.PfcpLog.Errorf("could not find meter size of %v", meterName) } switch meterID { @@ -349,21 +339,18 @@ func (up4 *UP4) initMetersPools() { up4.appMeterCellIDsPool.Add(uint32(i)) } - log.Trace("Application meter IDs pool initialized: ", up4.appMeterCellIDsPool.String()) + logger.PfcpLog.Debugln("Application meter IDs pool initialized:", up4.appMeterCellIDsPool.String()) case p4constants.MeterPreQosPipeSessionMeter: up4.sessMeterCellIDsPool = set.NewSet() for i := 1; i < int(meterSize); i++ { up4.sessMeterCellIDsPool.Add(uint32(i)) } - log.Trace("Session meter IDs pool initialized: ", up4.sessMeterCellIDsPool.String()) + logger.PfcpLog.Debugln("session meter IDs pool initialized:", up4.sessMeterCellIDsPool.String()) } } - log.WithFields(log.Fields{ - "applicationMeter pool size": up4.appMeterCellIDsPool.Cardinality(), - "sessMeter pool size": up4.sessMeterCellIDsPool.Cardinality(), - }).Debug("P4 Meters pools initialized successfully") + logger.PfcpLog.With("applicationMeter pool size", up4.appMeterCellIDsPool.Cardinality(), "sessMeter pool size", up4.sessMeterCellIDsPool.Cardinality()).Debugln("P4 Meters pools initialized successfully") } func (up4 *UP4) initTunnelPeerIDs() { @@ -408,18 +395,18 @@ func (up4 *UP4) setConnectedStatus(status bool) { // TODO: rename it to initUPF() func (up4 *UP4) SetUpfInfo(u *upf, conf *Conf) { - log.Println("SetUpfInfo UP4") + logger.PfcpLog.Infoln("SetUpfInfo UP4") up4.conf = conf.P4rtcIface up4.accessIP = MustParseStrIP(conf.P4rtcIface.AccessIP) u.accessIP = up4.accessIP.IP - log.Infof("AccessIP: %v", up4.accessIP) + logger.PfcpLog.Infof("AccessIP: %v", up4.accessIP) up4.ueIPPool = MustParseStrIP(conf.CPIface.UEIPPool) - log.Infof("UE IP pool: %v", up4.ueIPPool) + logger.PfcpLog.Infof("UE IP pool: %v", up4.ueIPPool) p4rtcServer := conf.P4rtcIface.P4rtcServer @@ -438,9 +425,7 @@ func (up4 *UP4) SetUpfInfo(u *upf, conf *Conf) { up4.host = p4rtcServer + ":" + p4rtcPort - log.WithFields(log.Fields{ - "UP4 endpoint": up4.host, - }).Info("UP4 endpoint configured") + logger.PfcpLog.With("UP4 endpoint", up4.host).Infoln("UP4 endpoint configured") up4.deviceID = 1 up4.timeout = 30 @@ -469,13 +454,13 @@ func (up4 *UP4) tryConnect() error { err := up4.setupChannel() if err != nil { - log.Errorf("Failed to setup UP4 channel: %v", err) + logger.PfcpLog.Errorf("failed to setup UP4 channel: %v", err) return err } err = up4.initialize(shouldClearAndInitialize) if err != nil { - log.Errorf("Failed to initialize UP4: %v", err) + logger.PfcpLog.Errorf("failed to initialize UP4: %v", err) return err } @@ -537,16 +522,13 @@ func (up4 *UP4) initInterfaces() error { return err } - log.WithFields(log.Fields{ - "N3 address": up4.accessIP, - "ue pool": up4.ueIPPool, - }).Debug("N3 address and UE pool successfully initialized in the UP4 pipeline") + logger.PfcpLog.With("N3 address", up4.accessIP, "ue pool", up4.ueIPPool).Debugln("N3 address and UE pool successfully initialized in the UP4 pipeline") return nil } func (up4 *UP4) listenToDDNs() { - log.Info("Listening to Data Notifications from UP4..") + logger.PfcpLog.Info("listening to Data Notifications from UP4..") notifier := NewDownlinkDataNotifier(up4.reportNotifyChan, 20*time.Second) @@ -566,7 +548,7 @@ func (up4 *UP4) listenToDDNs() { func (up4 *UP4) clearDatapathState() error { err := up4.clearTables() if err != nil { - log.Warningf("failed to clear tables: %v", err) + logger.PfcpLog.Warnf("failed to clear tables: %v", err) return err } @@ -596,7 +578,7 @@ func (up4 *UP4) initialize(shouldClear bool) error { go up4.listenToDDNs() if up4.enableEndMarker { - log.Println("Starting end marker loop") + logger.PfcpLog.Infoln("starting end marker loop") up4.endMarkerChan = make(chan []byte, 1024) go up4.endMarkerSendLoop() @@ -618,7 +600,7 @@ func (up4 *UP4) endMarkerSendLoop() { for outPacket := range up4.endMarkerChan { err := up4.p4client.SendPacketOut(outPacket) if err != nil { - log.Println("end marker write failed") + logger.PfcpLog.Errorln("end marker write failed") } } } @@ -659,10 +641,7 @@ func (up4 *UP4) unsafeAllocateGTPTunnelPeerID() (uint8, error) { allocated := up4.tunnelPeerIDsPool[0] up4.tunnelPeerIDsPool = up4.tunnelPeerIDsPool[1:] - log.WithFields(log.Fields{ - "ID": allocated, - "pool": up4.tunnelPeerIDsPool, - }).Trace("Tunnel peer ID") + logger.PfcpLog.With("ID", allocated, "pool", up4.tunnelPeerIDsPool).Debugln("tunnel peer ID") return allocated, nil } @@ -673,11 +652,7 @@ func (up4 *UP4) unsafeReleaseAllocatedGTPTunnelPeer(tunnelParams tunnelParams) { delete(up4.tunnelPeerIDs, tunnelParams) up4.tunnelPeerIDsPool = append(up4.tunnelPeerIDsPool, allocated.id) - log.WithFields(log.Fields{ - "tunnel params": tunnelParams, - "tunnel peer": allocated, - "pool": up4.tunnelPeerIDsPool, - }).Trace("Tunnel peer ID released") + logger.PfcpLog.With("tunnel params", tunnelParams, "tunnel peer", allocated, "pool", up4.tunnelPeerIDsPool).Debugln("tunnel peer ID released") } } @@ -753,9 +728,7 @@ func (up4 *UP4) removeGTPTunnelPeer(far far) { up4.tunnelPeerMu.Lock() defer up4.tunnelPeerMu.Unlock() - removeLog := log.WithFields(log.Fields{ - "far": far, - }) + removeLog := logger.PfcpLog.With("far", far) tunnelParameters := tunnelParams{ tunnelIP4Src: ip2int(up4.accessIP.IP), tunnelIP4Dst: far.tunnelIP4Dst, @@ -764,34 +737,33 @@ func (up4 *UP4) removeGTPTunnelPeer(far far) { tnlPeer, exists := up4.tunnelPeerIDs[tunnelParameters] if !exists { - removeLog.WithField( - "tunnel-params", tunnelParameters).Warn("GTP tunnel peer ID not found for tunnel params") + removeLog.With("tunnel-params", tunnelParameters).Warnln("GTP tunnel peer ID not found for tunnel params") return } - removeLog.WithField("tunnel-peer", tnlPeer) + removeLog.With("tunnel-peer", tnlPeer) - removeLog.Debug("Found GTP tunnel peer for tunnel params") + removeLog.Debugln("found GTP tunnel peer for tunnel params") tnlPeer.usedBy.Remove(tnlPeerReference{ far.fseID, far.farID, }) if tnlPeer.usedBy.Cardinality() != 0 { - removeLog.Debug("GTP tunnel peer was about to be removed, but it's in use by other UE session.") + removeLog.Debugln("GTP tunnel peer was about to be removed, but it's in use by other UE session.") return } gtpTunnelPeerEntry, err := up4.p4RtTranslator.BuildGTPTunnelPeerTableEntry(tnlPeer.id, tunnelParameters) if err != nil { - removeLog.Error("failed to build GTP tunnel peer entry to remove") + removeLog.Errorln("failed to build GTP tunnel peer entry to remove") return } - removeLog.Debug("Removing GTP Tunnel Peer ID") + removeLog.Debugln("removing GTP Tunnel Peer ID") if err := up4.p4client.ApplyTableEntries(p4.Update_DELETE, gtpTunnelPeerEntry); err != nil { - removeLog.Error("failed to remove GTP tunnel peer") + removeLog.Errorln("failed to remove GTP tunnel peer") } up4.unsafeReleaseAllocatedGTPTunnelPeer(tunnelParameters) @@ -895,10 +867,7 @@ func (up4 *UP4) allocateAppMeterCellID() (uint32, error) { "no free AppMeter Cell IDs available") } - log.WithFields(log.Fields{ - "allocated ID": allocated, - "number of free IDs": up4.appMeterCellIDsPool.Cardinality(), - }).Debug("Application meter cell ID allocated") + logger.PfcpLog.With("allocated ID", allocated, "number of free IDs", up4.appMeterCellIDsPool.Cardinality()).Debugln("application meter cell ID allocated") return allocated.(uint32), nil } @@ -911,10 +880,7 @@ func (up4 *UP4) releaseAppMeterCellID(allocated uint32) { up4.appMeterCellIDsPool.Add(allocated) - log.WithFields(log.Fields{ - "released ID": allocated, - "number of free IDs": up4.appMeterCellIDsPool.Cardinality(), - }).Debug("Application meter cell ID released") + logger.PfcpLog.With("released ID", allocated, "number of free IDs", up4.appMeterCellIDsPool.Cardinality()).Debugln("application meter cell ID released") } func (up4 *UP4) allocateSessionMeterCellID() (uint32, error) { @@ -925,10 +891,7 @@ func (up4 *UP4) allocateSessionMeterCellID() (uint32, error) { "no free SessionMeter Cell IDs available") } - log.WithFields(log.Fields{ - "allocated ID": allocated, - "number of free IDs": up4.sessMeterCellIDsPool.Cardinality(), - }).Debug("Session meter cell ID allocated") + logger.PfcpLog.With("allocated ID", allocated, "number of free IDs", up4.sessMeterCellIDsPool.Cardinality()).Debugln("session meter cell ID allocated") return allocated.(uint32), nil } @@ -941,10 +904,7 @@ func (up4 *UP4) releaseSessionMeterCellID(allocated uint32) { up4.sessMeterCellIDsPool.Add(allocated) - log.WithFields(log.Fields{ - "released ID": allocated, - "number of free IDs": up4.sessMeterCellIDsPool.Cardinality(), - }).Debug("Session meter cell ID released") + logger.PfcpLog.With("released ID", allocated, "number of free IDs", up4.sessMeterCellIDsPool.Cardinality()).Debugln("session meter cell ID released") } func (up4 *UP4) updateUEAddrAndFSEIDMappings(pdr pdr) { @@ -967,13 +927,11 @@ func (up4 *UP4) removeUeAddrAndFSEIDMappings(pdr pdr) { func (up4 *UP4) updateTunnelPeersBasedOnFARs(fars []far) error { for _, far := range fars { - logger := log.WithFields(log.Fields{ - "far": far, - }) + logger := logger.PfcpLog.With("far", far) // downlink FAR with tunnel params that does encapsulation if far.Forwards() && far.dstIntf == ie.DstInterfaceAccess && far.tunnelTEID != 0 { if err := up4.addOrUpdateGTPTunnelPeer(far); err != nil { - logger.Errorf("Failed to add or update GTP tunnel peer: %v", err) + logger.Errorf("failed to add or update GTP tunnel peer: %v", err) return err } } @@ -984,12 +942,8 @@ func (up4 *UP4) updateTunnelPeersBasedOnFARs(fars []far) error { func getMeterConfigurationFromQER(mbr uint64, gbr uint64) *p4.MeterConfig { defaultBurstDurationMs := 10 - logger := log.WithFields(log.Fields{ - "GBR (Kbps)": gbr, - "MBR (Kbps)": mbr, - "burstDuration (ms)": defaultBurstDurationMs, - }) - logger.Debug("Converting GBR/MBR to P4 Meter configuration") + logger := logger.PfcpLog.With("GBR (Kbps)", gbr, "MBR (Kbps)", mbr, "burstDuration (ms)", defaultBurstDurationMs) + logger.Debugln("converting GBR/MBR to P4 Meter configuration") // FIXME: calculate from rate once P4-UPF supports GBRs cbs := 0 @@ -1004,13 +958,8 @@ func getMeterConfigurationFromQER(mbr uint64, gbr uint64) *p4.MeterConfig { pir = maxUint64((mbr*1000)/8, uint64(cir)) } - logger = logger.WithFields(log.Fields{ - "CIR": cir, - "CBS": cbs, - "PIR": pir, - "PBS": pbs, - }) - logger.Debug("GBR/MBR has been converted to P4 Meter configuration") + logger = logger.With("CIR", cir, "CBS", cbs, "PIR", pir, "PBS", pbs) + logger.Debugln("GBR/MBR has been converted to P4 Meter configuration") return &p4.MeterConfig{ Cir: int64(cir), @@ -1105,12 +1054,8 @@ func (up4 *UP4) configureSessionMeter(q qer) (meter, error) { up4.releaseSessionMeterCellID(downlinkCellID) } - logger := log.WithFields(log.Fields{ - "uplink cell ID": uplinkCellID, - "downlink cell ID": downlinkCellID, - "qer": q, - }) - logger.Debug("Configuring Session Meter from QER") + logger := logger.PfcpLog.With("uplink cell ID", uplinkCellID, "downlink cell ID", downlinkCellID, "qer", q) + logger.Debugln("configuring Session Meter from QER") uplinkMeterConfig := getMeterConfigurationFromQER(q.ulMbr, q.ulGbr) uplinkMeterEntry := up4.p4RtTranslator.BuildMeterEntry(p4constants.MeterPreQosPipeSessionMeter, uplinkCellID, uplinkMeterConfig) @@ -1118,11 +1063,8 @@ func (up4 *UP4) configureSessionMeter(q qer) (meter, error) { downlinkMeterConfig := getMeterConfigurationFromQER(q.dlMbr, q.dlGbr) downlinkMeterEntry := up4.p4RtTranslator.BuildMeterEntry(p4constants.MeterPreQosPipeSessionMeter, downlinkCellID, downlinkMeterConfig) - logger = logger.WithFields(log.Fields{ - "uplink meter entry": uplinkMeterEntry, - "downlink meter entry": downlinkMeterEntry, - }) - logger.Debug("Installing P4 Meter entries") + logger = logger.With("uplink meter entry", uplinkMeterEntry, "downlink meter entry", downlinkMeterEntry) + logger.Debugln("installing P4 Meter entries") err = up4.p4client.ApplyMeterEntries(p4.Update_MODIFY, uplinkMeterEntry, downlinkMeterEntry) if err != nil { @@ -1140,15 +1082,11 @@ func (up4 *UP4) configureSessionMeter(q qer) (meter, error) { } func (up4 *UP4) configureMeters(qers []qer) error { - log.WithFields(log.Fields{ - "qers": qers, - }).Debug("Configuring P4 Meters based on QERs") + logger.PfcpLog.With("qers", qers).Debugln("configuring P4 Meters based on QERs") for _, qer := range qers { - logger := log.WithFields(log.Fields{ - "qer": qer, - }) - logger.Debug("Configuring P4 Meter based on QER") + logger := logger.PfcpLog.With("qer", qer) + logger.Debugln("configuring P4 Meter based on QER") // TODO: In case we have GBR QER, then we are going to program only app-level rate-limiting // (i.e., SessQerId will always be 0). @@ -1178,8 +1116,7 @@ func (up4 *UP4) configureMeters(qers []qer) error { return ErrOperationFailedWithReason("configure P4 Meter from QER", err.Error()) } - logger = logger.WithField("P4 meter", p4Meter) - logger.Debug("P4 meter successfully configured!") + logger.With("P4 meter", p4Meter).Debugln("P4 meter successfully configured!") up4.meters[meterID{ qerID: qer.qerID, @@ -1218,27 +1155,23 @@ func (up4 *UP4) resetMeter(meterID uint32, meter meter) { err := up4.p4client.ApplyMeterEntries(p4.Update_MODIFY, entries...) if err != nil { - log.Errorf("Failed to reset %v meter entries: %v", p4constants.GetMeterIDToNameMap()[meterID], err) + logger.PfcpLog.Errorf("failed to reset %v meter entries: %v", p4constants.GetMeterIDToNameMap()[meterID], err) } } func (up4 *UP4) resetMeters(qers []qer) { - log.WithFields(log.Fields{ - "qers": qers, - }).Debug("Resetting P4 Meters") + logger.PfcpLog.With("qers", qers).Debug("resetting P4 Meters") for _, qer := range qers { - logger := log.WithFields(log.Fields{ - "qer": qer, - }) - logger.Debug("Resetting P4 Meter") + logger := logger.PfcpLog.With("qer", qer) + logger.Debugln("resetting P4 Meter") p4Meter, exists := up4.meters[meterID{ qerID: qer.qerID, fseid: qer.fseID, }] if !exists { - logger.Error("P4 meter for QER ID not found, cannot reset!") + logger.Errorln("P4 meter for QER ID not found, cannot reset!") continue } @@ -1255,8 +1188,8 @@ func (up4 *UP4) resetMeters(qers []qer) { up4.releaseSessionMeterCellID(p4Meter.downlinkCellID) } - logger = logger.WithField("P4 meter", p4Meter) - logger.Debug("Removing P4 meter from allocated meters pool") + logger = logger.With("P4 meter", p4Meter) + logger.Debugln("removing P4 meter from allocated meters pool") delete(up4.meters, meterID{ qerID: qer.qerID, @@ -1266,12 +1199,8 @@ func (up4 *UP4) resetMeters(qers []qer) { } func (up4 *UP4) resetCounter(pdr pdr) error { - builderLog := log.WithFields(log.Fields{ - "Cell ID": pdr.ctrID, - "PDR ID": pdr.pdrID, - "F-SEID": pdr.fseID, - }) - builderLog.Debug("Clearing Counter cells") + builderLog := logger.PfcpLog.With("Cell ID", pdr.ctrID, "PDR ID", pdr.pdrID, "F-SEID", pdr.fseID) + builderLog.Debugln("clearing counter cells") resetValue := &p4.CounterData{ ByteCount: 0, @@ -1327,18 +1256,16 @@ func (up4 *UP4) modifyUP4ForwardingConfiguration(pdrs []pdr, allFARs []far, qers entriesToApply := make([]*p4.TableEntry, 0) - pdrLog := log.WithFields(log.Fields{ - "pdr": pdr, - }) - pdrLog.Debug("Installing P4 table entries for PDR") + pdrLog := logger.PfcpLog.With("pdr", pdr) + pdrLog.Debugln("installing P4 table entries for PDR") FAR, err = findRelatedFAR(pdr, allFARs) if err != nil { - pdrLog.Warning("no related FAR for PDR found: ", err) + pdrLog.Warnln("no related FAR for PDR found:", err) return err } - pdrLog = pdrLog.WithField("related FAR", FAR) - pdrLog.Debug("Found related FAR for PDR") + pdrLog = pdrLog.With("related FAR", FAR) + pdrLog.Debugln("found related FAR for PDR") tunnelParameters := tunnelParams{ tunnelIP4Src: ip2int(up4.accessIP.IP), @@ -1372,7 +1299,7 @@ func (up4 *UP4) modifyUP4ForwardingConfiguration(pdrs []pdr, allFARs []far, qers ueAddr, exists = up4.fseidToUEAddr[pdr.fseID] if !exists { // this is only possible if a linked DL PDR was not provided in the same PFCP Establishment message - log.Error("UE Address not found for uplink PDR, a linked DL PDR was not provided?") + logger.PfcpLog.Errorln("UE Address not found for uplink PDR, a linked DL PDR was not provided?") return ErrOperationFailedWithReason("adding UP4 entries", "UE Address not found for uplink PDR, a linked DL PDR was not provided?") } @@ -1410,16 +1337,16 @@ func (up4 *UP4) modifyUP4ForwardingConfiguration(pdrs []pdr, allFARs []far, qers qerID: pdr.qerIDList[0], fseid: pdr.fseID, }] - pdrLog.Debug("Application meter found for PDR: ", appMeter) + pdrLog.Debug("Application meter found for PDR:", appMeter) } var qfi uint8 = DefaultQFI relatedQER, err := findRelatedApplicationQER(pdr, qers) if err != nil { - pdrLog.Warning(err) + pdrLog.Warnln(err) } else { - pdrLog.Debug("Related QER found for PDR: ", relatedQER) + pdrLog.Debugln("related QER found for PDR:", relatedQER) qfi = relatedQER.qfi } @@ -1436,11 +1363,8 @@ func (up4 *UP4) modifyUP4ForwardingConfiguration(pdrs []pdr, allFARs []far, qers entriesToApply = append(entriesToApply, terminationsEntry) - pdrLog = pdrLog.WithFields(log.Fields{ - "entries": entriesToApply, - "method type": p4.Update_Type_name[int32(methodType)], - }) - pdrLog.Debug("Applying table entries") + pdrLog = pdrLog.With("entries", entriesToApply, "method type", p4.Update_Type_name[int32(methodType)]) + pdrLog.Debugln("applying table entries") err = up4.p4client.ApplyTableEntries(methodType, entriesToApply...) if err != nil { @@ -1543,16 +1467,12 @@ func (up4 *UP4) sendDelete(deleted PacketForwardingRules) error { func (up4 *UP4) SendMsgToUPF(method upfMsgType, all PacketForwardingRules, updated PacketForwardingRules) uint8 { err := up4.tryConnect() if err != nil { - log.Error("UP4 server not connected") + logger.PfcpLog.Errorln("UP4 server not connected") return ie.CauseRequestRejected } - up4Log := log.WithFields(log.Fields{ - "method-type": method, - "all": all, - "updated-rules": updated, - }) - up4Log.Debug("Sending PFCP message to UP4..") + up4Log := logger.PfcpLog.With("method-type", method, "all", all, "updated-rules", updated) + up4Log.Debugln("sending PFCP message to UP4..") switch method { case upfMsgTypeAdd: diff --git a/pfcpiface/upf.go b/pfcpiface/upf.go index 55cc05784..82e22bc41 100644 --- a/pfcpiface/upf.go +++ b/pfcpiface/upf.go @@ -8,7 +8,7 @@ import ( "time" "github.com/Showmax/go-fqdn" - log "github.com/sirupsen/logrus" + "github.com/omec-project/upf-epc/logger" ) // QosConfigVal : Qos configured value. @@ -41,6 +41,7 @@ type upf struct { accessIface string coreIface string ippoolCidr string + n4addr string accessIP net.IP coreIP net.IP nodeID string @@ -50,6 +51,7 @@ type upf struct { reportNotifyChan chan uint64 sliceInfo *SliceInfo readTimeout time.Duration + fteidGenerator *FTEIDGenerator datapath maxReqRetries uint8 @@ -99,7 +101,7 @@ func NewUPF(conf *Conf, fp datapath) *upf { if conf.CPIface.UseFQDN && nodeID == "" { nodeID, err = fqdn.FqdnHostname() if err != nil { - log.Fatalln("Unable to get hostname", err) + logger.PfcpLog.Fatalln("unable to get hostname", err) } } @@ -107,7 +109,7 @@ func NewUPF(conf *Conf, fp datapath) *upf { if nodeID != "" { hosts, err = net.LookupHost(nodeID) if err != nil { - log.Fatalln("Unable to resolve hostname", nodeID, err) + logger.PfcpLog.Fatalln("unable to resolve hostname", nodeID, err) } nodeID = hosts[0] @@ -128,6 +130,8 @@ func NewUPF(conf *Conf, fp datapath) *upf { maxReqRetries: conf.MaxReqRetries, enableHBTimer: conf.EnableHBTimer, readTimeout: time.Second * time.Duration(conf.ReadTimeout), + fteidGenerator: NewFTEIDGenerator(), + n4addr: conf.N4Addr, } if len(conf.CPIface.Peers) > 0 { @@ -135,34 +139,34 @@ func NewUPF(conf *Conf, fp datapath) *upf { nc := copy(u.peers, conf.CPIface.Peers) if nc == 0 { - log.Warnln("Failed to parse cpiface peers, PFCP Agent will not initiate connection to N4 peers.") + logger.PfcpLog.Warnln("failed to parse cpiface peers, PFCP Agent will not initiate connection to N4 peers.") } } if !conf.EnableP4rt { u.accessIP, err = GetUnicastAddressFromInterface(conf.AccessIface.IfName) if err != nil { - log.Errorln(err) + logger.PfcpLog.Errorln(err) return nil } u.coreIP, err = GetUnicastAddressFromInterface(conf.CoreIface.IfName) if err != nil { - log.Errorln(err) + logger.PfcpLog.Errorln(err) return nil } } u.respTimeout, err = time.ParseDuration(conf.RespTimeout) if err != nil { - log.Fatalln("Unable to parse resp_timeout") + logger.PfcpLog.Fatalln("unable to parse resp_timeout") } if u.enableHBTimer { if conf.HeartBeatInterval != "" { u.hbInterval, err = time.ParseDuration(conf.HeartBeatInterval) if err != nil { - log.Fatalln("Unable to parse heart_beat_interval") + logger.PfcpLog.Fatalln("unable to parse heart_beat_interval") } } } @@ -170,7 +174,7 @@ func NewUPF(conf *Conf, fp datapath) *upf { if u.enableUeIPAlloc { u.ippool, err = NewIPPool(u.ippoolCidr) if err != nil { - log.Fatalln("ip pool init failed", err) + logger.PfcpLog.Fatalln("ip pool init failed", err) } } diff --git a/pfcpiface/utils.go b/pfcpiface/utils.go index 4248ecbd7..5b715305d 100644 --- a/pfcpiface/utils.go +++ b/pfcpiface/utils.go @@ -11,8 +11,7 @@ import ( "strings" "github.com/omec-project/upf-epc/internal/p4constants" - - log "github.com/sirupsen/logrus" + "github.com/omec-project/upf-epc/logger" ) // Bits type. @@ -31,6 +30,13 @@ func setUeipFeature(features ...uint8) { } } +// Set the 5th bit of the first octet to 1. +func setFTUPFeature(features ...uint8) { + if len(features) >= 1 { + features[0] = features[0] | 0x10 + } +} + func setEndMarkerFeature(features ...uint8) { if len(features) >= 2 { features[1] = features[1] | 0x01 @@ -104,10 +110,10 @@ func calcBurstSizeFromRate(kbps uint64, ms uint64) uint64 { func MustParseStrIP(address string) *net.IPNet { ip, ipNet, err := net.ParseCIDR(address) if err != nil { - log.Fatalf("unable to parse IP %v that we should parse", address) + logger.PfcpLog.Fatalf("unable to parse IP %v that we should parse", address) } - log.Info("Parsed IP: ", ip) + logger.PfcpLog.Infoln("parsed IP:", ip) return ipNet } diff --git a/pfcpiface/utils_test.go b/pfcpiface/utils_test.go index a5df2e659..8032a9f03 100644 --- a/pfcpiface/utils_test.go +++ b/pfcpiface/utils_test.go @@ -5,6 +5,7 @@ package pfcpiface import ( "github.com/stretchr/testify/require" + "github.com/wmnsk/go-pfcp/ie" "net" "reflect" @@ -91,3 +92,27 @@ func TestGetSliceTcMeterIndex(t *testing.T) { ) } } + +func TestSetUeipFeature(t *testing.T) { + features := make([]uint8, 4) + + setUeipFeature(features...) + + ie := ie.NewUPFunctionFeatures(features...) + hasUeIPAlloc := ie.HasUEIP() + if !hasUeIPAlloc { + t.Errorf("Expected UEIPAlloc to be set") + } +} + +func TestSetFTUPFeature(t *testing.T) { + features := make([]uint8, 4) + + setFTUPFeature(features...) + + ie := ie.NewUPFunctionFeatures(features...) + hasFTUP := ie.HasFTUP() + if !hasFTUP { + t.Errorf("Expected FTUP to be set") + } +} diff --git a/pfcpiface/web_service.go b/pfcpiface/web_service.go index f482f468d..f06704ddf 100644 --- a/pfcpiface/web_service.go +++ b/pfcpiface/web_service.go @@ -9,7 +9,7 @@ import ( "math" "net/http" - log "github.com/sirupsen/logrus" + "github.com/omec-project/upf-epc/logger" ) // NetworkSlice ... Config received for slice rates and DNN. @@ -44,7 +44,7 @@ func setupConfigHandler(mux *http.ServeMux, upf *upf) { } func (c *ConfigHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) { - log.Infoln("handle http request for /v1/config/network-slices") + logger.PfcpLog.Infoln("handle http request for /v1/config/network-slices") switch r.Method { case "PUT": @@ -52,24 +52,24 @@ func (c *ConfigHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) { case "POST": body, err := io.ReadAll(r.Body) if err != nil { - log.Errorln("http req read body failed.") + logger.PfcpLog.Errorln("http req read body failed") sendHTTPResp(http.StatusBadRequest, w) } - log.Traceln(string(body)) + logger.PfcpLog.Debugln(string(body)) var nwSlice NetworkSlice err = json.Unmarshal(body, &nwSlice) if err != nil { - log.Errorln("Json unmarshal failed for http request") + logger.PfcpLog.Errorln("Json unmarshal failed for http request") sendHTTPResp(http.StatusBadRequest, w) } handleSliceConfig(&nwSlice, c.upf) sendHTTPResp(http.StatusCreated, w) default: - log.Infoln(w, "Sorry, only PUT and POST methods are supported.") + logger.PfcpLog.Infoln(w, "sorry, only PUT and POST methods are supported") sendHTTPResp(http.StatusMethodNotAllowed, w) } } @@ -89,12 +89,12 @@ func sendHTTPResp(status int, w http.ResponseWriter) { jsonResp, err := json.Marshal(resp) if err != nil { - log.Errorln("Error happened in JSON marshal. Err: ", err) + logger.PfcpLog.Errorln("error happened in JSON marshal:", err) } _, err = w.Write(jsonResp) if err != nil { - log.Errorln("http response write failed : ", err) + logger.PfcpLog.Errorln("http response write failed:", err) } } @@ -123,7 +123,7 @@ func calculateBitRates(mbr uint64, rate string) uint64 { } func handleSliceConfig(nwSlice *NetworkSlice, upf *upf) { - log.Infoln("handle slice config : ", nwSlice.SliceName) + logger.PfcpLog.Infoln("handle slice config:", nwSlice.SliceName) ulMbr := calculateBitRates(nwSlice.SliceQos.UplinkMbr, nwSlice.SliceQos.BitrateUnit) @@ -150,6 +150,6 @@ func handleSliceConfig(nwSlice *NetworkSlice, upf *upf) { err := upf.addSliceInfo(&sliceInfo) if err != nil { - log.Errorln("adding slice info to datapath failed : ", err) + logger.PfcpLog.Errorln("adding slice info to datapath failed:", err) } } diff --git a/pkg/fake_bess/fake_bess.go b/pkg/fake_bess/fake_bess.go index 0e6e74ad6..821d83fd4 100644 --- a/pkg/fake_bess/fake_bess.go +++ b/pkg/fake_bess/fake_bess.go @@ -4,7 +4,6 @@ package fake_bess import ( - "fmt" "net" "github.com/omec-project/upf-epc/pfcpiface/bess_pb" @@ -26,7 +25,7 @@ func NewFakeBESS() *FakeBESS { // Run starts and runs the BESS gRPC server on the given address. Blocking until Stop is called. func (b *FakeBESS) Run(address string) error { - listener, err := net.Listen("tcp", fmt.Sprintf(address)) + listener, err := net.Listen("tcp", address) if err != nil { return err } diff --git a/pkg/fake_bess/fake_bess_service.go b/pkg/fake_bess/fake_bess_service.go index 4a01df7d0..7adf7b136 100644 --- a/pkg/fake_bess/fake_bess_service.go +++ b/pkg/fake_bess/fake_bess_service.go @@ -9,9 +9,9 @@ import ( "math" "sync" + "github.com/omec-project/upf-epc/logger" "github.com/omec-project/upf-epc/pfcpiface/bess_pb" "github.com/omec-project/upf-epc/pkg/utils" - log "github.com/sirupsen/logrus" "google.golang.org/grpc/codes" "google.golang.org/grpc/status" "google.golang.org/protobuf/proto" @@ -175,8 +175,8 @@ func (b *fakeBessService) unsafeGetOrAddModule(name string) module { } } else if name == appQerModuleName || name == sessionQerModuleName { b.modules[name] = &qosModule{ - baseModule{name: name}, - nil, + baseModule: baseModule{name: name}, + entries: nil, } } else if name == gtpuPathMonitoringModuleName { b.modules[name] = >puPathMonitoringModule{ @@ -184,7 +184,7 @@ func (b *fakeBessService) unsafeGetOrAddModule(name string) module { nil, } } else { - log.Fatalf("unknown module name: %v", name) + logger.BessLog.Fatalf("unknown module name: %v", name) } } return b.modules[name] @@ -333,7 +333,7 @@ func (w *wildcardModule) HandleRequest(cmd string, arg *anypb.Any) (err error) { return } - log := log.WithField("module", w.Name()).WithField("cmd", cmd) + log := logger.BessLog.With("module", w.Name(), "cmd", cmd) if cmd == addCmd { wc := &bess_pb.WildcardMatchCommandAddArg{} @@ -349,11 +349,11 @@ func (w *wildcardModule) HandleRequest(cmd string, arg *anypb.Any) (err error) { } } if existing != nil { - log.Tracef("updated existing entry %v", existing) + log.Debugf("updated existing entry %v", existing) existing.Reset() proto.Merge(existing, wc) } else { - log.Tracef("added new entry %v", wc) + log.Debugf("added new entry %v", wc) w.entries = append(w.entries, wc) } } else if cmd == deleteCmd { @@ -372,7 +372,7 @@ func (w *wildcardModule) HandleRequest(cmd string, arg *anypb.Any) (err error) { if idx == -1 { return status.Errorf(codes.NotFound, "entry not found: %v", wc) } else { - log.Tracef("deleted existing entry %v", w.entries[idx]) + log.Debugf("deleted existing entry %v", w.entries[idx]) w.entries = append(w.entries[:idx], w.entries[idx+1:]...) } } else if cmd == clearCmd { @@ -407,7 +407,7 @@ func (e *exactMatchModule) HandleRequest(cmd string, arg *anypb.Any) (err error) return } - log := log.WithField("module", e.Name()).WithField("cmd", cmd) + log := logger.BessLog.With("module", e.Name(), "cmd", cmd) if cmd == addCmd { em := &bess_pb.ExactMatchCommandAddArg{} @@ -422,11 +422,11 @@ func (e *exactMatchModule) HandleRequest(cmd string, arg *anypb.Any) (err error) } } if existing != nil { - log.Tracef("updated existing entry %v", em) + log.Debugf("updated existing entry %v", em) existing.Reset() proto.Merge(existing, em) } else { - log.Tracef("added new entry %v", em) + log.Debugf("added new entry %v", em) e.entries = append(e.entries, em) } } else if cmd == deleteCmd { @@ -444,7 +444,7 @@ func (e *exactMatchModule) HandleRequest(cmd string, arg *anypb.Any) (err error) if idx == -1 { return status.Errorf(codes.NotFound, "entry not found: %v", em) } else { - log.Tracef("deleted existing entry %v", e.entries[idx]) + log.Debugf("deleted existing entry %v", e.entries[idx]) e.entries = append(e.entries[:idx], e.entries[idx+1:]...) } } else if cmd == clearCmd { @@ -463,11 +463,14 @@ func (e *exactMatchModule) HandleRequest(cmd string, arg *anypb.Any) (err error) } type qosModule struct { + mutex sync.Mutex baseModule entries []*bess_pb.QosCommandAddArg } func (q *qosModule) GetState() (msgs []proto.Message) { + q.mutex.Lock() + defer q.mutex.Unlock() for _, em := range q.entries { msgs = append(msgs, em) } @@ -475,11 +478,13 @@ func (q *qosModule) GetState() (msgs []proto.Message) { } func (q *qosModule) HandleRequest(cmd string, arg *anypb.Any) (err error) { + q.mutex.Lock() + defer q.mutex.Unlock() if err = q.baseModule.HandleRequest(cmd, arg); err != nil { return } - log := log.WithField("module", q.Name()).WithField("cmd", cmd) + log := logger.BessLog.With("module", q.Name(), "cmd", cmd) if cmd == addCmd { wc := &bess_pb.QosCommandAddArg{} @@ -494,11 +499,11 @@ func (q *qosModule) HandleRequest(cmd string, arg *anypb.Any) (err error) { } } if existing != nil { - log.Tracef("updated existing entry %v", existing) + log.Debugf("updated existing entry %v", existing) existing.Reset() proto.Merge(existing, wc) } else { - log.Tracef("added new entry %v", wc) + log.Debugf("added new entry %v", wc) q.entries = append(q.entries, wc) } } else if cmd == deleteCmd { @@ -516,7 +521,7 @@ func (q *qosModule) HandleRequest(cmd string, arg *anypb.Any) (err error) { if idx == -1 { return status.Errorf(codes.NotFound, "entry not found: %v", qc) } else { - log.Tracef("deleted existing entry %v", q.entries[idx]) + log.Debugf("deleted existing entry %v", q.entries[idx]) q.entries = append(q.entries[:idx], q.entries[idx+1:]...) } } else if cmd == clearCmd { @@ -551,7 +556,7 @@ func (q *gtpuPathMonitoringModule) HandleRequest(cmd string, arg *anypb.Any) (er return } - log := log.WithField("module", q.Name()).WithField("cmd", cmd) + log := logger.BessLog.With("module", q.Name(), "cmd", cmd) if cmd == addCmd { wc := &bess_pb.GtpuPathMonitoringCommandAddDeleteArg{} @@ -566,11 +571,11 @@ func (q *gtpuPathMonitoringModule) HandleRequest(cmd string, arg *anypb.Any) (er } } if existing != nil { - log.Tracef("updated existing entry %v", existing) + log.Debugf("updated existing entry %v", existing) existing.Reset() proto.Merge(existing, wc) } else { - log.Tracef("added new entry %v", wc) + log.Debugf("added new entry %v", wc) q.entries = append(q.entries, wc) } } else if cmd == deleteCmd { @@ -588,7 +593,7 @@ func (q *gtpuPathMonitoringModule) HandleRequest(cmd string, arg *anypb.Any) (er if idx == -1 { return status.Errorf(codes.NotFound, "entry not found: %v", qc) } else { - log.Tracef("deleted existing entry %v", q.entries[idx]) + log.Debugf("deleted existing entry %v", q.entries[idx]) q.entries = append(q.entries[:idx], q.entries[idx+1:]...) } } else if cmd == clearCmd { diff --git a/ptf/Dockerfile b/ptf/Dockerfile index d59cd72dd..efd2061c6 100644 --- a/ptf/Dockerfile +++ b/ptf/Dockerfile @@ -35,7 +35,7 @@ RUN pip3 install --no-cache-dir --root /python_output \ unittest-xml-reporting==$UNITTEST_XML_REPORTING_VER # Install TRex traffic gen and library for TRex API -FROM alpine:3.20.2 AS trex-builder +FROM alpine:3.20.3 AS trex-builder ARG TREX_VER ARG TREX_EXT_LIBS ARG TREX_LIBS diff --git a/test/integration/basic_test.go b/test/integration/basic_test.go index 0e8e64df9..aac67c9ba 100644 --- a/test/integration/basic_test.go +++ b/test/integration/basic_test.go @@ -83,7 +83,7 @@ func TestUPFBasedUeIPAllocation(t *testing.T) { WithDownlinkIP(testcase.input.nbAddress).BuildFAR(), } - err := pfcpClient.SendSessionEstablishmentRequest(pdrs, fars, nil) + err := pfcpClient.SendSessionEstablishmentRequest(pdrs, fars, nil, nil) require.NoError(t, err) resp, err := pfcpClient.PeekNextResponse() @@ -161,6 +161,9 @@ func TestDetectUP4Restart(t *testing.T) { WithDownlinkMBR(500000). WithUplinkGBR(0). WithDownlinkGBR(0).Build(), + }, []*ie.IE{ + session.NewURRBuilder().WithMethod(session.Create).WithID(1). + WithMeasurementMethod(1, 1, 1).WithReportingTrigger(session.ReportingTrigger{Flags: 1}).Build(), }) } @@ -614,7 +617,7 @@ func testUEAttach(t *testing.T, testcase *testCase) { )) } - sess, err := pfcpClient.EstablishSession(pdrs, fars, qers) + sess, err := pfcpClient.EstablishSession(pdrs, fars, qers, nil) testcase.expected.pdrs = pdrs testcase.expected.fars = fars testcase.expected.qers = qers @@ -628,7 +631,7 @@ func testUEAttach(t *testing.T, testcase *testCase) { WithMethod(session.Update).WithID(2). WithAction(ActionForward).WithDstInterface(ie.DstInterfaceAccess). WithTEID(testcase.input.dlTEID).WithDownlinkIP(testcase.input.nbAddress).BuildFAR(), - }, nil) + }, nil, nil) verifyEntries(t, testcase.input, testcase.expected, UEStateAttached) } @@ -643,7 +646,7 @@ func testUEBuffer(t *testing.T, testcase *testCase) { WithDownlinkIP(testcase.input.nbAddress).BuildFAR(), } - err := pfcpClient.ModifySession(testcase.session, nil, fars, nil) + err := pfcpClient.ModifySession(testcase.session, nil, fars, nil, nil) require.NoError(t, err) verifyEntries(t, testcase.input, testcase.expected, UEStateBuffering) @@ -657,7 +660,7 @@ func testUEBuffer(t *testing.T, testcase *testCase) { WithDownlinkIP(testcase.input.nbAddress).BuildFAR(), } - err = pfcpClient.ModifySession(testcase.session, nil, fars, nil) + err = pfcpClient.ModifySession(testcase.session, nil, fars, nil, nil) require.NoError(t, err) verifyEntries(t, testcase.input, testcase.expected, UEStateAttached) diff --git a/test/integration/conf.go b/test/integration/conf.go index 9021497e8..8e1bf7e1d 100644 --- a/test/integration/conf.go +++ b/test/integration/conf.go @@ -11,7 +11,7 @@ import ( "runtime" "github.com/omec-project/upf-epc/pfcpiface" - "github.com/sirupsen/logrus" + "go.uber.org/zap" ) const ( @@ -28,7 +28,7 @@ const ( var baseConfig = pfcpiface.Conf{ ReadTimeout: 15, RespTimeout: "2s", - LogLevel: logrus.TraceLevel, + LogLevel: zap.InfoLevel, } func BESSConfigDefault() pfcpiface.Conf { @@ -128,7 +128,7 @@ func GetConfig(datapath string, configType uint32) pfcpiface.Conf { } } - panic("Wrong datapath or config type provided") + panic("wrong datapath or config type provided") } func PushSliceMeterConfig(sliceConfig pfcpiface.NetworkSlice) error { @@ -137,7 +137,7 @@ func PushSliceMeterConfig(sliceConfig pfcpiface.NetworkSlice) error { return err } - _, err = http.Post("http://127.0.0.1:8080/v1/config/network-slices", "application/json", bytes.NewBuffer(rawSliceConfig)) + _, err = http.Post("http://127.0.0.8:8080/v1/config/network-slices", "application/json", bytes.NewBuffer(rawSliceConfig)) if err != nil { return err } diff --git a/test/integration/framework.go b/test/integration/framework.go index 695003373..766ca537d 100644 --- a/test/integration/framework.go +++ b/test/integration/framework.go @@ -13,14 +13,15 @@ import ( "github.com/omec-project/pfcpsim/pkg/pfcpsim" "github.com/omec-project/upf-epc/internal/p4constants" + "github.com/omec-project/upf-epc/logger" "github.com/omec-project/upf-epc/pfcpiface" "github.com/omec-project/upf-epc/pkg/fake_bess" "github.com/omec-project/upf-epc/test/integration/providers" v1 "github.com/p4lang/p4runtime/go/p4/v1" "github.com/prometheus/client_golang/prometheus" - "github.com/sirupsen/logrus" "github.com/stretchr/testify/require" "github.com/wmnsk/go-pfcp/ie" + "go.uber.org/zap" ) // this file should contain all the struct defs/constants used among different test cases. @@ -154,13 +155,7 @@ type testCase struct { } func init() { - logrus.SetLevel(logrus.TraceLevel) - logrus.SetReportCaller(true) - logrus.SetFormatter(&logrus.TextFormatter{ - FullTimestamp: true, - ForceColors: true, - }) - + logger.SetLogLevel(zap.DebugLevel) providers.MustPullDockerImage(ImageNameMockUP4) providers.MustCreateNetworkIfNotExists(DockerTestNetwork) } @@ -286,7 +281,7 @@ func mustInitCountersWithDummyValue() { } func MustStartMockUP4() { - providers.MustRunDockerContainer(ContainerNameMockUP4, ImageNameMockUP4, "--topo single", []string{"50001/tcp"}, "", DockerTestNetwork) + providers.MustRunDockerContainer(ContainerNameMockUP4, ImageNameMockUP4, "--topo single", "127.0.0.1", []string{"50001/tcp"}, "", DockerTestNetwork) err := waitForMockUP4ToStart() if err != nil { panic(err) @@ -301,7 +296,7 @@ func MustStopMockUP4() { func MustStartPFCPAgent() { providers.MustRunDockerContainer(ContainerNamePFCPAgent, ImageNamePFCPAgent, "-config /config/upf.jsonc", - []string{"8805/udp", "8080/tcp"}, "/tmp:/config", DockerTestNetwork) + "127.0.0.8", []string{"8805/udp", "8080/tcp"}, "/tmp:/config", DockerTestNetwork) } func MustStopPFCPAgent() { @@ -335,14 +330,16 @@ func setup(t *testing.T, configType uint32) { require.NoError(t, err) MustStartPFCPAgent() case ModeNative: - pfcpAgent = pfcpiface.NewPFCPIface(GetConfig(os.Getenv(EnvDatapath), configType)) + upfConf := GetConfig(os.Getenv(EnvDatapath), configType) + upfConf.N4Addr = "127.0.0.8" + pfcpAgent = pfcpiface.NewPFCPIface(upfConf) go pfcpAgent.Run() default: t.Fatal("Unexpected test mode") } pfcpClient = pfcpsim.NewPFCPClient("127.0.0.1") - err := pfcpClient.ConnectN4("127.0.0.1") + err := pfcpClient.ConnectN4("127.0.0.8") require.NoErrorf(t, err, "failed to connect to UPF") // wait for PFCP Agent to initialize, blocking diff --git a/test/integration/providers/docker.go b/test/integration/providers/docker.go index 7637c0ff6..503dd3820 100644 --- a/test/integration/providers/docker.go +++ b/test/integration/providers/docker.go @@ -8,7 +8,6 @@ import ( "errors" "fmt" "io" - "log" "os/exec" "strings" "time" @@ -20,7 +19,7 @@ import ( "github.com/docker/docker/api/types/network" "github.com/docker/docker/client" "github.com/docker/go-connections/nat" - "github.com/sirupsen/logrus" + "github.com/omec-project/upf-epc/logger" ) // MustRunDockerCommandAttach attaches to a running Docker container and executes a cmd. @@ -41,14 +40,14 @@ func MustRunDockerCommandAttach(containerName string, cmd string) { Stream: true, }) if err != nil { - logrus.Fatalf("Failed to attach container: %v", err) + logger.DockerLog.Fatalf("failed to attach container: %v", err) } defer waiter.Close() if err = waiter.Conn.SetWriteDeadline(time.Now().Add(time.Second * 1)); err != nil { - logrus.Fatalf("Failed to set deadline: %v", err) + logger.DockerLog.Fatalf("failed to set deadline: %v", err) } if _, err = waiter.Conn.Write(append([]byte(cmd), '\n')); err != nil { - logrus.Fatalf("Failed to write to container: %v", err) + logger.DockerLog.Fatalf("failed to write to container: %v", err) } } @@ -105,7 +104,7 @@ func MustCreateNetworkIfNotExists(name string) { allNetworks, err := cli.NetworkList(ctx, types.NetworkListOptions{}) if err != nil { - log.Fatalf("Failed to check if network exists: %v", err) + logger.DockerLog.Fatalf("failed to check if network exists: %v", err) } for _, net := range allNetworks { @@ -160,7 +159,7 @@ func WaitForContainerRunning(name string) error { // - exposedPorts specifies the list of L4 ports to expose. The format should be port_no/proto (e.g., 8080/tcp). It's optional. // - mnt defines the mount paths. The format should be `:`. It's optional. // - net defines a Docker network for a container (optional). -func MustRunDockerContainer(name, image, cmd string, exposedPorts []string, mnt string, net string) { +func MustRunDockerContainer(name, image, cmd string, hostIp string, exposedPorts []string, mnt string, net string) { ctx := context.Background() cli, err := client.NewClientWithOpts(client.FromEnv, client.WithAPIVersionNegotiation()) if err != nil { @@ -200,7 +199,7 @@ func MustRunDockerContainer(name, image, cmd string, exposedPorts []string, mnt for _, port := range exposedPorts { baseCfg.ExposedPorts[nat.Port(port)] = struct{}{} hostCfg.PortBindings[nat.Port(port)] = []nat.PortBinding{{ - HostIP: "127.0.0.1", + HostIP: hostIp, HostPort: port, }} } @@ -238,14 +237,14 @@ func MustStopDockerContainer(name string) { err = cli.ContainerKill(ctx, name, "SIGKILL") if err != nil { - logrus.Fatalf("Failed to stop Docker container %s: %v", name, err) + logger.DockerLog.Fatalf("failed to stop Docker container %s: %v", name, err) } err = cli.ContainerRemove(ctx, name, container.RemoveOptions{ Force: true, }) if err != nil { - logrus.Fatalf("Failed to stop Docker container %s: %v", name, err) + logger.DockerLog.Fatalf("failed to stop Docker container %s: %v", name, err) } }