Add more verbose logging

common/friend_code.go

@@ -0,0 +1,32 @@
+package common
+
+import (
+	"crypto/md5"
+	"encoding/binary"
+	"fmt"
+)
+
+func CalcFriendCode(pid uint32, gameId string) uint64 {
+	if pid == 0 {
+		return 0
+	}
+
+	buffer := make([]byte, 8)
+	binary.LittleEndian.PutUint32(buffer, pid)
+	buffer[4] = gameId[3]
+	buffer[5] = gameId[2]
+	buffer[6] = gameId[1]
+	buffer[7] = gameId[0]
+
+	digest := md5.Sum(buffer)
+	return uint64(pid) | (uint64(digest[0]&0xfe) << 31)
+}
+
+func CalcFriendCodeString(pid uint32, gameId string) string {
+	return GetFriendCodeString(CalcFriendCode(pid, gameId))
+}
+
+func GetFriendCodeString(fc uint64) string {
+	s := fmt.Sprintf("%012d", fc)
+	return s[len(s)-12:len(s)-8] + "-" + s[len(s)-8:len(s)-4] + "-" + s[len(s)-4:]
+}

database/login.go

@@ -2,8 +2,12 @@ package database
 
 import (
 	"context"
-	"github.com/jackc/pgx/v4/pgxpool"
+	"database/sql"
 	"wwfc/common"
+	"wwfc/logging"
+
+	"github.com/jackc/pgx/v4/pgxpool"
+	"github.com/logrusorgru/aurora/v3"
 )
 
 const (
@@ -12,9 +16,29 @@ const (
 	UpdateUserLogin    = `UPDATE logins SET auth_token = $1 WHERE user_id = $2`
 	InsertUserLogin    = `INSERT INTO logins (auth_token, user_id, gsbrcd) VALUES ($1, $2, $3)`
 	GetNASUserLogin    = `SELECT user_id, gsbrcd FROM logins WHERE auth_token = $1 LIMIT 1`
+	GetUserAuthToken   = `SELECT auth_token FROM logins WHERE user_id = $1`
 )
 
 func GenerateAuthToken(pool *pgxpool.Pool, ctx context.Context, userId int, gsbrcd string) string {
+	var exists bool
+	err := pool.QueryRow(ctx, DoesNASUserExist, userId).Scan(&exists)
+	if err != nil {
+		panic(err)
+	}
+
+	if exists {
+		// Temporary(?) workaround for multiple sessions with the same user ID (i.e. multiple Dolphin instances).
+		// Just don't change the user's auth token... ever.
+		// TODO: What do we actually do here? Do we even care about proper authentication at this stage?
+		var authToken string
+		err := pool.QueryRow(ctx, GetUserAuthToken, userId).Scan(&authToken)
+		if err != nil {
+			panic(err)
+		}
+
+		return authToken
+	}
+
 	authToken := "NDS" + common.RandomString(80)
 	for {
 		// We must make sure that the auth token doesn't exist before attempting to insert it into the database.
@@ -31,12 +55,6 @@ func GenerateAuthToken(pool *pgxpool.Pool, ctx context.Context, userId int, gsbr
 		authToken = "NDS" + common.RandomString(80)
 	}
 
-	var exists bool
-	err := pool.QueryRow(ctx, DoesNASUserExist, userId).Scan(&exists)
-	if err != nil {
-		panic(err)
-	}
-
 	if exists {
 		// UPDATE rather than INSERT
 		_, err = pool.Exec(ctx, UpdateUserLogin, authToken, userId)
@@ -58,15 +76,23 @@ func GetNASLogin(pool *pgxpool.Pool, ctx context.Context, authToken string) (int
 	var gsbrcd string
 	err := pool.QueryRow(ctx, GetNASUserLogin, authToken).Scan(&userId, &gsbrcd)
 	if err != nil {
-		panic(err)
+		if err == sql.ErrNoRows {
+			return 0, ""
+		} else {
+			panic(err)
+		}
 	}
 
 	return userId, gsbrcd
 }
 
-func LoginUserToGCPM(pool *pgxpool.Pool, ctx context.Context, authToken string) User {
+func LoginUserToGPCM(pool *pgxpool.Pool, ctx context.Context, authToken string) (User, bool) {
 	// 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())
+		return User{}, false
+	}
 
 	var exists bool
 	err := pool.QueryRow(ctx, DoesUserExist, userId, gsbrcd).Scan(&exists)
@@ -88,11 +114,11 @@ func LoginUserToGCPM(pool *pgxpool.Pool, ctx context.Context, authToken string)
 		// Create the GPCM account
 		user.CreateUser(pool, ctx)
 	} else {
-		err := pool.QueryRow(ctx, GetUserProfileID, userId).Scan(&user.ProfileId)
+		err := pool.QueryRow(ctx, GetUserProfileID, userId, gsbrcd).Scan(&user.ProfileId)
 		if err != nil {
 			panic(err)
 		}
 	}
 
-	return user
+	return user, true
 }

database/user.go

@@ -3,9 +3,10 @@ package database
 import (
 	"context"
 	"errors"
+	"wwfc/common"
+
 	"github.com/jackc/pgx/v4"
 	"github.com/jackc/pgx/v4/pgxpool"
-	"wwfc/common"
 )
 
 const (
@@ -15,7 +16,7 @@ const (
 	CreateUserSession = `INSERT INTO sessions (session_key, profile_id, login_ticket) VALUES ($1, $2, $3)`
 	DoesUserExist     = `SELECT EXISTS(SELECT 1 FROM users WHERE user_id = $1 AND gsbrcd = $2)`
 	DeleteUserSession = `DELETE FROM sessions WHERE profile_id = $1`
-	GetUserProfileID  = `SELECT profile_id FROM users WHERE user_id = $1`
+	GetUserProfileID  = `SELECT profile_id FROM users WHERE user_id = $1 AND gsbrcd = $2`
 )
 
 type User struct {

gcsp/login.go

@@ -5,12 +5,13 @@ import (
 	"crypto/md5"
 	"encoding/base64"
 	"encoding/hex"
-	"github.com/jackc/pgx/v4/pgxpool"
 	"log"
 	"strconv"
 	"strings"
 	"wwfc/common"
 	"wwfc/database"
+
+	"github.com/jackc/pgx/v4/pgxpool"
 )
 
 func generateResponse(gpcmChallenge, nasChallenge, authToken, clientChallenge string) string {
@@ -43,9 +44,10 @@ func login(pool *pgxpool.Pool, ctx context.Context, command common.GameSpyComman
 	proof := generateProof(challenge, "0qUekMb4", command.OtherValues["authtoken"], command.OtherValues["challenge"])
 
 	// Perform the login with the database.
-	user := database.LoginUserToGCPM(pool, ctx, authToken)
+	// TODO: Check valid result
+	user, _ := database.LoginUserToGPCM(pool, ctx, authToken)
 	loginTicket := strings.Replace(base64.StdEncoding.EncodeToString([]byte(common.RandomString(16))), "=", "_", -1)
-	// TODO: REMOVE!!!!!
+	// TODO: Remove in favour of proper thread safe holding
 	userId = user.UserId
 	// Now initiate the session
 	_ = database.CreateSession(pool, ctx, user.ProfileId, loginTicket)

gcsp/main.go

@@ -5,8 +5,6 @@ import (
 	"context"
 	"errors"
 	"fmt"
-	"github.com/jackc/pgx/v4/pgxpool"
-	"github.com/logrusorgru/aurora/v3"
 	"io"
 	"log"
 	"net"
@@ -14,6 +12,9 @@ import (
 	"time"
 	"wwfc/common"
 	"wwfc/logging"
+
+	"github.com/jackc/pgx/v4/pgxpool"
+	"github.com/logrusorgru/aurora/v3"
 )
 
 var (
@@ -66,16 +67,15 @@ func handleRequest(conn net.Conn) {
 
 	err := conn.(*net.TCPConn).SetKeepAlive(true)
 	if err != nil {
-		fmt.Printf("Unable to set keepalive - %s", err)
+		logging.Notice("GCSP", "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("GCSP", "Unable to set keepalive:", err.Error())
 	}
 
-	// log.Printf("%s: Connection established from %s. Sending challenge.", aurora.Green("[NOTICE]"), aurora.Yellow(conn.RemoteAddr()))
-	// conn.Write([]byte(fmt.Sprintf(`\lc\1\challenge\%s\id\1\final\`, challenge)))
+	logging.Notice("GCSP", "Connection established from", conn.RemoteAddr().String())
 
 	// Here we go into the listening loop
 	for {
@@ -94,7 +94,7 @@ func handleRequest(conn net.Conn) {
 		}
 
 		for _, command := range commands {
-			logging.Notice("GCSP", "Message received. Command:", aurora.Yellow(command.Command).String())
+			logging.Notice("GCSP", "Command:", aurora.Yellow(command.Command).String())
 			switch command.Command {
 			case "ka":
 				conn.Write([]byte(`\ka\\final\`))

gpcm/login.go

@@ -5,12 +5,13 @@ import (
 	"crypto/md5"
 	"encoding/base64"
 	"encoding/hex"
-	"github.com/jackc/pgx/v4/pgxpool"
 	"log"
 	"strconv"
 	"strings"
 	"wwfc/common"
 	"wwfc/database"
+
+	"github.com/jackc/pgx/v4/pgxpool"
 )
 
 func generateResponse(gpcmChallenge, nasChallenge, authToken, clientChallenge string) string {
@@ -43,7 +44,8 @@ func login(pool *pgxpool.Pool, ctx context.Context, command common.GameSpyComman
 	proof := generateProof(challenge, "0qUekMb4", command.OtherValues["authtoken"], command.OtherValues["challenge"])
 
 	// Perform the login with the database.
-	user := database.LoginUserToGCPM(pool, ctx, authToken)
+	// TODO: Check valid result
+	user, _ := database.LoginUserToGPCM(pool, ctx, authToken)
 	loginTicket := strings.Replace(base64.StdEncoding.EncodeToString([]byte(common.RandomString(16))), "=", "_", -1)
 	// TODO: Remove in favour of proper thread safe holding
 	userId = user.UserId

gpcm/main.go

@@ -5,14 +5,16 @@ import (
 	"context"
 	"errors"
 	"fmt"
-	"github.com/jackc/pgx/v4/pgxpool"
-	"github.com/logrusorgru/aurora/v3"
 	"io"
 	"log"
 	"net"
 	"os"
 	"time"
 	"wwfc/common"
+	"wwfc/logging"
+
+	"github.com/jackc/pgx/v4/pgxpool"
+	"github.com/logrusorgru/aurora/v3"
 )
 
 var (
@@ -68,17 +70,20 @@ func handleRequest(conn net.Conn) {
 
 	err := conn.(*net.TCPConn).SetKeepAlive(true)
 	if err != nil {
-		fmt.Printf("Unable to set keepalive - %s", err)
+		logging.Notice("GPCM", "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("GPCM", "Unable to set keepalive:", err.Error())
 	}
 
-	log.Printf("%s: Connection established from %s. Sending challenge.", aurora.Green("[NOTICE]"), aurora.Yellow(conn.RemoteAddr()))
 	conn.Write([]byte(fmt.Sprintf(`\lc\1\challenge\%s\id\1\final\`, challenge)))
 
+	logging.Notice("GPCM", "Connection established from", conn.RemoteAddr().String())
+
+	loggedIn := false
+
 	// Here we go into the listening loop
 	for {
 		buffer := make([]byte, 1024)
@@ -92,20 +97,60 @@ func handleRequest(conn net.Conn) {
 
 		commands, err := common.ParseGameSpyMessage(string(buffer))
 		if err != nil {
-			log.Fatal(err)
+			logging.Notice("GPCM", "Error parsing message:", err.Error())
+			logging.Notice("GPCM", "Raw data:", string(buffer))
+			return
 		}
 
 		for _, command := range commands {
-			log.Printf("%s: Message received. Command: %s", aurora.Green("[NOTICE]"), aurora.Yellow(command.Command))
+			logging.Notice("GPCM", "Command:", aurora.Yellow(command.Command).String())
+
+			if loggedIn == false {
+				if command.Command != "login" {
+					logging.Notice("GPCM", "Attempt to run command before login!!!")
+					return
+				}
+
+				payload := login(pool, ctx, command, challenge)
+				if userId != 0 {
+					loggedIn = true
+				}
+
+				conn.Write([]byte(payload))
+			}
 		}
 
-		// Make sure update profile runs before get profile
+		// Make sure commands that update the profile run before getprofile
 		for _, command := range commands {
 			switch command.Command {
+			case "login":
+				// User should already be authenticated
+				break
+
+			case "logout":
+				// Bye
+				return
+
 			case "updatepro":
-				// Nothing is written here.
 				updateProfile(pool, ctx, command)
 				break
+
+			case "status":
+				logging.Notice("GPCM", "statstring:", aurora.Cyan(command.OtherValues["statstring"]).String())
+				if command.OtherValues["locstring"] == "" {
+					logging.Notice("GPCM", "locstring: (empty)")
+				} else {
+					logging.Notice("GPCM", "locstring:", aurora.Cyan(command.OtherValues["locstring"]).String())
+				}
+				break
+
+			case "addbuddy":
+				addFriend(pool, ctx, command)
+				break
+
+			case "delbuddy":
+				removeFriend(pool, ctx, command)
+				break
 			}
 		}
 
@@ -114,10 +159,7 @@ func handleRequest(conn net.Conn) {
 			case "ka":
 				conn.Write([]byte(`\ka\\final\`))
 				break
-			case "login":
-				payload := login(pool, ctx, command, challenge)
-				conn.Write([]byte(payload))
-				break
+
 			case "getprofile":
 				payload := getProfile(pool, ctx, command)
 				conn.Write([]byte(payload))

gpcm/profile.go

@@ -2,10 +2,13 @@ package gpcm
 
 import (
 	"context"
-	"github.com/jackc/pgx/v4/pgxpool"
 	"strconv"
 	"wwfc/common"
 	"wwfc/database"
+	"wwfc/logging"
+
+	"github.com/jackc/pgx/v4/pgxpool"
+	"github.com/logrusorgru/aurora/v3"
 )
 
 func getProfile(pool *pgxpool.Pool, ctx context.Context, command common.GameSpyCommand) string {
@@ -50,6 +53,24 @@ func updateProfile(pool *pgxpool.Pool, ctx context.Context, command common.GameS
 	database.UpdateUser(pool, ctx, firstName, lastName, userId)
 }
 
+func addFriend(pool *pgxpool.Pool, ctx context.Context, command common.GameSpyCommand) {
+	profileid := command.OtherValues["newprofileid"]
+
+	profileid_int, err := strconv.ParseUint(profileid, 10, 32)
+	if err != nil {
+		logging.Notice("GPCM", "Error parsing profileid:", err.Error())
+		return
+	}
+
+	fc := common.CalcFriendCodeString(uint32(profileid_int), "RMCJ")
+	logging.Notice("GPCM", "Add friend:", aurora.Cyan(profileid).String(), aurora.Cyan(fc).String())
+	// TODO
+}
+
+func removeFriend(pool *pgxpool.Pool, ctx context.Context, command common.GameSpyCommand) {
+	// TODO
+}
+
 func createStatus() string {
 	return common.CreateGameSpyMessage(common.GameSpyCommand{
 		Command:      "bm",