1
0
mirror of https://github.com/SAP/jenkins-library.git synced 2025-09-16 09:26:22 +02:00

[ANS] logrus hook (#3671)

* Add ans implementation

* Remove todo comment

* Rename test function

Co-authored-by: Linda Siebert <39100394+LindaSieb@users.noreply.github.com>

* Better wording

Co-authored-by: Linda Siebert <39100394+LindaSieb@users.noreply.github.com>

* Add reading of response body function

* Use http pkg ReadResponseBody

* Check read error

* Better test case description

* Fix formatting

* Create own package for read response body

* Omit empty nested resource struct

* Separate Resource struct from Event struct

* Merge and unmarshall instead of only unmarshalling

* Improve status code error message

* Remove unchangeable event fields

* Separate event parts

* Change log level setter function

* Restructure ans send test

* Revert exporting readResponseBody function

Instead the code is duplicated in the xsuaa and ans package

* Add check correct ans setup request

* Add set options function for mocking

* Review fixes

* Correct function name

* Use strict unmarshalling

* Validate event

* Move functions

* Add documentation comments

* improve test

* Validate event

* Add logrus hook for ans

* Set defaults on new hook creation

* Fix log level on error

* Don't alter entry log level

* Set severity fatal on 'fatal error' log message

* Ensure that log entries don't affect each other

* Remove unnecessary correlationID

* Use file path instead of event template string

* Improve warning messages

* Add empty log message check

* Allow configuration from file and string

* Add sourceEventId to tags

* Change resourceType to Pipeline

* Use structured config approach

* Use new log level set function

* Check correct setup and return error

* Mock http requests

* Only send log level warning or higher

* Use new function name

* One-liner ifs

* Improve test name

* Fix tests

* Prevent double firing

* Reduce Fire test size

* Add error message to test

* Reduce newANSHook test size

* Further check error

* Rename to defaultEvent in hook struct

* Reduce ifs further

* Fix set error category test

The ansHook Fire test cannot run in parallel, as it would affect the
other tests that use the error category.

* Change function name to SetServiceKey

* Validate event

* Rename to eventTemplate in hook struct

* Move copy to event.go

* Fix function mix

* Remove unnecessary cleanup

* Remove parallel test

The translation fails now and again when parallel is on.

* Remove prefix test

* Remove unused copyEvent function

* Fix ifs

* Add docu comment

* Register ans hook from pkg

* register hook and setup event template seperately

* Exclusively read eventTemplate from environment

* setupEventTemplate tests

* adjust hook levels test

* sync tests- wlill still fail

* migrate TestANSHook_registerANSHook test

* fixes

* review - cleanup, reuse poke

* Apply suggestions from code review

* Change subject

* Review fixes

* Set stepName 'n/a' if not available

* Fix fire tests

Co-authored-by: Linda Siebert <39100394+LindaSieb@users.noreply.github.com>
Co-authored-by: Roland Stengel <r.stengel@sap.com>
This commit is contained in:
Oliver Feldmann
2022-06-17 16:40:45 +02:00
committed by GitHub
parent 0457601efd
commit c5b83de7e1
4 changed files with 591 additions and 0 deletions

View File

@@ -75,6 +75,16 @@ func (event *Event) Validate() (err error) {
return
}
// Copy will copy an ANS Event
func (event *Event) Copy() (destination Event, err error) {
var sourceJSON []byte
if sourceJSON, err = json.Marshal(event); err != nil {
return
}
err = destination.MergeWithJSON(sourceJSON)
return
}
// SetSeverityAndCategory takes the logrus log level and sets the corresponding ANS severity and category string
func (event *Event) SetSeverityAndCategory(level logrus.Level) {
switch level {

View File

@@ -179,3 +179,15 @@ func defaultEvent() Event {
},
}
}
func TestEvent_Copy(t *testing.T) {
t.Parallel()
t.Run("good", func(t *testing.T) {
originalEvent := defaultEvent()
newEvent, err := originalEvent.Copy()
require.NoError(t, err)
assert.Equal(t, originalEvent, newEvent, "Events should be the same after copying.")
newEvent.Resource.ResourceType = "different"
assert.NotEqual(t, originalEvent, newEvent, "Events should not affect each other after copying")
})
}

141
pkg/log/ansHook.go Normal file
View File

@@ -0,0 +1,141 @@
package log
import (
"fmt"
"github.com/SAP/jenkins-library/pkg/ans"
"github.com/pkg/errors"
"github.com/sirupsen/logrus"
"os"
"strings"
)
// ANSHook is used to set the hook features for the logrus hook
type ANSHook struct {
client ans.Client
eventTemplate ans.Event
firing bool
}
// Levels returns the supported log level of the hook.
func (ansHook *ANSHook) Levels() []logrus.Level {
return []logrus.Level{logrus.WarnLevel, logrus.ErrorLevel, logrus.PanicLevel, logrus.FatalLevel}
}
// Fire creates a new event from the logrus and sends an event to the ANS backend
func (ansHook *ANSHook) Fire(entry *logrus.Entry) (err error) {
if ansHook.firing {
return fmt.Errorf("ANS hook has already been fired")
}
ansHook.firing = true
defer func() { ansHook.firing = false }()
if len(strings.TrimSpace(entry.Message)) == 0 {
return
}
var event ans.Event
if event, err = ansHook.eventTemplate.Copy(); err != nil {
return
}
logLevel := entry.Level
event.SetSeverityAndCategory(logLevel)
var stepName string
if entry.Data["stepName"] != nil {
stepName = fmt.Sprint(entry.Data["stepName"])
} else {
stepName = "n/a"
}
event.Tags["pipeline:stepName"] = stepName
if errorCategory := GetErrorCategory().String(); errorCategory != "undefined" {
event.Tags["pipeline:errorCategory"] = errorCategory
}
event.EventTimestamp = entry.Time.Unix()
if event.Subject == "" {
event.Subject = fmt.Sprintf("Pipeline step '%s' sends '%s'", stepName, event.Severity)
}
event.Body = entry.Message
event.Tags["pipeline:logLevel"] = logLevel.String()
return ansHook.client.Send(event)
}
type registrationUtil interface {
ans.Client
registerHook(hook *ANSHook)
}
type registrationUtilImpl struct {
ans.Client
}
func (u *registrationUtilImpl) registerHook(hook *ANSHook) {
RegisterHook(hook)
}
func (u *registrationUtilImpl) registerSecret(secret string) {
RegisterSecret(secret)
}
// RegisterANSHookIfConfigured creates a new ANS hook for logrus if it is configured and registers it
func RegisterANSHookIfConfigured(correlationID string) error {
return registerANSHookIfConfigured(correlationID, &registrationUtilImpl{Client: &ans.ANS{}})
}
func registerANSHookIfConfigured(correlationID string, util registrationUtil) error {
ansServiceKeyJSON := os.Getenv("PIPER_ansHookServiceKey")
if len(ansServiceKeyJSON) == 0 {
return nil
}
ansServiceKey, err := ans.UnmarshallServiceKeyJSON(ansServiceKeyJSON)
if err != nil {
return errors.Wrap(err, "cannot initialize SAP Alert Notification Service due to faulty serviceKey json")
}
RegisterSecret(ansServiceKey.ClientSecret)
util.SetServiceKey(ansServiceKey)
if err = util.CheckCorrectSetup(); err != nil {
return errors.Wrap(err, "check http request to SAP Alert Notification Service failed; not setting up the ANS hook")
}
eventTemplate, err := setupEventTemplate(os.Getenv("PIPER_ansEventTemplate"), correlationID)
if err != nil {
return err
}
util.registerHook(&ANSHook{
client: util,
eventTemplate: eventTemplate,
})
return nil
}
func setupEventTemplate(customerEventTemplate, correlationID string) (ans.Event, error) {
event := ans.Event{
EventType: "Piper",
Tags: map[string]interface{}{"ans:correlationId": correlationID, "ans:sourceEventId": correlationID},
Resource: &ans.Resource{
ResourceType: "Pipeline",
ResourceName: "Pipeline",
},
}
if len(customerEventTemplate) > 0 {
if err := event.MergeWithJSON([]byte(customerEventTemplate)); err != nil {
Entry().WithField("stepName", "ANS").Warnf("provided SAP Alert Notification Service event template '%s' could not be unmarshalled: %v", customerEventTemplate, err)
return ans.Event{}, errors.Wrapf(err, "provided SAP Alert Notification Service event template '%s' could not be unmarshalled", customerEventTemplate)
}
}
if len(event.Severity) > 0 {
Entry().WithField("stepName", "ANS").Warnf("event severity set to '%s' will be overwritten according to the log level", event.Severity)
event.Severity = ""
}
if len(event.Category) > 0 {
Entry().WithField("stepName", "ANS").Warnf("event category set to '%s' will be overwritten according to the log level", event.Category)
event.Category = ""
}
if err := event.Validate(); err != nil {
return ans.Event{}, errors.Wrap(err, "did not initialize SAP Alert Notification Service due to faulty event template json")
}
return event, nil
}

428
pkg/log/ansHook_test.go Normal file
View File

@@ -0,0 +1,428 @@
package log
import (
"bytes"
"encoding/json"
"fmt"
"github.com/SAP/jenkins-library/pkg/ans"
"github.com/sirupsen/logrus"
"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
"os"
"reflect"
"strconv"
"testing"
"time"
)
func TestANSHook_Levels(t *testing.T) {
registrationUtil := createRegUtil()
t.Run("good", func(t *testing.T) {
t.Run("default hook levels", func(t *testing.T) {
registerANSHookIfConfigured(testCorrelationID, registrationUtil)
assert.Equal(t, []logrus.Level{logrus.WarnLevel, logrus.ErrorLevel, logrus.PanicLevel, logrus.FatalLevel}, registrationUtil.Hook.Levels())
})
})
}
func TestANSHook_setupEventTemplate(t *testing.T) {
t.Run("good", func(t *testing.T) {
t.Run("setup event without customer template", func(t *testing.T) {
event, _ := setupEventTemplate("", defaultCorrelationID())
assert.Equal(t, defaultEvent(), event, "unexpected event data")
})
t.Run("setup event from default customer template", func(t *testing.T) {
event, _ := setupEventTemplate(customerEventString(), defaultCorrelationID())
assert.Equal(t, defaultEvent(), event, "unexpected event data")
})
t.Run("setup event with category", func(t *testing.T) {
event, _ := setupEventTemplate(customerEventString(map[string]interface{}{"Category": "ALERT"}), defaultCorrelationID())
assert.Equal(t, "", event.Category, "unexpected category data")
})
t.Run("setup event with severity", func(t *testing.T) {
event, _ := setupEventTemplate(customerEventString(map[string]interface{}{"Severity": "WARNING"}), defaultCorrelationID())
assert.Equal(t, "", event.Severity, "unexpected severity data")
})
t.Run("setup event with invalid category", func(t *testing.T) {
event, _ := setupEventTemplate(customerEventString(map[string]interface{}{"Category": "invalid"}), defaultCorrelationID())
assert.Equal(t, "", event.Category, "unexpected category data")
})
t.Run("setup event with priority", func(t *testing.T) {
event, _ := setupEventTemplate(customerEventString(map[string]interface{}{"Priority": "1"}), defaultCorrelationID())
assert.Equal(t, 1, event.Priority, "unexpected priority data")
})
t.Run("setup event with omitted priority 0", func(t *testing.T) {
event, err := setupEventTemplate(customerEventString(map[string]interface{}{"Priority": "0"}), defaultCorrelationID())
assert.Equal(t, nil, err, "priority 0 must not fail")
assert.Equal(t, 0, event.Priority, "unexpected priority data")
})
})
t.Run("bad", func(t *testing.T) {
t.Run("setup event with invalid priority", func(t *testing.T) {
_, err := setupEventTemplate(customerEventString(map[string]interface{}{"Priority": "-1"}), defaultCorrelationID())
assert.Contains(t, err.Error(), "Priority must be 1 or greater", "unexpected error text")
})
t.Run("setup event with invalid variable name", func(t *testing.T) {
_, err := setupEventTemplate(customerEventString(map[string]interface{}{"Invalid": "invalid"}), defaultCorrelationID())
assert.Contains(t, err.Error(), "could not be unmarshalled", "unexpected error text")
})
})
}
func TestANSHook_registerANSHook(t *testing.T) {
os.Setenv("PIPER_ansHookServiceKey", defaultServiceKeyJSON)
t.Run("good", func(t *testing.T) {
t.Run("No service key skips registration", func(t *testing.T) {
util := createRegUtil()
os.Setenv("PIPER_ansHookServiceKey", "")
assert.Nil(t, registerANSHookIfConfigured(testCorrelationID, util), "registration did not nil")
assert.Nil(t, util.Hook, "registration registered hook")
os.Setenv("PIPER_ansHookServiceKey", defaultServiceKeyJSON)
})
t.Run("Default registration registers hook and secret", func(t *testing.T) {
util := createRegUtil()
assert.Nil(t, registerANSHookIfConfigured(testCorrelationID, util), "registration did not nil")
assert.NotNil(t, util.Hook, "registration didnt register hook")
assert.NotNil(t, util.Secret, "registration didnt register secret")
})
t.Run("Registration with default template", func(t *testing.T) {
util := createRegUtil()
os.Setenv("PIPER_ansEventTemplate", customerEventString())
assert.Nil(t, registerANSHookIfConfigured(testCorrelationID, util), "registration did not return nil")
assert.Equal(t, customerEvent(), util.Hook.eventTemplate, "unexpected event template data")
os.Setenv("PIPER_ansEventTemplate", "")
})
t.Run("Registration with customized template", func(t *testing.T) {
util := createRegUtil()
os.Setenv("PIPER_ansEventTemplate", customerEventString(map[string]interface{}{"Priority": "123"}))
assert.Nil(t, registerANSHookIfConfigured(testCorrelationID, util), "registration did not return nil")
assert.Equal(t, 123, util.Hook.eventTemplate.Priority, "unexpected event template data")
os.Setenv("PIPER_ansEventTemplate", "")
})
})
t.Run("bad", func(t *testing.T) {
t.Run("Fails on check error", func(t *testing.T) {
util := createRegUtil(map[string]interface{}{"CheckErr": fmt.Errorf("check failed")})
err := registerANSHookIfConfigured(testCorrelationID, util)
assert.Contains(t, err.Error(), "check failed", "unexpected error text")
})
t.Run("Fails on validation error", func(t *testing.T) {
os.Setenv("PIPER_ansEventTemplate", customerEventString(map[string]interface{}{"Priority": "-1"}))
err := registerANSHookIfConfigured(testCorrelationID, createRegUtil())
assert.Contains(t, err.Error(), "Priority must be 1 or greater", "unexpected error text")
os.Setenv("PIPER_ansEventTemplate", "")
})
})
os.Setenv("PIPER_ansHookServiceKey", "")
}
func TestANSHook_Fire(t *testing.T) {
registrationUtil := createRegUtil()
ansHook := &ANSHook{
client: registrationUtil,
}
t.Run("Straight forward test", func(t *testing.T) {
ansHook.eventTemplate = defaultEvent()
require.NoError(t, ansHook.Fire(defaultLogrusEntry()), "error is not nil")
assert.Equal(t, defaultResultingEvent(), registrationUtil.Event, "error category tag is not as expected")
registrationUtil.clearEventTemplate()
})
t.Run("Set error category", func(t *testing.T) {
SetErrorCategory(ErrorTest)
ansHook.eventTemplate = defaultEvent()
require.NoError(t, ansHook.Fire(defaultLogrusEntry()), "error is not nil")
assert.Equal(t, "test", registrationUtil.Event.Tags["pipeline:errorCategory"], "error category tag is not as expected")
SetErrorCategory(ErrorUndefined)
registrationUtil.clearEventTemplate()
})
t.Run("Event already set", func(t *testing.T) {
alreadySetEvent := ans.Event{EventType: "My event type", Subject: "My subject line", Tags: map[string]interface{}{"Some": 1.0, "Additional": "a string", "Tags": true}}
ansHook.eventTemplate = mergeEvents(t, defaultEvent(), alreadySetEvent)
require.NoError(t, ansHook.Fire(defaultLogrusEntry()), "error is not nil")
assert.Equal(t, mergeEvents(t, defaultResultingEvent(), alreadySetEvent), registrationUtil.Event, "event is not as expected")
registrationUtil.clearEventTemplate()
})
t.Run("Log entries should not affect each other", func(t *testing.T) {
ansHook.eventTemplate = defaultEvent()
SetErrorCategory(ErrorTest)
require.NoError(t, ansHook.Fire(defaultLogrusEntry()), "error is not nil")
assert.Equal(t, "test", registrationUtil.Event.Tags["pipeline:errorCategory"], "error category tag is not as expected")
SetErrorCategory(ErrorUndefined)
require.NoError(t, ansHook.Fire(defaultLogrusEntry()), "error is not nil")
assert.Nil(t, registrationUtil.Event.Tags["pipeline:errorCategory"], "error category tag is not nil")
registrationUtil.clearEventTemplate()
})
t.Run("White space messages should not send", func(t *testing.T) {
ansHook.eventTemplate = defaultEvent()
entryWithSpaceMessage := defaultLogrusEntry()
entryWithSpaceMessage.Message = " "
require.NoError(t, ansHook.Fire(entryWithSpaceMessage), "error is not nil")
assert.Equal(t, ans.Event{}, registrationUtil.Event, "event is not empty")
})
t.Run("Should not fire twice", func(t *testing.T) {
ansHook.eventTemplate = defaultEvent()
ansHook.firing = true
require.EqualError(t, ansHook.Fire(defaultLogrusEntry()), "ANS hook has already been fired", "error message is not as expected")
ansHook.firing = false
})
t.Run("No stepName set", func(t *testing.T) {
ansHook.eventTemplate = defaultEvent()
logrusEntryWithoutStepName := defaultLogrusEntry()
logrusEntryWithoutStepName.Data = map[string]interface{}{}
require.NoError(t, ansHook.Fire(logrusEntryWithoutStepName), "error is not nil")
assert.Equal(t, "n/a", registrationUtil.Event.Tags["pipeline:stepName"], "event step name tag is not as expected.")
assert.Equal(t, "Pipeline step 'n/a' sends 'WARNING'", registrationUtil.Event.Subject, "event subject is not as expected")
registrationUtil.clearEventTemplate()
})
}
const testCorrelationID = "1234"
const defaultServiceKeyJSON = `{"url": "https://my.test.backend", "client_id": "myTestClientID", "client_secret": "super secret", "oauth_url": "https://my.test.oauth.provider"}`
var defaultTime = time.Date(2001, 2, 3, 4, 5, 6, 7, time.UTC)
func defaultCorrelationID() string {
return testCorrelationID
}
func merge(base, overlay map[string]interface{}) map[string]interface{} {
result := map[string]interface{}{}
if base == nil {
base = map[string]interface{}{}
}
for key, value := range base {
result[key] = value
}
for key, value := range overlay {
if val, ok := value.(map[string]interface{}); ok {
if valBaseKey, ok := base[key].(map[string]interface{}); !ok {
result[key] = merge(map[string]interface{}{}, val)
} else {
result[key] = merge(valBaseKey, val)
}
} else {
result[key] = value
}
}
return result
}
func customerEvent(params ...interface{}) ans.Event {
event := ans.Event{}
json.Unmarshal([]byte(customerEventString(params)), &event)
return event
}
func customerEventString(params ...interface{}) string {
event := defaultEvent()
additionalFields := make(map[string]interface{})
if len(params) > 0 {
for i := 0; i < len(params); i++ {
additionalFields = merge(additionalFields, pokeObject(&event, params[i]))
}
}
// create json string from Event
marshaled, err := json.Marshal(event)
if err != nil {
panic(fmt.Sprintf("cannot marshal customer event: %v", err))
}
// add non Event members to json string
if len(additionalFields) > 0 {
closingBraceIdx := bytes.LastIndexByte(marshaled, '}')
for key, value := range additionalFields {
var entry string
switch value.(type) {
default:
panic(fmt.Sprintf("invalid key value type: %v", key))
case string:
entry = `, "` + key + `": "` + value.(string) + `"`
case int:
entry = `, "` + key + `": "` + strconv.Itoa(value.(int)) + `"`
}
add := []byte(entry)
marshaled = append(marshaled[:closingBraceIdx], add...)
}
marshaled = append(marshaled, '}')
}
return string(marshaled)
}
type registrationUtilMock struct {
ans.Client
Event ans.Event
ServiceKey ans.ServiceKey
SendErr error
CheckErr error
Hook *ANSHook
Secret string
}
func (m *registrationUtilMock) Send(event ans.Event) error {
m.Event = event
return m.SendErr
}
func (m *registrationUtilMock) CheckCorrectSetup() error {
return m.CheckErr
}
func (m *registrationUtilMock) SetServiceKey(serviceKey ans.ServiceKey) {
m.ServiceKey = serviceKey
}
func (m *registrationUtilMock) registerHook(hook *ANSHook) {
m.Hook = hook
}
func (m *registrationUtilMock) registerSecret(secret string) {
m.Secret = secret
}
func (m *registrationUtilMock) clearEventTemplate() {
m.Event = ans.Event{}
}
func createRegUtil(params ...interface{}) *registrationUtilMock {
mock := registrationUtilMock{}
if len(params) > 0 {
for i := 0; i < len(params); i++ {
pokeObject(&mock, params[i])
}
}
return &mock
}
func pokeObject(obj interface{}, param interface{}) map[string]interface{} {
additionalFields := make(map[string]interface{})
switch t := param.(type) {
case map[string]interface{}:
{
m := param.(map[string]interface{})
v := reflect.ValueOf(obj)
if v.Kind() == reflect.Ptr {
v = v.Elem()
}
for key, value := range m {
f := v.FieldByName(key)
if f != (reflect.Value{}) {
switch f.Kind() {
case reflect.String:
f.SetString(value.(string))
case reflect.Int, reflect.Int64:
switch t := value.(type) {
case string:
v, _ := strconv.Atoi(value.(string))
f.SetInt(int64(v))
case int:
f.SetInt(int64((value).(int)))
case int64:
f.SetInt(value.(int64))
default:
panic(fmt.Sprintf("unsupported value type: %v of key:%v value:%v\n", t, key, value))
}
case reflect.Map:
switch value.(type) {
case map[string]string, map[string]interface{}:
if value != nil {
val := reflect.ValueOf(value)
f.Set(val)
} else {
f.Set(reflect.Zero(f.Type()))
}
}
case reflect.Interface:
if value != nil {
val := reflect.ValueOf(value)
f.Set(val)
} else {
f.Set(reflect.Zero(f.Type()))
}
default:
panic(fmt.Sprintf("unsupported field type: %v of key:%v value:%v\n", f.Kind(), key, value))
}
} else {
additionalFields[key] = value
}
}
}
case []interface{}:
p := param.([]interface{})
for i := 0; i < len(p); i++ {
pokeObject(obj, p[i])
}
default:
panic(fmt.Sprintf("unsupported paramter type: %v", t))
}
return additionalFields
}
func defaultEvent() ans.Event {
event := ans.Event{
EventType: "Piper",
Tags: map[string]interface{}{
"ans:correlationId": testCorrelationID,
"ans:sourceEventId": testCorrelationID,
},
Resource: &ans.Resource{
ResourceType: "Pipeline",
ResourceName: "Pipeline",
},
}
return event
}
func defaultResultingEvent() ans.Event {
return customerEvent(map[string]interface{}{
"EventTimestamp": defaultTime.Unix(),
"Severity": "WARNING",
"Category": "ALERT",
"Subject": "Pipeline step 'testStep' sends 'WARNING'",
"Body": "my log message",
"Tags": map[string]interface{}{
"ans:correlationId": "1234",
"ans:sourceEventId": "1234",
"pipeline:stepName": "testStep",
"pipeline:logLevel": "warning",
},
})
}
func defaultLogrusEntry() *logrus.Entry {
return &logrus.Entry{
Level: logrus.WarnLevel,
Time: defaultTime,
Message: "my log message",
Data: map[string]interface{}{"stepName": "testStep"},
}
}
func mergeEvents(t *testing.T, event1, event2 ans.Event) ans.Event {
event2JSON, err := json.Marshal(event2)
require.NoError(t, err)
err = event1.MergeWithJSON(event2JSON)
require.NoError(t, err)
return event1
}