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

Sending live loader error output to Stderr #3560

Merged
merged 5 commits into from
Jun 28, 2019
Merged

Sending live loader error output to Stderr #3560

merged 5 commits into from
Jun 28, 2019

Conversation

gitlw
Copy link

@gitlw gitlw commented Jun 14, 2019

This change is Reviewable

@gitlw gitlw requested review from manishrjain and a team as code owners June 14, 2019 20:51
Copy link
Contributor

@martinmr martinmr left a comment

Choose a reason for hiding this comment

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

:lgtm:

Reviewed 1 of 1 files at r1.
Reviewable status: :shipit: complete! all files reviewed, all discussions resolved (waiting on @manishrjain)

Copy link
Contributor

@danielmai danielmai left a comment

Choose a reason for hiding this comment

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

Should these error logs go in a more verbose log level? Knowing which particular txn got aborted/retried is useful for debugging, but not in general when all you want to do is load data. These abort logs overwhelm the typical 5-second log informational log.

Reviewed 1 of 1 files at r1.
Reviewable status: all files reviewed, 1 unresolved discussion (waiting on @gitlw and @manishrjain)


dgraph/cmd/live/batch.go, line 125 at r1 (raw file):

		time.Sleep(dur)
	case err != y.ErrConflict:
		errLog.Printf("Error while mutating: %v\n", s.Message())

When running live loader this error message looks like this:

Error while mutating: Transaction has been aborted. Please retry.

Showing "Please retry" for live loading isn't helpful. Live loader will retry already on behalf of the user.

This particular error message isn't technically an "error" with live loader anyway. This should be handled by live loader.

Copy link
Author

@gitlw gitlw left a comment

Choose a reason for hiding this comment

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

Reviewable status: all files reviewed, 1 unresolved discussion (waiting on @danielmai and @manishrjain)


dgraph/cmd/live/batch.go, line 125 at r1 (raw file):

Previously, danielmai (Daniel Mai) wrote…

When running live loader this error message looks like this:

Error while mutating: Transaction has been aborted. Please retry.

Showing "Please retry" for live loading isn't helpful. Live loader will retry already on behalf of the user.

This particular error message isn't technically an "error" with live loader anyway. This should be handled by live loader.

I agree. So how about we add a -v flag to indicate whether these log lines should be shown?

@danielmai
Copy link
Contributor


dgraph/cmd/live/batch.go, line 125 at r1 (raw file):

Previously, gitlw (Lucas Wang) wrote…

I agree. So how about we add a -v flag to indicate whether these log lines should be shown?

Live loader already has -v as a global flag with glog around, and we make a deliberate choice to not use glog with tools like live loader. It makes it more confusing, but we could have a different flag to configure log verbosity for this.

Copy link
Contributor

@danielmai danielmai left a comment

Choose a reason for hiding this comment

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

Reviewed 2 of 2 files at r2.
Reviewable status: all files reviewed, 2 unresolved discussions (waiting on @gitlw and @manishrjain)


dgraph/cmd/live/batch.go, line 125 at r1 (raw file):

This should be handled by live loader.

What I meant by the above is that we don't need to print out transaction abort errors since they can happen with live loader and concurrent mutations. Live loader will retry and it's ok. The user will see the "Aborts:" counter go up, and no action by them is needed for temporary aborts. However, there can be other errors during mutations like invalid input formats that the user should know about, meaning this shouldn't be behind the verbose flag.

In v1.0.15 live loader handles the y.ErrAborted case. We can revert this line from this change to bring back this behavior: f314b3f#diff-b6f7fdc77028b083a4d14d4fb14aa431L139.


dgraph/cmd/live/batch.go, line 119 at r2 (raw file):

		dur := time.Duration(1+rand.Intn(10)) * time.Minute
		if opt.verbose {
			fmt.Printf("Server is overloaded. Will retry after %s.\n", dur.Round(time.Minute))

The "transaction abort" logs can be behind the verbose flag. The server being overloaded would be important for the user to know about and shouldn't be part of verbose.

Copy link
Author

@gitlw gitlw left a comment

Choose a reason for hiding this comment

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

Reviewable status: 1 of 2 files reviewed, 2 unresolved discussions (waiting on @danielmai, @gitlw, and @manishrjain)


dgraph/cmd/live/batch.go, line 125 at r1 (raw file):

Previously, danielmai (Daniel Mai) wrote…

This should be handled by live loader.

What I meant by the above is that we don't need to print out transaction abort errors since they can happen with live loader and concurrent mutations. Live loader will retry and it's ok. The user will see the "Aborts:" counter go up, and no action by them is needed for temporary aborts. However, there can be other errors during mutations like invalid input formats that the user should know about, meaning this shouldn't be behind the verbose flag.

In v1.0.15 live loader handles the y.ErrAborted case. We can revert this line from this change to bring back this behavior: f314b3f#diff-b6f7fdc77028b083a4d14d4fb14aa431L139.

Ok, I changed it so that the "server overloaded" and other types of errors would still be shown even without the verbose flag.

Regarding the y.ErrAborted case, that PR added the "case s.Code() == codes.Aborted:" check, which should handle the aborted txns, so I think the current logic looks fine.

Copy link
Contributor

@danielmai danielmai left a comment

Choose a reason for hiding this comment

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

Given these latest changes, does this PR still intend to output to stderr? Or was the main goal to surpress some logs, in which case the log verbosity flag does that.

Reviewed 1 of 1 files at r3.
Reviewable status: all files reviewed, 1 unresolved discussion (waiting on @gitlw and @manishrjain)


dgraph/cmd/live/batch.go, line 125 at r1 (raw file):

Regarding the y.ErrAborted case, that PR added the "case s.Code() == codes.Aborted:" check, which should handle the aborted txns, so I think the current logic looks fine.

It doesn't handle aborted txns. I see Error while mutating: Transaction has been aborted. Please retry. when I run live loader today. Do you see the same?

AFAIK codes.Aborted is for gRPC-aborted messages, not Dgraph-txn-aborted messages.

@manishrjain
Copy link
Contributor

Is this being worked on? Or, can be closed?

Copy link
Author

@gitlw gitlw left a comment

Choose a reason for hiding this comment

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

Reviewable status: 0 of 2 files reviewed, 1 unresolved discussion (waiting on @danielmai and @manishrjain)


dgraph/cmd/live/batch.go, line 125 at r1 (raw file):

Previously, danielmai (Daniel Mai) wrote…

Regarding the y.ErrAborted case, that PR added the "case s.Code() == codes.Aborted:" check, which should handle the aborted txns, so I think the current logic looks fine.

It doesn't handle aborted txns. I see Error while mutating: Transaction has been aborted. Please retry. when I run live loader today. Do you see the same?

AFAIK codes.Aborted is for gRPC-aborted messages, not Dgraph-txn-aborted messages.

You are right, I've added checking for ErrAborted and reverted to the initial behavior, which is not logging for ErrAborted.

Copy link
Author

@gitlw gitlw left a comment

Choose a reason for hiding this comment

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

@danielmai The purpose is to suppress the excessive logs. With the verbose flag, there is no need to redirect to stderr anymore.

Reviewable status: 0 of 2 files reviewed, 1 unresolved discussion (waiting on @danielmai and @manishrjain)

Copy link
Contributor

@danielmai danielmai left a comment

Choose a reason for hiding this comment

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

:lgtm:

Reviewed 2 of 2 files at r4.
Reviewable status: all files reviewed, 1 unresolved discussion (waiting on @danielmai and @manishrjain)

@gitlw gitlw merged commit 47496ed into master Jun 28, 2019
@gitlw gitlw deleted the gitlw/live_loader branch June 28, 2019 20:54
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Development

Successfully merging this pull request may close these issues.

4 participants