Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add logs for debugging #36

Merged
merged 11 commits into from
Sep 6, 2022
Merged

Add logs for debugging #36

merged 11 commits into from
Sep 6, 2022

Conversation

godrei
Copy link
Contributor

@godrei godrei commented Sep 5, 2022

Checklist

  • I've read and followed the Contribution Guidelines
  • step.yml and README.md is updated with the changes (if needed)

Version

Requires a MINOR version update

Context

A significant build time difference was observed between the actual UI test time within Firebase TestLab and the step run time.

This PR adds additional logs to the step to make it clear which process causes the time difference.

Changes

Functional changes:

  • Add timestamp to the major tasks' logs
  • Calculate and print an approximant time spent on different steps and status
    • status durations are approximate intervals because testresult.Step is not exposing the start time of different states, to overcome this, the step stores the time when first seeing the given state

Non-functional changes:

  • make up for the missing DownloadTestResults step input printing

Investigation details

Decisions

@godrei godrei marked this pull request as ready for review September 5, 2022 14:19
main.go Outdated

duration := endTime.Sub(startTime)

if _, err := fmt.Fprintf(w, "- time spent in %s state: ~%ds\n", state, duration/time.Second); err != nil {
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

NOTE: You can use duration.Round(), see https://pkg.go.dev/time#Duration.Round/.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

updated in: a84e948

lpusok
lpusok previously approved these changes Sep 6, 2022
main.go Outdated
return fmt.Sprintf("%s (%s %s %s %s)", step.Name, dimensions["Model"], dimensions["Version"], dimensions["Orientation"], dimensions["Locale"])
}

func updateStepsStatesToStartTime(stepsStatesToStartTime map[string]map[string]time.Time, stepsToNames map[string]string, response toolresults.ListStepsResponse) {
Copy link
Contributor

@tothszabi tothszabi Sep 6, 2022

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why are the step names separated from the states and timings? I think it made it a bit harder to understand for me.

We could move them into an internal struct and have something like

type internalStepData struct {
	name           string
	stateAndTiming map[string]time.Time
}

func (i *internalStepData) saveState(state string, startTime time.Time) {
	if _, ok := i.stateAndTiming[state]; ok {
		return
	}

	// Haven't seen this state yet -> set state start time
	i.stateAndTiming[state] = startTime
}

func newInternalStepData(step toolresults.Step) internalStepData {
	return internalStepData{
		name:           createStepNameWithDimensions(step),
		stateAndTiming: map[string]time.Time{},
	}
}

func updateStepsStatesToStartTime2(steps map[string]internalStepData, response toolresults.ListStepsResponse) {
	for _, step := range response.Steps {
		data, ok := steps[step.StepId]
		if !ok {
			data = newInternalStepData(*step)
			steps[step.StepId] = data
		}

		data. saveState(step.State, time.Now())
	}
}

and then also the time calculation could be moved into this internal struct. Probably other functions can be created as well so you might not need to understand so many things upfront. 😄

But it also good as it is. It just my first impression.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Updated in b438236 and 5487a88

lpusok
lpusok previously approved these changes Sep 6, 2022
@godrei godrei merged commit a30f92e into master Sep 6, 2022
@godrei godrei deleted the debug_logs branch September 6, 2022 13:12
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants