Skip to content

Commit

Permalink
Improve logging overhead by fixing string interpolation (#4107)
Browse files Browse the repository at this point in the history 
* First batch

* Second batch

* another batch

* last batch hopefully

* fix
  • Loading branch information
@Mag-nus
Mag-nus authored Mar 13, 2024
1 parent 0a9c9c3 commit 9d70b48
Show file tree
Hide file tree
Showing 52 changed files with 197 additions and 170 deletions.
2 changes: 1 addition & 1 deletion Source/ACE.Database/AuthenticationDatabase.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -29,7 +29,7 @@ public bool Exists(bool retryUntilFound)
{
if (((RelationalDatabaseCreator)context.Database.GetService<IDatabaseCreator>()).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;
}
}
Expand Down
2 changes: 1 addition & 1 deletion Source/ACE.Database/Models/Auth/AccountExtensions.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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);

Expand Down
12 changes: 6 additions & 6 deletions Source/ACE.Database/OfflineTools/Shard/BiotaGuidConsolidator.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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;
}

Expand Down Expand Up @@ -197,15 +197,15 @@ 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;
}

// Finally, remove the original biota
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;
}

Expand Down Expand Up @@ -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;
}

Expand Down Expand Up @@ -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;
}

Expand All @@ -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;
}

Expand Down
22 changes: 11 additions & 11 deletions Source/ACE.Database/ShardDatabase.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -35,7 +35,7 @@ public bool Exists(bool retryUntilFound)
{
if (((RelationalDatabaseCreator)context.Database.GetService<IDatabaseCreator>()).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;
}
}
Expand Down Expand Up @@ -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;
}
Expand Down Expand Up @@ -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;
}
Expand Down Expand Up @@ -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;
}
Expand Down Expand Up @@ -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;
}
Expand Down Expand Up @@ -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;
}
Expand Down Expand Up @@ -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;
}
Expand Down
14 changes: 7 additions & 7 deletions Source/ACE.Database/ShardDatabaseOfflineTools.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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);
}
}

Expand Down Expand Up @@ -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);
}
}

Expand Down Expand Up @@ -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;
Expand Down Expand Up @@ -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;
}
Expand Down Expand Up @@ -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++;
}
Expand Down Expand Up @@ -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++;
}
Expand Down Expand Up @@ -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++;
}
Expand Down
2 changes: 1 addition & 1 deletion Source/ACE.Database/WorldDatabase.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -30,7 +30,7 @@ public bool Exists(bool retryUntilFound)
{
if (((RelationalDatabaseCreator)context.Database.GetService<IDatabaseCreator>()).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;
}
}
Expand Down
2 changes: 1 addition & 1 deletion Source/ACE.Server/Command/Handlers/AccountCommands.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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;

Expand Down
9 changes: 6 additions & 3 deletions Source/ACE.Server/Command/Handlers/DeveloperCommands.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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++;
}
}
Expand All @@ -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++;
}
}
Expand All @@ -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++;
}
}
Expand Down
2 changes: 1 addition & 1 deletion Source/ACE.Server/Entity/Aetheria.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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<Sigil, EquipmentSet> SigilToEquipmentSet = new Dictionary<Sigil, EquipmentSet>()
Expand Down
2 changes: 1 addition & 1 deletion Source/ACE.Server/Entity/DamageEvent.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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;
}
Expand Down
Loading

0 comments on commit 9d70b48

Please sign in to comment.