diff --git a/Libraries/Core/Controllers/GameController.cs b/Libraries/Core/Controllers/GameController.cs index 975498a2..c714abe1 100644 --- a/Libraries/Core/Controllers/GameController.cs +++ b/Libraries/Core/Controllers/GameController.cs @@ -13,6 +13,7 @@ using Core.Utils; using Core.Utils.Cloners; using Core.Utils.Json; using Server; +using LogLevel = Core.Models.Spt.Logging.LogLevel; namespace Core.Controllers; @@ -95,7 +96,8 @@ public class GameController( if (fullProfile.DialogueRecords is not null) _profileFixerService.CheckForAndFixDialogueAttachments(fullProfile); - _logger.Debug($"Started game with session {sessionId} {fullProfile.ProfileInfo?.Username}"); + if(_logger.IsLogEnabled(LogLevel.Debug)) + _logger.Debug($"Started game with session {sessionId} {fullProfile.ProfileInfo?.Username}"); var pmcProfile = fullProfile.CharacterData.PmcData; @@ -521,10 +523,13 @@ public class GameController( /// private void LogProfileDetails(SptProfile fullProfile) { - _logger.Debug($"Profile made with: {fullProfile.SptData?.Version}"); - _logger.Debug($"Server version: {(ProgramStatics.SPT_VERSION()) ?? _coreConfig.SptVersion} {ProgramStatics.COMMIT()}"); - _logger.Debug($"Debug enabled: {ProgramStatics.DEBUG()}"); - _logger.Debug($"Mods enabled: {ProgramStatics.MODS()}"); + if (_logger.IsLogEnabled(LogLevel.Debug)) + { + _logger.Debug($"Profile made with: {fullProfile.SptData?.Version}"); + _logger.Debug($"Server version: {(ProgramStatics.SPT_VERSION()) ?? _coreConfig.SptVersion} {ProgramStatics.COMMIT()}"); + _logger.Debug($"Debug enabled: {ProgramStatics.DEBUG()}"); + _logger.Debug($"Mods enabled: {ProgramStatics.MODS()}"); + } } public void Load() diff --git a/Libraries/Core/Controllers/InsuranceController.cs b/Libraries/Core/Controllers/InsuranceController.cs index 1e269cd3..1cd0058f 100644 --- a/Libraries/Core/Controllers/InsuranceController.cs +++ b/Libraries/Core/Controllers/InsuranceController.cs @@ -16,6 +16,7 @@ using Core.Utils.Cloners; using Core.Utils.Collections; using SptCommon.Annotations; using Insurance = Core.Models.Eft.Profile.Insurance; +using LogLevel = Core.Models.Spt.Logging.LogLevel; namespace Core.Controllers; @@ -85,7 +86,10 @@ public class InsuranceController( var profileInsuranceDetails = _saveServer.GetProfile(sessionId).InsuranceList; if (profileInsuranceDetails.Count > 0) - _logger.Debug($"Found {profileInsuranceDetails.Count} insurance packages in profile {sessionId}"); + { + if(_logger.IsLogEnabled(LogLevel.Debug)) + _logger.Debug($"Found {profileInsuranceDetails.Count} insurance packages in profile {sessionId}"); + } return profileInsuranceDetails.Where(insured => insuranceTime >= insured.ScheduledTime).ToList(); } @@ -99,9 +103,10 @@ public class InsuranceController( */ protected void ProcessInsuredItems(List insuranceDetails, string sessionId) { - _logger.Debug( - $"Processing {insuranceDetails.Count} insurance packages, which includes a total of: {CountAllInsuranceItems(insuranceDetails)} items, in profile: {sessionId}" - ); + if(_logger.IsLogEnabled(LogLevel.Debug)) + _logger.Debug( + $"Processing {insuranceDetails.Count} insurance packages, which includes a total of: {CountAllInsuranceItems(insuranceDetails)} items, in profile: {sessionId}" + ); // Iterate over each of the insurance packages. foreach (var insured in insuranceDetails) @@ -162,7 +167,8 @@ public class InsuranceController( ) .ToList(); - _logger.Debug($"Removed processed insurance package. Remaining packages: {profile.InsuranceList.Count}"); + if(_logger.IsLogEnabled(LogLevel.Debug)) + _logger.Debug($"Removed processed insurance package. Remaining packages: {profile.InsuranceList.Count}"); } /** @@ -205,7 +211,8 @@ public class InsuranceController( // Log the number of items marked for deletion, if any if (!toDelete.Any()) { - _logger.Debug($"Marked {toDelete.Count} items for deletion from insurance."); + if(_logger.IsLogEnabled(LogLevel.Debug)) + _logger.Debug($"Marked {toDelete.Count} items for deletion from insurance."); } return toDelete; @@ -429,7 +436,8 @@ public class InsuranceController( // Log the parent item's name. itemsMap.TryGetValue(parentObj.Key, out var parentItem); var parentName = _itemHelper.GetItemName(parentItem.Template); - _logger.Debug($"Processing attachments of parent {parentName}"); + if(_logger.IsLogEnabled(LogLevel.Debug)) + _logger.Debug($"Processing attachments of parent {parentName}"); // Process the attachments for this individual parent item. ProcessAttachmentByParent(parentObj.Value, insuredTraderId, toDelete); @@ -473,7 +481,8 @@ public class InsuranceController( LogAttachmentsBeingRemoved(attachmentIdsToRemove, attachments, weightedAttachmentByPrice); - _logger.Debug($"Number of attachments to be deleted: {attachmentIdsToRemove.Count}"); + if(_logger.IsLogEnabled(LogLevel.Debug)) + _logger.Debug($"Number of attachments to be deleted: {attachmentIdsToRemove.Count}"); } private void LogAttachmentsBeingRemoved(List attachmentIdsToRemove, List attachments, Dictionary attachmentPrices) @@ -613,7 +622,8 @@ public class InsuranceController( // Log the roll with as much detail as possible. var itemName = insuredItem is not null ? $"{_itemHelper.GetItemName(insuredItem.Template)}" : ""; var status = roll ? "Delete" : "Keep"; - _logger.Debug($"Rolling {itemName} with {trader} - Return {traderReturnChance}% - Roll: {returnChance} - Status: {status}"); + if(_logger.IsLogEnabled(LogLevel.Debug)) + _logger.Debug($"Rolling {itemName} with {trader} - Return {traderReturnChance}% - Roll: {returnChance} - Status: {status}"); return roll; } @@ -696,7 +706,8 @@ public class InsuranceController( foreach (var softInsertSlot in softInsertSlots) { - _logger.Debug($"SoftInsertSlots: {softInsertSlot.SlotId}"); + if(_logger.IsLogEnabled(LogLevel.Debug)) + _logger.Debug($"SoftInsertSlots: {softInsertSlot.SlotId}"); pmcData.InsuredItems.Add(new InsuredItem { TId = body.TransactionId, ItemId = softInsertSlot.Id }); } } @@ -727,7 +738,8 @@ public class InsuranceController( // Ensure hash has item in it if (!inventoryItemsHash.ContainsKey(itemId)) { - _logger.Debug($"Item with id: {itemId} missing from player inventory, skipping"); + if(_logger.IsLogEnabled(LogLevel.Debug)) + _logger.Debug($"Item with id: {itemId} missing from player inventory, skipping"); continue; } diff --git a/Libraries/Core/Controllers/LocationController.cs b/Libraries/Core/Controllers/LocationController.cs index 4b8a0342..0b5b6d33 100644 --- a/Libraries/Core/Controllers/LocationController.cs +++ b/Libraries/Core/Controllers/LocationController.cs @@ -5,6 +5,7 @@ using Core.Models.Eft.Location; using Core.Models.Utils; using Core.Services; using Core.Utils.Cloners; +using LogLevel = Core.Models.Spt.Logging.LogLevel; namespace Core.Controllers; @@ -37,7 +38,8 @@ public class LocationController( var mapBase = kvp.Value.Base; if (mapBase == null) { - _logger.Debug($"Map: {kvp} has no base json file, skipping generation"); + if(_logger.IsLogEnabled(LogLevel.Debug)) + _logger.Debug($"Map: {kvp} has no base json file, skipping generation"); continue; } diff --git a/Libraries/Core/Controllers/QuestController.cs b/Libraries/Core/Controllers/QuestController.cs index 592ddad9..f5a6d68e 100644 --- a/Libraries/Core/Controllers/QuestController.cs +++ b/Libraries/Core/Controllers/QuestController.cs @@ -14,6 +14,7 @@ using Core.Services; using Core.Utils; using Core.Utils.Cloners; using SptCommon.Extensions; +using LogLevel = Core.Models.Spt.Logging.LogLevel; namespace Core.Controllers; @@ -188,7 +189,8 @@ public class QuestController( var matchingQuest = repeatableQuest.ActiveQuests.FirstOrDefault(x => x.Id == acceptedQuest.QuestId); if (matchingQuest is not null) { - _logger.Debug($"Accepted repeatable quest {acceptedQuest.QuestId} from {repeatableQuest.Name}"); + if(_logger.IsLogEnabled(LogLevel.Debug)) + _logger.Debug($"Accepted repeatable quest {acceptedQuest.QuestId} from {repeatableQuest.Name}"); matchingQuest.SptRepatableGroupName = repeatableQuest.Name; return matchingQuest; diff --git a/Libraries/Core/Generators/BotWeaponGenerator.cs b/Libraries/Core/Generators/BotWeaponGenerator.cs index 7746a9dd..c02cf589 100644 --- a/Libraries/Core/Generators/BotWeaponGenerator.cs +++ b/Libraries/Core/Generators/BotWeaponGenerator.cs @@ -11,6 +11,7 @@ using Core.Servers; using Core.Services; using Core.Utils; using Core.Utils.Cloners; +using LogLevel = Core.Models.Spt.Logging.LogLevel; namespace Core.Generators; @@ -529,9 +530,10 @@ public class BotWeaponGenerator( } var defaultMagTplId = _botWeaponGeneratorHelper.GetWeaponsDefaultMagazineTpl(weaponTemplate); - _logger.Debug( - $"[{botRole}] Unable to find magazine for weapon: {weaponTemplate.Id} {weaponTemplate.Name}, using mag template default: {defaultMagTplId}." - ); + if(_logger.IsLogEnabled(LogLevel.Debug)) + _logger.Debug( + $"[{botRole}] Unable to find magazine for weapon: {weaponTemplate.Id} {weaponTemplate.Name}, using mag template default: {defaultMagTplId}." + ); return defaultMagTplId; } @@ -550,17 +552,18 @@ public class BotWeaponGenerator( var desiredCaliber = GetWeaponCaliber(weaponTemplate); if (!cartridgePool.TryGetValue(desiredCaliber, out var cartridgePoolForWeapon) || cartridgePoolForWeapon?.Keys.Count == 0) { - _logger.Debug( - _localisationService.GetText( - "bot-no_caliber_data_for_weapon_falling_back_to_default", - new - { - weaponId = weaponTemplate.Id, - weaponName = weaponTemplate.Name, - defaultAmmo = weaponTemplate.Properties.DefAmmo, - } - ) - ); + if(_logger.IsLogEnabled(LogLevel.Debug)) + _logger.Debug( + _localisationService.GetText( + "bot-no_caliber_data_for_weapon_falling_back_to_default", + new + { + weaponId = weaponTemplate.Id, + weaponName = weaponTemplate.Name, + defaultAmmo = weaponTemplate.Properties.DefAmmo, + } + ) + ); // Immediately returns, default ammo is guaranteed to be compatible return weaponTemplate.Properties.DefAmmo; diff --git a/Libraries/Core/Generators/LocationLootGenerator.cs b/Libraries/Core/Generators/LocationLootGenerator.cs index 44a9e9ce..ea902992 100644 --- a/Libraries/Core/Generators/LocationLootGenerator.cs +++ b/Libraries/Core/Generators/LocationLootGenerator.cs @@ -11,6 +11,7 @@ using Core.Utils; using Core.Utils.Cloners; using Core.Utils.Collections; using SptCommon.Annotations; +using LogLevel = Core.Models.Spt.Logging.LogLevel; namespace Core.Generators; @@ -113,7 +114,8 @@ public class LocationLootGenerator( staticLootItemCount += containerWithLoot.Template.Items.Count; } - _logger.Debug($"Added {guaranteedContainers.Count} guaranteed containers"); + if(_logger.IsLogEnabled(LogLevel.Debug)) + _logger.Debug($"Added {guaranteedContainers.Count} guaranteed containers"); // Randomisation is turned off globally or just turned off for this map if ( @@ -123,9 +125,10 @@ public class LocationLootGenerator( ) ) { - _logger.Debug( - $"Container randomisation disabled, Adding {staticRandomisableContainersOnMap.Count} containers to {locationBase.Name}" - ); + if(_logger.IsLogEnabled(LogLevel.Debug)) + _logger.Debug( + $"Container randomisation disabled, Adding {staticRandomisableContainersOnMap.Count} containers to {locationBase.Name}" + ); foreach (var container in staticRandomisableContainersOnMap) { var containerWithLoot = AddLootToContainer( @@ -166,7 +169,8 @@ public class LocationLootGenerator( if (data.ContainerIdsWithProbability.Count == 0) { - _logger.Debug($"`Group: {key} has no containers with< 100 % spawn chance to choose from, skipping"); + if(_logger.IsLogEnabled(LogLevel.Debug)) + _logger.Debug($"`Group: {key} has no containers with< 100 % spawn chance to choose from, skipping"); continue; } @@ -203,9 +207,10 @@ public class LocationLootGenerator( ); if (containerObject is null) { - _logger.Debug( - $"Container: {chosenContainerId} not found in staticRandomisableContainersOnMap, this is bad" - ); + if(_logger.IsLogEnabled(LogLevel.Debug)) + _logger.Debug( + $"Container: {chosenContainerId} not found in staticRandomisableContainersOnMap, this is bad" + ); continue; } @@ -283,9 +288,10 @@ public class LocationLootGenerator( var containerIds = containerData.ContainerIdsWithProbability.Keys.ToList(); if (containerData.ChosenCount > containerIds.Count) { - _logger.Debug( - $"Group: {groupId} wants {containerData.ChosenCount} containers but pool only has {containerIds.Count}, add what's available" - ); + if(_logger.IsLogEnabled(LogLevel.Debug)) + _logger.Debug( + $"Group: {groupId} wants {containerData.ChosenCount} containers but pool only has {containerIds.Count}, add what's available" + ); return containerIds; } @@ -357,9 +363,10 @@ public class LocationLootGenerator( if (container.Probability >= 1) { - _logger.Debug( - $"Container {container.Template.Id} with group ${groupData.GroupId} had 100 % chance to spawn was picked as random container, skipping" - ); + if(_logger.IsLogEnabled(LogLevel.Debug)) + _logger.Debug( + $"Container {container.Template.Id} with group ${groupData.GroupId} had 100 % chance to spawn was picked as random container, skipping" + ); continue; } @@ -677,7 +684,8 @@ public class LocationLootGenerator( // Point is blacklsited, skip if (blacklistedSpawnpoints?.Contains(spawnpoint.Template.Id) ?? false) { - _logger.Debug($"Ignoring loose loot location: {spawnpoint.Template.Id}"); + if(_logger.IsLogEnabled(LogLevel.Debug)) + _logger.Debug($"Ignoring loose loot location: {spawnpoint.Template.Id}"); continue; } @@ -720,17 +728,18 @@ public class LocationLootGenerator( var tooManySpawnPointsRequested = desiredSpawnpointCount - chosenSpawnpoints.Count > 0; if (tooManySpawnPointsRequested) { - _logger.Debug( - _localisationService.GetText( - "location-spawn_point_count_requested_vs_found", - new - { - requested = desiredSpawnpointCount + guaranteedLoosePoints.Count, - found = chosenSpawnpoints.Count, - mapName = locationName, - } - ) - ); + if(_logger.IsLogEnabled(LogLevel.Debug)) + _logger.Debug( + _localisationService.GetText( + "location-spawn_point_count_requested_vs_found", + new + { + requested = desiredSpawnpointCount + guaranteedLoosePoints.Count, + found = chosenSpawnpoints.Count, + mapName = locationName, + } + ) + ); } // Iterate over spawnpoints @@ -839,7 +848,8 @@ public class LocationLootGenerator( ); if (items is null || !items.Any()) { - _logger.Debug($"Unable to adjust loot item {itemTpl} as it does not exist inside {locationName} forced loot."); + if(_logger.IsLogEnabled(LogLevel.Debug)) + _logger.Debug($"Unable to adjust loot item {itemTpl} as it does not exist inside {locationName} forced loot."); continue; } @@ -917,9 +927,10 @@ public class LocationLootGenerator( } else { - _logger.Debug( - $"Attempted to add a forced loot location with Id: {locationTemplateToAdd.Id} to map {locationName} that already has that id in use, skipping" - ); + if(_logger.IsLogEnabled(LogLevel.Debug)) + _logger.Debug( + $"Attempted to add a forced loot location with Id: {locationTemplateToAdd.Id} to map {locationName} that already has that id in use, skipping" + ); } } } @@ -1076,7 +1087,8 @@ public class LocationLootGenerator( else { // RSP30 (62178be9d0050232da3485d9/624c0b3340357b5f566e8766/6217726288ed9f0845317459) doesn't have any default presets and kills this code below as it has no chidren to reparent - _logger.Debug($"createStaticLootItem() No preset found for weapon: {chosenTpl}"); + if(_logger.IsLogEnabled(LogLevel.Debug)) + _logger.Debug($"createStaticLootItem() No preset found for weapon: {chosenTpl}"); } rootItem = items[0]; diff --git a/Libraries/Core/Generators/LootGenerator.cs b/Libraries/Core/Generators/LootGenerator.cs index 3c6c9563..2dd31eaf 100644 --- a/Libraries/Core/Generators/LootGenerator.cs +++ b/Libraries/Core/Generators/LootGenerator.cs @@ -11,6 +11,7 @@ using Core.Models.Utils; using Core.Services; using Core.Utils; using Core.Utils.Cloners; +using LogLevel = Core.Models.Spt.Logging.LogLevel; namespace Core.Generators; @@ -360,7 +361,8 @@ public class LootGenerator( // No `_encyclopedia` property, not possible to reliably get root item tpl if (chosenPreset.Encyclopedia is null) { - _logger.Debug("$Preset with id: {chosenPreset?.Id} lacks encyclopedia property, skipping"); + if(_logger.IsLogEnabled(LogLevel.Debug)) + _logger.Debug("$Preset with id: {chosenPreset?.Id} lacks encyclopedia property, skipping"); return false; } @@ -368,7 +370,8 @@ public class LootGenerator( // Get preset root item db details via its `_encyclopedia` property var itemDbDetails = _itemHelper.GetItem(chosenPreset.Encyclopedia); if (!itemDbDetails.Key) { - _logger.Debug($"$Unable to find preset with tpl: {chosenPreset.Encyclopedia}, skipping"); + if(_logger.IsLogEnabled(LogLevel.Debug)) + _logger.Debug($"$Unable to find preset with tpl: {chosenPreset.Encyclopedia}, skipping"); return false; } @@ -493,7 +496,8 @@ public class LootGenerator( var ammoBoxesMatchingCaliber = ammoBoxesDetails.Where((x) => x.Properties.AmmoCaliber == weaponCaliber); if (!ammoBoxesMatchingCaliber.Any()) { - _logger.Debug($"No ammo box with caliber {weaponCaliber} found, skipping"); + if(_logger.IsLogEnabled(LogLevel.Debug)) + _logger.Debug($"No ammo box with caliber {weaponCaliber} found, skipping"); continue; } @@ -519,7 +523,8 @@ public class LootGenerator( ); if (rewardItemPool.Count() == 0) { - _logger.Debug($"No items with base type of {rewardKey} found, skipping"); + if(_logger.IsLogEnabled(LogLevel.Debug)) + _logger.Debug($"No items with base type of {rewardKey} found, skipping"); continue; } @@ -561,9 +566,10 @@ public class LootGenerator( (item) => item?.Parent == rewardKey && !_itemFilterService.IsItemBlacklisted(item.Id) ); if (relatedItems is null || relatedItems.Count() == 0) { - _logger.Debug( - $"No items found to fulfil reward type: {rewardKey} for weapon: {chosenWeaponPreset.Name}, skipping type" - ); + if(_logger.IsLogEnabled(LogLevel.Debug)) + _logger.Debug( + $"No items found to fulfil reward type: {rewardKey} for weapon: {chosenWeaponPreset.Name}, skipping type" + ); continue; } diff --git a/Libraries/Core/Services/BotLootCacheService.cs b/Libraries/Core/Services/BotLootCacheService.cs index 6cf4b0dd..472cf33c 100644 --- a/Libraries/Core/Services/BotLootCacheService.cs +++ b/Libraries/Core/Services/BotLootCacheService.cs @@ -22,13 +22,17 @@ public class BotLootCacheService( ) { protected Dictionary _lootCache = new(); + protected object _lock = new(); /// /// Remove cached bot loot data /// public void ClearCache() { - _lootCache.Clear(); + lock (_lock) + { + _lootCache.Clear(); + } } /// @@ -46,14 +50,21 @@ public class BotLootCacheService( BotType botJsonTemplate, MinMax? itemPriceMinMax = null) { - if (!BotRoleExistsInCache(botRole)) + lock (_lock) { - InitCacheForBotRole(botRole); - AddLootToCache(botRole, isPmc, botJsonTemplate); + if (!BotRoleExistsInCache(botRole)) + { + InitCacheForBotRole(botRole); + AddLootToCache(botRole, isPmc, botJsonTemplate); + } } Dictionary result = null; - var botRoleCache = _lootCache[botRole]; + BotLootCache botRoleCache; + lock (_lock) + { + botRoleCache = _lootCache[botRole]; + } switch (lootType) { case LootCacheType.Special: @@ -436,21 +447,25 @@ public class BotLootCacheService( filteredVestItems[itemKvP.Key] = itemKvP.Value; } - var cacheForRole = _lootCache[botRole]; + BotLootCache cacheForRole; + lock (_lock) + { + cacheForRole = _lootCache[botRole]; - cacheForRole.HealingItems = healingItems; - cacheForRole.DrugItems = drugItems; - cacheForRole.FoodItems = foodItems; - cacheForRole.DrinkItems = drinkItems; - cacheForRole.CurrencyItems = currencyItems; - cacheForRole.StimItems = stimItems; - cacheForRole.GrenadeItems = grenadeItems; + cacheForRole.HealingItems = healingItems; + cacheForRole.DrugItems = drugItems; + cacheForRole.FoodItems = foodItems; + cacheForRole.DrinkItems = drinkItems; + cacheForRole.CurrencyItems = currencyItems; + cacheForRole.StimItems = stimItems; + cacheForRole.GrenadeItems = grenadeItems; - cacheForRole.SpecialItems = specialLootItems; - cacheForRole.BackpackLoot = filteredBackpackItems; - cacheForRole.PocketLoot = filteredPocketItems; - cacheForRole.VestLoot = filteredVestItems; - cacheForRole.SecureLoot = secureLootTPool; + cacheForRole.SpecialItems = specialLootItems; + cacheForRole.BackpackLoot = filteredBackpackItems; + cacheForRole.PocketLoot = filteredPocketItems; + cacheForRole.VestLoot = filteredVestItems; + cacheForRole.SecureLoot = secureLootTPool; + } } /// @@ -546,7 +561,8 @@ public class BotLootCacheService( /// true if they exist protected bool BotRoleExistsInCache(string botRole) { - return _lootCache.ContainsKey(botRole); + lock (_lock) + return _lootCache.ContainsKey(botRole); } /// @@ -555,23 +571,26 @@ public class BotLootCacheService( /// Bot role to hydrate protected void InitCacheForBotRole(string botRole) { - _lootCache[botRole] = new() + lock (_lock) { - BackpackLoot = new(), - PocketLoot = new(), - VestLoot = new(), - SecureLoot = new(), - CombinedPoolLoot = new(), + _lootCache.Add(botRole, new() + { + BackpackLoot = new(), + PocketLoot = new(), + VestLoot = new(), + SecureLoot = new(), + CombinedPoolLoot = new(), - SpecialItems = new(), - GrenadeItems = new(), - DrugItems = new(), - FoodItems = new(), - DrinkItems = new(), - CurrencyItems = new(), - HealingItems = new(), - StimItems = new(), - }; + SpecialItems = new(), + GrenadeItems = new(), + DrugItems = new(), + FoodItems = new(), + DrinkItems = new(), + CurrencyItems = new(), + HealingItems = new(), + StimItems = new(), + }); + } } ///