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 pluggable Logger for pipeline #262

Merged
merged 28 commits into from Apr 7, 2019

Conversation

@bobheadxi
Copy link
Contributor

commented Mar 28, 2019

closes #244

This PR allows something like the following: (edit no longer possible as of c92aaac - a wrapper needs to be written around zap)

package hercules_test

import (
	"go.uber.org/zap"
	gogit "gopkg.in/src-d/go-git.v4"
	"gopkg.in/src-d/hercules.v10"
)

func main() {
	repo, _ := gogit.PlainOpen(".")
	pipe := hercules.NewPipeline(repo)
	pipe.Initialize(map[string]interface{}{
                // custom logger
		hercules.ConfigLogger: zap.NewExample().Sugar(),
	})
}

I've added a Logger and Config variable for facts in package internal/core, and also added the logger to all pipeline items and replaced the log calls that i could find.

There are still a few calls to panic that I think we should try to remove in favour of error, but I noticed some tests actually assert that panics occur so I've tried not to change too much for now (notably BurndownAnalysis)

bobheadxi added 11 commits Mar 27, 2019
Signed-off-by: Robert Lin <robertlin1@gmail.com>
Signed-off-by: Robert Lin <robertlin1@gmail.com>
Signed-off-by: Robert Lin <robertlin1@gmail.com>
Signed-off-by: Robert Lin <robertlin1@gmail.com>
Signed-off-by: Robert Lin <robertlin1@gmail.com>
Signed-off-by: Robert Lin <robertlin1@gmail.com>
Signed-off-by: Robert Lin <robertlin1@gmail.com>
Signed-off-by: Robert Lin <robertlin1@gmail.com>
Signed-off-by: Robert Lin <robertlin1@gmail.com>
Signed-off-by: Robert Lin <robertlin1@gmail.com>
@bobheadxi bobheadxi force-pushed the bobheadxi:master branch from 0ae682d to 54d4796 Mar 28, 2019
@bobheadxi

This comment has been minimized.

Copy link
Contributor Author

commented Mar 29, 2019

@vmarkovtsev there appears to be an issue with labours even though nothing outward-facing has changed with this PR - do you have any ideas as to why this might be happening?

https://travis-ci.com/src-d/hercules/jobs/188673981#L2785

@vmarkovtsev

This comment has been minimized.

Copy link
Contributor

commented Mar 29, 2019

Yes, the problem is with Google's ortools, which is a dependency of seriate, which is a dependency of labours. They released v7 on March 26th which is not backward compatible, and I did not specify the upper version constraint in seriate. Fixing this now.

Signed-off-by: Robert Lin <robertlin1@gmail.com>
@bobheadxi bobheadxi force-pushed the bobheadxi:master branch from 54d4796 to e061508 Mar 29, 2019
Signed-off-by: Robert Lin <robertlin1@gmail.com>
@bobheadxi bobheadxi force-pushed the bobheadxi:master branch from 1b41cfd to 6462eb6 Mar 29, 2019
@bobheadxi

This comment has been minimized.

Copy link
Contributor Author

commented Mar 29, 2019

Thanks @vmarkovtsev looks like the build is passing now!

@vmarkovtsev

This comment has been minimized.

Copy link
Contributor

commented Mar 30, 2019

Reviewing this tomorrow 👍

Copy link
Contributor

left a comment

👍

cmd/hercules/plugin.template Outdated Show resolved Hide resolved
cmd/hercules/plugin.template Outdated Show resolved Hide resolved
internal/core/logger.go Outdated Show resolved Hide resolved
internal/core/logger.go Outdated Show resolved Hide resolved
internal/core/logger.go Outdated Show resolved Hide resolved
internal/plumbing/ticks.go Show resolved Hide resolved
internal/plumbing/tree_diff.go Outdated Show resolved Hide resolved
leaves/couples.go Outdated Show resolved Hide resolved
leaves/research/typos.go Outdated Show resolved Hide resolved
leaves/research/typos.go Outdated Show resolved Hide resolved
@bobheadxi

This comment has been minimized.

Copy link
Contributor Author

commented Mar 31, 2019

@vmarkovtsev real bugs should still propagate errors upwards for the caller to deal with - for example, using Hercules as a library in a web service, a user would definitely not want a fatal crash every time, but instead log and handle it safely, or at least get the chance to gracefully stop all connections before crashing. If it’s a service with state and buffers that needs to be written to disk, for example, a panic has a real danger of causing those things to be lost

@bobheadxi

This comment has been minimized.

Copy link
Contributor Author

commented Mar 31, 2019

If done right, returning errors will do the same thing as panic, since it’ll return up to the caller (for example, the Hercules command) and a panic can be done there, or simply exit with 1. Logger can be configured to capture stacktraces no errors as well

@vmarkovtsev

This comment has been minimized.

Copy link
Contributor

commented Mar 31, 2019

This is the thing, the places which I marked (I did not mark everything) are assertions which should never happen. The same as C++ assert or accessing a slice element out of bounds. If Go had macros, these would be disabled at all in the release build.

@bobheadxi

This comment has been minimized.

Copy link
Contributor Author

commented Mar 31, 2019

Hm... even then I believe it still better to propagate it properly, since sometimes unrelated things can cause certain impossibilities to happen, even if it doesn’t seem like it (at least it seems to be what happened here: #234 (comment))

Also feels good for the sake of consistency - out of bounds is one thing, but an unexpected invariant change feels like it should be returned properly at least based on what I understand of Go best practices, for the cases I mentioned earlier (in the event something goes wrong, even if it’s probably impossible, you want to give the caller the chance to clean up properly after itself, which could be critical - a panic interrupting a database write is less than pleasant)

If you feel strongly about keeping the panics I suppose I can change them back, but I would personally strongly recommend moving towards reducing the panics in the library component of Hercules (would be very helpful for me 😅)

@vmarkovtsev

This comment has been minimized.

Copy link
Contributor

commented Mar 31, 2019

Regarding catching panics in a lib, there is always recover() at your service.

@vmarkovtsev

This comment has been minimized.

Copy link
Contributor

commented Mar 31, 2019

I know your pain, I used to suffer the same way when I used enry to detect languages, and it used to be very buggy and paniced all the time when used concurrently. After all, I could report proper panic stack traces to the maintainers, and they were able to fix problems very fast. I do understand that we can change those logging calls to include stack traces. If you know how to do it (print a fancy stack trace when a 🐛 appears), to me it is the same as panicking. So I am fine with that actually.

@bobheadxi

This comment has been minimized.

Copy link
Contributor Author

commented Mar 31, 2019

Thanks! I actually did not consider recover at all, so thank you for pointing that out. I’ll look into both solutions (log stacktrace + return error vs panic) and see might be best for these cases, and make the necessary changes. I’ll apply fixes for your other comments as well.

Thanks for the review!

bobheadxi added 7 commits Apr 1, 2019
Signed-off-by: Robert Lin <robertlin1@gmail.com>
Signed-off-by: Robert Lin <robertlin1@gmail.com>
Signed-off-by: Robert Lin <robertlin1@gmail.com>
Signed-off-by: Robert Lin <robertlin1@gmail.com>
Signed-off-by: Robert Lin <robertlin1@gmail.com>
Signed-off-by: Robert Lin <robertlin1@gmail.com>
Signed-off-by: Robert Lin <robertlin1@gmail.com>
@bobheadxi bobheadxi force-pushed the bobheadxi:master branch from ade3fb1 to 71bc8fc Apr 2, 2019
@bobheadxi

This comment has been minimized.

Copy link
Contributor Author

commented Apr 2, 2019

@vmarkovtsev I've added a stacktrace capture to all calls to Error and Errorf. The output looks like this:

[ERROR] 2019/04/01 17:12:39 hello-world
[ERROR] 2019/04/01 17:12:39 stacktrace:
gopkg.in/src-d/hercules.v10/internal/core.TestLogger(0xc000178300)
	/Users/robertlin/go/src/gopkg.in/src-d/hercules.v10/internal/core/logger_test.go:50 +0xbf4
testing.tRunner(0xc000178300, 0x170a140)
	/usr/local/Cellar/go/1.12/libexec/src/testing/testing.go:865 +0xc0
created by testing.(*T).Run
	/usr/local/Cellar/go/1.12/libexec/src/testing/testing.go:916 +0x357

does that look okay to you?

bobheadxi added 3 commits Apr 2, 2019
Signed-off-by: Robert Lin <robertlin1@gmail.com>
Signed-off-by: Robert Lin <robertlin1@gmail.com>
Signed-off-by: Robert Lin <robertlin1@gmail.com>
@vmarkovtsev

This comment has been minimized.

Copy link
Contributor

commented Apr 2, 2019

Yep, but let's make a separate level for such logs, e.g. "critical" or "fatal".

@bobheadxi

This comment has been minimized.

Copy link
Contributor Author

commented Apr 2, 2019

Hm, is there a particular reason why? My thoughts:

  • adding Critical() breaks drop-in compatibility with many popular loggers (notably zap and logrus)
  • adding Fatal() means we either follow standard behaviour of calling os.Exit, which means we're back to panic-like behaviour, or not calling os.Exit and introducing a behavioural inconsistency with popular loggers (zap, logrus, standard library all exit on Fatal)

Another thought: zap, by default, captures stacktraces on Error-level logs and above, so capturing stacktraces on Error() isn't out of the ordinary:

https://github.com/uber-go/zap/blob/master/config.go#L67

	// DisableStacktrace completely disables automatic stacktrace capturing. By
	// default, stacktraces are captured for WarnLevel and above logs in
	// development and ErrorLevel and above in production.
	DisableStacktrace bool `json:"disableStacktrace" yaml:"disableStacktrace"`

Besides, a stacktrace should be interesting for all instances of l.Error right? Would be interested in hearing your thoughts on this

@vmarkovtsev

This comment has been minimized.

Copy link
Contributor

commented Apr 2, 2019

Most of the errors do not require printing the trace and the log will be dumped otherwise.

@bobheadxi

This comment has been minimized.

Copy link
Contributor Author

commented Apr 2, 2019

I've added Critical etc in c92aaac

Signed-off-by: Robert Lin <robertlin1@gmail.com>
@bobheadxi bobheadxi force-pushed the bobheadxi:master branch from 2345fe7 to c92aaac Apr 2, 2019
Copy link
Contributor

left a comment

This LGTM. However, our coverage has dropped by 0.5%, which is quite big. Sometimes it happens randomly, but we should check if there are pending tests which we should add.

@bobheadxi

This comment has been minimized.

Copy link
Contributor Author

commented Apr 7, 2019

I've added some additional tests in 6d09c8d

some drops are caused by the panic removals, where I've added a log and a return (example, example), I don't think these are really testable

Signed-off-by: Robert Lin <robertlin1@gmail.com>
@bobheadxi bobheadxi force-pushed the bobheadxi:master branch from daba29a to 6d09c8d Apr 7, 2019
@vmarkovtsev vmarkovtsev merged commit a4d2b46 into src-d:master Apr 7, 2019
3 of 4 checks passed
3 of 4 checks passed
codecov/project 85.71% (-0.04%) compared to 4a50675
Details
DCO DCO
Details
Travis CI - Pull Request Build Passed
Details
continuous-integration/appveyor/pr AppVeyor build succeeded
Details
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
2 participants
You can’t perform that action at this time.