Improve log fields #245

carlosms · 2018-09-10T16:41:10Z

The main change in this PR is that the callbacks with EventHandler accept the context, and keep the log fields like the PR number.

The service/git methods now get the log from the context, but the problem here is that the gRPC requests come from the analyzer, and we don't have the event-id or any other field.
I didn't look much into it, so I don't know if there is a way to pass some ID fields to the analyzer and get them back when they call GetFiles/GetChanges without modifying the proto messages.

Signed-off-by: Carlos Martín <carlos.martin.sanchez@gmail.com>

lookout-bot · 2018-09-10T16:41:28Z

cmd/lookoutd/serve.go

@@ -371,7 +371,7 @@ func (c *ServeCommand) initDB() (*sql.DB, error) {
 				"Use '%s migrate' to upgrade your database", dbVersion, version, build, maxVersion, name)
 	}

-	log.Debugf("the DB version is up to date, %v", dbVersion)
+	log.With(log.Fields{"db-version": dbVersion}).Debugf("the DB version is up to date")


line is 85 characters (lll)

If you have feedback about this comment, please, tell us.

lookout-bot · 2018-09-10T16:41:28Z

provider/github/client.go

@@ -50,10 +52,9 @@ type Client struct {
 }

 // NewClient creates new Client
-func NewClient(t http.RoundTripper, cache *cache.ValidableCache, l log.Logger, watchMinInterval string) *Client {
+func NewClient(t http.RoundTripper, cache *cache.ValidableCache, watchMinInterval string) *Client {


line is 99 characters (lll)

If you have feedback about this comment, please, tell us.

lookout-bot · 2018-09-10T16:41:29Z

provider/github/client.go

@@ -207,7 +207,7 @@ func (t *limitRoundTripper) RoundTrip(req *http.Request) (*http.Response, error)
 	t.rateLimits[category(req.URL.Path)] = rate
 	t.rateMu.Unlock()

-	t.Log.With(logFields).Debugf("http request to %s", req.URL.Path)
+	ctxlog.Get(req.Context()).With(logFields).Debugf("http request to %s", req.URL.Path)


line is 85 characters (lll)

If you have feedback about this comment, please, tell us.

lookout-bot · 2018-09-10T16:41:29Z

provider/github/watcher_test.go

@@ -133,7 +133,7 @@ func (s *WatcherTestSuite) TestWatch_CallbackError_Pull() {
 	s.mux.HandleFunc("/repos/mock/test/events", emptyArrayHandler)

 	w := s.newWatcher([]string{"github.com/mock/test"})
-	err := w.Watch(context.TODO(), func(e lookout.Event) error {
+	err := w.Watch(context.TODO(), func(ctx context.Context, e lookout.Event) error {


line is 82 characters (lll)

If you have feedback about this comment, please, tell us.

lookout-bot · 2018-09-10T16:41:29Z

provider/github/watcher_test.go

@@ -150,7 +150,7 @@ func (s *WatcherTestSuite) TestWatch_CallbackError_Event() {
 	s.mux.HandleFunc("/repos/mock/test/events", eventsHandler(&calls))

 	w := s.newWatcher([]string{"github.com/mock/test"})
-	err := w.Watch(context.TODO(), func(e lookout.Event) error {
+	err := w.Watch(context.TODO(), func(ctx context.Context, e lookout.Event) error {


line is 82 characters (lll)

If you have feedback about this comment, please, tell us.

lookout-bot · 2018-09-10T16:41:30Z

service/git/service.go

@@ -33,8 +32,8 @@ var ErrRefValidation = errors.NewKind("reference %v does not have a %s")

 // validateReferences checks if all the References have enough information to clone a repo.
 // Validation of the reference name is optional.
-func validateReferences(validateRefName bool, refs ...*lookout.ReferencePointer) error {
-	log.Infof("validating refs: %v, validateRefName: %v", refs, validateRefName)
+func validateReferences(ctx context.Context, validateRefName bool, refs ...*lookout.ReferencePointer) error {


line is 109 characters (lll)

If you have feedback about this comment, please, tell us.

lookout-bot · 2018-09-10T16:41:30Z

service/git/service.go

-func validateReferences(validateRefName bool, refs ...*lookout.ReferencePointer) error {
-	log.Infof("validating refs: %v, validateRefName: %v", refs, validateRefName)
+func validateReferences(ctx context.Context, validateRefName bool, refs ...*lookout.ReferencePointer) error {
+	ctxlog.Get(ctx).Infof("validating refs: %v, validateRefName: %v", refs, validateRefName)


line is 89 characters (lll)

If you have feedback about this comment, please, tell us.

lookout-bot · 2018-09-10T16:41:30Z

service/git/syncer.go

@@ -53,7 +53,7 @@ func (s *Syncer) Sync(ctx context.Context,
 		var rs config.RefSpec
 		if "" == rp.ReferenceName {
 			rs = config.RefSpec(fmt.Sprintf(config.DefaultFetchRefSpec, defaultRemoteName))
-			log.Warningf("empty ReferenceName given in %v, using default '%s' instead", rp, rs)
+			ctxlog.Get(ctx).Warningf("empty ReferenceName given in %v, using default '%s' instead", rp, rs)


line is 98 characters (lll)

If you have feedback about this comment, please, tell us.

lookout-bot · 2018-09-10T16:41:30Z

provider/github/watcher_test.go

@@ -133,7 +133,7 @@ func (s *WatcherTestSuite) TestWatch_CallbackError_Pull() {
 	s.mux.HandleFunc("/repos/mock/test/events", emptyArrayHandler)

 	w := s.newWatcher([]string{"github.com/mock/test"})
-	err := w.Watch(context.TODO(), func(e lookout.Event) error {
+	err := w.Watch(context.TODO(), func(ctx context.Context, e lookout.Event) error {


duplicate of /tmp/gometalint392739599/provider___.github.___watcher_test.go:153-158 (dupl)

If you have feedback about this comment, please, tell us.

lookout-bot · 2018-09-10T16:41:31Z

provider/github/watcher_test.go

@@ -150,7 +150,7 @@ func (s *WatcherTestSuite) TestWatch_CallbackError_Event() {
 	s.mux.HandleFunc("/repos/mock/test/events", eventsHandler(&calls))

 	w := s.newWatcher([]string{"github.com/mock/test"})
-	err := w.Watch(context.TODO(), func(e lookout.Event) error {
+	err := w.Watch(context.TODO(), func(ctx context.Context, e lookout.Event) error {


duplicate of /tmp/gometalint392739599/provider___.github.___watcher_test.go:136-141 (dupl)

If you have feedback about this comment, please, tell us.

smacker

👏

smacker · 2018-09-13T10:33:27Z

The service/git methods now get the log from the context, but the problem here is that the gRPC requests come from the analyzer, and we don't have the event-id or any other field.
I didn't look much into it, so I don't know if there is a way to pass some ID fields to the analyzer and get them back when they call GetFiles/GetChanges without modifying the proto messages.

Grpc allows to send metadata in header or trailer. There are some helpers in go-grpc-middleware for that.
We can include it in our sdk later to pass event-id to an analyzer and send it back.

carlosms · 2018-09-13T11:15:02Z

That's great. I created an issue with your suggestion so we don't forget about it: #248

carlosms added 8 commits September 10, 2018 18:32

Add structured logs for diff errors

625f4e2

Signed-off-by: Carlos Martín <carlos.martin.sanchez@gmail.com>

Use context logger for http logs

6d48df2

Signed-off-by: Carlos Martín <carlos.martin.sanchez@gmail.com>

Use context log in event callbacks

ccec2e0

Signed-off-by: Carlos Martín <carlos.martin.sanchez@gmail.com>

Init default logger in ctxlog

c34f9bc

Signed-off-by: Carlos Martín <carlos.martin.sanchez@gmail.com>

Use ctxlog in git services

c76781b

Signed-off-by: Carlos Martín <carlos.martin.sanchez@gmail.com>

Use default logger for gRPC status changes

844cdc5

Signed-off-by: Carlos Martín <carlos.martin.sanchez@gmail.com>

Fix default logger init for lookoutd migrate

9630001

Signed-off-by: Carlos Martín <carlos.martin.sanchez@gmail.com>

Make DB version log structured

b4921f2

Signed-off-by: Carlos Martín <carlos.martin.sanchez@gmail.com>

carlosms requested review from smacker, dpordomingo and bzz September 10, 2018 16:41

lookout-bot reviewed Sep 10, 2018

View reviewed changes

src-d deleted a comment from lookout-bot Sep 13, 2018

smacker approved these changes Sep 13, 2018

View reviewed changes

carlosms mentioned this pull request Sep 13, 2018

Add ID metadata to gRPC calls, and use it in logs #248

Closed

carlosms merged commit 5103a5a into src-d:master Sep 13, 2018

carlosms mentioned this pull request Nov 16, 2018

Log fields are lost when events are sent to the queue #357

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

Improve log fields #245

Improve log fields #245

Uh oh!

carlosms commented Sep 10, 2018

Uh oh!

lookout-bot Sep 10, 2018

Uh oh!

lookout-bot Sep 10, 2018

Uh oh!

lookout-bot Sep 10, 2018

Uh oh!

lookout-bot Sep 10, 2018

Uh oh!

lookout-bot Sep 10, 2018

Uh oh!

lookout-bot Sep 10, 2018

Uh oh!

lookout-bot Sep 10, 2018

Uh oh!

lookout-bot Sep 10, 2018

Uh oh!

lookout-bot Sep 10, 2018

Uh oh!

lookout-bot Sep 10, 2018

Uh oh!

smacker left a comment

Uh oh!

smacker commented Sep 13, 2018

Uh oh!

carlosms commented Sep 13, 2018

Uh oh!

Uh oh!

Improve log fields #245

Improve log fields #245

Uh oh!

Conversation

carlosms commented Sep 10, 2018

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

smacker left a comment

Choose a reason for hiding this comment

Uh oh!

smacker commented Sep 13, 2018

Uh oh!

carlosms commented Sep 13, 2018

Uh oh!

Uh oh!