Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Improve logging overhead by fixing string interpolation #4107

Merged
merged 5 commits into from
Mar 13, 2024
Merged

Improve logging overhead by fixing string interpolation #4107

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
5 commits
Select commit Hold shift + click to select a range
b65c017
First batch
Mag-nus Feb 13, 2024
ad60cf1
Second batch
Mag-nus Feb 13, 2024
20dc8eb
another batch
Mag-nus Feb 13, 2024
57e2635
last batch hopefully
Mag-nus Feb 13, 2024
9e46d63
fix
Mag-nus Feb 15, 2024
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion Source/ACE.Database/AuthenticationDatabase.cs
View file
Open in desktop
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
Open in desktop
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
Open in desktop
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
Open in desktop
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
Open in desktop
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
Open in desktop
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
Open in desktop
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
Open in desktop
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
Open in desktop
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
Open in desktop
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