fix: do not log error at login/consent cancelation (#1914)

Closes #1912

Signed-off-by: sawadashota <xiootas@gmail.com>

driver/registry_base.go

@@ -41,6 +41,7 @@ const (
 
 type RegistryBase struct {
 	l            *logrusx.Logger
+	al           *logrusx.Logger
 	c            configuration.Provider
 	cm           client.Manager
 	ch           *client.Handler
@@ -149,6 +150,13 @@ func (m *RegistryBase) Logger() *logrusx.Logger {
 	return m.l
 }
 
+func (m *RegistryBase) AuditLogger() *logrusx.Logger {
+	if m.al == nil {
+		m.al = logrusx.NewAudit("ORY Hydra", m.BuildVersion())
+	}
+	return m.al
+}
+
 func (m *RegistryBase) ClientHasher() fosite.Hasher {
 	if m.fh == nil {
 		if m.Tracer().IsLoaded() {

oauth2/handler.go

@@ -629,8 +629,13 @@ func (h *Handler) AuthHandler(w http.ResponseWriter, r *http.Request, _ httprout
 
 	session, err := h.r.ConsentStrategy().HandleOAuth2AuthorizationRequest(w, r, authorizeRequest)
 	if errors.Cause(err) == consent.ErrAbortOAuth2Request {
+		x.LogAudit(r, nil, h.r.AuditLogger())
 		// do nothing
 		return
+	} else if e := &(fosite.RFC6749Error{}); errors.As(err, &e) {
+		x.LogAudit(r, err, h.r.AuditLogger())
+		h.writeAuthorizeError(w, r, authorizeRequest, err)
+		return
 	} else if err != nil {
 		x.LogError(r, err, h.r.Logger())
 		h.writeAuthorizeError(w, r, authorizeRequest, err)

x/audit.go

@@ -0,0 +1,22 @@
+package x
+
+import (
+	"net/http"
+
+	"github.com/ory/x/logrusx"
+)
+
+func LogAudit(r *http.Request, message interface{}, logger *logrusx.Logger) {
+	if logger == nil {
+		logger = logrusx.NewAudit("", "")
+	}
+
+	logger = logger.WithRequest(r)
+
+	if err, ok := message.(error); ok {
+		logger.WithError(err).Infoln("access denied")
+		return
+	}
+
+	logger.Infoln("access allowed")
+}

x/audit_test.go

@@ -0,0 +1,50 @@
+package x
+
+import (
+	"bytes"
+	"fmt"
+	"net/http"
+	"testing"
+
+	"github.com/ory/x/logrusx"
+	"github.com/pkg/errors"
+	"github.com/sirupsen/logrus"
+	"github.com/stretchr/testify/assert"
+)
+
+func TestLogAudit(t *testing.T) {
+	for k, tc := range []struct {
+		d              string
+		message        interface{}
+		expectContains []string
+	}{
+		{
+			d:              "This should log \"access allowed\" because no errors are given",
+			message:        nil,
+			expectContains: []string{"msg=access allowed"},
+		},
+		{
+			d:              "This should log \"access denied\" because an error is given",
+			message:        errors.New("asdf"),
+			expectContains: []string{"msg=access denied"},
+		},
+	} {
+		t.Run(fmt.Sprintf("case=%d/description=%s", k, tc.d), func(t *testing.T) {
+			r, err := http.NewRequest(http.MethodGet, "https://hydra/some/endpoint", nil)
+			if err != nil {
+				t.Fatal(err)
+			}
+			buf := bytes.NewBuffer([]byte{})
+			l := logrusx.NewAudit("", "", logrusx.ForceLevel(logrus.TraceLevel))
+			l.Logger.Out = buf
+			LogAudit(r, tc.message, l)
+
+			t.Logf("%s", string(buf.Bytes()))
+
+			assert.Contains(t, buf.String(), "audience=audit")
+			for _, expectContain := range tc.expectContains {
+				assert.Contains(t, buf.String(), expectContain)
+			}
+		})
+	}
+}

x/registry.go

@@ -8,6 +8,7 @@ import (
 
 type RegistryLogger interface {
 	Logger() *logrusx.Logger
+	AuditLogger() *logrusx.Logger
 }
 
 type RegistryWriter interface {