diff --git a/internal/database/irc.go b/internal/database/irc.go index c5b2c9f..33ad49e 100644 --- a/internal/database/irc.go +++ b/internal/database/irc.go @@ -38,7 +38,7 @@ func (r *IrcRepo) GetNetworkByID(ctx context.Context, id int64) (*domain.IrcNetw if err != nil { return nil, errors.Wrap(err, "error building query") } - r.log.Trace().Str("database", "irc.check_existing_network").Msgf("query: '%v', args: '%v'", query, args) + r.log.Trace().Str("database", "irc.check_existing_network").Msgf("query: '%s', args: '%v'", query, args) var n domain.IrcNetwork @@ -243,13 +243,14 @@ func (r *IrcRepo) CheckExistingNetwork(ctx context.Context, network *domain.IrcN Select("id", "enabled", "name", "server", "port", "tls", "pass", "nick", "auth_mechanism", "auth_account", "auth_password", "invite_command", "bouncer_addr", "use_bouncer"). From("irc_network"). Where(sq.Eq{"server": network.Server}). - Where(sq.Eq{"auth_account": network.Auth.Account}) + Where(sq.Eq{"port": network.Port}). + Where(sq.Eq{"nick": network.Nick}) query, args, err := queryBuilder.ToSql() if err != nil { return nil, errors.Wrap(err, "error building query") } - r.log.Trace().Str("database", "irc.checkExistingNetwork").Msgf("query: '%v', args: '%v'", query, args) + r.log.Trace().Str("database", "irc.checkExistingNetwork").Msgf("query: '%s', args: '%v'", query, args) row := r.db.handler.QueryRowContext(ctx, query, args...) diff --git a/internal/irc/handler.go b/internal/irc/handler.go index 48e673f..0ca7d56 100644 --- a/internal/irc/handler.go +++ b/internal/irc/handler.go @@ -152,9 +152,9 @@ func (h *Handler) removeIndexer() { func (h *Handler) Run() error { // TODO validate // check if network requires nickserv - // chech if network or channels requires invite command + // check if network or channels requires invite command - addr := fmt.Sprintf("%v:%d", h.network.Server, h.network.Port) + addr := fmt.Sprintf("%s:%d", h.network.Server, h.network.Port) if h.network.UseBouncer && h.network.BouncerAddr != "" { addr = h.network.BouncerAddr @@ -209,6 +209,7 @@ func (h *Handler) Run() error { if err := func() error { // count connect attempts connectAttempts := 0 + disconnectTime := time.Now() // retry initial connect if network is down // using exponential backoff of 15 seconds @@ -221,10 +222,18 @@ func (h *Handler) Run() error { return err } - h.log.Debug().Msgf("connected at attempt %d", connectAttempts) + if connectAttempts > 0 { + h.log.Debug().Msgf("connected at attempt (%d) offline for %s", connectAttempts, time.Since(disconnectTime)) + return nil + } return nil }, + retry.OnRetry(func(n uint, err error) { + if n > 0 { + h.log.Debug().Msgf("%s connect attempt %d", h.network.Name, n) + } + }), retry.Delay(time.Second*15), retry.Attempts(25), retry.DelayType(func(n uint, err error, config *retry.Config) time.Duration { diff --git a/internal/irc/service.go b/internal/irc/service.go index 9eb7dd7..7913f8a 100644 --- a/internal/irc/service.go +++ b/internal/irc/service.go @@ -81,7 +81,7 @@ func (s *service) StartHandlers() { channels, err := s.repo.ListChannels(network.ID) if err != nil { - s.log.Error().Err(err).Msgf("failed to list channels for network %q", network.Server) + s.log.Error().Err(err).Msgf("failed to list channels for network: %s", network.Server) } for _, channel := range channels { @@ -103,11 +103,11 @@ func (s *service) StartHandlers() { s.handlers[network.ID] = handler s.lock.Unlock() - s.log.Debug().Msgf("starting network: %+v", network.Name) + s.log.Debug().Msgf("starting network: %s", network.Name) go func(network domain.IrcNetwork) { if err := handler.Run(); err != nil { - s.log.Error().Err(err).Msgf("failed to start handler for network %q", network.Name) + s.log.Error().Err(err).Msgf("failed to start handler for network: %s", network.Name) } }(network) } @@ -115,7 +115,7 @@ func (s *service) StartHandlers() { func (s *service) StopHandlers() { for _, handler := range s.handlers { - s.log.Info().Msgf("stopping network: %+v", handler.network.Name) + s.log.Info().Msgf("stopping network: %s", handler.network.Name) handler.Stop() } @@ -125,12 +125,12 @@ func (s *service) StopHandlers() { func (s *service) startNetwork(network domain.IrcNetwork) error { // look if we have the network in handlers already, if so start it if existingHandler, found := s.handlers[network.ID]; found { - s.log.Debug().Msgf("starting network: %+v", network.Name) + s.log.Debug().Msgf("starting network: %s", network.Name) if !existingHandler.client.Connected() { go func(handler *Handler) { if err := handler.Run(); err != nil { - s.log.Error().Err(err).Msgf("failed to start existingHandler for network %q", handler.network.Name) + s.log.Error().Err(err).Msgf("failed to start existing handler for network: %s", handler.network.Name) } }(existingHandler) } @@ -138,7 +138,7 @@ func (s *service) startNetwork(network domain.IrcNetwork) error { // if not found in handlers, lets add it and run it channels, err := s.repo.ListChannels(network.ID) if err != nil { - s.log.Error().Err(err).Msgf("failed to list channels for network %q", network.Server) + s.log.Error().Err(err).Msgf("failed to list channels for network: %s", network.Server) } for _, channel := range channels { @@ -158,11 +158,11 @@ func (s *service) startNetwork(network domain.IrcNetwork) error { s.handlers[network.ID] = handler s.lock.Unlock() - s.log.Debug().Msgf("starting network: %+v", network.Name) + s.log.Debug().Msgf("starting network: %s", network.Name) go func(network domain.IrcNetwork) { if err := handler.Run(); err != nil { - s.log.Error().Err(err).Msgf("failed to start handler for network %q", network.Name) + s.log.Error().Err(err).Msgf("failed to start handler for network: %s", network.Name) } }(network) } @@ -173,7 +173,7 @@ func (s *service) startNetwork(network domain.IrcNetwork) error { func (s *service) checkIfNetworkRestartNeeded(network *domain.IrcNetwork) error { // look if we have the network in handlers, if so restart it if existingHandler, found := s.handlers[network.ID]; found { - s.log.Debug().Msgf("irc: decide if irc network handler needs restart or updating: %+v", network.Server) + s.log.Debug().Msgf("irc: decide if irc network handler needs restart or updating: %s", network.Server) // if server, tls, invite command, port : changed - restart // if nickserv account, nickserv password : changed - stay connected, and change those @@ -181,18 +181,52 @@ func (s *service) checkIfNetworkRestartNeeded(network *domain.IrcNetwork) error if existingHandler.client.Connected() { handler := existingHandler.GetNetwork() restartNeeded := false + var fieldsChanged []string if handler.Server != network.Server { restartNeeded = true - } else if handler.Port != network.Port { - restartNeeded = true - } else if handler.TLS != network.TLS { - restartNeeded = true - } else if handler.InviteCommand != network.InviteCommand { - restartNeeded = true + fieldsChanged = append(fieldsChanged, "server") } + if handler.Port != network.Port { + restartNeeded = true + fieldsChanged = append(fieldsChanged, "port") + } + if handler.TLS != network.TLS { + restartNeeded = true + fieldsChanged = append(fieldsChanged, "tls") + } + if handler.Pass != network.Pass { + restartNeeded = true + fieldsChanged = append(fieldsChanged, "pass") + } + if handler.InviteCommand != network.InviteCommand { + restartNeeded = true + fieldsChanged = append(fieldsChanged, "invite command") + } + if handler.UseBouncer != network.UseBouncer { + restartNeeded = true + fieldsChanged = append(fieldsChanged, "use bouncer") + } + if handler.BouncerAddr != network.BouncerAddr { + restartNeeded = true + fieldsChanged = append(fieldsChanged, "bouncer addr") + } + if handler.Auth.Mechanism != network.Auth.Mechanism { + restartNeeded = true + fieldsChanged = append(fieldsChanged, "auth mechanism") + } + if handler.Auth.Account != network.Auth.Account { + restartNeeded = true + fieldsChanged = append(fieldsChanged, "auth account") + } + if handler.Auth.Password != network.Auth.Password { + restartNeeded = true + fieldsChanged = append(fieldsChanged, "auth password") + } + if restartNeeded { - s.log.Info().Msgf("irc: restarting network: %+v", network.Server) + s.log.Debug().Msgf("irc: fields %+v changed, restarting network: %s", fieldsChanged, network.Server) + s.log.Info().Msgf("irc: restarting network: %s", network.Server) // we need to reinitialize with new network config existingHandler.UpdateNetwork(network) @@ -201,7 +235,7 @@ func (s *service) checkIfNetworkRestartNeeded(network *domain.IrcNetwork) error go func() { if err := existingHandler.Restart(); err != nil { - s.log.Error().Stack().Err(err).Msgf("failed to restart network %q", existingHandler.network.Name) + s.log.Error().Stack().Err(err).Msgf("failed to restart network: %s", existingHandler.network.Name) } }() @@ -213,13 +247,7 @@ func (s *service) checkIfNetworkRestartNeeded(network *domain.IrcNetwork) error s.log.Debug().Msg("changing nick") if err := existingHandler.NickChange(network.Nick); err != nil { - s.log.Error().Stack().Err(err).Msgf("failed to change nick %q", network.Nick) - } - } else if handler.Auth.Password != network.Auth.Password { - s.log.Debug().Msg("nickserv: changing password") - - if err := existingHandler.NickServIdentify(network.Auth.Password); err != nil { - s.log.Error().Stack().Err(err).Msgf("failed to identify with nickserv %q", network.Nick) + s.log.Error().Err(err).Msgf("failed to change nick: %s", network.Nick) } } @@ -263,10 +291,10 @@ func (s *service) checkIfNetworkRestartNeeded(network *domain.IrcNetwork) error // leave channels for _, leaveChannel := range channelsToLeave { - s.log.Debug().Msgf("%v: part channel %v", network.Server, leaveChannel) + s.log.Debug().Msgf("%s: part channel %s", network.Server, leaveChannel) if err := existingHandler.PartChannel(leaveChannel); err != nil { - s.log.Error().Stack().Err(err).Msgf("failed to leave channel: %q", leaveChannel) + s.log.Error().Err(err).Msgf("failed to leave channel: %s", leaveChannel) } // create SSE stream for new channel @@ -275,10 +303,10 @@ func (s *service) checkIfNetworkRestartNeeded(network *domain.IrcNetwork) error // join channels for _, joinChannel := range channelsToJoin { - s.log.Debug().Msgf("%v: join new channel %v", network.Server, joinChannel) + s.log.Debug().Msgf("%s: join new channel %s", network.Server, joinChannel.Name) if err := existingHandler.JoinChannel(joinChannel.Name, joinChannel.Password); err != nil { - s.log.Error().Stack().Err(err).Msgf("failed to join channel: %q", joinChannel.Name) + s.log.Error().Err(err).Msgf("failed to join channel: %s", joinChannel.Name) } // create SSE stream for new channel @@ -296,7 +324,7 @@ func (s *service) checkIfNetworkRestartNeeded(network *domain.IrcNetwork) error } } else { if err := s.startNetwork(*network); err != nil { - s.log.Error().Stack().Err(err).Msgf("failed to start network: %q", network.Name) + s.log.Error().Err(err).Msgf("failed to start network: %s", network.Name) } } @@ -324,7 +352,7 @@ func (s *service) restartNetwork(network domain.IrcNetwork) error { func (s *service) StopNetwork(id int64) error { if handler, found := s.handlers[id]; found { handler.Stop() - s.log.Debug().Msgf("stopped network: %+v", handler.network.Server) + s.log.Debug().Msgf("stopped network: %s", handler.network.Server) } return nil @@ -341,7 +369,7 @@ func (s *service) StopAndRemoveNetwork(id int64) error { // remove from handlers delete(s.handlers, id) - s.log.Debug().Msgf("stopped network: %+v", id) + s.log.Debug().Msgf("stopped network: %d", id) } return nil @@ -350,7 +378,7 @@ func (s *service) StopAndRemoveNetwork(id int64) error { func (s *service) StopNetworkIfRunning(id int64) error { if handler, found := s.handlers[id]; found { handler.Stop() - s.log.Debug().Msgf("stopped network: %+v", handler.network.Server) + s.log.Debug().Msgf("stopped network: %s", handler.network.Server) } return nil @@ -359,13 +387,13 @@ func (s *service) StopNetworkIfRunning(id int64) error { func (s *service) GetNetworkByID(ctx context.Context, id int64) (*domain.IrcNetwork, error) { network, err := s.repo.GetNetworkByID(ctx, id) if err != nil { - s.log.Error().Err(err).Msgf("failed to get network: %v", id) + s.log.Error().Err(err).Msgf("failed to get network: %d", id) return nil, err } channels, err := s.repo.ListChannels(network.ID) if err != nil { - s.log.Error().Err(err).Msgf("failed to list channels for network %q", network.Server) + s.log.Error().Err(err).Msgf("failed to list channels for network: %s", network.Server) return nil, err } network.Channels = append(network.Channels, channels...) @@ -385,7 +413,7 @@ func (s *service) ListNetworks(ctx context.Context) ([]domain.IrcNetwork, error) for _, n := range networks { channels, err := s.repo.ListChannels(n.ID) if err != nil { - s.log.Error().Msgf("failed to list channels for network %q: %v", n.Server, err) + s.log.Error().Err(err).Msgf("failed to list channels for network: %s", n.Server) return nil, err } n.Channels = append(n.Channels, channels...) @@ -450,7 +478,7 @@ func (s *service) GetNetworksWithHealth(ctx context.Context) ([]domain.IrcNetwor channels, err := s.repo.ListChannels(n.ID) if err != nil { - s.log.Error().Msgf("failed to list channels for network %q: %v", n.Server, err) + s.log.Error().Err(err).Msgf("failed to list channels for network: %s", n.Server) return nil, err } @@ -496,21 +524,20 @@ func (s *service) GetNetworksWithHealth(ctx context.Context) ([]domain.IrcNetwor func (s *service) DeleteNetwork(ctx context.Context, id int64) error { network, err := s.GetNetworkByID(ctx, id) if err != nil { - s.log.Error().Stack().Err(err).Msgf("could not find network before delete: %v", network.Name) + s.log.Error().Err(err).Msgf("could not find network before delete: %d", id) return err } - s.log.Debug().Msgf("delete network: %v", id) + s.log.Debug().Msgf("delete network: %d %s", id, network.Name) // Remove network and handler - //if err = s.StopNetwork(network.Server); err != nil { if err = s.StopAndRemoveNetwork(network.ID); err != nil { - s.log.Error().Stack().Err(err).Msgf("could not stop and delete network: %v", network.Name) + s.log.Error().Err(err).Msgf("could not stop and delete network: %s", network.Name) return err } if err = s.repo.DeleteNetwork(ctx, id); err != nil { - s.log.Error().Stack().Err(err).Msgf("could not delete network: %v", network.Name) + s.log.Error().Err(err).Msgf("could not delete network: %s", network.Name) return err } @@ -518,7 +545,6 @@ func (s *service) DeleteNetwork(ctx context.Context, id int64) error { } func (s *service) UpdateNetwork(ctx context.Context, network *domain.IrcNetwork) error { - if network.Channels != nil { if err := s.repo.StoreNetworkChannels(ctx, network.ID, network.Channels); err != nil { return err @@ -528,7 +554,7 @@ func (s *service) UpdateNetwork(ctx context.Context, network *domain.IrcNetwork) if err := s.repo.UpdateNetwork(ctx, network); err != nil { return err } - s.log.Debug().Msgf("irc.service: update network: %+v", network) + s.log.Debug().Msgf("irc.service: update network: %s", network.Name) // stop or start network // TODO get current state to see if enabled or not? @@ -538,16 +564,16 @@ func (s *service) UpdateNetwork(ctx context.Context, network *domain.IrcNetwork) // if channels len : changes - join or leave err := s.checkIfNetworkRestartNeeded(network) if err != nil { - s.log.Error().Stack().Err(err).Msgf("could not restart network: %+v", network.Name) - return errors.New("could not restart network: %v", network.Name) + s.log.Error().Err(err).Msgf("could not restart network: %s", network.Name) + return errors.New("could not restart network: %s", network.Name) } } else { // take into account multiple channels per network err := s.StopAndRemoveNetwork(network.ID) if err != nil { - s.log.Error().Stack().Err(err).Msgf("could not stop network: %+v", network.Name) - return errors.New("could not stop network: %v", network.Name) + s.log.Error().Err(err).Msgf("could not stop network: %s", network.Name) + return errors.New("could not stop network: %s", network.Name) } } @@ -570,7 +596,7 @@ func (s *service) StoreNetwork(ctx context.Context, network *domain.IrcNetwork) if network.Channels != nil { for _, channel := range network.Channels { if err := s.repo.StoreChannel(ctx, network.ID, &channel); err != nil { - s.log.Error().Stack().Err(err).Msg("irc.storeChannel: error executing query") + s.log.Error().Err(err).Msg("irc.storeChannel: error executing query") return errors.Wrap(err, "error storing channel on network") } } @@ -582,7 +608,7 @@ func (s *service) StoreNetwork(ctx context.Context, network *domain.IrcNetwork) // get channels for existing network existingChannels, err := s.repo.ListChannels(existingNetwork.ID) if err != nil { - s.log.Error().Err(err).Msgf("failed to list channels for network %s", existingNetwork.Server) + s.log.Error().Err(err).Msgf("failed to list channels for network: %s", existingNetwork.Server) } existingNetwork.Channels = existingChannels