diff --git a/cmd/noma-daemon/main.go b/cmd/noma-daemon/main.go index 45bd8316..419b0ee9 100644 --- a/cmd/noma-daemon/main.go +++ b/cmd/noma-daemon/main.go @@ -5,6 +5,7 @@ import ( "flag" "fmt" "github.com/icinga/icingadb/pkg/logging" + "github.com/icinga/icingadb/pkg/utils" "github.com/icinga/noma/internal/config" "github.com/icinga/noma/internal/listener" "go.uber.org/zap" @@ -29,31 +30,39 @@ func main() { os.Exit(1) } - // TODO: proper logging config - logs, err := logging.NewLogging("noma", zap.DebugLevel, logging.CONSOLE, logging.Options{}, 10*time.Second) + logs, err := logging.NewLogging( + "noma", + conf.Logging.Level, + conf.Logging.Output, + conf.Logging.Options, + conf.Logging.Interval, + ) if err != nil { _, _ = fmt.Fprintln(os.Stderr, "cannot initialize logging:", err) os.Exit(1) } logger := logs.GetLogger() - logger.Info("connecting to database") - db, err := conf.Database.Open(logger) + db, err := conf.Database.Open(logs.GetChildLogger("database")) if err != nil { - _, _ = fmt.Fprintln(os.Stderr, "cannot connect to database:", err) - os.Exit(1) + logger.Fatalw("cannot create database connection from config", zap.Error(err)) } - logger.Debugw("pinged database", zap.Error(db.Ping())) defer db.Close() + { + logger.Infof("Connecting to database at '%s'", utils.JoinHostPort(conf.Database.Host, conf.Database.Port)) + if err := db.Ping(); err != nil { + logger.Fatalw("cannot connect to database", zap.Error(err)) + } + } - var runtimeConfig config.RuntimeConfig - if err := runtimeConfig.UpdateFromDatabase(context.TODO(), db, logger); err != nil { + runtimeConfig := config.NewRuntimeConfig(db, logs.GetChildLogger("runtime-updates")) + if err := runtimeConfig.UpdateFromDatabase(context.TODO()); err != nil { logger.Fatalw("failed to load config from database", zap.Error(err)) } - go runtimeConfig.PeriodicUpdates(context.TODO(), db, logger, 1*time.Second) + go runtimeConfig.PeriodicUpdates(context.TODO(), 1*time.Second) - if err := listener.NewListener(db, conf, &runtimeConfig).Run(); err != nil { + if err := listener.NewListener(db, conf, runtimeConfig, logs.GetChildLogger("listener")).Run(); err != nil { panic(err) } } diff --git a/internal/config/channel.go b/internal/config/channel.go index 3ecbf371..400375c7 100644 --- a/internal/config/channel.go +++ b/internal/config/channel.go @@ -2,28 +2,25 @@ package config import ( "context" - "github.com/icinga/icingadb/pkg/icingadb" - "github.com/icinga/icingadb/pkg/logging" "github.com/icinga/noma/internal/channel" "github.com/jmoiron/sqlx" "go.uber.org/zap" - "log" ) -func (r *RuntimeConfig) fetchChannels(ctx context.Context, db *icingadb.DB, tx *sqlx.Tx, logger *logging.Logger) error { +func (r *RuntimeConfig) fetchChannels(ctx context.Context, tx *sqlx.Tx) error { var channelPtr *channel.Channel - stmt := db.BuildSelectStmt(channelPtr, channelPtr) - log.Println(stmt) + stmt := r.db.BuildSelectStmt(channelPtr, channelPtr) + r.logger.Debugf("Executing query %q", stmt) var channels []*channel.Channel if err := tx.SelectContext(ctx, &channels, stmt); err != nil { - log.Println(err) + r.logger.Errorln(err) return err } channelsByType := make(map[string]*channel.Channel) for _, c := range channels { - channelLogger := logger.With( + channelLogger := r.logger.With( zap.Int64("id", c.ID), zap.String("name", c.Name), zap.String("type", c.Type), @@ -51,7 +48,7 @@ func (r *RuntimeConfig) fetchChannels(ctx context.Context, db *icingadb.DB, tx * return nil } -func (r *RuntimeConfig) applyPendingChannels(logger *logging.Logger) { +func (r *RuntimeConfig) applyPendingChannels() { if r.Channels == nil { r.Channels = make(map[string]*channel.Channel) } diff --git a/internal/config/configfile.go b/internal/config/configfile.go index 3f684848..b26dc936 100644 --- a/internal/config/configfile.go +++ b/internal/config/configfile.go @@ -12,6 +12,7 @@ type ConfigFile struct { DebugPassword string `yaml:"debug-password"` Icingaweb2URL string `yaml:"icingaweb2-url"` Database icingadbConfig.Database `yaml:"database"` + Logging icingadbConfig.Logging `yaml:"logging"` } func FromFile(path string) (*ConfigFile, error) { @@ -40,5 +41,12 @@ func FromFile(path string) (*ConfigFile, error) { } func (c *ConfigFile) Validate() error { - return c.Database.Validate() + if err := c.Database.Validate(); err != nil { + return err + } + if err := c.Logging.Validate(); err != nil { + return err + } + + return nil } diff --git a/internal/config/contact.go b/internal/config/contact.go index 6a194ce9..9520ddd6 100644 --- a/internal/config/contact.go +++ b/internal/config/contact.go @@ -2,22 +2,19 @@ package config import ( "context" - "github.com/icinga/icingadb/pkg/icingadb" - "github.com/icinga/icingadb/pkg/logging" "github.com/icinga/noma/internal/recipient" "github.com/jmoiron/sqlx" "go.uber.org/zap" - "log" ) -func (r *RuntimeConfig) fetchContacts(ctx context.Context, db *icingadb.DB, tx *sqlx.Tx, logger *logging.Logger) error { +func (r *RuntimeConfig) fetchContacts(ctx context.Context, tx *sqlx.Tx) error { var contactPtr *recipient.Contact - stmt := db.BuildSelectStmt(contactPtr, contactPtr) - log.Println(stmt) + stmt := r.db.BuildSelectStmt(contactPtr, contactPtr) + r.logger.Debugf("Executing query %q", stmt) var contacts []*recipient.Contact if err := tx.SelectContext(ctx, &contacts, stmt); err != nil { - log.Println(err) + r.logger.Errorln(err) return err } @@ -25,7 +22,7 @@ func (r *RuntimeConfig) fetchContacts(ctx context.Context, db *icingadb.DB, tx * for _, c := range contacts { contactsByID[c.ID] = c - logger.Debugw("loaded contact config", + r.logger.Debugw("loaded contact config", zap.Int64("id", c.ID), zap.String("name", c.FullName)) } @@ -44,7 +41,7 @@ func (r *RuntimeConfig) fetchContacts(ctx context.Context, db *icingadb.DB, tx * return nil } -func (r *RuntimeConfig) applyPendingContacts(logger *logging.Logger) { +func (r *RuntimeConfig) applyPendingContacts() { if r.Contacts == nil { r.Contacts = make(map[int64]*recipient.Contact) } diff --git a/internal/config/contact_address.go b/internal/config/contact_address.go index 15a29cee..bf9d9dfb 100644 --- a/internal/config/contact_address.go +++ b/internal/config/contact_address.go @@ -2,30 +2,27 @@ package config import ( "context" - "github.com/icinga/icingadb/pkg/icingadb" - "github.com/icinga/icingadb/pkg/logging" "github.com/icinga/noma/internal/recipient" "github.com/jmoiron/sqlx" "go.uber.org/zap" "golang.org/x/exp/slices" - "log" ) -func (r *RuntimeConfig) fetchContactAddresses(ctx context.Context, db *icingadb.DB, tx *sqlx.Tx, logger *logging.Logger) error { +func (r *RuntimeConfig) fetchContactAddresses(ctx context.Context, tx *sqlx.Tx) error { var addressPtr *recipient.Address - stmt := db.BuildSelectStmt(addressPtr, addressPtr) - log.Println(stmt) + stmt := r.db.BuildSelectStmt(addressPtr, addressPtr) + r.logger.Debugf("Executing query %q", stmt) var addresses []*recipient.Address if err := tx.SelectContext(ctx, &addresses, stmt); err != nil { - log.Println(err) + r.logger.Errorln(err) return err } addressesById := make(map[int64]*recipient.Address) for _, a := range addresses { addressesById[a.ID] = a - logger.Debugw("loaded contact_address config", + r.logger.Debugw("loaded contact_address config", zap.Int64("id", a.ID), zap.Int64("contact_id", a.ContactID), zap.String("type", a.Type), @@ -47,7 +44,7 @@ func (r *RuntimeConfig) fetchContactAddresses(ctx context.Context, db *icingadb. return nil } -func (r *RuntimeConfig) applyPendingContactAddresses(logger *logging.Logger) { +func (r *RuntimeConfig) applyPendingContactAddresses() { if r.ContactAddresses == nil { r.ContactAddresses = make(map[int64]*recipient.Address) } @@ -56,24 +53,24 @@ func (r *RuntimeConfig) applyPendingContactAddresses(logger *logging.Logger) { currentAddress := r.ContactAddresses[id] if pendingAddress == nil { - r.removeContactAddress(logger, currentAddress) + r.removeContactAddress(currentAddress) } else if currentAddress != nil { - r.updateContactAddress(logger, currentAddress, pendingAddress) + r.updateContactAddress(currentAddress, pendingAddress) } else { - r.addContactAddress(logger, pendingAddress) + r.addContactAddress(pendingAddress) } } r.pending.ContactAddresses = nil } -func (r *RuntimeConfig) addContactAddress(logger *logging.Logger, addr *recipient.Address) { +func (r *RuntimeConfig) addContactAddress(addr *recipient.Address) { contact := r.Contacts[addr.ContactID] if contact != nil { if i := slices.Index(contact.Addresses, addr); i < 0 { contact.Addresses = append(contact.Addresses, addr) - logger.Debugw("added new address to contact", + r.logger.Debugw("added new address to contact", zap.Any("contact", contact), zap.Any("address", addr)) } @@ -82,11 +79,11 @@ func (r *RuntimeConfig) addContactAddress(logger *logging.Logger, addr *recipien r.ContactAddresses[addr.ID] = addr } -func (r *RuntimeConfig) updateContactAddress(logger *logging.Logger, addr, pending *recipient.Address) { +func (r *RuntimeConfig) updateContactAddress(addr, pending *recipient.Address) { contactChanged := addr.ContactID != pending.ContactID if contactChanged { - r.removeContactAddress(logger, addr) + r.removeContactAddress(addr) } addr.ContactID = pending.ContactID @@ -94,18 +91,18 @@ func (r *RuntimeConfig) updateContactAddress(logger *logging.Logger, addr, pendi addr.Address = pending.Address if contactChanged { - r.addContactAddress(logger, addr) + r.addContactAddress(addr) } - logger.Debugw("updated contact address", zap.Any("address", addr)) + r.logger.Debugw("updated contact address", zap.Any("address", addr)) } -func (r *RuntimeConfig) removeContactAddress(logger *logging.Logger, addr *recipient.Address) { +func (r *RuntimeConfig) removeContactAddress(addr *recipient.Address) { if contact := r.Contacts[addr.ContactID]; contact != nil { if i := slices.Index(contact.Addresses, addr); i >= 0 { contact.Addresses = slices.Delete(contact.Addresses, i, i+1) - logger.Debugw("removed address from contact", + r.logger.Debugw("removed address from contact", zap.Any("contact", contact), zap.Any("address", addr)) } diff --git a/internal/config/group.go b/internal/config/group.go index 1981ec97..42744a80 100644 --- a/internal/config/group.go +++ b/internal/config/group.go @@ -2,22 +2,19 @@ package config import ( "context" - "github.com/icinga/icingadb/pkg/icingadb" - "github.com/icinga/icingadb/pkg/logging" "github.com/icinga/noma/internal/recipient" "github.com/jmoiron/sqlx" "go.uber.org/zap" - "log" ) -func (r *RuntimeConfig) fetchGroups(ctx context.Context, db *icingadb.DB, tx *sqlx.Tx, logger *logging.Logger) error { +func (r *RuntimeConfig) fetchGroups(ctx context.Context, tx *sqlx.Tx) error { var groupPtr *recipient.Group - stmt := db.BuildSelectStmt(groupPtr, groupPtr) - log.Println(stmt) + stmt := r.db.BuildSelectStmt(groupPtr, groupPtr) + r.logger.Debugf("Executing query %q", stmt) var groups []*recipient.Group if err := tx.SelectContext(ctx, &groups, stmt); err != nil { - log.Println(err) + r.logger.Errorln(err) return err } @@ -25,7 +22,7 @@ func (r *RuntimeConfig) fetchGroups(ctx context.Context, db *icingadb.DB, tx *sq for _, g := range groups { groupsById[g.ID] = g - logger.Debugw("loaded group config", + r.logger.Debugw("loaded group config", zap.Int64("id", g.ID), zap.String("name", g.Name)) } @@ -36,17 +33,17 @@ func (r *RuntimeConfig) fetchGroups(ctx context.Context, db *icingadb.DB, tx *sq } var memberPtr *ContactgroupMember - stmt = db.BuildSelectStmt(memberPtr, memberPtr) - log.Println(stmt) + stmt = r.db.BuildSelectStmt(memberPtr, memberPtr) + r.logger.Debugf("Executing query %q", stmt) var members []*ContactgroupMember if err := tx.SelectContext(ctx, &members, stmt); err != nil { - log.Println(err) + r.logger.Errorln(err) return err } for _, m := range members { - memberLogger := logger.With( + memberLogger := r.logger.With( zap.Int64("contact_id", m.ContactId), zap.Int64("contactgroup_id", m.GroupId), ) @@ -75,7 +72,7 @@ func (r *RuntimeConfig) fetchGroups(ctx context.Context, db *icingadb.DB, tx *sq return nil } -func (r *RuntimeConfig) applyPendingGroups(logger *logging.Logger) { +func (r *RuntimeConfig) applyPendingGroups() { if r.Groups == nil { r.Groups = make(map[int64]*recipient.Group) } diff --git a/internal/config/rule.go b/internal/config/rule.go index cfb8ccf3..f630b9d1 100644 --- a/internal/config/rule.go +++ b/internal/config/rule.go @@ -2,30 +2,27 @@ package config import ( "context" - "github.com/icinga/icingadb/pkg/icingadb" - "github.com/icinga/icingadb/pkg/logging" "github.com/icinga/noma/internal/filter" "github.com/icinga/noma/internal/rule" "github.com/icinga/noma/internal/utils" "github.com/jmoiron/sqlx" "go.uber.org/zap" - "log" ) -func (r *RuntimeConfig) fetchRules(ctx context.Context, db *icingadb.DB, tx *sqlx.Tx, logger *logging.Logger) error { +func (r *RuntimeConfig) fetchRules(ctx context.Context, tx *sqlx.Tx) error { var rulePtr *rule.Rule - stmt := db.BuildSelectStmt(rulePtr, rulePtr) - log.Println(stmt) + stmt := r.db.BuildSelectStmt(rulePtr, rulePtr) + r.logger.Debugf("Executing query %q", stmt) var rules []*rule.Rule if err := tx.SelectContext(ctx, &rules, stmt); err != nil { - log.Println(err) + r.logger.Errorln(err) return err } rulesByID := make(map[int64]*rule.Rule) for _, ru := range rules { - ruleLogger := logger.With( + ruleLogger := r.logger.With( zap.Int64("id", ru.ID), zap.String("name", ru.Name), zap.String("object_filter", ru.ObjectFilterExpr.String), @@ -49,18 +46,18 @@ func (r *RuntimeConfig) fetchRules(ctx context.Context, db *icingadb.DB, tx *sql } var escalationPtr *rule.Escalation - stmt = db.BuildSelectStmt(escalationPtr, escalationPtr) - log.Println(stmt) + stmt = r.db.BuildSelectStmt(escalationPtr, escalationPtr) + r.logger.Debugf("Executing query %q", stmt) var escalations []*rule.Escalation if err := tx.SelectContext(ctx, &escalations, stmt); err != nil { - log.Println(err) + r.logger.Errorln(err) return err } escalationsByID := make(map[int64]*rule.Escalation) for _, escalation := range escalations { - escalationLogger := logger.With( + escalationLogger := r.logger.With( zap.Int64("id", escalation.ID), zap.Int64("rule_id", escalation.RuleID), zap.String("condition", escalation.ConditionExpr.String), @@ -100,17 +97,17 @@ func (r *RuntimeConfig) fetchRules(ctx context.Context, db *icingadb.DB, tx *sql } var recipientPtr *rule.EscalationRecipient - stmt = db.BuildSelectStmt(recipientPtr, recipientPtr) - log.Println(stmt) + stmt = r.db.BuildSelectStmt(recipientPtr, recipientPtr) + r.logger.Debugf("Executing query %q", stmt) var recipients []*rule.EscalationRecipient if err := tx.SelectContext(ctx, &recipients, stmt); err != nil { - log.Println(err) + r.logger.Errorln(err) return err } for _, recipient := range recipients { - recipientLogger := logger.With( + recipientLogger := r.logger.With( zap.Int64("id", recipient.ID), zap.Int64("escalation_id", recipient.EscalationID), zap.String("channel_type", recipient.ChannelType.String)) @@ -138,7 +135,7 @@ func (r *RuntimeConfig) fetchRules(ctx context.Context, db *icingadb.DB, tx *sql return nil } -func (r *RuntimeConfig) applyPendingRules(logger *logging.Logger) { +func (r *RuntimeConfig) applyPendingRules() { if r.Rules == nil { r.Rules = make(map[int64]*rule.Rule) } @@ -147,7 +144,7 @@ func (r *RuntimeConfig) applyPendingRules(logger *logging.Logger) { if pendingRule == nil { delete(r.Rules, id) } else { - ruleLogger := logger.With( + ruleLogger := r.logger.With( zap.Int64("id", pendingRule.ID), zap.String("name", pendingRule.Name), zap.String("object_filter", pendingRule.ObjectFilterExpr.String), @@ -165,7 +162,7 @@ func (r *RuntimeConfig) applyPendingRules(logger *logging.Logger) { for _, escalation := range pendingRule.Escalations { for i, recipient := range escalation.Recipients { - recipientLogger := logger.With( + recipientLogger := r.logger.With( zap.Int64("id", recipient.ID), zap.Int64("escalation_id", recipient.EscalationID), zap.String("channel_type", recipient.ChannelType.String)) diff --git a/internal/config/runtime.go b/internal/config/runtime.go index 349570b9..8336c604 100644 --- a/internal/config/runtime.go +++ b/internal/config/runtime.go @@ -24,10 +24,17 @@ type RuntimeConfig struct { // pending contains changes to config objects that are to be applied to the embedded live config. pending ConfigSet + logger *logging.Logger + db *icingadb.DB + // mu is used to synchronize access to the live ConfigSet. mu sync.RWMutex } +func NewRuntimeConfig(db *icingadb.DB, logger *logging.Logger) *RuntimeConfig { + return &RuntimeConfig{db: db, logger: logger} +} + type ConfigSet struct { Channels map[string]*channel.Channel Contacts map[int64]*recipient.Contact @@ -38,13 +45,13 @@ type ConfigSet struct { Rules map[int64]*rule.Rule } -func (r *RuntimeConfig) UpdateFromDatabase(ctx context.Context, db *icingadb.DB, logger *logging.Logger) error { - err := r.fetchFromDatabase(ctx, db, logger) +func (r *RuntimeConfig) UpdateFromDatabase(ctx context.Context) error { + err := r.fetchFromDatabase(ctx) if err != nil { return err } - r.applyPending(logger) + r.applyPending() err = r.debugVerify() if err != nil { @@ -54,17 +61,17 @@ func (r *RuntimeConfig) UpdateFromDatabase(ctx context.Context, db *icingadb.DB, return nil } -func (r *RuntimeConfig) PeriodicUpdates(ctx context.Context, db *icingadb.DB, logger *logging.Logger, interval time.Duration) { +func (r *RuntimeConfig) PeriodicUpdates(ctx context.Context, interval time.Duration) { ticker := time.NewTicker(interval) defer ticker.Stop() for { select { case <-ticker.C: - logger.Debug("periodically updating config") - err := r.UpdateFromDatabase(ctx, db, logger) + r.logger.Debug("periodically updating config") + err := r.UpdateFromDatabase(ctx) if err != nil { - logger.Errorw("periodic config update failed, continuing with previous config", zap.Error(err)) + r.logger.Errorw("periodic config update failed, continuing with previous config", zap.Error(err)) } case <-ctx.Done(): break @@ -129,14 +136,14 @@ func (r *RuntimeConfig) GetContact(username string) *recipient.Contact { return nil } -func (r *RuntimeConfig) fetchFromDatabase(ctx context.Context, db *icingadb.DB, logger *logging.Logger) error { - logger.Debug("fetching configuration from database") +func (r *RuntimeConfig) fetchFromDatabase(ctx context.Context) error { + r.logger.Debug("fetching configuration from database") start := time.Now() // Reset all pending state to start from a clean state. r.pending = ConfigSet{} - tx, err := db.BeginTxx(ctx, &sql.TxOptions{ + tx, err := r.db.BeginTxx(ctx, &sql.TxOptions{ Isolation: sql.LevelRepeatableRead, ReadOnly: true, }) @@ -146,7 +153,7 @@ func (r *RuntimeConfig) fetchFromDatabase(ctx context.Context, db *icingadb.DB, // The transaction is only used for reading, never has to be committed. defer func() { _ = tx.Rollback() }() - updateFuncs := []func(ctx context.Context, db *icingadb.DB, tx *sqlx.Tx, logger *logging.Logger) error{ + updateFuncs := []func(ctx context.Context, tx *sqlx.Tx) error{ r.fetchChannels, r.fetchContacts, r.fetchContactAddresses, @@ -156,30 +163,30 @@ func (r *RuntimeConfig) fetchFromDatabase(ctx context.Context, db *icingadb.DB, r.fetchRules, } for _, f := range updateFuncs { - if err := f(ctx, db, tx, logger); err != nil { + if err := f(ctx, tx); err != nil { return err } } - logger.Debugw("fetched configuration from database", zap.Duration("took", time.Since(start))) + r.logger.Debugw("fetched configuration from database", zap.Duration("took", time.Since(start))) return nil } -func (r *RuntimeConfig) applyPending(logger *logging.Logger) { +func (r *RuntimeConfig) applyPending() { r.mu.Lock() defer r.mu.Unlock() - logger.Debug("applying pending configuration") + r.logger.Debug("applying pending configuration") start := time.Now() - r.applyPendingChannels(logger) - r.applyPendingContacts(logger) - r.applyPendingContactAddresses(logger) - r.applyPendingGroups(logger) - r.applyPendingTimePeriods(logger) - r.applyPendingSchedules(logger) - r.applyPendingRules(logger) + r.applyPendingChannels() + r.applyPendingContacts() + r.applyPendingContactAddresses() + r.applyPendingGroups() + r.applyPendingTimePeriods() + r.applyPendingSchedules() + r.applyPendingRules() - logger.Debugw("applied pending configuration", zap.Duration("took", time.Since(start))) + r.logger.Debugw("applied pending configuration", zap.Duration("took", time.Since(start))) } diff --git a/internal/config/schedule.go b/internal/config/schedule.go index a0f97556..43151639 100644 --- a/internal/config/schedule.go +++ b/internal/config/schedule.go @@ -2,22 +2,19 @@ package config import ( "context" - "github.com/icinga/icingadb/pkg/icingadb" - "github.com/icinga/icingadb/pkg/logging" "github.com/icinga/noma/internal/recipient" "github.com/jmoiron/sqlx" "go.uber.org/zap" - "log" ) -func (r *RuntimeConfig) fetchSchedules(ctx context.Context, db *icingadb.DB, tx *sqlx.Tx, logger *logging.Logger) error { +func (r *RuntimeConfig) fetchSchedules(ctx context.Context, tx *sqlx.Tx) error { var schedulePtr *recipient.Schedule - stmt := db.BuildSelectStmt(schedulePtr, schedulePtr) - log.Println(stmt) + stmt := r.db.BuildSelectStmt(schedulePtr, schedulePtr) + r.logger.Debugf("Executing query %q", stmt) var schedules []*recipient.Schedule if err := tx.SelectContext(ctx, &schedules, stmt); err != nil { - log.Println(err) + r.logger.Errorln(err) return err } @@ -25,23 +22,23 @@ func (r *RuntimeConfig) fetchSchedules(ctx context.Context, db *icingadb.DB, tx for _, g := range schedules { schedulesById[g.ID] = g - logger.Debugw("loaded schedule config", + r.logger.Debugw("loaded schedule config", zap.Int64("id", g.ID), zap.String("name", g.Name)) } var memberPtr *recipient.ScheduleMemberRow - stmt = db.BuildSelectStmt(memberPtr, memberPtr) - log.Println(stmt) + stmt = r.db.BuildSelectStmt(memberPtr, memberPtr) + r.logger.Debugf("Executing query %q", stmt) var members []*recipient.ScheduleMemberRow if err := tx.SelectContext(ctx, &members, stmt); err != nil { - log.Println(err) + r.logger.Errorln(err) return err } for _, member := range members { - memberLogger := makeScheduleMemberLogger(logger.SugaredLogger, member) + memberLogger := makeScheduleMemberLogger(r.logger.SugaredLogger, member) if s := schedulesById[member.ScheduleID]; s == nil { memberLogger.Warnw("ignoring schedule member for unknown schedule_id") @@ -66,7 +63,7 @@ func (r *RuntimeConfig) fetchSchedules(ctx context.Context, db *icingadb.DB, tx return nil } -func (r *RuntimeConfig) applyPendingSchedules(logger *logging.Logger) { +func (r *RuntimeConfig) applyPendingSchedules() { if r.Schedules == nil { r.Schedules = make(map[int64]*recipient.Schedule) } @@ -76,7 +73,7 @@ func (r *RuntimeConfig) applyPendingSchedules(logger *logging.Logger) { delete(r.Schedules, id) } else { for _, memberRow := range pendingSchedule.MemberRows { - memberLogger := makeScheduleMemberLogger(logger.SugaredLogger, memberRow) + memberLogger := makeScheduleMemberLogger(r.logger.SugaredLogger, memberRow) period := r.TimePeriods[memberRow.TimePeriodID] if period == nil { diff --git a/internal/config/timeperiod.go b/internal/config/timeperiod.go index 0a90b75c..7f6d0aa9 100644 --- a/internal/config/timeperiod.go +++ b/internal/config/timeperiod.go @@ -4,24 +4,21 @@ import ( "context" "database/sql" "fmt" - "github.com/icinga/icingadb/pkg/icingadb" - "github.com/icinga/icingadb/pkg/logging" "github.com/icinga/icingadb/pkg/types" "github.com/icinga/noma/internal/timeperiod" "github.com/jmoiron/sqlx" "go.uber.org/zap" - "log" "time" ) -func (r *RuntimeConfig) fetchTimePeriods(ctx context.Context, db *icingadb.DB, tx *sqlx.Tx, logger *logging.Logger) error { +func (r *RuntimeConfig) fetchTimePeriods(ctx context.Context, tx *sqlx.Tx) error { var timePeriodPtr *timeperiod.TimePeriod - stmt := db.BuildSelectStmt(timePeriodPtr, timePeriodPtr) - log.Println(stmt) + stmt := r.db.BuildSelectStmt(timePeriodPtr, timePeriodPtr) + r.logger.Debugf("Executing query %q", stmt) var timePeriods []*timeperiod.TimePeriod if err := tx.SelectContext(ctx, &timePeriods, stmt); err != nil { - log.Println(err) + r.logger.Errorln(err) return err } timePeriodsById := make(map[int64]*timeperiod.TimePeriod) @@ -40,19 +37,19 @@ func (r *RuntimeConfig) fetchTimePeriods(ctx context.Context, db *icingadb.DB, t } var entryPtr *TimeperiodEntry - stmt = db.BuildSelectStmt(entryPtr, entryPtr) - log.Println(stmt) + stmt = r.db.BuildSelectStmt(entryPtr, entryPtr) + r.logger.Debugf("Executing query %q", stmt) var entries []*TimeperiodEntry if err := tx.SelectContext(ctx, &entries, stmt); err != nil { - log.Println(err) + r.logger.Errorln(err) return err } for _, row := range entries { p := timePeriodsById[row.TimePeriodID] if p == nil { - logger.Warnw("ignoring entry for unknown timeperiod_id", + r.logger.Warnw("ignoring entry for unknown timeperiod_id", zap.Int64("timeperiod_entry_id", row.ID), zap.Int64("timeperiod_id", row.TimePeriodID)) continue @@ -67,7 +64,7 @@ func (r *RuntimeConfig) fetchTimePeriods(ctx context.Context, db *icingadb.DB, t loc, err := time.LoadLocation(row.Timezone) if err != nil { - logger.Warnw("ignoring time period entry with unknown timezone", + r.logger.Warnw("ignoring time period entry with unknown timezone", zap.Int64("timeperiod_entry_id", row.ID), zap.String("timezone", row.Timezone), zap.Error(err)) @@ -86,7 +83,7 @@ func (r *RuntimeConfig) fetchTimePeriods(ctx context.Context, db *icingadb.DB, t err = entry.Init() if err != nil { - logger.Warnw("ignoring time period entry", + r.logger.Warnw("ignoring time period entry", zap.Int64("timeperiod_entry_id", row.ID), zap.String("rrule", entry.RecurrenceRule), zap.Error(err)) @@ -95,7 +92,7 @@ func (r *RuntimeConfig) fetchTimePeriods(ctx context.Context, db *icingadb.DB, t p.Entries = append(p.Entries, entry) - logger.Debugw("loaded time period entry", + r.logger.Debugw("loaded time period entry", zap.String("timeperiod", p.Name), zap.Time("start", entry.Start), zap.Time("end", entry.End), @@ -122,7 +119,7 @@ func (r *RuntimeConfig) fetchTimePeriods(ctx context.Context, db *icingadb.DB, t return nil } -func (r *RuntimeConfig) applyPendingTimePeriods(logger *logging.Logger) { +func (r *RuntimeConfig) applyPendingTimePeriods() { if r.TimePeriods == nil { r.TimePeriods = make(map[int64]*timeperiod.TimePeriod) } diff --git a/internal/listener/listener.go b/internal/listener/listener.go index 87b71ff8..80a1e63c 100644 --- a/internal/listener/listener.go +++ b/internal/listener/listener.go @@ -5,6 +5,7 @@ import ( "encoding/json" "fmt" "github.com/icinga/icingadb/pkg/icingadb" + "github.com/icinga/icingadb/pkg/logging" "github.com/icinga/icingadb/pkg/types" "github.com/icinga/noma/internal/config" "github.com/icinga/noma/internal/event" @@ -13,7 +14,6 @@ import ( "github.com/icinga/noma/internal/recipient" "github.com/icinga/noma/internal/rule" "github.com/icinga/noma/internal/utils" - "log" "net/http" "time" ) @@ -21,14 +21,16 @@ import ( type Listener struct { configFile *config.ConfigFile db *icingadb.DB + logger *logging.Logger runtimeConfig *config.RuntimeConfig mux http.ServeMux } -func NewListener(db *icingadb.DB, configFile *config.ConfigFile, runtimeConfig *config.RuntimeConfig) *Listener { +func NewListener(db *icingadb.DB, configFile *config.ConfigFile, runtimeConfig *config.RuntimeConfig, logger *logging.Logger) *Listener { l := &Listener{ configFile: configFile, db: db, + logger: logger, runtimeConfig: runtimeConfig, } l.mux.HandleFunc("/process-event", l.ProcessEvent) @@ -38,7 +40,7 @@ func NewListener(db *icingadb.DB, configFile *config.ConfigFile, runtimeConfig * } func (l *Listener) Run() error { - log.Printf("Starting listener on http://%s", l.configFile.Listen) + l.logger.Infof("Starting listener on http://%s", l.configFile.Listen) return http.ListenAndServe(l.configFile.Listen, &l.mux) } @@ -85,7 +87,7 @@ func (l *Listener) ProcessEvent(w http.ResponseWriter, req *http.Request) { obj, err := object.FromTags(l.db, ev.Tags) if err != nil { - log.Println(err) + l.logger.Errorln(err) w.WriteHeader(http.StatusInternalServerError) _, _ = fmt.Fprintln(w, err.Error()) @@ -94,7 +96,7 @@ func (l *Listener) ProcessEvent(w http.ResponseWriter, req *http.Request) { err = obj.UpdateMetadata(ev.SourceId, ev.Name, utils.ToDBString(ev.URL), ev.ExtraTags) if err != nil { - log.Println(err) + l.logger.Errorln(err) w.WriteHeader(http.StatusInternalServerError) _, _ = fmt.Fprintln(w, err.Error()) @@ -102,7 +104,7 @@ func (l *Listener) ProcessEvent(w http.ResponseWriter, req *http.Request) { } if err = ev.Sync(l.db, obj.ID); err != nil { - log.Println(err) + l.logger.Errorln(err) w.WriteHeader(http.StatusInternalServerError) _, _ = fmt.Fprintln(w, err.Error()) @@ -120,7 +122,7 @@ func (l *Listener) ProcessEvent(w http.ResponseWriter, req *http.Request) { if err != nil { _, _ = fmt.Fprintln(w, err) - log.Println(err) + l.logger.Errorln(err) return } @@ -129,7 +131,7 @@ func (l *Listener) ProcessEvent(w http.ResponseWriter, req *http.Request) { msg := fmt.Sprintf("%q doesn't have active incident. Ignoring acknowledgement event from source %d", obj.DisplayName(), ev.SourceId) _, _ = fmt.Fprintln(w, msg) - log.Println(msg) + l.logger.Warnln(msg) return } @@ -137,7 +139,7 @@ func (l *Listener) ProcessEvent(w http.ResponseWriter, req *http.Request) { panic("non-OK state but no incident was created") } - log.Printf("%s: ignoring superfluous OK state event from source %d", obj.DisplayName(), ev.SourceId) + l.logger.Warnf("%s: ignoring superfluous OK state event from source %d", obj.DisplayName(), ev.SourceId) return } @@ -151,11 +153,11 @@ func (l *Listener) ProcessEvent(w http.ResponseWriter, req *http.Request) { if err != nil { _, _ = fmt.Fprintln(w, err) - log.Println(err) + l.logger.Errorln(err) return } - log.Printf("[%s %s] opened incident", obj.DisplayName(), currentIncident.String()) + l.logger.Infof("[%s %s] opened incident", obj.DisplayName(), currentIncident.String()) historyRow := &incident.HistoryRow{ Type: incident.Opened, @@ -167,18 +169,18 @@ func (l *Listener) ProcessEvent(w http.ResponseWriter, req *http.Request) { err = currentIncident.AddEvent(l.db, &ev) if err != nil { - log.Println(err) + l.logger.Errorln(err) return } - log.Println("processing event") + l.logger.Infof("processing event") if ev.Type == event.TypeAcknowledgement { err := l.ProcessAcknowledgementEvent(currentIncident, ev) if err != nil { _, _ = fmt.Fprintln(w, err) - log.Println(err) + l.logger.Errorln(err) } return @@ -199,13 +201,13 @@ func (l *Listener) ProcessEvent(w http.ResponseWriter, req *http.Request) { msg := fmt.Sprintf("%s: ignoring superfluous %q state event from source %d", obj.DisplayName(), ev.Severity.String(), ev.SourceId) _, _ = fmt.Fprintln(w, msg) - log.Println(msg) + l.logger.Warnln(msg) return } var causedByIncidentHistoryId types.Int if oldSourceSeverity != ev.Severity { - log.Printf( + l.logger.Infof( "[%s %s] source %d severity changed from %s to %s", obj.DisplayName(), currentIncident.String(), ev.SourceId, oldSourceSeverity.String(), ev.Severity.String(), @@ -224,7 +226,7 @@ func (l *Listener) ProcessEvent(w http.ResponseWriter, req *http.Request) { if err != nil { _, _ = fmt.Fprintln(w, err) - log.Println(err) + l.logger.Errorln(err) return } @@ -232,7 +234,7 @@ func (l *Listener) ProcessEvent(w http.ResponseWriter, req *http.Request) { if err != nil { _, _ = fmt.Fprintln(w, err) - log.Println(err) + l.logger.Errorln(err) return } @@ -244,7 +246,7 @@ func (l *Listener) ProcessEvent(w http.ResponseWriter, req *http.Request) { newIncidentSeverity := currentIncident.Severity() if newIncidentSeverity != oldIncidentSeverity { - log.Printf( + l.logger.Infof( "[%s %s] incident severity changed from %s to %s", obj.DisplayName(), currentIncident.String(), oldIncidentSeverity.String(), newIncidentSeverity.String(), @@ -254,7 +256,7 @@ func (l *Listener) ProcessEvent(w http.ResponseWriter, req *http.Request) { if err != nil { _, _ = fmt.Fprintln(w, err) - log.Println(err) + l.logger.Errorln(err) return } @@ -271,14 +273,14 @@ func (l *Listener) ProcessEvent(w http.ResponseWriter, req *http.Request) { if err != nil { _, _ = fmt.Fprintln(w, err) - log.Println(err) + l.logger.Errorln(err) return } } if newIncidentSeverity == event.SeverityOK { currentIncident.RecoveredAt = ev.Time - log.Printf("[%s %s] all sources recovered, closing incident", obj.DisplayName(), currentIncident.String()) + l.logger.Infof("[%s %s] all sources recovered, closing incident", obj.DisplayName(), currentIncident.String()) hr := &incident.HistoryRow{ EventID: utils.ToDBInt(ev.ID), @@ -289,7 +291,7 @@ func (l *Listener) ProcessEvent(w http.ResponseWriter, req *http.Request) { if err != nil { _, _ = fmt.Fprintln(w, err) - log.Println(err) + l.logger.Errorln(err) return } } @@ -316,7 +318,7 @@ func (l *Listener) ProcessEvent(w http.ResponseWriter, req *http.Request) { if r.ObjectFilter != nil { matched, err := r.ObjectFilter.Eval(obj) if err != nil { - log.Printf("[%s %s] rule %q failed to evaulte object filter: %s", obj.DisplayName(), currentIncident.String(), r.Name, err) + l.logger.Warnf("[%s %s] rule %q failed to evaluate object filter: %s", obj.DisplayName(), currentIncident.String(), r.Name, err) } if err != nil || !matched { @@ -325,7 +327,7 @@ func (l *Listener) ProcessEvent(w http.ResponseWriter, req *http.Request) { } currentIncident.Rules[r.ID] = struct{}{} - log.Printf("[%s %s] rule %q matches", obj.DisplayName(), currentIncident.String(), r.Name) + l.logger.Infof("[%s %s] rule %q matches", obj.DisplayName(), currentIncident.String(), r.Name) history := &incident.HistoryRow{ Time: types.UnixMilli(ev.Time), @@ -339,7 +341,7 @@ func (l *Listener) ProcessEvent(w http.ResponseWriter, req *http.Request) { if err != nil { _, _ = fmt.Fprintln(w, err) - log.Println(err) + l.logger.Errorln(err) return } @@ -371,7 +373,7 @@ func (l *Listener) ProcessEvent(w http.ResponseWriter, req *http.Request) { matched, err = escalation.Condition.Eval(cond) if err != nil { - log.Printf( + l.logger.Infof( "[%s %s] rule %q failed to evaulte escalation %q condition: %s", obj.DisplayName(), currentIncident.String(), r.Name, escalation.DisplayName(), err, ) @@ -407,7 +409,7 @@ func (l *Listener) ProcessEvent(w http.ResponseWriter, req *http.Request) { state.TriggeredAt = types.UnixMilli(ev.Time) r := l.runtimeConfig.Rules[escalation.RuleID] - log.Printf("[%s %s] rule %q reached escalation %q", obj.DisplayName(), currentIncident.String(), r.Name, escalation.DisplayName()) + l.logger.Infof("[%s %s] rule %q reached escalation %q", obj.DisplayName(), currentIncident.String(), r.Name, escalation.DisplayName()) history := &incident.HistoryRow{ Time: state.TriggeredAt, @@ -422,7 +424,7 @@ func (l *Listener) ProcessEvent(w http.ResponseWriter, req *http.Request) { if err != nil { _, _ = fmt.Fprintln(w, err) - log.Println(err) + l.logger.Errorln(err) return } @@ -430,7 +432,7 @@ func (l *Listener) ProcessEvent(w http.ResponseWriter, req *http.Request) { if err != nil { _, _ = fmt.Fprintln(w, err) - log.Println(err) + l.logger.Errorln(err) return } } @@ -486,28 +488,28 @@ func (l *Listener) ProcessEvent(w http.ResponseWriter, req *http.Request) { CausedByIncidentHistoryID: causedByIncidentHistoryId, } - log.Printf("[%s %s] notify %q via %q", obj.DisplayName(), currentIncident.String(), contact.FullName, chType) + l.logger.Infof("[%s %s] notify %q via %q", obj.DisplayName(), currentIncident.String(), contact.FullName, chType) _, err = currentIncident.AddHistory(hr, false) if err != nil { - log.Println(err) + l.logger.Errorln(err) } chConf := l.runtimeConfig.Channels[chType] if chConf == nil { - log.Printf("ERROR: could not find config for channel type %q", chType) + l.logger.Errorw("ERROR: could not find config for channel type %q", chType) continue } plugin, err := chConf.GetPlugin() if err != nil { - log.Printf("ERROR: could initialize channel type %q: %v", chType, err) + l.logger.Errorw("ERROR: could initialize channel type %q: %v", chType, err) continue } err = plugin.Send(contact, currentIncident, &ev, l.configFile.Icingaweb2URL) if err != nil { - log.Printf("ERROR: failed to send via channel type %q: %v", chType, err) + l.logger.Errorw("ERROR: failed to send via channel type %q: %v", chType, err) continue } } @@ -606,7 +608,7 @@ func (l *Listener) ProcessAcknowledgementEvent(i *incident.Incident, ev event.Ev i.Recipients[recipientKey] = &incident.RecipientState{Role: newRole} } - log.Printf("[%s %s] contact %q role changed from %s to %s", i.Object.DisplayName(), i.String(), contact.String(), oldRole.String(), newRole.String()) + l.logger.Infof("[%s %s] contact %q role changed from %s to %s", i.Object.DisplayName(), i.String(), contact.String(), oldRole.String(), newRole.String()) hr := &incident.HistoryRow{ Key: recipientKey,