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

tail build logs into build object #15181

Merged
merged 1 commit into from
Jul 16, 2017
Merged

Conversation

bparees
Copy link
Contributor

@bparees bparees commented Jul 13, 2017

Adds the last 5 lines of the build log to the build object, when the build pod reports failure.

@bparees bparees force-pushed the build_logs branch 3 times, most recently from 74bb541 to 7c7096c Compare July 13, 2017 04:37
@bparees
Copy link
Contributor Author

bparees commented Jul 13, 2017

[test]

@bparees
Copy link
Contributor Author

bparees commented Jul 13, 2017

[testextended][extended:core(builds)]

@bparees bparees changed the title tail build logs into build object [DO_NOT_MERGE] tail build logs into build object Jul 13, 2017
@bparees
Copy link
Contributor Author

bparees commented Jul 13, 2017

/cc @smarterclayton

@bparees
Copy link
Contributor Author

bparees commented Jul 13, 2017

@smarterclayton do you want the LogTail output to be part of describe for a build?

@bparees bparees force-pushed the build_logs branch 2 times, most recently from 8e03545 to b94d9f5 Compare July 13, 2017 13:54
@bparees
Copy link
Contributor Author

bparees commented Jul 13, 2017

(added LogTail to describer output)

@bparees
Copy link
Contributor Author

bparees commented Jul 13, 2017

@openshift/devex ptal

@bparees bparees changed the title [DO_NOT_MERGE] tail build logs into build object tail build logs into build object Jul 13, 2017
@bparees
Copy link
Contributor Author

bparees commented Jul 13, 2017

also @smarterclayton this is going to be something else that will be broken/annoying when we move to init containers....

@bparees
Copy link
Contributor Author

bparees commented Jul 13, 2017

flake #10773
flake #12072
[test]

@@ -304,6 +304,9 @@ type BuildStatus struct {
// including start time, duration (in milliseconds), and the steps that
// occured within each stage.
Stages []StageInfo

// LogTail is the last few lines of the build log. This value is only set for builds that failed.
LogTail *string
Copy link
Contributor

Choose a reason for hiding this comment

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

discussed with jordan, let's call this excerpt or outputExcerpt. No guarantee there is a log. Also, not a pointer to string, just do omit empty and a normal string. Pointer to string for this sort of field is not necessary.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

ok. also @csrwng suggested truncating the beginning instead of the end of the line, thoughts on that? I tend to agree the end might contain the more useful information (vs the timestamp at the beginning).

@openshift openshift deleted a comment from openshift-bot Jul 13, 2017
@openshift openshift deleted a comment from openshift-bot Jul 13, 2017
@smarterclayton
Copy link
Contributor

smarterclayton commented Jul 13, 2017 via email

@bparees
Copy link
Contributor Author

bparees commented Jul 13, 2017

Hrm, the beginning gets ragged too. Would probably middle elide, and we can go to 120 char or something

yeah i considered the ragged beginning problem too. middle it is. (compromise!)

middle := len(line) / 2
excess := (len(line) - 117) / 2
excerpt[i] = line[0:middle-excess] + "..." + line[middle+excess:]
}
Copy link
Contributor Author

Choose a reason for hiding this comment

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

this was fun to write but someone please check my work.

Copy link
Contributor

Choose a reason for hiding this comment

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

just excerpt[i] = line[:58] + "..." + line[len(line)-59:] ?

@bparees
Copy link
Contributor Author

bparees commented Jul 13, 2017

flake #15024

@@ -258,15 +259,19 @@ func shouldIgnore(build *buildapi.Build) bool {
}

// If a build is in a terminal state, ignore it; unless it is in a succeeded or failed
// state and its completion time is not set, then we should at least attempt to set its
// completion time if possible.
// state and its completion time or outputexcerpt is not set, then we should at least attempt to set its
Copy link
Contributor

Choose a reason for hiding this comment

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

Is it actually the case that we enter here twice, once on becoming aware that the build has failed and a second time when the excerpt text becomes available? (and that the order of those events is not reliable?)

If that's not the case (which I hope), then to avoid complicating matters, if possible I think we should keep the gating condition as simple as possible - e.g. build.Status.CompletionTimestamp == nil only - and the controller should set the OutputExcerpt as part of the update that sets CompletionTimestamp.

I would very much like to see the builder pod no longer updating Status.Phase, so that we can factor out this special case - avoiding complicating it in the meantime is a plus.

msg := pod.Status.ContainerStatuses[0].State.Terminated.Message
if len(msg) != 0 {
parts := strings.Split(msg, "\n")
// 6 will get us 5 lines because the last entry in parts is an empty string.
Copy link
Contributor

Choose a reason for hiding this comment

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

well, if the message is \n-terminated, that is - could do strings.Split(strings.TrimRight(msg, "\n"), "\n")

if len(msg) != 0 {
parts := strings.Split(msg, "\n")
// 6 will get us 5 lines because the last entry in parts is an empty string.
excerptLength := 6
Copy link
Contributor

Choose a reason for hiding this comment

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

I think 6 (or whatever) should be a named const.

middle := len(line) / 2
excess := (len(line) - 117) / 2
excerpt[i] = line[0:middle-excess] + "..." + line[middle+excess:]
}
Copy link
Contributor

Choose a reason for hiding this comment

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

just excerpt[i] = line[:58] + "..." + line[len(line)-59:] ?

if pod != nil && len(pod.Status.ContainerStatuses) != 0 && pod.Status.ContainerStatuses[0].State.Terminated != nil {
msg := pod.Status.ContainerStatuses[0].State.Terminated.Message
if len(msg) != 0 {
parts := strings.Split(msg, "\n")
Copy link
Contributor

Choose a reason for hiding this comment

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

I think this is a little on the baroque side. In our case Message is already bounded to min(2KB, 80 lines) (see readLastStringFromContainerLogs). Surely doing nothing more, or snipping the last n bytes or lines will do?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Since this is going to end up in the web console, we need it more cleaned up than what is already being done. Ensuring we have full lines (no starting in the middle of a line) is important in terms of confusing users, i think.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

(and 80 lines is going to be too much)

@bparees
Copy link
Contributor Author

bparees commented Jul 14, 2017

just excerpt[i] = line[:58] + "..." + line[len(line)-59:] ?

i knew there's a reason we keep you around... :)

updated.

@bparees
Copy link
Contributor Author

bparees commented Jul 14, 2017

(and i forgot to do it in a separate commit, sorry. habits.)

Copy link
Contributor

@smarterclayton smarterclayton left a comment

Choose a reason for hiding this comment

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

A few minor things then lgtm and API approved

@@ -90,6 +90,9 @@ const (
// if the buildconfig does not specify a value. This only applies to buildconfigs created
// via the new group api resource, not the legacy resource.
DefaultFailedBuildsHistoryLimit = int32(5)

// ExcerptLength is the maximum length of the LogSnippet on a build.
ExcerptLength = 5
Copy link
Contributor

Choose a reason for hiding this comment

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

I don't really like this as a constant that people depend on. Would just hide it in the build controller code

@@ -834,4 +837,25 @@ func setBuildCompletionTimestampAndDuration(build *buildapi.Build, podStartTime
update.setStartTime(*startTime)
}
update.setDuration(now.Rfc3339Copy().Time.Sub(startTime.Rfc3339Copy().Time))

if pod != nil && len(pod.Status.ContainerStatuses) != 0 && pod.Status.ContainerStatuses[0].State.Terminated != nil {
Copy link
Contributor

Choose a reason for hiding this comment

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

Better way for identifying which container status to grab in the future, fine now

@bparees
Copy link
Contributor Author

bparees commented Jul 15, 2017

constant moved, case lowered.

@smarterclayton
Copy link
Contributor

Regen open API (use make update-api) squash and I'll do a final pass and tag

@bparees
Copy link
Contributor Author

bparees commented Jul 15, 2017

@smarterclayton done

@smarterclayton
Copy link
Contributor

[merge]

@bparees
Copy link
Contributor Author

bparees commented Jul 15, 2017 via email

@smarterclayton
Copy link
Contributor

Verify is still failing

@bparees
Copy link
Contributor Author

bparees commented Jul 16, 2017

weird, i ran a full make update. running hack/update-generated-swagger-spec.sh seems to have picked up the change now though. maybe a generating/compiling order of operations issue?

@openshift-bot
Copy link
Contributor

Evaluated for origin testextended up to d2d4121

@openshift-bot
Copy link
Contributor

continuous-integration/openshift-jenkins/testextended Running (https://ci.openshift.redhat.com/jenkins/job/test_pull_request_origin_extended/857/) (Base Commit: 9dd6aa8) (PR Branch Commit: d2d4121) (Extended Tests: core(builds))

@openshift-bot
Copy link
Contributor

Evaluated for origin test up to d2d4121

@openshift-bot
Copy link
Contributor

continuous-integration/openshift-jenkins/test SUCCESS (https://ci.openshift.redhat.com/jenkins/job/test_pull_request_origin/3187/) (Base Commit: 9dd6aa8) (PR Branch Commit: d2d4121)

@openshift-bot
Copy link
Contributor

openshift-bot commented Jul 16, 2017

continuous-integration/openshift-jenkins/merge Waiting: You are in the build queue at position: 1

@bparees
Copy link
Contributor Author

bparees commented Jul 16, 2017

flake #13977
[merge]

@openshift-bot
Copy link
Contributor

Evaluated for origin merge up to d2d4121

@openshift-bot openshift-bot merged commit 41ac679 into openshift:master Jul 16, 2017
@bparees bparees deleted the build_logs branch July 19, 2017 02:16
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

4 participants