diff --git a/boomer.go b/boomer.go index cfcd096e..549725d9 100644 --- a/boomer.go +++ b/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, - Weight: testcase.Config.ToStruct().Weight, + Name: config.Name, + 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) + } + } }, } } diff --git a/models.go b/models.go index 5b840044..37724839 100644 --- a/models.go +++ b/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"` - Type string `json:"type" yaml:"type"` // start/end + Name string `json:"name" yaml:"name"` + 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 } diff --git a/runner.go b/runner.go index 6da62281..04fcb912 100644 --- a/runner.go +++ b/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 - log.Info(). - Str("name", stepTran.step.Transaction.Name). - Str("type", stepTran.step.Transaction.Type). - Msg("transaction") - return nil, nil + // transaction step + return r.runStepTransaction(stepTran.step.Transaction) } else if stepRend, ok := step.(*StepRendezvous); ok { - // rendezvous - log.Info(). - 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 + // rendezvous step + return r.runStepRendezvous(stepRend.step.Rendezvous) } 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, - success: false, + name: step.Name, + 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 {