diff --git a/Source/ACE.Database/AuthenticationDatabase.cs b/Source/ACE.Database/AuthenticationDatabase.cs index 74fc305a25..2d7c7a81cb 100644 --- a/Source/ACE.Database/AuthenticationDatabase.cs +++ b/Source/ACE.Database/AuthenticationDatabase.cs @@ -29,7 +29,7 @@ public bool Exists(bool retryUntilFound) { if (((RelationalDatabaseCreator)context.Database.GetService()).Exists()) { - log.Debug($"Successfully connected to {config.Database} database on {config.Host}:{config.Port}."); + log.DebugFormat("Successfully connected to {0} database on {1}:{2}.", config.Database, config.Host, config.Port); return true; } } diff --git a/Source/ACE.Database/Models/Auth/AccountExtensions.cs b/Source/ACE.Database/Models/Auth/AccountExtensions.cs index 60f01408cf..7eedb49c3c 100644 --- a/Source/ACE.Database/Models/Auth/AccountExtensions.cs +++ b/Source/ACE.Database/Models/Auth/AccountExtensions.cs @@ -39,7 +39,7 @@ public static bool PasswordMatches(this Account account, string password) } else // Account password is using SHA512 salt { - log.Debug($"{account.AccountName} password verified using SHA512 hash/salt, migrating to bcrypt."); + log.DebugFormat("{0} password verified using SHA512 hash/salt, migrating to bcrypt.", account.AccountName); var input = GetPasswordHash(account, password); diff --git a/Source/ACE.Database/OfflineTools/Shard/BiotaGuidConsolidator.cs b/Source/ACE.Database/OfflineTools/Shard/BiotaGuidConsolidator.cs index 932853aa95..fe703a61b9 100644 --- a/Source/ACE.Database/OfflineTools/Shard/BiotaGuidConsolidator.cs +++ b/Source/ACE.Database/OfflineTools/Shard/BiotaGuidConsolidator.cs @@ -152,7 +152,7 @@ public static void ConsolidateBiotaGuids(uint startingGuid, bool tryNotToBreakPl if (fullBiota == null) { Interlocked.Increment(ref numOfErrors); - log.Warn($"Failed to get biota with id 0x{partialBiota.Id:X8} from the database. This shouldn't happen. It also shouldn't require a rollback."); + log.WarnFormat("Failed to get biota with id 0x{0:X8} from the database. This shouldn't happen. It also shouldn't require a rollback.", partialBiota.Id); return; } @@ -197,7 +197,7 @@ public static void ConsolidateBiotaGuids(uint startingGuid, bool tryNotToBreakPl if (!shardDatabase.SaveBiota(converted, new ReaderWriterLockSlim())) { Interlocked.Increment(ref numOfErrors); - log.Fatal($"Failed to save new biota with id 0x{fullBiota.Id:X8} to the database. Please rollback your shard."); + log.FatalFormat("Failed to save new biota with id 0x{0:X8} to the database. Please rollback your shard.", fullBiota.Id); return; } @@ -205,7 +205,7 @@ public static void ConsolidateBiotaGuids(uint startingGuid, bool tryNotToBreakPl if (!shardDatabase.RemoveBiota(fullBiota.Id)) { Interlocked.Increment(ref numOfErrors); - log.Fatal($"Failed to remove original biota with id 0x{fullBiota.Id:X8} from database. Please rollback your shard."); + log.FatalFormat("Failed to remove original biota with id 0x{0:X8} from database. Please rollback your shard.", fullBiota.Id); return; } @@ -240,7 +240,7 @@ public static void ConsolidateBiotaGuids(uint startingGuid, bool tryNotToBreakPl if (fullBiota == null) { Interlocked.Increment(ref numOfErrors); - log.Warn($"Failed to get biota with id 0x{partialBiota.Id:X8} from the database. This shouldn't happen. It also shouldn't require a rollback."); + log.WarnFormat("Failed to get biota with id 0x{0:X8} from the database. This shouldn't happen. It also shouldn't require a rollback.", partialBiota.Id); break; } @@ -285,7 +285,7 @@ public static void ConsolidateBiotaGuids(uint startingGuid, bool tryNotToBreakPl if (!shardDatabase.SaveBiota(converted, new ReaderWriterLockSlim())) { Interlocked.Increment(ref numOfErrors); - log.Fatal($"Failed to save new biota with id 0x{fullBiota.Id:X8} to the database. Please rollback your shard."); + log.FatalFormat("Failed to save new biota with id 0x{0:X8} to the database. Please rollback your shard.", fullBiota.Id); break; } @@ -309,7 +309,7 @@ public static void ConsolidateBiotaGuids(uint startingGuid, bool tryNotToBreakPl if (!shardDatabase.RemoveBiota(fullBiota.Id)) { Interlocked.Increment(ref numOfErrors); - log.Fatal($"Failed to remove original biota with id 0x{fullBiota.Id:X8} from database. Please rollback your shard."); + log.FatalFormat("Failed to remove original biota with id 0x{0:X8} from database. Please rollback your shard.", fullBiota.Id); break; } diff --git a/Source/ACE.Database/ShardDatabase.cs b/Source/ACE.Database/ShardDatabase.cs index 15f93ea95d..9d96b3cb43 100644 --- a/Source/ACE.Database/ShardDatabase.cs +++ b/Source/ACE.Database/ShardDatabase.cs @@ -35,7 +35,7 @@ public bool Exists(bool retryUntilFound) { if (((RelationalDatabaseCreator)context.Database.GetService()).Exists()) { - log.Debug($"[DATABASE] Successfully connected to {config.Database} database on {config.Host}:{config.Port}."); + log.DebugFormat("[DATABASE] Successfully connected to {0} database on {1}:{2}.", config.Database, config.Host, config.Port); return true; } } @@ -290,7 +290,7 @@ protected bool DoSaveBiota(ShardDbContext context, Biota biota) context.SaveChanges(); if (firstException != null) - log.Debug($"[DATABASE] DoSaveBiota 0x{biota.Id:X8}:{biota.GetProperty(PropertyString.Name)} retry succeeded after initial exception of: {firstException.GetFullMessage()}"); + log.DebugFormat("[DATABASE] DoSaveBiota 0x{0:X8}:{1} retry succeeded after initial exception of: {2}", biota.Id, biota.GetProperty(PropertyString.Name), firstException.GetFullMessage()); return true; } @@ -372,7 +372,7 @@ public virtual bool RemoveBiota(uint id) context.SaveChanges(); if (firstException != null) - log.Debug($"[DATABASE] RemoveBiota 0x{id:X8} retry succeeded after initial exception of: {firstException.GetFullMessage()}"); + log.DebugFormat("[DATABASE] RemoveBiota 0x{0:X8} retry succeeded after initial exception of: {1}", id, firstException.GetFullMessage()); return true; } @@ -649,8 +649,8 @@ public bool SaveCharacter(Character character, ReaderWriterLockSlim rwLock) { cachedContext.SaveChanges(); - if (firstException != null) - log.Debug($"[DATABASE] SaveCharacter-1 0x{character.Id:X8}:{character.Name} retry succeeded after initial exception of: {firstException.GetFullMessage()}"); + if (firstException != null && log.IsDebugEnabled) + log.DebugFormat("[DATABASE] SaveCharacter-1 0x{0:X8}:{1} retry succeeded after initial exception of: {2}", character.Id, character.Name, firstException.GetFullMessage()); return true; } @@ -690,8 +690,8 @@ public bool SaveCharacter(Character character, ReaderWriterLockSlim rwLock) { context.SaveChanges(); - if (firstException != null) - log.Debug($"[DATABASE] SaveCharacter-2 0x{character.Id:X8}:{character.Name} retry succeeded after initial exception of: {firstException.GetFullMessage()}"); + if (firstException != null && log.IsDebugEnabled) + log.DebugFormat("[DATABASE] SaveCharacter-2 0x{0:X8}:{1} retry succeeded after initial exception of: {2}", character.Id, character.Name, firstException.GetFullMessage()); return true; } @@ -791,8 +791,8 @@ public bool RenameCharacter(Character character, string newName, ReaderWriterLoc character.Name = newName; cachedContext.SaveChanges(); - if (firstException != null) - log.Debug($"[DATABASE] RenameCharacter 0x{character.Id:X8}:{character.Name} retry succeeded after initial exception of: {firstException.GetFullMessage()}"); + if (firstException != null && log.IsDebugEnabled) + log.DebugFormat("[DATABASE] RenameCharacter 0x{0:X8}:{1} retry succeeded after initial exception of: {2}", character.Id, character.Name, firstException.GetFullMessage()); return true; } @@ -834,8 +834,8 @@ public bool RenameCharacter(Character character, string newName, ReaderWriterLoc { context.SaveChanges(); - if (firstException != null) - log.Debug($"[DATABASE] RenameCharacter 0x{character.Id:X8}:{character.Name} retry succeeded after initial exception of: {firstException.GetFullMessage()}"); + if (firstException != null && log.IsDebugEnabled) + log.DebugFormat("[DATABASE] RenameCharacter 0x{0:X8}:{1} retry succeeded after initial exception of: {2}", character.Id, character.Name, firstException.GetFullMessage()); return true; } diff --git a/Source/ACE.Database/ShardDatabaseOfflineTools.cs b/Source/ACE.Database/ShardDatabaseOfflineTools.cs index 386508513c..89a392c06a 100644 --- a/Source/ACE.Database/ShardDatabaseOfflineTools.cs +++ b/Source/ACE.Database/ShardDatabaseOfflineTools.cs @@ -139,7 +139,7 @@ public static void PurgeCharacter(ShardDbContext context, uint characterId, out } catch (Exception ex) { - log.Error($"[DATABASE][PURGE] PurgeCharacter 0x{characterId:X8} failed with exception: {ex}"); + log.ErrorFormat("[DATABASE][PURGE] PurgeCharacter 0x{0:X8} failed with exception: {1}", characterId, ex); } } @@ -254,7 +254,7 @@ public static void PurgePlayer(ShardDbContext context, uint playerId, out int ch } catch (Exception ex) { - log.Error($"[DATABASE][PURGE] PurgePlayer 0x{playerId:X8} failed with exception: {ex}"); + log.ErrorFormat("[DATABASE][PURGE] PurgePlayer 0x{0:X8} failed with exception: {1}", playerId, ex); } } @@ -312,7 +312,7 @@ public static bool PurgeBiota(ShardDbContext context, uint id, string reason = n } catch (Exception ex) { - log.Error($"[DATABASE][PURGE] PurgeBiota 0x{id:X8} failed with exception: {ex}"); + log.ErrorFormat("[DATABASE][PURGE] PurgeBiota 0x{0:X8} failed with exception: {1}", id, ex); } return true; @@ -1001,7 +1001,7 @@ public static void CheckForBiotaPropertiesPaletteOrderColumnInShard() } catch (Exception ex) { - log.Fatal($"Unable to restore order column in biota_properties_palette table in shard database due to following error: {ex.GetFullMessage()}"); + log.FatalFormat("Unable to restore order column in biota_properties_palette table in shard database due to following error: {0}", ex.GetFullMessage()); Environment.Exit(1); return; } @@ -1040,7 +1040,7 @@ public static void PruneDeletedCharactersFromFriendLists(out int numberOfRecords foreach (var invalidFriend in invalidFriends) { - log.Debug($"[PRUNE] Character 0x{invalidFriend.CharacterId:X8} had 0x{invalidFriend.FriendId:X8} for a friend, which is not found in database, and has been removed from their friends list."); + log.DebugFormat("[PRUNE] Character 0x{0:X8} had 0x{1:X8} for a friend, which is not found in database, and has been removed from their friends list.", invalidFriend.CharacterId, invalidFriend.FriendId); context.CharacterPropertiesFriendList.Remove(invalidFriend); numberOfRecordsFixed++; } @@ -1076,7 +1076,7 @@ public static void PruneDeletedObjectsFromShortcutBars(out int numberOfRecordsFi foreach (var invalidShortcut in invalidShortcuts) { - log.Debug($"[PRUNE] Character 0x{invalidShortcut.CharacterId:X8} had 0x{invalidShortcut.ShortcutObjectId:X8} as a shortcut (in position {invalidShortcut.ShortcutBarIndex}), which is not found in database, and has been removed from their shortcut bar."); + log.DebugFormat("[PRUNE] Character 0x{0:X8} had 0x{1:X8} as a shortcut (in position {2}), which is not found in database, and has been removed from their shortcut bar.", invalidShortcut.CharacterId, invalidShortcut.ShortcutObjectId, invalidShortcut.ShortcutBarIndex); context.CharacterPropertiesShortcutBar.Remove(invalidShortcut); numberOfRecordsFixed++; } @@ -1115,7 +1115,7 @@ public static void PruneDeletedCharactersFromSquelchLists(out int numberOfRecord foreach (var invalidSquelchCharacter in invalidSquelchCharacters) { - log.Debug($"[PRUNE] Character 0x{invalidSquelchCharacter.CharacterId:X8} had 0x{invalidSquelchCharacter.SquelchCharacterId:X8} squelched, which is not found in database, and has been removed from their squelch list."); + log.DebugFormat("[PRUNE] Character 0x{0:X8} had 0x{1:X8} squelched, which is not found in database, and has been removed from their squelch list.", invalidSquelchCharacter.CharacterId, invalidSquelchCharacter.SquelchCharacterId); context.CharacterPropertiesSquelch.Remove(invalidSquelchCharacter); numberOfRecordsFixed++; } diff --git a/Source/ACE.Database/WorldDatabase.cs b/Source/ACE.Database/WorldDatabase.cs index 77236ad460..5c31483410 100644 --- a/Source/ACE.Database/WorldDatabase.cs +++ b/Source/ACE.Database/WorldDatabase.cs @@ -30,7 +30,7 @@ public bool Exists(bool retryUntilFound) { if (((RelationalDatabaseCreator)context.Database.GetService()).Exists()) { - log.Debug($"[DATABASE] Successfully connected to {config.Database} database on {config.Host}:{config.Port}."); + log.DebugFormat("[DATABASE] Successfully connected to {0} database on {1}:{2}.", config.Database, config.Host, config.Port); return true; } } diff --git a/Source/ACE.Server/Command/Handlers/AccountCommands.cs b/Source/ACE.Server/Command/Handlers/AccountCommands.cs index 4a1a8c352f..9842e3bf5e 100644 --- a/Source/ACE.Server/Command/Handlers/AccountCommands.cs +++ b/Source/ACE.Server/Command/Handlers/AccountCommands.cs @@ -173,7 +173,7 @@ public static void HandlePasswd(Session session, params string[] parameters) return; } - log.Debug($"{session.Player.Name} is changing their password"); + log.DebugFormat("{0} is changing their password", session.Player.Name); var currentTime = DateTime.UtcNow; diff --git a/Source/ACE.Server/Command/Handlers/DeveloperCommands.cs b/Source/ACE.Server/Command/Handlers/DeveloperCommands.cs index cad9e528d1..83602e7c12 100644 --- a/Source/ACE.Server/Command/Handlers/DeveloperCommands.cs +++ b/Source/ACE.Server/Command/Handlers/DeveloperCommands.cs @@ -2245,7 +2245,8 @@ public static void HandleAuditObjectMaint(Session session, params string[] param { if (value.ObjMaint.RemoveKnownObject(kvp.Value, false)) { - log.Debug($"AuditObjectMaint removed 0x{kvp.Value.ID:X8}:{kvp.Value.Name} (IsDestroyed:{kvp.Value.WeenieObj?.WorldObject?.IsDestroyed}, Position:{kvp.Value.Position}) from 0x{value.ID:X8}:{value.Name} (IsDestroyed:{value.WeenieObj?.WorldObject?.IsDestroyed}, Position:{value.Position}) [ObjectTable]"); + if (log.IsDebugEnabled) + log.Debug($"AuditObjectMaint removed 0x{kvp.Value.ID:X8}:{kvp.Value.Name} (IsDestroyed:{kvp.Value.WeenieObj?.WorldObject?.IsDestroyed}, Position:{kvp.Value.Position}) from 0x{value.ID:X8}:{value.Name} (IsDestroyed:{value.WeenieObj?.WorldObject?.IsDestroyed}, Position:{value.Position}) [ObjectTable]"); objectTableErrors++; } } @@ -2257,7 +2258,8 @@ public static void HandleAuditObjectMaint(Session session, params string[] param { if (value.ObjMaint.RemoveVisibleObject(kvp.Value, false)) { - log.Debug($"AuditObjectMaint removed 0x{kvp.Value.ID:X8}:{kvp.Value.Name} (IsDestroyed:{kvp.Value.WeenieObj?.WorldObject?.IsDestroyed}, Position:{kvp.Value.Position}) from 0x{value.ID:X8}:{value.Name} (IsDestroyed:{value.WeenieObj?.WorldObject?.IsDestroyed}, Position:{value.Position}) [VisibleObjectTable]"); + if (log.IsDebugEnabled) + log.Debug($"AuditObjectMaint removed 0x{kvp.Value.ID:X8}:{kvp.Value.Name} (IsDestroyed:{kvp.Value.WeenieObj?.WorldObject?.IsDestroyed}, Position:{kvp.Value.Position}) from 0x{value.ID:X8}:{value.Name} (IsDestroyed:{value.WeenieObj?.WorldObject?.IsDestroyed}, Position:{value.Position}) [VisibleObjectTable]"); visibleObjectTableErrors++; } } @@ -2269,7 +2271,8 @@ public static void HandleAuditObjectMaint(Session session, params string[] param { if (value.ObjMaint.RemoveKnownPlayer(kvp.Value)) { - log.Debug($"AuditObjectMaint removed 0x{kvp.Value.ID:X8}:{kvp.Value.Name} (IsDestroyed:{kvp.Value.WeenieObj?.WorldObject?.IsDestroyed}, Position:{kvp.Value.Position}) from 0x{value.ID:X8}:{value.Name} (IsDestroyed:{value.WeenieObj?.WorldObject?.IsDestroyed}, Position:{value.Position}) [VoyeurTable]"); + if (log.IsDebugEnabled) + log.Debug($"AuditObjectMaint removed 0x{kvp.Value.ID:X8}:{kvp.Value.Name} (IsDestroyed:{kvp.Value.WeenieObj?.WorldObject?.IsDestroyed}, Position:{kvp.Value.Position}) from 0x{value.ID:X8}:{value.Name} (IsDestroyed:{value.WeenieObj?.WorldObject?.IsDestroyed}, Position:{value.Position}) [VoyeurTable]"); voyeurTableErrors++; } } diff --git a/Source/ACE.Server/Entity/Aetheria.cs b/Source/ACE.Server/Entity/Aetheria.cs index 4cb3f3ded3..88d0573926 100644 --- a/Source/ACE.Server/Entity/Aetheria.cs +++ b/Source/ACE.Server/Entity/Aetheria.cs @@ -244,7 +244,7 @@ public static void ActivateSigil(Player player, WorldObject source, WorldObject player.SendUseDoneEvent(); - log.Debug($"[CRAFTING] {player.Name} revealed a {color} {randSigil} with a surge of {surgeSpell} on {target.Name}:0x{target.Guid}"); + log.DebugFormat("[CRAFTING] {0} revealed a {1} {2} with a surge of {3} on {4}:0x{5}", player.Name, color, randSigil, surgeSpell, target.Name, target.Guid); } public static Dictionary SigilToEquipmentSet = new Dictionary() diff --git a/Source/ACE.Server/Entity/DamageEvent.cs b/Source/ACE.Server/Entity/DamageEvent.cs index 5a51f0077f..480677d047 100644 --- a/Source/ACE.Server/Entity/DamageEvent.cs +++ b/Source/ACE.Server/Entity/DamageEvent.cs @@ -474,7 +474,7 @@ public void GetBodyPart(Creature defender, Quadrant quadrant) if (bodyPart == CombatBodyPart.Undefined) { - log.Debug($"DamageEvent.GetBodyPart({defender?.Name} ({defender?.Guid}) ) - couldn't find body part for wcid {defender.WeenieClassId}, Quadrant {quadrant}"); + log.DebugFormat("DamageEvent.GetBodyPart({0} ({1}) ) - couldn't find body part for wcid {2}, Quadrant {3}", defender?.Name, defender?.Guid, defender.WeenieClassId, quadrant); Evaded = true; return; } diff --git a/Source/ACE.Server/Entity/GeneratorProfile.cs b/Source/ACE.Server/Entity/GeneratorProfile.cs index fc859c02e9..82f35433af 100644 --- a/Source/ACE.Server/Entity/GeneratorProfile.cs +++ b/Source/ACE.Server/Entity/GeneratorProfile.cs @@ -176,7 +176,7 @@ public void Enqueue(int numObjects = 1) { /*if (MaxObjectsSpawned) { - log.Debug($"{_generator.Name}.Enqueue({numObjects}): max objects reached"); + log.DebugFormat("{0}.Enqueue({1}): max objects reached", _generator.Name, numObjects); break; }*/ SpawnQueue.Add(GetSpawnTime()); @@ -275,7 +275,7 @@ public List Spawn() foreach (var obj in objects) { - //log.Debug($"{_generator.Name}.Spawn({obj.Name})"); + //log.DebugFormat("{0}.Spawn({1})", _generator.Name, obj.Name); obj.Generator = Generator; obj.GeneratorId = Generator.Guid.Full; @@ -305,7 +305,8 @@ public List Spawn() // This object still may be returned in the spawned collection if FirstSpawn is true. This is to prevent retry spam. if (!success) { - log.Debug($"[GENERATOR] 0x{Generator.Guid}:{Generator.WeenieClassId} {Generator.Name}.Spawn(): failed to spawn {obj.Name} (0x{obj.Guid}:{obj.WeenieClassId}) from profile {LinkId} at {RegenLocationType}{(obj.Location != null ? $"\n Gen LOC: {Generator.Location?.ToLOCString()}\n Obj LOC: {obj.Location.ToLOCString()}" : "")}"); + if (log.IsDebugEnabled) + log.Debug($"[GENERATOR] 0x{Generator.Guid}:{Generator.WeenieClassId} {Generator.Name}.Spawn(): failed to spawn {obj.Name} (0x{obj.Guid}:{obj.WeenieClassId}) from profile {LinkId} at {RegenLocationType}{(obj.Location != null ? $"\n Gen LOC: {Generator.Location?.ToLOCString()}\n Obj LOC: {obj.Location.ToLOCString()}" : "")}"); obj.Destroy(); } } @@ -417,7 +418,7 @@ public bool Spawn_Shop(WorldObject obj) public bool Spawn_Default(WorldObject obj) { // default location handler? - //log.Debug($"{_generator.Name}.Spawn_Default({obj.Name}): default handler for RegenLocationType {RegenLocationType}"); + //log.DebugFormat("{0}.Spawn_Default({1}): default handler for RegenLocationType {2}", _generator.Name, obj.Name, RegenLocationType); obj.Location = new ACE.Entity.Position(Generator.Location); @@ -428,7 +429,7 @@ public bool VerifyLandblock(WorldObject obj) { if (obj.Location == null || obj.Location.Landblock != Generator.Location.Landblock) { - //log.Debug($"{_generator.Name}.VerifyLandblock({obj.Name}) - spawn location is invalid landblock"); + //log.DebugFormat("{0}.VerifyLandblock({1}) - spawn location is invalid landblock", _generator.Name, obj.Name); return false; } return true; @@ -438,7 +439,7 @@ public bool VerifyWalkableSlope(WorldObject obj) { if (!obj.Location.Indoors && !obj.Location.IsWalkable() && !VerifyWalkableSlopeExcludedLandblocks.Contains(obj.Location.LandblockId.Landblock)) { - //log.Debug($"{_generator.Name}.VerifyWalkableSlope({obj.Name}) - spawn location is unwalkable slope"); + //log.DebugFormat("{0}.VerifyWalkableSlope({1}) - spawn location is unwalkable slope", _generator.Name, obj.Name); return false; } return true; @@ -469,7 +470,7 @@ public List TreasureGenerator() if (deathTreasure != null) { // TODO: get randomly generated death treasure from LootGenerationFactory - //log.Debug($"{_generator.Name}.TreasureGenerator(): found death treasure {Biota.WeenieClassId}"); + //log.DebugFormat("{0}.TreasureGenerator(): found death treasure {1}", _generator.Name, Biota.WeenieClassId); return LootGenerationFactory.CreateRandomLootObjects(deathTreasure); } else @@ -478,7 +479,7 @@ public List TreasureGenerator() if (wieldedTreasure != null) { // TODO: get randomly generated wielded treasure from LootGenerationFactory - //log.Debug($"{_generator.Name}.TreasureGenerator(): found wielded treasure {Biota.WeenieClassId}"); + //log.DebugFormat("{0}.TreasureGenerator(): found wielded treasure {1}", _generator.Name, Biota.WeenieClassId); // roll into the wielded treasure table //var table = new TreasureWieldedTable(wieldedTreasure); @@ -486,7 +487,7 @@ public List TreasureGenerator() } else { - log.Debug($"[GENERATOR] 0x{Generator.Guid}:{Generator.WeenieClassId} {Generator.Name}.TreasureGenerator(): couldn't find death treasure or wielded treasure for ID {Biota.WeenieClassId}"); + log.DebugFormat("[GENERATOR] 0x{0}:{1} {2}.TreasureGenerator(): couldn't find death treasure or wielded treasure for ID {3}", Generator.Guid, Generator.WeenieClassId, Generator.Name, Biota.WeenieClassId); return null; } } @@ -500,7 +501,7 @@ public void RemoveTreasure() var container = Generator as Container; if (container == null) { - log.Warn($"[GENERATOR] 0x{Generator.Guid}:{Generator.WeenieClassId} {Generator.Name}.RemoveTreasure(): container not found"); + log.WarnFormat("[GENERATOR] 0x{0}:{1} {2}.RemoveTreasure(): container not found", Generator.Guid, Generator.WeenieClassId, Generator.Name); return; } foreach (var spawned in Spawned.Keys) @@ -508,7 +509,7 @@ public void RemoveTreasure() var inventoryObjGuid = new ObjectGuid(spawned); if (!container.Inventory.TryGetValue(inventoryObjGuid, out var inventoryObj)) { - log.Warn($"[GENERATOR] 0x{Generator.Guid}:{Generator.WeenieClassId} {Generator.Name}.RemoveTreasure(): couldn't find {inventoryObjGuid}"); + log.WarnFormat("[GENERATOR] 0x{0}:{1} {2}.RemoveTreasure(): couldn't find {3}", Generator.Guid, Generator.WeenieClassId, Generator.Name, inventoryObjGuid); continue; } container.TryRemoveFromInventory(inventoryObjGuid); @@ -524,7 +525,7 @@ public void RemoveTreasure() /// public void NotifyGenerator(ObjectGuid target, RegenerationType eventType) { - //log.Debug($"{_generator.Name}.NotifyGenerator({target:X8}, {eventType})"); + //log.DebugFormat("{0}.NotifyGenerator({1:X8}, {2})", _generator.Name, target, eventType); Spawned.TryGetValue(target.Full, out var woi); diff --git a/Source/ACE.Server/Entity/Landblock.cs b/Source/ACE.Server/Entity/Landblock.cs index 23e911f913..f192a5f1df 100644 --- a/Source/ACE.Server/Entity/Landblock.cs +++ b/Source/ACE.Server/Entity/Landblock.cs @@ -167,7 +167,7 @@ public EnvironChangeType FogColor public Landblock(LandblockId id) { - //log.Debug($"Landblock({(id.Raw | 0xFFFF):X8})"); + //log.DebugFormat("Landblock({0:X8})", (id.Raw | 0xFFFF)); Id = id; @@ -866,11 +866,15 @@ private bool AddWorldObjectInternal(WorldObject wo) if (wo.Generator != null) { - log.Debug($"AddWorldObjectInternal: couldn't spawn 0x{wo.Guid}:{wo.Name} [{wo.WeenieClassId} - {wo.WeenieType}] at {wo.Location.ToLOCString()} from generator {wo.Generator.WeenieClassId} - 0x{wo.Generator.Guid}:{wo.Generator.Name}"); + if (log.IsDebugEnabled) + log.Debug($"AddWorldObjectInternal: couldn't spawn 0x{wo.Guid}:{wo.Name} [{wo.WeenieClassId} - {wo.WeenieType}] at {wo.Location.ToLOCString()} from generator {wo.Generator.WeenieClassId} - 0x{wo.Generator.Guid}:{wo.Generator.Name}"); wo.NotifyOfEvent(RegenerationType.PickUp); // Notify generator the generated object is effectively destroyed, use Pickup to catch both cases. } else if (wo.IsGenerator) // Some generators will fail random spawns if they're circumference spans over water or cliff edges - log.Debug($"AddWorldObjectInternal: couldn't spawn generator 0x{wo.Guid}:{wo.Name} [{wo.WeenieClassId} - {wo.WeenieType}] at {wo.Location.ToLOCString()}"); + { + if (log.IsDebugEnabled) + log.Debug($"AddWorldObjectInternal: couldn't spawn generator 0x{wo.Guid}:{wo.Name} [{wo.WeenieClassId} - {wo.WeenieType}] at {wo.Location.ToLOCString()}"); + } else if (wo.ProjectileTarget == null && !(wo is SpellProjectile)) log.Warn($"AddWorldObjectInternal: couldn't spawn 0x{wo.Guid}:{wo.Name} [{wo.WeenieClassId} - {wo.WeenieType}] at {wo.Location.ToLOCString()}"); @@ -1118,7 +1122,7 @@ public void Unload() { var landblockID = Id.Raw | 0xFFFF; - //log.Debug($"Landblock.Unload({landblockID:X8})"); + //log.DebugFormat("Landblock.Unload({0:X8})", landblockID); ProcessPendingWorldObjectAdditionsAndRemovals(); diff --git a/Source/ACE.Server/Entity/Spell.cs b/Source/ACE.Server/Entity/Spell.cs index dae6029544..c58c45e00b 100644 --- a/Source/ACE.Server/Entity/Spell.cs +++ b/Source/ACE.Server/Entity/Spell.cs @@ -81,7 +81,7 @@ public void Init(uint spellID, bool loadDB = true) Formula = new SpellFormula(this, _formula); if (loadDB && (_spell == null || _spellBase == null)) - log.Debug($"Spell.Init(spellID = {spellID}, loadDB = {loadDB}) failed! {(_spell == null ? "_spell was null" : "")} {(_spellBase == null ? "_spellBase was null" : "")}"); + log.DebugFormat("Spell.Init(spellID = {0}, loadDB = {1}) failed! {2} {3}", spellID, loadDB, (_spell == null ? "_spell was null" : ""), (_spellBase == null ? "_spellBase was null" : "")); } /// diff --git a/Source/ACE.Server/Factories/LootGenerationFactory_Clothing.cs b/Source/ACE.Server/Factories/LootGenerationFactory_Clothing.cs index ab028f8e5e..aa78f8ad06 100644 --- a/Source/ACE.Server/Factories/LootGenerationFactory_Clothing.cs +++ b/Source/ACE.Server/Factories/LootGenerationFactory_Clothing.cs @@ -404,7 +404,7 @@ private static void AssignArmorLevel(WorldObject wo, int tier, LootTables.ArmorT private static void AssignArmorLevelCompat(WorldObject wo, int tier, LootTables.ArmorType armorType) { - log.Debug($"[LOOT] Using AL Assignment Compatibility layer for item {wo.WeenieClassId} - {wo.Name}."); + log.DebugFormat("[LOOT] Using AL Assignment Compatibility layer for item {0} - {1}.", wo.WeenieClassId, wo.Name); var baseArmorLevel = wo.ArmorLevel ?? 0; diff --git a/Source/ACE.Server/Managers/EventManager.cs b/Source/ACE.Server/Managers/EventManager.cs index f7f281bad2..ea22a846e9 100644 --- a/Source/ACE.Server/Managers/EventManager.cs +++ b/Source/ACE.Server/Managers/EventManager.cs @@ -60,7 +60,8 @@ public static bool StartEvent(string e, WorldObject source, WorldObject target) Console.WriteLine($"Starting event {evnt.Name}"); } - log.Debug($"[EVENT] {(source == null ? "SYSTEM" : $"{source.Name} (0x{source.Guid}|{source.WeenieClassId})")}{(target == null ? "" : $", triggered by {target.Name} (0x{target.Guid}|{target.WeenieClassId}),")} started an event: {evnt.Name}{((int)state == evnt.State ? (source == null ? ", which is the default state for this event." : ", which had already been started.") : "")}"); + if (log.IsDebugEnabled) + log.Debug($"[EVENT] {(source == null ? "SYSTEM" : $"{source.Name} (0x{source.Guid}|{source.WeenieClassId})")}{(target == null ? "" : $", triggered by {target.Name} (0x{target.Guid}|{target.WeenieClassId}),")} started an event: {evnt.Name}{((int)state == evnt.State ? (source == null ? ", which is the default state for this event." : ", which had already been started.") : "")}"); return true; } @@ -88,7 +89,8 @@ public static bool StopEvent(string e, WorldObject source, WorldObject target) Console.WriteLine($"Stopping event {evnt.Name}"); } - log.Debug($"[EVENT] {(source == null ? "SYSTEM" : $"{source.Name} (0x{source.Guid}|{source.WeenieClassId})")}{(target == null ? "" : $", triggered by {target.Name} (0x{target.Guid}|{target.WeenieClassId}),")} stopped an event: {evnt.Name}{((int)state == evnt.State ? (source == null ? ", which is the default state for this event." : ", which had already been stopped.") : "")}"); + if (log.IsDebugEnabled) + log.Debug($"[EVENT] {(source == null ? "SYSTEM" : $"{source.Name} (0x{source.Guid}|{source.WeenieClassId})")}{(target == null ? "" : $", triggered by {target.Name} (0x{target.Guid}|{target.WeenieClassId}),")} stopped an event: {evnt.Name}{((int)state == evnt.State ? (source == null ? ", which is the default state for this event." : ", which had already been stopped.") : "")}"); return true; } diff --git a/Source/ACE.Server/Managers/GuidManager.cs b/Source/ACE.Server/Managers/GuidManager.cs index acc3dfd680..a2206c5860 100644 --- a/Source/ACE.Server/Managers/GuidManager.cs +++ b/Source/ACE.Server/Managers/GuidManager.cs @@ -62,10 +62,10 @@ public PlayerGuidAllocator(uint min, uint max, string name) // Need to start allocating at current value in db +1 current++; - log.Debug($"{name} GUID Allocator current is now {current:X8} of {max:X8}"); + log.DebugFormat("{0} GUID Allocator current is now {1:X8} of {2:X8}", name, current, max); if ((max - current) < LowIdLimit) - log.Warn($"Dangerously low on {name} GUIDs: {current:X8} of {max:X8}"); + log.WarnFormat("Dangerously low on {0} GUIDs: {1:X8} of {2:X8}", name, current, max); } this.name = name; @@ -77,12 +77,12 @@ public uint Alloc() { if (current == max) { - log.Fatal($"Out of {name} GUIDs!"); + log.FatalFormat("Out of {0} GUIDs!", name); return InvalidGuid; } if (current == max - LowIdLimit) - log.Warn($"Running dangerously low on {name} GUIDs, need to defrag"); + log.WarnFormat("Running dangerously low on {0} GUIDs, need to defrag", name); uint ret = current; current += 1; @@ -154,10 +154,10 @@ public DynamicGuidAllocator(uint min, uint max, string name) // Need to start allocating at current value in db +1 current++; - log.Debug($"{name} GUID Allocator current is now {current:X8} of {max:X8}"); + log.DebugFormat("{0} GUID Allocator current is now {1:X8} of {2:X8}", name, current, max); if ((max - current) < LowIdLimit) - log.Warn($"Dangerously low on {name} GUIDs: {current:X8} of {max:X8}"); + log.WarnFormat("Dangerously low on {0} GUIDs: {1:X8} of {2:X8}", name, current, max); } // Get available ids in the form of sequence gaps @@ -172,7 +172,7 @@ public DynamicGuidAllocator(uint min, uint max, string name) uint total = 0; foreach (var pair in availableIDs) total += (pair.end - pair.start) + 1; - log.Debug($"{name} GUID Sequence gaps initialized with total availableIDs of {total:N0}"); + log.DebugFormat("{0} GUID Sequence gaps initialized with total availableIDs of {1:N0}", name, total); done = true; Monitor.Pulse(this); } @@ -217,7 +217,7 @@ public uint Alloc() { if (!useSequenceGapExhaustedMessageDisplayed) { - log.Debug($"{name} GUID Sequence gaps exhausted. Any new, non-recycled GUID will be current + 1. current is now {current:X8}"); + log.DebugFormat("{0} GUID Sequence gaps exhausted. Any new, non-recycled GUID will be current + 1. current is now {1:X8}", name, current); useSequenceGapExhaustedMessageDisplayed = true; } } @@ -225,12 +225,12 @@ public uint Alloc() // Lastly, use an id that increments our max if (current == max) { - log.Fatal($"Out of {name} GUIDs!"); + log.FatalFormat("Out of {0} GUIDs!", name); return InvalidGuid; } if (current == max - LowIdLimit) - log.Warn($"Running dangerously low on {name} GUIDs, need to defrag"); + log.WarnFormat("Running dangerously low on {0} GUIDs, need to defrag", name); uint ret = current; current += 1; diff --git a/Source/ACE.Server/Managers/HouseManager.cs b/Source/ACE.Server/Managers/HouseManager.cs index eb940f66bb..d218fdc548 100644 --- a/Source/ACE.Server/Managers/HouseManager.cs +++ b/Source/ACE.Server/Managers/HouseManager.cs @@ -183,7 +183,7 @@ public static void AddRentQueue(IPlayer player, uint houseGuid) if (player.HouseRentTimestamp == null) { - log.Warn($"[HOUSE] HouseManager.AddRentQueue({player.Name}, {houseGuid:X8}): player has null HouseRentTimestamp"); + log.WarnFormat("[HOUSE] HouseManager.AddRentQueue({0}, {1:X8}): player has null HouseRentTimestamp", player.Name, houseGuid); player.HouseRentTimestamp = (int)house.GetRentDue(purchaseTime); //return; } @@ -363,7 +363,7 @@ private static void ProcessRent(PlayerHouse playerHouse) var isInActiveOrDisabled = playerHouse.House.HouseStatus <= HouseStatus.InActive; var isPaid = IsRentPaid(playerHouse); var hasRequirements = HasRequirements(playerHouse); - log.Debug($"[HOUSE] {playerHouse.PlayerName}.ProcessRent(): isPaid = {isPaid} | HasRequirements = {hasRequirements} | MaintenanceFree = {house.HouseStatus == HouseStatus.InActive}"); + log.DebugFormat("[HOUSE] {0}.ProcessRent(): isPaid = {1} | HasRequirements = {2} | MaintenanceFree = {3}", playerHouse.PlayerName, isPaid, hasRequirements, (house.HouseStatus == HouseStatus.InActive)); if (isInActiveOrDisabled || (isPaid && hasRequirements)) HandleRentPaid(playerHouse); @@ -381,7 +381,7 @@ private static void HandleRentPaid(PlayerHouse playerHouse) var player = PlayerManager.FindByGuid(playerHouse.PlayerGuid); if (player == null) { - log.Warn($"[HOUSE] HouseManager.HandleRentPaid({playerHouse.PlayerName}): couldn't find player"); + log.WarnFormat("[HOUSE] HouseManager.HandleRentPaid({0}): couldn't find player", playerHouse.PlayerName); return; } @@ -392,7 +392,7 @@ private static void HandleRentPaid(PlayerHouse playerHouse) if (nextRentTime <= rentTime) { - log.Warn($"[HOUSE] HouseManager.HandleRentPaid({playerHouse.PlayerName}): nextRentTime {nextRentTime} <= rentTime {rentTime}"); + log.WarnFormat("[HOUSE] HouseManager.HandleRentPaid({0}): nextRentTime {1} <= rentTime {2}", playerHouse.PlayerName, nextRentTime, rentTime); return; } @@ -409,7 +409,7 @@ private static void HandleRentPaid(PlayerHouse playerHouse) slumlord.SaveBiotaToDatabase(); } - log.Debug($"[HOUSE] HouseManager.HandleRentPaid({playerHouse.PlayerName}): rent payment successful!"); + log.DebugFormat("[HOUSE] HouseManager.HandleRentPaid({0}): rent payment successful!", playerHouse.PlayerName); // re-add item to queue AddRentQueue(player, playerHouse.House); @@ -450,7 +450,7 @@ public static void HandleEviction(House house, uint playerGuid, bool multihouse var nextRentTime = house.GetRentDue(purchaseTime); player.HouseRentTimestamp = (int)nextRentTime; - log.Debug($"[HOUSE] HouseManager.HandleRentPaid({player.Name}): house rent disabled via config"); + log.DebugFormat("[HOUSE] HouseManager.HandleRentPaid({0}): house rent disabled via config", player.Name); // re-add item to queue AddRentQueue(player, house); @@ -496,11 +496,11 @@ public static void HandleEviction(House house, uint playerGuid, bool multihouse player.HouseRentTimestamp = null; } else - log.Warn($"[HOUSE] HouseManager.HandleRentEviction({house.Guid}, {player.Name}, {multihouse}): house guids don't match {player.HouseInstance}"); + log.WarnFormat("[HOUSE] HouseManager.HandleRentEviction({0}, {1}, {2}): house guids don't match {3}", house.Guid, player.Name, multihouse, player.HouseInstance); house.ClearRestrictions(); - log.Debug($"[HOUSE] HouseManager.HandleRentEviction({player.Name})"); + log.DebugFormat("[HOUSE] HouseManager.HandleRentEviction({0})", player.Name); if (multihouse) { @@ -517,7 +517,7 @@ public static void HandleEviction(House house, uint playerGuid, bool multihouse var offlinePlayer = PlayerManager.GetOfflinePlayer(playerGuid); if (offlinePlayer == null) { - log.Warn($"[HOUSE] {player.Name}.HandleEviction(): couldn't find offline player"); + log.WarnFormat("[HOUSE] {0}.HandleEviction(): couldn't find offline player", player.Name); return; } offlinePlayer.SetProperty(PropertyBool.HouseEvicted, true); @@ -553,7 +553,8 @@ private static bool IsRentPaid(PlayerHouse playerHouse) { if (rentItem.Paid < rentItem.Num) { - log.Debug($"[HOUSE] {playerHouse.PlayerName}.IsRentPaid() - required {rentItem.Num:N0}x {(rentItem.Num > 1 ? $"{rentItem.PluralName}" : $"{rentItem.Name}")} ({rentItem.WeenieID}), found {rentItem.Paid:N0}"); + if (log.IsDebugEnabled) + log.Debug($"[HOUSE] {playerHouse.PlayerName}.IsRentPaid() - required {rentItem.Num:N0}x {(rentItem.Num > 1 ? $"{rentItem.PluralName}" : $"{rentItem.Name}")} ({rentItem.WeenieID}), found {rentItem.Paid:N0}"); return false; } } @@ -580,7 +581,7 @@ private static bool HasRequirements(PlayerHouse playerHouse) if (player == null) { - log.Warn($"[HOUSE] {playerHouse.PlayerName}.HasRequirements() - couldn't find player"); + log.WarnFormat("[HOUSE] {0}.HasRequirements() - couldn't find player", playerHouse.PlayerName); return false; } @@ -595,7 +596,7 @@ private static bool HasRequirements(PlayerHouse playerHouse) if (allegianceMinLevel > 0 && (allegiance == null || rank < allegianceMinLevel)) { - log.Debug($"[HOUSE] {playerHouse.PlayerName}.HasRequirements() - allegiance rank {rank} < {allegianceMinLevel}"); + log.DebugFormat("[HOUSE] {0}.HasRequirements() - allegiance rank {1} < {2}", playerHouse.PlayerName, rank, allegianceMinLevel); return false; } return true; @@ -737,7 +738,7 @@ public static void GetHouse(uint houseGuid, Action callback) RegisterCallback(houseBiota, callback); } else - log.Error($"[HOUSE] HouseManager.GetHouse({houseGuid:X8}): couldn't find house on loaded landblock"); + log.ErrorFormat("[HOUSE] HouseManager.GetHouse({0:X8}): couldn't find house on loaded landblock", houseGuid); } /// @@ -888,7 +889,7 @@ private static void PayRent(PlayerHouse playerHouse) actionChain.EnqueueChain(); } - log.Debug($"[HOUSE] HouseManager.PayRent({house.Guid}): fully paid rent into SlumLord."); + log.DebugFormat("[HOUSE] HouseManager.PayRent({0}): fully paid rent into SlumLord.", house.Guid); } }); } diff --git a/Source/ACE.Server/Managers/LandblockManager.cs b/Source/ACE.Server/Managers/LandblockManager.cs index 330d602719..d594d93c58 100644 --- a/Source/ACE.Server/Managers/LandblockManager.cs +++ b/Source/ACE.Server/Managers/LandblockManager.cs @@ -621,22 +621,22 @@ private static void UnloadLandblocks() swTrySplitEach.Stop(); if (swTrySplitEach.Elapsed.TotalMilliseconds > 3) - log.Warn($"[LANDBLOCK GROUP] TrySplit for {landblockGroups[i]} took: {swTrySplitEach.Elapsed.TotalMilliseconds:N2} ms"); + log.WarnFormat("[LANDBLOCK GROUP] TrySplit for {0} took: {1:N2} ms", landblockGroups[i], swTrySplitEach.Elapsed.TotalMilliseconds); else if (swTrySplitEach.Elapsed.TotalMilliseconds > 1) - log.Debug($"[LANDBLOCK GROUP] TrySplit for {landblockGroups[i]} took: {swTrySplitEach.Elapsed.TotalMilliseconds:N2} ms"); + log.DebugFormat("[LANDBLOCK GROUP] TrySplit for {0} took: {1:N2} ms", landblockGroups[i], swTrySplitEach.Elapsed.TotalMilliseconds); if (splits != null) { if (splits.Count > 0) { - log.Debug($"[LANDBLOCK GROUP] TrySplit resulted in {splits.Count} split(s) and took: {swTrySplitEach.Elapsed.TotalMilliseconds:N2} ms"); - log.Debug($"[LANDBLOCK GROUP] split for old: {landblockGroups[i]}"); + log.DebugFormat("[LANDBLOCK GROUP] TrySplit resulted in {0} split(s) and took: {1:N2} ms", splits.Count, swTrySplitEach.Elapsed.TotalMilliseconds); + log.DebugFormat("[LANDBLOCK GROUP] split for old: {0}", landblockGroups[i]); } foreach (var split in splits) { landblockGroups.Add(split); - log.Debug($"[LANDBLOCK GROUP] split and new: {split}"); + log.DebugFormat("[LANDBLOCK GROUP] split and new: {0}", split); } } } diff --git a/Source/ACE.Server/Managers/PropertyManager.cs b/Source/ACE.Server/Managers/PropertyManager.cs index d32b6bd629..5655dcfb8f 100644 --- a/Source/ACE.Server/Managers/PropertyManager.cs +++ b/Source/ACE.Server/Managers/PropertyManager.cs @@ -381,7 +381,7 @@ private static void DoWork(Object source, ElapsedEventArgs e) // next, we need to fetch all of the variables from the DB and compare them quickly. LoadPropertiesFromDB(); - log.Debug($"PropertyManager DoWork took {(DateTime.UtcNow - startTime).TotalMilliseconds:N0} ms"); + log.DebugFormat("PropertyManager DoWork took {0:N0} ms", (DateTime.UtcNow - startTime).TotalMilliseconds); } public static string ListProperties() { diff --git a/Source/ACE.Server/Managers/QuestManager.cs b/Source/ACE.Server/Managers/QuestManager.cs index ee74a5359b..8eea042c4a 100644 --- a/Source/ACE.Server/Managers/QuestManager.cs +++ b/Source/ACE.Server/Managers/QuestManager.cs @@ -589,7 +589,7 @@ public void HandleKillTask(string killQuestName, WorldObject killedCreature) if (killedCreature == null) { - log.Error($"{Name}.QuestManager.HandleKillTask({killQuestName}): input object is null!"); + log.ErrorFormat("{0}.QuestManager.HandleKillTask({1}): input object is null!", Name, killQuestName); return; } @@ -598,7 +598,7 @@ public void HandleKillTask(string killQuestName, WorldObject killedCreature) if (quest == null) { - log.Error($"{Name}.QuestManager.HandleKillTask({killQuestName}): couldn't find kill task {questName} in database"); + log.ErrorFormat("{0}.QuestManager.HandleKillTask({1}): couldn't find kill task {2} in database", Name, killQuestName, questName); return; } @@ -612,7 +612,7 @@ public void HandleKillTask(string killQuestName, WorldObject killedCreature) if (playerQuest == null) { // this should be impossible - log.Error($"{Name}.QuestManager.HandleKillTask({killQuestName}): couldn't find kill task {questName} in player quests"); + log.ErrorFormat("{0}.QuestManager.HandleKillTask({1}): couldn't find kill task {2} in player quests", Name, killQuestName, questName); return; } diff --git a/Source/ACE.Server/Managers/RecipeManager.cs b/Source/ACE.Server/Managers/RecipeManager.cs index 37c78f2fa0..bec6e99651 100644 --- a/Source/ACE.Server/Managers/RecipeManager.cs +++ b/Source/ACE.Server/Managers/RecipeManager.cs @@ -21,6 +21,7 @@ using ACE.Server.Network.GameEvent.Events; using ACE.Server.Network.GameMessages.Messages; using ACE.Server.WorldObjects; +using Microsoft.EntityFrameworkCore.ChangeTracking; namespace ACE.Server.Managers { @@ -80,7 +81,7 @@ public static void UseObjectOnTarget(Player player, WorldObject source, WorldObj } if (recipe.IsTinkering()) - log.Debug($"[TINKERING] {player.Name}.UseObjectOnTarget({source.NameWithMaterial}, {target.NameWithMaterial}) | Status: {(confirmed ? "" : "un")}confirmed"); + log.DebugFormat("[TINKERING] {0}.UseObjectOnTarget({1}, {2}) | Status: {3}confirmed", player.Name, source.NameWithMaterial, target.NameWithMaterial, (confirmed ? "" : "un")); var percentSuccess = GetRecipeChance(player, source, target, recipe); @@ -1067,7 +1068,8 @@ public static HashSet CreateDestroyItems(Player player, Recipe recipe, Wor player.Session.Network.EnqueueSend(new GameMessageSystemChat(message, ChatMessageType.Craft)); - log.Debug($"[CRAFTING] {player.Name} used {source.NameWithMaterial} on {target.NameWithMaterial} {(success ? "" : "un")}successfully. {(destroySource ? $"| {source.NameWithMaterial} was destroyed " : "")}{(destroyTarget ? $"| {target.NameWithMaterial} was destroyed " : "")}| {message}"); + if (log.IsDebugEnabled) + log.Debug($"[CRAFTING] {player.Name} used {source.NameWithMaterial} on {target.NameWithMaterial} {(success ? "" : "un")}successfully. {(destroySource ? $"| {source.NameWithMaterial} was destroyed " : "")}{(destroyTarget ? $"| {target.NameWithMaterial} was destroyed " : "")}| {message}"); } else BroadcastTinkering(player, source, target, successChance, success); @@ -1085,7 +1087,8 @@ public static void BroadcastTinkering(Player player, WorldObject tool, WorldObje else player.EnqueueBroadcast(new GameMessageSystemChat($"{player.Name} fails to apply the {sourceName} (workmanship {(tool.Workmanship ?? 0):#.00}) to the {target.NameWithMaterial}. The target is destroyed.", ChatMessageType.Craft), WorldObject.LocalBroadcastRange, ChatMessageType.Craft); - log.Debug($"[TINKERING] {player.Name} {(success ? "successfully applies" : "fails to apply")} the {sourceName} (workmanship {(tool.Workmanship ?? 0):#.00}) to the {target.NameWithMaterial}.{(!success ? " The target is destroyed." : "")} | Chance: {chance}"); + if (log.IsDebugEnabled) + log.Debug($"[TINKERING] {player.Name} {(success ? "successfully applies" : "fails to apply")} the {sourceName} (workmanship {(tool.Workmanship ?? 0):#.00}) to the {target.NameWithMaterial}.{(!success ? " The target is destroyed." : "")} | Chance: {chance}"); } public static WorldObject CreateItem(Player player, uint wcid, uint amount) diff --git a/Source/ACE.Server/Managers/ServerManager.cs b/Source/ACE.Server/Managers/ServerManager.cs index 2a49e6dfca..2297bb80de 100644 --- a/Source/ACE.Server/Managers/ServerManager.cs +++ b/Source/ACE.Server/Managers/ServerManager.cs @@ -149,10 +149,10 @@ private static void ShutdownServer() if (playerCount > 0 && DateTime.UtcNow - playerLogoffStart > TimeSpan.FromMinutes(5)) { playerLogoffStart = DateTime.UtcNow; - log.Warn($"5 minute log off failsafe reached and there are {playerCount} player{(playerCount > 1 ? "s" : "")} still online."); + log.WarnFormat("5 minute log off failsafe reached and there are {0} player{1} still online.", playerCount, (playerCount > 1 ? "s" : "")); foreach (var player in PlayerManager.GetAllOnline()) { - log.Warn($"Player {player.Name} (0x{player.Guid}) appears to be stuck in world and unable to log off normally. Requesting Forced Logoff..."); + log.WarnFormat("Player {0} (0x{1}) appears to be stuck in world and unable to log off normally. Requesting Forced Logoff...", player.Name, player.Guid); player.ForcedLogOffRequested = true; player.ForceLogoff(); } diff --git a/Source/ACE.Server/Managers/WorldManager.cs b/Source/ACE.Server/Managers/WorldManager.cs index 5b74644be6..2c4bdcbf1c 100644 --- a/Source/ACE.Server/Managers/WorldManager.cs +++ b/Source/ACE.Server/Managers/WorldManager.cs @@ -64,7 +64,7 @@ public static void Initialize() thread.Priority = ThreadPriority.AboveNormal; thread.Start(); log.DebugFormat("ServerTime initialized to {0}", Timers.WorldStartLoreTime); - log.DebugFormat($"Current maximum allowed sessions: {ConfigManager.Config.Server.Network.MaximumAllowedSessions}"); + log.DebugFormat("Current maximum allowed sessions: {0}", ConfigManager.Config.Server.Network.MaximumAllowedSessions); log.Info($"World started and is currently {WorldStatus.ToString()}{(PropertyManager.GetBool("world_closed", false).Item ? "" : " and will open automatically when server startup is complete.")}"); if (WorldStatus == WorldStatusState.Closed) @@ -103,7 +103,7 @@ public static void PlayerEnterWorld(Session session, Character character) var start = DateTime.UtcNow; DatabaseManager.Shard.GetPossessedBiotasInParallel(character.Id, biotas => { - log.Debug($"GetPossessedBiotasInParallel for {character.Name} took {(DateTime.UtcNow - start).TotalMilliseconds:N0} ms"); + log.DebugFormat("GetPossessedBiotasInParallel for {0} took {1:N0} ms", character.Name, (DateTime.UtcNow - start).TotalMilliseconds); ActionQueue.EnqueueAction(new ActionEventDelegate(() => DoPlayerEnterWorld(session, character, offlinePlayer.Biota, biotas))); }); diff --git a/Source/ACE.Server/Mods/ModManager.cs b/Source/ACE.Server/Mods/ModManager.cs index 45607937d5..72111fd320 100644 --- a/Source/ACE.Server/Mods/ModManager.cs +++ b/Source/ACE.Server/Mods/ModManager.cs @@ -138,7 +138,7 @@ private static bool TryLoadModContainer(string metadataPath, out ModContainer co if (!File.Exists(metadataPath)) { //Log missing metadata - log.Warn($"Metadata not found at: {metadataPath}"); + log.WarnFormat("Metadata not found at: {0}", metadataPath); return false; } diff --git a/Source/ACE.Server/Network/ConnectionListener.cs b/Source/ACE.Server/Network/ConnectionListener.cs index 3bf2ec5227..13e2299cdb 100644 --- a/Source/ACE.Server/Network/ConnectionListener.cs +++ b/Source/ACE.Server/Network/ConnectionListener.cs @@ -109,7 +109,7 @@ private void OnDataReceive(IAsyncResult result) StringBuilder sb = new StringBuilder(); sb.AppendLine($"Received Packet (Len: {data.Length}) [{ipEndpoint.Address}:{ipEndpoint.Port}=>{ListenerEndpoint.Address}:{ListenerEndpoint.Port}]"); sb.AppendLine(data.BuildPacketString()); - packetLog.Debug(sb.ToString()); + packetLog.DebugFormat("{0}", sb); } var packet = new ClientPacket(); diff --git a/Source/ACE.Server/Network/Handlers/AuthenticationHandler.cs b/Source/ACE.Server/Network/Handlers/AuthenticationHandler.cs index dc4532777b..078c2212fa 100644 --- a/Source/ACE.Server/Network/Handlers/AuthenticationHandler.cs +++ b/Source/ACE.Server/Network/Handlers/AuthenticationHandler.cs @@ -66,7 +66,7 @@ private static void DoLogin(Session session, PacketInboundLoginRequest loginRequ if (WorldManager.WorldStatus == WorldManager.WorldStatusState.Open) log.Info($"Auto creating account for: {loginRequest.Account}"); else - log.Debug($"Auto creating account for: {loginRequest.Account}"); + log.DebugFormat("Auto creating account for: {0}", loginRequest.Account); var accessLevel = (AccessLevel)ConfigManager.Config.Server.Accounts.DefaultAccessLevel; @@ -87,7 +87,7 @@ private static void DoLogin(Session session, PacketInboundLoginRequest loginRequ try { - log.Debug($"new client connected: {loginRequest.Account}. setting session properties"); + log.DebugFormat("new client connected: {0}. setting session properties", loginRequest.Account); AccountSelectCallback(account, session, loginRequest); } catch (Exception ex) @@ -138,9 +138,9 @@ private static void AccountSelectCallback(Account account, Session session, Pack } if (WorldManager.WorldStatus == WorldManager.WorldStatusState.Open) - log.Info($"client {loginRequest.Account} connected with no Password or GlsTicket included so booting"); + log.InfoFormat("client {0} connected with no Password or GlsTicket included so booting", loginRequest.Account); else - log.Debug($"client {loginRequest.Account} connected with no Password or GlsTicket included so booting"); + log.DebugFormat("client {0} connected with no Password or GlsTicket included so booting", loginRequest.Account); session.Terminate(SessionTerminationReason.NotAuthorizedNoPasswordOrGlsTicketIncludedInLoginReq, new GameMessageCharacterError(CharacterError.AccountInvalid)); @@ -169,7 +169,7 @@ private static void AccountSelectCallback(Account account, Session session, Pack if (WorldManager.WorldStatus == WorldManager.WorldStatusState.Open) log.Info($"client {loginRequest.Account} connected with non matching password so booting"); else - log.Debug($"client {loginRequest.Account} connected with non matching password so booting"); + log.DebugFormat("client {0} connected with non matching password so booting", loginRequest.Account); session.Terminate(SessionTerminationReason.NotAuthorizedPasswordMismatch, new GameMessageBootAccount(" because the password entered for this account was not correct")); @@ -197,14 +197,14 @@ private static void AccountSelectCallback(Account account, Session session, Pack if (WorldManager.WorldStatus == WorldManager.WorldStatusState.Open) log.Info($"client {loginRequest.Account} connected with verified password"); else - log.Debug($"client {loginRequest.Account} connected with verified password"); + log.DebugFormat("client {0} connected with verified password", loginRequest.Account); } else if (loginRequest.NetAuthType == NetAuthType.GlsTicket) { if (WorldManager.WorldStatus == WorldManager.WorldStatusState.Open) log.Info($"client {loginRequest.Account} connected with GlsTicket which is not implemented yet so booting"); else - log.Debug($"client {loginRequest.Account} connected with GlsTicket which is not implemented yet so booting"); + log.DebugFormat("client {0} connected with GlsTicket which is not implemented yet so booting", loginRequest.Account); session.Terminate(SessionTerminationReason.NotAuthorizedGlsTicketNotImplementedToProcLoginReq, new GameMessageCharacterError(CharacterError.AccountInvalid)); diff --git a/Source/ACE.Server/Network/Handlers/TurbineChatHandler.cs b/Source/ACE.Server/Network/Handlers/TurbineChatHandler.cs index 7cd1cb824e..9a6e01709a 100644 --- a/Source/ACE.Server/Network/Handlers/TurbineChatHandler.cs +++ b/Source/ACE.Server/Network/Handlers/TurbineChatHandler.cs @@ -104,10 +104,10 @@ public static void TurbineChatReceived(ClientMessage clientMessage, Session sess } if (channelID != adjustedChannelID) - log.Debug($"[CHAT] ChannelID ({channelID}) was adjusted to {adjustedChannelID} | ChatNetworkBlobDispatchType: {chatBlobDispatchType}"); + log.DebugFormat("[CHAT] ChannelID ({0}) was adjusted to {1} | ChatNetworkBlobDispatchType: {2}", channelID, adjustedChannelID, chatBlobDispatchType); if (chatType != adjustedchatType) - log.Debug($"[CHAT] ChatType ({chatType}) was adjusted to {adjustedchatType} | ChatNetworkBlobDispatchType: {chatBlobDispatchType}"); + log.DebugFormat("[CHAT] ChatType ({0}) was adjusted to {1} | ChatNetworkBlobDispatchType: {2}", chatType, adjustedchatType, chatBlobDispatchType); var gameMessageTurbineChat = new GameMessageTurbineChat(ChatNetworkBlobType.NETBLOB_EVENT_BINARY, ChatNetworkBlobDispatchType.ASYNCMETHOD_SENDTOROOMBYNAME, adjustedChannelID, session.Player.Name, message, senderID, adjustedchatType); diff --git a/Source/ACE.Server/Network/Managers/NetworkManager.cs b/Source/ACE.Server/Network/Managers/NetworkManager.cs index fbbc687f72..a0a6c1eac1 100644 --- a/Source/ACE.Server/Network/Managers/NetworkManager.cs +++ b/Source/ACE.Server/Network/Managers/NetworkManager.cs @@ -49,7 +49,7 @@ public static void ProcessPacket(ConnectionListener connectionListener, ClientPa //ServerPerformanceMonitor.RestartEvent(ServerPerformanceMonitor.MonitorType.ProcessPacket_1); if (packet.Header.Flags.HasFlag(PacketHeaderFlags.ConnectResponse)) { - packetLog.Debug($"{packet}, {endPoint}"); + packetLog.DebugFormat("{0}, {1}", packet, endPoint); PacketInboundConnectResponse connectResponse = new PacketInboundConnectResponse(packet); // This should be set on the second packet to the server from the client. @@ -95,7 +95,7 @@ public static void ProcessPacket(ConnectionListener connectionListener, ClientPa //ServerPerformanceMonitor.RestartEvent(ServerPerformanceMonitor.MonitorType.ProcessPacket_0); if (packet.Header.HasFlag(PacketHeaderFlags.LoginRequest)) { - packetLog.Debug($"{packet}, {endPoint}"); + packetLog.DebugFormat("{0}, {1}", packet, endPoint); if (GetAuthenticatedSessionCount() >= ConfigManager.Config.Server.Network.MaximumAllowedSessions) { log.InfoFormat("Login Request from {0} rejected. Server full.", endPoint); diff --git a/Source/ACE.Server/Network/NetworkSession.cs b/Source/ACE.Server/Network/NetworkSession.cs index 237b4df079..e58ed0d6a9 100644 --- a/Source/ACE.Server/Network/NetworkSession.cs +++ b/Source/ACE.Server/Network/NetworkSession.cs @@ -19,6 +19,7 @@ using ACE.Server.Network.Packets; using log4net; +using log4net.Util; namespace ACE.Server.Network { @@ -169,7 +170,8 @@ public void EnqueueSend(params ServerPacket[] packets) foreach (var packet in packets) { - packetLog.DebugFormat("[{0}] Enqueuing Packet {1}", session.LoggingIdentifier, packet.GetHashCode()); + if (packetLog.IsDebugEnabled) + packetLog.DebugFormat("[{0}] Enqueuing Packet {1}", session.LoggingIdentifier, packet.GetHashCode()); packetQueue.Enqueue(packet); } } @@ -419,7 +421,8 @@ private void DoRequestForRetransmission(uint rcvdSeq) EnqueueSend(reqPacket); LastRequestForRetransmitTime = DateTime.UtcNow; - packetLog.DebugFormat("[{0}] Requested retransmit of {1}", session.LoggingIdentifier, needSeq.Select(k => k.ToString()).Aggregate((a, b) => a + ", " + b)); + if (packetLog.IsDebugEnabled) + packetLog.DebugFormat("[{0}] Requested retransmit of {1}", session.LoggingIdentifier, needSeq.Select(k => k.ToString()).Aggregate((a, b) => a + ", " + b)); NetworkStatistics.S2C_RequestsForRetransmit_Aggregate_Increment(); } @@ -460,7 +463,7 @@ private void HandleOrderedPacket(ClientPacket packet) // In our current implimenation we handle all roles in this one server. if (packet.Header.HasFlag(PacketHeaderFlags.LoginRequest)) { - packetLog.Debug($"[{session.LoggingIdentifier}] LoginRequest"); + packetLog.DebugFormat("[{0}] LoginRequest", session.LoggingIdentifier); AuthenticationHandler.HandleLoginRequest(packet, session); return; } @@ -731,13 +734,15 @@ private void FlushPackets() private void SendPacket(ServerPacket packet) { - packetLog.DebugFormat("[{0}] Sending packet {1}", session.LoggingIdentifier, packet.GetHashCode()); + if (packetLog.IsDebugEnabled) + packetLog.DebugFormat("[{0}] Sending packet {1}", session.LoggingIdentifier, packet.GetHashCode()); NetworkStatistics.S2C_Packets_Aggregate_Increment(); if (packet.Header.HasFlag(PacketHeaderFlags.EncryptedChecksum)) { uint issacXor = ConnectionData.IssacServer.Next(); - packetLog.DebugFormat("[{0}] Setting Issac for packet {1} to {2}", session.LoggingIdentifier, packet.GetHashCode(), issacXor); + if (packetLog.IsDebugEnabled) + packetLog.DebugFormat("[{0}] Setting Issac for packet {1} to {2}", session.LoggingIdentifier, packet.GetHashCode(), issacXor); packet.IssacXor = issacXor; } @@ -756,7 +761,7 @@ private void SendPacketRaw(ServerPacket packet) packet.CreateReadyToSendPacket(buffer, out var size); - packetLog.Debug(packet.ToString()); + packetLog.DebugFormat("{0}", packet); if (packetLog.IsDebugEnabled) { @@ -764,7 +769,7 @@ private void SendPacketRaw(ServerPacket packet) var sb = new StringBuilder(); sb.AppendLine(String.Format("[{5}] Sending Packet (Len: {0}) [{1}:{2}=>{3}:{4}]", size, listenerEndpoint.Address, listenerEndpoint.Port, endPoint.Address, endPoint.Port, session.Network.ClientId)); sb.AppendLine(buffer.BuildPacketString(0, size)); - packetLog.Debug(sb.ToString()); + packetLog.DebugFormat("{0}", sb); } try diff --git a/Source/ACE.Server/Network/Session.cs b/Source/ACE.Server/Network/Session.cs index 8f18d55cd3..4a4f863b04 100644 --- a/Source/ACE.Server/Network/Session.cs +++ b/Source/ACE.Server/Network/Session.cs @@ -304,7 +304,7 @@ public void DropSession() if (WorldManager.WorldStatus == WorldManager.WorldStatusState.Open) log.Info($"Session {Network?.ClientId}\\{EndPointC2S} dropped. Account: {Account}, Player: {Player?.Name}{reas}"); else - log.Debug($"Session {Network?.ClientId}\\{EndPointC2S} dropped. Account: {Account}, Player: {Player?.Name}{reas}"); + log.DebugFormat("Session {0}\\{1} dropped. Account: {2}, Player: {3}{4}", Network?.ClientId, EndPointC2S, Account, Player?.Name, reas); } if (Player != null) diff --git a/Source/ACE.Server/Physics/PhysicsObj.cs b/Source/ACE.Server/Physics/PhysicsObj.cs index 857de5a6e9..642ea6118f 100644 --- a/Source/ACE.Server/Physics/PhysicsObj.cs +++ b/Source/ACE.Server/Physics/PhysicsObj.cs @@ -1322,7 +1322,7 @@ public SetPositionError SetPositionInternal(Position pos, SetPosition setPos, Tr // ideally CellArray.LoadCells = false would be passed to find_cell_list to prevent it from even attempting to load an unloaded neighboring landblock - log.Debug($"{Name} ({ID:X8}) AddPhysicsObj() - {pos.ShortLoc()} resulted in {transition.SpherePath.CurPos.ShortLoc()}, discarding"); + log.DebugFormat("{0} ({1:X8}) AddPhysicsObj() - {2}) resulted in {3}, discarding", Name, ID, pos.ShortLoc(), transition.SpherePath.CurPos.ShortLoc()); return SetPositionError.NoValidPosition; } @@ -1436,7 +1436,7 @@ public SetPositionError SetScatterPositionInternal(SetPosition setPos, Transitio var groundZ = landblock.GetZ(newPos.Frame.Origin) + 0.05f; if (Math.Abs(newPos.Frame.Origin.Z - groundZ) > ScatterThreshold_Z) - log.Debug($"{Name} ({ID:X8}).SetScatterPositionInternal() - tried to spawn outdoor object @ {newPos} ground Z {groundZ} (diff: {newPos.Frame.Origin.Z - groundZ}), investigate ScatterThreshold_Z"); + log.DebugFormat("{0} ({1:X8}).SetScatterPositionInternal() - tried to spawn outdoor object @ {2} ground Z {3} (diff: {4}), investigate ScatterThreshold_Z", Name, ID, newPos, groundZ, newPos.Frame.Origin.Z - groundZ); else newPos.Frame.Origin.Z = groundZ; @@ -1701,7 +1701,7 @@ public void UpdateObjectInternal(double quantum) else { if (IsPlayer) - log.Debug($"{Name} ({ID:X8}).UpdateObjectInternal({quantum}) - failed transition from {Position} to {newPos}"); + log.DebugFormat("{0} ({1:X8}).UpdateObjectInternal({2}) - failed transition from {3} to {4}", Name, ID, quantum, Position, newPos); else if (transit != null && transit.SpherePath.CurCell == null) log.Warn($"{Name} ({ID:X8}).UpdateObjectInternal({quantum}) - avoided CurCell=null from {Position} to {newPos}"); @@ -1782,7 +1782,7 @@ public bool UpdateObjectInternalServer(double quantum) SetPositionInternal(transit); } else - log.Debug($"{Name}.UpdateObjectInternalServer({quantum}) - failed transition from {Position} to {RequestPos}"); + log.DebugFormat("{0}.UpdateObjectInternalServer({1}) - failed transition from {2} to {3}", Name, quantum, Position, RequestPos); if (DetectionManager != null) DetectionManager.CheckDetection(); diff --git a/Source/ACE.Server/WorldObjects/Corpse.cs b/Source/ACE.Server/WorldObjects/Corpse.cs index 06dc889499..154a69e5d2 100644 --- a/Source/ACE.Server/WorldObjects/Corpse.cs +++ b/Source/ACE.Server/WorldObjects/Corpse.cs @@ -70,7 +70,8 @@ protected override void OnInitialInventoryLoadCompleted() var dtTimeToRot = DateTime.UtcNow.AddSeconds(TimeToRot ?? 0); var tsDecay = dtTimeToRot - DateTime.UtcNow; - log.Debug($"[CORPSE] {Name} (0x{Guid}) Reloaded from Database: Corpse Level: {Level ?? 0} | InventoryLoaded: {InventoryLoaded} | Inventory.Count: {Inventory.Count} | TimeToRot: {TimeToRot} | CreationTimestamp: {CreationTimestamp} ({Time.GetDateTimeFromTimestamp(CreationTimestamp ?? 0).ToLocalTime().ToString("yyyy-MM-dd HH:mm:ss")}) | Corpse should not decay before: {dtTimeToRot.ToLocalTime().ToString("yyyy-MM-dd HH:mm:ss")}, {tsDecay.ToString("%d")} day(s), {tsDecay.ToString("%h")} hours, {tsDecay.ToString("%m")} minutes, and {tsDecay.ToString("%s")} seconds from now."); + if (log.IsDebugEnabled) + log.Debug($"[CORPSE] {Name} (0x{Guid}) Reloaded from Database: Corpse Level: {Level ?? 0} | InventoryLoaded: {InventoryLoaded} | Inventory.Count: {Inventory.Count} | TimeToRot: {TimeToRot} | CreationTimestamp: {CreationTimestamp} ({Time.GetDateTimeFromTimestamp(CreationTimestamp ?? 0).ToLocalTime().ToString("yyyy-MM-dd HH:mm:ss")}) | Corpse should not decay before: {dtTimeToRot.ToLocalTime().ToString("yyyy-MM-dd HH:mm:ss")}, {tsDecay.ToString("%d")} day(s), {tsDecay.ToString("%h")} hours, {tsDecay.ToString("%m")} minutes, and {tsDecay.ToString("%s")} seconds from now."); } } @@ -114,7 +115,8 @@ public void RecalculateDecayTime(Player player) Level = player.Level ?? 1; - log.Debug($"[CORPSE] {Name}.RecalculateDecayTime({player.Name}) 0x{Guid}: Player Level: {player.Level} | Inventory.Count: {Inventory.Count} | TimeToRot: {TimeToRot} | CreationTimestamp: {CreationTimestamp} ({Time.GetDateTimeFromTimestamp(CreationTimestamp ?? 0).ToLocalTime().ToString("yyyy-MM-dd HH:mm:ss")}) | Corpse should not decay before: {dtTimeToRot.ToLocalTime().ToString("yyyy-MM-dd HH:mm:ss")}, {tsDecay.ToString("%d")} day(s), {tsDecay.ToString("%h")} hours, {tsDecay.ToString("%m")} minutes, and {tsDecay.ToString("%s")} seconds from now."); + if (log.IsDebugEnabled) + log.Debug($"[CORPSE] {Name}.RecalculateDecayTime({player.Name}) 0x{Guid}: Player Level: {player.Level} | Inventory.Count: {Inventory.Count} | TimeToRot: {TimeToRot} | CreationTimestamp: {CreationTimestamp} ({Time.GetDateTimeFromTimestamp(CreationTimestamp ?? 0).ToLocalTime().ToString("yyyy-MM-dd HH:mm:ss")}) | Corpse should not decay before: {dtTimeToRot.ToLocalTime().ToString("yyyy-MM-dd HH:mm:ss")}, {tsDecay.ToString("%d")} day(s), {tsDecay.ToString("%h")} hours, {tsDecay.ToString("%m")} minutes, and {tsDecay.ToString("%s")} seconds from now."); } /// @@ -344,8 +346,11 @@ public void TryGenerateRare(DamageHistoryInfo killer) var tier = LootGenerationFactory.GetRareTier(wo.WeenieClassId); LootGenerationFactory.RareChances.TryGetValue(tier, out var chance); - log.Debug($"[LOOT][RARE] {Name} ({Guid}) generated rare {wo.Name} ({wo.Guid}) for {killer.Name} ({killer.Guid})"); - log.Debug($"[LOOT][RARE] Tier {tier} -- 1 / {chance:N0} chance -- {luck:N0} luck"); + if (log.IsDebugEnabled) + { + log.Debug($"[LOOT][RARE] {Name} ({Guid}) generated rare {wo.Name} ({wo.Guid}) for {killer.Name} ({killer.Guid})"); + log.Debug($"[LOOT][RARE] Tier {tier} -- 1 / {chance:N0} chance -- {luck:N0} luck"); + } if (TryAddToInventory(wo)) { diff --git a/Source/ACE.Server/WorldObjects/Creature.cs b/Source/ACE.Server/WorldObjects/Creature.cs index 9e650c2911..de07d65b88 100644 --- a/Source/ACE.Server/WorldObjects/Creature.cs +++ b/Source/ACE.Server/WorldObjects/Creature.cs @@ -33,7 +33,7 @@ public QuestManager QuestManager if (_questManager == null) { /*if (!(this is Player)) - log.Debug($"Initializing non-player QuestManager for {Name} (0x{Guid})");*/ + log.DebugFormat("Initializing non-player QuestManager for {0} (0x{1})", Name, Guid);*/ _questManager = new QuestManager(this); } @@ -165,7 +165,7 @@ public void GenerateNewFace() { #if DEBUG //if (!(NpcLooksLikeObject ?? false)) - //log.Debug($"Creature.GenerateNewFace: {Name} (0x{Guid}) - wcid {WeenieClassId} - Heritage: {Heritage} | HeritageGroupName: {HeritageGroupName} | Gender: {Gender} | Sex: {Sex} - Data missing or unparsable, Cannot randomize face."); + //log.DebugFormat("Creature.GenerateNewFace: {0} (0x{1}) - wcid {2} - Heritage: {3} | HeritageGroupName: {4} | Gender: {5} | Sex: {6} - Data missing or unparsable, Cannot randomize face.", Name, Guid, WeenieClassId, Heritage, HeritageGroupName, Gender, Sex); #endif return; } @@ -173,7 +173,7 @@ public void GenerateNewFace() if (!cg.HeritageGroups.TryGetValue((uint)Heritage, out var heritageGroup) || !heritageGroup.Genders.TryGetValue((int)Gender, out var sex)) { #if DEBUG - log.Debug($"Creature.GenerateNewFace: {Name} (0x{Guid}) - wcid {WeenieClassId} - Heritage: {Heritage} | HeritageGroupName: {HeritageGroupName} | Gender: {Gender} | Sex: {Sex} - Data invalid, Cannot randomize face."); + log.DebugFormat("Creature.GenerateNewFace: {0} (0x{1}) - wcid {2} - Heritage: {3} | HeritageGroupName: {4} | Gender: {5} | Sex: {6} - Data invalid, Cannot randomize face.", Name, Guid, WeenieClassId, Heritage, HeritageGroupName, Gender, Sex); #endif return; } diff --git a/Source/ACE.Server/WorldObjects/Creature_Combat.cs b/Source/ACE.Server/WorldObjects/Creature_Combat.cs index 5f11eb6208..3b8714b01f 100644 --- a/Source/ACE.Server/WorldObjects/Creature_Combat.cs +++ b/Source/ACE.Server/WorldObjects/Creature_Combat.cs @@ -93,7 +93,7 @@ public float SetCombatMode(CombatMode combatMode, out float queueTime, bool forc animLength = HandleSwitchToMissileCombatMode(); break; default: - log.InfoFormat($"Unknown combat mode {CombatMode} for {Name}"); + log.InfoFormat("Unknown combat mode {0} for {1}", CombatMode, Name); break; } diff --git a/Source/ACE.Server/WorldObjects/Creature_Death.cs b/Source/ACE.Server/WorldObjects/Creature_Death.cs index 96ef26eaf9..790603de48 100644 --- a/Source/ACE.Server/WorldObjects/Creature_Death.cs +++ b/Source/ACE.Server/WorldObjects/Creature_Death.cs @@ -617,12 +617,12 @@ protected void CreateCorpse(DamageHistoryInfo killer, bool hadVitae = false) corpse.EnterWorld(); - if (player != null) + if (player != null && log.IsDebugEnabled) { if (corpse.PhysicsObj == null || corpse.PhysicsObj.Position == null) - log.Debug($"[CORPSE] {Name}'s corpse (0x{corpse.Guid}) failed to spawn! Tried at {player.Location.ToLOCString()}"); + log.DebugFormat("[CORPSE] {0}'s corpse (0x{1}) failed to spawn! Tried at {2}", Name, corpse.Guid, player.Location.ToLOCString()); else - log.Debug($"[CORPSE] {Name}'s corpse (0x{corpse.Guid}) is located at {corpse.PhysicsObj.Position}"); + log.DebugFormat("[CORPSE] {0}'s corpse (0x{1}) is located at {2}", Name, corpse.Guid, corpse.PhysicsObj.Position); } if (saveCorpse) @@ -729,10 +729,10 @@ public void DoCantripLogging(DamageHistoryInfo killer, WorldObject wo) var epicCantrips = wo.EpicCantrips; var legendaryCantrips = wo.LegendaryCantrips; - if (epicCantrips.Count > 0) + if (epicCantrips.Count > 0 && log.IsDebugEnabled) log.Debug($"[LOOT][EPIC] {Name} ({Guid}) generated item with {epicCantrips.Count} epic{(epicCantrips.Count > 1 ? "s" : "")} - {wo.Name} ({wo.Guid}) - {GetSpellList(epicCantrips)} - killed by {killer?.Name} ({killer?.Guid})"); - if (legendaryCantrips.Count > 0) + if (legendaryCantrips.Count > 0 && log.IsDebugEnabled) log.Debug($"[LOOT][LEGENDARY] {Name} ({Guid}) generated item with {legendaryCantrips.Count} legendar{(legendaryCantrips.Count > 1 ? "ies" : "y")} - {wo.Name} ({wo.Guid}) - {GetSpellList(legendaryCantrips)} - killed by {killer?.Name} ({killer?.Guid})"); } diff --git a/Source/ACE.Server/WorldObjects/Managers/EmoteManager.cs b/Source/ACE.Server/WorldObjects/Managers/EmoteManager.cs index e27dbef58d..b4e0f82ccc 100644 --- a/Source/ACE.Server/WorldObjects/Managers/EmoteManager.cs +++ b/Source/ACE.Server/WorldObjects/Managers/EmoteManager.cs @@ -1495,7 +1495,7 @@ public float ExecuteEmote(PropertiesEmote emoteSet, PropertiesEmoteAction emote, break; default: - log.Debug($"EmoteManager.Execute - Encountered Unhandled EmoteType {(EmoteType)emote.Type} for {WorldObject.Name} ({WorldObject.WeenieClassId})"); + log.DebugFormat("EmoteManager.Execute - Encountered Unhandled EmoteType {0} for {1} ({2})", (EmoteType)emote.Type, WorldObject.Name, WorldObject.WeenieClassId); break; } diff --git a/Source/ACE.Server/WorldObjects/Player.cs b/Source/ACE.Server/WorldObjects/Player.cs index 343e0cf779..01c299279f 100644 --- a/Source/ACE.Server/WorldObjects/Player.cs +++ b/Source/ACE.Server/WorldObjects/Player.cs @@ -265,7 +265,7 @@ public void HandleActionIdentifyObject(uint objectGuid) if (wo == null) { - //log.Debug($"{Name}.HandleActionIdentifyObject({objectGuid:X8}): couldn't find object"); + //log.DebugFormat("{0}.HandleActionIdentifyObject({1:X8}): couldn't find object", Name, objectGuid); Session.Network.EnqueueSend(new GameEventIdentifyObjectResponse(Session, objectGuid)); return; } @@ -647,7 +647,7 @@ private void FinalizeLogout() SavePlayerToDatabase(); PlayerManager.SwitchPlayerFromOnlineToOffline(this); - log.Debug($"[LOGOUT] Account {Account.AccountName} exited the world with character {Name} (0x{Guid}) at {DateTime.Now}."); + log.DebugFormat("[LOGOUT] Account {0} exited the world with character {1} (0x{2}) at {3}.", Account.AccountName, Name, Guid, DateTime.Now); } public void HandleMRT() @@ -687,7 +687,7 @@ public void HandleActionForceObjDescSend(uint itemGuid) var wo = FindObject(itemGuid, SearchLocations.Everywhere); if (wo == null) { - //log.Debug($"HandleActionForceObjDescSend() - couldn't find object {itemGuid:X8}"); + //log.DebugFormat("HandleActionForceObjDescSend() - couldn't find object {0:X8}", itemGuid); return; } Session.Network.EnqueueSend(new GameMessageObjDescEvent(wo)); diff --git a/Source/ACE.Server/WorldObjects/Player_Allegiance.cs b/Source/ACE.Server/WorldObjects/Player_Allegiance.cs index 4b8213d03f..f1c2358112 100644 --- a/Source/ACE.Server/WorldObjects/Player_Allegiance.cs +++ b/Source/ACE.Server/WorldObjects/Player_Allegiance.cs @@ -94,7 +94,7 @@ public void SwearAllegiance(uint targetGuid, bool success, bool confirmed = fals return; } - log.Debug($"[ALLEGIANCE] {Name} ({Level}) swearing allegiance to {patron.Name} ({patron.Level})"); + log.DebugFormat("[ALLEGIANCE] {0} ({1}) swearing allegiance to {2} ({3})", Name, Level, patron.Name, patron.Level); PatronId = targetGuid; @@ -175,7 +175,7 @@ public void HandleActionBreakAllegiance(uint targetGuid) if (target == null) return; - log.Debug($"[ALLEGIANCE] {Name} breaking allegiance to {target.Name}"); + log.DebugFormat("[ALLEGIANCE] {0} breaking allegiance to {1}", Name, target.Name); // target can be either patron or vassal var isPatron = PatronId == target.Guid.Full; @@ -1394,7 +1394,7 @@ public void HandleActionRemoveAllegianceBan(string playerName) public void HandleActionBreakAllegianceBoot(string playerName, bool accountBoot) { - log.Debug($"[ALLEGIANCE] {Name}.HandleActionBreakAllegianceBoot({playerName}, {accountBoot})"); + log.DebugFormat("[ALLEGIANCE] {0}.HandleActionBreakAllegianceBoot({1}, {2})", Name, playerName, accountBoot); // TODO: handle account boot diff --git a/Source/ACE.Server/WorldObjects/Player_Crafting.cs b/Source/ACE.Server/WorldObjects/Player_Crafting.cs index 1be199c3f1..9819c3db3a 100644 --- a/Source/ACE.Server/WorldObjects/Player_Crafting.cs +++ b/Source/ACE.Server/WorldObjects/Player_Crafting.cs @@ -132,7 +132,7 @@ public void HandleSalvaging(List salvageItems) var item = GetInventoryItem(itemGuid); if (item == null) { - //log.Debug($"[CRAFTING] {Name}.HandleSalvaging({itemGuid:X8}): couldn't find inventory item"); + //log.DebugFormat("[CRAFTING] {0}.HandleSalvaging({1:X8}): couldn't find inventory item", Name, itemGuid); continue; } diff --git a/Source/ACE.Server/WorldObjects/Player_Database.cs b/Source/ACE.Server/WorldObjects/Player_Database.cs index 10f80d3921..0b40b67541 100644 --- a/Source/ACE.Server/WorldObjects/Player_Database.cs +++ b/Source/ACE.Server/WorldObjects/Player_Database.cs @@ -102,7 +102,7 @@ public void SavePlayerToDatabase() DatabaseManager.Shard.SaveBiotasInParallel(biotas, result => { - log.Debug($"{Name} has been saved. It took {(DateTime.UtcNow - requestedTime).TotalMilliseconds:N0} ms to process the request."); + log.DebugFormat("{0} has been saved. It took {1:N0} ms to process the request.", Name, (DateTime.UtcNow - requestedTime).TotalMilliseconds); if (!result) { diff --git a/Source/ACE.Server/WorldObjects/Player_House.cs b/Source/ACE.Server/WorldObjects/Player_House.cs index a9b2bce5f1..aaaee3e478 100644 --- a/Source/ACE.Server/WorldObjects/Player_House.cs +++ b/Source/ACE.Server/WorldObjects/Player_House.cs @@ -137,7 +137,7 @@ public void HandleActionBuyHouse(uint slumlord_id, List item_ids) var item_id_list = string.Join(", ", item_ids.Select(i => i.ToString("X8"))); var consumeItemsList = string.Join(", ", consumeItems.Select(i => $"{i.Name} ({i.Guid}) x{i.Value}")); - log.Error($"[HOUSE] {Name}.HandleActionBuyHouse({slumlord_id:X8}, {item_id_list}) - TryConsumePurchaseItems failed with {consumeItemsList}"); + log.ErrorFormat("[HOUSE] {0}.HandleActionBuyHouse({1:X8}, {2}) - TryConsumePurchaseItems failed with {3}", Name, slumlord_id, item_id_list, consumeItemsList); return; } @@ -161,7 +161,7 @@ public void GiveDeed(SlumLord slumLord) if (location == null) { if (!HouseManager.ApartmentBlocks.TryGetValue(slumLord.Location.Landblock, out location)) - log.Error($"{Name}.GiveDeed() - couldn't find location {slumLord.Location.ToLOCString()}"); + log.ErrorFormat("{0}.GiveDeed() - couldn't find location {1}", Name, slumLord.Location.ToLOCString()); } deed.LongDesc = $"Bought by {Name}{titleStr} on {date} at {time}\n\nPurchased at {location}"; @@ -215,7 +215,7 @@ public void HandleActionRentHouse(uint slumlord_id, List item_ids) } } else - log.Error($"[HOUSE] {Name}.HandleActionRentHouse({slumlord_id:X8}): couldn't find house owner {slumlord.HouseOwner}"); + log.ErrorFormat("[HOUSE] {0}.HandleActionRentHouse({1:X8}): couldn't find house owner {2}", Name, slumlord_id, slumlord.HouseOwner); var logLine = $"[HOUSE] HandleActionRentHouse:" + Environment.NewLine; @@ -309,7 +309,7 @@ public List GetInventoryItems(List item_ids) if (item != null) inventoryItems.Add(item); else - log.Error($"{Name}.GetInventoryItems() - couldn't find {item_id:X8}"); + log.ErrorFormat("{0}.GetInventoryItems() - couldn't find {1:X8}", Name, item_id); } return inventoryItems; @@ -387,7 +387,7 @@ public bool TryMoveItemForRent(SlumLord slumlord, WorldObject item) return false; } - log.Debug($"[HOUSE] {Name}.TryMoveItemForRent({slumlord.Name} ({slumlord.Guid}), {((item.StackSize ?? 1) > 1 ? $"{item.StackSize}x " : "")}{item.Name} ({item.Guid})) - Successfully moved to Slumlord."); + log.DebugFormat("[HOUSE] {0}.TryMoveItemForRent({1} ({2}), {3}{4} ({5})) - Successfully moved to Slumlord.", Name, slumlord.Name, slumlord.Guid, ((item.StackSize ?? 1) > 1 ? $"{item.StackSize}x " : ""), item.Name, item.Guid); return true; } @@ -441,7 +441,8 @@ public bool TrySplitItemForRent(SlumLord slumlord, WorldObject item, int amount) return false; } - log.Debug($"[HOUSE] {Name}.TrySplitItemForRent({slumlord.Name} ({slumlord.Guid}), {item.Name} ({item.Guid}), {amount}) - Created new item {((newItem.StackSize ?? 1) > 1 ? $"{newItem.StackSize}x " : "")}{newItem.Name} ({newItem.Guid}) and moved to Slumlord."); + if (log.IsDebugEnabled) + log.Debug($"[HOUSE] {Name}.TrySplitItemForRent({slumlord.Name} ({slumlord.Guid}), {item.Name} ({item.Guid}), {amount}) - Created new item {((newItem.StackSize ?? 1) > 1 ? $"{newItem.StackSize}x " : "")}{newItem.Name} ({newItem.Guid}) and moved to Slumlord."); // force save of new slumlord stack newItem.SaveBiotaToDatabase(); diff --git a/Source/ACE.Server/WorldObjects/Player_Inventory.cs b/Source/ACE.Server/WorldObjects/Player_Inventory.cs index dd9cb80070..c66ffcc4ac 100644 --- a/Source/ACE.Server/WorldObjects/Player_Inventory.cs +++ b/Source/ACE.Server/WorldObjects/Player_Inventory.cs @@ -1081,7 +1081,7 @@ public void HandleActionPutItemInContainer(uint itemGuid, uint containerGuid, in if (isFromAPlayerCorpse) { - log.Debug($"[CORPSE] {Name} (0x{Guid}) picked up {item.Name} (0x{item.Guid}) from {itemRootOwner.Name} (0x{itemRootOwner.Guid})"); + log.DebugFormat("[CORPSE] {0} (0x{1}) picked up {2} (0x{3}) from {4} (0x{5})", Name, Guid, item.Name, item.Guid, itemRootOwner.Name, itemRootOwner.Guid); item.SaveBiotaToDatabase(); } } @@ -1604,7 +1604,7 @@ public void HandleActionGetAndWieldItem(uint itemGuid, EquipMask wieldedLocation if (isFromAPlayerCorpse) { - log.Debug($"[CORPSE] {Name} (0x{Guid}) picked up and wielded {item.Name} (0x{item.Guid}) from {rootOwner.Name} (0x{rootOwner.Guid})"); + log.DebugFormat("[CORPSE] {0} (0x{1}) picked up and wielded {2} (0x{3}) from {4} (0x{5})", Name, Guid, item.Name, item.Guid, rootOwner.Name, rootOwner.Guid); item.SaveBiotaToDatabase(); } } @@ -3142,7 +3142,8 @@ private bool DoHandleActionStackableMerge(WorldObject sourceStack, WorldObject t if (isFromAPlayerCorpse) { - log.Debug($"[CORPSE] {Name} (0x{Guid}) merged {amount:N0} {(sourceStack.IsDestroyed ? $"which resulted in the destruction" : $"leaving behind {sourceStack.StackSize:N0}")} of {sourceStack.Name} (0x{sourceStack.Guid}) to {targetStack.Name} (0x{targetStack.Guid}) from {sourceStackRootOwner.Name} (0x{sourceStackRootOwner.Guid})"); + if (log.IsDebugEnabled) + log.Debug($"[CORPSE] {Name} (0x{Guid}) merged {amount:N0} {(sourceStack.IsDestroyed ? $"which resulted in the destruction" : $"leaving behind {sourceStack.StackSize:N0}")} of {sourceStack.Name} (0x{sourceStack.Guid}) to {targetStack.Name} (0x{targetStack.Guid}) from {sourceStackRootOwner.Name} (0x{sourceStackRootOwner.Guid})"); targetStack.SaveBiotaToDatabase(); } @@ -3481,7 +3482,7 @@ private void HandleIOUTurnIn(WorldObject target, WorldObject iouToTurnIn) { var success = uint.TryParse(split[0], out var wcid); - //Console.WriteLine($"{success.ToString()} {wcid}"); + //Console.WriteLine($"{success} {wcid}"); Session.Network.EnqueueSend(new GameEventTell(target, "Ahh, an IOU! You know, I collect these for some reason. Let me see if I have something for it somewhere in my pack...", this, ChatMessageType.Tell)); @@ -3508,7 +3509,7 @@ private void HandleIOUTurnIn(WorldObject target, WorldObject iouToTurnIn) if (PropertyManager.GetBool("player_receive_immediate_save").Item) RushNextPlayerSave(5); - log.Debug($"[IOU] {Name} (0x{Guid}) traded in a IOU (0x{iouToTurnIn.Guid}) for {wcid} which became {item.Name} (0x{item.Guid})."); + log.DebugFormat("[IOU] {0} (0x{1}) traded in a IOU (0x{2}) for {3} which became {4} (0x{5}).", Name, Guid, iouToTurnIn.Guid, wcid, item.Name, item.Guid); } return; } diff --git a/Source/ACE.Server/WorldObjects/Player_Melee.cs b/Source/ACE.Server/WorldObjects/Player_Melee.cs index 40eb7ad88e..bd411cbacc 100644 --- a/Source/ACE.Server/WorldObjects/Player_Melee.cs +++ b/Source/ACE.Server/WorldObjects/Player_Melee.cs @@ -104,7 +104,7 @@ public void HandleActionTargetedMeleeAttack(uint targetGuid, uint attackHeight, if (target == null) { - //log.Debug($"{Name}.HandleActionTargetedMeleeAttack({targetGuid:X8}, {AttackHeight}, {powerLevel}) - couldn't find target guid"); + //log.DebugFormat("{0}.HandleActionTargetedMeleeAttack({1:X8}, {2}, {3}) - couldn't find target guid", Name, targetGuid, AttackHeight, powerLevel); OnAttackDone(); return; } diff --git a/Source/ACE.Server/WorldObjects/Player_Networking.cs b/Source/ACE.Server/WorldObjects/Player_Networking.cs index 07bc4a2b4a..6d8dcc1c5b 100644 --- a/Source/ACE.Server/WorldObjects/Player_Networking.cs +++ b/Source/ACE.Server/WorldObjects/Player_Networking.cs @@ -140,7 +140,7 @@ public void PlayerEnterWorld() actionChain.EnqueueChain(); } - log.Debug($"[LOGIN] Account {Account.AccountName} entered the world with character {Name} (0x{Guid}) at {DateTime.Now}."); + log.DebugFormat("[LOGIN] Account {0} entered the world with character {1} (0x{2}) at {3}.", Account.AccountName, Name, Guid, DateTime.Now); } public void SendTurbineChatChannels(bool breakAllegiance = false) diff --git a/Source/ACE.Server/WorldObjects/Player_Tick.cs b/Source/ACE.Server/WorldObjects/Player_Tick.cs index ba89749100..dadc37048b 100644 --- a/Source/ACE.Server/WorldObjects/Player_Tick.cs +++ b/Source/ACE.Server/WorldObjects/Player_Tick.cs @@ -325,7 +325,7 @@ public override bool UpdateObjectPhysics() if (elapsedSeconds >= 1) // Yea, that ain't good.... log.Warn($"[PERFORMANCE][PHYSICS] {Guid}:{Name} took {(elapsedSeconds * 1000):N1} ms to process UpdateObjectPhysics() at loc: {Location}"); else if (elapsedSeconds >= 0.010) - log.Debug($"[PERFORMANCE][PHYSICS] {Guid}:{Name} took {(elapsedSeconds * 1000):N1} ms to process UpdateObjectPhysics() at loc: {Location}"); + log.DebugFormat("[PERFORMANCE][PHYSICS] {0}:{1} took {2:N1} ms to process UpdateObjectPhysics() at loc: {3}", Guid, Name, (elapsedSeconds * 1000), Location); } } @@ -529,7 +529,7 @@ public bool UpdatePlayerPosition(ACE.Entity.Position newPosition, bool forceUpda if (elapsedSeconds >= 0.100) // Yea, that ain't good.... log.Warn($"[PERFORMANCE][PHYSICS] {Guid}:{Name} took {(elapsedSeconds * 1000):N1} ms to process UpdatePlayerPosition() at loc: {Location}"); else if (elapsedSeconds >= 0.010) - log.Debug($"[PERFORMANCE][PHYSICS] {Guid}:{Name} took {(elapsedSeconds * 1000):N1} ms to process UpdatePlayerPosition() at loc: {Location}"); + log.DebugFormat("[PERFORMANCE][PHYSICS] {0}:{1} took {2:N1} ms to process UpdatePlayerPosition() at loc: {3}", Guid, Name, (elapsedSeconds * 1000), Location); } } } diff --git a/Source/ACE.Server/WorldObjects/Player_Use.cs b/Source/ACE.Server/WorldObjects/Player_Use.cs index 2c0aeb15c2..7dd50a149d 100644 --- a/Source/ACE.Server/WorldObjects/Player_Use.cs +++ b/Source/ACE.Server/WorldObjects/Player_Use.cs @@ -209,7 +209,7 @@ public void HandleActionUseItem(uint itemGuid) } else { - log.Debug($"{Name}.HandleActionUseItem({itemGuid:X8}): couldn't find object"); + log.DebugFormat("{0}.HandleActionUseItem({1:X8}): couldn't find object", Name, itemGuid); SendUseDoneEvent(); } } diff --git a/Source/ACE.Server/WorldObjects/Vendor.cs b/Source/ACE.Server/WorldObjects/Vendor.cs index 50a2a49388..f2c8a88792 100644 --- a/Source/ACE.Server/WorldObjects/Vendor.cs +++ b/Source/ACE.Server/WorldObjects/Vendor.cs @@ -725,7 +725,7 @@ private void RotUniques() { foreach (var itemToRemove in itemsToRemove) { - log.Debug($"[VENDOR] Vendor {Name} has discontinued sale of {itemToRemove.Name} and removed it from its UniqueItemsForSale list."); + log.DebugFormat("[VENDOR] Vendor {0} has discontinued sale of {1} and removed it from its UniqueItemsForSale list.", Name, itemToRemove.Name); UniqueItemsForSale.Remove(itemToRemove.Guid); itemToRemove.Destroy(); // even though it has already been removed from the db at this point, we want to mark as freed in guid manager now diff --git a/Source/ACE.Server/WorldObjects/WorldObject_Decay.cs b/Source/ACE.Server/WorldObjects/WorldObject_Decay.cs index d6f4fad173..e8d92b032c 100644 --- a/Source/ACE.Server/WorldObjects/WorldObject_Decay.cs +++ b/Source/ACE.Server/WorldObjects/WorldObject_Decay.cs @@ -60,7 +60,7 @@ public void Decay(TimeSpan elapsed) TimeToRot = DefaultTimeToRot.TotalSeconds; if (this is Corpse && Level.HasValue) - log.Debug($"[CORPSE] {Name} (0x{Guid.ToString()}).Decay: TimeToRot had no value, set to {TimeToRot}"); + log.DebugFormat("[CORPSE] {0} (0x{1}).Decay: TimeToRot had no value, set to {2}", Name, Guid, TimeToRot); return; } @@ -76,7 +76,7 @@ public void Decay(TimeSpan elapsed) { TimeToRot = Corpse.EmptyDecayTime; if (Level.HasValue && PropertyManager.GetBool("corpse_decay_tick_logging").Item) - log.Debug($"[CORPSE] {corpse.Name} (0x{corpse.Guid.ToString()}).Decay({elapsed.ToString()}): InventoryLoaded = {corpse.InventoryLoaded} | Inventory.Count = {corpse.Inventory.Count} | previous TimeToRot: {previousTTR} | current TimeToRot: {TimeToRot}"); + log.DebugFormat("[CORPSE] {0} (0x{1}).Decay({2}): InventoryLoaded = {3} | Inventory.Count = {4} | previous TimeToRot: {5} | current TimeToRot: {6}", corpse.Name, corpse.Guid, elapsed, corpse.InventoryLoaded, corpse.Inventory.Count, previousTTR, TimeToRot); return; } } @@ -86,7 +86,7 @@ public void Decay(TimeSpan elapsed) TimeToRot -= elapsed.TotalSeconds; if (this is Corpse && Level.HasValue && PropertyManager.GetBool("corpse_decay_tick_logging").Item) - log.Debug($"[CORPSE] {corpse.Name} (0x{corpse.Guid.ToString()}).Decay({elapsed.ToString()}): previous TimeToRot: {previousTTR} | current TimeToRot: {TimeToRot}"); + log.DebugFormat("[CORPSE] {0} (0x{1}).Decay({2}): previous TimeToRot: {3} | current TimeToRot: {4}", corpse.Name, corpse.Guid, elapsed, previousTTR, TimeToRot); // Is there still time left? if (TimeToRot > 0) @@ -95,7 +95,7 @@ public void Decay(TimeSpan elapsed) TimeToRot = -2; // We force it to -2 to make sure it doesn't end up at 0 or -1. 0 indicates instant rot. -1 indicates no rot. 0 and -1 can be found in weenie defaults if (this is Corpse && Level.HasValue && PropertyManager.GetBool("corpse_decay_tick_logging").Item) - log.Debug($"[CORPSE] {corpse.Name} (0x{corpse.Guid.ToString()}).Decay({elapsed.ToString()}): previous TimeToRot: {previousTTR} | current TimeToRot: {TimeToRot}"); + log.DebugFormat("[CORPSE] {0} (0x{1}).Decay({2}): previous TimeToRot: {3} | current TimeToRot: {4}", corpse.Name, corpse.Guid, elapsed, previousTTR, TimeToRot); } if (this is Container container && container.IsOpen) @@ -131,7 +131,8 @@ public void Decay(TimeSpan elapsed) if (pukedItems.EndsWith(", ")) pukedItems = pukedItems.Substring(0, pukedItems.Length - 2); - log.Debug($"[CORPSE] {corpse.Name} (0x{corpse.Guid.ToString()}) at {corpse.Location.ToLOCString()} has decayed{((pukedItems == "") ? "" : $" and placed the following items on the landblock: {pukedItems}")}."); + if(log.IsDebugEnabled) + log.Debug($"[CORPSE] {corpse.Name} (0x{corpse.Guid}) at {corpse.Location.ToLOCString()} has decayed{((pukedItems == "") ? "" : $" and placed the following items on the landblock: {pukedItems}")}."); } if (corpse != null) diff --git a/Source/ACE.Server/WorldObjects/WorldObject_Generators.cs b/Source/ACE.Server/WorldObjects/WorldObject_Generators.cs index 6915571303..cdcfd43fcb 100644 --- a/Source/ACE.Server/WorldObjects/WorldObject_Generators.cs +++ b/Source/ACE.Server/WorldObjects/WorldObject_Generators.cs @@ -60,7 +60,7 @@ public void InitializeGenerator() // defaulting to Max == Init for our purposes. if ((MaxGeneratedObjects <= 0 || MaxGeneratedObjects < InitGeneratedObjects) && InitGeneratedObjects > 0) { - log.Warn($"[GENERATOR] 0x{Guid.Full.ToString()} {Name}.InitializeGenerator: {WeenieClassName} ({WeenieClassId}) MaxGeneratedObjects = {MaxGeneratedObjects} | InitGeneratedObjects = {InitGeneratedObjects}. Setting MaxGeneratedObjects = InitGeneratedObjects"); + log.Warn($"[GENERATOR] 0x{Guid.Full} {Name}.InitializeGenerator: {WeenieClassName} ({WeenieClassId}) MaxGeneratedObjects = {MaxGeneratedObjects} | InitGeneratedObjects = {InitGeneratedObjects}. Setting MaxGeneratedObjects = InitGeneratedObjects"); MaxGeneratedObjects = InitGeneratedObjects; } @@ -294,7 +294,7 @@ public int GetSpawnObjectsForProfile(GeneratorProfile profile) else numObjects = initCreate; - //Console.WriteLine($"INIT - 0x{Guid.ToString()} {Name} ({WeenieClassId}): CurrentCreate = {CurrentCreate} | profile.Biota.InitCreate = {profile.Biota.InitCreate} | profile.Biota.MaxCreate = {profile.Biota.MaxCreate} | InitCreate: {InitCreate} | MaxCreate: {MaxCreate} | initCreate: {initCreate} | maxCreate: {maxCreate} | leftObjects = {leftObjects} | numObjects: {numObjects}"); + //Console.WriteLine($"INIT - 0x{Guid} {Name} ({WeenieClassId}): CurrentCreate = {CurrentCreate} | profile.Biota.InitCreate = {profile.Biota.InitCreate} | profile.Biota.MaxCreate = {profile.Biota.MaxCreate} | InitCreate: {InitCreate} | MaxCreate: {MaxCreate} | initCreate: {initCreate} | maxCreate: {maxCreate} | leftObjects = {leftObjects} | numObjects: {numObjects}"); var genSlotsAvailable = MaxCreate - CurrentCreate; var profileSlotsAvailable = profile.MaxCreate - profile.CurrentCreate; @@ -323,7 +323,7 @@ public bool GenStopSelectProfileConditions if (CurrentCreate >= MaxCreate) { //if (CurrentCreate > InitCreate) - //log.Debug($"{WeenieClassId} - 0x{Guid}:{Name}.StopConditionsInit(): CurrentCreate({CurrentCreate}) > InitCreate({InitCreate})"); + //log.DebugFormat("{0} - 0x{1}:{2}.StopConditionsInit(): CurrentCreate({3}) > InitCreate({4})", WeenieClassId, Guid, Name, CurrentCreate, InitCreate); return true; } diff --git a/Source/ACE.Server/WorldObjects/WorldObject_Networking.cs b/Source/ACE.Server/WorldObjects/WorldObject_Networking.cs index 1e7473859d..947d590fce 100644 --- a/Source/ACE.Server/WorldObjects/WorldObject_Networking.cs +++ b/Source/ACE.Server/WorldObjects/WorldObject_Networking.cs @@ -448,7 +448,7 @@ public virtual void SendPartialUpdates(Session targetSession, List