chore: adds remaining logging for Hunter Navi and Plate data.

This commit is contained in:
Houmgaor
2025-11-01 17:14:05 +01:00
parent afc554f1ec
commit 3da54fade8
3 changed files with 91 additions and 15 deletions

View File

@@ -11,9 +11,10 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
- Alpelo object system backport functionality - Alpelo object system backport functionality
- Better config file handling and structure - Better config file handling and structure
- Comprehensive production logging for save operations (warehouse, Koryo points, savedata) - Comprehensive production logging for save operations (warehouse, Koryo points, savedata, Hunter Navi, plate equipment)
- Disconnect type tracking (graceful, connection_lost, error) with detailed logging - Disconnect type tracking (graceful, connection_lost, error) with detailed logging
- Session lifecycle logging with duration and metrics tracking - Session lifecycle logging with duration and metrics tracking
- Structured logging with timing metrics for all database save operations
### Changed ### Changed

View File

@@ -69,6 +69,15 @@ func handleMsgMhfLoadHunterNavi(s *Session, p mhfpacket.MHFPacket) {
func handleMsgMhfSaveHunterNavi(s *Session, p mhfpacket.MHFPacket) { func handleMsgMhfSaveHunterNavi(s *Session, p mhfpacket.MHFPacket) {
pkt := p.(*mhfpacket.MsgMhfSaveHunterNavi) pkt := p.(*mhfpacket.MsgMhfSaveHunterNavi)
saveStart := time.Now()
s.logger.Debug("Hunter Navi save request",
zap.Uint32("charID", s.charID),
zap.Bool("is_diff", pkt.IsDataDiff),
zap.Int("data_size", len(pkt.RawDataPayload)),
)
var dataSize int
if pkt.IsDataDiff { if pkt.IsDataDiff {
naviLength := 552 naviLength := 552
if s.server.erupeConfig.RealClientMode <= _config.G7 { if s.server.erupeConfig.RealClientMode <= _config.G7 {
@@ -78,7 +87,10 @@ func handleMsgMhfSaveHunterNavi(s *Session, p mhfpacket.MHFPacket) {
// Load existing save // Load existing save
err := s.server.db.QueryRow("SELECT hunternavi FROM characters WHERE id = $1", s.charID).Scan(&data) err := s.server.db.QueryRow("SELECT hunternavi FROM characters WHERE id = $1", s.charID).Scan(&data)
if err != nil { if err != nil {
s.logger.Error("Failed to load hunternavi", zap.Error(err)) s.logger.Error("Failed to load hunternavi",
zap.Error(err),
zap.Uint32("charID", s.charID),
)
} }
// Check if we actually had any hunternavi data, using a blank buffer if not. // Check if we actually had any hunternavi data, using a blank buffer if not.
@@ -88,21 +100,49 @@ func handleMsgMhfSaveHunterNavi(s *Session, p mhfpacket.MHFPacket) {
} }
// Perform diff and compress it to write back to db // Perform diff and compress it to write back to db
s.logger.Info("Diffing...") s.logger.Debug("Applying Hunter Navi diff",
zap.Uint32("charID", s.charID),
zap.Int("base_size", len(data)),
zap.Int("diff_size", len(pkt.RawDataPayload)),
)
saveOutput := deltacomp.ApplyDataDiff(pkt.RawDataPayload, data) saveOutput := deltacomp.ApplyDataDiff(pkt.RawDataPayload, data)
dataSize = len(saveOutput)
_, err = s.server.db.Exec("UPDATE characters SET hunternavi=$1 WHERE id=$2", saveOutput, s.charID) _, err = s.server.db.Exec("UPDATE characters SET hunternavi=$1 WHERE id=$2", saveOutput, s.charID)
if err != nil { if err != nil {
s.logger.Error("Failed to save hunternavi", zap.Error(err)) s.logger.Error("Failed to save hunternavi",
zap.Error(err),
zap.Uint32("charID", s.charID),
zap.Int("data_size", dataSize),
)
doAckSimpleSucceed(s, pkt.AckHandle, []byte{0x00, 0x00, 0x00, 0x00})
return
} }
s.logger.Info("Wrote recompressed hunternavi back to DB")
} else { } else {
dumpSaveData(s, pkt.RawDataPayload, "hunternavi") dumpSaveData(s, pkt.RawDataPayload, "hunternavi")
dataSize = len(pkt.RawDataPayload)
// simply update database, no extra processing // simply update database, no extra processing
_, err := s.server.db.Exec("UPDATE characters SET hunternavi=$1 WHERE id=$2", pkt.RawDataPayload, s.charID) _, err := s.server.db.Exec("UPDATE characters SET hunternavi=$1 WHERE id=$2", pkt.RawDataPayload, s.charID)
if err != nil { if err != nil {
s.logger.Error("Failed to save hunternavi", zap.Error(err)) s.logger.Error("Failed to save hunternavi",
zap.Error(err),
zap.Uint32("charID", s.charID),
zap.Int("data_size", dataSize),
)
doAckSimpleSucceed(s, pkt.AckHandle, []byte{0x00, 0x00, 0x00, 0x00})
return
} }
} }
saveDuration := time.Since(saveStart)
s.logger.Info("Hunter Navi saved successfully",
zap.Uint32("charID", s.charID),
zap.Bool("was_diff", pkt.IsDataDiff),
zap.Int("data_size", dataSize),
zap.Duration("duration", saveDuration),
)
doAckSimpleSucceed(s, pkt.AckHandle, []byte{0x00, 0x00, 0x00, 0x00}) doAckSimpleSucceed(s, pkt.AckHandle, []byte{0x00, 0x00, 0x00, 0x00})
} }

View File

@@ -5,6 +5,7 @@ import (
"erupe-ce/server/channelserver/compression/deltacomp" "erupe-ce/server/channelserver/compression/deltacomp"
"erupe-ce/server/channelserver/compression/nullcomp" "erupe-ce/server/channelserver/compression/nullcomp"
"go.uber.org/zap" "go.uber.org/zap"
"time"
) )
func handleMsgMhfLoadPlateData(s *Session, p mhfpacket.MHFPacket) { func handleMsgMhfLoadPlateData(s *Session, p mhfpacket.MHFPacket) {
@@ -19,24 +20,38 @@ func handleMsgMhfLoadPlateData(s *Session, p mhfpacket.MHFPacket) {
func handleMsgMhfSavePlateData(s *Session, p mhfpacket.MHFPacket) { func handleMsgMhfSavePlateData(s *Session, p mhfpacket.MHFPacket) {
pkt := p.(*mhfpacket.MsgMhfSavePlateData) pkt := p.(*mhfpacket.MsgMhfSavePlateData)
saveStart := time.Now()
s.logger.Debug("PlateData save request",
zap.Uint32("charID", s.charID),
zap.Bool("is_diff", pkt.IsDataDiff),
zap.Int("data_size", len(pkt.RawDataPayload)),
)
var dataSize int
if pkt.IsDataDiff { if pkt.IsDataDiff {
var data []byte var data []byte
// Load existing save // Load existing save
err := s.server.db.QueryRow("SELECT platedata FROM characters WHERE id = $1", s.charID).Scan(&data) err := s.server.db.QueryRow("SELECT platedata FROM characters WHERE id = $1", s.charID).Scan(&data)
if err != nil { if err != nil {
s.logger.Error("Failed to load platedata", zap.Error(err)) s.logger.Error("Failed to load platedata",
zap.Error(err),
zap.Uint32("charID", s.charID),
)
doAckSimpleSucceed(s, pkt.AckHandle, []byte{0x00, 0x00, 0x00, 0x00}) doAckSimpleSucceed(s, pkt.AckHandle, []byte{0x00, 0x00, 0x00, 0x00})
return return
} }
if len(data) > 0 { if len(data) > 0 {
// Decompress // Decompress
s.logger.Info("Decompressing...") s.logger.Debug("Decompressing PlateData", zap.Int("compressed_size", len(data)))
data, err = nullcomp.Decompress(data) data, err = nullcomp.Decompress(data)
if err != nil { if err != nil {
s.logger.Error("Failed to decompress platedata", zap.Error(err)) s.logger.Error("Failed to decompress platedata",
zap.Error(err),
zap.Uint32("charID", s.charID),
)
doAckSimpleSucceed(s, pkt.AckHandle, []byte{0x00, 0x00, 0x00, 0x00}) doAckSimpleSucceed(s, pkt.AckHandle, []byte{0x00, 0x00, 0x00, 0x00})
return return
} }
@@ -46,31 +61,51 @@ func handleMsgMhfSavePlateData(s *Session, p mhfpacket.MHFPacket) {
} }
// Perform diff and compress it to write back to db // Perform diff and compress it to write back to db
s.logger.Info("Diffing...") s.logger.Debug("Applying PlateData diff", zap.Int("base_size", len(data)))
saveOutput, err := nullcomp.Compress(deltacomp.ApplyDataDiff(pkt.RawDataPayload, data)) saveOutput, err := nullcomp.Compress(deltacomp.ApplyDataDiff(pkt.RawDataPayload, data))
if err != nil { if err != nil {
s.logger.Error("Failed to diff and compress platedata", zap.Error(err)) s.logger.Error("Failed to diff and compress platedata",
zap.Error(err),
zap.Uint32("charID", s.charID),
)
doAckSimpleSucceed(s, pkt.AckHandle, []byte{0x00, 0x00, 0x00, 0x00}) doAckSimpleSucceed(s, pkt.AckHandle, []byte{0x00, 0x00, 0x00, 0x00})
return return
} }
dataSize = len(saveOutput)
_, err = s.server.db.Exec("UPDATE characters SET platedata=$1 WHERE id=$2", saveOutput, s.charID) _, err = s.server.db.Exec("UPDATE characters SET platedata=$1 WHERE id=$2", saveOutput, s.charID)
if err != nil { if err != nil {
s.logger.Error("Failed to save platedata", zap.Error(err)) s.logger.Error("Failed to save platedata",
zap.Error(err),
zap.Uint32("charID", s.charID),
)
doAckSimpleSucceed(s, pkt.AckHandle, []byte{0x00, 0x00, 0x00, 0x00}) doAckSimpleSucceed(s, pkt.AckHandle, []byte{0x00, 0x00, 0x00, 0x00})
return return
} }
s.logger.Info("Wrote recompressed platedata back to DB")
} else { } else {
dumpSaveData(s, pkt.RawDataPayload, "platedata") dumpSaveData(s, pkt.RawDataPayload, "platedata")
dataSize = len(pkt.RawDataPayload)
// simply update database, no extra processing // simply update database, no extra processing
_, err := s.server.db.Exec("UPDATE characters SET platedata=$1 WHERE id=$2", pkt.RawDataPayload, s.charID) _, err := s.server.db.Exec("UPDATE characters SET platedata=$1 WHERE id=$2", pkt.RawDataPayload, s.charID)
if err != nil { if err != nil {
s.logger.Error("Failed to save platedata", zap.Error(err)) s.logger.Error("Failed to save platedata",
zap.Error(err),
zap.Uint32("charID", s.charID),
)
doAckSimpleSucceed(s, pkt.AckHandle, []byte{0x00, 0x00, 0x00, 0x00})
return
} }
} }
saveDuration := time.Since(saveStart)
s.logger.Info("PlateData saved successfully",
zap.Uint32("charID", s.charID),
zap.Bool("was_diff", pkt.IsDataDiff),
zap.Int("data_size", dataSize),
zap.Duration("duration", saveDuration),
)
doAckSimpleSucceed(s, pkt.AckHandle, []byte{0x00, 0x00, 0x00, 0x00}) doAckSimpleSucceed(s, pkt.AckHandle, []byte{0x00, 0x00, 0x00, 0x00})
} }