From fe2cdabf98e8d1028bbe1713daa187e538f042a0 Mon Sep 17 00:00:00 2001 From: Markku Virtanen Date: Fri, 21 May 2021 10:59:29 +0000 Subject: [PATCH] Restored UT cases + reduced UT run time Change-Id: I7444743442298c851215f750738a1b39db9a3243 Signed-off-by: Markku Virtanen --- pkg/control/control.go | 20 +++++++++++++---- pkg/control/registry.go | 1 + pkg/control/sdl_test.go | 14 ++++++++---- pkg/control/ut_ctrl_submgr_test.go | 44 +++++++++++++++++--------------------- pkg/control/ut_messaging_test.go | 10 ++++----- pkg/teststube2ap/stubE2.go | 8 ++++++- test/config-file.json | 1 + 7 files changed, 59 insertions(+), 39 deletions(-) diff --git a/pkg/control/control.go b/pkg/control/control.go index aee1158..9b3f43d 100755 --- a/pkg/control/control.go +++ b/pkg/control/control.go @@ -63,6 +63,7 @@ func idstring(err error, entries ...fmt.Stringer) string { var e2tSubReqTimeout time.Duration var e2tSubDelReqTime time.Duration var e2tRecvMsgTimeout time.Duration +var waitRouteCleanup_ms time.Duration var e2tMaxSubReqTryCount uint64 // Initial try + retry var e2tMaxSubDelReqTryCount uint64 // Initial try + retry var readSubsFromDb string @@ -165,11 +166,21 @@ func (c *Control) ReadConfigParameters(f string) { e2tRecvMsgTimeout = 2000 * 1000000 } xapp.Logger.Info("e2tRecvMsgTimeout %v", e2tRecvMsgTimeout) + + // Internal cfg parameter, used to define a wait time for RMR route clean-up. None default + // value 100ms used currently only in unittests. + waitRouteCleanup_ms = viper.GetDuration("controls.waitRouteCleanup_ms") * 1000000 + if waitRouteCleanup_ms == 0 { + waitRouteCleanup_ms = 5000 * 1000000 + } + xapp.Logger.Info("waitRouteCleanup %v", waitRouteCleanup_ms) + e2tMaxSubReqTryCount = viper.GetUint64("controls.e2tMaxSubReqTryCount") if e2tMaxSubReqTryCount == 0 { e2tMaxSubReqTryCount = 1 } xapp.Logger.Info("e2tMaxSubReqTryCount %v", e2tMaxSubReqTryCount) + e2tMaxSubDelReqTryCount = viper.GetUint64("controls.e2tMaxSubDelReqTryCount") if e2tMaxSubDelReqTryCount == 0 { e2tMaxSubDelReqTryCount = 1 @@ -365,7 +376,7 @@ func (c *Control) handleSubscriptionRequest(trans *TransactionXapp, subReqMsg *e } err = fmt.Errorf("XAPP-SubReq: failed %s", idstring(err, trans, subs)) xapp.Logger.Error("%s", err.Error()) - c.registry.RemoveFromSubscription(subs, trans, 5*time.Second, c) + c.registry.RemoveFromSubscription(subs, trans, waitRouteCleanup_ms, c) return nil, err } @@ -449,7 +460,7 @@ func (c *Control) SubscriptionDeleteHandler(restSubId *string, endPoint *string, xapp.Logger.Debug("XAPP-SubDelReq: Handling event %s ", idstring(nil, trans, subs)) - c.registry.RemoveFromSubscription(subs, trans, 5*time.Second, c) + c.registry.RemoveFromSubscription(subs, trans, waitRouteCleanup_ms, c) return nil } @@ -748,7 +759,7 @@ func (c *Control) handleSubscriptionCreate(subs *Subscription, parentTrans *Tran //Now RemoveFromSubscription in here to avoid race conditions (mostly concerns delete) if valid == false { - c.registry.RemoveFromSubscription(subs, parentTrans, 5*time.Second, c) + c.registry.RemoveFromSubscription(subs, parentTrans, waitRouteCleanup_ms, c) } c.UpdateSubscriptionInDB(subs, removeSubscriptionFromDb) @@ -780,7 +791,7 @@ func (c *Control) handleSubscriptionDelete(subs *Subscription, parentTrans *Tran //Now RemoveFromSubscription in here to avoid race conditions (mostly concerns delete) // If parallel deletes ongoing both might pass earlier sendE2TSubscriptionDeleteRequest(...) if // RemoveFromSubscription locates in caller side (now in handleXAPPSubscriptionDeleteRequest(...)) - c.registry.RemoveFromSubscription(subs, parentTrans, 5*time.Second, c) + c.registry.RemoveFromSubscription(subs, parentTrans, waitRouteCleanup_ms, c) c.registry.UpdateSubscriptionToDb(subs, c) parentTrans.SendEvent(nil, 0) } @@ -803,6 +814,7 @@ func (c *Control) sendE2TSubscriptionRequest(subs *Subscription, trans *Transact // Write uncompleted subscrition in db. If no response for subscrition it need to be re-processed (deleted) after restart c.WriteSubscriptionToDb(subs) + for retries := uint64(0); retries < e2tMaxSubReqTryCount; retries++ { desc := fmt.Sprintf("(retry %d)", retries) if retries == 0 { diff --git a/pkg/control/registry.go b/pkg/control/registry.go index 93a287a..ddb0226 100644 --- a/pkg/control/registry.go +++ b/pkg/control/registry.go @@ -336,6 +336,7 @@ func (r *Registry) RemoveFromSubscription(subs *Subscription, trans *Transaction go func() { if waitRouteClean > 0 { + xapp.Logger.Debug("Pending %v in order to wait route cleanup", waitRouteClean) time.Sleep(waitRouteClean) } diff --git a/pkg/control/sdl_test.go b/pkg/control/sdl_test.go index 6b3ca0b..2fac9b2 100644 --- a/pkg/control/sdl_test.go +++ b/pkg/control/sdl_test.go @@ -22,15 +22,17 @@ package control import ( "encoding/json" "fmt" - "gerrit.o-ran-sc.org/r/ric-plt/e2ap/pkg/e2ap" - "gerrit.o-ran-sc.org/r/ric-plt/submgr/pkg/teststube2ap" - "gerrit.o-ran-sc.org/r/ric-plt/xapp-frame/pkg/xapp" - "github.com/stretchr/testify/assert" "reflect" "strconv" "strings" + "sync" "testing" "time" + + "gerrit.o-ran-sc.org/r/ric-plt/e2ap/pkg/e2ap" + "gerrit.o-ran-sc.org/r/ric-plt/submgr/pkg/teststube2ap" + "gerrit.o-ran-sc.org/r/ric-plt/xapp-frame/pkg/xapp" + "github.com/stretchr/testify/assert" ) var sdlShouldReturnError bool = false @@ -48,6 +50,7 @@ type Mock struct { register map[uint32]*Subscription subIds []uint32 lastAllocatedSubId uint32 + marshalLock sync.Mutex } var mock *Mock @@ -464,6 +467,9 @@ func (m *Mock) Set(pairs ...interface{}) error { var key string var val string + m.marshalLock.Lock() + defer m.marshalLock.Unlock() + if sdlShouldReturnError == true { return GetSdlError() } diff --git a/pkg/control/ut_ctrl_submgr_test.go b/pkg/control/ut_ctrl_submgr_test.go index 9ffda38..038c20a 100644 --- a/pkg/control/ut_ctrl_submgr_test.go +++ b/pkg/control/ut_ctrl_submgr_test.go @@ -120,12 +120,12 @@ func PringSubscriptionQueryResult(resp models.SubscriptionList) { func (mc *testingSubmgrControl) wait_registry_empty(t *testing.T, secs int) bool { cnt := int(0) i := 1 - for ; i <= secs*2; i++ { + for ; i <= secs*10; i++ { cnt = len(mc.c.registry.register) if cnt == 0 { return true } - time.Sleep(500 * time.Millisecond) + time.Sleep(100 * time.Millisecond) } mc.TestError(t, "(submgr) no registry empty within %d secs: %d", secs, cnt) return false @@ -139,14 +139,14 @@ func (mc *testingSubmgrControl) get_registry_next_subid(t *testing.T) uint32 { func (mc *testingSubmgrControl) wait_registry_next_subid_change(t *testing.T, origSubId uint32, secs int) (uint32, bool) { i := 1 - for ; i <= secs*2; i++ { + for ; i <= secs*10; i++ { mc.c.registry.mutex.Lock() currSubId := mc.c.registry.subIds[0] mc.c.registry.mutex.Unlock() if currSubId != origSubId { return currSubId, true } - time.Sleep(500 * time.Millisecond) + time.Sleep(100 * time.Millisecond) } mc.TestError(t, "(submgr) no subId change within %d secs", secs) return 0, false @@ -155,12 +155,12 @@ func (mc *testingSubmgrControl) wait_registry_next_subid_change(t *testing.T, or func (mc *testingSubmgrControl) wait_subs_clean(t *testing.T, e2SubsId uint32, secs int) bool { var subs *Subscription i := 1 - for ; i <= secs*2; i++ { + for ; i <= secs*10; i++ { subs = mc.c.registry.GetSubscription(e2SubsId) if subs == nil { return true } - time.Sleep(500 * time.Millisecond) + time.Sleep(100 * time.Millisecond) } if subs != nil { mc.TestError(t, "(submgr) no clean within %d secs: %s", secs, subs.String()) @@ -171,27 +171,23 @@ func (mc *testingSubmgrControl) wait_subs_clean(t *testing.T, e2SubsId uint32, s } func (mc *testingSubmgrControl) wait_multi_subs_clean(t *testing.T, e2SubsIds []uint32, secs int) bool { - var subs *Subscription - var purgedSubscriptions int - i := 1 - k := 0 - for ; i <= secs*2; i++ { + + purgedSubscriptions := 0 + + for i := 1; i <= secs*10; i++ { purgedSubscriptions = 0 - for k = 0; k <= len(e2SubsIds); i++ { - subs = mc.c.registry.GetSubscription(e2SubsIds[k]) + for k := 0; k <= len(e2SubsIds); i++ { + subs := mc.c.registry.GetSubscription(e2SubsIds[k]) if subs == nil { mc.TestLog(t, "(submgr) subscriber purged for esSubsId %v", e2SubsIds[k]) purgedSubscriptions += 1 if purgedSubscriptions == len(e2SubsIds) { return true - } else { - continue } - } else { - mc.TestLog(t, "(submgr) subscriber %s no clean within %d secs: subs(N/A) - purged subscriptions %v", subs.String(), secs, purgedSubscriptions) - time.Sleep(500 * time.Millisecond) } } + mc.TestLog(t, "(submgr) subscriptions pending purging %v/%v after %d msecs", purgedSubscriptions, len(e2SubsIds), i+500) + time.Sleep(100 * time.Millisecond) } mc.TestError(t, "(submgr) no clean within %d secs: subs(N/A) - %v/%v subscriptions found still", secs, purgedSubscriptions, len(e2SubsIds)) @@ -202,7 +198,7 @@ func (mc *testingSubmgrControl) wait_multi_subs_clean(t *testing.T, e2SubsIds [] func (mc *testingSubmgrControl) wait_subs_trans_clean(t *testing.T, e2SubsId uint32, secs int) bool { var trans TransactionIf i := 1 - for ; i <= secs*2; i++ { + for ; i <= secs*10; i++ { subs := mc.c.registry.GetSubscription(e2SubsId) if subs == nil { return true @@ -211,7 +207,7 @@ func (mc *testingSubmgrControl) wait_subs_trans_clean(t *testing.T, e2SubsId uin if trans == nil { return true } - time.Sleep(500 * time.Millisecond) + time.Sleep(100 * time.Millisecond) } if trans != nil { mc.TestError(t, "(submgr) no clean within %d secs: %s", secs, trans.String()) @@ -239,12 +235,12 @@ func (mc *testingSubmgrControl) wait_subs_entrypoint_cnt_change(t *testing.T, or } i := 1 - for ; i <= secs*2; i++ { + for ; i <= secs*10; i++ { curr := subs.EpList.Size() if curr != orig { return curr, true } - time.Sleep(500 * time.Millisecond) + time.Sleep(100 * time.Millisecond) } mc.TestError(t, "(submgr) no subs %d entrypoint cnt change within %d secs", origSubId, secs) return 0, false @@ -259,12 +255,12 @@ func (mc *testingSubmgrControl) get_msgcounter(t *testing.T) uint64 { func (mc *testingSubmgrControl) wait_msgcounter_change(t *testing.T, orig uint64, secs int) (uint64, bool) { i := 1 - for ; i <= secs*2; i++ { + for ; i <= secs*10; i++ { curr := mc.c.CntRecvMsg if curr != orig { return curr, true } - time.Sleep(500 * time.Millisecond) + time.Sleep(100 * time.Millisecond) } mc.TestError(t, "(submgr) no msg counter change within %d secs", secs) return 0, false diff --git a/pkg/control/ut_messaging_test.go b/pkg/control/ut_messaging_test.go index 891437f..20f8709 100644 --- a/pkg/control/ut_messaging_test.go +++ b/pkg/control/ut_messaging_test.go @@ -4167,8 +4167,10 @@ func TestRESTSubReqAndSubDelOkSameActionWithRestartsInMiddle(t *testing.T) { // mainCtrl.SimulateRestart(t) // xapp.Logger.Debug("mainCtrl.SimulateRestart done") - // Delete subscription 1 + // Delete subscription 1, and wait until it has removed the first endpoint + subepcnt := mainCtrl.get_subs_entrypoint_cnt(t, e2SubsId1) xappConn1.SendRESTSubsDelReq(t, &restSubId1) + mainCtrl.wait_subs_entrypoint_cnt_change(t, e2SubsId1, subepcnt, 10) // When SDL support for the REST Interface is added // the submgr restart statement below should be removed @@ -4176,7 +4178,6 @@ func TestRESTSubReqAndSubDelOkSameActionWithRestartsInMiddle(t *testing.T) { // mainCtrl.SimulateRestart(t) // xapp.Logger.Debug("mainCtrl.SimulateRestart done") - queryXappSubscription(t, int64(e2SubsId1), "RAN_NAME_1", []string{"localhost:13660"}) // Delete subscription 2 @@ -4435,7 +4436,6 @@ func TestRESTTwoReportSubReqAndSubDelOk(t *testing.T) { mainCtrl.VerifyCounterValues(t) } -/* func TestRESTTwoReportSubReqAndSubDelOkNoActParams(t *testing.T) { subReqCount := 2 @@ -4471,8 +4471,7 @@ func TestRESTTwoReportSubReqAndSubDelOkNoActParams(t *testing.T) { mainCtrl.VerifyCounterValues(t) } -*/ -/* + func TestRESTFullAmountReportSubReqAndSubDelOk(t *testing.T) { subReqCount := 19 @@ -4508,7 +4507,6 @@ func TestRESTFullAmountReportSubReqAndSubDelOk(t *testing.T) { mainCtrl.VerifyCounterValues(t) } -*/ func TestRESTSubReqReportSameActionDiffEventTriggerDefinitionLen(t *testing.T) { CaseBegin("TestRESTSubReqReportSameActionDiffEventTriggerDefinitionLen") diff --git a/pkg/teststube2ap/stubE2.go b/pkg/teststube2ap/stubE2.go index 5604393..bcc6aae 100644 --- a/pkg/teststube2ap/stubE2.go +++ b/pkg/teststube2ap/stubE2.go @@ -631,7 +631,11 @@ func (tc *E2Stub) SendSubsDelFail(t *testing.T, req *e2ap.E2APSubscriptionDelete // Callback handler for subscription response notifications //----------------------------------------------------------------------------- func (tc *E2Stub) SubscriptionRespHandler(resp *clientmodel.SubscriptionResponse) { - if tc.subscriptionId == *resp.SubscriptionID { + if tc.subscriptionId == "SUBSCRIPTIONID NOT SET" { + tc.Info("REST notification received for %v while no SubscriptionID was not set for InstanceID=%v, RequestorID=%v (%v)", + *resp.SubscriptionID, *resp.SubscriptionInstances[0].InstanceID, *resp.SubscriptionInstances[0].RequestorID, tc) + tc.CallBackNotification <- *resp.SubscriptionInstances[0].InstanceID + } else if tc.subscriptionId == *resp.SubscriptionID { tc.Info("REST notification received SubscriptionID=%s, InstanceID=%v, RequestorID=%v (%v)", *resp.SubscriptionID, *resp.SubscriptionInstances[0].InstanceID, *resp.SubscriptionInstances[0].RequestorID, tc) tc.CallBackNotification <- *resp.SubscriptionInstances[0].InstanceID @@ -771,6 +775,8 @@ func (tc *E2Stub) SendRESTSubsReq(t *testing.T, params *RESTSubsReqParams) strin return "" } + tc.subscriptionId = "SUBSCIPTIONID NOT SET" + resp, err := xapp.Subscription.Subscribe(¶ms.SubsReqParams) if err != nil { // Swagger generated code makes checks for the values that are inserted the subscription function diff --git a/test/config-file.json b/test/config-file.json index df0beeb..93dd1cd 100644 --- a/test/config-file.json +++ b/test/config-file.json @@ -28,6 +28,7 @@ "e2tRecvMsgTimeout_ms": 2000, "e2tMaxSubReqTryCount": 2, "e2tMaxSubDelReqTryCount": 2, + "waitRouteCleanup_ms": 100, "readSubsFromDb": "true", "subscription": { "host": "localhost:8088", -- 2.16.6