X-Git-Url: https://gerrit.o-ran-sc.org/r/gitweb?a=blobdiff_plain;ds=sidebyside;f=pkg%2Fcontrol%2Fcontrol.go;h=1bc2ee86de8588e186c0f19009a3ddc559268de8;hb=31797b49985822f1d402501f16ab2794838bebba;hp=7e2d673b4c92a50d7cdcff7a283bf9aeb0142f03;hpb=0a9f260b43017c2860137cefcaa2e79ad896ab2d;p=ric-plt%2Fsubmgr.git diff --git a/pkg/control/control.go b/pkg/control/control.go old mode 100644 new mode 100755 index 7e2d673..1bc2ee8 --- a/pkg/control/control.go +++ b/pkg/control/control.go @@ -19,69 +19,68 @@ package control -import "C" - import ( - "errors" + "fmt" + "gerrit.o-ran-sc.org/r/ric-plt/e2ap/pkg/e2ap" rtmgrclient "gerrit.o-ran-sc.org/r/ric-plt/submgr/pkg/rtmgr_client" rtmgrhandle "gerrit.o-ran-sc.org/r/ric-plt/submgr/pkg/rtmgr_client/handle" "gerrit.o-ran-sc.org/r/ric-plt/xapp-frame/pkg/xapp" httptransport "github.com/go-openapi/runtime/client" "github.com/go-openapi/strfmt" "github.com/spf13/viper" - "math/rand" - "strconv" + "sync" "time" - "sync" ) -var rmrSendMutex = &sync.Mutex{} +//----------------------------------------------------------------------------- +// +//----------------------------------------------------------------------------- -var subReqTime time.Duration = 2 * time.Second -var SubDelReqTime time.Duration = 2 * time.Second +var subReqTime time.Duration = 5 * time.Second +var subDelReqTime time.Duration = 5 * time.Second +var maxSubReqTryCount uint64 = 2 // Initial try + retry +var maxSubDelReqTryCount uint64 = 2 // Initial try + retry type Control struct { - e2ap *E2ap - registry *Registry - rtmgrClient *RtmgrClient - tracker *Tracker - rcChan chan *xapp.RMRParams - timerMap *TimerMap + e2ap *E2ap + registry *Registry + tracker *Tracker + timerMap *TimerMap + rmrSendMutex sync.Mutex + msgCounter uint64 } type RMRMeid struct { - PlmnID string - EnbID string + PlmnID string + EnbID string RanName string } -var seedSN uint16 - const ( CREATE Action = 0 MERGE Action = 1 + NONE Action = 2 DELETE Action = 3 ) func init() { - xapp.Logger.Info("SUBMGR /ric-plt-submgr:r3-test-v2") + xapp.Logger.Info("SUBMGR") viper.AutomaticEnv() viper.SetEnvPrefix("submgr") viper.AllowEmptyEnv(true) - seedSN = uint16(viper.GetInt("seed_sn")) - if seedSN == 0 { - rand.Seed(time.Now().UnixNano()) - seedSN = uint16(rand.Intn(65535)) - } - if seedSN > 65535 { - seedSN = 0 - } - xapp.Logger.Info("SUBMGR: Initial Sequence Number: %v", seedSN) } -func NewControl() Control { +func NewControl() *Control { + + transport := httptransport.New(viper.GetString("rtmgr.HostAddr")+":"+viper.GetString("rtmgr.port"), viper.GetString("rtmgr.baseUrl"), []string{"http"}) + client := rtmgrclient.New(transport, strfmt.Default) + handle := rtmgrhandle.NewProvideXappSubscriptionHandleParamsWithTimeout(10 * time.Second) + deleteHandle := rtmgrhandle.NewDeleteXappSubscriptionHandleParamsWithTimeout(10 * time.Second) + rtmgrClient := RtmgrClient{client, handle, deleteHandle} + registry := new(Registry) - registry.Initialize(seedSN) + registry.Initialize() + registry.rtmgrClient = &rtmgrClient tracker := new(Tracker) tracker.Init() @@ -89,478 +88,497 @@ func NewControl() Control { timerMap := new(TimerMap) timerMap.Init() - transport := httptransport.New(viper.GetString("rtmgr.HostAddr")+":"+viper.GetString("rtmgr.port"), viper.GetString("rtmgr.baseUrl"), []string{"http"}) - client := rtmgrclient.New(transport, strfmt.Default) - handle := rtmgrhandle.NewProvideXappSubscriptionHandleParamsWithTimeout(10 * time.Second) - deleteHandle := rtmgrhandle.NewDeleteXappSubscriptionHandleParamsWithTimeout(10 * time.Second) - rtmgrClient := RtmgrClient{client, handle, deleteHandle} - - return Control{new(E2ap), registry, &rtmgrClient, tracker, make(chan *xapp.RMRParams),timerMap} + return &Control{e2ap: new(E2ap), + registry: registry, + tracker: tracker, + timerMap: timerMap, + msgCounter: 0, + } } func (c *Control) Run() { - go c.controlLoop() xapp.Run(c) } -func (c *Control) Consume(rp *xapp.RMRParams) (err error) { - c.rcChan <- rp - return -} +func (c *Control) rmrSendRaw(desc string, params *RMRParams) (err error) { -func (c *Control) rmrSend(params *xapp.RMRParams) (err error) { + xapp.Logger.Info("%s: %s", desc, params.String()) status := false i := 1 - rmrSendMutex.Lock() - for ; i <= 10 && status == false; i++ { - status = xapp.Rmr.Send(params, false) + for ; i <= 10 && status == false; i++ { + c.rmrSendMutex.Lock() + status = xapp.Rmr.Send(params.RMRParams, false) + c.rmrSendMutex.Unlock() if status == false { - xapp.Logger.Info("rmr.Send() failed. Retry count %v, Mtype: %v, SubId: %v, Xid %s",i, params.Mtype, params.SubId, params.Xid) + xapp.Logger.Info("rmr.Send() failed. Retry count %d, %s", i, params.String()) time.Sleep(500 * time.Millisecond) } } if status == false { - err = errors.New("rmr.Send() failed") + err = fmt.Errorf("rmr.Send() failed. Retry count %d, %s", i, params.String()) + xapp.Logger.Error("%s: %s", desc, err.Error()) xapp.Rmr.Free(params.Mbuf) } - rmrSendMutex.Unlock() - - /* - if !xapp.Rmr.Send(params, false) { - err = errors.New("rmr.Send() failed") - xapp.Rmr.Free(params.Mbuf) - } - */ return } -func (c *Control) rmrReplyToSender(params *xapp.RMRParams) (err error) { - c.rmrSend(params) - return +func (c *Control) rmrSend(desc string, subs *Subscription, trans *Transaction) (err error) { + params := &RMRParams{&xapp.RMRParams{}} + params.Mtype = trans.GetMtype() + params.SubId = int(subs.GetSubId()) + params.Xid = "" + params.Meid = subs.GetMeid() + params.Src = "" + params.PayloadLen = len(trans.Payload.Buf) + params.Payload = trans.Payload.Buf + params.Mbuf = nil + + return c.rmrSendRaw(desc, params) } -func (c *Control) controlLoop() { - for { - msg := <-c.rcChan - switch msg.Mtype { - case xapp.RICMessageTypes["RIC_SUB_REQ"]: - go c.handleSubscriptionRequest(msg) - case xapp.RICMessageTypes["RIC_SUB_RESP"]: - go c.handleSubscriptionResponse(msg) - case xapp.RICMessageTypes["RIC_SUB_FAILURE"]: - go c.handleSubscriptionFailure(msg) - case xapp.RICMessageTypes["RIC_SUB_DEL_REQ"]: - go c.handleSubscriptionDeleteRequest(msg) - case xapp.RICMessageTypes["RIC_SUB_DEL_RESP"]: - go c.handleSubscriptionDeleteResponse(msg) - default: - err := errors.New("Message Type " + strconv.Itoa(msg.Mtype) + " is discarded") - xapp.Logger.Error("Unknown message type: %v", err) - } - } +func (c *Control) rmrReplyToSender(desc string, subs *Subscription, trans *Transaction) (err error) { + params := &RMRParams{&xapp.RMRParams{}} + params.Mtype = trans.GetMtype() + params.SubId = int(subs.GetSubId()) + params.Xid = trans.GetXid() + params.Meid = trans.GetMeid() + params.Src = "" + params.PayloadLen = len(trans.Payload.Buf) + params.Payload = trans.Payload.Buf + params.Mbuf = nil + + return c.rmrSendRaw(desc, params) } -func (c *Control) handleSubscriptionRequest(params *xapp.RMRParams) (err error) { - xapp.Logger.Info("Subscription Request Received from Src: %s, Mtype: %v, SubId: %v, Xid: %s, Meid: %v",params.Src, params.Mtype, params.SubId, params.Xid, params.Meid) +func (c *Control) Consume(params *xapp.RMRParams) (err error) { xapp.Rmr.Free(params.Mbuf) params.Mbuf = nil - - /* Reserve a sequence number and set it in the payload */ - newSubId, isIdValid := c.registry.ReserveSequenceNumber() - if isIdValid != true { - xapp.Logger.Info("Further processing of this SubscriptionRequest stopped. SubId: %v, Xid: %s",params.SubId, params.Xid) - return + msg := &RMRParams{params} + c.msgCounter++ + switch msg.Mtype { + case xapp.RICMessageTypes["RIC_SUB_REQ"]: + go c.handleSubscriptionRequest(msg) + case xapp.RICMessageTypes["RIC_SUB_RESP"]: + go c.handleSubscriptionResponse(msg) + case xapp.RICMessageTypes["RIC_SUB_FAILURE"]: + go c.handleSubscriptionFailure(msg) + case xapp.RICMessageTypes["RIC_SUB_DEL_REQ"]: + go c.handleSubscriptionDeleteRequest(msg) + case xapp.RICMessageTypes["RIC_SUB_DEL_RESP"]: + go c.handleSubscriptionDeleteResponse(msg) + case xapp.RICMessageTypes["RIC_SUB_DEL_FAILURE"]: + go c.handleSubscriptionDeleteFailure(msg) + default: + xapp.Logger.Info("Unknown Message Type '%d', discarding", msg.Mtype) } - err = c.e2ap.SetSubscriptionRequestSequenceNumber(params.Payload, newSubId) - if err != nil { - err = errors.New("Unable to set Subscription Sequence Number in Payload due to: " + err.Error()) - return + return nil +} +func idstring(trans fmt.Stringer, subs fmt.Stringer, err error) string { + var retval string = "" + var filler string = "" + if trans != nil { + retval += filler + trans.String() + filler = " " } - - srcAddr, srcPort, err := c.rtmgrClient.SplitSource(params.Src) - if err != nil { - xapp.Logger.Error("Failed to update routing-manager about the subscription request with reason: %s", err) - return + if subs != nil { + retval += filler + subs.String() + filler = " " } - - /* Create transatcion records for every subscription request */ - xactKey := TransactionKey{newSubId, CREATE} - xactValue := Transaction{*srcAddr, *srcPort, params} - err = c.tracker.TrackTransaction(xactKey, xactValue) if err != nil { - xapp.Logger.Error("Failed to create a Subscription Request transaction record due to %v", err) - return + retval += filler + "err(" + err.Error() + ")" + filler = " " } + return retval +} - /* Update routing manager about the new subscription*/ - subRouteAction := SubRouteInfo{CREATE, *srcAddr, *srcPort, newSubId} - xapp.Logger.Info("Starting routing manager update") - c.rtmgrClient.SubscriptionRequestUpdate(subRouteAction) - - //time.Sleep(3 * time.Second) +func (c *Control) findSubs(ids []int) (*Subscription, error) { + var subs *Subscription = nil + for _, id := range ids { + if id >= 0 { + subs = c.registry.GetSubscription(uint16(id)) + } + if subs != nil { + break + } + } + if subs == nil { + return nil, fmt.Errorf("No valid subscription found with ids %v", ids) + } + return subs, nil +} - // Setting new subscription ID in the RMR header - params.SubId = int(newSubId) - xapp.Logger.Info("Forwarding Subscription Request to E2T: Mtype: %v, SubId: %v, Xid %s, Meid %v",params.Mtype, params.SubId, params.Xid, params.Meid) - err = c.rmrSend(params) +func (c *Control) findSubsAndTrans(ids []int) (*Subscription, *Transaction, error) { + subs, err := c.findSubs(ids) if err != nil { - xapp.Logger.Error("Failed to send request to E2T %v. SubId: %v, Xid: %s", err, params.SubId, params.Xid) - } /*else { - c.timerMap.StartTimer(newSubId, subReqTime, c.handleSubscriptionRequestTimer) - }*/ - xapp.Logger.Debug("--- Debugging transaction table = %v", c.tracker.transactionTable) - return + return nil, nil, err + } + trans := subs.GetTransaction() + if trans == nil { + return subs, nil, fmt.Errorf("No ongoing transaction found from %s", idstring(nil, subs, nil)) + } + return subs, trans, nil } -func (c *Control) handleSubscriptionResponse(params *xapp.RMRParams) (err error) { - xapp.Logger.Info("Subscription Response Received from Src: %s, Mtype: %v, SubId: %v, Meid: %v",params.Src, params.Mtype, params.SubId, params.Meid) - xapp.Rmr.Free(params.Mbuf) - params.Mbuf = nil +func (c *Control) handleSubscriptionRequest(params *RMRParams) { + xapp.Logger.Info("SubReq from xapp: %s", params.String()) - payloadSeqNum, err := c.e2ap.GetSubscriptionResponseSequenceNumber(params.Payload) + SubReqMsg, err := c.e2ap.UnpackSubscriptionRequest(params.Payload) if err != nil { - err = errors.New("Unable to get Subscription Sequence Number from Payload due to: " + err.Error()) + xapp.Logger.Error("SubReq Drop: %s", idstring(params, nil, err)) return } - xapp.Logger.Info("Received payloadSeqNum: %v",payloadSeqNum) - if !c.registry.IsValidSequenceNumber(payloadSeqNum) { - err = errors.New("Unknown Subscription ID: " + strconv.Itoa(int(payloadSeqNum)) + " in Subscritpion Response. Message discarded.") + trans, err := c.tracker.TrackTransaction(NewRmrEndpoint(params.Src), params.Xid, params.Meid, false, true) + if err != nil { + xapp.Logger.Error("SubReq Drop: %s", idstring(params, nil, err)) return } + trans.SubReqMsg = SubReqMsg -// c.timerMap.StopTimer(payloadSeqNum) - - c.registry.setSubscriptionToConfirmed(payloadSeqNum) - var transaction Transaction - transaction, err = c.tracker.RetriveTransaction(payloadSeqNum, CREATE) + subs, err := c.registry.ReserveSubscription(trans.Meid) if err != nil { - xapp.Logger.Error("Failed to retrive transaction record. Err: %v", err) - xapp.Logger.Info("Further processing of this Subscription Response stopped. SubId: %v, Xid: %s",params.SubId, params.Xid) + xapp.Logger.Error("SubReq Drop: %s", idstring(trans, nil, err)) + trans.Release() return } - xapp.Logger.Info("Subscription ID: %v, from address: %v:%v. Retrieved old subId...", int(payloadSeqNum), transaction.XappInstanceAddress, transaction.XappPort) - params.SubId = int(payloadSeqNum) - params.Xid = transaction.OrigParams.Xid - - xapp.Logger.Info("Forwarding Subscription Response to UEEC: Mtype: %v, SubId: %v, Xid: %s, Meid: %v",params.Mtype, params.SubId, params.Xid, params.Meid) - err = c.rmrReplyToSender(params) + err = subs.SetTransaction(trans) if err != nil { - xapp.Logger.Error("Failed to send response to requestor %v. SubId: %v, Xid: %s", err, params.SubId, params.Xid) + xapp.Logger.Error("SubReq Drop: %s", idstring(trans, subs, err)) + subs.Release() + trans.Release() + return } + trans.SubReqMsg.RequestId.Seq = uint32(subs.GetSubId()) - xapp.Logger.Info("Subscription ID: %v, from address: %v:%v. Deleting transaction record", int(payloadSeqNum), transaction.XappInstanceAddress, transaction.XappPort) - transaction, err = c.tracker.completeTransaction(payloadSeqNum, CREATE) + xapp.Logger.Debug("SubReq: Handling %s", idstring(trans, subs, nil)) + + // + // TODO: subscription create is in fact owned by subscription and not transaction. + // Transaction is toward xapp while Subscription is toward ran. + // In merge several xapps may wake transactions, while only one subscription + // toward ran occurs -> subscription owns subscription creation toward ran + // + // This is intermediate solution while improving message handling + // + trans.Mtype, trans.Payload, err = c.e2ap.PackSubscriptionRequest(trans.SubReqMsg) if err != nil { - xapp.Logger.Error("Failed to delete a Subscription Request transaction record due to %v", err) + xapp.Logger.Error("SubResp Drop: %s", idstring(trans, subs, err)) + subs.Release() + trans.Release() return } + + c.rmrSend("SubReq: SubReq to E2T", subs, trans) + c.timerMap.StartTimer("RIC_SUB_REQ", int(subs.GetSubId()), subReqTime, FirstTry, c.handleSubscriptionRequestTimer) return } -func (c *Control) handleSubscriptionFailure(params *xapp.RMRParams) (err error) { - xapp.Logger.Info("Subscription Failure Received from Src: %s, Mtype: %v, SubId: %v, Meid: %v",params.Src, params.Mtype, params.SubId, params.Meid) - xapp.Rmr.Free(params.Mbuf) - params.Mbuf = nil +func (c *Control) handleSubscriptionResponse(params *RMRParams) { + xapp.Logger.Info("SubResp from E2T: %s", params.String()) - payloadSeqNum, err := c.e2ap.GetSubscriptionFailureSequenceNumber(params.Payload) + SubRespMsg, err := c.e2ap.UnpackSubscriptionResponse(params.Payload) if err != nil { - err = errors.New("Unable to get Subscription Sequence Number from Payload due to: " + err.Error()) + xapp.Logger.Error("SubResp Drop %s", idstring(params, nil, err)) return } - xapp.Logger.Info("Received payloadSeqNum: %v", payloadSeqNum) - // should here be IsValidSequenceNumber check? + subs, trans, err := c.findSubsAndTrans([]int{int(SubRespMsg.RequestId.Seq), params.SubId}) + if err != nil { + xapp.Logger.Error("SubResp: %s", idstring(params, nil, err)) + return + } + trans.SubRespMsg = SubRespMsg + xapp.Logger.Debug("SubResp: Handling %s", idstring(trans, subs, nil)) -// c.timerMap.StopTimer(payloadSeqNum) + c.timerMap.StopTimer("RIC_SUB_REQ", int(subs.GetSubId())) - var transaction Transaction - transaction, err = c.tracker.RetriveTransaction(payloadSeqNum, CREATE) - if err != nil { - xapp.Logger.Error("Failed to retrive transaction record. Err %v", err) - xapp.Logger.Info("Further processing of this Subscription Failure stopped. SubId: %v, Xid: %s",params.SubId, params.Xid) + responseReceived := trans.CheckResponseReceived() + if responseReceived == true { + // Subscription timer already received return } - xapp.Logger.Info("Subscription ID: %v, from address: %v:%v. Forwarding response to requestor...", int(payloadSeqNum), transaction.XappInstanceAddress, transaction.XappPort) - params.SubId = int(payloadSeqNum) - params.Xid = transaction.OrigParams.Xid - - xapp.Logger.Info("Forwarding Subscription Failure to UEEC: Mtype: %v, SubId: %v, Xid: %v, Meid: %v",params.Mtype, params.SubId, params.Xid, params.Meid) - err = c.rmrReplyToSender(params) + trans.Mtype, trans.Payload, err = c.e2ap.PackSubscriptionResponse(trans.SubRespMsg) if err != nil { - xapp.Logger.Error("Failed to send response to requestor %v. SubId: %v, Xid: %s", err, params.SubId, params.Xid) + xapp.Logger.Error("SubResp: %s", idstring(trans, subs, err)) + trans.Release() + return } - time.Sleep(3 * time.Second) - - xapp.Logger.Info("Starting routing manager update") - subRouteAction := SubRouteInfo{CREATE, transaction.XappInstanceAddress, transaction.XappPort, payloadSeqNum} - c.rtmgrClient.SubscriptionRequestUpdate(subRouteAction) - - xapp.Logger.Info("Deleting trancaction record") - if c.registry.releaseSequenceNumber(payloadSeqNum) { - transaction, err = c.tracker.completeTransaction(payloadSeqNum, CREATE) - if err != nil { - xapp.Logger.Error("Failed to delete a Subscription Request transaction record due to %v", err) - return - } - } + subs.Confirmed() + trans.Release() + c.rmrReplyToSender("SubResp: SubResp to xapp", subs, trans) return } -func (c *Control) handleSubscriptionRequestTimer(subId uint16) { - xapp.Logger.Info("Subscription Request timer expired. SubId: %v",subId) -/* - transaction, err := c.tracker.completeTransaction(subId, CREATE) +func (c *Control) handleSubscriptionFailure(params *RMRParams) { + xapp.Logger.Info("SubFail from E2T: %s", params.String()) + + SubFailMsg, err := c.e2ap.UnpackSubscriptionFailure(params.Payload) if err != nil { - xapp.Logger.Error("Failed to delete a Subscription Request transaction record due to %v", err) + xapp.Logger.Error("SubFail Drop %s", idstring(params, nil, err)) return } - xapp.Logger.Info("SubId: %v, Xid %v, Meid: %v",subId, transaction.OrigParams.Xid, transaction.OrigParams.Meid) - var params xapp.RMRParams - params.Mtype = 12012 //xapp.RICMessageTypes["RIC_SUB_FAILURE"] - params.SubId = int(subId) - params.Meid = transaction.OrigParams.Meid - params.Xid = transaction.OrigParams.Xid - payload := []byte("40C9408098000003EA7E00050000010016EA6300020021EA6E00808180EA6F000400000000EA6F000400010040EA6F000400020080EA6F0004000300C0EA6F000400040100EA6F000400050140EA6F000400060180EA6F0004000701C0EA6F000400080200EA6F000400090240EA6F0004000A0280EA6F0004000B02C0EA6F0004000C0300EA6F0004000D0340EA6F0004000E0380EA6F0004000F03C0") - params.PayloadLen = len(payload) - params.Payload = payload - - xapp.Logger.Info("Forwarding Subscription Failure to UEEC: Mtype: %v, SubId: %v, Xid: %s, Meid: %v",params.Mtype, params.SubId, params.Xid, params.Meid) - err = c.rmrReplyToSender(¶ms) + subs, trans, err := c.findSubsAndTrans([]int{int(SubFailMsg.RequestId.Seq), params.SubId}) if err != nil { - xapp.Logger.Error("Failed to send response to requestor %v. SubId: %v, Xid: %s", err, params.SubId, params.Xid) + xapp.Logger.Error("SubFail: %s", idstring(params, nil, err)) + return } -*/ -/* - time.Sleep(3 * time.Second) + trans.SubFailMsg = SubFailMsg + xapp.Logger.Debug("SubFail: Handling %s", idstring(trans, subs, nil)) - xapp.Logger.Info("Subscription ID: %v, from address: %v:%v. Deleting transaction record", int(subId), transaction.XappInstanceAddress, transaction.XappPort) - - xapp.Logger.Info("Starting routing manager update") - subRouteAction := SubRouteInfo{DELETE, transaction.XappInstanceAddress, transaction.XappPort, payloadSeqNum} - c.rtmgrClient.SubscriptionRequestUpdate(subRouteAction) + c.timerMap.StopTimer("RIC_SUB_REQ", int(subs.GetSubId())) + responseReceived := trans.CheckResponseReceived() + if responseReceived == true { + // Subscription timer already received + return + } - xapp.Logger.Info("Deleting trancaction record") - if c.registry.releaseSequenceNumber(payloadSeqNum) { - transaction, err = c.tracker.completeTransaction(payloadSeqNum, CREATE) - if err != nil { - xapp.Logger.Error("Failed to delete a Subscription Request transaction record due to %v", err) - return - } + trans.Mtype, trans.Payload, err = c.e2ap.PackSubscriptionFailure(trans.SubFailMsg) + if err == nil { + c.rmrReplyToSender("SubFail: SubFail to xapp", subs, trans) + time.Sleep(3 * time.Second) + } else { + //TODO error handling improvement + xapp.Logger.Error("SubFail: (continue cleaning) %s", idstring(trans, subs, err)) } -*/ + + trans.Release() + subs.Release() return } -func (act Action) String() string { - actions := [...]string{ - "CREATE", - "MERGE", - "DELETE", +func (c *Control) handleSubscriptionRequestTimer(strId string, nbrId int, tryCount uint64) { + xapp.Logger.Info("SubReq timeout: subId: %v, tryCount: %v", nbrId, tryCount) + + subs, trans, err := c.findSubsAndTrans(([]int{nbrId})) + if err != nil { + xapp.Logger.Error("SubReq timeout: %s", idstring(nil, nil, err)) + return } + xapp.Logger.Debug("SubReq timeout: Handling %s", idstring(trans, subs, nil)) - if act < CREATE || act > DELETE { - return "Unknown" + responseReceived := trans.CheckResponseReceived() + if responseReceived == true { + // Subscription Response or Failure already received + return } - return actions[act] -} -func (act Action) valid() bool { - switch act { - case CREATE, MERGE, DELETE: - return true - default: - return false + if tryCount < maxSubReqTryCount { + xapp.Logger.Info("SubReq timeout: %s", idstring(trans, subs, nil)) + + trans.RetryTransaction() + + c.rmrSend("SubReq timeout: SubReq to E2T", subs, trans) + + tryCount++ + c.timerMap.StartTimer("RIC_SUB_REQ", int(subs.GetSubId()), subReqTime, tryCount, c.handleSubscriptionRequestTimer) + return } -} -func (c *Control) handleSubscriptionDeleteRequest(params *xapp.RMRParams) (err error) { - xapp.Logger.Info("Subscription Delete Request Received from Src: %s, Mtype: %v, SubId: %v, Xid: %s, Meid: %v",params.Src, params.Mtype, params.SubId, params.Xid, params.Meid) - xapp.Rmr.Free(params.Mbuf) - params.Mbuf = nil + // Release CREATE transaction + trans.Release() - payloadSeqNum, err := c.e2ap.GetSubscriptionDeleteRequestSequenceNumber(params.Payload) + // Create DELETE transaction (internal and no messages toward xapp) + deltrans, err := c.tracker.TrackTransaction(&trans.RmrEndpoint, trans.GetXid(), trans.GetMeid(), false, false) if err != nil { - err = errors.New("Unable to get Subscription Sequence Number from Payload due to: " + err.Error()) + xapp.Logger.Error("SubReq timeout: %s", idstring(trans, subs, err)) + //TODO improve error handling. Important at least in merge + subs.Release() return } - xapp.Logger.Info("Received payloadSeqNum: %v", payloadSeqNum) - if c.registry.IsValidSequenceNumber(payloadSeqNum) { - c.registry.deleteSubscription(payloadSeqNum) - trackErr := c.trackDeleteTransaction(params, payloadSeqNum) - if trackErr != nil { - xapp.Logger.Error("Failed to create a Subscription Delete Request transaction record due to %v", trackErr) - return trackErr - } - } - xapp.Logger.Info("Forwarding Delete Subscription Request to E2T: Mtype: %v, SubId: %v, Xid: %s, Meid: %v",params.Mtype, params.SubId, params.Xid, params.Meid) - c.rmrSend(params) + deltrans.SubDelReqMsg = &e2ap.E2APSubscriptionDeleteRequest{} + deltrans.SubDelReqMsg.RequestId.Id = trans.SubReqMsg.RequestId.Id + deltrans.SubDelReqMsg.RequestId.Seq = uint32(subs.GetSubId()) + deltrans.SubDelReqMsg.FunctionId = trans.SubReqMsg.FunctionId + deltrans.Mtype, deltrans.Payload, err = c.e2ap.PackSubscriptionDeleteRequest(deltrans.SubDelReqMsg) if err != nil { - xapp.Logger.Error("Failed to send request to E2T %v. SubId: %v, Xid: %s", err, params.SubId, params.Xid) - } /*else { - c.timerMap.StartTimer(payloadSeqNum, SubDelReqTime, c.handleSubscriptionDeleteRequestTimer) - }*/ - return -} + xapp.Logger.Error("SubReq timeout: %s", idstring(trans, subs, err)) + //TODO improve error handling. Important at least in merge + deltrans.Release() + subs.Release() + return + } -func (c *Control) trackDeleteTransaction(params *xapp.RMRParams, payloadSeqNum uint16) (err error) { - srcAddr, srcPort, err := c.rtmgrClient.SplitSource(params.Src) + err = subs.SetTransaction(deltrans) if err != nil { - xapp.Logger.Error("Failed to update routing-manager about the subscription delete request with reason: %s", err) + xapp.Logger.Error("SubReq timeout: %s", idstring(trans, subs, err)) + //TODO improve error handling. Important at least in merge + deltrans.Release() + return } - xactKey := TransactionKey{payloadSeqNum, DELETE} - xactValue := Transaction{*srcAddr, *srcPort, params} - err = c.tracker.TrackTransaction(xactKey, xactValue) + + c.rmrSend("SubReq timer: SubDelReq to E2T", subs, deltrans) + c.timerMap.StartTimer("RIC_SUB_DEL_REQ", int(subs.GetSubId()), subDelReqTime, FirstTry, c.handleSubscriptionDeleteRequestTimer) return } -func (c *Control) handleSubscriptionDeleteResponse(params *xapp.RMRParams) (err error) { - xapp.Logger.Info("Subscription Delete Response Received from Src: %s, Mtype: %v, SubId: %v, Meid: %v",params.Src, params.Mtype, params.SubId, params.Meid) - xapp.Rmr.Free(params.Mbuf) - params.Mbuf = nil +func (c *Control) handleSubscriptionDeleteRequest(params *RMRParams) { + xapp.Logger.Info("SubDelReq from xapp: %s", params.String()) - payloadSeqNum, err := c.e2ap.GetSubscriptionDeleteResponseSequenceNumber(params.Payload) + SubDelReqMsg, err := c.e2ap.UnpackSubscriptionDeleteRequest(params.Payload) if err != nil { - err = errors.New("Unable to get Subscription Sequence Number from Payload due to: " + err.Error()) + xapp.Logger.Error("SubDelReq Drop %s", idstring(params, nil, err)) return } - xapp.Logger.Info("Received payloadSeqNum: %v", payloadSeqNum) - // should here be IsValidSequenceNumber check? -// c.timerMap.StopTimer(payloadSeqNum) - - var transaction Transaction - transaction, err = c.tracker.RetriveTransaction(payloadSeqNum, DELETE) - if err != nil { - xapp.Logger.Error("Failed to retrive transaction record. Err %v", err) - xapp.Logger.Info("Further processing of this Subscription Delete Response stopped. SubId: %v, Xid: %s",params.SubId, params.Xid) + trans, err := c.tracker.TrackTransaction(NewRmrEndpoint(params.Src), params.Xid, params.Meid, false, true) + if err != nil { + xapp.Logger.Error("SubDelReq Drop %s", idstring(params, nil, err)) return } - xapp.Logger.Info("Subscription ID: %v, from address: %v:%v. Forwarding response to requestor...", int(payloadSeqNum), transaction.XappInstanceAddress, transaction.XappPort) + trans.SubDelReqMsg = SubDelReqMsg - params.SubId = int(payloadSeqNum) - params.Xid = transaction.OrigParams.Xid - xapp.Logger.Info("Forwarding Subscription Delete Response to UEEC: Mtype: %v, SubId: %v, Xid: %v, Meid: %v",params.Mtype, params.SubId, params.Xid, params.Meid) - err = c.rmrReplyToSender(params) + subs, err := c.findSubs([]int{int(trans.SubDelReqMsg.RequestId.Seq), params.SubId}) if err != nil { - xapp.Logger.Error("Failed to send response to requestor %v. SubId: %v, Xid: %s", err, params.SubId, params.Xid) -// return + xapp.Logger.Error("SubDelReq: %s", idstring(params, nil, err)) + trans.Release() + return } - time.Sleep(3 * time.Second) + err = subs.SetTransaction(trans) + if err != nil { + xapp.Logger.Error("SubDelReq: %s", idstring(trans, subs, err)) + trans.Release() + return + } - xapp.Logger.Info("Starting routing manager update") - subRouteAction := SubRouteInfo{DELETE, transaction.XappInstanceAddress, transaction.XappPort, payloadSeqNum} - c.rtmgrClient.SubscriptionRequestUpdate(subRouteAction) + xapp.Logger.Debug("SubDelReq: Handling %s", idstring(trans, subs, nil)) - xapp.Logger.Info("Deleting trancaction record") - if c.registry.releaseSequenceNumber(payloadSeqNum) { - transaction, err = c.tracker.completeTransaction(payloadSeqNum, DELETE) - if err != nil { - xapp.Logger.Error("Failed to delete a Subscription Delete Request transaction record due to %v", err) - return - } + // + // TODO: subscription delete is in fact owned by subscription and not transaction. + // Transaction is toward xapp while Subscription is toward ran. + // In merge several xapps may wake transactions, while only one subscription + // toward ran occurs -> subscription owns subscription creation toward ran + // + // This is intermediate solution while improving message handling + // + trans.Mtype, trans.Payload, err = c.e2ap.PackSubscriptionDeleteRequest(trans.SubDelReqMsg) + if err != nil { + xapp.Logger.Error("SubDelReq: %s", idstring(trans, subs, err)) + trans.Release() + return } + + subs.UnConfirmed() + + c.rmrSend("SubDelReq: SubDelReq to E2T", subs, trans) + + c.timerMap.StartTimer("RIC_SUB_DEL_REQ", int(subs.GetSubId()), subDelReqTime, FirstTry, c.handleSubscriptionDeleteRequestTimer) return } -func (c *Control) handleSubscriptionDeleteFailure(params *xapp.RMRParams) (err error) { - xapp.Logger.Info("Subscription Delete Failure Received from Src: %s, Mtype: %v, SubId: %v, Meid: %v",params.Src, params.Mtype, params.SubId, params.Meid) - xapp.Rmr.Free(params.Mbuf) - params.Mbuf = nil +func (c *Control) handleSubscriptionDeleteResponse(params *RMRParams) (err error) { + xapp.Logger.Info("SubDelResp from E2T:%s", params.String()) + + SubDelRespMsg, err := c.e2ap.UnpackSubscriptionDeleteResponse(params.Payload) + if err != nil { + xapp.Logger.Error("SubDelResp: Dropping this msg. %s", idstring(params, nil, err)) + return + } - payloadSeqNum, err := c.e2ap.GetSubscriptionDeleteFailureSequenceNumber(params.Payload) + subs, trans, err := c.findSubsAndTrans([]int{int(SubDelRespMsg.RequestId.Seq), params.SubId}) if err != nil { - err = errors.New("Unable to get Subscription Sequence Number from Payload due to: " + err.Error()) + xapp.Logger.Error("SubDelResp: %s", idstring(params, nil, err)) return } - xapp.Logger.Info("Received payloadSeqNum: %v", payloadSeqNum) + trans.SubDelRespMsg = SubDelRespMsg + xapp.Logger.Debug("SubDelResp: Handling %s", idstring(trans, subs, nil)) - // should here be IsValidSequenceNumber check? -// c.timerMap.StopTimer(payloadSeqNum) + c.timerMap.StopTimer("RIC_SUB_DEL_REQ", int(subs.GetSubId())) - var transaction Transaction - transaction, err = c.tracker.RetriveTransaction(payloadSeqNum, DELETE) - if err != nil { - xapp.Logger.Error("Failed to retrive transaction record. Err %v", err) - xapp.Logger.Info("Further processing of this Subscription Delete Failure stopped. SubId: %v, Xid: %s",params.SubId, params.Xid) + responseReceived := trans.CheckResponseReceived() + if responseReceived == true { + // Subscription Delete timer already received return } - xapp.Logger.Info("Subscription ID: %v, from address: %v:%v. Forwarding response to requestor...", int(payloadSeqNum), transaction.XappInstanceAddress, transaction.XappPort) - params.SubId = int(payloadSeqNum) - params.Xid = transaction.OrigParams.Xid - xapp.Logger.Info("Forwarding Subscription Delete Failure to UEEC: Mtype: %v, SubId: %v, Xid: %v, Meid: %v",params.Mtype, params.SubId, params.Xid, params.Meid) - err = c.rmrReplyToSender(params) + c.sendSubscriptionDeleteResponse("SubDelResp", trans, subs) + return +} + +func (c *Control) handleSubscriptionDeleteFailure(params *RMRParams) { + xapp.Logger.Info("SubDelFail from E2T:%s", params.String()) + + SubDelFailMsg, err := c.e2ap.UnpackSubscriptionDeleteFailure(params.Payload) if err != nil { - xapp.Logger.Error("Failed to send response to requestor %v. SubId: %v, Xid: %s", err, params.SubId, params.Xid) -// return + xapp.Logger.Error("SubDelFail: Dropping this msg. %s", idstring(params, nil, err)) + return } - time.Sleep(3 * time.Second) + subs, trans, err := c.findSubsAndTrans([]int{int(SubDelFailMsg.RequestId.Seq), params.SubId}) + if err != nil { + xapp.Logger.Error("SubDelFail: %s", idstring(params, nil, err)) + return + } + trans.SubDelFailMsg = SubDelFailMsg + xapp.Logger.Debug("SubDelFail: Handling %s", idstring(trans, subs, nil)) - xapp.Logger.Info("Starting routing manager update") - subRouteAction := SubRouteInfo{DELETE, transaction.XappInstanceAddress, transaction.XappPort, payloadSeqNum} - c.rtmgrClient.SubscriptionRequestUpdate(subRouteAction) + c.timerMap.StopTimer("RIC_SUB_DEL_REQ", int(subs.GetSubId())) - xapp.Logger.Info("Deleting trancaction record") - if c.registry.releaseSequenceNumber(payloadSeqNum) { - transaction, err = c.tracker.completeTransaction(payloadSeqNum, DELETE) - if err != nil { - xapp.Logger.Error("Failed to delete a Subscription Delete Request transaction record due to %v", err) - return - } + responseReceived := trans.CheckResponseReceived() + if responseReceived == true { + // Subscription Delete timer already received + return } + + c.sendSubscriptionDeleteResponse("SubDelFail", trans, subs) return } -func (c *Control) handleSubscriptionDeleteRequestTimer(subId uint16) { - xapp.Logger.Info("Subscription Delete Request timer expired. SubId: %v",subId) -/* - transaction, err := c.tracker.completeTransaction(subId, DELETE) +func (c *Control) handleSubscriptionDeleteRequestTimer(strId string, nbrId int, tryCount uint64) { + xapp.Logger.Info("SubDelReq timeout: subId: %v, tryCount: %v", nbrId, tryCount) + + subs, trans, err := c.findSubsAndTrans([]int{nbrId}) if err != nil { - xapp.Logger.Error("Failed to delete a Subscription Delete Request transaction record due to %v", err) + xapp.Logger.Error("SubDelReq timeout: %s", idstring(nil, nil, err)) return } - xapp.Logger.Info("SubId: %v, Xid %v, Meid: %v",subId, transaction.OrigParams.Xid, transaction.OrigParams.Meid) - - var params xapp.RMRParams - params.Mtype = 12022 //xapp.RICMessageTypes["RIC_SUB_DEL_FAILURE"] - params.SubId = int(subId) - params.Meid = transaction.OrigParams.Meid - params.Xid = transaction.OrigParams.Xid - payload := []byte("40CA4018000003EA7E00050000010016EA6300020021EA74000200C0") - params.PayloadLen = len(payload) - params.Payload = payload + xapp.Logger.Debug("SubDelReq timeout: Handling %s", idstring(trans, subs, nil)) - xapp.Logger.Info("Forwarding Subscription Delete Failure to UEEC: Mtype: %v, SubId: %v, Xid: %s, Meid: %v",params.Mtype, params.SubId, params.Xid, params.Meid) - err = c.rmrReplyToSender(¶ms) - if err != nil { - xapp.Logger.Error("Failed to send response to requestor %v. SubId: %v, Xid: %s", err, params.SubId, params.Xid) + responseReceived := trans.CheckResponseReceived() + if responseReceived == true { + // Subscription Delete Response or Failure already received + return } -*/ -/* - time.Sleep(3 * time.Second) - xapp.Logger.Info("Subscription ID: %v, from address: %v:%v. Deleting transaction record", int(subId), transaction.XappInstanceAddress, transaction.XappPort) - - xapp.Logger.Info("Starting routing manager update") - subRouteAction := SubRouteInfo{DELETE, transaction.XappInstanceAddress, transaction.XappPort, payloadSeqNum} - c.rtmgrClient.SubscriptionRequestUpdate(subRouteAction) - - xapp.Logger.Info("Deleting trancaction record") - if c.registry.releaseSequenceNumber(payloadSeqNum) { - transaction, err = c.tracker.completeTransaction(payloadSeqNum, DELETE) - if err != nil { - xapp.Logger.Error("Failed to delete a Subscription Delete Request transaction record due to %v", err) - return - } + + if tryCount < maxSubDelReqTryCount { + // Set possible to handle new response for the subId + trans.RetryTransaction() + c.rmrSend("SubDelReq timeout: SubDelReq to E2T", subs, trans) + tryCount++ + c.timerMap.StartTimer("RIC_SUB_DEL_REQ", int(subs.GetSubId()), subReqTime, tryCount, c.handleSubscriptionDeleteRequestTimer) + return } -*/ + + c.sendSubscriptionDeleteResponse("SubDelReq(timer)", trans, subs) return +} + +func (c *Control) sendSubscriptionDeleteResponse(desc string, trans *Transaction, subs *Subscription) { + + if trans.ForwardRespToXapp == true { + //Always generate SubDelResp + trans.SubDelRespMsg = &e2ap.E2APSubscriptionDeleteResponse{} + trans.SubDelRespMsg.RequestId.Id = trans.SubDelReqMsg.RequestId.Id + trans.SubDelRespMsg.RequestId.Seq = uint32(subs.GetSubId()) + trans.SubDelRespMsg.FunctionId = trans.SubDelReqMsg.FunctionId + + var err error + trans.Mtype, trans.Payload, err = c.e2ap.PackSubscriptionDeleteResponse(trans.SubDelRespMsg) + if err == nil { + c.rmrReplyToSender(desc+": SubDelResp to xapp", subs, trans) + time.Sleep(3 * time.Second) + } else { + //TODO error handling improvement + xapp.Logger.Error("%s: (continue cleaning) %s", desc, idstring(trans, subs, err)) + } } + + trans.Release() + subs.Release() +}