feat: load test with transactions

boomer.go

@@ -56,22 +56,49 @@ func (b *hrpBoomer) Quit() {
 }
 
 func (b *hrpBoomer) convertBoomerTask(testcase *TestCase) *boomer.Task {
+	config := testcase.Config.ToStruct()
 	return &boomer.Task{
-		Name:   testcase.Config.ToStruct().Name,
+		Name:   config.Name,
-		Weight: testcase.Config.ToStruct().Weight,
+		Weight: config.Weight,
 		Fn: func() {
-			runner := NewRunner(nil).SetDebug(b.debug)
+			runner := NewRunner(nil).SetDebug(b.debug).Reset()
 			for _, step := range testcase.TestSteps {
-				var err error
-				start := time.Now()
 				stepData, err := runner.runStep(step, testcase.Config)
-				elapsed := time.Since(start).Nanoseconds() / int64(time.Millisecond)
+
+				if stepData.stepType == stepTypeRendezvous {
+					// TODO: implement rendezvous in boomer
+					continue
+				}
+
+				// record transaction
+				if stepData.stepType == stepTypeTransaction {
+					// TODO: implement recording transaction in boomer
+					if stepData.elapsed != 0 {
+						b.RecordSuccess(string(stepTypeTransaction), stepData.name, stepData.elapsed, 0)
+					}
+					continue
+				}
+
 				if err == nil {
-					b.RecordSuccess(step.Type(), step.Name(), elapsed, stepData.responseLength)
+					b.RecordSuccess(step.Type(), step.Name(), stepData.elapsed, stepData.responseLength)
 				} else {
+					var elapsed int64
+					if stepData != nil {
+						elapsed = stepData.elapsed
+					}
 					b.RecordFailure(step.Type(), step.Name(), elapsed, err.Error())
 				}
 			}
+			endTime := time.Now()
+
+			// report duration for transaction without end
+			for name, transaction := range runner.transactions {
+				if len(transaction) == 1 {
+					// if transaction end time not exists, use testcase end time instead
+					duration := endTime.Sub(transaction[TransactionStart])
+					b.RecordSuccess(string(stepTypeTransaction), name, duration.Milliseconds(), 0)
+				}
+			}
 		},
 	}
 }

models.go

@@ -60,9 +60,25 @@ type TStep struct {
 	Export        []string               `json:"export,omitempty" yaml:"export,omitempty"`
 }
 
+type stepType string
+
+const (
+	stepTypeRequest     stepType = "request"
+	stepTypeTestCase    stepType = "testcase"
+	stepTypeTransaction stepType = "transaction"
+	stepTypeRendezvous  stepType = "rendezvous"
+)
+
+type TransactionType string
+
+const (
+	TransactionStart TransactionType = "start"
+	TransactionEnd   TransactionType = "end"
+)
+
 type Transaction struct {
-	Name string `json:"name" yaml:"name"`
+	Name string          `json:"name" yaml:"name"`
-	Type string `json:"type" yaml:"type"` // start/end
+	Type TransactionType `json:"type" yaml:"type"`
 }
 type Rendezvous struct {
 	Name    string  `json:"name" yaml:"name"`                           // required
@@ -127,7 +143,9 @@ type testCaseSummary struct{}
 
 type stepData struct {
 	name           string                 // step name
+	stepType       stepType               // step type, testcase/request/transaction/rendezvous
 	success        bool                   // step execution result
+	elapsed        int64                  // step execution time in millisecond(ms)
 	responseLength int64                  // response body length
 	exportVars     map[string]interface{} // extract variables
 }

runner.go

@@ -49,6 +49,19 @@ type hrpRunner struct {
 	debug            bool
 	client           *http.Client
 	sessionVariables map[string]interface{}
+	// transactions stores transaction timing info.
+	// key is transaction name, value is map of transaction type and time, e.g. start time and end time.
+	transactions map[string]map[TransactionType]time.Time
+	startTime    time.Time // record start time of the testcase
+}
+
+// Reset clears runner session variables.
+func (r *hrpRunner) Reset() *hrpRunner {
+	log.Info().Msg("[init] Reset session variables")
+	r.sessionVariables = make(map[string]interface{})
+	r.transactions = make(map[string]map[TransactionType]time.Time)
+	r.startTime = time.Now()
+	return r
 }
 
 // SetDebug configures whether to log HTTP request and response content.
@@ -84,6 +97,7 @@ func (r *hrpRunner) Run(testcases ...ITestCase) error {
 	// report execution timing event
 	defer ga.SendEvent(event.StartTiming("execution"))
 
+	r.Reset()
 	for _, iTestCase := range testcases {
 		testcase, err := iTestCase.ToTestCase()
 		if err != nil {
@@ -105,7 +119,7 @@ func (r *hrpRunner) runCase(testcase *TestCase) error {
 	}
 
 	log.Info().Str("testcase", config.Name()).Msg("run testcase start")
-
+	r.startTime = time.Now()
 	for _, step := range testcase.TestSteps {
 		_, err := r.runStep(step, config)
 		if err != nil {
@@ -120,21 +134,11 @@ func (r *hrpRunner) runCase(testcase *TestCase) error {
 func (r *hrpRunner) runStep(step IStep, config IConfig) (stepResult *stepData, err error) {
 	// step type priority order: transaction > rendezvous > testcase > request
 	if stepTran, ok := step.(*StepTransaction); ok {
-		// transaction
+		// transaction step
-		log.Info().
+		return r.runStepTransaction(stepTran.step.Transaction)
-			Str("name", stepTran.step.Transaction.Name).
-			Str("type", stepTran.step.Transaction.Type).
-			Msg("transaction")
-		return nil, nil
 	} else if stepRend, ok := step.(*StepRendezvous); ok {
-		// rendezvous
+		// rendezvous step
-		log.Info().
+		return r.runStepRendezvous(stepRend.step.Rendezvous)
-			Str("name", stepRend.step.Rendezvous.Name).
-			Float32("percent", stepRend.step.Rendezvous.Percent).
-			Int64("number", stepRend.step.Rendezvous.Number).
-			Int64("timeout", stepRend.step.Rendezvous.Timeout).
-			Msg("rendezvous")
-		return nil, nil
 	}
 
 	log.Info().Str("step", step.Name()).Msg("run step start")
@@ -143,7 +147,7 @@ func (r *hrpRunner) runStep(step IStep, config IConfig) (stepResult *stepData, e
 	copiedStep := &TStep{}
 	if err = copier.Copy(copiedStep, step.ToStruct()); err != nil {
 		log.Error().Err(err).Msg("copy step data failed")
-		return
+		return nil, err
 	}
 
 	cfg := config.ToStruct()
@@ -158,10 +162,11 @@ func (r *hrpRunner) runStep(step IStep, config IConfig) (stepResult *stepData, e
 	parsedVariables, err := parseVariables(stepVariables)
 	if err != nil {
 		log.Error().Interface("variables", cfg.Variables).Err(err).Msg("parse step variables failed")
-		return
+		return nil, err
 	}
 	copiedStep.Variables = parsedVariables // avoid data racing
 
+	// step type priority order: testcase > request
 	if _, ok := step.(*StepTestCaseWithOptionalArgs); ok {
 		// run referenced testcase
 		log.Info().Str("testcase", copiedStep.Name).Msg("run referenced testcase")
@@ -191,12 +196,68 @@ func (r *hrpRunner) runStep(step IStep, config IConfig) (stepResult *stepData, e
 		Bool("success", stepResult.success).
 		Interface("exportVars", stepResult.exportVars).
 		Msg("run step end")
-	return
+	return stepResult, nil
+}
+
+func (r *hrpRunner) runStepTransaction(transaction *Transaction) (stepResult *stepData, err error) {
+	log.Info().
+		Str("name", transaction.Name).
+		Str("type", string(transaction.Type)).
+		Msg("transaction")
+
+	stepResult = &stepData{
+		name:     transaction.Name,
+		stepType: stepTypeTransaction,
+		success:  true,
+	}
+
+	// create transaction if not exists
+	if _, ok := r.transactions[transaction.Name]; !ok {
+		r.transactions[transaction.Name] = make(map[TransactionType]time.Time)
+	}
+
+	// record transaction start time, override if already exists
+	if transaction.Type == TransactionStart {
+		r.transactions[transaction.Name][TransactionStart] = time.Now()
+	}
+	// record transaction end time, override if already exists
+	if transaction.Type == TransactionEnd {
+		r.transactions[transaction.Name][TransactionEnd] = time.Now()
+
+		// if transaction start time not exists, use testcase start time instead
+		if _, ok := r.transactions[transaction.Name][TransactionStart]; !ok {
+			r.transactions[transaction.Name][TransactionStart] = r.startTime
+		}
+
+		// calculate transaction duration
+		duration := r.transactions[transaction.Name][TransactionEnd].Sub(
+			r.transactions[transaction.Name][TransactionStart])
+		stepResult.elapsed = duration.Milliseconds()
+		log.Info().Str("name", transaction.Name).Dur("elapsed", duration).Msg("transaction")
+	}
+
+	return stepResult, nil
+}
+
+func (r *hrpRunner) runStepRendezvous(rend *Rendezvous) (stepResult *stepData, err error) {
+	log.Info().
+		Str("name", rend.Name).
+		Float32("percent", rend.Percent).
+		Int64("number", rend.Number).
+		Int64("timeout", rend.Timeout).
+		Msg("rendezvous")
+	stepResult = &stepData{
+		name:     rend.Name,
+		stepType: stepTypeRendezvous,
+		success:  true,
+	}
+	return stepResult, nil
 }
 
 func (r *hrpRunner) runStepRequest(step *TStep) (stepResult *stepData, err error) {
 	stepResult = &stepData{
 		name:           step.Name,
+		stepType:       stepTypeRequest,
 		success:        false,
 		responseLength: 0,
 	}
@@ -316,7 +377,9 @@ func (r *hrpRunner) runStepRequest(step *TStep) (stepResult *stepData, err error
 	}
 
 	// do request action
+	start := time.Now()
 	resp, err := r.client.Do(req)
+	stepResult.elapsed = time.Since(start).Milliseconds()
 	if err != nil {
 		return nil, errors.Wrap(err, "do request failed")
 	}
@@ -356,17 +419,24 @@ func (r *hrpRunner) runStepRequest(step *TStep) (stepResult *stepData, err error
 
 	stepResult.success = true
 	stepResult.responseLength = resp.ContentLength
-	return
+	return stepResult, nil
 }
 
 func (r *hrpRunner) runStepTestCase(step *TStep) (stepResult *stepData, err error) {
 	stepResult = &stepData{
-		name:    step.Name,
+		name:     step.Name,
-		success: false,
+		stepType: stepTypeTestCase,
+		success:  false,
 	}
 	testcase := step.TestCase
+	start := time.Now()
 	err = r.runCase(testcase)
-	return
+	stepResult.elapsed = time.Since(start).Milliseconds()
+	if err != nil {
+		return stepResult, err
+	}
+	stepResult.success = true
+	return stepResult, nil
 }
 
 func (r *hrpRunner) parseConfig(config IConfig) error {