diff --git a/.fossa.yml b/.fossa.yml deleted file mode 100644 index 5b089ecd..00000000 --- a/.fossa.yml +++ /dev/null @@ -1,20 +0,0 @@ -# SPDX-FileCopyrightText: 2021 Open Networking Foundation -# -# SPDX-License-Identifier: Apache-2.0 -# -# Generated by FOSSA CLI (https://github.com/fossas/fossa-cli) -# Visit https://fossa.com to learn more -# -# Usage: FOSSA_API_KEY=<> fossa analyze -# -T is not supported at this moment from fossa side. -version: 2 -cli: - server: https://app.fossa.com - fetcher: custom - project: smf -analyze: - modules: - - name: smf - type: raw - target: ../smf - path: ../smf diff --git a/VERSION b/VERSION index 1401eaf8..dc1e644a 100644 --- a/VERSION +++ b/VERSION @@ -1 +1 @@ -1.5.4-dev +1.6.0 diff --git a/callback/api_default.go b/callback/api_default.go index 5ce417a8..89629d3b 100644 --- a/callback/api_default.go +++ b/callback/api_default.go @@ -15,7 +15,6 @@ package callback import ( - "log" "net/http" "github.com/gin-gonic/gin" @@ -38,14 +37,14 @@ func HTTPSmPolicyUpdateNotification(c *gin.Context) { err := openapi.Deserialize(&request, reqBody, c.ContentType()) if err != nil { - logger.PduSessLog.Errorln("Deserialize request failed") + logger.PduSessLog.Errorln("deserialize request failed") } reqWrapper := httpwrapper.NewRequest(c.Request, request) reqWrapper.Params["smContextRef"] = c.Params.ByName("smContextRef") smContextRef := reqWrapper.Params["smContextRef"] - log.Printf("HTTPSmPolicyUpdateNotification received for UUID = %v", smContextRef) + logger.PduSessLog.Infof("HTTPSmPolicyUpdateNotification received for UUID = %v", smContextRef) txn := transaction.NewTransaction(reqWrapper.Body.(models.SmPolicyNotification), nil, svcmsgtypes.SmfMsgType(svcmsgtypes.SmPolicyUpdateNotification)) txn.CtxtKey = smContextRef @@ -60,7 +59,7 @@ func HTTPSmPolicyUpdateNotification(c *gin.Context) { resBody, err := openapi.Serialize(HTTPResponse.Body, "application/json") if err != nil { - log.Println(err) + logger.PduSessLog.Errorln(err) } c.Writer.Write(resBody) c.Status(HTTPResponse.Status) @@ -71,7 +70,7 @@ func SmPolicyControlTerminationRequestNotification(c *gin.Context) { } func N1N2FailureNotification(c *gin.Context) { - logger.PduSessLog.Info("Receive N1N2 Failure Notification") + logger.PduSessLog.Info("receive N1N2 Failure Notification") stats.IncrementN11MsgStats(smf_context.SMF_Self().NfInstanceID, string(svcmsgtypes.N1N2MessageTransferFailureNotification), "In", "", "") var request models.N1N2MsgTxfrFailureNotification diff --git a/callback/routers.go b/callback/routers.go index 4565ea67..ac038ba8 100644 --- a/callback/routers.go +++ b/callback/routers.go @@ -37,7 +37,7 @@ type Routes []Route // NewRouter returns a new router. func NewRouter() *gin.Engine { - router := utilLogger.NewGinWithLogrus(logger.GinLog) + router := utilLogger.NewGinWithZap(logger.GinLog) AddService(router) return router } diff --git a/consumer/nnrf.go b/consumer/nnrf.go index bd7d90ce..c9ffcc48 100644 --- a/consumer/nnrf.go +++ b/consumer/nnrf.go @@ -32,7 +32,7 @@ func SendNFRegistration() (*models.NfProfile, error) { sNssais := []models.Snssai{} if len(*smf_context.SmfInfo.SNssaiSmfInfoList) == 0 { - logger.ConsumerLog.Errorf("slice info not available, dropping NRF registration") + logger.ConsumerLog.Errorln("slice info not available, dropping NRF registration") return &rep, fmt.Errorf("slice info nil") } @@ -92,7 +92,6 @@ func SendNFRegistration() (*models.NfProfile, error) { logger.ConsumerLog.Infof("NRF Registration success, status [%v]", http.StatusText(res.StatusCode)) } else { logger.ConsumerLog.Infof("handler returned wrong status code %d", status) - // fmt.Errorf("NRF return wrong status code %d", status) logger.ConsumerLog.Errorf("NRF Registration failure, status [%v]", http.StatusText(res.StatusCode)) return &rep, fmt.Errorf("NRF Registration failure, [%v]", http.StatusText(res.StatusCode)) } @@ -105,7 +104,7 @@ func ReSendNFRegistration() (profile *models.NfProfile) { for { var err error if profile, err = SendNFRegistration(); err != nil { - logger.ConsumerLog.Warnf("Send NFRegistration Failed, %v", err) + logger.ConsumerLog.Warnf("send NFRegistration Failed, %v", err) time.Sleep(time.Second * 2) continue } @@ -114,7 +113,7 @@ func ReSendNFRegistration() (profile *models.NfProfile) { } var SendUpdateNFInstance = func(patchItem []models.PatchItem) (nfProfile *models.NfProfile, problemDetails *models.ProblemDetails, err error) { - logger.ConsumerLog.Debugf("Send Update NFInstance") + logger.ConsumerLog.Debugln("send Update NFInstance") smfSelf := smf_context.SMF_Self() configuration := Nnrf_NFManagement.NewConfiguration() @@ -164,7 +163,7 @@ func SendNFDeregistration() error { if res != nil { metrics.IncrementSvcNrfMsgStats(smf_context.SMF_Self().NfInstanceID, string(svcmsgtypes.NnrfNFRegister), "In", http.StatusText(res.StatusCode), "") if status := res.StatusCode; status != http.StatusNoContent { - logger.ConsumerLog.Warnln("handler returned wrong status code ", status) + logger.ConsumerLog.Warnln("handler returned wrong status code", status) return openapi.ReportError("handler returned wrong status code %d", status) } } @@ -216,7 +215,7 @@ func SendNrfForNfInstance(nrfUri string, targetNfType, requestNfType models.NfTy } }() - logger.ConsumerLog.Warnln("handler returned wrong status code ", httpResp.Status) + logger.ConsumerLog.Warnln("handler returned wrong status code", httpResp.Status) if httpResp.Status != localErr.Error() { metrics.IncrementSvcNrfMsgStats(smf_context.SMF_Self().NfInstanceID, string(svcMsgType), "In", http.StatusText(httpResp.StatusCode), httpResp.Status) } else { @@ -243,7 +242,7 @@ func SendNrfForNfInstance(nrfUri string, targetNfType, requestNfType models.NfTy if problemDetails != nil { logger.ConsumerLog.Errorf("SendCreateSubscription to NRF, Problem[%+v]", problemDetails) } else if err != nil { - logger.ConsumerLog.Errorf("SendCreateSubscription Error[%+v]", err) + logger.ConsumerLog.Errorf("SendCreateSubscription error[%+v]", err) } smfSelf.NfStatusSubscriptions.Store(nfProfile.NfInstanceId, nrfSubData.SubscriptionId) } @@ -302,7 +301,7 @@ func SendNFDiscoveryPCF() (problemDetails *models.ProblemDetails, err error) { } if localErr == nil { - logger.ConsumerLog.Traceln(result.NfInstances) + logger.ConsumerLog.Debugln(result.NfInstances) } else { apiError, ok := localErr.(openapi.GenericOpenAPIError) if ok { @@ -349,7 +348,7 @@ func SendNFDiscoveryServingAMF(smContext *smf_context.SMContext) (*models.Proble } func SendDeregisterNFInstance() (*models.ProblemDetails, error) { - logger.ConsumerLog.Infof("Send Deregister NFInstance") + logger.ConsumerLog.Infof("send deregister NFInstance") smfSelf := smf_context.SMF_Self() // Set client and set url @@ -382,7 +381,7 @@ func SendDeregisterNFInstance() (*models.ProblemDetails, error) { } func SendCreateSubscription(nrfUri string, nrfSubscriptionData models.NrfSubscriptionData, targetNfType models.NfType) (nrfSubData models.NrfSubscriptionData, problemDetails *models.ProblemDetails, err error) { - logger.ConsumerLog.Debugf("Send Create Subscription for %v", targetNfType) + logger.ConsumerLog.Debugf("send Create Subscription for %v", targetNfType) var res *http.Response nrfSubData, res, err = smf_context.SMF_Self().NFManagementClient.SubscriptionsCollectionApi.CreateSubscription(context.TODO(), nrfSubscriptionData) @@ -407,7 +406,7 @@ func SendCreateSubscription(nrfUri string, nrfSubscriptionData models.NrfSubscri } func SendRemoveSubscriptionProcedure(notificationData models.NotificationData) { - logger.ConsumerLog.Infof("[SMF] Send Remove Subscription Procedure") + logger.ConsumerLog.Infoln("[SMF] Send Remove Subscription Procedure") nfInstanceId := notificationData.NfInstanceUri[strings.LastIndex(notificationData.NfInstanceUri, "/")+1:] if subscriptionId, ok := smf_context.SMF_Self().NfStatusSubscriptions.Load(nfInstanceId); ok { diff --git a/consumer/nsmf_pdusession_callback.go b/consumer/nsmf_pdusession_callback.go index ff44d5d3..c8ed33d6 100644 --- a/consumer/nsmf_pdusession_callback.go +++ b/consumer/nsmf_pdusession_callback.go @@ -33,7 +33,7 @@ func SendSMContextStatusNotification(uri string) (*models.ProblemDetails, error) return nil, openapi.ReportError("Send SMContextStatus Notification Failed") } - logger.PduSessLog.Tracef("Send SMContextStatus Notification Success") + logger.PduSessLog.Debugln("send SMContextStatus Notification Success") } else if httpResp != nil { defer func() { if resCloseErr := httpResp.Body.Close(); resCloseErr != nil { @@ -47,7 +47,7 @@ func SendSMContextStatusNotification(uri string) (*models.ProblemDetails, error) problem := localErr.(openapi.GenericOpenAPIError).Model().(models.ProblemDetails) return &problem, nil } else { - logger.PduSessLog.Warnln("Http Response is nil in comsumer API SMContextNotification") + logger.PduSessLog.Warnln("http response is nil in comsumer API SMContextNotification") return nil, openapi.ReportError("Send SMContextStatus Notification Failed[%s]", localErr.Error()) } } diff --git a/context/datapath.go b/context/datapath.go index 840e4b3b..3167a165 100644 --- a/context/datapath.go +++ b/context/datapath.go @@ -116,7 +116,7 @@ func (node *DataPathNode) ActivateUpLinkTunnel(smContext *SMContext) error { var err error var pdr *PDR var flowQer *QER - logger.CtxLog.Traceln("In ActivateUpLinkTunnel") + logger.CtxLog.Debugln("in ActivateUpLinkTunnel") node.UpLinkTunnel.SrcEndPoint = node.Prev() node.UpLinkTunnel.DestEndPoint = node @@ -141,8 +141,8 @@ func (node *DataPathNode) ActivateUpLinkTunnel(smContext *SMContext) error { } else { // Default PDR if pdr, err = destUPF.AddPDR(); err != nil { - logger.CtxLog.Errorln("In ActivateUpLinkTunnel UPF IP: ", node.UPF.NodeID.ResolveNodeIdToIp().String()) - logger.CtxLog.Errorln("Allocate PDR Error: ", err) + logger.CtxLog.Errorln("in ActivateUpLinkTunnel UPF IP:", node.UPF.NodeID.ResolveNodeIdToIp().String()) + logger.CtxLog.Errorln("allocate PDR error:", err) return fmt.Errorf("add PDR failed: %s", err) } else { node.UpLinkTunnel.PDR["default"] = pdr @@ -150,7 +150,7 @@ func (node *DataPathNode) ActivateUpLinkTunnel(smContext *SMContext) error { } if err = smContext.PutPDRtoPFCPSession(destUPF.NodeID, node.UpLinkTunnel.PDR); err != nil { - logger.CtxLog.Errorln("Put PDR Error: ", err) + logger.CtxLog.Errorln("put PDR Error:", err) return err } @@ -165,7 +165,7 @@ func (node *DataPathNode) ActivateUpLinkTunnel(smContext *SMContext) error { teid, teidErr = destUPF.GenerateTEID() } if teidErr != nil { - logger.CtxLog.Errorf("Generate uplink TEID fail: %s", teidErr) + logger.CtxLog.Errorf("generate uplink TEID fail: %s", teidErr) return teidErr } else { node.UpLinkTunnel.TEID = teid @@ -199,8 +199,8 @@ func (node *DataPathNode) ActivateDownLinkTunnel(smContext *SMContext) error { } else { // Default PDR if pdr, err = destUPF.AddPDR(); err != nil { - logger.CtxLog.Errorln("In ActivateDownLinkTunnel UPF IP: ", node.UPF.NodeID.ResolveNodeIdToIp().String()) - logger.CtxLog.Errorln("Allocate PDR Error: ", err) + logger.CtxLog.Errorln("in ActivateDownLinkTunnel UPF IP:", node.UPF.NodeID.ResolveNodeIdToIp().String()) + logger.CtxLog.Errorln("allocate PDR Error:", err) return fmt.Errorf("add PDR failed: %s", err) } else { node.DownLinkTunnel.PDR["default"] = pdr @@ -209,7 +209,7 @@ func (node *DataPathNode) ActivateDownLinkTunnel(smContext *SMContext) error { // Put PDRs in PFCP session if err = smContext.PutPDRtoPFCPSession(destUPF.NodeID, node.DownLinkTunnel.PDR); err != nil { - logger.CtxLog.Errorln("Put PDR Error: ", err) + logger.CtxLog.Errorln("put PDR error:", err) return err } @@ -225,7 +225,7 @@ func (node *DataPathNode) ActivateDownLinkTunnel(smContext *SMContext) error { teid, teidErr = destUPF.GenerateTEID() } if teidErr != nil { - logger.CtxLog.Errorf("Generate downlink TEID fail: %s", teidErr) + logger.CtxLog.Errorf("generate downlink TEID fail: %s", teidErr) return teidErr } else { node.DownLinkTunnel.TEID = teid @@ -426,7 +426,7 @@ func (dataPath *DataPath) String() string { func (dataPath *DataPath) validateDataPathUpfStatus() error { firstDPNode := dataPath.FirstDPNode for curDataPathNode := firstDPNode; curDataPathNode != nil; curDataPathNode = curDataPathNode.Next() { - logger.PduSessLog.Infof("Nodes in Data Path [%v] and status [%v]", + logger.PduSessLog.Infof("nodes in Data Path [%v] and status [%v]", curDataPathNode.UPF.NodeID.ResolveNodeIdToIp().String(), curDataPathNode.UPF.UPFStatus.String()) if curDataPathNode.UPF.UPFStatus != AssociatedSetUpSuccess { logger.PduSessLog.Errorf("UPF [%v] in DataPath not associated", @@ -439,11 +439,11 @@ func (dataPath *DataPath) validateDataPathUpfStatus() error { func (dataPath *DataPath) ActivateUlDlTunnel(smContext *SMContext) error { firstDPNode := dataPath.FirstDPNode - logger.PduSessLog.Traceln("In ActivateTunnelAndPDR") - logger.PduSessLog.Traceln(dataPath.String()) + logger.PduSessLog.Debugln("in ActivateTunnelAndPDR") + logger.PduSessLog.Debugln(dataPath.String()) // Activate Tunnels for curDataPathNode := firstDPNode; curDataPathNode != nil; curDataPathNode = curDataPathNode.Next() { - logger.PduSessLog.Traceln("Current DP Node IP: ", curDataPathNode.UPF.NodeID.ResolveNodeIdToIp().String()) + logger.PduSessLog.Debugln("current DP Node IP:", curDataPathNode.UPF.NodeID.ResolveNodeIdToIp().String()) if err := curDataPathNode.ActivateUpLinkTunnel(smContext); err != nil { logger.CtxLog.Warnln(err) return err @@ -550,7 +550,7 @@ func (dpNode *DataPathNode) ActivateUpLinkPdr(smContext *SMContext, defQER *QER, } if upIP, err := iface.IP(smContext.SelectedPDUSessionType); err != nil { - logger.CtxLog.Errorf("activate UpLink PDR[%v] failed %v ", name, err) + logger.CtxLog.Errorf("activate UpLink PDR[%v] failed %v", name, err) return err } else { ULPDR.PDI.SourceInterface = SourceInterface{InterfaceValue: SourceInterfaceAccess} @@ -594,7 +594,7 @@ func (dpNode *DataPathNode) ActivateUpLinkPdr(smContext *SMContext, defQER *QER, iface = nextULTunnel.DestEndPoint.UPF.GetInterface(models.UpInterfaceType_N9, smContext.Dnn) if upIP, err := iface.IP(smContext.SelectedPDUSessionType); err != nil { - logger.CtxLog.Errorf("activate UpLink PDR[%v] failed %v ", name, err) + logger.CtxLog.Errorf("activate UpLink PDR[%v] failed %v", name, err) return err } else { ULFAR.ForwardingParameters.OuterHeaderCreation = &OuterHeaderCreation{ @@ -604,7 +604,7 @@ func (dpNode *DataPathNode) ActivateUpLinkPdr(smContext *SMContext, defQER *QER, } } } - logger.CtxLog.Infof("activate UpLink PDR[%v]:[%v] ", name, ULPDR) + logger.CtxLog.Infof("activate UpLink PDR[%v]:[%v]", name, ULPDR) } return nil } @@ -623,7 +623,7 @@ func (dpNode *DataPathNode) ActivateDlLinkPdr(smContext *SMContext, defQER *QER, } for name, DLPDR := range curDLTunnel.PDR { - logger.CtxLog.Infof("activate Downlink PDR[%v]:[%v] ", name, DLPDR) + logger.CtxLog.Infof("activate Downlink PDR[%v]:[%v]", name, DLPDR) DLDestUPF := curDLTunnel.DestEndPoint.UPF DLPDR.QER = append(DLPDR.QER, defQER) @@ -640,7 +640,7 @@ func (dpNode *DataPathNode) ActivateDlLinkPdr(smContext *SMContext, defQER *QER, iface = DLDestUPF.GetInterface(models.UpInterfaceType_N9, smContext.Dnn) if upIP, err := iface.IP(smContext.SelectedPDUSessionType); err != nil { - logger.CtxLog.Errorf("activate Downlink PDR[%v] failed %v ", name, err) + logger.CtxLog.Errorf("activate Downlink PDR[%v] failed %v", name, err) return err } else { DLPDR.PDI.SourceInterface = SourceInterface{InterfaceValue: SourceInterfaceCore} @@ -656,10 +656,10 @@ func (dpNode *DataPathNode) ActivateDlLinkPdr(smContext *SMContext, defQER *QER, DLFAR := DLPDR.FAR - logger.PduSessLog.Traceln("Current DP Node IP: ", dpNode.UPF.NodeID.ResolveNodeIdToIp().String()) - logger.PduSessLog.Traceln("Before DLPDR OuterHeaderCreation") + logger.PduSessLog.Debugln("current DP Node IP:", dpNode.UPF.NodeID.ResolveNodeIdToIp().String()) + logger.PduSessLog.Debugln("before DLPDR OuterHeaderCreation") if nextDLDest := dpNode.Prev(); nextDLDest != nil { - logger.PduSessLog.Traceln("In DLPDR OuterHeaderCreation") + logger.PduSessLog.Debugln("in DLPDR OuterHeaderCreation") nextDLTunnel := nextDLDest.DownLinkTunnel DLFAR.ApplyAction = ApplyAction{ @@ -673,7 +673,7 @@ func (dpNode *DataPathNode) ActivateDlLinkPdr(smContext *SMContext, defQER *QER, iface = nextDLDest.UPF.GetInterface(models.UpInterfaceType_N9, smContext.Dnn) if upIP, err := iface.IP(smContext.SelectedPDUSessionType); err != nil { - logger.CtxLog.Errorf("activate Downlink PDR[%v] failed %v ", name, err) + logger.CtxLog.Errorf("activate Downlink PDR[%v] failed %v", name, err) return err } else { DLFAR.ForwardingParameters = &ForwardingParameters{ @@ -701,7 +701,7 @@ func (dpNode *DataPathNode) ActivateDlLinkPdr(smContext *SMContext, defQER *QER, dlOuterHeaderCreation.Ipv4Address = smContext.Tunnel.ANInformation.IPAddress.To4() } } - logger.CtxLog.Infof("activate Downlink PDR[%v]:[%v] ", name, DLPDR) + logger.CtxLog.Infof("activate Downlink PDR[%v]:[%v]", name, DLPDR) } return nil } @@ -710,7 +710,7 @@ func (dpNode *DataPathNode) ActivateDlLinkPdr(smContext *SMContext, defQER *QER, func (dataPath *DataPath) ActivateTunnelAndPDR(smContext *SMContext, precedence uint32) error { // Check if UPF association is good if err := dataPath.validateDataPathUpfStatus(); err != nil { - logger.PduSessLog.Error("One or more UPF in DataPath not associated") + logger.PduSessLog.Errorln("one or more UPF in DataPath not associated") return err } @@ -719,7 +719,7 @@ func (dataPath *DataPath) ActivateTunnelAndPDR(smContext *SMContext, precedence // Allocate UL/DL PDRs for the Tunnels if err := dataPath.ActivateUlDlTunnel(smContext); err != nil { - logger.PduSessLog.Errorf("Activate UL/DL Tunnel error %v", err.Error()) + logger.PduSessLog.Errorf("activate UL/DL tunnel error %v", err.Error()) return err } @@ -731,19 +731,19 @@ func (dataPath *DataPath) ActivateTunnelAndPDR(smContext *SMContext, precedence return err } - logger.CtxLog.Traceln("Calculate ", curDataPathNode.UPF.PFCPAddr().String()) + logger.CtxLog.Debugln("calculate", curDataPathNode.UPF.PFCPAddr().String()) // Setup UpLink PDR if curDataPathNode.UpLinkTunnel != nil { if err := curDataPathNode.ActivateUpLinkPdr(smContext, defQER, precedence); err != nil { - logger.CtxLog.Errorf("Activate UpLink PDR error %v", err.Error()) + logger.CtxLog.Errorf("activate UpLink PDR error %v", err.Error()) } } // Setup DownLink PDR if curDataPathNode.DownLinkTunnel != nil { if err := curDataPathNode.ActivateDlLinkPdr(smContext, defQER, precedence, dataPath); err != nil { - logger.CtxLog.Errorf("Activate DlLink PDR error %v", err.Error()) + logger.CtxLog.Errorf("activate DlLink PDR error %v", err.Error()) } } diff --git a/context/db.go b/context/db.go index 1e78bfcb..6288c408 100644 --- a/context/db.go +++ b/context/db.go @@ -45,19 +45,19 @@ func SetupSmfCollection() { dbName = factory.SmfConfig.Configuration.SmfDbName } - logger.CfgLog.Infof("initialising db name [%v] url [%v] ", dbName, dbUrl) + logger.CfgLog.Infof("initialising db name [%v] url [%v]", dbName, dbUrl) // UUID table mongoapi.ConnectMongo(dbUrl, dbName) _, err := mongoapi.CommonDBClient.CreateIndex(SmContextDataColl, "ref") if err != nil { - logger.DataRepoLog.Errorf("Create index failed on ref field.") + logger.DataRepoLog.Errorln("create index failed on ref field") } // SEID Table _, err = mongoapi.CommonDBClient.CreateIndex(SeidSmContextCol, "seid") if err != nil { - logger.DataRepoLog.Errorf("Create index failed on TxnId field.") + logger.DataRepoLog.Errorln("create index failed on TxnId field") } smfCount := mongoapi.CommonDBClient.GetUniqueIdentity("smfCount") @@ -66,7 +66,7 @@ func SetupSmfCollection() { // set os env setEnvErr := os.Setenv("SMF_COUNT", strconv.Itoa(int(smfCount))) if setEnvErr != nil { - logger.DataRepoLog.Errorf("Setting SMF_COUNT env variable is failed.") + logger.DataRepoLog.Errorln("setting SMF_COUNT env variable is failed") } } @@ -137,7 +137,7 @@ func (smContext *SMContext) MarshalJSON() ([]byte, error) { // UnmarshalJSON customized unmarshaller for sm context func (smContext *SMContext) UnmarshalJSON(data []byte) error { - fmt.Println("db - in UnmarshalJSON") + logger.DataRepoLog.Infoln("db - in UnmarshalJSON") type Alias SMContext aux := &struct { *Alias @@ -148,7 +148,7 @@ func (smContext *SMContext) UnmarshalJSON(data []byte) error { } if err := json.Unmarshal(data, &aux); err != nil { - fmt.Println("err in customized unMarshall!!") + logger.DataRepoLog.Errorln("err in customized unMarshall") return err } @@ -224,7 +224,7 @@ func ToBsonMSeidRef(data SeidSmContextRef) (ret bson.M) { func ToBsonM(data *SMContext) (ret bson.M) { // Marshal data into json format - fmt.Println("db - in ToBsonM before marshal") + logger.DataRepoLog.Infoln("db - in ToBsonM before marshal") tmp, err := json.Marshal(data) if err != nil { logger.DataRepoLog.Errorf("SMContext marshall error: %v", err) @@ -240,7 +240,7 @@ func ToBsonM(data *SMContext) (ret bson.M) { // StoreSmContextInDB Store SmContext In DB func StoreSmContextInDB(smContext *SMContext) { - fmt.Println("db - Store SMContext In DB w ref") + logger.DataRepoLog.Infoln("db - Store SMContext In DB w ref") smContext.SMLock.Lock() defer smContext.SMLock.Unlock() smContextBsonA := ToBsonM(smContext) @@ -332,7 +332,7 @@ func GetSMContextByRefInDB(ref string) (smContext *SMContext) { return nil } } else { - logger.DataRepoLog.Warningf("SmContext doesn't exist with ref: %v", ref) + logger.DataRepoLog.Warnf("SmContext doesn't exist with ref: %v", ref) return nil } @@ -351,10 +351,10 @@ func GetSMContextBySEIDInDB(seidUint uint64) (smContext *SMContext) { } if result != nil { ref := result["ref"].(string) - logger.DataRepoLog.Debugln("StoreSeidContextInDB, result string : ", ref) + logger.DataRepoLog.Debugln("StoreSeidContextInDB, result string:", ref) return GetSMContext(ref) } else { - logger.DataRepoLog.Warningf("SmContext doesn't exist with seid: %v", seid) + logger.DataRepoLog.Warnf("SmContext doesn't exist with seid: %v", seid) return nil } } @@ -362,7 +362,7 @@ func GetSMContextBySEIDInDB(seidUint uint64) (smContext *SMContext) { // DeleteSmContextInDBBySEID Delete SMContext By SEID from DB func DeleteSmContextInDBBySEID(seidUint uint64) { seid := SeidConv(seidUint) - fmt.Println("db - delete SMContext In DB by seid") + logger.DataRepoLog.Infoln("db - delete SMContext In DB by seid") filter := bson.M{"seid": seid} logger.DataRepoLog.Infof("filter: %+v", filter) @@ -379,13 +379,13 @@ func DeleteSmContextInDBBySEID(seidUint uint64) { } DeleteSmContextInDBByRef(ref) } else { - logger.DataRepoLog.Infof("DB entry doesn't exist with seid: %v\n", seid) + logger.DataRepoLog.Infof("DB entry doesn't exist with seid: %v", seid) } } // DeleteSmContextInDBByRef Delete SMContext By ref from DB func DeleteSmContextInDBByRef(ref string) { - fmt.Println("db - delete SMContext In DB w ref") + logger.DataRepoLog.Infoln("db - delete SMContext In DB w ref") filter := bson.M{"ref": ref} logger.DataRepoLog.Infof("filter: %+v", filter) @@ -414,7 +414,7 @@ func mapToByte(data map[string]interface{}) (ret []byte) { func ShowSmContextPool() { smContextPool.Range(func(k, v interface{}) bool { - fmt.Println("db - iterate:", k, v) + logger.DataRepoLog.Infoln("db - iterate:", k, v) return true }) } diff --git a/context/db_uptunnel.go b/context/db_uptunnel.go index 87606466..69ac6dcd 100644 --- a/context/db_uptunnel.go +++ b/context/db_uptunnel.go @@ -6,7 +6,6 @@ package context import ( "encoding/json" - "fmt" "net" "github.com/omec-project/smf/logger" @@ -112,7 +111,7 @@ func RecoverTunnel(tunnelInfo *TunnelInfo) (tunnel *GTPTunnel) { } func RecoverFirstDPNode(nodeIDInDB NodeIDInDB) (dataPathNode *DataPathNode) { - fmt.Println("in RecoverFirstDPNode") + logger.CtxLog.Infoln("in RecoverFirstDPNode") nodeInDB := GetNodeInDBFromDB(nodeIDInDB) dataPathNode = &DataPathNode{ IsBranchingPoint: nodeInDB.IsBranchingPoint, @@ -126,13 +125,13 @@ func RecoverFirstDPNode(nodeIDInDB NodeIDInDB) (dataPathNode *DataPathNode) { if nodeInDB.DLTunnelInfo != nilVal { dataPathNode.DownLinkTunnel = RecoverTunnel(nodeInDB.DLTunnelInfo) } - fmt.Println("RecoverFirstDPNode - dataPathNode", dataPathNode) + logger.CtxLog.Infoln("RecoverFirstDPNode - dataPathNode", dataPathNode) if nodeInDB.ULTunnelInfo != nilVal { - fmt.Println("nodeInDB.ULTunnelInfo != nilVal") + logger.CtxLog.Infoln("nodeInDB.ULTunnelInfo != nilVal") dataPathNode.UpLinkTunnel.DestEndPoint = dataPathNode } if nodeInDB.DLTunnelInfo != nilVal { - fmt.Println("nodeInDB.DLTunnelInfo != nilVal") + logger.CtxLog.Infoln("nodeInDB.DLTunnelInfo != nilVal") dataPathNode.DownLinkTunnel.DestEndPoint = dataPathNode } return dataPathNode @@ -175,8 +174,8 @@ func GetNodeInDBFromDB(nodeIDInDB NodeIDInDB) (dataPathNodeInDB *DataPathNodeInD } dataPathNodeInDB = new(DataPathNodeInDB) - fmt.Println("GetNodeInDBFromDB, smf state json : ", result) - fmt.Println("GetNodeInDBFromDB, smf dataPathNodeInDB : ", dataPathNodeInDB) + logger.CtxLog.Infoln("GetNodeInDBFromDB, smf state json:", result) + logger.CtxLog.Infoln("GetNodeInDBFromDB, smf dataPathNodeInDB:", dataPathNodeInDB) err := json.Unmarshal(mapToByte(result), dataPathNodeInDB) if err != nil { diff --git a/context/gsm_handler.go b/context/gsm_handler.go index 0795a1cd..1c74b776 100644 --- a/context/gsm_handler.go +++ b/context/gsm_handler.go @@ -46,9 +46,9 @@ func (smContext *SMContext) HandlePDUSessionEstablishmentRequest(req *nasMessage protocolConfigurationOptions := nasConvert.NewProtocolConfigurationOptions() unmarshalErr := protocolConfigurationOptions.UnMarshal(EPCOContents) if unmarshalErr != nil { - smContext.SubGsmLog.Errorf("Parsing PCO failed: %s", unmarshalErr) + smContext.SubGsmLog.Errorf("parsing PCO failed: %s", unmarshalErr) } - smContext.SubGsmLog.Infoln("Protocol Configuration Options") + smContext.SubGsmLog.Infoln("protocol Configuration Options") smContext.SubGsmLog.Infoln(protocolConfigurationOptions) // Send MTU to UE always even if UE does not request it. @@ -56,8 +56,8 @@ func (smContext *SMContext) HandlePDUSessionEstablishmentRequest(req *nasMessage smContext.ProtocolConfigurationOptions.IPv4LinkMTURequest = true for _, container := range protocolConfigurationOptions.ProtocolOrContainerList { - smContext.SubGsmLog.Traceln("Container ID: ", container.ProtocolOrContainerID) - smContext.SubGsmLog.Traceln("Container Length: ", container.LengthOfContents) + smContext.SubGsmLog.Debugln("Container ID:", container.ProtocolOrContainerID) + smContext.SubGsmLog.Debugln("Container Length:", container.LengthOfContents) switch container.ProtocolOrContainerID { case nasMessage.PCSCFIPv6AddressRequestUL: smContext.SubGsmLog.Infoln("Didn't Implement container type PCSCFIPv6AddressRequestUL") diff --git a/context/ip_allocator.go b/context/ip_allocator.go index 243915ca..824359fe 100644 --- a/context/ip_allocator.go +++ b/context/ip_allocator.go @@ -7,7 +7,6 @@ package context import ( "errors" - "fmt" "net" "os" "strconv" @@ -100,9 +99,9 @@ func (a *IPAllocator) Allocate(imsi string) (net.IP, error) { logger.CtxLog.Errorf("failed to convert SMF_COUNT to int: %v", err) } ip := IPAddrWithOffset(a.ipNetwork.IP, int(offset)+(smfCount-1)*5000) - fmt.Printf("unique id - ip %v \n", ip) - fmt.Printf("unique id - offset %v \n", offset) - fmt.Printf("unique id - smfCount %v \n", smfCount) + logger.CtxLog.Infof("unique id - ip %v", ip) + logger.CtxLog.Infof("unique id - offset %v", offset) + logger.CtxLog.Infof("unique id - smfCount %v", smfCount) return ip, nil } } diff --git a/context/ip_allocator_test.go b/context/ip_allocator_test.go index 94c3093f..eee58b05 100644 --- a/context/ip_allocator_test.go +++ b/context/ip_allocator_test.go @@ -5,7 +5,6 @@ package context_test import ( - "fmt" "net" "testing" @@ -25,7 +24,7 @@ func TestIPPoolAlloc(t *testing.T) { if err != nil { t.Errorf("failed to allocate pool %v", err) } - fmt.Printf("Allocated address = %v\n", ip) + t.Logf("allocated address = %v", ip) allocAddresses = append(allocAddresses, ip.String()) } @@ -52,7 +51,7 @@ func TestIPPoolAllocRelease(t *testing.T) { if err != nil { t.Errorf("failed to allocate pool %v", err) } - fmt.Printf("Allocated address = %v\n", ip) + t.Logf("allocated address = %v", ip) if i == 1 { if ip.Equal(ip1) == false { t.Errorf("address not allocated in order ? allocated address %v", ip1) @@ -82,13 +81,13 @@ func TestIPPoolAllocLeastRecentlyUsed(t *testing.T) { if err != nil { t.Errorf("failed to allocate pool %v", err) } - fmt.Printf("Allocated address = %v\n", ip1) + t.Logf("allocated address = %v", ip1) allocator.Release("", ip1) ip2, err := allocator.Allocate("") if err != nil { t.Errorf("failed to allocate pool %v", err) } - fmt.Printf("Allocated address = %v\n", ip2) + t.Logf("allocated address = %v", ip2) // Same address is not allocate again.. if ip1.Equal(ip2) { diff --git a/context/sm_context.go b/context/sm_context.go index 0293c97c..6a08aa6f 100644 --- a/context/sm_context.go +++ b/context/sm_context.go @@ -17,7 +17,6 @@ import ( "sync/atomic" "github.com/google/uuid" - mi "github.com/omec-project/metricfunc/pkg/metricinfo" "github.com/omec-project/nas/nasConvert" "github.com/omec-project/nas/nasMessage" "github.com/omec-project/openapi/Namf_Communication" @@ -33,7 +32,8 @@ import ( errors "github.com/omec-project/smf/smferrors" "github.com/omec-project/smf/transaction" "github.com/omec-project/util/httpwrapper" - "github.com/sirupsen/logrus" + mi "github.com/omec-project/util/metricinfo" + "go.uber.org/zap" ) const ( @@ -138,13 +138,13 @@ type SMContext struct { // PCO Related ProtocolConfigurationOptions *ProtocolConfigurationOptions `json:"protocolConfigurationOptions" yaml:"protocolConfigurationOptions" bson:"protocolConfigurationOptions"` // ignore - SubGsmLog *logrus.Entry `json:"-" yaml:"subGsmLog" bson:"-,"` // ignore - SubPfcpLog *logrus.Entry `json:"-" yaml:"subPfcpLog" bson:"-"` // ignore - SubPduSessLog *logrus.Entry `json:"-" yaml:"subPduSessLog" bson:"-"` // ignore - SubCtxLog *logrus.Entry `json:"-" yaml:"subCtxLog" bson:"-"` // ignore - SubConsumerLog *logrus.Entry `json:"-" yaml:"subConsumerLog" bson:"-"` // ignore - SubFsmLog *logrus.Entry `json:"-" yaml:"subFsmLog" bson:"-"` // ignore - SubQosLog *logrus.Entry `json:"-" yaml:"subQosLog" bson:"-"` // ignore + SubGsmLog *zap.SugaredLogger `json:"-" yaml:"subGsmLog" bson:"-,"` // ignore + SubPfcpLog *zap.SugaredLogger `json:"-" yaml:"subPfcpLog" bson:"-"` // ignore + SubPduSessLog *zap.SugaredLogger `json:"-" yaml:"subPduSessLog" bson:"-"` // ignore + SubCtxLog *zap.SugaredLogger `json:"-" yaml:"subCtxLog" bson:"-"` // ignore + SubConsumerLog *zap.SugaredLogger `json:"-" yaml:"subConsumerLog" bson:"-"` // ignore + SubFsmLog *zap.SugaredLogger `json:"-" yaml:"subFsmLog" bson:"-"` // ignore + SubQosLog *zap.SugaredLogger `json:"-" yaml:"subQosLog" bson:"-"` // ignore // encountered a cycle via *context.SMContext ActiveTxn *transaction.Transaction `json:"-" yaml:"activeTxn" bson:"-,"` // ignore @@ -228,18 +228,13 @@ func NewSMContext(identifier string, pduSessID int32) (smContext *SMContext) { } func (smContext *SMContext) initLogTags() { - subField := logrus.Fields{ - "uuid": smContext.Ref, - "id": smContext.Identifier, "pduid": smContext.PDUSessionID, - } - - smContext.SubPfcpLog = logger.PfcpLog.WithFields(subField) - smContext.SubCtxLog = logger.CtxLog.WithFields(subField) - smContext.SubPduSessLog = logger.PduSessLog.WithFields(subField) - smContext.SubGsmLog = logger.GsmLog.WithFields(subField) - smContext.SubConsumerLog = logger.ConsumerLog.WithFields(subField) - smContext.SubFsmLog = logger.FsmLog.WithFields(subField) - smContext.SubQosLog = logger.QosLog.WithFields(subField) + smContext.SubPfcpLog = logger.PfcpLog.With("uuid", smContext.Ref, "id", smContext.Identifier, "pduid", smContext.PDUSessionID) + smContext.SubCtxLog = logger.CtxLog.With("uuid", smContext.Ref, "id", smContext.Identifier, "pduid", smContext.PDUSessionID) + smContext.SubPduSessLog = logger.PduSessLog.With("uuid", smContext.Ref, "id", smContext.Identifier, "pduid", smContext.PDUSessionID) + smContext.SubGsmLog = logger.GsmLog.With("uuid", smContext.Ref, "id", smContext.Identifier, "pduid", smContext.PDUSessionID) + smContext.SubConsumerLog = logger.ConsumerLog.With("uuid", smContext.Ref, "id", smContext.Identifier, "pduid", smContext.PDUSessionID) + smContext.SubFsmLog = logger.FsmLog.With("uuid", smContext.Ref, "id", smContext.Identifier, "pduid", smContext.PDUSessionID) + smContext.SubQosLog = logger.QosLog.With("uuid", smContext.Ref, "id", smContext.Identifier, "pduid", smContext.PDUSessionID) } func (smContext *SMContext) ChangeState(nextState SMContextState) { @@ -422,7 +417,7 @@ func (smContext *SMContext) PCFSelection() error { if res != nil { if status := res.StatusCode; status != http.StatusOK { metrics.IncrementSvcNrfMsgStats(SMF_Self().NfInstanceID, string(svcmsgtypes.NnrfNFDiscoveryPcf), "In", "Failure", "") - logger.CtxLog.Warningf("NFDiscovery PCF return status: %d\n", status) + logger.CtxLog.Warnf("NFDiscovery PCF return status: %d", status) } } @@ -455,10 +450,10 @@ func (smContext *SMContext) GetNodeIDByLocalSEID(seid uint64) (nodeID NodeID) { } func (smContext *SMContext) AllocateLocalSEIDForDataPath(dataPath *DataPath) { - logger.PduSessLog.Traceln("In AllocateLocalSEIDForDataPath") + logger.PduSessLog.Debugln("in AllocateLocalSEIDForDataPath") for curDataPathNode := dataPath.FirstDPNode; curDataPathNode != nil; curDataPathNode = curDataPathNode.Next() { NodeIDtoIP := curDataPathNode.UPF.NodeID.ResolveNodeIdToIp().String() - logger.PduSessLog.Traceln("NodeIDtoIP: ", NodeIDtoIP) + logger.PduSessLog.Debugln("NodeIDtoIP:", NodeIDtoIP) if _, exist := smContext.PFCPContext[NodeIDtoIP]; !exist { allocatedSEID, err := AllocateLocalSEID() if err != nil { @@ -577,7 +572,7 @@ func (smContext *SMContext) isAllowedPDUSessionType(requestedPDUSessionType uint } case models.PduSessionType_UNSTRUCTURED: smContext.SelectedPDUSessionType = nasConvert.ModelsToPDUSessionType(models.PduSessionType_UNSTRUCTURED) - return fmt.Errorf("Unstructured PDU Session type") + return fmt.Errorf("unstructured PDU Session type") default: return fmt.Errorf("requested PDU Sesstion type[%d] is not supported", requestedPDUSessionType) } diff --git a/context/ue_datapath.go b/context/ue_datapath.go index 13c597cb..020d329b 100644 --- a/context/ue_datapath.go +++ b/context/ue_datapath.go @@ -43,7 +43,7 @@ func NewUEPreConfigPaths(SUPI string, paths []factory.Path) (*UEPreConfigPaths, lowerBound := 0 pathIDGenerator := idgenerator.NewGenerator(1, math.MaxInt32) - logger.PduSessLog.Infoln("In NewUEPreConfigPaths") + logger.PduSessLog.Infoln("in NewUEPreConfigPaths") for idx, path := range paths { dataPath := NewDataPath() @@ -54,7 +54,7 @@ func NewUEPreConfigPaths(SUPI string, paths []factory.Path) (*UEPreConfigPaths, var pathID int64 if allocPathID, err := pathIDGenerator.Allocate(); err != nil { - logger.CtxLog.Warnf("Allocate pathID error: %+v", err) + logger.CtxLog.Warnf("allocate pathID error: %+v", err) return nil, err } else { pathID = allocPathID @@ -80,8 +80,7 @@ func NewUEPreConfigPaths(SUPI string, paths []factory.Path) (*UEPreConfigPaths, parentNode = newUeNode } - logger.CtxLog.Traceln("New data path added") - logger.CtxLog.Traceln("\n" + dataPath.String() + "\n") + logger.CtxLog.Debugln("new data path added:", dataPath.String()) } uePreConfigPaths = &UEPreConfigPaths{ @@ -97,7 +96,7 @@ func GetUEPreConfigPaths(SUPI string) *UEPreConfigPaths { func CheckUEHasPreConfig(SUPI string) (exist bool) { _, exist = smfContext.UEPreConfigPathPool[SUPI] - fmt.Println("CheckUEHasPreConfig") - fmt.Println(smfContext.UEPreConfigPathPool) + logger.CtxLog.Infoln("CheckUEHasPreConfig") + logger.CtxLog.Infoln(smfContext.UEPreConfigPathPool) return } diff --git a/context/upf.go b/context/upf.go index aa62a0e0..f7951941 100644 --- a/context/upf.go +++ b/context/upf.go @@ -127,7 +127,7 @@ func NewUPFInterfaceInfo(i *factory.InterfaceUpfInfoItem) *UPFInterfaceInfo { interfaceInfo.IPv4EndPointAddresses = make([]net.IP, 0) interfaceInfo.IPv6EndPointAddresses = make([]net.IP, 0) - logger.CtxLog.Infoln("Endpoints:", i.Endpoints) + logger.CtxLog.Infoln("endpoints:", i.Endpoints) for _, endpoint := range i.Endpoints { eIP := net.ParseIP(endpoint) @@ -218,7 +218,7 @@ func NewUPTunnel() (tunnel *UPTunnel) { func (upTunnel *UPTunnel) AddDataPath(dataPath *DataPath) { pathID, err := upTunnel.PathIDGenerator.Allocate() if err != nil { - logger.CtxLog.Warnf("Allocate pathID error: %+v", err) + logger.CtxLog.Warnf("allocate pathID error: %+v", err) return } @@ -323,7 +323,7 @@ func RetrieveUPFNodeByNodeID(nodeID NodeID) *UPF { (curUPF.NodeID.NodeIdType == NodeIdTypeFqdn || nodeID.NodeIdType == NodeIdTypeFqdn) { curUPFNodeIdIP := curUPF.NodeID.ResolveNodeIdToIp().To4() nodeIdIP := nodeID.ResolveNodeIdToIp().To4() - logger.CtxLog.Tracef("RetrieveUPF - upfNodeIdIP:[%+v], nodeIdIP:[%+v]", curUPFNodeIdIP, nodeIdIP) + logger.CtxLog.Debugf("retrieveUPF - upfNodeIdIP:[%+v], nodeIdIP:[%+v]", curUPFNodeIdIP, nodeIdIP) if reflect.DeepEqual(curUPFNodeIdIP, nodeIdIP) { targetUPF = curUPF return false @@ -348,7 +348,7 @@ func RemoveUPFNodeByNodeID(nodeID NodeID) bool { (upf.NodeID.NodeIdType == NodeIdTypeFqdn || nodeID.NodeIdType == NodeIdTypeFqdn) { upfNodeIdIP := upf.NodeID.ResolveNodeIdToIp().To4() nodeIdIP := nodeID.ResolveNodeIdToIp().To4() - logger.CtxLog.Tracef("RemoveUPF - upfNodeIdIP:[%+v], nodeIdIP:[%+v]", upfNodeIdIP, nodeIdIP) + logger.CtxLog.Debugf("removeUPF - upfNodeIdIP:[%+v], nodeIdIP:[%+v]", upfNodeIdIP, nodeIdIP) if reflect.DeepEqual(upfNodeIdIP, nodeIdIP) { return false } diff --git a/context/user_plane_information.go b/context/user_plane_information.go index 4bd4f84b..79de5ffc 100644 --- a/context/user_plane_information.go +++ b/context/user_plane_information.go @@ -76,7 +76,7 @@ func NewUserPlaneInformation(upTopology *factory.UserPlaneInformation) *UserPlan for name, node := range upTopology.UPNodes { err := userplaneInformation.InsertSmfUserPlaneNode(name, &node) if err != nil { - logger.UPNodeLog.Errorf("failed to insert UP Node[%v] ", node) + logger.UPNodeLog.Errorf("failed to insert UP Node[%v]", node) } } @@ -84,7 +84,7 @@ func NewUserPlaneInformation(upTopology *factory.UserPlaneInformation) *UserPlan for _, link := range upTopology.Links { err := userplaneInformation.InsertUPNodeLinks(&link) if err != nil { - logger.UPNodeLog.Errorf("failed to insert UP Node link[%v] ", link) + logger.UPNodeLog.Errorf("failed to insert UP Node link[%v]", link) } } return userplaneInformation @@ -114,8 +114,8 @@ func (upi *UserPlaneInformation) ResetDefaultUserPlanePath() { func (upi *UserPlaneInformation) GetDefaultUserPlanePathByDNN(selection *UPFSelectionParams) (path UPPath) { path, pathExist := upi.DefaultUserPlanePath[selection.String()] - logger.CtxLog.Traceln("In GetDefaultUserPlanePathByDNN") - logger.CtxLog.Traceln("selection: ", selection.String()) + logger.CtxLog.Debugln("in GetDefaultUserPlanePathByDNN") + logger.CtxLog.Debugln("selection:", selection.String()) if pathExist { return } else { @@ -177,18 +177,18 @@ func (upi *UserPlaneInformation) GenerateDefaultPath(selection *UPFSelectionPara var destinations []*UPNode for len(upi.AccessNetwork) == 0 { - logger.CtxLog.Errorf("There is no AN Node in config file!") + logger.CtxLog.Errorf("there is no AN Node in config file") return false } destinations = upi.selectMatchUPF(selection) if len(destinations) == 0 { - logger.CtxLog.Errorf("Can't find UPF with DNN[%s] S-NSSAI[sst: %d sd: %s] DNAI[%s]\n", selection.Dnn, + logger.CtxLog.Errorf("can not find UPF with DNN[%s] S-NSSAI[sst: %d sd: %s] DNAI[%s]", selection.Dnn, selection.SNssai.Sst, selection.SNssai.Sd, selection.Dnai) return false } else { - logger.CtxLog.Debugf("Found UPF with DNN[%s] S-NSSAI[sst: %d sd: %s] DNAI[%s]\n", selection.Dnn, + logger.CtxLog.Debugf("found UPF with DNN[%s] S-NSSAI[sst: %d sd: %s] DNAI[%s]", selection.Dnn, selection.SNssai.Sst, selection.SNssai.Sd, selection.Dnai) } @@ -212,7 +212,7 @@ func (upi *UserPlaneInformation) GenerateDefaultPath(selection *UPFSelectionPara upi.DefaultUserPlanePath[selection.String()] = path break } else { - logger.CtxLog.Debugf("No path between an-node[%v] and upf[%v] ", anName, string(destinations[0].NodeID.NodeIdValue)) + logger.CtxLog.Debugf("no path between an-node[%v] and upf[%v]", anName, string(destinations[0].NodeID.NodeIdValue)) continue } } @@ -282,8 +282,8 @@ func getPathBetween(cur *UPNode, dest *UPNode, visited map[*UPNode]bool, // insert new UPF (only N3) func (upi *UserPlaneInformation) InsertSmfUserPlaneNode(name string, node *factory.UPNode) error { - logger.UPNodeLog.Infof("UPNode[%v] to insert, content[%v]\n", name, node) - logger.UPNodeLog.Debugf("content of map[UPNodes] %v \n", upi.UPNodes) + logger.UPNodeLog.Infof("UPNode[%v] to insert, content[%v]", name, node) + logger.UPNodeLog.Debugf("content of map[UPNodes] %v", upi.UPNodes) upNode := new(UPNode) upNode.Type = UPNodeType(node.Type) @@ -348,7 +348,7 @@ func (upi *UserPlaneInformation) InsertSmfUserPlaneNode(name string, node *facto upNode.UPF.SNssaiInfos = snssaiInfos upi.UPFs[name] = upNode default: - logger.InitLog.Warningf("invalid UPNodeType: %s\n", upNode.Type) + logger.InitLog.Warnf("invalid UPNodeType: %s", upNode.Type) } upi.UPNodes[name] = upNode @@ -363,7 +363,7 @@ func (upi *UserPlaneInformation) InsertSmfUserPlaneNode(name string, node *facto // If the node is of type AN, then the node is updated with the new port. // If the node is of type UPF, then the node is updated with the new port and the new UPF information. func (upi *UserPlaneInformation) UpdateSmfUserPlaneNode(name string, newNode *factory.UPNode) error { - logger.UPNodeLog.Infof("UPNode [%v] to update, content[%v]\n", name, newNode) + logger.UPNodeLog.Infof("UPNode [%v] to update, content[%v]", name, newNode) existingNode, exists := upi.UPNodes[name] if !exists { @@ -421,7 +421,7 @@ func (upi *UserPlaneInformation) UpdateSmfUserPlaneNode(name string, newNode *fa } upi.UPFs[name] = existingNode default: - logger.InitLog.Warningf("invalid UPNodeType: %s\n", existingNode.Type) + logger.InitLog.Warnf("invalid UPNodeType: %s", existingNode.Type) } upi.UPNodes[name] = existingNode @@ -435,8 +435,8 @@ func (upi *UserPlaneInformation) UpdateSmfUserPlaneNode(name string, newNode *fa // delete UPF func (upi *UserPlaneInformation) DeleteSmfUserPlaneNode(name string, node *factory.UPNode) error { - logger.UPNodeLog.Infof("UPNode[%v] to delete, content[%v]\n", name, node) - logger.UPNodeLog.Debugf("content of map[UPNodes] %v \n", upi.UPNodes) + logger.UPNodeLog.Infof("UPNode[%v] to delete, content[%v]", name, node) + logger.UPNodeLog.Debugf("content of map[UPNodes] %v", upi.UPNodes) // Find UPF node upNode := upi.UPNodes[name] @@ -449,16 +449,16 @@ func (upi *UserPlaneInformation) DeleteSmfUserPlaneNode(name string, node *facto switch upNode.Type { case UPNODE_AN: // Remove from ANPOOL - logger.UPNodeLog.Debugf("content of map[AccessNetwork] %v \n", upi.AccessNetwork) + logger.UPNodeLog.Debugf("content of map[AccessNetwork] %v", upi.AccessNetwork) delete(upi.AccessNetwork, name) case UPNODE_UPF: // remove from UPF pool - logger.UPNodeLog.Debugf("content of map[UPFs] %v \n", upi.UPFs) - logger.UPNodeLog.Debugf("content of map[UPFsID] %v \n", upi.UPFsID) + logger.UPNodeLog.Debugf("content of map[UPFs] %v", upi.UPFs) + logger.UPNodeLog.Debugf("content of map[UPFsID] %v", upi.UPFsID) delete(upi.UPFs, name) delete(upi.UPFsID, name) // IP to ID map(Host may not be resolvable to IP, so iterate through all entries) - logger.UPNodeLog.Debugf("content of map[UPFsIPtoID] %v \n", upi.UPFsIPtoID) + logger.UPNodeLog.Debugf("content of map[UPFsIPtoID] %v", upi.UPFsIPtoID) for ipStr, nodeId := range upi.UPFsIPtoID { if nodeId == upNode.UPF.UUID() { delete(upi.UPFsIPtoID, ipStr) @@ -472,12 +472,12 @@ func (upi *UserPlaneInformation) DeleteSmfUserPlaneNode(name string, node *facto } // name to upNode map(//Common maps for gNB and UPF) - logger.UPNodeLog.Debugf("content of map[UPNodes] %v \n", upi.UPNodes) + logger.UPNodeLog.Debugf("content of map[UPNodes] %v", upi.UPNodes) delete(upi.UPNodes, name) logger.UPNodeLog.Infof("UPNode[%v] deleted from table[UPNodes]", name) // IP to name map(Host may not be resolvable to IP, so iterate through all entries) - logger.UPNodeLog.Debugf("content of map[UPFIPToName] %v \n", upi.UPFIPToName) + logger.UPNodeLog.Debugf("content of map[UPFIPToName] %v", upi.UPFIPToName) for ipStr, nodeName := range upi.UPFIPToName { if nodeName == name { delete(upi.UPFIPToName, ipStr) @@ -497,7 +497,7 @@ func (upi *UserPlaneInformation) InsertUPNodeLinks(link *factory.UPLink) error { nodeA := upi.UPNodes[link.A] nodeB := upi.UPNodes[link.B] if nodeA == nil || nodeB == nil { - logger.UPNodeLog.Warningf("UPLink [%s] <=> [%s] not establish\n", link.A, link.B) + logger.UPNodeLog.Warnf("UPLink [%s] <=> [%s] not establish", link.A, link.B) panic("Invalid UPF Links") } nodeA.Links = append(nodeA.Links, nodeB) @@ -507,7 +507,7 @@ func (upi *UserPlaneInformation) InsertUPNodeLinks(link *factory.UPLink) error { } func (upi *UserPlaneInformation) DeleteUPNodeLinks(link *factory.UPLink) error { - logger.UPNodeLog.Infof("deleting UP Node link[%v] ", link) + logger.UPNodeLog.Infof("deleting UP Node link[%v]", link) logger.UPNodeLog.Debugf("current UP Nodes [%+v]", upi.UPNodes) nodeA := upi.UPNodes[link.A] diff --git a/eventexposure/routers.go b/eventexposure/routers.go index 3552daf2..8993edd7 100644 --- a/eventexposure/routers.go +++ b/eventexposure/routers.go @@ -39,7 +39,7 @@ type Routes []Route // NewRouter returns a new router. func NewRouter() *gin.Engine { - router := utilLogger.NewGinWithLogrus(logger.GinLog) + router := utilLogger.NewGinWithZap(logger.GinLog) AddService(router) return router } diff --git a/factory/config_test.go b/factory/config_test.go index 67c9318b..4cfda4dd 100644 --- a/factory/config_test.go +++ b/factory/config_test.go @@ -6,7 +6,6 @@ package factory import ( - "fmt" "testing" protos "github.com/omec-project/config5g/proto/sdcoreConfig" @@ -442,7 +441,7 @@ func TestKafkaEnabledByDefault(t *testing.T) { // Webui URL is not set then default Webui URL value is returned func TestGetDefaultWebuiUrl(t *testing.T) { if err := InitConfigFactory("../config/smfcfg.yaml"); err != nil { - fmt.Printf("Error in InitConfigFactory: %v\n", err) + t.Logf("error in InitConfigFactory: %v", err) } got := SmfConfig.Configuration.WebuiUri want := "webui:9876" @@ -452,7 +451,7 @@ func TestGetDefaultWebuiUrl(t *testing.T) { // Webui URL is set to a custom value then custom Webui URL is returned func TestGetCustomWebuiUrl(t *testing.T) { if err := InitConfigFactory("../config/smfcfg_with_custom_webui_url.yaml"); err != nil { - fmt.Printf("Error in InitConfigFactory: %v\n", err) + t.Logf("error in InitConfigFactory: %v", err) } got := SmfConfig.Configuration.WebuiUri want := "myspecialwebui:9872" diff --git a/fsm/handler.go b/fsm/handler.go index ea4582c7..5d829547 100644 --- a/fsm/handler.go +++ b/fsm/handler.go @@ -7,12 +7,12 @@ package fsm import ( "fmt" - mi "github.com/omec-project/metricfunc/pkg/metricinfo" smf_context "github.com/omec-project/smf/context" "github.com/omec-project/smf/logger" stats "github.com/omec-project/smf/metrics" "github.com/omec-project/smf/producer" "github.com/omec-project/smf/transaction" + mi "github.com/omec-project/util/metricinfo" ) // Define SM Context level Events @@ -96,7 +96,7 @@ func HandleStateInitEventPduSessCreate(event SmEvent, eventData *SmEventData) (s err := stats.PublishMsgEvent(mi.Smf_msg_type_pdu_sess_create_rsp_failure) var errorMessage string = "" if err != nil { - logger.FsmLog.Errorf("error while publishing pdu session create response failure, %v ", err.Error()) + logger.FsmLog.Errorf("error while publishing pdu session create response failure, %v", err.Error()) errorMessage = err.Error() } txn := eventData.Txn.(*transaction.Transaction) @@ -106,7 +106,7 @@ func HandleStateInitEventPduSessCreate(event SmEvent, eventData *SmEventData) (s err := stats.PublishMsgEvent(mi.Smf_msg_type_pdu_sess_create_rsp_success) if err != nil { - logger.FsmLog.Errorf("error while publishing pdu session create response success, %v ", err.Error()) + logger.FsmLog.Errorf("error while publishing pdu session create response success, %v", err.Error()) } return smf_context.SmStatePfcpCreatePending, nil } diff --git a/fsm/txnFsm.go b/fsm/txnFsm.go index 8bf3c192..74d9f463 100644 --- a/fsm/txnFsm.go +++ b/fsm/txnFsm.go @@ -120,7 +120,7 @@ func (SmfTxnFsm) TxnCtxtRun(txn *transaction.Transaction) (transaction.TxnEvent, func (SmfTxnFsm) TxnProcess(txn *transaction.Transaction) (transaction.TxnEvent, error) { smContext := txn.Ctxt.(*smf_context.SMContext) if smContext == nil { - txn.TxnFsmLog.Errorf("event[%v], next-event[%v], SM context invalid ", transaction.TxnEventProcess.String(), transaction.TxnEventFailure.String()) + txn.TxnFsmLog.Errorf("event[%v], next-event[%v], SM context invalid", transaction.TxnEventProcess.String(), transaction.TxnEventFailure.String()) return transaction.TxnEventFailure, fmt.Errorf("TxnProcess, invalid SM Ctxt") } @@ -130,7 +130,7 @@ func (SmfTxnFsm) TxnProcess(txn *transaction.Transaction) (transaction.TxnEvent, smContextPool := smf_context.GetSmContextPool() val, ok := smContextPool.Load(smContext.Ref) if ok { - fmt.Println("db - smContext in smContextPool ", val) + txn.TxnFsmLog.Infoln("db - smContext in smContextPool", val) } else { smf_context.StoreSmContextPool(smContext) } diff --git a/go.mod b/go.mod index 04b8c22c..d4e116a0 100644 --- a/go.mod +++ b/go.mod @@ -4,20 +4,17 @@ go 1.21 require ( github.com/antihax/optional v1.0.0 - github.com/antonfisher/nested-logrus-formatter v1.3.1 github.com/gin-gonic/gin v1.10.0 github.com/google/uuid v1.6.0 github.com/mohae/deepcopy v0.0.0-20170929034955-c48cc78d4826 github.com/omec-project/aper v1.2.1 github.com/omec-project/config5g v1.5.0 - github.com/omec-project/metricfunc v1.4.1 - github.com/omec-project/nas v1.3.0 + github.com/omec-project/nas v1.4.1 github.com/omec-project/ngap v1.3.0 github.com/omec-project/openapi v1.3.1 - github.com/omec-project/util v1.1.0 + github.com/omec-project/util v1.2.1 github.com/pkg/errors v0.9.1 github.com/prometheus/client_golang v1.20.4 - github.com/sirupsen/logrus v1.9.3 github.com/stretchr/testify v1.9.0 github.com/urfave/cli v1.22.15 github.com/wmnsk/go-pfcp v0.0.24 @@ -55,7 +52,7 @@ require ( github.com/mitchellh/mapstructure v1.5.0 // indirect github.com/modern-go/concurrent v0.0.0-20180306012644-bacd9c7ef1dd // indirect github.com/modern-go/reflect2 v1.0.2 // indirect - github.com/montanaflynn/stats v0.6.6 // indirect + github.com/montanaflynn/stats v0.7.1 // indirect github.com/pelletier/go-toml/v2 v2.2.2 // indirect github.com/pierrec/lz4/v4 v4.1.15 // indirect github.com/pmezard/go-difflib v1.0.0 // indirect @@ -68,7 +65,7 @@ require ( github.com/xdg-go/pbkdf2 v1.0.0 // indirect github.com/xdg-go/scram v1.1.2 // indirect github.com/xdg-go/stringprep v1.0.4 // indirect - github.com/youmark/pkcs8 v0.0.0-20201027041543-1326539a0a0a // indirect + github.com/youmark/pkcs8 v0.0.0-20240726163527-a2c0da244d78 // indirect go.etcd.io/etcd/api/v3 v3.5.4 // indirect go.etcd.io/etcd/client/pkg/v3 v3.5.4 // indirect go.etcd.io/etcd/client/v3 v3.5.4 // indirect @@ -90,7 +87,7 @@ require ( require ( github.com/segmentio/kafka-go v0.4.47 - go.mongodb.org/mongo-driver v1.10.1 + go.mongodb.org/mongo-driver v1.17.0 go4.org/unsafe/assume-no-moving-gc v0.0.0-20230525183740-e7c30c78aeb2 // indirect ) diff --git a/go.sum b/go.sum index ff3fb5be..3405c601 100644 --- a/go.sum +++ b/go.sum @@ -15,8 +15,6 @@ github.com/alecthomas/units v0.0.0-20190717042225-c3de453c63f4/go.mod h1:ybxpYRF github.com/alecthomas/units v0.0.0-20190924025748-f65c72e2690d/go.mod h1:rBZYJk541a8SKzHPHnH3zbiI+7dagKZ0cgpgrD7Fyho= github.com/antihax/optional v1.0.0 h1:xK2lYat7ZLaVVcIuj82J8kIro4V6kDe0AUDFboUCwcg= github.com/antihax/optional v1.0.0/go.mod h1:uupD/76wgC+ih3iEmQUL+0Ugr19nfwCT1kdvxnR2qWY= -github.com/antonfisher/nested-logrus-formatter v1.3.1 h1:NFJIr+pzwv5QLHTPyKz9UMEoHck02Q9L0FP13b/xSbQ= -github.com/antonfisher/nested-logrus-formatter v1.3.1/go.mod h1:6WTfyWFkBc9+zyBaKIqRrg/KwMqBbodBjgbHjDz7zjA= github.com/asaskevich/govalidator v0.0.0-20210307081110-f21760c49a8d h1:Byv0BzEl3/e6D5CLfI0j/7hiIEtvGVFPCZ7Ei2oq8iQ= github.com/asaskevich/govalidator v0.0.0-20210307081110-f21760c49a8d/go.mod h1:WaHUgvxTVq04UNunO+XhnAqY/wQc+bxr74GqbsZ/Jqw= github.com/avast/retry-go/v4 v4.1.0 h1:CwudD9anYv6JMVnDuTRlK6kLo4dBamiL+F3U8YDiyfg= @@ -130,7 +128,6 @@ github.com/golang/protobuf v1.5.0/go.mod h1:FsONVRAS9T7sI+LIUmWTfcYkHO4aIWwzhcaS github.com/golang/protobuf v1.5.2/go.mod h1:XVQd3VNwM+JqD3oG2Ue2ip4fOMUkwXdXDdiuN0vRsmY= github.com/golang/protobuf v1.5.4 h1:i7eJL8qZTpSEXOPTxNKhASYpMn+8e5Q6AdndVa1dWek= github.com/golang/protobuf v1.5.4/go.mod h1:lnTiLA8Wa4RWRcIUkrtSVa5nRhsEGBg48fD6rSs7xps= -github.com/golang/snappy v0.0.1/go.mod h1:/XxbfmMg8lxefKM7IXC3fBNl/7bRcc72aCRzEWrmP2Q= github.com/golang/snappy v0.0.4 h1:yAGX7huGHXlcLOEtBnF4w7FQwA26wojNCwOYAEhLjQM= github.com/golang/snappy v0.0.4/go.mod h1:/XxbfmMg8lxefKM7IXC3fBNl/7bRcc72aCRzEWrmP2Q= github.com/google/go-cmp v0.2.0/go.mod h1:oXzfMopK8JAjlY9xF4vHSVASa0yLyX7SntLO5aqRK0M= @@ -138,7 +135,6 @@ github.com/google/go-cmp v0.3.0/go.mod h1:8QqcDgzrUqlUb/G2PQTWiueGozuR1884gddMyw github.com/google/go-cmp v0.3.1/go.mod h1:8QqcDgzrUqlUb/G2PQTWiueGozuR1884gddMywk6iLU= github.com/google/go-cmp v0.4.0/go.mod h1:v8dTdLbMG2kIc/vJvl+f65V22dbkXbowE6jgT/gNBxE= github.com/google/go-cmp v0.5.0/go.mod h1:v8dTdLbMG2kIc/vJvl+f65V22dbkXbowE6jgT/gNBxE= -github.com/google/go-cmp v0.5.2/go.mod h1:v8dTdLbMG2kIc/vJvl+f65V22dbkXbowE6jgT/gNBxE= github.com/google/go-cmp v0.5.4/go.mod h1:v8dTdLbMG2kIc/vJvl+f65V22dbkXbowE6jgT/gNBxE= github.com/google/go-cmp v0.5.5/go.mod h1:v8dTdLbMG2kIc/vJvl+f65V22dbkXbowE6jgT/gNBxE= github.com/google/go-cmp v0.6.0 h1:ofyhxvXcZhMsU5ulbFiLKl/XBFqE1GSq7atu8tAmTRI= @@ -167,7 +163,6 @@ github.com/julienschmidt/httprouter v1.2.0/go.mod h1:SYymIcj16QtmaHHD7aYtjjsJG7V github.com/julienschmidt/httprouter v1.3.0/go.mod h1:JR6WtHb+2LUe8TCKY3cZOxFyyO8IZAc4RVcycCCAKdM= github.com/kisielk/errcheck v1.5.0/go.mod h1:pFxgyoBC7bSaBwPgfKdkLd5X25qrDl4LWUI2bnpBCr8= github.com/kisielk/gotool v1.0.0/go.mod h1:XhKaO+MFFWcvkIS/tQcRk01m1F5IRFswLeQ+oQHNcck= -github.com/klauspost/compress v1.13.6/go.mod h1:/3/Vjq9QcHkK5uEr5lBEmyoZ1iFhe47etQ6QUkpK6sk= github.com/klauspost/compress v1.15.9/go.mod h1:PhcZ0MbTNciWF3rruxRgKxI5NkcHHrHUDtV4Yw2GlzU= github.com/klauspost/compress v1.17.9 h1:6KIumPrER1LHsvBVuDa0r5xaG0Es51mhhB9BQB2qeMA= github.com/klauspost/compress v1.17.9/go.mod h1:Di0epgTjJY877eYKx5yC51cX2A2Vl2ibi7bDH9ttBbw= @@ -216,9 +211,8 @@ github.com/modern-go/reflect2 v1.0.2 h1:xBagoLtFs94CBntxluKeaWgTMpvLxC4ur3nMaC9G github.com/modern-go/reflect2 v1.0.2/go.mod h1:yWuevngMOJpCy52FWWMvUC8ws7m/LJsjYzDa0/r8luk= github.com/mohae/deepcopy v0.0.0-20170929034955-c48cc78d4826 h1:RWengNIwukTxcDr9M+97sNutRR1RKhG96O6jWumTTnw= github.com/mohae/deepcopy v0.0.0-20170929034955-c48cc78d4826/go.mod h1:TaXosZuwdSHYgviHp1DAtfrULt5eUgsSMsZf+YrPgl8= -github.com/montanaflynn/stats v0.0.0-20171201202039-1bf9dbcd8cbe/go.mod h1:wL8QJuTMNUDYhXwkmfOly8iTdp5TEcJFWZD2D7SIkUc= -github.com/montanaflynn/stats v0.6.6 h1:Duep6KMIDpY4Yo11iFsvyqJDyfzLF9+sndUKT+v64GQ= -github.com/montanaflynn/stats v0.6.6/go.mod h1:etXPPgVO6n31NxCd9KQUMvCM+ve0ruNzt6R8Bnaayow= +github.com/montanaflynn/stats v0.7.1 h1:etflOAAHORrCC44V+aR6Ftzort912ZU+YLiSTuV8eaE= +github.com/montanaflynn/stats v0.7.1/go.mod h1:etXPPgVO6n31NxCd9KQUMvCM+ve0ruNzt6R8Bnaayow= github.com/morikuni/aec v1.0.0 h1:nP9CBfwrvYnBRgY6qfDQkygYDmYwOilePFkwzv4dU8A= github.com/morikuni/aec v1.0.0/go.mod h1:BbKIizmSmc5MMPqRYbxO4ZU0S0+P200+tUnFx7PXmsc= github.com/munnerz/goautoneg v0.0.0-20191010083416-a7dc8b61c822 h1:C3w9PqII01/Oq1c1nUAm88MOHcQC9l5mIlSMApZMrHA= @@ -233,16 +227,14 @@ github.com/omec-project/aper v1.2.1 h1:A4KhlTMta5mUA1DX2njOjOn0SuFi5WoWnSqdbRnl9 github.com/omec-project/aper v1.2.1/go.mod h1:CbCZ0uNmcD3XA4YM6wBwpqP1PYtGAaC3RqLL4B5gG2U= github.com/omec-project/config5g v1.5.0 h1:VC7uHIdg4S4F5onYvpFfaEAFBttWwWh6OSnNnSA20aM= github.com/omec-project/config5g v1.5.0/go.mod h1:yTjqsOjy8KQ8o4AlnPeZfP32CEvlm0kug3bMwZ3IDOQ= -github.com/omec-project/metricfunc v1.4.1 h1:n1EajFuGaHs9wouLL2GOBEt1oWj074dXei/NWLGNDaw= -github.com/omec-project/metricfunc v1.4.1/go.mod h1:biEfEyPV0KdhwYMQEcDFwuju7vQfx7fAvgDdc8MvF84= -github.com/omec-project/nas v1.3.0 h1:zNqEQSNTsupT3qP6keSuOusOHKrqEYoC5ghKR8TpKEQ= -github.com/omec-project/nas v1.3.0/go.mod h1:So4hpY95XZTpX0Joco/axIH4MlO0o13UT1rWQWZEuLQ= +github.com/omec-project/nas v1.4.1 h1:Ui3k5TnOQ8IGt09qUboaZ05IuMuVSbjZ54Y7iy85iVs= +github.com/omec-project/nas v1.4.1/go.mod h1:R0x9ehAHi/CUdsMWP+XmefjloEGwobkqz1/c8308yBo= github.com/omec-project/ngap v1.3.0 h1:NuAc6GZRup6E3jg+fGTy8aR4VkOlB1mnkaaYr6OGmMc= github.com/omec-project/ngap v1.3.0/go.mod h1:XBHem/s2xtRNCLPgH7Ubs7i72BTAvK1EILTWf7iQ0ao= github.com/omec-project/openapi v1.3.1 h1:NCteMRdMtWnMhf1CXYduuLgeu8fEhc/7XO1CiE7fN3Y= github.com/omec-project/openapi v1.3.1/go.mod h1:cR6Iharp2TLOzEmskQ/EdCVFZnpKh0zTvUSSuyXAYLE= -github.com/omec-project/util v1.1.0 h1:TUuLmzqTLChIEXQlK9g5Ihgmw4FUm/UJnjfu0wT8Gz0= -github.com/omec-project/util v1.1.0/go.mod h1:BEv8nCokB4j0fgAQ6VVkKuQ2PSP3DJMEmz25pFMw5X8= +github.com/omec-project/util v1.2.1 h1:+o5kbnZzKBmbqT4oprVGPgL0jH5b8BvRMfLye5srGQ4= +github.com/omec-project/util v1.2.1/go.mod h1:kUF2LXhmtw+m7Bk5IGOMFLj7CA8VKtilLI/9QBJcfxE= github.com/onsi/ginkgo v1.16.5 h1:8xi0RTUf59SOSfEtZMvwTvXYMzG4gV23XVHOZiXNtnE= github.com/onsi/ginkgo v1.16.5/go.mod h1:+E8gABHa3K6zRBolWtd+ROzc/U5bkGt0FwiG042wbpU= github.com/onsi/gomega v1.18.1 h1:M1GfJqGRrBrrGGsbxzV5dqM2U2ApXefZCQpkukxYRLE= @@ -313,7 +305,6 @@ github.com/stretchr/testify v1.2.2/go.mod h1:a8OnRcib4nhh0OaRAV+Yts87kKdq0PP7pXf 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.6.1/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg= github.com/stretchr/testify v1.7.0/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg= github.com/stretchr/testify v1.7.1/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg= github.com/stretchr/testify v1.8.0/go.mod h1:yNjHg4UonilssWZ8iaSj1OCr/vHnekPRkoO+kdMU+MU= @@ -325,8 +316,6 @@ github.com/testcontainers/testcontainers-go v0.13.0 h1:OUujSlEGsXVo/ykPVZk3KanBN github.com/testcontainers/testcontainers-go v0.13.0/go.mod h1:z1abufU633Eb/FmSBTzV6ntZAC1eZBYPtaFsn4nPuDk= github.com/thakurajayL/go-ipam v0.0.5-dev h1:EgOkLUKjGqVLjQ5RKK14x2W/EUhSm8bPjiAC0g1tyPw= github.com/thakurajayL/go-ipam v0.0.5-dev/go.mod h1:kriWKdZOK9c1i9XAEjx+FfEAjzV/mx2YL3Jl4dhJ3IY= -github.com/tidwall/pretty v1.0.0 h1:HsD+QiTn7sK6flMKIvNmpqz1qrpP3Ps6jOKIKMooyg4= -github.com/tidwall/pretty v1.0.0/go.mod h1:XNkn88O1ChpSDQmQeStsy+sBenx6DDtFZJxhVysOjyk= github.com/twitchyliquid64/golang-asm v0.15.1 h1:SU5vSMR7hnwNxj24w34ZyCi/FmDZTkS4MhqMhdFk5YI= github.com/twitchyliquid64/golang-asm v0.15.1/go.mod h1:a1lVb/DtPvCB8fslRZhAngC2+aY1QWCk3Cedj/Gdt08= github.com/ugorji/go/codec v1.2.12 h1:9LC83zGrHhuUA9l16C9AHXAqEV/2wBQ4nkvumAE65EE= @@ -337,15 +326,12 @@ 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/xdg-go/pbkdf2 v1.0.0 h1:Su7DPu48wXMwC3bs7MCNG+z4FhcyEuz5dlvchbq0B0c= github.com/xdg-go/pbkdf2 v1.0.0/go.mod h1:jrpuAogTd400dnrH08LKmI/xc1MbPOebTwRqcT5RDeI= -github.com/xdg-go/scram v1.1.1/go.mod h1:RaEWvsqvNKKvBPvcKeFjrG2cJqOkHTiyTpzz23ni57g= github.com/xdg-go/scram v1.1.2 h1:FHX5I5B4i4hKRVRBCFRxq1iQRej7WO3hhBuJf+UUySY= github.com/xdg-go/scram v1.1.2/go.mod h1:RT/sEzTbU5y00aCK8UOx6R7YryM0iF1N2MOmC3kKLN4= -github.com/xdg-go/stringprep v1.0.3/go.mod h1:W3f5j4i+9rC0kuIEJL0ky1VpHXQU3ocBgklLGvcBnW8= github.com/xdg-go/stringprep v1.0.4 h1:XLI/Ng3O1Atzq0oBs3TWm+5ZVgkq2aqdlvP9JtoZ6c8= github.com/xdg-go/stringprep v1.0.4/go.mod h1:mPGuuIYwz7CmR2bT9j4GbQqutWS1zV24gijq1dTyGkM= -github.com/youmark/pkcs8 v0.0.0-20181117223130-1be2e3e5546d/go.mod h1:rHwXgn7JulP+udvsHwJoVG1YGAP6VLg4y9I5dyZdqmA= -github.com/youmark/pkcs8 v0.0.0-20201027041543-1326539a0a0a h1:fZHgsYlfvtyqToslyjUt3VOPF4J7aK/3MPcK7xp3PDk= -github.com/youmark/pkcs8 v0.0.0-20201027041543-1326539a0a0a/go.mod h1:ul22v+Nro/R083muKhosV54bj5niojjWZvU8xrevuH4= +github.com/youmark/pkcs8 v0.0.0-20240726163527-a2c0da244d78 h1:ilQV1hzziu+LLM3zUTJ0trRztfwgjqKnBWNtSRkbmwM= +github.com/youmark/pkcs8 v0.0.0-20240726163527-a2c0da244d78/go.mod h1:aL8wCCfTfSfmXjznFBSZNN13rSJjlIOI1fUNAtF7rmI= github.com/yuin/goldmark v1.1.27/go.mod h1:3hX8gzYuyVAZsxl0MRgGTJEmQBFcNTphYh9decYSb74= github.com/yuin/goldmark v1.2.1/go.mod h1:3hX8gzYuyVAZsxl0MRgGTJEmQBFcNTphYh9decYSb74= github.com/yuin/goldmark v1.3.5/go.mod h1:mwnBkeHKe2W/ZEtQ+71ViKU8L12m81fl3OWwC1Zlc8k= @@ -357,8 +343,8 @@ go.etcd.io/etcd/client/pkg/v3 v3.5.4 h1:lrneYvz923dvC14R54XcA7FXoZ3mlGZAgmwhfm7H go.etcd.io/etcd/client/pkg/v3 v3.5.4/go.mod h1:IJHfcCEKxYu1Os13ZdwCwIUTUVGYTSAM3YSwc9/Ac1g= go.etcd.io/etcd/client/v3 v3.5.4 h1:p83BUL3tAYS0OT/r0qglgc3M1JjhM0diV8DSWAhVXv4= go.etcd.io/etcd/client/v3 v3.5.4/go.mod h1:ZaRkVgBZC+L+dLCjTcF1hRXpgZXQPOvnA/Ak/gq3kiY= -go.mongodb.org/mongo-driver v1.10.1 h1:NujsPveKwHaWuKUer/ceo9DzEe7HIj1SlJ6uvXZG0S4= -go.mongodb.org/mongo-driver v1.10.1/go.mod h1:z4XpeoU6w+9Vht+jAFyLgVrD+jGSQQe0+CBWFHNiHt8= +go.mongodb.org/mongo-driver v1.17.0 h1:Hp4q2MCjvY19ViwimTs00wHi7G4yzxh4/2+nTx8r40k= +go.mongodb.org/mongo-driver v1.17.0/go.mod h1:wwWm/+BuOddhcq3n68LKRmgk2wXzmF6s0SFOa0GINL4= go.opencensus.io v0.23.0 h1:gqCw0LfLxScz8irSi8exQc7fyQ0fKQU/qnC/X8+V/1M= go.opencensus.io v0.23.0/go.mod h1:XItmlyltB5F7CS4xOC1DcqMoFqwtC6OG2xF7mCv7P7E= go.uber.org/atomic v1.7.0/go.mod h1:fEN4uk6kAWBTFdckzkM89CLk9XfWZrxpCo0nPH17wJc= @@ -383,10 +369,8 @@ golang.org/x/arch v0.8.0/go.mod h1:FEVrYAQjsQXMVJ1nsMoVVXPZg6p2JE2mx8psSWTDQys= 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= -golang.org/x/crypto v0.0.0-20200302210943-78000ba7a073/go.mod h1:LzIPMQfyMNhhGPhUkYOs5KpL4U8rLKemX1yGLhDgUto= golang.org/x/crypto v0.0.0-20200622213623-75b288015ac9/go.mod h1:LzIPMQfyMNhhGPhUkYOs5KpL4U8rLKemX1yGLhDgUto= golang.org/x/crypto v0.0.0-20210921155107-089bfa567519/go.mod h1:GvvjBRRGRdwPK5ydBHafDWAxML/pGHZbMvKqRZ5+Abc= -golang.org/x/crypto v0.0.0-20220622213112-05595931fe9d/go.mod h1:IxCIyHEi3zRg3s0A5j5BB6A9Jmi73HwBIUl50j+osU4= golang.org/x/crypto v0.14.0/go.mod h1:MVFd36DqK4CsrnJYDkBA3VC4m2GkXAM0PvzMCn4JQf4= golang.org/x/crypto v0.27.0 h1:GXm2NjJrPaiv/h1tb2UH8QfgC/hOf/+z0p6PT8o1w7A= golang.org/x/crypto v0.27.0/go.mod h1:1Xngt8kV6Dvbssa53Ziq6Eqn0HqbZi5Z6R0ZpwQzt70= @@ -417,7 +401,6 @@ golang.org/x/net v0.0.0-20201021035429-f5854403a974/go.mod h1:sp8m0HH+o8qH0wwXwY golang.org/x/net v0.0.0-20210226172049-e18ecbb05110/go.mod h1:m0MpNAwzfU5UDzcl9v0D8zg8gWTRqZa9RBIspLL5mdg= golang.org/x/net v0.0.0-20210405180319-a5a99cb37ef4/go.mod h1:p54w0d4576C0XHj96bSt6lcn1PtDYWL6XObtHCRCNQM= golang.org/x/net v0.0.0-20210805182204-aaa1db679c0d/go.mod h1:9nx3DQGgdP8bBQD5qxJ1jj9UTztislL4KSBs9R2vV5Y= -golang.org/x/net v0.0.0-20211112202133-69e39bad7dc2/go.mod h1:9nx3DQGgdP8bBQD5qxJ1jj9UTztislL4KSBs9R2vV5Y= golang.org/x/net v0.0.0-20220722155237-a158d28d115b/go.mod h1:XRhObCWvk6IyKnWLug+ECip1KBveYUHfp+8e9klMJ9c= golang.org/x/net v0.6.0/go.mod h1:2Tu9+aMcznHK/AK1HMvgo6xiTLG5rD5rZLDS+rp2Bjs= golang.org/x/net v0.10.0/go.mod h1:0qNGK6F8kojg2nk9dLZ2mShWaEBan6FAoqfSigmmuDg= @@ -464,7 +447,6 @@ golang.org/x/sys v0.0.0-20210615035016-665e8c7367d1/go.mod h1:oPkhp1MJrh7nUepCBc golang.org/x/sys v0.0.0-20210809222454-d867a43fc93e/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.0.0-20211107104306-e0b2ad06fe42/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.0.0-20220520151302-bc2c85ada10a/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= -golang.org/x/sys v0.0.0-20220715151400-c0bba94af5f8/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.0.0-20220722155257-8c9f86f7a55f/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.5.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.6.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= @@ -541,7 +523,6 @@ google.golang.org/protobuf v1.34.2 h1:6xV6lTsCfpGD21XK49h7MhtcApnLqkfYgPcdHftf6h google.golang.org/protobuf v1.34.2/go.mod h1:qYOHts0dSfpeUzUFpOMr/WGzszTmLH+DiWniOlNbLDw= gopkg.in/alecthomas/kingpin.v2 v2.2.6/go.mod h1:FMv+mEhP44yOT+4EoQTLFTRgOQ1FBLkstjWtayDeSgw= gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0= -gopkg.in/check.v1 v1.0.0-20180628173108-788fd7840127/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0= gopkg.in/check.v1 v1.0.0-20190902080502-41f04d3bba15/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0= gopkg.in/check.v1 v1.0.0-20201130134442-10cb98267c6c h1:Hei/4ADfdWqJk1ZMxUNpqntNwaWcugrBjAiHlqqRiVk= gopkg.in/check.v1 v1.0.0-20201130134442-10cb98267c6c/go.mod h1:JHkPIbrfpd72SG/EVd6muEfDQjcINNoR0C8j2r3qZ4Q= diff --git a/logger/logger.go b/logger/logger.go index 1dffa41e..abc7a7ab 100644 --- a/logger/logger.go +++ b/logger/logger.go @@ -1,3 +1,4 @@ +// SPDX-FileCopyrightText: 2024 Intel Corporation // SPDX-FileCopyrightText: 2021 Open Networking Foundation // Copyright 2019 free5GC.org // @@ -6,66 +7,81 @@ package logger import ( - "time" - - formatter "github.com/antonfisher/nested-logrus-formatter" - "github.com/sirupsen/logrus" + "go.uber.org/zap" + "go.uber.org/zap/zapcore" ) var ( - log *logrus.Logger - AppLog *logrus.Entry - InitLog *logrus.Entry - CfgLog *logrus.Entry - DataRepoLog *logrus.Entry - GsmLog *logrus.Entry - PfcpLog *logrus.Entry - PduSessLog *logrus.Entry - CtxLog *logrus.Entry - ConsumerLog *logrus.Entry - GinLog *logrus.Entry - GrpcLog *logrus.Entry - UPNodeLog *logrus.Entry - FsmLog *logrus.Entry - TxnFsmLog *logrus.Entry - QosLog *logrus.Entry - KafkaLog *logrus.Entry + log *zap.Logger + AppLog *zap.SugaredLogger + InitLog *zap.SugaredLogger + CfgLog *zap.SugaredLogger + DataRepoLog *zap.SugaredLogger + GsmLog *zap.SugaredLogger + PfcpLog *zap.SugaredLogger + PduSessLog *zap.SugaredLogger + CtxLog *zap.SugaredLogger + ConsumerLog *zap.SugaredLogger + GinLog *zap.SugaredLogger + GrpcLog *zap.SugaredLogger + UPNodeLog *zap.SugaredLogger + FsmLog *zap.SugaredLogger + TxnFsmLog *zap.SugaredLogger + QosLog *zap.SugaredLogger + KafkaLog *zap.SugaredLogger + atomicLevel zap.AtomicLevel ) func init() { - log = logrus.New() - log.SetReportCaller(false) + 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 = "" - log.Formatter = &formatter.Formatter{ - TimestampFormat: time.RFC3339, - TrimMessages: true, - NoFieldsSpace: true, - HideKeys: true, - FieldsOrder: []string{"component", "category"}, + var err error + log, err = config.Build() + if err != nil { + panic(err) } - AppLog = log.WithFields(logrus.Fields{"component": "SMF", "category": "App"}) - InitLog = log.WithFields(logrus.Fields{"component": "SMF", "category": "Init"}) - CfgLog = log.WithFields(logrus.Fields{"component": "SMF", "category": "CFG"}) - DataRepoLog = log.WithFields(logrus.Fields{"component": "SMF", "category": "DRepo"}) - PfcpLog = log.WithFields(logrus.Fields{"component": "SMF", "category": "PFCP"}) - PduSessLog = log.WithFields(logrus.Fields{"component": "SMF", "category": "PduSess"}) - GsmLog = log.WithFields(logrus.Fields{"component": "SMF", "category": "GSM"}) - CtxLog = log.WithFields(logrus.Fields{"component": "SMF", "category": "CTX"}) - ConsumerLog = log.WithFields(logrus.Fields{"component": "SMF", "category": "Consumer"}) - GinLog = log.WithFields(logrus.Fields{"component": "SMF", "category": "GIN"}) - GrpcLog = log.WithFields(logrus.Fields{"component": "SMF", "category": "GRPC"}) - UPNodeLog = log.WithFields(logrus.Fields{"component": "SMF", "category": "UPNode"}) - FsmLog = log.WithFields(logrus.Fields{"component": "SMF", "category": "Fsm"}) - TxnFsmLog = log.WithFields(logrus.Fields{"component": "SMF", "category": "TxnFsm"}) - QosLog = log.WithFields(logrus.Fields{"component": "SMF", "category": "QosFsm"}) - KafkaLog = log.WithFields(logrus.Fields{"component": "SMF", "category": "Kafka"}) + AppLog = log.Sugar().With("component", "SMF", "category", "App") + InitLog = log.Sugar().With("component", "SMF", "category", "Init") + CfgLog = log.Sugar().With("component", "SMF", "category", "CFG") + DataRepoLog = log.Sugar().With("component", "SMF", "category", "DRepo") + PfcpLog = log.Sugar().With("component", "SMF", "category", "PFCP") + PduSessLog = log.Sugar().With("component", "SMF", "category", "PduSess") + GsmLog = log.Sugar().With("component", "SMF", "category", "GSM") + CtxLog = log.Sugar().With("component", "SMF", "category", "CTX") + ConsumerLog = log.Sugar().With("component", "SMF", "category", "Consumer") + GinLog = log.Sugar().With("component", "SMF", "category", "GIN") + GrpcLog = log.Sugar().With("component", "SMF", "category", "GRPC") + UPNodeLog = log.Sugar().With("component", "SMF", "category", "UPNode") + FsmLog = log.Sugar().With("component", "SMF", "category", "Fsm") + TxnFsmLog = log.Sugar().With("component", "SMF", "category", "TxnFsm") + QosLog = log.Sugar().With("component", "SMF", "category", "QosFsm") + KafkaLog = log.Sugar().With("component", "SMF", "category", "Kafka") } -func SetLogLevel(level logrus.Level) { - log.SetLevel(level) +func GetLogger() *zap.Logger { + return log } -func SetReportCaller(set bool) { - log.SetReportCaller(set) +// 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/metrics/kafka.go b/metrics/kafka.go index 43664dfc..a5110944 100644 --- a/metrics/kafka.go +++ b/metrics/kafka.go @@ -11,9 +11,9 @@ import ( "fmt" "time" - mi "github.com/omec-project/metricfunc/pkg/metricinfo" "github.com/omec-project/smf/factory" "github.com/omec-project/smf/logger" + mi "github.com/omec-project/util/metricinfo" "github.com/segmentio/kafka-go" ) diff --git a/metrics/kafka_test.go b/metrics/kafka_test.go index 0a2bd445..c03a7595 100644 --- a/metrics/kafka_test.go +++ b/metrics/kafka_test.go @@ -6,8 +6,8 @@ package metrics import ( "testing" - "github.com/omec-project/metricfunc/pkg/metricinfo" "github.com/omec-project/smf/factory" + "github.com/omec-project/util/metricinfo" ) var my_false bool = false diff --git a/metrics/telemetry.go b/metrics/telemetry.go index 6f52c836..54780870 100644 --- a/metrics/telemetry.go +++ b/metrics/telemetry.go @@ -10,9 +10,9 @@ package metrics import ( - "log" "net/http" + "github.com/omec-project/smf/logger" "github.com/prometheus/client_golang/prometheus" "github.com/prometheus/client_golang/prometheus/promhttp" ) @@ -98,7 +98,7 @@ func init() { smfStats = initSmfStats() if err := smfStats.register(); err != nil { - log.Panicln("SMF Stats register failed") + logger.KafkaLog.Panicln("SMF Stats register failed") } } @@ -107,7 +107,7 @@ func InitMetrics() { http.Handle("/metrics", promhttp.Handler()) err := http.ListenAndServe(":9089", nil) if err != nil { - log.Fatalf("failed to start metrics server: %v", err) + logger.KafkaLog.Fatalf("failed to start metrics server: %v", err) } } diff --git a/oam/routers.go b/oam/routers.go index f1dca30b..52c37987 100644 --- a/oam/routers.go +++ b/oam/routers.go @@ -29,7 +29,7 @@ type Routes []Route // NewRouter returns a new router. func NewRouter() *gin.Engine { - router := utilLogger.NewGinWithLogrus(logger.GinLog) + router := utilLogger.NewGinWithZap(logger.GinLog) AddService(router) return router } diff --git a/pdusession/api_individual_sm_context.go b/pdusession/api_individual_sm_context.go index a18e5587..1b65ac14 100644 --- a/pdusession/api_individual_sm_context.go +++ b/pdusession/api_individual_sm_context.go @@ -14,12 +14,11 @@ package pdusession import ( - "log" "net/http" "strings" "github.com/gin-gonic/gin" - mi "github.com/omec-project/metricfunc/pkg/metricinfo" + mi "github.com/omec-project/util/metricinfo" "github.com/omec-project/openapi" "github.com/omec-project/openapi/models" smf_context "github.com/omec-project/smf/context" @@ -33,7 +32,7 @@ import ( // HTTPReleaseSmContext - Release SM Context func HTTPReleaseSmContext(c *gin.Context) { - logger.PduSessLog.Info("Receive Release SM Context Request") + logger.PduSessLog.Infoln("receive Release SM Context Request") stats.IncrementN11MsgStats(smf_context.SMF_Self().NfInstanceID, string(svcmsgtypes.ReleaseSmContext), "In", "", "") stats.PublishMsgEvent(mi.Smf_msg_type_pdu_sess_release_req) @@ -49,7 +48,7 @@ func HTTPReleaseSmContext(c *gin.Context) { err = c.ShouldBindWith(&request, openapi.MultipartRelatedBinding{}) } if err != nil { - log.Print(err) + logger.PduSessLog.Errorln(err) problemDetail := "[Request Body] " + err.Error() rsp := models.ProblemDetails{ Title: "Malformed request syntax", @@ -85,7 +84,7 @@ func RetrieveSmContext(c *gin.Context) { // HTTPUpdateSmContext - Update SM Context func HTTPUpdateSmContext(c *gin.Context) { - logger.PduSessLog.Info("Receive Update SM Context Request") + logger.PduSessLog.Infoln("receive Update SM Context Request") stats.IncrementN11MsgStats(smf_context.SMF_Self().NfInstanceID, string(svcmsgtypes.UpdateSmContext), "In", "", "") stats.PublishMsgEvent(mi.Smf_msg_type_pdu_sess_modify_req) @@ -111,7 +110,7 @@ func HTTPUpdateSmContext(c *gin.Context) { c.JSON(http.StatusBadRequest, rsp) stats.IncrementN11MsgStats(smf_context.SMF_Self().NfInstanceID, string(svcmsgtypes.UpdateSmContext), "Out", http.StatusText(http.StatusBadRequest), "Malformed") - log.Print(err) + logger.PduSessLog.Errorln(err) return } diff --git a/pdusession/api_sm_contexts_collection.go b/pdusession/api_sm_contexts_collection.go index 78e91594..d445172c 100644 --- a/pdusession/api_sm_contexts_collection.go +++ b/pdusession/api_sm_contexts_collection.go @@ -18,7 +18,7 @@ import ( "strings" "github.com/gin-gonic/gin" - mi "github.com/omec-project/metricfunc/pkg/metricinfo" + mi "github.com/omec-project/util/metricinfo" "github.com/omec-project/openapi" "github.com/omec-project/openapi/models" smf_context "github.com/omec-project/smf/context" @@ -32,7 +32,7 @@ import ( // HTTPPostSmContexts - Create SM Context func HTTPPostSmContexts(c *gin.Context) { - logger.PduSessLog.Info("Receive Create SM Context Request") + logger.PduSessLog.Infoln("receive create SM Context Request") var request models.PostSmContextsRequest stats.IncrementN11MsgStats(smf_context.SMF_Self().NfInstanceID, string(svcmsgtypes.CreateSmContext), "In", "", "") stats.PublishMsgEvent(mi.Smf_msg_type_pdu_sess_create_req) diff --git a/pdusession/dummy_server.go b/pdusession/dummy_server.go index 342cceee..3fb6348a 100644 --- a/pdusession/dummy_server.go +++ b/pdusession/dummy_server.go @@ -5,7 +5,6 @@ package pdusession import ( - "log" "net/http" "github.com/omec-project/smf/logger" @@ -17,7 +16,7 @@ import ( ) func DummyServer() { - router := utilLogger.NewGinWithLogrus(logger.GinLog) + router := utilLogger.NewGinWithZap(logger.GinLog) AddService(router) @@ -34,6 +33,6 @@ func DummyServer() { } if err := server.ListenAndServeTLS(smfPemPath, smfkeyPath); err != nil { - log.Fatal(err) + logger.PduSessLog.Fatalln(err) } } diff --git a/pdusession/routers.go b/pdusession/routers.go index 0590decf..9c769910 100644 --- a/pdusession/routers.go +++ b/pdusession/routers.go @@ -39,7 +39,7 @@ type Routes []Route // NewRouter returns a new router. func NewRouter() *gin.Engine { - router := utilLogger.NewGinWithLogrus(logger.GinLog) + router := utilLogger.NewGinWithZap(logger.GinLog) AddService(router) return router } diff --git a/pfcp/adapter/adapter.go b/pfcp/adapter/adapter.go index bf267dc5..3222dce9 100644 --- a/pfcp/adapter/adapter.go +++ b/pfcp/adapter/adapter.go @@ -114,7 +114,7 @@ func HandlePfcpAssociationSetupResponse(msg *udp.Message) { upf := context.RetrieveUPFNodeByNodeID(*nodeID) if upf == nil { - logger.PfcpLog.Errorf("can't find UPF[%s]", nodeID.ResolveNodeIdToIp().String()) + logger.PfcpLog.Errorf("can not find UPF[%s]", nodeID.ResolveNodeIdToIp().String()) return } @@ -122,7 +122,7 @@ func HandlePfcpAssociationSetupResponse(msg *udp.Message) { if userPlaneIPResourceInformation != nil { upfProvidedDnn := string(userPlaneIPResourceInformation.NetworkInstance) if !upf.IsDnnConfigured(upfProvidedDnn) { - logger.PfcpLog.Errorf("handle PFCP Association Setup Response, DNN mismatch, [%v] is not configured ", upfProvidedDnn) + logger.PfcpLog.Errorf("handle PFCP Association Setup Response, DNN mismatch, [%v] is not configured", upfProvidedDnn) return } } @@ -230,7 +230,7 @@ func HandlePfcpSessionEstablishmentResponse(msg *udp.Message) { SEID := rsp.SEID() if SEID == 0 { if eventData, ok := msg.EventData.(udp.PfcpEventData); !ok { - logger.PfcpLog.Warnf("PFCP Session Establish Response found invalid event data, response discarded") + logger.PfcpLog.Warnln("PFCP Session Establish Response found invalid event data, response discarded") return } else { SEID = eventData.LSEID @@ -299,7 +299,7 @@ func HandlePfcpSessionModificationResponse(msg *udp.Message) { cause := pfcpRsp.Cause if cause == nil { - logger.PfcpLog.Warnf("PFCP Session Modification Response found invalid cause, response discarded") + logger.PfcpLog.Warnln("PFCP Session Modification Response found invalid cause, response discarded") return } causeValue, err := cause.Cause() @@ -318,7 +318,7 @@ func HandlePfcpSessionModificationResponse(msg *udp.Message) { if SEID == 0 { if eventData, ok := msg.EventData.(udp.PfcpEventData); !ok { - logger.PfcpLog.Warnf("PFCP Session Modification Response found invalid event data, response discarded") + logger.PfcpLog.Warnln("PFCP Session Modification Response found invalid event data, response discarded") return } else { SEID = eventData.LSEID @@ -331,7 +331,7 @@ func HandlePfcpSessionModificationResponse(msg *udp.Message) { upfNodeID := smContext.GetNodeIDByLocalSEID(SEID) upfIP := upfNodeID.ResolveNodeIdToIp().String() delete(smContext.PendingUPF, upfIP) - smContext.SubPduSessLog.Tracef("Delete pending pfcp response: UPF IP [%s]\n", upfIP) + smContext.SubPduSessLog.Debugf("delete pending pfcp response: UPF IP [%s]", upfIP) if smContext.PendingUPF.IsEmpty() { smContext.SBIPFCPCommunicationChan <- context.SessionUpdateSuccess @@ -346,9 +346,9 @@ func HandlePfcpSessionModificationResponse(msg *udp.Message) { } } - smContext.SubCtxLog.Traceln("PFCP Session Context") + smContext.SubCtxLog.Debugln("PFCP Session Context") for _, ctx := range smContext.PFCPContext { - smContext.SubCtxLog.Traceln(ctx.String()) + smContext.SubCtxLog.Debugln(ctx.String()) } } @@ -358,12 +358,12 @@ func HandlePfcpSessionDeletionResponse(msg *udp.Message) { logger.PfcpLog.Errorln("invalid PFCP Session Deletion Response") return } - logger.PfcpLog.Infof("handle PFCP Session Deletion Response") + logger.PfcpLog.Infoln("handle PFCP Session Deletion Response") SEID := pfcpRsp.SEID() if SEID == 0 { if eventData, ok := msg.EventData.(udp.PfcpEventData); !ok { - logger.PfcpLog.Warnf("PFCP Session Deletion Response found invalid event data, response discarded") + logger.PfcpLog.Warnln("PFCP Session Deletion Response found invalid event data, response discarded") return } else { SEID = eventData.LSEID @@ -372,13 +372,13 @@ func HandlePfcpSessionDeletionResponse(msg *udp.Message) { smContext := context.GetSMContextBySEID(SEID) if smContext == nil { - logger.PfcpLog.Warnf("PFCP Session Deletion Response found SM context nil, response discarded") + logger.PfcpLog.Warnln("PFCP Session Deletion Response found SM context nil, response discarded") return } cause := pfcpRsp.Cause if cause == nil { - logger.PfcpLog.Warnf("PFCP Session Deletion Response found invalid cause, response discarded") + logger.PfcpLog.Warnln("PFCP Session Deletion Response found invalid cause, response discarded") return } @@ -393,25 +393,25 @@ func HandlePfcpSessionDeletionResponse(msg *udp.Message) { upfNodeID := smContext.GetNodeIDByLocalSEID(SEID) upfIP := upfNodeID.ResolveNodeIdToIp().String() delete(smContext.PendingUPF, upfIP) - smContext.SubPduSessLog.Tracef("Delete pending pfcp response: UPF IP [%s]\n", upfIP) + smContext.SubPduSessLog.Debugf("delete pending pfcp response: UPF IP [%s]", upfIP) if smContext.PendingUPF.IsEmpty() && !smContext.LocalPurged { smContext.SBIPFCPCommunicationChan <- context.SessionReleaseSuccess } } - smContext.SubPfcpLog.Infof("PFCP Session Deletion Success[%d]\n", SEID) + smContext.SubPfcpLog.Infof("PFCP Session Deletion Success[%d]", SEID) } else { if smContext.SMContextState == context.SmStatePfcpRelease && !smContext.LocalPurged { smContext.SBIPFCPCommunicationChan <- context.SessionReleaseSuccess } - smContext.SubPfcpLog.Infof("PFCP Session Deletion Failed[%d]\n", SEID) + smContext.SubPfcpLog.Infof("PFCP Session Deletion Failed[%d]", SEID) } } func SetUpfInactive(nodeID context.NodeID) { upf := context.RetrieveUPFNodeByNodeID(nodeID) if upf == nil { - logger.PfcpLog.Errorf("can't find UPF[%s]", nodeID.ResolveNodeIdToIp().String()) + logger.PfcpLog.Errorf("can not find UPF[%s]", nodeID.ResolveNodeIdToIp().String()) // metrics.IncrementN4MsgStats(context.SMF_Self().NfInstanceID, // pfcpmsgtypes.PfcpMsgTypeString(msgType), // "In", "Failure", "unknown_upf") diff --git a/pfcp/handler/handler.go b/pfcp/handler/handler.go index e6edb90c..486def8b 100644 --- a/pfcp/handler/handler.go +++ b/pfcp/handler/handler.go @@ -11,7 +11,6 @@ import ( "fmt" "net" - mi "github.com/omec-project/metricfunc/pkg/metricinfo" "github.com/omec-project/openapi/models" smf_context "github.com/omec-project/smf/context" "github.com/omec-project/smf/factory" @@ -21,6 +20,7 @@ import ( pfcp_message "github.com/omec-project/smf/pfcp/message" "github.com/omec-project/smf/pfcp/udp" "github.com/omec-project/smf/producer" + mi "github.com/omec-project/util/metricinfo" "github.com/wmnsk/go-pfcp/ie" "github.com/wmnsk/go-pfcp/message" ) @@ -38,7 +38,7 @@ func FindUEIPAddress(createdPDRIEs []*ie.IE) net.IP { func HandlePfcpHeartbeatRequest(msg *udp.Message) { _, ok := msg.PfcpMessage.(*message.HeartbeatRequest) if !ok { - logger.PfcpLog.Errorf("invalid message type for heartbeat request") + logger.PfcpLog.Errorln("invalid message type for heartbeat request") return } logger.PfcpLog.Infof("handle PFCP Heartbeat Request") @@ -51,17 +51,17 @@ func HandlePfcpHeartbeatRequest(msg *udp.Message) { func HandlePfcpHeartbeatResponse(msg *udp.Message) { rsp, ok := msg.PfcpMessage.(*message.HeartbeatResponse) if !ok { - logger.PfcpLog.Errorf("invalid message type for heartbeat response") + logger.PfcpLog.Errorln("invalid message type for heartbeat response") return } - logger.PfcpLog.Infof("handle PFCP Heartbeat Response") + logger.PfcpLog.Infoln("handle PFCP Heartbeat Response") // Get NodeId from Seq:NodeId Map seq := rsp.Sequence() nodeID := pfcp_message.FetchPfcpTxn(seq) if nodeID == nil { - logger.PfcpLog.Errorf("No pending pfcp heartbeat response for sequence no: %v", seq) + logger.PfcpLog.Errorf("no pending pfcp heartbeat response for sequence no: %v", seq) metrics.IncrementN4MsgStats(smf_context.SMF_Self().NfInstanceID, rsp.MessageTypeName(), "In", "Failure", "invalid_seqno") return } @@ -70,7 +70,7 @@ func HandlePfcpHeartbeatResponse(msg *udp.Message) { upf := smf_context.RetrieveUPFNodeByNodeID(*nodeID) if upf == nil { - logger.PfcpLog.Errorf("can't find UPF[%s]", nodeID.ResolveNodeIdToIp().String()) + logger.PfcpLog.Errorf("can not find UPF[%s]", nodeID.ResolveNodeIdToIp().String()) metrics.IncrementN4MsgStats(smf_context.SMF_Self().NfInstanceID, rsp.MessageTypeName(), "In", "Failure", "unknown_upf") return } @@ -114,7 +114,7 @@ func HandlePfcpHeartbeatResponse(msg *udp.Message) { func SetUpfInactive(nodeID smf_context.NodeID, msgTypeName string) { upf := smf_context.RetrieveUPFNodeByNodeID(nodeID) if upf == nil { - logger.PfcpLog.Errorf("can't find UPF[%s]", nodeID.ResolveNodeIdToIp().String()) + logger.PfcpLog.Errorf("can not find UPF[%s]", nodeID.ResolveNodeIdToIp().String()) metrics.IncrementN4MsgStats(smf_context.SMF_Self().NfInstanceID, msgTypeName, "In", "Failure", "unknown_upf") return } @@ -126,20 +126,20 @@ func SetUpfInactive(nodeID smf_context.NodeID, msgTypeName string) { } func HandlePfcpPfdManagementRequest(msg *udp.Message) { - logger.PfcpLog.Warnf("PFCP PFD Management Request handling is not implemented") + logger.PfcpLog.Warnln("PFCP PFD Management Request handling is not implemented") } func HandlePfcpPfdManagementResponse(msg *udp.Message) { - logger.PfcpLog.Warnf("PFCP PFD Management Response handling is not implemented") + logger.PfcpLog.Warnln("PFCP PFD Management Response handling is not implemented") } func HandlePfcpAssociationSetupRequest(msg *udp.Message) { req, ok := msg.PfcpMessage.(*message.AssociationSetupRequest) if !ok { - logger.PfcpLog.Errorf("invalid message type for association setup request") + logger.PfcpLog.Errorln("invalid message type for association setup request") return } - logger.PfcpLog.Infof("handle PFCP Association Setup Request") + logger.PfcpLog.Infoln("handle PFCP Association Setup Request") nodeIDIE := req.NodeID if nodeIDIE == nil { @@ -159,7 +159,7 @@ func HandlePfcpAssociationSetupRequest(msg *udp.Message) { upf := smf_context.RetrieveUPFNodeByNodeID(*nodeID) if upf == nil { - logger.PfcpLog.Errorf("can't find UPF[%s]", nodeIDStr) + logger.PfcpLog.Errorf("can not find UPF[%s]", nodeIDStr) return } @@ -196,10 +196,10 @@ func HandlePfcpAssociationSetupRequest(msg *udp.Message) { func HandlePfcpAssociationSetupResponse(msg *udp.Message) { rsp, ok := msg.PfcpMessage.(*message.AssociationSetupResponse) if !ok { - logger.PfcpLog.Errorf("invalid message type for association setup response") + logger.PfcpLog.Errorln("invalid message type for association setup response") return } - logger.PfcpLog.Infof("handle PFCP Association Setup Response") + logger.PfcpLog.Infoln("handle PFCP Association Setup Response") nodeIDIE := rsp.NodeID @@ -234,7 +234,7 @@ func HandlePfcpAssociationSetupResponse(msg *udp.Message) { upf := smf_context.RetrieveUPFNodeByNodeID(*nodeID) if upf == nil { - logger.PfcpLog.Errorf("can't find UPF[%s]", nodeID.ResolveNodeIdToIp().String()) + logger.PfcpLog.Errorf("can not find UPF[%s]", nodeID.ResolveNodeIdToIp().String()) return } @@ -323,20 +323,20 @@ func HandlePfcpAssociationSetupResponse(msg *udp.Message) { } func HandlePfcpAssociationUpdateRequest(msg *udp.Message) { - logger.PfcpLog.Warnf("PFCP Association Update Request handling is not implemented") + logger.PfcpLog.Warnln("PFCP Association Update Request handling is not implemented") } func HandlePfcpAssociationUpdateResponse(msg *udp.Message) { - logger.PfcpLog.Warnf("PFCP Association Update Response handling is not implemented") + logger.PfcpLog.Warnln("PFCP Association Update Response handling is not implemented") } func HandlePfcpAssociationReleaseRequest(msg *udp.Message) { pfcpMsg, ok := msg.PfcpMessage.(*message.AssociationReleaseRequest) if !ok { - logger.PfcpLog.Errorf("invalid message type for association release request") + logger.PfcpLog.Errorln("invalid message type for association release request") return } - logger.PfcpLog.Infof("handle PFCP Association Release Request") + logger.PfcpLog.Infoln("handle PFCP Association Release Request") nodeIDIE := pfcpMsg.NodeID if nodeIDIE == nil { @@ -354,7 +354,7 @@ func HandlePfcpAssociationReleaseRequest(msg *udp.Message) { upf := smf_context.RetrieveUPFNodeByNodeID(*nodeID) if upf == nil { - logger.PfcpLog.Errorf("can't find UPF[%s]", nodeIDStr) + logger.PfcpLog.Errorf("can not find UPF[%s]", nodeIDStr) return } smf_context.RemoveUPFNodeByNodeID(*nodeID) @@ -367,10 +367,10 @@ func HandlePfcpAssociationReleaseRequest(msg *udp.Message) { func HandlePfcpAssociationReleaseResponse(msg *udp.Message) { pfcpMsg, ok := msg.PfcpMessage.(*message.AssociationReleaseResponse) if !ok { - logger.PfcpLog.Errorf("invalid message type for association release response") + logger.PfcpLog.Errorln("invalid message type for association release response") return } - logger.PfcpLog.Infof("handle PFCP Association Release Response") + logger.PfcpLog.Infoln("handle PFCP Association Release Response") if pfcpMsg.Cause == nil { logger.PfcpLog.Errorln("pfcp association release response needs Cause") return @@ -397,29 +397,29 @@ func HandlePfcpAssociationReleaseResponse(msg *udp.Message) { } func HandlePfcpVersionNotSupportedResponse(msg *udp.Message) { - logger.PfcpLog.Warnf("PFCP Version Not Support Response handling is not implemented") + logger.PfcpLog.Warnln("PFCP Version Not Support Response handling is not implemented") } func HandlePfcpNodeReportRequest(msg *udp.Message) { - logger.PfcpLog.Warnf("PFCP Node Report Request handling is not implemented") + logger.PfcpLog.Warnln("PFCP Node Report Request handling is not implemented") } func HandlePfcpNodeReportResponse(msg *udp.Message) { - logger.PfcpLog.Warnf("PFCP Node Report Response handling is not implemented") + logger.PfcpLog.Warnln("PFCP Node Report Response handling is not implemented") } func HandlePfcpSessionSetDeletionRequest(msg *udp.Message) { - logger.PfcpLog.Warnf("PFCP Session Set Deletion Request handling is not implemented") + logger.PfcpLog.Warnln("PFCP Session Set Deletion Request handling is not implemented") } func HandlePfcpSessionSetDeletionResponse(msg *udp.Message) { - logger.PfcpLog.Warnf("PFCP Session Set Deletion Response handling is not implemented") + logger.PfcpLog.Warnln("PFCP Session Set Deletion Response handling is not implemented") } func HandlePfcpSessionEstablishmentResponse(msg *udp.Message) { rsp, ok := msg.PfcpMessage.(*message.SessionEstablishmentResponse) if !ok { - logger.PfcpLog.Errorf("invalid message type for session establishment response") + logger.PfcpLog.Errorln("invalid message type for session establishment response") return } logger.PfcpLog.Infof("handle PFCP Session Establishment Response") @@ -427,7 +427,7 @@ func HandlePfcpSessionEstablishmentResponse(msg *udp.Message) { SEID := rsp.SEID() if SEID == 0 { if eventData, ok := msg.EventData.(udp.PfcpEventData); !ok { - logger.PfcpLog.Warnf("PFCP Session Establish Response found invalid event data, response discarded") + logger.PfcpLog.Warnln("PFCP Session Establish Response found invalid event data, response discarded") return } else { SEID = eventData.LSEID @@ -478,7 +478,7 @@ func HandlePfcpSessionEstablishmentResponse(msg *udp.Message) { ANUPF := smContext.Tunnel.DataPathPool.GetDefaultPath().FirstDPNode if rsp.NodeID == nil { - logger.PfcpLog.Errorf("PFCP Session Establishment Response missing NodeID") + logger.PfcpLog.Errorln("PFCP Session Establishment Response missing NodeID") return } rspNodeIDStr, err := rsp.NodeID.NodeID() @@ -491,7 +491,7 @@ func HandlePfcpSessionEstablishmentResponse(msg *udp.Message) { if ANUPF.UPF.NodeID.ResolveNodeIdToIp().Equal(nodeID.ResolveNodeIdToIp()) { // UPF Accept if rsp.Cause == nil { - logger.PfcpLog.Errorf("PFCP Session Establishment Response missing Cause") + logger.PfcpLog.Errorln("PFCP Session Establishment Response missing Cause") return } causeValue, err := rsp.Cause.Cause() @@ -501,7 +501,7 @@ func HandlePfcpSessionEstablishmentResponse(msg *udp.Message) { } if causeValue == ie.CauseRequestAccepted { smContext.SBIPFCPCommunicationChan <- smf_context.SessionEstablishSuccess - smContext.SubPfcpLog.Infof("PFCP Session Establishment accepted") + smContext.SubPfcpLog.Infoln("PFCP Session Establishment accepted") } else { smContext.SBIPFCPCommunicationChan <- smf_context.SessionEstablishFailed smContext.SubPfcpLog.Errorf("PFCP Session Establishment rejected with cause [%v]", causeValue) @@ -523,17 +523,17 @@ func HandlePfcpSessionEstablishmentResponse(msg *udp.Message) { func HandlePfcpSessionModificationResponse(msg *udp.Message) { rsp, ok := msg.PfcpMessage.(*message.SessionModificationResponse) if !ok { - logger.PfcpLog.Errorf("invalid message type for session establishment response") + logger.PfcpLog.Errorln("invalid message type for session establishment response") return } - logger.PfcpLog.Infof("handle PFCP Session Modification Response") + logger.PfcpLog.Infoln("handle PFCP Session Modification Response") SEID := rsp.SEID() if SEID == 0 { if eventData, ok := msg.EventData.(udp.PfcpEventData); !ok { - logger.PfcpLog.Warnf("PFCP Session Modification Response found invalid event data, response discarded") + logger.PfcpLog.Warnln("PFCP Session Modification Response found invalid event data, response discarded") return } else { SEID = eventData.LSEID @@ -553,7 +553,7 @@ func HandlePfcpSessionModificationResponse(msg *udp.Message) { } if rsp.Cause == nil { - logger.PfcpLog.Errorf("PFCP Session Modification Response missing Cause") + logger.PfcpLog.Errorln("PFCP Session Modification Response missing Cause") return } @@ -569,7 +569,7 @@ func HandlePfcpSessionModificationResponse(msg *udp.Message) { upfNodeID := smContext.GetNodeIDByLocalSEID(SEID) upfIP := upfNodeID.ResolveNodeIdToIp().String() delete(smContext.PendingUPF, upfIP) - smContext.SubPduSessLog.Tracef("Delete pending pfcp response: UPF IP [%s]\n", upfIP) + smContext.SubPduSessLog.Debugf("delete pending pfcp response: UPF IP [%s]", upfIP) if smContext.PendingUPF.IsEmpty() { smContext.SBIPFCPCommunicationChan <- smf_context.SessionUpdateSuccess @@ -585,32 +585,32 @@ func HandlePfcpSessionModificationResponse(msg *udp.Message) { } } - smContext.SubPfcpLog.Infof("PFCP Session Modification Success[%d]\n", SEID) + smContext.SubPfcpLog.Infof("PFCP Session Modification Success[%d]", SEID) } else { - smContext.SubPfcpLog.Infof("PFCP Session Modification Failed[%d]\n", SEID) + smContext.SubPfcpLog.Infof("PFCP Session Modification Failed[%d]", SEID) if smContext.SMContextState == smf_context.SmStatePfcpModify { smContext.SBIPFCPCommunicationChan <- smf_context.SessionUpdateFailed } } - smContext.SubCtxLog.Traceln("PFCP Session Context") + smContext.SubCtxLog.Debugln("PFCP Session Context") for _, ctx := range smContext.PFCPContext { - smContext.SubCtxLog.Traceln(ctx.String()) + smContext.SubCtxLog.Debugln(ctx.String()) } } func HandlePfcpSessionDeletionResponse(msg *udp.Message) { rsp, ok := msg.PfcpMessage.(*message.SessionDeletionResponse) if !ok { - logger.PfcpLog.Errorf("invalid message type for session deletion response") + logger.PfcpLog.Errorln("invalid message type for session deletion response") return } - logger.PfcpLog.Infof("handle PFCP Session Deletion Response") + logger.PfcpLog.Infoln("handle PFCP Session Deletion Response") SEID := rsp.SEID() if SEID == 0 { if eventData, ok := msg.EventData.(udp.PfcpEventData); !ok { - logger.PfcpLog.Warnf("PFCP Session Deletion Response found invalid event data, response discarded") + logger.PfcpLog.Warnln("PFCP Session Deletion Response found invalid event data, response discarded") return } else { SEID = eventData.LSEID @@ -619,13 +619,13 @@ func HandlePfcpSessionDeletionResponse(msg *udp.Message) { smContext := smf_context.GetSMContextBySEID(SEID) if smContext == nil { - logger.PfcpLog.Warnf("PFCP Session Deletion Response found SM context nil, response discarded") + logger.PfcpLog.Warnln("PFCP Session Deletion Response found SM context nil, response discarded") return // TODO fix: SEID should be the value sent by UPF but now the SEID value is from sm context } if rsp.Cause == nil { - logger.PfcpLog.Errorf("PFCP Session Deletion Response missing Cause") + logger.PfcpLog.Errorln("PFCP Session Deletion Response missing Cause") return } @@ -640,29 +640,29 @@ func HandlePfcpSessionDeletionResponse(msg *udp.Message) { upfNodeID := smContext.GetNodeIDByLocalSEID(SEID) upfIP := upfNodeID.ResolveNodeIdToIp().String() delete(smContext.PendingUPF, upfIP) - smContext.SubPduSessLog.Tracef("Delete pending pfcp response: UPF IP [%s]\n", upfIP) + smContext.SubPduSessLog.Debugf("delete pending pfcp response: UPF IP [%s]", upfIP) if smContext.PendingUPF.IsEmpty() && !smContext.LocalPurged { smContext.SBIPFCPCommunicationChan <- smf_context.SessionReleaseSuccess } } - smContext.SubPfcpLog.Infof("PFCP Session Deletion Success[%d]\n", SEID) + smContext.SubPfcpLog.Infof("PFCP Session Deletion Success[%d]", SEID) } else { if smContext.SMContextState == smf_context.SmStatePfcpRelease && !smContext.LocalPurged { smContext.SBIPFCPCommunicationChan <- smf_context.SessionReleaseSuccess } - smContext.SubPfcpLog.Infof("PFCP Session Deletion Failed[%d]\n", SEID) + smContext.SubPfcpLog.Infof("PFCP Session Deletion Failed[%d]", SEID) } } func HandlePfcpSessionReportRequest(msg *udp.Message) { req, ok := msg.PfcpMessage.(*message.SessionReportRequest) if !ok { - logger.PfcpLog.Errorf("invalid message type for session report request") + logger.PfcpLog.Errorln("invalid message type for session report request") return } - logger.PfcpLog.Infof("handle PFCP Session Report Request") + logger.PfcpLog.Infoln("handle PFCP Session Report Request") SEID := req.SEID() smContext := smf_context.GetSMContextBySEID(SEID) @@ -672,7 +672,7 @@ func HandlePfcpSessionReportRequest(msg *udp.Message) { var pfcpSRflag smf_context.PFCPSRRspFlags if smContext == nil { - logger.PfcpLog.Warnf("PFCP Session Report Request Found SM Context NULL, Request Rejected") + logger.PfcpLog.Warnln("PFCP Session Report Request Found SM Context NULL, Request Rejected") cause = ie.CauseRequestRejected // Rejecting buffering at UPF since not able to process Session Report Request @@ -692,11 +692,11 @@ func HandlePfcpSessionReportRequest(msg *udp.Message) { if req.ReportType.HasDLDR() { downlinkServiceInfo, err := req.DownlinkDataReport.DownlinkDataServiceInformation() if err != nil { - logger.PfcpLog.Warnf("DownlinkDataServiceInformation not found in DownlinkDataReport") + logger.PfcpLog.Warnln("DownlinkDataServiceInformation not found in DownlinkDataReport") } if downlinkServiceInfo != nil { - smContext.SubPfcpLog.Warnf("PFCP Session Report Request DownlinkDataServiceInformation handling is not implemented") + smContext.SubPfcpLog.Warnln("PFCP Session Report Request DownlinkDataServiceInformation handling is not implemented") } n1n2Request := models.N1N2MessageTransferRequest{} @@ -777,5 +777,5 @@ func HandlePfcpSessionReportRequest(msg *udp.Message) { } func HandlePfcpSessionReportResponse(msg *udp.Message) { - logger.PfcpLog.Warnf("PFCP Session Report Response handling is not implemented") + logger.PfcpLog.Warnln("PFCP Session Report Response handling is not implemented") } diff --git a/pfcp/message/send.go b/pfcp/message/send.go index 02c7a6fe..b9854e67 100644 --- a/pfcp/message/send.go +++ b/pfcp/message/send.go @@ -20,7 +20,6 @@ import ( "sync/atomic" "time" - mi "github.com/omec-project/metricfunc/pkg/metricinfo" "github.com/omec-project/nas/nasMessage" "github.com/omec-project/openapi/models" smf_context "github.com/omec-project/smf/context" @@ -29,6 +28,7 @@ import ( "github.com/omec-project/smf/metrics" "github.com/omec-project/smf/pfcp/adapter" "github.com/omec-project/smf/pfcp/udp" + mi "github.com/omec-project/util/metricinfo" "github.com/wmnsk/go-pfcp/message" ) @@ -47,7 +47,7 @@ func getSeqNumber() uint32 { } seqNum := atomic.AddUint32(&seq, 1) + uint32((smfCount-1)*5000) - logger.PfcpLog.Debugf("unique seq num: smfCount from os: %v; seqNum %v\n", smfCount, seqNum) + logger.PfcpLog.Debugf("unique seq num: smfCount from os: %v; seqNum %v", smfCount, seqNum) return seqNum } @@ -149,13 +149,13 @@ func SendPfcpAssociationSetupRequest(upNodeID smf_context.NodeID, upfPort uint16 IP: upNodeID.ResolveNodeIdToIp(), Port: int(upfPort), } - logger.PfcpLog.Infof("Sent PFCP Association Request to NodeID[%s]", upNodeID.ResolveNodeIdToIp().String()) + logger.PfcpLog.Infof("sent PFCP Association Request to NodeID[%s]", upNodeID.ResolveNodeIdToIp().String()) if factory.SmfConfig.Configuration.EnableUpfAdapter { if rsp, err := SendPfcpMsgToAdapter(upNodeID, pfcpMsg, addr, nil, UPFAdapterURL); err != nil { return err } else { - logger.PfcpLog.Debugf("send pfcp association response [%v] ", rsp) + logger.PfcpLog.Debugf("send pfcp association response [%v]", rsp) if rsp.StatusCode == http.StatusOK { pfcpMsgBytes, err := io.ReadAll(rsp.Body) if err != nil { @@ -194,7 +194,7 @@ func SendPfcpAssociationSetupResponse(upNodeID smf_context.NodeID, cause uint8, if err != nil { return err } - logger.PfcpLog.Infof("Sent PFCP Association Response to NodeID[%s]", upNodeID.ResolveNodeIdToIp().String()) + logger.PfcpLog.Infof("sent PFCP Association Response to NodeID[%s]", upNodeID.ResolveNodeIdToIp().String()) return nil } @@ -208,7 +208,7 @@ func SendPfcpAssociationReleaseResponse(upNodeID smf_context.NodeID, cause uint8 if err != nil { return err } - logger.PfcpLog.Infof("Sent PFCP Association Release Response to NodeID[%s]", upNodeID.ResolveNodeIdToIp().String()) + logger.PfcpLog.Infof("sent PFCP Association Release Response to NodeID[%s]", upNodeID.ResolveNodeIdToIp().String()) return nil } @@ -248,18 +248,18 @@ func SendPfcpSessionEstablishmentRequest( IP: ip, Port: int(upfPort), } - ctx.SubPduSessLog.Traceln("[SMF] Send SendPfcpSessionEstablishmentRequest") - ctx.SubPduSessLog.Traceln("Send to addr ", upaddr.String()) - logger.PfcpLog.Infof("in SendPfcpSessionEstablishmentRequest fseid %v\n", pfcpMsg.SEID()) + ctx.SubPduSessLog.Debugln("[SMF] Send SendPfcpSessionEstablishmentRequest") + ctx.SubPduSessLog.Debugln("send to addr", upaddr.String()) + logger.PfcpLog.Infof("in SendPfcpSessionEstablishmentRequest fseid %v", pfcpMsg.SEID()) if factory.SmfConfig.Configuration.EnableUpfAdapter { adapter.InsertPfcpTxn(pfcpMsg.Sequence(), &upNodeID) if rsp, err := SendPfcpMsgToAdapter(upNodeID, pfcpMsg, upaddr, nil, UPFAdapterURL); err != nil { - logger.PfcpLog.Errorf("send pfcp session establish msg to upf-adapter error [%v] ", err.Error()) + logger.PfcpLog.Errorf("send pfcp session establish msg to upf-adapter error [%v]", err.Error()) HandlePfcpSendError(pfcpMsg, err) return err } else { - logger.PfcpLog.Debugf("send pfcp session establish response [%v] ", rsp) + logger.PfcpLog.Debugf("send pfcp session establish response [%v]", rsp) if rsp.StatusCode == http.StatusOK { pfcpMsgBytes, err := io.ReadAll(rsp.Body) if err != nil { @@ -290,7 +290,7 @@ func SendPfcpSessionEstablishmentRequest( return err } } - ctx.SubPfcpLog.Infof("Sent PFCP Session Establish Request to NodeID[%s]", ip.String()) + ctx.SubPfcpLog.Infof("sent PFCP Session Establish Request to NodeID[%s]", ip.String()) return nil } @@ -321,10 +321,10 @@ func SendPfcpSessionModificationRequest( if factory.SmfConfig.Configuration.EnableUpfAdapter { if rsp, err := SendPfcpMsgToAdapter(upNodeID, pfcpMsg, upaddr, nil, UPFAdapterURL); err != nil { - logger.PfcpLog.Errorf("send pfcp session modify msg to upf-adapter error [%v] ", err.Error()) + logger.PfcpLog.Errorf("send pfcp session modify msg to upf-adapter error [%v]", err.Error()) return err } else { - logger.PfcpLog.Debugf("send pfcp session modify response [%v] ", rsp) + logger.PfcpLog.Debugf("send pfcp session modify response [%v]", rsp) if rsp.StatusCode == http.StatusOK { pfcpMsgBytes, err := io.ReadAll(rsp.Body) if err != nil { @@ -349,10 +349,10 @@ func SendPfcpSessionModificationRequest( eventData := udp.PfcpEventData{LSEID: ctx.PFCPContext[nodeIDtoIP].LocalSEID, ErrHandler: HandlePfcpSendError} err := udp.SendPfcp(pfcpMsg, upaddr, eventData) if err != nil { - logger.PfcpLog.Errorf("send pfcp session modify msg to upf error [%v] ", err.Error()) + logger.PfcpLog.Errorf("send pfcp session modify msg to upf error [%v]", err.Error()) } } - ctx.SubPfcpLog.Infof("Sent PFCP Session Modify Request to NodeID[%s]", upNodeID.ResolveNodeIdToIp().String()) + ctx.SubPfcpLog.Infof("sent PFCP Session Modify Request to NodeID[%s]", upNodeID.ResolveNodeIdToIp().String()) return nil } @@ -372,10 +372,10 @@ func SendPfcpSessionDeletionRequest(upNodeID smf_context.NodeID, ctx *smf_contex if factory.SmfConfig.Configuration.EnableUpfAdapter { if rsp, err := SendPfcpMsgToAdapter(upNodeID, pfcpMsg, upaddr, nil, UPFAdapterURL); err != nil { - logger.PfcpLog.Errorf("send pfcp session delete msg to upf-adapter error [%v] ", err.Error()) + logger.PfcpLog.Errorf("send pfcp session delete msg to upf-adapter error [%v]", err.Error()) return err } else { - logger.PfcpLog.Debugf("send pfcp session delete response [%v] ", rsp) + logger.PfcpLog.Debugf("send pfcp session delete response [%v]", rsp) if rsp.StatusCode == http.StatusOK { pfcpMsgBytes, err := io.ReadAll(rsp.Body) if err != nil { @@ -404,7 +404,7 @@ func SendPfcpSessionDeletionRequest(upNodeID smf_context.NodeID, ctx *smf_contex } } - ctx.SubPfcpLog.Infof("Sent PFCP Session Delete Request to NodeID[%s]", upNodeID.ResolveNodeIdToIp().String()) + ctx.SubPfcpLog.Infof("sent PFCP Session Delete Request to NodeID[%s]", upNodeID.ResolveNodeIdToIp().String()) return nil } @@ -414,7 +414,7 @@ func SendPfcpSessionReportResponse(addr *net.UDPAddr, cause uint8, pfcpSRflag sm if err != nil { return err } - logger.PfcpLog.Infof("Sent PFCP Session Report Response Seq[%d] to NodeID[%s]", seqFromUPF, addr.IP.String()) + logger.PfcpLog.Infof("sent PFCP Session Report Response Seq[%d] to NodeID[%s]", seqFromUPF, addr.IP.String()) return nil } @@ -424,7 +424,7 @@ func SendHeartbeatResponse(addr *net.UDPAddr, sequenceNumber uint32) error { if err != nil { return err } - logger.PfcpLog.Infof("Sent PFCP Heartbeat Response Seq[%d] to NodeID[%s]", sequenceNumber, addr.IP.String()) + logger.PfcpLog.Infof("sent PFCP Heartbeat Response Seq[%d] to NodeID[%s]", sequenceNumber, addr.IP.String()) return nil } @@ -445,7 +445,7 @@ func HandlePfcpSendError(msg message.Message, pfcpErr error) { case message.MsgTypeSessionDeletionRequest: handleSendPfcpSessRelReqError(msg, pfcpErr) default: - logger.PfcpLog.Errorf("Unable to send PFCP packet type [%v] and content [%v]", + logger.PfcpLog.Errorf("unable to send PFCP packet type [%v] and content [%v]", msg.MessageTypeName(), msg) } } @@ -454,7 +454,7 @@ func handleSendPfcpSessEstReqError(msg message.Message, pfcpErr error) { // Lets decode the PDU request pfcpEstReq, ok := msg.(*message.SessionEstablishmentRequest) if !ok { - logger.PfcpLog.Errorf("Unable to decode PFCP Session Establishment Request") + logger.PfcpLog.Errorf("unable to decode PFCP Session Establishment Request") return } @@ -491,9 +491,9 @@ func handleSendPfcpSessEstReqError(msg message.Message, pfcpErr error) { N1N2MessageCollectionDocumentApi. N1N2MessageTransfer(context.Background(), smContext.Supi, n1n2Request) smContext.ChangeState(smf_context.SmStateInit) - smContext.SubCtxLog.Traceln("SMContextState Change State: ", smContext.SMContextState.String()) + smContext.SubCtxLog.Debugln("SMContextState Change State:", smContext.SMContextState.String()) if err != nil { - smContext.SubPfcpLog.Warnf("Send N1N2Transfer failed") + smContext.SubPfcpLog.Warnln("send N1N2Transfer failed") } if rspData.Cause == models.N1N2MessageTransferCause_N1_MSG_NOT_TRANSFERRED { smContext.SubPfcpLog.Warnf("%v", rspData.Cause) @@ -508,7 +508,7 @@ func handleSendPfcpSessRelReqError(msg message.Message, pfcpErr error) { // Lets decode the PDU request pfcpRelReq, ok := msg.(*message.SessionDeletionRequest) if !ok { - logger.PfcpLog.Errorf("Unable to decode PFCP Session Deletion Request") + logger.PfcpLog.Errorln("unable to decode PFCP Session Deletion Request") return } @@ -525,7 +525,7 @@ func handleSendPfcpSessModReqError(msg message.Message, pfcpErr error) { // Lets decode the PDU request pfcpModReq, ok := msg.(*message.SessionModificationRequest) if !ok { - logger.PfcpLog.Errorf("Unable to decode PFCP Session Modification Request") + logger.PfcpLog.Errorln("unable to decode PFCP Session Modification Request") return } @@ -593,14 +593,14 @@ func SendPfcpMsgToAdapter(upNodeID smf_context.NodeID, msg message.Message, addr return nil, err } - logger.PfcpLog.Debugf("json encoded udpPodMsg [%s] ", udpPodMsgJson) + logger.PfcpLog.Debugf("json encoded udpPodMsg [%s]", udpPodMsgJson) // change the IP here - logger.PfcpLog.Debugf("send to :%s\n", url) + logger.PfcpLog.Debugf("send to: %s", url) bodyReader := bytes.NewReader(udpPodMsgJson) req, err := http.NewRequestWithContext(context.Background(), http.MethodPost, url, bodyReader) if err != nil { - logger.PfcpLog.Errorf("client: could not create request: %s\n", err) + logger.PfcpLog.Errorf("client: could not create request: %s", err) } req.Header.Set("Content-Type", "application/json") @@ -611,7 +611,7 @@ func SendPfcpMsgToAdapter(upNodeID smf_context.NodeID, msg message.Message, addr // waiting for http response rsp, err := client.Do(req) if err != nil { - logger.PfcpLog.Errorf("client: error making http request: %s\n", err) + logger.PfcpLog.Errorf("client: error making http request: %s", err) return nil, err } diff --git a/pfcp/message/send_test.go b/pfcp/message/send_test.go index a4483340..042d3288 100644 --- a/pfcp/message/send_test.go +++ b/pfcp/message/send_test.go @@ -8,7 +8,6 @@ import ( "encoding/json" "fmt" "io" - "log" "net" "net/http" "net/http/httptest" @@ -19,10 +18,10 @@ import ( "github.com/omec-project/smf/factory" "github.com/omec-project/smf/pfcp/message" "github.com/omec-project/smf/pfcp/udp" - "github.com/sirupsen/logrus" "github.com/stretchr/testify/assert" "github.com/wmnsk/go-pfcp/ie" pfcp_message "github.com/wmnsk/go-pfcp/message" + "go.uber.org/zap" ) func boolPointer(b bool) *bool { @@ -56,7 +55,7 @@ func TestSendPfcpAssociationSetupRequest(t *testing.T) { defer func() { if err = conn.Close(); err != nil { - log.Printf("error closing connection: %v", err) + t.Logf("error closing connection: %v", err) } }() @@ -83,7 +82,7 @@ func TestSendPfcpAssociationSetupResponse(t *testing.T) { defer func() { if err = conn.Close(); err != nil { - log.Printf("error closing connection: %v", err) + t.Logf("error closing connection: %v", err) } }() @@ -115,8 +114,12 @@ func TestSendPfcpSessionEstablishmentRequestUpNodeExists(t *testing.T) { NodeIdType: context.NodeIdTypeIpv4Address, NodeIdValue: net.ParseIP(upNodeIDStr).To4(), } - log := logrus.New() - mockLog := log.WithFields(logrus.Fields{}) + config := zap.NewProductionConfig() + log, err := config.Build() + if err != nil { + panic(err) + } + mockLog := log.Sugar() smContext := &context.SMContext{ PFCPContext: map[string]*context.PFCPSessionContext{ upNodeIDStr: { @@ -144,7 +147,7 @@ func TestSendPfcpSessionEstablishmentRequestUpNodeExists(t *testing.T) { defer func() { if err = conn.Close(); err != nil { - log.Printf("error closing connection: %v", err) + t.Logf("error closing connection: %v", err) } }() @@ -190,7 +193,7 @@ func TestSendPfcpSessionEstablishmentRequestUpNodeDoesNotExist(t *testing.T) { defer func() { if err = conn.Close(); err != nil { - log.Printf("error closing connection: %v", err) + t.Logf("error closing connection: %v", err) } }() @@ -216,8 +219,12 @@ func TestSendPfcpSessionModificationRequest(t *testing.T) { NodeIdType: context.NodeIdTypeIpv4Address, NodeIdValue: net.ParseIP(upNodeIDStr).To4(), } - log := logrus.New() - mockLog := log.WithFields(logrus.Fields{}) + config := zap.NewProductionConfig() + log, err := config.Build() + if err != nil { + panic(err) + } + mockLog := log.Sugar() smContext := &context.SMContext{ PFCPContext: map[string]*context.PFCPSessionContext{ upNodeIDStr: { @@ -245,7 +252,7 @@ func TestSendPfcpSessionModificationRequest(t *testing.T) { defer func() { if err = conn.Close(); err != nil { - log.Printf("error closing connection: %v", err) + t.Logf("error closing connection: %v", err) } }() @@ -271,8 +278,12 @@ func TestSendPfcpSessionDeletionRequest(t *testing.T) { NodeIdType: context.NodeIdTypeIpv4Address, NodeIdValue: net.ParseIP(upNodeIDStr).To4(), } - log := logrus.New() - mockLog := log.WithFields(logrus.Fields{}) + config := zap.NewProductionConfig() + log, err := config.Build() + if err != nil { + panic(err) + } + mockLog := log.Sugar() smContext := &context.SMContext{ PFCPContext: map[string]*context.PFCPSessionContext{ upNodeIDStr: { @@ -295,7 +306,7 @@ func TestSendPfcpSessionDeletionRequest(t *testing.T) { defer func() { if err = conn.Close(); err != nil { - log.Printf("error closing connection: %v", err) + t.Logf("error closing connection: %v", err) } }() @@ -328,7 +339,7 @@ func TestSendPfcpSessionReportResponse(t *testing.T) { defer func() { if err = conn.Close(); err != nil { - log.Printf("error closing connection: %v", err) + t.Logf("error closing connection: %v", err) } }() @@ -368,7 +379,7 @@ func TestSendHeartbeatRequest(t *testing.T) { defer func() { if err = conn.Close(); err != nil { - log.Printf("error closing connection: %v", err) + t.Logf("error closing connection: %v", err) } }() @@ -401,7 +412,7 @@ func TestSendHeartbeatResponse(t *testing.T) { defer func() { if err = conn.Close(); err != nil { - log.Printf("error closing connection: %v", err) + t.Logf("error closing connection: %v", err) } }() diff --git a/pfcp/udp/transaction.go b/pfcp/udp/transaction.go index 3bacd28f..78e678a8 100644 --- a/pfcp/udp/transaction.go +++ b/pfcp/udp/transaction.go @@ -84,19 +84,19 @@ func NewTransaction(pfcpMSG message.Message, binaryMSG []byte, Conn *net.UDPConn tx.TxType = SendingResponse tx.ConsumerAddr = DestAddr.String() } - logger.PfcpLog.Tracef("New Transaction SEQ[%d] DestAddr[%s]", tx.SequenceNumber, DestAddr.String()) + logger.PfcpLog.Debugf("new Transaction SEQ[%d] DestAddr[%s]", tx.SequenceNumber, DestAddr.String()) return tx } func (transaction *Transaction) Start() error { - logger.PfcpLog.Tracef("Start Transaction [%d]\n", transaction.SequenceNumber) + logger.PfcpLog.Debugf("start transaction [%d]", transaction.SequenceNumber) if transaction.TxType == SendingRequest { for iter := 0; iter < NumOfResend; iter++ { timer := time.NewTimer(ResendRequestTimeOutPeriod * time.Second) _, err := transaction.Conn.WriteToUDP(transaction.SendMsg, transaction.DestAddr) if err != nil { - logger.PfcpLog.Warnf("Request Transaction [%d]: %s\n", transaction.SequenceNumber, err) + logger.PfcpLog.Warnf("request transaction [%d]: %s", transaction.SequenceNumber, err) return err } @@ -104,12 +104,12 @@ func (transaction *Transaction) Start() error { case event := <-transaction.EventChannel: if event == ReceiveValidResponse { - logger.PfcpLog.Tracef("Request Transaction [%d]: receive valid response\n", transaction.SequenceNumber) + logger.PfcpLog.Debugf("request transaction [%d]: receive valid response", transaction.SequenceNumber) return nil } case <-timer.C: - logger.PfcpLog.Tracef("Request Transaction [%d]: timeout expire\n", transaction.SequenceNumber) - logger.PfcpLog.Tracef("Request Transaction [%d]: Resend packet\n", transaction.SequenceNumber) + logger.PfcpLog.Debugf("request transaction [%d]: timeout expire", transaction.SequenceNumber) + logger.PfcpLog.Debugf("request transaction [%d]: Resend packet", transaction.SequenceNumber) continue } } @@ -121,7 +121,7 @@ func (transaction *Transaction) Start() error { for iter := 0; iter < NumOfResend; iter++ { _, err := transaction.Conn.WriteToUDP(transaction.SendMsg, transaction.DestAddr) if err != nil { - logger.PfcpLog.Warnf("Response Transaction [%d]: sending error\n", transaction.SequenceNumber) + logger.PfcpLog.Warnf("response transaction [%d]: sending error", transaction.SequenceNumber) return err } @@ -129,12 +129,12 @@ func (transaction *Transaction) Start() error { case event := <-transaction.EventChannel: if event == ReceiveResendRequest { - logger.PfcpLog.Tracef("Response Transaction [%d]: receive resend request\n", transaction.SequenceNumber) - logger.PfcpLog.Tracef("Response Transaction [%d]: Resend packet\n", transaction.SequenceNumber) + logger.PfcpLog.Debugf("response transaction [%d]: receive resend request", transaction.SequenceNumber) + logger.PfcpLog.Debugf("response transaction [%d]: Resend packet", transaction.SequenceNumber) continue } case <-timer.C: - logger.PfcpLog.Tracef("Response Transaction [%d]: timeout expire\n", transaction.SequenceNumber) + logger.PfcpLog.Debugf("response transaction [%d]: timeout expire", transaction.SequenceNumber) return errors.Errorf("response timeout, seq [%d]", transaction.SequenceNumber) } } diff --git a/pfcp/udp/udp_test.go b/pfcp/udp/udp_test.go index cd5dff26..3cf8ec95 100644 --- a/pfcp/udp/udp_test.go +++ b/pfcp/udp/udp_test.go @@ -5,7 +5,6 @@ package udp_test import ( - "log" "net" "testing" "time" @@ -93,7 +92,7 @@ func TestRun(t *testing.T) { defer func() { if err = udp.Server.Conn.Close(); err != nil { - log.Printf("error closing connection: %v", err) + t.Logf("error closing connection: %v", err) } }() @@ -141,7 +140,7 @@ func TestServerSendPfcp(t *testing.T) { defer func() { if err = conn.Close(); err != nil { - log.Printf("error closing connection: %v", err) + t.Logf("error closing connection: %v", err) } }() diff --git a/producer/callback.go b/producer/callback.go index d57febe4..7495dddd 100644 --- a/producer/callback.go +++ b/producer/callback.go @@ -97,7 +97,7 @@ func BuildAndSendQosN1N2TransferMsg(smContext *smf_context.SMContext) error { // N1 Msg if smNasBuf, err := smf_context.BuildGSMPDUSessionModificationCommand(smContext); err != nil { - logger.PduSessLog.Errorf("Build GSM BuildGSMPDUSessionModificationCommand failed: %s", err) + logger.PduSessLog.Errorf("build GSM BuildGSMPDUSessionModificationCommand failed: %s", err) } else { n1n2Request.BinaryDataN1Message = smNasBuf n1n2Request.JsonData.N1MessageContainer = &n1MsgContainer @@ -112,25 +112,25 @@ func BuildAndSendQosN1N2TransferMsg(smContext *smf_context.SMContext) error { n1n2Request.JsonData.N2InfoContainer = &n2InfoContainer } - smContext.SubPduSessLog.Infof("QoS N1N2 transfer initiated") + smContext.SubPduSessLog.Infoln("QoS N1N2 transfer initiated") rspData, _, err := smContext. CommunicationClient. N1N2MessageCollectionDocumentApi. N1N2MessageTransfer(context.Background(), smContext.Supi, n1n2Request) if err != nil { - smContext.SubPfcpLog.Warnf("Send N1N2Transfer failed, %v ", err.Error()) + smContext.SubPfcpLog.Warnf("send N1N2Transfer failed, %v", err.Error()) return err } if rspData.Cause == models.N1N2MessageTransferCause_N1_MSG_NOT_TRANSFERRED { smContext.SubPfcpLog.Errorf("N1N2MessageTransfer failure, %v", rspData.Cause) return fmt.Errorf("N1N2MessageTransfer failure, %v", rspData.Cause) } - smContext.SubPduSessLog.Infof("QoS N1N2 Transfer completed") + smContext.SubPduSessLog.Infoln("QoS N1N2 Transfer completed") return nil } func HandleNfSubscriptionStatusNotify(request *httpwrapper.Request) *httpwrapper.Response { - logger.PduSessLog.Traceln("[SMF] Handle NF Status Notify") + logger.PduSessLog.Debugln("[SMF] Handle NF Status Notify") notificationData := request.Body.(models.NotificationData) @@ -159,7 +159,7 @@ func NfSubscriptionStatusNotifyProcedure(notificationData models.NotificationDat // This will force the smf to do nf discovery and get the updated nf profile from the nrf. if smf_context.SMF_Self().EnableNrfCaching { ok := nrfCache.RemoveNfProfileFromNrfCache(nfInstanceId) - logger.PduSessLog.Tracef("nfinstance %v deleted from cache: %v", nfInstanceId, ok) + logger.PduSessLog.Debugf("nfinstance %v deleted from cache: %v", nfInstanceId, ok) } return nil diff --git a/producer/n1n2_data_handler.go b/producer/n1n2_data_handler.go index ba24f5c8..aef175a5 100644 --- a/producer/n1n2_data_handler.go +++ b/producer/n1n2_data_handler.go @@ -33,10 +33,10 @@ func HandleUpdateN1Msg(txn *transaction.Transaction, response *models.UpdateSmCo smContext := txn.Ctxt.(*context.SMContext) if body.BinaryDataN1SmMessage != nil { - smContext.SubPduSessLog.Traceln("PDUSessionSMContextUpdate, Binary Data N1 SmMessage isn't nil!") + smContext.SubPduSessLog.Debugln("PDUSessionSMContextUpdate, Binary Data N1 SmMessage isn't nil") m := nas.NewMessage() err := m.GsmMessageDecode(&body.BinaryDataN1SmMessage) - smContext.SubPduSessLog.Traceln("PDUSessionSMContextUpdate, Update SM Context Request N1SmMessage: ", m) + smContext.SubPduSessLog.Debugln("PDUSessionSMContextUpdate, Update SM Context Request N1SmMessage:", m) if err != nil { smContext.SubPduSessLog.Error(err) txn.Rsp = &httpwrapper.Response{ @@ -78,17 +78,17 @@ func HandleUpdateN1Msg(txn *transaction.Transaction, response *models.UpdateSmCo if smContext.Tunnel != nil { smContext.ChangeState(context.SmStatePfcpModify) - smContext.SubCtxLog.Traceln("PDUSessionSMContextUpdate, SMContextState Change State: ", smContext.SMContextState.String()) + smContext.SubCtxLog.Debugln("PDUSessionSMContextUpdate, SMContextState Change State:", smContext.SMContextState.String()) // Send release to UPF // releaseTunnel(smContext) pfcpAction.sendPfcpDelete = true } else { smContext.ChangeState(context.SmStateModify) - smContext.SubCtxLog.Traceln("PDUSessionSMContextUpdate, SMContextState Change State: ", smContext.SMContextState.String()) + smContext.SubCtxLog.Debugln("PDUSessionSMContextUpdate, SMContextState Change State:", smContext.SMContextState.String()) } case nas.MsgTypePDUSessionReleaseComplete: - smContext.SubPduSessLog.Infof("PDUSessionSMContextUpdate, N1 Msg PDU Session Release Complete received") + smContext.SubPduSessLog.Infoln("PDUSessionSMContextUpdate, N1 Msg PDU Session Release Complete received") if smContext.SMContextState != context.SmStateInActivePending { // Wait till the state becomes SmStateActive again // TODO: implement sleep wait in concurrent architecture @@ -97,7 +97,7 @@ func HandleUpdateN1Msg(txn *transaction.Transaction, response *models.UpdateSmCo // Send Release Notify to AMF smContext.SubPduSessLog.Infof("PDUSessionSMContextUpdate, send Update SmContext Response") smContext.ChangeState(context.SmStateInit) - smContext.SubCtxLog.Traceln("PDUSessionSMContextUpdate, SMContextState Change State: ", smContext.SMContextState.String()) + smContext.SubCtxLog.Debugln("PDUSessionSMContextUpdate, SMContextState Change State:", smContext.SMContextState.String()) response.JsonData.UpCnxState = models.UpCnxState_DEACTIVATED /*problemDetails, err := consumer.SendSMContextStatusNotification(smContext.SmStatusNotifyUri) if problemDetails != nil || err != nil { @@ -109,12 +109,12 @@ func HandleUpdateN1Msg(txn *transaction.Transaction, response *models.UpdateSmCo smContext.SubPduSessLog.Warnf("PDUSessionSMContextUpdate, send SMContext Status Notification Error[%v]", err) } } else { - smContext.SubPduSessLog.Traceln("PDUSessionSMContextUpdate, sent SMContext Status Notification successfully") + smContext.SubPduSessLog.Debugln("PDUSessionSMContextUpdate, sent SMContext Status Notification successfully") }*/ - smContext.SubPduSessLog.Traceln("PDUSessionSMContextUpdate, sent SMContext Status Notification successfully") + smContext.SubPduSessLog.Debugln("PDUSessionSMContextUpdate, sent SMContext Status Notification successfully") } } else { - smContext.SubPduSessLog.Traceln("PDUSessionSMContextUpdate, Binary Data N1 SmMessage is nil!") + smContext.SubPduSessLog.Debugln("PDUSessionSMContextUpdate, Binary Data N1 SmMessage is nil") } return nil @@ -134,7 +134,7 @@ func HandleUpCnxState(txn *transaction.Transaction, response *models.UpdateSmCon smContext.SubPduSessLog.Infof("PDUSessionSMContextUpdate, SMContext State[%v] should be SmStateActive State", smContext.SMContextState.String()) } smContext.ChangeState(context.SmStateModify) - smContext.SubCtxLog.Traceln("PDUSessionSMContextUpdate, SMContextState Change State: ", smContext.SMContextState.String()) + smContext.SubCtxLog.Debugln("PDUSessionSMContextUpdate, SMContextState Change State:", smContext.SMContextState.String()) response.JsonData.N2SmInfo = &models.RefToBinaryData{ContentId: "PDUSessionResourceSetupRequestTransfer"} response.JsonData.UpCnxState = models.UpCnxState_ACTIVATING response.JsonData.N2SmInfoType = models.N2SmInfoType_PDU_RES_SETUP_REQ @@ -155,7 +155,7 @@ func HandleUpCnxState(txn *transaction.Transaction, response *models.UpdateSmCon } if smContext.Tunnel != nil { smContext.ChangeState(context.SmStateModify) - smContext.SubCtxLog.Traceln("PDUSessionSMContextUpdate, SMContextState Change State: ", smContext.SMContextState.String()) + smContext.SubCtxLog.Debugln("PDUSessionSMContextUpdate, SMContextState Change State:", smContext.SMContextState.String()) response.JsonData.UpCnxState = models.UpCnxState_DEACTIVATED smContext.UpCnxState = body.JsonData.UpCnxState smContext.UeLocation = body.JsonData.UeLocation @@ -187,7 +187,7 @@ func HandleUpCnxState(txn *transaction.Transaction, response *models.UpdateSmCon pfcpAction.sendPfcpModify = true smContext.ChangeState(context.SmStatePfcpModify) - smContext.SubCtxLog.Traceln("PDUSessionSMContextUpdate, SMContextState Change State: ", smContext.SMContextState.String()) + smContext.SubCtxLog.Debugln("PDUSessionSMContextUpdate, SMContextState Change State:", smContext.SMContextState.String()) } } return nil @@ -201,7 +201,7 @@ func HandleUpdateHoState(txn *transaction.Transaction, response *models.UpdateSm switch smContextUpdateData.HoState { case models.HoState_PREPARING: smContext.SubPduSessLog.Infof("PDUSessionSMContextUpdate, Ho state %v received", smContextUpdateData.HoState) - smContext.SubPduSessLog.Traceln("PDUSessionSMContextUpdate, in HoState_PREPARING") + smContext.SubPduSessLog.Debugln("PDUSessionSMContextUpdate, in HoState_PREPARING") if smContext.SMContextState != context.SmStateActive { // Wait till the state becomes SmStateActive again // TODO: implement sleep wait in concurrent architecture @@ -209,7 +209,7 @@ func HandleUpdateHoState(txn *transaction.Transaction, response *models.UpdateSm smContext.SMContextState.String()) } smContext.ChangeState(context.SmStateModify) - smContext.SubCtxLog.Traceln("PDUSessionSMContextUpdate, SMContextState Change State: ", smContext.SMContextState.String()) + smContext.SubCtxLog.Debugln("PDUSessionSMContextUpdate, SMContextState Change State:", smContext.SMContextState.String()) smContext.HoState = models.HoState_PREPARING if err := context.HandleHandoverRequiredTransfer(body.BinaryDataN2SmInformation, smContext); err != nil { smContext.SubPduSessLog.Errorf("PDUSessionSMContextUpdate, handle HandoverRequiredTransfer failed: %+v", err) @@ -228,7 +228,7 @@ func HandleUpdateHoState(txn *transaction.Transaction, response *models.UpdateSm response.JsonData.HoState = models.HoState_PREPARING case models.HoState_PREPARED: smContext.SubPduSessLog.Infof("PDUSessionSMContextUpdate, Ho state %v received", smContextUpdateData.HoState) - smContext.SubPduSessLog.Traceln("PDUSessionSMContextUpdate, in HoState_PREPARED") + smContext.SubPduSessLog.Debugln("PDUSessionSMContextUpdate, in HoState_PREPARED") if smContext.SMContextState != context.SmStateActive { // Wait till the state becomes SmStateActive again // TODO: implement sleep wait in concurrent architecture @@ -236,7 +236,7 @@ func HandleUpdateHoState(txn *transaction.Transaction, response *models.UpdateSm smContext.SMContextState.String()) } smContext.ChangeState(context.SmStateModify) - smContext.SubCtxLog.Traceln("PDUSessionSMContextUpdate, SMContextState Change State: ", smContext.SMContextState.String()) + smContext.SubCtxLog.Debugln("PDUSessionSMContextUpdate, SMContextState Change State:", smContext.SMContextState.String()) smContext.HoState = models.HoState_PREPARED response.JsonData.HoState = models.HoState_PREPARED if err := context.HandleHandoverRequestAcknowledgeTransfer(body.BinaryDataN2SmInformation, smContext); err != nil { @@ -256,7 +256,7 @@ func HandleUpdateHoState(txn *transaction.Transaction, response *models.UpdateSm response.JsonData.HoState = models.HoState_PREPARING case models.HoState_COMPLETED: smContext.SubPduSessLog.Infof("PDUSessionSMContextUpdate, Ho state %v received", smContextUpdateData.HoState) - smContext.SubPduSessLog.Traceln("PDUSessionSMContextUpdate, in HoState_COMPLETED") + smContext.SubPduSessLog.Debugln("PDUSessionSMContextUpdate, in HoState_COMPLETED") if smContext.SMContextState != context.SmStateActive { // Wait till the state becomes SmStateActive again // TODO: implement sleep wait in concurrent architecture @@ -264,7 +264,7 @@ func HandleUpdateHoState(txn *transaction.Transaction, response *models.UpdateSm smContext.SMContextState.String()) } smContext.ChangeState(context.SmStateModify) - smContext.SubCtxLog.Traceln("PDUSessionSMContextUpdate, SMContextState Change State: ", smContext.SMContextState.String()) + smContext.SubCtxLog.Debugln("PDUSessionSMContextUpdate, SMContextState Change State:", smContext.SMContextState.String()) smContext.HoState = models.HoState_COMPLETED response.JsonData.HoState = models.HoState_COMPLETED } @@ -300,7 +300,7 @@ func HandleUpdateCause(txn *transaction.Transaction, response *models.UpdateSmCo smContext.SubCtxLog.Infof("PDUSessionSMContextUpdate, Cause_REL_DUE_TO_DUPLICATE_SESSION_ID") smContext.ChangeState(context.SmStatePfcpModify) - smContext.SubCtxLog.Traceln("PDUSessionSMContextUpdate, SMContextState Change State: ", smContext.SMContextState.String()) + smContext.SubCtxLog.Debugln("PDUSessionSMContextUpdate, SMContextState Change State:", smContext.SMContextState.String()) // releaseTunnel(smContext) pfcpAction.sendPfcpDelete = true @@ -326,7 +326,7 @@ func HandleUpdateN2Msg(txn *transaction.Transaction, response *models.UpdateSmCo smContext.SMContextState.String()) } smContext.ChangeState(context.SmStateModify) - smContext.SubCtxLog.Traceln("PDUSessionSMContextUpdate, SMContextState Change State: ", smContext.SMContextState.String()) + smContext.SubCtxLog.Debugln("PDUSessionSMContextUpdate, SMContextState Change State:", smContext.SMContextState.String()) pdrList := []*context.PDR{} farList := []*context.FAR{} @@ -366,7 +366,7 @@ func HandleUpdateN2Msg(txn *transaction.Transaction, response *models.UpdateSmCo pfcpAction.sendPfcpModify = true smContext.ChangeState(context.SmStatePfcpModify) - smContext.SubCtxLog.Traceln("PDUSessionSMContextUpdate, SMContextState Change State: ", smContext.SMContextState.String()) + smContext.SubCtxLog.Debugln("PDUSessionSMContextUpdate, SMContextState Change State:", smContext.SMContextState.String()) case models.N2SmInfoType_PDU_RES_SETUP_FAIL: smContext.SubPduSessLog.Infof("PDUSessionSMContextUpdate, N2 SM info type %v received", smContextUpdateData.N2SmInfoType) @@ -386,7 +386,7 @@ func HandleUpdateN2Msg(txn *transaction.Transaction, response *models.UpdateSmCo smContext.SMContextState.String()) } smContext.ChangeState(context.SmStateInit) - smContext.SubCtxLog.Traceln("PDUSessionSMContextUpdate, SMContextState Change State: ", smContext.SMContextState.String()) + smContext.SubCtxLog.Debugln("PDUSessionSMContextUpdate, SMContextState Change State:", smContext.SMContextState.String()) smContext.SubPduSessLog.Infof("PDUSessionSMContextUpdate, send Update SmContext Response") response.JsonData.UpCnxState = models.UpCnxState_DEACTIVATED @@ -402,7 +402,7 @@ func HandleUpdateN2Msg(txn *transaction.Transaction, response *models.UpdateSmCo smContext.SubPduSessLog.Warnf("PDUSessionSMContextUpdate, send SMContext Status Notification Error[%v]", err) } } else { - smContext.SubPduSessLog.Traceln("PDUSessionSMContextUpdate, send SMContext Status Notification successfully") + smContext.SubPduSessLog.Debugln("PDUSessionSMContextUpdate, send SMContext Status Notification successfully") } } else { // normal case if smContext.SMContextState != context.SmStateInActivePending { @@ -413,12 +413,12 @@ func HandleUpdateN2Msg(txn *transaction.Transaction, response *models.UpdateSmCo } smContext.SubPduSessLog.Infof("PDUSessionSMContextUpdate, send Update SmContext Response") smContext.ChangeState(context.SmStateInActivePending) - smContext.SubCtxLog.Traceln("PDUSessionSMContextUpdate, SMContextState Change State: ", smContext.SMContextState.String()) + smContext.SubCtxLog.Debugln("PDUSessionSMContextUpdate, SMContextState Change State:", smContext.SMContextState.String()) } case models.N2SmInfoType_PATH_SWITCH_REQ: smContext.SubPduSessLog.Infof("PDUSessionSMContextUpdate, N2 SM info type %v received", smContextUpdateData.N2SmInfoType) - smContext.SubPduSessLog.Traceln("PDUSessionSMContextUpdate, handle Path Switch Request") + smContext.SubPduSessLog.Debugln("PDUSessionSMContextUpdate, handle Path Switch Request") if smContext.SMContextState != context.SmStateActive { // Wait till the state becomes Active again // TODO: implement sleep wait in concurrent architecture @@ -426,7 +426,7 @@ func HandleUpdateN2Msg(txn *transaction.Transaction, response *models.UpdateSmCo smContext.SMContextState.String()) } smContext.ChangeState(context.SmStateModify) - smContext.SubCtxLog.Traceln("PDUSessionSMContextUpdate, SMContextState Change State: ", smContext.SMContextState.String()) + smContext.SubCtxLog.Debugln("PDUSessionSMContextUpdate, SMContextState Change State:", smContext.SMContextState.String()) if err := context.HandlePathSwitchRequestTransfer(body.BinaryDataN2SmInformation, smContext); err != nil { smContext.SubPduSessLog.Errorf("PDUSessionSMContextUpdate, handle PathSwitchRequestTransfer: %+v", err) @@ -465,7 +465,7 @@ func HandleUpdateN2Msg(txn *transaction.Transaction, response *models.UpdateSmCo pfcpAction.sendPfcpModify = true smContext.ChangeState(context.SmStatePfcpModify) - smContext.SubCtxLog.Traceln("PDUSessionSMContextUpdate, SMContextState Change State: ", smContext.SMContextState.String()) + smContext.SubCtxLog.Debugln("PDUSessionSMContextUpdate, SMContextState Change State:", smContext.SMContextState.String()) case models.N2SmInfoType_PATH_SWITCH_SETUP_FAIL: smContext.SubPduSessLog.Infof("PDUSessionSMContextUpdate, N2 SM info type %v received", smContextUpdateData.N2SmInfoType) @@ -476,7 +476,7 @@ func HandleUpdateN2Msg(txn *transaction.Transaction, response *models.UpdateSmCo smContext.SMContextState.String()) } smContext.ChangeState(context.SmStateModify) - smContext.SubCtxLog.Traceln("PDUSessionSMContextUpdate, SMContextState Change State: ", smContext.SMContextState.String()) + smContext.SubCtxLog.Debugln("PDUSessionSMContextUpdate, SMContextState Change State:", smContext.SMContextState.String()) if err := context.HandlePathSwitchRequestSetupFailedTransfer(body.BinaryDataN2SmInformation, smContext); err != nil { smContext.SubPduSessLog.Error() } @@ -490,7 +490,7 @@ func HandleUpdateN2Msg(txn *transaction.Transaction, response *models.UpdateSmCo smContext.SMContextState.String()) } smContext.ChangeState(context.SmStateModify) - smContext.SubCtxLog.Traceln("PDUSessionSMContextUpdate, SMContextState Change State: ", smContext.SMContextState.String()) + smContext.SubCtxLog.Debugln("PDUSessionSMContextUpdate, SMContextState Change State:", smContext.SMContextState.String()) response.JsonData.N2SmInfo = &models.RefToBinaryData{ContentId: "Handover"} } diff --git a/producer/pdu_session.go b/producer/pdu_session.go index fe02fdcb..86f701fa 100644 --- a/producer/pdu_session.go +++ b/producer/pdu_session.go @@ -84,7 +84,7 @@ func HandlePDUSessionSMContextCreate(eventData interface{}) error { m := nas.NewMessage() if err := m.GsmMessageDecode(&request.BinaryDataN1SmMessage); err != nil || m.GsmHeader.GetMessageType() != nas.MsgTypePDUSessionEstablishmentRequest { - logger.PduSessLog.Errorln("PDUSessionSMContextCreate, GsmMessageDecode Error: ", err) + logger.PduSessLog.Errorln("PDUSessionSMContextCreate, GsmMessageDecode Error:", err) txn.Rsp = formContextCreateErrRsp(http.StatusForbidden, &Nsmf_PDUSession.N1SmError, nil) return fmt.Errorf("GsmMsgDecodeError") @@ -96,7 +96,7 @@ func HandlePDUSessionSMContextCreate(eventData interface{}) error { // smContext := smf_context.NewSMContext(createData.Supi, createData.PduSessionId) smContext.SubPduSessLog.Infof("PDUSessionSMContextCreate, SM context created") // smContext.ChangeState(smf_context.SmStateActivePending) - smContext.SubCtxLog.Traceln("PDUSessionSMContextCreate, SMContextState change state: ", smContext.SMContextState.String()) + smContext.SubCtxLog.Debugln("PDUSessionSMContextCreate, SMContextState change state:", smContext.SMContextState.String()) smContext.SetCreateData(createData) smContext.SmStatusNotifyUri = createData.SmContextStatusUri @@ -185,7 +185,7 @@ func HandlePDUSessionSMContextCreate(eventData interface{}) error { if smContext.SelectedPDUSessionType == nasMessage.PDUSessionTypeUnstructured { smContext.SubPduSessLog.Errorf("Unstructured PDU Session Not Supported") txn.Rsp = smContext.GeneratePDUSessionEstablishmentReject("PDUSessionTypeIPv4OnlyAllowed") - return fmt.Errorf("Unstructured PDU Session not supported") + return fmt.Errorf("unstructured PDU Session not supported") } if err := smContext.PCFSelection(); err != nil { @@ -263,7 +263,7 @@ func HandlePDUSessionSMContextCreate(eventData interface{}) error { if defaultPath == nil { smContext.ChangeState(smf_context.SmStateInit) - smContext.SubCtxLog.Traceln("PDUSessionSMContextCreate, SMContextState Change State: ", smContext.SMContextState.String()) + smContext.SubCtxLog.Debugln("PDUSessionSMContextCreate, SMContextState Change State:", smContext.SMContextState.String()) smContext.SubPduSessLog.Errorf("PDUSessionSMContextCreate, data path not found for selection param %v", upfSelectionParams.String()) txn.Rsp = smContext.GeneratePDUSessionEstablishmentReject("InsufficientResourceSliceDnn") @@ -280,7 +280,7 @@ func HandlePDUSessionSMContextCreate(eventData interface{}) error { txn.Rsp = smContext.GeneratePDUSessionEstablishmentReject("AMFDiscoveryFailure") return fmt.Errorf("AmfError") } else { - smContext.SubPduSessLog.Traceln("PDUSessionSMContextCreate, Send NF Discovery Serving AMF success") + smContext.SubPduSessLog.Debugln("PDUSessionSMContextCreate, Send NF Discovery Serving AMF success") } for _, service := range *smContext.AMFProfile.NfServices { @@ -355,14 +355,14 @@ func HandlePDUSessionSMContextUpdate(eventData interface{}) error { switch smContext.SMContextState { case smf_context.SmStatePfcpModify: - smContext.SubCtxLog.Traceln("PDUSessionSMContextUpdate, ctxt in PFCP Modification State") + smContext.SubCtxLog.Debugln("PDUSessionSMContextUpdate, ctxt in PFCP Modification State") var err error // Initiate PFCP Delete if pfcpAction.sendPfcpDelete { - smContext.SubPduSessLog.Infof("PDUSessionSMContextUpdate, send PFCP Deletion") + smContext.SubPduSessLog.Infoln("PDUSessionSMContextUpdate, send PFCP Deletion") smContext.ChangeState(smf_context.SmStatePfcpRelease) - smContext.SubCtxLog.Traceln("PDUSessionSMContextUpdate, SMContextState Change State: ", smContext.SMContextState.String()) + smContext.SubCtxLog.Debugln("PDUSessionSMContextUpdate, SMContextState Change State:", smContext.SMContextState.String()) // Initiate PFCP Release if err = SendPfcpSessionReleaseReq(smContext); err != nil { @@ -371,7 +371,7 @@ func HandlePDUSessionSMContextUpdate(eventData interface{}) error { // Change state to InactivePending smContext.ChangeState(smf_context.SmStateInActivePending) - smContext.SubCtxLog.Traceln("PDUSessionSMContextUpdate, SMContextState Change State: ", smContext.SMContextState.String()) + smContext.SubCtxLog.Debugln("PDUSessionSMContextUpdate, SMContextState Change State:", smContext.SMContextState.String()) // Update response to success httpResponse = &httpwrapper.Response{ @@ -380,7 +380,7 @@ func HandlePDUSessionSMContextUpdate(eventData interface{}) error { } } else if pfcpAction.sendPfcpModify { smContext.ChangeState(smf_context.SmStatePfcpModify) - smContext.SubCtxLog.Traceln("PDUSessionSMContextUpdate, SMContextState Change State: ", smContext.SMContextState.String()) + smContext.SubCtxLog.Debugln("PDUSessionSMContextUpdate, SMContextState Change State:", smContext.SMContextState.String()) smContext.SubPduSessLog.Infof("PDUSessionSMContextUpdate, send PFCP Modification") // Initiate PFCP Modify @@ -399,7 +399,7 @@ func HandlePDUSessionSMContextUpdate(eventData interface{}) error { //Change state to InactivePending smContext.ChangeState(smf_context.SmStateInActivePending) - smContext.SubCtxLog.Traceln("PDUSessionSMContextUpdate, SMContextState Change State: ", smContext.SMContextState.String()) + smContext.SubCtxLog.Debugln("PDUSessionSMContextUpdate, SMContextState Change State:", smContext.SMContextState.String()) */ } else { // Modify Success @@ -409,20 +409,20 @@ func HandlePDUSessionSMContextUpdate(eventData interface{}) error { } smContext.ChangeState(smf_context.SmStateActive) - smContext.SubCtxLog.Traceln("SMContextState Change State: ", smContext.SMContextState.String()) + smContext.SubCtxLog.Debugln("SMContextState Change State:", smContext.SMContextState.String()) } } case smf_context.SmStateModify: - smContext.SubCtxLog.Traceln("PDUSessionSMContextUpdate, ctxt in Modification Pending") + smContext.SubCtxLog.Debugln("PDUSessionSMContextUpdate, ctxt in Modification Pending") smContext.ChangeState(smf_context.SmStateActive) - smContext.SubCtxLog.Traceln("PDUSessionSMContextUpdate, SMContextState Change State: ", smContext.SMContextState.String()) + smContext.SubCtxLog.Debugln("PDUSessionSMContextUpdate, SMContextState Change State:", smContext.SMContextState.String()) httpResponse = &httpwrapper.Response{ Status: http.StatusOK, Body: response, } case smf_context.SmStateInit, smf_context.SmStateInActivePending: - smContext.SubCtxLog.Traceln("PDUSessionSMContextUpdate, ctxt in SmStateInit, SmStateInActivePending") + smContext.SubCtxLog.Debugln("PDUSessionSMContextUpdate, ctxt in SmStateInit, SmStateInActivePending") httpResponse = &httpwrapper.Response{ Status: http.StatusOK, Body: response, @@ -481,16 +481,16 @@ func makePduCtxtModifyErrRsp(smContext *smf_context.SMContext, errStr string) *h switch PFCPResponseStatus { case smf_context.SessionReleaseSuccess: - smContext.SubCtxLog.Traceln("PDUSessionSMContextRelease, PFCP SessionReleaseSuccess") + smContext.SubCtxLog.Debugln("PDUSessionSMContextRelease, PFCP SessionReleaseSuccess") smContext.ChangeState(smf_context.SmStateInActivePending) - smContext.SubCtxLog.Traceln("PDUSessionSMContextRelease, SMContextState Change State: ", smContext.SMContextState.String()) + smContext.SubCtxLog.Debugln("PDUSessionSMContextRelease, SMContextState Change State:", smContext.SMContextState.String()) //TODO: i will uncomment this in next PR SDCORE-209 //case smf_context.SessionReleaseTimeout: // fallthrough case smf_context.SessionReleaseFailed: - smContext.SubCtxLog.Traceln("PDUSessionSMContextRelease, PFCP SessionReleaseFailed") + smContext.SubCtxLog.Debugln("PDUSessionSMContextRelease, PFCP SessionReleaseFailed") smContext.ChangeState(smf_context.SmStateInActivePending) - smContext.SubCtxLog.Traceln("PDUSessionSMContextRelease, SMContextState Change State: ", smContext.SMContextState.String()) + smContext.SubCtxLog.Debugln("PDUSessionSMContextRelease, SMContextState Change State:", smContext.SMContextState.String()) } smf_context.RemoveSMContext(smContext.Ref) @@ -524,7 +524,7 @@ func HandlePDUSessionSMContextRelease(eventData interface{}) error { // Initiate PFCP release smContext.ChangeState(smf_context.SmStatePfcpRelease) - smContext.SubCtxLog.Traceln("PDUSessionSMContextRelease, SMContextState Change State: ", smContext.SMContextState.String()) + smContext.SubCtxLog.Debugln("PDUSessionSMContextRelease, SMContextState Change State:", smContext.SMContextState.String()) var httpResponse *httpwrapper.Response @@ -545,16 +545,16 @@ func HandlePDUSessionSMContextRelease(eventData interface{}) error { switch PFCPResponseStatus { case smf_context.SessionReleaseSuccess: - smContext.SubCtxLog.Traceln("PDUSessionSMContextRelease, PFCP SessionReleaseSuccess") + smContext.SubCtxLog.Debugln("PDUSessionSMContextRelease, PFCP SessionReleaseSuccess") smContext.ChangeState(smf_context.SmStatePfcpRelease) - smContext.SubCtxLog.Traceln("PDUSessionSMContextRelease, SMContextState Change State: ", smContext.SMContextState.String()) + smContext.SubCtxLog.Debugln("PDUSessionSMContextRelease, SMContextState Change State:", smContext.SMContextState.String()) httpResponse = &httpwrapper.Response{ Status: http.StatusNoContent, Body: nil, } case smf_context.SessionReleaseTimeout: - smContext.SubCtxLog.Traceln("PDUSessionSMContextRelease, PFCP SessionReleaseTimeout") + smContext.SubCtxLog.Debugln("PDUSessionSMContextRelease, PFCP SessionReleaseTimeout") smContext.ChangeState(smf_context.SmStateActive) httpResponse = &httpwrapper.Response{ Status: int(http.StatusInternalServerError), @@ -563,7 +563,7 @@ func HandlePDUSessionSMContextRelease(eventData interface{}) error { case smf_context.SessionReleaseFailed: // Update SmContext Request(N1 PDU Session Release Request) // Send PDU Session Release Reject - smContext.SubCtxLog.Traceln("PDUSessionSMContextRelease, PFCP SessionReleaseFailed") + smContext.SubCtxLog.Debugln("PDUSessionSMContextRelease, PFCP SessionReleaseFailed") problemDetail := models.ProblemDetails{ Status: http.StatusInternalServerError, Cause: "SYSTEM_FAILULE", @@ -572,7 +572,7 @@ func HandlePDUSessionSMContextRelease(eventData interface{}) error { Status: int(problemDetail.Status), } smContext.ChangeState(smf_context.SmStateActive) - smContext.SubCtxLog.Traceln("PDUSessionSMContextRelease, SMContextState Change State: ", smContext.SMContextState.String()) + smContext.SubCtxLog.Debugln("PDUSessionSMContextRelease, SMContextState Change State:", smContext.SMContextState.String()) errResponse := models.UpdateSmContextErrorResponse{ JsonData: &models.SmContextUpdateError{ Error: &problemDetail, @@ -589,7 +589,7 @@ func HandlePDUSessionSMContextRelease(eventData interface{}) error { default: smContext.SubCtxLog.Warnf("PDUSessionSMContextRelease, The state shouldn't be [%s]\n", PFCPResponseStatus) - smContext.SubCtxLog.Traceln("PDUSessionSMContextRelease, in case Unknown") + smContext.SubCtxLog.Debugln("PDUSessionSMContextRelease, in case Unknown") problemDetail := models.ProblemDetails{ Status: http.StatusInternalServerError, Cause: "SYSTEM_FAILULE", @@ -598,7 +598,7 @@ func HandlePDUSessionSMContextRelease(eventData interface{}) error { Status: int(problemDetail.Status), } smContext.ChangeState(smf_context.SmStateActive) - smContext.SubCtxLog.Traceln("PDUSessionSMContextRelease, SMContextState Change State: ", smContext.SMContextState.String()) + smContext.SubCtxLog.Debugln("PDUSessionSMContextRelease, SMContextState Change State:", smContext.SMContextState.String()) errResponse := models.UpdateSmContextErrorResponse{ JsonData: &models.SmContextUpdateError{ Error: &problemDetail, @@ -679,14 +679,14 @@ func SendPduSessN1N2Transfer(smContext *smf_context.SMContext, success bool) err if success { if smNasBuf, err := smf_context.BuildGSMPDUSessionEstablishmentAccept(smContext); err != nil { - logger.PduSessLog.Errorf("Build GSM PDUSessionEstablishmentAccept failed: %s", err) + logger.PduSessLog.Errorf("build GSM PDUSessionEstablishmentAccept failed: %s", err) } else { n1n2Request.BinaryDataN1Message = smNasBuf n1n2Request.JsonData.N1MessageContainer = &n1MsgContainer } if n2Pdu, err := smf_context.BuildPDUSessionResourceSetupRequestTransfer(smContext); err != nil { - logger.PduSessLog.Errorf("Build PDUSessionResourceSetupRequestTransfer failed: %s", err) + logger.PduSessLog.Errorf("build PDUSessionResourceSetupRequestTransfer failed: %s", err) } else { n1n2Request.BinaryDataN2Information = n2Pdu n1n2Request.JsonData.N2InfoContainer = &n2InfoContainer @@ -694,7 +694,7 @@ func SendPduSessN1N2Transfer(smContext *smf_context.SMContext, success bool) err } else { if smNasBuf, err := smf_context.BuildGSMPDUSessionEstablishmentReject(smContext, nasMessage.Cause5GSMRequestRejectedUnspecified); err != nil { - logger.PduSessLog.Errorf("Build GSM PDUSessionEstablishmentReject failed: %s", err) + logger.PduSessLog.Errorf("build GSM PDUSessionEstablishmentReject failed: %s", err) } else { n1n2Request.BinaryDataN1Message = smNasBuf n1n2Request.JsonData.N1MessageContainer = &n1MsgContainer @@ -707,7 +707,7 @@ func SendPduSessN1N2Transfer(smContext *smf_context.SMContext, success bool) err N1N2MessageCollectionDocumentApi. N1N2MessageTransfer(context.Background(), smContext.Supi, n1n2Request) if err != nil { - smContext.SubPfcpLog.Warnf("Send N1N2Transfer failed, %v ", err.Error()) + smContext.SubPfcpLog.Warnf("send N1N2Transfer failed, %v ", err.Error()) err = smContext.CommitSmPolicyDecision(false) if err != nil { smContext.SubPfcpLog.Errorf("CommitSmPolicyDecision failed, %v", err) @@ -735,7 +735,7 @@ func HandlePduSessN1N2TransFailInd(eventData interface{}) error { txn := eventData.(*transaction.Transaction) smContext := txn.Ctxt.(*smf_context.SMContext) - smContext.SubPduSessLog.Infof("In HandlePduSessN1N2TransFailInd, N1N2 Transfer Failure Notification received") + smContext.SubPduSessLog.Infoln("in HandlePduSessN1N2TransFailInd, N1N2 Transfer Failure Notification received") var httpResponse *httpwrapper.Response @@ -750,7 +750,7 @@ func HandlePduSessN1N2TransFailInd(eventData interface{}) error { ANUPF := dataPath.FirstDPNode for _, DLPDR := range ANUPF.DownLinkTunnel.PDR { if DLPDR == nil { - smContext.SubPduSessLog.Errorf("AN Release Error") + smContext.SubPduSessLog.Errorln("AN Release Error") return fmt.Errorf("AN Release Error") } else { DLPDR.FAR.ApplyAction = smf_context.ApplyAction{Buff: false, Drop: true, Dupl: false, Forw: false, Nocp: false} @@ -783,22 +783,22 @@ func HandlePduSessN1N2TransFailInd(eventData interface{}) error { func HandlePFCPResponse(smContext *smf_context.SMContext, PFCPResponseStatus smf_context.PFCPSessionResponseStatus, ) *httpwrapper.Response { - smContext.SubPfcpLog.Traceln("In HandlePFCPResponse") + smContext.SubPfcpLog.Debugln("in HandlePFCPResponse") var httpResponse *httpwrapper.Response switch PFCPResponseStatus { case smf_context.SessionUpdateSuccess: - smContext.SubCtxLog.Traceln("PDUSessionSMContextUpdate, PFCP Session Update Success") + smContext.SubCtxLog.Debugln("PDUSessionSMContextUpdate, PFCP Session Update Success") smContext.ChangeState(smf_context.SmStateActive) - smContext.SubCtxLog.Traceln("SMContextState Change State: ", smContext.SMContextState.String()) + smContext.SubCtxLog.Debugln("SMContextState Change State:", smContext.SMContextState.String()) httpResponse = &httpwrapper.Response{ Status: http.StatusNoContent, Body: nil, } case smf_context.SessionUpdateFailed: - smContext.SubCtxLog.Traceln("PDUSessionSMContextUpdate, PFCP Session Update Failed") + smContext.SubCtxLog.Debugln("PDUSessionSMContextUpdate, PFCP Session Update Failed") smContext.ChangeState(smf_context.SmStateActive) - smContext.SubCtxLog.Traceln("PDUSessionSMContextUpdate, SMContextState Change State: ", smContext.SMContextState.String()) + smContext.SubCtxLog.Debugln("PDUSessionSMContextUpdate, SMContextState Change State:", smContext.SMContextState.String()) // It is just a template httpResponse = &httpwrapper.Response{ Status: http.StatusForbidden, @@ -809,7 +809,7 @@ func HandlePFCPResponse(smContext *smf_context.SMContext, }, // Depends on the reason why N4 fail } case smf_context.SessionUpdateTimeout: - smContext.SubCtxLog.Traceln("PDUSessionSMContextUpdate, PFCP Session Modification Timeout") + smContext.SubCtxLog.Debugln("PDUSessionSMContextUpdate, PFCP Session Modification Timeout") /* TODO: exact http error response code for this usecase is 504, so relevant cause for this usecase is 500. If it gets added in spec 29.502 new release that can be added @@ -831,7 +831,7 @@ func HandlePFCPResponse(smContext *smf_context.SMContext, } smContext.ChangeState(smf_context.SmStatePfcpModify) - smContext.SubCtxLog.Traceln("PDUSessionSMContextUpdate, SMContextState Change State: ", smContext.SMContextState.String()) + smContext.SubCtxLog.Debugln("PDUSessionSMContextUpdate, SMContextState Change State:", smContext.SMContextState.String()) // It is just a template httpResponse = &httpwrapper.Response{ @@ -861,6 +861,6 @@ func HandlePFCPResponse(smContext *smf_context.SMContext, } } - smContext.SubPfcpLog.Traceln("Out HandlePFCPResponse") + smContext.SubPfcpLog.Debugln("out HandlePFCPResponse") return httpResponse } diff --git a/producer/sm_pfcp_handling.go b/producer/sm_pfcp_handling.go index 29cc04b5..bb95fd75 100644 --- a/producer/sm_pfcp_handling.go +++ b/producer/sm_pfcp_handling.go @@ -25,13 +25,13 @@ func SendPfcpSessionModifyReq(smContext *smf_context.SMContext, pfcpParam *pfcpP switch PFCPResponseStatus { case smf_context.SessionUpdateSuccess: - smContext.SubCtxLog.Traceln("PDUSessionSMContextUpdate, PFCP Session Update Success") + smContext.SubCtxLog.Debugln("PDUSessionSMContextUpdate, PFCP Session Update Success") case smf_context.SessionUpdateFailed: - smContext.SubCtxLog.Traceln("PDUSessionSMContextUpdate, PFCP Session Update Failed") + smContext.SubCtxLog.Debugln("PDUSessionSMContextUpdate, PFCP Session Update Failed") fallthrough case smf_context.SessionUpdateTimeout: - smContext.SubCtxLog.Traceln("PDUSessionSMContextUpdate, PFCP Session Modification Timeout") + smContext.SubCtxLog.Debugln("PDUSessionSMContextUpdate, PFCP Session Modification Timeout") err := fmt.Errorf("pfcp modification failure") return err @@ -47,13 +47,13 @@ func SendPfcpSessionReleaseReq(smContext *smf_context.SMContext) error { PFCPResponseStatus := <-smContext.SBIPFCPCommunicationChan switch PFCPResponseStatus { case smf_context.SessionReleaseSuccess: - smContext.SubCtxLog.Traceln("PDUSessionSMContextUpdate, PFCP Session Release Success") + smContext.SubCtxLog.Debugln("PDUSessionSMContextUpdate, PFCP Session Release Success") return nil case smf_context.SessionReleaseTimeout: - smContext.SubCtxLog.Error("PDUSessionSMContextUpdate, PFCP Session Release Failed") + smContext.SubCtxLog.Errorln("PDUSessionSMContextUpdate, PFCP Session Release Failed") return fmt.Errorf("pfcp session release timeout") case smf_context.SessionReleaseFailed: - smContext.SubCtxLog.Error("PDUSessionSMContextUpdate, PFCP Session Release Failed") + smContext.SubCtxLog.Errorln("PDUSessionSMContextUpdate, PFCP Session Release Failed") return fmt.Errorf("pfcp session release failed") } return nil diff --git a/producer/ulcl_procedure.go b/producer/ulcl_procedure.go index fe43ae44..99be8788 100644 --- a/producer/ulcl_procedure.go +++ b/producer/ulcl_procedure.go @@ -101,7 +101,7 @@ func AddPDUSessionAnchorAndULCL(smContext *context.SMContext, nodeID context.Nod delete(pendingUPF, trggierUPFIP) } else { logger.CtxLog.Warnln("In AddPDUSessionAnchorAndULCL case UpdatingRANAndIUPFUpLink") - logger.CtxLog.Warnln("UPF IP ", trggierUPFIP, " doesn't exist in pending UPF!") + logger.CtxLog.Warnf("UPF IP %s doesn't exist in pending UPF", trggierUPFIP) return } @@ -118,7 +118,7 @@ func EstablishPSA2(smContext *context.SMContext) { bpMGR.PendingUPF = make(context.PendingUPF) activatingPath := bpMGR.ActivatingPath ulcl := bpMGR.ULCL - logger.PduSessLog.Infoln("In EstablishPSA2") + logger.PduSessLog.Infoln("in EstablishPSA2") nodeAfterULCL := false for curDataPathNode := activatingPath.FirstDPNode; curDataPathNode != nil; curDataPathNode = curDataPathNode.Next() { if nodeAfterULCL { @@ -127,7 +127,7 @@ func EstablishPSA2(smContext *context.SMContext) { Port: factory.DEFAULT_PFCP_PORT, } - logger.PduSessLog.Traceln("Send to upf addr: ", addr.String()) + logger.PduSessLog.Debugln("send to upf addr:", addr.String()) upLinkPDR := curDataPathNode.UpLinkTunnel.PDR["default"] // TODO: Iterate over all PDRs @@ -159,11 +159,11 @@ func EstablishPSA2(smContext *context.SMContext) { } bpMGR.AddingPSAState = context.EstablishingNewPSA - logger.PduSessLog.Traceln("End of EstablishPSA2") + logger.PduSessLog.Debugln("end of EstablishPSA2") } func EstablishULCL(smContext *context.SMContext) { - logger.PduSessLog.Infoln("In EstablishULCL") + logger.PduSessLog.Infoln("in EstablishULCL") bpMGR := smContext.BPManager bpMGR.PendingUPF = make(context.PendingUPF) @@ -181,28 +181,28 @@ func EstablishULCL(smContext *context.SMContext) { FlowDespcription := flowdesc.NewIPFilterRule() err := FlowDespcription.SetAction(flowdesc.Permit) // permit if err != nil { - logger.PduSessLog.Errorf("Error occurs when setting flow despcription: %s\n", err) + logger.PduSessLog.Errorf("error occurs when setting flow despcription: %s", err) } err = FlowDespcription.SetDirection(flowdesc.Out) // uplink if err != nil { - logger.PduSessLog.Errorf("Error occurs when setting flow despcription: %s\n", err) + logger.PduSessLog.Errorf("error occurs when setting flow despcription: %s", err) } err = FlowDespcription.SetDestinationIP(dest.DestinationIP) if err != nil { - logger.PduSessLog.Errorf("Error occurs when setting flow despcription: %s\n", err) + logger.PduSessLog.Errorf("error occurs when setting flow despcription: %s", err) } err = FlowDespcription.SetDestinationPorts(dest.DestinationPort) if err != nil { - logger.PduSessLog.Errorf("Error occurs when setting flow despcription: %s\n", err) + logger.PduSessLog.Errorf("error occurs when setting flow despcription: %s", err) } err = FlowDespcription.SetSourceIP(smContext.PDUAddress.Ip.To4().String()) if err != nil { - logger.PduSessLog.Errorf("Error occurs when setting flow despcription: %s\n", err) + logger.PduSessLog.Errorf("error occurs when setting flow despcription: %s", err) } FlowDespcriptionStr, err := flowdesc.Encode(FlowDespcription) if err != nil { - logger.PduSessLog.Errorf("Error occurs when encoding flow despcription: %s\n", err) + logger.PduSessLog.Errorf("error occurs when encoding flow despcription: %s", err) } UPLinkPDR.PDI.SDFFilter = &context.SDFFilter{ @@ -237,7 +237,7 @@ func EstablishULCL(smContext *context.SMContext) { } func UpdatePSA2DownLink(smContext *context.SMContext) { - logger.PduSessLog.Traceln("In UpdatePSA2DownLink") + logger.PduSessLog.Debugln("in UpdatePSA2DownLink") bpMGR := smContext.BPManager bpMGR.PendingUPF = make(context.PendingUPF) @@ -279,7 +279,7 @@ func UpdatePSA2DownLink(smContext *context.SMContext) { } func EstablishRANTunnelInfo(smContext *context.SMContext) { - logger.PduSessLog.Traceln("In UpdatePSA2DownLink") + logger.PduSessLog.Debugln("in UpdatePSA2DownLink") bpMGR := smContext.BPManager activatingPath := bpMGR.ActivatingPath @@ -340,28 +340,28 @@ func UpdateRANAndIUPFUpLink(smContext *context.SMContext) { FlowDespcription := flowdesc.NewIPFilterRule() err := FlowDespcription.SetAction(flowdesc.Permit) // permit if err != nil { - logger.PduSessLog.Errorf("Error occurs when setting flow despcription: %s\n", err) + logger.PduSessLog.Errorf("error occurs when setting flow despcription: %s", err) } err = FlowDespcription.SetDirection(flowdesc.Out) // uplink if err != nil { - logger.PduSessLog.Errorf("Error occurs when setting flow despcription: %s\n", err) + logger.PduSessLog.Errorf("error occurs when setting flow despcription: %s", err) } err = FlowDespcription.SetDestinationIP(dest.DestinationIP) if err != nil { - logger.PduSessLog.Errorf("Error occurs when setting flow despcription: %s\n", err) + logger.PduSessLog.Errorf("error occurs when setting flow despcription: %s", err) } err = FlowDespcription.SetDestinationPorts(dest.DestinationPort) if err != nil { - logger.PduSessLog.Errorf("Error occurs when setting flow despcription: %s\n", err) + logger.PduSessLog.Errorf("error occurs when setting flow despcription: %s", err) } err = FlowDespcription.SetSourceIP(smContext.PDUAddress.Ip.To4().String()) if err != nil { - logger.PduSessLog.Errorf("Error occurs when setting flow despcription: %s\n", err) + logger.PduSessLog.Errorf("error occurs when setting flow despcription: %s", err) } FlowDespcriptionStr, err := flowdesc.Encode(FlowDespcription) if err != nil { - logger.PduSessLog.Errorf("Error occurs when encoding flow despcription: %s\n", err) + logger.PduSessLog.Errorf("error occurs when encoding flow despcription: %s", err) } UPLinkPDR.PDI.SDFFilter = &context.SDFFilter{ diff --git a/qos/qos_flow.go b/qos/qos_flow.go index da32f303..65497073 100644 --- a/qos/qos_flow.go +++ b/qos/qos_flow.go @@ -5,7 +5,6 @@ package qos import ( - "log" "strconv" "strings" @@ -84,7 +83,7 @@ type QosFlowsUpdate struct { func GetQosFlowIdFromQosId(qosId string) uint8 { id, err := strconv.Atoi(qosId) if err != nil { - logger.CtxLog.Errorf("String can not be converted to integer: %+v", err) + logger.CtxLog.Errorf("string can not be converted to integer: %+v", err) return 0 } else { return uint8(id) @@ -103,7 +102,7 @@ func BuildAuthorizedQosFlowDescriptions(smPolicyUpdates *PolicyUpdate) *QosFlowD // QoS Flow Description to be Added if qosFlowUpdate != nil { for name, qosFlow := range qosFlowUpdate.add { - log.Printf("Adding Qos Flow Description [%v] ", name) + logger.QosLog.Infof("adding Qos Flow Description [%v]", name) QFDescriptions.BuildAddQosFlowDescFromQoSDesc(qosFlow) } } @@ -182,7 +181,7 @@ func GetBitRate(sBitRate string) (val uint16, unit uint8) { // rate if rate, err := strconv.Atoi(sl[0]); err != nil { - log.Printf("invalid bit rate [%v]", sBitRate) + logger.QosLog.Errorf("invalid bit rate [%v]", sBitRate) } else { val = uint16(rate) } @@ -385,6 +384,6 @@ func GetDefaultQoSDataFromPolicyDecision(smPolicyDecision *models.SmPolicyDecisi } } - log.Fatal("Default Qos Data not received from PCF") + logger.QosLog.Fatalln("default Qos Data not received from PCF") return nil } diff --git a/qos/qos_flow_test.go b/qos/qos_flow_test.go index 33a5b113..6f7cfbb4 100644 --- a/qos/qos_flow_test.go +++ b/qos/qos_flow_test.go @@ -5,7 +5,6 @@ package qos_test import ( - "fmt" "testing" "github.com/omec-project/openapi/models" @@ -27,7 +26,7 @@ func TestBuildAuthorizedQosFlowDescriptions(t *testing.T) { authorizedQosFlow := qos.BuildAuthorizedQosFlowDescriptions(smPolicyUpdates) - fmt.Printf("Authorized QosFlow: %v\n", authorizedQosFlow.Content) + t.Logf("authorized QosFlow: %v", authorizedQosFlow.Content) firstQosDataId := authorizedQosFlow.Content[0] if firstQosDataId == 1 { expectedBytes := []byte{ diff --git a/qos/qos_rule.go b/qos/qos_rule.go index 97d7dea4..8c95cf29 100644 --- a/qos/qos_rule.go +++ b/qos/qos_rule.go @@ -7,7 +7,6 @@ package qos import ( "bytes" "encoding/binary" - "log" "net" "strconv" "strings" @@ -133,7 +132,7 @@ func BuildQosRules(smPolicyUpdates *PolicyUpdate) QoSRules { // New Rules to be added if pccRulesUpdate != nil { for pccRuleName, pccRuleVal := range pccRulesUpdate.add { - log.Printf("Building QoS Rule from PCC rule [%s]", pccRuleName) + logger.QosLog.Infof("building QoS Rule from PCC rule [%s]", pccRuleName) refQosData := GetQoSDataFromPolicyDecision(smPolicyDecision, pccRuleVal.RefQosData[0]) qosRule := BuildAddQoSRuleFromPccRule(pccRuleVal, refQosData, OperationCodeCreateNewQoSRule) qosRules = append(qosRules, *qosRule) @@ -510,7 +509,6 @@ func BuildPFCompProtocolId(val string) (*PacketFilterComponent, uint8) { binary.BigEndian.PutUint32(bs, uint32(pfcVal)) pfc.ComponentValue = []byte{bs[3]} } else { - // log TODO return nil, 0 } diff --git a/qos/qos_rule_test.go b/qos/qos_rule_test.go index 7f0fe767..9e2102a9 100644 --- a/qos/qos_rule_test.go +++ b/qos/qos_rule_test.go @@ -5,7 +5,6 @@ package qos_test import ( - "fmt" "testing" "github.com/omec-project/openapi/models" @@ -24,7 +23,7 @@ var flowDesc = []string{ func TestDecodeFlowDescToIPFilters(t *testing.T) { for i, flow := range flowDesc { ipf := qos.DecodeFlowDescToIPFilters(flow) - fmt.Printf("Flow: %v %v\n", i, ipf.String()) + t.Logf("flow: %v %v", i, ipf.String()) } } @@ -32,9 +31,9 @@ func TestGetPfContent(t *testing.T) { pf := &qos.PacketFilter{} for i, flow := range flowDesc { pf.GetPfContent(flow) - fmt.Println("Flow:", i) + t.Logf("Flow: %v", i) for _, pfc := range pf.Content { - fmt.Printf("%v", pfc.String()) + t.Logf("%v", pfc.String()) } } } @@ -54,12 +53,12 @@ func TestBuildQosRules(t *testing.T) { qosRules := qos.BuildQosRules(smPolicyUpdates) - fmt.Println("QosRules:", qosRules) + t.Logf("QosRules: %v", qosRules) if bytes, err := qosRules.MarshalBinary(); err != nil { - fmt.Printf("Marshal Error : %v", err.Error()) + t.Logf("marshal Error: %v", err.Error()) } else { - fmt.Printf("Encoded Bytes: %v", bytes) + t.Logf("encoded Bytes: %v", bytes) expectedBytes := []byte{ 0x1, 0x0, 0x37, 0x32, 0x31, 0x18, 0x10, 0x1, 0x1, 0x1, 0x1, 0xff, 0xff, 0xff, 0xff, 0x50, 0x3, 0xe8, diff --git a/service/init.go b/service/init.go index f5c9187a..92b27732 100644 --- a/service/init.go +++ b/service/init.go @@ -40,8 +40,6 @@ import ( "github.com/omec-project/util/http2_util" utilLogger "github.com/omec-project/util/logger" "github.com/omec-project/util/path_util" - pathUtilLogger "github.com/omec-project/util/path_util/logger" - "github.com/sirupsen/logrus" "github.com/urfave/cli" "go.uber.org/zap" "go.uber.org/zap/zapcore" @@ -88,7 +86,7 @@ type OneInstance struct { var nrfRegInProgress OneInstance -var initLog *logrus.Entry +var initLog *zap.SugaredLogger func init() { initLog = logger.InitLog @@ -155,35 +153,33 @@ func (smf *SMF) setLogLevel() { if factory.SmfConfig.Logger.SMF != nil { if factory.SmfConfig.Logger.SMF.DebugLevel != "" { - if level, err := logrus.ParseLevel(factory.SmfConfig.Logger.SMF.DebugLevel); err != nil { + if level, err := zapcore.ParseLevel(factory.SmfConfig.Logger.SMF.DebugLevel); err != nil { initLog.Warnf("SMF Log level [%s] is invalid, set to [info] level", factory.SmfConfig.Logger.SMF.DebugLevel) - logger.SetLogLevel(logrus.InfoLevel) + logger.SetLogLevel(zap.InfoLevel) } else { initLog.Infof("SMF Log level is set to [%s] level", level) logger.SetLogLevel(level) } } else { initLog.Infoln("SMF Log level is default set to [info] level") - logger.SetLogLevel(logrus.InfoLevel) + logger.SetLogLevel(zap.InfoLevel) } - logger.SetReportCaller(factory.SmfConfig.Logger.SMF.ReportCaller) } if factory.SmfConfig.Logger.NAS != nil { if factory.SmfConfig.Logger.NAS.DebugLevel != "" { - if level, err := logrus.ParseLevel(factory.SmfConfig.Logger.NAS.DebugLevel); err != nil { + if level, err := zapcore.ParseLevel(factory.SmfConfig.Logger.NAS.DebugLevel); err != nil { nasLogger.NasLog.Warnf("NAS Log level [%s] is invalid, set to [info] level", factory.SmfConfig.Logger.NAS.DebugLevel) - logger.SetLogLevel(logrus.InfoLevel) + logger.SetLogLevel(zap.InfoLevel) } else { nasLogger.SetLogLevel(level) } } else { nasLogger.NasLog.Warnln("NAS Log level not set. Default set to [info] level") - nasLogger.SetLogLevel(logrus.InfoLevel) + nasLogger.SetLogLevel(zap.InfoLevel) } - nasLogger.SetReportCaller(factory.SmfConfig.Logger.NAS.ReportCaller) } if factory.SmfConfig.Logger.NGAP != nil { @@ -231,22 +227,6 @@ func (smf *SMF) setLogLevel() { } } - if factory.SmfConfig.Logger.PathUtil != nil { - if factory.SmfConfig.Logger.PathUtil.DebugLevel != "" { - if level, err := logrus.ParseLevel(factory.SmfConfig.Logger.PathUtil.DebugLevel); err != nil { - pathUtilLogger.PathLog.Warnf("PathUtil Log level [%s] is invalid, set to [info] level", - factory.SmfConfig.Logger.PathUtil.DebugLevel) - pathUtilLogger.SetLogLevel(logrus.InfoLevel) - } else { - pathUtilLogger.SetLogLevel(level) - } - } else { - pathUtilLogger.PathLog.Warnln("PathUtil Log level not set. Default set to [info] level") - pathUtilLogger.SetLogLevel(logrus.InfoLevel) - } - pathUtilLogger.SetReportCaller(factory.SmfConfig.Logger.PathUtil.ReportCaller) - } - // Initialise Statistics go metrics.InitMetrics() } @@ -322,7 +302,7 @@ func (smf *SMF) Start() { nrfCache.InitNrfCaching(smfCtxt.NrfCacheEvictionInterval*time.Second, consumer.SendNrfForNfInstance) } - router := utilLogger.NewGinWithLogrus(logger.GinLog) + router := utilLogger.NewGinWithZap(logger.GinLog) oam.AddService(router) callback.AddService(router) for _, serviceName := range factory.SmfConfig.Configuration.ServiceNameList { @@ -354,10 +334,10 @@ func (smf *SMF) Start() { for _, upf := range context.SMF_Self().UserPlaneInformation.UPFs { if upf.NodeID.NodeIdType == context.NodeIdTypeFqdn { - logger.AppLog.Infof("send PFCP Association Request to UPF[%s](%s)\n", upf.NodeID.NodeIdValue, + logger.AppLog.Infof("send PFCP Association Request to UPF[%s](%s)", upf.NodeID.NodeIdValue, upf.NodeID.ResolveNodeIdToIp().String()) } else { - logger.AppLog.Infof("send PFCP Association Request to UPF[%s]\n", upf.NodeID.ResolveNodeIdToIp().String()) + logger.AppLog.Infof("send PFCP Association Request to UPF[%s]", upf.NodeID.ResolveNodeIdToIp().String()) } err := message.SendPfcpAssociationSetupRequest(upf.NodeID, upf.Port) if err != nil { @@ -398,7 +378,7 @@ func (smf *SMF) Start() { } func (smf *SMF) Terminate() { - logger.InitLog.Infof("terminating SMF...") + logger.InitLog.Infoln("terminating SMF...") // deregister with NRF problemDetails, err := consumer.SendDeregisterNFInstance() if problemDetails != nil { @@ -406,7 +386,7 @@ func (smf *SMF) Terminate() { } else if err != nil { logger.InitLog.Errorf("deregister NF instance Error[%+v]", err) } else { - logger.InitLog.Infof("deregister from NRF successfully") + logger.InitLog.Infoln("deregister from NRF successfully") } } @@ -428,7 +408,7 @@ func StartKeepAliveTimer(nfProfile *models.NfProfile) { func StopKeepAliveTimer() { if KeepAliveTimer != nil { - logger.InitLog.Infof("stopped KeepAlive Timer.") + logger.InitLog.Infoln("stopped KeepAlive Timer") KeepAliveTimer.Stop() KeepAliveTimer = nil } @@ -439,7 +419,7 @@ func UpdateNF() { KeepAliveTimerMutex.Lock() defer KeepAliveTimerMutex.Unlock() if KeepAliveTimer == nil { - initLog.Warnf("keepAlive timer has been stopped.") + initLog.Warnf("keepAlive timer has been stopped") return } // setting default value 30 sec @@ -484,7 +464,7 @@ func (smf *SMF) SendNrfRegistration() { // If NRF registration is ongoing then don't start another in parallel // Just mark it so that once ongoing finishes then resend another if nrfRegInProgress.intanceRun(consumer.ReSendNFRegistration) { - logger.InitLog.Infof("NRF Registration already in progress...") + logger.InitLog.Infoln("NRF Registration already in progress...") refreshNrfRegistration = true return } @@ -497,7 +477,7 @@ func (smf *SMF) SendNrfRegistration() { logger.InitLog.Infof("NRF Registration failure, %v", err.Error()) } else { StartKeepAliveTimer(prof) - logger.CfgLog.Infof("sent Register NF Instance with updated profile") + logger.CfgLog.Infoln("sent Register NF Instance with updated profile") } } } diff --git a/smf.go b/smf.go index a0d8f681..6609d503 100644 --- a/smf.go +++ b/smf.go @@ -20,13 +20,13 @@ import ( "github.com/omec-project/smf/logger" "github.com/omec-project/smf/service" - "github.com/sirupsen/logrus" "github.com/urfave/cli" + "go.uber.org/zap" ) var SMF = &service.SMF{} -var appLog *logrus.Entry +var appLog *zap.SugaredLogger func init() { appLog = logger.AppLog @@ -35,8 +35,7 @@ func init() { func main() { app := cli.NewApp() app.Name = "smf" - fmt.Print(app.Name, "\n") - // appLog.Infoln("SMF version: ", version.GetVersion()) + appLog.Infoln(app.Name) app.Usage = "-cfg common configuration file -smfcfg smf_configuration_file" app.Action = action app.Flags = SMF.GetCliCmd() diff --git a/transaction/transaction.go b/transaction/transaction.go index a5b6ea62..4e8d7cb4 100644 --- a/transaction/transaction.go +++ b/transaction/transaction.go @@ -11,7 +11,7 @@ import ( "github.com/omec-project/smf/logger" "github.com/omec-project/smf/msgtypes/svcmsgtypes" - "github.com/sirupsen/logrus" + "go.uber.org/zap" ) type Transaction struct { @@ -23,19 +23,14 @@ type Transaction struct { Err error Status chan bool NextTxn *Transaction - TxnFsmLog *logrus.Entry + TxnFsmLog *zap.SugaredLogger MsgType svcmsgtypes.SmfMsgType TxnId uint32 Priority uint32 } func (t *Transaction) initLogTags() { - subField := logrus.Fields{ - "txnid": t.TxnId, - "txntype": string(t.MsgType), "ctxtkey": t.CtxtKey, - } - - t.TxnFsmLog = logger.TxnFsmLog.WithFields(subField) + t.TxnFsmLog = logger.TxnFsmLog.With("txnid", t.TxnId, "txntype", string(t.MsgType), "ctxtkey", t.CtxtKey) } type TxnEvent uint @@ -119,7 +114,7 @@ func NewTransaction(req, rsp interface{}, msgType svcmsgtypes.SmfMsgType) *Trans func (t *Transaction) TransactionEnd() { t.endTime = time.Now() - t.TxnFsmLog.Infof("txn ended, execution time [%v] ", t.endTime.Sub(t.startTime)) + t.TxnFsmLog.Infof("txn ended, execution time [%v]", t.endTime.Sub(t.startTime)) } type TxnBus []*Transaction @@ -180,9 +175,9 @@ func (t *Transaction) StartTxnLifeCycle(fsm txnFsm) { for { currEvent := nextEvent - t.TxnFsmLog.Debugf("processing event[%v] ", currEvent.String()) + t.TxnFsmLog.Debugf("processing event[%v]", currEvent.String()) if nextEvent, err = TxnFsmHandler[currEvent](t); err != nil { - t.TxnFsmLog.Errorf("TxnFsm Error, Stage[%s] Err[%v] ", currEvent.String(), err.Error()) + t.TxnFsmLog.Errorf("TxnFsm Error, Stage[%s] Err[%v]", currEvent.String(), err.Error()) } // Current active txn is over, Schedule Next Txn if available @@ -196,12 +191,12 @@ func (t *Transaction) StartTxnLifeCycle(fsm txnFsm) { // Note- Pipelined Txn will not get chance to run immediately, // so they shall exit FSM and shall wait to run in TxnBus if nextEvent == TxnEventExit || nextEvent == TxnEventQueue { - t.TxnFsmLog.Debugf("TxnFsm [%v] ", nextEvent.String()) + t.TxnFsmLog.Debugf("TxnFsm [%v]", nextEvent.String()) return } } } func (t Transaction) String() string { - return fmt.Sprintf(" txn-id [%v], txn-type [%v], txn-key [%v] ", t.TxnId, t.MsgType, t.CtxtKey) + return fmt.Sprintf(" txn-id [%v], txn-type [%v], txn-key [%v]", t.TxnId, t.MsgType, t.CtxtKey) }