Leahnaya/wfc-server
1
0
Fork 0
mirror of https://github.com/WiiLink24/wfc-server.git synced 2026-09-07 16:15:30 -05:00
Code Issues Actions Packages Projects Releases Wiki Activity

Improvements to logging

Browse Source
This commit is contained in:
mkwcat
2023-10-24 23:09:50 -04:00
parent eca4f7f0ed
commit bf4c70ba4a
11 changed files with 98 additions and 65 deletions
Download Patch File Download Diff File Expand all files Collapse all files

6
database/login.go
View File

@@ -82,7 +82,7 @@ func LoginUserToGPCM(pool *pgxpool.Pool, ctx context.Context, authToken string)
// Query login table with the auth token.
userId, gsbrcd := GetNASLogin(pool, ctx, authToken)
if userId == 0 {
logging.Notice("DATABASE", "Invalid auth token:", aurora.Cyan(authToken).String())
logging.Error("DATABASE", "Invalid auth token:", aurora.Cyan(authToken))
return User{}, false
}
@@ -106,14 +106,14 @@ func LoginUserToGPCM(pool *pgxpool.Pool, ctx context.Context, authToken string)
// Create the GPCM account
user.CreateUser(pool, ctx)
logging.Notice("DATABASE", "Created new GPCM user:", aurora.Cyan(strconv.FormatInt(user.UserId, 10)).String(), aurora.Cyan(user.GsbrCode).String(), "-", aurora.Cyan(strconv.FormatInt(int64(user.ProfileId), 10)).String())
logging.Notice("DATABASE", "Created new GPCM user:", aurora.Cyan(strconv.FormatInt(user.UserId, 10)), aurora.Cyan(user.GsbrCode), "-", aurora.Cyan(strconv.FormatInt(int64(user.ProfileId), 10)))
} else {
err := pool.QueryRow(ctx, GetUserProfileID, userId, gsbrcd).Scan(&user.ProfileId)
if err != nil {
panic(err)
}
logging.Notice("DATABASE", "Log in GPCM user:", aurora.Cyan(strconv.FormatInt(user.UserId, 10)).String(), aurora.Cyan(user.GsbrCode).String(), "-", aurora.Cyan(strconv.FormatInt(int64(user.ProfileId), 10)).String())
logging.Notice("DATABASE", "Log in GPCM user:", aurora.Cyan(strconv.FormatInt(user.UserId, 10)), aurora.Cyan(user.GsbrCode), "-", aurora.Cyan(strconv.FormatInt(int64(user.ProfileId), 10)))
}
return user, true

4
gpcm/main.go
View File

@@ -107,7 +107,7 @@ func handleRequest(conn net.Conn) {
conn.Write([]byte(fmt.Sprintf(`\lc\1\challenge\%s\id\1\final\`, challenge)))
logging.Notice(session.ModuleName, "Connection established from", conn.RemoteAddr().String())
logging.Notice(session.ModuleName, "Connection established from", conn.RemoteAddr())
// Here we go into the listening loop
for {
@@ -132,7 +132,7 @@ func handleRequest(conn net.Conn) {
}
for _, command := range commands {
logging.Notice(session.ModuleName, "Command:", aurora.Yellow(command.Command).String())
logging.Notice(session.ModuleName, "Command:", aurora.Yellow(command.Command))
if session.LoggedIn == false {
if command.Command != "login" {

6
gpcm/profile.go
View File

@@ -70,7 +70,7 @@ func setStatus(session *GameSpySession, pool *pgxpool.Pool, ctx context.Context,
if statstring == "" {
logging.Notice(session.ModuleName, "statstring: (empty)")
} else {
logging.Notice(session.ModuleName, "statstring:", aurora.Cyan(statstring).String())
logging.Notice(session.ModuleName, "statstring:", aurora.Cyan(statstring))
}
}
@@ -82,7 +82,7 @@ func setStatus(session *GameSpySession, pool *pgxpool.Pool, ctx context.Context,
if locstring == "" {
logging.Notice(session.ModuleName, "locstring: (empty)")
} else {
logging.Notice(session.ModuleName, "locstring:", aurora.Cyan(locstring).String())
logging.Notice(session.ModuleName, "locstring:", aurora.Cyan(locstring))
}
}
@@ -122,7 +122,7 @@ func addFriend(session *GameSpySession, pool *pgxpool.Pool, ctx context.Context,
}
fc := common.CalcFriendCodeString(uint32(profileId), "RMCJ")
logging.Notice(session.ModuleName, "Add friend:", aurora.Cyan(strProfileId).String(), aurora.Cyan(fc).String())
logging.Notice(session.ModuleName, "Add friend:", aurora.Cyan(strProfileId), aurora.Cyan(fc))
// TODO
}

20
gpsp/main.go
View File

@@ -78,7 +78,7 @@ func handleRequest(conn net.Conn) {
logging.Notice(moduleName, "Unable to set keepalive:", err.Error())
}
logging.Notice(moduleName, "Connection established from", conn.RemoteAddr().String())
logging.Notice(moduleName, "Connection established from", aurora.BrightCyan(conn.RemoteAddr()))
// Here we go into the listening loop
for {
@@ -97,7 +97,7 @@ func handleRequest(conn net.Conn) {
}
for _, command := range commands {
logging.Notice(moduleName, "Command:", aurora.Yellow(command.Command).String())
logging.Notice(moduleName, "Command:", aurora.Yellow(command.Command))
switch command.Command {
case "ka":
conn.Write([]byte(`\ka\\final\`))
@@ -106,7 +106,7 @@ func handleRequest(conn net.Conn) {
case "otherslist":
strProfileId, ok := command.OtherValues["profileid"]
if !ok {
logging.Notice(moduleName, "Missing profileid in otherslist")
logging.Error(moduleName, "Missing profileid in otherslist")
return
}
@@ -120,7 +120,7 @@ func handleRequest(conn net.Conn) {
moduleName = "GPSP:" + strconv.FormatUint(profileId, 10)
moduleName += "/" + common.CalcFriendCodeString(uint32(profileId), "RMCJ")
} else if uint32(profileId) != knownProfileId {
logging.Notice(moduleName, "WARN: Mismatched profile ID in otherslist:", aurora.Cyan(strProfileId).String())
logging.Warn(moduleName, "Mismatched profile ID in otherslist:", aurora.Cyan(strProfileId))
}
conn.Write([]byte(handleOthersList(moduleName, uint32(profileId), command)))
@@ -135,25 +135,25 @@ func handleOthersList(moduleName string, profileId uint32, command common.GameSp
_, ok := command.OtherValues["sesskey"]
if !ok {
logging.Notice(moduleName, "Missing sesskey in otherslist")
logging.Error(moduleName, "Missing sesskey in otherslist")
return empty
}
numopids, ok := command.OtherValues["numopids"]
if !ok {
logging.Notice(moduleName, "Missing numopids in otherslist")
logging.Error(moduleName, "Missing numopids in otherslist")
return empty
}
opids, ok := command.OtherValues["opids"]
if !ok {
logging.Notice(moduleName, "Missing opids in otherslist")
logging.Error(moduleName, "Missing opids in otherslist")
return empty
}
_, ok = command.OtherValues["gamename"]
if !ok {
logging.Notice(moduleName, "Missing gamename in otherslist")
logging.Error(moduleName, "Missing gamename in otherslist")
return empty
}
@@ -164,7 +164,7 @@ func handleOthersList(moduleName string, profileId uint32, command common.GameSp
opidsSplit := strings.Split(opids, "|")
if len(opidsSplit) != numOpidsValue {
logging.Notice(moduleName, "Mismatch opids length with numopids:", aurora.Cyan(len(opidsSplit)).String(), "!=", aurora.Cyan(numOpidsValue).String())
logging.Error(moduleName, "Mismatch opids length with numopids:", aurora.Cyan(len(opidsSplit)), "!=", aurora.Cyan(numOpidsValue))
return empty
}
@@ -179,7 +179,7 @@ func handleOthersList(moduleName string, profileId uint32, command common.GameSp
// Also TODO: Check if the players are actually friends
user, ok := database.GetProfile(pool, ctx, uint32(otherId))
if !ok {
logging.Notice(moduleName, "Other ID doesn't exist:", aurora.Cyan(strOtherId).String())
logging.Error(moduleName, "Other ID doesn't exist:", aurora.Cyan(strOtherId))
// If the profile doesn't exist then skip adding it
continue
}

37
logging/log.go
View File

@@ -1,16 +1,47 @@
package logging
import (
"fmt"
"github.com/logrusorgru/aurora/v3"
"log"
)
func Notice(module string, arguments ...string) {
func Notice(module string, arguments ...any) {
var finalStr string
for _, argument := range arguments {
finalStr += argument
finalStr += fmt.Sprint(argument)
finalStr += " "
}
log.Printf("[%s]: %s", aurora.Green(module), finalStr)
log.Printf(aurora.BrightGreen("N[%s]").String()+": %s", module, finalStr)
}
func Error(module string, arguments ...any) {
var finalStr string
for _, argument := range arguments {
finalStr += fmt.Sprint(argument)
finalStr += " "
}
log.Printf(aurora.BrightRed("E[%s]").String()+": %s", module, finalStr)
}
func Warn(module string, arguments ...any) {
var finalStr string
for _, argument := range arguments {
finalStr += fmt.Sprint(argument)
finalStr += " "
}
log.Printf(aurora.BrightYellow("W[%s]").String()+": %s", module, finalStr)
}
func Info(module string, arguments ...any) {
var finalStr string
for _, argument := range arguments {
finalStr += fmt.Sprint(argument)
finalStr += " "
}
log.Printf(aurora.BrightCyan("I[%s]").String()+": %s", module, finalStr)
}

24
matchmaking/main.go
View File

@@ -87,14 +87,16 @@ func handleRequest(conn net.Conn) {
err := conn.(*net.TCPConn).SetKeepAlive(true)
if err != nil {
fmt.Printf("Unable to set keepalive - %s", err)
logging.Notice(ModuleName, "Unable to set keepalive", err.Error())
}
err = conn.(*net.TCPConn).SetKeepAlivePeriod(time.Hour * 1000)
if err != nil {
fmt.Printf("Unable to set keepalive - %s", err)
logging.Notice(ModuleName, "Unable to set keepalive", err.Error())
}
logging.Notice(ModuleName, "Connection established from", aurora.BrightCyan(conn.RemoteAddr()))
// Here we go into the listening loop
bufferSize := 0
packetSize := uint16(0)
@@ -110,7 +112,7 @@ func handleRequest(conn net.Conn) {
if bufferSize > 2 {
packetSize = binary.BigEndian.Uint16(buffer[:2])
if packetSize < 3 || packetSize >= 1024 {
logging.Notice(ModuleName, "Invalid packet size - terminating")
logging.Error(ModuleName, "Invalid packet size - terminating")
return
}
@@ -127,7 +129,7 @@ func handleRequest(conn net.Conn) {
return
}
logging.Notice(ModuleName, "Connection error")
logging.Error(ModuleName, "Connection error")
return
}
@@ -136,33 +138,33 @@ func handleRequest(conn net.Conn) {
switch buffer[2] {
case ServerListRequest:
logging.Notice(ModuleName, "Command:", aurora.Yellow("SERVER_LIST_REQUEST").String())
logging.Notice(ModuleName, "Command:", aurora.Yellow("SERVER_LIST_REQUEST"))
handleServerListRequest(conn, buffer[:packetSize])
break
case ServerInfoRequest:
logging.Notice(ModuleName, "Command:", aurora.Yellow("SERVER_INFO_REQUEST").String())
logging.Notice(ModuleName, "Command:", aurora.Yellow("SERVER_INFO_REQUEST"))
break
case SendMessageRequest:
logging.Notice(ModuleName, "Command:", aurora.Yellow("SEND_MESSAGE_REQUEST").String())
logging.Notice(ModuleName, "Command:", aurora.Yellow("SEND_MESSAGE_REQUEST"))
handleSendMessageRequest(conn, buffer[:packetSize])
break
case KeepaliveReply:
logging.Notice(ModuleName, "Command:", aurora.Yellow("KEEPALIVE_REPLY").String())
logging.Notice(ModuleName, "Command:", aurora.Yellow("KEEPALIVE_REPLY"))
break
case MapLoopRequest:
logging.Notice(ModuleName, "Command:", aurora.Yellow("MAPLOOP_REQUEST").String())
logging.Notice(ModuleName, "Command:", aurora.Yellow("MAPLOOP_REQUEST"))
break
case PlayerSearchRequest:
logging.Notice(ModuleName, "Command:", aurora.Yellow("PLAYER_SEARCH_REQUEST").String())
logging.Notice(ModuleName, "Command:", aurora.Yellow("PLAYER_SEARCH_REQUEST"))
break
default:
logging.Notice(ModuleName, "Unknown command:", aurora.Yellow(buffer[2]).String())
logging.Error(ModuleName, "Unknown command:", aurora.Cyan(buffer[2]))
break
}
}

24
matchmaking/server.go
View File

@@ -88,7 +88,7 @@ func handleServerListRequest(conn net.Conn, buffer []byte) {
if options&NoServerListOption != 0 || len(fieldList) == 0 {
// The client requests its own public IP and game port
logging.Notice(ModuleName, "Reply without server list", aurora.Cyan(conn.RemoteAddr()).String())
logging.Info(ModuleName, "Reply without server list", aurora.Cyan(conn.RemoteAddr()))
// The default game port 6500
output = binary.BigEndian.AppendUint16(output, 6500)
@@ -98,7 +98,7 @@ func handleServerListRequest(conn net.Conn, buffer []byte) {
return
}
logging.Notice(ModuleName, "Reply with server list", aurora.Cyan(conn.RemoteAddr()).String())
logging.Info(ModuleName, "Reply with server list", aurora.Cyan(conn.RemoteAddr()))
// The client's port
port, err := strconv.Atoi(strings.Split(conn.RemoteAddr().String(), ":")[1])
@@ -135,13 +135,13 @@ func handleServerListRequest(conn net.Conn, buffer []byte) {
var publicip string
if publicip, exists = server["publicip"]; !exists {
logging.Notice(ModuleName, "Server exists without public IP")
logging.Error(ModuleName, "Server exists without public IP")
continue
}
ip, err := strconv.ParseUint(publicip, 10, 32)
if err != nil {
logging.Notice(ModuleName, "Server has invalid public IP value")
logging.Error(ModuleName, "Server has invalid public IP value:", aurora.Cyan(publicip))
}
flagsBuffer = binary.BigEndian.AppendUint32(flagsBuffer, uint32(ip))
@@ -151,14 +151,14 @@ func handleServerListRequest(conn net.Conn, buffer []byte) {
if !exists {
// Fall back to local port if public port doesn't exist
if port, exists = server["localport"]; !exists {
logging.Notice(ModuleName, "Server exists without port")
logging.Error(ModuleName, "Server exists without port (publicip =", aurora.Cyan(publicip).String()+")")
continue
}
}
portValue, err := strconv.ParseUint(port, 10, 16)
if err != nil {
logging.Notice(ModuleName, "Server has invalid port value")
logging.Error(ModuleName, "Server has invalid port value:", aurora.Cyan(port))
continue
}
@@ -172,7 +172,7 @@ func handleServerListRequest(conn net.Conn, buffer []byte) {
// localip is written like "192.168.255.255" for example, so it needs to be parsed
ipSplit := strings.Split(localip0, ".")
if len(ipSplit) != 4 {
logging.Notice(ModuleName, "Server has invalid local IP")
logging.Error(ModuleName, "Server has invalid local IP:", aurora.Cyan(localip0))
continue
}
@@ -187,7 +187,7 @@ func handleServerListRequest(conn net.Conn, buffer []byte) {
}
if err != nil {
logging.Notice(ModuleName, "Server has invalid local IP value")
logging.Error(ModuleName, "Server has invalid local IP value:", aurora.Cyan(localip0))
continue
}
}
@@ -195,7 +195,7 @@ func handleServerListRequest(conn net.Conn, buffer []byte) {
if localport, exists := server["localport"]; exists {
portValue, err = strconv.ParseUint(localport, 10, 16)
if err != nil {
logging.Notice(ModuleName, "Server has invalid local port value")
logging.Error(ModuleName, "Server has invalid local port value:", aurora.Cyan(localport))
continue
}
@@ -214,7 +214,7 @@ func handleServerListRequest(conn net.Conn, buffer []byte) {
if (flags & HasKeysFlag) == 0 {
// Server does not have keys, so skip them
logging.Notice(ModuleName, "Wrote server without keys")
logging.Info(ModuleName, "Wrote server without keys")
continue
}
@@ -230,7 +230,7 @@ func handleServerListRequest(conn net.Conn, buffer []byte) {
output = append(output, 0x00)
}
logging.Notice(ModuleName, "Wrote server with keys")
logging.Info(ModuleName, "Wrote server with keys")
}
// Server with 0 flags and IP of 0xffffffff terminates the list
@@ -244,7 +244,7 @@ func handleSendMessageRequest(conn net.Conn, buffer []byte) {
// Read destination IP from buffer
destIP := fmt.Sprintf("%d.%d.%d.%d:%d", buffer[3], buffer[4], buffer[5], buffer[6], binary.BigEndian.Uint16(buffer[7:9]))
logging.Notice(ModuleName, "Send message from", aurora.Cyan(conn.RemoteAddr()).String(), "to", aurora.Cyan(destIP).String())
logging.Notice(ModuleName, "Send message from", aurora.BrightCyan(conn.RemoteAddr()), "to", aurora.BrightCyan(destIP).String())
// TODO: Perform basic packet verification
// TODO SECURITY: Check if the selected IP is actually online, or at least make sure it's not a local IP

10
nas/route.go
View File

@@ -48,15 +48,15 @@ func (r *RoutingGroup) HandleAction(action string, function func(*Response)) {
func (route *Route) Handle() http.Handler {
return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
logging.Notice("NAS", aurora.Yellow(r.Method).String(), aurora.Cyan(r.URL).String(), "via", aurora.Cyan(r.Host).String())
logging.Notice("NAS", aurora.Yellow(r.Method), aurora.Cyan(r.URL), "via", aurora.Cyan(r.Host))
err := r.ParseForm()
if err != nil {
logging.Notice("NAS", aurora.Red("Failed to parse form").String())
logging.Error("NAS", "Failed to parse form")
return
}
if !strings.HasPrefix(r.URL.Path, "/") {
logging.Notice("NAS", aurora.Red("Invalid URL").String())
logging.Error("NAS", "Invalid URL")
return
}
@@ -64,7 +64,7 @@ func (route *Route) Handle() http.Handler {
actionName, _ := base64.StdEncoding.DecodeString(strings.Replace(r.PostForm.Get("action"), "*", "=", -1))
if string(actionName) == "" {
logging.Notice("NAS", aurora.Red("No action in form").String())
logging.Error("NAS", "No action in form")
return
}
@@ -77,7 +77,7 @@ func (route *Route) Handle() http.Handler {
// Make sure we found an action
if action.ActionName == "" && action.ServiceType == "" {
logging.Notice("NAS", aurora.Red("No action for").String(), aurora.Yellow(string(actionName)).String())
logging.Error("NAS", "No action for", aurora.Cyan(string(actionName)))
return
}

4
qr2/heartbeat.go
View File

@@ -13,7 +13,7 @@ func heartbeat(conn net.PacketConn, addr net.Addr, buffer []byte) {
sessionId := binary.BigEndian.Uint32(buffer[1:5])
moduleName := "QR2:" + strconv.FormatInt(int64(sessionId), 10)
logging.Notice(moduleName, "Received heartbeat from", aurora.Cyan(addr).String())
logging.Info(moduleName, "Received heartbeat from", aurora.BrightCyan(addr))
values := strings.Split(string(buffer[5:]), "\u0000")
payload := map[string]string{}
@@ -23,7 +23,7 @@ func heartbeat(conn net.PacketConn, addr net.Addr, buffer []byte) {
}
payload[values[i]] = values[i+1]
logging.Notice(moduleName, aurora.Cyan(values[i]).String()+":", aurora.Cyan(values[i+1]).String())
logging.Info(moduleName, aurora.Cyan(values[i]).String()+":", aurora.Cyan(values[i+1]))
}
if statechanged, ok := payload["statechanged"]; ok {

24
qr2/main.go
View File

@@ -61,7 +61,7 @@ func StartServer() {
func handleConnection(conn net.PacketConn, addr net.Addr, buffer []byte) {
if buffer[0] == AvailableRequest {
logging.Notice("QR2", "Command:", aurora.Yellow("AVAILABLE").String())
logging.Notice("QR2", "Command:", aurora.Yellow("AVAILABLE"))
conn.WriteTo(createResponseHeader(AvailableRequest, 0), addr)
return
}
@@ -71,11 +71,11 @@ func handleConnection(conn net.PacketConn, addr net.Addr, buffer []byte) {
switch buffer[0] {
case QueryRequest:
logging.Notice(moduleName, "Command:", aurora.Yellow("QUERY").String())
logging.Notice(moduleName, "Command:", aurora.Yellow("QUERY"))
break
case ChallengeRequest:
logging.Notice(moduleName, "Command:", aurora.Yellow("CHALLENGE").String())
logging.Notice(moduleName, "Command:", aurora.Yellow("CHALLENGE"))
mutex.Lock()
sessions[sessionId].Authenticated = true
@@ -84,32 +84,32 @@ func handleConnection(conn net.PacketConn, addr net.Addr, buffer []byte) {
break
case EchoRequest:
logging.Notice(moduleName, "Command:", aurora.Yellow("ECHO").String())
logging.Notice(moduleName, "Command:", aurora.Yellow("ECHO"))
break
case HeartbeatRequest:
logging.Notice(moduleName, "Command:", aurora.Yellow("HEARTBEAT").String())
logging.Notice(moduleName, "Command:", aurora.Yellow("HEARTBEAT"))
heartbeat(conn, addr, buffer)
break
case AddErrorRequest:
logging.Notice(moduleName, "Command:", aurora.Yellow("ADDERROR").String())
logging.Notice(moduleName, "Command:", aurora.Yellow("ADDERROR"))
break
case EchoResponseRequest:
logging.Notice(moduleName, "Command:", aurora.Yellow("ECHO_RESPONSE").String())
logging.Notice(moduleName, "Command:", aurora.Yellow("ECHO_RESPONSE"))
break
case ClientMessageRequest:
logging.Notice(moduleName, "Command:", aurora.Yellow("CLIENT_MESSAGE").String())
logging.Notice(moduleName, "Command:", aurora.Yellow("CLIENT_MESSAGE"))
return
case ClientMessageAckRequest:
logging.Notice(moduleName, "Command:", aurora.Yellow("CLIENT_MESSAGE_ACK").String())
logging.Notice(moduleName, "Command:", aurora.Yellow("CLIENT_MESSAGE_ACK"))
return
case KeepAliveRequest:
logging.Notice(moduleName, "Command:", aurora.Yellow("KEEPALIVE").String())
logging.Notice(moduleName, "Command:", aurora.Yellow("KEEPALIVE"))
sessionId := binary.BigEndian.Uint32(buffer[1:5])
mutex.Lock()
sessions[sessionId].LastKeepAlive = time.Now().Unix()
@@ -120,11 +120,11 @@ func handleConnection(conn net.PacketConn, addr net.Addr, buffer []byte) {
return
case ClientRegisteredReply:
logging.Notice(moduleName, "Command:", aurora.Yellow("CLIENT_REGISTERED").String())
logging.Notice(moduleName, "Command:", aurora.Cyan("CLIENT_REGISTERED"))
break
default:
logging.Notice(moduleName, "Unknown command:", aurora.Yellow(buffer[0]).String())
logging.Error(moduleName, "Unknown command:", aurora.Yellow(buffer[0]))
return
}
}

4
qr2/session.go
View File

@@ -123,12 +123,12 @@ func SendClientMessage(destIP string, message []byte) {
panic(err)
}
logging.Notice("QR2", "Sending message...")
logging.Info("QR2", "Sending message")
masterConn.WriteTo(payload, destIPAddr)
return
}
}
mutex.Unlock()
logging.Notice("QR2", "Could not find destination server")
logging.Error("QR2", "Could not find destination server")
}