Error message is discarded when embedding an error

[Alex-PK]

Hi,

whenever WithError is used to log a message, the cause is taken from the embedded error and the logged message gets completely lost.

Example:

package main

import (
	"github.com/heroku/rollrus"
	log "github.com/sirupsen/logrus"
	"errors"
)

func main() {
	log.SetLevel(log.ErrorLevel)
	rollbarHook := rollrus.NewHook("bc", "test")
	log.AddHook(rollbarHook)

	log.WithError(errors.New("[Testing] inner message")).Error("[Testing] outer message")
}

This is what appears on rollbar:

 Traceback (most recent call last):
File "github.com/heroku/rollrus/rollrus.go" line 191 in rollrus.(*Hook).report
File "github.com/heroku/rollrus/rollrus.go" line 170 in rollrus.(*Hook).Fire
File "github.com/sirupsen/logrus/hooks.go" line 28 in logrus.LevelHooks.Fire
File "github.com/sirupsen/logrus/entry.go" line 98 in logrus.Entry.log
File "github.com/sirupsen/logrus/entry.go" line 159 in logrus.(*Entry).Error
File "rollrustest.go" line 15 in main.main

{699508d8}: [Testing] inner message

The "outer message" does not appear anywhere.

I traced down the problem to extractError, which takes the cause from the err field if it is present.

In my opinion, if there is an entry.Message, that should be used as cause, and the err field's cause should be logged in a separate field.

I can prepare a PR if needed.

Thanks!

[freeformz]

@Alex-PK I'd be happy to review a PR.

[fgblomqvist]

I think the best option here is for rollrus to stay unopinionated in terms of how things should be formatted when sent to Rollbar. E.g. while you (and most likely others) think that the top log message is the most important message, I'd argue that the cause error is the most important message.

The reason why is because, in larger applications, you'll most likely have tons of different possible errors for one command/function. All these errors usually vary in criticalness. Therefore, it would be very unhelpful if all you see at a glance in Rollbar is more generic messages (the top-level log messages), such as "failed to run command x", likewise, the titles are what's in focus in notifications (emails/elsewhere). Getting an email such as "failed to run command x" is a lot more stressful than one directly specifying the underlying cause (maybe your application simply failed to connect to a 3rd party service, something you can't necessarily do anything about).

Now, imo, the best of both worlds is to just format it as {log message}: {cause error}. However, there could surely be people who'd prefer it be done in a different way. Therefore, I think allowing the user to specify a custom formatter (or something like that) would be the ideal solution. It could still default to my proposed solution (a combination of both log message and cause error) to allow people to get a good generic solution as quickly as possible.

[yhsiang]

I found v0.2.0 already fixed this with rollbar custom data.
outer message will be added in custom.msg

https://github.com/heroku/rollrus/blob/v0.2.0/hook.go#L71

I will try on our environment first and report here