smaitch / Grail

World of Warcraft addon to provide a database of quest information.
31 stars 20 forks source link

Script slowing logins #122

Closed solitha closed 4 years ago

solitha commented 4 years ago

Logins are slower with the latest release and sometimes I get this error on loading into the game.

1x Grail\Grail-107.lua:7533: script ran too long [string "@Grail\Grail-107.lua"]:7533: in function_LocationStructure' [string "@Grail\Grail-107.lua"]:7508: in function _LocationKnown' [string "@Grail\Grail-107.lua"]:4409: in function_UpdateDatabaseFromLearnedDatabase' [string "@Grail\Grail-107.lua"]:4634: in function ?' [string "@Grail\Grail-107.lua"]:1559: in function?' [string "@Grail\Grail-107.lua"]:10472: in function `_Tooltip_OnEvent' [string "@Grail\Grail-107.lua"]:11058: in function <Grail\Grail.lua:11058>

Locals: self =

{ QuestBreadcrumbsFor = defined @Grail\Grail.lua:9088 bitMaskClassPriest = 256 IsBugged = defined @Grail\Grail.lua:6974 bitMaskGenderMale = 8192 _RecordArtifactLevels = defined @Grail\Grail.lua:9686 bitMaskCompleted = 1 _PrepareWorldQuestSelfNewNPCs = defined @Grail\Grail.lua:3324 QuestLocationsAccept = defined @Grail\Grail.lua:9246 IsAvailable = defined @Grail\Grail.lua:6956 NO_SKILL = -1 _HandleEventGarrisonBuildingActivated = defined @Grail\Grail.lua:6661 bitMaskClassAll = 268443644 _HandleEventLootClosed = defined @Grail\Grail.lua:6689 bitMaskQuestLegendary = 4096 _RemoveDelayedNotification = defined @Grail\Grail.lua:5095 reputationFriends =
{ } NPC_TYPE_BY = "BY" NPC_TYPE_DROP = "DROP" _PostDelayedNotification = defined @Grail\Grail.lua:8359 _MarkQuestType = defined @Grail\Grail.lua:5464 receivedCalendarUpdateEventList = false bitMaskClassDeathKnight = 4 QuestNPCPrerequisiteTurnins = defined @Grail\Grail.lua:9417 _ProcessServerBackup = defined @Grail\Grail.lua:8777 bitMaskQuestVariableLevel = 4278190080 MeetsRequirementGroup = defined @Grail\Grail.lua:7952 _EvaluateCodeAsPrerequisite = defined @Grail\Grail.lua:5978 bitMaskInLog = 16 bitMaskQuestWeekly = 4 bitMaskHolidayNoble = 256 MeetsRequirementProfession = defined @Grail\Grail.lua:8037 DoesNPCExist = defined @Grail\Grail.lua:5943 npcNames =
{ } _AllEvaluateTrueS = defined @Grail\Grail.lua:3690 bitMaskQuestFailureWithAncestor = 67043200 verifyTable =
{ } _NPCToUse = defined @Grail\Grail.lua:8223 garrisonBuildingLevelMapping =
{ } bitMaskClassHunter = 16 _LoadContinentData = defined @Grail\Grail.lua:3152 bitMaskQuestRaid = 128 _LocationStructure = defined @Grail\Grail.lua:7519 _HandleEventAchievementEarned = defined @Grail\Grail.lua:6656 checksReputationRewardsOnAcceptance = true classToMapAreaMapping =
{ } verifyTableCount = 0 playerGenderBitMask = 16384 _ReputationExceeds = defined @Grail\Grail.lua:9874 bitMaskRaceUnused9 = 4096 zonesForLootingTreasure =
{ } bitMaskQuestMonthly = 8 mapAreaBaseClass = 200000 exists73 = true LearnObjectName = defined @Grail\Grail.lua:7445 _ContainsAliasNPC = defined @Grail\Grail.lua:5685 classToBitMapping =
{ } FriendshipReputationNameAndLevelName = defined @Grail\Grail.lua:9973 QuestBreadcrumbs = defined @Grail\Grail.lua:9082 NPCName = defined @Grail\Grail.lua:8175 experimental = false bitMaskRaceNightborne = 2 mapAreaBaseReputation = 400000 UnregisterObserverQuestStatus = defined @Grail\Grail.lua:10520 tooltipNPC = com_mithrandir_grailTooltipNPC { } _FactionsFromQuestGivers = defined @Grail\Grail.lua:7854 QuestOnAcceptCompletes = defined @Grail\Grail.lua:9429 bitMaskAncestorLevelTooHigh = 33554432 bitMaskRaceTroll = 16777216 bitMaskCanGetUnused2 = 65536 celebratingHolidayCache =
{ } bitMaskQuestMinLevel = 65280 bitMaskLevelTooHigh = 32768 IsGroup = defined @Grail\Grail.lua:7008 bitMaskCanGetUnused8 = 4194304 bitMaskCanGetUnused15 = 1073741824 MeetsRequirementGroupPossibleToComplete = defined @Grail\Grail.lua:7980 questReputations =
{ } _AddThreatQuest`

T-a-z commented 4 years ago

the same here, login takes a long time, and always errors

`Message: Interface\AddOns\Grail\Grail.lua:8196: script ran too long Time: Fri Feb 7 11:06:38 2020 Count: 1 Stack: Interface\AddOns\Grail\Grail.lua:8196: script ran too long

[string "@Interface\AddOns\Grail\Grail.lua"]:8196: in function NPCName' [string "@Interface\AddOns\Grail\Grail.lua"]:9611: in function_RawNPCLocations' [string "@Interface\AddOns\Grail\Grail.lua"]:8149: in function `NPCLocations' [string "@Interface\AddOns\Grail\Grail.lua"]:9266: in function <Interface\AddOns\Grail\Grail.lua:9254>

[string "@Interface\AddOns\Grail\Grail.lua"]:5791: in function ?' [string "@Interface\AddOns\Grail\Grail.lua"]:1363: in function?' [string "@Interface\AddOns\Grail\Grail.lua"]:10472: in function `_Tooltip_OnEvent' [string "@Interface\AddOns\Grail\Grail.lua"]:11058: in function <Interface\AddOns\Grail\Grail.lua:11058>

Locals: `

smaitch commented 4 years ago

After a successful login can you tell me the results of the following slash command:

/dump Grail.timings

solitha commented 4 years ago

Following a clean login that threw no error, I used that and got the following:

1x [string "return Grail.timings"]:1: attempt to index global 'Grail' (a nil value) [string "return Grail.timings"]:1: in functionfunc' [string "@Blizzard_DebugTools\Dump.lua"]:393: in function DevTools_DumpCommand' [string "@FrameXML\ChatFrame.lua"]:2434: in function?' [string "@FrameXML\ChatFrame.lua"]:4859: in function ChatEdit_ParseText' [string "@FrameXML\ChatFrame.lua"]:4523: in functionChatEdit_SendText' [string "@FrameXML\ChatFrame.lua"]:4559: in function `ChatEdit_OnEnterPressed'

Locals: (temporary) = nil (temporary) = nil (*temporary) = "attempt to index global 'Grail' (a nil value)" `

solitha commented 4 years ago

Hmm. Finally hit a character that errored on login as shown below. I ran your dump command, and got the following (hoping I copy it accurately):

[1]={ AchievementsFactionCreation=0.13176369667053, CreateIndexedQuestList=16549.455515385, ProcessServerQuests=232.17944157124, QuestAccepted=0.12089002132416, AchievementsPandariaLoremaster=59.406551718712, AchievementsInternalConversion=121.32109081745, AchievementsInitialSetup=5.7211663722992 }


1x Grail\Grail-107.lua:5572: script ran too long [string "@Grail\Grail-107.lua"]:5572: in functionCodeObtainersRace' [string "@Grail\Grail-107.lua"]:7788: in function <Grail\Grail.lua:7732>

[string "@Grail\Grail-107.lua"]:4986: in function ?' [string "@Grail\Grail-107.lua"]:1559: in function?' [string "@Grail\Grail-107.lua"]:10472: in function `_Tooltip_OnEvent' [string "@Grail\Grail-107.lua"]:11058: in function <Grail\Grail.lua:11058>

Locals: self =

{ QuestBreadcrumbsFor = defined @Grail\Grail.lua:9088 bitMaskClassPriest = 256 IsBugged = defined @Grail\Grail.lua:6974 bitMaskGenderMale = 8192 _RecordArtifactLevels = defined @Grail\Grail.lua:9686 bitMaskCompleted = 1 _PrepareWorldQuestSelfNewNPCs = defined @Grail\Grail.lua:3324 QuestLocationsAccept = defined @Grail\Grail.lua:9246 IsAvailable = defined @Grail\Grail.lua:6956 NO_SKILL = -1 _HandleEventGarrisonBuildingActivated = defined @Grail\Grail.lua:6661 bitMaskClassAll = 268443644 _HandleEventLootClosed = defined @Grail\Grail.lua:6689 bitMaskQuestLegendary = 4096 _RemoveDelayedNotification = defined @Grail\Grail.lua:5095 reputationFriends =
{ } NPC_TYPE_BY = "BY" NPC_TYPE_DROP = "DROP" _PostDelayedNotification = defined @Grail\Grail.lua:8359 _MarkQuestType = defined @Grail\Grail.lua:5464 receivedCalendarUpdateEventList = false bitMaskClassDeathKnight = 4 QuestNPCPrerequisiteTurnins = defined @Grail\Grail.lua:9417 _ProcessServerBackup = defined @Grail\Grail.lua:8777 bitMaskQuestVariableLevel = 4278190080 MeetsRequirementGroup = defined @Grail\Grail.lua:7952 _EvaluateCodeAsPrerequisite = defined @Grail\Grail.lua:5978 bitMaskInLog = 16 bitMaskQuestWeekly = 4 bitMaskHolidayNoble = 256 MeetsRequirementProfession = defined @Grail\Grail.lua:8037 DoesNPCExist = defined @Grail\Grail.lua:5943 npcNames =
{ } _AllEvaluateTrueS = defined @Grail\Grail.lua:3690 bitMaskQuestFailureWithAncestor = 67043200 verifyTable =
{ } _NPCToUse = defined @Grail\Grail.lua:8223 garrisonBuildingLevelMapping =
{ } bitMaskClassHunter = 16 _LoadContinentData = defined @Grail\Grail.lua:3152 bitMaskQuestRaid = 128 _LocationStructure = defined @Grail\Grail.lua:7519 _HandleEventAchievementEarned = defined @Grail\Grail.lua:6656 checksReputationRewardsOnAcceptance = true classToMapAreaMapping =
{ } verifyTableCount = 0 playerGenderBitMask = 16384 _ReputationExceeds = defined @Grail\Grail.lua:9874 bitMaskRaceUnused9 = 4096 zonesForLootingTreasure =
{ } bitMaskQuestMonthly = 8 mapAreaBaseClass = 200000 exists73 = true LearnObjectName = defined @Grail\Grail.lua:7445 _ContainsAliasNPC = defined @Grail\Grail.lua:5685 classToBitMapping =
{ } FriendshipReputationNameAndLevelName = defined @Grail\Grail.lua:9973 QuestBreadcrumbs = defined @Grail\Grail.lua:9082 NPCName = defined @Grail\Grail.lua:8175 experimental = false bitMaskRaceNightborne = 2 mapAreaBaseReputation = 400000 UnregisterObserverQuestStatus = defined @Grail\Grail.lua:10520 tooltipNPC = com_mithrandir_grailTooltipNPC { } _FactionsFromQuestGivers = defined @Grail\Grail.lua:7854 QuestOnAcceptCompletes = defined @Grail\Grail.lua:9429 bitMaskAncestorLevelTooHigh = 33554432 bitMaskRaceTroll = 16777216 bitMaskCanGetUnused2 = 65536 celebratingHolidayCache =
{ } bitMaskQuestMinLevel = 65280 bitMaskLevelTooHigh = 32768 IsGroup = defined @Grail\Grail.lua:7008 bitMaskCanGetUnused8 = 4194304 bitMaskCanGetUnused15 = 1073741824 MeetsRequirementGroupPossibleToComplete = defined @Grail\Grail.lua:7980 questReputations =
{ } _AddThreatQuest`

solitha commented 4 years ago

The next two characters also threw errors on login. One showed similar results to the dump command. The other had this: [1]={ AchievementsInitialSetup=6.795104265213, AddonLoaded=18039.455547333, QuestAccepted=0.10649824142456, ProcessServerQuests=160.57803320885, AchievementsPandariaLoremaster=70.984166026115, AchievementsFactionCreation=0.128556554985046, AchievementsInternalConversion=204.35779595375, CreateIndexedQuestList=15688.972787023, }

smaitch commented 4 years ago

Wow that timings list is unexpected. Are you on a really slow machine? I am running WoW on a laptop and my CreateIndexQuestList value is 4013.xxx which means about 4 seconds, while yours is about 16 seconds. Admittedly, characters with fewer quests done, etc. seem to have on my laptop about a 3 second value instead of my most complex at 4 seconds. I will investigate if I can instrument and/or improve creating that initial list.

solitha commented 4 years ago

I mean, not that I know of. It's an older computer but it's serving well through a variety of games. I don't know what kind of metrics you'd need to judge that.

And the slowdown definitely became notable after the addon update a few days ago.

smaitch commented 4 years ago

Using the fact that the slowdown occurs when the 107 version is used is helpful. I will analyze all the changes and see if any might be impacting the performance.

T-a-z commented 4 years ago

After a successful login can you tell me the results of the following slash command:

/dump Grail.timings

no login possible without error message. dump: [1]={ AchievementsFactionCreation=0.091511390986852, AchievementsPandariaLoremaster=3.2681314671645, AchievementsInternalConversion=87.483962319558, AchievementsInitialSetup=3.426421440905 }

My Pc: Ram: 64GB CPU: Intel I5 6600 @ 3.3GHz SSD: Crucial MX500 (500GB)

smaitch commented 4 years ago

Can you try to use the latest Grail from GitHub to see if the problem still happens for you?

solitha commented 4 years ago

Ugh... sorry, you've gone beyond my extremely limited GitHub knowledge. Hope the others can help.

smaitch commented 4 years ago

Grail 110 is release. It should fix this issue.