test: session lifecycle tests to reveal issues with sessions configuration.

This commit is contained in:
Houmgaor
2025-10-31 12:59:32 +01:00
parent a6cf550fdb
commit 2d3edcfd10
5 changed files with 2255 additions and 2 deletions

View File

@@ -0,0 +1,589 @@
package channelserver
import (
"bytes"
"fmt"
"io"
"net"
"sync"
"testing"
"time"
"erupe-ce/network/mhfpacket"
"erupe-ce/server/channelserver/compression/nullcomp"
)
// ============================================================================
// CLIENT CONNECTION SIMULATION TESTS
// Tests that simulate actual client connections, not just mock sessions
//
// Purpose: Test the complete connection lifecycle as a real client would
// - TCP connection establishment
// - Packet exchange
// - Graceful disconnect
// - Ungraceful disconnect
// - Network errors
// ============================================================================
// MockNetConn simulates a net.Conn for testing
type MockNetConn struct {
readBuf *bytes.Buffer
writeBuf *bytes.Buffer
closed bool
mu sync.Mutex
readErr error
writeErr error
}
func NewMockNetConn() *MockNetConn {
return &MockNetConn{
readBuf: new(bytes.Buffer),
writeBuf: new(bytes.Buffer),
}
}
func (m *MockNetConn) Read(b []byte) (n int, err error) {
m.mu.Lock()
defer m.mu.Unlock()
if m.closed {
return 0, io.EOF
}
if m.readErr != nil {
return 0, m.readErr
}
return m.readBuf.Read(b)
}
func (m *MockNetConn) Write(b []byte) (n int, err error) {
m.mu.Lock()
defer m.mu.Unlock()
if m.closed {
return 0, io.ErrClosedPipe
}
if m.writeErr != nil {
return 0, m.writeErr
}
return m.writeBuf.Write(b)
}
func (m *MockNetConn) Close() error {
m.mu.Lock()
defer m.mu.Unlock()
m.closed = true
return nil
}
func (m *MockNetConn) LocalAddr() net.Addr {
return &net.TCPAddr{IP: net.IPv4(127, 0, 0, 1), Port: 54001}
}
func (m *MockNetConn) RemoteAddr() net.Addr {
return &net.TCPAddr{IP: net.IPv4(127, 0, 0, 1), Port: 12345}
}
func (m *MockNetConn) SetDeadline(t time.Time) error {
return nil
}
func (m *MockNetConn) SetReadDeadline(t time.Time) error {
return nil
}
func (m *MockNetConn) SetWriteDeadline(t time.Time) error {
return nil
}
func (m *MockNetConn) QueueRead(data []byte) {
m.mu.Lock()
defer m.mu.Unlock()
m.readBuf.Write(data)
}
func (m *MockNetConn) GetWritten() []byte {
m.mu.Lock()
defer m.mu.Unlock()
return m.writeBuf.Bytes()
}
func (m *MockNetConn) IsClosed() bool {
m.mu.Lock()
defer m.mu.Unlock()
return m.closed
}
// TestClientConnection_GracefulLoginLogout simulates a complete client session
// This is closer to what a real client does than handler-only tests
func TestClientConnection_GracefulLoginLogout(t *testing.T) {
db := SetupTestDB(t)
defer TeardownTestDB(t, db)
server := createTestServerWithDB(t, db)
defer server.Shutdown()
userID := CreateTestUser(t, db, "client_test_user")
charID := CreateTestCharacter(t, db, userID, "ClientChar")
t.Log("Simulating client connection with graceful logout")
// Simulate client connecting
mockConn := NewMockNetConn()
session := createTestSessionForServerWithChar(server, charID, "ClientChar")
// In real scenario, this would be set up by the connection handler
// For testing, we test handlers directly without starting packet loops
// Client sends save packet
saveData := make([]byte, 150000)
copy(saveData[88:], []byte("ClientChar\x00"))
saveData[8000] = 0xAB
saveData[8001] = 0xCD
compressed, err := nullcomp.Compress(saveData)
if err != nil {
t.Fatalf("Failed to compress: %v", err)
}
savePkt := &mhfpacket.MsgMhfSavedata{
SaveType: 0,
AckHandle: 12001,
AllocMemSize: uint32(len(compressed)),
DataSize: uint32(len(compressed)),
RawDataPayload: compressed,
}
handleMsgMhfSavedata(session, savePkt)
time.Sleep(100 * time.Millisecond)
// Client sends logout packet (graceful)
t.Log("Client sending logout packet")
logoutPkt := &mhfpacket.MsgSysLogout{}
handleMsgSysLogout(session, logoutPkt)
time.Sleep(100 * time.Millisecond)
// Verify connection closed
if !mockConn.IsClosed() {
// Note: Our mock doesn't auto-close, but real session would
t.Log("Mock connection not closed (expected for mock)")
}
// Verify data saved
var savedCompressed []byte
err = db.QueryRow("SELECT savedata FROM characters WHERE id = $1", charID).Scan(&savedCompressed)
if err != nil {
t.Fatalf("Failed to query savedata: %v", err)
}
if len(savedCompressed) == 0 {
t.Error("❌ No data saved after graceful logout")
} else {
decompressed, _ := nullcomp.Decompress(savedCompressed)
if len(decompressed) > 8001 {
if decompressed[8000] == 0xAB && decompressed[8001] == 0xCD {
t.Log("✓ Data saved correctly after graceful logout")
} else {
t.Error("❌ Data corrupted")
}
}
}
}
// TestClientConnection_UngracefulDisconnect simulates network failure
func TestClientConnection_UngracefulDisconnect(t *testing.T) {
db := SetupTestDB(t)
defer TeardownTestDB(t, db)
server := createTestServerWithDB(t, db)
defer server.Shutdown()
userID := CreateTestUser(t, db, "disconnect_user")
charID := CreateTestCharacter(t, db, userID, "DisconnectChar")
t.Log("Simulating ungraceful client disconnect (network error)")
session := createTestSessionForServerWithChar(server, charID, "DisconnectChar")
// Note: Not calling Start() - testing handlers directly
time.Sleep(50 * time.Millisecond)
// Client saves some data
saveData := make([]byte, 150000)
copy(saveData[88:], []byte("DisconnectChar\x00"))
saveData[9000] = 0xEF
saveData[9001] = 0x12
compressed, _ := nullcomp.Compress(saveData)
savePkt := &mhfpacket.MsgMhfSavedata{
SaveType: 0,
AckHandle: 13001,
AllocMemSize: uint32(len(compressed)),
DataSize: uint32(len(compressed)),
RawDataPayload: compressed,
}
handleMsgMhfSavedata(session, savePkt)
time.Sleep(100 * time.Millisecond)
// Simulate network failure - connection drops without logout packet
t.Log("Simulating network failure (no logout packet sent)")
// In real scenario, recvLoop would detect io.EOF and call logoutPlayer
logoutPlayer(session)
time.Sleep(100 * time.Millisecond)
// Verify data was saved despite ungraceful disconnect
var savedCompressed []byte
err := db.QueryRow("SELECT savedata FROM characters WHERE id = $1", charID).Scan(&savedCompressed)
if err != nil {
t.Fatalf("Failed to query: %v", err)
}
if len(savedCompressed) == 0 {
t.Error("❌ CRITICAL: No data saved after ungraceful disconnect")
t.Error("This means players lose data when they have connection issues!")
} else {
t.Log("✓ Data saved even after ungraceful disconnect")
}
}
// TestClientConnection_SessionTimeout simulates timeout disconnect
func TestClientConnection_SessionTimeout(t *testing.T) {
db := SetupTestDB(t)
defer TeardownTestDB(t, db)
server := createTestServerWithDB(t, db)
defer server.Shutdown()
userID := CreateTestUser(t, db, "timeout_user")
charID := CreateTestCharacter(t, db, userID, "TimeoutChar")
t.Log("Simulating session timeout (30s no packets)")
session := createTestSessionForServerWithChar(server, charID, "TimeoutChar")
// Note: Not calling Start() - testing handlers directly
time.Sleep(50 * time.Millisecond)
// Save data
saveData := make([]byte, 150000)
copy(saveData[88:], []byte("TimeoutChar\x00"))
saveData[10000] = 0xFF
compressed, _ := nullcomp.Compress(saveData)
savePkt := &mhfpacket.MsgMhfSavedata{
SaveType: 0,
AckHandle: 14001,
AllocMemSize: uint32(len(compressed)),
DataSize: uint32(len(compressed)),
RawDataPayload: compressed,
}
handleMsgMhfSavedata(session, savePkt)
time.Sleep(100 * time.Millisecond)
// Simulate timeout by setting lastPacket to long ago
session.lastPacket = time.Now().Add(-35 * time.Second)
// In production, invalidateSessions() goroutine would detect this
// and call logoutPlayer(session)
t.Log("Session timed out (>30s since last packet)")
logoutPlayer(session)
time.Sleep(100 * time.Millisecond)
// Verify data saved
var savedCompressed []byte
err := db.QueryRow("SELECT savedata FROM characters WHERE id = $1", charID).Scan(&savedCompressed)
if err != nil {
t.Fatalf("Failed to query: %v", err)
}
if len(savedCompressed) == 0 {
t.Error("❌ CRITICAL: No data saved after timeout disconnect")
} else {
decompressed, _ := nullcomp.Decompress(savedCompressed)
if len(decompressed) > 10000 && decompressed[10000] == 0xFF {
t.Log("✓ Data saved correctly after timeout")
} else {
t.Error("❌ Data corrupted or not saved")
}
}
}
// TestClientConnection_MultipleClientsSimultaneous simulates multiple clients
func TestClientConnection_MultipleClientsSimultaneous(t *testing.T) {
db := SetupTestDB(t)
defer TeardownTestDB(t, db)
server := createTestServerWithDB(t, db)
defer server.Shutdown()
numClients := 3
var wg sync.WaitGroup
wg.Add(numClients)
t.Logf("Simulating %d clients connecting simultaneously", numClients)
for clientNum := 0; clientNum < numClients; clientNum++ {
go func(num int) {
defer wg.Done()
username := fmt.Sprintf("multi_client_%d", num)
charName := fmt.Sprintf("MultiClient%d", num)
userID := CreateTestUser(t, db, username)
charID := CreateTestCharacter(t, db, userID, charName)
session := createTestSessionForServerWithChar(server, charID, charName)
// Note: Not calling Start() - testing handlers directly
time.Sleep(30 * time.Millisecond)
// Each client saves their own data
saveData := make([]byte, 150000)
copy(saveData[88:], []byte(charName+"\x00"))
saveData[11000+num] = byte(num)
compressed, _ := nullcomp.Compress(saveData)
savePkt := &mhfpacket.MsgMhfSavedata{
SaveType: 0,
AckHandle: uint32(15000 + num),
AllocMemSize: uint32(len(compressed)),
DataSize: uint32(len(compressed)),
RawDataPayload: compressed,
}
handleMsgMhfSavedata(session, savePkt)
time.Sleep(50 * time.Millisecond)
// Graceful logout
logoutPlayer(session)
time.Sleep(50 * time.Millisecond)
// Verify individual client's data
var savedCompressed []byte
err := db.QueryRow("SELECT savedata FROM characters WHERE id = $1", charID).Scan(&savedCompressed)
if err != nil {
t.Errorf("Client %d: Failed to query: %v", num, err)
return
}
if len(savedCompressed) > 0 {
decompressed, _ := nullcomp.Decompress(savedCompressed)
if len(decompressed) > 11000+num {
if decompressed[11000+num] == byte(num) {
t.Logf("Client %d: ✓ Data saved correctly", num)
} else {
t.Errorf("Client %d: ❌ Data corrupted", num)
}
}
} else {
t.Errorf("Client %d: ❌ No data saved", num)
}
}(clientNum)
}
wg.Wait()
t.Log("All clients disconnected")
}
// TestClientConnection_SaveDuringCombat simulates saving while in quest
// This tests if being in a stage affects save behavior
func TestClientConnection_SaveDuringCombat(t *testing.T) {
db := SetupTestDB(t)
defer TeardownTestDB(t, db)
server := createTestServerWithDB(t, db)
defer server.Shutdown()
userID := CreateTestUser(t, db, "combat_user")
charID := CreateTestCharacter(t, db, userID, "CombatChar")
t.Log("Simulating save/logout while in quest/stage")
session := createTestSessionForServerWithChar(server, charID, "CombatChar")
// Simulate being in a stage (quest)
// In real scenario, session.stage would be set when entering quest
// For now, we'll just test the basic save/logout flow
// Note: Not calling Start() - testing handlers directly
time.Sleep(50 * time.Millisecond)
// Save data during "combat"
saveData := make([]byte, 150000)
copy(saveData[88:], []byte("CombatChar\x00"))
saveData[12000] = 0xAA
compressed, _ := nullcomp.Compress(saveData)
savePkt := &mhfpacket.MsgMhfSavedata{
SaveType: 0,
AckHandle: 16001,
AllocMemSize: uint32(len(compressed)),
DataSize: uint32(len(compressed)),
RawDataPayload: compressed,
}
handleMsgMhfSavedata(session, savePkt)
time.Sleep(100 * time.Millisecond)
// Disconnect while in stage
t.Log("Player disconnects during quest")
logoutPlayer(session)
time.Sleep(100 * time.Millisecond)
// Verify data saved even during combat
var savedCompressed []byte
err := db.QueryRow("SELECT savedata FROM characters WHERE id = $1", charID).Scan(&savedCompressed)
if err != nil {
t.Fatalf("Failed to query: %v", err)
}
if len(savedCompressed) > 0 {
decompressed, _ := nullcomp.Decompress(savedCompressed)
if len(decompressed) > 12000 && decompressed[12000] == 0xAA {
t.Log("✓ Data saved correctly even during quest")
} else {
t.Error("❌ Data not saved correctly during quest")
}
} else {
t.Error("❌ CRITICAL: No data saved when disconnecting during quest")
}
}
// TestClientConnection_ReconnectAfterCrash simulates client crash and reconnect
func TestClientConnection_ReconnectAfterCrash(t *testing.T) {
db := SetupTestDB(t)
defer TeardownTestDB(t, db)
server := createTestServerWithDB(t, db)
defer server.Shutdown()
userID := CreateTestUser(t, db, "crash_user")
charID := CreateTestCharacter(t, db, userID, "CrashChar")
t.Log("Simulating client crash and immediate reconnect")
// First session - client crashes
session1 := createTestSessionForServerWithChar(server, charID, "CrashChar")
// Not calling Start()
time.Sleep(50 * time.Millisecond)
// Save some data before crash
saveData := make([]byte, 150000)
copy(saveData[88:], []byte("CrashChar\x00"))
saveData[13000] = 0xBB
compressed, _ := nullcomp.Compress(saveData)
savePkt := &mhfpacket.MsgMhfSavedata{
SaveType: 0,
AckHandle: 17001,
AllocMemSize: uint32(len(compressed)),
DataSize: uint32(len(compressed)),
RawDataPayload: compressed,
}
handleMsgMhfSavedata(session1, savePkt)
time.Sleep(50 * time.Millisecond)
// Client crashes (ungraceful disconnect)
t.Log("Client crashes (no logout packet)")
logoutPlayer(session1)
time.Sleep(100 * time.Millisecond)
// Client reconnects immediately
t.Log("Client reconnects after crash")
session2 := createTestSessionForServerWithChar(server, charID, "CrashChar")
// Not calling Start()
time.Sleep(50 * time.Millisecond)
// Load data
loadPkt := &mhfpacket.MsgMhfLoaddata{
AckHandle: 18001,
}
handleMsgMhfLoaddata(session2, loadPkt)
time.Sleep(50 * time.Millisecond)
// Verify data from before crash
var savedCompressed []byte
err := db.QueryRow("SELECT savedata FROM characters WHERE id = $1", charID).Scan(&savedCompressed)
if err != nil {
t.Fatalf("Failed to query: %v", err)
}
if len(savedCompressed) > 0 {
decompressed, _ := nullcomp.Decompress(savedCompressed)
if len(decompressed) > 13000 && decompressed[13000] == 0xBB {
t.Log("✓ Data recovered correctly after crash")
} else {
t.Error("❌ Data lost or corrupted after crash")
}
} else {
t.Error("❌ CRITICAL: All data lost after crash")
}
logoutPlayer(session2)
}
// TestClientConnection_PacketDuringLogout tests race condition
// What happens if save packet arrives during logout?
func TestClientConnection_PacketDuringLogout(t *testing.T) {
db := SetupTestDB(t)
defer TeardownTestDB(t, db)
server := createTestServerWithDB(t, db)
defer server.Shutdown()
userID := CreateTestUser(t, db, "race_user")
charID := CreateTestCharacter(t, db, userID, "RaceChar")
t.Log("Testing race condition: packet during logout")
session := createTestSessionForServerWithChar(server, charID, "RaceChar")
// Note: Not calling Start() - testing handlers directly
time.Sleep(50 * time.Millisecond)
// Prepare save packet
saveData := make([]byte, 150000)
copy(saveData[88:], []byte("RaceChar\x00"))
saveData[14000] = 0xCC
compressed, _ := nullcomp.Compress(saveData)
savePkt := &mhfpacket.MsgMhfSavedata{
SaveType: 0,
AckHandle: 19001,
AllocMemSize: uint32(len(compressed)),
DataSize: uint32(len(compressed)),
RawDataPayload: compressed,
}
var wg sync.WaitGroup
wg.Add(2)
// Goroutine 1: Send save packet
go func() {
defer wg.Done()
handleMsgMhfSavedata(session, savePkt)
t.Log("Save packet processed")
}()
// Goroutine 2: Trigger logout (almost) simultaneously
go func() {
defer wg.Done()
time.Sleep(10 * time.Millisecond) // Small delay
logoutPlayer(session)
t.Log("Logout processed")
}()
wg.Wait()
time.Sleep(100 * time.Millisecond)
// Verify final state
var savedCompressed []byte
err := db.QueryRow("SELECT savedata FROM characters WHERE id = $1", charID).Scan(&savedCompressed)
if err != nil {
t.Fatalf("Failed to query: %v", err)
}
if len(savedCompressed) > 0 {
decompressed, _ := nullcomp.Decompress(savedCompressed)
if len(decompressed) > 14000 && decompressed[14000] == 0xCC {
t.Log("✓ Race condition handled correctly - data saved")
} else {
t.Error("❌ Race condition caused data corruption")
}
} else {
t.Error("❌ Race condition caused data loss")
}
}

View File

@@ -0,0 +1,536 @@
package channelserver
import (
"bytes"
"testing"
"erupe-ce/common/mhfitem"
"erupe-ce/network/mhfpacket"
"erupe-ce/server/channelserver/compression/nullcomp"
)
// ============================================================================
// SAVE/LOAD INTEGRATION TESTS
// Tests to verify user-reported save/load issues
//
// USER COMPLAINT SUMMARY:
// Features that ARE saved: RdP, items purchased, money spent, Hunter Navi
// Features that are NOT saved: current equipment, equipment sets, transmogs,
// crafted equipment, monster kill counter (Koryo), warehouse, inventory
// ============================================================================
// TestSaveLoad_RoadPoints tests that Road Points (RdP) are saved correctly
// User reports this DOES save correctly
func TestSaveLoad_RoadPoints(t *testing.T) {
db := SetupTestDB(t)
defer TeardownTestDB(t, db)
userID := CreateTestUser(t, db, "testuser")
charID := CreateTestCharacter(t, db, userID, "TestChar")
// Set initial Road Points
initialPoints := uint32(1000)
_, err := db.Exec("UPDATE characters SET frontier_points = $1 WHERE id = $2", initialPoints, charID)
if err != nil {
t.Fatalf("Failed to set initial road points: %v", err)
}
// Modify Road Points
newPoints := uint32(2500)
_, err = db.Exec("UPDATE characters SET frontier_points = $1 WHERE id = $2", newPoints, charID)
if err != nil {
t.Fatalf("Failed to update road points: %v", err)
}
// Verify Road Points persisted
var savedPoints uint32
err = db.QueryRow("SELECT frontier_points FROM characters WHERE id = $1", charID).Scan(&savedPoints)
if err != nil {
t.Fatalf("Failed to query road points: %v", err)
}
if savedPoints != newPoints {
t.Errorf("Road Points not saved correctly: got %d, want %d", savedPoints, newPoints)
} else {
t.Logf("✓ Road Points saved correctly: %d", savedPoints)
}
}
// TestSaveLoad_HunterNavi tests that Hunter Navi data is saved correctly
// User reports this DOES save correctly
func TestSaveLoad_HunterNavi(t *testing.T) {
db := SetupTestDB(t)
defer TeardownTestDB(t, db)
userID := CreateTestUser(t, db, "testuser")
charID := CreateTestCharacter(t, db, userID, "TestChar")
// Create test session
mock := &MockCryptConn{sentPackets: make([][]byte, 0)}
s := createTestSession(mock)
s.charID = charID
s.server.db = db
// Create Hunter Navi data
naviData := make([]byte, 552) // G8+ size
for i := range naviData {
naviData[i] = byte(i % 256)
}
// Save Hunter Navi
pkt := &mhfpacket.MsgMhfSaveHunterNavi{
AckHandle: 1234,
IsDataDiff: false, // Full save
RawDataPayload: naviData,
}
handleMsgMhfSaveHunterNavi(s, pkt)
// Verify saved
var saved []byte
err := db.QueryRow("SELECT hunternavi FROM characters WHERE id = $1", charID).Scan(&saved)
if err != nil {
t.Fatalf("Failed to query hunter navi: %v", err)
}
if len(saved) == 0 {
t.Error("Hunter Navi not saved")
} else if !bytes.Equal(saved, naviData) {
t.Error("Hunter Navi data mismatch")
} else {
t.Logf("✓ Hunter Navi saved correctly: %d bytes", len(saved))
}
}
// TestSaveLoad_MonsterKillCounter tests that Koryo points (kill counter) are saved
// User reports this DOES NOT save correctly
func TestSaveLoad_MonsterKillCounter(t *testing.T) {
db := SetupTestDB(t)
defer TeardownTestDB(t, db)
userID := CreateTestUser(t, db, "testuser")
charID := CreateTestCharacter(t, db, userID, "TestChar")
// Create test session
mock := &MockCryptConn{sentPackets: make([][]byte, 0)}
s := createTestSession(mock)
s.charID = charID
s.server.db = db
// Initial Koryo points
initialPoints := uint32(0)
err := db.QueryRow("SELECT kouryou_point FROM characters WHERE id = $1", charID).Scan(&initialPoints)
if err != nil {
t.Fatalf("Failed to query initial koryo points: %v", err)
}
// Add Koryo points (simulate killing monsters)
addPoints := uint32(100)
pkt := &mhfpacket.MsgMhfAddKouryouPoint{
AckHandle: 5678,
KouryouPoints: addPoints,
}
handleMsgMhfAddKouryouPoint(s, pkt)
// Verify points were added
var savedPoints uint32
err = db.QueryRow("SELECT kouryou_point FROM characters WHERE id = $1", charID).Scan(&savedPoints)
if err != nil {
t.Fatalf("Failed to query koryo points: %v", err)
}
expectedPoints := initialPoints + addPoints
if savedPoints != expectedPoints {
t.Errorf("Koryo points not saved correctly: got %d, want %d (BUG CONFIRMED)", savedPoints, expectedPoints)
} else {
t.Logf("✓ Koryo points saved correctly: %d", savedPoints)
}
}
// TestSaveLoad_Inventory tests that inventory (item_box) is saved correctly
// User reports this DOES NOT save correctly
func TestSaveLoad_Inventory(t *testing.T) {
db := SetupTestDB(t)
defer TeardownTestDB(t, db)
userID := CreateTestUser(t, db, "testuser")
_ = CreateTestCharacter(t, db, userID, "TestChar")
// Create test items
items := []mhfitem.MHFItemStack{
{Item: mhfitem.MHFItem{ItemID: 1001}, Quantity: 10},
{Item: mhfitem.MHFItem{ItemID: 1002}, Quantity: 20},
{Item: mhfitem.MHFItem{ItemID: 1003}, Quantity: 30},
}
// Serialize and save inventory
serialized := mhfitem.SerializeWarehouseItems(items)
_, err := db.Exec("UPDATE users SET item_box = $1 WHERE id = $2", serialized, userID)
if err != nil {
t.Fatalf("Failed to save inventory: %v", err)
}
// Reload inventory
var savedItemBox []byte
err = db.QueryRow("SELECT item_box FROM users WHERE id = $1", userID).Scan(&savedItemBox)
if err != nil {
t.Fatalf("Failed to load inventory: %v", err)
}
if len(savedItemBox) == 0 {
t.Error("Inventory not saved (BUG CONFIRMED)")
} else if !bytes.Equal(savedItemBox, serialized) {
t.Error("Inventory data mismatch (BUG CONFIRMED)")
} else {
t.Logf("✓ Inventory saved correctly: %d bytes", len(savedItemBox))
}
}
// TestSaveLoad_Warehouse tests that warehouse contents are saved correctly
// User reports this DOES NOT save correctly
func TestSaveLoad_Warehouse(t *testing.T) {
db := SetupTestDB(t)
defer TeardownTestDB(t, db)
userID := CreateTestUser(t, db, "testuser")
charID := CreateTestCharacter(t, db, userID, "TestChar")
// Create test equipment for warehouse
equipment := []mhfitem.MHFEquipment{
{ItemID: 100, WarehouseID: 1},
{ItemID: 101, WarehouseID: 2},
{ItemID: 102, WarehouseID: 3},
}
// Serialize and save to warehouse
serializedEquip := mhfitem.SerializeWarehouseEquipment(equipment)
// Update warehouse equip0
_, err := db.Exec("UPDATE warehouse SET equip0 = $1 WHERE character_id = $2", serializedEquip, charID)
if err != nil {
// Warehouse entry might not exist, try insert
_, err = db.Exec(`
INSERT INTO warehouse (character_id, equip0)
VALUES ($1, $2)
ON CONFLICT (character_id) DO UPDATE SET equip0 = $2
`, charID, serializedEquip)
if err != nil {
t.Fatalf("Failed to save warehouse: %v", err)
}
}
// Reload warehouse
var savedEquip []byte
err = db.QueryRow("SELECT equip0 FROM warehouse WHERE character_id = $1", charID).Scan(&savedEquip)
if err != nil {
t.Errorf("Failed to load warehouse: %v (BUG CONFIRMED)", err)
return
}
if len(savedEquip) == 0 {
t.Error("Warehouse not saved (BUG CONFIRMED)")
} else if !bytes.Equal(savedEquip, serializedEquip) {
t.Error("Warehouse data mismatch (BUG CONFIRMED)")
} else {
t.Logf("✓ Warehouse saved correctly: %d bytes", len(savedEquip))
}
}
// TestSaveLoad_CurrentEquipment tests that currently equipped gear is saved
// User reports this DOES NOT save correctly
func TestSaveLoad_CurrentEquipment(t *testing.T) {
db := SetupTestDB(t)
defer TeardownTestDB(t, db)
userID := CreateTestUser(t, db, "testuser")
charID := CreateTestCharacter(t, db, userID, "TestChar")
// Create test session
mock := &MockCryptConn{sentPackets: make([][]byte, 0)}
s := createTestSession(mock)
s.charID = charID
s.Name = "TestChar"
s.server.db = db
// Create savedata with equipped gear
// Equipment data is embedded in the main savedata blob
saveData := make([]byte, 150000)
copy(saveData[88:], []byte("TestChar\x00"))
// Set weapon type at known offset (simplified)
weaponTypeOffset := 500 // Example offset
saveData[weaponTypeOffset] = 0x03 // Great Sword
compressed, err := nullcomp.Compress(saveData)
if err != nil {
t.Fatalf("Failed to compress savedata: %v", err)
}
// Save equipment data
pkt := &mhfpacket.MsgMhfSavedata{
SaveType: 0, // Full blob
AckHandle: 1111,
AllocMemSize: uint32(len(compressed)),
DataSize: uint32(len(compressed)),
RawDataPayload: compressed,
}
handleMsgMhfSavedata(s, pkt)
// Drain ACK
if len(s.sendPackets) > 0 {
<-s.sendPackets
}
// Reload savedata
var savedCompressed []byte
err = db.QueryRow("SELECT savedata FROM characters WHERE id = $1", charID).Scan(&savedCompressed)
if err != nil {
t.Fatalf("Failed to load savedata: %v", err)
}
if len(savedCompressed) == 0 {
t.Error("Savedata (current equipment) not saved (BUG CONFIRMED)")
return
}
// Decompress and verify
decompressed, err := nullcomp.Decompress(savedCompressed)
if err != nil {
t.Errorf("Failed to decompress savedata: %v", err)
return
}
if len(decompressed) < weaponTypeOffset+1 {
t.Error("Savedata too short, equipment data missing (BUG CONFIRMED)")
return
}
if decompressed[weaponTypeOffset] != saveData[weaponTypeOffset] {
t.Errorf("Equipment data not saved correctly (BUG CONFIRMED): got 0x%02X, want 0x%02X",
decompressed[weaponTypeOffset], saveData[weaponTypeOffset])
} else {
t.Logf("✓ Current equipment saved in savedata")
}
}
// TestSaveLoad_EquipmentSets tests that equipment set configurations are saved
// User reports this DOES NOT save correctly (creation/modification/deletion)
func TestSaveLoad_EquipmentSets(t *testing.T) {
db := SetupTestDB(t)
defer TeardownTestDB(t, db)
userID := CreateTestUser(t, db, "testuser")
charID := CreateTestCharacter(t, db, userID, "TestChar")
// Equipment sets are stored in characters.platemyset
testSetData := []byte{
0x01, 0x02, 0x03, 0x04, 0x05,
0x10, 0x20, 0x30, 0x40, 0x50,
}
// Save equipment sets
_, err := db.Exec("UPDATE characters SET platemyset = $1 WHERE id = $2", testSetData, charID)
if err != nil {
t.Fatalf("Failed to save equipment sets: %v", err)
}
// Reload equipment sets
var savedSets []byte
err = db.QueryRow("SELECT platemyset FROM characters WHERE id = $1", charID).Scan(&savedSets)
if err != nil {
t.Fatalf("Failed to load equipment sets: %v", err)
}
if len(savedSets) == 0 {
t.Error("Equipment sets not saved (BUG CONFIRMED)")
} else if !bytes.Equal(savedSets, testSetData) {
t.Error("Equipment sets data mismatch (BUG CONFIRMED)")
} else {
t.Logf("✓ Equipment sets saved correctly: %d bytes", len(savedSets))
}
}
// TestSaveLoad_Transmog tests that transmog/appearance data is saved correctly
// User reports this DOES NOT save correctly
func TestSaveLoad_Transmog(t *testing.T) {
db := SetupTestDB(t)
defer TeardownTestDB(t, db)
userID := CreateTestUser(t, db, "testuser")
charID := CreateTestCharacter(t, db, userID, "TestChar")
// Create test session
mock := &MockCryptConn{sentPackets: make([][]byte, 0)}
s := createTestSession(mock)
s.charID = charID
s.server.db = db
// Create transmog/decoration set data
transmogData := make([]byte, 100)
for i := range transmogData {
transmogData[i] = byte((i * 3) % 256)
}
// Save transmog data
pkt := &mhfpacket.MsgMhfSaveDecoMyset{
AckHandle: 2222,
RawDataPayload: transmogData,
}
handleMsgMhfSaveDecoMyset(s, pkt)
// Verify saved
var saved []byte
err := db.QueryRow("SELECT decomyset FROM characters WHERE id = $1", charID).Scan(&saved)
if err != nil {
t.Fatalf("Failed to query transmog data: %v", err)
}
if len(saved) == 0 {
t.Error("Transmog data not saved (BUG CONFIRMED)")
} else {
// handleMsgMhfSaveDecoMyset merges data, so check if anything was saved
t.Logf("✓ Transmog data saved: %d bytes", len(saved))
}
}
// TestSaveLoad_CraftedEquipment tests that crafted/upgraded equipment persists
// User reports this DOES NOT save correctly
func TestSaveLoad_CraftedEquipment(t *testing.T) {
db := SetupTestDB(t)
defer TeardownTestDB(t, db)
userID := CreateTestUser(t, db, "testuser")
charID := CreateTestCharacter(t, db, userID, "TestChar")
// Crafted equipment would be stored in savedata or warehouse
// Let's test warehouse equipment with upgrade levels
// Create crafted equipment with upgrade level
equipment := []mhfitem.MHFEquipment{
{
ItemID: 5000, // Crafted weapon
WarehouseID: 12345,
// Upgrade level would be in equipment metadata
},
}
serialized := mhfitem.SerializeWarehouseEquipment(equipment)
// Save to warehouse
_, err := db.Exec(`
INSERT INTO warehouse (character_id, equip0)
VALUES ($1, $2)
ON CONFLICT (character_id) DO UPDATE SET equip0 = $2
`, charID, serialized)
if err != nil {
t.Fatalf("Failed to save crafted equipment: %v", err)
}
// Reload
var saved []byte
err = db.QueryRow("SELECT equip0 FROM warehouse WHERE character_id = $1", charID).Scan(&saved)
if err != nil {
t.Errorf("Failed to load crafted equipment: %v (BUG CONFIRMED)", err)
return
}
if len(saved) == 0 {
t.Error("Crafted equipment not saved (BUG CONFIRMED)")
} else if !bytes.Equal(saved, serialized) {
t.Error("Crafted equipment data mismatch (BUG CONFIRMED)")
} else {
t.Logf("✓ Crafted equipment saved correctly: %d bytes", len(saved))
}
}
// TestSaveLoad_CompleteSaveLoadCycle tests a complete save/load cycle
// This simulates a player logging out and back in
func TestSaveLoad_CompleteSaveLoadCycle(t *testing.T) {
db := SetupTestDB(t)
defer TeardownTestDB(t, db)
userID := CreateTestUser(t, db, "testuser")
charID := CreateTestCharacter(t, db, userID, "SaveLoadTest")
// Create test session (login)
mock := &MockCryptConn{sentPackets: make([][]byte, 0)}
s := createTestSession(mock)
s.charID = charID
s.Name = "SaveLoadTest"
s.server.db = db
// 1. Set Road Points
rdpPoints := uint32(5000)
_, err := db.Exec("UPDATE characters SET frontier_points = $1 WHERE id = $2", rdpPoints, charID)
if err != nil {
t.Fatalf("Failed to set RdP: %v", err)
}
// 2. Add Koryo Points
koryoPoints := uint32(250)
addPkt := &mhfpacket.MsgMhfAddKouryouPoint{
AckHandle: 1111,
KouryouPoints: koryoPoints,
}
handleMsgMhfAddKouryouPoint(s, addPkt)
// 3. Save main savedata
saveData := make([]byte, 150000)
copy(saveData[88:], []byte("SaveLoadTest\x00"))
compressed, _ := nullcomp.Compress(saveData)
savePkt := &mhfpacket.MsgMhfSavedata{
SaveType: 0,
AckHandle: 2222,
AllocMemSize: uint32(len(compressed)),
DataSize: uint32(len(compressed)),
RawDataPayload: compressed,
}
handleMsgMhfSavedata(s, savePkt)
// Drain ACK packets
for len(s.sendPackets) > 0 {
<-s.sendPackets
}
// SIMULATE LOGOUT/LOGIN - Create new session
mock2 := &MockCryptConn{sentPackets: make([][]byte, 0)}
s2 := createTestSession(mock2)
s2.charID = charID
s2.server.db = db
s2.server.userBinaryParts = make(map[userBinaryPartID][]byte)
// Load character data
loadPkt := &mhfpacket.MsgMhfLoaddata{
AckHandle: 3333,
}
handleMsgMhfLoaddata(s2, loadPkt)
// Verify loaded name
if s2.Name != "SaveLoadTest" {
t.Errorf("Character name not loaded correctly: got %q, want %q", s2.Name, "SaveLoadTest")
}
// Verify Road Points persisted
var loadedRdP uint32
db.QueryRow("SELECT frontier_points FROM characters WHERE id = $1", charID).Scan(&loadedRdP)
if loadedRdP != rdpPoints {
t.Errorf("RdP not persisted: got %d, want %d (BUG CONFIRMED)", loadedRdP, rdpPoints)
} else {
t.Logf("✓ RdP persisted across save/load: %d", loadedRdP)
}
// Verify Koryo Points persisted
var loadedKoryo uint32
db.QueryRow("SELECT kouryou_point FROM characters WHERE id = $1", charID).Scan(&loadedKoryo)
if loadedKoryo != koryoPoints {
t.Errorf("Koryo points not persisted: got %d, want %d (BUG CONFIRMED)", loadedKoryo, koryoPoints)
} else {
t.Logf("✓ Koryo points persisted across save/load: %d", loadedKoryo)
}
t.Log("Complete save/load cycle test finished")
}

View File

@@ -0,0 +1,501 @@
package channelserver
import (
"fmt"
"sync"
"testing"
"time"
"erupe-ce/network/mhfpacket"
"erupe-ce/server/channelserver/compression/nullcomp"
"go.uber.org/zap"
"go.uber.org/zap/zapcore"
"go.uber.org/zap/zaptest/observer"
)
// ============================================================================
// SAVE DATA LIFECYCLE MONITORING TESTS
// Tests with logging and monitoring to detect when save handlers are called
//
// Purpose: Add observability to understand the save/load lifecycle
// - Track when save handlers are invoked
// - Monitor logout flow
// - Detect missing save calls during disconnect
// ============================================================================
// SaveHandlerMonitor tracks calls to save handlers
type SaveHandlerMonitor struct {
mu sync.Mutex
savedataCallCount int
hunterNaviCallCount int
kouryouPointCallCount int
warehouseCallCount int
decomysetCallCount int
savedataAtLogout bool
lastSavedataTime time.Time
lastHunterNaviTime time.Time
lastKouryouPointTime time.Time
lastWarehouseTime time.Time
lastDecomysetTime time.Time
logoutTime time.Time
}
func (m *SaveHandlerMonitor) RecordSavedata() {
m.mu.Lock()
defer m.mu.Unlock()
m.savedataCallCount++
m.lastSavedataTime = time.Now()
}
func (m *SaveHandlerMonitor) RecordHunterNavi() {
m.mu.Lock()
defer m.mu.Unlock()
m.hunterNaviCallCount++
m.lastHunterNaviTime = time.Now()
}
func (m *SaveHandlerMonitor) RecordKouryouPoint() {
m.mu.Lock()
defer m.mu.Unlock()
m.kouryouPointCallCount++
m.lastKouryouPointTime = time.Now()
}
func (m *SaveHandlerMonitor) RecordWarehouse() {
m.mu.Lock()
defer m.mu.Unlock()
m.warehouseCallCount++
m.lastWarehouseTime = time.Now()
}
func (m *SaveHandlerMonitor) RecordDecomyset() {
m.mu.Lock()
defer m.mu.Unlock()
m.decomysetCallCount++
m.lastDecomysetTime = time.Now()
}
func (m *SaveHandlerMonitor) RecordLogout() {
m.mu.Lock()
defer m.mu.Unlock()
m.logoutTime = time.Now()
// Check if savedata was called within 5 seconds before logout
if !m.lastSavedataTime.IsZero() && m.logoutTime.Sub(m.lastSavedataTime) < 5*time.Second {
m.savedataAtLogout = true
}
}
func (m *SaveHandlerMonitor) GetStats() string {
m.mu.Lock()
defer m.mu.Unlock()
return fmt.Sprintf(`Save Handler Statistics:
- Savedata calls: %d (last: %v)
- HunterNavi calls: %d (last: %v)
- KouryouPoint calls: %d (last: %v)
- Warehouse calls: %d (last: %v)
- Decomyset calls: %d (last: %v)
- Logout time: %v
- Savedata before logout: %v`,
m.savedataCallCount, m.lastSavedataTime,
m.hunterNaviCallCount, m.lastHunterNaviTime,
m.kouryouPointCallCount, m.lastKouryouPointTime,
m.warehouseCallCount, m.lastWarehouseTime,
m.decomysetCallCount, m.lastDecomysetTime,
m.logoutTime,
m.savedataAtLogout)
}
func (m *SaveHandlerMonitor) WasSavedataCalledBeforeLogout() bool {
m.mu.Lock()
defer m.mu.Unlock()
return m.savedataAtLogout
}
// TestMonitored_SaveHandlerInvocationDuringLogout tests if save handlers are called during logout
// This is the KEY test to identify the bug: logout should trigger saves but doesn't
func TestMonitored_SaveHandlerInvocationDuringLogout(t *testing.T) {
db := SetupTestDB(t)
defer TeardownTestDB(t, db)
server := createTestServerWithDB(t, db)
defer server.Shutdown()
userID := CreateTestUser(t, db, "monitor_test_user")
charID := CreateTestCharacter(t, db, userID, "MonitorChar")
monitor := &SaveHandlerMonitor{}
t.Log("Starting monitored session to track save handler calls")
// Create session with monitoring
session := createTestSessionForServerWithChar(server, charID, "MonitorChar")
// Modify data that SHOULD be auto-saved on logout
saveData := make([]byte, 150000)
copy(saveData[88:], []byte("MonitorChar\x00"))
saveData[5000] = 0x11
saveData[5001] = 0x22
compressed, err := nullcomp.Compress(saveData)
if err != nil {
t.Fatalf("Failed to compress savedata: %v", err)
}
// Save data during session
savePkt := &mhfpacket.MsgMhfSavedata{
SaveType: 0,
AckHandle: 7001,
AllocMemSize: uint32(len(compressed)),
DataSize: uint32(len(compressed)),
RawDataPayload: compressed,
}
t.Log("Calling handleMsgMhfSavedata during session")
handleMsgMhfSavedata(session, savePkt)
monitor.RecordSavedata()
time.Sleep(100 * time.Millisecond)
// Now trigger logout
t.Log("Triggering logout - monitoring if save handlers are called")
monitor.RecordLogout()
logoutPlayer(session)
time.Sleep(100 * time.Millisecond)
// Report statistics
t.Log(monitor.GetStats())
// Analysis
if monitor.savedataCallCount == 0 {
t.Error("❌ CRITICAL: No savedata calls detected during entire session")
}
if !monitor.WasSavedataCalledBeforeLogout() {
t.Log("⚠️ WARNING: Savedata was NOT called immediately before logout")
t.Log("This explains why players lose data - logout doesn't trigger final save!")
}
// Check if data actually persisted
var savedCompressed []byte
err = db.QueryRow("SELECT savedata FROM characters WHERE id = $1", charID).Scan(&savedCompressed)
if err != nil {
t.Fatalf("Failed to query savedata: %v", err)
}
if len(savedCompressed) == 0 {
t.Error("❌ CRITICAL: No savedata in database after logout")
} else {
decompressed, err := nullcomp.Decompress(savedCompressed)
if err != nil {
t.Errorf("Failed to decompress: %v", err)
} else if len(decompressed) > 5001 {
if decompressed[5000] == 0x11 && decompressed[5001] == 0x22 {
t.Log("✓ Data persisted (save was called during session, not at logout)")
} else {
t.Error("❌ Data corrupted or not saved")
}
}
}
}
// TestWithLogging_LogoutFlowAnalysis tests logout with detailed logging
func TestWithLogging_LogoutFlowAnalysis(t *testing.T) {
db := SetupTestDB(t)
defer TeardownTestDB(t, db)
// Create observed logger
core, logs := observer.New(zapcore.InfoLevel)
logger := zap.New(core)
server := createTestServerWithDB(t, db)
server.logger = logger
defer server.Shutdown()
userID := CreateTestUser(t, db, "logging_test_user")
charID := CreateTestCharacter(t, db, userID, "LoggingChar")
t.Log("Starting session with observed logging")
session := createTestSessionForServerWithChar(server, charID, "LoggingChar")
session.logger = logger
// Perform some actions
saveData := make([]byte, 150000)
copy(saveData[88:], []byte("LoggingChar\x00"))
compressed, _ := nullcomp.Compress(saveData)
savePkt := &mhfpacket.MsgMhfSavedata{
SaveType: 0,
AckHandle: 8001,
AllocMemSize: uint32(len(compressed)),
DataSize: uint32(len(compressed)),
RawDataPayload: compressed,
}
handleMsgMhfSavedata(session, savePkt)
time.Sleep(50 * time.Millisecond)
// Trigger logout
t.Log("Triggering logout with logging enabled")
logoutPlayer(session)
time.Sleep(100 * time.Millisecond)
// Analyze logs
allLogs := logs.All()
t.Logf("Captured %d log entries during session lifecycle", len(allLogs))
saveRelatedLogs := 0
logoutRelatedLogs := 0
for _, entry := range allLogs {
msg := entry.Message
if containsAny(msg, []string{"save", "Save", "SAVE"}) {
saveRelatedLogs++
t.Logf(" [SAVE LOG] %s", msg)
}
if containsAny(msg, []string{"logout", "Logout", "disconnect", "Disconnect"}) {
logoutRelatedLogs++
t.Logf(" [LOGOUT LOG] %s", msg)
}
}
t.Logf("Save-related logs: %d", saveRelatedLogs)
t.Logf("Logout-related logs: %d", logoutRelatedLogs)
if saveRelatedLogs == 0 {
t.Error("❌ No save-related log entries found - saves may not be happening")
}
if logoutRelatedLogs == 0 {
t.Log("⚠️ No logout-related log entries - may need to add logging to logoutPlayer()")
}
}
// TestConcurrent_MultipleSessionsSaving tests concurrent sessions saving data
// This helps identify race conditions in the save system
func TestConcurrent_MultipleSessionsSaving(t *testing.T) {
db := SetupTestDB(t)
defer TeardownTestDB(t, db)
server := createTestServerWithDB(t, db)
defer server.Shutdown()
numSessions := 5
var wg sync.WaitGroup
wg.Add(numSessions)
t.Logf("Starting %d concurrent sessions", numSessions)
for i := 0; i < numSessions; i++ {
go func(sessionID int) {
defer wg.Done()
username := fmt.Sprintf("concurrent_user_%d", sessionID)
charName := fmt.Sprintf("ConcurrentChar%d", sessionID)
userID := CreateTestUser(t, db, username)
charID := CreateTestCharacter(t, db, userID, charName)
session := createTestSessionForServerWithChar(server, charID, charName)
// Save data
saveData := make([]byte, 150000)
copy(saveData[88:], []byte(charName+"\x00"))
saveData[6000+sessionID] = byte(sessionID)
compressed, err := nullcomp.Compress(saveData)
if err != nil {
t.Errorf("Session %d: Failed to compress: %v", sessionID, err)
return
}
savePkt := &mhfpacket.MsgMhfSavedata{
SaveType: 0,
AckHandle: uint32(9000 + sessionID),
AllocMemSize: uint32(len(compressed)),
DataSize: uint32(len(compressed)),
RawDataPayload: compressed,
}
handleMsgMhfSavedata(session, savePkt)
time.Sleep(50 * time.Millisecond)
// Logout
logoutPlayer(session)
time.Sleep(50 * time.Millisecond)
// Verify data saved
var savedCompressed []byte
err = db.QueryRow("SELECT savedata FROM characters WHERE id = $1", charID).Scan(&savedCompressed)
if err != nil {
t.Errorf("Session %d: Failed to load savedata: %v", sessionID, err)
return
}
if len(savedCompressed) == 0 {
t.Errorf("Session %d: ❌ No savedata persisted", sessionID)
} else {
t.Logf("Session %d: ✓ Savedata persisted (%d bytes)", sessionID, len(savedCompressed))
}
}(i)
}
wg.Wait()
t.Log("All concurrent sessions completed")
}
// TestSequential_RepeatedLogoutLoginCycles tests for data corruption over multiple cycles
func TestSequential_RepeatedLogoutLoginCycles(t *testing.T) {
db := SetupTestDB(t)
defer TeardownTestDB(t, db)
server := createTestServerWithDB(t, db)
defer server.Shutdown()
userID := CreateTestUser(t, db, "cycle_test_user")
charID := CreateTestCharacter(t, db, userID, "CycleChar")
numCycles := 10
t.Logf("Running %d logout/login cycles", numCycles)
for cycle := 1; cycle <= numCycles; cycle++ {
session := createTestSessionForServerWithChar(server, charID, "CycleChar")
// Modify data each cycle
saveData := make([]byte, 150000)
copy(saveData[88:], []byte("CycleChar\x00"))
// Write cycle number at specific offset
saveData[7000] = byte(cycle >> 8)
saveData[7001] = byte(cycle & 0xFF)
compressed, _ := nullcomp.Compress(saveData)
savePkt := &mhfpacket.MsgMhfSavedata{
SaveType: 0,
AckHandle: uint32(10000 + cycle),
AllocMemSize: uint32(len(compressed)),
DataSize: uint32(len(compressed)),
RawDataPayload: compressed,
}
handleMsgMhfSavedata(session, savePkt)
time.Sleep(50 * time.Millisecond)
// Logout
logoutPlayer(session)
time.Sleep(50 * time.Millisecond)
// Verify data after each cycle
var savedCompressed []byte
db.QueryRow("SELECT savedata FROM characters WHERE id = $1", charID).Scan(&savedCompressed)
if len(savedCompressed) > 0 {
decompressed, err := nullcomp.Decompress(savedCompressed)
if err != nil {
t.Errorf("Cycle %d: Failed to decompress: %v", cycle, err)
} else if len(decompressed) > 7001 {
savedCycle := (int(decompressed[7000]) << 8) | int(decompressed[7001])
if savedCycle != cycle {
t.Errorf("Cycle %d: ❌ Data corruption - expected cycle %d, got %d",
cycle, cycle, savedCycle)
} else {
t.Logf("Cycle %d: ✓ Data correct", cycle)
}
}
} else {
t.Errorf("Cycle %d: ❌ No savedata", cycle)
}
}
t.Log("Completed all logout/login cycles")
}
// TestRealtime_SaveDataTimestamps tests when saves actually happen
func TestRealtime_SaveDataTimestamps(t *testing.T) {
db := SetupTestDB(t)
defer TeardownTestDB(t, db)
server := createTestServerWithDB(t, db)
defer server.Shutdown()
userID := CreateTestUser(t, db, "timestamp_test_user")
charID := CreateTestCharacter(t, db, userID, "TimestampChar")
type SaveEvent struct {
timestamp time.Time
eventType string
}
var events []SaveEvent
session := createTestSessionForServerWithChar(server, charID, "TimestampChar")
events = append(events, SaveEvent{time.Now(), "session_start"})
// Save 1
saveData := make([]byte, 150000)
copy(saveData[88:], []byte("TimestampChar\x00"))
compressed, _ := nullcomp.Compress(saveData)
savePkt := &mhfpacket.MsgMhfSavedata{
SaveType: 0,
AckHandle: 11001,
AllocMemSize: uint32(len(compressed)),
DataSize: uint32(len(compressed)),
RawDataPayload: compressed,
}
handleMsgMhfSavedata(session, savePkt)
events = append(events, SaveEvent{time.Now(), "save_1"})
time.Sleep(100 * time.Millisecond)
// Save 2
handleMsgMhfSavedata(session, savePkt)
events = append(events, SaveEvent{time.Now(), "save_2"})
time.Sleep(100 * time.Millisecond)
// Logout
events = append(events, SaveEvent{time.Now(), "logout_start"})
logoutPlayer(session)
events = append(events, SaveEvent{time.Now(), "logout_end"})
time.Sleep(50 * time.Millisecond)
// Print timeline
t.Log("Save event timeline:")
startTime := events[0].timestamp
for _, event := range events {
elapsed := event.timestamp.Sub(startTime)
t.Logf(" [+%v] %s", elapsed.Round(time.Millisecond), event.eventType)
}
// Calculate time between last save and logout
var lastSaveTime time.Time
var logoutTime time.Time
for _, event := range events {
if event.eventType == "save_2" {
lastSaveTime = event.timestamp
}
if event.eventType == "logout_start" {
logoutTime = event.timestamp
}
}
if !lastSaveTime.IsZero() && !logoutTime.IsZero() {
gap := logoutTime.Sub(lastSaveTime)
t.Logf("Time between last save and logout: %v", gap.Round(time.Millisecond))
if gap > 50*time.Millisecond {
t.Log("⚠️ Significant gap between last save and logout")
t.Log("Player changes after last save would be LOST")
}
}
}
// Helper function
func containsAny(s string, substrs []string) bool {
for _, substr := range substrs {
if len(s) >= len(substr) {
for i := 0; i <= len(s)-len(substr); i++ {
if s[i:i+len(substr)] == substr {
return true
}
}
}
}
return false
}

View File

@@ -0,0 +1,624 @@
package channelserver
import (
"bytes"
"net"
"testing"
"time"
_config "erupe-ce/config"
"erupe-ce/common/mhfitem"
"erupe-ce/network/clientctx"
"erupe-ce/network/mhfpacket"
"erupe-ce/server/channelserver/compression/nullcomp"
"github.com/jmoiron/sqlx"
"go.uber.org/zap"
)
// ============================================================================
// SESSION LIFECYCLE INTEGRATION TESTS
// Full end-to-end tests that simulate the complete player session lifecycle
//
// These tests address the core issue: handler-level tests don't catch problems
// with the logout flow. Players report data loss because logout doesn't
// trigger save handlers.
//
// Test Strategy:
// 1. Create a real session (not just call handlers directly)
// 2. Modify game data through packets
// 3. Trigger actual logout event (not just call handlers)
// 4. Create new session for the same character
// 5. Verify all data persists correctly
// ============================================================================
// TestSessionLifecycle_BasicSaveLoadCycle tests the complete session lifecycle
// This is the minimal reproduction case for player-reported data loss
func TestSessionLifecycle_BasicSaveLoadCycle(t *testing.T) {
db := SetupTestDB(t)
defer TeardownTestDB(t, db)
server := createTestServerWithDB(t, db)
defer server.Shutdown()
// Create test user and character
userID := CreateTestUser(t, db, "lifecycle_test_user")
charID := CreateTestCharacter(t, db, userID, "LifecycleChar")
t.Logf("Created character ID %d for lifecycle test", charID)
// ===== SESSION 1: Login, modify data, logout =====
t.Log("--- Starting Session 1: Login and modify data ---")
session1 := createTestSessionForServerWithChar(server, charID, "LifecycleChar")
// Note: Not calling Start() since we're testing handlers directly, not packet processing
// Modify data via packet handlers
initialPoints := uint32(5000)
_, err := db.Exec("UPDATE characters SET frontier_points = $1 WHERE id = $2", initialPoints, charID)
if err != nil {
t.Fatalf("Failed to set initial road points: %v", err)
}
// Save main savedata through packet
saveData := make([]byte, 150000)
copy(saveData[88:], []byte("LifecycleChar\x00"))
// Add some identifiable data at offset 1000
saveData[1000] = 0xDE
saveData[1001] = 0xAD
saveData[1002] = 0xBE
saveData[1003] = 0xEF
compressed, err := nullcomp.Compress(saveData)
if err != nil {
t.Fatalf("Failed to compress savedata: %v", err)
}
savePkt := &mhfpacket.MsgMhfSavedata{
SaveType: 0,
AckHandle: 1001,
AllocMemSize: uint32(len(compressed)),
DataSize: uint32(len(compressed)),
RawDataPayload: compressed,
}
t.Log("Sending savedata packet")
handleMsgMhfSavedata(session1, savePkt)
// Drain ACK
time.Sleep(100 * time.Millisecond)
// Now trigger logout via the actual logout flow
t.Log("Triggering logout via logoutPlayer")
logoutPlayer(session1)
// Give logout time to complete
time.Sleep(100 * time.Millisecond)
// ===== SESSION 2: Login again and verify data =====
t.Log("--- Starting Session 2: Login and verify data persists ---")
session2 := createTestSessionForServerWithChar(server, charID, "LifecycleChar")
// Note: Not calling Start() since we're testing handlers directly
// Load character data
loadPkt := &mhfpacket.MsgMhfLoaddata{
AckHandle: 2001,
}
handleMsgMhfLoaddata(session2, loadPkt)
time.Sleep(50 * time.Millisecond)
// Verify savedata persisted
var savedCompressed []byte
err = db.QueryRow("SELECT savedata FROM characters WHERE id = $1", charID).Scan(&savedCompressed)
if err != nil {
t.Fatalf("Failed to load savedata after session: %v", err)
}
if len(savedCompressed) == 0 {
t.Error("❌ CRITICAL: Savedata not persisted across logout/login cycle")
return
}
// Decompress and verify
decompressed, err := nullcomp.Decompress(savedCompressed)
if err != nil {
t.Errorf("Failed to decompress savedata: %v", err)
return
}
// Check our marker bytes
if len(decompressed) > 1003 {
if decompressed[1000] != 0xDE || decompressed[1001] != 0xAD ||
decompressed[1002] != 0xBE || decompressed[1003] != 0xEF {
t.Error("❌ CRITICAL: Savedata contents corrupted or not saved correctly")
t.Errorf("Expected [DE AD BE EF] at offset 1000, got [%02X %02X %02X %02X]",
decompressed[1000], decompressed[1001], decompressed[1002], decompressed[1003])
} else {
t.Log("✓ Savedata persisted correctly across logout/login")
}
} else {
t.Error("❌ CRITICAL: Savedata too short after reload")
}
// Verify name persisted
if session2.Name != "LifecycleChar" {
t.Errorf("❌ Character name not loaded correctly: got %q, want %q", session2.Name, "LifecycleChar")
} else {
t.Log("✓ Character name persisted correctly")
}
// Clean up
logoutPlayer(session2)
}
// TestSessionLifecycle_WarehouseDataPersistence tests warehouse across sessions
// This addresses user report: "warehouse contents not saved"
func TestSessionLifecycle_WarehouseDataPersistence(t *testing.T) {
db := SetupTestDB(t)
defer TeardownTestDB(t, db)
server := createTestServerWithDB(t, db)
defer server.Shutdown()
userID := CreateTestUser(t, db, "warehouse_test_user")
charID := CreateTestCharacter(t, db, userID, "WarehouseChar")
t.Log("Testing warehouse persistence across logout/login")
// ===== SESSION 1: Add items to warehouse =====
session1 := createTestSessionForServerWithChar(server, charID, "WarehouseChar")
// Create test equipment for warehouse
equipment := []mhfitem.MHFEquipment{
createTestEquipmentItem(100, 1),
createTestEquipmentItem(101, 2),
createTestEquipmentItem(102, 3),
}
serializedEquip := mhfitem.SerializeWarehouseEquipment(equipment)
// Save to warehouse directly (simulating a save handler)
_, err := db.Exec(`
INSERT INTO warehouse (character_id, equip0)
VALUES ($1, $2)
ON CONFLICT (character_id) DO UPDATE SET equip0 = $2
`, charID, serializedEquip)
if err != nil {
t.Fatalf("Failed to save warehouse: %v", err)
}
t.Log("Saved equipment to warehouse in session 1")
// Logout
logoutPlayer(session1)
time.Sleep(100 * time.Millisecond)
// ===== SESSION 2: Verify warehouse contents =====
session2 := createTestSessionForServerWithChar(server, charID, "WarehouseChar")
// Reload warehouse
var savedEquip []byte
err = db.QueryRow("SELECT equip0 FROM warehouse WHERE character_id = $1", charID).Scan(&savedEquip)
if err != nil {
t.Errorf("❌ Failed to load warehouse after logout: %v", err)
logoutPlayer(session2)
return
}
if len(savedEquip) == 0 {
t.Error("❌ Warehouse equipment not saved")
} else if !bytes.Equal(savedEquip, serializedEquip) {
t.Error("❌ Warehouse equipment data mismatch")
} else {
t.Log("✓ Warehouse equipment persisted correctly across logout/login")
}
logoutPlayer(session2)
}
// TestSessionLifecycle_KoryoPointsPersistence tests kill counter across sessions
// This addresses user report: "monster kill counter not saved"
func TestSessionLifecycle_KoryoPointsPersistence(t *testing.T) {
db := SetupTestDB(t)
defer TeardownTestDB(t, db)
server := createTestServerWithDB(t, db)
defer server.Shutdown()
userID := CreateTestUser(t, db, "koryo_test_user")
charID := CreateTestCharacter(t, db, userID, "KoryoChar")
t.Log("Testing Koryo points persistence across logout/login")
// ===== SESSION 1: Add Koryo points =====
session1 := createTestSessionForServerWithChar(server, charID, "KoryoChar")
// Add Koryo points via packet
addPoints := uint32(250)
pkt := &mhfpacket.MsgMhfAddKouryouPoint{
AckHandle: 3001,
KouryouPoints: addPoints,
}
t.Logf("Adding %d Koryo points", addPoints)
handleMsgMhfAddKouryouPoint(session1, pkt)
time.Sleep(50 * time.Millisecond)
// Verify points were added in session 1
var points1 uint32
err := db.QueryRow("SELECT COALESCE(kouryou_point, 0) FROM characters WHERE id = $1", charID).Scan(&points1)
if err != nil {
t.Fatalf("Failed to query koryo points: %v", err)
}
t.Logf("Koryo points after add: %d", points1)
// Logout
logoutPlayer(session1)
time.Sleep(100 * time.Millisecond)
// ===== SESSION 2: Verify Koryo points persist =====
session2 := createTestSessionForServerWithChar(server, charID, "KoryoChar")
// Reload Koryo points
var points2 uint32
err = db.QueryRow("SELECT COALESCE(kouryou_point, 0) FROM characters WHERE id = $1", charID).Scan(&points2)
if err != nil {
t.Errorf("❌ Failed to load koryo points after logout: %v", err)
logoutPlayer(session2)
return
}
if points2 != addPoints {
t.Errorf("❌ Koryo points not persisted: got %d, want %d", points2, addPoints)
} else {
t.Logf("✓ Koryo points persisted correctly: %d", points2)
}
logoutPlayer(session2)
}
// TestSessionLifecycle_MultipleDataTypesPersistence tests multiple data types in one session
// This is the comprehensive test that simulates a real player session
func TestSessionLifecycle_MultipleDataTypesPersistence(t *testing.T) {
db := SetupTestDB(t)
defer TeardownTestDB(t, db)
server := createTestServerWithDB(t, db)
defer server.Shutdown()
userID := CreateTestUser(t, db, "multi_test_user")
charID := CreateTestCharacter(t, db, userID, "MultiChar")
t.Log("Testing multiple data types persistence across logout/login")
// ===== SESSION 1: Modify multiple data types =====
session1 := createTestSessionForServerWithChar(server, charID, "MultiChar")
// 1. Set Road Points
rdpPoints := uint32(7500)
_, err := db.Exec("UPDATE characters SET frontier_points = $1 WHERE id = $2", rdpPoints, charID)
if err != nil {
t.Fatalf("Failed to set RdP: %v", err)
}
// 2. Add Koryo Points
koryoPoints := uint32(500)
addKoryoPkt := &mhfpacket.MsgMhfAddKouryouPoint{
AckHandle: 4001,
KouryouPoints: koryoPoints,
}
handleMsgMhfAddKouryouPoint(session1, addKoryoPkt)
// 3. Save Hunter Navi
naviData := make([]byte, 552)
for i := range naviData {
naviData[i] = byte((i * 7) % 256)
}
naviPkt := &mhfpacket.MsgMhfSaveHunterNavi{
AckHandle: 4002,
IsDataDiff: false,
RawDataPayload: naviData,
}
handleMsgMhfSaveHunterNavi(session1, naviPkt)
// 4. Save main savedata
saveData := make([]byte, 150000)
copy(saveData[88:], []byte("MultiChar\x00"))
saveData[2000] = 0xCA
saveData[2001] = 0xFE
saveData[2002] = 0xBA
saveData[2003] = 0xBE
compressed, err := nullcomp.Compress(saveData)
if err != nil {
t.Fatalf("Failed to compress savedata: %v", err)
}
savePkt := &mhfpacket.MsgMhfSavedata{
SaveType: 0,
AckHandle: 4003,
AllocMemSize: uint32(len(compressed)),
DataSize: uint32(len(compressed)),
RawDataPayload: compressed,
}
handleMsgMhfSavedata(session1, savePkt)
// Give handlers time to process
time.Sleep(100 * time.Millisecond)
t.Log("Modified all data types in session 1")
// Logout
logoutPlayer(session1)
time.Sleep(100 * time.Millisecond)
// ===== SESSION 2: Verify all data persists =====
session2 := createTestSessionForServerWithChar(server, charID, "MultiChar")
// Load character data
loadPkt := &mhfpacket.MsgMhfLoaddata{
AckHandle: 5001,
}
handleMsgMhfLoaddata(session2, loadPkt)
time.Sleep(50 * time.Millisecond)
allPassed := true
// Verify 1: Road Points
var loadedRdP uint32
db.QueryRow("SELECT frontier_points FROM characters WHERE id = $1", charID).Scan(&loadedRdP)
if loadedRdP != rdpPoints {
t.Errorf("❌ RdP not persisted: got %d, want %d", loadedRdP, rdpPoints)
allPassed = false
} else {
t.Logf("✓ RdP persisted: %d", loadedRdP)
}
// Verify 2: Koryo Points
var loadedKoryo uint32
db.QueryRow("SELECT COALESCE(kouryou_point, 0) FROM characters WHERE id = $1", charID).Scan(&loadedKoryo)
if loadedKoryo != koryoPoints {
t.Errorf("❌ Koryo points not persisted: got %d, want %d", loadedKoryo, koryoPoints)
allPassed = false
} else {
t.Logf("✓ Koryo points persisted: %d", loadedKoryo)
}
// Verify 3: Hunter Navi
var loadedNavi []byte
db.QueryRow("SELECT hunternavi FROM characters WHERE id = $1", charID).Scan(&loadedNavi)
if len(loadedNavi) == 0 {
t.Error("❌ Hunter Navi not saved")
allPassed = false
} else if !bytes.Equal(loadedNavi, naviData) {
t.Error("❌ Hunter Navi data mismatch")
allPassed = false
} else {
t.Logf("✓ Hunter Navi persisted: %d bytes", len(loadedNavi))
}
// Verify 4: Savedata
var savedCompressed []byte
db.QueryRow("SELECT savedata FROM characters WHERE id = $1", charID).Scan(&savedCompressed)
if len(savedCompressed) == 0 {
t.Error("❌ Savedata not saved")
allPassed = false
} else {
decompressed, err := nullcomp.Decompress(savedCompressed)
if err != nil {
t.Errorf("❌ Failed to decompress savedata: %v", err)
allPassed = false
} else if len(decompressed) > 2003 {
if decompressed[2000] != 0xCA || decompressed[2001] != 0xFE ||
decompressed[2002] != 0xBA || decompressed[2003] != 0xBE {
t.Error("❌ Savedata contents corrupted")
allPassed = false
} else {
t.Log("✓ Savedata persisted correctly")
}
} else {
t.Error("❌ Savedata too short")
allPassed = false
}
}
if allPassed {
t.Log("✅ All data types persisted correctly across logout/login cycle")
} else {
t.Log("❌ CRITICAL: Some data types failed to persist - logout may not be triggering save handlers")
}
logoutPlayer(session2)
}
// TestSessionLifecycle_DisconnectWithoutLogout tests ungraceful disconnect
// This simulates network failure or client crash
func TestSessionLifecycle_DisconnectWithoutLogout(t *testing.T) {
db := SetupTestDB(t)
defer TeardownTestDB(t, db)
server := createTestServerWithDB(t, db)
defer server.Shutdown()
userID := CreateTestUser(t, db, "disconnect_test_user")
charID := CreateTestCharacter(t, db, userID, "DisconnectChar")
t.Log("Testing data persistence after ungraceful disconnect")
// ===== SESSION 1: Modify data then disconnect without explicit logout =====
session1 := createTestSessionForServerWithChar(server, charID, "DisconnectChar")
// Modify data
rdpPoints := uint32(9999)
_, err := db.Exec("UPDATE characters SET frontier_points = $1 WHERE id = $2", rdpPoints, charID)
if err != nil {
t.Fatalf("Failed to set RdP: %v", err)
}
// Save data
saveData := make([]byte, 150000)
copy(saveData[88:], []byte("DisconnectChar\x00"))
saveData[3000] = 0xAB
saveData[3001] = 0xCD
compressed, err := nullcomp.Compress(saveData)
if err != nil {
t.Fatalf("Failed to compress savedata: %v", err)
}
savePkt := &mhfpacket.MsgMhfSavedata{
SaveType: 0,
AckHandle: 6001,
AllocMemSize: uint32(len(compressed)),
DataSize: uint32(len(compressed)),
RawDataPayload: compressed,
}
handleMsgMhfSavedata(session1, savePkt)
time.Sleep(100 * time.Millisecond)
// Simulate disconnect by calling logoutPlayer (which is called by recvLoop on EOF)
// In real scenario, this is triggered by connection close
t.Log("Simulating ungraceful disconnect")
logoutPlayer(session1)
time.Sleep(100 * time.Millisecond)
// ===== SESSION 2: Verify data saved despite ungraceful disconnect =====
session2 := createTestSessionForServerWithChar(server, charID, "DisconnectChar")
// Verify savedata
var savedCompressed []byte
err = db.QueryRow("SELECT savedata FROM characters WHERE id = $1", charID).Scan(&savedCompressed)
if err != nil {
t.Fatalf("Failed to load savedata: %v", err)
}
if len(savedCompressed) == 0 {
t.Error("❌ CRITICAL: No data saved after disconnect")
logoutPlayer(session2)
return
}
decompressed, err := nullcomp.Decompress(savedCompressed)
if err != nil {
t.Errorf("Failed to decompress: %v", err)
logoutPlayer(session2)
return
}
if len(decompressed) > 3001 {
if decompressed[3000] == 0xAB && decompressed[3001] == 0xCD {
t.Log("✓ Data persisted after ungraceful disconnect")
} else {
t.Error("❌ Data corrupted after disconnect")
}
} else {
t.Error("❌ Data too short after disconnect")
}
logoutPlayer(session2)
}
// TestSessionLifecycle_RapidReconnect tests quick logout/login cycles
// This simulates a player reconnecting quickly or connection instability
func TestSessionLifecycle_RapidReconnect(t *testing.T) {
db := SetupTestDB(t)
defer TeardownTestDB(t, db)
server := createTestServerWithDB(t, db)
defer server.Shutdown()
userID := CreateTestUser(t, db, "rapid_test_user")
charID := CreateTestCharacter(t, db, userID, "RapidChar")
t.Log("Testing data persistence with rapid logout/login cycles")
for cycle := 1; cycle <= 3; cycle++ {
t.Logf("--- Cycle %d ---", cycle)
session := createTestSessionForServerWithChar(server, charID, "RapidChar")
// Modify road points each cycle
points := uint32(1000 * cycle)
_, err := db.Exec("UPDATE characters SET frontier_points = $1 WHERE id = $2", points, charID)
if err != nil {
t.Fatalf("Cycle %d: Failed to update points: %v", cycle, err)
}
// Logout quickly
logoutPlayer(session)
time.Sleep(30 * time.Millisecond)
// Verify points persisted
var loadedPoints uint32
db.QueryRow("SELECT frontier_points FROM characters WHERE id = $1", charID).Scan(&loadedPoints)
if loadedPoints != points {
t.Errorf("❌ Cycle %d: Points not persisted: got %d, want %d", cycle, loadedPoints, points)
} else {
t.Logf("✓ Cycle %d: Points persisted correctly: %d", cycle, loadedPoints)
}
}
}
// Helper function to create test equipment item with proper initialization
func createTestEquipmentItem(itemID uint16, warehouseID uint32) mhfitem.MHFEquipment {
return mhfitem.MHFEquipment{
ItemID: itemID,
WarehouseID: warehouseID,
Decorations: make([]mhfitem.MHFItem, 3),
Sigils: make([]mhfitem.MHFSigil, 3),
}
}
// MockNetConn is defined in client_connection_simulation_test.go
// Helper function to create a test server with database
func createTestServerWithDB(t *testing.T, db *sqlx.DB) *Server {
t.Helper()
// Create minimal server for testing
// Note: This may need adjustment based on actual Server initialization
server := &Server{
db: db,
sessions: make(map[net.Conn]*Session),
stages: make(map[string]*Stage),
objectIDs: make(map[*Session]uint16),
userBinaryParts: make(map[userBinaryPartID][]byte),
semaphore: make(map[string]*Semaphore),
erupeConfig: _config.ErupeConfig,
isShuttingDown: false,
}
// Create logger
logger, _ := zap.NewDevelopment()
server.logger = logger
return server
}
// Helper function to create a test session for a specific character
func createTestSessionForServerWithChar(server *Server, charID uint32, name string) *Session {
mock := &MockCryptConn{sentPackets: make([][]byte, 0)}
mockNetConn := NewMockNetConn() // Create a mock net.Conn for the session map key
session := &Session{
logger: server.logger,
server: server,
rawConn: mockNetConn,
cryptConn: mock,
sendPackets: make(chan packet, 20),
clientContext: &clientctx.ClientContext{},
lastPacket: time.Now(),
sessionStart: time.Now().Unix(),
charID: charID,
Name: name,
}
// Register session with server (needed for logout to work properly)
server.Lock()
server.sessions[mockNetConn] = session
server.Unlock()
return session
}

View File

@@ -3,6 +3,8 @@ package channelserver
import ( import (
"bytes" "bytes"
"encoding/binary" "encoding/binary"
"io"
_config "erupe-ce/config" _config "erupe-ce/config"
"erupe-ce/network" "erupe-ce/network"
"sync" "sync"
@@ -29,8 +31,9 @@ func (m *MockCryptConn) SendPacket(data []byte) error {
} }
func (m *MockCryptConn) ReadPacket() ([]byte, error) { func (m *MockCryptConn) ReadPacket() ([]byte, error) {
// Mock implementation for testing // Return EOF to simulate graceful disconnect
return nil, nil // This makes recvLoop() exit and call logoutPlayer()
return nil, io.EOF
} }
func (m *MockCryptConn) GetSentPackets() [][]byte { func (m *MockCryptConn) GetSentPackets() [][]byte {