logger: Very initial working new logs

irc/client.go

@@ -402,7 +402,7 @@ func (client *Client) AllNickmasks() []string {
 // SetNickname sets the very first nickname for the client.
 func (client *Client) SetNickname(nickname string) error {
 	if client.HasNick() {
-		Log.error.Printf("%s nickname already set!", client.nickMaskString)
+		client.server.logger.Log(LogError, "nick", client.nick, fmt.Sprintf("%s nickname already set, something is wrong with server consistency", client.nickMaskString))
 		return ErrNickAlreadySet
 	}
 
@@ -543,7 +543,7 @@ var (
 		"NOTICE":  true,
 
 		RPL_WHOISCHANNELS: true,
-		RPL_USERHOST: true,
+		RPL_USERHOST:      true,
 	}
 )
 

irc/config.go

@@ -355,8 +355,10 @@ func LoadConfig(filename string) (config *Config, err error) {
 	if config.Limits.LineLen.Tags < 512 || config.Limits.LineLen.Rest < 512 {
 		return nil, errors.New("Line lengths must be 512 or greater (check the linelen section under server->limits)")
 	}
+	var newLogConfigs []LoggingConfig
 	for _, logConfig := range config.Logging {
 		// methods
+		logConfig.Methods = make(map[string]bool)
 		for _, method := range strings.Split(logConfig.Method, " ") {
 			if len(method) > 0 {
 				logConfig.Methods[strings.ToLower(method)] = true
@@ -374,6 +376,8 @@ func LoadConfig(filename string) (config *Config, err error) {
 		logConfig.Level = level
 
 		// types
+		logConfig.Types = make(map[string]bool)
+		logConfig.ExcludedTypes = make(map[string]bool)
 		for _, typeStr := range strings.Split(logConfig.TypeString, " ") {
 			if len(typeStr) == 0 {
 				continue
@@ -391,7 +395,10 @@ func LoadConfig(filename string) (config *Config, err error) {
 		if len(logConfig.Types) < 1 {
 			return nil, errors.New("Logger has no types to log")
 		}
+
+		newLogConfigs = append(newLogConfigs, logConfig)
 	}
+	config.Logging = newLogConfigs
 
 	return config, nil
 }

irc/logger.go

@@ -34,6 +34,12 @@ var (
 		"error":    LogError,
 		"errors":   LogError,
 	}
+	logLevelDisplayNames = map[LogLevel]string{
+		LogDebug: "debug",
+		LogInfo:  "info",
+		LogWarn:  "warning",
+		LogError: "error",
+	}
 )
 
 // ClientLogger is a logger dedicated to a single client. This is a convenience class that
@@ -77,7 +83,7 @@ func NewLogger(config []LoggingConfig) (*Logger, error) {
 			ExcludedTypes: logConfig.ExcludedTypes,
 		}
 		if sLogger.MethodFile.Enabled {
-			file, err := os.OpenFile(sLogger.MethodFile.Filename, os.O_APPEND, 0666)
+			file, err := os.OpenFile(sLogger.MethodFile.Filename, os.O_CREATE|os.O_APPEND|os.O_WRONLY, 0666)
 			if err != nil {
 				return nil, fmt.Errorf("Could not open log file %s [%s]", sLogger.MethodFile.Filename, err.Error())
 			}
@@ -85,6 +91,7 @@ func NewLogger(config []LoggingConfig) (*Logger, error) {
 			sLogger.MethodFile.File = file
 			sLogger.MethodFile.Writer = writer
 		}
+		logger.loggers = append(logger.loggers, sLogger)
 	}
 
 	return &logger, nil
@@ -132,7 +139,7 @@ func (logger *SingleLogger) Log(level LogLevel, logType, object, message string)
 	}
 
 	// assemble full line
-	fullString := fmt.Sprintf("%s : %s : %s : %s", time.Now().UTC().Format("2006-01-02T15:04:05.999Z"), logType, object, message)
+	fullString := fmt.Sprintf("%s : %s : %s : %s : %s", time.Now().UTC().Format("2006-01-02T15:04:05Z"), logLevelDisplayNames[level], logType, object, message)
 
 	// output
 	if logger.MethodSTDERR {

irc/server.go

@@ -136,18 +136,17 @@ type clientConn struct {
 }
 
 // NewServer returns a new Oragono server.
-func NewServer(configFilename string, config *Config) *Server {
+func NewServer(configFilename string, config *Config, logger *Logger) (*Server, error) {
 	casefoldedName, err := Casefold(config.Server.Name)
 	if err != nil {
-		log.Println(fmt.Sprintf("Server name isn't valid: [%s]", config.Server.Name), err.Error())
-		return nil
+		return nil, fmt.Errorf("Server name isn't valid [%s]: %s", config.Server.Name, err.Error())
 	}
 
 	// startup check that we have HELP entries for every command
 	for name := range Commands {
 		_, exists := Help[strings.ToLower(name)]
 		if !exists {
-			log.Fatal("Help entry does not exist for ", name)
+			return nil, fmt.Errorf("Help entry does not exist for command %s", name)
 		}
 	}
 
@@ -162,20 +161,20 @@ func NewServer(configFilename string, config *Config) *Server {
 
 	operClasses, err := config.OperatorClasses()
 	if err != nil {
-		log.Fatal("Error loading oper classes:", err.Error())
+		return nil, fmt.Errorf("Error loading oper classes: %s", err.Error())
 	}
 	opers, err := config.Operators(operClasses)
 	if err != nil {
-		log.Fatal("Error loading operators:", err.Error())
+		return nil, fmt.Errorf("Error loading operators: %s", err.Error())
 	}
 
 	connectionLimits, err := NewConnectionLimits(config.Server.ConnectionLimits)
 	if err != nil {
-		log.Fatal("Error loading connection limits:", err.Error())
+		return nil, fmt.Errorf("Error loading connection limits: %s", err.Error())
 	}
 	connectionThrottle, err := NewConnectionThrottle(config.Server.ConnectionThrottle)
 	if err != nil {
-		log.Fatal("Error loading connection throttler:", err.Error())
+		return nil, fmt.Errorf("Error loading connection throttler: %s", err.Error())
 	}
 
 	server := &Server{
@@ -204,6 +203,7 @@ func NewServer(configFilename string, config *Config) *Server {
 			},
 		},
 		listeners:      make(map[string]ListenerInterface),
+		logger:         logger,
 		monitoring:     make(map[string][]Client),
 		name:           config.Server.Name,
 		nameCasefolded: casefoldedName,
@@ -221,7 +221,7 @@ func NewServer(configFilename string, config *Config) *Server {
 	// open data store
 	db, err := buntdb.Open(config.Datastore.Path)
 	if err != nil {
-		log.Fatal(fmt.Sprintf("Failed to open datastore: %s", err.Error()))
+		return nil, fmt.Errorf("Failed to open datastore: %s", err.Error())
 	}
 	server.store = db
 
@@ -229,7 +229,7 @@ func NewServer(configFilename string, config *Config) *Server {
 	err = server.store.View(func(tx *buntdb.Tx) error {
 		version, _ := tx.Get(keySchemaVersion)
 		if version != latestDbSchema {
-			log.Println(fmt.Sprintf("Database must be updated. Expected schema v%s, got v%s.", latestDbSchema, version))
+			logger.Log(LogError, "startup", "server", fmt.Sprintf("Database must be updated. Expected schema v%s, got v%s.", latestDbSchema, version))
 			return errDbOutOfDate
 		}
 		return nil
@@ -237,7 +237,7 @@ func NewServer(configFilename string, config *Config) *Server {
 	if err != nil {
 		// close the db
 		db.Close()
-		return nil
+		return nil, errDbOutOfDate
 	}
 
 	// load *lines
@@ -261,7 +261,7 @@ func NewServer(configFilename string, config *Config) *Server {
 		return nil
 	})
 	if err != nil {
-		log.Fatal(fmt.Sprintf("Could not load salt: %s", err.Error()))
+		return nil, fmt.Errorf("Could not load salt: %s", err.Error())
 	}
 
 	if config.Server.MOTD != "" {
@@ -309,11 +309,11 @@ func NewServer(configFilename string, config *Config) *Server {
 
 	// start API if enabled
 	if server.restAPI.Enabled {
-		Log.info.Printf("%s rest API started on %s .", server.name, server.restAPI.Listen)
+		logger.Log(LogInfo, "startup", "server", fmt.Sprintf("%s rest API started on %s.", server.name, server.restAPI.Listen))
 		server.startRestAPI()
 	}
 
-	return server
+	return server, nil
 }
 
 // setISupport sets up our RPL_ISUPPORT reply.
@@ -378,7 +378,7 @@ func (server *Server) Shutdown() {
 	server.clients.ByNickMutex.RUnlock()
 
 	if err := server.store.Close(); err != nil {
-		Log.error.Println("Server.Shutdown store.Close: error:", err)
+		server.logger.Log(LogError, "shutdown", "db", fmt.Sprintln("Server.Shutdown store.Close: error:", err))
 	}
 }
 
@@ -398,7 +398,7 @@ func (server *Server) Run() {
 			// eventually we expect to use HUP to reload config
 			err := server.rehash()
 			if err != nil {
-				Log.error.Println("Failed to rehash:", err.Error())
+				server.logger.Log(LogError, "rehash", "server", fmt.Sprintln("Failed to rehash:", err.Error()))
 			}
 
 		case conn := <-server.newConns:
@@ -497,7 +497,7 @@ func (server *Server) createListener(addr string, tlsMap map[string]*tls.Config)
 	server.listeners[addr] = li
 
 	// start listening
-	Log.info.Printf("%s listening on %s using %s.", server.name, addr, tlsString)
+	server.logger.Log(LogInfo, "listeners", "listener", fmt.Sprintf("listening on %s using %s.", addr, tlsString))
 
 	// setup accept goroutine
 	go func() {
@@ -549,7 +549,7 @@ func (server *Server) createListener(addr string, tlsMap map[string]*tls.Config)
 					server.listenerUpdateMutex.Unlock()
 
 					// print notice
-					Log.info.Printf("%s updated listener %s using %s.", server.name, addr, tlsString)
+					server.logger.Log(LogInfo, "listeners", "listener", fmt.Sprintf("updated listener %s using %s.", addr, tlsString))
 				}
 			default:
 				// no events waiting for us, fall-through and continue
@@ -565,7 +565,7 @@ func (server *Server) createListener(addr string, tlsMap map[string]*tls.Config)
 func (server *Server) wslisten(addr string, tlsMap map[string]*TLSListenConfig) {
 	http.HandleFunc("/", func(w http.ResponseWriter, r *http.Request) {
 		if r.Method != "GET" {
-			Log.error.Printf("%s method not allowed", server.name)
+			server.logger.Log(LogError, "ws", addr, fmt.Sprintf("%s method not allowed", r.Method))
 			return
 		}
 
@@ -578,7 +578,7 @@ func (server *Server) wslisten(addr string, tlsMap map[string]*TLSListenConfig)
 
 		ws, err := upgrader.Upgrade(w, r, nil)
 		if err != nil {
-			Log.error.Printf("%s websocket upgrade error: %s", server.name, err)
+			server.logger.Log(LogError, "ws", addr, fmt.Sprintf("%s websocket upgrade error: %s", server.name, err))
 			return
 		}
 
@@ -596,7 +596,7 @@ func (server *Server) wslisten(addr string, tlsMap map[string]*TLSListenConfig)
 		if listenTLS {
 			tlsString = "TLS"
 		}
-		Log.info.Printf("%s websocket listening on %s using %s.", server.name, addr, tlsString)
+		server.logger.Log(LogInfo, "listeners", "listener", fmt.Sprintf("websocket listening on %s using %s.", addr, tlsString))
 
 		if listenTLS {
 			err = http.ListenAndServeTLS(addr, config.Cert, config.Key, nil)
@@ -604,7 +604,7 @@ func (server *Server) wslisten(addr string, tlsMap map[string]*TLSListenConfig)
 			err = http.ListenAndServe(addr, nil)
 		}
 		if err != nil {
-			Log.error.Printf("%s listenAndServe (%s) error: %s", server.name, tlsString, err)
+			server.logger.Log(LogError, "listeners", "listener", fmt.Sprintf("listenAndServe error [%s]: %s", tlsString, err))
 		}
 	}()
 }

oragono.go

@@ -43,6 +43,11 @@ Options:
 		log.Fatal("Config file did not load successfully:", err.Error())
 	}
 
+	logger, err := irc.NewLogger(config.Logging)
+	if err != nil {
+		log.Fatal("Logger did not load successfully:", err.Error())
+	}
+
 	if arguments["genpasswd"].(bool) {
 		fmt.Print("Enter Password: ")
 		bytePassword, err := terminal.ReadPassword(int(syscall.Stdin))
@@ -52,7 +57,7 @@ Options:
 		password := string(bytePassword)
 		encoded, err := irc.GenerateEncodedPassword(password)
 		if err != nil {
-			log.Fatalln("encoding error:", err)
+			log.Fatal("encoding error:", err.Error())
 		}
 		fmt.Print("\n")
 		fmt.Println(encoded)
@@ -84,16 +89,15 @@ Options:
 			}
 		}
 	} else if arguments["run"].(bool) {
-		irc.Log.SetLevel(config.Server.Log)
 		rand.Seed(time.Now().UTC().UnixNano())
-		server := irc.NewServer(configfile, config)
-		if server == nil {
-			log.Println("Could not load server")
+		server, err := irc.NewServer(configfile, config, logger)
+		if err != nil {
+			logger.Log(irc.LogError, "startup", "server", fmt.Sprintf("Could not load server: %s", err.Error()))
 			return
 		}
 		if !arguments["--quiet"].(bool) {
-			log.Println(fmt.Sprintf("Oragono v%s running", irc.SemVer))
-			defer log.Println(irc.SemVer, "exiting")
+			logger.Log(irc.LogInfo, "startup", "server", fmt.Sprintf("Oragono v%s running", irc.SemVer))
+			defer logger.Log(irc.LogInfo, "shutdown", "server", fmt.Sprintf("Oragono v%s exiting", irc.SemVer))
 		}
 		server.Run()
 	}